rust server & libev client: UDP does not work #855

piangere · 2022-06-01T16:13:19Z

Case 1:
Server: rust 1.15.0-alpha.4
Client: libev 3.3.5
udp does not work

Case 2
Server: rust 1.15.0-alpha.4
Client: rust 1.14.3
udp works

Case 3:
Server: libev 3.3.5
Client: libev 3.3.5
udp works

Case 4:
Server: libev 3.3.5
Client: rust 1.14.3
udp works

zonyitoo · 2022-06-02T02:05:50Z

At least tell everybody how to reproduce.

piangere · 2022-06-02T02:27:56Z

Case 1:
Server: rust 1.15.0-alpha.4

/usr/local/bin/ssserver -c /etc/shadowsocks-libev/config.json

cat /etc/shadowsocks-libev/config.json
{
    "server":"0.0.0.0",
    "server_port":83,
    "password":"*",
    "timeout":60,
    "method":"aes-256-gcm",
    "mode":"tcp_and_udp",
    "fast_open":true
}

Client: libev 3.3.5

ss-redir -c /koolshare/ss/ss.json -u --reuse-port -f /var/run/ss_1.pid

cat /koolshare/ss/ss.json
{
    "server":"*",
    "server_port":83,
    "local_address":"0.0.0.0",
    "local_port":3333,
    "password":"*",
    "timeout":600,
    "method":"aes-256-gcm"
}

My router is with full cone NAT.

with this setup:

tcp works
udp does not work

Note: it can't be network issue since case2 work fine with UDP.

I test with dota2 server. Case 1 cannot ping any server while case 2, case 3, case 4 can.

I also test whether UDP works with nslookup and as you can see, case 1 does not work.

$ nslookup twitter.com 8.8.8.8
;; connection timed out; no servers could be reached

When UDP works (case2):

$ nslookup twitter.com 8.8.8.8
Server:         8.8.8.8
Address:        8.8.8.8#53

Non-authoritative answer:
Name:   twitter.com
Address: 104.244.42.65
Name:   twitter.com
Address: 104.244.42.129

zonyitoo · 2022-06-02T10:04:22Z

What did you see when using Case1 in ssserver's log? Could you see any logs about UDP?

piangere · 2022-06-02T10:22:20Z

What did you see when using Case1 in ssserver's log? Could you see any logs about UDP?

case 1:

Server: rust 1.15.0-alpha.4
Client: libev 3.3.5. ss-redir in router

a computer beneath router:

~$ nslookup twitter.com 8.8.8.8
;; connection timed out; no servers could be reached

Server

2022-06-02T06:12:22.510825898-04:00 DEBUG [793:140644057778688] [shadowsocks_service::server::udprelay] created udp association for xx.xx.xx.xx:58470

xx.xx.xx.xx is the WAN ip of my router.

case 2:

Server: rust 1.15.0-alpha.4
Client: rust 1.14.3. sslocal redir mode in router

a computer beneath router:

~$ nslookup twitter.com 8.8.8.8
Server:         8.8.8.8
Address:        8.8.8.8#53

Non-authoritative answer:
Name:   twitter.com
Address: 104.244.42.129
Name:   twitter.com
Address: 104.244.42.193

Server

2022-06-02T06:13:28.566963125-04:00 DEBUG [793:140644057778688] [shadowsocks_service::server::udprelay] created udp association for xx.xx.xx.xx:33067
2022-06-02T06:13:28.703817474-04:00 DEBUG [793:140644057778688] [shadowsocks_service::server::udprelay] created udp association for xx.xx.xx.xx:34590

xx.xx.xx.xx is the WAN ip of my router.

case 3 & case 4

I can confirm nslookup works. Since the server is libev not rust, it's not the focus of the issue.

Difference

in case 1, ssserver logs 1 record
in case 2, ssserver logs 2 record2

It looks like in case 1:

libev redir ---> ssserver ---> 8.8.8.8: working
8.8.8.8 ---> ssserver --X-> libev redir: not working
or, is it (I am not sure how UDP works with shadowsocks)
8.8.8.8 --X-> libev redir?

