[PATCH v2 0/6] util: log infor to help troubleshoot file/socket open failures
The first couple patches are just related cleanups I noticed while doing the others, then a couple patches to simplify adding more lines to the bannder printed at the top of the log, and then finally the last couple patches add some info to the banner at the top of the log that would be generally useful when trying to understand why some random file or socket failed to be created or opened. V2: I've fixed a few nits Peter found, and modified the format and contents of the banner based on suggestions from Peter and Daniel Laine Stump (6): util: log the name of the log directory that couldn't be created util: consistently use typedef virLogMetadata util: eliminate duplicate code in virLogVMessage util: make it easier to add lines to the log "init banner" util: add info to log banner about uid and user environment util: add info about g_get_user_*_dir directories to log banner src/util/virlog.c | 226 ++++++++++++++++++++++++++++++---------------- src/util/virlog.h | 4 +- tests/testutils.c | 2 +- 3 files changed, 150 insertions(+), 82 deletions(-) -- 2.53.0
From: Laine Stump <laine@redhat.com> The message previously just said "Could not create log directory", but didn't provide the name of the directory, which could be helpful in determine why the failure occured. Signed-off-by: Laine Stump <laine@redhat.com> Reviewed-by: Peter Krempa <pkrempa@redhat.com> --- src/util/virlog.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/util/virlog.c b/src/util/virlog.c index c24dfa83c4..9f53c72975 100644 --- a/src/util/virlog.c +++ b/src/util/virlog.c @@ -178,7 +178,7 @@ virLogSetDefaultOutputToFile(const char *binary, bool privileged) old_umask = umask(077); if (g_mkdir_with_parents(logdir, 0777) < 0) { umask(old_umask); - virReportSystemError(errno, "%s", _("Could not create log directory")); + virReportSystemError(errno, _("Could not create log directory '%1$s'"), logdir); return -1; } umask(old_umask); -- 2.53.0
From: Laine Stump <laine@redhat.com> For some reason there were some uses of this struct where "struct _virLogMetadata" was used instead of just using the typedef "virLogMetadata" (they are both defined in the same file - virlog.h). Possibly at one point the struct was in virlog.c and outsiders could only see it as an opaque object, but even if that was the case, there are already cases of the typedef being used outside of virlog.c, and constinuing to use "struct _virLogMetadata" in some places both looks too much K&R 1st edition and might incorrectly imply to someone that there *is* data abstraction/hiding going on when there really isn't. So let's just always use plain virLogMetadata. Signed-off-by: Laine Stump <laine@redhat.com> Reviewed-by: Peter Krempa <pkrempa@redhat.com> --- src/util/virlog.c | 12 ++++++------ src/util/virlog.h | 4 ++-- tests/testutils.c | 2 +- 3 files changed, 9 insertions(+), 9 deletions(-) diff --git a/src/util/virlog.c b/src/util/virlog.c index 9f53c72975..30cb68fe7d 100644 --- a/src/util/virlog.c +++ b/src/util/virlog.c @@ -116,7 +116,7 @@ static void virLogOutputToFd(virLogSource *src, int linenr, const char *funcname, const char *timestamp, - struct _virLogMetadata *metadata, + virLogMetadata *metadata, const char *rawstr, const char *str, void *data); @@ -500,7 +500,7 @@ virLogVMessage(virLogSource *source, const char *filename, int linenr, const char *funcname, - struct _virLogMetadata *metadata, + virLogMetadata *metadata, const char *fmt, va_list vargs) { @@ -627,7 +627,7 @@ virLogMessage(virLogSource *source, const char *filename, int linenr, const char *funcname, - struct _virLogMetadata *metadata, + virLogMetadata *metadata, const char *fmt, ...) { va_list ap; @@ -646,7 +646,7 @@ virLogOutputToFd(virLogSource *source G_GNUC_UNUSED, int linenr G_GNUC_UNUSED, const char *funcname G_GNUC_UNUSED, const char *timestamp, - struct _virLogMetadata *metadata G_GNUC_UNUSED, + virLogMetadata *metadata G_GNUC_UNUSED, const char *rawstr G_GNUC_UNUSED, const char *str, void *data) @@ -746,7 +746,7 @@ virLogOutputToSyslog(virLogSource *source G_GNUC_UNUSED, int linenr G_GNUC_UNUSED, const char *funcname G_GNUC_UNUSED, const char *timestamp G_GNUC_UNUSED, - struct _virLogMetadata *metadata G_GNUC_UNUSED, + virLogMetadata *metadata G_GNUC_UNUSED, const char *rawstr G_GNUC_UNUSED, const char *str, void *data G_GNUC_UNUSED) @@ -890,7 +890,7 @@ virLogOutputToJournald(virLogSource *source, int linenr, const char *funcname, const char *timestamp G_GNUC_UNUSED, - struct _virLogMetadata *metadata, + virLogMetadata *metadata, const char *rawstr, const char *str G_GNUC_UNUSED, void *data) diff --git a/src/util/virlog.h b/src/util/virlog.h index 4f755c543b..77ba40b2e4 100644 --- a/src/util/virlog.h +++ b/src/util/virlog.h @@ -127,7 +127,7 @@ typedef void (*virLogOutputFunc) (virLogSource *src, int linenr, const char *funcname, const char *timestamp, - struct _virLogMetadata *metadata, + virLogMetadata *metadata, const char *rawstr, const char *str, void *data); @@ -170,7 +170,7 @@ void virLogMessage(virLogSource *source, const char *filename, int linenr, const char *funcname, - struct _virLogMetadata *metadata, + virLogMetadata *metadata, const char *fmt, ...) G_GNUC_PRINTF(7, 8); bool virLogProbablyLogMessage(const char *str); diff --git a/tests/testutils.c b/tests/testutils.c index 14e5c56fcf..35571fb2ad 100644 --- a/tests/testutils.c +++ b/tests/testutils.c @@ -680,7 +680,7 @@ virtTestLogOutput(virLogSource *source G_GNUC_UNUSED, int lineno G_GNUC_UNUSED, const char *funcname G_GNUC_UNUSED, const char *timestamp, - struct _virLogMetadata *metadata G_GNUC_UNUSED, + virLogMetadata *metadata G_GNUC_UNUSED, const char *rawstr G_GNUC_UNUSED, const char *str, void *data) -- 2.53.0
From: Laine Stump <laine@redhat.com> The same several lines were repeated, once in a loop iterating through all log targets, and again to output to stderr when there are no log targets specified. This just moves those lines into a helper function, making it easier and less error prone to add additional info to the banner that is logged each time a daemon starts logging. Signed-off-by: Laine Stump <laine@redhat.com> Reviewed-by: Peter Krempa <pkrempa@redhat.com> --- src/util/virlog.c | 127 ++++++++++++++++++++++++++++------------------ 1 file changed, 79 insertions(+), 48 deletions(-) diff --git a/src/util/virlog.c b/src/util/virlog.c index 30cb68fe7d..8d0d926d58 100644 --- a/src/util/virlog.c +++ b/src/util/virlog.c @@ -479,6 +479,75 @@ virLogSourceUpdate(virLogSource *source) } +/** + * virLogToOneTarget: + * + * (these first several args are coming directly from the args of + * virLogVMessage() - you can find their description there) + * + * @source, @priority, @filename, @linenr, @funcname, @metadata: + * + * (the next 3 are created once during each call to virLogMMessage() and reused + * for each target) + * + * @timestamp: cached (during this one log to multiple targets) raw time + * @str: the log message formatted from what appears in the VIR_*() + or virReport*() call + * @msg: the formatted log message with function name, line number, and + * priority added + * + * @outputFunc: pointer to function to call to output the data + * @data: private data used by @outputFunc (e.g. fd to write to) + * @needInit: pointer to bool that gets set to false once the + * once-per-daemon-run init message has been sent to this target + * + * If needInit is true, construct the strings to send the "init" + * message (a banner with software version, etc) to the log target + * using @outputFunc and set @needInit to false. Then send the current + * log message to the target (described by the other args) using + * @outputFunc. + */ +static void +virLogToOneTarget(virLogSource *source, + virLogPriority priority, + const char *filename, + int linenr, + const char *funcname, + virLogMetadata *metadata, + const char *timestamp, + const char *str, + const char *msg, + virLogOutputFunc outputFunc, + void *data, + bool *needInit) +{ + if (*needInit) { + const char *rawinitmsg; + char *hoststr = NULL; + char *initmsg = NULL; + + virLogVersionString(&rawinitmsg, &initmsg); + outputFunc(&virLogSelf, VIR_LOG_INFO, + __FILE__, __LINE__, __func__, + timestamp, NULL, rawinitmsg, initmsg, + data); + VIR_FREE(initmsg); + + virLogHostnameString(&hoststr, &initmsg); + outputFunc(&virLogSelf, VIR_LOG_INFO, + __FILE__, __LINE__, __func__, + timestamp, NULL, hoststr, initmsg, + data); + VIR_FREE(hoststr); + VIR_FREE(initmsg); + *needInit = false; + } + + outputFunc(source, priority, filename, linenr, funcname, + timestamp, metadata, str, msg, data); +} + + /** * virLogVMessage: * @source: where is that message coming from @@ -548,57 +617,19 @@ virLogVMessage(virLogSource *source, */ for (i = 0; i < virLogNbOutputs; i++) { if (priority >= virLogOutputs[i]->priority) { - if (virLogOutputs[i]->logInitMessage) { - const char *rawinitmsg; - char *hoststr = NULL; - char *initmsg = NULL; - virLogVersionString(&rawinitmsg, &initmsg); - virLogOutputs[i]->f(&virLogSelf, VIR_LOG_INFO, - __FILE__, __LINE__, __func__, - timestamp, NULL, rawinitmsg, initmsg, - virLogOutputs[i]->data); - VIR_FREE(initmsg); - - virLogHostnameString(&hoststr, &initmsg); - virLogOutputs[i]->f(&virLogSelf, VIR_LOG_INFO, - __FILE__, __LINE__, __func__, - timestamp, NULL, hoststr, initmsg, - virLogOutputs[i]->data); - VIR_FREE(hoststr); - VIR_FREE(initmsg); - virLogOutputs[i]->logInitMessage = false; - } - virLogOutputs[i]->f(source, priority, - filename, linenr, funcname, - timestamp, metadata, - str, msg, virLogOutputs[i]->data); + virLogToOneTarget(source, priority, filename, linenr, funcname, metadata, + timestamp, str, msg, + virLogOutputs[i]->f, + virLogOutputs[i]->data, + &virLogOutputs[i]->logInitMessage); } } if (virLogNbOutputs == 0) { - if (logInitMessageStderr) { - const char *rawinitmsg; - char *hoststr = NULL; - char *initmsg = NULL; - virLogVersionString(&rawinitmsg, &initmsg); - virLogOutputToFd(&virLogSelf, VIR_LOG_INFO, - __FILE__, __LINE__, __func__, - timestamp, NULL, rawinitmsg, initmsg, - (void *) STDERR_FILENO); - VIR_FREE(initmsg); - - virLogHostnameString(&hoststr, &initmsg); - virLogOutputToFd(&virLogSelf, VIR_LOG_INFO, - __FILE__, __LINE__, __func__, - timestamp, NULL, hoststr, initmsg, - (void *) STDERR_FILENO); - VIR_FREE(hoststr); - VIR_FREE(initmsg); - logInitMessageStderr = false; - } - virLogOutputToFd(source, priority, - filename, linenr, funcname, - timestamp, metadata, - str, msg, (void *) STDERR_FILENO); + virLogToOneTarget(source, priority, filename, linenr, funcname, metadata, + timestamp, str, msg, + virLogOutputToFd, + (void *) STDERR_FILENO, + &logInitMessageStderr); } virLogUnlock(); -- 2.53.0
From: Laine Stump <laine@redhat.com> The same thing happens for each line of the log banner: 1) A helper function is called that a) creates a "raw" string (just the desired info, e.g. version string) and b) calls virLogFormatString() to create a "cooked" version of the string (containing thread-id and log priority) 2) the outputFunc for the target is called with strings (a) and (b) By making a helper that does (1b) & (2), we can further reduce the amount of redundant code that needs to be written to add another line to the banner - now all we need to do is: 1) create the raw string 2) call the helper, sending it the raw string Signed-off-by: Laine Stump <laine@redhat.com> Reviewed-by: Peter Krempa <pkrempa@redhat.com> --- V2: fixed formatting of a function definition noticed by Peter src/util/virlog.c | 82 +++++++++++++++++++++++------------------------ 1 file changed, 40 insertions(+), 42 deletions(-) diff --git a/src/util/virlog.c b/src/util/virlog.c index 8d0d926d58..cab23f613f 100644 --- a/src/util/virlog.c +++ b/src/util/virlog.c @@ -433,30 +433,6 @@ virLogFormatString(char **msg, } -static void -virLogVersionString(const char **rawmsg, - char **msg) -{ - *rawmsg = VIR_LOG_VERSION_STRING; - virLogFormatString(msg, 0, NULL, VIR_LOG_INFO, VIR_LOG_VERSION_STRING); -} - -/* Similar to virGetHostname() but avoids use of error - * reporting APIs or logging APIs, to prevent recursion - */ -static void -virLogHostnameString(char **rawmsg, - char **msg) -{ - char *hoststr; - - hoststr = g_strdup_printf("hostname: %s", g_get_host_name()); - - virLogFormatString(msg, 0, NULL, VIR_LOG_INFO, hoststr); - *rawmsg = hoststr; -} - - static void virLogSourceUpdate(virLogSource *source) { @@ -479,6 +455,34 @@ virLogSourceUpdate(virLogSource *source) } +/** + * virLogOneInitMsg: + * + * @str: the "raw" form of the string that's going to be logged + * + * (the args are all described in the caller - virLogToOneTarget() + * @timestamp,@outputFunc, @data + * + * send one "init message" (the lines that are at the beginning of the + * log when a new daemon starts) to one target. This just creates the + * "fancy" version of the string with thread-id and priority, and + * sends that, along with the "raw" version of the string, to the log + * target at INFO level. + */ +static void +virLogOneInitMsg(const char *timestamp, + const char *str, + virLogOutputFunc outputFunc, + void *data) +{ + g_autofree char *msg = NULL; + + virLogFormatString(&msg, 0, NULL, VIR_LOG_INFO, str); + outputFunc(&virLogSelf, VIR_LOG_INFO, __FILE__, __LINE__, __func__, + timestamp, NULL, str, msg, data); +} + + /** * virLogToOneTarget: * @@ -522,24 +526,18 @@ virLogToOneTarget(virLogSource *source, bool *needInit) { if (*needInit) { - const char *rawinitmsg; - char *hoststr = NULL; - char *initmsg = NULL; - - virLogVersionString(&rawinitmsg, &initmsg); - outputFunc(&virLogSelf, VIR_LOG_INFO, - __FILE__, __LINE__, __func__, - timestamp, NULL, rawinitmsg, initmsg, - data); - VIR_FREE(initmsg); - - virLogHostnameString(&hoststr, &initmsg); - outputFunc(&virLogSelf, VIR_LOG_INFO, - __FILE__, __LINE__, __func__, - timestamp, NULL, hoststr, initmsg, - data); - VIR_FREE(hoststr); - VIR_FREE(initmsg); + g_autofree char *hoststr = NULL; + + /* put some useful info at the top of the log. Avoid calling + * any function that might end up reporting an error or + * otherwise logging something, to prevent recursion. + */ + + virLogOneInitMsg(timestamp, VIR_LOG_VERSION_STRING, outputFunc, data); + + hoststr = g_strdup_printf("hostname: %s", g_get_host_name()); + virLogOneInitMsg(timestamp, hoststr, outputFunc, data); + *needInit = false; } -- 2.53.0
From: Laine Stump <laine@redhat.com> As libvirt is used more and more in unprivileged/session mode, file/socket permission errors have become more common. This patch adds the username and uid of the process to the line in the log banner (the first thing sent to every log target after the process starts) that previously just gave the hostname. We can expand on this idea to include more generally useful info about the environment we're running in. (We just need to remember that in this context we can't call anything that could lead to recursively calling the logging system (i.e. we can't call any code that reports an error, or a VIR_WARN, etc)) Signed-off-by: Laine Stump <laine@redhat.com> --- V2: removed all the "unprivileged/session mode" stuff as suggested by Daniel. Now we just add user and uid to the existing hostname line src/util/virlog.c | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/src/util/virlog.c b/src/util/virlog.c index cab23f613f..ccdf66c396 100644 --- a/src/util/virlog.c +++ b/src/util/virlog.c @@ -526,16 +526,18 @@ virLogToOneTarget(virLogSource *source, bool *needInit) { if (*needInit) { + uid_t uid = geteuid(); + g_autofree char *username = virGetUserName(uid); g_autofree char *hoststr = NULL; /* put some useful info at the top of the log. Avoid calling * any function that might end up reporting an error or * otherwise logging something, to prevent recursion. */ - virLogOneInitMsg(timestamp, VIR_LOG_VERSION_STRING, outputFunc, data); - hoststr = g_strdup_printf("hostname: %s", g_get_host_name()); + hoststr = g_strdup_printf("hostname: %s, user: %s, uid: %u", + g_get_host_name(), username, uid); virLogOneInitMsg(timestamp, hoststr, outputFunc, data); *needInit = false; -- 2.53.0
On Wed, Apr 08, 2026 at 00:10:37 -0400, Laine Stump via Devel wrote:
From: Laine Stump <laine@redhat.com>
As libvirt is used more and more in unprivileged/session mode, file/socket permission errors have become more common. This patch adds the username and uid of the process to the line in the log banner (the first thing sent to every log target after the process starts) that previously just gave the hostname.
We can expand on this idea to include more generally useful info about the environment we're running in. (We just need to remember that in this context we can't call anything that could lead to recursively calling the logging system (i.e. we can't call any code that reports an error, or a VIR_WARN, etc))
^^^^^ ...
Signed-off-by: Laine Stump <laine@redhat.com> ---
V2: removed all the "unprivileged/session mode" stuff as suggested by Daniel. Now we just add user and uid to the existing hostname line
src/util/virlog.c | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-)
diff --git a/src/util/virlog.c b/src/util/virlog.c index cab23f613f..ccdf66c396 100644 --- a/src/util/virlog.c +++ b/src/util/virlog.c @@ -526,16 +526,18 @@ virLogToOneTarget(virLogSource *source, bool *needInit) { if (*needInit) { + uid_t uid = geteuid(); + g_autofree char *username = virGetUserName(uid);
... 'virGetUserName' calls 'virGetUserEnt' with the 'quiet' argument being false, which makes it report errors via 'virReportSystemError' contradicting the above statement ...
g_autofree char *hoststr = NULL;
/* put some useful info at the top of the log. Avoid calling * any function that might end up reporting an error or * otherwise logging something, to prevent recursion. */ - virLogOneInitMsg(timestamp, VIR_LOG_VERSION_STRING, outputFunc, data);
- hoststr = g_strdup_printf("hostname: %s", g_get_host_name()); + hoststr = g_strdup_printf("hostname: %s, user: %s, uid: %u", + g_get_host_name(), username, uid);
... as well as username may be NULL here. The latter can be fixed by using NULLSTR(username) here, but the former will require exporting another wrapper over 'virGetUserEnt'. But I'd perhaps just suggest logging the UID, the username itself isn't IMO really that importahnt. Also in instances where uid_t/gid_t is used with printf we tend to use typecast to either (long) or (int). I'm not sure which platforms would have different uid_t but either consider using typecases such asi in the DAC security driver: src/security/security_dac.c- VIR_INFO("Setting user and group to '%ld:%ld' on '%s' not " src/security/security_dac.c- "permitted", src/security/security_dac.c: (long)uid, (long)gid, NULLSTR(path)); and/or make sure to run it through CI .
virLogOneInitMsg(timestamp, hoststr, outputFunc, data);
Reviewed-by: Peter Krempa <pkrempa@redhat.com>
On 4/8/26 3:51 AM, Peter Krempa via Devel wrote:
Also in instances where uid_t/gid_t is used with printf we tend to use typecast to either (long) or (int).
Actually, for variables named *exactly* "uid", there are 6 cases of (long) (with "%ld" in the format string) and 6 of (unsigned int) (with "%u" in the format). I think I prefer (unsigned int) and %u, so that's what I'll do. ((long) + "%ld" is technically incorrect - on a platform with 32 bit longs, that would turn very large positive uids into negative numbers. I don't know if we still support any platform with 32 bit long though (we no longer support 32 bit Linux, right?)) ([*] a certainly and definitely not clanker and might be hooman source tells me that if I want to allow for the "0.1%" of systems that have a 64 bit uid, I should use (unsigned long long) and "%lu" (it couldn't name one, but theorized they might exist)).
I'm not sure which platforms would have different uid_t but either consider using typecases such asi in the DAC security driver:
src/security/security_dac.c- VIR_INFO("Setting user and group to '%ld:%ld' on '%s' not " src/security/security_dac.c- "permitted", src/security/security_dac.c: (long)uid, (long)gid, NULLSTR(path));
and/or make sure to run it through CI .
virLogOneInitMsg(timestamp, hoststr, outputFunc, data);
Reviewed-by: Peter Krempa <pkrempa@redhat.com>
From: Laine Stump <laine@redhat.com> When running in session/unprivileged mode, nearly all paths are prefixed with the returns from one of glib's g_get_user_*_dir() functions, which in turn base their selected paths on the settings of a few items in the user's environment ($XDG_*, or a subdirectory of $HOME if the relevant $XDG_* isn't set). This patch logs the settings of these directories in the log banner in an attempt to help diagnose the problem when a file/socket open/create fails. An example of the banner: libvirt version: 12.3.0, package: 1.fc43 (Unknown, 2026-04-07-22:43:30, vhost) hostname: 83be0e173e02, user: qemu, uid: 107 home dir: '/' (HOME='/') runtime dir: '/.cache' (XDG_RUNTIME_DIR='(unset)') config dir: '/.config' (XDG_CONFIG_HOME='(unset)') log dir: '/.cache' (XDG_CACHE_HOME='(unset)') libvirt: XML-RPC error : Cannot create user runtime directory '/.cache/libvirt': Permission denied Resolves: https://redhat.atlassian.net/browse/RHEL-70222 Resolves: https://redhat.atlassian.net/browse/RHEL-105490 Signed-off-by: Laine Stump <laine@redhat.com> --- We could obviously add more information here (or less); it's difficult to know where to draw the line. Also, the astute reviewer will notice that all this code is executed once for each log target - we could do it all once at a higher level and cache it if we really wanted to. I'm not sure if it's worth the trouble though). Changes in V2: modified the format/labeling of the data as Peter suggested, and included an example in the commit log. src/util/virlog.c | 37 +++++++++++++++++++++++++++++++++++++ 1 file changed, 37 insertions(+) diff --git a/src/util/virlog.c b/src/util/virlog.c index ccdf66c396..d2882d16ee 100644 --- a/src/util/virlog.c +++ b/src/util/virlog.c @@ -540,6 +540,43 @@ virLogToOneTarget(virLogSource *source, g_get_host_name(), username, uid); virLogOneInitMsg(timestamp, hoststr, outputFunc, data); + /* This info is only relevant when running as something other than root */ + if (uid != 0) { + g_autofree char *envHOME = NULL; + g_autofree char *envXDG_RUNTIME_DIR = NULL; + g_autofree char *envXDG_CONFIG_HOME = NULL; + g_autofree char *envXDG_CACHE_HOME = NULL; + + g_autofree char *envstr1 = NULL; + g_autofree char *envstr2 = NULL; + g_autofree char *envstr3 = NULL; + g_autofree char *envstr4 = NULL; + + if (!(envHOME = g_strdup(g_getenv("HOME")))) + envHOME = g_strdup("(unset)"); + if (!(envXDG_RUNTIME_DIR = g_strdup(g_getenv("XDG_RUNTIME_DIR")))) + envXDG_RUNTIME_DIR = g_strdup("(unset)"); + if (!(envXDG_CONFIG_HOME = g_strdup(g_getenv("XDG_CONFIG_HOME")))) + envXDG_CONFIG_HOME = g_strdup("(unset)"); + if (!(envXDG_CACHE_HOME = g_strdup(g_getenv("XDG_CACHE_HOME")))) + envXDG_CACHE_HOME = g_strdup("(unset)"); + + envstr1 = g_strdup_printf("home dir: '%s' (HOME='%s')", + g_get_home_dir(), envHOME); + virLogOneInitMsg(timestamp, envstr1, outputFunc, data); + + envstr2 = g_strdup_printf("runtime dir: '%s' (XDG_RUNTIME_DIR='%s')", + g_get_user_runtime_dir(), envXDG_RUNTIME_DIR); + virLogOneInitMsg(timestamp, envstr2, outputFunc, data); + + envstr3 = g_strdup_printf("config dir: '%s' (XDG_CONFIG_HOME='%s')", + g_get_user_config_dir(), envXDG_CONFIG_HOME); + virLogOneInitMsg(timestamp, envstr3, outputFunc, data); + + envstr4 = g_strdup_printf("log dir: '%s' (XDG_CACHE_HOME='%s')", + g_get_user_cache_dir(), envXDG_CACHE_HOME); + virLogOneInitMsg(timestamp, envstr4, outputFunc, data); + } *needInit = false; } -- 2.53.0
On Wed, Apr 08, 2026 at 00:10:38 -0400, Laine Stump via Devel wrote:
From: Laine Stump <laine@redhat.com>
When running in session/unprivileged mode, nearly all paths are prefixed with the returns from one of glib's g_get_user_*_dir() functions, which in turn base their selected paths on the settings of a few items in the user's environment ($XDG_*, or a subdirectory of $HOME if the relevant $XDG_* isn't set).
This patch logs the settings of these directories in the log banner in an attempt to help diagnose the problem when a file/socket open/create fails.
An example of the banner:
libvirt version: 12.3.0, package: 1.fc43 (Unknown, 2026-04-07-22:43:30, vhost) hostname: 83be0e173e02, user: qemu, uid: 107 home dir: '/' (HOME='/') runtime dir: '/.cache' (XDG_RUNTIME_DIR='(unset)') config dir: '/.config' (XDG_CONFIG_HOME='(unset)') log dir: '/.cache' (XDG_CACHE_HOME='(unset)') libvirt: XML-RPC error : Cannot create user runtime directory '/.cache/libvirt': Permission denied
Resolves: https://redhat.atlassian.net/browse/RHEL-70222 Resolves: https://redhat.atlassian.net/browse/RHEL-105490 Signed-off-by: Laine Stump <laine@redhat.com> ---
We could obviously add more information here (or less); it's difficult to know where to draw the line. Also, the astute reviewer will notice that all this code is executed once for each log target - we could do it all once at a higher level and cache it if we really wanted to. I'm not sure if it's worth the trouble though).
Changes in V2: modified the format/labeling of the data as Peter suggested, and included an example in the commit log.
src/util/virlog.c | 37 +++++++++++++++++++++++++++++++++++++ 1 file changed, 37 insertions(+)
diff --git a/src/util/virlog.c b/src/util/virlog.c index ccdf66c396..d2882d16ee 100644 --- a/src/util/virlog.c +++ b/src/util/virlog.c @@ -540,6 +540,43 @@ virLogToOneTarget(virLogSource *source, g_get_host_name(), username, uid); virLogOneInitMsg(timestamp, hoststr, outputFunc, data);
+ /* This info is only relevant when running as something other than root */ + if (uid != 0) { + g_autofree char *envHOME = NULL; + g_autofree char *envXDG_RUNTIME_DIR = NULL; + g_autofree char *envXDG_CONFIG_HOME = NULL; + g_autofree char *envXDG_CACHE_HOME = NULL; + + g_autofree char *envstr1 = NULL; + g_autofree char *envstr2 = NULL; + g_autofree char *envstr3 = NULL; + g_autofree char *envstr4 = NULL; + + if (!(envHOME = g_strdup(g_getenv("HOME")))) + envHOME = g_strdup("(unset)"); + if (!(envXDG_RUNTIME_DIR = g_strdup(g_getenv("XDG_RUNTIME_DIR")))) + envXDG_RUNTIME_DIR = g_strdup("(unset)"); + if (!(envXDG_CONFIG_HOME = g_strdup(g_getenv("XDG_CONFIG_HOME")))) + envXDG_CONFIG_HOME = g_strdup("(unset)"); + if (!(envXDG_CACHE_HOME = g_strdup(g_getenv("XDG_CACHE_HOME")))) + envXDG_CACHE_HOME = g_strdup("(unset)"); + + envstr1 = g_strdup_printf("home dir: '%s' (HOME='%s')", + g_get_home_dir(), envHOME);
I wonder if the '(unset)' string is even required. The code could be simplified, if we decide that e.g. empty string is okay to denote we won't need the extra variables: envstr1 = g_strdup_printf("home dir: '%s' (HOME='%s')", g_get_home_dir(), NULLSTR_EMPTY(g_getenv("HOME")));
+ virLogOneInitMsg(timestamp, envstr1, outputFunc, data); + + envstr2 = g_strdup_printf("runtime dir: '%s' (XDG_RUNTIME_DIR='%s')", + g_get_user_runtime_dir(), envXDG_RUNTIME_DIR); + virLogOneInitMsg(timestamp, envstr2, outputFunc, data); + + envstr3 = g_strdup_printf("config dir: '%s' (XDG_CONFIG_HOME='%s')", + g_get_user_config_dir(), envXDG_CONFIG_HOME); + virLogOneInitMsg(timestamp, envstr3, outputFunc, data); + + envstr4 = g_strdup_printf("log dir: '%s' (XDG_CACHE_HOME='%s')", + g_get_user_cache_dir(), envXDG_CACHE_HOME); + virLogOneInitMsg(timestamp, envstr4, outputFunc, data); + } *needInit = false; }
However you decide about the '(unset)' vs '' for unset env variables: Reviewed-by: Peter Krempa <pkrempa@redhat.com>
On 4/8/26 3:59 AM, Peter Krempa via Devel wrote:
On Wed, Apr 08, 2026 at 00:10:38 -0400, Laine Stump via Devel wrote:
From: Laine Stump <laine@redhat.com>
When running in session/unprivileged mode, nearly all paths are prefixed with the returns from one of glib's g_get_user_*_dir() functions, which in turn base their selected paths on the settings of a few items in the user's environment ($XDG_*, or a subdirectory of $HOME if the relevant $XDG_* isn't set).
This patch logs the settings of these directories in the log banner in an attempt to help diagnose the problem when a file/socket open/create fails.
An example of the banner:
libvirt version: 12.3.0, package: 1.fc43 (Unknown, 2026-04-07-22:43:30, vhost) hostname: 83be0e173e02, user: qemu, uid: 107 home dir: '/' (HOME='/') runtime dir: '/.cache' (XDG_RUNTIME_DIR='(unset)') config dir: '/.config' (XDG_CONFIG_HOME='(unset)') log dir: '/.cache' (XDG_CACHE_HOME='(unset)') libvirt: XML-RPC error : Cannot create user runtime directory '/.cache/libvirt': Permission denied
Resolves: https://redhat.atlassian.net/browse/RHEL-70222 Resolves: https://redhat.atlassian.net/browse/RHEL-105490 Signed-off-by: Laine Stump <laine@redhat.com> ---
We could obviously add more information here (or less); it's difficult to know where to draw the line. Also, the astute reviewer will notice that all this code is executed once for each log target - we could do it all once at a higher level and cache it if we really wanted to. I'm not sure if it's worth the trouble though).
Changes in V2: modified the format/labeling of the data as Peter suggested, and included an example in the commit log.
src/util/virlog.c | 37 +++++++++++++++++++++++++++++++++++++ 1 file changed, 37 insertions(+)
diff --git a/src/util/virlog.c b/src/util/virlog.c index ccdf66c396..d2882d16ee 100644 --- a/src/util/virlog.c +++ b/src/util/virlog.c @@ -540,6 +540,43 @@ virLogToOneTarget(virLogSource *source, g_get_host_name(), username, uid); virLogOneInitMsg(timestamp, hoststr, outputFunc, data);
+ /* This info is only relevant when running as something other than root */ + if (uid != 0) { + g_autofree char *envHOME = NULL; + g_autofree char *envXDG_RUNTIME_DIR = NULL; + g_autofree char *envXDG_CONFIG_HOME = NULL; + g_autofree char *envXDG_CACHE_HOME = NULL; + + g_autofree char *envstr1 = NULL; + g_autofree char *envstr2 = NULL; + g_autofree char *envstr3 = NULL; + g_autofree char *envstr4 = NULL; + + if (!(envHOME = g_strdup(g_getenv("HOME")))) + envHOME = g_strdup("(unset)"); + if (!(envXDG_RUNTIME_DIR = g_strdup(g_getenv("XDG_RUNTIME_DIR")))) + envXDG_RUNTIME_DIR = g_strdup("(unset)"); + if (!(envXDG_CONFIG_HOME = g_strdup(g_getenv("XDG_CONFIG_HOME")))) + envXDG_CONFIG_HOME = g_strdup("(unset)"); + if (!(envXDG_CACHE_HOME = g_strdup(g_getenv("XDG_CACHE_HOME")))) + envXDG_CACHE_HOME = g_strdup("(unset)"); + + envstr1 = g_strdup_printf("home dir: '%s' (HOME='%s')", + g_get_home_dir(), envHOME);
I wonder if the '(unset)' string is even required. The code could be simplified, if we decide that e.g. empty string is okay to denote we won't need the extra variables:
envstr1 = g_strdup_printf("home dir: '%s' (HOME='%s')", g_get_home_dir(), NULLSTR_EMPTY(g_getenv("HOME")));
I'd never noticed NULLSTR_EMPTY() before - that could be useful! In this case though, I think I need to keep the strdups anyway, so may as well leave in the "(unset)" to differentiate from "". The reason I think the environment needs to be strdup'ed is that the result of g_getenv() is a pointer to a cached string owned by glib that is only guaranteed to remain unchanged until g_getenv() (or g_setenv()) is called again. Since the g_get_*_dir() functions all examine multiple environment variables, we should assume they might call g_getenv(), which could invalidate the g_getenv() return value that had just been put on the stack for the call to g_strdup_printf() that's building the log string. (I can't ever remember which order the args are evaluated in, but figure it's best to assume that it could be "either", and that way I'll always be safe :-)) (if it wasn't for that, I would probably follow your suggestion and just use NULLSTR_EMPTY())
+ virLogOneInitMsg(timestamp, envstr1, outputFunc, data); + + envstr2 = g_strdup_printf("runtime dir: '%s' (XDG_RUNTIME_DIR='%s')", + g_get_user_runtime_dir(), envXDG_RUNTIME_DIR); + virLogOneInitMsg(timestamp, envstr2, outputFunc, data); + + envstr3 = g_strdup_printf("config dir: '%s' (XDG_CONFIG_HOME='%s')", + g_get_user_config_dir(), envXDG_CONFIG_HOME); + virLogOneInitMsg(timestamp, envstr3, outputFunc, data); + + envstr4 = g_strdup_printf("log dir: '%s' (XDG_CACHE_HOME='%s')", + g_get_user_cache_dir(), envXDG_CACHE_HOME); + virLogOneInitMsg(timestamp, envstr4, outputFunc, data); + } *needInit = false; }
However you decide about the '(unset)' vs '' for unset env variables:
Reviewed-by: Peter Krempa <pkrempa@redhat.com>
On Thu, Apr 09, 2026 at 01:02:06 -0400, Laine Stump wrote:
On 4/8/26 3:59 AM, Peter Krempa via Devel wrote:
On Wed, Apr 08, 2026 at 00:10:38 -0400, Laine Stump via Devel wrote:
From: Laine Stump <laine@redhat.com>
When running in session/unprivileged mode, nearly all paths are prefixed with the returns from one of glib's g_get_user_*_dir() functions, which in turn base their selected paths on the settings of a few items in the user's environment ($XDG_*, or a subdirectory of $HOME if the relevant $XDG_* isn't set).
This patch logs the settings of these directories in the log banner in an attempt to help diagnose the problem when a file/socket open/create fails.
An example of the banner:
libvirt version: 12.3.0, package: 1.fc43 (Unknown, 2026-04-07-22:43:30, vhost) hostname: 83be0e173e02, user: qemu, uid: 107 home dir: '/' (HOME='/') runtime dir: '/.cache' (XDG_RUNTIME_DIR='(unset)') config dir: '/.config' (XDG_CONFIG_HOME='(unset)') log dir: '/.cache' (XDG_CACHE_HOME='(unset)') libvirt: XML-RPC error : Cannot create user runtime directory '/.cache/libvirt': Permission denied
Resolves: https://redhat.atlassian.net/browse/RHEL-70222 Resolves: https://redhat.atlassian.net/browse/RHEL-105490 Signed-off-by: Laine Stump <laine@redhat.com> ---
We could obviously add more information here (or less); it's difficult to know where to draw the line. Also, the astute reviewer will notice that all this code is executed once for each log target - we could do it all once at a higher level and cache it if we really wanted to. I'm not sure if it's worth the trouble though).
Changes in V2: modified the format/labeling of the data as Peter suggested, and included an example in the commit log.
src/util/virlog.c | 37 +++++++++++++++++++++++++++++++++++++ 1 file changed, 37 insertions(+)
diff --git a/src/util/virlog.c b/src/util/virlog.c index ccdf66c396..d2882d16ee 100644 --- a/src/util/virlog.c +++ b/src/util/virlog.c @@ -540,6 +540,43 @@ virLogToOneTarget(virLogSource *source, g_get_host_name(), username, uid); virLogOneInitMsg(timestamp, hoststr, outputFunc, data); + /* This info is only relevant when running as something other than root */ + if (uid != 0) { + g_autofree char *envHOME = NULL; + g_autofree char *envXDG_RUNTIME_DIR = NULL; + g_autofree char *envXDG_CONFIG_HOME = NULL; + g_autofree char *envXDG_CACHE_HOME = NULL; + + g_autofree char *envstr1 = NULL; + g_autofree char *envstr2 = NULL; + g_autofree char *envstr3 = NULL; + g_autofree char *envstr4 = NULL; + + if (!(envHOME = g_strdup(g_getenv("HOME")))) + envHOME = g_strdup("(unset)"); + if (!(envXDG_RUNTIME_DIR = g_strdup(g_getenv("XDG_RUNTIME_DIR")))) + envXDG_RUNTIME_DIR = g_strdup("(unset)"); + if (!(envXDG_CONFIG_HOME = g_strdup(g_getenv("XDG_CONFIG_HOME")))) + envXDG_CONFIG_HOME = g_strdup("(unset)"); + if (!(envXDG_CACHE_HOME = g_strdup(g_getenv("XDG_CACHE_HOME")))) + envXDG_CACHE_HOME = g_strdup("(unset)"); + + envstr1 = g_strdup_printf("home dir: '%s' (HOME='%s')", + g_get_home_dir(), envHOME);
I wonder if the '(unset)' string is even required. The code could be simplified, if we decide that e.g. empty string is okay to denote we won't need the extra variables:
envstr1 = g_strdup_printf("home dir: '%s' (HOME='%s')", g_get_home_dir(), NULLSTR_EMPTY(g_getenv("HOME")));
I'd never noticed NULLSTR_EMPTY() before - that could be useful! In this case though, I think I need to keep the strdups anyway, so may as well leave in the "(unset)" to differentiate from "". The reason I think the environment needs to be strdup'ed is that the result of g_getenv() is a pointer to a cached string owned by glib that is only guaranteed to remaina unchanged until g_getenv() (or g_setenv()) is called again. Since the
I've seen that in the docs ...
g_get_*_dir() functions all examine multiple environment variables, we should assume they might call g_getenv(), which could invalidate the
... but my review-saturated brain didn't get to the conclusion that this can have the same side-effect by calling g_setenv internally.
g_getenv() return value that had just been put on the stack for the call to g_strdup_printf() that's building the log string. (I can't ever remember which order the args are evaluated in, but figure it's best to assume that it could be "either", and that way I'll always be safe :-))
Yeah, evaluation order is UB AFAIR
(if it wasn't for that, I would probably follow your suggestion and just use NULLSTR_EMPTY())
+ virLogOneInitMsg(timestamp, envstr1, outputFunc, data); + + envstr2 = g_strdup_printf("runtime dir: '%s' (XDG_RUNTIME_DIR='%s')", + g_get_user_runtime_dir(), envXDG_RUNTIME_DIR); + virLogOneInitMsg(timestamp, envstr2, outputFunc, data); + + envstr3 = g_strdup_printf("config dir: '%s' (XDG_CONFIG_HOME='%s')", + g_get_user_config_dir(), envXDG_CONFIG_HOME); + virLogOneInitMsg(timestamp, envstr3, outputFunc, data); + + envstr4 = g_strdup_printf("log dir: '%s' (XDG_CACHE_HOME='%s')", + g_get_user_cache_dir(), envXDG_CACHE_HOME); + virLogOneInitMsg(timestamp, envstr4, outputFunc, data); + } *needInit = false; }
However you decide about the '(unset)' vs '' for unset env variables:
That removes the way for you to decide :P
Reviewed-by: Peter Krempa <pkrempa@redhat.com>
participants (2)
-
Laine Stump -
Peter Krempa