Opened 5 months ago

Closed 5 months ago

Last modified 5 months ago

#22042 closed defect (fixed)

HSFETCH not followed by HS_DESC_CONTENT event

Reported by: nickler Owned by: dgoulet
Priority: Medium Milestone: Tor: 0.3.1.x-final
Component: Core Tor/Tor Version: Tor: 0.2.9.10
Severity: Normal Keywords: tor-hs, control, spec
Cc: Actual Points:
Parent ID: Points: 0.2
Reviewer: Sponsor:

Description

Hi,

I'm trying to periodically get a hidden service descriptor to monitor changes. I tried using stem with the following python script:

from stem.control import Controller
import datetime
import time

ONION = 'expyuzz4wqqyqhjn'

with Controller.from_port(port = 9051) as controller:
  controller.authenticate()
  while True:
      print(datetime.datetime.now())
      desc = controller.get_hidden_service_descriptor(ONION)
      time.sleep(60)

However, after about six iterations the get_hidden_service_descriptor blocks indefinitely (I waited up to 24 hours). I manually recreated what stem sends to the control port:

% nc 127.0.0.1 9051
AUTHENTICATE
250 OK
SETEVENTS HS_DESC_CONTENT HS_DESC
250 OK
HSFETCH expyuzz4wqqyqhjn
250 OK
650 HS_DESC REQUESTED expyuzz4wqqyqhjn NO_AUTH $D0B232E732DD69F181815EE6648E9AB8A67F73BA~ididntedittheconfig 2baufgsbt3a2jolhmvrsmd3ufdg72cyz
650 HS_DESC RECEIVED expyuzz4wqqyqhjn NO_AUTH $D0B232E732DD69F181815EE6648E9AB8A67F73BA~ididntedittheconfig 2baufgsbt3a2jolhmvrsmd3ufdg72cyz
650+HS_DESC_CONTENT expyuzz4wqqyqhjn 2baufgsbt3a2jolhmvrsmd3ufdg72cyz $D0B232E732DD69F181815EE6648E9AB8A67F73BA~ididntedittheconfig
<...>
650 OK
HSFETCH expyuzz4wqqyqhjn
250 OK
650 HS_DESC REQUESTED expyuzz4wqqyqhjn NO_AUTH $D05A37450AB9950181124563D3A7DBC5EE7D30BB~r3dn3ck 2baufgsbt3a2jolhmvrsmd3ufdg72cyz
650 HS_DESC RECEIVED expyuzz4wqqyqhjn NO_AUTH $D05A37450AB9950181124563D3A7DBC5EE7D30BB~r3dn3ck 2baufgsbt3a2jolhmvrsmd3ufdg72cyz
650+HS_DESC_CONTENT expyuzz4wqqyqhjn 2baufgsbt3a2jolhmvrsmd3ufdg72cyz $D05A37450AB9950181124563D3A7DBC5EE7D30BB~r3dn3ck
<...>
650 OK
HSFETCH expyuzz4wqqyqhjn
250 OK
650 HS_DESC REQUESTED expyuzz4wqqyqhjn NO_AUTH $707C1B61AC72227B34487B56D04BAA3BA1179CE8~BrassHornExit04 oalrv2mxdne6gfwikalgyl47sktjwxte
650 HS_DESC RECEIVED expyuzz4wqqyqhjn NO_AUTH $707C1B61AC72227B34487B56D04BAA3BA1179CE8~BrassHornExit04 nyuijvpn63lgfbupw5vqyfdhzbllyk7v
650+HS_DESC_CONTENT expyuzz4wqqyqhjn oalrv2mxdne6gfwikalgyl47sktjwxte $707C1B61AC72227B34487B56D04BAA3BA1179CE8~BrassHornExit04
<...>
650 OK
HSFETCH expyuzz4wqqyqhjn
250 OK
650 HS_DESC REQUESTED expyuzz4wqqyqhjn NO_AUTH $D06CD6EDAA93F4656E0C9F6347B26A2828D6CB25~Unnamed 2baufgsbt3a2jolhmvrsmd3ufdg72cyz
650 HS_DESC RECEIVED expyuzz4wqqyqhjn NO_AUTH $D06CD6EDAA93F4656E0C9F6347B26A2828D6CB25~Unnamed 2baufgsbt3a2jolhmvrsmd3ufdg72cyz
650+HS_DESC_CONTENT expyuzz4wqqyqhjn 2baufgsbt3a2jolhmvrsmd3ufdg72cyz $D06CD6EDAA93F4656E0C9F6347B26A2828D6CB25~Unnamed
<...>
650 OK
HSFETCH expyuzz4wqqyqhjn
250 OK
650 HS_DESC REQUESTED expyuzz4wqqyqhjn NO_AUTH $7056EA2E99144613694F0264C80579AAFEA6E1CD~ozora oalrv2mxdne6gfwikalgyl47sktjwxte
650 HS_DESC RECEIVED expyuzz4wqqyqhjn NO_AUTH $7056EA2E99144613694F0264C80579AAFEA6E1CD~ozora 2baufgsbt3a2jolhmvrsmd3ufdg72cyz
650+HS_DESC_CONTENT expyuzz4wqqyqhjn oalrv2mxdne6gfwikalgyl47sktjwxte $7056EA2E99144613694F0264C80579AAFEA6E1CD~ozora
<...>
650 OK
HSFETCH expyuzz4wqqyqhjn
250 OK
650 HS_DESC REQUESTED expyuzz4wqqyqhjn NO_AUTH $7044955A4D7B04CF70011D73B467B13CE5E69D41~L29Ah oalrv2mxdne6gfwikalgyl47sktjwxte
650 HS_DESC RECEIVED expyuzz4wqqyqhjn NO_AUTH $7044955A4D7B04CF70011D73B467B13CE5E69D41~L29Ah 2baufgsbt3a2jolhmvrsmd3ufdg72cyz
650+HS_DESC_CONTENT expyuzz4wqqyqhjn oalrv2mxdne6gfwikalgyl47sktjwxte $7044955A4D7B04CF70011D73B467B13CE5E69D41~L29Ah
<...>
650 OK
HSFETCH expyuzz4wqqyqhjn
250 OK

No HS_DESC or HS_DESC_CONTENT is received after the last HSFETCH (I waited about an hour). The control port spec (https://gitweb.torproject.org/torspec.git/tree/control-spec.txt) states that "On success, Tor replies "250 OK" then Tor MUST eventually follow this with both a HS_DESC and HS_DESC_CONTENT events with the results.".

I guess that stem blocks because it waits for the event. If I send another HSFETCH expyuzz4wqqyqhjn after a couple of minutes, the corresponding events are emitted just fine. Also I noticed that when the sleep in the above python script is increased to 10 minutes, get_hidden_service_descriptor continues to return a result quickly.

Child Tickets

Change History (14)

comment:1 Changed 5 months ago by cypherpunks

Component: - Select a componentCore Tor/Stem
Owner: set to atagar

comment:2 Changed 5 months ago by atagar

Component: Core Tor/StemCore Tor/Tor

Hi nickler, since you reproed this directly with the controlport this isn't stem related. Sending this over to the tor component.

comment:3 Changed 5 months ago by asn

Keywords: tor-hs added
Milestone: Tor: 0.3.1.x-final

Triaging this for 0.3.1.

comment:4 Changed 5 months ago by dgoulet

Resolution: not a bug
Status: newclosed

This is currently expected behavior and here is why. For every .onion, there are 6 HSDirs so after 6 HSFETCH, your client has gone over all 6 HSDirs for which each of them is put in a "lookup cache" and you won't be able to query them again for the same onion address in the next 15 minutes.

This is to avoid (maybe buggy) tor client to hammer HSDir for the same .onion... Thus, in this case, you can only HSFETCH the onion address after 15 minutes of wait period. So even waiting 24 hours won't do it here, you need to do the HSFETCH again after 15 minutes because the 7th one just didn't work in the first place thus no control event.

We could think of a new control port HS_DESC event that tells you "No more HSDir can be used" or something. Let's open a new ticket if we want that.

Side note: Hammering the HSDirs every 60 seconds is really not a good idea overall. It puts load on the network ultimately degrading it.

comment:5 Changed 5 months ago by atagar

Resolution: not a bug
Status: closedreopened

We could think of a new control port HS_DESC event that tells you "No more HSDir can be used" or something. Let's open a new ticket if we want that.

Hi David, lets use this ticket for that. According to the spec ("On success, Tor replies "250 OK" then Tor MUST eventually follow this with both a HS_DESC and HS_DESC_CONTENT events with the results.") this is a tor bug.

comment:6 Changed 5 months ago by dgoulet

Keywords: control added
Owner: changed from atagar to dgoulet
Points: 0.2
Status: reopenedaccepted

Ok.

So we should send back an HS_DESC failed event and then a HS_DESC_CONTENT empty event. Let's go with that for now. We'll _try_ to make it for 031.

comment:7 Changed 5 months ago by nickler

Thanks for working on fixing this!

Re "Hammering the HSDirs every 60 seconds": yeah I don't want to do that. But I believed that the HS descriptor would come from a local cache after reading the stem documentation and the spec which say something like:
"The caching behavior when fetching a descriptor using this command is identical to normal Tor client behavior."
Where can I read more about the normal Tor client behavior with respect to caching? Or does this note actually refer to the lookup cache dgoulet mentions?

comment:8 in reply to:  7 Changed 5 months ago by dgoulet

Replying to nickler:

Thanks for working on fixing this!

Re "Hammering the HSDirs every 60 seconds": yeah I don't want to do that. But I believed that the HS descriptor would come from a local cache after reading the stem documentation and the spec which say something like:
"The caching behavior when fetching a descriptor using this command is identical to normal Tor client behavior."

The HSFETCH command doesn't poke the cache, it always try to download a descriptor from HSDir(s). However, once downloaded, the descriptor ends up in the cache of the tor client you are using.

Where can I read more about the normal Tor client behavior with respect to caching? Or does this note actually refer to the lookup cache dgoulet mentions?

I fear there is no documentation about it except the source code for now :S ... There is a client descriptor cache and an introduction point failure cache. Most of it is in src/or/rendcache.c.

comment:9 Changed 5 months ago by dgoulet

Keywords: spec added
Status: acceptedneeds_review

This required a minor control spec change as well:

Spec: ticket22042_01
Tor: bug22042_031_01

comment:10 Changed 5 months ago by atagar

Thanks David! Spec change looks good to me. If you want me to merge it then let me know but I assume it should wait for the tor side to be merged.

comment:11 Changed 5 months ago by nickm

Status: needs_reviewneeds_revision

comments:

  • I think the torspec fix should say that the behavior began in version 0.3.1.1-alpha, and should say what previous versions did.
  • Should the functions that can now take id_digest == NULL have their documentation updated to say so?

comment:12 in reply to:  11 Changed 5 months ago by dgoulet

Status: needs_revisionneeds_review

Replying to nickm:

comments:

  • I think the torspec fix should say that the behavior began in version 0.3.1.1-alpha, and should say what previous versions did.

See fixup commit in ticket22042_01. (And I think you mean 0.3.1.0-alpha here unless you are planning to merge this _after_ first alpha? Let me know, I can make the change.)

  • Should the functions that can now take id_digest == NULL have their documentation updated to say so?

Indeed!

Fixup commit in bug22042_031_01. I have also added an extra commit to fix a comment over control_event_hs_descriptor_content() because it was just badly missing information.

comment:13 Changed 5 months ago by nickm

Resolution: fixed
Status: needs_reviewclosed

Squashed and merged!

comment:14 Changed 5 months ago by nickm

Merged the spec change too. (Whoops; I missed that the first time around. Thanks to dgoulet for reminding me)

Note: See TracTickets for help on using tickets.