<div dir="ltr">







<p class=""><span class="">Hi Folks,</span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class="">Using libvirt python bindings we are creating an lxc container.Here is the problem that we see sometimes (say 20 % of the time) when we create a new container.</span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class="">1.container gets created, and also starts.However the we are not able to enter the namepace of the container.It throws an error initPid not available.We see that the using netstat command , socket connection is closed.</span></p>
<p class=""><span class="">2.To get around this problem we have to stop and start the container again.We see that socket under  (/var/run/libvirt/*) connection is established and we are able to enter the namespace.</span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class="">Enabled the libvirtd debug logs to debug this issue.</span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class="">For <b>success</b> case we see that for new client connection gets created and is able to handle async incoming events, </span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.748+0000: 1247: info : virObjectNew:202 : OBJECT_NEW: obj=0x7fed54005460 classname=virLXCMonitor</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.748+0000: 1247: debug : virNetSocketNew:159 : localAddr=0x7fed7cd1d170 remoteAddr=0x7fed7cd1d200 fd=28 errfd=-1 pid=0</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.749+0000: 1247: info : virObjectNew:202 : OBJECT_NEW: obj=0x7fed54009040 classname=virNetSocket</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.749+0000: 1247: info : virNetSocketNew:209 : RPC_SOCKET_NEW: sock=0x7fed54009040 fd=28 errfd=-1 pid=0 localAddr=127.0.0.1;0, remoteAddr=127.0.0.1;0</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.749+0000: 1247: info : virObjectNew:202 : OBJECT_NEW: obj=0x7fed54009d10 classname=virNetClient</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.749+0000: 1247: info : virNetClientNew:327 : RPC_CLIENT_NEW: client=0x7fed54009d10 sock=0x7fed54009040</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.749+0000: 1247: info : virObjectRef:296 : OBJECT_REF: obj=0x7fed54009d10</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.749+0000: 1247: info : virObjectRef:296 : OBJECT_REF: obj=0x7fed54009040</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.750+0000: 1247: info : virObjectNew:202 : OBJECT_NEW: obj=0x7fed540009a0 classname=virNetClientProgram</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.750+0000: 1247: info : virObjectRef:296 : OBJECT_REF: obj=0x7fed540009a0</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.750+0000: 1247: info : virObjectRef:296 : OBJECT_REF: obj=0x7fed54005460</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.750+0000: 1247: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7fed5c168eb0</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.750+0000: 1247: debug : virLXCProcessCleanInterfaces:475 : Cleared net names: eth0 </i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.750+0000: 1247: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7fed5c168eb0</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.750+0000: 1247: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x7fed5c169600</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.755+0000: 1244: debug : virNetClientIncomingEvent:1808 : client=0x7fed54009d10 wantclose=0</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.755+0000: 1244: debug : virNetClientIncomingEvent:1816 : Event fired 0x7fed54009040 1</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.755+0000: 1244: debug : virNetMessageDecodeLength:151 : Got length, now need 36 total (32 more)</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.756+0000: 1244: info : virNetClientCallDispatch:1116 : RPC_CLIENT_MSG_RX: client=0x7fed54009d10 len=36 prog=305402420 vers=1 proc=2 type=2 status=0 serial=1</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.756+0000: 1244: debug : virKeepAliveCheckMessage:377 : ka=(nil), client=0x7fed81fc5ed4, msg=0x7fed54009d78</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.756+0000: 1244: debug : virNetClientProgramDispatch:220 : prog=305402420 ver=1 type=2 status=0 serial=1 proc=2</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:18:55.756+0000: 1244: debug : virLXCMonitorHandleEventInit:109 : Event init 1420 </i></span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class="">For <b>failure</b> case ,we see that the client socket connection is initiated and gets closed immediately after receiving an incoming event.In this case, I don’t see an object for virNetClientProgram being created.</span></p>
<p class=""><span class="">Incoming event comes in and since the its unable to find client->prog it bails out and closes the connection.</span></p>
<p class=""><span class="">Snaphost of the code,</span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class="">static int virNetClientCallDispatchMessage(virNetClientPtr client)</span></p>
<p class=""><span class="">{</span></p>
<p class=""><span class="">    size_t i;</span></p>
<p class=""><span class="">    virNetClientProgramPtr prog = NULL;</span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class="">    for (i = 0; i < client->nprograms; i++) {</span></p>
<p class=""><span class="">        if (virNetClientProgramMatches(client->programs[i],</span></p>
<p class=""><span class="">                                       &client->msg)) {</span></p>
<p class=""><span class="">            prog = client->programs[i];</span></p>
<p class=""><span class="">            break;</span></p>
<p class=""><span class="">        }</span></p>
<p class=""><span class="">    }    </span></p>
<p class=""><span class="">    if (!prog) {</span></p>
<p class=""><span class=""><b>        VIR_DEBUG("No program found for event with prog=%d vers=%d",</b></span></p>
<p class=""><span class=""><b>                  client->msg.header.prog, client->msg.header.vers);</b></span></p>
<p class=""><span class="">        return -1;</span></p>
<p class=""><span class="">    } </span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class=""><i>2016-03-12 08:19:15.935+0000: 1246: info : virObjectRef:296 : OBJECT_REF: obj=0x7fed5c168eb0</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:19:15.935+0000: 1246: info : virObjectRef:296 : OBJECT_REF: obj=0x7fed82bd7bc0</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:19:15.935+0000: 1246: info : virObjectNew:202 : OBJECT_NEW: obj=0x7fed82bd8120 classname=virLXCMonitor</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:19:15.935+0000: 1246: debug : virNetSocketNew:159 : localAddr=0x7fed7d51e170 remoteAddr=0x7fed7d51e200 fd=31 errfd=-1 pid=0</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:19:15.936+0000: 1246: info : virObjectNew:202 : OBJECT_NEW: obj=0x7fed82bd8660 classname=virNetSocket</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:19:15.936+0000: 1246: info : virNetSocketNew:209 : RPC_SOCKET_NEW: sock=0x7fed82bd8660 fd=31 errfd=-1 pid=0 localAddr=127.0.0.1;0, remoteAddr=127.0.0.1;0</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:19:15.936+0000: 1246: info : virObjectNew:202 : OBJECT_NEW: obj=0x7fed82bd8ca0 classname=virNetClient</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:19:15.936+0000: 1246: info : virNetClientNew:327 : RPC_CLIENT_NEW: client=0x7fed82bd8ca0 sock=0x7fed82bd8660</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:19:15.936+0000: 1246: info : virObjectRef:296 : OBJECT_REF: obj=0x7fed82bd8ca0</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:19:15.936+0000: 1246: info : virObjectRef:296 : OBJECT_REF: obj=0x7fed82bd8660</i></span></p>
<p class=""><span class=""><b><i>2016-03-12 08:19:15.942+0000: 1244: debug : virNetClientIncomingEvent:1808 : client=0x7fed82bd8ca0 wantclose=0</i></b></span></p>
<p class=""><span class=""><b><i>2016-03-12 08:19:15.942+0000: 1244: debug : virNetClientIncomingEvent:1816 : Event fired 0x7fed82bd8660 1</i></b></span></p>
<p class=""><span class=""><i>2016-03-12 08:19:15.942+0000: 1244: debug : virNetMessageDecodeLength:151 : Got length, now need 36 total (32 more)</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:19:15.942+0000: 1244: info : virNetClientCallDispatch:1116 : RPC_CLIENT_MSG_RX: client=0x7fed82bd8ca0 len=36 prog=305402420 vers=1 proc=2 type=2 status=0 serial=1</i></span></p>
<p class=""><span class=""><i>2016-03-12 08:19:15.942+0000: 1244: debug : virKeepAliveCheckMessage:377 : ka=(nil), client=0x7fed81fc5ed4, msg=0x7fed82bd8d08</i></span></p>
<p class=""><span class=""><b><i>2016-03-12 08:19:15.942+0000: 1244: debug : virNetClientCallDispatchMessage:1008 : No program found for event with prog=305402420 vers=1</i></b></span></p>
<p class=""><span class=""><i>2016-03-12 08:19:15.942+0000: 1244: debug : virNetMessageClear:57 : msg=0x7fed82bd8d08 nfds=0</i></span></p>
<p class=""><span class=""><b><i>2016-03-12 08:19:15.942+0000: 1244: debug : virNetClientMarkClose:632 : client=0x7fed82bd8ca0, reason=0</i></b></span></p>
<p class=""><span class=""><b><i>2016-03-12 08:19:15.942+0000: 1244: debug : virNetClientCloseLocked:648 : client=0x7fed82bd8ca0, sock=0x7fed82bd8660, reason=0</i></b></span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class="">Here is the snapshot of code ,</span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class="">virLXCMonitorPtr virLXCMonitorNew(virDomainObjPtr vm, </span></p>
<p class=""><span class="">                                  const char *socketdir,</span></p>
<p class=""><span class="">                                  virLXCMonitorCallbacksPtr cb) </span></p>
<p class=""><span class="">{</span></p>
<p class=""><span class="">    virLXCMonitorPtr mon;</span></p>
<p class=""><span class="">    char *sockpath = NULL;</span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class="">    if (virLXCMonitorInitialize() < 0)</span></p>
<p class=""><span class="">        return NULL;</span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class="">    if (!(mon = virObjectLockableNew(virLXCMonitorClass)))</span></p>
<p class=""><span class="">        return NULL;</span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class="">    if (virAsprintf(&sockpath, "%s/%s.sock",</span></p>
<p class=""><span class="">                    socketdir, vm->def->name) < 0)</span></p>
<p class=""><span class="">        goto error;</span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class="">    if (!(mon->client = virNetClientNewUNIX(sockpath, false, NULL)))</span></p>
<p class=""><span class="">        goto error;</span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class="">   </span><span class=""><b> if (virNetClientRegisterAsyncIO(mon->client) < 0)</b></span></p>
<p class=""><span class=""><b>        goto error;</b></span></p>
<p class=""><span class=""><b></b></span><br></p>
<p class=""><span class=""><b>    if (!(mon->program = virNetClientProgramNew(VIR_LXC_MONITOR_PROGRAM,</b></span></p>
<p class=""><span class=""><b>                                                VIR_LXC_MONITOR_PROGRAM_VERSION,</b></span></p>
<p class=""><span class=""><b>                                                virLXCMonitorEvents,</b></span></p>
<p class=""><span class=""><b>                                                ARRAY_CARDINALITY(virLXCMonitorEvents),</b></span></p>
<p class=""><span class=""><b>                                                mon)))</b></span></p>
<p class=""><span class=""><b>        goto error;</b></span></p>
<p class=""><span class=""><b></b></span><br></p>
<p class=""><span class=""><b>    if (virNetClientAddProgram(mon->client,</b></span></p>
<p class=""><span class=""><b>                               mon->program) < 0)</b></span></p>
<p class=""><span class=""><b>        goto error;</b></span></p>
<p class=""><span class=""><b></b></span><br></p>
<p class=""><span class=""><b>    mon->vm = vm;</b></span></p>
<p class=""><span class=""><b>    memcpy(&mon->cb, cb, sizeof(mon->cb));</b></span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class="">    virObjectRef(mon);</span></p>
<p class=""><span class="">    virNetClientSetCloseCallback(mon->client, virLXCMonitorEOFNotify, mon,</span></p>
<p class=""><span class="">                                 virLXCMonitorCloseFreeCallback);</span></p>
<p class=""><span class=""></span><br></p>
<p class=""><span class="">Is the problem occurring due to invocation of  “<b>virNetClientRegisterAsyncIO" api before the virNetClientAddProgram.Probably once we register for aysnc IO , immediately an event comes in and that thread takes priority and bails out since it does not find the client->prog?Also the client is not retrying to establish a new connection.</b></span></p>
<p class=""><span class=""><b></b></span><br></p>
<p class=""><span class=""><b>Please let me any thoughts/comments.Is there any patch already available which has fixed this issue?We are using libvirt 1.2.15</b></span></p>
<p class=""><span class=""><b></b></span><br></p>
<p class=""><span class=""><b>-Thanks,</b></span></p>
<p class=""><span class=""><b>Rammohan</b></span></p></div>