[SPARK-2312] Logging Unhandled messages

[isaias]

The previous solution has changed based on #2048 discussions.

[isaias]

After send the PR I realized that I could have written some tests based on underlyingActor and isDefinedAt, if is valuable I can do it.

BR

[isaias]

Hi @ScrapCodes,

I am starting to contribute with Spark and knowing the source code/structure now, but I think that the use of Actor are limited to internal developers, so the Unhandled messages are not often sent to an Actor System, maybe if the actors were exposed to public call, unhandled messages could be more frequents.
But we can change the level to Trace too. I think this log is useful for developers and shouldn't to impact the end users. But it is just a first impression, another opnion will be very useful.

BR

[SparkQA]

Can one of the admins verify this patch?

[pwendell]

@ScrapCodes do you have a verdict one way or the other on this?

[ScrapCodes]

@pwendell This patch will lead to logging of messages like

14/09/08 10:23:39.639 WARN AppClient$ClientActor: Received unexpected actor system event: Associated [akka.tcp://spark@localhost:35007] <- [akka.tcp://driverPropsFetcher@localhost:54437]
14/09/08 10:23:39.639 WARN SparkDeploySchedulerBackend: Received unexpected actor system event: Associated [akka.tcp://spark@localhost:35007] <- [akka.tcp://driverPropsFetcher@localhost:54437]
14/09/08 10:23:39.788 WARN SparkDeploySchedulerBackend: Received unexpected actor system event: AssociationError [akka.tcp://spark@localhost:35007] <- [akka.tcp://driverPropsFetcher@localhost:54437]: Error [Shut down address: akka.tcp://driverPropsFetcher@localhost:54437] 

These are akka system messages. And I guess logging them at "WARN" would be a little noisy(They are not many of them as I initially thought.). So I am okay with it if logging level is changed to at least "DEBUG" or even better TRACE. I will leave rest to your judgement.

[andrewor14]

ok to test...

[andrewor14]

@isaias I think logging these messages are fine, but as @ScrapCodes indicated it will be fairly noisy for random dis/association events. I agree that having something logged is better than silently dropping unknown messages, but maybe we need to filter some of these out before we do that.

[SparkQA]

Test build #27751 has finished for PR 2055 at commit f341777.

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

[srowen]

Yes, perhaps at least turn this down to info?

[isaias]

@andrewor14 @srowen I think that down to info or debug is ok. What do you think? Can I change it? Wait for now?

[srowen]

@isaias can you make the change here? let's use debug logging.

[isaias]

@srowen done

[srowen]

Cool, unless anyone pops up to object, I'll merge tomorrow.

[SparkQA]

Test build #30341 has finished for PR 2055 at commit f61d9e6.

• This patch passes all tests.
• This patch merges cleanly.
• This patch adds no public classes.
• This patch does not change any dependencies.

[andrewor14]

My only concern with logging at debug is that this will mask unexpected events in most cases. However, given that this is strictly more informative than before and we haven't had to rely on these warnings to debug the system, I think this is fine to merge as is. LGTM.

[srowen]

Yeah, end users could turn on debug logging for this logger if needed. I could be turned up later to info by default if desired.