diff --git a/Makefile b/Makefile index 61f69766a6c0..3348daee39b2 100644 --- a/Makefile +++ b/Makefile @@ -824,6 +824,7 @@ DOCGEN_TARGETS := \ bin/.docgen_functions \ docs/generated/redact_safe.md \ bin/.docgen_http \ + bin/.docgen_logformats \ docs/generated/logging.md \ docs/generated/eventlog.md @@ -1518,6 +1519,10 @@ bin/.docgen_functions: bin/docgen docgen functions docs/generated/sql --quiet touch $@ +bin/.docgen_logformats: bin/docgen + docgen logformats docs/generated/logformats.md + touch $@ + bin/.docgen_http: bin/docgen $(PROTOC) docgen http \ --protoc $(PROTOC) \ diff --git a/docs/generated/logformats.md b/docs/generated/logformats.md new file mode 100644 index 000000000000..f950470a08ba --- /dev/null +++ b/docs/generated/logformats.md @@ -0,0 +1,149 @@ +# Documentation for logging formats + +The supported log output formats are documented below. + + +- [`crdb-v1`](#format-crdb-v1) + +- [`crdb-v1-count`](#format-crdb-v1-count) + +- [`crdb-v1-tty`](#format-crdb-v1-tty) + +- [`crdb-v1-tty-count`](#format-crdb-v1-tty-count) + + + +## Format `crdb-v1` + +This is the legacy file format used from CockroachDB v1.0. + +Each log entry is emitted using a common prefix, described below, +followed by: + +- The logging context tags enclosed between "[" and "]", if any. It is possible + for this to be omitted if there were no context tags. +- the text of the log entry. + +Beware that the text of the log entry can span multiple lines. In particular, +the following caveats apply: + + +- the text of the log entry can start with text enclosed between "[" and "]". + It is not possible to distinguish between logging context tag information + and a "[...]" string in the main text of the log entry, if there were + no logging tags to start with. This means that this format is ambiguous. + Consider `crdb-v1-count` for an unambiguous alternative. + +- the text of the log entry can embed arbitrary application-level strings, + including strings that represent log entries. In particular, an accident + of implementation can cause the common entry prefix (described below) + to also appear on a line of its own, as part of the payload of a previous + log entry. There is no automated way to recognize when this occurs. + Care must be taken by a human observer to recognize these situations. + +- 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. + +### Common log entry prefix + +Each line of output starts with the following prefix: + + Lyymmdd hh:mm:ss.uuuuuu goid [chan@]file:line marker + +where the fields are defined as follows: + +| 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 (omitted if zero for use by tests). | +| chan | The channel number (omitted if zero for backward-compatibility). | +| file | The file name where the entry originated. | +| line | The line number where the entry originated. | +| marker | Redactability marker (see below for details). | + +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 present, 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. + + +## Format `crdb-v1-count` + +This is an alternative, backward-compatible legacy file format used from CockroachDB v2.0. + +Each log entry is emitted using a common prefix, described below, +followed by the text of the log entry. + +Beware that the text of the log entry can span multiple lines. In particular, +the following caveats apply: + + +- the text of the log entry can embed arbitrary application-level strings, + including strings that represent log entries. In particular, an accident + of implementation can cause the common entry prefix (described below) + to also appear on a line of its own, as part of the payload of a previous + log entry. There is no automated way to recognize when this occurs. + Care must be taken by a human observer to recognize these situations. + +- 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. + +### Common log entry prefix + +Each line of output starts with the following prefix: + + Lyymmdd hh:mm:ss.uuuuuu goid [chan@]file:line markertags counter + +where the fields are defined as follows: + +| 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 (omitted if zero for use by tests). | +| chan | The channel number (omitted if zero for backward-compatibility). | +| file | The file name where the entry originated. | +| line | The line number where the entry originated. | +| marker | Redactability marker (see below for details). | +| tags | The logging tags, enclosed between "[" and "]". May be absent. | +| counter | The entry counter. Always present. | + +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 present, 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. + + +## Format `crdb-v1-tty` + +Same textual format as `crdb-v1`. + +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-v1-tty-count` + +Same textual format as `crdb-v1-count`. + +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. + diff --git a/pkg/cmd/docgen/logformats.go b/pkg/cmd/docgen/logformats.go new file mode 100644 index 000000000000..9be9953a931e --- /dev/null +++ b/pkg/cmd/docgen/logformats.go @@ -0,0 +1,105 @@ +// Copyright 2020 The Cockroach Authors. +// +// Use of this software is governed by the Business Source License +// included in the file licenses/BSL.txt. +// +// As of the Change Date specified in that file, in accordance with +// the Business Source License, use of this software will be governed +// by the Apache License, Version 2.0, included in the file +// licenses/APL.txt. + +package main + +import ( + "bytes" + "fmt" + "os" + "sort" + "text/template" + + "github.com/cockroachdb/cockroach/pkg/cli/exit" + "github.com/cockroachdb/cockroach/pkg/util/log" + "github.com/spf13/cobra" +) + +func init() { + cmds = append(cmds, &cobra.Command{ + Use: "logformats", + Short: "Generate the markdown documentation for logging formats.", + Args: cobra.MaximumNArgs(1), + Run: runLogFormats, + }) +} + +func runLogFormats(_ *cobra.Command, args []string) { + if err := runLogFormatsInternal(args); err != nil { + fmt.Fprintln(os.Stderr, "ERROR:", err) + exit.WithCode(exit.UnspecifiedError()) + } +} + +func runLogFormatsInternal(args []string) error { + // Compile the template. + tmpl, err := template.New("format docs").Parse(fmtDocTemplate) + if err != nil { + return err + } + + m := log.GetFormatterDocs() + + // Sort the names. + fNames := make([]string, 0, len(m)) + for k := range m { + fNames = append(fNames, k) + } + sort.Strings(fNames) + + // Retrieve the metadata into a format that the templating engine can understand. + type info struct { + Name string + Doc string + } + var infos []info + for _, k := range fNames { + infos = append(infos, info{Name: k, Doc: m[k]}) + } + + // Render the template. + var src bytes.Buffer + if err := tmpl.Execute(&src, struct { + Formats []info + }{infos}); err != nil { + return err + } + + // Write the output file. + w := os.Stdout + if len(args) > 0 { + f, err := os.OpenFile(args[0], os.O_CREATE|os.O_TRUNC|os.O_WRONLY, 0666) + if err != nil { + return err + } + defer func() { _ = f.Close() }() + w = f + } + if _, err := w.Write(src.Bytes()); err != nil { + return err + } + + return nil +} + +const fmtDocTemplate = `# Documentation for logging formats + +The supported log output formats are documented below. + +{{range .Formats}} +- [` + "`{{.Name}}`" + `](#format-{{.Name}}) +{{end}} + +{{range .Formats}} +## Format ` + "`{{.Name}}`" + ` + +{{.Doc}} +{{end}} +` diff --git a/pkg/util/log/format_crdb_v1.go b/pkg/util/log/format_crdb_v1.go index bbf804253f09..d7b09c3146a2 100644 --- a/pkg/util/log/format_crdb_v1.go +++ b/pkg/util/log/format_crdb_v1.go @@ -21,6 +21,7 @@ import ( "github.com/cockroachdb/cockroach/pkg/util/log/logpb" "github.com/cockroachdb/cockroach/pkg/util/log/severity" "github.com/cockroachdb/cockroach/pkg/util/timeutil" + "github.com/cockroachdb/redact" "github.com/cockroachdb/ttycolor" ) @@ -42,6 +43,112 @@ func (formatCrdbV1) formatEntry(entry logEntry) *buffer { return formatLogEntryInternal(entry.convertToLegacy(), false /*showCounter*/, nil, entry.stacks) } +func (formatCrdbV1) doc() string { return formatCrdbV1CommonDoc(false /* withCounter */) } + +func formatCrdbV1CommonDoc(withCounter bool) string { + var buf strings.Builder + + if !withCounter { + buf.WriteString(`This is the legacy file format used from CockroachDB v1.0.`) + } else { + buf.WriteString(`This is an alternative, backward-compatible legacy file format used from CockroachDB v2.0.`) + } + + buf.WriteString(` + +Each log entry is emitted using a common prefix, described below,`) + + if withCounter { + buf.WriteString(` +followed by the text of the log entry.`) + } else { + buf.WriteString(` +followed by: + +- The logging context tags enclosed between "[" and "]", if any. It is possible + for this to be omitted if there were no context tags. +- the text of the log entry.`) + } + + buf.WriteString(` + +Beware that the text of the log entry can span multiple lines. In particular, +the following caveats apply: + +`) + + if !withCounter { + // If there is no counter, the format is ambiguous. Explain that. + buf.WriteString(` +- the text of the log entry can start with text enclosed between "[" and "]". + It is not possible to distinguish between logging context tag information + and a "[...]" string in the main text of the log entry, if there were + no logging tags to start with. This means that this format is ambiguous. + Consider ` + "`" + formatCrdbV1WithCounter{}.formatterName() + "`" + ` for an unambiguous alternative. +`) + } + + // General disclaimer about the lack of boundaries. + buf.WriteString(` +- the text of the log entry can embed arbitrary application-level strings, + including strings that represent log entries. In particular, an accident + of implementation can cause the common entry prefix (described below) + to also appear on a line of its own, as part of the payload of a previous + log entry. There is no automated way to recognize when this occurs. + Care must be taken by a human observer to recognize these situations. + +- 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. + +### Common log entry prefix + +Each line of output starts with the following prefix: + + Lyymmdd hh:mm:ss.uuuuuu goid [chan@]file:line marker`) + + if withCounter { + buf.WriteString(`tags counter`) + } + + buf.WriteString(` + +where the fields are defined as follows: + +| 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 (omitted if zero for use by tests). | +| chan | The channel number (omitted if zero for backward-compatibility). | +| file | The file name where the entry originated. | +| line | The line number where the entry originated. | +| marker | Redactability marker (see below for details). |`) + + if withCounter { + buf.WriteString(` +| tags | The logging tags, enclosed between "[" and "]". May be absent. | +| counter | The entry counter. Always present. |`) + } + + buf.WriteString(` + +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 "` + redactableIndicator + `" is present, the remainder of the log entry +contains delimiters (` + string(redact.StartMarker()) + `...` + string(redact.EndMarker()) + `) around +fields that are considered sensitive. These markers are automatically recognized +by ` + "`" + `debug zip` + "`" + ` and ` + "`" + `debug merge-logs` + "`" + ` when log redaction is requested. +`) + + return buf.String() +} + // formatCrdbV1WithCounter is the canonical log format including a // counter column. type formatCrdbV1WithCounter struct{} @@ -52,6 +159,8 @@ func (formatCrdbV1WithCounter) formatEntry(entry logEntry) *buffer { return formatLogEntryInternal(entry.convertToLegacy(), true /*showCounter*/, nil, entry.stacks) } +func (formatCrdbV1WithCounter) doc() string { return formatCrdbV1CommonDoc(true /* withCounter */) } + // formatCrdbV1TTY is like formatCrdbV1 and includes VT color codes if // the stderr output is a TTY and -nocolor is not passed on the // command line. @@ -67,6 +176,16 @@ func (formatCrdbV1TTY) formatEntry(entry logEntry) *buffer { return formatLogEntryInternal(entry.convertToLegacy(), false /*showCounter*/, cp, entry.stacks) } +const ttyFormatDoc = ` + +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.` + +func (formatCrdbV1TTY) doc() string { + return "Same textual format as `" + formatCrdbV1{}.formatterName() + "`." + ttyFormatDoc +} + // formatCrdbV1ColorWithCounter is like formatCrdbV1WithCounter and // includes VT color codes if the stderr output is a TTY and -nocolor // is not passed on the command line. @@ -82,6 +201,10 @@ func (formatCrdbV1TTYWithCounter) formatEntry(entry logEntry) *buffer { return formatLogEntryInternal(entry.convertToLegacy(), true /*showCounter*/, cp, entry.stacks) } +func (formatCrdbV1TTYWithCounter) doc() string { + return "Same textual format as `" + formatCrdbV1WithCounter{}.formatterName() + "`." + ttyFormatDoc +} + const severityChar = "IWEF" // formatEntryInternal renders a log entry. @@ -89,21 +212,6 @@ const severityChar = "IWEF" // It uses a newly allocated *buffer. The caller is responsible // for calling putBuffer() afterwards. // -// Log lines have this form: -// Lyymmdd hh:mm:ss.uuuuuu goid [chan@]file:line [tags] counter msg... -// where the fields are defined as follows: -// 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 -// goid The goroutine id (omitted if zero for use by tests) -// chan The channel number (omitted if zero for backward-compatibility) -// file The file name -// line The line number -// tags The context tags -// counter The log entry counter, if enabled and non-zero -// msg The user-supplied message func formatLogEntryInternal( entry logpb.Entry, showCounter bool, cp ttycolor.Profile, stacks []byte, ) *buffer { diff --git a/pkg/util/log/formats.go b/pkg/util/log/formats.go index 4d772f95e570..9bd4eaeba354 100644 --- a/pkg/util/log/formats.go +++ b/pkg/util/log/formats.go @@ -12,6 +12,8 @@ package log type logFormatter interface { formatterName() string + // doc is used to generate the formatter documentation. + doc() string // formatEntry formats a logEntry into a newly allocated *buffer. // The caller is responsible for calling putBuffer() afterwards. formatEntry(entry logEntry) *buffer @@ -28,3 +30,13 @@ var formatters = func() map[string]logFormatter { r(formatCrdbV1TTYWithCounter{}) return m }() + +// GetFormatterDocs returns the embedded documentation for all the +// supported formats. +func GetFormatterDocs() map[string]string { + m := make(map[string]string) + for fmtName, f := range formatters { + m[fmtName] = f.doc() + } + return m +} diff --git a/pkg/util/log/gen.go b/pkg/util/log/gen.go index 43671936ff43..aa8eea84e555 100644 --- a/pkg/util/log/gen.go +++ b/pkg/util/log/gen.go @@ -34,7 +34,7 @@ func main() { func run() error { if len(os.Args) < 3 { - return errors.Newf("usage: %s template>\n", os.Args[0]) + return errors.Newf("usage: %s