Skip to content

Commit 42a7c45

Browse files
fix range checkpoint (#18799)
1. fix range checkpoint 2. add log Approved by: @XuPeng-SH, @sukki37
1 parent 2da268f commit 42a7c45

File tree

3 files changed

+55
-13
lines changed

3 files changed

+55
-13
lines changed

pkg/vm/engine/tae/logstore/driver/logservicedriver/info.go

Lines changed: 10 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -31,15 +31,14 @@ var ErrDriverLsnNotFound = moerr.NewInternalErrorNoCtx("driver info: driver lsn
3131
var ErrRetryTimeOut = moerr.NewInternalErrorNoCtx("driver info: retry time out")
3232

3333
type driverInfo struct {
34-
addr map[uint64]*common.ClosedIntervals //logservicelsn-driverlsn TODO drop on truncate
35-
validLsn *roaring64.Bitmap
36-
addrMu sync.RWMutex
37-
driverLsn uint64 //
38-
syncing uint64
39-
synced uint64
40-
syncedMu sync.RWMutex
41-
driverLsnMu sync.RWMutex
42-
34+
addr map[uint64]*common.ClosedIntervals //logservicelsn-driverlsn TODO drop on truncate
35+
validLsn *roaring64.Bitmap
36+
addrMu sync.RWMutex
37+
driverLsn uint64 //
38+
syncing uint64
39+
synced uint64
40+
syncedMu sync.RWMutex
41+
driverLsnMu sync.RWMutex
4342
truncating atomic.Uint64 //
4443
truncatedLogserviceLsn uint64 //
4544

@@ -96,7 +95,7 @@ func (info *driverInfo) onReplayRecordEntry(lsn uint64, driverLsns *common.Close
9695
func (info *driverInfo) getNextValidLogserviceLsn(lsn uint64) uint64 {
9796
info.addrMu.Lock()
9897
defer info.addrMu.Unlock()
99-
if info.validLsn.GetCardinality() == 0 {
98+
if info.validLsn.IsEmpty() {
10099
return 0
101100
}
102101
max := info.validLsn.Maximum()
@@ -209,6 +208,7 @@ func (info *driverInfo) gcAddr(logserviceLsn uint64) {
209208
lsnToDelete = append(lsnToDelete, serviceLsn)
210209
}
211210
}
211+
info.validLsn.RemoveRange(0, logserviceLsn)
212212
for _, lsn := range lsnToDelete {
213213
delete(info.addr, lsn)
214214
}

pkg/vm/engine/tae/logstore/driver/logservicedriver/truncate.go

Lines changed: 24 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -16,14 +16,17 @@ package logservicedriver
1616

1717
import (
1818
"context"
19+
"time"
1920

2021
"github.com/matrixorigin/matrixone/pkg/common/moerr"
2122
"github.com/matrixorigin/matrixone/pkg/logutil"
23+
"go.uber.org/zap"
2224
// "time"
2325
)
2426

2527
// driver lsn -> entry lsn
2628
func (d *LogServiceDriver) Truncate(lsn uint64) error {
29+
logutil.Info("TRACE-WAL-TRUNCATE", zap.Uint64(" driver start truncate", lsn))
2730
if lsn > d.truncating.Load() {
2831
d.truncating.Store(lsn)
2932
}
@@ -44,19 +47,33 @@ func (d *LogServiceDriver) onTruncate(items ...any) {
4447
}
4548

4649
func (d *LogServiceDriver) doTruncate() {
50+
t0 := time.Now()
4751
target := d.truncating.Load()
4852
lastServiceLsn := d.truncatedLogserviceLsn
4953
lsn := lastServiceLsn
5054
//TODO use valid lsn
5155
next := d.getNextValidLogserviceLsn(lsn)
56+
loopCount := 0
5257
for d.isToTruncate(next, target) {
58+
loopCount++
5359
lsn = next
5460
next = d.getNextValidLogserviceLsn(lsn)
5561
if next <= lsn {
5662
break
5763
}
5864
}
65+
d.addrMu.RLock()
66+
min := d.validLsn.Minimum()
67+
max := d.validLsn.Maximum()
68+
d.addrMu.RUnlock()
69+
logutil.Info("TRACE-WAL-TRUNCATE-Get LogService lsn",
70+
zap.Int("loop count", loopCount),
71+
zap.Uint64("driver lsn", target),
72+
zap.Uint64("min", min),
73+
zap.Uint64("max", max),
74+
zap.String("duration", time.Since(t0).String()))
5975
if lsn == lastServiceLsn {
76+
logutil.Info("LogService Driver: retrun because logservice is small")
6077
return
6178
}
6279
d.truncateLogservice(lsn)
@@ -65,7 +82,8 @@ func (d *LogServiceDriver) doTruncate() {
6582
}
6683

6784
func (d *LogServiceDriver) truncateLogservice(lsn uint64) {
68-
logutil.Infof("LogService Driver: Start Truncate %d", lsn)
85+
logutil.Info("TRACE-WAL-TRUNCATE-Start Truncate", zap.Uint64("lsn", lsn))
86+
t0 := time.Now()
6987
client, err := d.clientPool.Get()
7088
if err == ErrClientPoolClosed {
7189
return
@@ -101,7 +119,10 @@ func (d *LogServiceDriver) truncateLogservice(lsn uint64) {
101119
panic(err)
102120
}
103121
}
104-
logutil.Infof("LogService Driver: Truncate %d successfully", lsn)
122+
logutil.Info("TRACE-WAL-TRUNCATE-Truncate successfully",
123+
zap.Uint64("lsn", lsn),
124+
zap.String("duration",
125+
time.Since(t0).String()))
105126
}
106127
func (d *LogServiceDriver) getLogserviceTruncate() (lsn uint64) {
107128
client, err := d.clientPool.Get()
@@ -127,6 +148,6 @@ func (d *LogServiceDriver) getLogserviceTruncate() (lsn uint64) {
127148
panic(err)
128149
}
129150
}
130-
logutil.Infof("Logservice Driver: Get Truncate %d", lsn)
151+
logutil.Infof("TRACE-WAL-TRUNCATE-Get Truncate %d", lsn)
131152
return
132153
}

pkg/vm/engine/tae/logstore/store/checkpoint.go

Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -15,13 +15,18 @@
1515
package store
1616

1717
import (
18+
"time"
19+
20+
"github.com/matrixorigin/matrixone/pkg/logutil"
1821
"github.com/matrixorigin/matrixone/pkg/vm/engine/tae/common"
1922
driverEntry "github.com/matrixorigin/matrixone/pkg/vm/engine/tae/logstore/driver/entry"
2023
"github.com/matrixorigin/matrixone/pkg/vm/engine/tae/logstore/entry"
2124
"github.com/matrixorigin/matrixone/pkg/vm/engine/tae/logstore/sm"
25+
"go.uber.org/zap"
2226
)
2327

2428
func (w *StoreImpl) RangeCheckpoint(gid uint32, start, end uint64) (ckpEntry entry.Entry, err error) {
29+
logutil.Info("TRACE-WAL-TRUNCATE-RangeCheckpoint", zap.Uint32("group", gid), zap.Uint64("lsn", end))
2530
ckpEntry = w.makeRangeCheckpointEntry(gid, start, end)
2631
drentry, _, err := w.doAppend(GroupCKP, ckpEntry)
2732
if err == sm.ErrClose {
@@ -58,6 +63,9 @@ func (w *StoreImpl) onLogCKPInfoQueue(items ...any) {
5863
if err != nil {
5964
panic(err)
6065
}
66+
logutil.Info("TRACE-WAL-TRUNCATE-CKP-Entry",
67+
zap.Uint32("group", e.Info.Checkpoints[0].Group),
68+
zap.Uint64("lsn", e.Info.Checkpoints[0].Ranges.GetMax()))
6169
w.logCheckpointInfo(e.Info)
6270
}
6371
w.onCheckpoint()
@@ -69,6 +77,7 @@ func (w *StoreImpl) onCheckpoint() {
6977
}
7078

7179
func (w *StoreImpl) ckpCkp() {
80+
t0 := time.Now()
7281
e := w.makeInternalCheckpointEntry()
7382
driverEntry, _, err := w.doAppend(GroupInternal, e)
7483
if err == sm.ErrClose {
@@ -77,6 +86,8 @@ func (w *StoreImpl) ckpCkp() {
7786
if err != nil {
7887
panic(err)
7988
}
89+
logutil.Info("TRACE-WAL-TRUNCATE-Internal-Entry",
90+
zap.String("duration", time.Since(t0).String()))
8091
w.truncatingQueue.Enqueue(driverEntry)
8192
err = e.WaitDone()
8293
if err != nil {
@@ -86,6 +97,7 @@ func (w *StoreImpl) ckpCkp() {
8697
}
8798

8899
func (w *StoreImpl) onTruncatingQueue(items ...any) {
100+
t0 := time.Now()
89101
for _, item := range items {
90102
e := item.(*driverEntry.Entry)
91103
err := e.WaitDone()
@@ -94,7 +106,14 @@ func (w *StoreImpl) onTruncatingQueue(items ...any) {
94106
}
95107
w.logCheckpointInfo(e.Info)
96108
}
109+
tTruncateEntry := time.Since(t0)
110+
t0 = time.Now()
97111
gid, driverLsn := w.getDriverCheckpointed()
112+
tGetDriverEntry := time.Since(t0)
113+
logutil.Info("TRACE-WAL-TRUNCATE",
114+
zap.String("wait truncating entry takes", tTruncateEntry.String()),
115+
zap.String("get driver lsn takes", tGetDriverEntry.String()),
116+
zap.Uint64("driver lsn", driverLsn))
98117
if gid == 0 {
99118
return
100119
}
@@ -113,7 +132,9 @@ func (w *StoreImpl) onTruncateQueue(items ...any) {
113132
lsn = w.driverCheckpointing.Load()
114133
err = w.driver.Truncate(lsn)
115134
}
135+
t := time.Now()
116136
w.gcWalDriverLsnMap(lsn)
137+
logutil.Info("TRACE-WAL-TRUNCATE-GC-Store", zap.String("duration", time.Since(t).String()))
117138
w.driverCheckpointed = lsn
118139
}
119140
}

0 commit comments

Comments
 (0)