Opened 10 years ago

Closed 8 years ago

Last modified 7 years ago

#960 closed defect (duplicate)

Tor believes bridges are offline at startup

Reported by: phobos Owned by:
Priority: Low Milestone: Tor: 0.2.3.x-final
Component: Core Tor/Tor Version: 0.2.1.13-alpha
Severity: Keywords: tor-bridge
Cc: phobos, nickm, Sebastian, arma Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description (last modified by nickm)

[07:42:32] < phobos> [Info] should_delay_dir_fetches(): delaying dir fetches (no running bridges known)
[07:42:34] < phobos> lies
[07:43:17] < phobos> it's been doing this for 10 minutes
[07:43:29] < phobos> yet I can connect to the bridges just fine
[07:45:56] < killerchicken_> heh
[07:46:09] < killerchicken_> if we could debug this, that would solve a lot of problem reports we had
[07:46:59] < phobos> forcing an app request through it makes it try
[07:47:03] < phobos> and succeed
[07:48:27] < killerchicken_> ah
[07:48:28] < killerchicken_> * are marked with purpose 'bridge' and are running. Else return 0.
[07:48:37] < killerchicken_> ups
[07:48:40] < killerchicken_> ./ Return 1 if any of our entry guards have descriptors that
[07:51:30] < killerchicken_> hm
[07:52:35] < killerchicken_> I'd love to debug this more, but it has to wait... Have you made a bug report?
[07:53:04] < phobos> on my to do list
[07:53:22] < killerchicken_> ok
[07:55:10] < killerchicken_> I think the problem is inside the any_bridge_descriptors_known() / choose_random_entry() logic
[07:55:37] < killerchicken_> I'll look at it more if nobody else finds the time. Can you please add this stuff from here to the bug?

Log file says:
ar 27 07:42:12.269 [Info] should_delay_dir_fetches(): delaying dir fetches (no running bridges known)
Mar 27 07:42:23.309 [Info] should_delay_dir_fetches(): delaying dir fetches (no running bridges known)
Mar 27 07:42:28.329 [Info] routerlist_remove_old_routers(): We have 1203 live routers and 0 old router descriptors.
Mar 27 07:42:28.334 [Info] should_delay_dir_fetches(): delaying dir fetches (no running bridges known)
Mar 27 07:42:34.348 [Info] should_delay_dir_fetches(): delaying dir fetches (no running bridges known)
Mar 27 07:42:45.388 [Info] should_delay_dir_fetches(): delaying dir fetches (no running bridges known)
Mar 27 07:42:56.420 [Info] should_delay_dir_fetches(): delaying dir fetches (no running bridges known)
Mar 27 07:43:07.461 [Info] should_delay_dir_fetches(): delaying dir fetches (no running bridges known)
Mar 27 07:43:18.500 [Info] should_delay_dir_fetches(): delaying dir fetches (no running bridges known)
Mar 27 07:43:29.541 [Info] should_delay_dir_fetches(): delaying dir fetches (no running bridges known)

forcing an app request through tor creates:
Mar 27 07:46:14.173 [Info] should_delay_dir_fetches(): delaying dir fetches (no running bridges known)
Mar 27 07:46:16.197 [Notice] Application request when we're believed to be offline. Optimistically trying known bridges again.
Mar 27 07:46:16.210 [Info] connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer.
Mar 27 07:46:25.220 [Info] update_consensus_router_descriptor_downloads(): 3 router descriptors downloadable. 0 delayed; 1201 present (0 of those were in old_routers); 0 would_reject; 0 wouldnt_use; 0 in progress.
Mar 27 07:46:25.233 [Info] launch_router_descriptor_downloads(): There are not many downloadable routerdescs, but we haven't tried downloading descriptors recently. Downloading.
Mar 27 07:46:25.248 [Info] launch_router_descriptor_downloads(): Launching 1 request for 3 routers, 4 at a time

[Automatically added by flyspray2trac: Operating System: Other Linux]

Child Tickets

Attachments (1)

bug960-tor.log.gz (21.3 KB) - added by phobos 10 years ago.

Download all attachments as: .zip

Change History (14)

comment:1 Changed 10 years ago by Sebastian

Hm, I tried to reproduce this for a while, but couldn't figure out how. Did you use
Vidalia to set up your Tor cient? If not, can you paste the relevant config options
you used and do you have an idea how old your cached* files were before you started?

Thanks!

comment:2 Changed 10 years ago by arma

Earlier in your logs, it will say why it decided that your bridge was down.
That's the line I need to see to make any progress here.

(For example, perhaps it made a directory request which the bridge couldn't
handle, so we marked it down.)

comment:3 Changed 10 years ago by phobos

Here's my info level log from start to working:
Mar 28 22:55:14.168 [Notice] Tor v0.2.1.13-alpha (r18828). This is experimental software. Do not rely on it for strong anonymity. (Running on Linux x86_64)
Mar 28 22:55:14.200 [Notice] Initialized libevent version 1.3e using method epoll. Good.
Mar 28 22:55:14.211 [Notice] Opening Socks listener on 127.0.0.1:9050
Mar 28 22:55:14.213 [Notice] Opening Control listener on 127.0.0.1:9051
Mar 28 22:56:23.946 [Info] should_delay_dir_fetches(): delaying dir fetches (no running bridges known)
Mar 28 22:56:23.948 [Info] routerlist_remove_old_routers(): We have 1225 live routers and 0 old router descriptors.
Mar 28 22:56:23.948 [Info] should_delay_dir_fetches(): delaying dir fetches (no running bridges known)
Mar 28 22:56:34.986 [Info] should_delay_dir_fetches(): delaying dir fetches (no running bridges known)
Mar 28 22:56:35.502 [Notice] Application request when we're believed to be offline. Optimistically trying known bridges again.
Mar 28 22:56:35.508 [Info] connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer.
Mar 28 22:56:45.028 [Info] update_consensus_router_descriptor_downloads(): 0 router descriptors downloadable. 0 delayed; 1223 present (0 of those were in old_routers); 0 would_reject; 1 wouldnt_use; 0 in progress.
Mar 28 22:56:56.072 [Info] update_consensus_router_descriptor_downloads(): 0 router descriptors downloadable. 0 delayed; 1223 present (0 of those were in old_routers); 0 would_reject; 1 wouldnt_use; 0 in progress.
Mar 28 22:57:05.662 [Notice] Application request when we're believed to be offline. Optimistically trying directory fetches again.
Mar 28 22:57:05.669 [Info] update_consensus_router_descriptor_downloads(): 0 router descriptors downloadable. 0 delayed; 1223 present (0 of those were in old_routers); 0 would_reject; 1 wouldnt_use; 0 in progress.
Mar 28 22:57:05.679 [Info] connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer.
Mar 28 22:57:07.563 [Notice] We now have enough directory information to build circuits.
Mar 28 22:57:07.566 [Info] choose_good_exit_server_general(): Found 471 servers that might support 2/2 pending connections.

comment:4 Changed 10 years ago by phobos

Everything is configured and controlled through vidalia r3642.

comment:5 Changed 10 years ago by phobos

Better log uploaded.

Changed 10 years ago by phobos

Attachment: bug960-tor.log.gz added

comment:6 Changed 10 years ago by arma

Looks like your guess is right: Vidalia is starting Tor before your network
is up yet, and Tor is blaming the bridge for the missing network.

So why does Tor sans bridges work for you? My theory is that there are enough
relays that you blame some of them but the network appears quickly enough that
some are still considered up.

The simple fix that comes to mind is to treat certain errnos as not the fault of
the dir mirror. This would cause us to keep iterating attempts, which should
survive the race better.

The complex fix is for Tor to recognize this situation (in this case, network
unreachable, but there are probably other similar cases) and hold off on doing
stuff until it's no longer in the situation. That would involve more state, which
is bad if we can avoid it.

Sounds like I should add a "don't mark your dir mirror down if the errno is a
general problem" patch, and we can see how that goes.

comment:7 Changed 10 years ago by Sebastian

Is this something Mike's new code is/could be addressing?

comment:8 Changed 9 years ago by nickm

Description: modified (diff)
Milestone: Tor: 0.2.3.x-final

There are some other problems if Tor comes up before your network does AFAICR. If we fix that well, we may fix this too.

comment:9 Changed 9 years ago by arma

Component: Tor ClientTor Bridge

comment:10 Changed 8 years ago by arma

Yes, I think this is a duplicate of #1247. I believe our stopgap feature of "if you get an application request, try it all again" is working reasonably well.

I think we should close this one and leave #1247 open.

comment:11 Changed 8 years ago by nickm

Resolution: Noneduplicate
Status: newclosed

ok, closing as duplicate of #1247.

comment:12 Changed 7 years ago by nickm

Keywords: tor-bridge added

comment:13 Changed 7 years ago by nickm

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