生产环境Cassandra节点执行查询时rpc_timeout问题求助

算力阿峰

2026-8-24

Cassandra单节点执行Count查询触发rpc_timeout问题排查

问题现象

生产环境部署3个Cassandra 2.0.9节点，仅其中一个节点（Cassandra 1）在通过cqlsh执行count(*)或特定查询时，持续出现rpc_timeout错误，其余同配置节点运行正常。

查询操作及报错信息

[cqlsh 4.1.1 | Cassandra 2.0.9 | CQL spec 3.1.1 | Thrift protocol 19.39.0]
Use HELP for help.
cqlsh> use xdata;
cqlsh:xdata> select count(*) from blobstore limit 100;
Request did not complete within rpc_timeout.

执行查询时的system.log日志片段

INFO [MemoryMeter:1] 2022-08-03 10:40:10,910 Memtable.java (line 481) CFS(Keyspace='system', ColumnFamily='sstable_activity') liveRatio is 14.607407883739976 (just-counted was 14.607407407407408).  calculation took 2ms for 54 cells
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,061 MessagingService.java (line 857) 1 REQUEST_RESPONSE messages dropped in last 5000ms
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,061 StatusLogger.java (line 55) Pool Name                    Active   Pending      Completed   Blocked  All Time Blocked
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,062 StatusLogger.java (line 70) MutationStage                     0         0           8726         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,062 StatusLogger.java (line 70) RequestResponseStage              0         0         193404         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,062 StatusLogger.java (line 70) ReadRepairStage                   0         0              0         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,062 StatusLogger.java (line 70) ReadStage                         0         0         295316         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,062 StatusLogger.java (line 70) ReplicateOnWriteStage             0         0              0         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,063 StatusLogger.java (line 70) MiscStage                         0         0           2582         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,063 StatusLogger.java (line 70) AntiEntropySessions               0         0           1028         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,063 StatusLogger.java (line 70) HintedHandoff                     0         0            112         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,063 StatusLogger.java (line 70) FlushWriter                       0         0             39         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,063 StatusLogger.java (line 70) MemoryMeter                       0         0             50         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,063 StatusLogger.java (line 70) GossipStage                       0         0         150208         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,063 StatusLogger.java (line 70) CacheCleanupExecutor              0         0              0         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,064 StatusLogger.java (line 70) InternalResponseStage             0         0           4112         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,064 StatusLogger.java (line 70) CompactionExecutor                0         0            271         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,064 StatusLogger.java (line 70) ValidationExecutor                0         0           2582         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,064 StatusLogger.java (line 70) MigrationStage                    0         0              2         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,064 StatusLogger.java (line 70) commitlog_archiver                0         0              0         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,064 StatusLogger.java (line 70) AntiEntropyStage                  0         0          11332         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,064 StatusLogger.java (line 70) PendingRangeCalculator            0         0              3         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,065 StatusLogger.java (line 70) MemtablePostFlusher               0         0           6062         0                 0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,065 StatusLogger.java (line 79) CompactionManager                 0         0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,065 StatusLogger.java (line 81) Commitlog                       n/a         0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,065 StatusLogger.java (line 93) MessagingService                n/a       0/0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,065 StatusLogger.java (line 103) Cache Type                     Size                 Capacity               KeysToSave
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,065 StatusLogger.java (line 105) KeyCache                      13808                104857600                      all
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,065 StatusLogger.java (line 111) RowCache                          0                        0                      all
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,065 StatusLogger.java (line 118) ColumnFamily                Memtable ops,data
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,065 StatusLogger.java (line 121) system.compaction_history              9,3184
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,065 StatusLogger.java (line 121) system.hints                              0,0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,065 StatusLogger.java (line 121) system.IndexInfo                          0,0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,066 StatusLogger.java (line 121) system.schema_columnfamilies                 0,0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,066 StatusLogger.java (line 121) system.schema_triggers                    0,0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,066 StatusLogger.java (line 121) system.NodeIdInfo                         0,0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,066 StatusLogger.java (line 121) system.paxos                              0,0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,066 StatusLogger.java (line 121) system.peer_events                        0,0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,066 StatusLogger.java (line 121) system.range_xfers                        0,0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,066 StatusLogger.java (line 121) system.compactions_in_progress                 0,0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,066 StatusLogger.java (line 121) system.peers                              0,0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,066 StatusLogger.java (line 121) system.schema_keyspaces                   0,0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,066 StatusLogger.java (line 121) system.local                              0,0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,066 StatusLogger.java (line 121) system.sstable_activity             639,23664
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,066 StatusLogger.java (line 121) system.schema_columns                     0,0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,066 StatusLogger.java (line 121) system.batchlog                           0,0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,067 StatusLogger.java (line 121) xdata.blobstore                  127,54400
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,067 StatusLogger.java (line 121) xdata.document                         0,0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,067 StatusLogger.java (line 121) xdata.blobstoremeta             252,121960
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,067 StatusLogger.java (line 121) system_traces.sessions                    0,0
INFO [ScheduledTasks:1] 2022-08-03 10:40:21,067 StatusLogger.java (line 121) system_traces.events                      0,0
INFO [ScheduledTasks:1] 2022-08-03 10:42:13,051 GCInspector.java (line 116) GC for ParNew: 261 ms for 1 collections, 2073077016 used; max is 8482586624

