Skip to content

Conversation

@VysotskiVadim
Copy link
Contributor

@VysotskiVadim VysotskiVadim commented Oct 5, 2022

Description

I'd like to add many debug logs to #6434. For example I want to logs ids of passed routes: routes.map { it.id }.joinToString(separator = ", ") {it} . But I worry that extensive logging with all this list transformations and concatenations may reduce performance for users who don't want to read them. What do you think about lazy logging where passed lazy messages are executed only if it makes sense for current log level?

@VysotskiVadim VysotskiVadim added the skip changelog Should not be added into version changelog. label Oct 5, 2022
@VysotskiVadim VysotskiVadim requested a review from a team as a code owner October 5, 2022 10:28
@RingerJK
Copy link
Contributor

RingerJK commented Oct 5, 2022

great idea 👍 what if we change API so that every message becomes a lazy message? it will align API

@codecov
Copy link

codecov bot commented Oct 5, 2022

Codecov Report

Merging #6439 (0a76da4) into main (73339c0) will decrease coverage by 0.04%.
The diff coverage is 24.13%.

Impacted file tree graph

@@             Coverage Diff              @@
##               main    #6439      +/-   ##
============================================
- Coverage     69.41%   69.37%   -0.05%     
  Complexity     4651     4651              
============================================
  Files           697      698       +1     
  Lines         27510    27536      +26     
  Branches       3204     3210       +6     
============================================
+ Hits          19097    19104       +7     
- Misses         7169     7187      +18     
- Partials       1244     1245       +1     
Impacted Files Coverage Δ
...om/mapbox/navigation/base/route/NavigationRoute.kt 51.92% <0.00%> (+0.24%) ⬆️
...main/java/com/mapbox/common/NativeLoggerWrapper.kt 0.00% <0.00%> (ø)
...mapbox/navigation/utils/internal/LoggerFrontend.kt 60.86% <0.00%> (-2.77%) ⬇️
...mapbox/navigation/utils/internal/LoggerProvider.kt 50.00% <0.00%> (-44.74%) ⬇️
...pbox/navigation/utils/internal/LoggingLevelUtil.kt 87.50% <87.50%> (ø)

NativeLoggerWrapper.debug(message, NAV_SDK_CATEGORY)
}

override fun logD(category: String?, lazyMsg: () -> String) {
Copy link
Contributor

Choose a reason for hiding this comment

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

I like that. The lambda would still be created but I don't see how we could evade that.
Even if we make the logD method inline (which is not possible with interfaces), LogConfiguration.getLoggingLevel() is not a constant, so the lambda would not be removed anyway.

Choose a reason for hiding this comment

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

LogConfiguration.getLoggingLevel() is not a constant

Inlining doesn't require everything in the lambda to be constant, does it? LogConfiguration.getLoggingLevel() is statically accessible to the lambda, so it should work just fine (at least that's what I see in decompiled classes). @VysotskiVadim I think it would be worth exploring how we could make this setup work with inline functions, I guess the biggest hurdle would be organizing the interface in a way that makes it possible.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Made methods inline to avoid creation of an object for lambda

Copy link
Contributor

Choose a reason for hiding this comment

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

Oh, right, I was thinking in other terms. If LogConfiguration.getLoggingLevel() was a constant and the inlining was used, the whole code might have been removed after the compilation because it would be unreachable.
But now yes, we have a code that creates a lambda but it won't be invoked if unnecessary, that works.

}

override fun logD(category: String?, lazyMsg: () -> String) {
when (LogConfiguration.getLoggingLevel()) {
Copy link
Contributor

Choose a reason for hiding this comment

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

This level can change. We should keep in mind (better even in docs) that if you had level info, invoked the lazy log and then changed the level to debug, you won't see the log. I'm not sure how it works with usual logs now but in AS it's just a filter so you'll see the old logs as well.

Choose a reason for hiding this comment

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

LogConfiguration is a runtime option. By default it's set to INFO and changing it in the runtime won't print all the old DEBUG logs, so it's consistent across the board.


/**
* @param category optional string to identify the source or category of the log message.
* @param lazyMsg is a lazy message to log. Isn't executed if current log level less verbose than Inline.
Copy link
Contributor

Choose a reason for hiding this comment

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

What is "current log level less verbose than Inline"?
It also should be info, not inline. But I still don't get the meaning.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

It also should be info, not inline

thanks 👍
I should have waited for tomorrow instead of quickly finishing PR this evening 🤣

Copy link
Contributor Author

Choose a reason for hiding this comment

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

What is "current log level less verbose than Inline"?

After fixing grammar errors and typos it sounds like " The lazy message isn't executed if current log level is less verbose than Info". With less verbose log level you see less details in the logs. For example Error is less verbose than Info, if you set current log level to Error you will see less logs. It doesn't make sense to execute lazy message with verbose level Info if current log level Error, because nobody will see the message anyway. Does it make sense?

Copy link
Contributor

Choose a reason for hiding this comment

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

Thanks. Then "if current log level is less verbose" and we should be good.

Copy link
Contributor

Choose a reason for hiding this comment

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

Ah, you've fixed that already.

}

/**
* Should not be used directly. Added to support inline calls.
Copy link
Contributor

Choose a reason for hiding this comment

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

How does it help with inlining?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Clarified documentation. Does it make sense now?

Copy link
Contributor

Choose a reason for hiding this comment

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

Aaah, I see. But why shouldn't it be used directly? It doesn't look like it can hurt anyone.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

It just feels like internal implementation detail and I can't keep it internal because of inline, so I decided to restrict usage by forbidding it in the comments 😅

@VysotskiVadim VysotskiVadim merged commit 6690787 into main Oct 6, 2022
@VysotskiVadim VysotskiVadim deleted the vv-lazy-log branch October 6, 2022 09:11
* Should not be used directly.
* Added to support inline calls. Public inline functions can use only public API inside.
*/
fun logLevel() = LoggerProvider.frontend.getLogLevel()
Copy link
Contributor

Choose a reason for hiding this comment

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

By the way, you can make it internal if you add @PublishedApi annotation.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Amazing! ❤️
#6447

@VysotskiVadim VysotskiVadim mentioned this pull request Oct 6, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

skip changelog Should not be added into version changelog.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

5 participants