I have a webjob which is successfully being triggered in Azure when a new item is added to the storage queue.
When it is triggered, I check the logs and all the code written has executed properly, but the web job stays in a "still executing" state, and after 121 seconds after execution it aborts.
Here is the method that gets triggered followed by the log file where you can see "Start Processing Content" is written to the log and "Processing Content Has Completed" was written to the log. That tells me that everything executed fine, and as far as I know there isn't anything else special that I need to do to signal that this was successfully executed.
So, how I think Web Jobs are supposed to work is that this would be considered a successful execution. Instead it is marked as "Failed" in the dashboard and completely stops the web job (even though it is designed to work in continuous mode). Also, App Service is set to Always On.
The recommendations in the error to increase the timeout make no sense. All that would do is instead of timing out 121 seconds after completion, it would timeout 5 mins after completion or whatever I set it to.
It's completely backwards to me that this timeout would abort the job after the job has even indicated it has "Succeeded". (See all the points I bolded the log below for those details). A bug maybe? Or some other missed setting by myself? Or another piece of absent documentation from MS?
App Service Plan is running on a paid service tier (B1).
public static async Task ProcessQueueMessage([QueueTrigger("myTrigger")] CloudQueueMessage message, TextWriter log)
{
System.Console.Out.WriteLine($"Start Processing Content");
await DoSomeWork();
System.Console.Out.WriteLine($"Processing Content Has Completed");
}
[06/24/2019 00:08:11 > 8a8d8d: INFO] Trigger Details: MessageId: 086184dd-f9be-4e1d-b1e7-49707bd1a4e7, DequeueCount: 1, InsertionTime: 6/24/2019 12:07:48 AM +00:00 [06/24/2019 00:08:11 > 8a8d8d: INFO] Start Processing Content [06/24/2019 00:08:15 > 8a8d8d: INFO] Processing Content Has Completed [06/24/2019 00:08:15 > 8a8d8d: INFO] info: Function.ProcessQueueMessage[0] [06/24/2019 00:08:15 > 8a8d8d: INFO]
Executed 'StorageQueueProcessor.ProcessQueueMessage' (Succeeded, Id=f3fcd403-515a-4746-803e-fba14d2b0455) [**06/24/2019 00:12:17 > 8a8d8d: ERR ] **Command 'cmd /c ""run.cmd""' was aborted due to no output nor CPU activity for 121 seconds. You can increase the SCM_COMMAND_IDLE_TIMEOUT app setting (or WEBJOBS_IDLE_TIMEOUT if this is a WebJob) if needed. cmd /c ""run.cmd"" [06/24/2019 00:12:17 > 8a8d8d: SYS INFO] Status changed to Failed [06/24/2019 00:12:17 > 8a8d8d: SYS ERR ] System.AggregateException: One or more errors occurred. ---> Kudu.Core.Infrastructure.CommandLineException: Command 'cmd /c ""run.cmd""' was aborted due to no output nor CPU activity for 121 seconds. You can increase the SCM_COMMAND_IDLE_TIMEOUT app setting (or WEBJOBS_IDLE_TIMEOUT if this is a WebJob) if needed. cmd /c ""run.cmd"" at Kudu.Core.Infrastructure.IdleManager.WaitForExit(IProcess process) in C:\Kudu Files\Private\src\master\Kudu.Core\Infrastructure\IdleManager.cs:line 96 at Kudu.Core.Infrastructure.ProcessExtensions.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.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Kudu.Core.Infrastructure.Executable.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.Task1.GetResultCore(Boolean waitCompletionNotification) at Kudu.Core.Infrastructure.Executable.ExecuteInternal(ITracer tracer, Func2 onWriteOutput, Func2 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, Action1 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 ""run.cmd""' was aborted due to no output nor CPU activity for 121 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 ""run.cmd""' was aborted due to no output nor CPU activity for 121 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 ""run.cmd""' was aborted due to no output nor CPU activity for 121 seconds. You can increase the SCM_COMMAND_IDLE_TIMEOUT app setting (or WEBJOBS_IDLE_TIMEOUT if this is a WebJob) if needed. cmd /c ""run.cmd"" at Kudu.Core.Infrastructure.IdleManager.WaitForExit(IProcess process) in C:\Kudu Files\Private\src\master\Kudu.Core\Infrastructure\IdleManager.cs:line 96 at Kudu.Core.Infrastructure.ProcessExtensions.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.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Kudu.Core.Infrastructure.Executable.d__31.MoveNext() in C:\Kudu Files\Private\src\master\Kudu.Core\Infrastructure\Executable.cs:line 255<---
