[GEODE-8726] NetstatFunction throws OutOfMemoryError

• Type: Bug
• Status: Open
• Priority: Major
• Resolution: Unresolved
• Affects Version/s: 1.14.0
• Component/s: gfsh
• Labels: GeodeOperationAPI
• Assignee: Unassigned
• Reporter: Dale Emery
• Created: 18/Nov/20 19:50
• Updated: 18/Nov/20 19:51

Description

If the output of lsof is very large, NetstatFunction throws OutOfMemoryError.

An upcoming commit runs distributed tests in parallel outside of docker. If lsof executes while many tests are running on the same machine, its output is very large. NetstatFunction tries to append this output onto a StringBuilder one line at a time. When the StringBuilder attempts to increase the size of its internal buffer, not enough memory is available.

This is essentially a recurrence of GEODE-2488. The fix for that ticket made NetstatFunction more memory efficient, but running the tests in parallel creates an extreme environment where even that added efficiency is not enough.

One possible fix: Write the lsof output to a file instead of to an in-memory StringBuilder.

Example failure:

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 'dunit_suspect-vm2.log' at line 566
 [fatal 2020/11/17 01:53:38.221 UTC <ClientHealthMonitor Thread> tid=86] Uncaught exception in thread Thread[ClientHealthMonitor Thread,5,RMI Runtime]java.lang.OutOfMemoryError: Java heap space at java.base/java.util.Arrays.copyOf(Arrays.java:3745) at java.base/java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:172) at java.base/java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:538) at java.base/java.lang.StringBuilder.append(StringBuilder.java:174) at org.apache.geode.management.internal.cli.functions.NetstatFunction.executeLsof(NetstatFunction.java:178) at org.apache.geode.management.internal.cli.functions.NetstatFunction.executeCommand(NetstatFunction.java:227) at org.apache.geode.management.internal.cli.functions.NetstatFunction.execute(NetstatFunction.java:80) at org.apache.geode.internal.cache.MemberFunctionStreamingMessage.process(MemberFunctionStreamingMessage.java:201) at org.apache.geode.distributed.internal.DistributionMessage.scheduleAction(DistributionMessage.java:376) at org.apache.geode.distributed.internal.DistributionMessage$1.run(DistributionMessage.java:441) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at org.apache.geode.distributed.internal.ClusterOperationExecutors.runUntilShutdown(ClusterOperationExecutors.java:446) at org.apache.geode.distributed.internal.ClusterOperationExecutors.doFunctionExecutionThread(ClusterOperationExecutors.java:381) at org.apache.geode.distributed.internal.ClusterOperationExecutors$$Lambda$240/0x000000084078f040.invoke(Unknown Source) at org.apache.geode.logging.internal.executors.LoggingThreadFactory.lambda$newThread$0(LoggingThreadFactory.java:120) at org.apache.geode.logging.internal.executors.LoggingThreadFactory$$Lambda$230/0x000000084078c840.run(Unknown Source) at java.base/java.lang.Thread.run(Thread.java:834)
 -----------------------------------------------------------------------Found suspect string in 'dunit_suspect-vm2.log' at line 587
 [fatal 2020/11/17 01:53:38.222 UTC <Function Execution Processor2> tid=88] Uncaught exception in thread Thread[Function Execution Processor2,10,RMI Runtime]java.lang.OutOfMemoryError: Java heap space at java.base/java.util.Arrays.copyOf(Arrays.java:3745) at java.base/java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:172) at java.base/java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:538) at java.base/java.lang.StringBuilder.append(StringBuilder.java:174) at org.apache.geode.management.internal.cli.functions.NetstatFunction.executeLsof(NetstatFunction.java:178) at org.apache.geode.management.internal.cli.functions.NetstatFunction.executeCommand(NetstatFunction.java:227) at org.apache.geode.management.internal.cli.functions.NetstatFunction.execute(NetstatFunction.java:80) at org.apache.geode.internal.cache.MemberFunctionStreamingMessage.process(MemberFunctionStreamingMessage.java:201) at org.apache.geode.distributed.internal.DistributionMessage.scheduleAction(DistributionMessage.java:376) at org.apache.geode.distributed.internal.DistributionMessage$1.run(DistributionMessage.java:441) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at org.apache.geode.distributed.internal.ClusterOperationExecutors.runUntilShutdown(ClusterOperationExecutors.java:446) at org.apache.geode.distributed.internal.ClusterOperationExecutors.doFunctionExecutionThread(ClusterOperationExecutors.java:381) at org.apache.geode.distributed.internal.ClusterOperationExecutors$$Lambda$240/0x000000084078f040.invoke(Unknown Source) at org.apache.geode.logging.internal.executors.LoggingThreadFactory.lambda$newThread$0(LoggingThreadFactory.java:120) at org.apache.geode.logging.internal.executors.LoggingThreadFactory$$Lambda$230/0x000000084078c840.run(Unknown Source) at java.base/java.lang.Thread.run(Thread.java:834)
 -----------------------------------------------------------------------Found suspect string in 'dunit_suspect-vm2.log' at line 608
 [error 2020/11/17 01:53:38.245 UTC <Cache Server Acceptor 0.0.0.0/0.0.0.0:43349 local port: 43349> tid=87] Cache server: Unexpected IOException from acceptjava.net.SocketException: Socket closed at java.base/java.net.PlainSocketImpl.socketAccept(Native Method) at java.base/java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:458) at java.base/java.net.ServerSocket.implAccept(ServerSocket.java:565) at java.base/java.net.ServerSocket.accept(ServerSocket.java:533) at org.apache.geode.internal.cache.tier.sockets.AcceptorImpl.accept(AcceptorImpl.java:1277) at org.apache.geode.internal.cache.tier.sockets.AcceptorImpl.run(AcceptorImpl.java:1216) at java.base/java.lang.Thread.run(Thread.java:834)
 -----------------------------------------------------------------------Found suspect string in 'dunit_suspect-vm2.log' at line 618
 [fatal 2020/11/17 01:53:38.247 UTC <Cache Server Acceptor 0.0.0.0/0.0.0.0:43349 local port: 43349> tid=87] Uncaught exception in thread Thread[Cache Server Acceptor 0.0.0.0/0.0.0.0:43349 local port: 43349,5,RMI Runtime]java.lang.OutOfMemoryError: Java heap space at java.base/java.util.Arrays.copyOf(Arrays.java:3745) at java.base/java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:172) at java.base/java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:538) at java.base/java.lang.StringBuilder.append(StringBuilder.java:174) at org.apache.geode.management.internal.cli.functions.NetstatFunction.executeLsof(NetstatFunction.java:178) at org.apache.geode.management.internal.cli.functions.NetstatFunction.executeCommand(NetstatFunction.java:227) at org.apache.geode.management.internal.cli.functions.NetstatFunction.execute(NetstatFunction.java:80) at org.apache.geode.internal.cache.MemberFunctionStreamingMessage.process(MemberFunctionStreamingMessage.java:201) at org.apache.geode.distributed.internal.DistributionMessage.scheduleAction(DistributionMessage.java:376) at org.apache.geode.distributed.internal.DistributionMessage$1.run(DistributionMessage.java:441) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at org.apache.geode.distributed.internal.ClusterOperationExecutors.runUntilShutdown(ClusterOperationExecutors.java:446) at org.apache.geode.distributed.internal.ClusterOperationExecutors.doFunctionExecutionThread(ClusterOperationExecutors.java:381) at org.apache.geode.distributed.internal.ClusterOperationExecutors$$Lambda$240/0x000000084078f040.invoke(Unknown Source) at org.apache.geode.logging.internal.executors.LoggingThreadFactory.lambda$newThread$0(LoggingThreadFactory.java:120) at org.apache.geode.logging.internal.executors.LoggingThreadFactory$$Lambda$230/0x000000084078c840.run(Unknown Source) at java.base/java.lang.Thread.run(Thread.java:834)
 -----------------------------------------------------------------------Found suspect string in 'dunit_suspect-vm0.log' at line 781
 [error 2020/11/17 01:53:50.295 UTC <RMI TCP Connection(5)-10.128.0.33> tid=94] Could not execute "netstat --with-lsof=true --file=/tmp/junit6368474235553216207/junit14401048426744114153/command.log.txt".java.lang.ClassCastException: class org.apache.geode.cache.execute.FunctionInvocationTargetException cannot be cast to class org.apache.geode.management.internal.cli.functions.NetstatFunction$NetstatFunctionResult (org.apache.geode.cache.execute.FunctionInvocationTargetException and org.apache.geode.management.internal.cli.functions.NetstatFunction$NetstatFunctionResult are in unnamed module of loader 'app') at org.apache.geode.management.internal.cli.commands.NetstatCommand.netstat(NetstatCommand.java:149) 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.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:282) at org.apache.geode.management.internal.cli.remote.CommandExecutor.callInvokeMethod(CommandExecutor.java:151) at org.apache.geode.management.internal.cli.remote.CommandExecutor.invokeCommand(CommandExecutor.java:161) at org.apache.geode.management.internal.cli.remote.CommandExecutor.execute(CommandExecutor.java:88) at org.apache.geode.management.internal.cli.remote.CommandExecutor.execute(CommandExecutor.java:71) at org.apache.geode.management.internal.cli.remote.OnlineCommandProcessor.executeCommand(OnlineCommandProcessor.java:135) at org.apache.geode.management.internal.cli.remote.OnlineCommandProcessor.executeCommandReturningJson(OnlineCommandProcessor.java:141) at org.apache.geode.management.internal.beans.MemberMBeanBridge.processCommand(MemberMBeanBridge.java:1237) at org.apache.geode.management.internal.beans.MemberMBean.processCommand(MemberMBean.java:424) 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 sun.reflect.misc.Trampoline.invoke(MethodUtil.java:71) at jdk.internal.reflect.GeneratedMethodAccessor14.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.base/sun.reflect.misc.MethodUtil.invoke(MethodUtil.java:260) at java.management/com.sun.jmx.mbeanserver.ConvertingMethod.invokeWithOpenReturn(ConvertingMethod.java:193) at java.management/com.sun.jmx.mbeanserver.ConvertingMethod.invokeWithOpenReturn(ConvertingMethod.java:175) at java.management/com.sun.jmx.mbeanserver.MXBeanIntrospector.invokeM2(MXBeanIntrospector.java:117) at java.management/com.sun.jmx.mbeanserver.MXBeanIntrospector.invokeM2(MXBeanIntrospector.java:54) at java.management/com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(MBeanIntrospector.java:237) at java.management/com.sun.jmx.mbeanserver.PerInterface.invoke(PerInterface.java:138) at java.management/com.sun.jmx.mbeanserver.MBeanSupport.invoke(MBeanSupport.java:252) at java.management/com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:809) at java.management/com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:801) at java.management/com.sun.jmx.remote.security.MBeanServerAccessController.invoke(MBeanServerAccessController.java:468) at java.management.rmi/javax.management.remote.rmi.RMIConnectionImpl.doOperation(RMIConnectionImpl.java:1466) at java.management.rmi/javax.management.remote.rmi.RMIConnectionImpl$PrivilegedOperation.run(RMIConnectionImpl.java:1307) at java.management.rmi/javax.management.remote.rmi.RMIConnectionImpl.doPrivilegedOperation(RMIConnectionImpl.java:1399) at java.management.rmi/javax.management.remote.rmi.RMIConnectionImpl.invoke(RMIConnectionImpl.java:827) 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 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:89) at org.apache.geode.test.dunit.internal.DUnitLauncher.closeAndCheckForSuspects(DUnitLauncher.java:408) at org.apache.geode.test.dunit.rules.ClusterStartupRule.after(ClusterStartupRule.java:185) at org.apache.geode.test.dunit.rules.ClusterStartupRule.access$100(ClusterStartupRule.java:69) at org.apache.geode.test.dunit.rules.ClusterStartupRule$1.evaluate(ClusterStartupRule.java:140) at org.junit.rules.RunRules.evaluate(RunRules.java:20) at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306) at org.junit.runners.ParentRunner.run(ParentRunner.java:413) 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)