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

python exception when running OP-request_uri-Unsigned with implicit flow #130

Open djfwong opened 5 years ago

djfwong commented 5 years ago

Hi there,

I am having an issue with running the following test OP-request_uri-Unsigned when using Implicit flow with id_token as the response type. The test passes for me in Basic flow, and the implementation is doing the same thing in both cases, is there anything being done to unblock this test?

In the server log for the implementation, we are giving the following error message: Endpoint: https://op.certification.openid.net:61401/authz_cb#error_description=processing+of+the+request_uri+parameter+is+unsupported&state=k9K1FihvDmpisK7v&error=request_uri_not_supported, which is consistent with what we do for the Basic profile.

This is my exception:
Something went seriously wrong, please tell us at certification@oidf.org
********************************************************************************

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/oidctest-0.7.3-py3.6.egg/oidctest/optt/__init__.py", line 288, in authz_post
    response=kwargs)
  File "/usr/local/lib/python3.6/dist-packages/otest-0.7.7-py3.6.egg/otest/aus/tool.py", line 225, in async_response
    response=response)
  File "/usr/local/lib/python3.6/dist-packages/otest-0.7.7-py3.6.egg/otest/aus/request.py", line 352, in parse_response
    raise Break("Unexpected error response")
otest.Break: Unexpected error response

There is the implementation's log:
2018-09-20 22:03:35,795  DEBUG [com.pingidentity.rest.oauth.clientregistration.controller.ClientRegistrationController] Registering a new client
2018-09-20 22:03:35,795  DEBUG [com.pingidentity.rest.oauth.clientregistration.controller.ClientRegistrationController] Request content type : [application/json]
2018-09-20 22:03:35,795  DEBUG [com.pingidentity.rest.oauth.clientregistration.controller.ClientRegistrationController] Parsing input JSON
2018-09-20 22:03:35,795  DEBUG [com.pingidentity.rest.oauth.clientregistration.controller.ClientRegistrationController] Applying default values.
2018-09-20 22:03:35,795  DEBUG [com.pingidentity.rest.oauth.clientregistration.controller.ClientRegistrationController] Applying post policy process default values.
2018-09-20 22:03:35,845  DEBUG [com.pingidentity.common.util.ldap.LDAPCrudHelper] entry: pf-oauth-client-id=dc-t9tEsOsWkE0aBB6WM3wjgS,OU=ConformanceClients,DC=example,DC=com successfully added to the LDAP data store
2018-09-20 22:03:35,848  INFO  [com.pingidentity.rest.oauth.clientregistration.controller.ClientRegistrationController] Client was created successfully
2018-09-20 22:03:36,272 tid:ia_8VJTjRCQz7TWN8aWYpuFT3IE DEBUG [org.sourceid.websso.servlet.ProtocolControllerServlet] ---REQUEST (GET)/as/authorization.oauth2 from 209.133.96.106: 
---PARAMETERS---
scope:
   openid
response_type:
   id_token
state:
   k9K1FihvDmpisK7v
redirect_uri:
   https://op.certification.openid.net:61401/authz_cb
nonce:
   H5wlTwdfAfCVVJX4
client_id:
   dc-t9tEsOsWkE0aBB6WM3wjgS
request_uri:
   https://op.certification.openid.net:61401/export/QAWYU1VvnA.jwt

2018-09-20 22:03:36,272 tid:ia_8VJTjRCQz7TWN8aWYpuFT3IE DEBUG [org.sourceid.saml20.bindings.BindingFactory] GET
 with Params: [scope, response_type, state, redirect_uri, nonce, client_id, request_uri]
 assume binding: oauth:authz
 from: 209.133.96.106
 Referer: https://op.certification.openid.net:61401/profile
 AuthType: null
 Content-Type: null
