fix(log): Stop logging peer IP addresses, to protect user privacy

[teor2345]

Motivation

We don't want to log peer IP addresses, because lists of peers are privacy and security sensitive.

Close #3320.

Complex Code or Requirements

This PR modifies some canonical IP address code, but these changes shouldn't impact network compatibility. (If they do, we'll see it in the integration tests.)

Solution

New types and functions:

• Add a PeerSocketAddr type which hides its IP address, but shows the port
• Make converting into PeerSocketAddr easier
• Add a canonical_peer_addr() function

Privacy fixes:

• Manually replace SocketAddr with PeerSocketAddr in zebra-network
• Stop logging peer addresses in RPC code

Related fixes:

• Update outdated IPv4-mapped IPv6 address code
• Make addresses canonical when deserializing

Testing

See my manual log check below in the comments.

Review

This is a large change, so we might not want to schedule any other zebra-network work until it's merged. (@mpguerra I've checked the existing zebra-network tickets in this sprint and they seem fine.)

We might also want to make it a high priority for review, I'll leave that up to Pili.

Reviewer Checklist

• Will the PR name make sense to users?
  • Does it need extra CHANGELOG info? (new features, breaking changes, large changes)
• Are the PR labels correct?
• Does the code do what the ticket and PR says?
  • Does it change concurrent code, unsafe code, or consensus rules?
• How do you know it works? Does it have tests?

Follow Up Work

Check for IP addresses of peers that are logged in other ways: going forward this should be considered a bug.

[teor2345]

I manually ran zebrad start, and I got this output:

...
2023-05-10T23:44:31.201494Z  INFO {zebrad="513fb74" net="Test"}:add_initial_peers: zebra_network::config: resolved seed peer IP addresses seed="192.168.215.106:38233" remote_ip_count=1
2023-05-10T23:44:31.201746Z  INFO {zebrad="513fb74" net="Test"}:add_initial_peers: zebra_network::config: resolved seed peer IP addresses seed="testnet.is.yolo.money:18233" remote_ip_count=1
2023-05-10T23:44:31.201782Z  INFO {zebrad="513fb74" net="Test"}:add_initial_peers: zebra_network::config: resolved seed peer IP addresses seed="dnsseed.testnet.z.cash:18233" remote_ip_count=2
2023-05-10T23:44:31.201789Z  INFO {zebrad="513fb74" net="Test"}:add_initial_peers: zebra_network::config: resolved seed peer IP addresses seed="testnet.seeder.zfnd.org:18233" remote_ip_count=3
2023-05-10T23:44:31.201804Z  INFO {zebrad="513fb74" net="Test"}:add_initial_peers: zebra_network::peer_set::initialize: connecting to initial peer set initial_peer_count=10 initial_peers={v4redacted:5823
3, v4redacted:18233, v4redacted:18233, v4redacted:18233, v4redacted:58233, v4redacted:58233, v4redacted:18233, v4redacted:18233, v4redacted:38233, v4redacted:38233}
2023-05-10T23:44:31.651242Z  INFO {zebrad="513fb74" net="Test"}:add_initial_peers: zebra_network::peer_set::initialize: an initial peer connection failed successes=1 errors=1 addr=v4redacted:18233 e=Connection refused (os error 111)

So this change seems to be working as expected for initial peers. I haven't seen any ongoing peer logs yet.

Configured seed peer DNS and IP addresses are ok to log, because they are stored on the disk already in zebrad.toml. But we don't log the results of the DNS query any more.

[teor2345]

I also checked that ongoing peer logs don't show IP addresses any more, here are some debug logs:

