REDIS: WRONGPASS invalid username-password pair or user is disabled from io.smallrye.health after update to 3.5.3

[denysandriyanov]

Describe the bug

Reproduced in the native image After updating from 3.4.3 to 3.5.3 Quarkus, when a ready call is made application returns Redis connection health check DOWN with "WRONGPASS invalid username-password pair or user is disabled" while user and password are valid and correct. No code or properties were changed during upgrade. Before upgrade app was working (incl. healthchecks)

Redis host and password are set using:

quarkus:
  redis:
    hosts: redis://valid-redis-host:6379
    password: validRedisPassword

As a side note, ready endpoint is under 9000 management port.

quarkus:
   management:
    enabled: true
    port: 9000

I was not able to reproduce this problem locally in JVM, only reproduced in native image

Expected behavior

After the update from 3.4.3 to 3.5.3 redis still works and is able to authenticate and when call is done to ready endpoint no errors returned

Actual behavior

{"timestamp":"2023-11-24T18:43:57.45274Z","sequence":503,"loggerClassName":"io.smallrye.health.HealthLogging_$logger","loggerName":"io.smallrye.health","level":"INFO","message":"SRHCK01001: Reporting health down status: {\"status\":\"DOWN\",\"checks\":[{\"name\":\"Redis connection health check\",\"status\":\"DOWN\",\"data\":{\"reason\":\"client []: WRONGPASS invalid username-password pair or user is disabled.\"}}]}","threadName":"executor-thread-2","threadId":52,"mdc":{"spanId":"80fd54598da74645","traceId":"6b20b08cbd56bd529dd25269bee91911","sampled":"true"},"ndc":"","hostName":"2f5d115b1944","processId":407}

How to Reproduce?

1) Use Quarkus 3.5.3 2) Use implementation 'io.quarkus:quarkus-redis-client' and 'io.quarkus:quarkus-smallrye-health' 3) Set valid redis host and password line in example 4) Run application 5) Do a call to "ready" endpoint

quarkus:
  redis:
    hosts: redis://valid-redis-host:6379
    password: validRedisPassword

Output of uname -a or ver

No response

Output of java -version

21.0.1

Quarkus version or git rev

3.5.3

Build tool (ie. output of mvnw --version or gradlew --version)

gradle

Additional information

native image

[quarkus-bot[bot]]

/cc @Ladicek (smallrye), @cescoffier (redis), @gsmet (redis), @jmartisk (health,smallrye), @machi1990 (redis), @phillip-kruger (smallrye), @radcortez (smallrye), @xstefank (health)

[denysandriyanov]

Probably also #native tag?

[cescoffier]

Does it work in JVM mode?

[denysandriyanov]

Yes. As i mentioned in description I was not able to reproduce this problem locally in JVM, only reproduced in native image

[cescoffier]

Interesting... @Ladicek any idea?

[Ladicek]

Doesn't ring a bell. I will try to reproduce, but I'm not holding my breath. @denysandriyanov which version of GraalVM are you using? And is that by any chance GraalVM CE, or Oracle GraalVM?

[denysandriyanov]

@Ladicek Hi. it is https://github.com/graalvm/graalvm-ce-builds/releases/download/jdk-21.0.1/graalvm-community-jdk-21.0.1_linux-x64_bin.tar.gz"

[denysandriyanov]

Also reproduced in Quarkus 3.6.0

[Ladicek]

I created an empty project using Quarkus 3.6.0, including quarkus-redis-client, quarkus-smallrye-health and quarkus-config-yaml and the following application.yml:

quarkus:
  management:
    enabled: true
    port: 9000
  redis:
    hosts: redis://localhost:6379
    password: asdfgh123

I compiled it to native using

Running Quarkus native-image plugin on GRAALVM 23.1 JDK 21.0.1+12-jvmci-23.1-b19

And as I expected, I cannot reproduce:

$ http localhost:9000/q/health
HTTP/1.1 200 OK
content-length: 145
content-type: application/json; charset=UTF-8

{
    "checks": [
        {
            "name": "Redis connection health check",
            "status": "UP"
        }
    ],
    "status": "UP"
}

