[SPARK-9844] File appender race condition during SparkWorker shutdown

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 1.3.0, 1.4.0
• Fix Version/s: 1.6.1, 2.0.0
• Component/s: Spark Core
• Assignee: Bryan Cutler
• Reporter: Alex Liu
• Created: 11/Aug/15 20:45
• Updated: 17/Feb/16 18:15
• Resolved: 14/Jan/16 11:06

Description

We find this issue still exists in 1.3.1

ERROR [Thread-6] 2015-07-28 22:49:57,653 SparkWorker-0 ExternalLogger.java:96 - Error writing stream to file /var/lib/spark/worker/worker-0/app-20150728224954-0003/0/stderr
ERROR [Thread-6] 2015-07-28 22:49:57,653 SparkWorker-0 ExternalLogger.java:96 - java.io.IOException: Stream closed
ERROR [Thread-6] 2015-07-28 22:49:57,654 SparkWorker-0 ExternalLogger.java:96 - 	at java.io.BufferedInputStream.getBufIfOpen(BufferedInputStream.java:170) ~[na:1.8.0_40]
ERROR [Thread-6] 2015-07-28 22:49:57,654 SparkWorker-0 ExternalLogger.java:96 - 	at java.io.BufferedInputStream.read1(BufferedInputStream.java:283) ~[na:1.8.0_40]
ERROR [Thread-6] 2015-07-28 22:49:57,654 SparkWorker-0 ExternalLogger.java:96 - 	at java.io.BufferedInputStream.read(BufferedInputStream.java:345) ~[na:1.8.0_40]
ERROR [Thread-6] 2015-07-28 22:49:57,654 SparkWorker-0 ExternalLogger.java:96 - 	at java.io.FilterInputStream.read(FilterInputStream.java:107) ~[na:1.8.0_40]
ERROR [Thread-6] 2015-07-28 22:49:57,655 SparkWorker-0 ExternalLogger.java:96 - 	at org.apache.spark.util.logging.FileAppender.appendStreamToFile(FileAppender.scala:70) ~[spark-core_2.10-1.3.1.1.jar:1.3.1.1]
ERROR [Thread-6] 2015-07-28 22:49:57,655 SparkWorker-0 ExternalLogger.java:96 - 	at org.apache.spark.util.logging.FileAppender$$anon$1$$anonfun$run$1.apply$mcV$sp(FileAppender.scala:39) [spark-core_2.10-1.3.1.1.jar:1.3.1.1]
ERROR [Thread-6] 2015-07-28 22:49:57,655 SparkWorker-0 ExternalLogger.java:96 - 	at org.apache.spark.util.logging.FileAppender$$anon$1$$anonfun$run$1.apply(FileAppender.scala:39) [spark-core_2.10-1.3.1.1.jar:1.3.1.1]
ERROR [Thread-6] 2015-07-28 22:49:57,655 SparkWorker-0 ExternalLogger.java:96 - 	at org.apache.spark.util.logging.FileAppender$$anon$1$$anonfun$run$1.apply(FileAppender.scala:39) [spark-core_2.10-1.3.1.1.jar:1.3.1.1]
ERROR [Thread-6] 2015-07-28 22:49:57,655 SparkWorker-0 ExternalLogger.java:96 - 	at org.apache.spark.util.Utils$.logUncaughtExceptions(Utils.scala:1618) [spark-core_2.10-1.3.1.1.jar:1.3.1.1]
ERROR [Thread-6] 2015-07-28 22:49:57,656 SparkWorker-0 ExternalLogger.java:96 - 	at org.apache.spark.util.logging.FileAppender$$anon$1.run(FileAppender.scala:38) [spark-core_2.10-1.3.1.1.jar:1.3.1.1]

at https://github.com/apache/spark/blob/master/core/src/main/scala/org/apache/spark/deploy/worker/ExecutorRunner.scala#L159

The process auto shuts down, but the log appenders are still running, which causes the error log messages.

Issue Links

• is duplicated by: SPARK-12876 Race condition when driver rapidly shutdown after started.
• is related to: SPARK-4300 Race condition during SparkWorker shutdown
• relates to: SPARK-4300 Race condition during SparkWorker shutdown
• links to: [Github] Pull Request #10714 (BryanCutler)