You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@httpd.apache.org by Alois Treindl <al...@astro.ch> on 2004/06/20 02:16:01 UTC

[users@httpd] apache 2.0 accesslog timestamp differs from apache 1.3

Hi

it seems that Apache 2.0 put as time %t in the logfile the time when a 
request was received and delivery began.

Apache 1.3 did put in the time when a request was completed.

The moment of the actual logging, however, is always the time when the 
request is completed - it cannot be earlier, because Apache needs to 
know the number of bytes delivered.

I observe a problem with the new 2.0 policy for downloads of large 
files, which can take several minutes.

A log entry is made at, e.g. 00:03:25 (after midnight) for a rquest 
which was received at 23:59:23

This messes up the temporal sequence of the accesslog, and consequently 
the logfile analyzer I am using is screwed up, particularily if logfiles 
are rotated at midnight - they contain some slow entries from the 
previous day.

Is there a way to get the behaviour of apache 1.3 back, when the 
timestamps were always of the time of completion of the request?

---------------------------------------------------------------------
The official User-To-User support forum of the Apache HTTP Server Project.
See <URL:http://httpd.apache.org/userslist.html> for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
   "   from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org


Re: [users@httpd] apache 2.0 accesslog timestamp differs from apache 1.3

Posted by Alois Treindl <al...@astro.ch>.
Nick Kew wrote:
> On Sun, 20 Jun 2004, Alois Treindl wrote:
> 
> 
>>>>Is there a way to get the behaviour of apache 1.3 back, when the
>>>>timestamps were always of the time of completion of the request?
> 
> 
> You could fairly trivially just substitute a patched log module.
> I expect the patch would be ten minutes work.
> 
> 

I am sorry, but I do not know how to make a patch.

I have got the redhat httpd source rpm, but have no idea how to create a 
patched mod_log_config.so here.

I would need some step-by-step instruction.

---------------------------------------------------------------------
The official User-To-User support forum of the Apache HTTP Server Project.
See <URL:http://httpd.apache.org/userslist.html> for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
   "   from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org


Re: [users@httpd] apache 2.0 accesslog timestamp differs from apache 1.3

Posted by Alois Treindl <al...@astro.ch>.
Nick Kew wrote:

> 
> 
> Developers sometimes make changes requested by users: I've written more
> than one new module in response to - for example - a passing request
> (or a "why can't it do?" question) on #apache[1], or a need identified
> in a Usenet thread[2].  But I doubt your attitude above has made you many
> friends.
> 

OK.

I have learned how to create and apply a patch, and made a patched 
mod_log_config.so for my purpose.

In the process, I discovered an actual bug in mod_log_config.c

The code is:
static const char *log_request_time(request_rec *r, char *a)
...
#ifdef I_INSIST_ON_EXTRA_CYCLES_FOR_CLF_COMPLIANCE
         apr_time_t request_time = apr_time_now();
#else
         apr_time_t request_time = r->request_time;
#endif
         unsigned t_seconds = (unsigned)apr_time_sec(request_time);
         unsigned i = t_seconds & TIME_CACHE_MASK;
         memcpy(cached_time, &(request_time_cache[i]), 
sizeof(*cached_time));
         if ((t_seconds != cached_time->t) ||
             (t_seconds != cached_time->t_validate)) {

             /* Invalid or old snapshot, so compute the proper time string
              * and store it in the cache
              */
             char sign;
             int timz;

             ap_explode_recent_localtime(&xt, r->request_time);


The last line is wrong: it uses r->request_time instead of the local
variable request_time.

It should be
ap_explode_recent_localtime(&xt, request_time);

I have submitted the bug to apache bugzilla.

---------------------------------------------------------------------
The official User-To-User support forum of the Apache HTTP Server Project.
See <URL:http://httpd.apache.org/userslist.html> for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
   "   from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org


Re: [users@httpd] apache 2.0 accesslog timestamp differs from apache 1.3

Posted by Nick Kew <ni...@webthing.com>.
On Sun, 20 Jun 2004, Alois Treindl wrote:

> >>Is there a way to get the behaviour of apache 1.3 back, when the
> >>timestamps were always of the time of completion of the request?

You could fairly trivially just substitute a patched log module.
I expect the patch would be ten minutes work.

> > Yes.  Use the define I_INSIST_ON_EXTRA_CYCLES_FOR_CLF_COMPLIANCE when
> > compiling apache.

I wasn't aware of that option:-)

> Can't this option not be controlled via a configuration directive,
> instead of a compile time constant? or would this require too many brain
>   cycles of the developer?

Developers sometimes make changes requested by users: I've written more
than one new module in response to - for example - a passing request
(or a "why can't it do?" question) on #apache[1], or a need identified
in a Usenet thread[2].  But I doubt your attitude above has made you many
friends.

[1] http://apache.webthing.com/mod_txt/
[2] http://apache.webthing.com/mod_proxy_html/

-- 
Nick Kew

---------------------------------------------------------------------
The official User-To-User support forum of the Apache HTTP Server Project.
See <URL:http://httpd.apache.org/userslist.html> for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
   "   from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org


Re: [users@httpd] apache 2.0 accesslog timestamp differs from apache 1.3

Posted by Alois Treindl <al...@astro.ch>.
André Malo wrote:
> * Alois Treindl <al...@astro.ch> wrote:
> 
> 
>>Can't this option not be controlled via a configuration directive, 
>>instead of a compile time constant? or would this require too many brain 
>>  cycles of the developer?
> 
> 
> patches welcome ;-)
> Preferrably an option to LogFormat, CustomLog, TransferLog and CookieLog.
> 

