IIS Failed Request Tracing

Auf der Seite IIS - Webserver Troubleshooting habe ich einige Möglichkeiten zur Analyse von IIS-Problemen beschrieben. Für das aus meiner Sicht sehr leistungsfähige Feature "IIS Failed Request Tracing" habe ich aber eine eigene Seite spendiert.

Einsatz

Oftmals sehen Sie im IISLog zwar die Zugriffe mit der URL und die Fehlercodes aber keine Details. Wenn Sie z.B. viele 401-Fehler sehen, dann können Sie im Windows Security Eventlog vielleicht ermitteln, welche NTLM-Anmeldungen fehlgeschlagen sind, aber der 401-Fehler an sich kann auch andere fehlerhafte Anmeldungen berichten. Hier wäre es dann hilfreich, wenn wir als Administrator z.B. den Request des Clients im Klartext, die Verarbeitung durch den IIS und die Rückantwort an den Client analysieren könnten.

Bei unterschlüsselten Verbindungen können Sie auch per WireShark die TCP-Connection mitschneiden aber da heute alles per HTTPS/TLS verschlüsselt ist, fällt diese Möglichkeit immer häufiger aus. Hier komme dann das "IIS Failed Request Tracing" zum Einsatz.

Installation

Voraussetzung ist, dass Sie das Feature "Tracing" installiert haben

Aktivierung pro Webseite

Im zweiten Schritt muss das Features auf der jeweiligen Webseite noch aktiviert werden.

Aktivierung pro Verzeichnis

Und dann müssen Sie auf dem jeweiligen virtuellen Verzeichnis ebenfalls noch genauer hinterlegen, welche Fehler sie denn protokollieren lassen wollen.

Auswerten mit Parse-FREBLogs

Das Ergebnis sind dann für jeden Request, auf den die Bedingungen zutreffen, entsprechende XML-Dateien in dem anfangs angegebenen Pfad.

Probieren Sie es einfach mal aus. Es ist schon erstaunlich wie detailliert diese XML-Dateien in einem Internet Explorer den Ablauf der Anforderung ausgeben. Fast immer finden Sie heraus, warum und wo der Fehler aufgetreten ist. Sehr oft kann man sogar erkennen, an welcher Stelle eine Anfrage getrödelt hat. Also auch für Performanceprobleme kann dies ein erster Ansatz sein. Richten Sie bitte diese Funktion aber nicht für "jeden" Request ein und vergessen Sie nicht die Funktion nach ein paar Ausgaben wieder abzuschalten. Diese zusätzliche Arbeit belastet den Server durchaus.

Zudem kann es ziemlich mühsam sein, die "richtigen" Dateien ausfindig zu machen. Daher habe ich mir ein kleines Skript welches zu jeder Datei die URLs etc. ausgibt:

# parse-freblogs.ps1

param (
   $path = "C:\inetpub\logs\FailedReqLogFiles\W3SVC1"
)

Write-Verbose "Gettings Files from $($path)"
foreach ($file in (get-childitem "$($path)/*.xml")){
   Write-Verbose "Processing $($file.name)"
   $content = [xml](get-content $file)
   $content.failedRequest | select @{name="Filename"; expr={$file.name}},verb,statuscode,url,authenticationtype,username
}

So kann ich dann zumindest anhand der URLs etc. schnell weiter filtern und die nicht erforderlichen Dateien gleich wieder löschen, z.B. mit:

.\parse-freblogs.ps1 `
| where {$_.url -eq "https://localhost:443/ews/"} `
| Foreach {Remove-Item 
"C:\inetpub\logs\FailedReqLogFiles\W3SVC1\$($_.filename)"}

.\parse-freblogs.ps1 `
| where {$_.url -like "*healthcheck.htm"} `
| Foreach {Remove-Item "C:\inetpub\logs\FailedReqLogFiles\W3SVC1\$($_.filename)"}

Gerade auf einem Exchange Server gibt es doch relativ viel Grundrauschen durch die Selbstüberwachung (Exchange 2013 Managed Availability) auf healtcheck.htm.

