Problem with local peering? (probably not)

General
1

I’m running both a leader and follower node on the same machine. From what I’ve gathered here and in the Telegram chat, this setup should allow for local peering. My leader node, however, gets a timeout, regardless of whether the follower is already running.

E (20:11:45) nc: Failed outgoing connection to None: Failed to negotiate transport protocol(s): [(/ip4/127.0.0.1/udp/3006/quic-v1: : Handshake with the remote timed out.: Handshake with the remote timed out.: Handshake with the remote timed out.)]

This error is logged in the leader right after “No known peers.”:

D (20:11:28) nockchain: peer_multiaddrs: [/ip4/127.0.0.1/udp/3006/quic-v1]
D (20:11:28) nockchain_bitcoin_sync: Starting bitcoin_watcher_driver with node_type: Leader
D (20:11:28) nockchain_bitcoin_sync: No Bitcoin RPC connection provided, using test genesis
 block
D (20:11:28) nockchain_bitcoin_sync: Creating test genesis block for leader node
I (20:11:28) kernel no longer in init phase, can't do init command
I (20:11:28) candidate block timestamp updated: 0x8000000d36c6faf0
I (20:11:28) libp2p_swarm: local_peer_id=12D3KooWLcggQmprwLYYpB3PjihGEYbGe3GWEA6Ciy94gyM6yi
tn
D (20:11:29) nockchain_bitcoin_sync: test genesis block template sent successfully
I (20:11:29) nockchain_bitcoin_sync: Bitcoin watcher driver initialization complete signal sent
D (20:11:29) nockchain_bitcoin_sync: bitcoin_watcher_driver completed successfully
I (20:11:29) driver_init: driver 'bitcoin_watcher' initialized
I (20:11:45) nc: Failed to bootstrap: No known peers.
E (20:11:45) nc: Failed outgoing connection to None: Failed to negotiate transport protocol(s): [(/ip4/127.0.0.1/udp/3006/quic-v1: : Handshake with the remote timed out.: Handshake with the remote timed out.: Handshake with the remote timed out.)]
I (20:11:45) driver_init: driver 'libp2p' initialized
I (20:11:45) driver_init: all drivers initialized, born poke sent
I (20:11:45) nc: SEvent: Listening on /ip4/127.0.0.1/udp/3005/quic-v1
I (20:11:45) nc: SEvent: Listening on /ip4/*REDACTED*/udp/3005/quic-v1
I (20:11:45) kernel no longer in init phase, can't do init command
D (20:11:45) driver_init: born poke acknowledged
W (20:11:45) behaviour: Failed to trigger bootstrap: No known peers.
E (20:12:00) nc: Failed outgoing connection to None: Failed to negotiate transport protocol(s): [(/ip4/127.0.0.1/udp/3006/quic-v1: : Handshake with the remote timed out.: Handshake with the remote timed out.: Handshake with the remote timed out.)]
I (20:13:48) candidate block timestamp updated: 0x8000000d36c6fb7c
I (20:16:08) candidate block timestamp updated: 0x8000000d36c6fc08
I (20:18:28) candidate block timestamp updated: 0x8000000d36c6fc94
I (20:20:48) candidate block timestamp updated: 0x8000000d36c6fd20

While the follower node is patiently waiting for the genesis block:

I (20:12:52) received btc block hash, waiting to hear nockchain genesis block!
I (20:12:52) libp2p_swarm: local_peer_id=12D3KooWSaRtj4e9b3YqcCAipSnEBm65yJ7sVs1wEhiCRnUiUFwY
D (20:12:52) nockchain_bitcoin_sync: btc-data command for fake genesis block sent successfully
I (20:12:52) nockchain_bitcoin_sync: Bitcoin watcher driver initialization complete signal sent
D (20:12:52) nockchain_bitcoin_sync: bitcoin_watcher_driver completed successfully
I (20:12:52) driver_init: driver 'bitcoin_watcher' initialized
I (20:12:52) kernel is in init phase, can't do non-init command
I (20:13:08) driver_init: driver 'libp2p' initialized
I (20:13:08) driver_init: all drivers initialized, born poke sent
I (20:13:08) nc: Failed to bootstrap: No known peers.
I (20:13:08) Requesting genesis block
I (20:13:08) nc: SEvent: Listening on /ip4/127.0.0.1/udp/3006/quic-v1
I (20:13:08) nc: SEvent: Listening on /ip4/*REDACTED*/udp/3006/quic-v1
D (20:13:08) driver_init: born poke acknowledged
1 Like
2

I had the same issue setting up a nockchain server for the first time this evening. I lost patience however and probably further exacerbated the problem by re-running the make run-nockchain-leader and make run-nockchain-follower commands in their respective terminals (although I didn’t see any info about how one should stop and restart these).

3

Running these commands again should be fine. Was there anything in your output/logs that made it seem like you’d exacerbated the connection issues?

4

Yes, messages about “ended friendships” and “port reuse” made me suspect that there was something left over from the previous run. Also, while the leader would continue to print out about candidate blocks on a restart, the follower never reprinted the earlier message about waiting for the genesis block.

It was definitely unintuitive to me that a make command would be used to not only run a process, but also be used unaltered to restart a process. But it was also the only option I had, as there was nothing in the README about how to stop/restart. And at any rate, I still share the same experience as you, with no evidence that the leader and follower are successfully connected.

1 Like
5

Here’s some more detail. Every 5 minutes on the leader, in and among the candidate block timestamp update messages, I get the following pair of error messages:

E (12:24:25) nc: Failed outgoing connection to Some(PeerId(“12D3KooWP6z5PZvz9GV9Spq1UG7CugoNhBbF2yDKfDnzB4NwhfDi”)): Dial error: Unexpected peer ID 12D3KooWBNagdW21g2F5LfxtPxMn1SCkN6iYMSZSwRwdzYUf6Q7i at Dialer { address: /ip4/127.0.0.1/udp/3006/quic-v1/p2p/12D3KooWP6z5PZvz9GV9Spq1UG7CugoNhBbF2yDKfDnzB4NwhfDi, role_override: Dialer, port_use: Reuse }.

E (12:24:25) nc: Failed outgoing connection to Some(PeerId(“12D3KooWP6z5PZvz9GV9Spq1UG7CugoNhBbF2yDKfDnzB4NwhfDi”)): Dial error: Unexpected peer ID 12D3KooWBNagdW21g2F5LfxtPxMn1SCkN6iYMSZSwRwdzYUf6Q7i at Dialer { address: /ip4/127.0.0.1/udp/3006/quic-v1/p2p/12D3KooWP6z5PZvz9GV9Spq1UG7CugoNhBbF2yDKfDnzB4NwhfDi, role_override: Dialer, port_use: Reuse }.

And on the follower, every 5 minutes contains this sequence of info and errors:

I (12:24:25) nc: SEvent: friendship ended with 12D3KooWR18WSn3dSnp1qoqED4hr9Rdg7Hws1yk4Pw7Ukjx7gxVY via: Listener { local_addr: /ip4/0.0.0.0/udp/3006/quic-v1, send_back_addr: /ip4/127.0.0.1/udp/3005/quic-v1 }. cause: Some(IO(Custom { kind: Other, error: Connection(ConnectionError(ApplicationClosed(ApplicationClose { error_code: 0, reason: b"" }))) }))

I (12:24:25) nc: SEvent: friendship ended with 12D3KooWR18WSn3dSnp1qoqED4hr9Rdg7Hws1yk4Pw7Ukjx7gxVY via: Listener { local_addr: /ip4/0.0.0.0/udp/3006/quic-v1, send_back_addr: /ip4/127.0.0.1/udp/3005/quic-v1 }. cause: Some(IO(Custom { kind: Other, error: Connection(ConnectionError(ApplicationClosed(ApplicationClose { error_code: 0, reason: b"" }))) }))

E (12:25:32) nc: Failed outgoing connection to Some(PeerId(“12D3KooWP6z5PZvz9GV9Spq1UG7CugoNhBbF2yDKfDnzB4NwhfDi”)): Dial error: Unexpected peer ID 12D3KooWBNagdW21g2F5LfxtPxMn1SCkN6iYMSZSwRwdzYUf6Q7i at Dialer { address: /ip4/127.0.0.1/udp/3006/quic-v1/p2p/12D3KooWP6z5PZvz9GV9Spq1UG7CugoNhBbF2yDKfDnzB4NwhfDi, role_override: Dialer, port_use: Reuse }.

