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

feat(*): more comprehensive log output #198

Closed
wants to merge 1 commit into from

Conversation

bennofs
Copy link

@bennofs bennofs commented Sep 21, 2018

The log messages for sent/received messages now always include the following info:

  • peer id of sender
  • peer id of receiver
  • message key
  • message type

There was already logging for the individual handlers but it was
inconsistent (for example some log the peer id of self while others do not) and
did not provide full information in all cases (some handlers do not log the key)

The log messages for sent/received messages now always include the following info:

* peer id of sender
* peer id of receiver
* message key
* message type

There was already logging for the individual handlers but it was
inconsistent (for example some log the peer id of self while others do not) and
did not provide full information in all cases (some handlers do not log the key)
@@ -70,6 +71,9 @@ func (dht *IpfsDHT) handleNewMessage(s inet.Stream) {
return
}

// log the received message
log.Event(ctx, "handleNewMessage", mPeer, pmes)
Copy link
Member

Choose a reason for hiding this comment

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

This should probably be a span event, like the others. That is, use log.Start and log.Finish. Really, we may want to break the rest of this function out into a separate function (so we can use defer to end the event).

@@ -108,41 +112,60 @@ func (dht *IpfsDHT) handleNewMessage(s inet.Stream) {
}
}

func tagWithMessage(ctx context.Context, name string, msg *pb.Message) {
log.SetTag(ctx, name+".key", b58.Encode([]byte(msg.GetKey())))
Copy link
Member

Choose a reason for hiding this comment

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

This is going to be a bit expensive. Let's wait for #200, then we can use the loggableKey helper type to format lazily and on-demand.

return nil, err
}
tagWithMessage(ctx, "response", rpmes)
Copy link
Member

Choose a reason for hiding this comment

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

I don't see the benefit of tagging the response and request differently. The key and type should be identical.

Copy link
Author

Choose a reason for hiding this comment

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

The reason for this is the request/response are part of the same span, so if we tag them the same, one will overwrite the other. We could convert this to span events, but that'll be ugly as well since span events only support single k/v (no nesting) AFAIK.

@anacrolix
Copy link
Contributor

I think this will be superceded by #300 and #297. I'm not sure spans are of interest at the moment either. Thanks

@anacrolix anacrolix closed this Mar 14, 2019
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.

3 participants