Reposoft / openidc-keycloak-test

zmartzone/mod_auth_openidc and keycloak combined - self hosted cloud auth
19 stars 6 forks source link

Error "no client secret is configured" after upgrade from 2.3.0 to 2.3.1 #19

Open solsson opened 7 years ago

solsson commented 7 years ago

Upon successful login the page shows "Error: OpenID Connect Provider error: Error in handling response type."

Logs:

openidc_1         | AH00558: httpd: Could not reliably determine the server's fully qualified domain name, using 172.19.0.5. Set the 'ServerName' directive globally to suppress this message
openidc_1         | AH00558: httpd: Could not reliably determine the server's fully qualified domain name, using 172.19.0.5. Set the 'ServerName' directive globally to suppress this message
openidc_1         | [Fri Aug 18 19:16:05.124778 2017] [auth_openidc:debug] [pid 1:tid 140127909681024] src/cache/shm.c(130): oidc_cache_shm_post_config: initialized shared memory with a cache size (# entries) of: 500, and a max (single) entry size of: 16913
openidc_1         | [Fri Aug 18 19:16:05.124847 2017] [auth_openidc:debug] [pid 1:tid 140127909681024] src/config.c(1865): oidc_config_check_vhost_config: enter
openidc_1         | [Fri Aug 18 19:16:05.124857 2017] [auth_openidc:warn] [pid 1:tid 140127909681024] oidc_check_config_openid_openidc: the URL scheme (http) of the configured OIDCProviderMetadataURL SHOULD be "https" for security reasons!
openidc_1         | [Fri Aug 18 19:16:05.125630 2017] [proxy:debug] [pid 8:tid 140127909681024] proxy_util.c(1779): AH00925: initializing worker http://keycloak:8080/auth/ shared
openidc_1         | [Fri Aug 18 19:16:05.125641 2017] [proxy:debug] [pid 8:tid 140127909681024] proxy_util.c(1821): AH00927: initializing worker http://keycloak:8080/auth/ local
openidc_1         | [Fri Aug 18 19:16:05.125650 2017] [proxy:debug] [pid 8:tid 140127909681024] proxy_util.c(1856): AH00930: initialized pool in child 8 for (keycloak) min=0 max=25 smax=25
openidc_1         | [Fri Aug 18 19:16:05.125695 2017] [mpm_event:notice] [pid 1:tid 140127909681024] AH00489: Apache/2.4.27 (Unix) configured -- resuming normal operations
openidc_1         | [Fri Aug 18 19:16:05.125721 2017] [core:notice] [pid 1:tid 140127909681024] AH00094: Command line: 'httpd -D FOREGROUND'
openidc_1         | [Fri Aug 18 19:16:05.125958 2017] [proxy:debug] [pid 9:tid 140127909681024] proxy_util.c(1779): AH00925: initializing worker http://keycloak:8080/auth/ shared
openidc_1         | [Fri Aug 18 19:16:05.125966 2017] [proxy:debug] [pid 9:tid 140127909681024] proxy_util.c(1821): AH00927: initializing worker http://keycloak:8080/auth/ local
openidc_1         | [Fri Aug 18 19:16:05.125974 2017] [proxy:debug] [pid 9:tid 140127909681024] proxy_util.c(1856): AH00930: initialized pool in child 9 for (keycloak) min=0 max=25 smax=25
openidc_1         | [Fri Aug 18 19:16:05.126897 2017] [proxy:debug] [pid 10:tid 140127909681024] proxy_util.c(1779): AH00925: initializing worker http://keycloak:8080/auth/ shared
openidc_1         | [Fri Aug 18 19:16:05.126916 2017] [proxy:debug] [pid 10:tid 140127909681024] proxy_util.c(1821): AH00927: initializing worker http://keycloak:8080/auth/ local
openidc_1         | [Fri Aug 18 19:16:05.126930 2017] [proxy:debug] [pid 10:tid 140127909681024] proxy_util.c(1856): AH00930: initialized pool in child 10 for (keycloak) min=0 max=25 smax=25

openidc_1         | [Fri Aug 18 19:16:18.562417 2017] [authz_core:debug] [pid 8:tid 140127722256128] mod_authz_core.c(809): [client 172.19.0.1:55522] AH01626: authorization result of Require all granted: granted
openidc_1         | [Fri Aug 18 19:16:18.562452 2017] [authz_core:debug] [pid 8:tid 140127722256128] mod_authz_core.c(809): [client 172.19.0.1:55522] AH01626: authorization result of <RequireAny>: granted
openidc_1         | 172.19.0.1 - - [18/Aug/2017:19:16:18 +0000] "GET / HTTP/1.1" 304 - "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | [Fri Aug 18 19:16:18.562545 2017] [auth_openidc:debug] [pid 8:tid 140127722256128] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: X-Forwarded-Proto=http
openidc_1         | [Fri Aug 18 19:16:18.562561 2017] [auth_openidc:debug] [pid 8:tid 140127722256128] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc
openidc_1         | [Fri Aug 18 19:16:18.562569 2017] [auth_openidc:debug] [pid 8:tid 140127722256128] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc
openidc_1         | [Fri Aug 18 19:16:18.562575 2017] [auth_openidc:debug] [pid 8:tid 140127722256128] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: X-Forwarded-Proto=http
openidc_1         | [Fri Aug 18 19:16:18.562581 2017] [auth_openidc:debug] [pid 8:tid 140127722256128] src/util.c(509): [client 172.19.0.1:55522] oidc_get_redirect_uri: determined absolute redirect uri: http://openidc/protected/redirect_uri
openidc_1         | [Fri Aug 18 19:16:18.562588 2017] [auth_openidc:debug] [pid 8:tid 140127722256128] src/util.c(1132): [client 172.19.0.1:55522] oidc_util_request_matches_url: comparing "/"=="/protected/redirect_uri"
openidc_1         | [Fri Aug 18 19:16:18.575178 2017] [authz_core:debug] [pid 8:tid 140127713863424] mod_authz_core.c(809): [client 172.19.0.1:55522] AH01626: authorization result of Require all granted: granted, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:18.575197 2017] [authz_core:debug] [pid 8:tid 140127713863424] mod_authz_core.c(809): [client 172.19.0.1:55522] AH01626: authorization result of <RequireAny>: granted, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:18.575225 2017] [auth_openidc:debug] [pid 8:tid 140127713863424] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: X-Forwarded-Proto=http, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:18.575234 2017] [auth_openidc:debug] [pid 8:tid 140127713863424] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:18.575243 2017] [auth_openidc:debug] [pid 8:tid 140127713863424] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:18.575250 2017] [auth_openidc:debug] [pid 8:tid 140127713863424] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: X-Forwarded-Proto=http, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:18.575259 2017] [auth_openidc:debug] [pid 8:tid 140127713863424] src/util.c(509): [client 172.19.0.1:55522] oidc_get_redirect_uri: determined absolute redirect uri: http://openidc/protected/redirect_uri, referer: http://openidc/
openidc_1         | 172.19.0.1 - - [18/Aug/2017:19:16:18 +0000] "GET /style.css HTTP/1.1" 304 - "http://openidc/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | [Fri Aug 18 19:16:18.575268 2017] [auth_openidc:debug] [pid 8:tid 140127713863424] src/util.c(1132): [client 172.19.0.1:55522] oidc_util_request_matches_url: comparing "/style.css"=="/protected/redirect_uri", referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:18.618128 2017] [authz_core:debug] [pid 8:tid 140127705470720] mod_authz_core.c(809): [client 172.19.0.1:55522] AH01626: authorization result of Require all granted: granted, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:18.618143 2017] [authz_core:debug] [pid 8:tid 140127705470720] mod_authz_core.c(809): [client 172.19.0.1:55522] AH01626: authorization result of <RequireAny>: granted, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:18.618168 2017] [auth_openidc:debug] [pid 8:tid 140127705470720] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: X-Forwarded-Proto=http, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:18.618176 2017] [auth_openidc:debug] [pid 8:tid 140127705470720] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:18.618179 2017] [auth_openidc:debug] [pid 8:tid 140127705470720] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:18.618183 2017] [auth_openidc:debug] [pid 8:tid 140127705470720] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: X-Forwarded-Proto=http, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:18.618187 2017] [auth_openidc:debug] [pid 8:tid 140127705470720] src/util.c(509): [client 172.19.0.1:55522] oidc_get_redirect_uri: determined absolute redirect uri: http://openidc/protected/redirect_uri, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:18.618192 2017] [auth_openidc:debug] [pid 8:tid 140127705470720] src/util.c(1132): [client 172.19.0.1:55522] oidc_util_request_matches_url: comparing "/favicon.ico"=="/protected/redirect_uri", referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:18.618200 2017] [core:info] [pid 8:tid 140127705470720] [client 172.19.0.1:55522] AH00128: File does not exist: /usr/local/apache2/htdocs/favicon.ico, referer: http://openidc/
openidc_1         | 172.19.0.1 - - [18/Aug/2017:19:16:18 +0000] "GET /favicon.ico HTTP/1.1" 404 209 "http://openidc/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | [Fri Aug 18 19:16:21.170663 2017] [authz_core:debug] [pid 8:tid 140127697078016] mod_authz_core.c(809): [client 172.19.0.1:55522] AH01626: authorization result of Require valid-user : denied (no authenticated user yet), referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.170691 2017] [authz_core:debug] [pid 8:tid 140127697078016] mod_authz_core.c(809): [client 172.19.0.1:55522] AH01626: authorization result of <RequireAny>: denied (no authenticated user yet), referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.170705 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/mod_auth_openidc.c(3302): [client 172.19.0.1:55522] oidc_check_user_id: incoming request: "/protected?(null)", ap_is_initial_req(r)=1, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.170723 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.170730 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.170737 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(509): [client 172.19.0.1:55522] oidc_get_redirect_uri: determined absolute redirect uri: http://openidc/protected/redirect_uri, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.170779 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(980): [client 172.19.0.1:55522] oidc_util_get_cookie: returning "mod_auth_openidc_session" = <null>, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.170856 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.170865 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.170871 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(509): [client 172.19.0.1:55522] oidc_get_redirect_uri: determined absolute redirect uri: http://openidc/protected/redirect_uri, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.170878 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(1132): [client 172.19.0.1:55522] oidc_util_request_matches_url: comparing "/protected"=="/protected/redirect_uri", referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.170889 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.170895 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.170903 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(490): [client 172.19.0.1:55522] oidc_get_current_url: current URL 'http://openidc/protected', referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.170907 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/mod_auth_openidc.c(2124): [client 172.19.0.1:55522] oidc_authenticate_user: enter, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.170912 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/cache/common.c(521): [client 172.19.0.1:55522] oidc_cache_get: enter: http://openidc/auth/realms/Testrealm/.well-known/openid-configuration (section=p, decrypt=0, type=shm), referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.171158 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/cache/common.c(557): [client 172.19.0.1:55522] oidc_cache_get: cache miss from shm cache backend for key http://openidc/auth/realms/Testrealm/.well-known/openid-configuration, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.171164 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(599): [client 172.19.0.1:55522] oidc_util_http_query_encoded_url: url=http://openidc/auth/realms/Testrealm/.well-known/openid-configuration, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.171170 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(640): [client 172.19.0.1:55522] oidc_util_http_call: url=http://openidc/auth/realms/Testrealm/.well-known/openid-configuration, data=(null), content_type=(null), basic_auth=(null), bearer_token=(null), ssl_validate_server=1, timeout=5, outgoing_proxy=(null), pass_cookies=0, ssl_cert=(null), ssl_key=(null), referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.175779 2017] [authz_core:debug] [pid 9:tid 140127722256128] mod_authz_core.c(835): [client 172.19.0.5:58662] AH01628: authorization result: granted (no directives)
openidc_1         | [Fri Aug 18 19:16:21.175834 2017] [proxy:debug] [pid 9:tid 140127722256128] mod_proxy.c(1227): [client 172.19.0.5:58662] AH01143: Running scheme http handler (attempt 0)
openidc_1         | [Fri Aug 18 19:16:21.175857 2017] [proxy:debug] [pid 9:tid 140127722256128] proxy_util.c(2156): AH00942: HTTP: has acquired connection for (keycloak)
openidc_1         | [Fri Aug 18 19:16:21.175869 2017] [proxy:debug] [pid 9:tid 140127722256128] proxy_util.c(2209): [client 172.19.0.5:58662] AH00944: connecting http://keycloak:8080/auth/realms/Testrealm/.well-known/openid-configuration to keycloak:8080
openidc_1         | [Fri Aug 18 19:16:21.176502 2017] [proxy:debug] [pid 9:tid 140127722256128] proxy_util.c(2418): [client 172.19.0.5:58662] AH00947: connected /auth/realms/Testrealm/.well-known/openid-configuration to keycloak:8080
openidc_1         | [Fri Aug 18 19:16:21.176726 2017] [proxy:debug] [pid 9:tid 140127722256128] proxy_util.c(2887): AH02824: HTTP: connection established with 172.19.0.2:8080 (keycloak)
openidc_1         | [Fri Aug 18 19:16:21.176753 2017] [proxy:debug] [pid 9:tid 140127722256128] proxy_util.c(3054): AH00962: HTTP: connection complete to 172.19.0.2:8080 (keycloak)
openidc_1         | [Fri Aug 18 19:16:21.179621 2017] [proxy:debug] [pid 9:tid 140127722256128] proxy_util.c(2171): AH00943: http: has released connection for (keycloak)
openidc_1         | 172.19.0.5 - - [18/Aug/2017:19:16:21 +0000] "GET /auth/realms/Testrealm/.well-known/openid-configuration HTTP/1.1" 200 1785 "-" "mod_auth_openidc"
openidc_1         | [Fri Aug 18 19:16:21.179850 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(777): [client 172.19.0.1:55522] oidc_util_http_call: HTTP response code=200, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.179874 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(782): [client 172.19.0.1:55522] oidc_util_http_call: response={"issuer":"http://openidc/auth/realms/Testrealm","authorization_endpoint":"http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth","token_endpoint":"http://openidc/auth/realms/Testrealm/protocol/openid-connect/token","token_introspection_endpoint":"http://openidc/auth/realms/Testrealm/protocol/openid-connect/token/introspect","userinfo_endpoint":"http://openidc/auth/realms/Testrealm/protocol/openid-connect/userinfo","end_session_endpoint":"http://openidc/auth/realms/Testrealm/protocol/openid-connect/logout","jwks_uri":"http://openidc/auth/realms/Testrealm/protocol/openid-connect/certs","check_session_iframe":"http://openidc/auth/realms/Testrealm/protocol/openid-connect/login-status-iframe.html","grant_types_supported":["authorization_code","implicit","refresh_token","password","client_credentials"],"response_types_supported":["code","none","id_token","token","id_token token","code id_token","code token","code id_token token"],"subject_types_supported":["public","pairwise"],"id_token_signing_alg_values_supported":["RS256"],"userinfo_signing_alg_values_supported":["RS256"],"request_object_signing_alg_values_supported":["none","RS256"],"response_modes_supported":["query","fragment","form_post"],"registration_endpoint":"http://openidc/auth/realms/Testrealm/clients-registrations/openid-connect","token_endpoint_auth_methods_supported":["private_key_jwt","client_secret_basic","client_secret_post"],"token_endpoint_auth_signing_alg_values_supported":["RS256"],"claims_supported":["sub","iss","auth_time","name","given_name","family_name","preferred_username","email"],"claim_types_supported":["normal"],"claims_parameter_supported":false,"scopes_supported":["openid","offline_access"],"request_parameter_supported":true,"request_uri_parameter_supported":true}, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180111 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/cache/common.c(580): [client 172.19.0.1:55522] oidc_cache_set: enter: http://openidc/auth/realms/Testrealm/.well-known/openid-configuration (section=p, len=1785, encrypt=0, ttl(s)=86400, type=shm), referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180144 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/cache/common.c(607): [client 172.19.0.1:55522] oidc_cache_set: successfully stored 1785 bytes in shm cache backend for key http://openidc/auth/realms/Testrealm/.well-known/openid-configuration, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180226 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180236 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180241 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(509): [client 172.19.0.1:55522] oidc_get_redirect_uri: determined absolute redirect uri: http://openidc/protected/redirect_uri, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180247 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(1132): [client 172.19.0.1:55522] oidc_util_request_matches_url: comparing "/protected"=="/protected/redirect_uri", referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180261 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/mod_auth_openidc.c(232): [client 172.19.0.1:55522] oidc_get_browser_state_hash: enter, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180272 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: User-Agent=Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180334 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(1947): [client 172.19.0.1:55522] oidc_util_create_symmetric_key: key_len=32, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180527 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(2158): [client 172.19.0.1:55522] oidc_util_hdr_err_out_add: Set-Cookie: mod_auth_openidc_state_niVJ3MJOMqS-V52XURJPUcJeKUU=eyJhbGciOiAiZGlyIiwgImVuYyI6ICJBMjU2R0NNIn0..AGH3FdZ9QDccGrK6.BPZYO6GICPfwIUokACknswDiuYSqF4q-MPj0MY6r9JiW96lMhGuYtAC9LMqR6nP6jnZCmdXIHOnOVa_TYR2NaHtAZzGlvNJPp3jneiLIzEgo8fEnKlcgc-FzVorv8pAQhkpCPfachVXVawQlUz5FLkGXlQDD07IiuntSaHbRp95SpQug-MByZc6MMQV_2P-v4py8T1mSIDSHdb-7h3V6m31-o6XXRODxH96I4i7Hz8dk3XkiD6TpKif4ITeug7nd3nqfYE_Cet8zglU4nAAUFYifiLv9NEUSWBHy9aLOKvxunQJk5Ek47wFE3-qp7hR0hMaJh-96cLLb81YU3gL2smHGPlp7K6SeJ46n9SJWhFooKsyGn1Y8YGEpj2MCNA.6p4PXW8MNr0sdzt8bllf3w; Path=/; HttpOnly, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180543 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180548 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180555 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(509): [client 172.19.0.1:55522] oidc_get_redirect_uri: determined absolute redirect uri: http://openidc/protected/redirect_uri, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180564 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180572 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(2104): [client 172.19.0.1:55522] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180580 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(509): [client 172.19.0.1:55522] oidc_get_redirect_uri: determined absolute redirect uri: http://openidc/protected/redirect_uri, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180600 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/proto.c(523): [client 172.19.0.1:55522] oidc_proto_authorization_request: enter, issuer=http://openidc/auth/realms/Testrealm, redirect_uri=http://openidc/protected/redirect_uri, state=niVJ3MJOMqS-V52XURJPUcJeKUU, proto_state={"ou":"http://openidc/protected","n":"0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw","om":"get","t":1503083781,"i":"http://openidc/auth/realms/Testrealm","rt":"code"}, code_challenge=(null), auth_request_params=(null), path_scope=(null), referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180615 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(570): [client 172.19.0.1:55522] oidc_util_http_add_form_url_encoded_param: processing: response_type=code, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180644 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(570): [client 172.19.0.1:55522] oidc_util_http_add_form_url_encoded_param: processing: scope=openid, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180664 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(570): [client 172.19.0.1:55522] oidc_util_http_add_form_url_encoded_param: processing: client_id=openid1, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180684 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(570): [client 172.19.0.1:55522] oidc_util_http_add_form_url_encoded_param: processing: state=niVJ3MJOMqS-V52XURJPUcJeKUU, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180704 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(570): [client 172.19.0.1:55522] oidc_util_http_add_form_url_encoded_param: processing: redirect_uri=http://openidc/protected/redirect_uri, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180731 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(570): [client 172.19.0.1:55522] oidc_util_http_add_form_url_encoded_param: processing: nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180754 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(599): [client 172.19.0.1:55522] oidc_util_http_query_encoded_url: url=http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180764 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/util.c(2136): [client 172.19.0.1:55522] oidc_util_hdr_table_set: Location: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.180776 2017] [auth_openidc:debug] [pid 8:tid 140127697078016] src/proto.c(641): [client 172.19.0.1:55522] oidc_proto_authorization_request: return: 302, referer: http://openidc/
openidc_1         | 172.19.0.1 - - [18/Aug/2017:19:16:21 +0000] "GET /protected HTTP/1.1" 302 464 "http://openidc/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | [Fri Aug 18 19:16:21.185650 2017] [authz_core:debug] [pid 8:tid 140127688685312] mod_authz_core.c(835): [client 172.19.0.1:55522] AH01628: authorization result: granted (no directives), referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.185691 2017] [proxy:debug] [pid 8:tid 140127688685312] mod_proxy.c(1227): [client 172.19.0.1:55522] AH01143: Running scheme http handler (attempt 0), referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.185711 2017] [proxy:debug] [pid 8:tid 140127688685312] proxy_util.c(2156): AH00942: HTTP: has acquired connection for (keycloak)
openidc_1         | [Fri Aug 18 19:16:21.185719 2017] [proxy:debug] [pid 8:tid 140127688685312] proxy_util.c(2209): [client 172.19.0.1:55522] AH00944: connecting http://keycloak:8080/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw to keycloak:8080, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.186118 2017] [proxy:debug] [pid 8:tid 140127688685312] proxy_util.c(2418): [client 172.19.0.1:55522] AH00947: connected /auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw to keycloak:8080, referer: http://openidc/
openidc_1         | [Fri Aug 18 19:16:21.186309 2017] [proxy:debug] [pid 8:tid 140127688685312] proxy_util.c(2887): AH02824: HTTP: connection established with 172.19.0.2:8080 (keycloak)
openidc_1         | [Fri Aug 18 19:16:21.186338 2017] [proxy:debug] [pid 8:tid 140127688685312] proxy_util.c(3054): AH00962: HTTP: connection complete to 172.19.0.2:8080 (keycloak)
openidc_1         | [Fri Aug 18 19:16:21.191932 2017] [proxy:debug] [pid 8:tid 140127688685312] proxy_util.c(2171): AH00943: http: has released connection for (keycloak)
openidc_1         | 172.19.0.1 - - [18/Aug/2017:19:16:21 +0000] "GET /auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw HTTP/1.1" 200 3597 "http://openidc/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | [Fri Aug 18 19:16:26.652849 2017] [authz_core:debug] [pid 10:tid 140127722256128] mod_authz_core.c(835): [client 172.19.0.1:55528] AH01628: authorization result: granted (no directives), referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.652911 2017] [proxy:debug] [pid 10:tid 140127722256128] mod_proxy.c(1227): [client 172.19.0.1:55528] AH01143: Running scheme http handler (attempt 0), referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.652940 2017] [proxy:debug] [pid 10:tid 140127722256128] proxy_util.c(2156): AH00942: HTTP: has acquired connection for (keycloak)
openidc_1         | [Fri Aug 18 19:16:26.652949 2017] [proxy:debug] [pid 10:tid 140127722256128] proxy_util.c(2209): [client 172.19.0.1:55528] AH00944: connecting http://keycloak:8080/auth/realms/Testrealm/login-actions/authenticate?code=xvHh-NcQB17zHRW7coNRcsQr-1j6p3dODDAXzQ-iHkg.9601aba6-31d7-4384-9238-a6ffe50f1c35&execution=a4a8936f-f13a-457b-89dc-37143b66823a to keycloak:8080, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.653683 2017] [proxy:debug] [pid 10:tid 140127722256128] proxy_util.c(2418): [client 172.19.0.1:55528] AH00947: connected /auth/realms/Testrealm/login-actions/authenticate?code=xvHh-NcQB17zHRW7coNRcsQr-1j6p3dODDAXzQ-iHkg.9601aba6-31d7-4384-9238-a6ffe50f1c35&execution=a4a8936f-f13a-457b-89dc-37143b66823a to keycloak:8080, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.653854 2017] [proxy:debug] [pid 10:tid 140127722256128] proxy_util.c(2887): AH02824: HTTP: connection established with 172.19.0.2:8080 (keycloak)
openidc_1         | [Fri Aug 18 19:16:26.653889 2017] [proxy:debug] [pid 10:tid 140127722256128] proxy_util.c(3054): AH00962: HTTP: connection complete to 172.19.0.2:8080 (keycloak)
openidc_1         | [Fri Aug 18 19:16:26.812589 2017] [proxy:debug] [pid 10:tid 140127722256128] proxy_util.c(2171): AH00943: http: has released connection for (keycloak)
openidc_1         | 172.19.0.1 - - [18/Aug/2017:19:16:26 +0000] "POST /auth/realms/Testrealm/login-actions/authenticate?code=xvHh-NcQB17zHRW7coNRcsQr-1j6p3dODDAXzQ-iHkg.9601aba6-31d7-4384-9238-a6ffe50f1c35&execution=a4a8936f-f13a-457b-89dc-37143b66823a HTTP/1.1" 302 - "http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | [Fri Aug 18 19:16:26.817461 2017] [authz_core:debug] [pid 10:tid 140127713863424] mod_authz_core.c(809): [client 172.19.0.1:55528] AH01626: authorization result of Require valid-user : denied (no authenticated user yet), referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817484 2017] [authz_core:debug] [pid 10:tid 140127713863424] mod_authz_core.c(809): [client 172.19.0.1:55528] AH01626: authorization result of <RequireAny>: denied (no authenticated user yet), referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817496 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/mod_auth_openidc.c(3302): [client 172.19.0.1:55528] oidc_check_user_id: incoming request: "/protected/redirect_uri?state=niVJ3MJOMqS-V52XURJPUcJeKUU&code=cKIMgQOCzp4I-1xwLZVpe__HFyAV_i28miCx0SrtDBc.9601aba6-31d7-4384-9238-a6ffe50f1c35", ap_is_initial_req(r)=1, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817512 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(2104): [client 172.19.0.1:55528] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817519 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(2104): [client 172.19.0.1:55528] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817525 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(509): [client 172.19.0.1:55528] oidc_get_redirect_uri: determined absolute redirect uri: http://openidc/protected/redirect_uri, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817534 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(2104): [client 172.19.0.1:55528] oidc_util_hdr_in_get: Cookie=mod_auth_openidc_state_niVJ3MJOMqS-V52XURJPUcJeKUU=eyJhbGciOiAiZGlyIiwgImVuYyI6ICJBMjU2R0NNIn0..AGH3FdZ9QDccGrK6.BPZYO6GICPfwIUokACknswDiuYSqF4q-MPj0MY6r9JiW96lMhGuYtAC9LMqR6nP6jnZCmdXIHOnOVa_TYR2NaHtAZzGlvNJPp3jneiLIzEgo8fEnKlcgc-FzVorv8pAQhkpCPfachVXVawQlUz5FLkGXlQDD07IiuntSaHbRp95SpQug-MByZc6MMQV_2P-v4py8T1mSIDSHdb-7h3V6m31-o6XXRODxH96I4i7Hz8dk3XkiD6TpKif4ITeug7nd3nqfYE_Cet8zglU4nAAUFYifiLv9NEUSWBHy9aLOKvxunQJk5Ek47wFE3-qp7hR0hMaJh-96cLLb81YU3gL2smHGPlp7K6SeJ46n9SJWhFooKsyGn1Y8YGEpj2MCNA.6p4PXW8MNr0sdzt8bllf3w, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817552 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(980): [client 172.19.0.1:55528] oidc_util_get_cookie: returning "mod_auth_openidc_session" = <null>, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817627 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(2104): [client 172.19.0.1:55528] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817634 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(2104): [client 172.19.0.1:55528] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817639 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(509): [client 172.19.0.1:55528] oidc_get_redirect_uri: determined absolute redirect uri: http://openidc/protected/redirect_uri, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817646 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(1132): [client 172.19.0.1:55528] oidc_util_request_matches_url: comparing "/protected/redirect_uri"=="/protected/redirect_uri", referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817655 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/mod_auth_openidc.c(1950): [client 172.19.0.1:55528] oidc_handle_redirect_authorization_response: enter, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817703 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(1424): [client 172.19.0.1:55528] oidc_util_read_form_encoded_params: read: state=niVJ3MJOMqS-V52XURJPUcJeKUU, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817719 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(1424): [client 172.19.0.1:55528] oidc_util_read_form_encoded_params: read: code=cKIMgQOCzp4I-1xwLZVpe__HFyAV_i28miCx0SrtDBc.9601aba6-31d7-4384-9238-a6ffe50f1c35, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817725 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(1429): [client 172.19.0.1:55528] oidc_util_read_form_encoded_params: parsed: 119 bytes into 2 elements, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817732 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/mod_auth_openidc.c(1779): [client 172.19.0.1:55528] oidc_handle_authorization_response: enter, response_mode=query, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | 172.19.0.1 - - [18/Aug/2017:19:16:26 +0000] "GET /protected/redirect_uri?state=niVJ3MJOMqS-V52XURJPUcJeKUU&code=cKIMgQOCzp4I-1xwLZVpe__HFyAV_i28miCx0SrtDBc.9601aba6-31d7-4384-9238-a6ffe50f1c35 HTTP/1.1" 200 335 "http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | [Fri Aug 18 19:16:26.817737 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/mod_auth_openidc.c(1436): [client 172.19.0.1:55528] oidc_authorization_response_match_state: enter (state=niVJ3MJOMqS-V52XURJPUcJeKUU), referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817745 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/mod_auth_openidc.c(721): [client 172.19.0.1:55528] oidc_restore_proto_state: enter, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817750 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(2104): [client 172.19.0.1:55528] oidc_util_hdr_in_get: Cookie=mod_auth_openidc_state_niVJ3MJOMqS-V52XURJPUcJeKUU=eyJhbGciOiAiZGlyIiwgImVuYyI6ICJBMjU2R0NNIn0..AGH3FdZ9QDccGrK6.BPZYO6GICPfwIUokACknswDiuYSqF4q-MPj0MY6r9JiW96lMhGuYtAC9LMqR6nP6jnZCmdXIHOnOVa_TYR2NaHtAZzGlvNJPp3jneiLIzEgo8fEnKlcgc-FzVorv8pAQhkpCPfachVXVawQlUz5FLkGXlQDD07IiuntSaHbRp95SpQug-MByZc6MMQV_2P-v4py8T1mSIDSHdb-7h3V6m31-o6XXRODxH96I4i7Hz8dk3XkiD6TpKif4ITeug7nd3nqfYE_Cet8zglU4nAAUFYifiLv9NEUSWBHy9aLOKvxunQJk5Ek47wFE3-qp7hR0hMaJh-96cLLb81YU3gL2smHGPlp7K6SeJ46n9SJWhFooKsyGn1Y8YGEpj2MCNA.6p4PXW8MNr0sdzt8bllf3w, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817759 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(2104): [client 172.19.0.1:55528] oidc_util_hdr_in_get: Cookie=mod_auth_openidc_state_niVJ3MJOMqS-V52XURJPUcJeKUU=eyJhbGciOiAiZGlyIiwgImVuYyI6ICJBMjU2R0NNIn0..AGH3FdZ9QDccGrK6.BPZYO6GICPfwIUokACknswDiuYSqF4q-MPj0MY6r9JiW96lMhGuYtAC9LMqR6nP6jnZCmdXIHOnOVa_TYR2NaHtAZzGlvNJPp3jneiLIzEgo8fEnKlcgc-FzVorv8pAQhkpCPfachVXVawQlUz5FLkGXlQDD07IiuntSaHbRp95SpQug-MByZc6MMQV_2P-v4py8T1mSIDSHdb-7h3V6m31-o6XXRODxH96I4i7Hz8dk3XkiD6TpKif4ITeug7nd3nqfYE_Cet8zglU4nAAUFYifiLv9NEUSWBHy9aLOKvxunQJk5Ek47wFE3-qp7hR0hMaJh-96cLLb81YU3gL2smHGPlp7K6SeJ46n9SJWhFooKsyGn1Y8YGEpj2MCNA.6p4PXW8MNr0sdzt8bllf3w, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817767 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(980): [client 172.19.0.1:55528] oidc_util_get_cookie: returning "mod_auth_openidc_state_niVJ3MJOMqS-V52XURJPUcJeKUU" = "eyJhbGciOiAiZGlyIiwgImVuYyI6ICJBMjU2R0NNIn0..AGH3FdZ9QDccGrK6.BPZYO6GICPfwIUokACknswDiuYSqF4q-MPj0MY6r9JiW96lMhGuYtAC9LMqR6nP6jnZCmdXIHOnOVa_TYR2NaHtAZzGlvNJPp3jneiLIzEgo8fEnKlcgc-FzVorv8pAQhkpCPfachVXVawQlUz5FLkGXlQDD07IiuntSaHbRp95SpQug-MByZc6MMQV_2P-v4py8T1mSIDSHdb-7h3V6m31-o6XXRODxH96I4i7Hz8dk3XkiD6TpKif4ITeug7nd3nqfYE_Cet8zglU4nAAUFYifiLv9NEUSWBHy9aLOKvxunQJk5Ek47wFE3-qp7hR0hMaJh-96cLLb81YU3gL2smHGPlp7K6SeJ46n9SJWhFooKsyGn1Y8YGEpj2MCNA.6p4PXW8MNr0sdzt8bllf3w", referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817777 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(2158): [client 172.19.0.1:55528] oidc_util_hdr_err_out_add: Set-Cookie: mod_auth_openidc_state_niVJ3MJOMqS-V52XURJPUcJeKUU=; Path=/; Expires=Thu, 01 Jan 1970 00:00:00 GMT; HttpOnly, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817785 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(204): [client 172.19.0.1:55528] oidc_util_jwt_verify: enter: JWT header={"alg": "dir", "enc": "A256GCM"}, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817824 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(1947): [client 172.19.0.1:55528] oidc_util_create_symmetric_key: key_len=32, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817894 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/mod_auth_openidc.c(232): [client 172.19.0.1:55528] oidc_get_browser_state_hash: enter, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817899 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(2104): [client 172.19.0.1:55528] oidc_util_hdr_in_get: User-Agent=Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817926 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/mod_auth_openidc.c(775): [client 172.19.0.1:55528] oidc_restore_proto_state: restored state: {"ou":"http://openidc/protected","i":"http://openidc/auth/realms/Testrealm","om":"get","n":"0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw","rt":"code","t":1503083781,"s":"niVJ3MJOMqS-V52XURJPUcJeKUU"}, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817933 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/cache/common.c(521): [client 172.19.0.1:55528] oidc_cache_get: enter: http://openidc/auth/realms/Testrealm/.well-known/openid-configuration (section=p, decrypt=0, type=shm), referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.817947 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/cache/common.c(555): [client 172.19.0.1:55528] oidc_cache_get: cache hit: return 1785 bytes from shm cache backend for key http://openidc/auth/realms/Testrealm/.well-known/openid-configuration, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.818017 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/proto.c(2881): [client 172.19.0.1:55528] oidc_proto_handle_authorization_response_code: enter, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.818021 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/proto.c(2688): [client 172.19.0.1:55528] oidc_proto_validate_issuer_client_id: iss and/or client_id matched OK: (null), http://openidc/auth/realms/Testrealm, (null), openid1, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.818026 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/proto.c(1919): [client 172.19.0.1:55528] oidc_proto_resolve_code: enter, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.818030 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(2104): [client 172.19.0.1:55528] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.818033 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(2104): [client 172.19.0.1:55528] oidc_util_hdr_in_get: Host=openidc, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.818036 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/util.c(509): [client 172.19.0.1:55528] oidc_get_redirect_uri: determined absolute redirect uri: http://openidc/protected/redirect_uri, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.818039 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/proto.c(1806): [client 172.19.0.1:55528] oidc_proto_token_endpoint_auth: token_endpoint_auth=client_secret_basic, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.818043 2017] [auth_openidc:debug] [pid 10:tid 140127713863424] src/proto.c(1654): [client 172.19.0.1:55528] oidc_proto_endpoint_auth_basic: enter, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.818046 2017] [auth_openidc:error] [pid 10:tid 140127713863424] [client 172.19.0.1:55528] oidc_proto_endpoint_auth_basic: no client secret is configured, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:26.818049 2017] [auth_openidc:error] [pid 10:tid 140127713863424] [client 172.19.0.1:55528] oidc_proto_resolve_code_and_validate_response: failed to resolve the code, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=niVJ3MJOMqS-V52XURJPUcJeKUU&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=0AbGDg8nP2eHO2RMen0CQPzPp8gyruQwGAu60eQTiRw
openidc_1         | [Fri Aug 18 19:16:50.171298 2017] [proxy:debug] [pid 93:tid 140127909681024] proxy_util.c(1779): AH00925: initializing worker http://keycloak:8080/auth/ shared
openidc_1         | [Fri Aug 18 19:16:50.171338 2017] [proxy:debug] [pid 93:tid 140127909681024] proxy_util.c(1821): AH00927: initializing worker http://keycloak:8080/auth/ local
openidc_1         | [Fri Aug 18 19:16:50.171363 2017] [proxy:debug] [pid 93:tid 140127909681024] proxy_util.c(1856): AH00930: initialized pool in child 93 for (keycloak) min=0 max=25 smax=25
openidc_1         | 172.19.0.1 - - [18/Aug/2017:19:17:09 +0000] "-" 408 - "-" "-"
openidc_1         | [Fri Aug 18 19:17:09.541202 2017] [reqtimeout:info] [pid 8:tid 140127680292608] [client 172.19.0.1:55532] AH01382: Request header read timeout
openidc_1         | 172.19.0.1 - - [18/Aug/2017:19:17:09 +0000] "-" 408 - "-" "-"
openidc_1         | 172.19.0.1 - - [18/Aug/2017:19:17:09 +0000] "-" 408 - "-" "-"
openidc_1         | [Fri Aug 18 19:17:09.541451 2017] [reqtimeout:info] [pid 8:tid 140127602996992] [client 172.19.0.1:55534] AH01382: Request header read timeout
openidc_1         | [Fri Aug 18 19:17:09.541516 2017] [reqtimeout:info] [pid 10:tid 140127705470720] [client 172.19.0.1:55530] AH01382: Request header read timeout
openidc_1         | [Fri Aug 18 19:17:09.543482 2017] [reqtimeout:info] [pid 9:tid 140127705470720] [client 172.19.0.1:55526] AH01382: Request header read timeout
openidc_1         | 172.19.0.1 - - [18/Aug/2017:19:17:09 +0000] "-" 408 - "-" "-"

Endpoint:

{
  "request_uri_parameter_supported": true,
  "request_parameter_supported": true,
  "scopes_supported": [
    "openid",
    "offline_access"
  ],
  "claims_parameter_supported": false,
  "claim_types_supported": [
    "normal"
  ],
  "claims_supported": [
    "sub",
    "iss",
    "auth_time",
    "name",
    "given_name",
    "family_name",
    "preferred_username",
    "email"
  ],
  "token_endpoint_auth_signing_alg_values_supported": [
    "RS256"
  ],
  "token_endpoint_auth_methods_supported": [
    "private_key_jwt",
    "client_secret_basic",
    "client_secret_post"
  ],
  "check_session_iframe": "http://openidc/auth/realms/Testrealm/protocol/openid-connect/login-status-iframe.html",
  "jwks_uri": "http://openidc/auth/realms/Testrealm/protocol/openid-connect/certs",
  "end_session_endpoint": "http://openidc/auth/realms/Testrealm/protocol/openid-connect/logout",
  "userinfo_endpoint": "http://openidc/auth/realms/Testrealm/protocol/openid-connect/userinfo",
  "token_introspection_endpoint": "http://openidc/auth/realms/Testrealm/protocol/openid-connect/token/introspect",
  "token_endpoint": "http://openidc/auth/realms/Testrealm/protocol/openid-connect/token",
  "authorization_endpoint": "http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth",
  "issuer": "http://openidc/auth/realms/Testrealm",
  "grant_types_supported": [
    "authorization_code",
    "implicit",
    "refresh_token",
    "password",
    "client_credentials"
  ],
  "response_types_supported": [
    "code",
    "none",
    "id_token",
    "token",
    "id_token token",
    "code id_token",
    "code token",
    "code id_token token"
  ],
  "subject_types_supported": [
    "public",
    "pairwise"
  ],
  "id_token_signing_alg_values_supported": [
    "RS256"
  ],
  "userinfo_signing_alg_values_supported": [
    "RS256"
  ],
  "request_object_signing_alg_values_supported": [
    "none",
    "RS256"
  ],
  "response_modes_supported": [
    "query",
    "fragment",
    "form_post"
  ],
  "registration_endpoint": "http://openidc/auth/realms/Testrealm/clients-registrations/openid-connect"
}

Now if I downgrade to 2.3.0, i.e. revert ed44401, auth works again. Endpoint json is identical. Log:

openidc_1         | [Fri Aug 18 19:28:14.808258 2017] [authz_core:debug] [pid 12:tid 140432545609472] mod_authz_core.c(809): [client 172.19.0.1:56252] AH01626: authorization result of Require valid-user
 : denied (no authenticated user yet)
openidc_1         | [Fri Aug 18 19:28:14.808289 2017] [authz_core:debug] [pid 12:tid 140432545609472] mod_authz_core.c(809): [client 172.19.0.1:56252] AH01626: authorization result of <RequireAny>: deni
ed (no authenticated user yet)
openidc_1         | [Fri Aug 18 19:28:14.808303 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/mod_auth_openidc.c(3280): [client 172.19.0.1:56252] oidc_check_user_id: incoming request: "/pr
otected/?(null)", ap_is_initial_req(r)=1
openidc_1         | [Fri Aug 18 19:28:14.808324 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/util.c(485): [client 172.19.0.1:56252] oidc_get_redirect_uri: determined absolute redirect uri
: http://openidc/protected/redirect_uri
openidc_1         | [Fri Aug 18 19:28:14.808347 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/util.c(932): [client 172.19.0.1:56252] oidc_util_get_cookie: returning "mod_auth_openidc_sessi
on" = <null>
openidc_1         | [Fri Aug 18 19:28:14.808410 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/util.c(485): [client 172.19.0.1:56252] oidc_get_redirect_uri: determined absolute redirect uri
: http://openidc/protected/redirect_uri
openidc_1         | [Fri Aug 18 19:28:14.808421 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/util.c(1084): [client 172.19.0.1:56252] oidc_util_request_matches_url: comparing "/protected/"
=="/protected/redirect_uri"
openidc_1         | [Fri Aug 18 19:28:14.808431 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/util.c(466): [client 172.19.0.1:56252] oidc_get_current_url: current URL 'http://openidc/prote
cted/'
openidc_1         | [Fri Aug 18 19:28:14.808437 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/mod_auth_openidc.c(2115): [client 172.19.0.1:56252] oidc_authenticate_user: enter
openidc_1         | [Fri Aug 18 19:28:14.808443 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/cache/common.c(521): [client 172.19.0.1:56252] oidc_cache_get: enter: http://openidc/auth/real
ms/Testrealm/.well-known/openid-configuration (section=p, decrypt=0, type=shm)
openidc_1         | [Fri Aug 18 19:28:14.808694 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/cache/common.c(557): [client 172.19.0.1:56252] oidc_cache_get: cache miss from shm cache backe
nd for key http://openidc/auth/realms/Testrealm/.well-known/openid-configuration
openidc_1         | [Fri Aug 18 19:28:14.808704 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/util.c(573): [client 172.19.0.1:56252] oidc_util_http_call: url=http://openidc/auth/realms/Tes
trealm/.well-known/openid-configuration, data=(null), content_type=(null), basic_auth=(null), bearer_token=(null), ssl_validate_server=1
openidc_1         | [Fri Aug 18 19:28:14.813261 2017] [authz_core:debug] [pid 10:tid 140432646321920] mod_authz_core.c(835): [client 172.19.0.5:59402] AH01628: authorization result: granted (no directiv
es)
openidc_1         | [Fri Aug 18 19:28:14.813303 2017] [proxy:debug] [pid 10:tid 140432646321920] mod_proxy.c(1228): [client 172.19.0.5:59402] AH01143: Running scheme http handler (attempt 0)
openidc_1         | [Fri Aug 18 19:28:14.813319 2017] [proxy:debug] [pid 10:tid 140432646321920] proxy_util.c(2156): AH00942: HTTP: has acquired connection for (keycloak)
openidc_1         | [Fri Aug 18 19:28:14.813329 2017] [proxy:debug] [pid 10:tid 140432646321920] proxy_util.c(2209): [client 172.19.0.5:59402] AH00944: connecting http://keycloak:8080/auth/realms/Testre
alm/.well-known/openid-configuration to keycloak:8080
openidc_1         | [Fri Aug 18 19:28:14.813961 2017] [proxy:debug] [pid 10:tid 140432646321920] proxy_util.c(2418): [client 172.19.0.5:59402] AH00947: connected /auth/realms/Testrealm/.well-known/openi
d-configuration to keycloak:8080
openidc_1         | [Fri Aug 18 19:28:14.814144 2017] [proxy:debug] [pid 10:tid 140432646321920] proxy_util.c(2884): AH02824: HTTP: connection established with 172.19.0.2:8080 (keycloak)
openidc_1         | [Fri Aug 18 19:28:14.814171 2017] [proxy:debug] [pid 10:tid 140432646321920] proxy_util.c(3051): AH00962: HTTP: connection complete to 172.19.0.2:8080 (keycloak)
openidc_1         | [Fri Aug 18 19:28:14.816632 2017] [proxy:debug] [pid 10:tid 140432646321920] proxy_util.c(2171): AH00943: http: has released connection for (keycloak)
openidc_1         | 172.19.0.5 - - [18/Aug/2017:19:28:14 +0000] "GET /auth/realms/Testrealm/.well-known/openid-configuration HTTP/1.1" 200 1785 "-" "mod_auth_openidc"
openidc_1         | [Fri Aug 18 19:28:14.816822 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/util.c(710): [client 172.19.0.1:56252] oidc_util_http_call: HTTP response code=200
openidc_1         | [Fri Aug 18 19:28:14.816850 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/util.c(715): [client 172.19.0.1:56252] oidc_util_http_call: response={"issuer":"http://openidc
/auth/realms/Testrealm","authorization_endpoint":"http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth","token_endpoint":"http://openidc/auth/realms/Testrealm/protocol/openid-connect/token","token
_introspection_endpoint":"http://openidc/auth/realms/Testrealm/protocol/openid-connect/token/introspect","userinfo_endpoint":"http://openidc/auth/realms/Testrealm/protocol/openid-connect/userinfo","end_session
_endpoint":"http://openidc/auth/realms/Testrealm/protocol/openid-connect/logout","jwks_uri":"http://openidc/auth/realms/Testrealm/protocol/openid-connect/certs","check_session_iframe":"http://openidc/auth/real
ms/Testrealm/protocol/openid-connect/login-status-iframe.html","grant_types_supported":["authorization_code","implicit","refresh_token","password","client_credentials"],"response_types_supported":["code","none
","id_token","token","id_token token","code id_token","code token","code id_token token"],"subject_types_supported":["public","pairwise"],"id_token_signing_alg_values_supported":["RS256"],"userinfo_signing_alg
_values_supported":["RS256"],"request_object_signing_alg_values_supported":["none","RS256"],"response_modes_supported":["query","fragment","form_post"],"registration_endpoint":"http://openidc/auth/realms/Testr
ealm/clients-registrations/openid-connect","token_endpoint_auth_methods_supported":["private_key_jwt","client_secret_basic","client_secret_post"],"token_endpoint_auth_signing_alg_values_supported":["RS256"],"c
laims_supported":["sub","iss","auth_time","name","given_name","family_name","preferred_username","email"],"claim_types_supported":["normal"],"claims_parameter_supported":false,"scopes_supported":["openid","off
line_access"],"request_parameter_supported":true,"request_uri_parameter_supported":true}
openidc_1         | [Fri Aug 18 19:28:14.817052 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/cache/common.c(580): [client 172.19.0.1:56252] oidc_cache_set: enter: http://openidc/auth/real
ms/Testrealm/.well-known/openid-configuration (section=p, len=1785, encrypt=0, ttl(s)=86399, type=shm)
openidc_1         | [Fri Aug 18 19:28:14.817096 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/cache/common.c(607): [client 172.19.0.1:56252] oidc_cache_set: successfully stored 1785 bytes 
in shm cache backend for key http://openidc/auth/realms/Testrealm/.well-known/openid-configuration
openidc_1         | [Fri Aug 18 19:28:14.817166 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/util.c(485): [client 172.19.0.1:56252] oidc_get_redirect_uri: determined absolute redirect uri
: http://openidc/protected/redirect_uri
openidc_1         | [Fri Aug 18 19:28:14.817174 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/util.c(1084): [client 172.19.0.1:56252] oidc_util_request_matches_url: comparing "/protected/"
=="/protected/redirect_uri"
openidc_1         | [Fri Aug 18 19:28:14.817185 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/mod_auth_openidc.c(230): [client 172.19.0.1:56252] oidc_get_browser_state_hash: enter
openidc_1         | [Fri Aug 18 19:28:14.817249 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/util.c(1843): [client 172.19.0.1:56252] oidc_util_create_symmetric_key: key_len=32
openidc_1         | [Fri Aug 18 19:28:14.817424 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/util.c(2043): [client 172.19.0.1:56252] oidc_util_hdr_err_out_add: Set-Cookie: mod_auth_openid
c_state_tHASvshIPNCRn4OHSRJrDla-CxQ=eyJhbGciOiAiZGlyIiwgImVuYyI6ICJBMjU2R0NNIn0..JNp4PRz-38gcIZu5.jBajHNzBWn4cfwXnFUNumFeT8NWorl7h_MOoaMTKuemEsPtTeKnq2FPpx3E4tAa9fcje3-z67BBD0tZwcpws_Y_dLPqmWWReRoc7cqgJmJdy7UM
xd5Lt37-WYRoCBBrP8dAaQhA7BGWS2-lg9mf1twLJpF2PxAcZ-9EltI9LSL7_Hl1mAE5gh2OUV6MDpYg8UKQxeAUa3xNKdDvg7aonTo8MjkE6ubmEZ5Xz9I1TtJEtvAF0BVav6JgeClRQm4upaSPFLzSEHoGhA4tOHFmQ8FSwrBDcViOv6eelY0rmX_dxz6GrvWAG2vfDT8birC6E
ZO-hWlI8AiC0jMPtRTFoOaPcFmhHmlO4ts68sJPzr6Ouwrt66qqa3_5YkDMuBi0.calTdW07stPjIKLgZWBGvA; Path=/; HttpOnly
openidc_1         | [Fri Aug 18 19:28:14.817448 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/util.c(485): [client 172.19.0.1:56252] oidc_get_redirect_uri: determined absolute redirect uri
: http://openidc/protected/redirect_uri
openidc_1         | [Fri Aug 18 19:28:14.817458 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/util.c(485): [client 172.19.0.1:56252] oidc_get_redirect_uri: determined absolute redirect uri
: http://openidc/protected/redirect_uri
openidc_1         | [Fri Aug 18 19:28:14.817477 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/proto.c(480): [client 172.19.0.1:56252] oidc_proto_authorization_request: enter, issuer=http:/
/openidc/auth/realms/Testrealm, redirect_uri=http://openidc/protected/redirect_uri, state=tHASvshIPNCRn4OHSRJrDla-CxQ, proto_state={"ou":"http://openidc/protected/","om":"get","i":"http://openidc/auth/realms/T
estrealm","rt":"code","n":"L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew","t":1503084494}, code_challenge=(null), auth_request_params=(null), path_scope=(null)
openidc_1         | [Fri Aug 18 19:28:14.817538 2017] [auth_openidc:debug] [pid 12:tid 140432545609472] src/util.c(2021): [client 172.19.0.1:56252] oidc_util_hdr_table_set: Location: http://openidc/auth
/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW
9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | 172.19.0.1 - - [18/Aug/2017:19:28:14 +0000] "GET /protected/ HTTP/1.1" 302 464 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.7
8 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | [Fri Aug 18 19:28:14.822438 2017] [authz_core:debug] [pid 12:tid 140432528824064] mod_authz_core.c(835): [client 172.19.0.1:56252] AH01628: authorization result: granted (no directiv
es)
openidc_1         | [Fri Aug 18 19:28:14.822487 2017] [proxy:debug] [pid 12:tid 140432528824064] mod_proxy.c(1228): [client 172.19.0.1:56252] AH01143: Running scheme http handler (attempt 0)
openidc_1         | [Fri Aug 18 19:28:14.822515 2017] [proxy:debug] [pid 12:tid 140432528824064] proxy_util.c(2156): AH00942: HTTP: has acquired connection for (keycloak)
openidc_1         | [Fri Aug 18 19:28:14.822526 2017] [proxy:debug] [pid 12:tid 140432528824064] proxy_util.c(2209): [client 172.19.0.1:56252] AH00944: connecting http://keycloak:8080/auth/realms/Testre
alm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMf
SL7PW67VqK_U10Ivew to keycloak:8080
openidc_1         | [Fri Aug 18 19:28:14.822957 2017] [proxy:debug] [pid 12:tid 140432528824064] proxy_util.c(2418): [client 172.19.0.1:56252] AH00947: connected /auth/realms/Testrealm/protocol/openid-c
onnect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew to
 keycloak:8080
openidc_1         | [Fri Aug 18 19:28:14.823113 2017] [proxy:debug] [pid 12:tid 140432528824064] proxy_util.c(2884): AH02824: HTTP: connection established with 172.19.0.2:8080 (keycloak)
openidc_1         | [Fri Aug 18 19:28:14.823139 2017] [proxy:debug] [pid 12:tid 140432528824064] proxy_util.c(3051): AH00962: HTTP: connection complete to 172.19.0.2:8080 (keycloak)
openidc_1         | [Fri Aug 18 19:28:14.831027 2017] [proxy:debug] [pid 12:tid 140432528824064] proxy_util.c(2171): AH00943: http: has released connection for (keycloak)
openidc_1         | 172.19.0.1 - - [18/Aug/2017:19:28:14 +0000] "GET /auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-C
xQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew HTTP/1.1" 200 3597 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) 
Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | [Fri Aug 18 19:28:18.988474 2017] [authz_core:debug] [pid 12:tid 140432520431360] mod_authz_core.c(835): [client 172.19.0.1:56252] AH01628: authorization result: granted (no directiv
es), referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected
%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:18.988533 2017] [proxy:debug] [pid 12:tid 140432520431360] mod_proxy.c(1228): [client 172.19.0.1:56252] AH01143: Running scheme http handler (attempt 0), referer: h
ttp://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri
&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:18.988546 2017] [proxy:debug] [pid 12:tid 140432520431360] proxy_util.c(2156): AH00942: HTTP: has acquired connection for (keycloak)
openidc_1         | [Fri Aug 18 19:28:18.988553 2017] [proxy:debug] [pid 12:tid 140432520431360] proxy_util.c(2209): [client 172.19.0.1:56252] AH00944: connecting http://keycloak:8080/auth/realms/Testre
alm/login-actions/authenticate?code=qc3MFptys552aOAsu6CoHrUODpDFKuqIT5p-FlVUtck.1f406ecf-b593-4cb2-bdc8-13cdf33f842e&execution=a4a8936f-f13a-457b-89dc-37143b66823a to keycloak:8080, referer: http://openidc/aut
h/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAX
W9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:18.988568 2017] [proxy:debug] [pid 12:tid 140432520431360] proxy_util.c(2418): [client 172.19.0.1:56252] AH00947: connected /auth/realms/Testrealm/login-actions/aut
henticate?code=qc3MFptys552aOAsu6CoHrUODpDFKuqIT5p-FlVUtck.1f406ecf-b593-4cb2-bdc8-13cdf33f842e&execution=a4a8936f-f13a-457b-89dc-37143b66823a to keycloak:8080, referer: http://openidc/auth/realms/Testrealm/pr
otocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW6
7VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.154767 2017] [proxy:debug] [pid 12:tid 140432520431360] proxy_util.c(2171): AH00943: http: has released connection for (keycloak)
openidc_1         | 172.19.0.1 - - [18/Aug/2017:19:28:18 +0000] "POST /auth/realms/Testrealm/login-actions/authenticate?code=qc3MFptys552aOAsu6CoHrUODpDFKuqIT5p-FlVUtck.1f406ecf-b593-4cb2-bdc8-13cdf33f8
42e&execution=a4a8936f-f13a-457b-89dc-37143b66823a HTTP/1.1" 302 - "http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJ
rDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/
60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | [Fri Aug 18 19:28:19.160748 2017] [authz_core:debug] [pid 12:tid 140432512038656] mod_authz_core.c(809): [client 172.19.0.1:56252] AH01626: authorization result of Require valid-user
 : denied (no authenticated user yet), referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_ur
i=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.160773 2017] [authz_core:debug] [pid 12:tid 140432512038656] mod_authz_core.c(809): [client 172.19.0.1:56252] AH01626: authorization result of <RequireAny>: deni
ed (no authenticated user yet), referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%
3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.160785 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/mod_auth_openidc.c(3280): [client 172.19.0.1:56252] oidc_check_user_id: incoming request: "/pr
otected/redirect_uri?state=tHASvshIPNCRn4OHSRJrDla-CxQ&code=_ItlpVd-JkYHbol3I3VPB5V-d91Rhrt81v0P5Nq3eUo.1f406ecf-b593-4cb2-bdc8-13cdf33f842e", ap_is_initial_req(r)=1, referer: http://openidc/auth/realms/Testre
alm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMf
SL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.160799 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(485): [client 172.19.0.1:56252] oidc_get_redirect_uri: determined absolute redirect uri
: http://openidc/protected/redirect_uri, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_
uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.160813 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(932): [client 172.19.0.1:56252] oidc_util_get_cookie: returning "mod_auth_openidc_sessi
on" = <null>, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2F
protected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.160851 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(485): [client 172.19.0.1:56252] oidc_get_redirect_uri: determined absolute redirect uri
: http://openidc/protected/redirect_uri, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_
uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.160856 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(1084): [client 172.19.0.1:56252] oidc_util_request_matches_url: comparing "/protected/r
edirect_uri"=="/protected/redirect_uri", referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_
uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.160862 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/mod_auth_openidc.c(1940): [client 172.19.0.1:56252] oidc_handle_redirect_authorization_respons
e: enter, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprot
ected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.160905 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(1376): [client 172.19.0.1:56252] oidc_util_read_form_encoded_params: read: state=tHASvs
hIPNCRn4OHSRJrDla-CxQ, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fo
penidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.160926 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(1376): [client 172.19.0.1:56252] oidc_util_read_form_encoded_params: read: code=_ItlpVd
-JkYHbol3I3VPB5V-d91Rhrt81v0P5Nq3eUo.1f406ecf-b593-4cb2-bdc8-13cdf33f842e, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHA
SvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.160934 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(1381): [client 172.19.0.1:56252] oidc_util_read_form_encoded_params: parsed: 119 bytes 
into 2 elements, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc
%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.160940 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/mod_auth_openidc.c(1770): [client 172.19.0.1:56252] oidc_handle_authorization_response: enter,
 response_mode=query, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fop
enidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.160946 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/mod_auth_openidc.c(1428): [client 172.19.0.1:56252] oidc_authorization_response_match_state: e
nter (state=tHASvshIPNCRn4OHSRJrDla-CxQ), referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect
_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.160954 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/mod_auth_openidc.c(714): [client 172.19.0.1:56252] oidc_restore_proto_state: enter, referer: h
ttp://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri
&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.160973 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(932): [client 172.19.0.1:56252] oidc_util_get_cookie: returning "mod_auth_openidc_state
_tHASvshIPNCRn4OHSRJrDla-CxQ" = "eyJhbGciOiAiZGlyIiwgImVuYyI6ICJBMjU2R0NNIn0..JNp4PRz-38gcIZu5.jBajHNzBWn4cfwXnFUNumFeT8NWorl7h_MOoaMTKuemEsPtTeKnq2FPpx3E4tAa9fcje3-z67BBD0tZwcpws_Y_dLPqmWWReRoc7cqgJmJdy7UMxd5
Lt37-WYRoCBBrP8dAaQhA7BGWS2-lg9mf1twLJpF2PxAcZ-9EltI9LSL7_Hl1mAE5gh2OUV6MDpYg8UKQxeAUa3xNKdDvg7aonTo8MjkE6ubmEZ5Xz9I1TtJEtvAF0BVav6JgeClRQm4upaSPFLzSEHoGhA4tOHFmQ8FSwrBDcViOv6eelY0rmX_dxz6GrvWAG2vfDT8birC6EZO-
hWlI8AiC0jMPtRTFoOaPcFmhHmlO4ts68sJPzr6Ouwrt66qqa3_5YkDMuBi0.calTdW07stPjIKLgZWBGvA", referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid
1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.160998 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(2043): [client 172.19.0.1:56252] oidc_util_hdr_err_out_add: Set-Cookie: mod_auth_openid
c_state_tHASvshIPNCRn4OHSRJrDla-CxQ=; Path=/; Expires=Thu, 01 Jan 1970 00:00:00 GMT; HttpOnly, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_
id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.161005 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(204): [client 172.19.0.1:56252] oidc_util_jwt_verify: enter: JWT header={"alg": "dir", 
"enc": "A256GCM"}, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopeni
dc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.161028 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(1843): [client 172.19.0.1:56252] oidc_util_create_symmetric_key: key_len=32, referer: h
ttp://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri
&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.161113 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/mod_auth_openidc.c(230): [client 172.19.0.1:56252] oidc_get_browser_state_hash: enter, referer
: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_
uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.161132 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/mod_auth_openidc.c(768): [client 172.19.0.1:56252] oidc_restore_proto_state: restored state: {
"ou":"http://openidc/protected/","s":"tHASvshIPNCRn4OHSRJrDla-CxQ","om":"get","i":"http://openidc/auth/realms/Testrealm","rt":"code","n":"L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew","t":1503084494}, referer: 
http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_ur
i&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.161141 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/cache/common.c(521): [client 172.19.0.1:56252] oidc_cache_get: enter: http://openidc/auth/real
ms/Testrealm/.well-known/openid-configuration (section=p, decrypt=0, type=shm), referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&stat
e=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.161153 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/cache/common.c(555): [client 172.19.0.1:56252] oidc_cache_get: cache hit: return 1785 bytes fr
om shm cache backend for key http://openidc/auth/realms/Testrealm/.well-known/openid-configuration, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&cl
ient_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.161224 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(2742): [client 172.19.0.1:56252] oidc_proto_handle_authorization_response_code: enter,
 referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fr
edirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.161229 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(2550): [client 172.19.0.1:56252] oidc_proto_validate_issuer_client_id: iss and/or clie
nt_id matched OK: (null), http://openidc/auth/realms/Testrealm, (null), openid1, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&sta
te=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.161234 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(1782): [client 172.19.0.1:56252] oidc_proto_resolve_code: enter, referer: http://openi
dc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-Fd
XxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.161238 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(485): [client 172.19.0.1:56252] oidc_get_redirect_uri: determined absolute redirect uri
: http://openidc/protected/redirect_uri, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_
uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.161243 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(1610): [client 172.19.0.1:56252] oidc_proto_token_endpoint_request: token_endpoint_aut
h=client_secret_basic, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fo
penidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.161246 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(1713): [client 172.19.0.1:56252] oidc_proto_token_endpoint_request: no client secret i
s configured; calling the token endpoint without client authentication; only public clients are supported, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=op
enid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.161293 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(768): [client 172.19.0.1:56252] oidc_util_http_post_form: post data="grant_type=authori
zation_code&code=_ItlpVd-JkYHbol3I3VPB5V-d91Rhrt81v0P5Nq3eUo.1f406ecf-b593-4cb2-bdc8-13cdf33f842e&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&state=tHASvshIPNCRn4OHSRJrDla-CxQ&client_id=openid
1", referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%
2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.161300 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(573): [client 172.19.0.1:56252] oidc_util_http_call: url=http://openidc/auth/realms/Tes
trealm/protocol/openid-connect/token, data=grant_type=authorization_code&code=_ItlpVd-JkYHbol3I3VPB5V-d91Rhrt81v0P5Nq3eUo.1f406ecf-b593-4cb2-bdc8-13cdf33f842e&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fre
direct_uri&state=tHASvshIPNCRn4OHSRJrDla-CxQ&client_id=openid1, content_type=application/x-www-form-urlencoded, basic_auth=(null), bearer_token=(null), ssl_validate_server=1, referer: http://openidc/auth/realm
s/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQ
AvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.165718 2017] [authz_core:debug] [pid 12:tid 140432503645952] mod_authz_core.c(835): [client 172.19.0.5:59410] AH01628: authorization result: granted (no directiv
es)
openidc_1         | [Fri Aug 18 19:28:19.165749 2017] [proxy:debug] [pid 12:tid 140432503645952] mod_proxy.c(1228): [client 172.19.0.5:59410] AH01143: Running scheme http handler (attempt 0)
openidc_1         | [Fri Aug 18 19:28:19.165758 2017] [proxy:debug] [pid 12:tid 140432503645952] proxy_util.c(2156): AH00942: HTTP: has acquired connection for (keycloak)
openidc_1         | [Fri Aug 18 19:28:19.165764 2017] [proxy:debug] [pid 12:tid 140432503645952] proxy_util.c(2209): [client 172.19.0.5:59410] AH00944: connecting http://keycloak:8080/auth/realms/Testre
alm/protocol/openid-connect/token to keycloak:8080
openidc_1         | [Fri Aug 18 19:28:19.165771 2017] [proxy:debug] [pid 12:tid 140432503645952] proxy_util.c(2418): [client 172.19.0.5:59410] AH00947: connected /auth/realms/Testrealm/protocol/openid-c
onnect/token to keycloak:8080
openidc_1         | [Fri Aug 18 19:28:19.195316 2017] [proxy:debug] [pid 12:tid 140432503645952] proxy_util.c(2171): AH00943: http: has released connection for (keycloak)
openidc_1         | 172.19.0.5 - - [18/Aug/2017:19:28:19 +0000] "POST /auth/realms/Testrealm/protocol/openid-connect/token HTTP/1.1" 200 3907 "-" "mod_auth_openidc"
openidc_1         | [Fri Aug 18 19:28:19.195469 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(710): [client 172.19.0.1:56252] oidc_util_http_call: HTTP response code=200, referer: h
ttp://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri
&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.195494 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(715): [client 172.19.0.1:56252] oidc_util_http_call: response={"access_token":"eyJhbGci
OiJSUzI1NiIsInR5cCIgOiAiSldUIiwia2lkIiA6ICJCOW5Ick82a29LeFlJRjFqYXVuUVJ5YU1jb1E0ckFxZ0syMFVWd3IwYmhvIn0.eyJqdGkiOiJmOGNmMDA1MC1iYTM2LTQwYjItODE4OC02NGRlMDM0ZmM4MmEiLCJleHAiOjE1MDMwODQ3OTksIm5iZiI6MCwiaWF0IjoxN
TAzMDg0NDk5LCJpc3MiOiJodHRwOi8vb3BlbmlkYy9hdXRoL3JlYWxtcy9UZXN0cmVhbG0iLCJhdWQiOiJvcGVuaWQxIiwic3ViIjoiMzQyZTg4ZDUtM2FkOS00OGU5LWI0ZjAtMGRhNDY0MTViNTk0IiwidHlwIjoiQmVhcmVyIiwiYXpwIjoib3BlbmlkMSIsIm5vbmNlIjoiTC
1GZFh4YklBWFc5Q3NBalFBdlpvb2ZNZlNMN1BXNjdWcUtfVTEwSXZldyIsImF1dGhfdGltZSI6MTUwMzA4NDQ5OSwic2Vzc2lvbl9zdGF0ZSI6IjFlYzU4ZWU5LTI4MDEtNGE5Zi1iMDIwLWU3YmI5Njk1N2EzYiIsImFjciI6IjEiLCJjbGllbnRfc2Vzc2lvbiI6IjFmNDA2ZWN
mLWI1OTMtNGNiMi1iZGM4LTEzY2RmMzNmODQyZSIsImFsbG93ZWQtb3JpZ2lucyI6WyJodHRwOi8vb3BlbmlkYyJdLCJyZWFsbV9hY2Nlc3MiOnsicm9sZXMiOlsidW1hX2F1dGhvcml6YXRpb24iXX0sInJlc291cmNlX2FjY2VzcyI6eyJhY2NvdW50Ijp7InJvbGVzIjpbIm1h
bmFnZS1hY2NvdW50IiwibWFuYWdlLWFjY291bnQtbGlua3MiLCJ2aWV3LXByb2ZpbGUiXX19LCJuYW1lIjoiVGVzdCBPcGVuaWRjIiwicHJlZmVycmVkX3VzZXJuYW1lIjoidGVzdDEiLCJnaXZlbl9uYW1lIjoiVGVzdCIsImZhbWlseV9uYW1lIjoiT3BlbmlkYyIsImVtYWlsI
joidGVzdDFAZXhhbXBsZS5uZXQifQ.g-yInPgMvRJGkzLopYPgNR2BrcrQs6slZz1-2KhHMlriX9OvVAZMrE95zLPxlR0w7tN9CfkTdprHq4BgvI1J0XXwYmbbDAaJtPpdadHF6l3TveO2SvGugshvuzHzot16quQLrpBMcAkxkGE24PVLDBFWt71JC6717IMdodwafbOCu53H60W
UIgXDJwg42sDVf-kdrKS2vrVm9qgAFUC-TluuJXl7HEr4yVPnKk7PfFMvYdKJC3ZH3GH3axxCu4aKFjAaZxh5c_v4kTz7fVgnfho19DQ7wBKMO84T8jGPXGY7ytMfufXChh3JI0zl1WV7pgLINlE52vYM1Cr4GJn_cQ","expires_in":300,"refresh_expires_in":60,"re
fresh_token":"eyJhbGciOiJSUzI1NiIsInR5cCIgOiAiSldUIiwia2lkIiA6ICJCOW5Ick82a29LeFlJRjFqYXVuUVJ5YU1jb1E0ckFxZ0syMFVWd3IwYmhvIn0.eyJqdGkiOiJjMzMwZWE2ZS04ZDk3LTQ3MjAtODQ4Yi0yYWUyZjhiY2I3N2UiLCJleHAiOjE1MDMwODQ1NTk
sIm5iZiI6MCwiaWF0IjoxNTAzMDg0NDk5LCJpc3MiOiJodHRwOi8vb3BlbmlkYy9hdXRoL3JlYWxtcy9UZXN0cmVhbG0iLCJhdWQiOiJvcGVuaWQxIiwic3ViIjoiMzQyZTg4ZDUtM2FkOS00OGU5LWI0ZjAtMGRhNDY0MTViNTk0IiwidHlwIjoiUmVmcmVzaCIsImF6cCI6Im9w
ZW5pZDEiLCJub25jZSI6IkwtRmRYeGJJQVhXOUNzQWpRQXZab29mTWZTTDdQVzY3VnFLX1UxMEl2ZXciLCJhdXRoX3RpbWUiOjAsInNlc3Npb25fc3RhdGUiOiIxZWM1OGVlOS0yODAxLTRhOWYtYjAyMC1lN2JiOTY5NTdhM2IiLCJjbGllbnRfc2Vzc2lvbiI6IjFmNDA2ZWNmL
WI1OTMtNGNiMi1iZGM4LTEzY2RmMzNmODQyZSIsInJlYWxtX2FjY2VzcyI6eyJyb2xlcyI6WyJ1bWFfYXV0aG9yaXphdGlvbiJdfSwicmVzb3VyY2VfYWNjZXNzIjp7ImFjY291bnQiOnsicm9sZXMiOlsibWFuYWdlLWFjY291bnQiLCJtYW5hZ2UtYWNjb3VudC1saW5rcyIsIn
ZpZXctcHJvZmlsZSJdfX19.JcyTtRmch0BovROCr0fBr32LWSmfJAIvqID5OL6vlE-QNO3TRZ7W3M7cBqF5M0Ej8LXRFu0ql1a-2wrYWPQVibPY3_yusXhqvGE0zh-_U8AvMzR9J8orX8EDedxNkn5MLQM6dsM3wIAb4m5pQHXBR8c1Z6wpQyrdHA4dyJ7rFWxHT1SyP6xjxDnPZe
DgiTP5TyJ6GCwv29Nj-gOTzd2h8q2H8xb7j-7oE6SF9dkN1DaU2w_wuazA7wox2A1Qc3FfPRjMoiJSVtAw4X3vRivJhknmpID5OruCtgkOkhqTjpE2O2A_-pwAY2NbEDBUp_g7XrgWZaL2t8T-hIfYCgNXKQ","token_type":"bearer","id_token":"eyJhbGciOiJSUzI1N
iIsInR5cCIgOiAiSldUIiwia2lkIiA6ICJCOW5Ick82a29LeFlJRjFqYXVuUVJ5YU1jb1E0ckFxZ0syMFVWd3IwYmhvIn0.eyJqdGkiOiIzNTIxYzYwYy01Njg3LTRjYTMtYmM4Yy04ODFjNDU4YTc1OGQiLCJleHAiOjE1MDMwODQ3OTksIm5iZiI6MCwiaWF0IjoxNTAzMDg0ND
k5LCJpc3MiOiJodHRwOi8vb3BlbmlkYy9hdXRoL3JlYWxtcy9UZXN0cmVhbG0iLCJhdWQiOiJvcGVuaWQxIiwic3ViIjoiMzQyZTg4ZDUtM2FkOS00OGU5LWI0ZjAtMGRhNDY0MTViNTk0IiwidHlwIjoiSUQiLCJhenAiOiJvcGVuaWQxIiwibm9uY2UiOiJMLUZkWHhiSUFYVzl
Dc0FqUUF2Wm9vZk1mU0w3UFc2N1ZxS19VMTBJdmV3IiwiYXV0aF90aW1lIjoxNTAzMDg0NDk5LCJzZXNzaW9uX3N0YXRlIjoiMWVjNThlZTktMjgwMS00YTlmLWIwMjAtZTdiYjk2OTU3YTNiIiwiYWNyIjoiMSIsIm5hbWUiOiJUZXN0IE9wZW5pZGMiLCJwcmVmZXJyZWRfdXNl
cm5hbWUiOiJ0ZXN0MSIsImdpdmVuX25hbWUiOiJUZXN0IiwiZmFtaWx5X25hbWUiOiJPcGVuaWRjIiwiZW1haWwiOiJ0ZXN0MUBleGFtcGxlLm5ldCJ9.ElzCFI4ueOuYhWtjRBHX1d7lOyqn0bptOYHJcmtFZXt-OwoIa4lL8-iNA_Kkx_jnKTCtgQ9vdxcO3xleC1fxLhKlNC_-
E1WQkYw4mcBXhVW-7uZH41LmYg3PxA2jjRbpAcNwpFml9zLtWQNRSts4dwhwVLpnAAW4EhjHkvTEDYUkTpYDQ6VJnHXVt5StpxqnFdS5yD28fSp4P8FSdQAdh9pWlsAli31doZQywGkag2HuL3g4NbwFDWx0XT3RPq-EONMzMg7wnKvkeuWIazjZHBBnxYPs_i0HV8iFZqNRsHraY
DE1GOw523hLZ14GgcaZnSz16zLWObNw5wZD9pb-_Q","not-before-policy":0,"session_state":"1ec58ee9-2801-4a9f-b020-e7bb96957a3b"}, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_typ
e=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.195728 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(2391): [client 172.19.0.1:56252] oidc_proto_validate_code_response: enter, referer: ht
tp://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&
nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.195764 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(1514): [client 172.19.0.1:56252] oidc_proto_parse_idtoken: enter: id_token header={"al
g":"RS256","typ" : "JWT","kid" : "B9nHrO6koKxYIF1jaunQRyaMcoQ4rAqgK20UVwr0bho"}, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&sta
te=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.195840 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(1536): [client 172.19.0.1:56252] oidc_proto_parse_idtoken: successfully parsed (and po
ssibly decrypted) JWT with header={"typ":"JWT","alg":"RS256","kid":"B9nHrO6koKxYIF1jaunQRyaMcoQ4rAqgK20UVwr0bho"}, and payload={"jti":"3521c60c-5687-4ca3-bc8c-881c458a758d","exp":1503084799,"nbf":0,"iat":15030
84499,"iss":"http://openidc/auth/realms/Testrealm","aud":"openid1","sub":"342e88d5-3ad9-48e9-b4f0-0da46415b594","typ":"ID","azp":"openid1","nonce":"L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew","auth_time":1503
084499,"session_state":"1ec58ee9-2801-4a9f-b020-e7bb96957a3b","acr":"1","name":"Test Openidc","preferred_username":"test1","given_name":"Test","family_name":"Openidc","email":"test1@example.net"}, referer: htt
p://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&n
once=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.195857 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/metadata.c(619): [client 172.19.0.1:56252] oidc_metadata_jwks_get: enter, jwks_uri=http://open
idc/auth/realms/Testrealm/protocol/openid-connect/certs, refresh=0, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPN
CRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.195866 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/cache/common.c(521): [client 172.19.0.1:56252] oidc_cache_get: enter: http://openidc/auth/real
ms/Testrealm/protocol/openid-connect/certs (section=j, decrypt=0, type=shm), referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=t
HASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.195916 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/cache/common.c(557): [client 172.19.0.1:56252] oidc_cache_get: cache miss from shm cache backe
nd for key http://openidc/auth/realms/Testrealm/protocol/openid-connect/certs, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state
=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.195924 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(573): [client 172.19.0.1:56252] oidc_util_http_call: url=http://openidc/auth/realms/Tes
trealm/protocol/openid-connect/certs, data=(null), content_type=(null), basic_auth=(null), bearer_token=(null), ssl_validate_server=1, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth
?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.200308 2017] [authz_core:debug] [pid 12:tid 140432621143808] mod_authz_core.c(835): [client 172.19.0.5:59412] AH01628: authorization result: granted (no directiv
es)
openidc_1         | [Fri Aug 18 19:28:19.200339 2017] [proxy:debug] [pid 12:tid 140432621143808] mod_proxy.c(1228): [client 172.19.0.5:59412] AH01143: Running scheme http handler (attempt 0)
openidc_1         | [Fri Aug 18 19:28:19.200346 2017] [proxy:debug] [pid 12:tid 140432621143808] proxy_util.c(2156): AH00942: HTTP: has acquired connection for (keycloak)
openidc_1         | [Fri Aug 18 19:28:19.200350 2017] [proxy:debug] [pid 12:tid 140432621143808] proxy_util.c(2209): [client 172.19.0.5:59412] AH00944: connecting http://keycloak:8080/auth/realms/Testre
alm/protocol/openid-connect/certs to keycloak:8080
openidc_1         | [Fri Aug 18 19:28:19.200355 2017] [proxy:debug] [pid 12:tid 140432621143808] proxy_util.c(2418): [client 172.19.0.5:59412] AH00947: connected /auth/realms/Testrealm/protocol/openid-c
onnect/certs to keycloak:8080
openidc_1         | [Fri Aug 18 19:28:19.201892 2017] [proxy:debug] [pid 12:tid 140432621143808] proxy_util.c(2171): AH00943: http: has released connection for (keycloak)
openidc_1         | 172.19.0.5 - - [18/Aug/2017:19:28:19 +0000] "GET /auth/realms/Testrealm/protocol/openid-connect/certs HTTP/1.1" 200 462 "-" "mod_auth_openidc"
openidc_1         | [Fri Aug 18 19:28:19.201998 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(710): [client 172.19.0.1:56252] oidc_util_http_call: HTTP response code=200, referer: h
ttp://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri
&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202015 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/util.c(715): [client 172.19.0.1:56252] oidc_util_http_call: response={"keys":[{"kid":"B9nHrO6k
oKxYIF1jaunQRyaMcoQ4rAqgK20UVwr0bho","kty":"RSA","alg":"RS256","use":"sig","n":"j0rfARlWsrxj6qleEe1_a1yE9ZGBcsEm6cCFHezcDgmK0rCkOsTjM_KBxzSJf6xOp7qMmUEKxSsx73Z-yf1aM0v8lGv09fH9ilyyk_vWv5kOfZOkLNAvYqCd8Ls9dkj_m
4lo30LD2zwMSx5nfY5j6hlKGOq1u-sIehBhqbx2kRIHnMOMzHKDrqvPaR441HzgbfQWc_q9VtI5Y3YjZgwixj1596qDB5rjZ8aTVAitC1qmsqpgo-smJOmbF6zneVgSw2jy7mA1Dd7G9VYlHPRyqh5bVTeC-0gdxiOKiWuUE19RbTqmw8Rjyuxg2aEZTSSjW4Z3SeTkjg-urQVmsI
FALw","e":"AQAB"}]}, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fope
nidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202122 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/cache/common.c(580): [client 172.19.0.1:56252] oidc_cache_set: enter: http://openidc/auth/real
ms/Testrealm/protocol/openid-connect/certs (section=j, len=462, encrypt=0, ttl(s)=3599, type=shm), referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&cli
ent_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202155 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/cache/common.c(607): [client 172.19.0.1:56252] oidc_cache_set: successfully stored 462 bytes i
n shm cache backend for key http://openidc/auth/realms/Testrealm/protocol/openid-connect/certs, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client
_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202165 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(1295): [client 172.19.0.1:56252] oidc_proto_get_key_from_jwks: search for kid "B9nHrO6
koKxYIF1jaunQRyaMcoQ4rAqgK20UVwr0bho" or thumbprint x5t "(null)", referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCR
n4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202248 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(1357): [client 172.19.0.1:56252] oidc_proto_get_key_from_jwks: found matching kid: "B9
nHrO6koKxYIF1jaunQRyaMcoQ4rAqgK20UVwr0bho" for jwk: {"kty":"RSA","kid":"B9nHrO6koKxYIF1jaunQRyaMcoQ4rAqgK20UVwr0bho","e":"AQAB","n":"j0rfARlWsrxj6qleEe1_a1yE9ZGBcsEm6cCFHezcDgmK0rCkOsTjM_KBxzSJf6xOp7qMmUEKxSsx
73Z-yf1aM0v8lGv09fH9ilyyk_vWv5kOfZOkLNAvYqCd8Ls9dkj_m4lo30LD2zwMSx5nfY5j6hlKGOq1u-sIehBhqbx2kRIHnMOMzHKDrqvPaR441HzgbfQWc_q9VtI5Y3YjZgwixj1596qDB5rjZ8aTVAitC1qmsqpgo-smJOmbF6zneVgSw2jy7mA1Dd7G9VYlHPRyqh5bVTeC-
0gdxiOKiWuUE19RbTqmw8Rjyuxg2aEZTSSjW4Z3SeTkjg-urQVmsIFALw"}, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHS
RJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202261 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(1426): [client 172.19.0.1:56252] oidc_proto_get_keys_from_jwks_uri: returning 1 key(s)
 obtained from the (possibly cached) JWKs URI, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&red
irect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202409 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(1471): [client 172.19.0.1:56252] oidc_proto_jwt_verify: JWT signature verification wit
h algorithm "RS256" was successful, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=h
ttp%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202430 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(1247): [client 172.19.0.1:56252] oidc_proto_validate_idtoken: enter, jwt.header="{"typ
":"JWT","alg":"RS256","kid":"B9nHrO6koKxYIF1jaunQRyaMcoQ4rAqgK20UVwr0bho"}", jwt.payload={"jti":"3521c60c-5687-4ca3-bc8c-881c458a758d","exp":1503084799,"nbf":0,"iat":1503084499,"iss":"http://openidc/auth/realm
s/Testrealm","aud":"openid1","sub":"342e88d5-3ad9-48e9-b4f0-0da46415b594","typ":"ID","azp":"openid1","nonce":"L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew","auth_time":1503084499,"session_state":"1ec58ee9-2801-
4a9f-b020-e7bb96957a3b","acr":"1","name":"Test Openidc","preferred_username":"test1","given_name":"Test","family_name":"Openidc","email":"test1@example.net"}", nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2F
redirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202443 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/cache/common.c(521): [client 172.19.0.1:56252] oidc_cache_get: enter: L-FdXxbIAXW9CsAjQAvZoofM
fSL7PW67VqK_U10Ivew (section=n, decrypt=0, type=shm), referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-
CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202463 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/cache/common.c(557): [client 172.19.0.1:56252] oidc_cache_get: cache miss from shm cache backe
nd for key L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDl
a-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202472 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/cache/common.c(580): [client 172.19.0.1:56252] oidc_cache_set: enter: L-FdXxbIAXW9CsAjQAvZoofM
fSL7PW67VqK_U10Ivew (section=n, len=43, encrypt=0, ttl(s)=1210, type=shm), referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHA
SvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202486 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/cache/common.c(607): [client 172.19.0.1:56252] oidc_cache_set: successfully stored 43 bytes in
 shm cache backend for key L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvs
hIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202493 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(964): [client 172.19.0.1:56252] oidc_proto_validate_nonce: nonce "L-FdXxbIAXW9CsAjQAvZ
oofMfSL7PW67VqK_U10Ivew" validated successfully and is now cached for 1210 seconds, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&
state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202502 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(1060): [client 172.19.0.1:56252] oidc_proto_validate_cnf: enter: policy=optional, refe
rer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredire
ct_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202509 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(1067): [client 172.19.0.1:56252] oidc_proto_validate_cnf: no Provided Token Binding ID
 environment variable found, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%
2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202516 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(1575): [client 172.19.0.1:56252] oidc_proto_parse_idtoken: valid id_token for user "34
2e88d5-3ad9-48e9-b4f0-0da46415b594" expires: [Fri, 18 Aug 2017 19:33:19 GMT], in 300 secs from now), referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&c
lient_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202532 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/mod_auth_openidc.c(1116): [client 172.19.0.1:56252] oidc_retrieve_claims_from_userinfo_endpoin
t: enter, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=tHASvshIPNCRn4OHSRJrDla-CxQ&redirect_uri=http%3A%2F%2Fopenidc%2Fprot
ected%2Fredirect_uri&nonce=L-FdXxbIAXW9CsAjQAvZoofMfSL7PW67VqK_U10Ivew
openidc_1         | [Fri Aug 18 19:28:19.202542 2017] [auth_openidc:debug] [pid 12:tid 140432512038656] src/proto.c(2022): [client 172.19.0.1:56252] oidc_proto_resolve_userinfo: enter, endpoint=http://o
penidc/auth/realms/Testrealm/protocol/openid-connect/userinfo, access_token=eyJhbGciOiJSUzI1NiIsInR5cCIgOiAiSldUIiwia2lkIiA6ICJCOW5Ick82a29LeFlJRjFqYXVuU

@zandbelt Might this be an effect of https://github.com/pingidentity/mod_auth_openidc/commit/0039c54253e970706a52f61a62869a1dd3d0eade?

I've tried to set OIDCClientSecret but then startup fails unless I have a OIDCOAuthIntrospectionEndpoint which is http in this test setup, so I got stuck there.

zandbelt commented 7 years ago

It looks like this is an unintended side effect but I'm not sure it is wrong yet.

What does your .conf file look like? Are you using a public client in a multi-provider setup? Setting OIDCClientSecret should not affect OIDCOAuthIntrospectionEndpoint but perhaps you meant to say OIDCProviderTokenEndpoint?

solsson commented 7 years ago

The conf is here: https://github.com/Reposoft/openidc-keycloak-test/blob/master/build-contracts/openidc/000-default.conf. It's a public client but is it multi-provider?

I need to get back to you on the directives because I can't test again right now. This was something I guessed based on the error message with OIDCClientSecret, but I might be mistaken.

solsson commented 7 years ago

I'm sorry, the comment I made about directives is irrelevant. We changed from confidential to public in https://github.com/Reposoft/openidc-keycloak-test/pull/18/files#diff-b3a249a260ce1f8ad7085fdc2697dd43L14. This is to support 3rd party integrations. The problem persists at re-test.

With info level, this is the success log, from 2.3.0.

openidc_1         | 172.18.0.4 - - [19/Aug/2017:18:53:10 +0000] "GET /auth/realms/Testrealm/.well-known/openid-configuration HTTP/1.1" 200 1785 "-" "mod_auth_openidc"
openidc_1         | 172.18.0.1 - - [19/Aug/2017:18:53:10 +0000] "GET /protected/ HTTP/1.1" 302 464 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | 172.18.0.1 - - [19/Aug/2017:18:53:10 +0000] "GET /auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=n45LGhhZ4e8jEZjZ0pBtPRO095I&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=kLkZt466DWoR1IOGJ4gWwnFnT-RNeHbd83Qvgpq8Lhs HTTP/1.1" 200 3597 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | 172.18.0.1 - - [19/Aug/2017:18:53:14 +0000] "POST /auth/realms/Testrealm/login-actions/authenticate?code=fZbDgV96wt3ZiIqAEMbqkMc0ByY4gdDYXIYoGDDOBGM.0cd133f7-319d-43b9-97f7-e1e6909d6203&execution=6c605ee1-ede5-44b9-965e-2417a7d625c2 HTTP/1.1" 302 - "http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=n45LGhhZ4e8jEZjZ0pBtPRO095I&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=kLkZt466DWoR1IOGJ4gWwnFnT-RNeHbd83Qvgpq8Lhs" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | 172.18.0.4 - - [19/Aug/2017:18:53:14 +0000] "POST /auth/realms/Testrealm/protocol/openid-connect/token HTTP/1.1" 200 3907 "-" "mod_auth_openidc"
openidc_1         | 172.18.0.4 - - [19/Aug/2017:18:53:14 +0000] "GET /auth/realms/Testrealm/protocol/openid-connect/certs HTTP/1.1" 200 462 "-" "mod_auth_openidc"
openidc_1         | 172.18.0.4 - - [19/Aug/2017:18:53:14 +0000] "GET /auth/realms/Testrealm/protocol/openid-connect/userinfo HTTP/1.1" 200 169 "-" "mod_auth_openidc"
openidc_1         | [Sat Aug 19 18:53:14.564140 2017] [auth_openidc:warn] [pid 11:tid 140237585999616] [client 172.18.0.1:48516] oidc_save_in_session: session management disabled: no "session_state" value is provided in the authentication response even though "check_session_iframe" (http://openidc/auth/realms/Testrealm/protocol/openid-connect/login-status-iframe.html) is set in the provider configuration, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=n45LGhhZ4e8jEZjZ0pBtPRO095I&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=kLkZt466DWoR1IOGJ4gWwnFnT-RNeHbd83Qvgpq8Lhs
openidc_1         | 172.18.0.1 - fc4aa9a3-9154-430d-86c9-eb4a32793a15 [19/Aug/2017:18:53:14 +0000] "GET /protected/redirect_uri?state=n45LGhhZ4e8jEZjZ0pBtPRO095I&code=fOkWhgAS4i6ir3lbEaBLS545fY2oeYy7UcxcpyrEl7Q.0cd133f7-319d-43b9-97f7-e1e6909d6203 HTTP/1.1" 302 209 "http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=n45LGhhZ4e8jEZjZ0pBtPRO095I&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=kLkZt466DWoR1IOGJ4gWwnFnT-RNeHbd83Qvgpq8Lhs" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | 172.18.0.1 - fc4aa9a3-9154-430d-86c9-eb4a32793a15 [19/Aug/2017:18:53:14 +0000] "GET /protected/ HTTP/1.1" 200 607 "http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=n45LGhhZ4e8jEZjZ0pBtPRO095I&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=kLkZt466DWoR1IOGJ4gWwnFnT-RNeHbd83Qvgpq8Lhs" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | 172.18.0.1 - - [19/Aug/2017:18:53:14 +0000] "GET /style.css HTTP/1.1" 304 - "http://openidc/protected/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | 172.18.0.1 - fc4aa9a3-9154-430d-86c9-eb4a32793a15 [19/Aug/2017:18:53:14 +0000] "GET /protected/script.js HTTP/1.1" 304 - "http://openidc/protected/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | 172.18.0.1 - fc4aa9a3-9154-430d-86c9-eb4a32793a15 [19/Aug/2017:18:53:14 +0000] "HEAD /protected/ HTTP/1.1" 304 - "http://openidc/protected/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | 172.18.0.1 - fc4aa9a3-9154-430d-86c9-eb4a32793a15 [19/Aug/2017:18:53:14 +0000] "GET /protected/ HTTP/1.1" 304 - "http://openidc/protected/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"

This is the log with identical conf but 2.3.1:

openidc_1         | 172.18.0.4 - - [19/Aug/2017:18:55:17 +0000] "GET /auth/realms/Testrealm/.well-known/openid-configuration HTTP/1.1" 200 1785 "-" "mod_auth_openidc"
openidc_1         | 172.18.0.1 - - [19/Aug/2017:18:55:17 +0000] "GET /protected/ HTTP/1.1" 302 464 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | 172.18.0.1 - - [19/Aug/2017:18:55:17 +0000] "GET /auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=Dy8545hMI6aUcIQXWNB-CpZD85Y&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=3twHstQbLoQi1dEO3_bqcQb1udLkBW6RMoIcMuwG1DA HTTP/1.1" 200 3597 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | 172.18.0.1 - - [19/Aug/2017:18:55:21 +0000] "POST /auth/realms/Testrealm/login-actions/authenticate?code=ctFbvCIclpgz3PlV08ir3FMPhbOuHnPrzjhuL3vEt5I.98dfe6c1-0721-4e5c-8e1f-0ed440c23589&execution=6c605ee1-ede5-44b9-965e-2417a7d625c2 HTTP/1.1" 302 - "http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=Dy8545hMI6aUcIQXWNB-CpZD85Y&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=3twHstQbLoQi1dEO3_bqcQb1udLkBW6RMoIcMuwG1DA" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | [Sat Aug 19 18:55:21.713533 2017] [auth_openidc:error] [pid 10:tid 140217503696640] [client 172.18.0.1:48664] oidc_proto_endpoint_auth_basic: no client secret is configured, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=Dy8545hMI6aUcIQXWNB-CpZD85Y&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=3twHstQbLoQi1dEO3_bqcQb1udLkBW6RMoIcMuwG1DA
openidc_1         | [Sat Aug 19 18:55:21.713558 2017] [auth_openidc:error] [pid 10:tid 140217503696640] [client 172.18.0.1:48664] oidc_proto_resolve_code_and_validate_response: failed to resolve the code, referer: http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=Dy8545hMI6aUcIQXWNB-CpZD85Y&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=3twHstQbLoQi1dEO3_bqcQb1udLkBW6RMoIcMuwG1DA
openidc_1         | 172.18.0.1 - - [19/Aug/2017:18:55:21 +0000] "GET /protected/redirect_uri?state=Dy8545hMI6aUcIQXWNB-CpZD85Y&code=DjkDeMbk0UAjhgwkLu9lv20hUjjXKeOoFJUK4A-HJv4.98dfe6c1-0721-4e5c-8e1f-0ed440c23589 HTTP/1.1" 200 335 "http://openidc/auth/realms/Testrealm/protocol/openid-connect/auth?response_type=code&scope=openid&client_id=openid1&state=Dy8545hMI6aUcIQXWNB-CpZD85Y&redirect_uri=http%3A%2F%2Fopenidc%2Fprotected%2Fredirect_uri&nonce=3twHstQbLoQi1dEO3_bqcQb1udLkBW6RMoIcMuwG1DA" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"
openidc_1         | 172.18.0.1 - - [19/Aug/2017:18:55:21 +0000] "GET /favicon.ico HTTP/1.1" 404 209 "http://openidc/protected/redirect_uri?state=Dy8545hMI6aUcIQXWNB-CpZD85Y&code=DjkDeMbk0UAjhgwkLu9lv20hUjjXKeOoFJUK4A-HJv4.98dfe6c1-0721-4e5c-8e1f-0ed440c23589" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/60.0.3112.78 Chrome/60.0.3112.78 Safari/537.36"

Are we doing something wrong after the switch from confidential to public? Everything works with 2.3.1 if I switch the client in Keycloak to confidential and re-introduce OIDCClientSecret. With confidential client and no OIDCClientSecret I get an identical error as with public.

zandbelt commented 7 years ago

By definition a public client is a client without a secret (or any other credential) and a confidential client does have one.

I believe I broke using public clients in 2.3.1 when using configuration metadata: mod_auth_openidc will (always) pick an authentication method for the token endpoint that the Provider publishes in its Discovery metadata.

Yet I would like to emphasize that using mod_auth_openidc as a public client is needlessly insecure. You should use mod_auth_openidc as a confidential client since public clients were only introduced for mobile and in-browser use cases and a so-called web client (which is what mod_auth_openidc is) is perfectly capable of keeping client secrets.

These are the options going forward:

  1. stick with 2.3.0 until I fix public clients in 2.3.2
  2. don't use OIDCMetadataURL but configure OIDCProvider* settings individually and manually; I believe that's a workaround that does allow for public clients
  3. switch to confidential clients
  4. (temporarily) apply a patch that will be included when 2.3.2 is released; I can provide that patch

My advice is 3.

solsson commented 7 years ago

Thanks for your advice, I appreciate it. Let me know if I can help with testing the patch, we've been building from source before. We're actually using mod_auth_openidc 1.x in production still, with confidential clients.

Our reason to mess with this is to support mobile applications that retrieve a token and use that for API requests. My research that lead to the decision is summarized in https://github.com/Reposoft/openidc-keycloak-test/pull/17#issuecomment-304363138. In short we're validating redirect URIs.

Are there better ways to do that than switching to public? Is there a pattern for authenticating with mod_auth_openidc as confidential client and retrieve something like an API token?

Mobile users do expect to authenticate on first use, and after that very rarely. We've been testing with code along the lines of https://github.com/Reposoft/openidc-keycloak-test/blob/171bb6e99d0fd160785f27c9548faf96a2ca91ce/build-contracts/keycloak-setup/spec.js#L41 and use that as a Bearer token to gain access through mod_auth_openidc.

zandbelt commented 7 years ago

The recommendation for mobile clients is for the app itself to be an OIDC client. It may create some credential after registering with an OpenID Connect provider using Dynamic Client Registration to increase security.

The pattern you describe is also possible, see: https://hanszandbelt.wordpress.com/2017/02/24/openid-connect-for-single-page-applications/ where you can replace "SPA" with "Mobile Client".

I have uploaded 2.3.2rc4 with an untested patch (attached) for public clients here: http://mod-auth-openidc.org/download/?C=M;O=D

mod_auth_openidc-2.3.2rc4.patch.txt

solsson commented 7 years ago

I've confirmed that the patch works with the config that previously failed (9801d65). I also noticed that an arbitrary OIDCClientSecret will have no effect with a public client; possibly a security gotcha.

Thanks for all your advice. I'd be happy to ask more questions but you've actually solved the issue already, so I'll read up on the resources and quite possibly get back through the mailing list.

Will close this issue once 2.3.2 is released.

zandbelt commented 7 years ago

What would be the security gotcha? In the end it is up to the configuration on the OP side to determine what is a public client or a confidential client no matter what the client thinks or sends. I'm not sure there's anything that can be done wrt. that.

solsson commented 7 years ago

I guess that was just a note to self. Keycloak's openid-connect clients default to public. It would be better if they default to confidential, now that we're leaning towards public being needlessly insecure. When we set up new realms we tend to copy configuration from some existing vhost and modify. There's a risk that some realm is misconfigured while appearing confidential in apache conf.