Re: [libvirt] [PATCH] virObject: Error on suspicious ref and unref

https://bugzilla.redhat.com/show_bug.cgi?id=1033061 Since our transformation into virObject is not complete and we must do ref and unref ourselves there's a chance that we will get it wrong. That is, while one thread is doing unref and subsequent dispose another thread may come and do the ref & unref on stale pointer. This results in dispose being called twice (and possibly simultaneously). These kind of errors are hard to catch so we should at least throw an error into logs if such situation occurs. In fact, I've seen a stack trace showing this error had happen (obj = 0x7f4968018260): Thread 2 (Thread 0x7f498596b880 (LWP 13394)): [...] #4 0x00007f496ff44607 in ncf_close (ncf=0x7f496801e3d0) at netcf.c:101 __PRETTY_FUNCTION__ = "ncf_close" #5 0x00007f4984f3f31b in virObjectUnref (anyobj=<optimized out>) at util/virobject.c:262 klass = 0x7f4968019020 obj = 0x7f4968018260 lastRef = true __func__ = "virObjectUnref" #6 0x00007f4970159785 in netcfStateCleanup () at interface/interface_backend_netcf.c:109 No locals. #7 0x00007f4984fc0e28 in virStateCleanup () at libvirt.c:883 i = 6 ret = 0 #8 0x00007f49859b55fd in main (argc=<optimized out>, argv=<optimized out>) at libvirtd.c:1549 srv = 0x7f498696ed00 remote_config_file = 0x0 statuswrite = -1 ret = <optimized out> pid_file_fd = 5 pid_file = 0x0 sock_file = 0x0 sock_file_ro = 0x0 timeout = -1 verbose = 0 godaemon = 0 ipsock = 0 config = 0x7f498696e760 privileged = <optimized out> implicit_conf = <optimized out> run_dir = 0x0 old_umask = <optimized out> opts = {{name = 0x7f49859e2b53 "verbose", has_arg = 0, flag = 0x7fff45057808, val = 118}, {name = 0x7f49859e2b5b "daemon", has_arg = 0, flag = 0x7fff4505780c, val = 100}, {name = 0x7f49859e2b62 "listen", has_arg = 0, flag = 0x7fff45057810, val = 108}, {name = 0x7f49859e2c9f "config", has_arg = 1, flag = 0x0, val = 102}, {name = 0x7f49859e2c00 "timeout", has_arg = 1, flag = 0x0, val = 116}, {name = 0x7f49859e2b69 "pid-file", has_arg = 1, flag = 0x0, val = 112}, {name = 0x7f49859e2b72 "version", has_arg = 0, flag = 0x0, val = 86}, {name = 0x7f49859e2b7a "help", has_arg = 0, flag = 0x0, val = 104}, {name = 0x0, has_arg = 0, flag = 0x0, val = 0}} __func__ = "main" Thread 1 (Thread 0x7f496d6a4700 (LWP 13405)): [...] #6 0x00007f496ff44607 in ncf_close (ncf=0x7f496801e3d0) at netcf.c:101 __PRETTY_FUNCTION__ = "ncf_close" #7 0x00007f4984f3f31b in virObjectUnref (anyobj=<optimized out>) at util/virobject.c:262 klass = 0x7f4968019020 obj = 0x7f4968018260 lastRef = true __func__ = "virObjectUnref" #8 0x00007f4970157752 in netcfInterfaceClose (conn=0x7f49680a3260) at interface/interface_backend_netcf.c:265 No locals. #9 0x00007f4984fb7984 in virConnectDispose (obj=0x7f49680a3260) at datatypes.c:149 conn = 0x7f49680a3260 #10 0x00007f4984f3f31b in virObjectUnref (anyobj=anyobj@entry=0x7f49680a3260) at util/virobject.c:262 klass = 0x7f49681d6760 obj = 0x7f49680a3260 lastRef = true __func__ = "virObjectUnref" #11 0x00007f4984fc11bf in virConnectClose (conn=conn@entry=0x7f49680a3260) at libvirt.c:1532 __func__ = "virConnectClose" __FUNCTION__ = "virConnectClose" #12 0x00007f496eced281 in virLXCProcessAutostartAll (driver=0x7f49681ffaa0) at lxc/lxc_process.c:1426 conn = 0x7f49680a3260 data = {driver = 0x7f49681ffaa0, conn = 0x7f49680a3260} #13 0x00007f4984fc0d21 in virStateInitialize (privileged=true, callback=callback@entry=0x7f49859b7180 <daemonInhibitCallback>, opaque=opaque@entry=0x7f498696ed00) at libvirt.c:864 i = 8 __func__ = "virStateInitialize" #14 0x00007f49859b71db in daemonRunStateInit (opaque=opaque@entry=0x7f498696ed00) at libvirtd.c:906 srv = 0x7f498696ed00 sysident = 0x7f4968000ae0 __func__ = "daemonRunStateInit" #15 0x00007f4984f4efe1 in virThreadHelper (data=<optimized out>) at util/virthreadpthread.c:161 args = 0x0 local = {func = 0x7f49859b71a0 <daemonRunStateInit>, opaque = 0x7f498696ed00} #16 0x00007f4982a40de3 in start_thread (arg=0x7f496d6a4700) at pthread_create.c:308 __res = <optimized out> pd = 0x7f496d6a4700 now = <optimized out> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {139953345021696, 7118305506502180663, 0, 139953345022400, 139953345021696, 140734351374104, -7179978120810397897, -7180347023594422473}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = <optimized out> pagesize_m1 = <optimized out> sp = <optimized out> freesize = <optimized out> #17 0x00007f498236716d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113 Signed-off-by: Michal Privoznik <mprivozn(a)redhat.com&gt; --- src/nwfilter/nwfilter_dhcpsnoop.c | 6 ++--- src/util/viratomic.h | 53 +++++++++++++++++++++++++++++++-------- src/util/virobject.c | 17 ++++++++++--- 3 files changed, 58 insertions(+), 18 deletions(-) diff --git a/src/nwfilter/nwfilter_dhcpsnoop.c b/src/nwfilter/nwfilter_dhcpsnoop.c index e8fcfef..71380bb 100644 --- a/src/nwfilter/nwfilter_dhcpsnoop.c +++ b/src/nwfilter/nwfilter_dhcpsnoop.c @@ -893,7 +893,7 @@ virNWFilterSnoopReqLeaseDel(virNWFilterSnoopReqPtr req, skip_instantiate: VIR_FREE(ipl); - virAtomicIntDecAndTest(&virNWFilterSnoopState.nLeases); + virAtomicIntDec(&virNWFilterSnoopState.nLeases); lease_not_found: VIR_FREE(ipstr); @@ -1169,7 +1169,7 @@ static void virNWFilterDHCPDecodeWorker(void *jobdata, void *opaque) _("Instantiation of rules failed on " "interface '%s'"), req->ifname); } - virAtomicIntDecAndTest(job->qCtr); + virAtomicIntDec(job->qCtr); VIR_FREE(job); } @@ -1562,7 +1562,7 @@ exit: pcap_close(pcapConf[i].handle); } - virAtomicIntDecAndTest(&virNWFilterSnoopState.nThreads); + virAtomicIntDec(&virNWFilterSnoopState.nThreads); return; }

