Project

General

Profile

Actions

Bug #2807

closed

%D and %{UNIT}T of mod_accesslog do not work as expected

Added by slim over 7 years ago. Updated over 7 years ago.

Status:
Fixed
Priority:
Normal
Category:
mod_accesslog
Target version:
ASK QUESTIONS IN Forums:

Description

mod_accesslog allows to log time used by a request via %D and %{UNIT}T tags of accesslog.format.

%D described as "time used in ms" when ms assumed to be miliseconds (1000 ms = 1 sec). Time used is logged in microseconds (1000'000 microseconds - 1 sec) instead.

%{UNIT}T stated as "time used in UNIT (s, ms, us, or ns)". Instead a timestamp is logged when "ms", "us" or "ns" are used

Actions #1

Updated by gstrauss over 7 years ago

  • Category set to documentation
  • Status changed from New to Fixed
  • Target version changed from 1.4.x to 1.4.46

%D described as "time used in ms" when ms assumed to be miliseconds (1000 ms = 1 sec). Time used is logged in microseconds (1000'000 microseconds - 1 sec) instead.

%D logs in microseconds, similar to Apache. I updated the incorrect doc at Docs_ModAccessLog

%{UNIT}T stated as "time used in UNIT (s, ms, us, or ns)". Instead a timestamp is logged when "ms", "us" or "ns" are used

I was not able to reproduce this -- %{s}T and %T both print the time in seconds for me. What you may be seeing is log buffering. If you send another request (over a second later), does the first line get logged? If you are still having a problem, please share your accesslog.format config.

Actions #2

Updated by gstrauss over 7 years ago

Clarification: the accesslog will be buffered until the buffer is full, unless %t is part of the format string. If %t is part of the format string, the log will be flushed on the next request after the time has changed (in seconds).

Actions #3

Updated by slim over 7 years ago

kinda of unix epoch timestamp is logged when %{ms}T or %{us}T is used in accesslog.format string instead of time used to process request in miliseconds or microseconds as expected

should I create separrate ticket for this ?

Actions #4

Updated by gstrauss over 7 years ago

I am sorry, but I did not understand the wording in your statement. Would you please clarify in a few complete sentences?

Since there was a documentation mistake, you may continue to ask specific questions about accesslog formats here in order to clarify the behavior.

Please do not file a new ticket to ask questions.
Questions are usually best asked in the forums (https://redmine.lighttpd.net/projects/lighttpd/boards)

Actions #5

Updated by slim over 7 years ago

as stated in docs:
"%{ms}T" - log time used in miliseconds
"%{us}T" - log time used in microseconds

as actually logged:
"%{ms}T" - unix timestamp of a request + two digits of something
"%{us}T" - unix timestamp of a request + four digits of something

Actions #6

Updated by gstrauss over 7 years ago

  • Category changed from documentation to mod_accesslog

If you can, please try the patch attached to this ticket. I had noticed an inconsistency at startup initialization time which might not have enabled high precision timestamps.

Actions #7

Updated by slim over 7 years ago

the patch looks good - milisecs and microsecs work now as expected

Actions

Also available in: Atom