db: ensure Metrics.WAL.BytesWritten is nondecreasing

The Metrics.WAL.BytesWritten metric is intended to be a monotonically
increasing counter of all bytes written to the write-ahead log. Previously, it
was possible for this metric to violate monotonicity immediately after a WAL
rotation. The d.logSize value—which corresponds to the size of the current
WAL—was not reset to zero. It was only reset after the first write to the new
WAL.

Close #3505.

db.go

@@ -2568,6 +2568,16 @@ func (d *DB) rotateMemtable(newLogNum base.DiskFileNum, logSeqNum uint64, prev *
 	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()

metrics_test.go

@@ -7,10 +7,13 @@ package pebble
 import (
 	"bytes"
 	"fmt"
+	"math/rand"
 	"runtime"
 	"strconv"
 	"strings"
+	"sync"
 	"testing"
+	"time"
 
 	"github.com/cockroachdb/datadriven"
 	"github.com/cockroachdb/pebble/internal/cache"
@@ -19,6 +22,7 @@ import (
 	"github.com/cockroachdb/pebble/objstorage/remote"
 	"github.com/cockroachdb/pebble/sstable"
 	"github.com/cockroachdb/pebble/vfs"
+	"github.com/cockroachdb/pebble/vfs/errorfs"
 	"github.com/cockroachdb/redact"
 	"github.com/stretchr/testify/require"
 )
@@ -421,3 +425,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 := errorfs.Wrap(vfs.NewMem(), errorfs.RandomLatency(nil, 100*time.Microsecond, time.Now().UnixNano()))
+	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()
+}

testdata/event_listener

@@ -217,9 +217,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   590B     0B       0 |     - | 1.2KB |     0     0B |     0     0B |     1   590B | 1.2KB |   1  0.5
-total |     3  1.7KB     0B       0 |     - |  698B |     1   590B |     0     0B |     4  3.0KB | 1.2KB |   3  4.4
+total |     3  1.7KB     0B       0 |     - |  671B |     1   590B |     0     0B |     4  3.0KB | 1.2KB |   3  4.5
 -------------------------------------------------------------------------------------------------------------------
-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: 1.7KB  in progress: 0 (0B)
              default: 1  delete: 0  elision: 0  move: 0  read: 0  rewrite: 0  multi-level: 0
@@ -317,9 +317,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 |     2  1.2KB     0B       0 |     - | 1.2KB |     1   590B |     0     0B |     1   590B | 1.2KB |   1  0.5
-total |     6  3.5KB     0B       0 |     - | 1.9KB |     3  1.7KB |     0     0B |     5  4.7KB | 1.2KB |   5  2.5
+total |     6  3.5KB     0B       0 |     - | 1.8KB |     3  1.7KB |     0     0B |     5  4.7KB | 1.2KB |   5  2.6
 -------------------------------------------------------------------------------------------------------------------
-WAL: 1 files (29B)  in: 82B  written: 137B (67% overhead)
+WAL: 1 files (0B)  in: 82B  written: 108B (32% overhead)
 Flushes: 6
 Compactions: 1  estimated debt: 3.5KB  in progress: 0 (0B)
              default: 1  delete: 0  elision: 0  move: 0  read: 0  rewrite: 0  multi-level: 0