Hello Piotr Kliczewski, Nir Soffer, Francesco Romani,

I'd like you to do a code review.  Please visit

    https://gerrit.ovirt.org/60103

to review the following change.

Change subject: rpc: Log also error codes of RPC calls
......................................................................

rpc: Log also error codes of RPC calls

In one of the previous commits, we added logging of RPC calls on info
level.  It'd be useful to have information about response codes there,
so this patch adds that information.

Change-Id: I776e667fcfd1a20a9ef5f6c638d6c3d950672314
Bug-Url: https://bugzilla.redhat.com/1351247
Backport-To: 4.0
Signed-off-by: Milan Zamazal <mzama...@redhat.com>
Reviewed-on: https://gerrit.ovirt.org/59234
Reviewed-by: Nir Soffer <nsof...@redhat.com>
Reviewed-by: Piotr Kliczewski <piotr.kliczew...@gmail.com>
Continuous-Integration: Jenkins CI
Reviewed-on: https://gerrit.ovirt.org/59999
Reviewed-by: Francesco Romani <from...@redhat.com>
---
M lib/yajsonrpc/__init__.py
M vdsm/rpc/bindingxmlrpc.py
2 files changed, 36 insertions(+), 13 deletions(-)


  git pull ssh://gerrit.ovirt.org:29418/vdsm refs/changes/03/60103/1

diff --git a/lib/yajsonrpc/__init__.py b/lib/yajsonrpc/__init__.py
index d02125a..e3d2d98 100644
--- a/lib/yajsonrpc/__init__.py
+++ b/lib/yajsonrpc/__init__.py
@@ -496,8 +496,22 @@
     def _serveRequest(self, ctx, req):
         start_time = monotonic_time()
         response = self._handle_request(req, ctx.address)
-        self.log.info("RPC call %s finished in %.2f seconds",
-                      req.method, monotonic_time() - start_time)
+        error = getattr(response, "error", None)
+        if error is None:
+            response_log = "succeeded"
+        else:
+            if isinstance(error, JsonRpcError):
+                error_code = error.code
+            elif isinstance(error, dict):
+                try:
+                    error_code = error['status']['code']
+                except:
+                    error_code = '?'
+            else:
+                error_code = '?'
+            response_log = "failed (error %s)" % (error_code,)
+        self.log.info("RPC call %s %s in %.2f seconds",
+                      req.method, response_log, monotonic_time() - start_time)
         if response is not None:
             ctx.requestDone(response)
 
diff --git a/vdsm/rpc/bindingxmlrpc.py b/vdsm/rpc/bindingxmlrpc.py
index 68ba1bd..058f5d7 100644
--- a/vdsm/rpc/bindingxmlrpc.py
+++ b/vdsm/rpc/bindingxmlrpc.py
@@ -327,15 +327,18 @@
 
                 self.log.debug(fmt, *logargs)
 
+                res = {}
                 try:
-                    return f(*args, **kwargs)
+                    res = f(*args, **kwargs)
                 except:
                     self.log.error("Unexpected exception", exc_info=True)
-                    return errCode['unexpected']
-                finally:
-                    self.log.info("RPC call %s finished in %.2f seconds",
-                                  f.__name__,
-                                  utils.monotonic_time() - start_time)
+                    res = errCode['unexpected']
+                self.log.info("RPC call %s finished (code=%s) in "
+                              "%.2f seconds",
+                              f.__name__,
+                              res.get('status', {}).get('code'),
+                              utils.monotonic_time() - start_time)
+                return res
 
             wrapper.__name__ = f.__name__
             wrapper.__doc__ = f.__doc__
@@ -1225,6 +1228,7 @@
 def wrapApiMethod(f):
     def wrapper(*args, **kwargs):
         start_time = utils.monotonic_time()
+        res = {}
         try:
             logLevel = logging.DEBUG
             suppress_args = f.__name__ in ('fenceNode',)
@@ -1285,18 +1289,23 @@
         except libvirt.libvirtError as e:
             f.__self__.cif.log.error("libvirt error", exc_info=True)
             if e.get_error_code() == libvirt.VIR_ERR_NO_DOMAIN:
-                return errCode['noVM']
+                res = errCode['noVM']
             else:
-                return errCode['unexpected']
+                res = errCode['unexpected']
+            return res
         except VdsmException as e:
             f.__self__.cif.log.error("vdsm exception occured", exc_info=True)
-            return e.response()
+            res = e.response()
+            return res
         except:
             f.__self__.cif.log.error("unexpected error", exc_info=True)
-            return errCode['unexpected']
+            res = errCode['unexpected']
+            return res
         finally:
-            f.__self__.cif.log.info("RPC call %s finished in %.2f seconds",
+            f.__self__.cif.log.info("RPC call %s finished (code=%s) in "
+                                    "%.2f seconds",
                                     f.__name__,
+                                    res.get('status', {}).get('code'),
                                     utils.monotonic_time() - start_time)
     wrapper.__name__ = f.__name__
     wrapper.__doc__ = f.__doc__


-- 
To view, visit https://gerrit.ovirt.org/60103
To unsubscribe, visit https://gerrit.ovirt.org/settings

Gerrit-MessageType: newchange
Gerrit-Change-Id: I776e667fcfd1a20a9ef5f6c638d6c3d950672314
Gerrit-PatchSet: 1
Gerrit-Project: vdsm
Gerrit-Branch: ovirt-3.6
Gerrit-Owner: Milan Zamazal <mzama...@redhat.com>
Gerrit-Reviewer: Francesco Romani <from...@redhat.com>
Gerrit-Reviewer: Nir Soffer <nsof...@redhat.com>
Gerrit-Reviewer: Piotr Kliczewski <piotr.kliczew...@gmail.com>
_______________________________________________
vdsm-patches mailing list
vdsm-patches@lists.fedorahosted.org
https://lists.fedorahosted.org/admin/lists/vdsm-patches@lists.fedorahosted.org

Reply via email to