[ 
https://issues.apache.org/jira/browse/QPID-4517?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13541401#comment-13541401
 ] 

Philip Harvey commented on QPID-4517:
-------------------------------------

I tested this log format change using a persistent store, with one producer and 
one consumer and a transaction batch size of one, again with logger 
org.apache.qpid set to DEBUG. I found that it still causes a significant 
performance improvement - throughput doubled on my laptop. 

My laptop is a cheap dual core machine with an SSD drive, so it probably 
exaggerates the impact of this change, due to its fast IO and slow processor. 
Nevertheless, these results suggest to me that typical production deployments 
would see a significant performance increase when using DEBUG logging. 

When the log level is INFO or above, there is, as expected, no measurable 
performance improvement.

The scenario I have in mind is when a production support team want to switch on 
DEBUG logging for a few minutes to help pin down the source of a performance 
problem, and obviously want to minimise the impact of this logging. It is 
frustrating when support teams are so fearful of the performance impact of 
debug-level logging that they resist enabling it, even if it would help solve a 
problem.

Regarding line numbers... on the whole, our log messages are sufficiently 
descriptive to allow us to locate the line of code that produced them, without 
requiring file names and line numbers. In my short time working on Qpid, I've 
never had to resort to using line numbers (in fact, they can be positively 
misleading in cases where we've written our own centralised logging functions). 
Any logging that is untraceable without an explicit file name and line number 
is obviously inadequate and should be fixed.

My view is that the performance increase of this change offsets the lack of 
line numbers in the log file. However, I accept that this is a trade-off so 
won't push this change if the majority disagree with me.

                
> Java Broker: default log4j configuration outputs line numbers, which is a 
> performance drag
> ------------------------------------------------------------------------------------------
>
>                 Key: QPID-4517
>                 URL: https://issues.apache.org/jira/browse/QPID-4517
>             Project: Qpid
>          Issue Type: Improvement
>          Components: Java Broker
>    Affects Versions: 0.20
>            Reporter: Philip Harvey
>            Assignee: Philip Harvey
>            Priority: Minor
>         Attachments: 
> 0001-QPID-4517-modify-broker-log4j-configuration-to-use-l.patch
>
>
> By default we produce this sort of logging:
> {noformat}
> 2012-12-20 09:52:51,490 INFO  [main] (AbstractConfiguration.java:124) - 
> Tag:'path'
> {noformat}
> Including line numbers is slow, as described by the log4j documentation 
> (http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/PatternLayout.html):
> "WARNING Generating caller location information is extremely slow and should 
> be avoided unless execution speed is not an issue."

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@qpid.apache.org
For additional commands, e-mail: dev-h...@qpid.apache.org

Reply via email to