CAS validation error

[IAM David Bantz]

 A CAS service is triggering an error on initial login (oddly, a second
attempted login usually works). First serious attempt to include a CAS
service, so struggling to comprehend this sequence. Pointers appreciated.


> 09:57:48:748  DEBUG [10.5.0.58]
> net.shibboleth.idp.cas.flow.impl.GrantServiceTicketAction:89 >  *Granting
> service ticket* for
> https://temsprep.alaska.edu:9022/tvlexp/tvlexp-flex/index.html;GLMSSESSIONID=4WBeKYKm5WrhFV87HlxEpnVAIwqx9VcNv0pj3uvKXZu4mjDG3kIp!494185068
>


> 09:57:48:749  DEBUG [10.5.0.58]
> net.shibboleth.idp.cas.ticket.impl.SimpleTicketService:193 >  Storing
> ST-1491933468748-MDJg4Q0lXaLvbcxp4PQrzruDr in context
> https://www.apereo.org/cas/protocol/login
>


> 09:57:48:749  INFO [10.5.0.58]
> net.shibboleth.idp.cas.flow.impl.GrantServiceTicketAction:100 >  *Granted
> service ticket* for
> https://temsprep.alaska.edu:9022/tvlexp/tvlexp-flex/index.html;GLMSSESSIONID=4WBeKYKm5WrhFV87HlxEpnVAIwqx9VcNv0pj3uvKXZu4mjDG3kIp!494185068
>


> 09:57:48:751  INFO [10.5.0.58] Shibboleth-Audit.SSO:241 >
> 20170411T175748Z||b7d0bb4f97d7234a13c97bdaa26db904f334d119480fdef08ba107c47471157d|
> https://temsprep.alaska.edu:9022/tvlexp/tvlexp-flex/index.html;GLMSSESSIONID=4WBeKYKm5WrhFV87HlxEpnVAIwqx9VcNv0pj3uvKXZu4mjDG3kIp!494185068|https://www.apereo.org/cas/protocol/login||||lttoth|||lttoth|ST-1491933468748-MDJg4Q0lXaLvbcxp4PQrzruDr|
>

immediately after, the IdP receives this request:


> 09:57:48:858  DEBUG [137.229.13.137]
> org.opensaml.saml.saml1.binding.decoding.impl.HTTPSOAP11Decoder:59 >
> Decoded SOAP messaged which included SAML message of type
> {urn:oasis:names:tc:SAML:1.0:protocol}Request
>


> 09:57:48:861  DEBUG [137.229.13.137] PROTOCOL_MESSAGE:121 >
> <?xml version="1.0" encoding="UTF-8"?>
> <SOAP-ENV:Envelope xmlns:SOAP-ENV="
> http://schemas.xmlsoap.org/soap/envelope/">
>     <SOAP-ENV:Header/>
>     <SOAP-ENV:Body>
>         <samlp:Request IssueInstant="2002-06-19T17:03:44.022Z"
>             MajorVersion="1" MinorVersion="1"
>             RequestID="_192.168.16.51.1024506224022"
> xmlns:samlp="urn:oasis:names:tc:SAML:1.0:protocol">
>
> <samlp:AssertionArtifact>ST-1491933468748-MDJg4Q0lXaLvbcxp4PQrzruDr</samlp:AssertionArtifact>
>         </samlp:Request>
>     </SOAP-ENV:Body>
> </SOAP-ENV:Envelope>
>

[...IdP determines default relying party is applicable...]

>
> 09:57:48:875  DEBUG [137.229.13.137]
> net.shibboleth.idp.cas.flow.impl.ValidateTicketAction:92 >  *Attempting
> to validate* ST-1491933468748-MDJg4Q0lXaLvbcxp4PQrzruDr
>


> 09:57:48:876  DEBUG [137.229.13.137]
> net.shibboleth.idp.cas.ticket.impl.SimpleTicketService:226 >  Reading
> ST-1491933468748-MDJg4Q0lXaLvbcxp4PQrzruDr
>


> 09:57:48:877  DEBUG [137.229.13.137]
> net.shibboleth.idp.cas.ticket.impl.SimpleTicketService:215 >  *Attempting
> to delete* ST-1491933468748-MDJg4Q0lXaLvbcxp4PQrzruDr from context
> https://www.apereo.org/cas/protocol/login
>


> 09:57:48:877  DEBUG [137.229.13.137]
> net.shibboleth.idp.cas.flow.impl.ValidateTicketAction:101 >  *Found and
> removed*
> ST-1491933468748-MDJg4Q0lXaLvbcxp4PQrzruDr/b7d0bb4f97d7234a13c97bdaa26db904f334d119480fdef08ba107c47471157d
> from ticket store
>


> 09:57:48:878  DEBUG [137.229.13.137]
> net.shibboleth.idp.cas.flow.impl.ValidateTicketAction:113 >  *Service
> issued* for
> https://temsprep.alaska.edu:9022/tvlexp/tvlexp-flex/index.html;GLMSSESSIONID=4WBeKYKm5WrhFV87HlxEpnVAIwqx9VcNv0pj3uvKXZu4mjDG3kIp!494185068 *does
> not match* https://temsprep.alaska.edu:9022/tvlexp/tvlexp-flex/index.html
>


> 09:57:48:880  INFO [137.229.13.137] Shibboleth-Audit.SSO:241 >
> 20170411T175748Z|||
> https://temsprep.alaska.edu:9022/tvlexp/tvlexp-flex/index.html|https://www.apereo.org/cas/protocol/serviceValidate||||||||ST-1491933468748-MDJg4Q0lXaLvbcxp4PQrzruDr|
>


> 09:57:48:882  DEBUG [137.229.13.137]
> net.shibboleth.idp.saml.profile.impl.SpringAwareMessageEncoderFactory:100
> >  Looking up message encoder based on binding URI:
> urn:oasis:names:tc:SAML:1.0:bindings:SOAP-binding
>


> 09:57:48:885  DEBUG [137.229.13.137] PROTOCOL_MESSAGE:70 >
> <?xml version="1.0" encoding="UTF-8"?>
> <SOAP-ENV:Envelope xmlns:SOAP-ENV="
> http://schemas.xmlsoap.org/soap/envelope/">
>     <SOAP-ENV:Body>
>         <saml1p:Response IssueInstant="2017-04-11T17:57:48.881Z"
>             MajorVersion="1" MinorVersion="1"
>             ResponseID="ST-1491933468748-MDJg4Q0lXaLvbcxp4PQrzruDr"
> xmlns:saml1p="urn:oasis:names:tc:SAML:1.0:protocol">
>             <saml1p:Status>
>                 <saml1p:*StatusCode Value="INVALID_SERVICE"* xmlns="
> http://www.ja-sig.org/products/cas/"/>
>                 <saml1p:StatusMessage>*E_SERVICE_MISMATCH*
> </saml1p:StatusMessage>
>             </saml1p:Status>
>         </saml1p:Response>
>     </SOAP-ENV:Body>
> </SOAP-ENV:Envelope>
> 09:57:48:886  DEBUG [137.229.13.137]
> net.shibboleth.idp.profile.impl.RecordResponseComplete:89 >  Profile Action
> RecordResponseComplete: Record response complete


David Bantz
UA OIT IAM
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://shibboleth.net/pipermail/users/attachments/20170411/ef88d4a3/attachment.html>