Message Tracking Grundlagen

Dieser Bereich kümmerst sich um die Funktion des Messagtracking in Exchange. Jede Mail, die "übertragen" und verarbeitet wird, hinterlässt eine Spur im Messagetracking. Es gibt dabei pro Mail nicht nur einen Datensatz sondern für jede Station eigene Einträge.

Zugänge und Abgänge

Für die meisten Einträge ist natürlich die Transport-Rolle zuständig. Aber auch die Mailbox-Rolle liefert einen Teil bei. Ein Exchange Server hat in der Regel vier Seiten, zu denen er spricht und von denen er angesprochen wird:

Die Stationen im Einzelnen:

Die Postfachdatenbank
Dorthin stellt die Transportrolle eingehende Mails an Postfächer zu und bekommt von Anwendern im Postausgang bereitgestellt Mails durch den Mail Submission Service zugestellt.

 

Exchange Server
Mehrere Exchange Server unterhalten sich natürlich miteinander per SMTP. Im Messagetracking sind diese Events einfache SMTP:SEND und SMTP:RECEIVE-Einträge, die man aber über den Namen des Connectors von anderen Übertragungen erkennen kann.

 

Das Internet
Mails zum und von dem Internet werden natürlich auch per SMTP gesendet und empfangen. Bei den meisten Firmen wird natürlich ein Spam- und Virenfilter davor stehen.

 

Internet SMTP-Dienste
Zuletzt gibt es natürlich noch sehr viele SMTP-Dienste wie Scan2Mail, Faxserver aber auch nachgelagerte Mailsysteme (ERP/CRM), die mit Exchange per SMTP kommunizieren.

 

Mails über all diese Schnittstellen generieren Einträge im jeweiligen Messagetrackinglog. Zusätzlich gibt es natürlich noch die Events der internen Verarbeitung.

Der Weg einer Mail

Ich habe mal exemplarisch eine Mail über verschiedene Wege gesendet und die Einträge im Trackinglog ermittelt. Hier ist zu beachten, dass der Mailboxserver selbst an den Server nur eine Benachrichtigung gibt, die Sie auf dem Mailboxserver finden, auch wenn dieser keine HubTransport-Rolle hat. Allerdings gibt es hier nicht mehr die einfache numerische EventID, sondern die Felder "SOURCE" und EVENTID.

Hinweis: Wenn Sie mehrere Server betreiben, dann kommen weitere Einträge bezüglich HARECEIVE, HARDIRECT und  HADISCARD dazu, da Exchange Mails immer zu einem zweiten Server als "Backup" schleust. Auch Transport-Agenten

Reihenfolge und TimeStamp
Wer über mehrere Server ein Tracking macht, kann sich auf die Zeitstempel nicht immer verlassen. Es ist manchmal nur schwer den logischen Ablauf zu ermitteln. Insbesondere, wenn Mails auch noch aufgeteilt werden.

Die Tabelle ist von oben nach unten zu lesen. Je nach Anzahl von Transport Agenten und Journal Agenten kann es weitere Einträge geben.

Internet
->MB
MB->
Internet
MB->MB
Local
Site2Site
Sender
Site2Site
Receiver
Beschreibung (Siehe KB 821905)

RECEIVE
SMTP

RECEIVE
MAILBOXRULE




DELIVER
STOREDRIVER

RECEIVE
STOREDRIVER

TRANSFER
ROUTING

SEND
SMTP




SUBMIT
STOREDRIVER

RECEIVE
STOREDRIVER







DELIVER
STOREDRIVER

SUBMIT
STOREDRIVER

 

 

Mail vom Store abgeholt
oder per SMTP Empfangen

Route


Per SMTP versendet


Zugestellt


Mail nach "gesendete Objekte" verschoben

Einschränkungen

