Libguestfs - Aug 2018 - [PATCH 0/2] v2v: rhv-upload-plugin: Improve error handling

These patches improve error handling when PUT request fail, including
the error response from oVirt server. This will make it easier to debug
issue when oVirt server logs have been rotated.

Nir Soffer (2):
  v2v: rhv-upload-plugin: Handle send send failures
  v2v: rhv-upload-plugin: Fix error formatting

 v2v/rhv-upload-plugin.py | 24 +++++++++++++++++-------
 1 file changed, 17 insertions(+), 7 deletions(-)

-- 
2.17.1

The oVirt server may fail a PUT request before reading all request body.
However before closing the connection, it writes a detailed error
response, that will make debugging issues like expired tickets much
easier to handle. If we don't get the response and log the error, the
error may be lost when the daemon log is rotated.

Change pwrite() and emulate_zero() to get the response after EPIPE,
failing with the error response from the oVirt server.

Here is an example error log when a ticket expires during import:

nbdkit: python[1]: error:
/home/nsoffer/src/libguestfs/tmp/v2v.pRoyXm/rhv-upload-plugin.py:
pwrite: error: ('%s: %d %s: %r', 'could not write sector offset
1841154048 size 1024', 403,
'Forbidden', b'{"explanation": "Access was denied to
this resource.", "code": 403, "detail":
"Ticket u\'6071e16f-ec60-4ff9-a594-10b0faae3617\' expired",
"title": "Forbidden"}')
---
 v2v/rhv-upload-plugin.py | 22 ++++++++++++++++------
 1 file changed, 16 insertions(+), 6 deletions(-)

diff --git a/v2v/rhv-upload-plugin.py b/v2v/rhv-upload-plugin.py
index 2d686c2da..7327ea4c5 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 errno
 import json
 import logging
 import socket
@@ -357,7 +358,12 @@ def pwrite(h, buf, offset):
     http.putheader("Content-Range", "bytes %d-%d/*" %
(offset, offset+count-1))
     http.putheader("Content-Length", str(count))
     http.endheaders()
-    http.send(buf)
+
+    try:
+        http.send(buf)
+    except socket.error as e:
+        if e[0] != errno.EPIPE:
+            raise
 
     r = http.getresponse()
     if r.status != 200:
@@ -413,11 +419,15 @@ def emulate_zero(h, count, offset):
         http.putheader("Content-Length", str(count))
         http.endheaders()
 
-        buf = bytearray(128*1024)
-        while count > len(buf):
-            http.send(buf)
-            count -= len(buf)
-        http.send(buffer(buf, 0, count))
+        try:
+            buf = bytearray(128*1024)
+            while count > len(buf):
+                http.send(buf)
+                count -= len(buf)
+            http.send(buffer(buf, 0, count))
+        except socket.error as e:
+            if e[0] != errno.EPIPE:
+                raise
 
         r = http.getresponse()
         if r.status != 200:
-- 
2.17.1

Fix the error format so we actually format the arguments instead of
raising the format string and the arguments.

Here is an upload error formatted correctly with this change:

nbdkit: python[1]: error:
/home/nsoffer/src/libguestfs/tmp/v2v.eC5yCl/rhv-upload-plugin.py:
pwrite: error: could not write sector offset 218911744 size 3584: 403 Forbidden:
b'{"explanation": "Access was denied to this resource.",
"code": 403, "detail":
"Ticket u\'61ac0483-48e3-4984-84d6-438884ba8bb2\' expired",
"title": "Forbidden"}'
---
 v2v/rhv-upload-plugin.py | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/v2v/rhv-upload-plugin.py b/v2v/rhv-upload-plugin.py
index 7327ea4c5..b5dd5521d 100644
--- a/v2v/rhv-upload-plugin.py
+++ b/v2v/rhv-upload-plugin.py
@@ -317,7 +317,7 @@ def request_failed(h, r, msg):
     debug(body)
 
     # Only a short error is included in the exception.
-    raise RuntimeError("%s: %d %s: %r", msg, status, reason,
body[:200])
+    raise RuntimeError("%s: %d %s: %r" % (msg, status, reason,
body[:200]))
 
 # For documentation see:
 # https://github.com/oVirt/ovirt-imageio/blob/master/docs/random-io.md
-- 
2.17.1

On Tue, Aug 21, 2018 at 01:15:02AM +0300, Nir Soffer
wrote:
> The oVirt server may fail a PUT request before reading all request body.
> However before closing the connection, it writes a detailed error
> response, that will make debugging issues like expired tickets much
> easier to handle. If we don't get the response and log the error, the
> error may be lost when the daemon log is rotated.
This series looks fine, I'll push it in a minute.

Couple of questions:

(1) Are we using the nbdkit enhanced Python error reporting yet?
What's stopping us if we are not?

(2) Is there a BZ associated with this change?  If not, we'll need one
if you want to get these changes into RHEL.

Thanks,

Rich.

-- 
Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones
Read my programming and virtualization blog: http://rwmj.wordpress.com
Fedora Windows cross-compiler. Compile Windows programs, test, and
build Windows installers. Over 100 libraries supported.
http://fedoraproject.org/wiki/MinGW