Hazelcast 嵌入式缓存打印了太多日志(目标是这个节点!-> [10.1.8.58]:5701","stack_trace":"<#d3566be0> j.l.IllegalArgumentException...)

Hazelcast embedded cache printing too many logs( Target is this node! -> [10.1.8.58]:5701","stack_trace":"<#d3566be0> j.l.IllegalArgumentException...)

我有一个 spring 引导 2.5 应用程序 spring spring 安全性 5,我在其中使用嵌入式 hazelcast 缓存来支持 spring 会话。此应用程序部署在 openshift 上,有两个 pods,其中相同的应用程序是 运行,因此我使用 hazelcast kubernetes 插件进行服务发现。一切都按预期工作。但是,我可以看到应用程序日志中充斥着以下日志行。 有什么建议 hazelcast 配置有什么问题吗?为什么生成这么多日志行?

生成的日志

10.1.8.58是后来加入集群的第二个pod的IP地址,日志只在这个pod中打印。

{"timestamp":"2021-06-03T19:00:43.732+10:00","app":"my-protected-application","logLevel":"INFO","thread":"hz.silly_gates.priority-generic-operation.thread-0","eventSource":"com.hazelcast.internal.cluster.impl.operations.SplitBrainMergeValidationOp","message":"[10.1.8.58]:5701 [spring-session-cluster] [4.2] Removing null, since it thinks it's already split from this cluster and looking to merge."}
{"timestamp":"2021-06-03T19:00:43.733+10:00","app":"my-protected-application","logLevel":"ERROR","thread":"hz.silly_gates.priority-generic-operation.thread-0","eventSource":"com.hazelcast.internal.cluster.impl.operations.SplitBrainMergeValidationOp","message":"[10.1.8.58]:5701 [spring-session-cluster] [4.2] Target is this node! -> [10.1.8.58]:5701","stack_trace":"<#d3566be0> j.l.IllegalArgumentException: Target is this node! -> [10.1.8.58]:5701\n\tat c.h.s.i.o.i.OutboundResponseHandler.checkTarget(OutboundResponseHandler.java:226)\n\tat c.h.s.i.o.i.OutboundResponseHandler.sendNormalResponse(OutboundResponseHandler.java:125)\n\tat c.h.s.i.o.i.OutboundResponseHandler.sendResponse(OutboundResponseHandler.java:88)\n\tat c.h.s.i.o.Operation.sendResponse(Operation.java:475)\n\tat c.h.s.i.o.i.OperationRunnerImpl.call(OperationRunnerImpl.java:282)\n\tat c.h.s.i.o.i.OperationRunnerImpl.run(OperationRunnerImpl.java:248)\n\tat c.h.s.i.o.i.OperationRunnerImpl.run(OperationRunnerImpl.java:469)\n\tat c.h.s.i.o.i.OperationThread.process(OperationThread.java:197)\n\tat c.h.s.i.o.i.OperationThread.process(OperationThread.java:137)\n\tat c.h.s.i.o.i.OperationThread.executeRun(OperationThread.java:123)\n\tat c.h.i.u.e.HazelcastManagedThread.run(HazelcastManagedThread.java:102)\n"}
{"timestamp":"2021-06-03T19:00:43.734+10:00","app":"my-protected-application","logLevel":"WARN","thread":"hz.silly_gates.priority-generic-operation.thread-0","eventSource":"com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl","message":"[10.1.8.58]:5701 [spring-session-cluster] [4.2] While sending op error... op: com.hazelcast.internal.cluster.impl.operations.SplitBrainMergeValidationOp{serviceName='hz:core:clusterService', identityHash=1017993990, partitionId=-1, replicaIndex=0, callId=324850, invocationTime=1622710843731 (2021-06-03 19:00:43.731), waitTimeout=-1, callTimeout=60000, tenantControl=com.hazelcast.spi.impl.tenantcontrol.NoopTenantControl@0}, error: java.lang.IllegalArgumentException: Target is this node! -> [10.1.8.58]:5701","stack_trace":"<#dbcc9949> j.l.IllegalArgumentException: Target is this node! -> [10.1.8.58]:5701, response: ErrorResponse{callId=324850, urgent=true, cause=java.lang.IllegalArgumentException: Target is this node! -> [10.1.8.58]:5701}\n\tat c.h.s.i.o.i.OutboundResponseHandler.send(OutboundResponseHandler.java:113)\n\tat c.h.s.i.o.i.OutboundResponseHandler.sendResponse(OutboundResponseHandler.java:96)\n\tat c.h.s.i.o.Operation.sendResponse(Operation.java:475)\n\tat c.h.s.i.o.i.OperationRunnerImpl.sendResponseAfterOperationError(OperationRunnerImpl.java:425)\n\tat c.h.s.i.o.i.OperationRunnerImpl.handleOperationError(OperationRunnerImpl.java:419)\n\tat c.h.s.i.o.i.OperationRunnerImpl.run(OperationRunnerImpl.java:253)\n\tat c.h.s.i.o.i.OperationRunnerImpl.run(OperationRunnerImpl.java:469)\n\tat c.h.s.i.o.i.OperationThread.process(OperationThread.java:197)\n\tat c.h.s.i.o.i.OperationThread.process(OperationThread.java:137)\n\tat c.h.s.i.o.i.OperationThread.executeRun(OperationThread.java:123)\n\tat c.h.i.u.e.HazelcastManagedThread.run(HazelcastManagedThread.java:102)\n"}
{"timestamp":"2021-06-03T19:00:43.786+10:00","app":"my-protected-application","logLevel":"INFO","thread":"hz.silly_gates.InvocationMonitorThread","eventSource":"com.hazelcast.spi.impl.operationservice.impl.InvocationMonitor","message":"[10.1.8.58]:5701 [spring-session-cluster] [4.2] Invocations:2 timeouts:1 backup-timeouts:0"}
{"timestamp":"2021-06-03T19:02:43.732+10:00","app":"my-protected-application","logLevel":"INFO","thread":"hz.silly_gates.priority-generic-operation.thread-0","eventSource":"com.hazelcast.internal.cluster.impl.operations.SplitBrainMergeValidationOp","message":"[10.1.8.58]:5701 [spring-session-cluster] [4.2] Removing null, since it thinks it's already split from this cluster and looking to merge."}
{"timestamp":"2021-06-03T19:02:43.733+10:00","app":"my-protected-application","logLevel":"ERROR","thread":"hz.silly_gates.priority-generic-operation.thread-0","eventSource":"com.hazelcast.internal.cluster.impl.operations.SplitBrainMergeValidationOp","message":"[10.1.8.58]:5701 [spring-session-cluster] [4.2] Target is this node! -> [10.1.8.58]:5701","stack_trace":"<#d3566be0> j.l.IllegalArgumentException: Target is this node! -> [10.1.8.58]:5701\n\tat c.h.s.i.o.i.OutboundResponseHandler.checkTarget(OutboundResponseHandler.java:226)\n\tat c.h.s.i.o.i.OutboundResponseHandler.sendNormalResponse(OutboundResponseHandler.java:125)\n\tat c.h.s.i.o.i.OutboundResponseHandler.sendResponse(OutboundResponseHandler.java:88)\n\tat c.h.s.i.o.Operation.sendResponse(Operation.java:475)\n\tat c.h.s.i.o.i.OperationRunnerImpl.call(OperationRunnerImpl.java:282)\n\tat c.h.s.i.o.i.OperationRunnerImpl.run(OperationRunnerImpl.java:248)\n\tat c.h.s.i.o.i.OperationRunnerImpl.run(OperationRunnerImpl.java:469)\n\tat c.h.s.i.o.i.OperationThread.process(OperationThread.java:197)\n\tat c.h.s.i.o.i.OperationThread.process(OperationThread.java:137)\n\tat c.h.s.i.o.i.OperationThread.executeRun(OperationThread.java:123)\n\tat c.h.i.u.e.HazelcastManagedThread.run(HazelcastManagedThread.java:102)\n"}
{"timestamp":"2021-06-03T19:02:43.734+10:00","app":"my-protected-application","logLevel":"WARN","thread":"hz.silly_gates.priority-generic-operation.thread-0","eventSource":"com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl","message":"[10.1.8.58]:5701 [spring-session-cluster] [4.2] While sending op error... op: com.hazelcast.internal.cluster.impl.operations.SplitBrainMergeValidationOp{serviceName='hz:core:clusterService', identityHash=1466719815, partitionId=-1, replicaIndex=0, callId=324859, invocationTime=1622710963731 (2021-06-03 19:02:43.731), waitTimeout=-1, callTimeout=60000, tenantControl=com.hazelcast.spi.impl.tenantcontrol.NoopTenantControl@0}, error: java.lang.IllegalArgumentException: Target is this node! -> [10.1.8.58]:5701","stack_trace":"<#dbcc9949> j.l.IllegalArgumentException: Target is this node! -> [10.1.8.58]:5701, response: ErrorResponse{callId=324859, urgent=true, cause=java.lang.IllegalArgumentException: Target is this node! -> [10.1.8.58]:5701}\n\tat c.h.s.i.o.i.OutboundResponseHandler.send(OutboundResponseHandler.java:113)\n\tat c.h.s.i.o.i.OutboundResponseHandler.sendResponse(OutboundResponseHandler.java:96)\n\tat c.h.s.i.o.Operation.sendResponse(Operation.java:475)\n\tat c.h.s.i.o.i.OperationRunnerImpl.sendResponseAfterOperationError(OperationRunnerImpl.java:425)\n\tat c.h.s.i.o.i.OperationRunnerImpl.handleOperationError(OperationRunnerImpl.java:419)\n\tat c.h.s.i.o.i.OperationRunnerImpl.run(OperationRunnerImpl.java:253)\n\tat c.h.s.i.o.i.OperationRunnerImpl.run(OperationRunnerImpl.java:469)\n\tat c.h.s.i.o.i.OperationThread.process(OperationThread.java:197)\n\tat c.h.s.i.o.i.OperationThread.process(OperationThread.java:137)\n\tat c.h.s.i.o.i.OperationThread.executeRun(OperationThread.java:123)\n\tat c.h.i.u.e.HazelcastManagedThread.run(HazelcastManagedThread.java:102)\n"}
{"timestamp":"2021-06-03T19:02:43.786+10:00","app":"my-protected-application","logLevel":"INFO","thread":"hz.silly_gates.InvocationMonitorThread","eventSource":"com.hazelcast.spi.impl.operationservice.impl.InvocationMonitor","message":"[10.1.8.58]:5701 [spring-session-cluster] [4.2] Invocations:2 timeouts:1 backup-timeouts:0"}
{"timestamp":"2021-06-03T19:04:43.732+10:00","app":"my-protected-application","logLevel":"INFO","thread":"hz.silly_gates.priority-generic-operation.thread-0","eventSource":"com.hazelcast.internal.cluster.impl.operations.SplitBrainMergeValidationOp","message":"[10.1.8.58]:5701 [spring-session-cluster] [4.2] Removing null, since it thinks it's already split from this cluster and looking to merge."}
{"timestamp":"2021-06-03T19:04:43.733+10:00","app":"my-protected-application","logLevel":"ERROR","thread":"hz.silly_gates.priority-generic-operation.thread-0","eventSource":"com.hazelcast.internal.cluster.impl.operations.SplitBrainMergeValidationOp","message":"[10.1.8.58]:5701 [spring-session-cluster] [4.2] Target is this node! -> [10.1.8.58]:5701","stack_trace":"<#d3566be0> j.l.IllegalArgumentException: Target is this node! -> [10.1.8.58]:5701\n\tat c.h.s.i.o.i.OutboundResponseHandler.checkTarget(OutboundResponseHandler.java:226)\n\tat c.h.s.i.o.i.OutboundResponseHandler.sendNormalResponse(OutboundResponseHandler.java:125)\n\tat c.h.s.i.o.i.OutboundResponseHandler.sendResponse(OutboundResponseHandler.java:88)\n\tat c.h.s.i.o.Operation.sendResponse(Operation.java:475)\n\tat c.h.s.i.o.i.OperationRunnerImpl.call(OperationRunnerImpl.java:282)\n\tat c.h.s.i.o.i.OperationRunnerImpl.run(OperationRunnerImpl.java:248)\n\tat c.h.s.i.o.i.OperationRunnerImpl.run(OperationRunnerImpl.java:469)\n\tat c.h.s.i.o.i.OperationThread.process(OperationThread.java:197)\n\tat c.h.s.i.o.i.OperationThread.process(OperationThread.java:137)\n\tat c.h.s.i.o.i.OperationThread.executeRun(OperationThread.java:123)\n\tat c.h.i.u.e.HazelcastManagedThread.run(HazelcastManagedThread.java:102)\n"}
{"timestamp":"2021-06-03T19:04:43.733+10:00","app":"my-protected-application","logLevel":"WARN","thread":"hz.silly_gates.priority-generic-operation.thread-0","eventSource":"com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl","message":"[10.1.8.58]:5701 [spring-session-cluster] [4.2] While sending op error... op: com.hazelcast.internal.cluster.impl.operations.SplitBrainMergeValidationOp{serviceName='hz:core:clusterService', identityHash=244619937, partitionId=-1, replicaIndex=0, callId=324868, invocationTime=1622711083731 (2021-06-03 19:04:43.731), waitTimeout=-1, callTimeout=60000, tenantControl=com.hazelcast.spi.impl.tenantcontrol.NoopTenantControl@0}, error: java.lang.IllegalArgumentException: Target is this node! -> [10.1.8.58]:5701","stack_trace":"<#dbcc9949> j.l.IllegalArgumentException: Target is this node! -> [10.1.8.58]:5701, response: ErrorResponse{callId=324868, urgent=true, cause=java.lang.IllegalArgumentException: Target is this node! -> [10.1.8.58]:5701}\n\tat c.h.s.i.o.i.OutboundResponseHandler.send(OutboundResponseHandler.java:113)\n\tat c.h.s.i.o.i.OutboundResponseHandler.sendResponse(OutboundResponseHandler.java:96)\n\tat c.h.s.i.o.Operation.sendResponse(Operation.java:475)\n\tat c.h.s.i.o.i.OperationRunnerImpl.sendResponseAfterOperationError(OperationRunnerImpl.java:425)\n\tat c.h.s.i.o.i.OperationRunnerImpl.handleOperationError(OperationRunnerImpl.java:419)\n\tat c.h.s.i.o.i.OperationRunnerImpl.run(OperationRunnerImpl.java:253)\n\tat c.h.s.i.o.i.OperationRunnerImpl.run(OperationRunnerImpl.java:469)\n\tat c.h.s.i.o.i.OperationThread.process(OperationThread.java:197)\n\tat c.h.s.i.o.i.OperationThread.process(OperationThread.java:137)\n\tat c.h.s.i.o.i.OperationThread.executeRun(OperationThread.java:123)\n\tat c.h.i.u.e.HazelcastManagedThread.run(HazelcastManagedThread.java:102)\n"}
{"timestamp":"2021-06-03T19:04:43.786+10:00","app":"my-protected-application","logLevel":"INFO","thread":"hz.silly_gates.InvocationMonitorThread","eventSource":"com.hazelcast.spi.impl.operationservice.impl.InvocationMonitor","message":"[10.1.8.58]:5701 [spring-session-cluster] [4.2] Invocations:2 timeouts:1 backup-timeouts:0"}

包含的 Maven 依赖项是

<dependency>
    <groupId>com.hazelcast</groupId>
    <artifactId>hazelcast</artifactId>
    <version>4.2</version>
</dependency>
<dependency>
    <groupId>org.springframework.session</groupId>
    <artifactId>spring-session-hazelcast</artifactId>
</dependency>
<dependency>
    <groupId>com.hazelcast</groupId>
    <artifactId>hazelcast-kubernetes</artifactId>
    <version>2.2.2</version>
</dependency>

Kubernetes 服务发现配置如下:

var joinConfig = config.getNetworkConfig().getJoin();
joinConfig.getTcpIpConfig().setEnabled(false);
joinConfig.getMulticastConfig().setEnabled(false);
joinConfig.getKubernetesConfig().setEnabled(true)
                .setProperty("service-dns", "dns-name");

您得到的异常 SplitBrainMergeValidationOp 意味着 Hazelcast 集群可能已经在裂脑中启动,然后试图合并到一个集群中。你能检查一下你是否遵循了所有 Hazelcast Kubernetes recommendations 吗?

特别是检查你是否使用了StatefulSet(不是Deployment)。在 DNS Lookup 发现的情况下,使用 Deployment 可能会导致 Hazelcast 以裂脑模式启动。