I manage the two following exit relays:
They are both on the same IP and servers. A few hours ago they lost contact even though I have both Apache and I2P servers on the same machine that are reachable. The weird log messages seem to go back to Dec 18, after a restart:
Dec 18 07:49:47 a-n-o-n-y-m-e Tor-Alberta[904715]: Bootstrapped 100% (done): Done
Dec 18 07:54:18 a-n-o-n-y-m-e Tor-Alberta[904715]: Your computer is too slow to handle this many circuit creation requests! Please consider using the MaxAdvertisedBandwidth config option or choosing a more restricted exit policy.
Dec 18 07:57:11 a-n-o-n-y-m-e Tor-Alberta[904715]: Your computer is too slow to handle this many circuit creation requests! Please consider using the MaxAdvertisedBandwidth config option or choosing a more restricted exit policy. [14254 similar message(s) suppressed in last 180 seconds]
There are a few more of these messages appearing afterward (My bandwidth is unlimited). This is the typical Heartbeat that comes afterward:
Dec 18 13:49:42 a-n-o-n-y-m-e Tor-Alberta[904715]: Heartbeat: Tor's uptime is 6:00 hours, with 476 circuits open. I've sent 30.87 GB and received 9.04 GB. I've received 13401 connections on IPv4 and 0 on IPv6. I've made 46754 connections with IPv4 and 0 with IPv6.
Dec 18 13:49:42 a-n-o-n-y-m-e Tor-Alberta[904715]: While not bootstrapping, fetched this many bytes: 6412201 (server descriptor fetch); 1424 (server descriptor upload); 376002 (consensus network-status fetch); 57564 (microdescriptor fetch)
Dec 18 13:49:42 a-n-o-n-y-m-e Tor-Alberta[904715]: Circuit handshake stats since last time: 8/8 TAP, 1356688/6457307 NTor.
Dec 18 13:49:42 a-n-o-n-y-m-e Tor-Alberta[904715]: Since startup we initiated 0 and received 0 v1 connections; initiated 0 and received 0 v2 connections; initiated 0 and received 0 v3 connections; initiated 0 and received 429 v4 connections; initiated 285 and received 11137 v5 connections.
Dec 18 13:49:42 a-n-o-n-y-m-e Tor-Alberta[904715]: Heartbeat: DoS mitigation since startup: 0 circuits killed with too many cells, 0 circuits rejected, 0 marked addresses, 0 marked addresses for max queue, 0 same address concurrent connections rejected, 0 connections rejected, 0 single hop clients refused, 0 INTRODUCE2 rejected.
Then I have this kind of message appearing:
Dec 18 14:13:23 a-n-o-n-y-m-e Tor-Alberta[904715]: No circuits are opened. Relaxed timeout for circuit 4487 (a Measuring circuit timeout 3-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. [4 similar message(s) suppressed in last 3300 seconds]
Then a few days later, this bug report:
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: tor_bug_occurred_(): Bug: ../src/core/or/conflux.c:567: conflux_pick_first_leg: Non-fatal assertion !(smartlist_len(cfx->legs) <= 0) failed. (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: Tor 0.4.8.10: Non-fatal assertion !(smartlist_len(cfx->legs) <= 0) failed in conflux_pick_first_leg at ../src/core/or/conflux.c:567. Stack trace: (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(log_backtrace_impl+0x5b) [0x55651f95b37b] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(tor_bug_occurred_+0x18a) [0x55651f97294a] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(conflux_decide_next_circ+0x40e) [0x55651fa12afe] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(circuit_get_package_window+0x75) [0x55651fa12ec5] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(+0x9ed63) [0x55651f908d63] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(connection_edge_package_raw_inbuf+0xae) [0x55651f90b80e] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(connection_edge_process_inbuf+0x6f) [0x55651fa2b9df] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(+0x1c2fb4) [0x55651fa2cfb4] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(+0x73ffc) [0x55651f8ddffc] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /lib/x86_64-linux-gnu/libevent-2.1.so.7(+0x1ff58) [0x7fcee899bf58] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /lib/x86_64-linux-gnu/libevent-2.1.so.7(event_base_loop+0x577) [0x7fcee899d8a7] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(do_main_loop+0x127) [0x55651f8de7c7] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(tor_run_main+0x215) [0x55651f8e2805] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(tor_main+0x4d) [0x55651f8e2c6d] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(main+0x1d) [0x55651f8d4dcd] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /lib/x86_64-linux-gnu/libc.so.6(+0x29d90) [0x7fcee80a8d90] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x80) [0x7fcee80a8e40] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(_start+0x25) [0x55651f8d4e25] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: conflux_pick_first_leg(): Bug: Matching client sets: (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: conflux_log_set(): Bug: Conflux 566550141B144136: 0 linked, 0 launched. Delivered: 75; teardown: 0; Current: (nil), Previous: (nil) (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: conflux_pick_first_leg(): Bug: Matching server sets: (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: conflux_log_set(): Bug: Conflux 566550141B144136: 0 linked, 0 launched. Delivered: 75; teardown: 0; Current: (nil), Previous: (nil) (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: conflux_pick_first_leg(): Bug: End conflux set dump (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: circuit_get_package_window(): Bug: Conflux has no circuit to send on. Circuit 0x556536e76c20 idx 138 marked at line ../src/core/or/command.c:663 (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: tor_bug_occurred_(): Bug: ../src/core/or/conflux.c:567: conflux_pick_first_leg: Non-fatal assertion !(smartlist_len(cfx->legs) <= 0) failed. (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: Tor 0.4.8.10: Non-fatal assertion !(smartlist_len(cfx->legs) <= 0) failed in conflux_pick_first_leg at ../src/core/or/conflux.c:567. Stack trace: (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(log_backtrace_impl+0x5b) [0x55651f95b37b] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(tor_bug_occurred_+0x18a) [0x55651f97294a] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(conflux_decide_next_circ+0x40e) [0x55651fa12afe] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(circuit_get_package_window+0x75) [0x55651fa12ec5] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(+0x9ed63) [0x55651f908d63] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(connection_edge_package_raw_inbuf+0xae) [0x55651f90b80e] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(connection_edge_process_inbuf+0x6f) [0x55651fa2b9df] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(+0x1c34dd) [0x55651fa2d4dd] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(+0x73ffc) [0x55651f8ddffc] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /lib/x86_64-linux-gnu/libevent-2.1.so.7(+0x1ff58) [0x7fcee899bf58] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /lib/x86_64-linux-gnu/libevent-2.1.so.7(event_base_loop+0x577) [0x7fcee899d8a7] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(do_main_loop+0x127) [0x55651f8de7c7] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(tor_run_main+0x215) [0x55651f8e2805] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(tor_main+0x4d) [0x55651f8e2c6d] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(main+0x1d) [0x55651f8d4dcd] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /lib/x86_64-linux-gnu/libc.so.6(+0x29d90) [0x7fcee80a8d90] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x80) [0x7fcee80a8e40] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: Bug: /usr/bin/tor(_start+0x25) [0x55651f8d4e25] (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: conflux_pick_first_leg(): Bug: Matching client sets: (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: conflux_log_set(): Bug: Conflux 566550141B144136: 0 linked, 0 launched. Delivered: 75; teardown: 0; Current: (nil), Previous: (nil) (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: conflux_pick_first_leg(): Bug: Matching server sets: (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: conflux_log_set(): Bug: Conflux 566550141B144136: 0 linked, 0 launched. Delivered: 75; teardown: 0; Current: (nil), Previous: (nil) (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: conflux_pick_first_leg(): Bug: End conflux set dump (on Tor 0.4.8.10 )
Dec 21 15:18:48 a-n-o-n-y-m-e Tor-Alberta[904715]: circuit_get_package_window(): Bug: Conflux has no circuit to send on. Circuit 0x556536e76c20 idx 138 marked at line ../src/core/or/command.c:663 (on Tor 0.4.8.10 )
It is then an alternation of these three last messages (Heartbeat + "No circuits are opened" + bug) until yesterday where I get a series of these messages:
Jan 5 21:58:59 a-n-o-n-y-m-e Tor-Alberta[904715]: Failed to find node for hop #1 of our path. Discarding this circuit.
Jan 5 21:58:59 a-n-o-n-y-m-e Tor-Alberta[904715]: Our circuit 0 (id: 355722) died due to an invalid selected path, purpose Unlinked conflux circuit. This may be a torrc configuration issue, or a bug.
At this point, I learned that my relays were down via Tor Weather.
I restarted the relays - even rebooted the whole server - and both relays seem to be unable to connect to the network. Here's a sample:
Jan 6 09:44:46 a-n-o-n-y-m-e Tor-Alberta[5621]: 254 connections have failed:
Jan 6 09:44:46 a-n-o-n-y-m-e Tor-Alberta[5621]: 254 connections died in state connect()ing with SSL state (No SSL object)
Jan 6 09:44:46 a-n-o-n-y-m-e Tor-Alberta[5621]: Problem bootstrapping. Stuck at 5% (conn): Connecting to a relay. (Connection timed out; TIMEOUT; count 256; recommendation warn; host 65369D044C659CD299E35763914FFD0FC9AD4509 at 92.205.161.164:80)
I also have a bridge on this server (different IP) and it seems OK ( Relay Search ). Last messages after the server reboot are:
Jan 6 08:34:17 a-n-o-n-y-m-e Tor-Nestor[998]: Bootstrapped 100% (done): Done
Jan 6 08:35:21 a-n-o-n-y-m-e Tor-Nestor[998]: Performing bandwidth self-test...done.
Jan 6 09:54:22 a-n-o-n-y-m-e Tor-Nestor[998]: No circuits are opened. Relaxed timeout for circuit 527 (a Measuring circuit timeout 3-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway.
I have stopped both relays until I figure out what is going on. Help would be appreciated.