Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Connection failing to TCP candidate when listening on multiple interfaces using MultiTCPMux and NAT1To1IPs #583

Closed
streamer45 opened this issue May 26, 2023 · 5 comments
Closed

Connection failing to TCP candidate when listening on multiple interfaces using MultiTCPMux and NAT1To1IPs #583

streamer45 opened this issue May 26, 2023 · 5 comments

Comments

@streamer45
Copy link

Your environment.

  • Version: v2.3.3
  • Browser: Chrome 112.0.5615.165

I am hitting similar problems I had in #541 but this time with TCP candidates. It seems I cannot get the NAT1To1IPs mapping to work correctly when listening on multiple interfaces and using MultiTCPMux. Listening on a single interface works as expected.

Server setup is very simple, standard EC2 with loopback and a private IP:

  • 127.0.0.1
  • 172.27.134.52

External IP is 54.196.153.204

Attaching logs of both attempts.

Single interface (working):

NAT mapping is: [54.196.153.204/172.27.134.52].

ice INFO: 2023/05/26 08:30:55 Listening TCP on 172.27.134.52:8443
ice INFO: 2023/05/26 08:30:55 Listening TCP on 127.0.0.1:8443
ice TRACE: 08:26:29.732571 agent.go:503: Unset selected candidate pair
ice DEBUG: 08:26:29.732642 agent.go:385: Started agent: isControlling? false, remoteUfrag: "13wS", remotePwd: "Ve/Qi9S2w1xznezrH8MmzsKC"
ice INFO: 2023/05/26 08:26:29 Setting new connection state: Checking
ice TRACE: 08:26:29.732689 agent.go:526: pinging all candidates
ice WARNING: 2023/05/26 08:26:29 Failed to ping without candidate pairs. Connection is not possible yet.
new candidate: udp4 host 54.196.153.204:8443 172.27.134.52:8443
ice WARNING: 2023/05/26 08:26:29 1:1 NAT mapping is enabled but no external IP is found for 127.0.0.1
ice DEBUG: 08:26:29.732906 gather.go:183: GetConn by ufrag: CGaTgGVknqwHRyQt
new candidate: tcp4 host 127.0.0.1:8443 127.0.0.1:8443
ice TRACE: 08:26:29.732869 agent.go:526: pinging all candidates
ice WARNING: 2023/05/26 08:26:29 Failed to ping without candidate pairs. Connection is not possible yet.
ice DEBUG: 08:26:29.733041 gather.go:183: GetConn by ufrag: CGaTgGVknqwHRyQt
new candidate: tcp4 host 54.196.153.204:8443 172.27.134.52:8443
ice TRACE: 08:26:29.733145 agent.go:526: pinging all candidates
ice WARNING: 2023/05/26 08:26:29 Failed to ping without candidate pairs. Connection is not possible yet.
ice TRACE: 08:26:29.733952 agent.go:526: pinging all candidates
ice TRACE: 08:26:29.734003 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.254.1:42523
ice DEBUG: 08:26:29.734017 udp_mux.go:263: Registered 192.168.254.1:42523 for CGaTgGVknqwHRyQt
ice TRACE: 08:26:29.735795 agent.go:526: pinging all candidates
ice TRACE: 08:26:29.735816 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.254.1:42523
ice TRACE: 08:26:29.735836 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.1.117:35590
ice DEBUG: 08:26:29.735842 udp_mux.go:263: Registered 192.168.1.117:35590 for CGaTgGVknqwHRyQt
ice INFO: 2023/05/26 08:26:29 Ignoring remote candidate with tcpType active: tcp4 host 192.168.254.1:9
ice INFO: 2023/05/26 08:26:29 Ignoring remote candidate with tcpType active: tcp4 host 192.168.1.117:9
ice TRACE: 08:26:29.936778 agent.go:526: pinging all candidates
ice TRACE: 08:26:29.936836 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.254.1:42523
ice TRACE: 08:26:29.936887 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.1.117:35590
ice DEBUG: 08:26:30.087951 tcp_mux.go:88: Accepted connection from: 93.40.208.57:35095 to 172.27.134.52:8443
ice DEBUG: 08:26:30.093506 tcp_mux.go:88: Accepted connection from: 93.40.208.57:35093 to 172.27.134.52:8443
ice WARNING: 2023/05/26 08:26:30 Error reading first packet from 93.40.208.57:35093: EOF
ice TRACE: 08:26:30.137272 agent.go:526: pinging all candidates
ice TRACE: 08:26:30.137298 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.254.1:42523
ice TRACE: 08:26:30.137325 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.1.117:35590
ice DEBUG: 08:26:30.143434 tcp_mux.go:194: msg attr: USERNAME: 0x434761546747566b6e717748527951743a31337753
ice DEBUG: 08:26:30.143447 tcp_mux.go:194: msg attr: 0xc057: 0x0002000a
ice DEBUG: 08:26:30.143462 tcp_mux.go:194: msg attr: ICE-CONTROLLING: 0x33f3d64cd63a3015
ice DEBUG: 08:26:30.143472 tcp_mux.go:194: msg attr: USE-CANDIDATE: 0x
ice DEBUG: 08:26:30.143483 tcp_mux.go:194: msg attr: PRIORITY: 0x507e1eff
ice DEBUG: 08:26:30.143496 tcp_mux.go:194: msg attr: MESSAGE-INTEGRITY: 0x865c8af4b0b15de724a12aa752770bd73be76b73
ice DEBUG: 08:26:30.143503 tcp_mux.go:194: msg attr: FINGERPRINT: 0x7d64dbf2
ice DEBUG: 08:26:30.143511 tcp_mux.go:205: Ufrag: CGaTgGVknqwHRyQt
ice INFO: 2023/05/26 08:26:30 AddConn: tcp remote 93.40.208.57:35095 to local 172.27.134.52:8443
ice DEBUG: 08:26:30.143581 agent.go:1045: Adding a new peer-reflexive candidate: 93.40.208.57:35095 
ice TRACE: 08:26:30.143597 agent.go:1049: inbound STUN (Request) from 93.40.208.57:35095 to tcp4 host 54.196.153.204:8443
ice TRACE: 08:26:30.143638 agent.go:899: ping STUN from tcp4 host 54.196.153.204:8443 to tcp4 prflx 93.40.208.57:35095 related :0
ice TRACE: 08:26:30.143668 agent.go:526: pinging all candidates
ice TRACE: 08:26:30.143690 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.254.1:42523
ice TRACE: 08:26:30.143737 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.1.117:35590
ice TRACE: 08:26:30.143760 agent.go:899: ping STUN from tcp4 host 127.0.0.1:8443 to tcp4 prflx 93.40.208.57:35095 related :0
ice TRACE: 08:26:30.143770 candidatepair.go:100: failed to send STUN message: io: read/write on closed pipe
ice TRACE: 08:26:30.143793 agent.go:899: ping STUN from tcp4 host 54.196.153.204:8443 to tcp4 prflx 93.40.208.57:35095 related :0
ice TRACE: 08:26:30.263459 selection.go:224: inbound STUN (SuccessResponse) from tcp4 prflx 93.40.208.57:35095 related :0 to tcp4 host 54.196.153.204:8443
ice TRACE: 08:26:30.263485 selection.go:234: Found valid candidate pair: prio 7935342541533085695 (local, prio 2124414975) tcp4 host 54.196.153.204:8443 <-> tcp4 prflx 93.40.208.57:35095 related :0 (remote, prio 1847590911)
ice TRACE: 08:26:30.263504 agent.go:509: Set selected candidate pair: prio 7935342541533085695 (local, prio 2124414975) tcp4 host 54.196.153.204:8443 <-> tcp4 prflx 93.40.208.57:35095 related :0 (remote, prio 1847590911)
ice INFO: 2023/05/26 08:26:30 Setting new connection state: Connected
ice TRACE: 08:26:30.263558 selection.go:224: inbound STUN (SuccessResponse) from tcp4 prflx 93.40.208.57:35095 related :0 to tcp4 host 54.196.153.204:8443
ice TRACE: 08:26:30.263597 selection.go:234: Found valid candidate pair: prio 7935342541533085695 (local, prio 2124414975) tcp4 host 54.196.153.204:8443 <-> tcp4 prflx 93.40.208.57:35095 related :0 (remote, prio 1847590911)
ice TRACE: 08:26:30.271454 agent.go:1049: inbound STUN (Request) from 93.40.208.57:35095 to tcp4 host 54.196.153.204:8443
ice TRACE: 08:26:30.271485 agent.go:899: ping STUN from tcp4 host 54.196.153.204:8443 to tcp4 prflx 93.40.208.57:35095 related :0
ice TRACE: 08:26:30.335182 agent.go:1049: inbound STUN (Request) from 93.40.208.57:35095 to tcp4 host 54.196.153.204:8443
ice TRACE: 08:26:30.335218 agent.go:899: ping STUN from tcp4 host 54.196.153.204:8443 to tcp4 prflx 93.40.208.57:35095 related :0
ice TRACE: 08:26:30.344265 selection.go:176: checking keepalive
ice TRACE: 08:26:30.388999 selection.go:224: inbound STUN (SuccessResponse) from tcp4 prflx 93.40.208.57:35095 related :0 to tcp4 host 54.196.153.204:8443
ice TRACE: 08:26:30.389015 selection.go:234: Found valid candidate pair: prio 7935342541533085695 (local, prio 2124414975) tcp4 host 54.196.153.204:8443 <-> tcp4 prflx 93.40.208.57:35095 related :0 (remote, prio 1847590911)
ice TRACE: 08:26:30.454714 selection.go:224: inbound STUN (SuccessResponse) from tcp4 prflx 93.40.208.57:35095 related :0 to tcp4 host 54.196.153.204:8443
ice TRACE: 08:26:30.454736 selection.go:234: Found valid candidate pair: prio 7935342541533085695 (local, prio 2124414975) tcp4 host 54.196.153.204:8443 <-> tcp4 prflx 93.40.208.57:35095 related :0 (remote, prio 1847590911)

Multiple interfaces (not working, timing out):

NAT mapping is: [54.196.153.204/127.0.0.1 172.27.134.52/172.27.134.52].

ice INFO: 2023/05/26 08:30:55 Listening TCP on 172.27.134.52:8443
ice INFO: 2023/05/26 08:30:55 Listening TCP on 127.0.0.1:8443
ice TRACE: 08:31:31.673450 agent.go:503: Unset selected candidate pair
ice DEBUG: 08:31:31.673509 agent.go:385: Started agent: isControlling? false, remoteUfrag: "sKz4", remotePwd: "y1QDCQDtNXi1+ZrAz1rpxOjc"
ice INFO: 2023/05/26 08:31:31 Setting new connection state: Checking
ice TRACE: 08:31:31.673549 agent.go:526: pinging all candidates
ice WARNING: 2023/05/26 08:31:31 Failed to ping without candidate pairs. Connection is not possible yet.
new candidate: udp4 host 54.196.153.204:8443 127.0.0.1:8443
new candidate: udp4 host 172.27.134.52:8443 172.27.134.52:8443
ice TRACE: 08:31:31.673682 agent.go:526: pinging all candidates
ice WARNING: 2023/05/26 08:31:31 Failed to ping without candidate pairs. Connection is not possible yet.
ice TRACE: 08:31:31.673813 agent.go:526: pinging all candidates
ice WARNING: 2023/05/26 08:31:31 Failed to ping without candidate pairs. Connection is not possible yet.
ice DEBUG: 08:31:31.673836 gather.go:176: GetAllConns by ufrag: ihArTOCWSZGqvkiX
new candidate: tcp4 host 54.196.153.204:8443 127.0.0.1:8443
new candidate: tcp4 host 54.196.153.204:8443 127.0.0.1:8443
ice TRACE: 08:31:31.673917 agent.go:526: pinging all candidates
ice WARNING: 2023/05/26 08:31:31 Failed to ping without candidate pairs. Connection is not possible yet.
ice DEBUG: 08:31:31.673970 agent.go:750: Ignore duplicate candidate: tcp4 host 54.196.153.204:8443
ice DEBUG: 08:31:31.673982 gather.go:176: GetAllConns by ufrag: ihArTOCWSZGqvkiX
new candidate: tcp4 host 172.27.134.52:8443 172.27.134.52:8443
new candidate: tcp4 host 172.27.134.52:8443 172.27.134.52:8443
ice DEBUG: 08:31:31.674015 agent.go:750: Ignore duplicate candidate: tcp4 host 172.27.134.52:8443
ice TRACE: 08:31:31.674020 agent.go:526: pinging all candidates
ice WARNING: 2023/05/26 08:31:31 Failed to ping without candidate pairs. Connection is not possible yet.
ice TRACE: 08:31:31.676934 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.254.1:35966
ice DEBUG: 08:31:31.676947 udp_mux.go:263: Registered 192.168.254.1:35966 for ihArTOCWSZGqvkiX
ice INFO: 2023/05/26 08:31:31 failed to send packet: write udp4 127.0.0.1:8443->192.168.254.1:35966: sendto: invalid argument
ice TRACE: 08:31:31.676981 agent.go:899: ping STUN from udp4 host 172.27.134.52:8443 to udp4 host 192.168.254.1:35966
ice DEBUG: 08:31:31.677003 udp_mux.go:263: Registered 192.168.254.1:35966 for ihArTOCWSZGqvkiX
ice TRACE: 08:31:31.678263 agent.go:526: pinging all candidates
ice TRACE: 08:31:31.678284 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.254.1:35966
ice INFO: 2023/05/26 08:31:31 failed to send packet: write udp4 127.0.0.1:8443->192.168.254.1:35966: sendto: invalid argument
ice TRACE: 08:31:31.678339 agent.go:899: ping STUN from udp4 host 172.27.134.52:8443 to udp4 host 192.168.254.1:35966
ice TRACE: 08:31:31.678361 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.1.117:45930
ice DEBUG: 08:31:31.678368 udp_mux.go:263: Registered 192.168.1.117:45930 for ihArTOCWSZGqvkiX
ice INFO: 2023/05/26 08:31:31 failed to send packet: write udp4 127.0.0.1:8443->192.168.1.117:45930: sendto: invalid argument
ice TRACE: 08:31:31.678384 agent.go:899: ping STUN from udp4 host 172.27.134.52:8443 to udp4 host 192.168.1.117:45930
ice DEBUG: 08:31:31.678391 udp_mux.go:263: Registered 192.168.1.117:45930 for ihArTOCWSZGqvkiX
ice INFO: 2023/05/26 08:31:31 Ignoring remote candidate with tcpType active: tcp4 host 192.168.254.1:9
ice TRACE: 08:31:31.879223 agent.go:526: pinging all candidates
ice TRACE: 08:31:31.879266 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.254.1:35966
ice INFO: 2023/05/26 08:31:31 failed to send packet: write udp4 127.0.0.1:8443->192.168.254.1:35966: sendto: invalid argument
ice TRACE: 08:31:31.879324 agent.go:899: ping STUN from udp4 host 172.27.134.52:8443 to udp4 host 192.168.254.1:35966
ice TRACE: 08:31:31.879363 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.1.117:45930
ice INFO: 2023/05/26 08:31:31 failed to send packet: write udp4 127.0.0.1:8443->192.168.1.117:45930: sendto: invalid argument
ice TRACE: 08:31:31.879412 agent.go:899: ping STUN from udp4 host 172.27.134.52:8443 to udp4 host 192.168.1.117:45930
ice DEBUG: 08:31:31.979374 tcp_mux.go:88: Accepted connection from: 93.40.208.57:35377 to 172.27.134.52:8443
ice DEBUG: 08:31:31.982511 tcp_mux.go:88: Accepted connection from: 93.40.208.57:35378 to 172.27.134.52:8443
ice WARNING: 2023/05/26 08:31:31 Error reading first packet from 93.40.208.57:35378: EOF
ice TRACE: 08:31:32.079838 agent.go:526: pinging all candidates
ice TRACE: 08:31:32.079864 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.254.1:35966
ice INFO: 2023/05/26 08:31:32 failed to send packet: write udp4 127.0.0.1:8443->192.168.254.1:35966: sendto: invalid argument
ice TRACE: 08:31:32.079905 agent.go:899: ping STUN from udp4 host 172.27.134.52:8443 to udp4 host 192.168.254.1:35966
ice TRACE: 08:31:32.079939 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.1.117:45930
ice INFO: 2023/05/26 08:31:32 failed to send packet: write udp4 127.0.0.1:8443->192.168.1.117:45930: sendto: invalid argument
ice TRACE: 08:31:32.079961 agent.go:899: ping STUN from udp4 host 172.27.134.52:8443 to udp4 host 192.168.1.117:45930
ice DEBUG: 08:31:32.080637 tcp_mux.go:194: msg attr: USERNAME: 0x69684172544f4357535a4771766b69583a734b7a34
ice DEBUG: 08:31:32.080650 tcp_mux.go:194: msg attr: 0xc057: 0x0002000a
ice DEBUG: 08:31:32.080664 tcp_mux.go:194: msg attr: ICE-CONTROLLING: 0x4de5bbdde8566021
ice DEBUG: 08:31:32.080675 tcp_mux.go:194: msg attr: USE-CANDIDATE: 0x
ice DEBUG: 08:31:32.080684 tcp_mux.go:194: msg attr: PRIORITY: 0x507e1eff
ice DEBUG: 08:31:32.080695 tcp_mux.go:194: msg attr: MESSAGE-INTEGRITY: 0x3cbabf7c389e3ec14de2da19abbda222961105c4
ice DEBUG: 08:31:32.080702 tcp_mux.go:194: msg attr: FINGERPRINT: 0x35229f6f
ice DEBUG: 08:31:32.080710 tcp_mux.go:205: Ufrag: ihArTOCWSZGqvkiX
ice INFO: 2023/05/26 08:31:32 AddConn: tcp remote 93.40.208.57:35377 to local 172.27.134.52:8443
ice TRACE: 08:31:32.280248 agent.go:526: pinging all candidates
ice TRACE: 08:31:32.280298 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.254.1:35966
ice INFO: 2023/05/26 08:31:32 failed to send packet: write udp4 127.0.0.1:8443->192.168.254.1:35966: sendto: invalid argument
ice TRACE: 08:31:32.280343 agent.go:899: ping STUN from udp4 host 172.27.134.52:8443 to udp4 host 192.168.254.1:35966
ice TRACE: 08:31:32.280397 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.1.117:45930
ice INFO: 2023/05/26 08:31:32 failed to send packet: write udp4 127.0.0.1:8443->192.168.1.117:45930: sendto: invalid argument
ice TRACE: 08:31:32.280463 agent.go:899: ping STUN from udp4 host 172.27.134.52:8443 to udp4 host 192.168.1.117:45930
ice TRACE: 08:31:32.480909 agent.go:526: pinging all candidates
ice TRACE: 08:31:32.480951 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.254.1:35966
ice INFO: 2023/05/26 08:31:32 failed to send packet: write udp4 127.0.0.1:8443->192.168.254.1:35966: sendto: invalid argument
ice TRACE: 08:31:32.481009 agent.go:899: ping STUN from udp4 host 172.27.134.52:8443 to udp4 host 192.168.254.1:35966
ice TRACE: 08:31:32.481046 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.1.117:45930
ice INFO: 2023/05/26 08:31:32 failed to send packet: write udp4 127.0.0.1:8443->192.168.1.117:45930: sendto: invalid argument
ice TRACE: 08:31:32.481117 agent.go:899: ping STUN from udp4 host 172.27.134.52:8443 to udp4 host 192.168.1.117:45930
ice TRACE: 08:31:32.681561 agent.go:526: pinging all candidates
ice TRACE: 08:31:32.681588 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.254.1:35966
ice INFO: 2023/05/26 08:31:32 failed to send packet: write udp4 127.0.0.1:8443->192.168.254.1:35966: sendto: invalid argument
ice TRACE: 08:31:32.681609 agent.go:899: ping STUN from udp4 host 172.27.134.52:8443 to udp4 host 192.168.254.1:35966
ice TRACE: 08:31:32.681627 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.1.117:45930
ice INFO: 2023/05/26 08:31:32 failed to send packet: write udp4 127.0.0.1:8443->192.168.1.117:45930: sendto: invalid argument
ice TRACE: 08:31:32.681650 agent.go:899: ping STUN from udp4 host 172.27.134.52:8443 to udp4 host 192.168.1.117:45930
ice TRACE: 08:31:32.881817 agent.go:526: pinging all candidates
ice TRACE: 08:31:32.881851 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.254.1:35966
ice INFO: 2023/05/26 08:31:32 failed to send packet: write udp4 127.0.0.1:8443->192.168.254.1:35966: sendto: invalid argument
ice TRACE: 08:31:32.881890 agent.go:899: ping STUN from udp4 host 172.27.134.52:8443 to udp4 host 192.168.254.1:35966
ice TRACE: 08:31:32.881948 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.1.117:45930
ice INFO: 2023/05/26 08:31:32 failed to send packet: write udp4 127.0.0.1:8443->192.168.1.117:45930: sendto: invalid argument
ice TRACE: 08:31:32.881995 agent.go:899: ping STUN from udp4 host 172.27.134.52:8443 to udp4 host 192.168.1.117:45930
ice TRACE: 08:31:33.082363 agent.go:526: pinging all candidates
ice TRACE: 08:31:33.082451 agent.go:540: max requests reached for pair prio 9115038253525819647 (local, prio 2130706431) udp4 host 54.196.153.204:8443 <-> udp4 host 192.168.254.1:35966 (remote, prio 2122260223), marking it as failed
ice TRACE: 08:31:33.082464 agent.go:540: max requests reached for pair prio 9115038253525819647 (local, prio 2130706431) udp4 host 172.27.134.52:8443 <-> udp4 host 192.168.254.1:35966 (remote, prio 2122260223), marking it as failed
ice TRACE: 08:31:33.082488 agent.go:899: ping STUN from udp4 host 54.196.153.204:8443 to udp4 host 192.168.1.117:45930
ice INFO: 2023/05/26 08:31:33 failed to send packet: write udp4 127.0.0.1:8443->192.168.1.117:45930: sendto: invalid argument
ice TRACE: 08:31:33.082547 agent.go:899: ping STUN from udp4 host 172.27.134.52:8443 to udp4 host 192.168.1.117:45930
ice TRACE: 08:31:33.283058 agent.go:526: pinging all candidates
ice TRACE: 08:31:33.283080 agent.go:540: max requests reached for pair prio 9114756778549174527 (local, prio 2130706431) udp4 host 54.196.153.204:8443 <-> udp4 host 192.168.1.117:45930 (remote, prio 2122194687), marking it as failed
ice TRACE: 08:31:33.283091 agent.go:540: max requests reached for pair prio 9114756778549174527 (local, prio 2130706431) udp4 host 172.27.134.52:8443 <-> udp4 host 192.168.1.117:45930 (remote, prio 2122194687), marking it as failed
ice TRACE: 08:31:33.483310 agent.go:526: pinging all candidates
ice TRACE: 08:31:33.683643 agent.go:526: pinging all candidates
ice TRACE: 08:31:33.884094 agent.go:526: pinging all candidates
ice TRACE: 08:31:34.084536 agent.go:526: pinging all candidates
ice TRACE: 08:31:34.285353 agent.go:526: pinging all candidates
ice TRACE: 08:31:34.485827 agent.go:526: pinging all candidates
ice TRACE: 08:31:34.686759 agent.go:526: pinging all candidates
ice TRACE: 08:31:34.887207 agent.go:526: pinging all candidates
ice TRACE: 08:31:35.087825 agent.go:526: pinging all candidates
ice TRACE: 08:31:35.288162 agent.go:526: pinging all candidates
ice TRACE: 08:31:35.488532 agent.go:526: pinging all candidates
ice TRACE: 08:31:35.689562 agent.go:526: pinging all candidates
ice TRACE: 08:31:35.890105 agent.go:526: pinging all candidates
ice TRACE: 08:31:36.090478 agent.go:526: pinging all candidates
ice TRACE: 08:31:36.291542 agent.go:526: pinging all candidates
ice TRACE: 08:31:36.491906 agent.go:526: pinging all candidates
ice TRACE: 08:31:36.692791 agent.go:526: pinging all candidates
ice TRACE: 08:31:36.893323 agent.go:526: pinging all candidates
ice TRACE: 08:31:37.093772 agent.go:526: pinging all candidates
ice TRACE: 08:31:37.294243 agent.go:526: pinging all candidates
ice TRACE: 08:31:37.495177 agent.go:526: pinging all candidates
ice TRACE: 08:31:37.695569 agent.go:526: pinging all candidates
ice TRACE: 08:31:37.896332 agent.go:526: pinging all candidates
ice TRACE: 08:31:38.097174 agent.go:526: pinging all candidates
ice TRACE: 08:31:38.297548 agent.go:526: pinging all candidates
ice TRACE: 08:31:38.498107 agent.go:526: pinging all candidates
ice TRACE: 08:31:38.698530 agent.go:526: pinging all candidates
ice TRACE: 08:31:38.899405 agent.go:526: pinging all candidates
ice TRACE: 08:31:39.100357 agent.go:526: pinging all candidates
ice TRACE: 08:31:39.300538 agent.go:526: pinging all candidates
ice TRACE: 08:31:39.500984 agent.go:526: pinging all candidates
ice TRACE: 08:31:39.701141 agent.go:526: pinging all candidates
ice TRACE: 08:31:39.902086 agent.go:526: pinging all candidates
ice TRACE: 08:31:40.102483 agent.go:526: pinging all candidates
ice TRACE: 08:31:40.303438 agent.go:526: pinging all candidates
ice TRACE: 08:31:40.503907 agent.go:526: pinging all candidates
ice TRACE: 08:31:40.704859 agent.go:526: pinging all candidates
ice TRACE: 08:31:40.905686 agent.go:526: pinging all candidates
ice TRACE: 08:31:41.106149 agent.go:526: pinging all candidates
ice TRACE: 08:31:41.307122 agent.go:526: pinging all candidates
ice TRACE: 08:31:41.507437 agent.go:526: pinging all candidates
ice TRACE: 08:31:41.707686 agent.go:526: pinging all candidates
ice TRACE: 08:31:41.907856 agent.go:526: pinging all candidates
ice TRACE: 08:31:42.108329 agent.go:526: pinging all candidates
ice TRACE: 08:31:42.308751 agent.go:526: pinging all candidates
ice TRACE: 08:31:42.509464 agent.go:526: pinging all candidates
ice TRACE: 08:31:42.709905 agent.go:526: pinging all candidates
ice TRACE: 08:31:42.910148 agent.go:526: pinging all candidates
ice TRACE: 08:31:43.110718 agent.go:526: pinging all candidates
ice TRACE: 08:31:43.311168 agent.go:526: pinging all candidates
ice TRACE: 08:31:43.511375 agent.go:526: pinging all candidates
ice TRACE: 08:31:43.711691 agent.go:526: pinging all candidates
ice TRACE: 08:31:43.912115 agent.go:526: pinging all candidates
ice TRACE: 08:31:44.112628 agent.go:526: pinging all candidates
ice TRACE: 08:31:44.313447 agent.go:526: pinging all candidates
ice TRACE: 08:31:44.513863 agent.go:526: pinging all candidates
ice TRACE: 08:31:44.714232 agent.go:526: pinging all candidates
ice TRACE: 08:31:44.914287 agent.go:526: pinging all candidates
ice TRACE: 08:31:45.114688 agent.go:526: pinging all candidates
ice TRACE: 08:31:45.315245 agent.go:526: pinging all candidates
ice TRACE: 08:31:45.515683 agent.go:526: pinging all candidates
ice TRACE: 08:31:45.716645 agent.go:526: pinging all candidates
ice TRACE: 08:31:45.917319 agent.go:526: pinging all candidates
ice TRACE: 08:31:46.117791 agent.go:526: pinging all candidates
ice TRACE: 08:31:46.318406 agent.go:526: pinging all candidates
ice TRACE: 08:31:46.519498 agent.go:526: pinging all candidates
ice TRACE: 08:31:46.719765 agent.go:526: pinging all candidates
ice TRACE: 08:31:46.920683 agent.go:526: pinging all candidates
ice TRACE: 08:31:47.121091 agent.go:526: pinging all candidates
ice INFO: 2023/05/26 08:31:47 error reading streaming packet: EOF
ice TRACE: 08:31:47.321241 agent.go:526: pinging all candidates
ice TRACE: 08:31:47.521699 agent.go:526: pinging all candidates
ice TRACE: 08:31:47.722117 agent.go:526: pinging all candidates
ice TRACE: 08:31:47.922503 agent.go:526: pinging all candidates
ice TRACE: 08:31:48.122916 agent.go:526: pinging all candidates
ice TRACE: 08:31:48.323364 agent.go:526: pinging all candidates
ice TRACE: 08:31:48.523779 agent.go:526: pinging all candidates
ice TRACE: 08:31:48.724243 agent.go:526: pinging all candidates
ice TRACE: 08:31:48.924660 agent.go:526: pinging all candidates
ice TRACE: 08:31:49.125091 agent.go:526: pinging all candidates
ice TRACE: 08:31:49.325505 agent.go:526: pinging all candidates
ice TRACE: 08:31:49.525940 agent.go:526: pinging all candidates
ice TRACE: 08:31:49.726352 agent.go:526: pinging all candidates
ice TRACE: 08:31:49.926795 agent.go:526: pinging all candidates
ice TRACE: 08:31:50.127206 agent.go:526: pinging all candidates
ice TRACE: 08:31:50.327653 agent.go:526: pinging all candidates
ice TRACE: 08:31:50.528037 agent.go:526: pinging all candidates
ice TRACE: 08:31:50.728470 agent.go:526: pinging all candidates
ice TRACE: 08:31:50.928962 agent.go:526: pinging all candidates
ice TRACE: 08:31:51.129409 agent.go:526: pinging all candidates
ice TRACE: 08:31:51.329823 agent.go:526: pinging all candidates
ice TRACE: 08:31:51.530268 agent.go:526: pinging all candidates
ice TRACE: 08:31:51.730921 agent.go:526: pinging all candidates
ice TRACE: 08:31:51.931319 agent.go:526: pinging all candidates
ice TRACE: 08:31:52.131709 agent.go:526: pinging all candidates
ice TRACE: 08:31:52.332123 agent.go:526: pinging all candidates
ice TRACE: 08:31:52.532501 agent.go:526: pinging all candidates
ice TRACE: 08:31:52.732982 agent.go:526: pinging all candidates
ice TRACE: 08:31:52.933401 agent.go:526: pinging all candidates
ice TRACE: 08:31:53.133859 agent.go:526: pinging all candidates
ice TRACE: 08:31:53.334276 agent.go:526: pinging all candidates
ice TRACE: 08:31:53.534678 agent.go:526: pinging all candidates
ice TRACE: 08:31:53.735107 agent.go:526: pinging all candidates
ice TRACE: 08:31:53.935497 agent.go:526: pinging all candidates
ice TRACE: 08:31:54.135919 agent.go:526: pinging all candidates
ice TRACE: 08:31:54.336368 agent.go:526: pinging all candidates
ice TRACE: 08:31:54.536764 agent.go:526: pinging all candidates
ice TRACE: 08:31:54.737202 agent.go:526: pinging all candidates
ice TRACE: 08:31:54.937638 agent.go:526: pinging all candidates
ice TRACE: 08:31:55.138084 agent.go:526: pinging all candidates
ice TRACE: 08:31:55.338522 agent.go:526: pinging all candidates
ice TRACE: 08:31:55.538967 agent.go:526: pinging all candidates
ice TRACE: 08:31:55.739399 agent.go:526: pinging all candidates
ice TRACE: 08:31:55.940253 agent.go:526: pinging all candidates
ice TRACE: 08:31:56.140678 agent.go:526: pinging all candidates
ice TRACE: 08:31:56.341087 agent.go:526: pinging all candidates
ice TRACE: 08:31:56.541521 agent.go:526: pinging all candidates
ice TRACE: 08:31:56.741881 agent.go:526: pinging all candidates
ice TRACE: 08:31:56.942234 agent.go:526: pinging all candidates
ice TRACE: 08:31:57.142632 agent.go:526: pinging all candidates
ice TRACE: 08:31:57.343074 agent.go:526: pinging all candidates
ice TRACE: 08:31:57.543511 agent.go:526: pinging all candidates
ice TRACE: 08:31:57.743967 agent.go:526: pinging all candidates
ice TRACE: 08:31:57.944415 agent.go:526: pinging all candidates
ice TRACE: 08:31:58.144890 agent.go:526: pinging all candidates
ice TRACE: 08:31:58.345324 agent.go:526: pinging all candidates
ice TRACE: 08:31:58.545807 agent.go:526: pinging all candidates
ice TRACE: 08:31:58.746251 agent.go:526: pinging all candidates
ice TRACE: 08:31:58.946716 agent.go:526: pinging all candidates
ice TRACE: 08:31:59.147150 agent.go:526: pinging all candidates
ice TRACE: 08:31:59.347558 agent.go:526: pinging all candidates
ice TRACE: 08:31:59.547995 agent.go:526: pinging all candidates
ice TRACE: 08:31:59.748455 agent.go:526: pinging all candidates
ice TRACE: 08:31:59.948891 agent.go:526: pinging all candidates
ice TRACE: 08:32:00.149363 agent.go:526: pinging all candidates
ice TRACE: 08:32:00.349801 agent.go:526: pinging all candidates
ice TRACE: 08:32:00.550266 agent.go:526: pinging all candidates
ice TRACE: 08:32:00.750697 agent.go:526: pinging all candidates
ice TRACE: 08:32:00.951164 agent.go:526: pinging all candidates
ice TRACE: 08:32:01.151546 agent.go:526: pinging all candidates
ice TRACE: 08:32:01.352003 agent.go:526: pinging all candidates
ice TRACE: 08:32:01.552492 agent.go:526: pinging all candidates
ice WARNING: 2023/05/26 08:32:01 Failed to read from candidate tcp4 host 54.196.153.204:8443: io: read/write on closed pipe
ice WARNING: 2023/05/26 08:32:01 Failed to read from candidate tcp4 host 172.27.134.52:8443: io: read/write on closed pipe
ice INFO: 2023/05/26 08:32:01 Setting new connection state: Failed
ice INFO: 2023/05/26 08:32:01 Setting new connection state: Closed
@streamer45 streamer45 mentioned this issue May 26, 2023
Merged
@streamer45
Copy link
Author

