Debugging shutdown issues on Windows 2003 with Winlogon tracing

By Andrei Ungureanu - Last updated: Monday, May 21, 2012 - Save & Share - Leave a Comment

Una din marile probleme cu Windows 2003 atunci cand faci administrare remote e ca nu stii niciodata daca atunci cand dai reboot sistemul tau reuseste sa se restarteze sau nu.

Windows 2008 e ceva mai avansat, dar nu pentru ca nu ar exista astfel de probleme ci pentru ca exista ceva procedee si tool-uri pentru a afla cauza problemei.

In schimb pe Windows 2003, tot ce stiam pana de curand era faza cu generearea unui crash dump in momentul in care sistemul “intepenea” in fereastra de shutdown.

Dar am aflat ca se mai poate face ceva ce poate ajuta in debugging. Si anume tracing pe Winlogon. Faza e ca nu merge activat in versiunea normala de Windows (free/retail build) ci numai in “checked/debug build”. Dar merge inlocuit si doar Winlogon.exe cu versiunea checked pe durata troubleshooting-ului. In caz ca nu aveti access la MSDN sa downloadati checked build, puteti downloada Service Pack 2 pentru Windows 2003 versiunea checked. Mai jos aveti link-ul pentru versiunea x86:

http://www.microsoft.com/en-us/download/confirmation.aspx?id=3685

Pasul urmator este sa setati urmatoarele variabile in registry:

HKLM\SOFTWARE\Microsoft\Windows NT\CurrentVersion\Winlogon\DebugFlags (REG_SZ)

HKLM\SOFTWARE\Microsoft\Windows NT\CurrentVersion\Winlogon\LogFile (REG_SZ)

Pentru a capta toate evenimentele va recomand sa setati DebugFlags cu urmatoarea valoare: Error, Warning, Trace, Init, Timeout, Sas, State, MPR, CoolSwitch, Profile, DebugLsa, DebugSpm, DebugMpr, DebugGo, Migrate, DebugServices, Setup, SC, Notify, Job

image

Si iata si cum arata log-ul:

14:52:06.936: 360.1956> Winlogon-Trace: Doing remote-initiated (W2K3\Administrator) Reboot=true, Force=true

14:52:06.951: 360.1956> Winlogon-Trace: Starting user thread for Logoff, flags = 3807

14:52:06.951: 360.2616> Winlogon-Trace: Doing immediate shutdown, LastGinaRet = b, Flags = 3804

14:52:06.951: 360.2616> Winlogon-Trace: Calling ExitWindowsEx(0x3804, 0)

14:52:07.842: 360.364> Winlogon-Trace-SAS: LOGONNOTIFY message 0

14:52:07.842: 360.364> Winlogon-Trace-SAS:     WINLOGON     : True

14:52:07.842: 360.364> Winlogon-Trace-SAS:     SYSTEM       : False

14:52:07.842: 360.364> Winlogon-Trace-SAS:     SHUTDOWN     : False

14:52:07.842: 360.364> Winlogon-Trace-SAS:     REBOOT       : False

14:52:07.842: 360.364> Winlogon-Trace-SAS:     POWEROFF     : False

14:52:07.842: 360.364> Winlogon-Trace-SAS:     FORCE        : True

14:52:07.842: 360.364> Winlogon-Trace-SAS:     OLD_SYSTEM   : False

14:52:07.842: 360.364> Winlogon-Trace-SAS:     OLD_SHUTDOWN : True

14:52:07.842: 360.364> Winlogon-Trace-SAS:     OLD_REBOOT   : True

14:52:07.842: 360.364> Winlogon-Trace-SAS:     OLD_POWEROFF : False

14:52:07.842: 360.364> Winlogon-Trace: Received SAS from winsrv, code 4 (User Logoff)

14:52:07.842: 360.364> Winlogon-Trace: In state LoggedOnUser, sending kill message to window

14:52:07.842: 360.364> Winlogon-Trace: Sending SAS code 4 (User Logoff) to window 50020 (Winlogon generic control dialog)

14:52:07.842: 360.364> Winlogon-Trace: ChangeStateForSAS: Went from 6 (LoggedOnUser) to 7 (LoggedOn_SAS)

14:52:07.842: 360.364> Winlogon-Trace: Source desktop was Default

14:52:07.842: 360.364> Winlogon-Trace: Switching desktop from Application to Winlogon

14:52:07.842: 360.364> Winlogon-Trace-State: SASRouter:  In state LoggedOn_SAS

14:52:07.842: 360.364> Winlogon-Trace-Timeout: Disabling timeouts

14:52:07.842: 360.364> Winlogon-Trace: In Logoff()

14:52:07.842: 360.364> Winlogon-Trace: Switching desktop from Winlogon to Application

14:52:07.842: 360.364> Winlogon-Trace: Closing handle 3a8 to users desktop

14:52:07.857: 360.1468> Winlogon-Trace: StopUserGPOProcessing: Waiting for user group policy thread to terminate.

14:52:07.857: 360.1468> Winlogon-Trace: StopUserGPOProcessing: User group policy thread has terminated.

14:52:07.951: 360.364> Winlogon-Trace: Source desktop was Default

14:52:07.951: 360.364> Winlogon-Trace: Switching desktop from Application to Winlogon

14:52:07.967: 360.364> Winlogon-Trace: ProfileUserMapping Refs = 2

14:52:07.967: 360.364> Winlogon-Trace: ProfileUserMapping Refs = 1

14:52:07.967: 360.364> Winlogon-Error: [WUInstall] Failed to query WU value (2).

14:52:07.967: 360.364> Winlogon-Error: [WUInstall] Failed to clean WU value (2).

14:52:07.967: 360.364> Winlogon-Trace: Actually closing user mapping

14:52:07.967: 360.364> Winlogon-Trace: ProfileUserMapping Refs = 0

14:52:07.967: 360.3220> Winlogon-Trace: ExitWindowsEx called to shut down COM processes

14:52:07.998: 360.364> Winlogon-Trace: ProfileUserMapping Refs = 0

14:52:07.998: 360.364> Winlogon-Trace: Actually opening user mapping.  User is logged on

14:52:07.998: 360.364> Winlogon-Trace: ProfileUserMapping Refs = 1

14:52:08.014: 360.364> Winlogon-Trace: Actually closing user mapping

14:52:08.014: 360.364> Winlogon-Trace: ProfileUserMapping Refs = 0

14:52:08.014: 360.364> Winlogon-Trace: In InternalWinStationNotifyLogoff

14:52:08.014: 360.2540> Winlogon-Error: [WUInstall] Skipping WU installs – Fail to open WU key (2).

14:52:08.154: 360.2540> Winlogon-Trace: [WUInstall] Skipping installs – not a shutdown.

14:52:08.154: 360.2540> Winlogon-Trace: [WUInstall] Skipping installs – not requested.

14:52:08.154: 360.2540> Winlogon-Trace: [WUInstall] Calling WUAutoUpdateAtShutdown(0)…

14:52:08.186: 360.2624> Winlogon-Trace: StopMachineGPOProcessing: Waiting for machine group policy thread to terminate.

14:52:08.201: 360.2624> Winlogon-Trace: StopMachineGPOProcessing: Machine group policy thread has terminated.

14:52:08.295: 2516.2280> Winlogon-Trace-SAS: LOGONNOTIFY message 9

Acum nu pot promite ca aceasta metoda o sa va rezolve problemele, insa este unul din putinele moduri in care poti face troubleshooting la asa ceva pe Windows 2003.

PS: mai sunt cateva variante cu windows debugger insa mi se par prea complicate pentru un sysadmin.

Posted in Windows Server • Tags: , Top Of Page

Write a comment