2023-05-10T23:50:41.982150Z DEBUG {zebrad="513fb74" net="Test"}:{peer=Out("v4redacted:18233")}: zebra_network::peer::connection: finished receiving peer response to Zebra request response=Block { height: 55372, hash: 00131228c15343594ad4a539f132c846961718f7d5231be4cdae1f271cac941f }
2023-05-10T23:50:41.982174Z DEBUG {zebrad="513fb74" net="Test"}:sync:try_to_sync:extend_tips: zebra_network::peer::connection: sending request from Zebra to peer state=AwaitingRequest request=BlocksByHash(1)
2023-05-10T23:50:41.982250Z DEBUG {zebrad="513fb74" net="Test"}:sync:try_to_sync:extend_tips: zebra_network::peer::connection: sending request from Zebra to peer state=AwaitingRequest request=BlocksByHash(1)
2023-05-10T23:50:42.076474Z DEBUG {zebrad="513fb74" net="Test"}:sync:try_to_sync:extend_tips: zebra_network::peer::connection: received peer response to Zebra request handler=BlocksByHash { pending_hashes: 1, blocks: 0 } msg=block { height: 55373, hash: 00129132a7cea26d690ae01b0d14c4a65ef9fe381d3fb87ce89e85fb23168d41 }
2023-05-10T23:50:42.076511Z DEBUG {zebrad="513fb74" net="Test"}:{peer=Out("v4redacted:30835")}: zebra_network::peer::connection: finished receiving peer response to Zebra request response=Block { height: 55373, hash: 00129132a7cea26d690ae01b0d14c4a65ef9fe381d3fb87ce89e85fb23168d41 }
2023-05-10T23:50:42.076540Z DEBUG {zebrad="513fb74" net="Test"}:sync:try_to_sync:extend_tips: zebra_network::peer::connection: sending request from Zebra to peer state=AwaitingRequest request=BlocksByHash(1)
2023-05-10T23:50:42.076713Z DEBUG {zebrad="513fb74" net="Test"}:sync:try_to_sync:extend_tips: zebra_network::peer::connection: sending request from Zebra to peer state=AwaitingRequest request=BlocksByHash(1)
2023-05-10T23:50:42.108654Z DEBUG {zebrad="513fb74" net="Test"}:sync:try_to_sync:extend_tips: zebra_network::peer::connection: received peer response to Zebra request handler=BlocksByHash { pending_hashes: 1, blocks: 0 } msg=block { height: 55373, hash: 00129132a7cea26d690ae01b0d14c4a65ef9fe381d3fb87ce89e85fb23168d41 }
2023-05-10T23:50:42.108699Z DEBUG {zebrad="513fb74" net="Test"}:{peer=Out("v4redacted:18233")}:msg_as_req{msg="block"}: zebra_network::peer::connection: received inbound peer message state=AwaitingResponse(BlocksByHash { pending_hashes: 1, blocks: 0 }) msg=block { height: 55373, hash: 00129132a7cea26d690ae01b0d14c4a65ef9fe381d3fb87ce89e85fb23168d41 }
2023-05-10T23:50:42.108721Z DEBUG {zebrad="513fb74" net="Test"}:{peer=Out("v4redacted:18233")}:msg_as_req{msg="block"}: zebra_network::peer::connection: got block message unsolicited or from canceled request msg=block { height: 55373, hash: 00129132a7cea26d690ae01b0d14c4a65ef9fe381d3fb87ce89e85fb23168d41 }
2023-05-10T23:50:42.108739Z DEBUG {zebrad="513fb74" net="Test"}:{peer=Out("v4redacted:18233")}: zebra_network::peer::connection: ignoring peer message: not a response or a request unused_msg=block { height: 55373, hash: 00129132a7cea26d690ae01b0d14c4a65ef9fe381d3fb87ce89e85fb23168d41 } self.state=AwaitingResponse(BlocksByHash { pending_hashes: 1, blocks: 0 })
2023-05-10T23:50:42.143668Z DEBUG {zebrad="513fb74" net="Test"}:sync:try_to_sync:extend_tips: zebra_network::peer::connection: received peer response to Zebra request handler=BlocksByHash { pending_hashes: 1, blocks: 0 } msg=block { height: 55374, hash: 00a0bb9c9e5d9f91198f8c8cafe189cd93a5c29a2de436d365a240336cc5bd40 }
2023-05-10T23:50:42.143700Z DEBUG {zebrad="513fb74" net="Test"}:{peer=Out("v4redacted:18233")}: zebra_network::peer::connection: finished receiving peer response to Zebra request response=Block { height: 55374, hash: 00a0bb9c9e5d9f91198f8c8cafe189cd93a5c29a2de436d365a240336cc5bd40 }

[teor2345]

The address redactions also work on peer errors and block gossips:

2023-05-11T00:47:37.447952Z  INFO {zebrad="513fb74" net="Main"}:{peer=Out("v4redacted:8233")}:msg_as_req{msg="inv"}:inbound:download_and_verify{hash=0000000000451cab4c0aeeeec094e9a0dda9a33e1adfe83e322a54a9fbf04ab6}: zebrad::components::inbound::downloads: downloaded and verified gossiped block height=Height(2081747)
2023-05-11T00:47:39.631909Z  INFO {zebrad="513fb74" net="Test"}:crawl_and_dial{new_peer_interval=61s}: zebra_network::peer_set::candidate_set: timeout waiting for peer service readiness or peer responses
2023-05-11T00:48:35.634620Z  INFO {zebrad="513fb74" net="Main"}:{peer=Out("v4redacted:8233")}:msg_as_req{msg="inv"}: zebra_network::peer::connection: inbound service is overloaded, closing connection remote_user_agent="/MagicBean:5.4.0/" negotiated_version=Version(170100) peer="v4redacted:8233" last_peer_state=Some("AwaitingRequest::In::Req::AdvertiseTransactionIds") remote_height=Height(2081735) cached_addrs=1 connection_state=AwaitingRequest
2023-05-11T00:48:35.634604Z  INFO {zebrad="513fb74" net="Main"}:{peer=Out("v4redacted:2838")}:msg_as_req{msg="inv"}: zebra_network::peer::connection: inbound service is overloaded, closing connection remote_user_agent="/MagicBean:5.4.1/" negotiated_version=Version(170100) peer="v4redacted:2838" last_peer_state=Some("AwaitingRequest::In::Req::AdvertiseTransactionIds") remote_height=Height(2081724) cached_addrs=1 connection_state=AwaitingRequest

[teor2345]

@oxarbitrage I'm happy to do a video review on this PR if that would help. But it's a lower priority than the release and security fixes.

[codecov]

Codecov Report

Merging #6662 (f2228af) into main (0190882) will increase coverage by 0.14%.
The diff coverage is 89.74%.

Additional details and impacted files

@@            Coverage Diff             @@
##             main    #6662      +/-   ##
==========================================
+ Coverage   77.87%   78.02%   +0.14%     
==========================================
  Files         309      310       +1     
  Lines       40665    40687      +22     
==========================================
+ Hits        31669    31745      +76     
+ Misses       8996     8942      -54     

[teor2345]

@Mergifyio update

[mergify]

update

✅ Branch has been successfully updated

[teor2345]

Failed due to #6667

[oxarbitrage]

We went through this PR on a video call. The number of changes are huge but tedious but we have good test coverage for this. The number of file changed is big too so i think we need to merge fast before starting to conflict.