Libguestfs - Nov 2019 - Re: [PATCH v2 00/11] rvh-upload: Various fixes and cleanups

On Tue, Nov 19, 2019 at 2:16 PM Martin Kletzander <mkletzan@redhat.com>
wrote:
> On Tue, Nov 19, 2019 at 01:14:23PM +0200, Nir Soffer wrote:
> >On Tue, Nov 19, 2019 at 11:17 AM Martin Kletzander
<mkletzan@redhat.com>
> wrote:
> >>
> >> On Mon, Nov 18, 2019 at 11:53:39PM +0200, Nir Soffer wrote:
> >> >This series extract oVirt SDK and imageio code to make it
eaiser to
> follow the
> >> >code and improve error handing in open() and close().
> >> >
> >> >Tested with virt-v2v master.
> >> >
> >> >Changes since v1:
> >> >- Rebase on merged patches from v1
> >> >- Fix regression introduced by "rhv-upload: Fix cleanup
after errors"
> >> >- Remove "rhv-upload: Try to remove disk on timeout"
since it cannot
> >> >  succeed
> >> >- Add more context in debug error logs
> >> >- Use disk_id instead of disk.id in close()
> >> >
> >> >v1 was here:
> >>
>https://www.redhat.com/archives/libguestfs/2019-November/msg00060.html
> >> >
> >> >Nir Soffer (11):
> >> >  rhv-upload: Cancel transfer if finalize failed
> >> >  rhv-upload: Keep disk_id in handle
> >> >  rhv-upload: Show disk id in error message
> >> >  rhv-upload: Don't keep transfer_service in handle
> >> >  rhv-upload: Get host before creating disk
> >> >  rhv-upload: Extract create_transfer() function
> >> >  rhv-upload: Show transfer id in error message
> >> >  rhv-upload: Extract imageio helpers
> >> >  rhv-upload: Extract get_options() helper
> >> >  rhv-upload: Extract optimize_http() helper
> >> >  rhv-upload: Clean up username and password
> >> >
> >>
> >> I'm not sure which one of these is causing it, it sounds like
the first
> one, but
> >> basically the cleanup path is probably not checked well.  I'm
facing a
> >> completely different issue currently, but when updated to your
version
> (in a
> >> hope that it might either provide more data in the error message
or
> even fix it)
> >> I'm now getting a "During handling of the above
exception, another
> exception
> >> occurred", which is not a good thing.  I think it should be
easy to fix
> and also
> >> check for similar issues elsewhere, but I'm now trying to
figure out
> different
> >> things that bother me ('No route to host' changing to
'Network
> unreachable'
> >> after the patches even though I can connect everywhere the upload
> plugin is
> >> connecting), so I can't look at it right now.  Here's the
traceback:
> >>
> >> Traceback (most recent call last):
> >>   File "/var/tmp/rhvupload.Vw0CIU/rhv-upload-plugin.py",
line 94, in
> open
> >>     options = get_options(http, destination_url)
> >>   File "/var/tmp/rhvupload.Vw0CIU/rhv-upload-plugin.py",
line 575, in
> get_options
> >>     http.request("OPTIONS", url.path)
> >>   File "/usr/lib64/python3.7/http/client.py", line 1252,
in request
> >>     self._send_request(method, url, body, headers, encode_chunked)
> >>   File "/usr/lib64/python3.7/http/client.py", line 1298,
in
> _send_request
> >>     self.endheaders(body, encode_chunked=encode_chunked)
> >>   File "/usr/lib64/python3.7/http/client.py", line 1247,
in endheaders
> >>     self._send_output(message_body, encode_chunked=encode_chunked)
> >>   File "/usr/lib64/python3.7/http/client.py", line 1026,
in _send_output
> >>     self.send(msg)
> >>   File "/usr/lib64/python3.7/http/client.py", line 966,
in send
> >>     self.connect()
> >>   File "/usr/lib64/python3.7/http/client.py", line 1414,
in connect
> >>     super().connect()
> >>   File "/usr/lib64/python3.7/http/client.py", line 938,
in connect
> >>     (self.host,self.port), self.timeout, self.source_address)
> >>   File "/usr/lib64/python3.7/socket.py", line 727, in
create_connection
> >>     raise err
> >>   File "/usr/lib64/python3.7/socket.py", line 716, in
create_connection
> >>     sock.connect(sa)
> >> OSError: [Errno 101] Network is unreachable
> >>
> >> During handling of the above exception, another exception
occurred:
> >>
> >> Traceback (most recent call last):
> >>   File "/var/tmp/rhvupload.Vw0CIU/rhv-upload-plugin.py",
line 97, in
> open
> >>     transfer_service.cancel()
> >> NameError: name 'transfer_service' is not defined
> >
> >Does this fix the error for you?
> >
>
https://github.com/nirs/virt-v2v/commit/2f93dbffad81a26445831293ecac213eadffbd57
> >
> >I did not test it yet.
> >
>
> If I remove the stray `def finalize_transfer(...)` it works, yes.
>
Right, belongs to the next patch.

