Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
wjglerum opened this issue Aug 17, 2020 · 20 comments · Fixed by #11466
Closed

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

wjglerum opened this issue Aug 17, 2020 · 20 comments · Fixed by #11466
Assignees
Labels
Milestone

Comments

@wjglerum
Copy link
Contributor

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
  1. 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

  2. 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
  1. 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
  1. 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
  1. 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

  2. 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
  1. 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
  1. 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):

  • Output of uname -a or ver:
Darwin Willems-MacBook-Pro.local 19.6.0 Darwin Kernel Version 19.6.0: Sun Jul  5 00:43:10 PDT 2020; root:xnu-6153.141.1~9/RELEASE_X86_64 x86_64
  • Output of java -version:
openjdk version "11.0.5" 2019-10-15
OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.5+10)
OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.5+10, mixed mode)
  • GraalVM version (if different from Java): N/A
  • Quarkus version or git rev: 1.7.0.FINAL
  • Build tool (ie. output of mvnw --version or gradlew --version):
Apache Maven 3.6.3 (cecedd343002696d0abb50b32b541b8a6ba2883f)
Maven home: /Users/wjglerum/.m2/wrapper/dists/apache-maven-3.6.3-bin/1iopthnavndlasol9gbrbg6bf2/apache-maven-3.6.3
Java version: 11.0.5, vendor: AdoptOpenJDK, runtime: /Library/Java/JavaVirtualMachines/adoptopenjdk-11.jdk/Contents/Home
Default locale: en_NL, platform encoding: US-ASCII
OS name: "mac os x", version: "10.15.6", arch: "x86_64", family: "mac"

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

@wjglerum wjglerum added the kind/bug Something isn't working label Aug 17, 2020
@gsmet gsmet added this to the 1.7.1.Final milestone Aug 17, 2020
@gsmet
Copy link
Member

gsmet commented Aug 17, 2020

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

@wjglerum
Copy link
Contributor Author

@wjglerum
Copy link
Contributor Author

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
Copy link
Member

@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
Copy link
Contributor Author

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
Copy link
Member

sberyozkin commented Aug 17, 2020

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
Copy link
Member

@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:

  • the 'state' cookie returned as part of step 1. is not returned to Quarkus as part of step 4.

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

@sberyozkin
Copy link
Member

sberyozkin commented Aug 18, 2020

@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
Copy link
Contributor Author

wjglerum commented Aug 18, 2020

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
Copy link
Contributor Author

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
Copy link
Contributor Author

wjglerum commented Aug 18, 2020

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, 8562266#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
Copy link
Member

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
Copy link
Member

@wjglerum the same issue is here, #11460 (comment)

@sberyozkin
Copy link
Member

sberyozkin commented Aug 19, 2020

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
Copy link
Contributor Author

wjglerum commented Aug 19, 2020

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
Copy link
Member

sberyozkin commented Aug 19, 2020

@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
Copy link
Member

@wjglerum see also this comment, #11460 (comment), 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
Copy link
Member

sberyozkin commented Aug 20, 2020

@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
Copy link
Contributor Author

wjglerum commented Aug 20, 2020

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

Here are the decoded headers from both tokens:

  • id token header:
{
  "typ": "JWT",
  "alg": "RS256",
  "kid": "<kid>"
}
  • access token header:
{
  "typ": "JWT",
  "nonce": "<nonce>",
  "alg": "RS256",
  "x5t": "<kid>",
  "kid": "<kid>"
}

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
Copy link
Contributor Author

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.

buhaiovos added a commit to buhaiovos/dailyman-ui that referenced this issue Aug 29, 2020
* it turned out that 1.7.0.Final had a bug in it which resulted in an endless loop of authenitcation when using google as OpenId provider. Issue is described here: quarkusio/quarkus#11418. Issue was fixed in 1.7.1, hence quarkus upgrade was required
* application has to provide two more properties through the environment: `quarkus.oidc.client-id` and `quarkus.oidc.credentials.secret`
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
3 participants