Merge pull request #267 from knaperek/fix-logger-messages

Fix paramter passing in logging messages throughout the codebase
This commit is contained in:
Roland Hedberg
2015-10-15 21:29:36 +02:00
34 changed files with 442 additions and 447 deletions

View File

@@ -91,7 +91,7 @@ def dict2list_of_tuples(d):
class Service(object):
def __init__(self, environ, start_response, user=None):
self.environ = environ
logger.debug("ENVIRON: %s" % environ)
logger.debug("ENVIRON: %s", environ)
self.start_response = start_response
self.user = user
@@ -104,7 +104,7 @@ class Service(object):
def unpack_post(self):
_dict = parse_qs(get_post(self.environ))
logger.debug("unpack_post:: %s" % _dict)
logger.debug("unpack_post:: %s", _dict)
try:
return dict([(k, v[0]) for k, v in _dict.items()])
except Exception:
@@ -124,11 +124,11 @@ class Service(object):
_dict = self.unpack_post()
else:
_dict = None
logger.debug("_dict: %s" % _dict)
logger.debug("_dict: %s", _dict)
return _dict
def operation(self, saml_msg, binding):
logger.debug("_operation: %s" % saml_msg)
logger.debug("_operation: %s", saml_msg)
if not (saml_msg and 'SAMLRequest' in saml_msg):
resp = BadRequest('Error parsing request or no request')
return resp(self.environ, self.start_response)
@@ -210,7 +210,7 @@ class Service(object):
"""
logger.debug("- SOAP -")
_dict = self.unpack_soap()
logger.debug("_dict: %s" % _dict)
logger.debug("_dict: %s", _dict)
return self.operation(_dict, BINDING_SOAP)
def uri(self):
@@ -273,7 +273,7 @@ class SSO(Service):
logger.info("parsed OK")
_authn_req = self.req_info.message
logger.debug("%s" % _authn_req)
logger.debug("%s", _authn_req)
try:
self.binding_out, self.destination = IDP.pick_binding(
@@ -281,11 +281,11 @@ class SSO(Service):
bindings=self.response_bindings,
entity_id=_authn_req.issuer.text, request=_authn_req)
except Exception as err:
logger.error("Couldn't find receiver endpoint: %s" % err)
logger.error("Couldn't find receiver endpoint: %s", err)
raise
logger.debug("Binding: %s, destination: %s" % (self.binding_out,
self.destination))
logger.debug("Binding: %s, destination: %s", self.binding_out,
self.destination)
resp_args = {}
try:
@@ -313,18 +313,18 @@ class SSO(Service):
try:
resp_args, _resp = self.verify_request(query, binding_in)
except UnknownPrincipal as excp:
logger.error("UnknownPrincipal: %s" % (excp,))
logger.error("UnknownPrincipal: %s", excp)
resp = ServiceError("UnknownPrincipal: %s" % (excp,))
return resp(self.environ, self.start_response)
except UnsupportedBinding as excp:
logger.error("UnsupportedBinding: %s" % (excp,))
logger.error("UnsupportedBinding: %s", excp)
resp = ServiceError("UnsupportedBinding: %s" % (excp,))
return resp(self.environ, self.start_response)
if not _resp:
identity = USERS[self.user].copy()
# identity["eduPersonTargetedID"] = get_eptid(IDP, query, session)
logger.info("Identity: %s" % (identity,))
logger.info("Identity: %s", identity)
if REPOZE_ID_EQUIVALENT:
identity[REPOZE_ID_EQUIVALENT] = self.user
@@ -345,7 +345,7 @@ class SSO(Service):
resp = ServiceError("Exception: %s" % (excp,))
return resp(self.environ, self.start_response)
logger.info("AuthNResponse: %s" % _resp)
logger.info("AuthNResponse: %s", _resp)
if self.op_type == "ecp":
kwargs = {"soap_headers": [
ecp.Response(
@@ -357,12 +357,12 @@ class SSO(Service):
"%s" % _resp, self.destination,
relay_state, response=True, **kwargs)
logger.debug("HTTPargs: %s" % http_args)
logger.debug("HTTPargs: %s", http_args)
return self.response(self.binding_out, http_args)
@staticmethod
def _store_request(saml_msg):
logger.debug("_store_request: %s" % saml_msg)
logger.debug("_store_request: %s", saml_msg)
key = sha1(saml_msg["SAMLRequest"]).hexdigest()
# store the AuthnRequest
IDP.ticket[key] = saml_msg
@@ -508,7 +508,7 @@ def do_authentication(environ, start_response, authn_context, key,
if len(auth_info):
method, reference = auth_info[0]
logger.debug("Authn chosen: %s (ref=%s)" % (method, reference))
logger.debug("Authn chosen: %s (ref=%s)", method, reference)
return method(environ, start_response, reference, key, redirect_uri, headers)
else:
resp = Unauthorized("No usable authentication method")
@@ -546,7 +546,7 @@ def username_password_authn(environ, start_response, reference, key,
"authn_reference": reference,
"redirect_uri": redirect_uri
}
logger.info("do_authentication argv: %s" % argv)
logger.info("do_authentication argv: %s", argv)
return resp(environ, start_response, **argv)
@@ -562,7 +562,7 @@ def verify_username_and_password(dic):
def do_verify(environ, start_response, _):
query = parse_qs(get_post(environ))
logger.debug("do_verify: %s" % query)
logger.debug("do_verify: %s", query)
try:
_ok, user = verify_username_and_password(query)
@@ -576,13 +576,13 @@ def do_verify(environ, start_response, _):
uid = rndstr(24)
IDP.cache.uid2user[uid] = user
IDP.cache.user2uid[user] = uid
logger.debug("Register %s under '%s'" % (user, uid))
logger.debug("Register %s under '%s'", user, uid)
kaka = set_cookie("idpauthn", "/", uid, query["authn_reference"][0])
lox = "%s?id=%s&key=%s" % (query["redirect_uri"][0], uid,
query["key"][0])
logger.debug("Redirect => %s" % lox)
logger.debug("Redirect => %s", lox)
resp = Redirect(lox, headers=[kaka], content="text/html")
return resp(environ, start_response)
@@ -610,17 +610,17 @@ class SLO(Service):
logger.info("--- Single Log Out Service ---")
try:
logger.debug("req: '%s'" % request)
logger.debug("req: '%s'", request)
req_info = IDP.parse_logout_request(request, binding)
except Exception as exc:
logger.error("Bad request: %s" % exc)
logger.error("Bad request: %s", exc)
resp = BadRequest("%s" % exc)
return resp(self.environ, self.start_response)
msg = req_info.message
if msg.name_id:
lid = IDP.ident.find_local_id(msg.name_id)
logger.info("local identifier: %s" % lid)
logger.info("local identifier: %s", lid)
if lid in IDP.cache.user2uid:
uid = IDP.cache.user2uid[lid]
if uid in IDP.cache.uid2user:
@@ -630,8 +630,8 @@ class SLO(Service):
try:
IDP.session_db.remove_authn_statements(msg.name_id)
except KeyError as exc:
logger.error("Unknown session: %s" % exc)
resp = ServiceError("Unknown session: %s" % exc)
logger.error("Unknown session: %s", exc)
resp = ServiceError("Unknown session: %s", exc)
return resp(self.environ, self.start_response)
resp = IDP.create_logout_response(msg, [binding])
@@ -649,7 +649,7 @@ class SLO(Service):
hinfo = IDP.apply_binding(binding, "%s" % resp, destination,
relay_state, response=response)
except Exception as exc:
logger.error("ServiceError: %s" % exc)
logger.error("ServiceError: %s", exc)
resp = ServiceError("%s" % exc)
return resp(self.environ, self.start_response)
@@ -657,7 +657,7 @@ class SLO(Service):
delco = delete_cookie(self.environ, "idpauthn")
if delco:
hinfo["headers"].append(delco)
logger.info("Header: %s" % (hinfo["headers"],))
logger.info("Header: %s", (hinfo["headers"],))
if binding == BINDING_HTTP_REDIRECT:
for key, value in hinfo['headers']:
@@ -688,7 +688,7 @@ class NMI(Service):
request.name_id, request.new_id, request.new_encrypted_id,
request.terminate)
logger.debug("New NameID: %s" % name_id)
logger.debug("New NameID: %s", name_id)
_resp = IDP.create_manage_name_id_response(request)
@@ -718,12 +718,12 @@ class AIDR(Service):
hinfo = IDP.apply_binding(BINDING_URI, "%s" % assertion, response=True)
logger.debug("HINFO: %s" % hinfo)
logger.debug("HINFO: %s", hinfo)
resp = Response(hinfo["data"], headers=hinfo["headers"])
return resp(self.environ, self.start_response)
def operation(self, _dict, binding, **kwargs):
logger.debug("_operation: %s" % _dict)
logger.debug("_operation: %s", _dict)
if not _dict or "ID" not in _dict:
resp = BadRequest('Error parsing request or no request')
return resp(self.environ, self.start_response)
@@ -764,7 +764,7 @@ class AQS(Service):
_query.requested_authn_context,
_query.session_index)
logger.debug("response: %s" % msg)
logger.debug("response: %s", msg)
hinfo = IDP.apply_binding(BINDING_SOAP, "%s" % msg, "", "",
response=True)
@@ -787,7 +787,7 @@ class ATTR(Service):
name_id = _query.subject.name_id
uid = name_id.text
logger.debug("Local uid: %s" % uid)
logger.debug("Local uid: %s", uid)
identity = EXTRA[uid]
# Comes in over SOAP so only need to construct the response
@@ -795,7 +795,7 @@ class ATTR(Service):
msg = IDP.create_attribute_response(identity,
name_id=name_id, **args)
logger.debug("response: %s" % msg)
logger.debug("response: %s", msg)
hinfo = IDP.apply_binding(BINDING_SOAP, "%s" % msg, "", "",
response=True)
@@ -842,7 +842,7 @@ class NIM(Service):
# Cookie handling
# ----------------------------------------------------------------------------
def info_from_cookie(kaka):
logger.debug("KAKA: %s" % kaka)
logger.debug("KAKA: %s", kaka)
if kaka:
cookie_obj = SimpleCookie(kaka)
morsel = cookie_obj.get("idpauthn", None)
@@ -859,14 +859,14 @@ def info_from_cookie(kaka):
def delete_cookie(environ, name):
kaka = environ.get("HTTP_COOKIE", '')
logger.debug("delete KAKA: %s" % kaka)
logger.debug("delete KAKA: %s", kaka)
if kaka:
cookie_obj = SimpleCookie(kaka)
morsel = cookie_obj.get(name, None)
cookie = SimpleCookie()
cookie[name] = ""
cookie[name]['path'] = "/"
logger.debug("Expire: %s" % morsel)
logger.debug("Expire: %s", morsel)
cookie[name]["expires"] = _expiration("dawn")
return tuple(cookie.output().split(": ", 1))
return None
@@ -877,7 +877,7 @@ def set_cookie(name, _, *args):
cookie[name] = base64.b64encode(":".join(args))
cookie[name]['path'] = "/"
cookie[name]["expires"] = _expiration(5) # 5 minutes from now
logger.debug("Cookie expires: %s" % cookie[name]["expires"])
logger.debug("Cookie expires: %s", cookie[name]["expires"])
return tuple(cookie.output().split(": ", 1))
# ----------------------------------------------------------------------------
@@ -940,7 +940,7 @@ def metadata(environ, start_response):
start_response('200 OK', [('Content-Type', "text/xml")])
return metadata
except Exception as ex:
logger.error("An error occured while creating metadata:" + ex.message)
logger.error("An error occured while creating metadata: %s", ex.message)
return not_found(environ, start_response)
@@ -959,7 +959,7 @@ def staticfile(environ, start_response):
start_response('200 OK', [('Content-Type', "text/xml")])
return open(path, 'r').read()
except Exception as ex:
logger.error("An error occured while creating metadata:" + ex.message)
logger.error("An error occured while creating metadata: %s", ex.message)
return not_found(environ, start_response)
@@ -971,9 +971,9 @@ def application(environ, start_response):
the functions from above can access the url placeholders.
If nothing matches, call the `not_found` function.
:param environ: The HTTP application environment
:param start_response: The application to run when the handling of the
:param start_response: The application to run when the handling of the
request is done
:return: The response as a list of lines
"""
@@ -984,7 +984,7 @@ def application(environ, start_response):
return metadata(environ, start_response)
kaka = environ.get("HTTP_COOKIE", None)
logger.info("<application> PATH: %s" % path)
logger.info("<application> PATH: %s", path)
if kaka:
logger.info("= KAKA =")
@@ -994,7 +994,7 @@ def application(environ, start_response):
else:
try:
query = parse_qs(environ["QUERY_STRING"])
logger.debug("QUERY: %s" % query)
logger.debug("QUERY: %s", query)
user = IDP.cache.uid2user[query["id"][0]]
except KeyError:
user = None
@@ -1013,7 +1013,7 @@ def application(environ, start_response):
except IndexError:
environ['myapp.url_args'] = path
logger.debug("Callback: %s" % (callback,))
logger.debug("Callback: %s", callback)
if isinstance(callback, tuple):
cls = callback[0](environ, start_response, user)
func = getattr(cls, callback[1])

View File