Für diverse Auswertungen habe ich eigentlich immer nach zwingend vorkommenden Einträgen gesucht. Lange Zeit bin ich davon ausgegangen dass jede Mail eine der folgenden Einträge hat:

  • STOREDRIVER:RECEIVE
    Eine Mail wurde per MAPI in die Datenbank zum Versand abgelegt und der Store informiert einen Transport. Das wäre ein Indikator für den "Start" einer Mail. Leider musste ich feststellen, dass dieser Event nicht zuverlässig ist.
  • STOREDRIVER:DELIVER
    Der Event scheint aber sehr zuverlässig zu kennzeichnen, wenn eine eingehende Nachricht in ein Postfach abgelegt wurde. So kann man zumindest den Eingang für bestimmte Adressen ermitteln.
  • STOREDRIVER:NOTIFYMAPI
    Diese Meldung sollte erscheinen, wenn ein Client eine Mail mit Outlook in den Postausgang legt. Leider ist der Event nur ein Zeichen für eine neue Mail aber enthält keine Informationen wie Empfänger, Betreff, MessageID, Größe etc. und ist daher kaum für eine Auswertung zu gebrauchen.
  • SMTP-RECEIVE mit Connector
    Eine einkommende Mail könnte man ja über diesen Eintrag ermitteln. Aber da der Event auch beim Verkehr zwischen den Servern erscheint und dabei als Empfangsconnector in der Regel der "Default Connector" eingetragen ist, können Sie damit eigentlich nur das Empfangsvolumen in BEzug auf den Transport dieses Servers ermitteln.
  • SMTP:SEND mit Connector
    Filtert man auf diesen Eintrag und liest zudem den Namen des Send-Connectors aus, dann ist es ein guter Indikator für eine Mail, die Exchange verlässt. Intern per SMTP übertragene Mails haben als ConnectorID den String "Intra-Organization SMTP Send Connector". Nach extern gehende Mails sind so aber gut zu erfassen. Eine Mail an mehrere Empfänger kann aber durchaus mehrfach versendet werden

Source und EventID

Es gibt übrigens noch einige weitere EventIDs und Quellen. Eine komplette Liste findet sich bei Microsoft

Allerdings sagen diese Listen nicht über die möglichen Kombinationen aus. Ich habe daher in einer größeren Umgebung einmal die Paarungen gesucht und folgende Verteilung der Häufigkeit gesehen.

get-transportservice | get-messagetrackinglog | group {$_.source+":"+$_.eventid} -NoElement 

Count Name
----- ----
26962 MEETINGMESSAGEPROCESSO..
...70 STOREDRIVER:DELIVER
15395 MAILBOXRULE:RECEIVE
 1068 STOREDRIVER:DUPLICATED..
   11 STOREDRIVER:DROP
...84 STOREDRIVER:NOTIFYMAPI
...61 STOREDRIVER:RECEIVE
...40 STOREDRIVER:SUBMIT
...56 SMTP:HADISCARD
...54 SMTP:HARECEIVE
...12 SMTP:HAREDIRECT
...12 SMTP:RECEIVE
...08 AGENT:AGENTINFO
...49 SMTP:SEND
39325 ROUTING:TRANSFER
 2685 AGENT:TRANSFER
13272 ROUTING:DROP
58817 ROUTING:RESOLVE
 2464 ROUTING:FAIL
10310 SMTP:SENDEXTERNAL
3 407 ROUTING:EXPAND
 2298 DSN:DSN
  121 AGENT:REDIRECT
  121 AGENT:RESUBMIT
 1266 DSN:BADMAIL
    1 SMTP:FAIL
  119 ROUTING:REDIRECT
   71 ROUTING:DUPLICATEEXPAND
   55 AGENT:FAIL
   22 STOREDRIVER:SUBMITFAIL
   23 STOREDRIVER:THROTTLE
    7 SMTP:DEFER

Wunderwaffe Agent/Agentinfo?

Der erste Server, der eine Mail verarbeitet, wendet auch die Transportregeln etc. an. Damit sollte es den Event pro Mail genau einmal geben. Das ist aber nicht immer so richtig da z.B. Mails an eine Mailbox, die im Rahmen einer Migration per TargetAddress weiter geleitet wird, natürlich wieder den Event angestoßen wird. Dabei sind durch die Umleitung (nicht mit einer Weiterleitung zu verwechseln) die MessageID und Absender unverändert. Aber dennoch ist aus meiner Sicht dieser Event quasi prädestiniert um Auswertungen zu beginnen, bei denen jede Mail genau einmal enthalten sein soll.

