8

After upgrading to Polkadot v0.9.23 from v0.9.16, I am missing the default "start up" message (WS/RPC connections, hardware, para-id etc, see below) when initiating the node client, both for the parachain as well as the standalone clients.

Exemplary command

cargo run --release --bin my-runtime -- --dev --tmp --validator  --ws-port=9944 --port 30044 --alice --ws-external --rpc-external --rpc-cors all --rpc-methods=unsafe --unsafe-rpc-external

First, I thought I would need to add something to my command, e.g. enabling a non-default log-level for sc-service or similar pallets. Unfortunately, that did not succeed. However, my default command (without any non-default logs) produces the missing log message for all Substrate/Polkadot/Cumulus repositories.

I triple-checked the differences between my client and the templates and could not find any unexpected divergences. I was hoping that someone here had a similar issue or could provide me with any kind of hint. Thanks in advance!

Expectation: Heres an exemplary message from the Polkadot binary when executing the above command with bin=polkadot in the Polkadot repository:

     Running `target/release/polkadot --dev --tmp --validator --ws-port=9944 --port 30033 --alice --ws-external --rpc-external --rpc-cors all --rpc-methods=unsafe --unsafe-rpc-external
2022-06-09 14:00:05 πŸ‘Ά Creating empty BABE epoch changes on what appears to be first startup.    
2022-06-09 14:00:05 🏷  Local node identity is: 12D3KooWLtiot9DJov5WMKRbiTxRY9r5CvZCiePsAUmRJXFnnmis    
2022-06-09 14:00:05 πŸ’» Operating system: linux    
2022-06-09 14:00:05 πŸ’» CPU architecture: x86_64    
2022-06-09 14:00:05 πŸ’» Target environment: gnu    
2022-06-09 14:00:05 πŸ’» CPU: 12th Gen Intel(R) Core(TM) i9-12900K    
2022-06-09 14:00:05 πŸ’» CPU cores: 16    
2022-06-09 14:00:05 πŸ’» Memory: 128628MB    
2022-06-09 14:00:05 πŸ’» Kernel: 5.13.0-35-generic    
2022-06-09 14:00:05 πŸ’» Linux distribution: Ubuntu 20.04.4 LTS    
2022-06-09 14:00:05 πŸ’» Virtual machine: no    
2022-06-09 14:00:05 πŸ“¦ Highest known block at #0    
2022-06-09 14:00:05 〽️ Prometheus exporter started at 127.0.0.1:9615    
2022-06-09 14:00:05 Running JSON-RPC HTTP server: addr=0.0.0.0:9933, allowed origins=None    
2022-06-09 14:00:05 Running JSON-RPC WS server: addr=0.0.0.0:40044, allowed origins=None    
2022-06-09 14:00:05 🏁 CPU score: 1375MB/s    
2022-06-09 14:00:05 🏁 Memory score: 14784MB/s    
2022-06-09 14:00:05 🏁 Disk score (seq. writes): 2515MB/s    
2022-06-09 14:00:05 🏁 Disk score (rand. writes): 968MB/s    
2022-06-09 14:00:05 πŸ‘Ά Starting BABE Authorship worker    
2022-06-09 14:00:07 πŸ™Œ Starting consensus session on top of parent 0xd2d8af4849031dacb13979ea8ad0d84ce97e5395df6bc6df6bbea0791bc16a0d    
2022-06-09 14:00:07 ParentBlockRandomness did not provide entropy    
2022-06-09 14:00:07 ParentBlockRandomness did not provide entropy    
2022-06-09 14:00:07 ParentBlockRandomness did not provide entropy   

Reality

     Running `target/release/helloworld --dev --tmp --validator --ws-port=9944 --port 30033 --alice --ws-external --rpc-external --rpc-cors all --rpc-methods=unsafe --unsafe-rpc-external`
2022-06-09 14:55:20 〽️ Prometheus exporter started at 127.0.0.1:9615    
2022-06-09 14:55:24 πŸ™Œ Starting consensus session on top of parent 0x9a91c757c54d50b9717263ce02540704ff89b609c1d92905cb697b4f3790f012    
2022-06-09 14:55:24 🎁 Prepared block for proposing at 1 (1 ms) [hash: 0xac75a665ebcfca9ace85eb92ae36dc4fa3a4643903f5afc89888c11ccc8059d7; parent_hash: 0x9a91…f012; extrinsics (1): [0x64eb…f8b3]]    
2022-06-09 14:55:24 πŸ”– Pre-sealed block for proposal at 1. Hash now 0x9c716b73f6767e192ee642108f51225d7fa042cad0fdb0291027c301a973c716, previously 0xac75a665ebcfca9ace85eb92ae36dc4fa3a4643903f5afc89888c11ccc8059d7.    
2022-06-09 14:55:24 ✨ Imported #1 (0x9c71…c716)  
3
  • Maybe you can check if the log level has changed between v0.9.16 and v0.9.23. And try to pass env arguments for log level, set all to trace, check if the log occurs. Jun 10, 2022 at 9:03
  • I cannot reproduce this with the latest polkadot releas binary from here. What did you modify? If you use the provided binary, you should see the old message. Jun 10, 2022 at 12:41
  • For the Polkadot, Substrate and Cumulus repositories, everything is fine. However in my own repository which holds a parachain and relay runtime each, both clients don't print.
    – 0x5hmoo
    Jun 11, 2022 at 7:02

3 Answers 3

5

I had the same problem after upgrading my custom node code to Polkadot 0.9.22. After checking the differences between my code and the node template, I found no relevant difference. I then had a look at Cargo.lock and that's where the problem was.

To make the "startup messages" show again, I had to fix the dependency of tracing-core. The dependency section of the node (not the one of the runtime) looks like this:

[dependencies]
...
tracing-core = "=0.1.26"
...

For the record, the version 0.1.27 (which causes the problem) is out since 8 days (June 15th 2022).

Note: an issue and a PR were submitted.

1

In my case, this issue was introduced by some sub-dependency. Seems like one should still not upgrade blindly using cargo update and rather just update a couple of dependencies across the Polkadot, Substrate and Cumulus repositories.

After resetting my Cargo.lock to the post-upgrade state and updating randomly selected Dotsama pallets, the logs were back!

cargo update -p sp-io -p cumulus-client-cli -p cumulus-relay-chain-interface -p polkadot-service -p polkadot-parachain
0

The log source in substrate still exists at this time, and I believe this PR was the last modification to this logging. If I understand correctly, this comment indicates there are not run for --dev mode, as it drastically slows down the "boot" time for nodes when you are trying things out.

At this time I don't know how to override the --dev flag to run these. I will update when I do here.

Note also --dev no implies/includes --tmp, you don't need both flags.

3
  • Thanks for the reply. I did not know this implication of --dev yet ☺️ However, the remainder of your statement cant be true for 0.9.23 or below as in the example above, I ran the Polkadot binary with --dev and still received the desired output. Or did I misunderstand you?
    – 0x5hmoo
    Jun 10, 2022 at 12:01
  • Moreover, I started a node of my runtime for a live network (so non-dev) and it did not print the startup message :(
    – 0x5hmoo
    Jun 10, 2022 at 12:20
  • Btw, develop nodes still print the logs per default. However, you can provide a flag to omit them.
    – 0x5hmoo
    Jun 15, 2022 at 19:08

Your Answer

By clicking β€œPost Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.