Opened 5 months ago

Closed 3 months ago

#21027 closed defect (fixed)

tor_bug_occurred_(): Bug: src/or/entrynodes.c:816: entry_guard_add_to_sample_impl: Non-fatal assertion !(have_sampled_guard_with_id(gs, rsa_id_digest)) failed. (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)

Reported by: asn Owned by: nickm
Priority: High Milestone: Tor: 0.3.0.x-final
Component: Core Tor/Tor Version:
Severity: Normal Keywords: tor-guard, tor-guards-revamp, regression, review-group-16
Cc: bo0od Actual Points:
Parent ID: Points: 1
Reviewer: asn Sponsor:

Description

Hey,

I've been running an oldish version of the guard branch on my tor browser. Top commit is 2767ae18064a879218 plus some extra logging code of mine.

I used Tor with guards and in my logs the following appeared:

Dec 18 01:10:04.000 [warn] tor_bug_occurred_(): Bug: src/or/entrynodes.c:816: entry_guard_add_to_sample_impl: Non-fatal assertion !(have_sampled_guard_with_id(gs, rsa_id_digest)) failed. (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de) 
Dec 18 01:10:04.000 [warn] Bug: Non-fatal assertion !(have_sampled_guard_with_id(gs, rsa_id_digest)) failed in entry_guard_add_to_sample_impl at src/or/entrynodes.c:816. Stack trace: (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /usr/lib/x86_64-linux-gnu/libasan.so.1(backtrace+0x3a) [0x7f0cde5be48a] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(log_backtrace+0x46) [0x7f0cdff74dc6] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(tor_bug_occurred_+0x12f) [0x7f0cdffc4c1f] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x8a249a) [0x7f0cdff2f49a] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x8a3b5c) [0x7f0cdff30b5c] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x8a500f) [0x7f0cdff3200f] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(entry_guards_update_all+0x10f0) [0x7f0cdff379e0] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(guards_update_all+0x83) [0x7f0cdff43cc3] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(set_options+0x62af) [0x7f0cdfe2521f] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(options_trial_assign+0xb3) [0x7f0cdfe28693] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x803aff) [0x7f0cdfe90aff] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(connection_control_process_inbuf+0xdcd) [0x7f0cdfe9df9d] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x7cb938) [0x7f0cdfe58938] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x56f716) [0x7f0cdfbfc716] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/libevent-2.0.so.5(event_base_loop+0x937) [0x7f0cdde408d7] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(do_main_loop+0x385) [0x7f0cdfbfe535] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(tor_main+0x1385) [0x7f0cdfc03385] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(main+0x1c) [0x7f0cdfbf16dc] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5) [0x7f0cdc098b45] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x56665b) [0x7f0cdfbf365b] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)

I've since restarted Tor to use git master, will update the ticket accordingly. Perhaps the above traceback is enough to identify the issue anyway.

Child Tickets

Change History (29)

comment:1 Changed 5 months ago by asn

Some more context:

Dec 18 01:10:04.000 [notice] Tor 0.3.0.0-alpha-dev (git-8b75261b6dc341de) opening log file.
Dec 18 01:10:04.000 [warn] Staying with guard context "bridges" (no change)
Dec 18 01:10:04.000 [warn] Sampled guard $160228DCDC3D22B45C203498C041E60D5BB92F69 ($160228DCDC3D22B45C203498C041E60D5BB92F69) is now unlisted.
Dec 18 01:10:04.000 [warn] Updated sampled guard $160228DCDC3D22B45C203498C041E60D5BB92F69 ($160228DCDC3D22B45C203498C041E60D5BB92F69): filtered
=0; reachable_filtered=0.
Dec 18 01:10:04.000 [warn] Updated sampled guard $160228DCDC3D22B45C203498C041E60D5BB92F69 ($160228DCDC3D22B45C203498C041E60D5BB92F69): filtered
=0; reachable_filtered=0.
Dec 18 01:10:04.000 [warn] Trying to sample a reachable guard: We know of 0 in the USABLE_FILTERED set.
Dec 18 01:10:04.000 [warn]   (That isn't enough. Trying to expand the sample.)
Dec 18 01:10:04.000 [warn] Expanding the sample guard set. We have 1 guards in the sample, and 18 eligible guards to extend it with.
Dec 18 01:10:04.000 [warn] Updated sampled guard  ($C73ADBAC8ADFDBF0FC0F3F4E8091C0107D093716): filtered=1; reachable_filtered=1.
Dec 18 01:10:04.000 [warn] Updated sampled guard  ($752CF7825B3B9EA6A98C83AC41F7099D67007EA5): filtered=1; reachable_filtered=1.
Dec 18 01:10:04.000 [warn] tor_bug_occurred_(): Bug: src/or/entrynodes.c:816: entry_guard_add_to_sample_impl: Non-fatal assertion !(have_sampled
_guard_with_id(gs, rsa_id_digest)) failed. (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug: Non-fatal assertion !(have_sampled_guard_with_id(gs, rsa_id_digest)) failed in entry_guard_add_to_sample_impl at
 src/or/entrynodes.c:816. Stack trace: (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /usr/lib/x86_64-linux-gnu/libasan.so.1(backtrace+0x3a) [0x7f0cde5be48a] (on Tor 0.3.0.0-alpha-dev 8b75261b6d
c341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(log_backtrace+0x46) [0x7f0cdff74dc6] (on Tor 0.3.0.0-al
pha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(tor_bug_occurred_+0x12f) [0x7f0cdffc4c1f] (on Tor 0.3.0
.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x8a249a) [0x7f0cdff2f49a] (on Tor 0.3.0.0-alpha-dev 8
b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x8a3b5c) [0x7f0cdff30b5c] (on Tor 0.3.0.0-alpha-dev 8
b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x8a500f) [0x7f0cdff3200f] (on Tor 0.3.0.0-alpha-dev 8
b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(entry_guards_update_all+0x10f0) [0x7f0cdff379e0] (on To
r 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(guards_update_all+0x83) [0x7f0cdff43cc3] (on Tor 0.3.0.
0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(set_options+0x62af) [0x7f0cdfe2521f] (on Tor 0.3.0.0-al
pha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(options_trial_assign+0xb3) [0x7f0cdfe28693] (on Tor 0.3
.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x803aff) [0x7f0cdfe90aff] (on Tor 0.3.0.0-alpha-dev 8
b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(connection_control_process_inbuf+0xdcd) [0x7f0cdfe9df9d
] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x7cb938) [0x7f0cdfe58938] (on Tor 0.3.0.0-alpha-dev 8
b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x56f716) [0x7f0cdfbfc716] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/libevent-2.0.so.5(event_base_loop+0x937) [0x7f0cdde408d7] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(do_main_loop+0x385) [0x7f0cdfbfe535] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(tor_main+0x1385) [0x7f0cdfc03385] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(main+0x1c) [0x7f0cdfbf16dc] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5) [0x7f0cdc098b45] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x56665b) [0x7f0cdfbf365b] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn]   (After filters [b], we have 2 guards to consider.)
Dec 18 01:10:04.000 [warn]   (Selected  ($752CF7825B3B9EA6A98C83AC41F7099D67007EA5).)
Dec 18 01:10:04.000 [warn] Trying to sample a reachable guard: We know of 2 in the USABLE_FILTERED set.
Dec 18 01:10:04.000 [warn]   (That isn't enough. Trying to expand the sample.)
Dec 18 01:10:04.000 [warn] Expanding the sample guard set. We have 3 guards in the sample, and 14 eligible guards to extend it with.
Dec 18 01:10:04.000 [warn] Updated sampled guard  ($A832D176ECD5C7C6B58825AE22FC4C90FA249637): filtered=1; reachable_filtered=1.
Dec 18 01:10:04.000 [warn] tor_bug_occurred_(): Bug: src/or/entrynodes.c:816: entry_guard_add_to_sample_impl: Non-fatal assertion !(have_sampled_guard_with_id(gs, rsa_id_digest)) failed. (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug: Non-fatal assertion !(have_sampled_guard_with_id(gs, rsa_id_digest)) failed in entry_guard_add_to_sample_impl at src/or/entrynodes.c:816. Stack trace: (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /usr/lib/x86_64-linux-gnu/libasan.so.1(backtrace+0x3a) [0x7f0cde5be48a] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(log_backtrace+0x46) [0x7f0cdff74dc6] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(tor_bug_occurred_+0x12f) [0x7f0cdffc4c1f] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x8a249a) [0x7f0cdff2f49a] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x8a3b5c) [0x7f0cdff30b5c] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x8a500f) [0x7f0cdff3200f] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(entry_guards_update_all+0x10f0) [0x7f0cdff379e0] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(guards_update_all+0x83) [0x7f0cdff43cc3] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(set_options+0x62af) [0x7f0cdfe2521f] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(options_trial_assign+0xb3) [0x7f0cdfe28693] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x803aff) [0x7f0cdfe90aff] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(connection_control_process_inbuf+0xdcd) [0x7f0cdfe9df9d] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x7cb938) [0x7f0cdfe58938] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x56f716) [0x7f0cdfbfc716] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/libevent-2.0.so.5(event_base_loop+0x937) [0x7f0cdde408d7] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(do_main_loop+0x385) [0x7f0cdfbfe535] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(tor_main+0x1385) [0x7f0cdfc03385] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(main+0x1c) [0x7f0cdfbf16dc] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5) [0x7f0cdc098b45] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x56665b) [0x7f0cdfbf365b] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn]   (After filters [b], we have 2 guards to consider.)
Dec 18 01:10:04.000 [warn]   (Selected  ($C73ADBAC8ADFDBF0FC0F3F4E8091C0107D093716).)
Dec 18 01:10:04.000 [warn] Trying to sample a reachable guard: We know of 3 in the USABLE_FILTERED set.
Dec 18 01:10:04.000 [warn]   (That isn't enough. Trying to expand the sample.)
Dec 18 01:10:04.000 [warn] Expanding the sample guard set. We have 4 guards in the sample, and 11 eligible guards to extend it with.
Dec 18 01:10:04.000 [warn] Updated sampled guard  ($FE7840FE1E21FE0A0639ED176EDA00A3ECA1E34D): filtered=1; reachable_filtered=1.
Dec 18 01:10:04.000 [warn] Updated sampled guard  ($8FB9F4319E89E5C6223052AA525A192AFBC85D55): filtered=1; reachable_filtered=1.
Dec 18 01:10:04.000 [warn] Updated sampled guard  ($00DC6C4FA49A65BD1472993CF6730D54F11E0DBB): filtered=1; reachable_filtered=1.
Dec 18 01:10:04.000 [warn] Updated sampled guard  ($BBB28DF0F201E706BE564EFE690FE9577DD8386D): filtered=1; reachable_filtered=1.
Dec 18 01:10:04.000 [warn] tor_bug_occurred_(): Bug: src/or/entrynodes.c:816: entry_guard_add_to_sample_impl: Non-fatal assertion !(have_sampled_guard_with_id(gs, rsa_id_digest)) failed. (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug: Non-fatal assertion !(have_sampled_guard_with_id(gs, rsa_id_digest)) failed in entry_guard_add_to_sample_impl at src/or/entrynodes.c:816. Stack trace: (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /usr/lib/x86_64-linux-gnu/libasan.so.1(backtrace+0x3a) [0x7f0cde5be48a] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(log_backtrace+0x46) [0x7f0cdff74dc6] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(tor_bug_occurred_+0x12f) [0x7f0cdffc4c1f] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x8a249a) [0x7f0cdff2f49a] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x8a3b5c) [0x7f0cdff30b5c] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x8a500f) [0x7f0cdff3200f] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(entry_guards_update_all+0x10f0) [0x7f0cdff379e0] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(guards_update_all+0x83) [0x7f0cdff43cc3] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(set_options+0x62af) [0x7f0cdfe2521f] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(options_trial_assign+0xb3) [0x7f0cdfe28693] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x803aff) [0x7f0cdfe90aff] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(connection_control_process_inbuf+0xdcd) [0x7f0cdfe9df9d] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x7cb938) [0x7f0cdfe58938] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x56f716) [0x7f0cdfbfc716] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/libevent-2.0.so.5(event_base_loop+0x937) [0x7f0cdde408d7] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(do_main_loop+0x385) [0x7f0cdfbfe535] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(tor_main+0x1385) [0x7f0cdfc03385] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(main+0x1c) [0x7f0cdfbf16dc] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5) [0x7f0cdc098b45] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn] Bug:     /home/f/tor-browser_en-US/Browser/TorBrowser/Tor/tor(+0x56665b) [0x7f0cdfbf365b] (on Tor 0.3.0.0-alpha-dev 8b75261b6dc341de)
Dec 18 01:10:04.000 [warn]   (After filters [b], we have 5 guards to consider.)
Dec 18 01:10:04.000 [warn]   (Selected  ($00DC6C4FA49A65BD1472993CF6730D54F11E0DBB).)
Dec 18 01:10:04.000 [warn] Primary entry guards have changed. New primary guard list is: 
Dec 18 01:10:04.000 [warn]   1/3:  ($752CF7825B3B9EA6A98C83AC41F7099D67007EA5)
Dec 18 01:10:04.000 [warn]   2/3:  ($C73ADBAC8ADFDBF0FC0F3F4E8091C0107D093716)
Dec 18 01:10:04.000 [warn]   3/3:  ($00DC6C4FA49A65BD1472993CF6730D54F11E0DBB)
Dec 18 01:10:04.000 [notice] Tor 0.3.0.0-alpha-dev (git-8b75261b6dc341de) opening log file.
Dec 18 01:10:04.000 [notice] Tor 0.3.0.0-alpha-dev (git-8b75261b6dc341de) opening log file.
Dec 18 01:10:04.000 [notice] Tor 0.3.0.0-alpha-dev (git-8b75261b6dc341de) opening log file.
Dec 18 01:10:05.000 [notice] Delaying directory fetches: No running bridges
Dec 18 01:10:05.000 [notice] new bridge descriptor 'noether' (fresh): $7B126FAB960E5AC6A629C729434FF84FB5074EC2~noether at 192.99.11.54
Dec 18 01:10:05.000 [warn] Staying with guard context "bridges" (no change)

comment:2 Changed 5 months ago by nickm

  • Owner set to nickm
  • Status changed from new to accepted

comment:3 Changed 5 months ago by nickm

Staying with guard context "bridges" (no change)

So this is with bridges, and we're calling entry_guard_add_bridge_to_sample().

comment:4 Changed 5 months ago by nickm

Were you using bridges here? Regular bridges, or using nodes as bridges?

Was your controller doing something to your guard options, or your list of bridges?

comment:5 Changed 5 months ago by nickm

  • Keywords regression added
  • Points set to 1
  • Priority changed from Medium to High

(Assigning points as a wild guess here -- bug-hunting can be unpredictable.)

comment:6 Changed 5 months ago by asn

OK, did some log digging to get answers to these questions.

Yes, I was using bridges.

I think this error occured when I switched from using 1 private bridge, to using the default tor browser bridges. I did the switch using the tor browser options dialog, so I assume that it HUPed Tor when the change happened.

As you can see in the log above, my private bridge ($160228DC...) got marked as non-filtered (because it was not on torrc anymore), and the regular tor browser bridges were about to get sampled, and then the error occured.

(FWIW, I tried to reproduce the above switching behavior just now, but I didn't get the error.)

Last edited 5 months ago by asn (previous) (diff)

comment:7 follow-up: Changed 5 months ago by nickm

For all of the Bridge lines, did you specify IDs, or did you specify any of them with an address only?

comment:8 Changed 5 months ago by nickm

"We have 4 guards in the sample, and 11 eligible guards to extend it with." I wonder how that's possible if there were only 4 Bridge lines configured here...

Is TorBrowser maybe doing stuff to add or remove Bridge lines?

comment:9 in reply to: ↑ 7 Changed 5 months ago by asn

Replying to nickm:

For all of the Bridge lines, did you specify IDs, or did you specify any of them with an address only?

I'm pretty sure all bridge lines had both address and identity fingerprint.

It wouldn't surprise me if Tor browser is doing controlport stuff to add or remove bridge lines.

I'm currently doing testing with no bridges, but maybe I should go back to testing bridges.

comment:10 Changed 4 months ago by nickm

  • Status changed from accepted to needs_information

Information needed: Can this still happen, or was it from an old version of the branch?

comment:11 Changed 4 months ago by asn

  • Milestone changed from Tor: 0.3.0.x-final to Tor: unspecified

Let's triage this out of 0.3.0, I couldn't reproduce this issue with master.
Needs more testing to see if the bug is still here.

comment:12 Changed 4 months ago by gk

  • Cc bo0od added

This happens with 0.3.0.2-alpha in a Tor Browser context still it seems, see #21391 which seems to be a duplicate. See especially the logs there.

comment:13 Changed 4 months ago by nickm

  • Milestone changed from Tor: unspecified to Tor: 0.3.0.x-final

comment:14 Changed 4 months ago by nickm

  • Status changed from needs_information to assigned

comment:15 Changed 3 months ago by nickm

Hm, still a bit confusing. Let's think.

We're reaching entry_guard_add_to_sample_impl() with an RSA id that's already a sampled guard in gs.

So therefore (assuming that we're handling bridges right [1]) we're calling entry_guard_add_bridge_to_sample() with a bridge whose bridge_get_rsa_id_digest() is giving us an id we already have.

That, in turn, implies that select_and_add_guard_item_for_sample() chose that bridge.

And that in turn implies that get_eligible_guards() gave it to us as a possibility.

But that implies that get_sampled_guard_for_bridge gave us NULL for that guard, which shouldn't be possible if we already know a bridge with that ID.

comment:16 follow-up: Changed 3 months ago by nickm

  • Status changed from assigned to needs_review

Oh. Now I think I get it. There's a possibility that the same bridge is listed twice among our bridges in bridge_list_get(). If that happens, if we go to add two bridges at a time for some reason, we'll add that bridge twice.

Does my branch bug21027_testing branch make this bug go away? Or does it change the warning at all?

comment:17 in reply to: ↑ 16 Changed 3 months ago by asn

Replying to nickm:

Oh. Now I think I get it. There's a possibility that the same bridge is listed twice among our bridges in bridge_list_get(). If that happens, if we go to add two bridges at a time for some reason, we'll add that bridge twice.

Does my branch bug21027_testing branch make this bug go away? Or does it change the warning at all?

I think this is a good hypothesis!

I managed to reproduce this non-fatal assert by using the following three Bridge lines in my Tor Browser (which are actually the same underlying bridge with different PTs):

obfs3 83.212.101.3:80 A09D536DD1752D542E1FBB3C9CE4449D51298239
scramblesuit 83.212.101.3:443 A09D536DD1752D542E1FBB3C9CE4449D51298239 password=XTCXLG2JAMJKZW2POLBAOWOQETQSMASH
obfs4 83.212.101.3:50000 A09D536DD1752D542E1FBB3C9CE4449D51298239 cert=lPRQ/MXdD1t5SRZ9MquYQNT9m5DV757jtdXdlePmRCudUU9CFUOX1Tm7/meFSyPOsud7Cw iat-mode=0

I can confirm that your patch silences the non-fatal assert, but I wonder if it implements the right behavior. What does a user expect by putting the above lines in their torrc?

IMO a user would expect that each of those three Bridge lines will be treated as a separate entry guard and get sampled; whereas I think your patch will only add one of them to the sampled set.

comment:18 Changed 3 months ago by nickm

IMO a user would expect that each of those three Bridge lines will be treated as a separate entry guard and get sampled; whereas I think your patch will only add one of them to the sampled set.

Oh hm wow that's hard. The current guard system really assumes that there is at most one guard per identity. I'll have to think about design there.

comment:19 Changed 3 months ago by nickm

Further investigation:

Fortunately, there aren't any ID->guard maps in the data structures. The exported entry_guard_get_by_id_digest*() function, though, _does_ assume that "the guard with a given RSA ID" is a well-specified concept. Nothing outside of circpathbias.c uses it, however.

The get_sampled_guard_with_id() function (which appears to do the same thing!) is used by have_sampled_guard_with_id() and by get_sampled_guard_for_bridge().

So I think the right answer here is to just back off on the assumption that RSA IDs are unique by bridges. But we'll need to have a better notion for bridge equality, and other improved functions. Hmmmm.

comment:20 Changed 3 months ago by nickm

  • Status changed from needs_review to needs_revision

comment:21 Changed 3 months ago by nickm

  • Status changed from needs_revision to needs_review

Okay, how about this branch here: bug21027_v2

I think it removes the few places where I'd assumed that multiple bridge_info_t instances shouldn't share an ID.

comment:22 Changed 3 months ago by dgoulet

  • Status changed from needs_review to needs_revision

Let me try to figure this one:

 * [...] but tolerate a bridge with
 * an unknown digest if the digest is provided. */

If digest is provided, we want to "tolerate" or I guess return a bridge that matches addr/port *if* that bridge doesn't match the given digest? (the unknown is confusing, is it unset or just doesn't match the given digest?)

Shouldn't that comment look like this in some "pseudo code" which seems very weird:

if (digest && bridge->identity != digest)) {
  return bridge;
}

