tidb内存突增 导致oom

为提高效率,请提供以下信息,问题描述清晰能够更快得到解决:
【 TiDB 使用环境】

【概述】 场景 + 问题概述
经常有overwritten-nodes,NODE_disk_read_latency_more_than_32ms,disk_read_latency_more_than_32ms告警
以及tidb_tikvclient_backoff_seconds_count,TiDB tikvclient_backoff_count error告警

【背景】 做过哪些操作
业务无变化
【现象】 业务和数据库现象
TiDB_memory_abnormal,TiDB heap memory usage is over 10 GB
TiDB_monitor_keep_alive,TiDB monitor_keep_alive error
【问题】 当前遇到的问题
找不出导致tidb OOM的原因
【业务影响】
tidb oom假死
【TiDB 版本】
4.0.9
【应用软件及版本】

【附件】 相关日志及配置信息
查看tidb日志有个binlog的告警
[2021/10/15 23:03:04.722 +08:00] [WARN] [binloginfo.go:127] [“[binloginfo] disable the skipBinlog flag”]

[2021/10/15 23:03:04.722 +08:00] [WARN] [binloginfo.go:153] [“[binloginfo] start waiting for binlog recovering”]

[2021/10/15 23:03:05.222 +08:00] [WARN] [binloginfo.go:161] [“[binloginfo] binlog recovered”]

[2021/10/15 23:03:05.223 +08:00] [WARN] [binloginfo.go:127] [“[binloginfo] disable the skipBinlog flag”]

[2021/10/15 23:03:05.223 +08:00] [WARN] [binloginfo.go:153] [“[binloginfo] start waiting for binlog recovering”]

[2021/10/15 23:03:05.723 +08:00] [WARN] [binloginfo.go:161] [“[binloginfo] binlog recovered”]

[2021/10/15 23:03:05.923 +08:00] [INFO] [coprocessor.go:1034] [“[TIME_COP_PROCESS] resp_time:607.061625ms txnStartTS:428424609216069635 region_id:97140 store_addr:172.18.41.13:20160 kv_process_ms:605 scan_total_write:644049 scan_processed_write:644048 scan_total_data:0 scan_processed_data:0 scan_total_lock:1 scan_processed_lock:0”] [conn=5540497]

[2021/10/15 23:03:18.457 +08:00] [ERROR] [terror.go:271] [“encountered error”] [error=“write tcp xxxxx.11:10080->172.18.251.4:35918: write: broken pipe”] [stack=“github.com/pingcap/parser/terror.Log
\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/pkg/mod/github.com/pingcap/parser@v0.0.0-20201130080042-c3ddfec58248/terror/terror.go:271
github.com/pingcap/tidb/server.writeData
\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/server/http_handler.go:115
github.com/pingcap/tidb/server.ddlHistoryJobHandler.ServeHTTP
\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/server/http_handler.go:1054
github.com/gorilla/mux.(*Router).ServeHTTP
\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/pkg/mod/github.com/gorilla/mux@v1.7.4/mux.go:210
net/http.(*ServeMux).ServeHTTP
\t/usr/local/go/src/net/http/server.go:2387
github.com/pingcap/tidb/server.CorsHandler.ServeHTTP
\t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/server/util.go:432
net/http.serverHandler.ServeHTTP
\t/usr/local/go/src/net/http/server.go:2802
net/http.(*conn).serve
\t/usr/local/go/src/net/http/server.go:1890”]

出现这个告警后 sql开始堵住了 tidb 发生oom
image

  • TiUP Cluster Display 信息
  • TiUP CLuster Edit config 信息

监控(https://metricstool.pingcap.com/)

  • TiDB-Overview Grafana监控

  • TiDB Grafana 监控
    image
    image

  • TiKV Grafana 监控

  • PD Grafana 监控

  • 对应模块日志(包含问题前后 1 小时日志)


若提问为性能优化、故障排查类问题,请下载脚本运行。终端输出的打印结果,请务必全选并复制粘贴上传。

2 个赞

先看看问题时间段的慢SQL,有没有大数量的或较高执行次数的

1 个赞

您好 问题时间段sql慢查询没有明显的增大 比较稳定 请问这个WARN 是什么意思呢,不是很理解
[2021/10/15 23:03:04.722 +08:00] [WARN] [binloginfo.go:127] ["[binloginfo] disable the skipBinlog flag"]

[2021/10/15 23:03:04.722 +08:00] [WARN] [binloginfo.go:153] ["[binloginfo] start waiting for binlog recovering"]

[2021/10/15 23:03:05.222 +08:00] [WARN] [binloginfo.go:161] ["[binloginfo] binlog recovered"]

[2021/10/15 23:03:05.223 +08:00] [WARN] [binloginfo.go:127] ["[binloginfo] disable the skipBinlog flag"]

[2021/10/15 23:03:05.223 +08:00] [WARN] [binloginfo.go:153] ["[binloginfo] start waiting for binlog recovering"]

[2021/10/15 23:03:05.723 +08:00] [WARN] [binloginfo.go:161] ["[binloginfo] binlog recovered"]

2 个赞

目前线上 一个集群是高并发读 一个集群是高并发写入 都出现了tidb oom问题,重启tidb服务恢复正常了 最近几天没再发生了

1 个赞

oom问题可以按照文档排查,或者先设置sql的内存阀值,避免oom

1 个赞

有使用binlog同步吗? 每次oom前都会出现这个吗? CPU、内存 突增时 QPS 有没有增长

1 个赞

你好 我们是按默认配置部署的 没开binlog image 在出现这个binlog的日志时间点 看cpu和内存是开始突增的 挺吻合的 然后就出现大量的慢语句卡住 这个是比较完整的日志。tidb.log (25.1 KB)

2 个赞

你好 当时内存突增很多把主机内存全吃了

1 个赞

限制单个sql的内存使用,如果还出现 就说明是并发或者其他导致的

1 个赞

大佬 日志有看出啥吗

1 个赞

亲 我前面发了个tidb日志 能帮我看看吗 不是很理解
[2021/10/15 23:03:04.722 +08:00] [WARN] [binloginfo.go:127] ["[binloginfo] disable the skipBinlog flag"]

[2021/10/15 23:03:04.722 +08:00] [WARN] [binloginfo.go:153] ["[binloginfo] start waiting for binlog recovering"]

[2021/10/15 23:03:05.222 +08:00] [WARN] [binloginfo.go:161] ["[binloginfo] binlog recovered"]

[2021/10/15 23:03:05.223 +08:00] [WARN] [binloginfo.go:127] ["[binloginfo] disable the skipBinlog flag"]

[2021/10/15 23:03:05.223 +08:00] [WARN] [binloginfo.go:153] ["[binloginfo] start waiting for binlog recovering"]

[2021/10/15 23:03:05.723 +08:00] [WARN] [binloginfo.go:161] ["[binloginfo] binlog recovered"]
这段日志是什么操作 会有啥影响 或者说什么情况会触发这个

1 个赞

开启了binlog?pump?

1 个赞

没开启呢 我看两次集群tidb oom 内存开始突增的时间的时间点都会打印这个日志然后看监控内存开始上涨 之前都没出现过这个 怀疑和这个日志输出有关系 当时是没做啥操作的 两次故障时间都是在晚上23点-1点 相对比较闲时

发一下拓扑

这个时间 是否有备份?

您好 这个是安装时的模版 topology.yaml (8.4 KB)

没做备份

之前有开启过?

https://docs.pingcap.com/zh/tidb/stable/exporting-grafana-snapshots#将-grafana-监控数据导出成快照 把问题时段和前1小时内的overview tikv-detail tidb disk的监控导出下

没呢 一直没开过