Skip to content
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.

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

crl-release-23.2: db: ensure Metrics.WAL.BytesWritten is nondecreasing #3569

Merged
merged 2 commits into from
May 13, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
1 change: 0 additions & 1 deletion compaction.go
Original file line number Diff line number Diff line change
Expand Up @@ -2142,7 +2142,6 @@ func (d *DB) flush1() (bytesFlushed uint64, err error) {
// calculation even when the WAL is disabled.
metrics.BytesIn = metrics.BytesFlushed
} else {
metrics := c.metrics[0]
for i := 0; i < n; i++ {
metrics.BytesIn += d.mu.mem.queue[i].logSize
}
Expand Down
20 changes: 17 additions & 3 deletions db.go
Original file line number Diff line number Diff line change
Expand Up @@ -377,7 +377,7 @@ type DB struct {
queue []fileInfo
// The number of input bytes to the log. This is the raw size of the
// batches written to the WAL, without the overhead of the record
// envelopes.
// envelopes. Requires DB.mu to be held when read or written.
bytesIn uint64
// The LogWriter is protected by commitPipeline.mu. This allows log
// writes to be performed without holding DB.mu, but requires both
Expand Down Expand Up @@ -2471,7 +2471,7 @@ func (d *DB) makeRoomForWrite(b *Batch) error {
var prevLogSize uint64
if !d.opts.DisableWAL {
now := time.Now()
newLogNum, prevLogSize = d.recycleWAL()
newLogNum, prevLogSize = d.rotateWAL()
if b != nil {
b.commitStats.WALRotationDuration += time.Since(now)
}
Expand Down Expand Up @@ -2543,15 +2543,29 @@ func (d *DB) rotateMemtable(newLogNum FileNum, logSeqNum uint64, prev *memTable)
var entry *flushableEntry
d.mu.mem.mutable, entry = d.newMemTable(newLogNum, logSeqNum)
d.mu.mem.queue = append(d.mu.mem.queue, entry)
// d.logSize tracks the log size of the WAL file corresponding to the most
// recent flushable. The log size of the previous mutable memtable no longer
// applies to the current mutable memtable.
//
// It's tempting to perform this update in rotateWAL, but that would not be
// atomic with the enqueue of the new flushable. A call to DB.Metrics()
// could acquire DB.mu after the WAL has been rotated but before the new
// memtable has been appended; this would result in omitting the log size of
// the most recent flushable.
d.logSize.Store(0)
d.updateReadStateLocked(nil)
if prev.writerUnref() {
d.maybeScheduleFlush()
}
}

// rotateWAL creates a new write-ahead log, possibly recycling a previous WAL's
// files. It returns the file number assigned to the new WAL, and the size of
// the previous WAL file.
//
// Both DB.mu and commitPipeline.mu must be held by the caller. Note that DB.mu
// may be released and reacquired.
func (d *DB) recycleWAL() (newLogNum FileNum, prevLogSize uint64) {
func (d *DB) rotateWAL() (newLogNum FileNum, prevLogSize uint64) {
if d.opts.DisableWAL {
panic("pebble: invalid function call")
}
Expand Down
22 changes: 14 additions & 8 deletions ingest.go
Original file line number Diff line number Diff line change
Expand Up @@ -1223,7 +1223,12 @@ func (d *DB) handleIngestAsFlushable(meta []*fileMetadata, seqNum uint64) error
// We create a new WAL for the flushable instead of reusing the end of
// the previous WAL. This simplifies the increment of the minimum
// unflushed log number, and also simplifies WAL replay.
logNum, _ = d.recycleWAL()
var prevLogSize uint64
logNum, prevLogSize = d.rotateWAL()
// As the rotator of the WAL, we're responsible for updating the
// previous flushable queue tail's log size.
d.mu.mem.queue[len(d.mu.mem.queue)-1].logSize = prevLogSize

d.mu.Unlock()
err := d.commit.directWrite(b)
if err != nil {
Expand All @@ -1243,13 +1248,14 @@ func (d *DB) handleIngestAsFlushable(meta []*fileMetadata, seqNum uint64) error
// the appropriate value below.
newLogNum := d.mu.mem.queue[len(d.mu.mem.queue)-1].logNum
if !d.opts.DisableWAL {
// This is WAL num of the next mutable memtable which comes after the
// ingestedFlushable in the flushable queue. The mutable memtable
// will be created below.
newLogNum, _ = d.recycleWAL()
if err != nil {
return err
}
// newLogNum will be the WAL num of the next mutable memtable which
// comes after the ingestedFlushable in the flushable queue. The mutable
// memtable will be created below.
//
// The prevLogSize returned by rotateWAL is the WAL to which the
// flushable ingest keys were appended. This intermediary WAL is only
// used to record the flushable ingest and nothing else.
newLogNum, entry.logSize = d.rotateWAL()
}

currMem := d.mu.mem.mutable
Expand Down
65 changes: 65 additions & 0 deletions metrics_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,9 +7,12 @@ package pebble
import (
"bytes"
"fmt"
"math/rand"
"strconv"
"strings"
"sync"
"testing"
"time"

"github.com/cockroachdb/datadriven"
"github.com/cockroachdb/pebble/internal/humanize"
Expand Down Expand Up @@ -334,3 +337,65 @@ func TestMetricsWAmpDisableWAL(t *testing.T) {
require.Greater(t, tot.WriteAmp(), 1.0)
require.NoError(t, d.Close())
}

// TestMetricsWALBytesWrittenMonotonicity tests that the
// Metrics.WAL.BytesWritten metric is always nondecreasing.
// It's a regression test for issue #3505.
func TestMetricsWALBytesWrittenMonotonicity(t *testing.T) {
fs := vfs.NewMem()
d, err := Open("", &Options{
FS: fs,
// Use a tiny memtable size so that we get frequent flushes. While a
// flush is in-progress or completing, the WAL bytes written should
// remain nondecreasing.
MemTableSize: 1 << 20, /* 20 KiB */
})
require.NoError(t, err)

stopCh := make(chan struct{})

ks := testkeys.Alpha(3)
var wg sync.WaitGroup
const concurrentWriters = 5
wg.Add(concurrentWriters)
for w := 0; w < concurrentWriters; w++ {
go func() {
defer wg.Done()
data := make([]byte, 1<<10) // 1 KiB
rng := rand.New(rand.NewSource(time.Now().UnixNano()))
_, err := rng.Read(data)
require.NoError(t, err)

buf := make([]byte, ks.MaxLen())
for i := 0; ; i++ {
select {
case <-stopCh:
return
default:
}
n := testkeys.WriteKey(buf, ks, int64(i)%ks.Count())
require.NoError(t, d.Set(buf[:n], data, NoSync))
}
}()
}

func() {
defer func() { close(stopCh) }()
abort := time.After(time.Second)
var prevWALBytesWritten uint64
for {
select {
case <-abort:
return
default:
}

m := d.Metrics()
if m.WAL.BytesWritten < prevWALBytesWritten {
t.Fatalf("WAL bytes written decreased: %d -> %d", prevWALBytesWritten, m.WAL.BytesWritten)
}
prevWALBytesWritten = m.WAL.BytesWritten
}
}()
wg.Wait()
}
8 changes: 4 additions & 4 deletions testdata/event_listener
Original file line number Diff line number Diff line change
Expand Up @@ -278,9 +278,9 @@ level | tables size val-bl vtables | score | in | tables size | tables siz
4 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
5 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
6 | 1 662B 0B 0 | - | 1.3KB | 0 0B | 0 0B | 1 662B | 1.3KB | 1 0.5
total | 3 2.0KB 0B 0 | - | 825B | 1 717B | 0 0B | 4 3.4KB | 1.3KB | 3 4.2
total | 3 2.0KB 0B 0 | - | 798B | 1 717B | 0 0B | 4 3.4KB | 1.3KB | 3 4.3
-------------------------------------------------------------------------------------------------------------------
WAL: 1 files (27B) in: 48B written: 108B (125% overhead)
WAL: 1 files (0B) in: 48B written: 81B (69% overhead)
Flushes: 3
Compactions: 1 estimated debt: 2.0KB in progress: 0 (0B)
default: 1 delete: 0 elision: 0 move: 0 read: 0 rewrite: 0 multi-level: 0
Expand Down Expand Up @@ -370,7 +370,7 @@ metrics
| | | | ingested | moved | written | | amp
level | tables size val-bl vtables | score | in | tables size | tables size | tables size | read | r w
------+-----------------------------+-------+-------+--------------+--------------+--------------+-------+---------
0 | 4 2.7KB 0B 0 | 0.80 | 81B | 2 1.4KB | 0 0B | 4 2.6KB | 0B | 4 32.7
0 | 4 2.7KB 0B 0 | 0.80 | 108B | 2 1.4KB | 0 0B | 4 2.6KB | 0B | 4 24.5
1 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
2 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
3 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
Expand All @@ -379,7 +379,7 @@ level | tables size val-bl vtables | score | in | tables size | tables siz
6 | 2 1.3KB 0B 0 | - | 1.3KB | 1 717B | 0 0B | 1 662B | 1.3KB | 1 0.5
total | 6 4.0KB 0B 0 | - | 2.2KB | 3 2.1KB | 0 0B | 5 5.4KB | 1.3KB | 5 2.5
-------------------------------------------------------------------------------------------------------------------
WAL: 1 files (29B) in: 82B written: 110B (34% overhead)
WAL: 1 files (0B) in: 82B written: 108B (32% overhead)
Flushes: 6
Compactions: 1 estimated debt: 4.0KB in progress: 0 (0B)
default: 1 delete: 0 elision: 0 move: 0 read: 0 rewrite: 0 multi-level: 0
Expand Down
32 changes: 16 additions & 16 deletions testdata/metrics
Original file line number Diff line number Diff line change
Expand Up @@ -57,9 +57,9 @@ level | tables size val-bl vtables | score | in | tables size | tables siz
4 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
5 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
6 | 0 0B 0B 0 | - | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
total | 1 661B 0B 0 | - | 56B | 0 0B | 0 0B | 1 717B | 0B | 1 12.8
total | 1 661B 0B 0 | - | 28B | 0 0B | 0 0B | 1 689B | 0B | 1 24.6
-------------------------------------------------------------------------------------------------------------------
WAL: 1 files (28B) in: 17B written: 56B (229% overhead)
WAL: 1 files (0B) in: 17B written: 28B (65% overhead)
Flushes: 1
Compactions: 0 estimated debt: 0B in progress: 0 (0B)
default: 0 delete: 0 elision: 0 move: 0 read: 0 rewrite: 0 multi-level: 0
Expand Down Expand Up @@ -111,9 +111,9 @@ level | tables size val-bl vtables | score | in | tables size | tables siz
4 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
5 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
6 | 1 667B 0B 0 | - | 1.3KB | 0 0B | 0 0B | 1 667B | 1.3KB | 1 0.5
total | 1 667B 0B 0 | - | 84B | 0 0B | 0 0B | 3 2.0KB | 1.3KB | 1 24.7
total | 1 667B 0B 0 | - | 56B | 0 0B | 0 0B | 3 2.0KB | 1.3KB | 1 36.5
-------------------------------------------------------------------------------------------------------------------
WAL: 1 files (28B) in: 34B written: 84B (147% overhead)
WAL: 1 files (0B) in: 34B written: 56B (65% overhead)
Flushes: 2
Compactions: 1 estimated debt: 0B in progress: 0 (0B)
default: 1 delete: 0 elision: 0 move: 0 read: 0 rewrite: 0 multi-level: 0
Expand Down Expand Up @@ -150,9 +150,9 @@ level | tables size val-bl vtables | score | in | tables size | tables siz
4 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
5 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
6 | 1 667B 0B 0 | - | 1.3KB | 0 0B | 0 0B | 1 667B | 1.3KB | 1 0.5
total | 1 667B 0B 0 | - | 84B | 0 0B | 0 0B | 3 2.0KB | 1.3KB | 1 24.7
total | 1 667B 0B 0 | - | 56B | 0 0B | 0 0B | 3 2.0KB | 1.3KB | 1 36.5
-------------------------------------------------------------------------------------------------------------------
WAL: 1 files (28B) in: 34B written: 84B (147% overhead)
WAL: 1 files (0B) in: 34B written: 56B (65% overhead)
Flushes: 2
Compactions: 1 estimated debt: 0B in progress: 0 (0B)
default: 1 delete: 0 elision: 0 move: 0 read: 0 rewrite: 0 multi-level: 0
Expand Down Expand Up @@ -186,9 +186,9 @@ level | tables size val-bl vtables | score | in | tables size | tables siz
4 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
5 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
6 | 1 667B 0B 0 | - | 1.3KB | 0 0B | 0 0B | 1 667B | 1.3KB | 1 0.5
total | 1 667B 0B 0 | - | 84B | 0 0B | 0 0B | 3 2.0KB | 1.3KB | 1 24.7
total | 1 667B 0B 0 | - | 56B | 0 0B | 0 0B | 3 2.0KB | 1.3KB | 1 36.5
-------------------------------------------------------------------------------------------------------------------
WAL: 1 files (28B) in: 34B written: 84B (147% overhead)
WAL: 1 files (0B) in: 34B written: 56B (65% overhead)
Flushes: 2
Compactions: 1 estimated debt: 0B in progress: 0 (0B)
default: 1 delete: 0 elision: 0 move: 0 read: 0 rewrite: 0 multi-level: 0
Expand Down Expand Up @@ -225,9 +225,9 @@ level | tables size val-bl vtables | score | in | tables size | tables siz
4 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
5 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
6 | 1 667B 0B 0 | - | 1.3KB | 0 0B | 0 0B | 1 667B | 1.3KB | 1 0.5
total | 1 667B 0B 0 | - | 84B | 0 0B | 0 0B | 3 2.0KB | 1.3KB | 1 24.7
total | 1 667B 0B 0 | - | 56B | 0 0B | 0 0B | 3 2.0KB | 1.3KB | 1 36.5
-------------------------------------------------------------------------------------------------------------------
WAL: 1 files (28B) in: 34B written: 84B (147% overhead)
WAL: 1 files (0B) in: 34B written: 56B (65% overhead)
Flushes: 2
Compactions: 1 estimated debt: 0B in progress: 0 (0B)
default: 1 delete: 0 elision: 0 move: 0 read: 0 rewrite: 0 multi-level: 0
Expand Down Expand Up @@ -290,9 +290,9 @@ level | tables size val-bl vtables | score | in | tables size | tables siz
4 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
5 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
6 | 1 667B 0B 0 | - | 1.3KB | 0 0B | 0 0B | 1 667B | 1.3KB | 1 0.5
total | 4 2.9KB 38B 0 | - | 242B | 0 0B | 0 0B | 6 4.4KB | 1.3KB | 2 18.6
total | 4 2.9KB 38B 0 | - | 149B | 0 0B | 0 0B | 6 4.3KB | 1.3KB | 2 29.7
-------------------------------------------------------------------------------------------------------------------
WAL: 1 files (93B) in: 116B written: 242B (109% overhead)
WAL: 1 files (0B) in: 116B written: 149B (28% overhead)
Flushes: 3
Compactions: 1 estimated debt: 2.9KB in progress: 0 (0B)
default: 1 delete: 0 elision: 0 move: 0 read: 0 rewrite: 0 multi-level: 0
Expand Down Expand Up @@ -339,9 +339,9 @@ level | tables size val-bl vtables | score | in | tables size | tables siz
4 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
5 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
6 | 3 2.2KB 41B 0 | - | 3.5KB | 0 0B | 0 0B | 3 2.2KB | 3.5KB | 1 0.6
total | 3 2.2KB 41B 0 | - | 242B | 0 0B | 0 0B | 8 6.0KB | 3.5KB | 1 25.3
total | 3 2.2KB 41B 0 | - | 149B | 0 0B | 0 0B | 8 5.9KB | 3.5KB | 1 40.5
-------------------------------------------------------------------------------------------------------------------
WAL: 1 files (93B) in: 116B written: 242B (109% overhead)
WAL: 1 files (0B) in: 116B written: 149B (28% overhead)
Flushes: 3
Compactions: 2 estimated debt: 0B in progress: 0 (0B)
default: 2 delete: 0 elision: 0 move: 0 read: 0 rewrite: 0 multi-level: 0
Expand Down Expand Up @@ -427,7 +427,7 @@ metrics
| | | | ingested | moved | written | | amp
level | tables size val-bl vtables | score | in | tables size | tables size | tables size | read | r w
------+-----------------------------+-------+-------+--------------+--------------+--------------+-------+---------
0 | 4 2.8KB 0B 0 | 0.50 | 149B | 3 2.1KB | 0 0B | 6 4.2KB | 0B | 2 28.8
0 | 4 2.8KB 0B 0 | 0.50 | 187B | 3 2.1KB | 0 0B | 6 4.2KB | 0B | 2 22.9
1 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
2 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
3 | 0 0B 0B 0 | 0.00 | 0B | 0 0B | 0 0B | 0 0B | 0B | 0 0.0
Expand All @@ -436,7 +436,7 @@ level | tables size val-bl vtables | score | in | tables size | tables siz
6 | 3 2.2KB 41B 0 | - | 3.5KB | 0 0B | 0 0B | 3 2.2KB | 3.5KB | 1 0.6
total | 7 5.0KB 41B 0 | - | 2.3KB | 3 2.1KB | 0 0B | 9 8.7KB | 3.5KB | 3 3.8
-------------------------------------------------------------------------------------------------------------------
WAL: 1 files (26B) in: 176B written: 175B (-1% overhead)
WAL: 1 files (0B) in: 176B written: 187B (6% overhead)
Flushes: 8
Compactions: 2 estimated debt: 5.0KB in progress: 0 (0B)
default: 2 delete: 0 elision: 0 move: 0 read: 0 rewrite: 0 multi-level: 0
Expand Down
Loading