Reverse PendingTx chain id args and remove its Display impl

[seanchen1991]

Closes: #1488

Description

Reverses the order of the chain_id and counterparty_chain_id arguments when displaying a PendingTx. PendingTx's Display impl was also removed as per the recent log reformatting work.

I'm not sure I went about this in the best way though. Is there a better way to handle constructing the relay path? Also, why is that for PendingTx's, the order of the chain IDs need to be reversed in the first place? Is this actually correct?

---

PR author checklist:

• Added changelog entry, using unclog.
• Added tests: integration (for Hermes) or unit/mock tests (for modules).
• Linked to GitHub issue.
• Updated code comments and documentation (e.g., docs/).

Reviewer checklist:

• Reviewed Files changed in the GitHub PR explorer.
• Manually tested (in case integration/unit/mock tests are absent).

[mzabaluev]

This is better, but I'd rather rework all these [{}] constructs into span-wise KVs whenever the opportunity arises, as was partially done in #1491.

[seanchen1991]

rework all these [{}] constructs into span-wise KVs

I'm not entirely clear what this means. What will the resulting log lines look like?

[mzabaluev]

I'm not entirely clear what this means. What will the resulting log lines look like?

That will depend on the tracing backend. One of the benefits of using KVs is that they are converted into similar structural fields in logging backends supporting this (e.g. journald). In the terminal output subscriber that is used by Hermes now, a tracing event in a span created with span!(tracing::Level::ERROR, "some_op", chain="foo", connection="bar") will look something like this (with some bold and italic font styling added on an ANSI terminal):

some_op{chain=foo connection=bar}: here comes the event message

So, the information will still be flattened in this simple backend, but it will be easy to decipher and search for (if a bit more verbose).

[romac]

Let's perhaps add a span to this method, as @mzabaluev suggests:

    let span = trace_span!(
             "inserting new pending txs",
             chain = %relay_path.chain_id()
             counterparty_chain = %relay_path.counterparty_chain_id,
             port = %relay_path.port_id,
             channel = %relay_path.channel_id,
    );

    let _guard = span.enter();

[mzabaluev]

All these could rather be in KV pairs to potentially aid log filtering.

[romac]

I guess they could but they're also useful when combing through the logs "by hand". But perhaps we can have both?

[seanchen1991]

But perhaps we can have both?

I'm not sure what's the best way to go about achieving this.

[romac]

Let's leave it like this for now and see if we can improve things in another PR. Nevermind, let's do this: https://github.com/informalsystems/ibc-rs/pull/1843/files/31d0316899456fe9de31fe4991fb10b98b8b5707#r803620700

[mzabaluev]

Looks good inasmuch as it resolves the representation problem in logs.

[seanchen1991]

Incorporating the changes suggested by @mzabaluev and @romac produces pending transaction logs structured like this:

2022-02-10T16:57:04.094471Z  INFO ThreadId(27) packet_cmd{src_chain=network2 src_port=transfer src_channel=channel-0 dst_chain=network1}:relay{odata=kFyYp1_fHH ->Destination @0-111380; len=1}: success                                                                     
2022-02-10T16:57:04.176579Z TRACE ThreadId(27) packet_cmd{src_chain=network2 src_port=transfer src_channel=channel-0 dst_chain=network1}:processing pending tx{chain=network1 counterparty_chain=network2 port=transfer channel=channel-0}: trying to confirm TxHashes: count=1; 56CA346F921BBD61A96AED34A4D281DFA4B8388E095B3CE9CA26839C2944C364 

compared to the previous style:

2022-02-01T16:58:45.701278Z  INFO ThreadId(27) [network2:transfer/channel-0 -> network1] success
2022-02-01T16:58:45.701300Z TRACE ThreadId(27) [network2:transfer/channel-0 -> network1] trying to confirm TxHashes: count=1; 122F297830AAE108E14695763F054C7106B094828C259140874D8C01C734EF43 

[romac]

@adizere What do you think?

[adizere]

I think the new style is better! Will try to give a more thorough review but briefly I think we’re good to go!

…

On Fri, 11 Feb 2022 at 15:35, Romain Ruetschi ***@***.***> wrote: @adizere <https://github.com/adizere> What do you think? — Reply to this email directly, view it on GitHub <#1843 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AANM6SX237RVKM4N2M3CI53U2UNERANCNFSM5NSMULVQ> . Triage notifications on the go with GitHub Mobile for iOS <https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675> or Android <https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub>. You are receiving this because you were mentioned.Message ID: ***@***.***>

[adizere]

LGTM, neat work here! Glad we're slowly getting rid of fmt::Displays.

[adizere]

I went ahead and merged, though I overlooked theres was no changelog entry. Cc @seanchen1991 to remember the changelogs in future PRs.