Frequent htpdate failure in local test suite run
I regularly see htpdate failing when I run the test suite on my laptop. I understand @anonym and @boyska have seen similar problems. Interestingly, we don't see this on Jenkins.
Last time it happened I took a look and it was clear that DNS resolution was the problem (tor-resolve
would not resolve anything). Here's what I see in the Journal:
Aug 17 07:47:47.000 [notice] Bootstrapped 5% (conn): Connecting to a relay
Aug 17 07:47:47.000 [notice] Bootstrapped 10% (conn_done): Connected to a relay
Aug 17 07:47:47.000 [notice] Bootstrapped 14% (handshake): Handshaking with a relay
Aug 17 07:47:47.000 [notice] Bootstrapped 15% (handshake_done): Handshake with a relay done
Aug 17 07:47:47.000 [notice] Bootstrapped 20% (onehop_create): Establishing an encrypted directory connection
Aug 17 07:47:47.000 [notice] Bootstrapped 25% (requesting_status): Asking for networkstatus consensus
Aug 17 07:47:47.000 [notice] Bootstrapped 30% (loading_status): Loading networkstatus consensus
Aug 17 07:47:47.000 [notice] I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
Aug 17 07:47:47.000 [notice] Bootstrapped 40% (loading_keys): Loading authority key certs
Aug 17 07:47:47.000 [notice] The current consensus has no exit nodes. Tor can only build internal paths, such as paths to onion services.
Aug 17 07:47:47.000 [notice] Bootstrapped 45% (requesting_descriptors): Asking for relay descriptors
Aug 17 07:47:47.000 [notice] I learned some more directory information, but not enough to build a circuit: We need more microdescriptors: we have 0/20, and can only build 0% of likely paths. (We have 0% of guards bw, 0% of midpoint bw, and 0% of end bw (no exits in consensus, using mid) = 0% of path bw.)
Aug 17 07:47:47.000 [notice] Bootstrapped 50% (loading_descriptors): Loading relay descriptors
Aug 17 07:47:48.000 [notice] Bootstrapped 75% (enough_dirinfo): Loaded enough directory info to build circuits
Aug 17 07:47:48.000 [notice] New control connection opened from 127.0.0.1.
Aug 17 07:47:48.000 [notice] New control connection opened from 127.0.0.1.
Aug 17 07:47:48.000 [notice] New control connection opened from 127.0.0.1.
Aug 17 07:47:48.000 [notice] Bootstrapped 80% (ap_conn): Connecting to a relay to build circuits
Aug 17 07:47:48.000 [notice] Bootstrapped 85% (ap_conn_done): Connected to a relay to build circuits
Aug 17 07:47:48.000 [notice] Bootstrapped 89% (ap_handshake): Finishing handshake with a relay to build circuits
Aug 17 07:47:48.000 [notice] Bootstrapped 90% (ap_handshake_done): Handshake finished with a relay to build circuits
Aug 17 07:47:48.000 [notice] Bootstrapped 95% (circuit_create): Establishing a Tor circuit
Aug 17 07:47:48.000 [notice] Bootstrapped 100% (done): Done
Aug 17 07:47:49.000 [notice] New control connection opened from 127.0.0.1.
Aug 17 07:47:49.000 [notice] New control connection opened from 127.0.0.1.
Aug 17 07:47:49.000 [notice] Application request when we haven't received a consensus with exits. Optimistically trying directory fetches again.
[Dozens of the above notice message per second]
Aug 17 07:49:50.000 [warn] Warning from libevent: Error Operation not permitted (1) while writing response to port; dropping
Aug 17 07:49:50.000 [warn] Warning from libevent: Error Operation not permitted (1) while writing response to port; dropping
Aug 17 07:49:50.000 [warn] Warning from libevent: Error Operation not permitted (1) while writing response to port; dropping
Aug 17 07:49:50.000 [warn] Warning from libevent: Error Operation not permitted (1) while writing response to port; dropping
Aug 17 07:49:50.000 [warn] Warning from libevent: Error Operation not permitted (1) while writing response to port; dropping
Aug 17 07:49:50.000 [warn] Warning from libevent: Error Operation not permitted (1) while writing response to port; dropping
[Tons more of the aforementioned notice message]
The libevent error comes from https://sources.debian.org/src/libevent/2.1.12-stable-1/evdns.c/?hl=1460#L1460.
But really the main problem seems to be that tor is confused: it's supposed to have bootstrapped, but then it tells us it has no exits.