[tor-bugs] #2401 [Tor Client]: rend_cache_store(): We already have a v2 descriptor for service xxxxx

Tor Bug Tracker & Wiki torproject-admin at torproject.org
Sat Jan 22 15:06:40 UTC 2011


#2401: rend_cache_store(): We already have a v2 descriptor for service xxxxx
--------------------------------+-------------------------------------------
 Reporter:  prof7bit            |        Type:  defect    
   Status:  new                 |    Priority:  normal    
Milestone:  Tor: 0.2.1.x-final  |   Component:  Tor Client
  Version:  Tor: unspecified    |    Keywords:            
   Parent:                      |  
--------------------------------+-------------------------------------------

Comment(by prof7bit):

 Below is an example where it took far longer than 15 minutes, actually it
 never succeeded although I know that the service existed.

 Although it was older than 15 minutes it did not try any of the
 introduction points of the newly fetched descriptor or even tried to
 compare whether it is still the same old descriptor or a different one. It
 just throws it away after fetching it, it won't ever update its cache,
 whenever there is *any* v2 descriptor in the cache, no matter how old it
 is.

 The following comment is in rendcommon.c at the top of the function
 rend_cache_store():

 {{{
  998  * If we are acting as client due to the published flag and have any
 v2
  999  * descriptor with the same ID, reject this one in order to not get
 1000  * confused with having both versions for the same service.
 }}}
 and the following is in the code:

 {{{
 1043   /* Do we have a v2 descriptor and fetched this descriptor as a
 client? */
 1044   tor_snprintf(key, sizeof(key), "2%s", query);
 1045   if (!published && strmap_get_lc(rend_cache, key)) {
 1046     log_info(LD_REND, "We already have a v2 descriptor for service
 %s.",
 1047              safe_str_client(query));
 1048     rend_service_descriptor_free(parsed);
 1049     return -1;
 1050   }
 }}}
 To me this looks plain wrong. It wont ever be able to connect to this
 hidden service ever again once it has *any* descriptor for this service in
 its cache, no matter how old it is. I can vaguely remember a time in the
 past when hidden services worked flawlessly but at the moment it is really
 difficult, almost impossible sometimes.You won't notice the problem if you
 fire up Tor and connect to some random hidden service website with the
 browser but when you are using an application like torchat which will
 desperately try to establish a long lived connection to each of the
 buddies on its list from which it got a ping (and thus *knows* that it's
 service must be online) the problem becomes obvious.

 It all seems to be related to v2 descriptors. I have seen this situation
 resolve itself sometimes as soon as a new v0 descriptor appears on the
 scene from somewhere, then it will immediately connect but the whole v2
 mechanism seems completely broken.

 {{{
 Jan 22 14:45:41.013 [info] connection_ap_handshake_rewrite_and_attach():
 Got a hidden service request for ID 'gtvsxxxxxxxxxxxx'
 Jan 22 14:45:41.013 [info] connection_ap_handshake_rewrite_and_attach():
 Stale descriptor gtvsxxxxxxxxxxxx. Re-fetching.
 Jan 22 14:45:41.043 [info] directory_get_from_hs_dir(): Sending fetch
 request for v2 descriptor for service 'gtvsxxxxxxxxxxxx' with descriptor
 ID '25zu6xfciiexu46ejtdgl36a47dd62fv', auth type 0, and descriptor cookie
 '[none]' to hidden service directory 'infogtor' on port 9030.
 Jan 22 14:45:41.043 [info] rend_client_refetch_renddesc(): Fetching
 rendezvous descriptor for service "gtvsxxxxxxxxxxxx"
 Jan 22 14:45:44.475 [info] rend_cache_store(): We already have a v2
 descriptor for service gtvsxxxxxxxxxxxx.
 Jan 22 14:46:07.872 [info] circuit_get_open_circ_or_launch(): Chose
 '$9C1F4DFBCBB38C8DA3CB1EAEE1B564BA83462E7B' as intro point for
 'gtvsxxxxxxxxxxxx'.
 Jan 22 14:46:19.839 [info] rend_client_remove_intro_point(): 2 options
 left for "gtvsxxxxxxxxxxxx".
 Jan 22 14:46:19.839 [info] rend_client_introduction_acked(): Got nack for
 "gtvsxxxxxxxxxxxx" from $9C1F4DFBCBB38C8DA3CB1EAEE1B564BA83462E7B. Re-
 extending circ 2401, this time to
 $F3C71028D177715BB93F6D0E3440E24F1832A234.
 Jan 22 14:46:22.140 [info] rend_client_remove_intro_point(): 1 options
 left for "gtvsxxxxxxxxxxxx".
 Jan 22 14:46:22.141 [info] rend_client_introduction_acked(): Got nack for
 "gtvsxxxxxxxxxxxx" from $F3C71028D177715BB93F6D0E3440E24F1832A234. Re-
 extending circ 2401, this time to
 $0748226B219A3C7CFD7217A5B552BCE8599CC9C4.
 Jan 22 14:46:22.457 [info] circuit_get_open_circ_or_launch(): Chose
 '$0748226B219A3C7CFD7217A5B552BCE8599CC9C4' as intro point for
 'gtvsxxxxxxxxxxxx'.
 Jan 22 14:46:27.640 [info] rend_client_remove_intro_point(): No more intro
 points remain for "gtvsxxxxxxxxxxxx". Re-fetching descriptor.
 Jan 22 14:46:27.640 [info] rend_client_refetch_renddesc(): Fetching
 rendezvous descriptor for service "gtvsxxxxxxxxxxxx"
 Jan 22 14:46:36.692 [info] rend_cache_store(): We already have a v2
 descriptor for service gtvsxxxxxxxxxxxx.
 Jan 22 14:48:07.996 [notice] Tried for 120 seconds to get a connection to
 gtvsxxxxxxxxxxxx:11009. Giving up. (waiting for rendezvous desc)
 Jan 22 14:54:46.009 [info] connection_ap_handshake_rewrite_and_attach():
 Got a hidden service request for ID 'gtvsxxxxxxxxxxxx'
 Jan 22 14:54:46.010 [info] circuit_get_open_circ_or_launch(): No intro
 points for 'gtvsxxxxxxxxxxxx': re-fetching service descriptor.
 Jan 22 14:54:46.010 [info] rend_client_refetch_renddesc(): Fetching
 rendezvous descriptor for service "gtvsxxxxxxxxxxxx"
 Jan 22 14:54:51.787 [info] rend_cache_store(): We already have a v2
 descriptor for service gtvsxxxxxxxxxxxx.
 Jan 22 14:56:46.364 [notice] Tried for 120 seconds to get a connection to
 gtvsxxxxxxxxxxxx:11009. Giving up. (waiting for rendezvous desc)
 Jan 22 15:02:18.385 [info] connection_ap_handshake_rewrite_and_attach():
 Got a hidden service request for ID 'gtvsxxxxxxxxxxxx'
 Jan 22 15:02:18.385 [info] connection_ap_handshake_rewrite_and_attach():
 Stale descriptor gtvsxxxxxxxxxxxx. Re-fetching.
 Jan 22 15:02:18.408 [info] directory_get_from_hs_dir(): Sending fetch
 request for v2 descriptor for service 'gtvsxxxxxxxxxxxx' with descriptor
 ID '25zu6xfciiexu46ejtdgl36a47dd62fv', auth type 0, and descriptor cookie
 '[none]' to hidden service directory 'SNOWOUTSIDE' on port 9030.
 Jan 22 15:02:18.408 [info] rend_client_refetch_renddesc(): Fetching
 rendezvous descriptor for service "gtvsxxxxxxxxxxxx"
 Jan 22 15:02:20.437 [info] rend_cache_store(): We already have a v2
 descriptor for service gtvsxxxxxxxxxxxx.
 Jan 22 15:02:38.010 [info] rend_cache_store_v2_desc_as_client(): We
 already have this service descriptor gtvsxxxxxxxxxxxx.
 Jan 22 15:04:18.197 [notice] Tried for 120 seconds to get a connection to
 gtvsxxxxxxxxxxxx:11009. Giving up. (waiting for rendezvous desc)
 Jan 22 15:10:36.209 [info] connection_ap_handshake_rewrite_and_attach():
 Got a hidden service request for ID 'gtvsxxxxxxxxxxxx'
 Jan 22 15:10:36.210 [info] circuit_get_open_circ_or_launch(): No intro
 points for 'gtvsxxxxxxxxxxxx': re-fetching service descriptor.
 Jan 22 15:10:36.210 [info] rend_client_refetch_renddesc(): Fetching
 rendezvous descriptor for service "gtvsxxxxxxxxxxxx"
 Jan 22 15:10:38.559 [info] rend_cache_store(): We already have a v2
 descriptor for service gtvsxxxxxxxxxxxx.
 Jan 22 15:12:36.280 [notice] Tried for 120 seconds to get a connection to
 gtvsxxxxxxxxxxxx:11009. Giving up. (waiting for rendezvous desc)
 Jan 22 15:18:38.293 [info] connection_ap_handshake_rewrite_and_attach():
 Got a hidden service request for ID 'gtvsxxxxxxxxxxxx'
 Jan 22 15:18:38.293 [info] connection_ap_handshake_rewrite_and_attach():
 Stale descriptor gtvsxxxxxxxxxxxx. Re-fetching.
 Jan 22 15:18:38.320 [info] directory_get_from_hs_dir(): Sending fetch
 request for v2 descriptor for service 'gtvsxxxxxxxxxxxx' with descriptor
 ID '25zu6xfciiexu46ejtdgl36a47dd62fv', auth type 0, and descriptor cookie
 '[none]' to hidden service directory 'infogtor' on port 9030.
 Jan 22 15:18:38.324 [info] rend_client_refetch_renddesc(): Fetching
 rendezvous descriptor for service "gtvsxxxxxxxxxxxx"
 Jan 22 15:18:40.954 [info] rend_cache_store(): We already have a v2
 descriptor for service gtvsxxxxxxxxxxxx.
 Jan 22 15:18:50.249 [info] rend_cache_store_v2_desc_as_client(): We
 already have this service descriptor gtvsxxxxxxxxxxxx.
 Jan 22 15:20:38.344 [notice] Tried for 120 seconds to get a connection to
 gtvsxxxxxxxxxxxx:11009. Giving up. (waiting for rendezvous desc)

 }}}

-- 
Ticket URL: <https://trac.torproject.org/projects/tor/ticket/2401#comment:3>
Tor Bug Tracker & Wiki <https://trac.torproject.org/>
The Tor Project: anonymity online


More information about the tor-bugs mailing list