Can OAuth2 logging be improved?

[hakan-77]

Is your feature request related to a problem? Please describe.

We have integrated OAuth to tens of 3rd party services and never have we struggled as much as we do with RabbitMQ. I will submit other issues, but most importantly we should improve logging. E.g. an error message like "Authentication using an OAuth 2/JWT token failed: provided token is invalid" does not help too much. What exactly is the issue? Is it wrong public key? "iss" not matching? expired token?

Describe the solution you'd like

Improved logging, at least for debug level. At least for errors, but ideally for all the auth flow events too.

Describe alternatives you've considered

No response

Additional context

No response

[michaelklishin]

@hakan-77 "improve logging" is neither specific nor actionable. It cannot be an issue in its current form, our team has certain standards.

RabbitMQ supports five IDPs and six configurations, some of which deviate from the standard specs, and the number of things that can go wrong is very broad. This complexity is inherent,
not something specific to our OAuth 2 implementation.

We routinely hear request to reduce the amount RabbitMQ logs, including at debug level,
and specifically not log anything that can be even distantly sensitive, and JWT tokens are by definitions sensitive values.

Which is why we have extensive OAuth 2 documentation, examples, and a troubleshooting guide.

[lukebakken]

I will submit other issues

Please, don't do that. If you would like to see improved logging, submit pull requests.

[hakan-77]

@lukebakken I am confused. Do all other issues also submit pull requests? Do you expect all of your users to program in Erlang?

[michaelklishin]

@hakan-77 we do expect our open source users to contribute, not necessarily with code. You get the software for free after all.

Specifically, we need common failure scenarios to test and see what can be improved in each case.
Those can be well researched issues or PRs if you think you can go straight for some code changes.

[michaelklishin]

While we do have failure scenarios in our test suites, we cannot know which are the ones that our users face. For that, we need anecdotal evidence and reports. But we need them to be detailed enough to reproduce with, say, Keycloak.

Issues that do not have enough details for us to reproduce have a high chance of being closed. We are a small team who gives away quite a bit of our work for free, we cannot afford to spend days guessing.

[michaelklishin]

@hakan-77 to give you an idea of how many different scenarios there are, take a look at the main OAuth 2 test suite.

That's not everything, we have a comparable number in other suites/plugins plus an OAuth 2 client.

In each scenario, a number of things can go wrong, from cryptographic operations-related to misconfigured IDP URIs and such.

It's incredibly difficult to "improve logging" for all of them. For some specific well known cases, sure, but you haven't even mentioned what exactly were the issues in your case.

Hence the suggestion to go straight to pull requests, for both the code and the documentation guides.

Let's not pretend like it's a matter of adding a few logging lines in one module.

[hakan-77]

@michaelklishin I don't program in Erlang, but in other languages we usually have supporting JWT libraries that pinpoint the issue. A JWT token can be invalid for several different reasons. "Authentication using an OAuth 2/JWT token failed: provided token is invalid" does not give a clue why. Maybe you're parsing JWT yourself? Also, we don't know if the JWKS url is successfully parsed at first place, if public key is being used, and hence my feedback on logging the steps of the flow.

As I mentioned before, we integrate with many platforms, from Grafana to harbor to gitea to ... you name it. This is the way pretty much all of these platforms OAuth work, helping users pinpoint issues.

If you are truly interested in understanding how to improve the platform, I can help. If the only way to do this is to program in Erlang, then I'm not the right person.

[michaelklishin]

@hakan-77 we use such a library, jose. We depend on the details in provides. I can imagine that it could need a lot of love in that area.

First and foremost, we need specific reproducible failure scenarios.

[michaelklishin]

I can also imagine that our own OAuth 2-related code can be improved in many places. I'm not denying that by any means.

[hakan-77]

Oh, definitely. As I mentioned, we integrate with many platforms, and the common theme is that we have to tweak the configuration for almost all of these platforms. My original issue is exactly about this, help us pinpoint the issue, so we can tailor for RabbitMQ. I'll share below our configuration.

[michaelklishin]

There are also oauth2_client (our own library), rabbitmq_auth_backend_oauth2, and lots of OAuth 2-related changes in the management and other plugins.

[hakan-77]

OAuth provider: Custom Django OAuth, it is compatible with Keycloak.
RabbitMQ cluster: we used k8s operator with the below configuration
I'll add some of my suspicions below the yaml

apiVersion: rabbitmq.com/v1beta1
kind: RabbitmqCluster
metadata:
  name: my-rabbit
  namespace: my-ns
