OpenIDC/mod_auth_openidc

oidc_util_hdr_err_out_add: Cache-Control: no-cache, no-store, max-age=0

Closed this issue · 1 comments

Discussed in #1257

Originally posted by Moret00 September 3, 2024
Server Version: Apache/2.4.52 (Ubuntu)

mod_auth_openidc

When I'm trying to reach the "exampleresource" resource by clicking on the Link https://localhost:8443/exampleresource, my Browser correctly redirects me to the Authentication page. In the meantime, (without having inserted any kind of credentials) in the /var/log/apache2/error.log appear this long sequence of logs (shown below). After attempting to authenticate myself on the Browser (by inserting Username & Password in the form) it shows me an "Invalid credentials" error. Can anyone help me with this issue?

My /etc/apache2/sites-available/default-ssl.conf:

OIDCProviderMetadataURL /.well-known/openid-configuration
OIDCClientID <client_id>
OIDCClientSecret <client_secret>
OIDCRedirectURI https://localhost:44333/login/oauth2/code/app
OIDCCryptoPassphrase <crypto_passphrase>
OIDCPKCEMethod S256
OIDCOAuthSSLValidateServer Off
OIDCSSLValidateServer Off
OIDCScope "openid profile email"

OIDCCookiePath "/"
OIDCCookieHttpOnly Off
OIDCCookieSameSite Off
OIDCSessionType client-cookie:persistent

LogLevel auth_openidc:trace8
OIDCSessionInactivityTimeout 86400

<Location /exampleresource>
AuthType openid-connect
Require valid-user
RequestHeader set Authorization "Bearer %{OIDC_id_token}e"

Alias /exampleresource /var/www/html/exampleresource.html
Alias /error.html /var/www/html/error.html

ErrorLog ${APACHE_LOG_DIR}/error.log
CustomLog ${APACHE_LOG_DIR}/access.log combined

sudo tail -f /var/log/apache2/error.log

[Tue Sep 03 10:11:56.707893 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/mod_auth_openidc.c(3952): [client ::1:50168] oidc_check_user_id: incoming request: "/exampleresource?(null)", ap_is_initial_req(r)=1
[Tue Sep 03 10:11:56.707926 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(1225): [client ::1:50168] oidc_util_get_cookie: returning "mod_auth_openidc_session_chunks" =
[Tue Sep 03 10:11:56.707928 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(1225): [client ::1:50168] oidc_util_get_cookie: returning "mod_auth_openidc_session" =
[Tue Sep 03 10:11:56.707930 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(1388): [client ::1:50168] oidc_util_request_matches_url: comparing "/exampleresource"=="/login/oauth2/code/app"
[Tue Sep 03 10:11:56.707932 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(2473): [client ::1:50168] oidc_util_hdr_in_get: Sec-Fetch-Mode=navigate
[Tue Sep 03 10:11:56.707933 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(2473): [client ::1:50168] oidc_util_hdr_in_get: Sec-Fetch-Mode=navigate
[Tue Sep 03 10:11:56.707934 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(2473): [client ::1:50168] oidc_util_hdr_in_get: Sec-Fetch-Dest=document
[Tue Sep 03 10:11:56.707935 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(2473): [client ::1:50168] oidc_util_hdr_in_get: Sec-Fetch-Dest=document
[Tue Sep 03 10:11:56.707936 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(2473): [client ::1:50168] oidc_util_hdr_in_get: Accept=text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,/;q=0.8,application/signed-exchange;v=b3;q=0.7
[Tue Sep 03 10:11:56.707938 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(2473): [client ::1:50168] oidc_util_hdr_in_get: Host=localhost:8443
[Tue Sep 03 10:11:56.707940 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(2473): [client ::1:50168] oidc_util_hdr_in_get: Host=localhost:8443
[Tue Sep 03 10:11:56.707942 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(630): [client ::1:50168] oidc_get_current_url: current URL 'https://localhost:8443/exampleresource'
[Tue Sep 03 10:11:56.707943 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/mod_auth_openidc.c(2255): [client ::1:50168] oidc_authenticate_user: enter
[Tue Sep 03 10:11:56.707945 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/cache/common.c(305): [client ::1:50168] oidc_cache_get: enter: /.well-known/openid-configuration (section=p, decrypt=0, type=shm)
[Tue Sep 03 10:11:56.708036 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/cache/common.c(340): [client ::1:50168] oidc_cache_get: cache miss from shm cache backend for key /.well-known/openid-configuration
[Tue Sep 03 10:11:56.708046 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(761): [client ::1:50168] oidc_util_http_query_encoded_url: url=/.well-known/openid-configuration
[Tue Sep 03 10:11:56.708049 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(800): [client ::1:50168] oidc_util_http_call: url=/.well-known/openid-configuration, data=(null), content_type=(null), basic_auth=null, bearer_token=(null), ssl_validate_server=0, timeout=5, outgoing_proxy=(null), pass_cookies=0, ssl_cert=(null), ssl_key=(null), ssl_key_pwd=(null)
[Tue Sep 03 10:11:56.810417 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(997): [client ::1:50168] oidc_util_http_call: HTTP response code=200
[Tue Sep 03 10:11:56.810542 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(1002): [client ::1:50168] oidc_util_http_call: response={\n"issuer":"",\n"authorization_endpoint":"/mga/sps/oauth/oauth20/authorize",\n"token_endpoint":"/mga/sps/oauth/oauth20/token",\n"userinfo_endpoint":"/mga/sps/oauth/oauth20/userinfo",\n"jwks_uri":"/mga/sps/oauth/oauth20/jwks/TTC",\n"response_types_supported":["code","none"],\n"response_modes_supported":["fragment","form_post"],\n"id_token_signing_alg_values_supported":["RS256"],\n"id_token_encryption_alg_values_supported":[],\n"id_token_encryption_enc_values_supported":[],\n"poc":"/mga/",\n"subject_types_supported":["public"],\n"name":"TTC",\n"grant_types_supported":["authorization_code","refresh_token"],\n"introspect_endpoint":"/mga/sps/oauth/oauth20/introspect",\n"revocation_endpoint":"/mga/sps/oauth/oauth20/revoke",\n"registration_endpoint":"https:///mga/sps/oauth/oauth20/register/TTC",\n"device_authorize_endpoint":"/mga/sps/oauth/oauth20/device_authorize",\n"user_authorize_endpoint":"/mga/sps/oauth/oauth20/user_authorize",\n"token_endpoint_auth_methods_supported":["private_key_jwt","client_secret_post","client_secret_basic","tls_client_auth","self_signed_tls_client_auth"],\n"claims_supported": ["realmName","preferred_username","given_name","uid","upn","groupIds","employee_id","name","tenantId","mobile_number", "department","job_title","family_name","email"],\n"userinfo_signing_alg_values_supported":["RS256"],\n"request_parameter_supported":true\n}
[Tue Sep 03 10:11:56.810870 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/cache/common.c(360): [client ::1:50168] oidc_cache_set: enter: /.well-known/openid-configuration (section=p, len=1785, encrypt=0, ttl(s)=86399, type=shm)
[Tue Sep 03 10:11:56.810936 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/cache/common.c(389): [client ::1:50168] oidc_cache_set: successfully stored 1785 bytes in shm cache backend for key /.well-known/openid-configuration
[Tue Sep 03 10:11:56.810970 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/proto.c(67): [client ::1:50168] oidc_proto_generate_random_bytes: apr_generate_random_bytes call for 32 bytes
[Tue Sep 03 10:11:56.810979 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/proto.c(71): [client ::1:50168] oidc_proto_generate_random_bytes: apr_generate_random_bytes returned
[Tue Sep 03 10:11:56.810987 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/proto.c(67): [client ::1:50168] oidc_proto_generate_random_bytes: apr_generate_random_bytes call for 32 bytes
[Tue Sep 03 10:11:56.810993 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/proto.c(71): [client ::1:50168] oidc_proto_generate_random_bytes: apr_generate_random_bytes returned
[Tue Sep 03 10:11:56.811023 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(1388): [client ::1:50168] oidc_util_request_matches_url: comparing "/exampleresource"=="/login/oauth2/code/app"
[Tue Sep 03 10:11:56.811071 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/mod_auth_openidc.c(209): [client ::1:50168] oidc_get_browser_state_hash: enter
[Tue Sep 03 10:11:56.811081 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(2473): [client ::1:50168] oidc_util_hdr_in_get: User-Agent=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36
[Tue Sep 03 10:11:56.811097 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(2288): [client ::1:50168] oidc_util_create_symmetric_key: key_len=32
[Tue Sep 03 10:11:56.811203 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(1115): [client ::1:50168] oidc_util_set_cookie_append_value: no cookie append environment variable OIDC_SET_COOKIE_APPEND found
[Tue Sep 03 10:11:56.811275 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(2551): [client ::1:50168] oidc_util_hdr_err_out_add: Set-Cookie: mod_auth_openidc_state_3PU50OD4vl-Bq9eIe9r50-faX4w=KlmPzq-l-5V_h6M5.ha23_CwEmkEWXpPfjIXeByIR4yaYUkzgdAPKTnKQdP3nXlLgmoyDyC3GUDSIayPcHcP19-pgcNdNn7Ejo84nOkD7AAxX7oNi6COgLbv8nQaiNrW4FqClddGYe7ipFKIO_MTas8OP5aLeUHqbf8SfDzKcM9eG9PqXGmgmWnUH_okJ8O77iLdcPLZnME5N2WxLLyzS3lGVqOAAYByKWMtn8lHSvRSFSZ-KEHX5hr5rsHBIMZpVOgxBXyEQyo7C-Ff3eAPOtEh4NPnAdMT1V-V28DB8f66apnOZ7mSC1dg8yxqRkVJxU4FkXekb_VEGxUkXdS0lZ91Y2ISVOBiUUrjf7iPcwO6p9XwrP8tm9glQzqewKwbLjdishkx_gs8xmN1oQnljbte79FaK0tVqNBN04ACd6S1RHJmlaXQnG6HK06PTjXInA1XD89ZNOQfUdg6pFqPs0YvNOpZgutisKtzBsdhpwsyxe4xavIDF2269e0IakJxVUvbWxvLa.DNfxMa___GbLI4jDL9Mvjg; Path=/; Secure; SameSite=None
[Tue Sep 03 10:11:56.811299 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/proto.c(643): [client ::1:50168] oidc_proto_authorization_request: enter, issuer=, redirect_uri=https://localhost:44333/login/oauth2/code/app, state=, proto_state={"ou":"https://localhost:8443/exampleresource","om":"get","i":"","rt":"code","n":"<n_value>","t":<t_value>,"ps":"<ps_value>"}, code_challenge=<code_challenge>, auth_request_params=(null), path_scope=(null)
[Tue Sep 03 10:11:56.811316 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(731): [client ::1:50168] oidc_util_http_add_form_url_encoded_param: processing: response_type=code
[Tue Sep 03 10:11:56.811365 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(731): [client ::1:50168] oidc_util_http_add_form_url_encoded_param: processing: scope=openid profile email
[Tue Sep 03 10:11:56.811379 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(731): [client ::1:50168] oidc_util_http_add_form_url_encoded_param: processing: client_id=<client_id>
[Tue Sep 03 10:11:56.811398 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(731): [client ::1:50168] oidc_util_http_add_form_url_encoded_param: processing: state=
[Tue Sep 03 10:11:56.811414 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(731): [client ::1:50168] oidc_util_http_add_form_url_encoded_param: processing: redirect_uri=https://localhost:44333/login/oauth2/code/app
[Tue Sep 03 10:11:56.811470 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(731): [client ::1:50168] oidc_util_http_add_form_url_encoded_param: processing: nonce=
[Tue Sep 03 10:11:56.811490 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(731): [client ::1:50168] oidc_util_http_add_form_url_encoded_param: processing: code_challenge=<code_challenge>
[Tue Sep 03 10:11:56.811545 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(731): [client ::1:50168] oidc_util_http_add_form_url_encoded_param: processing: code_challenge_method=S256
[Tue Sep 03 10:11:56.811567 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(761): [client ::1:50168] oidc_util_http_query_encoded_url: url=/mga/sps/oauth/oauth20/authorize?response_type=code&scope=openid%20profile%20email&client_id=<client_id>&state=&redirect_uri=https%3A%2F%2Flocalhost%3A44333%2Flogin%2Foauth2%2Fcode%2Fapp&nonce=&code_challenge=<code_challenge>&code_challenge_method=S256
[Tue Sep 03 10:11:56.811578 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(2529): [client ::1:50168] oidc_util_hdr_table_set: Location: /mga/sps/oauth/oauth20/authorize?response_type=code&scope=openid%20profile%20email&client_id=<client_id>&state=&redirect_uri=https%3A%2F%2Flocalhost%3A44333%2Flogin%2Foauth2%2Fcode%2Fapp&nonce=&code_challenge=<code_challenge>&code_challenge_method=S256
[Tue Sep 03 10:11:56.811594 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/util.c(2551): [client ::1:50168] oidc_util_hdr_err_out_add: Cache-Control: no-cache, no-store, max-age=0
[Tue Sep 03 10:11:56.811599 2024] [auth_openidc:debug] [pid 19045:tid 140034543277632] src/proto.c(785): [client ::1:50168] oidc_proto_authorization_request: return: 302

That's the Browser answer after the Authentication try:
invalidcredentials