lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Erick Erickson (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (SOLR-11884) find/fix inefficiencies in our use of logging
Date Sun, 04 Mar 2018 20:49:00 GMT

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

Erick Erickson commented on SOLR-11884:
---------------------------------------

NOTE: SOLR-7887 fixed the %C issues....

> find/fix inefficiencies in our use of logging
> ---------------------------------------------
>
>                 Key: SOLR-11884
>                 URL: https://issues.apache.org/jira/browse/SOLR-11884
>             Project: Solr
>          Issue Type: Improvement
>      Security Level: Public(Default Security Level. Issues are Public) 
>          Components: logging
>            Reporter: Erick Erickson
>            Assignee: Erick Erickson
>            Priority: Major
>
> We've been looking at Solr using Flight Recorder and ran across some interesting things
I'd like to discuss. Let's discuss general logging approaches here, then perhaps break out
sub-JIRAs when we reach any kind of agreement.
> 1> Every log message generates a new Throwable, presumably to get things like line
number, file, class name and the like. On a 2 minute run blasting updates this meant 150,000
(yes, 150K) instances of "new Throwable()".
>  
> See the section "Asynchronous Logging with Caller Location Information" at:
> [https://logging.apache.org/log4j/2.x/performance.html]
> I'm not totally sure changing the layout pattern will fix this in log4j 1.x, but apparently
certainly should in log4j 2.
>  
> The cost of course would be that lots of our log messages would lack some of the information.
Exceptions would still contain all the file/class/line information of course.
>  
> Proposal:
> Change the layout pattern to, by default, _NOT_  include information that requires a
Throwable to be created. Also include a pattern that could be un-commented to get this information
back for troubleshooting.
>  
> --------------------
>  
> We generate strings when we don't need them. Any construct like
> log.info("whatever " + method_that_builds_a_string + " : " + some_variable);
> generates the string (some of which are quite expensive) and then throws it away if the
log level is at, say, WARN. The above link also shows that parameterizing this doesn't suffer
this problem, so anything like the above should be re-written as:
> log.info("whatever {} : {} ", method_that_builds_a_string, some_variable);
>  
> The alternative is to do something like but let's make use of the built-in capabilities
instead.
> if (log.level >= INFO) {
>    log.info("whatever " + method_that_builds_a_string + " : " + some_variable);
> }
> etc.
> This would be a pretty huge thing to fix all-at-once so I suppose we'll have to approach
it incrementally. It's also something that, if we get them all out of the code should be added
to precommit failures. In the meantime, if anyone who has the precommit chops could create
a target that checked for this it'd be a great help in tracking all of them down, then could
be incorporated in the regular precommit checks if/when they're all removed.
> Proposal:
> Use JFR or whatever to identify the egregious violations of this kind of thing (I have
a couple I've found) and change them to parameterized form (and prove it works). Then see
what we can do to move forward with removing them all through the code base.
>  
>  



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org


Mime
View raw message