loadStatsWorker panic when init stats

[xuyifangreeneyes]

Bug Report

Please answer these questions before submitting your issue. Thanks!

1. Minimal reproduce step (Required)

Still looking for reproduce steps.

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

Init stats successfully. No panic happens.

3. What did you see instead (Required)

[2023/03/03 05:42:14.849 +00:00] [ERROR] [misc.go:116] ["panic in the recoverable goroutine"] [keyspaceName=XXXXX] [label=domain] [funcInfo=loadStatsWorker] [r="\"time: missing Location in call to Date\""] [stack="github.com/pingcap/tidb/util.Recover
	/go/src/github.com/pingcap/tidb/util/misc.go:120
runtime.gopanic
	/usr/local/go/src/runtime/panic.go:884
time.Date
	/usr/local/go/src/time/time.go:1442
github.com/pingcap/tidb/types.CoreTime.GoTime
	/go/src/github.com/pingcap/tidb/types/core_time.go:174
github.com/pingcap/tidb/types.(*Time).ConvertTimeZone
	/go/src/github.com/pingcap/tidb/types/time.go:365
github.com/pingcap/tidb/types.checkTimestampType
	/go/src/github.com/pingcap/tidb/types/time.go:2176
github.com/pingcap/tidb/types.Time.check
	/go/src/github.com/pingcap/tidb/types/time.go:687
github.com/pingcap/tidb/types.parseTime
	/go/src/github.com/pingcap/tidb/types/time.go:2008
github.com/pingcap/tidb/types.ParseTime
	/go/src/github.com/pingcap/tidb/types/time.go:1984
github.com/pingcap/tidb/types.(*Datum).convertToMysqlTimestamp
	/go/src/github.com/pingcap/tidb/types/datum.go:1257
github.com/pingcap/tidb/types.(*Datum).ConvertTo
	/go/src/github.com/pingcap/tidb/types/datum.go:909
github.com/pingcap/tidb/statistics/handle.(*Handle).initStatsBuckets4Chunk
	/go/src/github.com/pingcap/tidb/statistics/handle/bootstrap.go:314
github.com/pingcap/tidb/statistics/handle.(*Handle).initStatsBuckets
	/go/src/github.com/pingcap/tidb/statistics/handle/bootstrap.go:375
github.com/pingcap/tidb/statistics/handle.(*Handle).InitStats
	/go/src/github.com/pingcap/tidb/statistics/handle/bootstrap.go:429
github.com/pingcap/tidb/domain.(*Domain).loadStatsWorker
	/go/src/github.com/pingcap/tidb/domain/domain.go:2004
github.com/pingcap/tidb/util.(*WaitGroupEnhancedWrapper).Run.func1
	/go/src/github.com/pingcap/tidb/util/wait_group_wrapper.go:96"]

4. What is your TiDB version? (Required)

v6.6(upgrade from v6.4)

[xuyifangreeneyes]

The panic can happen when h.mu.ctx.GetSessionVars().StmtCtx.TimeZone is nil. I set it to nil deliberately in code and got the panic stack.

In my local tidb-server, h.mu.ctx.GetSessionVars().StmtCtx.TimeZone is Asia/Shanghai. I guess that maybe there is some difference between my local tidb-server and the cluster where panic happens, like system env, config and so on, which causes the issue.

A quick fix is not use h.mu.ctx.GetSessionVars().StmtCtx, just create a new StatementContext like the following:
https://github.com/pingcap/tidb/blob/master/statistics/interact_with_storage.go#L118-L138. However, in this way, #41985 still exists.

[xuyifangreeneyes]

I found the reproduce steps:

use test;
set @@global.tidb_analyze_version = 1;
set @@session.tidb_analyze_version = 1;
create table t(a timestamp primary key);
insert into t values (now());
insert into t values (now());
insert into t values (now());
insert into t values (now());
insert into t values (now());
analyze table t with 0 topn;

Then restart tidb-server. We can see the panic logs as follows:

[2023/03/07 19:07:47.579 +08:00] [INFO] [domain.go:2052] ["loadStatsWorker exited."]
[2023/03/07 19:07:47.579 +08:00] [ERROR] [misc.go:116] ["panic in the recoverable goroutine"] [label=domain] [funcInfo=loadStatsWorker] [r="\"time: missing Location in call to Date\""] [stack="github.com/pingcap/tidb/util.Recover\n\t/Users/xuyifan/tidb/util/misc.go:120\nruntime.gopanic\n\t/usr/local/go/src/runtime/panic.go:884\ntime.Date\n\t/usr/local/go/src/time/time.go:1469\ngithub.com/pingcap/tidb/types.CoreTime.GoTime\n\t/Users/xuyifan/tidb/types/core_time.go:174\ngithub.com/pingcap/tidb/types.(*Time).ConvertTimeZone\n\t/Users/xuyifan/tidb/types/time.go:365\ngithub.com/pingcap/tidb/types.checkTimestampType\n\t/Users/xuyifan/tidb/types/time.go:2176\ngithub.com/pingcap/tidb/types.Time.check\n\t/Users/xuyifan/tidb/types/time.go:687\ngithub.com/pingcap/tidb/types.parseTime\n\t/Users/xuyifan/tidb/types/time.go:2008\ngithub.com/pingcap/tidb/types.ParseTime\n\t/Users/xuyifan/tidb/types/time.go:1984\ngithub.com/pingcap/tidb/types.(*Datum).convertToMysqlTimestamp\n\t/Users/xuyifan/tidb/types/datum.go:1257\ngithub.com/pingcap/tidb/types.(*Datum).ConvertTo\n\t/Users/xuyifan/tidb/types/datum.go:909\ngithub.com/pingcap/tidb/statistics/handle.(*Handle).initStatsBuckets4Chunk\n\t/Users/xuyifan/tidb/statistics/handle/bootstrap.go:314\ngithub.com/pingcap/tidb/statistics/handle.(*Handle).initStatsBuckets\n\t/Users/xuyifan/tidb/statistics/handle/bootstrap.go:375\ngithub.com/pingcap/tidb/statistics/handle.(*Handle).InitStats\n\t/Users/xuyifan/tidb/statistics/handle/bootstrap.go:429\ngithub.com/pingcap/tidb/domain.(*Domain).loadStatsWorker\n\t/Users/xuyifan/tidb/domain/domain.go:2056\ngithub.com/pingcap/tidb/util.(*WaitGroupEnhancedWrapper).Run.func1\n\t/Users/xuyifan/tidb/util/wait_group_wrapper.go:96"]
[2023/03/07 19:07:47.579 +08:00] [INFO] [wait_group_wrapper.go:137] ["background process exited"] [source=domain] [process=loadStatsWorker]

[xuyifangreeneyes]

The reason why stats ver2 cannot reproduce the issues:

In InitStats -> initStatsHistograms -> initStatsHistograms4Chunk, if stats ver is 2, initTopNCountSum is called and h.mu.ctx executes one sql inside. Before executing one sql, ResetContextOfStmt sets h.mu.ctx.GetSessionVars().StmtCtx to a not-nil value.

[xuyifangreeneyes]

/cherry-pick release-6.5-20230425-v6.5.2