Opened 6 years ago

Closed 3 years ago

#10461 closed defect (fixed)

tor seems to ignore "DirServer" option

Reported by: mr-4 Owned by: nickm
Priority: Medium Milestone: Tor: unspecified
Component: Core Tor/Tor Version: Tor: 0.2.4.18-rc
Severity: Normal Keywords: tor-client, 025-triaged, 026-triaged-1, 027-triaged-1-out, tor-03-unspecified-201612
Cc: Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

I've got the following 3 directives in my torrc:

DirServer 95.223.60.130:443 23155386E3B4B93B0294DB3A6263A8FAFE273255
DirServer 89.245.227.226:9001 6CB447C4CBCC4F5BDB4BA096902C2956CB534999
DirServer 109.228.139.83:9001 9DD97868543CB3CF432B96C082DFAC1FD16F6768

but none of the above statements seem to have been honoured by tor as I get this in my logs (debug-level):

[notice] {GENERAL} 0 entries in guards
[info] {CIRC} compute_weighted_bandwidths(): Empty routerlist passed in to consensus weight node selection for rule weight as guard
[info] {CIRC} smartlist_choose_node_by_bandwidth(): Empty routerlist passed in to old node selection for rule weight as guard
[info] {DIR} directory_pick_generic_dirserver(): No router found for consensus network-status fetch; falling back to dirserver list.
[info] {DIR} router_pick_dirserver_generic(): No dirservers are reachable. Trying them all again.
[notice] {DIR} While fetching directory info, no running dirservers known. Will try again later. (purpose 14)
[info] {GENERAL} or_state_save(): Saved state to "/var/lib/tor/tor/state"

Why?

I don't usually set the DirServer options, but, as of yesterday, my tor gets stuck at 5% when I shutdown tor after getting the following log:

{PROTOCOL} Received a bad CERTS cell from [scrubbed]:9001: The link certificate didn't match the TLS public key

I then wiped out the entire /var/lib/tor directory (to force fresh consensus download) and then got this when I tried to start tor (again, debug-level):

=============================
Dec 21 11:17:24.000 [notice] {GENERAL} 0 entries in guards
Dec 21 11:17:24.000 [info] {CIRC} compute_weighted_bandwidths(): Empty routerlist passed in to consensus weight node selection for rule weight as guard
Dec 21 11:17:24.000 [info] {CIRC} smartlist_choose_node_by_bandwidth(): Empty routerlist passed in to old node selection for rule weight as guard
Dec 21 11:17:24.000 [info] {DIR} directory_pick_generic_dirserver(): No router found for consensus network-status fetch; falling back to dirserver list.
Dec 21 11:17:24.000 [debug] {DIR} directory_initiate_command_rend(): anonymized 0, use_begindir 1.
Dec 21 11:17:24.000 [debug] {DIR} directory_initiate_command_rend(): Initiating consensus network-status fetch
Dec 21 11:17:24.000 [info] {APP} connection_ap_make_link(): Making internal direct tunnel to [scrubbed]:443 ...
Dec 21 11:17:24.000 [debug] {NET} connection_add_impl(): new conn type Socks, socket -1, address (Tor_internal), n_conns 3.
Dec 21 11:17:24.000 [debug] {DIR} circuit_get_open_circ_or_launch(): considering 1, $7BE683E65D48141321C5ED92F075C55364AC7123
Dec 21 11:17:24.000 [debug] {CIRC} onion_pick_cpath_exit(): Launching a one-hop circuit for dir tunnel.
Dec 21 11:17:24.000 [info] {CIRC} onion_pick_cpath_exit(): Using requested exit node '$7BE683E65D48141321C5ED92F075C55364AC7123~7BE683E65D48141321C at 193.23.244.244'
Dec 21 11:17:24.000 [debug] {CIRC} onion_extend_cpath(): Path is 0 long; we want 1
Dec 21 11:17:24.000 [debug] {CIRC} onion_extend_cpath(): Chose router $7BE683E65D48141321C5ED92F075C55364AC7123~7BE683E65D48141321C at 193.23.244.244 for hop 1 (exit is 7BE683E65D48141321C5ED92F075C55364AC7123)
Dec 21 11:17:24.000 [debug] {CIRC} onion_extend_cpath(): Path is complete: 1 steps long
Dec 21 11:17:24.000 [debug] {CIRC} circuit_handle_first_hop(): Looking for firsthop '193.23.244.244:443'
Dec 21 11:17:24.000 [info] {CIRC} circuit_handle_first_hop(): Next router is [scrubbed]: Not connected. Connecting.
Dec 21 11:17:24.000 [notice] {CONTROL} Bootstrapped 5%: Connecting to directory server.
Dec 21 11:17:24.000 [debug] {CHANNEL} channel_tls_connect(): In channel_tls_connect() for channel 0xb797c2e8 (global id 0)
Dec 21 11:17:24.000 [debug] {CHANNEL} channel_set_identity_digest(): Setting remote endpoint digest on channel 0xb797c2e8 with global ID 0 to digest 7BE683E65D48141321C5ED92F075C55364AC7123
Dec 21 11:17:24.000 [debug] {NET} connection_connect(): Connecting to [scrubbed]:443.
Dec 21 11:17:25.000 [debug] {NET} connection_connect(): Connection to [scrubbed]:443 in progress (sock 4).
Dec 21 11:17:25.000 [debug] {NET} connection_add_impl(): new conn type OR, socket 4, address 193.23.244.244, n_conns 4.
Dec 21 11:17:25.000 [debug] {CHANNEL} channel_tls_connect(): Got orconn 0xb797c3c0 for channel with global id 0
Dec 21 11:17:25.000 [debug] {CHANNEL} channel_register(): Registering channel 0xb797c2e8 (ID 0) in state opening (1) with digest 7BE683E65D48141321C5ED92F075C55364AC7123
Dec 21 11:17:25.000 [debug] {CHANNEL} channel_add_to_digest_map(): Added channel 0xb797c2e8 (global ID 0) to identity map in state opening (1) with digest 7BE683E65D48141321C5ED92F075C55364AC7123
Dec 21 11:17:25.000 [debug] {CHANNEL} channel_set_cell_handlers(): Setting cell_handler callback for channel 0xb797c2e8 to 0xb7668500
Dec 21 11:17:25.000 [debug] {CHANNEL} channel_set_cell_handlers(): Setting var_cell_handler callback for channel 0xb797c2e8 to 0xb7667340
Dec 21 11:17:25.000 [debug] {CIRC} circuit_handle_first_hop(): connecting in progress (or finished). Good.
Dec 21 11:17:25.000 [info] {APP} connection_ap_make_link(): ... application connection created and linked.
Dec 21 11:17:25.000 [debug] {NET} connection_add_impl(): new conn type Directory, socket -1, address 193.23.244.244, n_conns 5.
Dec 21 11:17:25.000 [info] {DIR} directory_send_command(): Downloading consensus from 193.23.244.244:443 using /tor/status-vote/current/consensus-microdesc/14C131+27B6B5+49015F+585769+805509+D586D1+E8A9C4+ED03BB+EFCBE7.z
Dec 21 11:17:25.000 [info] {GENERAL} or_state_save(): Saved state to "/var/lib/tor/tor/state"
Dec 21 11:17:25.000 [debug] {NET} conn_read_callback(): socket -1 wants to read.
Dec 21 11:17:25.000 [info] {EDGE} connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer.
Dec 21 11:17:25.000 [info] {EDGE} connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer.
Dec 21 11:17:25.000 [debug] {DIR} connection_dir_finished_flushing(): client finished sending command.
Dec 21 11:17:25.000 [debug] {NET} conn_read_callback(): socket 4 wants to read.
Dec 21 11:17:25.000 [info] {CONTROL} control_event_bootstrap_problem(): Problem bootstrapping. Stuck at 5%: Connecting to directory server. (Connection refused; CONNECTREFUSED; count 1; recommendation ignore)
Dec 21 11:17:25.000 [debug] {CHANNEL} channel_close_for_error(): Closing channel 0xb797c2e8 due to lower-layer error
Dec 21 11:17:25.000 [debug] {CHANNEL} channel_change_state(): Changing state of channel 0xb797c2e8 (global ID 0) from "opening" to "closing"
Dec 21 11:17:25.000 [debug] {CHANNEL} channel_remove_from_digest_map(): Removed channel 0xb797c2e8 (global ID 0) from identity map in state closing (4) with digest 7BE683E65D48141321C5ED92F075C55364AC7123
Dec 21 11:17:25.000 [debug] {CHANNEL} connection_mark_for_close_internal_(): Calling connection_mark_for_close_internal_() on an OR conn at src/or/connection.c:2828
Dec 21 11:17:25.000 [debug] {NET} conn_close_if_marked(): Cleaning up connection (fd -1).
Dec 21 11:17:25.000 [debug] {CIRC} circuit_n_chan_done(): chan to NULL/193.23.244.244:443, status=0
Dec 21 11:17:25.000 [info] {CIRC} circuit_n_chan_done(): Channel failed; closing circ.
Dec 21 11:17:25.000 [info] {OR} circuit_build_failed(): Our circuit died before the first hop with no connection
Dec 21 11:17:25.000 [info] {APP} connection_ap_fail_onehop(): Closing one-hop stream to '$7BE683E65D48141321C5ED92F075C55364AC7123/193.23.244.244' because the OR conn just failed.
Dec 21 11:17:25.000 [debug] {CIRC} circuit_increment_failure_count(): n_circuit_failures now 1.
Dec 21 11:17:25.000 [debug] {CHANNEL} channel_change_state(): Changing state of channel 0xb797c2e8 (global ID 0) from "closing" to "channel error"
Dec 21 11:17:25.000 [info] {HANDSHAKE} connection_or_note_state_when_broken(): Connection died in state 'connect()ing with SSL state (No SSL object)'
Dec 21 11:17:25.000 [debug] {NET} connection_remove(): removing socket -1 (type OR), n_conns now 5
Dec 21 11:17:25.000 [debug] {NET} conn_close_if_marked(): Cleaning up connection (fd -1).
Dec 21 11:17:25.000 [debug] {NET} connection_remove(): removing socket -1 (type Socks), n_conns now 4
Dec 21 11:17:25.000 [info] {GENERAL} connection_free_(): Freeing linked Socks connection [waiting for circuit] with 152 bytes on inbuf, 0 on outbuf.
Dec 21 11:17:25.000 [debug] {NET} conn_read_callback(): socket -1 wants to read.
Dec 21 11:17:25.000 [info] {HTTP} connection_dir_client_reached_eof(): 'fetch' response not all here, but we're at eof. Closing.
Dec 21 11:17:25.000 [debug] {NET} conn_close_if_marked(): Cleaning up connection (fd -1).
=============================

Repeat ad-nauseum! The above log seems to stem from the fact that it looks as though dannenberg ($7BE683E65D48141321C5ED92F075C55364AC7123/193.23.244.244) doesn't accept connections on ports 443 or 80 anymore (is it down?), grinding my tor bootup to a screeching halt - something I tried to offset by explicitly setting 3 "DirServer" options, but to no avail.

Secondly, why is tor insisting on downloading its descriptors/data from that directory and not trying some other - is dannenberg the only one? I seriously doubt it!

Child Tickets

Attachments (2)

tor-10461-alternatedir.zip (3.9 KB) - added by mr-4 6 years ago.
AlternativeDirAuthority configuration and log files
tor-10461-fallbackdir.zip (5.8 KB) - added by mr-4 6 years ago.
FallbackDir configuration and log files

Download all attachments as: .zip

Change History (21)

comment:1 Changed 6 years ago by nickm

DirServer is an obsolete name for the option currently called "DirAuthority". (We changed the name because the old one was confusing.) It's used to replace the directory authorities that you believe in. You probably shouldn't use it unless you're running your own private Tor network. Is there some legacy documentation out there that tells people about the DirServer option but doesn't explain what it does well? If so, we should fix that.

If you want to change which directory servers Tor uses when it doesn't know any directory servers or doesn't have a live consensus, that's the FallbackDir option.

Otherwise, directory requests are made to one of your guard nodes, as determined by the UseEntryGuardsAsDirectoryGuards option.

comment:2 Changed 6 years ago by mr-4

Well, something isn't right! This is what I have at the top of my debug file log:

[debug] {DIR} parse_dir_authority_line(): Trusted 100 dirserver at 128.31.0.39:9131 (9695)
[debug] {DIR} parse_dir_authority_line(): Trusted 111 dirserver at 86.59.21.38:80 (847B)
[debug] {DIR} parse_dir_authority_line(): Trusted 102 dirserver at 194.109.206.212:80 (7EA6)
[debug] {DIR} parse_dir_authority_line(): Trusted 16 dirserver at 82.94.251.203:80 (4A0C)
[debug] {DIR} parse_dir_authority_line(): Trusted 100 dirserver at 76.73.17.194:9030 (F397)
[debug] {DIR} parse_dir_authority_line(): Trusted 100 dirserver at 212.112.245.170:80 (F204)
[debug] {DIR} parse_dir_authority_line(): Trusted 100 dirserver at 193.23.244.244:80 (7BE6)
[debug] {DIR} parse_dir_authority_line(): Trusted 100 dirserver at 208.83.223.34:443 (0AD3)
[debug] {DIR} parse_dir_authority_line(): Trusted 100 dirserver at 171.25.193.9:443 (BD6A)
[debug] {DIR} parse_dir_authority_line(): Trusted 100 dirserver at 154.35.32.5:80 (CF6D)

Off these, at least 3 should be working: dannenberg, tor26 and maatuska (I have {US} in my ExcludedNodes list), but they don't! Even with explicitly adding the following to my torrc file:

DirAuthority 95.223.60.130:9030 23155386E3B4B93B0294DB3A6263A8FAFE273255
DirAuthority tor26 86.59.21.38:80 847B1F850344D7876491A54892F904934E4EB85D
DirAuthority maatuska 171.25.193.9:443 BD6A829255CB08E66FBE7D3748363586E46B3810
DirAuthority 95.223.60.130:443 23155386E3B4B93B0294DB3A6263A8FAFE273255
DirAuthority 89.245.227.226:9001 6CB447C4CBCC4F5BDB4BA096902C2956CB534999
DirAuthority 89.245.227.226:9030 6CB447C4CBCC4F5BDB4BA096902C2956CB534999
DirAuthority 109.228.139.83:9001 9DD97868543CB3CF432B96C082DFAC1FD16F6768

I still get the following in my log:

[info] {DIR} microdesc_cache_reload(): Reloaded microdescriptor cache. Found 0 descriptors.
[info] {FS} tor_mmap_file(): Could not open "/var/lib/tor/cached-descriptors" for mmap(): No such file or directory
[info] {FS} tor_mmap_file(): Could not open "/var/lib/tor/cached-extrainfo" for mmap(): No such file or directory
[info] {DIR} I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
[info] {DIR} update_consensus_networkstatus_downloads(): Launching microdesc networkstatus consensus download.
[info] {CIRC} entry_guards_set_from_config(): Adding configured EntryNodes '{EU},{AT},{HR},{CH},{CZ},{DK},{FI},{FR},{DE},{HU},{IT},{LU},{MT},{NL},{NO},{SK},{SI},{ES},{SE},{BE},{IS}'.
[notice] {GENERAL} 0 entries in guards
[info] {CIRC} compute_weighted_bandwidths(): Empty routerlist passed in to consensus weight node selection for rule weight as guard
[info] {CIRC} smartlist_choose_node_by_bandwidth(): Empty routerlist passed in to old node selection for rule weight as guard
[info] {DIR} directory_pick_generic_dirserver(): No router found for consensus network-status fetch; falling back to dirserver list.
[info] {DIR} router_pick_dirserver_generic(): No dirservers are reachable. Trying them all again.
[notice] {DIR} While fetching directory info, no running dirservers known. Will try again later. (purpose 14)
[info] {GENERAL} or_state_save(): Saved state to "/var/lib/tor/state"

Please note that at least 2 of the "default" directory authorities are NOT in any of my exclude list (which, to be fair, is quite extensive) - I checked and double-checked this yesterday.

Even if any of them are in that list and tor cannot connect to them for this very reason, I would expect tor to tell me that (something like "trying to connect to XXX directory authority, but it is in your ExcludeNodes list" - the same way as it does with ordinary ExitNodes).

The fact is that it doesn't!

The above message shown "No dirservers are reachable. Trying them all again." is not helpful at all.

Why are no dirservers available? Why is tor not able to connect to any of them? Why is tor not listing what directory servers is trying to connect to?

These are answers I expect to get when I have the reporting level set that low (=debug). It is not acceptable for me to be scratching my head having to guess what tor is doing and what appears to be wrong, particularly when I asked tor to be reporting everything.

comment:3 Changed 6 years ago by mr-4

One other thing: when I use "UseEntryGuardsAsDirectoryGuards" tor is unable to start, the message I get is "Failed to parse/validate config: Unknown option 'UseEntryGuardsAsDirectoryGuards'. Failing.".

comment:4 Changed 6 years ago by mr-4

Also: when I don't have any "DirAuthority" statements in my torrc, I get the following sequence:

