conn_race.md

Pruned logs

Carol's log

# carol restarts
2022-10-17 11:56:31.967 [INF] LTND: Shutdown complete
...
2022-10-17 11:56:33.145 [INF] BTCN: Server listening on 127.0.0.1:8805


# carol attempts to connect to bob
2022-10-17 11:56:33.146 [DBG] SRVR: Attempting persistent connection to channel peer [Bob]@127.0.0.1:8565
2022-10-17 11:56:33.152 [DBG] BTCN: Connected to [Bob]@127.0.0.1:8565 (reqid 2)
2022-10-17 11:56:33.152 [INF] SRVR: Established connection to: [Bob]@127.0.0.1:8565
2022-10-17 11:56:33.152 [INF] SRVR: Finalizing connection to [Bob]@127.0.0.1:8565, inbound=false
2022-10-17 11:56:33.152 [DBG] PRNF: PeerNotifier notifying peer: [Bob] online


# carol receives conn request from bob, and ignores it
2022-10-17 11:56:33.153 [DBG] SRVR: Already have outbound connection for [Bob]@127.0.0.1:8565, ignoring inbound connection from local=127.0.0.1:8805, remote=127.0.0.1:60350
2022-10-17 11:56:33.153 [DBG] PEER: Peer([Bob]): Sending Init to [Bob]@127.0.0.1:8565
2022-10-17 11:56:33.153 [INF] PEER: Peer([Bob]): disconnecting [Bob]@127.0.0.1:8565, reason: unable to start peer: unable to send init msg: write tcp 127.0.0.1:35294->127.0.0.1:8565: write: broken pipe
2022-10-17 11:56:33.153 [DBG] SRVR: Peer [Bob]@127.0.0.1:8565 has been disconnected
2022-10-17 11:56:33.153 [DBG] SRVR: Notifying that peer [Bob]@127.0.0.1:8565 is offline
2022-10-17 11:56:33.153 [DBG] SRVR: removing peer [Bob]@127.0.0.1:8565
2022-10-17 11:56:33.153 [DBG] PRNF: PeerNotifier notifying peer: [Bob] offline


# carol will retry it in 2s
2022-10-17 11:56:33.153 [DBG] SRVR: Scheduling connection re-establishment to persistent peer [Bob] in 2.1s
2022-10-17 11:56:33.153 [DBG] BTCN: Disconnected from [Bob]@127.0.0.1:8565 (reqid 2)

Bob's log

# conn closed due to carol restarts
2022-10-17 11:56:31.865 [INF] PEER: Peer([carol]): unable to read message from peer: EOF
2022-10-17 11:56:31.865 [INF] PEER: Peer([carol]): disconnecting [carol]@127.0.0.1:8805, reason: read handler closed
2022-10-17 11:56:31.966 [DBG] SRVR: Peer [carol]@127.0.0.1:8805 has been disconnected
2022-10-17 11:56:31.966 [INF] HSWC: ChannelLink([ChanPoint: Bob=>carol]): stopping
2022-10-17 11:56:31.966 [INF] HSWC: ChannelLink([ChanPoint: Bob=>carol]): exited
2022-10-17 11:56:31.966 [DBG] SRVR: Notifying that peer [carol]@127.0.0.1:8805 is offline
2022-10-17 11:56:31.966 [DBG] SRVR: removing peer [carol]@127.0.0.1:8805
2022-10-17 11:56:31.966 [DBG] PRNF: PeerNotifier notifying peer: [carol] offline


# bob attempts to connect to carol
2022-10-17 11:56:31.966 [DBG] SRVR: Scheduling connection re-establishment to persistent peer [carol] in 1s
2022-10-17 11:56:32.967 [DBG] SRVR: Attempting to re-establish persistent connection to peer [carol]
2022-10-17 11:56:32.967 [DBG] SRVR: Attempting persistent connection to channel peer [carol]@127.0.0.1:8805
2022-10-17 11:56:32.967 [DBG] BTCN: Attempting to connect to [carol]@127.0.0.1:8805 (reqid 1)
2022-10-17 11:56:32.969 [DBG] BTCN: Connected to [carol]@127.0.0.1:8805 (reqid 1)
2022-10-17 11:56:32.969 [INF] SRVR: Established connection to: [carol]@127.0.0.1:8805
2022-10-17 11:56:32.969 [INF] SRVR: Finalizing connection to [carol]@127.0.0.1:8805, inbound=false
2022-10-17 11:56:32.969 [DBG] PRNF: PeerNotifier notifying peer: [carol] online
2022-10-17 11:56:32.970 [DBG] PEER: Peer([carol]): Sending Init to [carol]@127.0.0.1:8805


# bob receives the conn request from carol, and ignores it.
2022-10-17 11:56:33.152 [DBG] SRVR: Already have outbound connection for [carol]@127.0.0.1:8805, ignoring inbound connection from local=127.0.0.1:8565, remote=127.0.0.1:35294
2022-10-17 11:56:33.153 [INF] PEER: Peer([carol]): disconnecting [carol]@127.0.0.1:8805, reason: unable to start peer: unable to read init msg: read tcp 127.0.0.1:60350->127.0.0.1:8805: read: connection reset by peer
2022-10-17 11:56:33.153 [DBG] SRVR: Peer [carol]@127.0.0.1:8805 has been disconnected
2022-10-17 11:56:33.153 [DBG] SRVR: Notifying that peer [carol]@127.0.0.1:8805 is offline
2022-10-17 11:56:33.153 [DBG] SRVR: removing peer [carol]@127.0.0.1:8805
2022-10-17 11:56:33.153 [DBG] PRNF: PeerNotifier notifying peer: [carol] offline


# bob will retry it in 2s
2022-10-17 11:56:33.153 [DBG] SRVR: Scheduling connection re-establishment to persistent peer [carol] in 2.1s
2022-10-17 11:56:33.153 [DBG] BTCN: Disconnected from [carol]@127.0.0.1:8805 (reqid 1)