tor_bug_occurred_(): Bug: ../src/feature/nodelist/microdesc.c:494: warn_if_nul_found: Non-fatal assertion !(nul_found) failed. (on Tor 0.4.0.5) [also on 0.4.5.8]

changed milestone to %Tor: unspecified in legacy/trac

added 042-should in Legacy / Trac assert in Legacy / Trac component::core tor/tor in Legacy / Trac microdesc in Legacy / Trac milestone::Tor: unspecified in Legacy / Trac priority::medium in Legacy / Trac reporter::computer_freak in Legacy / Trac severity::normal in Legacy / Trac status::new in Legacy / Trac type::defect in Legacy / Trac labels

Trac:
Milestone: N/A to Tor: 0.4.2.x-final

Trac:
Keywords: N/A deleted, microdesc assert added
Component: Core Tor to Core Tor/Tor

Trac:
Keywords: microdesc assert deleted, microdesc assert crash added

Trac:
Keywords: microdesc assert crash deleted, microdesc assert added

Trac:
Keywords: microdesc assert deleted, microdesc assert 042-should added

Distributing 0.4.2 tickets between network team members.

Trac:
Owner: N/A to nickm
Status: new to assigned

I haven't been able to figure this out beyond what's already on legacy/trac#31683 (moved). None of my hypotheses there turned out to be supported by the code.

Trac:
Milestone: Tor: 0.4.2.x-final to Tor: unspecified

Trac:
Owner: nickm to N/A

Trac:
Status: assigned to new

mentioned in issue legacy/trac#31683 (moved)

moved from legacy/trac#31364 (moved)

added Bug label and removed 1 deleted label

removed 1 deleted label

removed milestone

Hi. I don't have much details but I received the following warning today:

May 31 20:32:50.000 [warn] tor_bug_occurred_: Bug: src/feature/nodelist/microdesc.c:496: warn_if_nul_found: Non-fatal assertion !(nul_found) failed. (on Tor 0.4.5.8 )
May 31 20:32:50.000 [warn] Bug: Tor 0.4.5.8: Non-fatal assertion !(nul_found) failed in warn_if_nul_found at src/feature/nodelist/microdesc.c:496. Stack trace: (on Tor 0.4.5.8 )
May 31 20:32:50.000 [warn] Bug:     0x130c00c <log_backtrace_impl+0x5c> at /usr/local/bin/tor (on Tor 0.4.5.8 )
May 31 20:32:50.000 [warn] Bug:     0x131a539 <tor_bug_occurred_+0x1d9> at /usr/local/bin/tor (on Tor 0.4.5.8 )
May 31 20:32:50.000 [warn] Bug:     0x1235e27 <microdesc_cache_clear+0x217> at /usr/local/bin/tor (on Tor 0.4.5.8 )
May 31 20:32:50.000 [warn] Bug:     0x1234d9e <microdesc_cache_reload+0xde> at /usr/local/bin/tor (on Tor 0.4.5.8 )
May 31 20:32:50.000 [warn] Bug:     0x1234cb6 <get_microdesc_cache+0xc6> at /usr/local/bin/tor (on Tor 0.4.5.8 )
May 31 20:32:50.000 [warn] Bug:     0x11cc9c2 <nodelist_set_consensus+0x52> at /usr/local/bin/tor (on Tor 0.4.5.8 )
May 31 20:32:50.000 [warn] Bug:     0x11d66a3 <networkstatus_set_current_consensus+0xec3> at /usr/local/bin/tor (on Tor 0.4.5.8 )
May 31 20:32:50.000 [warn] Bug:     0x11d26fb <router_reload_consensus_networkstatus+0xfb> at /usr/local/bin/tor (on Tor 0.4.5.8 )
May 31 20:32:50.000 [warn] Bug:     0x1157c49 <run_tor_main_loop+0x139> at /usr/local/bin/tor (on Tor 0.4.5.8 )
May 31 20:32:50.000 [warn] Bug:     0x1157fec <tor_run_main+0x12c> at /usr/local/bin/tor (on Tor 0.4.5.8 )
May 31 20:32:50.000 [warn] Bug:     0x1156981 <tor_main+0x61> at /usr/local/bin/tor (on Tor 0.4.5.8 )
May 31 20:32:50.000 [warn] Bug:     0x1156639 <main+0x19> at /usr/local/bin/tor (on Tor 0.4.5.8 )
May 31 20:32:50.000 [warn] warn_if_nul_found: Bug: Found unexpected NUL while reading microdesc journal, offset 0at position 1243266/5149801. (on Tor 0.4.5.8 )
May 31 20:32:50.000 [warn] warn_if_nul_found: Bug:       surrounding string: 734353322B4B36733679754569306F0A00000000000000000000000000000000 (on Tor 0.4.5.8 )
May 31 20:32:50.000 [warn] parse error: internal NUL character.
May 31 20:32:50.000 [warn] Unparseable microdescriptor found in journal

I have 4 exit relays that have been running since march 2020. The relays currently run Tor version 0.4.5.8 on FreeBSD 12.2-RELEASE-p7. All 4 servers run the exact same software, and I upgrade/reboot them all at the same time. Still, the warning only happened in one of the relays. When restarting Tor, the warning did not happen again. I have logs for all relays since March 2020, and this is the only occurrence of this warning.

Let me know if there is anything I can do to help.

Thanks for the update! Knowing that this still happens in 0.4.5.8 should make it a little more possible to debug.

Let's see...

Found unexpected NUL while reading microdesc journal, offset 0at position 1243266/5149801
       surrounding string: 734353322B4B36733679754569306F0A00000000000000000000000000000000

The position is 1243266, which is 0x12f882—not terribly suggestive. This "surrounding string" works out to "sCS2+K6s6yuEi0o\n\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00", which looks like the end of a line of base64, followed by some NULs.

Something is wrong with the stack trace: It says that microdesc_cache_clear is in the stack, but that function doesn't call warn_if_nul_found() as far as I can tell. Instead, warn_if_nul_found seems to be getting called from microdesc_cache_reload one level up.

changed milestone to %Tor: 0.4.7.x-freeze

tor_bug_occurred_(): Bug: ../src/feature/nodelist/microdesc.c:494: warn_if_nul_found: Non-fatal assertion !(nul_found) failed. (on Tor 0.4.0.5) [also on 0.4.5.8]

Child items 0

Activity