Dian Fu created FLINK-19489:
------------------------------- Summary: SplitFetcherTest.testNotifiesWhenGoingIdleConcurrent gets stuck Key: FLINK-19489 URL: https://issues.apache.org/jira/browse/FLINK-19489 Project: Flink Issue Type: Improvement Components: Connectors / Common Affects Versions: 1.12.0 Reporter: Dian Fu https://dev.azure.com/apache-flink/apache-flink/_build/results?buildId=7158&view=logs&j=298e20ef-7951-5965-0e79-ea664ddc435e&t=b4cd3436-dbe8-556d-3bca-42f92c3cbf2f {code} 020-10-01T21:55:34.9982203Z "main" #1 prio=5 os_prio=0 cpu=1048.80ms elapsed=921.99s tid=0x00007f8c00015800 nid=0xf6e in Object.wait() [0x00007f8c06648000] 2020-10-01T21:55:34.9982807Z java.lang.Thread.State: WAITING (on object monitor) 2020-10-01T21:55:34.9983177Z at java.lang.Object.wait(java.base@11.0.7/Native Method) 2020-10-01T21:55:34.9983871Z - waiting on <0x000000008e0be190> (a org.apache.flink.connector.base.source.reader.fetcher.SplitFetcherTest$QueueDrainerThread) 2020-10-01T21:55:34.9984581Z at java.lang.Thread.join(java.base@11.0.7/Thread.java:1305) 2020-10-01T21:55:34.9985433Z - waiting to re-lock in wait() <0x000000008e0be190> (a org.apache.flink.connector.base.source.reader.fetcher.SplitFetcherTest$QueueDrainerThread) 2020-10-01T21:55:34.9985998Z at org.apache.flink.core.testutils.CheckedThread.trySync(CheckedThread.java:112) 2020-10-01T21:55:34.9986511Z at org.apache.flink.core.testutils.CheckedThread.sync(CheckedThread.java:100) 2020-10-01T21:55:34.9987004Z at org.apache.flink.core.testutils.CheckedThread.sync(CheckedThread.java:89) 2020-10-01T21:55:34.9987707Z at org.apache.flink.connector.base.source.reader.fetcher.SplitFetcherTest$QueueDrainerThread.shutdown(SplitFetcherTest.java:301) 2020-10-01T21:55:34.9988427Z at org.apache.flink.connector.base.source.reader.fetcher.SplitFetcherTest.testNotifiesWhenGoingIdleConcurrent(SplitFetcherTest.java:131) 2020-10-01T21:55:34.9989025Z at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.7/Native Method) 2020-10-01T21:55:34.9989531Z at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.7/NativeMethodAccessorImpl.java:62) 2020-10-01T21:55:34.9990117Z at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.7/DelegatingMethodAccessorImpl.java:43) 2020-10-01T21:55:34.9990626Z at java.lang.reflect.Method.invoke(java.base@11.0.7/Method.java:566) 2020-10-01T21:55:34.9991078Z at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) 2020-10-01T21:55:34.9991602Z at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) 2020-10-01T21:55:34.9992119Z at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) 2020-10-01T21:55:34.9992749Z at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) 2020-10-01T21:55:34.9993229Z at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) 2020-10-01T21:55:34.9993700Z at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) 2020-10-01T21:55:34.9994202Z at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) 2020-10-01T21:55:34.9994670Z at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) 2020-10-01T21:55:34.9995098Z at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) 2020-10-01T21:55:34.9995524Z at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) 2020-10-01T21:55:34.9995965Z at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) 2020-10-01T21:55:34.9996403Z at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) 2020-10-01T21:55:34.9996816Z at org.junit.runners.ParentRunner.run(ParentRunner.java:363) 2020-10-01T21:55:34.9997268Z at org.junit.runners.Suite.runChild(Suite.java:128) 2020-10-01T21:55:34.9997695Z at org.junit.runners.Suite.runChild(Suite.java:27) 2020-10-01T21:55:34.9998077Z at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) 2020-10-01T21:55:34.9998510Z at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) 2020-10-01T21:55:34.9998941Z at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) 2020-10-01T21:55:34.9999380Z at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) 2020-10-01T21:55:34.9999815Z at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) 2020-10-01T21:55:35.0000226Z at org.junit.runners.ParentRunner.run(ParentRunner.java:363) 2020-10-01T21:55:35.0000662Z at org.apache.maven.surefire.junitcore.JUnitCore.run(JUnitCore.java:55) 2020-10-01T21:55:35.0001190Z at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:137) 2020-10-01T21:55:35.0001746Z at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeLazy(JUnitCoreWrapper.java:119) 2020-10-01T21:55:35.0002432Z at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:87) 2020-10-01T21:55:35.0002974Z at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:75) 2020-10-01T21:55:35.0003797Z at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:158) 2020-10-01T21:55:35.0004349Z at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384) 2020-10-01T21:55:35.0004913Z at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345) 2020-10-01T21:55:35.0005427Z at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126) 2020-10-01T21:55:35.0005900Z at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418) 2020-10-01T21:55:35.0006196Z 2020-10-01T21:55:35.0006585Z "Reference Handler" #2 daemon prio=10 os_prio=0 cpu=0.79ms elapsed=921.95s tid=0x00007f8c0027e800 nid=0xf7b waiting on condition [0x00007f8bd0af1000] 2020-10-01T21:55:35.0007132Z java.lang.Thread.State: RUNNABLE 2020-10-01T21:55:35.0007513Z at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.7/Native Method) 2020-10-01T21:55:35.0008018Z at java.lang.ref.Reference.processPendingReferences(java.base@11.0.7/Reference.java:241) 2020-10-01T21:55:35.0008484Z at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.7/Reference.java:213) 2020-10-01T21:55:35.0008769Z 2020-10-01T21:55:35.0009134Z "Finalizer" #3 daemon prio=8 os_prio=0 cpu=0.48ms elapsed=921.95s tid=0x00007f8c00283000 nid=0xf7d in Object.wait() [0x00007f8bd09f0000] 2020-10-01T21:55:35.0009630Z java.lang.Thread.State: WAITING (on object monitor) 2020-10-01T21:55:35.0009980Z at java.lang.Object.wait(java.base@11.0.7/Native Method) 2020-10-01T21:55:35.0010612Z - waiting on <0x000000008e704170> (a java.lang.ref.ReferenceQueue$Lock) 2020-10-01T21:55:35.0011047Z at java.lang.ref.ReferenceQueue.remove(java.base@11.0.7/ReferenceQueue.java:155) 2020-10-01T21:55:35.0011672Z - waiting to re-lock in wait() <0x000000008e704170> (a java.lang.ref.ReferenceQueue$Lock) 2020-10-01T21:55:35.0012130Z at java.lang.ref.ReferenceQueue.remove(java.base@11.0.7/ReferenceQueue.java:176) 2020-10-01T21:55:35.0012672Z at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.7/Finalizer.java:170) 2020-10-01T21:55:35.0012943Z 2020-10-01T21:55:35.0013322Z "Signal Dispatcher" #4 daemon prio=9 os_prio=0 cpu=0.52ms elapsed=921.94s tid=0x00007f8c00297800 nid=0xf7f runnable [0x0000000000000000] 2020-10-01T21:55:35.0013773Z java.lang.Thread.State: RUNNABLE 2020-10-01T21:55:35.0013975Z 2020-10-01T21:55:35.0014366Z "C2 CompilerThread0" #5 daemon prio=9 os_prio=0 cpu=641.40ms elapsed=921.94s tid=0x00007f8c00299800 nid=0xf80 waiting on condition [0x0000000000000000] 2020-10-01T21:55:35.0014854Z java.lang.Thread.State: RUNNABLE 2020-10-01T21:55:35.0015120Z No compile task 2020-10-01T21:55:35.0015267Z 2020-10-01T21:55:35.0015674Z "C1 CompilerThread0" #15 daemon prio=9 os_prio=0 cpu=491.81ms elapsed=921.94s tid=0x00007f8c0029c000 nid=0xf81 waiting on condition [0x0000000000000000] 2020-10-01T21:55:35.0016145Z java.lang.Thread.State: RUNNABLE 2020-10-01T21:55:35.0016409Z No compile task 2020-10-01T21:55:35.0016558Z 2020-10-01T21:55:35.0016934Z "Sweeper thread" #20 daemon prio=9 os_prio=0 cpu=53.17ms elapsed=921.94s tid=0x00007f8c0029e000 nid=0xf82 runnable [0x0000000000000000] 2020-10-01T21:55:35.0017450Z java.lang.Thread.State: RUNNABLE 2020-10-01T21:55:35.0017688Z 2020-10-01T21:55:35.0018064Z "Service Thread" #21 daemon prio=9 os_prio=0 cpu=0.20ms elapsed=921.90s tid=0x00007f8c00321800 nid=0xf8a runnable [0x0000000000000000] 2020-10-01T21:55:35.0018510Z java.lang.Thread.State: RUNNABLE 2020-10-01T21:55:35.0018710Z 2020-10-01T21:55:35.0019343Z "Common-Cleaner" #22 daemon prio=8 os_prio=0 cpu=2.51ms elapsed=921.89s tid=0x00007f8c0032d000 nid=0xf90 in Object.wait() [0x00007f8ba3ffe000] 2020-10-01T21:55:35.0019861Z java.lang.Thread.State: TIMED_WAITING (on object monitor) 2020-10-01T21:55:35.0020238Z at java.lang.Object.wait(java.base@11.0.7/Native Method) 2020-10-01T21:55:35.0020701Z - waiting on <no object reference available> 2020-10-01T21:55:35.0021178Z at java.lang.ref.ReferenceQueue.remove(java.base@11.0.7/ReferenceQueue.java:155) 2020-10-01T21:55:35.0021880Z - waiting to re-lock in wait() <0x000000008e705d98> (a java.lang.ref.ReferenceQueue$Lock) 2020-10-01T21:55:35.0022450Z at jdk.internal.ref.CleanerImpl.run(java.base@11.0.7/CleanerImpl.java:148) 2020-10-01T21:55:35.0022860Z at java.lang.Thread.run(java.base@11.0.7/Thread.java:834) 2020-10-01T21:55:35.0023273Z at jdk.internal.misc.InnocuousThread.run(java.base@11.0.7/InnocuousThread.java:134) 2020-10-01T21:55:35.0023544Z 2020-10-01T21:55:35.0024207Z "surefire-forkedjvm-command-thread" #23 daemon prio=5 os_prio=0 cpu=14.02ms elapsed=921.83s tid=0x00007f8c003de000 nid=0xf92 runnable [0x00007f8ba3ad5000] 2020-10-01T21:55:35.0024689Z java.lang.Thread.State: RUNNABLE 2020-10-01T21:55:35.0025037Z at java.io.FileInputStream.readBytes(java.base@11.0.7/Native Method) 2020-10-01T21:55:35.0025453Z at java.io.FileInputStream.read(java.base@11.0.7/FileInputStream.java:279) 2020-10-01T21:55:35.0025895Z at java.io.BufferedInputStream.fill(java.base@11.0.7/BufferedInputStream.java:252) 2020-10-01T21:55:35.0026359Z at java.io.BufferedInputStream.read(java.base@11.0.7/BufferedInputStream.java:271) 2020-10-01T21:55:35.0026942Z - locked <0x000000008e707330> (a java.io.BufferedInputStream) 2020-10-01T21:55:35.0027426Z at java.io.DataInputStream.readInt(java.base@11.0.7/DataInputStream.java:392) 2020-10-01T21:55:35.0027979Z at org.apache.maven.surefire.booter.MasterProcessCommand.decode(MasterProcessCommand.java:115) 2020-10-01T21:55:35.0028623Z at org.apache.maven.surefire.booter.CommandReader$CommandRunnable.run(CommandReader.java:391) 2020-10-01T21:55:35.0029053Z at java.lang.Thread.run(java.base@11.0.7/Thread.java:834) 2020-10-01T21:55:35.0029280Z 2020-10-01T21:55:35.0029927Z "surefire-forkedjvm-ping-30s" #24 daemon prio=5 os_prio=0 cpu=847.16ms elapsed=921.75s tid=0x00007f8c00473800 nid=0xf93 waiting on condition [0x00007f8ba35c8000] 2020-10-01T21:55:35.0030448Z java.lang.Thread.State: TIMED_WAITING (parking) 2020-10-01T21:55:35.0030804Z at jdk.internal.misc.Unsafe.park(java.base@11.0.7/Native Method) 2020-10-01T21:55:35.0031430Z - parking to wait for <0x000000008e702fe0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) 2020-10-01T21:55:35.0031930Z at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.7/LockSupport.java:234) 2020-10-01T21:55:35.0032543Z at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(java.base@11.0.7/AbstractQueuedSynchronizer.java:2123) 2020-10-01T21:55:35.0033139Z at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.7/ScheduledThreadPoolExecutor.java:1182) 2020-10-01T21:55:35.0033730Z at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.7/ScheduledThreadPoolExecutor.java:899) 2020-10-01T21:55:35.0034270Z at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.7/ThreadPoolExecutor.java:1054) 2020-10-01T21:55:35.0034751Z at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.7/ThreadPoolExecutor.java:1114) 2020-10-01T21:55:35.0035246Z at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.7/ThreadPoolExecutor.java:628) 2020-10-01T21:55:35.0035671Z at java.lang.Thread.run(java.base@11.0.7/Thread.java:834) 2020-10-01T21:55:35.0035882Z 2020-10-01T21:55:35.0036266Z "process reaper" #25 daemon prio=10 os_prio=0 cpu=278.14ms elapsed=921.73s tid=0x00007f8b94016000 nid=0xf97 waiting on condition [0x00007f8c064d5000] 2020-10-01T21:55:35.0036747Z java.lang.Thread.State: TIMED_WAITING (parking) 2020-10-01T21:55:35.0037150Z at jdk.internal.misc.Unsafe.park(java.base@11.0.7/Native Method) 2020-10-01T21:55:35.0037822Z - parking to wait for <0x000000008e704488> (a java.util.concurrent.SynchronousQueue$TransferStack) 2020-10-01T21:55:35.0038282Z at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.7/LockSupport.java:234) 2020-10-01T21:55:35.0038782Z at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(java.base@11.0.7/SynchronousQueue.java:462) 2020-10-01T21:55:35.0039467Z at java.util.concurrent.SynchronousQueue$TransferStack.transfer(java.base@11.0.7/SynchronousQueue.java:361) 2020-10-01T21:55:35.0039943Z at java.util.concurrent.SynchronousQueue.poll(java.base@11.0.7/SynchronousQueue.java:937) 2020-10-01T21:55:35.0040413Z at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.7/ThreadPoolExecutor.java:1053) 2020-10-01T21:55:35.0040907Z at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.7/ThreadPoolExecutor.java:1114) 2020-10-01T21:55:35.0041393Z at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.7/ThreadPoolExecutor.java:628) 2020-10-01T21:55:35.0041803Z at java.lang.Thread.run(java.base@11.0.7/Thread.java:834) 2020-10-01T21:55:35.0042026Z 2020-10-01T21:55:35.0042516Z "Queue Drainer" #28 prio=10 os_prio=0 cpu=0.95ms elapsed=920.78s tid=0x00007f8c009d6800 nid=0xfb7 waiting on condition [0x00007f8ba22bd000] 2020-10-01T21:55:35.0042993Z java.lang.Thread.State: WAITING (parking) 2020-10-01T21:55:35.0043338Z at jdk.internal.misc.Unsafe.park(java.base@11.0.7/Native Method) 2020-10-01T21:55:35.0043949Z - parking to wait for <0x000000008df00fa8> (a java.util.concurrent.CompletableFuture$Signaller) 2020-10-01T21:55:35.0044408Z at java.util.concurrent.locks.LockSupport.park(java.base@11.0.7/LockSupport.java:194) 2020-10-01T21:55:35.0044887Z at java.util.concurrent.CompletableFuture$Signaller.block(java.base@11.0.7/CompletableFuture.java:1796) 2020-10-01T21:55:35.0045357Z at java.util.concurrent.ForkJoinPool.managedBlock(java.base@11.0.7/ForkJoinPool.java:3128) 2020-10-01T21:55:35.0045830Z at java.util.concurrent.CompletableFuture.waitingGet(java.base@11.0.7/CompletableFuture.java:1823) 2020-10-01T21:55:35.0046742Z at java.util.concurrent.CompletableFuture.get(java.base@11.0.7/CompletableFuture.java:1998) 2020-10-01T21:55:35.0047375Z at org.apache.flink.connector.base.source.reader.synchronization.FutureCompletingBlockingQueue.take(FutureCompletingBlockingQueue.java:235) 2020-10-01T21:55:35.0048103Z at org.apache.flink.connector.base.source.reader.fetcher.SplitFetcherTest$QueueDrainerThread.go(SplitFetcherTest.java:289) 2020-10-01T21:55:35.0048659Z at org.apache.flink.core.testutils.CheckedThread.run(CheckedThread.java:74) 2020-10-01T21:55:35.0048929Z 2020-10-01T21:55:35.0049311Z "Attach Listener" #29 daemon prio=9 os_prio=0 cpu=0.39ms elapsed=0.10s tid=0x00007f8bb4001000 nid=0x1922 waiting on condition [0x0000000000000000] 2020-10-01T21:55:35.0049756Z java.lang.Thread.State: RUNNABLE 2020-10-01T21:55:35.0049952Z 2020-10-01T21:55:35.0050238Z "VM Thread" os_prio=0 cpu=128.10ms elapsed=921.96s tid=0x00007f8c00276800 nid=0xf7a runnable 2020-10-01T21:55:35.0050517Z 2020-10-01T21:55:35.0050805Z "GC Thread#0" os_prio=0 cpu=31.75ms elapsed=921.98s tid=0x00007f8c00041000 nid=0xf72 runnable 2020-10-01T21:55:35.0051086Z 2020-10-01T21:55:35.0051375Z "GC Thread#1" os_prio=0 cpu=27.13ms elapsed=921.35s tid=0x00007f8bc8001000 nid=0xfaa runnable 2020-10-01T21:55:35.0051656Z 2020-10-01T21:55:35.0051947Z "GC Thread#2" os_prio=0 cpu=28.21ms elapsed=921.35s tid=0x00007f8bc8002800 nid=0xfab runnable 2020-10-01T21:55:35.0052230Z 2020-10-01T21:55:35.0052594Z "GC Thread#3" os_prio=0 cpu=29.39ms elapsed=921.35s tid=0x00007f8bc8004000 nid=0xfac runnable 2020-10-01T21:55:35.0052871Z 2020-10-01T21:55:35.0053157Z "GC Thread#4" os_prio=0 cpu=27.78ms elapsed=921.35s tid=0x00007f8bc8005800 nid=0xfad runnable 2020-10-01T21:55:35.0053437Z 2020-10-01T21:55:35.0053722Z "GC Thread#5" os_prio=0 cpu=28.21ms elapsed=921.35s tid=0x00007f8bc8007000 nid=0xfae runnable 2020-10-01T21:55:35.0054000Z 2020-10-01T21:55:35.0054290Z "G1 Main Marker" os_prio=0 cpu=0.88ms elapsed=921.98s tid=0x00007f8c00074800 nid=0xf73 runnable 2020-10-01T21:55:35.0054572Z 2020-10-01T21:55:35.0054851Z "G1 Conc#0" os_prio=0 cpu=0.10ms elapsed=921.98s tid=0x00007f8c00076800 nid=0xf74 runnable 2020-10-01T21:55:35.0055127Z 2020-10-01T21:55:35.0055518Z "G1 Refine#0" os_prio=0 cpu=0.83ms elapsed=921.98s tid=0x00007f8c001aa800 nid=0xf77 runnable 2020-10-01T21:55:35.0055852Z 2020-10-01T21:55:35.0056161Z "G1 Young RemSet Sampling" os_prio=0 cpu=257.38ms elapsed=921.98s tid=0x00007f8c001ac800 nid=0xf78 runnable 2020-10-01T21:55:35.0056683Z "VM Periodic Task Thread" os_prio=0 cpu=657.91ms elapsed=921.90s tid=0x00007f8c00324000 nid=0xf8b waiting on condition 2020-10-01T21:55:35.0056992Z 2020-10-01T21:55:35.0057263Z JNI global refs: 29, weak refs: 0 {code} -- This message was sent by Atlassian Jira (v8.3.4#803005) |
Free forum by Nabble | Edit this page |