[SPARK-32024][WEBUI] Update ApplicationStoreInfo.size during HistoryServerDiskManager initializing #28859

zhli1142015 · 2020-06-18T14:20:09Z

What changes were proposed in this pull request?

Update ApplicationStoreInfo.size to real size during HistoryServerDiskManager initializing.

Why are the changes needed?

This PR is for fixing bug 32024. We found after history server restart, below error would randomly happen: "java.lang.IllegalStateException: Disk usage tracker went negative (now = -, delta = -)" from HistoryServerDiskManager.

Cause: Reading data from level db would trigger table file compaction, which may also trigger size of level db directory changes. This size change may not be recorded in LevelDB (ApplicationStoreInfo in listing). When service restarts, currentUsage is calculated from real directory size, but ApplicationStoreInfo are loaded from leveldb, then currentUsage may be less then sum of ApplicationStoreInfo.size. In makeRoom() function, ApplicationStoreInfo.size is used to update usage. Then currentUsage becomes negative after several round of release() and lease() (makeRoom()).
Reproduce: we can reproduce this issue in dev environment by reducing config value of "spark.history.retainedApplications" and "spark.history.store.maxDiskUsage" to some small values. Here are steps: 1. start history server, load some applications and access some pages (maybe "stages" page to trigger leveldb compaction). 2. restart HS, and refresh pages.
I also added an UT to simulate this case in HistoryServerDiskManagerSuite.
Benefit: this change would help improve history server reliability.

Does this PR introduce any user-facing change?

No

How was this patch tested?

Add unit test and manually tested it.

zhli1142015 · 2020-06-18T14:26:40Z

@jiangxb1987 , @dongjoon-hyun , @ueshin , Could you please help to review this?

gatorsmile · 2020-06-20T04:12:52Z

cc @gengliangwang

HeartSaVioR · 2020-06-21T12:36:14Z

core/src/main/scala/org/apache/spark/deploy/history/HistoryServerDiskManager.scala

@@ -83,6 +83,20 @@ private class HistoryServerDiskManager(
      listing.delete(info.getClass(), info.path)
    }

+    // Reading level db would trigger table file compaction, then it may cause size of level db


We could apply "partition" instead of filter in L78, so that we only call iterate with view once and retrieve two lists (orphans, existing) - L90 can use existing to avoid calling view again.

@HeartSaVioR , thank you for your comments, updated it.

HeartSaVioR · 2020-06-21T12:44:52Z

core/src/test/scala/org/apache/spark/deploy/history/HistoryServerDiskManagerSuite.scala

@@ -158,4 +158,26 @@ class HistoryServerDiskManagerSuite extends SparkFunSuite with BeforeAndAfter {
    assert(manager.approximateSize(50L, true) > 50L)
  }

