[tor-relays] Heartbeat: It seems like we are not in the cached consensus.

Fran fatal at mailbox.org
Tue Jul 28 20:33:41 UTC 2020


Hey,

thanks @Torix for the IPv6 suggestion, all auth were reachable via v6, but for testing I turned of IPv6 in the tor config - no change.

So today I found some time for a deeper investigation.
Let's have a look at the latest votes of some auths:

moria1:
> r systemli rGAdvbf71TRUBF7cCNrjw4HIz4g eSgH8PUcVufV4Cqvh18i49Kurio 2020-07-28 18:43:35 192.68.11.219 443 80
> s Exit Fast Guard Running Stable V2Dir Valid
> v Tor 0.4.3.5
> pr Cons=1-2 Desc=1-2 DirCache=1-2 HSDir=1-2 HSIntro=3-5 HSRend=1-2 Link=1-5 LinkAuth=1,3 Microdesc=1-2 Relay=1-2 Padding=2 FlowCtrl=1
> w Bandwidth=61 Measured=28400
> p accept 20-21,23,43,53,79-81,88,110,143,194,220,389,443,464-465,531,543-544,554,563,587,636,706,749,853,873,902-904,981,989-995,1194,1220,1293,1500,1533,1677,1723,1755,1863,2082-2083,2086-2087,2095-2096,2102-2104,3128,3389,3690,4321,4643,5050,5190,5222-5223,5228,5900,6660-6669,6679,6697,8000,8008,8074,8080,8082,8087-8088,8232-8233,8332-8333,8443,8888,9418,9999-10000,11371,19294,19638,50002,64738
> id ed25519 0RcV7ahmBl4wUd32bY5g0VrMHoFD8E9Zr+z8oAQGCZE
> m 28,29 sha256=YEKj/MKcRLSdfgZXz6DEwVizU5aAkr1d/9wBsCTjj3o

tor26:
> r systemli rGAdvbf71TRUBF7cCNrjw4HIz4g eSgH8PUcVufV4Cqvh18i49Kurio 2020-07-28 18:43:35 192.68.11.219 443 80
> s Exit Stable V2Dir Valid
> v Tor 0.4.3.5
> pr Cons=1-2 Desc=1-2 DirCache=1-2 HSDir=1-2 HSIntro=3-5 HSRend=1-2 Link=1-5 LinkAuth=1,3 Microdesc=1-2 Relay=1-2 Padding=2 FlowCtrl=1
> w Bandwidth=61
> p accept 20-21,23,43,53,79-81,88,110,143,194,220,389,443,464-465,531,543-544,554,563,587,636,706,749,853,873,902-904,981,989-995,1194,1220,1293,1500,1533,1677,1723,1755,1863,2082-2083,2086-2087,2095-2096,2102-2104,3128,3389,3690,4321,4643,5050,5190,5222-5223,5228,5900,6660-6669,6679,6697,8000,8008,8074,8080,8082,8087-8088,8232-8233,8332-8333,8443,8888,9418,9999-10000,11371,19294,19638,50002,64738
> id ed25519 0RcV7ahmBl4wUd32bY5g0VrMHoFD8E9Zr+z8oAQGCZE
> m 28,29 sha256=YEKj/MKcRLSdfgZXz6DEwVizU5aAkr1d/9wBsCTjj3o

