HCW Logging

Nicht immer geht bei der Installation und Konfiguration einer Exchange Hybrid Bereitstellung mit dem HCW - Hybrid Configuration Wizard alles glatt. Meist scheitert es an fehlenden Vorbedingungen. Neben der Anzeige des Fehlers auf der GUI gibt es aber eine ganze Menge an Protokolldateien, die Sie während der Installation, der Konfiguration aber auch später im Betrieb konsultieren können.

Übersicht

Leider gibt es nicht das eine Protokoll, in der alles steht, denn der HCW besteht ebenfalls aus einem Boot-Loader und dem eigentlichen Programm. Vielleicht lassen Sie durch den HCW auch noch einen Exchange Hybrid Agent installieren, der ebenfalls sein eigenes Log hat. So kommen einige Dateien und Pfade zusammen.

%Appdata%\Microsoft\Exchange Hybrid Configuration
%Appdata%\Microsoft\Exchange Hybrid Configuration\<YYYYMMDD_hhmmss>.log
%ProgramData%\Microsoft Hybrid Service\Logging
%ProgramData%\Microsoft\Microsoft Hybrid Service\Trace

Sie sehen aber auch, dass %appdata% kein systemweites Verzeichnis ist, sondern immer im Benutzerprofil des gerade aktiven Administrators liegt. Wen auf einem System der HCW von unterschiedlichen Personen gestartet wird und sie später den Durchlauf analysieren wollen, dann müssten Sie schon wissen, unter welchem Benutzer damals HCW gestartet wurde.

Nur die Protokolle für den Exchange Hybrid Agent liegen natürlich nicht im Benutzerverzeichnis sondern unter ProgramData. Schauen wir uns die einzelnen Pfade einmal an

%Appdata%\Microsoft\Exchange Hybrid Configuration

Die erste Anlaufstelle für Probleme und Analysen bezüglich dem Hybrid Configuration Wizard ist dieses Verzeichnis.

Hier landen in mehreren Dateien, die alle mit der Startzeitpunkt und einer passenden Extension benannt sind, die Aktionen des HCW in sehr ausführlicher Form. Allerdings verteilen sich die Daten auf fünf Dateien pro Lauf:

  • <YYYYMMDD_hhmmss>*.boot
    Logging des Programmstarts mit Download des richtigen HCW und Übergabe der Kontrolle.
  • <YYYYMMDD_hhmmss>.hybridconnector.log
    Protokolliert die Installation des Hybrid Connectors an sich, d.h. des Diensts, welcher sich dann zum AzureAD AppProxy verbindet.
  • Exchange Hybrid Configuration.cc
    JSON-Datei mit vermutlich einer Kopie der Konfiguration. Ich bin mir ziemlich sicher, dass die Konfiguration nicht im Appdata. Bei mir steht z.b. drin
{
   "CurrentDomain":"UCLABOR.DE",
   "Mode":"FullHybrid",
   "ObjectConfigTransfer":false,
   "ClientVersion":4785079012425728,
   "DateTimeUtcTicks":638664157746188278,
   "ServerVersion":4222129109925906,
   "MigrationEndpointIdentity":null,
   "ConnectorApplicationName":"eb92551b-9c63-4472-a8dc-2be7fcf00313",
   "LastConnectorChoice":true,
   "ConnectorFirstExperienceUtcTicks":637840181199095932
}
  • <YYYYMMDD_hhmmss>.xhcw
    Diese Datei enthält eine ausführliche Konfiguration als XML-Datei und eher für eine automatische Verarbeitung gedacht. Ich vermute, dass Microsoft diese XML-Datei im Fehlerfall in die Cloud hoch lädt und analysiert. Für ihre eigene Analysen ist die nächste Datei interessanter, da Sie zumindest die gleichen Fehler liefert.
  • <YYYYMMDD_hhmmss>.log
    Diese Textdatei enthält ein ausführliches und lesbares Format der Aktivitäten. Sie finden nicht nur die Analysen im Details sondern auch Zusammenfassungen, die ich im folgenden Abschnitt weiter beschreibe.

