前端应用反馈：java.sql.SQLException: runtime error: invalid memory address or nil pointer dereference

longge93 · 2020 年6 月 12 日 08:41

升级TIDB 4.0后，出现这样的查询失败，之前一直没问题。如何解决？

Lucien-卢西恩 · 2020 年6 月 12 日 08:56

确认一下 tidb.log 和系统 demsg 日志，是不是 tidb service oom 导致重启了。

longge93 · 2020 年6 月 12 日 09:19

看了监控和日志，应该不是OOM。还有其他需要排查的可能么？

小王同学 · 2020 年6 月 12 日 10:02

您好，可以查下 tidb.log 里面是否有对应的报错，如果有 [err=“runtime error: invalid memory address or nil pointer dereference”] 相关报错内容，麻烦确认下是否开启 plan cache，plan cache 中存在一个已知 bug，pr 链接：https://github.com/pingcap/tidb/issues/17727 关闭则可以恢复正常。如果不是该问题，可以看下 tidb.log 中的报错内容。感谢

longge93 · 2020 年6 月 12 日 14:50

plan cache如何关闭？

Lucien-卢西恩 · 2020 年6 月 13 日 01:33

通过修改 TiDB.toml 的 plan-cache 参数设置为 false，然后重启生效
https://github.com/pingcap/tidb/blob/v4.0.0/config/config.toml.example#L259-L262

longge93 · 2020 年6 月 13 日 03:09

tidb.log中的报错如下

使用的是TIDB 4.0GA版本，plan-chache值没有改过，应该是默认值False

Lucien-卢西恩 · 2020 年6 月 13 日 10:08

麻烦提供完整的上下文日志
另外需要发一下 TiDB 启动日志，关键词是 “Welcome"

longge93 · 2020 年6 月 14 日 13:50

1.上下文日志上图够么，不行我就把tidb.log整个发出来。

2.启动日志也在tidb.log么？

谢谢！

来了老弟 · 2020 年6 月 15 日 01:34

辛苦将 tidb.log download 下来，这边看下。系统 demsg 日志也反馈下，辛苦

在的，尝试在 tidb.log 日志开头看下是否可以i找到。如果日志已经切割，可以看下 log 目录是否存在 old 日志

longge93 · 2020 年6 月 15 日 14:18

TIDB启动日志：

