Opened 19 months ago

Last modified 6 months ago

#28992 merge_ready defect

Bug: ../src/feature/hs/hs_client.c:571: send_introduce1: Non-fatal assertion !(ip == NULL) failed.

Reported by: traumschule Owned by: dgoulet
Priority: High Milestone: Tor: 0.4.2.x-final
Component: Core Tor/Tor Version: Tor: 0.3.2.1-alpha
Severity: Normal Keywords: consider-backport-after-0434, tor-hs, 043-must, 035-backport, 041-backport, 042-backport, 043-backport, BugSmashFund
Cc: Actual Points: 0.2
Parent ID: Points: 0.1
Reviewer: asn Sponsor: Sponsor27-can

Description

(likely follow-up of #28669)

Jan 04 06:53:53.620 [notice] Your system clock just jumped 21357 seconds forward; assuming established circuits no longer work.
Jan 04 06:55:05.286 [warn] tor_bug_occurred_(): Bug: ../src/feature/hs/hs_client.c:280: retry_all_socks_conn_waiting_for_desc: Non-fatal assertion !(status == HS_CLIENT_FETCH_HAVE_DESC) failed. (on Tor 0.4.0.0-alpha-dev )
Jan 04 06:55:05.287 [warn] Bug: Non-fatal assertion !(status == HS_CLIENT_FETCH_HAVE_DESC) failed in retry_all_socks_conn_waiting_for_desc at ../src/feature/hs/hs_client.c:280. Stack trace: (on Tor 0.4.0.0-alpha-dev )

Jan 04 06:55:56.522 [warn] tor_bug_occurred_(): Bug: ../src/feature/hs/hs_client.c:280: retry_all_socks_conn_waiting_for_desc: Non-fatal assertion !(status == HS_CLIENT_FETCH_HAVE_DESC) failed. (on Tor 0.4.0.0-alpha-dev )
Jan 04 06:55:56.523 [warn] Bug: Non-fatal assertion !(status == HS_CLIENT_FETCH_HAVE_DESC) failed in retry_all_socks_conn_waiting_for_desc at ../src/feature/hs/hs_client.c:280. Stack trace: (on Tor 0.4.0.0-alpha-dev )
J
Jan 04 06:55:56.569 [warn] tor_bug_occurred_(): Bug: ../src/feature/hs/hs_client.c:280: retry_all_socks_conn_waiting_for_desc: Non-fatal assertion !(status == HS_CLIENT_FETCH_HAVE_DESC) failed. (on Tor 0.4.0.0-alpha-dev )
Jan 04 06:55:56.570 [warn] Bug: Non-fatal assertion !(status == HS_CLIENT_FETCH_HAVE_DESC) failed in retry_all_socks_conn_waiting_for_desc at ../src/feature/hs/hs_client.c:280. Stack trace: (on Tor 0.4.0.0-alpha-dev )
J
Jan 04 06:55:56.613 [warn] tor_bug_occurred_(): Bug: ../src/feature/hs/hs_client.c:280: retry_all_socks_conn_waiting_for_desc: Non-fatal assertion !(status == HS_CLIENT_FETCH_HAVE_DESC) failed. (on Tor 0.4.0.0-alpha-dev )
Jan 04 06:55:56.615 [warn] Bug: Non-fatal assertion !(status == HS_CLIENT_FETCH_HAVE_DESC) failed in retry_all_socks_conn_waiting_for_desc at ../src/feature/hs/hs_client.c:280. Stack trace: (on Tor 0.4.0.0-alpha-dev )
...
Jan 04 08:48:21.767 [warn] tor_bug_occurred_(): Bug: ../src/feature/hs/hs_client.c:571: send_introduce1: Non-fatal assertion !(ip == NULL) failed. (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.772 [warn] Bug: Non-fatal assertion !(ip == NULL) failed in send_introduce1 at ../src/feature/hs/hs_client.c:571. Stack trace: (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(log_backtrace_impl+0x65) [0x681d35] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(tor_bug_occurred_+0xbd) [0x67d55d] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(hs_client_send_introduce1+0x23c) [0x58070c] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(connection_ap_handshake_attach_circuit+0x797) [0x514317] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(connection_ap_attach_pending+0x171) [0x517b61] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(hs_client_receive_rendezvous_acked+0x82) [0x580d92] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(rend_process_relay_cell+0x235) [0x5cb345] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(+0xa0c04) [0x532c04] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(circuit_receive_relay_cell+0x38a) [0x53515a] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(command_process_cell+0x181) [0x515111] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(channel_tls_handle_cell+0x34a) [0x4f9cea] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(+0x8beed) [0x51deed] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(+0x4a931) [0x4dc931] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(connection_handle_read+0x9a4) [0x4e6784] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(+0x5ab79) [0x4ecb79] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/lib/i386-linux-gnu/libevent-2.0.so.5(event_base_loop+0x7d1) [0xb7619681] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(tor_libevent_run_event_loop+0x30) [0x61dfe0] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(do_main_loop+0xc5) [0x4edfe5] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(run_tor_main_loop+0x1ce) [0x4d996e] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(tor_run_main+0x11c5) [0x4dad25] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(tor_main+0x3f) [0x4d7ebf] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(main+0x35) [0x4d7a15] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /lib/i386-linux-gnu/libc.so.6(__libc_start_main+0xf1) [0xb6f65b41] (on Tor 0.4.0.0-alpha-dev )
Jan 04 08:48:21.773 [warn] Bug:     /usr/bin/tor(+0x45a71) [0x4d7a71] (on Tor 0.4.0.0-alpha-dev )

Child Tickets

Attachments (1)

28992-info.scrubbed.log.xz (25.8 KB) - added by traumschule 19 months ago.
Bug: Non-fatal assertion !(ip == NULL) failed in send_introduce1 at ../src/feature/hs/hs_client.c:571. Stack trace: (on Tor 0.4.0.0-alpha-dev-20190103T151451Z-1~d90.stretch+1)

Download all attachments as: .zip

Change History (17)

Changed 19 months ago by traumschule

Attachment: 28992-info.scrubbed.log.xz added

Bug: Non-fatal assertion !(ip == NULL) failed in send_introduce1 at ../src/feature/hs/hs_client.c:571. Stack trace: (on Tor 0.4.0.0-alpha-dev-20190103T151451Z-1~d90.stretch+1)

comment:1 Changed 19 months ago by traumschule

See also #27471.

comment:2 Changed 19 months ago by traumschule

Resolution: worksforme
Status: newclosed

This only happened once after a clock jump on a specific nightly version.

comment:3 Changed 6 months ago by gk

Resolution: worksforme
Status: closedreopened

I think I got that one, too, yesterday, however, only the last assert and without the clock jump line:

Feb 03 13:03:57.000 [warn] tor_bug_occurred_(): Bug: ../src/feature/hs/hs_client.c:636: send_introduce1: Non-fatal assertion !(ip == NULL) failed. (Future instances of this warning will be silenced.) (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug: Tor 0.4.3.1-alpha-dev (git-39c5e1b84994c2f2): Non-fatal assertion !(ip == NULL) failed in send_introduce1 at ../src/feature/hs/hs_client.c:636. Stack trace: (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /usr/lib/x86_64-linux-gnu/libasan.so.5(+0x69c51) [0x7f2f065fcc51] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(log_backtrace_impl+0x60) [0x5591ba79fc60] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(tor_bug_occurred_+0x2de) [0x5591ba79590e] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(hs_client_send_introduce1+0x3da) [0x5591ba58bfaa] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(connection_ap_handshake_attach_circuit+0xacf) [0x5591ba478a2f] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(connection_ap_attach_pending+0x2e0) [0x5591ba4827b0] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(hs_client_receive_rendezvous_acked+0xc7) [0x5591ba58cbe7] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(rend_process_relay_cell+0x200) [0x5591ba63b7a0] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x2a786f) [0x5591ba4bd86f] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x2aa322) [0x5591ba4c0322] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(circuit_receive_relay_cell+0xa3b) [0x5591ba4c4c1b] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(command_process_cell+0x7c8) [0x5591ba47c348] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(channel_tls_handle_cell+0x5cf) [0x5591ba42e50f] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x27bf61) [0x5591ba491f61] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(connection_handle_read+0x1ae2) [0x5591ba40a772] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x200831) [0x5591ba416831] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /usr/lib/x86_64-linux-gnu/libevent-2.1.so.7(+0x23b0f) [0x7f2f063fbb0f] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /usr/lib/x86_64-linux-gnu/libevent-2.1.so.7(event_base_loop+0x52f) [0x7f2f063fc24f] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(do_main_loop+0x21d) [0x5591ba41855d] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(tor_run_main+0x173d) [0x5591ba3ef4dd] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(tor_main+0x68) [0x5591ba3eb3d8] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(main+0x1c) [0x5591ba3e471c] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xeb) [0x7f2f05ed2bbb] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)
Feb 03 13:03:57.000 [warn] Bug:     /home/thomas/Arbeit/Tor/debugging/32379/tor-browser_en-US/Browser/TorBrowser/Tor/tor(_start+0x2a) [0x5591ba3eab4a] (on Tor 0.4.3.1-alpha-dev 39c5e1b84994c2f2)

