[libvirt] [PATCHv3 0/6] Fix memory corruption/crash in the connection close callback

This series fixes the crash resulting from a race condition in the connection close callback. To observe the crash apply the first patch only. To verify that the patchset fixes the crash please apply all but 2/6 and verify using virsh. 2/6 fixes the crash in a redundant way in case the close callback is used. In the case it isn't 2/6 itself can't fix the issue. For a better explanation of this problem please see the description in 6/6. Peter Krempa (4): DO NOT APPLY UPSTREAM: Close callback race corruption crash reproducer. virsh: Move cmdConnect from virsh-host.c to virsh.c virsh: Register and unregister the close callback also in cmdConnect rpc: Fix connection close callback race condition and memory corruption/crash Viktor Mihajlovski (2): libvirt: Increase connection reference count for callbacks virsh: Unregister the connection close notifier upon termination src/datatypes.c | 55 ++++++++++++++++++++---- src/datatypes.h | 22 +++++++--- src/libvirt.c | 30 ++++++++----- src/remote/remote_driver.c | 62 ++++++++++++++++----------- src/rpc/virnetclient.c | 9 +++- tools/virsh-host.c | 67 ----------------------------- tools/virsh.c | 102 ++++++++++++++++++++++++++++++++++++++++++--- 7 files changed, 225 insertions(+), 122 deletions(-) -- 1.8.1.5

--- src/remote/remote_driver.c | 5 +++++ src/rpc/virnetclient.c | 9 ++++++++- 2 files changed, 13 insertions(+), 1 deletion(-) diff --git a/src/remote/remote_driver.c b/src/remote/remote_driver.c index 885120e..711143a 100644 --- a/src/remote/remote_driver.c +++ b/src/remote/remote_driver.c @@ -1027,6 +1027,11 @@ doRemoteClose(virConnectPtr conn, struct private_data *priv) (xdrproc_t) xdr_void, (char *) NULL) == -1) ret = -1; + /* this is needed so that the remote side has the time to close the socket */ + printf("\n\n DEBUG: Connection close called, sleeping\n\n"); + sleep(1); + printf("\n\n DEBUG: Finishing close\n\n"); + #ifdef WITH_GNUTLS virObjectUnref(priv->tls); priv->tls = NULL; diff --git a/src/rpc/virnetclient.c b/src/rpc/virnetclient.c index 010c5c3..51b80a2 100644 --- a/src/rpc/virnetclient.c +++ b/src/rpc/virnetclient.c @@ -674,8 +674,15 @@ virNetClientCloseLocked(virNetClientPtr client) virKeepAliveStop(ka); virObjectUnref(ka); } - if (closeCb) + if (closeCb) { + /* the callback has to delay for a while until the connection object + * is being freed in the original thread that closed the connection + * */ + printf("\n\n DEBUG: calling the close callback\n\n"); + sleep(2); closeCb(client, closeReason, closeOpaque); + printf("\n\n DEBUG: callback returned\n\n"); + } virObjectLock(client); virObjectUnref(client); -- 1.8.1.5

On 03/31/2013 10:20 AM, Peter Krempa wrote:
--- src/remote/remote_driver.c | 5 +++++ src/rpc/virnetclient.c | 9 ++++++++- 2 files changed, 13 insertions(+), 1 deletion(-)
While I agree that this must not be applied upstream, I applied it locally and was indeed able to more reliably reproduce the problems. Thanks; having this patch in place locally will make the rest of my review easier.
diff --git a/src/remote/remote_driver.c b/src/remote/remote_driver.c index 885120e..711143a 100644 --- a/src/remote/remote_driver.c +++ b/src/remote/remote_driver.c @@ -1027,6 +1027,11 @@ doRemoteClose(virConnectPtr conn, struct private_data *priv) (xdrproc_t) xdr_void, (char *) NULL) == -1) ret = -1;
+ /* this is needed so that the remote side has the time to close the socket */ + printf("\n\n DEBUG: Connection close called, sleeping\n\n"); + sleep(1); + printf("\n\n DEBUG: Finishing close\n\n"); + #ifdef WITH_GNUTLS virObjectUnref(priv->tls); priv->tls = NULL; diff --git a/src/rpc/virnetclient.c b/src/rpc/virnetclient.c index 010c5c3..51b80a2 100644 --- a/src/rpc/virnetclient.c +++ b/src/rpc/virnetclient.c @@ -674,8 +674,15 @@ virNetClientCloseLocked(virNetClientPtr client) virKeepAliveStop(ka); virObjectUnref(ka); } - if (closeCb) + if (closeCb) { + /* the callback has to delay for a while until the connection object + * is being freed in the original thread that closed the connection + * */ + printf("\n\n DEBUG: calling the close callback\n\n"); + sleep(2); closeCb(client, closeReason, closeOpaque); + printf("\n\n DEBUG: callback returned\n\n"); + }
virObjectLock(client); virObjectUnref(client);
-- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org

From: Viktor Mihajlovski <mihajlov@linux.vnet.ibm.com> By adjusting the reference count of the connection object we prevent races between callback function and virConnectClose. Signed-off-by: Viktor Mihajlovski <mihajlov@linux.vnet.ibm.com> --- src/libvirt.c | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/src/libvirt.c b/src/libvirt.c index 4b9ea75..e9aff8a 100644 --- a/src/libvirt.c +++ b/src/libvirt.c @@ -20186,6 +20186,8 @@ int virConnectRegisterCloseCallback(virConnectPtr conn, return -1; } + virObjectRef(conn); + virMutexLock(&conn->lock); virCheckNonNullArgGoto(cb, error); @@ -20206,6 +20208,7 @@ int virConnectRegisterCloseCallback(virConnectPtr conn, error: virMutexUnlock(&conn->lock); + virObjectUnref(conn); virDispatchError(NULL); return -1; } @@ -20255,6 +20258,8 @@ int virConnectUnregisterCloseCallback(virConnectPtr conn, virMutexUnlock(&conn->lock); + virObjectUnref(conn); + return 0; error: -- 1.8.1.5

On 03/31/2013 10:20 AM, Peter Krempa wrote:
From: Viktor Mihajlovski <mihajlov@linux.vnet.ibm.com>
By adjusting the reference count of the connection object we prevent races between callback function and virConnectClose.
Signed-off-by: Viktor Mihajlovski <mihajlov@linux.vnet.ibm.com> --- src/libvirt.c | 5 +++++ 1 file changed, 5 insertions(+)
ACK. -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org

From: Viktor Mihajlovski <mihajlov@linux.vnet.ibm.com> Before closing the connection we unregister the close callback to prevent a reference leak. Further, the messages on virConnectClose != 0 are a bit more specific now. Signed-off-by: Viktor Mihajlovski <mihajlov@linux.vnet.ibm.com> --- tools/virsh.c | 23 ++++++++++++++++++----- 1 file changed, 18 insertions(+), 5 deletions(-) diff --git a/tools/virsh.c b/tools/virsh.c index 7ff12ec..d6c0e8c 100644 --- a/tools/virsh.c +++ b/tools/virsh.c @@ -321,9 +321,18 @@ vshReconnect(vshControl *ctl) { bool connected = false; - if (ctl->conn != NULL) { + if (ctl->conn) { + int ret; + connected = true; - virConnectClose(ctl->conn); + + virConnectUnregisterCloseCallback(ctl->conn, vshCatchDisconnect); + ret = virConnectClose(ctl->conn); + if (ret < 0) + vshError(ctl, "%s", _("Failed to disconnect from the hypervisor")); + else if (ret > 0) + vshError(ctl, "%s", _("One or more references were leaked after " + "disconnect from the hypervisor")); } ctl->conn = virConnectOpenAuth(ctl->name, @@ -2660,9 +2669,13 @@ vshDeinit(vshControl *ctl) VIR_FREE(ctl->name); if (ctl->conn) { int ret; - if ((ret = virConnectClose(ctl->conn)) != 0) { - vshError(ctl, _("Failed to disconnect from the hypervisor, %d leaked reference(s)"), ret); - } + virConnectUnregisterCloseCallback(ctl->conn, vshCatchDisconnect); + ret = virConnectClose(ctl->conn); + if (ret < 0) + vshError(ctl, "%s", _("Failed to disconnect from the hypervisor")); + else if (ret > 0) + vshError(ctl, "%s", _("One or more references were leaked after " + "disconnect from the hypervisor")); } virResetLastError(); -- 1.8.1.5

On 03/31/2013 10:20 AM, Peter Krempa wrote:
From: Viktor Mihajlovski <mihajlov@linux.vnet.ibm.com>
Before closing the connection we unregister the close callback to prevent a reference leak.
Further, the messages on virConnectClose != 0 are a bit more specific now.
Signed-off-by: Viktor Mihajlovski <mihajlov@linux.vnet.ibm.com> --- tools/virsh.c | 23 ++++++++++++++++++----- 1 file changed, 18 insertions(+), 5 deletions(-)
ACK. Thanks to patch 2/6, you could now technically close the connection first, then unregister the callback, and the reference held by the callback will ensure that the connection lives long enough to let that work even after things were "closed". Most likely to happen if things are multithreaded, where one thread is unregistering while another thread is closing the connection. But given that earlier libvirt had problems, we obviously don't want to advertise that "backwards" approach to cleanup. -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org

The function is used to establish connection so it should be in the main virsh file. This movement also enables further improvements done in next patches. --- tools/virsh-host.c | 67 ---------------------------------------------------- tools/virsh.c | 69 ++++++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 69 insertions(+), 67 deletions(-) diff --git a/tools/virsh-host.c b/tools/virsh-host.c index 2d49296..a7e31da 100644 --- a/tools/virsh-host.c +++ b/tools/virsh-host.c @@ -68,67 +68,6 @@ cmdCapabilities(vshControl *ctl, const vshCmd *cmd ATTRIBUTE_UNUSED) } /* - * "connect" command - */ -static const vshCmdInfo info_connect[] = { - {.name = "help", - .data = N_("(re)connect to hypervisor") - }, - {.name = "desc", - .data = N_("Connect to local hypervisor. This is built-in " - "command after shell start up.") - }, - {.name = NULL} -}; - -static const vshCmdOptDef opts_connect[] = { - {.name = "name", - .type = VSH_OT_DATA, - .flags = VSH_OFLAG_EMPTY_OK, - .help = N_("hypervisor connection URI") - }, - {.name = "readonly", - .type = VSH_OT_BOOL, - .help = N_("read-only connection") - }, - {.name = NULL} -}; - -static bool -cmdConnect(vshControl *ctl, const vshCmd *cmd) -{ - bool ro = vshCommandOptBool(cmd, "readonly"); - const char *name = NULL; - - if (ctl->conn) { - int ret; - if ((ret = virConnectClose(ctl->conn)) != 0) { - vshError(ctl, _("Failed to disconnect from the hypervisor, %d leaked reference(s)"), ret); - return false; - } - ctl->conn = NULL; - } - - VIR_FREE(ctl->name); - if (vshCommandOptStringReq(ctl, cmd, "name", &name) < 0) - return false; - - ctl->name = vshStrdup(ctl, name); - - ctl->useGetInfo = false; - ctl->useSnapshotOld = false; - ctl->readonly = ro; - - ctl->conn = virConnectOpenAuth(ctl->name, virConnectAuthPtrDefault, - ctl->readonly ? VIR_CONNECT_RO : 0); - - if (!ctl->conn) - vshError(ctl, "%s", _("Failed to connect to the hypervisor")); - - return !!ctl->conn; -} - -/* * "freecell" command */ static const vshCmdInfo info_freecell[] = { @@ -912,12 +851,6 @@ const vshCmdDef hostAndHypervisorCmds[] = { .info = info_capabilities, .flags = 0 }, - {.name = "connect", - .handler = cmdConnect, - .opts = opts_connect, - .info = info_connect, - .flags = VSH_CMD_FLAG_NOCONNECT - }, {.name = "freecell", .handler = cmdFreecell, .opts = opts_freecell, diff --git a/tools/virsh.c b/tools/virsh.c index d6c0e8c..a43c236 100644 --- a/tools/virsh.c +++ b/tools/virsh.c @@ -355,6 +355,69 @@ vshReconnect(vshControl *ctl) ctl->useSnapshotOld = false; } + +/* + * "connect" command + */ +static const vshCmdInfo info_connect[] = { + {.name = "help", + .data = N_("(re)connect to hypervisor") + }, + {.name = "desc", + .data = N_("Connect to local hypervisor. This is built-in " + "command after shell start up.") + }, + {.name = NULL} +}; + +static const vshCmdOptDef opts_connect[] = { + {.name = "name", + .type = VSH_OT_DATA, + .flags = VSH_OFLAG_EMPTY_OK, + .help = N_("hypervisor connection URI") + }, + {.name = "readonly", + .type = VSH_OT_BOOL, + .help = N_("read-only connection") + }, + {.name = NULL} +}; + +static bool +cmdConnect(vshControl *ctl, const vshCmd *cmd) +{ + bool ro = vshCommandOptBool(cmd, "readonly"); + const char *name = NULL; + + if (ctl->conn) { + int ret; + if ((ret = virConnectClose(ctl->conn)) != 0) { + vshError(ctl, _("Failed to disconnect from the hypervisor, %d leaked reference(s)"), ret); + return false; + } + ctl->conn = NULL; + } + + VIR_FREE(ctl->name); + if (vshCommandOptStringReq(ctl, cmd, "name", &name) < 0) + return false; + + ctl->name = vshStrdup(ctl, name); + + ctl->useGetInfo = false; + ctl->useSnapshotOld = false; + ctl->readonly = ro; + + ctl->conn = virConnectOpenAuth(ctl->name, virConnectAuthPtrDefault, + ctl->readonly ? VIR_CONNECT_RO : 0); + + if (!ctl->conn) + vshError(ctl, "%s", _("Failed to connect to the hypervisor")); + + return !!ctl->conn; +} + + #ifndef WIN32 static void vshPrintRaw(vshControl *ctl, ...) @@ -3000,6 +3063,12 @@ vshParseArgv(vshControl *ctl, int argc, char **argv) } static const vshCmdDef virshCmds[] = { + {.name = "connect", + .handler = cmdConnect, + .opts = opts_connect, + .info = info_connect, + .flags = VSH_CMD_FLAG_NOCONNECT + }, {.name = "cd", .handler = cmdCd, .opts = opts_cd, -- 1.8.1.5

On 03/31/2013 10:20 AM, Peter Krempa wrote:
The function is used to establish connection so it should be in the main virsh file. This movement also enables further improvements done in next patches. --- tools/virsh-host.c | 67 ---------------------------------------------------- tools/virsh.c | 69 ++++++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 69 insertions(+), 67 deletions(-)
Straightforward code motion; ACK with one nit:
@@ -3000,6 +3063,12 @@ vshParseArgv(vshControl *ctl, int argc, char **argv) }
static const vshCmdDef virshCmds[] = { + {.name = "connect", + .handler = cmdConnect, + .opts = opts_connect, + .info = info_connect, + .flags = VSH_CMD_FLAG_NOCONNECT + }, {.name = "cd",
This is not alphabetically sorted. Also, your commit message might mention that 'connect' has moved from 'virsh help host' into 'virsh help virsh' (I'm okay with that move, but it IS worth mentioning that it was intentional). -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org

This patch improves the error message after disconnecting from the hypervisor and adds the close callback operations required not to leak the callback reference. --- tools/virsh.c | 22 ++++++++++++++++------ 1 file changed, 16 insertions(+), 6 deletions(-) diff --git a/tools/virsh.c b/tools/virsh.c index a43c236..a6e6eec 100644 --- a/tools/virsh.c +++ b/tools/virsh.c @@ -391,10 +391,14 @@ cmdConnect(vshControl *ctl, const vshCmd *cmd) if (ctl->conn) { int ret; - if ((ret = virConnectClose(ctl->conn)) != 0) { - vshError(ctl, _("Failed to disconnect from the hypervisor, %d leaked reference(s)"), ret); - return false; - } + + virConnectUnregisterCloseCallback(ctl->conn, vshCatchDisconnect); + ret = virConnectClose(ctl->conn); + if (ret < 0) + vshError(ctl, "%s", _("Failed to disconnect from the hypervisor")); + else if (ret > 0) + vshError(ctl, "%s", _("One or more references were leaked after " + "disconnect from the hypervisor")); ctl->conn = NULL; } @@ -411,10 +415,16 @@ cmdConnect(vshControl *ctl, const vshCmd *cmd) ctl->conn = virConnectOpenAuth(ctl->name, virConnectAuthPtrDefault, ctl->readonly ? VIR_CONNECT_RO : 0); - if (!ctl->conn) + if (!ctl->conn) { vshError(ctl, "%s", _("Failed to connect to the hypervisor")); + return false; + } + + if (virConnectRegisterCloseCallback(ctl->conn, vshCatchDisconnect, + NULL, NULL) < 0) + vshError(ctl, "%s", _("Unable to register disconnect callback")); - return !!ctl->conn; + return true; } -- 1.8.1.5

On 03/31/2013 10:20 AM, Peter Krempa wrote:
This patch improves the error message after disconnecting from the hypervisor and adds the close callback operations required not to leak the callback reference. --- tools/virsh.c | 22 ++++++++++++++++------ 1 file changed, 16 insertions(+), 6 deletions(-)
ACK. -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org

The last Viktor's effort to fix the race and memory corruption unfortunately wasn't complete in the case the close callback was not registered in an connection. At that time, the trail of event's that I'll describe later could still happend and corrupt the memory or cause a crash of the client (including the daemon in case of a p2p migration). Consider the following prerequisities and trail of events: Let's have a remote connection to a hypervisor that doesn't have a close callback registered and the client is using the event loop. The crash happens in cooperation of 2 threads. Thread E is the event loop and thread W is the worker that does some stuff. R denotes the remote client. 1.) W - The client finishes everything and sheds the last reference on the client 2.) W - The virObject stuff invokes virConnectDispose that invokes doRemoteClose 3.) W - the remote close method invokes the REMOTE_PROC_CLOSE RPC method. 4.) W - The thread is preempted at this point. 5.) R - The remote side recieves the close and closes the socket. 6.) E - poll() wakes up due to the closed socket and invokes the close callback 7.) E - The event loop is preempted right before remoteClientCloseFunc is called 8.) W - The worker now finishes, and frees the conn object. 9.) E - The remoteClientCloseFunc accesses the now-freed conn object in the attempt to retrieve pointer for the real close callback. 10.) Kaboom, corrupted memory/segfault. This patch tries to fix this by introducing a new object that survives the freeing of the connection object. We can't increase the reference count on the connection object itself as the connection would never be closed as the connection is closed only when the reference count reaches zero. The new object - virConnectCloseCallbackData - is a lockable object that keeps the pointers to the real user registered callback and ensures that the connection callback is either not called if the connection was already freed or that the connection isn't freed while this is being called. --- src/datatypes.c | 55 ++++++++++++++++++++++++++++++++++++-------- src/datatypes.h | 22 ++++++++++++++---- src/libvirt.c | 29 ++++++++++++----------- src/remote/remote_driver.c | 57 +++++++++++++++++++++++++++------------------- 4 files changed, 112 insertions(+), 51 deletions(-) diff --git a/src/datatypes.c b/src/datatypes.c index b04e100..b21daac 100644 --- a/src/datatypes.c +++ b/src/datatypes.c @@ -37,6 +37,7 @@ virClassPtr virConnectClass; +virClassPtr virConnectCloseCallbackDataClass; virClassPtr virDomainClass; virClassPtr virDomainSnapshotClass; virClassPtr virInterfaceClass; @@ -49,6 +50,7 @@ virClassPtr virStorageVolClass; virClassPtr virStoragePoolClass; static void virConnectDispose(void *obj); +static void virConnectCloseCallbackDataDispose(void *obj); static void virDomainDispose(void *obj); static void virDomainSnapshotDispose(void *obj); static void virInterfaceDispose(void *obj); @@ -63,14 +65,19 @@ static void virStoragePoolDispose(void *obj); static int virDataTypesOnceInit(void) { -#define DECLARE_CLASS(basename) \ - if (!(basename ## Class = virClassNew(virClassForObject(), \ +#define DECLARE_CLASS_COMMON(basename, parent) \ + if (!(basename ## Class = virClassNew(parent, \ #basename, \ sizeof(basename), \ basename ## Dispose))) \ return -1; +#define DECLARE_CLASS(basename) \ + DECLARE_CLASS_COMMON(basename, virClassForObject()) +#define DECLARE_CLASS_LOCKABLE(basename) \ + DECLARE_CLASS_COMMON(basename, virClassForObjectLockable()) DECLARE_CLASS(virConnect); + DECLARE_CLASS_LOCKABLE(virConnectCloseCallbackData); DECLARE_CLASS(virDomain); DECLARE_CLASS(virDomainSnapshot); DECLARE_CLASS(virInterface); @@ -82,6 +89,8 @@ virDataTypesOnceInit(void) DECLARE_CLASS(virStorageVol); DECLARE_CLASS(virStoragePool); +#undef DECLARE_CLASS_COMMON +#undef DECLARE_CLASS_LOCKABLE #undef DECLARE_CLASS return 0; @@ -107,12 +116,17 @@ virGetConnect(void) if (!(ret = virObjectNew(virConnectClass))) return NULL; - if (virMutexInit(&ret->lock) < 0) { - VIR_FREE(ret); - return NULL; - } + if (!(ret->closeCallback = virObjectNew(virConnectCloseCallbackDataClass))) + goto error; + + if (virMutexInit(&ret->lock) < 0) + goto error; return ret; + +error: + virObjectUnref(ret); + return NULL; } /** @@ -146,19 +160,42 @@ virConnectDispose(void *obj) virMutexLock(&conn->lock); - if (conn->closeFreeCallback) - conn->closeFreeCallback(conn->closeOpaque); - virResetError(&conn->err); virURIFree(conn->uri); + virObjectLock(conn->closeCallback); + conn->closeCallback->callback = NULL; + virObjectUnlock(conn->closeCallback); + + virObjectUnref(conn->closeCallback); + virMutexUnlock(&conn->lock); virMutexDestroy(&conn->lock); } /** + * virConnectCloseCallbackDataDispose: + * @obj: the close callback data to release + * + * Release resources bound to the connection close callback. + */ +static void +virConnectCloseCallbackDataDispose(void *obj) +{ + virConnectCloseCallbackDataPtr cb = obj; + + virObjectLock(cb); + + if (cb->freeCallback) + cb->freeCallback(cb->opaque); + + virObjectUnlock(cb); +} + + +/** * virGetDomain: * @conn: the hypervisor connection * @name: pointer to the domain name diff --git a/src/datatypes.h b/src/datatypes.h index a1dfc1e..e5ecf18 100644 --- a/src/datatypes.h +++ b/src/datatypes.h @@ -93,6 +93,22 @@ extern virClassPtr virStoragePoolClass; # define VIR_IS_DOMAIN_SNAPSHOT(obj) \ (VIR_IS_SNAPSHOT(obj) && VIR_IS_DOMAIN((obj)->domain)) + +typedef struct _virConnectCloseCallbackData virConnectCloseCallbackData; +typedef virConnectCloseCallbackData *virConnectCloseCallbackDataPtr; + +/** + * Internal structure holding data related to connection close callbacks. + */ +struct _virConnectCloseCallbackData { + virObjectLockable parent; + + virConnectPtr conn; + virConnectCloseFunc callback; + void *opaque; + virFreeCallback freeCallback; +}; + /** * _virConnect: * @@ -142,11 +158,7 @@ struct _virConnect { void *userData; /* the user data */ /* Per-connection close callback */ - virConnectCloseFunc closeCallback; - void *closeOpaque; - virFreeCallback closeFreeCallback; - bool closeDispatch; - unsigned closeUnregisterCount; + virConnectCloseCallbackDataPtr closeCallback; }; /** diff --git a/src/libvirt.c b/src/libvirt.c index e9aff8a..cef9f1f 100644 --- a/src/libvirt.c +++ b/src/libvirt.c @@ -20189,24 +20189,27 @@ int virConnectRegisterCloseCallback(virConnectPtr conn, virObjectRef(conn); virMutexLock(&conn->lock); + virObjectLock(conn->closeCallback); virCheckNonNullArgGoto(cb, error); - if (conn->closeCallback) { + if (conn->closeCallback->callback) { virLibConnError(VIR_ERR_OPERATION_INVALID, "%s", _("A close callback is already registered")); goto error; } - conn->closeCallback = cb; - conn->closeOpaque = opaque; - conn->closeFreeCallback = freecb; + conn->closeCallback->callback = cb; + conn->closeCallback->opaque = opaque; + conn->closeCallback->freeCallback = freecb; + virObjectUnlock(conn->closeCallback); virMutexUnlock(&conn->lock); return 0; error: + virObjectUnlock(conn->closeCallback); virMutexUnlock(&conn->lock); virObjectUnref(conn); virDispatchError(NULL); @@ -20240,29 +20243,29 @@ int virConnectUnregisterCloseCallback(virConnectPtr conn, } virMutexLock(&conn->lock); + virObjectLock(conn->closeCallback); virCheckNonNullArgGoto(cb, error); - if (conn->closeCallback != cb) { + if (conn->closeCallback->callback != cb) { virLibConnError(VIR_ERR_OPERATION_INVALID, "%s", _("A different callback was requested")); goto error; } - conn->closeCallback = NULL; - conn->closeUnregisterCount++; - if (!conn->closeDispatch && conn->closeFreeCallback) - conn->closeFreeCallback(conn->closeOpaque); - conn->closeFreeCallback = NULL; - conn->closeOpaque = NULL; - - virMutexUnlock(&conn->lock); + conn->closeCallback->callback = NULL; + if (conn->closeCallback->freeCallback) + conn->closeCallback->freeCallback(conn->closeCallback->opaque); + conn->closeCallback->freeCallback = NULL; virObjectUnref(conn); + virObjectUnlock(conn->closeCallback); + virMutexUnlock(&conn->lock); return 0; error: + virObjectUnlock(conn->closeCallback); virMutexUnlock(&conn->lock); virDispatchError(NULL); return -1; diff --git a/src/remote/remote_driver.c b/src/remote/remote_driver.c index 711143a..200043e 100644 --- a/src/remote/remote_driver.c +++ b/src/remote/remote_driver.c @@ -337,32 +337,38 @@ enum virDrvOpenRemoteFlags { VIR_DRV_OPEN_REMOTE_AUTOSTART = (1 << 2), /* Autostart a per-user daemon */ }; +static void +remoteClientCloseFreeFunc(void *opaque) +{ + virConnectCloseCallbackDataPtr cbdata = opaque; + + virObjectUnref(cbdata); +} -static void remoteClientCloseFunc(virNetClientPtr client ATTRIBUTE_UNUSED, - int reason, - void *opaque) +static void +remoteClientCloseFunc(virNetClientPtr client ATTRIBUTE_UNUSED, + int reason, + void *opaque) { - virConnectPtr conn = opaque; + virConnectCloseCallbackDataPtr cbdata = opaque; - virMutexLock(&conn->lock); - if (conn->closeCallback) { - virConnectCloseFunc closeCallback = conn->closeCallback; - void *closeOpaque = conn->closeOpaque; - virFreeCallback closeFreeCallback = conn->closeFreeCallback; - unsigned closeUnregisterCount = conn->closeUnregisterCount; + virObjectLock(cbdata); - VIR_DEBUG("Triggering connection close callback %p reason=%d", - conn->closeCallback, reason); - conn->closeDispatch = true; - virMutexUnlock(&conn->lock); - closeCallback(conn, reason, closeOpaque); - virMutexLock(&conn->lock); - conn->closeDispatch = false; - if (conn->closeUnregisterCount != closeUnregisterCount && - closeFreeCallback) - closeFreeCallback(closeOpaque); + if (cbdata->callback) { + VIR_DEBUG("Triggering connection close callback %p reason=%d, opaque=%p", + cbdata->callback, reason, cbdata->opaque); + cbdata->callback(cbdata->conn, reason, cbdata->opaque); + + if (cbdata->freeCallback) + cbdata->freeCallback(cbdata->opaque); + cbdata->callback = NULL; + cbdata->freeCallback = NULL; } - virMutexUnlock(&conn->lock); + virObjectUnlock(cbdata); + + /* free the connection reference that comes along with the callback + * registration */ + virObjectUnref(cbdata->conn); } /* helper macro to ease extraction of arguments from the URI */ @@ -765,9 +771,11 @@ doRemoteOpen(virConnectPtr conn, goto failed; } + virObjectRef(conn->closeCallback); + virNetClientSetCloseCallback(priv->client, remoteClientCloseFunc, - conn, NULL); + conn->closeCallback, remoteClientCloseFreeFunc); if (!(priv->remoteProgram = virNetClientProgramNew(REMOTE_PROGRAM, REMOTE_PROTOCOL_VERSION, @@ -1036,10 +1044,11 @@ doRemoteClose(virConnectPtr conn, struct private_data *priv) virObjectUnref(priv->tls); priv->tls = NULL; #endif + virNetClientSetCloseCallback(priv->client, NULL, - NULL, - NULL); + conn->closeCallback, remoteClientCloseFreeFunc); + virNetClientClose(priv->client); virObjectUnref(priv->client); priv->client = NULL; -- 1.8.1.5

On 03/31/2013 10:20 AM, Peter Krempa wrote:
The last Viktor's effort to fix the race and memory corruption unfortunately wasn't complete in the case the close callback was not registered in an connection. At that time, the trail of event's that I'll describe later could still happend and corrupt the memory or cause a crash of the client (including the daemon in case of a p2p migration).
Consider the following prerequisities and trail of events: Let's have a remote connection to a hypervisor that doesn't have a close callback registered and the client is using the event loop. The crash happens in cooperation of 2 threads. Thread E is the event loop and thread W is the worker that does some stuff. R denotes the remote client.
1.) W - The client finishes everything and sheds the last reference on the client 2.) W - The virObject stuff invokes virConnectDispose that invokes doRemoteClose 3.) W - the remote close method invokes the REMOTE_PROC_CLOSE RPC method. 4.) W - The thread is preempted at this point. 5.) R - The remote side recieves the close and closes the socket. 6.) E - poll() wakes up due to the closed socket and invokes the close callback 7.) E - The event loop is preempted right before remoteClientCloseFunc is called 8.) W - The worker now finishes, and frees the conn object. 9.) E - The remoteClientCloseFunc accesses the now-freed conn object in the attempt to retrieve pointer for the real close callback. 10.) Kaboom, corrupted memory/segfault.
With patch 1/6 alone, I think I saw exactly this scenario by doing: # virsh migrate dom qemu+ssh://remote/system --live --p2p --verbose where I observed this on the source side under valgrind. [as to the patch itself, I'm still testing it, and ran out of time to definitively say ack today, but so far I'm liking it] DEBUG: Connection close called, sleeping 2013-04-01 23:31:06.966+0000: 8724: error : virNetSocketReadWire:1181 : End of file while reading data: : Input/output error DEBUG: calling the close callback DEBUG: Finishing close ==8724== Invalid read of size 4 ==8724== at 0x390A009220: pthread_mutex_lock (pthread_mutex_lock.c:50) ==8724== by 0x4E89372: virMutexLock (threads-pthread.c:85) ==8724== by 0x4F76CC0: remoteClientCloseFunc (remote_driver.c:337) ==8724== by 0x4FA7E12: virNetClientCloseLocked (virnetclient.c:693) ==8724== by 0x4FAAB69: virNetClientIncomingEvent (virnetclient.c:1866) ==8724== by 0x4FBFE73: virNetSocketEventHandle (virnetsocket.c:1500) ==8724== by 0x4E6E69F: virEventPollDispatchHandles (event_poll.c:485) ==8724== by 0x4E6EF38: virEventPollRunOnce (event_poll.c:632) ==8724== by 0x4E6CFD7: virEventRunDefaultImpl (event.c:247) ==8724== by 0x4FB2DEB: virNetServerRun (virnetserver.c:748) ==8724== by 0x40DC17: main (libvirtd.c:1228) ==8724== Address 0x14df2540 is 160 bytes inside a block of size 312 free'd ==8724== at 0x4A063F0: free (vg_replace_malloc.c:446) ==8724== by 0x4E7AA26: virFree (memory.c:419) ==8724== by 0x4E94D5C: virObjectUnref (virobject.c:145) ==8724== by 0x4F2EEDB: virConnectClose (libvirt.c:1458) ==8724== by 0x12A9A67E: doPeer2PeerMigrate (qemu_migration.c:2630) ==8724== by 0x12A9A8BB: qemuMigrationPerformJob (qemu_migration.c:2685) ==8724== by 0x12A9B0D4: qemuMigrationPerform (qemu_migration.c:2872) ==8724== by 0x12ADA7E0: qemuDomainMigratePerform3 (qemu_driver.c:10107) ==8724== by 0x4F3D7D0: virDomainMigratePerform3 (libvirt.c:6253) ==8724== by 0x438CD7: remoteDispatchDomainMigratePerform3 (remote.c:3593) ==8724== by 0x418A8D: remoteDispatchDomainMigratePerform3Helper (remote_dispatch.h:3629) ==8724== by 0x4FAC16D: virNetServerProgramDispatchCall (virnetserverprogram.c:431) ==8724== ==8724== Invalid read of size 4 ==8724== at 0x390A00924C: pthread_mutex_lock (pthread_mutex_lock.c:61) ==8724== by 0x4E89372: virMutexLock (threads-pthread.c:85) ==8724== by 0x4F76CC0: remoteClientCloseFunc (remote_driver.c:337) ==8724== by 0x4FA7E12: virNetClientCloseLocked (virnetclient.c:693) ==8724== by 0x4FAAB69: virNetClientIncomingEvent (virnetclient.c:1866) ==8724== by 0x4FBFE73: virNetSocketEventHandle (virnetsocket.c:1500) ==8724== by 0x4E6E69F: virEventPollDispatchHandles (event_poll.c:485) ==8724== by 0x4E6EF38: virEventPollRunOnce (event_poll.c:632) ==8724== by 0x4E6CFD7: virEventRunDefaultImpl (event.c:247) ==8724== by 0x4FB2DEB: virNetServerRun (virnetserver.c:748) ==8724== by 0x40DC17: main (libvirtd.c:1228) ==8724== Address 0x14df2530 is 144 bytes inside a block of size 312 free'd ==8724== at 0x4A063F0: free (vg_replace_malloc.c:446) ==8724== by 0x4E7AA26: virFree (memory.c:419) ==8724== by 0x4E94D5C: virObjectUnref (virobject.c:145) ==8724== by 0x4F2EEDB: virConnectClose (libvirt.c:1458) ==8724== by 0x12A9A67E: doPeer2PeerMigrate (qemu_migration.c:2630) ==8724== by 0x12A9A8BB: qemuMigrationPerformJob (qemu_migration.c:2685) ==8724== by 0x12A9B0D4: qemuMigrationPerform (qemu_migration.c:2872) ==8724== by 0x12ADA7E0: qemuDomainMigratePerform3 (qemu_driver.c:10107) ==8724== by 0x4F3D7D0: virDomainMigratePerform3 (libvirt.c:6253) ==8724== by 0x438CD7: remoteDispatchDomainMigratePerform3 (remote.c:3593) ==8724== by 0x418A8D: remoteDispatchDomainMigratePerform3Helper (remote_dispatch.h:3629) ==8724== by 0x4FAC16D: virNetServerProgramDispatchCall (virnetserverprogram.c:431) ==8724== ==8724== Invalid read of size 4 ==8724== at 0x390A009257: pthread_mutex_lock (pthread_mutex_lock.c:127) ==8724== by 0x4E89372: virMutexLock (threads-pthread.c:85) ==8724== by 0x4F76CC0: remoteClientCloseFunc (remote_driver.c:337) ==8724== by 0x4FA7E12: virNetClientCloseLocked (virnetclient.c:693) ==8724== by 0x4FAAB69: virNetClientIncomingEvent (virnetclient.c:1866) ==8724== by 0x4FBFE73: virNetSocketEventHandle (virnetsocket.c:1500) ==8724== by 0x4E6E69F: virEventPollDispatchHandles (event_poll.c:485) ==8724== by 0x4E6EF38: virEventPollRunOnce (event_poll.c:632) ==8724== by 0x4E6CFD7: virEventRunDefaultImpl (event.c:247) ==8724== by 0x4FB2DEB: virNetServerRun (virnetserver.c:748) ==8724== by 0x40DC17: main (libvirtd.c:1228) ==8724== Address 0x14df253c is 156 bytes inside a block of size 312 free'd ==8724== at 0x4A063F0: free (vg_replace_malloc.c:446) ==8724== by 0x4E7AA26: virFree (memory.c:419) ==8724== by 0x4E94D5C: virObjectUnref (virobject.c:145) ==8724== by 0x4F2EEDB: virConnectClose (libvirt.c:1458) ==8724== by 0x12A9A67E: doPeer2PeerMigrate (qemu_migration.c:2630) ==8724== by 0x12A9A8BB: qemuMigrationPerformJob (qemu_migration.c:2685) ==8724== by 0x12A9B0D4: qemuMigrationPerform (qemu_migration.c:2872) ==8724== by 0x12ADA7E0: qemuDomainMigratePerform3 (qemu_driver.c:10107) ==8724== by 0x4F3D7D0: virDomainMigratePerform3 (libvirt.c:6253) ==8724== by 0x438CD7: remoteDispatchDomainMigratePerform3 (remote.c:3593) ==8724== by 0x418A8D: remoteDispatchDomainMigratePerform3Helper (remote_dispatch.h:3629) ==8724== by 0x4FAC16D: virNetServerProgramDispatchCall (virnetserverprogram.c:431) ==8724== ==8724== Invalid write of size 4 ==8724== at 0x390A00925C: pthread_mutex_lock (pthread_mutex_lock.c:125) ==8724== by 0x4E89372: virMutexLock (threads-pthread.c:85) ==8724== by 0x4F76CC0: remoteClientCloseFunc (remote_driver.c:337) ==8724== by 0x4FA7E12: virNetClientCloseLocked (virnetclient.c:693) ==8724== by 0x4FAAB69: virNetClientIncomingEvent (virnetclient.c:1866) ==8724== by 0x4FBFE73: virNetSocketEventHandle (virnetsocket.c:1500) ==8724== by 0x4E6E69F: virEventPollDispatchHandles (event_poll.c:485) ==8724== by 0x4E6EF38: virEventPollRunOnce (event_poll.c:632) ==8724== by 0x4E6CFD7: virEventRunDefaultImpl (event.c:247) ==8724== by 0x4FB2DEB: virNetServerRun (virnetserver.c:748) ==8724== by 0x40DC17: main (libvirtd.c:1228) ==8724== Address 0x14df2538 is 152 bytes inside a block of size 312 free'd ==8724== at 0x4A063F0: free (vg_replace_malloc.c:446) ==8724== by 0x4E7AA26: virFree (memory.c:419) ==8724== by 0x4E94D5C: virObjectUnref (virobject.c:145) ==8724== by 0x4F2EEDB: virConnectClose (libvirt.c:1458) ==8724== by 0x12A9A67E: doPeer2PeerMigrate (qemu_migration.c:2630) ==8724== by 0x12A9A8BB: qemuMigrationPerformJob (qemu_migration.c:2685) ==8724== by 0x12A9B0D4: qemuMigrationPerform (qemu_migration.c:2872) ==8724== by 0x12ADA7E0: qemuDomainMigratePerform3 (qemu_driver.c:10107) ==8724== by 0x4F3D7D0: virDomainMigratePerform3 (libvirt.c:6253) ==8724== by 0x438CD7: remoteDispatchDomainMigratePerform3 (remote.c:3593) ==8724== by 0x418A8D: remoteDispatchDomainMigratePerform3Helper (remote_dispatch.h:3629) ==8724== by 0x4FAC16D: virNetServerProgramDispatchCall (virnetserverprogram.c:431) ==8724== ==8724== Invalid read of size 8 ==8724== at 0x4F76CC5: remoteClientCloseFunc (remote_driver.c:338) ==8724== by 0x4FA7E12: virNetClientCloseLocked (virnetclient.c:693) ==8724== by 0x4FAAB69: virNetClientIncomingEvent (virnetclient.c:1866) ==8724== by 0x4FBFE73: virNetSocketEventHandle (virnetsocket.c:1500) ==8724== by 0x4E6E69F: virEventPollDispatchHandles (event_poll.c:485) ==8724== by 0x4E6EF38: virEventPollRunOnce (event_poll.c:632) ==8724== by 0x4E6CFD7: virEventRunDefaultImpl (event.c:247) ==8724== by 0x4FB2DEB: virNetServerRun (virnetserver.c:748) ==8724== by 0x40DC17: main (libvirtd.c:1228) ==8724== Address 0x14df25b8 is 280 bytes inside a block of size 312 free'd ==8724== at 0x4A063F0: free (vg_replace_malloc.c:446) ==8724== by 0x4E7AA26: virFree (memory.c:419) ==8724== by 0x4E94D5C: virObjectUnref (virobject.c:145) ==8724== by 0x4F2EEDB: virConnectClose (libvirt.c:1458) ==8724== by 0x12A9A67E: doPeer2PeerMigrate (qemu_migration.c:2630) ==8724== by 0x12A9A8BB: qemuMigrationPerformJob (qemu_migration.c:2685) ==8724== by 0x12A9B0D4: qemuMigrationPerform (qemu_migration.c:2872) ==8724== by 0x12ADA7E0: qemuDomainMigratePerform3 (qemu_driver.c:10107) ==8724== by 0x4F3D7D0: virDomainMigratePerform3 (libvirt.c:6253) ==8724== by 0x438CD7: remoteDispatchDomainMigratePerform3 (remote.c:3593) ==8724== by 0x418A8D: remoteDispatchDomainMigratePerform3Helper (remote_dispatch.h:3629) ==8724== by 0x4FAC16D: virNetServerProgramDispatchCall (virnetserverprogram.c:431) ==8724== ==8724== Invalid read of size 4 ==8724== at 0x390A00A630: pthread_mutex_unlock (pthread_mutex_unlock.c:37) ==8724== by 0x4E893AF: virMutexUnlock (threads-pthread.c:90) ==8724== by 0x4F76DD1: remoteClientCloseFunc (remote_driver.c:354) ==8724== by 0x4FA7E12: virNetClientCloseLocked (virnetclient.c:693) ==8724== by 0x4FAAB69: virNetClientIncomingEvent (virnetclient.c:1866) ==8724== by 0x4FBFE73: virNetSocketEventHandle (virnetsocket.c:1500) ==8724== by 0x4E6E69F: virEventPollDispatchHandles (event_poll.c:485) ==8724== by 0x4E6EF38: virEventPollRunOnce (event_poll.c:632) ==8724== by 0x4E6CFD7: virEventRunDefaultImpl (event.c:247) ==8724== by 0x4FB2DEB: virNetServerRun (virnetserver.c:748) ==8724== by 0x40DC17: main (libvirtd.c:1228) ==8724== Address 0x14df2540 is 160 bytes inside a block of size 312 free'd ==8724== at 0x4A063F0: free (vg_replace_malloc.c:446) ==8724== by 0x4E7AA26: virFree (memory.c:419) ==8724== by 0x4E94D5C: virObjectUnref (virobject.c:145) ==8724== by 0x4F2EEDB: virConnectClose (libvirt.c:1458) ==8724== by 0x12A9A67E: doPeer2PeerMigrate (qemu_migration.c:2630) ==8724== by 0x12A9A8BB: qemuMigrationPerformJob (qemu_migration.c:2685) ==8724== by 0x12A9B0D4: qemuMigrationPerform (qemu_migration.c:2872) ==8724== by 0x12ADA7E0: qemuDomainMigratePerform3 (qemu_driver.c:10107) ==8724== by 0x4F3D7D0: virDomainMigratePerform3 (libvirt.c:6253) ==8724== by 0x438CD7: remoteDispatchDomainMigratePerform3 (remote.c:3593) ==8724== by 0x418A8D: remoteDispatchDomainMigratePerform3Helper (remote_dispatch.h:3629) ==8724== by 0x4FAC16D: virNetServerProgramDispatchCall (virnetserverprogram.c:431) ==8724== ==8724== Invalid write of size 4 ==8724== at 0x390A00A645: pthread_mutex_unlock (pthread_mutex_unlock.c:46) ==8724== by 0x4E893AF: virMutexUnlock (threads-pthread.c:90) ==8724== by 0x4F76DD1: remoteClientCloseFunc (remote_driver.c:354) ==8724== by 0x4FA7E12: virNetClientCloseLocked (virnetclient.c:693) ==8724== by 0x4FAAB69: virNetClientIncomingEvent (virnetclient.c:1866) ==8724== by 0x4FBFE73: virNetSocketEventHandle (virnetsocket.c:1500) ==8724== by 0x4E6E69F: virEventPollDispatchHandles (event_poll.c:485) ==8724== by 0x4E6EF38: virEventPollRunOnce (event_poll.c:632) ==8724== by 0x4E6CFD7: virEventRunDefaultImpl (event.c:247) ==8724== by 0x4FB2DEB: virNetServerRun (virnetserver.c:748) ==8724== by 0x40DC17: main (libvirtd.c:1228) ==8724== Address 0x14df2538 is 152 bytes inside a block of size 312 free'd ==8724== at 0x4A063F0: free (vg_replace_malloc.c:446) ==8724== by 0x4E7AA26: virFree (memory.c:419) ==8724== by 0x4E94D5C: virObjectUnref (virobject.c:145) ==8724== by 0x4F2EEDB: virConnectClose (libvirt.c:1458) ==8724== by 0x12A9A67E: doPeer2PeerMigrate (qemu_migration.c:2630) ==8724== by 0x12A9A8BB: qemuMigrationPerformJob (qemu_migration.c:2685) ==8724== by 0x12A9B0D4: qemuMigrationPerform (qemu_migration.c:2872) ==8724== by 0x12ADA7E0: qemuDomainMigratePerform3 (qemu_driver.c:10107) ==8724== by 0x4F3D7D0: virDomainMigratePerform3 (libvirt.c:6253) ==8724== by 0x438CD7: remoteDispatchDomainMigratePerform3 (remote.c:3593) ==8724== by 0x418A8D: remoteDispatchDomainMigratePerform3Helper (remote_dispatch.h:3629) ==8724== by 0x4FAC16D: virNetServerProgramDispatchCall (virnetserverprogram.c:431) ==8724== ==8724== Invalid read of size 4 ==8724== at 0x390A00A64C: pthread_mutex_unlock (pthread_mutex_unlock.c:49) ==8724== by 0x4E893AF: virMutexUnlock (threads-pthread.c:90) ==8724== by 0x4F76DD1: remoteClientCloseFunc (remote_driver.c:354) ==8724== by 0x4FA7E12: virNetClientCloseLocked (virnetclient.c:693) ==8724== by 0x4FAAB69: virNetClientIncomingEvent (virnetclient.c:1866) ==8724== by 0x4FBFE73: virNetSocketEventHandle (virnetsocket.c:1500) ==8724== by 0x4E6E69F: virEventPollDispatchHandles (event_poll.c:485) ==8724== by 0x4E6EF38: virEventPollRunOnce (event_poll.c:632) ==8724== by 0x4E6CFD7: virEventRunDefaultImpl (event.c:247) ==8724== by 0x4FB2DEB: virNetServerRun (virnetserver.c:748) ==8724== by 0x40DC17: main (libvirtd.c:1228) ==8724== Address 0x14df253c is 156 bytes inside a block of size 312 free'd ==8724== at 0x4A063F0: free (vg_replace_malloc.c:446) ==8724== by 0x4E7AA26: virFree (memory.c:419) ==8724== by 0x4E94D5C: virObjectUnref (virobject.c:145) ==8724== by 0x4F2EEDB: virConnectClose (libvirt.c:1458) ==8724== by 0x12A9A67E: doPeer2PeerMigrate (qemu_migration.c:2630) ==8724== by 0x12A9A8BB: qemuMigrationPerformJob (qemu_migration.c:2685) ==8724== by 0x12A9B0D4: qemuMigrationPerform (qemu_migration.c:2872) ==8724== by 0x12ADA7E0: qemuDomainMigratePerform3 (qemu_driver.c:10107) ==8724== by 0x4F3D7D0: virDomainMigratePerform3 (libvirt.c:6253) ==8724== by 0x438CD7: remoteDispatchDomainMigratePerform3 (remote.c:3593) ==8724== by 0x418A8D: remoteDispatchDomainMigratePerform3Helper (remote_dispatch.h:3629) ==8724== by 0x4FAC16D: virNetServerProgramDispatchCall (virnetserverprogram.c:431) ==8724== ==8724== Invalid read of size 4 ==8724== at 0x390A00A656: pthread_mutex_unlock (pthread_mutex_unlock.c:52) ==8724== by 0x4E893AF: virMutexUnlock (threads-pthread.c:90) ==8724== by 0x4F76DD1: remoteClientCloseFunc (remote_driver.c:354) ==8724== by 0x4FA7E12: virNetClientCloseLocked (virnetclient.c:693) ==8724== by 0x4FAAB69: virNetClientIncomingEvent (virnetclient.c:1866) ==8724== by 0x4FBFE73: virNetSocketEventHandle (virnetsocket.c:1500) ==8724== by 0x4E6E69F: virEventPollDispatchHandles (event_poll.c:485) ==8724== by 0x4E6EF38: virEventPollRunOnce (event_poll.c:632) ==8724== by 0x4E6CFD7: virEventRunDefaultImpl (event.c:247) ==8724== by 0x4FB2DEB: virNetServerRun (virnetserver.c:748) ==8724== by 0x40DC17: main (libvirtd.c:1228) ==8724== Address 0x14df2530 is 144 bytes inside a block of size 312 free'd ==8724== at 0x4A063F0: free (vg_replace_malloc.c:446) ==8724== by 0x4E7AA26: virFree (memory.c:419) ==8724== by 0x4E94D5C: virObjectUnref (virobject.c:145) ==8724== by 0x4F2EEDB: virConnectClose (libvirt.c:1458) ==8724== by 0x12A9A67E: doPeer2PeerMigrate (qemu_migration.c:2630) ==8724== by 0x12A9A8BB: qemuMigrationPerformJob (qemu_migration.c:2685) ==8724== by 0x12A9B0D4: qemuMigrationPerform (qemu_migration.c:2872) ==8724== by 0x12ADA7E0: qemuDomainMigratePerform3 (qemu_driver.c:10107) ==8724== by 0x4F3D7D0: virDomainMigratePerform3 (libvirt.c:6253) ==8724== by 0x438CD7: remoteDispatchDomainMigratePerform3 (remote.c:3593) ==8724== by 0x418A8D: remoteDispatchDomainMigratePerform3Helper (remote_dispatch.h:3629) ==8724== by 0x4FAC16D: virNetServerProgramDispatchCall (virnetserverprogram.c:431) ==8724== DEBUG: callback returned -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org

