[conn.go:1024] ["connection running loop panic"]

[apollodafoni]

Bug Report

Please answer these questions before submitting your issue. Thanks!

1. Minimal reproduce step (Required)

• /go-tpc ch prepare -P 4000 --warehouses 100 -D tpcc
• /go-tpc ch run -P 4000 --warehouses 100 -T 8 -D tpcc --acThreads 0 --conn-params "tidb_isolation_read_engines='tikv,tidb'" --ignore-error"

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

work well

3. What did you see instead (Required)

[conn.go:1024] ["connection running loop panic"] [conn=132120934] [session_alias=] [lastSQL="INSERT into order_line (ol_o_id, ol_d_id, ol_w_id, ol_number, ol_i_id, ol_supply_w_id, ol_quantity, ol_amount, ol_dist_info) VALUES (?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?),(?,?,?,?,?,?,?,?,?) [arguments: (3123, 6, 62, 1, 81757, 62, 2, 144.826473888, "YGUZJCHOKDKQEIUUMONOYUCU", 3123, 6, 62, 2, 98365, 62, 4, 273.77857451200003, "LQOCFPZWIJBHNGSGVJQRENIS", 3123, 6, 62, 3, 16804, 62, 3, 194.4719453424, "YMKKZYWNRNDSAWNFOGYCUWHS", 3123, 6, 62, 4, 94585, 62, 6, 145.15265964, "CULSRIGAEZTATTZQFUXXNRVD", 3123, 6, 62, 5, 48315, 62, 5, 489.2786280000001, "ESJODMAFIWSRJPFRBJARLHXP")]"] [err="runtime error: invalid memory address or nil pointer dereference"] [stack="github.com/pingcap/tidb/pkg/server.(*clientConn).Run.func1\n\t/workspace/source/tidb/pkg/server/conn.go:1027\nruntime.gopanic\n\t/usr/local/go/src/runtime/panic.go:914\ngit.luolix.top/pingcap/tidb/pkg/executor.(*Compiler).Compile.func1\n\t/workspace/source/tidb/pkg/executor/compiler.go:57\nruntime.gopanic\n\t/usr/local/go/src/runtime/panic.go:914\nruntime.panicmem\n\t/usr/local/go/src/runtime/panic.go:261\nruntime.sigpanic\n\t/usr/local/go/src/runtime/signal_unix.go:861\ngit.luolix.top/pingcap/tidb/pkg/expression.ColumnInfos2ColumnsAndNames\n\t/workspace/source/tidb/pkg/expression/expression.go:1018\ngit.luolix.top/pingcap/tidb/pkg/expression.TableInfo2SchemaAndNames\n\t/workspace/source/tidb/pkg/expression/expression.go:966\ngit.luolix.top/pingcap/tidb/pkg/planner/core.(*PlanBuilder).buildInsert\n\t/workspace/source/tidb/pkg/planner/core/planbuilder.go:3633\ngit.luolix.top/pingcap/tidb/pkg/planner/core.(*PlanBuilder).Build\n\t/workspace/source/tidb/pkg/planner/core/planbuilder.go:508\ngit.luolix.top/pingcap/tidb/pkg/planner.buildLogicalPlan\n\t/workspace/source/tidb/pkg/planner/optimize.go:564\ngit.luolix.top/pingcap/tidb/pkg/planner.optimize\n\t/workspace/source/tidb/pkg/planner/optimize.go:481\ngit.luolix.top/pingcap/tidb/pkg/planner.Optimize\n\t/workspace/source/tidb/pkg/planner/optimize.go:349\ngit.luolix.top/pingcap/tidb/pkg/planner/core.generateNewPlan\n\t/workspace/source/tidb/pkg/planner/core/plan_cache.go:302\ngit.luolix.top/pingcap/tidb/pkg/planner/core.GetPlanFromPlanCache\n\t/workspace/source/tidb/pkg/planner/core/plan_cache.go:251\ngit.luolix.top/pingcap/tidb/pkg/planner.OptimizeExecStmt\n\t/workspace/source/tidb/pkg/planner/optimize.go:541\ngit.luolix.top/pingcap/tidb/pkg/planner.Optimize\n\t/workspace/source/tidb/pkg/planner/optimize.go:163\ngit.luolix.top/pingcap/tidb/pkg/executor.(*Compiler).Compile\n\t/workspace/source/tidb/pkg/executor/compiler.go:99\ngit.luolix.top/pingcap/tidb/pkg/session.(*session).ExecuteStmt\n\t/workspace/source/tidb/pkg/session/session.go:2098\ngit.luolix.top/pingcap/tidb/pkg/server.(*TiDBContext).ExecuteStmt\n\t/workspace/source/tidb/pkg/server/driver_tidb.go:294\ngit.luolix.top/pingcap/tidb/pkg/server.(*clientConn).executePreparedStmtAndWriteResult\n\t/workspace/source/tidb/pkg/server/conn_stmt.go:306\ngit.luolix.top/pingcap/tidb/pkg/server.(*clientConn).executePlanCacheStmt\n\t/workspace/source/tidb/pkg/server/conn_stmt.go:234\ngit.luolix.top/pingcap/tidb/pkg/server.(*clientConn).handleStmtExecute\n\t/workspace/source/tidb/pkg/server/conn_stmt.go:225\ngit.luolix.top/pingcap/tidb/pkg/server.(*clientConn).dispatch\n\t/workspace/source/tidb/pkg/server/conn.go:1386\ngit.luolix.top/pingcap/tidb/pkg/server.(*clientConn).Run\n\t/workspace/source/tidb/pkg/server/conn.go:1125\ngit.luolix.top/pingcap/tidb/pkg/server.(*Server).onConn\n\t/workspace/source/tidb/pkg/server/server.go:739"]

4. What is your TiDB version? (Required)

tidb git_hash: e21109913d02ac37184fd54ef5c748664ad89284

[ti-chi-bot]

@apollodafoni: The label(s) component/execution cannot be applied, because the repository doesn't have them.

In response to this:

/component execution

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the ti-community-infra/tichi repository.

[zanmato1984]

The stack shows that the error is reported in planner, changing label.

[ti-chi-bot]

@apollodafoni: The label(s) component/execution cannot be applied, because the repository doesn't have them.

In response to this:

/component execution

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the ti-community-infra/tichi repository.

[apollodafoni]

/assign @AilinKid

[apollodafoni]

/label affects-8.2

[apollodafoni]

/impact panic

[AilinKid]

mysql> explain INSERT into order_line (ol_o_id, ol_d_id, ol_w_id, ol_number, ol_i_id, ol_supply_w_id, ol_quantity, ol_amount, ol_dist_info) VALUES
    ->  (3123, 6, 62, 1, 81757, 62, 2, 144.826473888, "YGUZJCHOKDKQEIUUMONOYUCU"),
    ->  (3123, 6, 62, 2, 98365, 62, 4, 273.77857451200003, "LQOCFPZWIJBHNGSGVJQRENIS"),
    ->  (3123, 6, 62, 3, 16804, 62, 3, 194.4719453424, "YMKKZYWNRNDSAWNFOGYCUWHS"),
    ->  (3123, 6, 62, 4, 94585, 62, 6, 145.15265964, "CULSRIGAEZTATTZQFUXXNRVD"),
    ->  (3123, 6, 62, 5, 48315, 62, 5, 489.2786280000001, "ESJODMAFIWSRJPFRBJARLHXP");
ERROR 1105 (HY000): runtime error: invalid memory address or nil pointer dereference

[AilinKid]

we found

