"Padding negotiated cell from wrong hop" messages on re-extended intro circs
Seems like even after #32040 (closed) and #30992 (closed) we still get "Padding negotiated cell from wrong hop" messages on main
when a client circ fails the first intro and then re-extends for a second attempt (happens much more often on chutney than normal net):
Jul 15 16:30:22.990 [info] connection_ap_handshake_attach_circuit(): Found open intro circ 4275612781 (id: 75). Rend circuit 4061106010
(id: 74); Sending introduction. (stream 0 sec old)
Jul 15 16:30:22.990 [info] send_introduce1(): Sending INTRODUCE1 cell to service 3meybgbnlmca5d46w4kjkyzolkcdubo3mn7a5wppcprvapan7oinjmi
d on circuit 4275612781
Jul 15 16:30:22.991 [info] circpad_setup_machine_on_circ(): Registering machine client_ip_circ to origin circ 75 (7)
Jul 15 16:30:22.991 [info] circpad_node_supports_padding(): Checking padding: supported
Jul 15 16:30:22.991 [info] circpad_negotiate_padding(): Negotiating padding on circuit 75 (7), command 2, for ctr 1
Jul 15 16:30:22.991 [info] circpad_machine_spec_transition(): Circuit 75 circpad machine 0 transitioning from 0 to 1
Jul 15 16:30:22.991 [info] circpad_machine_schedule_padding(): Padding in 4294967295 usec on circuit 75
Jul 15 16:30:22.991 [info] pathbias_count_use_attempt(): Used circuit 74 is already in path state use succeeded. Circuit is a Hidden ser
vice client: Pending rendezvous point currently open.
Jul 15 16:30:23.014 [info] circpad_deliver_recognized_relay_cell_events(): Got padding cell on origin circuit 75.
Jul 15 16:30:23.062 [info] circpad_deliver_recognized_relay_cell_events(): Got padding cell on origin circuit 75.
Jul 15 16:30:23.063 [info] handle_introduce_ack_bad(): Received INTRODUCE_ACK nack by $3AEDDA5127E2ABFCC5EE2B470A64AC60FEBC39A6~ [i3korg
rlaRZFTqf3vQC/wT26FoeXhGGylWIn3p83Po0] at 127.0.0.1. Reason: 1
Jul 15 16:30:23.063 [info] circpad_circuit_machineinfo_free_idx(): Freeing padding info idx 0 on circuit 75 (6)
Jul 15 16:30:23.063 [info] circpad_node_supports_padding(): Checking padding: supported
Jul 15 16:30:23.063 [info] circpad_negotiate_padding(): Negotiating padding on circuit 75 (6), command 1, for ctr 1
Jul 15 16:30:23.063 [info] intro_point_is_usable(): Intro point with auth key vi6y0u23BiXbHhFVxADbvjmhOU8B70O/HwoCiUPm1mo had an error.
Not usable
Jul 15 16:30:23.063 [info] hs_client_reextend_intro_circuit(): Re-extending circ 4275612781, this time to $D3514D3562BED4F28837ECCEE3561
724654B17A0~ [IlkMzThwHe1ksPJ7bsPgkLJX+IKvZXwJEf7bSZ9qRq8] at 127.0.0.1.
Jul 15 16:30:23.063 [info] circpad_deliver_recognized_relay_cell_events(): Got padding cell on origin circuit 75.
Jul 15 16:30:23.063 [info] circpad_deliver_recognized_relay_cell_events(): Got padding cell on origin circuit 75.
Jul 15 16:30:23.063 [info] circpad_deliver_recognized_relay_cell_events(): Got padding cell on origin circuit 75.
Jul 15 16:30:23.063 [info] circpad_deliver_recognized_relay_cell_events(): Got padding cell on origin circuit 75.
Jul 15 16:30:23.071 [info] circpad_deliver_recognized_relay_cell_events(): Got padding cell on origin circuit 75.
Jul 15 16:30:23.071 [info] circpad_deliver_recognized_relay_cell_events(): Got padding cell on origin circuit 75.
Jul 15 16:30:23.071 [info] circpad_handle_padding_negotiated(): Received STOP command on PADDING_NEGOTIATED for circuit 75
Jul 15 16:30:23.081 [warn] Padding negotiated cell from wrong hop on circuit 75