スケジューリングされたAzure Webジョブで長時間の処理を実行する場合に留意しておいたほうが良い点

いわさです。

Azureではジョブタスクを実行するための様々な方法が用意されていますが、その中のひとつにAzure App ServiceのWebジョブという機能があります。

このWebジョブで夜間バッチのようにスケジューリングされた長時間の実行を行うことは可能なのかを調べていました。
可能ではあるのですが、いくつか留意すべき点があったので今度使う時のためにまとめておきたいと思います。

常時接続の有効化

Azure Webジョブはいくつかの実行モードがありますが、継続的実行とトリガーされた実行の場合にまず最初に気をつけなければいけない点がApp Serviceの「常時接続の有効化」です。

常時接続がオフだと、アプリに受信トラフィックが発生しない場合、20分後にアンロードされます。
アンロードされると新しいリクエストが発生した際にウォームアップ時間のために待機時間が発生します。

そして、アンロード中はWebジョブプロセスは実行されないため、スケジューリングが期待した形で動作しないことになります。
こちらはWebジョブのポータル画面や、実行ログでも警告が出るので気をつけている方多いかもしれません。

なお、常時接続のデフォルト設定は「オフ」です。

[09/20/2021 14:49:10 > 19a5ac: SYS INFO] Run script 'ContinuousPrint.exe' with script host - 'WindowsScriptHost'
[09/20/2021 14:49:10 > 19a5ac: SYS INFO] Status changed to Running
[09/20/2021 14:49:10 > 19a5ac: INFO] hoge
[09/20/2021 14:49:10 > 19a5ac: SYS INFO] Status changed to Success
[09/20/2021 14:49:10 > 19a5ac: SYS INFO] Process went down, waiting for 60 seconds
[09/20/2021 14:49:10 > 19a5ac: SYS INFO] Status changed to PendingRestart
[09/20/2021 14:49:59 > 19a5ac: SYS INFO] WebJob is stopping due to website shutting down
[09/20/2021 14:49:59 > 19a5ac: SYS INFO] Status changed to Stopping
[09/20/2021 14:49:59 > 19a5ac: SYS INFO] Status changed to Stopped

常時接続をオンにすると5分おきにGETリクエストが内部ロードバランサーより送信され、アイドル状態になることを回避することが出来ます。
常時接続オンにはBasic以上のプランが必要です。

"WEBJOBS_IDLE_TIMEOUT"

トリガーされたジョブの場合は、環境変数のWEBJOBS_IDLE_TIMEOUTの設定値が有効になります。

この数値は実行中プロセスが待機状態になった場合に、プロセスが中断されるまでの時間です。
デフォルトは120秒になっています。
例えば、120秒以上スリープが発生するようなWebジョブ処理の場合だと、以下のような実行結果となります。

[09/20/2021 15:36:57 > d3d05c: SYS INFO] Status changed to Initializing
[09/20/2021 15:36:57 > d3d05c: SYS INFO] Run script 'ContinuousPrint.exe' with script host - 'WindowsScriptHost'
[09/20/2021 15:36:57 > d3d05c: SYS INFO] Status changed to Running
[09/20/2021 15:36:58 > d3d05c: INFO] hoge
[09/20/2021 15:40:58 > d3d05c: ERR ] Command 'cmd /c ""Continuous ...' was aborted due to no output nor CPU activity for 120 seconds. You can increase the SCM_COMMAND_IDLE_TIMEOUT app setting (or WEBJOBS_IDLE_TIMEOUT if this is a WebJob) if needed.
cmd /c ""ContinuousPrint.exe""
[09/20/2021 15:40:59 > d3d05c: SYS INFO] Status changed to Failed
[09/20/2021 15:40:59 > d3d05c: SYS ERR ] System.AggregateException: One or more errors occurred. ---> Kudu.Core.Infrastructure.CommandLineException: Command 'cmd /c ""Continuous ...' was aborted due to no output nor CPU activity for 120 seconds. You can increase the SCM_COMMAND_IDLE_TIMEOUT app setting (or WEBJOBS_IDLE_TIMEOUT if this is a WebJob) if needed.
cmd /c ""ContinuousPrint.exe""
   at Kudu.Core.Infrastructure.IdleManager.WaitForExit(IProcess process) in C:\Kudu Files\Private\src\master\Kudu.Core\Infrastructure\IdleManager.cs:line 45
   at Kudu.Core.Infrastructure.ProcessExtensions.<Start>d__13.MoveNext() in C:\Kudu Files\Private\src\master\Kudu.Core\Infrastructure\ProcessExtensions.cs:line 254
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Kudu.Core.Infrastructure.Executable.<ExecuteAsync>d__31.MoveNext() in C:\Kudu Files\Private\src\master\Kudu.Core\Infrastructure\Executable.cs:line 255
   --- End of inner exception stack trace ---
   at System.Threading.Tasks.Task.ThrowIfExceptional(Boolean includeTaskCanceledExceptions)
   at System.Threading.Tasks.Task`1.GetResultCore(Boolean waitCompletionNotification)
   at System.Threading.Tasks.Task`1.get_Result()
   at Kudu.Core.Infrastructure.Executable.ExecuteInternal(ITracer tracer, Func`2 onWriteOutput, Func`2 onWriteError, Encoding encoding, String arguments, Object[] args) in C:\Kudu Files\Private\src\master\Kudu.Core\Infrastructure\Executable.cs:line 216
   at Kudu.Core.Infrastructure.Executable.ExecuteReturnExitCode(ITracer tracer, Action`1 onWriteOutput, Action`1 onWriteError, String arguments, Object[] args) in C:\Kudu Files\Private\src\master\Kudu.Core\Infrastructure\Executable.cs:line 165
   at Kudu.Core.Jobs.BaseJobRunner.RunJobInstance(JobBase job, IJobLogger logger, String runId, String trigger, ITracer tracer, Int32 port) in C:\Kudu Files\Private\src\master\Kudu.Core\Jobs\BaseJobRunner.cs:line 272
---> (Inner Exception #0) ExitCode: -1, Output: Command 'cmd /c ""Continuous ...' was aborted due to no output nor CPU activity for 120 seconds. You can increase the SCM_COMMAND_IDLE_TIMEOUT app setting (or WEBJOBS_IDLE_TIMEOUT if this is a WebJob) if needed., Error: Command 'cmd /c ""Continuous ...' was aborted due to no output nor CPU activity for 120 seconds. You can increase the SCM_COMMAND_IDLE_TIMEOUT app setting (or WEBJOBS_IDLE_TIMEOUT if this is a WebJob) if needed., Kudu.Core.Infrastructure.CommandLineException: Command 'cmd /c ""Continuous ...' was aborted due to no output nor CPU activity for 120 seconds. You can increase the SCM_COMMAND_IDLE_TIMEOUT app setting (or WEBJOBS_IDLE_TIMEOUT if this is a WebJob) if needed.
cmd /c ""ContinuousPrint.exe""
   at Kudu.Core.Infrastructure.IdleManager.WaitForExit(IProcess process) in C:\Kudu Files\Private\src\master\Kudu.Core\Infrastructure\IdleManager.cs:line 45
   at Kudu.Core.Infrastructure.ProcessExtensions.<Start>d__13.MoveNext() in C:\Kudu Files\Private\src\master\Kudu.Core\Infrastructure\ProcessExtensions.cs:line 254
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Kudu.Core.Infrastructure.Executable.<ExecuteAsync>d__31.MoveNext() in C:\Kudu Files\Private\src\master\Kudu.Core\Infrastructure\Executable.cs:line 255<---

次のように設定を変更してみましょう。

[09/20/2021 15:43:41 > d3d05c: SYS INFO] Status changed to Initializing
[09/20/2021 15:43:41 > d3d05c: SYS INFO] Run script 'ContinuousPrint.exe' with script host - 'WindowsScriptHost'
[09/20/2021 15:43:41 > d3d05c: SYS INFO] Status changed to Running
[09/20/2021 15:43:42 > d3d05c: INFO] hoge
[09/20/2021 15:48:42 > d3d05c: INFO] hoge

120秒以上のスリープが発生する場合でも実行することが出来ました。
Webジョブで実行する処理の内容によってはこの設定値を意識したほうが良い場合があります。

Graceful Shuttdown

Webジョブが停止される場合、プロセスへシャットダウンの通知がされてからジョブプロセスが停止するまでに待機時間が設けられています。
トリガープロセスの場合はデフォルトは30秒になっています。

この設定値はsettings.jobファイルのstopping_wait_timeで調整することが可能ですので必要に応じて調整すべきか検討されると良いでしょう。

ただし、Webアプリ自体が再起動されるシャットダウンはハードシャットダウンとなり、制限時間が決まっているようなので、これは回避できません。
例としてはVMのメンテナンスに伴うスイッチなどが該当します。

まとめ

長時間の実行は可能ではありますが、何らかの理由(基盤のメンテナンスなど)で中断される可能性を回避することは難しそうです。
中断された場合でも再開したりロールバック出来たりなど、停止しても問題ない前提でジョブは設計することが重要だなと感じました。