#28962: circuits are not both ready. Stalling conn.
--------------------------+------------------------------------
Reporter: traumschule | Owner: (none)
Type: defect | Status: new
Priority: Medium | Milestone: Tor: 0.4.0.x-final
Component: Core Tor/Tor | Version:
Severity: Normal | Resolution:
Keywords: tor-hs | Actual Points:
Parent ID: | Points:
Reviewer: | Sponsor:
--------------------------+------------------------------------
Old description:
> My Tor 0.4.0.0-alpha-dev client shows {{{circuits are not both ready.
> Stalling conn.}}} and most connections hang for some minutes until it
> let‘s through a bunch and hangs again.
>
> It‘s confusing to see netflow padding while waiting for connections,
> looks like an instance of #23681. Maybe it just means that the guard is
> under load?
>
> Relevant code is around src/core/or/circuituse.c:3025.
> Log shows a lot of timeouts like:
> {{{
> Dec 30 10:48:14.000 [info] circuit_build_times_get_xm(): Xm mode #0: 325
> 75
> Dec 30 10:48:14.000 [info] circuit_build_times_get_xm(): Xm mode #1: 375
> 47
> Dec 30 10:48:14.000 [info] circuit_build_times_get_xm(): Xm mode #2: 325
> 75
> Dec 30 10:48:14.000 [info] circuit_build_times_set_timeout_worker():
> Circuit build measurement period of 1337373ms is more than twice the
> maximum build time we have ever observed. Capping it to 1143450ms.
> Dec 30 10:48:14.000 [info] circuit_build_times_set_timeout(): Set circuit
> build timeout to 29s (28864.874645ms, 1143450.000000ms, Xm: 336, a:
> 0.361406, r: 0.282000) based on 1000 circuit times
> Dec 30 10:48:14.000 [info] entry_guards_note_guard_success(): Recorded
> success for primary confirmed guard <scrubbed>
> Dec 30 10:48:14.000 [info] circuit_build_no_more_hops(): circuit built!
> Dec 30 10:48:14.000 [info] pathbias_count_build_success(): Got success
> count 209.532891/219.352138 for guard <scrubbed>
> Dec 30 10:48:14.000 [info] connection_ap_handshake_attach_circuit():
> Intro circ 4177057486 (id: 2028) present and awaiting ACK. Rend circuit
> 3511196698 (id: 2011). Stalling. (stream 41 sec old)
> Dec 30 10:48:14.000 [info] or_state_save(): Saved state to
> "/var/lib/tor/state"
> Dec 30 10:48:14.000 [info] rend_client_introduction_acked(): Got nack for
> [scrubbed] from [scrubbed]...
> Dec 30 10:48:14.000 [info] rend_client_report_intro_point_failure(): 5
> options left for [scrubbed].
> Dec 30 10:48:14.000 [info] hs_client_reextend_intro_circuit(): Re-
> extending circ 4177057486, this time to [scrubbed].
> Dec 30 10:48:14.000 [info] circuit_send_intermediate_onion_skin():
> Sending extend relay cell.
> Dec 30 10:48:14.000 [info] connection_ap_handshake_attach_circuit():
> ready rend circ 3511196698 (id: 2011) already here. Nointro-ack yet on
> intro 4177057486 (id: 2028). (stream 41 sec old)
> Dec 30 10:48:14.000 [info] connection_ap_handshake_attach_circuit():
> Intro 4177057486 (id: 2028) and rend circuit 3511196698 (id: 2011)
> circuits are not both ready. Stalling conn. (41 sec old)
> ...
> Dec 30 10:49:01.000 [info] connection_ap_handshake_attach_circuit():
> Intro 4177057486 (id: 2028) and rend circuit 3511196698 (id: 2011)
> circuits are not both ready. Stalling conn. (88 sec old)
> Dec 30 10:49:02.000 [info] connection_ap_handshake_attach_circuit():
> ready rend circ 3511196698 (id: 2011) already here. Nointro-ack yet on
> intro 4177057486 (id: 2028). (stream 89 sec old)
> Dec 30 10:49:02.000 [info] connection_ap_handshake_attach_circuit():
> Intro 4177057486 (id: 2028) and rend circuit 3511196698 (id: 2011)
> circuits are not both ready. Stalling conn. (89 sec old)
> Dec 30 10:49:03.000 [info] connection_ap_handshake_attach_circuit():
> ready rend circ 3511196698 (id: 2011) already here. Nointro-ack yet on
> intro 4177057486 (id: 2028). (stream 90 sec old)
> Dec 30 10:49:03.000 [info] connection_ap_handshake_attach_circuit():
> Intro 4177057486 (id: 2028) and rend circuit 3511196698 (id: 2011)
> circuits are not both ready. Stalling conn. (90 sec old)
> Dec 30 10:49:04.000 [info]
> channelpadding_send_padding_cell_for_callback(): Sending netflow
> keepalive on 608 to [scrubbed] ([scrubbed]) after 8689 ms. Delta 1ms
> Dec 30 10:49:04.000 [info] connection_ap_handshake_attach_circuit():
> ready rend circ 3511196698 (id: 2011) already here. Nointro-ack yet on
> intro 4177057486 (id: 2028). (stream 91 sec old)
> Dec 30 10:49:04.000 [info] connection_ap_handshake_attach_circuit():
> Intro 4177057486 (id: 2028) and rend circuit 3511196698 (id: 2011)
> circuits are not both ready. Stalling conn. (91 sec old)
> Dec 30 10:49:05.000 [info] connection_ap_handshake_attach_circuit():
> ready rend circ 3511196698 (id: 2011) already here. Nointro-ack yet on
> intro 4177057486 (id: 2028). (stream 92 sec old)
> Dec 30 10:49:05.000 [info] connection_ap_handshake_attach_circuit():
> Intro 4177057486 (id: 2028) and rend circuit 3511196698 (id: 2011)
> circuits are not both ready. Stalling conn. (92 sec old)
> Dec 30 10:49:07.000 [info] connection_ap_handshake_attach_circuit():
> ready rend circ 3511196698 (id: 2011) already here. Nointro-ack yet on
> intro 4177057486 (id: 2028). (stream 93 sec old)
> Dec 30 10:49:07.000 [info] connection_ap_handshake_attach_circuit():
> Intro 4177057486 (id: 2028) and rend circuit 3511196698 (id: 2011)
> circuits are not both ready. Stalling conn. (93 sec old)
> }}}
New description:
Using an unstable (wifi) connection my Tor 0.4.0.0-alpha-dev client shows
{{{circuits are not both ready. Stalling conn.}}} and most connections
hang for some minutes until it let‘s through a bunch and hangs again.
It‘s confusing to see netflow padding while waiting for connections, looks
like an instance of #23681.
Relevant code is around src/core/or/circuituse.c:3025.
Log shows a lot of timeouts like:
{{{
Dec 30 10:48:14.000 [info] circuit_build_times_get_xm(): Xm mode #0: 325
75
Dec 30 10:48:14.000 [info] circuit_build_times_get_xm(): Xm mode #1: 375
47
Dec 30 10:48:14.000 [info] circuit_build_times_get_xm(): Xm mode #2: 325
75
Dec 30 10:48:14.000 [info] circuit_build_times_set_timeout_worker():
Circuit build measurement period of 1337373ms is more than twice the
maximum build time we have ever observed. Capping it to 1143450ms.
Dec 30 10:48:14.000 [info] circuit_build_times_set_timeout(): Set circuit
build timeout to 29s (28864.874645ms, 1143450.000000ms, Xm: 336, a:
0.361406, r: 0.282000) based on 1000 circuit times
Dec 30 10:48:14.000 [info] entry_guards_note_guard_success(): Recorded
success for primary confirmed guard <scrubbed>
Dec 30 10:48:14.000 [info] circuit_build_no_more_hops(): circuit built!
Dec 30 10:48:14.000 [info] pathbias_count_build_success(): Got success
count 209.532891/219.352138 for guard <scrubbed>
Dec 30 10:48:14.000 [info] connection_ap_handshake_attach_circuit(): Intro
circ 4177057486 (id: 2028) present and awaiting ACK. Rend circuit
3511196698 (id: 2011). Stalling. (stream 41 sec old)
Dec 30 10:48:14.000 [info] or_state_save(): Saved state to
"/var/lib/tor/state"
Dec 30 10:48:14.000 [info] rend_client_introduction_acked(): Got nack for
[scrubbed] from [scrubbed]...
Dec 30 10:48:14.000 [info] rend_client_report_intro_point_failure(): 5
options left for [scrubbed].
Dec 30 10:48:14.000 [info] hs_client_reextend_intro_circuit(): Re-
extending circ 4177057486, this time to [scrubbed].
Dec 30 10:48:14.000 [info] circuit_send_intermediate_onion_skin(): Sending
extend relay cell.
Dec 30 10:48:14.000 [info] connection_ap_handshake_attach_circuit(): ready
rend circ 3511196698 (id: 2011) already here. Nointro-ack yet on intro
4177057486 (id: 2028). (stream 41 sec old)
Dec 30 10:48:14.000 [info] connection_ap_handshake_attach_circuit(): Intro
4177057486 (id: 2028) and rend circuit 3511196698 (id: 2011) circuits are
not both ready. Stalling conn. (41 sec old)
...
Dec 30 10:49:01.000 [info] connection_ap_handshake_attach_circuit(): Intro
4177057486 (id: 2028) and rend circuit 3511196698 (id: 2011) circuits are
not both ready. Stalling conn. (88 sec old)
Dec 30 10:49:02.000 [info] connection_ap_handshake_attach_circuit(): ready
rend circ 3511196698 (id: 2011) already here. Nointro-ack yet on intro
4177057486 (id: 2028). (stream 89 sec old)
Dec 30 10:49:02.000 [info] connection_ap_handshake_attach_circuit(): Intro
4177057486 (id: 2028) and rend circuit 3511196698 (id: 2011) circuits are
not both ready. Stalling conn. (89 sec old)
Dec 30 10:49:03.000 [info] connection_ap_handshake_attach_circuit(): ready
rend circ 3511196698 (id: 2011) already here. Nointro-ack yet on intro
4177057486 (id: 2028). (stream 90 sec old)
Dec 30 10:49:03.000 [info] connection_ap_handshake_attach_circuit(): Intro
4177057486 (id: 2028) and rend circuit 3511196698 (id: 2011) circuits are
not both ready. Stalling conn. (90 sec old)
Dec 30 10:49:04.000 [info]
channelpadding_send_padding_cell_for_callback(): Sending netflow keepalive
on 608 to [scrubbed] ([scrubbed]) after 8689 ms. Delta 1ms
Dec 30 10:49:04.000 [info] connection_ap_handshake_attach_circuit(): ready
rend circ 3511196698 (id: 2011) already here. Nointro-ack yet on intro
4177057486 (id: 2028). (stream 91 sec old)
Dec 30 10:49:04.000 [info] connection_ap_handshake_attach_circuit(): Intro
4177057486 (id: 2028) and rend circuit 3511196698 (id: 2011) circuits are
not both ready. Stalling conn. (91 sec old)
Dec 30 10:49:05.000 [info] connection_ap_handshake_attach_circuit(): ready
rend circ 3511196698 (id: 2011) already here. Nointro-ack yet on intro
4177057486 (id: 2028). (stream 92 sec old)
Dec 30 10:49:05.000 [info] connection_ap_handshake_attach_circuit(): Intro
4177057486 (id: 2028) and rend circuit 3511196698 (id: 2011) circuits are
not both ready. Stalling conn. (92 sec old)
Dec 30 10:49:07.000 [info] connection_ap_handshake_attach_circuit(): ready
rend circ 3511196698 (id: 2011) already here. Nointro-ack yet on intro
4177057486 (id: 2028). (stream 93 sec old)
Dec 30 10:49:07.000 [info] connection_ap_handshake_attach_circuit(): Intro
4177057486 (id: 2028) and rend circuit 3511196698 (id: 2011) circuits are
not both ready. Stalling conn. (93 sec old)
}}}
--
Comment (by traumschule):
Removing wrong assumption.
--
Ticket URL: <https://trac.torproject.org/projects/tor/ticket/28962#comment:3>
Tor Bug Tracker & Wiki <https://trac.torproject.org/>
The Tor Project: anonymity online
_______________________________________________
tor-bugs mailing list
tor-bugs@lists.torproject.org
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs
