Windows Update ETLs manuell dekodieren

08 März 2018 AustrianBossfan it

Seit Windows 10 werden die Logfiles vom Windows Update Service nicht mehr in einfach lesbare Log-Dateien sondern in sogenannte Event Trace Logfiles (ETL) geschrieben. Wieder einmal eine ganz tolle Idee von Microsoft, die besonders dann hilfreich ist wenn es ans Troubleshooten von Windows Update Problemen geht (die soll es ja angeblich hin und wieder geben).

Die ETL Files haben 2 eklatante Nachteile:

  • man kann nicht mehr live (mittels tail oder anderen Tools) mitlesen
  • lokal gibt es das Powershell Cmdlet "Get-WindowsUpdateLog", welches die ETLs in ein lesbares Log dekodieren und auf den Desktop legen. Leider ist man nicht immer lokal unterwegs, schon gar nicht wenn man im Enterprise Umfeld tätig ist.

Manuelles dekodieren ist möglich, aber natürlich nicht so einfach wie man es gerne hätte. Dazu muss man wie folgt vorgehen:

Die Windows Update ETL Files befinden sich auf C:\Windows\logs\WindowsUpdate:

Mittels tracefmt.exe können diese ETLs nun in eine lesbares Logfile dekodiert werden:

tracefmt.exe -o windowsupate.log WindowsUpdate.20180308.103756.226.8.etl -r c:\Symbols

Möchte man mehrere ETLs auf einmal dekodieren, einfach durch Leerzeichen getrennt die entsprechenden Dateinamen angeben.

Das Ergebnis ist ein (halbwegs vernünftig) lesbares Logfile, wie man es von früheren Windows Versionen gewöhnt ist:

[0]0DA8.25DC::03/07/2018-14:37:26.883 [WUTraceLogging]{"name":"Misc","Info":"Got WSUS Client/Server URL: \"http://wsus.meine.firma.at/ClientWebService/client.asmx\""}
[0]0DA8.25DC::03/07/2018-14:37:26.900 [WUTraceLogging]{"name":"ProtocolTalker","Info":"OK to reuse existing configuration"}
[0]0DA8.25DC::03/07/2018-14:37:26.900 [WUTraceLogging]{"name":"ProtocolTalker","Info":"Existing cookie is valid, just use it"}
[0]0DA8.25DC::03/07/2018-14:37:26.900 [WUTraceLogging]{"name":"ProtocolTalker","Info":"PTInfo: Server requested registration"}
[0]0DA8.25DC::03/07/2018-14:37:26.916 [WUTraceLogging]{"name":"Misc","Info":"Got WSUS Reporting URL: \"http://wsus.meine.firma.at/ReportingWebService/ReportingWebService.asmx\""}
[0]0DA8.25DC::03/07/2018-14:37:26.916 [WUTraceLogging]{"name":"IdleTimer","Info":"WU operation (CLegacyEventUploader::HandleEvents) started; operation # 102; does use network; is at background priority"}
[0]0DA8.25DC::03/07/2018-14:37:26.916 [WUTraceLogging]{"name":"WebServices","Info":"Auto proxy settings for this web service call."}
[0]0DA8.25DC::03/07/2018-14:37:27.241 [WUTraceLogging]{"name":"IdleTimer","Info":"WU operation (CLegacyEventUploader::HandleEvents, operation # 102) stopped; does use network; is at background priority"}
[0]0DA8.246C::03/07/2018-14:47:27.250 [WUTraceLogging]{"name":"Agent","Info":"Earliest future timer found: "}
[0]0DA8.246C::03/07/2018-14:47:27.250 [WUTraceLogging]{"name":"Agent","Info":"    Timer: 29A863E7-8609-4D1E-B7CD-5668F857F1DB, Expires 2018-03-08 09:14:12, not idle-only, not network-only"}
[0]0DA8.13E0::03/07/2018-14:47:28.253 [WUTraceLogging]{"name":"Misc","Info":"CSusClientGlobal::DoServicePreShutdown"}
[0]0DA8.13E0::03/07/2018-14:47:28.253 [WUTraceLogging]{"name":"IdleTimer","Info":"Idle timer disabled in preparation for service shutdown"}
[0]0DA8.13E0::03/07/2018-14:47:28.253 [WUTraceLogging]{"name":"Misc","Info":"WUTaskManager uninit"}
[0]0DA8.13E0::03/07/2018-14:47:28.253 [WUTraceLogging]{"name":"Agent","Info":"Earliest future timer found: "}
[0]0DA8.13E0::03/07/2018-14:47:28.253 [WUTraceLogging]{"name":"Agent","Info":"    Timer: 29A863E7-8609-4D1E-B7CD-5668F857F1DB, Expires 2018-03-08 09:14:12, not idle-only, not network-only"}
[0]0DA8.13E0::03/07/2018-14:47:28.259 [WUTraceLogging]{"name":"Misc","Info":"CreateSessionStateChangeTrigger, TYPE:2, Enable:No"}
[0]0DA8.13E0::03/07/2018-14:47:28.259 [WUTraceLogging]{"name":"Misc","Info":"CreateSessionStateChangeTrigger, TYPE:4, Enable:No"}
[0]0DA8.13E0::03/07/2018-14:47:28.266 [WUTraceLogging]{"name":"Misc","Info":"Agent uninit"}
[0]0DA8.13E0::03/07/2018-14:47:28.269 [WUTraceLogging]{"name":"Misc","Info":"Reporter uninit"}
[0]0DA8.13E0::03/07/2018-14:47:28.269 [WUTraceLogging]{"name":"Misc","Info":"network cost manager uninit"}
[0]0DA8.13E0::03/07/2018-14:47:28.269 [WUTraceLogging]{"name":"Misc","Info":"Eventer uninit"}
[0]0DA8.13E0::03/07/2018-14:47:28.269 [WUTraceLogging]{"name":"Misc","Info":"ServiceManager uninit"}
[0]0DA8.13E0::03/07/2018-14:47:28.270 [WUTraceLogging]{"name":"Misc","Info":"PersistentTimeoutScheduler uninit"}
[0]0DA8.13E0::03/07/2018-14:47:28.270 [WUTraceLogging]{"name":"Misc","Info":"datastore uninit"}
[0]0DA8.13E0::03/07/2018-14:47:28.297 [WUTraceLogging]{"name":"Misc","Info":"setting cache uninit"}
[0]0DA8.13E0::03/07/2018-14:47:28.297 [WUTraceLogging]{"name":"Misc","Info":"security checker uninit"}
[0]0DA8.13E0::03/07/2018-14:47:28.297 [WUTraceLogging]{"name":"Misc","Info":"Test Hook uninit"}
[0]0DA8.13E0::03/07/2018-14:47:28.297 [WUTraceLogging]{"name":"Misc","Info":"IdleTimer uninit"}
[0]0DA8.13E0::03/07/2018-14:47:28.299 [WUTraceLogging]{"name":"Shared","Info":"* END * Service exit Exit code = 0x240001"}

 

 

Windows Server 2016 WSUS

07 September 2017 AustrianBossfan it

Heute habe ich zum ersten Mal WSUS (Windows Server Update Services) unter Windows Server 2016 installiert. Ich betreibe WSUS seit mehreren Windows-Generationen und habe damit eigentlich gute Erfahrungen gemacht, doch unter Windows Server 2016 wollte es von Anfang an nicht so richtig funktionieren. Die Installation ist genauso einfach wie früher auch: WSUS Rolle installieren, Post Installation Wizard ausführen, Initial Syncronization laufen lassen und Updates approven.

Nun sollten die WSUS-Clients verbinden und Updates installieren können. Dachte ich, doch es trat bei jedem Sync folgender Fehler auf:

Windows Update Error 0x8024401c

Im Prinzip ist das ein genersicher Timeout. Die Clients waren in der WSUS Console sichtbar, aber hatten alle den Status "Not reported yet". Also prinzipiell konnten sie zum WSUS Service verbinden, aber dann sind sie in ein Timeout gelaufen.

Wie üblich begann ich das Problem einzugrenzen, was ja seit Windows 10 / Windows Server 2016 ganz schön schwierig geworden ist, da man nicht mehr live die Logfiles des Windows Update Clients mitlesen kann (ETL sei dank). Powershell und Get-WindowsUpdateLogs sind nun zu verwenden. Wie komfortabel, wenn man das alle 2 Minuten neu ausführen muss wenn man die aktuellen Log-Einträge lesen will. Das Zeug das die in Redmond gesoffen haben, als sie sich das ausgedacht haben, würde ich gerne mal probieren... ;-)

Dank Google und diversen Foren kam ich nach Stunden des Stöberns und Tüftelns auf die Lösung des Problems:

In der IIS Console muss am WSUS Application Pool (Advanced Settings) folgendes geändert werden:

  • General\Queue Length: 2500
  • CPU\Limit interval (minutes): 15
  • Rapid-Fail Protection\"Service Unavailable" Response: TcpLevel
  • Recycling\Private Memory Limit (KB): 0

Danach konnten die Clients die Updates herunterladen und installieren.