JSON Error when trying to authenticate with Yubikey

Question

JSON Error when trying to authenticate with Yubikey

Pande-monium opened this issue 2 years ago · 2 comments

Hello,

I'm having some troubles setting up Keycloak + Privacyidea + Yubikeys.
Both Keycloak and PI Servers are running and individually doing what they are supposed to do.
I have enrolled the Yubikeys in PI in AES mode with PI handling the private key of the yubikey.
When I try to login on the Keycloak server however I get an error:

2022-05-25 11:52:30,572 WARN  [org.keycloak.services] (executor-thread-0) KC-SERVICES0013: Failed authentication: java.lang.ClassCastException: class com.google.gson.JsonNull cannot be cast to class com.google.gson.JsonPrimitive (com.google.gson.JsonNull and com.google.gson.JsonPrimitive are in unnamed module of loader io.quarkus.bootstrap.runner.RunnerClassLoader @368239c8)
	at com.google.gson.JsonObject.getAsJsonPrimitive(JsonObject.java:172)
	at org.privacyidea.JSONParser.getString(JSONParser.java:508)
	at org.privacyidea.JSONParser.parsePIResponse(JSONParser.java:149)
	at org.privacyidea.PrivacyIDEA.validateCheck(PrivacyIDEA.java:129)
	at org.privacyidea.authenticator.PrivacyIDEAAuthenticator.action(PrivacyIDEAAuthenticator.java:402)
	at org.keycloak.authentication.DefaultAuthenticationFlow.processAction(DefaultAuthenticationFlow.java:169)
	at org.keycloak.authentication.AuthenticationProcessor.authenticationAction(AuthenticationProcessor.java:990)
	at org.keycloak.services.resources.LoginActionsService.processFlow(LoginActionsService.java:321)
	at org.keycloak.services.resources.LoginActionsService.processAuthentication(LoginActionsService.java:292)
	at org.keycloak.services.resources.LoginActionsService.authenticate(LoginActionsService.java:276)
	at org.keycloak.services.resources.LoginActionsService.authenticateForm(LoginActionsService.java:349)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:170)
	at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:130)
	at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:660)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:524)
	at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:474)
	at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:476)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:434)
	at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:192)
	at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:141)
	at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:32)
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:492)
	at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:261)
	at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:161)
	at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
	at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:164)
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:247)
	at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:73)
	at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:151)
	at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:82)
	at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:42)
	at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
	at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
	at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
	at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:67)
	at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:55)
	at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
	at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
	at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
	at io.quarkus.vertx.http.runtime.VertxHttpRecorder$5.handle(VertxHttpRecorder.java:380)
	at io.quarkus.vertx.http.runtime.VertxHttpRecorder$5.handle(VertxHttpRecorder.java:358)
	at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
	at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
	at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
	at org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter.lambda$createBlockingHandler$1(QuarkusRequestFilter.java:71)
	at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159)
	at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100)
	at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157)
	at io.quarkus.vertx.core.runtime.VertxCoreRecorder$13.runWith(VertxCoreRecorder.java:543)
	at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2449)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1478)
	at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
	at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:829)

2022-05-25 11:52:30,597 WARN  [org.keycloak.events] (executor-thread-0) type=LOGIN_ERROR, realmId=MY_REALM, clientId=account-console, userId=null, ipAddress=213.240.178.59, error=invalid_user_credentials, auth_method=openid-connect, auth_type=code, redirect_uri=https://OUR.DOMAIN.com/realms/MY_REALM/account/#/, code_id=8fbf381f-3136-4f0d-93d9-5cc60ce281c7, authSessionParentId=8fbf381f-3136-4f0d-93d9-5cc60ce281c7, authSessionTabId=fuRGK8eT7NQ

It Looks like something in the JSON is Null that's not supposed to be Null.
The PI server logs show, that the authentication went through successfully.

Also the response just before this log entry looks quite promising (Log also from Keycloak):

