Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[SPARK-44074][CORE][SQL][TESTS][3.4] Fix loglevel restore behavior of SparkFunSuite#withLogAppender and re-enable UT Logging plan changes for execution #43157

Closed
wants to merge 1 commit into from

Conversation

LuciferYang
Copy link
Contributor

@LuciferYang LuciferYang commented Sep 28, 2023

What changes were proposed in this pull request?

The main change of this pr is to add a call of SparkFunSuite#wupdateLoggers after restore loglevel when 'level' of withLogAppender function is not None, and under the premise of this change, the UT Logging plan changes for execution disabled in #43141 can be re-enabled.

Why are the changes needed?

  • Fix bug of SparkFunSuite#withLogAppender when 'level' is not None
  • Re-enable UT Logging plan changes for execution

Does this PR introduce any user-facing change?

No

How was this patch tested?

  • Pass GitHub Actions
  • Manual test
build/sbt "sql/testOnly org.apache.spark.sql.JoinHintSuite org.apache.spark.sql.execution.QueryExecutionSuite"

Before

[info] - Logging plan changes for execution *** FAILED *** (36 milliseconds)
[info]   testAppender.loggingEvents.exists(((x$10: org.apache.logging.log4j.core.LogEvent) => x$10.getMessage().getFormattedMessage().contains(expectedMsg))) was false (QueryExecutionSuite.scala:232)
[info]   org.scalatest.exceptions.TestFailedException:
[info]   at org.scalatest.Assertions.newAssertionFailedException(Assertions.scala:472)
[info]   at org.scalatest.Assertions.newAssertionFailedException$(Assertions.scala:471)
[info]   at org.scalatest.Assertions$.newAssertionFailedException(Assertions.scala:1231)
[info]   at org.scalatest.Assertions$AssertionsHelper.macroAssert(Assertions.scala:1295)
[info]   at org.apache.spark.sql.execution.QueryExecutionSuite.$anonfun$new$34(QueryExecutionSuite.scala:232)
[info]   at scala.collection.immutable.List.foreach(List.scala:431)
[info]   at org.apache.spark.sql.execution.QueryExecutionSuite.$anonfun$new$31(QueryExecutionSuite.scala:231)
[info]   at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)
[info]   at org.scalatest.OutcomeOf.outcomeOf(OutcomeOf.scala:85)
[info]   at org.scalatest.OutcomeOf.outcomeOf$(OutcomeOf.scala:83)
[info]   at org.scalatest.OutcomeOf$.outcomeOf(OutcomeOf.scala:104)
[info]   at org.scalatest.Transformer.apply(Transformer.scala:22)
...

The failure reason is withLogAppender(hintAppender, level = Some(Level.WARN)) used in JoinHintSuite, but SparkFunSuite#wupdateLoggers doesn't have the correct restore Loglevel.

The test was successful before SPARK-44034 due to there was AdaptiveQueryExecSuite between JoinHintSuite and QueryExecutionSuite, and AdaptiveQueryExecSuite called withLogAppender(hintAppender, level = Some(Level.DEBUG)), but AdaptiveQueryExecSuite move to slow sql test group after SPARK-44034

After

[info] Run completed in 7 seconds, 485 milliseconds.
[info] Total number of tests run: 32
[info] Suites: completed 2, aborted 0
[info] Tests: succeeded 32, failed 0, canceled 0, ignored 0, pending 0
[info] All tests passed.

…rkFunSuite#withLogAppender` and re-enable UT `Logging plan changes for execution`

### What changes were proposed in this pull request?
The main change of this pr is to add a call of `SparkFunSuite#wupdateLoggers` after restore loglevel when 'level' of `withLogAppender` function is not `None`, and under the premise of this change, the UT `Logging plan changes for execution` disabled in apache#41638 can be re-enabled.

### Why are the changes needed?
- Fix bug of `SparkFunSuite#withLogAppender` when 'level' is not None
- Re-enable UT `Logging plan changes for execution`

### Does this PR introduce _any_ user-facing change?
No

### How was this patch tested?
- Pass GitHub Actions
- Manual test

```
build/sbt "sql/testOnly org.apache.spark.sql.JoinHintSuite org.apache.spark.sql.execution.QueryExecutionSuite"
```

**Before**

