Cannot use ssr-client as upstream of privoxy/... etc.

lovepocky commented 4 years ago

Please answer these questions before submitting your issue. Thanks!

What version of shadowsocks-native are you using?

v0.7(release), master

What operating system are you using?

server:ubuntu18 client: ubuntu 18.04, mac(10.12)

What did you do?

forward privoxy to ssr-client. but failed(503, Privoxy was unable to socks5-forward your request http://www.youtube.com/ through ${my_ip}: SOCKS5 reply contains unsupported address type).

i.e. http_proxy=http://127.0.0.1:8118 curl -v www.youtube.com

What did you expect to see?

What did you see instead?

I have tried to debug client, but cannot solve this problem.

I found that do_handshake received data is 5,1,0(nread=3) when using privoxy, and cx->methods will be 1.

But, use ssr-client directly, received data is 5,2,0,1(nread=4) , and cx->methods will be 3.

https://github.com/ShadowsocksR-Live/shadowsocksr-native/blob/8f4f912f397704f927b985dd567535a16098ba64/src/client/s5.c#L73-L90

What is your config in detail (with all sensitive info masked)?

lovepocky commented 4 years ago

some of log here:

failed example:

ssr-client 2019/12/15 11:38  warn  [ func  ] client_tunnel_initialize
ssr-client 2019/12/15 11:38  info  ==== tunnel created     count   1 ====
ssr-client 2019/12/15 11:38  warn  in init_done_cb
ssr-client 2019/12/15 11:38  warn  init done success? 1
ssr-client 2019/12/15 11:38  warn  [ func  ] socket_read
ssr-client 2019/12/15 11:38  warn  [ func  ] socket_read_done_cb
ssr-client 2019/12/15 11:38  warn  [ func  ] socket_read_done_cb, nread = 3
ssr-client 2019/12/15 11:38  warn  [ call do_next  ] tunnel_read_done
ssr-client 2019/12/15 11:38  warn  func do_next, stage = 0
ssr-client 2019/12/15 11:38  warn  [ func  ] do_handshake
ssr-client 2019/12/15 11:38  warn  in s5_parse
ssr-client 2019/12/15 11:38  warn  cx 0
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 5, cx->state = 0
ssr-client 2019/12/15 11:38  warn  s5_state_version, 5
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 1, cx->state = 1
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 0, cx->state = 2
ssr-client 2019/12/15 11:38  warn  case ---- s5_state_methods, c = 0
ssr-client 2019/12/15 11:38  warn  cx->methods = 1
ssr-client 2019/12/15 11:38  warn  cx->methods = 3
ssr-client 2019/12/15 11:38  warn  out, err = 1
ssr-client 2019/12/15 11:38  warn  [ func do_next  ] complete
ssr-client 2019/12/15 11:38  warn  [ func  ] socket_read_done_cb, end of do-while
ssr-client 2019/12/15 11:38  warn  [ call do_next  ] tunnel_write_done
ssr-client 2019/12/15 11:38  warn  func do_next, stage = 2
ssr-client 2019/12/15 11:38  warn  [ func  ] socket_read
ssr-client 2019/12/15 11:38  warn  [ func do_next  ] complete
ssr-client 2019/12/15 11:38  warn  [ func  ] socket_read_done_cb
ssr-client 2019/12/15 11:38  warn  [ func  ] socket_read_done_cb, nread = 22
ssr-client 2019/12/15 11:38  warn  [ call do_next  ] tunnel_read_done
ssr-client 2019/12/15 11:38  warn  func do_next, stage = 3
ssr-client 2019/12/15 11:38  warn  do_parse_s5_request
ssr-client 2019/12/15 11:38  warn  in s5_parse
ssr-client 2019/12/15 11:38  warn  cx 8
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 5, cx->state = 8
ssr-client 2019/12/15 11:38  warn  s5_state_req_version, 5
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 1, cx->state = 9
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 0, cx->state = 10
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 3, cx->state = 11
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 15, cx->state = 12
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 119, cx->state = 13
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 119, cx->state = 13
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 119, cx->state = 13
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 46, cx->state = 13
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 121, cx->state = 13
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 111, cx->state = 13
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 117, cx->state = 13
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 116, cx->state = 13
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 117, cx->state = 13
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 98, cx->state = 13
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 101, cx->state = 13
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 46, cx->state = 13
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 99, cx->state = 13
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 111, cx->state = 13
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 109, cx->state = 13
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 0, cx->state = 14
ssr-client 2019/12/15 11:38  warn  [ func s5_parse  ] data = 80, cx->state = 15
ssr-client 2019/12/15 11:38  warn  s5_state_req_dport1, c = 80
ssr-client 2019/12/15 11:38  warn  out, err = 3
ssr-client 2019/12/15 11:38  warn  config->over_tls_enable
ssr-client 2019/12/15 11:38  info  connecting www.youtube.com:80 ...
ssr-client 2019/12/15 11:38  warn  do_parse_s5_request complete
ssr-client 2019/12/15 11:38  warn  [ func do_next  ] complete
ssr-client 2019/12/15 11:38  warn  [ func  ] socket_read_done_cb, end of do-while
ssr-client 2019/12/15 11:38  warn  [ call do_next  ] tunnel_write_done
ssr-client 2019/12/15 11:38  warn  func do_next, stage = 13
ssr-client 2019/12/15 11:38  warn  [ stage case  ] tunnel_stage_auth_completion_done
ssr-client 2019/12/15 11:38  warn  [ func  ] tunnel_tls_do_launch_streaming
ssr-client 2019/12/15 11:38  warn  incoming->result = 0
ssr-client 2019/12/15 11:38  warn  [ func  ] tunnel_tls_do_launch_streaming / socket_read
ssr-client 2019/12/15 11:38  warn  [ func  ] socket_read
ssr-client 2019/12/15 11:38  warn  [ func  ] tunnel_tls_do_launch_streaming, ctx->stage = 7
ssr-client 2019/12/15 11:38  warn  [ func do_next  ] complete
ssr-client 2019/12/15 11:38  warn  [ func  ] socket_read_done_cb
ssr-client 2019/12/15 11:38  warn  [ func  ] socket_read_done_cb, nread = -4095
ssr-client 2019/12/15 11:38  warn  [ func  ] socket_read_done_cb, UV_EOF
ssr-client 2019/12/15 11:38  warn  client_tunnel_shutdown
ssr-client 2019/12/15 11:38  warn  tls_client_shutdown
ssr-client 2019/12/15 11:38  warn  _mbed_close_done_cb
ssr-client 2019/12/15 11:38  warn  tunnel_tls_on_shutting_down
ssr-client 2019/12/15 11:38  info  ---- disconnected www.youtube.com:80 ----
ssr-client 2019/12/15 11:38  info  ==== tunnel destroyed   count   0 ====

success example:

ssr-client 2019/12/15 11:34  warn  [ func  ] client_tunnel_initialize
ssr-client 2019/12/15 11:34  info  ==== tunnel created     count   1 ====
ssr-client 2019/12/15 11:34  warn  in init_done_cb
ssr-client 2019/12/15 11:34  warn  init done success? 1
ssr-client 2019/12/15 11:34  warn  [ func  ] socket_read
ssr-client 2019/12/15 11:34  warn  [ func  ] socket_read_done_cb
ssr-client 2019/12/15 11:34  warn  [ func  ] socket_read_done_cb, nread = 4
ssr-client 2019/12/15 11:34  warn  [ call do_next  ] tunnel_read_done
ssr-client 2019/12/15 11:34  warn  func do_next, stage = 0
ssr-client 2019/12/15 11:34  warn  [ func  ] do_handshake
ssr-client 2019/12/15 11:34  warn  in s5_parse
ssr-client 2019/12/15 11:34  warn  cx 0
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 5, cx->state = 0
ssr-client 2019/12/15 11:34  warn  s5_state_version, 5
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 2, cx->state = 1
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 0, cx->state = 2
ssr-client 2019/12/15 11:34  warn  case ---- s5_state_methods, c = 0
ssr-client 2019/12/15 11:34  warn  cx->methods = 1
ssr-client 2019/12/15 11:34  warn  cx->methods = 3
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 1, cx->state = 2
ssr-client 2019/12/15 11:34  warn  case ---- s5_state_methods, c = 1
ssr-client 2019/12/15 11:34  warn  cx->methods = 3
ssr-client 2019/12/15 11:34  warn  cx->methods = 3
ssr-client 2019/12/15 11:34  warn  out, err = 1
ssr-client 2019/12/15 11:34  warn  [ func do_next  ] complete
ssr-client 2019/12/15 11:34  warn  [ func  ] socket_read_done_cb, end of do-while
ssr-client 2019/12/15 11:34  warn  [ call do_next  ] tunnel_write_done
ssr-client 2019/12/15 11:34  warn  func do_next, stage = 2
ssr-client 2019/12/15 11:34  warn  [ func  ] socket_read
ssr-client 2019/12/15 11:34  warn  [ func do_next  ] complete
ssr-client 2019/12/15 11:34  warn  [ func  ] socket_read_done_cb
ssr-client 2019/12/15 11:34  warn  [ func  ] socket_read_done_cb, nread = 22
ssr-client 2019/12/15 11:34  warn  [ call do_next  ] tunnel_read_done
ssr-client 2019/12/15 11:34  warn  func do_next, stage = 3
ssr-client 2019/12/15 11:34  warn  do_parse_s5_request
ssr-client 2019/12/15 11:34  warn  in s5_parse
ssr-client 2019/12/15 11:34  warn  cx 8
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 5, cx->state = 8
ssr-client 2019/12/15 11:34  warn  s5_state_req_version, 5
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 1, cx->state = 9
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 0, cx->state = 10
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 3, cx->state = 11
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 15, cx->state = 12
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 119, cx->state = 13
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 119, cx->state = 13
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 119, cx->state = 13
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 46, cx->state = 13
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 121, cx->state = 13
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 111, cx->state = 13
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 117, cx->state = 13
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 116, cx->state = 13
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 117, cx->state = 13
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 98, cx->state = 13
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 101, cx->state = 13
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 46, cx->state = 13
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 99, cx->state = 13
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 111, cx->state = 13
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 109, cx->state = 13
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 0, cx->state = 14
ssr-client 2019/12/15 11:34  warn  [ func s5_parse  ] data = 80, cx->state = 15
ssr-client 2019/12/15 11:34  warn  s5_state_req_dport1, c = 80
ssr-client 2019/12/15 11:34  warn  out, err = 3
ssr-client 2019/12/15 11:34  warn  config->over_tls_enable
ssr-client 2019/12/15 11:34  info  connecting www.youtube.com:80 ...
ssr-client 2019/12/15 11:34  warn  do_parse_s5_request complete
ssr-client 2019/12/15 11:34  warn  [ func do_next  ] complete
ssr-client 2019/12/15 11:34  warn  [ func  ] socket_read_done_cb, end of do-while
ssr-client 2019/12/15 11:34  warn  [ call do_next  ] tunnel_write_done
ssr-client 2019/12/15 11:34  warn  func do_next, stage = 13
ssr-client 2019/12/15 11:34  warn  [ stage case  ] tunnel_stage_auth_completion_done
ssr-client 2019/12/15 11:34  warn  [ func  ] tunnel_tls_do_launch_streaming
ssr-client 2019/12/15 11:34  warn  incoming->result = 0
ssr-client 2019/12/15 11:34  warn  [ func  ] tunnel_tls_do_launch_streaming / socket_read
ssr-client 2019/12/15 11:34  warn  [ func  ] socket_read
ssr-client 2019/12/15 11:34  warn  [ func  ] tunnel_tls_do_launch_streaming, ctx->stage = 7
ssr-client 2019/12/15 11:34  warn  [ func do_next  ] complete
ssr-client 2019/12/15 11:34  warn  [ func  ] socket_read_done_cb
ssr-client 2019/12/15 11:34  warn  [ func  ] socket_read_done_cb, nread = 79
ssr-client 2019/12/15 11:34  warn  [ call do_next  ] tunnel_read_done
ssr-client 2019/12/15 11:34  warn  func do_next, stage = 7
ssr-client 2019/12/15 11:34  warn  [ do_next / case  ] tunnel_stage_tls_streaming
ssr-client 2019/12/15 11:34  warn  [ func  ] socket_read
ssr-client 2019/12/15 11:34  warn  [ func do_next  ] complete
ssr-client 2019/12/15 11:34  warn  [ func  ] socket_read_done_cb, end of do-while
ssr-client 2019/12/15 11:34  warn  [ call do_next  ] tunnel_write_done
ssr-client 2019/12/15 11:34  warn  func do_next, stage = 7
ssr-client 2019/12/15 11:34  warn  [ do_next / case  ] tunnel_stage_tls_streaming
ssr-client 2019/12/15 11:34  warn  [ func do_next  ] complete
ssr-client 2019/12/15 11:34  warn  [ func  ] socket_read_done_cb
ssr-client 2019/12/15 11:34  warn  [ func  ] socket_read_done_cb, nread = -4095
ssr-client 2019/12/15 11:34  warn  [ func  ] socket_read_done_cb, UV_EOF
ssr-client 2019/12/15 11:34  warn  client_tunnel_shutdown
ssr-client 2019/12/15 11:34  warn  tls_client_shutdown
ssr-client 2019/12/15 11:34  warn  _mbed_close_done_cb
ssr-client 2019/12/15 11:34  warn  tunnel_tls_on_shutting_down
ssr-client 2019/12/15 11:34  info  ---- disconnected www.youtube.com:80 ----
ssr-client 2019/12/15 11:34  info  ==== tunnel destroyed   count   0 ====

ssrlive commented 4 years ago

what is your privoxy config file? you must do it like this: https://github.com/ssrlive/Privoxy#sample-config-file

lovepocky commented 4 years ago

@ssrlive privoxy(3.0.28) installed by brew. and simply add config: forward-socks5 / 127.0.0.1:1080 .

lovepocky commented 4 years ago

Should i use this forked privoxy(https://github.com/ssrlive/Privoxy)?

ssrlive commented 4 years ago

needn't. I will review my code.

lovepocky commented 4 years ago

Thank you very much ~

ssrlive commented 4 years ago

I find that it's hard to reproduce the bug. only the command can reproduce it. curl -x localhost:8118 http://www.youtube.com/ -a a.html

ssrlive commented 4 years ago

I found that do_handshake received data is 5,1,0(nread=3) when using privoxy, and cx->methods will be 1.

But, use ssr-client directly, received data is 5,2,0,1(nread=4) , and cx->methods will be 3.

It's not a bug. curl -x socks5://localhost:1080 https://www.youtube.com/ will cause nread=4

curl -x http://localhost:8118 https://www.youtube.com/ will cause nread=3, it's via privoxy.

https://zh.wikipedia.org/zh-hans/SOCKS#SOCKS5

Saddly. it's can not get data for DNS cache pollution. but chrome and firefox work fine.

lovepocky commented 4 years ago

some additional logs @ssrlive

command: $ http_proxy=http://127.0.0.1:8118 curl -v youtube.com

privoxy config:

debug     1 # Log the destination for each request Privoxy let through. See also debug 1024.
debug     2 # show each connection status
debug     4 # show I/O status
debug     8 # show header parsing
debug    16 # log all data written to the network
debug    32 # debug force feature
# debug    64 # debug regular expression filters
debug   128 # debug redirects
# debug   256 # debug GIF de-animation
debug   512 # Common Log Format
debug  1024 # Log the destination for requests Privoxy didn't let through, and the reason why.
# debug  2048 # CGI user interface
debug  4096 # Startup banner and warnings.
debug  8192 # Non-fatal errors
debug 32768 # log all data read from the network
debug 65536 # Log the applying actions

Success with ordinary ssr client

curl -> privoxy -> socks5 listened by another ssr client

2019-12-16 19:06:18.293 7fffaeb14 Info: Privoxy version 3.0.28
2019-12-16 19:06:18.294 7fffaeb14 Info: Program name: /usr/local/Cellar/privoxy/3.0.28/sbin/privoxy
2019-12-16 19:06:18.298 7fffaeb14 Info: Loading filter file: /usr/local/etc/privoxy/default.filter
2019-12-16 19:06:18.302 7fffaeb14 Info: Loading filter file: /usr/local/etc/privoxy/user.filter
2019-12-16 19:06:18.303 7fffaeb14 Info: Loading actions file: /usr/local/etc/privoxy/match-all.action
2019-12-16 19:06:18.303 7fffaeb14 Info: Loading actions file: /usr/local/etc/privoxy/default.action
2019-12-16 19:06:18.311 7fffaeb14 Info: Loading actions file: /usr/local/etc/privoxy/user.action
2019-12-16 19:06:18.311 7fffaeb14 Connect: Initialized 100 socket slots.
2019-12-16 19:06:18.312 7fffaeb14 Info: Listening on port 8118 on IP address 127.0.0.1
2019-12-16 19:06:18.312 7fffaeb14 Connect: Waiting for the next client connection. Currently active threads: 0
2019-12-16 19:06:20.609 7fffaeb14 Connect: Waiting for the next client connection. Currently active threads: 1
2019-12-16 19:06:20.609 70000baf8 Connect: Accepted connection from 127.0.0.1 on socket 4
2019-12-16 19:06:20.609 70000baf8 Received: from socket 4: GET http://youtube.com/ HTTP/1.1\x0d\x0aHost: youtube.com\x0d\x0aUser-Agent: curl/7.59.0\x0d\x0aAccept: */*\x0d\x0aProxy-Connection: Keep-Alive\x0d\x0a\x0d\x0a
2019-12-16 19:06:20.609 70000baf8 Connect: Complete client request received.
2019-12-16 19:06:20.609 70000baf8 Header: scan: GET http://youtube.com/ HTTP/1.1
2019-12-16 19:06:20.609 70000baf8 Header: scan: Host: youtube.com
2019-12-16 19:06:20.610 70000baf8 Header: scan: User-Agent: curl/7.59.0
2019-12-16 19:06:20.610 70000baf8 Header: scan: Accept: */*
2019-12-16 19:06:20.610 70000baf8 Header: scan: Proxy-Connection: Keep-Alive
2019-12-16 19:06:20.610 70000baf8 Header: crumble crunched: Proxy-Connection: Keep-Alive!
2019-12-16 19:06:20.610 70000baf8 Connect: Overriding forwarding settings based on 'forward-socks5 127.0.0.1:1080 .'
2019-12-16 19:06:20.610 70000baf8 Header: New HTTP Request-Line: GET / HTTP/1.1
2019-12-16 19:06:20.610 70000baf8 Actions: +change-x-forwarded-for{block} +client-header-tagger{css-requests} +client-header-tagger{image-requests} +client-header-tagger{range-requests} +forward-override{forward-socks5 127.0.0.1:1080 .} +hide-from-header{block} +set-image-blocker{pattern}
2019-12-16 19:06:20.610 70000baf8 Request: youtube.com/
2019-12-16 19:06:20.628 70000baf8 Connect: to youtube.com
2019-12-16 19:06:20.629 70000baf8 Connect: Connected to 127.0.0.1[127.0.0.1]:1080.
2019-12-16 19:06:20.629 70000baf8 Writing: to socket 5: \x05\x01\x00
2019-12-16 19:06:20.629 70000baf8 Received: from socket 5: \x05\x00
2019-12-16 19:06:20.629 70000baf8 Writing: to socket 5: \x05\x01\x00\x03\x0byoutube.com\x00P
2019-12-16 19:06:20.629 70000baf8 Received: from socket 5: \x05\x00\x00\x01\x00\x00\x00\x00\x00\x00
2019-12-16 19:06:20.629 70000baf8 Connect: Created new connection to youtube.com:80 on socket 5.
2019-12-16 19:06:20.629 70000baf8 Writing: to socket 5: GET / HTTP/1.1\x0d\x0aHost: youtube.com\x0d\x0aUser-Agent: curl/7.59.0\x0d\x0aAccept: */*\x0d\x0a\x0d\x0a
2019-12-16 19:06:20.629 70000baf8 Connect: to youtube.com successful
2019-12-16 19:06:20.725 70000baf8 Received: from socket 5: HTTP/1.1 301 Moved Permanently\x0d\x0aLocation: https://youtube.com/\x0d\x0aContent-Length: 0\x0d\x0aDate: Mon, 16 Dec 2019 11:06:20 GMT\x0d\x0aContent-Type: text/html\x0d\x0aServer: YouTube Frontend Proxy\x0d\x0aX-XSS-Protection: 0\x0d\x0a\x0d\x0a
2019-12-16 19:06:20.725 70000baf8 Header: scan: HTTP/1.1 301 Moved Permanently
2019-12-16 19:06:20.725 70000baf8 Header: scan: Location: https://youtube.com/
2019-12-16 19:06:20.725 70000baf8 Header: scan: Content-Length: 0
2019-12-16 19:06:20.725 70000baf8 Header: scan: Date: Mon, 16 Dec 2019 11:06:20 GMT
2019-12-16 19:06:20.725 70000baf8 Header: scan: Content-Type: text/html
2019-12-16 19:06:20.725 70000baf8 Header: scan: Server: YouTube Frontend Proxy
2019-12-16 19:06:20.725 70000baf8 Header: scan: X-XSS-Protection: 0
2019-12-16 19:06:20.725 70000baf8 Header: A HTTP/1.1 response without Connection header implies keep-alive.
2019-12-16 19:06:20.725 70000baf8 Header: Adding: Proxy-Connection: keep-alive
2019-12-16 19:06:20.725 70000baf8 Writing: to socket 4: HTTP/1.1 301 Moved Permanently\x0d\x0aLocation: https://youtube.com/\x0d\x0aContent-Length: 0\x0d\x0aDate: Mon, 16 Dec 2019 11:06:20 GMT\x0d\x0aContent-Type: text/html\x0d\x0aServer: YouTube Frontend Proxy\x0d\x0aX-XSS-Protection: 0\x0d\x0aProxy-Connection: keep-alive\x0d\x0a\x0d\x0a
2019-12-16 19:06:20.725 70000baf8 Connect: Done reading from server. Content length: 0 as expected. Bytes most recently read: 0.
127.0.0.1 - - [16/Dec/2019:19:06:20 +0800] "GET http://youtube.com/ HTTP/1.1" 200 0
2019-12-16 19:06:20.726 70000baf8 Connect: Closing server socket 5 connected to youtube.com. Keep-alive 1. Tainted: 0. Socket alive 1. Timeout: 0.
2019-12-16 19:06:20.726 70000baf8 Connect: Waiting for the next client request on socket 4. No server socket to keep open.
2019-12-16 19:06:20.726 70000baf8 Connect: Closing client socket 4. Keep-alive: 1. Socket alive: 0. Data available: 0. Configuration file change detected: 0. Requests received: 1.

Failed with ssrot client

curl -> privoxy -> socks5 listened by ssrot client

2019-12-16 19:03:50.027 7fffaeb14 Info: Privoxy version 3.0.28
2019-12-16 19:03:50.027 7fffaeb14 Info: Program name: /usr/local/Cellar/privoxy/3.0.28/sbin/privoxy
2019-12-16 19:03:50.031 7fffaeb14 Info: Loading filter file: /usr/local/etc/privoxy/default.filter
2019-12-16 19:03:50.034 7fffaeb14 Info: Loading filter file: /usr/local/etc/privoxy/user.filter
2019-12-16 19:03:50.035 7fffaeb14 Info: Loading actions file: /usr/local/etc/privoxy/match-all.action
2019-12-16 19:03:50.035 7fffaeb14 Info: Loading actions file: /usr/local/etc/privoxy/default.action
2019-12-16 19:03:50.042 7fffaeb14 Info: Loading actions file: /usr/local/etc/privoxy/user.action
2019-12-16 19:03:50.043 7fffaeb14 Connect: Initialized 100 socket slots.
2019-12-16 19:03:50.043 7fffaeb14 Info: Listening on port 8118 on IP address 127.0.0.1
2019-12-16 19:03:50.043 7fffaeb14 Connect: Waiting for the next client connection. Currently active threads: 0
2019-12-16 19:03:52.260 70000aeb8 Connect: Accepted connection from 127.0.0.1 on socket 4
2019-12-16 19:03:52.260 7fffaeb14 Connect: Waiting for the next client connection. Currently active threads: 1
2019-12-16 19:03:52.260 70000aeb8 Received: from socket 4: GET http://youtube.com/ HTTP/1.1\x0d\x0aHost: youtube.com\x0d\x0aUser-Agent: curl/7.59.0\x0d\x0aAccept: */*\x0d\x0aProxy-Connection: Keep-Alive\x0d\x0a\x0d\x0a
2019-12-16 19:03:52.260 70000aeb8 Connect: Complete client request received.
2019-12-16 19:03:52.260 70000aeb8 Header: scan: GET http://youtube.com/ HTTP/1.1
2019-12-16 19:03:52.260 70000aeb8 Header: scan: Host: youtube.com
2019-12-16 19:03:52.260 70000aeb8 Header: scan: User-Agent: curl/7.59.0
2019-12-16 19:03:52.260 70000aeb8 Header: scan: Accept: */*
2019-12-16 19:03:52.260 70000aeb8 Header: scan: Proxy-Connection: Keep-Alive
2019-12-16 19:03:52.260 70000aeb8 Header: crumble crunched: Proxy-Connection: Keep-Alive!
2019-12-16 19:03:52.260 70000aeb8 Connect: Overriding forwarding settings based on 'forward-socks5 127.0.0.1:1080 .'
2019-12-16 19:03:52.260 70000aeb8 Header: New HTTP Request-Line: GET / HTTP/1.1
2019-12-16 19:03:52.260 70000aeb8 Actions: +change-x-forwarded-for{block} +client-header-tagger{css-requests} +client-header-tagger{image-requests} +client-header-tagger{range-requests} +forward-override{forward-socks5 127.0.0.1:1080 .} +hide-from-header{block} +set-image-blocker{pattern}
2019-12-16 19:03:52.260 70000aeb8 Request: youtube.com/
2019-12-16 19:03:52.260 70000aeb8 Connect: to youtube.com
2019-12-16 19:03:52.261 70000aeb8 Connect: Connected to 127.0.0.1[127.0.0.1]:1080.
2019-12-16 19:03:52.261 70000aeb8 Writing: to socket 5: \x05\x01\x00
2019-12-16 19:03:52.261 70000aeb8 Received: from socket 5: \x05\x00
2019-12-16 19:03:52.261 70000aeb8 Writing: to socket 5: \x05\x01\x00\x03\x0byoutube.com\x00P
2019-12-16 19:03:52.866 70000aeb8 Received: from socket 5: \x05\x00\x00\x03\x0byoutu
2019-12-16 19:03:52.866 70000aeb8 Connect: socks5_connect: SOCKS5 reply contains unsupported address type
2019-12-16 19:03:52.867 70000aeb8 Connect: Overriding forwarding settings based on 'forward-socks5 127.0.0.1:1080 .'
2019-12-16 19:03:52.868 70000aeb8 Actions: +change-x-forwarded-for{block} +client-header-tagger{css-requests} +client-header-tagger{image-requests} +client-header-tagger{range-requests} +forward-override{forward-socks5 127.0.0.1:1080 .} +hide-from-header{block} +set-image-blocker{pattern}
2019-12-16 19:03:52.868 70000aeb8 Crunch: Forwarding failed: http://youtube.com/
127.0.0.1 - - [16/Dec/2019:19:03:52 +0800] "GET http://youtube.com/ HTTP/1.1" 503 7045
2019-12-16 19:03:52.868 70000aeb8 Writing: to socket 4: HTTP/1.1 503 Forwarding failure\x0d\x0aContent-Length: 7045\x0d\x0aContent-Type: text/html\x0d\x0aCache-Control: no-cache\x0d\x0aDate: Mon, 16 Dec 2019 11:03:52 GMT\x0d\x0aLast-Modified: Wed, 08 Jun 1955 12:00:00 GMT\x0d\x0aExpires: Sat, 17 Jun 2000 12:00:00 GMT\x0d\x0aPragma: no-cache\x0d\x0a\x0d\x0a
2019-12-16 19:03:52.868 70000aeb8 Writing: to socket 4: <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN" "http://www.w3.org/TR/html4/strict.dtd">\x0a<html>\x0a\x0a<head>\x0a  <title>503 - Forwarding failure (Privoxy@localhost)</title>\x0a  <meta http-equiv="Content-Style-Type" content="text/css">\x0a  <meta http-equiv="Content-Script-Type" content="text/javascript">\x0a  <meta http-equiv="Content-Type" content="text/html; charset=UTF-8">\x0a  <meta name="robots" content="noindex,nofollow">\x0a  <link rel="shortcut icon" href="http://config.privoxy.org/error-favicon.ico">\x0a  <style type="text/css">\x0a\x0a/*\x0a * CSS for Privoxy CGI and script output\x0a *\x0a * $Id: cgi-style.css,v 1.14 2011/09/04 11:09:40 fabiankeil Exp $\x0a */\x0a\x0a/*\x0a * General rules: Font, Color, Headings, Margins, Links\x0a */\x0abody,td,th { font-family: arial, helvetica, helv, sans-serif; }\x0abody { background-color: #ffffff; color: #000000; }\x0a\x0ah1 { font-size: 140%; margin: 0px; }\x0ah2 { font-size: 120%; margin: 0px; }\x0ah3 { font-size: 110%; margin: 0px; }\x0a\x0ap,pre  { margin-left: 15px; }\x0ali { margin: 2px 15px; }\x0adl { margin: 2px 15px; }\x0a\x0aa:link    { color: #0000dd; text-decoration: none; }\x0aa:visited { color: #330099; text-decoration: none; }\x0aa:active  { color: #3333ff; text-decoration: none; }\x0a\x0a/*\x0a * Boxen as Table elements:\x0a */\x0atd.title   { border: solid black 1px; background-color: #dddddd; }\x0atd.box     { border: solid black 1px; background-color: #eeeeee; }\x0atd.info    { border: solid black 1px; background-color: #ccccff; }\x0atd.warning { border: solid black 1px; background-color: #ffdddd; }\x0a\x0a/*\x0a * Special Table Boxen: for nesting, naked container and for\x0a * the Status field in CGI Output:\x0a */\x0atd.wrapbox { border: solid black 1px; padding: 5px; }\x0atd.container { padding: 0px; }\x0atd.status  { border: solid black 1px; background-color: #ff0000; color: #ffffff; font-size: 300%; font-weight: bolder; }\x0a\x0a/*\x0a * Same Boxen as <div>s:\x0a */\x0adiv.title    { border: solid black 1px; background-color: #dddddd; margin: 20px; padding: 20px; }\x0adiv.box      { border: solid black 1px; background-color: #eeeeee; margin: 20px; padding: 20px; }\x0adiv.info     { border: solid black 1px; background-color: #ccccff; margin: 20px; padding: 20px; }\x0adiv.warning  { border: solid black 1px; background-color: #ffdddd; margin: 20px; padding: 20px; }\x0adiv.wrapbox  { border: solid black 1px;                            margin: 20px; padding:  5px; }\x0a\x0a\x0a/*\x0a * Bold definitions in <dl>s, grey BG for table headings, transparent (no-bordered) table\x0a */\x0adt { font-weight: bold; }\x0ath { background-color: #dddddd; }\x0atable.transparent { border-style: none}\x0a\x0a/*\x0a * Special purpose paragraphs: Small for page footers,\x0a * Important for quoting wrong or dangerous examples,\x0a * Whiteframed for the toggle?mini=y CGI\x0a */\x0ap.small { font-size: 10px; margin: 0px; }\x0ap.important { border: solid black 1px; background-color: #ffdddd; font-weight: bold; padding: 2px; }\x0ap.whiteframed { margin: 5px; padding: 5px; border: solid black 1px; text-align: center; background-color: #eeeeee; }\x0a\x0a/*\x0a * Links as buttons:\x0a */\x0a\x0atd.buttons {\x0a  padding: 2px;\x0a}\x0a\x0aa.cmd, td.indentbuttons a, td.buttons a {\x0a  white-space: nowrap;\x0a  width: auto;\x0a  padding: 2px;\x0a  background-color: #dddddd;\x0a  color:            #000000;\x0a  text-decoration: none;\x0a  border-top:    1px solid #ffffff;\x0a  border-left:   1px solid #ffffff;\x0a  border-bottom: 1px solid #000000;\x0a  border-right:  1px solid #000000;\x0a}\x0aa.cmd:hover, td.indentbuttons a:hover, td.buttons a:hover {\x0a  background-color: #eeeeee;\x0a}\x0aa.cmd:active, td.indentbuttons a:active, td.buttons a:active {\x0a  border-top:    1px solid #000000;\x0a  border-left:   1px solid #000000;\x0a  border-bottom: 1px solid #ffffff;\x0a  border-right:  1px solid #ffffff;\x0a}\x0a\x0a\x0a/*\x0a * Special red emphasis:\x0a */\x0aem.warning, strong.warning { color: #ff0000 }\x0a\x0a/*\x0a * In show-status we use tables directly behind headlines\x0a * and for some reason or another the headlines are set to\x0a * "margin:0" and leave the tables no air to breath.\x0a *\x0a * A proper fix would be to replace or remove the "margin:0",\x0a * but as this affects every cgi page we do it another time\x0a * and use this workaround until then.\x0a */\x0a.box table { margin-top: 1em; }\x0a\x0a/*\x0a * Let the URL and pattern input fields scale with the browser\x0a * width and try to prevent vertical scroll bars if the width\x0a * is less than 80 characters.\x0a */\x0ainput.url, input.pattern { width: 95%; }\x0a  </style>\x0a</head>\x0a\x0a<body>\x0a\x0a  <table summary="" cellpadding="20" cellspacing="10" border="0" width="100%">\x0a    <tr>\x0a      <td class="status">\x0a        503\x0a      </td>\x0a      <td class="title" style="width: 100%">\x0a\x0a   ... [too long, truncated]

And after this message, the connection failed.

2019-12-16 19:03:52.866 70000aeb8 Received: from socket 5: \x05\x00\x00\x03\x0byoutu

Maybe the proxy returned an invalid BND.ADDR ?

lovepocky commented 4 years ago

Could you paste snippet of your ssr-client config?

Here is mine.

{
    "password": "password",
    "method": "aes-128-ctr",
    "protocol": "auth_aes128_md5",
    "protocol_param": "",
    "obfs": "tls1.2_ticket_auth",
    "obfs_param": "",

    "udp": false,
    "timeout": 300,

    "server_settings": {
        "listen_address": "0.0.0.0",
        "listen_port": 10000
    },

    "client_settings": {
        "server": "${server_domain}",
        "server_port": 443,
        "listen_address": "0.0.0.0",
        "listen_port": 1080
    },

    "over_tls_settings": {
        "enable": true,
        "server_domain": "${server_domain}",
        "path": "/${path_parameter}/",
        "root_cert_file": ""
    }
}

ssrlive commented 4 years ago

it's a privoxy bug. recently, we can change the line

https://github.com/ShadowsocksR-Live/shadowsocksr-native/blob/master/src/client/client.c#L641

to

      buf[3] = 1;  init_data_len = 7;     //  memcpy(buf + 3, init_data, init_data_len);

Please test it on your PC. Hope the bug fixed.

ssrlive commented 4 years ago

this is the fixing to Privoxy by someone https://github.com/ssrlive/Privoxy/blob/master/gateway.c#L1210

lovepocky commented 4 years ago

After patching this line, it works now, thank you!

https://github.com/ShadowsocksR-Live/shadowsocksr-native/blob/98baa3c37df789038cabb72c03b1e53c21939b9c/src/client/client.c#L641

ShadowsocksR-Live / shadowsocksr-native