dizum:
> r systemli rGAdvbf71TRUBF7cCNrjw4HIz4g eSgH8PUcVufV4Cqvh18i49Kurio 2020-07-28 18:43:35 192.68.11.219 443 80
> s Exit Stable V2Dir Valid
> v Tor 0.4.3.5
> pr Cons=1-2 Desc=1-2 DirCache=1-2 HSDir=1-2 HSIntro=3-5 HSRend=1-2 Link=1-5 LinkAuth=1,3 Microdesc=1-2 Relay=1-2 Padding=2 FlowCtrl=1
> w Bandwidth=61
> p accept 20-21,23,43,53,79-81,88,110,143,194,220,389,443,464-465,531,543-544,554,563,587,636,706,749,853,873,902-904,981,989-995,1194,1220,1293,1500,1533,1677,1723,1755,1863,2082-2083,2086-2087,2095-2096,2102-2104,3128,3389,3690,4321,4643,5050,5190,5222-5223,5228,5900,6660-6669,6679,6697,8000,8008,8074,8080,8082,8087-8088,8232-8233,8332-8333,8443,8888,9418,9999-10000,11371,19294,19638,50002,64738
> id ed25519 0RcV7ahmBl4wUd32bY5g0VrMHoFD8E9Zr+z8oAQGCZE
> m 28,29 sha256=YEKj/MKcRLSdfgZXz6DEwVizU5aAkr1d/9wBsCTjj3o
>
gablemoo:
> r systemli rGAdvbf71TRUBF7cCNrjw4HIz4g eSgH8PUcVufV4Cqvh18i49Kurio 2020-07-28 18:43:35 192.68.11.219 443 80
> s Exit Fast Stable V2Dir Valid
> v Tor 0.4.3.5
> pr Cons=1-2 Desc=1-2 DirCache=1-2 HSDir=1-2 HSIntro=3-5 HSRend=1-2 Link=1-5 LinkAuth=1,3 Microdesc=1-2 Relay=1-2 Padding=2 FlowCtrl=1
> w Bandwidth=61 Measured=27000
> p accept 20-21,23,43,53,79-81,88,110,143,194,220,389,443,464-465,531,543-544,554,563,587,636,706,749,853,873,902-904,981,989-995,1194,1220,1293,1500,1533,1677,1723,1755,1863,2082-2083,2086-2087,2095-2096,2102-2104,3128,3389,3690,4321,4643,5050,5190,5222-5223,5228,5900,6660-6669,6679,6697,8000,8008,8074,8080,8082,8087-8088,8232-8233,8332-8333,8443,8888,9418,9999-10000,11371,19294,19638,50002,64738
> id ed25519 0RcV7ahmBl4wUd32bY5g0VrMHoFD8E9Zr+z8oAQGCZE
> m 28,29 sha256=YEKj/MKcRLSdfgZXz6DEwVizU5aAkr1d/9wBsCTjj3o

maatuska:
> r systemli rGAdvbf71TRUBF7cCNrjw4HIz4g eSgH8PUcVufV4Cqvh18i49Kurio 2020-07-28 18:43:35 192.68.11.219 443 80
> s Exit Stable V2Dir Valid
> v Tor 0.4.3.5
> pr Cons=1-2 Desc=1-2 DirCache=1-2 HSDir=1-2 HSIntro=3-5 HSRend=1-2 Link=1-5 LinkAuth=1,3 Microdesc=1-2 Relay=1-2 Padding=2 FlowCtrl=1
> w Bandwidth=61
> p accept 20-21,23,43,53,79-81,88,110,143,194,220,389,443,464-465,531,543-544,554,563,587,636,706,749,853,873,902-904,981,989-995,1194,1220,1293,1500,1533,1677,1723,1755,1863,2082-2083,2086-2087,2095-2096,2102-2104,3128,3389,3690,4321,4643,5050,5190,5222-5223,5228,5900,6660-6669,6679,6697,8000,8008,8074,8080,8082,8087-8088,8232-8233,8332-8333,8443,8888,9418,9999-10000,11371,19294,19638,50002,64738
> id ed25519 0RcV7ahmBl4wUd32bY5g0VrMHoFD8E9Zr+z8oAQGCZE

faravahar:
> r systemli rGAdvbf71TRUBF7cCNrjw4HIz4g eSgH8PUcVufV4Cqvh18i49Kurio 2020-07-28 18:43:35 192.68.11.219 443 80
> s Exit Fast Guard Running Stable V2Dir Valid
> v Tor 0.4.3.5
> pr Cons=1-2 Desc=1-2 DirCache=1-2 HSDir=1-2 HSIntro=3-5 HSRend=1-2 Link=1-5 LinkAuth=1,3 Microdesc=1-2 Relay=1-2 Padding=2 FlowCtrl=1
> w Bandwidth=61 Measured=28400
> p accept 20-21,23,43,53,79-81,88,110,143,194,220,389,443,464-465,531,543-544,554,563,587,636,706,749,853,873,902-904,981,989-995,1194,1220,1293,1500,1533,1677,1723,1755,1863,2082-2083,2086-2087,2095-2096,2102-2104,3128,3389,3690,4321,4643,5050,5190,5222-5223,5228,5900,6660-6669,6679,6697,8000,8008,8074,8080,8082,8087-8088,8232-8233,8332-8333,8443,8888,9418,9999-10000,11371,19294,19638,50002,64738
> id ed25519 0RcV7ahmBl4wUd32bY5g0VrMHoFD8E9Zr+z8oAQGCZE
> m 28,29 sha256=YEKj/MKcRLSdfgZXz6DEwVizU5aAkr1d/9wBsCTjj3o

