pkg/cli: add tenant ID filter flag to debug merge-logs

With multiple tenants running per-process, log files are
shared between tenants where tenant ID tags are used to
distinguish which tenant a log entry originated from.

When dealing with logs, especially in a debug.zip bundle,
we need to provide tools that make it easy to filter logs
to a specific tenant, or group of tenants.

This patch updates the `debug merge-logs` command with a
`--tenant-ids` flag which can be used to filter merged
logs to specific tenant ID(s). For example, to only include
logs for app tenants 2 and 3:

```
cockroach debug merge-logs ... --tenant-ids=2,3
```

Release note (cli change): The `debug merge-logs`
CLI command is now equipped with a `--tenant-ids`
flag, which can be used to provide the command with
a list of tenant IDs to filter logs on. For example,
to only include logs for secondary tenants 2 and 3:

```
cockroach debug merge-logs ... --tenant-ids=2,3
```

Note that when processing logs from older cluster
versions, where a tenant ID tag may not be present
on the log entry, the command will interpret any
log without a tenant ID as belonging to the system
tenant (tenant ID = 1).

pkg/cli/debug.go

@@ -1128,16 +1128,17 @@ const logFilePattern = "^(?:(?P<fpath>.*)/)?" + 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")

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

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) {

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

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

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)

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

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