Блог

Узлы выходят из строя после перезапуска с ошибкой:

 INFO  [Messaging-EventLoop-3-12] 2021-08-17 11:09:07,845 InboundConnectionInitiator.java:464 - /X.X.46.68:7000(/X.X.46.68:56090)->/X.X.X.77:7000-URGENT_MESSAGES-cdaa1ab9 messaging connection established, version = 12, framing = LZ4, encryption = unencrypted
INFO  [Messaging-EventLoop-3-1] 2021-08-17 11:09:07,867 InboundConnectionInitiator.java:464 - /X.X.86.42:7000(/X.X.86.42:52188)->/X.X.X.77:7000-URGENT_MESSAGES-9c2d74c5 messaging connection established, version = 12, framing = CRC, encryption = unencrypted
ERROR [main] 2021-08-17 11:09:08,523 CassandraDaemon.java:909 - Exception encountered during startup
java.lang.RuntimeException: Unable to gossip with any peers
    at org.apache.cassandra.gms.Gossiper.doShadowRound(Gossiper.java:1801)
    at org.apache.cassandra.service.StorageService.checkForEndpointCollision(StorageService.java:648)
    at org.apache.cassandra.service.StorageService.prepareToJoin(StorageService.java:934)
    at org.apache.cassandra.service.StorageService.initServer(StorageService.java:784)
    at org.apache.cassandra.service.StorageService.initServer(StorageService.java:729)
    at org.apache.cassandra.service.CassandraDaemon.setup(CassandraDaemon.java:420)
    at org.apache.cassandra.service.CassandraDaemon.activate(CassandraDaemon.java:763)
    at org.apache.cassandra.service.CassandraDaemon.main(CassandraDaemon.java:887)
INFO  [StorageServiceShutdownHook] 2021-08-17 11:09:08,530 HintsService.java:220 - Paused hints dispatch
WARN  [StorageServiceShutdownHook] 2021-08-17 11:09:08,531 Gossiper.java:1989 - No local state, state is in silent shutdown, or node hasn't joined, not announcing shutdown
INFO  [StorageServiceShutdownHook] 2021-08-17 11:09:08,531 MessagingService.java:441 - Waiting for messaging service to quiesce
INFO  [Messaging-EventLoop-3-7] 2021-08-17 11:09:08,534 OutboundConnection.java:1150 - /X.X.X.77:7000(/X.X.X.77:52766)->/X.X.X.76:7000-SMALL_MESSAGES-27a82ea6 successfully connected, version = 12, framing = CRC, encryption = unencrypted
INFO  [Messaging-EventLoop-3-8] 2021-08-17 11:09:08,534 OutboundConnection.java:1150 - /X.X.X.77:7000(/X.X.X.77:52768)->/X.X.X.76:7000-LARGE_MESSAGES-762ad3e9 successfully connected, version = 12, framing = CRC, encryption = unencrypted
INFO  [Messaging-EventLoop-3-1] 2021-08-17 11:09:08,535 OutboundConnection.java:1150 - /X.X.X.77:7000(/X.X.X.77:35938)->/X.X.X.40:7000-SMALL_MESSAGES-97e069da successfully connected, version = 12, framing = CRC, encryption = unencrypted

 

Начальные и другие узлы показывают следующее в журнале отладки во время запуска узла:

    ERROR [Messaging-EventLoop-3-2] 2021-08-17 11:09:07,535 OutboundConnection.java:1058 - /X.X.X.116:7000->/X.X.X.77:7000-URGENT_MESSAGES-ef747971 channel in potentially inconsistent state after error; closing
java.lang.IllegalArgumentException: Maximum payload size is 128KiB
    at org.apache.cassandra.net.FrameEncoderCrc.encode(FrameEncoderCrc.java:73)
    at org.apache.cassandra.net.FrameEncoder.write(FrameEncoder.java:134)
    at io.netty.channel.AbstractChannelHandlerContext.invokeWrite0(AbstractChannelHandlerContext.java:717)
    at io.netty.channel.AbstractChannelHandlerContext.invokeWriteAndFlush(AbstractChannelHandlerContext.java:764)
    at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:790)
    at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:758)
    at io.netty.channel.DefaultChannelPipeline.writeAndFlush(DefaultChannelPipeline.java:1020)
    at io.netty.channel.AbstractChannel.writeAndFlush(AbstractChannel.java:299)
    at org.apache.cassandra.net.AsyncChannelPromise.writeAndFlush(AsyncChannelPromise.java:77)
    at org.apache.cassandra.net.OutboundConnection$EventLoopDelivery.doRun(OutboundConnection.java:837)
    at org.apache.cassandra.net.OutboundConnection$Delivery.run(OutboundConnection.java:687)
    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.lang.Thread.run(Thread.java:748)