%Appdata%\Microsoft\Exchange Hybrid Configuration\.log

Die zentrale Datei des HCW-Lauf trägt einfach nur den Zeitstempel und die Erweiterung ".log". Sie liegt nicht in einem Programmverzeichnis sondern immer im %Appdata% des ausführenden Benutzers. Das macht eine spätere Fehlersuche oder Nachvollziehbarkeit natürlich kniffliger, wenn verschiedene Administratoren den HCW aufrufen. Kritisch ist das aber nicht, denn die eigentliche Konfiguration des HCW landet sowieso im Active Directory (Empfängerrichtlinien, OrganizationSharing, Send/Receive-Connector, Auth-Server und das Hybrid Configurtion Dokument). Insofern ist es egal, welcher Administrator den HCW erneut aufruft, das der HCW sich aus diesem Objekt die zuletzt aktive Konfiguration abholt. Dies sehen Sie auch im Logfile:

Sie können im Log aber auch viele Aufrufe und deren Ergebnis sehen, so dass Sie eigentlich nicht mit Fiddler oder einem anderen Proxy irgendwie den HTTPS-Datenstrom analysieren müssen. Hier ein Beispile eines fehlerfreien Auslesens einer Einstellung mittels GraphAPI eines Modern Hybrid Agent.

2024.11.05 14:22:42.542  10332 [Client=UX, fn=SendAsync, Thread=12] START GET https://graph.microsoft.com/beta/<guid1>/applications/<guid2>/onPremisesPublishing 
2024.11.05 14:22:42.725  10333 [Client=UX, fn=SendAsync, Thread=12] 
                                      FINISH Time=183,0ms Results=OK 
                                          {
                                             "@odata.context":"https://graph.microsoft.com/beta/$metadata#applications('<guid2')/onPremisesPublishing",
                                             "externalUrl":"https://<guid2>.resource.mailboxmigration.his.msappproxy.net/",
                                             "internalUrl":"https://ex01.uclabor.de/",
                                             "alternateUrl":null,
                                             "externalAuthenticationType":"passthru",
                                             "isTranslateHostHeaderEnabled":false,
                                             "isTranslateLinksInBodyEnabled":false,
                                             "isOnPremPublishingEnabled":true,
                                             "isHttpOnlyCookieEnabled":false,
                                             "isSecureCookieEnabled":false,
                                             "isPersistentCookieEnabled":false,
                                             "isBackendCertificateValidationEnabled":true,
                                             "applicationServerTimeout":"Default",
                                             "useAlternateUrlForTranslationAndRedirect":false,
                                             "applicationType":"","isStateSessionEnabled":true,
                                             "isAccessibleViaZTNAClient":false,
                                             "isDnsResolutionEnabled":false,
                                             "verifiedCustomDomainCertificatesMetadata":null,
                                             "verifiedCustomDomainKeyCredential":null,
                                             "verifiedCustomDomainPasswordCredential":null,
                                             "segmentsConfiguration":null,
                                             "singleSignOnSettings":{
                                                "singleSignOnMode":"none",
                                                "kerberosSignOnSettings":null
                                             },
                                             "onPremisesApplicationSegments":[]
                                          }
2024.11.05 14:22:42.735  10407 [Client=UX, Thread=12] Updating Local Client Configuration File

Sie können hier die <GUID2> der Azure Application sehen und zudem die interne URL des Servers. "ex01.uclabor.de" ist nicht aus dem Internet erreichbar.

Wenn ich den HCW, z.B. im Rahmen einer Fehlersuche (Siehe Hybrid Agent, Extended Protection und Port 9821) den HCW zu lange stehen lasse, dann kann ich einen Fehler provozieren, weil das OAUTH-Token abläuft: 