[2020/06/15 15:36:20.258 +08:00] [INFO] [printer.go:42] [“Welcome to TiDB.”] [“Release Version”=v4.0.0]
[Edition=Community] [“Git Commit Hash”=689a6b6439ae7835947fcaccf329a3fc303986cb] [“Git Branch”=heads/refs/tags/v4.0.1] [“UTC Build Time”=“2020-06-12 06:01:55”] [GoVersion=go1.13] [“Race Enabled”=false] [“Check Table Before Drop”=false] [“TiKV Min Version”=v3.0.0-60965b006877ca7234adaced7890d7b029ed1306]
[2020/06/15 15:36:20.258 +08:00] [INFO] [printer.go:56] [“loaded config”] [config="{“host”:“0.0.0.0”,“advertise-address”:“192.168.30.30”,“port”:4000,“cors”:"",“store”:“tikv”,“path”:“192.168.30.30:2379”,“socket”:"",“lease”:“45s”,“run-ddl”:true,“split-table”:true,“token-limit”:1000,“oom-use-tmp-storage”:true,“tmp-storage-path”:"/tmp/1000_tidb/MC4wLjAuMDo0MDAwLzAuMC4wLjA6MTAwODA=/tmp-storage",“oom-action”:“log”,“mem-quota-query”:1073741824,“tmp-storage-quota”:-1,“enable-streaming”:false,“enable-batch-dml”:false,“lower-case-table-names”:2,“server-version”:"",“log”:{“level”:“info”,“format”:“text”,“disable-timestamp”:false,“enable-timestamp”:null,“disable-error-stack”:null,“enable-error-stack”:null,“file”:{“filename”:"/data1/deploy/log/tidb.log",“max-size”:300,“max-days”:0,“max-backups”:0},“enable-slow-log”:true,“slow-query-file”:“log/tidb_slow_query.log”,“slow-threshold”:5000,“expensive-threshold”:10000,“query-log-max-len”:2048,“record-plan-in-slow-log”:1},“security”:{“skip-grant-table”:false,“ssl-ca”:"",“ssl-cert”:"",“ssl-key”:"",“require-secure-transport”:false,“cluster-ssl-ca”:"",“cluster-ssl-cert”:"",“cluster-ssl-key”:"",“cluster-verify-cn”:null},“status”:{“status-host”:“0.0.0.0”,“metrics-addr”:"",“status-port”:10080,“metrics-interval”:15,“report-status”:true,“record-db-qps”:false},“performance”:{“max-procs”:0,“max-memory”:0,“stats-lease”:“3s”,“stmt-count-limit”:5000,“feedback-probability”:0.05,“query-feedback-limit”:1024,“pseudo-estimate-ratio”:0.8,“force-priority”:“NO_PRIORITY”,“bind-info-lease”:“3s”,“txn-total-size-limit”:104857600,“tcp-keep-alive”:true,“cross-join”:true,“run-auto-analyze”:true,“agg-push-down-join”:false,“committer-concurrency”:16,“max-txn-ttl”:600000},“prepared-plan-cache”:{“enabled”:false,“capacity”:100,“memory-guard-ratio”:0.1},“opentracing”:{“enable”:false,“rpc-metrics”:false,“sampler”:{“type”:“const”,“param”:1,“sampling-server-url”:"",“max-operations”:0,“sampling-refresh-interval”:0},“reporter”:{“queue-size”:0,“buffer-flush-interval”:0,“log-spans”:false,“local-agent-host-port”:""}},“proxy-protocol”:{“networks”:"",“header-timeout”:5},“tikv-client”:{“grpc-connection-count”:16,“grpc-keepalive-time”:10,“grpc-keepalive-timeout”:3,“commit-timeout”:“41s”,“max-batch-size”:128,“overload-threshold”:200,“max-batch-wait-time”:0,“batch-wait-size”:8,“enable-chunk-rpc”:true,“region-cache-ttl”:600,“store-limit”:0,“store-liveness-timeout”:“120s”,“copr-cache”:{“enable”:false,“capacity-mb”:1000,“admission-max-result-mb”:10,“admission-min-process-ms”:5}},“binlog”:{“enable”:false,“ignore-error”:false,“write-timeout”:“15s”,“binlog-socket”:"",“strategy”:“range”},“compatible-kill-query”:false,“plugin”:{“dir”:"",“load”:""},“pessimistic-txn”:{“enable”:true,“max-retry-count”:256},“check-mb4-value-in-utf8”:true,“max-index-length”:3072,“alter-primary-key”:false,“treat-old-version-utf8-as-utf8mb4”:true,“enable-table-lock”:false,“delay-clean-table-lock”:0,“split-region-max-num”:1000,“stmt-summary”:{“enable”:true,“enable-internal-query”:false,“max-stmt-count”:200,“max-sql-length”:4096,“refresh-interval”:1800,“history-size”:24},“repair-mode”:false,“repair-table-list”:[],“isolation-read”:{“engines”:[“tikv”,“tiflash”,“tidb”]},“max-server-connections”:0,“new_collations_enabled_on_first_bootstrap”:false,“experimental”:{“allow-auto-random”:false,“allow-expression-index”:false}}"]

longge93 · 2020 年6 月 16 日 06:47

返回结果很小，是一个多表的JOIN，但是返回结果只是一条数据。

来了老弟 · 2020 年6 月 16 日 06:49

将 explain analyze select 返回贴出来看下，可能是在该 sql 语句执行时，内存使用超出了限制。

longge93 · 2020 年6 月 16 日 06:54

目测内存应该不至于溢出，表都很小，一万条左右，join一下，不至于超出内存限制的。

来了老弟 · 2020 年6 月 16 日 07:23

非常感谢你的反馈，请问该 sql 执行是偶发还是必现的问题？

可否提供下脱敏表结构和 sql 语句这边复现下。
提供下各个组件的版本。感谢

./bin/tidb-server -V
./bin/tikv-server -V
./bin/pd-server -V

longge93 · 2020 年6 月 17 日 11:46

偶发

组件版本：
TIDB：

[tidb@localhost bin]$ ./tidb-server -V
Release Version: v4.0.0
Edition: Community
Git Commit Hash: 689a6b6439ae7835947fcaccf329a3fc303986cb
Git Branch: heads/refs/tags/v4.0.1
UTC Build Time: 2020-06-12 06:01:55
GoVersion: go1.13
Race Enabled: false
TiKV Min Version: v3.0.0-60965b006877ca7234adaced7890d7b029ed1306
Check Table Before Drop: false

pd-server:

[tidb@localhost bin]$ ./pd-server -V
Release Version: v4.0.1
Edition: Community
Git Commit Hash: 30f0b014b7ff3cd1b5f041bf7ce73448dc0d0fe8
Git Branch: heads/refs/tags/v4.0.1
UTC Build Time:  2020-06-12 05:38:34

tikv-server:

[root@localhost22 bin]# ./tikv-server -V
TiKV 
Release Version:   4.0.1
Edition:           Community
Git Commit Hash:   78d7a854026962669ceb2ee0ac343a5e88faa310
Git Commit Branch: heads/refs/tags/v4.0.1
UTC Build Time:    2020-06-12 09:13:05
Rust Version:      rustc 1.42.0-nightly (0de96d37f 2019-12-19)
Enable Features:   jemalloc portable sse protobuf-codec
Profile:           dist_release

表结构稍后发

来了老弟 · 2020 年6 月 17 日 13:48

ok，稍后辛苦补一下表结构和 sql 语句

Hacker_Rc5f1tYG · 2020 年11 月 13 日 06:18

你好，我们也遇到类似情况，请问如何解决呢？

john402 · 2021 年1 月 20 日 05:45

您好，类似问题我们也遇到过，是偶发性的。
$ tiup cluster list
Found cluster newer version:

The latest version:         v1.3.1
Local installed version:    v1.2.5
Update current component:   tiup update cluster
Update all components:      tiup update --all

Starting component cluster: /home/tidb/.tiup/components/cluster/v1.2.5/tiup-cluster list
Name User Version Path PrivateKey

tidb-pro tidb v4.0.4 /home/tidb/.tiup/storage/cluster/clusters/tidb-pro /home/tidb/.tiup/storage/cluster/clusters/tidb-pro/ssh/id_rsa

应用服务报错信息：
invalid memory address or nil pointer dereference

[2021-01-19T08:41:22.911] [INFO] console - { Error: ER_UNKNOWN_ERROR: runtime error: invalid memory address or nil pointer dereference
at Query.Sequence._packetToError (/home/APP/yujiang.Foil.Node.Npm/win64-node8.15.1/mysql/lib/protocol/sequences/Sequence.js:47:14)
at Query.ErrorPacket (/home/APP/yujiang.Foil.Node.Npm/win64-node8.15.1/mysql/lib/protocol/sequences/Query.js:77:18)
at Protocol._parsePacket (/home/APP/yujiang.Foil.Node.Npm/win64-node8.15.1/mysql/lib/protocol/Protocol.js:278:23)
at Parser.write (/home/APP/yujiang.Foil.Node.Npm/win64-node8.15.1/mysql/lib/protocol/Parser.js:76:12)
at Protocol.write (/home/APP/yujiang.Foil.Node.Npm/win64-node8.15.1/mysql/lib/protocol/Protocol.js:38:16)
at Socket. (/home/APP/yujiang.Foil.Node.Npm/win64-node8.15.1/mysql/lib/Connection.js:91:28)
at Socket. (/home/APP/yujiang.Foil.Node.Npm/win64-node8.15.1/mysql/lib/Connection.js:502:10)
at emitOne (events.js:116:13)
at Socket.emit (events.js:211:7)
at addChunk (_stream_readable.js:263:12)
--------------------
at Protocol._enqueue (/home/APP/yujiang.Foil.Node.Npm/win64-node8.15.1/mysql/lib/protocol/Protocol.js:144:48)
at PoolConnection.query (/home/APP/yujiang.Foil.Node.Npm/win64-node8.15.1/mysql/lib/Connection.js:200:25)
at doQuery (/home/APP/yujiang.Foil.Node/src/yjDBService.engine.mysql.js:475:24)
at success (/home/APP/yujiang.Foil.Node/src/yjDBService.engine.mysql.js:466:9)
at Object.exports.safeSuccess (/home/APP/yujiang.Foil.Node/src/yjError.js13)
at Object.exports.handleResult (/home/APP/yujiang.Foil.Node/src/yjError.js:154:12)
at /home/APP/yujiang.Foil.Node/src/yjDBService.engine.mysql.js:90:11
at Ping.onOperationComplete (/home/APP/yujiang.Foil.Node.Npm/win64-node8.15.1/mysql/lib/Pool.js:110:5)
at bound (domain.js:301:14)
at Ping.runBound [as _callback] (domain.js:314:12)
code: ‘ER_UNKNOWN_ERROR’,
errno: 1105,
sqlMessage: ‘runtime error: invalid memory address or nil pointer dereference’,
sqlState: ‘HY000’,
index: 0,
sql: ’ select SQL_CALC_FOUND_ROWS p1.,(case when p3.GreenhousesSystemParentOID is null then 0 else count() end) as childrenCount,Re_SI.ReSystemIDCOID,Re_SI.IDCOID from Gre
enhousesSystem as p1 left outer join GreenhousesSystem as p3 on p1.GreenhousesSystemOID=p3.GreenhousesSystemParentOID left join Re_systemIDCOID Re_SI on Re_SI.GreenhousesSystemOID=p1.GreenhousesSystemOID where p1.GreenhousesSystemParentOID='4' group by p1.GreenhousesSystemOID Order By GreenhousesSystemOID asc;SELECT FOUND_ROWS() as Total;', url: ‘/biz/iAGS/more/morechild/systemManage/getDeviceSystem?id=4&page=1&rows=10&sort=GreenhousesSystemOID&order=asc&isLoadChildren=true&IDCOID=50’ }

注：单独执行sql语句时没有报错。

zhimadi · 2021 年2 月 10 日 02:38

您好，类似问题我们也遇到过，是偶发性的。V4.0.9版本，请问怎么解决？