search

quarkusio / quarkus

Quarkus: Supersonic Subatomic Java.
https://quarkus.io
Apache License 2.0
13.63k stars 2.64k forks source link

OIDC extension does not work with Azure AD after upgrading to Quarkus 1.7.0.FINAL #11418

Closed wjglerum closed 4 years ago

wjglerum commented 4 years ago

Describe the bug We have a webapp where we delegate the login to Azure AD with the Quarkus OIDC extension. When we upgrade to Quarkus 1.7.0.FINAL the login through our OIDC provider is broken. Locally everything works with Keycloak as the OIDC provider. However when using Azure AD as the OIDC provider we get in a loop during login.

Expected behavior Logging in with Azure AD as the OIDC provider works.

Actual behavior After logging in with Azure AD we end up with an infinite loop. Flow of requests:

  1. Request URL: http://localhost:8080/ Response headers:

    location: https://login.microsoftonline.com/<<<tenant_id>>>/oauth2/v2.0/authorize?redirect_uri=http%3A%2F%2Flocalhost%3A8080%2F&state=9a9c65c4-5005-4480-8648-bd727c27cc09&scope=openid&response_type=code&client_id=<<<client_id>>>
set-cookie: q_auth=9a9c65c4-5005-4480-8648-bd727c27cc09; Max-Age=1800; Expires=Mon, 17 Aug 2020 12:55:53 GMT; HTTPOnly

  2. Request URL: https://login.microsoftonline.com/<<<tenant_id>>>/oauth2/v2.0/authorize?redirect_uri=http%3A%2F%2Flocalhost%3A8080%2F&state=9a9c65c4-5005-4480-8648-bd727c27cc09&scope=openid&response_type=code&client_id=<<<client_id>>> Login flow with Azure AD

  3. Request URL: https://login.microsoftonline.com/kmsi Response headers:

    Location: http://localhost:8080/?code=<<<code>>>&state=9a9c65c4-5005-4480-8648-bd727c27cc09&session_state=c6f3b182-acc3-43f5-a997-193762b28332

  4. Request URL: http://localhost:8080/?code=<<<code>>>&state=9a9c65c4-5005-4480-8648-bd727c27cc09&session_state=c6f3b182-acc3-43f5-a997-193762b28332 Response headers:

    set-cookie: q_auth=cf068392-6be2-4159-a095-971df27b9a20|?code=<<<code>>>&state=9a9c65c4-5005-4480-8648-bd727c27cc09&session_state=c6f3b182-acc3-43f5-a997-193762b28332; Max-Age=1800; Expires=Mon, 17 Aug 2020 12:57:48 GMT; HTTPOnly

  5. The result is an infinite loop (which your browser kills eventually)

From the logs with DEBUG level set for the OIDC plugin:

[INFO] Scanning for projects...
[INFO] 
[INFO] -------------------< nl.wjglerum:quarkus-oidc-azure >-------------------
[INFO] Building quarkus-oidc-azure 1.0.0-SNAPSHOT
[INFO] --------------------------------[ jar ]---------------------------------
[INFO] 
[INFO] --- quarkus-maven-plugin:1.7.0.Final:prepare (default) @ quarkus-oidc-azure ---
[INFO] 
[INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ quarkus-oidc-azure ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] Copying 2 resources
[INFO] 
[INFO] --- maven-compiler-plugin:3.8.1:compile (default-compile) @ quarkus-oidc-azure ---
[INFO] Nothing to compile - all classes are up to date
[INFO] 
[INFO] --- quarkus-maven-plugin:1.7.0.Final:dev (default-cli) @ quarkus-oidc-azure ---
Listening for transport dt_socket at address: 5005
__  ____  __  _____   ___  __ ____  ______ 
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/ 
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \   
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/   
2020-08-17 14:25:47,563 INFO  [io.quarkus] (Quarkus Main Thread) quarkus-oidc-azure 1.0.0-SNAPSHOT on JVM (powered by Quarkus 1.7.0.Final) started in 3.219s. Listening on: http://0.0.0.0:8080
2020-08-17 14:25:47,570 INFO  [io.quarkus] (Quarkus Main Thread) Profile dev activated. Live Coding activated.
2020-08-17 14:25:47,571 INFO  [io.quarkus] (Quarkus Main Thread) Installed features: [cdi, oidc, resteasy, security]
2020-08-17 14:25:53,340 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-7) Authentication request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:25:53,342 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-7) q_auth cookie 'max-age' parameter is set to 1800
2020-08-17 14:27:47,465 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-7) Token request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:48,308 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) Authentication request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:48,308 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) q_auth cookie 'max-age' parameter is set to 1800
2020-08-17 14:27:48,591 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-7) Token request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:49,337 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) Authentication request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:49,338 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) q_auth cookie 'max-age' parameter is set to 1800
2020-08-17 14:27:49,593 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-7) Token request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:50,438 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) Authentication request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:50,439 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) q_auth cookie 'max-age' parameter is set to 1800
2020-08-17 14:27:50,741 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-7) Token request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:51,440 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) Authentication request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:51,441 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) q_auth cookie 'max-age' parameter is set to 1800
2020-08-17 14:27:51,694 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-7) Token request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:53,134 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) Authentication request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:53,134 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) q_auth cookie 'max-age' parameter is set to 1800
2020-08-17 14:27:53,493 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-7) Token request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:54,185 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) Authentication request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:54,185 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) q_auth cookie 'max-age' parameter is set to 1800
2020-08-17 14:27:54,418 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-7) Token request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:55,138 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) Authentication request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:55,138 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) q_auth cookie 'max-age' parameter is set to 1800
2020-08-17 14:27:55,394 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-7) Token request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:56,185 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) Authentication request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:56,186 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) q_auth cookie 'max-age' parameter is set to 1800
2020-08-17 14:27:56,392 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-7) Token request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:57,091 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) Authentication request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:57,091 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) q_auth cookie 'max-age' parameter is set to 1800
2020-08-17 14:27:57,688 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-7) Token request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:58,334 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) Authentication request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:27:58,334 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (executor-thread-1) q_auth cookie 'max-age' parameter is set to 1800
2020-08-17 14:27:58,924 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-7) State cookie value does not match the state query parameter value

The weird bit here is the only on the last request it warns us about the fact that the state cookie does not match.

Quarkus 1.6 Compare this with the output when using Quarkus 1.6.0.FINAL

  1. Request URL: http://localhost:8080/ Response headers:

    location: https://login.microsoftonline.com/<<<tenant_id>>/oauth2/v2.0/authorize?redirect_uri=http%3A%2F%2Flocalhost%3A8080%2F&state=e27702af-ba2a-49d5-9c4d-d6ce5e621bc5&scope=openid&response_type=code&client_id=<<<client_id>>>
set-cookie: q_auth=e27702af-ba2a-49d5-9c4d-d6ce5e621bc5; Max-Age=1800; Expires=Mon, 17 Aug 2020 13:22:23 GMT; HTTPOnly

  2. Request URL: https://login.microsoftonline.com/<<<tenant_id>>>/oauth2/v2.0/authorize?redirect_uri=http%3A%2F%2Flocalhost%3A8080%2F&state=e27702af-ba2a-49d5-9c4d-d6ce5e621bc5&scope=openid&response_type=code&client_id=<<<client_id>>> Login flow with Azure AD

  3. Request URL: https://login.microsoftonline.com/kmsi Response headers:

    Location: http://localhost:8080/?code=<<<code>>>&state=e27702af-ba2a-49d5-9c4d-d6ce5e621bc5&session_state=8192f17c-fc9c-4293-95f7-d0789239dc2e

  4. Request URL: http://localhost:8080/?code=<<<code>>>&state=e27702af-ba2a-49d5-9c4d-d6ce5e621bc5&session_state=8192f17c-fc9c-4293-95f7-d0789239dc2e Response headers:

    set-cookie: q_session=<<<token>>>|<<<token>>>|null; Max-Age=3900; Expires=Mon, 17 Aug 2020 13:59:02 GMT; HTTPOnly
set-cookie: q_auth=; Max-Age=0; Expires=Mon, 17 Aug 2020 12:54:02 GMT

  5. Request URL: http://localhost:8080/ And user is logged in successfully and cookies are set properly.

