Skip to content

util/log: various simplifications towards logging channels#56336

Merged
craig[bot] merged 16 commits intocockroachdb:masterfrom
knz:20201105-logparams
Nov 19, 2020
Merged

util/log: various simplifications towards logging channels#56336
craig[bot] merged 16 commits intocockroachdb:masterfrom
knz:20201105-logparams

Conversation

@knz
Copy link
Copy Markdown
Contributor

@knz knz commented Nov 5, 2020

These are general enhancements that I extracted from my work on #51987 into piecemeal commits. I think they are worth merging regardless of whether we adopt the channel proposal.

@knz knz requested review from bdarnell and tbg November 5, 2020 19:25
@knz knz requested a review from a team as a code owner November 5, 2020 19:25
@cockroach-teamcity
Copy link
Copy Markdown
Member

This change is Reviewable

@knz knz force-pushed the 20201105-logparams branch 10 times, most recently from 9dbe7cf to f52d26f Compare November 8, 2020 20:03
Copy link
Copy Markdown
Member

@tbg tbg left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

:lgtm:

The bash-based codegen made my toenails curl up a bit, but I suppose it does leave things in a better place than where they started.

Reviewed 7 of 7 files at r1, 14 of 14 files at r2, 15 of 15 files at r3, 7 of 7 files at r4, 7 of 7 files at r5, 1 of 1 files at r6, 70 of 70 files at r7.
Reviewable status: :shipit: complete! 1 of 0 LGTMs obtained (waiting on @bdarnell and @knz)


pkg/util/log/flags.go, line 32 at r2 (raw file):

	showLogs bool

	// Level beyond which entries submitted to any logger are written

at or beyond? I.e. if this is ERROR then ERROR does get written.


pkg/util/log/log_flush.go, line 36 at r4 (raw file):

	debugLog.lockAndFlushAndSync(true /*doSync*/)
	_ = registry.iter(func(l *loggerT) error {
		// Some loggers (e.g. the audit log) want to keep all the files.

Old code, but I don't understand this comment. Is this explaining why we doSync?


pkg/util/log/secondary_log.go, line 22 at r2 (raw file):

// whose logging events go to a different file than the main logging
// facility.
type SecondaryLogger struct {

At this point, is there even a true distinction between loggerT and SecondaryLogger? Does it have extra methods or something?

Copy link
Copy Markdown
Contributor Author

@knz knz left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reviewable status: :shipit: complete! 1 of 0 LGTMs obtained (waiting on @bdarnell and @tbg)


pkg/util/log/flags.go, line 32 at r2 (raw file):

Previously, tbg (Tobias Grieger) wrote…

at or beyond? I.e. if this is ERROR then ERROR does get written.

Fixed.


pkg/util/log/log_flush.go, line 36 at r4 (raw file):

Previously, tbg (Tobias Grieger) wrote…

Old code, but I don't understand this comment. Is this explaining why we doSync?

Yeah this comment doesn't mean anything. Removed.


pkg/util/log/secondary_log.go, line 22 at r2 (raw file):

Previously, tbg (Tobias Grieger) wrote…

At this point, is there even a true distinction between loggerT and SecondaryLogger? Does it have extra methods or something?

yes it does. This is further simplified in #51987.

@knz knz force-pushed the 20201105-logparams branch 9 times, most recently from 3df23d3 to 3c3271b Compare November 14, 2020 17:15
@knz knz force-pushed the 20201105-logparams branch 3 times, most recently from ae4e4a4 to e325d49 Compare November 16, 2020 13:17
@knz
Copy link
Copy Markdown
Contributor Author

knz commented Nov 17, 2020

todo: check whether this addresses #55423

knz added 5 commits November 19, 2020 11:47
This commit makes a few steps towards removing the special status
of `mainLog` as “template” for the secondary loggers.

It does so as follows:

- it lifts the global variables `showLog` into a field of `logging`,
  which is shared across all loggers. This does not change the
  behavior but makes the code slightly easier to understand.

- it makes the `stderrThreshold` parameter common to all
  loggers. Previously, the code was written to suggest that each logger
  could configure their stderrThreshold separately, however this was
  never used throughout the code base. We also have no recorded demand
  for such a fine grained configuration. This patch thus simplifies the
  code to bring the parameter into the common `logging` struct. This
  also makes the code slightly easier to understand and reason about.

- it makes the `logMaxFileSize` and `logCombinedMaxFileSize`
  parameters configurable per logger. They were previously common to all
  loggers.  Even though the code does not yet allow separate
  configurations for separate loggers, this change provisionally makes
  sense because we already know there is demand for keeping audit
  logs forever and debug logs only for a short time.

- it makes the handling of the `syncWrites` flag simpler. Previously,
  this parameter existed separately for each logger. It could also be
  toggled on and off across all loggers simultaneously, by
  `SetSync()`. However, the only caller of `SetSync()` ever set it to
  `true`. This patch thus simplifies the handling by making the
  per-logger `syncWrite` flag immutable (so it can be lifted out of the
  `mu` sub-struct), and have the file write log look into a (new)
  `logging.syncWrites`, which can be flipped by `SetSync()`.
  This also makes the code simpler overall.

- as a result of the above changes, the constructor
  `NewSecondaryLogger()` now needs only peek at `logging` and does not
  need `mainLog` any more.

- similarly, the `Scope()` facilities in `test_log_scope.go` can
  be simplified since they only affect settings across all loggers.

Release note: None
There is nothing “main” about it, especially given the upcoming
work to send the more important logging events to secondary loggers.

Also, the tests in `clog_test.go` are simplified to not define custom
methods over `loggerT`.

Release note: None
This simplifies the code and makes it generally easier to understand.

Release note: None
This simplifies the code everywhere `iter()` or `iterLocked()` is
used, by removing the special case for `debugLog`.

Release note: None
In a later iteration of the code, we will want to load custom logging
parameters into the debug logger during `logging.Setup()`. To ensure
these get picked up properly, we need to ensure that `StartGCDaemon()`
is only called after that.

(Until then, the code movement does not change semantics.)

Release note: None
@knz
Copy link
Copy Markdown
Contributor Author

knz commented Nov 19, 2020

bors r=tbg,itsbilal

@knz knz force-pushed the 20201105-logparams branch from b2afe52 to d66a193 Compare November 19, 2020 10:47
@craig
Copy link
Copy Markdown
Contributor

craig bot commented Nov 19, 2020

🕐 Waiting for PR status (Github check) to be set, probably by CI. Bors will automatically try to run when all required PR statuses are set.

@craig
Copy link
Copy Markdown
Contributor

craig bot commented Nov 19, 2020

Build failed:

knz added 10 commits November 19, 2020 12:45
This change extracts the protobuf definitions into a separate package
`logpb`. This disentangles the `log` package from `logpb` and enables
other packages to depend on `logpb` without bringing the entire `log`
infrastructure. It also clarifies the notion that the structs defined
in `logpb` have a stable marshalled representation.

Additionally, this change aliases the severity constants into
shorthands in a new sub-package `severity`, which somewhat simplifies
usage in other packages.

Finally, this change introduces a code generator for the more
repetitive interfaces.

Release note: None
This also removes the separate mutex for DirName inside file sinks.

Release note: None
Prior to this patch, whether to prepare output for redactability was a
property of the logger, so it would be done the same way for all the
sinks.

The logging modernization project however requires this to be
configurable per sink, so that e.g. the full output is present in
files but not in stderr, or (later) the full output is present in
files but not on the external Fluentd network collector.

This patch moves towards this by performing redaction editing
separately for each sink.

Release note: None
Prior to this patch, the logging package would terminate the process
immediately upon encountering an error while writing to any of the log
sinks.

This was cumbersome, because if e.g. an error was encountered while
writing to the stderr sink (the first one), the log entry would not be
written to the file sink at all and thus become discarded, *even
though the file sink may still be available*.

This patch fixes that issue by first trying to emit the log entry to
all the sinks, collecting errors on the way, and only after that
report any encountered error.

Additionally, this patch introduces the notion of "sink criticality":
a way for a sink to be marked as "non-critical" so that an error
writing to the sink is safely ignored. This facility is not yet used
in this commit however.

Release note: None
@knz knz force-pushed the 20201105-logparams branch from d66a193 to 2fbd75a Compare November 19, 2020 11:46
@knz
Copy link
Copy Markdown
Contributor Author

knz commented Nov 19, 2020

bazel build file missing after rebase...

bors r=tbg,itsbilal

@craig
Copy link
Copy Markdown
Contributor

craig bot commented Nov 19, 2020

Build succeeded:

@craig craig bot merged commit 2d9be02 into cockroachdb:master Nov 19, 2020
@knz knz deleted the 20201105-logparams branch November 19, 2020 12:20
@knz knz mentioned this pull request Nov 19, 2020
craig bot pushed a commit that referenced this pull request Nov 22, 2020
56897: util/log: misc fixes r=itsbilal a=knz

This somehow slipped through the review of #56336 

Fixes #56936 

Co-authored-by: Raphael 'kena' Poss <knz@thaumogen.net>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants