search

openid-certification / oidctest

THE CERTIFICATION TEST SUITE HAS BEEN MIGRATED TO A NEW SERVICE https://www.certificatinon.openid.net
Other
49 stars 15 forks source link

rp-frontchannel-rpinitlogout: backchannel logout is triggered instead of frontchannel #191

Closed zandbelt closed 4 years ago

zandbelt commented 4 years ago

It appears rp-frontchannel-rpinitlogout triggers backchannel logout as shown in the trace below at [1]; this is probably due to the fact that both front- and backchannel endpoints are registered for the OP as also seen in the logs but I believe the suite should then prefer front channel logout for this specifically (named) test.

[1]

2019-10-09 07:04:04,102 oidctest.cp.op:DEBUG request_body: b'{"client_name":"OpenID Connect Apache Module (mod_auth_openidc)","redirect_uris":["https://localhost.zmartzone.eu/protected/"],"response_types":["code","id_token","id_token token","code id_token","code token","code id_token token"],"token_endpoint_auth_method":"client_secret_basic","contacts":["hans.zandbelt@zmartzone.eu"],"jwks_uri":"https://host.docker.internal/protected/?jwks=rsa","initiate_login_uri":"https://localhost.zmartzone.eu/protected/","frontchannel_logout_uri":"https://localhost.zmartzone.eu/protected/?logout=get","backchannel_logout_uri":"https://localhost.zmartzone.eu/protected/?logout=backchannel","id_token_token_binding_cnf":"tbh","post_logout_redirect_uris":["https://localhost.zmartzone.eu/loggedout.html"]}' 2019-10-09 07:04:04,103 oic.oic.provider:DEBUG @registration_endpoint: <<{"client_name":"OpenID Connect Apache Module (mod_auth_openidc)","redirect_uris":["https://localhost.zmartzone.eu/protected/"],"response_types":["code","","id_token token","code id_token","code token","code id_token token"],"token_endpoint_auth_method":"client_secret_basic","contacts":["hans.zandbelt@zmartzone.eu"],"jwks_uri":"https://host.docker.internal/protected/?jwks=rsa","initiate_login_uri":"https://localhost.zmartzone.eu/protected/","frontchannel_logout_uri":"https://localhost.zmartzone.eu/protected/?logout=get","backchannel_logout_uri":"https://localhost.zmartzone.eu/protected/?logout=backchannel","id_token_token_binding_cnf":"tbh","post_logout_redirect_uris":["https://localhost.zmartzone.eu/loggedout.html"]}>> 2019-10-09 07:04:04,103 oic.oic.provider:INFO registration_request:{'application_type': 'web', 'response_types': ['code', 'id_token', 'id_token token', 'code id_token', 'code token', 'code id_token token'], 'client_name': 'OpenID Connect Apache Module (mod_auth_openidc)', 'redirect_uris': ['https://localhost.zmartzone.eu/protected/'], 'token_endpoint_auth_method': 'client_secret_basic', 'contacts': ['hans.zandbelt@zmartzone.eu'], 'jwks_uri': 'https://host.docker.internal/protected/?jwks=rsa', 'initiate_login_uri': 'https://localhost.zmartzone.eu/protected/', 'frontchannel_logout_uri': 'https://localhost.zmartzone.eu/protected/?logout=get', 'backchannel_logout_uri': 'https://localhost.zmartzone.eu/protected/?logout=backchannel', 'id_token_token_binding_cnf': 'tbh', 'post_logout_redirect_uris': ['https://localhost.zmartzone.eu/loggedout.html']} 2019-10-09 07:04:04,103 oic.oic.provider:DEBUG _cinfo: {'client_id': 'y86o9x5xw4E2', 'client_secret': '', 'registration_access_token': 'roHW4qbG6fNcqQKDKMsgMqrQZWfSB6z8', 'registration_client_uri': 'https://rp-test:8080/mod_auth_openidc-code/registration?client_id=y86o9x5xw4E2', 'client_secret_expires_at': 1570691044, 'client_id_issued_at': 1570604644, 'client_salt': 'M7rxh8nk'} 2019-10-09 07:04:04,103 oic.utils.keyio:DEBUG loading keys for issuer: y86o9x5xw4E2 2019-10-09 07:04:04,103 oic.utils.keyio:DEBUG pcr: {'application_type': 'web', 'response_types': ['code', 'id_token', 'id_token token', 'code id_token', 'code token', 'code id_token token'], 'client_name': 'OpenID Connect Apache Module (mod_auth_openidc)', 'redirect_uris': ['https://localhost.zmartzone.eu/protected/'], 'token_endpoint_auth_method': 'client_secret_basic', 'contacts': ['hans.zandbelt@zmartzone.eu'], 'jwks_uri': 'https://host.docker.internal/protected/?jwks=rsa', 'initiate_login_uri': 'https://localhost.zmartzone.eu/protected/', 'frontchannel_logout_uri': 'https://localhost.zmartzone.eu/protected/?logout=get', 'backchannel_logout_uri': 'https://localhost.zmartzone.eu/protected/?logout=backchannel', 'id_token_token_binding_cnf': 'tbh', 'post_logout_redirect_uris': ['https://localhost.zmartzone.eu/loggedout.html']} 2019-10-09 07:04:04,103 oic.oic.provider:DEBUG found 1 keys for client_id=y86o9x5xw4E2 2019-10-09 07:04:04,103 oic.oic.provider:INFO registration_response: {'client_id': 'y86o9x5xw4E2', 'client_secret': '', 'registration_access_token': 'roHW4qbG6fNcqQKDKMsgMqrQZWfSB6z8', 'registration_client_uri': 'https://rp-test:8080/mod_auth_openidc-code/registration?client_id=y86o9x5xw4E2', 'client_secret_expires_at': 1570691044, 'client_id_issued_at': 1570604644, 'application_type': 'web', 'response_types': ['code', 'id_token', 'id_token token', 'code id_token', 'code token', 'code id_token token'], 'client_name': 'OpenID Connect Apache Module (mod_auth_openidc)', 'token_endpoint_auth_method': 'client_secret_basic', 'contacts': ['hans.zandbelt@zmartzone.eu'], 'jwks_uri': 'https://host.docker.internal/protected/?jwks=rsa', 'initiate_login_uri': 'https://localhost.zmartzone.eu/protected/', 'frontchannel_logout_uri': 'https://localhost.zmartzone.eu/protected/?logout=get', 'backchannel_logout_uri': 'https://localhost.zmartzone.eu/protected/?logout=backchannel', 'post_logout_redirect_uris': ['https://localhost.zmartzone.eu/loggedout.html'], 'redirect_uris': ['https://localhost.zmartzone.eu/protected/']} 2019-10-09 07:04:04,104 cherrypy.access.140367853023584:INFO 172.20.0.1 - - [09/Oct/2019:07:04:04] "POST /mod_auth_openidc-code/rp-frontchannel-rpinitlogout/registration HTTP/1.1" 201 1105 "" "mod_auth_openidc" 2019-10-09 07:04:04,146 oidctest.cp.op:INFO ent:172.20.0.1, vpath: ['mod_auth_openidc-code', 'rp-frontchannel-rpinitlogout', 'authorization'] 2019-10-09 07:04:04,147 oidctest.cp.op:DEBUG AuthorizationRequest: {'response_type': 'code', 'scope': 'openid', 'client_id': 'y86o9x5xw4E2', 'state': 'xhCEjnQBFvZVEYlpsW99R2eILc4', 'redirect_uri': 'https://localhost.zmartzone.eu/protected/', 'nonce': 'JY1VosCqnoc6yFHxzYL-reIMLaNnkVNkQtxbQ1bHibg'} 2019-10-09 07:04:04,147 oic.oauth2.provider:DEBUG Request: 'response_type=code&scope=openid&client_id=y86o9x5xw4E2&state=xhCEjnQBFvZVEYlpsW99R2eILc4&redirect_uri=https%3A%2F%2Flocalhost.zmartzone.eu%2Fprotected%2F&nonce=JY1VosCqnoc6yFHxzYL-reIMLaNnkVNkQtxbQ1bHibg' 2019-10-09 07:04:04,147 root:DEBUG KeyBundle fetch keys from: https://host.docker.internal/protected/?jwks=rsa 2019-10-09 07:04:04,147 urllib3.connectionpool:DEBUG Starting new HTTPS connection (1): host.docker.internal:443 2019-10-09 07:04:04,160 urllib3.connectionpool:DEBUG https://host.docker.internal:443 "GET /protected/?jwks=rsa HTTP/1.1" 200 751 2019-10-09 07:04:04,161 oic.utils.keyio:DEBUG Loaded JWKS: { "keys" : [ {"kty":"RSA","kid":"Aenckeykid","e":"AQAB","n":"2sDzGBWiOyc4r7Q3mRWas28PGY9FzD4LIiyO4jkz1rgvJos_U1zOY6XW-BF_OHDQs13NzHhv1oYwCFOO4e97SDeNHMnkP9gn0pi_RVSfEngOTp5wjVBIFfFpk3beuwDDIR8y-QWMfY20CY8jZfpQqqaS8BLGATlUqHwGsvBP228QPc6PcypgUQbR0MouSWMa0icg2l4eUwpaNzoCfJb4JAih5TMBxp4kSE1Ib0XqYaTU2mU0V9HgrKjDRYwmvmWEZVx6zHGL7LJ-mITYSFq6455wkFJ-9XEkNPORCzPh5UJ4940BJy0zOzifkri9gsDw1nuBd0jcb16G--75HIv3JKNoUnKZPkQzbe8b7LIR2DQXeHPA_4o4r-Aio3osQuSgZOaffaplY_DC661gfAMxn6BbcCyW0W5zm_mz6S_tOQnrgLai7FevbX1f5EV5gPno_2ouzpAIYTFcElKp_hrEAMW04Mg7apY8j1OEOuikNupqFDBCp3xmaMuf35g5HcmUgFwvKD41Vu0mc69gXcjshwrtbHPOQLCHtyQiyxjsU3OOHcMAEx9lRCvmvGfRVgliJvVflZBl8scSM1NN_I3ATy2hfBwKxC3X9qbBp-LFXUtAikoSHTxvBZGi1Kl7eEPc8udH2iW8hP7Q7vhTb3kG7XMaMmtcOK6hh0J4LutqYhc"} ] } from https://host.docker.internal/protected/?jwks=rsa 2019-10-09 07:04:04,161 oic.utils.keyio:DEBUG Loaded JWKS: { "keys" : [ {"kty":"RSA","kid":"Aenckeykid","e":"AQAB","n":"2sDzGBWiOyc4r7Q3mRWas28PGY9FzD4LIiyO4jkz1rgvJos_U1zOY6XW-BF_OHDQs13NzHhv1oYwCFOO4e97SDeNHMnkP9gn0pi_RVSfEngOTp5wjVBIFfFpk3beuwDDIR8y-QWMfY20CY8jZfpQqqaS8BLGATlUqHwGsvBP228QPc6PcypgUQbR0MouSWMa0icg2l4eUwpaNzoCfJb4JAih5TMBxp4kSE1Ib0XqYaTU2mU0V9HgrKjDRYwmvmWEZVx6zHGL7LJ-mITYSFq6455wkFJ-9XEkNPORCzPh5UJ4940BJy0zOzifkri9gsDw1nuBd0jcb16G--75HIv3JKNoUnKZPkQzbe8b7LIR2DQXeHPA_4o4r-Aio3osQuSgZOaffaplY_DC661gfAMxn6BbcCyW0W5zm_mz6S_tOQnrgLai7FevbX1f5EV5gPno_2ouzpAIYTFcElKp_hrEAMW04Mg7apY8j1OEOuikNupqFDBCp3xmaMuf35g5HcmUgFwvKD41Vu0mc69gXcjshwrtbHPOQLCHtyQiyxjsU3OOHcMAEx9lRCvmvGfRVgliJvVflZBl8scSM1NN_I3ATy2hfBwKxC3X9qbBp-LFXUtAikoSHTxvBZGi1Kl7eEPc8udH2iW8hP7Q7vhTb3kG7XMaMmtcOK6hh0J4LutqYhc"} ] } from https://host.docker.internal/protected/?jwks=rsa 2019-10-09 07:04:04,161 oic.oic:DEBUG Found 4 verify keys 2019-10-09 07:04:04,161 oic.oauth2.provider:DEBUG AuthzRequest: {'response_type': 'code', 'scope': 'openid', 'client_id': 'y86o9x5xw4E2', 'state': 'xhCEjnQBFvZVEYlpsW99R2eILc4', 'redirect_uri': 'https://localhost.zmartzone.eu/protected/', 'nonce': 'JY1VosCqnoc6yFHxzYL-reIMLaNnkVNkQtxbQ1bHibg'} 2019-10-09 07:04:04,161 oic.oic.provider:INFO authorization_request: {'response_type': 'code', 'scope': 'openid', 'client_id': 'y86o9x5xw4E2', 'state': 'xhCEjnQBFvZVEYlpsW99R2eILc4', 'redirect_uri': 'https://localhost.zmartzone.eu/protected/', 'nonce': 'JY1VosCqnoc6yFHxzYL-reIMLaNnkVNkQtxbQ1bHibg'} 2019-10-09 07:04:04,161 oic.oauth2.provider:INFO No active authentication 2019-10-09 07:04:04,162 oic.oic.provider:DEBUG - authenticated - 2019-10-09 07:04:04,162 oic.oic.provider:DEBUG AREQ keys: ['response_type', 'scope', 'client_id', 'state', 'redirect_uri', 'nonce'] 2019-10-09 07:04:04,162 oic.utils.sdb:DEBUG uid2sub: {'diana': ['1b2fc9341a16ae4e30082965d537ae47c21a0f27fd43eab78330ed81751ae6db']} 2019-10-09 07:04:04,162 oic.oauth2.provider:DEBUG - in authenticated() - 2019-10-09 07:04:04,162 oic.oauth2.provider:DEBUG response type: ['code'] 2019-10-09 07:04:04,163 oic.oic.provider:INFO authorization response: {'state': 'xhCEjnQBFvZVEYlpsW99R2eILc4', 'scope': 'openid', 'code': '', 'iss': 'https://rp-test:8080/mod_auth_openidc-code/rp-frontchannel-rpinitlogout', 'client_id': 'y86o9x5xw4E2'} 2019-10-09 07:04:04,163 oic.oic.provider:DEBUG Redirected to: 'https://localhost.zmartzone.eu/protected/?state=xhCEjnQBFvZVEYlpsW99R2eILc4&scope=openid&code=&iss=https%3A%2F%2Frp-test%3A8080%2Fmod_auth_openidc-code%2Frp-frontchannel-rpinitlogout&client_id=y86o9x5xw4E2' :: <class 'str'> 2019-10-09 07:04:04,163 cherrypy.access.140367853023584:INFO 172.20.0.1 - - [09/Oct/2019:07:04:04] "GET /mod_auth_openidc-code/rp-frontchannel-rpinitlogout/authorization?response_type=code&scope=openid&client_id=y86o9x5xw4E2&state=xhCEjnQBFvZVEYlpsW99R2eILc4&redirect_uri=https%3A%2F%2Flocalhost.zmartzone.eu%2Fprotected%2F&nonce=JY1VosCqnoc6yFHxzYL-reIMLaNnkVNkQtxbQ1bHibg HTTP/1.1" 302 1147 "" "curl/7.66.0" 2019-10-09 07:04:04,217 oidctest.cp.op:INFO ent:172.20.0.1, vpath: ['mod_auth_openidc-code', 'rp-frontchannel-rpinitlogout', 'token'] 2019-10-09 07:04:04,217 oidctest.cp.op:DEBUG Authorization: Basic eTg2bzl4NXh3NEUyOjhkZDdkODM0YTEwZDk1MmRmNWFhMDJhZjQzZTM5YmMxNjk3YmE3NDNhY2Y5YWYzMTUxZTFjMTJl 2019-10-09 07:04:04,217 oic.utils.authn.client:DEBUG REQ: {'grant_type': 'authorization_code', 'code': '', 'redirect_uri': 'https://localhost.zmartzone.eu/protected/', 'state': 'xhCEjnQBFvZVEYlpsW99R2eILc4'} 2019-10-09 07:04:04,217 oic.utils.authn.client:DEBUG Basic auth 2019-10-09 07:04:04,217 oic.oic.provider:DEBUG - token - 2019-10-09 07:04:04,218 oic.oic.provider:INFO token_request: {'grant_type': 'authorization_code', 'code': '', 'redirect_uri': 'https://localhost.zmartzone.eu/protected/', 'state': 'xhCEjnQBFvZVEYlpsW99R2eILc4'} 2019-10-09 07:04:04,218 oic.oic.provider:DEBUG AccessTokenRequest: {'grant_type': 'authorization_code', 'code': '', 'redirect_uri': 'https://localhost.zmartzone.eu/protected/', 'state': 'xhCEjnQBFvZVEYlpsW99R2eILc4'} 2019-10-09 07:04:04,218 oic.utils.authn.client:DEBUG REQ: {'grant_type': 'authorization_code', 'code': '', 'redirect_uri': 'https://localhost.zmartzone.eu/protected/', 'state': 'xhCEjnQBFvZVEYlpsW99R2eILc4'} 2019-10-09 07:04:04,218 oic.utils.authn.client:DEBUG Basic auth 2019-10-09 07:04:04,219 oic.oic.provider:DEBUG All checks OK 2019-10-09 07:04:04,219 oic.oic:DEBUG authzreq: {'response_type': 'code', 'scope': 'openid', 'client_id': 'y86o9x5xw4E2', 'state': 'xhCEjnQBFvZVEYlpsW99R2eILc4', 'redirect_uri': 'https://localhost.zmartzone.eu/protected/', 'nonce': 'JY1VosCqnoc6yFHxzYL-reIMLaNnkVNkQtxbQ1bHibg'} 2019-10-09 07:04:04,219 oic.oic.provider:DEBUG Signing alg: RS256 [RSA] 2019-10-09 07:04:04,219 oic.oic:DEBUG authzreq: {'response_type': 'code', 'scope': 'openid', 'client_id': 'y86o9x5xw4E2', 'state': 'xhCEjnQBFvZVEYlpsW99R2eILc4', 'redirect_uri': 'https://localhost.zmartzone.eu/protected/', 'nonce': 'JY1VosCqnoc6yFHxzYL-reIMLaNnkVNkQtxbQ1bHibg'} 2019-10-09 07:04:04,220 oic.oic.provider:DEBUG id_token: {'iss': 'https://rp-test:8080/mod_auth_openidc-code/rp-frontchannel-rpinitlogout', 'sub': '1b2fc9341a16ae4e30082965d537ae47c21a0f27fd43eab78330ed81751ae6db', 'aud': ['y86o9x5xw4E2'], 'exp': 1570691044, 'acr': 'PASSWORD', 'iat': 1570604644, 'auth_time': 1570604644, 'nonce': 'JY1VosCqnoc6yFHxzYL-reIMLaNnkVNkQtxbQ1bHibg'} 2019-10-09 07:04:04,220 jwkest.jws:DEBUG Picking key by key type=RSA 2019-10-09 07:04:04,220 jwkest.jws:DEBUG Picking key based on alg=RS256, kid=None and use=sig 2019-10-09 07:04:04,220 jwkest.jws:DEBUG Picked: kid:lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I, use:sig, kty:RSA 2019-10-09 07:04:04,220 root:DEBUG JWT header: {'alg': 'RS256', 'kid': 'lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I'} 2019-10-09 07:04:04,221 jwkest.jws:DEBUG Signed message using key with kid=lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I 2019-10-09 07:04:04,222 oic.oic.provider:DEBUG _tinfo: {'oauth_state': 'token', 'code': '', 'code_used': True, 'authzreq': '{"response_type": "code", "scope": "openid", "client_id": "y86o9x5xw4E2", "state": "xhCEjnQBFvZVEYlpsW99R2eILc4", "redirect_uri": "https://localhost.zmartzone.eu/protected/", "nonce": "JY1VosCqnoc6yFHxzYL-reIMLaNnkVNkQtxbQ1bHibg"}', 'client_id': 'y86o9x5xw4E2', 'response_type': ['code'], 'revoked': False, 'authn_event': '{"uid": "diana", "salt": "", "authn_time": 1570604644, "valid_until": 1570608244, "authn_info": "PASSWORD"}', 'nonce': 'JY1VosCqnoc6yFHxzYL-reIMLaNnkVNkQtxbQ1bHibg', 'redirect_uri': 'https://localhost.zmartzone.eu/protected/', 'state': 'xhCEjnQBFvZVEYlpsW99R2eILc4', 'scope': ['openid'], 'sub': '1b2fc9341a16ae4e30082965d537ae47c21a0f27fd43eab78330ed81751ae6db', 'permission': '', 'access_token': '', 'access_token_scope': '?', 'token_type': 'Bearer', 'id_token': 'eyJhbGciOiJSUzI1NiIsImtpZCI6ImxtV25EanduTFV4NUV4WlU4UVBkZnBxNmJ2TjZrRTJFVklYUFYzZWhlLUkifQ.eyJpc3MiOiAiaHR0cHM6Ly9ycC10ZXN0OjgwODAvbW9kX2F1dGhfb3BlbmlkYy1jb2RlL3JwLWZyb250Y2hhbm5lbC1ycGluaXRsb2dvdXQiLCAic3ViIjogIjFiMmZjOTM0MWExNmFlNGUzMDA4Mjk2NWQ1MzdhZTQ3YzIxYTBmMjdmZDQzZWFiNzgzMzBlZDgxNzUxYWU2ZGIiLCAiYXVkIjogWyJ5ODZvOXg1eHc0RTIiXSwgImV4cCI6IDE1NzA2OTEwNDQsICJhY3IiOiAiUEFTU1dPUkQiLCAiaWF0IjogMTU3MDYwNDY0NCwgImF1dGhfdGltZSI6IDE1NzA2MDQ2NDQsICJub25jZSI6ICJKWTFWb3NDcW5vYzZ5Rkh4ellMLXJlSU1MYU5ua1ZOa1F0eGJRMWJIaWJnIn0.BHwDeeqN8NYd5Rcb5mLu3E0XPtlm97CEDnnSAahCUedWSzbOnegXPrmOWoDdAwnpGbGj4k0SQFakB_WI08Jp-65-qUYU9H3y9_LHpBiQUk6C0ljkkquGJjdnlYgQ6xQRM8Aq3ntNBwTC27kuaQT_w233598NBisdL3iJx1Ef6GVjmgFa4NvVSvht-pGKTB_B_3s6hhVwygwmcCJZrMkMTTCaxzkTf7aWHWQaG8ECVvCj9Z-jiM2lNOYHHmvGsb2n7tla6ofErzdLq1Q-sRe8LLkDNDyeAa_BYPWR7w6TSmi8db6cmSY1a1QNM6t9CBGVRbRNcuPDeRiHKbHLf0IMaA'} 2019-10-09 07:04:04,222 oic.oic.provider:INFO access_token_response: {'state': 'xhCEjnQBFvZVEYlpsW99R2eILc4', 'scope': 'openid', 'access_token': '', 'token_type': 'Bearer', 'id_token': 'eyJhbGciOiJSUzI1NiIsImtpZCI6ImxtV25EanduTFV4NUV4WlU4UVBkZnBxNmJ2TjZrRTJFVklYUFYzZWhlLUkifQ.eyJpc3MiOiAiaHR0cHM6Ly9ycC10ZXN0OjgwODAvbW9kX2F1dGhfb3BlbmlkYy1jb2RlL3JwLWZyb250Y2hhbm5lbC1ycGluaXRsb2dvdXQiLCAic3ViIjogIjFiMmZjOTM0MWExNmFlNGUzMDA4Mjk2NWQ1MzdhZTQ3YzIxYTBmMjdmZDQzZWFiNzgzMzBlZDgxNzUxYWU2ZGIiLCAiYXVkIjogWyJ5ODZvOXg1eHc0RTIiXSwgImV4cCI6IDE1NzA2OTEwNDQsICJhY3IiOiAiUEFTU1dPUkQiLCAiaWF0IjogMTU3MDYwNDY0NCwgImF1dGhfdGltZSI6IDE1NzA2MDQ2NDQsICJub25jZSI6ICJKWTFWb3NDcW5vYzZ5Rkh4ellMLXJlSU1MYU5ua1ZOa1F0eGJRMWJIaWJnIn0.BHwDeeqN8NYd5Rcb5mLu3E0XPtlm97CEDnnSAahCUedWSzbOnegXPrmOWoDdAwnpGbGj4k0SQFakB_WI08Jp-65-qUYU9H3y9_LHpBiQUk6C0ljkkquGJjdnlYgQ6xQRM8Aq3ntNBwTC27kuaQT_w233598NBisdL3iJx1Ef6GVjmgFa4NvVSvht-pGKTB_B_3s6hhVwygwmcCJZrMkMTTCaxzkTf7aWHWQaG8ECVvCj9Z-jiM2lNOYHHmvGsb2n7tla6ofErzdLq1Q-sRe8LLkDNDyeAa_BYPWR7w6TSmi8db6cmSY1a1QNM6t9CBGVRbRNcuPDeRiHKbHLf0IMaA'} 2019-10-09 07:04:04,222 cherrypy.access.140367853023584:INFO 172.20.0.1 - - [09/Oct/2019:07:04:04] "POST /mod_auth_openidc-code/rp-frontchannel-rpinitlogout/token HTTP/1.1" 200 1312 "" "mod_auth_openidc" 2019-10-09 07:04:04,242 oidctest.cp.op:INFO ent:172.20.0.1, vpath: ['static', 'jwks_uOVgcBseqMra0TS2.json'] 2019-10-09 07:04:04,242 cherrypy.error.140367853023584:INFO [09/Oct/2019:07:04:04] TOOLS.STATICDIR Checking file '/usr/local/src/oidf/oidc_cp_rplib/static/jwks_uOVgcBseqMra0TS2.json' to fulfill '/static/jwks_uOVgcBseqMra0TS2.json' 2019-10-09 07:04:04,242 cherrypy.access.140367853023584:INFO 172.20.0.1 - - [09/Oct/2019:07:04:04] "GET /static/jwks_uOVgcBseqMra0TS2.json HTTP/1.1" 200 1312 "" "mod_auth_openidc" 2019-10-09 07:04:04,262 oidctest.cp.op:INFO ent:172.20.0.1, vpath: ['mod_auth_openidc-code', 'rp-frontchannel-rpinitlogout', 'userinfo'] 2019-10-09 07:04:04,263 oic.oic.provider:DEBUG userinfo_endpoint: request={}, kwargs={'authn': 'Bearer Z0FBQUFBQmRuWVprOGtvcWliRVVvc1ZBRGRpbkkwM0syOGdNU2o2b3BIRzBzbzVkaEJJRlFkZkptZmZJU0lWVFBMX3diaktscVNuSnZfb29kcXp2cnYxOFJCaTlZNVhzNWVwQUVBS0szUTNXQmhBQ3NYMnZlWk8wNnhGenB3TWNYbmtBdW5jVGQ4RUZZZW95aU9sd0ptTV9xWk5MTnMzdV9ZZEU0cmZoUUc4ZUJBLXZFaVhUUFF3R1ZYNzktcE02dzdUUUtiUkJaU29PMHRKNU5EVElnaG92dmtVSm5Ca1puYlZDdE9naE9uQ0V5OXBkbGpFTXVQZz0='} 2019-10-09 07:04:04,263 oic.oic.provider:DEBUG Bearer token 332 chars 2019-10-09 07:04:04,263 oic.oic.provider:DEBUG access_token type: 'T' 2019-10-09 07:04:04,263 oic.oic:DEBUG authzreq: {'response_type': 'code', 'scope': 'openid', 'client_id': 'y86o9x5xw4E2', 'state': 'xhCEjnQBFvZVEYlpsW99R2eILc4', 'redirect_uri': 'https://localhost.zmartzone.eu/protected/', 'nonce': 'JY1VosCqnoc6yFHxzYL-reIMLaNnkVNkQtxbQ1bHibg'} 2019-10-09 07:04:04,264 oic.oic.provider:DEBUG userinfo_claim: {'sub': None} 2019-10-09 07:04:04,264 oic.oic.provider:DEBUG Session info: {'oauth_state': 'token', 'code': '', 'code_used': True, 'authzreq': '{"response_type": "code", "scope": "openid", "client_id": "y86o9x5xw4E2", "state": "xhCEjnQBFvZVEYlpsW99R2eILc4", "redirect_uri": "https://localhost.zmartzone.eu/protected/", "nonce": "JY1VosCqnoc6yFHxzYL-reIMLaNnkVNkQtxbQ1bHibg"}', 'client_id': 'y86o9x5xw4E2', 'response_type': ['code'], 'revoked': False, 'authn_event': '{"uid": "diana", "salt": "", "authn_time": 1570604644, "valid_until": 1570608244, "authn_info": "PASSWORD"}', 'nonce': 'JY1VosCqnoc6yFHxzYL-reIMLaNnkVNkQtxbQ1bHibg', 'redirect_uri': 'https://localhost.zmartzone.eu/protected/', 'state': 'xhCEjnQBFvZVEYlpsW99R2eILc4', 'scope': ['openid'], 'sub': '1b2fc9341a16ae4e30082965d537ae47c21a0f27fd43eab78330ed81751ae6db', 'permission': '', 'access_token': '', 'access_token_scope': '?', 'token_type': 'Bearer', 'id_token': 'eyJhbGciOiJSUzI1NiIsImtpZCI6ImxtV25EanduTFV4NUV4WlU4UVBkZnBxNmJ2TjZrRTJFVklYUFYzZWhlLUkifQ.eyJpc3MiOiAiaHR0cHM6Ly9ycC10ZXN0OjgwODAvbW9kX2F1dGhfb3BlbmlkYy1jb2RlL3JwLWZyb250Y2hhbm5lbC1ycGluaXRsb2dvdXQiLCAic3ViIjogIjFiMmZjOTM0MWExNmFlNGUzMDA4Mjk2NWQ1MzdhZTQ3YzIxYTBmMjdmZDQzZWFiNzgzMzBlZDgxNzUxYWU2ZGIiLCAiYXVkIjogWyJ5ODZvOXg1eHc0RTIiXSwgImV4cCI6IDE1NzA2OTEwNDQsICJhY3IiOiAiUEFTU1dPUkQiLCAiaWF0IjogMTU3MDYwNDY0NCwgImF1dGhfdGltZSI6IDE1NzA2MDQ2NDQsICJub25jZSI6ICJKWTFWb3NDcW5vYzZ5Rkh4ellMLXJlSU1MYU5ua1ZOa1F0eGJRMWJIaWJnIn0.BHwDeeqN8NYd5Rcb5mLu3E0XPtlm97CEDnnSAahCUedWSzbOnegXPrmOWoDdAwnpGbGj4k0SQFakB_WI08Jp-65-qUYU9H3y9_LHpBiQUk6C0ljkkquGJjdnlYgQ6xQRM8Aq3ntNBwTC27kuaQT_w233598NBisdL3iJx1Ef6GVjmgFa4NvVSvht-pGKTB_B_3s6hhVwygwmcCJZrMkMTTCaxzkTf7aWHWQaG8ECVvCj9Z-jiM2lNOYHHmvGsb2n7tla6ofErzdLq1Q-sRe8LLkDNDyeAa_BYPWR7w6TSmi8db6cmSY1a1QNM6t9CBGVRbRNcuPDeRiHKbHLf0IMaA'} 2019-10-09 07:04:04,264 oic.oic.provider:DEBUG user_info_response: {'sub': '1b2fc9341a16ae4e30082965d537ae47c21a0f27fd43eab78330ed81751ae6db'} 2019-10-09 07:04:04,264 cherrypy.access.140367853023584:INFO 172.20.0.1 - - [09/Oct/2019:07:04:04] "GET /mod_auth_openidc-code/rp-frontchannel-rpinitlogout/userinfo HTTP/1.1" 200 75 "" "mod_auth_openidc" 2019-10-09 07:04:04,375 oidctest.cp.op:INFO ent:172.20.0.1, vpath: ['mod_auth_openidc-code', 'rp-frontchannel-rpinitlogout', 'end_session'] 2019-10-09 07:04:04,375 oidctest.cp.op:DEBUG EndSessionRequest: {'id_token_hint': 'eyJhbGciOiJSUzI1NiIsImtpZCI6ImxtV25EanduTFV4NUV4WlU4UVBkZnBxNmJ2TjZrRTJFVklYUFYzZWhlLUkifQ.eyJpc3MiOiAiaHR0cHM6Ly9ycC10ZXN0OjgwODAvbW9kX2F1dGhfb3BlbmlkYy1jb2RlL3JwLWZyb250Y2hhbm5lbC1ycGluaXRsb2dvdXQiLCAic3ViIjogIjFiMmZjOTM0MWExNmFlNGUzMDA4Mjk2NWQ1MzdhZTQ3YzIxYTBmMjdmZDQzZWFiNzgzMzBlZDgxNzUxYWU2ZGIiLCAiYXVkIjogWyJ5ODZvOXg1eHc0RTIiXSwgImV4cCI6IDE1NzA2OTEwNDQsICJhY3IiOiAiUEFTU1dPUkQiLCAiaWF0IjogMTU3MDYwNDY0NCwgImF1dGhfdGltZSI6IDE1NzA2MDQ2NDQsICJub25jZSI6ICJKWTFWb3NDcW5vYzZ5Rkh4ellMLXJlSU1MYU5ua1ZOa1F0eGJRMWJIaWJnIn0.BHwDeeqN8NYd5Rcb5mLu3E0XPtlm97CEDnnSAahCUedWSzbOnegXPrmOWoDdAwnpGbGj4k0SQFakB_WI08Jp-65-qUYU9H3y9_LHpBiQUk6C0ljkkquGJjdnlYgQ6xQRM8Aq3ntNBwTC27kuaQT_w233598NBisdL3iJx1Ef6GVjmgFa4NvVSvht-pGKTB_B_3s6hhVwygwmcCJZrMkMTTCaxzkTf7aWHWQaG8ECVvCj9Z-jiM2lNOYHHmvGsb2n7tla6ofErzdLq1Q-sRe8LLkDNDyeAa_BYPWR7w6TSmi8db6cmSY1a1QNM6t9CBGVRbRNcuPDeRiHKbHLf0IMaA', 'post_logout_redirect_uri': 'https://localhost.zmartzone.eu/loggedout.html'} 2019-10-09 07:04:04,376 oic.oic.provider:DEBUG End session request: {} 2019-10-09 07:04:04,376 oic.oauth2.message:DEBUG Raw JSON: {'iss': 'https://rp-test:8080/mod_auth_openidc-code/rp-frontchannel-rpinitlogout', 'sub': '1b2fc9341a16ae4e30082965d537ae47c21a0f27fd43eab78330ed81751ae6db', 'aud': ['y86o9x5xw4E2'], 'exp': 1570691044, 'acr': 'PASSWORD', 'iat': 1570604644, 'auth_time': 1570604644, 'nonce': 'JY1VosCqnoc6yFHxzYL-reIMLaNnkVNkQtxbQ1bHibg'} 2019-10-09 07:04:04,376 oic.oauth2.message:DEBUG JWS header: {'alg': 'RS256', 'kid': 'lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I'} 2019-10-09 07:04:04,376 oic.oauth2.message:DEBUG Found signing key. 2019-10-09 07:04:04,376 jwkest.jws:DEBUG Picking key by key type=RSA 2019-10-09 07:04:04,377 jwkest.jws:DEBUG Picking key based on alg=RS256, kid=lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I and use= 2019-10-09 07:04:04,377 jwkest.jws:DEBUG Picked: kid:lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I, use:sig, kty:RSA 2019-10-09 07:04:04,377 jwkest.jws:DEBUG Picked: kid:lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I, use:sig, kty:RSA 2019-10-09 07:04:04,377 jwkest.jws:DEBUG Verified message using key with kid=lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I 2019-10-09 07:04:04,377 jwkest.jws:DEBUG Picking key by key type=RSA 2019-10-09 07:04:04,377 jwkest.jws:DEBUG Picking key based on alg=RS256, kid=None and use=sig 2019-10-09 07:04:04,377 jwkest.jws:DEBUG Picked: kid:lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I, use:sig, kty:RSA 2019-10-09 07:04:04,378 root:DEBUG JWT header: {'alg': 'RS256', 'kid': 'lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I'} 2019-10-09 07:04:04,379 jwkest.jws:DEBUG Signed message using key with kid=lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I 2019-10-09 07:04:04,379 cherrypy.access.140367853023584:INFO 172.20.0.1 - - [09/Oct/2019:07:04:04] "GET /mod_auth_openidc-code/rp-frontchannel-rpinitlogout/end_session?id_token_hint=eyJhbGciOiJSUzI1NiIsImtpZCI6ImxtV25EanduTFV4NUV4WlU4UVBkZnBxNmJ2TjZrRTJFVklYUFYzZWhlLUkifQ.eyJpc3MiOiAiaHR0cHM6Ly9ycC10ZXN0OjgwODAvbW9kX2F1dGhfb3BlbmlkYy1jb2RlL3JwLWZyb250Y2hhbm5lbC1ycGluaXRsb2dvdXQiLCAic3ViIjogIjFiMmZjOTM0MWExNmFlNGUzMDA4Mjk2NWQ1MzdhZTQ3YzIxYTBmMjdmZDQzZWFiNzgzMzBlZDgxNzUxYWU2ZGIiLCAiYXVkIjogWyJ5ODZvOXg1eHc0RTIiXSwgImV4cCI6IDE1NzA2OTEwNDQsICJhY3IiOiAiUEFTU1dPUkQiLCAiaWF0IjogMTU3MDYwNDY0NCwgImF1dGhfdGltZSI6IDE1NzA2MDQ2NDQsICJub25jZSI6ICJKWTFWb3NDcW5vYzZ5Rkh4ellMLXJlSU1MYU5ua1ZOa1F0eGJRMWJIaWJnIn0.BHwDeeqN8NYd5Rcb5mLu3E0XPtlm97CEDnnSAahCUedWSzbOnegXPrmOWoDdAwnpGbGj4k0SQFakB_WI08Jp-65-qUYU9H3y9_LHpBiQUk6C0ljkkquGJjdnlYgQ6xQRM8Aq3ntNBwTC27kuaQT_w233598NBisdL3iJx1Ef6GVjmgFa4NvVSvht-pGKTB_B_3s6hhVwygwmcCJZrMkMTTCaxzkTf7aWHWQaG8ECVvCj9Z-jiM2lNOYHHmvGsb2n7tla6ofErzdLq1Q-sRe8LLkDNDyeAa_BYPWR7w6TSmi8db6cmSY1a1QNM6t9CBGVRbRNcuPDeRiHKbHLf0IMaA&post_logout_redirect_uri=https%3A%2F%2Flocalhost.zmartzone.eu%2Floggedout.html HTTP/1.1" 302 2365 "" "curl/7.66.0" 2019-10-09 07:04:04,427 oidctest.cp.op:INFO ent:172.20.0.1, vpath: ['mod_auth_openidc-code', 'rp-frontchannel-rpinitlogout', 'logout'] 2019-10-09 07:04:04,428 oidctest.cp.op:DEBUG LogoutRequest: {'sjwt': 'eyJhbGciOiJSUzI1NiIsImtpZCI6ImxtV25EanduTFV4NUV4WlU4UVBkZnBxNmJ2TjZrRTJFVklYUFYzZWhlLUkifQ.eyJpc3MiOiAiaHR0cHM6Ly9ycC10ZXN0OjgwODAvbW9kX2F1dGhfb3BlbmlkYy1jb2RlL3JwLWZyb250Y2hhbm5lbC1ycGluaXRsb2dvdXQiLCAiaWF0IjogMTU3MDYwNDY0NCwgImV4cCI6IDE1NzA2OTEwNDQsICJraWQiOiAibG1XbkRqd25MVXg1RXhaVThRUGRmcHE2YnZONmtFMkVWSVhQVjNlaGUtSSIsICJhdWQiOiBbImh0dHBzOi8vcnAtdGVzdDo4MDgwL21vZF9hdXRoX29wZW5pZGMtY29kZS9ycC1mcm9udGNoYW5uZWwtcnBpbml0bG9nb3V0Il0sICJ1aWQiOiAiZGlhbmEiLCAiY2xpZW50X2lkIjogInk4Nm85eDV4dzRFMiIsICJyZWRpcmVjdF91cmkiOiAiaHR0cHM6Ly9sb2NhbGhvc3Quem1hcnR6b25lLmV1L2xvZ2dlZG91dC5odG1sIiwgInNpZCI6ICIxMWIwM2I5NzI5MjAxM2M1OTBjMzU0NmU1YWE0NmU5ZjVkMjgyZTlhNTgwMmRjMjQ1ODY0M2E1ZiIsICJqdGkiOiAiZWI5MDQyODMwNTYwNGI4YmI0MWY3NGZlYmI3ODZhZjIifQ.SUtVndibgp_rM42So6bq09vcWtKv4ulM1uz0TtXVNaFpP3-gLdgMGgOc6W5kVFJIFne_ieX_C58hhq1PxbMVUUPb_NlTaBtn23ulvc_jUOIVYmXKWhK4qK302OcwD7ooccJRK2N4SVdxSMmKGEz6qY5KbLLk8OUZUlsvgJLdvLzPLF7HJWepDzhbGVjucQFjzgbNqH4fsghJndzMEZFirWqSU0TAigjWAL4gMoRTAhGu2jZGb4-FElpyQejjY9LvPzhuivGg6dFHxMo65Cvlagov3Fo6wOtn4zYjVF5onLnRWvGEahwo3kF2vtEDBsvWXitbQuBWzI3Qn9mFmKoy8Q'} 2019-10-09 07:04:04,428 jwkest.jws:DEBUG Picking key by key type=RSA 2019-10-09 07:04:04,428 jwkest.jws:DEBUG Picking key based on alg=RS256, kid=lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I and use= 2019-10-09 07:04:04,428 jwkest.jws:DEBUG Picked: kid:lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I, use:sig, kty:RSA 2019-10-09 07:04:04,428 jwkest.jws:DEBUG Verified message using key with kid=lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I 2019-10-09 07:04:04,429 oidctest.cp.op:DEBUG SJWT unpacked: {'iss': 'https://rp-test:8080/mod_auth_openidc-code/rp-frontchannel-rpinitlogout', 'iat': 1570604644, 'exp': 1570691044, 'kid': 'lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I', 'aud': ['https://rp-test:8080/mod_auth_openidc-code/rp-frontchannel-rpinitlogout'], 'uid': 'diana', 'client_id': 'y86o9x5xw4E2', 'redirect_uri': 'https://localhost.zmartzone.eu/loggedout.html', 'sid': '11b03b97292013c590c3546e5aa46e9f5d282e9a5802dc2458643a5f', 'jti': 'eb90428305604b8bb41f74febb786af2'} 2019-10-09 07:04:04,429 jwkest.jws:DEBUG Picking key by key type=RSA 2019-10-09 07:04:04,429 jwkest.jws:DEBUG Picking key based on alg=RS256, kid=None and use=sig 2019-10-09 07:04:04,429 jwkest.jws:DEBUG Picked: kid:lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I, use:sig, kty:RSA 2019-10-09 07:04:04,429 root:DEBUG JWT header: {'alg': 'RS256', 'kid': 'lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I'} 2019-10-09 07:04:04,430 jwkest.jws:DEBUG Signed message using key with kid=lmWnDjwnLUx5ExZU8QPdfpq6bvN6kE2EVIXPV3ehe-I 2019-10-09 07:04:04,430 oic.oic.provider:INFO logging out from y86o9x5xw4E2 at https://localhost.zmartzone.eu/protected/?logout=backchannel 2019-10-09 07:04:04,431 urllib3.connectionpool:DEBUG Starting new HTTPS connection (1): localhost.zmartzone.eu:443 2019-10-09 07:04:04,434 oic.oauth2.base:ERROR http_request failed: HTTPSConnectionPool(host='localhost.zmartzone.eu', port=443): Max retries exceeded with url: /protected/?logout=backchannel (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x7fa9ef670588>: Failed to establish a new connection: [Errno 111] Connection refused',)), url: https://localhost.zmartzone.eu/protected/?logout=backchannel, htargs: {'allow_redirects': False, 'cert': None, 'verify': False, 'timeout': 5, 'data': 'logouttoken=eyJhbGciOiJSUzI1NiIsImtpZCI6ImxtV25EanduTFV4NUV4WlU4UVBkZnBxNmJ2TjZrRTJFVklYUFYzZWhlLUkifQ.eyJpc3MiOiAiaHR0cHM6Ly9ycC10ZXN0OjgwODAvbW9kX2F1dGhfb3BlbmlkYy1jb2RlL3JwLWZyb250Y2hhbm5lbC1ycGluaXRsb2dvdXQiLCAiaWF0IjogMTU3MDYwNDY0NCwgImV4cCI6IDE1NzA2OTEwNDQsICJraWQiOiAibG1XbkRqd25MVXg1RXhaVThRUGRmcHE2YnZONmtFMkVWSVhQVjNlaGUtSSIsICJhdWQiOiBbInk4Nm85eDV4dzRFMiJdLCAic3ViIjogIjFiMmZjOTM0MWExNmFlNGUzMDA4Mjk2NWQ1MzdhZTQ3YzIxYTBmMjdmZDQzZWFiNzgzMzBlZDgxNzUxYWU2ZGIiLCAic2lkIjogIjExYjAzYjk3MjkyMDEzYzU5MGMzNTQ2ZTVhYTQ2ZTlmNWQyODJlOWE1ODAyZGMyNDU4NjQzYTVmIiwgImV2ZW50cyI6IHsiaHR0cDovL3NjaGVtYXMub3BlbmlkLm5ldC9ldmVudC9iYWNrY2hhbm5lbC1sb2dvdXQiOiB7fX0sICJqdGkiOiAiZGQ1OWIxYWI3OGM2NDkwNTgyMWUyZTRiYzUxYjc1MWUifQ.Xyk1qnmr8u5D9rJdwSJZCAX4PWWqoNE70xKhisDnXnE0yHniFLLmGdiVCKHgsSL-6N-j1IFqUz_oi6_4MIc4Ia9CaKXJpc4-WrjZPRNhAZD2k_CZ4i8i314iuTMONptxOVVhllzPnlSYqQGKfNaQSIbD_rVlx9NjzQeOKurY4wia7cQ6OzhfNNWWaK3dEQodcE84gSabx_uko5OIeoEqOGX5ZzYXh2SIcObnAbpaSm70A1sQhTtZMpHNZua5ngRiAe26ciqIOec1IDIDEIxEpXtUjvAbKICoD41WdoW5XNbksqj-okwb60xOHHFregLjdJ7GwSaEIQw3sbDM1i1UQ'}, method: POST 2019-10-09 07:04:04,434 oidctest.cp.op:ERROR HTTPSConnectionPool(host='localhost.zmartzone.eu', port=443): Max retries exceeded with url: /protected/?logout=backchannel (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x7fa9ef670588>: Failed to establish a new connection: [Errno 111] Connection refused',)) Traceback (most recent call last): File "/usr/local/lib/python3.6/dist-packages/urllib3-1.25.6-py3.6.egg/urllib3/connection.py", line 157, in _new_conn (self._dns_host, self.port), self.timeout, **extra_kw File "/usr/local/lib/python3.6/dist-packages/urllib3-1.25.6-py3.6.egg/urllib3/util/connection.py", line 84, in create_connection raise err File "/usr/local/lib/python3.6/dist-packages/urllib3-1.25.6-py3.6.egg/urllib3/util/connection.py", line 74, in create_connection sock.connect(sa) ConnectionRefusedError: [Errno 111] Connection refused

rohe commented 4 years ago

Just checked in a fix that should take care of this.