Free/Busy mit OAUTH

Auf dieser Seite möchte ich etwas tiefer in die Kommunikation zwischen Exchange Online und On-Premises einsteigen, insbesondere was Free/Busys und OAUTH bedeutet. Das Verständnis hilft auch bei der Fehlersuche in realen Umgebungen.

Umgebung

Wir nehmen eine klassische Exchange Hybrid Umgebung mit einem lokalen Exchange 2016 Server, bei dem mit ADSync die Benutzer korrekt synchronisiert werden und der Hybrid Configuration Wizard auch OAUTH und Exchange Partner Application korrekt eingerichtet hat. Das Bild zeigt folgendes:

  • Exchange Hybrid
    Die Umgebung besteht aus einem Exchange On-Prem und Exchange Online Server mit komplett eingerichteten Hybrid-Mode, so dass Free/Busy eigentlich funktionieren müssten.
  • OnPrem Mailbox
    Es gibt ein Postfach auf dem lokalen Exchange Server, welches dank ADSync auch in der Cloud "bekannt" ist
  • CloudUser
    Zudem gibt es ein Postfach, welches nur in der Cloud bekannt ist. Das kann ein CloudOnly Benutzer oder Admin sein oder auch die klassische Fehlkonfiguration, dass ein lokaler Benutzer per ADSync in der Cloud angelegt und mit Exchange Lizenz versehen wurde aber im lokalen AD nicht als "RemoteMailbox" provisioniert wurde.

Diese Konstellation ist per Se natürlich ein Fehler und ist einfach zu heilen. Aber es gibt noch weitere Konstellationen, z.B. Free/Busy zwischen mehreren Organisationen, die hier aber komplizierter sind. Für die Beschreibung der Probleme, der Analyse und Ursache reicht diese vereinfachte Version.

Keine F/B-Zeiten

Ich habe mich dann als "clouduser@msxfaq.de" mit Outlook an Postfach in der Cloud angemeldet und wollte natürlich einen Termin mit dem Benutzer "OnPremUser@msxfaq.de" vereinbaren. In den Frei/Belegt-Zeiten habe ich aber nur den bekannten schaffierte Balken gesehen.

Leider zeigt Outlook hier nicht wirklich die Details an, warum er keine Daten erhalten hat. Mit meinem Server konnte Outlook kommunizieren, da er meine eigenen Frei/Belegt-Zeiten sehr wohl ermittelt hat. Outlook hat aber einen Fehler bekommen, den es aber dem Anwender vorenthält.

Analyse auf dem Client

Nun ist das Problem bei einem Cloud-Postfach, dass ich nicht auf dem Exchange Server in ein Eventlog schauen kann und die Anfrage der Cloud auf meinen Exchange Server kann ich dank HTTPS erst einmal auch nicht mit Wireshark analysieren. Aber soweit muss ich gar nicht gehen, denn auch auf dem Client kann ich erste Fehler abfragen.

Die Frei/Belegt-Abfrage von Outlook ist eine klassische EWS-Abfrage gegen den Exchange Online-Server, auf dem das Postfach liegt. Outlook protokolliert normalerweise leider solche fehlerhaften Abfragen nicht im Eventlog oder einer lokalen Datei. Ich könnte aber einen Trace-Mode aktivieren, bei dem Outlook dann Dateien in "%temp%\OlkAS\Datum-Urhzeit-AS.LOG" an.

Ich nutze hier aber mal Fiddler auf dem Client, der sich mit aktivierter HTTPS-Decryption als Proxy dazwischen klemmt und mir alle HTTP-Anfragen direkt anzeigt. Um nicht zu viel Anfragen zu sehen, starte ich erst einmal Outlook und lasse es seine anfänglich Synchronisationen ausführen und dann zur Ruhe kommen.

Ich leere dann den Fiddler-Trace oder starte Fiddler erst dann und planen einen neuen Termin mit "OnPremUser@msxfaq.de" und klicke dann auf die Terminplanung, um wieder die Frei/Belegt-Zeiten zu erhalten. In Fiddler suche ich einfach mit CTRL-F nach der Zeichenfolge "OnPremUser" und Fiddler markiert die entsprechenden Request bei mir gelb.

Meist ist es es der letzte Eintrag, da Outlook schon während der Eingabe der Adresse per EWS auch die Teiladressen versucht zu finden. Wenn Sie den richtigen Eintrag finden, dann sehen Sie den EWS-Request mit der XML-Playload "GetUserAvailabilityRequest" zu dem Benutzer und den ausgewählten Zeitraum.

Die Fehlermeldung ist hier zweigeteilt. Die EWS-Anfrage selbst wird hier mit einem 200 OK erfolgreich beantwortet aber in den Nutzdaten stehen die Fehler.

MessageText: Proxy web request failed. ,
     inner exception: System.Net.WebException: 
     The request failed with HTTP status 401: Unauthorized.
ResponseCode: ErrorProxyRequestProcessingFailed
Proxy web request failed. , inner exception: 
    The request failed with HTTP status 401: Unauthorized.,
    diagnostics: 2000005;
    reason="The user specified by the user-context in the token does not exist.";
    error_category="invalid_user" LID: 43532

Wer sich den Fehler genau anschaut, sieht hier aber auch den Server "AM0PR04MB6163", welcher den Fehler liefert. Dieser Server hat per HTTPS eine Verbindung zu meinem On-Premises-Server gestartet, um die Frei/Belegt-Zeiten zu erhalten. Da stellt sich natürlich die Frage, was mein Exchange Online Server zu, On-Premises-Server genau gesendet hat.

Wenn mein Exchange Server überhaupt nicht zum anderen Server kommt, dann beschreibt der Fehler meist, dass die Verbindung nicht hergestellt wurde oder die Adresse nicht gefunden werden konnte. Diese Seite beschäftigt sich aber mit der Fehlermeldung "user-context in the token does not exist".

FREB auf Exchange OnPrem

Die Anfrage der Cloud kommt bei mir natürlich per HTTPS an. Es kommen natürlich sehr viele Anfragen dort an und bei meiner Laborumgebung habe ich leider keinen Reverse-Proxy davor, der auch noch SSL aufbricht und mit daher die Daten ausleiten könnte. Aber auch mit den Tracing-Funktionen des des IIS (Siehe IIS - Webserver Troubleshooting)) kann ich hier Details generieren. Ich aktiviere FREB auf dem EWS-Verzeichnis und lasse einfach alle 401-Fehler mitschneiden und drücke dann in Outlook in der Frei/Belegt-Anzeige der Terminplanung auf aktualisieren.

Damit mit der IIS nicht die Logs schnell wieder überschreibt, kopiere ich mir die XML und die XSL-Datei mal schnell auf die Seite, ehe ich an die Analyse gehe.

Es durchaus nicht unüblich, dass auch andere Anfragen von Clients einen 401 generieren. Der Trick ist, genug dieser Logs zu haben und nach der Mailadresse des Postfachs zu suchen, dessen Frei/Belegt-Zeiten von der Cloud angefragt werden. Die sind zwar per HTTPS verschlüsselt aber der Trace enthält ja den Request als Klartext.

Tipp: Wenn Sie viele Dateien haben, dann suchen Sie sich die erste, die die Mailadresse des Postfachs enthält und finden Sie im Header der Feld "client-request-id", denn die Cloud behält die ID über mehrere Request bei, die zur gleichen Anfrage gehören.

Auswertung der FREB-Logs

Hier kann ich nun natürlich nicht Fiddler nehmen, sondern muss die die XML-Dateien anschauen und wer genau hinschaut, findet drei Request mit Antwort: In meinem Fall habe ich drei Requests gesehen, wobei der erste Request sie durchaus in die Irre leiten kann. Der erste Request ist natürlich eine anonyme Anfrage. Das ist normal, denn der Exchange Online Server, der bei dieser Kommunikation der "Client" ist, weiß noch nichts von den Möglichkeiten meines Exchange Servers.

