At $WORK, we're trying to instrument our Apache 2.4.51 server to
diagnose latency issues.
Among our goals is to instrument our logs to distinguish between
clients taking too long to complete requests, and our server from
taking too long to provide a response.
Further, we want those logs to be terse, as disk space and log
retention are important.
I've been exploring combinations of:
from mod_logio:
LogIOTrackTTFB
from mod_log_config:
%D The time taken to serve the request, in microseconds.
%^FB Delay in microseconds between when the request
arrived and the first byte of the response headers
are written.
%{begin:%d/%b/%Y:%T}t.%{begin:usec_frac}t
beginning of request processing, in microseconds.
When I compare the recorded timestamps with a packet capture, and
a purposely-slowed POST request, I see that both of these counters
seem to start from when the first packet of the request comes in,
not when the whole request has been received.
As such, the timers describe the whole request/response cycle, and
don't let us infer where the latency is.
We've also explored info-level logging into our error_log, which
does yield useful records:
when a TLS session has completed setup.
when the request was completely received.
These are both great, and coupled with the details we can get in
our access_log, we can better pinpoint latency.
But, info-level logging yields a firehouse of data that floods the
logs, hamper retention.
Does anyone have any suggestions as to how to introduce a timestamp
into the access log as to when the entire request was received?
Or how to expose the details we see in the error_log, but in a way
that's much more terse than all of info?
Thanks for any pointers!
--
Brian Reichert <reichert@xxxxxxxxxxx>
BSD admin/developer at large
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@xxxxxxxxxxxxxxxx
For additional commands, e-mail: users-help@xxxxxxxxxxxxxxxx
|