[
https://issues.apache.org/jira/browse/GEODE-6659?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17042081#comment-17042081
]
Kirk Lund commented on GEODE-6659:
----------------------------------
I recently started seeing this stack trace intermittently in dunit tests that
use MembershipManagerHelper.crashDistributedSystem. I’m wondering if
inhibitForcedDisconnectLogging previously suppressed logging this particular
stack trace before I changed Alerting to be asynchronous in a single-threaded
Executor (due to a change in our Log4J dependency). I could add IOException as
an IgnoredException for reconnect tests using that crashDistributedSystem but I
think we may simply want to suppress this stack trace when it is hit from
Alerting.
{noformat}
org.apache.geode.management.JMXMBeanReconnectDUnitTest >
serverMXBeansAreRestoredOnBothLocatorsAfterCrashedServerReturns FAILED
java.lang.AssertionError: Suspicious strings were written to the log during
this run.
Fix the strings or use IgnoredException.addIgnoredException to ignore.
-----------------------------------------------------------------------
Found suspect string in log4j at line 2532
java.io.IOException: Cannot form connection to alert listener
172.17.0.7(locator2:1:locator)<ec><v1>:41002
at
org.apache.geode.internal.tcp.Connection.createSender(Connection.java:998)
at
org.apache.geode.internal.tcp.ConnectionTable.handleNewPendingConnection(ConnectionTable.java:288)
at
org.apache.geode.internal.tcp.ConnectionTable.getSharedConnection(ConnectionTable.java:392)
at
org.apache.geode.internal.tcp.ConnectionTable.get(ConnectionTable.java:567)
at
org.apache.geode.internal.tcp.TCPConduit.getConnection(TCPConduit.java:782)
at
org.apache.geode.distributed.internal.direct.DirectChannel.getConnections(DirectChannel.java:545)
at
org.apache.geode.distributed.internal.direct.DirectChannel.sendToMany(DirectChannel.java:334)
at
org.apache.geode.distributed.internal.direct.DirectChannel.sendToOne(DirectChannel.java:248)
at
org.apache.geode.distributed.internal.direct.DirectChannel.send(DirectChannel.java:604)
at
org.apache.geode.distributed.internal.DistributionImpl.directChannelSend(DistributionImpl.java:348)
at
org.apache.geode.distributed.internal.DistributionImpl.send(DistributionImpl.java:293)
at
org.apache.geode.distributed.internal.ClusterDistributionManager.sendViaMembershipManager(ClusterDistributionManager.java:2061)
at
org.apache.geode.distributed.internal.ClusterDistributionManager.sendOutgoing(ClusterDistributionManager.java:1988)
at
org.apache.geode.distributed.internal.ClusterDistributionManager.sendMessage(ClusterDistributionManager.java:2025)
at
org.apache.geode.distributed.internal.ClusterDistributionManager.putOutgoing(ClusterDistributionManager.java:1085)
at
org.apache.geode.alerting.internal.ClusterAlertMessaging.lambda$null$0(ClusterAlertMessaging.java:92)
at
org.apache.geode.alerting.internal.spi.AlertingAction.execute(AlertingAction.java:34)
at
org.apache.geode.alerting.internal.ClusterAlertMessaging.lambda$sendAlert$1(ClusterAlertMessaging.java:70)
at
java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
{noformat}
> CI failure: DistributedSystemMXBeanWithAlertsDistributedTest >
> managerReceivesAlertsFromAllMembersAtAlertLevelAndAbove cannot send "cache
> closed" message
> ---------------------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: GEODE-6659
> URL: https://issues.apache.org/jira/browse/GEODE-6659
> Project: Geode
> Issue Type: Bug
> Components: core
> Reporter: Dale Emery
> Priority: Major
>
> When the cache is closed during test teardown, it can't get a connection to
> send the "cache closing" message. It then tries to send an alert about that
> failure, and it can't get a connection to send that either. So it throws
> IOException and bails out.
> CI failure:
> [https://concourse.apachegeode-ci.info/teams/main/pipelines/apache-develop-main/jobs/DistributedTestOpenJDK11/builds/624]
> Test results:
> [http://files.apachegeode-ci.info/builds/apache-develop-main/1.10.0-SNAPSHOT.0183/test-results/distributedTest/1555361324/]
> Stack trace:
> {noformat}
> java.lang.AssertionError: Suspicious strings were written to the log during
> this run.
> Fix the strings or use IgnoredException.addIgnoredException to ignore.
> -----------------------------------------------------------------------
> Found suspect string in log4j at line 2457
> [fatal 2019/04/15 19:48:11.076 UTC <RMI TCP Connection(1)-172.17.0.3> tid=34]
> Failed to send message <Alert "Attempting TCP/IP reconnect to
> 172.17.0.3(managerVM:149)<v28>:41001" level WARNING> to member
> <172.17.0.3(managerVM:149)<v28>:41001> view,
> View[172.17.0.3(58:locator)<ec><v0>:41000|31] members:
> [172.17.0.3(58:locator)<ec><v0>:41000,
> 172.17.0.3(managerVM:149)<v28>:41001{lead},
> 172.17.0.3(memberVM-1:153)<v29>:41002, 172.17.0.3(memberVM-2:158)<v30>:41003,
> 172.17.0.3(memberVM-3:162)<v31>:41004]
> java.io.IOException: Cannot form connection to alert listener
> 172.17.0.3(managerVM:149)<v28>:41001
> at
> org.apache.geode.internal.tcp.Connection.createSender(Connection.java:952)
> at
> org.apache.geode.internal.tcp.ConnectionTable.handleNewPendingConnection(ConnectionTable.java:293)
> at
> org.apache.geode.internal.tcp.ConnectionTable.getSharedConnection(ConnectionTable.java:404)
> at
> org.apache.geode.internal.tcp.ConnectionTable.get(ConnectionTable.java:589)
> at
> org.apache.geode.internal.tcp.TCPConduit.getConnection(TCPConduit.java:824)
> at
> org.apache.geode.distributed.internal.direct.DirectChannel.getConnections(DirectChannel.java:536)
> at
> org.apache.geode.distributed.internal.direct.DirectChannel.sendToMany(DirectChannel.java:326)
> at
> org.apache.geode.distributed.internal.direct.DirectChannel.sendToOne(DirectChannel.java:241)
> at
> org.apache.geode.distributed.internal.direct.DirectChannel.send(DirectChannel.java:595)
> at
> org.apache.geode.distributed.internal.membership.gms.mgr.GMSMembershipManager.directChannelSend(GMSMembershipManager.java:1710)
> at
> org.apache.geode.distributed.internal.membership.gms.mgr.GMSMembershipManager.send(GMSMembershipManager.java:1891)
> at
> org.apache.geode.distributed.internal.ClusterDistributionManager.sendViaMembershipManager(ClusterDistributionManager.java:2852)
> at
> org.apache.geode.distributed.internal.ClusterDistributionManager.sendOutgoing(ClusterDistributionManager.java:2779)
> at
> org.apache.geode.distributed.internal.ClusterDistributionManager.sendMessage(ClusterDistributionManager.java:2816)
> at
> org.apache.geode.distributed.internal.ClusterDistributionManager.putOutgoing(ClusterDistributionManager.java:1526)
> at
> org.apache.geode.internal.alerting.AlertMessaging.sendAlert(AlertMessaging.java:75)
> at
> org.apache.geode.internal.logging.log4j.AlertAppender.sendAlertMessage(AlertAppender.java:187)
> at
> org.apache.geode.internal.logging.log4j.AlertAppender.doAppend(AlertAppender.java:162)
> at
> org.apache.geode.internal.logging.log4j.AlertAppender.lambda$append$0(AlertAppender.java:158)
> at
> org.apache.geode.internal.alerting.AlertingAction.execute(AlertingAction.java:29)
> at
> org.apache.geode.internal.logging.log4j.AlertAppender.append(AlertAppender.java:158)
> at
> org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
> at
> org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
> at
> org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
> at
> org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:464)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:448)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:431)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.logParent(LoggerConfig.java:455)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:450)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:431)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:406)
> at
> org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:63)
> at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:146)
> at
> org.apache.logging.log4j.spi.ExtendedLoggerWrapper.logMessage(ExtendedLoggerWrapper.java:217)
> at
> org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2170)
> at
> org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2125)
> at
> org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2108)
> at
> org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2019)
> at
> org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1890)
> at
> org.apache.logging.log4j.spi.AbstractLogger.warn(AbstractLogger.java:2747)
> at
> org.apache.geode.internal.tcp.TCPConduit.getConnection(TCPConduit.java:792)
> at
> org.apache.geode.distributed.internal.direct.DirectChannel.getConnections(DirectChannel.java:536)
> at
> org.apache.geode.distributed.internal.direct.DirectChannel.sendToMany(DirectChannel.java:326)
> at
> org.apache.geode.distributed.internal.direct.DirectChannel.send(DirectChannel.java:597)
> at
> org.apache.geode.distributed.internal.membership.gms.mgr.GMSMembershipManager.directChannelSend(GMSMembershipManager.java:1710)
> at
> org.apache.geode.distributed.internal.membership.gms.mgr.GMSMembershipManager.send(GMSMembershipManager.java:1891)
> at
> org.apache.geode.distributed.internal.ClusterDistributionManager.sendViaMembershipManager(ClusterDistributionManager.java:2852)
> at
> org.apache.geode.distributed.internal.ClusterDistributionManager.sendOutgoing(ClusterDistributionManager.java:2779)
> at
> org.apache.geode.distributed.internal.ClusterDistributionManager.sendMessage(ClusterDistributionManager.java:2816)
> at
> org.apache.geode.distributed.internal.ClusterDistributionManager.putOutgoing(ClusterDistributionManager.java:1526)
> at
> org.apache.geode.internal.cache.GemFireCacheImpl.close(GemFireCacheImpl.java:2282)
> at
> org.apache.geode.internal.cache.GemFireCacheImpl.close(GemFireCacheImpl.java:1907)
> at
> org.apache.geode.internal.cache.GemFireCacheImpl.close(GemFireCacheImpl.java:1897)
> at
> org.apache.geode.management.DistributedSystemMXBeanWithAlertsDistributedTest.lambda$tearDown$bb17a952$1(DistributedSystemMXBeanWithAlertsDistributedTest.java:153)
> at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.base/java.lang.reflect.Method.invoke(Method.java:566)
> at
> org.apache.geode.test.dunit.internal.MethodInvoker.executeObject(MethodInvoker.java:123)
> at
> org.apache.geode.test.dunit.internal.RemoteDUnitVM.executeMethodOnObject(RemoteDUnitVM.java:69)
> at jdk.internal.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
> at
> java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.base/java.lang.reflect.Method.invoke(Method.java:566)
> at
> java.rmi/sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:359)
> at java.rmi/sun.rmi.transport.Transport$1.run(Transport.java:200)
> at java.rmi/sun.rmi.transport.Transport$1.run(Transport.java:197)
> at java.base/java.security.AccessController.doPrivileged(Native Method)
> at java.rmi/sun.rmi.transport.Transport.serviceCall(Transport.java:196)
> at
> java.rmi/sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:562)
> at
> java.rmi/sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:796)
> at
> java.rmi/sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:677)
> at java.base/java.security.AccessController.doPrivileged(Native Method)
> at
> java.rmi/sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:676)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
> at java.base/java.lang.Thread.run(Thread.java:834)
> at org.junit.Assert.fail(Assert.java:88)
> at
> org.apache.geode.test.dunit.internal.DUnitLauncher.closeAndCheckForSuspects(DUnitLauncher.java:380)
> at
> org.apache.geode.test.dunit.rules.DistributedRule$TearDown.doTearDown(DistributedRule.java:215)
> at
> org.apache.geode.test.dunit.rules.DistributedRule.after(DistributedRule.java:147)
> at
> org.apache.geode.test.dunit.rules.AbstractDistributedRule.afterDistributedTest(AbstractDistributedRule.java:81)
> at
> org.apache.geode.test.dunit.rules.AbstractDistributedRule$1.evaluate(AbstractDistributedRule.java:61)
> at
> org.apache.geode.test.dunit.rules.AbstractDistributedRule$1.evaluate(AbstractDistributedRule.java:59)
> at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
> at org.junit.rules.RunRules.evaluate(RunRules.java:20)
> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
> at
> org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.runTestClass(JUnitTestClassExecutor.java:110)
> at
> org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:58)
> at
> org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:38)
> at
> org.gradle.api.internal.tasks.testing.junit.AbstractJUnitTestClassProcessor.processTestClass(AbstractJUnitTestClassProcessor.java:62)
> at
> org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:51)
> at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:566)
> at
> org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
> at
> org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
> at
> org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
> at
> org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
> at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
> at
> org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:118)
> at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:566)
> at
> org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
> at
> org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
> at
> org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:175)
> at
> org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:157)
> at
> org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:404)
> at
> org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:63)
> at
> org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:46)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
> at
> org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:55)
> at java.lang.Thread.run(Thread.java:834)
> {noformat}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
