diff options
| author | Jozef Knaperek <jknaperek@gmail.com> | 2015-10-12 16:22:19 +0200 |
|---|---|---|
| committer | Jozef Knaperek <jknaperek@gmail.com> | 2015-10-15 15:33:10 +0200 |
| commit | c7febbf9e8c85355dccb53a326a51bfc41db1c66 (patch) | |
| tree | 976664df2088314a431be719f64359448ddf17e9 | |
| parent | 1228db66eb006e0f069cc1b6b1612c6cbaa8df1d (diff) | |
| download | pysaml2-c7febbf9e8c85355dccb53a326a51bfc41db1c66.tar.gz | |
Fix paramter passing in logging messages
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.
34 files changed, 442 insertions, 447 deletions
diff --git a/example/idp2/idp.py b/example/idp2/idp.py index f3db83e6..5e78d36f 100755 --- a/example/idp2/idp.py +++ b/example/idp2/idp.py @@ -91,7 +91,7 @@ def dict2list_of_tuples(d): class Service(object): def __init__(self, environ, start_response, user=None): self.environ = environ - logger.debug("ENVIRON: %s" % environ) + logger.debug("ENVIRON: %s", environ) self.start_response = start_response self.user = user @@ -104,7 +104,7 @@ class Service(object): def unpack_post(self): _dict = parse_qs(get_post(self.environ)) - logger.debug("unpack_post:: %s" % _dict) + logger.debug("unpack_post:: %s", _dict) try: return dict([(k, v[0]) for k, v in _dict.items()]) except Exception: @@ -124,11 +124,11 @@ class Service(object): _dict = self.unpack_post() else: _dict = None - logger.debug("_dict: %s" % _dict) + logger.debug("_dict: %s", _dict) return _dict def operation(self, saml_msg, binding): - logger.debug("_operation: %s" % saml_msg) + logger.debug("_operation: %s", saml_msg) if not (saml_msg and 'SAMLRequest' in saml_msg): resp = BadRequest('Error parsing request or no request') return resp(self.environ, self.start_response) @@ -210,7 +210,7 @@ class Service(object): """ logger.debug("- SOAP -") _dict = self.unpack_soap() - logger.debug("_dict: %s" % _dict) + logger.debug("_dict: %s", _dict) return self.operation(_dict, BINDING_SOAP) def uri(self): @@ -273,7 +273,7 @@ class SSO(Service): logger.info("parsed OK") _authn_req = self.req_info.message - logger.debug("%s" % _authn_req) + logger.debug("%s", _authn_req) try: self.binding_out, self.destination = IDP.pick_binding( @@ -281,11 +281,11 @@ class SSO(Service): bindings=self.response_bindings, entity_id=_authn_req.issuer.text, request=_authn_req) except Exception as err: - logger.error("Couldn't find receiver endpoint: %s" % err) + logger.error("Couldn't find receiver endpoint: %s", err) raise - logger.debug("Binding: %s, destination: %s" % (self.binding_out, - self.destination)) + logger.debug("Binding: %s, destination: %s", self.binding_out, + self.destination) resp_args = {} try: @@ -313,18 +313,18 @@ class SSO(Service): try: resp_args, _resp = self.verify_request(query, binding_in) except UnknownPrincipal as excp: - logger.error("UnknownPrincipal: %s" % (excp,)) + logger.error("UnknownPrincipal: %s", excp) resp = ServiceError("UnknownPrincipal: %s" % (excp,)) return resp(self.environ, self.start_response) except UnsupportedBinding as excp: - logger.error("UnsupportedBinding: %s" % (excp,)) + logger.error("UnsupportedBinding: %s", excp) resp = ServiceError("UnsupportedBinding: %s" % (excp,)) return resp(self.environ, self.start_response) if not _resp: identity = USERS[self.user].copy() # identity["eduPersonTargetedID"] = get_eptid(IDP, query, session) - logger.info("Identity: %s" % (identity,)) + logger.info("Identity: %s", identity) if REPOZE_ID_EQUIVALENT: identity[REPOZE_ID_EQUIVALENT] = self.user @@ -345,7 +345,7 @@ class SSO(Service): resp = ServiceError("Exception: %s" % (excp,)) return resp(self.environ, self.start_response) - logger.info("AuthNResponse: %s" % _resp) + logger.info("AuthNResponse: %s", _resp) if self.op_type == "ecp": kwargs = {"soap_headers": [ ecp.Response( @@ -357,12 +357,12 @@ class SSO(Service): "%s" % _resp, self.destination, relay_state, response=True, **kwargs) - logger.debug("HTTPargs: %s" % http_args) + logger.debug("HTTPargs: %s", http_args) return self.response(self.binding_out, http_args) @staticmethod def _store_request(saml_msg): - logger.debug("_store_request: %s" % saml_msg) + logger.debug("_store_request: %s", saml_msg) key = sha1(saml_msg["SAMLRequest"]).hexdigest() # store the AuthnRequest IDP.ticket[key] = saml_msg @@ -508,7 +508,7 @@ def do_authentication(environ, start_response, authn_context, key, if len(auth_info): method, reference = auth_info[0] - logger.debug("Authn chosen: %s (ref=%s)" % (method, reference)) + logger.debug("Authn chosen: %s (ref=%s)", method, reference) return method(environ, start_response, reference, key, redirect_uri, headers) else: resp = Unauthorized("No usable authentication method") @@ -546,7 +546,7 @@ def username_password_authn(environ, start_response, reference, key, "authn_reference": reference, "redirect_uri": redirect_uri } - logger.info("do_authentication argv: %s" % argv) + logger.info("do_authentication argv: %s", argv) return resp(environ, start_response, **argv) @@ -562,7 +562,7 @@ def verify_username_and_password(dic): def do_verify(environ, start_response, _): query = parse_qs(get_post(environ)) - logger.debug("do_verify: %s" % query) + logger.debug("do_verify: %s", query) try: _ok, user = verify_username_and_password(query) @@ -576,13 +576,13 @@ def do_verify(environ, start_response, _): uid = rndstr(24) IDP.cache.uid2user[uid] = user IDP.cache.user2uid[user] = uid - logger.debug("Register %s under '%s'" % (user, uid)) + logger.debug("Register %s under '%s'", user, uid) kaka = set_cookie("idpauthn", "/", uid, query["authn_reference"][0]) lox = "%s?id=%s&key=%s" % (query["redirect_uri"][0], uid, query["key"][0]) - logger.debug("Redirect => %s" % lox) + logger.debug("Redirect => %s", lox) resp = Redirect(lox, headers=[kaka], content="text/html") return resp(environ, start_response) @@ -610,17 +610,17 @@ class SLO(Service): logger.info("--- Single Log Out Service ---") try: - logger.debug("req: '%s'" % request) + logger.debug("req: '%s'", request) req_info = IDP.parse_logout_request(request, binding) except Exception as exc: - logger.error("Bad request: %s" % exc) + logger.error("Bad request: %s", exc) resp = BadRequest("%s" % exc) return resp(self.environ, self.start_response) msg = req_info.message if msg.name_id: lid = IDP.ident.find_local_id(msg.name_id) - logger.info("local identifier: %s" % lid) + logger.info("local identifier: %s", lid) if lid in IDP.cache.user2uid: uid = IDP.cache.user2uid[lid] if uid in IDP.cache.uid2user: @@ -630,8 +630,8 @@ class SLO(Service): try: IDP.session_db.remove_authn_statements(msg.name_id) except KeyError as exc: - logger.error("Unknown session: %s" % exc) - resp = ServiceError("Unknown session: %s" % exc) + logger.error("Unknown session: %s", exc) + resp = ServiceError("Unknown session: %s", exc) return resp(self.environ, self.start_response) resp = IDP.create_logout_response(msg, [binding]) @@ -649,7 +649,7 @@ class SLO(Service): hinfo = IDP.apply_binding(binding, "%s" % resp, destination, relay_state, response=response) except Exception as exc: - logger.error("ServiceError: %s" % exc) + logger.error("ServiceError: %s", exc) resp = ServiceError("%s" % exc) return resp(self.environ, self.start_response) @@ -657,7 +657,7 @@ class SLO(Service): delco = delete_cookie(self.environ, "idpauthn") if delco: hinfo["headers"].append(delco) - logger.info("Header: %s" % (hinfo["headers"],)) + logger.info("Header: %s", (hinfo["headers"],)) if binding == BINDING_HTTP_REDIRECT: for key, value in hinfo['headers']: @@ -688,7 +688,7 @@ class NMI(Service): request.name_id, request.new_id, request.new_encrypted_id, request.terminate) - logger.debug("New NameID: %s" % name_id) + logger.debug("New NameID: %s", name_id) _resp = IDP.create_manage_name_id_response(request) @@ -718,12 +718,12 @@ class AIDR(Service): hinfo = IDP.apply_binding(BINDING_URI, "%s" % assertion, response=True) - logger.debug("HINFO: %s" % hinfo) + logger.debug("HINFO: %s", hinfo) resp = Response(hinfo["data"], headers=hinfo["headers"]) return resp(self.environ, self.start_response) def operation(self, _dict, binding, **kwargs): - logger.debug("_operation: %s" % _dict) + logger.debug("_operation: %s", _dict) if not _dict or "ID" not in _dict: resp = BadRequest('Error parsing request or no request') return resp(self.environ, self.start_response) @@ -764,7 +764,7 @@ class AQS(Service): _query.requested_authn_context, _query.session_index) - logger.debug("response: %s" % msg) + logger.debug("response: %s", msg) hinfo = IDP.apply_binding(BINDING_SOAP, "%s" % msg, "", "", response=True) @@ -787,7 +787,7 @@ class ATTR(Service): name_id = _query.subject.name_id uid = name_id.text - logger.debug("Local uid: %s" % uid) + logger.debug("Local uid: %s", uid) identity = EXTRA[uid] # Comes in over SOAP so only need to construct the response @@ -795,7 +795,7 @@ class ATTR(Service): msg = IDP.create_attribute_response(identity, name_id=name_id, **args) - logger.debug("response: %s" % msg) + logger.debug("response: %s", msg) hinfo = IDP.apply_binding(BINDING_SOAP, "%s" % msg, "", "", response=True) @@ -842,7 +842,7 @@ class NIM(Service): # Cookie handling # ---------------------------------------------------------------------------- def info_from_cookie(kaka): - logger.debug("KAKA: %s" % kaka) + logger.debug("KAKA: %s", kaka) if kaka: cookie_obj = SimpleCookie(kaka) morsel = cookie_obj.get("idpauthn", None) @@ -859,14 +859,14 @@ def info_from_cookie(kaka): def delete_cookie(environ, name): kaka = environ.get("HTTP_COOKIE", '') - logger.debug("delete KAKA: %s" % kaka) + logger.debug("delete KAKA: %s", kaka) if kaka: cookie_obj = SimpleCookie(kaka) morsel = cookie_obj.get(name, None) cookie = SimpleCookie() cookie[name] = "" cookie[name]['path'] = "/" - logger.debug("Expire: %s" % morsel) + logger.debug("Expire: %s", morsel) cookie[name]["expires"] = _expiration("dawn") return tuple(cookie.output().split(": ", 1)) return None @@ -877,7 +877,7 @@ def set_cookie(name, _, *args): cookie[name] = base64.b64encode(":".join(args)) cookie[name]['path'] = "/" cookie[name]["expires"] = _expiration(5) # 5 minutes from now - logger.debug("Cookie expires: %s" % cookie[name]["expires"]) + logger.debug("Cookie expires: %s", cookie[name]["expires"]) return tuple(cookie.output().split(": ", 1)) # ---------------------------------------------------------------------------- @@ -940,7 +940,7 @@ def metadata(environ, start_response): start_response('200 OK', [('Content-Type', "text/xml")]) return metadata except Exception as ex: - logger.error("An error occured while creating metadata:" + ex.message) + logger.error("An error occured while creating metadata: %s", ex.message) return not_found(environ, start_response) @@ -959,7 +959,7 @@ def staticfile(environ, start_response): start_response('200 OK', [('Content-Type', "text/xml")]) return open(path, 'r').read() except Exception as ex: - logger.error("An error occured while creating metadata:" + ex.message) + logger.error("An error occured while creating metadata: %s", ex.message) return not_found(environ, start_response) @@ -971,9 +971,9 @@ def application(environ, start_response): the functions from above can access the url placeholders. If nothing matches, call the `not_found` function. - + :param environ: The HTTP application environment - :param start_response: The application to run when the handling of the + :param start_response: The application to run when the handling of the request is done :return: The response as a list of lines """ @@ -984,7 +984,7 @@ def application(environ, start_response): return metadata(environ, start_response) kaka = environ.get("HTTP_COOKIE", None) - logger.info("<application> PATH: %s" % path) + logger.info("<application> PATH: %s", path) if kaka: logger.info("= KAKA =") @@ -994,7 +994,7 @@ def application(environ, start_response): else: try: query = parse_qs(environ["QUERY_STRING"]) - logger.debug("QUERY: %s" % query) + logger.debug("QUERY: %s", query) user = IDP.cache.uid2user[query["id"][0]] except KeyError: user = None @@ -1013,7 +1013,7 @@ def application(environ, start_response): except IndexError: environ['myapp.url_args'] = path - logger.debug("Callback: %s" % (callback,)) + logger.debug("Callback: %s", callback) if isinstance(callback, tuple): cls = callback[0](environ, start_response, user) func = getattr(cls, callback[1]) diff --git a/example/idp2/idp_uwsgi.py b/example/idp2/idp_uwsgi.py index dcc01216..30e4b26a 100755 --- a/example/idp2/idp_uwsgi.py +++ b/example/idp2/idp_uwsgi.py @@ -88,7 +88,7 @@ def dict2list_of_tuples(d): class Service(object): def __init__(self, environ, start_response, user=None): self.environ = environ - logger.debug("ENVIRON: %s" % environ) + logger.debug("ENVIRON: %s", environ) self.start_response = start_response self.user = user @@ -101,7 +101,7 @@ class Service(object): def unpack_post(self): _dict = parse_qs(get_post(self.environ)) - logger.debug("unpack_post:: %s" % _dict) + logger.debug("unpack_post:: %s", _dict) try: return dict([(k, v[0]) for k, v in _dict.items()]) except Exception: @@ -121,11 +121,11 @@ class Service(object): _dict = self.unpack_post() else: _dict = None - logger.debug("_dict: %s" % _dict) + logger.debug("_dict: %s", _dict) return _dict def operation(self, saml_msg, binding): - logger.debug("_operation: %s" % saml_msg) + logger.debug("_operation: %s", saml_msg) if not saml_msg or not 'SAMLRequest' in saml_msg: resp = BadRequest('Error parsing request or no request') return resp(self.environ, self.start_response) @@ -186,7 +186,7 @@ class Service(object): """ logger.debug("- SOAP -") _dict = self.unpack_soap() - logger.debug("_dict: %s" % _dict) + logger.debug("_dict: %s", _dict) return self.operation(_dict, BINDING_SOAP) def uri(self): @@ -246,7 +246,7 @@ class SSO(Service): logger.info("parsed OK") _authn_req = self.req_info.message - logger.debug("%s" % _authn_req) + logger.debug("%s", _authn_req) try: self.binding_out, self.destination = IDP.pick_binding( @@ -254,11 +254,11 @@ class SSO(Service): bindings=self.response_bindings, entity_id=_authn_req.issuer.text) except Exception as err: - logger.error("Couldn't find receiver endpoint: %s" % err) + logger.error("Couldn't find receiver endpoint: %s", err) raise - logger.debug("Binding: %s, destination: %s" % (self.binding_out, - self.destination)) + logger.debug("Binding: %s, destination: %s", self.binding_out, + self.destination) resp_args = {} try: @@ -285,18 +285,18 @@ class SSO(Service): try: resp_args, _resp = self.verify_request(query, binding_in) except UnknownPrincipal as excp: - logger.error("UnknownPrincipal: %s" % (excp,)) + logger.error("UnknownPrincipal: %s", excp) resp = ServiceError("UnknownPrincipal: %s" % (excp,)) return resp(self.environ, self.start_response) except UnsupportedBinding as excp: - logger.error("UnsupportedBinding: %s" % (excp,)) + logger.error("UnsupportedBinding: %s", excp) resp = ServiceError("UnsupportedBinding: %s" % (excp,)) return resp(self.environ, self.start_response) if not _resp: identity = USERS[self.user].copy() # identity["eduPersonTargetedID"] = get_eptid(IDP, query, session) - logger.info("Identity: %s" % (identity,)) + logger.info("Identity: %s", identity) if REPOZE_ID_EQUIVALENT: identity[REPOZE_ID_EQUIVALENT] = self.user @@ -317,7 +317,7 @@ class SSO(Service): resp = ServiceError("Exception: %s" % (excp,)) return resp(self.environ, self.start_response) - logger.info("AuthNResponse: %s" % _resp) + logger.info("AuthNResponse: %s", _resp) if self.op_type == "ecp": kwargs = {"soap_headers": [ ecp.Response( @@ -329,11 +329,11 @@ class SSO(Service): "%s" % _resp, self.destination, relay_state, response=True, **kwargs) - logger.debug("HTTPargs: %s" % http_args) + logger.debug("HTTPargs: %s", http_args) return self.response(self.binding_out, http_args) def _store_request(self, saml_msg): - logger.debug("_store_request: %s" % saml_msg) + logger.debug("_store_request: %s", saml_msg) key = sha1(saml_msg["SAMLRequest"]).hexdigest() # store the AuthnRequest IDP.ticket[key] = saml_msg @@ -468,7 +468,7 @@ def do_authentication(environ, start_response, authn_context, key, if len(auth_info): method, reference = auth_info[0] - logger.debug("Authn chosen: %s (ref=%s)" % (method, reference)) + logger.debug("Authn chosen: %s (ref=%s)", method, reference) return method(environ, start_response, reference, key, redirect_uri) else: resp = Unauthorized("No usable authentication method") @@ -504,7 +504,7 @@ def username_password_authn(environ, start_response, reference, key, "authn_reference": reference, "redirect_uri": redirect_uri } - logger.info("do_authentication argv: %s" % argv) + logger.info("do_authentication argv: %s", argv) return resp(environ, start_response, **argv) @@ -520,7 +520,7 @@ def verify_username_and_password(dic): def do_verify(environ, start_response, _): query = parse_qs(get_post(environ)) - logger.debug("do_verify: %s" % query) + logger.debug("do_verify: %s", query) try: _ok, user = verify_username_and_password(query) @@ -534,13 +534,13 @@ def do_verify(environ, start_response, _): uid = rndstr(24) IDP.cache.uid2user[uid] = user IDP.cache.user2uid[user] = uid - logger.debug("Register %s under '%s'" % (user, uid)) + logger.debug("Register %s under '%s'", user, uid) kaka = set_cookie("idpauthn", "/", uid, query["authn_reference"][0]) lox = "%s?id=%s&key=%s" % (query["redirect_uri"][0], uid, query["key"][0]) - logger.debug("Redirect => %s" % lox) + logger.debug("Redirect => %s", lox) resp = Redirect(lox, headers=[kaka], content="text/html") return resp(environ, start_response) @@ -568,17 +568,17 @@ class SLO(Service): logger.info("--- Single Log Out Service ---") try: _, body = request.split("\n") - logger.debug("req: '%s'" % body) + logger.debug("req: '%s'", body) req_info = IDP.parse_logout_request(body, binding) except Exception as exc: - logger.error("Bad request: %s" % exc) + logger.error("Bad request: %s", exc) resp = BadRequest("%s" % exc) return resp(self.environ, self.start_response) msg = req_info.message if msg.name_id: lid = IDP.ident.find_local_id(msg.name_id) - logger.info("local identifier: %s" % lid) + logger.info("local identifier: %s", lid) if lid in IDP.cache.user2uid: uid = IDP.cache.user2uid[lid] if uid in IDP.cache.uid2user: @@ -588,7 +588,7 @@ class SLO(Service): try: IDP.session_db.remove_authn_statements(msg.name_id) except KeyError as exc: - logger.error("ServiceError: %s" % exc) + logger.error("ServiceError: %s", exc) resp = ServiceError("%s" % exc) return resp(self.environ, self.start_response) @@ -597,7 +597,7 @@ class SLO(Service): try: hinfo = IDP.apply_binding(binding, "%s" % resp, "", relay_state) except Exception as exc: - logger.error("ServiceError: %s" % exc) + logger.error("ServiceError: %s", exc) resp = ServiceError("%s" % exc) return resp(self.environ, self.start_response) @@ -605,7 +605,7 @@ class SLO(Service): delco = delete_cookie(self.environ, "idpauthn") if delco: hinfo["headers"].append(delco) - logger.info("Header: %s" % (hinfo["headers"],)) + logger.info("Header: %s", (hinfo["headers"],)) resp = Response(hinfo["data"], headers=hinfo["headers"]) return resp(self.environ, self.start_response) @@ -626,7 +626,7 @@ class NMI(Service): request.name_id, request.new_id, request.new_encrypted_id, request.terminate) - logger.debug("New NameID: %s" % name_id) + logger.debug("New NameID: %s", name_id) _resp = IDP.create_manage_name_id_response(request) @@ -656,12 +656,12 @@ class AIDR(Service): hinfo = IDP.apply_binding(BINDING_URI, "%s" % assertion, response=True) - logger.debug("HINFO: %s" % hinfo) + logger.debug("HINFO: %s", hinfo) resp = Response(hinfo["data"], headers=hinfo["headers"]) return resp(self.environ, self.start_response) def operation(self, _dict, binding, **kwargs): - logger.debug("_operation: %s" % _dict) + logger.debug("_operation: %s", _dict) if not _dict or "ID" not in _dict: resp = BadRequest('Error parsing request or no request') return resp(self.environ, self.start_response) @@ -702,7 +702,7 @@ class AQS(Service): _query.requested_authn_context, _query.session_index) - logger.debug("response: %s" % msg) + logger.debug("response: %s", msg) hinfo = IDP.apply_binding(BINDING_SOAP, "%s" % msg, "", "", response=True) @@ -725,7 +725,7 @@ class ATTR(Service): name_id = _query.subject.name_id uid = name_id.text - logger.debug("Local uid: %s" % uid) + logger.debug("Local uid: %s", uid) identity = EXTRA[self.user] # Comes in over SOAP so only need to construct the response @@ -733,7 +733,7 @@ class ATTR(Service): msg = IDP.create_attribute_response(identity, name_id=name_id, **args) - logger.debug("response: %s" % msg) + logger.debug("response: %s", msg) hinfo = IDP.apply_binding(BINDING_SOAP, "%s" % msg, "", "", response=True) @@ -780,7 +780,7 @@ class NIM(Service): # Cookie handling # ---------------------------------------------------------------------------- def info_from_cookie(kaka): - logger.debug("KAKA: %s" % kaka) + logger.debug("KAKA: %s", kaka) if kaka: cookie_obj = SimpleCookie(kaka) morsel = cookie_obj.get("idpauthn", None) @@ -797,14 +797,14 @@ def info_from_cookie(kaka): def delete_cookie(environ, name): kaka = environ.get("HTTP_COOKIE", '') - logger.debug("delete KAKA: %s" % kaka) + logger.debug("delete KAKA: %s", kaka) if kaka: cookie_obj = SimpleCookie(kaka) morsel = cookie_obj.get(name, None) cookie = SimpleCookie() cookie[name] = "" cookie[name]['path'] = "/" - logger.debug("Expire: %s" % morsel) + logger.debug("Expire: %s", morsel) cookie[name]["expires"] = _expiration("dawn") return tuple(cookie.output().split(": ", 1)) return None @@ -815,7 +815,7 @@ def set_cookie(name, _, *args): cookie[name] = base64.b64encode(":".join(args)) cookie[name]['path'] = "/" cookie[name]["expires"] = _expiration(5) # 5 minutes from now - logger.debug("Cookie expires: %s" % cookie[name]["expires"]) + logger.debug("Cookie expires: %s", cookie[name]["expires"]) return tuple(cookie.output().split(": ", 1)) # ---------------------------------------------------------------------------- @@ -878,7 +878,7 @@ def metadata(environ, start_response): start_response('200 OK', [('Content-Type', "text/xml")]) return metadata except Exception as ex: - logger.error("An error occured while creating metadata:" + ex.message) + logger.error("An error occured while creating metadata:", ex.message) return not_found(environ, start_response) @@ -897,7 +897,7 @@ def staticfile(environ, start_response): start_response('200 OK', [('Content-Type', "text/xml")]) return open(path, 'r').read() except Exception as ex: - logger.error("An error occured while creating metadata:" + ex.message) + logger.error("An error occured while creating metadata:", ex.message) return not_found(environ, start_response) @@ -909,9 +909,9 @@ def application(environ, start_response): the functions from above can access the url placeholders. If nothing matches, call the `not_found` function. - + :param environ: The HTTP application environment - :param start_response: The application to run when the handling of the + :param start_response: The application to run when the handling of the request is done :return: The response as a list of lines """ @@ -922,7 +922,7 @@ def application(environ, start_response): return metadata(environ, start_response) kaka = environ.get("HTTP_COOKIE", None) - logger.info("<application> PATH: %s" % path) + logger.info("<application> PATH: %s", path) if kaka: logger.info("= KAKA =") @@ -932,7 +932,7 @@ def application(environ, start_response): else: try: query = parse_qs(environ["QUERY_STRING"]) - logger.debug("QUERY: %s" % query) + logger.debug("QUERY: %s", query) user = IDP.cache.uid2user[query["id"][0]] except KeyError: user = None @@ -951,7 +951,7 @@ def application(environ, start_response): except IndexError: environ['myapp.url_args'] = path - logger.debug("Callback: %s" % (callback,)) + logger.debug("Callback: %s", callback) if isinstance(callback, tuple): cls = callback[0](environ, start_response, user) func = getattr(cls, callback[1]) diff --git a/example/idp2_repoze/idp.py b/example/idp2_repoze/idp.py index cd6b486d..9512fca0 100755 --- a/example/idp2_repoze/idp.py +++ b/example/idp2_repoze/idp.py @@ -83,7 +83,7 @@ def dict2list_of_tuples(d): class Service(object): def __init__(self, environ, start_response, user=None): self.environ = environ - logger.debug("ENVIRON: %s" % environ) + logger.debug("ENVIRON: %s", environ) self.start_response = start_response self.user = user @@ -93,22 +93,22 @@ class Service(object): return dict([(k, v[0]) for k, v in parse_qs(_qs).items()]) else: return None - + def unpack_post(self): _dict = parse_qs(get_post(self.environ)) - logger.debug("unpack_post:: %s" % _dict) + logger.debug("unpack_post:: %s", _dict) try: return dict([(k, v[0]) for k, v in _dict.items()]) except Exception: return None - + def unpack_soap(self): try: query = get_post(self.environ) return {"SAMLRequest": query, "RelayState": ""} except Exception: return None - + def unpack_either(self): if self.environ["REQUEST_METHOD"] == "GET": _dict = self.unpack_redirect() @@ -116,11 +116,11 @@ class Service(object): _dict = self.unpack_post() else: _dict = None - logger.debug("_dict: %s" % _dict) + logger.debug("_dict: %s", _dict) return _dict def operation(self, _dict, binding): - logger.debug("_operation: %s" % _dict) + logger.debug("_operation: %s", _dict) if not _dict or not 'SAMLRequest' in _dict: resp = BadRequest('Error parsing request or no request') return resp(self.environ, self.start_response) @@ -178,7 +178,7 @@ class Service(object): """ logger.debug("- SOAP -") _dict = self.unpack_soap() - logger.debug("_dict: %s" % _dict) + logger.debug("_dict: %s", _dict) return self.operation(_dict, BINDING_SOAP) def uri(self): @@ -196,8 +196,8 @@ class Service(object): # "PATH_INFO"], "key": key}) # headers = [('Content-Type', 'text/plain')] # - # logger.debug("location: %s" % loc) - # logger.debug("headers: %s" % headers) + # logger.debug("location: %s", loc) + # logger.debug("headers: %s", headers) # # resp = Redirect(loc, headers=headers) # @@ -255,15 +255,15 @@ class SSO(Service): logger.info("parsed OK") _authn_req = self.req_info.message - logger.debug("%s" % _authn_req) + logger.debug("%s", _authn_req) self.binding_out, self.destination = IDP.pick_binding( "assertion_consumer_service", bindings=self.response_bindings, entity_id=_authn_req.issuer.text) - logger.debug("Binding: %s, destination: %s" % (self.binding_out, - self.destination)) + logger.debug("Binding: %s, destination: %s", self.binding_out, + self.destination) resp_args = {} try: @@ -282,18 +282,18 @@ class SSO(Service): try: resp_args, _resp = self.verify_request(query, binding_in) except UnknownPrincipal as excp: - logger.error("UnknownPrincipal: %s" % (excp,)) + logger.error("UnknownPrincipal: %s", excp) resp = ServiceError("UnknownPrincipal: %s" % (excp,)) return resp(self.environ, self.start_response) except UnsupportedBinding as excp: - logger.error("UnsupportedBinding: %s" % (excp,)) + logger.error("UnsupportedBinding: %s", excp) resp = ServiceError("UnsupportedBinding: %s" % (excp,)) return resp(self.environ, self.start_response) if not _resp: identity = USERS[self.user].copy() #identity["eduPersonTargetedID"] = get_eptid(IDP, query, session) - logger.info("Identity: %s" % (identity,)) + logger.info("Identity: %s", identity) if REPOZE_ID_EQUIVALENT: identity[REPOZE_ID_EQUIVALENT] = self.user @@ -310,15 +310,15 @@ class SSO(Service): resp = ServiceError("Exception: %s" % (excp,)) return resp(self.environ, self.start_response) - logger.info("AuthNResponse: %s" % _resp) + logger.info("AuthNResponse: %s", _resp) http_args = IDP.apply_binding(self.binding_out, "%s" % _resp, self.destination, relay_state, response=True) - logger.debug("HTTPargs: %s" % http_args) + logger.debug("HTTPargs: %s", http_args) return self.response(self.binding_out, http_args) def _store_request(self, _dict): - logger.debug("_store_request: %s" % _dict) + logger.debug("_store_request: %s", _dict) key = sha1(_dict["SAMLRequest"]).hexdigest() # store the AuthnRequest IDP.ticket[key] = _dict @@ -412,7 +412,7 @@ class SSO(Service): except TypeError: resp = Unauthorized() else: - logger.debug("Authz_info: %s" % _info) + logger.debug("Authz_info: %s", _info) try: (user, passwd) = _info.split(":") if is_equal(PASSWD[user], passwd): @@ -448,7 +448,7 @@ def do_authentication(environ, start_response, authn_context, key, if len(auth_info): method, reference = auth_info[0] - logger.debug("Authn chosen: %s (ref=%s)" % (method, reference)) + logger.debug("Authn chosen: %s (ref=%s)", method, reference) return method(environ, start_response, reference, key, redirect_uri) else: resp = Unauthorized("No usable authentication method") @@ -482,7 +482,7 @@ def username_password_authn(environ, start_response, reference, key, "authn_reference": reference, "redirect_uri": redirect_uri } - logger.info("do_authentication argv: %s" % argv) + logger.info("do_authentication argv: %s", argv) return resp(environ, start_response, **argv) @@ -498,7 +498,7 @@ def verify_username_and_password(dic): def do_verify(environ, start_response, _): query = parse_qs(get_post(environ)) - logger.debug("do_verify: %s" % query) + logger.debug("do_verify: %s", query) try: _ok, user = verify_username_and_password(query) @@ -512,13 +512,13 @@ def do_verify(environ, start_response, _): uid = rndstr(24) IDP.cache.uid2user[uid] = user IDP.cache.user2uid[user] = uid - logger.debug("Register %s under '%s'" % (user, uid)) + logger.debug("Register %s under '%s'", user, uid) kaka = set_cookie("idpauthn", "/", uid, query["authn_reference"][0]) lox = "%s?id=%s&key=%s" % (query["redirect_uri"][0], uid, query["key"][0]) - logger.debug("Redirect => %s" % lox) + logger.debug("Redirect => %s", lox) resp = Redirect(lox, headers=[kaka], content="text/html") return resp(environ, start_response) @@ -546,17 +546,17 @@ class SLO(Service): logger.info("--- Single Log Out Service ---") try: _, body = request.split("\n") - logger.debug("req: '%s'" % body) + logger.debug("req: '%s'", body) req_info = IDP.parse_logout_request(body, binding) except Exception as exc: - logger.error("Bad request: %s" % exc) + logger.error("Bad request: %s", exc) resp = BadRequest("%s" % exc) return resp(self.environ, self.start_response) - + msg = req_info.message if msg.name_id: lid = IDP.ident.find_local_id(msg.name_id) - logger.info("local identifier: %s" % lid) + logger.info("local identifier: %s", lid) if lid in IDP.cache.user2uid: uid = IDP.cache.user2uid[lid] if uid in IDP.cache.uid2user: @@ -566,55 +566,55 @@ class SLO(Service): try: IDP.session_db.remove_authn_statements(msg.name_id) except KeyError as exc: - logger.error("ServiceError: %s" % exc) + logger.error("ServiceError: %s", exc) resp = ServiceError("%s" % exc) return resp(self.environ, self.start_response) - + resp = IDP.create_logout_response(msg, [binding]) - + try: hinfo = IDP.apply_binding(binding, "%s" % resp, "", relay_state) except Exception as exc: - logger.error("ServiceError: %s" % exc) + logger.error("ServiceError: %s", exc) resp = ServiceError("%s" % exc) return resp(self.environ, self.start_response) - + #_tlh = dict2list_of_tuples(hinfo["headers"]) delco = delete_cookie(self.environ, "idpauthn") if delco: hinfo["headers"].append(delco) - logger.info("Header: %s" % (hinfo["headers"],)) + logger.info("Header: %s", hinfo["headers"]) resp = Response(hinfo["data"], headers=hinfo["headers"]) return resp(self.environ, self.start_response) - + # ---------------------------------------------------------------------------- # Manage Name ID service # ---------------------------------------------------------------------------- class NMI(Service): - + def do(self, query, binding, relay_state=""): logger.info("--- Manage Name ID Service ---") req = IDP.parse_manage_name_id_request(query, binding) request = req.message - + # Do the necessary stuff name_id = IDP.ident.handle_manage_name_id_request( request.name_id, request.new_id, request.new_encrypted_id, request.terminate) - - logger.debug("New NameID: %s" % name_id) - + + logger.debug("New NameID: %s", name_id) + _resp = IDP.create_manage_name_id_response(request) - + # It's using SOAP binding hinfo = IDP.apply_binding(BINDING_SOAP, "%s" % _resp, "", relay_state, response=True) - + resp = Response(hinfo["data"], headers=hinfo["headers"]) return resp(self.environ, self.start_response) - + # ---------------------------------------------------------------------------- # === Assertion ID request === # ---------------------------------------------------------------------------- @@ -630,15 +630,15 @@ class AIDR(Service): except Unknown: resp = NotFound(aid) return resp(self.environ, self.start_response) - + hinfo = IDP.apply_binding(BINDING_URI, "%s" % assertion, response=True) - - logger.debug("HINFO: %s" % hinfo) + + logger.debug("HINFO: %s", hinfo) resp = Response(hinfo["data"], headers=hinfo["headers"]) return resp(self.environ, self.start_response) def operation(self, _dict, binding, **kwargs): - logger.debug("_operation: %s" % _dict) + logger.debug("_operation: %s", _dict) if not _dict or "ID" not in _dict: resp = BadRequest('Error parsing request or no request') return resp(self.environ, self.start_response) @@ -678,7 +678,7 @@ class AQS(Service): _query.requested_authn_context, _query.session_index) - logger.debug("response: %s" % msg) + logger.debug("response: %s", msg) hinfo = IDP.apply_binding(BINDING_SOAP, "%s" % msg, "", "", response=True) @@ -701,7 +701,7 @@ class ATTR(Service): name_id = _query.subject.name_id uid = name_id.text - logger.debug("Local uid: %s" % uid) + logger.debug("Local uid: %s", uid) identity = EXTRA[uid] # Comes in over SOAP so only need to construct the response @@ -709,7 +709,7 @@ class ATTR(Service): msg = IDP.create_attribute_response(identity, name_id=name_id, **args) - logger.debug("response: %s" % msg) + logger.debug("response: %s", msg) hinfo = IDP.apply_binding(BINDING_SOAP, "%s" % msg, "", "", response=True) @@ -739,23 +739,23 @@ class NIM(Service): except PolicyError: resp = BadRequest("Unknown entity") return resp(self.environ, self.start_response) - + info = IDP.response_args(request) _resp = IDP.create_name_id_mapping_response(name_id, **info) - + # Only SOAP hinfo = IDP.apply_binding(BINDING_SOAP, "%s" % _resp, "", "", response=True) - + resp = Response(hinfo["data"], headers=hinfo["headers"]) return resp(self.environ, self.start_response) - + # ---------------------------------------------------------------------------- # Cookie handling # ---------------------------------------------------------------------------- def info_from_cookie(kaka): - logger.debug("KAKA: %s" % kaka) + logger.debug("KAKA: %s", kaka) if kaka: cookie_obj = SimpleCookie(kaka) morsel = cookie_obj.get("idpauthn", None) @@ -772,14 +772,14 @@ def info_from_cookie(kaka): def delete_cookie(environ, name): kaka = environ.get("HTTP_COOKIE", '') - logger.debug("delete KAKA: %s" % kaka) + logger.debug("delete KAKA: %s", kaka) if kaka: cookie_obj = SimpleCookie(kaka) morsel = cookie_obj.get(name, None) cookie = SimpleCookie() cookie[name] = "" cookie[name]['path'] = "/" - logger.debug("Expire: %s" % morsel) + logger.debug("Expire: %s", morsel) cookie[name]["expires"] = _expiration("dawn") return tuple(cookie.output().split(": ", 1)) return None @@ -790,7 +790,7 @@ def set_cookie(name, _, *args): cookie[name] = base64.b64encode(":".join(args)) cookie[name]['path'] = "/" cookie[name]["expires"] = _expiration(5) # 5 minutes from now - logger.debug("Cookie expires: %s" % cookie[name]["expires"]) + logger.debug("Cookie expires: %s", cookie[name]["expires"]) return tuple(cookie.output().split(": ", 1)) # ---------------------------------------------------------------------------- @@ -853,7 +853,7 @@ def metadata(environ, start_response): start_response('200 OK', [('Content-Type', "text/xml")]) return metadata except Exception as ex: - logger.error("An error occured while creating metadata:" + ex.message) + logger.error("An error occured while creating metadata: %s", ex.message) return not_found(environ, start_response) def staticfile(environ, start_response): @@ -867,7 +867,7 @@ def staticfile(environ, start_response): start_response('200 OK', [('Content-Type', "text/xml")]) return open(path, 'r').read() except Exception as ex: - logger.error("An error occured while creating metadata:" + ex.message) + logger.error("An error occured while creating metadata: %s", ex.message) return not_found(environ, start_response) def application(environ, start_response): @@ -878,9 +878,9 @@ def application(environ, start_response): the functions from above can access the url placeholders. If nothing matches, call the `not_found` function. - + :param environ: The HTTP application environment - :param start_response: The application to run when the handling of the + :param start_response: The application to run when the handling of the request is done :return: The response as a list of lines """ @@ -891,7 +891,7 @@ def application(environ, start_response): return metadata(environ, start_response) kaka = environ.get("HTTP_COOKIE", None) - logger.info("<application> PATH: %s" % path) + logger.info("<application> PATH: %s", path) if kaka: logger.info("= KAKA =") @@ -900,7 +900,7 @@ def application(environ, start_response): else: try: query = parse_qs(environ["QUERY_STRING"]) - logger.debug("QUERY: %s" % query) + logger.debug("QUERY: %s", query) user = IDP.cache.uid2user[query["id"][0]] except KeyError: user = None @@ -919,7 +919,7 @@ def application(environ, start_response): except IndexError: environ['myapp.url_args'] = path - logger.debug("Callback: %s" % (callback,)) + logger.debug("Callback: %s", (callback,)) if isinstance(callback, tuple): cls = callback[0](environ, start_response, user) func = getattr(cls, callback[1]) diff --git a/example/sp-repoze/sp.py b/example/sp-repoze/sp.py index 49e38dc6..b6539e03 100755 --- a/example/sp-repoze/sp.py +++ b/example/sp-repoze/sp.py @@ -37,7 +37,7 @@ def dict_to_table(ava, lev=0, width=1): txt.append("<td>%s</td>\n" % valarr) elif isinstance(valarr, list): i = 0 - n = len(valarr) + n = len(valarr) for val in valarr: if not i: txt.append("<th rowspan=%d>%s</td>\n" % (len(valarr), prop)) @@ -105,7 +105,7 @@ def whoami(environ, start_response, user): response.extend("<a href='logout'>Logout</a>") resp = Response(response) return resp(environ, start_response) - + #noinspection PyUnusedLocal def not_found(environ, start_response): @@ -128,7 +128,7 @@ def slo(environ, start_response, user): if "QUERY_STRING" in environ: query = parse_qs(environ["QUERY_STRING"]) - logger.info("query: %s" % query) + logger.info("query: %s", query) try: response = sc.parse_logout_request_response( query["SAMLResponse"][0], binding=BINDING_HTTP_REDIRECT) @@ -147,19 +147,19 @@ def slo(environ, start_response, user): headers.append(delco) resp = Redirect("/done", headers=headers) return resp(environ, start_response) - + #noinspection PyUnusedLocal def logout(environ, start_response, user): # This is where it starts when a user wants to log out client = environ['repoze.who.plugins']["saml2auth"] subject_id = environ["repoze.who.identity"]['repoze.who.userid'] - logger.info("[logout] subject_id: '%s'" % (subject_id,)) + logger.info("[logout] subject_id: '%s'", subject_id) target = "/done" # What if more than one _dict = client.saml_client.global_logout(subject_id) - logger.info("[logout] global_logout > %s" % (_dict,)) + logger.info("[logout] global_logout > %s", _dict) rem = environ['repoze.who.plugins'][client.rememberer_name] rem.forget(environ, subject_id) @@ -180,15 +180,15 @@ def logout(environ, start_response, user): #noinspection PyUnusedLocal def done(environ, start_response, user): # remove cookie and stored info - logger.info("[done] environ: %s" % environ) + logger.info("[done] environ: %s", environ) subject_id = environ["repoze.who.identity"]['repoze.who.userid'] client = environ['repoze.who.plugins']["saml2auth"] - logger.info("[logout done] remaining subjects: %s" % ( - client.saml_client.users.subjects(),)) + logger.info("[logout done] remaining subjects: %s", + client.saml_client.users.subjects()) start_response('200 OK', [('Content-Type', 'text/html')]) return ["<h3>You are now logged out from this service</h3>"] - + # ---------------------------------------------------------------------------- # map urls to functions @@ -215,7 +215,7 @@ def metadata(environ, start_response): start_response('200 OK', [('Content-Type', "text/xml")]) return metadata except Exception as ex: - logger.error("An error occured while creating metadata:" + ex.message) + logger.error("An error occured while creating metadata: %s", ex.message) return not_found(environ, start_response) def application(environ, start_response): @@ -226,14 +226,14 @@ def application(environ, start_response): the functions from above can access the url placeholders. If nothing matches, call the `not_found` function. - + :param environ: The HTTP application environment - :param start_response: The application to run when the handling of the + :param start_response: The application to run when the handling of the request is done :return: The response as a list of lines """ path = environ.get('PATH_INFO', '').lstrip('/') - logger.info("<application> PATH: %s" % path) + logger.info("<application> PATH: %s", path) if path == "metadata": return metadata(environ, start_response) @@ -241,9 +241,9 @@ def application(environ, start_response): user = environ.get("REMOTE_USER", "") if not user: user = environ.get("repoze.who.identity", "") - logger.info("repoze.who.identity: '%s'" % user) + logger.info("repoze.who.identity: '%s'", user) else: - logger.info("REMOTE_USER: '%s'" % user) + logger.info("REMOTE_USER: '%s'", user) #logger.info(logging.Logger.manager.loggerDict) for regex, callback in urls: if user: diff --git a/example/sp-wsgi/sp.py b/example/sp-wsgi/sp.py index 94615750..f5fcb4a7 100755 --- a/example/sp-wsgi/sp.py +++ b/example/sp-wsgi/sp.py @@ -168,7 +168,7 @@ class Cache(object): def get_user(self, environ): cookie = environ.get("HTTP_COOKIE", '') cookie = cookie.decode("UTF-8") - logger.debug("Cookie: %s" % cookie) + logger.debug("Cookie: %s", cookie) if cookie: cookie_obj = SimpleCookie(cookie) morsel = cookie_obj.get(self.cookie_name, None) @@ -184,7 +184,7 @@ class Cache(object): def delete_cookie(self, environ): cookie = environ.get("HTTP_COOKIE", '') - logger.debug("delete cookie: %s" % cookie) + logger.debug("delete cookie: %s", cookie) if cookie: _name = self.cookie_name cookie_obj = SimpleCookie(cookie) @@ -192,7 +192,7 @@ class Cache(object): cookie = SimpleCookie() cookie[_name] = "" cookie[_name]['path'] = "/" - logger.debug("Expire: %s" % morsel) + logger.debug("Expire: %s", morsel) cookie[_name]["expires"] = _expiration("now") return cookie.output().split(": ", 1) return None @@ -204,7 +204,7 @@ class Cache(object): cookie[self.cookie_name] = uid cookie[self.cookie_name]['path'] = "/" cookie[self.cookie_name]["expires"] = _expiration(480) - logger.debug("Cookie expires: %s" % cookie[self.cookie_name]["expires"]) + logger.debug("Cookie expires: %s", cookie[self.cookie_name]["expires"]) return cookie.output().encode("UTF-8").split(": ", 1) @@ -216,11 +216,11 @@ class Cache(object): class Service(object): def __init__(self, environ, start_response, user=None): self.environ = environ - logger.debug("ENVIRON: %s" % environ) + logger.debug("ENVIRON: %s", environ) self.start_response = start_response self.user = user self.sp = None - + def unpack_redirect(self): if "QUERY_STRING" in self.environ: _qs = self.environ["QUERY_STRING"] @@ -230,7 +230,7 @@ class Service(object): def unpack_post(self): _dict = parse_qs(get_post(self.environ)) - logger.debug("unpack_post:: %s" % _dict) + logger.debug("unpack_post:: %s", _dict) try: return dict([(k, v[0]) for k, v in _dict.items()]) except Exception: @@ -250,11 +250,11 @@ class Service(object): _dict = self.unpack_post() else: _dict = None - logger.debug("_dict: %s" % _dict) + logger.debug("_dict: %s", _dict) return _dict def operation(self, _dict, binding): - logger.debug("_operation: %s" % _dict) + logger.debug("_operation: %s", _dict) if not _dict: resp = BadRequest('Error parsing request or no request') return resp(self.environ, self.start_response) @@ -312,7 +312,7 @@ class Service(object): """ logger.debug("- SOAP -") _dict = self.unpack_soap() - logger.debug("_dict: %s" % _dict) + logger.debug("_dict: %s", _dict) return self.operation(_dict, BINDING_SOAP) def uri(self): @@ -359,11 +359,11 @@ class ACS(Service): self.response = self.sp.parse_authn_request_response( response, binding, self.outstanding_queries, self.cache.outstanding_certs) except UnknownPrincipal as excp: - logger.error("UnknownPrincipal: %s" % (excp,)) + logger.error("UnknownPrincipal: %s", excp) resp = ServiceError("UnknownPrincipal: %s" % (excp,)) return resp(self.environ, self.start_response) except UnsupportedBinding as excp: - logger.error("UnsupportedBinding: %s" % (excp,)) + logger.error("UnsupportedBinding: %s", excp) resp = ServiceError("UnsupportedBinding: %s" % (excp,)) return resp(self.environ, self.start_response) except VerificationError as err: @@ -373,7 +373,7 @@ class ACS(Service): resp = ServiceError("Other error: %s" % (err,)) return resp(self.environ, self.start_response) - logger.info("AVA: %s" % self.response.ava) + logger.info("AVA: %s", self.response.ava) user = User(self.response.name_id, self.response.ava) cookie = self.cache.set_cookie(user) @@ -384,7 +384,7 @@ class ACS(Service): return resp(self.environ, self.start_response) def verify_attributes(self, ava): - logger.info("SP: %s" % self.sp.config.entityid) + logger.info("SP: %s", self.sp.config.entityid) rest = POLICY.get_entity_categories( self.sp.config.entityid, self.sp.metadata) @@ -446,7 +446,7 @@ class SSO(object): def _wayf_redirect(self, came_from): sid_ = sid() self.cache.outstanding_queries[sid_] = came_from - logger.debug("Redirect to WAYF function: %s" % self.wayf) + logger.debug("Redirect to WAYF function: %s", self.wayf) return -1, SeeOther(headers=[('Location', "%s?%s" % (self.wayf, sid_))]) def _pick_idp(self, came_from): @@ -457,7 +457,7 @@ class SSO(object): _cli = self.sp - logger.debug("[_pick_idp] %s" % self.environ) + logger.debug("[_pick_idp] %s", self.environ) if "HTTP_PAOS" in self.environ: if self.environ["HTTP_PAOS"] == PAOS_HEADER_INFO: if 'application/vnd.paos+xml' in self.environ["HTTP_ACCEPT"]: @@ -474,7 +474,7 @@ class SSO(object): if not _entityid: return -1, ServiceError("No IdP to talk to") - logger.debug("IdP to talk to: %s" % _entityid) + logger.debug("IdP to talk to: %s", _entityid) return ecp.ecp_auth_request(_cli, _entityid, _rstate) else: return -1, ServiceError('Faulty Accept header') @@ -504,7 +504,7 @@ class SSO(object): if _idp_entity_id in idps: idp_entity_id = _idp_entity_id except KeyError: - logger.debug("No IdP entity ID in query: %s" % query) + logger.debug("No IdP entity ID in query: %s", query) pass if not idp_entity_id: @@ -542,7 +542,7 @@ class SSO(object): else: return -1, NotImplemented("No WAYF or DS present!") - logger.info("Chosen IdP: '%s'" % idp_entity_id) + logger.info("Chosen IdP: '%s'", idp_entity_id) return 0, idp_entity_id def redirect_to_auth(self, _cli, entity_id, came_from, sigalg=""): @@ -551,8 +551,8 @@ class SSO(object): _binding, destination = _cli.pick_binding( "single_sign_on_service", self.bindings, "idpsso", entity_id=entity_id) - logger.debug("binding: %s, destination: %s" % (_binding, - destination)) + logger.debug("binding: %s, destination: %s", _binding, + destination) # Binding here is the response binding that is which binding the # IDP should use to return the response. acs = _cli.config.getattr("endpoints", "sp")[ @@ -601,14 +601,14 @@ class SSO(object): # Which page was accessed to get here came_from = geturl(self.environ) - logger.debug("[sp.challenge] RelayState >> '%s'" % came_from) + logger.debug("[sp.challenge] RelayState >> '%s'", came_from) # If more than one idp and if none is selected, I have to do wayf (done, response) = self._pick_idp(came_from) # Three cases: -1 something went wrong or Discovery service used # 0 I've got an IdP to send a request to # >0 ECP in progress - logger.debug("_idp_pick returned: %s" % done) + logger.debug("_idp_pick returned: %s", done) if done == -1: return response(self.environ, self.start_response) elif done > 0: @@ -686,11 +686,11 @@ def logout(environ, start_response, sp): sso = SSO(sp, environ, start_response, cache=CACHE, **ARGS) return sso.do() - logger.info("[logout] subject_id: '%s'" % (user.name_id,)) + logger.info("[logout] subject_id: '%s'", user.name_id) # What if more than one data = sp.global_logout(user.name_id) - logger.info("[logout] global_logout > %s" % data) + logger.info("[logout] global_logout > %s", data) for entity_id, logout_info in data.items(): if isinstance(logout_info, tuple): @@ -718,8 +718,8 @@ def logout(environ, start_response, sp): def finish_logout(environ, start_response): - logger.info("[logout done] environ: %s" % environ) - logger.info("[logout done] remaining subjects: %s" % CACHE.uid2user.values()) + logger.info("[logout done] environ: %s", environ) + logger.info("[logout done] remaining subjects: %s", CACHE.uid2user.values()) # remove cookie and stored info cookie = CACHE.delete_cookie(environ) @@ -771,7 +771,7 @@ def metadata(environ, start_response): start_response('200 OK', [('Content-Type', "text/xml")]) return metadata except Exception as ex: - logger.error("An error occured while creating metadata:" + ex.message) + logger.error("An error occured while creating metadata: %s", ex.message) return not_found(environ, start_response) def application(environ, start_response): @@ -780,14 +780,14 @@ def application(environ, start_response): the functions from above. If nothing matches, call the `not_found` function. - + :param environ: The HTTP application environment - :param start_response: The application to run when the handling of the + :param start_response: The application to run when the handling of the request is done :return: The response as a list of lines """ path = environ.get('PATH_INFO', '').lstrip('/') - logger.debug("<application> PATH: '%s'" % path) + logger.debug("<application> PATH: '%s'", path) if path == "metadata": return metadata(environ, start_response) diff --git a/src/idp_test/base.py b/src/idp_test/base.py index aebb38a8..4707147d 100644 --- a/src/idp_test/base.py +++ b/src/idp_test/base.py @@ -115,18 +115,18 @@ class Conversation(tool.Conversation): if use_artifact: saml_art = _client.use_artifact(str_req, self.args["entity_id"]) - logger.info("SAML Artifact: %s" % saml_art) + logger.info("SAML Artifact: %s", saml_art) info_typ = "SAMLart" else: - logger.info("SAML Request: %s" % str_req) + logger.info("SAML Request: %s", str_req) info_typ = "SAMLRequest" # depending on binding send the query if self.args["request_binding"] is BINDING_SOAP: res = _client.send_using_soap(str_req, loc) if res.status_code >= 400: - logger.info("Received a HTTP error (%d) '%s'" % ( - res.status_code, res.text)) + logger.info("Received a HTTP error (%d) '%s'", + res.status_code, res.text) raise HTTPError(res.text) else: self.response_args["binding"] = BINDING_SOAP @@ -156,8 +156,8 @@ class Conversation(tool.Conversation): res = None if res is not None and res.status_code >= 400: - logger.info("Received a HTTP error (%d) '%s'" % ( - res.status_code, res.text)) + logger.info("Received a HTTP error (%d) '%s'", + res.status_code, res.text) raise HTTPError(res.text) self.last_response = res @@ -240,11 +240,11 @@ class Conversation(tool.Conversation): self.test_sequence(self.oper.tests["post"]) except KeyError: pass - logger.info("SAML Response: %s" % _resp) + logger.info("SAML Response: %s", _resp) except FatalError as ferr: if _resp: - logger.info("Faulty response: %s" % _resp) - logger.error("Exception %s" % ferr) + logger.info("Faulty response: %s", _resp) + logger.error("Exception %s", ferr) raise except ElementTree.ParseError: return False @@ -252,8 +252,8 @@ class Conversation(tool.Conversation): raise except Exception as err: if _resp: - logger.info("Faulty response: %s" % _resp) - logger.error("Exception %s" % err) + logger.info("Faulty response: %s", _resp) + logger.error("Exception %s", err) self.err_check("exception", err) - return True
\ No newline at end of file + return True diff --git a/src/idp_test/check.py b/src/idp_test/check.py index 156b216a..ab115ea9 100644 --- a/src/idp_test/check.py +++ b/src/idp_test/check.py @@ -548,7 +548,7 @@ class VerifyAttributeNameFormat(Check): try: assert attr.name_format == conv.msg_constraints[ "name_format"] - logger.debug("Attribute name format valid: " + + logger.debug("Attribute name format valid: %s", attr.name_format) except AssertionError: if NAME_FORMAT_UNSPECIFIED != conv.msg_constraints[ diff --git a/src/idp_test/interaction.py b/src/idp_test/interaction.py index 2fbc46ba..2eddc70c 100644 --- a/src/idp_test/interaction.py +++ b/src/idp_test/interaction.py @@ -380,8 +380,8 @@ class Operation(object): _args["location"] = location _args["features"] = features - logger.info("--> FUNCTION: %s" % self.function.__name__) - logger.info("--> ARGS: %s" % _args) + logger.info("--> FUNCTION: %s", self.function.__name__) + logger.info("--> ARGS: %s", _args) result = self.function(httpc, response, **_args) self.post_op(result, conv, _args) diff --git a/src/saml2/assertion.py b/src/saml2/assertion.py index 795c0cd8..c9d138bf 100644 --- a/src/saml2/assertion.py +++ b/src/saml2/assertion.py @@ -356,7 +356,7 @@ class Policy(object): _are[key.lower()] = [re.compile(value) for value in values] spec["attribute_restrictions"] = _are - logger.debug("policy restrictions: %s" % self._restrictions) + logger.debug("policy restrictions: %s", self._restrictions) return self._restrictions @@ -486,7 +486,7 @@ class Policy(object): _ava = None if required or optional: - logger.debug("required: %s, optional: %s" % (required, optional)) + logger.debug("required: %s, optional: %s", required, optional) _ava = filter_on_attributes( ava.copy(), required, optional, self.acs, self.get_fail_on_missing_requested(sp_entity_id)) diff --git a/src/saml2/attribute_converter.py b/src/saml2/attribute_converter.py index de68f22a..5a1b3715 100644 --- a/src/saml2/attribute_converter.py +++ b/src/saml2/attribute_converter.py @@ -133,8 +133,8 @@ def to_local(acs, statement, allow_unknown_attributes=False): allow_unknown_attributes: _func = acs[0].lcd_ava_from else: - logger.info("Unsupported attribute name format: %s" % ( - attr.name_format,)) + logger.info("Unsupported attribute name format: %s", + attr.name_format) continue try: @@ -143,7 +143,7 @@ def to_local(acs, statement, allow_unknown_attributes=False): if allow_unknown_attributes: key, val = acs[0].lcd_ava_from(attr) else: - logger.info("Unknown attribute name: %s" % (attr,)) + logger.info("Unknown attribute name: %s", attr) continue except AttributeError: continue @@ -180,8 +180,8 @@ def list_to_local(acs, attrlist, allow_unknown_attributes=False): allow_unknown_attributes: _func = acs[0].lcd_ava_from else: - logger.info("Unsupported attribute name format: %s" % ( - attr.name_format,)) + logger.info("Unsupported attribute name format: %s", + attr.name_format) continue try: @@ -190,7 +190,7 @@ def list_to_local(acs, attrlist, allow_unknown_attributes=False): if allow_unknown_attributes: key, val = acs[0].lcd_ava_from(attr) else: - logger.info("Unknown attribute name: %s" % (attr,)) + logger.info("Unknown attribute name: %s", attr) continue except AttributeError: continue diff --git a/src/saml2/attribute_resolver.py b/src/saml2/attribute_resolver.py index 7d7f4fb6..18a66100 100644 --- a/src/saml2/attribute_resolver.py +++ b/src/saml2/attribute_resolver.py @@ -37,7 +37,7 @@ class AttributeResolver(object): for ass in self.metadata.attribute_consuming_service(member): for attr_serv in ass.attribute_service: logger.info( - "Send attribute request to %s" % attr_serv.location) + "Send attribute request to %s", attr_serv.location) if attr_serv.binding != BINDING_SOAP: continue # attribute query assumes SOAP binding diff --git a/src/saml2/client.py b/src/saml2/client.py index 64871d62..baee02f3 100644 --- a/src/saml2/client.py +++ b/src/saml2/client.py @@ -111,7 +111,7 @@ class Saml2Client(Base): continue destination = self._sso_location(entityid, binding) - logger.info("destination to provider: %s" % destination) + logger.info("destination to provider: %s", destination) reqid, request = self.create_authn_request( destination, vorg, scoping, response_binding, nameid_format, @@ -120,7 +120,7 @@ class Saml2Client(Base): _req_str = str(request) - logger.info("AuthNReq: %s" % _req_str) + logger.info("AuthNReq: %s", _req_str) try: sigalg = kwargs["sigalg"] @@ -156,7 +156,7 @@ class Saml2Client(Base): if isinstance(name_id, six.string_types): name_id = decode(name_id) - logger.info("logout request for: %s" % name_id) + logger.info("logout request for: %s", name_id) # find out which IdPs/AAs I should notify entity_ids = self.users.issuers_of_info(name_id) @@ -187,7 +187,7 @@ class Saml2Client(Base): responses = {} for entity_id in entity_ids: - logger.debug("Logout from '%s'" % entity_id) + logger.debug("Logout from '%s'", entity_id) # for all where I can use the SOAP binding, do those first for binding in [BINDING_SOAP, BINDING_HTTP_POST, BINDING_HTTP_REDIRECT]: @@ -201,11 +201,11 @@ class Saml2Client(Base): srvs = None if not srvs: - logger.debug("No SLO '%s' service" % binding) + logger.debug("No SLO '%s' service", binding) continue destination = destinations(srvs)[0] - logger.info("destination to provider: %s" % destination) + logger.info("destination to provider: %s", destination) try: session_info = self.users.get_info_from(name_id, entity_id) session_indexes = [session_info['session_index']] @@ -246,12 +246,12 @@ class Saml2Client(Base): if response and response.status_code == 200: not_done.remove(entity_id) response = response.text - logger.info("Response: %s" % response) + logger.info("Response: %s", response) res = self.parse_logout_request_response(response, binding) responses[entity_id] = res else: - logger.info("NOT OK response from %s" % destination) + logger.info("NOT OK response from %s", destination) else: self.state[req_id] = {"entity_id": entity_id, @@ -298,11 +298,11 @@ class Saml2Client(Base): response message, response headers and message) """ - logger.info("state: %s" % (self.state,)) + logger.info("state: %s", self.state) status = self.state[response.in_response_to] - logger.info("status: %s" % (status,)) + logger.info("status: %s", status) issuer = response.issuer() - logger.info("issuer: %s" % issuer) + logger.info("issuer: %s", issuer) del self.state[response.in_response_to] if status["entity_ids"] == [issuer]: # done self.local_logout(decode(status["name_id"])) @@ -343,10 +343,10 @@ class Saml2Client(Base): if response: # not_done.remove(entity_id) - logger.info("OK response from %s" % destination) + logger.info("OK response from %s", destination) return response else: - logger.info("NOT OK response from %s" % destination) + logger.info("NOT OK response from %s", destination) return None @@ -497,7 +497,7 @@ class Saml2Client(Base): 'method': "POST } """ - logger.info("logout request: %s" % request) + logger.info("logout request: %s", request) _req = self._parse_request(request, LogoutRequest, "single_logout_service", binding) diff --git a/src/saml2/client_base.py b/src/saml2/client_base.py index b499e19d..cbecd1d7 100644 --- a/src/saml2/client_base.py +++ b/src/saml2/client_base.py @@ -140,7 +140,7 @@ class Base(Entity): if srvs: return destinations(srvs)[0] else: - logger.info("_sso_location: %s, %s" % (entityid, binding)) + logger.info("_sso_location: %s, %s", entityid, binding) raise IdpUnspecified("No IdP to send to given the premises") # get the idp location from the metadata. If there is more than one @@ -580,12 +580,12 @@ class Base(Entity): "assertion_consumer_service", binding, **kwargs) except StatusError as err: - logger.error("SAML status error: %s" % err) + logger.error("SAML status error: %s", err) raise except UnravelError: return None except Exception as err: - logger.error("XML parse error: %s" % err) + logger.error("XML parse error: %s", err) raise if resp is None: @@ -596,8 +596,7 @@ class Base(Entity): logger.info("--- ADDED person info ----") pass else: - logger.error("Response type not supported: %s" % ( - saml2.class_name(resp),)) + logger.error("Response type not supported: %s", saml2.class_name(resp)) return resp # ------------------------------------------------------------------------ @@ -701,7 +700,7 @@ class Base(Entity): _binding = BINDING_SOAP kwargs["binding"] = _binding - logger.debug("entityid: %s, binding: %s" % (entityid, _binding)) + logger.debug("entityid: %s, binding: %s", entityid, _binding) # The IDP publishes support for ECP by using the SOAP binding on # SingleSignOnService diff --git a/src/saml2/ecp_client.py b/src/saml2/ecp_client.py index c41a046a..90c3b44c 100644 --- a/src/saml2/ecp_client.py +++ b/src/saml2/ecp_client.py @@ -74,7 +74,7 @@ class Client(Entity): if metadata_file: self._metadata = MetadataStore([saml, samlp], None, config) self._metadata.load("local", metadata_file) - logger.debug("Loaded metadata from '%s'" % metadata_file) + logger.debug("Loaded metadata from '%s'", metadata_file) else: self._metadata = None @@ -109,12 +109,12 @@ class Client(Entity): if headers: ht_args["headers"].extend(headers) - logger.debug("[P2] Sending request: %s" % ht_args["data"]) + logger.debug("[P2] Sending request: %s", ht_args["data"]) # POST the request to the IdP response = self.send(**ht_args) - logger.debug("[P2] Got IdP response: %s" % response) + logger.debug("[P2] Got IdP response: %s", response) if response.status_code != 200: raise SAMLError( @@ -127,12 +127,12 @@ class Client(Entity): if respdict is None: raise SAMLError("Unexpected reply from the IdP") - logger.debug("[P2] IdP response dict: %s" % respdict) + logger.debug("[P2] IdP response dict: %s", respdict) idp_response = respdict["body"] assert idp_response.c_tag == "Response" - logger.debug("[P2] IdP AUTHN response: %s" % idp_response) + logger.debug("[P2] IdP AUTHN response: %s", idp_response) _ecp_response = None for item in respdict["header"]: @@ -155,7 +155,7 @@ class Client(Entity): if respdict is None: raise SAMLError("Unexpected reply from the SP") - logger.debug("[P1] SP response dict: %s" % respdict) + logger.debug("[P1] SP response dict: %s", respdict) # AuthnRequest in the body or not authn_request = respdict["body"] @@ -201,7 +201,7 @@ class Client(Entity): ht_args = self.use_soap(idp_response, args["rc_url"], [args["relay_state"]]) - logger.debug("[P3] Post to SP: %s" % ht_args["data"]) + logger.debug("[P3] Post to SP: %s", ht_args["data"]) ht_args["headers"].append(('Content-Type', 'application/vnd.paos+xml')) @@ -217,7 +217,7 @@ class Client(Entity): raise SAMLError( "Error POSTing package to SP: %s" % response.error) - logger.debug("[P3] SP response: %s" % response.text) + logger.debug("[P3] SP response: %s", response.text) self.done_ecp = True logger.debug("Done ECP") @@ -266,7 +266,7 @@ class Client(Entity): opargs["headers"] = self.add_paos_headers(opargs["headers"]) response = self.send(url, op, **opargs) - logger.debug("[Op] SP response: %s" % response) + logger.debug("[Op] SP response: %s", response) if response.status_code != 200: raise SAMLError( diff --git a/src/saml2/entity.py b/src/saml2/entity.py index 60de964f..4d0c548a 100644 --- a/src/saml2/entity.py +++ b/src/saml2/entity.py @@ -109,7 +109,7 @@ def create_artifact(entity_id, message_handle, endpoint_index=0): if not isinstance(message_handle, six.binary_type): message_handle = message_handle.encode('utf-8') - ter = b"".join((ARTIFACT_TYPECODE, + ter = b"".join((ARTIFACT_TYPECODE, ("%.2x" % endpoint_index).encode('ascii'), sourceid.digest(), message_handle)) @@ -283,11 +283,10 @@ class Entity(HTTPBase): except UnsupportedBinding: pass - logger.error("Failed to find consumer URL: %s, %s, %s" % (entity_id, - bindings, - descr_type)) - #logger.error("Bindings: %s" % bindings) - #logger.error("Entities: %s" % self.metadata) + logger.error("Failed to find consumer URL: %s, %s, %s", + entity_id, bindings, descr_type) + #logger.error("Bindings: %s", bindings) + #logger.error("Entities: %s", self.metadata) raise SAMLError("Unknown entity or unsupported bindings") @@ -363,7 +362,7 @@ class Entity(HTTPBase): :param msgtype: :return: """ - #logger.debug("unravel '%s'" % txt) + #logger.debug("unravel '%s'", txt) if binding not in [BINDING_HTTP_REDIRECT, BINDING_HTTP_POST, BINDING_SOAP, BINDING_URI, BINDING_HTTP_ARTIFACT, None]: @@ -424,7 +423,7 @@ class Entity(HTTPBase): except (AttributeError, TypeError): to_sign = [(class_name(msg), mid)] - logger.info("REQUEST: %s" % msg) + logger.info("REQUEST: %s", msg) return signed_instance_factory(msg, self.sec, to_sign) def _message(self, request_cls, destination=None, message_id=0, @@ -470,7 +469,7 @@ class Entity(HTTPBase): if sign: return reqid, self.sign(req, sign_prepare=sign_prepare) else: - logger.info("REQUEST: %s" % req) + logger.info("REQUEST: %s", req) return reqid, req @staticmethod @@ -758,8 +757,8 @@ class Entity(HTTPBase): if receiver_addresses: break - _log_debug("receiver addresses: %s" % receiver_addresses) - _log_debug("Binding: %s" % binding) + _log_debug("receiver addresses: %s", receiver_addresses) + _log_debug("Binding: %s", binding) try: timeslack = self.config.accepted_time_diff @@ -888,7 +887,7 @@ class Entity(HTTPBase): response = self._status_response(samlp.LogoutResponse, issuer, status, sign, **rinfo) - logger.info("Response: %s" % (response,)) + logger.info("Response: %s", response) return response @@ -925,7 +924,7 @@ class Entity(HTTPBase): msg = element_to_extension_element(self.artifact[artifact]) response.extension_elements = [msg] - logger.info("Response: %s" % (response,)) + logger.info("Response: %s", response) return response @@ -993,7 +992,7 @@ class Entity(HTTPBase): response = self._status_response(samlp.ManageNameIDResponse, issuer, status, sign, **rinfo) - logger.info("Response: %s" % (response,)) + logger.info("Response: %s", response) return response @@ -1044,7 +1043,7 @@ class Entity(HTTPBase): try: response = response_cls(self.sec, **kwargs) except Exception as exc: - logger.info("%s" % exc) + logger.info("%s", exc) raise xmlstr = self.unravel(xmlstr, binding, response_cls.msgtype) @@ -1055,7 +1054,7 @@ class Entity(HTTPBase): try: response = response.loads(xmlstr, False, origxml=origxml) except SigverError as err: - logger.error("Signature Error: %s" % err) + logger.error("Signature Error: %s", err) raise except UnsolicitedResponse: logger.error("Unsolicited response") @@ -1065,7 +1064,7 @@ class Entity(HTTPBase): logger.error("Not well-formed XML") raise - logger.debug("XMLSTR: %s" % xmlstr) + logger.debug("XMLSTR: %s", xmlstr) if response: keys = None diff --git a/src/saml2/httpbase.py b/src/saml2/httpbase.py index 2fd00151..016e0ff4 100644 --- a/src/saml2/httpbase.py +++ b/src/saml2/httpbase.py @@ -151,7 +151,7 @@ class HTTPBase(object): part = urlparse(request.url) _domain = part.hostname - logger.debug("%s: '%s'" % (_domain, kaka)) + logger.debug("%s: '%s'", _domain, kaka) for cookie_name, morsel in kaka.items(): std_attr = ATTRS.copy() @@ -228,14 +228,14 @@ class HTTPBase(object): _kwargs["headers"] = dict(_kwargs["headers"]) try: - logger.debug("%s to %s" % (method, url)) + logger.debug("%s to %s", method, url) for arg in ["cookies", "data", "auth"]: try: - logger.debug("%s: %s" % (arg.upper(), _kwargs[arg])) + logger.debug("%s: %s", arg.upper(), _kwargs[arg]) except KeyError: pass r = requests.request(method, url, **_kwargs) - logger.debug("Response status: %s" % r.status_code) + logger.debug("Response status: %s", r.status_code) except requests.ConnectionError as exc: raise ConnectionError("%s" % exc) @@ -325,7 +325,7 @@ class HTTPBase(object): soap_message = make_soap_enveloped_saml_thingy(request, soap_headers) - logger.debug("SOAP message: %s" % soap_message) + logger.debug("SOAP message: %s", soap_message) if sign and self.sec: _signed = self.sec.sign_statement(soap_message, @@ -353,11 +353,11 @@ class HTTPBase(object): args["headers"] = dict(args["headers"]) response = self.send(**args) except Exception as exc: - logger.info("HTTPClient exception: %s" % (exc,)) + logger.info("HTTPClient exception: %s", exc) raise if response.status_code == 200: - logger.info("SOAP response: %s" % response.text) + logger.info("SOAP response: %s", response.text) return response else: raise HTTPError("%d:%s" % (response.status_code, response.content)) diff --git a/src/saml2/ident.py b/src/saml2/ident.py index 502f1315..b6af8e99 100644 --- a/src/saml2/ident.py +++ b/src/saml2/ident.py @@ -184,7 +184,7 @@ class IdentDB(object): try: _vals = self.db[userid] except KeyError: - logger.debug("failed to find userid %s in IdentDB" % userid) + logger.debug("failed to find userid %s in IdentDB", userid) return res for val in _vals.split(" "): @@ -211,8 +211,8 @@ class IdentDB(object): :return: """ - logger.debug("local_policy: %s, name_id_policy: %s" % (local_policy, - name_id_policy)) + logger.debug("local_policy: %s, name_id_policy: %s", local_policy, + name_id_policy) if name_id_policy and name_id_policy.sp_name_qualifier: sp_name_qualifier = name_id_policy.sp_name_qualifier @@ -280,8 +280,8 @@ class IdentDB(object): try: return self.db[name_id.text] except KeyError: - logger.debug("name: %s" % name_id.text) - #logger.debug("id sub keys: %s" % self.subkeys()) + logger.debug("name: %s", name_id.text) + #logger.debug("id sub keys: %s", self.subkeys()) return None def match_local_id(self, userid, sp_name_qualifier, name_qualifier): diff --git a/src/saml2/mdstore.py b/src/saml2/mdstore.py index 09531abc..ad70a689 100644 --- a/src/saml2/mdstore.py +++ b/src/saml2/mdstore.py @@ -330,7 +330,7 @@ class InMemoryMetaData(MetaData): self.filter = kwargs["filter"] except KeyError: self.filter = None - + def items(self): return self.entity.items() @@ -359,15 +359,15 @@ class InMemoryMetaData(MetaData): if self.check_validity: try: if not valid(entity_descr.valid_until): - logger.error("Entity descriptor (entity id:%s) to old" % ( - entity_descr.entity_id,)) + logger.error("Entity descriptor (entity id:%s) to old", + entity_descr.entity_id) return except AttributeError: pass # have I seen this entity_id before ? If so if log: ignore it if entity_descr.entity_id in self.entity: - print("Duplicated Entity descriptor (entity id: '%s')" % + print("Duplicated Entity descriptor (entity id: '%s')" % entity_descr.entity_id, file=sys.stderr) return @@ -416,7 +416,7 @@ class InMemoryMetaData(MetaData): try: valid_instance(self.entities_descr) except NotValid as exc: - logger.error(exc.args[0]) + logger.error("Invalid XML message: %s", exc.args[0]) return if self.check_validity: @@ -467,7 +467,7 @@ class InMemoryMetaData(MetaData): res[srv["binding"]].append(srv) except KeyError: res[srv["binding"]] = [srv] - logger.debug("service => %s" % res) + logger.debug("service => %s", res) return res def attribute_requirement(self, entity_id, index=None): @@ -677,7 +677,7 @@ class MetaDataExtern(InMemoryMetaData): _txt = response.text.encode("utf-8") return self.parse_and_check_signature(_txt) else: - logger.info("Response status: %s" % response.status_code) + logger.info("Response status: %s", response.status_code) return False @@ -741,7 +741,7 @@ class MetaDataMDX(InMemoryMetaData): if self.parse_and_check_signature(_txt): return self.entity[item] else: - logger.info("Response status: %s" % response.status_code) + logger.info("Response status: %s", response.status_code) raise KeyError @@ -878,8 +878,8 @@ class MetadataStore(object): def service(self, entity_id, typ, service, binding=None): known_entity = False - logger.debug("service(%s, %s, %s, %s)" % (entity_id, typ, service, - binding)) + logger.debug("service(%s, %s, %s, %s)", entity_id, typ, service, + binding) for key, _md in self.metadata.items(): srvs = _md.service(entity_id, typ, service, binding) if srvs: @@ -890,10 +890,10 @@ class MetadataStore(object): known_entity = True if known_entity: - logger.error("Unsupported binding: %s (%s)" % (binding, entity_id)) + logger.error("Unsupported binding: %s (%s)", binding, entity_id) raise UnsupportedBinding(binding) else: - logger.error("Unknown system entity: %s" % entity_id) + logger.error("Unknown system entity: %s", entity_id) raise UnknownSystemEntity(entity_id) def ext_service(self, entity_id, typ, service, binding=None): diff --git a/src/saml2/mongo_store.py b/src/saml2/mongo_store.py index ad9b0728..4171f707 100644 --- a/src/saml2/mongo_store.py +++ b/src/saml2/mongo_store.py @@ -113,7 +113,7 @@ class SessionStorageMDB(object): return result def remove_authn_statements(self, name_id): - logger.debug("remove authn about: %s" % name_id) + logger.debug("remove authn about: %s", name_id) key = sha1(code_binary(name_id)).hexdigest() for item in self.assertion.find({"name_id_key": key}): self.assertion.remove(item["_id"]) diff --git a/src/saml2/pack.py b/src/saml2/pack.py index 91b6f976..3377c451 100644 --- a/src/saml2/pack.py +++ b/src/saml2/pack.py @@ -169,18 +169,18 @@ def make_soap_enveloped_saml_thingy(thingy, header_parts=None): if isinstance(thingy, six.string_types): # remove the first XML version/encoding line if thingy[0:5].lower() == '<?xml': - logger.debug("thingy0: %s" % thingy) + logger.debug("thingy0: %s", thingy) _part = thingy.split("\n") thingy = "".join(_part[1:]) thingy = thingy.replace(PREFIX, "") - logger.debug("thingy: %s" % thingy) + logger.debug("thingy: %s", thingy) _child = ElementTree.Element('') _child.tag = '{%s}FuddleMuddle' % DUMMY_NAMESPACE body.append(_child) _str = ElementTree.tostring(envelope, encoding="UTF-8") if isinstance(_str, six.binary_type): _str = _str.decode('utf-8') - logger.debug("SOAP precursor: %s" % _str) + logger.debug("SOAP precursor: %s", _str) # find an remove the namespace definition i = _str.find(DUMMY_NAMESPACE) j = _str.rfind("xmlns:", 0, i) diff --git a/src/saml2/request.py b/src/saml2/request.py index 8f8cbb79..479b993f 100644 --- a/src/saml2/request.py +++ b/src/saml2/request.py @@ -43,7 +43,7 @@ class Request(object): # own copy self.xmlstr = xmldata[:] - logger.debug("xmlstr: %s" % (self.xmlstr,)) + logger.debug("xmlstr: %s", self.xmlstr) try: self.message = self.signature_check(xmldata, origdoc=origdoc, must=must, @@ -55,15 +55,15 @@ class Request(object): if not self.message: logger.error("Response was not correctly signed") - logger.info(xmldata) + logger.info("Response: %s", xmldata) raise IncorrectlySigned() - logger.info("request: %s" % (self.message,)) + logger.info("request: %s", self.message) try: valid_instance(self.message) except NotValid as exc: - logger.error("Not valid request: %s" % exc.args[0]) + logger.error("Not valid request: %s", exc.args[0]) raise return self @@ -83,8 +83,8 @@ class Request(object): assert self.message.version == "2.0" if self.message.destination and self.receiver_addrs and \ self.message.destination not in self.receiver_addrs: - logger.error("%s not in %s" % (self.message.destination, - self.receiver_addrs)) + logger.error("%s not in %s", self.message.destination, + self.receiver_addrs) raise OtherError("Not destined for me!") assert self.issue_instant_ok() diff --git a/src/saml2/response.py b/src/saml2/response.py index be9f1fa7..810266cf 100644 --- a/src/saml2/response.py +++ b/src/saml2/response.py @@ -277,15 +277,15 @@ class StatusResponse(object): if not self.response: logger.error("Response was not correctly signed") if self.xmlstr: - logger.info(self.xmlstr) + logger.info("Response: %s", self.xmlstr) raise IncorrectlySigned() - logger.debug("response: %s" % (self.response,)) + logger.debug("response: %s", self.response) try: valid_instance(self.response) except NotValid as exc: - logger.error("Not valid response: %s" % exc.args[0]) + logger.error("Not valid response: %s", exc.args[0]) self._clear() return self @@ -311,7 +311,7 @@ class StatusResponse(object): # own copy self.xmlstr = xmldata[:] - logger.debug("xmlstr: %s" % (self.xmlstr,)) + logger.debug("xmlstr: %s", self.xmlstr) if origxml: self.origxml = origxml else: @@ -343,9 +343,9 @@ class StatusResponse(object): def status_ok(self): if self.response.status: status = self.response.status - logger.info("status: %s" % (status,)) + logger.info("status: %s", status) if status.status_code.value != samlp.STATUS_SUCCESS: - logger.info("Not successful operation: %s" % status) + logger.info("Not successful operation: %s", status) if status.status_code.status_code: excep = STATUSCODE2EXCEPTION[ status.status_code.status_code.value] @@ -376,8 +376,8 @@ class StatusResponse(object): def _verify(self): if self.request_id and self.in_response_to and \ self.in_response_to != self.request_id: - logger.error("Not the id I expected: %s != %s" % ( - self.in_response_to, self.request_id)) + logger.error("Not the id I expected: %s != %s", + self.in_response_to, self.request_id) return None try: @@ -392,8 +392,8 @@ class StatusResponse(object): if self.asynchop: if self.response.destination and \ self.response.destination not in self.return_addrs: - logger.error("%s not in %s" % (self.response.destination, - self.return_addrs)) + logger.error("%s not in %s", self.response.destination, + self.return_addrs) return None assert self.issue_instant_ok() @@ -563,7 +563,7 @@ class AuthnResponse(StatusResponse): assert self.assertion.conditions conditions = self.assertion.conditions - logger.debug("conditions: %s" % conditions) + logger.debug("conditions: %s", conditions) # if no sub-elements or elements are supplied, then the # assertion is considered to be valid. @@ -583,7 +583,7 @@ class AuthnResponse(StatusResponse): if conditions.not_before: validate_before(conditions.not_before, self.timeslack) except Exception as excp: - logger.error("Exception on conditions: %s" % (excp,)) + logger.error("Exception on conditions: %s", excp) if not lax: raise else: @@ -631,9 +631,9 @@ class AuthnResponse(StatusResponse): attribute_statement.attribute.extend(attrlist) def read_attribute_statement(self, attr_statem): - logger.debug("Attribute Statement: %s" % (attr_statem,)) + logger.debug("Attribute Statement: %s", attr_statem) for aconv in self.attribute_converters: - logger.debug("Converts name format: %s" % (aconv.name_format,)) + logger.debug("Converts name format: %s", aconv.name_format) self.decrypt_attributes(attr_statem) return to_local(self.attribute_converters, attr_statem, @@ -688,9 +688,9 @@ class AuthnResponse(StatusResponse): # This is where I don't allow unsolicited reponses # Either in_response_to == None or has a value I don't # recognize - logger.debug("in response to: '%s'" % data.in_response_to) - logger.info("outstanding queries: %s" % ( - self.outstanding_queries.keys(),)) + logger.debug("in response to: '%s'", data.in_response_to) + logger.info("outstanding queries: %s", + self.outstanding_queries.keys()) raise Exception( "Combination of session id and requestURI I don't " "recall") @@ -750,7 +750,7 @@ class AuthnResponse(StatusResponse): else: raise VerificationError("Missing NameID") - logger.info("Subject NameID: %s" % self.name_id) + logger.info("Subject NameID: %s", self.name_id) return self.name_id def _assertion(self, assertion, verified=False): @@ -770,13 +770,13 @@ class AuthnResponse(StatusResponse): try: self.sec.check_signature(assertion, class_name(assertion),self.xmlstr) except Exception as exc: - logger.error("correctly_signed_response: %s" % exc) + logger.error("correctly_signed_response: %s", exc) raise self.assertion = assertion - logger.debug("assertion context: %s" % (self.context,)) - logger.debug("assertion keys: %s" % (assertion.keyswv())) - logger.debug("outstanding_queries: %s" % (self.outstanding_queries,)) + logger.debug("assertion context: %s", self.context) + logger.debug("assertion keys: %s", assertion.keyswv()) + logger.debug("outstanding_queries: %s", self.outstanding_queries) #if self.context == "AuthnReq" or self.context == "AttrQuery": if self.context == "AuthnReq": @@ -791,7 +791,7 @@ class AuthnResponse(StatusResponse): #if self.context == "AuthnReq" or self.context == "AttrQuery": # self.ava = self.get_identity() - # logger.debug("--- AVA: %s" % (self.ava,)) + # logger.debug("--- AVA: %s", self.ava) try: self.get_subject() @@ -824,7 +824,7 @@ class AuthnResponse(StatusResponse): if not self.sec.check_signature( assertion, origdoc=decr_txt, node_name=class_name(assertion), issuer=issuer): - logger.error("Failed to verify signature on '%s'" % assertion) + logger.error("Failed to verify signature on '%s'", assertion) raise SignatureError() res.append(assertion) return res @@ -957,7 +957,7 @@ class AuthnResponse(StatusResponse): if self.context == "AuthnReq" or self.context == "AttrQuery": self.ava = self.get_identity() - logger.debug("--- AVA: %s" % (self.ava,)) + logger.debug("--- AVA: %s", self.ava) return True @@ -970,7 +970,7 @@ class AuthnResponse(StatusResponse): try: res = self._verify() except AssertionError as err: - logger.error("Verification error on the response: %s" % err) + logger.error("Verification error on the response: %s", err) raise else: if res is None: @@ -1197,7 +1197,7 @@ class AssertionIDResponse(object): def loads(self, xmldata, decode=True, origxml=None): # own copy self.xmlstr = xmldata[:] - logger.debug("xmlstr: %s" % (self.xmlstr,)) + logger.debug("xmlstr: %s", self.xmlstr) self.origxml = origxml try: @@ -1219,7 +1219,7 @@ class AssertionIDResponse(object): try: valid_instance(self.response) except NotValid as exc: - logger.error("Not valid response: %s" % exc.args[0]) + logger.error("Not valid response: %s", exc.args[0]) raise return self @@ -1227,10 +1227,10 @@ class AssertionIDResponse(object): if not self.response: logger.error("Response was not correctly signed") if self.xmlstr: - logger.info(self.xmlstr) + logger.info("Response: %s", self.xmlstr) raise IncorrectlySigned() - logger.debug("response: %s" % (self.response,)) + logger.debug("response: %s", self.response) return self diff --git a/src/saml2/s2repoze/plugins/formswithhidden.py b/src/saml2/s2repoze/plugins/formswithhidden.py index 143de198..8ec78592 100644 --- a/src/saml2/s2repoze/plugins/formswithhidden.py +++ b/src/saml2/s2repoze/plugins/formswithhidden.py @@ -45,7 +45,7 @@ class FormHiddenPlugin(FormPlugin): def identify(self, environ): logger = environ.get('repoze.who.logger','') logger.info("formplugin identify") - #logger and logger.info("environ keys: %s" % environ.keys()) + #logger and logger.info("environ keys: %s", environ.keys()) query = parse_dict_querystring(environ) # If the extractor finds a special query string on any request, # it will attempt to find the values in the input body. @@ -95,7 +95,7 @@ class FormHiddenPlugin(FormPlugin): for key, val in query.items(): hidden.append(HIDDEN_PRE_LINE % ("_%s_" % key, val)) - logger.info("hidden: %s" % (hidden,)) + logger.info("hidden: %s", hidden) form = self.formbody or _DEFAULT_FORM form = form % "\n".join(hidden) diff --git a/src/saml2/s2repoze/plugins/sp.py b/src/saml2/s2repoze/plugins/sp.py index 43c5983b..7c263d5b 100644 --- a/src/saml2/s2repoze/plugins/sp.py +++ b/src/saml2/s2repoze/plugins/sp.py @@ -148,14 +148,14 @@ class SAML2Plugin(object): post = parse_qs(body) # parse the POST fields into a dict - logger.debug('identify post: %s' % (post,)) + logger.debug('identify post: %s', post) return post def _wayf_redirect(self, came_from): sid_ = sid() self.outstanding_queries[sid_] = came_from - logger.info("Redirect to WAYF function: %s" % self.wayf) + logger.info("Redirect to WAYF function: %s", self.wayf) return -1, HTTPSeeOther(headers=[('Location', "%s?%s" % (self.wayf, sid_))]) @@ -175,7 +175,7 @@ class SAML2Plugin(object): _cli = self.saml_client - logger.info("[_pick_idp] %s" % environ) + logger.info("[_pick_idp] %s", environ) if "HTTP_PAOS" in environ: if environ["HTTP_PAOS"] == PAOS_HEADER_INFO: if 'application/vnd.paos+xml' in environ["HTTP_ACCEPT"]: @@ -191,7 +191,7 @@ class SAML2Plugin(object): if not _entityid: return -1, HTTPInternalServerError( detail="No IdP to talk to") - logger.info("IdP to talk to: %s" % _entityid) + logger.info("IdP to talk to: %s", _entityid) return ecp.ecp_auth_request(_cli, _entityid, _relay_state) else: @@ -203,7 +203,7 @@ class SAML2Plugin(object): idps = self.metadata.with_descriptor("idpsso") - logger.info("IdP URL: %s" % idps) + logger.info("IdP URL: %s", idps) idp_entity_id = query = None @@ -217,7 +217,7 @@ class SAML2Plugin(object): idp_entity_id = _idp_entity_id break except KeyError: - logger.debug("No IdP entity ID in query: %s" % query) + logger.debug("No IdP entity ID in query: %s", query) pass if idp_entity_id is None: @@ -228,7 +228,7 @@ class SAML2Plugin(object): return -1, HTTPInternalServerError(detail='Misconfiguration') else: idp_entity_id = "" - logger.info("ENVIRON: %s" % environ) + logger.info("ENVIRON: %s", environ) if self.wayf: if query: @@ -260,7 +260,7 @@ class SAML2Plugin(object): return -1, HTTPNotImplemented( detail='No WAYF or DJ present!') - logger.info("Chosen IdP: '%s'" % idp_entity_id) + logger.info("Chosen IdP: '%s'", idp_entity_id) return 0, idp_entity_id #### IChallenger #### @@ -290,7 +290,7 @@ class SAML2Plugin(object): # Which page was accessed to get here came_from = construct_came_from(environ) environ["myapp.came_from"] = came_from - logger.debug("[sp.challenge] RelayState >> '%s'" % came_from) + logger.debug("[sp.challenge] RelayState >> '%s'", came_from) # Am I part of a virtual organization or more than one ? try: @@ -301,14 +301,14 @@ class SAML2Plugin(object): except AttributeError: vorg_name = "" - logger.info("[sp.challenge] VO: %s" % vorg_name) + logger.info("[sp.challenge] VO: %s", vorg_name) # If more than one idp and if none is selected, I have to do wayf (done, response) = self._pick_idp(environ, came_from) # Three cases: -1 something went wrong or Discovery service used # 0 I've got an IdP to send a request to # >0 ECP in progress - logger.debug("_idp_pick returned: %s" % done) + logger.debug("_idp_pick returned: %s", done) if done == -1: return response elif done > 0: @@ -316,14 +316,14 @@ class SAML2Plugin(object): return ECP_response(response) else: entity_id = response - logger.info("[sp.challenge] entity_id: %s" % entity_id) + logger.info("[sp.challenge] entity_id: %s", entity_id) # Do the AuthnRequest _binding = BINDING_HTTP_REDIRECT try: srvs = _cli.metadata.single_sign_on_service(entity_id, _binding) - logger.debug("srvs: %s" % srvs) + logger.debug("srvs: %s", srvs) dest = srvs[0]["location"] - logger.debug("destination: %s" % dest) + logger.debug("destination: %s", dest) extensions = None cert = None @@ -358,7 +358,7 @@ class SAML2Plugin(object): destination=dest, relay_state=came_from) - logger.debug("ht_args: %s" % ht_args) + logger.debug("ht_args: %s", ht_args) except Exception as exc: logger.exception(exc) raise Exception( @@ -378,7 +378,7 @@ class SAML2Plugin(object): self.outstanding_queries[_sid] = came_from if not ht_args["data"] and ht_args["headers"][0][0] == "Location": - logger.debug('redirect to: %s' % ht_args["headers"][0][1]) + logger.debug('redirect to: %s', ht_args["headers"][0][1]) return HTTPSeeOther(headers=ht_args["headers"]) else: return ht_args["data"] @@ -391,13 +391,13 @@ class SAML2Plugin(object): 'repoze.who.userid': cni, "user": session_info["ava"], } - logger.debug("Identity: %s" % identity) + logger.debug("Identity: %s", identity) return identity def _eval_authn_response(self, environ, post, binding=BINDING_HTTP_POST): logger.info("Got AuthN response, checking..") - logger.info("Outstanding: %s" % (self.outstanding_queries,)) + logger.info("Outstanding: %s", self.outstanding_queries) try: # Evaluate the response, returns a AuthnResponse instance @@ -416,7 +416,7 @@ class SAML2Plugin(object): return None if session_info["came_from"]: - logger.debug("came_from << %s" % session_info["came_from"]) + logger.debug("came_from << %s", session_info["came_from"]) try: path, query = session_info["came_from"].split('?') environ["PATH_INFO"] = path @@ -424,7 +424,7 @@ class SAML2Plugin(object): except ValueError: environ["PATH_INFO"] = session_info["came_from"] - logger.info("Session_info: %s" % session_info) + logger.info("Session_info: %s", session_info) return session_info def do_ecp_response(self, body, environ): @@ -433,7 +433,7 @@ class SAML2Plugin(object): environ["s2repoze.relay_state"] = _relay_state.text session_info = response.session_info() - logger.info("Session_info: %s" % session_info) + logger.info("Session_info: %s", session_info) return session_info @@ -453,15 +453,15 @@ class SAML2Plugin(object): return None # if logger: - # logger.info("ENVIRON: %s" % environ) - # logger.info("self: %s" % (self.__dict__,)) + # logger.info("ENVIRON: %s", environ) + # logger.info("self: %s", self.__dict__) uri = environ.get('REQUEST_URI', construct_url(environ)) - logger.debug('[sp.identify] uri: %s' % (uri,)) + logger.debug('[sp.identify] uri: %s', uri) query = parse_dict_querystring(environ) - logger.debug('[sp.identify] query: %s' % (query,)) + logger.debug('[sp.identify] query: %s', query) if "SAMLResponse" in query or "SAMLRequest" in query: post = query @@ -471,7 +471,7 @@ class SAML2Plugin(object): binding = BINDING_HTTP_POST try: - logger.debug('[sp.identify] post keys: %s' % (post.keys(),)) + logger.debug('[sp.identify] post keys: %s', post.keys()) except (TypeError, IndexError): pass @@ -567,9 +567,9 @@ class SAML2Plugin(object): pass _cli = self.saml_client - logger.debug("[add_metadata] for %s" % name_id) + logger.debug("[add_metadata] for %s", name_id) try: - logger.debug("Issuers: %s" % _cli.users.sources(name_id)) + logger.debug("Issuers: %s", _cli.users.sources(name_id)) except KeyError: pass @@ -578,7 +578,7 @@ class SAML2Plugin(object): try: (ava, _) = _cli.users.get_identity(name_id) #now = time.gmtime() - logger.debug("[add_metadata] adds: %s" % ava) + logger.debug("[add_metadata] adds: %s", ava) identity["user"].update(ava) except KeyError: pass @@ -596,7 +596,7 @@ class SAML2Plugin(object): except KeyError: logger.exception("Failed to do attribute aggregation, " "missing common attribute") - logger.debug("[add_metadata] returns: %s" % (dict(identity),)) + logger.debug("[add_metadata] returns: %s", dict(identity)) if not identity["user"]: # remove cookie and demand re-authentication @@ -633,7 +633,7 @@ class SAML2Plugin(object): else: ht_args = responses[responses.keys()[0]][1] if not ht_args["data"] and ht_args["headers"][0][0] == "Location": - logger.debug('redirect to: %s' % ht_args["headers"][0][1]) + logger.debug('redirect to: %s', ht_args["headers"][0][1]) return HTTPSeeOther(headers=ht_args["headers"]) else: return ht_args["data"] diff --git a/src/saml2/sdb.py b/src/saml2/sdb.py index d8d21695..d4fc155a 100644 --- a/src/saml2/sdb.py +++ b/src/saml2/sdb.py @@ -72,7 +72,7 @@ class SessionStorage(object): try: statements = self.authn[key] except KeyError: - logger.info("Unknown subject %s" % name_id) + logger.info("Unknown subject %s", name_id) return [] for statement in statements: @@ -88,7 +88,7 @@ class SessionStorage(object): return result def remove_authn_statements(self, name_id): - logger.debug("remove authn about: %s" % name_id) + logger.debug("remove authn about: %s", name_id) nkey = sha1(code_binary(name_id)).hexdigest() del self.authn[nkey] diff --git a/src/saml2/server.py b/src/saml2/server.py index 7a385248..ae2c6f15 100644 --- a/src/saml2/server.py +++ b/src/saml2/server.py @@ -614,8 +614,7 @@ class Server(Entity): name_id = self.ident.construct_nameid(userid, policy, sp_entity_id, name_id_policy) - logger.debug("construct_nameid: %s => %s" % (userid, - name_id)) + logger.debug("construct_nameid: %s => %s", userid, name_id) except IOError as exc: response = self.create_error_response(in_response_to, destination, @@ -732,7 +731,7 @@ class Server(Entity): if sign_response: return self.sign(_resp) else: - logger.info("Message: %s" % _resp) + logger.info("Message: %s", _resp) return _resp def create_authn_query_response(self, subject, session_index=None, @@ -810,7 +809,7 @@ class Server(Entity): """ lid = self.ident.find_local_id(name_id) - logger.info("Clean out %s" % lid) + logger.info("Clean out %s", lid) # remove the authentications try: diff --git a/src/saml2/sigver.py b/src/saml2/sigver.py index c8d2daab..1a825992 100644 --- a/src/saml2/sigver.py +++ b/src/saml2/sigver.py @@ -778,7 +778,7 @@ class CryptoBackendXmlSec1(CryptoBackend): :param xpath: What should be encrypted :return: """ - logger.debug("Encryption input len: %d" % len(text)) + logger.debug("Encryption input len: %d", len(text)) _, fil = make_temp(str(text).encode('utf-8'), decode=False) com_list = [self.xmlsec, "--encrypt", "--pubkey-cert-pem", recv_key, @@ -838,7 +838,7 @@ class CryptoBackendXmlSec1(CryptoBackend): :return: The decrypted document """ - logger.debug("Decrypt input len: %d" % len(enctext)) + logger.debug("Decrypt input len: %d", len(enctext)) _, fil = make_temp(str(enctext).encode('utf-8'), decode=False) com_list = [self.xmlsec, "--decrypt", "--privkey-pem", @@ -882,8 +882,8 @@ class CryptoBackendXmlSec1(CryptoBackend): if signed_statement: return signed_statement.decode('utf-8') logger.error( - "Signing operation failed :\nstdout : %s\nstderr : %s" % ( - stdout, stderr)) + "Signing operation failed :\nstdout : %s\nstderr : %s", + stdout, stderr) raise SigverError(stderr) except DecryptError: raise SigverError("Signing failed") @@ -948,7 +948,7 @@ class CryptoBackendXmlSec1(CryptoBackend): com_list.extend(["--output", ntf.name]) com_list += extra_args - logger.debug("xmlsec command: %s" % " ".join(com_list)) + logger.debug("xmlsec command: %s", " ".join(com_list)) pof = Popen(com_list, stderr=PIPE, stdout=PIPE) @@ -956,14 +956,14 @@ class CryptoBackendXmlSec1(CryptoBackend): p_err = pof.stderr.read().decode('utf-8') if pof.returncode is not None and pof.returncode < 0: - logger.error(LOG_LINE % (p_out, p_err)) + logger.error(LOG_LINE, p_out, p_err) raise XmlsecError("%d:%s" % (pof.returncode, p_err)) try: if validate_output: parse_xmlsec_output(p_err) except XmlsecError as exc: - logger.error(LOG_LINE_2 % (p_out, p_err, exc)) + logger.error(LOG_LINE_2, p_out, p_err, exc) raise ntf.seek(0) @@ -1226,7 +1226,7 @@ class CertHandler(object): cert_str, self._cert_str, self._key_str) else: valid, mess = self._osw.verify(self._cert_str, cert_str) - logger.info("CertHandler.verify_cert: %s" % mess) + logger.info("CertHandler.verify_cert: %s", mess) return valid return True @@ -1463,8 +1463,8 @@ class SecurityContext(object): decode=False, delete=self._xmlsec_delete_tmpfiles) for cert in cert_from_instance(item)] else: - logger.debug("==== Certs from metadata ==== %s: %s ====" % (issuer, - certs)) + logger.debug("==== Certs from metadata ==== %s: %s ====", issuer, + certs) if not certs: raise MissingKey("%s" % issuer) @@ -1498,13 +1498,13 @@ class SecurityContext(object): verified = True break except XmlsecError as exc: - logger.error("check_sig: %s" % exc) + logger.error("check_sig: %s", exc) pass except SignatureError as exc: - logger.error("check_sig: %s" % exc) + logger.error("check_sig: %s", exc) pass except Exception as exc: - logger.error("check_sig: %s" % exc) + logger.error("check_sig: %s", exc) raise if (not verified) and (not only_valid_cert): diff --git a/src/saml2/virtual_org.py b/src/saml2/virtual_org.py index 0e81b065..3f66442c 100644 --- a/src/saml2/virtual_org.py +++ b/src/saml2/virtual_org.py @@ -42,7 +42,7 @@ class VirtualOrg(object): # Remove the ones I have cached data from about this subject vo_members = [m for m in vo_members if not self.sp.users.cache.active( name_id, m)] - logger.info("VO members (not cached): %s" % vo_members) + logger.info("VO members (not cached): %s", vo_members) return vo_members def get_common_identifier(self, name_id): @@ -59,8 +59,8 @@ class VirtualOrg(object): def do_aggregation(self, name_id): - logger.info("** Do VO aggregation **\nSubjectID: %s, VO:%s" % ( - name_id, self._name)) + logger.info("** Do VO aggregation **\nSubjectID: %s, VO:%s", + name_id, self._name) to_ask = self.members_to_ask(name_id) if to_ask: @@ -72,9 +72,9 @@ class VirtualOrg(object): com_identifier, self.sp.config.entityid, to_ask): _ = self._cache_session(session_info) - logger.info(">Issuers: %s" % self.sp.users.issuers_of_info(name_id)) - logger.info("AVA: %s" % (self.sp.users.get_identity(name_id),)) + logger.info(">Issuers: %s", self.sp.users.issuers_of_info(name_id)) + logger.info("AVA: %s", self.sp.users.get_identity(name_id)) return True else: - return False
\ No newline at end of file + return False diff --git a/src/saml2test/interaction.py b/src/saml2test/interaction.py index ddfbeacb..941399e6 100644 --- a/src/saml2test/interaction.py +++ b/src/saml2test/interaction.py @@ -102,7 +102,7 @@ class Interaction(object): self.who = "Form process" def pick_interaction(self, _base="", content="", req=None): - logger.info("pick_interaction baseurl: %s" % _base) + logger.info("pick_interaction baseurl: %s", _base) unic = content if content: _bs = BeautifulSoup(content) @@ -113,11 +113,11 @@ class Interaction(object): _match = 0 for attr, val in interaction["matches"].items(): if attr == "url": - logger.info("matching baseurl against: %s" % val) + logger.info("matching baseurl against: %s", val) if val == _base: _match += 1 elif attr == "title": - logger.info("matching '%s' against title" % val) + logger.info("matching '%s' against title", val) if _bs is None: break if _bs.title is None: @@ -140,7 +140,7 @@ class Interaction(object): _match += 1 if _match == len(interaction["matches"]): - logger.info("Matched: %s" % interaction["matches"]) + logger.info("Matched: %s", interaction["matches"]) return interaction raise InteractionNeeded("No interaction matched") @@ -319,7 +319,7 @@ class Interaction(object): else: url = path - logger.info("GET %s" % url) + logger.info("GET %s", url) return self.httpc.send(url, "GET") #return resp, "" @@ -390,8 +390,8 @@ class Action(object): _args.update({"location": location, "features": features, "conv": conv}) - logger.info("<-- FUNCTION: %s" % function.__name__) - logger.info("<-- ARGS: %s" % _args) + logger.info("<-- FUNCTION: %s", function.__name__) + logger.info("<-- ARGS: %s", _args) result = function(response, **_args) self.post_op(result, conv, _args) diff --git a/src/saml2test/opfunc.py b/src/saml2test/opfunc.py index 2d612edc..014f93ba 100644 --- a/src/saml2test/opfunc.py +++ b/src/saml2test/opfunc.py @@ -109,17 +109,17 @@ def do_request(client, url, method, body="", headers=None): if headers is None: headers = {} - logger.info("--> URL: %s" % url) - logger.info("--> BODY: %s" % body) - logger.info("--> Headers: %s" % (headers,)) + logger.info("--> URL: %s", url) + logger.info("--> BODY: %s", body) + logger.info("--> Headers: %s", headers) response = client.http_request(url, method=method, data=body, headers=headers) - logger.info("<-- RESPONSE: %s" % response) - logger.info("<-- CONTENT: %s" % response.text) + logger.info("<-- RESPONSE: %s", response) + logger.info("<-- CONTENT: %s", response.text) if response.cookies: - logger.info("<-- COOKIES: %s" % response.cookies) + logger.info("<-- COOKIES: %s", response.cookies) return url, response, response.text @@ -366,8 +366,8 @@ class Operation(object): _args["location"] = location - logger.info("--> FUNCTION: %s" % self.function.__name__) - logger.info("--> ARGS: %s" % (_args,)) + logger.info("--> FUNCTION: %s", self.function.__name__) + logger.info("--> ARGS: %s", _args) result = self.function(self.conv.client, response, content, **_args) self.post_op(result, self.conv, _args) diff --git a/src/saml2test/tool.py b/src/saml2test/tool.py index d9113599..da96c336 100644 --- a/src/saml2test/tool.py +++ b/src/saml2test/tool.py @@ -51,14 +51,14 @@ class Conversation(object): def check_severity(self, stat): if stat["status"] >= 4: - logger.error("WHERE: %s" % stat["id"]) - logger.error("STATUS:%s" % STATUSCODE[stat["status"]]) + logger.error("WHERE: %s", stat["id"]) + logger.error("STATUS:%s", STATUSCODE[stat["status"]]) try: - logger.error("HTTP STATUS: %s" % stat["http_status"]) + logger.error("HTTP STATUS: %s", stat["http_status"]) except KeyError: pass try: - logger.error("INFO: %s" % stat["message"]) + logger.error("INFO: %s", stat["message"]) except KeyError: pass @@ -119,8 +119,7 @@ class Conversation(object): raise FatalError( "Too long sequence of redirects: %s" % rdseq) - logger.info("HTTP %d Location: %s" % (_response.status_code, - url)) + logger.info("HTTP %d Location: %s", _response.status_code, url) # If back to me for_me = False for redirect_uri in self.my_endpoints(): @@ -143,13 +142,13 @@ class Conversation(object): break else: try: - logger.info("GET %s" % url) + logger.info("GET %s", url) _response = self.client.send(url, "GET") except Exception as err: raise FatalError("%s" % err) content = _response.text - logger.info("<-- CONTENT: %s" % content) + logger.info("<-- CONTENT: %s", content) self.position = url self.last_content = content self.response = _response @@ -169,15 +168,15 @@ class Conversation(object): self.position = url cnt = content.replace("\n", '').replace("\t", '').replace("\r", '') - logger.error("URL: %s" % url) - logger.error("Page Content: %s" % cnt) + logger.error("URL: %s", url) + logger.error("Page Content: %s", cnt) raise except KeyError: self.position = url cnt = content.replace("\n", '').replace("\t", '').replace("\r", '') - logger.error("URL: %s" % url) - logger.error("Page Content: %s" % cnt) + logger.error("URL: %s", url) + logger.error("Page Content: %s", cnt) self.err_check("interaction-needed") if _spec == _last_action: @@ -194,7 +193,7 @@ class Conversation(object): _last_action = _spec if len(_spec) > 2: - logger.info(">> %s <<" % _spec["page-type"]) + logger.info(">> %s <<", _spec["page-type"]) if _spec["page-type"] == "login": self.login_page = content @@ -213,12 +212,11 @@ class Conversation(object): self.response = _response if _response.status_code >= 400: - txt = "Got status code '%s', error: %s" % ( - _response.status_code, content) - logger.error(txt) + txt = "Got status code '%s', error: %s" + logger.error(txt, _response.status_code, content) self.test_output.append( {"status": ERROR, - "message": txt, + "message": txt % (_response.status_code, content), #"id": "exception", #"name": "interaction needed", "url": self.position}) diff --git a/src/sp_test/__init__.py b/src/sp_test/__init__.py index 586fdd23..d275c87e 100644 --- a/src/sp_test/__init__.py +++ b/src/sp_test/__init__.py @@ -232,7 +232,7 @@ class Client(object): else: self.test_log = exception_trace("RUN", err) tsum = self.test_summation(self.args.oper) - logger.error("Unexpected exception in test driver %s" % + logger.error("Unexpected exception in test driver %s", traceback.format_exception(*sys.exc_info())) diff --git a/src/sp_test/base.py b/src/sp_test/base.py index 1ed778cf..c1e54921 100644 --- a/src/sp_test/base.py +++ b/src/sp_test/base.py @@ -80,14 +80,14 @@ class Conversation(): def check_severity(self, stat): if stat["status"] >= 3: - logger.error("WHERE: %s" % stat["id"]) - logger.error("STATUS:%s" % STATUSCODE[stat["status"]]) + logger.error("WHERE: %s", stat["id"]) + logger.error("STATUS:%s", STATUSCODE[stat["status"]]) try: - logger.error("HTTP STATUS: %s" % stat["http_status"]) + logger.error("HTTP STATUS: %s", stat["http_status"]) except KeyError: pass try: - logger.error("INFO: %s" % stat["message"]) + logger.error("INFO: %s", stat["message"]) except KeyError: pass @@ -153,9 +153,9 @@ class Conversation(): Create the <operation> directory; delete all possibly existing files Write response content into response_x.<ext> (with x incrementing from 0) """ - logger.info("<-- Status: %s" % response.status_code) + logger.info("<-- Status: %s", response.status_code) if response.status_code in [302, 301, 303]: - logger.info("<-- location: %s" % + logger.info("<-- location: %s", response.headers._store['location'][1]) else: if self.commandlineargs.content_log: @@ -183,11 +183,11 @@ class Conversation(): f = open(fn, "w") f.write(response.content) f.close() - logger.info("<-- Response content (encoding=%s) in file %s" % - (encoding, fn)) + logger.info("<-- Response content (encoding=%s) in file %s", + encoding, fn) pass else: - logger.info("<-- Content: %s" % response.content) + logger.info("<-- Content: %s", response.content) def wb_send_GET_startpage(self): """ @@ -251,7 +251,7 @@ class Conversation(): raise FatalError( "Too long sequence of redirects: %s" % rdseq) - logger.info("--> REDIRECT TO: %s" % url) + logger.info("--> REDIRECT TO: %s", url) # If back to me for_me = False try: @@ -491,11 +491,11 @@ class Conversation(): _spec = self.interaction.pick_interaction(_base, content) except InteractionNeeded: self.position = url - logger.error("Page Content: %s" % content) + logger.error("Page Content: %s", content) raise except KeyError: self.position = url - logger.error("Page Content: %s" % content) + logger.error("Page Content: %s", content) self.err_check("interaction-needed") if _spec == _last_action: @@ -506,7 +506,7 @@ class Conversation(): _last_action = _spec if len(_spec) > 2: - logger.info(">> %s <<" % _spec["page-type"]) + logger.info(">> %s <<", _spec["page-type"]) if _spec["page-type"] == "login": self.login_page = content diff --git a/src/utility/metadata.py b/src/utility/metadata.py index 06752d2d..bf1c4a18 100644 --- a/src/utility/metadata.py +++ b/src/utility/metadata.py @@ -16,21 +16,21 @@ def fetch_metadata(url, path, maxage=600): fetch = False if not os.path.isfile(path): fetch = True - logger.debug("metadata file %s not found" % path) + logger.debug("metadata file %s not found", path) elif (os.path.getmtime(path) + maxage) < time.time(): fetch = True - logger.debug("metadata file %s from %s is more than %s s old" % - (path, - strftime("%Y-%m-%d %H:%M:%S", time.localtime(os.path.getmtime(path))), - maxage)) + logger.debug("metadata file %s from %s is more than %s s old", + path, + strftime("%Y-%m-%d %H:%M:%S", time.localtime(os.path.getmtime(path))), + maxage) else: - logger.debug("metadata file %s is less than %s s old" % (path, maxage)) + logger.debug("metadata file %s is less than %s s old", path, maxage) if fetch: f=urllib.URLopener() try: f.retrieve(url, path) - logger.debug("downloaded metadata from %s into %s" % (url, path)) + logger.debug("downloaded metadata from %s into %s", url, path) except: - logger.debug("downloaded metadata from %s failed: %s" % - (url, sys.exc_info()[0])) + logger.debug("downloaded metadata from %s failed: %s", + url, sys.exc_info()[0]) |