Federation (forward messages between different relays) won't work

[sameh-farouk]

What Happens:

• Rmb-peer lets you specify and connect to a relay using either its domain name or IP address.
• The peer connection to its relay are initialized using the full URL provided by the user, this lets you send and receive messages to and from your relay, regardless using IP address or domain for your relay.

https://github.com/threefoldtech/rmb-rs/blob/933b64ba21d0ddc3d3dfb3861e381285814569c9/src/peer/socket.rs#L97

• under the hood and when it come to update twin info on TFchain, the peer will incorrectly parsing the provided URL if it contain IP address instead of a domain, and without complaining, send a transaction to update TFchain with null relay.

https://github.com/threefoldtech/rmb-rs/blob/933b64ba21d0ddc3d3dfb3861e381285814569c9/src/bins/rmb-peer.rs#L159-L165

• This will gone unnoticed as long as all peers use same null relay. relay will forward messages locally to to the connected peers.

• When there are other relay involved in communication, you will able to send messages to your relay without any errors, but federation won't work and nobody can reach you back because your peer updated your twin info with incorrect relay info.

I'm expect:

• If using IP addresses for a relay should be supported, we need to fix URL parsing logic to update the chain with correct info.

• If this is something we don't need, we should handle the case when user provide an IP address and explicitly check if domain is None before updating TFchain and stop early if user didn't provide a domain for his relay. but i see in this in the relay help:

  -m, --domain domain of this relay or it's public IP. used to identify if a twin is on this relay or not

[sameh-farouk]

Update: @muhamadazmy Today I give this another shot but using domain names instead of IP address.

Started a relay A in VM

rmb-relay --domain r1.3x0.me --substrate wss://tfchain.dev.grid.tf:443 -dd

Another relay B on different machine

rmb-relay --domain r2.3x0.me --substrate wss://tfchain.dev.grid.tf:443 -dd

Locally I started 2 peers

peer 1

./rmb-peer -m "<MNEMONIC>" --substrate "wss://tfchain.dev.grid.tf:443" --relay "ws://r1.3x0.me:8080" -d --redis "redis://localhost:6379"
2023-08-13T18:00:06.219Z DEBUG [rustls::client::hs] No cached session for DnsName(DnsName(DnsName("tfchain.dev.grid.tf")))
2023-08-13T18:00:06.219Z DEBUG [rustls::client::hs] Not resuming any session
2023-08-13T18:00:06.311Z DEBUG [rustls::client::hs] Using ciphersuite TLS13_AES_256_GCM_SHA384
2023-08-13T18:00:06.311Z DEBUG [rustls::client::tls13] Not resuming
2023-08-13T18:00:06.311Z DEBUG [rustls::client::tls13] TLS1.3 encrypted extensions: [ServerNameAck]
2023-08-13T18:00:06.311Z DEBUG [rustls::client::hs] ALPN protocol is None
2023-08-13T18:00:06.401Z DEBUG [rustls::client::tls13] Ticket saved
2023-08-13T18:00:06.401Z DEBUG [rustls::client::tls13] Ticket saved
2023-08-13T18:00:07.323Z DEBUG [rmb_peer] twin relay domain: Some("r1.3x0.me")
2023-08-13T18:00:07.323Z INFO [rmb_peer] twin: 41
2023-08-13T18:00:07.517Z DEBUG [tungstenite::handshake::client] Client handshake done.

peer 2 (using different Redis server)

 ./rmb-peer -m "<MNEMONIC>" --substrate "wss://tfchain.dev.grid.tf:443" --relay "ws://r2.3x0.me:8080" -d --redis "redis://localhost:6380"
2023-08-13T18:00:08.850Z DEBUG [rustls::client::hs] No cached session for DnsName(DnsName(DnsName("tfchain.dev.grid.tf")))
2023-08-13T18:00:08.850Z DEBUG [rustls::client::hs] Not resuming any session
2023-08-13T18:00:08.942Z DEBUG [rustls::client::hs] Using ciphersuite TLS13_AES_256_GCM_SHA384
2023-08-13T18:00:08.942Z DEBUG [rustls::client::tls13] Not resuming
2023-08-13T18:00:08.942Z DEBUG [rustls::client::tls13] TLS1.3 encrypted extensions: [ServerNameAck]
2023-08-13T18:00:08.942Z DEBUG [rustls::client::hs] ALPN protocol is None
2023-08-13T18:00:09.030Z DEBUG [rustls::client::tls13] Ticket saved
2023-08-13T18:00:09.030Z DEBUG [rustls::client::tls13] Ticket saved
2023-08-13T18:00:09.773Z DEBUG [rmb_peer] twin relay domain: Some("r2.3x0.me")
2023-08-13T18:00:09.773Z INFO [rmb_peer] twin: 3698
2023-08-13T18:00:10.024Z DEBUG [tungstenite::handshake::client] Client handshake done.

