You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@spark.apache.org by "Steve Loughran (JIRA)" <ji...@apache.org> on 2016/03/23 21:57:25 UTC
[jira] [Comment Edited] (SPARK-14106) history server application
cache doesn't detect that apps are completed
[ https://issues.apache.org/jira/browse/SPARK-14106?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15209153#comment-15209153 ]
Steve Loughran edited comment on SPARK-14106 at 3/23/16 8:56 PM:
-----------------------------------------------------------------
This surfaced in logs of my yarn timeline integration tests. There a specific no-op() probe is hooked up on completed applications, so there's no overhead at all on their checks.
{code}
contains 32 event(s)
2016-03-23 20:46:06,594 [qtp196369530-25] INFO server.YarnHistoryProvider (Logging.scala:logInfo(58)) - Building Application UI Spark Pi attempt Some(1) under /history/application_1458752661638_0002/1
2016-03-23 20:46:06,595 [qtp196369530-25] INFO server.YarnHistoryProvider (Logging.scala:logInfo(58)) - App application_1458752661638_0002 history contains 32 events
2016-03-23 20:46:06,597 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Block Manager ID":{"Host":"192.168.1.132","Executor ID":"driver","Port":40481},"Event":"SparkListenerBlockManagerAdded","Timestamp":1458753291682,"Maximum Memory":480116736}
2016-03-23 20:46:06,608 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Event":"SparkListenerEnvironmentUpdate","System Properties":{"java.vm.info":"mixed mode","line.separator":"\n","java.vm.version":"25.74-b02","sun.cpu.isalist":"","java.vm.specification.vendor":"Oracle Corporation","os.version":"3.13.0-83-generic","java.l ... }
2016-03-23 20:46:06,614 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"App Attempt ID":"1","App ID":"application_1458752661638_0002","Timestamp":1458753289143,"User":"stevel","Event":"SparkListenerApplicationStart","Driver Logs":{"stdout":"http://xubunty.cotham.uk:8042/node/containerlogs/container_1458752661638_0002_01_0000 ... }
2016-03-23 20:46:06,621 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Executor ID":"1","Event":"SparkListenerExecutorAdded","Executor Info":{"Total Cores":1,"Log Urls":{"stderr":"http://xubunty.cotham.uk:8042/node/containerlogs/container_1458752661638_0002_01_000002/stevel/stderr?start=-4096","stdout":"http://xubunty.cotha ... }
2016-03-23 20:46:06,624 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Timestamp":1458753309182,"Executor ID":"2","Event":"SparkListenerExecutorAdded","Executor Info":{"Total Cores":1,"Host":"xubunty.cotham.uk","Log Urls":{"stdout":"http://xubunty.cotham.uk:8042/node/containerlogs/container_1458752661638_0002_01_000003/stev ... }
2016-03-23 20:46:06,625 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Block Manager ID":{"Executor ID":"1","Port":56415,"Host":"xubunty.cotham.uk"},"Event":"SparkListenerBlockManagerAdded","Maximum Memory":535953408,"Timestamp":1458753309248}
2016-03-23 20:46:06,626 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Block Manager ID":{"Port":49921,"Executor ID":"2","Host":"xubunty.cotham.uk"},"Event":"SparkListenerBlockManagerAdded","Maximum Memory":535953408,"Timestamp":1458753309295}
2016-03-23 20:46:06,632 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Event":"SparkListenerJobStart","Stage Infos":[{"Parent IDs":[],"Stage ID":0,"RDD Info":[{"Disk Size":0,"RDD ID":1,"Name":"MapPartitionsRDD","Storage Level":{"Use Memory":false,"Deserialized":false,"Replication":1,"Use Disk":false,"Use ExternalBlockStore" ... }
2016-03-23 20:46:06,666 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage Info":{"Parent IDs":[],"Stage ID":0,"RDD Info":[{"Disk Size":0,"RDD ID":1,"Name":"MapPartitionsRDD","Storage Level":{"Use Memory":false,"Deserialized":false,"Replication":1,"Use Disk":false,"Use ExternalBlockStore":false},"Callsite":"map at SparkPi ... }
2016-03-23 20:46:06,678 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Task Info":{"Executor ID":"1","Finish Time":0,"Launch Time":1458753311859,"Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Index":0,"Host":"xubunty.cotham.uk","Attempt":0,"Task ID":0}," ... }
2016-03-23 20:46:06,682 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Task Info":{"Finish Time":0,"Executor ID":"2","Getting Result Time":0,"Launch Time":1458753311896,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Task ID":1,"Host":"xubunty.cotham.uk","Attempt":0,"Index":1}," ... }
2016-03-23 20:46:06,684 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Task Info":{"Finish Time":0,"Executor ID":"2","Launch Time":1458753318378,"Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Host":"xubunty.cotham.uk","Index":2,"Attempt":0,"Task ID":2}," ... }
2016-03-23 20:46:06,686 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Event":"SparkListenerTaskStart","Stage Attempt ID":0,"Task Info":{"Launch Time":1458753318411,"Executor ID":"1","Finish Time":0,"Index":3,"Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false ... }
2016-03-23 20:46:06,688 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Task Info":{"Launch Time":1458753318555,"Executor ID":"1","Finish Time":0,"Task ID":4,"Index":4,"Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Host":"xubunty.cotham.uk","Attempt":0}," ... }
2016-03-23 20:46:06,691 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Task Info":{"Launch Time":1458753318411,"Executor ID":"1","Finish Time":1458753318582,"Index":3,"Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Host":"xubunty.cotham.uk","Attempt":0,"T ... }
2016-03-23 20:46:06,718 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Info":{"Executor ID":"2","Getting Result Time":0,"Launch Time":1458753311896,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Finish Time":1458753318655,"Task ID":1,"Failed":false,"Attempt":0,"Host":"xubunty.cotham.uk","Index":1},"T ... }
2016-03-23 20:46:06,721 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Event":"SparkListenerTaskEnd","Task Metrics":{"Result Size":1039,"Host Name":"xubunty.cotham.uk","Executor Run Time":239,"Disk Bytes Spilled":0,"Result Serialization Time":0,"Executor Deserialize Time":6012,"JVM GC Time":2150,"Memory Bytes S ... }
2016-03-23 20:46:06,724 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Event":"SparkListenerTaskStart","Task Info":{"Finish Time":1458753318809,"Executor ID":"2","Launch Time":1458753318668,"Index":5,"Getting Result Time":0,"Task ID":5,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":fa ... }
2016-03-23 20:46:06,727 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Task Info":{"Index":6,"Executor ID":"1","Task ID":6,"Finish Time":1458753318870,"Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Launch Time":1458753318715,"Host":"xubunty.cotham.uk","A ... }
2016-03-23 20:46:06,730 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Info":{"Finish Time":1458753318720,"Launch Time":1458753318555,"Executor ID":"1","Task ID":4,"Index":4,"Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Host":"xubunty.cotham.uk","Attempt":0},"S ... }
2016-03-23 20:46:06,733 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Metrics":{"Executor Deserialize Time":75,"Result Size":1039,"Host Name":"xubunty.cotham.uk","Disk Bytes Spilled":0,"Result Serialization Time":0,"Executor Run Time":66,"JVM GC Time":0,"Memory Bytes Spilled":0},"Task Info":{"Finish Time":145875331872 ... }
2016-03-23 20:46:06,736 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Info":{"Index":7,"Launch Time":1458753318805,"Executor ID":"2","Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Task ID":7,"Failed":false,"Host":"xubunty.cotham.uk","Attempt":0,"Finish Time":1458753318968},"S ... }
2016-03-23 20:46:06,739 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Task Metrics":{"Memory Bytes Spilled":0,"Result Size":1039,"Host Name":"xubunty.cotham.uk","Disk Bytes Spilled":0,"Executor Deserialize Time":17,"Result Serialization Time":2,"JVM GC Time":0,"Executor Run Time":65},"Event":"SparkListenerTask ... }
2016-03-23 20:46:06,741 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Task Info":{"Finish Time":1458753319080,"Launch Time":1458753318867,"Executor ID":"1","Getting Result Time":0,"Locality":"PROCESS_LOCAL","Task ID":8,"Accumulables":[],"Speculative":false,"Failed":false,"Host":"xubunty.cotham.uk","Attempt":0, ... }
2016-03-23 20:46:06,744 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Metrics":{"Executor Deserialize Time":18,"Result Size":1039,"Host Name":"xubunty.cotham.uk","Executor Run Time":62,"Disk Bytes Spilled":0,"Result Serialization Time":0,"JVM GC Time":0,"Memory Bytes Spilled":0},"Stage ID":0,"Task Info":{"Index":6,"Ex ... }
2016-03-23 20:46:06,748 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Info":{"Task ID":9,"Index":9,"Executor ID":"2","Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Host":"xubunty.cotham.uk","Launch Time":1458753318966,"Attempt":0,"Finish Time":1458753319088},"S ... }
2016-03-23 20:46:06,750 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Info":{"Index":7,"Launch Time":1458753318805,"Executor ID":"2","Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Task ID":7,"Failed":false,"Host":"xubunty.cotham.uk","Attempt":0,"Finish Time":1458753318968},"S ... }
2016-03-23 20:46:06,753 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Metrics":{"Memory Bytes Spilled":0,"Executor Run Time":52,"Result Size":1039,"Host Name":"xubunty.cotham.uk","Disk Bytes Spilled":0,"Result Serialization Time":0,"JVM GC Time":0,"Executor Deserialize Time":21},"Stage ID":0,"Task Info":{"Finish Time" ... }
2016-03-23 20:46:06,756 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Info":{"Task ID":9,"Index":9,"Executor ID":"2","Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Host":"xubunty.cotham.uk","Launch Time":1458753318966,"Attempt":0,"Finish Time":1458753319088},"T ... }
2016-03-23 20:46:06,761 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage Info":{"Completion Time":1458753319118,"Parent IDs":[],"Stage ID":0,"RDD Info":[{"Disk Size":0,"RDD ID":1,"Name":"MapPartitionsRDD","Storage Level":{"Use Memory":false,"Deserialized":false,"Replication":1,"Use Disk":false,"Use ExternalBlockStore":f ... }
2016-03-23 20:46:06,769 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Completion Time":1458753319153,"Job ID":0,"Job Result":{"Result":"JobSucceeded"},"Event":"SparkListenerJobEnd"}
2016-03-23 20:46:06,773 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Timestamp":1458753319404,"Event":"SparkListenerApplicationEnd"}
*** History Provider knows app is finished; information is in ApplicationHistoryInfo ***
2016-03-23 20:46:06,776 [qtp196369530-25] DEBUG server.YarnHistoryProvider (Logging.scala:logDebug(62)) - Application is complete: returning 'completed' application probe
*** ApplicationCache doesn't think so; adds the filter **
2016-03-23 20:46:06,778 [qtp196369530-25] DEBUG history.ApplicationCache (Logging.scala:logDebug(62)) - Application is incomplete: adding filter to check for updates
2016-03-23 20:46:06,784 [qtp196369530-25] DEBUG history.ApplicationCacheCheckFilter (Logging.scala:logDebug(62)) - initializing filter ApplicationCacheCheckFilter for application_1458752661638_0002/Some(1)
2016-03-23 20:46:06,800 [qtp196369530-25] DEBUG history.ApplicationCache (Logging.scala:logDebug(62)) - Loaded application application_1458752661638_0002/Some(1) -> UI org.apache.spark.ui.SparkUI@445b85d6, completed=false, probeTime=1458765966799
*** Every get on the UI hits the filter ***
2016-03-23 20:46:06,814 [qtp196369530-18] DEBUG history.ApplicationCacheCheckFilterRelay (Logging.scala:logDebug(62)) - Checking application_1458752661638_0002/Some(1) from /history/application_1458752661638_0002/1/
*** which then goes to the probe ***
2016-03-23 20:46:06,815 [qtp196369530-18] DEBUG history.ApplicationCache (ApplicationCache.scala:lookupAndUpdate(186)) - Probing at time 1458765966814 for updated application application_1458752661638_0002/1 -> UI org.apache.spark.ui.SparkUI@445b85d6, completed=false, probeTime=1458765966799
*** here: the no-op ***
2016-03-23 20:46:06,816 [qtp196369530-18] DEBUG server.YarnHistoryProvider (Logging.scala:logDebug(62)) - completedAppProbe(): no-op
2016-03-23 20:46:06,822 [qtp196369530-19] DEBUG history.ApplicationCacheCheckFilterRelay (Logging.scala:logDebug(62)) - Checking application_1458752661638_0002/Some(1) from /history/application_1458752661638_0002/1/jobs/
2016-03-23 20:46:06,823 [qtp196369530-19] DEBUG history.ApplicationCache (ApplicationCache.scala:lookupAndUpdate(186)) - Probing at time 1458765966823 for updated application application_1458752661638_0002/1 -> UI org.apache.spark.ui.SparkUI@445b85d6, completed=false, probeTime=1458765966814
2016-03-23 20:46:06,823 [qtp196369530-19] DEBUG server.YarnHistoryProvider (Logging.scala:logDebug(62)) - completedAppProbe(): no-op
2016-03-23 20:46:07,371 [qtp196369530-25] DEBUG server.YarnHistoryProvider (Logging.scala:logDebug
{code}
was (Author: stevel@apache.org):
This surfaced in logs of my yarn timeline integration tests. There a specific no-op() probe is hooked up on completed applications, so there's no overhead at all on their checks.
{code}
contains 32 event(s)
2016-03-23 20:46:06,594 [qtp196369530-25] INFO server.YarnHistoryProvider (Logging.scala:logInfo(58)) - Building Application UI Spark Pi attempt Some(1) under /history/application_1458752661638_0002/1
2016-03-23 20:46:06,595 [qtp196369530-25] INFO server.YarnHistoryProvider (Logging.scala:logInfo(58)) - App application_1458752661638_0002 history contains 32 events
2016-03-23 20:46:06,597 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Block Manager ID":{"Host":"192.168.1.132","Executor ID":"driver","Port":40481},"Event":"SparkListenerBlockManagerAdded","Timestamp":1458753291682,"Maximum Memory":480116736}
2016-03-23 20:46:06,608 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Event":"SparkListenerEnvironmentUpdate","System Properties":{"java.vm.info":"mixed mode","line.separator":"\n","java.vm.version":"25.74-b02","sun.cpu.isalist":"","java.vm.specification.vendor":"Oracle Corporation","os.version":"3.13.0-83-generic","java.l ... }
2016-03-23 20:46:06,614 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"App Attempt ID":"1","App ID":"application_1458752661638_0002","Timestamp":1458753289143,"User":"stevel","Event":"SparkListenerApplicationStart","Driver Logs":{"stdout":"http://xubunty.cotham.uk:8042/node/containerlogs/container_1458752661638_0002_01_0000 ... }
2016-03-23 20:46:06,621 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Executor ID":"1","Event":"SparkListenerExecutorAdded","Executor Info":{"Total Cores":1,"Log Urls":{"stderr":"http://xubunty.cotham.uk:8042/node/containerlogs/container_1458752661638_0002_01_000002/stevel/stderr?start=-4096","stdout":"http://xubunty.cotha ... }
2016-03-23 20:46:06,624 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Timestamp":1458753309182,"Executor ID":"2","Event":"SparkListenerExecutorAdded","Executor Info":{"Total Cores":1,"Host":"xubunty.cotham.uk","Log Urls":{"stdout":"http://xubunty.cotham.uk:8042/node/containerlogs/container_1458752661638_0002_01_000003/stev ... }
2016-03-23 20:46:06,625 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Block Manager ID":{"Executor ID":"1","Port":56415,"Host":"xubunty.cotham.uk"},"Event":"SparkListenerBlockManagerAdded","Maximum Memory":535953408,"Timestamp":1458753309248}
2016-03-23 20:46:06,626 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Block Manager ID":{"Port":49921,"Executor ID":"2","Host":"xubunty.cotham.uk"},"Event":"SparkListenerBlockManagerAdded","Maximum Memory":535953408,"Timestamp":1458753309295}
2016-03-23 20:46:06,632 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Event":"SparkListenerJobStart","Stage Infos":[{"Parent IDs":[],"Stage ID":0,"RDD Info":[{"Disk Size":0,"RDD ID":1,"Name":"MapPartitionsRDD","Storage Level":{"Use Memory":false,"Deserialized":false,"Replication":1,"Use Disk":false,"Use ExternalBlockStore" ... }
2016-03-23 20:46:06,666 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage Info":{"Parent IDs":[],"Stage ID":0,"RDD Info":[{"Disk Size":0,"RDD ID":1,"Name":"MapPartitionsRDD","Storage Level":{"Use Memory":false,"Deserialized":false,"Replication":1,"Use Disk":false,"Use ExternalBlockStore":false},"Callsite":"map at SparkPi ... }
2016-03-23 20:46:06,678 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Task Info":{"Executor ID":"1","Finish Time":0,"Launch Time":1458753311859,"Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Index":0,"Host":"xubunty.cotham.uk","Attempt":0,"Task ID":0}," ... }
2016-03-23 20:46:06,682 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Task Info":{"Finish Time":0,"Executor ID":"2","Getting Result Time":0,"Launch Time":1458753311896,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Task ID":1,"Host":"xubunty.cotham.uk","Attempt":0,"Index":1}," ... }
2016-03-23 20:46:06,684 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Task Info":{"Finish Time":0,"Executor ID":"2","Launch Time":1458753318378,"Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Host":"xubunty.cotham.uk","Index":2,"Attempt":0,"Task ID":2}," ... }
2016-03-23 20:46:06,686 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Event":"SparkListenerTaskStart","Stage Attempt ID":0,"Task Info":{"Launch Time":1458753318411,"Executor ID":"1","Finish Time":0,"Index":3,"Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false ... }
2016-03-23 20:46:06,688 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Task Info":{"Launch Time":1458753318555,"Executor ID":"1","Finish Time":0,"Task ID":4,"Index":4,"Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Host":"xubunty.cotham.uk","Attempt":0}," ... }
2016-03-23 20:46:06,691 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Task Info":{"Launch Time":1458753318411,"Executor ID":"1","Finish Time":1458753318582,"Index":3,"Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Host":"xubunty.cotham.uk","Attempt":0,"T ... }
2016-03-23 20:46:06,718 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Info":{"Executor ID":"2","Getting Result Time":0,"Launch Time":1458753311896,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Finish Time":1458753318655,"Task ID":1,"Failed":false,"Attempt":0,"Host":"xubunty.cotham.uk","Index":1},"T ... }
2016-03-23 20:46:06,721 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Event":"SparkListenerTaskEnd","Task Metrics":{"Result Size":1039,"Host Name":"xubunty.cotham.uk","Executor Run Time":239,"Disk Bytes Spilled":0,"Result Serialization Time":0,"Executor Deserialize Time":6012,"JVM GC Time":2150,"Memory Bytes S ... }
2016-03-23 20:46:06,724 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Event":"SparkListenerTaskStart","Task Info":{"Finish Time":1458753318809,"Executor ID":"2","Launch Time":1458753318668,"Index":5,"Getting Result Time":0,"Task ID":5,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":fa ... }
2016-03-23 20:46:06,727 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Task Info":{"Index":6,"Executor ID":"1","Task ID":6,"Finish Time":1458753318870,"Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Launch Time":1458753318715,"Host":"xubunty.cotham.uk","A ... }
2016-03-23 20:46:06,730 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Info":{"Finish Time":1458753318720,"Launch Time":1458753318555,"Executor ID":"1","Task ID":4,"Index":4,"Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Host":"xubunty.cotham.uk","Attempt":0},"S ... }
2016-03-23 20:46:06,733 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Metrics":{"Executor Deserialize Time":75,"Result Size":1039,"Host Name":"xubunty.cotham.uk","Disk Bytes Spilled":0,"Result Serialization Time":0,"Executor Run Time":66,"JVM GC Time":0,"Memory Bytes Spilled":0},"Task Info":{"Finish Time":145875331872 ... }
2016-03-23 20:46:06,736 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Info":{"Index":7,"Launch Time":1458753318805,"Executor ID":"2","Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Task ID":7,"Failed":false,"Host":"xubunty.cotham.uk","Attempt":0,"Finish Time":1458753318968},"S ... }
2016-03-23 20:46:06,739 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Task Metrics":{"Memory Bytes Spilled":0,"Result Size":1039,"Host Name":"xubunty.cotham.uk","Disk Bytes Spilled":0,"Executor Deserialize Time":17,"Result Serialization Time":2,"JVM GC Time":0,"Executor Run Time":65},"Event":"SparkListenerTask ... }
2016-03-23 20:46:06,741 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage ID":0,"Task Info":{"Finish Time":1458753319080,"Launch Time":1458753318867,"Executor ID":"1","Getting Result Time":0,"Locality":"PROCESS_LOCAL","Task ID":8,"Accumulables":[],"Speculative":false,"Failed":false,"Host":"xubunty.cotham.uk","Attempt":0, ... }
2016-03-23 20:46:06,744 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Metrics":{"Executor Deserialize Time":18,"Result Size":1039,"Host Name":"xubunty.cotham.uk","Executor Run Time":62,"Disk Bytes Spilled":0,"Result Serialization Time":0,"JVM GC Time":0,"Memory Bytes Spilled":0},"Stage ID":0,"Task Info":{"Index":6,"Ex ... }
2016-03-23 20:46:06,748 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Info":{"Task ID":9,"Index":9,"Executor ID":"2","Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Host":"xubunty.cotham.uk","Launch Time":1458753318966,"Attempt":0,"Finish Time":1458753319088},"S ... }
2016-03-23 20:46:06,750 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Info":{"Index":7,"Launch Time":1458753318805,"Executor ID":"2","Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Task ID":7,"Failed":false,"Host":"xubunty.cotham.uk","Attempt":0,"Finish Time":1458753318968},"S ... }
2016-03-23 20:46:06,753 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Metrics":{"Memory Bytes Spilled":0,"Executor Run Time":52,"Result Size":1039,"Host Name":"xubunty.cotham.uk","Disk Bytes Spilled":0,"Result Serialization Time":0,"JVM GC Time":0,"Executor Deserialize Time":21},"Stage ID":0,"Task Info":{"Finish Time" ... }
2016-03-23 20:46:06,756 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Task Info":{"Task ID":9,"Index":9,"Executor ID":"2","Getting Result Time":0,"Locality":"PROCESS_LOCAL","Accumulables":[],"Speculative":false,"Failed":false,"Host":"xubunty.cotham.uk","Launch Time":1458753318966,"Attempt":0,"Finish Time":1458753319088},"T ... }
2016-03-23 20:46:06,761 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Stage Info":{"Completion Time":1458753319118,"Parent IDs":[],"Stage ID":0,"RDD Info":[{"Disk Size":0,"RDD ID":1,"Name":"MapPartitionsRDD","Storage Level":{"Use Memory":false,"Deserialized":false,"Replication":1,"Use Disk":false,"Use ExternalBlockStore":f ... }
2016-03-23 20:46:06,769 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Completion Time":1458753319153,"Job ID":0,"Job Result":{"Result":"JobSucceeded"},"Event":"SparkListenerJobEnd"}
2016-03-23 20:46:06,773 [qtp196369530-25] DEBUG yarn.YarnTimelineUtils (Logging.scala:logDebug(62)) - toSparkEvent payload is {"Timestamp":1458753319404,"Event":"SparkListenerApplicationEnd"}
*** History Provider knows app is finished; information is in ApplicationHistoryInfo ***
2016-03-23 20:46:06,776 [qtp196369530-25] DEBUG server.YarnHistoryProvider (Logging.scala:logDebug(62)) - Application is complete: returning 'completed' application probe{code}
*** ApplicationCache doesn't think so; adds the filter **
2016-03-23 20:46:06,778 [qtp196369530-25] DEBUG history.ApplicationCache (Logging.scala:logDebug(62)) - Application is incomplete: adding filter to check for updates
2016-03-23 20:46:06,784 [qtp196369530-25] DEBUG history.ApplicationCacheCheckFilter (Logging.scala:logDebug(62)) - initializing filter ApplicationCacheCheckFilter for application_1458752661638_0002/Some(1)
2016-03-23 20:46:06,800 [qtp196369530-25] DEBUG history.ApplicationCache (Logging.scala:logDebug(62)) - Loaded application application_1458752661638_0002/Some(1) -> UI org.apache.spark.ui.SparkUI@445b85d6, completed=false, probeTime=1458765966799
*** Every get on the UI hits the filter ***
2016-03-23 20:46:06,814 [qtp196369530-18] DEBUG history.ApplicationCacheCheckFilterRelay (Logging.scala:logDebug(62)) - Checking application_1458752661638_0002/Some(1) from /history/application_1458752661638_0002/1/
*** which then goes to the probe ***
2016-03-23 20:46:06,815 [qtp196369530-18] DEBUG history.ApplicationCache (ApplicationCache.scala:lookupAndUpdate(186)) - Probing at time 1458765966814 for updated application application_1458752661638_0002/1 -> UI org.apache.spark.ui.SparkUI@445b85d6, completed=false, probeTime=1458765966799
*** here: the no-op ***
2016-03-23 20:46:06,816 [qtp196369530-18] DEBUG server.YarnHistoryProvider (Logging.scala:logDebug(62)) - completedAppProbe(): no-op
2016-03-23 20:46:06,822 [qtp196369530-19] DEBUG history.ApplicationCacheCheckFilterRelay (Logging.scala:logDebug(62)) - Checking application_1458752661638_0002/Some(1) from /history/application_1458752661638_0002/1/jobs/
2016-03-23 20:46:06,823 [qtp196369530-19] DEBUG history.ApplicationCache (ApplicationCache.scala:lookupAndUpdate(186)) - Probing at time 1458765966823 for updated application application_1458752661638_0002/1 -> UI org.apache.spark.ui.SparkUI@445b85d6, completed=false, probeTime=1458765966814
2016-03-23 20:46:06,823 [qtp196369530-19] DEBUG server.YarnHistoryProvider (Logging.scala:logDebug(62)) - completedAppProbe(): no-op
2016-03-23 20:46:07,371 [qtp196369530-25] DEBUG server.YarnHistoryProvider (Logging.scala:logDebug
{code}
> history server application cache doesn't detect that apps are completed
> -----------------------------------------------------------------------
>
> Key: SPARK-14106
> URL: https://issues.apache.org/jira/browse/SPARK-14106
> Project: Spark
> Issue Type: Bug
> Components: Web UI
> Affects Versions: 2.0.0
> Reporter: Steve Loughran
> Priority: Minor
>
> The cache in SPARK-7889 hooks up a filter to the web UI of incomplete apps, triggering a probe to see if the app is out of date.
> It looks like the filter is being hooked up to completed apps too, that is: the {{ApplicationCache}} isn't correctly detecting when apps are finished.
--
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