On 03/31/2013 10:20 AM, Peter Krempa wrote:
The last Viktor's effort to fix the race and memory corruption unfortunately wasn't complete in the case the close callback was not registered in an connection. At that time, the trail of event's that I'll describe later could still happend and corrupt the memory or cause a crash of the client (including
s/happend/happen/
the daemon in case of a p2p migration).
Consider the following prerequisities and trail of events: Let's have a remote connection to a hypervisor that doesn't have a close callback registered and the client is using the event loop. The crash happens in cooperation of 2 threads. Thread E is the event loop and thread W is the worker that does some stuff. R denotes the remote client.
1.) W - The client finishes everything and sheds the last reference on the client 2.) W - The virObject stuff invokes virConnectDispose that invokes doRemoteClose 3.) W - the remote close method invokes the REMOTE_PROC_CLOSE RPC method. 4.) W - The thread is preempted at this point. 5.) R - The remote side recieves the close and closes the socket.
s/recieves/receives/
6.) E - poll() wakes up due to the closed socket and invokes the close callback 7.) E - The event loop is preempted right before remoteClientCloseFunc is called 8.) W - The worker now finishes, and frees the conn object. 9.) E - The remoteClientCloseFunc accesses the now-freed conn object in the attempt to retrieve pointer for the real close callback. 10.) Kaboom, corrupted memory/segfault.
This patch tries to fix this by introducing a new object that survives the freeing of the connection object. We can't increase the reference count on the connection object itself as the connection would never be closed as the
s/itself as/itself or/; s/closed as/closed, as/
connection is closed only when the reference count reaches zero.
The new object - virConnectCloseCallbackData - is a lockable object that keeps the pointers to the real user registered callback and ensures that the connection callback is either not called if the connection was already freed or that the connection isn't freed while this is being called. --- src/datatypes.c | 55 ++++++++++++++++++++++++++++++++++++-------- src/datatypes.h | 22 ++++++++++++++---- src/libvirt.c | 29 ++++++++++++----------- src/remote/remote_driver.c | 57 +++++++++++++++++++++++++++------------------- 4 files changed, 112 insertions(+), 51 deletions(-)
So far, this is just a code review. I'm also planning on testing the patch, and will report back with results later in the day.
@@ -63,14 +65,19 @@ static void virStoragePoolDispose(void *obj); static int virDataTypesOnceInit(void) { -#define DECLARE_CLASS(basename) \ - if (!(basename ## Class = virClassNew(virClassForObject(), \ +#define DECLARE_CLASS_COMMON(basename, parent) \ + if (!(basename ## Class = virClassNew(parent, \ #basename, \ sizeof(basename), \ basename ## Dispose))) \ return -1; +#define DECLARE_CLASS(basename) \ + DECLARE_CLASS_COMMON(basename, virClassForObject()) +#define DECLARE_CLASS_LOCKABLE(basename) \ + DECLARE_CLASS_COMMON(basename, virClassForObjectLockable())
Wonder if these definitions are useful enough to rename to VIR_DECLARE_* and move into virobject.h. But that would be a separate patch, to adjust all clients that would benefit from it.
+++ b/src/datatypes.h @@ -93,6 +93,22 @@ extern virClassPtr virStoragePoolClass; # define VIR_IS_DOMAIN_SNAPSHOT(obj) \ (VIR_IS_SNAPSHOT(obj) && VIR_IS_DOMAIN((obj)->domain))
+ +typedef struct _virConnectCloseCallbackData virConnectCloseCallbackData; +typedef virConnectCloseCallbackData *virConnectCloseCallbackDataPtr; + +/** + * Internal structure holding data related to connection close callbacks. + */ +struct _virConnectCloseCallbackData { + virObjectLockable parent; + + virConnectPtr conn; + virConnectCloseFunc callback; + void *opaque; + virFreeCallback freeCallback; +};
Would it make sense to move this struct definition to be local to datatypes.c, and have all other uses of it treat it as opaque?...
+++ b/src/libvirt.c @@ -20189,24 +20189,27 @@ int virConnectRegisterCloseCallback(virConnectPtr conn, virObjectRef(conn);
virMutexLock(&conn->lock); + virObjectLock(conn->closeCallback);
virCheckNonNullArgGoto(cb, error);
- if (conn->closeCallback) { + if (conn->closeCallback->callback) {
...But then you would need to expose an accessor function instead of directly accessing closeCallback->callback. Okay, probably fine as is.
+++ b/src/remote/remote_driver.c @@ -337,32 +337,38 @@ enum virDrvOpenRemoteFlags { VIR_DRV_OPEN_REMOTE_AUTOSTART = (1 << 2), /* Autostart a per-user daemon */ };
+static void +remoteClientCloseFreeFunc(void *opaque) +{ + virConnectCloseCallbackDataPtr cbdata = opaque; + + virObjectUnref(cbdata); +}
You shouldn't need this; just use virObjectFreeCallback instead.
+remoteClientCloseFunc(virNetClientPtr client ATTRIBUTE_UNUSED, + int reason, + void *opaque) { - virConnectPtr conn = opaque; + virConnectCloseCallbackDataPtr cbdata = opaque;
- virMutexLock(&conn->lock); - if (conn->closeCallback) { - virConnectCloseFunc closeCallback = conn->closeCallback; - void *closeOpaque = conn->closeOpaque; - virFreeCallback closeFreeCallback = conn->closeFreeCallback; - unsigned closeUnregisterCount = conn->closeUnregisterCount; + virObjectLock(cbdata);
- VIR_DEBUG("Triggering connection close callback %p reason=%d", - conn->closeCallback, reason); - conn->closeDispatch = true; - virMutexUnlock(&conn->lock); - closeCallback(conn, reason, closeOpaque); - virMutexLock(&conn->lock); - conn->closeDispatch = false; - if (conn->closeUnregisterCount != closeUnregisterCount && - closeFreeCallback) - closeFreeCallback(closeOpaque); + if (cbdata->callback) { + VIR_DEBUG("Triggering connection close callback %p reason=%d, opaque=%p", + cbdata->callback, reason, cbdata->opaque); + cbdata->callback(cbdata->conn, reason, cbdata->opaque); + + if (cbdata->freeCallback) + cbdata->freeCallback(cbdata->opaque); + cbdata->callback = NULL; + cbdata->freeCallback = NULL; } - virMutexUnlock(&conn->lock); + virObjectUnlock(cbdata); + + /* free the connection reference that comes along with the callback + * registration */ + virObjectUnref(cbdata->conn); }
Took me a couple reads, but it looks right. The old code had to temporarily drop connection lock while using the callback; the new code never even grabs connection lock because all the callback data is encapsulated in a separate object.
/* helper macro to ease extraction of arguments from the URI */ @@ -765,9 +771,11 @@ doRemoteOpen(virConnectPtr conn, goto failed; }
+ virObjectRef(conn->closeCallback); + virNetClientSetCloseCallback(priv->client, remoteClientCloseFunc, - conn, NULL); + conn->closeCallback, remoteClientCloseFreeFunc);
Here's where virObjectFreeCallback comes in handy. On the surface, the code seems reasonable. If my testing passes, and you fix up the typos and the unneeded helper function, then I don't mind giving: ACK. -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org

On 03/31/2013 10:20 AM, Peter Krempa wrote:
The last Viktor's effort to fix the race and memory corruption unfortunately wasn't complete in the case the close callback was not registered in an connection. At that time, the trail of event's that I'll describe later could still happend and corrupt the memory or cause a crash of the client (including the daemon in case of a p2p migration).
The new object - virConnectCloseCallbackData - is a lockable object that keeps the pointers to the real user registered callback and ensures that the connection callback is either not called if the connection was already freed or that the connection isn't freed while this is being called. --- src/datatypes.c | 55 ++++++++++++++++++++++++++++++++++++-------- src/datatypes.h | 22 ++++++++++++++---- src/libvirt.c | 29 ++++++++++++----------- src/remote/remote_driver.c | 57 +++++++++++++++++++++++++++------------------- 4 files changed, 112 insertions(+), 51 deletions(-)
I've (finally) completed my stress-testing, and agree that this patch is sufficient to avoid the race (especially when patch 1/6 is also applied to make the race more obvious). ACK, and let's get this applied and backported to maintenance branches as appropriate. -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org

On 04/05/13 04:50, Eric Blake wrote:
On 03/31/2013 10:20 AM, Peter Krempa wrote:
The last Viktor's effort to fix the race and memory corruption unfortunately wasn't complete in the case the close callback was not registered in an connection. At that time, the trail of event's that I'll describe later could still happend and corrupt the memory or cause a crash of the client (including the daemon in case of a p2p migration).
The new object - virConnectCloseCallbackData - is a lockable object that keeps the pointers to the real user registered callback and ensures that the connection callback is either not called if the connection was already freed or that the connection isn't freed while this is being called. --- src/datatypes.c | 55 ++++++++++++++++++++++++++++++++++++-------- src/datatypes.h | 22 ++++++++++++++---- src/libvirt.c | 29 ++++++++++++----------- src/remote/remote_driver.c | 57 +++++++++++++++++++++++++++------------------- 4 files changed, 112 insertions(+), 51 deletions(-)
I've (finally) completed my stress-testing, and agree that this patch is sufficient to avoid the race (especially when patch 1/6 is also applied to make the race more obvious).
ACK, and let's get this applied and backported to maintenance branches as appropriate.
Thanks I've pushed this upstream and I will post a 0.10.2 backport later. Peter

On 03/31/2013 06:20 PM, Peter Krempa wrote:
This series fixes the crash resulting from a race condition in the connection close callback. To observe the crash apply the first patch only. To verify that the patchset fixes the crash please apply all but 2/6 and verify using virsh. 2/6 fixes the crash in a redundant way in case the close callback is used. In the case it isn't 2/6 itself can't fix the issue.
For a better explanation of this problem please see the description in 6/6.
Peter Krempa (4): DO NOT APPLY UPSTREAM: Close callback race corruption crash reproducer. virsh: Move cmdConnect from virsh-host.c to virsh.c virsh: Register and unregister the close callback also in cmdConnect rpc: Fix connection close callback race condition and memory corruption/crash
Viktor Mihajlovski (2): libvirt: Increase connection reference count for callbacks virsh: Unregister the connection close notifier upon termination
src/datatypes.c | 55 ++++++++++++++++++++---- src/datatypes.h | 22 +++++++--- src/libvirt.c | 30 ++++++++----- src/remote/remote_driver.c | 62 ++++++++++++++++----------- src/rpc/virnetclient.c | 9 +++- tools/virsh-host.c | 67 ----------------------------- tools/virsh.c | 102 ++++++++++++++++++++++++++++++++++++++++++--- 7 files changed, 225 insertions(+), 122 deletions(-)
I fear we're yet not thru this. Today I had a segfault doing a migration using virsh migrate --verbose --live $guest qemu+ssh://$host/system. This is with Friday's git HEAD. The migration took very long (but succeeded except for the libvirt crash) so there still seems to be a race lingering in the object reference counting exposed by the --verbose option (getjobinfo?). (gdb) bt #0 qemuDomainGetJobInfo (dom=<optimized out>, info=0x3fffaaaaa70) at qemu/qemu_driver.c:10166 #1 0x000003fffd4bbe68 in virDomainGetJobInfo (domain=0x3ffe4002660, info=0x3fffaaaaa70) at libvirt.c:17440 #2 0x000002aace36b528 in remoteDispatchDomainGetJobInfo (server=<optimized out>, msg=<optimized out>, ret=0x3ffe40029d0, args=0x3ffe40026a0, rerr=0x3fffaaaac20, client=<optimized out>) at remote_dispatch.h:2069 #3 remoteDispatchDomainGetJobInfoHelper (server=<optimized out>, client=<optimized out>, msg=<optimized out>, rerr=0x3fffaaaac20, args=0x3ffe40026a0, ret=0x3ffe40029d0) at remote_dispatch.h:2045 #4 0x000003fffd500384 in virNetServerProgramDispatchCall (msg=0x2ab035dd800, client=0x2ab035df5d0, server=0x2ab035ca370, prog=0x2ab035cf210) at rpc/virnetserverprogram.c:439 #5 virNetServerProgramDispatch (prog=0x2ab035cf210, server=0x2ab035ca370, client=0x2ab035df5d0, msg=0x2ab035dd800) at rpc/virnetserverprogram.c:305 #6 0x000003fffd4fad3c in virNetServerProcessMsg (msg=<optimized out>, prog=<optimized out>, client=<optimized out>, srv=0x2ab035ca370) at rpc/virnetserver.c:162 #7 virNetServerHandleJob (jobOpaque=<optimized out>, opaque=0x2ab035ca370) at rpc/virnetserver.c:183 #8 0x000003fffd42a91c in virThreadPoolWorker (opaque=opaque@entry=0x2ab035a9e60) at util/virthreadpool.c:144 #9 0x000003fffd42a236 in virThreadHelper (data=<optimized out>) at util/virthreadpthread.c:161 #10 0x000003fffcdee412 in start_thread () from /lib64/libpthread.so.0 #11 0x000003fffcd30056 in thread_start () from /lib64/libc.so.6 (gdb) l 10161 if (!(vm = qemuDomObjFromDomain(dom))) 10162 goto cleanup; 10163 10164 priv = vm->privateData; 10165 10166 if (virDomainObjIsActive(vm)) { 10167 if (priv->job.asyncJob && !priv->job.dump_memory_only) { 10168 memcpy(info, &priv->job.info, sizeof(*info)); 10169 10170 /* Refresh elapsed time again just to ensure it (gdb) print *vm $1 = {parent = {parent = {magic = 3735928559, refs = 0, klass = 0xdeadbeef}, lock = {lock = {__data = {__lock = 0, __count = 0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, __list = {__prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 39 times>, __align = 0}}}, pid = 0, state = {state = 0, reason = 0}, autostart = 0, persistent = 0, updated = 0, def = 0x0, newDef = 0x0, snapshots = 0x0, current_snapshot = 0x0, hasManagedSave = false, privateData = 0x0, privateDataFreeFunc = 0x0, taint = 0} I am currently blocked with other work but if anyone has a theory that I should verify let me know... -- Mit freundlichen Grüßen/Kind Regards Viktor Mihajlovski IBM Deutschland Research & Development GmbH Vorsitzender des Aufsichtsrats: Martina Köderitz Geschäftsführung: Dirk Wittkopp Sitz der Gesellschaft: Böblingen Registergericht: Amtsgericht Stuttgart, HRB 243294

On 04/08/13 13:55, Viktor Mihajlovski wrote:
I fear we're yet not thru this. Today I had a segfault doing a migration using virsh migrate --verbose --live $guest qemu+ssh://$host/system. This is with Friday's git HEAD. The migration took very long (but succeeded except for the libvirt crash) so there still seems to be a race lingering in the object reference counting exposed by the --verbose option (getjobinfo?).
(gdb) bt #0 qemuDomainGetJobInfo (dom=<optimized out>, info=0x3fffaaaaa70) at qemu/qemu_driver.c:10166 #1 0x000003fffd4bbe68 in virDomainGetJobInfo (domain=0x3ffe4002660, info=0x3fffaaaaa70) at libvirt.c:17440 #2 0x000002aace36b528 in remoteDispatchDomainGetJobInfo (server=<optimized out>, msg=<optimized out>, ret=0x3ffe40029d0, args=0x3ffe40026a0, rerr=0x3fffaaaac20, client=<optimized out>) at remote_dispatch.h:2069 #3 remoteDispatchDomainGetJobInfoHelper (server=<optimized out>, client=<optimized out>, msg=<optimized out>, rerr=0x3fffaaaac20, args=0x3ffe40026a0, ret=0x3ffe40029d0) at remote_dispatch.h:2045 #4 0x000003fffd500384 in virNetServerProgramDispatchCall (msg=0x2ab035dd800, client=0x2ab035df5d0, server=0x2ab035ca370, prog=0x2ab035cf210) at rpc/virnetserverprogram.c:439 #5 virNetServerProgramDispatch (prog=0x2ab035cf210, server=0x2ab035ca370, client=0x2ab035df5d0, msg=0x2ab035dd800) at rpc/virnetserverprogram.c:305 #6 0x000003fffd4fad3c in virNetServerProcessMsg (msg=<optimized out>, prog=<optimized out>, client=<optimized out>, srv=0x2ab035ca370) at rpc/virnetserver.c:162 #7 virNetServerHandleJob (jobOpaque=<optimized out>, opaque=0x2ab035ca370) at rpc/virnetserver.c:183 #8 0x000003fffd42a91c in virThreadPoolWorker (opaque=opaque@entry=0x2ab035a9e60) at util/virthreadpool.c:144 #9 0x000003fffd42a236 in virThreadHelper (data=<optimized out>) at util/virthreadpthread.c:161 #10 0x000003fffcdee412 in start_thread () from /lib64/libpthread.so.0 #11 0x000003fffcd30056 in thread_start () from /lib64/libc.so.6
(gdb) l 10161 if (!(vm = qemuDomObjFromDomain(dom))) 10162 goto cleanup; 10163 10164 priv = vm->privateData; 10165 10166 if (virDomainObjIsActive(vm)) { 10167 if (priv->job.asyncJob && !priv->job.dump_memory_only) { 10168 memcpy(info, &priv->job.info, sizeof(*info)); 10169 10170 /* Refresh elapsed time again just to ensure it
(gdb) print *vm $1 = {parent = {parent = {magic = 3735928559, refs = 0, klass = 0xdeadbeef}, lock = {lock = {__data = {__lock = 0, __count = 0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, __list = {__prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 39 times>, __align = 0}}}, pid = 0, state = {state = 0, reason = 0}, autostart = 0, persistent = 0, updated = 0, def = 0x0, newDef = 0x0, snapshots = 0x0, current_snapshot = 0x0, hasManagedSave = false, privateData = 0x0, privateDataFreeFunc = 0x0, taint = 0}
I am currently blocked with other work but if anyone has a theory that I should verify let me know...
Aiee, perhaps a race between a thread freeing a domain object (and the private data) and another thread that happened to acquire the domain object pointer before it was freed? Let me verify if that is possible. Peter

On 04/08/13 14:06, Peter Krempa wrote:
On 04/08/13 13:55, Viktor Mihajlovski wrote:
I fear we're yet not thru this. Today I had a segfault doing a migration using virsh migrate --verbose --live $guest qemu+ssh://$host/system. This is with Friday's git HEAD. The migration took very long (but succeeded except for the libvirt crash) so there still seems to be a race lingering in the object reference counting exposed by the --verbose option (getjobinfo?).
(gdb) bt #0 qemuDomainGetJobInfo (dom=<optimized out>, info=0x3fffaaaaa70) at qemu/qemu_driver.c:10166 #1 0x000003fffd4bbe68 in virDomainGetJobInfo (domain=0x3ffe4002660, info=0x3fffaaaaa70) at libvirt.c:17440 #2 0x000002aace36b528 in remoteDispatchDomainGetJobInfo (server=<optimized out>, msg=<optimized out>, ret=0x3ffe40029d0, args=0x3ffe40026a0, rerr=0x3fffaaaac20, client=<optimized out>) at remote_dispatch.h:2069 #3 remoteDispatchDomainGetJobInfoHelper (server=<optimized out>, client=<optimized out>, msg=<optimized out>, rerr=0x3fffaaaac20, args=0x3ffe40026a0, ret=0x3ffe40029d0) at remote_dispatch.h:2045 #4 0x000003fffd500384 in virNetServerProgramDispatchCall (msg=0x2ab035dd800, client=0x2ab035df5d0, server=0x2ab035ca370, prog=0x2ab035cf210) at rpc/virnetserverprogram.c:439 #5 virNetServerProgramDispatch (prog=0x2ab035cf210, server=0x2ab035ca370, client=0x2ab035df5d0, msg=0x2ab035dd800) at rpc/virnetserverprogram.c:305 #6 0x000003fffd4fad3c in virNetServerProcessMsg (msg=<optimized out>, prog=<optimized out>, client=<optimized out>, srv=0x2ab035ca370) at rpc/virnetserver.c:162 #7 virNetServerHandleJob (jobOpaque=<optimized out>, opaque=0x2ab035ca370) at rpc/virnetserver.c:183 #8 0x000003fffd42a91c in virThreadPoolWorker (opaque=opaque@entry=0x2ab035a9e60) at util/virthreadpool.c:144 #9 0x000003fffd42a236 in virThreadHelper (data=<optimized out>) at util/virthreadpthread.c:161 #10 0x000003fffcdee412 in start_thread () from /lib64/libpthread.so.0 #11 0x000003fffcd30056 in thread_start () from /lib64/libc.so.6
(gdb) l 10161 if (!(vm = qemuDomObjFromDomain(dom))) 10162 goto cleanup; 10163 10164 priv = vm->privateData; 10165 10166 if (virDomainObjIsActive(vm)) { 10167 if (priv->job.asyncJob && !priv->job.dump_memory_only) { 10168 memcpy(info, &priv->job.info, sizeof(*info)); 10169 10170 /* Refresh elapsed time again just to ensure it
(gdb) print *vm $1 = {parent = {parent = {magic = 3735928559, refs = 0, klass = 0xdeadbeef}, lock = {lock = {__data = {__lock = 0, __count = 0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, __list = {__prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 39 times>, __align = 0}}}, pid = 0, state = {state = 0, reason = 0}, autostart = 0, persistent = 0, updated = 0, def = 0x0, newDef = 0x0, snapshots = 0x0, current_snapshot = 0x0, hasManagedSave = false, privateData = 0x0, privateDataFreeFunc = 0x0, taint = 0}
I am currently blocked with other work but if anyone has a theory that I should verify let me know...
Aiee, perhaps a race between a thread freeing a domain object (and the private data) and another thread that happened to acquire the domain object pointer before it was freed? Let me verify if that is possible.
Ufff. The domain objects in the qemu driver don't use reference counting to track the lifecycles. Thus it's (Theoretically) possible to acquire a lock of a domain object in one thread while another thread happens to free the domain object. I have a reproducer for this issue: diff --git a/src/conf/domain_conf.c b/src/conf/domain_conf.c index f50a964..90896cb 100644 --- a/src/conf/domain_conf.c +++ b/src/conf/domain_conf.c @@ -2222,6 +2222,8 @@ void virDomainObjListRemove(virDomainObjListPtr doms, virUUIDFormat(dom->def->uuid, uuidstr); virObjectUnlock(dom); + sleep(2); + virObjectLock(doms); virHashRemoveEntry(doms->objs, uuidstr); virObjectUnlock(doms); diff --git a/src/qemu/qemu_driver.c b/src/qemu/qemu_driver.c index 997d7c3..f1aeab7 100644 --- a/src/qemu/qemu_driver.c +++ b/src/qemu/qemu_driver.c @@ -2300,6 +2300,8 @@ static int qemuDomainGetInfo(virDomainPtr dom, if (!(vm = qemuDomObjFromDomain(dom))) goto cleanup; + sleep(5); + info->state = virDomainObjGetState(vm, NULL); if (!virDomainObjIsActive(vm)) { and use a bash oneliner to trigger the issue: virsh undefine domain & sleep .1; virsh dominfo domain The daemon crashes afterwards. I'll try to come up with a fix. Peter

[Re-sending, there was probably a problem and the mail didn't reach the list apparently] On 04/08/13 14:06, Peter Krempa wrote:
On 04/08/13 13:55, Viktor Mihajlovski wrote:
I fear we're yet not thru this. Today I had a segfault doing a migration using virsh migrate --verbose --live $guest qemu+ssh://$host/system. This is with Friday's git HEAD. The migration took very long (but succeeded except for the libvirt crash) so there still seems to be a race lingering in the object reference counting exposed by the --verbose option (getjobinfo?).
(gdb) bt #0 qemuDomainGetJobInfo (dom=<optimized out>, info=0x3fffaaaaa70) at qemu/qemu_driver.c:10166 #1 0x000003fffd4bbe68 in virDomainGetJobInfo (domain=0x3ffe4002660, info=0x3fffaaaaa70) at libvirt.c:17440 #2 0x000002aace36b528 in remoteDispatchDomainGetJobInfo (server=<optimized out>, msg=<optimized out>, ret=0x3ffe40029d0, args=0x3ffe40026a0, rerr=0x3fffaaaac20, client=<optimized out>) at remote_dispatch.h:2069 #3 remoteDispatchDomainGetJobInfoHelper (server=<optimized out>, client=<optimized out>, msg=<optimized out>, rerr=0x3fffaaaac20, args=0x3ffe40026a0, ret=0x3ffe40029d0) at remote_dispatch.h:2045 #4 0x000003fffd500384 in virNetServerProgramDispatchCall (msg=0x2ab035dd800, client=0x2ab035df5d0, server=0x2ab035ca370, prog=0x2ab035cf210) at rpc/virnetserverprogram.c:439 #5 virNetServerProgramDispatch (prog=0x2ab035cf210, server=0x2ab035ca370, client=0x2ab035df5d0, msg=0x2ab035dd800) at rpc/virnetserverprogram.c:305 #6 0x000003fffd4fad3c in virNetServerProcessMsg (msg=<optimized out>, prog=<optimized out>, client=<optimized out>, srv=0x2ab035ca370) at rpc/virnetserver.c:162 #7 virNetServerHandleJob (jobOpaque=<optimized out>, opaque=0x2ab035ca370) at rpc/virnetserver.c:183 #8 0x000003fffd42a91c in virThreadPoolWorker (opaque=opaque@entry=0x2ab035a9e60) at util/virthreadpool.c:144 #9 0x000003fffd42a236 in virThreadHelper (data=<optimized out>) at util/virthreadpthread.c:161 #10 0x000003fffcdee412 in start_thread () from /lib64/libpthread.so.0 #11 0x000003fffcd30056 in thread_start () from /lib64/libc.so.6
(gdb) l 10161 if (!(vm = qemuDomObjFromDomain(dom))) 10162 goto cleanup; 10163 10164 priv = vm->privateData; 10165 10166 if (virDomainObjIsActive(vm)) { 10167 if (priv->job.asyncJob && !priv->job.dump_memory_only) { 10168 memcpy(info, &priv->job.info, sizeof(*info)); 10169 10170 /* Refresh elapsed time again just to ensure it
(gdb) print *vm $1 = {parent = {parent = {magic = 3735928559, refs = 0, klass = 0xdeadbeef}, lock = {lock = {__data = {__lock = 0, __count = 0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, __list = {__prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 39 times>, __align = 0}}}, pid = 0, state = {state = 0, reason = 0}, autostart = 0, persistent = 0, updated = 0, def = 0x0, newDef = 0x0, snapshots = 0x0, current_snapshot = 0x0, hasManagedSave = false, privateData = 0x0, privateDataFreeFunc = 0x0, taint = 0}
I am currently blocked with other work but if anyone has a theory that I should verify let me know...
Aiee, perhaps a race between a thread freeing a domain object (and the private data) and another thread that happened to acquire the domain object pointer before it was freed? Let me verify if that is possible.
Ufff. The domain objects in the qemu driver don't use reference counting to track the lifecycles. Thus it's (Theoretically) possible to acquire a lock of a domain object in one thread while another thread happens to free the domain object. I have a reproducer for this issue: diff --git a/src/conf/domain_conf.c b/src/conf/domain_conf.c index f50a964..90896cb 100644 --- a/src/conf/domain_conf.c +++ b/src/conf/domain_conf.c @@ -2222,6 +2222,8 @@ void virDomainObjListRemove(virDomainObjListPtr doms, virUUIDFormat(dom->def->uuid, uuidstr); virObjectUnlock(dom); + sleep(2); + virObjectLock(doms); virHashRemoveEntry(doms->objs, uuidstr); virObjectUnlock(doms); diff --git a/src/qemu/qemu_driver.c b/src/qemu/qemu_driver.c index 997d7c3..f1aeab7 100644 --- a/src/qemu/qemu_driver.c +++ b/src/qemu/qemu_driver.c @@ -2300,6 +2300,8 @@ static int qemuDomainGetInfo(virDomainPtr dom, if (!(vm = qemuDomObjFromDomain(dom))) goto cleanup; + sleep(5); + info->state = virDomainObjGetState(vm, NULL); if (!virDomainObjIsActive(vm)) { and use a bash oneliner to trigger the issue: virsh undefine domain & sleep .1; virsh dominfo domain The daemon crashes afterwards. I'll try to come up with a fix. Peter

On 04/08/2013 07:04 AM, Peter Krempa wrote:
Aiee, perhaps a race between a thread freeing a domain object (and the private data) and another thread that happened to acquire the domain object pointer before it was freed? Let me verify if that is possible.
Ufff. The domain objects in the qemu driver don't use reference counting to track the lifecycles. Thus it's (Theoretically) possible to acquire a lock of a domain object in one thread while another thread happens to free the domain object.
I have a reproducer for this issue:
Thanks; I can confirm under valgrind that we have a use after free, with all sorts of nasty heap corruption potential, after instrumenting my source a bit more: diff --git i/src/conf/domain_conf.c w/src/conf/domain_conf.c index 03e5740..0572822 100644 --- i/src/conf/domain_conf.c +++ w/src/conf/domain_conf.c @@ -2240,7 +2240,11 @@ void virDomainObjListRemove(virDomainObjListPtr doms, virUUIDFormat(dom->def->uuid, uuidstr); virObjectUnlock(dom); + printf(" DEBUG: about to remove dom %s from list\n", uuidstr); + sleep(2); + virObjectLock(doms); + printf(" DEBUG: locked, removing dom %s from list\n", uuidstr); virHashRemoveEntry(doms->objs, uuidstr); virObjectUnlock(doms); } diff --git i/src/qemu/qemu_driver.c w/src/qemu/qemu_driver.c index 2c0d7d1..98a49e9 100644 --- i/src/qemu/qemu_driver.c +++ w/src/qemu/qemu_driver.c @@ -2297,9 +2297,15 @@ static int qemuDomainGetInfo(virDomainPtr dom, int err; unsigned long long balloon; + char uuidstr[VIR_UUID_STRING_BUFLEN]; if (!(vm = qemuDomObjFromDomain(dom))) goto cleanup; + virUUIDFormat(dom->uuid, uuidstr); + printf(" DEBUG: about to look up info on %s\n", uuidstr); + sleep(5); + printf(" DEBUG: looking up info on %s\n", uuidstr); + info->state = virDomainObjGetState(vm, NULL); if (!virDomainObjIsActive(vm)) {
and use a bash oneliner to trigger the issue:
virsh undefine domain & sleep .1; virsh dominfo domain
valgrind shows the culprit: DEBUG: about to remove dom 51c6fc83-65a4-e627-b698-042b00145202 from list DEBUG: about to look up info on 51c6fc83-65a4-e627-b698-042b00145202 DEBUG: locked, removing dom 51c6fc83-65a4-e627-b698-042b00145202 from list DEBUG: looking up info on 51c6fc83-65a4-e627-b698-042b00145202 ==10033== Thread 6: ==10033== Invalid read of size 4 ==10033== at 0x50FF3BB: virDomainObjGetState (domain_conf.c:16264) ==10033== by 0x1B044EF0: qemuDomainGetInfo (qemu_driver.c:2309) ==10033== by 0x515A08C: virDomainGetInfo (libvirt.c:4240) ==10033== by 0x1243CC: remoteDispatchDomainGetInfo (remote_dispatch.h:1987) ==10033== by 0x1242B1: remoteDispatchDomainGetInfoHelper (remote_dispatch.h:1963) ==10033== by 0x51D2EE9: virNetServerProgramDispatchCall (virnetserverprogram.c:439) ==10033== by 0x51D2A60: virNetServerProgramDispatch (virnetserverprogram.c:305) ==10033== by 0x51D922C: virNetServerProcessMsg (virnetserver.c:162) ==10033== by 0x51D931B: virNetServerHandleJob (virnetserver.c:183) ==10033== by 0x50B97FD: virThreadPoolWorker (virthreadpool.c:144) ==10033== by 0x50B91CE: virThreadHelper (virthreadpthread.c:161) ==10033== by 0x7CAA850: start_thread (pthread_create.c:301) ==10033== Address 0x1daf3a1c is 60 bytes inside a block of size 136 free'd ==10033== at 0x4A063F0: free (vg_replace_malloc.c:446) ==10033== by 0x506C0BD: virFree (viralloc.c:443) ==10033== by 0x50A7366: virObjectUnref (virobject.c:272) ==10033== by 0x50D1112: virDomainObjListDataFree (domain_conf.c:891) ==10033== by 0x5088F3F: virHashRemoveEntry (virhash.c:468) ==10033== by 0x50D48CA: virDomainObjListRemove (domain_conf.c:2248) ==10033== by 0x1AFF1A4A: qemuDomainRemoveInactive (qemu_domain.c:1864) ==10033== by 0x1B04ED30: qemuDomainUndefineFlags (qemu_driver.c:5704) ==10033== by 0x5166490: virDomainUndefineFlags (libvirt.c:8214) ==10033== by 0x131732: remoteDispatchDomainUndefineFlags (remote_dispatch.h:7066) ==10033== by 0x13161F: remoteDispatchDomainUndefineFlagsHelper (remote_dispatch.h:7044) ==10033== by 0x51D2EE9: virNetServerProgramDispatchCall (virnetserverprogram.c:439) Once again, I'm trying to ascertain how far back this issue appears. -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org

On 04/08/2013 08:27 PM, Eric Blake wrote:
On 04/08/2013 07:04 AM, Peter Krempa wrote:
Aiee, perhaps a race between a thread freeing a domain object (and the private data) and another thread that happened to acquire the domain object pointer before it was freed? Let me verify if that is possible.
Ufff. The domain objects in the qemu driver don't use reference counting to track the lifecycles. Thus it's (Theoretically) possible to acquire a lock of a domain object in one thread while another thread happens to free the domain object.
I have a reproducer for this issue:
Thanks; I can confirm under valgrind that we have a use after free, with all sorts of nasty heap corruption potential, after instrumenting my source a bit more:
Once again, I'm trying to ascertain how far back this issue appears.
This time, it appears the problem is more recent. I initially suspected commit d1c7b00b (Feb 2013, v1.0.3), since that rearranged the locks inside virDomainObjListRemove, but even after instrumenting that function, I was unable to get a crash; instead, I got the expected lookup failure: # virsh undefine fedora-local& sleep .1; virsh dominfo fedora-local [1] 25898 Domain fedora-local has been undefined error: failed to get domain 'fedora-local' error: Domain not found: no domain with matching name 'fedora-local' [1]+ Done virsh undefine fedora-local It's too late for me now to search any more tonight, but on the bright side, that narrows down the search, and we have at most two releases affected (rather than all the way back to 0.10.0 on the race that originally spawned this thread). -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org

On 04/08/2013 09:43 PM, Eric Blake wrote:
Thanks; I can confirm under valgrind that we have a use after free, with all sorts of nasty heap corruption potential, after instrumenting my source a bit more:
Once again, I'm trying to ascertain how far back this issue appears.
This time, it appears the problem is more recent. I initially suspected commit d1c7b00b (Feb 2013, v1.0.3), since that rearranged the locks inside virDomainObjListRemove, but even after instrumenting that function, I was unable to get a crash; instead, I got the expected lookup failure:
# virsh undefine fedora-local& sleep .1; virsh dominfo fedora-local [1] 25898 Domain fedora-local has been undefined
error: failed to get domain 'fedora-local' error: Domain not found: no domain with matching name 'fedora-local'
[1]+ Done virsh undefine fedora-local
It's too late for me now to search any more tonight, but on the bright side, that narrows down the search, and we have at most two releases affected (rather than all the way back to 0.10.0 on the race that originally spawned this thread).
My 'git bisect' is complete. Commit d1c7b00b introduced the bug, but the bug was latent until commit a9e97e0 removed qemuDriverLock. Furthermore, applying danpb's/Peter's fix [1] on top of a9e97e0 (basically fixing the latent bug of d1c7b00b) once again avoids the crash. [1] https://www.redhat.com/archives/libvir-list/2013-April/msg00706.html -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org

On 03/31/2013 10:20 AM, Peter Krempa wrote:
This series fixes the crash resulting from a race condition in the connection close callback. To observe the crash apply the first patch only. To verify that the patchset fixes the crash please apply all but 2/6 and verify using virsh. 2/6 fixes the crash in a redundant way in case the close callback is used. In the case it isn't 2/6 itself can't fix the issue.
For a better explanation of this problem please see the description in 6/6.
Peter Krempa (4): DO NOT APPLY UPSTREAM: Close callback race corruption crash reproducer.
For the record, I'm currently trying to investigate where this race was first introduced, to make it easier to state how far back this series must be backported... -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org

On 04/08/2013 02:42 PM, Eric Blake wrote:
On 03/31/2013 10:20 AM, Peter Krempa wrote:
This series fixes the crash resulting from a race condition in the connection close callback. To observe the crash apply the first patch only. To verify that the patchset fixes the crash please apply all but 2/6 and verify using virsh. 2/6 fixes the crash in a redundant way in case the close callback is used. In the case it isn't 2/6 itself can't fix the issue.
For a better explanation of this problem please see the description in 6/6.
Peter Krempa (4): DO NOT APPLY UPSTREAM: Close callback race corruption crash reproducer.
For the record, I'm currently trying to investigate where this race was first introduced, to make it easier to state how far back this series must be backported...
Looks like it has been present since close connection callbacks were first added around commit b1029b6f, Jul 2012 (version 0.10.0). I just confirmed that adding patch 1/6 on top of 0.10.0 reliably caused the same valgrind detection of use-after-free. v0.9.13 is immune because it predates close callbacks. -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
participants (3)
-
Eric Blake
-
Peter Krempa
-
Viktor Mihajlovski