laravel schedule 초단위 사용할때 cron 주의사항
Updated on
진짜 10시간동안 이 문제를 해결하느라 고생했다.
일단 간단하게 설명하자면.
Schedule::command(TestCommand::class)->everyMinute()->onOneServer()->runInBackground(); Schedule::command(Test2Command::class)->everyTwoSeconds()->onOneServer()->runInBackground(); Schedule::command(Test2Command::class)->everyTwoSeconds()->onOneServer()->runInBackground();
이런식으로 laravel schedule 을 초 단위로 설정하는 경우가 있다.
이때 문서에서는 말하길
SHELL=/bin/sh PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin * * * * * php /var/www/artisan schedule:run > /tmp/cron.last 2>&1
처럼 하라고 되어있다.
근데 여기서는 큰 문제가 하나 있는데.
schedule:run 는 process 가 뜨고, 거기서 1분동안 매 1초마다 process가 반복적으로 돌아간다는 것이다.
그 코드가 laravel 코드에서 그렇게 되어있다.
처음 접근은 onOneServer 문제인가? runInBackground 문제인가 ? command? job? 이쪽을 디버깅했지만 여기에서 발생되는 문제는 아니였다. 그래서 php 자체가 실행되는건지 체크했더니. 아예 실행조차 안되고 있었다.
그래서 처음에 alpine linux 이미지에서 dcron을 설치해서 사용하고 있었는데. dcron의 문제인가? 싶어서 dcron 을 지우고 busybox cron 으로 바꿔보기도 했다.
그런데 여전히 busybox cron 으로 변경해도 해결되지 않았다.
그래서 결국에 cron에 logging 을 했고.
cat cron.log crond: crond (busybox 1.37.0) started, log level 8 crond: USER cron pid 86 cmd php /var/www/artisan schedule:run > /tmp/cron.last 2>&1 crond: USER cron pid 87 cmd echo "Cron is working: $(date)" >> /tmp/cron_test.log crond: user cron: process already running: php /var/www/artisan schedule:run > /tmp/cron.last 2>&1 crond: USER cron pid 896 cmd echo "Cron is working: $(date)" >> /tmp/cron_test.log crond: USER cron pid 904 cmd php /var/www/artisan schedule:run > /tmp/cron.last 2>&1 crond: USER cron pid 905 cmd echo "Cron is working: $(date)" >> /tmp/cron_test.log
이런 결과를 얻게 됬다.
crond: user cron: process already running
프로세스 중복으로 실행이 안된거다…
아.. 이걸 지금 알았다니 ㅠㅠ
그래서 찾아본 결과
바로 이렇게.. 체크해서 이미 프로세스가 실행중이라면 중복 실행을 하지 않는걸 확인할 수 있었다. 진짜… cron 이 pid 중복 실행을 억제한다는 걸 알았다. 아닌가? 알고있었는데 까먹었었나 ㅡ. ㅡ ?
아… 그래서 해결한 방법은 ..
SHELL=/bin/sh PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin * * * * * php /var/www/artisan schedule:run > /tmp/cron.last 2>&1 &
뒤에 & 를 붙임으로서 백그라운드 실행으로 변경해서 해결하게 되었다.
옛날에는 뒤에 & 를 붙여서 사용하곤 했는데, 저번에 초단위 스케쥴러가 추가되었을때 문서를 보고서 & 를 제거해서 사용하고 있는데 이것이 문제가 된 것 같다.
그러면 왜 이 문제가 발생하느냐 ??? php schedule:run 가 59초를 마지막 기점으로 종료가 되야한다.
protected function repeatEvents($events) { $hasEnteredMaintenanceMode = false; while (Date::now()->lte($this->startedAt->endOfMinute())) { foreach ($events as $event) { if ($this->shouldInterrupt()) { return; } if (! $event->shouldRepeatNow()) { continue; } $hasEnteredMaintenanceMode = $hasEnteredMaintenanceMode || $this->laravel->isDownForMaintenance(); if ($hasEnteredMaintenanceMode && ! $event->runsInMaintenanceMode()) { continue; } if (! $event->filtersPass($this->laravel)) { $this->dispatcher->dispatch(new ScheduledTaskSkipped($event)); continue; } if ($event->onOneServer) { $this->runSingleServerEvent($event); } else { $this->runEvent($event); } $this->eventsRan = true; } Sleep::usleep(100000); } }
그런데. 이게 2초마다 실행되게 하더라도 2,4,6,8초마다 실행되지가 않는다.
command 를 매번 읽을때마다 약간의 딜레이가 생기는데, 그럴때
2,4,7,9,11,12,14 이런식으로 중간에 시간이 밀려 실행되는 경우가 있다.
그렇다면 59초에 실행되는 command 들이 1초 이내에 모두 완료되지 못한다면,
해당 프로세스는 59초에 종료가되야하지만 59초에 실행된 명령어들이 아직 마무리 되지 않았기 때문에
cron 에서는 crond: user cron: process already running
문제가 발생하게 되는것이다.
이 문제는 결국에 스케쥴러에서 돌아갈때 무조건 runInBackground()
를 써야되는건 당연한거고.
schedule:run
를 사용할거면, 뒤에 & 백그라운드로 실행해야 되고.
중복관리는 코드 상으로 컨트롤 해야한다.
Schedule::command(Test2Command::class)->everyTwoSeconds()->onOneServer()->withoutOverlapping()->runInBackground();
withoutOverlapping()
를 사용해서 말이다.
참고로 모두 job이든, command 를 dispatch 해서 job으로 넘기든, command 가 40개, 50개가 되는 순간부터 process 가 60초를 넘기지 않을거란 보장은 없다.
물론 이 문제가 busybox cron 나 dcron 만의 문제일 수도 있다. 내가 alpine linux image로 넘어오면서 생겼을 수도 있고.
아무튼 schedule:run
를 사용해서 스케쥴러를 돌릴거라면, 백그라운드 실행을 추천한다.