Failure to use correct IP address on reconnect to UDP P2P server (t_server 11t)
Nobody has claimed this yet.
- Dominant language
- C
- Stars
- 14.6k
- Forks
- 3.4k
- PR merge metrics
- No merged PRs in 30d
Description
Describe the bug
A clear and concise description of what the bug is.
To Reproduce
This is a problem I'm facing when running the t_server tests. The test 11t is failing.
The 11 set of tests is running against server tun-udp-p2p-tls-sha256.
11t is a test that connects 400 seconds (at least one tls soft reset) after 11a finished. 11a uses proto udp6 while 11t is using proto udp4.
Expected behavior
11t is supposed to succeed in connecting to the server.
Version information (please complete the following information):
- OS: Rocky 9
- OpenVPN version: master
Additional context
Verb 9 log of a failing connect on server side:
Jun 19 11:14:49 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: I/O WAIT status=0x0020
Jun 19 11:14:49 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=0 state=S_INITIAL, mysid=b34ce21e 1b964e7a, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Jun 19 11:14:49 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=1 state=S_PRE_START, mysid=0f98d627 5f3b12ea, stored-sid=00000000 00000000, stored-ip=[AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726
Jun 19 11:14:49 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_process: chg=1 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
Jun 19 11:14:49 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK reliable_can_send active=1 current=0 : [1] 0
Jun 19 11:14:49 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK reliable_send_timeout 1 [1] 0
Jun 19 11:14:49 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_process: timeout set to 1
Jun 19 11:14:49 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=2 state=S_ERROR, mysid=243440d8 16c21a49, stored-sid=1da8fe70 b4b31abe, stored-ip=[AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726
Jun 19 11:14:49 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: RANDOM USEC=124388
Jun 19 11:14:49 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_CTL rwflags=0x0001 ev=5 arg=0x02202db0
Jun 19 11:14:49 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_CTL rwflags=0x0001 ev=4 arg=0x00000002
Jun 19 11:14:49 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: I/O WAIT TR|Tw| [1/124388]#012 SR|Sw
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: event_wait returned 0
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: I/O WAIT status=0x0020
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=0 state=S_INITIAL, mysid=b34ce21e 1b964e7a, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=1 state=S_PRE_START, mysid=0f98d627 5f3b12ea, stored-sid=00000000 00000000, stored-ip=[AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_process: chg=1 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK reliable_can_send active=1 current=1 : [1] 0
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK reliable_send ID 0 (size=4 to=32)
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: write_control_auth(): P_CONTROL_HARD_RESET_SERVER_V2
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: Reliable -> TCP/UDP
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK reliable_send_timeout 32 [1] 0
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_process: timeout set to 30
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=2 state=S_ERROR, mysid=243440d8 16c21a49, stored-sid=1da8fe70 b4b31abe, stored-ip=[AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_CTL rwflags=0x0003 ev=5 arg=0x02202db0
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_CTL rwflags=0x0000 ev=4 arg=0x00000002
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: I/O WAIT Tr|Tw| [15/124388]#012 SR|SW
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_WAIT[0,0] fd=5 rev=0x00000004 rwflags=0x0002 arg=0x02202db0
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: event_wait returned 1
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: I/O WAIT status=0x0002
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: UDPv6 WRITE [14] to [AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 sid=0f98d627 5f3b12ea [ ] pid=0 DATA
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: UDPv6 write returned 14
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=0 state=S_INITIAL, mysid=b34ce21e 1b964e7a, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=1 state=S_PRE_START, mysid=0f98d627 5f3b12ea, stored-sid=00000000 00000000, stored-ip=[AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_process: chg=1 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK reliable_can_send active=1 current=0 : [1] 0
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK reliable_send_timeout 32 [1] 0
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_process: timeout set to 30
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=2 state=S_ERROR, mysid=243440d8 16c21a49, stored-sid=1da8fe70 b4b31abe, stored-ip=[AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_CTL rwflags=0x0001 ev=5 arg=0x02202db0
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_CTL rwflags=0x0001 ev=4 arg=0x00000002
Jun 19 11:14:50 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: I/O WAIT TR|Tw| [15/124388]#012 SR|Sw
Jun 19 11:15:06 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: event_wait returned 0
Jun 19 11:15:06 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: I/O WAIT status=0x0020
Jun 19 11:15:06 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=0 state=S_INITIAL, mysid=b34ce21e 1b964e7a, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Jun 19 11:15:06 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=1 state=S_PRE_START, mysid=0f98d627 5f3b12ea, stored-sid=00000000 00000000, stored-ip=[AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726
Jun 19 11:15:06 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_process: chg=1 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
Jun 19 11:15:06 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK reliable_can_send active=1 current=0 : [1] 0
Jun 19 11:15:06 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK reliable_send_timeout 16 [1] 0
Jun 19 11:15:06 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_process: timeout set to 14
Jun 19 11:15:06 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=2 state=S_ERROR, mysid=243440d8 16c21a49, stored-sid=1da8fe70 b4b31abe, stored-ip=[AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726
Jun 19 11:15:06 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: RANDOM USEC=32299
Jun 19 11:15:06 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_CTL rwflags=0x0001 ev=5 arg=0x02202db0
Jun 19 11:15:06 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_CTL rwflags=0x0001 ev=4 arg=0x00000002
Jun 19 11:15:06 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: I/O WAIT TR|Tw| [14/32299]#012 SR|Sw
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: event_wait returned 0
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: I/O WAIT status=0x0020
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=0 state=S_INITIAL, mysid=b34ce21e 1b964e7a, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=1 state=S_PRE_START, mysid=0f98d627 5f3b12ea, stored-sid=00000000 00000000, stored-ip=[AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_process: chg=1 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS Error: TLS handshake failed
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_process: chg=1 ks=S_ERROR_PRE lame=S_UNDEF to_link->len=0 wakeup=604800
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK reliable_can_send active=1 current=0 : [1] 0
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PID packet_id_free
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PID packet_id_free
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PID packet_id_free
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_session_init: entry
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PID packet_id_init seq_backtrack=64 time_backtrack=15
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PID packet_id_init seq_backtrack=64 time_backtrack=15
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_session_init: new session object, sid=cb3aeab3 3df01914
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=2 state=S_ERROR, mysid=243440d8 16c21a49, stored-sid=1da8fe70 b4b31abe, stored-ip=[AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: RANDOM USEC=11391
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_CTL rwflags=0x0001 ev=5 arg=0x02202db0
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_CTL rwflags=0x0001 ev=4 arg=0x00000002
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: I/O WAIT TR|Tw| [15/11391]#012 SR|Sw
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_WAIT[0,0] fd=5 rev=0x00000001 rwflags=0x0001 arg=0x02202db0
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: event_wait returned 1
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: I/O WAIT status=0x0001
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: UDPv6 read returned 14
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: UDPv6 READ [14] from [AF_INET6]::ffff:10.151.0.83:37857: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 sid=adb87f7d 567375f6 [ ] pid=0 DATA
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: control channel, op=P_CONTROL_HARD_RESET_CLIENT_V2, IP=[AF_INET6]::ffff:10.151.0.83:37857
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: initial packet test, i=0 state=S_INITIAL, mysid=b34ce21e 1b964e7a, rec-sid=adb87f7d 567375f6, rec-ip=[AF_INET6]::ffff:10.151.0.83:37857, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: initial packet test, i=1 state=S_INITIAL, mysid=cb3aeab3 3df01914, rec-sid=adb87f7d 567375f6, rec-ip=[AF_INET6]::ffff:10.151.0.83:37857, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: initial packet test, i=2 state=S_ERROR, mysid=243440d8 16c21a49, rec-sid=adb87f7d 567375f6, rec-ip=[AF_INET6]::ffff:10.151.0.83:37857, stored-sid=1da8fe70 b4b31abe, stored-ip=[AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: Initial packet from [AF_INET6]::ffff:10.151.0.83:37857, sid=adb87f7d 567375f6
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: Session State 1 i=1 state=S_INITIAL, mysid=cb3aeab3 3df01914, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: Session State NEW i=1 state=S_INITIAL, mysid=cb3aeab3 3df01914, stored-sid=adb87f7d 567375f6, stored-ip=[AF_INET6]::ffff:10.151.0.83:37857
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK reliable_schedule_now
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK read ID 0 (buf->len=0)
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK RWBS rel->size=12 rel->packet_id=00000000 id=00000000 ret=1
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK mark active incoming ID 0
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK acknowledge ID 0 (ack->len=1)
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: Session State DONE i=1 state=S_INITIAL, mysid=cb3aeab3 3df01914, stored-sid=adb87f7d 567375f6, stored-ip=[AF_INET6]::ffff:10.151.0.83:37857
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=0 state=S_INITIAL, mysid=b34ce21e 1b964e7a, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process override remote addr: i=1 state=S_INITIAL, stored-ip=[AF_INET6]::ffff:10.151.0.83:37857 actual-ip=[AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=cb3aeab3 3df01914, stored-sid=adb87f7d 567375f6, stored-ip=[AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_process: chg=1 ks=S_INITIAL lame=S_UNDEF to_link->len=0 wakeup=604800
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK mark active outgoing ID 0
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: Initial Handshake, sid=cb3aeab3 3df01914
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK reliable_can_send active=1 current=1 : [1] 0
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK reliable_send ID 0 (size=4 to=2)
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK write ID 0 (ack->len=1, n=1)
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: write_control_auth(): P_CONTROL_HARD_RESET_SERVER_V2
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: Reliable -> TCP/UDP
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK reliable_send_timeout 2 [1] 0
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_process: timeout set to 2
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=2 state=S_ERROR, mysid=243440d8 16c21a49, stored-sid=1da8fe70 b4b31abe, stored-ip=[AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_CTL rwflags=0x0003 ev=5 arg=0x02202db0
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_CTL rwflags=0x0000 ev=4 arg=0x00000002
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: I/O WAIT Tr|Tw| [2/11391]#012 SR|SW
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_WAIT[0,0] fd=5 rev=0x00000004 rwflags=0x0002 arg=0x02202db0
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: event_wait returned 1
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: I/O WAIT status=0x0002
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: UDPv6 WRITE [26] to [AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 sid=cb3aeab3 3df01914 [ 0 sid=adb87f7d 567375f6 ] pid=0 DATA
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: UDPv6 write returned 26
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=0 state=S_INITIAL, mysid=b34ce21e 1b964e7a, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=1 state=S_PRE_START, mysid=cb3aeab3 3df01914, stored-sid=adb87f7d 567375f6, stored-ip=[AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_process: chg=1 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK reliable_can_send active=1 current=0 : [1] 0
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: SSL state (accept): before SSL initialization
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: ACK reliable_send_timeout 2 [1] 0
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_process: timeout set to 2
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: tls_multi_process: i=2 state=S_ERROR, mysid=243440d8 16c21a49, stored-sid=1da8fe70 b4b31abe, stored-ip=[AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_CTL rwflags=0x0001 ev=5 arg=0x02202db0
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_CTL rwflags=0x0001 ev=4 arg=0x00000002
Jun 19 11:15:20 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: I/O WAIT TR|Tw| [2/11391]#012 SR|Sw
Jun 19 11:15:22 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: PO_WAIT[0,0] fd=5 rev=0x00000001 rwflags=0x0001 arg=0x02202db0
Jun 19 11:15:22 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: event_wait returned 1
Jun 19 11:15:22 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: I/O WAIT status=0x0001
Jun 19 11:15:22 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: UDPv6 read returned 14
Jun 19 11:15:22 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: UDPv6 READ [14] from [AF_INET6]::ffff:10.151.0.83:37857: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 sid=adb87f7d 567375f6 [ ] pid=0 DATA
Jun 19 11:15:22 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: control channel, op=P_CONTROL_HARD_RESET_CLIENT_V2, IP=[AF_INET6]::ffff:10.151.0.83:37857
Jun 19 11:15:22 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: initial packet test, i=0 state=S_INITIAL, mysid=b34ce21e 1b964e7a, rec-sid=adb87f7d 567375f6, rec-ip=[AF_INET6]::ffff:10.151.0.83:37857, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Jun 19 11:15:22 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: initial packet test, i=1 state=S_PRE_START, mysid=cb3aeab3 3df01914, rec-sid=adb87f7d 567375f6, rec-ip=[AF_INET6]::ffff:10.151.0.83:37857, stored-sid=adb87f7d 567375f6, stored-ip=[AF_INET6]2a05:d014:1f13:8002:1ce9:87ec:a7e8:4967:57726
Jun 19 11:15:22 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS: found match, session[1], sid=adb87f7d 567375f6
Jun 19 11:15:22 tserver-rocky-9-amd64 tun-udp-p2p-tls-sha256[89986]: TLS Error: Received control packet from unexpected IP addr: [AF_INET6]::ffff:10.151.0.83:37857
The interesting part starts at 11:15:20 but I left some context in the log. Some of the log output is from additional logging I added to the server. As we can see there is still the IPv6 address from 11a present in the state. After the new packet is received over IPv4 everything looks fine in tls_pre_decrypt but then on the next call to tls_process_multi ks->remove_addr is overridden with the obsolete IPv6 address. That seems wrong.
Contributor guide
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start by reproducing the t_server test 11t against tun-udp-p2p-tls-sha256 and compare it with 11a, noting the UDPv6-to-UDPv4 transition after the TLS soft reset. Trace how the reconnect chooses its peer address using the verbose server log. Done means test 11t successfully reconnects to the server using the correct IP address.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- c
- Domain
- networking
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Quiet
- Clarity
- Mostly clear
- Newbie friendliness
- 45/100