[ https://issues.apache.org/jira/browse/SOLR-11884?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16334977#comment-16334977 ]
Michael Braun commented on SOLR-11884: -------------------------------------- [~erickerickson] I previously logged SOLR-10415 to track some of the issues I found in solr core. > 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