[Author Prev][Author Next][Thread Prev][Thread Next][Author Index][Thread Index]
[tor-bugs] #18351 [Tor]: Relay directory failures and logging are too aggressive
#18351: Relay directory failures and logging are too aggressive
------------------------+--------------------------------
Reporter: sysrqb | Owner:
Type: defect | Status: new
Priority: Medium | Milestone: Tor: 0.2.8.x-final
Component: Tor | Version: Tor: unspecified
Severity: Normal | Keywords:
Actual Points: | Parent ID:
Points: | Sponsor:
------------------------+--------------------------------
As mentioned in #18348, when a relay exhausts the available directory
authorities, it now produces the below warning. It seems there are three
points to consider when taken in the context of a relay:
1) The actual log message is not correct, this completely unrelated to the
firewall/reachability logic
2) I'm not certain, but I believe this is likely a normal situation on the
network
3) Logging this at warn seems overly aggressive for something a user can't
control
1) and 2) are actually the same point. See the attached debug log extract
(including some additional messages I added). Nearly all the dir auths are
marked as down due to 304 responses. Should tor be less aggressive about
avoiding a directory authority after a 304? I worry, if this is normal
behavior, then the network's load is not be distributed among all the
directories. It seems like they're being picked off, one-by-one.
Especially when this is in the logs - unless I'm reading it wrong they're
identical requests despite the first one succeeding (possibly another
bug?):
{{{
--
Feb 20 05:26:37.000 [info] directory_send_command: Downloading consensus
from 128.31.0.39:9131 using /tor/status-vote/current/consensus-
microdesc/0232AF+14C131+23D15D+49015F+805509+D586D1+E8A9C4+ED03BB+EFCBE7.z
Feb 20 05:26:39.000 [debug] connection_dir_client_reached_eof: Received
response from directory server '128.31.0.39:9131': 200 "OK" (purpose: 14)
--
Feb 20 05:27:37.000 [info] directory_send_command: Downloading consensus
from 131.188.40.189 using /tor/status-vote/current/consensus-
microdesc/0232AF+14C131+23D15D+49015F+805509+D586D1+E8A9C4+ED03BB+EFCBE7.z
Feb 20 05:27:38.000 [debug] connection_dir_client_reached_eof: Received
response from directory server '131.188.40.189:80': 304 "Not modified"
(purpose: 14)
Feb 20 05:29:37.000 [info] directory_send_command: Downloading consensus
from 199.254.238.52 using /tor/status-vote/current/consensus-
microdesc/0232AF+14C131+23D15D+49015F+805509+D586D1+E8A9C4+ED03BB+EFCBE7.z
Feb 20 05:29:41.000 [debug] connection_dir_client_reached_eof: Received
response from directory server '199.254.238.52:80': 304 "Not modified"
(purpose: 14)
}}}
In the attached log, router_set_status() records when a node is marked
down. The preceeding lines should say why.
router_pick_trusteddirserver_impl() records which nodes we disqualified
when we want to send a new request.
Scary backtrace:
{{{
[warn] router_picked_poor_directory_log: Bug: Firewall denied all OR and
Dir addresses for all relays when searching for a directory. (on Tor
0.2.8.1-alpha-dev 1f679d4ae11cd976)
[warn] Bug: Node search initiated by. Stack trace: (on Tor 0.2.8.1-alpha-
dev 1f679d4ae11cd976)
[warn] Bug: 0x1157e08 <log_backtrace+0x48> at /usr/local/bin/tor (on
Tor 0.2.8.1-alpha-dev 1f679d4ae11cd976)
[warn] Bug: 0x10af86b <hid_serv_responsible_for_desc_id+0xdeb> at
/usr/local/bin/tor (on Tor 0.2.8.1-alpha-dev 1f679d4ae11cd976)
[warn] Bug: 0x10a6a86 <router_pick_trusteddirserver+0x76> at
/usr/local/bin/tor (on Tor 0.2.8.1-alpha-dev 1f679d4ae11cd976)
[warn] Bug: 0x1126183 <directory_get_from_dirserver+0x293> at
/usr/local/bin/tor (on Tor 0.2.8.1-alpha-dev 1f679d4ae11cd976)
[warn] Bug: 0x10ad45a <launch_descriptor_downloads+0x4ba> at
/usr/local/bin/tor (on Tor 0.2.8.1-alpha-dev 1f679d4ae11cd976)
[warn] Bug: 0x10ad21a <launch_descriptor_downloads+0x27a> at
/usr/local/bin/tor (on Tor 0.2.8.1-alpha-dev 1f679d4ae11cd976)
[warn] Bug: 0x10adb6b
<update_consensus_router_descriptor_downloads+0x6cb> at /usr/local/bin/tor
(on Tor 0.2.8.1-alpha-dev 1f679d4ae11cd976)
[warn] Bug: 0x10ac7f6 <update_all_descriptor_downloads+0x66> at
/usr/local/bin/tor (on Tor 0.2.8.1-alpha-dev 1f679d4ae11cd976)
[warn] Bug: 0x10602c8 <directory_info_has_arrived+0x48> at
/usr/local/bin/tor (on Tor 0.2.8.1-alpha-dev 1f679d4ae11cd976)
[warn] Bug: 0x1128890 <connection_dir_reached_eof+0x1160> at
/usr/local/bin/tor (on Tor 0.2.8.1-alpha-dev 1f679d4ae11cd976)
[warn] Bug: 0x1107f5b <connection_handle_read+0xb3b> at
/usr/local/bin/tor (on Tor 0.2.8.1-alpha-dev 1f679d4ae11cd976)
[warn] Bug: 0x105f044 <connection_add_impl+0x214> at
/usr/local/bin/tor (on Tor 0.2.8.1-alpha-dev 1f679d4ae11cd976)
[warn] Bug: 0x801aa538e <event_base_loop+0x81e> at
/usr/local/lib/libevent-2.0.so.5 (on Tor 0.2.8.1-alpha-dev
1f679d4ae11cd976)
[warn] Bug: 0x1060cc5 <do_main_loop+0x5c5> at /usr/local/bin/tor (on
Tor 0.2.8.1-alpha-dev 1f679d4ae11cd976)
[warn] Bug: 0x1062fcf <tor_main+0xdf> at /usr/local/bin/tor (on Tor
0.2.8.1-alpha-dev 1f679d4ae11cd976)
[warn] Bug: 0x105ed49 <main+0x19> at /usr/local/bin/tor (on Tor
0.2.8.1-alpha-dev 1f679d4ae11cd976)
[warn] Bug: 0x105ec41 <_start+0x1a1> at /usr/local/bin/tor (on Tor
0.2.8.1-alpha-dev 1f679d4ae11cd976)
}}}
--
Ticket URL: <https://trac.torproject.org/projects/tor/ticket/18351>
Tor Bug Tracker & Wiki <https://trac.torproject.org/>
The Tor Project: anonymity online
_______________________________________________
tor-bugs mailing list
tor-bugs@xxxxxxxxxxxxxxxxxxxx
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs