Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

some inTest assert panic comes from ddl/systable/min_job_id when testing #54868

Closed
AilinKid opened this issue Jul 24, 2024 · 2 comments · Fixed by #54913
Closed

some inTest assert panic comes from ddl/systable/min_job_id when testing #54868

AilinKid opened this issue Jul 24, 2024 · 2 comments · Fixed by #54913
Labels
affects-7.5 affects-8.1 component/ddl This issue is related to DDL of TiDB. impact/panic severity/minor type/bug The issue is confirmed as a bug.

Comments

@AilinKid
Copy link
Contributor

Bug Report

Please answer these questions before submitting your issue. Thanks!

1. Minimal reproduce step (Required)

panic: assert failed, location mismatch, ctxLoc: Local, varsLoc: Local, stmtLoc: Local [recovered]
	panic: assert failed, location mismatch, ctxLoc: Local, varsLoc: Local, stmtLoc: Local

goroutine 1993 [running]:
github.com/pingcap/tidb/pkg/executor.(*Compiler).Compile.func1()
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/executor/compiler.go:57 +0x360
panic({0x104246040?, 0x1400a1476f0?})
	/opt/homebrew/opt/go/libexec/src/runtime/panic.go:914 +0x218
github.com/pingcap/tidb/pkg/util/intest.doPanic(...)
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/util/intest/assert.go:59
github.com/pingcap/tidb/pkg/util/intest.Assert(...)
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/util/intest/assert.go:27
github.com/pingcap/tidb/pkg/expression/context.AssertLocationWithSessionVars(0x1046baa00?, 0x1400ae80000)
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/expression/context/context.go:232 +0x1c8
github.com/pingcap/tidb/pkg/expression/contextsession.(*SessionEvalContext).TypeCtx(0x1400a226240)
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/expression/contextsession/sessionctx.go:209 +0xb0
github.com/pingcap/tidb/pkg/expression.typeCtx(...)
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/expression/context.go:57
github.com/pingcap/tidb/pkg/expression.(*Constant).Equal(0x1400a17bec0, {0x104bf9788, 0x1400a226240}, {0x104c35ce0?, 0x1400a17bec0})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/expression/constant.go:437 +0xa0
github.com/pingcap/tidb/pkg/expression.(*baseBuiltinFunc).equal(0x1400a226480, {0x104bf9788, 0x1400a226240}, {0x104c0fb68?, 0x1400a226480?})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/expression/builtin.go:400 +0xd8
github.com/pingcap/tidb/pkg/expression.(*ScalarFunction).Equal(0x1400a224460, {0x104bf9788, 0x1400a226240}, {0x104c35fb0?, 0x1400a224460})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/expression/scalar_function.go:372 +0xc4
github.com/pingcap/tidb/pkg/planner/cardinality.getMaskAndRanges({0x104bfedc0, 0x1400a147220}, {0x1400a147670, 0x1, 0x1}, 0x0?, {0x0?, 0x104b6e6e8?, 0x14006284fa8?}, 0x10022ce6c?, ...)
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/planner/cardinality/selectivity.go:730 +0x3cc
github.com/pingcap/tidb/pkg/planner/cardinality.Selectivity({0x104bfedc0, 0x1400a147220?}, 0x1400a223260, {0x1400a1475d0, 0x1, 0x1}, {0x1400a1472f0, 0x1, 0x104be0f80?})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/planner/cardinality/selectivity.go:130 +0x970
github.com/pingcap/tidb/pkg/planner/core.(*DataSource).deriveStatsByFilter(0x140099d58c0, {0x1400a1475d0, 0x1, 0x1}, {0x1400a1472f0, 0x1, 0x2})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/planner/core/stats.go:197 +0xe4
github.com/pingcap/tidb/pkg/planner/core.(*DataSource).DeriveStats(0x140099d58c0, {0x140099d58c0?, 0x400a0b2ff0?, 0x1?}, 0x14006285ee8?, {0x10022c584?, 0x1?, 0x1400a162528?}, {0x0?, 0x0?, ...})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/planner/core/logical_datasource.go:328 +0x45c
github.com/pingcap/tidb/pkg/planner/core/operator/logicalop.(*BaseLogicalPlan).RecursiveDeriveStats(0x140099d58e0, {0x0, 0x0, 0x0})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/planner/core/operator/logicalop/base_logical_plan.go:188 +0x204
github.com/pingcap/tidb/pkg/planner/core/operator/logicalop.(*BaseLogicalPlan).RecursiveDeriveStats(0x1400a0b2ff0, {0x0, 0x0, 0x0})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/planner/core/operator/logicalop/base_logical_plan.go:181 +0x114
github.com/pingcap/tidb/pkg/planner/core/operator/logicalop.(*BaseLogicalPlan).RecursiveDeriveStats(0x140099c3e20, {0x0, 0x0, 0x0})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/planner/core/operator/logicalop/base_logical_plan.go:181 +0x114
github.com/pingcap/tidb/pkg/planner/core/operator/logicalop.(*BaseLogicalPlan).RecursiveDeriveStats(0x1400a0b2f20, {0x0, 0x0, 0x0})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/planner/core/operator/logicalop/base_logical_plan.go:181 +0x114
github.com/pingcap/tidb/pkg/planner/core.physicalOptimize({0x104c321d8, 0x1400a0b2f00}, 0x1400a2168a0)
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/planner/core/optimizer.go:1046 +0xdc
github.com/pingcap/tidb/pkg/planner/core.doOptimize({0x104bba9b8, 0x1400a1deb40}, {0x104bfedc0?, 0x1400a147220?}, 0x140062864c8?, {0x104c321d8, 0x1400a0b2f00})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/planner/core/optimizer.go:308 +0xf0
github.com/pingcap/tidb/pkg/planner/core.DoOptimize({0x104bba9b8, 0x1400a1deb40}, {0x104bfedc0, 0x1400a147220}, 0x1400a224380?, {0x104c321d8, 0x1400a0b2f00})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/planner/core/optimizer.go:355 +0xd0
github.com/pingcap/tidb/pkg/planner.optimize({0x104bba9b8, 0x1400a1deb40}, {0x104bfedc0?, 0x1400a147220}, {0x104bc6cf0?, 0x1400a0f8b40?}, {0x104c02388, 0x1400a0d17a0})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/planner/optimize.go:525 +0x500
github.com/pingcap/tidb/pkg/planner.Optimize({0x104bba9b8?, 0x1400a1deb40}, {0x104c39b10?, 0x140099ed900}, {0x104bc6cf0, 0x1400a0f8b40}, {0x104c02388?, 0x1400a0d17a0})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/planner/optimize.go:356 +0x1178
github.com/pingcap/tidb/pkg/executor.(*Compiler).Compile(0x1400ae93840, {0x104bba9b8?, 0x1400a1deb40?}, {0x104bd1808?, 0x1400a0f8b40})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/executor/compiler.go:99 +0x2c8
github.com/pingcap/tidb/pkg/session.(*session).ExecuteStmt(0x140099ed900, {0x104bba9b8?, 0x1400a1deb40?}, {0x104bd1808, 0x1400a0f8b40?})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/session/session.go:2098 +0x650
github.com/pingcap/tidb/pkg/session.(*session).ExecuteInternal(0x140099ed900, {0x104bba9b8, 0x1400a1deb40}, {0x1400a22bdc0, 0x3c}, {0x0, 0x0, 0x0})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/session/session.go:1523 +0x17c
github.com/pingcap/tidb/pkg/ddl/session.(*Session).Execute(0x1400a147230, {0x104bba9b8, 0x1400a1deb40}, {0x1400a22bdc0, 0x3c}, {0x103566932, 0xe})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/ddl/session/session.go:85 +0x150
github.com/pingcap/tidb/pkg/ddl/systable.(*manager).GetMinJobID.func1(0x1400acbad98?)
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/ddl/systable/manager.go:120 +0x94
github.com/pingcap/tidb/pkg/ddl/systable.(*manager).withNewSession(0x1400acf2cd0, 0x14001488dd0)
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/ddl/systable/manager.go:71 +0xc4
github.com/pingcap/tidb/pkg/ddl/systable.(*manager).GetMinJobID(0x1013ca433?, {0x104bba9b8?, 0x1400a1deb40?}, 0x8c?)
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/ddl/systable/manager.go:118 +0x58
github.com/pingcap/tidb/pkg/ddl/systable.(*MinJobIDRefresher).refresh(0x10359a57b?, {0x104bba9b8?, 0x1400a1deb40?})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/ddl/systable/min_job_id.go:66 +0x48
github.com/pingcap/tidb/pkg/ddl/systable.(*MinJobIDRefresher).Start(0x18?, {0x104bba9b8, 0x1400a1deb40})
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/ddl/systable/min_job_id.go:54 +0x38
github.com/pingcap/tidb/pkg/ddl.(*ddl).Start.func3()
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/ddl/ddl.go:869 +0x30
github.com/pingcap/tidb/pkg/util.(*WaitGroupWrapper).Run.func1()
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/util/wait_group_wrapper.go:157 +0x58
created by github.com/pingcap/tidb/pkg/util.(*WaitGroupWrapper).Run in goroutine 47
	/Users/arenatlx/go/src/github.com/pingcap/tidb/pkg/util/wait_group_wrapper.go:155 +0x7c

