Skip to content

Commit

Permalink
log: add version field to json formatted log entries
Browse files Browse the repository at this point in the history
Release note (cli change): version details have been added to all json
formatted log entries. Refer to the reference docs for details about
the field.
  • Loading branch information
cameronnunez committed Sep 21, 2021
1 parent 9b22647 commit 2662eda
Show file tree
Hide file tree
Showing 12 changed files with 77 additions and 32 deletions.
4 changes: 4 additions & 0 deletions docs/generated/logformats.md
Original file line number Diff line number Diff line change
Expand Up @@ -332,6 +332,7 @@ Each entry contains at least the following fields:
| `line` | The line number where the event was emitted in the source. |
| `redactable` | Whether the payload is redactable (see below for details). |
| `timestamp` | The timestamp at which the event was emitted on the logging channel. |
| `version` | The binary version with which the event was generated. |


After a couple of *header* entries written at the beginning of each log sink,
Expand Down Expand Up @@ -389,6 +390,7 @@ Each entry contains at least the following fields:
| `l` | The line number where the event was emitted in the source. |
| `r` | Whether the payload is redactable (see below for details). |
| `t` | The timestamp at which the event was emitted on the logging channel. |
| `v` | The binary version with which the event was generated. |


After a couple of *header* entries written at the beginning of each log sink,
Expand Down Expand Up @@ -447,6 +449,7 @@ Each entry contains at least the following fields:
| `line` | The line number where the event was emitted in the source. |
| `redactable` | Whether the payload is redactable (see below for details). |
| `timestamp` | The timestamp at which the event was emitted on the logging channel. |
| `version` | The binary version with which the event was generated. |


After a couple of *header* entries written at the beginning of each log sink,
Expand Down Expand Up @@ -505,6 +508,7 @@ Each entry contains at least the following fields:
| `l` | The line number where the event was emitted in the source. |
| `r` | Whether the payload is redactable (see below for details). |
| `t` | The timestamp at which the event was emitted on the logging channel. |
| `v` | The binary version with which the event was generated. |


After a couple of *header* entries written at the beginning of each log sink,
Expand Down
32 changes: 24 additions & 8 deletions pkg/build/info.go
Original file line number Diff line number Diff line change
Expand Up @@ -35,10 +35,11 @@ var (
cgoTargetTriple string
platform = fmt.Sprintf("%s %s", runtime.GOOS, runtime.GOARCH)
// Distribution is changed by the CCL init-time hook in non-APL builds.
Distribution = "OSS"
typ string // Type of this build: <empty>, "development", or "release"
channel = "unknown"
envChannel = envutil.EnvOrDefaultString("COCKROACH_CHANNEL", "unknown")
Distribution = "OSS"
typ string // Type of this build: <empty>, "development", or "release"
channel = "unknown"
envChannel = envutil.EnvOrDefaultString("COCKROACH_CHANNEL", "unknown")
binaryVersion = computeVersion(tag)
)

// IsRelease returns true if the binary was produced by a "release" build.
Expand All @@ -52,8 +53,21 @@ func SeemsOfficial() bool {
return channel == "official-binary" || channel == "source-archive"
}

// VersionPrefix returns the version prefix of the current build.
func VersionPrefix() string {
func computeVersion(tag string) string {
v, err := version.Parse(tag)
if err != nil {
return "dev"
}
return v.String()
}

// BinaryVersion returns the version prefix, patch number and metadata of the current build.
func BinaryVersion() string {
return binaryVersion
}

// BinaryVersionPrefix returns the version prefix of the current build.
func BinaryVersionPrefix() string {
v, err := version.Parse(tag)
if err != nil {
return "dev"
Expand Down Expand Up @@ -137,11 +151,13 @@ func GetInfo() Info {
// TestingOverrideTag allows tests to override the build tag.
func TestingOverrideTag(t string) func() {
prev := tag
prevVersion := binaryVersion
tag = t
return func() { tag = prev }
binaryVersion = computeVersion(tag)
return func() { tag = prev; binaryVersion = prevVersion }
}

// MakeIssueURL produces a URL to a CockroachDB issue.
func MakeIssueURL(issue int) string {
return fmt.Sprintf("https://go.crdb.dev/issue-v/%d/%s", issue, VersionPrefix())
return fmt.Sprintf("https://go.crdb.dev/issue-v/%d/%s", issue, BinaryVersionPrefix())
}
2 changes: 1 addition & 1 deletion pkg/ccl/cliccl/demo.go
Original file line number Diff line number Diff line change
Expand Up @@ -41,7 +41,7 @@ func getLicense(clusterID uuid.UUID) (string, error) {
q := req.URL.Query()
// Let the endpoint know we are requesting a demo license.
q.Add("kind", "demo")
q.Add("version", build.VersionPrefix())
q.Add("version", build.BinaryVersionPrefix())
q.Add("clusterid", clusterID.String())
req.URL.RawQuery = q.Encode()

Expand Down
4 changes: 2 additions & 2 deletions pkg/docs/docs.go
Original file line number Diff line number Diff line change
Expand Up @@ -18,12 +18,12 @@ import (

// URLBase is the root URL for the version of the docs associated with this
// binary.
var URLBase = "https://www.cockroachlabs.com/docs/" + build.VersionPrefix()
var URLBase = "https://www.cockroachlabs.com/docs/" + build.BinaryVersionPrefix()

// URLReleaseNotesBase is the root URL for the release notes for the .0 patch
// release associated with this binary.
var URLReleaseNotesBase = fmt.Sprintf("https://www.cockroachlabs.com/docs/releases/%s.0.html",
build.VersionPrefix())
build.BinaryVersionPrefix())

// URL generates the URL to pageName in the version of the docs associated
// with this binary.
Expand Down
6 changes: 3 additions & 3 deletions pkg/server/server_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -1045,7 +1045,7 @@ Binary built without web UI.
fmt.Sprintf(
`{"ExperimentalUseLogin":false,"LoginEnabled":false,"LoggedInUser":null,"Tag":"%s","Version":"%s","NodeID":"%d","OIDCAutoLogin":false,"OIDCLoginEnabled":false,"OIDCButtonText":""}`,
build.GetInfo().Tag,
build.VersionPrefix(),
build.BinaryVersionPrefix(),
1,
),
)
Expand Down Expand Up @@ -1080,7 +1080,7 @@ Binary built without web UI.
fmt.Sprintf(
`{"ExperimentalUseLogin":true,"LoginEnabled":true,"LoggedInUser":"authentic_user","Tag":"%s","Version":"%s","NodeID":"%d","OIDCAutoLogin":false,"OIDCLoginEnabled":false,"OIDCButtonText":""}`,
build.GetInfo().Tag,
build.VersionPrefix(),
build.BinaryVersionPrefix(),
1,
),
},
Expand All @@ -1089,7 +1089,7 @@ Binary built without web UI.
fmt.Sprintf(
`{"ExperimentalUseLogin":true,"LoginEnabled":true,"LoggedInUser":null,"Tag":"%s","Version":"%s","NodeID":"%d","OIDCAutoLogin":false,"OIDCLoginEnabled":false,"OIDCButtonText":""}`,
build.GetInfo().Tag,
build.VersionPrefix(),
build.BinaryVersionPrefix(),
1,
),
},
Expand Down
2 changes: 1 addition & 1 deletion pkg/ui/ui.go
Original file line number Diff line number Diff line change
Expand Up @@ -137,7 +137,7 @@ func Handler(cfg Config) http.Handler {
LoginEnabled: cfg.LoginEnabled,
LoggedInUser: cfg.GetUser(r.Context()),
Tag: buildInfo.Tag,
Version: build.VersionPrefix(),
Version: build.BinaryVersionPrefix(),
NodeID: cfg.NodeID.String(),
OIDCAutoLogin: oidcConf.AutoLogin,
OIDCLoginEnabled: oidcConf.Enabled,
Expand Down
1 change: 1 addition & 0 deletions pkg/util/log/BUILD.bazel
Original file line number Diff line number Diff line change
Expand Up @@ -147,6 +147,7 @@ go_test(
data = glob(["testdata/**"]),
embed = [":log"],
deps = [
"//pkg/build",
"//pkg/cli/exit",
"//pkg/settings/cluster",
"//pkg/util/caller",
Expand Down
7 changes: 6 additions & 1 deletion pkg/util/log/fluent_client_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@ import (
"testing"
"time"

"github.com/cockroachdb/cockroach/pkg/build"
"github.com/cockroachdb/cockroach/pkg/util/leaktest"
"github.com/cockroachdb/cockroach/pkg/util/log/channel"
"github.com/cockroachdb/cockroach/pkg/util/log/logconfig"
Expand All @@ -27,6 +28,10 @@ import (
)

func TestFluentClient(t *testing.T) {
// CLI tests are sensitive to the server version, but test binaries don't have
// a version injected. Pretend to be a very up-to-date version.
defer build.TestingOverrideTag("v999.0.0")()

defer leaktest.AfterTest(t)()
sc := ScopeWithoutShowLogs(t)
defer sc.Close(t)
Expand Down Expand Up @@ -75,7 +80,7 @@ func TestFluentClient(t *testing.T) {
msg, err := json.Marshal(info)
require.NoError(t, err)

const expected = `{"c":1,"f":"util/log/fluent_client_test.go","g":222,"l":58,"message":"hello world","n":1,"r":1,"s":1,"sev":"I","t":"XXX","tag":"log_test.ops"}`
const expected = `{"c":1,"f":"util/log/fluent_client_test.go","g":222,"l":63,"message":"hello world","n":1,"r":1,"s":1,"sev":"I","t":"XXX","tag":"log_test.ops","v":"v999.0.0"}`
require.Equal(t, expected, string(msg))
}

Expand Down
11 changes: 11 additions & 0 deletions pkg/util/log/format_json.go
Original file line number Diff line number Diff line change
Expand Up @@ -173,6 +173,8 @@ var jsonTags = map[byte]struct {
"The node ID where the event was generated, once known. Only reported for single-tenant or KV servers.", true},
'x': {[2]string{"x", "cluster_id"},
"The cluster ID where the event was generated, once known. Only reported for single-tenant of KV servers.", true},
'v': {[2]string{"v", "version"},
"The binary version with which the event was generated.", true},
// SQL servers in multi-tenant deployments.
'q': {[2]string{"q", "instance_id"},
"The SQL instance ID where the event was generated, once known. Only reported for multi-tenant SQL servers.", true},
Expand Down Expand Up @@ -292,6 +294,15 @@ func formatJSON(entry logEntry, forFluent bool, tags tagChoice) *buffer {
buf.Write(buf.tmp[:n])
}

// The binary version.
if entry.version != "" {
buf.WriteString(`,"`)
buf.WriteString(jtags['v'].tags[tags])
buf.WriteString(`":"`)
escapeString(buf, entry.version)
buf.WriteByte('"')
}

if !entry.header {
// Severity, both in numeric form (for ease of processing) and
// string form (to facilitate human comprehension).
Expand Down
5 changes: 5 additions & 0 deletions pkg/util/log/format_json_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@ import (
"testing"
"time"

"github.com/cockroachdb/cockroach/pkg/build"
"github.com/cockroachdb/cockroach/pkg/util/log/channel"
"github.com/cockroachdb/cockroach/pkg/util/log/eventpb"
"github.com/cockroachdb/cockroach/pkg/util/log/severity"
Expand All @@ -25,6 +26,10 @@ import (
)

func TestJSONFormats(t *testing.T) {
// CLI tests are sensitive to the server version, but test binaries don't have
// a version injected. Pretend to be a very up-to-date version.
defer build.TestingOverrideTag("v999.0.0")()

tm, err := time.Parse(MessageTimeFormat, "060102 15:04:05.654321")
if err != nil {
t.Fatal(err)
Expand Down
3 changes: 3 additions & 0 deletions pkg/util/log/log_entry.go
Original file line number Diff line number Diff line change
Expand Up @@ -60,6 +60,8 @@ type logEntry struct {
// The channel on which the entry was sent. This is not reported by
// formatters when the header boolean is set.
ch Channel
// The binary version with which the event was generated.
version string

// The goroutine where the event was generated.
gid int64
Expand Down Expand Up @@ -118,6 +120,7 @@ func makeEntry(ctx context.Context, s Severity, c Channel, depth int) (res logEn
ts: timeutil.Now().UnixNano(),
sev: s,
ch: c,
version: build.BinaryVersion(),
gid: goid.Get(),
tags: logtags.FromContext(ctx),
}
Expand Down
32 changes: 16 additions & 16 deletions pkg/util/log/testdata/json
Original file line number Diff line number Diff line change
@@ -1,10 +1,10 @@
run
----
#
json-fluent-compact: {"tag":"log_test.unknown","header":1,"t":"1136214245.654321000","g":11,"f":"util/log/format_json_test.go","l":123,"r":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"message":"hello ‹world›"}
json-fluent: {"tag":"log_test.unknown","header":1,"timestamp":"1136214245.654321000","goroutine":11,"file":"util/log/format_json_test.go","line":123,"redactable":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"message":"hello ‹world›"}
json-compact: {"header":1,"t":"1136214245.654321000","g":11,"f":"util/log/format_json_test.go","l":123,"r":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"message":"hello ‹world›"}
json: {"header":1,"timestamp":"1136214245.654321000","goroutine":11,"file":"util/log/format_json_test.go","line":123,"redactable":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"message":"hello ‹world›"}
json-fluent-compact: {"tag":"log_test.unknown","header":1,"t":"1136214245.654321000","v":"v999.0.0","g":11,"f":"util/log/format_json_test.go","l":123,"r":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"message":"hello ‹world›"}
json-fluent: {"tag":"log_test.unknown","header":1,"timestamp":"1136214245.654321000","version":"v999.0.0","goroutine":11,"file":"util/log/format_json_test.go","line":123,"redactable":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"message":"hello ‹world›"}
json-compact: {"header":1,"t":"1136214245.654321000","v":"v999.0.0","g":11,"f":"util/log/format_json_test.go","l":123,"r":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"message":"hello ‹world›"}
json: {"header":1,"timestamp":"1136214245.654321000","version":"v999.0.0","goroutine":11,"file":"util/log/format_json_test.go","line":123,"redactable":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"message":"hello ‹world›"}
#
json-fluent-compact: {"tag":"log_test.dev","c":0,"t":"1136214245.654321000","s":0,"g":11,"f":"","l":123,"n":0,"r":0,"message":""}
json-fluent: {"tag":"log_test.dev","channel_numeric":0,"channel":"DEV","timestamp":"1136214245.654321000","severity_numeric":0,"severity":"UNKNOWN","goroutine":11,"file":"","line":123,"entry_counter":0,"redactable":0,"message":""}
Expand All @@ -21,17 +21,17 @@ json-fluent-compact: {"tag":"log_test.dev","c":0,"t":"1136214245.654321000","T":
json-compact: {"c":0,"t":"1136214245.654321000","T":"abc","q":123,"s":0,"g":11,"f":"","l":123,"n":0,"r":0,"message":""}
json: {"channel_numeric":0,"channel":"DEV","timestamp":"1136214245.654321000","tenant_id":"abc","instance_id":123,"severity_numeric":0,"severity":"UNKNOWN","goroutine":11,"file":"","line":123,"entry_counter":0,"redactable":0,"message":""}
#
json-fluent-compact: {"tag":"log_test.dev","c":0,"t":"1136214245.654321000","s":1,"sev":"I","g":11,"f":"util/log/format_json_test.go","l":123,"n":0,"r":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"event":{"Timestamp":123,"EventType":"rename_database","DatabaseName":"‹hello›","NewDatabaseName":"‹world›"}}
json-fluent: {"tag":"log_test.dev","channel_numeric":0,"channel":"DEV","timestamp":"1136214245.654321000","severity_numeric":1,"severity":"INFO","goroutine":11,"file":"util/log/format_json_test.go","line":123,"entry_counter":0,"redactable":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"event":{"Timestamp":123,"EventType":"rename_database","DatabaseName":"‹hello›","NewDatabaseName":"‹world›"}}
json-compact: {"c":0,"t":"1136214245.654321000","s":1,"sev":"I","g":11,"f":"util/log/format_json_test.go","l":123,"n":0,"r":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"event":{"Timestamp":123,"EventType":"rename_database","DatabaseName":"‹hello›","NewDatabaseName":"‹world›"}}
json: {"channel_numeric":0,"channel":"DEV","timestamp":"1136214245.654321000","severity_numeric":1,"severity":"INFO","goroutine":11,"file":"util/log/format_json_test.go","line":123,"entry_counter":0,"redactable":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"event":{"Timestamp":123,"EventType":"rename_database","DatabaseName":"‹hello›","NewDatabaseName":"‹world›"}}
json-fluent-compact: {"tag":"log_test.dev","c":0,"t":"1136214245.654321000","v":"v999.0.0","s":1,"sev":"I","g":11,"f":"util/log/format_json_test.go","l":123,"n":0,"r":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"event":{"Timestamp":123,"EventType":"rename_database","DatabaseName":"‹hello›","NewDatabaseName":"‹world›"}}
json-fluent: {"tag":"log_test.dev","channel_numeric":0,"channel":"DEV","timestamp":"1136214245.654321000","version":"v999.0.0","severity_numeric":1,"severity":"INFO","goroutine":11,"file":"util/log/format_json_test.go","line":123,"entry_counter":0,"redactable":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"event":{"Timestamp":123,"EventType":"rename_database","DatabaseName":"‹hello›","NewDatabaseName":"‹world›"}}
json-compact: {"c":0,"t":"1136214245.654321000","v":"v999.0.0","s":1,"sev":"I","g":11,"f":"util/log/format_json_test.go","l":123,"n":0,"r":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"event":{"Timestamp":123,"EventType":"rename_database","DatabaseName":"‹hello›","NewDatabaseName":"‹world›"}}
json: {"channel_numeric":0,"channel":"DEV","timestamp":"1136214245.654321000","version":"v999.0.0","severity_numeric":1,"severity":"INFO","goroutine":11,"file":"util/log/format_json_test.go","line":123,"entry_counter":0,"redactable":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"event":{"Timestamp":123,"EventType":"rename_database","DatabaseName":"‹hello›","NewDatabaseName":"‹world›"}}
#
json-fluent-compact: {"tag":"log_test.ops","c":1,"t":"1136214245.654321000","s":2,"sev":"W","g":11,"f":"util/log/format_json_test.go","l":123,"n":0,"r":0,"tags":{"noval":"","s":"1","long":"2"},"message":"hello world"}
json-fluent: {"tag":"log_test.ops","channel_numeric":1,"channel":"OPS","timestamp":"1136214245.654321000","severity_numeric":2,"severity":"WARNING","goroutine":11,"file":"util/log/format_json_test.go","line":123,"entry_counter":0,"redactable":0,"tags":{"noval":"","s":"1","long":"2"},"message":"hello world"}
json-compact: {"c":1,"t":"1136214245.654321000","s":2,"sev":"W","g":11,"f":"util/log/format_json_test.go","l":123,"n":0,"r":0,"tags":{"noval":"","s":"1","long":"2"},"message":"hello world"}
json: {"channel_numeric":1,"channel":"OPS","timestamp":"1136214245.654321000","severity_numeric":2,"severity":"WARNING","goroutine":11,"file":"util/log/format_json_test.go","line":123,"entry_counter":0,"redactable":0,"tags":{"noval":"","s":"1","long":"2"},"message":"hello world"}
json-fluent-compact: {"tag":"log_test.ops","c":1,"t":"1136214245.654321000","v":"v999.0.0","s":2,"sev":"W","g":11,"f":"util/log/format_json_test.go","l":123,"n":0,"r":0,"tags":{"noval":"","s":"1","long":"2"},"message":"hello world"}
json-fluent: {"tag":"log_test.ops","channel_numeric":1,"channel":"OPS","timestamp":"1136214245.654321000","version":"v999.0.0","severity_numeric":2,"severity":"WARNING","goroutine":11,"file":"util/log/format_json_test.go","line":123,"entry_counter":0,"redactable":0,"tags":{"noval":"","s":"1","long":"2"},"message":"hello world"}
json-compact: {"c":1,"t":"1136214245.654321000","v":"v999.0.0","s":2,"sev":"W","g":11,"f":"util/log/format_json_test.go","l":123,"n":0,"r":0,"tags":{"noval":"","s":"1","long":"2"},"message":"hello world"}
json: {"channel_numeric":1,"channel":"OPS","timestamp":"1136214245.654321000","version":"v999.0.0","severity_numeric":2,"severity":"WARNING","goroutine":11,"file":"util/log/format_json_test.go","line":123,"entry_counter":0,"redactable":0,"tags":{"noval":"","s":"1","long":"2"},"message":"hello world"}
#
json-fluent-compact: {"tag":"log_test.health","c":2,"t":"1136214245.654321000","s":3,"sev":"E","g":11,"f":"util/log/format_json_test.go","l":123,"n":0,"r":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"message":"hello ‹world›"}
json-fluent: {"tag":"log_test.health","channel_numeric":2,"channel":"HEALTH","timestamp":"1136214245.654321000","severity_numeric":3,"severity":"ERROR","goroutine":11,"file":"util/log/format_json_test.go","line":123,"entry_counter":0,"redactable":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"message":"hello ‹world›"}
json-compact: {"c":2,"t":"1136214245.654321000","s":3,"sev":"E","g":11,"f":"util/log/format_json_test.go","l":123,"n":0,"r":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"message":"hello ‹world›"}
json: {"channel_numeric":2,"channel":"HEALTH","timestamp":"1136214245.654321000","severity_numeric":3,"severity":"ERROR","goroutine":11,"file":"util/log/format_json_test.go","line":123,"entry_counter":0,"redactable":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"message":"hello ‹world›"}
json-fluent-compact: {"tag":"log_test.health","c":2,"t":"1136214245.654321000","v":"v999.0.0","s":3,"sev":"E","g":11,"f":"util/log/format_json_test.go","l":123,"n":0,"r":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"message":"hello ‹world›"}
json-fluent: {"tag":"log_test.health","channel_numeric":2,"channel":"HEALTH","timestamp":"1136214245.654321000","version":"v999.0.0","severity_numeric":3,"severity":"ERROR","goroutine":11,"file":"util/log/format_json_test.go","line":123,"entry_counter":0,"redactable":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"message":"hello ‹world›"}
json-compact: {"c":2,"t":"1136214245.654321000","v":"v999.0.0","s":3,"sev":"E","g":11,"f":"util/log/format_json_test.go","l":123,"n":0,"r":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"message":"hello ‹world›"}
json: {"channel_numeric":2,"channel":"HEALTH","timestamp":"1136214245.654321000","version":"v999.0.0","severity_numeric":3,"severity":"ERROR","goroutine":11,"file":"util/log/format_json_test.go","line":123,"entry_counter":0,"redactable":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"message":"hello ‹world›"}

0 comments on commit 2662eda

Please sign in to comment.