Page MenuHomePhabricator

whonixcheck false positive in check_journal
Testing in next build required, Needs TriagePublic

Description

whonixcheck reports non-issues:

[WARNING] [whonixcheck] systemd journal check Result:
warnings:
########################################
Jul 21 00:34:59 host kernel: random: 5 urandom warning(s) missed due to ratelimiting
Jul 21 00:34:22 host first-boot-home-population[769]: '/var/cache/tb-binary/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/Crypto/pct_warnings.py' -> '/home/user/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/Crypto/pct_warnings.py'
Jul 21 00:34:32 host first-boot-home-population[769]: '/var/cache/tb-binary/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/trial/test/test_warning.py' -> '/home/user/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/trial/test/test_warning.py'
########################################

errors:
########################################
Jul 21 00:34:54 host kernel: ACPI Error: No handler or method for GPE 00, disabling event (20190215/evgpe-835)
Jul 21 00:34:54 host kernel: ACPI Error: No handler or method for GPE 01, disabling event (20190215/evgpe-835)
Jul 21 00:34:54 host kernel: ACPI Error: No handler or method for GPE 03, disabling event (20190215/evgpe-835)
Jul 21 00:34:54 host kernel: ACPI Error: No handler or method for GPE 04, disabling event (20190215/evgpe-835)
Jul 21 00:34:54 host kernel: ACPI Error: No handler or method for GPE 05, disabling event (20190215/evgpe-835)
Jul 21 00:34:54 host kernel: ACPI Error: No handler or method for GPE 06, disabling event (20190215/evgpe-835)
Jul 21 00:34:54 host kernel: ACPI Error: No handler or method for GPE 07, disabling event (20190215/evgpe-835)
Jul 21 00:34:54 host kernel: RAS: Correctable Errors collector initialized.
Jul 21 00:34:55 host kernel: Error: Driver 'pcspkr' is already registered, aborting...
Jul 21 00:35:03 host apparmor.systemd[476]: Error: Loading AppArmor profiles - failed, Do you have the correct privileges?
Jul 21 00:35:04 host xl[531]: libxl: error: libxl_utils.c:818:libxl_cpu_bitmap_alloc: failed to retrieve the maximum number of cpus
Jul 21 00:34:24 host first-boot-home-population[769]: '/var/cache/tb-binary/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/conch/error.py' -> '/home/user/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/conch/error.py'
Jul 21 00:34:25 host first-boot-home-population[769]: '/var/cache/tb-binary/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/cred/error.py' -> '/home/user/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/cred/error.py'
Jul 21 00:34:25 host first-boot-home-population[769]: '/var/cache/tb-binary/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/internet/error.py' -> '/home/user/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/internet/error.py'
Jul 21 00:34:28 host first-boot-home-population[769]: '/var/cache/tb-binary/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/names/error.py' -> '/home/user/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/names/error.py'
Jul 21 00:34:31 host first-boot-home-population[769]: '/var/cache/tb-binary/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/test/test_error.py' -> '/home/user/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/test/test_error.py'
Jul 21 00:34:32 host first-boot-home-population[769]: '/var/cache/tb-binary/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/test/test_strerror.py' -> '/home/user/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/test/test_strerror.py'
Jul 21 00:34:33 host first-boot-home-population[769]: '/var/cache/tb-binary/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/web/error.py' -> '/home/user/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/web/error.py'
Jul 21 00:34:33 host first-boot-home-population[769]: '/var/cache/tb-binary/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/web/test/test_error.py' -> '/home/user/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/web/test/test_error.py'
Jul 21 00:34:33 host first-boot-home-population[769]: '/var/cache/tb-binary/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/words/protocols/jabber/error.py' -> '/home/user/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/words/protocols/jabber/error.py'
Jul 21 00:34:33 host first-boot-home-population[769]: '/var/cache/tb-binary/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/words/test/test_jabbererror.py' -> '/home/user/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/twisted/words/test/test_jabbererror.py'
Jul 21 00:34:34 host first-boot-home-population[769]: '/var/cache/tb-binary/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/txsocksx/errors.py' -> '/home/user/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/txsocksx/errors.py'
Jul 21 00:34:34 host first-boot-home-population[769]: '/var/cache/tb-binary/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/yaml/error.py' -> '/home/user/.tb/tor-browser/Browser/TorBrowser/Tor/PluggableTransports/yaml/error.py'
########################################

journal keeps metadata about each message, so it's possible to avoid it with journalctl -p err -b (I've added -b to avoid listing messages from previous boot).

Anyway, in normal boot warnings/errors are logged (for example looks like some kernel messages have wrong priority, like ACPI: No IOAPIC entries present logged as an error is perfectly normal and even desirable on Xen PVH without PCI devices). So, I'm considering disabling this check for automated tests. Alternative could be excluding known false positives, but I'm not sure if you want to maintain such a list...

See https://openqa.qubes-os.org/tests/3446/file/whonixcheck-whonixcheck-anon-whonix.log and other files at https://openqa.qubes-os.org/tests/3446#downloads

Details

Impact
Needs Triage

Event Timeline

marmarek created this task.Sun, Jul 21, 3:03 AM
journal keeps metadata about each message, so it's possible to avoid it with `journalctl -p err -b` (I've added `-b` to avoid listing messages from previous boot).

Cool. I will move to be using that soon.

Alternative could be excluding known false positives, but I'm not sure if you want to maintain such a list...

Not really.

I didn't suppose whonixcheck --verbose output to be taken for granted.
Wouldn't want users run it and then ask about it.

whonixcheck "systemd journal check" was only supposed to be manually
glimpsed over as a convenience for advanced users and developers. It's
severity could be lowered to "info" and not causing non-zero exit codes
in any case.

So, I'm considering disabling this check for automated tests.

Does lowering "severity could be lowered to "info" and not causing
non-zero exit codes" + journalctl -p err -b sound like a good solution?

Does lowering "severity could be lowered to "info" and not causing
non-zero exit codes" + `journalctl -p err -b` sound like a good solution?

Yes, makes sense. It would allow to still run the check (and log the
output, for manual check if necessary), while avoiding false positives.

   ## '--priority=0..4'
   ## "emerg" (0), "alert" (1), "crit" (2), "err" (3), "warning" (4)
   journalctl_output="$(sudo --non-interactive /bin/journalctl
--no-pager --priority=0..4 --boot)" || true

Sounds good?

Patrick changed the task status from Open to testing-in-next-build-required.Sun, Jul 21, 6:29 PM

Done in git master.

Sounds good, thanks.