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 "Chris Williams (JIRA)" <ji...@apache.org> on 2009/08/18 18:25:15 UTC

[jira] Created: (LOG4PHP-71) Using LoggerAppenderFile logging to the log file in one Apache session blocks every other Apache session that tries to write to the file until the original request has been processed

Using LoggerAppenderFile logging to the log file in one Apache session blocks every other Apache session that tries to write to the file until the original request has been processed
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

                 Key: LOG4PHP-71
                 URL: https://issues.apache.org/jira/browse/LOG4PHP-71
             Project: Log4php
          Issue Type: Bug
          Components: Code
         Environment: MAMP, LAMP, WAMP
            Reporter: Chris Williams


Note: We probably have an older version of log4php than what's currently available.

We were experiencing problems in our application where one session is waiting on another session. This effectively single threads our Apache requests for different clients. We narrowed this down to our use of log4php.

The code below will open a file for writing but will not close it until the request has been handled:
	$logger = LoggerManager::getLogger('logger');
	$logger->debug($message);

We added the following call and are no longer experiencing the file blocking since it looks like this call closes the file:
	LoggerManager::shutdown();

Is this the expected behavior? Should the log file be kept open between usage?


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


[jira] Commented: (LOG4PHP-71) Using LoggerAppenderFile logging to the log file in one Apache session blocks every other Apache session that tries to write to the file until the original request has been processed

Posted by "Christian Grobmeier (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/LOG4PHP-71?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12744880#action_12744880 ] 

Christian Grobmeier commented on LOG4PHP-71:
--------------------------------------------

This is indeed not really good. We will check this since i think that the latest code is similar to the version you might use.

Just for the record: are you using apache vers. 2 or 1? Are you running PHP as a module or as CGI? 
Maybe this behaviour is somehow related to the configuration too

> Using LoggerAppenderFile logging to the log file in one Apache session blocks every other Apache session that tries to write to the file until the original request has been processed
> --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
>                 Key: LOG4PHP-71
>                 URL: https://issues.apache.org/jira/browse/LOG4PHP-71
>             Project: Log4php
>          Issue Type: Bug
>          Components: Code
>         Environment: MAMP, LAMP, WAMP
>            Reporter: Chris Williams
>
> Note: We probably have an older version of log4php than what's currently available.
> We were experiencing problems in our application where one session is waiting on another session. This effectively single threads our Apache requests for different clients. We narrowed this down to our use of log4php.
> The code below will open a file for writing but will not close it until the request has been handled:
> 	$logger = LoggerManager::getLogger('logger');
> 	$logger->debug($message);
> We added the following call and are no longer experiencing the file blocking since it looks like this call closes the file:
> 	LoggerManager::shutdown();
> Is this the expected behavior? Should the log file be kept open between usage?

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


[jira] Commented: (LOG4PHP-71) Using LoggerAppenderFile logging to the log file in one Apache session blocks every other Apache session that tries to write to the file until the original request has been processed

Posted by "Chris Williams (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/LOG4PHP-71?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12745058#action_12745058 ] 

Chris Williams commented on LOG4PHP-71:
---------------------------------------

We're using Apache 2. Using PHP as a module. Tested this by turning off all of our logging and the app worked as we expected with sessions not blocking each other. Also, switched back to our old logging architecture and this problem went away. I'm assuming that the old architecture closes the files after writing to them.

> Using LoggerAppenderFile logging to the log file in one Apache session blocks every other Apache session that tries to write to the file until the original request has been processed
> --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
>                 Key: LOG4PHP-71
>                 URL: https://issues.apache.org/jira/browse/LOG4PHP-71
>             Project: Log4php
>          Issue Type: Bug
>          Components: Code
>    Affects Versions: 2.0
>         Environment: MAMP, LAMP, WAMP
>            Reporter: Chris Williams
>             Fix For: 2.0
>
>
> Note: We probably have an older version of log4php than what's currently available.
> We were experiencing problems in our application where one session is waiting on another session. This effectively single threads our Apache requests for different clients. We narrowed this down to our use of log4php.
> The code below will open a file for writing but will not close it until the request has been handled:
> 	$logger = LoggerManager::getLogger('logger');
> 	$logger->debug($message);
> We added the following call and are no longer experiencing the file blocking since it looks like this call closes the file:
> 	LoggerManager::shutdown();
> Is this the expected behavior? Should the log file be kept open between usage?

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


[jira] Commented: (LOG4PHP-71) Using LoggerAppenderFile logging to the log file in one Apache session blocks every other Apache session that tries to write to the file until the original request has been processed

Posted by "Christian Grobmeier (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/LOG4PHP-71?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12746061#action_12746061 ] 

Christian Grobmeier commented on LOG4PHP-71:
--------------------------------------------

