[tor-bugs] #19966 [Core Tor/Torsocks]: torproxy goes south with more than 1 connection attempt per second to a hidden service

Tue Aug 23 22:51:16 UTC 2016

#19966: torproxy goes south with more than 1 connection attempt per second to a
hidden service
-----------------------------------+--------------------------------
     Reporter:  Alan               |      Owner:  dgoulet
         Type:  defect             |     Status:  new
     Priority:  High               |  Milestone:  Tor: 0.2.7.x-final
    Component:  Core Tor/Torsocks  |    Version:  Tor: 0.2.8.6
     Severity:  Major              |   Keywords:
Actual Points:                     |  Parent ID:
       Points:                     |   Reviewer:
      Sponsor:                     |
-----------------------------------+--------------------------------
 I have a web service running as a tor hidden service.  I have a test
 script that connects to the hidden service through tor proxy, sends a
 short string, gets a short reply, and then the hidden service closes the
 connection.  Each time the test script connects, it uses a different socks
 username, so it should get a fresh tor circuit each time.

 This works mostly ok with Tor v0.2.7.6 (git-7a489a6389110120) running on
 Windows 7 with Libevent 2.0.22-stable, OpenSSL 1.0.1t and Zlib 1.2.8.
 With four test scripts, it makes about 1 connection per second.
 Obviously, with any network, it is going to get some connection and
 network errors, but it recovers eventually.

 With Tor v0.2.8.6 (git-4d217548e3f05569) running on Windows 7 with
 Libevent 2.0.22-stable, OpenSSL 1.0.1t and Zlib 1.2.8, it doesn't run so
 well.  Up to about one connection every two seconds, it runs ok, but as
 soon as I go above that, tor proxy goes south and starts refusing all
 connections and the logging error messages shown below.  This behavior
 makes is unsuitable/unreliable to use in a "production" environment.

 It seems to not matter what version of tor I use on the hidden service
 side--only the version on the client side seems to matter, and that is
 where the errors messages are seen.

 This is the contents of my torrc file, which works under v0.2.7.6 but not
 under v0.2.8.6.

 Log notice stdout
 LogMessageDomains 1
 SafeLogging 0
 MaxClientCircuitsPending 200
 KeepalivePeriod 15
 SocksTimeout 60
 NewCircuitPeriod 1
 LearnCircuitBuildTimeout 1
 CircuitBuildTimeout 60
 NumEntryGuards 20

 The error messages are:

 Aug 23 18:30:32.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:32.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:34.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:34.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:35.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:35.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:35.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:35.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:36.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:36.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:36.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:36.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:36.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:36.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:37.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:37.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:37.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:37.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:37.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:37.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:37.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:37.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:38.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:38.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:39.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:39.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:39.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:39.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:39.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:40.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:40.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:40.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:40.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:40.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:40.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:40.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:40.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:41.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:41.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:41.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:41.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:41.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:41.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:41.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:41.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:41.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:41.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:41.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:41.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:41.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:41.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:41.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:41.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:42.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:42.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:42.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:42.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:42.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:42.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:42.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:42.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:42.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:42.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:42.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:42.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:43.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:43.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:43.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:43.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:43.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:43.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:43.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:43.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:43.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:43.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:43.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:43.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:43.000 [warn] {REND} Fetching v2 rendezvous descriptor
 failed. Retrying at another directory.
 Aug 23 18:30:43.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:43.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).
 Aug 23 18:30:43.000 [notice] {REND} Closing stream for
 'vgfdgkr7tudleiq3.onion': hidden service is unavailable (try again later).

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