K8ssandra节点重放Commit Log无响应及HTTP 500问题咨询

我们运行一个3节点Cassandra 4集群，某一时刻其中一个节点出现Commit Log重放，监控显示磁盘吞吐量达17GB，该节点近2分钟无响应，另外两个节点出现连接失败错误。后续发现节点重启由K8ssandra触发，但重启后readiness探针返回HTTP 500错误。针对以下问题进行解答：

1. Commit Log重放的原因是什么？ #

Commit Log重放是Cassandra节点异常重启后的必然操作：

• Cassandra的Commit Log用于持久化尚未刷写到SSTable的写操作，当节点意外宕机（比如无响应被K8ssandra重启、OOMKill、磁盘IO过载导致挂起），重启后必须重放Commit Log中的内容，确保数据一致性。
• 结合现象和日志分析，节点先出现2分钟无响应，大概率是资源瓶颈（磁盘IO、内存、CPU过载）导致节点无法处理请求，K8ssandra通过liveness探针检测到节点异常后触发重启，重启后进入Commit Log重放流程，这期间磁盘吞吐量飙升是因为重放需要大量读取Commit Log并写入数据文件。

2. 如何降低此类节点宕机风险？ #

• 优化资源配置：确保K8s为Cassandra节点分配足够的CPU、内存资源，使用高性能磁盘（如SSD）并保障充足IOPS，避免磁盘成为瓶颈；调整K8s资源限制（requests/limits），防止节点因资源耗尽被驱逐。
• 调整Commit Log参数：根据业务写流量合理设置commitlog_segment_size_in_mb；选择合适的commitlog_sync策略（如periodic配合合理的commitlog_sync_period_in_ms），平衡数据安全性和性能，减少重放时的数据量。
• 优化探针配置：延长readiness探针的initialDelaySeconds，给节点足够的启动和Commit Log重放时间；调整liveness探针的failureThreshold和periodSeconds，避免因短暂响应延迟误触发重启。
• 监控与告警：实时监控节点的磁盘吞吐量、CPU/内存使用率、节点响应时间、集群连接状态，设置阈值告警，提前发现资源瓶颈或节点异常。
• 集群负载优化：确保数据在集群中均匀分布，避免单节点承担过多流量；定期运行nodetool cleanup和nodetool compact，清理冗余数据，减少磁盘压力。

3. HTTP 500错误的原因是什么？ #

从更新日志可以明确原因：

• 节点重启后，Cassandra尚未完全启动完成（日志最后才出现Started Cassandra），此时内部用于探针检查的Unix Socket（/tmp/cassandra.sock）还未就绪，探针请求尝试连接该Socket时被拒绝。
• Readiness探针的作用是检查节点是否已准备好处理请求，当Cassandra处于启动/Commit Log重放阶段时，无法正常响应探针请求，因此返回HTTP 500错误。

相关日志 #

Commit Log重放日志

CommitLog.java:173 - Replaying /opt/cassandra/data/commitlog/CommitLog-7-1674673652744.log

其他节点连接失败日志

NoSpamLogger.java:98 - /20.9.1.45:7000->prod-k8ssandra-seed-service/20.9.0.242:7000-SMALL_MESSAGES-[no-channel] failed to connect
java.nio.channels.ClosedChannelException: null
    at org.apache.cassandra.net.OutboundConnectionInitiator$Handler.channelInactive(OutboundConnectionInitiator.java:248)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241)
    at io.netty.channel.DefaultChannelPipeline$HeadContext.channelInactive(DefaultChannelPipeline.java:1405)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248)
    at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:901)
    at io.netty.channel.AbstractChannel$AbstractUnsafe$8.run(AbstractChannel.java:819)
    at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
    at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
    at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384)
    at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
    at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
    at java.base/java.lang.Thread.run(Unknown Source)

更新日志

INFO  [nioEventLoopGroup-2-2] 2023-01-25 19:07:10,694 Cli.java:617 - address=/127.0.0.6:53027 url=/api/v0/probes/liveness status=200 OK
INFO  [nioEventLoopGroup-2-1] 2023-01-25 19:07:12,698 Cli.java:617 - address=http url=/api/v0/probes/readiness status=500 Internal Server Error
INFO  [epollEventLoopGroup-38-1] 2023-01-25 19:07:20,700 Clock.java:47 - Using native clock for microsecond precision
WARN  [epollEventLoopGroup-38-2] 2023-01-25 19:07:20,701 AbstractBootstrap.java:452 - Unknown channel option 'TCP_NODELAY' for channel '[id: 0x919a5c8b]'
WARN  [epollEventLoopGroup-38-2] 2023-01-25 19:07:20,703 Loggers.java:39 - [s33] Error connecting to Node(endPoint=/tmp/cassandra.sock, hostId=null, hashCode=71aac1d0), trying next node (AnnotatedConnectException: connect(..) failed: Connection refused: /tmp/cassandra.sock)
INFO  [nioEventLoopGroup-2-2] 2023-01-25 19:07:20,703 Cli.java:617 - address=/127.0.0.6:51773 url=/api/v0/probes/readiness status=500 Internal Server Error
INFO  [epollEventLoopGroup-39-1] 2023-01-25 19:07:25,393 Clock.java:47 - Using native clock for microsecond precision
WARN  [epollEventLoopGroup-39-2] 2023-01-25 19:07:25,394 AbstractBootstrap.java:452 - Unknown channel option 'TCP_NODELAY' for channel '[id: 0x80b52436]'
WARN  [epollEventLoopGroup-39-2] 2023-01-25 19:07:25,395 Loggers.java:39 - [s34] Error connecting to Node(endPoint=/tmp/cassandra.sock, hostId=null, hashCode=cc8ec36), trying next node (AnnotatedConnectException: connect(..) failed: Connection refused: /tmp/cassandra.sock)
INFO  [pool-2-thread-1] 2023-01-25 19:07:25,602 LifecycleResources.java:186 - Started Cassandra

内容的提问来源于stack exchange，提问作者Doron Levi