From c7febbf9e8c85355dccb53a326a51bfc41db1c66 Mon Sep 17 00:00:00 2001 From: Jozef Knaperek Date: Mon, 12 Oct 2015 16:22:19 +0200 Subject: [PATCH] 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. --- example/idp2/idp.py | 88 ++++++------ example/idp2/idp_uwsgi.py | 86 ++++++------ example/idp2_repoze/idp.py | 132 +++++++++--------- example/sp-repoze/sp.py | 32 ++--- example/sp-wsgi/sp.py | 62 ++++---- src/idp_test/base.py | 24 ++-- src/idp_test/check.py | 2 +- src/idp_test/interaction.py | 4 +- src/saml2/assertion.py | 4 +- src/saml2/attribute_converter.py | 12 +- src/saml2/attribute_resolver.py | 2 +- src/saml2/client.py | 28 ++-- src/saml2/client_base.py | 11 +- src/saml2/ecp_client.py | 18 +-- src/saml2/entity.py | 33 +++-- src/saml2/httpbase.py | 14 +- src/saml2/ident.py | 10 +- src/saml2/mdstore.py | 24 ++-- src/saml2/mongo_store.py | 2 +- src/saml2/pack.py | 6 +- src/saml2/request.py | 12 +- src/saml2/response.py | 60 ++++---- src/saml2/s2repoze/plugins/formswithhidden.py | 4 +- src/saml2/s2repoze/plugins/sp.py | 62 ++++---- src/saml2/sdb.py | 4 +- src/saml2/server.py | 7 +- src/saml2/sigver.py | 26 ++-- src/saml2/virtual_org.py | 12 +- src/saml2test/interaction.py | 14 +- src/saml2test/opfunc.py | 16 +-- src/saml2test/tool.py | 32 ++--- src/sp_test/__init__.py | 2 +- src/sp_test/base.py | 26 ++-- src/utility/metadata.py | 18 +-- 34 files changed, 442 insertions(+), 447 deletions(-) diff --git a/example/idp2/idp.py b/example/idp2/idp.py index f3db83e..5e78d36 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(" PATH: %s" % path) + logger.info(" 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 dcc0121..30e4b26 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(" PATH: %s" % path) + logger.info(" 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 cd6b486..9512fca 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(" PATH: %s" % path) + logger.info(" 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 49e38dc..b6539e0 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("%s\n" % valarr) elif isinstance(valarr, list): i = 0 - n = len(valarr) + n = len(valarr) for val in valarr: if not i: txt.append("%s\n" % (len(valarr), prop)) @@ -105,7 +105,7 @@ def whoami(environ, start_response, user): response.extend("Logout") 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 ["

You are now logged out from this service

"] - + # ---------------------------------------------------------------------------- # 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(" PATH: %s" % path) + logger.info(" 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 9461575..f5fcb4a 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(" PATH: '%s'" % path) + logger.debug(" 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 aebb38a..4707147 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 156b216..ab115ea 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 2fbc46b..2eddc70 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 795c0cd..c9d138b 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 de68f22..5a1b371 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 7d7f4fb..18a6610 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 64871d6..baee02f 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 b499e19..cbecd1d 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 c41a046..90c3b44 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 60de964..4d0c548 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 2fd0015..016e0ff 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 502f131..b6af8e9 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 09531ab..ad70a68 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 ad9b072..4171f70 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 91b6f97..3377c45 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() == '> '%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 d8d2169..d4fc155 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 7a38524..ae2c6f1 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 c8d2daa..1a82599 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 0e81b06..3f66442 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 ddfbeac..941399e 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 2d612ed..014f93b 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 d911359..da96c33 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 586fdd2..d275c87 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 1ed778c..c1e5492 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 directory; delete all possibly existing files Write response content into response_x. (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 06752d2..bf1c4a1 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])