Opened 6 years ago

Closed 6 years ago

#10616 closed defect (fixed)

Bug: No origin circuit for successful SOCKS stream 6434

Reported by: arma Owned by: andrea
Priority: Medium Milestone: Tor: 0.2.5.x-final
Component: Core Tor/Tor Version:
Severity: Keywords: tor-client, 025-triaged
Cc: Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

While failing to connect to a hidden service:

Jan 12 01:47:05.687 [info] connection_dir_client_reached_eof(): Received rendezvous descriptor (size 3258, status 200 ("OK"))
Jan 12 01:47:05.688 [info] rend_cache_store_v2_desc_as_client(): We already have this service descriptor wvhfrckfqzmyou42.
Jan 12 01:47:05.688 [info] connection_dir_client_reached_eof(): Successfully fetched v2 rendezvous descriptor.
Jan 12 01:47:05.688 [notice] Closing stream for 'wvhfrckfqzmyou42.onion': hidden service is unavailable (try again later).
Jan 12 01:47:05.688 [info] rend_client_note_connection_attempt_ended(): Connection attempt for wvhfrckfqzmyou42 has ended; cleaning up temporary state.
Jan 12 01:47:05.688 [info] connection_ap_handshake_socks_reply(): Bug: No origin circuit for successful SOCKS stream 6434. Reason: 2
Jan 12 01:47:05.688 [info] rend_client_note_connection_attempt_ended(): Connection attempt for wvhfrckfqzmyou42 has ended; cleaning up temporary state.
Jan 12 01:47:05.688 [debug] conn_close_if_marked(): Cleaning up connection (fd 13).

LD_BUG is intended to be for events that indicate bugs in Tor. Is this a bug in Tor, or is it a misuse of LD_BUG?

Child Tickets

Change History (13)

comment:1 Changed 6 years ago by nickm

Milestone: Tor: 0.2.4.x-final

Hm. It's complaining that we got END_STREAM_REASON_RESOLVEFAILED for a stream, but that stream isn't attached to a circuit. This is an oversight in the pathbias code. Looks like it should have been fixed:

      // DNS remaps can trigger this. So can failed hidden service
      // lookups.

we should make the failed-hidden-service-lookup case not give a message there.

I also wonder about:

Jan 12 01:47:05.688 [info] connection_dir_client_reached_eof(): Successfully fetched v2 rendezvous descriptor.
Jan 12 01:47:05.688 [notice] Closing stream for 'wvhfrckfqzmyou42.onion': hidden service is unavailable (try again later).

It seems like something's missing if we think we fetched it, *and* we can't connect. It would be nice to know why.

comment:2 Changed 6 years ago by nickm

Keywords: 024-backport added
Milestone: Tor: 0.2.4.x-finalTor: 0.2.5.x-final

comment:3 Changed 6 years ago by nickm

Keywords: 025-triaged added

comment:4 Changed 6 years ago by andrea

Owner: set to andrea
Status: newassigned

comment:5 Changed 6 years ago by nickm

Current plan on these is to investigate the bug, try to finish writing the patch on each, and then evaluate whether the patch is 0.2.5 or 0.2.6 material in terms of simplicity and importance.

comment:6 Changed 6 years ago by nickm

Keywords: 024-backport removed

comment:7 Changed 6 years ago by andrea

I believe this is a bug in connection_ap_handshake_socks_reply(); the enclosing if clause is written as though endreason == END_STREAM_REASON_RESOLVEFAILED implies the circuit was completed (i.e., we made it to an exit node but then DNS lookup failed), but that endreason has a different meaning for hidden service circuits.

comment:8 Changed 6 years ago by andrea

The other case mentioned in the comment about DNS remaps probably originates in the call from connection_ap_handshake_socks_resolved() on connection_edge.c line 2256 when answer_type is not one of RESOLVED_TYPE_IPV4, RESOLVED_TYPE_IPV6 or RESOLVED_TYPE_HOSTNAME.

comment:9 Changed 6 years ago by andrea

Some other possible causes of a call to connection_ap_handshake_socks_resolved() with endreason == END_STREAM_REASON_RESOLVEFAILED are:

  • via connection_mark_unattached_ap() for a CLOSESTREAM control command on control.c line 2827 (clearly not the case here)
  • via connection_mark_unattached_ap() for connection_ap_process_end_not_open() on relay.c line 914, when receiving an END cell before the stream is opened. This can't be the case here because it would have to be ored with END_STREAM_REASON_FLAG_REMOTE.

comment:10 Changed 6 years ago by andrea

I believe the only possible origin of this call to connection_ap_handshake_socks_reply() is via connection_mark_unattached_ap() called on line 1088 of rendclient.c. The redundant calls to rend_client_note_connection_attempt_ended() are also notable; one originates from connection_mark_unattached_ap() before the call to connection_ap_handshake_socks_reply(), and the other from rend_client_desc_trynow() immediately after the call to connection_mark_unattached_ap().

comment:11 Changed 6 years ago by andrea

Conclusion: this is a bug in connection_ap_handshake_socks_reply(), which should either ignore !conn->edge_.on_circuit silently or should check for those two known cases where END_STREAM_REASON_RESOLVEFAILED does not actually imply a completed circuit, and only log anything if neither of them apply.

comment:12 Changed 6 years ago by andrea

Status: assignedneeds_review

Simple fix (suppress the error message when endreason == END_STREAM_REASON_RESOLVEFAILED) in my bug10616 branch. I'm filing a new ticket in 0.2.6 to refactor to avoid the redundant call.

comment:13 Changed 6 years ago by nickm

Resolution: fixed
Status: needs_reviewclosed

Merged into master. The ticket Andrea added for the 0.2.6 refactor work is #12194.

Note: See TracTickets for help on using tickets.