E (12:25:32) nc: SEvent: Failed incoming connection from /ip4/127.0.0.1/udp/3006/quic-v1 to /ip4/0.0.0.0/udp/3006/quic-v1: Listen error: Local peer ID at Listener { local_addr: /ip4/0.0.0.0/udp/3006/quic-v1, send_back_addr: /ip4/127.0.0.1/udp/3006/quic-v1 }.

I would love to be able to confidently reset both of these, but last time I checked it wasn’t obvious to me how to do so.

6

It’s easier to see what’s going on with RUST_LOG=debug. Some of these errors are normal after restarting the nodes. They attempt to connect to known peers, but because the peer IDs are reset every time you run nodes, these initial connections will fail. They stop appearing for me after several occurrences.

Are you sure you aren’t running more Nockchain processes than the two you intend to run? It’s possible to start with a clean state by deleting the test-leader and test-follower directories after you’ve stopped the nodes. On the next run, they’ll be recreated.

I still don’t get the output I’ve seen in screenshots from others, but the debug log messages show that my nodes are able to ping each other, implying no actual peering problems. The genesis block is not being published, so I’m not sure if there are any interesting messages that should be exchanged by the nodes.

1 Like
7

I’ve deleted both dirs and the .sock, and have just started both again with the relevant make commands. I can see that the server is listening at udp 3005 and 6. Can I ask what you’re seeing on an ongoing basis that makes you think the leader and follower can see each other and are continuing to communicate successfully? And shouldn’t the (fakenet) genesis block be published? Isn’t that the point of the -leader process?

8

E (18:01:21) nc: Failed outgoing connection to None: Failed to negotiate transport protocol(s): [(/ip4/127.0.0.1/udp/3006/quic-v1: : Handshake with the remote timed out.: Handshake with the remote timed out.: Handshake with the remote timed out.)]
I (18:02:04) nc: SEvent: friendship ended with [ID, redacted] via: Listener { local_addr: /ip4/0.0.0.0/udp/3005/quic-v1, send_back_addr: /ip4/127.0.0.1/udp/59002/quic-v1 }. cause: Some(KeepAliveTimeout)

For the record, the only peer I’m catching is the follower from leader, and leader from follower. I’m assuming this is the intended behavior, as we don’t have peer discovery active yet until genesis?

9

That’s right. Fakenet is local only, and the provided commands assume a 1 leader, 1 follower setup.

10

The ping debug messages show me that both nodes are able to ping each other.

And yes, it would be neat if the genesis block was actually published on fakenet. I’m not sure if that’s the case for others in which case we’re doing something wrong. From my reading of the code, I think this is intended because the %genesis poke is never called without an actual Bitcoin RPC connection.

11

Modifying
mkdir -p test-follower && cd test-follower && rm -f nockchain.sock && RUST_BACKTRACE=1 cargo run --release --bin nockchain – --fakenet --genesis-watcher --npc-socket nockchain.sock --mining-pubkey $(MINING_PUBKEY) --bind /ip4/0.0.0.0/udp/3006/quic-v1 --peer /ip4/127.0.0.1/udp/3005/quic-v1 --new-peer-id --no-default-peers

to
mkdir -p test-follower && cd test-follower && RUST_BACKTRACE=1 cargo run --release --bin nockchain – --fakenet --genesis-watcher --npc-socket nockchain.sock --mining-pubkey $(MINING_PUBKEY) --bind /ip4/0.0.0.0/udp/3006/quic-v1 --peer /ip4/127.0.0.1/udp/3005/quic-v1 --new-peer-id --no-default-peers

makes the fakenet work as expected
i.e. remove the
&& rm -f nockchain.sock
part from the follower

By “as expected” I mean:

