У меня есть клиентское программное обеспечение, которое вызывает и сервер apache httpd, установленный на одном компьютере. Перед вызовом apache регистрирует запись в журнале:
2011-11-23 13:27:43,777 | 8323|1381677376 | root | DEBUG | Calling http://mydomain.com/api/project/325/postings/add_and_remove_labels
Как видите, звонок осуществляется в 13:27:43 по местному времени. Домен mydomain.com разрешает внешний IP-адрес той же машины.
Однако, когда я смотрю файл access.log, я говорю запись журнала, отметка времени [1] которой установлена на 5 секунд позже:
[23/Nov/2011:13:27:48 +0100] "GET /api/project/325/postings/add_and_remove_labels
Это базовый сервер mod_wsgi, работающий в режиме демона, но я не уверен, актуален ли он (отметка времени должна быть началом, если запрос на уровне apache).
Как мне лучше всего найти источник этих 5 секунд?
Привет, Вооз
Уточнение: [1] - Отметка времени - это когда запрос началось. Это правда, что запись записывается в журнал, когда запрос заканчивается, но это время начала запроса.
Это потому, что журнал доступа записывается на конец запроса, а не начало. Поэтому, если вы сделаете запрос в 12:00, и это займет минуту, запись не будет записана до 12:01. Тот факт, что он может включать такие вещи, как количество переданных байтов, является верным индикатором этого.
Вы также можете выполнить трассировку от одного хоста к другому, чтобы узнать, действительно ли он получает запрос - если вы видите задержки во время маршрутизации, у вас есть источник вашей проблемы.
Две вещи, которые нужно проверить:
- время разрешить имя mydomain.com на сервере (кредиты TokenMacGuy в комментариях)
- время выполнения вашего скрипта, так как журнал записывается по завершении запроса