Test Failed: Method Not Allowed

betsythefc commented 6 years ago

On my podcast app (AntennaPod) setting the HTTP proxy to go through Orbot, I get the message "Test failed: Method Not Allowed". I've confirmed by testing with another proxy that the issue is with Orbot.

What else will you need to diagnose this?

pgerber commented 6 years ago

Tor responds with HTTP/1.0 405 Method Not Allowed.

Debug log:

05-18 20:53:00.949  4571  4571 D Tor     : conn_read_callback(): socket 10 wants to read.
05-18 20:53:00.949  4571  4571 D Tor     : connection_handle_listener_read(): Connection accepted on socket 14 (child of fd 10).
05-18 20:53:00.949  4571  4571 I Tor     : connection_handle_listener_read(): New SOCKS connection opened from 127.0.0.1.
05-18 20:53:00.949  4571  4571 I Tor     : connection_handle_listener_read(): New SOCKS connection opened from 127.0.0.1.
05-18 20:53:00.949  4571  4571 D Tor     : connection_add_impl(): new conn type Socks, socket 14, address 127.0.0.1, n_conns 8.
05-18 20:53:00.959  4571  4571 D Tor     : conn_read_callback(): socket 14 wants to read.
05-18 20:53:00.959  4571  4571 D Tor     : read_to_chunk(): Read 135 bytes. 135 on inbuf.
05-18 20:53:00.959  4571  4571 D Tor     : fetch_from_buf_http(): headerlen 135, bodylen 0.
05-18 20:53:00.959  4571  4571 D Tor     : parse_http_command(): Skipping over 'http[s]://hostname/' string
05-18 20:53:00.959  4571  4571 W Tor     : Saying "HTTP/1.0 405 Method Not Allowed\r\n\r\n"
05-18 20:53:00.959  4571  4571 W Tor     : Saying "HTTP/1.0 405 Method Not Allowed\r\n\r\n"
05-18 20:53:00.959  4571  4571 W Tor     : connection_mark_unattached_ap_(): Bug: stream (marked at src/or/connection_edge.c:2551) sending two socks replies? (on Tor 0.3.3.5-rc 81d71f0d41adf0d8)
05-18 20:53:00.959  4571  4571 W Tor     : connection_mark_unattached_ap_(): Bug: stream (marked at src/or/connection_edge.c:2551) sending two socks replies? (on Tor 0.3.3.5-rc 81d71f0d41adf0d8)
05-18 20:53:00.959  4571  4571 D Tor     : conn_close_if_marked(): Cleaning up connection (fd 14).
05-18 20:53:00.960  4571  4571 D Tor     : connection_remove(): removing socket 14 (type Socks), n_conns now 8
05-18 20:53:00.960  4571  4571 D Tor     : connection_free_minimal(): closing fd 14.
05-18 20:53:00.960  4571  4571 D Tor     : conn_write_callback(): socket 4 wants to write.
05-18 20:53:00.960  4449  4572 D Orbot   : WARN: Saying "HTTP/1.0 405 Method Not Allowed\r\n\r\n" 
05-18 20:53:00.961  4449  4572 D Orbot   : WARN: connection_mark_unattached_ap_(): Bug: stream (marked at src/or/connection_edge.c:2551) sending two socks replies? (on Tor 0.3.3.5-rc 81d71f0d41adf0d8) 
05-18 20:53:01.040  4571  4571 D Tor     : circuit_remove_handled_ports(): Port 443 is already being handled; removing.
05-18 20:53:01.040  4571  4571 D Tor     : conn_write_callback(): socket 4 wants to write.

pgerber commented 6 years ago

So, I looked into it a bit closer. Turns out that Tor's newly built-in HTTP proxy only supports the use of the HTTP CONNECT method (AKA tunneling) but not the use of regular HTTP requests. The previously used proxy provider, Polipo, supported it.

Regular HTTP VS Tunneling Illustrated using Curl

Using curl with --proxy (regular HTTP request) fails

$ curl -v --proxy http://localhost:8228 http://check.torproject.org
* Rebuilt URL to: http://check.torproject.org/
*   Trying ::1...
* TCP_NODELAY set
* connect to ::1 port 8228 failed: Connection refused
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to (nil) (127.0.0.1) port 8228 (#0)
> GET http://check.torproject.org/ HTTP/1.1
> Host: check.torproject.org
> User-Agent: curl/7.52.1
> Accept: */*
> Proxy-Connection: Keep-Alive
> 
* HTTP 1.0, assume close after body
< HTTP/1.0 405 Method Not Allowed
< 
* Curl_http_done: called premature == 0
* Closing connection 0

… but using tunneling (HTTP CONNECT) works …

$ curl -v --proxytunnel http://localhost:8228 http://check.torproject.org
* Rebuilt URL to: http://localhost:8228/
*   Trying ::1...
* TCP_NODELAY set
* connect to ::1 port 8228 failed: Connection refused
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 8228 (#0)
> GET / HTTP/1.1
> Host: localhost:8228
> User-Agent: curl/7.52.1
> Accept: */*
> 
* HTTP 1.0, assume close after body
< HTTP/1.0 405 Method Not Allowed
< 
* Curl_http_done: called premature == 0
* Closing connection 0
* Rebuilt URL to: http://check.torproject.org/
*   Trying 138.201.14.212...
* TCP_NODELAY set
* Connected to check.torproject.org (138.201.14.212) port 80 (#1)
> GET / HTTP/1.1
> Host: check.torproject.org
> User-Agent: curl/7.52.1
> Accept: */*
> 
< HTTP/1.1 301 Moved Permanently
< Date: Fri, 18 May 2018 19:59:07 GMT
< Server: Apache
< X-Content-Type-Options: nosniff
< X-Frame-Options: sameorigin
< X-Xss-Protection: 1
< Referrer-Policy: no-referrer
< Location: https://check.torproject.org/
< Content-Length: 307
< Content-Type: text/html; charset=iso-8859-1
< 
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>301 Moved Permanently</title>
</head><body>
<h1>Moved Permanently</h1>
<p>The document has moved <a href="https://check.torproject.org/">here</a>.</p>
<hr>
<address>Apache Server at check.torproject.org Port 80</address>
</body></html>
* Curl_http_done: called premature == 0
* Connection #1 to host check.torproject.org left intact

AndroidPod Implementation

Antenna pod uses regular HTTP requests. Note the HEAD http://www.google.com/ in the dump below (full tcpdump capture):

Conenction dump of AntennaPod connecting to Tor's proxy port:

$ /usr/sbin/tcpdump -r dump -Xv
reading from file dump, link-type EN10MB (Ethernet)
21:32:02.891347 IP (tos 0x0, ttl 64, id 4232, offset 0, flags [DF], proto TCP (6), length 60)
    localhost.33578 > localhost.8228: Flags [S], cksum 0xfe30 (incorrect -> 0xb616), seq 3091408940, win 43690, options [mss 65495,sackOK,TS val 1145186072 ecr 0,nop,wscale 7], length 0
        0x0000:  4500 003c 1088 4000 4006 2c32 7f00 0001  E..<..@.@.,2....
        0x0010:  7f00 0001 832a 2024 b843 282c 0000 0000  .....*.$.C(,....
        0x0020:  a002 aaaa fe30 0000 0204 ffd7 0402 080a  .....0..........
        0x0030:  4442 2718 0000 0000 0103 0307            DB'.........
21:32:02.891395 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto TCP (6), length 60)
    localhost.8228 > localhost.33578: Flags [S.], cksum 0xfe30 (incorrect -> 0xe6ea), seq 1726151901, ack 3091408941, win 43690, options [mss 65495,sackOK,TS val 1145186072 ecr 1145186072,nop,wscale 7], length 0
        0x0000:  4500 003c 0000 4000 4006 3cba 7f00 0001  E..<..@.@.<.....
        0x0010:  7f00 0001 2024 832a 66e2 fcdd b843 282d  .....$.*f....C(-
        0x0020:  a012 aaaa fe30 0000 0204 ffd7 0402 080a  .....0..........
        0x0030:  4442 2718 4442 2718 0103 0307            DB'.DB'.....
21:32:02.891438 IP (tos 0x0, ttl 64, id 4233, offset 0, flags [DF], proto TCP (6), length 52)
    localhost.33578 > localhost.8228: Flags [.], cksum 0xfe28 (incorrect -> 0xb92f), ack 1, win 342, options [nop,nop,TS val 1145186072 ecr 1145186072], length 0
        0x0000:  4500 0034 1089 4000 4006 2c39 7f00 0001  E..4..@.@.,9....
        0x0010:  7f00 0001 832a 2024 b843 282d 66e2 fcde  .....*.$.C(-f...
        0x0020:  8010 0156 fe28 0000 0101 080a 4442 2718  ...V.(......DB'.
        0x0030:  4442 2718                                DB'.
21:32:03.593646 IP (tos 0x0, ttl 64, id 4234, offset 0, flags [DF], proto TCP (6), length 187)
    localhost.33578 > localhost.8228: Flags [P.], cksum 0xfeaf (incorrect -> 0xf488), seq 1:136, ack 1, win 342, options [nop,nop,TS val 1145186775 ecr 1145186072], length 135
        0x0000:  4500 00bb 108a 4000 4006 2bb1 7f00 0001  E.....@.@.+.....
        0x0010:  7f00 0001 832a 2024 b843 282d 66e2 fcde  .....*.$.C(-f...
        0x0020:  8018 0156 feaf 0000 0101 080a 4442 29d7  ...V........DB).
        0x0030:  4442 2718 4845 4144 2068 7474 703a 2f2f  DB'.HEAD.http://
        0x0040:  7777 772e 676f 6f67 6c65 2e63 6f6d 2f20  www.google.com/.
        0x0050:  4854 5450 2f31 2e31 0d0a 486f 7374 3a20  HTTP/1.1..Host:.
        0x0060:  7777 772e 676f 6f67 6c65 2e63 6f6d 0d0a  www.google.com..
        0x0070:  436f 6e6e 6563 7469 6f6e 3a20 4b65 6570  Connection:.Keep
        0x0080:  2d41 6c69 7665 0d0a 4163 6365 7074 2d45  -Alive..Accept-E
        0x0090:  6e63 6f64 696e 673a 2067 7a69 700d 0a55  ncoding:.gzip..U
        0x00a0:  7365 722d 4167 656e 743a 206f 6b68 7474  ser-Agent:.okhtt
        0x00b0:  702f 332e 392e 300d 0a0d 0a              p/3.9.0....
21:32:03.593680 IP (tos 0x0, ttl 64, id 50298, offset 0, flags [DF], proto TCP (6), length 52)
    localhost.8228 > localhost.33578: Flags [.], cksum 0xfe28 (incorrect -> 0xb322), ack 136, win 350, options [nop,nop,TS val 1145186775 ecr 1145186775], length 0
        0x0000:  4500 0034 c47a 4000 4006 7847 7f00 0001  E..4.z@.@.xG....
        0x0010:  7f00 0001 2024 832a 66e2 fcde b843 28b4  .....$.*f....C(.
        0x0020:  8010 015e fe28 0000 0101 080a 4442 29d7  ...^.(......DB).
        0x0030:  4442 29d7                                DB).
21:32:03.593845 IP (tos 0x0, ttl 64, id 50299, offset 0, flags [DF], proto TCP (6), length 87)
    localhost.8228 > localhost.33578: Flags [P.], cksum 0xfe4b (incorrect -> 0xb64b), seq 1:36, ack 136, win 350, options [nop,nop,TS val 1145186775 ecr 1145186775], length 35
        0x0000:  4500 0057 c47b 4000 4006 7823 7f00 0001  E..W.{@.@.x#....
        0x0010:  7f00 0001 2024 832a 66e2 fcde b843 28b4  .....$.*f....C(.
        0x0020:  8018 015e fe4b 0000 0101 080a 4442 29d7  ...^.K......DB).
        0x0030:  4442 29d7 4854 5450 2f31 2e30 2034 3035  DB).HTTP/1.0.405
        0x0040:  204d 6574 686f 6420 4e6f 7420 416c 6c6f  .Method.Not.Allo
        0x0050:  7765 640d 0a0d 0a                        wed....
21:32:03.593874 IP (tos 0x0, ttl 64, id 4235, offset 0, flags [DF], proto TCP (6), length 52)
    localhost.33578 > localhost.8228: Flags [.], cksum 0xfe28 (incorrect -> 0xb307), ack 36, win 342, options [nop,nop,TS val 1145186775 ecr 1145186775], length 0
        0x0000:  4500 0034 108b 4000 4006 2c37 7f00 0001  E..4..@.@.,7....
        0x0010:  7f00 0001 832a 2024 b843 28b4 66e2 fd01  .....*.$.C(.f...
        0x0020:  8010 0156 fe28 0000 0101 080a 4442 29d7  ...V.(......DB).
        0x0030:  4442 29d7                                DB).
21:32:03.593942 IP (tos 0x0, ttl 64, id 50300, offset 0, flags [DF], proto TCP (6), length 52)
    localhost.8228 > localhost.33578: Flags [F.], cksum 0xfe28 (incorrect -> 0xb2fe), seq 36, ack 136, win 350, options [nop,nop,TS val 1145186775 ecr 1145186775], length 0
        0x0000:  4500 0034 c47c 4000 4006 7845 7f00 0001  E..4.|@.@.xE....
        0x0010:  7f00 0001 2024 832a 66e2 fd01 b843 28b4  .....$.*f....C(.
        0x0020:  8011 015e fe28 0000 0101 080a 4442 29d7  ...^.(......DB).
        0x0030:  4442 29d7                                DB).
21:32:03.594134 IP (tos 0x0, ttl 64, id 4236, offset 0, flags [DF], proto TCP (6), length 52)
    localhost.33578 > localhost.8228: Flags [F.], cksum 0xfe28 (incorrect -> 0xb305), seq 136, ack 37, win 342, options [nop,nop,TS val 1145186775 ecr 1145186775], length 0
        0x0000:  4500 0034 108c 4000 4006 2c36 7f00 0001  E..4..@.@.,6....
        0x0010:  7f00 0001 832a 2024 b843 28b4 66e2 fd02  .....*.$.C(.f...
        0x0020:  8011 0156 fe28 0000 0101 080a 4442 29d7  ...V.(......DB).
        0x0030:  4442 29d7                                DB).
21:32:03.594184 IP (tos 0x0, ttl 64, id 50301, offset 0, flags [DF], proto TCP (6), length 52)
    localhost.8228 > localhost.33578: Flags [.], cksum 0xfe28 (incorrect -> 0xb2fd), ack 137, win 350, options [nop,nop,TS val 1145186775 ecr 1145186775], length 0
        0x0000:  4500 0034 c47d 4000 4006 7844 7f00 0001  E..4.}@.@.xD....
        0x0010:  7f00 0001 2024 832a 66e2 fd02 b843 28b5  .....$.*f....C(.
        0x0020:  8010 015e fe28 0000 0101 080a 4442 29d7  ...^.(......DB).
        0x0030:  4442 29d7                                DB).

tommienu commented 6 years ago

Seeing the same issue when proxying Chromium through Orbot. So this is definitely and issue that will grow as were unable to use webview (chromium) proxying together with the new version. This worked fine in 16.0.1-BETA-1.

n8fr8 commented 6 years ago

We will fix this (ideally by getting Tor's HTTP proxy to add the capability), but... you really should be using Orfox for browsing.

betsythefc commented 6 years ago

I use orbot mostly for browsing, but also route my RSS and Podcast feeds through it.

tommienu commented 6 years ago

@n8fr8

We will fix this (ideally by getting Tor's HTTP proxy to add the capability), but... you really should be using Orfox for browsing.

For sure, it's a legacy thing that we'd like to maintain though.

And thank you for fixing it. I'm sure a lot of other projects that uses Orbot will appreciate this.

n8fr8 commented 6 years ago

It would be good to have a list of popular open-source apps that people like to proxy through Orbot. Then perhaps we can add NetCipher/SOCKS proxying support to them ourselves.

miguelmarco commented 6 years ago

Hi, I am finding this problem too with ZcashPannel (https://github.com/miguelmarco/ZcashPannel), which is definitely an app intended to be used through orbot (using netcipher).

It used to work ok before, but after an orbot update, I am getting this kind of error too.

eighthave commented 5 years ago

I'm seeing this with F-Droid as well,using Orbot 16.0.5-RC-2-tor-0.3.4.9. Tor Browser for Android was working fine at the same time. It works when I revert to Orbot 15.5.1-RC-2-multi-SDK23.

Is this related at all? https://trac.torproject.org/projects/tor/ticket/26470

guardianproject / orbot

Test Failed: Method Not Allowed #159

Regular HTTP VS Tunneling Illustrated using Curl

AndroidPod Implementation