[
https://issues.apache.org/jira/browse/SOLR-11934?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17101305#comment-17101305
]
Erick Erickson commented on SOLR-11934:
---------------------------------------
I was able to look at a few more logs and... it's ambiguous of course. For
instance, I don't see _any_ commit_flush messages. I believe that's because
there was no indexing going on.
Looking at the data set I posted earlier, some interesting things:
I checked locally, and a commit (triggered from autocommit settings that open a
new searcher) logs the following:
* SolrCore logging that it's registered a new searcher
* SolrIndexWriter logging that it's calling setCommitData
* QuerySenderListener with a message about "QuerySenderListener sending
requests to..."
* DirectUpdateHandler2 logging it's started and ended a commit_flush
* SolrIndexSearcher telling us it's opened a new searcher
So the above run had somewhere in the neighborhood of 140K commits (whether
external or internal I don't think matters) that generated on the order of 840K
messages. Oh, none of the searcher opening messages tell us anything about how
long it took to open the searcher, that would be good to add as part of another
JIRA.
So by setting the log level to debug for all the messages relating to opening a
searcher except one (I think the one in SolrIndexSearcher is the logical one,
I'll beef it up a little) and setting the call in LogUpdateProcessorFactory to
debug I can drop the number of log messages from this kind of app by roughly
2/3, which accomplishes the original intent.
Note that the original problem was the observation that, in an app that indexed
one doc at a time and committed it (yeah, I know how bad that is and I told
them so) the logging was verbose, which squares with the observations above.
This looks like an index-heavy kind of application with either external commits
or short autocommit intervals.
I'd _really_ like to see a query-heavy type application. My first impulse when
I thought of dropping logging the query to debug rather than INFO was NOOOOOO!.
But with the slow query log would that be so bad? Tossing that out for
discussion, my personal feeling is that analyzing how Solr is performing often
depends soooo much on query response time that logging what we do now for the
query results is a must.
> Visit Solr logging, it's too noisy.
> -----------------------------------
>
> Key: SOLR-11934
> URL: https://issues.apache.org/jira/browse/SOLR-11934
> Project: Solr
> Issue Type: Improvement
> Reporter: Erick Erickson
> Assignee: Erick Erickson
> Priority: Major
>
> I think we have way too much INFO level logging. Or, perhaps more correctly,
> Solr logging needs to be examined and messages logged at an appropriate level.
> We log every update at an INFO level for instance. But I think we log LIR at
> INFO as well. As a sysadmin I don't care to have my logs polluted with a
> message for every update, but if I'm trying to keep my system healthy I want
> to see LIR messages and try to understand why.
> Plus, in large installations logging at INFO level is creating a _LOT_ of
> files.
> What I want to discuss on this JIRA is
> 1> What kinds of messages do we want log at WARN, INFO, DEBUG, and TRACE
> levels?
> 2> Who's the audience at each level? For a running system that's functioning,
> sysops folks would really like WARN messages that mean something need
> attention for instance. If I'm troubleshooting should I turn on INFO? DEBUG?
> TRACE?
> So let's say we get some kind of agreement as to the above. Then I propose
> three things
> 1> Someone (and probably me but all help gratefully accepted) needs to go
> through our logging and assign appropriate levels. This will take quite a
> while, I intend to work on it in small chunks.
> 2> Actually answer whether unnecessary objects are created when something
> like log.info("whatever {}", someObjectOrMethodCall); is invoked. Is this
> independent on the logging implementation used? The SLF4J and log4j seem a
> bit contradictory.
> 3> Maybe regularize log, logger, LOG as variable names, but that's a nit.
> As a tactical approach, I suggest we tag each LoggerFactory.getLogger in
> files we work on with //SOLR-(whatever number is assigned when I create
> this). We can remove them all later, but since I expect to approach this
> piecemeal it'd be nice to keep track of which files have been done already.
> Finally, I really really really don't want to do this all at once. There are
> 5-6 thousand log messages. Even at 1,000 a week that's 6 weeks, even starting
> now it would probably span the 7.3 release.
> This will probably be an umbrella issue so we can keep all the commits
> straight and people can volunteer to "fix the files in core" as a separate
> piece of work (hint).
> There are several existing JIRAs about logging in general, let's link them in
> here as well.
> Let the discussion begin!
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-unsubscr...@lucene.apache.org
For additional commands, e-mail: issues-h...@lucene.apache.org
