You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4php-dev@logging.apache.org by "Ivan Habunek (JIRA)" <ji...@apache.org> on 2010/04/19 21:37:50 UTC

[jira] Updated: (LOG4PHP-113) Milliseconds do not change when using LoggerLayoutPattern

     [ https://issues.apache.org/jira/browse/LOG4PHP-113?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Ivan Habunek updated LOG4PHP-113:
---------------------------------

    Attachment: LoggerDatePatternConverter.milliseconds.patch

I have tracked down what causes this issue. The problem lies in the convert() method of LoggerDatePatternConverter. On line 50 of LoggerDatePatternConverter.php, the date format pattern ($this->df) is modified so that 'u' in the pattern (which represents milliseconds) is replaced with the actual milliseconds from the event timestamp. This is done because the php date() function (invoked in line 51) doesn't handle milliseconds properly. The mistake is that the member variable $this->df is changed for this and every future event handled by this class. Therefore all events have the same millisecond value. Fixed by creating a local variable $df to hold the pattern.

This patch fixes the issue.


> Milliseconds do not change when using LoggerLayoutPattern
> ---------------------------------------------------------
>
>                 Key: LOG4PHP-113
>                 URL: https://issues.apache.org/jira/browse/LOG4PHP-113
>             Project: Log4php
>          Issue Type: Bug
>          Components: Code
>    Affects Versions: 2.1
>            Reporter: Ivan Habunek
>            Priority: Minor
>         Attachments: LoggerDatePatternConverter.milliseconds.patch
>
>
> When using a LoggerLayoutPattern which has a date conversion pattern using milliseconds, the milliseconds are the same for all events. To reproduce, use the following code and configuration:
> log4php.xml
> ===========
> <?xml version='1.0' encoding='us-ascii'?>
> <!DOCTYPE Library SYSTEM "log4php.dtd">
> <log4php:configuration xmlns:log4php="http://logging.apache.org/log4php/" threshold="all" debug="false">
> 	<appender name="default" class="LoggerAppenderEcho">
> 		<layout class="LoggerLayoutPattern">
> 			<param name="conversionPattern" value="%d{Y-m-d H:i:s.u} %m%n" />
> 		</layout>
> 	</appender>
> 	<root>
> 		<level value="DEBUG" />
> 		<appender_ref ref="default" />
> 	</root>
> </log4php:configuration>
> PHP code:
> =========
> <?php
> require '../log4php/src/main/php/Logger.php';
> Logger::configure('log4php.xml');
> $logger = Logger::getRootLogger();
> foreach (range(0, 10) as $item)
> {
> 	$logger->debug("The time is: " . microtime(true));
> 	usleep(10000);
> }
> ?>
> Example output:
> ==============
> 2010-04-19 20:57:52.318 The time is: 1271703472.3181
> 2010-04-19 20:57:52.318 The time is: 1271703472.3292
> 2010-04-19 20:57:52.318 The time is: 1271703472.3399
> 2010-04-19 20:57:52.318 The time is: 1271703472.3507
> 2010-04-19 20:57:52.318 The time is: 1271703472.3614
> As you can see, the milliseconds are constant and equal to 318. This is the millisecond when the first event happened.
> Expected output:
> ===============
> 2010-04-19 20:57:52.318 The time is: 1271703472.3181
> 2010-04-19 20:57:52.329 The time is: 1271703472.3292
> 2010-04-19 20:57:52.340 The time is: 1271703472.3399
> 2010-04-19 20:57:52.351 The time is: 1271703472.3507
> 2010-04-19 20:57:52.361 The time is: 1271703472.3614

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.