日志暴增

[2022/10/12 10:26:38.179 +08:00] [WARN] [collate.go:145] [“Unable to get collator by name, use binCollator instead.”] [name=] [stack=“github.com/pingcap/tidb/util/collate.GetCollator\ \t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/util/collate/collate.go:148\ github.com/pingcap/tidb/types.CompareString\ \t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/types/compare.go:118\ github.com/pingcap/tidb/types.(*Datum).compareBinaryLiteral\ \t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/types/datum.go:772\ngithub.com/pingcap/tidb/types.(*Datum).CompareDatum\ \t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/types/datum.go:592\ngithub.com/pingcap/tidb/statistics.(*sampleItemSorter).Less\ \t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/statistics/sample.go:80\ sort.insertionSort\ \t/usr/local/go/src/sort/sort.go:40\ sort.stable\ \t/usr/local/go/src/sort/sort.go:385\ sort.Stable\ \t/usr/local/go/src/sort/sort.go:378\ngithub.com/pingcap/tidb/statistics.SortSampleItems\ \t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/statistics/sample.go:64\ github.com/pingcap/tidb/statistics.BuildHistAndTopN\ \t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/statistics/builder.go:244\ github.com/pingcap/tidb/executor.(*AnalyzeColumnsExec).subBuildWorker\ \t/home/jenkins/agent/workspace/optimization-build-tidb-linux-amd/go/src/github.com/pingcap/tidb/executor/analyze.go:1330”]

描述问题时候,请按照:
【 TiDB 使用环境】生产环境 /测试/ Poc
【 TiDB 版本】
【遇到的问题】
【复现路径】做过哪些操作出现的问题
【问题现象及影响】

描述,尽可能提供更多有效的背景信息,很多问题在不同的场景、业务下,大家可能提供的建议是不一样的,没有讲清楚只会让大家想帮忙都无从下手~

这类日志在暴增,一会磁盘就满了

[2022/10/12 10:35:17.966 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_PROCESS] resp_time:3.471352099s txnStartTS:436611868457959470 region_id:81356146 store_addr:10.0.254.151:20160 kv_process_ms:2683 kv_wait_ms:781 kv_read_ms:180 processed_versions:9686 total_versions:11253 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:16251 rocksdb_cache_hit_count:39255 rocksdb_read_count:1 rocksdb_read_byte:16327"] [conn=60427]
[2022/10/12 10:35:17.975 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_PROCESS] resp_time:307.0573ms txnStartTS:436611868366209053 region_id:82321774 store_addr:10.0.254.152:20160 kv_process_ms:277 kv_wait_ms:23 kv_read_ms:242 processed_versions:4023 total_versions:4083 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:182 rocksdb_cache_hit_count:52558 rocksdb_read_count:0 rocksdb_read_byte:0"] [conn=60411]
[2022/10/12 10:35:17.975 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_PROCESS] resp_time:1.671915062s txnStartTS:436611868379316297 region_id:82338077 store_addr:10.0.254.151:20160 kv_process_ms:1383 kv_wait_ms:282 kv_read_ms:186 processed_versions:3933 total_versions:3993 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:184 rocksdb_cache_hit_count:51355 rocksdb_read_count:0 rocksdb_read_byte:0"] [conn=60417]
[2022/10/12 10:35:18.000 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_WAIT] resp_time:594.041432ms txnStartTS:436611869296820255 region_id:79305440 store_addr:10.0.254.153:20160 kv_process_ms:0 kv_wait_ms:592 kv_read_ms:0 processed_versions:0 total_versions:0 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:0 rocksdb_cache_hit_count:0 rocksdb_read_count:0 rocksdb_read_byte:0"] [conn=60449]
[2022/10/12 10:35:18.006 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_WAIT] resp_time:600.535469ms txnStartTS:436611869296820255 region_id:78561746 store_addr:10.0.254.153:20160 kv_process_ms:0 kv_wait_ms:598 kv_read_ms:0 processed_versions:3 total_versions:3 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:0 rocksdb_cache_hit_count:40 rocksdb_read_count:0 rocksdb_read_byte:0"] [conn=60449]
[2022/10/12 10:35:18.009 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_PROCESS] resp_time:767.531185ms txnStartTS:436611868929818639 region_id:78671164 store_addr:10.0.254.151:20160 kv_process_ms:212 kv_wait_ms:548 kv_read_ms:3 processed_versions:60 total_versions:67 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:23 rocksdb_cache_hit_count:640 rocksdb_read_count:1 rocksdb_read_byte:2148"] [conn=60433]
[2022/10/12 10:35:18.013 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_PROCESS] resp_time:771.680852ms txnStartTS:436611868929818639 region_id:81840147 store_addr:10.0.254.151:20160 kv_process_ms:221 kv_wait_ms:549 kv_read_ms:4 processed_versions:156 total_versions:175 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:189 rocksdb_cache_hit_count:960 rocksdb_read_count:1 rocksdb_read_byte:5668"] [conn=60433]
[2022/10/12 10:35:18.013 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_PROCESS] resp_time:1.247759311s txnStartTS:436611869296820255 region_id:81840147 store_addr:10.0.254.151:20160 kv_process_ms:872 kv_wait_ms:365 kv_read_ms:272 processed_versions:6368 total_versions:6888 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:2410 rocksdb_cache_hit_count:64844 rocksdb_read_count:0 rocksdb_read_byte:0"] [conn=60449]
[2022/10/12 10:35:18.032 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_PROCESS] resp_time:711.852499ms txnStartTS:436611868929818639 region_id:78671164 store_addr:10.0.254.151:20160 kv_process_ms:204 kv_wait_ms:508 kv_read_ms:3 processed_versions:60 total_versions:69 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:27 rocksdb_cache_hit_count:651 rocksdb_read_count:1 rocksdb_read_byte:3173"] [conn=60433]
[2022/10/12 10:35:18.077 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_PROCESS] resp_time:676.589179ms txnStartTS:436611868929818639 region_id:78671164 store_addr:10.0.254.151:20160 kv_process_ms:216 kv_wait_ms:460 kv_read_ms:9 processed_versions:151 total_versions:182 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:183 rocksdb_cache_hit_count:1112 rocksdb_read_count:2 rocksdb_read_byte:9799"] [conn=60433]
[2022/10/12 10:35:18.083 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_PROCESS] resp_time:683.167256ms txnStartTS:436611868929818639 region_id:81840147 store_addr:10.0.254.151:20160 kv_process_ms:218 kv_wait_ms:464 kv_read_ms:7 processed_versions:196 total_versions:221 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:207 rocksdb_cache_hit_count:1395 rocksdb_read_count:0 rocksdb_read_byte:0"] [conn=60433]

版本: v5.2.3

参考一下这个

[2022/10/12 10:50:09.890 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_PROCESS] resp_time:362.506862ms txnStartTS:436612104702132247 region_id:82311112 store_addr:10.0.5.60:20160 kv_process_ms:312 kv_wait_ms:42 kv_read_ms:125 processed_versions:3878 total_versions:3939 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:187 rocksdb_cache_hit_count:46596 rocksdb_read_count:0 rocksdb_read_byte:0"] [conn=61885]
[2022/10/12 10:50:09.890 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_PROCESS] resp_time:1.804818709s txnStartTS:436612104675917856 region_id:81928694 store_addr:10.0.254.153:20160 kv_process_ms:1515 kv_wait_ms:285 kv_read_ms:160 processed_versions:3861 total_versions:3918 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:171 rocksdb_cache_hit_count:50411 rocksdb_read_count:0 rocksdb_read_byte:0"] [conn=61875]
[2022/10/12 10:50:09.897 +08:00] [INFO] [coprocessor.go:812] ["[TIME_COP_PROCESS] resp_time:1.371839489s txnStartTS:436612104702132241 region_id:82126616 store_addr:10.0.254.151:20160 kv_process_ms:1115 kv_wait_ms:247 kv_read_ms:116 processed_versions:2378 total_versions:2906 rocksdb_delete_skipped_count:0 rocksdb_key_skipped_count:1700 rocksdb_cache_hit_count:25911 rocksdb_read_count:0 rocksdb_read_byte:0"] [conn=61883]

很多信息啊

从日志能看出是什么原因吗

的确有analyze操作,是版本有bug吗

tidb_server节点重启了也不行

关闭日志,或者去排查业务系统的问题

5 个赞

调整一下日志级别

修改日志策略,再排查其他问题

1 个赞

[2022/10/12 10:26:38.179 +08:00] [WARN] [collate.go:145] [“Unable to get collator by name, use binCollator instead.”] [name=]

从这看一直是wran日志级别,避免磁盘满,先改成error,避免打印日志,在排查一下。
我看有人已经发了解决方式了。可以试试

好像情况不一样,我是每天0点会更新统计信息,中午的时候重启过了tidb_server,现在又有更新统计信息的出来了

听说有个命令可以把set global 之后的配置刷新回配置文件里,不知道是哪个命令

什么日志级别

案例学习,谢谢