Skip to content
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

refactor: use tracing's structured logging #4174

Draft
wants to merge 6 commits into
base: main
Choose a base branch
from

Conversation

aatifsyed
Copy link
Contributor

#4143

Semi-automated with https://github.com/aatifsyed/synsert/blob/5f7d39c1ff1ae47d2b028b045378197036a71fa1/examples/tracing.rs

Change checklist

  • I have performed a self-review of my own code,
  • I have made corresponding changes to the documentation,
  • I have added tests that prove my fix is effective or that my feature works (if possible),
  • I have made sure the CHANGELOG is up-to-date. All user-facing changes should be reflected in this document.

@aatifsyed aatifsyed requested a review from a team as a code owner April 10, 2024 09:20
@aatifsyed aatifsyed requested review from hanabi1224 and elmattic and removed request for a team April 10, 2024 09:20
@@ -271,7 +271,7 @@ where
match network.hello_request(peer_id, request).await {
Ok(response) => response,
Err(e) => {
debug!("Hello request failed: {}", e);
debug!(error = %e, "hello request failed");
Copy link
Contributor

Choose a reason for hiding this comment

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

Should we use ? here to log the inner error since e is of anyhow::Error type?

Err(error) => {
    debug!(?error, "hello request failed");
    return;
}

"header_len: {header_len}, msg.bls_msg_includes.len(): {}, msg.secp_msg_includes.len(): {}",
msg.bls_msg_includes.len(),
msg.secp_msg_includes.len()
%header_len, msg.bls_msg_includes.len = %msg.bls_msg_includes.len(), msg.secp_msg_includes.len = %msg.secp_msg_includes.len()
Copy link
Contributor

Choose a reason for hiding this comment

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

nit: kinda nice, but confusing. I would never be able to deduce what msg.bls_msg_includes.len = %msg.bls_msg_includes.len() does without the diff.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I think this just comes down to knowing tracing::event's API, like knowing format! or printf 🤷

Copy link
Contributor

@ruseinov ruseinov Apr 11, 2024

Choose a reason for hiding this comment

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

Perhaps it would be easier to understand if you did something like bls_msg_includes_len = .... It's not blocking, but this is not reading well nor should reading the code require one to know tracing API specifics. format! and printf are intuitive, while this just looks like you are assigning a value to a property of an object. The confusion here comes from the fact that msg variable is actually defined in this scope and it does have the bls_msg_includes property.

Copy link
Member

Choose a reason for hiding this comment

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

While I agree that the tracing API is not particularly obvious, it seems a standard in the Rust ecosystem https://blessed.rs/crates#section-common-subsection-logging. As such, we should learn how to utilize it and get familiar with it. I recommend tinkering a bit to get a hold of it, what results are produced etc. We can't stay in the printf world forever. 🦖

@aatifsyed aatifsyed changed the title refactor: use tracing's structured logging (part 1) refactor: use tracing's structured logging Apr 10, 2024
@aatifsyed
Copy link
Contributor Author

$ git diff main | cat | rg '@@' | wc -l
182

So many call sites

@LesnyRumcajs
Copy link
Member

I'll look into tracing docs and get back to you here.

@aatifsyed aatifsyed marked this pull request as draft April 11, 2024 10:00
} else {
info!("Weight tie left unbroken, default to {}", other.key());
info!(default = %other.key() , "weight tie defaulted");
Copy link
Member

Choose a reason for hiding this comment

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

Let's not use the default, I believe it's a keyword to be used in the future.

@@ -386,7 +381,7 @@ where
{
Ok(tipset) => tipset,
Err(why) => {
debug!("Querying full tipset failed: {}", why);
debug!(reason = %why, "querying full tipset failed");
Copy link
Member

Choose a reason for hiding this comment

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

Copy link
Member

@LesnyRumcajs LesnyRumcajs left a comment

Choose a reason for hiding this comment

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

What do we do with the errors marked as % - Display? Shouldn't they all be ? to include the the entire trace, not only the latest context?

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.

None yet

4 participants