You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@geode.apache.org by "Barry Oglesby (JIRA)" <ji...@apache.org> on 2019/02/21 01:41:00 UTC
[jira] [Commented] (GEODE-6435) CI Failure:
SerialGatewaySenderQueueDUnitTest.testCreateMaximumSenders assertion fails
[ https://issues.apache.org/jira/browse/GEODE-6435?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16773584#comment-16773584 ]
Barry Oglesby commented on GEODE-6435:
--------------------------------------
Several threads in vm4 are throwing OutOfMemoryErrors in this test.
{noformat}
[vm4] java.lang.OutOfMemoryError: Java heap space
[vm4] Dumping heap to java_pid367.hprof ...
[vm4] Heap dump file created [558837052 bytes in 1.626 secs]
[vm4] [fatal 2019/02/20 01:51:58.219 UTC <Asynchronous disk writer for region ln-62> tid=0x8ba] Fatal error from asynchronous flusher thread
[vm4] java.lang.OutOfMemoryError: Java heap space
[vm4] [error 2019/02/20 01:51:58.232 UTC <unicast receiver,2e6d9f20266c-48305> tid=0x6ac] JGRP000190: failed receiving packet
[vm4] java.lang.OutOfMemoryError: Java heap space
[vm4] [fatal 2019/02/20 01:51:59.303 UTC <Asynchronous disk writer for region ln-54> tid=0x87a] Fatal error from asynchronous flusher thread
[vm4] java.lang.OutOfMemoryError: Java heap space
[vm4] [fatal 2019/02/20 01:51:59.303 UTC <Asynchronous disk writer for region ln-19> tid=0x760] Fatal error from asynchronous flusher thread
[vm4] java.lang.OutOfMemoryError: Java heap space
[vm4] [fatal 2019/02/20 01:51:59.303 UTC <Asynchronous disk writer for region ln-55> tid=0x882] Fatal error from asynchronous flusher thread
[vm4] java.lang.OutOfMemoryError: Java heap space
[vm4] [fatal 2019/02/20 01:51:59.304 UTC <Asynchronous disk writer for region ln-106> tid=0xa23] Fatal error from asynchronous flusher thread
[vm4] java.lang.OutOfMemoryError: Java heap space
{noformat}
When I run the test on my local machine, it is successful. The difference is that my test runs in ~7 seconds. The failed test took ~10 seconds. This is enough time for the PingTask to run. This creates an additional connection (so it doubles the connections).
A stack trace shows the PingTask creating a Connection:
{noformat}
[vm4] java.lang.Exception: Stack trace
[vm4] at java.base/java.lang.Thread.dumpStack(Thread.java:1387)
[vm4] at org.apache.geode.cache.client.internal.ConnectionImpl.connect(ConnectionImpl.java:112)
[vm4] at org.apache.geode.cache.client.internal.ConnectionConnector.connectClientToServer(ConnectionConnector.java:75)
[vm4] at org.apache.geode.cache.client.internal.ConnectionFactoryImpl.createClientToServerConnection(ConnectionFactoryImpl.java:111)
[vm4] at org.apache.geode.cache.client.internal.pooling.ConnectionManagerImpl.borrowConnection(ConnectionManagerImpl.java:321)
[vm4] at org.apache.geode.cache.client.internal.OpExecutorImpl.executeOnServer(OpExecutorImpl.java:395)
[vm4] at org.apache.geode.cache.client.internal.OpExecutorImpl.executeOn(OpExecutorImpl.java:362)
[vm4] at org.apache.geode.cache.client.internal.PoolImpl.executeOn(PoolImpl.java:835)
[vm4] at org.apache.geode.cache.client.internal.PingOp.execute(PingOp.java:36)
[vm4] at org.apache.geode.cache.client.internal.LiveServerPinger$PingTask.run2(LiveServerPinger.java:90)
[vm4] at org.apache.geode.cache.client.internal.PoolImpl$PoolTask.run(PoolImpl.java:1371)
[vm4] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
[vm4] at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
[vm4] at org.apache.geode.internal.ScheduledThreadPoolExecutorWithKeepAlive$DelegatingScheduledFuture.run(ScheduledThreadPoolExecutorWithKeepAlive.java:276)
[vm4] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[vm4] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[vm4] at java.base/java.lang.Thread.run(Thread.java:834)
{noformat}
In the failed test, there are log messages from the poolTimer threads like below. These are coming from the PingTask threads.
{noformat}
[vm4] [info 2019/02/20 01:51:02.547 UTC <poolTimer-ln-46-4> tid=0xaa0] Socket receive buffer size is 212992 instead of the requested 524288.
[vm4] [info 2019/02/20 01:51:02.547 UTC <poolTimer-ln-46-4> tid=0xaa0] Socket send buffer size is 212992 instead of the requested 524288.
[vm4] [info 2019/02/20 01:51:02.607 UTC <poolTimer-ln-47-4> tid=0xaa1] Socket receive buffer size is 212992 instead of the requested 524288.
[vm4] [info 2019/02/20 01:51:02.608 UTC <poolTimer-ln-47-4> tid=0xaa1] Socket send buffer size is 212992 instead of the requested 524288.
[vm4] [info 2019/02/20 01:51:02.657 UTC <poolTimer-ln-48-4> tid=0xaa2] Socket receive buffer size is 212992 instead of the requested 524288.
[vm4] [info 2019/02/20 01:51:02.657 UTC <poolTimer-ln-48-4> tid=0xaa2] Socket send buffer size is 212992 instead of the requested 524288.
[vm4] [info 2019/02/20 01:51:02.727 UTC <poolTimer-ln-50-6> tid=0xaa4] Socket receive buffer size is 212992 instead of the requested 524288.
[vm4] [info 2019/02/20 01:51:02.727 UTC <poolTimer-ln-50-6> tid=0xaa4] Socket send buffer size is 212992 instead of the requested 524288.
...
{noformat}
If I add a sleep in the test to mimic the CI test run, my test throws the same OutOfMemoryErrors.
This test does not behave the same way in JDK 8. It uses much less memory.
I attached a few charts showing the memory usage in both JDK 8 and JDK 11 with successful and failed tests.
> CI Failure: SerialGatewaySenderQueueDUnitTest.testCreateMaximumSenders assertion fails
> --------------------------------------------------------------------------------------
>
> Key: GEODE-6435
> URL: https://issues.apache.org/jira/browse/GEODE-6435
> Project: Geode
> Issue Type: Bug
> Reporter: Patrick Rhomberg
> Assignee: Barry Oglesby
> Priority: Major
> Attachments: jdk11_OldGen_usedMemory_failure.gif, jdk11_OldGen_usedMemory_success.gif, jdk8_OldGen_usedMemory_success.gif
>
>
> {noformat}
> org.apache.geode.internal.cache.wan.serial.SerialGatewaySenderQueueDUnitTest > testCreateMaximumSenders FAILED
> org.apache.geode.test.dunit.RMIException: While invoking org.apache.geode.internal.cache.wan.serial.SerialGatewaySenderQueueDUnitTest$$Lambda$390/0x0000000840596840.run in VM 2 running on Host 2e6d9f20266c with 8 VMs
> at org.apache.geode.test.dunit.VM.executeMethodOnObject(VM.java:579)
> at org.apache.geode.test.dunit.VM.invoke(VM.java:406)
> at org.apache.geode.internal.cache.wan.serial.SerialGatewaySenderQueueDUnitTest.testCreateMaximumSenders(SerialGatewaySenderQueueDUnitTest.java:370)
> Caused by:
> org.awaitility.core.ConditionTimeoutException: Condition with lambda expression in org.apache.geode.internal.cache.wan.WANTestBase that uses long was not fulfilled within 300 seconds.
> at org.awaitility.core.ConditionAwaiter.await(ConditionAwaiter.java:145)
> at org.awaitility.core.CallableCondition.await(CallableCondition.java:79)
> at org.awaitility.core.CallableCondition.await(CallableCondition.java:27)
> at org.awaitility.core.ConditionFactory.until(ConditionFactory.java:902)
> at org.awaitility.core.ConditionFactory.until(ConditionFactory.java:860)
> at org.apache.geode.internal.cache.wan.WANTestBase.verifyListenerEvents(WANTestBase.java:3542)
> at org.apache.geode.internal.cache.wan.serial.SerialGatewaySenderQueueDUnitTest.lambda$testCreateMaximumSenders$faf964a3$1(SerialGatewaySenderQueueDUnitTest.java:370)
> java.lang.AssertionError: An exception occurred during asynchronous invocation.
> Caused by:
> java.rmi.ConnectIOException: error during JRMP connection establishment; nested exception is:
> java.net.SocketTimeoutException: Read timed out
> Caused by:
> java.net.SocketTimeoutException: Read timed out
> {noformat}
>
> See pipeline failure here:
> [https://concourse.apachegeode-ci.info/teams/main/pipelines/apache-develop-main/jobs/DistributedTestOpenJDK11/builds/413]
> Find test results here:
> [http://files.apachegeode-ci.info/builds/apache-develop-main/1.9.0-SNAPSHOT.0456/test-results/distributedTest/1550631451/]
> Find artifacts here:
> [http://files.apachegeode-ci.info/builds/apache-develop-main/1.9.0-SNAPSHOT.0456/test-artifacts/1550631451/distributedtestfiles-OpenJDK11-1.9.0-SNAPSHOT.0456.tgz]
>
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)