On TFchain everything seems okay,

tfgridModule.twins: Option<PalletTfgridTwin>
{
  id: 41
  accountId: 5DFkH2fcqYecVHjfgAEfxgsJyoEg5Kd93JFihfpHDaNoWagJ
  relay: r1.3x0.me
  entities: []
  pk: 0x02e8e2adfb8a0b489d3fb3df46adece2df2aa7639d88fc4baa96bbe9cc981cb131
}

tfgridModule.twins: Option<PalletTfgridTwin>
{
  id: 3,698
  accountId: 5FTr4MwdrnigM6gN2o2x4U4qRtdiPar9HAQFc3618t387s7x
  relay: r2.3x0.me
  entities: []
  pk: 0x02ed13c42b96c7eb761494903e3a05594d45e9635e3eaec9355c1b93ed16c92417
}

But whenever i try to send a message from peer 1 (twin 41) to peer 2 (twin 3698), It can reach relay A but it won't make it to relay B (I'm using the client-server example from rmb-sdk-go package)

2023-08-13T18:18:18.958Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:149 Read.read                                                                                                                                                                                                   
2023-08-13T18:18:18.958Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:126 AllowStd.with_context                                                           
2023-08-13T18:18:18.958Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:152 Read.with_context read -> poll_read                                                                                                                                                                         
2023-08-13T18:18:18.958Z TRACE [tungstenite::protocol::frame::frame] Parsed headers [130, 254]                                                                                                                                                                                                                                                                                      
2023-08-13T18:18:18.958Z TRACE [tungstenite::protocol::frame::frame] First: 10000010                                                                                                                                                                                                                                                                                                
2023-08-13T18:18:18.958Z TRACE [tungstenite::protocol::frame::frame] Second: 11111110                                                                                                                                                                                                                                                                                               
2023-08-13T18:18:18.958Z TRACE [tungstenite::protocol::frame::frame] Opcode: Data(Binary)                                                                                                                                                                                                                                                                                           
2023-08-13T18:18:18.958Z TRACE [tungstenite::protocol::frame::frame] Masked: true                                                                                                                                                                                                                                                                                                   
2023-08-13T18:18:18.959Z TRACE [tungstenite::protocol::frame] received frame                                                                                                                                                                                                                                                                                                        
<FRAME>                                                                                                                                                                                                                                                                                                                                                                             
final: true                                                                                                                                                                                                                                                                                                                                                                         
reserved: false false false                                                                                                                                                                                                                                                                                                                                                         
opcode: BINARY                                                                                                                                                                                                                                                                                                                                                                      
length: 214                                                                                                                                                                                                                                                                                                                                                                         
payload length: 206                                                                                                                                                                                                                                                                                                                                                                 
payload: 0x67fd1680fe814845fbfc825aea429d59ed42d440b814d2bf4158355bd16d655e911d55db8395ad13d87b64dc4bb265f013b3652b3dfa2caad7d75d64f4f9d860d4d0310a531fda2fff4f687784a9a79d94a6afea9d0fd9e38e526f5116f7739fd2b1391c79e38e819ed529e1e92cf7dff8e601ee76265673a0ca951dc4ba40c44b64f9f7aa4ede37d0538243ea598043b4448a7dd32fd3cb542c51b855df1ff740d49ab23e6ed0215897e41ff8895f1b69bdb19b8
04f76eb8c33ec2c76989277fa5553ead4c1                                                                                                                                                                                                                                                                                                                                                 

2023-08-13T18:18:18.959Z TRACE [tungstenite::protocol] Received message Binary Data<length=206>                                                                                                                                                                                                                                                                                     
2023-08-13T18:18:18.960Z DEBUG [rmb::relay::federation::router] federation to: https://r2.3x0.me/                                                                                                                                                                                                                                                                                   
2023-08-13T18:18:19.003Z DEBUG [reqwest::connect] starting new connection: https://r2.3x0.me/                                                                                                                                                                                                                                                                                       
2023-08-13T18:18:19.003Z TRACE [tokio_tungstenite] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/lib.rs:283 Stream.poll_next                                                                                                                                                                                                       
2023-08-13T18:18:19.003Z TRACE [tokio_tungstenite] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/lib.rs:238 WebSocketStream.with_context                                                                                                                                                                                           
2023-08-13T18:18:19.003Z TRACE [tokio_tungstenite] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/lib.rs:293 Stream.with_context poll_next -> read_message()                                                                                                                                                                        
2023-08-13T18:18:19.003Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:178 Write.flush                                                                                                                                                                                                 
2023-08-13T18:18:19.003Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:126 AllowStd.with_context                                                                                                                                                                                       
2023-08-13T18:18:19.003Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:180 Write.with_context flush -> poll_flush                                                                                                                                                                      
2023-08-13T18:18:19.003Z TRACE [tungstenite::protocol] Frames still in queue: 0                                                                                                                                                                                                                                                                                                     
2023-08-13T18:18:19.003Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:149 Read.read                                                                       
2023-08-13T18:18:19.003Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:126 AllowStd.with_context                                                           
2023-08-13T18:18:19.003Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:152 Read.with_context read -> poll_read                                             
2023-08-13T18:18:19.003Z TRACE [tokio_tungstenite::compat] WouldBlock                                                                                                                                                                                   
2023-08-13T18:18:19.156Z TRACE [mio::poll] registering event source with poller: token=Token(7), interests=READABLE | WRITABLE                                                                                                                          
2023-08-13T18:18:19.157Z TRACE [mio::poll] deregistering event source from poller                                                                                                                                                                       
2023-08-13T18:18:21.157Z DEBUG [reqwest::connect] starting new connection: https://r2.3x0.me/                                                                                                                                                           
2023-08-13T18:18:21.199Z TRACE [mio::poll] registering event source with poller: token=Token(16777223), interests=READABLE | WRITABLE                                                                                                                   
2023-08-13T18:18:21.199Z TRACE [mio::poll] deregistering event source from poller                                                                                                                                                                       
2023-08-13T18:18:23.200Z DEBUG [reqwest::connect] starting new connection: https://r2.3x0.me/                                                                                                                                                           
2023-08-13T18:18:23.201Z TRACE [rmb::relay::switch] [1] handling 1 connections                                                                                                                                                                          
2023-08-13T18:18:23.232Z TRACE [mio::poll] registering event source with poller: token=Token(33554439), interests=READABLE | WRITABLE                                                                                                                   
2023-08-13T18:18:23.233Z TRACE [mio::poll] deregistering event source from poller                                                                                                                                                                       
2023-08-13T18:18:25.238Z TRACE [rmb::relay::api] relaying message 1691950705238-0 to peer 41                                                                                                                                                            
2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/lib.rs:238 WebSocketStream.with_context                                                               
2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:178 Write.flush                                                                     
2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:126 AllowStd.with_context                                                           
2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:180 Write.with_context flush -> poll_flush                                          
2023-08-13T18:18:25.239Z TRACE [tungstenite::protocol] Frames still in queue: 0                                                                                                                                                                         
2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/lib.rs:238 WebSocketStream.with_context                                                               
2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:178 Write.flush                                                                     
2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:126 AllowStd.with_context                                                           
2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:180 Write.with_context flush -> poll_flush                                          
2023-08-13T18:18:25.239Z TRACE [tungstenite::protocol] Frames still in queue: 1                                                                                                                                                                         
2023-08-13T18:18:25.239Z TRACE [tungstenite::protocol] Sending frame: Frame { header: FrameHeader { is_final: true, rsv1: false, rsv2: false, rsv3: false, opcode: Data(Binary), mask: None }, payload: [10, 36, 55, 48, 98, 49, 53, 52, 50, 102, 45, 50, 55, 51, 99, 45, 52, 52, 99, 100, 45, 97, 53, 98, 102, 45, 52, 51, 56, 100, 55, 102, 56, 48, 48, 101, 48, 97, 98, 45, 18, 4
3, 114, 101, 108, 97, 121, 32, 39, 114, 50, 46, 51, 120, 48, 46, 109, 101, 39, 32, 119, 97, 115, 32, 110, 111, 116, 32, 114, 101, 97, 99, 104, 97, 98, 108, 101, 32, 105, 110, 32, 116, 105, 109, 101] }                                                                                                                                                                            
2023-08-13T18:18:25.239Z TRACE [tungstenite::protocol::frame] writing frame                                                                                                                                                                             
<FRAME>                                                                                                                                                                                                                                                 
final: true                                                                                                                                                                                                                                             
reserved: false false false                                                                                                                                                                                                                             
opcode: BINARY                                                                                                                                                                                                                                          
length: 87                                                                                                                                                                                                                                              
payload length: 85                                                                                                                                                                                                                                      
payload: 0xa2437306231353432662d323733632d343463642d613562662d343338643766383030653061622d122b72656c6179202772322e3378302e6d652720776173206e6f7420726561636861626c6520696e2074696d65                                                                    

