[solved]gzdoom floods /var/log/messages with dbus-daemon msg

[ecko]

freedoom is great, but gzdomm floods /var/log/messages with thousands of identical error messages per second (while the game works perfectly). The messages are not helpful and render /var/log/messages practically impossible to use for other purposes. I could report to upstream gzdoom, but in the meantime I need to reduce the logging level of dbus-daemon. man dbus-daemon says there is --nosyslog option, but how do I configure dbus (openrc) to use it, at least during my gaming sessions?

Code: Select all

Nov 14 00:22:51 ecko dbus-daemon[3414]: [system] Rejected: destination has a full message queue, 0 matched rules; type="error", sender="(unset)" ((bus)) interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.ServiceUnknown" requested_reply="1" destination=":1.93" (uid=1000 pid=15188 comm="/usr/bin/gzdoom -iwad freedoom2.wad " label="kernel")

Per minute of gaming:

Code: Select all

grep -c "Nov 14 00:22:.. ecko dbus-daemon" /var/log/messages
74864

[netfab]

Hi,

I need to reduce the logging level of dbus-daemon. man dbus-daemon says there is --nosyslog option, but how do I configure dbus (openrc) to use it, at least during my gaming sessions?

From /etc/init.d/dbus :

#!/sbin/openrc-run
# Copyright 1999-2019 Gentoo Authors
# Distributed under the terms of the GNU General Public License, v2 or later

extra_started_commands="reload"

description="An IPC message bus daemon"
pidfile="/run/dbus.pid"
command="/usr/bin/dbus-daemon"
command_args="--system"

After you modified command_args, the system bus should be restarted (/etc/init.d/dbus restart), but I don't know if it is possible, it may have side effects. Never tried.

[GuntherDW]

This has (probably) nothing to do with gzdoom, but it seems like this is the issue people are having with the nvidia drivers.
If you've updated to a driver >470.## for some reason their libraries are calling dbus for pretty much every frame rendered using it.

https://forums.developer.nvidia.com/t/b ... ges/192892

There's currently no BGO issue though, but a couple workarounds are listed in that message on the nvidia forums.

If you're not using nvidia drivers (or said version), disregard my messsage.

[ecko]

This has (probably) nothing to do with gzdoom, but it seems like this is the issue people are having with the nvidia drivers.

Totally on spot, I just updated to x11-drivers/nvidia-drivers-495.44.

#!/sbin/openrc-run
# Copyright 1999-2019 Gentoo Authors
# Distributed under the terms of the GNU General Public License, v2 or later

extra_started_commands="reload"

description="An IPC message bus daemon"
pidfile="/run/dbus.pid"
command="/usr/bin/dbus-daemon"
command_args="--system --nosyslog"

I added --nosyslog (as above) and restarted dbus (at which point firefox immediately died).

Thanks for the assistance, I'll mark it as solved and report if something new happens.

[Ionen]

Disabling logs wouldn't stop it from (still) spamming dbus like no tomorrow, I wasn't logging these (so I didn't really notice), but it's certainly there when looking at `dbus-monitor --system` doing like a ~10000+ requests per second on the test I did.

Had a look at the binary patch suggested in the nvidia thread and decided it may be worth adding here (I additionally made a version for the 32bit glcore library which seems to work, it's a very simple jz->jmp workaround).

It's in nvidia-drivers-495.44-r1, tell me if run into any problems.

[GuntherDW]

It doesn't solve it entirely apparently.
Programs like mpv are still logging said message to the syslog apparently so I had to re-enable the black-hole target.

Code: Select all

Nov 19 07:51:58 allison dbus-daemon[2657]: [system] Rejected: destination has a full message queue, 0 matched rules; type="error", sender="(unset)" ((bus)) interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.ServiceUnknown" requested_reply="1" destination=":1.412" (uid=1000 pid=28484 comm="mpv ... !")

I'll rebuild mpv when I get back home today to doublecheck at least.

[Ionen]

It doesn't solve it entirely apparently.
Programs like mpv are still logging said message to the syslog apparently so I had to re-enable the black-hole target..

Odd, I tried with mpv (tried opengl and vulkan output) and I don't get this.

It does make 1 request to check if service exists, but stops there.

This is with >=495.44-r1, right? All applications also need to be restarted if you didn't reboot so they use the new libnvidia-glcore.so (maybe Xorg as well for glx module, which may explain mpv despite freshly started).

If did restart everything, then I don't know Do hope nvidia will have a proper fix next version -- alternatively could stick to stable drivers for now (10000+ requests / second feel silly even to a black-hole).

[GuntherDW]

Yes, multiple reboots even.

You have enabled hwdec, right?

I'm currently using mpv 0.34 and your 495.44-r1 fix (entirely new kernel from the old one even).

Code: Select all

Portage 3.0.28 (python 3.9.9-final-0, default/linux/amd64/17.1/desktop/plasma, gcc-11.2.0, glibc-2.34-r2, 5.15.2-gentoo x86_64)
=================================================================
                         System Settings
=================================================================
System uname: Linux-5.15.2-gentoo-x86_64-AMD_Ryzen_7_3700X_8-Core_Processor-with-glibc2.34
KiB Mem:    32893456 total,    234776 free
KiB Swap:   16777208 total,  10390776 free
Timestamp of repository gentoo: Tue, 16 Nov 2021 07:06:39 +0000
Head commit of repository gentoo: 4b8ae29d10a9c48b2f7334013d1a2dad0691ef97

Head commit of repository steam-overlay: bcdf7b7b1ffb3058a0d924e849a5abf18f364d9c

sh bash 5.1_p8
ld GNU ld (Gentoo 2.37_p1 p1) 2.37
distcc 3.4 x86_64-pc-linux-gnu [disabled]
app-shells/bash:          5.1_p8::gentoo
dev-java/java-config:     2.3.1::gentoo
dev-lang/perl:            5.34.0-r5::gentoo
dev-lang/python:          2.7.18_p13::gentoo, 3.9.9::gentoo, 3.10.0_p1::gentoo
dev-lang/rust:            1.56.1::gentoo
dev-util/cmake:           3.21.4::gentoo
sys-apps/baselayout:      2.8::gentoo
sys-apps/openrc:          0.44.8::gentoo
sys-apps/sandbox:         2.29::gentoo
sys-devel/autoconf:       2.13-r1::gentoo, 2.71-r1::gentoo
sys-devel/automake:       1.13.4-r2::gentoo, 1.16.5::gentoo
sys-devel/binutils:       2.37_p1-r1::gentoo
sys-devel/gcc:            11.2.0::gentoo
sys-devel/gcc-config:     2.4::gentoo
sys-devel/libtool:        2.4.6-r6::gentoo
sys-devel/make:           4.3::gentoo
sys-kernel/linux-headers: 5.15::gentoo (virtual/os-headers)
sys-libs/glibc:           2.34-r2::gentoo
Repositories:

gentoo
    location: /mnt/scratch/portage/repos/gentoo-git
    sync-type: git
    sync-uri: https://github.com/gentoo-mirror/gentoo
    priority: -1000
    sync-git-verify-commit-signature: true

guntherdw
    location: /mnt/scratch/portage/overlays/own-overlay
    masters: gentoo
    priority: 50

steam-overlay
    location: /mnt/scratch/portage/overlays/steam-overlay
    sync-type: git
    sync-uri: https://github.com/anyc/steam-overlay.git
    masters: gentoo
    priority: 50

ACCEPT_KEYWORDS="amd64 ~amd64"
ACCEPT_LICENSE="*"
CBUILD="x86_64-pc-linux-gnu"
CFLAGS="-O2 -pipe -march=native"
CHOST="x86_64-pc-linux-gnu"
CONFIG_PROTECT="/etc /usr/share/config /usr/share/gnupg/qualified.txt /usr/share/maven-bin-3.8/conf"
CONFIG_PROTECT_MASK="/etc/ca-certificates.conf /etc/dconf /etc/env.d /etc/fonts/fonts.conf /etc/gconf /etc/gentoo-release /etc/revdep-rebuild /etc/sandbox.d /etc/terminfo"
CXXFLAGS="-O2 -pipe -march=native"
DISTDIR="/var/cache/distfiles"
ENV_UNSET="CARGO_HOME DBUS_SESSION_BUS_ADDRESS DISPLAY GOBIN GOPATH PERL5LIB PERL5OPT PERLPREFIX PERL_CORE PERL_MB_OPT PERL_MM_OPT XAUTHORITY XDG_CACHE_HOME XDG_CONFIG_HOME XDG_DATA_HOME XDG_RUNTIME_DIR"
FCFLAGS="-O2 -pipe -march=native"
FEATURES="assume-digests binpkg-docompress binpkg-dostrip binpkg-logs binpkg-multi-instance buildpkg config-protect-if-modified distlocks ebuild-locks fixlafiles ipc-sandbox merge-sync multilib-strict network-sandbox news parallel-fetch pid-sandbox preserve-libs protect-owned qa-unresolved-soname-deps sandbox sfperms strict unknown-features-warn unmerge-logs unmerge-orphans userfetch userpriv usersandbox usersync xattr"
FFLAGS="-O2 -pipe -march=native"
GENTOO_MIRRORS="https://mirror.erickochen.nl/gentoo/ http://gentoo.mirror.root.lu/ https://ftp.snt.utwente.nl/pub/os/linux/gentoo/ https://mirror.leaseweb.com/gentoo/"
LANG="en_GB.utf8"
LDFLAGS="-Wl,-O1 -Wl,--as-needed"
MAKEOPTS="-j16 -l15"
PKGDIR="/var/cache/binpkgs"
PORTAGE_CONFIGROOT="/"
PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --omit-dir-times --compress --force --whole-file --delete --stats --human-readable --timeout=180 --exclude=/distfiles --exclude=/local --exclude=/packages --exclude=/.git"
PORTAGE_TMPDIR="/mnt/scratch/portage/tmp/"
USE="X a52 aac acl acpi activities alsa amd64 apng bluetooth bluray branding bzip2 cairo cdda cdr cli crypt cups dbus declarative dri dri3 dts dvd dvdr egl elogind emboss encode exif flac fluidsynth fortran gdbm gif gpm gtk gui iconv icu imagemagick ipv6 jpeg kde kipi kwallet lcms libglvnd libnotify libtirpc lm_sensors lz4 mad midi mikmod mms mng mod mp3 mp4 mpeg multilib ncurses nfs nls nptl ofono ogg openal opencl opengl openmp pam pango pcre pdf pipewire plasma plymouth png policykit postproc ppds pulseaudio qml qt5 readline screencast sdl seccomp semantic-desktop spell split-usr ssl sslv3 startup-notification svg tiff truetype udev udisks unicode upower usb v4l v4l2 vaapi vdpau vorbis vulkan wayland webp widgets wifi wxwidgets x264 xattr xcb xdg xinerama xkb xml xv xvid zlib zstd" ABI_X86="64" ADA_TARGET="gnat_2019" APACHE2_MODULES="authn_core authz_core socache_shmcb unixd actions alias auth_basic authn_alias authn_anon authn_dbm authn_default authn_file authz_dbm authz_default authz_groupfile authz_host authz_owner authz_user autoindex cache cgi cgid dav dav_fs dav_lock deflate dir disk_cache env expires ext_filter file_cache filter headers include info log_config logio mem_cache mime mime_magic negotiation rewrite setenvif speling status unique_id userdir usertrack vhost_alias" CALLIGRA_FEATURES="karbon sheets words" COLLECTD_PLUGINS="df interface irq load memory rrdtool swap syslog" CPU_FLAGS_X86="aes avx avx2 f16c fma3 mmx mmxext pclmul popcnt sha sse sse2 sse3 sse4_1 sse4_2 sse4a ssse3" ELIBC="glibc" GPSD_PROTOCOLS="ashtech aivdm earthmate evermore fv18 garmin garmintxt gpsclock greis isync itrax mtk3301 nmea ntrip navcom oceanserver oldstyle oncore rtcm104v2 rtcm104v3 sirf skytraq superstar2 timing tsip tripmate tnt ublox ubx" INPUT_DEVICES="libinput" KERNEL="linux" LCD_DEVICES="bayrad cfontz cfontz633 glk hd44780 lb216 lcdm001 mtxorb ncurses text" LIBREOFFICE_EXTENSIONS="presenter-console presenter-minimizer" LLVM_TARGETS="BPF NVPTX" LUA_SINGLE_TARGET="lua5-1" LUA_TARGETS="lua5-1" OFFICE_IMPLEMENTATION="libreoffice" PHP_TARGETS="php7-3 php7-4" POSTGRES_TARGETS="postgres12 postgres13" PYTHON_SINGLE_TARGET="python3_9" PYTHON_TARGETS="python3_9" QEMU_SOFTMMU_TARGETS="aarch64 alpha arm cris hppa i386 lm32 m68k microblaze microblazeel mips mips64 mips64el mipsel moxie nios2 or1k ppc ppc64 riscv32 riscv64 s390x sh4 sh4eb sparc sparc64 tricore unicore32 x86_64 xtensa xtensaeb" QEMU_USER_TARGETS="aarch64 aarch64_be alpha arm armeb cris hppa i386 m68k microblaze microblazeel mips mips64 mips64el mipsel mipsn32 mipsn32el nios2 or1k ppc ppc64 ppc64abi32 ppc64le riscv32 riscv64 s390x sh4 sh4eb sparc sparc32plus sparc64 tilegx x86_64 xtensa xtensaeb" RUBY_TARGETS="ruby30" USERLAND="GNU" VIDEO_CARDS="nvidia" XTABLES_ADDONS="quota2 psd pknock lscan length2 ipv4options ipset ipp2p iface geoip fuzzy condition tee tarpit sysrq proto steal rawnat logmark ipmark dhcpmac delude chaos account"
Unset:  CC, CPPFLAGS, CTARGET, CXX, EMERGE_DEFAULT_OPTS, INSTALL_MASK, LC_ALL, LINGUAS, PORTAGE_BINHOST, PORTAGE_BUNZIP2_COMMAND, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS, PORTAGE_RSYNC_EXTRA_OPTS, RUSTFLAGS

=================================================================
                        Package Settings
=================================================================

media-video/mpv-0.34.0::gentoo was built with the following:
USE="X alsa archive bluray cdda cli cplugins cuda doc dvd egl gamepad iconv jpeg lcms libmpv lua openal opengl pulseaudio sdl tools uchardet vaapi vdpau wayland xv zlib (-aqua) (-coreaudio) -debug -drm -dvb -gbm -jack -javascript -libcaca (-raspberry-pi) -rubberband (-selinux) -test -vulkan -zimg" ABI_X86="(64)" LUA_SINGLE_TARGET="luajit -lua5-1" PYTHON_TARGETS="python3_9 -python3_8"
FEATURES="binpkg-docompress fixlafiles preserve-libs unmerge-orphans binpkg-multi-instance assume-digests buildpkg ipc-sandbox merge-sync network-sandbox xattr binpkg-dostrip sfperms parallel-fetch userfetch binpkg-logs userpriv sandbox news usersync usersandbox multilib-strict protect-owned strict unmerge-logs config-protect-if-modified unknown-features-warn pid-sandbox qa-unresolved-soname-deps distlocks ebuild-locks"

And yes, I know that mirror is down and I should remove it from my mirror list, I just haven't as of yet.

EDIT: Checking dbus-monitor, having hwdec disabled still trigger it apparently. I might just have to rebuild mpv I guess.
I have "gpu" set as video output, which is essentially the old opengl-hq I think?

EDIT2: Having rebuilt mpv with the vulkan USE flag enabled (was disabled apparently due to issues with libplacebo on my machine) and there's no difference really. Either the nvidia libs weren't patched correctly on my end or something else is at play. I'll attempt to figure it out.

[Ionen]

EDIT: Checking dbus-monitor, having hwdec disabled still trigger it apparently. I might just have to rebuild mpv I guess.
I have "gpu" set as video output, which is essentially the old opengl-hq I think?

EDIT2: Having rebuilt mpv with the vulkan USE flag enabled (was disabled apparently due to issues with libplacebo on my machine) and there's no difference really. Either the nvidia libs weren't patched correctly on my end or something else is at play. I'll attempt to figure it out.

vulkan doesn't get used by default, needs --gpu-api=vulkan on top of --vo=gpu (this is what I use usually, but I went back to opengl to try it -- tried cuda as well but dbus was still fine).

That aside, rebuilding doesn't matter, nothing is directly built against that library (it's dynamically loaded at runtime). If it works should still see a request in `dbus-monitor --system` but not a very fast endless flood of it.

Can't exclude something might have went wrong with the patching, libraries should be:

Code: Select all

# patched:
$ md5sum /usr/lib{,64}/libnvidia-glcore.so.495.44
57290338692e3c384e09cc1646dae3ab  /usr/lib/libnvidia-glcore.so.495.44
f246a765c1be60e773a04ce0d672ce5f  /usr/lib64/libnvidia-glcore.so.495.44
# original:
$ md5sum {32/,}libnvidia-glcore.so.495.44
208eee9f2a46466fff62f88a1011e733  32/libnvidia-glcore.so.495.44
55608a4a1da00088d019dfffbf4de4fe  libnvidia-glcore.so.495.44

That aside patch may not be considering every possibilities, maybe hitting a different code path due to some setting or another (I did try on two rather different systems, but that's about it).

No need for you to waste time on this anyhow, this is all just a temporary measure until nvidia fix it. Just keep the black-hole if it works for you meanwhile.

[GuntherDW]

Just checked and yes, the files on my system are the patched ones.

I was just trying to rule out a couple things, no worry

Code: Select all

guntherdw /v/log λ md5sum /usr/lib{,64}/libnvidia-glcore.so.495.44 
57290338692e3c384e09cc1646dae3ab  /usr/lib/libnvidia-glcore.so.495.44
f246a765c1be60e773a04ce0d672ce5f  /usr/lib64/libnvidia-glcore.so.495.44

So it either is something in my config indeed or something else. Maybe a stray lib somewhere or something?
And yes, dbus-monitor (and thus /var/log/messages) is still receiving a flood of messages if I don't black-hole it.

The only custom things I have in my mpv config besides those USE flags is that it prefers dav1d for AV1, cache/screenshot settings and hwdec set to auto.
And I can confirm that using -vo vdpau doesn't send dbus flying while -vo gpu does. -vo gpu with --gpu-api=vulkan does not however.
There is a couple things that pop up though in "dbus-monitor --system" besides the spam.
It is possible that it also happens with opengl but I can't tell with how spammy the output is normally.

Note: I still have that powerd dbus config "installed", should I disable/delete it?

Code: Select all

method call time=1637327163.055523 sender=:1.686 -> destination=org.freedesktop.DBus serial=1 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=Hello
method return time=1637327163.055533 sender=org.freedesktop.DBus -> destination=:1.686 serial=1 reply_serial=1
   string ":1.686"
signal time=1637327163.055538 sender=org.freedesktop.DBus -> destination=(null destination) serial=1346 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged
   string ":1.686"
   string ""
   string ":1.686"
signal time=1637327163.055544 sender=org.freedesktop.DBus -> destination=:1.686 serial=2 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameAcquired
   string ":1.686"
method call time=1637327163.055658 sender=:1.686 -> destination=org.freedesktop.DBus serial=2 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=RequestName
   string "nvidia.powerd.client"
   uint32 2
error time=1637327163.055662 sender=org.freedesktop.DBus -> destination=:1.686 error_name=org.freedesktop.DBus.Error.AccessDenied reply_serial=2
   string "Connection ":1.686" is not allowed to own the service "nvidia.powerd.client" due to security policies in the configuration file"
method call time=1637327163.080256 sender=:1.686 -> destination=org.freedesktop.DBus serial=3 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=RequestName
   string "nvidia.powerd.client"
   uint32 2
error time=1637327163.080270 sender=org.freedesktop.DBus -> destination=:1.686 error_name=org.freedesktop.DBus.Error.AccessDenied reply_serial=3
   string "Connection ":1.686" is not allowed to own the service "nvidia.powerd.client" due to security policies in the configuration file"
signal time=1637327163.812689 sender=org.freedesktop.DBus -> destination=:1.686 serial=96 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameLost
   string ":1.686"
signal time=1637327163.812712 sender=org.freedesktop.DBus -> destination=(null destination) serial=1347 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged
   string ":1.686"
   string ":1.686"
   string ""

[Ionen]

For a follow up on this, this is fixed upstream in 510.39.01 /but/ the spam may still happen if have old workaround dbus .conf files around, i.e. these can cause nvidia to believe powerd is running and it starts using it (perhaps it's related to why you were still getting it with patched 495 too, I never tried those non-patch workarounds given I wanted to stop the spam itself rather than just silence it -- but I heard of them causing issues for other people today).

Shouldn't happen on a clean system as far as I can tell.