Skip to content

[SPARK-30387] Improving stop hook log message #27049

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.

Sign up for GitHub

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

Closed
jobitmathew wants to merge 2 commits into from
Closed

[SPARK-30387] Improving stop hook log message #27049

Changes from 1 commit
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
9e71efe
improving stop hook log message
jobitmathew Dec 30, 2019
b6577cb
Updated log message
jobitmathew Jan 2, 2020
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion ...s/yarn/src/main/scala/org/apache/spark/scheduler/cluster/YarnClientSchedulerBackend.scala
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -164,7 +164,7 @@ private[spark] class YarnClientSchedulerBackend(

super.stop()
client.stop()
logInfo("Stopped")
logInfo("YarnClientSchedulerBackend Stopped")

@HeartSaVioR HeartSaVioR Dec 30, 2019

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Isn't YarnClientSchedulerBackend added to full of log message, as in most case the format contains the logger name (mostly same as class name)?

@amanomer amanomer Dec 30, 2019

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Current log message is

2019-12-27 20:23:26,613 | INFO | [main] | Stopped | org.apache.spark.internal.Logging$class.logInfo(Logging.scala:54)

@tgravescs tgravescs Dec 31, 2019

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

You must be using a custom logging file because by default you get:

19/12/31 10:47:28 INFO YarnClientSchedulerBackend: Stopped

@tgravescs tgravescs Dec 31, 2019

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Look at the spark conf/log4j.properties.template file for the format used there

@srowen srowen Dec 31, 2019

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

If true, and I suspect you're right, is there much harm in just adding to the log message anyway?

@amanomer amanomer Dec 31, 2019

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Also on other places we are using descriptive log message. Like,

spark/core/src/main/scala/org/apache/spark/deploy/ExternalShuffleService.scala

Lines 169 to 171 in ce7a49f

ShutdownHookManager.addShutdownHook { () =>
logInfo("Shutting down shuffle service.")
server.stop()

@tgravescs tgravescs Dec 31, 2019

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

no harm, I'm ok with the change, there may just be other places in the code that aren't clear without it so you may want to look at your logging config anyway.

@HeartSaVioR HeartSaVioR Jan 2, 2020

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Same as @tgravescs, I think log4j format matters, but agree no harm with this.

@HyukjinKwon HyukjinKwon Jan 2, 2020

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

I don't think we should necessarily add it.

because by default you get:

19/12/31 10:47:28 INFO YarnClientSchedulerBackend: Stopped

Also, by default, seems showing the logs fine. Otherwise, we should fix so many places as @tgravescs pointed out. If class names should be shown, that should properly configured for such places.

@amanomer amanomer Jan 2, 2020

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Yes. as @tgravescs pointed out, here logs can be improved by changing log4j conversion pattern.

@HyukjinKwon HyukjinKwon Jan 2, 2020

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

@amanomer, why don't you just make the log better just by not using class name directly like the reference you pointed out? e.g.) YARN client scheduler backend stopped.

@amanomer amanomer Jan 2, 2020

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

@jobitmathew please update the log message.

@jobitmathew84 jobitmathew84 Jan 2, 2020

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

@amanomer
@HyukjinKwon
@srowen
@tgravescs
changes done as per HyukjinKwon's suggestion.Could you please check.

}

override protected def updateDelegationTokens(tokens: Array[Byte]): Unit = {
Expand Down