2022-05-25 11:52:25,017 INFO  [org.privacyidea.authenticator.PrivacyIDEAAuthenticator] (pool-8-thread-1) PrivacyIDEA SDK: Sending to /auth
2022-05-25 11:52:25,018 INFO  [org.privacyidea.authenticator.PrivacyIDEAAuthenticator] (pool-8-thread-1) PrivacyIDEA SDK: username=SERVICE_ACCOUNT_USER
2022-05-25 11:52:25,018 INFO  [org.privacyidea.authenticator.PrivacyIDEAAuthenticator] (pool-8-thread-1) PrivacyIDEA SDK: password=****************
2022-05-25 11:52:25,018 INFO  [org.privacyidea.authenticator.PrivacyIDEAAuthenticator] (pool-8-thread-1) PrivacyIDEA SDK: realm=SERVICE_ACCOUNT_REALM
2022-05-25 11:52:25,664 INFO  [org.privacyidea.authenticator.PrivacyIDEAAuthenticator] (pool-8-thread-1) PrivacyIDEA SDK: Sending to /token/
2022-05-25 11:52:25,664 INFO  [org.privacyidea.authenticator.PrivacyIDEAAuthenticator] (pool-8-thread-1) PrivacyIDEA SDK: user=MY_USERNAME
2022-05-25 11:52:26,023 INFO  [org.privacyidea.authenticator.PrivacyIDEAAuthenticator] (OkHttp https://pi.enobyte.com/...) PrivacyIDEA SDK: /token/:
{
  "id": 1,
  "jsonrpc": "2.0",
  "result": {
    "status": true,
    "value": {
      "count": 1,
      "current": 1,
      "tokens": [
        {
          "active": true,
          "count": 1294,
          "count_window": 10,
          "description": "15419071",
          "failcount": 0,
          "id": 6,
          "info": {
            "count_auth": "15",
            "count_auth_success": "9",
            "last_auth": "2022-05-25 11:51:14.799594+02:00",
            "tokenkind": "hardware",
            "yubikey.prefix": "vvccccunfhnv",
            "yubikey.tokenid": "3216472fa3cd"
          },
          "locked": false,
          "maxfail": 10,
          "otplen": 44,
          "realms": [
            "MY_REALM_ldap_realm"
          ],
          "resolver": "MY_REALM",
          "revoked": false,
          "rollout_state": "",
          "serial": "UBAM00024C24",
          "sync_window": 1000,
          "tokentype": "yubikey",
          "user_editable": true,
          "user_id": "a80cc5a0-507d-103a-9088-012f05376100",
          "user_realm": "MY_REALM_ldap_realm",
          "username": "MY_USERNAME"
        }
      ]
    }
  },
  "time": 1653472346.0000277,
  "version": "privacyIDEA None",
  "signature": "rsa_sha256_pss:OMITTED_A_512_CHAR_SIGNATURE"
}
2022-05-25 11:52:30,038 INFO  [org.privacyidea.authenticator.PrivacyIDEAAuthenticator] (pool-8-thread-2) PrivacyIDEA SDK: Sending to /validate/check
2022-05-25 11:52:30,039 INFO  [org.privacyidea.authenticator.PrivacyIDEAAuthenticator] (pool-8-thread-2) PrivacyIDEA SDK: user=MY_USERNAME
2022-05-25 11:52:30,039 INFO  [org.privacyidea.authenticator.PrivacyIDEAAuthenticator] (pool-8-thread-2) PrivacyIDEA SDK: pass=********************************************
2022-05-25 11:52:30,039 INFO  [org.privacyidea.authenticator.PrivacyIDEAAuthenticator] (pool-8-thread-2) PrivacyIDEA SDK: realm=MY_REALM_ldap_realm
2022-05-25 11:52:30,571 INFO  [org.privacyidea.authenticator.PrivacyIDEAAuthenticator] (OkHttp https://pi.enobyte.com/...) PrivacyIDEA SDK: /validate/check:
{
  "detail": {
    "message": "matching 1 tokens",
    "otplen": 44,
    "serial": "UBAM00024C24",
    "threadid": 140277831210880,
    "type": "yubikey"
  },
  "id": 2,
  "jsonrpc": "2.0",
  "result": {
    "authentication": "ACCEPT",
    "status": true,
    "value": true
  },
  "time": 1653472350.551489,
  "version": "privacyIDEA None",
  "signature": "rsa_sha256_pss:OMITTED_ANOTHER_512_CHAR_SIGNATURE"
}

In case it matters:
The two omitted signatures are not identical.

Any idea if I did something wrong to cause this?

Answer 1 · 2022-05-25T15:06:08.000Z

Hi, i don't think you did something wrong - the provider should not crash because of something this trivial.
The problem is the version number. If you look at the response it says "version": "privacyIDEA None". There should also be a field "versionNumber" which seems to be missing if the version number can not be found in the server. I remember we had the same problem some time ago, but i referred to the server because i do not know much of it. I think it had to do with the python virtual env. However, for this provider, the problem will be fixed in the next version which should be released soon.
If you need it fixed quick, you can just comment the line https://github.com/privacyidea/java-client/blob/8153196d38cb8b810627e6ff6c08f0d38f304ad2/src/main/java/org/privacyidea/JSONParser.java#L155 (its 155 in the version in the main branch) and compile it according to the readme of this repo.

Answer 2 · 2022-05-25T15:16:38.000Z

Hello nilsbehlen,

thank you for your quick response.
I'll see if I can get a maven build environment setup to compile it myself, but in any case I'm looking forward to the next version release :)

Best regards,
Pande