[PATCH 0/9] Fix stream event opaque data leak and improve debugging
This series fixes a leak of the 'opaque' pointer registered as private data for virStream Event callback. This manifests itself as leak of connections to virtstoraged in modular deployments if e.g. virsh vol-upload is used. The rest of the series adds various VIR_DEBUG statements and logging of class name and reference count for virObject(Un)Ref. Peter Krempa (9): remote_driver: Don't leak opaque pointer passed to 'virStreamEventAddCallback' libvirt_probes: Fix alignment of 'virobject' probe points util: probe: Add 'PROBE_DEBUG' util: object: Downgrade PROBE points to PROBE_DEBUG util: object: Add class name to the Ref/Unref/Dispose debug messages daemonRemoveClientStream: Add debug log remoteClientFree: Add debug log of parameters virNetClientStreamEventRemoveCallback: Add debug log util: virobject: Add debug refcounting output src/libvirt_probes.d | 12 +++++------ src/remote/remote_daemon_dispatch.c | 5 +++++ src/remote/remote_daemon_stream.c | 5 +++-- src/remote/remote_driver.c | 9 +++++++- src/rpc/virnetclientstream.c | 4 ++++ src/util/virobject.c | 33 +++++++++++++++++++++++++---- src/util/virprobe.h | 14 ++++++++++++ 7 files changed, 69 insertions(+), 13 deletions(-) -- 2.54.0
From: Peter Krempa <pkrempa@redhat.com> In the implementation of the virStream events in the remote driver, the freeing of the passed opaque data for the callback was guarded by: if (!cbdata->cb && cbdata->ff) (cbdata->ff)(cbdata->opaque); thus if the 'cb' is passed to 'virStreamEventAddCallback' the private data would never be freed once 'virStreamEventRemoveCallback' is called. The issue can be reproduced both in client applications which would register the stream callback and also in the libvirt daemons, when modular daemons are used. The virStream remote driver client code is in such deployments also used to tunnel requests from the hypervisor daemon (virtqemud) to sub-daemons (virstoraged). In those cases the leak is amplified as the stream event callback is internally used to do the tunnelling and the daemon dispatch code stores a reference to the 'virNetClient' object associated with the connection. As this causes the last reference on the virNetClient object to be still active, the corresponding connection to the storage daemon isn't closed either, leaking a FD both in virtqemud and virtstoraged. Internally the data is stored in 'struct remoteStreamCallbackData' which is defined only in 'remote_driver.c' and there's no code which would update the 'cb' field, thus the leak can't be avoided. Remove the check for 'cb'. My assumption is that this was supposed to mimic the 'dispatching' field in 'util/fdstream.c' or similar logic in other dispatch functions. The patch also adds debug statements which I've used to trace this. The leak of a connection in 'virtqemud' has the following backtrace under valgrind (note that the pointer is considered reachable and thus this isn't visible in default config): ==3678343== 136 bytes in 1 blocks are still reachable in loss record 2,680 of 2,964 ==3678343== at 0x48FC6CD: calloc (vg_replace_malloc.c:1616) ==3678343== by 0x4ED8A91: g_malloc0 (in /usr/lib64/libglib-2.0.so.0.8600.5) ==3678343== by 0x5019CA2: g_type_class_get (in /usr/lib64/libgobject-2.0.so.0.8600.5) ==3678343== by 0x5001011: g_object_new_with_properties (in /usr/lib64/libgobject-2.0.so.0.8600.5) ==3678343== by 0x5001EA0: g_object_new (in /usr/lib64/libgobject-2.0.so.0.8600.5) ==3678343== by 0x499E653: virObjectNew (virobject.c:252) ==3678343== by 0x499EA0F: virObjectLockableNew (virobject.c:274) ==3678343== by 0x4A84651: virNetClientStreamNew (virnetclientstream.c:144) ==3678343== by 0x4AE82AE: remoteStorageVolUpload (remote_client_bodies.h:8242) ==3678343== by 0x4BED13D: virStorageVolUpload (libvirt-storage.c:1809) ==3678343== by 0x4043539: remoteDispatchStorageVolUpload (remote_daemon_dispatch_stubs.h:20248) ==3678343== by 0x4043539: remoteDispatchStorageVolUploadHelper (remote_daemon_dispatch_stubs.h:20218) ==3678343== by 0x4A89A2C: virNetServerProgramDispatchCall (virnetserverprogram.c:423) ==3678343== by 0x4A89A2C: virNetServerProgramDispatch (virnetserverprogram.c:299) Resolves: https://redhat.atlassian.net/browse/RHEL-170773 Signed-off-by: Peter Krempa <pkrempa@redhat.com> --- src/remote/remote_driver.c | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/src/remote/remote_driver.c b/src/remote/remote_driver.c index 000c1b5324..e83b0abcbe 100644 --- a/src/remote/remote_driver.c +++ b/src/remote/remote_driver.c @@ -5363,8 +5363,12 @@ static void remoteStreamEventCallback(virNetClientStream *stream G_GNUC_UNUSED, static void remoteStreamCallbackFree(void *opaque) { struct remoteStreamCallbackData *cbdata = opaque; + virNetClientStream *privst = cbdata->st->privateData; - if (!cbdata->cb && cbdata->ff) + VIR_DEBUG("stream=%p, clientstream=%p, cb=%p, ff=%p, opaque=%p", + cbdata->st, privst, cbdata->cb, cbdata->ff, cbdata->opaque); + + if (cbdata->ff) (cbdata->ff)(cbdata->opaque); virObjectUnref(cbdata->st); @@ -5385,6 +5389,9 @@ remoteStreamEventAddCallback(virStreamPtr st, struct remoteStreamCallbackData *cbdata; VIR_LOCK_GUARD lock = remoteDriverLock(priv); + VIR_DEBUG("st=%p, clientstream=%p, events=%d, cb=%p, opaque=%p, ff=%p", + st, privst, events, cb, opaque, ff); + cbdata = g_new0(struct remoteStreamCallbackData, 1); cbdata->cb = cb; cbdata->opaque = opaque; -- 2.54.0
From: Peter Krempa <pkrempa@redhat.com> Signed-off-by: Peter Krempa <pkrempa@redhat.com> --- src/libvirt_probes.d | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/src/libvirt_probes.d b/src/libvirt_probes.d index d9e75d9797..58d362ac6e 100644 --- a/src/libvirt_probes.d +++ b/src/libvirt_probes.d @@ -13,12 +13,12 @@ provider libvirt { probe event_glib_remove_timeout_idle(int timer, void *ff, void *opaque); probe event_glib_dispatch_timeout(int timer, void *cb, void *opaque); - # file: src/util/virobject.c - # prefix: object - probe object_new(void *obj, const char *klassname); - probe object_ref(void *obj); - probe object_unref(void *obj); - probe object_dispose(void *obj); + # file: src/util/virobject.c + # prefix: object + probe object_new(void *obj, const char *klassname); + probe object_ref(void *obj); + probe object_unref(void *obj); + probe object_dispose(void *obj); # file: src/rpc/virnetsocket.c # prefix: rpc -- 2.54.0
From: Peter Krempa <pkrempa@redhat.com> The standard 'PROBE' macro uses the 'info' priority for the log entry corresponding to the probe point. While in some cases it makes sense to log above debug priority in others it does not. Add the possibility to pick a lower priority level. Signed-off-by: Peter Krempa <pkrempa@redhat.com> --- src/util/virprobe.h | 14 ++++++++++++++ 1 file changed, 14 insertions(+) diff --git a/src/util/virprobe.h b/src/util/virprobe.h index 80a5f48ec8..d23b626d2f 100644 --- a/src/util/virprobe.h +++ b/src/util/virprobe.h @@ -90,6 +90,15 @@ VIR_ADD_CASTS(__VA_ARGS__)); \ } +# define PROBE_DEBUG(NAME, FMT, ...) \ + VIR_DEBUG_INT(&virLogSelf, \ + __FILE__, __LINE__, __func__, \ + #NAME ": " FMT, __VA_ARGS__); \ + if (LIBVIRT_ ## NAME ## _ENABLED()) { \ + PROBE_EXPAND(LIBVIRT_ ## NAME, \ + VIR_ADD_CASTS(__VA_ARGS__)); \ + } + # define PROBE_QUIET(NAME, FMT, ...) \ if (LIBVIRT_ ## NAME ## _ENABLED()) { \ PROBE_EXPAND(LIBVIRT_ ## NAME, \ @@ -101,5 +110,10 @@ __FILE__, __LINE__, __func__, \ #NAME ": " FMT, __VA_ARGS__); +# define PROBE_DEBUG(NAME, FMT, ...) \ + VIR_DEBUG_INT(&virLogSelf, \ + __FILE__, __LINE__, __func__, \ + #NAME ": " FMT, __VA_ARGS__); \ + # define PROBE_QUIET(NAME, FMT, ...) #endif -- 2.54.0
From: Peter Krempa <pkrempa@redhat.com> The debug messages related to PROBE points in object handling don't really need to be logged with the 'info' priority. Downshift them to 'debug'. Signed-off-by: Peter Krempa <pkrempa@redhat.com> --- src/util/virobject.c | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/src/util/virobject.c b/src/util/virobject.c index 92af4f9fd6..1aa42e62c1 100644 --- a/src/util/virobject.c +++ b/src/util/virobject.c @@ -253,7 +253,7 @@ virObjectNew(virClass *klass) priv = vir_object_get_instance_private(obj); priv->klass = klass; - PROBE(OBJECT_NEW, "obj=%p classname=%s", obj, priv->klass->name); + PROBE_DEBUG(OBJECT_NEW, "obj=%p classname=%s", obj, priv->klass->name); return obj; } @@ -316,7 +316,7 @@ static void vir_object_finalize(GObject *gobj) virObjectPrivate *priv = vir_object_get_instance_private(obj); virClass *klass = priv->klass; - PROBE(OBJECT_DISPOSE, "obj=%p", gobj); + PROBE_DEBUG(OBJECT_DISPOSE, "obj=%p", gobj); while (klass) { if (klass->dispose) @@ -375,7 +375,7 @@ virObjectUnref(void *anyobj) return; g_object_unref(anyobj); - PROBE(OBJECT_UNREF, "obj=%p", obj); + PROBE_DEBUG(OBJECT_UNREF, "obj=%p", obj); } @@ -397,7 +397,7 @@ virObjectRef(void *anyobj) return NULL; g_object_ref(obj); - PROBE(OBJECT_REF, "obj=%p", obj); + PROBE_DEBUG(OBJECT_REF, "obj=%p", obj); return anyobj; } -- 2.54.0
From: Peter Krempa <pkrempa@redhat.com> Since the object stores the pointer to the parent class object internally we can add the name of the class of the object to the debug messages. Since the debug messages are based on probe points propagate it into the probe point rather than adding separate debug message. For virObjectUnref, this also fixes the ordering of the messages to be 'unref->dispose' by invoking the PROBE before unref rather than the other way around which didn't make sense in the logs and wouldn't allow accessing the class pointer from the already disposed-of object. Signed-off-by: Peter Krempa <pkrempa@redhat.com> --- src/libvirt_probes.d | 6 +++--- src/util/virobject.c | 14 +++++++++++--- 2 files changed, 14 insertions(+), 6 deletions(-) diff --git a/src/libvirt_probes.d b/src/libvirt_probes.d index 58d362ac6e..b73e9d6e82 100644 --- a/src/libvirt_probes.d +++ b/src/libvirt_probes.d @@ -16,9 +16,9 @@ provider libvirt { # file: src/util/virobject.c # prefix: object probe object_new(void *obj, const char *klassname); - probe object_ref(void *obj); - probe object_unref(void *obj); - probe object_dispose(void *obj); + probe object_ref(void *obj, const char *klassname); + probe object_unref(void *obj, const char *klassname); + probe object_dispose(void *obj, const char *klassname); # file: src/rpc/virnetsocket.c # prefix: rpc diff --git a/src/util/virobject.c b/src/util/virobject.c index 1aa42e62c1..0ccaaf101e 100644 --- a/src/util/virobject.c +++ b/src/util/virobject.c @@ -310,13 +310,14 @@ virObjectRWLockableNew(virClass *klass) return obj; } + static void vir_object_finalize(GObject *gobj) { virObject *obj = VIR_OBJECT(gobj); virObjectPrivate *priv = vir_object_get_instance_private(obj); virClass *klass = priv->klass; - PROBE_DEBUG(OBJECT_DISPOSE, "obj=%p", gobj); + PROBE_DEBUG(OBJECT_DISPOSE, "obj=%p classname=%s", gobj, klass->name); while (klass) { if (klass->dispose) @@ -370,12 +371,15 @@ void virObjectUnref(void *anyobj) { virObject *obj = anyobj; + virObjectPrivate *priv; if (VIR_OBJECT_NOTVALID(obj)) return; + priv = vir_object_get_instance_private(obj); + PROBE_DEBUG(OBJECT_UNREF, "obj=%p classname=%s", obj, priv->klass->name); + g_object_unref(anyobj); - PROBE_DEBUG(OBJECT_UNREF, "obj=%p", obj); } @@ -392,12 +396,16 @@ void * virObjectRef(void *anyobj) { virObject *obj = anyobj; + virObjectPrivate *priv; if (VIR_OBJECT_NOTVALID(obj)) return NULL; + g_object_ref(obj); - PROBE_DEBUG(OBJECT_REF, "obj=%p", obj); + + priv = vir_object_get_instance_private(obj); + PROBE_DEBUG(OBJECT_REF, "obj=%p classname=%s", obj, priv->klass->name); return anyobj; } -- 2.54.0
From: Peter Krempa <pkrempa@redhat.com> Signed-off-by: Peter Krempa <pkrempa@redhat.com> --- src/remote/remote_daemon_stream.c | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/src/remote/remote_daemon_stream.c b/src/remote/remote_daemon_stream.c index 453728a66b..3777c8e684 100644 --- a/src/remote/remote_daemon_stream.c +++ b/src/remote/remote_daemon_stream.c @@ -480,8 +480,9 @@ daemonRemoveClientStream(virNetServerClient *client, daemonClientStream *curr = priv->streams; daemonClientStream *prev = NULL; - VIR_DEBUG("client=%p, proc=%d, serial=%u, st=%p", - client, stream->procedure, stream->serial, stream->st); + VIR_DEBUG("client=%p, proc=%d, serial=%u, st=%p, closed=%d", + client, stream->procedure, stream->serial, stream->st, + stream->closed); if (stream->filterID != -1) { virNetServerClientRemoveFilter(client, -- 2.54.0
From: Peter Krempa <pkrempa@redhat.com> Add a debug log when remote client is beng disposed of. Signed-off-by: Peter Krempa <pkrempa@redhat.com> --- src/remote/remote_daemon_dispatch.c | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/src/remote/remote_daemon_dispatch.c b/src/remote/remote_daemon_dispatch.c index 81b0ed00da..55a1bd2af8 100644 --- a/src/remote/remote_daemon_dispatch.c +++ b/src/remote/remote_daemon_dispatch.c @@ -1808,6 +1808,11 @@ void remoteClientFree(void *data) { struct daemonClientPrivate *priv = data; + VIR_DEBUG("priv=%p, conn=%p, interfaceConn=%p, networkConn=%p, nodedevConn=%p, nwfilterConn=%p, secretConn=%p, storageConn=%p", + priv, priv->conn, priv->interfaceConn, priv->networkConn, + priv->nodedevConn, priv->nwfilterConn, priv->secretConn, + priv->storageConn); + if (priv->conn) virConnectClose(priv->conn); if (priv->interfaceConn) -- 2.54.0
From: Peter Krempa <pkrempa@redhat.com> Log when removig event callback including internal state. Signed-off-by: Peter Krempa <pkrempa@redhat.com> --- src/rpc/virnetclientstream.c | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/src/rpc/virnetclientstream.c b/src/rpc/virnetclientstream.c index 380b785869..bad356f8f3 100644 --- a/src/rpc/virnetclientstream.c +++ b/src/rpc/virnetclientstream.c @@ -773,6 +773,10 @@ int virNetClientStreamEventRemoveCallback(virNetClientStream *st) int ret = -1; virObjectLock(st); + + VIR_DEBUG("st=%p, cbDispatch=%u, cbOpaque=%p, cbFree=%p", + st, st->cbDispatch, st->cbOpaque, st->cbFree); + if (!st->cb) { virReportError(VIR_ERR_INTERNAL_ERROR, "%s", _("no stream callback registered")); -- 2.54.0
On a Thursday in 2026, Peter Krempa via Devel wrote:
From: Peter Krempa <pkrempa@redhat.com>
Log when removig event callback including internal state.
removing
Signed-off-by: Peter Krempa <pkrempa@redhat.com> --- src/rpc/virnetclientstream.c | 4 ++++ 1 file changed, 4 insertions(+)
diff --git a/src/rpc/virnetclientstream.c b/src/rpc/virnetclientstream.c index 380b785869..bad356f8f3 100644 --- a/src/rpc/virnetclientstream.c +++ b/src/rpc/virnetclientstream.c @@ -773,6 +773,10 @@ int virNetClientStreamEventRemoveCallback(virNetClientStream *st) int ret = -1;
virObjectLock(st); + + VIR_DEBUG("st=%p, cbDispatch=%u, cbOpaque=%p, cbFree=%p", + st, st->cbDispatch, st->cbOpaque, st->cbFree); + if (!st->cb) { virReportError(VIR_ERR_INTERNAL_ERROR, "%s", _("no stream callback registered")); -- 2.54.0
From: Peter Krempa <pkrempa@redhat.com> virObject internally uses g_object which doesn't expose the internal reference count. When debug logging we log ref/unref operations but when reading logs it's hard to follow if a precise reference count is needed at some points. Add a private reference counter variable and use it in debug messages of virObject operations. The code is designed so that it can be disabled if ever needed since it's just for debugging. For now let's keep it enabled. With all the informaton added the logs look like (timestamps trimmed): debug : virObjectRef:424 : OBJECT_REF: obj=0x7fffac001d30 classname=qemuMonitor refs=3 debug : virObjectUnref:392 : OBJECT_UNREF: obj=0x7fffac001d30 classname=qemuMonitor refs=2 debug : virObjectNew:264 : OBJECT_NEW: obj=0x7fffac00db70 classname=virDomainEventAgentLifecycle debug : virObjectUnref:392 : OBJECT_UNREF: obj=0x7fffac00db70 classname=virDomainEventAgentLifecycle refs=0 debug : vir_object_finalize:328 : OBJECT_DISPOSE: obj=0x7fffac00db70 classname=virDomainEventAgentLifecycle Signed-off-by: Peter Krempa <pkrempa@redhat.com> --- src/libvirt_probes.d | 4 ++-- src/util/virobject.c | 23 ++++++++++++++++++++--- 2 files changed, 22 insertions(+), 5 deletions(-) diff --git a/src/libvirt_probes.d b/src/libvirt_probes.d index b73e9d6e82..5f029c3eb6 100644 --- a/src/libvirt_probes.d +++ b/src/libvirt_probes.d @@ -16,8 +16,8 @@ provider libvirt { # file: src/util/virobject.c # prefix: object probe object_new(void *obj, const char *klassname); - probe object_ref(void *obj, const char *klassname); - probe object_unref(void *obj, const char *klassname); + probe object_ref(void *obj, const char *klassname, int refs); + probe object_unref(void *obj, const char *klassname, int refs); probe object_dispose(void *obj, const char *klassname); # file: src/rpc/virnetsocket.c diff --git a/src/util/virobject.c b/src/util/virobject.c index 0ccaaf101e..876a04789f 100644 --- a/src/util/virobject.c +++ b/src/util/virobject.c @@ -32,6 +32,8 @@ VIR_LOG_INIT("util.object"); +#define VIR_OBJECT_DEBUG_REFCOUNT 1 + static unsigned int magicCounter = 0xCAFE0000; struct _virClass { @@ -48,6 +50,9 @@ struct _virClass { typedef struct _virObjectPrivate virObjectPrivate; struct _virObjectPrivate { virClass *klass; +#if VIR_OBJECT_DEBUG_REFCOUNT + int refs; /* Informative reference count used for PROBE and debug messages. */ +#endif /* VIR_OBJECT_DEBUG_REFCOUNT */ }; @@ -253,6 +258,9 @@ virObjectNew(virClass *klass) priv = vir_object_get_instance_private(obj); priv->klass = klass; +#if VIR_OBJECT_DEBUG_REFCOUNT + priv->refs = 1; +#endif /*VIR_OBJECT_DEBUG_REFCOUNT */ PROBE_DEBUG(OBJECT_NEW, "obj=%p classname=%s", obj, priv->klass->name); return obj; @@ -372,12 +380,17 @@ virObjectUnref(void *anyobj) { virObject *obj = anyobj; virObjectPrivate *priv; + int refs = -1; if (VIR_OBJECT_NOTVALID(obj)) return; priv = vir_object_get_instance_private(obj); - PROBE_DEBUG(OBJECT_UNREF, "obj=%p classname=%s", obj, priv->klass->name); +#if VIR_OBJECT_DEBUG_REFCOUNT + refs = g_atomic_int_add(&priv->refs, -1) - 1; +#endif /* VIR_OBJECT_DEBUG_REFCOUNT */ + PROBE_DEBUG(OBJECT_UNREF, "obj=%p classname=%s refs=%d", + obj, priv->klass->name, refs); g_object_unref(anyobj); } @@ -397,15 +410,19 @@ virObjectRef(void *anyobj) { virObject *obj = anyobj; virObjectPrivate *priv; + int refs = -1; if (VIR_OBJECT_NOTVALID(obj)) return NULL; - g_object_ref(obj); priv = vir_object_get_instance_private(obj); - PROBE_DEBUG(OBJECT_REF, "obj=%p classname=%s", obj, priv->klass->name); +#if VIR_OBJECT_DEBUG_REFCOUNT + refs = g_atomic_int_add(&priv->refs, 1) + 1; +#endif /* VIR_OBJECT_DEBUG_REFCOUNT */ + PROBE_DEBUG(OBJECT_REF, "obj=%p classname=%s refs=%d", + obj, priv->klass->name, refs); return anyobj; } -- 2.54.0
On a Thursday in 2026, Peter Krempa via Devel wrote:
This series fixes a leak of the 'opaque' pointer registered as private data for virStream Event callback. This manifests itself as leak of connections to virtstoraged in modular deployments if e.g. virsh vol-upload is used.
The rest of the series adds various VIR_DEBUG statements and logging of class name and reference count for virObject(Un)Ref.
Peter Krempa (9): remote_driver: Don't leak opaque pointer passed to 'virStreamEventAddCallback' libvirt_probes: Fix alignment of 'virobject' probe points util: probe: Add 'PROBE_DEBUG' util: object: Downgrade PROBE points to PROBE_DEBUG util: object: Add class name to the Ref/Unref/Dispose debug messages daemonRemoveClientStream: Add debug log remoteClientFree: Add debug log of parameters virNetClientStreamEventRemoveCallback: Add debug log util: virobject: Add debug refcounting output
src/libvirt_probes.d | 12 +++++------ src/remote/remote_daemon_dispatch.c | 5 +++++ src/remote/remote_daemon_stream.c | 5 +++-- src/remote/remote_driver.c | 9 +++++++- src/rpc/virnetclientstream.c | 4 ++++ src/util/virobject.c | 33 +++++++++++++++++++++++++---- src/util/virprobe.h | 14 ++++++++++++ 7 files changed, 69 insertions(+), 13 deletions(-)
Reviewed-by: Ján Tomko <jtomko@redhat.com> Jano
participants (2)
-
Ján Tomko -
Peter Krempa