2024.11.05 17:03:33.432   10332 [Client=UX, fn=SendAsync, Thread=11] START PATCH https://graph.microsoft.com/beta/<guid1>/applications/<GUID2>
                                    {"onPremisesPublishing":
                                       {
                                          "applicationServerTimeout":"Default",
                                          "applicationType":"microsoftapp",
                                          "externalAuthenticationType":"passthru",
                                          "externalUrl":"https://<GUID2>.resource.mailboxmigration.his.msappproxy.net:443/",
                                          "internalUrl":"https://ex01.uclabor.de:443/",
                                          "isOnPremPublishingEnabled":true,
                                          "isTranslateHostHeaderEnabled":false,
                                          "isTranslateLinksInBodyEnabled":false,
                                          "singleSignOnSettings":null,
                                          "verifiedCustomDomainCertificatesMetadata":null,
                                          "verifiedCustomDomainKeyCredential":null,
                                          "verifiedCustomDomainPasswordCredential":null
                                       }
                                    }
2024.11.05 17:03:33.548   10333 [Client=UX, fn=SendAsync, Thread=11] FINISH Time=116,0ms Results=Unauthorized 
                                       {"error":
                                          {
                                             "code":"InvalidAuthenticationToken",
                                             "message":"Lifetime validation failed, the token is expired.",
                                             "innerError":{
                                                "date":"2024-11-05T17:03:33",
                                                "request-id":"1ca110ae-d8e2-4a4d-95aa-2ac52a32c6d9",
                                                "client-request-id":"1ca110ae-d8e2-4a4d-95aa-2ac52a32c6d9"
                                             }
                                          }
                                       }
2024.11.05 17:03:33.549   10407 [Client=UX, Thread=11] Updating Local Client Configuration File

Solche Fehler hat Microsoft z.B. nicht abgefangen und holt nicht mehr die neuen Anmeldedaten ein. Im Umkehrschluss bedeutet das dann aber auch, dass die Kennworte nicht irgendwo gespeichert wurden.

%ProgramData%\Microsoft Hybrid Service\Logging

Die beiden folgenden Verzeichnisse haben nur indirekt mit dem HCW selbst zu tun. Hier landen die Protokolle des Exchange Hybrid Agent.

Auszug aus MicrosoftHybridService_d0f72727-0d06-4aa0-bf9d-60fa82e7f2f4

Microsoft.Online.EME.Hybrid.Agent.Service.EXE Error: 0 : Web socket exception. 
   ConnectionId, '6add78f3-1d9c-43a8-b2b5-e40f23d174cd', 
   exception: 'System.Net.WebSockets.WebSocketException (0x80004005): An internal 
   WebSocket error occurred. Please see the innerException, if present, for more details.
   ---> System.IO.IOException: Unable to read data from the transport connection: An 
        existing connection was forcibly closed by the remote host. 
   ---> System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host

ProgramData%\Microsoft\Microsoft Hybrid Service\Trace

Interessanterweise produziert der gleichen Fehler in beiden Protokollen quasi die gleiche Meldung.

Auszug aus MicrosoftHybridService_478692a8-35dc-4782-b5ac-99446c86a1f7

Microsoft.Online.EME.Hybrid.Agent.Service.EXE Error: 0 : Web socket exception. 
  ConnectionId, '0c3a7a19-5a09-4173-8427-19d2e8107ca6', 
  exception: 'System.Net.WebSockets.WebSocketException (0x80004005): An internal 
    WebSocket error occurred. Please see the innerException, if present, for more details.  
    ---> System.IO.IOException: Unable to read data from the transport connection: An 
         existing connection was forcibly closed by the remote host. 
    ---> System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host

So richtig konnte ich mir noch nicht zusammenreimen, warum es beide Verzeichnisse gibt.

Eventlog

Auch im Windows Application Eventlog gibt es nun eine neue Source "Microsoft Hybrid Service", der aber zumindest bei mir sehr schweigsam ist:

 

Bei Kunden habe ich aber schon die ein oder andere Fehlermeldung gesehen. Ein Blick ins Eventlog kann also nie schaden.

Weitere Links