知识库

Neo4j debug.log 中 E_COUNT_EXCEEDED 警告消息的解释

本文旨在解释 Neo4j 可以写入其 debug.log 的 E_COUNT_EXCEEDED 警告信息,并提供一些监控和故障排除的选项。

在运行 Neo4j 因果集群时,您可能会在 FOLLOWER 上看到以下错误

021-05-05 20:42:43.349+0530 WARN [o.n.c.c.BatchingMessageHandler] Raft in-queue dropping messages after: E_COUNT_EXCEEDED
2021-05-05 20:42:45.465+0530 INFO [o.n.c.c.BatchingMessageHandler] Raft in-queue not dropping messages anymore. Dropped 771 messages.
2021-05-05 20:42:46.250+0530 WARN [o.n.c.c.BatchingMessageHandler] Raft in-queue dropping messages after: E_COUNT_EXCEEDED
2021-05-05 20:42:48.461+0530 INFO [o.n.c.c.BatchingMessageHandler] Raft in-queue not dropping messages anymore. Dropped 958 messages.
2021-05-05 20:42:49.587+0530 WARN [o.n.c.c.BatchingMessageHandler] Raft in-queue dropping messages after: E_COUNT_EXCEEDED
2021-05-05 20:42:50.829+0530 INFO [o.n.c.c.BatchingMessageHandler] Raft in-queue not dropping messages anymore. Dropped 541 messages.
2021-05-05 20:42:59.392+0530 WARN [o.n.c.c.BatchingMessageHandler] Raft in-queue dropping messages after: E_COUNT_EXCEEDED
2021-05-05 20:42:59.744+0530 INFO [o.n.c.c.BatchingMessageHandler] Raft in-queue not dropping messages anymore. Dropped 163 messages.

您也可能经常看到这些信息

2021-05-05 20:42:59.392+0530 INFO [o.n.c.c.s.CommandApplicationProcess] BatchSize{min=1.0, max=7.0, avg=1.1328449328449361, count=4096}
2021-05-05 20:42:59.398+0530 INFO [o.n.c.c.s.CommandApplicationProcess] BatchSize{min=15.0, max=15.0, avg=15.0, count=1}

BatchSize 信息性消息报告了多个批次已应用,其中包含 >4000 个操作,队列的默认大小为 4096(causal_clustering.state_machine_flush_window_size 参数)。每当我们超出队列大小时,就会看到 E_COUNT_EXCEEDED

实际上,这意味着 Raft 消息正进入队列等待处理,但队列填充的速度快于 Neo4j 处理 Raft 消息的速度。

该队列的大小由 causal_clustering.raft_in_queue_size 设置。在上面的示例中,我们看到队列正在填满。于是消息被丢弃,随后队列被稍微排空以再次接受消息,又再次填满。Neo4j 不断重复此过程。

该问题等同于临时网络分区。它应当能够恢复,但这表明存在性能问题。

E_COUNT_EXCEEDED 警告通常意味着工作负载对集群来说过高。

此外,在 Leader 上,我们可能会观察到这种情况

2021-05-05 20:42:59.658+0530 INFO [o.n.c.c.r.RaftReplicator] Replication attempt 2 to leader MemberId{46531432}: DistributedOperation{content=TransactionRepresentationReplicatedTransaction{tx=PhysicalTransactionRepresentation[masterId:-1,authorId:-1,timeStarted:1620227030656,latestCommittedTxWhenStarted:3999325909,timeCommitted:1620227030657,lockSession:2,additionalHeader:[]commands.length:2}, globalSession=GlobalSession{sessionId=2d76658e-cb25-4d33-b46d-4f163c2e04c4, owner=MemberId{46531432}}, operationId=LocalOperationId{localSessionId=821, sequenceNumber=525762}}
2021-05-05 20:42:59.789 INFO [o.n.c.c.r.RaftReplicator] Replication attempt 2 to leader MemberId{46531432}: DistributedOperation{content=TransactionRepresentationReplicatedTransaction{tx=PhysicalTransactionRepresentation[masterId:-1,authorId:-1,timeStarted:1620227030659,latestCommittedTxWhenStarted:3999325909,timeCommitted:1620227030662,lockSession:2,additionalHeader:[]commands.length:2}, globalSession=GlobalSession{sessionId=2d76658e-cb25-4d33-b46d-4f163c2e04c4, owner=MemberId{46531432}}, operationId=LocalOperationId{localSessionId=218, sequenceNumber=569728}}

这些信息表明 LEADER 无法将 Raft 消息复制到 FOLLOWER(们)。

同样,这表明工作负载对集群来说过高。事务打到 LEADER 上,而 LEADER 随后将这些事务复制到所有 FOLLOWER。复制遵循这里描述的 Raft 协议:https://raft.github.io/raft.pdf

然而,工作负载过大,导致 FOLLOWER 的队列填满,最终使得 LEADER 上的复制丢弃出站消息。

故障排除与监控

首先,诊断此问题可能相当复杂,建议您向 Neo4j 支持提交工单。

在与支持团队合作之前,您可以检查以下领域,寻找瓶颈迹象

1) 磁盘。我们正将 Raft 队列写入磁盘,因此需要确保有足够的 I/O 容量来满足集群的写入需求。建议使用 iostat 监控磁盘。下面的命令可以提供最佳概览

iostat -x -c -d -t 1 600 >> $(hostname -i)-iostat.out

这里最重要的指标是队列深度。队列深度指的是待处理的访问操作数量。我倾向于将长时间内大于 1 的值视为瓶颈的标志。这意味着成员在写入事务和读取数据时都会变慢。

同样,还需要确定相关的 Neo4j 目录映射到哪些设备。例如,dbms.directories.datadbms.directories.transaction.logs.root 将存放在某些设备上,但如果不知道具体设备,就无法判断被饱和的设备是否是我们关注的对象。它们*可能*完全属于其他应用或进程!

技术支持可以就此提供建议,具体取决于设备的类型。

2) 有用于 Raft 消息处理的指标,可帮助洞察哪些环节慢或被阻塞。neo4j.causal_clustering.core.message_processing_delayneo4j.causal_clustering.core.message_processing_timer 在此情形下非常有用。

3) 对事务进行历史监控。建议使用您偏好的监控工具绘制事务数量随时间的变化图。目的是发现可能与问题发生同步的趋势。或许事务数量出现峰值,对应着 E_COUNT_EXCEEDED 的出现?

解决方案

解决方法取决于具体问题所在。

如果问题是由 I/O 瓶颈导致的,可以将 Neo4j 的目录隔离到独立的设备上。例如,您可以将 ~data~transactions 分别置于不同的磁盘。Neo4j 4.2 及更高版本允许运维人员将 Raft 日志放在独立的设备上。

但归根结底,这可能是由于工作负载配置过高,超出了集群的物理资源所致。

© . This site is unofficial and not affiliated with Neo4j, Inc.