Skip to content

Commit

Permalink
Browse files Browse the repository at this point in the history
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>
  • Loading branch information
5 people committed Jan 25, 2021
5 parents bc21f3a + a767cdd + f0377c4 + e18ffc8 + d1d5915 commit 2ec7d92
Show file tree
Hide file tree
Showing 69 changed files with 1,135 additions and 289 deletions.
135 changes: 133 additions & 2 deletions docs/generated/logformats.md
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,10 @@ The supported log output formats are documented below.

- [`crdb-v1-tty-count`](#format-crdb-v1-tty-count)

- [`crdb-v2`](#format-crdb-v2)

- [`crdb-v2-tty`](#format-crdb-v2-tty)

- [`json`](#format-json)

- [`json-compact`](#format-json-compact)
Expand Down Expand Up @@ -52,7 +56,10 @@ the following caveats apply:
- The log entry parser provided by CockroachDB to read log files is faulty
and is unable to recognize the aforementioned pitfall; nor can it read
entries larger than 64KiB successfully. Generally, use of this internal
log entry parser is discouraged.
log entry parser is discouraged for entries written with this format.

See the newer format `crdb-v2` for an alternative
without these limitations.

### Header lines

Expand Down Expand Up @@ -117,7 +124,10 @@ the following caveats apply:
- The log entry parser provided by CockroachDB to read log files is faulty
and is unable to recognize the aforementioned pitfall; nor can it read
entries larger than 64KiB successfully. Generally, use of this internal
log entry parser is discouraged.
log entry parser is discouraged for entries written with this format.

See the newer format `crdb-v2` for an alternative
without these limitations.

### Header lines

Expand Down Expand Up @@ -179,6 +189,127 @@ In addition, if the output stream happens to be a VT-compatible terminal,
and the flag `no-color` was *not* set in the configuration, the entries
are decorated using ANSI color codes.

## Format `crdb-v2`

This is the main file format used from CockroachDB v21.1.

Each log entry is emitted using a common prefix, described below,
followed by the text of the log entry.

### Entry format

Each line of output starts with the following prefix:

Lyymmdd hh:mm:ss.uuuuuu goid [chan@]file:line marker [tags...] counter cont

| Field | Description |
|-----------------|---------------------------------------------------------------------|
| L | A single character, representing the log level (eg 'I' for INFO). |
| yy | The year (zero padded; ie 2016 is '16'). |
| mm | The month (zero padded; ie May is '05'). |
| dd | The day (zero padded). |
| hh:mm:ss.uuuuuu | Time in hours, minutes and fractional seconds. Timezone is UTC. |
| goid | The goroutine id (zero when cannot be determined). |
| chan | The channel number (omitted if zero for backward-compatibility). |
| file | The file name where the entry originated. Also see below. |
| line | The line number where the entry originated. |
| marker | Redactability marker (see below for details). |
| tags | The logging tags, enclosed between "[" and "]". See below. |
| counter | The optional entry counter (see below for details). |
| cont | Continuation mark for structured and multi-line entries. See below. |

The `chan@` prefix before the file name indicates the logging channel,
and is omitted if the channel is DEV.

The file name may be prefixed by the string "`(gostd) `" to indicate
that the log entry was produced inside the Go standard library, instead
of a CockroachDB component. Entry parsers must be configured to ignore this prefix
when present.

The `marker` part is the redactability marker.
The redactability marker can be empty; in this case, its position in the common prefix is
a double ASCII space character which can be used to reliably identify this situation.
If the marker is "⋮", the remainder of the log entry
contains delimiters (‹...›) around
fields that are considered sensitive. These markers are automatically recognized
by `debug zip` and `debug merge-logs` when log redaction is requested.

The logging `tags` part is enclosed between square brackets `[...]`,
and the syntax `[-]` is used when there are no logging tags
associated with the log entry.

The `counter` part is numeric, and is incremented for every
log entry emitted to this sink. (There is thus one counter sequence per
sink.) For entries that do not have a counter value
associated, for example header entries in file sinks, the counter position
in the common prefix is empty: the tags part that precedes is then
followed by two ASCII space characters, instead of one space, the counter
and another space. The presence of the two ASCII spaces indicates
reliably that no counter was present.

The `cont` part is a format/continuation indicator:

| Continuation indicator | ASCII | Description |
|------------------------|-------|--|
| space | 0x32 | Start of an unstructured entry. |
| equal sign, "=" | 0x3d | Start of a structured entry. |
| exclamation mark, "!" | 0x21 | Start of an embedded stack trace. |
| plus sign, "+" | 0x2b | Continuation of a multi-line entry. The payload contains a newline character at this position. |
| vertical bar | 0x7c | Continuation of a large entry. |

### Examples

Example single-line unstructured entry:

I210116 21:49:17.073282 14 server/node.go:464 ⋮ [] 23 started with engine type ‹2›

Example multi-line unstructured entry:

I210116 21:49:17.083093 14 1@cli/start.go:690 ⋮ [-] 40 node startup completed:
I210116 21:49:17.083093 14 1@cli/start.go:690 ⋮ [-] 40 +CockroachDB node starting at 2021-01-16 21:49 (took 0.0s)

Example structured entry:

I210116 21:49:17.080713 14 1@util/log/event_log.go:32 ⋮ [] 32 ={"Timestamp":1610833757080706620,"EventType":"node_restart"}

Example long entries broken up into multiple lines:

I210116 21:49:17.073282 14 server/node.go:464 ⋮ [] 23 aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa....
I210116 21:49:17.073282 14 server/node.go:464 ⋮ [] 23 |aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa

I210116 21:49:17.080713 14 1@util/log/event_log.go:32 ⋮ [] 32 ={"Timestamp":1610833757080706620,"EventTy...
I210116 21:49:17.080713 14 1@util/log/event_log.go:32 ⋮ [] 32 |pe":"node_restart"}

### Backward-compatibility notes

Entries in this format can be read by most crdb-v1 log parsers,
in particular the one included in the DB console and
also the `debug merge-logs` facility.

However, implementers of previous version parsers must
understand that the logging tags field is now always
included, and the lack of logging tags is included
by a tag string set to "`[-]`".

Likewise, the entry counter is now also always included,
and there is a special character after the entry counter
to indicate whether the remainder of the line is a
structured entry, or a continuation of a previous entry.

Finally, in the previous format, structured entries
were prefixed with the string "Structured entry:". In
the new format, they are prefixed by the '=' continuation
indicator.


## Format `crdb-v2-tty`

Same textual format as `crdb-v2`.

In addition, if the output stream happens to be a VT-compatible terminal,
and the flag `no-color` was *not* set in the configuration, the entries
are decorated using ANSI color codes.

## Format `json`

This format emits log entries as a JSON payload.
Expand Down
8 changes: 4 additions & 4 deletions pkg/cli/interactive_tests/test_log_config_msg.tcl
Original file line number Diff line number Diff line change
Expand Up @@ -9,8 +9,8 @@ start_server $argv

start_test "Check that the cluster and node ID is reported at the start of the first log file."
spawn tail -n 1000 -F logs/db/logs/cockroach.log
eexpect "\\\[config\\\] clusterID:"
eexpect "\\\[config\\\] nodeID:"
eexpect "\\\[config\\\] * clusterID:"
eexpect "\\\[config\\\] * nodeID:"
eexpect "node startup completed"
end_test

Expand All @@ -32,7 +32,7 @@ system "grep -q 'restarted pre-existing node' logs/db/logs/*.log"
# it just started.
system "if grep -q 'restarted pre-existing node' logs/db/logs/cockroach.log; then false; fi"
# Verify that the last log file does contain the cluster ID.
system "grep -qF '\[config\] clusterID:' logs/db/logs/cockroach.log"
system "grep -qF '\[config\] nodeID:' logs/db/logs/cockroach.log"
system "grep -qF '\[config\] clusterID:' logs/db/logs/cockroach.log"
system "grep -qF '\[config\] nodeID:' logs/db/logs/cockroach.log"
end_test

8 changes: 4 additions & 4 deletions pkg/cli/log_flags_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -42,18 +42,18 @@ func TestSetupLogging(t *testing.T) {
`exit-on-error: false` +
`}, `
stdFileDefaultsRe := regexp.MustCompile(
`file-defaults: \{dir: (?P<path>[^,]+), max-file-size: 10MiB, buffered-writes: true, filter: INFO, format: crdb-v1, redactable: true\}`)
`file-defaults: \{dir: (?P<path>[^,]+), max-file-size: 10MiB, buffered-writes: true, filter: INFO, format: crdb-v2, redactable: true\}`)
fileDefaultsNoMaxSizeRe := regexp.MustCompile(
`file-defaults: \{dir: (?P<path>[^,]+), buffered-writes: true, filter: INFO, format: crdb-v1, redactable: true\}`)
const fileDefaultsNoDir = `file-defaults: {buffered-writes: true, filter: INFO, format: crdb-v1, redactable: true}`
`file-defaults: \{dir: (?P<path>[^,]+), buffered-writes: true, filter: INFO, format: crdb-v2, redactable: true\}`)
const fileDefaultsNoDir = `file-defaults: {buffered-writes: true, filter: INFO, format: crdb-v2, redactable: true}`
const defaultLogDir = `PWD/cockroach-data/logs`
stdCaptureFd2Re := regexp.MustCompile(
`capture-stray-errors: \{enable: true, dir: (?P<path>[^}]+)\}`)
fileCfgRe := regexp.MustCompile(
`\{channels: (?P<chans>[^ ]+), dir: (?P<path>[^,]+), max-file-size: 10MiB, buffered-writes: (?P<buf>[^,]+), filter: INFO, format: (?P<format>[^,]+), redactable: true\}`)

stderrCfgRe := regexp.MustCompile(
`stderr: {channels: all, filter: (?P<level>[^,]+), format: crdb-v1-tty, redactable: (?P<redactable>[^}]+)}`)
`stderr: {channels: all, filter: (?P<level>[^,]+), format: crdb-v2-tty, redactable: (?P<redactable>[^}]+)}`)

wd, err := os.Getwd()
if err != nil {
Expand Down
Loading

0 comments on commit 2ec7d92

Please sign in to comment.