Two whole days of my life, down the drain! Thankfully, it was just my pet project, but I ended up sacrificing an entire weekend wrestling with this enigma. So, I'm writing this blog post to save you from the same fate.
Problem:
I am using Quarkus and keycloak to protect my routes. With keycloak's start-dev
everything was working perfectly fine, but as soon as I tried to deploy everything with docker in production, I got following error as soon as I issued an access token and tried to access my protected route with it.
keycloak | 2023-10-30 18:54:42,832 WARN [org.keycloak.events] (executor-thread-13)
type=PERMISSION_TOKEN_ERROR, realmId=36382947-8ffa-4a8a-9881-2b7eeb84f800,
clientId=backend-service, userId=null, ipAddress=192.168.16.4,
error=invalid_token, reason='HTTP 500 Internal Server Error',
auth_method=oauth_credentials, audience=backend-service,
grant_type=urn:ietf:params:oauth:grant-type:uma-ticket,
permission=df1b74a9-3f10-499d-a581-368de48e512b,
client_auth_method=client-secret
"Fantastic! HTTP 500 Internal Server Errors, the crème de la crème of exceptions. They are even more delightful when they emanate from a charming 3rd-party package like our dear friend, Keycloak".
"Should you encounter a problem, consult the log files, my friend."
This way you'll become the Sherlock Holmes of software mysteries!
So I started my keycloak instance with --log-level=DEBUG
, here the full code
keycloak:
image: quay.io/keycloak/keycloak:22.0.5
container_name: keycloak
ports:
- "8443:8443"
environment:
KC_DB: postgres
KC_DB_URL: jdbc:postgresql://postgres:5432/keycloak
KC_DB_USERNAME: keycloak_user
KC_DB_PASSWORD: secret
KEYCLOAK_ADMIN: admin
KEYCLOAK_ADMIN_PASSWORD: admin
volumes:
- ./cert/keycloak-cert.pem:/etc/keycloak-cert.pem
- ./cert/keycloak-private-key.pem:/etc/keycloak-key.pem
command: ['start',
'--hostname-strict=false',
'--https-certificate-file=/etc/keycloak-cert.pem',
'--https-certificate-key-file=/etc/keycloak-key.pem',
'--log-level=DEBUG']
depends_on:
- "postgres"
Sherlock Holmes stumbled upon his first clue because the log files gave him following hint of an Invalid token issuer
.
keycloak | 2023-10-30 19:16:23,186 DEBUG [org.keycloak.services.managers.AuthenticationManager] (executor-thread-2)
Failed to verify identity token: Invalid token issuer. Expected
'https://keycloak:8443/realms/myrealm', but was
'https://localhost:8443/realms/myrealm'
Aha! After that two more exceptions decided to crash the party and I'm not one to keep secrets:
Troublemaker number one
keycloak | 2023-10-30 19:16:23,186 DEBUG [org.keycloak.authorization.authorization.AuthorizationTokenService] (executor-thread-2) PERMISSION_TOKEN_ERROR: org.keycloak.services.ErrorResponseException: HTTP 500 Internal Server Error
keycloak | at org.keycloak.authorization.common.KeycloakIdentity.<init>(KeycloakIdentity.java:73)
keycloak | at org.keycloak.authorization.common.KeycloakIdentity.<init>(KeycloakIdentity.java:68)
keycloak | at org.keycloak.authorization.authorization.AuthorizationTokenService.lambda$static$0(AuthorizationTokenService.java:139)
keycloak | at org.keycloak.authorization.authorization.AuthorizationTokenService.createEvaluationContext(AuthorizationTokenService.java:474)
keycloak | at org.keycloak.authorization.authorization.AuthorizationTokenService.authorize(AuthorizationTokenService.java:213)
keycloak | at org.keycloak.protocol.oidc.endpoints.TokenEndpoint.permissionGrant(TokenEndpoint.java:986)
keycloak | at org.keycloak.protocol.oidc.endpoints.TokenEndpoint.processGrantRequestInternal(TokenEndpoint.java:233)
keycloak | at org.keycloak.protocol.oidc.endpoints.TokenEndpoint.processGrantRequest(TokenEndpoint.java:190)
keycloak | at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
keycloak | at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
keycloak | at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
keycloak | at java.base/java.lang.reflect.Method.invoke(Method.java:568)
keycloak | at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:154)
keycloak | at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:118)
keycloak | at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:560)
keycloak | at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:452)
keycloak | at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:413)
keycloak | at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:321)
keycloak | at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:415)
keycloak | at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:378)
keycloak | at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:174)
keycloak | at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:142)
keycloak | at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:168)
keycloak | at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:131)
keycloak | at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:33)
keycloak | at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:429)
keycloak | at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:240)
keycloak | at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:154)
keycloak | at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:321)
keycloak | at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:157)
keycloak | at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:229)
keycloak | at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:82)
keycloak | at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:147)
keycloak | at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:84)
keycloak | at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:44)
keycloak | at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
keycloak | at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
keycloak | at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
keycloak | at io.quarkus.vertx.http.runtime.options.HttpServerCommonHandlers$1.handle(HttpServerCommonHandlers.java:58)
keycloak | at io.quarkus.vertx.http.runtime.options.HttpServerCommonHandlers$1.handle(HttpServerCommonHandlers.java:36)
keycloak | at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
keycloak | at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
keycloak | at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
keycloak | at org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter.lambda$createBlockingHandler$0(QuarkusRequestFilter.java:82)
keycloak | at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:576)
keycloak | at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
keycloak | at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)
keycloak | at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
keycloak | at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
keycloak | at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
keycloak | at java.base/java.lang.Thread.run(Thread.java:840)
and Troublemaker number two
keycloak | 2023-10-30 19:16:23,187 DEBUG [org.keycloak.authorization.authorization.AuthorizationTokenService] (executor-thread-2) Error while evaluating permissions: org.keycloak.services.CorsErrorResponseException: HTTP 500 Internal Server Error
keycloak | at org.keycloak.authorization.authorization.AuthorizationTokenService.lambda$static$0(AuthorizationTokenService.java:142)
keycloak | at org.keycloak.authorization.authorization.AuthorizationTokenService.createEvaluationContext(AuthorizationTokenService.java:474)
keycloak | at org.keycloak.authorization.authorization.AuthorizationTokenService.authorize(AuthorizationTokenService.java:213)
keycloak | at org.keycloak.protocol.oidc.endpoints.TokenEndpoint.permissionGrant(TokenEndpoint.java:986)
keycloak | at org.keycloak.protocol.oidc.endpoints.TokenEndpoint.processGrantRequestInternal(TokenEndpoint.java:233)
keycloak | at org.keycloak.protocol.oidc.endpoints.TokenEndpoint.processGrantRequest(TokenEndpoint.java:190)
keycloak | at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
keycloak | at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
keycloak | at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
keycloak | at java.base/java.lang.reflect.Method.invoke(Method.java:568)
keycloak | at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:154)
keycloak | at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:118)
keycloak | at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:560)
keycloak | at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:452)
keycloak | at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:413)
keycloak | at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:321)
keycloak | at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:415)
keycloak | at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:378)
keycloak | at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:174)
keycloak | at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:142)
keycloak | at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:168)
keycloak | at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:131)
keycloak | at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:33)
keycloak | at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:429)
keycloak | at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:240)
keycloak | at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:154)
keycloak | at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:321)
keycloak | at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:157)
keycloak | at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:229)
keycloak | at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:82)
keycloak | at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:147)
keycloak | at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:84)
keycloak | at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:44)
keycloak | at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
keycloak | at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
keycloak | at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
keycloak | at io.quarkus.vertx.http.runtime.options.HttpServerCommonHandlers$1.handle(HttpServerCommonHandlers.java:58)
keycloak | at io.quarkus.vertx.http.runtime.options.HttpServerCommonHandlers$1.handle(HttpServerCommonHandlers.java:36)
keycloak | at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
keycloak | at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
keycloak | at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
keycloak | at org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter.lambda$createBlockingHandler$0(QuarkusRequestFilter.java:82)
keycloak | at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:576)
keycloak | at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
keycloak | at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)
keycloak | at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
keycloak | at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
keycloak | at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
keycloak | at java.base/java.lang.Thread.run(Thread.java:840)
Oh, what do we have here? A surprise guest: the CorsErrorResponseException! CORS errors, the all-time favorites (not).
But this time they give a us an interesting hint which relates to the first exception message. We can clearly see that the Token issuer is localhost
instead of keycloak
.
Failed to verify identity token: Invalid token issuer. Expected
'https://keycloak:8443/realms/myrealm', but was 'https://localhost:8443/realms/myrealm'
Solution
First, I will tell you how to fix this problem and if your curiosity remains aroused, I will tell you the reason behind this problem.
Simply go to your Keycloak Admin console -> Select your Realm -> Realm settings -> General -> Frontend url and enter
https://<your-container-name>:<port>
for example my keycloak was running in Docker in a named container called keycloak
Because I was using docker-compose
, my backend will reference the keycloak instance by container name. The port was :8443
, so I had to set the Frontend url to:
https://keycloak:8443
This will override the base URL for frontend requests
This will override the base URL for frontend requests
This will override the base URL for frontend requests
There is a Chinese proverb which goes 重要的事情说三遍 and means "Say important things three times" because this solved the problem, which I am going to explain now.
Reason
The problem behind all that was that I was issuing my access token via Postman using localhost
and therefore my token issuer
was localhost
and not keycloak
.
https://localhost:8443/realms/myrealm/protocol/openid-connect/token
My backend had the environment variable KEYCLOAK_URL because it needs to reference the keycloak
instance by container name to function properly.
KEYCLOAK_URL=https://keycloak:8443/realms/myrealm
With keycloak's Frontend url, you can override the base URL of your frontend requests and this will solve the problem.
"Skip the chatter, hand over the code!"
version: "3.8"
services:
postgres:
image: postgres:15-alpine
container_name: postgres-15
restart: always
environment:
POSTGRES_USER: admin
POSTGRES_PASSWORD: secret
POSTGRES_DB: jdbc:postgresql://localhost:5432/appdb
volumes:
- pg-data-volume:/var/lib/postgresql/data
- ./scripts/schema.sql:/docker-entrypoint-initdb.d/1.sql
- ./scripts/load-data.sql:/docker-entrypoint-initdb.d/2.sql
ports:
- "5432:5432"
keycloak:
image: quay.io/keycloak/keycloak:22.0.5
container_name: keycloak
ports:
- "8443:8443"
environment:
KC_DB: postgres
KC_DB_URL: jdbc:postgresql://postgres:5432/keycloakdb
KC_DB_USERNAME: keycloak_user
KC_DB_PASSWORD: secret
KEYCLOAK_ADMIN: admin
KEYCLOAK_ADMIN_PASSWORD: admin
volumes:
- ./cert/keycloak-cert.pem:/etc/keycloak-cert.pem
- ./cert/keycloak-private-key.pem:/etc/keycloak-key.pem
command: ['start',
'--hostname-strict=false',
'--https-certificate-file=/etc/keycloak-cert.pem',
'--https-certificate-key-file=/etc/keycloak-key.pem',
'--log-level=DEBUG']
depends_on:
- "postgres"
app:
image: <my-custom-image>
container_name: app
restart: always
ports:
- "8080:8080"
environment:
DB_USERNAME: admin
DB_PASSWORD: secret
DB_URI: jdbc:postgresql://postgres:5432/db
KEYCLOAK_URL: https://keycloak:8443/realms/myrealm
KEYCLOAK_CLIENT_ID: backend-service
KEYCLOAK_CLIENT_SECRET: secret
depends_on:
- "keycloak"
volumes:
pg-data-volume: