[libvirt] [PATCH v2 1/6] libvirtaio: add more debug logging

This logging is helpful for tracing problems with unclosed connections and leaking file descriptors. Signed-off-by: Wojtek Porczyk <woju(a)invisiblethingslab.com&gt; --- libvirtaio.py | 33 +++++++++++++++++++++++++-------- 1 file changed, 25 insertions(+), 8 deletions(-) diff --git a/libvirtaio.py b/libvirtaio.py index 7c8c396..46de9ab 100644 --- a/libvirtaio.py +++ b/libvirtaio.py @@ -74,7 +74,7 @@ class Callback(object): def close(self): '''Schedule *ff* callback''' self.impl.log.debug('callback %d close(), scheduling ff', self.iden) - self.impl.schedule_ff_callback(self.opaque) + self.impl.schedule_ff_callback(self.iden, self.opaque) # # file descriptors @@ -275,6 +275,10 @@ class virEventAsyncIOImpl(object): self.descriptors = DescriptorDict(self) self.log = logging.getLogger(self.__class__.__name__) + def __repr__(self): + return '<{} callbacks={} descriptors={}>'.format( + type(self).__name__, self.callbacks, self.descriptors) + def register(self): '''Register this instance as event loop implementation''' # pylint: disable=bad-whitespace @@ -284,9 +288,18 @@ class virEventAsyncIOImpl(object): self._add_timeout, self._update_timeout, self._remove_timeout) return self - def schedule_ff_callback(self, opaque): + def schedule_ff_callback(self, iden, opaque): '''Schedule a ff callback from one of the handles or timers''' - self.loop.call_soon(libvirt.virEventInvokeFreeCallback, opaque) + ensure_future(self._ff_callback(iden, opaque), loop=self.loop) + + @asyncio.coroutine + def _ff_callback(self, iden, opaque): + '''Directly free the opaque object + + This is a coroutine. + ''' + self.log.debug('ff_callback(iden=%d, opaque=...)', iden) + return libvirt.virEventInvokeFreeCallback(opaque) def is_idle(self): '''Returns False if there are leftovers from a connection @@ -309,10 +322,10 @@ class virEventAsyncIOImpl(object): .. seealso:: https://libvirt.org/html/libvirt-libvirt-event.html#virEventAddHandleFunc... ''' - self.log.debug('add_handle(fd=%d, event=%d, cb=%r, opaque=%r)', - fd, event, cb, opaque) callback = FDCallback(self, cb, opaque, descriptor=self.descriptors[fd], event=event) + self.log.debug('add_handle(fd=%d, event=%d, cb=..., opaque=...) = %d', + fd, event, callback.iden) self.callbacks[callback.iden] = callback self.descriptors[fd].add_handle(callback) return callback.iden @@ -339,7 +352,11 @@ class virEventAsyncIOImpl(object): https://libvirt.org/html/libvirt-libvirt-event.html#virEventRemoveHandleFunc ''' self.log.debug('remove_handle(watch=%d)', watch) - callback = self.callbacks.pop(watch) + try: + callback = self.callbacks.pop(watch) + except KeyError as err: + self.log.warning('remove_handle(): no such handle: %r', err.args[0]) + raise fd = callback.descriptor.fd assert callback is self.descriptors[fd].remove_handle(watch) if len(self.descriptors[fd].callbacks) == 0: @@ -358,9 +375,9 @@ class virEventAsyncIOImpl(object): .. seealso:: https://libvirt.org/html/libvirt-libvirt-event.html#virEventAddTimeoutFunc ''' - self.log.debug('add_timeout(timeout=%d, cb=%r, opaque=%r)', - timeout, cb, opaque) callback = TimeoutCallback(self, cb, opaque) + self.log.debug('add_timeout(timeout=%d, cb=..., opaque=...) = %d', + timeout, callback.iden) self.callbacks[callback.iden] = callback callback.update(timeout=timeout) return callback.iden -- 2.9.4