+  test ("SPARK-32024: update ApplicationStoreInfo.size during initializing") {


nit: no space between test and (

thanks, updated.

HeartSaVioR · 2020-06-21T12:50:21Z

core/src/test/scala/org/apache/spark/deploy/history/HistoryServerDiskManagerSuite.scala

+    val leaseB = manager1.lease(2)
+    assert(manager1.free() === 1)
+    leaseB.rollback()
+    assert(manager1.free() === 3)


Probably better to simulate another case: actual directory size is bigger than appinfo - some cache entities can be written after replaying, which "might" affect the size.
(That said, the mismatch between appinfo and actual dir size also occurs during run, though it may not matter unless there's no reflection.)

Thanks, this is a valid case, i added it in my UT.

…nStoreInfo.size-during-disk-manager-initialize

zhli1142015 · 2020-06-23T10:18:42Z

Gently ping, @HeartSaVioR , could you please help review again?
@jiangxb1987 , @dongjoon-hyun , @ueshin , @gengliangwang , could you please help to review?

HeartSaVioR · 2020-06-24T10:55:02Z

core/src/test/scala/org/apache/spark/deploy/history/HistoryServerDiskManagerSuite.scala

+    doReturn(3L).when(manager2).sizeOf(meq(new File(testDir, "apps")))
+    manager2.initialize()
+    assert(manager2.free() === 0)
+    val leaseC = manager2.lease(2)


Better to explicitly mention it leads eviction on cached entities, hence free() goes to 1.

Thanks, updated

HeartSaVioR · 2020-06-24T10:56:04Z

core/src/test/scala/org/apache/spark/deploy/history/HistoryServerDiskManagerSuite.scala

+    doReturn(2L).when(manager1).sizeOf(meq(leaseB.tmpPath))
+    val dstB = leaseB.commit("app2", None)
+    assert(manager1.committed() === 2)
+    val manager2 = mockManager()


Let's add some empty lines in overall to bring readability.

Thanks, updated

HeartSaVioR · 2020-06-24T11:04:00Z

core/src/test/scala/org/apache/spark/deploy/history/HistoryServerDiskManagerSuite.scala

+    doReturn(3L).when(manager).sizeOf(meq(leaseA.tmpPath))
+    val dstA = leaseA.commit("app1", None)
+    assert(manager.free() === 0)
+    assert(manager.committed() === 3)


Could we track and verify ApplicationStoreInfo in store as well? I see the test represents how HistoryServerDiskManager fails without the patch, but it would be pretty much intuitive if we also verify what we've changed directly.

Good idea, updated.

HeartSaVioR

LGTM

zhli1142015 · 2020-07-01T06:17:49Z

Gently ping, @jiangxb1987 , @dongjoon-hyun , @ueshin , @gengliangwang , could you please help to review?

gengliangwang · 2020-07-02T02:25:08Z

ok to test

SparkQA · 2020-07-02T02:34:00Z

Test build #124847 has finished for PR 28859 at commit b9057ec.

This patch fails build dependency tests.
This patch merges cleanly.
This patch adds no public classes.

HeartSaVioR · 2020-07-02T11:50:44Z

retest this, please

SparkQA · 2020-07-02T12:02:56Z

Test build #124897 has finished for PR 28859 at commit b9057ec.

This patch fails build dependency tests.
This patch merges cleanly.
This patch adds no public classes.

HeartSaVioR · 2020-07-02T23:25:27Z

retest this, please

zhli1142015 · 2020-07-03T00:38:34Z

retest this, please

gengliangwang · 2020-07-03T01:53:23Z

core/src/main/scala/org/apache/spark/deploy/history/HistoryServerDiskManager.scala

-    val orphans = listing.view(classOf[ApplicationStoreInfo]).asScala.filter { info =>
-      !new File(info.path).exists()
-    }.toSeq
+    val (existing, orphans) = listing


nit: existing => existences

gengliangwang · 2020-07-03T01:55:20Z

core/src/main/scala/org/apache/spark/deploy/history/HistoryServerDiskManager.scala

+    // directory changed. When service restarts, "currentUsage" is calculated from real directory
+    // size. Update "ApplicationStoreInfo.size" to ensure "currentUsage" equals
+    // sum of "ApplicationStoreInfo.size".
+    val changedStoreInfo = existing.filter { info =>


Nit: I think we can write this in one loop:

existing.foreach { info => val fileSize = sizeOf(new File(info.path) if (fileSize != info.size) { listing.write(info.copy(size = fileSize)) } }

thanks, updated.

SparkQA · 2020-07-05T20:03:59Z

Test build #124947 has finished for PR 28859 at commit ed05872.

This patch fails build dependency tests.
This patch merges cleanly.
This patch adds no public classes.

HeartSaVioR · 2020-07-05T22:20:22Z

retest this, please

HeartSaVioR · 2020-07-07T23:29:05Z

retest this, please

SparkQA · 2020-07-08T03:15:43Z

Test build #125267 has finished for PR 28859 at commit ed05872.

This patch fails Spark unit tests.
This patch merges cleanly.
This patch adds no public classes.

HeartSaVioR · 2020-07-08T06:52:34Z

The PR builders look to be quite unstable, though all the test failures are not related to the change.

build 125054

org.apache.spark.sql.hive.thriftserver.HiveSessionImplSuite.(It is not a test it is a sbt.testing.SuiteSelector)

build 125079

org.apache.spark.sql.hive.thriftserver.CliSuite.xml

build 125250

org.apache.spark.sql.kafka010.KafkaRelationSuiteV1.timestamp provided for starting, ending not provided
org.apache.spark.sql.hive.thriftserver.HiveSessionImplSuite.(It is not a test it is a sbt.testing.SuiteSelector)

build 125267

org.apache.spark.sql.execution.DataSourceV2ScanExecRedactionSuite.SPARK-30362: test input metrics for DSV2
org.apache.spark.sql.hive.thriftserver.CliSuite.Pad Decimal numbers with trailing zeros to the scale of the column

There's no consistent failure on specific test in these builds, which represents the change doesn't break the test.

HeartSaVioR · 2020-07-08T06:56:54Z

Let me trigger the test once more. If that also fails with flaky test we'd probably be better to just merge.

HeartSaVioR · 2020-07-08T06:57:03Z

retest this, please

SparkQA · 2020-07-08T10:00:03Z

Test build #125313 has finished for PR 28859 at commit ed05872.

This patch fails Spark unit tests.
This patch merges cleanly.
This patch adds no public classes.

HeartSaVioR · 2020-07-08T12:33:40Z

build 125313

org.apache.spark.sql.hive.thriftserver.HiveSessionImplSuite.(It is not a test it is a sbt.testing.SuiteSelector)

zhli1142015 · 2020-07-08T12:55:42Z

Thank you for your helping @HeartSaVioR . cc @gengliangwang , is it ok to merge this PR, or I need to run test again?

…erverDiskManager initializing ### What changes were proposed in this pull request? Update ApplicationStoreInfo.size to real size during HistoryServerDiskManager initializing. ### Why are the changes needed? This PR is for fixing bug [32024](https://issues.apache.org/jira/browse/SPARK-32024). We found after history server restart, below error would randomly happen: "java.lang.IllegalStateException: Disk usage tracker went negative (now = -***, delta = -***)" from `HistoryServerDiskManager`. ![Capture](https://user-images.githubusercontent.com/10524738/85034468-fda4ae80-b136-11ea-9011-f0c3e6508002.JPG) **Cause**: Reading data from level db would trigger table file compaction, which may also trigger size of level db directory changes. This size change may not be recorded in LevelDB (`ApplicationStoreInfo` in `listing`). When service restarts, `currentUsage` is calculated from real directory size, but `ApplicationStoreInfo` are loaded from leveldb, then `currentUsage` may be less then sum of `ApplicationStoreInfo.size`. In `makeRoom()` function, `ApplicationStoreInfo.size` is used to update usage. Then `currentUsage` becomes negative after several round of `release()` and `lease()` (`makeRoom()`). **Reproduce**: we can reproduce this issue in dev environment by reducing config value of "spark.history.retainedApplications" and "spark.history.store.maxDiskUsage" to some small values. Here are steps: 1. start history server, load some applications and access some pages (maybe "stages" page to trigger leveldb compaction). 2. restart HS, and refresh pages. I also added an UT to simulate this case in `HistoryServerDiskManagerSuite`. **Benefit**: this change would help improve history server reliability. ### Does this PR introduce _any_ user-facing change? No ### How was this patch tested? Add unit test and manually tested it. Closes #28859 from zhli1142015/update-ApplicationStoreInfo.size-during-disk-manager-initialize. Authored-by: Zhen Li <zhli@microsoft.com> Signed-off-by: Jungtaek Lim (HeartSaVioR) <kabhwan.opensource@gmail.com> (cherry picked from commit 8e7fc04) Signed-off-by: Jungtaek Lim (HeartSaVioR) <kabhwan.opensource@gmail.com>

HeartSaVioR · 2020-07-08T13:01:06Z

Thanks @zhli1142015 for the contribution! Merged into master, branch-3.0, branch-2.4 respectively.

HyukjinKwon · 2020-07-08T13:32:29Z

Hey @HeartSaVioR, let's don't merge PRs when tests are being failed.

HeartSaVioR · 2020-07-08T13:46:39Z

Oh OK. Thanks for noticing. I hope we'd be a bit flexible and pragmatic, but I also sincerely respect the rule and policy. I'll follow it in next time.

HyukjinKwon · 2020-07-08T14:00:44Z

Honestly, I do merge too time to time e.g.) when there are some reasons or when the Jenkins build itself is completely orthogonal such as fixing AppVeyor CI issue .. but should be best to stick to the standard in general :-).

dongjoon-hyun · 2020-07-08T16:47:44Z

Hi, All. This breaks branch-2.4 UT. I didn't take a look at the other branches.

- SPARK-32024: update ApplicationStoreInfo.size during initializing *** FAILED ***
  0 did not equal 3 (HistoryServerDiskManagerSuite.scala:168)

dongjoon-hyun · 2020-07-08T16:49:46Z

Could you recover this please via a follow-up or a revert, @HeartSaVioR ?

dongjoon-hyun · 2020-07-08T19:10:42Z

It turns out this breaks branch-3.0, too

https://amplab.cs.berkeley.edu/jenkins/view/Spark%20QA%20Test%20(Dashboard)/job/spark-branch-3.0-test-maven-hadoop-2.7-hive-1.2/lastCompletedBuild/testReport/org.apache.spark.deploy.history/HistoryServerDiskManagerSuite/SPARK_32024__update_ApplicationStoreInfo_size_during_initializing/

HeartSaVioR · 2020-07-08T20:40:25Z

Thanks for sharing the test failure, @dongjoon-hyun . I took a quick look, and realized 245aee9 was landed only on master branch (as it's an improvement) which got rid of size call in destination path, whereas branch-3.0 and branch-2.4 don't.

Below is the commit I fixed the test in branch-3.0 (confirmed test passed):

HeartSaVioR@6a36c9c

and I also confirmed the test pass if we cherry pick 245aee9 to branch-3.0:

HeartSaVioR@c8c9531

I'm now applying the fix to branch-2.4 - IDE requires rebuild on switching 3.x vs 2.x so it'd take time, but the mechanism of the fix should be applied to 2.4 as well.

Would we like to go with hotfix, or cherry pick 245aee9?

HeartSaVioR · 2020-07-08T20:41:46Z

Probably better to land the hotfix into master as well if we go with hotfix, as it looks to be safer assumption rather than depending on 245aee9.

zhli1142015 · 2020-07-08T20:53:31Z

Thanks @HeartSaVioR and @dongjoon-hyun . i can reproduce it on branch 3.0 also, the cause is same as @HeartSaVioR mentioned, commit 245aee9 is not in branch 2.4 and 3.0. how about fix test case "SPARK-32024: update ApplicationStoreInfo.size during initializing" in default , 2.4 and 3.0, let it only covers this change?

HeartSaVioR · 2020-07-08T20:56:54Z

I'll submit a hotfix patch against master (can cherry-pick to broken branches) once I confirmed my fix works for branch-2.4 as well (it should work with master as well, as it "adds" the when statement).

dongjoon-hyun · 2020-07-08T21:30:53Z

Thank you, @HeartSaVioR !

HeartSaVioR · 2020-07-08T21:42:53Z

OK confirmed the hotfix works in master and branch-2.4 as well. Will submit a hotfix soon.

…hen statements ### What changes were proposed in this pull request? This patch fixes the test failure due to the missing when statements for destination path. Note that it didn't fail on master branch, because 245aee9 got rid of size call in destination path, but still good to not depend on 245aee9. ### Why are the changes needed? The build against branch-3.0 / branch-2.4 starts to fail after merging SPARK-32024 (#28859) and this patch will fix it. ### Does this PR introduce _any_ user-facing change? No. ### How was this patch tested? Ran modified UT against master / branch-3.0 / branch-2.4. Closes #29046 from HeartSaVioR/QUICKFIX-SPARK-32024. Authored-by: Jungtaek Lim (HeartSaVioR) <kabhwan.opensource@gmail.com> Signed-off-by: HyukjinKwon <gurwls223@apache.org>

…hen statements ### What changes were proposed in this pull request? This patch fixes the test failure due to the missing when statements for destination path. Note that it didn't fail on master branch, because 245aee9 got rid of size call in destination path, but still good to not depend on 245aee9. ### Why are the changes needed? The build against branch-3.0 / branch-2.4 starts to fail after merging SPARK-32024 (#28859) and this patch will fix it. ### Does this PR introduce _any_ user-facing change? No. ### How was this patch tested? Ran modified UT against master / branch-3.0 / branch-2.4. Closes #29046 from HeartSaVioR/QUICKFIX-SPARK-32024. Authored-by: Jungtaek Lim (HeartSaVioR) <kabhwan.opensource@gmail.com> Signed-off-by: HyukjinKwon <gurwls223@apache.org> (cherry picked from commit 161cf2a) Signed-off-by: HyukjinKwon <gurwls223@apache.org>

zhli1142015 added 2 commits June 18, 2020 06:33

update ApplicationStoreInfo.size during initializing

599152e

fix test

57c16a0

probot-autolabeler bot added the CORE label Jun 18, 2020

zhli1142015 added 3 commits June 18, 2020 07:37

update comments

3e242b3

update test

79ed4b9

update test case

73042c3

HeartSaVioR reviewed Jun 21, 2020

View reviewed changes

zhli1142015 added 2 commits June 21, 2020 07:28

fix comments

56134d6

Merge remote-tracking branch 'upstream/master' into update-Applicatio…

a6760e1

…nStoreInfo.size-during-disk-manager-initialize

HeartSaVioR reviewed Jun 24, 2020

View reviewed changes

update test

b9057ec

HeartSaVioR approved these changes Jun 26, 2020

View reviewed changes

gengliangwang reviewed Jul 3, 2020

View reviewed changes

address comments

ed05872

gengliangwang approved these changes Jul 3, 2020

View reviewed changes

HeartSaVioR closed this in 8e7fc04 Jul 8, 2020

[SPARK-32024][WEBUI] Update ApplicationStoreInfo.size during HistoryServerDiskManager initializing #28859

[SPARK-32024][WEBUI] Update ApplicationStoreInfo.size during HistoryServerDiskManager initializing #28859

Conversation

zhli1142015 commented Jun 18, 2020 • edited

What changes were proposed in this pull request?

Why are the changes needed?

Does this PR introduce any user-facing change?

How was this patch tested?

zhli1142015 commented Jun 18, 2020

gatorsmile commented Jun 20, 2020

Choose a reason for hiding this comment

zhli1142015 Jun 21, 2020 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

zhli1142015 commented Jun 23, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

HeartSaVioR left a comment

Choose a reason for hiding this comment

zhli1142015 commented Jul 1, 2020

gengliangwang commented Jul 2, 2020

SparkQA commented Jul 2, 2020

HeartSaVioR commented Jul 2, 2020

SparkQA commented Jul 2, 2020

HeartSaVioR commented Jul 2, 2020

zhli1142015 commented Jul 3, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

SparkQA commented Jul 5, 2020

HeartSaVioR commented Jul 5, 2020

HeartSaVioR commented Jul 7, 2020

SparkQA commented Jul 8, 2020

HeartSaVioR commented Jul 8, 2020 • edited

HeartSaVioR commented Jul 8, 2020

HeartSaVioR commented Jul 8, 2020

SparkQA commented Jul 8, 2020

HeartSaVioR commented Jul 8, 2020

zhli1142015 commented Jul 8, 2020

HeartSaVioR commented Jul 8, 2020

HyukjinKwon commented Jul 8, 2020

HeartSaVioR commented Jul 8, 2020

HyukjinKwon commented Jul 8, 2020

dongjoon-hyun commented Jul 8, 2020

dongjoon-hyun commented Jul 8, 2020

dongjoon-hyun commented Jul 8, 2020

HeartSaVioR commented Jul 8, 2020 • edited

HeartSaVioR commented Jul 8, 2020

zhli1142015 commented Jul 8, 2020

HeartSaVioR commented Jul 8, 2020

dongjoon-hyun commented Jul 8, 2020

HeartSaVioR commented Jul 8, 2020

zhli1142015 commented Jun 18, 2020 •

edited

zhli1142015 Jun 21, 2020 •

edited

HeartSaVioR commented Jul 8, 2020 •

edited

HeartSaVioR commented Jul 8, 2020 •

edited