Linie logu Apache pojawiają się poza kolejnością - dlaczego?

Question

Mam serwer WWW Apache, a gdy pewien użytkownik uzyskuje dostęp do określonej strony, otrzymuję wiersz dziennika, którego znacznik czasu nie jest zsynchronizowany.

Próbka wyjściowa:

IP1 - - [22/Jun/2009:12:20:40 +0000] "GET URL1" 200 3490 "REFERRING_URL1" "Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.1; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.04506.648; .NET CLR 3.5.21022)" 

IP2 - - [22/Jun/2009:12:11:47 +0000] "GET URL2" 200 17453 "-" "Mozilla/5.0 (Macintosh; U; PPC Mac OS X 10.5; en-US; rv:1.9.0.11) Gecko/2009060214 Firefox/3.0.11" 

IP3 - - [22/Jun/2009:12:20:41 +0000] "GET URL3" 200 889 "REFERRING_URL2" "Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.0; GTB6; SLCC1; .NET CLR 2.0.50727; Media Center PC 5.0; 3P_USEC 1.0.11.2; .NET CLR 3.5.30729; .NET CLR 3.0.30618)" 

(ja anonimowe zainteresowanie IP - IP1, IP2 i IP3, żądanych adresów URL - URL1, url2 i Url3 i dwa referrrer URL)

Jak można widać trzy linie (które pojawiły się w logu w tej kolejności), są niezsynchronizowane. Dzieje się tak tylko wtedy, gdy IP2 żąda adresu URL2 - wszystkie pozostałe dzienniki wydają się normalne.

Wszelkie pomysły?

Answer 1

Logi są zapisywane po zakończeniu żądania, więc wczesne długie żądania mogą być pisane po opóźnionych krótkich. Dodaj% D, aby wyświetlić definicję LogFormat, aby zobaczyć czas potrzebny na wykonanie żądania w mikrosekundach.

Zobacz więcej here

Answer 2

Może robisz jakieś żądania COMET?

Moja pierwsza myśl polega na tym, że dziennik rejestruje tylko godzinę zakończenia żądania. Być może prośba IP1 zabrała trochę czasu, zanim dotarła do IP2. Tylko żądania, które wiem, że zachowują się w ten sposób, są żądaniami CJA AJAXey.

Prawdopodobnie nie jest to właściwa odpowiedź, być może wskazówką.

Edytuj: http://www.linuxquestions.org/questions/linux-networking-3/apache-log-entries-order-516354/ potwierdza, że ​​czas w dzienniku zawiera czas wymagany do przesłania zawartości do przeglądarki.