Add debug log for 2.0.1 (#20729)

matrixorigin · Dec 11, 2024 · 44b3761 · 44b3761
1 parent 25b06b2
commit 44b3761
Show file tree

Hide file tree

Showing 3 changed files with 25 additions and 1 deletion.
diff --git a/pkg/vm/engine/tae/txn/txnimpl/store.go b/pkg/vm/engine/tae/txn/txnimpl/store.go
@@ -746,7 +746,9 @@ func (store *txnStore) PrePrepare(ctx context.Context) (err error) {
 	}
 	approxSize := store.approxSize()
 	if approxSize > MaxWalSize {
-		return moerr.NewInternalError(ctx, fmt.Sprintf("WAL entry approxSize %d is too large, max is %d", approxSize, MaxWalSize))
+		return moerr.NewInternalError(
+			ctx, fmt.Sprintf("Txn %x WAL entry approxSize %d is too large, max is %d", store.txn.GetID(), approxSize, MaxWalSize),
+		)
 	}
 	if approxSize > 50*mpool.MB {
 		logutil.Warnf("[Large-WAL-Entry]txn %x, WAL entry approxSize %d", store.txn.GetID(), approxSize)

diff --git a/pkg/vm/engine/tae/txn/txnimpl/table.go b/pkg/vm/engine/tae/txn/txnimpl/table.go
@@ -1157,6 +1157,19 @@ func (tbl *txnTable) DoPrecommitDedupByPK(
 	pksZM index.ZM,
 	isTombstone bool,
 ) (err error) {
+	start := time.Now()
+	defer func() {
+		duration := time.Since(start)
+		if duration > time.Second {
+			logutil.Info(
+				"SLOW-LOG-DoPrecommitDedupByPK",
+				zap.String("txn", tbl.store.txn.String()),
+				zap.String("table", tbl.GetLocalSchema(isTombstone).Name),
+				zap.Bool("is-tombstone", isTombstone),
+				zap.Duration("duration", time.Since(start)),
+			)
+		}
+	}()
 	moprobe.WithRegion(context.Background(), moprobe.TxnTableDoPrecommitDedupByPK, func() {
 		var rowIDs containers.Vector
 		rowIDs, err = tbl.getBaseTable(isTombstone).preCommitGetRowsByPK(tbl.store.ctx, pks)

diff --git a/pkg/vm/engine/tae/txn/txnimpl/txndb.go b/pkg/vm/engine/tae/txn/txnimpl/txndb.go
@@ -29,6 +29,7 @@ import (
 	"github.com/matrixorigin/matrixone/pkg/vm/engine/tae/containers"
 	"github.com/matrixorigin/matrixone/pkg/vm/engine/tae/iface/handle"
 	"github.com/matrixorigin/matrixone/pkg/vm/engine/tae/iface/txnif"
+	"go.uber.org/zap"
 )
 
 type txnDB struct {
@@ -483,6 +484,14 @@ func (db *txnDB) PrePrepare(ctx context.Context) (err error) {
 		}
 	}
 	v2.TxnTNPrePrepareDeduplicateDurationHistogram.Observe(time.Since(now).Seconds())
+	if time.Since(now) > time.Second {
+		logutil.Info(
+			"SLOW-LOG-PrePrepareDedup",
+			zap.String("txn", db.store.txn.String()),
+			zap.String("db", db.entry.GetName()),
+			zap.Duration("duration", time.Since(now)),
+		)
+	}
 
 	for _, table := range db.tables {
 		if err = table.PrePrepare(); err != nil {