```
[info] - Logging plan changes for execution *** FAILED *** (36 milliseconds)
[info]   testAppender.loggingEvents.exists(((x$10: org.apache.logging.log4j.core.LogEvent) => x$10.getMessage().getFormattedMessage().contains(expectedMsg))) was false (QueryExecutionSuite.scala:232)
[info]   org.scalatest.exceptions.TestFailedException:
[info]   at org.scalatest.Assertions.newAssertionFailedException(Assertions.scala:472)
[info]   at org.scalatest.Assertions.newAssertionFailedException$(Assertions.scala:471)
[info]   at org.scalatest.Assertions$.newAssertionFailedException(Assertions.scala:1231)
[info]   at org.scalatest.Assertions$AssertionsHelper.macroAssert(Assertions.scala:1295)
[info]   at org.apache.spark.sql.execution.QueryExecutionSuite.$anonfun$new$34(QueryExecutionSuite.scala:232)
[info]   at scala.collection.immutable.List.foreach(List.scala:431)
[info]   at org.apache.spark.sql.execution.QueryExecutionSuite.$anonfun$new$31(QueryExecutionSuite.scala:231)
[info]   at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)
[info]   at org.scalatest.OutcomeOf.outcomeOf(OutcomeOf.scala:85)
[info]   at org.scalatest.OutcomeOf.outcomeOf$(OutcomeOf.scala:83)
[info]   at org.scalatest.OutcomeOf$.outcomeOf(OutcomeOf.scala:104)
[info]   at org.scalatest.Transformer.apply(Transformer.scala:22)
...

```

The failure reason is `withLogAppender(hintAppender, level = Some(Level.WARN))` used in `JoinHintSuite`, but `SparkFunSuite#wupdateLoggers` doesn't have the correct restore Loglevel.

The test was successful before SPARK-44034 due to there was `AdaptiveQueryExecSuite` between `JoinHintSuite` and `QueryExecutionSuite`, and `AdaptiveQueryExecSuite` called `withLogAppender(hintAppender, level = Some(Level.DEBUG))`, but `AdaptiveQueryExecSuite` move to `slow sql` test group after SPARK-44034

**After**

```
[info] Run completed in 7 seconds, 485 milliseconds.
[info] Total number of tests run: 32
[info] Suites: completed 2, aborted 0
[info] Tests: succeeded 32, failed 0, canceled 0, ignored 0, pending 0
[info] All tests passed.
```

Closes apache#41663 from LuciferYang/SPARK-44074.

Authored-by: yangjie01 <yangjie01@baidu.com>
Signed-off-by: Dongjoon Hyun <dongjoon@apache.org>
@LuciferYang
Copy link
Contributor Author

cc @HyukjinKwon @sunchao

@LuciferYang
Copy link
Contributor Author

backport this one due to test("Logging plan changes for execution") be ignored in SPARK-44034, we should re-enable this test in branch-3.4

Copy link
Member

@sunchao sunchao left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@sunchao
Copy link
Member

sunchao commented Sep 28, 2023

retest this please

@LuciferYang
Copy link
Contributor Author

Re-triggered the failed GA task.

@LuciferYang
Copy link
Contributor Author

GA passed, I will merge this one.

@LuciferYang
Copy link
Contributor Author

Merged into branch-3.4, thanks @sunchao ~

LuciferYang added a commit that referenced this pull request Sep 29, 2023
… `SparkFunSuite#withLogAppender` and re-enable UT `Logging plan changes for execution`

### What changes were proposed in this pull request?
The main change of this pr is to add a call of `SparkFunSuite#wupdateLoggers` after restore loglevel when 'level' of `withLogAppender` function is not `None`, and under the premise of this change, the UT `Logging plan changes for execution` disabled in #43141 can be re-enabled.

### Why are the changes needed?
- Fix bug of `SparkFunSuite#withLogAppender` when 'level' is not None
- Re-enable UT `Logging plan changes for execution`

### Does this PR introduce _any_ user-facing change?
No

### How was this patch tested?
- Pass GitHub Actions
- Manual test

```
build/sbt "sql/testOnly org.apache.spark.sql.JoinHintSuite org.apache.spark.sql.execution.QueryExecutionSuite"
```

**Before**