RunspaceId              : <guid>
Timestamp               : 11/30/2017 2:43:23 PM
ClientIp                :
ClientHostname          : EX01
ServerIp                :
ServerHostname          :
SourceContext           : CatContentConversion
ConnectorId             :
Source                  : AGENT
EventId                 : AGENTINFO
InternalMessageId       : 45367739552
MessageId               : <12345@msxfaq.com>
NetworkMessageId        : 12345678-1234-1234-1234-1234567890ab
Recipients              : {User2@msxfaq.com, User3@msxfaq.com}
RecipientStatus         : {}
TotalBytes              : 18275
RecipientCount          : 2
RelatedRecipientAddress :
Reference               :
MessageSubject          : Betreffzeile
Sender                  : info@msxfaq.de
ReturnPath              : info@msxfaq.de
Directionality          : Originating
TenantId                :
OriginalClientIp        : 192.168.178.112
MessageInfo             :
MessageLatency          :
MessageLatencyType      : None
EventData               : {[TRA, ETRP|ruleId=b20daada-f091-4089-a8e8-9003302661ec|st=2016-09-21T11:12:25.0000000Z|ExecW=11|ExecC=0|Conditions=MRP,M.AN,0;LMP,M.
                          AN,12|Components=FIPS_TE,0,12], [TRA,
                          ETRP|ruleId=a8bee0f6-a04f-436b-8eed-57a23b6cc4bd|st=2017-12-13T09:29:25.0000000Z|ExecW=0|ExecC=0|Conditions=CP,F,0;CP,F,0], [TRA,
                          ETRP|ruleId=f12eb37a-9bb1-49eb-9a91-e5f135ad7191|st=2017-11-29T09:29:02.0000000Z|ExecW=0|ExecC=0|Conditions=IP,F,0;IP,F,0], [TRA,
                          ETR|ruleId=b02e3712-83a7-4695-a53d-b5d02705ba26|st=6/3/2015 9:47:01 AM|action=SetHeader|sev=1|mode=Enforce], [TRA,
                          ETRP|ruleId=b02e3712-83a7-4695-a53d-b5d02705ba26|st=2015-06-03T09:47:01.0000000Z|ExecW=0|ExecC=0|Actions=SH,0|Conditions=CP,M.F,0],
                          ETRI|MsgType=SummaryTnef|Ex=|IsKnown=|FipsStatus=Success|AttchUns=|ceErr=|Synth=False-Na-]...}
TransportTrafficType    : Email
SchemaVersion           : 15.01.1261.035

Es sind eigentlich alle relevanten Informationen enthalten wie:

  • Absender und Empfänger
    Damit können Sie die Richtung der Mail ermitteln. Das Feld "Directionality" eignet sich dazu leider nicht
  • Betreff und Größe
    Zur weiteren Auswertung
  • OriginalClientIP
    Für die Zuordnung des realen Absender

Message Tracking und Performance

Kaum jemand wird alle Daten benötigen und so ist eine Filterung der Quellen erforderlich. Eine Filterung über die Parameter wird vom Exchange Server remote ausgeführt und nur die zutreffenden Daten werden zum Client gesendet. Das geht schneller und spart Bandbreite. Folgende Messwerte können das belegen:

  • 6 Exchange 2016 Server
  • 1 Stunde Intervall
  • ca. 250.000 Datensätze auf allen Servern zusammen

 

Test

Commandlet

Dauer Sek

Anzahl

Logs aller Stunden lesen

get-transportserver  `
| Get-MessageTrackingLog `
-ResultSize unlimited `
-Start (get-date).addhours(-1)`
| out-null

280

250.000

Server Filterung

get-transportserver  `
| Get-MessageTrackingLog `
-ResultSize unlimited `
-Start (get-date).addhours(-1)`
- Recipients "info2@msxfaq.de"
| out-null

15

654

Client Filterung

get-transportserver  `
| Get-MessageTrackingLog `
-ResultSize unlimited `
-Start (get-date).addhours(-1)`
| ? {$_.Recipients  -contains "info2@msxfaq.de"} `
| out-null

350

190

Sie sehen schon sehr gut, dass eine Vorfilterung über Parameter auf jeden Fall anzuraten ist, es sei denn Sie würden sehr viele Anfragen nach unterschiedlichen Empfängern stellen. Dann würde ich vielleicht doch daran denken die Logs in eine lokale Datenbank zu übertragen und hier dann weiter auszuwerten.

Aber wenn Sie genau hingeschaut haben, dann sehen Sie einen Unterschied bei der Anzahl der übergebenen Objekte zwischen der Client und Serverfilterung. Darauf gehe ich im nächsten Abschnitt ein.

Message Tracking und Filtern

Eine zweite Besonderheit sollten Sie beachten, wenn Sie nach bestimmten Einträgen suchen. Das Exchange Messagetracking ist viel leistungsfähiger, als man zuerst denken mag. Das fällt z.B. auf, wenn Sie nach alles Mails einer internen Mailbox suchen. Eine Mailbox kann durchaus mehrere Adressen haben und hier gibt es ein Postfach "User2@msxfaq.de", welches zusätzlich auch noch die Adresse "info2@msxfaq.de" hat. Ich kann nun auf zwei Arten nach Mals an diese Adresse suchen

# Filterung auf dem Server

[PS] C:\>get-messagetrackinglog -recipient info2@msxfaq.de | ?{$_.MessageSubject -eq "Test1"}

Timestamp               EventId       Source        Sender             Recipients          MessageSubject
---------               -------       ------        ------             ----------          --------------
11/22/2017 22:36:25 AM  HARECEIVE     SMTP User1@carius.de   {info2@msxfaq.de}    Test1
11/22/2018 22:38:13 AM  HADISCARD     SMTP User1@carius.de   {info2@msxfaq.de}    Test1
11/22/2017 22:36:25 AM  HAREDIRECT    SMTP User1@carius.de   {info2@msxfaq.de}    Test1
11/22/2017 22:36:25 AM  RECEIVE       SMTP User1@carius.de   {info2@msxfaq.de}    Test1
11/22/2017 22:36:25 AM  RESOLVE       ROUTING User1@carius.de   {User2@msxfaq.de}    Test1
11/22/2017 22:36:25 AM  AGENTINFO     AGENT User1@carius.de   {User2@msxfaq.de}    Test1
11/22/2017 22:36:25 AM  SEND          SMTP User1@carius.de   {User2@msxfaq.de}    Test1
11/22/2017 22:36:25 AM  DELIVER       STOREDRIVER User1@carius.de   {User2@msxfaq.de}    Test1

Eine Mail an diese Adresse wird von Exchange sehr früh auf die primäre Adresse "User2@msxfaq.de" umgeschrieben. in den weiteren Logs steht dann wieder die primäre Adresse drin. Der Exchange Server filtert über die Parameter nicht genau auf den String sondern auf das Empfängerobjekt.

Anders sieht es aus, wenn Sie sich alle Einträge holen und danach über den String des Felds "Recipients" filtern. Hier kommen deutlich weniger Einträge zurück.

# Filterung auf dem Client

[PS] C:\>get-messagetrackinglog | ? {$_.recipients -eq "info2@msxfaq.de"} | ?{$_.MessageSubject -eq "Test1"}

Timestamp               EventId       Source        Sender            Recipients           MessageSubject
---------               -------       ------        ------            ----------           --------------
11/22/2017 22:36:25 AM  HARECEIVE     SMTP User1@carius.de   {info2@msxfaq.de}    Test1
11/22/2017 22:36:25 AM  HAREDIRECT    SMTP User1@carius.de   {info2@msxfaq.de}    Test1
11/22/2017 22:36:25 AM  RECEIVE       SMTP User1@carius.de   {info2@msxfaq.de}    Test1

Daher ist es wichtig möglichst "richtig" zu filtern und auszuwerten.

Weitere Links