dannenberg:
> r systemli rGAdvbf71TRUBF7cCNrjw4HIz4g eSgH8PUcVufV4Cqvh18i49Kurio 2020-07-28 18:43:35 192.68.11.219 443 80
> s Exit Running Stable V2Dir Valid
> v Tor 0.4.3.5
> pr Cons=1-2 Desc=1-2 DirCache=1-2 HSDir=1-2 HSIntro=3-5 HSRend=1-2 Link=1-5 LinkAuth=1,3 Microdesc=1-2 Relay=1-2 Padding=2 FlowCtrl=1
> w Bandwidth=61
> p accept 20-21,23,43,53,79-81,88,110,143,194,220,389,443,464-465,531,543-544,554,563,587,636,706,749,853,873,902-904,981,989-995,1194,1220,1293,1500,1533,1677,1723,1755,1863,2082-2083,2086-2087,2095-2096,2102-2104,3128,3389,3690,4321,4643,5050,5190,5222-5223,5228,5900,6660-6669,6679,6697,8000,8008,8074,8080,8082,8087-8088,8232-8233,8332-8333,8443,8888,9418,9999-10000,11371,19294,19638,50002,64738
> id ed25519 0RcV7ahmBl4wUd32bY5g0VrMHoFD8E9Zr+z8oAQGCZE
> m 28,29 sha256=YEKj/MKcRLSdfgZXz6DEwVizU5aAkr1d/9wBsCTjj3o

So all auths find the node, all say its valid, only 2/7 say it's running. All 7 say the bandwith is 61 (config is RelayBandwidthRate 22 MBytes and RelayBandwidthBurst 23 MBytes) and only three auth
servers show a measured bandwidth.

Lates log lines:

Jul 28 20:42:10.000 [notice] Heartbeat: It seems like we are not in the cached consensus.
Jul 28 20:42:10.000 [notice] Heartbeat: Tor's uptime is 1 day 0:00 hours, with 0 circuits open. I've sent 3.99 MB and received 17.08 MB.
Jul 28 20:42:10.000 [notice] Average packaged cell fullness: 12.249%. TLS write overhead: 51%
Jul 28 20:42:10.000 [notice] Circuit handshake stats since last time: 0/0 TAP, 4/4 NTor.
Jul 28 20:42:10.000 [notice] Since startup we initiated 0 and received 345 v1 connections; initiated 0 and received 0 v2 connections; initiated 0 and received 1 v3 connections; initiated 0 and
received 3 v4 connections; initiated 27 and received 279 v5 connections.
Jul 28 20:42:10.000 [notice] DoS mitigation since startup: 0 circuits killed with too many cells. 0 circuits rejected, 0 marked addresses. 0 connections closed. 0 single hop clients refused. 0
INTRODUCE2 rejected.

Log excerpts from debug mode:

Jul 28 22:26:59.000 [debug] channel_free_: Freeing channel 81 at 0x1e5230589800
Jul 28 22:26:59.000 [debug] scheduler_set_channel_state: chan 81 changed from scheduler state IDLE to IDLE
Jul 28 22:26:59.000 [debug] channel_clear_remote_end: Clearing remote endpoint identity on channel 0x1e5230589800 with global ID 81
Jul 28 22:26:59.000 [debug] circuitmux_free_: Freeing cmux at 0x1e5246edf780 with no queued destroys, the cmux destroy balance was 0, global is 0
Jul 28 22:26:59.000 [debug] conn_read_callback: socket 15 wants to read.
Jul 28 22:26:59.000 [debug] connection_buf_read_from_socket: 15: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448.
Jul 28 22:26:59.000 [debug] TLS error: unexpected close while reading (SSL negotiation finished successfully)
Jul 28 22:26:59.000 [debug] tor_tls_read: read returned r=0, err=-8
Jul 28 22:26:59.000 [debug] connection_buf_read_from_socket: TLS connection closed on read. Closing. (Nickname Faravahar, address 154.35.175.225)
Jul 28 22:26:59.000 [debug] channel_close_for_error: Closing channel 0x1e527e25a400 due to lower-layer error
Jul 28 22:26:59.000 [debug] channel_change_state_: Changing state of channel 0x1e527e25a400 (global ID 80) from "open" to "closing"
Jul 28 22:26:59.000 [debug] channel_remove_from_digest_map: Removed channel 0x1e527e25a400 (global ID 80) from identity map in state closing (4) with digest CF6D0AAFB385BE71B8E111FC5CFF4B47923733BC
Jul 28 22:26:59.000 [debug] scheduler_set_channel_state: chan 80 changed from scheduler state WAITING_FOR_CELLS to IDLE
Jul 28 22:26:59.000 [debug] connection_mark_for_close_internal_: Calling connection_mark_for_close_internal_() on an OR conn at src/core/mainloop/connection.c:3723
Jul 28 22:26:59.000 [debug] conn_close_if_marked: Cleaning up connection (fd -1).
Jul 28 22:26:59.000 [debug] channel_change_state_: Changing state of channel 0x1e527e25a400 (global ID 80) from "closing" to "channel error"
Jul 28 22:26:59.000 [debug] scheduler_set_channel_state: chan 80 changed from scheduler state IDLE to IDLE
Jul 28 22:26:59.000 [debug] dispatch_send_msg_unchecked: Queued: orconn_status (<gid=108 status=3 reason=7>) from orconn_event, on orconn.
Jul 28 22:26:59.000 [debug] dispatcher_run_msg_cbs: Delivering: orconn_status (<gid=108 status=3 reason=7>) from orconn_event, on orconn:
Jul 28 22:26:59.000 [debug] dispatcher_run_msg_cbs:   Delivering to btrack.
Jul 28 22:26:59.000 [info] bto_status_rcvr: ORCONN DELETE gid=108 status=3 reason=7
[...]
Jul 28 22:28:28.000 [debug] connection_buf_read_from_socket: 12: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448.
Jul 28 22:28:28.000 [debug] connection_buf_read_from_socket: After TLS read of 514: 543 read, 0 written
Jul 28 22:28:28.000 [debug] connection_or_process_cells_from_inbuf: 12: starting, inbuf_datalen 514 (0 pending in tls object).
Jul 28 22:28:28.000 [debug] connection_or_process_cells_from_inbuf: 12: starting, inbuf_datalen 0 (0 pending in tls object).
Jul 28 22:28:29.000 [debug] circuit_remove_handled_ports: Port 443 is already being handled; removing.
Jul 28 22:28:29.000 [debug] circuit_remove_handled_ports: Port 80 is already being handled; removing.


