Request log format string %D

[Jon Ekdahl <jo...@gmail.com>]

Hi,

I came across what I believe to be a defect in the log format description
[1]. The %D format string is described as "The time taken to serve the
request, in microseconds". However, the default request exit format is
"%\{end}t \[%R] <\- %s %\{Content-Type}o %Dms", indicating that %D actually
produces *milliseconds*, not microseconds. I found the
RequestLoggerResponse class [2] in the Sling code base that suggests that
request duration is at least recorded in milliseconds.

Is this simply a documentation bug, then? Well, maybe not. The Sling
documentation [1] also links to the Apache httpd log format description
[3], where %D means duration in microseconds.

Can somebody confirm that %D produces milliseconds?

Cheers, Jon


[1]:
http://sling.apache.org/documentation/development/client-request-logging.html#log-format-specification
[2]:
https://github.com/apache/sling/blob/trunk/bundles/engine/src/main/java/org/apache/sling/engine/impl/log/RequestLoggerResponse.java
[3]: http://httpd.apache.org/docs/current/mod/mod_log_config.html

Re: Request log format string %D

[Robert Munteanu <ro...@apache.org>]

Hi Jon,

On Fri, 2015-11-27 at 09:36 +0000, Jon Ekdahl wrote:
> Hi,
> 
> I came across what I believe to be a defect in the log format
> description
> [1]. The %D format string is described as "The time taken to serve
> the
> request, in microseconds". However, the default request exit format
> is
> "%\{end}t \[%R] <\- %s %\{Content-Type}o %Dms", indicating that %D
> actually
> produces *milliseconds*, not microseconds. I found the
> RequestLoggerResponse class [2] in the Sling code base that suggests
> that
> request duration is at least recorded in milliseconds.
> 
> Is this simply a documentation bug, then? Well, maybe not. The Sling
> documentation [1] also links to the Apache httpd log format
> description
> [3], where %D means duration in microseconds.
> 
> Can somebody confirm that %D produces milliseconds?

It produced milliseconds indeed [4]. I've updated the documentation to
reflect this.

Thanks for the detailed report.

Best,

Robert


[4]: https://github.com/apache/sling/blob/efa00b70417d7a99dec50aac4ffaa
45030d28a91/bundles/engine/src/main/java/org/apache/sling/engine/impl/l
og/CustomLogFormat.java#L669-L688


> 
> Cheers, Jon
> 
> 
> [1]:
> http://sling.apache.org/documentation/development/client-request-logg
> ing.html#log-format-specification
> [2]:
> https://github.com/apache/sling/blob/trunk/bundles/engine/src/main/ja
> va/org/apache/sling/engine/impl/log/RequestLoggerResponse.java
> [3]: http://httpd.apache.org/docs/current/mod/mod_log_config.html