@@ -88,7 +88,7 @@ def dict2list_of_tuples(d):
class Service(object):
def __init__(self, environ, start_response, user=None):
self.environ = environ
logger.debug("ENVIRON: %s" % environ)
logger.debug("ENVIRON: %s", environ)
self.start_response = start_response
self.user = user
@@ -101,7 +101,7 @@ class Service(object):
def unpack_post(self):
_dict = parse_qs(get_post(self.environ))
logger.debug("unpack_post:: %s" % _dict)
logger.debug("unpack_post:: %s", _dict)
try:
return dict([(k, v[0]) for k, v in _dict.items()])
except Exception:
@@ -121,11 +121,11 @@ class Service(object):
_dict = self.unpack_post()
else:
_dict = None
logger.debug("_dict: %s" % _dict)
logger.debug("_dict: %s", _dict)
return _dict
def operation(self, saml_msg, binding):
logger.debug("_operation: %s" % saml_msg)
logger.debug("_operation: %s", saml_msg)
if not saml_msg or not 'SAMLRequest' in saml_msg:
resp = BadRequest('Error parsing request or no request')
return resp(self.environ, self.start_response)
@@ -186,7 +186,7 @@ class Service(object):
"""
logger.debug("- SOAP -")
_dict = self.unpack_soap()
logger.debug("_dict: %s" % _dict)
logger.debug("_dict: %s", _dict)
return self.operation(_dict, BINDING_SOAP)
def uri(self):
@@ -246,7 +246,7 @@ class SSO(Service):
logger.info("parsed OK")
_authn_req = self.req_info.message
logger.debug("%s" % _authn_req)
logger.debug("%s", _authn_req)
try:
self.binding_out, self.destination = IDP.pick_binding(
@@ -254,11 +254,11 @@ class SSO(Service):
bindings=self.response_bindings,
entity_id=_authn_req.issuer.text)
except Exception as err:
logger.error("Couldn't find receiver endpoint: %s" % err)
logger.error("Couldn't find receiver endpoint: %s", err)
raise
logger.debug("Binding: %s, destination: %s" % (self.binding_out,
self.destination))
logger.debug("Binding: %s, destination: %s", self.binding_out,
self.destination)
resp_args = {}
try:
@@ -285,18 +285,18 @@ class SSO(Service):
try:
resp_args, _resp = self.verify_request(query, binding_in)
except UnknownPrincipal as excp:
logger.error("UnknownPrincipal: %s" % (excp,))
logger.error("UnknownPrincipal: %s", excp)
resp = ServiceError("UnknownPrincipal: %s" % (excp,))
return resp(self.environ, self.start_response)
except UnsupportedBinding as excp:
logger.error("UnsupportedBinding: %s" % (excp,))
logger.error("UnsupportedBinding: %s", excp)
resp = ServiceError("UnsupportedBinding: %s" % (excp,))
return resp(self.environ, self.start_response)
if not _resp:
identity = USERS[self.user].copy()
# identity["eduPersonTargetedID"] = get_eptid(IDP, query, session)
logger.info("Identity: %s" % (identity,))
logger.info("Identity: %s", identity)
if REPOZE_ID_EQUIVALENT:
identity[REPOZE_ID_EQUIVALENT] = self.user
@@ -317,7 +317,7 @@ class SSO(Service):
resp = ServiceError("Exception: %s" % (excp,))
return resp(self.environ, self.start_response)
logger.info("AuthNResponse: %s" % _resp)
logger.info("AuthNResponse: %s", _resp)
if self.op_type == "ecp":
kwargs = {"soap_headers": [
ecp.Response(
@@ -329,11 +329,11 @@ class SSO(Service):
"%s" % _resp, self.destination,
relay_state, response=True, **kwargs)
logger.debug("HTTPargs: %s" % http_args)
logger.debug("HTTPargs: %s", http_args)
return self.response(self.binding_out, http_args)
def _store_request(self, saml_msg):
logger.debug("_store_request: %s" % saml_msg)
logger.debug("_store_request: %s", saml_msg)
key = sha1(saml_msg["SAMLRequest"]).hexdigest()
# store the AuthnRequest
IDP.ticket[key] = saml_msg
@@ -468,7 +468,7 @@ def do_authentication(environ, start_response, authn_context, key,
if len(auth_info):
method, reference = auth_info[0]
logger.debug("Authn chosen: %s (ref=%s)" % (method, reference))
logger.debug("Authn chosen: %s (ref=%s)", method, reference)
return method(environ, start_response, reference, key, redirect_uri)
else:
resp = Unauthorized("No usable authentication method")
@@ -504,7 +504,7 @@ def username_password_authn(environ, start_response, reference, key,
"authn_reference": reference,
"redirect_uri": redirect_uri
}
logger.info("do_authentication argv: %s" % argv)
logger.info("do_authentication argv: %s", argv)
return resp(environ, start_response, **argv)
@@ -520,7 +520,7 @@ def verify_username_and_password(dic):
def do_verify(environ, start_response, _):
query = parse_qs(get_post(environ))
logger.debug("do_verify: %s" % query)
logger.debug("do_verify: %s", query)
try:
_ok, user = verify_username_and_password(query)
@@ -534,13 +534,13 @@ def do_verify(environ, start_response, _):
uid = rndstr(24)
IDP.cache.uid2user[uid] = user
IDP.cache.user2uid[user] = uid
logger.debug("Register %s under '%s'" % (user, uid))
logger.debug("Register %s under '%s'", user, uid)
kaka = set_cookie("idpauthn", "/", uid, query["authn_reference"][0])
lox = "%s?id=%s&key=%s" % (query["redirect_uri"][0], uid,
query["key"][0])
logger.debug("Redirect => %s" % lox)
logger.debug("Redirect => %s", lox)
resp = Redirect(lox, headers=[kaka], content="text/html")
return resp(environ, start_response)
@@ -568,17 +568,17 @@ class SLO(Service):
logger.info("--- Single Log Out Service ---")
try:
_, body = request.split("\n")
logger.debug("req: '%s'" % body)
logger.debug("req: '%s'", body)
req_info = IDP.parse_logout_request(body, binding)
except Exception as exc:
logger.error("Bad request: %s" % exc)
logger.error("Bad request: %s", exc)
resp = BadRequest("%s" % exc)
return resp(self.environ, self.start_response)
msg = req_info.message
if msg.name_id:
lid = IDP.ident.find_local_id(msg.name_id)
logger.info("local identifier: %s" % lid)
logger.info("local identifier: %s", lid)
if lid in IDP.cache.user2uid:
uid = IDP.cache.user2uid[lid]
if uid in IDP.cache.uid2user:
@@ -588,7 +588,7 @@ class SLO(Service):
try:
IDP.session_db.remove_authn_statements(msg.name_id)
except KeyError as exc:
logger.error("ServiceError: %s" % exc)
logger.error("ServiceError: %s", exc)
resp = ServiceError("%s" % exc)
return resp(self.environ, self.start_response)
@@ -597,7 +597,7 @@ class SLO(Service):
try:
hinfo = IDP.apply_binding(binding, "%s" % resp, "", relay_state)
except Exception as exc:
logger.error("ServiceError: %s" % exc)
logger.error("ServiceError: %s", exc)
resp = ServiceError("%s" % exc)
return resp(self.environ, self.start_response)
@@ -605,7 +605,7 @@ class SLO(Service):
delco = delete_cookie(self.environ, "idpauthn")
if delco:
hinfo["headers"].append(delco)
logger.info("Header: %s" % (hinfo["headers"],))
logger.info("Header: %s", (hinfo["headers"],))
resp = Response(hinfo["data"], headers=hinfo["headers"])
return resp(self.environ, self.start_response)
@@ -626,7 +626,7 @@ class NMI(Service):
request.name_id, request.new_id, request.new_encrypted_id,
request.terminate)
logger.debug("New NameID: %s" % name_id)
logger.debug("New NameID: %s", name_id)
_resp = IDP.create_manage_name_id_response(request)
@@ -656,12 +656,12 @@ class AIDR(Service):
hinfo = IDP.apply_binding(BINDING_URI, "%s" % assertion, response=True)
logger.debug("HINFO: %s" % hinfo)
logger.debug("HINFO: %s", hinfo)
resp = Response(hinfo["data"], headers=hinfo["headers"])
return resp(self.environ, self.start_response)
def operation(self, _dict, binding, **kwargs):
logger.debug("_operation: %s" % _dict)
logger.debug("_operation: %s", _dict)
if not _dict or "ID" not in _dict:
resp = BadRequest('Error parsing request or no request')
return resp(self.environ, self.start_response)
@@ -702,7 +702,7 @@ class AQS(Service):
_query.requested_authn_context,
_query.session_index)
logger.debug("response: %s" % msg)
logger.debug("response: %s", msg)
hinfo = IDP.apply_binding(BINDING_SOAP, "%s" % msg, "", "",
response=True)
@@ -725,7 +725,7 @@ class ATTR(Service):
name_id = _query.subject.name_id
uid = name_id.text
logger.debug("Local uid: %s" % uid)
logger.debug("Local uid: %s", uid)
identity = EXTRA[self.user]
# Comes in over SOAP so only need to construct the response
@@ -733,7 +733,7 @@ class ATTR(Service):
msg = IDP.create_attribute_response(identity,
name_id=name_id, **args)
logger.debug("response: %s" % msg)
logger.debug("response: %s", msg)
hinfo = IDP.apply_binding(BINDING_SOAP, "%s" % msg, "", "",
response=True)
@@ -780,7 +780,7 @@ class NIM(Service):
# Cookie handling
# ----------------------------------------------------------------------------
def info_from_cookie(kaka):
logger.debug("KAKA: %s" % kaka)
logger.debug("KAKA: %s", kaka)
if kaka:
cookie_obj = SimpleCookie(kaka)
morsel = cookie_obj.get("idpauthn", None)
@@ -797,14 +797,14 @@ def info_from_cookie(kaka):
def delete_cookie(environ, name):
kaka = environ.get("HTTP_COOKIE", '')
logger.debug("delete KAKA: %s" % kaka)
logger.debug("delete KAKA: %s", kaka)
if kaka:
cookie_obj = SimpleCookie(kaka)
morsel = cookie_obj.get(name, None)
cookie = SimpleCookie()
cookie[name] = ""
cookie[name]['path'] = "/"
logger.debug("Expire: %s" % morsel)
logger.debug("Expire: %s", morsel)
cookie[name]["expires"] = _expiration("dawn")
return tuple(cookie.output().split(": ", 1))
return None
@@ -815,7 +815,7 @@ def set_cookie(name, _, *args):
cookie[name] = base64.b64encode(":".join(args))
cookie[name]['path'] = "/"
cookie[name]["expires"] = _expiration(5) # 5 minutes from now
logger.debug("Cookie expires: %s" % cookie[name]["expires"])
logger.debug("Cookie expires: %s", cookie[name]["expires"])
return tuple(cookie.output().split(": ", 1))
# ----------------------------------------------------------------------------
@@ -878,7 +878,7 @@ def metadata(environ, start_response):
start_response('200 OK', [('Content-Type', "text/xml")])
return metadata
except Exception as ex:
logger.error("An error occured while creating metadata:" + ex.message)
logger.error("An error occured while creating metadata:", ex.message)
return not_found(environ, start_response)
@@ -897,7 +897,7 @@ def staticfile(environ, start_response):
start_response('200 OK', [('Content-Type', "text/xml")])
return open(path, 'r').read()
except Exception as ex:
logger.error("An error occured while creating metadata:" + ex.message)
logger.error("An error occured while creating metadata:", ex.message)
return not_found(environ, start_response)
@@ -909,9 +909,9 @@ def application(environ, start_response):
the functions from above can access the url placeholders.
If nothing matches, call the `not_found` function.
:param environ: The HTTP application environment
:param start_response: The application to run when the handling of the
:param start_response: The application to run when the handling of the
request is done
:return: The response as a list of lines
"""
@@ -922,7 +922,7 @@ def application(environ, start_response):
return metadata(environ, start_response)
kaka = environ.get("HTTP_COOKIE", None)
logger.info("<application> PATH: %s" % path)
logger.info("<application> PATH: %s", path)
if kaka:
logger.info("= KAKA =")
@@ -932,7 +932,7 @@ def application(environ, start_response):
else:
try:
query = parse_qs(environ["QUERY_STRING"])
logger.debug("QUERY: %s" % query)
logger.debug("QUERY: %s", query)
user = IDP.cache.uid2user[query["id"][0]]
except KeyError:
user = None
@@ -951,7 +951,7 @@ def application(environ, start_response):
except IndexError:
environ['myapp.url_args'] = path
logger.debug("Callback: %s" % (callback,))
logger.debug("Callback: %s", callback)
if isinstance(callback, tuple):
cls = callback[0](environ, start_response, user)
func = getattr(cls, callback[1])

View File

@@ -83,7 +83,7 @@ def dict2list_of_tuples(d):
class Service(object):
def __init__(self, environ, start_response, user=None):
self.environ = environ
logger.debug("ENVIRON: %s" % environ)
logger.debug("ENVIRON: %s", environ)
self.start_response = start_response
self.user = user
@@ -93,22 +93,22 @@ class Service(object):
return dict([(k, v[0]) for k, v in parse_qs(_qs).items()])
else:
return None
def unpack_post(self):
_dict = parse_qs(get_post(self.environ))
logger.debug("unpack_post:: %s" % _dict)
logger.debug("unpack_post:: %s", _dict)
try:
return dict([(k, v[0]) for k, v in _dict.items()])
except Exception:
return None
def unpack_soap(self):
try:
query = get_post(self.environ)
return {"SAMLRequest": query, "RelayState": ""}
except Exception:
return None
def unpack_either(self):
if self.environ["REQUEST_METHOD"] == "GET":
_dict = self.unpack_redirect()
@@ -116,11 +116,11 @@ class Service(object):
_dict = self.unpack_post()
else:
_dict = None
logger.debug("_dict: %s" % _dict)
logger.debug("_dict: %s", _dict)
return _dict
def operation(self, _dict, binding):
logger.debug("_operation: %s" % _dict)
logger.debug("_operation: %s", _dict)
if not _dict or not 'SAMLRequest' in _dict:
resp = BadRequest('Error parsing request or no request')
return resp(self.environ, self.start_response)
@@ -178,7 +178,7 @@ class Service(object):
"""
logger.debug("- SOAP -")
_dict = self.unpack_soap()
logger.debug("_dict: %s" % _dict)
logger.debug("_dict: %s", _dict)
return self.operation(_dict, BINDING_SOAP)
def uri(self):
@@ -196,8 +196,8 @@ class Service(object):
# "PATH_INFO"], "key": key})
# headers = [('Content-Type', 'text/plain')]
#
# logger.debug("location: %s" % loc)
# logger.debug("headers: %s" % headers)
# logger.debug("location: %s", loc)
# logger.debug("headers: %s", headers)
#
# resp = Redirect(loc, headers=headers)
#
@@ -255,15 +255,15 @@ class SSO(Service):
logger.info("parsed OK")
_authn_req = self.req_info.message
logger.debug("%s" % _authn_req)
logger.debug("%s", _authn_req)
self.binding_out, self.destination = IDP.pick_binding(
"assertion_consumer_service",
bindings=self.response_bindings,
entity_id=_authn_req.issuer.text)
logger.debug("Binding: %s, destination: %s" % (self.binding_out,
self.destination))
logger.debug("Binding: %s, destination: %s", self.binding_out,
self.destination)
resp_args = {}
try:
@@ -282,18 +282,18 @@ class SSO(Service):
try:
resp_args, _resp = self.verify_request(query, binding_in)
except UnknownPrincipal as excp:
logger.error("UnknownPrincipal: %s" % (excp,))
logger.error("UnknownPrincipal: %s", excp)
resp = ServiceError("UnknownPrincipal: %s" % (excp,))
return resp(self.environ, self.start_response)
except UnsupportedBinding as excp:
logger.error("UnsupportedBinding: %s" % (excp,))
logger.error("UnsupportedBinding: %s", excp)
resp = ServiceError("UnsupportedBinding: %s" % (excp,))
return resp(self.environ, self.start_response)
if not _resp:
identity = USERS[self.user].copy()
#identity["eduPersonTargetedID"] = get_eptid(IDP, query, session)
logger.info("Identity: %s" % (identity,))
logger.info("Identity: %s", identity)
if REPOZE_ID_EQUIVALENT:
identity[REPOZE_ID_EQUIVALENT] = self.user
@@ -310,15 +310,15 @@ class SSO(Service):
resp = ServiceError("Exception: %s" % (excp,))
return resp(self.environ, self.start_response)
logger.info("AuthNResponse: %s" % _resp)
logger.info("AuthNResponse: %s", _resp)
http_args = IDP.apply_binding(self.binding_out,
"%s" % _resp, self.destination,
relay_state, response=True)
logger.debug("HTTPargs: %s" % http_args)
logger.debug("HTTPargs: %s", http_args)
return self.response(self.binding_out, http_args)
def _store_request(self, _dict):
logger.debug("_store_request: %s" % _dict)
logger.debug("_store_request: %s", _dict)
key = sha1(_dict["SAMLRequest"]).hexdigest()
# store the AuthnRequest
IDP.ticket[key] = _dict
@@ -412,7 +412,7 @@ class SSO(Service):
except TypeError:
resp = Unauthorized()
else:
logger.debug("Authz_info: %s" % _info)
logger.debug("Authz_info: %s", _info)
try:
(user, passwd) = _info.split(":")
if is_equal(PASSWD[user], passwd):
@@ -448,7 +448,7 @@ def do_authentication(environ, start_response, authn_context, key,
if len(auth_info):
method, reference = auth_info[0]
logger.debug("Authn chosen: %s (ref=%s)" % (method, reference))
logger.debug("Authn chosen: %s (ref=%s)", method, reference)
return method(environ, start_response, reference, key, redirect_uri)
else:
resp = Unauthorized("No usable authentication method")
@@ -482,7 +482,7 @@ def username_password_authn(environ, start_response, reference, key,
"authn_reference": reference,
"redirect_uri": redirect_uri
}
logger.info("do_authentication argv: %s" % argv)
logger.info("do_authentication argv: %s", argv)
return resp(environ, start_response, **argv)
@@ -498,7 +498,7 @@ def verify_username_and_password(dic):
def do_verify(environ, start_response, _):
query = parse_qs(get_post(environ))
logger.debug("do_verify: %s" % query)
logger.debug("do_verify: %s", query)
try:
_ok, user = verify_username_and_password(query)
@@ -512,13 +512,13 @@ def do_verify(environ, start_response, _):
uid = rndstr(24)
IDP.cache.uid2user[uid] = user
IDP.cache.user2uid[user] = uid
logger.debug("Register %s under '%s'" % (user, uid))
logger.debug("Register %s under '%s'", user, uid)
kaka = set_cookie("idpauthn", "/", uid, query["authn_reference"][0])
lox = "%s?id=%s&key=%s" % (query["redirect_uri"][0], uid,
query["key"][0])
logger.debug("Redirect => %s" % lox)
logger.debug("Redirect => %s", lox)
resp = Redirect(lox, headers=[kaka], content="text/html")
return resp(environ, start_response)
@@ -546,17 +546,17 @@ class SLO(Service):
logger.info("--- Single Log Out Service ---")
try:
_, body = request.split("\n")
logger.debug("req: '%s'" % body)
logger.debug("req: '%s'", body)
req_info = IDP.parse_logout_request(body, binding)
except Exception as exc:
logger.error("Bad request: %s" % exc)
logger.error("Bad request: %s", exc)
resp = BadRequest("%s" % exc)
return resp(self.environ, self.start_response)
msg = req_info.message
if msg.name_id:
lid = IDP.ident.find_local_id(msg.name_id)
logger.info("local identifier: %s" % lid)
logger.info("local identifier: %s", lid)
if lid in IDP.cache.user2uid:
uid = IDP.cache.user2uid[lid]
if uid in IDP.cache.uid2user:
@@ -566,55 +566,55 @@ class SLO(Service):
try:
IDP.session_db.remove_authn_statements(msg.name_id)
except KeyError as exc:
logger.error("ServiceError: %s" % exc)
logger.error("ServiceError: %s", exc)
resp = ServiceError("%s" % exc)
return resp(self.environ, self.start_response)
resp = IDP.create_logout_response(msg, [binding])
try:
hinfo = IDP.apply_binding(binding, "%s" % resp, "", relay_state)
except Exception as exc:
logger.error("ServiceError: %s" % exc)
logger.error("ServiceError: %s", exc)
resp = ServiceError("%s" % exc)
return resp(self.environ, self.start_response)
#_tlh = dict2list_of_tuples(hinfo["headers"])
delco = delete_cookie(self.environ, "idpauthn")
if delco:
hinfo["headers"].append(delco)
logger.info("Header: %s" % (hinfo["headers"],))
logger.info("Header: %s", hinfo["headers"])
resp = Response(hinfo["data"], headers=hinfo["headers"])
return resp(self.environ, self.start_response)
# ----------------------------------------------------------------------------
# Manage Name ID service
# ----------------------------------------------------------------------------
class NMI(Service):
def do(self, query, binding, relay_state=""):
logger.info("--- Manage Name ID Service ---")
req = IDP.parse_manage_name_id_request(query, binding)
request = req.message
# Do the necessary stuff
name_id = IDP.ident.handle_manage_name_id_request(
request.name_id, request.new_id, request.new_encrypted_id,
request.terminate)
logger.debug("New NameID: %s" % name_id)
logger.debug("New NameID: %s", name_id)
_resp = IDP.create_manage_name_id_response(request)
# It's using SOAP binding
hinfo = IDP.apply_binding(BINDING_SOAP, "%s" % _resp, "",
relay_state, response=True)
resp = Response(hinfo["data"], headers=hinfo["headers"])
return resp(self.environ, self.start_response)
# ----------------------------------------------------------------------------
# === Assertion ID request ===
# ----------------------------------------------------------------------------
@@ -630,15 +630,15 @@ class AIDR(Service):
except Unknown:
resp = NotFound(aid)
return resp(self.environ, self.start_response)
hinfo = IDP.apply_binding(BINDING_URI, "%s" % assertion, response=True)
logger.debug("HINFO: %s" % hinfo)
logger.debug("HINFO: %s", hinfo)
resp = Response(hinfo["data"], headers=hinfo["headers"])
return resp(self.environ, self.start_response)
def operation(self, _dict, binding, **kwargs):
logger.debug("_operation: %s" % _dict)
logger.debug("_operation: %s", _dict)
if not _dict or "ID" not in _dict:
resp = BadRequest('Error parsing request or no request')
return resp(self.environ, self.start_response)
@@ -678,7 +678,7 @@ class AQS(Service):
_query.requested_authn_context,
_query.session_index)
logger.debug("response: %s" % msg)
logger.debug("response: %s", msg)
hinfo = IDP.apply_binding(BINDING_SOAP, "%s" % msg, "", "",
response=True)
@@ -701,7 +701,7 @@ class ATTR(Service):
name_id = _query.subject.name_id
uid = name_id.text
logger.debug("Local uid: %s" % uid)
logger.debug("Local uid: %s", uid)
identity = EXTRA[uid]
# Comes in over SOAP so only need to construct the response
@@ -709,7 +709,7 @@ class ATTR(Service):
msg = IDP.create_attribute_response(identity,
name_id=name_id, **args)
logger.debug("response: %s" % msg)
logger.debug("response: %s", msg)
hinfo = IDP.apply_binding(BINDING_SOAP, "%s" % msg, "", "",
response=True)
@@ -739,23 +739,23 @@ class NIM(Service):
except PolicyError:
resp = BadRequest("Unknown entity")
return resp(self.environ, self.start_response)
info = IDP.response_args(request)
_resp = IDP.create_name_id_mapping_response(name_id, **info)
# Only SOAP
hinfo = IDP.apply_binding(BINDING_SOAP, "%s" % _resp, "", "",
response=True)
resp = Response(hinfo["data"], headers=hinfo["headers"])
return resp(self.environ, self.start_response)
# ----------------------------------------------------------------------------
# Cookie handling
# ----------------------------------------------------------------------------
def info_from_cookie(kaka):
logger.debug("KAKA: %s" % kaka)
logger.debug("KAKA: %s", kaka)
if kaka:
cookie_obj = SimpleCookie(kaka)
morsel = cookie_obj.get("idpauthn", None)
@@ -772,14 +772,14 @@ def info_from_cookie(kaka):
def delete_cookie(environ, name):
kaka = environ.get("HTTP_COOKIE", '')
logger.debug("delete KAKA: %s" % kaka)
logger.debug("delete KAKA: %s", kaka)
if kaka:
cookie_obj = SimpleCookie(kaka)
morsel = cookie_obj.get(name, None)
cookie = SimpleCookie()
cookie[name] = ""
cookie[name]['path'] = "/"
logger.debug("Expire: %s" % morsel)
logger.debug("Expire: %s", morsel)
cookie[name]["expires"] = _expiration("dawn")
return tuple(cookie.output().split(": ", 1))
return None
@@ -790,7 +790,7 @@ def set_cookie(name, _, *args):
cookie[name] = base64.b64encode(":".join(args))
cookie[name]['path'] = "/"
cookie[name]["expires"] = _expiration(5) # 5 minutes from now
logger.debug("Cookie expires: %s" % cookie[name]["expires"])
logger.debug("Cookie expires: %s", cookie[name]["expires"])
return tuple(cookie.output().split(": ", 1))
# ----------------------------------------------------------------------------
@@ -853,7 +853,7 @@ def metadata(environ, start_response):
start_response('200 OK', [('Content-Type', "text/xml")])
return metadata
except Exception as ex:
logger.error("An error occured while creating metadata:" + ex.message)
logger.error("An error occured while creating metadata: %s", ex.message)
return not_found(environ, start_response)
def staticfile(environ, start_response):
@@ -867,7 +867,7 @@ def staticfile(environ, start_response):
start_response('200 OK', [('Content-Type', "text/xml")])
return open(path, 'r').read()
except Exception as ex:
logger.error("An error occured while creating metadata:" + ex.message)
logger.error("An error occured while creating metadata: %s", ex.message)
return not_found(environ, start_response)
def application(environ, start_response):
@@ -878,9 +878,9 @@ def application(environ, start_response):
the functions from above can access the url placeholders.
If nothing matches, call the `not_found` function.
:param environ: The HTTP application environment
:param start_response: The application to run when the handling of the
:param start_response: The application to run when the handling of the
request is done
:return: The response as a list of lines
"""
@@ -891,7 +891,7 @@ def application(environ, start_response):
return metadata(environ, start_response)
kaka = environ.get("HTTP_COOKIE", None)
logger.info("<application> PATH: %s" % path)
logger.info("<application> PATH: %s", path)
if kaka:
logger.info("= KAKA =")
@@ -900,7 +900,7 @@ def application(environ, start_response):
else:
try:
query = parse_qs(environ["QUERY_STRING"])
logger.debug("QUERY: %s" % query)
logger.debug("QUERY: %s", query)
user = IDP.cache.uid2user[query["id"][0]]
except KeyError:
user = None
@@ -919,7 +919,7 @@ def application(environ, start_response):
except IndexError:
environ['myapp.url_args'] = path
logger.debug("Callback: %s" % (callback,))
logger.debug("Callback: %s", (callback,))
if isinstance(callback, tuple):
cls = callback[0](environ, start_response, user)
func = getattr(cls, callback[1])

View File

@@ -37,7 +37,7 @@ def dict_to_table(ava, lev=0, width=1):
txt.append("<td>%s</td>\n" % valarr)
elif isinstance(valarr, list):
i = 0
n = len(valarr)
n = len(valarr)
for val in valarr:
if not i:
txt.append("<th rowspan=%d>%s</td>\n" % (len(valarr), prop))
@@ -105,7 +105,7 @@ def whoami(environ, start_response, user):
response.extend("<a href='logout'>Logout</a>")
resp = Response(response)
return resp(environ, start_response)
#noinspection PyUnusedLocal
def not_found(environ, start_response):
@@ -128,7 +128,7 @@ def slo(environ, start_response, user):
if "QUERY_STRING" in environ:
query = parse_qs(environ["QUERY_STRING"])
logger.info("query: %s" % query)
logger.info("query: %s", query)
try:
response = sc.parse_logout_request_response(
query["SAMLResponse"][0], binding=BINDING_HTTP_REDIRECT)
@@ -147,19 +147,19 @@ def slo(environ, start_response, user):
headers.append(delco)
resp = Redirect("/done", headers=headers)
return resp(environ, start_response)
#noinspection PyUnusedLocal
def logout(environ, start_response, user):
# This is where it starts when a user wants to log out
client = environ['repoze.who.plugins']["saml2auth"]
subject_id = environ["repoze.who.identity"]['repoze.who.userid']
logger.info("[logout] subject_id: '%s'" % (subject_id,))
logger.info("[logout] subject_id: '%s'", subject_id)
target = "/done"
# What if more than one
_dict = client.saml_client.global_logout(subject_id)
logger.info("[logout] global_logout > %s" % (_dict,))
logger.info("[logout] global_logout > %s", _dict)
rem = environ['repoze.who.plugins'][client.rememberer_name]
rem.forget(environ, subject_id)
@@ -180,15 +180,15 @@ def logout(environ, start_response, user):
#noinspection PyUnusedLocal
def done(environ, start_response, user):
# remove cookie and stored info
logger.info("[done] environ: %s" % environ)
logger.info("[done] environ: %s", environ)
subject_id = environ["repoze.who.identity"]['repoze.who.userid']
client = environ['repoze.who.plugins']["saml2auth"]
logger.info("[logout done] remaining subjects: %s" % (
client.saml_client.users.subjects(),))
logger.info("[logout done] remaining subjects: %s",
client.saml_client.users.subjects())
start_response('200 OK', [('Content-Type', 'text/html')])
return ["<h3>You are now logged out from this service</h3>"]
# ----------------------------------------------------------------------------
# map urls to functions
@@ -215,7 +215,7 @@ def metadata(environ, start_response):
start_response('200 OK', [('Content-Type', "text/xml")])
return metadata
except Exception as ex:
logger.error("An error occured while creating metadata:" + ex.message)
logger.error("An error occured while creating metadata: %s", ex.message)
return not_found(environ, start_response)
def application(environ, start_response):
@@ -226,14 +226,14 @@ def application(environ, start_response):
the functions from above can access the url placeholders.
If nothing matches, call the `not_found` function.
:param environ: The HTTP application environment
:param start_response: The application to run when the handling of the
:param start_response: The application to run when the handling of the
request is done
:return: The response as a list of lines
"""
path = environ.get('PATH_INFO', '').lstrip('/')
logger.info("<application> PATH: %s" % path)
logger.info("<application> PATH: %s", path)
if path == "metadata":
return metadata(environ, start_response)
@@ -241,9 +241,9 @@ def application(environ, start_response):
user = environ.get("REMOTE_USER", "")
if not user:
user = environ.get("repoze.who.identity", "")
logger.info("repoze.who.identity: '%s'" % user)
logger.info("repoze.who.identity: '%s'", user)
else:
logger.info("REMOTE_USER: '%s'" % user)
logger.info("REMOTE_USER: '%s'", user)
#logger.info(logging.Logger.manager.loggerDict)
for regex, callback in urls:
if user:

View File

@@ -168,7 +168,7 @@ class Cache(object):
def get_user(self, environ):
cookie = environ.get("HTTP_COOKIE", '')
cookie = cookie.decode("UTF-8")
logger.debug("Cookie: %s" % cookie)
logger.debug("Cookie: %s", cookie)
if cookie:
cookie_obj = SimpleCookie(cookie)
morsel = cookie_obj.get(self.cookie_name, None)
@@ -184,7 +184,7 @@ class Cache(object):
def delete_cookie(self, environ):
cookie = environ.get("HTTP_COOKIE", '')
logger.debug("delete cookie: %s" % cookie)
logger.debug("delete cookie: %s", cookie)
if cookie:
_name = self.cookie_name
cookie_obj = SimpleCookie(cookie)
@@ -192,7 +192,7 @@ class Cache(object):
cookie = SimpleCookie()
cookie[_name] = ""
cookie[_name]['path'] = "/"
logger.debug("Expire: %s" % morsel)
logger.debug("Expire: %s", morsel)
cookie[_name]["expires"] = _expiration("now")
return cookie.output().split(": ", 1)
return None
@@ -204,7 +204,7 @@ class Cache(object):
cookie[self.cookie_name] = uid
cookie[self.cookie_name]['path'] = "/"
cookie[self.cookie_name]["expires"] = _expiration(480)
logger.debug("Cookie expires: %s" % cookie[self.cookie_name]["expires"])
logger.debug("Cookie expires: %s", cookie[self.cookie_name]["expires"])
return cookie.output().encode("UTF-8").split(": ", 1)
@@ -216,11 +216,11 @@ class Cache(object):
class Service(object):
def __init__(self, environ, start_response, user=None):
self.environ = environ
logger.debug("ENVIRON: %s" % environ)
logger.debug("ENVIRON: %s", environ)
self.start_response = start_response
self.user = user
self.sp = None
def unpack_redirect(self):
if "QUERY_STRING" in self.environ:
_qs = self.environ["QUERY_STRING"]
@@ -230,7 +230,7 @@ class Service(object):
def unpack_post(self):
_dict = parse_qs(get_post(self.environ))
logger.debug("unpack_post:: %s" % _dict)
logger.debug("unpack_post:: %s", _dict)
try:
return dict([(k, v[0]) for k, v in _dict.items()])
except Exception:
@@ -250,11 +250,11 @@ class Service(object):
_dict = self.unpack_post()
else:
_dict = None
logger.debug("_dict: %s" % _dict)
logger.debug("_dict: %s", _dict)
return _dict
def operation(self, _dict, binding):
logger.debug("_operation: %s" % _dict)
logger.debug("_operation: %s", _dict)
if not _dict:
resp = BadRequest('Error parsing request or no request')
return resp(self.environ, self.start_response)
@@ -312,7 +312,7 @@ class Service(object):
"""
logger.debug("- SOAP -")
_dict = self.unpack_soap()
logger.debug("_dict: %s" % _dict)
logger.debug("_dict: %s", _dict)
return self.operation(_dict, BINDING_SOAP)
def uri(self):
@@ -359,11 +359,11 @@ class ACS(Service):
self.response = self.sp.parse_authn_request_response(
response, binding, self.outstanding_queries, self.cache.outstanding_certs)
except UnknownPrincipal as excp:
logger.error("UnknownPrincipal: %s" % (excp,))
logger.error("UnknownPrincipal: %s", excp)
resp = ServiceError("UnknownPrincipal: %s" % (excp,))
return resp(self.environ, self.start_response)
except UnsupportedBinding as excp:
logger.error("UnsupportedBinding: %s" % (excp,))
logger.error("UnsupportedBinding: %s", excp)
resp = ServiceError("UnsupportedBinding: %s" % (excp,))
return resp(self.environ, self.start_response)
except VerificationError as err:
@@ -373,7 +373,7 @@ class ACS(Service):
resp = ServiceError("Other error: %s" % (err,))
return resp(self.environ, self.start_response)
logger.info("AVA: %s" % self.response.ava)
logger.info("AVA: %s", self.response.ava)
user = User(self.response.name_id, self.response.ava)
cookie = self.cache.set_cookie(user)
@@ -384,7 +384,7 @@ class ACS(Service):
return resp(self.environ, self.start_response)
def verify_attributes(self, ava):
logger.info("SP: %s" % self.sp.config.entityid)
logger.info("SP: %s", self.sp.config.entityid)
rest = POLICY.get_entity_categories(
self.sp.config.entityid, self.sp.metadata)
@@ -446,7 +446,7 @@ class SSO(object):
def _wayf_redirect(self, came_from):
sid_ = sid()
self.cache.outstanding_queries[sid_] = came_from
logger.debug("Redirect to WAYF function: %s" % self.wayf)
logger.debug("Redirect to WAYF function: %s", self.wayf)
return -1, SeeOther(headers=[('Location', "%s?%s" % (self.wayf, sid_))])
def _pick_idp(self, came_from):
@@ -457,7 +457,7 @@ class SSO(object):
_cli = self.sp
logger.debug("[_pick_idp] %s" % self.environ)
logger.debug("[_pick_idp] %s", self.environ)
if "HTTP_PAOS" in self.environ:
if self.environ["HTTP_PAOS"] == PAOS_HEADER_INFO:
if 'application/vnd.paos+xml' in self.environ["HTTP_ACCEPT"]:
@@ -474,7 +474,7 @@ class SSO(object):
if not _entityid:
return -1, ServiceError("No IdP to talk to")
logger.debug("IdP to talk to: %s" % _entityid)
logger.debug("IdP to talk to: %s", _entityid)
return ecp.ecp_auth_request(_cli, _entityid, _rstate)
else:
return -1, ServiceError('Faulty Accept header')
@@ -504,7 +504,7 @@ class SSO(object):
if _idp_entity_id in idps:
idp_entity_id = _idp_entity_id
except KeyError:
logger.debug("No IdP entity ID in query: %s" % query)
logger.debug("No IdP entity ID in query: %s", query)
pass
if not idp_entity_id:
@@ -542,7 +542,7 @@ class SSO(object):
else:
return -1, NotImplemented("No WAYF or DS present!")
logger.info("Chosen IdP: '%s'" % idp_entity_id)
logger.info("Chosen IdP: '%s'", idp_entity_id)
return 0, idp_entity_id
def redirect_to_auth(self, _cli, entity_id, came_from, sigalg=""):
@@ -551,8 +551,8 @@ class SSO(object):
_binding, destination = _cli.pick_binding(
"single_sign_on_service", self.bindings, "idpsso",
entity_id=entity_id)
logger.debug("binding: %s, destination: %s" % (_binding,
destination))
logger.debug("binding: %s, destination: %s", _binding,
destination)
# Binding here is the response binding that is which binding the
# IDP should use to return the response.
acs = _cli.config.getattr("endpoints", "sp")[
@@ -601,14 +601,14 @@ class SSO(object):
# Which page was accessed to get here
came_from = geturl(self.environ)
logger.debug("[sp.challenge] RelayState >> '%s'" % came_from)
logger.debug("[sp.challenge] RelayState >> '%s'", came_from)
# If more than one idp and if none is selected, I have to do wayf
(done, response) = self._pick_idp(came_from)
# Three cases: -1 something went wrong or Discovery service used
# 0 I've got an IdP to send a request to
# >0 ECP in progress
logger.debug("_idp_pick returned: %s" % done)
logger.debug("_idp_pick returned: %s", done)
if done == -1:
return response(self.environ, self.start_response)
elif done > 0:
@@ -686,11 +686,11 @@ def logout(environ, start_response, sp):
sso = SSO(sp, environ, start_response, cache=CACHE, **ARGS)
return sso.do()
logger.info("[logout] subject_id: '%s'" % (user.name_id,))
logger.info("[logout] subject_id: '%s'", user.name_id)
# What if more than one
data = sp.global_logout(user.name_id)
logger.info("[logout] global_logout > %s" % data)
logger.info("[logout] global_logout > %s", data)
for entity_id, logout_info in data.items():
if isinstance(logout_info, tuple):
@@ -718,8 +718,8 @@ def logout(environ, start_response, sp):
def finish_logout(environ, start_response):
logger.info("[logout done] environ: %s" % environ)
logger.info("[logout done] remaining subjects: %s" % CACHE.uid2user.values())
logger.info("[logout done] environ: %s", environ)
logger.info("[logout done] remaining subjects: %s", CACHE.uid2user.values())
# remove cookie and stored info
cookie = CACHE.delete_cookie(environ)
@@ -771,7 +771,7 @@ def metadata(environ, start_response):
start_response('200 OK', [('Content-Type', "text/xml")])
return metadata
except Exception as ex:
logger.error("An error occured while creating metadata:" + ex.message)
logger.error("An error occured while creating metadata: %s", ex.message)
return not_found(environ, start_response)
def application(environ, start_response):
@@ -780,14 +780,14 @@ def application(environ, start_response):
the functions from above.
If nothing matches, call the `not_found` function.
:param environ: The HTTP application environment
:param start_response: The application to run when the handling of the
:param start_response: The application to run when the handling of the
request is done
:return: The response as a list of lines
"""
path = environ.get('PATH_INFO', '').lstrip('/')
logger.debug("<application> PATH: '%s'" % path)
logger.debug("<application> PATH: '%s'", path)
if path == "metadata":
return metadata(environ, start_response)

View File

@@ -115,18 +115,18 @@ class Conversation(tool.Conversation):
if use_artifact:
saml_art = _client.use_artifact(str_req, self.args["entity_id"])
logger.info("SAML Artifact: %s" % saml_art)
logger.info("SAML Artifact: %s", saml_art)
info_typ = "SAMLart"
else:
logger.info("SAML Request: %s" % str_req)
logger.info("SAML Request: %s", str_req)
info_typ = "SAMLRequest"
# depending on binding send the query
if self.args["request_binding"] is BINDING_SOAP:
res = _client.send_using_soap(str_req, loc)
if res.status_code >= 400:
logger.info("Received a HTTP error (%d) '%s'" % (
res.status_code, res.text))
logger.info("Received a HTTP error (%d) '%s'",
res.status_code, res.text)
raise HTTPError(res.text)
else:
self.response_args["binding"] = BINDING_SOAP
@@ -156,8 +156,8 @@ class Conversation(tool.Conversation):
res = None
if res is not None and res.status_code >= 400:
logger.info("Received a HTTP error (%d) '%s'" % (
res.status_code, res.text))
logger.info("Received a HTTP error (%d) '%s'",
res.status_code, res.text)
raise HTTPError(res.text)
self.last_response = res
@@ -240,11 +240,11 @@ class Conversation(tool.Conversation):
self.test_sequence(self.oper.tests["post"])
except KeyError:
pass
logger.info("SAML Response: %s" % _resp)
logger.info("SAML Response: %s", _resp)
except FatalError as ferr:
if _resp:
logger.info("Faulty response: %s" % _resp)
logger.error("Exception %s" % ferr)
logger.info("Faulty response: %s", _resp)
logger.error("Exception %s", ferr)
raise
except ElementTree.ParseError:
return False
@@ -252,8 +252,8 @@ class Conversation(tool.Conversation):
raise
except Exception as err:
if _resp:
logger.info("Faulty response: %s" % _resp)
logger.error("Exception %s" % err)
logger.info("Faulty response: %s", _resp)
logger.error("Exception %s", err)
self.err_check("exception", err)
return True
return True

View File

@@ -548,7 +548,7 @@ class VerifyAttributeNameFormat(Check):
try:
assert attr.name_format == conv.msg_constraints[
"name_format"]
logger.debug("Attribute name format valid: " +
logger.debug("Attribute name format valid: %s",
attr.name_format)
except AssertionError:
if NAME_FORMAT_UNSPECIFIED != conv.msg_constraints[

View File

@@ -380,8 +380,8 @@ class Operation(object):
_args["location"] = location
_args["features"] = features
logger.info("--> FUNCTION: %s" % self.function.__name__)
logger.info("--> ARGS: %s" % _args)
logger.info("--> FUNCTION: %s", self.function.__name__)
logger.info("--> ARGS: %s", _args)
result = self.function(httpc, response, **_args)
self.post_op(result, conv, _args)

View File

@@ -356,7 +356,7 @@ class Policy(object):
_are[key.lower()] = [re.compile(value) for value in values]
spec["attribute_restrictions"] = _are
logger.debug("policy restrictions: %s" % self._restrictions)
logger.debug("policy restrictions: %s", self._restrictions)
return self._restrictions
@@ -486,7 +486,7 @@ class Policy(object):
_ava = None
if required or optional:
logger.debug("required: %s, optional: %s" % (required, optional))
logger.debug("required: %s, optional: %s", required, optional)
_ava = filter_on_attributes(
ava.copy(), required, optional, self.acs,
self.get_fail_on_missing_requested(sp_entity_id))

View File

@@ -133,8 +133,8 @@ def to_local(acs, statement, allow_unknown_attributes=False):
allow_unknown_attributes:
_func = acs[0].lcd_ava_from
else:
logger.info("Unsupported attribute name format: %s" % (
attr.name_format,))
logger.info("Unsupported attribute name format: %s",
attr.name_format)
continue
try:
@@ -143,7 +143,7 @@ def to_local(acs, statement, allow_unknown_attributes=False):
if allow_unknown_attributes:
key, val = acs[0].lcd_ava_from(attr)
else:
logger.info("Unknown attribute name: %s" % (attr,))
logger.info("Unknown attribute name: %s", attr)
continue
except AttributeError:
continue
@@ -180,8 +180,8 @@ def list_to_local(acs, attrlist, allow_unknown_attributes=False):
allow_unknown_attributes:
_func = acs[0].lcd_ava_from
else:
logger.info("Unsupported attribute name format: %s" % (
attr.name_format,))
logger.info("Unsupported attribute name format: %s",
attr.name_format)
continue
try:
@@ -190,7 +190,7 @@ def list_to_local(acs, attrlist, allow_unknown_attributes=False):
if allow_unknown_attributes:
key, val = acs[0].lcd_ava_from(attr)
else:
logger.info("Unknown attribute name: %s" % (attr,))
logger.info("Unknown attribute name: %s", attr)
continue
except AttributeError:
continue

View File

@@ -37,7 +37,7 @@ class AttributeResolver(object):
for ass in self.metadata.attribute_consuming_service(member):
for attr_serv in ass.attribute_service:
logger.info(
"Send attribute request to %s" % attr_serv.location)
"Send attribute request to %s", attr_serv.location)
if attr_serv.binding != BINDING_SOAP:
continue
# attribute query assumes SOAP binding

View File

@@ -111,7 +111,7 @@ class Saml2Client(Base):
continue
destination = self._sso_location(entityid, binding)
logger.info("destination to provider: %s" % destination)
logger.info("destination to provider: %s", destination)
reqid, request = self.create_authn_request(
destination, vorg, scoping, response_binding, nameid_format,
@@ -120,7 +120,7 @@ class Saml2Client(Base):
_req_str = str(request)
logger.info("AuthNReq: %s" % _req_str)
logger.info("AuthNReq: %s", _req_str)
try:
sigalg = kwargs["sigalg"]
@@ -156,7 +156,7 @@ class Saml2Client(Base):
if isinstance(name_id, six.string_types):
name_id = decode(name_id)
logger.info("logout request for: %s" % name_id)
logger.info("logout request for: %s", name_id)
# find out which IdPs/AAs I should notify
entity_ids = self.users.issuers_of_info(name_id)
@@ -187,7 +187,7 @@ class Saml2Client(Base):
responses = {}
for entity_id in entity_ids:
logger.debug("Logout from '%s'" % entity_id)
logger.debug("Logout from '%s'", entity_id)
# for all where I can use the SOAP binding, do those first
for binding in [BINDING_SOAP, BINDING_HTTP_POST,
BINDING_HTTP_REDIRECT]:
@@ -201,11 +201,11 @@ class Saml2Client(Base):
srvs = None
if not srvs:
logger.debug("No SLO '%s' service" % binding)
logger.debug("No SLO '%s' service", binding)
continue
destination = destinations(srvs)[0]
logger.info("destination to provider: %s" % destination)
logger.info("destination to provider: %s", destination)
try:
session_info = self.users.get_info_from(name_id, entity_id)
session_indexes = [session_info['session_index']]
@@ -246,12 +246,12 @@ class Saml2Client(Base):
if response and response.status_code == 200:
not_done.remove(entity_id)
response = response.text
logger.info("Response: %s" % response)
logger.info("Response: %s", response)
res = self.parse_logout_request_response(response,
binding)
responses[entity_id] = res
else:
logger.info("NOT OK response from %s" % destination)
logger.info("NOT OK response from %s", destination)
else:
self.state[req_id] = {"entity_id": entity_id,
@@ -298,11 +298,11 @@ class Saml2Client(Base):
response message, response headers and message)
"""
logger.info("state: %s" % (self.state,))
logger.info("state: %s", self.state)
status = self.state[response.in_response_to]
logger.info("status: %s" % (status,))
logger.info("status: %s", status)
issuer = response.issuer()
logger.info("issuer: %s" % issuer)
logger.info("issuer: %s", issuer)
del self.state[response.in_response_to]
if status["entity_ids"] == [issuer]: # done
self.local_logout(decode(status["name_id"]))
@@ -343,10 +343,10 @@ class Saml2Client(Base):
if response:
# not_done.remove(entity_id)
logger.info("OK response from %s" % destination)
logger.info("OK response from %s", destination)
return response
else:
logger.info("NOT OK response from %s" % destination)
logger.info("NOT OK response from %s", destination)
return None
@@ -497,7 +497,7 @@ class Saml2Client(Base):
'method': "POST
}
"""
logger.info("logout request: %s" % request)
logger.info("logout request: %s", request)
_req = self._parse_request(request, LogoutRequest,
"single_logout_service", binding)

View File

@@ -140,7 +140,7 @@ class Base(Entity):
if srvs:
return destinations(srvs)[0]
else:
logger.info("_sso_location: %s, %s" % (entityid, binding))
logger.info("_sso_location: %s, %s", entityid, binding)
raise IdpUnspecified("No IdP to send to given the premises")
# get the idp location from the metadata. If there is more than one
@@ -580,12 +580,12 @@ class Base(Entity):
"assertion_consumer_service",
binding, **kwargs)
except StatusError as err:
logger.error("SAML status error: %s" % err)
logger.error("SAML status error: %s", err)
raise
except UnravelError:
return None
except Exception as err:
logger.error("XML parse error: %s" % err)
logger.error("XML parse error: %s", err)
raise
if resp is None:
@@ -596,8 +596,7 @@ class Base(Entity):
logger.info("--- ADDED person info ----")
pass
else:
logger.error("Response type not supported: %s" % (
saml2.class_name(resp),))
logger.error("Response type not supported: %s", saml2.class_name(resp))
return resp
# ------------------------------------------------------------------------
@@ -701,7 +700,7 @@ class Base(Entity):
_binding = BINDING_SOAP
kwargs["binding"] = _binding
logger.debug("entityid: %s, binding: %s" % (entityid, _binding))
logger.debug("entityid: %s, binding: %s", entityid, _binding)
# The IDP publishes support for ECP by using the SOAP binding on
# SingleSignOnService

View File

@@ -74,7 +74,7 @@ class Client(Entity):
if metadata_file:
self._metadata = MetadataStore([saml, samlp], None, config)
self._metadata.load("local", metadata_file)
logger.debug("Loaded metadata from '%s'" % metadata_file)
logger.debug("Loaded metadata from '%s'", metadata_file)
else:
self._metadata = None
@@ -109,12 +109,12 @@ class Client(Entity):
if headers:
ht_args["headers"].extend(headers)
logger.debug("[P2] Sending request: %s" % ht_args["data"])
logger.debug("[P2] Sending request: %s", ht_args["data"])
# POST the request to the IdP
response = self.send(**ht_args)
logger.debug("[P2] Got IdP response: %s" % response)
logger.debug("[P2] Got IdP response: %s", response)
if response.status_code != 200:
raise SAMLError(
@@ -127,12 +127,12 @@ class Client(Entity):
if respdict is None:
raise SAMLError("Unexpected reply from the IdP")
logger.debug("[P2] IdP response dict: %s" % respdict)
logger.debug("[P2] IdP response dict: %s", respdict)
idp_response = respdict["body"]
assert idp_response.c_tag == "Response"
logger.debug("[P2] IdP AUTHN response: %s" % idp_response)
logger.debug("[P2] IdP AUTHN response: %s", idp_response)
_ecp_response = None
for item in respdict["header"]:
@@ -155,7 +155,7 @@ class Client(Entity):
if respdict is None:
raise SAMLError("Unexpected reply from the SP")
logger.debug("[P1] SP response dict: %s" % respdict)
logger.debug("[P1] SP response dict: %s", respdict)
# AuthnRequest in the body or not
authn_request = respdict["body"]
@@ -201,7 +201,7 @@ class Client(Entity):
ht_args = self.use_soap(idp_response, args["rc_url"],
[args["relay_state"]])
logger.debug("[P3] Post to SP: %s" % ht_args["data"])
logger.debug("[P3] Post to SP: %s", ht_args["data"])
ht_args["headers"].append(('Content-Type', 'application/vnd.paos+xml'))
@@ -217,7 +217,7 @@ class Client(Entity):
raise SAMLError(
"Error POSTing package to SP: %s" % response.error)
logger.debug("[P3] SP response: %s" % response.text)
logger.debug("[P3] SP response: %s", response.text)
self.done_ecp = True
logger.debug("Done ECP")
@@ -266,7 +266,7 @@ class Client(Entity):
opargs["headers"] = self.add_paos_headers(opargs["headers"])
response = self.send(url, op, **opargs)
logger.debug("[Op] SP response: %s" % response)
logger.debug("[Op] SP response: %s", response)
if response.status_code != 200:
raise SAMLError(

View File

@@ -109,7 +109,7 @@ def create_artifact(entity_id, message_handle, endpoint_index=0):
if not isinstance(message_handle, six.binary_type):
message_handle = message_handle.encode('utf-8')
ter = b"".join((ARTIFACT_TYPECODE,
ter = b"".join((ARTIFACT_TYPECODE,
("%.2x" % endpoint_index).encode('ascii'),
sourceid.digest(),
message_handle))
@@ -283,11 +283,10 @@ class Entity(HTTPBase):
except UnsupportedBinding:
pass
logger.error("Failed to find consumer URL: %s, %s, %s" % (entity_id,
bindings,
descr_type))
#logger.error("Bindings: %s" % bindings)
#logger.error("Entities: %s" % self.metadata)
logger.error("Failed to find consumer URL: %s, %s, %s",
entity_id, bindings, descr_type)
#logger.error("Bindings: %s", bindings)
#logger.error("Entities: %s", self.metadata)
raise SAMLError("Unknown entity or unsupported bindings")
@@ -363,7 +362,7 @@ class Entity(HTTPBase):
:param msgtype:
:return:
"""
#logger.debug("unravel '%s'" % txt)
#logger.debug("unravel '%s'", txt)
if binding not in [BINDING_HTTP_REDIRECT, BINDING_HTTP_POST,
BINDING_SOAP, BINDING_URI, BINDING_HTTP_ARTIFACT,
None]:
@@ -424,7 +423,7 @@ class Entity(HTTPBase):
except (AttributeError, TypeError):
to_sign = [(class_name(msg), mid)]
logger.info("REQUEST: %s" % msg)
logger.info("REQUEST: %s", msg)
return signed_instance_factory(msg, self.sec, to_sign)
def _message(self, request_cls, destination=None, message_id=0,
@@ -470,7 +469,7 @@ class Entity(HTTPBase):
if sign:
return reqid, self.sign(req, sign_prepare=sign_prepare)
else:
logger.info("REQUEST: %s" % req)
logger.info("REQUEST: %s", req)
return reqid, req
@staticmethod
@@ -758,8 +757,8 @@ class Entity(HTTPBase):
if receiver_addresses:
break
_log_debug("receiver addresses: %s" % receiver_addresses)
_log_debug("Binding: %s" % binding)
_log_debug("receiver addresses: %s", receiver_addresses)
_log_debug("Binding: %s", binding)
try:
timeslack = self.config.accepted_time_diff
@@ -888,7 +887,7 @@ class Entity(HTTPBase):
response = self._status_response(samlp.LogoutResponse, issuer, status,
sign, **rinfo)
logger.info("Response: %s" % (response,))
logger.info("Response: %s", response)
return response
@@ -925,7 +924,7 @@ class Entity(HTTPBase):
msg = element_to_extension_element(self.artifact[artifact])
response.extension_elements = [msg]
logger.info("Response: %s" % (response,))
logger.info("Response: %s", response)
return response
@@ -993,7 +992,7 @@ class Entity(HTTPBase):
response = self._status_response(samlp.ManageNameIDResponse, issuer,
status, sign, **rinfo)
logger.info("Response: %s" % (response,))
logger.info("Response: %s", response)
return response
@@ -1044,7 +1043,7 @@ class Entity(HTTPBase):
try:
response = response_cls(self.sec, **kwargs)
except Exception as exc:
logger.info("%s" % exc)
logger.info("%s", exc)
raise
xmlstr = self.unravel(xmlstr, binding, response_cls.msgtype)
@@ -1055,7 +1054,7 @@ class Entity(HTTPBase):
try:
response = response.loads(xmlstr, False, origxml=origxml)
except SigverError as err:
logger.error("Signature Error: %s" % err)
logger.error("Signature Error: %s", err)
raise
except UnsolicitedResponse:
logger.error("Unsolicited response")
@@ -1065,7 +1064,7 @@ class Entity(HTTPBase):
logger.error("Not well-formed XML")
raise
logger.debug("XMLSTR: %s" % xmlstr)
logger.debug("XMLSTR: %s", xmlstr)
if response:
keys = None

View File

@@ -151,7 +151,7 @@ class HTTPBase(object):
part = urlparse(request.url)
_domain = part.hostname
logger.debug("%s: '%s'" % (_domain, kaka))
logger.debug("%s: '%s'", _domain, kaka)
for cookie_name, morsel in kaka.items():
std_attr = ATTRS.copy()
@@ -228,14 +228,14 @@ class HTTPBase(object):
_kwargs["headers"] = dict(_kwargs["headers"])
try:
logger.debug("%s to %s" % (method, url))
logger.debug("%s to %s", method, url)
for arg in ["cookies", "data", "auth"]:
try:
logger.debug("%s: %s" % (arg.upper(), _kwargs[arg]))
logger.debug("%s: %s", arg.upper(), _kwargs[arg])
except KeyError:
pass
r = requests.request(method, url, **_kwargs)
logger.debug("Response status: %s" % r.status_code)
logger.debug("Response status: %s", r.status_code)
except requests.ConnectionError as exc:
raise ConnectionError("%s" % exc)
@@ -325,7 +325,7 @@ class HTTPBase(object):
soap_message = make_soap_enveloped_saml_thingy(request, soap_headers)
logger.debug("SOAP message: %s" % soap_message)
logger.debug("SOAP message: %s", soap_message)
if sign and self.sec:
_signed = self.sec.sign_statement(soap_message,
@@ -353,11 +353,11 @@ class HTTPBase(object):
args["headers"] = dict(args["headers"])
response = self.send(**args)
except Exception as exc:
logger.info("HTTPClient exception: %s" % (exc,))
logger.info("HTTPClient exception: %s", exc)
raise
if response.status_code == 200:
logger.info("SOAP response: %s" % response.text)
logger.info("SOAP response: %s", response.text)
return response
else:
raise HTTPError("%d:%s" % (response.status_code, response.content))

View File

@@ -184,7 +184,7 @@ class IdentDB(object):
try:
_vals = self.db[userid]
except KeyError:
logger.debug("failed to find userid %s in IdentDB" % userid)
logger.debug("failed to find userid %s in IdentDB", userid)
return res
for val in _vals.split(" "):
@@ -211,8 +211,8 @@ class IdentDB(object):
:return:
"""
logger.debug("local_policy: %s, name_id_policy: %s" % (local_policy,
name_id_policy))
logger.debug("local_policy: %s, name_id_policy: %s", local_policy,
name_id_policy)
if name_id_policy and name_id_policy.sp_name_qualifier:
sp_name_qualifier = name_id_policy.sp_name_qualifier
@@ -280,8 +280,8 @@ class IdentDB(object):
try:
return self.db[name_id.text]
except KeyError:
logger.debug("name: %s" % name_id.text)
#logger.debug("id sub keys: %s" % self.subkeys())
logger.debug("name: %s", name_id.text)
#logger.debug("id sub keys: %s", self.subkeys())
return None
def match_local_id(self, userid, sp_name_qualifier, name_qualifier):

View File

@@ -330,7 +330,7 @@ class InMemoryMetaData(MetaData):
self.filter = kwargs["filter"]
except KeyError:
self.filter = None
def items(self):
return self.entity.items()
@@ -359,15 +359,15 @@ class InMemoryMetaData(MetaData):
if self.check_validity:
try:
if not valid(entity_descr.valid_until):
logger.error("Entity descriptor (entity id:%s) to old" % (
entity_descr.entity_id,))
logger.error("Entity descriptor (entity id:%s) to old",
entity_descr.entity_id)
return
except AttributeError:
pass
# have I seen this entity_id before ? If so if log: ignore it
if entity_descr.entity_id in self.entity:
print("Duplicated Entity descriptor (entity id: '%s')" %
print("Duplicated Entity descriptor (entity id: '%s')" %
entity_descr.entity_id, file=sys.stderr)
return
@@ -416,7 +416,7 @@ class InMemoryMetaData(MetaData):
try:
valid_instance(self.entities_descr)
except NotValid as exc:
logger.error(exc.args[0])
logger.error("Invalid XML message: %s", exc.args[0])
return
if self.check_validity:
@@ -467,7 +467,7 @@ class InMemoryMetaData(MetaData):
res[srv["binding"]].append(srv)
except KeyError:
res[srv["binding"]] = [srv]
logger.debug("service => %s" % res)
logger.debug("service => %s", res)
return res
def attribute_requirement(self, entity_id, index=None):
@@ -677,7 +677,7 @@ class MetaDataExtern(InMemoryMetaData):
_txt = response.text.encode("utf-8")
return self.parse_and_check_signature(_txt)
else:
logger.info("Response status: %s" % response.status_code)
logger.info("Response status: %s", response.status_code)
return False
@@ -741,7 +741,7 @@ class MetaDataMDX(InMemoryMetaData):
if self.parse_and_check_signature(_txt):
return self.entity[item]
else:
logger.info("Response status: %s" % response.status_code)
logger.info("Response status: %s", response.status_code)
raise KeyError
@@ -878,8 +878,8 @@ class MetadataStore(object):
def service(self, entity_id, typ, service, binding=None):
known_entity = False
logger.debug("service(%s, %s, %s, %s)" % (entity_id, typ, service,
binding))
logger.debug("service(%s, %s, %s, %s)", entity_id, typ, service,
binding)
for key, _md in self.metadata.items():
srvs = _md.service(entity_id, typ, service, binding)
if srvs:
@@ -890,10 +890,10 @@ class MetadataStore(object):
known_entity = True
if known_entity:
logger.error("Unsupported binding: %s (%s)" % (binding, entity_id))
logger.error("Unsupported binding: %s (%s)", binding, entity_id)
raise UnsupportedBinding(binding)
else:
logger.error("Unknown system entity: %s" % entity_id)
logger.error("Unknown system entity: %s", entity_id)
raise UnknownSystemEntity(entity_id)
def ext_service(self, entity_id, typ, service, binding=None):

View File

@@ -113,7 +113,7 @@ class SessionStorageMDB(object):
return result
def remove_authn_statements(self, name_id):
logger.debug("remove authn about: %s" % name_id)
logger.debug("remove authn about: %s", name_id)
key = sha1(code_binary(name_id)).hexdigest()
for item in self.assertion.find({"name_id_key": key}):
self.assertion.remove(item["_id"])

View File

@@ -169,18 +169,18 @@ def make_soap_enveloped_saml_thingy(thingy, header_parts=None):
if isinstance(thingy, six.string_types):
# remove the first XML version/encoding line
if thingy[0:5].lower() == '<?xml':
logger.debug("thingy0: %s" % thingy)
logger.debug("thingy0: %s", thingy)
_part = thingy.split("\n")
thingy = "".join(_part[1:])
thingy = thingy.replace(PREFIX, "")
logger.debug("thingy: %s" % thingy)
logger.debug("thingy: %s", thingy)
_child = ElementTree.Element('')
_child.tag = '{%s}FuddleMuddle' % DUMMY_NAMESPACE
body.append(_child)
_str = ElementTree.tostring(envelope, encoding="UTF-8")
if isinstance(_str, six.binary_type):
_str = _str.decode('utf-8')
logger.debug("SOAP precursor: %s" % _str)
logger.debug("SOAP precursor: %s", _str)
# find an remove the namespace definition
i = _str.find(DUMMY_NAMESPACE)
j = _str.rfind("xmlns:", 0, i)

View File

@@ -43,7 +43,7 @@ class Request(object):
# own copy
self.xmlstr = xmldata[:]
logger.debug("xmlstr: %s" % (self.xmlstr,))
logger.debug("xmlstr: %s", self.xmlstr)
try:
self.message = self.signature_check(xmldata, origdoc=origdoc,
must=must,
@@ -55,15 +55,15 @@ class Request(object):
if not self.message:
logger.error("Response was not correctly signed")
logger.info(xmldata)
logger.info("Response: %s", xmldata)
raise IncorrectlySigned()
logger.info("request: %s" % (self.message,))
logger.info("request: %s", self.message)
try:
valid_instance(self.message)
except NotValid as exc:
logger.error("Not valid request: %s" % exc.args[0])
logger.error("Not valid request: %s", exc.args[0])
raise
return self
@@ -83,8 +83,8 @@ class Request(object):
assert self.message.version == "2.0"
if self.message.destination and self.receiver_addrs and \
self.message.destination not in self.receiver_addrs:
logger.error("%s not in %s" % (self.message.destination,
self.receiver_addrs))
logger.error("%s not in %s", self.message.destination,
self.receiver_addrs)
raise OtherError("Not destined for me!")
assert self.issue_instant_ok()

View File

@@ -277,15 +277,15 @@ class StatusResponse(object):
if not self.response:
logger.error("Response was not correctly signed")
if self.xmlstr:
logger.info(self.xmlstr)
logger.info("Response: %s", self.xmlstr)
raise IncorrectlySigned()
logger.debug("response: %s" % (self.response,))
logger.debug("response: %s", self.response)
try:
valid_instance(self.response)
except NotValid as exc:
logger.error("Not valid response: %s" % exc.args[0])
logger.error("Not valid response: %s", exc.args[0])
self._clear()
return self
@@ -311,7 +311,7 @@ class StatusResponse(object):
# own copy
self.xmlstr = xmldata[:]
logger.debug("xmlstr: %s" % (self.xmlstr,))
logger.debug("xmlstr: %s", self.xmlstr)
if origxml:
self.origxml = origxml
else:
@@ -343,9 +343,9 @@ class StatusResponse(object):
def status_ok(self):
if self.response.status:
status = self.response.status
logger.info("status: %s" % (status,))
logger.info("status: %s", status)
if status.status_code.value != samlp.STATUS_SUCCESS:
logger.info("Not successful operation: %s" % status)
logger.info("Not successful operation: %s", status)
if status.status_code.status_code:
excep = STATUSCODE2EXCEPTION[
status.status_code.status_code.value]
@@ -376,8 +376,8 @@ class StatusResponse(object):
def _verify(self):
if self.request_id and self.in_response_to and \
self.in_response_to != self.request_id:
logger.error("Not the id I expected: %s != %s" % (
self.in_response_to, self.request_id))
logger.error("Not the id I expected: %s != %s",
self.in_response_to, self.request_id)
return None
try:
@@ -392,8 +392,8 @@ class StatusResponse(object):
if self.asynchop:
if self.response.destination and \
self.response.destination not in self.return_addrs:
logger.error("%s not in %s" % (self.response.destination,
self.return_addrs))
logger.error("%s not in %s", self.response.destination,
self.return_addrs)
return None
assert self.issue_instant_ok()
@@ -563,7 +563,7 @@ class AuthnResponse(StatusResponse):
assert self.assertion.conditions
conditions = self.assertion.conditions
logger.debug("conditions: %s" % conditions)
logger.debug("conditions: %s", conditions)
# if no sub-elements or elements are supplied, then the
# assertion is considered to be valid.
@@ -583,7 +583,7 @@ class AuthnResponse(StatusResponse):
if conditions.not_before:
validate_before(conditions.not_before, self.timeslack)
except Exception as excp:
logger.error("Exception on conditions: %s" % (excp,))
logger.error("Exception on conditions: %s", excp)
if not lax:
raise
else:
@@ -631,9 +631,9 @@ class AuthnResponse(StatusResponse):
attribute_statement.attribute.extend(attrlist)
def read_attribute_statement(self, attr_statem):
logger.debug("Attribute Statement: %s" % (attr_statem,))
logger.debug("Attribute Statement: %s", attr_statem)
for aconv in self.attribute_converters:
logger.debug("Converts name format: %s" % (aconv.name_format,))
logger.debug("Converts name format: %s", aconv.name_format)
self.decrypt_attributes(attr_statem)
return to_local(self.attribute_converters, attr_statem,
@@ -688,9 +688,9 @@ class AuthnResponse(StatusResponse):
# This is where I don't allow unsolicited reponses
# Either in_response_to == None or has a value I don't
# recognize
logger.debug("in response to: '%s'" % data.in_response_to)
logger.info("outstanding queries: %s" % (
self.outstanding_queries.keys(),))
logger.debug("in response to: '%s'", data.in_response_to)
logger.info("outstanding queries: %s",
self.outstanding_queries.keys())
raise Exception(
"Combination of session id and requestURI I don't "
"recall")
@@ -750,7 +750,7 @@ class AuthnResponse(StatusResponse):
else:
raise VerificationError("Missing NameID")
logger.info("Subject NameID: %s" % self.name_id)
logger.info("Subject NameID: %s", self.name_id)
return self.name_id
def _assertion(self, assertion, verified=False):
@@ -770,13 +770,13 @@ class AuthnResponse(StatusResponse):
try:
self.sec.check_signature(assertion, class_name(assertion),self.xmlstr)
except Exception as exc:
logger.error("correctly_signed_response: %s" % exc)
logger.error("correctly_signed_response: %s", exc)
raise
self.assertion = assertion
logger.debug("assertion context: %s" % (self.context,))
logger.debug("assertion keys: %s" % (assertion.keyswv()))
logger.debug("outstanding_queries: %s" % (self.outstanding_queries,))
logger.debug("assertion context: %s", self.context)
logger.debug("assertion keys: %s", assertion.keyswv())
logger.debug("outstanding_queries: %s", self.outstanding_queries)
#if self.context == "AuthnReq" or self.context == "AttrQuery":
if self.context == "AuthnReq":
@@ -791,7 +791,7 @@ class AuthnResponse(StatusResponse):
#if self.context == "AuthnReq" or self.context == "AttrQuery":
# self.ava = self.get_identity()
# logger.debug("--- AVA: %s" % (self.ava,))
# logger.debug("--- AVA: %s", self.ava)
try:
self.get_subject()
@@ -824,7 +824,7 @@ class AuthnResponse(StatusResponse):
if not self.sec.check_signature(
assertion, origdoc=decr_txt,
node_name=class_name(assertion), issuer=issuer):
logger.error("Failed to verify signature on '%s'" % assertion)
logger.error("Failed to verify signature on '%s'", assertion)
raise SignatureError()
res.append(assertion)
return res
@@ -957,7 +957,7 @@ class AuthnResponse(StatusResponse):
if self.context == "AuthnReq" or self.context == "AttrQuery":
self.ava = self.get_identity()
logger.debug("--- AVA: %s" % (self.ava,))
logger.debug("--- AVA: %s", self.ava)
return True
@@ -970,7 +970,7 @@ class AuthnResponse(StatusResponse):
try:
res = self._verify()
except AssertionError as err:
logger.error("Verification error on the response: %s" % err)
logger.error("Verification error on the response: %s", err)
raise
else:
if res is None:
@@ -1197,7 +1197,7 @@ class AssertionIDResponse(object):
def loads(self, xmldata, decode=True, origxml=None):
# own copy
self.xmlstr = xmldata[:]
logger.debug("xmlstr: %s" % (self.xmlstr,))
logger.debug("xmlstr: %s", self.xmlstr)
self.origxml = origxml
try:
@@ -1219,7 +1219,7 @@ class AssertionIDResponse(object):
try:
valid_instance(self.response)
except NotValid as exc:
logger.error("Not valid response: %s" % exc.args[0])
logger.error("Not valid response: %s", exc.args[0])
raise
return self
@@ -1227,10 +1227,10 @@ class AssertionIDResponse(object):
if not self.response:
logger.error("Response was not correctly signed")
if self.xmlstr:
logger.info(self.xmlstr)
logger.info("Response: %s", self.xmlstr)
raise IncorrectlySigned()
logger.debug("response: %s" % (self.response,))
logger.debug("response: %s", self.response)
return self

View File

@@ -45,7 +45,7 @@ class FormHiddenPlugin(FormPlugin):
def identify(self, environ):
logger = environ.get('repoze.who.logger','')
logger.info("formplugin identify")
#logger and logger.info("environ keys: %s" % environ.keys())
#logger and logger.info("environ keys: %s", environ.keys())
query = parse_dict_querystring(environ)
# If the extractor finds a special query string on any request,
# it will attempt to find the values in the input body.
@@ -95,7 +95,7 @@ class FormHiddenPlugin(FormPlugin):
for key, val in query.items():
hidden.append(HIDDEN_PRE_LINE % ("_%s_" % key, val))
logger.info("hidden: %s" % (hidden,))
logger.info("hidden: %s", hidden)
form = self.formbody or _DEFAULT_FORM
form = form % "\n".join(hidden)

View File

@@ -148,14 +148,14 @@ class SAML2Plugin(object):
post = parse_qs(body) # parse the POST fields into a dict
logger.debug('identify post: %s' % (post,))
logger.debug('identify post: %s', post)
return post
def _wayf_redirect(self, came_from):
sid_ = sid()
self.outstanding_queries[sid_] = came_from
logger.info("Redirect to WAYF function: %s" % self.wayf)
logger.info("Redirect to WAYF function: %s", self.wayf)
return -1, HTTPSeeOther(headers=[('Location',
"%s?%s" % (self.wayf, sid_))])
@@ -175,7 +175,7 @@ class SAML2Plugin(object):
_cli = self.saml_client
logger.info("[_pick_idp] %s" % environ)
logger.info("[_pick_idp] %s", environ)
if "HTTP_PAOS" in environ:
if environ["HTTP_PAOS"] == PAOS_HEADER_INFO:
if 'application/vnd.paos+xml' in environ["HTTP_ACCEPT"]:
@@ -191,7 +191,7 @@ class SAML2Plugin(object):
if not _entityid:
return -1, HTTPInternalServerError(
detail="No IdP to talk to")
logger.info("IdP to talk to: %s" % _entityid)
logger.info("IdP to talk to: %s", _entityid)
return ecp.ecp_auth_request(_cli, _entityid,
_relay_state)
else:
@@ -203,7 +203,7 @@ class SAML2Plugin(object):
idps = self.metadata.with_descriptor("idpsso")
logger.info("IdP URL: %s" % idps)
logger.info("IdP URL: %s", idps)
idp_entity_id = query = None
@@ -217,7 +217,7 @@ class SAML2Plugin(object):
idp_entity_id = _idp_entity_id
break
except KeyError:
logger.debug("No IdP entity ID in query: %s" % query)
logger.debug("No IdP entity ID in query: %s", query)
pass
if idp_entity_id is None:
@@ -228,7 +228,7 @@ class SAML2Plugin(object):
return -1, HTTPInternalServerError(detail='Misconfiguration')
else:
idp_entity_id = ""
logger.info("ENVIRON: %s" % environ)
logger.info("ENVIRON: %s", environ)
if self.wayf:
if query:
@@ -260,7 +260,7 @@ class SAML2Plugin(object):
return -1, HTTPNotImplemented(
detail='No WAYF or DJ present!')
logger.info("Chosen IdP: '%s'" % idp_entity_id)
logger.info("Chosen IdP: '%s'", idp_entity_id)
return 0, idp_entity_id
#### IChallenger ####
@@ -290,7 +290,7 @@ class SAML2Plugin(object):
# Which page was accessed to get here
came_from = construct_came_from(environ)
environ["myapp.came_from"] = came_from
logger.debug("[sp.challenge] RelayState >> '%s'" % came_from)
logger.debug("[sp.challenge] RelayState >> '%s'", came_from)
# Am I part of a virtual organization or more than one ?
try:
@@ -301,14 +301,14 @@ class SAML2Plugin(object):
except AttributeError:
vorg_name = ""
logger.info("[sp.challenge] VO: %s" % vorg_name)
logger.info("[sp.challenge] VO: %s", vorg_name)
# If more than one idp and if none is selected, I have to do wayf
(done, response) = self._pick_idp(environ, came_from)
# Three cases: -1 something went wrong or Discovery service used
# 0 I've got an IdP to send a request to
# >0 ECP in progress
logger.debug("_idp_pick returned: %s" % done)
logger.debug("_idp_pick returned: %s", done)
if done == -1:
return response
elif done > 0:
@@ -316,14 +316,14 @@ class SAML2Plugin(object):
return ECP_response(response)
else:
entity_id = response
logger.info("[sp.challenge] entity_id: %s" % entity_id)
logger.info("[sp.challenge] entity_id: %s", entity_id)
# Do the AuthnRequest
_binding = BINDING_HTTP_REDIRECT
try:
srvs = _cli.metadata.single_sign_on_service(entity_id, _binding)
logger.debug("srvs: %s" % srvs)
logger.debug("srvs: %s", srvs)
dest = srvs[0]["location"]
logger.debug("destination: %s" % dest)
logger.debug("destination: %s", dest)
extensions = None
cert = None
@@ -358,7 +358,7 @@ class SAML2Plugin(object):
destination=dest,
relay_state=came_from)
logger.debug("ht_args: %s" % ht_args)
logger.debug("ht_args: %s", ht_args)
except Exception as exc:
logger.exception(exc)
raise Exception(
@@ -378,7 +378,7 @@ class SAML2Plugin(object):
self.outstanding_queries[_sid] = came_from
if not ht_args["data"] and ht_args["headers"][0][0] == "Location":
logger.debug('redirect to: %s' % ht_args["headers"][0][1])
logger.debug('redirect to: %s', ht_args["headers"][0][1])
return HTTPSeeOther(headers=ht_args["headers"])
else:
return ht_args["data"]
@@ -391,13 +391,13 @@ class SAML2Plugin(object):
'repoze.who.userid': cni,
"user": session_info["ava"],
}
logger.debug("Identity: %s" % identity)
logger.debug("Identity: %s", identity)
return identity
def _eval_authn_response(self, environ, post, binding=BINDING_HTTP_POST):
logger.info("Got AuthN response, checking..")
logger.info("Outstanding: %s" % (self.outstanding_queries,))
logger.info("Outstanding: %s", self.outstanding_queries)
try:
# Evaluate the response, returns a AuthnResponse instance
@@ -416,7 +416,7 @@ class SAML2Plugin(object):
return None
if session_info["came_from"]:
logger.debug("came_from << %s" % session_info["came_from"])
logger.debug("came_from << %s", session_info["came_from"])
try:
path, query = session_info["came_from"].split('?')
environ["PATH_INFO"] = path
@@ -424,7 +424,7 @@ class SAML2Plugin(object):
except ValueError:
environ["PATH_INFO"] = session_info["came_from"]
logger.info("Session_info: %s" % session_info)
logger.info("Session_info: %s", session_info)
return session_info
def do_ecp_response(self, body, environ):
@@ -433,7 +433,7 @@ class SAML2Plugin(object):
environ["s2repoze.relay_state"] = _relay_state.text
session_info = response.session_info()
logger.info("Session_info: %s" % session_info)
logger.info("Session_info: %s", session_info)
return session_info
@@ -453,15 +453,15 @@ class SAML2Plugin(object):
return None
# if logger:
# logger.info("ENVIRON: %s" % environ)
# logger.info("self: %s" % (self.__dict__,))
# logger.info("ENVIRON: %s", environ)
# logger.info("self: %s", self.__dict__)
uri = environ.get('REQUEST_URI', construct_url(environ))
logger.debug('[sp.identify] uri: %s' % (uri,))
logger.debug('[sp.identify] uri: %s', uri)
query = parse_dict_querystring(environ)
logger.debug('[sp.identify] query: %s' % (query,))
logger.debug('[sp.identify] query: %s', query)
if "SAMLResponse" in query or "SAMLRequest" in query:
post = query
@@ -471,7 +471,7 @@ class SAML2Plugin(object):
binding = BINDING_HTTP_POST
try:
logger.debug('[sp.identify] post keys: %s' % (post.keys(),))
logger.debug('[sp.identify] post keys: %s', post.keys())
except (TypeError, IndexError):
pass
@@ -567,9 +567,9 @@ class SAML2Plugin(object):
pass
_cli = self.saml_client
logger.debug("[add_metadata] for %s" % name_id)
logger.debug("[add_metadata] for %s", name_id)
try:
logger.debug("Issuers: %s" % _cli.users.sources(name_id))
logger.debug("Issuers: %s", _cli.users.sources(name_id))
except KeyError:
pass
@@ -578,7 +578,7 @@ class SAML2Plugin(object):
try:
(ava, _) = _cli.users.get_identity(name_id)
#now = time.gmtime()
logger.debug("[add_metadata] adds: %s" % ava)
logger.debug("[add_metadata] adds: %s", ava)
identity["user"].update(ava)
except KeyError:
pass
@@ -596,7 +596,7 @@ class SAML2Plugin(object):
except KeyError:
logger.exception("Failed to do attribute aggregation, "
"missing common attribute")
logger.debug("[add_metadata] returns: %s" % (dict(identity),))
logger.debug("[add_metadata] returns: %s", dict(identity))
if not identity["user"]:
# remove cookie and demand re-authentication
@@ -633,7 +633,7 @@ class SAML2Plugin(object):
else:
ht_args = responses[responses.keys()[0]][1]
if not ht_args["data"] and ht_args["headers"][0][0] == "Location":
logger.debug('redirect to: %s' % ht_args["headers"][0][1])
logger.debug('redirect to: %s', ht_args["headers"][0][1])
return HTTPSeeOther(headers=ht_args["headers"])
else:
return ht_args["data"]

View File

@@ -72,7 +72,7 @@ class SessionStorage(object):
try:
statements = self.authn[key]
except KeyError:
logger.info("Unknown subject %s" % name_id)
logger.info("Unknown subject %s", name_id)
return []
for statement in statements:
@@ -88,7 +88,7 @@ class SessionStorage(object):
return result
def remove_authn_statements(self, name_id):
logger.debug("remove authn about: %s" % name_id)
logger.debug("remove authn about: %s", name_id)
nkey = sha1(code_binary(name_id)).hexdigest()
del self.authn[nkey]

View File

@@ -614,8 +614,7 @@ class Server(Entity):
name_id = self.ident.construct_nameid(userid, policy,
sp_entity_id,
name_id_policy)
logger.debug("construct_nameid: %s => %s" % (userid,
name_id))
logger.debug("construct_nameid: %s => %s", userid, name_id)
except IOError as exc:
response = self.create_error_response(in_response_to,
destination,
@@ -732,7 +731,7 @@ class Server(Entity):
if sign_response:
return self.sign(_resp)
else:
logger.info("Message: %s" % _resp)
logger.info("Message: %s", _resp)
return _resp
def create_authn_query_response(self, subject, session_index=None,
@@ -810,7 +809,7 @@ class Server(Entity):
"""
lid = self.ident.find_local_id(name_id)
logger.info("Clean out %s" % lid)
logger.info("Clean out %s", lid)
# remove the authentications
try:

View File

@@ -778,7 +778,7 @@ class CryptoBackendXmlSec1(CryptoBackend):
:param xpath: What should be encrypted
:return:
"""
logger.debug("Encryption input len: %d" % len(text))
logger.debug("Encryption input len: %d", len(text))
_, fil = make_temp(str(text).encode('utf-8'), decode=False)
com_list = [self.xmlsec, "--encrypt", "--pubkey-cert-pem", recv_key,
@@ -838,7 +838,7 @@ class CryptoBackendXmlSec1(CryptoBackend):
:return: The decrypted document
"""
logger.debug("Decrypt input len: %d" % len(enctext))
logger.debug("Decrypt input len: %d", len(enctext))
_, fil = make_temp(str(enctext).encode('utf-8'), decode=False)
com_list = [self.xmlsec, "--decrypt", "--privkey-pem",
@@ -882,8 +882,8 @@ class CryptoBackendXmlSec1(CryptoBackend):
if signed_statement:
return signed_statement.decode('utf-8')
logger.error(
"Signing operation failed :\nstdout : %s\nstderr : %s" % (
stdout, stderr))
"Signing operation failed :\nstdout : %s\nstderr : %s",
stdout, stderr)
raise SigverError(stderr)
except DecryptError:
raise SigverError("Signing failed")
@@ -948,7 +948,7 @@ class CryptoBackendXmlSec1(CryptoBackend):
com_list.extend(["--output", ntf.name])
com_list += extra_args
logger.debug("xmlsec command: %s" % " ".join(com_list))
logger.debug("xmlsec command: %s", " ".join(com_list))
pof = Popen(com_list, stderr=PIPE, stdout=PIPE)
@@ -956,14 +956,14 @@ class CryptoBackendXmlSec1(CryptoBackend):
p_err = pof.stderr.read().decode('utf-8')
if pof.returncode is not None and pof.returncode < 0:
logger.error(LOG_LINE % (p_out, p_err))
logger.error(LOG_LINE, p_out, p_err)
raise XmlsecError("%d:%s" % (pof.returncode, p_err))
try:
if validate_output:
parse_xmlsec_output(p_err)
except XmlsecError as exc:
logger.error(LOG_LINE_2 % (p_out, p_err, exc))
logger.error(LOG_LINE_2, p_out, p_err, exc)
raise
ntf.seek(0)
@@ -1226,7 +1226,7 @@ class CertHandler(object):
cert_str, self._cert_str, self._key_str)
else:
valid, mess = self._osw.verify(self._cert_str, cert_str)
logger.info("CertHandler.verify_cert: %s" % mess)
logger.info("CertHandler.verify_cert: %s", mess)
return valid
return True
@@ -1463,8 +1463,8 @@ class SecurityContext(object):
decode=False, delete=self._xmlsec_delete_tmpfiles)
for cert in cert_from_instance(item)]
else:
logger.debug("==== Certs from metadata ==== %s: %s ====" % (issuer,
certs))
logger.debug("==== Certs from metadata ==== %s: %s ====", issuer,
certs)
if not certs:
raise MissingKey("%s" % issuer)
@@ -1498,13 +1498,13 @@ class SecurityContext(object):
verified = True
break
except XmlsecError as exc:
logger.error("check_sig: %s" % exc)
logger.error("check_sig: %s", exc)
pass
except SignatureError as exc:
logger.error("check_sig: %s" % exc)
logger.error("check_sig: %s", exc)
pass
except Exception as exc:
logger.error("check_sig: %s" % exc)
logger.error("check_sig: %s", exc)
raise
if (not verified) and (not only_valid_cert):

