#28970: tor_bug_occurred_(): Bug: ../src/or/hs_client.c:624: setup_intro_circ_auth_key: Non-fatal assertion -------------------------------------------------+------------------------- Reporter: torcrash | Owner: dgoulet Type: defect | Status: | reopened Priority: High | Milestone: Tor: | 0.4.2.x-final Component: Core Tor/Tor | Version: Tor: | 0.3.4.9 Severity: Critical | Resolution: Keywords: tor-client, tor-hs, postfreeze-ok, | Actual Points: 040-unreached-must, network-team-roadmap- | august, regression?, 041-unreached-must | Parent ID: #29995 | Points: 5 Reviewer: | Sponsor: | Sponsor27-must -------------------------------------------------+------------------------- Changes (by asn):
* status: closed => reopened * resolution: fixed => Comment: Hmm, I got this on a recent 042 branch of mine (https://github.com/asn-d6/tor/tree/padanalysis) which is based on `e57209dc32`. That should include all the fixes from above as it is from about a month ago. Fortunately I have info logs which might be helpful. The fun thing is that a NEWNYM occured between cannibalization and use of intro circ: {{{ Sep 09 10:36:23.000 [info] circuit_launch_by_extend_info(): Cannibalizing circ 2971206838 (id: 18) for purpose 6 (Hidden service client: Connecting to intro point) Sep 09 10:36:23.000 [info] circuit_send_intermediate_onion_skin(): Sending extend relay cell. Sep 09 10:36:23.000 [info] rep_hist_note_used_internal(): New port prediction added. Will continue predictive circ building for 2484 more seconds. Sep 09 10:36:23.000 [info] connection_ap_handshake_attach_circuit(): Intro 2971206838 (id: 18) and rend circuit 2792227503 (id: 17) circuits are not both ready. Stalling conn. (0 sec old) Sep 09 10:36:24.000 [info] hs_client_receive_rendezvous_acked(): Received an RENDEZVOUS_ESTABLISHED. This circuit is now ready for rendezvous. Sep 09 10:36:24.000 [info] circpad_setup_machine_on_circ(): Registering machine client_rp_circ to origin circ 17 (10) Sep 09 10:36:24.000 [info] circpad_node_supports_padding(): Checking padding: supported Sep 09 10:36:24.000 [info] circpad_negotiate_padding(): Negotiating padding on circuit 17 (10) Sep 09 10:36:24.000 [info] circpad_machine_spec_transition(): Circpad machine 0 transitioning from 0 to 1 Sep 09 10:36:24.000 [info] circpad_choose_state_length(): State length sampled to 1. Sep 09 10:36:24.000 [info] circpad_machine_schedule_padding(): Padding in 751 usec Sep 09 10:36:24.000 [info] circpad_machine_schedule_padding(): Padding in 0 sec, 751 usec Sep 09 10:36:24.000 [info] connection_ap_handshake_attach_circuit(): ready rend circ 2792227503 (id: 17) already here. Nointro-ack yet on intro 2971206838 (id: 18). (str eam 1 sec old) Sep 09 10:36:24.000 [info] connection_ap_handshake_attach_circuit(): Intro 2971206838 (id: 18) and rend circuit 2792227503 (id: 17) circuits are not both ready. Stalling conn. (1 sec old) Sep 09 10:36:24.000 [info] circpad_send_padding_cell_for_callback(): Callback: Sending padding to origin circuit 17 (10) [length: 0] Sep 09 10:36:24.000 [info] circpad_machine_spec_transition(): Circpad machine 0 transitioning from 1 to 65535 Sep 09 10:36:24.000 [info] circpad_handle_padding_negotiated(): Middle node did not accept our padding request. Sep 09 10:36:24.000 [info] connection_ap_handshake_attach_circuit(): ready rend circ 2792227503 (id: 17) already here. Nointro-ack yet on intro 2971206838 (id: 18). (str eam 1 sec old) Sep 09 10:36:24.000 [info] connection_ap_handshake_attach_circuit(): Intro 2971206838 (id: 18) and rend circuit 2792227503 (id: 17) circuits are not both ready. Stalling conn. (1 sec old) Sep 09 10:36:24.000 [info] circuit_predict_and_launch_new(): Have 7 clean circs (0 uptime-internal, 0 internal), need another hidden service circ. Sep 09 10:36:24.000 [info] extend_info_from_node(): Including Ed25519 ID for $0FEDEBE83C1F2DE3D6673876BBA1433CCF0ADE51~jannis at 31.31.74.47 Sep 09 10:36:24.000 [info] select_primary_guard_for_circuit(): Selected primary guard Unnamed ($C07622052739697129BA49A5DF3C503CE1AAA100) for circuit. Sep 09 10:36:24.000 [info] extend_info_from_node(): Including Ed25519 ID for $C07622052739697129BA49A5DF3C503CE1AAA100~Unnamed at 78.129.180.14 Sep 09 10:36:24.000 [info] extend_info_from_node(): Including Ed25519 ID for $ACE29EC7700BD112DEB42B934E5E443476CD577C~StoneCat at 195.201.26.175 Sep 09 10:36:24.000 [info] circuit_send_first_onion_skin(): First hop: finished sending CREATE cell to '$C07622052739697129BA49A5DF3C503CE1AAA100~Unnamed at 78.129.180.1 4' Sep 09 10:36:24.000 [info] circuit_finish_handshake(): Finished building circuit hop: Sep 09 10:36:24.000 [info] internal (high-uptime) circ (length 3, last hop jannis): $C07622052739697129BA49A5DF3C503CE1AAA100(open) $ACE29EC7700BD112DEB42B934E5E443476CD 577C(closed) $0FEDEBE83C1F2DE3D6673876BBA1433CCF0ADE51(closed) Sep 09 10:36:24.000 [info] circuit_send_intermediate_onion_skin(): Sending extend relay cell. Sep 09 10:36:24.000 [info] handle_deferred_signewnym_cb(): Honoring delayed NEWNYM request Sep 09 10:36:24.000 [notice] Executing NEWNYM Sep 09 10:36:24.000 [info] rend_cache_purge(): Purging HS v2 descriptor cache Sep 09 10:36:24.000 [info] rend_cache_failure_purge(): Purging HS v2 failure cache Sep 09 10:36:24.000 [info] hs_purge_last_hid_serv_requests(): Purging client last-HS-desc-request-time table Sep 09 10:36:24.000 [info] cancel_descriptor_fetches(): Hidden service client descriptor fetches cancelled. Sep 09 10:36:24.000 [info] hs_cache_client_intro_state_purge(): Hidden service client introduction point state cache purged. Sep 09 10:36:24.000 [info] hs_cache_purge_as_client(): Hidden service client descriptor cache purged. Sep 09 10:36:24.000 [info] hs_client_purge_state(): Hidden service client state has been purged. Sep 09 10:36:24.000 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer. Sep 09 10:36:24.000 [info] connection_edge_reached_eof(): conn (fd 15) reached eof. Closing. Sep 09 10:36:24.000 [info] connection_handle_listener_read(): New SOCKS connection opened from 127.0.0.1. Sep 09 10:36:24.000 [info] connection_ap_handle_onion(): No descriptor found in our cache for ieed562tnprqmalo7geqcgxqcdixbg2czptgmqxlxx4v2kwrmb74ufad. Fetching. Sep 09 10:36:24.000 [info] rep_hist_note_used_internal(): New port prediction added. Will continue predictive circ building for 2484 more seconds. Sep 09 10:36:24.000 [info] rep_hist_note_used_internal(): New port prediction added. Will continue predictive circ building for 2484 more seconds. Sep 09 10:36:24.000 [info] connection_ap_make_link(): Making internal anonymized tunnel to 51.68.140.94:443 ... Sep 09 10:36:24.000 [info] connection_ap_make_link(): ... application connection created and linked. Sep 09 10:36:24.000 [info] directory_launch_v3_desc_fetch(): Descriptor fetch request for service QQg++1Nr4wYBbvmJARrwENFwm0LL5mZC6735XSrRYH8 with blinded key ecp1LrfJD36sKrkzHCxuel+psRktL3Cg6fZcaGb85io to directory $71EFE4314646C4613895509723BFD354D8EABCAF~Cosworth01 at 51.68.140.94 Sep 09 10:36:24.000 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for rendezvous desc' state. Leaving it on buffer. Sep 09 10:36:24.000 [info] extend_info_from_node(): Including Ed25519 ID for $71EFE4314646C4613895509723BFD354D8EABCAF~Cosworth01 at 51.68.140.94 Sep 09 10:36:24.000 [info] onion_pick_cpath_exit(): Using requested exit node '$71EFE4314646C4613895509723BFD354D8EABCAF~Cosworth01 at 51.68.140.94' Sep 09 10:36:24.000 [info] select_primary_guard_for_circuit(): Selected primary guard Unnamed ($C07622052739697129BA49A5DF3C503CE1AAA100) for circuit. Sep 09 10:36:24.000 [info] extend_info_from_node(): Including Ed25519 ID for $C07622052739697129BA49A5DF3C503CE1AAA100~Unnamed at 78.129.180.14 Sep 09 10:36:24.000 [info] extend_info_from_node(): Including Ed25519 ID for $134DED8B9FC5EEFD61AEF65659CF4AF0AA7FBCB5~Unnamed at 213.239.204.62 Sep 09 10:36:24.000 [info] extend_info_from_node(): Including Ed25519 ID for $3F05B8C1DF491BBF5E7DD199440911A84D9165D8~Unnamed at 91.211.247.246 Sep 09 10:36:24.000 [info] circuit_send_first_onion_skin(): First hop: finished sending CREATE cell to '$C07622052739697129BA49A5DF3C503CE1AAA100~Unnamed at 78.129.180.14' Sep 09 10:36:24.000 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer. Sep 09 10:36:24.000 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer. Sep 09 10:36:24.000 [info] circuit_finish_handshake(): Finished building circuit hop: Sep 09 10:36:24.000 [info] internal (high-uptime) circ (length 4, last hop ): $C07622052739697129BA49A5DF3C503CE1AAA100(open) $46644B13F6409018E14ECEE1E9594740064C9F24(open) $DC79C9D75CFD7A91F9232922E05D225CBDCB7703(open) $7C499ACD60FB651DD486B6D802290A3EBBECCD84(open) Sep 09 10:36:24.000 [info] entry_guards_note_guard_success(): Recorded success for primary confirmed guard Unnamed ($C07622052739697129BA49A5DF3C503CE1AAA100) Sep 09 10:36:24.000 [info] circuit_build_no_more_hops(): circuit built! Sep 09 10:36:24.000 [info] client_intro_circ_has_opened(): Introduction circuit 2971206838 has opened. Attaching streams. Sep 09 10:36:24.000 [warn] tor_bug_occurred_(): Bug: src/feature/hs/hs_client.c:685: setup_intro_circ_auth_key: Non-fatal assertion !(desc == NULL) failed. (Future instances of this warning will be silenced.) (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: Non-fatal assertion !(desc == NULL) failed in setup_intro_circ_auth_key at src/feature/hs/hs_client.c:685. Stack trace: (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: ./src/app/tor(log_backtrace_impl+0x46) [0x560f75f444f6] (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: ./src/app/tor(tor_bug_occurred_+0x16b) [0x560f75f3f8fb] (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: ./src/app/tor(hs_client_circuit_has_opened+0x3b0) [0x560f75e40ce0] (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: ./src/app/tor(circuit_send_next_onion_skin+0x2b8) [0x560f75dbb588] (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: ./src/app/tor(+0xb8eb3) [0x560f75df1eb3] (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: ./src/app/tor(circuit_receive_relay_cell+0x2b5) [0x560f75df3ff5] (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: ./src/app/tor(command_process_cell+0x2c0) [0x560f75dd5bb0] (on Tor 0.4.2.0 -alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: ./src/app/tor(channel_tls_handle_cell+0x253) [0x560f75db5433] (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: ./src/app/tor(+0xa595c) [0x560f75dde95c] (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: ./src/app/tor(connection_handle_read+0xaac) [0x560f75da2c4c] (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: ./src/app/tor(+0x6eebe) [0x560f75da7ebe] (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: /usr/lib/x86_64-linux- gnu/libevent-2.1.so.6(+0x229ba) [0x7fedcecba9ba] (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: /usr/lib/x86_64-linux- gnu/libevent-2.1.so.6(event_base_loop+0x5a7) [0x7fedcecbb537] (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: ./src/app/tor(do_main_loop+0xdd) [0x560f75da91dd] (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: ./src/app/tor(tor_run_main+0x1115) [0x560f75d96af5] (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: ./src/app/tor(tor_main+0x3a) [0x560f75d9418a] (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: ./src/app/tor(main+0x19) [0x560f75d93d69] (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: /lib/x86_64-linux- gnu/libc.so.6(__libc_start_main+0xeb) [0x7fedce74009b] (on Tor 0.4.2.0 -alpha-dev eef7896e854c3d6d) Sep 09 10:36:24.000 [warn] Bug: ./src/app/tor(_start+0x2a) [0x560f75d93dba] (on Tor 0.4.2.0-alpha-dev eef7896e854c3d6d) }}} -- Ticket URL: <https://trac.torproject.org/projects/tor/ticket/28970#comment:28> 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