[SPARK-21922] Fix duration always updating when task failed but status is still RUN… #19132

caneGuy · 2017-09-05T10:45:38Z

…NING

What changes were proposed in this pull request?

When driver quit abnormally which cause executor shutdown and task metrics can not be sent to driver for updating.In this case the status will always be 'RUNNING' and the duration on history UI will be 'CurrentTime - launchTime' which increase infinitely.
We can fix this time by modify time of event log since this time has gotten when FSHistoryProvider fetch event log from File System.
And the result picture is uploaded in SPARK-21922.
How to reproduce?
(1) Submit a job to spark on yarn
(2) Mock an oom(or other case can make driver quit abnormally) senario for driver
(3) Make sure executor is running task when driver quitting
(4) Open the history server and checkout result
It is not a corner case since there are many such jobs in our current cluster.

How was this patch tested?

Deploy historyserver and open a job has this problem.

…NING

ajbozarth · 2017-09-05T20:10:12Z

Though this may fix the problem it is 100% the wrong way to do it for multiple reasons:

The UI should not touch the FS, FS access it abstracted out so the UI is can work with multiple FS impls
This fix assumes it's running the History Server in a class used by both the Web UI and SHS

Without a deeper look at the issue I would instead look at why the problem is occurring and fixing that rather than putting a bandaid on the UI like this. (Note: I've done this before and got the same response, nothing personally :)

I would recommend closing this and opening a new PR once you figure out a new solution.

caneGuy · 2017-09-06T01:36:43Z

Thanks for your recommendation @ajbozarth .Could you put a link for your pr?For the problem you mentioned,i have thought about them.
1、FsHistoryServer will always use FS to get event log
2、For spark ui, my implementation will not access FS.

…till RUNNING" This reverts commit 03a33a9.

…yServer

caneGuy · 2017-09-06T03:44:56Z

@ajbozarth I have updated the implementation which only access FS in FSHistoryServerProvider

ajbozarth

Thank you for the update, this is a much better implementation, just one nit otherwise LGTM

ajbozarth · 2017-09-06T07:55:29Z

core/src/main/scala/org/apache/spark/status/api/v1/AllStagesResource.scala

      attempt = uiData.taskInfo.attemptNumber,
      launchTime = new Date(uiData.taskInfo.launchTime),
-      duration = uiData.taskDuration,
+      duration = uiData.taskDuration(),


this is unrelated and unnecessary

Since i have changed taskDuration below,if do not add () here a compiler error will occur.

odd, I thought for sure it'd be fine, then this LGTM

Thanks @ajbozarth

Here what if we call the REST API on history server to get stage info? Looks like we may still have this issue since we don't have last update time here, what do you think @ajbozarth ?

You are right, @jerryshao .IIUC, the ui in AllStagesResource.scala is passed from ApiRootResource which also create sparkUI by FSHistoryProvider.So we can also get lastUpdateTime from this ui in AllStagesResource and pass to the taskDuration interface.I think it is another problem for REST?Should we fix here?

Yes, if it is not a big change I think it should be fixed here. Because currently with this fix UI and REST API are inconsistent.

caneGuy · 2017-09-06T12:49:37Z

Ping @kiszk @jerryshao can you help reivew this?

caneGuy · 2017-09-08T02:06:19Z

@vanzin @zsxwing could you help reivew this?Thanks.

jerryshao · 2017-09-08T07:15:17Z

Is this a problem only in History UI, or it also has issues in Live UI? From my understanding you only pass a last update time for history UI, so is it intended?

Also you mentioned "When executor failed and task metrics have not send to driver,the status will always be 'RUNNING'", is this a bug in scheduler?

caneGuy · 2017-09-08T09:37:30Z

It just appear on history ui since Live ui will use heartbeat metric result @jerryshao(From my understanding) .It appears when Driver exit unnormally,then status of taskinfo can not be updated correctlly.

jerryshao · 2017-09-11T00:59:17Z

So your PR description is quite confusing, would you please elaborate your problem in detail and describe how to reproduce the issue.

caneGuy · 2017-09-11T01:46:08Z

Done @jerryshao

jerryshao · 2017-09-11T06:04:47Z

Still I have a question about history server, is you event log an incomplete event log or completed when you met such issue?

caneGuy · 2017-09-11T09:46:40Z

@jerryshao Thanks for your time. IIUC, event log is completed since driver has not dropped any event of executor which has problem described above.See below,driver only drop two events after shutting down:
2017-09-11,17:08:57,605 ERROR org.apache.spark.scheduler.LiveListenerBus: SparkListenerBus has already stopped! Dropping event SparkListenerExecutorMetricsUpdate(300,WrappedArray()) 2017-09-11,17:08:57,623 INFO org.apache.spark.deploy.yarn.YarnAllocator: Driver requested a total number of 0 executor(s). 2017-09-11,17:08:57,624 INFO org.apache.spark.scheduler.cluster.YarnClusterSchedulerBackend: Shutting down all executors 2017-09-11,17:08:57,624 INFO org.apache.spark.scheduler.cluster.YarnClusterSchedulerBackend: Asking each executor to shut down 2017-09-11,17:08:57,629 ERROR org.apache.spark.scheduler.LiveListenerBus: SparkListenerBus has already stopped! Dropping event SparkListenerExecutorMetricsUpdate(258,WrappedArray())

And below showing an executor has this problem:

Case here is a job running today of our cluster.

jerryshao · 2017-09-12T02:28:37Z

ok to test.

jerryshao

Can you please make sure everything is OK in Live UI?

jerryshao · 2017-09-12T02:37:26Z

core/src/main/scala/org/apache/spark/ui/SparkUI.scala

    val operationGraphListener: RDDOperationGraphListener,
    var appName: String,
    val basePath: String,
+    val lastUpdateTime: Long = -1L,


I would like to user Option[Long] = None as default value to reflect there's no update time.

Updated @jerryshao Thanks for your time.

jerryshao · 2017-09-12T02:42:00Z

Looks like I don't have the Jenkins permission to trigger UT 😞 . Let me ping @srowen to trigger the test.

caneGuy · 2017-09-12T03:07:17Z

Yes i have confirmed.Below is a testing job: @jerryshao

HyukjinKwon · 2017-09-12T13:13:33Z

ok to test

HyukjinKwon · 2017-09-12T13:18:45Z

@jerryshao, for triggering tests on Jenkins, I think this should be added by its admin manually as well if I understood correctly. In my case, I asked this to Josh Rosen before via email privately. I am quite sure you are facing the same issue I (and Holden, Felix and Takuya) met before if I understood correctly.

jerryshao · 2017-09-12T13:26:11Z

Thanks @HyukjinKwon , I will ping Josh about this thing 😄 .

SparkQA · 2017-09-12T16:34:32Z

Test build #81678 has finished for PR 19132 at commit 25fe22c.

This patch passes all tests.
This patch merges cleanly.
This patch adds no public classes.

caneGuy · 2017-09-12T23:51:22Z

@jerryshao @HyukjinKwon Jenkins done.Thanks too much.

jerryshao · 2017-09-13T01:47:11Z

Overall LGTM, @ajbozarth can you please review again?

ajbozarth · 2017-09-13T01:50:59Z

I've been following, still LGTM

jerryshao · 2017-09-13T06:28:24Z

core/src/main/scala/org/apache/spark/status/api/v1/AllStagesResource.scala

    } yield {
-      AllStagesResource.stageUiToStageData(status, stageInfo, stageUiData, includeDetails = false)
+      AllStagesResource.stageUiToStageData(
+        status, stageInfo, stageUiData, includeDetails = false, Some(ui))


It's not a good design to pass in SparkUI to only get lastUpdate, the API looks weird to add this SparkUI argument, the fix here only just make it work. It is better to add one more field in StageUIData or TaskUIData if possible.

SparkQA · 2017-09-13T07:04:45Z

Test build #81709 has finished for PR 19132 at commit 560d442.

This patch fails due to an unknown error code, -9.
This patch merges cleanly.
This patch adds no public classes.

SparkQA · 2017-09-13T10:49:41Z

Test build #81710 has finished for PR 19132 at commit f0e1ded.

This patch passes all tests.
This patch merges cleanly.
This patch adds no public classes.

jerryshao · 2017-09-14T03:22:18Z

core/src/main/scala/org/apache/spark/ui/jobs/UIData.scala

    var memoryBytesSpilled: Long = _
    var diskBytesSpilled: Long = _
    var isBlacklisted: Int = _
+    var jobLastUpdateTime: Option[Long] = None


Is it better to rename to stageLastUpdateTime or just lastUpdateTime? Since this structure is unrelated to job, would be better to not involve "job".

jerryshao · 2017-09-14T03:25:44Z

core/src/main/scala/org/apache/spark/status/api/v1/OneStageResource.scala

      @DefaultValue("ID") @QueryParam("sortBy") sortBy: TaskSorting): Seq[TaskData] = {
    withStageAttempt(stageId, stageAttemptId) { stage =>
-      val tasks = stage.ui.taskData.values.map{AllStagesResource.convertTaskData}.toIndexedSeq
+      val tasks = stage.ui.taskData.values.map{


The style should be changed to map { AllStagesResource.convertTaskData(_, ui.lastUpdateTime) }, requires whitespace between { and }. You could check other similar codes about the style.

jerryshao · 2017-09-14T06:17:59Z

core/src/main/scala/org/apache/spark/status/api/v1/AllStagesResource.scala

    val taskData = if (includeDetails) {
-      Some(stageUiData.taskData.map { case (k, v) => k -> convertTaskData(v) } )
+      Some(stageUiData.taskData.map { case (k, v) =>
+        k -> convertTaskData(v, stageUiData.lastUpdateTime) } )


Sorry I may not stated clearly, it should be:

Some(stageUiData.taskData.map { case (k, v) => k -> convertTaskData(v, stageUiData.lastUpdateTime) })

No whitespace after "}".

Thanks for your patient.Actually i did not check carefully.

SparkQA · 2017-09-14T07:04:45Z

Test build #81764 has finished for PR 19132 at commit 8ec4319.

This patch fails due to an unknown error code, -9.
This patch merges cleanly.
This patch adds no public classes.

SparkQA · 2017-09-14T10:19:49Z

Test build #81768 has finished for PR 19132 at commit 06035f7.

This patch passes all tests.
This patch merges cleanly.
This patch adds no public classes.

jerryshao · 2017-09-14T12:39:11Z

LGTM, merging to master, if possible to 2.2.

jerryshao · 2017-09-14T12:44:45Z

Cannot cleanly merge to 2.2, so this will only land to master branch.

caneGuy · 2017-09-14T14:22:33Z

@jerryshao Thanks.

Fix duration always updating when task failed but status is still RUN…

03a33a9

…NING

caneGuy added 2 commits September 6, 2017 11:02

Revert "Fix duration always updating when task failed but status is s…

a442000

…till RUNNING" This reverts commit 03a33a9.

Do not access fs in SPARK-UI pass event log access time from FSHistor…

8b47418

…yServer

ajbozarth approved these changes Sep 6, 2017

View reviewed changes

jerryshao requested changes Sep 12, 2017

View reviewed changes

Update as commented

25fe22c

Update as commented

560d442

jerryshao reviewed Sep 13, 2017

View reviewed changes

Make api more cleaner

f0e1ded

jerryshao reviewed Sep 14, 2017

View reviewed changes

Modify field name and update code style

8ec4319

jerryshao reviewed Sep 14, 2017

View reviewed changes

Update code style

06035f7

asfgit closed this in 4b88393 Sep 14, 2017

caneGuy deleted the zhoukang/fix-duration branch September 25, 2017 12:07

[SPARK-21922] Fix duration always updating when task failed but status is still RUN… #19132

[SPARK-21922] Fix duration always updating when task failed but status is still RUN… #19132

Uh oh!

Conversation

caneGuy commented Sep 5, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

What changes were proposed in this pull request?

How was this patch tested?

Uh oh!

ajbozarth commented Sep 5, 2017

Uh oh!

caneGuy commented Sep 6, 2017

Uh oh!

caneGuy commented Sep 6, 2017

Uh oh!

ajbozarth left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

caneGuy Sep 6, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

caneGuy commented Sep 6, 2017

Uh oh!

caneGuy commented Sep 8, 2017

Uh oh!

jerryshao commented Sep 8, 2017

Uh oh!

caneGuy commented Sep 8, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

jerryshao commented Sep 11, 2017

Uh oh!

caneGuy commented Sep 11, 2017

Uh oh!

jerryshao commented Sep 11, 2017

Uh oh!

caneGuy commented Sep 11, 2017

Uh oh!

jerryshao commented Sep 12, 2017

Uh oh!

jerryshao left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

caneGuy Sep 12, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jerryshao commented Sep 12, 2017

Uh oh!

caneGuy commented Sep 12, 2017

Uh oh!

HyukjinKwon commented Sep 12, 2017

Uh oh!

HyukjinKwon commented Sep 12, 2017

Uh oh!

jerryshao commented Sep 12, 2017

Uh oh!

SparkQA commented Sep 12, 2017

Uh oh!

caneGuy commented Sep 12, 2017

Uh oh!

jerryshao commented Sep 13, 2017

Uh oh!

ajbozarth commented Sep 13, 2017

Uh oh!

caneGuy commented Sep 5, 2017 •

edited

Loading

caneGuy Sep 6, 2017 •

edited

Loading

caneGuy commented Sep 8, 2017 •

edited

Loading

caneGuy Sep 12, 2017 •

edited

Loading

jerryshao Sep 13, 2017 •

edited

Loading

jerryshao Sep 14, 2017 •

edited

Loading

jerryshao Sep 14, 2017 •

edited

Loading