notify-send: silence vfprintf null
Hi,
here's a smallish patch to silence some annoying warnings i have in my
logs on my mozilla builder at each build, which is running headless and
doesnt have a notification daemon running:
Apr 9 07:07:05 c64 notify-send: vfprintf %s NULL in "Using sever %s %s, v%s -
Supporting Notification Spec %s"
Apr 9 07:07:05 c64 last message repeated 3 times
Apr 9 07:12:16 c64 notify-send: vfprintf %s NULL in "Using sever %s %s, v%s -
Supporting Notification Spec %s"
Apr 9 07:12:16 c64 last message repeated 3 times
The mozilla build system does run notify-send (if installed) at various
steps of the build, cf
https://searchfox.org/mozilla-central/source/python/mozbuild/mozbuild/base.py#627
i've had those since a long time, the strange thing is that the printed
message is only a g_debug one and i dont know what would set glib
debugging msgs to be printed within the mozbuild goo, but that can be
reproduced locally with:
(thats on a laptop running xfce)
G_MESSAGES_DEBUG=all notify-send --app-name="Mozilla Build System" "bla bli
blu" blah
(notify-send:16579): libnotify-DEBUG: 09:37:00.687: Using sever Xfce Notify
Daemon Xfce, v0.8.2 - Supporting Notification Spec 1.2
(on my builder i get this)
[09:37]
c64:/usr/obj/ports/libnotify-0.8.2/libnotify-0.8.2/$G_MESSAGES_DEBUG=all
notify-send --app-name="Mozilla Build System" "bla bli blu" blah
(notify-send:29048): libnotify-DEBUG: 09:37:28.198: Using sever (null)(null),
v(null) - Supporting Notification Spec (null)
Impossible de lancer automatiquement D-Bus sans $DISPLAY X11
[09:37] c64:/usr/obj/ports/libnotify-0.8.2/libnotify-0.8.2/ $tail -1
/var/log/messages
Apr 9 09:37:28 c64 notify-send: vfprintf %s NULL in "Using sever %s %s, v%s -
Supporting Notification Spec %s"
patch below, better suggestions welcome :)
avoid vfprintf %s NULL in "Using sever %s %s, v%s - Supporting Notification
Spec %s"
Index: tools/notify-send.c
--- tools/notify-send.c.orig
+++ tools/notify-send.c
@@ -329,8 +329,10 @@ main (int argc, char *argv[])
&server_version,
&server_spec_version);
-g_debug ("Using sever %s %s, v%s - Supporting Notification Spec %s",
- server_name, server_vendor, server_version,
server_spec_version);
+if (server_name != NULL && server_vendor != NULL &&
+server_version != NULL && server_spec_version != NULL)
+g_debug ("Using sever %s %s, v%s - Supporting Notification
Spec %s",
+ server_name, server_vendor, server_version,
server_spec_version);
g_free (server_name);
g_free (server_vendor);
g_free (server_version);
Re: notify-send: silence vfprintf null
On Sun, Apr 09, 2023 at 09:50:09AM +0200, Landry Breuil wrote:
> Hi,
>
> here's a smallish patch to silence some annoying warnings i have in my
> logs on my mozilla builder at each build, which is running headless and
> doesnt have a notification daemon running:
>
> Apr 9 07:07:05 c64 notify-send: vfprintf %s NULL in "Using sever %s %s, v%s
> - Supporting Notification Spec %s"
> Apr 9 07:07:05 c64 last message repeated 3 times
> Apr 9 07:12:16 c64 notify-send: vfprintf %s NULL in "Using sever %s %s, v%s
> - Supporting Notification Spec %s"
> Apr 9 07:12:16 c64 last message repeated 3 times
>
> The mozilla build system does run notify-send (if installed) at various
> steps of the build, cf
> https://searchfox.org/mozilla-central/source/python/mozbuild/mozbuild/base.py#627
>
> i've had those since a long time, the strange thing is that the printed
> message is only a g_debug one and i dont know what would set glib
> debugging msgs to be printed within the mozbuild goo, but that can be
> reproduced locally with:
>
> (thats on a laptop running xfce)
> G_MESSAGES_DEBUG=all notify-send --app-name="Mozilla Build System" "bla bli
> blu" blah
> (notify-send:16579): libnotify-DEBUG: 09:37:00.687: Using sever Xfce Notify
> Daemon Xfce, v0.8.2 - Supporting Notification Spec 1.2
>
> (on my builder i get this)
> [09:37]
> c64:/usr/obj/ports/libnotify-0.8.2/libnotify-0.8.2/$G_MESSAGES_DEBUG=all
> notify-send --app-name="Mozilla Build System" "bla bli blu" blah
> (notify-send:29048): libnotify-DEBUG: 09:37:28.198: Using sever (null)(null),
> v(null) - Supporting Notification Spec (null)
> Impossible de lancer automatiquement D-Bus sans $DISPLAY X11
> [09:37] c64:/usr/obj/ports/libnotify-0.8.2/libnotify-0.8.2/ $tail -1
> /var/log/messages
> Apr 9 09:37:28 c64 notify-send: vfprintf %s NULL in "Using sever %s %s, v%s
> - Supporting Notification Spec %s"
>
> patch below, better suggestions welcome :)
Looks fine to me (with a bump).
> avoid vfprintf %s NULL in "Using sever %s %s, v%s - Supporting Notification
> Spec %s"
> Index: tools/notify-send.c
> --- tools/notify-send.c.orig
> +++ tools/notify-send.c
> @@ -329,8 +329,10 @@ main (int argc, char *argv[])
> &server_version,
> &server_spec_version);
>
> -g_debug ("Using sever %s %s, v%s - Supporting Notification Spec %s",
> - server_name, server_vendor, server_version,
> server_spec_version);
> +if (server_name != NULL && server_vendor != NULL &&
> +server_version != NULL && server_spec_version != NULL)
> +g_debug ("Using sever %s %s, v%s - Supporting Notification
> Spec %s",
> + server_name, server_vendor, server_version,
> server_spec_version);
> g_free (server_name);
> g_free (server_vendor);
> g_free (server_version);
--
Antoine
Re: notify-send: silence vfprintf null
On 2023/04/09 09:50, Landry Breuil wrote: > Hi, > > here's a smallish patch to silence some annoying warnings i have in my > logs on my mozilla builder at each build, which is running headless and > doesnt have a notification daemon running: > > Apr 9 07:07:05 c64 notify-send: vfprintf %s NULL in "Using sever %s %s, v%s > - Supporting Notification Spec %s" > Apr 9 07:07:05 c64 last message repeated 3 times > Apr 9 07:12:16 c64 notify-send: vfprintf %s NULL in "Using sever %s %s, v%s > - Supporting Notification Spec %s" > Apr 9 07:12:16 c64 last message repeated 3 times These are *all* over the place in various software, it can result in a huge amount of crap sent to syslog. Example from the first machine running GNOME I looked at below - if I look harder there's a good chance I'll find some with "last message repeated" counts in the hundreds. Basically it seems that g_debug callers expect to be able to use NULL srrings and it would be huge whack-a-mole to clean them up. I wonder if it might be better to do something to catch these in g_debug() and avoid passing the NULL to vfprintf. Mar 30 00:20:12 nuc610-59-141 console-kit-daemon: vfprintf %s NULL in "instance of invalid non-instantiatable type '%s'" Mar 30 00:20:12 nuc610-59-141 console-kit-daemon: vfprintf %s NULL in "instance of invalid non-instantiatable type '%s'" Mar 30 00:20:12 nuc610-59-141 gdm: vfprintf %s NULL in "GdmSession: type %s, program? %s, seat %s" Mar 30 00:20:12 nuc610-59-141 gdm: vfprintf %s NULL in "GdmSession: type %s, program? %s, seat %s" Mar 30 00:20:19 nuc610-59-141 gsd-media-keys: vfprintf %s NULL in "gvc-mixer-output-set-property - card port name: %s" Mar 30 00:20:22 nuc610-59-141 gnome-shell: vfprintf %s NULL in "gvc-mixer-output-set-property - card port name: %s" Mar 30 00:25:51 nuc610-59-141 gdm: vfprintf %s NULL in "GdmDisplay: id: %s" Mar 30 00:25:51 nuc610-59-141 gdm: vfprintf %s NULL in "GdmDisplay: seat id: %s" Mar 30 00:25:51 nuc610-59-141 gdm: vfprintf %s NULL in "GdmDisplay: supported session types: %s" Mar 30 00:25:54 nuc610-59-141 gdm: vfprintf %s NULL in "GdmSession: Creating D-Bus server for greeters and such for session %s (%p)" Mar 30 00:25:54 nuc610-59-141 gdm: vfprintf %s NULL in "GdmDisplay: Creating greeter for %s %s" Mar 30 00:25:54 nuc610-59-141 gdm: vfprintf %s NULL in "GdmSession: Creating D-Bus server for greeters and such for session %s (%p)" Mar 30 00:25:54 nuc610-59-141 gdm: vfprintf %s NULL in "GdmSession: type %s, program? %s, seat %s" Mar 30 00:26:00 nuc610-59-141 gsd-media-keys: vfprintf %s NULL in "gvc-mixer-output-set-property - card port name: %s" Mar 30 00:26:01 nuc610-59-141 gnome-shell: vfprintf %s NULL in "gvc-mixer-output-set-property - card port name: %s" Mar 30 00:26:02 nuc610-59-141 gdm: vfprintf %s NULL in "GdmSession: Considering session %s for username %s" Mar 30 00:26:02 nuc610-59-141 gdm: vfprintf %s NULL in "GdmSession: Considering session %s for username %s" Mar 30 00:26:04 nuc610-59-141 gdm: vfprintf %s NULL in "GdmSession: client requesting automatic login for user '%s' on session '%s' (%p)" Mar 30 00:26:04 nuc610-59-141 gdm: vfprintf %s NULL in "GdmSession: selecting user '%s' for session '%s' (%p)" Mar 30 00:26:04 nuc610-59-141 gdm: vfprintf %s NULL in "GdmSession: type %s, program? %s, seat %s" Mar 30 00:26:05 nuc610-59-141 gdm: vfprintf %s NULL in "GdmSession: Ignoring session %s as requested" Mar 30 00:26:05 nuc610-59-141 gdm: vfprintf %s NULL in "GdmSession: type %s, program? %s, seat %s" Mar 30 00:26:05 nuc610-59-141 console-kit-daemon: vfprintf %s NULL in "instance of invalid non-instantiatable type '%s'" Mar 30 00:26:05 nuc610-59-141 console-kit-daemon: vfprintf %s NULL in "instance of invalid non-instantiatable type '%s'" Mar 30 00:26:05 nuc610-59-141 gdm: vfprintf %s NULL in "GdmSession: type %s, program? %s, seat %s" Mar 30 00:26:05 nuc610-59-141 gdm: vfprintf %s NULL in "GdmSession: type %s, program? %s, seat %s" Mar 30 00:26:10 nuc610-59-141 gsd-media-keys: vfprintf %s NULL in "gvc-mixer-output-set-property - card port name: %s" Mar 30 00:26:12 nuc610-59-141 gnome-shell: vfprintf %s NULL in "gvc-mixer-output-set-property - card port name: %s" Mar 30 06:57:37 nuc610-59-141 gdm-autologin]: vfprintf %s NULL in "GdmSession: Creating D-Bus server for greeters and such for session %s (%p)" Mar 30 07:06:08 nuc610-59-141 dleyna-renderer-service: vfprintf %s NULL in "Entries: %s" Mar 30 07:06:08 nuc610-59-141 dleyna-renderer-service: vfprintf %s NULL in " host_ip: %s" Mar 30 07:06:08 nuc610-59-141 dleyna-renderer-service: vfprintf %s NULL in " network: %s" Mar 30 07:06:08 nuc610-59-141 nautilus: vfprintf %s NULL in "unable to parse ctime: %s" Mar 30 07:06:08 nuc610-59-141 nautilus: vfprintf %s NULL in "unable to parse ctime: %s" Mar 30 11:28:50 nuc610-59-141 gdm-autologin]: vfprintf %s NULL in "GdmSession: Creating D-Bus server for greeters and such for session %s (%p)" Apr 1 15:08:33 nuc610-59-141 dleyna-renderer-
Re: notify-send: silence vfprintf null
On Sun, Apr 09, 2023 at 10:31:28AM +0100, Stuart Henderson wrote: > On 2023/04/09 09:50, Landry Breuil wrote: > > Hi, > > > > here's a smallish patch to silence some annoying warnings i have in my > > logs on my mozilla builder at each build, which is running headless and > > doesnt have a notification daemon running: > > > > Apr 9 07:07:05 c64 notify-send: vfprintf %s NULL in "Using sever %s %s, > > v%s - Supporting Notification Spec %s" > > Apr 9 07:07:05 c64 last message repeated 3 times > > Apr 9 07:12:16 c64 notify-send: vfprintf %s NULL in "Using sever %s %s, > > v%s - Supporting Notification Spec %s" > > Apr 9 07:12:16 c64 last message repeated 3 times > > These are *all* over the place in various software, it can result in a > huge amount of crap sent to syslog. Example from the first machine running > GNOME I looked at below - if I look harder there's a good chance I'll > find some with "last message repeated" counts in the hundreds. > > Basically it seems that g_debug callers expect to be able to use NULL > srrings and it would be huge whack-a-mole to clean them up. I wonder > if it might be better to do something to catch these in g_debug() and > avoid passing the NULL to vfprintf. Ah that would be much better indeed.
Re: notify-send: silence vfprintf null
Le Sun, Apr 09, 2023 at 11:41:22AM +0200, Antoine Jacoutot a écrit : > On Sun, Apr 09, 2023 at 10:31:28AM +0100, Stuart Henderson wrote: > > On 2023/04/09 09:50, Landry Breuil wrote: > > > Hi, > > > > > > here's a smallish patch to silence some annoying warnings i have in my > > > logs on my mozilla builder at each build, which is running headless and > > > doesnt have a notification daemon running: > > > > > > Apr 9 07:07:05 c64 notify-send: vfprintf %s NULL in "Using sever %s %s, > > > v%s - Supporting Notification Spec %s" > > > Apr 9 07:07:05 c64 last message repeated 3 times > > > Apr 9 07:12:16 c64 notify-send: vfprintf %s NULL in "Using sever %s %s, > > > v%s - Supporting Notification Spec %s" > > > Apr 9 07:12:16 c64 last message repeated 3 times > > > > These are *all* over the place in various software, it can result in a > > huge amount of crap sent to syslog. Example from the first machine running > > GNOME I looked at below - if I look harder there's a good chance I'll > > find some with "last message repeated" counts in the hundreds. > > > > Basically it seems that g_debug callers expect to be able to use NULL > > srrings and it would be huge whack-a-mole to clean them up. I wonder > > if it might be better to do something to catch these in g_debug() and > > avoid passing the NULL to vfprintf. > > Ah that would be much better indeed. I've had a quick look and got a bit lost in the maze, but my understanding is that via various aliases/defines, the function called is g_logv in https://gitlab.gnome.org/GNOME/glib/-/blob/main/glib/gmessages.c#L1291 - so the code should iterate on args and replace the NULL ones by '(null)' ? or in format_string() ? there seems to be many dragons and abstractions in that code... Landry
Re: notify-send: silence vfprintf null
Stuart Henderson: > Basically it seems that g_debug callers expect to be able to use NULL > srrings and it would be huge whack-a-mole to clean them up. I wonder > if it might be better to do something to catch these in g_debug() and > avoid passing the NULL to vfprintf. How would you do this? You would have to process the format string to see which arguments are pointers and then replace corresponding NULL arguments. The glib code passes the variadic arguments straight through to v*printf(). Here's how that looks: g_debug() macro expands to -> g_log() calls -> g_logv() calls -> g_strdup_vprintf() calls -> vasprintf() or -> _g_vsnprintf() macro expands to -> vsnprintf() or -> g_log_structured() calls -> g_strdup_vprintf() calls -> vasprintf() or -> _g_vsnprintf() macro expands to -> vsnprintf() -- Christian "naddy" Weisgerber na...@mips.inka.de
Re: notify-send: silence vfprintf null
Landry Breuil: > I've had a quick look and got a bit lost in the maze, but my > understanding is that via various aliases/defines, the function called > is g_logv in > https://gitlab.gnome.org/GNOME/glib/-/blob/main/glib/gmessages.c#L1291 - > so the code should iterate on args and replace the NULL ones by '(null)' ? You can't tell by looking at an argument whether it is a a pointer or a long (or a sign-extended int on most archs). You need to examine the format string. Also, how do you replace an element in a va_list? I don't think you can. I don't think you can construct a new va_list element by element either. -- Christian "naddy" Weisgerber na...@mips.inka.de
Re: notify-send: silence vfprintf null
Christian Weisgerber wrote: > Landry Breuil: > > > I've had a quick look and got a bit lost in the maze, but my > > understanding is that via various aliases/defines, the function called > > is g_logv in > > https://gitlab.gnome.org/GNOME/glib/-/blob/main/glib/gmessages.c#L1291 - > > so the code should iterate on args and replace the NULL ones by '(null)' ? > > You can't tell by looking at an argument whether it is a a pointer > or a long (or a sign-extended int on most archs). You need to > examine the format string. > > Also, how do you replace an element in a va_list? I don't think > you can. I don't think you can construct a new va_list element by > element either. Whoa, no way -- you cannot touch them. The pointers could be to objects that the caller uses for an additional purpose. There is no specification which says they have to be unique to this call.
Re: notify-send: silence vfprintf null
On 2023/04/12 16:37, Christian Weisgerber wrote: > Stuart Henderson: > > > Basically it seems that g_debug callers expect to be able to use NULL > > srrings and it would be huge whack-a-mole to clean them up. I wonder > > if it might be better to do something to catch these in g_debug() and > > avoid passing the NULL to vfprintf. > > How would you do this? You would have to process the format string > to see which arguments are pointers and then replace corresponding > NULL arguments. The glib code passes the variadic arguments straight > through to v*printf(). Here's how that looks: > > g_debug() macro expands to > -> g_log() calls >-> g_logv() calls > -> g_strdup_vprintf() calls > -> vasprintf() > or > -> _g_vsnprintf() macro expands to > -> vsnprintf() >or > -> g_log_structured() calls >-> g_strdup_vprintf() calls > -> vasprintf() > or >-> _g_vsnprintf() macro expands to > -> vsnprintf() Perhaps by calling a different function instead of v*printf that does most of the same things except not syslogging for null %s prints..
Re: notify-send: silence vfprintf null
Stuart Henderson: > Perhaps by calling a different function instead of v*printf that does > most of the same things except not syslogging for null %s prints.. Well... glib2's configure checks for vasprintf() and vsnprintf() and can fall back to an included copy of gnulib's implementation of those functions. If I understand the gnulib code correctly, it doesn't actually reimplement the *printf() family, but works as a wrapper that breaks down some functionality and still calls basic system *printf() functions. I also can't find any special handling of NULL arguments for the %s format. So I think forcing glib to use the gnulib implementation will not solve this problem by itself. However, the gnulib functions call an internal printf_parse() routine that analyzes the format string and digests it into arrays of directives and corresponding arguments. This looks like the spot where an argument for %s could be checked for NULL and swapped out with a pointer to the string constant "(null)". Assuming we manage to hack up the g_log() backend as outlined above, what's next? With the most common source of those log messages removed, the second most common one will become apparent... I question our wisdom of having printf() log instances of %s NULL, but then declaring that we can't fix the offenders and need to resort to intercepting arguments passed to printf(). -- Christian "naddy" Weisgerber na...@mips.inka.de
Re: notify-send: silence vfprintf null
> I question our wisdom of having printf() log instances of %s NULL, > but then declaring that we can't fix the offenders and need to > resort to intercepting arguments passed to printf(). Indeed, let's step back here. The logging has cleaned numerous bugs in our base tree. But ports, that's another matter. I suspect a bunch of upstreams have used information from openbsd builds on their own, or based upon feedback from openbsd ports builders, and that this has resulted in repair numerous NULL conditions. But not all. There will be communities who don't care. It remains an odd situation, I think a printf of %s NULL is permitted to access and SIGSEGV, and I think one unix operating system in the past did, but noone nowadays does. (Was it Ultrix?) Anyways -- maybe we have achieved everything we wanted to achieve (I mean, fixing base to be accurate), and it is time to disable this logging. Also, maybe we can re-enable it for a couple months every few years, (but not in release) to encourage fresh developer consideration of the issue?
Re: notify-send: silence vfprintf null
Christian Weisgerber:
> If I understand the gnulib code correctly, it doesn't actually
> reimplement the *printf() family, but works as a wrapper that breaks
> down some functionality and still calls basic system *printf()
> functions. I also can't find any special handling of NULL arguments
> for the %s format.
I missed it:
case TYPE_STRING:
ap->a.a_string = va_arg (args, const char *);
/* A null pointer is an invalid argument for "%s", but in practice
it occurs quite frequently in printf statements that produce
debug output. Use a fallback in this case. */
if (ap->a.a_string == NULL)
ap->a.a_string = "(NULL)";
break;
FWIW, I can confirm that switching glib2 over to the gnulib printf()
functions means that no more warnings for %s NULL will be created
by calls to g_log() etc.
--- meson.build.orig
+++ meson.build
@@ -1205,7 +1205,7 @@ else
endif
# Our printf is 'good' only if vsnpintf()/snprintf()/printf() supports C99
well enough
-use_system_printf = have_good_vsnprintf and have_good_snprintf and
have_good_printf
+use_system_printf = false
glib_conf.set('USE_SYSTEM_PRINTF', use_system_printf)
glibconfig_conf.set('GLIB_USING_SYSTEM_PRINTF', use_system_printf)
--
Christian "naddy" Weisgerber na...@mips.inka.de