2025-05-18T17:14:56.146831Z TRACE new_established_connection{remote_addr=/ip4/127.0.0.1/udp/33627/quic-v1 id=4 peer=
12D3KooWNmew2dCC8f6R8tf3v6i112UCNCZG2STXJxuYjxmxruZR}:Connection::poll:ConnectionHandler::poll: quinn_proto::connect
ion::streams: wrote 32 bytes stream=client bidirectional stream 0
2025-05-18T17:14:56.146843Z TRACE new_established_connection{remote_addr=/ip4/127.0.0.1/udp/33627/quic-v1 id=4 peer=
12D3KooWNmew2dCC8f6R8tf3v6i112UCNCZG2STXJxuYjxmxruZR}:Connection::poll:ConnectionHandler::poll: libp2p_ping::handler
: answered inbound ping from peer
2025-05-18T17:14:56.146867Z TRACE Swarm::poll:drive{id=1}:send{space=Data pn=316}: quinn_proto::connection::streams:
:state: STREAM id=client bidirectional stream 0 off=1190 len=32 fin=false
2025-05-18T17:14:56.146881Z TRACE Swarm::poll:drive{id=1}: quinn_proto::connection: sending 63 bytes in 1 datagrams
2025-05-18T17:14:56.146912Z TRACE Swarm::poll:drive{id=1}: quinn_proto::connection: got Data packet (63 bytes) from
127.0.0.1:33627 using id a3421b252b860ffe
2025-05-18T17:14:56.146924Z TRACE Swarm::poll:drive{id=1}:recv{space=Data pn=312}: quinn_proto::connection: got stre
am frame id=server bidirectional stream 0 offset=1190 len=32 fin=false
2025-05-18T17:14:56.146939Z TRACE Swarm::poll:drive{id=1}:send{space=Data pn=317}: quinn_proto::connection: ACK Arra
yRangeSet([307..313]), Delay = 64us
2025-05-18T17:14:56.146949Z TRACE Swarm::poll:drive{id=1}: quinn_proto::connection: sending 36 bytes in 1 datagrams
2025-05-18T17:14:56.146974Z DEBUG new_established_connection{remote_addr=/ip4/127.0.0.1/udp/33627/quic-v1 id=4 peer=
12D3KooWNmew2dCC8f6R8tf3v6i112UCNCZG2STXJxuYjxmxruZR}:Connection::poll:ConnectionHandler::poll: libp2p_ping::handler
: ping succeeded rtt=387.844µs
2025-05-18T17:14:56.147005Z TRACE Swarm::poll:drive{id=1}: quinn_proto::connection: got Data packet (36 bytes) from
127.0.0.1:33627 using id a3421b252b860ffe
2025-05-18T17:14:56.147008Z TRACE nockchain_libp2p_io::nc: SEvent: other swarm event Behaviour(Ping(Event { peer: Pe
erId("12D3KooWNmew2dCC8f6R8tf3v6i112UCNCZG2STXJxuYjxmxruZR"), connection: ConnectionId(4), result: Ok(387.844µs) }))
2025-05-18T17:14:56.147027Z DEBUG next_effect: nockapp::nockapp::driver: Waiting for recv on next effect
2025-05-18T17:14:56.147024Z TRACE Swarm::poll:drive{id=1}:recv{space=Data pn=313}: quinn_proto::connection: got fram
e Ack(Ack { largest: 316, delay: 4, ecn: Some(EcnCounts { ect0: 314, ect1: 0, ce: 0 }), ranges: "[314..=316]" })

I’m still stuck unable to query (even though it should be empty) wallet balance

1 Like
12

My earlier repeating errors are no longer occurring. Progress! And yes, I know that my leader and follower have some visibility to one another due to each other’s IDs showing up in the “friendship ended with” messages, but those, as well as “Failed [outgoing/incoming] connection” don’t exactly inspire confidence that everything is going smoothly. Maybe it is!, but I’m not sure how I’m supposed to infer that from the logs. Anyway, I believe additional detail in the READMEs are on the agenda for the two-day launch extension, so maybe more info is forthcoming.

13

I was able to process a query of the wallet notes… seems a bit unstable but at the very least I confirmed that my setup with enough hammering of ‘delete the test folders and launch the leader then the follower after a minute then the wallet scan from the root dir then a note query’ does eventually give green lights!

I’m pretty sure that’s all just this fakenet jank

1 Like
14

Interesting! I can’t get the follower to run when the older nockchain.sock socket is still present. Standard “address already in use” error.

15

image
image1920×1080 282 KB

Is it normal behavior for the leader?

16

:white_check_mark: It’s exactly what I’ve been seeing after cleaning up my machine and starting over.

17

This is quasi correct, i.e. only if the sockets shit themselves. Should work in prod tho but fakenet needs a few restarts and deletes to work

18

My last comment here was completely incorrect. Genesis is called with fakenet config. I have no idea what’s holding us back from mining fakenet blocks.