basic-authorship: debug level is now less spammy

[michalkucharczyk]

The debug level in sc-basic-authorship is now less spammy. Previously it was outputing logs per individual transactions. It was quite hard to follow the logs (and also generates unneeded traffic in grafana).

Now debug level only show some internal details, without spamming output with per-transaction logs. They were moved to trace level.

I also added the EndProposingReason to the summary INFO message. This allows us to know what was the block limit (which is very useful for debugging).

Example:

🎁 Prepared block for proposing at 64 (1186 ms) hash: 0x4b5386c13c507d0dbab319ac054cc1bcfa08311e184452221ad07f12ecc6091c; parent_hash: 0x157c…ca5e; end: HitBlockWeightLimit; extrinsics_count: 7032; 

[michalkucharczyk]

/cmd prdoc --bump major --audience node_dev

[bkchr]

Suggested change

	"🎁 Prepared block for proposing at {} ({} ms) hash: {:?}; parent_hash: {}; end: {:?}; extrinsics_count: {};",
	block.header().number(),
	block_took.as_millis(),
	<Block as BlockT>::Hash::from(block.header().hash()),
	block.header().parent_hash(),
	end_reason,
	"🎁 Prepared block for proposing at {} ({} ms) hash: {:?}; parent_hash: {}; extrinsics_count: {};",
	block.header().number(),
	block_took.as_millis(),
	<Block as BlockT>::Hash::from(block.header().hash()),
	block.header().parent_hash(),

No need to log this in info.

[michalkucharczyk]

I need it here, this is why I added it. I need to know why block builder is hitting limits. And we may have it "for free" in this line.

I am now confused, it is OK to merge it with end reason or not?

[bkchr]

Why do you need it there? You could just enable trace logging.

[bkchr]

Also we have metrics for this.

[skunert]

I think its useful to have, with tracing it will spam all tx again.

[michalkucharczyk]

I don't want to enable trace, because it is way too spammy. With 7k txs in block it may affect the block time building. And for sure it does not help with collecting logs in grafana/loki - it sometimes breaks with too many logs.

I can add another "if branch" here for debug level, but I think it will be more confusing when reasoning about what to enable.

[bkchr]

Adding this because you want to debug one network doesn't make that much sense IMO. Then print the end reason in debug. For normal operators this is not that useful.

[michalkucharczyk]

It is not one network, instead of having important info in log I always need to restart the node whiat is a cost (time). having this log allows very quick assessment of what is happening in block builder.

and logs are not only for operator. after all why does operator need this hash?

I would not propose it if I could live w/o this. And finally @skunert says he finds it useful too.