[
https://issues.apache.org/jira/browse/SOLR-11884?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16335266#comment-16335266
]
Erick Erickson commented on SOLR-11884:
---------------------------------------
Thanks Michael, at least they're linked now
> 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)
> 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-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org
