refactor: logging improvements - all components should receive a logger component

[SgtPooki]

We discussed in https://pl-strflt.notion.site/Mob-Coding-session-2f0cdd202cdf4b6faec03bd87ca15703?pvs=4 how having a logger component that includes the last 5 characters of the peerId could be incredibly useful when running multiple nodes locally

One way we discussed for accomplishing this is to pass a logger component to all components similar to how other components reference each other.

Tasks

Beta Give feedback

1. Prefix debug messages per node with peerID #378
   help wanted kind/discussion need/analysis +3
2. feat: Add new logging options to the components #2207
   dependencies dx +2

[achingbrain]

Developer ergonomics should be considered.

Given the logger libp2p:yamux you can have:

libp2p:yamux hello
libp2p:yamux:error oh no an error
libp2p:yamux:trace really detailed trace log

Logging is disabled by default:

$ libp2p
* no output *

Even when logging is enabled trace logging is still disabled by default:

$ DEBUG=libp2p:* libp2p
libp2p:yamux hello
libp2p:yamux:error oh no an error
* no trace logging*

Turning on trace logging:

$ DEBUG=libp2p:*,*:trace libp2p
libp2p:yamux hello
libp2p:yamux:error oh no an error
libp2p:yamux:trace really detailed trace log

Prefixing with the PeerId will result in:

123Foo:libp2p:yamux hello
123Foo:libp2p:yamux:error oh no an error
123Foo:libp2p:yamux:trace really detailed trace log

Turning on logging might then be like:

$ DEBUG=*:libp2p:* libp2p
123Foo:libp2p:yamux hello
123Foo:libp2p:yamux:error oh no an error

Turning on trace logging is the same as before:

$ DEBUG=*:libp2p:*,*:trace libp2p
123Foo:libp2p:yamux hello
123Foo:libp2p:yamux:error oh no an error
123Foo:libp2p:yamux:trace really detailed trace log

[maschad]

Developer ergonomics should be considered.

I agree but are these examples to suggest that it would be too noisy? Because the current alternative to this is to have the peerID appended such as:

$ DEBUG=*:libp2p:*,*:trace libp2p
libp2p:yamux hello by peer 123Foo3252352QwmsaIksFN...
libp2p:yamux:error oh no an error by peer 123Foo3252352QwmsaIksFN...
libp2p:yamux:trace really detailed trace log by peer  123Foo3252352QwmsaIksFN...

I think having the characters prefixed is a good compromise, especially since the namespaces are distinguished by colour anyway.

[SgtPooki]

I feel like the exact text in #2105 (comment) needs to be moved to docs!

[SgtPooki]

If it's in the format Alex mentions above, it should be filterable (DX expectation), but it wouldn't be, as far as I know.

Can we facilitate a user adding that functionality (prefix logs with peerIds) without defaulting to it?

I don't think this is an everyday use case, but enabling support would help debugging.

How do other networking tools handle an aggregate log with different peer sources? (I should look into wireshark or other examples.)

[achingbrain]

It's more of a design decision conversation, I don't think we're going to refer back to this or direct new users to read it.

the current alternative to this is to have the peerID appended such as:

$ DEBUG=:libp2p:,*:trace libp2p
libp2p:yamux hello by peer 123Foo3252352QwmsaIksFN...

I don't think this is something we'd consider.

One problem I see with:

123Foo:libp2p:yamux hello

is that all PeerIds are prefixed with the same few characters - Qm (RSA), 123DKoo (Ed25519) or 16Uiu2HAm (secp256k1). Personally when scanning I only look at the last few characters though the first few are also useful for knowing what type of key you are looking at.

Given the following range of peer IDs you might want the first two characters + the last, I don't know, four?

RSA       PeerId(QmUdacVbY7Bg1MBS2Qp2WerP5kFfBm4iksPEBn6UqBYkJQ)
RSA       PeerId(QmZxWvnEyteab8EefRVG6C27iYuFbj2bfpdjEgwsbcTXQV)
RSA       PeerId(QmQP5kpgZWLGtgU6SUj5gi7AvoT93J5MLaAZbMh9kj71rb)
RSA       PeerId(QmQMdugH1XDzN3aqwSAysLqdqu8UV1wDmKLJGUitHVk3fn)
Ed25519   PeerId(12D3KooWNwe1kSaDHfjwtPawD5zuyW6hbm2e6JxmPXYZxFvo8krC)
Ed25519   PeerId(12D3KooWKj37jzxzj4AzUjKPX7VeKgiBp7EGQpwpoFAHKUKABiM3)
Ed25519   PeerId(12D3KooWNYL5FQF6MeXy9XMGBbNL6AbNBQ3Jg9e75yiC1mKXfe1V)
Ed25519   PeerId(12D3KooWGr2vWKA2zE6XWPkt2HEL9GeD24imiMpL8xT1khhohAJ9)
secp256k1 PeerId(16Uiu2HAm5B8HoEjWw2GXhriaC3usLqfqb3hmDaxwFCPpyMNMfr7o)
secp256k1 PeerId(16Uiu2HAmSLmM6cHPWUmem2Lm2p42iT1sQeo7y8EKaaCBj7udhASw)
secp256k1 PeerId(16Uiu2HAmGEPZzrTQvmHSamgPVSp8fV4Tiozqdj5qVDwrcuaEXfzk)
secp256k1 PeerId(16Uiu2HAm3bRpT25V552WGdkEcLhFBL6asDYYhktzR7SmdrFDGUqq)

QmYkJQ:libp2p:yamux hello
QmTXQV:libp2p:yamux hello
Qm71rb:libp2p:yamux hello
Qmk3fn:libp2p:yamux hello
128krC:libp2p:yamux hello
12BiM3:libp2p:yamux hello
12fe1V:libp2p:yamux hello
12hAJ9:libp2p:yamux hello
16fr7o:libp2p:yamux hello
16hASw:libp2p:yamux hello
16Xfzk:libp2p:yamux hello
16GUqq:libp2p:yamux hello

Or with a divider (not : as we use that for component hierarchies in the logger name) to make it clear we've omitted some characters?

Qm..YkJQ:libp2p:yamux hello
Qm..TXQV:libp2p:yamux hello
Qm..71rb:libp2p:yamux hello
Qm..k3fn:libp2p:yamux hello
12..8krC:libp2p:yamux hello
12..BiM3:libp2p:yamux hello
12..fe1V:libp2p:yamux hello
12..hAJ9:libp2p:yamux hello
16..fr7o:libp2p:yamux hello
16..hASw:libp2p:yamux hello
16..Xfzk:libp2p:yamux hello
16..GUqq:libp2p:yamux hello

[maschad]

Or with a divider (not : as we use that for component hierarchies in the logger name) to make it clear we've omitted some characters?

Qm..YkJQ:libp2p:yamux hello

I think this is the best suggestion.

I am going to be a bit pedantic and suggest we use ... since an ellipsis is usually represented with three periods

I also think using the first 3 and last 4 characters is the most viable right now, I say first 3 as it's a bit more obvious to distinguish between Ed25519 and secp256k1 peer ids.

[achingbrain]

Well if we're going to be pedantic we should use the … unicode symbol 😛

[maschad]

Great idea!!

[maschad]

Closed by #2228