I wonder how to repro that one, though, as I've never seen this before in Tor Browser. :(

comment:4 Changed 6 months ago by dgoulet

Cc: asn dgoulet removed
Keywords: 043-must 035-backport 041-backport 042-backport added
Milestone: Tor: 0.4.0.x-finalTor: 0.4.3.x-final
Points: 0.1
Reviewer: asn
Sponsor: Sponsor27-can
Status: reopenedneeds_review

Ok, I think we are at the point of removing that BUG().

Between the rendezvous circuit creation and when we send the INTRO point, the descriptor can change "naturally" so we should stop thinking we can control all code path there and just recover which is what the code already does.

I even propose that we backport else we'll get these warnings for the next half decade...

I've done the patch (trivial). Here is what I propose:

Branch: ticket28992_035_01
PR: https://github.com/torproject/tor/pull/1707

(merges cleanly forward.)

comment:5 Changed 6 months ago by asn

Status: needs_reviewneeds_revision

seems reasonable, but let's add a log_info as well so that if we ever end up with an issue where this behavior occured and we get logs, we can find out that this actually happened.

comment:6 Changed 6 months ago by dgoulet

Status: needs_revisionneeds_review

Done! See fixup.

comment:7 Changed 6 months ago by dgoulet

Owner: set to dgoulet
Status: needs_reviewaccepted

