[SPARK-17843][Web UI] Indicate event logs pending for processing on history server UI #15410

vijoshi · 2016-10-10T00:18:20Z

What changes were proposed in this pull request?

History Server UI's application listing to display information on currently under process event logs so a user knows that pending this processing an application may not list on the UI.

When there are no event logs under process, the application list page has a "Last Updated" date-time at the top indicating the date-time of the last completed scan of the event logs. The value is displayed to the user in his/her local time zone.

How was this patch tested?

All unit tests pass. Particularly all the suites under org.apache.spark.deploy.history.* were run to test changes.

Very first startup - Pending logs - no logs processed yet:

- Very first startup - Pending logs - some logs processed:

- Last updated - No currently pending logs:

- Last updated - With some currently pending logs:

- No applications found and No currently pending logs:

ajbozarth

I like the idea of this change, but I think it can be more stream-lined as I commented. From a first look though the general code quality looks good

ajbozarth · 2016-10-10T19:42:00Z

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

+
+      try {
+        for (file <- logInfos) {
+          tasks += replayExecutor.submit(new Runnable {


Is there a need for this step? Why can't we just pendingReplayTasksCount.addAndGet(logInfos.size) below and only have to add the finally code block. This seems like a lot of unnecessary code change.

the replayExecutor.submit can raise an exception resulting in fewer logInfos getting queued for replay. although one can argue that the underlying ExecutorService implementation used today will probably not do this, but I did not feel comfortable leaving this possibility out. note that - if there were to be an exception on the replayExecutor. submit( ) it would break not only the counting logic (assuming we'd already done a pendingReplayTasksCount.addAndGet(logInfos.size) instead of only adding as many as got successfully submitted) but also the older one of preventing a new thread getting scheduled for "checkForLogs( )" while there are tasks already running in replayExecutor.

however if there's a thought that we can completely ignore the possibility of exceptions on replayExecutor.submit( ), I can optimise the code on those lines. Let me know.

From my understanding the catch at the end of checkForLogs would stop any current issue, but without it your new counting code would break, so with the addition of the counting code this change makes sense.

tgravescs · 2016-10-11T14:54:17Z

while I understand the problem, the issue here is that what you are printing might not be accurate either. We only pull for new logs every X number of seconds (default is 10s, user could change to longer) so if I come in one of those periods then it could say 0 when there are actually some to be read yet. Maybe this is ok as its better then it was but its also not guaranteed.

vijoshi · 2016-10-11T18:08:33Z

@tgravescs - you're right - for newer logs that are generated, there could be a window of time (10 secs or whatever the user configures) where the new logs are not picked up for replay and the UI doesn't say anything about them. however the issue we see is more with old completed apps. a little after history server startup, user browses to the app list and has no idea why the older completed apps are missing (perhaps those that were visible just before the history server was restarted). since the polling for logs/replay is scheduled immediately as part of history server startup (zero delay for the first round), this fix could help these cases.

tgravescs · 2016-10-11T19:04:13Z

ah, yeah startup would definitely be a good case for this and like I mentioned its better then nothing so I'm ok with concept.

I wonder for the other use case where it hasn't looked in ~ 10 seconds if it would be more clear to users if we put a little string at the top that is like "last updated time XX:XX:XX" or app list current as of XX:XX:XX.

ajbozarth · 2016-10-11T20:03:51Z

Just to raise an idea that would possibly mean less code change, would simply having a flag that causing a "currently processing applications" type message to display without an actual count with it?

Overall I think this is a good addition though.

andrewor14 · 2016-10-12T16:28:09Z

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

@@ -38,6 +39,13 @@ private[history] class HistoryPage(parent: HistoryServer) extends WebUIPage("")
              {providerConfig.map { case (k, v) => <li><strong>{k}:</strong> {v}</li> }}
            </ul>
            {
+            if (eventLogsUnderProcessCount > 0) {
+              <p>There are {eventLogsUnderProcessCount} event log(s) currently being
+                processed which may result in additional applications getting listed on this page.


Instead of just telling the user how many logs are pending, it will be a lot more useful to tell him which ones are pending so he can wait before clicking on a specific application

andrewor14 · 2016-10-12T16:31:37Z

ok to test

I think the idea is good, but it would be a better UX if we display the pending applications as rows in the existing table (or a new one) and indicate there that they're still being processed. It might be more code change but I think it's worth it.

tgravescs · 2016-10-12T22:01:41Z

If we are going to list the actual applications being loaded in the table then you have to rely on the filename to know the application id. This may be ok, but its then the interface and we can't change it or whatever we change it to has to be compatible and backwards compatible. Personally I would rather see us do something much smarter with file names/paths to include enough metadata to do simple table list or have metadata file that would allow loading of the history table much faster and load the actual contents only when actually clicked on.

tgravescs · 2016-10-12T22:03:24Z

Note the reason I mention the above things is I don't want us to start relying on the filename if its just going to change again.

vijoshi · 2016-10-13T08:40:28Z

Display "Last updated " with a generic message, possibly omitting the count of logs

Ok, while looking at this I notice that the scan date-time the FsHistoryProvider currently internally captures (lastScanTime) is based on the filesystem date-time:

  private def getNewLastScanTime(): Long = {
      val fileName = "." + UUID.randomUUID().toString
      val path = new Path(logDir, fileName)
      val fos = fs.create(path)`

     try {
        fos.close()
        fs.getFileStatus(path).getModificationTime

This probably made sense when earlier versions of FsHistoryProvider used this value to determine new/updated logs it needed to replay. This is no longer the case. In checkForLogs() the check is based on file size now. So my question is that the fact that getNewLastScanTime is still present - is there a reason to rely on or use the filesystem time value? We don't get a timezone out of the FileStatus api. If I were to display an "Last updated/Updated as of: " value on the app listing page, I would rather read/record the time value from the JVM and ensure the Web UI converted it to user's local timezone for display.

vijoshi · 2016-10-13T08:43:43Z

Display applications that are pending, instead of a count

Though agree that this would be better UX-wise, but we would only have the filenames (logInfos) to go by to build this list until a clean way to extract app metadata exists without parsing event log file contents. If the UI just displayed the pending ones in a different table as "names" of pending logs without asserting that they are necessarily the app-id (though presently the names may match the app-ids) - would that be good enough ? The message on the top that I am trying to add on the application listing page could link to a new page that lists these pending logs to avoid cluttering the application listing page?

tgravescs · 2016-10-14T19:06:54Z

personally I would rather not display directory or filenames unless we are doing it right. User shouldn't know the internal implementation or storage option.

andrewor14 · 2016-10-14T20:35:28Z

We shouldn't display file names but we should display application names and IDs, something the user understands. We don't have to do that as part of this issue.

ajbozarth · 2016-10-14T20:55:31Z

@andrewor14 I plan to address that in another issue soon (see by end of the month) as soon as I have time. Fixing how the History Server loads has been coming up in a lot of PRs lately.

vijoshi · 2016-10-17T05:14:37Z

@ajbozarth @tgravescs @andrewor14 - updated pull request to show a Last Updated message on the app list page when there are no pending logs being processed. I would have liked to have the ApplicationListResource use a json schema where the application list and associated metadata - updated date, pending logs etc could be included together. but given that the json schema returned today is just a collection of application info json - change to this would be too much code change for this smallish fix - probably something for the /api/v2/ to consider.

tgravescs · 2016-10-17T13:09:30Z

can you update the description with latest implementation and screen shot.

tgravescs · 2016-10-17T13:09:46Z

Jenkins, test this please

SparkQA · 2016-10-17T20:12:27Z

Test build #67070 has finished for PR 15410 at commit b43e241.

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

vijoshi · 2016-10-20T08:58:31Z

@tgravescs @ajbozarth @andrewor14 can this be merged now? can we get it into the 2.0 branch - should i simply open a pull request on 2.0?

vijoshi · 2016-10-20T08:59:29Z

This needs to remain open - clicked the wrong button!!

tgravescs · 2016-10-20T17:31:17Z

were the description and screen shots updated?

vijoshi · 2016-10-20T17:42:17Z

@tgravescs Yes, the description for the pull request now has screen shots for the "Last Updated: XXX" case as well. I added description for the "Last Updated" message on the app list page just now.

ajbozarth · 2016-10-20T19:37:41Z

Should we display the Last Updated even if the currently processing message is displayed? Then the user will know the last update even when a new update is processing, rare case, but still useful.

vijoshi · 2016-10-21T10:33:47Z

@ajbozarth yeah sounds useful. but note that for the very first load, we would have no 'Last Updated' value to display since that gets set only after the log scan+replay cycle completes at least once. any suggestions for an alternate text when we're in this situation?

ajbozarth · 2016-10-21T20:33:16Z

I would say just not displaying it would be fine, so making the else if an if

vijoshi · 2016-10-24T10:04:33Z

@ajbozarth @tgravescs @andrewor14 - updated the implementation to always display "Last Updated Date-Time" when we have atleast one completed scan of the event log directory. I have changed the impl slightly

the javascript for "last updated" goes into a "historypage-common.js" since it's now always needed for inclusion on the history page (earlier it was inside the bigger "historypage.js" file that gets included only if there are some apps to list)
if there are pending event logs, do not show the "Did you specify the correct logging directory?" message

Have updated description with screenshots for each of the above scenarios.

tgravescs · 2016-11-07T14:57:45Z

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

+          logError(s"Exception while submitting event log for replay", e)
+      }
+
+      pendingReplayTasksCount.addAndGet (tasks.size)


nit: remove extra space after addAndGet before (

tgravescs · 2016-11-07T15:10:02Z

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

@@ -123,6 +123,8 @@ private[history] class FsHistoryProvider(conf: SparkConf, clock: Clock)
  // List of application logs to be deleted by event log cleaner.
  private var attemptsToClean = new mutable.ListBuffer[FsApplicationAttemptInfo]

+  private val pendingReplayTasksCount = new java.util.concurrent.atomic.AtomicInteger (0)


remove extra space after AtomicInteger before (

tgravescs · 2016-11-07T15:10:18Z

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

@@ -111,7 +111,7 @@ private[history] class FsHistoryProvider(conf: SparkConf, clock: Clock)

  // The modification time of the newest log detected during the last scan.   Currently only
  // used for logging msgs (logs are re-scanned based on file size, rather than modtime)
-  private var lastScanTime = -1L
+  private val lastScanTime = new java.util.concurrent.atomic.AtomicLong (-1)


remove extra space after AtomicLong before (

tgravescs · 2016-11-07T15:10:52Z

couple minor spacing nits, otherwise looks good.

vijoshi · 2016-11-07T17:45:50Z

@tgravescs thanks, have updated the fix.

tgravescs · 2016-11-08T14:18:35Z

Jenkins, test this please

SparkQA · 2016-11-08T15:48:16Z

Test build #68341 has finished for PR 15410 at commit 596c7ae.

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

tgravescs · 2016-11-08T15:50:26Z

test failure looks unrelated, kicking again.

Jenkins, test this please

vijoshi · 2016-11-08T18:21:49Z

retest this please

tgravescs · 2016-11-08T19:34:51Z

Jenkins, test this please

SparkQA · 2016-11-08T23:47:36Z

Test build #68357 has finished for PR 15410 at commit 596c7ae.

This patch fails from timeout after a configured wait of 250m.
This patch merges cleanly.
This patch adds no public classes.

vijoshi · 2016-11-09T03:19:52Z

retest this please

tgravescs · 2016-11-09T14:29:12Z

Jenkins, test this please

SparkQA · 2016-11-09T16:17:52Z

Test build #68409 has finished for PR 15410 at commit 596c7ae.

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

tgravescs · 2016-11-10T14:04:59Z

I've seen other pr tests passing now, let try again.

tgravescs · 2016-11-10T14:05:01Z

Jenkins, test this please

SparkQA · 2016-11-10T16:06:23Z

Test build #68471 has finished for PR 15410 at commit 596c7ae.

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

tgravescs · 2016-11-10T16:21:00Z

@vijoshi please look at test failures in more detail to see if these changes could have affected.

…608_master

tgravescs · 2016-11-11T13:37:36Z

Jenkins, test this please

SparkQA · 2016-11-11T16:01:04Z

Test build #68524 has finished for PR 15410 at commit 46357ee.

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

tgravescs · 2016-11-11T18:53:02Z

+1

…istory server UI ## What changes were proposed in this pull request? History Server UI's application listing to display information on currently under process event logs so a user knows that pending this processing an application may not list on the UI. When there are no event logs under process, the application list page has a "Last Updated" date-time at the top indicating the date-time of the last _completed_ scan of the event logs. The value is displayed to the user in his/her local time zone. ## How was this patch tested? All unit tests pass. Particularly all the suites under org.apache.spark.deploy.history.\* were run to test changes. - Very first startup - Pending logs - no logs processed yet: <img width="1280" alt="screen shot 2016-10-24 at 3 07 04 pm" src="https://cloud.githubusercontent.com/assets/12079825/19640981/b8d2a96a-99fc-11e6-9b1f-2d736fe90e48.png"> - Very first startup - Pending logs - some logs processed: <img width="1280" alt="screen shot 2016-10-24 at 3 18 42 pm" src="https://cloud.githubusercontent.com/assets/12079825/19641087/3f8e3bae-99fd-11e6-9ef1-e0e70d71d8ef.png"> - Last updated - No currently pending logs: <img width="1280" alt="screen shot 2016-10-17 at 8 34 37 pm" src="https://cloud.githubusercontent.com/assets/12079825/19443100/4d13946c-94a9-11e6-8ee2-c442729bb206.png"> - Last updated - With some currently pending logs: <img width="1280" alt="screen shot 2016-10-24 at 3 09 31 pm" src="https://cloud.githubusercontent.com/assets/12079825/19640903/7323ba3a-99fc-11e6-8359-6a45753dbb28.png"> - No applications found and No currently pending logs: <img width="1280" alt="screen shot 2016-10-24 at 3 24 26 pm" src="https://cloud.githubusercontent.com/assets/12079825/19641364/03a2cb04-99fe-11e6-87d6-d09587fc6201.png"> Author: Vinayak <vijoshi5@in.ibm.com> Closes #15410 from vijoshi/SAAS-608_master. (cherry picked from commit a531fe1) Signed-off-by: Tom Graves <tgraves@yahoo-inc.com>

## What changes were proposed in this pull request? Backport PR #15410 to branch-2.0 ## How was this patch tested? Existing unit tests. Screenshots for UI changes provided in PR #15410. Author: Vinayak <vijoshi5@in.ibm.com> Closes #15991 from vijoshi/SAAS-608.

…istory server UI ## What changes were proposed in this pull request? History Server UI's application listing to display information on currently under process event logs so a user knows that pending this processing an application may not list on the UI. When there are no event logs under process, the application list page has a "Last Updated" date-time at the top indicating the date-time of the last _completed_ scan of the event logs. The value is displayed to the user in his/her local time zone. ## How was this patch tested? All unit tests pass. Particularly all the suites under org.apache.spark.deploy.history.\* were run to test changes. - Very first startup - Pending logs - no logs processed yet: <img width="1280" alt="screen shot 2016-10-24 at 3 07 04 pm" src="https://cloud.githubusercontent.com/assets/12079825/19640981/b8d2a96a-99fc-11e6-9b1f-2d736fe90e48.png"> - Very first startup - Pending logs - some logs processed: <img width="1280" alt="screen shot 2016-10-24 at 3 18 42 pm" src="https://cloud.githubusercontent.com/assets/12079825/19641087/3f8e3bae-99fd-11e6-9ef1-e0e70d71d8ef.png"> - Last updated - No currently pending logs: <img width="1280" alt="screen shot 2016-10-17 at 8 34 37 pm" src="https://cloud.githubusercontent.com/assets/12079825/19443100/4d13946c-94a9-11e6-8ee2-c442729bb206.png"> - Last updated - With some currently pending logs: <img width="1280" alt="screen shot 2016-10-24 at 3 09 31 pm" src="https://cloud.githubusercontent.com/assets/12079825/19640903/7323ba3a-99fc-11e6-8359-6a45753dbb28.png"> - No applications found and No currently pending logs: <img width="1280" alt="screen shot 2016-10-24 at 3 24 26 pm" src="https://cloud.githubusercontent.com/assets/12079825/19641364/03a2cb04-99fe-11e6-87d6-d09587fc6201.png"> Author: Vinayak <vijoshi5@in.ibm.com> Closes apache#15410 from vijoshi/SAAS-608_master.

vijoshi changed the title ~~initial commit~~ [SPARK-17843][Web UI] Indicate event logs pending for processing on history server UI Oct 10, 2016

ajbozarth reviewed Oct 10, 2016

View reviewed changes

andrewor14 reviewed Oct 12, 2016

View reviewed changes

vijoshi closed this Oct 20, 2016

vijoshi reopened this Oct 20, 2016

vijoshi force-pushed the SAAS-608_master branch from cfcae6a to cd5056b Compare October 24, 2016 10:23

tgravescs reviewed Nov 7, 2016

View reviewed changes

review comments - 2

596c7ae

Merge remote-tracking branch 'remotes/spark_master/master' into SAAS-…

46357ee

…608_master

asfgit closed this in a531fe1 Nov 11, 2016

vijoshi mentioned this pull request Nov 23, 2016

[SPARK-17843][WEB UI] Indicate event logs pending for processing on h… #15991

Closed

vijoshi deleted the SAAS-608_master branch January 24, 2017 10:31

[SPARK-17843][Web UI] Indicate event logs pending for processing on history server UI #15410

[SPARK-17843][Web UI] Indicate event logs pending for processing on history server UI #15410

Conversation

vijoshi commented Oct 10, 2016 • edited Loading

What changes were proposed in this pull request?

How was this patch tested?

ajbozarth left a comment

Choose a reason for hiding this comment

ajbozarth Oct 10, 2016

Choose a reason for hiding this comment

vijoshi Oct 11, 2016 • edited Loading

Choose a reason for hiding this comment

ajbozarth Oct 11, 2016

Choose a reason for hiding this comment

tgravescs commented Oct 11, 2016

vijoshi commented Oct 11, 2016

tgravescs commented Oct 11, 2016

ajbozarth commented Oct 11, 2016

andrewor14 Oct 12, 2016

Choose a reason for hiding this comment

andrewor14 commented Oct 12, 2016 • edited Loading

tgravescs commented Oct 12, 2016

tgravescs commented Oct 12, 2016

vijoshi commented Oct 13, 2016 • edited Loading

vijoshi commented Oct 13, 2016 • edited Loading

tgravescs commented Oct 14, 2016

andrewor14 commented Oct 14, 2016

ajbozarth commented Oct 14, 2016

vijoshi commented Oct 17, 2016

tgravescs commented Oct 17, 2016

tgravescs commented Oct 17, 2016

SparkQA commented Oct 17, 2016

vijoshi commented Oct 20, 2016

vijoshi commented Oct 20, 2016

tgravescs commented Oct 20, 2016

vijoshi commented Oct 20, 2016

ajbozarth commented Oct 20, 2016

vijoshi commented Oct 21, 2016

ajbozarth commented Oct 21, 2016

vijoshi commented Oct 24, 2016

tgravescs Nov 7, 2016

Choose a reason for hiding this comment

tgravescs Nov 7, 2016

Choose a reason for hiding this comment

tgravescs Nov 7, 2016

Choose a reason for hiding this comment

tgravescs commented Nov 7, 2016

vijoshi commented Nov 7, 2016

tgravescs commented Nov 8, 2016

SparkQA commented Nov 8, 2016

tgravescs commented Nov 8, 2016

vijoshi commented Nov 8, 2016

tgravescs commented Nov 8, 2016

SparkQA commented Nov 8, 2016

vijoshi commented Nov 9, 2016

tgravescs commented Nov 9, 2016

SparkQA commented Nov 9, 2016

tgravescs commented Nov 10, 2016

tgravescs commented Nov 10, 2016

SparkQA commented Nov 10, 2016

tgravescs commented Nov 10, 2016

tgravescs commented Nov 11, 2016

SparkQA commented Nov 11, 2016

tgravescs commented Nov 11, 2016

vijoshi commented Oct 10, 2016 •

edited

Loading

vijoshi Oct 11, 2016 •

edited

Loading

andrewor14 commented Oct 12, 2016 •

edited

Loading

vijoshi commented Oct 13, 2016 •

edited

Loading

vijoshi commented Oct 13, 2016 •

edited

Loading