GitLab

We have a branch bug15618_030-testing at https://gitweb.torproject.org/user/dgoulet/tor.git that logs a warning when we call more than 2 times circuit has_opened() on a circuit. The patch was made to confirm the theory on legacy/trac#15618 (moved) related to a warning we see on relays. While until now I never saw the warning on relay side, I see it quite often on client side.

Based on the log messages, I think this is related to introduction point circuits and not rendezvous circuits as we thought. Basically it happens when we open a 4 hop circuit with last hop X, and immediately we extend that circuit to a 5 hop one with last hop Y, where Y is (I think) the introduction point. I got the warning 2 times in a row and the similarity between them is that they are 5 hop circuits with the last two hops 4 and 5 the same, but different hops 2 and 3.

Dec 25 13:15:15.000 [info] internal circ (length 5, last hop $D7316BF7FD633DD7474B18C33E1D5FDEB04D26A7): $A7C411B809D0AA98C4264917BB701ABF17B2181E(open) $B5212DB685A2A0FCFBAE425738E478D12361710D(open) $123F403DA94A74F959B7FE0E5B27FA57EFA12925(open) $1F4105C688E835A56AF3D66C787677B57240FFA2(open) $D7316BF7FD633DD7474B18C33E1D5FDEB04D26A7(open)
Dec 25 13:15:15.000 [info] entry_guards_note_guard_success(): Recorded success for primary confirmed guard sakujakira ($A7C411B809D0AA98C4264917BB701ABF17B2181E)
Dec 25 13:15:15.000 [info] circuit_send_next_onion_skin(): circuit built!
Dec 25 13:15:15.000 [warn] BLAM. Circuit has_opened() called 3 times.
Dec 25 13:15:15.000 [info] rend_client_introcirc_has_opened(): introcirc is open
Dec 25 13:15:15.000 [info] connection_ap_handshake_attach_circuit(): pending-join circ 3419634369 already here, with intro ack. Stalling. (stream 26 sec old)
Dec 25 13:15:15.000 [info] connection_ap_handshake_attach_circuit(): ready rend circ 2404371907 already here (no intro-ack yet on intro 2259155742). (stream 26 sec old)
Dec 25 13:15:15.000 [info] connection_ap_handshake_attach_circuit(): found open intro circ 2259155742 (rend 2404371907); sending introduction. (stream 26 sec old)
Dec 25 13:15:15.000 [info] rend_client_send_introduction(): Sending an INTRODUCE1 cell
Dec 25 13:15:15.000 [info] pathbias_count_use_attempt(): Used circuit 53293 is already in path state use succeeded. Circuit is a Hidden service client: Pending rendezvous point currently open.

Dec 25 13:15:16.000 [info] internal circ (length 5, last hop $D7316BF7FD633DD7474B18C33E1D5FDEB04D26A7): $A7C411B809D0AA98C4264917BB701ABF17B2181E(open) $5C01D5518D1F5A071C6F07D1F4630F577AB5B60A(open) $DA9DA02A7B0565DF5F3E961CA911E750072DCBBD(open) $1F4105C688E835A56AF3D66C787677B57240FFA2(open) $D7316BF7FD633DD7474B18C33E1D5FDEB04D26A7(open)
Dec 25 13:15:16.000 [info] entry_guards_note_guard_success(): Recorded success for primary confirmed guard sakujakira ($A7C411B809D0AA98C4264917BB701ABF17B2181E)
Dec 25 13:15:16.000 [info] circuit_send_next_onion_skin(): circuit built!
Dec 25 13:15:16.000 [warn] BLAM. Circuit has_opened() called 3 times.
Dec 25 13:15:16.000 [info] rend_client_introcirc_has_opened(): introcirc is open
Dec 25 13:15:16.000 [info] connection_ap_handshake_attach_circuit(): pending-join circ 3419634369 already here, with intro ack. Stalling. (stream 26 sec old)
Dec 25 13:15:16.000 [info] connection_ap_handshake_attach_circuit(): Intro circ 2259155742 present and awaiting ack (rend 2404371907). Stalling. (stream 26 sec old)
Dec 25 13:15:16.000 [info] connection_ap_handshake_attach_circuit(): Intro circ 3200472182 present and awaiting ack (rend 4286776399). Stalling. (stream 26 sec old)
Dec 25 13:15:16.000 [info] connection_ap_handshake_attach_circuit(): ready rend circ 2334828448 already here (no intro-ack yet on intro 4002828471). (stream 27 sec old)
Dec 25 13:15:16.000 [info] connection_ap_handshake_attach_circuit(): found open intro circ 4002828471 (rend 2334828448); sending introduction. (stream 27 sec old)
Dec 25 13:15:16.000 [info] rend_client_send_introduction(): Sending an INTRODUCE1 cell
Dec 25 13:15:16.000 [info] pathbias_count_use_attempt(): Used circuit 53301 is already in path state use succeeded. Circuit is a Hidden service client: Pending rendezvous point currently open.