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

log: log lines collected by debug.zip seem to be truncated to 65K #50166

Closed
andreimatei opened this issue Jun 12, 2020 · 2 comments · Fixed by #59087
Closed

log: log lines collected by debug.zip seem to be truncated to 65K #50166

andreimatei opened this issue Jun 12, 2020 · 2 comments · Fixed by #59087
Assignees
Labels
A-logging In and around the logging infrastructure. C-bug Code not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior.

Comments

@andreimatei
Copy link
Contributor

It seems that log entries can be arbitrarily large, but when they're collected by the debug.zip (and I assume by the UI) through this RPC something seems to truncate them to 65KB each.
This is particularly unfortunate for query traces, which are a single entry (with many lines).

@andreimatei andreimatei added the C-bug Code not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior. label Jun 12, 2020
@andreimatei andreimatei added the A-logging In and around the logging infrastructure. label Jun 12, 2020
craig bot pushed a commit that referenced this issue Jan 25, 2021
58722: kvserver: don't refuse to fwd lease proposals in some edge cases r=andreimatei a=andreimatei

This patch backpedals a little bit on the logic introduced in #55148.
That patch said that, if a leader is known, every other replica refuses
to propose a lease acquisition. Instead, the replica in question
redirects whomever was triggering the lease acquisition to the leader,
thinking that the leader should take the lease.
That patch introduced a deadlock: some replicas refuse to take the lease
because they are not VOTER_FULL (see CheckCanReceiveLease()). To fix the
deadlock, this patch incorporates that check in the proposal buffer's
decision about whether or not to reject a proposal: if the leader is
believed to refuse to take the lease, then we again forward our own
lease request.

An edge case to the edge case is when the leader is not even part of the
proposer's range descriptor. This can happen if the proposer is far
behind. In this case, we assume that the leader is eligible. If it
isn't, the deadlock will resolve once the proposer catches up.

A future patch will relax the conditions under which a replica agrees to
take the lease. VOTER_INCOMING replicas should take the lease.
VOTER_DEMOTING are more controversial.

Fixes #57798

Release note: None

59087: util/log: new output format 'crdb-v2' r=itsbilal a=knz

Fixes  #50166. 

This new format intends to address all the known shortcomings with `crdb-v1` while remaining compatible with entry parsers designed for the previous version.
See the user-facing release note below for a summary of changes; and the included reference documentation for details.


Example TTY output with colors:
![image](https://user-images.githubusercontent.com/642886/104824568-261e9380-5853-11eb-9ad9-e5936f0890fd.png)


Example for a single-line unstructured entry.

Before:
```
I210116 22:17:03.736236 57 cli/start.go:681 ⋮ node startup completed:
```

After:
```
I210116 22:17:03.736236 57 cli/start.go:681 ⋮ [-] 12  node startup completed:
              tag field now always included   ^^^
          entry counter now always included       ^^^
```

Example for a multi-line unstructured entry.

Before:
```
I210116 22:15:38.105666 452 gossip/gossip.go:567 ⋮ [n1] 74  gossip status (ok, 1 node‹›)
gossip client (0/3 cur/max conns)
gossip connectivity
  n1 [sentinel];
```

(subsequent lines lack a log entry prefix; hard to determine where
entries start and end)

After:
```
I210116 22:15:38.105666 452 gossip/gossip.go:567 ⋮ [n1] 74  gossip status (ok, 1 node‹›)
I210116 22:15:38.105666 452 gossip/gossip.go:567 ⋮ [n1] 74 +gossip client (0/3 cur/max conns)
I210116 22:15:38.105666 452 gossip/gossip.go:567 ⋮ [n1] 74 +gossip connectivity
I210116 22:15:38.105666 452 gossip/gossip.go:567 ⋮ [n1] 74 +  n1 [sentinel];
  ^^^ common prefix repeated for each msg line
       same entry counter for every subsequent line    ^^^
               continuation marker "+" on susequent lines ^^
```

Example for a structured entry.

Before:
```
I210116 22:14:38.175829 469 util/log/event_log.go:32 ⋮ [n1] Structured entry: {...}
```

After:
```
I210116 22:14:38.175829 469 util/log/event_log.go:32 ⋮ [n1] 21 ={...}
                            entry counter always present    ^^
                      equal sign "=" denotes structured entry ^^
```

Release note (cli change): The default output format for `file-group`
and `stderr` sinks has been changed to `crdb-v2`.

This new format is non-ambiguous and makes it possible to reliably
parse log files. Refer to the format's documentation for
details. Additionally, it prevents single log lines from exceeding a
large size; this problem is inherent to the `crdb-v1` format and can
prevent `cockroach debug zip` from retrieving v1 log files.

The new format has also been designed so that existinglog file
analyzers for the `crdb-v1` format can read entries written the new
format. However, this conversion may be imperfect. Again, refer to
the new format's documentation for details.

In case of incompatibility, users can force the previous format by
using `format: crdb-v1` in their logging configuration.

59141: ui: upgrade admin-ui-components to new dep r=dhartunian a=dhartunian

We renamed the `admin-ui-components` package
to `cluster-ui`.

Release note: None

59388: build,bazel: remove references to `gofmt` in bazel build r=rickystewart a=rickystewart

This was cargo-culted from the `Makefile`, but isn't necessary to get
the build to succeed, and interferes with hermiticity because it
requires `gofmt` to be globally installed. It's simpler to just remove
these references entirely.

Release note: None

Co-authored-by: Andrei Matei <andrei@cockroachlabs.com>
Co-authored-by: Raphael 'kena' Poss <knz@thaumogen.net>
Co-authored-by: David Hartunian <davidh@cockroachlabs.com>
Co-authored-by: Ricky Stewart <ricky@cockroachlabs.com>
@craig craig bot closed this as completed in #59087 Jan 25, 2021
@andreimatei
Copy link
Contributor Author

@knz The linked PR talks about a new log format, but the issue here was the log collection endpoint which does the truncation. Did this collection change?

@knz
Copy link
Contributor

knz commented Jan 25, 2021

The linked pr ensures that no entry is larger than approx 1kb.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-logging In and around the logging infrastructure. C-bug Code not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants