End2End EWS

Auf der Seite End2End-MSXLatenz beschreibe ich, wie man per WMI von Exchange Daten der Client ermitteln kann. Das ist mit Exchange 2007 und höher so nicht mehr per WMI möglich. Allerdings gibt es durchaus andere Logs, die man auswerten könnte.. Diese Seite beschäftigt sich aber mit einem Skript, welche simmer wieder den Posteingang liest und damit sowohl die Erreichbarkeit des Service als auch eine Geschwindigkeit des Service überprüfen kann.

Dieses Skript nutzt EWS, um sich mit einem Postfach zu verbinden und immer wieder eine Mail zu lesen. (Ohne Cached-Mode). Es misst den Zeitbedarf dafür und meldet größere Abweichungen von Mittelwert. Auch hier ist es problemlos möglich, quasi im Sekundentakt die Mail zu lesen und Probleme sehr schnell zu erkennen und diese im Eventlog zu melden. Damit hat eine nachgeschaltete Überwachungssoftware dann in der Regel keine Probleme mehr einen Alarm auszulösen.

Warum ein eigenes Skript?

Microsoft hat mit "Test-Outlook" und "Test-WebService" vergleichbares per PowerShell. Diese Commandlets laufen aber nur auf Exchange Server und nicht von einem beliebigen PC. Zudem brauchen diese Zugriffe ziemlich lange, da Sie den kompletten Verbindungsaufbau durchführen. Mein Skript hingegen baut einmal die Verbindung auf und liest dann immer und immer wieder schnell die erste Mail aus dem Posteingang und kann damit eine lückenlose schnelle Überwachung und Performance-Messung auch aus der Ferne über ein LAN, WAN, WLAN gewährleisten. Und es kann auch "echtes Postfach" überwachen und nicht nur die Systemmailbox.

Allerdings sollten Sie auch im Hinterkopf behalten, dass so ein häufiges lesen nicht "zu oft" passieren darf. Exchange wehrt sich schon bei übermäßiger Beanspruchung (Thema Budget und Throttling). Einen DoS sollten Sie damit besser nicht versuchen. Die so oft gelesenen Daten werden aber von Exchange natürlich bevorzugt im Cache gehalten.

Funktionsweise

Der Code baut im wesentlichen auf der Funktion von Test-EWS auf. Meinem kleinen Tool und Mustervorlage zum Überprüfen von EWS und Sicht dann immer nach der ersten Mail im Postfach. So wird jedes mal eine EWS-Anfrage ausgelöst.

Genau genommen sind es zwei Aktionen, das aus mir nicht ganz verständlichen Gründen immer erst eine anonyme Anfrage gestellt wird, auf die die EWS.DLL dann authentifiziert das zweite Mal fragt. Der Request zeigt schön die Aktion:

Sie sehen hier aber auch, dass zur Anmeldung "Basic Auth" zum Einsatz kommt. Ich war zu dem Zeitpunkt "extern" und EWS nutzt wohl noch nicht ADFS. Interessant finde ich hier auch den Eintrag "ResponseTime", zu dem ich keine weiteren Informationen habe. Es könnte sein, dass EWS hier an den Server mit dem Post die Latenzzeit des vorherigen Aufrufs übersendet. Das Kernprogramm sieht wie folgt aus:

Die Variable "$inbox" wird vorher schon instanziert, so dass ich hier dann einfach jede Sekunde eine Messung macht und die Daten nach 10 Messungen an eine CSV-Datei anhänge. Die enthält dann folgende Daten:

"beserver","timestamp","durationmin","durationmax","durationavg"
"VI1PR0402MB3646","06.03.2018 13:32:25","386,5109","452,201","412,8508"
"VI1PR0402MB3646","06.03.2018 13:32:35","369,1626","448,7712","416,47995"
"VI1PR0402MB3646","06.03.2018 13:32:46","387,8168","1052,8737","565,58746"
"VI1PR0402MB3646","06.03.2018 13:32:56","403,5637","458,0882","427,45375"
"VI1PR0402MB3646","06.03.2018 13:33:06","361,0322","476,3444","427,47761"
"VI1PR0402MB3646","06.03.2018 13:33:16","398,3042","538,8762","465,66"

Ca. alle 10 Sekunden wird eine Zeile angehängt, die neben dem Backend Server auch die Dauer des Abrufs (min/max/avg) protokolliert wird. Die Werte lassen sich dann gut in Power Bi

Sie sehen hier einen deutliche Verschlechterung der durchschnittlichen aber und der maximalen Antwortzeit. Letztlich war dies durch einen Netzwerkwechsel verursacht, bei dem der gleichen Client einen anderen Provider verwendet hat. Das Zeit natürlich auch ein Problem. Wenn der Client dies nicht durch eine Netzwerkunterbrechung mitbekommen hat, dann gibt es auch keinen Grund eine neue DNS-Anfrage zu starten. Der in dieser Zeit angesprochenen Office 365 Zugänge waren also nicht optimal. 1000ms Latenzzeit ist nicht gut. Die anderen Werte zeigen aber eine durchschnittliche zügige Verbindung, bei denen es manchmal aber zumindest eine Transaktion gibt, die deutlich länger braucht.

Analyse HTTPHeader

Wenn Sie sich die HTTP-Request Header anschauen, dann fällt mir noch was auf:

$result.Service.HttpResponseHeaders

Key                  Value
---                  -----
Transfer-Encoding    chunked
Content-Encoding     gzip
Vary                 Accept-Encoding
request-id           1c8b3ec4-6cf2-4fa8-ac8d-490ed3eb1e4a
X-CalculatedFETarget VI1P195CU001.internal.outlook.com
X-BackEndHttpStatus  200,200
X-FEProxyInfo        VI1P195CA0007.EURP195.PROD.OUTLOOK.COM
X-CalculatedBETarget VI1PR0402MB3646.eurprd04.prod.outlook.com
x-EwsHandler         FindItem
X-DiagInfo           VI1PR0402MB3646
X-BEServer           VI1PR0402MB3646
X-FEServer           VI1P195CA0007,AM3PR04CA0146
Cache-Control        private
Content-Type         text/xml; charset=utf-8
Date                 Sat, 10 Mar 2018 11:32:15 GMT
Set-Cookie           exchangecookie=0491d47b6b6a45beaa330f3ce618b930; path=/
Server               Microsoft-IIS/10.0
X-AspNet-Version     4.0.30319
X-Powered-By         ASP.NET

Bei Office 365 gibt es zwei FE-Server. Anscheinend werden meine Anfrage erst durch einen Zugangs-Frontend geroutet, der diese dann über einen weiteren Frontend zum Backend zustellt. Aber das ist dann wieder ein anderes Kapitel.

Beispiel mit Office 365

Beim Zugriff auf Office 365 zeigt sich, wie Microsoft die Last der Clientzugriffe verteilt. ein EWS-Client landet bei einem "naheliegenden" Frontend, der dann aber nicht direkt zu dem Backend geht, der die aktive Datenbank für das Postfach hält. dann müssten ja alle Frontends weltweit den aktuellen Status aller Postfächer und Datenbanken kennen. Anscheinend wertet der erster Frontend nur aus, in welchem Datacenter das Postfach ist um den Zugriff als Proxy dorthin zu senden. Interessanterweise ist der erste Frontend mit jedem Request ein anderer Server und erst der zweite Frontend ist dann immer der gleiche, der die Daten dann zum immer gleichen Backend weiter gibt.

PS C:\end2end-ews> .\end2end-ews.ps1
Number or Unread Messages :  5881
FE1:VI1PR10CA0097   FE2:AM5P189CA0022   BE:VI1PR0402MB3646   RTT(ms)90.0631
New X-BEServer VI1PR0402MB3646 detected
FE1:VI1PR10CA0114   FE2:AM5P189CA0022   BE:VI1PR0402MB3646   RTT(ms)88.0345
FE1:VI1PR10CA0097   FE2:AM5P189CA0022   BE:VI1PR0402MB3646   RTT(ms)90.0568
FE1:VI1PR10CA0114   FE2:AM5P189CA0022   BE:VI1PR0402MB3646   RTT(ms)89.0561
FE1:VI1PR10CA0097   FE2:AM5P189CA0022   BE:VI1PR0402MB3646   RTT(ms)100.0662
FE1:VI1PR10CA0114   FE2:AM5P189CA0022   BE:VI1PR0402MB3646   RTT(ms)90.0596
FE1:VI1PR10CA0114   FE2:AM5P189CA0022   BE:VI1PR0402MB3646   RTT(ms)89.0612
FE1:VI1PR10CA0097   FE2:AM5P189CA0022   BE:VI1PR0402MB3646   RTT(ms)88.0555
FE1:VI1PR10CA0114   FE2:AM5P189CA0022   BE:VI1PR0402MB3646   RTT(ms)92.0589
FE1:VI1PR10CA0097   FE2:AM5P189CA0022   BE:VI1PR0402MB3646   RTT(ms)88.0535
Summary Message

beserver    : VI1PR0402MB3646
timestamp   : 05.05.2018 15:06:58
durationmin : 88,0345
durationmax : 100,0662
durationavg : 90,45654

Export Results to archivcsv .\end2end-ews.csv

Wenn ich aber schon im richtigen DataCenter bin, dann ist der FE1 leer

Hier sehen Sie auch die normale Antwortzeit meiner Requests. Per Default werden die letzten 10 Messwerte zusammen gefasst und als Min/MAX/Avg-Werte in eine CSV-Datei archiviert.

PRTG Integration

Wenn eine PRTGPushURL mit angegeben ist, dann sendet das Skript die Daten auch noch an einen PRTG-Probe zur Speicherung als Sensordaten.

Über mehrere Stunden sind die Daten schon interessant:

Noch deutlicher sind die Anfragen über mehrere Tage hinweg.

Download

 

Das Skript ist aktuell noch kein öffentlicher Download. Es wird von mir und Net at Work Consultants bei Kunden eingesetzt und muss erst noch ein paar Monate seine Dauertauglichkeit beweisen. Aktuell gibt es noch immer Sonderfälle, die die Messung verfälschen und noch nicht gelöst sind.

Weiterentwicklung

Für die Performance-Überwachung bezüglich der Netzwerkverbindung gibt es hier wohl kaum noch Potential für weitere Änderungen. Denkbar wäre aber z.B. auch die Auswertung der Backend-Server und wann und wie sich diese Wechseln. So könnten Sie vielleicht einen Eindruck gewinnen, wie Microsoft intern seine Server umbaut oder ihr Postfach umzieht.

Aktuell prüft das Skript auch genau einen Posteinfang. Mit EWS-Impersonation könnte man mehrere Postfächer abfragen und damit eben der Performance auch einen Erreichbarkeitscheck umsetzen. Allerdings wird man so nicht alle Postfächer eines Unternehmens überwachen wollen. Irgendwann wird auch Office 365 den Client per Throttling ausbremsen und die Daten werden schlechter.

Weitere Links