Was macht die "Zeit" - Feld in das Protokoll zeigen, genau?

Ich studiert habe in der W3C-format-log-Dateien im IIS 7.5 eine Weile auf einem server mit einige performance-Probleme, und es scheint mir, dass, im Gegensatz zu MSDN-Dokumentation, die "Zeit" - Feld ist nicht

"die Zeit, in Coordinated Universal Time (UTC), zu der die Anforderung aufgetreten"

... sondern es ist der Zeitpunkt, zu dem die Reaktion beendet war, gesendet.

Ich sage dies, weil wenn ich Spur die Reihenfolge der Anforderung der Seite vom Benutzer in einer einigermaßen kontrollierten Umgebung, würden Sie haben zu gehen zurück in die Zeit, die zum senden der nächsten Anforderung, sonst werden Sie in der Lage, um Ihre Anfragen für Seiten, die erschreckend schnell für eine Seite mit einem großen Zeit-Eintrag genommen.

Zum Beispiel (und ich bin schwärzen, abkürzen und weglassen, für Sicherheit und Klarheit):

#Fields: date time s-ip cs-method cs-uri-stem cs-uri-query s-port cs-username c-ip sc-status sc-substatus sc-win32-status time-taken
2012-11-28 22:25:17 192.168.0.21 GET /Main.aspx - 80 AWalker 192.168.0.100 200 0 0 764
2012-11-28 22:25:26 192.168.0.21 POST /Main.aspx - 80 AWalker 192.168.0.100 200 0 0 109
2012-11-28 22:25:56 192.168.0.21 GET /_Start.aspx - 80 AWalker 192.168.0.100 302 0 0 28782
2012-11-28 22:26:33 192.168.0.21 GET /Action.aspx - 80 AWalker 192.168.0.100 200 0 0 38032
2012-11-28 22:26:46 192.168.0.21 POST /Action.aspx - 80 AWalker 192.168.0.100 200 0 0 124
2012-11-28 22:27:39 192.168.0.21 GET /Information.aspx - 80 AWalker 192.168.0.100 200 0 0 52509
2012-11-28 22:27:52 192.168.0.21 POST /Information.aspx - 80 AWalker 192.168.0.100 200 0 0 140

Wenn ich interpretiere "Zeit" als "Anfrage erhalten" (entweder Anfang oder Ende, aber bevor die Reaktion beginnt), dann sieht das falsch. Hier ist, was ich meine:

• Um 22:25:17, die BEKOMMEN /Main.aspx empfangen wurde, und es dauerte 764ms zu liefern, die Reaktion, was bedeutet, dass die Antwort nicht beendet, bis 14:25:17.764.
• Um 14:25:26, die POST /Main.aspx empfangen wurde. Das ist acht Sekunden nach der vorherigen Antwort fertig. Es dauerte 109ms zu liefern, diese Antwort, und endet bei 14:25:26.109.
• Um 14:25:56, die für /_Start.aspx empfangen wurde. Das sind fast 30 Sekunden nach der vorherigen Antwort fertig. Dies scheint angebracht, die der Benutzer studiert haben Main.aspx bevor Sie auf den link, um _Start.aspx. Es dauerte, seltsam, fast 29 Sekunden, um diese 302 Redirect-Antwort (28782ms), und endet bei 14:26:24.782. Aber das ist, warum ich freue mich auf die Protokolle, um herauszufinden, warum.
• Um 14:26:33, das man für /Aktion.aspx empfangen wurde. Das ist etwa 8 Sekunden nach der vorherigen Antwort fertig. Das scheint angemessen (8 Sekunden Antwortzeit für die Benutzer). Die Reaktion nahm 38032ms (viel zu lang, daher der Untersuchung), und fertig um 14:27:11.032.
• Um 14:26:46, der POST /Aktion.aspx empfangen wurde. Das ist 8,2 Sekunden vor die bisherige Antwort fertig. Ja, ich bin mir voll bewusst, dass die Nutzer nicht immer zu warten, bis die Seite vollständig gerendert, bevor Sie auf einen link, um sich die nächste Seite, oder drücken Sie Aktualisieren, aber es passiert eine Menge, auch für viel kürzere Anfragen. Die Reaktion nahm 124ms, und endet bei 14:26:46.124.
• Um 14:27:39, die BEKOMMEN für, Informationen.aspx empfangen wurde. Das ist mit 52,9 Sekunden nach der vorherigen Antwort fertig. Das scheint mir ein wenig lange, da waren die Tester gesagt, schlug das system so hart wie Sie konnte, aber es ist nicht unangemessen lang ist. Die Reaktion nahm 52509ms (fast genau 52.9 Sekunden!), finishing um 14:28:31.509. Das ist ein sehr seltsamer Zufall, dass passiert sehr oft wenn ich interpretieren die Uhrzeit-Feld als "Anfrage erhalten".
• Um 14:27:52 die POST für Informationen.aspx empfangen wurde. Das ist 39.5 Sekunden vor die bisherige Antwort fertig.

Diese Art von Muster immer wieder, über und über, in den logs.

Umgekehrt, wenn ich zu interpretieren, den "Zeit" - Feld, um meine "Antwort fertig", dann bekomme ich saner zahlen:

• Gegen 14:25:16.236 (764ms vor 14:25:17), die für /Main.aspx empfangen wurde, und es dauerte 764ms zu liefern, beenden die Antwort um 14:25:17.
• Gegen 14:25:25.891, der POST /Main.aspx empfangen wurde. Das sind etwa 8,9 Sekunden nach der vorherigen Antwort fertig. Es dauerte 109ms zu liefern, diese Antwort, und endet bei 14:25:26.
• Gegen 14:25:27.218, die für /_Start.aspx empfangen wurde. Das ist 1,2 Sekunden nach der vorherigen Antwort fertig. Das ist schnell für eine Reaktion vom Benutzer, aber nicht zu viel für diese gut ausgebildeten Testern die Navigation durch ein bekanntes Menü. Die Reaktion nahm 28,782 ms (zu lange, aber dies ist die Ursache für die performance-Analyse), und fertig um 14:25:56.
• Gegen 14:25:54.968, die für /Aktion.aspx empfangen wurde. Das ist etwa 1,0 Sekunde vor die bisherige Antwort fertig war. Das könnte ein Rundungsfehler, da das Feld nicht erfassen Millisekunden. Die Reaktion nahm 38032ms, und fertig war um 14:26:33.
• Um etwa 14:26:45.876, der POST /Aktion.aspx empfangen wurde. Das ist ungefähr 12.9 Sekunden nach der vorherigen Antwort fertig. Das ist ziemlich normal, dass eine Antwortzeit für die Benutzer. Die Reaktion nahm 124ms, und fertig war um 14:26:46.
• Um etwa 14:26:46.491, die BEKOMMEN für, Informationen.aspx empfangen wurde. Dies war etwa 0,5 Sekunden nach der vorherigen Antwort fertig. Das könnte eine Skript-initiierte umleiten oder einen fast-user. Die Reaktion nahm 52509ms, und fertig um 14:27:39. Langsame Seite.
• Um etwa 14:27:51.860, der POST /Informationen.aspx empfangen wurde. Das war ungefähr 12.9 Sekunden nach der vorherigen Antwort fertig. Normale Antwortzeit für die Benutzer (zufällig der gleiche wie der Vorherige POST). Die Reaktion nahm 140ms, und fertig um 14:27:52.

Anderen Grund, es macht einfach mehr Sinn für mich, dass die "Zeit" - Feld für das Ende der Reaktion, vielmehr als den Anfang der Anforderung ist diese:

Die log-Einträge aufgezeichnet werden physisch in aufsteigender Reihenfolge von der "Zeit" - Feld (chronologisch geordnet), aber Sie enthalten immer die "Zeit genommen" - Feld, die nur bekannt nach die Antwort war schließlich geliefert.

So, welche Art ist es? Ist die Dokumentation falsch?