[SPARK-6690] spark-sql script ends up throwing Exception when event logging is enabled.

[sarutak]

When event logging is enabled, spark-sql script ends up throwing Exception like as follows.

15/04/03 13:51:49 INFO handler.ContextHandler: stopped o.e.j.s.ServletContextHandler{/jobs,null}
15/04/03 13:51:49 ERROR scheduler.LiveListenerBus: Listener EventLoggingListener threw an exception
java.lang.reflect.InvocationTargetException
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.apache.spark.scheduler.EventLoggingListener$$anonfun$logEvent$3.apply(EventLoggingListener.scala:144)
    at org.apache.spark.scheduler.EventLoggingListener$$anonfun$logEvent$3.apply(EventLoggingListener.scala:144)
    at scala.Option.foreach(Option.scala:236)
    at org.apache.spark.scheduler.EventLoggingListener.logEvent(EventLoggingListener.scala:144)
    at org.apache.spark.scheduler.EventLoggingListener.onApplicationEnd(EventLoggingListener.scala:188)
    at org.apache.spark.scheduler.SparkListenerBus$class.onPostEvent(SparkListenerBus.scala:54)
    at org.apache.spark.scheduler.LiveListenerBus.onPostEvent(LiveListenerBus.scala:31)
    at org.apache.spark.scheduler.LiveListenerBus.onPostEvent(LiveListenerBus.scala:31)
    at org.apache.spark.util.ListenerBus$class.postToAll(ListenerBus.scala:53)
    at org.apache.spark.util.AsynchronousListenerBus.postToAll(AsynchronousListenerBus.scala:37)
    at org.apache.spark.util.AsynchronousListenerBus$$anon$1$$anonfun$run$1.apply$mcV$sp(AsynchronousListenerBus.scala:79)
    at org.apache.spark.util.Utils$.tryOrStopSparkContext(Utils.scala:1171)
    at org.apache.spark.util.AsynchronousListenerBus$$anon$1.run(AsynchronousListenerBus.scala:63)
Caused by: java.io.IOException: Filesystem closed
    at org.apache.hadoop.hdfs.DFSClient.checkOpen(DFSClient.java:707)
    at org.apache.hadoop.hdfs.DFSOutputStream.flushOrSync(DFSOutputStream.java:1843)
    at org.apache.hadoop.hdfs.DFSOutputStream.hflush(DFSOutputStream.java:1804)
    at org.apache.hadoop.fs.FSDataOutputStream.hflush(FSDataOutputStream.java:127)
    ... 17 more
15/04/03 13:51:49 INFO ui.SparkUI: Stopped Spark web UI at http://sarutak-devel:4040
15/04/03 13:51:49 INFO scheduler.DAGScheduler: Stopping DAGScheduler
Exception in thread "Thread-6" java.io.IOException: Filesystem closed
    at org.apache.hadoop.hdfs.DFSClient.checkOpen(DFSClient.java:707)
    at org.apache.hadoop.hdfs.DFSClient.getFileInfo(DFSClient.java:1760)
    at org.apache.hadoop.hdfs.DistributedFileSystem$17.doCall(DistributedFileSystem.java:1124)
    at org.apache.hadoop.hdfs.DistributedFileSystem$17.doCall(DistributedFileSystem.java:1120)
    at org.apache.hadoop.fs.FileSystemLinkResolver.resolve(FileSystemLinkResolver.java:81)
    at org.apache.hadoop.hdfs.DistributedFileSystem.getFileStatus(DistributedFileSystem.java:1120)
    at org.apache.hadoop.fs.FileSystem.exists(FileSystem.java:1398)
    at org.apache.spark.scheduler.EventLoggingListener.stop(EventLoggingListener.scala:209)
    at org.apache.spark.SparkContext$$anonfun$stop$3.apply(SparkContext.scala:1408)
    at org.apache.spark.SparkContext$$anonfun$stop$3.apply(SparkContext.scala:1408)
    at scala.Option.foreach(Option.scala:236)
    at org.apache.spark.SparkContext.stop(SparkContext.scala:1408)
    at org.apache.spark.sql.hive.thriftserver.SparkSQLEnv$.stop(SparkSQLEnv.scala:66)
    at org.apache.spark.sql.hive.thriftserver.SparkSQLCLIDriver$$anon$1.run(SparkSQLCLIDriver.scala:107)

This is because FileSystem#close is called by the shutdown hook registered in SparkSQLCLIDriver.

    Runtime.getRuntime.addShutdownHook(
      new Thread() {
        override def run() {
          SparkSQLEnv.stop()
        }
      }
    )

This issue was resolved by SPARK-3062 but I think, it's brought again by SPARK-2261.

[SparkQA]

Test build #29648 has started for PR 5341 at commit d05f4d1.

[SparkQA]

Test build #29648 has finished for PR 5341 at commit d05f4d1.

• This patch passes all tests.
• This patch merges cleanly.
• This patch adds no public classes.
• This patch does not change any dependencies.

[AmplabJenkins]

Test PASSed.
Refer to this link for build results (access rights to CI server needed):
https://amplab.cs.berkeley.edu/jenkins//job/SparkPullRequestBuilder/29648/
Test PASSed.

[SparkQA]

Test build #30001 has started for PR 5341 at commit 7870280.

[SparkQA]

Test build #30001 has finished for PR 5341 at commit 7870280.

• This patch fails to build.
• This patch merges cleanly.
• This patch adds no public classes.
• This patch does not change any dependencies.

[AmplabJenkins]

Test FAILed.
Refer to this link for build results (access rights to CI server needed):
https://amplab.cs.berkeley.edu/jenkins//job/SparkPullRequestBuilder/30001/
Test FAILed.

[SparkQA]

Test build #30009 has started for PR 5341 at commit 2b479c3.

[SparkQA]

Test build #30009 has finished for PR 5341 at commit 2b479c3.

• This patch passes all tests.
• This patch merges cleanly.
• This patch adds no public classes.
• This patch does not change any dependencies.

[AmplabJenkins]

Test PASSed.
Refer to this link for build results (access rights to CI server needed):
https://amplab.cs.berkeley.edu/jenkins//job/SparkPullRequestBuilder/30009/
Test PASSed.

[vanzin]

I don't think this is the best fix. See discussion in #4771 (which the original author unfortunately closed).

[WangTaoTheTonic]

Hey @sarutak Any updates on this?

[sarutak]

I think #5560 resolved this issue so I'll close this PR.