(FWIW, I'm running Redis using docker run -it --rm -p 6379:6379 -p 8001:8001 -e REDIS_ARGS="--requirepass asdfgh123" redis/redis-stack:latest).

I'm afraid we'll need more details to diagnose the issue.

[denysandriyanov]

Could you please suggest at which dirrection to look. I mean we changed nothing in the code, env config or properties just upgraded quarkus version from 3.4.3 to 3.5.3, later tried with 3.6.0, JAVA 17 to JAVA 21 For builds we are using buildpack that is supporting 21 java https://github.com/paketo-buildpacks/graalvm/releases/tag/v8.3.4

Nothing in code was changed, so I have no idea at least at which dirrection to dig.

below is application yaml, may be you notice something that might cause problem after upading to latest quarkus

quarkus:
  csrf-reactive:
    cookie-force-secure: true
  management:
    enabled: true
    port: 9000
  http:
    root-path: /oauth2
  redis:
    hosts: ${AUTH_CONSENT_REDIS_HOST}
    password: ${AUTH_CONSENT_REDIS_PASSWORD:null}
  cache:
    redis:
      loginRequest:
        expire-after-write: 60s
      logoutRequest:
        expire-after-write: 60s
  swagger-ui:
    urls:
      default: /oauth2/login-consent/v3/api-docs
      local: /v3/api-docs
    validator-url: none
    management:
      enabled: false
    always-include: true
    path: /swagger-ui
  smallrye-openapi:
    management:
      enabled: false
    auto-add-security: false
    path: /v3/api-docs
    always-include: true
  micrometer:
    binder:
      http-client:
        enabled: true
    export:
      prometheus:
        path: /metrics
  smallrye-health:
    liveness-path: /healthz
    readiness-path: /ready

[denysandriyanov]

@Ladicek @cescoffier I was diginng around and found interesting thing. Please take a look on below

1. Here is part from application.yaml, notice that AUTH_CONSENT_REDIS_HOST is variable for the redis host and if it is not set it should default to redis://127.0.0.1:6379

2. Here is the value of that variable that environment is passing to the application. Notice that it is "redis://redis-consent:6379" - it's a valid/available redis that is running in the cluster.

3. Here is log {"timestamp":"2023-12-01T06:00:40.840536Z","sequence":580,"loggerClassName":"io.smallrye.health.HealthLogging_$logger","loggerName":"io.smallrye.health","level":"INFO","message":"SRHCK01001: Reporting health down status: {\"status\":\"DOWN\",\"checks\":[{\"name\":\"Redis connection health check\",\"status\":\"DOWN\",\"data\":{\"reason\":\"client []: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: /127.0.0.1:6379\"}}]}","threadName":"executor-thread-1","threadId":41,"mdc":{"spanId":"8d7bad9e7048cac3","traceId":"cde97f82ab22f835f36943c304dda22e","sampled":"true"},"ndc":"","hostName":"ce03750a7a69","processId":427}

But the ip that is mentioned in the log is not the host that was set in environment variables. Like the env variable is ignored by application or something? You might say - something is wrong with environment, but the previous build on 3.4.3 quarkus is working in the same env.

Were there any changes in how quarkus is handling env variables/application.yaml properties?

Again, nothing was changed in the environment or configuration, only quarkus was updated which caused previously working system to behave like described

[Ladicek]

Good observation! I'm looking into the implementation of the Redis health check and it obtains the Redis clients from CDI as usual, so that should be fine...

@radcortez would you know if there were some config (EDIT: as in SmallRye Config) changes that could lead to the behavior described in the previous comment? It seems the default value has higher priority than environment variable, which would certainly be unexpected, but I'm sure we have plenty of tests for that, so there must be something else going on.

[denysandriyanov]

The woraroud I currently used is to keep the "defaults" in the microprofile-config.properties, but still would be nice to get it nailed and fixed

[radcortez]

@radcortez would you know if there were some config (EDIT: as in SmallRye Config) changes that could lead to the behavior described in the previous comment? It seems the default value has higher priority than environment variable, which would certainly be unexpected, but I'm sure we have plenty of tests for that, so there must be something else going on.

I'll have a look.

[radcortez]

I've tried to reproduce this with the code from https://github.com/radcortez/quarkus-config-playground/tree/quarkus-37306, but no luck:

🌀 ./target/config-playground-1.0.0-SNAPSHOT-runner
__  ____  __  _____   ___  __ ____  ______
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/
2023-12-01 19:49:42,142 INFO  [io.quarkus] (main) config-playground 1.0.0-SNAPSHOT native (powered by Quarkus 3.6.0) started in 0.025s. Listening on: http://0.0.0.0:8080. Management interface listening on http://0.0.0.0:9000.
2023-12-01 19:49:42,142 INFO  [io.quarkus] (main) Profile prod activated.
2023-12-01 19:49:42,142 INFO  [io.quarkus] (main) Installed features: [cdi, config-yaml, redis-client, resteasy-reactive, smallrye-context-propagation, smallrye-health, vertx]
2023-12-01 19:49:44,133 INFO  [io.sma.health] (executor-thread-1) SRHCK01001: Reporting health down status: {"status":"DOWN","checks":[{"name":"Redis connection health check","status":"DOWN","data":{"reason":"client [<default>]: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: /127.0.0.1:63799"}}]}
^C2023-12-01 19:49:46,800 INFO  [io.quarkus] (Shutdown thread) config-playground stopped in 0.001s

🌀 curl http://localhost:9000/q/health
{
    "status": "DOWN",
    "checks": [
        {
            "name": "Redis connection health check",
            "status": "DOWN",
            "data": {
                "reason": "client [<default>]: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: /127.0.0.1:63799"
            }
        }
    ]
}

🌀 export AUTH_CONSENT_REDIS_HOST=redis://127.0.0.1:6379

🌀 ./target/config-playground-1.0.0-SNAPSHOT-runner
__  ____  __  _____   ___  __ ____  ______
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/
2023-12-01 19:49:50,790 INFO  [io.quarkus] (main) config-playground 1.0.0-SNAPSHOT native (powered by Quarkus 3.6.0) started in 0.024s. Listening on: http://0.0.0.0:8080. Management interface listening on http://0.0.0.0:9000.
2023-12-01 19:49:50,790 INFO  [io.quarkus] (main) Profile prod activated.
2023-12-01 19:49:50,790 INFO  [io.quarkus] (main) Installed features: [cdi, config-yaml, redis-client, resteasy-reactive, smallrye-context-propagation, smallrye-health, vertx]
2023-12-01 19:49:52,745 INFO  [io.sma.health] (executor-thread-1) SRHCK01001: Reporting health down status: {"status":"DOWN","checks":[{"name":"Redis connection health check","status":"DOWN","data":{"reason":"client [<default>]: WRONGPASS invalid username-password pair or user is disabled."}}]}
^C2023-12-01 19:49:55,015 INFO  [io.quarkus] (Shutdown thread) config-playground stopped in 0.001s
19:49:55 (679) radcortez@radcortez: ~/Code/personal/quarkus-config-playground (main u-1)

🌀 curl http://localhost:9000/q/health
{
    "status": "DOWN",
    "checks": [
        {
            "name": "Redis connection health check",
            "status": "DOWN",
            "data": {
                "reason": "client [<default>]: WRONGPASS invalid username-password pair or user is disabled."
            }
        }
    ]
}

🌀 export AUTH_CONSENT_REDIS_PASSWORD=asdfgh123

🌀 ./target/config-playground-1.0.0-SNAPSHOT-runner
__  ____  __  _____   ___  __ ____  ______
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/
2023-12-01 19:50:00,644 INFO  [io.quarkus] (main) config-playground 1.0.0-SNAPSHOT native (powered by Quarkus 3.6.0) started in 0.028s. Listening on: http://0.0.0.0:8080. Management interface listening on http://0.0.0.0:9000.
2023-12-01 19:50:00,644 INFO  [io.quarkus] (main) Profile prod activated.
2023-12-01 19:50:00,644 INFO  [io.quarkus] (main) Installed features: [cdi, config-yaml, redis-client, resteasy-reactive, smallrye-context-propagation, smallrye-health, vertx]
^C2023-12-01 19:50:10,017 INFO  [io.quarkus] (Shutdown thread) config-playground stopped in 0.001s

🌀 curl http://localhost:9000/q/health
{
    "status": "UP",
    "checks": [
        {
            "name": "Redis connection health check",
            "status": "UP",
            "data": {
                "default": "PONG"
            }
        }
    ]
}

Notice the error coming from the health check is different, depending if the env vars are set or not (either missing hosts, or password, and finally succeeding). Can you check if I've missed something?

[Ladicek]

There's one other interesting thing:

client []: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: /127.0.0.1:6379

There should be a name of the Redis client in the brackets, but there's nothing: client [].

The default Redis client is named <default>.

Maybe the YAML is parsed differently...?

[Ladicek]

@denysandriyanov Could you please confirm that there's indeed client [] in the log? And do you override the version of SnakeYAML?

[denysandriyanov]

@Ladicek yes there is client [] in the log.

+--- io.quarkus:quarkus-config-yaml -> 3.6.0 | +--- io.smallrye.config:smallrye-config-source-yaml:3.4.4 | | +--- org.yaml:snakeyaml:2.1 -> 2.2