Skip to content

Commit 0a097e2

Browse files
committed
backend: address PR review comments and add defrag tests
Address review feedback from Thomas, Filip, and Ben: - Rename defragSetupSnapshot to defragPrepare; 'snapshot' is overloaded in etcd (raft snapshots) - Drop FillPercent=0.9 from replayJournal; no meaningful effect on the small number of journal replay ops in a freshly compacted db - Error on missing bucket in replayJournal delete path, consistent with put path - Panic on append-after-close instead of silently dropping ops; this path is unreachable in normal operation - Combine close() and drain() into closeAndDrain() to eliminate the two-step state machine - Use atomic.Pointer[defragJournal] to fix data race between LockInsideApply (reads before mutex) and defrag lifecycle (writes under mutex); use Swap(nil) for atomic load-and-clear - Load defragJournal from batchTx in cancel/replay instead of passing as parameter; defer defragCancelJournal for cleanup - Drop bytes.Clone from journal appends; callers provide Go heap slices same as txWriteBuffer which doesn't clone - Strip copyright headers from new files - Consistent os.Remove error handling across all defrag error paths - Add defragBeforeReplay gofail failpoint between copy and replay - Add defragCopyFailHook for test injection of copy failures Tests: - E2E: TestNonBlockingDefragNoSpace and TestNonBlockingDefragSuccess - Unit: TestBackendDefragConcurrentLockInsideApply (race detector), TestBackendDefragCopyFailurePreservesData (no data loss on copy failure), TestDefragJournalAppendAfterClosePanics
1 parent 828d711 commit 0a097e2

9 files changed

Lines changed: 364 additions & 132 deletions

File tree

server/storage/backend/backend.go

Lines changed: 49 additions & 30 deletions
Original file line numberDiff line numberDiff line change
@@ -135,6 +135,10 @@ type backend struct {
135135
// 0 means unlimited (no backpressure).
136136
defragJournalMaxOps int
137137

138+
// defragCopyFailHook, if non-nil, is called instead of defragFromTx
139+
// during the copy phase. Used by tests to simulate copy failures.
140+
defragCopyFailHook func() error
141+
138142
lg *zap.Logger
139143
}
140144

