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: