SPARK-3357 [CORE] Internal log messages should be set at DEBUG level instead of INFO

[srowen]

Demote some 'noisy' log messages to debug level. I added a few more, to include everything that gets logged in stanzas like this:

15/03/01 00:03:54 INFO BlockManager: Removing broadcast 0
15/03/01 00:03:54 INFO BlockManager: Removing block broadcast_0_piece0
15/03/01 00:03:54 INFO MemoryStore: Block broadcast_0_piece0 of size 839 dropped from memory (free 277976091)
15/03/01 00:03:54 INFO BlockManagerInfo: Removed broadcast_0_piece0 on localhost:49524 in memory (size: 839.0 B, free: 265.1 MB)
15/03/01 00:03:54 INFO BlockManagerMaster: Updated info of block broadcast_0_piece0
15/03/01 00:03:54 INFO BlockManager: Removing block broadcast_0
15/03/01 00:03:54 INFO MemoryStore: Block broadcast_0 of size 1088 dropped from memory (free 277977179)
15/03/01 00:03:54 INFO ContextCleaner: Cleaned broadcast 0

as well as regular messages like

15/03/01 00:02:33 INFO MemoryStore: ensureFreeSpace(2640) called with curMem=47322, maxMem=278019440

WDYT? good or should some be left alone?

CC @mengxr who suggested some of this.

[SparkQA]

Test build #28135 has started for PR 4838 at commit d9b784d.

• This patch merges cleanly.

[SparkQA]

Test build #28135 has finished for PR 4838 at commit d9b784d.

• This patch passes all tests.
• This patch merges cleanly.
• This patch adds no public classes.

[AmplabJenkins]

Test PASSed.
Refer to this link for build results (access rights to CI server needed):
https://amplab.cs.berkeley.edu/jenkins//job/SparkPullRequestBuilder/28135/
Test PASSed.

[pwendell]

This one I'd say is fairly important. I've used it somewhat often in production clusters to understand when things are dropping to disk and why.

[pwendell]

Chimed in in a few places. I think overall, a good goal is that when we are doing our normal GC of RDD's and broadcasts, we don't want to be so verbose. This cleaning occurs asynchronously and it's confusing for users to see these messages.

When dropping blocks due to cache contention though, I'm not so sure we want silence these messages.

[SparkQA]

Test build #28145 has started for PR 4838 at commit dce75c1.

• This patch merges cleanly.

[SparkQA]

Test build #28145 has finished for PR 4838 at commit dce75c1.

• This patch passes all tests.
• This patch merges cleanly.
• This patch adds no public classes.

[AmplabJenkins]

Test PASSed.
Refer to this link for build results (access rights to CI server needed):
https://amplab.cs.berkeley.edu/jenkins//job/SparkPullRequestBuilder/28145/
Test PASSed.

[pwendell]

On this one - do you know if this already gets logged somewhere else if a block is dropped from memory due to contention? It would be good to make sure there is some INFO level logging when a block is dropped due to memory being exceeded.

[pwendell]

I believe we do have INFO level logging for this up the call chain when drops are blocked due to cache contention:

https://github.com/apache/spark/blob/master/core/src/main/scala/org/apache/spark/storage/BlockManager.scala#L1004

Might be nice to augment that logging to have information on the size and limit (like this does).