Нам потребовалось считать время, которое требуется апачу чтоб сгенерировать страницу.
Настроил логин в nginx в следующем формате :
log_format mainlog '[$connection : $request_time : $bytes_sent : $host : $upstream_response_time] '

Однако в самом логе заметил следующее :
[761513 : 0.000 : 508 : mega-torrent.ru : 0.000]
[761515 : 0.000 : 608 : mega-torrent.ru : 0.000]
[761500 : 0.100 : 315 : forum.kipelov.ru : 0.100]
[761521 : 0.000 : 512 : www.mega-torrent.ru : 0.000]
[757972 : 0.100 : 1496 : www.mega-torrent.ru : 0.100]
[762111 : 0.000 : 5856 : kipelov.ru : 0.000]
[763463 : 0.000 : 512 : www.mega-torrent.ru : 0.000]
[766547 : 0.400 : 7385 : rieltor.org : 0.100]

Большинство записей имеют вид :
[766576 : 0.000 : 512 : www.mega-torrent.ru : 0.000]


Очень редко бывает что считает правильно(всего пару раз замечал) :
[761526 : 0.005 : 512 : www.mega-torrent.ru : 0.005]
[761527 : 0.008 : 599 : www.mega-torrent.ru : 0.008]

т.е считает с точностью не до 1 мсек, а до 0.1 сек

Версия : nginx version: nginx/0.7.67
Ос : Debian 5, Linux eleron.averhost.com 2.6.32-5-xen-amd64 #1 SMP Sat Jul 24 04:03:11 UTC 2010 x86_64 GNU/Linux

В Изменениях есть запись к версии 0.5.1 :
Исправление: переменная $upstream_response_time могла быть равна "0.000", хотя время обработки было больше 1 миллисекунды.

Очевидно всплыл старый баг.

P.s. Немного изменил формат лога, заметил странность :
[ 7589 : 1281522505.015 : 0.100 : 0.100 : 2921 : rieltor.org ]
[ 6676 : 1281522505.215 : 0.000 : 0.000 : 773 : www.mega-torrent.ru ]
[ 7594 : 1281522505.315 : 0.000 : 0.000 : 512 : www.mega-torrent.ru ]
[ 7599 : 1281522505.915 : 0.000 : 0.000 : 608 : mega-torrent.ru ]
[ 7601 : 1281522505.915 : 0.000 : 0.000 : 440 : mega-torrent.ru ]
[ 7603 : 1281522506.315 : 0.000 : 0.000 : 440 : mega-torrent.ru ]
[ 7607 : 1281522506.515 : 0.000 : 0.000 : 608 : mega-torrent.ru ]

Такое чувство что страницы отдаются импульсами по 0.1 сек