From f83b3adb016d564154bcd89a6319f71a106cd4c2 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Pavel=20K=C3=A1cha?= <ph@cesnet.cz>
Date: Sat, 17 Jan 2015 20:03:07 +0100
Subject: [PATCH] Error is now raised via req.error helper, which automatically
adds already known info (method, request id), thus calls are terser. Client's
Error communicates request id, if received from server. exc_info made
explicit everywhere. Automatic exc_info gathering sometimes returned bogus
info about unrelated exception from far before.
---
warden3/warden_client/warden_client.py | 38 ++++++++-----
warden3/warden_client/warden_curl_test.sh | 20 +++++++
warden3/warden_server/warden_server.py | 69 ++++++++++++++---------
3 files changed, 84 insertions(+), 43 deletions(-)
diff --git a/warden3/warden_client/warden_client.py b/warden3/warden_client/warden_client.py
index 531e1c1..e2ed6bb 100644
--- a/warden3/warden_client/warden_client.py
+++ b/warden3/warden_client/warden_client.py
@@ -58,13 +58,14 @@ class Error(Exception):
"""
def __init__(self, message, logger=None, error=None, prio="error", method=None,
- detail=None, exc=None):
+ req_id=None, detail=None, exc=None):
+ self.message = message
self.error = error
self.method = method
- self.message = message
+ self.req_id = req_id
self.detail = detail
- (self.exctype, self.excval, self.exctb) = exc or exc_info()
+ (self.exctype, self.excval, self.exctb) = exc or (None, None, None)
self.cause = self.excval # compatibility with other exceptions
if logger:
getattr(logger, prio, "error")(str(self))
@@ -96,7 +97,9 @@ class Error(Exception):
out = []
out.append("(%s)" % (self.error or "local"))
if self.method is not None:
- out.append(" in \"%s\"" % self.method)
+ out.append(" in %s" % self.method)
+ if self.req_id is not None:
+ out.append("(%8x)" % self.req_id)
if self.message is not None:
out.append(": %s" % self.message)
if self.excval is not None:
@@ -194,7 +197,7 @@ class Client(object):
fl.setFormatter(format_time)
self.logger.addHandler(fl)
except Exception as e:
- Error("Unable to setup file logging", self.logger)
+ Error("Unable to setup file logging", self.logger, exc=exc_info())
if syslog is not None:
try:
@@ -205,7 +208,7 @@ class Client(object):
sl.setFormatter(format_notime)
self.logger.addHandler(sl)
except Exception as e:
- Error("Unable to setup syslog logging", self.logger)
+ Error("Unable to setup syslog logging", self.logger, exc=exc_info())
if not (errlog or filelog or syslog):
# User wants explicitly no logging, so let him shoot its socks off.
@@ -234,7 +237,7 @@ class Client(object):
return Error("Don't know how to connect to \"%s\"" % self.url.scheme, self.logger,
detail={"url": self.url.geturl()})
except Exception:
- return Error("HTTPS connection failed", self.logger,
+ return Error("HTTPS connection failed", self.logger, exc=exc_info(),
detail={
"url": self.url.geturl(),
"timeout": self.timeout,
@@ -264,7 +267,7 @@ class Client(object):
data = json.dumps(payload)
except:
return Error("Serialization to JSON failed", self.logger,
- method=func, detail=payload)
+ exc=exc_info(), method=func, detail=payload)
self.headers = {
"Content-Type": "application/json",
@@ -286,7 +289,7 @@ class Client(object):
self.conn.request("POST", loc, data, self.headers)
except:
return Error("Sending of request to server failed", self.logger,
- method=func, detail={
+ exc=exc_info(), method=func, detail={
"loc": loc,
"headers": self.headers,
"data": data})
@@ -294,19 +297,19 @@ class Client(object):
try:
res = self.conn.getresponse()
except:
- return Error("HTTP reply failed", self.logger, method=func)
+ return Error("HTTP reply failed", self.logger, method=func, exc=exc_info())
try:
response_data = res.read()
except:
- return Error("Fetching HTTP data from server failed", self.logger, method=func)
+ return Error("Fetching HTTP data from server failed", self.logger, method=func, exc=exc_info())
if res.status==httplib.OK:
try:
data = json.loads(response_data)
except:
data = Error("JSON message parsing failed", self.logger,
- method=func, detail={"response": response_data})
+ exc=exc_info(), method=func, detail={"response": response_data})
else:
try:
data = json.loads(response_data)
@@ -315,11 +318,13 @@ class Client(object):
data = Error("Generic server HTTP error", self.logger,
method=func,
error=res.status,
+ exc=exc_info(),
detail={"response": response_data})
else:
data = Error(data.get("message", None), self.logger,
method=data.get("method", None),
error=res.status,
+ req_id=data.get("req_id", None),
detail=data.get("detail", None))
return data
@@ -334,7 +339,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", detail={"idstore": idf})
+ Error("Writing id file \"%s\" failed" % idf, self.logger,
+ prio="info", exc=exc_info(), detail={"idstore": idf})
return id
@@ -346,7 +352,8 @@ 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", detail={"idstore": idf})
+ Error("Reading id file \"%s\" failed, relying on server" % idf,
+ self.logger, prio="info", exc=exc_info(), detail={"idstore": idf})
id = None
return id
@@ -383,7 +390,8 @@ class Client(object):
events = res["events"]
newid = res["lastid"]
except KeyError:
- return Error("Server returned bogus reply", self.logger, method="getEvents", detail={"response": res})
+ return Error("Server returned bogus reply", self.logger,
+ method="getEvents", exc=exc_info(), detail={"response": res})
self._saveID(newid)
diff --git a/warden3/warden_client/warden_curl_test.sh b/warden3/warden_client/warden_curl_test.sh
index f00f478..95af2e5 100755
--- a/warden3/warden_client/warden_curl_test.sh
+++ b/warden3/warden_client/warden_curl_test.sh
@@ -43,6 +43,26 @@ curl \
$url/getEvents
echo
+echo "Test Called with unknown category"
+curl \
+ --key $keyfile \
+ --cert $certfile \
+ --cacert $cafile \
+ --connect-timeout 3 \
+ --request POST \
+ $url/getEvents?cat=bflm
+echo
+
+echo "Test Called with both cat and nocat"
+curl \
+ --key $keyfile \
+ --cert $certfile \
+ --cacert $cafile \
+ --connect-timeout 3 \
+ --request POST \
+ "$url/getEvents?cat=Other&nocat=Test"
+echo
+
echo "Test Invalid data for getEvents - silently discarded"
curl \
--key $keyfile \
diff --git a/warden3/warden_server/warden_server.py b/warden3/warden_server/warden_server.py
index 64e6224..5caa694 100755
--- a/warden3/warden_server/warden_server.py
+++ b/warden3/warden_server/warden_server.py
@@ -33,14 +33,15 @@ VERSION = "3.0-not-even-alpha"
class Error(Exception):
- def __init__(self, message, error=500, method=None,
- detail=None, exc=(None, None, None)):
+ def __init__(self, message, error=500, exc=None,
+ method=None, req_id=None, detail=None):
+ self.message = message
self.error = int(error)
+ (self.exctype, self.excval, self.exctb) = exc or (None, None, None)
+ self.cause = self.excval # compatibility with other exceptions
self.method = method
- self.message = message
+ self.req_id = req_id
self.detail = detail
- (self.exctype, self.excval, self.exctb) = exc or sys.exc_info()
- self.cause = self.excval # compatibility with other exceptions
def __str__(self):
@@ -78,6 +79,8 @@ class Error(Exception):
d["message"] = self.message
if self.detail is not None:
d["detail"] = self.detail
+ if self.req_id is not None:
+ d["req_id"] = self.req_id
return d
@@ -118,6 +121,10 @@ def StreamLogger(stream=sys.stderr, level=logging.INFO):
class LogRequestFilter(logging.Filter):
+ """ Filter class, instance of which is added to logger class to add
+ info about request automatically into every logline, no matter
+ how it came into existence.
+ """
def __init__(self, req):
logging.Filter.__init__(self)
@@ -125,9 +132,10 @@ class LogRequestFilter(logging.Filter):
def filter(self, record):
- record.req_preamble = ""
if self.req.env:
record.req_preamble = "%8x/%s: " % (self.req.req_id or 0, self.req.path)
+ else:
+ record.req_preamble = ""
return True
@@ -201,6 +209,11 @@ class Request(Object):
self.req_id = 0 if env is None else randint(0x00000000, 0xFFFFFFFF)
+ def error(self, message, error=500, exc=None, detail=None):
+ return Error(message, error, exc, self.path, self.req_id, detail=detail)
+
+
+
class ObjectReq(Object):
@@ -421,8 +434,8 @@ class MySQL(ObjectReq):
try:
mapped_id = section[v]
except KeyError:
- raise Error("Wrong tag or category used in query.", 422, method='getEvents',
- exc=sys.exc_info(), detail={"key": v})
+ raise self.req.error("Wrong tag or category used in query.", 422,
+ sys.exc_info(), detail={"key": v})
if mapped_id % 100:
variables_id.append(mapped_id)
@@ -443,14 +456,14 @@ class MySQL(ObjectReq):
logging.debug("fetch_events: id=%i, count=%i, cat=%s, nocat=%s, tag=%s, notag=%s, group=%s, nogroup=%s" % (id, count, str(cat), str(nocat), str(tag), str(notag), str(group), str(nogroup)))
if cat and nocat:
- raise Error("Unrealizable conditions. Choose cat or nocat option.", 422, method='getEvents',
- exc=sys.exc_info(), detail={'cat': cat, 'nocat' : nocat})
+ raise self.req.error("Unrealizable conditions. Choose cat or nocat option.", 422,
+ detail={'cat': cat, 'nocat' : nocat})
if tag and notag:
- raise Error("Unrealizable conditions. Choose tag or notag option.", 422, method='getEvents',
- exc=sys.exc_info(), detail={'tag': cat, 'notag' : nocat})
+ raise self.req.error("Unrealizable conditions. Choose tag or notag option.", 422,
+ detail={'tag': cat, 'notag' : nocat})
if group and nogroup:
- raise Error("Unrealizable conditions. Choose group or nogroup option.", 422, method='getEvents',
- exc=sys.exc_info(), detail={'tag': cat, 'notag' : nocat})
+ raise self.req.error("Unrealizable conditions. Choose group or nogroup option.", 422,
+ detail={'tag': cat, 'notag' : nocat})
sqlwhere = []
sqlparams = []
@@ -603,23 +616,23 @@ class Server(ObjectReq):
try:
injson = environ['wsgi.input'].read()
except:
- raise Error("Data read error.", 408, method=path, exc=sys.exc_info())
+ raise self.req.error("Data read error.", 408, sys.exc_info())
try:
method = getattr(self.handler, path)
method.exposed # dummy access to trigger AttributeError
except Exception:
- raise Error("You've fallen of the cliff.", 404, method=path)
+ raise self.req.error("You've fallen of the cliff.", 404)
self.req.client = client = self.auth.authenticate(environ)
if not client:
- raise Error("I'm watching. Authenticate.", 403, method=path)
+ raise self.req.error("I'm watching. Authenticate.", 403)
try:
events = json.loads(injson) if injson else None
- except Exception:
- raise Error("Deserialization error", 400, method=path,
- exc=sys.exc_info(), detail={"args": injson})
+ except Exception as e:
+ raise self.req.error("Deserialization error", 400,
+ sys.exc_info(), detail={"args": injson, "parser": str(e)})
args = parse_qs(environ.get('QUERY_STRING', ""))
logging.debug("calling handler with %s" % str(args))
@@ -634,13 +647,13 @@ class Server(ObjectReq):
# which could (although shouldn't) appear in handler code
output = json.dumps(result, default=lambda v: str(v))
except Exception as e:
- raise Error("Serialization error", 500, method=path,
- exc=sys.exc_info(), detail={"args": str(result)})
+ raise self.req.error("Serialization error", 500,
+ sys.exc_info(), detail={"args": str(result)})
except Error as e:
exception = e
except Exception as e:
- exception = Error("Server exception", 500, method=path, exc=sys.exc_info())
+ exception = self.req.error("Server exception", 500, sys.exc_info())
if exception:
status = "%d %s" % (exception.error, exception.message)
@@ -695,7 +708,7 @@ class WardenHandler(ObjectReq):
def getDebug(self):
auth = self.auth.authorize(self.req.env, self.req.client, self.req.path, None)
if not auth:
- raise Error("I'm watching. Authorize.", 403, method='getDebug', detail={"client": self.req.client})
+ raise self.req.error("I'm watching. Authorize.", 403, detail={"client": self.req.client["hostname"]})
return {
"environment": self.req.env,
@@ -722,7 +735,7 @@ class WardenHandler(ObjectReq):
def getInfo(self):
auth = self.auth.authorize(self.req.env, self.req.client, self.req.path, None)
if not auth:
- raise Error("I'm watching. Authorize.", 403, method='getDebug', detail={"client": self.req.client})
+ raise self.req.error("I'm watching. Authorize.", 403, detail={"client": self.req.client["hostname"]})
info = {
"version": VERSION,
@@ -742,7 +755,7 @@ class WardenHandler(ObjectReq):
auth = self.auth.authorize(self.req.env, self.req.client, self.req.path, None)
if not auth:
- raise Error("I'm watching. Authorize.", 403, method='getDebug', detail={"client": self.req.client})
+ raise self.req.error("I'm watching. Authorize.", 403, detail={"client": self.req.client["hostname"]})
try:
id = int(id[0])
@@ -784,10 +797,10 @@ class WardenHandler(ObjectReq):
@expose
def sendEvents(self, events=[]):
if not isinstance(events, list):
- raise Error("List of events expected.", 400, method="sendEvents")
+ raise self.req.error("List of events expected.", 400)
if len(events)>self.send_events_limit:
- raise Error("Too much events in one batch.", 413, method="sendEvents",
+ raise self.req.error("Too much events in one batch.", 413,
detail={"limit": self.send_events_limit})
saved = 0
--
GitLab