[
https://issues.apache.org/jira/browse/SPARK-14106?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15209153#comment-15209153
]
Steve Loughran commented on SPARK-14106:
----------------------------------------
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-unsubscr...@spark.apache.org
For additional commands, e-mail: issues-h...@spark.apache.org