It's some interoperability issue.

zonyitoo · 2022-06-02T10:54:47Z

You should try to enable higher log level, for example -vvv.

The line created udp association ... indicated that ssserver receives an UDP association packet from a new client, so it was going to create a new association for it.

So if you can see 2 lines of logs, then there must be 2 individual clients (or sockets) were created and send 2 UDP packets to ssserver.

And yes,

CLIENT -> libev-sslocal -> ssserver -> 8.8.8.8
CLIENT <- libev-sslocal <- ssserver <- 8.8.8.8

You should add -vvv on ssserver and see if it receives responses from 8.8.8.8.

piangere · 2022-06-02T14:22:27Z

Here you are:

case 1:

CLIENT -> libev ss-redir -> rust ssserver -> 8.8.8.8

2022-06-02T10:14:25.346354261-04:00 TRACE [1565:139851401037568] [shadowsocks::relay::udprelay::aead] UDP packet got AEAD salt b"\xed\xf9\x11|\xf5\xaf&6x]\xac\xb9\xb1\x1c\xec\xdf\x90\xbf\xb0\xdf\xd1\xfc\xdb\x983u\xfd\x1d\x99\x95\xffS"
2022-06-02T10:14:25.346608037-04:00 TRACE [1565:139851401037568] [shadowsocks::relay::udprelay::proxy_socket] UDP server client receive from xx.xx.xx.xx:52772, addr 8.8.8.8:53, control: None, packet length 84 bytes, payload length 29 bytes
2022-06-02T10:14:25.346993232-04:00 DEBUG [1565:139851401042432] [shadowsocks_service::server::udprelay] created udp association for xx.xx.xx.xx:52772
2022-06-02T10:14:25.347254650-04:00 TRACE [1565:139851398936320] [shadowsocks_service::server::udprelay] udp relay xx.xx.xx.xx:52772 -> 8.8.8.8:53 with 29 bytes, control: None
2022-06-02T10:14:25.348478684-04:00 TRACE [1565:139851398936320] [shadowsocks_service::server::udprelay] udp relay xx.xx.xx.xx:52772 <- [::ffff:8.8.8.8]:53 received 61 bytes
2022-06-02T10:14:25.348927140-04:00 TRACE [1565:139851398936320] [shadowsocks::relay::udprelay::aead] UDP packet generated aead salt b"^\xdc\x9dQ\x9c\xf7\xb7\\\xf8^\xc2\xa4$\xdb\x9f*mS\xf1cl\x99\x89\xa5\xf7\xd9\xc5\xd8J\'/\x0f"
2022-06-02T10:14:25.350032864-04:00 TRACE [1565:139851398936320] [shadowsocks::relay::udprelay::proxy_socket] UDP server client send to, addr [::ffff:8.8.8.8]:53, control: UdpSocketControlData { client_session_id: 0, server_session_id: 0, packet_id: 0 }, payload length 61 bytes, packet length 128 bytes
2022-06-02T10:14:25.350505598-04:00 TRACE [1565:139851398936320] [shadowsocks_service::server::udprelay] udp relay xx.xx.xx.xx:52772 <- [::ffff:8.8.8.8]:53 with 61 bytes
2022-06-02T10:14:30.350542210-04:00 TRACE [1565:139851398936320] [shadowsocks::relay::udprelay::aead] UDP packet got AEAD salt b"\xb1*\xa72h\xd1\xf5B\x1d\xba\xec\xe1R\xe72\x02\x08Fb\x8fU\x0fm\xa8\x1a\xda-uZ4\xf0\x16"
2022-06-02T10:14:30.351088534-04:00 TRACE [1565:139851398936320] [shadowsocks::relay::udprelay::proxy_socket] UDP server client receive from xx.xx.xx.xx:52772, addr 8.8.8.8:53, control: None, packet length 84 bytes, payload length 29 bytes
2022-06-02T10:14:30.351358848-04:00 TRACE [1565:139851398936320] [shadowsocks_service::server::udprelay] udp relay xx.xx.xx.xx:52772 -> 8.8.8.8:53 with 29 bytes, control: None
2022-06-02T10:14:30.352053293-04:00 TRACE [1565:139851401037568] [shadowsocks_service::server::udprelay] udp relay xx.xx.xx.xx:52772 <- [::ffff:8.8.8.8]:53 received 61 bytes
2022-06-02T10:14:30.352214921-04:00 TRACE [1565:139851401037568] [shadowsocks::relay::udprelay::aead] UDP packet generated aead salt b"\xd0g\xc3\xc0\x8do\xf8\x9eYx\x97\x81\xa1\xd24\x03-h\x1fw\xfc\xdf\xa9\xbe d\xf6\x81\x04t1R"
2022-06-02T10:14:30.352570751-04:00 TRACE [1565:139851401037568] [shadowsocks::relay::udprelay::proxy_socket] UDP server client send to, addr [::ffff:8.8.8.8]:53, control: UdpSocketControlData { client_session_id: 0, server_session_id: 0, packet_id: 0 }, payload length 61 bytes, packet length 128 bytes
2022-06-02T10:14:30.352769184-04:00 TRACE [1565:139851401037568] [shadowsocks_service::server::udprelay] udp relay xx.xx.xx.xx:52772 <- [::ffff:8.8.8.8]:53 with 61 bytes
2022-06-02T10:14:35.353380145-04:00 TRACE [1565:139851401037568] [shadowsocks::relay::udprelay::aead] UDP packet got AEAD salt b"fW\xba\x8cn\xef\x81\xdf\xcc\xedj\x12\x1eF\xfb/\x08=\x19\xa6\x81*\xf3\xd3N\xab\x80x\x9b\xacd\\"
2022-06-02T10:14:35.353683854-04:00 TRACE [1565:139851401037568] [shadowsocks::relay::udprelay::proxy_socket] UDP server client receive from xx.xx.xx.xx:52772, addr 8.8.8.8:53, control: None, packet length 84 bytes, payload length 29 bytes
2022-06-02T10:14:35.353907136-04:00 TRACE [1565:139851401037568] [shadowsocks_service::server::udprelay] udp relay xx.xx.xx.xx:52772 -> 8.8.8.8:53 with 29 bytes, control: None
2022-06-02T10:14:35.354505286-04:00 TRACE [1565:139851398936320] [shadowsocks_service::server::udprelay] udp relay xx.xx.xx.xx:52772 <- [::ffff:8.8.8.8]:53 received 61 bytes
2022-06-02T10:14:35.354677916-04:00 TRACE [1565:139851398936320] [shadowsocks::relay::udprelay::aead] UDP packet generated aead salt b")\xc3\x8e7\xfb\'1\xbbY\x1a%b\x0f\x93\x83\xd8,\xbd\x11\xeek\xd1\xb6\xf9f>\xb9\x03\x01#\xd0\\"
2022-06-02T10:14:35.355085907-04:00 TRACE [1565:139851398936320] [shadowsocks::relay::udprelay::proxy_socket] UDP server client send to, addr [::ffff:8.8.8.8]:53, control: UdpSocketControlData { client_session_id: 0, server_session_id: 0, packet_id: 0 }, payload length 61 bytes, packet length 128 bytes
2022-06-02T10:14:35.355286573-04:00 TRACE [1565:139851398936320] [shadowsocks_service::server::udprelay] udp relay xx.xx.xx.xx:52772 <- [::ffff:8.8.8.8]:53 with 61 bytes
2022-06-02T10:14:35.874949843-04:00 TRACE [1565:139851401042432] [shadowsocks::relay::tcprelay::crypto_io] generated AEAD cipher salt b"\xa3\xf0\xcd\x1b<cj\x96\xa2\xc5\xcf\x03;\xd1\xb2i\xf8\xee\x05-U^\xcd\xcb\xd1\xd1\xc3\xe7&\x98\xce\xb0"
2022-06-02T10:14:35.876398443-04:00 TRACE [1565:139851398936320] [shadowsocks::relay::tcprelay::aead] got AEAD salt b"|\x06T\x03&\x1a\xe4\xdd\xe9n\x8b\xea\x06A\x12\xaaT\x7f\x06\xb3\x7f\x05qi\x0e\xac\xe2a\x89|dx"
2022-06-02T10:14:35.876643955-04:00 TRACE [1565:139851398936320] [shadowsocks_service::server::tcprelay] accepted tcp client connection xx.xx.xx.xx:43717, establishing tunnel to 8.8.8.8:53
2022-06-02T10:14:35.877062772-04:00 DEBUG [1565:139851401037568] [shadowsocks_service::server::tcprelay] established tcp tunnel xx.xx.xx.xx:43717 <-> 8.8.8.8:53 with ConnectOpts { fwmark: None, bind_local_addr: None, bind_interface: None, tcp: TcpSocketOpts { send_buffer_size: None, recv_buffer_size: None, nodelay: false, fastopen: true, keepalive: Some(15s) } }
2022-06-02T10:14:36.024542301-04:00 TRACE [1565:139851401037568] [shadowsocks_service::server::tcprelay] tcp tunnel xx.xx.xx.xx:43717 <-> 8.8.8.8:53 closed, L2R 0 bytes, R2L 112 bytes

case 2:

CLIENT -> rust sslocal redir mode -> rust ssserver -> 8.8.8.8

rust sslocal redir mode setting:

sslocal --protocol redir -b 0.0.0.0:3333 -s *.*.*.*:83 -m aes-256-gcm -k ***** --tcp-redir redirect --udp-redir tproxy -U -d

2022-06-02T10:15:47.148040647-04:00 TRACE [1565:139851401037568] [shadowsocks::relay::udprelay::aead] UDP packet got AEAD salt b"\xb6\t^\xae\xb8Ux9c\x9az\x01\xe90,\xa9V\xd6\x05\xdd\xb8\xd3\x8d\xa9\x85\x8dN7!\x17\x90J"
2022-06-02T10:15:47.149099636-04:00 TRACE [1565:139851401037568] [shadowsocks::relay::udprelay::proxy_socket] UDP server client receive from xx.xx.xx.xx:49383, addr 8.8.8.8:53, control: None, packet length 84 bytes, payload length 29 bytes
2022-06-02T10:15:47.149402036-04:00 DEBUG [1565:139851401042432] [shadowsocks_service::server::udprelay] created udp association for xx.xx.xx.xx:49383
2022-06-02T10:15:47.151182103-04:00 TRACE [1565:139851401037568] [shadowsocks_service::server::udprelay] udp relay xx.xx.xx.xx:49383 -> 8.8.8.8:53 with 29 bytes, control: None
2022-06-02T10:15:47.152355329-04:00 TRACE [1565:139851398936320] [shadowsocks_service::server::udprelay] udp relay xx.xx.xx.xx:49383 <- [::ffff:8.8.8.8]:53 received 61 bytes
2022-06-02T10:15:47.152749419-04:00 TRACE [1565:139851398936320] [shadowsocks::relay::udprelay::aead] UDP packet generated aead salt b"\xba\xe2\xfd\x8d\xf0\t\xa55\xff\xdaUI\xf8\xcc\x11\xf7v\x914\x85\x04Q\x05\xa4\xe4\xc7a\x8e\x1f>\xd2\xd2"
2022-06-02T10:15:47.154064389-04:00 TRACE [1565:139851398936320] [shadowsocks::relay::udprelay::proxy_socket] UDP server client send to, addr [::ffff:8.8.8.8]:53, control: UdpSocketControlData { client_session_id: 0, server_session_id: 0, packet_id: 0 }, payload length 61 bytes, packet length 128 bytes
2022-06-02T10:15:47.154670500-04:00 TRACE [1565:139851398936320] [shadowsocks_service::server::udprelay] udp relay xx.xx.xx.xx:49383 <- [::ffff:8.8.8.8]:53 with 61 bytes
2022-06-02T10:15:47.297508557-04:00 TRACE [1565:139851398936320] [shadowsocks::relay::udprelay::aead] UDP packet got AEAD salt b"\x94Qpx\xbe\x9a\xc2\x12\xfc\x89\xa7\xd82\xef$\xa0+\xed,#,\x8d\xd9{\x1b\xd1\xc0V2TM\xf9"
2022-06-02T10:15:47.298490216-04:00 TRACE [1565:139851398936320] [shadowsocks::relay::udprelay::proxy_socket] UDP server client receive from xx.xx.xx.xx:46720, addr 8.8.8.8:53, control: None, packet length 84 bytes, payload length 29 bytes
2022-06-02T10:15:47.299088671-04:00 DEBUG [1565:139851401042432] [shadowsocks_service::server::udprelay] created udp association for xx.xx.xx.xx:46720
2022-06-02T10:15:47.299352243-04:00 TRACE [1565:139851401037568] [shadowsocks_service::server::udprelay] udp relay xx.xx.xx.xx:46720 -> 8.8.8.8:53 with 29 bytes, control: None
2022-06-02T10:15:47.300653124-04:00 TRACE [1565:139851398936320] [shadowsocks_service::server::udprelay] udp relay xx.xx.xx.xx:46720 <- [::ffff:8.8.8.8]:53 received 101 bytes
2022-06-02T10:15:47.300920713-04:00 TRACE [1565:139851398936320] [shadowsocks::relay::udprelay::aead] UDP packet generated aead salt b"FKC$1G(&y\xad\xe4\n\x93h\xcdd\x02\xd5!\xea\xa0CWu\xeb\xb6\x11m\xa6\x07H\xb4"
2022-06-02T10:15:47.301271805-04:00 TRACE [1565:139851398936320] [shadowsocks::relay::udprelay::proxy_socket] UDP server client send to, addr [::ffff:8.8.8.8]:53, control: UdpSocketControlData { client_session_id: 0, server_session_id: 0, packet_id: 0 }, payload length 101 bytes, packet length 168 bytes
2022-06-02T10:15:47.301452422-04:00 TRACE [1565:139851398936320] [shadowsocks_service::server::udprelay] udp relay xx.xx.xx.xx:46720 <- [::ffff:8.8.8.8]:53 with 101 bytes

xx.xx.xx.xx is my WAN IP.

zonyitoo · 2022-06-02T15:43:45Z

2022-06-02T10:14:25.348478684-04:00 TRACE [1565:139851398936320] [shadowsocks_service::server::udprelay] udp relay xx.xx.xx.xx:52772 <- [::ffff:8.8.8.8]:53 received 61 bytes

Ok, I know why.

shadowsocks-rust uses IPv6 sockets for outbound, so the received address is always an IPv6 address. As you can see in the logs, 8.8.8.8 becomes an IPv4-mapped-IPv6 address ::ffff:8.8.8.8.

shadowsocks-libev would then create a IPv6 socket and bind to ::ffff:8.8.8.8 and then send back to your client.

https://github.com/shadowsocks/shadowsocks-libev/blob/c2fc967c1a3e4d864d866cc92dd29a04cdb11f98/src/udprelay.c#L904-L916

The (struct sockaddr *)&remote_ctx->src_addr is an IPv4 address, based on your configuration in shadowsocks-libev. So you should see errors like: [udp] remote_recv_sendto.

There are 2 possible solutions for this:

ssserver of shadowsocks-rust converts IPv4-mapped-IPv6 target address back to IPv4 before sending back
shadowsocks-libev converts IPv4-mapped-IPv6 address to IPv4 if the sa_family of src_addr is AF_INET

piangere · 2022-06-02T15:47:52Z

Glad you found the root cause.

Yes, I've not enabled IPv6 on my local network but my proxy server has it enabled. So there's a mismatch.

We should probably support IPv4 and IPv6 mixed scenarios.

zonyitoo · 2022-06-02T15:48:42Z

Did you actually see [udp] remote_recv_sendto in libev's log?

piangere · 2022-06-02T15:51:30Z

Sorry, I've not enabled log for libev.
I think it's fairly easy to reproduce the issue. Maybe you and madeye can work it out?

redir local will always use IPv6 sockets for sending back UDP packets. server will convert IPv4-mapped-IPv6 to IPv4 for maximum compatibilty. ref #855

…nverts to IPv4 ref #855

zonyitoo · 2022-06-03T11:24:26Z

These commits should fix this issue.

piangere · 2022-06-03T14:45:42Z

any test build so I can help verify?

zonyitoo · 2022-06-03T15:49:02Z

https://github.com/shadowsocks/shadowsocks-rust/actions

ref shadowsocks/shadowsocks-rust#855 When receiving UDP packets from remote servers, Redir will have to create transparent sockets to bind() on those target addresses and then relay data back to the local client. Target addresses may be IPv4 or IPv6 addresses, so we may have to create that transprent sockets based on the target addresses' family. The most simpliest and easiest way is to always create IPv6 sockets and converts IPv4 binding addresses and peer addresses to IPv4-mapped-IPv6.

