Skip to content

[Kaizen] improve logging configuration #977

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.

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

Merged
merged 8 commits into from
Jun 1, 2021
Merged

Conversation

jvdp
Copy link
Contributor

@jvdp jvdp commented Apr 30, 2021

akka.loglevel should be set to DEBUG so that messages with this level can actually show up in the logs, if we configure them appropriately. The filters and levels defined in logback.xml are applied after and thus will still filter all debug messages by default.

This should not cause significant overhead: https://doc.akka.io/docs/akka/current/logging.html#slf4j

Copy link
Contributor

@dzajkowski dzajkowski left a comment

Choose a reason for hiding this comment

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

please follow up on Petra's comment.

@jvdp
Copy link
Contributor Author

jvdp commented May 10, 2021

please follow up on Petra's comment.

So I did some basic performance checks with the getBlock endpoint (which logs a couple pretty big messages on DEBUG) and there is no noticable performance degradation. (If anything it became faster?)

@jvdp jvdp requested a review from dzajkowski May 10, 2021 13:13
@jvdp jvdp force-pushed the kaizen/improve-logging-config branch from 4a003f5 to ccbf7fd Compare May 10, 2021 13:39
@jvdp
Copy link
Contributor Author

jvdp commented May 10, 2021

I added a change to filter out the many messages like:

2021-05-10 15:41:28,710 [i.i.s.d.e.v.DiscoveryService$ServiceImpl] - Storing the ENR for Peer(id = 75fba1a45cbeba353361e8ec1ee2ce276fd5f88e78816024f3363b411e1a647bfb043eaec95fc101a8ae1c1a9d420cb2095c7665db3d029b526bce602ec65f86, address = /x.x.x.x:30303)

@jvdp jvdp force-pushed the kaizen/improve-logging-config branch from ccbf7fd to b6b157d Compare May 10, 2021 13:45
# Not using ${logging.logs-level} because it might be set to TRACE, which our version of Akka doesn't have.
loglevel = "INFO"
# the effective log level is configured for Logback; this loglevel only determines what is passed to Slf4j
loglevel = "DEBUG"
Copy link
Contributor

@dzajkowski dzajkowski May 13, 2021

Choose a reason for hiding this comment

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

ok so I think this is overthinking it. the consequence of passing TRACE to the log system is:

[ERROR] [05/13/2021 09:51:24.512] [run-main-0] [EventStream(akka://mantis_system)] unknown akka.loglevel TRACE
akka.event.Logging$LoggerException:
	at akka.event.LoggingBus.$anonfun$startDefaultLoggers$1(Logging.scala:113)
	at akka.event.LoggingBus.$anonfun$startDefaultLoggers$1$adapted(Logging.scala:110)
	at scala.Option.getOrElse(Option.scala:201)
	at akka.event.LoggingBus.startDefaultLoggers(Logging.scala:110)
	at akka.event.LoggingBus.startDefaultLoggers$(Logging.scala:108)
	at akka.event.EventStream.startDefaultLoggers(EventStream.scala:26)
	at akka.actor.LocalActorRefProvider.init(ActorRefProvider.scala:605)
	at akka.actor.ActorSystemImpl.liftedTree2$1(ActorSystem.scala:1021)
	at akka.actor.ActorSystemImpl._start$lzycompute(ActorSystem.scala:1017)
	at akka.actor.ActorSystemImpl._start(ActorSystem.scala:1017)
	at akka.actor.ActorSystemImpl.start(ActorSystem.scala:1040)
	at akka.actor.ActorSystem$.apply(ActorSystem.scala:272)
	at akka.actor.ActorSystem$.apply(ActorSystem.scala:316)
	at akka.actor.ActorSystem$.apply(ActorSystem.scala:260)

I think this is fine and it's a better solution to use ${logging.logs-level} instead of trying to guess what a good level might be.
maybe a note on the logs-level setting that notes this interaction.
eg.

# Note: if this level is set to TRACE the akka.loglevel needs to be adjusted (akka does not know TRACE)

Copy link
Contributor Author

@jvdp jvdp May 13, 2021

Choose a reason for hiding this comment

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

Well, that won't work as expected when overall "logs-level" is info but you configure some specific parts for a level lower than that. (Which is what I'm doing a lot now.)

Copy link
Contributor

Choose a reason for hiding this comment

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

For me this feels like a bit of personal preference. How often do we use a log level of trace anyway? For that I think I prefer Dom's perspective

@jvdp jvdp force-pushed the kaizen/improve-logging-config branch 2 times, most recently from 5852359 to 3cdbf51 Compare May 24, 2021 18:41
@jvdp
Copy link
Contributor Author

jvdp commented May 28, 2021

Writing a top-level comment to clarify the reason for this PR: it's a bit hidden (and surprising, at least to me) that you have to change the akka.loglevel when you set the LOGSLEVEL env var to DEBUG or set a fine-grained log level for a package prefix to DEBUG in logback.xml. There's no indication that this is needed, other than debug messages mysteriously not appearing. This PR aims to address both those use cases.

@jvdp jvdp requested review from dzajkowski and leo-bogastry May 28, 2021 12:54
@jvdp jvdp merged commit e1997b6 into develop Jun 1, 2021
@jvdp jvdp deleted the kaizen/improve-logging-config branch June 1, 2021 09:09
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants