[tor-bugs] #7302 [Tor]: Hibernating v0.2.3.x nags about failure connect

Sat Nov 3 21:10:52 UTC 2012

#7302: Hibernating v0.2.3.x nags about failure connect
-------------------------+--------------------------------------------------
 Reporter:  tmpname0901  |          Owner:                  
     Type:  defect       |         Status:  new             
 Priority:  normal       |      Milestone:                  
Component:  Tor          |        Version:  Tor: 0.2.3.24-rc
 Keywords:               |         Parent:                  
   Points:               |   Actualpoints:                  
-------------------------+--------------------------------------------------
 A hibernating v0.2.3.x relay fills its logs with complaints about
 inability to establish connections.

 Below the complaints are bootstrap-related because a hibernating relay was
 restarted.  Similar complaints are seen with a constantly-running relay
 when the consensus becomes outdated.

 A relay may spend the bulk of its accounting period issuing these
 warnings, after the configured bandwidth is exhausted.

 ------------------

 Nov 01 21:09:18.000 [notice] Tor 0.2.3.24-rc (git-4f228f39ec74abfa)
 opening log file.
 Nov 01 21:09:18.000 [notice] This version of OpenSSL has a known-good EVP
 counter-mode implementation. Using it.
 Nov 01 21:09:18.000 [notice] OpenSSL OpenSSL 1.0.1c 10 May 2012 looks like
 version 0.9.8m or later; I will try SSL_OP to enable renegotiation
 Nov 01 21:09:18.000 [notice] Your Tor server's identity key fingerprint is
 'Unnamed XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX'
 Nov 01 21:09:18.000 [notice] Configured hibernation. This interval begins
 at 2012-09-30 00:00:00 and ends at 2012-11-05 00:00:00. We have no prior
 estimate for bandwidth, so we will start out awake and hibernate when we
 exhaust our quota.
 Nov 01 21:09:18.000 [notice] Parsing GEOIP file /usr/share/tor/geoip.
 Nov 01 21:09:18.000 [notice] Configured to measure statistics. Look for
 the *-stats files that will first be written to the data directory in 24
 hours from now.
 Nov 01 21:09:19.000 [notice] Reloaded microdescriptor cache.  Found 8634
 descriptors.
 Nov 01 21:09:21.000 [notice] We now have enough directory information to
 build circuits.
 Nov 01 21:09:21.000 [notice] Bootstrapped 80%: Connecting to the Tor
 network.
 Nov 01 21:09:22.000 [notice] Bandwidth soft limit reached; commencing
 hibernation. No new connections will be accepted
 Nov 01 21:09:22.000 [notice] Going dormant. Blowing away remaining
 connections.
 Nov 01 21:09:22.000 [notice] Heartbeat: It seems like we are not in the
 cached consensus.
 Nov 01 21:09:22.000 [notice] Heartbeat: Tor's uptime is 0:00 hours, with 3
 circuits open. I've sent 0 kB and received 0 kB.
 Nov 01 21:09:22.000 [notice] Bootstrapped 85%: Finishing handshake with
 first hop.
 Nov 02 03:09:22.000 [notice] Heartbeat: It seems like we are not in the
 cached consensus.
 Nov 02 03:09:22.000 [notice] Heartbeat: Tor's uptime is 6:00 hours, with
 43 circuits open. I've sent 1.37 MB and received 3.59 MB.
 Nov 02 09:09:22.000 [notice] Heartbeat: It seems like we are not in the
 cached consensus.
 Nov 02 09:09:22.000 [notice] Heartbeat: Tor's uptime is 12:00 hours, with
 93 circuits open. I've sent 3.82 MB and received 9.03 MB.
 Nov 02 15:09:22.000 [notice] Heartbeat: It seems like we are not in the
 cached consensus.
 Nov 02 15:09:22.000 [notice] Heartbeat: Tor's uptime is 18:00 hours, with
 141 circuits open. I've sent 7.14 MB and received 15.68 MB.
 Nov 02 21:09:22.000 [notice] Heartbeat: It seems like we are not in the
 cached consensus.
 Nov 02 21:09:22.000 [notice] Heartbeat: Tor's uptime is 1 day 0:00 hours,
 with 177 circuits open. I've sent 11.14 MB and received 22.99 MB.
 Nov 03 03:09:22.000 [notice] Heartbeat: It seems like we are not in the
 cached consensus.
 Nov 03 03:09:22.000 [notice] Heartbeat: Tor's uptime is 1 day 6:00 hours,
 with 202 circuits open. I've sent 15.26 MB and received 30.09 MB.
 Nov 03 07:52:34.000 [warn] Problem bootstrapping. Stuck at 85%: Finishing
 handshake with first hop. (Connection timed out; TIMEOUT; count 10;
 recommendation warn)
 Nov 03 07:52:34.000 [warn] 9 connections have failed:
 Nov 03 07:52:34.000 [warn]  8 connections died in state connect()ing with
 SSL state (No SSL object)
 Nov 03 07:52:34.000 [warn]  1 connections died in state handshaking (TLS)
 with SSL state SSLv2/v3 read server hello A in HANDSHAKE
 Nov 03 07:52:35.000 [warn] Problem bootstrapping. Stuck at 85%: Finishing
 handshake with first hop. (Connection timed out; TIMEOUT; count 11;
 recommendation warn)
 Nov 03 07:52:35.000 [warn] 10 connections have failed:
 Nov 03 07:52:35.000 [warn]  9 connections died in state connect()ing with
 SSL state (No SSL object)
 Nov 03 07:52:35.000 [warn]  1 connections died in state handshaking (TLS)
 with SSL state SSLv2/v3 read server hello A in HANDSHAKE
 Nov 03 09:09:22.000 [notice] Heartbeat: It seems like we are not in the
 cached consensus.
 Nov 03 09:09:22.000 [notice] Heartbeat: Tor's uptime is 1 day 12:00 hours,
 with 250 circuits open. I've sent 19.92 MB and received 38.68 MB.
 Nov 03 10:50:28.000 [warn] Problem bootstrapping. Stuck at 85%: Finishing
 handshake with first hop. (Connection timed out; TIMEOUT; count 12;
 recommendation warn)
 Nov 03 10:50:28.000 [warn] 11 connections have failed:
 Nov 03 10:50:28.000 [warn]  10 connections died in state connect()ing with
 SSL state (No SSL object)
 Nov 03 10:50:28.000 [warn]  1 connections died in state handshaking (TLS)
 with SSL state SSLv2/v3 read server hello A in HANDSHAKE
 Nov 03 10:54:26.000 [warn] Problem bootstrapping. Stuck at 85%: Finishing
 handshake with first hop. (DONE; DONE; count 13; recommendation warn)
 Nov 03 10:54:26.000 [warn] 13 connections have failed:
 Nov 03 10:54:26.000 [warn]  11 connections died in state connect()ing with
 SSL state (No SSL object)
 Nov 03 10:54:26.000 [warn]  1 connections died in state handshaking (Tor,
 v3 handshake) with SSL state SSL negotiation finished successfully in OPEN
 Nov 03 10:54:26.000 [warn]  1 connections died in state handshaking (TLS)
 with SSL state SSLv2/v3 read server hello A in HANDSHAKE
 Nov 03 15:09:22.000 [notice] Heartbeat: It seems like we are not in the
 cached consensus.
 Nov 03 15:09:22.000 [notice] Heartbeat: Tor's uptime is 1 day 18:00 hours,
 with 294 circuits open. I've sent 25.17 MB and received 47.26 MB.
 Nov 03 15:38:11.000 [warn] Problem bootstrapping. Stuck at 85%: Finishing
 handshake with first hop. (Connection timed out; TIMEOUT; count 14;
 recommendation warn)
 Nov 03 15:38:11.000 [warn] 13 connections have failed:
 Nov 03 15:38:11.000 [warn]  11 connections died in state connect()ing with
 SSL state (No SSL object)
 Nov 03 15:38:11.000 [warn]  1 connections died in state handshaking (Tor,
 v3 handshake) with SSL state SSL negotiation finished successfully in OPEN
 Nov 03 15:38:11.000 [warn]  1 connections died in state handshaking (TLS)
 with SSL state SSLv2/v3 read server hello A in HANDSHAKE
 Nov 03 16:47:41.000 [notice] Catching signal TERM, exiting cleanly

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