piangere · 2022-06-03T16:27:06Z

I can confirm the latest nightly build fixed case 1. Thanks for your hard work.

ref shadowsocks/shadowsocks-rust#855 When receiving UDP packets from remote servers, Redir will have to create transparent sockets to bind() on those target addresses and then relay data back to the local client. Target addresses may be IPv4 or IPv6 addresses, so we may have to create that transprent sockets based on the target addresses' family. The most simpliest and easiest way is to always create IPv6 sockets and converts IPv4 binding addresses and peer addresses to IPv4-mapped-IPv6.

zonyitoo added a commit that referenced this issue Jun 2, 2022

properly handle IPv4-mapped-IPv6 target addresses in response

c9f7a7b

redir local will always use IPv6 sockets for sending back UDP packets. server will convert IPv4-mapped-IPv6 to IPv4 for maximum compatibilty. ref #855

zonyitoo added a commit that referenced this issue Jun 3, 2022

tun udp target/peer type match, socks5 udp IPv4-mapped-IPv6 always co…

0137258

…nverts to IPv4 ref #855

zonyitoo mentioned this issue Jun 3, 2022

Redir UDP send back sockets should always be IPv6 shadowsocks/shadowsocks-libev#2906

Merged

piangere closed this as completed Jun 3, 2022

dev4u mentioned this issue Jun 5, 2022

upgrade to SIP022 ciphers shadowsocks/shadowsocks-android#2887

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

rust server & libev client: UDP does not work #855

rust server & libev client: UDP does not work #855

piangere commented Jun 1, 2022

zonyitoo commented Jun 2, 2022 •

edited

Loading

piangere commented Jun 2, 2022 •

edited

Loading

zonyitoo commented Jun 2, 2022

piangere commented Jun 2, 2022 •

edited

Loading

zonyitoo commented Jun 2, 2022

piangere commented Jun 2, 2022

zonyitoo commented Jun 2, 2022

piangere commented Jun 2, 2022

zonyitoo commented Jun 2, 2022

piangere commented Jun 2, 2022

zonyitoo commented Jun 3, 2022

piangere commented Jun 3, 2022

zonyitoo commented Jun 3, 2022

piangere commented Jun 3, 2022

rust server & libev client: UDP does not work #855

rust server & libev client: UDP does not work #855

Comments

piangere commented Jun 1, 2022

zonyitoo commented Jun 2, 2022 • edited Loading

piangere commented Jun 2, 2022 • edited Loading

zonyitoo commented Jun 2, 2022

piangere commented Jun 2, 2022 • edited Loading

case 1:

case 2:

case 3 & case 4

Difference

zonyitoo commented Jun 2, 2022

piangere commented Jun 2, 2022

case 1:

case 2:

zonyitoo commented Jun 2, 2022

piangere commented Jun 2, 2022

zonyitoo commented Jun 2, 2022

piangere commented Jun 2, 2022

zonyitoo commented Jun 3, 2022

piangere commented Jun 3, 2022

zonyitoo commented Jun 3, 2022

piangere commented Jun 3, 2022

zonyitoo commented Jun 2, 2022 •

edited

Loading

piangere commented Jun 2, 2022 •

edited

Loading

piangere commented Jun 2, 2022 •

edited

Loading