dndx / phantun

Transforms UDP stream into (fake) TCP streams that can go through Layer 3 & Layer 4 (NAPT) firewalls/NATs.
Apache License 2.0
1.58k stars 128 forks source link

Occasionally disconnected after being connected for a few days #147

Closed resticDOG closed 7 months ago

resticDOG commented 7 months ago

Server

Client

Anomalies

I have successfully set up and run a Wireguard service on OpenWrt 22.03.5 (aarch64) using Phantun Server 0.6.0. However, I've recently encountered issues with network services connected via Phantun faketcp. While direct connections via Wireguard remain functional, attempts to access network services through Phantun faketcp have failed.

I used iperf3 to evaluate network performance and found that the first three packets sent from the server are not received correctly, but subsequent packets are received normally. Upon inspecting the packets with tcpdump, it appears there might be anomalies in their structure. Below are relevant logs with sensitive information redacted:

Server Log

 ~ RUST_LOG=TRACE /usr/bin/phantun_server --local 25379 --remote 127.0.0.1:25378
 INFO  server > Remote address is: 127.0.0.1:25378
 INFO  server > 4 cores available
 TRACE mio::poll > registering event source with poller: token=Token(1), interests=READABLE | WRITABLE
 TRACE mio::poll > registering event source with poller: token=Token(2), interests=READABLE | WRITABLE
 TRACE mio::poll > registering event source with poller: token=Token(3), interests=READABLE | WRITABLE
 TRACE mio::poll > registering event source with poller: token=Token(4), interests=READABLE | WRITABLE
 DEBUG neli::socket > Message sent:
Nlmsghdr { nl_len: 64, nl_type: Newaddr, nl_flags: NlmFFlags(FlagBuffer(1, PhantomData)), nl_seq: 0, nl_pid: 0, nl_payload: Payload(Ifaddrmsg { ifa_family: Inet6, ifa_prefixlen: 128, ifa_flags: IfaFFlags(FlagBuffer(0, PhantomData)), ifa_scope: 0, ifa_index: 51, rtattrs: RtBuffer([Rtattr { rta_len: 20, rta_type: Local, rta_payload: Buffer }, Rtattr { rta_len: 20, rta_type: Address, rta_payload: Buffer }]) }) }
 INFO  server       > Created TUN device tun0
 INFO  server       > Listening on 25379
 TRACE fake_tcp     > Cache miss, checking the shared tuples table for connection
 INFO  fake_tcp     > Sent SYN + ACK to client
 TRACE fake_tcp     > Cache miss, checking the shared tuples table for connection
 TRACE fake_tcp     > Storing connection information into local tuples
 INFO  fake_tcp     > Connection from {MyClientPublicIP}:2890 established
 INFO  server       > New connection: (Fake TCP connection from 192.168.201.2:25379 to {MyClientPublicIP}:2890)
 TRACE mio::poll    > registering event source with poller: token=Token(5), interests=READABLE | WRITABLE
 TRACE mio::poll    > deregistering event source from poller
 TRACE mio::poll    > registering event source with poller: token=Token(16777221), interests=READABLE | WRITABLE
 TRACE mio::poll    > registering event source with poller: token=Token(6), interests=READABLE | WRITABLE
 TRACE mio::poll    > registering event source with poller: token=Token(7), interests=READABLE | WRITABLE
 TRACE mio::poll    > registering event source with poller: token=Token(8), interests=READABLE | WRITABLE

Client Log

