binlog 写入报错

jiangdj1992 · 2020 年12 月 1 日 11:57

为提高效率，提问时请提供以下信息，问题描述清晰可优先响应。

【TiDB 版本】：V4.0.0
【问题描述】：
TIDB 日志报错如下， binglog写入失败导致灾备需要重建，最近出现几次，不解决无法使用binlog同步

[2020/11/30 16:44:40.803 +08:00] [INFO] [split_region.go:205] [“split regions complete”] [“region count”=1] [“region IDs”="[83818832]"]
[2020/11/30 16:44:40.803 +08:00] [INFO] [split_region.go:242] [“wait scatter region”] [regionID=83818832] [backoff(ms)=120000]
[2020/11/30 16:44:40.804 +08:00] [INFO] [split_region.go:256] [“wait scatter region”] [regionID=83818832] [reverse=scatter-region] [status=RUNNING]
[2020/11/30 16:44:40.968 +08:00] [INFO] [region_cache.go:772] [“switch region leader to specific leader due to kv return NotLeader”] [regionID=78407281] [currIdx=1] [leaderStoreID=18475091]
[2020/11/30 16:44:41.042 +08:00] [WARN] [client.go:295] ["[pumps client] write binlog to pump failed"] [NodeID=10.223.0.160:8250] [“binlog type”=Prewrite] [“start ts”=421193505041547349] [“committs”=0] [length=2191429992] [error=“rpc error: code = ResourceExhausted desc = trying to send message larger than max (2191430008 vs. 2147483647)”]
[2020/11/30 16:44:41.043 +08:00] [ERROR] [binloginfo.go:253] [“write binlog failed”] [binlog_type=Prewrite] [binlog_start_ts=421193505041547349] [binlog_commit_ts=0] [error=“rpc error: code = ResourceExhausted desc = trying to send message larger than max (2191430008 vs. 2147483647)”]
[2020/11/30 16:44:41.043 +08:00] [ERROR] [binloginfo.go:259] [“write binlog fail but error ignored”]

事务大小配置为1个G ，看历史有相关问题，但是没有解决说明

mysql> show config where name like ‘%txn-total-size-limit%’;
±-----±------------------±---------------------------------±-----------+
| Type | Instance | Name | Value |
±-----±------------------±---------------------------------±-----------+
| tidb | 10.223.1.160:4000 | performance.txn-total-size-limit | 1073741824 |
| tidb | 10.223.1.159:4000 | performance.txn-total-size-limit | 1073741824 |
| tidb | 10.223.2.158:4000 | performance.txn-total-size-limit | 1073741824 |
±-----±------------------±---------------------------------±-----------+

QBin · 2020 年12 月 2 日 02:56

在写入 Prewrite Binlog 的时候是有 2G 的限制的。不建议在开启 Binlog 的时候使用太大事务。

jiangdj1992 · 2020 年12 月 2 日 02:58

最大事务大小我们设置的是1G，日志里的2G是指什么操作呢

jiangdj1992 · 2020 年12 月 2 日 02:58

或者这个参数哪里可以调整，我们自己调整一下

小王同学 · 2020 年12 月 3 日 06:09

目前参数是在代码中写死的，无法修改。建议你们这边修改事务，或者尝试使用 ticdc 同步。没有限制。

jiangdj1992 · 2020 年12 月 3 日 06:11

我们事务是限制到1G, 为什么会出现超过2G的情况呢, 还请麻烦解惑一下

来了老弟 · 2020 年12 月 4 日 03:17

查下应用那边怎么写的？因为这个是 tidb 接收的事务大小。

jiangdj1992 · 2020 年12 月 7 日 02:58

应用那边是一个delete from table where 条件语句,占用内存超过2G. 但是执行状态是成功的

事务限制了1G, 但是这个执行成功了

来了老弟 · 2020 年12 月 7 日 03:23

辛苦在 tikv log 中查找参数 grpc-raft-conn-num 的值是多少？

再将其调整为
server.grpc-raft-conn-num = 3 试下
https://docs.pingcap.com/zh/tidb/stable/tikv-configuration-file#servergrpc-raft-conn-num

jiangdj1992 · 2020 年12 月 7 日 03:46

server.grpc-raft-conn-num 系统是1 , 我看配置文件默认是10, 这个影响什么呢, 我们系统是从2.0->3.0>4.0 升级来的

来了老弟 · 2020 年12 月 7 日 06:16

github.com

pingcap/tiup/blob/a290d33a1d9d4270bbfb67425ad2d45bdc3098d0/examples/topology.example.yaml#L192


# readpool.coprocessor.normal-concurrency: 8
# readpool.coprocessor.low-concurrency: 8
# readpool.coprocessor.max-tasks-per-worker-high: 2000
# readpool.coprocessor.max-tasks-per-worker-normal: 2000
# readpool.coprocessor.max-tasks-per-worker-low: 2000
# server.status-thread-pool-size: 1
# server.grpc-compression-type: "none"
# server.grpc-concurrency: 4
# server.grpc-concurrent-stream: 1024
# server.grpc-memory-pool-quota: "32G"
# server.grpc-raft-conn-num: 1
# server.grpc-stream-initial-window-size: "2MB"
# server.grpc-keepalive-time: "10s"
# server.grpc-keepalive-timeout: "3s"
# server.concurrent-send-snap-limit: 32
# server.concurrent-recv-snap-limit: 32
# server.end-point-recursion-limit: 1000
# server.end-point-request-max-handle-duration: "60s"
# server.snap-max-write-bytes-per-sec: "100MB"
# server.enable-request-batch: true
# #server.request-batch-enable-cross-command: true

server.grpc-raft-conn-num # TiKV 每个实例之间的 gRPC 连接数

可否调整看下

jiangdj1992 · 2020 年12 月 7 日 08:27

这个可以安排调整, 但是这个参数调整是解决了什么问题呢? 禁止执行超过2G的sql,还是可以允许写入2G的binlog到文件记录呢?

来了老弟 · 2020 年12 月 8 日 06:06

解决单个 rpc 最大 2g 的问题。

请问调整后是否可以正常同步。

这个参数咋能理解成「禁止」，connection num。。。。

jiangdj1992 · 2020 年12 月 8 日 11:14

主要是没有联想到这个参数和binlog的2G有什么联系, 所以猜测了一下, 目前还没有调整, 需要安排晚上计划一下,谢谢回复

小王同学 · 2020 年12 月 10 日 06:42

你好，现在问题是否已解决？

jiangdj1992 · 2020 年12 月 10 日 06:47

我在直接部署的新的 v4.0.0环境里没有复现这个问题，目前没测试清楚还没调整

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

好的，了解

jiangdj1992 · 2020 年12 月 12 日 00:57

经测试环境复现 , 修改这个参数没有彻底解决2G限制的问题, 还是会报错,但具体多大内存报错很是疑惑

事务大小限制10G, 执行如上就会报错,此时server.grpc-raft-conn-num = 10, 当server.grpc-raft-conn-num =1或者3 时,如下:

来了老弟 · 2020 年12 月 14 日 02:03

你好，

binlog 的报错信息可否展示下

jiangdj1992 · 2020 年12 月 14 日 03:22

报错信息如下, 这个参数server.grpc-raft-conn-num 调整过1 3 10 64 均不起作用, 开启了binlog和pumps

[2020/12/12 11:55:59.335 +08:00] [INFO] [2pc.go:738] [“prewrite encounters lock”] [conn=1] [lock=“key: {tableID=565, indexID=1, indexValues={1614, 13379533, }}, primary: {tableID=565, indexID=1, indexValues={192, 19985153, }}, txnStartTS: 421460138045734913, lockForUpdateTS:0, ttl: 176759, type: Del”]
[2020/12/12 11:56:00.295 +08:00] [WARN] [client.go:295] ["[pumps client] write binlog to pump failed"] [NodeID=10.20.14.157:8250] [“binlog type”=Prewrite] [“start ts”=421460758016294913] [“committs”=0] [length=2847592820] [error=“rpc error: code = ResourceExhausted desc = trying to send message larger than max (2847592836 vs. 2147483647)”]
[2020/12/12 11:56:00.295 +08:00] [ERROR] [binloginfo.go:253] [“write binlog failed”] [binlog_type=Prewrite] [binlog_start_ts=421460758016294913] [binlog_commit_ts=0] [error=“rpc error: code = ResourceExhausted desc = trying to send message larger than max (2847592836 vs. 2147483647)”]
[2020/12/12 11:56:04.991 +08:00] [INFO] [2pc.go:738] [“prewrite encounters lock”] [conn=1] [lock=“key: {tableID=565, indexID=1, indexValues={53397, 11954017, }}, primary: {tableID=565, indexID=1,indexValues={192, 19985153, }}, txnStartTS: 421460138045734913, lockForUpdateTS:0, ttl: 176759, type: Del”]
[2020/12/12 11:56:04.991 +08:00] [INFO] [2pc.go:738] [“prewrite encounters lock”] [conn=1] [lock=“key: {tableID=565, indexID=1, indexValues={53397, 11954018, }}, primary: {tableID=565, indexID=1,indexValues={192, 19985153, }}, txnStartTS: 421460138045734913, lockForUpdateTS:0, ttl: 176759, type: Del”]