[FLINK-2455] Misleading I/O manager error log messages

• Type: Improvement
• Status: Closed
• Priority: Major
• Resolution: Won't Do
• Affects Version/s: 0.9, 0.10.0
• Component/s: Runtime / Coordination
• Assignee: Unassigned
• Reporter: Ufuk Celebi
• Created: 31/Jul/15 17:24
• Updated: 26/Feb/19 16:02
• Resolved: 26/Feb/19 16:02

Description

The logs reported by andralungu in FLINK-2412 show a lot of the following messages:

20:13:27,504 WARN  org.apache.flink.runtime.taskmanager.Task                     - Task 'CHAIN DataSource (at getEdgesDataSet(Degrees.java:64) (org.apache.flink.api.java.io.CsvInputFormat)) -> Map (Map at getEdgesDataSet(Degrees.java:64)) (50/60)' did not react to cancelling signal, but is stuck in method:
 java.lang.Object.wait(Native Method)
org.apache.flink.runtime.io.disk.iomanager.AsynchronousFileIOChannel.close(AsynchronousFileIOChannel.java:126)
org.apache.flink.runtime.io.disk.iomanager.AsynchronousFileIOChannel.closeAndDelete(AsynchronousFileIOChannel.java:158)
org.apache.flink.runtime.io.network.partition.SpillableSubpartition.release(SpillableSubpartition.java:130)
org.apache.flink.runtime.io.network.partition.ResultPartition.release(ResultPartition.java:300)
org.apache.flink.runtime.io.network.partition.ResultPartitionManager.releasePartitionsProducedBy(ResultPartitionManager.java:95)
org.apache.flink.runtime.io.network.NetworkEnvironment.unregisterTask(NetworkEnvironment.java:356)
org.apache.flink.runtime.taskmanager.Task.run(Task.java:674)
java.lang.Thread.run(Thread.java:722)

20:13:27,583 ERROR org.apache.flink.runtime.io.network.partition.ResultPartition  - Error during release of result subpartition: Closing of asynchronous file channel was interrupted.
java.io.IOException: Closing of asynchronous file channel was interrupted.
	at org.apache.flink.runtime.io.disk.iomanager.AsynchronousFileIOChannel.close(AsynchronousFileIOChannel.java:130)
	at org.apache.flink.runtime.io.disk.iomanager.AsynchronousFileIOChannel.closeAndDelete(AsynchronousFileIOChannel.java:158)
	at org.apache.flink.runtime.io.network.partition.SpillableSubpartition.release(SpillableSubpartition.java:130)
	at org.apache.flink.runtime.io.network.partition.ResultPartition.release(ResultPartition.java:300)
	at org.apache.flink.runtime.io.network.partition.ResultPartitionManager.releasePartitionsProducedBy(ResultPartitionManager.java:95)
	at org.apache.flink.runtime.io.network.NetworkEnvironment.unregisterTask(NetworkEnvironment.java:356)
	at org.apache.flink.runtime.taskmanager.Task.run(Task.java:674)
	at java.lang.Thread.run(Thread.java:722)

This is repeated for each subpartition during the release of a spillable partition (each subpartition is closed idp). The task is interrupted while waiting for the file channel to be closed.

20:15:50,329 ERROR org.apache.flink.runtime.io.network.partition.ResultPartition  - Error during release of result subpartition: IO-Manager has been closed.
java.io.IOException: IO-Manager has been closed.
	at org.apache.flink.runtime.io.disk.iomanager.IOManagerAsync$WriterThread.shutdown(IOManagerAsync.java:424)
	at org.apache.flink.runtime.io.disk.iomanager.IOManagerAsync.shutdown(IOManagerAsync.java:125)
	at org.apache.flink.runtime.io.disk.iomanager.IOManager$1.run(IOManager.java:103)