1月 29 15:58:23 new-business-dev-001 phantun_client[3485905]:  INFO  client > Remote address is: {MyServerIP}:25379
1月 29 15:58:23 new-business-dev-001 phantun_client[3485905]:  INFO  client > 8 cores available
1月 29 15:58:23 new-business-dev-001 phantun_client[3485905]:  TRACE mio::poll > registering event source with poller: token=Token(1), interests=READABLE | WRITABLE
1月 29 15:58:23 new-business-dev-001 phantun_client[3485905]:  TRACE mio::poll > registering event source with poller: token=Token(2), interests=READABLE | WRITABLE
1月 29 15:58:23 new-business-dev-001 phantun_client[3485905]:  TRACE mio::poll > registering event source with poller: token=Token(3), interests=READABLE | WRITABLE
1月 29 15:58:23 new-business-dev-001 phantun_client[3485905]:  TRACE mio::poll > registering event source with poller: token=Token(4), interests=READABLE | WRITABLE
1月 29 15:58:23 new-business-dev-001 phantun_client[3485905]:  TRACE mio::poll > registering event source with poller: token=Token(5), interests=READABLE | WRITABLE
1月 29 15:58:23 new-business-dev-001 phantun_client[3485905]:  TRACE mio::poll > registering event source with poller: token=Token(6), interests=READABLE | WRITABLE
1月 29 15:58:23 new-business-dev-001 phantun_client[3485905]:  TRACE mio::poll > registering event source with poller: token=Token(7), interests=READABLE | WRITABLE
1月 29 15:58:23 new-business-dev-001 phantun_client[3485905]:  TRACE mio::poll > registering event source with poller: token=Token(8), interests=READABLE | WRITABLE
1月 29 15:58:23 new-business-dev-001 phantun_client[3485905]:  INFO  client    > Created TUN device tun0
1月 29 15:58:23 new-business-dev-001 phantun_client[3485905]:  TRACE mio::poll > registering event source with poller: token=Token(9), interests=READABLE | WRITABLE
1月 29 15:58:24 new-business-dev-001 phantun_client[3485905]:  INFO  client    > New UDP client from 127.0.0.1:37885
1月 29 15:58:24 new-business-dev-001 phantun_client[3485905]:  INFO  fake_tcp  > Sent SYN to server
1月 29 15:58:25 new-business-dev-001 phantun_client[3485905]:  INFO  fake_tcp  > Waiting for SYN + ACK timed out
1月 29 15:58:25 new-business-dev-001 phantun_client[3485905]:  INFO  fake_tcp  > Sent SYN to server
1月 29 15:58:26 new-business-dev-001 phantun_client[3485905]:  INFO  fake_tcp  > Waiting for SYN + ACK timed out
1月 29 15:58:26 new-business-dev-001 phantun_client[3485905]:  INFO  fake_tcp  > Sent SYN to server
1月 29 15:58:26 new-business-dev-001 phantun_client[3485905]:  TRACE fake_tcp  > Cache miss, checking the shared tuples table for connection
1月 29 15:58:26 new-business-dev-001 phantun_client[3485905]:  TRACE fake_tcp  > Storing connection information into local tuples
1月 29 15:58:26 new-business-dev-001 phantun_client[3485905]:  INFO  fake_tcp  > Connection to {MyServerIP}:25379 established
1月 29 15:58:26 new-business-dev-001 phantun_client[3485905]:  DEBUG client    > inserted fake TCP socket into connection table
1月 29 15:58:26 new-business-dev-001 phantun_client[3485905]:  TRACE mio::poll > registering event source with poller: token=Token(10), interests=READABLE | WRITABLE
1月 29 15:58:26 new-business-dev-001 phantun_client[3485905]:  TRACE mio::poll > registering event source with poller: token=Token(11), interests=READABLE | WRITABLE
1月 29 15:58:26 new-business-dev-001 phantun_client[3485905]:  TRACE mio::poll > registering event source with poller: token=Token(12), interests=READABLE | WRITABLE
1月 29 15:58:26 new-business-dev-001 phantun_client[3485905]:  TRACE mio::poll > registering event source with poller: token=Token(13), interests=READABLE | WRITABLE
1月 29 15:58:26 new-business-dev-001 phantun_client[3485905]:  TRACE mio::poll > registering event source with poller: token=Token(14), interests=READABLE | WRITABLE
1月 29 15:58:26 new-business-dev-001 phantun_client[3485905]:  TRACE mio::poll > registering event source with poller: token=Token(15), interests=READABLE | WRITABLE
1月 29 15:58:26 new-business-dev-001 phantun_client[3485905]:  TRACE mio::poll > registering event source with poller: token=Token(16), interests=READABLE | WRITABLE
1月 29 15:58:26 new-business-dev-001 phantun_client[3485905]:  TRACE mio::poll > registering event source with poller: token=Token(17), interests=READABLE | WRITABLE

Iperf3 log

