You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by "Ramkumar R. Aiyengar" <an...@gmail.com> on 2014/08/25 22:44:10 UTC
Logging levels in Solr code
I am in the process of looking at some of the ERROR level log output coming
from Solr to set up alarms, but currently the severity of what ERROR means
is kind of mixed across the code base. I am happy to fix this where I find,
but some guidance on what the various levels mean would be helpful. This is
what I would have expected:
- ERROR: Shouldn't happen, indicates a bug or misconfiguration. Leads to
loss of functionality or some operation failing. Any occurrence indicates
something needs to be fixed.
- WARN: Recoverable problem, might genuinely happen in rare cases. If it
happens too often, might indicate an issue or misconfiguration. Bad input
data could fall into this category, or should it be INFO?
- INFO: Informational messages which would help in investigation,
indicates expected behaviour.
Let me know if this is not accurate..
Re: Logging levels in Solr code
Posted by Jack Krupansky <ja...@basetechnology.com>.
Maybe what is needed is one or both of:
1. A parameter to raise the log level temporarily for the duration of a single request.
2. An administrative command to raise the log level for a designated short interval of time, like, say, 10 seconds.
Or...
3. An administrative command to dynamically set some regex-like patterns to temporarily raise the log level when something in the request, like the query string, matches one of a set of patterns. Simply doing a regex on the query string alone is probably sufficient for many common use cases.
-- Jack Krupansky
From: Steve Davids
Sent: Monday, August 25, 2014 9:45 PM
To: dev@lucene.apache.org
Subject: Re: Logging levels in Solr code
I am personally in favour of some record of any request sent to a server being logged by default to help trace activity
It seems as though that would be more of a TRACE level item.
I have used the Log4J/SLF4J MDC to provide a distributed transaction id which makes life much easier to trace requests throughout the request chain, then display that transaction id for every item in the various logs. It is simple to implement, create a HTTPClient HttpRequestInterceptor to always append a header value to each request with the transaction UUID, that transaction ID is either taken off of the request via a ServletFilter or some other mechanism or automatically generated if it wasn’t present on the incoming request. Then simply reference the MDC value in the Log4J pattern via something like: %X{transactionId}.
I have found it extremely difficult to try and debug some of the distributed requests especially when I know that there are some servers that are having issues with socket connection timeouts, though the LBSolrServer doesn’t log when exceptions are thrown or when retry attempts are happening. I would love to see trace/debug level logging for initiating requests and info/warn if a request was unsuccessful for any reason.
Just some thoughts, you really only come across these things when things aren’t working right and it annoys you when the option isn’t there :)
-Steve
On Aug 25, 2014, at 6:04 PM, Mark Miller <ma...@gmail.com> wrote:
On Aug 25, 2014, at 5:21 PM, Ramkumar R. Aiyengar <an...@gmail.com> wrote:
I am personally in favour of some record of any request sent to a server being logged by default to help trace activity
Certainly you should have the option to turn it on, but I don’t think it makes a great default. I don’t think the standard user will find it that useful and it will flood logs, making finding other useful information more difficult and ballooning retention requirements so that you don’t lose relevant logs. When you batch or stream, it also only logs a subset of the adds by default.
- Mark
http://about.me/markrmiller
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
Re: Logging levels in Solr code
Posted by Steve Davids <sd...@gmail.com>.
>
> I am personally in favour of some record of any request sent to a server
> being logged by default to help trace activity
It seems as though that would be more of a TRACE level item.
I have used the Log4J/SLF4J MDC to provide a distributed transaction id
which makes life much easier to trace requests throughout the request
chain, then display that transaction id for every item in the various logs.
It is simple to implement, create a HTTPClient HttpRequestInterceptor to
always append a header value to each request with the transaction UUID,
that transaction ID is either taken off of the request via a ServletFilter
or some other mechanism or automatically generated if it wasn’t present on
the incoming request. Then simply reference the MDC value in the Log4J
pattern via something like: %X{transactionId}.
I have found it extremely difficult to try and debug some of the
distributed requests especially when I know that there are some servers
that are having issues with socket connection timeouts, though the
LBSolrServer doesn’t log when exceptions are thrown or when retry attempts
are happening. I would love to see trace/debug level logging for initiating
requests and info/warn if a request was unsuccessful for any reason.
Just some thoughts, you really only come across these things when things
aren’t working right and it annoys you when the option isn’t there :)
-Steve
On Aug 25, 2014, at 6:04 PM, Mark Miller <ma...@gmail.com> wrote:
On Aug 25, 2014, at 5:21 PM, Ramkumar R. Aiyengar <an...@gmail.com>
wrote:
I am personally in favour of some record of any request sent to a server
being logged by default to help trace activity
Certainly you should have the option to turn it on, but I don’t think it
makes a great default. I don’t think the standard user will find it that
useful and it will flood logs, making finding other useful information more
difficult and ballooning retention requirements so that you don’t lose
relevant logs. When you batch or stream, it also only logs a subset of the
adds by default.
- Mark
http://about.me/markrmiller
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
Re: Logging levels in Solr code
Posted by Mark Miller <ma...@gmail.com>.
> On Aug 25, 2014, at 5:21 PM, Ramkumar R. Aiyengar <an...@gmail.com> wrote:
>
> I am personally in favour of some record of any request sent to a server being logged by default to help trace activity
Certainly you should have the option to turn it on, but I don’t think it makes a great default. I don’t think the standard user will find it that useful and it will flood logs, making finding other useful information more difficult and ballooning retention requirements so that you don’t lose relevant logs. When you batch or stream, it also only logs a subset of the adds by default.
- Mark
http://about.me/markrmiller
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
Re: Logging levels in Solr code
Posted by "Ramkumar R. Aiyengar" <an...@gmail.com>.
Thanks Mark.
I am personally in favour of some record of any request sent to a server
being logged by default to help trace activity when something goes wrong
(which is something successful add logging indirectly achieves), but
unfortunately that currently includes internal distrib=false requests which
adds to the spam.
In any case, I will probably first start with ERROR and WAR...
On Mon, Aug 25, 2014 at 9:48 PM, Mark Miller <ma...@gmail.com> wrote:
>
>
> > On Aug 25, 2014, at 4:44 PM, Ramkumar R. Aiyengar <
> andyetitmoves@gmail.com> wrote:
> >
> > I am in the process of looking at some of the ERROR level log output
> coming from Solr to set up alarms, but currently the severity of what ERROR
> means is kind of mixed across the code base. I am happy to fix this where I
> find, but some guidance on what the various levels mean would be helpful.
> This is what I would have expected:
> >
> > • ERROR: Shouldn't happen, indicates a bug or misconfiguration.
> Leads to loss of functionality or some operation failing. Any occurrence
> indicates something needs to be fixed.
> > • WARN: Recoverable problem, might genuinely happen in rare cases.
> If it happens too often, might indicate an issue or misconfiguration. Bad
> input data could fall into this category, or should it be INFO?
> > • INFO: Informational messages which would help in investigation,
> indicates expected behaviour.
> > Let me know if this is not accurate..
> >
>
> Looks right overall. Which is not to say you won’t find an abuse here or
> there…
>
> bq. Bad input data could fall into this category,
>
> +1
>
> I’ve been using more DEBUG as well. I think INFO should not spam (like our
> default successful add logging does) - it should just be useful always
> logged stuff to help with debugging and monitoring and operations.
>
> DEBUG can be a bit more spammy and just whatever is useful if developing
> in that area.
>
> - Mark
>
> http://about.me/markrmiller
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
>
>
--
Not sent from my iPhone or my Blackberry or anyone else's
Re: Logging levels in Solr code
Posted by Mark Miller <ma...@gmail.com>.
> On Aug 25, 2014, at 4:44 PM, Ramkumar R. Aiyengar <an...@gmail.com> wrote:
>
> I am in the process of looking at some of the ERROR level log output coming from Solr to set up alarms, but currently the severity of what ERROR means is kind of mixed across the code base. I am happy to fix this where I find, but some guidance on what the various levels mean would be helpful. This is what I would have expected:
>
> • ERROR: Shouldn't happen, indicates a bug or misconfiguration. Leads to loss of functionality or some operation failing. Any occurrence indicates something needs to be fixed.
> • WARN: Recoverable problem, might genuinely happen in rare cases. If it happens too often, might indicate an issue or misconfiguration. Bad input data could fall into this category, or should it be INFO?
> • INFO: Informational messages which would help in investigation, indicates expected behaviour.
> Let me know if this is not accurate..
>
Looks right overall. Which is not to say you won’t find an abuse here or there…
bq. Bad input data could fall into this category,
+1
I’ve been using more DEBUG as well. I think INFO should not spam (like our default successful add logging does) - it should just be useful always logged stuff to help with debugging and monitoring and operations.
DEBUG can be a bit more spammy and just whatever is useful if developing in that area.
- Mark
http://about.me/markrmiller
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org