You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@spark.apache.org by "Artur Sukhenko (JIRA)" <ji...@apache.org> on 2016/08/31 16:55:20 UTC
[jira] [Updated] (SPARK-17340) .sparkStaging is not cleaned if
killed
[ https://issues.apache.org/jira/browse/SPARK-17340?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Artur Sukhenko updated SPARK-17340:
-----------------------------------
Summary: .sparkStaging is not cleaned if killed (was: .sparkStaging not cleaned in yarn-cluster mode)
> .sparkStaging is not cleaned if killed
> ---------------------------------------
>
> Key: SPARK-17340
> URL: https://issues.apache.org/jira/browse/SPARK-17340
> Project: Spark
> Issue Type: Bug
> Affects Versions: 1.5.2, 1.6.1, 2.0.0
> Reporter: Artur Sukhenko
> Priority: Minor
>
> When running Spark (yarn,cluster mode) and killing application
> .sparkStaging is not cleaned.
> Reproduce:
> 1. run SparkPi job in yarn cluster mode
> 2. Wait app to switch to RUNNING and Press Ctrl+C
> 3. kill app:
> #yarn application -kill <app id>
> 4. Verify that it is not cleaned up:
> #hadoop fs -ls .sparkStaging
> Tested in Spark 1.5.2, 1.6.1, 2.0.0 - same error.
> When app is killed like this
> ======================================================
> $ hadoop fs -ls .sparkStaging
> Found 6 items
> drwx------ - user user 3 2016-08-26 00:57 .sparkStaging/application_1472140614688_0001
> drwx------ - user user 3 2016-08-26 01:09 .sparkStaging/application_1472140614688_0002
> drwx------ - user user 3 2016-08-26 19:51 .sparkStaging/application_1472140614688_0005
> drwx------ - user user 3 2016-08-26 19:53 .sparkStaging/application_1472140614688_0007
> drwx------ - user user 3 2016-08-31 22:43 .sparkStaging/application_1472634296300_0011
> drwx------ - user user 3 2016-08-31 23:30 .sparkStaging/application_1472651370711_0006
> {code}
> ERROR yarn.ApplicationMaster: RECEIVED SIGNAL 15: SIGTERM
> 16/08/26 00:51:17 INFO spark.SparkContext: Invoking stop() from shutdown hook
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Starting task 506.0 in stage 0.0 (TID 506, node1, PROCESS_LOCAL, 2085 bytes)
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Starting task 507.0 in stage 0.0 (TID 507, node1, PROCESS_LOCAL, 2085 bytes)
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Finished task 504.0 in stage 0.0 (TID 504) in 14 ms on node1 (505/1000)
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Finished task 505.0 in stage 0.0 (TID 505) in 14 ms on node1 (506/1000)
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/metrics/json,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/stages/stage/kill,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/api,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/static,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/executors/threadDump/json,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/executors/threadDump,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/executors/json,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/executors,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/environment/json,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/environment,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/storage/rdd/json,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/storage/rdd,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/storage/json,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/storage,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/stages/pool/json,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/stages/pool,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/stages/stage/json,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/stages/stage,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/stages/json,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/stages,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/jobs/job/json,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/jobs/job,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/jobs/json,null}
> 16/08/26 00:51:17 INFO handler.ContextHandler: stopped o.s.j.s.ServletContextHandler{/jobs,null}
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Starting task 508.0 in stage 0.0 (TID 508, node1, PROCESS_LOCAL, 2085 bytes)
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Finished task 507.0 in stage 0.0 (TID 507) in 20 ms on node1 (507/1000)
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Starting task 509.0 in stage 0.0 (TID 509, node1, PROCESS_LOCAL, 2085 bytes)
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Finished task 506.0 in stage 0.0 (TID 506) in 38 ms on node1 (508/1000)
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Starting task 510.0 in stage 0.0 (TID 510, node1, PROCESS_LOCAL, 2085 bytes)
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Finished task 508.0 in stage 0.0 (TID 508) in 35 ms on node1 (509/1000)
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Starting task 511.0 in stage 0.0 (TID 511, node1, PROCESS_LOCAL, 2085 bytes)
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Finished task 510.0 in stage 0.0 (TID 510) in 11 ms on node1 (510/1000)
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Starting task 512.0 in stage 0.0 (TID 512, node1, PROCESS_LOCAL, 2085 bytes)
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Finished task 509.0 in stage 0.0 (TID 509) in 25 ms on node1 (511/1000)
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Starting task 513.0 in stage 0.0 (TID 513, node1, PROCESS_LOCAL, 2085 bytes)
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Finished task 511.0 in stage 0.0 (TID 511) in 22 ms on node1 (512/1000)
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Starting task 514.0 in stage 0.0 (TID 514, node1, PROCESS_LOCAL, 2085 bytes)
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Finished task 512.0 in stage 0.0 (TID 512) in 26 ms on node1 (513/1000)
> 16/08/26 00:51:17 INFO ui.SparkUI: Stopped Spark web UI at http://192.168.33.11:41489
> 16/08/26 00:51:17 INFO scheduler.DAGScheduler: Stopping DAGScheduler
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Starting task 515.0 in stage 0.0 (TID 515, node1, PROCESS_LOCAL, 2085 bytes)
> 16/08/26 00:51:17 INFO scheduler.DAGScheduler: ResultStage 0 (reduce at SparkPi.scala:36) failed in 7.827 s
> 16/08/26 00:51:17 INFO scheduler.DAGScheduler: Job 0 failed: reduce at SparkPi.scala:36, took 8.039526 s
> 16/08/26 00:51:17 INFO cluster.YarnClusterSchedulerBackend: Shutting down all executors
> 16/08/26 00:51:17 INFO scheduler.TaskSetManager: Finished task 514.0 in stage 0.0 (TID 514) in 21 ms on node1 (514/1000)
> 16/08/26 00:51:17 ERROR yarn.ApplicationMaster: User class threw exception: org.apache.spark.SparkException: Job cancelled because SparkContext was shut down
> org.apache.spark.SparkException: Job cancelled because SparkContext was shut down
> at org.apache.spark.scheduler.DAGScheduler$$anonfun$cleanUpAfterSchedulerStop$1.apply(DAGScheduler.scala:703)
> at org.apache.spark.scheduler.DAGScheduler$$anonfun$cleanUpAfterSchedulerStop$1.apply(DAGScheduler.scala:702)
> at scala.collection.mutable.HashSet.foreach(HashSet.scala:79)
> at org.apache.spark.scheduler.DAGScheduler.cleanUpAfterSchedulerStop(DAGScheduler.scala:702)
> at org.apache.spark.scheduler.DAGSchedulerEventProcessLoop.onStop(DAGScheduler.scala:1514)
> at org.apache.spark.util.EventLoop.stop(EventLoop.scala:84)
> at org.apache.spark.scheduler.DAGScheduler.stop(DAGScheduler.scala:1438)
> at org.apache.spark.SparkContext$$anonfun$stop$7.apply$mcV$sp(SparkContext.scala:1724)
> at org.apache.spark.util.Utils$.tryLogNonFatalError(Utils.scala:1185)
> at org.apache.spark.SparkContext.stop(SparkContext.scala:1723)
> at org.apache.spark.SparkContext$$anonfun$3.apply$mcV$sp(SparkContext.scala:587)
> at org.apache.spark.util.SparkShutdownHook.run(ShutdownHookManager.scala:264)
> at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1$$anonfun$apply$mcV$sp$1.apply$mcV$sp(ShutdownHookManager.scala:234)
> at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1$$anonfun$apply$mcV$sp$1.apply(ShutdownHookManager.scala:234)
> at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1$$anonfun$apply$mcV$sp$1.apply(ShutdownHookManager.scala:234)
> at org.apache.spark.util.Utils$.logUncaughtExceptions(Utils.scala:1699)
> at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1.apply$mcV$sp(ShutdownHookManager.scala:234)
> at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1.apply(ShutdownHookManager.scala:234)
> at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1.apply(ShutdownHookManager.scala:234)
> at scala.util.Try$.apply(Try.scala:161)
> at org.apache.spark.util.SparkShutdownHookManager.runAll(ShutdownHookManager.scala:234)
> at org.apache.spark.util.SparkShutdownHookManager$$anon$2.run(ShutdownHookManager.scala:216)
> at org.apache.hadoop.util.ShutdownHookManager$1.run(ShutdownHookManager.java:54)
> at org.apache.spark.scheduler.DAGScheduler.runJob(DAGScheduler.scala:567)
> at org.apache.spark.SparkContext.runJob(SparkContext.scala:1824)
> at org.apache.spark.SparkContext.runJob(SparkContext.scala:1944)
> at org.apache.spark.rdd.RDD$$anonfun$reduce$1.apply(RDD.scala:1007)
> at org.apache.spark.rdd.RDDOperationScope$.withScope(RDDOperationScope.scala:147)
> at org.apache.spark.rdd.RDDOperationScope$.withScope(RDDOperationScope.scala:108)
> at org.apache.spark.rdd.RDD.withScope(RDD.scala:310)
> at org.apache.spark.rdd.RDD.reduce(RDD.scala:989)
> at org.apache.spark.examples.SparkPi$.main(SparkPi.scala:36)
> at org.apache.spark.examples.SparkPi.main(SparkPi.scala)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at org.apache.spark.deploy.yarn.ApplicationMaster$$anon$2.run(ApplicationMaster.scala:525)
> 16/08/26 00:51:17 INFO yarn.ApplicationMaster: Final app status: FAILED, exitCode: 15, (reason: User class threw exception: org.apache.spark.SparkException: Job cancelled because SparkContext was shut down)
> 16/08/26 00:51:17 INFO cluster.YarnClusterSchedulerBackend: Asking each executor to shut down
> End of LogType:stderr
> {code}
> Currently cleanupStagingDir is run when app has final status SUCCEEDED.
> {code:title=ApplicationMaster.java}
> if (!unregistered) {
> // we only want to unregister if we don't want the RM to retry
> if (finalStatus == FinalApplicationStatus.SUCCEEDED || isLastAttempt) {
> unregister(finalStatus, finalMsg)
> cleanupStagingDir(fs)
> }
> }
> {code}
> If we kill spark-submit in terminal with Ctrl+C - the cleanup is not performed.
> Can we do unregister and cleanup if we get
> (yarn kill)
> exitCode 15 in Spark 1.5.X/1.6.X
> {code}
> ERROR yarn.ApplicationMaster: RECEIVED SIGNAL 15: SIGTERM
> INFO yarn.ApplicationMaster: Final app status: FAILED, exitCode: 15, (reason: User class threw exception: org.apache.spark.SparkException: Job cancelled because SparkContext was shut down)
> {code}
> and exitCode 16 in Spark 2.0.X
> {code}
> ERROR ApplicationMaster: RECEIVED SIGNAL TERM
> INFO ApplicationMaster: Final app status: FAILED, exitCode: 16, (reason: Shutdown hook called before final status was reported.)
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-unsubscribe@spark.apache.org
For additional commands, e-mail: issues-help@spark.apache.org