@@ -570,6 +574,10 @@ func (b *backend) defragBlocking() error {
570574

571575
dbp, size1, sizeInUse1 := b.defragLogStart()
572576

577+
// NOTE: We should exit as soon as possible because that tx
578+
// might be closed. The inflight request might use invalid
579+
// tx and then panic as well. The real panic reason might be
580+
// shadowed by new panic. So, we should fatal here with lock.
573581
defer func() {
574582
if rerr := recover(); rerr != nil {
575583
b.lg.Fatal("unexpected panic during defrag", zap.Any("panic", rerr))
@@ -586,7 +594,9 @@ func (b *backend) defragBlocking() error {
586594
b.batchTx.tx = b.unsafeBegin(true)
587595
b.readTx.tx = b.unsafeBegin(false)
588596
tmpdb.Close()
589-
os.RemoveAll(tdbp)
597+
if rmErr := os.RemoveAll(tdbp); rmErr != nil {
598+
b.lg.Error("failed to remove tmp database", zap.String("path", tdbp), zap.Error(rmErr))
599+
}
590600
return err
591601
}
592602

@@ -596,7 +606,7 @@ func (b *backend) defragBlocking() error {
596606
if err != nil {
597607
tmpdb.Close()
598608
if rmErr := os.RemoveAll(tdbp); rmErr != nil {
599-
b.lg.Error("failed to remove db.tmp after defragmentation completed", zap.Error(rmErr))
609+
b.lg.Error("failed to remove tmp database", zap.String("path", tdbp), zap.Error(rmErr))
600610
}
601611
b.batchTx.tx = b.unsafeBegin(true)
602612
b.readTx.tx = b.unsafeBegin(false)
@@ -650,28 +660,37 @@ func (b *backend) defragNonBlocking() error {
650660

651661
dbp, size1, sizeInUse1 := b.defragLogStart()
652662

653-
journal, snapTx, err := b.defragSetupSnapshot()
663+
readTx, err := b.defragPrepare()
654664
if err != nil {
655665
tmpdb.Close()
656-
os.Remove(tdbp)
666+
if rmErr := os.Remove(tdbp); rmErr != nil {
667+
b.lg.Error("failed to remove tmp database", zap.String("path", tdbp), zap.Error(rmErr))
668+
}
657669
return err
658670
}
671+
defer b.defragCancelJournal()
659672

660673
b.lg.Info("defrag: copying data (writes unlocked)")
661674

662675
// gofail: var defragBeforeCopy struct{}
663-
err = defragFromTx(snapTx, tmpdb, defragLimit)
664-
snapTx.Rollback()
676+
if b.defragCopyFailHook != nil {
677+
err = b.defragCopyFailHook()
678+
} else {
679+
err = defragFromTx(readTx, tmpdb, defragLimit)
680+
}
681+
readTx.Rollback()
665682

666683
if err != nil {
667-
b.defragCancelJournal(journal)
668684
tmpdb.Close()
669-
os.RemoveAll(tdbp)
685+
if rmErr := os.RemoveAll(tdbp); rmErr != nil {
686+
b.lg.Error("failed to remove tmp database", zap.String("path", tdbp), zap.Error(rmErr))
687+
}
670688
return err
671689
}
672690

691+
// gofail: var defragBeforeReplay struct{}
673692
b.lg.Info("defrag: replaying journal")
674-
err = b.defragReplayAndSwap(journal, tmpdb, dbp, tdbp)
693+
err = b.defragReplayAndSwap(tmpdb, dbp, tdbp)
675694
if err != nil {
676695
return err
677696
}
@@ -682,54 +701,57 @@ func (b *backend) defragNonBlocking() error {
682701
return nil
683702
}
684703

685-
// defragSetupSnapshot commits pending writes, takes a read-only
686-
// snapshot, and installs a journal to capture writes during the copy.
687-
func (b *backend) defragSetupSnapshot() (*defragJournal, *bolt.Tx, error) {
704+
// defragPrepare commits pending writes, opens a read-only bbolt
705+
// transaction for the copy phase, and installs a journal to capture
706+
// writes that occur during the copy.
707+
func (b *backend) defragPrepare() (*bolt.Tx, error) {
688708
b.batchTx.LockOutsideApply()
689709
defer b.batchTx.Unlock()
690710

691711
b.batchTx.commit(false)
692712

693713
b.mu.RLock()
694-
snapTx, err := b.db.Begin(false)
714+
readTx, err := b.db.Begin(false)
695715
b.mu.RUnlock()
696716
if err != nil {
697-
return nil, nil, fmt.Errorf("failed to begin snapshot tx for defrag: %w", err)
717+
return nil, fmt.Errorf("failed to begin read tx for defrag: %w", err)
698718
}
699719

700-
journal := newDefragJournal(b.defragJournalMaxOps)
701-
b.batchTx.defragJournal = journal
702-
return journal, snapTx, nil
720+
b.batchTx.defragJournal.Store(newDefragJournal(b.defragJournalMaxOps))
721+
return readTx, nil
703722
}
704723

705724
// defragCancelJournal removes the journal from the batch transaction
706-
// and closes it. Called when the copy phase fails.
707-
func (b *backend) defragCancelJournal(journal *defragJournal) {
725+
// and closes it. Safe to call even if the journal was already
726+
// drained or never installed.
727+
func (b *backend) defragCancelJournal() {
708728
b.batchTx.LockOutsideApply()
709729
defer b.batchTx.Unlock()
710-
b.batchTx.defragJournal = nil
711-
journal.close()
730+
if journal := b.batchTx.defragJournal.Swap(nil); journal != nil {
731+
journal.closeAndDrain()
732+
}
712733
}
713734

714735
// defragReplayAndSwap drains the journal, replays it into the temp
715736
// database, then atomically swaps the old database for the new one.
716737
// batchTx is held for the entire operation to prevent writes between
717738
// journal drain and database swap.
718-
func (b *backend) defragReplayAndSwap(journal *defragJournal, tmpdb *bolt.DB, dbp, tdbp string) error {
739+
func (b *backend) defragReplayAndSwap(tmpdb *bolt.DB, dbp, tdbp string) error {
719740
b.batchTx.LockOutsideApply()
720741
defer b.batchTx.Unlock()
721742

722-
b.batchTx.defragJournal = nil
723-
journal.close()
724-
ops := journal.drain()
743+
journal := b.batchTx.defragJournal.Swap(nil)
744+
ops := journal.closeAndDrain()
725745

726746
if len(ops) > 0 {
727747
b.lg.Info("defrag: replaying journal ops", zap.Int("count", len(ops)))
728748
}
729749

730750
if err := replayJournal(tmpdb, ops, defragLimit); err != nil {
731751
tmpdb.Close()
732-
os.RemoveAll(tdbp)
752+
if rmErr := os.RemoveAll(tdbp); rmErr != nil {
753+
b.lg.Error("failed to remove tmp database", zap.String("path", tdbp), zap.Error(rmErr))
754+
}
733755
return err
734756
}
735757

@@ -878,16 +900,13 @@ func replayJournal(tmpdb *bolt.DB, ops []defragJournalOp, limit int) error {
878900
if b == nil {
879901
return fmt.Errorf("replay: bucket %s not found for put", op.bucketName)
880902
}
881-
if op.seq {
882-
b.FillPercent = 0.9
883-
}
884903
if err = b.Put(op.key, op.value); err != nil {
885904
return fmt.Errorf("replay: put in bucket %s: %w", op.bucketName, err)
886905
}
887906
case opDelete:
888907
b := tx.Bucket(op.bucketName)
889908
if b == nil {
890-
continue
909+
return fmt.Errorf("replay: bucket %s not found for delete", op.bucketName)
891910
}
892911
if err = b.Delete(op.key); err != nil {
893912
return fmt.Errorf("replay: delete from bucket %s: %w", op.bucketName, err)

server/storage/backend/backend_test.go

Lines changed: 140 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1554,3 +1554,143 @@ func TestBackendDefragBackpressure(t *testing.T) {
15541554
}
15551555
rtx.Unlock()
15561556
}
1557+
1558+
// TestBackendDefragConcurrentLockInsideApply exercises the data race
1559+
// between LockInsideApply reading t.defragJournal without the mutex
1560+
// and defrag setting/clearing it under the mutex. Run with -race to
1561+
// verify there is no unsynchronized pointer access.
1562+
func TestBackendDefragConcurrentLockInsideApply(t *testing.T) {
1563+
b, _ := betesting.NewDefaultTmpBackend(t)
1564+
defer betesting.Close(t, b)
1565+
backend.SetNonBlockingDefragForTest(b, true)
1566+
1567+
tx := b.BatchTx()
1568+
tx.Lock()
1569+
tx.UnsafeCreateBucket(schema.Test)
1570+
for i := 0; i < 1000; i++ {
1571+
tx.UnsafePut(schema.Test, []byte(fmt.Sprintf("key_%04d", i)), make([]byte, 256))
1572+
}
1573+
tx.Unlock()
1574+
b.ForceCommit()
1575+
1576+
// Concurrent goroutines calling LockInsideApply while defrag
1577+
// sets and clears the defragJournal pointer.
1578+
var wg sync.WaitGroup
1579+
stop := make(chan struct{})
1580+
1581+
for g := 0; g < 4; g++ {
1582+
wg.Add(1)
1583+
go func(id int) {
1584+
defer wg.Done()
1585+
for i := 0; ; i++ {
1586+
select {
1587+
case <-stop:
1588+
return
1589+
default:
1590+
}
1591+
tx := b.BatchTx()
1592+
tx.LockInsideApply()
1593+
tx.UnsafePut(schema.Test, []byte(fmt.Sprintf("w%d_%06d", id, i)), []byte("v"))
1594+
tx.Unlock()
1595+
}
1596+
}(g)
1597+
}
1598+
1599+
err := b.Defrag()
1600+
close(stop)
1601+
wg.Wait()
1602+
require.NoError(t, err)
1603+
}
1604+
1605+
// TestBackendDefragCopyFailurePreservesData proves that when the copy
1606+
// phase fails during non-blocking defrag, no data is lost. Writes
1607+
// during the copy phase go to both the live database and the journal;
1608+
// discarding the journal on failure is safe because the live database
1609+
// already has every write.
1610+
func TestBackendDefragCopyFailurePreservesData(t *testing.T) {
1611+
b, _ := betesting.NewDefaultTmpBackend(t)
1612+
defer betesting.Close(t, b)
1613+
backend.SetNonBlockingDefragForTest(b, true)
1614+
1615+
tx := b.BatchTx()
1616+
tx.Lock()
1617+
tx.UnsafeCreateBucket(schema.Test)
1618+
for i := 0; i < 100; i++ {
1619+
tx.UnsafePut(schema.Test, []byte(fmt.Sprintf("pre_%04d", i)), []byte("value"))
1620+
}
1621+
tx.Unlock()
1622+
b.ForceCommit()
1623+
1624+
// Inject a copy failure. Writes will still flow into the live
1625+
// database and the journal during the (simulated) copy phase.
1626+
var wg sync.WaitGroup
1627+
stop := make(chan struct{})
1628+
var written atomic.Int32
1629+
1630+
backend.SetDefragCopyFailHookForTest(b, func() error {
1631+
// Give the concurrent writer time to produce writes while
1632+
// the journal is active.
1633+
time.Sleep(50 * time.Millisecond)
1634+
return fmt.Errorf("simulated copy failure")
1635+
})
1636+
1637+
wg.Add(1)
1638+
go func() {
1639+
defer wg.Done()
1640+
for i := 0; ; i++ {
1641+
select {
1642+
case <-stop:
1643+
return
1644+
default:
1645+
}
1646+
wtx := b.BatchTx()
1647+
wtx.Lock()
1648+
wtx.UnsafePut(schema.Test, []byte(fmt.Sprintf("during_%06d", i)), []byte("val"))
1649+
wtx.Unlock()
1650+
written.Add(1)
1651+
}
1652+
}()
1653+
1654+
err := b.Defrag()
1655+
close(stop)
1656+
wg.Wait()
1657+
1658+
// Defrag should have failed.
1659+
require.Error(t, err)
1660+
require.Contains(t, err.Error(), "simulated copy failure")
1661+
1662+
totalWritten := int(written.Load())
1663+
require.Greater(t, totalWritten, 0,
1664+
"at least some writes must have occurred during the failed defrag")
1665+
t.Logf("wrote %d ops during failed defrag copy", totalWritten)
1666+
1667+
// All pre-existing data must survive.
1668+
b.ForceCommit()
1669+
rtx := b.BatchTx()
1670+
rtx.Lock()
1671+
for i := 0; i < 100; i++ {
1672+
keys, _ := rtx.UnsafeRange(schema.Test, []byte(fmt.Sprintf("pre_%04d", i)), nil, 0)
1673+
require.Lenf(t, keys, 1, "pre_%04d must survive failed defrag", i)
1674+
}
1675+
// All writes during the failed copy must also survive — they went
1676+
// to the live database, not just the journal.
1677+
for i := 0; i < totalWritten; i++ {
1678+
keys, _ := rtx.UnsafeRange(schema.Test, []byte(fmt.Sprintf("during_%06d", i)), nil, 0)
1679+
require.Lenf(t, keys, 1, "during_%06d must survive failed defrag", i)
1680+
}
1681+
rtx.Unlock()
1682+
1683+
// The server should remain fully functional after the failed defrag.
1684+
tx = b.BatchTx()
1685+
tx.Lock()
1686+
tx.UnsafePut(schema.Test, []byte("after_failure"), []byte("ok"))
1687+
tx.Unlock()
1688+
b.ForceCommit()
1689+
1690+
rtx = b.BatchTx()
1691+
rtx.Lock()
1692+
keys, vals := rtx.UnsafeRange(schema.Test, []byte("after_failure"), nil, 0)
1693+
rtx.Unlock()
1694+
require.Len(t, keys, 1)
1695+
require.Equal(t, []byte("ok"), vals[0])
1696+
}

server/storage/backend/batch_tx.go

Lines changed: 11 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -291,7 +291,11 @@ type batchTxBuffered struct {
291291
batchTx
292292
buf txWriteBuffer
293293
pendingDeleteOperations int
294-
defragJournal *defragJournal
294+
// defragJournal captures write operations during the non-blocking
295+
// defrag copy phase. Accessed atomically because LockInsideApply
296+
// reads it before acquiring the batchTx mutex (for backpressure),
297+
// while defragPrepare/defragReplayAndSwap set it under the mutex.
298+
defragJournal atomic.Pointer[defragJournal]
295299
}
296300

297301
func newBatchTxBuffered(backend *backend) *batchTxBuffered {
@@ -307,7 +311,7 @@ func newBatchTxBuffered(backend *backend) *batchTxBuffered {
307311
}
308312

309313
func (t *batchTxBuffered) LockInsideApply() {
310-
if j := t.defragJournal; j != nil {
314+
if j := t.defragJournal.Load(); j != nil {
311315
j.waitForSpace()
312316
}
313317
t.batchTx.LockInsideApply()
@@ -394,38 +398,38 @@ func (t *batchTxBuffered) unsafeCommit(stop bool) {
394398
}
395399

396400
func (t *batchTxBuffered) UnsafeCreateBucket(bucket Bucket) {
397-
if j := t.defragJournal; j != nil {
401+
if j := t.defragJournal.Load(); j != nil {
398402
j.appendCreateBucket(bucket.Name())
399403
}
400404
t.batchTx.UnsafeCreateBucket(bucket)
401405
}
402406

403407
func (t *batchTxBuffered) UnsafePut(bucket Bucket, key []byte, value []byte) {
404-
if j := t.defragJournal; j != nil {
408+
if j := t.defragJournal.Load(); j != nil {
405409
j.appendPut(bucket.Name(), key, value, false)
406410
}
407411
t.batchTx.UnsafePut(bucket, key, value)
408412
t.buf.put(bucket, key, value)
409413
}
410414

411415
func (t *batchTxBuffered) UnsafeSeqPut(bucket Bucket, key []byte, value []byte) {
412-
if j := t.defragJournal; j != nil {
416+
if j := t.defragJournal.Load(); j != nil {
413417
j.appendPut(bucket.Name(), key, value, true)
414418
}
415419
t.batchTx.UnsafeSeqPut(bucket, key, value)
416420
t.buf.putSeq(bucket, key, value)
417421
}
418422

419423
func (t *batchTxBuffered) UnsafeDelete(bucketType Bucket, key []byte) {
420-
if j := t.defragJournal; j != nil {
424+
if j := t.defragJournal.Load(); j != nil {
421425
j.appendDelete(bucketType.Name(), key)
422426
}
423427
t.batchTx.UnsafeDelete(bucketType, key)
424428
t.pendingDeleteOperations++
425429
}
426430

427431
func (t *batchTxBuffered) UnsafeDeleteBucket(bucket Bucket) {
428-
if j := t.defragJournal; j != nil {
432+
if j := t.defragJournal.Load(); j != nil {
429433
j.appendDeleteBucket(bucket.Name())
430434
}
431435
t.batchTx.UnsafeDeleteBucket(bucket)

0 commit comments

Comments
 (0)