[SPARK-16002][SQL]Sleep when no new data arrives to avoid 100% CPU usage #13718

zsxwing · 2016-06-16T22:09:19Z

What changes were proposed in this pull request?

Add a configuration to allow people to set a minimum polling delay when no new data arrives (default is 10ms). This PR also cleans up some INFO logs.

How was this patch tested?

Existing unit tests.

zsxwing · 2016-06-16T22:10:13Z

sql/core/src/main/scala/org/apache/spark/sql/execution/streaming/FileStreamSource.scala

+    val listingTimeMs = (endTime.toDouble - startTime) / 1000000
+    if (listingTimeMs > 2000) {
+      // Output a warning when listing files uses more than 2 seconds.
+      logWarning(s"Listed ${files.size} file(s) in $listingTimeMs ms")


This log is pretty useful when listing files is extremely slow.

Should this be at DEBUG level ?

The user wouldn't know what to do seeing these warnings.

@tedyu as this is a Streaming application, this log may help the user find the bottleneck when the app becomes slow.

Should some kind of metric be introduced so that the user doesn't need to examine logs ?

Should some kind of metric be introduced so that the user doesn't need to examine logs ?

Sounds great. But that's not the priority task right now.

zsxwing · 2016-06-16T23:22:32Z

Also /cc @tdas

marmbrus · 2016-06-16T23:25:34Z

LGTM

tdas · 2016-06-16T23:33:45Z

sql/core/src/main/scala/org/apache/spark/sql/execution/streaming/FileStreamSource.scala

@@ -120,7 +120,13 @@ class FileStreamSource(
    val catalog = new ListingFileCatalog(sparkSession, globbedPaths, options, Some(new StructType))
    val files = catalog.allFiles().map(_.getPath.toUri.toString)
    val endTime = System.nanoTime
-    logInfo(s"Listed ${files.size} in ${(endTime.toDouble - startTime) / 1000000}ms")
+    val listingTimeMs = (endTime.toDouble - startTime) / 1000000
+    if (listingTimeMs > 2000) {


Why 2 seconds?

No special reason... Just randomly choose a number. @tdas any suggestion for this number?

SparkQA · 2016-06-16T23:36:39Z

Test build #60665 has finished for PR 13718 at commit f059d0a.

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

SparkQA · 2016-06-17T00:26:05Z

Test build #60667 has finished for PR 13718 at commit 115c9b3.

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

zsxwing · 2016-06-17T23:07:23Z

sql/core/src/test/scala/org/apache/spark/sql/streaming/StreamSuite.scala

@@ -164,6 +164,7 @@ class StreamSuite extends StreamTest {
      /* -- batch 0 ----------------------- */
      // Add some data in batch 0
      AddData(inputData, 1, 2, 3),
+      EnsureManualClockInWaitingState,


This is necessary. Otherwise, the manual clock may be advanced too early and then ManualClock.waitTillTime will block forever.

SparkQA · 2016-06-18T00:32:32Z

Test build #60732 has finished for PR 13718 at commit 9447e28.

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

SparkQA · 2016-06-18T01:04:08Z

Test build #60733 has finished for PR 13718 at commit 8a9b592.

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

SparkQA · 2016-06-18T01:19:24Z

Test build #60734 has finished for PR 13718 at commit ddf890f.

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

zsxwing · 2016-06-18T05:03:19Z

@tdas I fixed the test. Could you take another look?

marmbrus · 2016-06-20T17:48:14Z

core/src/main/scala/org/apache/spark/util/ManualClock.scala

+  /**
+   * Returns whether there is any thread being blocked in `waitTillTime`.
+   */
+  def isWaiting: Boolean = synchronized { _isWaiting }


Can this ever return true, given that its synchronized with the only method that mutates _isWaiting (and that method sets it to false in a finally)?

wait(10) in waitTillTime will give up the lock.

wait's javadoc:

This method causes the current thread (call it T) to place itself in the wait set for this object and then to relinquish any and all synchronization claims on this object.

So isWaiting returns true only when some threads is blocked by wait(10).

SparkQA · 2016-06-20T20:49:04Z

Test build #60862 has finished for PR 13718 at commit 7b6dcd2.

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

zsxwing · 2016-06-20T20:59:07Z

retest this please

SparkQA · 2016-06-20T23:13:35Z

Test build #60875 has finished for PR 13718 at commit 7b6dcd2.

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

yhuai · 2016-06-21T19:40:29Z

LGTM. Thanks. Merging to master and branch 2.0.

…sage ## What changes were proposed in this pull request? Add a configuration to allow people to set a minimum polling delay when no new data arrives (default is 10ms). This PR also cleans up some INFO logs. ## How was this patch tested? Existing unit tests. Author: Shixiong Zhu <shixiong@databricks.com> Closes #13718 from zsxwing/SPARK-16002. (cherry picked from commit c399c7f) Signed-off-by: Yin Huai <yhuai@databricks.com>

Sleep when no new data arrives to avoid 100% CPU usage

f059d0a

zsxwing reviewed Jun 16, 2016
View reviewed changes

Use timeconf

115c9b3

tdas reviewed Jun 16, 2016
View reviewed changes

Disable a flaky test

9447e28

zsxwing reviewed Jun 17, 2016
View reviewed changes

Fix the flaky test

ddf890f

marmbrus reviewed Jun 20, 2016
View reviewed changes

Merge EnsureManualClockInWaitingState and AdvanceManualClock

7b6dcd2

asfgit closed this in c399c7f Jun 21, 2016

zsxwing deleted the SPARK-16002 branch June 21, 2016 19:48

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[SPARK-16002][SQL]Sleep when no new data arrives to avoid 100% CPU usage #13718

[SPARK-16002][SQL]Sleep when no new data arrives to avoid 100% CPU usage #13718

zsxwing commented Jun 16, 2016

zsxwing Jun 16, 2016

tedyu Jun 21, 2016

zsxwing Jun 21, 2016

tedyu Jun 21, 2016

zsxwing Jun 21, 2016

zsxwing commented Jun 16, 2016

marmbrus commented Jun 16, 2016

tdas Jun 16, 2016

zsxwing Jun 16, 2016 •

edited

SparkQA commented Jun 16, 2016

SparkQA commented Jun 17, 2016

zsxwing Jun 17, 2016

SparkQA commented Jun 18, 2016

SparkQA commented Jun 18, 2016

SparkQA commented Jun 18, 2016

zsxwing commented Jun 18, 2016

marmbrus Jun 20, 2016

zsxwing Jun 20, 2016

zsxwing Jun 20, 2016

SparkQA commented Jun 20, 2016

zsxwing commented Jun 20, 2016

SparkQA commented Jun 20, 2016

yhuai commented Jun 21, 2016 •

edited

[SPARK-16002][SQL]Sleep when no new data arrives to avoid 100% CPU usage #13718

[SPARK-16002][SQL]Sleep when no new data arrives to avoid 100% CPU usage #13718

Conversation

zsxwing commented Jun 16, 2016

What changes were proposed in this pull request?

How was this patch tested?

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

zsxwing commented Jun 16, 2016

marmbrus commented Jun 16, 2016

Choose a reason for hiding this comment

zsxwing Jun 16, 2016 • edited

Choose a reason for hiding this comment

SparkQA commented Jun 16, 2016

SparkQA commented Jun 17, 2016

Choose a reason for hiding this comment

SparkQA commented Jun 18, 2016

SparkQA commented Jun 18, 2016

SparkQA commented Jun 18, 2016

zsxwing commented Jun 18, 2016

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

SparkQA commented Jun 20, 2016

zsxwing commented Jun 20, 2016

SparkQA commented Jun 20, 2016

yhuai commented Jun 21, 2016 • edited

zsxwing Jun 16, 2016 •

edited

yhuai commented Jun 21, 2016 •

edited