Opened 3 years ago

Last modified 2 years ago

#21297 new defect

Hidden service unavailable.

Reported by: weasel Owned by:
Priority: Medium Milestone: Tor: unspecified
Component: Core Tor/Tor Version: Tor: 0.2.9.8
Severity: Normal Keywords: tor-hs needs-insight needs-analysis
Cc: asn Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

I have a Tor 0.2.9.8 that provides 2 hidden services. It's been running for about 3 days now, and now the hidden service appears to no longer be reachable (cf. #21296).

weasel@vineale:~$ zgrep Tor /var/log/syslog.1.gz /var/log/syslog -h
Jan 23 08:01:07 s_local@vineale Tor[26073]: Heartbeat: Tor's uptime is 2 days 11:52 hours, with 65 circuits open. I've sent 12.54 GB and received 6.87 GB.
Jan 23 08:01:07 s_local@vineale Tor[26073]: Average packaged cell fullness: 46.879%. TLS write overhead: 3%
Jan 23 08:19:23 s_local@vineale Tor[26073]: No circuits are opened. Relaxed timeout for circuit 772577 (a Hidden service: Establishing introduction point 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. 17 guards are live. [1 similar message(s) suppressed in last 3600 seconds]
Jan 23 09:52:52 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 23 11:17:01 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 23 11:29:30 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 23 11:40:04 s_local@vineale Tor[26073]: No circuits are opened. Relaxed timeout for circuit 772843 (a Hidden service: Establishing introduction point 3-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. 17 guards are live.
Jan 23 11:41:39 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 23 11:41:41 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 23 11:53:54 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 23 12:05:44 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 23 12:31:04 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 23 12:31:44 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 23 12:31:46 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 23 12:31:50 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 23 14:01:07 s_local@vineale Tor[26073]: Heartbeat: Tor's uptime is 2 days 17:52 hours, with 70 circuits open. I've sent 12.54 GB and received 6.87 GB.
Jan 23 14:01:07 s_local@vineale Tor[26073]: Average packaged cell fullness: 46.880%. TLS write overhead: 3%
Jan 23 15:46:35 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 23 20:01:07 s_local@vineale Tor[26073]: Heartbeat: Tor's uptime is 2 days 23:52 hours, with 66 circuits open. I've sent 12.54 GB and received 6.88 GB.
Jan 23 20:01:07 s_local@vineale Tor[26073]: Average packaged cell fullness: 46.880%. TLS write overhead: 3%
Jan 23 20:08:54 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 23 23:17:51 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 23 23:31:41 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 23 23:43:03 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 24 00:06:08 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 24 00:30:34 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 24 00:30:38 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 24 00:30:40 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 24 00:57:42 s_local@vineale Tor[26073]: No circuits are opened. Relaxed timeout for circuit 773874 (a Hidden service: Establishing introduction point 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. 17 guards are live. [1 similar message(s) suppressed in last 3600 seconds]
Jan 24 01:13:21 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 24 01:24:48 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 24 01:36:15 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 24 02:01:07 s_local@vineale Tor[26073]: Heartbeat: Tor's uptime is 3 days 5:52 hours, with 69 circuits open. I've sent 12.54 GB and received 6.88 GB.
Jan 24 02:01:07 s_local@vineale Tor[26073]: Average packaged cell fullness: 46.881%. TLS write overhead: 3%
Jan 24 03:49:17 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.
Jan 24 05:18:34 s_local@vineale Tor[26073]: No circuits are opened. Relaxed timeout for circuit 774201 (a Hidden service: Establishing introduction point 4-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. 17 guards are live. [2 similar message(s) suppressed in last 3600 seconds]
Jan 24 06:50:51 s_local@vineale Tor[26073]: connection_edge_process_relay_cell (at origin) failed.

Any idea what's up here?

Child Tickets

Change History (8)

comment:1 Changed 3 years ago by asn

Cc: asn added

Ugh that's weird but not enough info in the logs. Debug/info logs would help.

comment:2 Changed 3 years ago by dgoulet

Keywords: tor-hs added
Milestone: Tor: 0.3.0.x-final

This line doesn't seems very good... Seems the IP circuit were stuck in "handshake" state and timed out... Network issue on the machine? And yes, debug logs would be desirable if possible.

Jan 23 11:40:04 s_local@vineale Tor[26073]: No circuits are opened. Relaxed timeout for circuit 772843 (a Hidden service: Establishing introduction point 3-hop circuit in state doing handshakes with channel state open) to 60000ms. However, it appears the circuit has timed out anyway. 17 guards are live.

comment:3 Changed 3 years ago by weasel

https://volatile.noreply.org/2017-01-24-qHp2UqVNHZE/log has info level logs now. Good enough or do we need more?

comment:4 Changed 3 years ago by weasel

https://volatile.noreply.org/2017-01-24-xCjU30EM40I/log has some debug level logs near its end

comment:5 Changed 3 years ago by dgoulet

Still a mystery but I've opened #21302 which lists a few issues we currently have that may be part of the problem here.

comment:6 Changed 3 years ago by dgoulet

Milestone: Tor: 0.3.0.x-finalTor: unspecified

comment:7 Changed 3 years ago by teor

Also see #21446 and children for even more issues that might be related.

comment:8 Changed 2 years ago by nickm

Keywords: needs-insight needs-analysis added
Note: See TracTickets for help on using tickets.