Re: [Libguestfs] [PATCH] rhv-upload: Handle any error in NBD handlers

Currently we handle only HTTP errors like getting unexpected response code from imageio server. However if we could not send the request, or some other error is raised, we failed to mark the handle as failed, and finalized the transfer in close(). This may fool virt-v2v to create a VM with an empty or partially uploaded disk. Decorate all the NBD hander functions with a @failing decorator, ensuring that any error in the decorated function will mark the handle as failed. Since errors are handled now by @failing decorator, remove the code to mark a handle as failed in request_failed().

I tested 3 flows by injecting errors in imageio server: ## Error in flush() nbdkit: python[1]: debug: pwrite count=65536 offset=6442385408 fua=0     (100.00/100%) nbdkit: python[1]: debug: flush unexpected response from imageio server: could not flush 403: Forbidden b'no flush for you!' nbdkit: python[1]: error: /home/nsoffer/src/virt-v2v/tmp/rhvupload.bwlJfk/rhv-upload-plugin.py: flush: error: ['Traceback (most recent call last):\n', '  File "/home/nsoffer/src/virt-v2v/tmp/rhvupload.bwlJfk/rhv-upload-plugin.py", line 86, in wrapper\n    return func(h, *args)\n', '  File "/home/nsoffer/src/virt-v2v/tmp/rhvupload.bwlJfk/rhv-upload-plugin.py", line 323, in flush\n    request_failed(r, "could not flush")\n', '  File "/home/nsoffer/src/virt-v2v/tmp/rhvupload.bwlJfk/rhv-upload-plugin.py", line 165, in request_failed\n    raise RuntimeError("%s: %d %s: %r" % (msg, status, reason, body[:200]))\n', "RuntimeError: could not flush: 403 Forbidden: b'no flush for you!'\n"] nbdkit: python[1]: debug: sending error reply: Input/output error nbdkit: python[1]: debug: flush unexpected response from imageio server: could not flush 403: Forbidden b'no flush for you!' nbdkit: python[1]: error: /home/nsoffer/src/virt-v2v/tmp/rhvupload.bwlJfk/rhv-upload-plugin.py: flush: error: ['Traceback (most recent call last):\n', '  File "/home/nsoffer/src/virt-v2v/tmp/rhvupload.bwlJfk/rhv-upload-plugin.py", line 86, in wrapper\n    return func(h, *args)\n', '  File "/home/nsoffer/src/virt-v2v/tmp/rhvupload.bwlJfk/rhv-upload-plugin.py", line 323, in flush\n    request_failed(r, "could not flush")\n', '  File "/home/nsoffer/src/virt-v2v/tmp/rhvupload.bwlJfk/rhv-upload-plugin.py", line 165, in request_failed\n    raise RuntimeError("%s: %d %s: %r" % (msg, status, reason, body[:200]))\n', "RuntimeError: could not flush: 403 Forbidden: b'no flush for you!'\n"] nbdkit: python[1]: debug: sending error reply: Input/output error virtual copying rate: 3992.5 M bits/sec nbdkit: python[1]: debug: client sent NBD_CMD_DISC, closing connection nbdkit: python[1]: debug: close canceling transfer a46a6646-6eb5-44c9-8234-de5b1779daa5 ## Error in pwrite() nbdkit: python[1]: debug: pwrite count=65536 offset=0 fua=0 unexpected response from imageio server: could not write sector offset 0 size 65536 403: Forbidden b'no put for you!' nbdkit: python[1]: error: /home/nsoffer/src/virt-v2v/tmp/rhvupload.mVaSya/rhv-upload-plugin.py: pwrite: error: ['Traceback (most recent call last):\n', '  File "/home/nsoffer/src/virt-v2v/tmp/rhvupload.mVaSya/rhv-upload-plugin.py", line 86, in wrapper\n    return func(h, *args)\n', '  File "/home/nsoffer/src/virt-v2v/tmp/rhvupload.mVaSya/rhv-upload-plugin.py", line 218, in pwrite\n    (offset, count))\n', '  File "/home/nsoffer/src/virt-v2v/tmp/rhvupload.mVaSya/rhv-upload-plugin.py", line 165, in request_failed\n    raise RuntimeError("%s: %d %s: %r" % (msg, status, reason, body[:200]))\n', "RuntimeError: could not write sector offset 0 size 65536: 403 Forbidden: b'no put for you!'\n"] nbdkit: python[1]: debug: sending error reply: Input/output error qemu-img: error while writing sector 0: Input/output error nbdkit: python[1]: debug: flush nbdkit: python[1]: debug: flush nbdkit: python[1]: debug: client sent NBD_CMD_DISC, closing connection nbdkit: python[1]: debug: close canceling transfer d12874ff-be5a-4db2-b911-2b125f004b4c virt-v2v: error: qemu-img command failed, see earlier errors ## Error to connect to unix socket. Simulated by changing reporting non existing socket path. nbdkit: python[1]: debug: pwrite count=65536 offset=0 fua=0 nbdkit: python[1]: error: /home/nsoffer/src/virt-v2v/tmp/rhvupload.YOMKDV/rhv-upload-plugin.py: pwrite: error: ['Traceback (most recent call last):\n', '  File "/home/nsoffer/src/virt-v2v/tmp/rhvupload.YOMKDV/rhv-upload-plugin.py", line 86, in wrapper\n    return func(h, *args)\n', '  File "/home/nsoffer/src/virt-v2v/tmp/rhvupload.YOMKDV/rhv-upload-plugin.py", line 207, in pwrite\n    http.endheaders()\n', '  File "/usr/lib64/python3.7/http/client.py", line 1247, in endheaders\n    self._send_output(message_body, encode_chunked=encode_chunked)\n', '  File "/usr/lib64/python3.7/http/client.py", line 1026, in _send_output\n    self.send(msg)\n', '  File "/usr/lib64/python3.7/http/client.py", line 966, in send\n    self.connect()\n', '  File "/home/nsoffer/src/virt-v2v/tmp/rhvupload.YOMKDV/rhv-upload-plugin.py", line 378, in connect\n    self.sock.connect(self.path)\n', 'ConnectionRefusedError: [Errno 111] Connection refused\n'] nbdkit: python[1]: debug: sending error reply: Input/output error qemu-img: error while writing sector 0: Input/output error nbdkit: python[1]: debug: flush nbdkit: python[1]: error: /home/nsoffer/src/virt-v2v/tmp/rhvupload.YOMKDV/rhv-upload-plugin.py: flush: error: ['Traceback (most recent call last):\n', '  File "/home/nsoffer/src/virt-v2v/tmp/rhvupload.YOMKDV/rhv-upload-plugin.py", line 86, in wrapper\n    return func(h, *args)\n', '  File "/home/nsoffer/src/virt-v2v/tmp/rhvupload.YOMKDV/rhv-upload-plugin.py", line 319, 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: flush nbdkit: python[1]: error: /home/nsoffer/src/virt-v2v/tmp/rhvupload.YOMKDV/rhv-upload-plugin.py: flush: error: ['Traceback (most recent call last):\n', '  File "/home/nsoffer/src/virt-v2v/tmp/rhvupload.YOMKDV/rhv-upload-plugin.py", line 86, in wrapper\n    return func(h, *args)\n', '  File "/home/nsoffer/src/virt-v2v/tmp/rhvupload.YOMKDV/rhv-upload-plugin.py", line 319, 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: client sent NBD_CMD_DISC, closing connection nbdkit: python[1]: debug: close canceling transfer a3a1d037-c15e-4b70-b8f9-3a809d690be9 v2v/rhv-upload-plugin.py | 45 +++++++++++++++++++++++++++++----------- 1 file changed, 33 insertions(+), 12 deletions(-) diff --git a/v2v/rhv-upload-plugin.py b/v2v/rhv-upload-plugin.py index 43fea18b..7ed521f3 100644 --- a/v2v/rhv-upload-plugin.py +++ b/v2v/rhv-upload-plugin.py @@ -17,6 +17,7 @@ # 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. import builtins +import functools import json import logging import socket @@ -72,6 +73,22 @@ def parse_username(): parsed = urlparse(params['output_conn']) return parsed.username or "admin@internal" +def failing(func): + """ + Decorator marking the handle as failed if any expection is raised in the + decorated function. This is used in close() to cleanup properly after + failures. + """ + @functools.wraps(func) + def wrapper(h, *args): + try: + return func(h, *args) + except: + h['failed'] = True + raise + + return wrapper + def open(readonly): connection = sdk.Connection( url = params['output_conn'], @@ -115,22 +132,21 @@ def open(readonly): 'path': destination_url.path, } +@failing def can_trim(h): return h['can_trim'] +@failing def can_flush(h): return h['can_flush'] +@failing def get_size(h): return params['disk_size'] # Any unexpected HTTP response status from the server will end up calling this -# function which logs the full error, sets the failed state, and raises a -# RuntimeError exception. -def request_failed(h, r, msg): - # Setting the failed flag in the handle will cancel the transfer on close. - h['failed'] = True - +# function which logs the full error, and raises a RuntimeError exception. +def request_failed(r, msg): status = r.status reason = r.reason try: @@ -152,6 +168,7 @@ def request_failed(h, r, msg): # For examples of working code to read/write from the server, see: # https://github.com/oVirt/ovirt-imageio/blob/master/daemon/test/server_tes... +@failing def pread(h, count, offset): http = h['http'] transfer = h['transfer'] @@ -165,12 +182,13 @@ def pread(h, count, offset): r = http.getresponse() # 206 = HTTP Partial Content. if r.status != 206: - request_failed(h, r, + request_failed(r, "could not read sector offset %d size %d" % (offset, count)) return r.read() +@failing def pwrite(h, buf, offset): http = h['http'] transfer = h['transfer'] @@ -194,12 +212,13 @@ def pwrite(h, buf, offset): r = http.getresponse() if r.status != 200: - request_failed(h, r, + request_failed(r, "could not write sector offset %d size %d" % (offset, count)) r.read() +@failing def zero(h, count, offset, may_trim): http = h['http'] @@ -223,7 +242,7 @@ def zero(h, count, offset, may_trim): r = http.getresponse() if r.status != 200: - request_failed(h, r, + request_failed(r, "could not zero sector offset %d size %d" % (offset, count)) @@ -257,12 +276,13 @@ def emulate_zero(h, count, offset): r = http.getresponse() if r.status != 200: - request_failed(h, r, + request_failed(r, "could not write zeroes offset %d size %d" % (offset, count)) r.read() +@failing def trim(h, count, offset): http = h['http'] @@ -279,12 +299,13 @@ def trim(h, count, offset): r = http.getresponse() if r.status != 200: - request_failed(h, r, + request_failed(r, "could not trim sector offset %d size %d" % (offset, count)) r.read() +@failing def flush(h): http = h['http'] @@ -298,7 +319,7 @@ def flush(h): r = http.getresponse() if r.status != 200: - request_failed(h, r, "could not flush") + request_failed(r, "could not flush") r.read() -- 2.21.0