diff --git a/pkg/cli/debug.go b/pkg/cli/debug.go index a0c69825f144..1a603b98f50b 100644 --- a/pkg/cli/debug.go +++ b/pkg/cli/debug.go @@ -1128,16 +1128,17 @@ const logFilePattern = "^(?:(?P.*)/)?" + log.FileNamePattern + "$" // TODO(knz): this struct belongs elsewhere. // See: https://github.com/cockroachdb/cockroach/issues/49509 var debugMergeLogsOpts = struct { - from time.Time - to time.Time - filter *regexp.Regexp - program *regexp.Regexp - file *regexp.Regexp - keepRedactable bool - prefix string - redactInput bool - format string - useColor forceColor + from time.Time + to time.Time + filter *regexp.Regexp + program *regexp.Regexp + file *regexp.Regexp + keepRedactable bool + prefix string + redactInput bool + format string + useColor forceColor + tenantIDsFilter []string }{ program: nil, // match everything file: regexp.MustCompile(logFilePattern), @@ -1190,7 +1191,23 @@ func runDebugMergeLogs(cmd *cobra.Command, args []string) error { } } - return writeLogStream(s, outStream, o.filter, o.keepRedactable, cp) + // Validate tenantIDsFilter + if len(o.tenantIDsFilter) != 0 { + for _, tID := range o.tenantIDsFilter { + number, err := strconv.ParseUint(tID, 10, 64) + if err != nil { + return errors.Wrapf(err, + "invalid tenant ID provided in filter: %s. Tenant IDs must be integers >= 0", tID) + } + _, err = roachpb.MakeTenantID(number) + if err != nil { + return errors.Wrapf(err, + "invalid tenant ID provided in filter: %s. Unable to parse into roachpb.TenantID", tID) + } + } + } + + return writeLogStream(s, outStream, o.filter, o.keepRedactable, cp, o.tenantIDsFilter) } var debugIntentCount = &cobra.Command{ @@ -1450,6 +1467,8 @@ func init() { "log format of the input files") f.Var(&debugMergeLogsOpts.useColor, "color", "force use of TTY escape codes to colorize the output") + f.StringSliceVar(&debugMergeLogsOpts.tenantIDsFilter, "tenant-ids", nil, + "tenant IDs to filter logs by") f = debugDecodeKeyCmd.Flags() f.Var(&decodeKeyOptions.encoding, "encoding", "key argument encoding") diff --git a/pkg/cli/debug_merge_logs.go b/pkg/cli/debug_merge_logs.go index d51b394d4658..a45546bfd31b 100644 --- a/pkg/cli/debug_merge_logs.go +++ b/pkg/cli/debug_merge_logs.go @@ -40,7 +40,12 @@ type logStream interface { // writeLogStream pops messages off of s and writes them to out prepending // prefix per message and filtering messages which match filter. func writeLogStream( - s logStream, out io.Writer, filter *regexp.Regexp, keepRedactable bool, cp ttycolor.Profile, + s logStream, + out io.Writer, + filter *regexp.Regexp, + keepRedactable bool, + cp ttycolor.Profile, + tenantIDsFilter []string, ) error { const chanSize = 1 << 16 // 64k const maxWriteBufSize = 1 << 18 // 256kB @@ -49,6 +54,10 @@ func writeLogStream( logpb.Entry *fileInfo } + tenantIDFilterSet := make(map[string]struct{}, len(tenantIDsFilter)) + for _, tID := range tenantIDsFilter { + tenantIDFilterSet[tID] = struct{}{} + } render := func(ei entryInfo, w io.Writer) (err error) { // TODO(postamar): add support for other output formats // Currently, `render` applies the `crdb-v1-tty` format regardless of the @@ -96,6 +105,11 @@ func writeLogStream( entryChan = nil break } + if len(tenantIDsFilter) != 0 { + if _, ok := tenantIDFilterSet[ei.TenantID]; !ok { + break + } + } startLen := pending.Len() if err := render(ei, pending); err != nil { return err diff --git a/pkg/cli/debug_merge_logs_test.go b/pkg/cli/debug_merge_logs_test.go index d8cffa7616da..471d928d603c 100644 --- a/pkg/cli/debug_merge_logs_test.go +++ b/pkg/cli/debug_merge_logs_test.go @@ -168,6 +168,21 @@ func getCases(format string) []testCase { dataPaths: []string{"/5/redactable.log"}, flags: []string{"--redact=true", "--redactable-output=true", "--file-pattern", ".*"}, }, + { + name: "6.no-tenant-filter", + dataPaths: []string{"/6/*/*"}, + flags: []string{"--redact=false", "--redactable-output=false", "--file-pattern", ".*"}, + }, + { + name: "6.app-tenants-filter", + dataPaths: []string{"/6/*/*"}, + flags: []string{"--redact=false", "--redactable-output=false", "--file-pattern", ".*", "--tenant-ids=2,3"}, + }, + { + name: "6.system-tenant-filter", + dataPaths: []string{"/6/*/*"}, + flags: []string{"--redact=false", "--redactable-output=false", "--file-pattern", ".*", "--tenant-ids=1"}, + }, } for i := range cases { cases[i].format = format @@ -181,6 +196,9 @@ func resetDebugMergeLogFlags(errorFn func(s string)) { errorFn(fmt.Sprintf("Failed to set flag to default: %v", err)) } }) + // (Value).Set() for Slice flags has weird behavior where it appends to the existing + // slice instead of truly clearing the value. Manually reset it instead. + debugMergeLogsOpts.tenantIDsFilter = []string{} } func (c testCase) run(t *testing.T) { diff --git a/pkg/cli/testdata/merge_logs_crdb-v1/1/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_06_47Z.004130.log b/pkg/cli/testdata/merge_logs_crdb-v1/1/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_06_47Z.004130.log index baf302f063b0..997531e40cb4 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v1/1/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_06_47Z.004130.log +++ b/pkg/cli/testdata/merge_logs_crdb-v1/1/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_06_47Z.004130.log @@ -1,10 +1,10 @@ -I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) -I181130 22:14:37.516378 441 server/status/runtime.go:465 [n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] gossip status (ok, 3 nodes) +I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [T1,n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) +I181130 22:14:37.516378 441 server/status/runtime.go:465 [T1,n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] gossip status (ok, 3 nodes) gossip client (0/3 cur/max conns) gossip server (2/3 cur/max conns, infos 4077/2242 sent/received, bytes 1275332B/555352B sent/received) 2: ajwerner-test-0002:26257 (8m0s) 3: ajwerner-test-0003:26257 (8m0s) -I181130 22:14:47.519324 441 server/status/runtime.go:465 [n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net -I181130 22:14:57.522236 441 server/status/runtime.go:465 [n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net -I181130 22:15:07.525316 441 server/status/runtime.go:465 [n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net +I181130 22:14:47.519324 441 server/status/runtime.go:465 [T1,n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net +I181130 22:14:57.522236 441 server/status/runtime.go:465 [T1,n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net +I181130 22:15:07.525316 441 server/status/runtime.go:465 [T1,n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v1/1/2.logs/cockroach.test-0002.ubuntu.2018-11-30T22_06_47Z.003959.log b/pkg/cli/testdata/merge_logs_crdb-v1/1/2.logs/cockroach.test-0002.ubuntu.2018-11-30T22_06_47Z.003959.log index d7e7869f2497..89c1b353de9a 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v1/1/2.logs/cockroach.test-0002.ubuntu.2018-11-30T22_06_47Z.003959.log +++ b/pkg/cli/testdata/merge_logs_crdb-v1/1/2.logs/cockroach.test-0002.ubuntu.2018-11-30T22_06_47Z.003959.log @@ -1,10 +1,10 @@ -I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 -I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] -I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 -I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] -I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 -I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] -I181130 22:14:57.650774 499 server/status/runtime.go:465 [n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net -I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 -I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] -I181130 22:15:07.653821 499 server/status/runtime.go:465 [n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net +I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 +I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] +I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 +I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] +I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [T1,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 +I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [T1,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] +I181130 22:14:57.650774 499 server/status/runtime.go:465 [T1,n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net +I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [T1,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 +I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [T1,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] +I181130 22:15:07.653821 499 server/status/runtime.go:465 [T1,n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v1/2/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_06_47Z.004130.log b/pkg/cli/testdata/merge_logs_crdb-v1/2/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_06_47Z.004130.log index 181149b717c1..1c057463263e 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v1/2/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_06_47Z.004130.log +++ b/pkg/cli/testdata/merge_logs_crdb-v1/2/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_06_47Z.004130.log @@ -1,6 +1,6 @@ -I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) -I181130 22:14:37.516378 441 server/status/runtime.go:465 [n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] gossip status (ok, 3 nodes) +I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [T1,n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) +I181130 22:14:37.516378 441 server/status/runtime.go:465 [T1,n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] gossip status (ok, 3 nodes) gossip client (0/3 cur/max conns) gossip server (2/3 cur/max conns, infos 4077/2242 sent/received, bytes 1275332B/555352B sent/received) 2: ajwerner-test-0002:26257 (8m0s) diff --git a/pkg/cli/testdata/merge_logs_crdb-v1/2/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_14_47Z.004130.log b/pkg/cli/testdata/merge_logs_crdb-v1/2/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_14_47Z.004130.log index 3ef19304683c..e375d33ef913 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v1/2/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_14_47Z.004130.log +++ b/pkg/cli/testdata/merge_logs_crdb-v1/2/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_14_47Z.004130.log @@ -1,3 +1,3 @@ -I181130 22:14:47.519324 441 server/status/runtime.go:465 [n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net -I181130 22:14:57.522236 441 server/status/runtime.go:465 [n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net -I181130 22:15:07.525316 441 server/status/runtime.go:465 [n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net +I181130 22:14:47.519324 441 server/status/runtime.go:465 [T1,n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net +I181130 22:14:57.522236 441 server/status/runtime.go:465 [T1,n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net +I181130 22:15:07.525316 441 server/status/runtime.go:465 [T1,n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v1/2/2.logs/cockroach.test-0002.ubuntu.2018-11-30T22_06_47Z.003959.log b/pkg/cli/testdata/merge_logs_crdb-v1/2/2.logs/cockroach.test-0002.ubuntu.2018-11-30T22_06_47Z.003959.log index d7e7869f2497..89c1b353de9a 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v1/2/2.logs/cockroach.test-0002.ubuntu.2018-11-30T22_06_47Z.003959.log +++ b/pkg/cli/testdata/merge_logs_crdb-v1/2/2.logs/cockroach.test-0002.ubuntu.2018-11-30T22_06_47Z.003959.log @@ -1,10 +1,10 @@ -I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 -I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] -I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 -I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] -I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 -I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] -I181130 22:14:57.650774 499 server/status/runtime.go:465 [n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net -I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 -I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] -I181130 22:15:07.653821 499 server/status/runtime.go:465 [n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net +I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 +I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] +I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 +I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] +I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [T1,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 +I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [T1,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] +I181130 22:14:57.650774 499 server/status/runtime.go:465 [T1,n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net +I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [T1,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 +I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [T1,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] +I181130 22:15:07.653821 499 server/status/runtime.go:465 [T1,n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v1/3/1/not_standard.log b/pkg/cli/testdata/merge_logs_crdb-v1/3/1/not_standard.log index baf302f063b0..997531e40cb4 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v1/3/1/not_standard.log +++ b/pkg/cli/testdata/merge_logs_crdb-v1/3/1/not_standard.log @@ -1,10 +1,10 @@ -I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) -I181130 22:14:37.516378 441 server/status/runtime.go:465 [n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] gossip status (ok, 3 nodes) +I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [T1,n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) +I181130 22:14:37.516378 441 server/status/runtime.go:465 [T1,n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] gossip status (ok, 3 nodes) gossip client (0/3 cur/max conns) gossip server (2/3 cur/max conns, infos 4077/2242 sent/received, bytes 1275332B/555352B sent/received) 2: ajwerner-test-0002:26257 (8m0s) 3: ajwerner-test-0003:26257 (8m0s) -I181130 22:14:47.519324 441 server/status/runtime.go:465 [n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net -I181130 22:14:57.522236 441 server/status/runtime.go:465 [n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net -I181130 22:15:07.525316 441 server/status/runtime.go:465 [n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net +I181130 22:14:47.519324 441 server/status/runtime.go:465 [T1,n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net +I181130 22:14:57.522236 441 server/status/runtime.go:465 [T1,n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net +I181130 22:15:07.525316 441 server/status/runtime.go:465 [T1,n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v1/3/2/also_not_standard.log b/pkg/cli/testdata/merge_logs_crdb-v1/3/2/also_not_standard.log index d7e7869f2497..89c1b353de9a 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v1/3/2/also_not_standard.log +++ b/pkg/cli/testdata/merge_logs_crdb-v1/3/2/also_not_standard.log @@ -1,10 +1,10 @@ -I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 -I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] -I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 -I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] -I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 -I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] -I181130 22:14:57.650774 499 server/status/runtime.go:465 [n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net -I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 -I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] -I181130 22:15:07.653821 499 server/status/runtime.go:465 [n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net +I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 +I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] +I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 +I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] +I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [T1,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 +I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [T1,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] +I181130 22:14:57.650774 499 server/status/runtime.go:465 [T1,n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net +I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [T1,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 +I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [T1,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] +I181130 22:15:07.653821 499 server/status/runtime.go:465 [T1,n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v1/4/npe-repanic.log b/pkg/cli/testdata/merge_logs_crdb-v1/4/npe-repanic.log index ed451f5d640f..6a047e1886a2 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v1/4/npe-repanic.log +++ b/pkg/cli/testdata/merge_logs_crdb-v1/4/npe-repanic.log @@ -1,4 +1,4 @@ -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 i was created via the following code: +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] i was created via the following code: func main() { defer cleanup() defer cleanup() diff --git a/pkg/cli/testdata/merge_logs_crdb-v1/4/npe.log b/pkg/cli/testdata/merge_logs_crdb-v1/4/npe.log index 797c09e1e09d..38290bf132b4 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v1/4/npe.log +++ b/pkg/cli/testdata/merge_logs_crdb-v1/4/npe.log @@ -1,10 +1,10 @@ I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 query: SELECT count(*) FROM "multi col range partitioning - MAXVALUE MAXVALUE" WHERE a >= 4 AND (a, b) < (5, 6) -E190412 10:06:00.645112 195432 storage/queue.go:866 [n1,replicate,s1,r161/2:/Table/84/{1/5/7-2}] no removable replicas from range that needs a removal: [2*:27, 3:0] -E190412 10:06:00.681552 195558 storage/queue.go:866 [n1,replicate,s1,r158/3:/Table/84/1/3{-/4}] no removable replicas from range that needs a removal: [2:0, 3*:34] -E190412 10:06:00.780922 195831 storage/queue.go:866 [n3,replicate,s3,r49/1:/Table/84/1/{3/4-4}] no removable replicas from range that needs a removal: [1*:16, 2:0] -E190412 10:06:00.818605 195938 storage/queue.go:866 [n1,replicate,s1,r159/2:/Table/84/1/{4-5/6}] no removable replicas from range that needs a removal: [2*:27, 3:0] -E190412 10:06:01.015534 196474 storage/queue.go:866 [n2,replicate,s2,r161/3:/Table/84/{1/5/7-2}] no removable replicas from range that needs a removal: [2:0, 3*:29] -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 query: SELECT count(*) FROM "multi col range partitioning - MAXVALUE MAXVALUE" WHERE (a, b) < (3, 4) +E190412 10:06:00.645112 195432 storage/queue.go:866 [T1,n1,replicate,s1,r161/2:/Table/84/{1/5/7-2}] no removable replicas from range that needs a removal: [2*:27, 3:0] +E190412 10:06:00.681552 195558 storage/queue.go:866 [T1,n1,replicate,s1,r158/3:/Table/84/1/3{-/4}] no removable replicas from range that needs a removal: [2:0, 3*:34] +E190412 10:06:00.780922 195831 storage/queue.go:866 [T1,n3,replicate,s3,r49/1:/Table/84/1/{3/4-4}] no removable replicas from range that needs a removal: [1*:16, 2:0] +E190412 10:06:00.818605 195938 storage/queue.go:866 [T1,n1,replicate,s1,r159/2:/Table/84/1/{4-5/6}] no removable replicas from range that needs a removal: [2*:27, 3:0] +E190412 10:06:01.015534 196474 storage/queue.go:866 [T1,n2,replicate,s2,r161/3:/Table/84/{1/5/7-2}] no removable replicas from range that needs a removal: [2:0, 3*:29] +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] query: SELECT count(*) FROM "multi col range partitioning - MAXVALUE MAXVALUE" WHERE (a, b) < (3, 4) panic: runtime error: invalid memory address or nil pointer dereference [recovered] panic: runtime error: invalid memory address or nil pointer dereference [signal SIGSEGV: segmentation violation code=0x1 addr=0x10 pc=0x20efbad] diff --git a/pkg/cli/testdata/merge_logs_crdb-v1/5/redactable.log b/pkg/cli/testdata/merge_logs_crdb-v1/5/redactable.log index 9053f9a06a61..bb3ebe033bf5 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v1/5/redactable.log +++ b/pkg/cli/testdata/merge_logs_crdb-v1/5/redactable.log @@ -1,2 +1,2 @@ -I190412 10:06:00.490104 183717 server/server.go:1423 ⋮ safe ‹unsafe› -I190412 10:06:00.490104 183717 server/server.go:1424 unknownsafe +I190412 10:06:00.490104 183717 server/server.go:1423 ⋮ [T1] safe ‹unsafe› +I190412 10:06:00.490104 183717 server/server.go:1424 [T1] unknownsafe diff --git a/pkg/cli/testdata/merge_logs_crdb-v1/6/1.logs/cockroach.test-0001.ubuntu.2023-01-09T22_06_47Z.004130.log b/pkg/cli/testdata/merge_logs_crdb-v1/6/1.logs/cockroach.test-0001.ubuntu.2023-01-09T22_06_47Z.004130.log new file mode 100644 index 000000000000..0a740efdc601 --- /dev/null +++ b/pkg/cli/testdata/merge_logs_crdb-v1/6/1.logs/cockroach.test-0001.ubuntu.2023-01-09T22_06_47Z.004130.log @@ -0,0 +1,10 @@ +I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [T3,n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) +I181130 22:14:37.516378 441 server/status/runtime.go:465 [T1,n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] gossip status (ok, 3 nodes) +gossip client (0/3 cur/max conns) +gossip server (2/3 cur/max conns, infos 4077/2242 sent/received, bytes 1275332B/555352B sent/received) + 2: ajwerner-test-0002:26257 (8m0s) + 3: ajwerner-test-0003:26257 (8m0s) +I181130 22:14:47.519324 441 server/status/runtime.go:465 [T1,n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net +I181130 22:14:57.522236 441 server/status/runtime.go:465 [T2,n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net +I181130 22:15:07.525316 441 server/status/runtime.go:465 [T3,n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v1/6/2.logs/cockroach.test-0002.ubuntu.2022-01-09T22_06_47Z.003959.log b/pkg/cli/testdata/merge_logs_crdb-v1/6/2.logs/cockroach.test-0002.ubuntu.2022-01-09T22_06_47Z.003959.log new file mode 100644 index 000000000000..183d4e5cc316 --- /dev/null +++ b/pkg/cli/testdata/merge_logs_crdb-v1/6/2.logs/cockroach.test-0002.ubuntu.2022-01-09T22_06_47Z.003959.log @@ -0,0 +1,10 @@ +I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 +I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [T2,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] +I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [T3,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 +I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] +I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [T2,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 +I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [T3,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] +I181130 22:14:57.650774 499 server/status/runtime.go:465 [T1,n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net +I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [T2,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 +I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [T3,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] +I181130 22:15:07.653821 499 server/status/runtime.go:465 [T1,n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v1/results/6.app-tenants-filter b/pkg/cli/testdata/merge_logs_crdb-v1/results/6.app-tenants-filter new file mode 100644 index 000000000000..37c1382584b1 --- /dev/null +++ b/pkg/cli/testdata/merge_logs_crdb-v1/results/6.app-tenants-filter @@ -0,0 +1,9 @@ +> I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [T3,n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) +> I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [T2,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] +> I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [T3,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 +> I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [T2,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 +> I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [T3,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] +> I181130 22:14:57.522236 441 server/status/runtime.go:465 [T2,n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net +> I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [T2,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 +> I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [T3,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] +> I181130 22:15:07.525316 441 server/status/runtime.go:465 [T3,n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v1/results/6.no-tenant-filter b/pkg/cli/testdata/merge_logs_crdb-v1/results/6.no-tenant-filter new file mode 100644 index 000000000000..7ba8d5bf400f --- /dev/null +++ b/pkg/cli/testdata/merge_logs_crdb-v1/results/6.no-tenant-filter @@ -0,0 +1,20 @@ +> I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [T3,n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) +> I181130 22:14:37.516378 441 server/status/runtime.go:465 [T1,n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net +> I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] gossip status (ok, 3 nodes) +gossip client (0/3 cur/max conns) +gossip server (2/3 cur/max conns, infos 4077/2242 sent/received, bytes 1275332B/555352B sent/received) + 2: ajwerner-test-0002:26257 (8m0s) + 3: ajwerner-test-0003:26257 (8m0s) +> I181130 22:14:47.519324 441 server/status/runtime.go:465 [T1,n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net +> I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 +> I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [T2,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] +> I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [T3,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 +> I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] +> I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [T2,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 +> I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [T3,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] +> I181130 22:14:57.522236 441 server/status/runtime.go:465 [T2,n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net +> I181130 22:14:57.650774 499 server/status/runtime.go:465 [T1,n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net +> I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [T2,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 +> I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [T3,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] +> I181130 22:15:07.525316 441 server/status/runtime.go:465 [T3,n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net +> I181130 22:15:07.653821 499 server/status/runtime.go:465 [T1,n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v1/results/6.system-tenant-filter b/pkg/cli/testdata/merge_logs_crdb-v1/results/6.system-tenant-filter new file mode 100644 index 000000000000..0670883dfdbe --- /dev/null +++ b/pkg/cli/testdata/merge_logs_crdb-v1/results/6.system-tenant-filter @@ -0,0 +1,11 @@ +> I181130 22:14:37.516378 441 server/status/runtime.go:465 [T1,n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net +> I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] gossip status (ok, 3 nodes) +gossip client (0/3 cur/max conns) +gossip server (2/3 cur/max conns, infos 4077/2242 sent/received, bytes 1275332B/555352B sent/received) + 2: ajwerner-test-0002:26257 (8m0s) + 3: ajwerner-test-0003:26257 (8m0s) +> I181130 22:14:47.519324 441 server/status/runtime.go:465 [T1,n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net +> I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 +> I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] +> I181130 22:14:57.650774 499 server/status/runtime.go:465 [T1,n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net +> I181130 22:15:07.653821 499 server/status/runtime.go:465 [T1,n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v2/1/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_06_47Z.004130.log b/pkg/cli/testdata/merge_logs_crdb-v2/1/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_06_47Z.004130.log index 11213a6a0d3a..0f913e8e3525 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v2/1/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_06_47Z.004130.log +++ b/pkg/cli/testdata/merge_logs_crdb-v2/1/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_06_47Z.004130.log @@ -1,10 +1,10 @@ -I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) -I181130 22:14:37.516378 441 server/status/runtime.go:465 [n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] gossip status (ok, 3 nodes) -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] +gossip client (0/3 cur/max conns) -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] +gossip server (2/3 cur/max conns, infos 4077/2242 sent/received, bytes 1275332B/555352B sent/received) -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] + 2: ajwerner-test-0002:26257 (8m0s) -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] + 3: ajwerner-test-0003:26257 (8m0s) -I181130 22:14:47.519324 441 server/status/runtime.go:465 [n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net -I181130 22:14:57.522236 441 server/status/runtime.go:465 [n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net -I181130 22:15:07.525316 441 server/status/runtime.go:465 [n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net +I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [T1,n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) +I181130 22:14:37.516378 441 server/status/runtime.go:465 [T1,n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] gossip status (ok, 3 nodes) +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] +gossip client (0/3 cur/max conns) +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] +gossip server (2/3 cur/max conns, infos 4077/2242 sent/received, bytes 1275332B/555352B sent/received) +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] + 2: ajwerner-test-0002:26257 (8m0s) +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] + 3: ajwerner-test-0003:26257 (8m0s) +I181130 22:14:47.519324 441 server/status/runtime.go:465 [T1,n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net +I181130 22:14:57.522236 441 server/status/runtime.go:465 [T1,n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net +I181130 22:15:07.525316 441 server/status/runtime.go:465 [T1,n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v2/1/2.logs/cockroach.test-0002.ubuntu.2018-11-30T22_06_47Z.003959.log b/pkg/cli/testdata/merge_logs_crdb-v2/1/2.logs/cockroach.test-0002.ubuntu.2018-11-30T22_06_47Z.003959.log index 4869977cd987..3ba08f3a70b8 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v2/1/2.logs/cockroach.test-0002.ubuntu.2018-11-30T22_06_47Z.003959.log +++ b/pkg/cli/testdata/merge_logs_crdb-v2/1/2.logs/cockroach.test-0002.ubuntu.2018-11-30T22_06_47Z.003959.log @@ -1,10 +1,10 @@ -I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 -I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] -I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 -I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] -I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 -I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] -I181130 22:14:57.650774 499 server/status/runtime.go:465 [n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net -I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 -I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] -I181130 22:15:07.653821 499 server/status/runtime.go:465 [n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net +I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 +I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] +I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 +I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] +I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [T1,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 +I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [T1,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] +I181130 22:14:57.650774 499 server/status/runtime.go:465 [T1,n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net +I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [T1,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 +I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [T1,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] +I181130 22:15:07.653821 499 server/status/runtime.go:465 [T1,n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v2/2/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_06_47Z.004130.log b/pkg/cli/testdata/merge_logs_crdb-v2/2/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_06_47Z.004130.log index 5879e11fd644..3efb8350b9c2 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v2/2/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_06_47Z.004130.log +++ b/pkg/cli/testdata/merge_logs_crdb-v2/2/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_06_47Z.004130.log @@ -1,7 +1,7 @@ -I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) -I181130 22:14:37.516378 441 server/status/runtime.go:465 [n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] gossip status (ok, 3 nodes) -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] +gossip client (0/3 cur/max conns) -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] +gossip server (2/3 cur/max conns, infos 4077/2242 sent/received, bytes 1275332B/555352B sent/received) -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] + 2: ajwerner-test-0002:26257 (8m0s) -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] + 3: ajwerner-test-0003:26257 (8m0s) +I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [T1,n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) +I181130 22:14:37.516378 441 server/status/runtime.go:465 [T1,n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] gossip status (ok, 3 nodes) +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] +gossip client (0/3 cur/max conns) +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] +gossip server (2/3 cur/max conns, infos 4077/2242 sent/received, bytes 1275332B/555352B sent/received) +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] + 2: ajwerner-test-0002:26257 (8m0s) +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] + 3: ajwerner-test-0003:26257 (8m0s) diff --git a/pkg/cli/testdata/merge_logs_crdb-v2/2/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_14_47Z.004130.log b/pkg/cli/testdata/merge_logs_crdb-v2/2/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_14_47Z.004130.log index 6bbc0a563feb..5bc51c62e111 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v2/2/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_14_47Z.004130.log +++ b/pkg/cli/testdata/merge_logs_crdb-v2/2/1.logs/cockroach.test-0001.ubuntu.2018-11-30T22_14_47Z.004130.log @@ -1,3 +1,3 @@ -I181130 22:14:47.519324 441 server/status/runtime.go:465 [n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net -I181130 22:14:57.522236 441 server/status/runtime.go:465 [n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net -I181130 22:15:07.525316 441 server/status/runtime.go:465 [n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net +I181130 22:14:47.519324 441 server/status/runtime.go:465 [T1,n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net +I181130 22:14:57.522236 441 server/status/runtime.go:465 [T1,n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net +I181130 22:15:07.525316 441 server/status/runtime.go:465 [T1,n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v2/2/2.logs/cockroach.test-0002.ubuntu.2018-11-30T22_06_47Z.003959.log b/pkg/cli/testdata/merge_logs_crdb-v2/2/2.logs/cockroach.test-0002.ubuntu.2018-11-30T22_06_47Z.003959.log index 4869977cd987..3ba08f3a70b8 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v2/2/2.logs/cockroach.test-0002.ubuntu.2018-11-30T22_06_47Z.003959.log +++ b/pkg/cli/testdata/merge_logs_crdb-v2/2/2.logs/cockroach.test-0002.ubuntu.2018-11-30T22_06_47Z.003959.log @@ -1,10 +1,10 @@ -I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 -I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] -I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 -I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] -I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 -I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] -I181130 22:14:57.650774 499 server/status/runtime.go:465 [n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net -I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 -I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] -I181130 22:15:07.653821 499 server/status/runtime.go:465 [n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net +I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 +I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] +I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 +I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] +I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [T1,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 +I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [T1,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] +I181130 22:14:57.650774 499 server/status/runtime.go:465 [T1,n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net +I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [T1,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 +I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [T1,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] +I181130 22:15:07.653821 499 server/status/runtime.go:465 [T1,n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v2/3/1/not_standard.log b/pkg/cli/testdata/merge_logs_crdb-v2/3/1/not_standard.log index 11213a6a0d3a..0f913e8e3525 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v2/3/1/not_standard.log +++ b/pkg/cli/testdata/merge_logs_crdb-v2/3/1/not_standard.log @@ -1,10 +1,10 @@ -I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) -I181130 22:14:37.516378 441 server/status/runtime.go:465 [n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] gossip status (ok, 3 nodes) -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] +gossip client (0/3 cur/max conns) -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] +gossip server (2/3 cur/max conns, infos 4077/2242 sent/received, bytes 1275332B/555352B sent/received) -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] + 2: ajwerner-test-0002:26257 (8m0s) -I181130 22:14:47.400515 437 gossip/gossip.go:555 [n1] + 3: ajwerner-test-0003:26257 (8m0s) -I181130 22:14:47.519324 441 server/status/runtime.go:465 [n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net -I181130 22:14:57.522236 441 server/status/runtime.go:465 [n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net -I181130 22:15:07.525316 441 server/status/runtime.go:465 [n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net +I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [T1,n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) +I181130 22:14:37.516378 441 server/status/runtime.go:465 [T1,n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] gossip status (ok, 3 nodes) +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] +gossip client (0/3 cur/max conns) +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] +gossip server (2/3 cur/max conns, infos 4077/2242 sent/received, bytes 1275332B/555352B sent/received) +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] + 2: ajwerner-test-0002:26257 (8m0s) +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] + 3: ajwerner-test-0003:26257 (8m0s) +I181130 22:14:47.519324 441 server/status/runtime.go:465 [T1,n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net +I181130 22:14:57.522236 441 server/status/runtime.go:465 [T1,n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net +I181130 22:15:07.525316 441 server/status/runtime.go:465 [T1,n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v2/3/2/also_not_standard.log b/pkg/cli/testdata/merge_logs_crdb-v2/3/2/also_not_standard.log index 4869977cd987..3ba08f3a70b8 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v2/3/2/also_not_standard.log +++ b/pkg/cli/testdata/merge_logs_crdb-v2/3/2/also_not_standard.log @@ -1,10 +1,10 @@ -I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 -I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] -I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 -I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] -I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 -I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] -I181130 22:14:57.650774 499 server/status/runtime.go:465 [n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net -I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 -I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] -I181130 22:15:07.653821 499 server/status/runtime.go:465 [n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net +I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 +I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] +I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 +I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] +I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [T1,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 +I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [T1,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] +I181130 22:14:57.650774 499 server/status/runtime.go:465 [T1,n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net +I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [T1,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 +I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [T1,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] +I181130 22:15:07.653821 499 server/status/runtime.go:465 [T1,n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v2/4/npe-repanic.log b/pkg/cli/testdata/merge_logs_crdb-v2/4/npe-repanic.log index 4e5a3428cabf..cfab120756c4 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v2/4/npe-repanic.log +++ b/pkg/cli/testdata/merge_logs_crdb-v2/4/npe-repanic.log @@ -1,69 +1,69 @@ -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] i was created via the following code: -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !func main() { -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! defer cleanup() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! defer cleanup() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! defer cleanup() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! defer cleanup() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! defer cleanup() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! defer cleanup() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! defer cleanup() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! func() { func() { func() { func() { func() { -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! func() { func() { panic("boom") -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! }()}()}()}()}()}()}() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !} -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !and here we go: -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! panic: boom [recovered] -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! panic: boom [recovered] -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! panic: boom [recovered] -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! panic: boom [recovered] -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! panic: boom [recovered] -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! panic: boom [recovered] -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! panic: boom -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !goroutine 1 [running]: -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !main.cleanup() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /tmp/sandbox881972553/main.go:20 +0x60 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !panic(0x122540, 0x16aa50) -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /usr/local/go/src/runtime/panic.go:522 +0x240 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !main.cleanup() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /tmp/sandbox881972553/main.go:20 +0x60 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !panic(0x122540, 0x16aa50) -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /usr/local/go/src/runtime/panic.go:522 +0x240 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !main.cleanup() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /tmp/sandbox881972553/main.go:20 +0x60 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !panic(0x122540, 0x16aa50) -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /usr/local/go/src/runtime/panic.go:522 +0x240 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !main.cleanup() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /tmp/sandbox881972553/main.go:20 +0x60 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !panic(0x122540, 0x16aa50) -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /usr/local/go/src/runtime/panic.go:522 +0x240 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !main.cleanup() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /tmp/sandbox881972553/main.go:20 +0x60 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !panic(0x122540, 0x16aa50) -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /usr/local/go/src/runtime/panic.go:522 +0x240 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !main.cleanup() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /tmp/sandbox881972553/main.go:20 +0x60 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !panic(0x122540, 0x16aa50) -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /usr/local/go/src/runtime/panic.go:522 +0x240 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !main.cleanup() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /tmp/sandbox881972553/main.go:20 +0x60 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !panic(0x122540, 0x16aa50) -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /usr/local/go/src/runtime/panic.go:522 +0x240 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !main.main.func1.1.1.1.1.1.1(...) -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /tmp/sandbox881972553/main.go:42 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !main.main.func1.1.1.1.1.1() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /tmp/sandbox881972553/main.go:43 +0x40 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !main.main.func1.1.1.1.1() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /tmp/sandbox881972553/main.go:44 +0x20 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !main.main.func1.1.1.1() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /tmp/sandbox881972553/main.go:45 +0x20 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !main.main.func1.1.1() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /tmp/sandbox881972553/main.go:46 +0x20 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !main.main.func1.1() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /tmp/sandbox881972553/main.go:47 +0x20 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !main.main.func1() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /tmp/sandbox881972553/main.go:48 +0x20 -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] !main.main() -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] ! /tmp/sandbox881972553/main.go:49 +0x200 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] i was created via the following code: +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !func main() { +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! defer cleanup() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! defer cleanup() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! defer cleanup() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! defer cleanup() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! defer cleanup() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! defer cleanup() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! defer cleanup() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! func() { func() { func() { func() { func() { +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! func() { func() { panic("boom") +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! }()}()}()}()}()}()}() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !} +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !and here we go: +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! panic: boom [recovered] +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! panic: boom [recovered] +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! panic: boom [recovered] +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! panic: boom [recovered] +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! panic: boom [recovered] +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! panic: boom [recovered] +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! panic: boom +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !goroutine 1 [running]: +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !main.cleanup() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /tmp/sandbox881972553/main.go:20 +0x60 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !panic(0x122540, 0x16aa50) +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /usr/local/go/src/runtime/panic.go:522 +0x240 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !main.cleanup() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /tmp/sandbox881972553/main.go:20 +0x60 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !panic(0x122540, 0x16aa50) +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /usr/local/go/src/runtime/panic.go:522 +0x240 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !main.cleanup() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /tmp/sandbox881972553/main.go:20 +0x60 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !panic(0x122540, 0x16aa50) +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /usr/local/go/src/runtime/panic.go:522 +0x240 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !main.cleanup() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /tmp/sandbox881972553/main.go:20 +0x60 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !panic(0x122540, 0x16aa50) +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /usr/local/go/src/runtime/panic.go:522 +0x240 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !main.cleanup() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /tmp/sandbox881972553/main.go:20 +0x60 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !panic(0x122540, 0x16aa50) +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /usr/local/go/src/runtime/panic.go:522 +0x240 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !main.cleanup() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /tmp/sandbox881972553/main.go:20 +0x60 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !panic(0x122540, 0x16aa50) +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /usr/local/go/src/runtime/panic.go:522 +0x240 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !main.cleanup() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /tmp/sandbox881972553/main.go:20 +0x60 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !panic(0x122540, 0x16aa50) +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /usr/local/go/src/runtime/panic.go:522 +0x240 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !main.main.func1.1.1.1.1.1.1(...) +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /tmp/sandbox881972553/main.go:42 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !main.main.func1.1.1.1.1.1() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /tmp/sandbox881972553/main.go:43 +0x40 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !main.main.func1.1.1.1.1() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /tmp/sandbox881972553/main.go:44 +0x20 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !main.main.func1.1.1.1() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /tmp/sandbox881972553/main.go:45 +0x20 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !main.main.func1.1.1() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /tmp/sandbox881972553/main.go:46 +0x20 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !main.main.func1.1() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /tmp/sandbox881972553/main.go:47 +0x20 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !main.main.func1() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /tmp/sandbox881972553/main.go:48 +0x20 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] !main.main() +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /tmp/sandbox881972553/main.go:49 +0x200 diff --git a/pkg/cli/testdata/merge_logs_crdb-v2/4/npe.log b/pkg/cli/testdata/merge_logs_crdb-v2/4/npe.log index 5bae5bea342c..66363f9f6bb7 100644 --- a/pkg/cli/testdata/merge_logs_crdb-v2/4/npe.log +++ b/pkg/cli/testdata/merge_logs_crdb-v2/4/npe.log @@ -1,26 +1,26 @@ -I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [-] query: SELECT count(*) FROM "multi col range partitioning - MAXVALUE MAXVALUE" WHERE a >= 4 AND (a, b) < (5, 6) -E190412 10:06:00.645112 195432 storage/queue.go:866 [n1,replicate,s1,r161/2:/Table/84/{1/5/7-2}] no removable replicas from range that needs a removal: [2*:27, 3:0] -E190412 10:06:00.681552 195558 storage/queue.go:866 [n1,replicate,s1,r158/3:/Table/84/1/3{-/4}] no removable replicas from range that needs a removal: [2:0, 3*:34] -E190412 10:06:00.780922 195831 storage/queue.go:866 [n3,replicate,s3,r49/1:/Table/84/1/{3/4-4}] no removable replicas from range that needs a removal: [1*:16, 2:0] -E190412 10:06:00.818605 195938 storage/queue.go:866 [n1,replicate,s1,r159/2:/Table/84/1/{4-5/6}] no removable replicas from range that needs a removal: [2*:27, 3:0] -E190412 10:06:01.015534 196474 storage/queue.go:866 [n2,replicate,s2,r161/3:/Table/84/{1/5/7-2}] no removable replicas from range that needs a removal: [2:0, 3*:29] -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] query: SELECT count(*) FROM "multi col range partitioning - MAXVALUE MAXVALUE" WHERE (a, b) < (3, 4) -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] !panic: runtime error: invalid memory address or nil pointer dereference [recovered] -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] ! panic: runtime error: invalid memory address or nil pointer dereference -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] ![signal SIGSEGV: segmentation violation code=0x1 addr=0x10 pc=0x20efbad] -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] ! -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] !goroutine 76680 [running]: -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] !github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).Recover(0xc000c467e0, 0x379a020, 0xc0029cb650) -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] ! /go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:185 +0x11f -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] !panic(0x2ccb620, 0x527ac20) -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] ! /usr/local/go/src/runtime/panic.go:513 +0x1b9 -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] !github.com/cockroachdb/cockroach/pkg/storage.(*replicaItem).setProcessing(...) -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] ! /go/src/github.com/cockroachdb/cockroach/pkg/storage/queue.go:80 -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] !github.com/cockroachdb/cockroach/pkg/storage.(*baseQueue).addToPurgatoryLocked.func2.1(0xc000473340, 0x379a020, 0xc0029cb650, 0xc000c467e0) -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] ! /go/src/github.com/cockroachdb/cockroach/pkg/storage/queue.go:928 +0x1dd -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] !github.com/cockroachdb/cockroach/pkg/storage.(*baseQueue).addToPurgatoryLocked.func2(0x379a020, 0xc0029cb650) -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] ! /go/src/github.com/cockroachdb/cockroach/pkg/storage/queue.go:949 +0x462 -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] !github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc001480a10, 0xc000c467e0, 0xc0002f37c0) -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] ! /go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:200 +0xe1 -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] !created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker -I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [-] ! /go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0xa8 +I190412 10:06:00.490104 183717 ccl/partitionccl/partition_test.go:204 [T1] query: SELECT count(*) FROM "multi col range partitioning - MAXVALUE MAXVALUE" WHERE a >= 4 AND (a, b) < (5, 6) +E190412 10:06:00.645112 195432 storage/queue.go:866 [T1,n1,replicate,s1,r161/2:/Table/84/{1/5/7-2}] no removable replicas from range that needs a removal: [2*:27, 3:0] +E190412 10:06:00.681552 195558 storage/queue.go:866 [T1,n1,replicate,s1,r158/3:/Table/84/1/3{-/4}] no removable replicas from range that needs a removal: [2:0, 3*:34] +E190412 10:06:00.780922 195831 storage/queue.go:866 [T1,n3,replicate,s3,r49/1:/Table/84/1/{3/4-4}] no removable replicas from range that needs a removal: [1*:16, 2:0] +E190412 10:06:00.818605 195938 storage/queue.go:866 [T1,n1,replicate,s1,r159/2:/Table/84/1/{4-5/6}] no removable replicas from range that needs a removal: [2*:27, 3:0] +E190412 10:06:01.015534 196474 storage/queue.go:866 [T1,n2,replicate,s2,r161/3:/Table/84/{1/5/7-2}] no removable replicas from range that needs a removal: [2:0, 3*:29] +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] query: SELECT count(*) FROM "multi col range partitioning - MAXVALUE MAXVALUE" WHERE (a, b) < (3, 4) +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] !panic: runtime error: invalid memory address or nil pointer dereference [recovered] +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] ! panic: runtime error: invalid memory address or nil pointer dereference +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] ![signal SIGSEGV: segmentation violation code=0x1 addr=0x10 pc=0x20efbad] +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] ! +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] !goroutine 76680 [running]: +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] !github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).Recover(0xc000c467e0, 0x379a020, 0xc0029cb650) +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:185 +0x11f +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] !panic(0x2ccb620, 0x527ac20) +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /usr/local/go/src/runtime/panic.go:513 +0x1b9 +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] !github.com/cockroachdb/cockroach/pkg/storage.(*replicaItem).setProcessing(...) +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /go/src/github.com/cockroachdb/cockroach/pkg/storage/queue.go:80 +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] !github.com/cockroachdb/cockroach/pkg/storage.(*baseQueue).addToPurgatoryLocked.func2.1(0xc000473340, 0x379a020, 0xc0029cb650, 0xc000c467e0) +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /go/src/github.com/cockroachdb/cockroach/pkg/storage/queue.go:928 +0x1dd +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] !github.com/cockroachdb/cockroach/pkg/storage.(*baseQueue).addToPurgatoryLocked.func2(0x379a020, 0xc0029cb650) +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /go/src/github.com/cockroachdb/cockroach/pkg/storage/queue.go:949 +0x462 +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] !github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc001480a10, 0xc000c467e0, 0xc0002f37c0) +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:200 +0xe1 +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] !created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker +I190412 10:06:01.029478 183717 ccl/partitionccl/partition_test.go:204 [T1] ! /go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0xa8 diff --git a/pkg/cli/testdata/merge_logs_crdb-v2/6/1.logs/cockroach.test-0001.ubuntu.2023-01-09T22_06_47Z.004130.log b/pkg/cli/testdata/merge_logs_crdb-v2/6/1.logs/cockroach.test-0001.ubuntu.2023-01-09T22_06_47Z.004130.log new file mode 100644 index 000000000000..811dd5a8b01d --- /dev/null +++ b/pkg/cli/testdata/merge_logs_crdb-v2/6/1.logs/cockroach.test-0001.ubuntu.2023-01-09T22_06_47Z.004130.log @@ -0,0 +1,10 @@ +I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [T3,n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) +I181130 22:14:37.516378 441 server/status/runtime.go:465 [T1,n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] gossip status (ok, 3 nodes) +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] +gossip client (0/3 cur/max conns) +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] +gossip server (2/3 cur/max conns, infos 4077/2242 sent/received, bytes 1275332B/555352B sent/received) +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] + 2: ajwerner-test-0002:26257 (8m0s) +I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] + 3: ajwerner-test-0003:26257 (8m0s) +I181130 22:14:47.519324 441 server/status/runtime.go:465 [T1,n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net +I181130 22:14:57.522236 441 server/status/runtime.go:465 [T2,n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net +I181130 22:15:07.525316 441 server/status/runtime.go:465 [T3,n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v2/6/2.logs/cockroach.test-0002.ubuntu.2022-01-09T22_06_47Z.003959.log b/pkg/cli/testdata/merge_logs_crdb-v2/6/2.logs/cockroach.test-0002.ubuntu.2022-01-09T22_06_47Z.003959.log new file mode 100644 index 000000000000..881f2a43fb9f --- /dev/null +++ b/pkg/cli/testdata/merge_logs_crdb-v2/6/2.logs/cockroach.test-0002.ubuntu.2022-01-09T22_06_47Z.003959.log @@ -0,0 +1,10 @@ +I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 +I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [T2,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] +I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [T3,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 +I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] +I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [T2,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 +I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [T3,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] +I181130 22:14:57.650774 499 server/status/runtime.go:465 [T1,n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net +I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [T2,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 +I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [T3,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] +I181130 22:15:07.653821 499 server/status/runtime.go:465 [T1,n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v2/results/6.app-tenants-filter b/pkg/cli/testdata/merge_logs_crdb-v2/results/6.app-tenants-filter new file mode 100644 index 000000000000..37c1382584b1 --- /dev/null +++ b/pkg/cli/testdata/merge_logs_crdb-v2/results/6.app-tenants-filter @@ -0,0 +1,9 @@ +> I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [T3,n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) +> I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [T2,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] +> I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [T3,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 +> I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [T2,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 +> I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [T3,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] +> I181130 22:14:57.522236 441 server/status/runtime.go:465 [T2,n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net +> I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [T2,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 +> I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [T3,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] +> I181130 22:15:07.525316 441 server/status/runtime.go:465 [T3,n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v2/results/6.no-tenant-filter b/pkg/cli/testdata/merge_logs_crdb-v2/results/6.no-tenant-filter new file mode 100644 index 000000000000..7ba8d5bf400f --- /dev/null +++ b/pkg/cli/testdata/merge_logs_crdb-v2/results/6.no-tenant-filter @@ -0,0 +1,20 @@ +> I181130 22:14:34.828612 740 storage/store_rebalancer.go:277 [T3,n1,s1,store-rebalancer] load-based lease transfers successfully brought s1 down to 37128.65 qps (mean=29834.62, upperThreshold=37293.27) +> I181130 22:14:37.516378 441 server/status/runtime.go:465 [T1,n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net +> I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] gossip status (ok, 3 nodes) +gossip client (0/3 cur/max conns) +gossip server (2/3 cur/max conns, infos 4077/2242 sent/received, bytes 1275332B/555352B sent/received) + 2: ajwerner-test-0002:26257 (8m0s) + 3: ajwerner-test-0003:26257 (8m0s) +> I181130 22:14:47.519324 441 server/status/runtime.go:465 [T1,n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net +> I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 +> I181130 22:14:49.706563 6152567 storage/replica_command.go:342 [T2,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split of this range at key /Table/53/1/-3661595080111255049 [r586] +> I181130 22:14:49.732930 6153357 storage/split_queue.go:213 [T3,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split based on load at key /Table/53/1/-8134885765915906309 +> I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] +> I181130 22:14:50.203263 6163815 storage/split_queue.go:213 [T2,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split based on load at key /Table/53/1/-8768249731886885702 +> I181130 22:14:50.203299 6163815 storage/replica_command.go:342 [T3,n2,split,s2,r171/3:/Table/53/1/-87{94402…-45781…}] initiating a split of this range at key /Table/53/1/-8768249731886885702 [r588] +> I181130 22:14:57.522236 441 server/status/runtime.go:465 [T2,n1] runtime stats: 986 MiB RSS, 1332 goroutines, 438 MiB/140 MiB/777 MiB GO alloc/idle/total, 151 MiB/203 MiB CGO alloc/total, 137663.6 CGO/sec, 2168.3/222.8 %(u/s)time, 0.4 %gc (45x), 192 MiB/203 MiB (r/w)net +> I181130 22:14:57.650774 499 server/status/runtime.go:465 [T1,n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net +> I181130 22:15:05.892547 6507691 storage/split_queue.go:213 [T2,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split based on load at key /Table/53/1/-698671514117501959 +> I181130 22:15:05.892592 6507691 storage/replica_command.go:342 [T3,n2,split,s2,r129/3:/Table/53/1/-{722633…-673989…}] initiating a split of this range at key /Table/53/1/-698671514117501959 [r589] +> I181130 22:15:07.525316 441 server/status/runtime.go:465 [T3,n1] runtime stats: 952 MiB RSS, 1422 goroutines, 397 MiB/165 MiB/777 MiB GO alloc/idle/total, 112 MiB/164 MiB CGO alloc/total, 133359.9 CGO/sec, 2137.8/225.1 %(u/s)time, 0.4 %gc (43x), 187 MiB/198 MiB (r/w)net +> I181130 22:15:07.653821 499 server/status/runtime.go:465 [T1,n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net diff --git a/pkg/cli/testdata/merge_logs_crdb-v2/results/6.system-tenant-filter b/pkg/cli/testdata/merge_logs_crdb-v2/results/6.system-tenant-filter new file mode 100644 index 000000000000..0670883dfdbe --- /dev/null +++ b/pkg/cli/testdata/merge_logs_crdb-v2/results/6.system-tenant-filter @@ -0,0 +1,11 @@ +> I181130 22:14:37.516378 441 server/status/runtime.go:465 [T1,n1] runtime stats: 900 MiB RSS, 1509 goroutines, 421 MiB/144 MiB/777 MiB GO alloc/idle/total, 96 MiB/144 MiB CGO alloc/total, 154632.4 CGO/sec, 2206.9/216.0 %(u/s)time, 0.4 %gc (43x), 182 MiB/204 MiB (r/w)net +> I181130 22:14:47.400515 437 gossip/gossip.go:555 [T1,n1] gossip status (ok, 3 nodes) +gossip client (0/3 cur/max conns) +gossip server (2/3 cur/max conns, infos 4077/2242 sent/received, bytes 1275332B/555352B sent/received) + 2: ajwerner-test-0002:26257 (8m0s) + 3: ajwerner-test-0003:26257 (8m0s) +> I181130 22:14:47.519324 441 server/status/runtime.go:465 [T1,n1] runtime stats: 957 MiB RSS, 1690 goroutines, 420 MiB/173 MiB/777 MiB GO alloc/idle/total, 124 MiB/174 MiB CGO alloc/total, 143837.6 CGO/sec, 2245.9/218.3 %(u/s)time, 0.5 %gc (47x), 199 MiB/210 MiB (r/w)net +> I181130 22:14:49.706516 6152567 storage/split_queue.go:213 [T1,n2,split,s2,r163/3:/Table/53/1/-36{84178…-35915…}] initiating a split based on load at key /Table/53/1/-3661595080111255049 +> I181130 22:14:49.732976 6153357 storage/replica_command.go:342 [T1,n2,split,s2,r269/3:/Table/53/1/-81{56147…-10716…}] initiating a split of this range at key /Table/53/1/-8134885765915906309 [r587] +> I181130 22:14:57.650774 499 server/status/runtime.go:465 [T1,n2] runtime stats: 729 MiB RSS, 1127 goroutines, 416 MiB/91 MiB/584 MiB GO alloc/idle/total, 75 MiB/128 MiB CGO alloc/total, 111534.7 CGO/sec, 2013.0/232.3 %(u/s)time, 0.4 %gc (56x), 189 MiB/189 MiB (r/w)net +> I181130 22:15:07.653821 499 server/status/runtime.go:465 [T1,n2] runtime stats: 756 MiB RSS, 1127 goroutines, 338 MiB/113 MiB/584 MiB GO alloc/idle/total, 94 MiB/149 MiB CGO alloc/total, 108469.2 CGO/sec, 1964.7/227.0 %(u/s)time, 0.4 %gc (54x), 185 MiB/184 MiB (r/w)net