Tor 0.2.6.2-alpha complaining about "no exits in consensus" but consensus actually seems fine
Since the upgrade to Tor 0.2.6.2-alpha I frequently get complaints like this on the non-exit relay polizeierziehung ($5CE3AD8AD04ADE66C0037A3CF5F7F7A40D48A20B):
Feb 17 10:19:57.000 [warn] {NET} We need more descriptors: we have 0/6967, and can only build 1% of likely paths. (We have 10% of guards bw, 10% of midpoint bw, and 100% of exit bw (no exits in consensus) = 1%
of path bw.)
Feb 17 10:20:58.000 [warn] {NET} We need more descriptors: we have 0/6967, and can only build 1% of likely paths. (We have 10% of guards bw, 10% of midpoint bw, and 100% of exit bw (no exits in consensus) = 1%
of path bw.)
Feb 17 10:21:59.000 [warn] {NET} We need more descriptors: we have 0/6967, and can only build 1% of likely paths. (We have 10% of guards bw, 10% of midpoint bw, and 100% of exit bw (no exits in consensus) = 1%
of path bw.)
At the moment they occur once per Next seconds.
Tor already complained about "no exits in consensus" while bootstrapping but stopped after connecting to the network:
Feb 15 12:41:01.000 [notice] Tor 0.2.6.2-alpha (git-6cb1daf062df5252) opening new log file.
Feb 15 12:41:01.576 [notice] Tor v0.2.6.2-alpha (git-6cb1daf062df5252) running on ElectroBSD with Libevent 2.0.21-stable, OpenSSL 1.0.1j-freebsd and Zlib 1.2.8.
Feb 15 12:41:01.576 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Feb 15 12:41:01.576 [notice] This version is not a stable Tor release. Expect more bugs than usual.
Feb 15 12:41:01.576 [notice] Read configuration file "/usr/local/etc/tor/torrc".
Feb 15 12:41:01.581 [notice] Based on detected system memory, MaxMemInQueues is set to 1102 MB. You can override this by setting MaxMemInQueues by hand.
Feb 15 12:41:01.583 [notice] Opening Control listener on 127.0.0.1:9051
Feb 15 12:41:01.583 [notice] Opening OR listener on 0.0.0.0:9001
Feb 15 12:41:01.000 [warn] Your log may contain sensitive information - you're logging more than "notice". Don't log unless it serves an important reason. Overwrite the log afterwards.
Feb 15 12:41:01.000 [notice] Parsing GEOIP IPv4 file /usr/local/share/tor/geoip.
Feb 15 12:41:01.000 [notice] Parsing GEOIP IPv6 file /usr/local/share/tor/geoip6.
Feb 15 12:41:01.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.
Feb 15 12:41:01.000 [notice] We were built to run on a 64-bit CPU, with OpenSSL 1.0.1 or later, but with a version of OpenSSL that apparently lacks accelerated support for the NIST P-224 and P-256 groups. Building openssl with such support (using the enable-ec_nistp_64_gcc_128 option when configuring it) would make ECDH much faster.
Feb 15 12:41:01.000 [notice] Your Tor server's identity key fingerprint is 'polizeierziehung 5CE3AD8AD04ADE66C0037A3CF5F7F7A40D48A20B'
Feb 15 12:41:01.000 [notice] Bootstrapped 0%: Starting
Feb 15 12:41:01.000 [notice] The current consensus has no exit nodes. Tor can only build internal paths, such as paths to hidden services.
Feb 15 12:41:01.000 [warn] We need more descriptors: we have 0/7070, and can only build 0% of likely paths. (We have 0% of guards bw, 0% of midpoint bw, and 100% of exit bw (no exits in consensus) = 0% of path bw.)
Feb 15 12:41:01.000 [notice] Bootstrapped 45%: Asking for relay descriptors for internal paths
Feb 15 12:41:01.000 [notice] Guessed our IP address as 95.211.241.83 (source: 194.109.206.212).
Feb 15 12:41:02.000 [notice] Bootstrapped 50%: Loading relay descriptors
Feb 15 12:41:02.000 [notice] I learned some more directory information, but not enough to build a circuit: We need more descriptors: we have 0/7070, and can only build 0% of likely paths. (We have 0% of guards
bw, 0% of midpoint bw, and 100% of exit bw (no exits in consensus) = 0% of path bw.)
Feb 15 12:41:02.000 [notice] We'd like to launch a circuit to handle a connection, but we already have 32 general-purpose client circuits pending. Waiting until some finish.
Feb 15 12:41:02.000 [notice] I learned some more directory information, but not enough to build a circuit: We need more descriptors: we have 0/7070, and can only build 0% of likely paths. (We have 0% of guards
bw, 0% of midpoint bw, and 100% of exit bw (no exits in consensus) = 0% of path bw.)
[...]
Feb 15 12:41:07.000 [notice] I learned some more directory information, but not enough to build a circuit: We need more descriptors: we have 0/7070, and can only build 0% of likely paths. (We have 0% of guards bw, 0% of midpoint bw, and 100% of exit bw (no exits in consensus) = 0% of path bw.)
Feb 15 12:41:07.000 [notice] We now have enough directory information to build circuits.
Feb 15 12:41:07.000 [notice] Bootstrapped 80%: Connecting to the Tor network
Feb 15 12:41:07.000 [notice] Bootstrapped 85%: Finishing handshake with first hop
Feb 15 12:41:08.000 [notice] Bootstrapped 90%: Establishing a Tor circuit
Feb 15 12:41:08.000 [notice] Tor has successfully opened a circuit. Looks like client functionality is working.
Feb 15 12:41:08.000 [notice] Bootstrapped 100%: Done
Feb 15 12:41:12.000 [notice] Performing bandwidth self-test...done.
Feb 15 12:41:13.000 [notice] New control connection opened from 127.0.1.5.
Feb 15 12:47:54.000 [notice] Received reload signal (hup). Reloading config and resetting internal state.
Feb 15 12:47:54.000 [notice] Read configuration file "/usr/local/etc/tor/torrc".
Feb 15 12:47:54.000 [notice] Tor 0.2.6.2-alpha (git-6cb1daf062df5252) opening log file.
Feb 15 12:47:54.000 [notice] Your Tor server's identity key fingerprint is 'polizeierziehung 5CE3AD8AD04ADE66C0037A3CF5F7F7A40D48A20B'
Feb 15 12:49:40.000 [notice] Received reload signal (hup). Reloading config and resetting internal state.
Feb 15 12:49:40.000 [notice] Read configuration file "/usr/local/etc/tor/torrc".
Feb 15 12:49:40.000 [notice] Tor 0.2.6.2-alpha (git-6cb1daf062df5252) opening log file.
Feb 15 12:49:40.000 [notice] {GENERAL} Your Tor server's identity key fingerprint is 'polizeierziehung 5CE3AD8AD04ADE66C0037A3CF5F7F7A40D48A20B'
Feb 15 12:51:50.000 [notice] {GENERAL} Received reload signal (hup). Reloading config and resetting internal state.
Feb 15 12:51:50.000 [notice] {CONFIG} Read configuration file "/usr/local/etc/tor/torrc".
Feb 15 12:51:50.000 [notice] Tor 0.2.6.2-alpha (git-6cb1daf062df5252) opening log file.
Feb 15 12:51:50.000 [notice] {GENERAL} Your Tor server's identity key fingerprint is 'polizeierziehung 5CE3AD8AD04ADE66C0037A3CF5F7F7A40D48A20B'
Feb 15 16:18:48.000 [notice] {CIRC} No circuits are opened. Relaxed timeout for circuit 100 (a General-purpose client 1-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it app
ears the circuit has timed out anyway. 1 guards are live.
Feb 15 18:41:03.000 [notice] {HEARTBEAT} Heartbeat: Tor's uptime is 6:00 hours, with 1024 circuits open. I've sent 11.68 GB and received 11.70 GB.
Feb 15 18:41:03.000 [notice] {HEARTBEAT} Average packaged cell fullness: 86.395%
Feb 15 18:41:03.000 [notice] {HEARTBEAT} TLS write overhead: 3%
Feb 15 18:41:03.000 [notice] {HEARTBEAT} Circuit handshake stats since last time: 29367/29367 TAP, 21000/21000 NTor.
Feb 16 00:41:03.000 [notice] {HEARTBEAT} Heartbeat: Tor's uptime is 12:00 hours, with 946 circuits open. I've sent 25.76 GB and received 25.78 GB.
Feb 16 00:41:03.000 [notice] {HEARTBEAT} Average packaged cell fullness: 84.401%
Feb 16 00:41:03.000 [notice] {HEARTBEAT} TLS write overhead: 3%
Feb 16 00:41:03.000 [notice] {HEARTBEAT} Circuit handshake stats since last time: 21818/21818 TAP, 18671/18671 NTor.
Feb 16 06:41:03.000 [notice] {HEARTBEAT} Heartbeat: Tor's uptime is 18:00 hours, with 884 circuits open. I've sent 36.23 GB and received 36.24 GB.
Feb 16 06:41:03.000 [notice] {HEARTBEAT} Average packaged cell fullness: 82.261%
Feb 16 06:41:03.000 [notice] {HEARTBEAT} TLS write overhead: 3%
Feb 16 06:41:03.000 [notice] {HEARTBEAT} Circuit handshake stats since last time: 20746/20746 TAP, 15523/15523 NTor.
Feb 16 08:31:35.000 [notice] {NET} The current consensus has no exit nodes. Tor can only build internal paths, such as paths to hidden services.
Feb 16 09:15:28.000 [notice] {CIRC} No circuits are opened. Relaxed timeout for circuit 163 (a General-purpose client 1-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. 1 guards are live.
Feb 16 12:41:03.000 [notice] {HEARTBEAT} Heartbeat: Tor's uptime is 1 day 0:00 hours, with 926 circuits open. I've sent 47.99 GB and received 47.97 GB.
Feb 16 12:41:03.000 [notice] {HEARTBEAT} Average packaged cell fullness: 80.405%
Feb 16 12:41:03.000 [notice] {HEARTBEAT} TLS write overhead: 3%
Feb 16 12:41:03.000 [notice] {HEARTBEAT} Circuit handshake stats since last time: 26272/26272 TAP, 20201/20201 NTor.
Feb 16 18:41:03.000 [notice] {HEARTBEAT} Heartbeat: Tor's uptime is 1 day 6:00 hours, with 1118 circuits open. I've sent 62.63 GB and received 62.58 GB.
Feb 16 18:41:03.000 [notice] {HEARTBEAT} Average packaged cell fullness: 78.707%
Feb 16 18:41:03.000 [notice] {HEARTBEAT} TLS write overhead: 3%
Feb 16 18:41:03.000 [notice] {HEARTBEAT} Circuit handshake stats since last time: 31213/31213 TAP, 23753/23753 NTor.
Feb 16 22:12:01.000 [warn] {NET} We need more descriptors: we have 0/7082, and can only build 59% of likely paths. (We have 77% of guards bw, 77% of midpoint bw, and 100% of exit bw (no exits in consensus) = 59% of path bw.) [62 similar message(s) suppressed in last 60 seconds]
Feb 16 22:13:02.000 [notice] {NET} The current consensus has no exit nodes. Tor can only build internal paths, such as paths to hidden services.
Feb 16 22:13:02.000 [warn] {NET} We need more descriptors: we have 0/7082, and can only build 59% of likely paths. (We have 77% of guards bw, 77% of midpoint bw, and 100% of exit bw (no exits in consensus) = 59% of path bw.)
Feb 16 22:14:03.000 [warn] {NET} We need more descriptors: we have 0/7082, and can only build 59% of likely paths. (We have 77% of guards bw, 77% of midpoint bw, and 100% of exit bw (no exits in consensus) = 59% of path bw.)
At least the cached consensus seems to be fine:
_tor@onion1:~ % grep -c "s Exit" /var/db/tor/cached-consensus
1154
The debug log also shows:
_tor@onion1:~ % grep mmap /var/log/tor/debug.log
Feb 15 12:41:01.000 [info] tor_mmap_t *tor_mmap_file(const char *)(): Could not open "/var/db/tor/cached-microdescs" for mmap(): No such file or directory
Feb 15 12:41:01.000 [info] tor_mmap_t *tor_mmap_file(const char *)(): Could not open "/var/db/tor/cached-extrainfo" for mmap(): No such file or directory
These files indeed do not exist but Tor could create them:
_tor@onion1:~ % ls -ld /var/db/tor/
drwx------ 4 _tor _tor 11 Feb 17 11:51 /var/db/tor/
_tor@onion1:~ % ls -l /var/db/tor/
total 1151
-rw------- 1 _tor _tor 20441 Feb 11 15:10 cached-certs
-rw------- 1 _tor _tor 1587237 Feb 17 11:51 cached-consensus
-rw------- 1 _tor _tor 20879 Feb 17 11:50 cached-descriptors
-rw------- 1 _tor _tor 0 Feb 17 11:50 cached-descriptors.new
-rw------- 1 _tor _tor 58 Jan 6 16:47 fingerprint
drwx------ 2 _tor _tor 7 Feb 10 16:47 keys
-rw------- 1 _tor _tor 0 Feb 15 12:41 lock
-rw------- 1 _tor _tor 5008 Feb 17 01:51 state
drwx------ 2 _tor _tor 3 Feb 16 12:41 stats
The problem seems to be reproducible and I can provide additional log excerpts upon request.
As far as I can tell Tor is relaying traffic as expected.
My impression is that the complaints are a side-effect of 55ad54e0 which fixed legacy/trac#13718 (moved), but I haven't really looked into this yet.