Mailing-List: contact dev-help@httpd.apache.org; run by ezmlm
Precedence: bulk
Reply-To: dev@httpd.apache.org
Received-SPF: pass (nike.apache.org: domain of rainer.jung@kippdata.de
 designates 195.227.30.149 as permitted sender)
Message-ID: <4C45D747.4010604@kippdata.de>
Date: Tue, 20 Jul 2010 19:05:11 +0200
From: Rainer Jung <rainer.jung@kippdata.de>
User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; de;
 rv:1.9.2.4) Gecko/20100608 Thunderbird/3.1
MIME-Version: 1.0
To: dev@httpd.apache.org
Subject: Re: Error log format configuration syntax
References: <alpine.DEB.1.10.1007200016170.23931@eru.sfritsch.de>
In-Reply-To: <alpine.DEB.1.10.1007200016170.23931@eru.sfritsch.de>
Content-Type: text/plain; charset=ISO-8859-15; format=flowed
Content-Transfer-Encoding: 7bit

On 20.07.2010 00:39, Stefan Fritsch wrote:
> Hi,
>
> I have been working on making the error log format configurable. It's
> more or less working now, but I could use some feed-back about the
> config syntax. The difficulty is that many tokens only produce output in
> some situations (e.g. no remote IP in server scope, no thread id in a
> non-threaded MPM, etc.). Since we don't want to have many empty []s or
> "-"s in the log, such tokens should take a prefix and suffix that are
> only printed if there is some relevant data. Also, some tokens need an
> additional argument (e.g. time format, header name, ...).
>
> Due to cut'n'paste from mod_log_config, the currently implemented syntax is
> this:
>
> %{arg}{prefix}{suffix}T
>
> This results in rather ugly configuration lines. For example the format
>
> ErrorLogFormat prefix "[%{u}t] [%l] [pid %P%{:tid }T] %F: %{}{:
> }E%{[client }{] }a"
> ErrorLogFormat suffix "%{Referer}{, referer: }i"
>
> gives roughly what we currently have in trunk:
>
> [Mon Jul 19 23:41:17.073289 2010] [debug] [pid 19220:tid 4132666224]
> http_request.c(300): (42)Broken Pipe: [client 127.0.0.1:36119]
> something's broken, referer: http://blah.com/

Ah, you used prefix and suffix here in two different contexts, once as a 
placeholder in describing the syntax for the per token prefixes and 
suffixes, and once as reserved words for defining the log format used in 
front of the message and behind the message. I guess you can get rid of 
the latter split by assigning a format specifier also to the log 
message, like '%M' or similar, and then

ErrorLogFormat "[%{u}t] [%l] [pid %P%{:tid }T] %F: %{}{: }E%{[client }{] 
}a %M %{}{, referer: }i"

> One could use different separators:
>
> %<prefix>{arg}<suffix>T
>
> which would lead to things like
>
> ErrorLogFormat prefix "[%{u}t] [%l] [pid %P%<:tid >T] %F: %<><:
>  >E%<[client ><] >a"
> ErrorLogFormat suffix "%<, referer: >{Referer}< >i"
>
> which is a bit better but not really good. Or maybe:
>
> %<prefix>{arg}T<suffix>
>
> resulting in
>
> ErrorLogFormat prefix "[%{u}t] [%l] [pid %P%<:tid >T] %F: %E<:
>  >%<[client >a<] >"
> ErrorLogFormat suffix "%<, referer: >{Referer}i< >"
>
> Does anyone have a better idea?

Maybe questioning, how important the configurable pre and suffixes are. 
We could either provide fixed ones for the individual log patterns, or 
we could provide none and indeed log an empty string or "-" if we don't 
have a value. I'd say both ways are viable. I guess some users would 
find it nice to have a fixed column format until the error message 
begins, so it's easier to parse by script, others will find it more 
readable if the empty fields get suppressed (condensed format).

What about:

- Allow to choose whether empty values get dropped (one configuration 
switch to choose the condensed format)

- taking all adjacent non-whitespace as prefixes and suffixes, collapse 
resulting adjacent whitespace in the output by adding the whitespace in 
front of the prefix to the prefix and dropping leading whitespace from 
the resulting line)

> BTW, I have also implemented once per request and once per connection
> logging and log ids that can be used to connect different lines in the
> error log and the error log with the access log.

Great.

> For example, this format
>
> ErrorLogFormat prefix "[%{uc}t] [%m:%l] %{}{req:}{ }L%{C}{conn:}{ }L"
> ErrorLogFormat suffix ""
> ErrorLogFormat connection "[pid %P] local: %A <-> remote: %a"
> ErrorLogFormat request "request %k on connection %{c}L
> %{Referer}{Referer: }i"
>
> gives this output, which should be rather nice for debugging:
>
> [2010-07-19 23:35:45.076082] [core:notice] Command line:
> '/usr/local/apache2/bin/httpd'
> [2010-07-19 23:35:46.832314] [-:-] conn:ruMCWgQNaAo [pid 18932] local:
> 127.0.0.1:8081 <-> remote: 127.0
> .0.1:49804
> [2010-07-19 23:35:46.832367] [-:-] req:VOMCWgQNaAo request 0 on
> connection ruMCWgQNaAo [2010-07-19 23:35:46.832382] [http:trace4]
> req:VOMCWgQNaAo Headers received from client:
> [2010-07-19 23:35:46.832382] [http:trace4] req:VOMCWgQNaAo Connection:
> Keep-Alive
> ...
> [2010-07-19 23:35:46.833359] [-:-] req:secCWmQNaAo request 1 on
> connection ruMCWgQNaAo [2010-07-19 23:35:46.833385] [http:trace4]
> req:secCWmQNaAo Headers received from client:
>
>
> The patch is available at
> http://people.apache.org/~sf/errorlog_format_v1.diff . It still needs
> some polishing and cleanup, though.
>
> Cheers,
> Stefan