We’re running NSB endpoints on Azure web jobs and we have had issues with endpoint occasionally stopping to process messages from Azure Service Bus queue. Seems like the endpoint or web job freezes and the messages just stays in ASB queue.
Only when the Azure web job is restarted the endpoint starts to process messages again. Basicly the endpoint is configured in similar way than in this Particular’s show case: Azure Cloud Showcase • NServiceBus Samples • Particular Docs.
Hi Kimmo,
To help, would need a bit more of information.
Do you have any information in your log files?
I tried to upload full web job’s log file as a ZIP here, but seems like new users aren’t allowed to do this, so here’s one part of the log. This might not be related to the problem, but I have not found any else errors from the web job log.
[02/09/2018 01:41:20 > d6fac0: INFO] X.Y.Z.MyEndpoint1 host started.
[02/09/2018 02:40:40 > d6fac0: SYS INFO] WebJob is still running
[02/09/2018 03:23:19 > d6fac0: SYS INFO] WebJob is stopping due to website shutting down
[02/09/2018 03:23:19 > d6fac0: SYS INFO] Status changed to Stopping
[02/09/2018 03:23:20 > d6fac0: ERR ]
[02/09/2018 03:23:20 > d6fac0: ERR ] Unhandled Exception: System.Threading.Tasks.TaskCanceledException: A task was canceled.
[02/09/2018 03:23:20 > d6fac0: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
[02/09/2018 03:23:20 > d6fac0: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
[02/09/2018 03:23:20 > d6fac0: ERR ] at Microsoft.Azure.WebJobs.Host.Protocols.PersistentQueueWriter`1.d__0.MoveNext()
[02/09/2018 03:23:20 > d6fac0: ERR ] — End of stack trace from previous location where exception was thrown —
[02/09/2018 03:23:20 > d6fac0: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
[02/09/2018 03:23:20 > d6fac0: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
[02/09/2018 03:23:20 > d6fac0: ERR ] at Microsoft.Azure.WebJobs.Host.Loggers.CompositeFunctionInstanceLogger.d__8.MoveNext()
[02/09/2018 03:23:20 > d6fac0: ERR ] — End of stack trace from previous location where exception was thrown —
[02/09/2018 03:23:20 > d6fac0: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
[02/09/2018 03:23:20 > d6fac0: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
[02/09/2018 03:23:20 > d6fac0: ERR ] at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.d__1.MoveNext()
[02/09/2018 03:23:20 > d6fac0: ERR ] — End of stack trace from previous location where exception was thrown —
[02/09/2018 03:23:20 > d6fac0: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
[02/09/2018 03:23:20 > d6fac0: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
[02/09/2018 03:23:20 > d6fac0: ERR ] at Microsoft.Azure.WebJobs.Host.Executors.HeartbeatFunctionExecutor.d__0.MoveNext()
[02/09/2018 03:23:20 > d6fac0: ERR ] — End of stack trace from previous location where exception was thrown —
[02/09/2018 03:23:20 > d6fac0: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
[02/09/2018 03:23:20 > d6fac0: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
[02/09/2018 03:23:20 > d6fac0: ERR ] at Microsoft.Azure.WebJobs.Host.Executors.AbortListenerFunctionExecutor.d__0.MoveNext()
[02/09/2018 03:23:20 > d6fac0: ERR ] — End of stack trace from previous location where exception was thrown —
[02/09/2018 03:23:20 > d6fac0: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
[02/09/2018 03:23:20 > d6fac0: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
[02/09/2018 03:23:20 > d6fac0: ERR ] at Microsoft.Azure.WebJobs.Host.Executors.ShutdownFunctionExecutor.d__0.MoveNext()
[02/09/2018 03:23:20 > d6fac0: ERR ] — End of stack trace from previous location where exception was thrown —
[02/09/2018 03:23:20 > d6fac0: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
[02/09/2018 03:23:20 > d6fac0: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
[02/09/2018 03:23:20 > d6fac0: ERR ] at Microsoft.Azure.WebJobs.JobHost.d__7.MoveNext()
[02/09/2018 03:23:20 > d6fac0: ERR ] — End of stack trace from previous location where exception was thrown —
[02/09/2018 03:23:20 > d6fac0: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
[02/09/2018 03:23:20 > d6fac0: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
[02/09/2018 03:23:20 > d6fac0: ERR ] at Microsoft.Azure.WebJobs.JobHost.Call(MethodInfo method)
[02/09/2018 03:23:20 > d6fac0: ERR ] at X.Y.Z.MyEndpoint1.Program.Main() in C:\agent_work\1\s\X.Y.Z.MyEndpoint1\Program.cs:line 33
[02/09/2018 03:23:21 > d6fac0: SYS ERR ] Job failed due to exit code -532462766
[02/09/2018 03:23:21 > d6fac0: SYS INFO] Status changed to Stopped
[02/09/2018 03:23:49 > 14ce59: SYS INFO] Status changed to Starting
[02/09/2018 03:23:49 > 14ce59: SYS INFO] WebJob singleton setting is False
[02/09/2018 03:23:59 > 14ce59: SYS INFO] Run script ‘X.Y.Z.MyEndpoint1.exe’ with script host - ‘WindowsScriptHost’
[02/09/2018 03:23:59 > 14ce59: SYS INFO] Status changed to Running
[02/09/2018 03:24:39 > 14ce59: INFO] Starting X.Y.Z.MyEndpoint1 host…
[02/09/2018 03:24:39 > 14ce59: INFO] Found the following functions:
[02/09/2018 03:24:39 > 14ce59: INFO] X.Y.Z.MyEndpoint1.Program.AsyncMain
[02/09/2018 03:24:39 > 14ce59: INFO] Executing: ‘Program.AsyncMain’ - Reason: ‘This function was programmatically called via the host APIs.’
[02/09/2018 03:24:39 > 14ce59: INFO] 2018-02-09 05:24:24.515 INFO DefaultFactory Logging to ‘D:\local\Temp\jobs\continuous\X-Y-Z-MyEndpoint1\fy10srx5.qff’ with level Info
[02/09/2018 03:24:39 > 14ce59: INFO] 2018-02-09 05:24:33.843 INFO NServiceBus.LicenseManager Selected active license from D:\local\Temp\jobs\continuous\X-Y-Z-MyEndpoint1\fy10srx5.qff\NServiceBus\License.xml
[02/09/2018 03:24:39 > 14ce59: INFO]
[02/09/2018 03:24:39 > 14ce59: INFO] 2018-02-09 05:24:33.999 INFO NServiceBus.PerformanceMonitorUsersInstaller Did not attempt to add user ‘IIS APPPOOL\MyDemoSite__357c’ to group ‘Performance Monitor Users’ since the process is not running with elevated privileges. Processing will continue. To manually perform this action, run the following command from an admin console:
[02/09/2018 03:24:39 > 14ce59: INFO] net localgroup “Performance Monitor Users” “IIS APPPOOL\MyDemoSite__357c” /add
Also the next web job issue seems somewhat similar, so at this stage I’m not sure is the problem related to Azure web job or NServiceBus configuration or both of those working together. Continuous Web Job frozen and preventing further QueueTriggers · Issue #590 · Azure/azure-webjobs-sdk · GitHub
Could you please post NServiceBus log?
Azure ServiceBus transport is not using webjobs trigger, but has its own receiving mechansim. If it’s the one that is failing, NServiceBus logs will contain the information that might help.
Here’s content of one NSB log file:
2018-02-08 16:05:51.912 INFO NServiceBus.Unicast.UnicastBus Initiating shutdown.
2018-02-08 16:05:52.849 INFO NServiceBus.ForwardingTopology Closing messaging factories
2018-02-08 16:05:59.630 INFO NServiceBus.Unicast.UnicastBus Shutdown complete.
2018-02-08 16:06:02.271 INFO DefaultFactory Logging to ‘D:\home\site\wwwroot\App_Data’ with level Info
2018-02-08 16:06:03.583 INFO DefaultFactory Logging to ‘D:\home\site\wwwroot\App_Data’ with level Info
2018-02-08 16:06:16.114 FATAL NServiceBus.Features.LicenseReminder Failed to initialize the license
System.IO.IOException: The specified registry key does not exist.
at Microsoft.Win32.RegistryKey.Win32Error(Int32 errorCode, String str)
at Microsoft.Win32.RegistryKey.CreateSubKeyInternal(String subkey, RegistryKeyPermissionCheck permissionCheck, Object registrySecurityObj, RegistryOptions registryOptions)
at Microsoft.Win32.RegistryKey.CreateSubKey(String subkey, RegistryKeyPermissionCheck permissionCheck)
at Microsoft.Win32.RegistryKey.CreateSubKey(String subkey)
at Particular.Licensing.TrialStartDateStore.GetTrialStartDate()
at Particular.Licensing.ActiveLicense.Find(String applicationName, LicenseSource[] licenseSources)
at NServiceBus.LicenseManager.InitializeLicense(String licenseText, String licenseFilePath)
at NServiceBus.Features.LicenseReminder.Setup(FeatureConfigurationContext context)
2018-02-08 16:06:16.333 INFO NServiceBus.PerformanceMonitorUsersInstaller Did not attempt to add user ‘IIS APPPOOL\MyDemoSite__357c’ to group ‘Performance Monitor Users’ since the process is not running with elevated privileges. Processing will continue. To manually perform this action, run the following command from an admin console:
net localgroup “Performance Monitor Users” “IIS APPPOOL\MyDemoSite__357c” /add
2018-02-08 16:06:16.536 INFO NServiceBus.PerformanceCounterHelper NServiceBus performance counter for ‘# of msgs pulled from the input queue /sec’ is not set up correctly. To rectify this problem, consult the NServiceBus performance counters documentation.
2018-02-08 16:06:16.536 INFO NServiceBus.PerformanceCounterHelper NServiceBus performance counter for ‘# of msgs successfully processed / sec’ is not set up correctly. To rectify this problem, consult the NServiceBus performance counters documentation.
2018-02-08 16:06:16.552 INFO NServiceBus.PerformanceCounterHelper NServiceBus performance counter for ‘# of msgs failures / sec’ is not set up correctly. To rectify this problem, consult the NServiceBus performance counters documentation.
2018-02-08 16:06:16.896 FATAL NServiceBus.Features.LicenseReminder Failed to initialize the license
System.IO.IOException: The specified registry key does not exist.
at Microsoft.Win32.RegistryKey.Win32Error(Int32 errorCode, String str)
at Microsoft.Win32.RegistryKey.CreateSubKeyInternal(String subkey, RegistryKeyPermissionCheck permissionCheck, Object registrySecurityObj, RegistryOptions registryOptions)
at Microsoft.Win32.RegistryKey.CreateSubKey(String subkey, RegistryKeyPermissionCheck permissionCheck)
at Microsoft.Win32.RegistryKey.CreateSubKey(String subkey)
at Particular.Licensing.TrialStartDateStore.GetTrialStartDate()
at Particular.Licensing.ActiveLicense.Find(String applicationName, LicenseSource[] licenseSources)
at NServiceBus.LicenseManager.InitializeLicense(String licenseText, String licenseFilePath)
at NServiceBus.Features.LicenseReminder.Setup(FeatureConfigurationContext context)
2018-02-08 16:06:17.036 INFO NServiceBus.PerformanceMonitorUsersInstaller Did not attempt to add user ‘IIS APPPOOL\MyDemoSite__357c’ to group ‘Performance Monitor Users’ since the process is not running with elevated privileges. Processing will continue. To manually perform this action, run the following command from an admin console:
net localgroup “Performance Monitor Users” “IIS APPPOOL\MyDemoSite__357c” /add
2018-02-08 16:06:17.239 INFO NServiceBus.PerformanceCounterHelper NServiceBus performance counter for ‘# of msgs pulled from the input queue /sec’ is not set up correctly. To rectify this problem, consult the NServiceBus performance counters documentation.
2018-02-08 16:06:17.239 INFO NServiceBus.PerformanceCounterHelper NServiceBus performance counter for ‘# of msgs successfully processed / sec’ is not set up correctly. To rectify this problem, consult the NServiceBus performance counters documentation.
2018-02-08 16:06:17.255 INFO NServiceBus.PerformanceCounterHelper NServiceBus performance counter for ‘# of msgs failures / sec’ is not set up correctly. To rectify this problem, consult the NServiceBus performance counters documentation.
2018-02-08 16:06:39.161 INFO NServiceBus.Unicast.UnicastBus Initiating shutdown.
2018-02-08 16:06:39.208 INFO NServiceBus.ForwardingTopology Closing messaging factories
2018-02-08 16:06:39.318 INFO NServiceBus.Unicast.UnicastBus Shutdown complete.
2018-02-08 16:29:48.589 INFO DefaultFactory Logging to ‘D:\home\site\wwwroot\App_Data’ with level Info
2018-02-08 16:30:06.450 FATAL NServiceBus.Features.LicenseReminder Failed to initialize the license
System.IO.IOException: The specified registry key does not exist.
at Microsoft.Win32.RegistryKey.Win32Error(Int32 errorCode, String str)
at Microsoft.Win32.RegistryKey.CreateSubKeyInternal(String subkey, RegistryKeyPermissionCheck permissionCheck, Object registrySecurityObj, RegistryOptions registryOptions)
at Microsoft.Win32.RegistryKey.CreateSubKey(String subkey, RegistryKeyPermissionCheck permissionCheck)
at Microsoft.Win32.RegistryKey.CreateSubKey(String subkey)
at Particular.Licensing.TrialStartDateStore.GetTrialStartDate()
at Particular.Licensing.ActiveLicense.Find(String applicationName, LicenseSource[] licenseSources)
at NServiceBus.LicenseManager.InitializeLicense(String licenseText, String licenseFilePath)
at NServiceBus.Features.LicenseReminder.Setup(FeatureConfigurationContext context)
2018-02-08 16:30:06.732 INFO NServiceBus.PerformanceMonitorUsersInstaller Did not attempt to add user ‘IIS APPPOOL\MyDemoSite__357c’ to group ‘Performance Monitor Users’ since the process is not running with elevated privileges. Processing will continue. To manually perform this action, run the following command from an admin console:
net localgroup “Performance Monitor Users” “IIS APPPOOL\MyDemoSite__357c” /add
2018-02-08 16:30:07.013 INFO NServiceBus.PerformanceCounterHelper NServiceBus performance counter for ‘# of msgs pulled from the input queue /sec’ is not set up correctly. To rectify this problem, consult the NServiceBus performance counters documentation.
2018-02-08 16:30:07.013 INFO NServiceBus.PerformanceCounterHelper NServiceBus performance counter for ‘# of msgs successfully processed / sec’ is not set up correctly. To rectify this problem, consult the NServiceBus performance counters documentation.
2018-02-08 16:30:07.028 INFO NServiceBus.PerformanceCounterHelper NServiceBus performance counter for ‘# of msgs failures / sec’ is not set up correctly. To rectify this problem, consult the NServiceBus performance counters documentation.
2018-02-08 16:30:24.895 INFO NServiceBus.Unicast.UnicastBus Initiating shutdown.
2018-02-08 16:30:25.145 INFO NServiceBus.ForwardingTopology Closing messaging factories
2018-02-08 16:30:25.332 INFO NServiceBus.Unicast.UnicastBus Shutdown complete.
Thank you Kimmo.
This one unfortunately doesn’t reveal the issue. It starts with NServiceBus logging that shutdown is initialized, but not the reason for the shutdown that took place earlier. Could you share those logs?
Hi Kimmo,
Have you had a chance to look at the log files to see what error is causing endpoint to shutdown?
Hi Sean,
Could I email the full log straight to you? I got the same situation now on one of the environments. This problem is hard to track because it’s so infrequent.
Hi there,
Could you share here what was the root cause of this issue? We are currently experiencing the same problem, where our WebJob stops processing messages and we need to restart it in order to get it working again.
There is something common between @kpuranen logs and ours, particularly the message ‘Closing messaging factories’. Here is a snippet of our logs
[06/25/2019 05:30:18 > b1c301: INFO] 2019-06-25 05:30:17.714 INFO NServiceBus.ForwardingTopology Closing messaging factories
[06/25/2019 05:30:18 > ae2af4: INFO] 2019-06-25 05:30:18.425 INFO NServiceBus.ForwardingTopology Closing messaging factories
[06/25/2019 09:02:14 > ae2af4: SYS INFO] WebJob is still running
[06/25/2019 09:03:03 > b1c301: SYS INFO] WebJob is still running
[06/25/2019 10:01:35 > b1c301: SYS INFO] WebJob is stopping due to website shutting down
[06/25/2019 10:01:35 > b1c301: SYS INFO] Status changed to Stopping
[06/25/2019 10:01:36 > b1c301: INFO] Job host stopped
[06/25/2019 10:01:39 > b1c301: SYS INFO] Status changed to Success
[06/25/2019 10:01:39 > b1c301: SYS INFO] Status changed to Stopped
[06/25/2019 20:02:53 > 9ed36b: SYS INFO] Status changed to Starting
[06/25/2019 20:02:54 > 9ed36b: SYS INFO] WebJob singleton setting is False
[06/25/2019 20:03:16 > 9ed36b: SYS INFO] Run script 'Rockend.InvoiceGenius.InvoiceGateway.WebJobHost.exe' with script host - 'WindowsScriptHost'
[06/25/2019 20:03:16 > 9ed36b: SYS INFO] Status changed to Running
[06/25/2019 20:03:36 > 9ed36b: INFO] 2019-06-25 20:03:36.509 INFO DefaultFactory Logging to 'D:\local\Temp\jobs\continuous\InvoiceGenius-InvoiceGateway-WebJobHost\vbtm1qsa.wv2\' with level Info
[06/25/2019 20:04:08 > 9ed36b: INFO] No job functions found. Try making your job classes and methods public. If you're using binding extensions (e.g. ServiceBus, Timers, etc.) make sure you've called the registration method for the extension(s) in your startup code (e.g. config.UseServiceBus(), config.UseTimers(), etc.).
[06/25/2019 20:04:09 > 9ed36b: INFO] Job host started
[06/25/2019 20:07:18 > 9ed36b: INFO] 2019-06-25 20:07:18.507 INFO NServiceBus.ForwardingTopology Closing messaging factories
[06/25/2019 21:02:14 > ae2af4: SYS INFO] WebJob is still running
[06/25/2019 21:02:55 > 9ed36b: SYS INFO] WebJob is still running
[06/26/2019 09:02:15 > ae2af4: SYS INFO] WebJob is still running
[06/26/2019 09:02:55 > 9ed36b: SYS INFO] WebJob is still running
[06/26/2019 10:01:25 > 9ed36b: SYS INFO] WebJob is stopping due to website shutting down
[06/26/2019 10:01:25 > 9ed36b: SYS INFO] Status changed to Stopping
[06/26/2019 10:01:30 > 9ed36b: INFO] Job host stopped
[06/26/2019 10:01:30 > 9ed36b: ERR ] Thread was being aborted.
[06/26/2019 10:01:30 > 9ed36b: SYS INFO] WebJob process was aborted
[06/26/2019 10:01:30 > 9ed36b: SYS INFO] Status changed to Stopped
[06/26/2019 20:02:31 > bc3b59: SYS INFO] Status changed to Starting
[06/26/2019 20:02:31 > bc3b59: SYS INFO] WebJob singleton setting is False
[06/26/2019 20:02:51 > bc3b59: SYS INFO] Run script 'Rockend.InvoiceGenius.InvoiceGateway.WebJobHost.exe' with script host - 'WindowsScriptHost'
[06/26/2019 20:02:51 > bc3b59: SYS INFO] Status changed to Running
[06/26/2019 20:03:10 > bc3b59: INFO] 2019-06-26 20:03:10.196 INFO DefaultFactory Logging to 'D:\local\Temp\jobs\continuous\InvoiceGenius-InvoiceGateway-WebJobHost\isd0gort.l4s\' with level Info
[06/26/2019 20:03:38 > bc3b59: INFO] No job functions found. Try making your job classes and methods public. If you're using binding extensions (e.g. ServiceBus, Timers, etc.) make sure you've called the registration method for the extension(s) in your startup code (e.g. config.UseServiceBus(), config.UseTimers(), etc.).
[06/26/2019 20:03:39 > bc3b59: INFO] Job host started
[06/26/2019 20:19:13 > bc3b59: INFO] 2019-06-26 20:19:12.811 INFO NServiceBus.ForwardingTopology Closing messaging factories
[06/26/2019 21:02:15 > ae2af4: SYS INFO] WebJob is still running
[06/26/2019 21:02:31 > bc3b59: SYS INFO] WebJob is still running
[06/26/2019 23:36:21 > bc3b59: SYS INFO] Status changed to Disabling
[06/26/2019 23:36:27 > bc3b59: SYS INFO] Detected WebJob file/s were updated, refreshing WebJob
[06/26/2019 23:36:27 > bc3b59: SYS INFO] Status changed to Stopping
[06/26/2019 23:36:27 > ae2af4: SYS INFO] Detected WebJob file/s were updated, refreshing WebJob
[06/26/2019 23:36:27 > ae2af4: SYS INFO] Status changed to Stopping
[06/26/2019 23:36:28 > ae2af4: INFO] Job host stopped
[06/26/2019 23:36:29 > bc3b59: INFO] Job host stopped
[06/26/2019 23:36:32 > ae2af4: ERR ] Thread was being aborted.
[06/26/2019 23:36:32 > ae2af4: SYS INFO] WebJob process was aborted
[06/26/2019 23:36:32 > ae2af4: SYS INFO] Status changed to Stopped
[06/26/2019 23:36:32 > bc3b59: ERR ] Thread was being aborted.
[06/26/2019 23:36:32 > bc3b59: SYS INFO] WebJob process was aborted
[06/26/2019 23:36:32 > bc3b59: SYS INFO] Status changed to Stopped
[06/26/2019 23:37:35 > bc3b59: SYS INFO] Detected WebJob file/s were updated, refreshing WebJob
[06/26/2019 23:37:35 > bc3b59: SYS INFO] Status changed to Starting
[06/26/2019 23:37:35 > ae2af4: SYS INFO] Detected WebJob file/s were updated, refreshing WebJob
[06/26/2019 23:37:35 > ae2af4: SYS INFO] Status changed to Starting
[06/26/2019 23:37:35 > ae2af4: SYS INFO] Run script 'Rockend.InvoiceGenius.InvoiceGateway.WebJobHost.exe' with script host - 'WindowsScriptHost'
[06/26/2019 23:37:35 > ae2af4: SYS INFO] Status changed to Running
[06/26/2019 23:37:35 > bc3b59: SYS INFO] Run script 'Rockend.InvoiceGenius.InvoiceGateway.WebJobHost.exe' with script host - 'WindowsScriptHost'
[06/26/2019 23:37:35 > bc3b59: SYS INFO] Status changed to Running
[06/26/2019 23:37:54 > bc3b59: INFO] 2019-06-26 23:37:54.134 INFO DefaultFactory Logging to 'D:\local\Temp\jobs\continuous\InvoiceGenius-InvoiceGateway-WebJobHost\isd0gort.l4s\' with level Info
[06/26/2019 23:38:01 > ae2af4: INFO] 2019-06-26 23:38:01.921 INFO DefaultFactory Logging to 'D:\local\Temp\jobs\continuous\InvoiceGenius-InvoiceGateway-WebJobHost\jr2jdv2c.5pl\' with level Info
[06/26/2019 23:38:20 > ae2af4: INFO] No job functions found. Try making your job classes and methods public. If you're using binding extensions (e.g. ServiceBus, Timers, etc.) make sure you've called the registration method for the extension(s) in your startup code (e.g. config.UseServiceBus(), config.UseTimers(), etc.).
[06/26/2019 23:38:21 > ae2af4: INFO] Job host started
[06/26/2019 23:38:22 > bc3b59: INFO] No job functions found. Try making your job classes and methods public. If you're using binding extensions (e.g. ServiceBus, Timers, etc.) make sure you've called the registration method for the extension(s) in your startup code (e.g. config.UseServiceBus(), config.UseTimers(), etc.).
[06/26/2019 23:38:23 > bc3b59: INFO] Job host started
[06/27/2019 00:37:35 > bc3b59: SYS INFO] WebJob is still running
[06/27/2019 00:37:35 > ae2af4: SYS INFO] WebJob is still running
Thanks for your help and would appreciate if you could shed some light into this issue
We got this working after some try and fail attempts, but still I’m not sure what was the actual cause of the problem. I think it had something to do with code in Program.cs Main method. The web job started to work properly after we changed the code to be similar as in this sample:
On that project we’re using: NuGet Gallery | NServiceBus.Azure.Transports.WindowsAzureServiceBus 7.2.1
We have the same problem (the Closing messaging factories error) @luisdv described for the same code base but many years later.
The webjob is still running however it just won’t read any messages from the Azure service bus queue.
Here’re the logs:
[11/07/2022 22:27:08 > 3eb1d6: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
[11/07/2022 22:27:08 > 3eb1d6: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
[11/07/2022 22:27:08 > 3eb1d6: ERR ] at Microsoft.Azure.WebJobs.JobHost.Call(MethodInfo method)
[11/07/2022 22:27:08 > 3eb1d6: ERR ] at Rock.Invoice.InvGateway.WebJobHost.Program.Main()
[11/07/2022 22:27:08 > 3eb1d6: SYS ERR ] Job failed due to exit code -532462766
[11/07/2022 22:27:08 > 3eb1d6: SYS INFO] Status changed to Stopped
[11/07/2022 23:00:47 > 7b5dbd: SYS INFO] WebJob is still running
[11/07/2022 23:51:47 > b9948f: INFO] 2022-11-07 23:51:47.223 INFO NServiceBus.ForwardingTopology Closing messaging factories
[11/07/2022 23:51:47 > 7b5dbd: INFO] 2022-11-07 23:51:47.668 INFO NServiceBus.ForwardingTopology Closing messaging factories
[11/08/2022 07:13:26 > b9948f: SYS INFO] WebJob is stopping due to website shutting down
[11/08/2022 07:13:26 > b9948f: SYS INFO] Status changed to Stopping
[11/08/2022 07:13:26 > b9948f: ERR ]
[11/08/2022 07:13:26 > b9948f: ERR ] Unhandled Exception: System.Threading.Tasks.TaskCanceledException: A task was canceled.
[11/08/2022 07:13:26 > b9948f: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
[11/08/2022 07:13:26 > b9948f: ERR ] at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
[11/08/2022 07:13:26 > b9948f: ERR ] at Microsoft.Azure.WebJobs.Host.Protocols.PersistentQueueWriter`1.<EnqueueAsync>d__3.MoveNext()
[11/08/2022 07:13:26 > b9948f: ERR ] --- End of stack trace from previous location where exception was thrown ---