I would improve documentation on that function because it doesn't actually explain the "closest" in the function name nor what it actually does clearly.

comment:23 Changed 3 months ago by nickm

  • Keywords review-group-16 added

comment:24 Changed 3 months ago by cypherpunks

What does a user expect by putting the above lines in their torrc?

I have completely distinct Bridge lines in torrc, but new bridge descriptor for a single Bridge line in torrc reoccurs in log. Already (cached) bridge descriptors still get (fresh) duplicates.

Edit: This happens in 0.2.9.9 too.

Last edited 3 months ago by cypherpunks (previous) (diff)

comment:25 Changed 3 months ago by asn

Hello, as I said also in IRC, I think that the provided patch addresses the issue. I tested this on my Tor Browser with the bridges from comment:17 and I verified that they are all treated as separate bridges indeed, and they get sampled to SAMPLED_GUARDS properly.

That said, I agree with the comments of David about the code/comment quality:

  • The function documentation for get_closest_configured_bridge_by_addr_port_digest() seems to be incomplete and incorrect. What does tolerate mean? Does it actualy tolerate a bridge with an unknown digest if the digest is provided? I don't see this in the code. Also, if anything, the new function seems less tolerable than the old one in general.

Also, is that the important difference of this new function for our purposes? IIUC, the important part for us is that it will only return a bridge if the addrport really matches; whereas the old get_configured_bridge_by_addr_port_digest() would return a bridge that matches the digest even if the addrport was completely different. Is that what you tried to express in the comment? Can we perhaps make it more clear?

  • Also, as David said, get_closest_configured_bridge_by_addr_port_digest() is kind of an ambiguous name. Can we clarify it? I couldn't think of a better name; these two functions are quite similar semantically with some small esoteric differences.

Alternatively, could we merge these two functions together and use a func argument to disambiguate?

All in all the patch seems good with regards to functionality, but perhaps we should take care of the above to improve code quality and maintainability.

comment:26 follow-up: Changed 3 months ago by nickm

  • Status changed from needs_revision to needs_review

Thanks for the reviews! I've tried to improve the documentation and function name in a fixup commit.

comment:27 Changed 3 months ago by nickm

  • Reviewer set to asn

comment:28 in reply to: ↑ 26 Changed 3 months ago by asn

  • Status changed from needs_review to merge_ready

Replying to nickm:

Thanks for the reviews! I've tried to improve the documentation and function name in a fixup commit.

Looks good to me. Let's get this merged.

comment:29 Changed 3 months ago by nickm

  • Resolution set to fixed
  • Status changed from merge_ready to closed

Thanks for all the reviews! Squashed as bug21027_v2_squashed and merged!

Note: See TracTickets for help on using tickets.