[SPARK-48182][SQL] SQL (java side): Migrate `error/warn/info` with variables to structured logging framework #46450

panbingkun · 2024-05-07T23:23:42Z

What changes were proposed in this pull request?

The pr aims to
1.migrate error/warn/info in module SQL 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.

…riables to structured logging framework

panbingkun · 2024-05-08T10:53:09Z

...-thriftserver/src/main/scala/org/apache/spark/sql/hive/thriftserver/SparkSQLCLIService.scala


+import org.apache.spark.internal.Logger


Used in this place:

spark/sql/hive-thriftserver/src/main/scala/org/apache/spark/sql/hive/thriftserver/SparkSQLCLIService.scala

Lines 116 to 119 in bd896ca

private val logInfo = (msg: String) => getAncestorField[Logger](this, 3, "LOG").info(msg)

private val logError = (msg: String, e: Throwable) =>

getAncestorField[Logger](this, 3, "LOG").error(msg, e)

panbingkun · 2024-05-08T10:57:41Z

sql/hive-thriftserver/src/main/java/org/apache/hive/service/auth/TSetIpAddressProcessor.java

@@ -38,7 +39,7 @@
 */
 public class TSetIpAddressProcessor<I extends Iface> extends TCLIService.Processor<Iface> {

-  private static final Logger LOGGER = LoggerFactory.getLogger(TSetIpAddressProcessor.class.getName());
+  private static final Logger LOGGER = LoggerFactory.getLogger(TSetIpAddressProcessor.class);


https://github.com/qos-ch/slf4j/blob/1d82519b07d7d755096d916dfbfaddd2d0e07c4f/slf4j-api/src/main/java/org/slf4j/LoggerFactory.java#L446-L456

panbingkun · 2024-05-08T11:00:05Z

sql/hive-thriftserver/src/main/java/org/apache/hive/service/ServiceOperations.java

@@ -129,9 +132,8 @@ public static Exception stopQuietly(Service service) {
    try {
      stop(service);
    } catch (Exception e) {
-      LOG.warn("When stopping the service " + service.getName()
-                   + " : " + e,


I think " : " + e is redundant because there is , e(Throwable) behind

panbingkun · 2024-05-08T11:26:12Z

sql/hive-thriftserver/src/main/java/org/apache/hive/service/cli/session/SessionManager.java

-    LOG.info(
-        "HiveServer2: Background operation thread keepalive time: " + keepAliveTime + " seconds");
+    LOG.info("HiveServer2: Background operation thread keepalive time: {} ms",
+      MDC.of(LogKeys.THREAD_KEEP_ALIVE_TIME$.MODULE$, keepAliveTime * 1000));


Let's turn our time unit into ms

panbingkun · 2024-05-08T11:29:29Z

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

@@ -193,4 +193,8 @@ static MessageThrowable of(String message, Throwable throwable) {
      return new MessageThrowable(message, throwable);
    }
  }
+


The following code will use it:

panbingkun · 2024-05-08T11:34:28Z

sql/hive-thriftserver/src/main/java/org/apache/hive/service/ServiceUtils.java

@@ -18,7 +18,7 @@

 import java.io.IOException;

-import org.slf4j.Logger;
+import org.apache.spark.internal.Logger;


The following code use it
I searched the spark code base. It seems that the public static void cleanup(Logger log, java.io.Closeable... closeables) method is not used. Maybe we can delete the following code?

spark/sql/hive-thriftserver/src/main/java/org/apache/hive/service/ServiceUtils.java

Lines 55 to 67 in d7f69e7

public static void cleanup(Logger log, java.io.Closeable... closeables) {

for (java.io.Closeable c : closeables) {

if (c != null) {

try {

c.close();

} catch(IOException e) {

if (log != null && log.isDebugEnabled()) {

log.debug("Exception in closing " + c, e);

}

}

}

}

}

panbingkun · 2024-05-08T11:38:10Z

cc @gengliangwang

gengliangwang · 2024-05-09T00:57:57Z

sql/hive-thriftserver/src/main/java/org/apache/hive/service/auth/HiveAuthFactory.java

-      throw new HiveSQLException(msg, "08S01", e);
+      LOG.error("Error verifying delegation token {}", e,
+        MDC.of(LogKeys.TOKEN$.MODULE$, delegationToken));
+      throw new HiveSQLException("Error verifying delegation token " + delegationToken,


nit: we can store the log entry into msg and use msg.message here.

How about the following?

gengliangwang · 2024-05-09T01:06:21Z

sql/hive-thriftserver/src/main/java/org/apache/hive/service/cli/session/SessionManager.java

-            " seconds has been exceeded. RUNNING background operations will be shut down", e);
+        LOG.warn("HIVE_SERVER2_ASYNC_EXEC_SHUTDOWN_TIMEOUT = {} ms has been exceeded. " +
+          "RUNNING background operations will be shut down", e,
+          MDC.of(LogKeys.TIMEOUT$.MODULE$, timeout * 1000));


This is not updated..

oh timeout is long type already. Keep the current code is also fine

gengliangwang · 2024-05-09T01:07:54Z

...hriftserver/src/main/java/org/apache/hive/service/cli/operation/ClassicTableTypeMapping.java

@@ -69,7 +72,8 @@ public ClassicTableTypeMapping() {
  public String[] mapToHiveType(String clientTypeName) {
    Collection<String> hiveTableType = clientToHiveMap.get(clientTypeName.toUpperCase());
    if (hiveTableType == null) {
-      LOG.warn("Not supported client table type " + clientTypeName);
+      LOG.warn("Not supported client table type {}",
+        MDC.of(LogKeys.CLIENT_TABLE_TYPE$.MODULE$, clientTypeName));


NIt: CLIENT_TABLE_TYPE is a bit confusing here. Is there a better name for this?

CLIENT_TABLE_TYPE -> CLASSIS_TABLE_TYPE

gengliangwang · 2024-05-09T03:24:57Z

...hriftserver/src/main/java/org/apache/hive/service/cli/operation/ClassicTableTypeMapping.java

@@ -69,7 +72,8 @@ public ClassicTableTypeMapping() {
  public String[] mapToHiveType(String clientTypeName) {
    Collection<String> hiveTableType = clientToHiveMap.get(clientTypeName.toUpperCase());
    if (hiveTableType == null) {
-      LOG.warn("Not supported client table type " + clientTypeName);
+      LOG.warn("Not supported client table type {}",
+        MDC.of(LogKeys.CLASSIS_TABLE_TYPE$.MODULE$, clientTypeName));


Seem there is a typo CLASSIC.
Let's simply use TABLE_TYPE for all the keys in this file.

gengliangwang · 2024-05-09T05:44:09Z

Thanks, merging to master

…riables to structured logging framework ### What changes were proposed in this pull request? The pr aims to 1.migrate `error/warn/info` in module `SQL` 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. Closes apache#46450 from panbingkun/sql_java_sl. Authored-by: panbingkun <panbingkun@baidu.com> Signed-off-by: Gengliang Wang <gengliang@apache.org>

panbingkun added 2 commits May 7, 2024 19:55

ready

03d777a

[SPARK-48182][SQL] SQL (java side): Migrate error/warn/info with va…

73e1cf1

…riables to structured logging framework

github-actions bot added the SQL label May 7, 2024

panbingkun added 3 commits May 8, 2024 08:10

fix

a83c185

fix

18df2f5

fix

1b580a5

panbingkun commented May 8, 2024

View reviewed changes

panbingkun added 2 commits May 8, 2024 19:37

update

71e0719

Merge branch 'master' into sql_java_sl

f621e24

panbingkun marked this pull request as ready for review May 8, 2024 11:37

gengliangwang reviewed May 9, 2024

View reviewed changes

panbingkun added 2 commits May 9, 2024 10:10

Merge branch 'master' into sql_java_sl

8fdc231

fix

ab2f1a5

gengliangwang reviewed May 9, 2024

View reviewed changes

update

88c31fd

gengliangwang approved these changes May 9, 2024

View reviewed changes

gengliangwang closed this in 85a6e35 May 9, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[SPARK-48182][SQL] SQL (java side): Migrate `error/warn/info` with variables to structured logging framework #46450

[SPARK-48182][SQL] SQL (java side): Migrate `error/warn/info` with variables to structured logging framework #46450

panbingkun commented May 7, 2024 •

edited

panbingkun May 8, 2024

panbingkun May 8, 2024

panbingkun May 8, 2024

panbingkun May 8, 2024

panbingkun May 8, 2024

panbingkun May 8, 2024

panbingkun commented May 8, 2024

gengliangwang May 9, 2024

panbingkun May 9, 2024

gengliangwang May 9, 2024

panbingkun May 9, 2024

gengliangwang May 9, 2024

gengliangwang May 9, 2024

gengliangwang May 9, 2024

panbingkun May 9, 2024

gengliangwang May 9, 2024

panbingkun May 9, 2024

gengliangwang commented May 9, 2024

	private val logInfo = (msg: String) => getAncestorField[Logger](this, 3, "LOG").info(msg)

	private val logError = (msg: String, e: Throwable) =>
	getAncestorField[Logger](this, 3, "LOG").error(msg, e)

	public static void cleanup(Logger log, java.io.Closeable... closeables) {
	for (java.io.Closeable c : closeables) {
	if (c != null) {
	try {
	c.close();
	} catch(IOException e) {
	if (log != null && log.isDebugEnabled()) {
	log.debug("Exception in closing " + c, e);
	}
	}
	}
	}
	}

[SPARK-48182][SQL] SQL (java side): Migrate error/warn/info with variables to structured logging framework #46450

[SPARK-48182][SQL] SQL (java side): Migrate error/warn/info with variables to structured logging framework #46450

Conversation

panbingkun commented May 7, 2024 • 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?

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

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

panbingkun commented May 8, 2024

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

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

gengliangwang commented May 9, 2024

[SPARK-48182][SQL] SQL (java side): Migrate `error/warn/info` with variables to structured logging framework #46450

[SPARK-48182][SQL] SQL (java side): Migrate `error/warn/info` with variables to structured logging framework #46450

panbingkun commented May 7, 2024 •

edited