the panic log is about

 2024-07-03 11:19:01 (UTC+08:00)TiDB tc-tidb-0.tc-tidb-peer.e2e-htap-ddl2-tps-7597434-1-943.svc:4000[conn.go:1162]
  ["command dispatched failed"] [conn=1820353348] [session_alias=] [connInfo="id:1820353348, addr:10.200.0.166:60396
   status:10, collation:utf8mb4_general_ci, user:root"] [command=Query] [status="inTxn:0, autocommit:1"] 
   [sql="show create table  order_line"] [txn_mode=PESSIMISTIC] [timestamp=0]
    [err="runtime error: invalid memory address or nil pointer dereference
github.com/pingcap/errors.AddStack
\t/root/go/pkg/mod/github.com/pingcap/errors@v0.11.5-0.20240318064555-6bd07397691f/errors.go:178
github.com/pingcap/errors.Trace
\t/root/go/pkg/mod/github.com/pingcap/errors@v0.11.5-0.20240318064555-6bd07397691f/juju_adaptor.go:15
github.com/pingcap/tidb/pkg/util.GetRecoverError
\t/workspace/source/tidb/pkg/util/util.go:303
github.com/pingcap/tidb/pkg/executor/internal/exec.Next.func1
\t/workspace/source/tidb/pkg/executor/internal/exec/executor.go:394
runtime.gopanic
\t/usr/local/go/src/runtime/panic.go:914
runtime.panicmem
\t/usr/local/go/src/runtime/panic.go:261
runtime.sigpanic
\t/usr/local/go/src/runtime/signal_unix.go:861
github.com/pingcap/tidb/pkg/executor.constructResultOfShowCreateTable
\t/workspace/source/tidb/pkg/executor/show.go:989
github.com/pingcap/tidb/pkg/executor.(*ShowExec).fetchShowCreateTable
\t/workspace/source/tidb/pkg/executor/show.go:1435
github.com/pingcap/tidb/pkg/executor.(*ShowExec).fetchAll
\t/workspace/source/tidb/pkg/executor/show.go:187
github.com/pingcap/tidb/pkg/executor.(*ShowExec).Next
\t/workspace/source/tidb/pkg/executor/show.go:132
github.com/pingcap/tidb/pkg/executor/internal/exec.Next
\t/workspace/source/tidb/pkg/executor/internal/exec/executor.go:410
github.com/pingcap/tidb/pkg/executor.(*ExecStmt).next
\t/workspace/source/tidb/pkg/executor/adapter.go:1250
github.com/pingcap/tidb/pkg/executor.(*recordSet).Next
\t/workspace/source/tidb/pkg/executor/adapter.go:175
github.com/pingcap/tidb/pkg/server/internal/resultset.(*tidbResultSet).Next
\t/workspace/source/tidb/pkg/server/internal/resultset/resultset.go:64
github.com/pingcap/tidb/pkg/server.(*clientConn).writeChunks
\t/workspace/source/tidb/pkg/server/conn.go:2332
github.com/pingcap/tidb/pkg/server.(*clientConn).writeResultSet
\t/workspace/source/tidb/pkg/server/conn.go:2275
github.com/pingcap/tidb/pkg/server.(*clientConn).handleStmt
\t/workspace/source/tidb/pkg/server/conn.go:2068
github.com/pingcap/tidb/pkg/server.(*clientConn).handleQuery
\t/workspace/source/tidb/pkg/server/conn.go:1785
github.com/pingcap/tidb/pkg/server.(*clientConn).dispatch
\t/workspace/source/tidb/pkg/server/conn.go:1359
github.com/pingcap/tidb/pkg/server.(*clientConn).Run
\t/workspace/source/tidb/pkg/server/conn.go:1125
github.com/pingcap/tidb/pkg/server.(*Server).onConn
\t/workspace/source/tidb/pkg/server/server.go:739
runtime.goexit
\t/usr/local/go/src/runtime/asm_amd64.s:1650"]

and we found the original meta json has some unhealthy state

[AilinKid]

[AilinKid]

summary: if table columns have non-consecutive public columns (assumption: always compact public columns ahead, then append non-public columns), the panic will happen like above.

[AilinKid]

it seems this is the source ddl job, non-public still exists in the columns, while the new ddl-add -olumn job is finished and append the new col behind them.

[apollodafoni]

/severity major