[tor-bugs] #30942 [Core Tor/Tor]: [warn] Unexpected INTRODUCE_ACK on circuit 3944288021.

[Tor Bug Tracker & Wiki]

#30942: [warn] Unexpected INTRODUCE_ACK on circuit 3944288021.
------------------------------+--------------------
     Reporter:  arma          |      Owner:  (none)
         Type:  defect        |     Status:  new
     Priority:  Medium        |  Milestone:
    Component:  Core Tor/Tor  |    Version:
     Severity:  Normal        |   Keywords:
Actual Points:                |  Parent ID:
       Points:                |   Reviewer:
      Sponsor:                |
------------------------------+--------------------
 Running
 {{{
 Jun 19 01:26:41.987 [notice] Tor 0.4.2.0-alpha-dev (git-438b7eec856b0cac)
 running on Linux with Libevent 2.1.8-stable, OpenSSL 1.1.1c, Zlib 1.2.11,
 Liblzma N/A, and Libzstd N/A.
 }}}

 Looking at my debug-level logs, here are some lines that look relevant:
 {{{
 Jun 20 14:42:15.423 [info] rend_client_introduction_acked(): Received ack.
 Telling rend circ...
 Jun 20 14:42:15.423 [debug] circuit_change_purpose(): changing purpose of
 origin circ 87 from "Hidden service client: Pending rendezvous point" (10)
 to "Hidden service client: Pending rendezvous point (ack received)" (11)
 Jun 20 14:42:15.423 [debug] circuit_change_purpose(): changing purpose of
 origin circ 88 from "Hidden service client: Waiting for ack from intro
 point" (7) to "Hidden service client: Received ack from intro point" (8)
 Jun 20 14:42:15.423 [debug] circuit_get_by_circid_channel_impl():
 circuit_get_by_circid_channel_impl() returning circuit 0x562673bfdc90 for
 circ_id 2983373670, channel ID 29 (0x562674553c80)
 Jun 20 14:42:15.423 [info] circuit_mark_for_close_(): Circuit 2983373670
 (id: 88) marked for close at src/feature/rend/rendclient.c:418 (orig
 reason: 9, new reason: 0)
 Jun 20 14:42:15.423 [info] rend_client_close_other_intros(): Closing
 introduction circuit 90 that we built in parallel (Purpose 7).
 Jun 20 14:42:15.423 [debug] circuit_get_by_circid_channel_impl():
 circuit_get_by_circid_channel_impl() returning circuit 0x562673c1d930 for
 circ_id 3944288021, channel ID 29 (0x562674553c80)
 Jun 20 14:42:15.423 [info] circpad_marked_circuit_for_padding(): Circuit
 90 is not marked for close because of a  pending padding machine.
 Jun 20 14:42:15.423 [debug] circuit_change_purpose(): changing purpose of
 origin circ 90 from "Hidden service client: Waiting for ack from intro
 point" (7) to "Circuit kept open for padding" (15)
 [...]
 Jun 20 14:42:15.470 [debug] connection_or_process_cells_from_inbuf(): 13:
 starting, inbuf_datalen 514 (0 pending in tls object).
 Jun 20 14:42:15.470 [debug] channel_process_cell(): Processing incoming
 cell_t 0x7ffc169e5030 for channel 0x562674553c80 (global ID 29)
 Jun 20 14:42:15.470 [debug] circuit_get_by_circid_channel_impl():
 circuit_get_by_circid_channel_impl() returning circuit 0x562673c1d930 for
 circ_id 3944288021, channel ID 29 (0x562674553c80)
 Jun 20 14:42:15.470 [debug] circuit_receive_relay_cell(): Sending to
 origin.
 Jun 20 14:42:15.470 [debug] connection_edge_process_relay_cell(): Now seen
 205318 relay cells here (command 40, stream 0).
 Jun 20 14:42:15.470 [warn] Unexpected INTRODUCE_ACK on circuit 3944288021.
 Jun 20 14:42:15.470 [debug] circuit_get_by_circid_channel_impl():
 circuit_get_by_circid_channel_impl() returning circuit 0x562673c1d930 for
 circ_id 3944288021, channel ID 29 (0x562674553c80)
 Jun 20 14:42:15.470 [info] pathbias_should_count(): Circuit 90 is not
 being counted by pathbias because it was ignored in the past. Purpose is
 Circuit kept open for padding, path state is new
 Jun 20 14:42:15.471 [info] circuit_mark_for_close_(): Circuit 3944288021
 (id: 90) marked for close at src/feature/hs/hs_client.c:1770 (orig reason:
 1, new reason: 0)
 }}}

 I.e. it looks like we built two parallel intro circuits, one of them
 worked, so we closed the other, but we didn't actually close it, we put it
 into an "open for padding" state, and then the intro ack arrived on it
 after a while, which surprised us.

--
Ticket URL: <https://trac.torproject.org/projects/tor/ticket/30942>
Tor Bug Tracker & Wiki <https://trac.torproject.org/>
The Tor Project: anonymity online