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: oic.utils.http_util.InvalidCookieSign #197

Closed zandbelt closed 4 years ago

zandbelt commented 4 years ago

2019-11-08 07:26:44,139 oidctest.cp.op:INFO ent:212.84.155.17, vpath: ['mod_auth_openidc-code', 'rp-frontchannel-rpinitlogout', 'end_session'] 2019-11-08 07:26:44,139 oidctest.cp.op:DEBUG EndSessionRequest: {'id_token_hint': 'eyJhbGciOiJSUzI1NiIsImtpZCI6Im1Fa2MxbFF5Z29VMTBqMk5sVUUtWVlCdjJ1b2FKMXhHLUZua0dxZlRsRzAifQ.eyJpc3MiOiAiaHR0cHM6Ly9uZXctcnAuY2VydGlmaWNhdGlvbi5vcGVuaWQubmV0OjgwODAvbW9kX2F1dGhfb3BlbmlkYy1jb2RlL3JwLWZyb250Y2hhbm5lbC1ycGluaXRsb2dvdXQiLCAic3ViIjogIjFiMmZjOTM0MWExNmFlNGUzMDA4Mjk2NWQ1MzdhZTQ3YzIxYTBmMjdmZDQzZWFiNzgzMzBlZDgxNzUxYWU2ZGIiLCAiYXVkIjogWyJLMDFYV0Y2T3RtbUwiXSwgImV4cCI6IDE1NzMyODQ0MDIsICJhY3IiOiAiUEFTU1dPUkQiLCAiaWF0IjogMTU3MzE5ODAwMiwgImF1dGhfdGltZSI6IDE1NzMxOTgwMDIsICJub25jZSI6ICJJU09RbS1jWk5jVGtxUHpxUnE2MDZTSWJaVVRpcWRvcV9qNml4SjZhLXlnIn0.sgLLVfXJLYTNtCRIy99w4KgCc7oOSWmuJl0cGzeDKRLOQERONFb-w3415M3PBzWFbh5TGIli7qKxIRPNphgDCH1npwVVwyBPLx-0F-ZsQDV2VpiW3P93dortZTSyihEkGlB73Omy-f8yFLqHNn4HA3wUl7siNUvzDJ5h9LBfSQ8IIgCv4Yuv_DfyV-e_qXXKMb73TG4_QSjTjJFoPquxdpbENWwN5kY-Zfil4nY9IHmMONSeRjBztbt9OK9b1BE3NpWou346CkbJZNHOzOAGCwBi_wpCybBJFP1bmEVCzpt0H_MIfqg8ghcVqPTpzvJhJR6IPxezl5eRtPP2YY-IHw'} 2019-11-08 07:26:44,140 oic.oic.provider:DEBUG End session request: {'id_token_hint': 'eyJhbGciOiJSUzI1NiIsImtpZCI6Im1Fa2MxbFF5Z29VMTBqMk5sVUUtWVlCdjJ1b2FKMXhHLUZua0dxZlRsRzAifQ.eyJpc3MiOiAiaHR0cHM6Ly9uZXctcnAuY2VydGlmaWNhdGlvbi5vcGVuaWQubmV0OjgwODAvbW9kX2F1dGhfb3BlbmlkYy1jb2RlL3JwLWZyb250Y2hhbm5lbC1ycGluaXRsb2dvdXQiLCAic3ViIjogIjFiMmZjOTM0MWExNmFlNGUzMDA4Mjk2NWQ1MzdhZTQ3YzIxYTBmMjdmZDQzZWFiNzgzMzBlZDgxNzUxYWU2ZGIiLCAiYXVkIjogWyJLMDFYV0Y2T3RtbUwiXSwgImV4cCI6IDE1NzMyODQ0MDIsICJhY3IiOiAiUEFTU1dPUkQiLCAiaWF0IjogMTU3MzE5ODAwMiwgImF1dGhfdGltZSI6IDE1NzMxOTgwMDIsICJub25jZSI6ICJJU09RbS1jWk5jVGtxUHpxUnE2MDZTSWJaVVRpcWRvcV9qNml4SjZhLXlnIn0.sgLLVfXJLYTNtCRIy99w4KgCc7oOSWmuJl0cGzeDKRLOQERONFb-w3415M3PBzWFbh5TGIli7qKxIRPNphgDCH1npwVVwyBPLx-0F-ZsQDV2VpiW3P93dortZTSyihEkGlB73Omy-f8yFLqHNn4HA3wUl7siNUvzDJ5h9LBfSQ8IIgCv4Yuv_DfyV-e_qXXKMb73TG4_QSjTjJFoPquxdpbENWwN5kY-Zfil4nY9IHmMONSeRjBztbt9OK9b1BE3NpWou346CkbJZNHOzOAGCwBi_wpCybBJFP1bmEVCzpt0H_MIfqg8ghcVqPTpzvJhJR6IPxezl5eRtPP2YY-IHw'} 2019-11-08 07:26:44,140 cherrypy.error.140437853786576:ERROR [08/Nov/2019:07:26:44] HTTP Traceback (most recent call last): File "/usr/local/lib/python3.6/dist-packages/oic-1.1.1-py3.6.egg/oic/utils/aes.py", line 209, in decrypt_and_verify return self.kernel.decrypt_and_verify(cipherdata, tag) File "/usr/local/lib/python3.6/dist-packages/pycryptodomex-3.6.6-py3.6-linux-x86_64.egg/Cryptodome/Cipher/_mode_siv.py", line 339, in decrypt_and_verify self.verify(mac_tag) File "/usr/local/lib/python3.6/dist-packages/pycryptodomex-3.6.6-py3.6-linux-x86_64.egg/Cryptodome/Cipher/_mode_siv.py", line 255, in verify raise ValueError("MAC check failed") ValueError: MAC check failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.6/dist-packages/oic-1.1.1-py3.6.egg/oic/utils/http_util.py", line 459, in parse_cookie cleartext = crypt.decrypt_and_verify(ciphertext, tag) File "/usr/local/lib/python3.6/dist-packages/oic-1.1.1-py3.6.egg/oic/utils/aes.py", line 211, in decrypt_and_verify raise AESError("Failed to verify data") oic.utils.aes.AESError: Failed to verify data

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.6/dist-packages/CherryPy-8.9.1-py3.6.egg/cherrypy/_cprequest.py", line 670, in respond response.body = self.handler() File "/usr/local/lib/python3.6/dist-packages/CherryPy-8.9.1-py3.6.egg/cherrypy/lib/encoding.py", line 220, in call self.body = self.oldhandler(*args, *kwargs) File "/usr/local/lib/python3.6/dist-packages/CherryPy-8.9.1-py3.6.egg/cherrypy/_cpdispatch.py", line 60, in call return self.callable(self.args, self.kwargs) File "/usr/local/lib/python3.6/dist-packages/oidctest-0.9.0-py3.6.egg/oidctest/cp/op.py", line 359, in index resp = op.end_session_endpoint(_info.to_urlencoded(), cookie=cookie) File "/usr/local/lib/python3.6/dist-packages/oidctest-0.9.0-py3.6.egg/oidctest/rp/provider.py", line 650, in end_session_endpoint kwargs) File "/usr/local/lib/python3.6/dist-packages/oic-1.1.1-py3.6.egg/oic/oic/provider.py", line 2130, in end_sessionendpoint , client_id, uid = self._get_uid_from_cookie(cookie) File "/usr/local/lib/python3.6/dist-packages/oic-1.1.1-py3.6.egg/oic/oic/provider.py", line 1976, in _get_uid_from_cookie _cval = cookie_dealer.get_cookie_value(cookie, self.sso_cookie_name) File "/usr/local/lib/python3.6/dist-packages/oic-1.1.1-py3.6.egg/oic/utils/http_util.py", line 645, in get_cookie_value cookie_name, self.srv.seed, cookie, self.srv.symkey File "/usr/local/lib/python3.6/dist-packages/oic-1.1.1-py3.6.egg/oic/utils/http_util.py", line 461, in parse_cookie raise InvalidCookieSign() oic.utils.http_util.InvalidCookieSign