> In the meantime I managed to fix the original issue (which I needed to
> revert to
> test this patch =) ), thankfully it was just caused by my oVirt host setup.
>
> Unfortunately I am getting another issue.  Now nbdkit fails after all the
> data
> is written and it is trying to write the disk id file.  I'm getting
"No
> such
> file or directory", so because it is writing to that file I'm
assuming the
> directory does not exist.  On the other hand it *must* exists because
it's
> the
> same one where the python scripts are saved.  So I need to debug more.
>
This works for me, are you running a modified plugin?

On Tue, Nov 19, 2019 at 02:24:11PM +0200, Nir Soffer
wrote:
>On Tue, Nov 19, 2019 at 2:16 PM Martin Kletzander
<mkletzan@redhat.com>
>wrote:
>
>> On Tue, Nov 19, 2019 at 01:14:23PM +0200, Nir Soffer wrote:
>> >On Tue, Nov 19, 2019 at 11:17 AM Martin Kletzander
<mkletzan@redhat.com>
>> wrote:
>> >>
>> >> On Mon, Nov 18, 2019 at 11:53:39PM +0200, Nir Soffer wrote:
>> >> >This series extract oVirt SDK and imageio code to make it
eaiser to
>> follow the
>> >> >code and improve error handing in open() and close().
>> >> >
>> >> >Tested with virt-v2v master.
>> >> >
>> >> >Changes since v1:
>> >> >- Rebase on merged patches from v1
>> >> >- Fix regression introduced by "rhv-upload: Fix
cleanup after errors"
>> >> >- Remove "rhv-upload: Try to remove disk on
timeout" since it cannot
>> >> >  succeed
>> >> >- Add more context in debug error logs
>> >> >- Use disk_id instead of disk.id in close()
>> >> >
>> >> >v1 was here:
>> >>
>https://www.redhat.com/archives/libguestfs/2019-November/msg00060.html
>> >> >
>> >> >Nir Soffer (11):
>> >> >  rhv-upload: Cancel transfer if finalize failed
>> >> >  rhv-upload: Keep disk_id in handle
>> >> >  rhv-upload: Show disk id in error message
>> >> >  rhv-upload: Don't keep transfer_service in handle
>> >> >  rhv-upload: Get host before creating disk
>> >> >  rhv-upload: Extract create_transfer() function
>> >> >  rhv-upload: Show transfer id in error message
>> >> >  rhv-upload: Extract imageio helpers
>> >> >  rhv-upload: Extract get_options() helper
>> >> >  rhv-upload: Extract optimize_http() helper
>> >> >  rhv-upload: Clean up username and password
>> >> >
>> >>
>> >> I'm not sure which one of these is causing it, it sounds
like the first
>> one, but
>> >> basically the cleanup path is probably not checked well. 
I'm facing a
>> >> completely different issue currently, but when updated to your
version
>> (in a
>> >> hope that it might either provide more data in the error
message or
>> even fix it)
>> >> I'm now getting a "During handling of the above
exception, another
>> exception
>> >> occurred", which is not a good thing.  I think it should
be easy to fix
>> and also
>> >> check for similar issues elsewhere, but I'm now trying to
figure out
>> different
>> >> things that bother me ('No route to host' changing to
'Network
>> unreachable'
>> >> after the patches even though I can connect everywhere the
upload
>> plugin is
>> >> connecting), so I can't look at it right now.  Here's
the traceback:
>> >>
>> >> Traceback (most recent call last):
>> >>   File
"/var/tmp/rhvupload.Vw0CIU/rhv-upload-plugin.py", line 94, in
>> open
>> >>     options = get_options(http, destination_url)
>> >>   File
"/var/tmp/rhvupload.Vw0CIU/rhv-upload-plugin.py", line 575, in
>> get_options
>> >>     http.request("OPTIONS", url.path)
>> >>   File "/usr/lib64/python3.7/http/client.py", line
1252, in request
>> >>     self._send_request(method, url, body, headers,
encode_chunked)
>> >>   File "/usr/lib64/python3.7/http/client.py", line
1298, in
>> _send_request
>> >>     self.endheaders(body, encode_chunked=encode_chunked)
>> >>   File "/usr/lib64/python3.7/http/client.py", line
1247, in endheaders
>> >>     self._send_output(message_body,
encode_chunked=encode_chunked)
>> >>   File "/usr/lib64/python3.7/http/client.py", line
1026, in _send_output
>> >>     self.send(msg)
>> >>   File "/usr/lib64/python3.7/http/client.py", line
966, in send
>> >>     self.connect()
>> >>   File "/usr/lib64/python3.7/http/client.py", line
1414, in connect
>> >>     super().connect()
>> >>   File "/usr/lib64/python3.7/http/client.py", line
938, in connect
>> >>     (self.host,self.port), self.timeout, self.source_address)
>> >>   File "/usr/lib64/python3.7/socket.py", line 727,
in create_connection
>> >>     raise err
>> >>   File "/usr/lib64/python3.7/socket.py", line 716,
in create_connection
>> >>     sock.connect(sa)
>> >> OSError: [Errno 101] Network is unreachable
>> >>
>> >> During handling of the above exception, another exception
occurred:
>> >>
>> >> Traceback (most recent call last):
>> >>   File
"/var/tmp/rhvupload.Vw0CIU/rhv-upload-plugin.py", line 97, in
>> open
>> >>     transfer_service.cancel()
>> >> NameError: name 'transfer_service' is not defined
>> >
>> >Does this fix the error for you?
>> >
>>
https://github.com/nirs/virt-v2v/commit/2f93dbffad81a26445831293ecac213eadffbd57
>> >
>> >I did not test it yet.
>> >
>>
>> If I remove the stray `def finalize_transfer(...)` it works, yes.
>>
>
>Right, belongs to the next patch.
>
>
>> In the meantime I managed to fix the original issue (which I needed to
>> revert to
>> test this patch =) ), thankfully it was just caused by my oVirt host
setup.
>>
>> Unfortunately I am getting another issue.  Now nbdkit fails after all
the
>> data
>> is written and it is trying to write the disk id file.  I'm getting
"No
>> such
>> file or directory", so because it is writing to that file I'm
assuming the
>> directory does not exist.  On the other hand it *must* exists because
it's
>> the
>> same one where the python scripts are saved.  So I need to debug more.
>>
>
>This works for me, are you running a modified plugin?
No, it is a current master of virt-v2v.  But don't worry about it now.  It
is
most probably something with my setup again.  Even though it worked before and
these issues started showing up after an update to virt-v2v.  I'll try with
current master of nbdkit, libguestfs and virt-v2v first and if that fails
I'll
try different version of virt-v2v and then start debugging it from the script
itself.  It is a bit tedious as I need to modify the script in-tree, upload it
to the server, build it there, install it, then run virt-v2v-wrapper (that's
how
I'm testing it now) and then inspect the logs on that remote machine.

On Tue, Nov 19, 2019 at 01:48:31PM +0100, Martin Kletzander
wrote:
>On Tue, Nov 19, 2019 at 02:24:11PM +0200, Nir Soffer wrote:
>>On Tue, Nov 19, 2019 at 2:16 PM Martin Kletzander
<mkletzan@redhat.com> wrote:
>>> On Tue, Nov 19, 2019 at 01:14:23PM +0200, Nir Soffer wrote:
>>> >On Tue, Nov 19, 2019 at 11:17 AM Martin Kletzander
<mkletzan@redhat.com> wrote:
>>> >>
>>> >> Traceback (most recent call last):
>>> >>   File
"/var/tmp/rhvupload.Vw0CIU/rhv-upload-plugin.py", line 97, in
>>> open
>>> >>     transfer_service.cancel()
>>> >> NameError: name 'transfer_service' is not defined
>>> >
>>> >Does this fix the error for you?
>>> >
>>>
https://github.com/nirs/virt-v2v/commit/2f93dbffad81a26445831293ecac213eadffbd57
>>> >
>>> >I did not test it yet.
>>> >
>>>
>>> If I remove the stray `def finalize_transfer(...)` it works, yes.
>>>
>>
>>Right, belongs to the next patch.
>>
>>
>>> In the meantime I managed to fix the original issue (which I needed
to
>>> revert to
>>> test this patch =) ), thankfully it was just caused by my oVirt
host setup.
>>>
>>> Unfortunately I am getting another issue.  Now nbdkit fails after
all the
>>> data
>>> is written and it is trying to write the disk id file.  I'm
getting "No
>>> such
>>> file or directory", so because it is writing to that file
I'm assuming the
>>> directory does not exist.  On the other hand it *must* exists
because it's
>>> the
>>> same one where the python scripts are saved.  So I need to debug
more.
>>>
>>
>>This works for me, are you running a modified plugin?
>
>No, it is a current master of virt-v2v.  But don't worry about it now. 
It is
>most probably something with my setup again.  Even though it worked before
and
>these issues started showing up after an update to virt-v2v.  I'll try
with
>current master of nbdkit, libguestfs and virt-v2v first and if that fails
I'll
>try different version of virt-v2v and then start debugging it from the
script
>itself.  It is a bit tedious as I need to modify the script in-tree, upload
it
>to the server, build it there, install it, then run virt-v2v-wrapper
(that's how
>I'm testing it now) and then inspect the logs on that remote machine.
Actually looking at the whole log what I'm getting is:

nbdkit: python[1]: error: /var/tmp/rhvupload.jngN1W/rhv-upload-plugin.py: flush:
error: ['Traceback (most recent call last):\n', '  File
"/var/tmp/rhvupload.jngN1W/rhv-upload-plugin.py", line 298, in flush\n
http.request("PATCH", h[\'path\'], body=buf,
headers=headers)\n', '  File
"/usr/lib64/python3.7/http/client.py", line 1252, in request\n   
self._send_request(method, url, body, headers, encode_chunked)\n', ' 
File "/usr/lib64/python3.7/http/client.py", line 1263, in
_send_request\n    self.putrequest(method, url, **skips)\n', '  File
"/usr/lib64/python3.7/http/client.py", line 1108, in putrequest\n   
raise CannotSendRequest(self.__state)\n',
'http.client.CannotSendRequest: Request-sent\n']
nbdkit: python[1]: debug: sending error reply: Input/output error
nbdkit: python[1]: debug: python: flush
nbdkit: python[1]: error: /var/tmp/rhvupload.jngN1W/rhv-upload-plugin.py: flush:
error: ['Traceback (most recent call last):\n', '  File
"/var/tmp/rhvupload.jngN1W/rhv-upload-plugin.py", line 298, in flush\n
http.request("PATCH", h[\'path\'], body=buf,
headers=headers)\n', '  File
"/usr/lib64/python3.7/http/client.py", line 1252, in request\n   
self._send_request(method, url, body, headers, encode_chunked)\n', ' 
File "/usr/lib64/python3.7/http/client.py", line 1263, in
_send_request\n    self.putrequest(method, url, **skips)\n', '  File
"/usr/lib64/python3.7/http/client.py", line 1108, in putrequest\n   
raise CannotSendRequest(self.__state)\n',
'http.client.CannotSendRequest: Request-sent\n']
nbdkit: python[1]: debug: sending error reply: Input/output error

...

and then after couple of lines, when it is actually closing I get:

...

finalized after 8.060538530349731 seconds
nbdkit: python[1]: error: /var/tmp/rhvupload.jngN1W/rhv-upload-plugin.py: close:
error: ['Traceback (most recent call last):\n', '  File
"/var/tmp/rhvupload.jngN1W/rhv-upload-plugin.py", line 362, in
close\n', "FileNotFoundError: [Errno 2] No such file or directory:
'/var/tmp/rhvupload.jngN1W/diskid.0'\n"]
nbdkit: debug: python: unload plugin

So it might be because virt-v2v already removed that directory and did not wait
for nbdkit to completely end.  I'm testing with older commit of virt-v2v
now.

Martin