Is OIDCMetadataDir still working?

[xjia1]

I'm using Fedora 34 and since I upgraded mod_auth_openidc from 2.4.8.4 to 2.4.9, OIDCMetadataDir has stopped working.

A new message appears

src/mod_auth_openidc.c(2261): [client a.b.c.d:40088] oidc_authenticate_user: defer discovery to the content handler

which appears to be related to ac56864 48ad854 d6a9361

But even with the latest version that message is still there.

[zandbelt]

presumably you are using Require claim directives at the Redirect URI location, can you confirm that?

[brandonk10]

I appear to be having this exact problem. I can confirm I'm using Require Claim iss: inside my directory directive. I can't get the metadata directory to work, but switching to a single provider with metadata URL works fine.

[zandbelt]

which version are you using?

[zandbelt]

FWIW, on a different note: the Require statements need to be on different lines to be effective

[akomlik]

I guess in our deployment apache acts as reverse proxy (we have to use it specifically in order to use OIDC) that passes on request with empty user field to our internal backend (envoy) resulting in 401 instead of expected redirect to discovery page. This only started happening with upgrade from 2.4.4 to later version.

so when I hit start page /v3 I get this on logs:

[Mon Jan 03 22:46:21.062331 2022] [ssl:debug] [pid 1419:tid 140677207774784] ssl_engine_kernel.c(415): [client 34.218.23.209:34004] AH02034: Initial (No.1) HTTPS request received for child 335 (server labdc04.netspyglass.com:443)
[Mon Jan 03 22:46:21.062622 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/mod_auth_openidc.c(4058): [client 34.218.23.209:34004] oidc_authz_checker: enter: require_args=""email~akomlik@gmail.com""
[Mon Jan 03 22:46:21.062657 2022] [authz_core:debug] [pid 1419:tid 140677207774784] mod_authz_core.c(815): [client 34.218.23.209:34004] AH01626: authorization result of Require claim "email~akomlik@gmail.com": denied (no authenticated user yet)
[Mon Jan 03 22:46:21.062671 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/mod_auth_openidc.c(4058): [client 34.218.23.209:34004] oidc_authz_checker: enter: require_args=""hd:happygears.net""
[Mon Jan 03 22:46:21.062681 2022] [authz_core:debug] [pid 1419:tid 140677207774784] mod_authz_core.c(815): [client 34.218.23.209:34004] AH01626: authorization result of Require claim "hd:happygears.net": denied (no authenticated user yet)
[Mon Jan 03 22:46:21.062689 2022] [authz_core:debug] [pid 1419:tid 140677207774784] mod_authz_core.c(815): [client 34.218.23.209:34004] AH01626: authorization result of <RequireAny>: denied (no authenticated user yet)
[Mon Jan 03 22:46:21.062731 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/mod_auth_openidc.c(3926): [client 34.218.23.209:34004] oidc_check_user_id: incoming request: "/v3/?(null)", ap_is_initial_req(r)=1
[Mon Jan 03 22:46:21.062746 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Host=labdc04.netspyglass.com
[Mon Jan 03 22:46:21.062755 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Host=labdc04.netspyglass.com
[Mon Jan 03 22:46:21.062764 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(634): [client 34.218.23.209:34004] oidc_get_redirect_uri: determined absolute redirect uri: https://labdc04.netspyglass.com/openidc_callback
[Mon Jan 03 22:46:21.062774 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(1214): [client 34.218.23.209:34004] oidc_util_get_cookie: returning "mod_auth_openidc_session" = <null>
[Mon Jan 03 22:46:21.062783 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Host=labdc04.netspyglass.com
[Mon Jan 03 22:46:21.062844 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Host=labdc04.netspyglass.com
[Mon Jan 03 22:46:21.062858 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(634): [client 34.218.23.209:34004] oidc_get_redirect_uri: determined absolute redirect uri: https://labdc04.netspyglass.com/openidc_callback
[Mon Jan 03 22:46:21.062933 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(1377): [client 34.218.23.209:34004] oidc_util_request_matches_url: comparing "/v3/"=="/openidc_callback"
[Mon Jan 03 22:46:21.062946 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Accept=*/*
[Mon Jan 03 22:46:21.062954 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Accept=*/*
[Mon Jan 03 22:46:21.062961 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Accept=*/*
[Mon Jan 03 22:46:21.062970 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Host=labdc04.netspyglass.com
[Mon Jan 03 22:46:21.062978 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Host=labdc04.netspyglass.com
[Mon Jan 03 22:46:21.062985 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(615): [client 34.218.23.209:34004] oidc_get_current_url: current URL 'https://labdc04.netspyglass.com/v3/'
[Mon Jan 03 22:46:21.062992 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/mod_auth_openidc.c(2271): [client 34.218.23.209:34004] oidc_authenticate_user: enter
[Mon Jan 03 22:46:21.062999 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/mod_auth_openidc.c(2282): [client 34.218.23.209:34004] oidc_authenticate_user: defer discovery to the content handler
[Mon Jan 03 22:46:21.063009 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/mod_auth_openidc.c(4058): [client 34.218.23.209:34004] oidc_authz_checker: enter: require_args=""email~akomlik@gmail.com""
[Mon Jan 03 22:46:21.063018 2022] [authz_core:debug] [pid 1419:tid 140677207774784] mod_authz_core.c(815): [client 34.218.23.209:34004] AH01626: authorization result of Require claim "email~akomlik@gmail.com": granted
[Mon Jan 03 22:46:21.063027 2022] [authz_core:debug] [pid 1419:tid 140677207774784] mod_authz_core.c(815): [client 34.218.23.209:34004] AH01626: authorization result of <RequireAny>: granted
[Mon Jan 03 22:46:21.063137 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/mod_auth_openidc.c(4058): [client 34.218.23.209:34004] oidc_authz_checker: enter: require_args=""email~akomlik@gmail.com""
[Mon Jan 03 22:46:21.063161 2022] [authz_core:debug] [pid 1419:tid 140677207774784] mod_authz_core.c(815): [client 34.218.23.209:34004] AH01626: authorization result of Require claim "email~akomlik@gmail.com": denied (no authenticated user yet)
[Mon Jan 03 22:46:21.063171 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/mod_auth_openidc.c(4058): [client 34.218.23.209:34004] oidc_authz_checker: enter: require_args=""hd:happygears.net""
[Mon Jan 03 22:46:21.063177 2022] [authz_core:debug] [pid 1419:tid 140677207774784] mod_authz_core.c(815): [client 34.218.23.209:34004] AH01626: authorization result of Require claim "hd:happygears.net": denied (no authenticated user yet)
[Mon Jan 03 22:46:21.063182 2022] [authz_core:debug] [pid 1419:tid 140677207774784] mod_authz_core.c(815): [client 34.218.23.209:34004] AH01626: authorization result of <RequireAny>: denied (no authenticated user yet)
[Mon Jan 03 22:46:21.063189 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/mod_auth_openidc.c(3926): [client 34.218.23.209:34004] oidc_check_user_id: incoming request: "/v3/.*/proxy:http:/envoy:10000/v3/?(null)", ap_is_initial_req(r)=0
[Mon Jan 03 22:46:21.063195 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Host=labdc04.netspyglass.com
[Mon Jan 03 22:46:21.063201 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Host=labdc04.netspyglass.com
[Mon Jan 03 22:46:21.063207 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(634): [client 34.218.23.209:34004] oidc_get_redirect_uri: determined absolute redirect uri: https://labdc04.netspyglass.com/openidc_callback
[Mon Jan 03 22:46:21.063214 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(1214): [client 34.218.23.209:34004] oidc_util_get_cookie: returning "mod_auth_openidc_session" = <null>
[Mon Jan 03 22:46:21.063223 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Host=labdc04.netspyglass.com
[Mon Jan 03 22:46:21.063231 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Host=labdc04.netspyglass.com
[Mon Jan 03 22:46:21.063239 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(634): [client 34.218.23.209:34004] oidc_get_redirect_uri: determined absolute redirect uri: https://labdc04.netspyglass.com/openidc_callback
[Mon Jan 03 22:46:21.063248 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(1377): [client 34.218.23.209:34004] oidc_util_request_matches_url: comparing "/v3/.*/proxy:http:/envoy:10000/v3/"=="/openidc_callback"
[Mon Jan 03 22:46:21.063257 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Accept=*/*
[Mon Jan 03 22:46:21.063264 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Accept=*/*
[Mon Jan 03 22:46:21.063270 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Accept=*/*
[Mon Jan 03 22:46:21.063275 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Host=labdc04.netspyglass.com
[Mon Jan 03 22:46:21.063281 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(2510): [client 34.218.23.209:34004] oidc_util_hdr_in_get: Host=labdc04.netspyglass.com
[Mon Jan 03 22:46:21.063286 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/util.c(615): [client 34.218.23.209:34004] oidc_get_current_url: current URL 'https://labdc04.netspyglass.com/v3/.*/proxy:http://envoy:10000/v3/'
[Mon Jan 03 22:46:21.063291 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/mod_auth_openidc.c(2271): [client 34.218.23.209:34004] oidc_authenticate_user: enter
[Mon Jan 03 22:46:21.063302 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/mod_auth_openidc.c(2282): [client 34.218.23.209:34004] oidc_authenticate_user: defer discovery to the content handler
[Mon Jan 03 22:46:21.063308 2022] [auth_openidc:debug] [pid 1419:tid 140677207774784] src/mod_auth_openidc.c(4058): [client 34.218.23.209:34004] oidc_authz_checker: enter: require_args=""email~akomlik@gmail.com""
[Mon Jan 03 22:46:21.063314 2022] [authz_core:debug] [pid 1419:tid 140677207774784] mod_authz_core.c(815): [client 34.218.23.209:34004] AH01626: authorization result of Require claim "email~akomlik@gmail.com": granted
[Mon Jan 03 22:46:21.063320 2022] [authz_core:debug] [pid 1419:tid 140677207774784] mod_authz_core.c(815): [client 34.218.23.209:34004] AH01626: authorization result of <RequireAny>: granted
[Mon Jan 03 22:46:21.063389 2022] [proxy:debug] [pid 1419:tid 140677207774784] mod_proxy.c(1503): [client 34.218.23.209:34004] AH01143: Running scheme http handler (attempt 0)
[Mon Jan 03 22:46:21.063404 2022] [proxy:debug] [pid 1419:tid 140677207774784] proxy_util.c(2531): AH00942: http: has acquired connection for (envoy)
[Mon Jan 03 22:46:21.063416 2022] [proxy:debug] [pid 1419:tid 140677207774784] proxy_util.c(2587): [client 34.218.23.209:34004] AH00944: connecting http://envoy:10000/v3/ to envoy:10000
[Mon Jan 03 22:46:21.063758 2022] [proxy:debug] [pid 1419:tid 140677207774784] proxy_util.c(2810): [client 34.218.23.209:34004] AH00947: connected /v3/ to envoy:10000
[Mon Jan 03 22:46:21.064219 2022] [proxy:debug] [pid 1419:tid 140677207774784] proxy_util.c(3276): AH02824: http: connection established with 10.0.4.68:10000 (envoy)
[Mon Jan 03 22:46:21.064254 2022] [proxy:debug] [pid 1419:tid 140677207774784] proxy_util.c(3462): AH00962: http: connection complete to 10.0.4.68:10000 (envoy)
[Mon Jan 03 22:46:21.068448 2022] [proxy:debug] [pid 1419:tid 140677207774784] proxy_util.c(2546): AH00943: http: has released connection for (envoy)
[Mon Jan 03 22:46:21.074042 2022] [core:debug] [pid 1419:tid 140677207774784] util_cookies.c(58): [client 34.218.23.209:34004] AH00007: ap_cookie: user '(null)' set cookie: 'session=sLx7BBbFOQDpS1+j/ZNO7rbx114d26PGXfcGyue1Rz7wIuv1e3jumyWnPF4qWuqumpy+zfLgblU=;Max-Age=604800;path=/'
[Mon Jan 03 22:46:21.075583 2022] [ssl:debug] [pid 1419:tid 140677199382080] ssl_engine_io.c(1147): [client 34.218.23.209:34004] AH02001: Connection closed to child 336 with standard shutdown (server labdc04.netspyglass.com:443)
^C

I worked around this by explicit redirect to discovery page if incoming request does not have mod_auth_openidc_session cookie set (meaning user is not yet authorized)

<LocationMatch "^/v3/.*)">
  <If "! %{HTTP_COOKIE} =~ /mod_auth_openidc_session/ && ! -n req('X-NSG-Auth-API-Token')" >
    Require all granted
    RewriteEngine On
    RewriteRule ^.*$ "/idp-discovery.html?target_link_uri=%{REQUEST_SCHEME}://%{HTTP_HOST}%{REQUEST_URI}" [QSD,L,R]
  </If>
</LocationMatch>

[zandbelt]

You have:

[Mon Jan 03 22:46:21.062689 2022] [authz_core:debug] [pid 1419:tid 140677207774784] mod_authz_core.c(815): [client 34.218.23.209:34004] AH01626: authorization result of <RequireAny>: denied (no authenticated user yet)

but in the configs that you sent I cannot find any RequireAny statement, there seems to be a mismatch between what I test and what you use.

[akomlik]

I just verified what I sent you is correct.
I don't have such statement anywhere in configs. Searching for it I only find it in module shared library and in error.log:

root@labdc04a-proxy-1:/# grep -lr RequireAny /usr/local/apache2/
/usr/local/apache2/modules/mod_authz_core.so
/usr/local/apache2/logs/error.log
root@labdc04a-proxy-1:/#

So, not sure where it comes from. I was surprised to see that, too.

For comparison, when I used plugin 2.4.4 the log with all same configs looked like this:

[Wed Dec 29 19:06:40.744266 2021] [ssl:debug] [pid 37:tid 140325968406272] ssl_engine_kernel.c(415): [client 69.110.136.6:59061] AH02034: Initial (No.1) HTTPS request received for child 456 (server labdc04.netspyglass.com:443)
[Wed Dec 29 19:06:40.744476 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/mod_auth_openidc.c(4106): [client 69.110.136.6:59061] oidc_authz_checker: enter
[Wed Dec 29 19:06:40.744513 2021] [authz_core:debug] [pid 37:tid 140325968406272] mod_authz_core.c(815): [client 69.110.136.6:59061] AH01626: authorization result of Require claim "email~craigoshima@gmail.com" Require claim "email~mlussier@gmail.com" Require claim "email~akomlik@gmail.com" Require claim "hd:happygears.net": denied (no authenticated user yet)
[Wed Dec 29 19:06:40.744526 2021] [authz_core:debug] [pid 37:tid 140325968406272] mod_authz_core.c(815): [client 69.110.136.6:59061] AH01626: authorization result of <RequireAny>: denied (no authenticated user yet)
[Wed Dec 29 19:06:40.744554 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/mod_auth_openidc.c(3999): [client 69.110.136.6:59061] oidc_check_user_id: incoming request: "/?(null)", ap_is_initial_req(r)=1
[Wed Dec 29 19:06:40.744571 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/util.c(2316): [client 69.110.136.6:59061] oidc_util_hdr_in_get: Cookie=x_csrf=rj2hZszPOjw; session=mKaO3HpCwfaXO/ewj9BL043XGNQjjQATB+MOqKmPYjHYrziKCxWPTUmExrem47ulmloc3s5rr04=
[Wed Dec 29 19:06:40.744582 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/util.c(1054): [client 69.110.136.6:59061] oidc_util_get_cookie: returning "mod_auth_openidc_session" = <null>
[Wed Dec 29 19:06:40.744593 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/util.c(1217): [client 69.110.136.6:59061] oidc_util_request_matches_url: comparing "/"=="/openidc_callback"
[Wed Dec 29 19:06:40.744603 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/util.c(2316): [client 69.110.136.6:59061] 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.9
[Wed Dec 29 19:06:40.744627 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/util.c(2316): [client 69.110.136.6:59061] oidc_util_hdr_in_get: Host=labdc04.netspyglass.com
[Wed Dec 29 19:06:40.744635 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/util.c(2316): [client 69.110.136.6:59061] oidc_util_hdr_in_get: Host=labdc04.netspyglass.com
[Wed Dec 29 19:06:40.744643 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/util.c(518): [client 69.110.136.6:59061] oidc_get_current_url: current URL 'https://labdc04.netspyglass.com/'
[Wed Dec 29 19:06:40.744651 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/mod_auth_openidc.c(2398): [client 69.110.136.6:59061] oidc_authenticate_user: enter
[Wed Dec 29 19:06:40.744658 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/mod_auth_openidc.c(2241): [client 69.110.136.6:59061] oidc_discovery: enter
[Wed Dec 29 19:06:40.744665 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/util.c(2316): [client 69.110.136.6:59061] oidc_util_hdr_in_get: Host=labdc04.netspyglass.com
[Wed Dec 29 19:06:40.744672 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/util.c(2316): [client 69.110.136.6:59061] oidc_util_hdr_in_get: Host=labdc04.netspyglass.com
[Wed Dec 29 19:06:40.744679 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/util.c(518): [client 69.110.136.6:59061] oidc_get_current_url: current URL 'https://labdc04.netspyglass.com/'
[Wed Dec 29 19:06:40.744687 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/proto.c(81): [client 69.110.136.6:59061] oidc_proto_generate_random_bytes: apr_generate_random_bytes call for 8 bytes
[Wed Dec 29 19:06:40.744699 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/proto.c(85): [client 69.110.136.6:59061] oidc_proto_generate_random_bytes: apr_generate_random_bytes returned
[Wed Dec 29 19:06:40.744800 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/mod_auth_openidc.c(2279): [client 69.110.136.6:59061] oidc_discovery: redirecting to external discovery page: https://labdc04.netspyglass.com:443/idp-discovery.html?target_link_uri=https%3A%2F%2Flabdc04.netspyglass.com%2F&method=get&oidc_callback=https%3A%2F%2Flabdc04.netspyglass.com%3A443%2Fopenidc_callback&x_csrf=f0Y6e0z3WzI
[Wed Dec 29 19:06:40.744819 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/util.c(944): [client 69.110.136.6:59061] oidc_util_set_cookie_append_value: no cookie append environment variable OIDC_SET_COOKIE_APPEND found
[Wed Dec 29 19:06:40.744828 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/util.c(2394): [client 69.110.136.6:59061] oidc_util_hdr_err_out_add: Set-Cookie: x_csrf=f0Y6e0z3WzI; Path=/; Secure; HttpOnly; SameSite=None
[Wed Dec 29 19:06:40.744837 2021] [auth_openidc:debug] [pid 37:tid 140325968406272] src/util.c(2372): [client 69.110.136.6:59061] oidc_util_hdr_table_set: Location: https://labdc04.netspyglass.com:443/idp-discovery.html?target_link_uri=https%3A%2F%2Flabdc04.netspyglass.com%2F&method=get&oidc_callback=https%3A%2F%2Flabdc04.netspyglass.com%3A443%2Fopenidc_callback&x_csrf=f0Y6e0z3WzI
[Wed Dec 29 19:06:40.755970 2021] [core:debug] [pid 37:tid 140325968406272] util_cookies.c(58): [client 69.110.136.6:59061] AH00007: ap_cookie: user '(null)' set cookie: 'session=HsT7ftNORUbnfLN79lhCaZfVsiFqWZSENFB9broMsZHNjoVXuWsi55ExQe/csH9JsMYko2Ncb5U=;Max-Age=604800;path=/'
[Wed Dec 29 19:06:40.756002 2021] [headers:debug] [pid 37:tid 140325968406272] mod_headers.c(890): AH01503: headers: ap_headers_error_filter()
[Wed Dec 29 19:06:40.798540 2021] [ssl:debug] [pid 37:tid 140325842581248] ssl_engine_kernel.c(415): [client 69.110.136.6:59061] AH02034: Subsequent (No.2) HTTPS request received for child 462 (server labdc04.netspyglass.com:443)
[Wed Dec 29 19:06:40.798658 2021] [authz_core:debug] [pid 37:tid 140325842581248] mod_authz_core.c(815): [client 69.110.136.6:59061] AH01626: authorization result of Require all granted: granted
[Wed Dec 29 19:06:40.798682 2021] [authz_core:debug] [pid 37:tid 140325842581248] mod_authz_core.c(815): [client 69.110.136.6:59061] AH01626: authorization result of <RequireAny>: granted
[Wed Dec 29 19:06:40.807010 2021] [core:debug] [pid 37:tid 140325842581248] util_cookies.c(58): [client 69.110.136.6:59061] AH00007: ap_cookie: user '(null)' set cookie: 'session=kXs4Itm/zP9ZCcSGoDhNzI0IlpErp6Ug5aXp5Ncodv5u/G2xnv/xbE6eCn8I5pmnWz50DQ/Zw5c=;Max-Age=604800;path=/'

[zandbelt]

I'm starting to see the issue here: it is the mod_auth_form that is conflicting with mod_auth_openidc here and the former actually returns deny in the authorization phase after mod_auth_openidc has interacted with the request. In the end this is a matter of two authentication modules trying to be first: your workaround is probably your best chance, if you need a code fix you'll have to work on a PR yourself or get into a commercial development agreement via sales@zmartzone.eu.