<div class="zcontentRow"> <p>Michal,</p><p>   please check my comments in the following.<br></p><p><br></p><p>>On 07/21/2017 08:20 AM, liu.yunh@zte.com.cn wrote:</p><p>>> Hi Michal,</p><p>>> </p><p>>>     This problem is triggerred by libvirt python's example event-test.py. the original examples has resouce leak issue</p><p>>> </p><p>>> at the remove_handle and remove_timer. </p><p>>> </p><p>>>     with "python -u event-test.py" run this example and "systemctl restart libvirtd.service" will trigger resource leak problem.</p><p>>> </p><p>>> with lsof -p <event-test.pid> can see socket handler's number increased , after restart libvirtd.serivce each time.</p><p>></p><p>>This is interesting. When I try this out, the python script just gets</p><p>>disconnected and never connects back. So I don't see any number (FD)</p><p>>getting increased.</p><p>></p><p>   we are evaluating the event driven framework in the event-test.py example. because it's only illurstrate one shot connection, we modify <span style="line-height: 21px;">virEventLoopPureStart with a loop</span></p><p><span style="line-height: 21px;">to allow the thread reconnect to libvirtd.service. the original example as you seen, once the libvirtd.service was restart, the example stop running. so you also need do little modification </span></p><p><span style="line-height: 21px;">to allow the thread reconnect to libvirtd.service. the resource leak problem will be seen after the modification.</span></p><p><span style="line-height: 21px;"><br></span></p><p>>> <br></p><p>>>     the reason is remove_handle and remove_timer do not return the remove handle information to libvirt-python's framework. </p><p>>> </p><p>>> little patch was apply to this example, to fix this problem.</p><p>>> </p><p>>>    Now, run this example again and restart libvirtd.service , call sequence virNetSocketRemoveIOCallback->virNetSocketEventFree </p><p>>> </p><p>>> can be observed , the no-recursive mutex, lock with recursive issue can be seen. </p><p>></p><p>>Recursive mutexes are usually sign of bad design. Anyway in this case,</p><p>>one lock should be held by thread doing virNetSocketRemoveIOCallback().</p><p>>The other (event loop) should be trying to lock the socket lock from</p><p>>virNetSocketEventFree(). Since these are two different threads, each one</p><p>>of them is modifying the state of the socket we have to have them use</p><p>>the lock.</p><p>></p><p>>> </p><p>>>     you can check the detail stack trace and our comments about the lock's issue in function virNetSocketEventFree  in the following.</p><p>>> </p><p>>> </p><p>>> </p><p>>> </p><p>>>   ====================================================================  </p><p>>> </p><p>>>  def add_timer(self, interval, cb, opaque):</p><p>>> </p><p>>>         timerID = self.nextTimerID + 1</p><p>>> </p><p>>>         self.nextTimerID = self.nextTimerID + 1</p><p>>> </p><p>>> </p><p>>> </p><p>>> </p><p>>>         h = self.virEventLoopPureTimer(timerID, interval, cb, opaque)</p><p>>> </p><p>>>         self.timers.append(h)</p><p>>> </p><p>>> -       self.timers_opaque[timerID] = opaque</p><p>>> </p><p>>>         self.interrupt()</p><p>>> </p><p>>> </p><p>>> </p><p>>> </p><p>>>         debug("Add timer %d interval %d" % (timerID, interval))</p><p>>> </p><p>>> </p><p>>> </p><p>>> </p><p>>>         return timerID</p><p>>> </p><p>>> </p><p>>> </p><p>>> </p><p>>> </p><p>>> </p><p>>> </p><p>>>      def remove_handle(self, handleID):</p><p>>> </p><p>>>          handles = []</p><p>>> </p><p>>> -        opaque = None</p><p>>> </p><p>>>          for h in self.handles:</p><p>>> </p><p>>>              if h.get_id() == handleID:</p><p>>> </p><p>>>                  self.poll.unregister(h.get_fd())</p><p>>> </p><p>>> -                opaque = self.opaques[handleID]</p><p>>> </p><p>>> -                del self.opaques[handleID]</p><p>>> </p><p>>>                  debug("Remove handle %d fd %d" % (handleID, h.get_fd()))</p><p>>> </p><p>>>              else:</p><p>>> </p><p>>>                  handles.append(h)</p><p>>> </p><p>>>          self.handles = handles</p><p>>> </p><p>>>          self.interrupt()</p><p>>> </p><p>>> -        return opaque</p><p>>> </p><p>>> </p><p>>> </p><p>>> </p><p>>>      # Stop firing the periodic timer</p><p>>> </p><p>>>      def remove_timer(self, timerID):</p><p>>> </p><p>>>          timers = []</p><p>>> </p><p>>> -        opaque = None</p><p>>> </p><p>>>          for h in self.timers:</p><p>>> </p><p>>>              if h.get_id() != timerID:</p><p>>> </p><p>>>                  timers.append(h)</p><p>>> </p><p>>> -            else:</p><p>>> </p><p>>> -                opaque = self.timers_opaque[timerID]</p><p>>> </p><p>>>                  debug("Remove timer %d" % timerID)</p><p>>> </p><p>>>          self.timers = timers</p><p>>> </p><p>>>          self.interrupt()</p><p>>> </p><p>>> -        return opaque</p><p>></p><p>></p><p>>I don't see this code anywhere and thus cannot perform the changes</p><p>>you've suggested. Sorry. Is this current git HEAD?</p><p>></p><p>>> </p><p>>> ====================================================================================</p><p>>> </p><p>>> </p><p>>> </p><p>>> </p><p>>> </p><p>>>>> On 07/15/2017 05:00 PM, Peng Hao wrote:</p><p>>> </p><p>>>>> virNetSocketRemoveIOCallback get sock's ObjectLock and will call</p><p>>> </p><p>>>>> virNetSocketEventFree. virNetSocketEventFree may be free sock</p><p>>> </p><p>>>>> object and virNetSocketRemoveIOCallback will access a null pointer</p><p>>> </p><p>>>>> in release sock's ObjectLock.</p><p>>> </p><p>>>>></p><p>>> </p><p>>>>> Signed-off-by: Liu Yun <liu.yunh@zte.com.cn></p><p>>> </p><p>>>>> Signed-off-by: Peng Hao <peng.hao2@zte.com.cn></p><p>>> </p><p>>>>> ---</p><p>>> </p><p>>>>>  src/rpc/virnetsocket.c | 6 +++---</p><p>>> </p><p>>>>>  1 file changed, 3 insertions(+), 3 deletions(-)</p><p>>> </p><p>>>>></p><p>>> </p><p>>>></p><p>>> </p><p>>>> I don't think this can work.</p><p>>> </p><p>>>></p><p>>> </p><p>>>>> diff --git a/src/rpc/virnetsocket.c b/src/rpc/virnetsocket.c</p><p>>> </p><p>>>>> index d228c8a..8b550e8 100644</p><p>>> </p><p>>>>> --- a/src/rpc/virnetsocket.c</p><p>>> </p><p>>>>> +++ b/src/rpc/virnetsocket.c</p><p>>> </p><p>>>>> @@ -2140,14 +2140,12 @@ static void virNetSocketEventFree(void *opaque)</p><p>>> </p><p>>>>>      virFreeCallback ff</p><p>>> </p><p>>>>>      void *eopaque</p><p>>> </p><p>>>>>  </p><p>>> </p><p>>>>> -    virObjectLock(sock)</p><p>>> </p><p>>>>>      ff = sock->ff</p><p>>> </p><p>>>>>      eopaque = sock->opaque</p><p>>> </p><p>>>>>      sock->func = NULL</p><p>>> </p><p>>>>>      sock->ff = NULL</p><p>>> </p><p>>>>>      sock->opaque = NULL</p><p>>> </p><p>>>>> -    virObjectUnlock(sock)</p><p>>> </p><p>>>></p><p>>> </p><p>>>> I think we need the lock here. This function is called from the event</p><p>>> </p><p>>>> loop thread. So even if virNetSocketUpdateIOCallback() locks the @socket</p><p>>> </p><p>>>> this code can see it unlocked. Or locked. But the crucial part is it's</p><p>>> </p><p>>>> modifying the object and thus should have lock held.</p><p>>> </p><p>>>></p><p>>> </p><p>>>    I have check the code , in default implementation of eventPoll, virEventPollRunOnce always dispatch and clear in one thread loop,</p><p>>> </p><p>>> so, the lock in the virNetSocketEventFree may be unnessary.</p><p>>> </p><p>>> </p><p>>> </p><p>>> </p><p>>>>> -</p><p>>> </p><p>>>>> +  </p><p>>> </p><p>>>>>      if (ff)</p><p>>> </p><p>>>>>          ff(eopaque)</p><p>>> </p><p>>>>>  </p><p>>> </p><p>>>>> @@ -2207,6 +2205,7 @@ void virNetSocketUpdateIOCallback(virNetSocketPtr sock,</p><p>>> </p><p>>>>>  </p><p>>> </p><p>>>>>  void virNetSocketRemoveIOCallback(virNetSocketPtr sock)</p><p>>> </p><p>>>>>  {</p><p>>> </p><p>>>>> +    virObjectRef(sock)</p><p>>> </p><p>>> </p><p>>> </p><p>>> </p><p>>> This should be mistake when generate the patch. The correct one is </p><p>>> </p><p>>>      +    virObjectUnref(sock)</p><p>>> </p><p>>>>>      virObjectLock(sock)</p><p>>> </p><p>>>></p><p>>> </p><p>>>> I think this is what actually fixes your problem. However, I also think</p><p>>> </p><p>>>> it introduces uneven ratio of ref:unref calls.</p><p>>> </p><p>>>></p><p>>> </p><p>>>>>  </p><p>>> </p><p>>>>>      if (sock->watch < 0) {</p><p>>> </p><p>>>>> @@ -2220,6 +2219,7 @@ void virNetSocketRemoveIOCallback(virNetSocketPtr sock)</p><p>>> </p><p>>>>>      sock->watch = -1</p><p>>> </p><p>>>>>  </p><p>>> </p><p>>>>>      virObjectUnlock(sock)</p><p>>> </p><p>>>>> +    virObjectRef(sock)</p><p>>> </p><p>>> </p><p>>> </p><p>>> </p><p>>> </p><p>>> This should be mistake when generate the patch. The correct one is </p><p>>> </p><p>>> </p><p>>>      +    virObjectUnref(sock)</p><p>>> </p><p>>>></p><p>>> </p><p>>>> It definitely does so because you ref twice. Anyway, do you perhaps have</p><p>>> </p><p>>>> a backtrace to share?</p><p>>> </p><p>></p><p>>Can you provide the output of 't a a bt'? I wonder if this is the only</p><p>>thread (and thus something left socket locked) or we have some deadlock</p><p>>here.</p><p>   following is the all threads bactrace information. it show only one thread to accquire the lock.</p><p>(gdb) info threads</p><p>  Id   Target Id         Frame</p><p>  2    Thread 0x7ff3c6362740 (LWP 20078) sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:85</p><p>* 1    Thread 0x7ff3b48d4700 (LWP 20081) __lll_lock_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135</p><p>(gdb) thread 2</p><p>[Switching to thread 2 (Thread 0x7ff3c6362740 (LWP 20078))]</p><p>#0  sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:85</p><p>85              movq    %rax, %rcx</p><p>(gdb) bt</p><p>#0  sem_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/sem_wait.S:85</p><p>#1  0x00007ff3c5eb17b5 in PyThread_acquire_lock () from /lib64/libpython2.7.so.1.0</p><p>#2  0x00007ff3c5e808a6 in PyEval_RestoreThread () from /lib64/libpython2.7.so.1.0</p><p>#3  0x00007ff3b50fe086 in time_sleep () from /usr/lib64/python2.7/lib-dynload/timemodule.so</p><p>#4  0x00007ff3c5e85aa4 in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>#5  0x00007ff3c5e870bd in PyEval_EvalCodeEx () from /lib64/libpython2.7.so.1.0</p><p>#6  0x00007ff3c5e8576f in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>#7  0x00007ff3c5e870bd in PyEval_EvalCodeEx () from /lib64/libpython2.7.so.1.0</p><p>#8  0x00007ff3c5e871c2 in PyEval_EvalCode () from /lib64/libpython2.7.so.1.0</p><p>#9  0x00007ff3c5ea05ff in run_mod () from /lib64/libpython2.7.so.1.0</p><p>#10 0x00007ff3c5ea17be in PyRun_FileExFlags () from /lib64/libpython2.7.so.1.0</p><p>#11 0x00007ff3c5ea2a49 in PyRun_SimpleFileExFlags () from /lib64/libpython2.7.so.1.0</p><p>#12 0x00007ff3c5eb3b9f in Py_Main () from /lib64/libpython2.7.so.1.0</p><p>#13 0x00007ff3c50e0b15 in __libc_start_main (main=0x4006f0 <main>, argc=3, ubp_av=0x7ffca58ef528, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffca58ef518)</p><p>    at libc-start.c:274</p><p>#14 0x0000000000400721 in _start ()</p><p>(gdb) thread 1</p><p>[Switching to thread 1 (Thread 0x7ff3b48d4700 (LWP 20081))]</p><p>#0  __lll_lock_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135</p><p>135     2:      movl    %edx, %eax</p><p>(gdb) bt</p><p>#0  __lll_lock_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135</p><p>#1  0x00007ff3c5b92d02 in _L_lock_791 () from /lib64/libpthread.so.0</p><p>#2  0x00007ff3c5b92c08 in __GI___pthread_mutex_lock (mutex=mutex@entry=0xa6b9c0) at pthread_mutex_lock.c:64</p><p>#3  0x00007ff3be351e15 in virMutexLock (m=m@entry=0xa6b9c0) at util/virthread.c:89</p><p>#4  0x00007ff3be3338ae in virObjectLock (anyobj=anyobj@entry=0xa6b9b0) at util/virobject.c:323</p><p>#5  0x00007ff3be47a52c in virNetSocketEventFree (opaque=0xa6b9b0) at rpc/virnetsocket.c:2134</p><p>#6  0x00007ff3be82af87 in libvirt_virEventRemoveHandleFunc (watch=<optimized out>) at libvirt-override.c:5496</p><p>#7  0x00007ff3be47dc69 in virNetSocketRemoveIOCallback (sock=0xa6b9b0) at rpc/virnetsocket.c:2212</p><p>#8  0x00007ff3be469d76 in virNetClientMarkClose (client=0xa6bcb0, reason=0) at rpc/virnetclient.c:779</p><p>#9  0x00007ff3be46a0eb in virNetClientIncomingEvent (sock=0xa6b9b0, events=9, opaque=0xa6bcb0) at rpc/virnetclient.c:1985</p><p>#10 0x00007ff3be81e347 in libvirt_virEventInvokeHandleCallback (self=<optimized out>, args=<optimized out>) at libvirt-override.c:5718</p><p>#11 0x00007ff3c5e85aa4 in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>#12 0x00007ff3c5e870bd in PyEval_EvalCodeEx () from /lib64/libpython2.7.so.1.0</p><p>#13 0x00007ff3c5e8576f in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>#14 0x00007ff3c5e85860 in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>#15 0x00007ff3c5e85860 in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>#16 0x00007ff3c5e85860 in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>#17 0x00007ff3c5e870bd in PyEval_EvalCodeEx () from /lib64/libpython2.7.so.1.0</p><p>#18 0x00007ff3c5e1405d in function_call () from /lib64/libpython2.7.so.1.0</p><p>#19 0x00007ff3c5def0b3 in PyObject_Call () from /lib64/libpython2.7.so.1.0</p><p>#20 0x00007ff3c5e822f7 in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>#21 0x00007ff3c5e85860 in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>#22 0x00007ff3c5e85860 in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>#23 0x00007ff3c5e870bd in PyEval_EvalCodeEx () from /lib64/libpython2.7.so.1.0</p><p>#24 0x00007ff3c5e13f68 in function_call () from /lib64/libpython2.7.so.1.0</p><p>#25 0x00007ff3c5def0b3 in PyObject_Call () from /lib64/libpython2.7.so.1.0</p><p>#26 0x00007ff3c5dfe0a5 in instancemethod_call () from /lib64/libpython2.7.so.1.0</p><p>#27 0x00007ff3c5def0b3 in PyObject_Call () from /lib64/libpython2.7.so.1.0</p><p>#28 0x00007ff3c5e80f07 in PyEval_CallObjectWithKeywords () from /lib64/libpython2.7.so.1.0</p><p>#29 0x00007ff3c5eb5842 in t_bootstrap () from /lib64/libpython2.7.so.1.0</p><p>#30 0x00007ff3c5b90dc5 in start_thread (arg=0x7ff3b48d4700) at pthread_create.c:308</p><p>#31 0x00007ff3c51b521d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113</p><p>(gdb)</p><p>></p><p>>>     </p><p>>> </p><p>>> #0  __lll_lock_wait ()</p><p>>> </p><p>>>     at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135</p><p>>> </p><p>>> #1  0x00007fde6207cd02 in _L_lock_791 () from /lib64/libpthread.so.0</p><p>>> </p><p>>> #2  0x00007fde6207cc08 in __GI___pthread_mutex_lock (</p><p>>> </p><p>>>     mutex=mutex@entry=0x119c3e0) at pthread_mutex_lock.c:64</p><p>>> </p><p>>> #3  0x00007fde5a97ee15 in virMutexLock (m=m@entry=0x119c3e0)</p><p>>> </p><p>>>     at util/virthread.c:89</p><p>>> </p><p>>> #4  0x00007fde5a9608ae in virObjectLock (anyobj=anyobj@entry=0x119c3d0)</p><p>>> </p><p>>>     at util/virobject.c:323</p><p>>> </p><p>>> #5  0x00007fde5aaa752c in virNetSocketEventFree (opaque=0x119c3d0)</p><p>>> </p><p>>>     at rpc/virnetsocket.c:2134</p><p>>> </p><p>>> #6  0x00007fde5ae57f87 in libvirt_virEventRemoveHandleFunc (</p><p>>> </p><p>>>     watch=<optimized out>) at libvirt-override.c:5496</p><p>>> </p><p>>> #7  0x00007fde5aaaac69 in virNetSocketRemoveIOCallback (sock=0x119c3d0)</p><p>>> </p><p>>>     at rpc/virnetsocket.c:2212</p><p>>> </p><p>>> #8  0x00007fde5aa96d76 in virNetClientMarkClose (client=0x119c650, reason=0)</p><p>>> </p><p>>>     at rpc/virnetclient.c:779</p><p>>> </p><p>>> #9  0x00007fde5aa970eb in virNetClientIncomingEvent (sock=0x119c3d0, events=9,</p><p>>> </p><p>>>     opaque=0x119c650) at rpc/virnetclient.c:1985</p><p>>> </p><p>>> #10 0x00007fde5ae4b347 in libvirt_virEventInvokeHandleCallback (</p><p>>> </p><p>>>     self=<optimized out>, args=<optimized out>) at libvirt-override.c:5718</p><p>>> </p><p>>> #11 0x00007fde6236faa4 in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>>> </p><p>>> #12 0x00007fde623710bd in PyEval_EvalCodeEx () from /lib64/libpython2.7.so.1.0</p><p>>> </p><p>>> ---Type <return> to continue, or q <return> to quit---</p><p>>> </p><p>>> #13 0x00007fde6236f76f in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>>> </p><p>>> #14 0x00007fde6236f860 in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>>> </p><p>>> #15 0x00007fde6236f860 in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>>> </p><p>>> #16 0x00007fde6236f860 in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>>> </p><p>>> #17 0x00007fde623710bd in PyEval_EvalCodeEx () from /lib64/libpython2.7.so.1.0</p><p>>> </p><p>>> #18 0x00007fde622fe05d in function_call () from /lib64/libpython2.7.so.1.0</p><p>>> </p><p>>> #19 0x00007fde622d90b3 in PyObject_Call () from /lib64/libpython2.7.so.1.0</p><p>>> </p><p>>> #20 0x00007fde6236c2f7 in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>>> </p><p>>> #21 0x00007fde6236f860 in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>>> </p><p>>> #22 0x00007fde6236f860 in PyEval_EvalFrameEx () from /lib64/libpython2.7.so.1.0</p><p>>> </p><p>>> #23 0x00007fde623710bd in PyEval_EvalCodeEx () from /lib64/libpython2.7.so.1.0</p><p>>> </p><p>>> #24 0x00007fde622fdf68 in function_call () from /lib64/libpython2.7.so.1.0</p><p>>> </p><p>>> #25 0x00007fde622d90b3 in PyObject_Call () from /lib64/libpython2.7.so.1.0</p><p>>> </p><p>>> #26 0x00007fde622e80a5 in instancemethod_call ()</p><p>>> </p><p>>> </p><p>></p><p>>Michal</p><p><br></p> </div>