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 cockroachdb#3505.

db.go

@@ -2569,6 +2569,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