<div dir="ltr"><div dir="ltr"><div class="gmail_default" style="font-size:small;color:#000000"><span style="color:rgb(34,34,34)">On Fri, Aug 9, 2019 at 11:20 AM Richard W.M. Jones <<a href="mailto:rjones@redhat.com">rjones@redhat.com</a>> wrote:</span><br></div></div><div class="gmail_quote"><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">On Fri, Aug 09, 2019 at 02:58:18AM +0300, Nir Soffer wrote:<br> > On Thu, Aug 8, 2019 at 5:05 PM Richard W.M. Jones <<a href="mailto:rjones@redhat.com" target="_blank">rjones@redhat.com</a>> wrote:<br> > <br> > > > + if disk.status == types.DiskStatus.OK:<br> > > > + debug("finalized after %s seconds", time.time() -<br> > > start)<br> > ><br> > <br> > Maybe this was the real error? (using , instead of %)<br> <br> I fixed this in a later build. However the error we're talking about<br> here seems to be unrelated to it.<br> <br> ...<br> > > ', ' File "/usr/lib64/python2.7/site-packages/ovirtsdk4/services.py",<br> > > line 37334, in remove<br> > > self._internal_remove(headers, query, wait)<br> > > ', ' File "/usr/lib64/python2.7/site-packages/ovirtsdk4/service.py", line<br> > > 271, in _internal_remove<br> > > return future.wait() if wait else future<br> > > ', ' File "/usr/lib64/python2.7/site-packages/ovirtsdk4/service.py", line<br> > > 55, in wait<br> > > return self._code(response)<br> > > ', ' File "/usr/lib64/python2.7/site-packages/ovirtsdk4/service.py", line<br> > > 268, in callback<br> > > self._check_fault(response)<br> > > ', ' File "/usr/lib64/python2.7/site-packages/ovirtsdk4/service.py", line<br> > > 132, in _check_fault<br> > > self._raise_error(response, body)<br> > > ', ' File "/usr/lib64/python2.7/site-packages/ovirtsdk4/service.py", line<br> > > 118, in _raise_error<br> > > raise error<br> > > ', 'Error: Fault reason is "Operation Failed". Fault detail is "[Cannot<br> > > remove Virtual Disk. Related operation is currently in progress. Please try<br> > > again later.]". HTTP response code is 409.<br> > > ']<br> > ><br> > <br> > I think this error means that the disk is currently busy, probably because<br> > of the real error.<br> > <br> > Ilanit, can you share complete virt-v2v and daemon logs?<br> <br> These are quite large so I uploaded them here:<br> <br> <a href="http://oirase.annexia.org/tmp/v2v-import-20190808T125134-439694.log" rel="noreferrer" target="_blank">http://oirase.annexia.org/tmp/v2v-import-20190808T125134-439694.log</a></blockquote><div><br></div><div><div class="gmail_default" style="font-size:small;color:rgb(0,0,0)">I think what we see here is that upload was successful:</div></div><div><br></div><div><div class="gmail_default" style=""><font color="#000000"></font>nbdkit: python[1]: debug: flush<br>nbdkit: python[1]: debug: flush<br>nbdkit: python[1]: debug: client sent disconnect command, closing connection<br>nbdkit: python[1]: debug: close<br>...<br>virtual copying rate: 649.6 M bits/sec<br>...<br>[1729.6] Creating output metadata<br>virt-v2v: error: transfer of disk 1/1 failed, see earlier error messages<br>...<br>nbdkit: python[1]: error: /var/tmp/v2v.sZm0my/rhv-upload-plugin.py: close: error: ['Traceback (most recent call last):\n', ' File "/var/tmp/v2v.sZm0my/rhv-upload-plugin.py", line 577, in close\n', ' File "/var/tmp/v2v.sZm0my/rhv-upload-plugin.py", line 516, in delete_disk_on_failure\n', ' File "/usr/lib64/python2.7/site-packages/ovirtsdk4/services.py", line 37334, in remove\n self._internal_remove(headers, query, wait)\n', ' File "/usr/lib64/python2.7/site-packages/ovirtsdk4/service.py", line 271, in _internal_remove\n return future.wait() if wait else future\n', ' File "/usr/lib64/python2.7/site-packages/ovirtsdk4/service.py", line 55, in wait\n return self._code(response)\n', ' File "/usr/lib64/python2.7/site-packages/ovirtsdk4/service.py", line 268, in callback\n self._check_fault(response)\n', ' File "/usr/lib64/python2.7/site-packages/ovirtsdk4/service.py", line 132, in _check_fault\n self._raise_error(response, body)\n', ' File "/usr/lib64/python2.7/site-packages/ovirtsdk4/service.py", line 118, in _raise_error\n raise error\n', 'Error: Fault reason is "Operation Failed". Fault detail is "[Cannot remove Virtual Disk. Related operation is currently in progress. Please try again later.]". HTTP response code is 409.\n']</div></div><div class="gmail_quote"><br></div>But we had a bug in the logging code:<br><br> debug("fmt", value)<br><br>This raised when we discovered that the upload was successful, and we tried to cleanup<br>after errors by deleting the disk. This fail<span class="gmail_default" style="font-size:small;color:rgb(0,0,0)">ed</span> because the disk is still being used by engine<br>at this point.</div><div class="gmail_quote"><br><div class="gmail_default" style="font-size:small;color:rgb(0,0,0)">Base on what Ilanit wrote in the other thread, after fixing the debug() call this works.</div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><br> <a href="http://oirase.annexia.org/tmp/v2v-import-20190808T125134-439694-wrapper.log" rel="noreferrer" target="_blank">http://oirase.annexia.org/tmp/v2v-import-20190808T125134-439694-wrapper.log</a><br> <br> Rich.<br> <br> -- <br> Richard Jones, Virtualization Group, Red Hat <a href="http://people.redhat.com/~rjones" rel="noreferrer" target="_blank">http://people.redhat.com/~rjones</a><br> Read my programming and virtualization blog: <a href="http://rwmj.wordpress.com" rel="noreferrer" target="_blank">http://rwmj.wordpress.com</a><br> virt-builder quickly builds VMs from scratch<br> <a href="http://libguestfs.org/virt-builder.1.html" rel="noreferrer" target="_blank">http://libguestfs.org/virt-builder.1.html</a><br> </blockquote></div></div>