[SPARK-48490][CORE][FOLLOWUP] Fix Unescape about MessageWithContext #47029

panbingkun · 2024-06-19T11:42:56Z

What changes were proposed in this pull request?

The PR aims to solve the issue encountered in the following scenarios:
#46897 (comment)
We force the execution of StringEscapeUtils.unescapeJava operation on message of MessageWithContext, which will result in unexpected behavior.

Why are the changes needed?

Fix bug.

Does this PR introduce any user-facing change?

No.

How was this patch tested?

Pass GA
Existed UT

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

No.

panbingkun · 2024-06-19T11:53:10Z

common/utils/src/test/scala/org/apache/spark/util/StructuredLoggingSuite.scala


  def basicMsgWithEscapeCharMDC: LogEntry =
-    log"This is a log message\nThis is a new line \t other msg"
+    log"This is a log message" + LF + log"This is a new line " + TAB + log" other msg"


Although the above writing may seem a bit ugly, so far, the only method I can find that meets the requirements and is relatively acceptable

panbingkun · 2024-06-19T12:02:55Z

Background
[SPARK-48554][INFRA] Use R 4.4.0 in windows R GitHub Action Window job #46897
Reproduction steps

org.apache.commons.text.StringEscapeUtils.unescapeJava("C:\\Users\\runneradmin\\AppData\\Local\\Temp\\spark-9f4b7e74-ea9e-46fc-bde6-1449cc9f6e8e\\userFiles-aaee9fd8-13b2-4cb2-a968-52895086988b\\run-all.R")

Unable to parse unicode value: serF
java.lang.IllegalArgumentException: Unable to parse unicode value: serF
	at org.apache.commons.text.translate.UnicodeUnescaper.translate(UnicodeUnescaper.java:55)
	at org.apache.commons.text.translate.AggregateTranslator.translate(AggregateTranslator.java:58)
	at org.apache.commons.text.translate.CharSequenceTranslator.translate(CharSequenceTranslator.java:101)
	at org.apache.commons.text.translate.CharSequenceTranslator.translate(CharSequenceTranslator.java:63)
	at org.apache.commons.text.StringEscapeUtils.unescapeJava(StringEscapeUtils.java:802)

panbingkun · 2024-06-19T12:04:24Z

cc @gengliangwang @HyukjinKwon @dongjoon-hyun

panbingkun · 2024-06-19T12:08:43Z

Regarding the unexpected behaviors that already exist in our Spark, I will work together to fix them once this PR is completed. eg:

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

Line 3027 in 484e7ac

    
           logInfo(log"Unzipped from ${MDC(PATH, dfsZipFile)}\n\t${MDC(PATHS, files.mkString("\n\t"))}")

panbingkun · 2024-06-19T12:11:10Z

The root cause is that it be recognized as a string, not a character in StringContext, eg: '\n'

when write as log"\n", it is actually:

92, 110

when write as s"\n", it is actually:

HyukjinKwon · 2024-06-20T00:28:23Z

common/utils/src/main/scala/org/apache/spark/internal/Logging.scala

 * Companion class for lazy evaluation of the MessageWithContext instance.
 */
 class LogEntry(messageWithContext: => MessageWithContext) {
-  def message: String = StringEscapeUtils.unescapeJava(messageWithContext.message)


Should we maybe simply try-catch, and return the original string if it fails?

Windows users are arguably less in any event.

and logging shouldn't fail the application anyway.

Hmm..., this may have successfully unescaped, but the result does not meet expectations, such as:

println(StringEscapeUtils.unescapeJava("C:\\Users\\runneradmin\\AppData\\Local\\remp\\spark-9f4b7e74-ea9e-46fc-bde6-1449cc9f6e8e"))

We may expect it to output as:

C:\Users\runneradmin\AppData\Local\remp\spark-9f4b7e74-ea9e-46fc-bde6-1449cc9f6e8e

Actual, its output is:

empspark-9f4b7e74-ea9e-46fc-bde6-1449cc9f6e8e

So it's better not to execute the unescape operation and let the user manually use the method I wrote in UT to achieve its expected behavior, although it does look a bit ugly.

and logging shouldn't fail the application anyway.

Yes, we can use try ... catch temporarily fixes it, but it has some of my flaws mentioned above.
Or should we do this (use try ... catch) first and let build_sparkr_window pass?

I am fine with this approach but I think we need @gengliangwang 's look at least.

Yeah, let's wait for @gengliangwang's review.
Thanks!

gengliangwang · 2024-06-20T04:14:55Z

The root cause is that it be recognized as a string, not a character in StringContext, eg: '\n'
when write as log"\n", it is actually:
92, 110

@panbingkun I don't get it. How does this happen in windows? We are passing entry.message to the log4j methods.

gengliangwang · 2024-06-20T04:20:56Z

common/utils/src/main/scala/org/apache/spark/internal/Logging.scala


+  private final val LF_CHAR: Char = '\n'
+  private final val TAB_CHAR: Char = '\t'
+  final val LF = MessageWithContext(s"$LF_CHAR", new java.util.HashMap[String, String]())


Wait..are you suggesting that we should use this constant in log messages? If so, I would prefer try...catch as @HyukjinKwon suggested.

This is just to make it easier for developers to use commonly used escape characters, such as:
line break - LF_CHAR, tab - TAB_CHAR
Of course, we can also use it this way:

Additional explanation, if we write it as follows, it will exhibit unexpected behavior:

Because it is written in this way, in our framework it will consider "\n" as a string rather than a character

that is to say:

s"\n" != log"\n".message

panbingkun · 2024-06-20T05:20:47Z

The root cause is that it be recognized as a string, not a character in StringContext, eg: '\n'
when write as log"\n", it is actually:
92, 110

@panbingkun I don't get it. How does this happen in windows? We are passing entry.message to the log4j methods.

It should not only be on Windows, as long as there are strings like "\r", "\t", "\n" in our log messages, similar unexpected behavior will occur.
However, it happens that the file path on Windows is like this: "C:\Users\runneradmin\AppData\Local\remp\spark-9f4b7e74-ea9e-46fc-bde6-1449cc9f6e8e", while on Mac OS or Linux systems, the file path is "/Users/runneradmin/AppData/Local/remp/spark-9f4b7e74-ea9e-46fc-bde6-1449cc9f6e8e", so we did not encounter it before.

panbingkun · 2024-06-20T05:56:30Z

common/utils/src/main/scala/org/apache/spark/internal/Logging.scala

      MessageWithContext(sb.toString(), context)
    }
+
+    def log(c: Char): MessageWithContext = {


We have provided a new method for the character

gengliangwang · 2024-06-21T01:15:03Z

@panbingkun I created a new approach in #47050

panbingkun · 2024-06-21T01:44:55Z

closing in favor of #47050

[SPARK-48490][CORE][FOLLOWUP] Fix Unescape about MessageWithContext

9768ceb

panbingkun commented Jun 19, 2024

View reviewed changes

panbingkun marked this pull request as ready for review June 19, 2024 12:04

HyukjinKwon reviewed Jun 20, 2024

View reviewed changes

gengliangwang reviewed Jun 20, 2024

View reviewed changes

panbingkun commented Jun 20, 2024

View reviewed changes

panbingkun closed this Jun 21, 2024

[SPARK-48490][CORE][FOLLOWUP] Fix Unescape about MessageWithContext #47029

[SPARK-48490][CORE][FOLLOWUP] Fix Unescape about MessageWithContext #47029

Uh oh!

Conversation

panbingkun commented Jun 19, 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!

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

Uh oh!

Uh oh!

panbingkun commented Jun 19, 2024

Uh oh!

panbingkun commented Jun 19, 2024

Uh oh!

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

Uh oh!

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!

Choose a reason for hiding this comment

Uh oh!

gengliangwang commented Jun 20, 2024

Uh oh!

Choose a reason for hiding this comment

Uh oh!

panbingkun Jun 20, 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!

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

Uh oh!

Uh oh!

panbingkun Jun 20, 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!

gengliangwang commented Jun 21, 2024

Uh oh!

panbingkun commented Jun 21, 2024

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

panbingkun commented Jun 19, 2024 •

edited

Loading

panbingkun commented Jun 19, 2024 •

edited

Loading

panbingkun commented Jun 19, 2024 •

edited

Loading

panbingkun Jun 20, 2024 •

edited

Loading

panbingkun commented Jun 20, 2024 •

edited

Loading

panbingkun Jun 20, 2024 •

edited

Loading