comment:8 Changed 6 months ago by dgoulet

Status: acceptedneeds_review

comment:9 Changed 6 months ago by nickm

Priority: MediumHigh

Mark 043-must tickets as high priority

comment:10 Changed 6 months ago by asn

Status: needs_reviewneeds_revision

travis is no longer happy :/

comment:11 Changed 6 months ago by dgoulet

Status: needs_revisionneeds_review

Sorry typo got in magically...

comment:12 Changed 6 months ago by asn

Resolution: fixed
Status: needs_reviewclosed

Merged! Thanks!

comment:13 Changed 6 months ago by teor

Actual Points: 0.1
Keywords: consider-backport-after-0434 043-backport BugSmashFund added
Milestone: Tor: 0.4.3.x-finalTor: 0.4.2.x-final
Resolution: fixed
Status: closedreopened
Version: Tor: 0.3.2.1-alpha

Please don't close tickets that are marked for backport!

Merged to 0.4.3 and later.

Remember, 0.4.3 is in alpha, so new bugs should be merged to 0.4.3 to get testing.

comment:14 Changed 6 months ago by teor

Status: reopenedmerge_ready

comment:15 Changed 6 months ago by teor

I made a new squashed PR for merging to 0.3.5 and later:

comment:16 Changed 6 months ago by teor

Actual Points: 0.10.2
Note: See TracTickets for help on using tickets.