missing URL-encoding in audit log

[Andrew Morgan]

On Tue, 25 Jul 2017, Cantor, Scott wrote:

> On 7/25/17, 12:50 PM, "users on behalf of Andrew Morgan" 
> <users-bounces at shibboleth.net on behalf of morgan at orst.edu> wrote:
>
>> Here is the original Apache log entry from the client's web browser:
>
> Yes, but the URL there is encoded, once, to make it a parameter. The 
> problem is that the pipe character cannot (if that claim is correct) 
> appear *unencoded* in a URL. That means after the IdP decodes the URL 
> parameter, the unencoded URL should not have a pipe in it. The pipe has 
> to be encoded once in the original URL. It would then be double-encoded 
> when appearing in a parameter, and never appear once decoded by the web 
> server.
>
>> I'm not sure what the browser or CAS client could do differently.  The 
>> service and TARGET parameters are URL-encoded, right?
>
> Yes, but the decoded value contains an unsafe character. The CAS client 
> isn't the problem, the thing generating an unsafe URL is the problem.

Okay, I understand.

I tested this myself with a simple phpCAS client I keep around.  In my 
browser, I typed a URL and URL-encoded the | as %7C.

[25/Jul/2017:10:21:13 -0700] "GET /idp-dev/profile/cas/login?service=http%3A%2F%2Fpeople.oregonstate.edu%2F%7Emorgan%2FCAS-1.3.4%2Ftest.php%3Ffoo%3Dtest%257Cpipe HTTP/1.1" 302 450
[25/Jul/2017:10:21:56 -0700] "POST /cas-dev/samlValidate?TARGET=http%3A%2F%2Fpeople.oregonstate.edu%2F%7Emorgan%2FCAS-1.3.4%2Ftest.php%3Ffoo%3Dtest%257Cpipe HTTP/1.1" 200 12575

and the corresponding idp-process.log entries are:

2017-07-25 10:21:55,992 - INFO [net.shibboleth.idp.cas.flow.impl.GrantServiceTicketAction:123] - Granted service ticket for http://people.oregonstate.edu/~morgan/CAS-1.3.4/test.php?foo=test%7Cpipe
2017-07-25 10:21:56,001 - INFO [Shibboleth-Audit.SSO:241] - 20170725T172156Z|10.214.121.42|||http://people.oregonstate.edu/~morgan/CAS-1.3.4/test.php?foo=test%7Cpipe|https://www.apereo.org/cas/protocol/login||||morgan|||morgan|ST-1501003315986-CBaQgivpZAdA2U5q3b4lwdOTj|
2017-07-25 10:21:56,980 - INFO [net.shibboleth.idp.cas.flow.impl.ValidateTicketAction:117] - Successfully validated ST-1501003315986-CBaQgivpZAdA2U5q3b4lwdOTj for http://people.oregonstate.edu/~morgan/CAS-1.3.4/test.php?foo=test%7Cpipe
2017-07-25 10:21:57,144 - INFO [Shibboleth-Audit.SSO:241] - 20170725T172157Z|128.193.5.23|||http://people.oregonstate.edu/~morgan/CAS-1.3.4/test.php?foo=test%7Cpipe|https://www.apereo.org/cas/protocol/serviceValidate||||morgan||commonName,firstname,osuprimarymail,eduPersonAffiliation,osupidm,givenName,osuuid,lastname,uid,eduPersonPrimaryAffiliation,eduPersonScopedAffiliation,UDC_IDENTIFIER,surname,eduPersonPrincipalName,fullname,email|morgan|ST-1501003315986-CBaQgivpZAdA2U5q3b4lwdOTj|


However, it appears that my browser (Firefox) doesn't URL-encode the | for 
me.  If I type the URL with the | directly in the location bar, it will 
not automatically URL-encode it, and I get the parsing errors we have 
discussed before:

[25/Jul/2017:10:27:56 -0700] "GET /idp-dev/profile/cas/login?service=http%3A%2F%2Fpeople.oregonstate.edu%2F%7Emorgan%2FCAS-1.3.4%2Ftest.php%3Ffoo%3Dtest%7Cpipe4 HTTP/1.1" 302 316
[25/Jul/2017:10:28:27 -0700] "POST /cas-dev/samlValidate?TARGET=http%3A%2F%2Fpeople.oregonstate.edu%2F%7Emorgan%2FCAS-1.3.4%2Ftest.php%3Ffoo%3Dtest%7Cpipe4 HTTP/1.1" 200 12575

2017-07-25 10:28:27,586 - INFO [net.shibboleth.idp.cas.flow.impl.GrantServiceTicketAction:123] - Granted service ticket for http://people.oregonstate.edu/~morgan/CAS-1.3.4/test.php?foo=test|pipe4
2017-07-25 10:28:27,593 - INFO [Shibboleth-Audit.SSO:241] - 20170725T172827Z|10.214.121.42|||http://people.oregonstate.edu/~morgan/CAS-1.3.4/test.php?foo=test|pipe4|https://www.apereo.org/cas/protocol/login||||morgan|||morgan|ST-1501003707577-g1K8Yvy0X2HEfKiTACwjKD1f1|
2017-07-25 10:28:27,987 - WARN [net.shibboleth.idp.cas.service.impl.DefaultServiceComparator:86] - Error parsing http://people.oregonstate.edu/~morgan/CAS-1.3.4/test.php?foo=test|pipe4
2017-07-25 10:28:27,988 - WARN [net.shibboleth.idp.cas.service.impl.DefaultServiceComparator:86] - Error parsing http://people.oregonstate.edu/~morgan/CAS-1.3.4/test.php?foo=test|pipe4
2017-07-25 10:28:27,989 - INFO [net.shibboleth.idp.cas.flow.impl.ValidateTicketAction:117] - Successfully validated ST-1501003707577-g1K8Yvy0X2HEfKiTACwjKD1f1 for http://people.oregonstate.edu/~morgan/CAS-1.3.4/test.php?foo=test|pipe4
2017-07-25 10:28:28,155 - INFO [Shibboleth-Audit.SSO:241] - 20170725T172828Z|128.193.5.23|||http://people.oregonstate.edu/~morgan/CAS-1.3.4/test.php?foo=test|pipe4|https://www.apereo.org/cas/protocol/serviceValidate||||morgan||commonName,firstname,osuprimarymail,eduPersonAffiliation,osupidm,givenName,osuuid,lastname,uid,eduPersonPrimaryAffiliation,eduPersonScopedAffiliation,UDC_IDENTIFIER,surname,eduPersonPrincipalName,fullname,email|morgan|ST-1501003707577-g1K8Yvy0X2HEfKiTACwjKD1f1|


I can hassle some of the application owners that I see generating these 
error messages, but obviously I can't control ignorance on the internet. 
:)

I'll look into the scripted bean to encode/filter the | in the audit log 
SP field.

Thanks,
 	Andy