Opened 14 years ago

Last modified 7 years ago

#201 closed defect (Fixed)

unable fetching DirServer listings via HTTPproxy (v0105 - v0118)

Reported by: adrians Owned by:
Priority: Very Low Milestone:
Component: Core Tor/Tor Version:
Severity: Keywords:
Cc: adrians Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

I updated from 0.1.1.6 to 0.1.1.8 which stopped the proper functioning of TOR for me.

It seems that the client has problems fetching the new DirServer listing because it complaints about the HTTP response.

I attached the 0.1.1.8 debug-log.

Nearly (?) the same appeared in 0.1.1.6 and 0.1.1.7 what was (in 0.1.1.6) resolvable by _manually_ loading the listing via MSIE and replacing the content in cached-directory.

This no longer works for any of the versions 105, 116, 117, 118. Therefore I had to downgrade to 0.1.1.5 which is obviously not affected.

Maybe, it is in relation to the HTTPproxying as I always must use a HTTPproxy with basic HTTPauth.

+++++ using WinXP Prof. SP2

Oct 19 13:27:23.485 [notice] Tor 0.1.1.8-alpha opening new log file.
Oct 19 13:27:23.485 [info] or_state_load(): Loaded state from "./workingDir/state"
Oct 19 13:27:23.485 [info] crypto_global_init(): Initializing OpenSSL engine support.
Oct 19 13:27:23.532 [info] Using default implementation for RSA
Oct 19 13:27:23.548 [info] Using default implementation for DH
Oct 19 13:27:23.548 [info] Using default implementation for RAND
Oct 19 13:27:23.548 [info] Using default implementation for SHA1
Oct 19 13:27:23.548 [info] Using default implementation for 3DES
Oct 19 13:27:23.548 [info] Using default implementation for AES
Oct 19 13:27:24.391 [info] read_file_to_str(): Could not stat "./workingDir/cached-routers".
Oct 19 13:27:24.391 [info] read_file_to_str(): Could not stat "./workingDir/cached-routers.new".
Oct 19 13:27:24.391 [info] router_reload_networkstatus(): Skipping cached-status file with unexpected name "."
Oct 19 13:27:24.391 [info] router_reload_networkstatus(): Skipping cached-status file with unexpected name ".."
Oct 19 13:27:24.391 [notice] directory_info_has_arrived(): I learned some more directory information, but not enough to build a circuit.
Oct 19 13:27:24.391 [notice] update_router_descriptor_downloads(): Launching request for all routers
Oct 19 13:27:24.391 [info] router_pick_directory_server(): No reachable router entries for dirservers. Trying them all again.
Oct 19 13:27:24.391 [info] router_pick_directory_server(): Still no known router entries. Reloading and trying again.
Oct 19 13:27:24.391 [info] read_file_to_str(): Could not stat "./workingDir/cached-routers".
Oct 19 13:27:24.391 [info] read_file_to_str(): Could not stat "./workingDir/cached-routers.new".
Oct 19 13:27:24.391 [info] directory_get_from_dirserver(): No router found for server descriptors; falling back to dirserver list
Oct 19 13:27:24.391 [debug] directory_initiate_command(): initiating server descriptor fetch
Oct 19 13:27:24.391 [debug] connection_connect(): Connecting to [scrubbed]:80.
Oct 19 13:27:24.407 [debug] connection_connect(): Connection to [scrubbed]:80 in progress (sock 300).
Oct 19 13:27:24.407 [info] connection_add(): new conn type Directory, socket 300, nfds 3.
Oct 19 13:27:24.407 [debug] write_to_buf(): added 23 bytes to buf (now 23 total).
Oct 19 13:27:24.407 [debug] write_to_buf(): added 17 bytes to buf (now 40 total).
Oct 19 13:27:24.407 [debug] write_to_buf(): added 101 bytes to buf (now 141 total).
Oct 19 13:27:24.407 [info] update_networkstatus_client_downloads(): For 3/3 running directory servers, we have 0 live network-status documents. Downloading 2.
Oct 19 13:27:24.407 [info] router_pick_directory_server(): No reachable router entries for dirservers. Trying them all again.
Oct 19 13:27:24.407 [info] router_pick_directory_server(): Still no known router entries. Reloading and trying again.
Oct 19 13:27:24.407 [info] read_file_to_str(): Could not stat "./workingDir/cached-routers".
Oct 19 13:27:24.407 [info] read_file_to_str(): Could not stat "./workingDir/cached-routers.new".
Oct 19 13:27:24.407 [info] directory_get_from_dirserver(): No router found for network status; falling back to dirserver list
Oct 19 13:27:24.407 [debug] directory_initiate_command(): initiating network-status fetch
Oct 19 13:27:24.407 [debug] connection_connect(): Connecting to [scrubbed]:80.
Oct 19 13:27:24.407 [debug] connection_connect(): Connection to [scrubbed]:80 in progress (sock 320).
Oct 19 13:27:24.407 [info] connection_add(): new conn type Directory, socket 320, nfds 4.
Oct 19 13:27:24.407 [debug] write_to_buf(): added 22 bytes to buf (now 22 total).
Oct 19 13:27:24.407 [debug] write_to_buf(): added 98 bytes to buf (now 120 total).
Oct 19 13:27:24.407 [debug] write_to_buf(): added 100 bytes to buf (now 220 total).
Oct 19 13:27:24.407 [debug] retry_listeners(): Already have Socks listener on 127.0.0.1:9050
Oct 19 13:27:24.407 [debug] retry_listeners(): Already have Control listener on 127.0.0.1:9051
Oct 19 13:27:24.407 [debug] conn_write_callback(): socket 300 wants to write.
Oct 19 13:27:24.407 [info] connection_dir_finished_connecting(): Dir connection to router 18.244.0.114:80 established.
Oct 19 13:27:24.407 [debug] flush_buf(): 300: flushed 141 bytes, 0 ready to flush, 0 remain.
Oct 19 13:27:24.407 [debug] connection_dir_finished_flushing(): client finished sending command.
Oct 19 13:27:24.407 [debug] conn_write_callback(): socket 320 wants to write.
Oct 19 13:27:24.407 [info] connection_dir_finished_connecting(): Dir connection to router 86.59.5.130:80 established.
Oct 19 13:27:24.407 [debug] flush_buf(): 320: flushed 220 bytes, 0 ready to flush, 0 remain.
Oct 19 13:27:24.407 [debug] connection_dir_finished_flushing(): client finished sending command.
Oct 19 13:27:24.423 [debug] conn_read_callback(): socket 300 wants to read.
Oct 19 13:27:24.423 [debug] read_to_buf_impl(): Read 64 bytes. 64 on inbuf.
Oct 19 13:27:24.423 [debug] connection_dir_process_inbuf(): Got data, not eof. Leaving on inbuf.
Oct 19 13:27:24.423 [debug] conn_read_callback(): socket 300 wants to read.
Oct 19 13:27:24.423 [debug] read_to_buf_impl(): Encountered eof
Oct 19 13:27:24.423 [debug] connection_dir_process_inbuf(): Got data, not eof. Leaving on inbuf.
Oct 19 13:27:24.423 [debug] fetch_from_buf_http(): headerlen 47, bodylen 17.
Oct 19 13:27:24.423 [debug] connection_dir_client_reached_eof(): Received response from directory server '18.244.0.114:80': 400 "Bad Request"
Oct 19 13:27:24.423 [info] connection_dir_client_reached_eof(): HTTP body from server '18.244.0.114:80' was labeled as uncompressed, but it seems to be confusing binary junk.
Oct 19 13:27:24.423 [warn] connection_dir_client_reached_eof(): Unable to decompress HTTP body (server '18.244.0.114:80').
Oct 19 13:27:24.423 [info] conn_close_if_marked(): Cleaning up connection (fd 300).
Oct 19 13:27:24.423 [info] connection_dir_request_failed(): Giving up on directory server at '18.244.0.114'; retrying
Oct 19 13:27:24.423 [info] connection_remove(): removing socket 300 (type Directory), nfds now 3
Oct 19 13:27:24.423 [info] _connection_free(): closing fd 300.

...

[Automatically added by flyspray2trac: Operating System: Windows 2k/XP]

Child Tickets

Change History (6)

comment:1 Changed 14 years ago by arma

I'm not sure what's going on here. Are you using FascistFirewall or ReachableAddresses?

Does this still not work for you?

Tell me more about your proxy?

I need more information before I can track it down.

comment:2 Changed 14 years ago by nickm

No info provided; downgrading priority.

comment:3 Changed 14 years ago by adrians

The problem still remains in 0.1.1.10.
Older versions up to and including 0.1.1.5 seem to have the same problem but do not request data from DirServers if a valid cached-directory file is found at start-up. That´s why I manually download it from the DirServers and save it into the respective file. Newer versions always request new information from DirServers.

Therefore I did some TCPdumping. To my mind the HTTP request header line "Content-Length: 0" is causing the problem.

direct telnet to my proxy - works
####################
GET http://66.148.84.248:9030/ HTTP/1.0
Host: 66.148.84.248:9030
Proxy-Authorization: Basic c2c0PASWD=
####################

direct telnet to my proxy does NOT work
####################
GET http://66.148.84.248:9030/ HTTP/1.0
Host: 66.148.84.248:9030
Proxy-Authorization: Basic c2c0PASWD=
Content-Length: 0

HTTP/1.1 400 Bad Request
Connection: close
400 Bad Request
####################

test results of some TOR versions:

tor 0.1.0.8 without cached-directory
####################
GET http://66.148.84.248:9030/tor/dir.z HTTP/1.0
Content-Length: 0
Host: 66.148.84.248:9030
Proxy-Authorization: Basic c2c0PASWD=

HTTP/1.1 400 Bad Request
Connection: close
400 Bad Request
####################

tor 0.1.1.10 without cached-directory
####################
GET http://18.244.0.188:9031/tor/server/all.z HTTP/1.0
Content-Length: 0
Host: 18.244.0.188:9031
Proxy-Authorization: Basic c2c0PASWD=

HTTP/1.1 400 Bad Request
Connection: close
400 Bad Request
####################

Would it be useful to integrate the HTTP option "Proxy-Connection: Keep-Alive" (e.g. MSIE, Firefox) or "Connection: Keep-Alive" (http://www.w3.org/Protocols/rfc2616/rfc2616-sec8.html) to use HTTP pipelining?

comment:4 Changed 13 years ago by nickm

Okay. In CVS, we no longer add a content-length: 0 header with GET requests.
(Nothing I can see in the HTTP 1.0 RFC forbids this, but hey.)

comment:5 Changed 13 years ago by nickm

flyspray2trac: bug closed.
fixed in cvs?

comment:6 Changed 7 years ago by nickm

Component: Tor ClientTor
Note: See TracTickets for help on using tickets.