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: extend logpb.Entry with more fine grained fields #66096

Merged
merged 6 commits into from
Jun 7, 2021

Conversation

knz
Copy link
Contributor

@knz knz commented Jun 4, 2021

Needed for #65633 and #61378.

cc @cockroachdb/server

@knz knz requested a review from cameronnunez June 4, 2021 18:46
@cockroach-teamcity
Copy link
Member

This change is Reviewable

Copy link
Contributor

@cameronnunez cameronnunez left a comment

Choose a reason for hiding this comment

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

After these minor changes, LGTM! Thanks for your work here.

"github.com/kr/pretty"
)

func TestCrdbV1FormatDecode(t *testing.T) {
Copy link
Contributor

Choose a reason for hiding this comment

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

Suggested change
func TestCrdbV1FormatDecode(t *testing.T) {
func TestFormatCrdbV1Decode(t *testing.T) {

For consistency, I suggest a slight change to the function name here.


// Verify the truncation logic for reading logs that are longer than the
// default scanner can handle.
preambleLength := len(formatEntry(severity.INFO, channel.DEV, t1, 0, "clog_test.go", 136, ``, ""))
Copy link
Contributor

Choose a reason for hiding this comment

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

Each instance of the string "clog_test.go" in format_crdb_v1_test.go and testdata/crdb_v1 should be changed to the string "format_crdb_v1_test.go"

@knz knz force-pushed the 20210604-logpb branch from 8cc0921 to bab7d79 Compare June 5, 2021 10:31
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.

nit: if you are only requesting minor changes, then it's better to leave your review disposition as "neutral" instead of "changes requested".
With "changes requested" I have to wait until you complete the review before I can merge the PR.

Reviewable status: :shipit: complete! 0 of 0 LGTMs obtained (waiting on @cameronnunez)


pkg/util/log/format_crdb_v1_test.go, line 32 at r3 (raw file):

Previously, cameronnunez (Cameron Nunez) wrote…
func TestFormatCrdbV1Decode(t *testing.T) {

For consistency, I suggest a slight change to the function name here.

Done.


pkg/util/log/format_crdb_v1_test.go, line 122 at r3 (raw file):

Previously, cameronnunez (Cameron Nunez) wrote…

Each instance of the string "clog_test.go" in format_crdb_v1_test.go and testdata/crdb_v1 should be changed to the string "format_crdb_v1_test.go"

Done.

knz added 6 commits June 7, 2021 13:28
This simplifies the test and makes it more extensible.

Release note: None
…entries

Prior to this change, we did not have a public data structure able to
represent the various fields available in a `crdb-v2` log entry: the
existing `logpb.Entry` was not able to distinguish structured and
non-structured entries, and did not have the ability to delimit the
message and the stack trace.

This patch extends `logpb.Entry` to make it more able to represent
`crdb-v2` entries, at least for the purpose of extending `debug
merge-log` towards conversion between logging formats.

Additionally, the patch adds a *best effort* attempt at populating
the new fields in the `crdb-v1` entry parser. This is best effort
because the crdb-v1 parser is lossy so we cannot faithfully
parse its entries reliably.

Release note: None
Release note (cli change): When log entries are written to disk,
the first few header lines written at the start of every new file
now report the configured logging format.
Release note (bug fix): Previously, `--log='file-defaults: {format:
crdb-v1}'` was not handled properly. This has been fixed. This bug
existed since v21.1.0.
This increases troubleshootability.

Release note: None
@knz knz force-pushed the 20210604-logpb branch from bab7d79 to 1456c73 Compare June 7, 2021 11:49
@knz knz requested a review from a team as a code owner June 7, 2021 11:49
@cameronnunez
Copy link
Contributor

cameronnunez commented Jun 7, 2021

nit: if you are only requesting minor changes, then it's better to leave your review disposition as "neutral" instead of "changes requested".
With "changes requested" I have to wait until you complete the review before I can merge the PR.

Understood!

@knz
Copy link
Contributor Author

knz commented Jun 7, 2021

You still need to review and change your disposition.
image

@cameronnunez
Copy link
Contributor

You still need to review and change your disposition.
image

👍 Done.

@knz
Copy link
Contributor Author

knz commented Jun 7, 2021

awesome, thank you!

bors r=cameronnunez

@craig
Copy link
Contributor

craig bot commented Jun 7, 2021

Build succeeded:

@craig craig bot merged commit 46ef251 into cockroachdb:master Jun 7, 2021
@knz knz deleted the 20210604-logpb branch June 8, 2021 07:06
craig bot pushed a commit that referenced this pull request Jun 10, 2021
61378: log,debug: fix `logspy`, new HTTP API to change `vmodule` r=stevendanna,tbg,andreimatei a=miretskiy

Fixes #61335.
First 3 commits from #66096.

**tldr: the logspy endpoint does not enable maximum verbosity any more, and now returns JSON entries. Use the new vmodule endpoint to configure verbosity if needed.**

See the commit messages of the last 2 commits for details and rationales.

Relevant user-facing changes:

**Release note (security update):** All the logging output to files
or network sinks was previously disabled temporarily while an operator
was using the `/debug/logspy` HTTP API, resulting in lost entries
and a breach of auditability guarantees. This behavior has been corrected.

**Release note (bug fix):** Log entries are not lost any more while the
`/debug/logspy` HTTP API is being used. This bug had existed since
CockroachDB v1.1.

**Release note (api change):** The `/debug/logspy` HTTP API has changed.
The endpoint now returns JSON data by default.
This change is motivated as follows:

- the previous format, `crdb-v1`, cannot be parsed reliably.
- using JSON entries guarantees that the text of each entry
  all fits on a single line of output (newline characters
  inside the messages are escaped). This makes filtering
  easier and more reliable.
- using JSON enables the user to apply `jq` on the output, for
  example via `curl -s .../debug/logspy | jq ...`

If the previous format is desired, the user can pass the query
argument `&flatten=1` to the `logspy` URL to obtain the previous flat
text format (`crdb-v1`) instead.

**Release note (api change)**: The `/debug/logspy` API does not any more
enable maximum logging verbosity automatically. To change the
verbosity, use the new `/debug/vmodule` endpoint or pass the
`&vmodule=` query parameter to the `/debug/logspy` endpoint.

For example, suppose you wish to run a 20s logspy session:

- Before:

  ```
  curl 'https://.../debug/logspy?duration=20s&...'
  ```

- Now:

  ```
  curl 'https://.../debug/logspy?duration=20s&vmodule=...'
  ```

  OR

  ```
  curl 'https://.../debug/vmodule?duration=22s&vmodule=...'
  curl 'https://.../debug/logspy?duration=20s'
  ```

As for the regular `vmodule` command-line flag, the maximum verbosity
across all the source code can be selected with the pattern `*=4`.

Note: at most one in-flight HTTP API request is allowed to modify the
`vmodule` parameter. This maintain the invariant that the
configuration restored at the end of each request is the same as when
the request started.

**Release note (api change)**: The new `/debug/vmodule` API makes it
possible for an operator to configure the logging verbosity in a
similar way as the SQL built-in function
`crdb_internal.set_vmodule()`, or to query the current configuration
as in `crdb_internal.get_vmodule()`. Additionally, any configuration
change performed via this API can be automatically reverted after a
configurable delay. The API forms are:

- `/debug/vmodule` - retrieve the current configuration.
- `/debug/vmodule?set=[vmodule config]&duration=[duration]` - change
  the configuration to `[vmodule config]` . The previous configuration
  at the time the `/debug/vmodule` request started is restored after
  `[duration]`. This duration, if not specified, defaults to twice the
  default duration of a `logspy` request (currently, the `logspy`
  default duration is 5s, so the `vmodule` default duration is 10s).
  If the duration is zero or negative, the previous configuration
  is never restored.

65648: sqlliveness/slstorage: break InternalExecutor depedency r=knz a=ajwerner

There was no fundamental reason to rely on SQL for this low-level subsystem.

Release note: None

66273: storageccl: don't update file registry when creating unencrypted files r=jbowens a=andyyang890

This patch changes PebbleFileRegistry to not store an entry
for an unencrypted file. This should lead to a performance
improvement since the file registry is rewritten every time
it is updated.

Fixes #65430.

Release note: None

Co-authored-by: Raphael 'kena' Poss <[email protected]>
Co-authored-by: Andrew Werner <[email protected]>
Co-authored-by: Andy Yang <[email protected]>
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.

3 participants