FEB.XML in Edge anzeigen

Früher konnten Sie die XML-Dateien per Doppelklick im Internet Explorer anzeigen lassen.

Allerdings ist der IE mittlerweile natürlich veraltet. Der neue Edge-Browser zeigt aber nur hier nur eine leere Seite, weil er aus Sicherheitsgründen keine "file://-Urls" mehr mit öffnet. Und genau das ist der Verweis auf die XSLT-Datei. Starten Sie daher den Edge mit folgendem Parameter:

C:> start msedge.exe --allow-file-access-from-files

Dazu müssen vorher aber alle Edge-Instanzen geschlossen sein.

Copy-FREBEvents u.a. 3rd Party Tools

FREB muss schnell sein und daher schreibt es nur ganz flott die Ausgaben in eine Datei. Der Windows Explorer kennt aber keine Metadaten und so können Sie keine Spalten mit den URL o.. anzeigen. Wenn Sie auf einem Testsystem ein paar Requests analysieren oder auf einen Produktionssystems sich auf eine bestimmte URL bzw. HTTP-Fehlernummer beschränken können, dann habe sie ein paar XML-Dateien zu scannen. Das skaliert aber nicht, wen Sie hunderte oder mehr Dateien durchsuchen wollen. Dann ist die Zeit für andere Tools, die alle Dateien anlesen und einen einfacheren Zugang gewähren.

Für mich ist natürlich PowerShell das erste Mittel, um auf einem Server schnell einen Überblick zu bekommen. Neben dem kleinen Skript "parse-freblogs.ps1", welches ich weiter oben schon bereitgestellt habe, habe ich mir noch ein "Copy-Script gebaut, welches die fraglichen XML-Dateien anhand der Inhalte in ein anderes Verzeichnis kopiert.

# Copy-FREBEvents
#
# Grab FREBLogs with specific request data

[cmdletbinding()]
param(
   $directory = "C:/inetpub/logs/FailedReqLogFiles/W3SVC1/*.xml" ,
   $url = "*/EWS/mrsproxy.svc" ,
   $headercontains = "*" ,
   $destination = "C:/inetpub/logs/FailedReqLogFiles/W3SVC1/filter/"
)

Write-Verbose "Copy-FREBEvents:Start"
Write-Verbose "Copy-FREBEvents:Parameter:directory  :$($directory)"
Write-Verbose "Copy-FREBEvents:Parameter:url        :$($url)"
Write-Verbose "Copy-FREBEvents:Parameter:destination:$($destination)"

if (!(Test-path -path $destination -pathtype container)) {
   Write-Verbose "Create Destination $($destination)"
   mkdir $destination | out-null
}

foreach ($item in (Get-item $directory)){
   Write-Verbose " Processing File $($item.fullname)"
   [xml]$content = get-content -path $item.fullname
   if ($content.failedRequest.url -like $url) {
      Write-Verbose " MATCH URL"
      $ReqHeader = (($content.failedRequest.Event `
                   | where {$_.RenderingInfo.Opcode -eq "GENERAL_REQUEST_HEADERS"}).eventdata.data `
                   | where {$_.name -eq "Headers"}).'#text'
      if ($RegHeader -like $headercontains) {
         Write-Verbose " MATCH HeaderContains"
         copy-item -path $item.fullname -destination $destination
      }
   }
}

Write-Verbose "Copy-FREBEvents.End"

Das Beispiel sucht gezielt die Anfragen an "/EWS/MRSPROXY.svc" nach den angegebenen Strings im Header, z.B. eine Authentifizierung, ein UserAgent o.ä. Ich habe das Skript z.B. bei der Analyse von MRS und Extended Protection eingesetzt und so herausgefunden, dass Exchange Online eine NTLM-Anmeldung nutzt, die mit Extended Protection nur bei Erfüllung aller Voraussetzungen funktioniert.

Es gibt aber noch weitere Tools wie z.B.:

Weitere Links