openstack/deb-python-pysaml2
Code Issues Proposed changes

Fix paramter passing in logging messages

Browse Source 
Pass parameters into logger calls directly instead of pre-merging
with the logger message. This way the logs are easier to maintain
and process. The code is also faster when logging is turned off
since it doesn't have to evaluate all params and render them into
strings.
This commit is contained in:
Jozef Knaperek
2015-10-12 16:22:19 +02:00
parent 1228db66eb
commit c7febbf9e8
34 changed files with 442 additions and 447 deletions
Download Patch File Download Diff File Expand all files Collapse all files

88
example/idp2/idp.py
View File

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

86
example/idp2/idp_uwsgi.py
View File

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

132
example/idp2_repoze/idp.py
View File

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

32
example/sp-repoze/sp.py
View File

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

62
example/sp-wsgi/sp.py
View File

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

24
src/idp_test/base.py
View File

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

2
src/idp_test/check.py
View File

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

4
src/idp_test/interaction.py
View File

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

4
src/saml2/assertion.py
View File

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

12
src/saml2/attribute_converter.py
View File

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

2
src/saml2/attribute_resolver.py
View File

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

28
src/saml2/client.py
View File

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

11
src/saml2/client_base.py
View File

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

18
src/saml2/ecp_client.py
View File

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

33
src/saml2/entity.py
View File

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

14
src/saml2/httpbase.py
View File

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

10
src/saml2/ident.py
View File

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

24
src/saml2/mdstore.py
View File

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

2
src/saml2/mongo_store.py
View File

@@ -113,7 +113,7 @@ class SessionStorageMDB(object):
return result return result
def remove_authn_statements(self, name_id): 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() key = sha1(code_binary(name_id)).hexdigest()
for item in self.assertion.find({"name_id_key": key}): for item in self.assertion.find({"name_id_key": key}):
self.assertion.remove(item["_id"]) self.assertion.remove(item["_id"])

6
src/saml2/pack.py
View File

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

12
src/saml2/request.py
View File

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

60
src/saml2/response.py
View File

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

4
src/saml2/s2repoze/plugins/formswithhidden.py
View File

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

62
src/saml2/s2repoze/plugins/sp.py
View File

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

4
src/saml2/sdb.py
View File

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

7
src/saml2/server.py
View File

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

26
src/saml2/sigver.py
View File

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

12
src/saml2/virtual_org.py
View File

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

14
src/saml2test/interaction.py
View File

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

16
src/saml2test/opfunc.py
View File

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

32
src/saml2test/tool.py
View File

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

2
src/sp_test/__init__.py
View File

@@ -232,7 +232,7 @@ class Client(object):
else: else:
self.test_log = exception_trace("RUN", err) self.test_log = exception_trace("RUN", err)
tsum = self.test_summation(self.args.oper) 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())) traceback.format_exception(*sys.exc_info()))

26
src/sp_test/base.py
View File

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

18
src/utility/metadata.py
View File

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