POST https://hybrid.msxfaq.de:443/ews/exchange.asmx
Connection: Keep-Alive
Content-Length: 2829
Content-Type: text/xml; charset=utf-8
Accept-Encoding: gzip
Host: hybrid.msxfaq.de
User-Agent: ASProxy/CrossForest/EmailDomain//15.20.5273.022/Freebusy
X-AnchorMailbox: user1@msxfaq.de
Sie : {9C163B00-D0CE-4003-8F8D-49470C70B9FD}
SOAPAction: "http://schemas.microsoft.com/exchange/services/2006/messages/GetUserAvailability"
X-Forwarded-Proto: https
X-Forwarded-For: 52.97.164.149
X-Forwarded-Host: hybrid.msxfaq.de
X-Forwarded-Server: hybrid.msxfaq.de

Allerdings verrät Exchange selbst hier auch noch nicht, dass er Bearer versteht. (Siehe auch Test-Bearer). Entsprechend ist die Antwort ein "401 unauthorized" mit der Rückgabe möglicher Authentifizierungsverfahren.

401 Unauthorized
Server: Microsoft-IIS/8.5
request-id: 09f849d8-746b-4754-8d7a-339f114b39d4
X-OWA-Version: 15.1.2375.24
WWW-Authenticate: Negotiate
WWW-Authenticate: NTLM
WWW-Authenticate: Basic realm="hybrid.msxfaq.de"
X-Powered-By: ASP.NET
X-FEServer: EX2016

Natürlich kann der Exchange Online-Server hier nichts mit anfangen. Nur bei Exchange 2007 war die Vorgabe eines "Dienstkontos" der einzige Weg. Seit Exchange 2010 und neuer wurde das MFG Microsoft Federation Gateway genutzt. Aber Exchange hat ja einen zweiten Schuss frei und der nächste Request sah dann etwas verändert aus:

POST https://hybrid.msxfaq.de:443/ews/exchange.asmx
Connection: Keep-Alive
Content-Length: 2829
Content-Type: text/xml; charset=utf-8
Accept-Encoding: gzip
Authorization: Bearer
Host: hybrid.msxfaq.de
User-Agent: ASProxy/CrossForest/EmailDomain//15.20.5273.022/Freebusy
X-AnchorMailbox: user1@msxfaq.de
client-request-id: {9C163B00-D0CE-4003-8F8D-49470C70B9FD}
SOAPAction: "http://schemas.microsoft.com/exchange/services/2006/messages/GetUserAvailability"
X-Forwarded-Proto: https
X-Forwarded-For: 52.97.164.149
X-Forwarded-Host: hybrid.msxfaq.de
X-Forwarded-Server: hybrid.msxfaq.de

Wieder bekommt er einen 401 aber diesmal mit Bearer-Antwort.

401 Unauthorized
Server: Microsoft-IIS/8.5
request-id: 66a6b256-a565-464c-87d3-79f5d9ec3d46
WWW-Authenticate: Bearer client_id="00000002-0000-0ff1-ce00-000000000000", 
               trusted_issuers=&quot;00000001-0000-0000-c000-000000000000@<GUID des Tenant>,
                                     00000003-0000-0ff1-ce00-000000000000@0fb5b3a9-4993-4eae-80e1-82a164b25ab7,
                                     00000004-0000-0ff1-ce00-000000000000@msxfaq.de&quot;,
               token_types=&quot;app_asserted_user_v1 service_asserted_app_v1&quot;
X-OWA-Version: 15.1.2375.24
WWW-Authenticate: Negotiate
WWW-Authenticate: NTLM
WWW-Authenticate: Basic realm=&quot;hybrid.msxfaq.de&quot;
X-Powered-By: ASP.NET
X-FEServer: EX2016

Sollten ihr Exchange Server auf diesen zweiten Request nicht mit einer Bearer-Information reagieren, dann prüfen Sie die Authentifizierungseinstellungen ihres EWS-Verzeichnis mit "Get-WebServiceVirtualDirectory". Hier mutt OAuthAuthentication aktiv sein. Manchmal scheint die Einstellung nicht zu wirken und es könnte helfen, die Authentifizierung zu deaktivieren und wieder zu reaktivieren. Normalerweise aktiviert der HCW - Hybrid Configuration Wizard dies bei der Einrichtung.