View File

@@ -42,7 +42,7 @@ class VirtualOrg(object):
# Remove the ones I have cached data from about this subject
vo_members = [m for m in vo_members if not self.sp.users.cache.active(
name_id, m)]
logger.info("VO members (not cached): %s" % vo_members)
logger.info("VO members (not cached): %s", vo_members)
return vo_members
def get_common_identifier(self, name_id):
@@ -59,8 +59,8 @@ class VirtualOrg(object):
def do_aggregation(self, name_id):
logger.info("** Do VO aggregation **\nSubjectID: %s, VO:%s" % (
name_id, self._name))
logger.info("** Do VO aggregation **\nSubjectID: %s, VO:%s",
name_id, self._name)
to_ask = self.members_to_ask(name_id)
if to_ask:
@@ -72,9 +72,9 @@ class VirtualOrg(object):
com_identifier, self.sp.config.entityid, to_ask):
_ = self._cache_session(session_info)
logger.info(">Issuers: %s" % self.sp.users.issuers_of_info(name_id))
logger.info("AVA: %s" % (self.sp.users.get_identity(name_id),))
logger.info(">Issuers: %s", self.sp.users.issuers_of_info(name_id))
logger.info("AVA: %s", self.sp.users.get_identity(name_id))
return True
else:
return False
return False

View File

@@ -102,7 +102,7 @@ class Interaction(object):
self.who = "Form process"
def pick_interaction(self, _base="", content="", req=None):
logger.info("pick_interaction baseurl: %s" % _base)
logger.info("pick_interaction baseurl: %s", _base)
unic = content
if content:
_bs = BeautifulSoup(content)
@@ -113,11 +113,11 @@ class Interaction(object):
_match = 0
for attr, val in interaction["matches"].items():
if attr == "url":
logger.info("matching baseurl against: %s" % val)
logger.info("matching baseurl against: %s", val)
if val == _base:
_match += 1
elif attr == "title":
logger.info("matching '%s' against title" % val)
logger.info("matching '%s' against title", val)
if _bs is None:
break
if _bs.title is None:
@@ -140,7 +140,7 @@ class Interaction(object):
_match += 1
if _match == len(interaction["matches"]):
logger.info("Matched: %s" % interaction["matches"])
logger.info("Matched: %s", interaction["matches"])
return interaction
raise InteractionNeeded("No interaction matched")
@@ -319,7 +319,7 @@ class Interaction(object):
else:
url = path
logger.info("GET %s" % url)
logger.info("GET %s", url)
return self.httpc.send(url, "GET")
#return resp, ""
@@ -390,8 +390,8 @@ class Action(object):
_args.update({"location": location, "features": features, "conv": conv})
logger.info("<-- FUNCTION: %s" % function.__name__)
logger.info("<-- ARGS: %s" % _args)
logger.info("<-- FUNCTION: %s", function.__name__)
logger.info("<-- ARGS: %s", _args)
result = function(response, **_args)
self.post_op(result, conv, _args)

View File

@@ -109,17 +109,17 @@ def do_request(client, url, method, body="", headers=None):
if headers is None:
headers = {}
logger.info("--> URL: %s" % url)
logger.info("--> BODY: %s" % body)
logger.info("--> Headers: %s" % (headers,))
logger.info("--> URL: %s", url)
logger.info("--> BODY: %s", body)
logger.info("--> Headers: %s", headers)
response = client.http_request(url, method=method, data=body,
headers=headers)
logger.info("<-- RESPONSE: %s" % response)
logger.info("<-- CONTENT: %s" % response.text)
logger.info("<-- RESPONSE: %s", response)
logger.info("<-- CONTENT: %s", response.text)
if response.cookies:
logger.info("<-- COOKIES: %s" % response.cookies)
logger.info("<-- COOKIES: %s", response.cookies)
return url, response, response.text
@@ -366,8 +366,8 @@ class Operation(object):
_args["location"] = location
logger.info("--> FUNCTION: %s" % self.function.__name__)
logger.info("--> ARGS: %s" % (_args,))
logger.info("--> FUNCTION: %s", self.function.__name__)
logger.info("--> ARGS: %s", _args)
result = self.function(self.conv.client, response, content, **_args)
self.post_op(result, self.conv, _args)

View File

@@ -51,14 +51,14 @@ class Conversation(object):
def check_severity(self, stat):
if stat["status"] >= 4:
logger.error("WHERE: %s" % stat["id"])
logger.error("STATUS:%s" % STATUSCODE[stat["status"]])
logger.error("WHERE: %s", stat["id"])
logger.error("STATUS:%s", STATUSCODE[stat["status"]])
try:
logger.error("HTTP STATUS: %s" % stat["http_status"])
logger.error("HTTP STATUS: %s", stat["http_status"])
except KeyError:
pass
try:
logger.error("INFO: %s" % stat["message"])
logger.error("INFO: %s", stat["message"])
except KeyError:
pass
@@ -119,8 +119,7 @@ class Conversation(object):
raise FatalError(
"Too long sequence of redirects: %s" % rdseq)
logger.info("HTTP %d Location: %s" % (_response.status_code,
url))
logger.info("HTTP %d Location: %s", _response.status_code, url)
# If back to me
for_me = False
for redirect_uri in self.my_endpoints():
@@ -143,13 +142,13 @@ class Conversation(object):
break
else:
try:
logger.info("GET %s" % url)
logger.info("GET %s", url)
_response = self.client.send(url, "GET")
except Exception as err:
raise FatalError("%s" % err)
content = _response.text
logger.info("<-- CONTENT: %s" % content)
logger.info("<-- CONTENT: %s", content)
self.position = url
self.last_content = content
self.response = _response
@@ -169,15 +168,15 @@ class Conversation(object):
self.position = url
cnt = content.replace("\n", '').replace("\t", '').replace("\r",
'')
logger.error("URL: %s" % url)
logger.error("Page Content: %s" % cnt)
logger.error("URL: %s", url)
logger.error("Page Content: %s", cnt)
raise
except KeyError:
self.position = url
cnt = content.replace("\n", '').replace("\t", '').replace("\r",
'')
logger.error("URL: %s" % url)
logger.error("Page Content: %s" % cnt)
logger.error("URL: %s", url)
logger.error("Page Content: %s", cnt)
self.err_check("interaction-needed")
if _spec == _last_action:
@@ -194,7 +193,7 @@ class Conversation(object):
_last_action = _spec
if len(_spec) > 2:
logger.info(">> %s <<" % _spec["page-type"])
logger.info(">> %s <<", _spec["page-type"])
if _spec["page-type"] == "login":
self.login_page = content
@@ -213,12 +212,11 @@ class Conversation(object):
self.response = _response
if _response.status_code >= 400:
txt = "Got status code '%s', error: %s" % (
_response.status_code, content)
logger.error(txt)
txt = "Got status code '%s', error: %s"
logger.error(txt, _response.status_code, content)
self.test_output.append(
{"status": ERROR,
"message": txt,
"message": txt % (_response.status_code, content),
#"id": "exception",
#"name": "interaction needed",
"url": self.position})

View File

@@ -232,7 +232,7 @@ class Client(object):
else:
self.test_log = exception_trace("RUN", err)
tsum = self.test_summation(self.args.oper)
logger.error("Unexpected exception in test driver %s" %
logger.error("Unexpected exception in test driver %s",
traceback.format_exception(*sys.exc_info()))

View File

@@ -80,14 +80,14 @@ class Conversation():
def check_severity(self, stat):
if stat["status"] >= 3:
logger.error("WHERE: %s" % stat["id"])
logger.error("STATUS:%s" % STATUSCODE[stat["status"]])
logger.error("WHERE: %s", stat["id"])
logger.error("STATUS:%s", STATUSCODE[stat["status"]])
try:
logger.error("HTTP STATUS: %s" % stat["http_status"])
logger.error("HTTP STATUS: %s", stat["http_status"])
except KeyError:
pass
try:
logger.error("INFO: %s" % stat["message"])
logger.error("INFO: %s", stat["message"])
except KeyError:
pass
@@ -153,9 +153,9 @@ class Conversation():
Create the <operation> directory; delete all possibly existing files
Write response content into response_x.<ext> (with x incrementing from 0)
"""
logger.info("<-- Status: %s" % response.status_code)
logger.info("<-- Status: %s", response.status_code)
if response.status_code in [302, 301, 303]:
logger.info("<-- location: %s" %
logger.info("<-- location: %s",
response.headers._store['location'][1])
else:
if self.commandlineargs.content_log:
@@ -183,11 +183,11 @@ class Conversation():
f = open(fn, "w")
f.write(response.content)
f.close()
logger.info("<-- Response content (encoding=%s) in file %s" %
(encoding, fn))
logger.info("<-- Response content (encoding=%s) in file %s",
encoding, fn)
pass
else:
logger.info("<-- Content: %s" % response.content)
logger.info("<-- Content: %s", response.content)
def wb_send_GET_startpage(self):
"""
@@ -251,7 +251,7 @@ class Conversation():
raise FatalError(
"Too long sequence of redirects: %s" % rdseq)
logger.info("--> REDIRECT TO: %s" % url)
logger.info("--> REDIRECT TO: %s", url)
# If back to me
for_me = False
try:
@@ -491,11 +491,11 @@ class Conversation():
_spec = self.interaction.pick_interaction(_base, content)
except InteractionNeeded:
self.position = url
logger.error("Page Content: %s" % content)
logger.error("Page Content: %s", content)
raise
except KeyError:
self.position = url
logger.error("Page Content: %s" % content)
logger.error("Page Content: %s", content)
self.err_check("interaction-needed")
if _spec == _last_action:
@@ -506,7 +506,7 @@ class Conversation():
_last_action = _spec
if len(_spec) > 2:
logger.info(">> %s <<" % _spec["page-type"])
logger.info(">> %s <<", _spec["page-type"])
if _spec["page-type"] == "login":
self.login_page = content

View File

@@ -16,21 +16,21 @@ def fetch_metadata(url, path, maxage=600):
fetch = False
if not os.path.isfile(path):
fetch = True
logger.debug("metadata file %s not found" % path)
logger.debug("metadata file %s not found", path)
elif (os.path.getmtime(path) + maxage) < time.time():
fetch = True
logger.debug("metadata file %s from %s is more than %s s old" %
(path,
strftime("%Y-%m-%d %H:%M:%S", time.localtime(os.path.getmtime(path))),
maxage))
logger.debug("metadata file %s from %s is more than %s s old",
path,
strftime("%Y-%m-%d %H:%M:%S", time.localtime(os.path.getmtime(path))),
maxage)
else:
logger.debug("metadata file %s is less than %s s old" % (path, maxage))
logger.debug("metadata file %s is less than %s s old", path, maxage)
if fetch:
f=urllib.URLopener()
try:
f.retrieve(url, path)
logger.debug("downloaded metadata from %s into %s" % (url, path))
logger.debug("downloaded metadata from %s into %s", url, path)
except:
logger.debug("downloaded metadata from %s failed: %s" %
(url, sys.exc_info()[0]))
logger.debug("downloaded metadata from %s failed: %s",
url, sys.exc_info()[0])