search

ooni / probe

OONI Probe network measurement tool for detecting internet censorship
https://ooni.org/install
BSD 3-Clause "New" or "Revised" License
750 stars 142 forks source link

testingsocks5: TestInvalidVersion: connection_reset_by_peer #2538

Open bassosimone opened 9 months ago

bassosimone commented 9 months ago

I have seen this test of the ./internal/testingsocks5 package fail twice in https://github.com/ooni/probe-cli/pull/1281.

The full log of a failed tests run is here:

--- FAIL: TestInvalidVersion (0.00s)
    internal_test.go:102: write tcp 127.0.0.1:49540->127.0.0.1:38529: write: connection reset by peer
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: []
2023/09/18 11:41:03  info SOCKS5: got version: [5] 
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: []   
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 1 2 1 3 102 111 111 51 98 97 114]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: [5 255]
2023/09/18 11:41:03  warn SOCKS5: s.serveConn: failed to authenticate: failed to get auth methods: EOF
2023/09/18 11:41:03  info SOCKS5: got version: [5] 
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: [5 255]
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 1 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: [5 0]
2023/09/18 11:41:03  info SOCKS5: got version: [5] 
2023/09/18 11:41:03  info SOCKS5: authenticated: &{Method:0 Payload:map[]}
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: [5 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: []
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: []   
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 1 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: [5 0]
2023/09/18 11:41:03  warn SOCKS5: s.serveConn: failed to read destination address: failed to get command version: unexpected EOF
2023/09/18 11:41:03  info SOCKS5: got version: [5] 
2023/09/18 11:41:03  info SOCKS5: authenticated: &{Method:0 Payload:map[]}
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: [5 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [17 2 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: []
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: []   
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 1 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: [5 0]
2023/09/18 11:41:03  warn SOCKS5: s.serveConn: failed to read destination address: unsupported command version: 17
2023/09/18 11:41:03  info SOCKS5: got version: [5] 
2023/09/18 11:41:03  info SOCKS5: authenticated: &{Method:0 Payload:map[]}
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: [5 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 2 0 1 127 0 0 1 0 80]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: [5 7 0 1 0 0 0 0 0 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: [5 7 0 1 0 0 0 0 0 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 1 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: [5 0]
2023/09/18 11:41:03  info SOCKS5: got version: [5] 
2023/09/18 11:41:03  info SOCKS5: authenticated: &{Method:0 Payload:map[]}
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: [5 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 2 0 55 127 0 0 1 0 80]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: []
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: []   
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 1 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: [5 0]
2023/09/18 11:41:03  warn SOCKS5: s.serveConn: failed to read destination address: unrecognized address type
2023/09/18 11:41:03  info SOCKS5: got version: [5] 
2023/09/18 11:41:03  info SOCKS5: authenticated: &{Method:0 Payload:map[]}
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: [5 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 2 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: []
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: []   
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 1 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: [5 0]
2023/09/18 11:41:03  warn SOCKS5: s.serveConn: failed to read destination address: EOF
2023/09/18 11:41:03  info SOCKS5: got version: [5] 
2023/09/18 11:41:03  info SOCKS5: authenticated: &{Method:0 Payload:map[]}
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: [5 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 2 0 1]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: []
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: []   
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 1 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: [5 0]
2023/09/18 11:41:03  warn SOCKS5: s.serveConn: failed to read destination address: EOF
2023/09/18 11:41:03  info SOCKS5: got version: [5] 
2023/09/18 11:41:03  info SOCKS5: authenticated: &{Method:0 Payload:map[]}
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: [5 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 2 0 4]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: []
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: []   
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 1 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: [5 0]
2023/09/18 11:41:03  warn SOCKS5: s.serveConn: failed to read destination address: EOF
2023/09/18 11:41:03  info SOCKS5: got version: [5] 
2023/09/18 11:41:03  info SOCKS5: authenticated: &{Method:0 Payload:map[]}
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: [5 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 2 0 3]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: []
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: []   
2023/09/18 11:41:03  warn SOCKS5: s.serveConn: failed to authenticate: no supported authentication mechanism
2023/09/18 11:41:03  warn SOCKS5: s.serveConn: failed to read destination address: EOF
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 1 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: [5 0]
2023/09/18 11:41:03  info SOCKS5: got version: [5] 
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: [5 0]
2023/09/18 11:41:03  info SOCKS5: authenticated: &{Method:0 Payload:map[]}
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 2 0 3 10]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: []
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: []   
2023/09/18 11:41:03  warn SOCKS5: s.serveConn: failed to read destination address: EOF
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 1 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: [5 0]
2023/09/18 11:41:03  info SOCKS5: got version: [5] 
2023/09/18 11:41:03  info SOCKS5: authenticated: &{Method:0 Payload:map[]}
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: [5 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: sending: [5 2 0 4 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]
2023/09/18 11:41:03  info SOCKS5_CLIENT: expecting: []
2023/09/18 11:41:03  info SOCKS5_CLIENT: got: []   
2023/09/18 11:41:03  warn SOCKS5: s.serveConn: failed to read destination address: EOF
2023/09/18 11:41:03 dialerWithAssertions: verified that the network is tcp as expected
2023/09/18 11:41:03 dialerWithAssertions: verified that the address is 10.0.0.1 as expected
2023/09/18 11:41:03  info SOCKS5: got version: [5] 
2023/09/18 11:41:03  info SOCKS5: authenticated: &{Method:0 Payload:map[]}
2023/09/18 11:41:03  info SOCKS5: handling CONNECT command
2023/09/18 11:41:03  info SOCKS5: endpoint: www.example.com:80
2023/09/18 11:41:03  warn netem: ReadFrameNonblocking: netem: network stack closed
2023/09/18 11:41:03  warn netem: dns: pconn.ReadFrom: EOF
2023/09/18 11:41:03  warn netem: ReadFrameNonblocking: netem: network stack closed
2023/09/18 11:41:04 dialerWithAssertions: verified that the network is tcp as expected
2023/09/18 11:41:04 dialerWithAssertions: verified that the address is 10.0.0.1 as expected
2023/09/18 11:41:04  info SOCKS5: got version: [5] 
2023/09/18 11:41:04  info SOCKS5: authenticated: &{Method:0 Payload:map[]}
2023/09/18 11:41:04  info SOCKS5: handling CONNECT command
2023/09/18 11:41:04  info SOCKS5: endpoint: www.example.com:443
2023/09/18 11:41:04  warn netem: dns: pconn.ReadFrom: EOF
2023/09/18 11:41:04 dialerWithAssertions: verified that the network is tcp as expected
2023/09/18 11:41:04 dialerWithAssertions: verified that the address is 10.0.0.1 as expected
2023/09/18 11:41:04  info SOCKS5: got version: [5] 
2023/09/18 11:41:04  info SOCKS5: authenticated: &{Method:0 Payload:map[]}
2023/09/18 11:41:04  info SOCKS5: handling CONNECT command
2023/09/18 11:41:04  info SOCKS5: endpoint: 93.184.216.34:80
2023/09/18 11:41:04  warn netem: ReadFrameNonblocking: netem: network stack closed
2023/09/18 11:41:04  warn netem: dns: pconn.ReadFrom: EOF
2023/09/18 11:41:05 dialerWithAssertions: verified that the network is tcp as expected
2023/09/18 11:41:05 dialerWithAssertions: verified that the address is 10.0.0.1 as expected
2023/09/18 11:41:05  info SOCKS5: got version: [5] 
2023/09/18 11:41:05  info SOCKS5: authenticated: &{Method:0 Payload:map[]}
2023/09/18 11:41:05  info SOCKS5: handling CONNECT command
2023/09/18 11:41:05  info SOCKS5: endpoint: 93.184.216.34:443
2023/09/18 11:41:05  warn netem: dns: pconn.ReadFrom: EOF
2023/09/18 11:41:05  warn netem: ReadFrameNonblocking: netem: network stack closed
2023/09/18 11:41:06  info SOCKS5: got version: [5] 
2023/09/18 11:41:06  info SOCKS5: authenticated: &{Method:0 Payload:map[]}
2023/09/18 11:41:06  info SOCKS5: handling CONNECT command
2023/09/18 11:41:06  info SOCKS5: endpoint: www.example.com:443
2023/09/18 11:41:06  warn netem: dns: pconn.ReadFrom: EOF
FAIL
    github.com/ooni/probe-cli/v3/internal/testingsocks5 coverage: 100.0% of statements
FAIL    github.com/ooni/probe-cli/v3/internal/testingsocks5 3.517s

I am going to commit a mitigation for this test being flaky. We should investigate and fix it when possible.