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
The HS torrc is:
ControlPort 9051
DataDirectory /home/alecm/tor-dev/data
SafeLogging 0
Log info stdout
HiddenServiceDir /home/alecm/tor-dev/hs
HiddenServicePort 80 localhost:80
SocksPort 0
RendPostPeriod 0 seconds
I also have an OSX version of Tor Browser Bundle - version 5.5a4 (tor
0.2.7.4-rc)
I amended /Applications/TorBrowser.app/TorBrowser/Data/Tor/torrc-defaults to
include:
SafeLogging 0
Log info file /tmp/tor-log.txt
...so that I can see what is going on.
I launched the Hidden Service (HS)
I accessed the HS from TBB - Successful Page Load!
The TBB logfile contains the following sequence, pertinent to the first
connection attempt, with manual edits:
---- start ----
>Nov 12 17:41:13.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_1
>Nov 12 17:45:02.000 [info] connection_ap_handshake_rewrite_and_attach(): Got
a hidden service request for ID 'MY_ONION'
>Nov 12 17:45:02.000 [info] connection_ap_handshake_rewrite_and_attach():
Unknown descriptor MY_ONION. Fetching.
>Nov 12 17:45:02.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:45:03.000 [info] circuit_get_open_circ_or_launch(): Chose
INTROPOINT_1 as intro point for 'MY_ONION'.
>Nov 12 17:45:03.000 [info] rend_client_note_connection_attempt_ended():
Connection attempt for MY_ONION has ended; cleaning up temporary state.
>Nov 12 17:45:03.000 [info] link_apconn_to_circ(): Looks like completed
circuit to hidden service does allow optimistic data for connection to MY_ONION
---- end ----
This looks good.
I killed the HS - the means of killing appears immaterial, SIGINT, SIGTERM,
same thing always happens.
I waited about 60 seconds.
I re-launched the HS.
I accessed the HS from (still running, not restarted) TBB using Shift-Reload to
force a page-refresh - Failure!
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...
>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
signature.asc
Description: Message signed with OpenPGP using GPGMail
_______________________________________________ tor-dev mailing list [email protected] https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-dev