2. What did you expect to see? (Required)

no panic

3. What did you see instead (Required)

occasionally panic

4. What is your TiDB version? (Required)

master

@AilinKid AilinKid added type/bug The issue is confirmed as a bug. component/ddl This issue is related to DDL of TiDB. labels Jul 24, 2024
@D3Hunter
Copy link
Contributor

D3Hunter commented Jul 25, 2024

apply this diff on 8.1.0, run any case that create domain&store, it will report same error, the cause is after line 3321 there will be sessionCtx be used to run queries, but we actually shouldn't allow it before we call timeutil.SetSystemTZ(tz) at 3332

tidb/pkg/session/session.go

Lines 3321 to 3332 in 945d07c

ses, err := createSessionsImpl(store, 10)
if err != nil {
return nil, err
}
ses[0].GetSessionVars().InRestrictedSQL = true
// get system tz from mysql.tidb
tz, err := ses[0].getTableValue(ctx, mysql.TiDBTable, tidbSystemTZ)
if err != nil {
return nil, err
}
timeutil.SetSystemTZ(tz)

this issue became obvious as GetMinJobID runs immediately after it starts, but other routines mostly will wait for some interval.

diff --git a/pkg/ddl/job_table.go b/pkg/ddl/job_table.go
index aa2ebc3d51..41884214bb 100644
--- a/pkg/ddl/job_table.go
+++ b/pkg/ddl/job_table.go
@@ -97,6 +97,10 @@ func (d *ddl) getJob(se *sess.Session, tp jobType, filter func(*model.Job) (bool
 		excludedJobIDs = fmt.Sprintf("and job_id not in (%s)", ids)
 	}
 	sql := fmt.Sprintf(getJobSQL, not, excludedJobIDs)
+	if intest.COUNTER.Load() == 1 {
+		se.Context.GetSessionVars().InsideDDLGet.Store(true)
+		defer se.Context.GetSessionVars().InsideDDLGet.Store(false)
+	}
 	rows, err := se.Execute(context.Background(), sql, label)
 	if err != nil {
 		return nil, errors.Trace(err)
diff --git a/pkg/executor/executor.go b/pkg/executor/executor.go
index 71feeb2086..e01e5f08b8 100644
--- a/pkg/executor/executor.go
+++ b/pkg/executor/executor.go
@@ -1990,6 +1990,10 @@ func ResetContextOfStmt(ctx sessionctx.Context, s ast.StmtNode) (err error) {
 		sc = vars.InitStatementContext()
 	}
 	sc.SetTimeZone(vars.Location())
+	if intest.COUNTER.Load() == 1 && vars.InsideDDLGet.Load() {
+		<-intest.SYNCCH
+		intest.COUNTER.Add(1)
+	}
 	sc.TaskID = stmtctx.AllocateTaskID()
 	sc.CTEStorageMap = map[int]*CTEStorages{}
 	sc.IsStaleness = false
diff --git a/pkg/expression/context/context.go b/pkg/expression/context/context.go
index 73a817fdf4..2224dce436 100644
--- a/pkg/expression/context/context.go
+++ b/pkg/expression/context/context.go
@@ -16,6 +16,8 @@ package context
 
 import (
 	"fmt"
+	"runtime"
+	"strings"
 	"time"
 
 	"github.com/pingcap/tidb/pkg/errctx"
@@ -23,7 +25,10 @@ import (
 	"github.com/pingcap/tidb/pkg/sessionctx/stmtctx"
 	"github.com/pingcap/tidb/pkg/sessionctx/variable"
 	"github.com/pingcap/tidb/pkg/types"
+	"github.com/pingcap/tidb/pkg/util/intest"
+	"github.com/pingcap/tidb/pkg/util/logutil"
 	"github.com/pingcap/tidb/pkg/util/mathutil"
+	"go.uber.org/zap"
 )
 
 // EvalContext is used to evaluate an expression
@@ -104,3 +109,24 @@ type ExprContext interface {
 	// GetGroupConcatMaxLen returns the value of the 'group_concat_max_len' system variable.
 	GetGroupConcatMaxLen() uint64
 }
+
+// AssertLocationWithSessionVars asserts the location in the context and session variables are the same.
+// It is only used for testing.
+func AssertLocationWithSessionVars(ctxLoc *time.Location, vars *variable.SessionVars) {
+	if intest.COUNTER.Load() == 2 {
+		buf := make([]byte, 1<<16)
+		runtime.Stack(buf, true)
+		if strings.Contains(string(buf), "getGeneralJob") {
+			<-intest.SYNCCH
+		}
+	}
+	ctxLocStr := ctxLoc.String()
+	varsLocStr := vars.Location().String()
+	stmtLocStr := vars.StmtCtx.TimeZone().String()
+	logutil.BgLogger().Info("AssertLocationWithSessionVars", zap.String("ctxLoc", ctxLocStr),
+		zap.String("varsLoc", varsLocStr), zap.String("stmtLoc", stmtLocStr))
+	intest.Assert(ctxLocStr == varsLocStr && ctxLocStr == stmtLocStr,
+		"location mismatch, ctxLoc: %s, varsLoc: %s, stmtLoc: %s",
+		ctxLoc.String(), ctxLocStr, stmtLocStr,
+	)
+}
diff --git a/pkg/expression/contextimpl/sessionctx.go b/pkg/expression/contextimpl/sessionctx.go
index 5d792f2c9b..c6cfc03c28 100644
--- a/pkg/expression/contextimpl/sessionctx.go
+++ b/pkg/expression/contextimpl/sessionctx.go
@@ -167,6 +167,10 @@ func (ctx *SessionEvalContext) SQLMode() mysql.SQLMode {
 
 // TypeCtx returns the types.Context
 func (ctx *SessionEvalContext) TypeCtx() types.Context {
+	tc := ctx.sctx.GetSessionVars().StmtCtx.TypeCtx()
+	if intest.InTest {
+		exprctx.AssertLocationWithSessionVars(tc.Location(), ctx.sctx.GetSessionVars())
+	}
 	return ctx.sctx.GetSessionVars().StmtCtx.TypeCtx()
 }
 
diff --git a/pkg/session/session.go b/pkg/session/session.go
index 2cc9d07167..a811343f9d 100644
--- a/pkg/session/session.go
+++ b/pkg/session/session.go
@@ -3329,7 +3329,14 @@ func bootstrapSessionImpl(store kv.Storage, createSessionsImpl func(store kv.Sto
 	if err != nil {
 		return nil, err
 	}
+	intest.COUNTER.Add(1)
+	intest.SYNCCH <- struct{}{}
+	systemTZ, err := timeutil.GetSystemTZ()
+	logutil.BgLogger().Warn("before set timezone", zap.String("tz", systemTZ), zap.Error(err))
 	timeutil.SetSystemTZ(tz)
+	systemTZ, err = timeutil.GetSystemTZ()
+	intest.SYNCCH <- struct{}{}
+	logutil.BgLogger().Warn("after set timezone", zap.String("tz", systemTZ), zap.Error(err))
 
 	// get the flag from `mysql`.`tidb` which indicating if new collations are enabled.
 	newCollationEnabled, err := loadCollationParameter(ctx, ses[0])
diff --git a/pkg/sessionctx/variable/session.go b/pkg/sessionctx/variable/session.go
index c4bb81ee8d..7cb8a27fdb 100644
--- a/pkg/sessionctx/variable/session.go
+++ b/pkg/sessionctx/variable/session.go
@@ -788,8 +788,8 @@ type SessionVars struct {
 	LastFoundRows uint64
 
 	// StmtCtx holds variables for current executing statement.
-	StmtCtx *stmtctx.StatementContext
-
+	StmtCtx      *stmtctx.StatementContext
+	InsideDDLGet atomic.Bool
 	// RefCountOfStmtCtx indicates the reference count of StmtCtx. When the
 	// StmtCtx is accessed by other sessions, e.g. oom-alarm-handler/expensive-query-handler, add one first.
 	// Note: this variable should be accessed and updated by atomic operations.
diff --git a/pkg/util/intest/common.go b/pkg/util/intest/common.go
index a2ebccd4b3..4017451490 100644
--- a/pkg/util/intest/common.go
+++ b/pkg/util/intest/common.go
@@ -16,6 +16,8 @@
 
 package intest
 
+import "sync/atomic"
+
 // InTest checks if the code is running in test.
 const InTest = false
 
@@ -34,3 +36,7 @@ func AssertNoError(_ error, _ ...any) {}
 // AssertFunc is a stub function in release build.
 // See the same function `util/intest/assert.go` for the real implement in test.
 func AssertFunc(_ func() bool, _ ...any) {}
+
+var COUNTER atomic.Int32
+
+var SYNCCH = make(chan struct{})
diff --git a/pkg/util/intest/intest.go b/pkg/util/intest/intest.go
index a96d2fbf73..fd10044f16 100644
--- a/pkg/util/intest/intest.go
+++ b/pkg/util/intest/intest.go
@@ -16,5 +16,11 @@
 
 package intest
 
+import "sync/atomic"
+
 // InTest checks if the code is running in test.
 const InTest = true
+
+var COUNTER atomic.Int32
+
+var SYNCCH = make(chan struct{})

@D3Hunter
Copy link
Contributor

7.1/7.5/8.1 have similar issue, but they don't have this assert, and it's harder to reproduce this problem, so mark it as minor

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
affects-7.5 affects-8.1 component/ddl This issue is related to DDL of TiDB. impact/panic severity/minor type/bug The issue is confirmed as a bug.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants