shib session not accepted for vhosts with different IPs

[el.ster]

Dear experts,

Thank you for your valuable input. Meanwhile I got the native logs from both
systems with all possible log levels set to DEBUG. Both systems start with
an initial request no.1, followed by a subsequent request. In that
subsequent request, on the working system a method named shib_auth_checker
is entered while on the failing system another subsequent request is
received, followed by an endless loop of these same subsequent requests:

Working:
[Mon Aug 24 15:23:34.852397 2020] [ssl:debug] [pid 109042:tid
140101722851072] ssl_engine_kernel.c(377): [client 139.25.88.150:57191]
AH02034: Initial (No.1) HTTPS request received for child 193 (server
sp.example.com:443), referer: https://idp.example.com/
[Mon Aug 24 15:23:34.852417 2020] [mod_shib:debug] [pid 109042:tid
140101722851072] mod_shib.cpp(369): [client 139.25.88.150:57191]
get_request_config created per-request structure, referer:
https://idp.example.com/
[Mon Aug 24 15:23:34.852612 2020] [mod_shib:debug] [pid 109042:tid
140101722851072] mod_shib.cpp(1613): [client 139.25.88.150:57191]
shib_base_check_authz found uninitialized request object, referer:
https://idp.example.com/
[Mon Aug 24 15:23:34.852619 2020] [authz_core:debug] [pid 109042:tid
140101722851072] mod_authz_core.c(820): [client 139.25.88.150:57191]
AH01626: authorization result of Require shib-session : denied (no
authenticated user yet), referer: https://idp.example.com/
[Mon Aug 24 15:23:34.852624 2020] [authz_core:debug] [pid 109042:tid
140101722851072] mod_authz_core.c(820): [client 139.25.88.150:57191]
AH01626: authorization result of <RequireAny>: denied (no authenticated user
yet), referer: https://idp.example.com/
[Mon Aug 24 15:23:34.852635 2020] [mod_shib:debug] [pid 109042:tid
140101722851072] mod_shib.cpp(783): [client 139.25.88.150:57191]
shib_check_user entered in pid (109042), referer: https://idp.example.com/
[Mon Aug 24 15:23:34.887648 2020] [headers:debug] [pid 109042:tid
140101722851072] mod_headers.c(900): AH01503: headers:
ap_headers_error_filter()
[Mon Aug 24 15:23:34.948886 2020] [ssl:debug] [pid 109042:tid
140101722851072] ssl_engine_kernel.c(377): [client 139.25.88.150:57191]
AH02034: Subsequent (No.2) HTTPS request received for child 193 (server
sp.example.com:443), referer: https://idp.example.com/
[Mon Aug 24 15:23:34.948920 2020] [mod_shib:debug] [pid 109042:tid
140101722851072] mod_shib.cpp(369): [client 139.25.88.150:57191]
get_request_config created per-request structure, referer:
https://idp.example.com/
[Mon Aug 24 15:23:34.949094 2020] [mod_shib:debug] [pid 109042:tid
140101722851072] mod_shib.cpp(1613): [client 139.25.88.150:57191]
shib_base_check_authz found uninitialized request object, referer:
https://idp.example.com/
[Mon Aug 24 15:23:34.949106 2020] [authz_core:debug] [pid 109042:tid
140101722851072] mod_authz_core.c(820): [client 139.25.88.150:57191]
AH01626: authorization result of Require shib-session : denied (no
authenticated user yet), referer: https://idp.example.com/
[Mon Aug 24 15:23:34.949110 2020] [authz_core:debug] [pid 109042:tid
140101722851072] mod_authz_core.c(820): [client 139.25.88.150:57191]
AH01626: authorization result of <RequireAny>: denied (no authenticated user
yet), referer: https://idp.example.com/
[Mon Aug 24 15:23:34.949115 2020] [mod_shib:debug] [pid 109042:tid
140101722851072] mod_shib.cpp(783): [client 139.25.88.150:57191]
shib_check_user entered in pid (109042), referer: https://idp.example.com/
[Mon Aug 24 15:23:34.950142 2020] [mod_shib:debug] [pid 109042:tid
140101722851072] mod_shib.cpp(934): [client 139.25.88.150:57191]
shib_auth_checker entered in pid (109042), referer: https://idp.example.com/
[Mon Aug 24 15:23:34.950180 2020] [mod_shib:debug] [pid 109042:tid
140101722851072] mod_shib.cpp(486): [client 139.25.88.150:57191] htaccess:
accepting shib-session/valid-user based on active session, referer:
https://idp.example.com/