With the following logs:

[INFO] Scanning for projects...
[INFO] 
[INFO] -------------------< nl.wjglerum:quarkus-oidc-azure >-------------------
[INFO] Building quarkus-oidc-azure 1.0.0-SNAPSHOT
[INFO] --------------------------------[ jar ]---------------------------------
[INFO] 
[INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ quarkus-oidc-azure ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] Copying 2 resources
[INFO] 
[INFO] --- maven-compiler-plugin:3.8.1:compile (default-compile) @ quarkus-oidc-azure ---
[INFO] Nothing to compile - all classes are up to date
[INFO] 
[INFO] --- quarkus-maven-plugin:1.6.0.Final:dev (default-cli) @ quarkus-oidc-azure ---
Listening for transport dt_socket at address: 5005
__  ____  __  _____   ___  __ ____  ______ 
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/ 
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \   
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/   
2020-08-17 14:49:03,697 INFO  [io.quarkus] (Quarkus Main Thread) quarkus-oidc-azure 1.0.0-SNAPSHOT on JVM (powered by Quarkus 1.6.0.Final) started in 3.556s. Listening on: http://0.0.0.0:8080
2020-08-17 14:49:03,699 INFO  [io.quarkus] (Quarkus Main Thread) Profile dev activated. Live Coding activated.
2020-08-17 14:49:03,699 INFO  [io.quarkus] (Quarkus Main Thread) Installed features: [cdi, oidc, resteasy, security]
2020-08-17 14:49:10,958 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-3) Authentication request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:49:10,959 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-3) q_auth cookie 'max-age' parameter is set to 1800
2020-08-17 14:49:11,152 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-3) Token request redirect_uri parameter: http://localhost:8080/
2020-08-17 14:49:12,037 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-3) q_session cookie 'max-age' parameter is set to 3900
2020-08-17 14:49:12,038 DEBUG [io.qua.oid.run.CodeAuthenticationMechanism] (vert.x-eventloop-thread-3) Final redirect URI: http://localhost:8080/

Everything looks good here.

To Reproduce Steps to reproduce the behavior:

  1. Sample project with just quarkus-oidc enabled, see https://github.com/wjglerum/quarkus-oidc-azure
  2. Register your application in Azure AD https://docs.microsoft.com/en-us/azure/active-directory/develop/quickstart-register-app
  3. Use the endpoint, client id and client secret in the configuration
  4. Run the project with mvn quarkus:dev and try to login
  5. You will end up into a redirect loop

Configuration