2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:167 Write.write                                                                     
2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:126 AllowStd.with_context                                                                                                                                                                                       
2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:169 Write.with_context write -> poll_write                                                                                                                                                                      
2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:178 Write.flush                                                                     
2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:126 AllowStd.with_context                                                                                                                                                                                       
2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:180 Write.with_context flush -> poll_flush                                                                                                                                                                      
2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/lib.rs:238 WebSocketStream.with_context                                                                                                                                                                                           
2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:178 Write.flush                                                                                                                                                                                                 
2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:126 AllowStd.with_context                                                                                                                                                                                       
2023-08-13T18:18:25.239Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:180 Write.with_context flush -> poll_flush                                                                                                                                                                      
2023-08-13T18:18:25.239Z TRACE [tungstenite::protocol] Frames still in queue: 0                                                                                                                                                                                                                                                                                                     
2023-08-13T18:18:25.240Z DEBUG [rmb::relay::federation::router] failed to federation message: relay 'r2.3x0.me' was not reachable in time                                                                                                                                                                                                                                           
2023-08-13T18:18:25.240Z TRACE [rmb::relay::switch] [1] handling 1 connections                                                                                                                                                                                                                                                                                                      
2023-08-13T18:18:27.450Z TRACE [tokio_tungstenite] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/lib.rs:283 Stream.poll_next                                                                                                                                                                                                       
2023-08-13T18:18:27.450Z TRACE [tokio_tungstenite] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/lib.rs:238 WebSocketStream.with_context                                                                                                                                                                                           
2023-08-13T18:18:27.450Z TRACE [tokio_tungstenite] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/lib.rs:293 Stream.with_context poll_next -> read_message()                                                                                                                                                                        
2023-08-13T18:18:27.450Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:178 Write.flush                                                                                                                                                                                                 
2023-08-13T18:18:27.450Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:126 AllowStd.with_context                                                                                                                                                                                       
2023-08-13T18:18:27.450Z TRACE [tokio_tungstenite::compat] /home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-tungstenite-0.18.0/src/compat.rs:180 Write.with_context flush -> poll_flush                                                                                                                                                                      
2023-08-13T18:18:27.450Z TRACE [tungstenite::protocol] Frames still in queue: 0                                                                                                              

And this error in the peer 1 logs

2023-08-13T18:18:25.267Z ERROR [rmb::peer::protocol] failed to process incoming message: envelope validation error: message has expired

If i started both peers with same Relay (no federation), they can communicate normally. Do you have any idea what could be wrong with my multi-relay setup?

[muhamadazmy]

It's good catch, this is indeed an issue. if we parse the IP and set a null relay on the twin info. Instead a peer should only accept a valid domain name to his relay.

I always use ws://localhost:<port> when testing so might be the reason i have not noticed the issue.

The system is forced to use names to make sure 1) relays are public, 2) relays are running over SSL. which means rmb-peer should not accept a url with ip address (may be unless running in debug mode) .

On another hand. You made your setup too complicated, instead you could have run the 2 relays inside 2 separate namespaces on the same machine. and then set names in hosts file. that should make your life much easier.

In the example above I don't see where r1.3x0.me is coming from or if it resolve to a correct relay ip

[sameh-farouk]

On another hand. You made your setup too complicated, instead you could have run the 2 relays inside 2 separate namespaces on the same machine. and then set names in hosts file. that should make your life much easier.

I also attempted this method, but it was unsuccessful. I resorted to using separate VMs with domain names to mimic the regular usage.

In the example above I don't see where r1.3x0.me is coming from or if it resolve to a correct relay ip

Both are correctly resolved. I double checked that.

[sameh-farouk]

The system is forced to use names to make sure 1) relays are public, 2) relays are running over SSL. which means rmb-peer should not accept a url with ip address (may be unless running in debug mode) .

@muhamadazmy Thank you so much for helping me out with this issue. I finally realized that I need a reverse proxy for TLS termination (your note), which was the key to solving my problem. I was confused because I thought the RMB would handle this, but I was wrong.

This confusion was mainly due to the lack of documentation but the main objectives of this issue now is to add proper validation of the relay domain.

I can help soon with with adding a clear and reliable documentation for setup both development and production environments.

[sameh-farouk]

Peer now only accept a valid domain name to his relay. fixed in 2718d89e984158ec07b37144232d5fa4d4290495.