Non-working:
[Mon Aug 24 15:38:01.324989 2020] [ssl:debug] [pid 112809:tid
139841719236352] ssl_engine_kernel.c(377): [client 139.25.88.150:57610]
AH02034: Initial (No.1) HTTPS request received for child 130 (server
sp.example.com:443), referer: https://idp.example.com/
[Mon Aug 24 15:38:01.325010 2020] [mod_shib:debug] [pid 112809:tid
139841719236352] mod_shib.cpp(369): [client 139.25.88.150:57610]
get_request_config created per-request structure, referer:
https://idp.example.com/
[Mon Aug 24 15:38:01.325214 2020] [mod_shib:debug] [pid 112809:tid
139841719236352] mod_shib.cpp(1613): [client 139.25.88.150:57610]
shib_base_check_authz found uninitialized request object, referer:
https://idp.example.com/
[Mon Aug 24 15:38:01.325222 2020] [authz_core:debug] [pid 112809:tid
139841719236352] mod_authz_core.c(820): [client 139.25.88.150:57610]
AH01626: authorization result of Require shib-session : denied (no
authenticated user yet), referer: https://idp.example.com/
[Mon Aug 24 15:38:01.325226 2020] [authz_core:debug] [pid 112809:tid
139841719236352] mod_authz_core.c(820): [client 139.25.88.150:57610]
AH01626: authorization result of <RequireAny>: denied (no authenticated user
yet), referer: https://idp.example.com/
[Mon Aug 24 15:38:01.325236 2020] [mod_shib:debug] [pid 112809:tid
139841719236352] mod_shib.cpp(783): [client 139.25.88.150:57610]
shib_check_user entered in pid (112809), referer: https://idp.example.com/
[Mon Aug 24 15:38:01.359428 2020] [headers:debug] [pid 112809:tid
139841719236352] mod_headers.c(900): AH01503: headers:
ap_headers_error_filter()
[Mon Aug 24 15:38:01.400030 2020] [ssl:debug] [pid 112809:tid
139841719236352] ssl_engine_kernel.c(377): [client 139.25.88.150:57610]
AH02034: Subsequent (No.2) HTTPS request received for child 130 (server
sp.example.com:443), referer: https://idp.example.com/
[Mon Aug 24 15:38:01.400053 2020] [mod_shib:debug] [pid 112809:tid
139841719236352] mod_shib.cpp(369): [client 139.25.88.150:57610]
get_request_config created per-request structure, referer:
https://idp.example.com/
[Mon Aug 24 15:38:01.400163 2020] [mod_shib:debug] [pid 112809:tid
139841719236352] mod_shib.cpp(1613): [client 139.25.88.150:57610]
shib_base_check_authz found uninitialized request object, referer:
https://idp.example.com/
[Mon Aug 24 15:38:01.400176 2020] [authz_core:debug] [pid 112809:tid
139841719236352] mod_authz_core.c(820): [client 139.25.88.150:57610]
AH01626: authorization result of Require shib-session : denied (no
authenticated user yet), referer: https://idp.example.com/
[Mon Aug 24 15:38:01.400180 2020] [authz_core:debug] [pid 112809:tid
139841719236352] mod_authz_core.c(820): [client 139.25.88.150:57610]
AH01626: authorization result of <RequireAny>: denied (no authenticated user
yet), referer: https://idp.example.com/
[Mon Aug 24 15:38:01.400186 2020] [mod_shib:debug] [pid 112809:tid
139841719236352] mod_shib.cpp(783): [client 139.25.88.150:57610]
shib_check_user entered in pid (112809), referer: https://idp.example.com/
[Mon Aug 24 15:38:01.401745 2020] [headers:debug] [pid 112809:tid
139841719236352] mod_headers.c(900): AH01503: headers:
ap_headers_error_filter()
[Mon Aug 24 15:38:01.552481 2020] [ssl:debug] [pid 112809:tid
139841719236352] ssl_engine_kernel.c(377): [client 139.25.88.150:57610]
AH02034: Subsequent (No.3) HTTPS request received for child 130 (server
sp.example.com:443), referer: https://idp.example.com/
[Mon Aug 24 15:38:01.552515 2020] [mod_shib:debug] [pid 112809:tid
139841719236352] mod_shib.cpp(369): [client 139.25.88.150:57610]
get_request_config created per-request structure, referer:
https://idp.example.com/
[Mon Aug 24 15:38:01.552640 2020] [mod_shib:debug] [pid 112809:tid
139841719236352] mod_shib.cpp(1613): [client 139.25.88.150:57610]
shib_base_check_authz found uninitialized request object, referer:
https://idp.example.com/
[Mon Aug 24 15:38:01.552646 2020] [authz_core:debug] [pid 112809:tid
139841719236352] mod_authz_core.c(820): [client 139.25.88.150:57610]
AH01626: authorization result of Require shib-session : denied (no
authenticated user yet), referer: https://idp.example.com/
[Mon Aug 24 15:38:01.552650 2020] [authz_core:debug] [pid 112809:tid
139841719236352] mod_authz_core.c(820): [client 139.25.88.150:57610]
AH01626: authorization result of <RequireAny>: denied (no authenticated user
yet), referer: https://idp.example.com/
[Mon Aug 24 15:38:01.552656 2020] [mod_shib:debug] [pid 112809:tid
139841719236352] mod_shib.cpp(783): [client 139.25.88.150:57610]
shib_check_user entered in pid (112809), referer: https://idp.example.com/

Any ideas why the non-working system doesn't make it into the
shib_auth_checker method?

Thanks and br,
Elmar




--
Sent from: https://shibboleth.1660669.n2.nabble.com/Shibboleth-Users-f1660767.html