[info] {DIR} microdesc_cache_reload(): Reloaded microdescriptor cache. Found 0 descriptors.
[info] {FS} tor_mmap_file(): Could not open "/var/lib/tor/tor/cached-descriptors" for mmap(): No such file or directory
[info] {FS} tor_mmap_file(): Could not open "/var/lib/tor/tor/cached-extrainfo" for mmap(): No such file or directory
[info] {DIR} I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
[info] {DIR} update_consensus_networkstatus_downloads(): Launching microdesc networkstatus consensus download.
[info] {CIRC} entry_guards_set_from_config(): Adding configured EntryNodes '{EU},{AT},{HR},{CH},{CZ},{DK},{FI},{FR},{DE},{HU},{IT},{LU},{MT},{NL},{NO},{SK},{SI},{ES},{SE},{BE},{IS}'.
[notice] {GENERAL} 0 entries in guards
[info] {CIRC} compute_weighted_bandwidths(): Empty routerlist passed in to consensus weight node selection for rule weight as guard
[info] {CIRC} smartlist_choose_node_by_bandwidth(): Empty routerlist passed in to old node selection for rule weight as guard
[info] {DIR} directory_pick_generic_dirserver(): No router found for consensus network-status fetch; falling back to dirserver list.
[debug] {DIR} directory_initiate_command_rend(): anonymized 0, use_begindir 1.
[debug] {DIR} directory_initiate_command_rend(): Initiating consensus network-status fetch
[info] {APP} connection_ap_make_link(): Making internal direct tunnel to [scrubbed]:443 ...
[debug] {NET} connection_add_impl(): new conn type Socks, socket -1, address (Tor_internal), n_conns 2.
[debug] {DIR} circuit_get_open_circ_or_launch(): considering 1, $7BE683E65D48141321C5ED92F075C55364AC7123
[debug] {CIRC} onion_pick_cpath_exit(): Launching a one-hop circuit for dir tunnel.
[info] {CIRC} onion_pick_cpath_exit(): Using requested exit node '$7BE683E65D48141321C5ED92F075C55364AC7123~7BE683E65D48141321C at 193.23.244.244'
[debug] {CIRC} onion_extend_cpath(): Path is 0 long; we want 1
[debug] {CIRC} onion_extend_cpath(): Chose router $7BE683E65D48141321C5ED92F075C55364AC7123~7BE683E65D48141321C at 193.23.244.244 for hop 1 (exit is 7BE683E65D48141321C5ED92F075C55364AC7123)
[debug] {CIRC} onion_extend_cpath(): Path is complete: 1 steps long
[debug] {CIRC} circuit_handle_first_hop(): Looking for firsthop '193.23.244.244:443'
[info] {CIRC} circuit_handle_first_hop(): Next router is [scrubbed]: Not connected. Connecting.
[notice] {CONTROL} Bootstrapped 5%: Connecting to directory server.
[debug] {CHANNEL} channel_tls_connect(): In channel_tls_connect() for channel 0xb79ea130 (global id 0)
[debug] {CHANNEL} channel_set_identity_digest(): Setting remote endpoint digest on channel 0xb79ea130 with global ID 0 to digest 7BE683E65D48141321C5ED92F075C55364AC7123
[debug] {NET} connection_connect(): Connecting to [scrubbed]:443.
[debug] {NET} connection_connect(): Connection to [scrubbed]:443 in progress (sock 4).
[debug] {NET} connection_add_impl(): new conn type OR, socket 4, address 193.23.244.244, n_conns 3.
[debug] {CHANNEL} channel_tls_connect(): Got orconn 0xb79ea208 for channel with global id 0
[debug] {CHANNEL} channel_register(): Registering channel 0xb79ea130 (ID 0) in state opening (1) with digest 7BE683E65D48141321C5ED92F075C55364AC7123
[debug] {CHANNEL} channel_add_to_digest_map(): Added channel 0xb79ea130 (global ID 0) to identity map in state opening (1) with digest 7BE683E65D48141321C5ED92F075C55364AC7123
[debug] {CHANNEL} channel_set_cell_handlers(): Setting cell_handler callback for channel 0xb79ea130 to 0xb76d6500
[debug] {CHANNEL} channel_set_cell_handlers(): Setting var_cell_handler callback for channel 0xb79ea130 to 0xb76d5340
[debug] {CIRC} circuit_handle_first_hop(): connecting in progress (or finished). Good.
[info] {APP} connection_ap_make_link(): ... application connection created and linked.
[debug] {NET} connection_add_impl(): new conn type Directory, socket -1, address 193.23.244.244, n_conns 4.
[info] {DIR} directory_send_command(): Downloading consensus from 193.23.244.244:443 using /tor/status-vote/current/consensus-microdesc/14C131+27B6B5+49015F+585769+805509+D586D1+E8A9C4+ED03BB+EFCBE7.z
[info] {GENERAL} or_state_save(): Saved state to "/var/lib/tor/tor/state"
[debug] {NET} conn_read_callback(): socket -1 wants to read.
[info] {EDGE} connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer.
[info] {EDGE} connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer.
[debug] {DIR} connection_dir_finished_flushing(): client finished sending command.
[debug] {NET} conn_read_callback(): socket 4 wants to read.
[info] {CONTROL} control_event_bootstrap_problem(): Problem bootstrapping. Stuck at 5%: Connecting to directory server. (Connection refused; CONNECTREFUSED; count 1; recommendation ignore)
[debug] {CHANNEL} channel_close_for_error(): Closing channel 0xb79ea130 due to lower-layer error
[debug] {CHANNEL} channel_change_state(): Changing state of channel 0xb79ea130 (global ID 0) from "opening" to "closing"
[debug] {CHANNEL} channel_remove_from_digest_map(): Removed channel 0xb79ea130 (global ID 0) from identity map in state closing (4) with digest 7BE683E65D48141321C5ED92F075C55364AC7123
[debug] {CHANNEL} connection_mark_for_close_internal_(): Calling connection_mark_for_close_internal_() on an OR conn at src/or/connection.c:2828
[debug] {NET} conn_close_if_marked(): Cleaning up connection (fd -1).
[debug] {CIRC} circuit_n_chan_done(): chan to NULL/193.23.244.244:443, status=0
[info] {CIRC} circuit_n_chan_done(): Channel failed; closing circ.
[info] {OR} circuit_build_failed(): Our circuit died before the first hop with no connection
[info] {APP} connection_ap_fail_onehop(): Closing one-hop stream to '$7BE683E65D48141321C5ED92F075C55364AC7123/193.23.244.244' because the OR conn just failed.
[debug] {CIRC} circuit_increment_failure_count(): n_circuit_failures now 1.
[debug] {CHANNEL} channel_change_state(): Changing state of channel 0xb79ea130 (global ID 0) from "closing" to "channel error"
[info] {HANDSHAKE} connection_or_note_state_when_broken(): Connection died in state 'connect()ing with SSL state (No SSL object)'
[debug] {NET} connection_remove(): removing socket -1 (type OR), n_conns now 4
[debug] {NET} conn_close_if_marked(): Cleaning up connection (fd -1).
[debug] {NET} connection_remove(): removing socket -1 (type Socks), n_conns now 3
[info] {GENERAL} connection_free_(): Freeing linked Socks connection [waiting for circuit] with 152 bytes on inbuf, 0 on outbuf.
[debug] {NET} conn_read_callback(): socket -1 wants to read.
[info] {HTTP} connection_dir_client_reached_eof(): 'fetch' response not all here, but we're at eof. Closing.
[debug] {NET} conn_close_if_marked(): Cleaning up connection (fd -1).
[info] {DIR} update_consensus_networkstatus_downloads(): Launching microdesc networkstatus consensus download.
[info] {CIRC} compute_weighted_bandwidths(): Empty routerlist passed in to consensus weight node selection for rule weight as guard
[info] {CIRC} smartlist_choose_node_by_bandwidth(): Empty routerlist passed in to old node selection for rule weight as guard
[info] {DIR} directory_pick_generic_dirserver(): No router found for consensus network-status fetch; falling back to dirserver list.
[debug] {DIR} directory_initiate_command_rend(): anonymized 0, use_begindir 1.
[debug] {DIR} directory_initiate_command_rend(): Initiating consensus network-status fetch
[info] {APP} connection_ap_make_link(): Making internal direct tunnel to [scrubbed]:443 ...
[debug] {NET} connection_add_impl(): new conn type Socks, socket -1, address (Tor_internal), n_conns 3.
[debug] {DIR} circuit_get_open_circ_or_launch(): considering 1, $7BE683E65D48141321C5ED92F075C55364AC7123
[debug] {CIRC} onion_pick_cpath_exit(): Launching a one-hop circuit for dir tunnel.
[info] {CIRC} onion_pick_cpath_exit(): Using requested exit node '$7BE683E65D48141321C5ED92F075C55364AC7123~7BE683E65D48141321C at 193.23.244.244'
[debug] {CIRC} onion_extend_cpath(): Path is 0 long; we want 1
[debug] {CIRC} onion_extend_cpath(): Chose router $7BE683E65D48141321C5ED92F075C55364AC7123~7BE683E65D48141321C at 193.23.244.244 for hop 1 (exit is 7BE683E65D48141321C5ED92F075C55364AC7123)
[debug] {CIRC} onion_extend_cpath(): Path is complete: 1 steps long
[debug] {CIRC} circuit_handle_first_hop(): Looking for firsthop '193.23.244.244:443'
[info] {CIRC} circuit_handle_first_hop(): Next router is [scrubbed]: Not connected. Connecting.
[debug] {CHANNEL} channel_tls_connect(): In channel_tls_connect() for channel 0xb79ebc50 (global id 1)
[debug] {CHANNEL} channel_set_identity_digest(): Setting remote endpoint digest on channel 0xb79ebc50 with global ID 1 to digest 7BE683E65D48141321C5ED92F075C55364AC7123
[debug] {NET} connection_connect(): Connecting to [scrubbed]:443.
[debug] {NET} connection_connect(): Connection to [scrubbed]:443 in progress (sock 4).
[debug] {NET} connection_add_impl(): new conn type OR, socket 4, address 193.23.244.244, n_conns 4.
[debug] {CHANNEL} channel_tls_connect(): Got orconn 0xb79ebd40 for channel with global id 1
[debug] {CHANNEL} channel_register(): Registering channel 0xb79ebc50 (ID 1) in state opening (1) with digest 7BE683E65D48141321C5ED92F075C55364AC7123
[debug] {CHANNEL} channel_add_to_digest_map(): Added channel 0xb79ebc50 (global ID 1) to identity map in state opening (1) with digest 7BE683E65D48141321C5ED92F075C55364AC7123
[debug] {CHANNEL} channel_set_cell_handlers(): Setting cell_handler callback for channel 0xb79ebc50 to 0xb76d6500
[debug] {CHANNEL} channel_set_cell_handlers(): Setting var_cell_handler callback for channel 0xb79ebc50 to 0xb76d5340
[debug] {CIRC} circuit_handle_first_hop(): connecting in progress (or finished). Good.
[info] {APP} connection_ap_make_link(): ... application connection created and linked.
[debug] {NET} connection_add_impl(): new conn type Directory, socket -1, address 193.23.244.244, n_conns 5.
[info] {DIR} directory_send_command(): Downloading consensus from 193.23.244.244:443 using /tor/status-vote/current/consensus-microdesc/14C131+27B6B5+49015F+585769+805509+D586D1+E8A9C4+ED03BB+EFCBE7.z
[debug] {NET} connection_remove(): removing socket -1 (type Directory), n_conns now 5
[info] {GENERAL} connection_free_(): Freeing linked Directory connection [client reading] with 0 bytes on inbuf, 0 on outbuf.
[debug] {NET} conn_read_callback(): socket -1 wants to read.
[info] {EDGE} connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer.
[info] {EDGE} connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer.
[debug] {DIR} connection_dir_finished_flushing(): client finished sending command.
[debug] {NET} conn_read_callback(): socket 4 wants to read.
[info] {CONTROL} control_event_bootstrap_problem(): Problem bootstrapping. Stuck at 5%: Connecting to directory server. (Connection refused; CONNECTREFUSED; count 2; recommendation ignore)
[info] {HANDSHAKE} 1 connections have failed:
[info] {HANDSHAKE} 1 connections died in state connect()ing with SSL state (No SSL object)
[debug] {CHANNEL} channel_close_for_error(): Closing channel 0xb79ebc50 due to lower-layer error
[debug] {CHANNEL} channel_change_state(): Changing state of channel 0xb79ebc50 (global ID 1) from "opening" to "closing"
[debug] {CHANNEL} channel_remove_from_digest_map(): Removed channel 0xb79ebc50 (global ID 1) from identity map in state closing (4) with digest 7BE683E65D48141321C5ED92F075C55364AC7123
[debug] {CHANNEL} connection_mark_for_close_internal_(): Calling connection_mark_for_close_internal_() on an OR conn at src/or/connection.c:2828
[debug] {NET} conn_close_if_marked(): Cleaning up connection (fd -1).
[debug] {CIRC} circuit_n_chan_done(): chan to NULL/193.23.244.244:443, status=0
[info] {CIRC} circuit_n_chan_done(): Channel failed; closing circ.
[info] {OR} circuit_build_failed(): Our circuit died before the first hop with no connection
[info] {APP} connection_ap_fail_onehop(): Closing one-hop stream to '$7BE683E65D48141321C5ED92F075C55364AC7123/193.23.244.244' because the OR conn just failed.

When I add dannenberg explicitly with "DirAuthority", like "DirAuthority 193.23.244.244:443 7BE683E65D48141321C5ED92F075C55364AC7123" I get this:

Dec 22 12:14:32.000 [info] {DIR} microdesc_cache_reload(): Reloaded microdescriptor cache. Found 0 descriptors.
Dec 22 12:14:32.000 [info] {FS} tor_mmap_file(): Could not open "/var/lib/tor/tor/cached-descriptors" for mmap(): No such file or directory
Dec 22 12:14:32.000 [info] {FS} tor_mmap_file(): Could not open "/var/lib/tor/tor/cached-extrainfo" for mmap(): No such file or directory
Dec 22 12:14:32.000 [info] {DIR} I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
Dec 22 12:14:33.000 [info] {DIR} update_consensus_networkstatus_downloads(): Launching microdesc networkstatus consensus download.
Dec 22 12:14:33.000 [info] {CIRC} entry_guards_set_from_config(): Adding configured EntryNodes '{EU},{AT},{HR},{CH},{CZ},{DK},{FI},{FR},{DE},{HU},{IT},{LU},{MT},{NL},{NO},{SK},{SI},{ES},{SE},{BE},{IS}'.
Dec 22 12:14:33.000 [notice] {GENERAL} 0 entries in guards
Dec 22 12:14:33.000 [info] {CIRC} compute_weighted_bandwidths(): Empty routerlist passed in to consensus weight node selection for rule weight as guard
Dec 22 12:14:33.000 [info] {CIRC} smartlist_choose_node_by_bandwidth(): Empty routerlist passed in to old node selection for rule weight as guard
Dec 22 12:14:33.000 [info] {DIR} directory_pick_generic_dirserver(): No router found for consensus network-status fetch; falling back to dirserver list.
Dec 22 12:14:33.000 [info] {DIR} router_pick_dirserver_generic(): No dirservers are reachable. Trying them all again.
Dec 22 12:14:33.000 [notice] {DIR} While fetching directory info, no running dirservers known. Will try again later. (purpose 14)
Dec 22 12:14:33.000 [info] {GENERAL} or_state_save(): Saved state to "/var/lib/tor/tor/state"

Why?

The two scenarios shouldn't be any different. In other words whether tor tries to connect to dannenberg (which appears to be down by the way) implicitly (by default) or explicitly with "DirAuthority" in torrc should not matter, but that appears not to be the case. Over to you!

comment:5 Changed 6 years ago by nickm

So, my advice still stands: you should use FallbackDir instead, because [Alternative]DirAuthority doesn't actually work that way. Setting a different set of DirAuthorities while staying on the main network will get you weird results. "You probably shouldn't use it unless you're running your own private Tor network."

I would like to track down what is going on here, but the thing is, using DirAuthorities to pick a set of directory authorities other than the entire set for the network is not a well-defined or recommended thing at all. So I'm not sure what kind of semantics I should be aiming for. It's normal, for instance, that a Tor node will pick a directory authority _as a regular directory_ if that authority is listed in the consensus. And it's normal for Tor to use any cached guards it has as initial contact points for the network.

And it's also expected that if you have less than the full set of authorities configured, Tor will reject some of the signed consensuses too many of those particular authorities miss a vote. So there are lots of weird things that could be going on right here and actually figuring out this twisted situation is going to be a bit complicated. The "DirAuthority" option does a lot of stuff.

I do know that that, whatever is happening, the DirAuthority/DirServer option is not actually ignored in the general case: all of our testing network scripts use it to prevent testing networks and clients to talk to the real network. It definitely works there; I use it all the time. So it can't be a matter of stuff getting "ignored". If these options were simply ignored, the "chutney" tool wouldn't work, for example.

So, let's think. How can we actually track this down? I think the best bet at this point would be if you could paste an example torrc that should work, but doesn't. Right now, I know some of the options that are breaking here, but I'm not able to reproduce the failing cases above when I try to make the same behavior happen on my computer.

Is that something you're able to do?

comment:6 Changed 6 years ago by mr-4

OK, here goes...

In a nutshell, I've ran 2 separate scenarios: a) using AlternativeDirAuthority; and b) FallbackDir, none of which worked. I am attaching 2 separate zip files containing my configuration files, as well as the relevant logs.

In more detail...

a) Using AlternativeDirAuthority (I used "pinkPanther", which was up and running and had V2Dir flag set).

  1. As evident from the log attached, tor ignores my request for using AlternativeDirAuthority and uses 86.59.21.38:80 and 82.94.251.203:80 as "trusted servers". Why?
  1. Even though tor "uses" 89.245.200.168:9030 (pinkPanther) as trusted server dir authority, no requests are fetched/initiated to that directory ("No dirservers are reachable. Trying them all again."). Why is that?
  1. In addition to point 2 above - even though I am running at maximum debug level, tor doesn't inform me of the reason _why_ No dirservers are reachable, particularly given that I have not listed 89.245.200.168 as an address to be rejected. If tor decides, for whatever reason, that it won't fetch its info from that address, I need to know the reason why is that so.

b) using FallbackDir: I rejected all "default" tor directory authorities and included 89.245.200.168 as a fallback directory in order to force tor to fetch its info from that directory and no other.

  1. As evident from the logs provided, tor is completely ignoring my "reject ..." statements and connects to and fetches its info from 193.23.244.244:443, which is a rejected address. Why?
  1. Given that the "reject ..." statements for the "default directory authorities" seem to be completely ignored by tor, this FallbackDir statement is completely useless!

In conclusion, all the points I raised in the original report still stand. Over to you Nick...

Changed 6 years ago by mr-4

Attachment: tor-10461-alternatedir.zip added

AlternativeDirAuthority configuration and log files

Changed 6 years ago by mr-4

Attachment: tor-10461-fallbackdir.zip added

FallbackDir configuration and log files

comment:7 Changed 6 years ago by nickm

Okay, I'll try to analyze the fallback one this week if I can get through enough other 0.2.4.x and 0.2.5.x tickets before the dev meeting next week. Thanks for the patience, thanks for the configurations, and sorry for the delays!

comment:8 Changed 6 years ago by nickm

Keywords: tor-client added
Milestone: Tor: 0.2.5.x-final

comment:9 Changed 6 years ago by nickm

Keywords: 025-triaged added

comment:10 Changed 5 years ago by nickm

Milestone: Tor: 0.2.5.x-finalTor: 0.2.6.x-final

comment:11 Changed 5 years ago by nickm

Keywords: 026-triaged-1 added

comment:12 Changed 5 years ago by nickm

Owner: set to nickm
Status: newassigned

comment:13 Changed 5 years ago by nickm

Milestone: Tor: 0.2.6.x-finalTor: 0.2.7.x-final

comment:14 Changed 5 years ago by nickm

Keywords: 027-triaged-1-out added

Marking triaged-out items from first round of 0.2.7 triage.

comment:15 Changed 5 years ago by nickm

Milestone: Tor: 0.2.7.x-finalTor: 0.2.???

Make all non-needs_review, non-needs_revision, 027-triaged-1-out items belong to 0.2.???

comment:16 Changed 4 years ago by arma

Severity: Normal

What a mess of a ticket. It looks like the original poster was misunderstanding or trying to misuse the dirserver syntax? And then it morphed into something about fallbackdirs? Do you think any of the recent work on fallbackdirs has resolved whatever those issues were?

comment:17 Changed 3 years ago by teor

Milestone: Tor: 0.2.???Tor: 0.3.???

Milestone renamed

comment:18 Changed 3 years ago by nickm

Keywords: tor-03-unspecified-201612 added
Milestone: Tor: 0.3.???Tor: unspecified

Finally admitting that 0.3.??? was a euphemism for Tor: unspecified all along.

comment:19 in reply to:  16 Changed 3 years ago by teor

Resolution: fixed
Status: assignedclosed

Replying to arma:

What a mess of a ticket. It looks like the original poster was misunderstanding or trying to misuse the dirserver syntax? And then it morphed into something about fallbackdirs? Do you think any of the recent work on fallbackdirs has resolved whatever those issues were?

Yes, we fixed these issues in 0.2.8.1-alpha, when we introduced fallback directories.

Note: See TracTickets for help on using tickets.