INFO  [Messaging-EventLoop-3-10] 2021-08-17 11:09:08,540 InboundConnectionInitiator.java:464 - /X.X.X.77:7000(/X.X.X.77:36684)->/X.X.X.116:7000-SMALL_MESSAGES-8ab4a5dc messaging connection established, version = 12, framing = CRC, encryption = unencrypted
INFO  [Messaging-EventLoop-3-11] 2021-08-17 11:09:08,540 InboundConnectionInitiator.java:464 - /X.X.X.77:7000(/X.X.X.77:36686)->/X.X.X.116:7000-LARGE_MESSAGES-7f053d49 messaging connection established, version = 12, framing = CRC, encryption = unencrypted
INFO  [Messaging-EventLoop-3-2] 2021-08-17 11:09:15,680 NoSpamLogger.java:92 - /X.X.X.116:7000->/X.X.X.77:7000-URGENT_MESSAGES-[no-channel] failed to connect
io.netty.channel.AbstractChannel$AnnotatedConnectException: finishConnect(..) failed: Connection refused: /X.X.X.77:7000
Caused by: java.net.ConnectException: finishConnect(..) failed: Connection refused
    at io.netty.channel.unix.Errors.throwConnectException(Errors.java:124)
    at io.netty.channel.unix.Socket.finishConnect(Socket.java:251)
    at io.netty.channel.epoll.AbstractEpollChannel$AbstractEpollUnsafe.doFinishConnect(AbstractEpollChannel.java:673)
    at io.netty.channel.epoll.AbstractEpollChannel$AbstractEpollUnsafe.finishConnect(AbstractEpollChannel.java:650)
    at io.netty.channel.epoll.AbstractEpollChannel$AbstractEpollUnsafe.epollOutReady(AbstractEpollChannel.java:530)
    at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:470)
    at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:378)
    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.lang.Thread.run(Thread.java:748)
INFO  [Messaging-EventLoop-3-2] 2021-08-17 11:09:45,714 NoSpamLogger.java:92 - /X.X.X.116:7000->/X.X.X.77:7000-URGENT_MESSAGES-[no-channel] failed to connect

 

Началось после обновления с 3.10 до 4.0. Не проблема с брандмауэром или плохая конфигурация, так как та же конфигурация работала ранее.

Ни одна из этих ошибок не является ошибкой, поэтому они не являются причиной того, что ваши узлы не перезапускаются.

Первая запись для сплетен заносится в DEBUG журнал, так что это не проблема. Вторая запись для обмена сообщениями регистрируется на INFO уровне, так что это просто информация и не о чем беспокоиться.

Вам необходимо просмотреть system.log и обратить внимание на последние 1 или 2 ERROR записи, потому что они важны для понимания того, почему узлы не смогли перезапуститься. Ваше здоровье!

[ИЗМЕНИТЬ] Эта ошибка указывает на то, что существует проблема с контактом с начальными узлами:

 ERROR [main] 2021-08-17 11:09:08,523 CassandraDaemon.java:909 - Exception encountered during startup
java.lang.RuntimeException: Unable to gossip with any peers
    at org.apache.cassandra.gms.Gossiper.doShadowRound(Gossiper.java:1801)
    at org.apache.cassandra.service.StorageService.checkForEndpointCollision(StorageService.java:648)
    ...
 

В Cassandra 4.0 узлы теперь идентифицируются по сочетанию их IP-порта (CASSANDRA-7544), поэтому убедитесь, что вы соответствующим образом настроили список исходных элементов. Например:

 seed_provider:
    - class_name: org.apache.cassandra.locator.SimpleSeedProvider
      parameters:
          - seeds: "10.1.2.3:7000,10.1.2.4:7000,10.1.2.5:7000"
 

Очень важно, чтобы по крайней мере один из исходных узлов был в рабочем состоянии и работал в полную силу. По этой причине рекомендуется сначала обновить начальные узлы.

Также убедитесь, что между узлами есть сетевое подключение с помощью утилит Linux, таких как nc и. telnet Убедитесь, что трафик между узлами на порту 7000 не блокируется брандмауэрами (например iptables , или firewalld ). Если вы перезагрузили серверы, брандмауэры довольно часто включаются случайно.

[ОБНОВЛЕНИЕ] Убедитесь, что часы на серверах синхронизированы. Если будет слишком много дрейфа, узлы не смогут сплетничать. Ваше здоровье!

Приведенное ниже сообщение об ошибке в вопросе было связано с тем, что размер сообщений о сплетнях, отправляемых при повторном запуске узла, может превышать жесткий предел в большом кластере.

  ERROR [Messaging-EventLoop-3-2] 2021-08-17 11:09:07,535 OutboundConnection.java:1058 - /X.X.X.116:7000->/X.X.X.77:7000-URGENT_MESSAGES-ef747971 channel in potentially inconsistent state after error; closing
java.lang.IllegalArgumentException: Maximum payload size is 128KiB 
 

Это ошибка начиная с версии 4.0-alpha1 и была исправлена в версии 4.0.1. Проверьте CASSANDRA-16877.

Также, если вы видите сообщение журнала, как показано ниже, в одном из начальных узлов, это связано с дрейфом времени между узлами, о котором Эрик упомянул в своем обновленном ответе.

 INFO  [ScheduledTasks:1] 2021-09-10 11:14:26,567 MessagingMetrics.java:206 - GOSSIP_DIGEST_SYN messages were dropped in last 5000 ms: 0 internal and 1 cross node. Mean internal dropped latency: 0 ms and Mean cross-node dropped latency: 15137813 ms