You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@flink.apache.org by "Dian Fu (Jira)" <ji...@apache.org> on 2020/10/02 00:52:00 UTC
[jira] [Created] (FLINK-19489)
SplitFetcherTest.testNotifiesWhenGoingIdleConcurrent gets stuck
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)