Bug: The application request to "jabber.org":5222 has launched 10 circuits without finding one it likes.
In Tor 0.2.2.25-alpha we put in a check to detect inconsistencies between our "build a circuit to handle a stream" logic and our "attach a stream to one of the available circuits" logic.
It triggers for me, but I think it's a false positive.
Apr 29 01:04:25.331 [debug] new_route_len(): Chosen route length 3 (2230/2352 routers suitable).
Apr 29 01:04:25.334 [info] choose_good_exit_server_general(): Found 391 servers that might support 1/1 pending connections.
Apr 29 01:04:25.335 [debug] smartlist_choose_by_bandwidth_weights(): Choosing node for rule weight as exit based on weights Wg=0.679100 Wm=1.000000 We=1.000000 Wd=0.679100 with total bw 1359895429.600000
Apr 29 01:04:25.335 [info] choose_good_exit_server_general(): Chose exit server 'chomsky'
Apr 29 01:04:25.335 [debug] onion_extend_cpath(): Path is 0 long; we want 3
Apr 29 01:04:25.336 [debug] onion_extend_cpath(): Chose router kemna for hop 1 (exit is chomsky)
Apr 29 01:04:25.336 [debug] onion_extend_cpath(): Path is 1 long; we want 3
Apr 29 01:04:25.336 [debug] choose_good_middle_server(): Contemplating intermediate hop: random choice.
Apr 29 01:04:25.340 [debug] smartlist_choose_by_bandwidth_weights(): Choosing node for rule weight as middle node based on weights Wg=0.310000 Wm=1.000000 We=0.000000 Wd=0.160400 with total bw 941905438.000000
Apr 29 01:04:25.340 [debug] onion_extend_cpath(): Chose router spmtorrelay for hop 2 (exit is chomsky)
Apr 29 01:04:25.340 [debug] onion_extend_cpath(): Path is 2 long; we want 3
Apr 29 01:04:25.519 [debug] onion_extend_cpath(): Chose router chomsky for hop 3 (exit is chomsky)
Apr 29 01:04:25.519 [debug] onion_extend_cpath(): Path is complete: 3 steps long
Apr 29 01:04:25.520 [debug] circuit_handle_first_hop(): Looking for firsthop '85.25.62.36:9001'
Apr 29 01:04:25.520 [info] circuit_handle_first_hop(): Next router is kemna: Not connected. Connecting.
Apr 29 01:04:25.520 [debug] connection_connect(): Connecting to "85.25.62.36":9001.
Apr 29 01:04:25.520 [info] connection_connect(): connect() to "85.25.62.36":9001 failed: Network is unreachable
Apr 29 01:04:25.520 [debug] entry_guard_register_connect_status(): Failed to connect to unreachable entry guard 'kemna' (CFF48861E1A2774BF0D483998198CFECEA9FF477). It has been unreachable since 2011-04-23 21:30:56.
Apr 29 01:04:25.520 [debug] router_set_status(): Marking router 'kemna/85.25.62.36' as down.
Apr 29 01:04:25.520 [info] circuit_handle_first_hop(): connect to firsthop failed. Closing.
Apr 29 01:04:25.520 [info] circuit_build_failed(): Our circuit died before the first hop with no connection
Apr 29 01:04:25.520 [debug] entry_guard_register_connect_status(): Failed to connect to unreachable entry guard 'kemna' (CFF48861E1A2774BF0D483998198CFECEA9FF477). It has been unreachable since 2011-04-23 21:30:56.
Apr 29 01:04:25.520 [debug] router_set_status(): Marking router 'kemna/85.25.62.36' as down.
Apr 29 01:04:25.520 [debug] circuit_increment_failure_count(): n_circuit_failures now 1.
Apr 29 01:04:25.520 [warn] circuit_get_open_circ_or_launch(): Bug: The application request to "jabber.org":5222 has launched 10 circuits without finding one it likes.
Apr 29 01:04:25.520 [info] circuit_get_open_circ_or_launch(): No safe circuit (purpose 5) ready for edge connection; delaying.
I think we need to change the check so it only increments num_circuits_launched when the circuit it launches makes it to the 'open' state. I fear that's a more complex hack though.