日志关键点分析

消息丢包：日志显示1 REQUEST_RESPONSE messages dropped in last 5000ms，说明节点处理请求响应时存在丢包情况，可能是网络波动或消息队列过载导致。
GC停顿：ParNew GC单次耗时261ms，虽然单看不算特别严重，但如果GC频繁发生，会导致查询线程被阻塞，进而触发超时。
线程池状态：各线程池Pending请求数均为0，说明查询触发时节点没有明显的线程堆积，但count(*)本身是全表扫描操作，对Cassandra资源消耗极大，若该节点数据量更大或磁盘IO性能更差，就会比其他节点更慢。

排查与解决方案

1. 检查数据分布是否倾斜

执行nodetool status xdata查看该节点的token范围和数据负载，确认是否比其他节点承载了更多blobstore表的数据。如果数据倾斜，count查询需要扫描更多数据，自然更容易超时。
若存在倾斜，可通过nodetool move调整token，或新增节点后执行nodetool repair重新平衡数据。

2. 优化JVM GC配置

针对当前GC耗时问题，调整CMS收集器参数，降低GC停顿时间：

-XX:NewRatio=2
-XX:SurvivorRatio=8
-XX:+UseParNewGC
-XX:+UseConcMarkSweepGC
-XX:+CMSParallelRemarkEnabled
-XX:MaxTenuringThreshold=6
-XX:CMSInitiatingOccupancyFraction=70
-XX:+UseCMSInitiatingOccupancyOnly

配置完成后重启节点，通过nodetool gcstats监控GC频率和耗时，确保单次GC停顿不超过rpc_timeout的一半（默认10s，尽量控制在1s以内）。

3. 临时调整rpc_timeout参数

在cassandra.yaml中修改rpc_timeout_in_ms参数，从默认10000ms适当增大到20000ms，重启节点测试。注意这只是临时缓解手段，不能替代根本优化。

4. 替换低效的count(*)查询

Cassandra的count(*)是全表扫描，效率极低，建议采用以下替代方案：

预计算计数：编写定时任务（如用Spark或Python脚本）定期统计并将计数结果存储到单独的汇总表中，查询时直接读取汇总值。
抽样估算：如果不需要精确计数，用select count(*) from blobstore limit 10000进行抽样估算，大幅降低扫描开销。
升级Cassandra版本：高版本（如3.x及以上）对count查询有优化，比如支持物化视图自动同步计数，或更高效的分区扫描机制。

5. 检查磁盘IO与网络状态

用iostat -x 1查看该节点的磁盘读写使用率，如果磁盘IO繁忙（%util接近100%），会导致sstable扫描缓慢，触发超时。可考虑更换高性能磁盘，或调整compaction策略减少IO压力。
用ping和mtr测试该节点与其他节点的网络连通性，排查是否存在丢包、高延迟等问题，必要时联系运维调整网络配置。

6. 手动触发compaction

执行nodetool compact xdata blobstore合并该表的sstable文件，减少扫描时需要打开的文件数量，提升查询效率。注意compaction会消耗大量IO，建议在业务低峰期执行。

内容的提问来源于stack exchange，提问作者Aji Fauzan

生产环境Cassandra节点执行查询时rpc_timeout问题求助

问题现象 #

查询操作及报错信息 #

执行查询时的system.log日志片段 #

日志关键点分析 #

排查与解决方案 #

1. 检查数据分布是否倾斜 #

2. 优化JVM GC配置 #

3. 临时调整rpc_timeout参数 #

4. 替换低效的count(*)查询 #

5. 检查磁盘IO与网络状态 #

6. 手动触发compaction #