Anyone any ideas?

Thanks,

Fran



On 24.07.20 17:13, torix at protonmail.com wrote:
> Dear Fran,
> 
> I now see no entry at all to your relay in the tor metrics.  Am I correct in saying that you are running ipv6 as well as 4?  I have had problems with a host's ipv6 connectivity and discovered somewhere in the docs a ping6 test of all the bwauths you might try:
> 
> ing6 -c2 2001:858:2:2:aabb:0:563b:1526 && ping6 -c2 2620:13:4000:6000::1000:118 && ping6 -c2 2001:67c:289c::9 && ping6 -c2 2001:678:558:1000::244 && ping6 -c2 2607:8500:154::3 && ping6 -c2 2001:638:a000:4140::ffff:189 && echo OK.
> 
> HTH,
> 
> --Torix
> 
> Sent with ProtonMail Secure Email.
> 
> ‐‐‐‐‐‐‐ Original Message ‐‐‐‐‐‐‐
> On Tuesday, July 21, 2020 12:45 PM, Fran <fatal at mailbox.org> wrote:
> 
>> Hey,
>>
>> the problem persists. upgraded to several new daily snapshots of openbsd in between, no success.
>>
>> On 20.07.20 08:30, Keifer Bly wrote:
>>
>>> It is worth noting, tor conscious does not immediately update. It can take 40 minutes up to about 3 hours for an operating status update to appear in the conscious based on my experience from the
>>> bridge and middle relay I run.
>>
>> the relay had been up for > 17 hours (see log excerpt)
>>
>>>>> Your relay has a very large number of connections to other relays. Is your outbound address the same as your relay address? Found 9 connections to 6 relays. Found 4
>>>
>>> What do you mean No FW on the machine?
>>
>> no firewall
>>
>>> You need to configure port forwarding on the network for the specific machine / ip address the relay is running on, for both inbound and outbound traffic.
>>
>> the machine has it's own global unicast ipv4 and ipv6 addresses.
>>
>> best
>>
>> fran
>>
>>> On Sat, Jul 18, 2020 at 9:40 PM Fran <fatal at mailbox.org mailto:fatal at mailbox.org> wrote:
>>>
>>>     Hello,
>>>
>>>     I'm taking care of a server of a friend who's on holiday. The server is up and running but not part of the consensus.
>>>
>>>     As beeing instructed I updated to the lastest OpenBSD snapshot when I saw that a new tor release is available  (Tor 0.4.3.5 on OpenBSD).
>>>
>>>     Excerpts from the log:
>>>
>>>     Jul 13 20:04:02.000 [notice] Self-testing indicates your DirPort is reachable from the outside. Excellent.
>>>     Jul 13 20:05:02.000 [notice] Self-testing indicates your ORPort is reachable from the outside. Excellent. Publishing server descriptor.
>>>     Jul 13 20:05:35.000 [notice] Performing bandwidth self-test...done.
>>>     Jul 14 02:04:01.000 [notice] Heartbeat: It seems like we are not in the cached consensus.
>>>     Jul 14 02:04:01.000 [notice] Heartbeat: Tor's uptime is 6:00 hours, with 0 circuits open. I've sent 2.04 MB and received 6.25 MB.
>>>     Jul 14 02:04:01.000 [notice] Average packaged cell fullness: 12.450%. TLS write overhead: 33%
>>>     Jul 14 02:04:01.000 [notice] Circuit handshake stats since last time: 0/0 TAP, 5/5 NTor.
>>>     Jul 14 02:04:01.000 [notice] Since startup we initiated 0 and received 157 v1 connections; initiated 0 and received 0 v2 connections; initiated 0 and received 0 v3 connections; initiated 0 and
>>>     received 5 v4 connections; initiated 48 and received 124 v5 connections.
>>>     Jul 14 02:04:01.000 [notice] DoS mitigation since startup: 0 circuits killed with too many cells. 0 circuits rejected, 0 marked addresses. 0 connections closed. 0 single hop clients refused. 0
>>>     INTRODUCE2 rejected.
>>>     Jul 14 06:04:02.000 [notice] Your relay has a very large number of connections to other relays. Is your outbound address the same as your relay address? Found 9 connections to 6 relays. Found 4
>>>     current canonical connections, in 0 of which we were a non-canonical peer. 3 relays had more than 1 connection, 0 had more than 2, and 0 had more than 4 connections.
>>>     Jul 14 08:04:01.000 [notice] Heartbeat: It seems like we are not in the cached consensus.
>>>     Jul 14 08:04:01.000 [notice] Heartbeat: Tor's uptime is 12:00 hours, with 1 circuits open. I've sent 3.46 MB and received 11.22 MB.
>>>     Jul 14 08:04:01.000 [notice] Average packaged cell fullness: 12.450%. TLS write overhead: 47%
>>>     Jul 14 08:04:01.000 [notice] Circuit handshake stats since last time: 2/2 TAP, 1/1 NTor.
>>>     Jul 14 08:04:01.000 [notice] Since startup we initiated 0 and received 340 v1 connections; initiated 0 and received 0 v2 connections; initiated 0 and received 0 v3 connections; initiated 0 and
>>>     received 10 v4 connections; initiated 57 and received 246 v5 connections.
>>>     Jul 14 08:04:01.000 [notice] DoS mitigation since startup: 0 circuits killed with too many cells. 0 circuits rejected, 0 marked addresses. 0 connections closed. 0 single hop clients refused. 0
>>>     INTRODUCE2 rejected.
>>>     Jul 14 14:04:01.000 [notice] Heartbeat: It seems like we are not in the cached consensus.
>>>     Jul 14 14:04:01.000 [notice] Heartbeat: Tor's uptime is 18:00 hours, with 1 circuits open. I've sent 4.89 MB and received 15.33 MB.
>>>     Jul 14 14:04:01.000 [notice] Average packaged cell fullness: 26.760%. TLS write overhead: 51%
>>>     Jul 14 14:04:01.000 [notice] Circuit handshake stats since last time: 2/2 TAP, 6/6 NTor.
>>>     Jul 14 14:04:01.000 [notice] Since startup we initiated 0 and received 493 v1 connections; initiated 0 and received 0 v2 connections; initiated 0 and received 0 v3 connections; initiated 0 and
>>>     received 18 v4 connections; initiated 64 and received 370 v5 connections.
>>>     Jul 14 14:04:01.000 [notice] DoS mitigation since startup: 0 circuits killed with too many cells. 0 circuits rejected, 0 marked addresses. 0 connections closed. 0 single hop clients refused. 0
>>>     INTRODUCE2 rejected.
>>>
>>>
>>>     Atlas show the server as down: https://metrics.torproject.org/rs.html#details/AC601DBDB7FBD53454045EDC08DAE3C381C8CF88
>>>
>>>     Accessing the status page on port 80 works.
>>>     No FW on the machine.
>>>
>>>     Any ideas?
>>>
>>>     Thanks and regards
>>>
>>>     Fran
>>>     _______________________________________________
>>>     tor-relays mailing list
>>>     tor-relays at lists.torproject.org <mailto:tor-relays at lists.torproject.org>
>>>     https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-relays
>>>
>>>
>>> tor-relays mailing list
>>> tor-relays at lists.torproject.org
>>> https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-relays
>>
>> tor-relays mailing list
>> tor-relays at lists.torproject.org
>> https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-relays
> 
> 
> _______________________________________________
> tor-relays mailing list
> tor-relays at lists.torproject.org
> https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-relays
> 


More information about the tor-relays mailing list