spec:
  replicas: 1
  rabbitmq:
    additionalPlugins:
      - rabbitmq_auth_backend_oauth2
    additionalConfig: |
      log.default.level = debug
      auth_backends.1 = rabbit_auth_backend_oauth2
      auth_backends.2 = internal
      management.oauth_enabled = true
      management.oauth_client_id = 4F5Upg2dcFBlgan9yHldscNXgJBJQgy5gjNqcuXi
      management.oauth_client_secret = ...
      management.oauth_scopes = openid profile email username roles
      management.oauth_provider_url = https://.../o
      auth_oauth2.issuer =  tried both https://.../o/  and also the JWT issuer: iss.mydomain.com (which fails faster)
      auth_oauth2.preferred_username_claims.1 = username
      auth_oauth2.preferred_username_claims.2 = email
      auth_oauth2.jwks_url = https://.../o/.well-known/jwks.json
      auth_oauth2.resource_server_id = rabbitmq
      auth_oauth2.authorization_endpoint = https://.../o/authorize/
      auth_oauth2.token_endpoint = https://.../o/token/
      auth_oauth2.verify_aud = false
      auth_oauth2.https.peer_verification = verify_none
      auth_oauth2.algorithms.1 = RS256
      auth_oauth2.https.fail_if_no_peer_cert = false

JWT content:

{"sub": "my_name@company.com", 
"name": "my_name my_lastname", "given_name": "my_name", 
"family_name": "my_lastname", "email": "my_name@company.com", "username": "my_name", "roles": "Admin", 
"scope": ["rabbitmq.tag:administrator"] }

Server log:

2025-02-20 20:21:09.855064+00:00 [debug] <0.974.0> Using oauth_provider {id: "<from keyconfig>", issuer: "https://.../o", token_endpoint: "https://.../o/token/", authorization_endpoint: "https://.../o/authorize/", end_session_endpoint: "https://.../o/logout/", jwks_uri: "https://.../o/.well-known/jwks.json", ssl_options: {verify: verify_peer, fail_if_no_peer_cert: false, crl_check: false, depth: 10, cacertfile: undefined, cacerts(count): 146 } } from keyconfig
2025-02-20 20:21:11.200698+00:00 [debug] <0.985.0> Using oauth_provider {id: "<from keyconfig>", issuer: "https://.../o", token_endpoint: "https://.../o/token/", authorization_endpoint: "https://.../o/authorize/", end_session_endpoint: "https://.../o/logout/", jwks_uri: "https://.../o/.well-known/jwks.json", ssl_options: {verify: verify_peer, fail_if_no_peer_cert: false, crl_check: false, depth: 10, cacertfile: undefined, cacerts(count): 146 } } from keyconfig
2025-02-20 20:21:11.621234+00:00 [debug] <0.1010.0> User '4F5Upg2dcFBlgan9yHldscNXgJBJQgy5gjNqcuXi' failed authentication by backend rabbit_auth_backend_internal
2025-02-20 20:21:11.656795+00:00 [debug] <0.1010.0> Authentication using an OAuth 2/JWT token failed: provided token is invalid
2025-02-20 20:21:11.657753+00:00 [debug] <0.1010.0> User '4F5Upg2dcFBlgan9yHldscNXgJBJQgy5gjNqcuXi' failed authentication by backend rabbit_auth_backend_oauth2
2025-02-20 20:21:11.660309+00:00 [warning] <0.1010.0> HTTP access denied: Authentication using an OAuth 2/JWT token failed: provided token is invalid

Potential issues:

• in one of the documentations I read the jwt issuer is expected to have protocol e.g. https://my.company instead of my.company ? (JWT standard does not mandate this)
• Server logs state "User '4F5Upg2dcFBlgan9yHldscNXgJBJQgy5gjNqcuXi' failed" why not my user name in sub/username or even email?
• I had to manually set auth_oauth2.authorization_endpoint, auth_oauth2.token_endpoint. maybe o/.well-known/openid-configuration is not parsed?

[michaelklishin]

I agree that we likely can do better than that on number 2, @MarcialRosales would be the right person to verify whether the docs need clarifying in 1 and 3.

[hakan-77]

I just realized @MarcialRosales already has an open issue, Improve error messages shown in the management ui when using oauth2 authentication #12261 which is quite similar to what I was asking. I must have missed this.

That being said, I still believe there are types of OAuth2 errors that one would not print on the management UI due to security concerns. And for these, improved debug logging would be a breeze. Ideally, in each step e.g. "parsed jwks, will use ...", "public key located in.." and on errors.

OAuth2 issues are the worst to deal with, and every little helps.

[MarcialRosales]

