Bug #45191 [Com]: error_log ignores date.timezone php.ini val when setting logging timestamps

[wadkar at gmail dot com]

Edit report at https://bugs.php.net/bug.php?id=45191&edit=1

 ID: 45191
 Comment by: wadkar at gmail dot com
 Reported by:info at organicdata dot co dot za
 Summary:error_log ignores date.timezone php.ini val when
 setting logging timestamps
 Status: Closed
 Type:   Bug
 Package:Date/time related
 Operating System:   Centos el5
 PHP Version:5.2CVS-2008-06-05 (snap)
 Assigned To:derick
 Block user comment: N
 Private report: N

 New Comment:

This bug may still be a problem for someone, here are the details :
# php -v
PHP 5.3.8 (cli) (built: Dec  1 2011 12:23:50)

The problem is with the OS this time= CentOS 5+OpenVZ with IUS repo. The host 
machine (with the OpenVZ kernel) has no problems
# uname -a
Linux vz-node2 2.6.18-274.el5.028stab093.2xen #1 SMP Tue Aug 23 16:50:42 MSD 
2011 x86_64 x86_64 x86_64 GNU/Linux
# echo '' > /tmp/error.log && php -dlog_errors=On -derror_log=/tmp/error.log -r 
'error_reporting(-1); SOMEBADCONSTANT;' && cat /tmp/error.log && date

[30-Jan-2012 14:38:56] PHP Notice:  Use of undefined constant SOMEBADCONSTANT - 
assumed 'SOMEBADCONSTANT' in Command line code on line 1
Mon Jan 30 14:38:56 IST 2012

The same code snippet, however, when run on a VM gives

# uname -a
Linux container1 2.6.18-274.el5.028stab093.2xen #1 SMP Tue Aug 23 16:50:42 MSD 
2011 x86_64 x86_64 x86_64 GNU/Linux
# echo '' > /tmp/error.log && php -dlog_errors=On -derror_log=/tmp/error.log -r 
'error_reporting(-1); SOMEBADCONSTANT;' && cat /tmp/error.log && date
 
[30-Jan-2012 09:10:05 UTC] PHP Notice:  Use of undefined constant 
SOMEBADCONSTANT - assumed 'SOMEBADCONSTANT' in Command line code on line 1
Mon Jan 30 14:40:05 IST 2012

The internal TZ settings are respected though:
# php -i | grep timezone
Default timezone => Asia/Calcutta
date.timezone => Asia/Calcutta => Asia/Calcutta
# php -r 'echo date_default_timezone_get(), PHP_EOL; $d = new DateTime(); echo 
$d->format(DATE_RFC822), PHP_EOL;' && date
Asia/Calcutta
Mon, 30 Jan 12 14:49:17 +0530
Mon Jan 30 14:49:17 IST 2012

I am not sure if this is the bug with PHP or with virtualized environment. I 
just wanted to comment/report my observation. I was worried for a moment that 
my CLI scripts would fail to respect the TZ settings, but that is not the case.

Thanks

-Sudarshan Wadkar


Previous Comments:

[2009-05-03 19:09:31] der...@php.net

This bug has been fixed in CVS.

Snapshots of the sources are packaged every three hours; this change
will be in the next snapshot. You can grab the snapshot at
http://snaps.php.net/.
 
Thank you for the report, and for helping us make PHP better.




[2008-07-29 06:46:39] der...@php.net

It should be switched from strftime() to php_format_date(). This is not an 
issue with the Date/Time functionality though, but with the syslog one.


[2008-07-28 22:47:26] j...@php.net

Derick, any comments?


[2008-07-28 22:46:30] j...@php.net

Actually error_log="somefile.log" does not use any syslog stuff to write the 
entries in it. This is the line from main.c:490 which gets executed if 
error_log != syslog:

strftime(error_time_str, sizeof(error_time_str), "%d-%b-%Y %H:%M:%S", 
php_localtime_r(&error_time, &tmbuf));

There are 2 problems here: [a] it's using locale sensitive %b modifier [b] It 
doesn't care about date.timezone. 

Solutions:
[a] IMO it should use this pattern instead: "%Y-%m-%d %H:%M:%S" (f.e. lighttpd 
uses this for it's error_log entries :)
[b] I don't know how to safely achieve the above mentioned issues with 
date.timezone vs. system timezone. Might be better leave this as is..


[2008-07-15 17:05:49] info at organicdata dot co dot za

Thanks very much for the feedback - I understand that my "bug" interpretation 
may have been wrong. My concern is really a result of a combination of the 
following:

1. the PHP recommendations I've seen is that you don't rely on system time zone 
and set the time zone explicitly in PHP
2. I want to have a single central logging file containing all system errors 
3. The custom error handling routine I use does not catch all errors that PHP 
can throw, some are only captured by the internal error handler used by setting 
log_errors=On

Because of 3, the only way I can achieve 2 that I can see is to set the output 
file in my custom error handler to be the same as the value set in the inifil

Bug #45191 [Com]: error_log ignores date.timezone php.ini val when setting logging timestamps

[wadkar at gmail dot com]

Edit report at https://bugs.php.net/bug.php?id=45191&edit=1

 ID: 45191
 Comment by: wadkar at gmail dot com
 Reported by:info at organicdata dot co dot za
 Summary:error_log ignores date.timezone php.ini val when
 setting logging timestamps
 Status: Closed
 Type:   Bug
 Package:Date/time related
 Operating System:   Centos el5
 PHP Version:5.2CVS-2008-06-05 (snap)
 Assigned To:derick
 Block user comment: N
 Private report: N

 New Comment:

@christopher
Interesting observation. My report is with 5.3.8 version, which outputs the log 
with UTC timestamp (the timezone is part of it). I am getting a feeling that 
this might not be a direct issue with php-src but somewhere in between system 
calls made by php-src for logging and the OS itself which passes on TZ data for 
this call.


Previous Comments:

[2012-02-11 18:15:29] christopher at specialtyproduce dot com

It seems this bug may have reappeared between 5.3.8 and 5.3.9?

I have two MS 2008 R2 VMs, built from the same starting images.  Both running 
IIS 7.5, system timezone is set for "Pacific Standard Time" and the TZ 
environment variable is not set.

Machine A : PHP 5.3.8 (cli) (built: Aug 23 2011 12:14:39)
  (Originally configured with PHP 5.2.17 and subsequently upgraded to 5.3.8)
Machine B : PHP 5.3.9 (cli) (built: Jan 10 2012 16:33:06)

Their php.ini files are virtually identical, with:
log_errors = On
date.timezone=America/Los_Angeles
error_log="C:\PHP\logs\php53_errors.log"

I ran a version of the "mycode.php" from the original bug report on both 
machines.

mycode.php
--
FIRSTBADCONSTANT;
date_default_timezone_set("UTC");
SOMEBADCONSTANT;
date_default_timezone_set("America/Los_Angeles");
ANOTHERBADCONSTANT;

Machine A php53_errors.log
--
[11-Feb-2012 09:39:18] PHP Notice:  Use of undefined constant FIRSTBADCONSTANT 
- assumed 'FIRSTBADCONSTANT' in C:\Temp\mycode.php on line 2
[11-Feb-2012 17:39:18] PHP Notice:  Use of undefined constant SOMEBADCONSTANT - 
assumed 'SOMEBADCONSTANT' in C:\Temp\mycode.php on line 4
[11-Feb-2012 09:39:18] PHP Notice:  Use of undefined constant 
ANOTHERBADCONSTANT - assumed 'ANOTHERBADCONSTANT' in C:\Temp\mycode.php on line 
6

Machine B php53_errors.log
--
[11-Feb-2012 18:06:52 UTC] PHP Notice:  Use of undefined constant 
FIRSTBADCONSTANT - assumed 'FIRSTBADCONSTANT' in C:\Temp\mycode.php on line 2
[11-Feb-2012 18:06:52 UTC] PHP Notice:  Use of undefined constant 
SOMEBADCONSTANT - assumed 'SOMEBADCONSTANT' in C:\Temp\mycode.php on line 4
[11-Feb-2012 18:06:52 UTC] PHP Notice:  Use of undefined constant 
ANOTHERBADCONSTANT - assumed 'ANOTHERBADCONSTANT' in C:\Temp\mycode.php on line 
6

The 5.3.9 error reporting seems locked in UTC.


[2012-02-09 23:21:35] daniel dot caillibaud at sesamath dot net

In an openvz VM, with php-fpm 5.3.10 (debian squeeze OS), with a sytem date 
configured on UTC+1 (on physical host, but `date` in VM also show UTC+1), in 
php.ini I've a

date.timezone = "Europe/Paris"

but php error_log date is displayed as UTC
[09-Feb-2012 23:15:08 UTC] PHP Notice: ...
while all others logs are in the system timezone, e.g nginx
[10/Feb/2012:00:16:46 +0100] ...

and syslog as well is UTC+1 (but doesn't show it on each log line).

Hope it helps...


[2012-01-30 09:20:08] wadkar at gmail dot com

This bug may still be a problem for someone, here are the details :
# php -v
PHP 5.3.8 (cli) (built: Dec  1 2011 12:23:50)

The problem is with the OS this time= CentOS 5+OpenVZ with IUS repo. The host 
machine (with the OpenVZ kernel) has no problems
# uname -a
Linux vz-node2 2.6.18-274.el5.028stab093.2xen #1 SMP Tue Aug 23 16:50:42 MSD 
2011 x86_64 x86_64 x86_64 GNU/Linux
# echo '' > /tmp/error.log && php -dlog_errors=On -derror_log=/tmp/error.log -r 
'error_reporting(-1); SOMEBADCONSTANT;' && cat /tmp/error.log && date

[30-Jan-2012 14:38:56] PHP Notice:  Use of undefined constant SOMEBADCONSTANT - 
assumed 'SOMEBADCONSTANT' in Command line code on line 1
Mon Jan 30 14:38:56 IST 2012

The same code snippet, however, when run on a VM gives

# uname -a
Linux container1 2.6.18-274.el5.028stab093.2xen #1 SMP Tue Aug 23 16:50:42 MSD 
2011 x86_64 x86_64 x86_64 GNU/Linux
# echo '' > /tmp/error.log && php -dlog_errors=On -derror_log=/tmp/error.log -r 
'error_reporting(-1); SOMEBADCONSTANT;' && cat /tmp/error.log && date
 
[30-Jan-2012 09:10:05 UTC] PHP Notice:  Use of undefined constant 
SOMEBADCONS