Skip to content
This repository has been archived by the owner on Nov 15, 2023. It is now read-only.

Init RuntimeLogger automatically for each runtime api call #8128

Merged
merged 13 commits into from
Mar 1, 2021

Conversation

bkchr
Copy link
Member

@bkchr bkchr commented Feb 15, 2021

This pr change the runtime api in such a way to always and automatically
enable the RuntimeLogger. This enables the user to use log or
tracing from inside the runtime to create log messages. As logging
introduces some extra code and especially increases the size of the wasm
blob. It is advised to disable all logging completely with
sp-api/disable-logging when doing the wasm builds for the on-chain
wasm runtime.

Besides these changes, the pr also brings most of the logging found in
frame to the same format "runtime::*".

Fixes: #7927

Should fix: #8107

polkadot companion: paritytech/polkadot#2522

This pr change the runtime api in such a way to always and automatically
enable the `RuntimeLogger`. This enables the user to use `log` or
`tracing` from inside the runtime to create log messages. As logging
introduces some extra code and especially increases the size of the wasm
blob. It is advised to disable all logging completely with
`sp-api/disable-logging` when doing the wasm builds for the on-chain
wasm runtime.

Besides these changes, the pr also brings most of the logging found in
frame to the same format "runtime::*".
@bkchr bkchr added A0-please_review Pull request needs code review. B7-runtimenoteworthy C1-low PR touches the given topic and has a low impact on builders. labels Feb 15, 2021
@kianenigma
Copy link
Contributor

Maybe we can do something like this to also standardize this runtime:: prefix.

frame/im-online/src/lib.rs Outdated Show resolved Hide resolved
frame/staking/src/lib.rs Show resolved Hide resolved
Co-authored-by: Guillaume Thiolliere <gui.thiolliere@gmail.com>
Copy link
Contributor

@gui1117 gui1117 left a comment

Choose a reason for hiding this comment

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

If I understand correctly the feature "max_level_off" propagate to all crate thus the wasm binary compiled with feature "disable-logging" compiles all the crate with "log/max_level_off", isn't it?

I'm not familiar with how log removes the logging code.
Or maybe what you mean by:

As logging introduces some extra code and especially increases the size of the wasm
blob.

Is just about the initialization of logger in wasm not the logging in pallets themself.

Another note: I think it should better to have the feature disable-logging in node-runtime as well so people can compile wasm binary with cargo build --feature disable-logging -p node-runtime (or I don't know what it the command documented to build the wasm binary)

test-utils/runtime/Cargo.toml Outdated Show resolved Hide resolved
@bkchr
Copy link
Member Author

bkchr commented Feb 15, 2021

If I understand correctly the feature "max_level_off" propagate to all crate thus the wasm binary compiled with feature "disable-logging" compiles all the crate with "log/max_level_off", isn't it?

Yes that is correct.

I'm not familiar with how log removes the logging code.

The logging is just a macro that is essentially wrapped in some if: https://github.com/rust-lang/log/blob/master/src/macros.rs#L201

This feature sets STATIC_MAX_LEVEL to OFF. So, the if condition is always false and the compiler should remove the if completely, because it would be never called. :)

@bkchr
Copy link
Member Author

bkchr commented Feb 15, 2021

Another note: I think it should better to have the feature disable-logging in node-runtime as well so people can compile wasm binary with cargo build --feature disable-logging -p node-runtime (or I don't know what it the command documented to build the wasm binary)

Yeah in the end that will come. However, I'm not sure if we require this for the Substrate node. In the end I want a proper tutorial that explains this to people. :)

@gui1117
Copy link
Contributor

gui1117 commented Feb 22, 2021

So this will need the polkadot companion for adding features to the runtimes,
And also document the process somehow,

But otherwise looks good to me

@bkchr
Copy link
Member Author

bkchr commented Feb 22, 2021

Yeah. I want to go some 2 way documentation way. For polkadot I will communicate this internal. For Substrate in general I want to have this on the dev hub

Copy link
Contributor

@gui1117 gui1117 left a comment

Choose a reason for hiding this comment

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

ok, don't know in which order we do stuff for documentation, but this PR is ok

]
nightly = []
Copy link
Contributor

@kianenigma kianenigma Feb 25, 2021

Choose a reason for hiding this comment

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

hell yea thank you

Copy link
Contributor

@kianenigma kianenigma left a comment

Choose a reason for hiding this comment

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

  1. I couldn't find this in the wasm-builder: can we have a test to compare the wasm size when the feature is on or off?

  2. As recommended elsewhere, I think can autogenerate the const LOG_TARGET: ... for all pallets in the macro, instead of assuming that they all prefix with runtime. We can also generate one helper macro for logging with LOG_TARGET (what I have done in staking). Could be an easy follow up.

@kianenigma
Copy link
Contributor

And, if we had changelogs, this def. needs to go into one as I think it breaks many downstream projects.

@bkchr
Copy link
Member Author

bkchr commented Feb 25, 2021

  • I couldn't find this in the wasm-builder: can we have a test to compare the wasm size when the feature is on or off?

For Kusama the difference is 700 bytes :D So, not that much xD

  • As recommended elsewhere, I think can autogenerate the const LOG_TARGET: ... for all pallets in the macro, instead of assuming that they all prefix with runtime. We can also generate one helper macro for logging with LOG_TARGET (what I have done in staking). Could be an easy follow up.

Yeah, my plan ;)

@bkchr bkchr merged commit dd29596 into master Mar 1, 2021
@bkchr bkchr deleted the bkchr-runtime-logger branch March 1, 2021 14:29
HCastano added a commit to paritytech/parity-bridges-common that referenced this pull request Mar 5, 2021
HCastano added a commit to paritytech/parity-bridges-common that referenced this pull request Mar 8, 2021
* Bump Substrate to version used by Polkadot (`5f056830`)

* Use `log` crate for runtime logging

See paritytech/substrate#8128 for more info.

* Stop using return value from `execute_block`

* Update test weight
brenzi pushed a commit to encointer/pallets that referenced this pull request Mar 17, 2021
@athei
Copy link
Member

athei commented Apr 14, 2021

Are the released runtimes compiled with disable-logging enabled? I am asking because this feature does not seem to be the default and in the release notes is no command line which was used to build the runtime.

@bkchr
Copy link
Member Author

bkchr commented Apr 14, 2021

They are disabled in the Polkadot/Kusama runtimes

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
A0-please_review Pull request needs code review. C1-low PR touches the given topic and has a low impact on builders.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Prefix All Runtime Logs with runtime:: RuntimeLogger fix
5 participants