❯ iperf3 -c 192.168.5.99 -R -d
send_parameters:
{
        "tcp":  true,
        "omit": 0,
        "time": 10,
        "parallel":     1,
        "reverse":      true,
        "len":  131072,
        "pacing_timer": 1000,
        "client_version":       "3.7"
}
Connecting to host 192.168.5.99, port 5201
Reverse mode, remote host 192.168.5.99 is sending
SNDBUF is 16384, expecting 0
RCVBUF is 131072, expecting 0
Congestion algorithm is cubic
[  5] local 192.168.7.5 port 60572 connected to 192.168.5.99 port 5201
tcpi_snd_cwnd 10 tcpi_snd_mss 1368 tcpi_rtt 13952
interval_len 1.001036 bytes_transferred 0
interval forces keep
[ ID] Interval           Transfer     Bitrate
[  5]   0.00-1.00   sec  0.00 Bytes  0.00 bits/sec
tcpi_snd_cwnd 10 tcpi_snd_mss 1368 tcpi_rtt 13952
interval_len 0.999999 bytes_transferred 0
interval forces keep
[  5]   1.00-2.00   sec  0.00 Bytes  0.00 bits/sec
tcpi_snd_cwnd 10 tcpi_snd_mss 1368 tcpi_rtt 13952
interval_len 1.000002 bytes_transferred 0
interval forces keep
[  5]   2.00-3.00   sec  0.00 Bytes  0.00 bits/sec
tcpi_snd_cwnd 10 tcpi_snd_mss 1368 tcpi_rtt 13952
interval_len 0.999028 bytes_transferred 1045415
interval forces keep
[  5]   3.00-4.00   sec  1021 KBytes  8.37 Mbits/sec
tcpi_snd_cwnd 10 tcpi_snd_mss 1368 tcpi_rtt 13952
interval_len 1.000006 bytes_transferred 3221755
interval forces keep
[  5]   4.00-5.00   sec  3.07 MBytes  25.8 Mbits/sec
tcpi_snd_cwnd 10 tcpi_snd_mss 1368 tcpi_rtt 13952
interval_len 0.999990 bytes_transferred 3212606
interval forces keep
[  5]   5.00-6.00   sec  3.06 MBytes  25.7 Mbits/sec
tcpi_snd_cwnd 10 tcpi_snd_mss 1368 tcpi_rtt 13952
interval_len 1.000000 bytes_transferred 3206071
interval forces keep
[  5]   6.00-7.00   sec  3.06 MBytes  25.6 Mbits/sec
tcpi_snd_cwnd 10 tcpi_snd_mss 1368 tcpi_rtt 13952
interval_len 1.000009 bytes_transferred 3162940
interval forces keep
[  5]   7.00-8.00   sec  3.02 MBytes  25.3 Mbits/sec
tcpi_snd_cwnd 10 tcpi_snd_mss 1368 tcpi_rtt 13952
interval_len 0.999989 bytes_transferred 1767064
interval forces keep
[  5]   8.00-9.00   sec  1.69 MBytes  14.1 Mbits/sec
tcpi_snd_cwnd 10 tcpi_snd_mss 1368 tcpi_rtt 13952
Late receive, state = 4
send_results
{
        "cpu_util_total":       1.0080353033902407,
        "cpu_util_user":        0,
        "cpu_util_system":      1.0080353033902407,
        "sender_has_retransmits":       -1,
        "congestion_used":      "cubic",
        "streams":      [{
                        "id":   1,
                        "bytes":        18334411,
                        "retransmits":  -1,
                        "jitter":       0,
                        "errors":       0,
                        "packets":      0,
                        "start_time":   0,
                        "end_time":     10.000066
                }]
}
get_results
{
        "cpu_util_total":       1.0169800978646832,
        "cpu_util_user":        0.035336917230512563,
        "cpu_util_system":      0.98161321716563155,
        "sender_has_retransmits":       1,
        "congestion_used":      "cubic",
        "streams":      [{
                        "id":   1,
                        "bytes":        18429822,
                        "retransmits":  221,
                        "jitter":       0,
                        "errors":       0,
                        "packets":      0,
                        "start_time":   0,
                        "end_time":     10.012023
                }]
}
interval_len 1.000007 bytes_transferred 2718560
interval forces keep
[  5]   9.00-10.00  sec  2.59 MBytes  21.7 Mbits/sec
- - - - - - - - - - - - - - - - - - - - - - - - -
[ ID] Interval           Transfer     Bitrate         Retr
[  5]   0.00-10.01  sec  17.6 MBytes  14.7 Mbits/sec  221             sender
[  5]   0.00-10.00  sec  17.5 MBytes  14.7 Mbits/sec                  receiver
iperf Done.

