Unexpected error when handling authentication request to identity provider. #45
Comments
|
Works fine for the single patient resourceId. For multiple ids, I see this event (invalid_user_credentials) logged in keycloak even though I provide correct login details. |
|
which version of keycloak? |
|
Keycloak version is 15.0.2.
Sorry. I am not keycloak expert. Where can I find server logs?
…________________________________
From: Lee Surprenant ***@***.***>
Sent: Thursday, February 24, 2022 10:28 PM
To: Alvearie/keycloak-extensions-for-fhir ***@***.***>
Cc: ssekar1976 ***@***.***>; Author ***@***.***>
Subject: Re: [Alvearie/keycloak-extensions-for-fhir] Unexpected error when handling authentication request to identity provider. (Issue #45)
which version of keycloak?
anything useful in the keycloak server logs?
—
Reply to this email directly, view it on GitHub<#45 (comment)>, or unsubscribe<https://github.com/notifications/unsubscribe-auth/AFKLPF4LW4FRWVS3BEVJFXLU43ZPNANCNFSM5PIZKZ2A>.
Triage notifications on the go with GitHub Mobile for iOS<https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675> or Android<https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub>.
You are receiving this because you authored the thread.Message ID: ***@***.***>
|
|
Hi Lee,
I do not see anything in the server logs.
I see 400 error in the access log.
[cid:1f079052-0f49-46d4-a485-c1125eca77b9]
…________________________________
From: Lee Surprenant ***@***.***>
Sent: Thursday, February 24, 2022 10:28 PM
To: Alvearie/keycloak-extensions-for-fhir ***@***.***>
Cc: ssekar1976 ***@***.***>; Author ***@***.***>
Subject: Re: [Alvearie/keycloak-extensions-for-fhir] Unexpected error when handling authentication request to identity provider. (Issue #45)
which version of keycloak?
anything useful in the keycloak server logs?
—
Reply to this email directly, view it on GitHub<#45 (comment)>, or unsubscribe<https://github.com/notifications/unsubscribe-auth/AFKLPF4LW4FRWVS3BEVJFXLU43ZPNANCNFSM5PIZKZ2A>.
Triage notifications on the go with GitHub Mobile for iOS<https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675> or Android<https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub>.
You are receiving this because you authored the thread.Message ID: ***@***.***>
|
|
This is the error i see in the server logs: 16:08:21,867 WARN [org.keycloak.events] (default task-65) type=LOGIN_ERROR, realmId=d1283bbc-de4a-4978-8e9c-cac7feee267d, clientId=inferno, userId=null, ipAddress=172.17.0.1, error=invalid_user_credentials, auth_method=openid-connect, auth_type=code, redirect_uri=http://localhost:4567/inferno/static/, code_id=55a44f94-d0ae-455c-b883-55efd985c336, username=fhiruser, authSessionParentId=55a44f94-d0ae-455c-b883-55efd985c336, authSessionTabId=_CA2MdLA-FY 16:17:41,095 INFO [org.alvearie.keycloak.PatientSelectionForm] (default task-65) Client request is missing the 'aud' parameter, using 'http://localhost:4080/' from config. 16:17:41,098 WARN [org.keycloak.services] (default task-65) KC-SERVICES0013: Failed authentication: javax.ws.rs.ProcessingException: RESTEASY004655: Unable to invoke request: org.apache.http.conn.HttpHostConnectException: Connect to localhost:4080 [localhost/127.0.0.1] failed: Connection refused (Connection refused) at [email protected]//org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient4Engine.invoke(ApacheHttpClient4Engine.java:341) at [email protected]//org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.invoke(ClientInvocation.java:464) at [email protected]//org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.invoke(ClientInvocation.java:65) at [email protected]//org.jboss.resteasy.client.jaxrs.internal.ClientInvocationBuilder.post(ClientInvocationBuilder.java:232) at deployment.keycloak-extensions-0.0.1-SNAPSHOT.jar//org.alvearie.keycloak.PatientSelectionForm.authenticate(PatientSelectionForm.java:123) at [email protected]//org.keycloak.authentication.DefaultAuthenticationFlow.processSingleFlowExecutionModel(DefaultAuthenticationFlow.java:446) at [email protected]//org.keycloak.authentication.DefaultAuthenticationFlow.processFlow(DefaultAuthenticationFlow.java:253) at [email protected]//org.keycloak.authentication.DefaultAuthenticationFlow.processSingleFlowExecutionModel(DefaultAuthenticationFlow.java:389) at [email protected]//org.keycloak.authentication.DefaultAuthenticationFlow.continueAuthenticationAfterSuccessfulAction(DefaultAuthenticationFlow.java:186) at [email protected]//org.keycloak.authentication.DefaultAuthenticationFlow.processAction(DefaultAuthenticationFlow.java:164) at [email protected]//org.keycloak.authentication.AuthenticationProcessor.authenticationAction(AuthenticationProcessor.java:950) at [email protected]//org.keycloak.services.resources.LoginActionsService.processFlow(LoginActionsService.java:312) at [email protected]//org.keycloak.services.resources.LoginActionsService.processAuthentication(LoginActionsService.java:283) at [email protected]//org.keycloak.services.resources.LoginActionsService.authenticate(LoginActionsService.java:267) at [email protected]//org.keycloak.services.resources.LoginActionsService.authenticateForm(LoginActionsService.java:340) at jdk.internal.reflect.GeneratedMethodAccessor969.invoke(Unknown Source) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at [email protected]//org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:138) at [email protected]//org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:546) at [email protected]//org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:435) at [email protected]//org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$0(ResourceMethodInvoker.java:396) at [email protected]//org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:358) at [email protected]//org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:398) at [email protected]//org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:365) at [email protected]//org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:150) at [email protected]//org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:104) at [email protected]//org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:440) at [email protected]//org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:229) at [email protected]//org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:135) at [email protected]//org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:358) at [email protected]//org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:138) at [email protected]//org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:215) at [email protected]//org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:245) at [email protected]//org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:61) at [email protected]//org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56) at [email protected]//javax.servlet.http.HttpServlet.service(HttpServlet.java:590) at [email protected]//io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74) at [email protected]//io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129) at [email protected]//org.keycloak.provider.wildfly.WildFlyRequestFilter.lambda$doFilter$0(WildFlyRequestFilter.java:41) at [email protected]//org.keycloak.services.filters.AbstractRequestFilter.filter(AbstractRequestFilter.java:43) at [email protected]//org.keycloak.provider.wildfly.WildFlyRequestFilter.doFilter(WildFlyRequestFilter.java:39) at [email protected]//io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) at [email protected]//io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at [email protected]//io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84) at [email protected]//io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62) at [email protected]//io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68) at [email protected]//io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36) at [email protected]//org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78) at [email protected]//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at [email protected]//io.undertow.servlet.handlers.RedirectDirHandler.handleRequest(RedirectDirHandler.java:68) at [email protected]//io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:117) at [email protected]//io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57) at [email protected]//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at [email protected]//io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46) at [email protected]//io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64) at [email protected]//io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60) at [email protected]//io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77) at [email protected]//io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50) at [email protected]//io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43) at [email protected]//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at [email protected]//org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61) at [email protected]//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at [email protected]//org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68) at [email protected]//io.undertow.servlet.handlers.SendErrorPageHandler.handleRequest(SendErrorPageHandler.java:52) at [email protected]//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at [email protected]//io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:269) at [email protected]//io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:78) at [email protected]//io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:133) at [email protected]//io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:130) at [email protected]//io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48) at [email protected]//io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43) at [email protected]//org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105) at [email protected]//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1530) at [email protected]//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1530) at [email protected]//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1530) at [email protected]//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1530) at [email protected]//io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:249) at [email protected]//io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:78) at [email protected]//io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:99) at [email protected]//io.undertow.server.Connectors.executeRootHandler(Connectors.java:387) at [email protected]//io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:841) at [email protected]//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35) at [email protected]//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990) at [email protected]//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486) at [email protected]//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377) at [email protected]//org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1280) at java.base/java.lang.Thread.run(Thread.java:829) Caused by: org.apache.http.conn.HttpHostConnectException: Connect to localhost:4080 [localhost/127.0.0.1] failed: Connection refused (Connection refused) at org.apache.httpcomponents.core//org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:156) at org.apache.httpcomponents.core//org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376) at org.apache.httpcomponents.core//org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:393) at org.apache.httpcomponents.core//org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236) at org.apache.httpcomponents.core//org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186) at org.apache.httpcomponents.core//org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89) at org.apache.httpcomponents.core//org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110) at org.apache.httpcomponents.core//org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185) at org.apache.httpcomponents.core//org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83) at org.apache.httpcomponents.core//org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56) at [email protected]//org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient4Engine.invoke(ApacheHttpClient4Engine.java:336) ... 87 more Caused by: java.net.ConnectException: Connection refused (Connection refused) at java.base/java.net.PlainSocketImpl.socketConnect(Native Method) at java.base/java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:399) at java.base/java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:242) at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:224) at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.base/java.net.Socket.connect(Socket.java:609) at org.apache.httpcomponents.core//org.apache.http.conn.socket.PlainConnectionSocketFactory.connectSocket(PlainConnectionSocketFactory.java:75) at org.apache.httpcomponents.core//org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142) ... 97 more 16:17:41,100 WARN [org.keycloak.events] (default task-65) type=LOGIN_ERROR, realmId=d1283bbc-de4a-4978-8e9c-cac7feee267d, clientId=inferno, userId=null, ipAddress=172.17.0.1, error=invalid_user_credentials, auth_method=openid-connect, auth_type=code, redirect_uri=http://localhost:4567/inferno/static/, code_id=55a44f94-d0ae-455c-b883-55efd985c336, username=fhiruser, authSessionParentId=55a44f94-d0ae-455c-b883-55efd985c336, authSessionTabId=ShD-AVp7eo4 |
|
I was able to fix the earlier issue by setting FHIR_BASE_URL=http://172.30.96.1:4080/ (instead of localhost:4080) for alvearie/keycloak-config. Now I am stuck with this error. Looks like it is trying to pull the patient resource and it is failing due to launch/context or scope in the token. 17:00:36,556 WARN [org.alvearie.keycloak.PatientSelectionForm] (default task-10) Response with code 400 { "resourceType": "OperationOutcome", "id": "fa6eacad-d442-4e6d-957f-1b02e86eff52", "meta": { "versionId": "8ae56936-c021-45af-b742-cff609efeb10", "lastUpdated": "2022-02-25T17:00:36.5471276+00:00" }, "issue": [ { "severity": "error", "code": "invalid", "details": { "coding": [ { "system": "http://hl7.org/fhir/dotnet-api-operation-outcome", "code": "5001" } ], "text": "Cannot enforce 'patient/*' claims without a launch context." } } ] } |
|
Yes, the patient context picker will try to find which patients the user has access to and present them to the user via a picklist. For that request to the FHIR server, it's setting the patient/Patient.read scope on the following line: https://github.com/Alvearie/keycloak-extensions-for-fhir/blob/main/keycloak-extensions/src/main/java/org/alvearie/keycloak/PatientSelectionForm.java#L199 |
|
Thanks for your quick response Lee! Appreciate your help resolving this! I am using firely server. I am passing the scopes "launch/patient openid fhirUser offline_access patient/*.read" when I get new access token. Is that correct? What is the fhir api url being used to get the patient resources (for multiple)? So I can make a separate api call using postman and verify it. |
|
its doing a batch read of each resourceId configured for this user: |
|
I was getting this same error when I was trying with single resourceId in the user profile which I was able to fix it by turning it on "Add to access token " in "Patient ID Token Mapper" under "launch/context" scope. |
|
The patient selector is finally shows up when I disable smart authorization in firely server. Looks like there is some issue going on with the scope & launch context in my setup. |
|
Finally I figured out why it is failing on getting patient resources. When I enable SMART Authorization in firely server, it looks for "user/*" scope to get the patient resources. But you have set "patient/Patient.read" scope to get patient resources which supposed to be used only in patient context (launch/patient). Did you try/test patient picker using IBM FHIR Server without SMART Authorization enabled? |
|
On IBM FHIR Server, we apply the Even though the keycloak client is sort of a "trusted" client of the FHIR server, I thought it would be a nice double-check to set this patient context on the batch read of the Patient resources ...basically asking the FHIR Server ensure that we only get Patient resources for the patient picker that the end user actually has access to. However, I can see the logic in using I can give that a try on our server if you give it a try on yours...let me know how it goes. |
|
Thanks for detail reply. Looks like you have configured a claim "patient" (to pass the selected patient's id from the patient picker) which supposed to be used for patient compartment. It works fine in my setup with firely server. The other one "patient_id" claim is used to pass the resourceId which is configured at the user profile. Patient picker is using this claim to prepare the bundle request and get those patient resources. Is that correct? |
"patient" is the key that comes back on the token response and that is defined by the spec. but we don't use that as the name of the claim within the access token...for that we use "patient_id". we originally got that from a MITRE reference implementation I believe, but it should be considered implementation detail...the spec doesn't put any requirements on the content of the access token (it is "opaque" to the client). For the batch read that we perform from keycloak, we set this The documentation for that is at https://github.com/Alvearie/keycloak-extensions-for-fhir#the-patient-context-picker |
|
Sorry for the delay response. I was able to make it work only after setting the scope to "user/Patient.read". Please refer/read authorization section in the below url - "But with a scope of ‘patient/’ you are required to also have a ‘patient=…’ launch context to know to which patient the user connects". https://docs.fire.ly/projects/Firely-Server/en/latest/security/accesscontrol.html?highlight=scope You may also setup and try using trial version if you have time. https://docs.fire.ly/projects/Firely-Server/en/latest/getting_started.html |
|
Thanks @ssekar1976 To be clear, having a I'm thinking we should close this issue and open a new one that is more clear in scope: to look into changing it to use However, it sounds like that won't be enough for using with the Firely server because apparently you need to add a special |
I am getting this error "Unexpected error when handling authentication request to identity provider." when I try to configure resourceId with multiple ids (space delimited). I appreciate on any help to resolve it.
The text was updated successfully, but these errors were encountered: