[Libguestfs] [PATCH] v2v: Log full imageio response on failure.

[Nir Soffer]

On Tue, Jun 5, 2018 at 4:40 PM Richard W.M. Jones <rjones at redhat.com> wrote:

> Thanks: Nir Soffer
> ---
>  v2v/rhv-upload-plugin.py | 66
> ++++++++++++++++++++++++++++--------------------
>  1 file changed, 39 insertions(+), 27 deletions(-)
>
> diff --git a/v2v/rhv-upload-plugin.py b/v2v/rhv-upload-plugin.py
> index 791c9e7d2..c3de7d555 100644
> --- a/v2v/rhv-upload-plugin.py
> +++ b/v2v/rhv-upload-plugin.py
> @@ -228,6 +228,29 @@ def can_flush(h):
>  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, pauses the
> +# transfer, sets the failed state, and raises a RuntimeError
> +# exception.
> +def unexpected_response(h, r, msg):
>

This is not really unexpected response, maybe "request_failed"?


> +    # Setting the failed flag in the handle causes the disk to be
> +    # cleaned up on close.
> +    h['failed'] = True
> +    h['transfer_service'].pause()
> +
> +    status = r.status
> +    reason = r.reason
> +    body = r.read()
>

This should not fail, but if we there is a possible failure, it would be
more
robust to do:

    try:
        body = r.read()
    except EnvironmentError as e:
        body = "(Unable to read response body: %s)" % e

If this raises as is, we would fail with EnvironmentError, hiding
the status, reason, and msg.


> +
> +    # Log the full error if we're verbose.
> +    debug("unexpected response from imageio server:")
> +    debug(msg)
> +    debug("%d: %s" % (status, reason))
> +    debug(body)
>

Hiding fatal error in non-verbose will make it hard to support.


> +
> +    # Only a short error is included in the exception.
> +    raise RuntimeError("%s: %d: %s" % (msg, status, reason))
>

And instead include the start of the body in the error text like this:

    raise RuntimeError("%s: [%d] %s: %r", msg, status, reason, bofy[:200])

(Using %r to avoid unwanted newlines in the response).


> +
>  # For documentation see:
>  # https://github.com/oVirt/ovirt-imageio/blob/master/docs/random-io.md
>  # For examples of working code to read/write from the server, see:
> @@ -248,16 +271,14 @@ def pread(h, count, offset):
>      r = http.getresponse()
>      # 206 = HTTP Partial Content.
>      if r.status != 206:
> -        h['transfer_service'].pause()
> -        h['failed'] = True
> -        raise RuntimeError("could not read sector (%d, %d): %d: %s" %
> -                           (offset, count, r.status, r.reason))
> +        unexpected_response(h, r,
> +                            "could not read sector offset %d size %d" %
> +                            (offset, count))
>

This is much nicer.


>      return r.read()
>
>  def pwrite(h, buf, offset):
>      http = h['http']
>      transfer = h['transfer']
> -    transfer_service = h['transfer_service']
>
>      count = len(buf)
>      h['highestwrite'] = max(h['highestwrite'], offset+count)
> @@ -275,15 +296,13 @@ def pwrite(h, buf, offset):
>
>      r = http.getresponse()
>      if r.status != 200:
> -        transfer_service.pause()
> -        h['failed'] = True
> -        raise RuntimeError("could not write sector (%d, %d): %d: %s" %
> -                           (offset, count, r.status, r.reason))
> +        unexpected_response(h, r,
> +                            "could not write sector offset %d size %d" %
> +                            (offset, count))
>
>  def zero(h, count, offset, may_trim):
>      http = h['http']
>      transfer = h['transfer']
> -    transfer_service = h['transfer_service']
>
>      # Unlike the trim and flush calls, there is no 'can_zero' method
>      # so nbdkit could call this even if the server doesn't support
> @@ -306,10 +325,9 @@ def zero(h, count, offset, may_trim):
>
>      r = http.getresponse()
>      if r.status != 200:
> -        transfer_service.pause()
> -        h['failed'] = True
> -        raise RuntimeError("could not zero sector (%d, %d): %d: %s" %
> -                           (offset, count, r.status, r.reason))
> +        unexpected_response(h, r,
> +                            "could not zero sector offset %d size %d" %
> +                            (offset, count))
>
>  def emulate_zero(h, count, offset):
>      # qemu-img convert starts by trying to zero/trim the whole device.
> @@ -334,15 +352,13 @@ def emulate_zero(h, count, offset):
>
>          r = http.getresponse()
>          if r.status != 200:
> -            transfer_service.pause()
> -            h['failed'] = True
> -            raise RuntimeError("could not write zeroes (%d, %d): %d: %s" %
> -                               (offset, count, r.status, r.reason))
> +            unexpected_response(h, r,
> +                                "could not write zeroes offset %d size
> %d" %
> +                                (offset, count))
>
>  def trim(h, count, offset):
>      http = h['http']
>      transfer = h['transfer']
> -    transfer_service = h['transfer_service']
>
>      # Construct the JSON request for trimming.
>      buf = json.dumps({'op': "trim",
> @@ -358,15 +374,13 @@ def trim(h, count, offset):
>
>      r = http.getresponse()
>      if r.status != 200:
> -        transfer_service.pause()
> -        h['failed'] = True
> -        raise RuntimeError("could not trim sector (%d, %d): %d: %s" %
> -                           (offset, count, r.status, r.reason))
> +        unexpected_response(h, r,
> +                            "could not trim sector offset %d size %d" %
> +                            (offset, count))
>
>  def flush(h):
>      http = h['http']
>      transfer = h['transfer']
> -    transfer_service = h['transfer_service']
>
>      # Construct the JSON request for flushing.
>      buf = json.dumps({'op': "flush"}).encode()
> @@ -379,9 +393,7 @@ def flush(h):
>
>      r = http.getresponse()
>      if r.status != 200:
> -        transfer_service.pause()
> -        h['failed'] = True
> -        raise RuntimeError("could not flush: %d: %s" % (r.status,
> r.reason))
> +        unexpected_response(h, r, "could not flush")
>
>  def delete_disk_on_failure(h):
>      disk_service = h['disk_service']
>
>
Nir
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/libguestfs/attachments/20180605/94f9139f/attachment.htm>