Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

util/log: refactor and bug fixes #40993

Merged
merged 3 commits into from
Oct 17, 2019

Conversation

knz
Copy link
Contributor

@knz knz commented Sep 23, 2019

Fixes #40983.
Fixes #40973.
Fixes #40974.
Fixes #41231.

I might also want to add code to clean up #40972, #40982 and #40990 provided I receive some guidance from @tbg or someone familiar with the log package.

@cockroach-teamcity
Copy link
Member

This change is Reviewable

@knz knz requested a review from tbg September 23, 2019 20:35
craig bot pushed a commit that referenced this pull request Sep 24, 2019
41018: c-deps: bump rocksdb for unique cache IDs on Windows r=ajkr a=ajkr

Picks up cockroachdb/rocksdb#58.

We found a corruption caused by multiple FAT32 files assigned the same
block cache key prefix. We don't know the extent to which this problem
affects other filesystems or other Windows file ID generation mechanisms.
We decided to turn off the reliance on filesystem for generating cache
keys on Windows. Instead we use randomization per table reader. This
would cause a performance penalty for use cases that open multiple table
readers per file, but I believe cockroach is not such a use case.

Fixes #40918, fixes #40950.

Release justification: Prevents corruption on some Windows filesystems

Release note: None

41020: util/log: fix GC of secondary loggers r=petermattis a=knz

Fixes #40974.

This is a subset of #40993 suitable for 19.2 and backport to 19.1.

Release justification: bug fix

Release note (bug fix): CockroachDB will now properly remove excess
secondary log files (SQL audit logging, statement execution logging,
and RocksDB events).

Co-authored-by: Andrew Kryczka <andrew.kryczka2@gmail.com>
Co-authored-by: Raphael 'kena' Poss <knz@thaumogen.net>
@knz knz force-pushed the 20190323-util-log-refactor branch from be64598 to 340846a Compare October 1, 2019 16:45
@knz
Copy link
Contributor Author

knz commented Oct 1, 2019

Added a commit to use sync.Pool as recommended by @petermattis .

craig bot pushed a commit that referenced this pull request Oct 1, 2019
41220: sql: move histogram decoding into the stats cache r=RaduBerinde a=RaduBerinde

Currently the stats cache exposes the encoded histogram data, and the
opt catalog decodes it. The problem is that opt catalog objects are
not shared across connections so this is inefficient (especially in
memory usage).

This change moves the decoding into the stats cache. The opt catalog
objects now simply point to the data computed by the cache.

There are still inefficiencies to improve on in the future: the opt
catalog can hold on to multiple versions of tables, so we will keep
many versions of histograms "alive".

Informs #41206.
Informs #40922.

Release justification: fix for new functionality.

Release note: None

41231: util/log: ensure that secondary loggers do not leak memory r=petermattis,nvanbenschoten a=knz

Fixes #41230.

Note: the primary cause of this issue is removed by #40993 but that PR is blocked until 19.2 is out. I'm cherry-picking the subset of those changes sufficient to solve issue #41230, here.

Prior to this patch, logging via a secondary logger would allocate a
buffer, then add it to the buffer free list of the secondary logger.

This was causing a memory leak because only the free list from the
main logger is used to allocate buffers (even in secondary loggers),
so all the now-unused buffers from secondary logs would remain unused
and accumulate, locked from Go's GC attention because they are
referenced somewhere.

Release justification: bug fix

Release note (bug fix): A memory leak was fixed that affected
secondary logging (SQL audit logs, statement execution, and RocksDB
logging).

Co-authored-by: Radu Berinde <radu@cockroachlabs.com>
Co-authored-by: Raphael 'kena' Poss <knz@thaumogen.net>
@knz knz force-pushed the 20190323-util-log-refactor branch from 340846a to 74eb436 Compare October 1, 2019 17:57
@knz knz force-pushed the 20190323-util-log-refactor branch from 74eb436 to 56e5ad2 Compare October 14, 2019 18:07
@knz knz requested a review from petermattis October 14, 2019 18:08
Copy link
Collaborator

@petermattis petermattis 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! 0 of 0 LGTMs obtained (waiting on @knz, @petermattis, and @tbg)


pkg/util/log/clog.go, line 43 at r3 (raw file):

	// pool for entry formatting buffers.
	bufPool sync.Pool

I would make this a global. All of the loggers should be sharing a single sync.Pool.

This change is functionality-neutral and performs the following code
structure adjustments:

- renames `logging` to `mainLog` to reflect its true nature.
- moves code away from `clog.go` to separate files:

  - `severity.go`: the `Severity` printing and conversion routines.
  - `log_entry.go`: code specific to building and parsing log entries
    (i.e. conversion between text and `log.Entry`).
  - `log_gc.go`: removing old log files (files beyond the configured
    size and number thresholds).
  - `log_flush.go`: the code that handles flushing the buffered log data
    to files and output streams.
  - `log_bridge.go`: the code that manages the coupling of the
    cockroachdb `log` package with the default Go `log` package.
  - `sync_buffer.go`: the code that manages the coupling between
    a logger and an `*os.File`.
  - `log_buffer.go`: the code that manages buffering of a single log
    entry, and optimizes the reuse of entry buffers.
  - `vmodule.go`: the code that filters the production of log entries
    depending on the source code point where the entry is produced,
    depending on `--vmodule` and `crdb_internal.set_vmodule()`
    configurations.
  - `exit_override.go`: the code that manages the callback when the
    logging system is shutting down.
  - `get_stacks.go`: the code that assembles the goroutine stack dumps
    to produce upon a log.Fatal entry.
  - `intercept.go`: the code that injects a callback for log events.
    (Used by the `logspy` debug endpoint)
  - `backtrace_trigger.go`: the code that manages
    the special purpose tracepoints.
  - `tracebacks.go`: the code that manages the the coupling with
    the standard Go environment variable `GOTRACEBACK`.

Release note: None
This commit introduces the distinction between `loggingT`, the global
logging state, and `loggerT`, the per-logger state.
The main logger also becomes a global variable `mainLog` in this
package.

With this commit, the mutex on the global state is not held any more
on the common path, which means that there will be less contention
between primary and secondary loggers, and between secondary loggers,
if at all.

Release note (bug fix): CockroachDB will now properly remove excess
secondary log files (SQL audit logging, statement execution logging,
and RocksDB events).

Release note (bug fix): CockroachDB will now properly emit the cluster
ID, once known, to all secondary log files (SQL audit logging,
statement execution logging, and RocksDB events).
This was suggested by @petermattis: the free list code predates the
introduction of `sync.Pool` in the Go standard library. Using
`sync.Pool` ensures that the code becomes less sensitive to a missing
call to `putBuffer()`.

Release note: None
@knz knz force-pushed the 20190323-util-log-refactor branch from 56e5ad2 to f2bae17 Compare October 16, 2019 15:21
Copy link
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! 0 of 0 LGTMs obtained (waiting on @petermattis and @tbg)


pkg/util/log/clog.go, line 43 at r3 (raw file):

Previously, petermattis (Peter Mattis) wrote…

I would make this a global. All of the loggers should be sharing a single sync.Pool.

It is global now. The loggingT is now used for the common singleton, and there is a separate per-logger loggerT.

Copy link
Collaborator

@petermattis petermattis 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! 0 of 0 LGTMs obtained (waiting on @knz and @tbg)


pkg/util/log/clog.go, line 43 at r3 (raw file):

Previously, knz (kena) wrote…

It is global now. The loggingT is now used for the common singleton, and there is a separate per-logger loggerT.

Ah, I missed that. Very good. Carry on.

Copy link
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: I did not review the code movement in depth.

Reviewed 7 of 26 files at r1, 20 of 20 files at r4, 18 of 18 files at r5, 2 of 2 files at r6.
Reviewable status: :shipit: complete! 1 of 0 LGTMs obtained (waiting on @knz)

@knz
Copy link
Contributor Author

knz commented Oct 17, 2019

thank you!

bors r+

craig bot pushed a commit that referenced this pull request Oct 17, 2019
40993: util/log: refactor and bug fixes r=knz a=knz

Fixes #40983.
Fixes #40973.
Fixes #40974.
Fixes #41231.

I might also want to add code to clean up #40972, #40982 and #40990 provided I receive some guidance from @tbg or someone familiar with the log package.


41654: parser: fix telemetry link for materialized views r=jordanlewis a=jordanlewis

This commit fixes the error message that you get if you try to create a
materialized view to point at the right GitHub issue.

Release note: None

Co-authored-by: Raphael 'kena' Poss <knz@thaumogen.net>
Co-authored-by: Jordan Lewis <jordanthelewis@gmail.com>
@craig
Copy link
Contributor

craig bot commented Oct 17, 2019

Build succeeded

@craig craig bot merged commit f2bae17 into cockroachdb:master Oct 17, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
4 participants