Flask Scheduling이 2번 실행되는 현상에 대해

개요

최근에 특정 시간이 되면 지정된 Slack Channel에 메시지를 전송해 주는 간단한 Flask 서버를 만들었습니다. AWS의 App Runner를 이용해 배포된 상태였는데 어째선지 Flask 서버의 Scheduler가 2번 실행되는 현상을 겪었습니다. 이로 인해 같은 Slack Channel에 메시지를 중복 전송되는 문제가 발생했습니다.

문제의 짤

 

어떻게 된 건지 싶어 이런저런 조사를 하게 되었습니다. 적용된 환경은 Flask 2.2.2에 Scheduling 처리는 APScheduler 3.10.1을 입니다.

╰─$ pip list
Package               Version
--------------------- -----------
APScheduler           3.10.1
...
Flask                 2.2.2
...

Flask의 Debug 모드

해결 방법을 찾던 도중 flask-apscheduler라는 라이브러리의 Issue에서 적힌 정보를 읽게 되었습니다

That happens because Flask in debug mode spawns a child process so that it can restart that process each time your code changes, the new child process initializes and starts a new APScheduler, that's why your jobs are running twice.

Context: https://stackoverflow.com/questions/25504149/why-does-running-the-flask-dev-server-run-itself-twice

I guess I can detect if the current process is the child one and then I wouldn't allow APScheduler to start.

For now, to work around that, you can either to set Flask reloader use_reloader=False or debug=False.

이슈 내용 중 발췌

내용을 보아하니 Flask를 debug 모드로 실행하여 코드 변경을 감지한 경우 하위 프로세스를 새로 생성하고 생성된 프로세스로 Flask를 가동한다고 합니다. 상황에 대입해 이해해 보자면, 개발 시의 편의를 위해 코드를 변경할 경우 Flask가 재시작되는데 ApSchduler를 사용할 경우 이 영향으로 코드가 두 번 실행될 수 있다고 하는 것 같습니다.

 

적힌 텍스트만 읽었을 때는 ApScheduler는 Scheduling이 적용된 코드를 실행하고 나면 Flask를 다시 실행하는 잠재적인 요소가 있다는 걸로 보입니다.

 

검증을 해봅시다.
 

검증하기

검증을 위해 구성한 코드입니다. debug, use_reolader를 True로 설정하고 APScheduler를 이용해 간단한 Scheduler를 추가해 코드가 2번씩 실행되는지 확인해 봅시다.

import os
from flask import Flask
import time

from apscheduler.schedulers.background import BackgroundScheduler

app = Flask(__name__)


def job_for_testing():
    print(f'will be printed twice... {time.time()}, {os.getpid()}')


background_scheduler = BackgroundScheduler(
    timezone='Asia/Seoul',
    daemon=True
)

background_scheduler.add_job(
    job_for_testing, 'interval', seconds=5, id='1'
)
background_scheduler.start()


@app.route("/")
def index():
    return "Hello World"


if __name__ == '__main__':
    app.run(debug=True, use_reloader=True)

위 코드는 5초마다 job_for_testing() 함수를 호출하는 코드입니다. 코드를 실행하면 다음과 같은 결과를 얻을 수 있습니다.

(venv) ╭─jako@prompt-mini ~/private/opt
╰─$ python app.py
 * Serving Flask app 'app'
 * Debug mode: on
WARNING: This is a development server. Do not use it in a production deployment. Use a production WSGI server instead.
 * Running on http://127.0.0.1:5000
Press CTRL+C to quit
 * Restarting with stat
 * Debugger is active!
 * Debugger PIN: 141-457-385
will be printed twice... 1677844849.7060218, (6940, 3371)
will be printed twice... 1677844849.882195, (6941, 6940)
will be printed twice... 1677844854.7027369, (6940, 3371)
will be printed twice... 1677844854.879904, (6941, 6940)
will be printed twice... 1677844859.7019148, (6940, 3371)
will be printed twice... 1677844859.881723, (6941, 6940)

실행 결과를 보니 5초마다 같은 코드를 2번씩 실행하고 있습니다. 여기에 더해 재밌는 점은 이 코드를 실행한 상태에서 코드를 변경한 경우 다음과 같이 결과가 출력됩니다.