# Add your application.properties here, if applicable.
quarkus.oidc.auth-server-url=<<<endpoint>>>
quarkus.oidc.credentials.secret=<<<client_secret>>>
quarkus.oidc.client-id=<<<client_id>>>
quarkus.oidc.application-type=web-app
quarkus.http.auth.permission.authenticated.paths=/*
quarkus.http.auth.permission.authenticated.policy=authenticated
quarkus.log.category."io.quarkus.oidc".level= DEBUG

Screenshots (If applicable, add screenshots to help explain your problem.)

Environment (please complete the following information):

Additional context Let me know if I can provide more information. Also, did anything major change in the OIDC extension this release?

gsmet commented 4 years ago

/cc @sberyozkin this one looks like a regression. Could you prioritize it? Thanks!

wjglerum commented 4 years ago

I see that something changed with the principal and user information, see https://github.com/quarkusio/quarkus/commit/856226615b3aefe8a6445987479758c3af81de2b#diff-c34b979eed4ac8884d4a875479eca3cf

I tried setting https://quarkus.io/guides/security-openid-connect-web-authentication#quarkus-oidc_quarkus.oidc.authentication.user-info-required and https://quarkus.io/guides/security-openid-connect-web-authentication#quarkus-oidc_quarkus.oidc.roles.source however this also didn't solve my problem.

wjglerum commented 4 years ago

I also did some debugging to see what requests Quarkus is making to Azure AD. It seems that it successfully exchanged a code for a set of ID and access tokens. It also fetches the OpenID config and certs correctly on startup.

I did this with Proxyman running on my Mac intercepting and decrypting SSL traffic. With the following Quarkus config:

quarkus.oidc.proxy.host=localhost
quarkus.oidc.proxy.port=9090
sberyozkin commented 4 years ago

@wjglerum The linked changes are not related at all to the problem so please do not enhance the existing configuration for now. I'm nearly 100% sure it is not a Quarkus OIDC issue. The reason I think it is not related is to do with your comment : The weird bit here is the only on the last request it warns us about the fact that the state cookie does not match. Something goes wrong in the transit. Can you please investigate more, perhaps simplify the setup first, etc.

wjglerum commented 4 years ago

Thanks for your reply @sberyozkin. I was going through the changes in the OIDC extension and this came across, so I gave it a try. It's not part of the original bug report and sample project.

I tried the simplest setup as possible with my sample project, with little to no config. I also tried debugging and checking what is going on. I ruled out the calls to Azure AD from Quarkus as these are similar in both versions (checked with Proxyman).

When double checking the request flows, I found the weird bit. When Quarkus successfully requested the tokens from Azure AD with the code and redirects the user back to the application it sets a weird cookie:

Request URL: http://localhost:8080/?code=<<<code>>>&state=9a9c65c4-5005-4480-8648-bd727c27cc09&session_state=c6f3b182-acc3-43f5-a997-193762b28332 Response headers:

set-cookie: q_auth=cf068392-6be2-4159-a095-971df27b9a20|?code=<<<code>>>&state=9a9c65c4-5005-4480-8648-bd727c27cc09&session_state=c6f3b182-acc3-43f5-a997-193762b28332; Max-Age=1800; Expires=Mon, 17 Aug 2020 12:57:48 GMT; HTTPOnly

This is not what I would expect.

In 1.6.0.FINAL it sets the following cookies instead:

set-cookie: q_session=<<<token>>>|<<<token>>>|null; Max-Age=3900; Expires=Mon, 17 Aug 2020 13:59:02 GMT; HTTPOnly
set-cookie: q_auth=; Max-Age=0; Expires=Mon, 17 Aug 2020 12:54:02 GMT

There is nothing in the logs, even with debugging logging. Any pointers were we could look into? For now I'm pretty stuck on this.

sberyozkin commented 4 years ago

Hi @wjglerum in 1.7.0.Final, when one issues an initial request, example, http://localhost:8080/service?a=b, this ?a=b will be restored once the authentication has been completed, and indeed, once all is done, you will get exactly what you've posted above.

The fact you see this strange q_auth value suggests that the Request URL like http://localhost:8080/?code=<<<code>>>&state=9a9c65c4-5005-4480-8648-bd727c27cc09&session_state=c6f3b182-acc3-43f5-a997-193762b28332 is seen by Quarkus OIDC not as part of the code flow, i.e the original state cookie which was set when you tried to access Quarkus was not detected after the user was redirected back to Quarkus so it treats this request as a completely new independent request.

Can you set a breakpoint here please: https://github.com/quarkusio/quarkus/blob/master/extensions/oidc/runtime/src/main/java/io/quarkus/oidc/runtime/CodeAuthenticationMechanism.java#L205

This is where the return leg of the code flow is processed.

And here: https://github.com/quarkusio/quarkus/blob/master/extensions/oidc/runtime/src/main/java/io/quarkus/oidc/runtime/CodeAuthenticationMechanism.java#L289 This is the code which runs after the code flow completes and where you should get q_auth reset. as per your last fragment below.

sberyozkin commented 4 years ago

@wjglerum Hi, did you have a chance to look into it ? Let me summarize again what I think is happening in your case, referring to the issue description here:

Can you try quarkus.oidc.authentication.cookie-path=/ ?

sberyozkin commented 4 years ago

@wjglerum I've started creating an Azure tenant and I have to admit I don't know what exactly I'm doing there, different types are possible, etc. Can you please create some test tenantid which I can use ?

wjglerum commented 4 years ago

Hi @sberyozkin, finally got some time to properly debug this. Had a quick look yesterday evening but couldn't find anything useful. Thanks to your suggestions for the breakpoints I now did manage to find an exception. Which does not happen when we use Keycloak as the OIDC provider.

The troubled bit seems to be here: https://github.com/quarkusio/quarkus/blob/master/extensions/oidc/runtime/src/main/java/io/quarkus/oidc/runtime/CodeAuthenticationMechanism.java#L325

It fails with the following message: io.vertx.core.impl.NoStackTraceThrowable: Invalid path

With the following stacktrace (from the IntelliJ IDEA debug console):

0 = {StackTraceElement@7483} "io.quarkus.oidc.runtime.OidcIdentityProvider$3$1.handle(OidcIdentityProvider.java:196)"
1 = {StackTraceElement@7484} "io.quarkus.oidc.runtime.OidcIdentityProvider$3$1.handle(OidcIdentityProvider.java:192)"
2 = {StackTraceElement@7485} "io.vertx.ext.auth.oauth2.impl.OAuth2AuthProviderImpl.lambda$decodeToken$6(OAuth2AuthProviderImpl.java:342)"
3 = {StackTraceElement@7486} "io.vertx.ext.auth.oauth2.impl.OAuth2AuthProviderImpl.lambda$authenticate$4(OAuth2AuthProviderImpl.java:290)"
4 = {StackTraceElement@7487} "io.vertx.ext.auth.oauth2.impl.OAuth2TokenImpl.lambda$introspect$3(OAuth2TokenImpl.java:354)"
5 = {StackTraceElement@7488} "io.vertx.ext.auth.oauth2.impl.OAuth2API.fetch(OAuth2API.java:49)"
6 = {StackTraceElement@7489} "io.vertx.ext.auth.oauth2.impl.OAuth2TokenImpl.introspect(OAuth2TokenImpl.java:345)"
7 = {StackTraceElement@7490} "io.vertx.ext.auth.oauth2.impl.OAuth2TokenImpl.introspect(OAuth2TokenImpl.java:503)"
8 = {StackTraceElement@7491} "io.vertx.ext.auth.oauth2.impl.OAuth2AuthProviderImpl.authenticate(OAuth2AuthProviderImpl.java:288)"
9 = {StackTraceElement@7492} "io.vertx.ext.auth.oauth2.impl.OAuth2AuthProviderImpl.decodeToken(OAuth2AuthProviderImpl.java:338)"
10 = {StackTraceElement@7493} "io.quarkus.oidc.runtime.OidcIdentityProvider$3.accept(OidcIdentityProvider.java:191)"
11 = {StackTraceElement@7494} "io.quarkus.oidc.runtime.OidcIdentityProvider$3.accept(OidcIdentityProvider.java:188)"
12 = {StackTraceElement@7495} "io.smallrye.mutiny.operators.UniCreateWithEmitter.subscribing(UniCreateWithEmitter.java:22)"
13 = {StackTraceElement@7496} "io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:43)"
14 = {StackTraceElement@7497} "io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:38)"
15 = {StackTraceElement@7498} "io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:30)"
16 = {StackTraceElement@7499} "io.smallrye.mutiny.operators.UniBlockingAwait.await(UniBlockingAwait.java:48)"
17 = {StackTraceElement@7500} "io.smallrye.mutiny.groups.UniAwait.atMost(UniAwait.java:61)"
18 = {StackTraceElement@7501} "io.smallrye.mutiny.groups.UniAwait.indefinitely(UniAwait.java:42)"
19 = {StackTraceElement@7502} "io.quarkus.oidc.runtime.OidcIdentityProvider.verifyCodeFlowAccessToken(OidcIdentityProvider.java:202)"
20 = {StackTraceElement@7503} "io.quarkus.oidc.runtime.OidcIdentityProvider.validateTokenWithOidcServer(OidcIdentityProvider.java:84)"
21 = {StackTraceElement@7504} "io.quarkus.oidc.runtime.OidcIdentityProvider.authenticate(OidcIdentityProvider.java:72)"
22 = {StackTraceElement@7505} "io.quarkus.oidc.runtime.OidcIdentityProvider.access$000(OidcIdentityProvider.java:33)"
23 = {StackTraceElement@7506} "io.quarkus.oidc.runtime.OidcIdentityProvider$1.get(OidcIdentityProvider.java:59)"
24 = {StackTraceElement@7507} "io.quarkus.oidc.runtime.OidcIdentityProvider$1.get(OidcIdentityProvider.java:47)"
25 = {StackTraceElement@7508} "io.smallrye.mutiny.operators.UniCreateFromDeferredSupplier.subscribing(UniCreateFromDeferredSupplier.java:24)"
26 = {StackTraceElement@7509} "io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:43)"
27 = {StackTraceElement@7510} "io.smallrye.mutiny.operators.UniSerializedSubscriber.subscribe(UniSerializedSubscriber.java:38)"
28 = {StackTraceElement@7511} "io.smallrye.mutiny.groups.UniSubscribe.withSubscriber(UniSubscribe.java:49)"
29 = {StackTraceElement@7512} "io.smallrye.mutiny.groups.UniSubscribe.with(UniSubscribe.java:69)"
30 = {StackTraceElement@7513} "io.quarkus.oidc.runtime.CodeAuthenticationMechanism$4.lambda$accept$0(CodeAuthenticationMechanism.java:299)"
31 = {StackTraceElement@7514} "io.vertx.ext.auth.oauth2.impl.OAuth2AuthProviderImpl.lambda$authenticate$5(OAuth2AuthProviderImpl.java:318)"
32 = {StackTraceElement@7515} "io.vertx.ext.auth.oauth2.impl.flow.AuthCodeImpl.lambda$getToken$0(AuthCodeImpl.java:93)"
33 = {StackTraceElement@7516} "io.vertx.ext.auth.oauth2.impl.flow.AbstractOAuth2Flow.lambda$getToken$0(AbstractOAuth2Flow.java:148)"
34 = {StackTraceElement@7517} "io.vertx.ext.auth.oauth2.impl.OAuth2API.lambda$null$1(OAuth2API.java:129)"
35 = {StackTraceElement@7518} "io.vertx.core.http.impl.HttpClientResponseImpl$BodyHandler.notifyHandler(HttpClientResponseImpl.java:292)"
36 = {StackTraceElement@7519} "io.vertx.core.http.impl.HttpClientResponseImpl.lambda$bodyHandler$0(HttpClientResponseImpl.java:193)"
37 = {StackTraceElement@7520} "io.vertx.core.http.impl.HttpClientResponseImpl.handleEnd(HttpClientResponseImpl.java:248)"
38 = {StackTraceElement@7521} "io.vertx.core.http.impl.Http1xClientConnection$StreamImpl.lambda$beginResponse$0(Http1xClientConnection.java:483)"
39 = {StackTraceElement@7522} "io.vertx.core.streams.impl.InboundBuffer.handleEvent(InboundBuffer.java:237)"
40 = {StackTraceElement@7523} "io.vertx.core.streams.impl.InboundBuffer.write(InboundBuffer.java:127)"
41 = {StackTraceElement@7524} "io.vertx.core.http.impl.Http1xClientConnection$StreamImpl.endResponse(Http1xClientConnection.java:502)"
42 = {StackTraceElement@7525} "io.vertx.core.http.impl.Http1xClientConnection$StreamImpl.access$000(Http1xClientConnection.java:241)"
43 = {StackTraceElement@7526} "io.vertx.core.http.impl.Http1xClientConnection.handleResponseEnd(Http1xClientConnection.java:641)"
44 = {StackTraceElement@7527} "io.vertx.core.http.impl.Http1xClientConnection.handleHttpMessage(Http1xClientConnection.java:601)"
45 = {StackTraceElement@7528} "io.vertx.core.http.impl.Http1xClientConnection.handleMessage(Http1xClientConnection.java:575)"
46 = {StackTraceElement@7529} "io.vertx.core.impl.ContextImpl.executeTask(ContextImpl.java:366)"
47 = {StackTraceElement@7530} "io.vertx.core.impl.EventLoopContext.execute(EventLoopContext.java:43)"
48 = {StackTraceElement@7531} "io.vertx.core.impl.ContextImpl.executeFromIO(ContextImpl.java:229)"
49 = {StackTraceElement@7532} "io.vertx.core.net.impl.VertxHandler.channelRead(VertxHandler.java:173)"
50 = {StackTraceElement@7533} "io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)"
51 = {StackTraceElement@7534} "io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)"
52 = {StackTraceElement@7535} "io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)"
53 = {StackTraceElement@7536} "io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436)"
54 = {StackTraceElement@7537} "io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324)"
55 = {StackTraceElement@7538} "io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296)"
56 = {StackTraceElement@7539} "io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251)"
57 = {StackTraceElement@7540} "io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)"
58 = {StackTraceElement@7541} "io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)"
59 = {StackTraceElement@7542} "io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)"
60 = {StackTraceElement@7543} "io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1518)"
61 = {StackTraceElement@7544} "io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1267)"
62 = {StackTraceElement@7545} "io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1314)"
63 = {StackTraceElement@7546} "io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:501)"
64 = {StackTraceElement@7547} "io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:440)"
65 = {StackTraceElement@7548} "io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)"
66 = {StackTraceElement@7549} "io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)"
67 = {StackTraceElement@7550} "io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)"
68 = {StackTraceElement@7551} "io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)"
69 = {StackTraceElement@7552} "io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436)"
70 = {StackTraceElement@7553} "io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:253)"
71 = {StackTraceElement@7554} "io.netty.handler.proxy.HttpProxyHandler$HttpClientCodecWrapper.channelRead(HttpProxyHandler.java:272)"
72 = {StackTraceElement@7555} "io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)"
73 = {StackTraceElement@7556} "io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)"
74 = {StackTraceElement@7557} "io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)"
75 = {StackTraceElement@7558} "io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)"
76 = {StackTraceElement@7559} "io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)"
77 = {StackTraceElement@7560} "io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)"
78 = {StackTraceElement@7561} "io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)"
79 = {StackTraceElement@7562} "io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)"
80 = {StackTraceElement@7563} "io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714)"
81 = {StackTraceElement@7564} "io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650)"
82 = {StackTraceElement@7565} "io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576)"
83 = {StackTraceElement@7566} "io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)"
84 = {StackTraceElement@7567} "io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)"
85 = {StackTraceElement@7568} "io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)"
86 = {StackTraceElement@7569} "io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)"
87 = {StackTraceElement@7570} "java.base/java.lang.Thread.run(Thread.java:834)"

It looks like it cannot read or parse a certain part of the response from Azure AD correctly. Which is weird as it does work in Quarkus 1.6.x.

I can share the client id + secret with you for the test App registration I created on Azure AD. How can I best sent you this (sensitive) information?

wjglerum commented 4 years ago

After some more debugging related to the "Invalid path" exception from above I found some more information. This error seems to come from the fetch method from the OAuth2API from Vert.x Auth, see https://github.com/vert-x3/vertx-auth/blob/3.9.2/vertx-auth-oauth2/src/main/java/io/vertx/ext/auth/oauth2/impl/OAuth2API.java#L47

Using Keycloak:

Using Azure AD

Any idea why is this second fetch is happening?

wjglerum commented 4 years ago

Alright I think I found it! This works for our project and my sample project in combination with Azure AD:

quarkus.oidc.authentication.verify-access-token=false -> does the trick quarkus.oidc.roles.source=idtoken -> to read the roles from the idtoken instead

The second fetch was for the access token I think. Somehow Quarkus/SmallRye JWT/Vert.x Auth doesn't pick up the right path or Azure AD doesn't expose the right configuration on their discovery endpoint for verifying access tokens.

Also see

So I think this change was indeed introduced in the commit I mentioned, https://github.com/quarkusio/quarkus/commit/856226615b3aefe8a6445987479758c3af81de2b#diff-c34b979eed4ac8884d4a875479eca3cf Not sure if we need a change on the Quarkus side though.

See https://docs.microsoft.com/en-us/azure/active-directory/develop/access-tokens#validating-tokens for more information on validating tokens. It should be possible to validate the access token locally right?

sberyozkin commented 4 years ago

Hi @wjglerum Thanks for spending the time on debugging this issue. Hmm... Something strange is going on. OK,

quarkus.oidc.authentication.verify-access-token=...

I did introduce this check (true by default) because until 1.7.0 the access token (which is in the session cookie) is not validated at all which is risky, even though for the code flow we use and verify id_token. But the users can still inject the access token, access its properties or propagate it, so it has to be verified in principle.

However it does look like it causes side-effects. Specifically, if the discovery document does not return an introspection endpoint address and the the access token is opaque (binary) or JWT but is signed by a key which is not available in the fetched JWK set - which is why you are seeing an extra fetch and the ultimate failure due to the missing introspection path.

So what I will do is I will set this property to false by default.

quarkus.oidc.roles.source=idtoken - you don't need to set it, it is a default in the code flow case

Thanks again, and sorry for this regression - even though IMHO it is a good improvement from the security point of view. I'll take care of it now.

sberyozkin commented 4 years ago

@wjglerum the same issue is here, https://github.com/quarkusio/quarkus/issues/11460#issuecomment-676106720

sberyozkin commented 4 years ago

The reason it is all working with KC is because its access token is also JWT and besides, it also reports the introspection path in the discovery doc, hence the Quarkus tests are passing

wjglerum commented 4 years ago

Thanks for your explanation and follow up @sberyozkin!

It would be nice if we could somehow validate the access token coming from OIDC providers like Azure AD. This should be possible right?

Because the access token returned by Azure AD is a JWT which has a kid claim in the header which links to the keys from the endpoint found in the OIDC configuration, see:

sberyozkin commented 4 years ago

@wjglerum Are you sure you are referring to the access token as opposed to ID token ? One does not have to verify the access token with Quarkus in the code flow since we work with ID token as the primary token. The fact you have the flow failing with this AT validation being on by default does indicate the AT is either opaque or has no JWK in the local JWK set which Quarkus fetched and the discovery doc also does not return an introspection endpoint address which is used as a fallback if no JWK is available locally. Can you share the content of q_session ? You can trim a bit the content of each token but please keep the first 10 or so chars, for me to see if both are JWT or not

sberyozkin commented 4 years ago

@wjglerum see also this comment, https://github.com/quarkusio/quarkus/issues/11460#issuecomment-676511319, if you can try to debug even more than it will clarify things. As I said, the 1st thing which has to be done is to fix this side-effect to avoid the users opening new issues. Next we can investigate, as part of a new issue, how to optionally verify not only ID but also ATs returned from Azure as part of the code flow

sberyozkin commented 4 years ago

@wjglerum similarly to Google, Azure does not have an introspection endpoint in this discovery doc. The access token returned with the code flow is not meant to access Quarkus itself, Quarkus App can use it to access Azure API or refresh ID tokens, same as with Google. I'm absolutely certain the AT is not verifiable locally. I've added this option to verify the access token with the code flow (in addition to ID token) because sometimes, especially with keycloak, users can inject AT as JsonWebToken.

wjglerum commented 4 years ago

@sberyozkin thanks for changing the default for verifying the access tokens!

Here are the decoded headers from both tokens:

Seeing the headers I do think that Quarkus OIDC should be able to verify the access token. As the access token uses the same kid as the id token. I also see that Quarkus OIDC does get the keys successfully from the OIDC provider on start up and it contains the mentioned kid.

I'll try to do some more debugging tomorrow on why it is not using the keys to verify the access token.

wjglerum commented 4 years ago

Alright, I had some more time to look at the validation of the access token. It seems it's not possible with Azure AD. Or at least not with the specified kid. I tried to manually verify the tokens with the certificate obtained from the Azure AD endpoint. This works on https://jwt.io/ for the id token. It does not work with the access token it will return "Invalid signature". I turned on some more debugging and this is also what happens in the code, it fails to verify the signature of the JWT of the access token. Next it tries to use the introspection path, but as you mentioned this is not present in the OIDC config for Azure AD.

Double checked the docs for access tokens from Azure AD and they also mention that we should treat them as opaque tokens:

Clients should treat access tokens as opaque strings, as the contents of the token are intended for the resource only. https://docs.microsoft.com/en-us/azure/active-directory/develop/access-tokens

I guess it makes sense to keep the default to not enforce validation of access tokens.