Eu tenho um software cliente que chama o servidor Apache httpd instalado na mesma máquina. Antes de chamar o apache registra uma entrada de log:
2011-11-23 13:27:43,777 | 8323|1381677376 | root | DEBUG | Calling http://mydomain.com/api/project/325/postings/add_and_remove_labels
Como você pode ver, a ligação foi feita às 13h27min43s, horário local. O domínio meudominio.com resolve o IP externo da mesma máquina.
No entanto, quando olho para o arquivo access.log, digo entrada de log cujo carimbo de data/hora [1] é 5 segundos depois:
[23/Nov/2011:13:27:48 +0100] "GET /api/project/325/postings/add_and_remove_labels
Este é um servidor base mod_wsgi rodando em modo daemon, mas não tenho certeza se é relevante (o carimbo de data / hora deve ser o início se a solicitação estiver no nível do Apache).
Qual a melhor forma de proceder para descobrir a origem desses 5 segundos?
Obrigada, Boaz
Esclarecimento: [1] - O carimbo de data/hora é quando a solicitaçãoiniciado. É verdade que a entrada é gravada no log quando a solicitação termina, mas o horário é o início da solicitação.
Responder1
Isso ocorre porque o log de acesso é gravado nelefimdo pedido, não do início. Portanto, se você fizer a solicitação às 12h e demorar um minuto para ser concluída, a entrada só será escrita às 12h01. O fato de poder incluir coisas como o número de bytes transferidos é um indicador seguro disso.
Você também pode executar um traceroute de um host para outro para ver se ele realmente está recebendo a solicitação - se estiver vendo atrasos durante o roteamento, você tem a origem do seu problema.
Responder2
Duas coisas para verificar:
- o tempo para resolver o nome mydomain.com no servidor (créditos para TokenMacGuy nos comentários)
- o tempo de execução do seu script, pois o log é gravado após a conclusão da solicitação