EXO Message Pending

Wir überwachen mit PRTG auch die Warteschlangen in Exchange Online auf Probleme und hier beschreibe ich eine unklare Situation mit Advanced Thread Protection.

Status von Messages

In der Regel wird eine Mail vorne in die Exchange Online Trnsport-Dienste per SMTP oder durch einen Client per MAPI/HTTP eingeliefert, dann geroutet und am Ende in ein Postfach oder extern zugestellt. Das dauert etwas Zeit und damit sind quasi immer einige Nachrichten "unterwegs" und beim Absender schon versendet aber beim Ziel noch nicht angekommen. Die Laufzeit einer Mail können Sie auch ermitteln aber mich interessiert eher die Mails, die noch nicht zugestellt sind. Microsoft stellt dazu einen Status bereit, den ich mit Get-MessageTrace filtern kann.

None          : The message has no delivery status because it was rejected or redirected to a different recipient.
GettingStatus : The message is waiting for status update.
Failed        : Message delivery was attempted and it failed or the message was filtered as spam or malware, or by transport rules.
Pending       : Message delivery is underway or was deferred and is being retried.
Delivered     : The message was delivered to its destination.
Expanded      : There was no message delivery because the message was addressed to a distribution group and the membership of the distribution was expanded.
Quarantined   : The message was quarantined.
FilteredAsSpam: The message was marked as spam.

Quelle: Get-MessageTrace - Status https://learn.microsoft.com/en-us/powershell/module/exchange/get-messagetrace?view=exchange-ps#-status 

Interessant finde ich hier alle Nachrichten, die noch "Pending sind und in gewissem Maße auch "Failed". Ob ich mir auch die Mails in der Quarantäne oder "FileredAsSpam" anschauen muss, müssen sie selbst entscheiden. Hier eine exemplarische Ausgabe:

Get-MessageTrace -status Pending

Das sieht unspektakulär aus aber mich hat diese Ansicht alarmiert, denn ich habe die Abfrage am 19. Nov 2024 gegen 16:00 (GMT+1) gestellt und die letzte Mail war um 14:54 GMT, also gerade mal 6 Minuten vorher. Ich hätte aber nicht erwartet, dass ich auch Mails vom frühen Vormittag finde. Die älteste Mail mit dem Status "Pending" hat den Zeitstempel 08:37:15 GMT, also ca. 09:37 lokale Zeit und damit mehr als 6 Stunden alt. Sollte die Mail wirklich noch nicht angekommen sein?

PRTG

Wenn Mails versenden aber noch nicht zugestellt ist, dann ist das eine Information, die ich überwachen möchte. Exchange Online bietet natürlich keine Performance Counter an und ich habe auch keine "Queues" pro Tenant, die ich abfragen kann. Ich kann aber über "Get-MessagetTrace" natürlich z.B. alle 15 Minuten einmal den Status abfragen und die Anzahl zählen.

$NumerofPendingMessages= (Get-MessageTrace -Status Pending).count

Diesen Aufruf kann ich manuell oder z.B. als PRTG - Custom Sensor oder in PowerShell mit PRTG - PS Custom Sensor umsetzen. Am besten nutzen sie dazu dann eine eigene App-Registration, wie ich es auf EXO PowerShell Automation beschrieben habe. Das PS1-Skeipt für den Sensor habe ich noch nicht beschrieben.

In PRTG sehen wir die Daten für "Failed" und "Pending" wie folgt.

Das folgende Bild zeigt die Details der letzten 24 Stunden, Es beginnt bei ca. 16:00 des Vortrags und geht bis zum 19 Nov 2024 16:00. Die Grenze zum gelben "Warnbereich" ist bei 10 Nachrichten.


Quelle: PRTG Net at Work 19. Nov 2024 16:00, 24h Ansicht

Ich interpretiere dieses Diagramm so, dass Die Abfrage in der Nacht ziemlich unkritisch ist aber tagsüber durchaus einige Mails im Status "Pending" stehen. Ob diese aber wirklich "Pending" sind oder nur die Abfrage veralteten Daten liefert, behandle ich im nächsten Abschnitt.

Zusätzlich habe ich hier die Daten der letzten 30 Tage und da ist zu sehen, dass quasi jeden Tag die Werte etwas ansteigen aber meist deutlich unter der Warnschwelle von 10 Nachrichten bleiben.


Quelle: PRTG Net at Work 19. Nov 2024 16:00, 30 Tage Ansicht

Aber es gibt schon den ein oder anderen Tag, wo die Zahlen deutlich erhöht sind.

Detailauswertung

Als die Werte über 10 Nachrichten waren und PRTG daher eine Warnung ausgegeben hat, war mein Kollege so freundlich, per Exchange Online PowerShell die Werte etwas genauer zu untersuchen und wir haben eine Unstimmigkeit gefunden. Die Daten wurde alle am 19. Nov 2024 gegen 16:10 abgefragt. Zuerst hat er die fraglichen Mails im Abstand von 10 Sekunden mehrfach ausgeben lassen. Das ging per PowerShell sehr einfach mit:

While ($true) {
   Get-MessageTrace -Status "Pending"
   Start-Sleep -Seconds 10
   Write-Host "---------------------------------------"
}

Ich hätte nun erwartet, dass die Rückgaben gleich sind und maximal oben neue Mails einlaufen und ältere bereits zugestellte Mails nicht mehr zugestellt werden. Allerdings ist das Bild etwas anders, denn ich habe farblich drei Bereich in drei aufeinanderfolgenden Abfragen markiert:

  • Grün
    Zuerst gab es zwei Nachrichten, dann aber eine andere dritte Nachricht und danach wieder die zuerst aufgeführten zwei Nachrichten
  • Rot
    Das ähnliche Bild gibt es noch einmal für Nachrichten um 08:40.
  • Blau
    Allerdings gibt es auch Nachrichten, die in allen drei Aufrufen geliefert werden.

Ich vermute, dass mein Abruf per Get-Messagetrace von unterschiedlichen Servern im Backend bedient wird, die ihrerseits unterschiedliche Kopien der Datenbanken abfragen. Im Gegensatz zu OnPremises mit einer überschaubaren Anzahl von Exchange Servern, deren Messagetracking sie einfach abrufen können, betreibt Microsoft in Exchange Online sicher Tausende von Transport-Servern, die ihre Trackinglogs vermutlich in einer riesige Datenbank pro Tenant einspeisen, die dann von der PowerShell abgefragt wird.

Mein Kollege hat sich dann eine Mail von 08:40 vorgenommen und dazu die MessageTraceDetails abgefragt. Bei der ersten Abfrage war die Mail noch im Status "Pending" und die Ursache war eine Zurückstellung aufgrund eines Scanvorgangs von "Advanced Thread Protection" mit folgender Meldung.

400 4.7.721 Advanced Thread Protection scanning in progress."

Bei der darauffolgenden Abfrage war die Mail dann angeblich zugestellt.

Damit hätte ich den Vorgang als abgeschlossen ansehen können. Aber wir haben danach dennoch ein drittes Mal den Status abgefragt und da war die Nachricht wieder im Status "Pending" und der finale "Delivered"-Eintrag wieder verschwunden. Nach Auskunft des Empfängers war die Mail natürlich schon lange angekommen.

Zwischenstand

Wir konnten nicht abschließend klären, ob dies nun eine temporäre Unstimmigkeit war. Die Daten per PRTG zeigen viele Messungen mit "0" oder wenigen Mails und bislang hat sich kein Anwender beschwert, dass Mails fehlen oder zumindest sehr spät angekommen wären. Die Analysen haben zu einer Zeit stattgefunden, wo Exchange Online sicher etwas mehr Last hatte, als gewöhnlich und mehr als 10 Nachrichten bei einer Anfrage auf '-Status "Pending"' geliefert wurden. Bei allen Nachrichten in dem Status wurde in den Details auf "400 4.7.221 Advanced Thread Protection scanning in progress." verwiesen. Vielleicht war hier eine Überlastung. Ein Support-Ticket habe ich dazu aber dann doch nicht eröffnet. Wir beobachten die PRTG-Messung etwas weiter.

Weitere Links