Im Ereignisprotokoll fand sich folgende Warnung:
Event Type: Warning
Event Source: USER32
Event Category: None
Event ID: 1073
Date: 23.05.2009
Time: 19:35:29
User: DOMAIN\Administrator
Computer: SERVER
Description: The attempt by user DOMAIN\Administrator to restart/shutdown computer SERVER failed
For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.
Data: 0000: 80 48 3e 77 H>w
Typisch in so einem Fall ist, dass Programme noch einen Handle auf eine Datei und/oder die Registry des aktuell angemeldeten Benutzers offen lassen und so das Entladen des Profils verhindern. Um diese Theorie zu untermauern habe ich zuerst das User Environment Loggin aktiviert:
How to enable user environment debug logging in retail builds of Windows
http://support.microsoft.com/kb/221833/EN-US/
Das Logfile war leider beim Abmeldevorgang nicht ergiebig und zeigte überhaupt keinen Eintrag. Eine genauere Analyse zeigte, dass man nach dem Neustart sich einmal abmelden konnte. Ab der zweiten Abmeldung schlug diese fehl. Die erste Abmeldung schien zu klappen:
USERENV(1630.1624) 17:50:05:768 LibMain: Process Name: C:\WINDOWS\system32\userinit.exe
USERENV(180.184) 17:50:10:037 UnloadUserProfile: Entering, hProfile = <0x828>
USERENV(180.184) 17:50:10:053 UnloadUserProfile: In console winlogon process
USERENV(180.184) 17:50:10:053 UnloadUserProfileP: Entering, hProfile = <0x828>
USERENV(180.184) 17:50:10:053 GetExclusionListFromRegistry: Policy list is empty, returning user list =
USERENV(180.184) 17:50:10:053 CSyncManager::EnterLock: New entry created
USERENV(180.184) 17:50:10:053 CHashTable::HashAdd: S-1-5-21-1801674531-1677128483-839522115-500 added in bucket 5
USERENV(180.184) 17:50:10:053 UnloadUserProfileP: Wait succeeded. In critical section.
USERENV(180.184) 17:50:10:491 MyRegUnLoadKey: Returning 1.
USERENV(180.184) 17:50:10:491 UnloadUserProfileP: Succesfully unloaded profile
USERENV(180.184) 17:50:10:678 MyRegUnLoadKey: Returning 1.
USERENV(180.184) 17:50:10:678 UnLoadClassHive: Successfully unmounted S-1-5-21-1801674531-1677128483-839522115-500_Classes
USERENV(180.184) 17:50:10:678 UnloadUserProfileP: Successfully unloaded user classes
USERENV(180.184) 17:50:10:710 UnloadUserProfileP: Impersonated user
USERENV(180.184) 17:50:10:710 UnloadUserProfileP: Writing local ini file
USERENV(180.184) 17:50:10:710 UnloadUserProfileP: Reverting to Self
USERENV(180.184) 17:50:10:710 UnloadUserProfileP: exitting and cleaning up
USERENV(180.184) 17:50:10:710 CSyncManager::LeaveLock
USERENV(180.184) 17:50:10:710 CSyncManager::LeaveLock: Lock released
USERENV(180.184) 17:50:10:710 CHashTable::HashDelete: S-1-5-21-1801674531-1677128483-839522115-500 deleted USERENV(180.184) 17:50:10:710 CSyncManager::LeaveLock: Lock deleted
USERENV(180.184) 17:50:10:710 UnloadUserProfileP: Leave critical section.
USERENV(180.184) 17:50:10:710 UnloadUserProfileP: Leaving with a return value of 1
USERENV(180.184) 17:50:10:710 UnloadUserProfile: UnloadUserProfileP succeeded
USERENV(180.184) 17:50:10:710 UnloadUserProfile: returning 1
USERENV(fe0.ac4) 17:52:43:285 InitializePolicyProcessing: Initialised Machine Mutex/Events
USERENV(fe0.ac4) 17:52:43:285 InitializePolicyProcessing: Initialised User Mutex/Events
USERENV(fe0.ac4) 17:52:43:285 LibMain: Process Name: \??\C:\WINDOWS\system32\winlogon.exe
USERENV(180.184) 17:52:46:333 LoadUserProfile: Yes, we can impersonate the user. Running as self
Doch bei der zweiten Anmeldung konnte man sehen, dass das Profil in Wahrheit gar nicht vollständig entladen werden konnte:
USERENV(128c.1270) 17:52:46:973 GetProfileType: Profile already loaded.
In so einem Fall ist immer installierte Drittanbieter-Software verdächtig. Hier hilft das Programm msconfig.exe mit deren Hilfe man selektiv Drittanbieterdienste deaktivieren kann:
Sukzessives Ab- und wieder Anschaltern der Dienste ergab den Bösewicht. Es war das Dienst LanSafe Power Monitor. Er gehört zur USV des Kunden und löst im Fall eines Stromausfalls einen kontrollierten Shutdown aus. Mithilfe des Process Explorer von Sysinternals (http://technet.microsoft.com/de-de/sysinternals/bb896653.aspx) zeigt sich, dass der Dienst als Kind auch ein Starmenü-Tray Applet als Kindprozess startet:
Nachdem der Dienst selbst nicht in der Benutzersitzung läuft richtet sich der Verdacht gegen das kleine Hilfsprogramm. Tatsächlich: Beendet man das Programm unsanft wird der Abmeldevorgang sofort anstandslos durchgeführt. Leider hatte der Kunde bereits die aktuelle Version der Software im Einsatz sodass ein Update auf eine neue Version nicht möglich war.
Nachdem der Fehler erst seit kurzem Aufgetreten war, setzte ich eine virtuelle Maschine auf um das Problem hier zu reproduzieren. Die Updates wurden der Reihe nach eingespielt und der Fehler zu reproduzieren versucht. Er trat auf nach dem Einspielen des Internet Explorer 7 bzw. 8. Tatsächlich hatte der Kunde vor kurzem auf den IE7 aktualisiert. Konkret war offenbar das Update IDNMitigationAPIs verantwortlich, das als Voraussetzung für den IE7 (und 8) installiert wird. Es findet sich leider recht wenig Information im Internet, was dieses Hotfix im Detail bewirkt.
Der Hersteller gibt weder in den Release Notes noch in der Dokumentation Probleme mit dem IE7 an, ich habe daher empfehlen den Hersteller zu kontaktieren und in der Zwischenzeit die Tray Applikation manuell zu beenden.
Keine Kommentare:
Kommentar veröffentlichen