Я использую Apache / 2.2.15 (Unix). В конкретном проекте (с использованием php 5.3) в журналах отображается запрос (POST из сложной формы) через долгое время после выполнения запроса (40-50 минут).
Иногда время ожидания запроса истекает; иногда (как утверждает пользователь) все идет нормально. Но я не могу объяснить большой сдвиг во времени между моментом выполнения запроса и временем его регистрации.
У вас есть идеи, почему это происходит? Вы когда-нибудь замечали нечто подобное?
Некоторые строки журнала ниже:
[12/Oct/2015:11:32:01 -0500] "GET /adm/manageCompanies.php....
[12/Oct/2015:11:32:04 -0500] "GET /adm/manageCompanies.php....
[12/Oct/2015:**10:25:00** -0500] "POST /adm/manageCompanies.ph....
[12/Oct/2015:11:32:04 -0500] "GET /adm/manageCompanies.php....
[12/Oct/2015:11:32:08 -0500] "GET /adm/manageCompanies.php....
Строка со временем, выделенная жирным шрифтом, указывает на проблему - он зарегистрирован совершенно не по порядку ...
Еще один пример ниже:
[13/Oct/2015:08:18:05 -0500] "POST /adm/manageCompanies.php....
[13/Oct/2015:08:18:05 -0500] "GET /adm/manageCompanies.php ....
[13/Oct/2015:08:22:53 -0500] "GET /adm/manageCompanies.php ....
[13/Oct/2015:**07:37:37** -0500] "POST /adm/manageCompanies.php....
[13/Oct/2015:08:32:48 -0500] "GET /adm/manageCompanies.php ....
[13/Oct/2015:08:32:50 -0500] "GET /adm/manageCompanies.php ....
Как я могу найти причину этой проблемы? Это не вопрос регистрации, но время ожидания отправленной формы истекает и вызывает «повреждение».
Обычно я включаю ведение журнала продолжительности запроса, см.% D здесь:
http://httpd.apache.org/docs/2.2/mod/mod_log_config.html
Он печатает время в микросекундах, необходимое для удовлетворения запроса. Таким образом, вы можете легко найти, какие скрипты самые медленные.
Тем не менее, в вашем случае я бы начал отладку скрипта manageCompanies.php, возможно, добавив некоторые эхо или print_r в какой-либо файл в «стратегических» частях скрипта, начиная с части, которая обрабатывает метод POST, до и после циклов и в конечном итоге Запросы к БД, запись метки времени и, например, «Начало цикла foo / конец цикла foo», надеюсь, вы уловили идею.
На этот раз Apache получил запрос.
Apache записывает в журналы после завершения запроса.
Вы можете проверить в статусе сервера, какие запросы слишком длинные, и когда он у вас появится, взять его PID.
Затем вы можете изменить этот процесс, чтобы увидеть, что он делает:
strace -t -tt -p PID
Затем lsof может помочь вам увидеть, что находится в конце идентификатора файлового дескриптора (подключение к базе данных, веб-сервис ...)