This appears to be somewhat similar to #505 but the problem does not appear to be the same connection getting closed but more like any subsequent connection with the same address so simply ignoring duplicate candidates isn't helping.

@cnderrauber Wondering if you have any clue on what could be causing this, whether a misconfiguration or else.

@cnderrauber
Copy link
Member

Your config looks weird, is there a special reason to map the loopback ip to an external ip? I don't think it can work as the external traffic will only arrive to your private ip 172.x

@streamer45
Copy link
Author

Your config looks weird, is there a special reason to map the loopback ip to an external ip? I don't think it can work as the external traffic will only arrive to your private ip 172.x

Indeed that's a bit weird but since it was working fine in the MultiUDPMux case (see #541) I just kept that unchanged. But for MultiTCPMux, even passing something that makes more sense like [54.196.153.204/172.27.134.52 127.0.0.1/127.0.0.1] to sEngine.SetNAT1To1IPs() is not working. Is that expected as well?

@cnderrauber
Copy link
Member

cnderrauber commented May 29, 2023 •
edited
Loading

If your are trying to make tcp mux listening on a single port of all interfaces, you don't need a MultiTCPMux. I think it is designed for listening on multiple tcp ports. You can refer to the livekit for the correct usage in your case, also with correct nat mapping

		networkTypes = append(networkTypes,
			webrtc.NetworkTypeTCP4, webrtc.NetworkTypeTCP6,
		)
		tcpListener, err = net.ListenTCP("tcp", &net.TCPAddr{
			Port: int(rtcConf.TCPPort),
		})
		if err != nil {
			return nil, err
		}

		tcpMux := ice.NewTCPMuxDefault(ice.TCPMuxParams{
			Logger:          s.LoggerFactory.NewLogger("tcp_mux"),
			Listener:        tcpListener,
			ReadBufferSize:  readBufferSize,
			WriteBufferSize: writeBufferSizeInBytes,
		})

		s.SetICETCPMux(tcpMux)

@streamer45
Copy link
Author

That's likely the key misconception on my part. I implicitly thought MultiTCPMux was the tcp alternative to MultiUDPMux which I've been using on connections to a single port but I suppose they differ in some important details and are not fully symmetric in behaviour. I'll simplify this case then (listen on all interfaces) by using a simple TCPMux and providing the port only as you suggested.

I appreciate your help on this, thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@streamer45 @cnderrauber