Alec Muffett <[email protected]> writes:
> For the sake of documentation I thought I would share this here:
>
> I have a (test) Hidden Service, running vanilla tor 0.2.6.10
>
> <snip>
>
> The TBB logfile contains the following sequence, pertinent to the second
> connection attempt:
>
> ---- start ----
> >Nov 12 17:46:27.000 [info] connection_ap_handshake_rewrite_and_attach():
> Got a hidden service request for ID 'MY_ONION'
> >Nov 12 17:46:27.000 [info] circuit_get_open_circ_or_launch(): Chose
> INTROPOINT_3 as intro point for 'MY_ONION'.
> >Nov 12 17:46:27.000 [info] rend_client_introduction_acked(): Got nack for
> MY_ONION from INTROPOINT_3...
> >Nov 12 17:46:27.000 [info] rend_client_report_intro_point_failure(): 2
> options left for "MY_ONION".
> >Nov 12 17:46:28.000 [info] rend_client_introduction_acked(): Got nack for
> MY_ONION from INTROPOINT_2...
> >Nov 12 17:46:28.000 [info] rend_client_report_intro_point_failure(): 1
> options left for "MY_ONION".
> >Nov 12 17:46:28.000 [info] rend_client_introduction_acked(): Got nack for
> MY_ONION from INTROPOINT_1...
> >Nov 12 17:46:28.000 [info] rend_client_report_intro_point_failure(): No
> more intro points remain for "MY_ONION". Re-fetching descriptor.
>
> Okay, this makes sense, all the IPs are invalid because I killed the daemon,
> none of them are reachable...
>
> >Nov 12 17:46:28.000 [info] directory_get_from_hs_dir(): Sending fetch
> request
> > for v2 descriptor for service 'MY_ONION' with descriptor ID 'MY_DESC_2',
> > auth type 0, and descriptor cookie '[none]' to hidden service directory
> > HSDIR_3
>
> Wait, is it relevant that it has picked descriptor ID 'MY_DESC_2' here, not
> the
> prior 'MY_DESC_1'? The latter crops-up further down. Perhaps this is a DHT
> thing? This is the only reference to MY_DESC_2...
>
Maybe MY_DESC_2 is the descriptor ID of the second replica? There are two
replicas for an HS descriptor, each served by 3 HSDIrs.
The descriptor ID is formed like this:
descriptor-id =
H(permanent-id | H(time-period | descriptor-cookie | replica))
This might also explain why you get the "we already have this descriptor"
message below.
Not sure though, for more confidence I would have to look deeper here.
> >Nov 12 17:46:29.000 [info] rend_cache_store_v2_desc_as_client(): Service
> descriptor with service ID MY_ONION, every intro points are unusable.
> Discarding it.
>
> That sounds okay, garbage collection of dead data is good...
>
> >Nov 12 17:46:29.000 [info] directory_get_from_hs_dir(): Sending fetch
> request
> > for v2 descriptor for service 'MY_ONION' with descriptor ID 'MY_DESC_1',
> > auth type 0, and descriptor cookie '[none]' to hidden service directory
> > HSDIR_4
>
> Wait, now we are re-fetching MY_DESC_1 again?...
>
> >Nov 12 17:46:30.000 [info] rend_cache_store_v2_desc_as_client(): We
> already have this service descriptor MY_ONION.
>
> And it thinks we already have it? But didn't we just discard it?...
>
> >Nov 12 17:46:30.000 [notice] Closing stream for 'MY_ONION.onion': hidden
> service is unavailable (try again later).
>
> And there is the connection failure, and it looks like it didn't find a new
> descriptor, or rejected a new one if it found it - assuming it found it at
> all...
>
> >Nov 12 17:46:30.000 [info] rend_client_note_connection_attempt_ended():
> Connection attempt for MY_ONION has ended; cleaning up temporary state.
> >Nov 12 17:46:30.000 [info] rend_client_note_connection_attempt_ended():
> Connection attempt for MY_ONION has ended; cleaning up temporary state.
>
> Try "reload" again, just for good luck:
>
> >Nov 12 17:46:40.000 [info] connection_ap_handshake_rewrite_and_attach():
> Got a hidden service request for ID 'MY_ONION'
> >Nov 12 17:46:40.000 [info] connection_ap_handshake_rewrite_and_attach():
> Unknown descriptor MY_ONION. Fetching.
> >Nov 12 17:46:40.000 [info] directory_get_from_hs_dir(): Sending fetch
> request
> > for v2 descriptor for service 'MY_ONION' with descriptor ID 'MY_DESC_1',
> > auth type 0, and descriptor cookie '[none]' to hidden service directory
> > HSDIR_2
> >Nov 12 17:46:41.000 [info] rend_cache_store_v2_desc_as_client(): We
> already have this service descriptor MY_ONION.
> >Nov 12 17:46:41.000 [notice] Closing stream for 'MY_ONION.onion': hidden
> service is unavailable (try again later).
> >Nov 12 17:46:41.000 [info] rend_client_note_connection_attempt_ended():
> Connection attempt for MY_ONION has ended; cleaning up temporary state.
> >Nov 12 17:46:41.000 [info] rend_client_note_connection_attempt_ended():
> Connection attempt for MY_ONION has ended; cleaning up temporary state.
> ---- end ----
>
> So, it looks like one of three things:
>
> - perhaps TBB is not actually discarding the dead descriptor
> - or perhaps TBB is re-fetching the old descriptor and failing connections
> again
> - or perhaps TBB is fetching the new descriptor and rejecting it in favour of
> the old one, which it hasn't really discarded.
>
> In any case: killing TBB and restarting it seems to fix this situation, so
> it's something on the client side at fault?
>
> - alec
>
> _______________________________________________
> tor-dev mailing list
> [email protected]
> https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-dev
_______________________________________________
tor-dev mailing list
[email protected]
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-dev
