[BEAM-9757] Flake in JavaPortabilityApi precommit

• Type: Bug
• Status: Resolved
• Priority: P1
• Resolution: Not A Problem
• Fix Version/s: Missing
• Component/s: test-failures
• Labels: beam-fixit flake
• Assignee: Unassigned
• Reporter: Kyle Weaver
• Created: 14/Apr/20 16:30
• Updated: 13/Jan/22 21:51
• Resolved: 06/Apr/21 23:30

Description

org.apache.beam.runners.dataflow.worker.util.MemoryMonitorTest.detectGCThrashing

Error Message
java.lang.AssertionError
Stacktrace
java.lang.AssertionError
at org.junit.Assert.fail(Assert.java:87)
at org.junit.Assert.assertTrue(Assert.java:42)
at org.junit.Assert.assertTrue(Assert.java:53)
at org.apache.beam.runners.dataflow.worker.util.MemoryMonitorTest.detectGCThrashing(MemoryMonitorTest.java:93)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:288)
at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:282)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.lang.Thread.run(Thread.java:748)
Standard Error
Apr 13, 2020 11:38:54 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor run
INFO: Memory is used/total/max = 189/1511/1820 MB, GC last/max = 0.00/0.00 %, #pushbacks=0, gc thrashing=false
Apr 13, 2020 11:38:56 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor dumpHeap
WARNING: Heap dumped to /tmp/junit4868537985750235077/junit1782833439507703448/heap_dump.hprof
Apr 13, 2020 11:38:58 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor run
INFO: Memory is used/total/max = 210/1511/1820 MB, GC last/max = 0.00/0.00 %, #pushbacks=0, gc thrashing=false
Apr 13, 2020 11:38:58 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor dumpHeap
WARNING: Heap dumped to /tmp/junit5110608932509920991/junit3762538188841792209/heap_dump.hprof
Apr 13, 2020 11:38:59 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor run
INFO: Memory is used/total/max = 231/1511/1820 MB, GC last/max = 0.00/0.00 %, #pushbacks=0, gc thrashing=false
Apr 13, 2020 11:38:59 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor dumpHeap
WARNING: Heap dumped to /tmp/junit419632844612311154/junit923609148290982010/heap_dump.hprof
Apr 13, 2020 11:38:59 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor tryUploadHeapDumpIfItExists
INFO: Looking for heap dump at /tmp/junit419632844612311154/junit923609148290982010/heap_dump.hprof
Apr 13, 2020 11:38:59 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor tryUploadHeapDumpIfItExists
WARNING: Heap dump /tmp/junit419632844612311154/junit923609148290982010/heap_dump.hprof detected, attempting to upload to GCS
Apr 13, 2020 11:39:00 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor tryUploadHeapDumpIfItExists
WARNING: Heap dump /tmp/junit419632844612311154/junit923609148290982010/heap_dump.hprof uploaded to /tmp/junit419632844612311154/junit2761624807817345489/heap_dumpa8934b66-834c-4c26-8b05-47c995150ef8.hprof
Apr 13, 2020 11:39:00 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor tryUploadHeapDumpIfItExists
INFO: Deleted local heap dump /tmp/junit419632844612311154/junit923609148290982010/heap_dump.hprof
Apr 13, 2020 11:39:00 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor run
INFO: Memory is used/total/max = 247/1511/1820 MB, GC last/max = 120.00/120.00 %, #pushbacks=0, gc thrashing=false
Apr 13, 2020 11:39:00 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor waitForResources
INFO: Waiting for resources for Test2. Memory is used/total/max = 247/1511/1820 MB, GC last/max = 100.00/120.00 %, #pushbacks=1, gc thrashing=true
Apr 13, 2020 11:39:00 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor waitForResources
INFO: Resources granted for Test2. Memory is used/total/max = 247/1511/1820 MB, GC last/max = 0.00/120.00 %, #pushbacks=1, gc thrashing=false
Apr 13, 2020 11:39:00 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor run
INFO: Memory is used/total/max = 257/1511/1820 MB, GC last/max = 0.00/0.00 %, #pushbacks=0, gc thrashing=false
Apr 13, 2020 11:39:03 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor dumpHeap
WARNING: Heap dumped to /tmp/junit8536797963449583216/junit7789550538562597859/heap_dump.hprof
Apr 13, 2020 11:39:07 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor run
INFO: Memory is used/total/max = 259/1511/1820 MB, GC last/max = 4.97/4.97 %, #pushbacks=0, gc thrashing=false
Apr 13, 2020 11:39:07 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor dumpHeap
WARNING: Heap dumped to /tmp/junit8536797963449583216/junit7789550538562597859/heap_dump.hprof
Apr 13, 2020 11:39:07 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor run
INFO: Memory is used/total/max = 259/1511/1820 MB, GC last/max = 5.25/5.25 %, #pushbacks=0, gc thrashing=false
Apr 13, 2020 11:39:07 PM org.apache.beam.runners.dataflow.worker.util.MemoryMonitor run
INFO: Memory is used/total/max = 260/1511/1820 MB, GC last/max = 5.45/5.45 %, #pushbacks=0, gc thrashing=false