[FLINK-18533] Race condition between task acknowledgement and first heartbeat - ASF JIRA

XML

Word

Printable

JSON

Details

Type: Bug
Status: Closed
Priority: Critical
Resolution: Fixed
Affects Version/s: 1.12.0
Fix Version/s: 1.12.0
Component/s: Runtime / Coordination
Labels:
- pull-request-available
- test-stability

Description

~~FLINK-17075~~ introduced a reconciliation mechanism for detecting missing/unknown deployments.
For this purpose, we begin tracking deployments after the task submission was acknowledged by the TaskExecutor, and match these against the deployments on the TaskExecutor as reported by the heartbeats.

~_{However, TaskManagerGateway#submitTask is not called in the main thread (so it doesn't spend time on serializating the TaskDeploymentDescriptor), and as such the receival of the acknowledgement is also not running in the main thread.}~

For some reason it appears that heartbeat requests sent after the acknowledge can end up being processed before the acknowledge.
This is pretty easy to reproduce by reverting 6e811e6f21e5baa6bfb1862a51815e1d151c7097 and introducing a sleep into the processing of the task submission ackowledgement within Execution#deploy().

As shown in the AccumulatorLiveITCase, this manifests as a task that was just deployed to being canceled.

https://dev.azure.com/apache-flink/apache-flink/_build/results?buildId=4350&view=logs&j=39d5b1d5-3b41-54dc-6458-1e2ddd1cdcf3&t=a99e99c7-21cd-5a1f-7274-585e62b72f56

2020-07-08T21:46:15.4438026Z Printing stack trace of Java process 40159
2020-07-08T21:46:15.4442864Z ==============================================================================
2020-07-08T21:46:15.4475676Z Picked up JAVA_TOOL_OPTIONS: -XX:+HeapDumpOnOutOfMemoryError
2020-07-08T21:46:15.7672746Z 2020-07-08 21:46:15
2020-07-08T21:46:15.7673349Z Full thread dump OpenJDK 64-Bit Server VM (25.242-b08 mixed mode):
2020-07-08T21:46:15.7673590Z 
2020-07-08T21:46:15.7673893Z "Attach Listener" #86 daemon prio=9 os_prio=0 tid=0x00007fef8c025800 nid=0x1b231 runnable [0x0000000000000000]
2020-07-08T21:46:15.7674242Z    java.lang.Thread.State: RUNNABLE
2020-07-08T21:46:15.7674419Z 
2020-07-08T21:46:15.7675150Z "flink-taskexecutor-io-thread-2" #85 daemon prio=5 os_prio=0 tid=0x00007fef9c020000 nid=0xb03a waiting on condition [0x00007fefac1f3000]
2020-07-08T21:46:15.7675964Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7676249Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7680997Z 	- parking to wait for  <0x0000000087180a20> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7681506Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7682009Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7682666Z 	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
2020-07-08T21:46:15.7683100Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7683554Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7684013Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7684371Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7684559Z 
2020-07-08T21:46:15.7685213Z "Flink-DispatcherRestEndpoint-thread-4" #84 daemon prio=5 os_prio=0 tid=0x00007fef90431800 nid=0x9e49 waiting on condition [0x00007fef7df4a000]
2020-07-08T21:46:15.7685665Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7686052Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7686707Z 	- parking to wait for  <0x0000000087180cc0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7687184Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7687721Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7688342Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1088)
2020-07-08T21:46:15.7688935Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
2020-07-08T21:46:15.7689579Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7690451Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7690928Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7691317Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7691502Z 
2020-07-08T21:46:15.7692183Z "Flink-DispatcherRestEndpoint-thread-3" #83 daemon prio=5 os_prio=0 tid=0x00007fefa01e2800 nid=0x9dc9 waiting on condition [0x00007fef7f1f4000]
2020-07-08T21:46:15.7692636Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7692920Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7693647Z 	- parking to wait for  <0x0000000087180cc0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7694105Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7694595Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7695178Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1088)
2020-07-08T21:46:15.7695746Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
2020-07-08T21:46:15.7696445Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7696933Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7697394Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7697794Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7697986Z 
2020-07-08T21:46:15.7698687Z "Flink-DispatcherRestEndpoint-thread-2" #82 daemon prio=5 os_prio=0 tid=0x00007fefa01e1800 nid=0x9d97 waiting on condition [0x00007fef7e34c000]
2020-07-08T21:46:15.7699367Z    java.lang.Thread.State: TIMED_WAITING (parking)
2020-07-08T21:46:15.7699671Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7700328Z 	- parking to wait for  <0x0000000087180cc0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7701040Z 	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
2020-07-08T21:46:15.7701692Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
2020-07-08T21:46:15.7702310Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
2020-07-08T21:46:15.7702916Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
2020-07-08T21:46:15.7703457Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7704029Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7709397Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7709844Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7710036Z 
2020-07-08T21:46:15.7710763Z "Thread-23" #71 prio=5 os_prio=0 tid=0x00007fef81ddc800 nid=0x9d5e waiting on condition [0x00007fef7ebf0000]
2020-07-08T21:46:15.7711170Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7711465Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7712165Z 	- parking to wait for  <0x00000000871812a0> (a java.util.concurrent.CompletableFuture$Signaller)
2020-07-08T21:46:15.7712594Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7713049Z 	at java.util.concurrent.CompletableFuture$Signaller.block(CompletableFuture.java:1707)
2020-07-08T21:46:15.7713499Z 	at java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3323)
2020-07-08T21:46:15.7713957Z 	at java.util.concurrent.CompletableFuture.waitingGet(CompletableFuture.java:1742)
2020-07-08T21:46:15.7714396Z 	at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1908)
2020-07-08T21:46:15.7715121Z 	at org.apache.flink.client.ClientUtils.submitJobAndWaitForResult(ClientUtils.java:107)
2020-07-08T21:46:15.7715618Z 	at org.apache.flink.test.accumulators.AccumulatorLiveITCase$1.go(AccumulatorLiveITCase.java:148)
2020-07-08T21:46:15.7716212Z 	at org.apache.flink.core.testutils.CheckedThread.run(CheckedThread.java:74)
2020-07-08T21:46:15.7716490Z 
2020-07-08T21:46:15.7717251Z "AkkaRpcService-Supervisor-Termination-Future-Executor-thread-1" #70 daemon prio=5 os_prio=0 tid=0x00007fefa401e000 nid=0x9d5c waiting on condition [0x00007fef7eff2000]
2020-07-08T21:46:15.7717761Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7718040Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7718688Z 	- parking to wait for  <0x00000000871814b8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7719174Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7719714Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7720268Z 	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
2020-07-08T21:46:15.7720731Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7721215Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7721689Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7722089Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7722279Z 
2020-07-08T21:46:15.7722934Z "flink-taskexecutor-io-thread-1" #69 daemon prio=5 os_prio=0 tid=0x00007fef9c18b000 nid=0x9d5b waiting on condition [0x00007fef7e74e000]
2020-07-08T21:46:15.7723481Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7723777Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7724461Z 	- parking to wait for  <0x0000000087180a20> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7725025Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7725647Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7726288Z 	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
2020-07-08T21:46:15.7726757Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7727243Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7727719Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7728118Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7728311Z 
2020-07-08T21:46:15.7728915Z "pool-3-thread-1" #68 prio=5 os_prio=0 tid=0x00007fefd8683800 nid=0x9d5a waiting on condition [0x00007fef7e44d000]
2020-07-08T21:46:15.7729425Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7729699Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7730550Z 	- parking to wait for  <0x0000000087181900> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7731026Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7731526Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7732122Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1081)
2020-07-08T21:46:15.7732706Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
2020-07-08T21:46:15.7733225Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7733691Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7734235Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7734622Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7734925Z 
2020-07-08T21:46:15.7735553Z "Flink-MetricRegistry-thread-1" #64 daemon prio=5 os_prio=0 tid=0x00007fef9c10a000 nid=0x9d52 waiting on condition [0x00007fef7ecf1000]
2020-07-08T21:46:15.7736123Z    java.lang.Thread.State: TIMED_WAITING (parking)
2020-07-08T21:46:15.7736411Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7737066Z 	- parking to wait for  <0x0000000087181b80> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7737547Z 	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
2020-07-08T21:46:15.7738100Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
2020-07-08T21:46:15.7738725Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
2020-07-08T21:46:15.7739426Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
2020-07-08T21:46:15.7739947Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7740517Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7740970Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7741454Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7741650Z 
2020-07-08T21:46:15.7742217Z "pool-2-thread-1" #61 prio=5 os_prio=0 tid=0x00007fefa0087000 nid=0x9d4f waiting on condition [0x00007fef7e84f000]
2020-07-08T21:46:15.7742628Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7742979Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7743629Z 	- parking to wait for  <0x0000000087181dc0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7744110Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7744610Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7748719Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1081)
2020-07-08T21:46:15.7749446Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
2020-07-08T21:46:15.7749975Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7750562Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7751005Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7751365Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7751542Z 
2020-07-08T21:46:15.7752400Z "jobmanager-future-thread-2" #58 daemon prio=5 os_prio=0 tid=0x00007fef9c0ff800 nid=0x9d4c waiting on condition [0x00007fef7f2f5000]
2020-07-08T21:46:15.7752842Z    java.lang.Thread.State: TIMED_WAITING (parking)
2020-07-08T21:46:15.7753133Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7753752Z 	- parking to wait for  <0x0000000087182040> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7754233Z 	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
2020-07-08T21:46:15.7754770Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
2020-07-08T21:46:15.7755364Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
2020-07-08T21:46:15.7756121Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
2020-07-08T21:46:15.7756809Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7757294Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7757786Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7758170Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7758360Z 
2020-07-08T21:46:15.7759187Z "FlinkCompletableFutureDelayScheduler-thread-1" #57 daemon prio=5 os_prio=0 tid=0x00007fef9c0f8000 nid=0x9d4b waiting on condition [0x00007fef7f3f6000]
2020-07-08T21:46:15.7759642Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7759910Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7760656Z 	- parking to wait for  <0x0000000087182280> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7761106Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7761610Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7762188Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1081)
2020-07-08T21:46:15.7762857Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
2020-07-08T21:46:15.7763509Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7763977Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7764465Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7764863Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7765054Z 
2020-07-08T21:46:15.7765798Z "jobmanager-future-thread-1" #51 daemon prio=5 os_prio=0 tid=0x00007fefb4019800 nid=0x9d40 waiting on condition [0x00007fef7f0f3000]
2020-07-08T21:46:15.7766860Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7767199Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7767934Z 	- parking to wait for  <0x0000000087182040> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7768427Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7769046Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7769644Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1088)
2020-07-08T21:46:15.7770228Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
2020-07-08T21:46:15.7770737Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7771326Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7771772Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7772144Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7772441Z 
2020-07-08T21:46:15.7773057Z "mini-cluster-io-thread-8" #46 daemon prio=5 os_prio=0 tid=0x00007fefa003e000 nid=0x9d3a waiting on condition [0x00007fef7f4f7000]
2020-07-08T21:46:15.7773594Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7773888Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7774524Z 	- parking to wait for  <0x00000000871826a8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7775014Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7775545Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7776086Z 	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
2020-07-08T21:46:15.7776692Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7777163Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7777654Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7778054Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7778243Z 
2020-07-08T21:46:15.7778993Z "mini-cluster-io-thread-7" #45 daemon prio=5 os_prio=0 tid=0x00007fefa003c800 nid=0x9d39 waiting on condition [0x00007fef7f5f8000]
2020-07-08T21:46:15.7779432Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7779716Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7780326Z 	- parking to wait for  <0x00000000871826a8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7780804Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7781421Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7781934Z 	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
2020-07-08T21:46:15.7782378Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7782815Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7783269Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7783628Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7784198Z 
2020-07-08T21:46:15.7785126Z "mini-cluster-io-thread-6" #44 daemon prio=5 os_prio=0 tid=0x00007fefa003b000 nid=0x9d38 waiting on condition [0x00007fef7f6f9000]
2020-07-08T21:46:15.7786719Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7787001Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7787771Z 	- parking to wait for  <0x00000000871826a8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7788266Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7788785Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7789334Z 	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
2020-07-08T21:46:15.7789797Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7790281Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7790770Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7791155Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7791350Z 
2020-07-08T21:46:15.7791985Z "mini-cluster-io-thread-5" #43 daemon prio=5 os_prio=0 tid=0x00007fefa4005000 nid=0x9d37 waiting on condition [0x00007fef7f7fa000]
2020-07-08T21:46:15.7792439Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7792718Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7793477Z 	- parking to wait for  <0x00000000871826a8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7794120Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7794908Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7795453Z 	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
2020-07-08T21:46:15.7795959Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7796446Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7796921Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7798102Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7798308Z 
2020-07-08T21:46:15.7799064Z "mini-cluster-io-thread-4" #42 daemon prio=5 os_prio=0 tid=0x00007fef81bcb000 nid=0x9d36 waiting on condition [0x00007fef7fafb000]
2020-07-08T21:46:15.7799503Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7799796Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7800432Z 	- parking to wait for  <0x00000000871826a8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7800925Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7801557Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7802188Z 	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
2020-07-08T21:46:15.7802641Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7803083Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7803537Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7803909Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7804085Z 
2020-07-08T21:46:15.7804669Z "mini-cluster-io-thread-3" #41 daemon prio=5 os_prio=0 tid=0x00007fefa0033800 nid=0x9d35 waiting on condition [0x00007fef7fbfc000]
2020-07-08T21:46:15.7805207Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7805488Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7806232Z 	- parking to wait for  <0x00000000871826a8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7806723Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7807383Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7808642Z 	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
2020-07-08T21:46:15.7809393Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7809867Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7810356Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7810742Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7810947Z 
2020-07-08T21:46:15.7811680Z "mini-cluster-io-thread-2" #40 daemon prio=5 os_prio=0 tid=0x00007fef81bc5800 nid=0x9d34 waiting on condition [0x00007fef7fcfd000]
2020-07-08T21:46:15.7812136Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7812413Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7813079Z 	- parking to wait for  <0x00000000871826a8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7813561Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7814096Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7814648Z 	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
2020-07-08T21:46:15.7815113Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7815598Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7816075Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7816474Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7816663Z 
2020-07-08T21:46:15.7817337Z "Flink-DispatcherRestEndpoint-thread-1" #38 daemon prio=5 os_prio=0 tid=0x00007fef81ba7800 nid=0x9d30 waiting on condition [0x00007fef7fdfe000]
2020-07-08T21:46:15.7817803Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7818256Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7818948Z 	- parking to wait for  <0x0000000087180cc0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7819424Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7819954Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7820563Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1088)
2020-07-08T21:46:15.7821169Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
2020-07-08T21:46:15.7821709Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7822185Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7822675Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7823066Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7823268Z 
2020-07-08T21:46:15.7823894Z "mini-cluster-io-thread-1" #37 daemon prio=5 os_prio=0 tid=0x00007fef81ba6800 nid=0x9d2f waiting on condition [0x00007fef881f5000]
2020-07-08T21:46:15.7824346Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7824625Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7825558Z 	- parking to wait for  <0x00000000871826a8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7826069Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7826571Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7828100Z 	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
2020-07-08T21:46:15.7830710Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7833058Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7833602Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7833991Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7834183Z 
2020-07-08T21:46:15.7834974Z "flink-rest-server-netty-boss-thread-1" #36 daemon prio=5 os_prio=0 tid=0x00007fef81ba2800 nid=0x9d2e runnable [0x00007fef886f6000]
2020-07-08T21:46:15.7837524Z    java.lang.Thread.State: RUNNABLE
2020-07-08T21:46:15.7837854Z 	at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
2020-07-08T21:46:15.7838216Z 	at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
2020-07-08T21:46:15.7838640Z 	at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
2020-07-08T21:46:15.7839059Z 	at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
2020-07-08T21:46:15.7839863Z 	- locked <0x0000000087183808> (a org.apache.flink.shaded.netty4.io.netty.channel.nio.SelectedSelectionKeySet)
2020-07-08T21:46:15.7840536Z 	- locked <0x00000000871837f8> (a java.util.Collections$UnmodifiableSet)
2020-07-08T21:46:15.7841094Z 	- locked <0x00000000871837b0> (a sun.nio.ch.EPollSelectorImpl)
2020-07-08T21:46:15.7841467Z 	at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
2020-07-08T21:46:15.7841995Z 	at org.apache.flink.shaded.netty4.io.netty.channel.nio.SelectedSelectionKeySetSelector.select(SelectedSelectionKeySetSelector.java:62)
2020-07-08T21:46:15.7842624Z 	at org.apache.flink.shaded.netty4.io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:806)
2020-07-08T21:46:15.7843171Z 	at org.apache.flink.shaded.netty4.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:454)
2020-07-08T21:46:15.7843758Z 	at org.apache.flink.shaded.netty4.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:918)
2020-07-08T21:46:15.7844391Z 	at org.apache.flink.shaded.netty4.io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
2020-07-08T21:46:15.7844988Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7845195Z 
2020-07-08T21:46:15.7845547Z "IOManager reader thread #1" #30 daemon prio=5 os_prio=0 tid=0x00007fefd976f000 nid=0x9d09 waiting on condition [0x00007fef887f7000]
2020-07-08T21:46:15.7845994Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7846271Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7846965Z 	- parking to wait for  <0x0000000087183a70> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7847459Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7847978Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7848536Z 	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
2020-07-08T21:46:15.7849045Z 	at org.apache.flink.runtime.io.disk.iomanager.IOManagerAsync$ReaderThread.run(IOManagerAsync.java:354)
2020-07-08T21:46:15.7849380Z 
2020-07-08T21:46:15.7849731Z "IOManager writer thread #1" #29 daemon prio=5 os_prio=0 tid=0x00007fefd976d000 nid=0x9d08 waiting on condition [0x00007fef888f8000]
2020-07-08T21:46:15.7853026Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7853377Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7854189Z 	- parking to wait for  <0x0000000087183c78> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7854691Z 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
2020-07-08T21:46:15.7855215Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
2020-07-08T21:46:15.7855767Z 	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
2020-07-08T21:46:15.7856438Z 	at org.apache.flink.runtime.io.disk.iomanager.IOManagerAsync$WriterThread.run(IOManagerAsync.java:460)
2020-07-08T21:46:15.7856783Z 
2020-07-08T21:46:15.7857397Z "Timer-2" #27 daemon prio=5 os_prio=0 tid=0x00007fefd9736800 nid=0x9d07 in Object.wait() [0x00007fef889f9000]
2020-07-08T21:46:15.7857846Z    java.lang.Thread.State: TIMED_WAITING (on object monitor)
2020-07-08T21:46:15.7858155Z 	at java.lang.Object.wait(Native Method)
2020-07-08T21:46:15.7858663Z 	- waiting on <0x0000000087183e80> (a java.util.TaskQueue)
2020-07-08T21:46:15.7859019Z 	at java.util.TimerThread.mainLoop(Timer.java:552)
2020-07-08T21:46:15.7859530Z 	- locked <0x0000000087183e80> (a java.util.TaskQueue)
2020-07-08T21:46:15.7859863Z 	at java.util.TimerThread.run(Timer.java:505)
2020-07-08T21:46:15.7860062Z 
2020-07-08T21:46:15.7860636Z "Timer-1" #25 daemon prio=5 os_prio=0 tid=0x00007fefd9734000 nid=0x9d06 in Object.wait() [0x00007fef88afa000]
2020-07-08T21:46:15.7861073Z    java.lang.Thread.State: TIMED_WAITING (on object monitor)
2020-07-08T21:46:15.7861394Z 	at java.lang.Object.wait(Native Method)
2020-07-08T21:46:15.7861888Z 	- waiting on <0x0000000087184060> (a java.util.TaskQueue)
2020-07-08T21:46:15.7880889Z 	at java.util.TimerThread.mainLoop(Timer.java:552)
2020-07-08T21:46:15.7884642Z 	- locked <0x0000000087184060> (a java.util.TaskQueue)
2020-07-08T21:46:15.7885023Z 	at java.util.TimerThread.run(Timer.java:505)
2020-07-08T21:46:15.7885225Z 
2020-07-08T21:46:15.7885568Z "BLOB Server listener at 40413" #21 daemon prio=5 os_prio=0 tid=0x00007fefd9731000 nid=0x9d05 runnable [0x00007fef88bfb000]
2020-07-08T21:46:15.7885962Z    java.lang.Thread.State: RUNNABLE
2020-07-08T21:46:15.7886274Z 	at java.net.PlainSocketImpl.socketAccept(Native Method)
2020-07-08T21:46:15.7886677Z 	at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409)
2020-07-08T21:46:15.7887099Z 	at java.net.ServerSocket.implAccept(ServerSocket.java:560)
2020-07-08T21:46:15.7887488Z 	at java.net.ServerSocket.accept(ServerSocket.java:528)
2020-07-08T21:46:15.7887891Z 	at org.apache.flink.runtime.blob.BlobServer.run(BlobServer.java:262)
2020-07-08T21:46:15.7888333Z 
2020-07-08T21:46:15.7888964Z "Timer-0" #22 daemon prio=5 os_prio=0 tid=0x00007fefd9719000 nid=0x9d04 in Object.wait() [0x00007fef88efc000]
2020-07-08T21:46:15.7889410Z    java.lang.Thread.State: TIMED_WAITING (on object monitor)
2020-07-08T21:46:15.7889716Z 	at java.lang.Object.wait(Native Method)
2020-07-08T21:46:15.7890222Z 	- waiting on <0x00000000871846a0> (a java.util.TaskQueue)
2020-07-08T21:46:15.7890561Z 	at java.util.TimerThread.mainLoop(Timer.java:552)
2020-07-08T21:46:15.7891090Z 	- locked <0x00000000871846a0> (a java.util.TaskQueue)
2020-07-08T21:46:15.7891423Z 	at java.util.TimerThread.run(Timer.java:505)
2020-07-08T21:46:15.7891621Z 
2020-07-08T21:46:15.7892216Z "flink-metrics-scheduler-1" #17 prio=5 os_prio=0 tid=0x00007fefd96de000 nid=0x9d00 waiting on condition [0x00007fefac2f4000]
2020-07-08T21:46:15.7892671Z    java.lang.Thread.State: TIMED_WAITING (sleeping)
2020-07-08T21:46:15.7892986Z 	at java.lang.Thread.sleep(Native Method)
2020-07-08T21:46:15.7893378Z 	at akka.actor.LightArrayRevolverScheduler.waitNanos(LightArrayRevolverScheduler.scala:85)
2020-07-08T21:46:15.7896632Z 	at akka.actor.LightArrayRevolverScheduler$$anon$4.nextTick(LightArrayRevolverScheduler.scala:265)
2020-07-08T21:46:15.7901619Z 	at akka.actor.LightArrayRevolverScheduler$$anon$4.run(LightArrayRevolverScheduler.scala:235)
2020-07-08T21:46:15.7902086Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7902278Z 
2020-07-08T21:46:15.7903094Z "flink-akka.actor.default-dispatcher-3" #15 prio=5 os_prio=0 tid=0x00007fefd914e800 nid=0x9cfe waiting on condition [0x00007fefac6f6000]
2020-07-08T21:46:15.7904034Z    java.lang.Thread.State: TIMED_WAITING (parking)
2020-07-08T21:46:15.7904361Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7905300Z 	- parking to wait for  <0x0000000087184ce8> (a akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinPool)
2020-07-08T21:46:15.7905963Z 	at akka.dispatch.forkjoin.ForkJoinPool.idleAwaitWork(ForkJoinPool.java:2135)
2020-07-08T21:46:15.7906421Z 	at akka.dispatch.forkjoin.ForkJoinPool.scan(ForkJoinPool.java:2067)
2020-07-08T21:46:15.7906846Z 	at akka.dispatch.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
2020-07-08T21:46:15.7907313Z 	at akka.dispatch.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)
2020-07-08T21:46:15.7907592Z 
2020-07-08T21:46:15.7908832Z "flink-akka.actor.default-dispatcher-2" #14 prio=5 os_prio=0 tid=0x00007fefd9139800 nid=0x9cfb waiting on condition [0x00007fefac7f7000]
2020-07-08T21:46:15.7909581Z    java.lang.Thread.State: WAITING (parking)
2020-07-08T21:46:15.7909902Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7917391Z 	- parking to wait for  <0x0000000087184ce8> (a akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinPool)
2020-07-08T21:46:15.7917891Z 	at akka.dispatch.forkjoin.ForkJoinPool.scan(ForkJoinPool.java:2075)
2020-07-08T21:46:15.7918347Z 	at akka.dispatch.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
2020-07-08T21:46:15.7918803Z 	at akka.dispatch.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)
2020-07-08T21:46:15.7919099Z 
2020-07-08T21:46:15.7919706Z "flink-scheduler-1" #13 prio=5 os_prio=0 tid=0x00007fefd90a3800 nid=0x9cfa waiting on condition [0x00007fefac8f8000]
2020-07-08T21:46:15.7920155Z    java.lang.Thread.State: TIMED_WAITING (sleeping)
2020-07-08T21:46:15.7920447Z 	at java.lang.Thread.sleep(Native Method)
2020-07-08T21:46:15.7920850Z 	at akka.actor.LightArrayRevolverScheduler.waitNanos(LightArrayRevolverScheduler.scala:85)
2020-07-08T21:46:15.7921378Z 	at akka.actor.LightArrayRevolverScheduler$$anon$4.nextTick(LightArrayRevolverScheduler.scala:265)
2020-07-08T21:46:15.7921924Z 	at akka.actor.LightArrayRevolverScheduler$$anon$4.run(LightArrayRevolverScheduler.scala:235)
2020-07-08T21:46:15.7922347Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7922537Z 
2020-07-08T21:46:15.7922887Z "process reaper" #11 daemon prio=10 os_prio=0 tid=0x00007fef8c039800 nid=0x9cf5 waiting on condition [0x00007fefad336000]
2020-07-08T21:46:15.7923487Z    java.lang.Thread.State: TIMED_WAITING (parking)
2020-07-08T21:46:15.7923790Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7924433Z 	- parking to wait for  <0x00000000871852d8> (a java.util.concurrent.SynchronousQueue$TransferStack)
2020-07-08T21:46:15.7924909Z 	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
2020-07-08T21:46:15.7925392Z 	at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
2020-07-08T21:46:15.7925923Z 	at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
2020-07-08T21:46:15.7926411Z 	at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
2020-07-08T21:46:15.7926861Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
2020-07-08T21:46:15.7927346Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7927830Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7928232Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7928421Z 
2020-07-08T21:46:15.7929070Z "surefire-forkedjvm-ping-30s" #10 daemon prio=5 os_prio=0 tid=0x00007fefd8333800 nid=0x9cf2 waiting on condition [0x00007fefaddf4000]
2020-07-08T21:46:15.7929529Z    java.lang.Thread.State: TIMED_WAITING (parking)
2020-07-08T21:46:15.7929832Z 	at sun.misc.Unsafe.park(Native Method)
2020-07-08T21:46:15.7930483Z 	- parking to wait for  <0x000000008003f018> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
2020-07-08T21:46:15.7930969Z 	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
2020-07-08T21:46:15.7931521Z 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
2020-07-08T21:46:15.7932135Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
2020-07-08T21:46:15.7932839Z 	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
2020-07-08T21:46:15.7933385Z 	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
2020-07-08T21:46:15.7933857Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
2020-07-08T21:46:15.7934347Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-07-08T21:46:15.7934731Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7934935Z 
2020-07-08T21:46:15.7935575Z "surefire-forkedjvm-command-thread" #9 daemon prio=5 os_prio=0 tid=0x00007fefd831c000 nid=0x9cf1 runnable [0x00007fefc8110000]
2020-07-08T21:46:15.7936010Z    java.lang.Thread.State: RUNNABLE
2020-07-08T21:46:15.7936301Z 	at java.io.FileInputStream.readBytes(Native Method)
2020-07-08T21:46:15.7936656Z 	at java.io.FileInputStream.read(FileInputStream.java:255)
2020-07-08T21:46:15.7937053Z 	at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
2020-07-08T21:46:15.7937482Z 	at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
2020-07-08T21:46:15.7938078Z 	- locked <0x000000008003f298> (a java.io.BufferedInputStream)
2020-07-08T21:46:15.7938448Z 	at java.io.DataInputStream.readInt(DataInputStream.java:387)
2020-07-08T21:46:15.7938917Z 	at org.apache.maven.surefire.booter.MasterProcessCommand.decode(MasterProcessCommand.java:115)
2020-07-08T21:46:15.7939441Z 	at org.apache.maven.surefire.booter.CommandReader$CommandRunnable.run(CommandReader.java:391)
2020-07-08T21:46:15.7939867Z 	at java.lang.Thread.run(Thread.java:748)
2020-07-08T21:46:15.7940058Z 
2020-07-08T21:46:15.7940383Z "Service Thread" #8 daemon prio=9 os_prio=0 tid=0x00007fefd820a800 nid=0x9cef runnable [0x0000000000000000]
2020-07-08T21:46:15.7940761Z    java.lang.Thread.State: RUNNABLE
2020-07-08T21:46:15.7940950Z 
2020-07-08T21:46:15.7942892Z "C1 CompilerThread1" #7 daemon prio=9 os_prio=0 tid=0x00007fefd81ff800 nid=0x9cee waiting on condition [0x0000000000000000]
2020-07-08T21:46:15.7943483Z    java.lang.Thread.State: RUNNABLE
2020-07-08T21:46:15.7943655Z 
2020-07-08T21:46:15.7944001Z "C2 CompilerThread0" #6 daemon prio=9 os_prio=0 tid=0x00007fefd81fd000 nid=0x9ced waiting on condition [0x0000000000000000]
2020-07-08T21:46:15.7945021Z    java.lang.Thread.State: RUNNABLE
2020-07-08T21:46:15.7945236Z 
2020-07-08T21:46:15.7945548Z "Signal Dispatcher" #5 daemon prio=9 os_prio=0 tid=0x00007fefd81fb000 nid=0x9cec runnable [0x0000000000000000]
2020-07-08T21:46:15.7945946Z    java.lang.Thread.State: RUNNABLE
2020-07-08T21:46:15.7946121Z 
2020-07-08T21:46:15.7946503Z "Surrogate Locker Thread (Concurrent GC)" #4 daemon prio=9 os_prio=0 tid=0x00007fefd81f9800 nid=0x9ceb waiting on condition [0x0000000000000000]
2020-07-08T21:46:15.7946936Z    java.lang.Thread.State: RUNNABLE
2020-07-08T21:46:15.7947124Z 
2020-07-08T21:46:15.7947437Z "Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007fefd81c9800 nid=0x9cea in Object.wait() [0x00007fefc8dfc000]
2020-07-08T21:46:15.7947882Z    java.lang.Thread.State: WAITING (on object monitor)
2020-07-08T21:46:15.7948179Z 	at java.lang.Object.wait(Native Method)
2020-07-08T21:46:15.7948525Z 	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144)
2020-07-08T21:46:15.7949696Z 	- locked <0x0000000080043288> (a java.lang.ref.ReferenceQueue$Lock)
2020-07-08T21:46:15.7950111Z 	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165)
2020-07-08T21:46:15.7950533Z 	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216)
2020-07-08T21:46:15.7950778Z 
2020-07-08T21:46:15.7951106Z "Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007fefd81c5000 nid=0x9ce9 in Object.wait() [0x00007fefc8efd000]
2020-07-08T21:46:15.7951551Z    java.lang.Thread.State: WAITING (on object monitor)
2020-07-08T21:46:15.7951862Z 	at java.lang.Object.wait(Native Method)
2020-07-08T21:46:15.7952575Z 	at java.lang.Object.wait(Object.java:502)
2020-07-08T21:46:15.7953820Z 	at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
2020-07-08T21:46:15.7954525Z 	- locked <0x0000000080043278> (a java.lang.ref.Reference$Lock)
2020-07-08T21:46:15.7954935Z 	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)
2020-07-08T21:46:15.7955185Z 
2020-07-08T21:46:15.7955492Z "main" #1 prio=5 os_prio=0 tid=0x00007fefd800b800 nid=0x9ce0 in Object.wait() [0x00007fefe2138000]
2020-07-08T21:46:15.7956693Z    java.lang.Thread.State: WAITING (on object monitor)
2020-07-08T21:46:15.7957487Z 	at java.lang.Object.wait(Native Method)
2020-07-08T21:46:15.7958906Z 	- waiting on <0x0000000087181118> (a org.apache.flink.test.accumulators.AccumulatorLiveITCase$1)
2020-07-08T21:46:15.7959330Z 	at java.lang.Thread.join(Thread.java:1252)
2020-07-08T21:46:15.7959948Z 	- locked <0x0000000087181118> (a org.apache.flink.test.accumulators.AccumulatorLiveITCase$1)
2020-07-08T21:46:15.7960408Z 	at org.apache.flink.core.testutils.CheckedThread.trySync(CheckedThread.java:112)
2020-07-08T21:46:15.7960896Z 	at org.apache.flink.core.testutils.CheckedThread.sync(CheckedThread.java:100)
2020-07-08T21:46:15.7961352Z 	at org.apache.flink.core.testutils.CheckedThread.sync(CheckedThread.java:89)
2020-07-08T21:46:15.7961901Z 	at org.apache.flink.test.accumulators.AccumulatorLiveITCase.submitJobAndVerifyResults(AccumulatorLiveITCase.java:178)
2020-07-08T21:46:15.7962593Z 	at org.apache.flink.test.accumulators.AccumulatorLiveITCase.testStreaming(AccumulatorLiveITCase.java:137)
2020-07-08T21:46:15.7963051Z 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2020-07-08T21:46:15.7963469Z 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2020-07-08T21:46:15.7963954Z 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2020-07-08T21:46:15.7964396Z 	at java.lang.reflect.Method.invoke(Method.java:498)
2020-07-08T21:46:15.7964820Z 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
2020-07-08T21:46:15.7965332Z 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
2020-07-08T21:46:15.7965986Z 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
2020-07-08T21:46:15.7966471Z 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
2020-07-08T21:46:15.7966960Z 	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
2020-07-08T21:46:15.7967388Z 	at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
2020-07-08T21:46:15.7976578Z 	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
2020-07-08T21:46:15.7977052Z 	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
2020-07-08T21:46:15.7996016Z 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
2020-07-08T21:46:15.7996567Z 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
2020-07-08T21:46:15.7998186Z 	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
2020-07-08T21:46:15.8000214Z 	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
2020-07-08T21:46:15.8001811Z 	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
2020-07-08T21:46:15.8002898Z 	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
2020-07-08T21:46:15.8003494Z 	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
2020-07-08T21:46:15.8004932Z 	at org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:48)
2020-07-08T21:46:15.8005359Z 	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
2020-07-08T21:46:15.8006127Z 	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
2020-07-08T21:46:15.8006585Z 	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365)
2020-07-08T21:46:15.8007100Z 	at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273)
2020-07-08T21:46:15.8007613Z 	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238)
2020-07-08T21:46:15.8008314Z 	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159)
2020-07-08T21:46:15.8008844Z 	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
2020-07-08T21:46:15.8009398Z 	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
2020-07-08T21:46:15.8009884Z 	at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
2020-07-08T21:46:15.8010358Z 	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
2020-07-08T21:46:15.8010622Z 
2020-07-08T21:46:15.8010875Z "VM Thread" os_prio=0 tid=0x00007fefd81bb800 nid=0x9ce8 runnable 
2020-07-08T21:46:15.8011089Z 
2020-07-08T21:46:15.8011384Z "Gang worker#0 (Parallel GC Threads)" os_prio=0 tid=0x00007fefd8020000 nid=0x9ce1 runnable 
2020-07-08T21:46:15.8011637Z 
2020-07-08T21:46:15.8011928Z "Gang worker#1 (Parallel GC Threads)" os_prio=0 tid=0x00007fefd8022000 nid=0x9ce2 runnable 
2020-07-08T21:46:15.8012181Z 
2020-07-08T21:46:15.8012467Z "G1 Main Concurrent Mark GC Thread" os_prio=0 tid=0x00007fefd8046000 nid=0x9ce6 runnable 
2020-07-08T21:46:15.8012717Z 
2020-07-08T21:46:15.8013007Z "Gang worker#0 (G1 Parallel Marking Threads)" os_prio=0 tid=0x00007fefd8047800 nid=0x9ce7 runnable 
2020-07-08T21:46:15.8013287Z 
2020-07-08T21:46:15.8013565Z "G1 Concurrent Refinement Thread#0" os_prio=0 tid=0x00007fefd8028000 nid=0x9ce5 runnable 
2020-07-08T21:46:15.8013829Z 
2020-07-08T21:46:15.8014102Z "G1 Concurrent Refinement Thread#1" os_prio=0 tid=0x00007fefd8026000 nid=0x9ce4 runnable 
2020-07-08T21:46:15.8034995Z 
2020-07-08T21:46:15.8035322Z "G1 Concurrent Refinement Thread#2" os_prio=0 tid=0x00007fefd8024800 nid=0x9ce3 runnable 
2020-07-08T21:46:15.8035581Z 
2020-07-08T21:46:15.8035879Z "VM Periodic Task Thread" os_prio=0 tid=0x00007fefd820d800 nid=0x9cf0 waiting on condition 
2020-07-08T21:46:15.8036137Z 
2020-07-08T21:46:15.8036337Z JNI global references: 1359

Attachments

Issue Links

is caused by

FLINK-17075 Add task status reconciliation between TM and JM

Closed

links to

GitHub Pull Request #12948

Activity

People

Assignee:: Chesnay Schepler

Reporter:: Dian Fu

Votes:: 0 Vote for this issue

Watchers:: 2 Start watching this issue

Dates

Created:: 09/Jul/20 02:07

Updated:: 23/Jul/20 09:47

Resolved:: 23/Jul/20 09:47