You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@cassandra.apache.org by Mick Semb Wever <mc...@apache.org> on 2024/07/23 11:35:02 UTC
Re: [DISCUSS] The way we log
reply below…
On Thu, 30 May 2024 at 14:34, Štefan Miklošovič <st...@gmail.com>
wrote:
> I see the feedback is overall positive. I will merge that and I will
> improve the documentation on the website along with what Benedict suggested.
>
I think the codestyle needs to be more explicit that this applies _only_ to
trace statements, and also take the opportunity to provide more context to
our unusual use of log levels and its implications.
tl;dr
For the debug log level I would like to propose we:
1. codestyle should mention that: debug doesn't mean debug to us, it is
for background activities intended to be enabled in production,
2. doc/comment in logback.xml that the debug logger should not be disabled
3. codestyle against (and remove all) isDebugEnabled
long format…
1.
Our debug logging is not "debug" but the "non read/write path logging".
We hijacked the debug loglevel for the separation of all background
activities. This trips most newcomers up. We can do a better job of
documenting this (see (2).
system.log == read/write path.
debug.log == also background activities.
There's some nuance here – there is logging around background activities
that we do want in system.log, which is correspondingly at the info
loglevel. But generally, on the read/write path, we want to use the trace
level when one typically thinks about "debug", and on the background paths,
use debug when thinking about "info".
More history on this in CASSANDRA-10241 and in
https://lists.apache.org/thread/mgmbmdw4cp4rq684wcllfjc3sd1sbhkm
This separation of log files between foreground and background activity
*is* very valuable to the operator (and expert). We have a lot of
experience on this.
And we did have some good docs about logging here:
https://cwiki.apache.org/confluence/display/CASSANDRA2/LoggingGuidelines
This should be revived IMHO.
2.
We often see operators in production disable the debug loglevel (or
appender), thinking they are doing the right thing. We are then left
unable to investigate issues related to background tasks (compaction,
streaming, repairs, etc), and have to ask them to enable it again before
collecting the logs again.
Aside: we do tell operators to disable either the file appenders or stdout,
as having both running is unnecessary. When they do this they often then
go and make the mistake of also disabling the ASYNCDEBUGLOG.
There's been calls in the past to better name our log files. I do favour
the renaming system.log to foreground.log, and debug.log to everything.log,
or anything along those lines. In the referenced ML thread there was also
discussion about using a marker, so to remove foreground activities from
debug.log, in which case a name like background.log would make more sense.
But renaming log files is a compatibility break, and is a separate
discussion.
3.
The use of isDebugEnabled should be avoided, as it confuses
- heavy methods calls in debug cannot be avoid
- that debug is always enabled (just like assertions)
- debug isn't appropriate on the read/write path (use trace instead)
- info isn't appropriate on the background paths, unless you intentionally
want it in system.log
Debug should never cause a production performance problem. A past example
of this confusion:
https://github.com/apache/cassandra/commit/ac77e5e7742548f7c7c25da3923841f59d4b2713
It's my understanding this has already been the intentional practice and
precedence for most of us, ~10% of debug calls today are wrapped by
isDebugEnabled, compared to ~37% for trace being wrapped with
isTraceEnabled.
While the use of isDebugEnabled might offer some small value to those that
adominantly want to disable the background logging, and see some minimal
perf improvement from it, I don't think that argument is popular, or wise,
enough against a healthy code style and precedence that is intuitive to its
intent.
Like our assert statements needing not to cause production performance
problems (because like debug we expect it to be enabled in production),
best we document our idiosyncrasies rather than let them be tribal
knowledge.
Re: [DISCUSS] The way we log
Posted by Mick Semb Wever <mc...@apache.org>.
> I disagree with all of this. Debug logging *can* be enabled for
> production clusters, but it should not be on by default.
>
> DEBUG should *not* be taken to mean “background activities” and we should
> stamp this out wherever this has been occurring. DEBUG means verbose
> logging for use debugging system behaviour. It should be safe to enable in
> production, but it should not be on by default.
>
> If you want to siphon some log messages to one log file, and others to
> another, we should be using some explicit mechanism such as a separate
> logger hierarchy, and *not* the log level.
>
I agree with you Benedict. But that's not what we have today, specifically
post CASSANDRA-10241.
What's your proposal to change it to *how it should be*? And who will do
that work ? Along with better naming of log files, I wholeheartedly support
a more intuitive approach to using separate loggers in the code, e.g. with
markers.
My proposal is only in lieu of such an agreement and change.
Re: [DISCUSS] The way we log
Posted by Benedict Elliott Smith <be...@apache.org>.
I disagree with all of this. Debug logging can be enabled for production clusters, but it should not be on by default.
DEBUG should not be taken to mean “background activities” and we should stamp this out wherever this has been occurring. DEBUG means verbose logging for use debugging system behaviour. It should be safe to enable in production, but it should not be on by default.
If you want to siphon some log messages to one log file, and others to another, we should be using some explicit mechanism such as a separate logger hierarchy, and not the log level.
> On 23 Jul 2024, at 12:35, Mick Semb Wever <mc...@apache.org> wrote:
>
> reply below…
>
>
> On Thu, 30 May 2024 at 14:34, Štefan Miklošovič <stefan.miklosovic@gmail.com <ma...@gmail.com>> wrote:
>> I see the feedback is overall positive. I will merge that and I will improve the documentation on the website along with what Benedict suggested.
>
>
>
> I think the codestyle needs to be more explicit that this applies _only_ to trace statements, and also take the opportunity to provide more context to our unusual use of log levels and its implications.
>
> tl;dr
>
> For the debug log level I would like to propose we:
> 1. codestyle should mention that: debug doesn't mean debug to us, it is for background activities intended to be enabled in production,
> 2. doc/comment in logback.xml that the debug logger should not be disabled
> 3. codestyle against (and remove all) isDebugEnabled
>
>
> long format…
>
> 1.
> Our debug logging is not "debug" but the "non read/write path logging".
> We hijacked the debug loglevel for the separation of all background activities. This trips most newcomers up. We can do a better job of documenting this (see (2).
>
> system.log == read/write path.
> debug.log == also background activities.
>
> There's some nuance here – there is logging around background activities that we do want in system.log, which is correspondingly at the info loglevel. But generally, on the read/write path, we want to use the trace level when one typically thinks about "debug", and on the background paths, use debug when thinking about "info".
>
> More history on this in CASSANDRA-10241 and in https://lists.apache.org/thread/mgmbmdw4cp4rq684wcllfjc3sd1sbhkm
>
> This separation of log files between foreground and background activity *is* very valuable to the operator (and expert). We have a lot of experience on this.
>
> And we did have some good docs about logging here: https://cwiki.apache.org/confluence/display/CASSANDRA2/LoggingGuidelines
> This should be revived IMHO.
>
> 2.
> We often see operators in production disable the debug loglevel (or appender), thinking they are doing the right thing. We are then left unable to investigate issues related to background tasks (compaction, streaming, repairs, etc), and have to ask them to enable it again before collecting the logs again.
>
> Aside: we do tell operators to disable either the file appenders or stdout, as having both running is unnecessary. When they do this they often then go and make the mistake of also disabling the ASYNCDEBUGLOG.
>
> There's been calls in the past to better name our log files. I do favour the renaming system.log to foreground.log, and debug.log to everything.log, or anything along those lines. In the referenced ML thread there was also discussion about using a marker, so to remove foreground activities from debug.log, in which case a name like background.log would make more sense. But renaming log files is a compatibility break, and is a separate discussion.
>
>
> 3.
> The use of isDebugEnabled should be avoided, as it confuses
> - heavy methods calls in debug cannot be avoid
> - that debug is always enabled (just like assertions)
> - debug isn't appropriate on the read/write path (use trace instead)
> - info isn't appropriate on the background paths, unless you intentionally want it in system.log
>
> Debug should never cause a production performance problem. A past example of this confusion: https://github.com/apache/cassandra/commit/ac77e5e7742548f7c7c25da3923841f59d4b2713
>
> It's my understanding this has already been the intentional practice and precedence for most of us, ~10% of debug calls today are wrapped by isDebugEnabled, compared to ~37% for trace being wrapped with isTraceEnabled.
>
> While the use of isDebugEnabled might offer some small value to those that adominantly want to disable the background logging, and see some minimal perf improvement from it, I don't think that argument is popular, or wise, enough against a healthy code style and precedence that is intuitive to its intent.
>
> Like our assert statements needing not to cause production performance problems (because like debug we expect it to be enabled in production), best we document our idiosyncrasies rather than let them be tribal knowledge.
>
>
>
Re: [DISCUSS] The way we log
Posted by Štefan Miklošovič <sm...@apache.org>.
>
> I do not agree we should remove isDebugEnabled tests, as debug logging
> should be possible to turn off and avoid any penalty.
>
if (logger.isDebugEnabled())
logger.debug("hello")
is performance-wise same as doing
logger.debug("hello")
we already went through this, the latter version internally checks what
level it is on so us wrapping it in additional "if" does not make any
difference.
The only reasonable use-case I see to justify the wrapping into
isDebugEnabled() is if the subsequent logger.debug logs something which
takes considerable time / memory to construct.
> However, it is not very important so I will not fight that battle. I will
> however fight any attempt to codify weird rules for logging levels.
>
> On 23 Jul 2024, at 14:26, J. D. Jordan <je...@gmail.com> wrote:
>
> I don’t know that I agree we should remove use if isDebugEnabled, but we
> should be assuming debug is enabled and not doing anything too crazy there.
> The description of the log levels from the old wiki describes the state of
> our logging very well, +1 to get that back into the docs.
> If someone wants to propose and implement a new logging scheme going
> forward that would be a different thread. We should make sure the docs and
> recommendations match the current state of the code.
>
> -Jeremiah
>
> On Jul 23, 2024, at 8:06 AM, Štefan Miklošovič <sm...@apache.org>
> wrote:
>
>
> For the record, I am OK with removing logger.isDebugEnabled() in the same
> spirit as it was done with logger.isTracingEnabled(). That is, some
> invocations of isDebugEnabled() are not necessary, logger.debug() is just
> enough, I already went through the reasons why it is so in the first email
> from which the decision to remove isTracingEnabled when it was not a heavy
> operation was made.
>
> The primary reason for not removing isDebugEnabled was just my hesitation
> to introduce any big diff but if we all think it is OK now to remove
> isDebugEnabled in trunk I am fine with that.
>
> I am not completely sure how to respond to all other stuff though so I'll
> skip that and see where this goes.
>
> On Tue, Jul 23, 2024 at 1:36 PM Mick Semb Wever <mc...@apache.org> wrote:
>
>> reply below…
>>
>>
>> On Thu, 30 May 2024 at 14:34, Štefan Miklošovič <
>> stefan.miklosovic@gmail.com> wrote:
>>
>>> I see the feedback is overall positive. I will merge that and I will
>>> improve the documentation on the website along with what Benedict suggested.
>>>
>>
>>
>>
>> I think the codestyle needs to be more explicit that this applies _only_
>> to trace statements, and also take the opportunity to provide more context
>> to our unusual use of log levels and its implications.
>>
>> tl;dr
>>
>> For the debug log level I would like to propose we:
>> 1. codestyle should mention that: debug doesn't mean debug to us, it is
>> for background activities intended to be enabled in production,
>> 2. doc/comment in logback.xml that the debug logger should not be
>> disabled
>> 3. codestyle against (and remove all) isDebugEnabled
>>
>>
>> long format…
>>
>> 1.
>> Our debug logging is not "debug" but the "non read/write path logging".
>> We hijacked the debug loglevel for the separation of all background
>> activities. This trips most newcomers up. We can do a better job of
>> documenting this (see (2).
>>
>> system.log == read/write path.
>> debug.log == also background activities.
>>
>> There's some nuance here – there is logging around background activities
>> that we do want in system.log, which is correspondingly at the info
>> loglevel. But generally, on the read/write path, we want to use the trace
>> level when one typically thinks about "debug", and on the background paths,
>> use debug when thinking about "info".
>>
>> More history on this in CASSANDRA-10241 and in
>> https://lists.apache.org/thread/mgmbmdw4cp4rq684wcllfjc3sd1sbhkm
>>
>> This separation of log files between foreground and background activity
>> *is* very valuable to the operator (and expert). We have a lot of
>> experience on this.
>>
>> And we did have some good docs about logging here:
>> https://cwiki.apache.org/confluence/display/CASSANDRA2/LoggingGuidelines
>> This should be revived IMHO.
>>
>> 2.
>> We often see operators in production disable the debug loglevel (or
>> appender), thinking they are doing the right thing. We are then left
>> unable to investigate issues related to background tasks (compaction,
>> streaming, repairs, etc), and have to ask them to enable it again before
>> collecting the logs again.
>>
>> Aside: we do tell operators to disable either the file appenders or
>> stdout, as having both running is unnecessary. When they do this they
>> often then go and make the mistake of also disabling the ASYNCDEBUGLOG.
>>
>> There's been calls in the past to better name our log files. I do favour
>> the renaming system.log to foreground.log, and debug.log to everything.log,
>> or anything along those lines. In the referenced ML thread there was also
>> discussion about using a marker, so to remove foreground activities from
>> debug.log, in which case a name like background.log would make more sense.
>> But renaming log files is a compatibility break, and is a separate
>> discussion.
>>
>>
>> 3.
>> The use of isDebugEnabled should be avoided, as it confuses
>> - heavy methods calls in debug cannot be avoid
>> - that debug is always enabled (just like assertions)
>> - debug isn't appropriate on the read/write path (use trace instead)
>> - info isn't appropriate on the background paths, unless you
>> intentionally want it in system.log
>>
>> Debug should never cause a production performance problem. A past
>> example of this confusion:
>> https://github.com/apache/cassandra/commit/ac77e5e7742548f7c7c25da3923841f59d4b2713
>>
>>
>> It's my understanding this has already been the intentional practice and
>> precedence for most of us, ~10% of debug calls today are wrapped by
>> isDebugEnabled, compared to ~37% for trace being wrapped with
>> isTraceEnabled.
>>
>> While the use of isDebugEnabled might offer some small value to those
>> that adominantly want to disable the background logging, and see some
>> minimal perf improvement from it, I don't think that argument is popular,
>> or wise, enough against a healthy code style and precedence that is
>> intuitive to its intent.
>>
>> Like our assert statements needing not to cause production performance
>> problems (because like debug we expect it to be enabled in production),
>> best we document our idiosyncrasies rather than let them be tribal
>> knowledge.
>>
>>
>>
>>
>
Re: [DISCUSS] The way we log
Posted by Benedict Elliott Smith <be...@apache.org>.
1) That is not the current state of the code;
2) We should anyway not be codifying something just because a handful of people have been doing it.
C-10241 does not accord with this view either - it makes clear the debug log output should be for "where we can log things that might help if something goes wrong.” It says nothing about logging “background tasks” and anyone using debug logging this way should stop. We should make clear this is not the right way to separate log files.
I do not agree we should remove isDebugEnabled tests, as debug logging should be possible to turn off and avoid any penalty. However, it is not very important so I will not fight that battle. I will however fight any attempt to codify weird rules for logging levels.
> On 23 Jul 2024, at 14:26, J. D. Jordan <je...@gmail.com> wrote:
>
> I don’t know that I agree we should remove use if isDebugEnabled, but we should be assuming debug is enabled and not doing anything too crazy there.
> The description of the log levels from the old wiki describes the state of our logging very well, +1 to get that back into the docs.
> If someone wants to propose and implement a new logging scheme going forward that would be a different thread. We should make sure the docs and recommendations match the current state of the code.
>
> -Jeremiah
>
>> On Jul 23, 2024, at 8:06 AM, Štefan Miklošovič <sm...@apache.org> wrote:
>>
>>
>> For the record, I am OK with removing logger.isDebugEnabled() in the same spirit as it was done with logger.isTracingEnabled(). That is, some invocations of isDebugEnabled() are not necessary, logger.debug() is just enough, I already went through the reasons why it is so in the first email from which the decision to remove isTracingEnabled when it was not a heavy operation was made.
>>
>> The primary reason for not removing isDebugEnabled was just my hesitation to introduce any big diff but if we all think it is OK now to remove isDebugEnabled in trunk I am fine with that.
>>
>> I am not completely sure how to respond to all other stuff though so I'll skip that and see where this goes.
>>
>> On Tue, Jul 23, 2024 at 1:36 PM Mick Semb Wever <mck@apache.org <ma...@apache.org>> wrote:
>>> reply below…
>>>
>>>
>>> On Thu, 30 May 2024 at 14:34, Štefan Miklošovič <stefan.miklosovic@gmail.com <ma...@gmail.com>> wrote:
>>>> I see the feedback is overall positive. I will merge that and I will improve the documentation on the website along with what Benedict suggested.
>>>
>>>
>>>
>>> I think the codestyle needs to be more explicit that this applies _only_ to trace statements, and also take the opportunity to provide more context to our unusual use of log levels and its implications.
>>>
>>> tl;dr
>>>
>>> For the debug log level I would like to propose we:
>>> 1. codestyle should mention that: debug doesn't mean debug to us, it is for background activities intended to be enabled in production,
>>> 2. doc/comment in logback.xml that the debug logger should not be disabled
>>> 3. codestyle against (and remove all) isDebugEnabled
>>>
>>>
>>> long format…
>>>
>>> 1.
>>> Our debug logging is not "debug" but the "non read/write path logging".
>>> We hijacked the debug loglevel for the separation of all background activities. This trips most newcomers up. We can do a better job of documenting this (see (2).
>>>
>>> system.log == read/write path.
>>> debug.log == also background activities.
>>>
>>> There's some nuance here – there is logging around background activities that we do want in system.log, which is correspondingly at the info loglevel. But generally, on the read/write path, we want to use the trace level when one typically thinks about "debug", and on the background paths, use debug when thinking about "info".
>>>
>>> More history on this in CASSANDRA-10241 and in https://lists.apache.org/thread/mgmbmdw4cp4rq684wcllfjc3sd1sbhkm
>>>
>>> This separation of log files between foreground and background activity *is* very valuable to the operator (and expert). We have a lot of experience on this.
>>>
>>> And we did have some good docs about logging here: https://cwiki.apache.org/confluence/display/CASSANDRA2/LoggingGuidelines
>>> This should be revived IMHO.
>>>
>>> 2.
>>> We often see operators in production disable the debug loglevel (or appender), thinking they are doing the right thing. We are then left unable to investigate issues related to background tasks (compaction, streaming, repairs, etc), and have to ask them to enable it again before collecting the logs again.
>>>
>>> Aside: we do tell operators to disable either the file appenders or stdout, as having both running is unnecessary. When they do this they often then go and make the mistake of also disabling the ASYNCDEBUGLOG.
>>>
>>> There's been calls in the past to better name our log files. I do favour the renaming system.log to foreground.log, and debug.log to everything.log, or anything along those lines. In the referenced ML thread there was also discussion about using a marker, so to remove foreground activities from debug.log, in which case a name like background.log would make more sense. But renaming log files is a compatibility break, and is a separate discussion.
>>>
>>>
>>> 3.
>>> The use of isDebugEnabled should be avoided, as it confuses
>>> - heavy methods calls in debug cannot be avoid
>>> - that debug is always enabled (just like assertions)
>>> - debug isn't appropriate on the read/write path (use trace instead)
>>> - info isn't appropriate on the background paths, unless you intentionally want it in system.log
>>>
>>> Debug should never cause a production performance problem. A past example of this confusion: https://github.com/apache/cassandra/commit/ac77e5e7742548f7c7c25da3923841f59d4b2713
>>>
>>> It's my understanding this has already been the intentional practice and precedence for most of us, ~10% of debug calls today are wrapped by isDebugEnabled, compared to ~37% for trace being wrapped with isTraceEnabled.
>>>
>>> While the use of isDebugEnabled might offer some small value to those that adominantly want to disable the background logging, and see some minimal perf improvement from it, I don't think that argument is popular, or wise, enough against a healthy code style and precedence that is intuitive to its intent.
>>>
>>> Like our assert statements needing not to cause production performance problems (because like debug we expect it to be enabled in production), best we document our idiosyncrasies rather than let them be tribal knowledge.
>>>
>>>
>>>
Re: [DISCUSS] The way we log
Posted by Jon Haddad <ru...@apache.org>.
+1 to using Markers, and to Josh's & Benedict's points.
Logs have defined semantics, redefining them is confusing. To be completely honest, I wasn't even consciously aware of the convention that DEBUG would be used for background logs. I don't expect most users would be either.
On 2024/07/31 17:10:06 Aleksey Yeshchenko wrote:
> I reckon we could start using slf4j/logback Markers to tag individual logging statements as foreground/background (or, ideally, with more granularity than that - separate out repair, compaction, schema, reads/wrties, etc.).
>
> > On 24 Jul 2024, at 16:02, Josh McKenzie <jm...@apache.org> wrote:
> >
> > I argued this point 6 years ago and I'll continue to argue it today. Relying on assertions in production code by default, having debug live in production code by default, these are code and culture smells to me. Yes we work on complex distributed systems. No we should not be relying on crutches like this in production environments to make up for the fact that our property and fuzz-based testing has historically been inadequate. And don't get me started on it being 2024 and us not having nightly perf regression testing.
> >
> > Let me quote Benedict and strongly +1 his words here:
> >
> >> Debug logging can be enabled for production clusters, but it should not be on by default.
> >
> >> DEBUG should not be taken to mean “background activities” and we should stamp this out wherever this has been occurring
> >
> >> DEBUG means verbose logging for use debugging system behaviour. It should be safe to enable in production, but it should not be on by default.
> >
> >> We should anyway not be codifying something just because a handful of people have been doing it.
> >
> > Doing our own thing w/regards to logging as a project is a pretty big unforced error IMO.
> >
> > A brief glance at cockroach's logging channels <https://www.cockroachlabs.com/docs/stable/logging-overview#logging-channels> and sinks or postgres' various severity levels <https://www.postgresql.org/docs/current/runtime-config-logging.html#RUNTIME-CONFIG-SEVERITY-LEVELS> etc. just reinforces for me how our approach to logging and debug feels ad-hoc, reactive, and organic to me. There's a lot of prior art we could learn from here.
> >
> > So I'm in my glass house here chucking stones, because of course I don't have the bandwidth to help address any of this. I'm with you on this Mick:
> >> What's your proposal to change it to how it should be? And who will do that work ? Along with better naming of log files, I wholeheartedly support a more intuitive approach to using separate loggers in the code, e.g. with markers.
> >>
> >> My proposal is only in lieu of such an agreement and change.
> >
> > On Wed, Jul 24, 2024, at 4:59 AM, Berenguer Blasi wrote:
> >> I wouldn't forbid isDebugEnabled.
> >>
> >> Guarding heavy debug params with it makes perfect sense per se, you avoid a perf penalty with 1 loc. If in C* production clusters are expected/preferred to be run with debug logging on so be it but being an OSS project we're unaware of all tools, side-projects and any other consumers of our code. They could be benefiting from not running in debug.
> >>
> >> Parsing the use of isDebugEnabled as making debug not meant for production is sthg I am not totally following. Debug is, imo, is perfectly fine in production for it's intended uses and with it's know impact. If we want to signal we want C* to be ran in debug in production then let's add a big warning in the logback xml files on even log that as a WARN or ERROR. But I wouldn't push down that concern into the code style.
> >>
> >> Besides, imo, if we remove/forbid it getting it back if we changed our minds wouldn't be an easy task. Whereas if it's there it doesn't hurt.
> >>
> >> My 2cts
> >>
> >> On 23/7/24 16:12, Mick Semb Wever wrote:
> >>>
> >>>
> >>> On Tue, 23 Jul 2024 at 15:27, J. D. Jordan <jeremiah.jordan@gmail.com <ma...@gmail.com>> wrote:
> >>> I don’t know that I agree we should remove use if isDebugEnabled, but we should be assuming debug is enabled and not doing anything too crazy there.
> >>>
> >>>
> >>> The problem is that the use of isDebugEnabled, as trivial as it is, leads to the typical assumption that debug is not meant for production. This has tripped us up in the past. It's important that debug logging does not impact production performance. Any use of isDebugEnabled is counter-intuitive to this. Maybe restoring the logging guidelines is enough, but I'd argue that we can further simplify things (at least against our current state of affairs) by just disallowing the use of isDebugEnabled altogether.
> >>>
> >>> And yes, debug equalling background tasks is not entirely accurate, my bad (the doc provides a far more accurate description to what might be found in system vs debug log files). And there's for example read/write tracing, that if enabled, might only be found in the debug.log . This has been brought up previously, and in the ticket and old ml thread there's mention in keeping system.log clean to read/writes/hotpaths. The logging guideline was written (by Paulo I believe) as a result of 10241 and that old ml thread.
> >>> We have an existing logging guideline doc, we need debug to be performant in production – it is enabled by default, and is designed and recommended to be used in production.
>
>
Re: [DISCUSS] The way we log
Posted by Aleksey Yeshchenko <al...@apple.com>.
I reckon we could start using slf4j/logback Markers to tag individual logging statements as foreground/background (or, ideally, with more granularity than that - separate out repair, compaction, schema, reads/wrties, etc.).
> On 24 Jul 2024, at 16:02, Josh McKenzie <jm...@apache.org> wrote:
>
> I argued this point 6 years ago and I'll continue to argue it today. Relying on assertions in production code by default, having debug live in production code by default, these are code and culture smells to me. Yes we work on complex distributed systems. No we should not be relying on crutches like this in production environments to make up for the fact that our property and fuzz-based testing has historically been inadequate. And don't get me started on it being 2024 and us not having nightly perf regression testing.
>
> Let me quote Benedict and strongly +1 his words here:
>
>> Debug logging can be enabled for production clusters, but it should not be on by default.
>
>> DEBUG should not be taken to mean “background activities” and we should stamp this out wherever this has been occurring
>
>> DEBUG means verbose logging for use debugging system behaviour. It should be safe to enable in production, but it should not be on by default.
>
>> We should anyway not be codifying something just because a handful of people have been doing it.
>
> Doing our own thing w/regards to logging as a project is a pretty big unforced error IMO.
>
> A brief glance at cockroach's logging channels <https://www.cockroachlabs.com/docs/stable/logging-overview#logging-channels> and sinks or postgres' various severity levels <https://www.postgresql.org/docs/current/runtime-config-logging.html#RUNTIME-CONFIG-SEVERITY-LEVELS> etc. just reinforces for me how our approach to logging and debug feels ad-hoc, reactive, and organic to me. There's a lot of prior art we could learn from here.
>
> So I'm in my glass house here chucking stones, because of course I don't have the bandwidth to help address any of this. I'm with you on this Mick:
>> What's your proposal to change it to how it should be? And who will do that work ? Along with better naming of log files, I wholeheartedly support a more intuitive approach to using separate loggers in the code, e.g. with markers.
>>
>> My proposal is only in lieu of such an agreement and change.
>
> On Wed, Jul 24, 2024, at 4:59 AM, Berenguer Blasi wrote:
>> I wouldn't forbid isDebugEnabled.
>>
>> Guarding heavy debug params with it makes perfect sense per se, you avoid a perf penalty with 1 loc. If in C* production clusters are expected/preferred to be run with debug logging on so be it but being an OSS project we're unaware of all tools, side-projects and any other consumers of our code. They could be benefiting from not running in debug.
>>
>> Parsing the use of isDebugEnabled as making debug not meant for production is sthg I am not totally following. Debug is, imo, is perfectly fine in production for it's intended uses and with it's know impact. If we want to signal we want C* to be ran in debug in production then let's add a big warning in the logback xml files on even log that as a WARN or ERROR. But I wouldn't push down that concern into the code style.
>>
>> Besides, imo, if we remove/forbid it getting it back if we changed our minds wouldn't be an easy task. Whereas if it's there it doesn't hurt.
>>
>> My 2cts
>>
>> On 23/7/24 16:12, Mick Semb Wever wrote:
>>>
>>>
>>> On Tue, 23 Jul 2024 at 15:27, J. D. Jordan <jeremiah.jordan@gmail.com <ma...@gmail.com>> wrote:
>>> I don’t know that I agree we should remove use if isDebugEnabled, but we should be assuming debug is enabled and not doing anything too crazy there.
>>>
>>>
>>> The problem is that the use of isDebugEnabled, as trivial as it is, leads to the typical assumption that debug is not meant for production. This has tripped us up in the past. It's important that debug logging does not impact production performance. Any use of isDebugEnabled is counter-intuitive to this. Maybe restoring the logging guidelines is enough, but I'd argue that we can further simplify things (at least against our current state of affairs) by just disallowing the use of isDebugEnabled altogether.
>>>
>>> And yes, debug equalling background tasks is not entirely accurate, my bad (the doc provides a far more accurate description to what might be found in system vs debug log files). And there's for example read/write tracing, that if enabled, might only be found in the debug.log . This has been brought up previously, and in the ticket and old ml thread there's mention in keeping system.log clean to read/writes/hotpaths. The logging guideline was written (by Paulo I believe) as a result of 10241 and that old ml thread.
>>> We have an existing logging guideline doc, we need debug to be performant in production – it is enabled by default, and is designed and recommended to be used in production.
Re: [DISCUSS] The way we log
Posted by Josh McKenzie <jm...@apache.org>.
I argued this point 6 years ago and I'll continue to argue it today. Relying on assertions in production code by default, having debug live in production code by default, these are code and culture smells to me. Yes we work on complex distributed systems. No we should not be relying on crutches like this in production environments to make up for the fact that our property and fuzz-based testing has historically been inadequate. And don't get me started on it being 2024 and us not having nightly perf regression testing.
Let me quote Benedict and strongly +1 his words here:
> Debug logging *can* be enabled for production clusters, but it should not be on by default.
> DEBUG should *not* be taken to mean “background activities” and we should stamp this out wherever this has been occurring
> DEBUG means verbose logging for use debugging system behaviour. It should be safe to enable in production, but it should not be on by default.
> We should anyway not be codifying something just because a handful of people have been doing it.
Doing our own thing w/regards to logging as a project is a pretty big unforced error IMO.
A brief glance at cockroach's logging channels <https://www.cockroachlabs.com/docs/stable/logging-overview#logging-channels> and sinks or postgres' various severity levels <https://www.postgresql.org/docs/current/runtime-config-logging.html#RUNTIME-CONFIG-SEVERITY-LEVELS> etc. just reinforces for me how our approach to logging and debug feels ad-hoc, reactive, and organic to me. There's a lot of prior art we could learn from here.
So I'm in my glass house here chucking stones, because of course I don't have the bandwidth to help *address* any of this. I'm with you on this Mick:
> What's your proposal to change it to *how it should be*? And who will do that work ? Along with better naming of log files, I wholeheartedly support a more intuitive approach to using separate loggers in the code, e.g. with markers.
>
> My proposal is only in lieu of such an agreement and change.
On Wed, Jul 24, 2024, at 4:59 AM, Berenguer Blasi wrote:
> I wouldn't forbid isDebugEnabled.
>
> Guarding heavy debug params with it makes perfect sense per se, you avoid a perf penalty with 1 loc. If in C* production clusters are expected/preferred to be run with debug logging on so be it but being an OSS project we're unaware of all tools, side-projects and any other consumers of our code. They could be benefiting from not running in debug.
>
> Parsing the use of isDebugEnabled as making debug not meant for production is sthg I am not totally following. Debug is, imo, is perfectly fine in production for it's intended uses and with it's know impact. If we want to signal we want C* to be ran in debug in production then let's add a big warning in the logback xml files on even log that as a WARN or ERROR. But I wouldn't push down that concern into the code style.
>
> Besides, imo, if we remove/forbid it getting it back if we changed our minds wouldn't be an easy task. Whereas if it's there it doesn't hurt.
>
> My 2cts
>
> On 23/7/24 16:12, Mick Semb Wever wrote:
>>
>>
>> On Tue, 23 Jul 2024 at 15:27, J. D. Jordan <je...@gmail.com> wrote:
>>> I don’t know that I agree we should remove use if isDebugEnabled, but we should be assuming debug is enabled and not doing anything too crazy there.
>>
>>
>> The problem is that the use of isDebugEnabled, as trivial as it is, leads to the typical assumption that debug is not meant for production. This has tripped us up in the past. It's important that debug logging does not impact production performance. Any use of isDebugEnabled is counter-intuitive to this. Maybe restoring the logging guidelines is enough, but I'd argue that we can further simplify things (at least against our current state of affairs) by just disallowing the use of isDebugEnabled altogether.
>>
>> And yes, debug equalling background tasks is not entirely accurate, my bad (the doc provides a far more accurate description to what might be found in system vs debug log files). And there's for example read/write tracing, that if enabled, might only be found in the debug.log . This has been brought up previously, and in the ticket and old ml thread there's mention in keeping system.log clean to read/writes/hotpaths. The logging guideline was written (by Paulo I believe) as a result of 10241 and that old ml thread.
>> We have an existing logging guideline doc, we need debug to be performant in production – it is enabled by default, and is designed and recommended to be used in production.
>>
>>
>>
Re: [DISCUSS] The way we log
Posted by Berenguer Blasi <be...@gmail.com>.
I wouldn't forbid isDebugEnabled.
Guarding heavy debug params with it makes perfect sense per se, you
avoid a perf penalty with 1 loc. If in C* production clusters are
expected/preferred to be run with debug logging on so be it but being an
OSS project we're unaware of all tools, side-projects and any other
consumers of our code. They could be benefiting from not running in debug.
Parsing the use of isDebugEnabled as making debug not meant for
production is sthg I am not totally following. Debug is, imo, is
perfectly fine in production for it's intended uses and with it's know
impact. If we want to signal we want C* to be ran in debug in production
then let's add a big warning in the logback xml files on even log that
as a WARN or ERROR. But I wouldn't push down that concern into the code
style.
Besides, imo, if we remove/forbid it getting it back if we changed our
minds wouldn't be an easy task. Whereas if it's there it doesn't hurt.
My 2cts
On 23/7/24 16:12, Mick Semb Wever wrote:
>
>
> On Tue, 23 Jul 2024 at 15:27, J. D. Jordan <je...@gmail.com>
> wrote:
>
> I don’t know that I agree we should remove use if isDebugEnabled,
> but we should be assuming debug is enabled and not doing anything
> too crazy there.
>
>
>
> The problem is that the use of isDebugEnabled, as trivial as it is,
> leads to the typical assumption that debug is not meant for
> production. This has tripped us up in the past. It's important that
> debug logging does not impact production performance. Any use of
> isDebugEnabled is counter-intuitive to this. Maybe restoring the
> logging guidelines is enough, but I'd argue that we can further
> simplify things (at least against our current state of affairs) by
> just disallowing the use of isDebugEnabled altogether.
>
> And yes, debug equalling background tasks is not entirely accurate, my
> bad (the doc provides a far more accurate description to what might be
> found in system vs debug log files). And there's for example
> read/write tracing, that if enabled, might only be found in the
> debug.log . This has been brought up previously, and in the ticket
> and old ml thread there's mention in keeping system.log clean to
> read/writes/hotpaths. The logging guideline was written (by Paulo I
> believe) as a result of 10241 and that old ml thread.
>
> We have an existing logging guideline doc, we need debug to be
> performant in production – it is enabled by default, and is designed
> and recommended to be used in production.
>
>
Re: [DISCUSS] The way we log
Posted by Mick Semb Wever <mc...@apache.org>.
On Tue, 23 Jul 2024 at 15:27, J. D. Jordan <je...@gmail.com>
wrote:
> I don’t know that I agree we should remove use if isDebugEnabled, but we
> should be assuming debug is enabled and not doing anything too crazy there.
>
The problem is that the use of isDebugEnabled, as trivial as it is, leads
to the typical assumption that debug is not meant for production. This has
tripped us up in the past. It's important that debug logging does not
impact production performance. Any use of isDebugEnabled is
counter-intuitive to this. Maybe restoring the logging guidelines is
enough, but I'd argue that we can further simplify things (at least against
our current state of affairs) by just disallowing the use of isDebugEnabled
altogether.
And yes, debug equalling background tasks is not entirely accurate, my bad
(the doc provides a far more accurate description to what might be found in
system vs debug log files). And there's for example read/write tracing,
that if enabled, might only be found in the debug.log . This has been
brought up previously, and in the ticket and old ml thread there's mention
in keeping system.log clean to read/writes/hotpaths. The logging guideline
was written (by Paulo I believe) as a result of 10241 and that old ml
thread.
We have an existing logging guideline doc, we need debug to be performant
in production – it is enabled by default, and is designed and recommended
to be used in production.
Re: [DISCUSS] The way we log
Posted by Štefan Miklošovič <sm...@apache.org>.
I don't know what consists of "too crazy" in your books. It would look same
as it is now after we removed isTracingEnabled. Maybe going through the
opening email and seeing the reasoning why, similarly, isDebugEnabled is
not always necessary would be helpful?
On Tue, Jul 23, 2024 at 3:27 PM J. D. Jordan <je...@gmail.com>
wrote:
> I don’t know that I agree we should remove use if isDebugEnabled, but we
> should be assuming debug is enabled and not doing anything too crazy there.
> The description of the log levels from the old wiki describes the state of
> our logging very well, +1 to get that back into the docs.
> If someone wants to propose and implement a new logging scheme going
> forward that would be a different thread. We should make sure the docs and
> recommendations match the current state of the code.
>
> -Jeremiah
>
> On Jul 23, 2024, at 8:06 AM, Štefan Miklošovič <sm...@apache.org>
> wrote:
>
>
> For the record, I am OK with removing logger.isDebugEnabled() in the same
> spirit as it was done with logger.isTracingEnabled(). That is, some
> invocations of isDebugEnabled() are not necessary, logger.debug() is just
> enough, I already went through the reasons why it is so in the first email
> from which the decision to remove isTracingEnabled when it was not a heavy
> operation was made.
>
> The primary reason for not removing isDebugEnabled was just my hesitation
> to introduce any big diff but if we all think it is OK now to remove
> isDebugEnabled in trunk I am fine with that.
>
> I am not completely sure how to respond to all other stuff though so I'll
> skip that and see where this goes.
>
> On Tue, Jul 23, 2024 at 1:36 PM Mick Semb Wever <mc...@apache.org> wrote:
>
>> reply below…
>>
>>
>> On Thu, 30 May 2024 at 14:34, Štefan Miklošovič <
>> stefan.miklosovic@gmail.com> wrote:
>>
>>> I see the feedback is overall positive. I will merge that and I will
>>> improve the documentation on the website along with what Benedict suggested.
>>>
>>
>>
>>
>> I think the codestyle needs to be more explicit that this applies _only_
>> to trace statements, and also take the opportunity to provide more context
>> to our unusual use of log levels and its implications.
>>
>> tl;dr
>>
>> For the debug log level I would like to propose we:
>> 1. codestyle should mention that: debug doesn't mean debug to us, it is
>> for background activities intended to be enabled in production,
>> 2. doc/comment in logback.xml that the debug logger should not be
>> disabled
>> 3. codestyle against (and remove all) isDebugEnabled
>>
>>
>> long format…
>>
>> 1.
>> Our debug logging is not "debug" but the "non read/write path logging".
>> We hijacked the debug loglevel for the separation of all background
>> activities. This trips most newcomers up. We can do a better job of
>> documenting this (see (2).
>>
>> system.log == read/write path.
>> debug.log == also background activities.
>>
>> There's some nuance here – there is logging around background activities
>> that we do want in system.log, which is correspondingly at the info
>> loglevel. But generally, on the read/write path, we want to use the trace
>> level when one typically thinks about "debug", and on the background paths,
>> use debug when thinking about "info".
>>
>> More history on this in CASSANDRA-10241 and in
>> https://lists.apache.org/thread/mgmbmdw4cp4rq684wcllfjc3sd1sbhkm
>>
>> This separation of log files between foreground and background activity
>> *is* very valuable to the operator (and expert). We have a lot of
>> experience on this.
>>
>> And we did have some good docs about logging here:
>> https://cwiki.apache.org/confluence/display/CASSANDRA2/LoggingGuidelines
>> This should be revived IMHO.
>>
>> 2.
>> We often see operators in production disable the debug loglevel (or
>> appender), thinking they are doing the right thing. We are then left
>> unable to investigate issues related to background tasks (compaction,
>> streaming, repairs, etc), and have to ask them to enable it again before
>> collecting the logs again.
>>
>> Aside: we do tell operators to disable either the file appenders or
>> stdout, as having both running is unnecessary. When they do this they
>> often then go and make the mistake of also disabling the ASYNCDEBUGLOG.
>>
>> There's been calls in the past to better name our log files. I do favour
>> the renaming system.log to foreground.log, and debug.log to everything.log,
>> or anything along those lines. In the referenced ML thread there was also
>> discussion about using a marker, so to remove foreground activities from
>> debug.log, in which case a name like background.log would make more sense.
>> But renaming log files is a compatibility break, and is a separate
>> discussion.
>>
>>
>> 3.
>> The use of isDebugEnabled should be avoided, as it confuses
>> - heavy methods calls in debug cannot be avoid
>> - that debug is always enabled (just like assertions)
>> - debug isn't appropriate on the read/write path (use trace instead)
>> - info isn't appropriate on the background paths, unless you
>> intentionally want it in system.log
>>
>> Debug should never cause a production performance problem. A past
>> example of this confusion:
>> https://github.com/apache/cassandra/commit/ac77e5e7742548f7c7c25da3923841f59d4b2713
>>
>>
>> It's my understanding this has already been the intentional practice and
>> precedence for most of us, ~10% of debug calls today are wrapped by
>> isDebugEnabled, compared to ~37% for trace being wrapped with
>> isTraceEnabled.
>>
>> While the use of isDebugEnabled might offer some small value to those
>> that adominantly want to disable the background logging, and see some
>> minimal perf improvement from it, I don't think that argument is popular,
>> or wise, enough against a healthy code style and precedence that is
>> intuitive to its intent.
>>
>> Like our assert statements needing not to cause production performance
>> problems (because like debug we expect it to be enabled in production),
>> best we document our idiosyncrasies rather than let them be tribal
>> knowledge.
>>
>>
>>
>>
Re: [DISCUSS] The way we log
Posted by "J. D. Jordan" <je...@gmail.com>.
I don’t know that I agree we should remove use if isDebugEnabled, but we
should be assuming debug is enabled and not doing anything too crazy there.
The description of the log levels from the old wiki describes the state of our
logging very well, +1 to get that back into the docs.
If someone wants to propose and implement a new logging scheme going forward
that would be a different thread. We should make sure the docs and
recommendations match the current state of the code.
-Jeremiah
> On Jul 23, 2024, at 8:06 AM, Štefan Miklošovič <sm...@apache.org>
> wrote:
>
>
>
>
> For the record, I am OK with removing logger.isDebugEnabled() in the same
> spirit as it was done with logger.isTracingEnabled(). That is, some
> invocations of isDebugEnabled() are not necessary, logger.debug() is just
> enough, I already went through the reasons why it is so in the first email
> from which the decision to remove isTracingEnabled when it was not a heavy
> operation was made.
>
> The primary reason for not removing isDebugEnabled was just my hesitation to
> introduce any big diff but if we all think it is OK now to remove
> isDebugEnabled in trunk I am fine with that.
>
> I am not completely sure how to respond to all other stuff though so I'll
> skip that and see where this goes.
>
>
>
>
>
> On Tue, Jul 23, 2024 at 1:36 PM Mick Semb Wever
> <[mck@apache.org](mailto:mck@apache.org)> wrote:
>
>
>> reply below…
>>
>>
>
>>
>>
>
>>
>> On Thu, 30 May 2024 at 14:34, Štefan Miklošovič
<[stefan.miklosovic@gmail.com](mailto:stefan.miklosovic@gmail.com)> wrote:
>
>>
>>> I see the feedback is overall positive. I will merge that and I will
improve the documentation on the website along with what Benedict suggested.
>>
>>
>
>>
>>
>
>>
>>
>
>>
>> I think the codestyle needs to be more explicit that this applies _only_ to
trace statements, and also take the opportunity to provide more context to our
unusual use of log levels and its implications.
>>
>>
>
>>
>> tl;dr
>>
>>
>
>>
>> For the debug log level I would like to propose we:
>>
>> 1\. codestyle should mention that: debug doesn't mean debug to us, it is
for background activities intended to be enabled in production,
> 2\. doc/comment in logback.xml that the debug logger should not be disabled
>>
>> 3\. codestyle against (and remove all) isDebugEnabled
>>
>>
>
>>
>>
>
>>
>> long format…
>>
>>
>
>>
>> 1.
>>
>> Our debug logging is not "debug" but the "non read/write path logging".
>
>>
>> We hijacked the debug loglevel for the separation of all background
activities. This trips most newcomers up. We can do a better job of
documenting this (see (2).
>>
>>
>
>>
>> system.log == read/write path.
>>
>> debug.log == also background activities.
>>
>>
>
>>
>> There's some nuance here – there is logging around background activities
that we do want in system.log, which is correspondingly at the info loglevel.
But generally, on the read/write path, we want to use the trace level when one
typically thinks about "debug", and on the background paths, use debug when
thinking about "info".
>>
>>
>
>>
>> More history on this in CASSANDRA-10241 and in
<https://lists.apache.org/thread/mgmbmdw4cp4rq684wcllfjc3sd1sbhkm>
>>
>>
>
>>
>> This separation of log files between foreground and background activity
*is* very valuable to the operator (and expert). We have a lot of experience
on this.
>>
>>
>
>>
>> And we did have some good docs about logging here:
<https://cwiki.apache.org/confluence/display/CASSANDRA2/LoggingGuidelines>
>>
>> This should be revived IMHO.
>>
>>
>
>>
>> 2.
>>
>> We often see operators in production disable the debug loglevel (or
appender), thinking they are doing the right thing. We are then left unable
to investigate issues related to background tasks (compaction, streaming,
repairs, etc), and have to ask them to enable it again before collecting the
logs again.
>>
>>
>
>>
>> Aside: we do tell operators to disable either the file appenders or stdout,
as having both running is unnecessary. When they do this they often then go
and make the mistake of also disabling the ASYNCDEBUGLOG.
>>
>>
>
>>
>> There's been calls in the past to better name our log files. I do favour
the renaming system.log to foreground.log, and debug.log to everything.log, or
anything along those lines. In the referenced ML thread there was also
discussion about using a marker, so to remove foreground activities from
debug.log, in which case a name like background.log would make more sense.
But renaming log files is a compatibility break, and is a separate discussion.
>>
>>
>
>>
>>
>
>>
>> 3.
>>
>> The use of isDebugEnabled should be avoided, as it confuses
>>
>> \- heavy methods calls in debug cannot be avoid
>>
>> \- that debug is always enabled (just like assertions)
>>
>> \- debug isn't appropriate on the read/write path (use trace instead)
>>
>> \- info isn't appropriate on the background paths, unless you intentionally
want it in system.log
>>
>>
>
>>
>> Debug should never cause a production performance problem. A past example
of this confusion:
<https://github.com/apache/cassandra/commit/ac77e5e7742548f7c7c25da3923841f59d4b2713>
>>
>>
>
>>
>> It's my understanding this has already been the intentional practice and
precedence for most of us, ~10% of debug calls today are wrapped by
isDebugEnabled, compared to ~37% for trace being wrapped with isTraceEnabled.
>>
>>
>
>>
>> While the use of isDebugEnabled might offer some small value to those that
adominantly want to disable the background logging, and see some minimal perf
improvement from it, I don't think that argument is popular, or wise, enough
against a healthy code style and precedence that is intuitive to its intent.
>>
>>
>
>>
>> Like our assert statements needing not to cause production performance
problems (because like debug we expect it to be enabled in production), best
we document our idiosyncrasies rather than let them be tribal knowledge.
>>
>>
>
>>
>>
>
>>
>>
>
Re: [DISCUSS] The way we log
Posted by Štefan Miklošovič <sm...@apache.org>.
For the record, I am OK with removing logger.isDebugEnabled() in the same
spirit as it was done with logger.isTracingEnabled(). That is, some
invocations of isDebugEnabled() are not necessary, logger.debug() is just
enough, I already went through the reasons why it is so in the first email
from which the decision to remove isTracingEnabled when it was not a heavy
operation was made.
The primary reason for not removing isDebugEnabled was just my hesitation
to introduce any big diff but if we all think it is OK now to remove
isDebugEnabled in trunk I am fine with that.
I am not completely sure how to respond to all other stuff though so I'll
skip that and see where this goes.
On Tue, Jul 23, 2024 at 1:36 PM Mick Semb Wever <mc...@apache.org> wrote:
> reply below…
>
>
> On Thu, 30 May 2024 at 14:34, Štefan Miklošovič <
> stefan.miklosovic@gmail.com> wrote:
>
>> I see the feedback is overall positive. I will merge that and I will
>> improve the documentation on the website along with what Benedict suggested.
>>
>
>
>
> I think the codestyle needs to be more explicit that this applies _only_
> to trace statements, and also take the opportunity to provide more context
> to our unusual use of log levels and its implications.
>
> tl;dr
>
> For the debug log level I would like to propose we:
> 1. codestyle should mention that: debug doesn't mean debug to us, it is
> for background activities intended to be enabled in production,
> 2. doc/comment in logback.xml that the debug logger should not be disabled
> 3. codestyle against (and remove all) isDebugEnabled
>
>
> long format…
>
> 1.
> Our debug logging is not "debug" but the "non read/write path logging".
> We hijacked the debug loglevel for the separation of all background
> activities. This trips most newcomers up. We can do a better job of
> documenting this (see (2).
>
> system.log == read/write path.
> debug.log == also background activities.
>
> There's some nuance here – there is logging around background activities
> that we do want in system.log, which is correspondingly at the info
> loglevel. But generally, on the read/write path, we want to use the trace
> level when one typically thinks about "debug", and on the background paths,
> use debug when thinking about "info".
>
> More history on this in CASSANDRA-10241 and in
> https://lists.apache.org/thread/mgmbmdw4cp4rq684wcllfjc3sd1sbhkm
>
> This separation of log files between foreground and background activity
> *is* very valuable to the operator (and expert). We have a lot of
> experience on this.
>
> And we did have some good docs about logging here:
> https://cwiki.apache.org/confluence/display/CASSANDRA2/LoggingGuidelines
> This should be revived IMHO.
>
> 2.
> We often see operators in production disable the debug loglevel (or
> appender), thinking they are doing the right thing. We are then left
> unable to investigate issues related to background tasks (compaction,
> streaming, repairs, etc), and have to ask them to enable it again before
> collecting the logs again.
>
> Aside: we do tell operators to disable either the file appenders or
> stdout, as having both running is unnecessary. When they do this they
> often then go and make the mistake of also disabling the ASYNCDEBUGLOG.
>
> There's been calls in the past to better name our log files. I do favour
> the renaming system.log to foreground.log, and debug.log to everything.log,
> or anything along those lines. In the referenced ML thread there was also
> discussion about using a marker, so to remove foreground activities from
> debug.log, in which case a name like background.log would make more sense.
> But renaming log files is a compatibility break, and is a separate
> discussion.
>
>
> 3.
> The use of isDebugEnabled should be avoided, as it confuses
> - heavy methods calls in debug cannot be avoid
> - that debug is always enabled (just like assertions)
> - debug isn't appropriate on the read/write path (use trace instead)
> - info isn't appropriate on the background paths, unless you intentionally
> want it in system.log
>
> Debug should never cause a production performance problem. A past example
> of this confusion:
> https://github.com/apache/cassandra/commit/ac77e5e7742548f7c7c25da3923841f59d4b2713
>
>
> It's my understanding this has already been the intentional practice and
> precedence for most of us, ~10% of debug calls today are wrapped by
> isDebugEnabled, compared to ~37% for trace being wrapped with
> isTraceEnabled.
>
> While the use of isDebugEnabled might offer some small value to those that
> adominantly want to disable the background logging, and see some minimal
> perf improvement from it, I don't think that argument is popular, or wise,
> enough against a healthy code style and precedence that is intuitive to its
> intent.
>
> Like our assert statements needing not to cause production performance
> problems (because like debug we expect it to be enabled in production),
> best we document our idiosyncrasies rather than let them be tribal
> knowledge.
>
>
>
>