* Detected change in '/Users/jako/private/opt/app.py', reloading
 * Restarting with stat
 * Debugger is active!
 * Debugger PIN: 141-457-385
will be printed twice... 1677844916.823905, (7010, 3371)
[mod] will be printed twice... 1677844917.663384, (7025, 7010)
will be printed twice... 1677844921.8223, (7010, 3371)
[mod] will be printed twice... 1677844922.663629, (7025, 7010)
will be printed twice... 1677844926.826087, (7010, 3371)
[mod] will be printed twice... 1677844927.6637068, (7025, 7010)

변경하기 전 Scheduling 코드도 실행되고 있으며 변경된 이후의 코드도 실행되고 있는 현상을 확인할 수 있습니다. 더불어 pid와 ppid가 변하는 것도 같이 확인이 가능합니다.

해결하기

사실 첨부한 Issue에 해결방법도 다 나와있긴 했습니다. debug와 use_reloader를 false로 처리하고 앞서 실행한 코드를 다시 실행해 봅시다.

...

if __name__ == '__main__':
    app.run(debug=False, use_reloader=False)

이제 Scheduler는 5초마다 한 번씩만 코드를 실행합니다.

╰─$ python app.py
 * Serving Flask app 'app'
 * Debug mode: off
WARNING: This is a development server. Do not use it in a production deployment. Use a production WSGI server instead.
 * Running on http://127.0.0.1:5000
Press CTRL+C to quit
[mod] will be printed twice... 1677922444.447351, (11515, 10438)
[mod] will be printed twice... 1677922449.448627, (11515, 10438)
[mod] will be printed twice... 1677922454.44845, (11515, 10438)
[mod] will be printed twice... 1677922459.444151, (11515, 10438)

이제까지는 간단히 app.py의 파일을 python으로 실행했습니다. 하지만 Flask를 실행하는 것에는 flask run
이라는 명령어로도 실행을 할 수 있습니다. app.py에 debug와 use_reload를 false로 설정하고 실행한 반면에 flask run으로 실행하게 될 경우에는 다음과 같이 처리해 줍시다.

flask run --no-reload

 

아니 근데 왜 debug 모드로 배포를?

맞습니다. 이 문제가 일어난 건 배포 환경을 신경 쓰지 않았다는 점입니다. 만약 uwsgi나 gunicorn과 같은 환경으로 구성하고 올렸다면 당연히  debug나 no-reload 옵션쯤은 false로 설정하고 올렸을 것입니다.

 

덕분에 새로운 사실을 알게 되어 보람은 있지만 배포 환경은 역시 신중할 필요가 있겠네요

후기

2월 회고를 보니 저는 이 문제에 대해 다음과 같이 생각하고 있었습니다.

두 번째 접근법은 똑같은 조금은 다른 결이 다르게 접근했다. App Runner가 컨테이너를 실행할 때 Flask App을 생성한다면 ApScheduler라는 객체의 초기화가 2번 이루어지는 게 아닐까 싶었다 ApScheduler를 실행할 때는 start()라는 메서드를 호출함으로 스케줄링 작업을 호출하는데 이 부분에서 start() 호출하는 시점을 조절해 주면 어떨까 싶었다.

결론적으로는 두 번째 접근법에서 도출한 해법이 메시지를 2번 전송하지 못하게 했는데 실험 중인 단계라서 이게 정확한 것인지는 두고 볼 필요가 있겠다.

... 2월 회고 중

ApScheduler라는 라이브러리를 처음 사용해 보는 것이기 때문에 Flask 내부가 자체적으로 어떤 식으로 돌아가는지에 대해서는 놓친 채로 생각하고 있었습니다.

 

특정 라이브러리를 사용할 때의 잠재적인 문제점은 그 상황을 맞닥뜨릴 때 좀 더 체감이 되는 것 같습니다. 하지만 이번 상황은 여러 테스트를 거친다면 찾아낼 수 있었던 것 같은데 그러지 못했다는 게 아쉬운 부분이네요.