[SPARK-48134][CORE] Spark core (java side): Migrate `error/warn/info` with variables to structured logging framework #46390

panbingkun · 2024-05-05T12:55:08Z

What changes were proposed in this pull request?

The pr aims to
1.migrate error/warn/info in module core with variables to structured logging framework for java side.
2.convert all dependencies on org.slf4j.Logger & org.slf4j.LoggerFactory to org.apache.spark.internal.Logger & org.apache.spark.internal.LoggerFactory, in order to completely prohibit importing org.slf4j.Logger & org.slf4j.LoggerFactory in java code later.

Why are the changes needed?

To enhance Apache Spark's logging system by implementing structured logging.

Does this PR introduce any user-facing change?

No.

How was this patch tested?

Pass GA.

Was this patch authored or co-authored using generative AI tooling?

No.

… with variables to structured logging framework

panbingkun · 2024-05-06T09:16:20Z

common/utils/src/main/java/org/apache/spark/internal/Logger.java

    this.slf4jLogger = slf4jLogger;
  }

+  public boolean isErrorEnabled() {


It is found that some logic uses this method during migration.

panbingkun · 2024-05-06T09:18:53Z

common/utils/src/main/java/org/apache/spark/internal/Logger.java

+    slf4jLogger.error(msg, arg1, arg2);
+  }
+
+  public void error(String msg, String... args) {


Why is the method signature not public void error(String msg, Object... args)
Because it conflicts with public void error(String msg, MDC... mdcs)
When we want to use error(String msg, MDC... mdcs), it will enter error(String msg, Object... args)

panbingkun · 2024-05-06T09:20:21Z

core/src/main/java/org/apache/spark/io/ReadAheadInputStream.java

 */
 package org.apache.spark.io;

-import com.google.common.base.Preconditions;


Taking this chance, let's adjust the import order of java code

panbingkun · 2024-05-06T09:27:27Z

core/src/main/java/org/apache/spark/io/ReadAheadInputStream.java

 public class ReadAheadInputStream extends InputStream {

-  private static final Logger logger = LoggerFactory.getLogger(ReadAheadInputStream.class);
+  private static final Logger LOGGER = LoggerFactory.getLogger(ReadAheadInputStream.class);


Let's capitalize variables of type static final.

I would suggest avoiding such unnecessary change.
In https://www.slf4j.org/api/org/slf4j/Logger.html, the example code is using logger as well.

panbingkun · 2024-05-06T09:30:06Z

core/src/main/java/org/apache/spark/memory/TaskMemoryManager.java

-          requestingConsumer);
+      if (LOGGER.isDebugEnabled()) {
+        LOGGER.debug("Task {} acquired {} for {}", String.valueOf(taskAttemptId),
+          Utils.bytesToString(got), requestingConsumer.toString());


This place does not need to check whether requestingConsumer is null, because it has been checked previously as following:

panbingkun · 2024-05-06T10:42:00Z

cc @gengliangwang

gengliangwang · 2024-05-06T17:47:40Z

core/src/main/java/org/apache/spark/io/ReadAheadInputStream.java

        underlyingInputStream.close();
      } catch (IOException e) {
-        logger.warn(e.getMessage(), e);
+        LOGGER.warn("{}", e, MDC.of(LogKeys.REASON$.MODULE$, e.getMessage()));


REASON => ERROR?

gengliangwang · 2024-05-06T19:04:58Z

core/src/main/java/org/apache/spark/util/collection/unsafe/sort/UnsafeExternalSorter.java

+      MDC.of(LogKeys.THREAD_ID$.MODULE$, Thread.currentThread().getId()),
+      MDC.of(LogKeys.MEMORY_SIZE$.MODULE$, Utils.bytesToString(getMemoryUsage())),
+      MDC.of(LogKeys.NUM_SPILL_WRITERS$.MODULE$, spillWriters.size()),
+      MDC.of(LogKeys.TIME_UNIT$.MODULE$, spillWriters.size() > 1 ? " times" : " time"));


SPILL_TIMES?

…uctured logging framework ### What changes were proposed in this pull request? Since we are targeting on migration INFO/WARN/ERROR level logs to structure logging, this PR removes the logDebug and logTrace methods from the JAVA structured logging framework. ### Why are the changes needed? In the log migration PR #46390, there are unnecessary changes such as updating ``` logger.debug("Task {} need to spill {} for {}", taskAttemptId, Utils.bytesToString(required - got), requestingConsumer); ``` to ``` LOGGER.debug("Task {} need to spill {} for {}", String.valueOf(taskAttemptId), Utils.bytesToString(required - got), requestingConsumer.toString()); ``` With this PR, we can avoid such changes during log migrations. ### Does this PR introduce _any_ user-facing change? No ### How was this patch tested? Existing UT. ### Was this patch authored or co-authored using generative AI tooling? No Closes #46405 from gengliangwang/updateJavaLog. Authored-by: Gengliang Wang <gengliang@apache.org> Signed-off-by: Dongjoon Hyun <dhyun@apple.com>

panbingkun · 2024-05-07T01:12:59Z

@gengliangwang
All done.
Thanks.

gengliangwang · 2024-05-07T05:57:26Z

core/src/main/java/org/apache/spark/util/collection/unsafe/sort/UnsafeSorterSpillReader.java


 package org.apache.spark.util.collection.unsafe.sort;

+import java.io.*;


let's revert the unnecessary changes in this file

Is it the import order of the file header, or from org.slf4j.Logger & org.slf4j.LoggerFactory to org.apache.spark.internal.Logger &org.apache.spark.internal.LoggerFactory
The later change is to prohibit the import of org.slf4j.Logger & org.slf4j.LoggerFactory in java code later, so as to prevent subsequent developers from introducingorg.slf4j.Logger & org.slf4j.LoggerFactory again, thus writing inconsistent logic.

Since there is no log migration in this file, why do we need to change the import order here?

The import order has been restored.
I actually have an idea to align the import order of java with the import order of scala.
It's OK, I restored it, 😄

gengliangwang · 2024-05-07T06:01:55Z

core/src/main/java/org/apache/spark/util/collection/unsafe/sort/UnsafeExternalSorter.java

-      logger.info("Spilling data because number of spilledRecords crossed the threshold " +
-        numElementsForSpillThreshold);
+      logger.info("Spilling data because number of spilledRecords crossed the threshold {}",
+        MDC.of(LogKeys.SHUFFLE_SPILL_NUM_ELEMENTS_FORCE_SPILL_THRESHOLD$.MODULE$,


this key is sort of long. How about NUM_ELEMENTS_SPILL_THRESHOLD?

gengliangwang

LGTM except two comments

gengliangwang · 2024-05-07T20:07:46Z

Thanks, merging to master

cxzl25 · 2024-08-23T09:35:13Z

core/src/main/java/org/apache/spark/shuffle/sort/ShuffleExternalSorter.java

    if (inMemSorter.numRecords() >= numElementsForSpillThreshold) {
-      logger.info("Spilling data because number of spilledRecords crossed the threshold " +
-        numElementsForSpillThreshold);
+      logger.info("Spilling data because number of spilledRecords crossed the threshold {}" +


When re-implementing SPARK-27734, I found that there was something wrong with the logs here.

{}" + MDC.of -> {}", MDC.of

[SPARK-48134][CORE] Spark core (java side): Migrate error/warn/info…

fda2a95

… with variables to structured logging framework

github-actions bot added the CORE label May 5, 2024

update it

f97c2a6

panbingkun commented May 6, 2024

View reviewed changes

panbingkun marked this pull request as ready for review May 6, 2024 10:42

gengliangwang reviewed May 6, 2024

View reviewed changes

gengliangwang mentioned this pull request May 6, 2024

[SPARK-48145][CORE] Remove logDebug and logTrace with MDC in JAVA structured logging framework #46405

Closed

gengliangwang reviewed May 6, 2024

View reviewed changes

panbingkun added 3 commits May 7, 2024 08:23

update

442691f

update

4f988f1

fix

e7a7b51

gengliangwang reviewed May 7, 2024

View reviewed changes

gengliangwang approved these changes May 7, 2024

View reviewed changes

panbingkun added 2 commits May 7, 2024 14:47

Merge branch 'master' into core_java_sl

a97a1f3

update

4943ec3

gengliangwang closed this in 3d9d1f3 May 7, 2024

cxzl25 reviewed Aug 23, 2024

View reviewed changes


		package org.apache.spark.util.collection.unsafe.sort;

		import java.io.*;

[SPARK-48134][CORE] Spark core (java side): Migrate error/warn/info with variables to structured logging framework #46390

[SPARK-48134][CORE] Spark core (java side): Migrate error/warn/info with variables to structured logging framework #46390

Uh oh!

Conversation

panbingkun commented May 5, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

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?

Was this patch authored or co-authored using generative AI tooling?

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!

Choose a reason for hiding this comment

Uh oh!

panbingkun commented May 6, 2024

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!

panbingkun commented May 7, 2024

Uh oh!

gengliangwang May 7, 2024 • 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!

gengliangwang May 7, 2024 • 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!

gengliangwang left a comment

Choose a reason for hiding this comment

Uh oh!

gengliangwang commented May 7, 2024

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

[SPARK-48134][CORE] Spark core (java side): Migrate `error/warn/info` with variables to structured logging framework #46390

[SPARK-48134][CORE] Spark core (java side): Migrate `error/warn/info` with variables to structured logging framework #46390

panbingkun commented May 5, 2024 •

edited

Loading

gengliangwang May 7, 2024 •

edited

Loading

gengliangwang May 7, 2024 •

edited

Loading