more logs

pingcap · Feb 21, 2025 · aee14c5 · aee14c5
1 parent 51537dd
commit aee14c5
Show file tree

Hide file tree

Showing 6 changed files with 77 additions and 8 deletions.
diff --git a/pkg/ddl/backfilling_dist_executor.go b/pkg/ddl/backfilling_dist_executor.go
@@ -71,6 +71,8 @@ type BackfillSubTaskMeta struct {
 	external.SortedKVMeta `json:",inline"`
 }
 
+var DecodeBackfillSubTaskMeta4Test = decodeBackfillSubTaskMeta
+
 func decodeBackfillSubTaskMeta(raw []byte) (*BackfillSubTaskMeta, error) {
 	var subtask BackfillSubTaskMeta
 	err := json.Unmarshal(raw, &subtask)

diff --git a/pkg/ddl/backfilling_dist_scheduler.go b/pkg/ddl/backfilling_dist_scheduler.go
@@ -386,7 +386,17 @@ func generateGlobalSortIngestPlan(
 				if kvMetaGroups[i] == nil {
 					kvMetaGroups[i] = &external.SortedKVMeta{}
 				}
+				logger.Warn("[date0218] generateGlobalSortIngestPlan before merged", zap.Int("i", i),
+					brlogutil.Key("startKey", kvMetaGroups[i].StartKey),
+					brlogutil.Key("endKey", kvMetaGroups[i].EndKey),
+					brlogutil.Key("cur.startKey", cur.StartKey),
+					brlogutil.Key("cur.endKey", cur.EndKey),
+				)
 				kvMetaGroups[i].Merge(cur)
+				// [date0218] All of these endKey can NOT be decoded
+				logger.Warn("[date0218] generateGlobalSortIngestPlan after merged",
+					brlogutil.Key("startKey", kvMetaGroups[i].StartKey),
+					brlogutil.Key("endKey", kvMetaGroups[i].EndKey))
 			}
 		})
 		if err != nil {
@@ -470,15 +480,18 @@ func splitSubtaskMetaForOneKVMetaGroup(
 
 	startKey := kvMeta.StartKey
 	var endKey kv.Key
+	logger.Warn("[date0218] splitSubtaskMetaForOneKVMetaGroup", brlogutil.Key("startKey", kvMeta.StartKey), brlogutil.Key("endKey", kvMeta.EndKey))
 	for {
 		endKeyOfGroup, dataFiles, statFiles, interiorRangeJobKeys, interiorRegionSplitKeys, err := splitter.SplitOneRangesGroup()
 		if err != nil {
 			return nil, err
 		}
 		if len(endKeyOfGroup) == 0 {
 			endKey = kvMeta.EndKey
+			logger.Warn("[date0218] splitSubtaskMetaForOneKVMetaGroup get endKey with kvMeta.EndKey")
 		} else {
 			endKey = kv.Key(endKeyOfGroup).Clone()
+			logger.Warn("[date0218] splitSubtaskMetaForOneKVMetaGroup get endKey without kvMeta.EndKey", brlogutil.Key("endKey", endKey))
 		}
 		logger.Info("split subtask range",
 			zap.String("startKey", hex.EncodeToString(startKey)),
@@ -497,7 +510,7 @@ func splitSubtaskMetaForOneKVMetaGroup(
 		regionSplitKeys = append(regionSplitKeys, interiorRegionSplitKeys...)
 		regionSplitKeys = append(regionSplitKeys, endKey)
 		for i, k := range regionSplitKeys {
-			logger.Warn("[date0218]splitSubtaskMetaForOneKVMetaGroup", zap.Int("i", i), brlogutil.Key("key", k))
+			logger.Warn("[date0218] splitSubtaskMetaForOneKVMetaGroup regionSplitKeys", zap.Int("i", i), brlogutil.Key("key", k))
 		}
 		m := &BackfillSubTaskMeta{
 			MetaGroups: []*external.SortedKVMeta{{
@@ -669,6 +682,7 @@ func forEachBackfillSubtaskMeta(
 	}
 	for _, subTaskMeta := range subTaskMetas {
 		subtask, err := decodeBackfillSubTaskMeta(subTaskMeta)
+		// TODO: 0218 add log here for subtask
 		if err != nil {
 			logutil.DDLLogger().Error("unmarshal error", zap.Error(err))
 			return errors.Trace(err)

diff --git a/pkg/ddl/backfilling_dist_scheduler_test.go b/pkg/ddl/backfilling_dist_scheduler_test.go
diff --git a/pkg/disttask/framework/storage/subtask_state.go b/pkg/disttask/framework/storage/subtask_state.go
@@ -17,9 +17,12 @@ package storage
 import (
 	"context"
 
+	brlogutil "github.com/pingcap/tidb/br/pkg/logutil"
 	"github.com/pingcap/tidb/pkg/disttask/framework/proto"
 	"github.com/pingcap/tidb/pkg/sessionctx"
+	"github.com/pingcap/tidb/pkg/util/logutil"
 	"github.com/pingcap/tidb/pkg/util/sqlexec"
+	"go.uber.org/zap"
 )
 
 // StartSubtask updates the subtask state to running.
@@ -47,6 +50,7 @@ func (mgr *TaskManager) StartSubtask(ctx context.Context, subtaskID int64, execI
 
 // FinishSubtask updates the subtask meta and mark state to succeed.
 func (mgr *TaskManager) FinishSubtask(ctx context.Context, execID string, id int64, meta []byte) error {
+	logutil.BgLogger().Warn("[date0218] FinishSubtask", zap.Int64("id", id), brlogutil.Key("meta", meta))
 	_, err := mgr.ExecuteSQLWithNewSession(ctx, `update mysql.tidb_background_subtask
 		set meta = %?, state = %?, state_update_time = unix_timestamp(), end_time = CURRENT_TIMESTAMP()
 		where id = %? and exec_id = %?`,

diff --git a/pkg/disttask/framework/storage/task_table.go b/pkg/disttask/framework/storage/task_table.go
@@ -24,14 +24,17 @@ import (
 	"github.com/docker/go-units"
 	"github.com/pingcap/errors"
 	"github.com/pingcap/failpoint"
+	brlogutil "github.com/pingcap/tidb/br/pkg/logutil"
 	"github.com/pingcap/tidb/pkg/disttask/framework/proto"
 	"github.com/pingcap/tidb/pkg/kv"
 	"github.com/pingcap/tidb/pkg/sessionctx"
 	"github.com/pingcap/tidb/pkg/sessionctx/vardef"
 	"github.com/pingcap/tidb/pkg/util"
 	"github.com/pingcap/tidb/pkg/util/chunk"
+	"github.com/pingcap/tidb/pkg/util/logutil"
 	"github.com/pingcap/tidb/pkg/util/sqlexec"
 	clitutil "github.com/tikv/client-go/v2/util"
+	"go.uber.org/zap"
 )
 
 const (
@@ -715,7 +718,9 @@ func (*TaskManager) insertSubtasks(ctx context.Context, se sessionctx.Context, s
 		args       = make([]any, 0, len(subtasks)*7)
 	)
 	sb.WriteString(`insert into mysql.tidb_background_subtask(` + InsertSubtaskColumns + `) values `)
-	for _, subtask := range subtasks {
+	for i, subtask := range subtasks {
+		logutil.BgLogger().Warn("[date0218] insertSubtasks", zap.Int("i", i), zap.Int64("id", subtask.TaskID), zap.Int64("step", int64(subtask.Step)),
+			brlogutil.Key("meta", subtask.Meta))
 		markerList = append(markerList, "(%?, %?, %?, %?, %?, %?, %?, %?, CURRENT_TIMESTAMP(), '{}', '{}')")
 		args = append(args, subtask.Step, subtask.TaskID, subtask.ExecID, subtask.Meta,
 			proto.SubtaskStatePending, proto.Type2Int(subtask.Type), subtask.Concurrency, subtask.Ordinal)