[FLINK-21201] Creating BoundedBlockingSubpartition blocks TaskManager’s main thread

• Type: Improvement
• Status: Open
• Priority: Not a Priority
• Resolution: Unresolved
• Affects Version/s: 1.12.1
• Component/s: Runtime / Network
• Labels: auto-deprioritized-major stale-minor
• Assignee: Unassigned
• Reporter: Zhilong Hong
• Created: 29/Jan/21 08:49
• Updated: 29/Oct/21 11:40

Description

When we are trying to run batch jobs with 8k parallelism, it takes a long time to deploy the vertices. After the investigation, we find that creating BoundedBlockingSubpartition blocks TaskManager’s main thread during the procedure of submitTask. 

When JobMaster invokes submitTask and sends an RPC call to the TaskManager, the TaskManager will receive the RPC call and execute the submitTask method in its main thread. In the submitTask method, the TaskExecutor will create a Task instance and try to start it. During the creation, the TaskExecutor will create the ResultPartition and its ResultSubpartitions. 

For the batch job, the type of ResultSubpartitions is the BoundedBlockingSubpartition with the FileChannelBoundedData. The BoundedBlockingSubpartition will create a file on the local disk, which is an IO operation and could take a long time. 

In our test, it would take at most 30+ seconds to create 8k BoundedBlockingSubpartitions. This procedure blocks the main thread of the TaskManager, and would lead to heartbeat timeout and slow task deploying. In my opinion, the IO operation should be executed with IOExecutor rather than the main thread. 

I add several log items to show what TaskExecutor is doing during submitTask.

2021-01-29 14:44:37,557 INFO  org.apache.flink.runtime.taskexecutor.TaskExecutor           [] - Start to submit task #898 (c9aefd1d30c2b133ba04ad495cd894fd)
2021-01-29 14:44:37,557 INFO  org.apache.flink.runtime.taskexecutor.slot.TaskSlotTableImpl [] - Activate slot 38cafd5b456cc8ff873bbe18e4bf708a.
2021-01-29 14:44:37,932 INFO  org.apache.flink.runtime.taskexecutor.TaskExecutor           [] - Start to init Task #898 (c9aefd1d30c2b133ba04ad495cd894fd) instance.
2021-01-29 14:44:37,932 INFO  org.apache.flink.runtime.io.network.NettyShuffleEnvironment  [] - Start to create 1 result partition(s).
2021-01-29 14:44:37,932 INFO  org.apache.flink.runtime.io.network.partition.ResultPartitionFactory [] - Initializing BoundedBlockingResultPartitions
2021-01-29 14:44:37,932 INFO  org.apache.flink.runtime.io.network.partition.ResultPartitionFactory [] - Start to create 8000 FILE BoundedBlockingSubpartitions.
2021-01-29 14:44:37,932 INFO  org.apache.flink.runtime.io.network.partition.BoundedBlockingSubpartition [] - FileChannel #0 created.

... ...

2021-01-29 14:45:06,052 INFO  org.apache.flink.runtime.io.network.partition.BoundedBlockingSubpartition [] - FileChannel #7999 created.
2021-01-29 14:45:06,052 INFO  org.apache.flink.runtime.io.network.partition.ResultPartitionFactory [] - Finish creating 8000 FILE BoundedBlockingSubpartitions.
2021-01-29 14:45:06,052 INFO  org.apache.flink.runtime.io.network.NettyShuffleEnvironment  [] - Finish creating 1 result partition(s).
2021-01-29 14:45:06,052 INFO  org.apache.flink.runtime.taskexecutor.TaskExecutor           [] - Finish initializing task #898 (c9aefd1d30c2b133ba04ad495cd894fd) instance.
2021-01-29 14:45:06,052 INFO  org.apache.flink.runtime.taskexecutor.TaskExecutor           [] - Received task Source: Source 0 (898/8000)#0 (c9aefd1d30c2b133ba04ad495cd894fd), deploy into slot with allocation id 38cafd5b456cc8ff873bbe18e4bf708a.
2021-01-29 14:45:06,053 INFO  org.apache.flink.runtime.taskmanager.Task                    [] - Source: Source 0 (898/8000)#0 (c9aefd1d30c2b133ba04ad495cd894fd) switched from CREATED to DEPLOYING.

We can see that it takes nearly 29 seconds to create 8k BoundedBlockingSubpartitions, and this would blocks the main thread in the TaskExecutor.

The log of JobManager and TaskManager is attached below. The most typical task is Source 0: #898.