Tcpdump log(First Three Entries for iperf3, complete log available here

tcpdump -i any host 192.168.7.5 and port 5201
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on any, link-type LINUX_SLL (Linux cooked v1), capture size 262144 bytes
16:48:51.591529 IP 192.168.7.5.46984 > 192.168.5.99.5201: Flags [S], seq 2781992617, win 64860, options [mss 1380,sackOK,TS val 2505321675 ecr 0,nop,wscale 7], length 0
16:48:51.591798 IP 192.168.5.99.5201 > 192.168.7.5.46984: Flags [S.], seq 1247326741, ack 2781992618, win 65535, options [mss 1380,sackOK,TS val 2304853964 ecr 2505321675,nop,wscale 11], length 0
16:48:51.605154 IP 192.168.7.5.46984 > 192.168.5.99.5201: Flags [.], ack 1, win 507, options [nop,nop,TS val 2505321690 ecr 2304853964], length 0
16:48:51.605408 IP 192.168.7.5.46984 > 192.168.5.99.5201: Flags [P.], seq 1:38, ack 1, win 507, options [nop,nop,TS val 2505321690 ecr 2304853964], length 37
16:48:51.605567 IP 192.168.5.99.5201 > 192.168.7.5.46984: Flags [.], ack 38, win 32, options [nop,nop,TS val 2304853978 ecr 2505321690], length 0
16:48:51.606595 IP 192.168.5.99.5201 > 192.168.7.5.46984: Flags [P.], seq 1:2, ack 38, win 32, options [nop,nop,TS val 2304853979 ecr 2505321690], length 1
16:48:51.619561 IP 192.168.7.5.46984 > 192.168.5.99.5201: Flags [P.], seq 38:42, ack 2, win 507, options [nop,nop,TS val 2505321704 ecr 2304853979], length 4
16:48:51.619724 IP 192.168.7.5.46984 > 192.168.5.99.5201: Flags [.], ack 2, win 507, options [nop,nop,TS val 2505321704 ecr 2304853979], length 0
16:48:51.661953 IP 192.168.5.99.5201 > 192.168.7.5.46984: Flags [.], ack 42, win 32, options [nop,nop,TS val 2304854035 ecr 2505321704], length 0
16:48:51.675931 IP 192.168.7.5.46984 > 192.168.5.99.5201: Flags [P.], seq 42:157, ack 2, win 507, options [nop,nop,TS val 2505321761 ecr 2304854035], length 115
16:48:51.676041 IP 192.168.5.99.5201 > 192.168.7.5.46984: Flags [.], ack 157, win 32, options [nop,nop,TS val 2304854049 ecr 2505321761], length 0
16:48:51.676328 IP 192.168.5.99.5201 > 192.168.7.5.46984: Flags [P.], seq 2:3, ack 157, win 32, options [nop,nop,TS val 2304854049 ecr 2505321761], length 1
16:48:51.689469 IP 192.168.7.5.46984 > 192.168.5.99.5201: Flags [.], ack 3, win 507, options [nop,nop,TS val 2505321774 ecr 2304854049], length 0
16:48:51.689609 IP 192.168.7.5.46992 > 192.168.5.99.5201: Flags [S], seq 1116316938, win 64860, options [mss 1380,sackOK,TS val 2505321774 ecr 0,nop,wscale 7], length 0
16:48:51.689875 IP 192.168.5.99.5201 > 192.168.7.5.46992: Flags [S.], seq 3660800768, ack 1116316939, win 65535, options [mss 1380,sackOK,TS val 2304854062 ecr 2505321774,nop,wscale 11], length 0
16:48:51.703464 IP 192.168.7.5.46992 > 192.168.5.99.5201: Flags [.], ack 1, win 507, options [nop,nop,TS val 2505321789 ecr 2304854062], length 0
16:48:51.703742 IP 192.168.7.5.46992 > 192.168.5.99.5201: Flags [P.], seq 1:38, ack 1, win 507, options [nop,nop,TS val 2505321789 ecr 2304854062], length 37
16:48:51.703882 IP 192.168.5.99.5201 > 192.168.7.5.46992: Flags [.], ack 38, win 32, options [nop,nop,TS val 2304854076 ecr 2505321789], length 0
16:48:51.706427 IP 192.168.5.99.5201 > 192.168.7.5.46984: Flags [P.], seq 3:4, ack 157, win 32, options [nop,nop,TS val 2304854079 ecr 2505321774], length 
resticDOG commented 7 months ago

The issue was not with Phantun but with the upstream device responsible for port forwarding on my server. After restarting that device, everything is working fine now.

dndx commented 7 months ago

Glad to know.