tool/logs: add support for flushable ingestions #2906
Conversation
|
This change is |
There was a problem hiding this comment.
Reviewable status: 0 of 4 files reviewed, 1 unresolved discussion (waiting on @itsbilal)
tool/logs/compaction.go line 1053 at r2 (raw file):
} func parseIngestDuringFlush(line string, b *logEventCollector) error {
Yes, this logic is basically a duplicate of parseIngest, but I'd like to keep it separate as I find it easier to reason about this way.
There was a problem hiding this comment.
Reviewable status: 0 of 4 files reviewed, 2 unresolved discussions (waiting on @itsbilal)
tool/logs/compaction.go line 1116 at r2 (raw file):
return errors.Newf("could not parse file number: %s", err) } files[i] = ingestedFile{
was a bug
There was a problem hiding this comment.
Reviewable status: 0 of 4 files reviewed, 5 unresolved discussions (waiting on @bananabrick and @itsbilal)
tool/logs/compaction.go line 138 at r2 (raw file):
/* Job ID */ `\[JOB (?P<job>\d+)]\s` + /* match ingested flushable */ `flushed \d ingested flushable`) flushableIngestedPatternJobIdx = ingestedPattern.SubexpIndex("job")
flushableIngestedPattern
tool/logs/compaction.go line 144 at r2 (raw file):
/* File number */ `(?P<file>\d+)\s` + /* Bytes */ `\((?P<bytes>[0-9.]+( [BKMGTPE]|[KMGTPE]?B))\)`) flushableIngestedFilePatternLevelIdx = ingestedFilePattern.SubexpIndex("level")
flushableIngestedFilePattern.. though I'd probably just use the ingestedFilePattern and stuff as they should always be the same, no?
tool/logs/compaction.go line 1053 at r2 (raw file):
Previously, bananabrick (Arjun Nair) wrote…
Yes, this logic is basically a duplicate of parseIngest, but I'd like to keep it separate as I find it easier to reason about this way.
[nit] The loop could be factored out (and we can remove flushableIngestedFilePattern*Idx)
tool/logs/testdata/compactions-23-1 line 479 at r2 (raw file):
compact L6 L6 0 0 0 1 1 0B 0B 0B 11MB 0s total 1 1 0 1 3 128MB 3.6MB 4.0MB 11MB 1s
These tests belong in compactions (they have post-23.1 format, e.g. 1.9KB instead of 1.9 K).
If you care whether we parse these in 23.1, you should include a 23-1 style test here and for TestCompactionLogs_Regex
|
Previously, RaduBerinde wrote…
Maybe we should rename |
There was a problem hiding this comment.
Reviewable status: 0 of 4 files reviewed, 1 unresolved discussion (waiting on @itsbilal and @RaduBerinde)
tool/logs/compaction.go line 144 at r2 (raw file):
Previously, RaduBerinde wrote…
flushableIngestedFilePattern.. though I'd probably just use the
ingestedFilePatternand stuff as they should always be the same, no?
Done.
tool/logs/compaction.go line 1053 at r2 (raw file):
Previously, RaduBerinde wrote…
[nit] The loop could be factored out (and we can remove
flushableIngestedFilePattern*Idx)
Done.
There was a problem hiding this comment.
Reviewable status: 0 of 4 files reviewed, 2 unresolved discussions (waiting on @itsbilal and @RaduBerinde)
tool/logs/testdata/compactions-23-1 line 484 at r3 (raw file):
log I230831 04:13:28.824280 3780 3@pebble/event.go:685 ⋮ [n10,s10,pebble] 365 [JOB 226] flushed 6 ingested flushables L0:024334 (1.5 K) + L0:024339 (1.0 K) + L0:024335 (1.9 K) + L0:024336 (1.1 K) + L0:024337 (1.1 K) + L0:024338 (12 K) in 0.0s (0.0s total), output rate 67 M/s
Looked at the code for both master vs 23.1 which generates this line and I believe this is the correct 23.1 format.
There was a problem hiding this comment.
Reviewable status: 0 of 4 files reviewed, 2 unresolved discussions (waiting on @itsbilal)
tool/logs/testdata/compactions-23-1 line 479 at r2 (raw file):
Previously, RaduBerinde wrote…
Maybe we should rename
compactionstocompactions-currentorcompactions-master? You're not the first one who was confused by this
Sorry, on second thought compactions-master will become confusing when we fork a release branch.. I think -current or -latest is better. All else LGTM, thanks!
There are two kinds of log lines which are relevant to flushable ingestions. The first one is of the form: ``` ingested as flushable 024323 (1.5KB), 024328 (1.0KB), 024324 (2.0KB), 024325 (1.1KB), 024326 (1.1KB), 024327 (54KB) ``` The second one is of the form: ``` flushed 6 ingested flushables L0:024323 (1.5KB) + L0:024328 (1.0KB) + L0:024324 (2.0KB) + L2:024325 (1.1KB) + L2:024326 (1.1KB) + L0:024327 (54KB) in 0.0s (0.0s total), output rate 152MB/s ``` The first type gets printed when we perform a flushable ingestion, and the second type gets printed when we actually ingest the sstables during the flush. For now, we ignore the first log type, and parse the second log type as ingestions. On the following logs: ``` I230831 04:13:28.689575 3717 3@pebble/event.go:685 ⋮ [n10,s10,pebble] 345 [JOB 219] flushed 6 ingested flushables L0:024323 (1.5KB) + L0:024328 (1.0KB) + L0:024324 (2.0KB) + L2:024325 (1.1KB) + L2:024326 (1.1KB) + L0:024327 (54KB) in 0.0s (0.0s total), output rate 152MB/s I230831 04:13:28.824280 3780 3@pebble/event.go:685 ⋮ [n10,s10,pebble] 365 [JOB 226] flushed 6 ingested flushables L0:024334 (1.5KB) + L0:024339 (1.0KB) + L0:024335 (1.9KB) + L0:024336 (1.1KB) + L0:024337 (1.1KB) + L0:024338 (12KB) in 0.0s (0.0s total), output rate 67MB/s ``` We get the following ingestion summary: ``` _kind______from______to_____________________________________count___bytes______time flush L0 2 227KB 0s ingest L0 10 77KB ingest L2 2 2.2KB total 14 306KB 0s _kind______from______to___default____move___elide__delete___count___in(B)__out(B)__mov(B)__del(B)______time compact L2 L3 2 0 0 0 2 31MB 31MB 0B 0B 0s compact L3 L4 0 4 0 0 4 0B 0B 60MB 0B 0s compact L4 L5 2 3 0 0 5 64MB 64MB 32MB 0B 0s compact L5 L6 4 0 0 0 4 320MB 320MB 0B 0B 0s compact L6 L6 0 0 32 1 33 1.3GB 1.3GB 0B 4.4MB 3s total 8 7 32 1 48 1.7GB 1.7GB 92MB 4.4MB 4s ``` Fixes: #2899
There was a problem hiding this comment.
Reviewable status: 0 of 4 files reviewed, 2 unresolved discussions (waiting on @itsbilal)
There are two kinds of log lines which are relevant to flushable ingestions.
The first one is of the form:
The second one is of the form:
The first type gets printed when we perform a flushable ingestion, and the second type gets printed when we actually ingest the sstables during the flush.
For now, we ignore the first log type, and parse the second log type as ingestions.
On the following logs:
We get the following ingestion summary:
Fixes: #2899