lyc8503 / EasierConnect

NJU EasyConnect 第三方开源 Golang 客户端 / NJU EasyConnect protocol reimplementation in Go
539 stars 124 forks source link

Error occurred while send, retrying: unexpected send handshake reply #17

Open yanlc39 opened 1 year ago

yanlc39 commented 1 year ago

When I was using the socks proxy after the connection has been established, I'll get these. But it had work a while.

panic: send retry limit exceeded.
goroutine 35 [running]:
EasierConnect/core.StartProtocol.func2()
    /Users/***/EasierConnect/core/protocol.go:210 +0xf0
created by EasierConnect/core.StartProtocol
    /Users/***/EasierConnect/core/protocol.go:213 +0x154
lyc8503 commented 1 year ago

Maybe your issue is duplicated with #10 Please try https://github.com/lyc8503/EasierConnect/releases/tag/TestBuild11

If it does not work please run with arg --debug-dump and attach your log.

yanlc39 commented 1 year ago

The TestBuild11 version displayed some logs like these

2023/01/25 13:42:28 socks dial: ***:443
2023/01/25 13:42:28 socks dial: ***:443
2023/01/25 13:42:28 send: wrote 60 bytes
00000000  45 00 00 3c 4b da 00 00  40 06 af c9 02 00 01 1f  |E..<K...@.......|
00000010  ca cf b1 2a d5 2023/01/25 13:42:28 send: wrote 60 bytes
69 01 bb  cb 4e e2 51 00 00 00 00  |...*.i...N.Q....|
00000020  a0 02 6a 40 52 39 00 00  02 04 05 50 04 02 08 0a  |..j@R9.....P....|
00000030  22 a7 65 67 00 00 00 00  01 03 03 05              |".eg........|
00000000  45 00 00 3c 4b d9 00 00  40 06 af ca 02 00 01 1f  |E..<K...@.......|
00000010  ca cf b1 2a 5d 3e 01 bb  8c 8b 62 2d 00 00 00 00  |...*]>....b-....|
00000020  a0 02 6a 40 89 4c 00 00  02 04 05 50 04 02 08 0a  |..j@.L.....P....|
00000030  22 a7 65 67 00 00 00 00  01 03 03 05              |".eg........|
2023/01/25 13:42:29 socks dial: ***:443
2023/01/25 13:42:29 send: wrote 60 bytes
00000000  45 00 00 3c ae 90 00 00  40 06 0f 28 02 00 01 1f  |E..<....@..(....|
00000010  8e fb 2a ea 46 28 01 bb  8e 1a 3b a6 00 00 00 00  |..*.F(....;.....|
00000020  a0 02 6a 40 36 99 00 00  02 04 05 50 04 02 08 0a  |..j@6......P....|
00000030  3b 19 9d cb 00 00 00 00  01 03 03 05              |;...........|
2023/01/25 13:42:29 send: wrote 60 bytes
00000000  45 00 00 2023/01/25 13:42:29 send: wrote 60 bytes
3c 00000000  45 00 00 3c 4b dc 00 00  40 06 af c7 02 00 01 1f  |E..<K...@.......|
00000010  ca cf b1 2a 5d 3e 01 bb  8c 8b 62 2d 00 00 00 00  |...*]>....b-....|
00000020  a0 02 6a 40 89 4c 00 00  02 04 05 50 04 02 08 0a  |..j@.L.....P....|
00000030  22 a7 65 67 00 4b db 00 00  40 06 af c8 02 00 01 1f  |E..<K...@.......|
00000010  ca cf b1 2a d5 69 01 bb  cb 4e e2 51 00 00 00 00  |...*.i...N.Q....|
00000020  a0 02 6a 40 52 39 00 00  02 04 05 50 04 02 08 0a  |..j@R9.....P....|
00000030  22 a7 65 67 00 00 00 00  01 03 03 05              |".eg........|
00 00 00  01 03 03 05              |".eg........|
2023/01/25 13:42:30 send: wrote 60 bytes
00000000  45 00 00 3c ae 91 00 00  40 06 0f 27 02 00 01 1f  |E..<....@..'....|
00000010  8e fb 2a ea 46 28 01 bb  8e 1a 3b a6 00 00 00 00  |..*.F(....;.....|
00000020  a0 02 6a 40 36 99 00 00  02 04 05 50 04 02 08 0a  |..j@6......P....|
00000030  3b 19 9d cb 00 00 00 00  01 03 03 05              |;...........|
2023/01/25 13:42:31 send: wrote 60 bytes
00000000  45 00 00 3c 4b dd 00 00  40 06 af c6 02 00 01 1f  |E..<K...@.......|
00000010  ca cf b1 2a d5 69 01 bb  cb 4e e2 51 00 00 00 00  |...*.i...N.Q....|
00000020  a0 02 6a 40 52 39 00 00  02 04 05 50 04 02 08 0a  |..j@R9.....P....|
00000030  22 a7 2023/01/25 13:42:31 send: wrote 60 bytes
65 67 00 00 00 00  01 03 03 05       00000000  45 00 00 3c 4b de 00        |".eg........|
00  40 06 af c5 02 00 01 1f  |E..<K...@.......|
00000010  ca cf b1 2a 5d 3e 01 bb  8c 8b 62 2d 00 00 00 00  |...*]>....b-....|
00000020  a0 02 6a 40 89 4c 00 00  02 04 05 50 04 02 08 0a  |..j@.L.....P....|
00000030  22 a7 65 67 00 00 00 00  01 03 03 05              |".eg........|
2023/01/25 13:42:32 send: wrote 60 bytes
00000000  45 00 00 3c ae 92 00 00  40 06 0f 26 02 00 01 1f  |E..<....@..&....|
00000010  8e fb 2a ea 46 28 01 bb  8e 1a 3b a6 00 00 00 00  |..*.F(....;.....|
00000020  a0 02 6a 40 36 99 00 00  02 04 05 50 04 02 08 0a  |..j@6......P....|
00000030  3b 19 9d cb 00 00 00 00  01 03 03 05              |;...........|
2023/01/25 13:42:32 socks dial: ***:443
2023/01/25 13:42:32 Error occurred while send, retrying: write tcp 192.168.0.112:62022->addr.to.vpn:4433: write: broken pipe
2023/01/25 13:42:32 socket: connected to:  addr.to.vpn:4433
2023/01/25 13:42:32 tls: connected to:  addr.to.vpn:4433
2023/01/25 13:42:32 send handshake: wrote 64 bytes
00000000  05 00 00 00 65 62 64 61  32 33 65 66 63 61 64 32  |....ebda23efcad2|
00000010  38 65 35 66 30 34 66 65  35 62 63 35 35 63 36 65  |8e5f04fe5bc55c6e|
00000020  36 37 61 00 34 31 37 63  35 66 62 65 32 33 30 39  |67a.417c5fbe2309|
00000030  65 32 38 33 00 00 00 00  00 00 00 00 1f 01 00 02  |e283............|
2023/01/25 13:42:32 send handshake: read 36 bytes
00000000  08 00 00 00 00 00 00 00  00 c7 48 d8 5e 2d 85 eb  |..........H.^-..|
00000010  d0 3d de 87 fc 7f 00 00  17 4c f4 e4 32 7f 00 00  |.=.......L..2...|
00000020  00 00 00 00                                       |....|
2023/01/25 13:42:32 Error occurred while send, retrying: unexpected send handshake reply
2023/01/25 13:42:32 socket: connected to:  addr.to.vpn:4433
2023/01/25 13:42:32 tls: connected to:  addr.to.vpn:4433
2023/01/25 13:42:32 send handshake: wrote 64 bytes
00000000  05 00 00 00 65 62 64 61  32 33 65 66 63 61 64 32  |....ebda23efcad2|
00000010  38 65 35 66 30 34 66 65  35 62 63 35 35 63 36 65  |8e5f04fe5bc55c6e|
00000020  36 37 61 00 34 31 37 63  35 66 62 65 32 33 30 39  |67a.417c5fbe2309|
00000030  65 32 38 33 00 00 00 00  00 00 00 00 1f 01 00 02  |e283............|
2023/01/25 13:42:32 send handshake: read 36 bytes
00000000  08 00 00 00 00 00 00 00  00 c7 48 d8 5e 2d 85 eb  |..........H.^-..|
00000010  d0 3d de 87 fc 7f 00 00  17 4c f4 e4 32 7f 00 00  |.=.......L..2...|
00000020  00 00 00 00                                       |....|
2023/01/25 13:42:32 Error occurred while send, retrying: unexpected send handshake reply
2023/01/25 13:42:32 socket: connected to:  addr.to.vpn:4433
2023/01/25 13:42:32 tls: connected to:  addr.to.vpn:4433
2023/01/25 13:42:33 send handshake: wrote 64 bytes
00000000  05 00 00 00 65 62 64 61  32 33 65 66 63 61 64 32  |....ebda23efcad2|
00000010  38 65 35 66 30 34 66 65  35 62 63 35 35 63 36 65  |8e5f04fe5bc55c6e|
00000020  36 37 61 00 34 31 37 63  35 66 62 65 32 33 30 39  |67a.417c5fbe2309|
00000030  65 32 38 33 00 00 00 00  00 00 00 00 1f 01 00 02  |e283............|
2023/01/25 13:42:33 send handshake: read 36 bytes
00000000  08 00 00 00 00 00 00 00  00 c7 48 d8 5e 2d 85 eb  |..........H.^-..|
00000010  d0 3d de 87 fc 7f 00 00  17 4c f4 e4 32 7f 00 00  |.=.......L..2...|
00000020  00 00 00 00                                       |....|
2023/01/25 13:42:33 Error occurred while send, retrying: unexpected send handshake reply
2023/01/25 13:42:33 socket: connected to:  addr.to.vpn:4433
2023/01/25 13:42:33 tls: connected to:  addr.to.vpn:4433
2023/01/25 13:42:33 send handshake: wrote 64 bytes
00000000  05 00 00 00 65 62 64 61  32 33 65 66 63 61 64 32  |....ebda23efcad2|
00000010  38 65 35 66 30 34 66 65  35 62 63 35 35 63 36 65  |8e5f04fe5bc55c6e|
00000020  36 37 61 00 34 31 37 63  35 66 62 65 32 33 30 39  |67a.417c5fbe2309|
00000030  65 32 38 33 00 00 00 00  00 00 00 00 1f 01 00 02  |e283............|
2023/01/25 13:42:33 send handshake: read 36 bytes
00000000  08 00 00 00 00 00 00 00  00 c7 48 d8 5e 2d 85 eb  |..........H.^-..|
00000010  d0 3d de 87 fc 7f 00 00  17 4c f4 e4 32 7f 00 00  |.=.......L..2...|
00000020  00 00 00 00                                       |....|
2023/01/25 13:42:33 Error occurred while send, retrying: unexpected send handshake reply
panic: send retry limit exceeded.

goroutine 63 [running]:
EasierConnect/core.StartProtocol.func2()
    EasierConnect/core/protocol.go:210 +0xf0
created by EasierConnect/core.StartProtocol
    EasierConnect/core/protocol.go:213 +0x154
aecra commented 1 year ago

I encountered exactly the same problem.

lyc8503 commented 1 year ago

The server is returning an error which indicates that the connection cannot be established. There may be differences in the protocol between different versions of client.

What version of EasyConnect are you using?

Hagb commented 1 year ago

This problem may be caused by trying to access an ip not in "L3VPN resources" (the concept from Sangfor). In the official client, route of such ip(s) is not through the virtual network interface of EasyConnect.

For example, if the only "L3VPN resources" provided by server is 192.168.2.1-192.168.2.200, the route table in Linux version shows:

default via xxxxxxx
192.168.2.1 dev tun0 scope link
192.168.2.2/31 dev tun0 scope link 
192.168.2.4/30 dev tun0 scope link 
192.168.2.8/29 dev tun0 scope link 
....

In this case, if using EasierConnect, trying to access 192.168.2.1 is OK, but trying to access 192.168.1.1 causes the problem.

lyc8503 commented 1 year ago

This problem may be caused by trying to access an ip not in "L3VPN resources" (the concept from Sangfor). In the official client, route of such ip(s) is not through the virtual network interface of EasyConnect.

For example, if the only "L3VPN resources" provided by server is 192.168.2.1-192.168.2.200, the route table in Linux version shows:

default via xxxxxxx
192.168.2.1 dev tun0 scope link
192.168.2.2/31 dev tun0 scope link 
192.168.2.4/30 dev tun0 scope link 
192.168.2.8/29 dev tun0 scope link 
....

In this case, if using EasierConnect, trying to access 192.168.2.1 is OK, but trying to access 192.168.1.1 causes the problem.

This could possibly be the cause. I didn't test such a situation because our school includes almost all network segments and routes all traffic through the vpn. (which may be a misconfiguration.)

To fix it, we need to parse the target ip resources in https://github.com/lyc8503/EasierConnect/blob/main/core/web_login.go#L210 , and filter out traffic that doesn't belong to the target segments.

For now, a workaround is that make sure you don't route irrelevant traffic through socks5.

Hagb commented 1 year ago

This problem may be caused by trying to access an ip not in "L3VPN resources" (the concept from Sangfor). In the official client, route of such ip(s) is not through the virtual network interface of EasyConnect.

For example, if the only "L3VPN resources" provided by server is 192.168.2.1-192.168.2.200, the route table in Linux version shows:

default via xxxxxxx
192.168.2.1 dev tun0 scope link
192.168.2.2/31 dev tun0 scope link 
192.168.2.4/30 dev tun0 scope link 
192.168.2.8/29 dev tun0 scope link 
....

In this case, if using EasierConnect, trying to access 192.168.2.1 is OK, but trying to access 192.168.1.1 causes the problem.

GET /por/rclist.csp with Cookie: TWFID=logined-twfid; request header gives the resources list. For example, in the above case, it returns:

<Resource>
        <Rcs> 
        <Rc id="1" name="test" type="2" proto="-1" svc="Other" host="192.168.2.1~192.168.2.200" port="1~65535" enable_disguise="0" note="" attr="0" app_path="" rc_grp_id="0" rc_logo="05_font_face_xe60d.png" authorization="1" auth_sp_id="0" selectid="-1" />
        </Rcs>
....
</Resource>
Hagb commented 1 year ago

This could possibly be the cause. I didn't test such a situation because our school includes almost all network segments and routes all traffic through the vpn. (which may be a misconfiguration.)

Try to access x.y.z.w in which x>224. Seems that they will never be routed by EasyConnect. With these ip(s), I can reproduce the problem after connecting to vpn of my school, which also has misconfigured route.

yanlc39 commented 1 year ago

The server is returning an error which indicates that the connection cannot be established. There may be differences in the protocol between different versions of client.

What version of EasyConnect are you using?

Okay, I'm using EasyConnect 7.6.7.4. Sounds like that different versions could cause different prob?

lyc8503 commented 1 year ago

The server is returning an error which indicates that the connection cannot be established. There may be differences in the protocol between different versions of client. What version of EasyConnect are you using?

Okay, I'm using EasyConnect 7.6.7.4. Sounds like that different versions could cause different prob?

Different versions/configs of EasyConnect server have various different behaviours, which makes it hard to debug.

For this issue, as I mentioned above, For now, a workaround is that make sure you don't route irrelevant traffic through socks5. I may try to fix the problem later.