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])