I wrote a benchmark to test whats is the best option for nonblocking writes.
See: http://blog.grobmeier.de/2009/08/21/performance-ofnonblocking-write-to-files-via-php.html

Solution is to use flock to unlock the file after writing, and flock to lock it again before. Opeining/Closing the file is very bad for performance.

I will create a patch for this and include it in the trunk (or somebody else does :-))

Thanks for bringing this up!

> Using LoggerAppenderFile logging to the log file in one Apache session blocks every other Apache session that tries to write to the file until the original request has been processed
> --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
>                 Key: LOG4PHP-71
>                 URL: https://issues.apache.org/jira/browse/LOG4PHP-71
>             Project: Log4php
>          Issue Type: Bug
>          Components: Code
>    Affects Versions: 2.0
>         Environment: MAMP, LAMP, WAMP
>            Reporter: Chris Williams
>             Fix For: 2.0
>
>
> Note: We probably have an older version of log4php than what's currently available.
> We were experiencing problems in our application where one session is waiting on another session. This effectively single threads our Apache requests for different clients. We narrowed this down to our use of log4php.
> The code below will open a file for writing but will not close it until the request has been handled:
> 	$logger = LoggerManager::getLogger('logger');
> 	$logger->debug($message);
> We added the following call and are no longer experiencing the file blocking since it looks like this call closes the file:
> 	LoggerManager::shutdown();
> Is this the expected behavior? Should the log file be kept open between usage?

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


[jira] Commented: (LOG4PHP-71) Using LoggerAppenderFile logging to the log file in one Apache session blocks every other Apache session that tries to write to the file until the original request has been processed

Posted by "Christian Grobmeier (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/LOG4PHP-71?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12745059#action_12745059 ] 

Christian Grobmeier commented on LOG4PHP-71:
--------------------------------------------

According to PHP documentation, a file is blocked until it is closed. What you experienced is the standard behaviour of PHP.

Log4PHP needs to close the file directly after writing. The following solutions might be considered:

1) use file_put_content which is analogue to fopen, fwrite, and fclose
2) close the file directly after writing
3) use one of the newer stream classes to enable streaming to the file. BUT a file lock must be aquired

We need to check how the performance impacts are with closing the file.

However, I think I would prefer to close the file at first glance.


> Using LoggerAppenderFile logging to the log file in one Apache session blocks every other Apache session that tries to write to the file until the original request has been processed
> --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
>                 Key: LOG4PHP-71
>                 URL: https://issues.apache.org/jira/browse/LOG4PHP-71
>             Project: Log4php
>          Issue Type: Bug
>          Components: Code
>    Affects Versions: 2.0
>         Environment: MAMP, LAMP, WAMP
>            Reporter: Chris Williams
>             Fix For: 2.0
>
>
> Note: We probably have an older version of log4php than what's currently available.
> We were experiencing problems in our application where one session is waiting on another session. This effectively single threads our Apache requests for different clients. We narrowed this down to our use of log4php.
> The code below will open a file for writing but will not close it until the request has been handled:
> 	$logger = LoggerManager::getLogger('logger');
> 	$logger->debug($message);
> We added the following call and are no longer experiencing the file blocking since it looks like this call closes the file:
> 	LoggerManager::shutdown();
> Is this the expected behavior? Should the log file be kept open between usage?

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


[jira] Updated: (LOG4PHP-71) Using LoggerAppenderFile logging to the log file in one Apache session blocks every other Apache session that tries to write to the file until the original request has been processed

Posted by "Christian Grobmeier (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/LOG4PHP-71?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Christian Grobmeier updated LOG4PHP-71:
---------------------------------------

    Fix Version/s: 2.0

> Using LoggerAppenderFile logging to the log file in one Apache session blocks every other Apache session that tries to write to the file until the original request has been processed
> --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
>                 Key: LOG4PHP-71
>                 URL: https://issues.apache.org/jira/browse/LOG4PHP-71
>             Project: Log4php
>          Issue Type: Bug
>          Components: Code
>    Affects Versions: 2.0
>         Environment: MAMP, LAMP, WAMP
>            Reporter: Chris Williams
>             Fix For: 2.0
>
>
> Note: We probably have an older version of log4php than what's currently available.
> We were experiencing problems in our application where one session is waiting on another session. This effectively single threads our Apache requests for different clients. We narrowed this down to our use of log4php.
> The code below will open a file for writing but will not close it until the request has been handled:
> 	$logger = LoggerManager::getLogger('logger');
> 	$logger->debug($message);
> We added the following call and are no longer experiencing the file blocking since it looks like this call closes the file:
> 	LoggerManager::shutdown();
> Is this the expected behavior? Should the log file be kept open between usage?

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