```
[info] - Logging plan changes for execution *** FAILED *** (36 milliseconds)
[info]   testAppender.loggingEvents.exists(((x$10: org.apache.logging.log4j.core.LogEvent) => x$10.getMessage().getFormattedMessage().contains(expectedMsg))) was false (QueryExecutionSuite.scala:232)
[info]   org.scalatest.exceptions.TestFailedException:
[info]   at org.scalatest.Assertions.newAssertionFailedException(Assertions.scala:472)
[info]   at org.scalatest.Assertions.newAssertionFailedException$(Assertions.scala:471)
[info]   at org.scalatest.Assertions$.newAssertionFailedException(Assertions.scala:1231)
[info]   at org.scalatest.Assertions$AssertionsHelper.macroAssert(Assertions.scala:1295)
[info]   at org.apache.spark.sql.execution.QueryExecutionSuite.$anonfun$new$34(QueryExecutionSuite.scala:232)
[info]   at scala.collection.immutable.List.foreach(List.scala:431)
[info]   at org.apache.spark.sql.execution.QueryExecutionSuite.$anonfun$new$31(QueryExecutionSuite.scala:231)
[info]   at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)
[info]   at org.scalatest.OutcomeOf.outcomeOf(OutcomeOf.scala:85)
[info]   at org.scalatest.OutcomeOf.outcomeOf$(OutcomeOf.scala:83)
[info]   at org.scalatest.OutcomeOf$.outcomeOf(OutcomeOf.scala:104)
[info]   at org.scalatest.Transformer.apply(Transformer.scala:22)
...

```

The failure reason is `withLogAppender(hintAppender, level = Some(Level.WARN))` used in `JoinHintSuite`, but `SparkFunSuite#wupdateLoggers` doesn't have the correct restore Loglevel.

The test was successful before SPARK-44034 due to there was `AdaptiveQueryExecSuite` between `JoinHintSuite` and `QueryExecutionSuite`, and `AdaptiveQueryExecSuite` called `withLogAppender(hintAppender, level = Some(Level.DEBUG))`, but `AdaptiveQueryExecSuite` move to `slow sql` test group after SPARK-44034

**After**

```
[info] Run completed in 7 seconds, 485 milliseconds.
[info] Total number of tests run: 32
[info] Suites: completed 2, aborted 0
[info] Tests: succeeded 32, failed 0, canceled 0, ignored 0, pending 0
[info] All tests passed.
```

Closes #43157 from LuciferYang/SPARK-44074-34.

Authored-by: yangjie01 <yangjie01@baidu.com>
Signed-off-by: yangjie01 <yangjie01@baidu.com>
LuciferYang added a commit to LuciferYang/spark that referenced this pull request Sep 29, 2023
… `SparkFunSuite#withLogAppender` and re-enable UT `Logging plan changes for execution`

### What changes were proposed in this pull request?
The main change of this pr is to add a call of `SparkFunSuite#wupdateLoggers` after restore loglevel when 'level' of `withLogAppender` function is not `None`, and under the premise of this change, the UT `Logging plan changes for execution` disabled in apache#43141 can be re-enabled.

### Why are the changes needed?
- Fix bug of `SparkFunSuite#withLogAppender` when 'level' is not None
- Re-enable UT `Logging plan changes for execution`

### Does this PR introduce _any_ user-facing change?
No

### How was this patch tested?
- Pass GitHub Actions
- Manual test

```
build/sbt "sql/testOnly org.apache.spark.sql.JoinHintSuite org.apache.spark.sql.execution.QueryExecutionSuite"
```

**Before**

```
[info] - Logging plan changes for execution *** FAILED *** (36 milliseconds)
[info]   testAppender.loggingEvents.exists(((x$10: org.apache.logging.log4j.core.LogEvent) => x$10.getMessage().getFormattedMessage().contains(expectedMsg))) was false (QueryExecutionSuite.scala:232)
[info]   org.scalatest.exceptions.TestFailedException:
[info]   at org.scalatest.Assertions.newAssertionFailedException(Assertions.scala:472)
[info]   at org.scalatest.Assertions.newAssertionFailedException$(Assertions.scala:471)
[info]   at org.scalatest.Assertions$.newAssertionFailedException(Assertions.scala:1231)
[info]   at org.scalatest.Assertions$AssertionsHelper.macroAssert(Assertions.scala:1295)
[info]   at org.apache.spark.sql.execution.QueryExecutionSuite.$anonfun$new$34(QueryExecutionSuite.scala:232)
[info]   at scala.collection.immutable.List.foreach(List.scala:431)
[info]   at org.apache.spark.sql.execution.QueryExecutionSuite.$anonfun$new$31(QueryExecutionSuite.scala:231)
[info]   at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)
[info]   at org.scalatest.OutcomeOf.outcomeOf(OutcomeOf.scala:85)
[info]   at org.scalatest.OutcomeOf.outcomeOf$(OutcomeOf.scala:83)
[info]   at org.scalatest.OutcomeOf$.outcomeOf(OutcomeOf.scala:104)
[info]   at org.scalatest.Transformer.apply(Transformer.scala:22)
...

```

The failure reason is `withLogAppender(hintAppender, level = Some(Level.WARN))` used in `JoinHintSuite`, but `SparkFunSuite#wupdateLoggers` doesn't have the correct restore Loglevel.