I think this should simply be fixed and revert to the 1.3 behaviour.

The argument with 'server cpu cycles saved' is reidculous - looking up 
the system clock is a very cheap call. The actual cpu cycles used are in 
formatting and printing the log entry field, and that is the same 
whether current time, or begin of request time is logged.


---------------------------------------------------------------------
The official User-To-User support forum of the Apache HTTP Server Project.
See <URL:http://httpd.apache.org/userslist.html> for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
   "   from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org


Re: [users@httpd] apache 2.0 accesslog timestamp differs from apache 1.3

Posted by André Malo <nd...@perlig.de>.
* Alois Treindl <al...@astro.ch> wrote:

> Can't this option not be controlled via a configuration directive, 
> instead of a compile time constant? or would this require too many brain 
>   cycles of the developer?

patches welcome ;-)
Preferrably an option to LogFormat, CustomLog, TransferLog and CookieLog.

nd
-- 
s  s^saaaaaoaaaoaaaaooooaaoaaaomaaaa  a  alataa  aaoat  a  a
a maoaa a laoata  a  oia a o  a m a  o  alaoooat aaool aaoaa
matooololaaatoto  aaa o a  o ms;s;\s;s;g;y;s;:;s;y#mailto: #
 \51/\134\137| http://www.perlig.de #;print;# > nd@perlig.de

---------------------------------------------------------------------
The official User-To-User support forum of the Apache HTTP Server Project.
See <URL:http://httpd.apache.org/userslist.html> for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
   "   from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org


Re: [users@httpd] apache 2.0 accesslog timestamp differs from apache 1.3

Posted by Alois Treindl <al...@astro.ch>.
Joshua Slive wrote:
> On Sun, 20 Jun 2004, Alois Treindl wrote:
> 
>>it seems that Apache 2.0 put as time %t in the logfile the time when a
>>request was received and delivery began.
>>
>>Apache 1.3 did put in the time when a request was completed.
> 
> 
>>Is there a way to get the behaviour of apache 1.3 back, when the
>>timestamps were always of the time of completion of the request?
> 
> 
> Yes.  Use the define I_INSIST_ON_EXTRA_CYCLES_FOR_CLF_COMPLIANCE when
> compiling apache.
> 
> But you might be interested in reading this comment in the source, which
> explains why the default has changed:
>     /* ###  I think getting the time again at the end of the request
>      * just for logging is dumb.  i know it's "required" for CLF.
>      * folks writing log parsing tools don't realise that out of order
>      * times have always been possible (consider what happens if one
>      * process calculates the time to log, but then there's a context
>      * switch before it writes and before that process is run again the
>      * log rotation occurs) and they should just fix their tools rather
>      * than force the server to pay extra cpu cycles.  if you've got
>      * a problem with this, you can set the define.  -djg
>      */
> 
> See:
> http://cvs.apache.org/viewcvs.cgi/httpd-2.0/modules/loggers/mod_log_config.c?view=markup

Thanks for letting me know.

I find the attitude of the source code comment arrogant.

I happen to use a precompiled Apache server (part of a Redhat supported 
Enterprise solution) and I loose support if I run a self-compiled version.

Can't this option not be controlled via a configuration directive, 
instead of a compile time constant? or would this require too many brain 
  cycles of the developer?

---------------------------------------------------------------------
The official User-To-User support forum of the Apache HTTP Server Project.
See <URL:http://httpd.apache.org/userslist.html> for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
   "   from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org


Re: [users@httpd] apache 2.0 accesslog timestamp differs from apache 1.3

Posted by Joshua Slive <jo...@slive.ca>.
On Sun, 20 Jun 2004, Alois Treindl wrote:
> it seems that Apache 2.0 put as time %t in the logfile the time when a
> request was received and delivery began.
>
> Apache 1.3 did put in the time when a request was completed.

> Is there a way to get the behaviour of apache 1.3 back, when the
> timestamps were always of the time of completion of the request?

Yes.  Use the define I_INSIST_ON_EXTRA_CYCLES_FOR_CLF_COMPLIANCE when
compiling apache.

But you might be interested in reading this comment in the source, which
explains why the default has changed:
    /* ###  I think getting the time again at the end of the request
     * just for logging is dumb.  i know it's "required" for CLF.
     * folks writing log parsing tools don't realise that out of order
     * times have always been possible (consider what happens if one
     * process calculates the time to log, but then there's a context
     * switch before it writes and before that process is run again the
     * log rotation occurs) and they should just fix their tools rather
     * than force the server to pay extra cpu cycles.  if you've got
     * a problem with this, you can set the define.  -djg
     */

See:
http://cvs.apache.org/viewcvs.cgi/httpd-2.0/modules/loggers/mod_log_config.c?view=markup


Joshua.

---------------------------------------------------------------------
The official User-To-User support forum of the Apache HTTP Server Project.
See <URL:http://httpd.apache.org/userslist.html> for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
   "   from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org