mod_pagespeed_message uses wrong timezone

[GoogleCodeExporter]

What steps will reproduce the problem?
1. Enable mod_pagespeed_message handler in Apache
2. Check the messages page in your browser

What is the expected output? What do you see instead?
Entries are logged using wrong timezone than Apache or the server uses. For 
example my latest entry was
[Mon, 04 Jun 2012 10:34:43.480897 GMT] [Info] [11085] No permission to rewrite 
'http://www.example.com/photo.jpg'. 
Using date-command on the server returns: Mon Jun  4 13:34:59 EEST 2012

Also Apache itself uses correct timezone in log-files. Would be great that 
Pagespeed would respect that and use the same timezone. Reading logs is a bit 
difficult when I have to always calculate the hour difference in my head and 
then try to see what logs are happening and when.

What version of the product are you using (please check X-Mod-Pagespeed
header)? 0.10.22.4-r1633

On what operating system? Ubuntu 10.04.4 LTS

Which version of Apache? 2.2.14-5ubuntu8.9

Which MPM? Worker and Prefork tested

Original issue reported on code.google.com by henri.ko...@gmail.com on 4 Jun 2012 at 10:53

[GoogleCodeExporter]

Yes I see the code-path where we are printing time in GMT.  I'm trying to 
figure out what we should do about that.  Sorry for the annoyance!

Original comment by jmara...@google.com on 4 Jun 2012 at 2:28

• Changed state: Accepted

[GoogleCodeExporter]

While we are messing around with the messaging, we should also clean up our 
messages in Apache 2.4.  E.g.:

[Mon Jun 04 10:28:53.348150 2012] [pagespeed:error] [pid 17442:tid 
47482842760960] [mod_pagespeed 0.10.0.0-1629 @17442] URL 
http://modpagespeed.com:1023/someimage.png active for 97 ms

Note that the PID is printed twice.  If we are running in 2.4 we could avoid 
printing it after the mod_pagespeed version string.

Also note in that particular message we are using the correct timezone (in this 
case US Eastern).  I think maybe INFO messages are being printed with a 
different mechanism so they can be forked to a circular buffer 
/mod_pagespeed_messages.

Original comment by jmara...@google.com on 4 Jun 2012 at 2:33

[GoogleCodeExporter]

Yeah, in Apache 2.2 that message is:

[Mon Jun 04 10:31:30 2012] [error] [mod_pagespeed 0.10.0.0-1629 @21263] URL 
http://modpagespeed.com:1023/someimage.png active for 319 ms

Again, the correct timezone is being used but in Apache 2.2 the process-ID is 
not printed by Apache so it should be printed by mod_pagespeed.

Original comment by jmara...@google.com on 4 Jun 2012 at 2:35

[GoogleCodeExporter]

Couldn't see any error-messages but infos are definately using wrong timezone.

As you spoke about fiddling with messages, is it possible to filter out these 
"No permission to rewrite" messages (with an option or so). Because I know 
foreign domain resources won't be rewritten (so there's really no info for me) 
and when I have set certain paths forbidden I don't need info about those 
either. It's just that about half of my messages consist of these no permission 
-messages. I know they can be helpful sometimes (when dealing with multiple 
allowed domains or testing black lists for certain paths) but in a production 
environment they post too much glutter to my taste.

Anyway, nice that the timestamp issue can be fixed at some point :)

Original comment by henri.ko...@gmail.com on 4 Jun 2012 at 6:08

[GoogleCodeExporter]

Typically we see most server configurations set to use
  loglevel warn
while in production.  We recommend "loglevel info" or "loglevel debug" only 
when debugging.  Is there some reason you need to leave it running in "loglevel 
info" all the time?

Original comment by jmara...@google.com on 4 Jun 2012 at 6:10

[GoogleCodeExporter]

I have "loglevel warn" on all servers for Apache. I don't think MPS uses that 
value for it's messages?

Original comment by henri.ko...@gmail.com on 4 Jun 2012 at 6:51

[GoogleCodeExporter]

We should.  I'll check on that too.

Original comment by jmara...@google.com on 4 Jun 2012 at 6:58

[GoogleCodeExporter]

Sorry I didn't read the bug carefully enough.  The GMT message is only going 
into /mod_pagespeed_messages.

This is much simpler than I thought.  We just need to use 
   apr_status_t apr_ctime(char *date_str, apr_time_t t);

Would a source update be good enough for you?  Or do you need a new binary 
release?

Original comment by jmara...@google.com on 4 Jun 2012 at 8:47

[GoogleCodeExporter]

Original comment by jmara...@google.com on 4 Jun 2012 at 8:47

[GoogleCodeExporter]

Thank you for the fix!

I've currently installed mps from a binary package and updated from your ubuntu 
repo. It's easier ofc but I should be able to install from source too. 

Original comment by henri.ko...@gmail.com on 4 Jun 2012 at 9:27

[GoogleCodeExporter]

Original comment by jmara...@google.com on 5 Jun 2012 at 3:38

• Changed state: Started

[GoogleCodeExporter]

Original comment by jmara...@google.com on 5 Jun 2012 at 3:43

• Added labels: Milestone-v23

[GoogleCodeExporter]

This issue was closed by revision r1639.

Original comment by jmara...@google.com on 5 Jun 2012 at 4:43

• Changed state: Fixed