[
https://issues.apache.org/jira/browse/SOLR-16910?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17752513#comment-17752513
]
David Smiley commented on SOLR-16910:
-------------------------------------
{quote} * new class wouldn't do any actual logging – would just put info about
adds/dels in {{rsp.toLog}}{quote}
FWIW this is what we do at work. We don't use the stock
LogUpdateProcessorFactory, we have our own which adds to rsp.toLog and thus has
normal looking request logs.
> Adjusting LogUpdateProcessorFactory's log level has side effects on SolrCore
> logging and changes "slowUpdateThresholdMillis" formatting
> ---------------------------------------------------------------------------------------------------------------------------------------
>
> Key: SOLR-16910
> URL: https://issues.apache.org/jira/browse/SOLR-16910
> Project: Solr
> Issue Type: Bug
> Security Level: Public(Default Security Level. Issues are Public)
> Reporter: Chris M. Hostetter
> Priority: Major
>
> The logic in {{LogUpdateProcessorFactory.finish()}} when doing "INFO" level
> logging is weird.
> It has some non-intuitive side effects on:
> * SolrCore's {{Request}} logger
> * the output format of it's own {{slowUpdateThresholdMillis}} logging.
> Current logic (psuedocode)...
> {code:java}
> if (my logging level is at least INFO):
> log.info( rsp.toLog + (summary of adds and deletes processed) + elapsed
> time )
> clear rsp.toLog
> if (my logging level is at least WARN):
> if ( elapsed time > slowUpdateThresholdMillis ):
> log.warn( "slow: " + rsp.toLog + (summary of adds and deletes processed)
> + elapsed time )
> clear rsp.toLog
> {code}
> ...the crux of the logic living in
> {{LogUpdateProcessorFactory.getLogStringAndClearRspToLog()}} which handles
> the formatting of the log messages and clearing {{{}rsp.toLog{}}}.
> When {{rsp.toLog}} is empty, SolrCore's {{Request}} logger (intentionally)
> does *{*}NOT{*}* log the request.
> If you have {{INFO}} level logging configured globally, and you don't
> configure {{{}slowUpdateThresholdMillis{}}}, (ie: the solr default behavior)
> then the behavior of {{LogUpdateProcessorFactory}} is only slightly weird:
> * {{LogUpdateProcessorFactory}} INFO logs "update" requests with added
> context about adds/deletes
> ** Unless there was an exception thrown during the updates (before
> {{finish()}} was called) - then it logs nothing
> * SolrCore's {{Request}} logger INFO logs any request that
> {{LogUpdateProcessorFactory}} doesn't
> ** (ie: non update requests, or update requests that threw exceptions)
>
> (I'm guessing most solr devs are just use to this long standing default
> beahvior and don't really think about why SolrCore doesn't log {{/update}}
> requests ...or even notice that it _does_ log {{/update}} requests that threw
> an exception)
>
> If you have {{INFO}} level logging configured globally, and you turn on
> {{{}slowUpdateThresholdMillis{}}}, the behavior of
> {{LogUpdateProcessorFactory}} is a _little_ weird:
> * {{LogUpdateProcessorFactory}} INFO logs "update" requests with added
> context about adds/deletes
> ** {{LogUpdateProcessorFactory}} WARN logs any "slow" update requests with
> added context about adds/deletes
> *** _*BUT*_ ... w/o the standard request info (webapp, path, request params,
> etc...)
> ** the "QTime" logged for each request can be _different_ between the INFO
> logging and the WARN logging
> * SolrCore's {{Request}} logger INFO logs any request that
> {{LogUpdateProcessorFactory}} doesn't
> ** (ie: non update requests, or update requests that threw exceptions)
>
> If you customize the logging levels for various loggers, things get
> _*REALLY*_ weird...
> * {{LogUpdateProcessorFactory=OFF}} + {{SolrCore.Request=INFO}}
> ** Now SolrCore's {{Request}} logger _does_ log updates just like other
> types of requests
> * {{LogUpdateProcessorFactory=WARN}} + {{slowUpdateThresholdMillis}} +
> {{SolrCore.Request=INFO}}
> ** Now SolrCore's {{Request}} logger _does_ log updates just like other
> types of requests
> *** And even SolrCore's {{SlowRequest}} logger may log it (if it's slow)
> ** _*UNLESS...*_ the request is slower then {{slowUpdateThresholdMillis}} ...
> *** In which case {{LogUpdateProcessorFactory}} WARN logs it *WITH* the
> standard request info (webapp, path, request params, etc...)
> *** *But* these "slow" queries don't get logged by SolrCore's
> {{{{Request}}}} or {{SlowRequest}} loggers
> ----
> Example scenarios that can arise from these combinations, that might cause
> you to think you're losing your mind (one of these may - or may not - have
> happened to me)
> * You start with {{LogUpdateProcessorFactory=OFF}} +
> {{SolrCore.Request=INFO}} (with some {{slowQueryThresholdMillis}} configured)
> ** You change {{LogUpdateProcessorFactory=INFO}} because you want to see the
> add/delete details of some of the {{/update}} requests in your slow query log
> ** Now you get {{LogUpdateProcessorFactory}} logging of your updates - but
> for some reason they stop showing up in your normal and/or slow query logs ???
> * You start with {{ROOT=INFO}}
> ** You feel like your logs are too noisy
> *** in particular you don't need to see all {{LogUpdateProcessorFactory}}
> logging of updates, because you really only care about the "queries" being
> logged by {{SolrCore.Request}}
> ** So you change to {{ROOT=WARN}} + {{SolrCore.Request=INFO}}
> *** Now for some reason {{SolrCore.Request}} is suddenly logging update
> requests it wasn't logging before ???
> * You start with {{ROOT=WARN}} and have {{slowUpdateThresholdMillis}}
> configured
> ** You are happy with the format of the {{slow: ...}} WARN messages you get
> from {{LogUpdateProcessorFactory}} and an automated tool that parses those
> logs to run a report
> ** You need to do some debugging, so you temporarily enable {{ROOT=INFO}}
> *** now for some reason your {{slow: ...}} WARN messages are in a different
> format that breaks your log parsing tool
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