diff --git a/src/util/viratomic.h b/src/util/viratomic.h index 4d7f7e5..877900e 100644 --- a/src/util/viratomic.h +++ b/src/util/viratomic.h @@ -68,6 +68,18 @@ VIR_STATIC int virAtomicIntInc(volatile int *atomic) ATTRIBUTE_NONNULL(1); /** + * virAtomicIntDec: + * Decrements the value of atomic by 1. + * + * Think of this operation as an atomic version of + * { *atomic -= 1; return *atomic == 0; } + * + * This call acts as a full compiler and hardware memory barrier. + */ +VIR_STATIC int virAtomicIntDec(volatile int *atomic) + ATTRIBUTE_NONNULL(1); + +/** * virAtomicIntDecAndTest: * Decrements the value of atomic by 1. * @@ -75,6 +87,8 @@ VIR_STATIC int virAtomicIntInc(volatile int *atomic) * { *atomic -= 1; return *atomic == 0; } * * This call acts as a full compiler and hardware memory barrier. + * Returns true if the resulting decremented value is zero, + * false otherwise. */ VIR_STATIC bool virAtomicIntDecAndTest(volatile int *atomic) ATTRIBUTE_NONNULL(1); @@ -176,12 +190,15 @@ VIR_STATIC unsigned int virAtomicIntXor(volatile unsigned int *atomic, (void)(0 ? *(atomic) ^ *(atomic) : 0); \ __sync_add_and_fetch((atomic), 1); \ })) +# define virAtomicIntDec(atomic) \ + (__extension__ ({ \ + (void)verify_true(sizeof(*(atomic)) == sizeof(int)); \ + (void)(0 ? *(atomic) ^ *(atomic) : 0); \ + __sync_sub_and_fetch((atomic), 1); \ + })) # define virAtomicIntDecAndTest(atomic) \ - (__extension__ ({ \ - (void)verify_true(sizeof(*(atomic)) == sizeof(int)); \ - (void)(0 ? *(atomic) ^ *(atomic) : 0); \ - __sync_fetch_and_sub((atomic), 1) == 1; \ - })) + (virAtomicIntDec(atomic) == 0) + # define virAtomicIntCompareExchange(atomic, oldval, newval) \ (__extension__ ({ \ (void)verify_true(sizeof(*(atomic)) == sizeof(int)); \ @@ -252,10 +269,16 @@ virAtomicIntInc(volatile int *atomic) return InterlockedIncrement((volatile LONG *)atomic); } +static inline int +virAtomicIntDec(volatile int *atomic) +{ + return InterlockedDecrement((volatile LONG *)atomic); +} + static inline bool virAtomicIntDecAndTest(volatile int *atomic) { - return InterlockedDecrement((volatile LONG *)atomic) == 0; + return virAtomicIntDec(atomic) == 0; } static inline bool @@ -334,16 +357,22 @@ virAtomicIntInc(volatile int *atomic) return value; } -static inline bool -virAtomicIntDecAndTest(volatile int *atomic) +static inline int +virAtomicIntDec(volatile int *atomic) { - bool is_zero; + bool value; pthread_mutex_lock(&virAtomicLock); - is_zero = --(*atomic) == 0; + value = --(*atomic);

