title: Azure DevOps Server 2019.1 Problem with "WorkItem User Delivery" Job hanging
body: <p>I manage two on-premesis Azure DevOps Servers both running version 2019.Update1.1 (17.153.29522.3).</p>
  <p>One of these two servers stops sending &quot;Work Item&quot; notifications on a regular basis.   When this issue occurs, the notifications do actually exist, and are held by the server until a reboot of the application tier is done.   After the reboot of that machine, hundreds of backlogged work item notifications are sent out at once in a large &quot;flurry&quot; (all at once).</p>
  <p>I have monitored the issue over the course of 8 weeks.   During that time, the issue has occurred 6 times.   All 6 times it has started on a Thursday evening.  I do not know what initiates the issue.   However, if it happens, it always happens on a Thursday evening.   (Just not every Thursday evening.)</p>
  <p>The issue occurred last night 7/23/2020.</p>
  <p>On the OI Job Monitoring page this morning, after the reboot I see that the &quot;WorkItem User Delivery&quot; Job failed with a result of &quot;Inactive&quot; and a run time of 14 hours and 9 minutes.</p>
  <pre><code>History Id  Priority    Result      Host Name                           Job Name                Queue Time          Time in Queue   Run Time
  9227035     10          Inactive    [TEAM FOUNDATION]DefaultCollection  WorkItem User Delivery  7/23/2020 2:30 PM   0:00:00.28      14:09:26.557
  </code></pre>
  <p>Details are:</p>
  <pre><code>Job History Details
  
  [9227035] [TEAM FOUNDATION]DefaultCollection:WorkItem User Delivery
  Result: Inactive
  Priority:   10
  Queued Reasons: Queued
  Host:   [TEAM FOUNDATION]DefaultCollection
  Job Name:   WorkItem User Delivery
  Agent:  Process does not exist anymore
  Queue Time: Thursday, July 23, 2020 2:30 PM
  Queue Duration: 0:00:00.28
  Start Time: Thursday, July 23, 2020 2:30 PM
  Run Duration:   14:09:26.557
  End Time:   Friday, July 24, 2020 4:39 AM
  Result Message: 
  Host Id:    33d3f91e-acc9-41b9-8744-fc2ed904235a
  Job Id: 631f49b3-46e1-42ec-8fff-081bd176c18a
  Agent Id:   3d718e2d-8c24-4297-9088-9e58c2ed9a6e
  </code></pre>
  <p>I would like to ask for help in diagnosing this issue as well as any recommendations on how to resolve it.</p>
  <p>Note: I am reviewing the old case of a similar issue mentioned here: <a href="https://stackoverflow.com/questions/48157133/tfs-2017-update-2-workitem-user-delivery-job-stuck-no-email-soap-notificat">Tfs 2017 Update 2 - &quot;WorkItem user delivery&quot; job stuck - no email/soap notifications</a></p>
  <p>I'd also like to ask if any of the advice in that case is still relevant to Azure DevOps Server 2019.Update1.1.   His resolution message does not seem to apply, however.</p>
  <pre><code>EDIT as of 7/31/2020 Follows....
  </code></pre>
  <p>True to the pattern, the WorkItem User Delivery job hung again on Thursday 7/30/2020 at 4:27:32 Pacific Time.</p>
  <p>This time I was monitoring the TfsJobAgent.exe via procmon for the previous several hours, filtering on &quot;:587&quot;.</p>
  <p><a href="https://i.stack.imgur.com/w9EqP.png" rel="nofollow noreferrer"><img src="https://i.stack.imgur.com/w9EqP.png" alt="enter image description here" /></a></p>
  <p>After the interation at 4:27, there was no further attempt from that process to initate traffic to the email server.</p>
  <p>The job failure message that was generated at that time:</p>
  <blockquote>
  <p>E-Mail job summary: 1 errors, 0 warnings.The detailed log for this job
  is available here:
  https://.com/DefaultCollection/_apis/notification/DiagnosticLogs/a96d6177-beef-477a-a2ee-2c31433214d0/entries/52195e2c-6e55-4db6-aea7-e9d16279da80Previous
  job run succeeded.Current job run succeeded - consecutive successes:
  3843Properties and stats:timings:NotificationSql=6 PreDelivery=0
  Filter=0 Identity=0 NotificationDeliveryTimeAverage=30014
  NotificationDeliveryTimeAttempts=1 Summary: read=1 attempted=1
  succeeded=0 failed=1 failedAlertable=0 failedNonAlertable=0
  failedRetryable=1 recipientCount=1 failedWithFailed=1
  DeploymentCompletedEvent: read=1 attempted=1 succeeded=0 failed=1
  failedAlertable=0 failedNonAlertable=0 failedRetryable=1
  recipientCount=1 Smtp:UnassignedBatch 1 First 423866 Started
  08:11:38.4594602 Finished 08:12:08.6917156:Notification 423866 for
  DeploymentCompletedEvent result Failed!TF271000: An error occurred
  while attempting to send an email notification to the following
  address: redacted.user@co.com. Verify that the email notification
  settings are correct in the Team Foundation Administration
  Console.SmtpException:Failure sending
  mail.@ExceptionDispatchInfo.Throw:0@TaskAwaiter.HandleNonSuccessAndDebuggerNotification:0@d__2.MoveNext:0@ExceptionDispatchInfo.Throw:0@TaskAwaiter.HandleNonSuccessAndDebuggerNotification:0@d__6.MoveNext:0+Inner:WebException:The
  operation has timed out.08:12:08.6917156:ID:423866 -
  NextProcessTime=7/31/2020 9:12:08 AM Prior
  Attempts=1008:12:08.9573417:Previous job run
  succeeded.08:12:08.9573417:Current job run succeeded - consecutive
  successes: 3843</p>
  </blockquote>
  <p>The Diagnostic Log at the URL above returned:</p>
  <p>Internal log text:</p>
  <blockquote>
  <p>{&quot;count&quot;:1,&quot;value&quot;:[{&quot;batches&quot;:[{&quot;startTime&quot;:&quot;08:11:38.4594602&quot;,&quot;endTime&quot;:&quot;08:12:08.6917156&quot;,&quot;notificationIds&quot;:&quot;423866&quot;,&quot;notificationCount&quot;:1,&quot;problematicNotifications&quot;:[{&quot;id&quot;:423866,&quot;result&quot;:&quot;Failed&quot;,&quot;eventId&quot;:1293755,&quot;eventType&quot;:&quot;DeploymentCompletedEvent&quot;,&quot;subscriptionId&quot;:&quot;477&quot;,&quot;stats&quot;:{},&quot;recipients&quot;:{&quot;7833f10d-690f-45f4-8ed8-40e012a86868&quot;:{&quot;recipient&quot;:{&quot;id&quot;:&quot;7833f10d-690f-45f4-8ed8-40e012a86868&quot;,&quot;displayName&quot;:&quot;&quot;},&quot;status&quot;:null}},&quot;messages&quot;:[{&quot;level&quot;:1,&quot;time&quot;:&quot;08:12:08.6917156&quot;,&quot;message&quot;:&quot;TF271000:
  An error occurred while attempting to send an email notification to
  the following address: redacted.co.com. Verify that the email
  notification settings are correct in the Team Foundation
  Administration Console.\r\nSmtpException:Failure sending
  mail.\r\n@ExceptionDispatchInfo.Throw:0\r\n@TaskAwaiter.HandleNonSuccessAndDebuggerNotification:0\r\n@d__2.MoveNext:0\r\n@ExceptionDispatchInfo.Throw:0\r\n@TaskAwaiter.HandleNonSuccessAndDebuggerNotification:0\r\n@d__6.MoveNext:0\r\n+Inner:\r\nWebException:The
  operation has timed
  out.\r\n\r\n&quot;}]}]}],&quot;result&quot;:&quot;PartiallySucceeded&quot;,&quot;stats&quot;:{&quot;timings&quot;:{&quot;NotificationSql&quot;:6,&quot;PreDelivery&quot;:0,&quot;Filter&quot;:0,&quot;Identity&quot;:0,&quot;NotificationDeliveryTimeAverage&quot;:30014,&quot;NotificationDeliveryTimeAttempts&quot;:1},&quot;All&quot;:{&quot;read&quot;:1,&quot;attempted&quot;:1,&quot;succeeded&quot;:0,&quot;failed&quot;:1,&quot;failedAlertable&quot;:0,&quot;failedNonAlertable&quot;:0,&quot;failedRetryable&quot;:1,&quot;recipientCount&quot;:1,&quot;Failed&quot;:1},&quot;DeploymentCompletedEvent&quot;:{&quot;read&quot;:1,&quot;attempted&quot;:1,&quot;succeeded&quot;:0,&quot;failed&quot;:1,&quot;failedAlertable&quot;:0,&quot;failedNonAlertable&quot;:0,&quot;failedRetryable&quot;:1,&quot;recipientCount&quot;:1,&quot;Failed&quot;:1},&quot;EmailCounters&quot;:{&quot;emailProcessed&quot;:1,&quot;emailStarted&quot;:1,&quot;emailFailed&quot;:1,&quot;emailAttemptedMessages&quot;:1,&quot;emailAttemptedRecipients&quot;:1},&quot;EmailTimings&quot;:{&quot;AllSendMailAverage&quot;:30002,&quot;AllSendMailAttempts&quot;:1,&quot;SucceededSendMailAverage&quot;:0,&quot;SucceededSendMailAttempts&quot;:0,&quot;FailedSendMailAverage&quot;:30002,&quot;FailedSendMailAttempts&quot;:1,&quot;Subscriber&quot;:0,&quot;TemplateFetch&quot;:0,&quot;Transform&quot;:12}},&quot;logType&quot;:&quot;NotificationDelivery&quot;,&quot;source&quot;:&quot;a96d6177-beef-477a-a2ee-2c31433214d0&quot;,&quot;id&quot;:&quot;52195e2c-6e55-4db6-aea7-e9d16279da80&quot;,&quot;startTime&quot;:&quot;2020-07-31T08:11:38.4594602Z&quot;,&quot;endTime&quot;:&quot;2020-07-31T08:12:09.0511168Z&quot;,&quot;description&quot;:&quot;Notifications
  E-Mail
  Delivery&quot;,&quot;warnings&quot;:0,&quot;errors&quot;:1,&quot;activityId&quot;:&quot;6bddc09f-e357-413c-9e3f-66092a38968d&quot;,&quot;properties&quot;:{&quot;JobTimeSlice&quot;:&quot;300000&quot;,&quot;JobTimeoutMultiple&quot;:&quot;12&quot;,&quot;JobRestartDelay&quot;:&quot;30&quot;,&quot;ProcessingJobDelaySeconds&quot;:&quot;300&quot;,&quot;MaxConcurrentInstances&quot;:&quot;5&quot;,&quot;InstancesExceededRescheduleDelaySeconds&quot;:&quot;30000&quot;,&quot;RerunNotificationJobDelaySecs&quot;:&quot;30000&quot;,&quot;ContributionFallbackModeRescheduleDelaySeconds&quot;:&quot;60000&quot;,&quot;OrganizationAadTenantId&quot;:&quot;00000000-0000-0000-0000-000000000000&quot;,&quot;EventingEnabled&quot;:&quot;True&quot;,&quot;FailedRetryInterval&quot;:&quot;300&quot;,&quot;NotificationBatchSize&quot;:&quot;100&quot;,&quot;NotificationStatFlushFrequency&quot;:&quot;5&quot;,&quot;CoreDeliveryStartDelay&quot;:&quot;10&quot;,&quot;EmailEnabled&quot;:&quot;True&quot;,&quot;MaxMailSenders&quot;:&quot;8&quot;,&quot;MaxMailRecipients&quot;:&quot;90&quot;,&quot;AsciiOnlyEmailAddresses&quot;:&quot;False&quot;,&quot;Feature:
  NotificationJob.DisablePlainTextEmail&quot;:&quot;True&quot;,&quot;SmtpServer&quot;:&quot;smtp.office365.com&quot;,&quot;SmtpPort&quot;:&quot;587&quot;,&quot;HasSmtpUser&quot;:&quot;true&quot;,&quot;HasSmtpPassword&quot;:&quot;true&quot;,&quot;HostName&quot;:&quot;DefaultCollection&quot;,&quot;SendingDomain&quot;:&quot;redacted.co.com&quot;,&quot;NextProcessTime&quot;:&quot;7/31/2020
  8:15:38
  AM&quot;},&quot;messages&quot;:[{&quot;level&quot;:3,&quot;time&quot;:&quot;08:12:08.6917156&quot;,&quot;message&quot;:&quot;ID:423866</p>
  <ul>
  <li>NextProcessTime=7/31/2020 9:12:08 AM Prior Attempts=10&quot;},{&quot;level&quot;:3,&quot;time&quot;:&quot;08:12:08.9573417&quot;,&quot;message&quot;:&quot;Previous
  job run
  succeeded.&quot;},{&quot;level&quot;:3,&quot;time&quot;:&quot;08:12:08.9573417&quot;,&quot;message&quot;:&quot;Current
  job run succeeded - consecutive successes: 3843&quot;}]}]}</li>
  </ul>
  </blockquote>
  <p>The server remained this way for 10 hours during the investigation.   During this time, the email server could be pinged.   The admin console could successfully send email alert test messages.</p>
  <p>After the 10 hour period, only the TFSJobAgent service was restarted.   Once that was restarted a flurry of email messages were successfully sent.   Procmon was able to record the traffic that occurred after the TfsJobAgent restart.</p>
  <pre><code>Some tentative conclusions so far:
  1. The issue cannot be a App Tier machine issue nor an email server issue:
     a) Tfs Administration Console can send messages during a &quot;hang&quot;.
     b) Only a restart of the TfsJobAgent is required to reset the &quot;hang&quot;.
  2. The TfsJobAgent process does not even try to contact the email server during the &quot;hang&quot;.
     a) Outside of the &quot;hang&quot; window, Procmon can record its attempts.
     b) During the &quot;hang&quot; window, Procmon sees no attempt to contact the email server.
  3. The TfsJobAgent code believes it has made the attempt but never actually made it.
     a) It records results to contact as &quot;operation timed out&quot; which procmon never saw.
  </code></pre>
  <p>Tentative hypothesis: Either there is a bug in the TfsJobAgent....or something that it processed....which compromised that processes ability to send/receive network traffic (at most) or traffic to the email server (at least).</p>