Hi @hakan-77 , first of all thanks for reporting your issues with Oauth2 plugin. I would like that you bring up every issue you have had in the past troubleshooting an oauth2 issue so that we can do something about it. The troubleshooting guide that I have put together should serve 99% of all users troubleshooting an issue. I want users to go there first and from there advise them how to trouble shoot the issue they are having, for instance, advise them to the logs and search for some keywords or go to the console in the browser, etc. If the logs are not there to help troubleshoot a particular issue, we change the code. I think it can work well for both of us.

Back to your issues. I dont know which version of RabbitMQ you are using, but if you look at this configuration file (https://github.com/rabbitmq/rabbitmq-oauth2-tutorial/blob/main/conf/keycloak/rabbitmq.conf) that is used in the keycloak example you will see two key variables (by the way, most of the examples with other Idps also rely on the auto-discovery of endpoints..):

• auth_oauth2.issuer (https://openid.net/specs/openid-connect-core-1_0.html#IssuerIdentifier) . It must be a url with https. Even the OpenId spec says so. i am sure you have read the RabbitMQ oauth2 docs, and most likely you have read the section Configure OAuth 2.0 provider's issuer. Here it is explained that if you provide this url, RabbitMQ will download all the other endpoints via the OpenID discovery endpoint
• About seeing a weird username in the logs , the doc's section Preferred username claims
  , explains that you can configure what claim you want RabbitMQ to use to identify the user. RabbitMQ extracts the username for logging purposes and also to display the username of the logged in user in the management ui. RabbitMQ normally uses sub as the default claim for username. However, not always, that claim contains a user-friendly name. Hence you can configure RabbitMQ with your preferred claims for username.

Please, let me know if you have more doubts/questions and more importantly, suggestions on how to improve the troubleshooting guide to help that potential user who may have the same issues you had. Thanks !

[hakan-77]

Hi @MarcialRosales,

Thank you for your response. I have went through the troubleshooting guide, but it didn't help. I will try again. I have to repeat my original ask, troubleshooting guides are great, but even better is the system logging what is wrong at first place. Until this happens, I'll do my best to improve the guide.

Regarding issuer ("iss") requirement to be a url with https, I am copying directly from the url you shared https://openid.net/specs/openid-connect-core-1_0.html#IssuerIdentifier

---

16.15. Issuer Identifier
OpenID Connect supports multiple Issuers per Host and Port combination. The issuer returned by discovery MUST exactly match the value of iss in the ID Token.

OpenID Connect treats the path component of any Issuer URI as being part of the Issuer Identifier. For instance, the subject "1234" with an Issuer Identifier of "https://example.com" is not equivalent to the subject "1234" with an Issuer Identifier of "https://example.com/sales".

It is RECOMMENDED that only a single Issuer per host be used. However, if a host supports multiple tenants, multiple Issuers for that host may be needed.

---

This does not say "iss" needs to be a https url, but the examples they give use https urls. In my experience, some prefer "iss" to be a url, so end users can lookup, it guarantees uniqueness etc. and others prefer to keep it short since JWT tokens are notoriously long e.g. 500-600 chars in every http request header, in comparison to, say, github tokens 20-30 chars. And practically, I can confidently say other OAuth systems do not enforce such requirement.

Since @michaelklishin mentioned you use https://github.com/potatosalad/erlang-jose library for jwt workloads, I got suspicious of their understanding of the JWT specification and wanted to open a ticket in that repo, but I see they do not enforce such a rule, and even their readme.md uses iss without https. Please check "usage" section of their read me file https://github.com/potatosalad/erlang-jose?tab=readme-ov-file#usage

# JSON Web Token (JWT)
jwt = %{
  "iss" => "joe",
  "exp" => 1300819380,
  "http://example.com/is_root" => true
}

Lastly, I think it would be fantastic if you could check Grafana'a OAuth configuration https://grafana.com/docs/grafana/latest/setup-grafana/configure-security/configure-authentication/keycloak/ since it is one of the most popular services out there and their OAuth is extremely battle tested, and one of the best we experienced with, from config to logging.

For OAuth configs, one provides url's (or one /well-defined url), a client id, a secret, scope, and you're good to go. Username/password login is left intact, so one has a backup plan to login in case OAuth doesn't work. Scopes are wrong? no problem, user is created with no permissions, and the "fallback admin" logs in w/ username/password, grants permissions manually.. and happy days.

[michaelklishin]

Thank you, now we are talking specifics and something like this can be turned into an issue or a few issues next week as we refine the initial scope.

[hakan-77]

Perfect. I'll let @MarcialRosales open the issues, and I'm more than happy to contribute in: 1) the design phase: e.g. some of the checks/validations you guys are doing and we are discussing are the OAuth providers (Okta, Keycloak etc.) job. Should you (OAuth client) even care and enforce how the "iss" is defined? and 2) testing.