Skip to content

crl-release-25.4: pebble: log per-table/blob output sizes for flushes and compactions #6119

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
RaduBerinde merged 1 commit into from
Jul 3, 2026
Merged

crl-release-25.4: pebble: log per-table/blob output sizes for flushes and compactions #6119

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
17 changes: 17 additions & 0 deletions compaction.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -155,6 +155,9 @@ const (
compactionKindRewrite
compactionKindIngestedFlushable
compactionKindBlobFileRewrite
// compactionKindVirtualRewrite must be the last compactionKind.
// If a new kind has to be added after VirtualRewrite,
// update AllCompactionKindStrings() accordingly.
compactionKindVirtualRewrite
)

Expand Down Expand Up @@ -197,6 +200,20 @@ func (k compactionKind) compactingOrFlushing() string {
return "compacting"
}

// AllCompactionKindStrings returns all compaction kind string representations
// for testing purposes. Used by tool/logs/compaction_test.go to verify the
// compaction summary tool stays in sync with new compaction types.
//
// NOTE: This function iterates up to compactionKindVirtualRewrite. If a new
// compactionKind is added after VirtualRewrite, update this function accordingly.
func AllCompactionKindStrings() map[string]bool {
kinds := make(map[string]bool)
for k := compactionKindDefault; k <= compactionKindVirtualRewrite; k++ {
kinds[k.String()] = true
}
return kinds
}

type compaction interface {
AddInProgressLocked(*DB)
BeganAt() time.Time
Expand Down
92 changes: 78 additions & 14 deletions event.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -58,6 +58,41 @@ func formatFileNums(tables []TableInfo) string {
return buf.String()
}

// FormatTablesWithSizes formats a list of tables, showing each table's file
// number, its size, and (if non-zero) its estimated blob reference size. For
// example: "000123(1.0MB+4.0MB) 000124(2.0MB)".
func FormatTablesWithSizes(tables []TableInfo) string {
var buf strings.Builder
for i := range tables {
if i > 0 {
buf.WriteString(" ")
}
buf.WriteString(tables[i].FileNum.String())
buf.WriteByte('(')
buf.WriteString(humanize.Bytes.Uint64(tables[i].Size).String())
if refSize := tables[i].EstimatedReferenceSize(); refSize > 0 {
buf.WriteByte('+')
buf.WriteString(humanize.Bytes.Uint64(refSize).String())
}
buf.WriteByte(')')
}
return buf.String()
}

// formatTotalSize formats a total table size and (if non-zero) total reference
// size as "size+refSize" (e.g. "3.0MB+4.0MB"). The no-space form is
// intentional: it mirrors the per-file form produced by FormatTablesWithSizes
// (e.g. "000123(7.0MB+2.0MB)"). The log parser in tool/logs/compaction.go
// accepts both this and the spaced "size + refSize" form that
// LevelInfo.SafeFormat uses for input levels.
func formatTotalSize(size, refSize uint64) string {
s := humanize.Bytes.Uint64(size).String()
if refSize > 0 {
s += "+" + humanize.Bytes.Uint64(refSize).String()
}
return s
}

// DataCorruptionInfo contains the information for a DataCorruption event.
type DataCorruptionInfo struct {
// Path of the file that is corrupted. For remote files the path starts with
Expand Down Expand Up @@ -288,6 +323,41 @@ func formatBlobFileNums(blobs []BlobFileInfo) string {
return buf.String()
}

// FormatBlobsWithSizes formats a list of blob files, showing each blob file's
// disk file number and size (and the MVCC garbage percentage, if present). For
// example: "000125(5.0MB) 000126(2.0MB, MVCCGarbage: 12%)".
func FormatBlobsWithSizes(blobs []BlobFileInfo) string {
var buf strings.Builder
for i := range blobs {
if i > 0 {
buf.WriteString(" ")
}
buf.WriteString(blobs[i].DiskFileNum.String())
buf.WriteByte('(')
buf.WriteString(humanize.Bytes.Uint64(blobs[i].Size).String())
if blobs[i].MVCCGarbageSize > 0 {
fmt.Fprintf(&buf, ", MVCCGarbage: %s",
crhumanize.Percent(blobs[i].MVCCGarbageSize, blobs[i].ValueSize))
}
buf.WriteByte(')')
}
return buf.String()
}

// formatOutputBlobs returns the " blob(s) [...] (...)" log segment for a list of
// output blob files, or an empty string if there are none.
func formatOutputBlobs(blobs []BlobFileInfo) redact.SafeString {
if len(blobs) == 0 {
return ""
}
pluralBlob := redact.SafeString("s")
if len(blobs) == 1 {
pluralBlob = ""
}
return redact.SafeString(fmt.Sprintf(" blob%s [%s] (%s)",
pluralBlob, FormatBlobsWithSizes(blobs), humanize.Bytes.Uint64(blobsTotalSize(blobs))))
}

// CompactionInfo contains the info for a compaction event.
type CompactionInfo struct {
// JobID is the ID of the compaction job.
Expand Down Expand Up @@ -362,11 +432,13 @@ func (i CompactionInfo) SafeFormat(w redact.SafePrinter, _ rune) {
if len(i.Annotations) > 0 {
w.Printf("%s ", i.Annotations)
}
blobInfo := formatOutputBlobs(i.Output.Blobs)
w.Print(levelInfos(i.Input))
w.Printf(" -> L%d [%s] (%s), in %.1fs (%.1fs total), output rate %s/s",
w.Printf(" -> L%d [%s] (%s)%s, in %.1fs (%.1fs total), output rate %s/s",
redact.Safe(i.Output.Level),
redact.Safe(formatFileNums(i.Output.Tables)),
redact.Safe(humanize.Bytes.Uint64(outputSize)),
redact.Safe(FormatTablesWithSizes(i.Output.Tables)),
redact.Safe(formatTotalSize(outputSize, tablesTotalReferenceSize(i.Output.Tables))),
blobInfo,
redact.Safe(i.Duration.Seconds()),
redact.Safe(i.TotalDuration.Seconds()),
redact.Safe(humanize.Bytes.Uint64(uint64(float64(outputSize)/i.Duration.Seconds()))))
Expand Down Expand Up @@ -435,15 +507,7 @@ func (i FlushInfo) SafeFormat(w redact.SafePrinter, _ rune) {
if i.Input == 1 {
plural = ""
}
blobInfo := redact.SafeString("")
if len(i.OutputBlobs) > 0 {
pluralBlob := redact.SafeString("s")
if len(i.OutputBlobs) == 1 {
pluralBlob = ""
}
blobInfo = redact.SafeString(fmt.Sprintf(" blob%s [%s] (%s)",
pluralBlob, formatBlobFileNums(i.OutputBlobs), humanize.Bytes.Uint64(blobsTotalSize(i.OutputBlobs))))
}
blobInfo := formatOutputBlobs(i.OutputBlobs)
if !i.Done {
w.Printf("[JOB %d] ", redact.Safe(i.JobID))
if !i.Ingest {
Expand All @@ -464,8 +528,8 @@ func (i FlushInfo) SafeFormat(w redact.SafePrinter, _ rune) {
w.Printf("[JOB %d] flushed %d memtable%s (%s) to L0 [%s] (%s)%s, in %.1fs (%.1fs total), output rate %s/s",
redact.Safe(i.JobID), redact.Safe(i.Input), plural,
redact.Safe(humanize.Bytes.Uint64(i.InputBytes)),
redact.Safe(formatFileNums(i.OutputTables)),
redact.Safe(humanize.Bytes.Uint64(outputSize)),
redact.Safe(FormatTablesWithSizes(i.OutputTables)),
redact.Safe(formatTotalSize(outputSize, tablesTotalReferenceSize(i.OutputTables))),
blobInfo,
redact.Safe(i.Duration.Seconds()),
redact.Safe(i.TotalDuration.Seconds()),
Expand Down
60 changes: 60 additions & 0 deletions event_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@ import (
"encoding/hex"
"strings"
"testing"
"time"

"github.com/cockroachdb/datadriven"
"github.com/cockroachdb/pebble/internal/base"
Expand Down Expand Up @@ -69,3 +70,62 @@ func TestLevelInfoSafeFormat(t *testing.T) {
require.Equal(t, "L0 [000001 000002] (4.0KB + 1.2MB) Score=1.31", li.String())
})
}

func TestFormatTablesWithSizes(t *testing.T) {
require.Equal(t, "", FormatTablesWithSizes(nil))
require.Equal(t, "000001(3.0KB)",
FormatTablesWithSizes([]TableInfo{tableInfoWithRefSize(1, 3<<10, 0)}))
require.Equal(t, "000001(3.0KB+1.0MB)",
FormatTablesWithSizes([]TableInfo{tableInfoWithRefSize(1, 3<<10, 1<<20)}))
// Multiple tables exercise the separator and the per-table refSize omission.
require.Equal(t, "000001(3.0KB+1.0MB) 000002(1.0KB)",
FormatTablesWithSizes([]TableInfo{
tableInfoWithRefSize(1, 3<<10, 1<<20),
tableInfoWithRefSize(2, 1<<10, 0),
}))
}

func TestFormatBlobsWithSizes(t *testing.T) {
require.Equal(t, "", FormatBlobsWithSizes(nil))
require.Equal(t, "000006(5.0MB)",
FormatBlobsWithSizes([]BlobFileInfo{{DiskFileNum: base.DiskFileNum(6), Size: 5 << 20}}))
// Multiple blobs; the second carries MVCC garbage (1/4 of its values).
require.Equal(t, "000006(5.0MB) 000007(2.0MB, MVCCGarbage: 25%)",
FormatBlobsWithSizes([]BlobFileInfo{
{DiskFileNum: base.DiskFileNum(6), Size: 5 << 20},
{DiskFileNum: base.DiskFileNum(7), Size: 2 << 20, ValueSize: 4 << 20, MVCCGarbageSize: 1 << 20},
}))
}

func TestFormatTotalSize(t *testing.T) {
require.Equal(t, "3.0KB", formatTotalSize(3<<10, 0))
require.Equal(t, "3.0KB+1.0MB", formatTotalSize(3<<10, 1<<20))
}

// TestCompactionInfoSafeFormatBlobs verifies the compaction "done" line renders
// per-table output sizes and the output-blob segment. This is the only direct
// coverage of the compaction output-blob branch; golden testdata flushes blobs
// but never compacts them.
func TestCompactionInfoSafeFormatBlobs(t *testing.T) {
ci := CompactionInfo{
JobID: 1,
Reason: "default",
Input: []LevelInfo{{Level: 0, Tables: []TableInfo{tableInfoWithRefSize(1, 1<<20, 0)}}},
Output: LevelInfo{
Level: 6,
Tables: []TableInfo{
tableInfoWithRefSize(10, 8<<20, 2<<20),
tableInfoWithRefSize(11, 2<<20, 0),
},
Blobs: []BlobFileInfo{
{DiskFileNum: base.DiskFileNum(12), Size: 3 << 20},
{DiskFileNum: base.DiskFileNum(13), Size: 1 << 20},
},
},
Duration: time.Second,
TotalDuration: time.Second,
Done: true,
}
require.Contains(t, ci.String(),
"-> L6 [000010(8.0MB+2.0MB) 000011(2.0MB)] (10MB+2.0MB) blobs [000012(3.0MB) 000013(1.0MB)] (4.0MB)")
}
2 changes: 1 addition & 1 deletion replay/testdata/collect/clean_before_copy
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,7 @@ flush
000002
----
created src/000002.sst
[JOB 0] flushed 1 memtable (100B) to L0 [000002] (10KB), in 0.1s (0.1s total), output rate 100KB/s
[JOB 0] flushed 1 memtable (100B) to L0 [000002(10KB)] (10KB), in 0.1s (0.1s total), output rate 100KB/s

clean
src/000002.sst
Expand Down
2 changes: 1 addition & 1 deletion replay/testdata/collect/copy_before_clean
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,7 @@ flush
000002
----
created src/000002.sst
[JOB 0] flushed 1 memtable (100B) to L0 [000002] (10KB), in 0.1s (0.1s total), output rate 100KB/s
[JOB 0] flushed 1 memtable (100B) to L0 [000002(10KB)] (10KB), in 0.1s (0.1s total), output rate 100KB/s

# Wait for 000002.sst to be copied.

Expand Down
4 changes: 2 additions & 2 deletions replay/testdata/collect/manifest_copying
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -30,7 +30,7 @@ flush
000003
----
created src/000003.sst
[JOB 0] flushed 1 memtable (100B) to L0 [000003] (10KB), in 0.1s (0.1s total), output rate 100KB/s
[JOB 0] flushed 1 memtable (100B) to L0 [000003(10KB)] (10KB), in 0.1s (0.1s total), output rate 100KB/s

wait
----
Expand Down Expand Up @@ -62,7 +62,7 @@ flush
----
created src/000005.sst
created src/000006.sst
[JOB 0] flushed 1 memtable (100B) to L0 [000005 000006] (20KB), in 0.1s (0.1s total), output rate 200KB/s
[JOB 0] flushed 1 memtable (100B) to L0 [000005(10KB) 000006(10KB)] (20KB), in 0.1s (0.1s total), output rate 200KB/s

wait
----
Expand Down
4 changes: 2 additions & 2 deletions replay/testdata/collect/start_stop
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -38,7 +38,7 @@ flush
----
created src/000005.sst
created src/000006.sst
[JOB 0] flushed 1 memtable (100B) to L0 [000005 000006] (20KB), in 0.1s (0.1s total), output rate 200KB/s
[JOB 0] flushed 1 memtable (100B) to L0 [000005(10KB) 000006(10KB)] (20KB), in 0.1s (0.1s total), output rate 200KB/s

# dst/ should now have the original insgested files (00000{2-4}.sst) and the
# manifest, but not the more-recently flushed files (00000{5-6}.sst). src/
Expand Down Expand Up @@ -82,7 +82,7 @@ flush
----
created src/000007.sst
created src/000008.sst
[JOB 0] flushed 1 memtable (100B) to L0 [000007 000008] (20KB), in 0.1s (0.1s total), output rate 200KB/s
[JOB 0] flushed 1 memtable (100B) to L0 [000007(10KB) 000008(10KB)] (20KB), in 0.1s (0.1s total), output rate 200KB/s

wait
----
Expand Down
10 changes: 5 additions & 5 deletions testdata/compaction/compaction_cancellation
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -34,7 +34,7 @@ manual compaction cancelled: context canceled, current queued compactions: 0
# One compaction was done.
compaction-log
----
[JOB 1] compacted(move) L2 [000004] (680B) Score=0.00 + L3 [] (0B) Score=0.00 -> L3 [000004] (680B), in 1.0s (1.0s total), output rate 680B/s
[JOB 1] compacted(move) L2 [000004] (680B) Score=0.00 + L3 [] (0B) Score=0.00 -> L3 [000004(680B)] (680B), in 1.0s (1.0s total), output rate 680B/s

compact a-z L2 parallel
----
Expand All @@ -45,8 +45,8 @@ L3:

compaction-log sort
----
[JOB 1] compacted(move) L2 [000005] (680B) Score=0.00 + L3 [] (0B) Score=0.00 -> L3 [000005] (680B), in 1.0s (1.0s total), output rate 680B/s
[JOB 1] compacted(move) L2 [000006] (680B) Score=0.00 + L3 [] (0B) Score=0.00 -> L3 [000006] (680B), in 1.0s (1.0s total), output rate 680B/s
[JOB 1] compacted(move) L2 [000005] (680B) Score=0.00 + L3 [] (0B) Score=0.00 -> L3 [000005(680B)] (680B), in 1.0s (1.0s total), output rate 680B/s
[JOB 1] compacted(move) L2 [000006] (680B) Score=0.00 + L3 [] (0B) Score=0.00 -> L3 [000006(680B)] (680B), in 1.0s (1.0s total), output rate 680B/s

# Repeat with only blocking the last of the three manual compactions.
add-ongoing-compaction startLevel=3 outputLevel=4 start=g end=h
Expand All @@ -59,5 +59,5 @@ manual compaction cancelled: context canceled, current queued compactions: 0
# Two compactions were done.
compaction-log
----
[JOB 1] compacted(move) L3 [000004] (680B) Score=0.00 + L4 [] (0B) Score=0.00 -> L4 [000004] (680B), in 1.0s (1.0s total), output rate 680B/s
[JOB 1] compacted(move) L3 [000005] (680B) Score=0.00 + L4 [] (0B) Score=0.00 -> L4 [000005] (680B), in 1.0s (1.0s total), output rate 680B/s
[JOB 1] compacted(move) L3 [000004] (680B) Score=0.00 + L4 [] (0B) Score=0.00 -> L4 [000004(680B)] (680B), in 1.0s (1.0s total), output rate 680B/s
[JOB 1] compacted(move) L3 [000005] (680B) Score=0.00 + L4 [] (0B) Score=0.00 -> L4 [000005(680B)] (680B), in 1.0s (1.0s total), output rate 680B/s
6 changes: 3 additions & 3 deletions testdata/compaction/mvcc_garbage_blob
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -39,8 +39,8 @@ Blob files:

flush-log
----
[JOB 1] flushed 1 memtable (100B) to L0 [000005] (827B) blob [000006 (MVCCGarbage: 100%)] (102B), in 1.0s (1.0s total), output rate 827B/s
[JOB 1] flushed 1 memtable (100B) to L0 [000008] (707B), in 1.0s (1.0s total), output rate 707B/s
[JOB 1] flushed 1 memtable (100B) to L0 [000005(827B+102B)] (827B+102B) blob [000006(102B, MVCCGarbage: 100%)] (102B), in 1.0s (1.0s total), output rate 827B/s
[JOB 1] flushed 1 memtable (100B) to L0 [000008(707B)] (707B), in 1.0s (1.0s total), output rate 707B/s

batch
set yay@3 a
Expand All @@ -62,4 +62,4 @@ Blob files:

flush-log
----
[JOB 1] flushed 1 memtable (100B) to L0 [000010] (795B) blob [000011 (MVCCGarbage: 17%)] (102B), in 1.0s (1.0s total), output rate 795B/s
[JOB 1] flushed 1 memtable (100B) to L0 [000010(795B+102B)] (795B+102B) blob [000011(102B, MVCCGarbage: 17%)] (102B), in 1.0s (1.0s total), output rate 795B/s
6 changes: 3 additions & 3 deletions testdata/compaction/score_compaction_picked_before_manual
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,7 +15,7 @@ L6:
# compaction.
compaction-log
----
[JOB 1] compacted(move) L5 [000004] (680B) Score=0.00 + L6 [] (0B) Score=0.00 -> L6 [000004] (680B), in 1.0s (1.0s total), output rate 680B/s
[JOB 1] compacted(move) L5 [000004] (680B) Score=0.00 + L6 [] (0B) Score=0.00 -> L6 [000004(680B)] (680B), in 1.0s (1.0s total), output rate 680B/s

# Do an auto score-based compaction with the same LSM as the previous test.
define disable-multi-level lbase-max-bytes=1 auto-compactions=off
Expand All @@ -33,7 +33,7 @@ L6:
# Note the score is > 1.0 since these is a score-based compaction.
compaction-log
----
[JOB 1] compacted(move) L5 [000004] (680B) Score=944.44 + L6 [] (0B) Score=0.00 -> L6 [000004] (680B), in 1.0s (1.0s total), output rate 680B/s
[JOB 1] compacted(move) L5 [000004] (680B) Score=944.44 + L6 [] (0B) Score=0.00 -> L6 [000004(680B)] (680B), in 1.0s (1.0s total), output rate 680B/s

# With the same LSM as the previous test, try to do both a manual and
# score-based compaction. The score-based compaction runs first.
Expand Down Expand Up @@ -64,4 +64,4 @@ set-disable-auto-compact v=true
# The score-based compaction ran first.
compaction-log
----
[JOB 1] compacted(move) L5 [000004] (680B) Score=944.44 + L6 [] (0B) Score=0.00 -> L6 [000004] (680B), in 1.0s (1.0s total), output rate 680B/s
[JOB 1] compacted(move) L5 [000004] (680B) Score=944.44 + L6 [] (0B) Score=0.00 -> L6 [000004(680B)] (680B), in 1.0s (1.0s total), output rate 680B/s
Loading
Loading