Was nun im Hintergrund passiert, kann man nur vermute. Der Exchange Online Server wird nun zum Microsoft Authentication Service gehen und sich ein Ticket zu einem der angegebenen Dienstendpunkte besorgen. Im letztlich dritten Request kommt der Exchange Server dann mit einem Bearer-Token (von mir gekürzt) wieder:

POST https://hybrid.msxfaq.de:443/ews/exchange.asmx
Connection: Keep-Alive
Content-Length: 2829
Content-Type: text/xml; charset=utf-8
Accept-Encoding: gzip
Authorization: Bearer eyJhbGciOiJu..... TU5MGE2In0.
Host: hybrid.msxfaq.de
User-Agent: ASProxy/CrossForest/EmailDomain//15.20.5273.022/Freebusy
X-AnchorMailbox: user1@msxfaq.de
client-request-id: {9C163B00-D0CE-4003-8F8D-49470C70B9FD}
SOAPAction: &quot;http://schemas.microsoft.com/exchange/services/2006/messages/GetUserAvailability&quot;
X-Forwarded-Proto: https
X-Forwarded-For: 52.97.164.149
X-Forwarded-Host: hybrid.msxfaq.de
X-Forwarded-Server: hybrid.msxfaq.de

Die Antwort auf diesen Request ist dann zwar immer noch der "401 unauthorized" aber im "WWW-Authenticate" steht ein "invalid_token":

401 Unauthorized
Server: Microsoft-IIS/8.5
request-id: de056a8e-60d8-436c-9efc-55f7ae765ed3
x-ms-diagnostics: 2000005;reason=&quot;The user specified by the user-context in the token does not exist.&quot;;error_category=&quot;invalid_user&quot;
WWW-Authenticate: Bearer client_id=&quot;00000002-0000-0ff1-ce00-000000000000&quot;, 
               trusted_issuers=&quot;00000001-0000-0000-c000-000000000000@<GUID des Tenant>,
                                     00000003-0000-0ff1-ce00-000000000000@0fb5b3a9-4993-4eae-80e1-82a164b25ab7,
                                     00000004-0000-0ff1-ce00-000000000000@msxfaq.de&quot;, 
               token_types=&quot;app_asserted_user_v1 service_asserted_app_v1&quot;, error=&quot;invalid_token&quot;
X-OWA-Version: 15.1.2375.24
WWW-Authenticate: Negotiate
WWW-Authenticate: NTLM
WWW-Authenticate: Basic realm=&quot;hybrid.msxfaq.de&quot;
X-Powered-By: ASP.NET
X-FEServer: EX2016

Die XML-Payload ist schon vom Fiddler bekannt aber steht auch hier im Header "x-ms-diagnostics" noch einmal drin:

Der On-Premises Exchange Server verarbeitet also das BearerToken aber ist damit nicht zufrieden

Bearer Decoding

Der nächste Schritt besteht nun darin, dass Token aus dem dritten Request aus dem Header zu extrahieren. Dazu kopiere ich den Text hinter dem "bearer" aus dem Request und lasse es durch https://jwt.io oder https://jwt.ms decodieren. Das Token ist der vom Aussteller digital signierte Beweis, wer ich bin und ist nur einige Stunden gültig.

{
  "alg": "none",
  "typ": "JWT"
}.{
  "nameid": "1003000080AC45FA",
  "upn": "Clouduser@msxfaq.de",
  "smtp": "Clouduser@msxfaq.de",
  "sip": "Clouduser@msxfaq.de",
  "nii": "urn:federation:MicrosoftOnline",
  "actortoken": "eyJ0eXAi.............IYlw",
  "nbf": 1653324960,
  "exp": 1653353760,
  "iss": "00000002-0000-0ff1-ce00-000000000000@<GUID des Tenant>",
  "aud": "00000002-0000-0ff1-ce00-000000000000/hybrid.msxfaq.de@<GUID des Tenant>"
}.

"nbf" steht für "Not before" und "exp" für Expire  in Sekunden seit 1.1.1970.  Die Differenz ergibt bei mir 28800 Sekunden = 8 Stunden. Interessanter ist aber die Identität. Die Cloud gibt vor, dass Sie der User "clouduser@msxfaq.de" ist und liefert dies als UPN, SIP und SMTP-Adresse. Das ist ein klassische "Delegation"-Aufruf, bei dem sich der Exchange Online Server im Auftrag des Anwender die Daten besorgt.

Kein User?

Der On-Premises Exchange Server hat diese Anfrage mit einem "No_User" quittiert. Für mich bedeutet das, dass der Exchange Server aus dem Bearer-Token die Identität nimmt und danach sucht. Also habe ich auf dem Exchange Server ein "Get-Recipient" mit der Mailadresse gemacht und leider den Benutzer nicht gefunden.

Was war auch nicht überraschend, denn das Postfach "clouduser@msxfaq.de" ist nur ein "CloudOnly-Postfach, welches im lokalen Active Directory nicht vorhanden ist. Um die Funktion bereitzustellen habe ich nun zwei Optionen:

  • AD Benutzer mit Remote Mailbox
    Das wäre die Heilung, wenn das Cloud-Postfach aus Versehen angelegt wurde und sowieso ein lokales Konto benötigt wird. Vielleicht ist es ja schon vorhanden aber wurde vergessen als RemoteMailbox zu aktivieren, so dass der lokale Exchange Server gar nicht weiß, dass es das Cloud-Postfach gibt.
  • MailContact oder MailUser
    Dies ist ein Sonderfall, wenn das Cloud-Postfach in ihrem On-Premises Exchange nicht als RemoteMailbox erscheinen darf. Sie können heute durchaus mehrere separate lokale Exchange Topologien mit einem ADSync in einen gemeinsamen Tenant replizieren. Allerdings brauchen Sie dann immer eine eigene Lösung, um die Empfänger zwischen den beiden Exchange Topologien abzugleichen.
    Der CloudOnly ist in dem Fall eigentlich eher eine RemoteMailbox aus einer anderen befreundeten Exchange Organisation, die schon in Tenant arbeitet.

Dem angefragten Exchange Server ist es letztlich egal, welcher Typ das lokale Objekt ist, solange es nur eine Mailadresse hat, die mit der Adresse im Bearer-Token übereinstimmt. Nachdem ein entsprechendes lokales Exchange Objekt angelegt wurde, konnte auch der Exchange Online Anwender die Frei/Belegt-Zeiten sofort abfragen. Es war keine Neuanmeldung o.ä. erforderlich, denn das Token war ja korrekt und ist beim Exchange Server auch angekommen.

Zusammenfassung

Diese Seite gehört sicher zu den etwas anspruchsvolleren technischen Erläuterungen von Zusammenhängen in einer Exchange Free/Busy-Konstellation. Sie sollten einfach mitnehmen, dass der Client immer seinen Heimatserver fragt, der sich dann im Auftrag des Anwenders die Frei/Belegt-Zeiten abholt und dabei eine Bearer-Authentication mit der Mailadresse des anfragenden Anwenders stellt.

Auf der anderen Seite muss der Exchange Server erst einmal "Bearer" als Authentifizierungsverfahren anbieten und ein ReverseProxy oder Firewall muss natürlich diese Anfragen ohne Preauthentication durchlassen. Zuletzt kann es aber noch daran scheitern, dass der anfragende Benutzer gar nicht im Zielsystem bekannt ist und daher ein "The user specified by the user-context in the token does not exist" generiert wird, den Sie aber mit Fiddler auf dem Client sogar einsehen können. Leider gibt es in Outlook selbst keinen einfachen Weg, diese Fehlermeldung sichtbar zu machen, denn die ETL-Dateien des Outlook Client Logging sind wohl nur für Microsoft zu decodieren. Da bleibt dann nur Fiddler oder ein ähnlicher Proxy mit der Fähigkeit auch TLS zu decodieren.

Damit Free/Busy funktioniert, müssen mehrere Zahnräder sauber ineinander greifen aber mit den richtigen Analysewerkzeugen, die auch in Verbindung mit Exchange Online jedem Exchange Administrator zur Verfügung stehen, können Sie Ursachenforschung betreiben.

Weitere Links