The test was successful before SPARK-44034 due to there was `AdaptiveQueryExecSuite` between `JoinHintSuite` and `QueryExecutionSuite`, and `AdaptiveQueryExecSuite` called `withLogAppender(hintAppender, level = Some(Level.DEBUG))`, but `AdaptiveQueryExecSuite` move to `slow sql` test group after SPARK-44034

**After**

```
[info] Run completed in 7 seconds, 485 milliseconds.
[info] Total number of tests run: 32
[info] Suites: completed 2, aborted 0
[info] Tests: succeeded 32, failed 0, canceled 0, ignored 0, pending 0
[info] All tests passed.
```

Closes apache#43157 from LuciferYang/SPARK-44074-34.

Authored-by: yangjie01 <yangjie01@baidu.com>
Signed-off-by: yangjie01 <yangjie01@baidu.com>
@LuciferYang LuciferYang deleted the SPARK-44074-34 branch October 18, 2023 05:26
viirya pushed a commit to viirya/spark-1 that referenced this pull request Oct 19, 2023
… `SparkFunSuite#withLogAppender` and re-enable UT `Logging plan changes for execution`

### What changes were proposed in this pull request?
The main change of this pr is to add a call of `SparkFunSuite#wupdateLoggers` after restore loglevel when 'level' of `withLogAppender` function is not `None`, and under the premise of this change, the UT `Logging plan changes for execution` disabled in apache#43141 can be re-enabled.

### Why are the changes needed?
- Fix bug of `SparkFunSuite#withLogAppender` when 'level' is not None
- Re-enable UT `Logging plan changes for execution`

### Does this PR introduce _any_ user-facing change?
No

### How was this patch tested?
- Pass GitHub Actions
- Manual test

```
build/sbt "sql/testOnly org.apache.spark.sql.JoinHintSuite org.apache.spark.sql.execution.QueryExecutionSuite"
```

**Before**

```
[info] - Logging plan changes for execution *** FAILED *** (36 milliseconds)
[info]   testAppender.loggingEvents.exists(((x$10: org.apache.logging.log4j.core.LogEvent) => x$10.getMessage().getFormattedMessage().contains(expectedMsg))) was false (QueryExecutionSuite.scala:232)
[info]   org.scalatest.exceptions.TestFailedException:
[info]   at org.scalatest.Assertions.newAssertionFailedException(Assertions.scala:472)
[info]   at org.scalatest.Assertions.newAssertionFailedException$(Assertions.scala:471)
[info]   at org.scalatest.Assertions$.newAssertionFailedException(Assertions.scala:1231)
[info]   at org.scalatest.Assertions$AssertionsHelper.macroAssert(Assertions.scala:1295)
[info]   at org.apache.spark.sql.execution.QueryExecutionSuite.$anonfun$new$34(QueryExecutionSuite.scala:232)
[info]   at scala.collection.immutable.List.foreach(List.scala:431)
[info]   at org.apache.spark.sql.execution.QueryExecutionSuite.$anonfun$new$31(QueryExecutionSuite.scala:231)
[info]   at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)
[info]   at org.scalatest.OutcomeOf.outcomeOf(OutcomeOf.scala:85)
[info]   at org.scalatest.OutcomeOf.outcomeOf$(OutcomeOf.scala:83)
[info]   at org.scalatest.OutcomeOf$.outcomeOf(OutcomeOf.scala:104)
[info]   at org.scalatest.Transformer.apply(Transformer.scala:22)
...

```

The failure reason is `withLogAppender(hintAppender, level = Some(Level.WARN))` used in `JoinHintSuite`, but `SparkFunSuite#wupdateLoggers` doesn't have the correct restore Loglevel.

The test was successful before SPARK-44034 due to there was `AdaptiveQueryExecSuite` between `JoinHintSuite` and `QueryExecutionSuite`, and `AdaptiveQueryExecSuite` called `withLogAppender(hintAppender, level = Some(Level.DEBUG))`, but `AdaptiveQueryExecSuite` move to `slow sql` test group after SPARK-44034

**After**

```
[info] Run completed in 7 seconds, 485 milliseconds.
[info] Total number of tests run: 32
[info] Suites: completed 2, aborted 0
[info] Tests: succeeded 32, failed 0, canceled 0, ignored 0, pending 0
[info] All tests passed.
```

Closes apache#43157 from LuciferYang/SPARK-44074-34.

Authored-by: yangjie01 <yangjie01@baidu.com>
Signed-off-by: yangjie01 <yangjie01@baidu.com>
(cherry picked from commit e056fc8)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
2 participants