rohe commented 4 years ago

Can't replicate this error. So, I have no idea what's going on.

rohe commented 4 years ago

Am I right in that you only saw this once ?

zandbelt commented 4 years ago

no, it is repeatable for me, always happens

rohe commented 4 years ago

OK, I'll see if I can get some time to look at it tomorrow.

rohe commented 4 years ago

Probably have to add some more logging lines in the code. I will do that directly in the code on new_rp.

zandbelt commented 4 years ago

after pushing the latest changes to new-rp the result is still:

2019-11-11 08:16:06,716 oidctest.cp.op:INFO ent:212.84.155.17, vpath: ['mod_auth_openidc-code', 'rp-frontchannel-rpinitlogout', 'end_session']
2019-11-11 08:16:06,717 oidctest.cp.op:DEBUG EndSessionRequest: {'id_token_hint': 'eyJhbGciOiJSUzI1NiIsImtpZCI6Im1Fa2MxbFF5Z29VMTBqMk5sVUUtWVlCdjJ1b2FKMXhHLUZua0dxZlRsRzAifQ.eyJpc3MiOiAiaHR0cHM6Ly9uZXctcnAuY2VydGlmaWNhdGlvbi5vcGVuaWQubmV0OjgwODAvbW9kX2F1dGhfb3BlbmlkYy1jb2RlL3JwLWZyb250Y2hhbm5lbC1ycGluaXRsb2dvdXQiLCAic3ViIjogIjFiMmZjOTM0MWExNmFlNGUzMDA4Mjk2NWQ1MzdhZTQ3YzIxYTBmMjdmZDQzZWFiNzgzMzBlZDgxNzUxYWU2ZGIiLCAiYXVkIjogWyJ4bTVyWlBLSUlLTlQiXSwgImV4cCI6IDE1NzM1NDY1NjUsICJhY3IiOiAiUEFTU1dPUkQiLCAiaWF0IjogMTU3MzQ2MDE2NSwgImF1dGhfdGltZSI6IDE1NzM0NjAxNjUsICJub25jZSI6ICItc2NJamZjMGJ1Q3ltV1cxVEhQUWpJVmhneXBtQTNPWk9iV2kxd0JpZ2lFIn0.YTJhQALK1rHmF5mrE9mO91G0yU5V4Y4CGRO-QGfakC4_ssP5DJHs0uVmeCDKcdLafFIDl5mfeCfQcUiaSLZiJFINslJsagGskxRAwqwEhZGvwJxFMmuXrpqwAAn75DeYGKoNIeOdIf8r2Dy5zkSvVCyfIymRLf0vx6P-7NOtvZwbPM6r0w0AQi_V68cA7hZmuJST4tDw8-Gz9loChMC86oPmIi9mAgy7ZHAUSPTXeGSjS7RAkiviNgtYBdGpmNTw8SjcDBUmHBjXVWIvGDHr1Dm04NC6Uxzn4RpuBnJ0WiA3IfR4l--IBqIF_onOn1WM22itsh92SUn12dSOv7cLLg'}
2019-11-11 08:16:06,717 oidctest.cp.op:DEBUG Request cookie at end_session_endpoint: Set-Cookie: pyoidc_sso="1573460165|+EMs3qEga/TPxjLVd7j3Dw==|6L1z447whhtxp7EZP6K+O/7Ylty+lEEPvwYkRlbJI3T4haUz|1uNT80n4CMABnH4tSSQPUQ=="
Set-Cookie: session_id=34ab8e5192fce50899cf6d678753a738bd560b5d
2019-11-11 08:16:06,717 oic.oic.provider:DEBUG End session request: {'id_token_hint': 'eyJhbGciOiJSUzI1NiIsImtpZCI6Im1Fa2MxbFF5Z29VMTBqMk5sVUUtWVlCdjJ1b2FKMXhHLUZua0dxZlRsRzAifQ.eyJpc3MiOiAiaHR0cHM6Ly9uZXctcnAuY2VydGlmaWNhdGlvbi5vcGVuaWQubmV0OjgwODAvbW9kX2F1dGhfb3BlbmlkYy1jb2RlL3JwLWZyb250Y2hhbm5lbC1ycGluaXRsb2dvdXQiLCAic3ViIjogIjFiMmZjOTM0MWExNmFlNGUzMDA4Mjk2NWQ1MzdhZTQ3YzIxYTBmMjdmZDQzZWFiNzgzMzBlZDgxNzUxYWU2ZGIiLCAiYXVkIjogWyJ4bTVyWlBLSUlLTlQiXSwgImV4cCI6IDE1NzM1NDY1NjUsICJhY3IiOiAiUEFTU1dPUkQiLCAiaWF0IjogMTU3MzQ2MDE2NSwgImF1dGhfdGltZSI6IDE1NzM0NjAxNjUsICJub25jZSI6ICItc2NJamZjMGJ1Q3ltV1cxVEhQUWpJVmhneXBtQTNPWk9iV2kxd0JpZ2lFIn0.YTJhQALK1rHmF5mrE9mO91G0yU5V4Y4CGRO-QGfakC4_ssP5DJHs0uVmeCDKcdLafFIDl5mfeCfQcUiaSLZiJFINslJsagGskxRAwqwEhZGvwJxFMmuXrpqwAAn75DeYGKoNIeOdIf8r2Dy5zkSvVCyfIymRLf0vx6P-7NOtvZwbPM6r0w0AQi_V68cA7hZmuJST4tDw8-Gz9loChMC86oPmIi9mAgy7ZHAUSPTXeGSjS7RAkiviNgtYBdGpmNTw8SjcDBUmHBjXVWIvGDHr1Dm04NC6Uxzn4RpuBnJ0WiA3IfR4l--IBqIF_onOn1WM22itsh92SUn12dSOv7cLLg'}
2019-11-11 08:16:06,718 cherrypy.error.140149147738744:ERROR [11/Nov/2019:08:16:06] HTTP 
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/oic-1.1.1-py3.6.egg/oic/utils/aes.py", line 209, in decrypt_and_verify
    return self.kernel.decrypt_and_verify(cipherdata, tag)
  File "/usr/local/lib/python3.6/dist-packages/pycryptodomex-3.6.6-py3.6-linux-x86_64.egg/Cryptodome/Cipher/_mode_siv.py", line 339, in decrypt_and_verify
    self.verify(mac_tag)
  File "/usr/local/lib/python3.6/dist-packages/pycryptodomex-3.6.6-py3.6-linux-x86_64.egg/Cryptodome/Cipher/_mode_siv.py", line 255, in verify
    raise ValueError("MAC check failed")
ValueError: MAC check failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/oic-1.1.1-py3.6.egg/oic/utils/http_util.py", line 459, in parse_cookie
    cleartext = crypt.decrypt_and_verify(ciphertext, tag)
  File "/usr/local/lib/python3.6/dist-packages/oic-1.1.1-py3.6.egg/oic/utils/aes.py", line 211, in decrypt_and_verify
    raise AESError("Failed to verify data")
oic.utils.aes.AESError: Failed to verify data

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/CherryPy-8.9.1-py3.6.egg/cherrypy/_cprequest.py", line 670, in respond
    response.body = self.handler()
  File "/usr/local/lib/python3.6/dist-packages/CherryPy-8.9.1-py3.6.egg/cherrypy/lib/encoding.py", line 220, in __call__
    self.body = self.oldhandler(*args, **kwargs)
  File "/usr/local/lib/python3.6/dist-packages/CherryPy-8.9.1-py3.6.egg/cherrypy/_cpdispatch.py", line 60, in __call__
    return self.callable(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.6/dist-packages/oidctest-0.9.0-py3.6.egg/oidctest/cp/op.py", line 362, in index
    resp = op.end_session_endpoint(_info.to_urlencoded(), cookie=cookie)
  File "/usr/local/lib/python3.6/dist-packages/oidctest-0.9.0-py3.6.egg/oidctest/rp/provider.py", line 650, in end_session_endpoint
    **kwargs)
  File "/usr/local/lib/python3.6/dist-packages/oic-1.1.1-py3.6.egg/oic/oic/provider.py", line 2130, in end_session_endpoint
    _, client_id, uid = self._get_uid_from_cookie(cookie)
  File "/usr/local/lib/python3.6/dist-packages/oic-1.1.1-py3.6.egg/oic/oic/provider.py", line 1976, in _get_uid_from_cookie
    _cval = cookie_dealer.get_cookie_value(cookie, self.sso_cookie_name)
  File "/usr/local/lib/python3.6/dist-packages/oic-1.1.1-py3.6.egg/oic/utils/http_util.py", line 645, in get_cookie_value
    cookie_name, self.srv.seed, cookie, self.srv.symkey
  File "/usr/local/lib/python3.6/dist-packages/oic-1.1.1-py3.6.egg/oic/utils/http_util.py", line 461, in parse_cookie
    raise InvalidCookieSign()
oic.utils.http_util.InvalidCookieSign
rohe commented 4 years ago

The configuration is wrong. Don't know why it wasn't carried over example_conf.py contains the line:

SEED = b"abcdefghijklmnop"

Doesn't appear in conf.py . Absolutely vital.