Samstag, 23. Mai 2009

Benutzerkonto kann auf Server nicht abgemeldet werden

Kürzlich kam mir bei einem Kunden folgendes Problem unter. Nachdem ich mich auf einem seiner Server angemeldet hatte, konnte ich mich nicht wieder abmelden. Auf den Befehl Abmelden aus dem Startmenü reagierte die Maschine nicht. Auch Herunterfahren oder Neustarten (das ja den Abmeldevorgang beinhaltet) konnte man nicht durchführen. Nur mit Hilfe des Befehls shutdown.exe und dessen Schalter -f (für force, zu deutsch erzwingen) konnte die Maschine zum Neustart bewegt werden. Das Problem konnte erst seit kurzem bestanden haben da laut übereinstimmender Aussage des lokalen IT Personals der Abmeldevorgang vor kurzem noch anstandslos funktioniert hatte.

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
USERENV(180.184) 17:50:10:053 CSyncManager::EnterLock: No existing entry found
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) 1
7: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