#23543: prop224: Disconnects on long-lasting HS connections (possibly because of mds) -----------------------------------------+--------------------------------- Reporter: asn | Owner: (none) Type: defect | Status: new Priority: Medium | Milestone: Tor: | 0.3.2.x-final Component: Core Tor/Tor | Version: Severity: Normal | Resolution: Keywords: tor-hs prop224 prop224-bugs | Actual Points: Parent ID: | Points: 1 Reviewer: | Sponsor: -----------------------------------------+---------------------------------
Comment (by asn): Here is another such disconnect case from yesterday evening. It's a legacy HS client running latest master connecting to a legacy HS: {{{ Sep 16 17:29:31.000 [debug] connection_edge_process_relay_cell(): Now seen 55751 relay cells here (command 9, stream 0). Sep 16 17:29:31.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x7f8c23b46820 for circ_id 2915300815, channel ID 6 (0x7f8c240de460) Sep 16 17:29:31.000 [debug] pathbias_count_use_success(): Marked circuit 151 (7.000000/8.000000) as used successfully for guard motmot ($E248C3A604E196137A3175D4B2E4328922178B47) Sep 16 17:29:31.000 [info] circuit_mark_for_close_(): Circuit 2915300815 marked for close at src/or/circuitbuild.c:1543 (orig reason: 520, new reason: 0) Sep 16 17:29:31.000 [debug] connection_or_process_cells_from_inbuf(): 16: starting, inbuf_datalen 0 (0 pending in tls object). Sep 16 17:29:31.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Sep 16 17:29:31.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Sep 16 17:29:31.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x7f8c23b46820 for circ_id 2915300815, channel ID 6 (0x7f8c240de460) Sep 16 17:29:31.000 [debug] circuitmux_append_destroy_cell(): Cmux at 0x7f8c23af4dc0 queued a destroy for circ 2915300815, cmux counter is now 1, global counter is now 1 Sep 16 17:29:31.000 [debug] circuitmux_append_destroy_cell(): Primed a buffer. Sep 16 17:29:31.000 [debug] channel_write_cell_generic_(): Writing p 0x7f8c2364cee0 to channel 0x7f8c240de460 with global ID 6 Sep 16 17:29:31.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x7f8c23b46820 for circ_id 2915300815, channel ID 6 (0x7f8c240de460) Sep 16 17:29:31.000 [debug] channel_tls_get_overhead_estimate_method(): Estimated overhead ratio for TLS chan 6 is 1.053891 Sep 16 17:29:31.000 [debug] channel_update_xmit_queue_size(): Increasing queue size for channel 6 by 541 from 0 to 541 Sep 16 17:29:31.000 [debug] channel_update_xmit_queue_size(): Increasing global queue size by 541 for channel 6, new size is 541 Sep 16 17:29:31.000 [debug] scheduler_adjust_queue_size(): Queue size adjustment by +541 for channel 6 Sep 16 17:29:31.000 [debug] scheduler_update_queue_heuristic(): Queue heuristic is now 0 Sep 16 17:29:31.000 [debug] scheduler_adjust_queue_size(): Queue heuristic is now 541 Sep 16 17:29:31.000 [debug] circuitmux_notify_xmit_destroy(): Cmux at 0x7f8c23af4dc0 sent a destroy, cmux counter is now 0, global counter is now 0 Sep 16 17:29:31.000 [debug] channel_send_destroy(): Sending destroy (circID 2915300815) on channel 0x7f8c240de460 (global ID 6) Sep 16 17:29:31.000 [info] connection_edge_destroy(): CircID 0: At an edge. Marking connection for close. Sep 16 17:29:31.000 [info] rend_client_note_connection_attempt_ended(): Connection attempt for d6sfftbz6pkwfwwl has ended; cleaning up temporary state. Sep 16 17:29:31.000 [debug] conn_close_if_marked(): Cleaning up connection (fd 12). Sep 16 17:29:31.000 [debug] connection_remove(): removing socket 12 (type Socks), n_conns now 4 Sep 16 17:29:31.000 [debug] connection_free_(): closing fd 12. Sep 16 17:29:31.000 [debug] conn_write_callback(): socket 16 wants to write. Sep 16 17:29:31.000 [debug] flush_chunk_tls(): flushed 514 bytes, 0 ready to flush, 0 remain. Sep 16 17:29:31.000 [debug] connection_handle_write_impl(): After TLS write of 514: 0 read, 543 written Sep 16 17:29:31.000 [debug] channel_tls_get_overhead_estimate_method(): Estimated overhead ratio for TLS chan 6 is 1.053891 Sep 16 17:29:31.000 [debug] channel_update_xmit_queue_size(): Decreasing queue size for channel 6 by 541 from 541 to 0 Sep 16 17:29:31.000 [debug] channel_update_xmit_queue_size(): Decreasing global queue size by 541 for channel 6, new size is 0 Sep 16 17:29:31.000 [debug] scheduler_adjust_queue_size(): Queue size adjustment by -541 for channel 6 Sep 16 17:29:31.000 [debug] scheduler_adjust_queue_size(): Queue heuristic is now 0 Sep 16 17:29:31.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Sep 16 17:29:31.000 [debug] connection_bucket_refill_helper(): or_conn->write_bucket now 1073741824. Sep 16 17:29:32.000 [debug] conn_read_callback(): socket 7 wants to read. Sep 16 17:29:32.000 [debug] connection_handle_listener_read(): Connection accepted on socket 12 (child of fd 7). Sep 16 17:29:32.000 [info] connection_handle_listener_read(): New SOCKS connection opened from 127.0.0.1. Sep 16 17:29:32.000 [debug] connection_add_impl(): new conn type Socks, socket 12, address 127.0.0.1, n_conns 4. Sep 16 17:29:32.000 [debug] conn_read_callback(): socket 12 wants to read. Sep 16 17:29:32.000 [debug] read_to_chunk(): Read 33 bytes. 33 on inbuf. Sep 16 17:29:32.000 [debug] connection_ap_handshake_process_socks(): entered. Sep 16 17:29:32.000 [debug] parse_socks(): socks4: Everything is here. Success. Sep 16 17:29:32.000 [debug] connection_ap_handshake_rewrite(): Client asked for d6sfftbz6pkwfwwl.onion:6697 Sep 16 17:29:32.000 [info] connection_ap_handle_onion(): Got a hidden service request for ID 'd6sfftbz6pkwfwwl' Sep 16 17:29:32.000 [info] rep_hist_note_used_internal(): New port prediction added. Will continue predictive circ building for 2580 more seconds. Sep 16 17:29:32.000 [info] connection_ap_handle_onion(): Descriptor is here. Great. Sep 16 17:29:32.000 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer. Sep 16 17:29:32.000 [notice] Application request when we haven't used client functionality lately. Optimistically trying directory fetches again. }}} The incriminating mark for close at circuitbuild.c:1543 seems to be from `circuit_truncated()`. Could this be from natural causes where one of the rend circuit hops died and the circ had to be rebuilt? :/ -- Ticket URL: <https://trac.torproject.org/projects/tor/ticket/23543#comment:5> 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