pthread_mutex_unlock(&virAtomicLock); - return is_zero; + return value;

+} + +static inline int +virAtomicIntDecAndTest(volatile int *atomic) +{ + return virAtomicIntDec(atomic) == 0; } static inline bool @@ -436,6 +465,8 @@ virAtomicIntXor(volatile unsigned int *atomic, virAtomicIntSet((int *)atomic, val) # define virAtomicIntInc(atomic) \ virAtomicIntInc((int *)atomic) +# define virAtomicIntDec(atomic) \ + virAtomicIntDec((int *)atomic) # define virAtomicIntDecAndTest(atomic) \ virAtomicIntDecAndTest((int *)atomic) # define virAtomicIntCompareExchange(atomic, oldval, newval) \ diff --git a/src/util/virobject.c b/src/util/virobject.c index 61b5413..4299432 100644 --- a/src/util/virobject.c +++ b/src/util/virobject.c @@ -252,9 +252,9 @@ bool virObjectUnref(void *anyobj) if (!obj) return false; - bool lastRef = virAtomicIntDecAndTest(&obj->refs); + int newRefs = virAtomicIntDec(&obj->refs); PROBE(OBJECT_UNREF, "obj=%p", obj); - if (lastRef) { + if (newRefs == 0) { PROBE(OBJECT_DISPOSE, "obj=%p", obj); virClassPtr klass = obj->klass; while (klass) { @@ -268,9 +268,13 @@ bool virObjectUnref(void *anyobj) obj->magic = 0xDEADBEEF; obj->klass = (void*)0xDEADBEEF; VIR_FREE(obj); + } else if (newRefs < 0) { + virReportError(VIR_ERR_INTERNAL_ERROR, + _("Suspicious unrefing of object %p"), + anyobj);

} - return !lastRef; + return newRefs > 0; } @@ -289,8 +293,13 @@ void *virObjectRef(void *anyobj) if (!obj) return NULL; - virAtomicIntInc(&obj->refs); + bool firstRef = virAtomicIntInc(&obj->refs) <= 1; PROBE(OBJECT_REF, "obj=%p", obj); + if (firstRef) { + virReportError(VIR_ERR_INTERNAL_ERROR, + _("Suspicious refing of object %p"), + anyobj);

+ } return anyobj; }