Reworked error handling in server, client and filer (again :( ). We definitely...

Reworked error handling in server, client and filer (again :( ). We definitely have to support multiple errors so let's do it right.  Error now contains list of errors.  Got rid of "detail" section everything now goes directly within particular error.  Error can bear "events" attribute for list of sent events concerned (or none if all sent events erred). Streamlined error logging.
Server now retries if MySQL went away.
Response result now gets properly encoded if Unicode appears somehow (however that's just fighting symptoms, should get more thorough fix).

warden3/contrib/warden_filer/warden_filer.py

@@ -221,26 +221,27 @@ def sender(config, wclient, sdir, oneshot):
 
             count_ok = count_err = count_retry = 0
             if isinstance(res, Error):
-                try:
-                    errs = res.detail["errors"]
-                except (KeyError, AttributeError, TypeError):
-                    errs = None
-                if errs:
-                    # Event errors - move bad events into "errors"
-                    for e in errs.iterkeys():
+                for e in res.errors:
+                    # list of events with this error (none means all events)
+                    evlist = e.get("events", xrange(len(nf_sent)))
+                    # error number
+                    error = e.get("error", 0)
+                    for idx in evlist:
                         try:
-                            idx = int(e)
+                            idx_n = int(idx)
+                            # 4xx errors are permanent, 5xx are server ones, suitable for retry
+                            dest_dir = sdir.errors if 400 <= error < 500 else sdir.incoming
                         except ValueError:
+                            # Cannot grok event number, skip
                             continue
-                        nf_sent[idx].moveto(sdir.errors)
-                        nf_sent[idx] = None
-                        count_err += 1
-                else:
-                    # Global errors - move all events back to "incoming" for attempt in next round
-                    for idx in range(len(nf_sent)):
-                        nf_sent[idx].moveto(sdir.incoming)
-                        nf_sent[idx] = None
-                        count_retry += 1
+                        if nf_sent[idx_n]:
+                            nf_sent[idx_n].moveto(dest_dir)
+                            nf_sent[idx_n] = None
+                            if dest_dir == sdir.errors:
+                                count_err += 1
+                            else:
+                                count_retry += 1
+
             # Cleanup rest - succesfully sent events
             for name in nf_sent:
                 if name:

warden3/warden_client/warden_client.py

@@ -56,24 +56,32 @@ class Error(Exception):
         Also, it can be raised as an exception.
     """
 
-    def __init__(self, message, logger=None, error=None, prio="error", method=None,
-            req_id=None, detail=None, exc=None):
-
-        self.message = message
-        self.error = error
-        self.method = method
-        self.req_id = req_id
-        self.detail = detail
-        (self.exctype, self.excval, self.exctb) = exc or (None, None, None)
-        self.cause = self.excval # compatibility with other exceptions
+    def __init__(self, logger=None, prio=logging.ERROR, method=None, req_id=None,
+            exc=None, errors=None, **kwargs):
+
+        self.errors = []
+        if errors:
+            self.extend(method, req_id, errors)
+        if kwargs:
+            self.append(method, req_id, **kwargs)
         if logger:
-            getattr(logger, prio, "error")(str(self))
-            info = self.info_str()
-            if info:
-                logger.info(info)
-            debug = self.debug_str()
-            if debug:
-                logger.debug(debug)
+            log(logger, prio)
+
+
+    def append(self, method=None, req_id=None, **kwargs):
+        # We shift method and req_id into each and every error, because
+        # we want to be able to simply merge more Error arrays (for
+        # returning errors from more Warden calls at once
+        if method and not "method" in kwargs:
+            kwargs["method"] = method
+        if req_id and not "req_id" in kwargs:
+            kwargs["req_id"] = req_id
+        self.errors.append(kwargs)
+
+
+    def extend(self, method=None, req_id=None, iterable=[]):
+        for e in iterable:
+            self.append(method, req_id, **e)
 
 
     def __len__ (self):
@@ -97,29 +105,56 @@ class Error(Exception):
 
 
     def __str__(self):
+        return "\n".join(self.str_err(e) for e in self.errors)
+
+
+    def log(self, logger, prio=logging.ERROR):
+        for e in self.errors:
+            logger.log(prio, self.str_err(e))
+            info = self.str_info(e)
+            if info:
+                logger.info(info)
+            debug = self.str_debug(e)
+            if debug:
+                logger.debug(debug)
+
+
+    def str_preamble(self, e):
+        return "%08x/%s" % (e.get("req_id", 0), e.get("method", "?"))
+
+
+    def str_err(self, e):
         out = []
-        out.append("(%s)" % (self.error or "local"))
-        if self.method is not None:
-            out.append(" in %s" % self.method)
-        if self.req_id is not None:
-            out.append("(%08x)" % self.req_id)
-        if self.message is not None:
-            out.append(": %s" % self.message)
-        if self.excval is not None:
-            out.append(" - cause was %s: %s" % (type(self.excval).__name__, str(self.excval)))
+        out.append(self.str_preamble(e))
+        out.append(" Error(%s) %s " % (e.get("error", 0), e.get("message", "Unknown error")))
+        if "exc" in e and e["exc"]:
+            out.append("(cause was %s: %s)" % (e["exc"][0].__name__, str(e["exc"][1])))
         return "".join(out)
 
 
-    def info_str(self):
-        return ("Detail: %s" % pformat(self.detail)) or ""
+    def str_info(self, e):
+        ecopy = dict(e)    # shallow copy
+        ecopy.pop("req_id", None)
+        ecopy.pop("method", None)
+        ecopy.pop("error", None)
+        ecopy.pop("message", None)
+        ecopy.pop("exc", None)
+        if ecopy:
+            out = "%s Detail: %s" % (self.str_preamble(e), json.dumps(ecopy, default=lambda v: str(v)))
+        else:
+            out = ""
+        return out
 
 
-    def debug_str(self):
+    def str_debug(self, e):
         out = []
-        if self.excval is not None:
-            out.append("Exception %s: %s\n" % (type(self.excval).__name__, str(self.excval)))
-        if self.exctb is not None:
-            out.append("Traceback:\n%s" % "".join(format_tb(self.exctb)))
+        out.append(self.str_preamble(e))
+        if not "exc" in e or not e["exc"]:
+            return ""
+        exc_tb = e["exc"][2]
+        if exc_tb:
+            out.append("Traceback:\n")
+            out.extend(format_tb(exc_tb))
         return "".join(out)
 
 
@@ -178,7 +213,7 @@ class Client(object):
                 self.logger.warning("Unknown syslog facility \"%s\", using \"local7\"" % fac)
                 return logging.handlers.SysLogHandler.LOG_LOCAL7
 
-        form = "%(filename)s[%(process)d]: (%(levelname)s) %(name)s %(message)s"
+        form = "%(filename)s[%(process)d]: %(name)s (%(levelname)s) %(message)s"
         format_notime = logging.Formatter(form)
         format_time = logging.Formatter('%(asctime)s ' + form)
 
@@ -189,7 +224,7 @@ class Client(object):
         if errlog is not None:
             el = logging.StreamHandler(stderr)
             el.setFormatter(format_time)
-            el.setLevel(loglevel(errlog.get("level", "debug")))
+            el.setLevel(loglevel(errlog.get("level", "info")))
             self.logger.addHandler(el)
 
         if filelog is not None:
@@ -198,22 +233,22 @@ class Client(object):
                     filename=path.join(
                         path.dirname(__file__),
                         filelog.get("file", "%s.log" % self.name)))
-                fl.setLevel(loglevel(filelog.get("level", "warning")))
+                fl.setLevel(loglevel(filelog.get("level", "debug")))
                 fl.setFormatter(format_time)
                 self.logger.addHandler(fl)
             except Exception as e:
-                Error("Unable to setup file logging", self.logger, exc=exc_info())
+                Error(self.logger, message="Unable to setup file logging", exc=exc_info())
 
         if syslog is not None:
             try:
                 sl = logging.handlers.SysLogHandler(
                     address=syslog.get("socket", "/dev/log"),
                     facility=facility(syslog.get("facility", "local7")))
-                sl.setLevel(loglevel(syslog.get("level", "warning")))
+                sl.setLevel(loglevel(syslog.get("level", "debug")))
                 sl.setFormatter(format_notime)
                 self.logger.addHandler(sl)
             except Exception as e:
-                Error("Unable to setup syslog logging", self.logger, exc=exc_info())
+                Error(self.logger, message="Unable to setup syslog logging", exc=exc_info())
 
         if not (errlog or filelog or syslog):
             # User wants explicitly no logging, so let him shoot his socks off.
@@ -241,10 +276,10 @@ class Client(object):
                     strict = False,
                     timeout = self.timeout)
             else:
-                return Error("Don't know how to connect to \"%s\"" % self.url.scheme, self.logger,
+                return Error(self.logger, message="Don't know how to connect to \"%s\"" % self.url.scheme,
                         detail={"url": self.url.geturl()})
         except Exception:
-            return Error("HTTPS connection failed", self.logger, exc=exc_info(),
+            return Error(self.logger, message="HTTPS connection failed", exc=exc_info(),
                 detail={
                     "url": self.url.geturl(),
                     "timeout": self.timeout,
@@ -278,7 +313,7 @@ class Client(object):
             else:
                 data = json.dumps(payload)
         except:
-            return Error("Serialization to JSON failed", self.logger,
+            return Error(self.logger, message="Serialization to JSON failed",
                 exc=exc_info(), method=func, detail=payload)
 
         self.headers = {
@@ -297,7 +332,7 @@ class Client(object):
             conn.request("POST", loc, data, self.headers)
         except:
             conn.close()
-            return Error("Sending of request to server failed", self.logger,
+            return Error(self.logger, message="Sending of request to server failed",
                 exc=exc_info(), method=func, detail={
                     "loc": loc,
                     "headers": self.headers,
@@ -307,7 +342,7 @@ class Client(object):
             res = conn.getresponse()
         except:
             conn.close()
-            return Error("HTTP reply failed", self.logger, method=func, exc=exc_info(), detail={
+            return Error(self.logger, method=func, message="HTTP reply failed", exc=exc_info(), detail={
                 "loc": loc,
                 "headers": self.headers,
                 "data": data})
@@ -316,7 +351,7 @@ class Client(object):
             response_data = res.read()
         except:
             conn.close()
-            return Error("Fetching HTTP data from server failed", self.logger, method=func, exc=exc_info(), detail={
+            return Error(self.logger, method=func, message="Fetching HTTP data from server failed", exc=exc_info(), detail={
                 "loc": loc,
                 "headers": self.headers,
                 "data": data})
@@ -327,24 +362,23 @@ class Client(object):
             try:
                 data = json.loads(response_data)
             except:
-                data = Error("JSON message parsing failed", self.logger,
+                data = Error(self.logger, message="JSON message parsing failed",
                     exc=exc_info(), method=func, detail={"response": response_data})
         else:
             try:
                 data = json.loads(response_data)
-                data["error"]   # trigger exception if not dict or no error key
+                data["errors"]   # trigger exception if not dict or no error key
             except:
-                data = Error("Generic server HTTP error", self.logger,
+                data = Error(self.logger, message="Generic server HTTP error",
                     method=func,
                     error=res.status,
                     exc=exc_info(),
                     detail={"response": response_data})
             else:
-                data = Error(data.get("message", None), self.logger,
+                data = Error(self.logger,
                     method=data.get("method", None),
-                    error=res.status,
                     req_id=data.get("req_id", None),
-                    detail=data.get("detail", None))
+                    errors=data.get("errors", []))
 
         return data
 
@@ -358,8 +392,8 @@ class Client(object):
                 f.write(str(id))
         except (ValueError, IOError) as e:
             # Use Error instance just for proper logging
-            Error("Writing id file \"%s\" failed" % idf, self.logger,
-                prio="info", exc=exc_info(), detail={"idstore": idf})
+            Error(self.logger, message="Writing id file \"%s\" failed" % idf,
+                prio=logging.INFO, exc=exc_info(), detail={"idstore": idf})
         return id
 
 
@@ -371,8 +405,9 @@ class Client(object):
             with open(idf, "r") as f:
                 id = int(f.read())
         except (ValueError, IOError) as e:
-            Error("Reading id file \"%s\" failed, relying on server" % idf,
-                self.logger, prio="info", exc=exc_info(), detail={"idstore": idf})
+            Error(self.logger, prio=logging.INFO,
+                message="Reading id file \"%s\" failed, relying on server" % idf,
+                exc=exc_info(), detail={"idstore": idf})
             id = None
         return id
 
@@ -409,7 +444,7 @@ class Client(object):
             events = res["events"]
             newid = res["lastid"]
         except KeyError:
-            return Error("Server returned bogus reply", self.logger,
+            return Error(self.logger, message="Server returned bogus reply",
                 method="getEvents", exc=exc_info(), detail={"response": res})
 
         self._saveID(newid)