Not Redirecting to serviceValidate

[Ratismal]

Hello. I'm trying to use mod_auth_cas on a CentOS Apache server (httpd) v2.4.6 to restrict access to a directory.

The Problem

When accessing the restricted directory, it redirects me to the login page without issue. When redirecting from the login page back to the restricted directory (with the token), it is supposed to redirect once more to the serviceValidate with the service parameter, as well as the newly obtained token parameter. However, it instead redirects back to the login page, creating an infinite loop of redirects. The service parameter gets recreated every time with a longer length. For example, with a configuration that links the login and validate URLs to the proper URLs, this is the last URL generated before the browser stops:

http://some.site/protected?ticket=ST-1818-EHOFj3zesNhU1m9SNiac-https%3A%2F%2Fsome.site%3A8443%2Fcas&ticket=ST-1819-puVSoE4erwDNg9ctHI4L-https%3A%2F%2Fsome.site%3A8443%2Fcas&ticket=ST-1820-Hlz4vYfSrlTt93cEmY2J-https%3A%2F%2Fsome.site%3A8443%2Fcas&ticket=ST-1821-Gyj5rmHcNZfB5qebVlri-https%3A%2F%2Fsome.site%3A8443%2Fcas&ticket=ST-1822-zMUYr6TzwBfcqmMZAbYk-https%3A%2F%2Fsome.site%3A8443%2Fcas&ticket=ST-1823-z3C3QNFkJfVMiikeuSRU-https%3A%2F%2Fsome.site%3A8443%2Fcas&ticket=ST-1824-NqpKY7g7C2DlPmrXePgk-https%3A%2F%2Fsome.site%3A8443%2Fcas&ticket=ST-1825-es1sAmgWOtGmjxlcdRzi-https%3A%2F%2Fsome.site%3A8443%2Fcas&ticket=ST-1826-1S2SVE3r1O0cWXkmwneK-https%3A%2F%2Fsome.site%3A8443%2Fcas&ticket=ST-1827-ylnPEBnuHky0iWCzcgOT-https%3A%2F%2Fsome.site%3A8443%2Fcasome.site%3A8443%2Fcas

Configuration

mod_auth_cas is configured as follows:

CASVersion 2
CASDebug On
CASCookiePath /var/cache/httpd/mod_auth_cas/
CASLoginURL https://some.site/login.html
CASValidateURL https://some.site/validate.html
CASCertificatePath /opt/tomcat/conf/site.keystore

<Location /protected>
        Authtype CAS
        require valid-user
</Location>

https://some.site/login.html and https://some.site/validate.html both redirect to a page which allows me to process redirects step-by-step. It displays the GET parameters in the URL, displays whether the redirect originated from login or validate, and provides buttons to go to the login and serviceValidate pages. For example:

Debugging Procedure

As mentioned in the configuration section, I have set up an intermediary site to ease the process of redirects. The earlier screenshot refers to how the site appears when you first attempt to access the restricted directory. Next, the login button is pressed to generate a token. However, this is the response:

As you can see, the token is successfully generated. However we're redirected back to the login endpoint, which puts the token into the service parameter. Clicking validate is no good, as the token parameter is missing, and clicking the login button again results in this:

This illustrates the redirect loop experienced.

Conclusion

Any help with resolving this issue would be greatly appreciated, as I've been trying to figure this out for several weeks. If any more information is required, I will be more than happy to provide it. Thank you in advance!

[dhawes]

You should post the debug logs from mod_auth_cas here. They should tell us what we need to know.

When redirecting from the login page back to the restricted directory (with the token), it is supposed to redirect once more to the serviceValidate with the service parameter

There is no redirect for serviceValidate here. mod_auth_cas directly communicates with the CASValidateURL to validate the CAS ticket. Once that is complete, a redirect is sent to the browser to remove the ticket parameter from the URL. See the CAS protocol diagram here:

https://apereo.github.io/cas/4.2.x/protocol/CAS-Protocol.html

Post your debug logs and we'll go from there.

[Ratismal]

I set the login and validate URLs back to their proper values, took the output from tail error_log -n 1000 | grep auth and filtered it to all the resulting logs that took place at the moment of attempting to access the restricted directory. I replaced the domain names with some.site and my client IP with 192.168.0.1. This is the result: error_log_auth.log

Please let me know if this is sufficient.

[dhawes]

I should have noticed this before. The ticket:

ticket=ST-1818-EHOFj3zesNhU1m9SNiac-https%3A%2F%2Fsome.site%3A8443%2Fcas

contains characters that are not allowed by validCASTicketFormat(), which creates a redirect loop.

You can either modify your CAS server to send different STs, or modify mod_auth_cas to accept those characters.

https://github.com/apereo/mod_auth_cas/blob/v1.1/src/mod_auth_cas.c#L690

If anyone can find a link to the set of characters in a valid CAS ST, that would be useful. #134 is related.

[Ratismal]

I changed the host.name CAS property from https://some.site:8443/cas to somesite, and I'm no longer getting the redirect loop! 🎉

However, I am now getting a 401 Unauthorized error.

This server could not verify that you are authorized to access the document requested. Either you supplied the wrong credentials (e.g., bad password), or your browser doesn't understand how to supply the credentials required.

Is there anything else that I would need to change for require valid-user to work?

Edit: excerpt from error_log

[Wed Mar 14 12:35:24.169646 2018] [authz_core:debug] [pid 30353] mod_authz_core.c(809): [client 192.168.0.1:49230] AH01626: authorization result of Require valid-user : denied (no authenticated user yet)
[Wed Mar 14 12:35:24.169684 2018] [authz_core:debug] [pid 30353] mod_authz_core.c(809): [client 192.168.0.1:49230] AH01626: authorization result of <RequireAny>: denied (no authenticated user yet)
[Wed Mar 14 12:35:24.169705 2018] [:debug] [pid 30353] mod_auth_cas.c(2058): [client 192.168.0.1:49230] Entering cas_authenticate()
[Wed Mar 14 12:35:24.169734 2018] [:debug] [pid 30353] mod_auth_cas.c(652): [client 192.168.0.1:49230] Modified r->args (now '')
[Wed Mar 14 12:35:24.169981 2018] [:debug] [pid 30353] mod_auth_cas.c(1761): [client 192.168.0.1:49230] entering getResponseFromServer()
[Wed Mar 14 12:35:24.170171 2018] [:debug] [pid 30353] mod_auth_cas.c(1436): [client 192.168.0.1:49230] entering isValidCASTicket()

[dhawes]

Is that the last entry in the error log? The next thing that should be printed is the server response. If there was no response, you'll get a 401.

Based on what you've said here about your setup, I expect you're getting stuck on the service validation, which is done by mod_auth_cas and not the user. Check the webserver logs on your intermediary site. I expect you'll see the request from mod_auth_cas to the CASValidateURL.

[Ratismal]

Yes, that's the last entry of in the error log; it's denying access before calling cas_authenticate(), and then stops after it enters isValidCASTicket().

I checked the CAS logs, and could not find any entries whatsoever when attempting to access the restricted directory, so I don't think a request is being made.

[dhawes]

What happens when you use the actual /serviceValidate URL of your CAS server for CASValidateURL?

[Ratismal]

I have been using the actual serviceValidate URL. CAS does not show in the logs that a request was ever made. Visiting the serviceValidate URL in a browser does create logs.

[dhawes]

I would expect either a curl error in your logs or a validation response. From the line numbers, you are using v1.1, right?

Are you comfortable modifying the source to add more debug messages? I can help you with this if you'd like.

[Ratismal]

I'm not sure how to check what version I'm using, but yes I'd be comfortable with modifying the source. Just let me know where to put the debug messages.

[dhawes]

Try this branch (based on master) and post your logs:

https://github.com/dhawes/mod_auth_cas/tree/issue-145-service-validate

[Ratismal]

[Thu Mar 15 11:48:59.557672 2018] [authz_core:debug] [pid 4855] mod_authz_core.c(809): [client 192.168.0.1:62623] AH01626: authorization result of Require valid-user : denied (no authenticated user yet)
[Thu Mar 15 11:48:59.557706 2018] [authz_core:debug] [pid 4855] mod_authz_core.c(809): [client 192.168.0.1:62623] AH01626: authorization result of <RequireAny>: denied (no authenticated user yet)
[Thu Mar 15 11:48:59.557716 2018] [auth_cas:debug] [pid 4855] mod_auth_cas.c(2076): [client 192.168.0.1:62623] Entering cas_authenticate()
[Thu Mar 15 11:48:59.557725 2018] [auth_cas:debug] [pid 4855] mod_auth_cas.c(656): [client 192.168.0.1:62623] Modified r->args (now '')
[Thu Mar 15 11:48:59.557807 2018] [auth_cas:debug] [pid 4855] mod_auth_cas.c(1779): [client 192.168.0.1:62623] entering getResponseFromServer()
[Thu Mar 15 11:48:59.557887 2018] [auth_cas:error] [pid 4855] [client 192.168.0.1:62623] MOD_AUTH_CAS: Could not process Certificate Authority: /opt/tomcat/conf/somesite.keystore
[Thu Mar 15 11:48:59.557910 2018] [auth_cas:debug] [pid 4855] mod_auth_cas.c(1440): [client 192.168.0.1:62623] entering isValidCASTicket()

So, there would appear to be an issue with the CAS certificate.

It should be noted that I was not the one who initially created this system; it was created by another group who left little to no documentation. I'm not entirely sure what the somesite.keystore actually is, but it would appear to be completely invalid. I realize that this is drifting away slightly from the scope of mod_auth_cas, but would you happen to know how I might be able to generate a valid certificate?

[dhawes]

I'd expect it's a Java keystore. You can export the certs from there, but honestly I would just:

openssl s_client -connect -showcerts cas.server:443

, copy the certs into a file called cachain.pem, and then:

CASCertificatePath /path/to/cachain.pem

[Ratismal]

I did the following:

echo "" | openssl s_client -connect some.site:8443 -prexit 2>/dev/null | sed -n -e '/BEGIN\ CERTIFICATE/,/END\ CERTIFICATE/ p' > cachain.pem

And entered the path to that file into theCASCertificatePath. I'm still getting the same error.

Are there any specific permissions I should be assigning the keychain? This is what it currently is:

-rw-r--r--. 1 apache apache   3594 Mar 15 12:45 cachain.pem

[Ratismal]

My bad, the certificate file was in a directory that apache could not access. I'm now getting this error:

[Thu Mar 15 12:52:14.377176 2018] [auth_cas:debug] [pid 7735] mod_auth_cas.c(1848): [client 192.168.0.1:63427] MOD_AUTH_CAS: curl_easy_perform() failed (Peer's Certificate issuer is not recognized.)

Edit: moving the original somesite.keystore file into an accessible directory and using it returns this error:

[Thu Mar 15 12:54:05.687043 2018] [auth_cas:debug] [pid 7812] mod_auth_cas.c(1848): [client 192.168.0.1:63464] MOD_AUTH_CAS: curl_easy_perform() failed (\x91ae\xbf)

[dhawes]

Sounds like a simple CA trust issue now.

You didn't use -showcerts with s_client. Is the complete chain in your cachain.pem?

[Ratismal]

I tried with -showcerts which had one certificate, and with -prexit which had 2. Neither worked.

I copied the keychain that apache itself was using into an accessible directory and linked that, and now it's working fine 🎉 Obviously it's not a very succinct solution as it'll break when the cert needs renewing, but I can deal with that on my own.

Thank you so much for all your help! I really appreciate you taking the time out of your day to help me. I would not have been able to figure this out on my own. Thanks!

[dhawes]

Excellent, I'm glad it's all working now.

This wasn't my best troubleshooting ever. I should have noticed the ST characters off the bat and I wish I had noted the .keystore file, but we got there eventually, right? ;)

[Ratismal]

Nah you were fine! I didn't notice those either ;3