2018-09-20 22:03:36,486 tid:ia_8VJTjRCQz7TWN8aWYpuFT3IE DEBUG [org.sourceid.saml20.bindings.LoggingInterceptor] Received InMessageContext:
InMessageContext
entityId: dc-t9tEsOsWkE0aBB6WM3wjgS (null)
virtualServerId: null
Binding: oauth:authz
relayState: k9K1FihvDmpisK7v
params: {access_token_manager_id=null, response_type=id_token, nonce=H5wlTwdfAfCVVJX4, response_mode=null, aud=null, login_hint=null, ui_locales=null, claims_locales=null, scope=openid, acr_values=null, redirect_uri=https://op.certification.openid.net:61401/authz_cb, prompt=null}

2018-09-20 22:03:36,583 tid:ia_8VJTjRCQz7TWN8aWYpuFT3IE DEBUG [org.sourceid.oauth20.handlers.HandleAuthorizationRequest] Normal exception being handled during OAuth request processing: org.sourceid.oauth20.handlers.AuthorizationRequestException: request_uri_not_supported: processing of the request_uri parameter is unsupported
2018-09-20 22:03:36,584 tid:ia_8VJTjRCQz7TWN8aWYpuFT3IE DEBUG [org.sourceid.saml20.bindings.LoggingInterceptor] Transported Response. OutMessageContext:
OutMessageContext
entityId: dc-t9tEsOsWkE0aBB6WM3wjgS (null)
virtualServerId: null
Binding: oauth:authz
relayState: k9K1FihvDmpisK7v
params: {state=k9K1FihvDmpisK7v, error=request_uri_not_supported, error_description=processing of the request_uri parameter is unsupported}
Endpoint: https://op.certification.openid.net:61401/authz_cb#error_description=processing+of+the+request_uri+parameter+is+unsupported&state=k9K1FihvDmpisK7v&error=request_uri_not_supported
SignaturePolicy: BINDING_DEFAULT
zandbelt commented 5 years ago

I'm confused: your OP does not support this test so why would you want it to pass? The test suite should somehow record that your OP does not support this, right? I agree the stacktrace is somewhat rough but is that your concern then?

djfwong commented 5 years ago

Yes correct, when it errors out I can’t grab the test logs. It doesn’t have to successfully pass, just not error out and enough to satisfy conformance requirements. Currently I can’t grab the test logs even if it fails since all I see is the python exception.

zandbelt commented 5 years ago

I see, grabbing the logs is important here. And your saying that running this test in Basic ("code") flow does correctly record an error in log files, correct?

djfwong commented 5 years ago

Yes. Seems broken for me in implicit mode so far, basic code flow was fine. I can’t remember if that also happens for hybrid mode as well, will need to check tomorrow. Thanks for taking a look Hans.

zandbelt commented 5 years ago

Although this is a defect that should and will be fixed (I've patched it locally already), I'm running into a few things here:

It seems you're using statically configured provider information and use the default setting for request_uri_parameter_supported which is True. Setting this to False would be an obvious solution that is more correct since you don't support request_uri's, if it weren't for the fact that we're running into another limitation of the test tool wrt. configuration boolean values for statically provided registration values...

Another workaround for the time being would be to use auto-configured provider through Discovery which would indicated request_uri_parameter_supported: false and the tests would abort with a warning. (I know PingFederate has a Discovery metadata template that can be tweaked...)

Is that possible whilst waiting for the 2 fixes?

djfwong commented 5 years ago

How long until the fixes get pushed to the main tool? Yeah I can take a look at PF settings to bypass the failure that’s a great suggestion thanks Hans

zandbelt commented 5 years ago

just no ETA right now

djfwong commented 5 years ago

Hello Hans, I tried what you suggested by modifying the well known endpoint template to always say false (https://oidc-conformance.ping-eng.com:9031/.well-known/openid-configuration) And the test still fails for me. I still see the same Python exception as earlier. I tried in implicit mode, but would assume it would fail in hybrid as well as that was happening to me earlier before the template change.

zandbelt commented 5 years ago

If you're using the same setup as before, it is still statically configured so it doesn't use the (old or new) Discovery document. See: https://op.certification.openid.net:60000/action/https%3A%2F%2Foidc-conformance.ping-eng.com%3A9031/Dynamic%20and%20Form%20POST%20OP?action=configure You'd need to enable "discover". To do that you need to register a new "tag" for your issuer, this time with "discover" set to "true".

Edit: besides that, the default provided by PingFederate is already set to "false" I believe.

djfwong commented 5 years ago

Ah! right, thanks Han! Will give that a try, thanks again

zandbelt commented 5 years ago

The proposed fix in otest would/could be:

diff --git a/src/otest/aus/request.py b/src/otest/aus/request.py
index f29e5b5..75b1f82 100644
--- a/src/otest/aus/request.py
+++ b/src/otest/aus/request.py
@@ -20,6 +20,7 @@
 from otest import Unknown
 from otest import operation
 from otest.check import ERROR
+from otest.check import WARNING
 from otest.check import State
 from otest.events import EV_FAULT
 from otest.events import EV_HTTP_RESPONSE
@@ -349,7 +350,9 @@
             self.expected_error_response(response)
         else:
             if isinstance(response, ErrorResponse):
-                raise Break("Unexpected error response")
+                _conv.events.store(EV_FAULT, State(_conv.test_id, WARNING,
+                                                   message=response["error"],
+                                                   context='error_response'))

 def same_issuer(issuer_A, issuer_B):

so unexpected errors are logged and can be included in certification results (as failed) instead of the flow being terminated with no log entries.

I'm not sure if this has any side effects... @rohe can you comment?