Tor's socks5 handshake with username/password auth doesn't follow the protocol spec, and pidgin notices
With Tor 0.2.4.12-alpha and the #8117 (moved) patch, my pidgin will no longer handshake with my Tor.
May 15 01:15:13.260 [debug] conn_read_callback(): socket 6 wants to read.
May 15 01:15:13.260 [debug] connection_handle_listener_read(): Connection accepted on socket 14 (child of fd 6).
May 15 01:15:13.260 [debug] connection_add_impl(): new conn type Socks, socket 14, address 127.0.0.1, n_conns 6.
May 15 01:15:13.260 [debug] conn_read_callback(): socket 14 wants to read.
May 15 01:15:13.260 [debug] read_to_chunk(): New byte 0 is '5'
May 15 01:15:13.260 [debug] read_to_chunk(): New byte 1 is '3'
May 15 01:15:13.260 [debug] read_to_chunk(): New byte 2 is '0'
May 15 01:15:13.260 [debug] read_to_chunk(): New byte 3 is '3'
May 15 01:15:13.260 [debug] read_to_chunk(): New byte 4 is '2'
May 15 01:15:13.260 [debug] read_to_chunk(): Read 5 bytes. 5 on inbuf.
May 15 01:15:13.260 [debug] connection_ap_handshake_process_socks(): entered.
May 15 01:15:13.260 [debug] parse_socks(): socks5: accepted method 2 (username/password)
May 15 01:15:13.260 [debug] connection_write_to_buf_impl_(): Wrote byte 0: '5'
May 15 01:15:13.260 [debug] connection_write_to_buf_impl_(): Wrote byte 1: '2'
May 15 01:15:13.260 [debug] connection_ap_handshake_process_socks(): socks handshake not all here yet.
May 15 01:15:13.260 [debug] connection_ap_handshake_process_socks(): entered.
May 15 01:15:13.260 [debug] connection_ap_handshake_process_socks(): socks handshake not all here yet.
May 15 01:15:13.260 [debug] conn_write_callback(): socket 14 wants to write.
May 15 01:15:13.260 [debug] conn_read_callback(): socket 14 wants to read.
May 15 01:15:13.260 [debug] read_to_chunk(): New byte 0 is '1'
May 15 01:15:13.261 [debug] read_to_chunk(): New byte 1 is '0'
May 15 01:15:13.261 [debug] read_to_chunk(): New byte 2 is '0'
May 15 01:15:13.261 [debug] read_to_chunk(): Read 3 bytes. 3 on inbuf.
May 15 01:15:13.261 [debug] connection_ap_handshake_process_socks(): entered.
May 15 01:15:13.261 [debug] parse_socks(): socks5: Accepted username/password without checking.
May 15 01:15:13.261 [debug] connection_write_to_buf_impl_(): Wrote byte 0: '5'
May 15 01:15:13.261 [debug] connection_write_to_buf_impl_(): Wrote byte 1: '0'
May 15 01:15:13.261 [debug] connection_ap_handshake_process_socks(): socks handshake not all here yet.
May 15 01:15:13.261 [debug] connection_ap_handshake_process_socks(): entered.
May 15 01:15:13.261 [debug] connection_ap_handshake_process_socks(): socks handshake not all here yet.
May 15 01:15:13.261 [debug] conn_write_callback(): socket 14 wants to write.
May 15 01:15:13.261 [debug] conn_read_callback(): socket 14 wants to read.
May 15 01:15:13.261 [debug] read_to_chunk(): Encountered eof on fd 14
May 15 01:15:13.261 [debug] connection_ap_handshake_process_socks(): entered.
May 15 01:15:13.261 [debug] connection_ap_handshake_process_socks(): socks handshake not all here yet.
May 15 01:15:13.261 [info] connection_edge_reached_eof(): conn (fd 14) reached eof. Closing.
If I change my socksport line in my torrc to
SocksPort 9050 PreferSOCKSNoAuth
then it works again:
May 15 01:19:03.307 [debug] conn_read_callback(): socket 6 wants to read.
May 15 01:19:03.307 [debug] connection_handle_listener_read(): Connection accepted on socket 11 (child of fd 6).
May 15 01:19:03.307 [debug] connection_add_impl(): new conn type Socks, socket 11, address 127.0.0.1, n_conns 5.
May 15 01:19:03.307 [debug] conn_read_callback(): socket 11 wants to read.
May 15 01:19:03.307 [debug] read_to_chunk(): New byte 0 is '5'
May 15 01:19:03.307 [debug] read_to_chunk(): New byte 1 is '3'
May 15 01:19:03.307 [debug] read_to_chunk(): New byte 2 is '0'
May 15 01:19:03.307 [debug] read_to_chunk(): New byte 3 is '3'
May 15 01:19:03.307 [debug] read_to_chunk(): New byte 4 is '2'
May 15 01:19:03.307 [debug] read_to_chunk(): Read 5 bytes. 5 on inbuf.
May 15 01:19:03.307 [debug] connection_ap_handshake_process_socks(): entered.
May 15 01:19:03.307 [debug] parse_socks(): socks5: accepted method 0 (no authentication)
May 15 01:19:03.307 [debug] connection_write_to_buf_impl_(): Wrote byte 0: '5'
May 15 01:19:03.307 [debug] connection_write_to_buf_impl_(): Wrote byte 1: '0'
May 15 01:19:03.307 [debug] connection_ap_handshake_process_socks(): socks handshake not all here yet.
May 15 01:19:03.307 [debug] connection_ap_handshake_process_socks(): entered.
May 15 01:19:03.307 [debug] connection_ap_handshake_process_socks(): socks handshake not all here yet.
May 15 01:19:03.307 [debug] conn_write_callback(): socket 11 wants to write.
May 15 01:19:03.311 [debug] conn_read_callback(): socket 11 wants to read.
May 15 01:19:03.311 [debug] read_to_chunk(): New byte 0 is '5'
May 15 01:19:03.311 [debug] read_to_chunk(): New byte 1 is '1'
May 15 01:19:03.311 [debug] read_to_chunk(): New byte 2 is '0'
May 15 01:19:03.311 [debug] read_to_chunk(): New byte 3 is '3'
May 15 01:19:03.311 [debug] read_to_chunk(): New byte 4 is '22'
May 15 01:19:03.311 [debug] read_to_chunk(): New byte 5 is '97'
[...]
May 15 01:19:03.311 [debug] read_to_chunk(): Read 29 bytes. 29 on inbuf.
May 15 01:19:03.311 [debug] connection_ap_handshake_process_socks(): entered.
May 15 01:19:03.312 [debug] parse_socks(): socks5: checking request
May 15 01:19:03.312 [debug] parse_socks(): socks5: fqdn address type