[Using Sakai] CAS related sakai problem
Anders Nordkvist
anders.nordqvist at his.se
Tue Apr 3 06:37:58 PDT 2012
Hi,
I have now captured the http-headers! I don't know what to get of them though!
I logged in to the studentportalen.his.se and it worked fine. I suppose I have to log in when it's not working to see the headers!
Regards
Anders Nordkvist
System administrator
University Of Skövde
Sweden
-----Original Message-----
From: Shoji Kajita [mailto:kajita at nagoya-u.jp]
Sent: den 29 mars 2012 13:15
To: Anders Nordkvist
Cc: Steve Swinsburg; Sakai User
Subject: Re: [Using Sakai] CAS related sakai problem
Hi,
Can you caputre HTTP responses by CAS server, using LiveHTTPHeaders http://livehttpheaders.mozdev.org/ ?
We have recently integrated sakai-2.9.x with cas-server-3.4.11.
Shoji at Kyoto University
At Thu, 29 Mar 2012 11:01:34 +0000,
Anders Nordkvist wrote:
>
> Hi,
>
> We have a Uportal framework which sakai is integreted in (studentportalen.his.se). The CAS-server is used for both Sakai and Uportal.
> Students log in via CAS to studentportalen.his.se and personal via CAS to scio.his.se (because they don't need to get into the portal).
>
>
> Regards
> Anders Nordkvist
> System administrator
> University Of Skövde
> Sweden
>
>
>
>
> -----Original Message-----
> From: Steve Swinsburg [mailto:steve.swinsburg at gmail.com]
> Sent: den 29 mars 2012 12:50
> To: Anders Nordkvist
> Cc: Andrew Petro; Sakai User
> Subject: Re: [Using Sakai] CAS related sakai problem
>
> Hi Anders,
>
> The service ticket has been granted for scio.his.se (Sakai) but the error message is coming from studentportalen.his.se (uPortal). Are you sure those are the logs for this particular issue?
>
> cheers,
> Steve
>
>
> On 29/03/2012, at 9:08 PM, Anders Nordkvist wrote:
>
> > Hi,
> >
> > The problem is ocurring quite often. It seems to help to restart our CAS-servers then the logs in Sakai are not showing anymore and everything seems normal for a while. This is the catalina.out logs from CAS1 with the same ticket as from the other logs:
>
> >
> >
> > 2012-03-23 10:53:32,090 INFO
> > [org.jasig.cas.CentralAuthenticationServiceImpl] - <Granted service
> > ticket [ST-408-N0ZlV2izrLYiEZ4qficK-cas] for service
> > [http://scio.his.se/sakai-login-tool/container] for user [***]>
> > WHAT: ST-408-N0ZlV2izrLYiEZ4qficK-cas for
> > http://scio.his.se/sakai-login-tool/container
> >
> >
> >
> > Here is the cas.out log:
> >
> > 2012-03-23 10:51:06,786 WARN [org.jasig.cas.util.HttpClient] - Error
> > Sending message to url endpoint
> > [https://studentportalen.his.se/uPortal/Login]. Error is [Server
> > redirected too many times (20)]
> > 2012-03-23 10:53:58,651 WARN [org.jasig.cas.util.HttpClient] - Error
> > Sending message to url endpoint
> > [https://studentportalen.his.se/uPortal/Login]. Error is [Server
> > redirected too many times (20)]
> > 2012-03-23 10:54:24,499 WARN [org.jasig.cas.util.HttpClient] - Error
> > Sending message to url endpoint
> > [https://studentportalen.his.se/uPortal/Login]. Error is [Server
> > redirected too many times (20)]
> >
> > (this "server redirected to many times" log occur every day at all
> > times)
> >
> >
> >
> > This is the cas.log from the other cas- server (CAS2). I couldn't find the ticket from 23/3 so I have taken one from today instead (we had the same issue today so the Sakai logs are like below). I have masked some things out:
> >
> >
> > 2012-03-29 10:54:09,944 INFO [org.jasig.cas.CentralAuthenticationServiceImpl] - ServiceTicket [ST-24382-cQw9f70fOCYblCYVf0nt-cas] has expired.
> > 2012-03-29 10:54:09,945 INFO
> > [com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager] -
> > Audit trail record BEGIN
> > =============================================================
> > WHO: audit:unknown
> > WHAT: ST-24382-cQw9f70fOCYblCYVf0nt-cas
> > ACTION: SERVICE_TICKET_VALIDATE_FAILED
> > APPLICATION: CAS
> > WHEN: Thu Mar 29 10:54:09 CEST 2012
> > CLIENT IP ADDRESS: 193.10.***.*** (out netscaler server) SERVER IP
> > ADDRESS: 193.10.***.*** (our cas2 server)
> >
> >
> > Steve, if you mean the database in the back it's a mysql database (not clustered). The database is virtual and stores both CAS and Sakai. we have had some performance issues with it lately which ended in bosting it up with two CPU's (4 CPU's now).
> >
> >
> > Regards
> > Anders Nordkvist
> > System administrator
> > University Of Skövde
> > Sweden
> >
> >
> >
> > -----Original Message-----
> > From: sakai-user-bounces at collab.sakaiproject.org
> > [mailto:sakai-user-bounces at collab.sakaiproject.org] On Behalf Of
> > Andrew Petro
> > Sent: den 25 mars 2012 15:08
> > To: Sakai User
> > Subject: Re: [Using Sakai] CAS related sakai problem
> >
> > Anders,
> >
> > While you might get better logging with the latest Jasig Java CAS Client, there's no problem with the legacy Yale Java CAS Client such that it would be unsuccessful in validating a service ticket.
> >
> > I agree the SSL issue should be addressed. CAS service tickets should be presented to Sakai over https:// rather than http:// to prevent man-in-the-middle attacks involving those service tickets being intercepted and illicitly used by adversaries to log in to Sakai as the end user.
> >
> > What I think you're saying is that every month or so, a service ticket fails to validate. Ok. But service tickets failing to validate aren't in themselves a particularly surprising -- service tickets are short-lived one-time-use tokens. They can be invalid because they've expired, i.e., crazy long delays between issue and validation stemming from network or browser slowness. They can be invalid because they've already been validated once, i.e., user stepped back through browser history or reloaded with the ticket on the URL. Having that sort of thing happen every month or so could be within normal parameters.
> >
> > Or it could be a real problem. Steve's question is interesting, and latency in ticket replication such that the other CAS server node is not yet aware of a service ticket being validated could certainly cause this issue.
> >
> > I wonder what your CAS server logs have to say about this? In particular, if you're running a recent enough version of CAS and are using the Inspektr-implemented audit logging feature, that could provide a relatively clean history of what happened with what tickets when, and could let you know (through some interpretation of the logs) if the specific service ticket id that's failing to validate is failing because of expiration, because of having already been validated, or because the CAS server node asked isn't aware of it at all.
> >
> > Kind regards,
> >
> > Andrew
> >
> >
> >
> >
> > On Mar 24, 2012, at 4:56 AM, Steve Swinsburg wrote:
> >
> >> First thing would be to use the Jasig cas client rather than the Yale one.
> >>
> >> The ssl issue Sam noted also should be addressed.
> >>
> >> Also, what's the ticket registry storage on the CAS server? We used to use a jpa database backend which was clustered but not replicating fast enough so it was causing this exact issue.
> >>
> >> Cheers
> >> Steve
> >>
> >>
> >> Sent from my iPhone
> >>
> >> On 24/03/2012, at 1:49, Sam Ottenhoff <ottenhoff at longsight.com> wrote:
> >>
> >>> It seems like your Sakai is running on HTTPS:
> >>> https://scio.his.se/portal
> >>>
> >>> But your service parameter to CAS is saying that you are running
> >>> on plain HTTP:
> >>> service=http%3A%2F%2Fscio.his.se%2Fsakai-login-tool%2Fcontainer
> >>>
> >>> --Sam
> >>>
> >>> On Fri, Mar 23, 2012 at 10:38 AM, Anders Nordkvist <anders.nordqvist at his.se> wrote:
> >>> Hi,
> >>>
> >>>
> >>>
> >>> We have sakai version 2.7.X and use CAS version 3.4.6 for
> >>> authentication. We have two Sakai nodes and two CAS nodes in a
> >>> load balanced environment. We use a mysql database server. Today
> >>> we had a rather strange problem. A problem that's returning with
> >>> say a month interval. The problem is that Sakai users get this
> >>> error log when logging in to our CAS authentication server:tus500
> >>> -
> >>>
> >>> type Exception report
> >>>
> >>> message
> >>>
> >>> description The server encountered an internal error () that prevented it from fulfilling this request.
> >>>
> >>> exception
> >>>
> >>> javax.servlet.ServletException: Unable to validate
> >>> ProxyTicketValidator
> >>> [[edu.yale.its.tp.cas.client.ProxyTicketValidator proxyList=[null]
> >>> [edu.yale.its.tp.cas.client.ServiceTicketValidator
> >>> casValidateUrl=[https://hscas.his.se/cas/serviceValidate]
> >>> ticket=[ST-408-N0ZlV2izrLYiEZ4qficK-cas]
> >>> service=[http%3A%2F%2Fscio.his.se%2Fsakai-login-tool%2Fcontainer]
> >>> errorCode=[INVALID_TICKET] errorMessage=[ticket
> >>> 'ST-408-N0ZlV2izrLYiEZ4qficK-cas' not recognized] renew=false
> >>> entireResponse=[<cas:serviceResponse
> >>> xmlns:cas='http://www.yale.edu/tp/cas'>
> >>>
> >>> <cas:authenticationFailure code='INVALID_TICKET'>
> >>>
> >>> ticket 'ST-408-N0ZlV2izrLYiEZ4qficK-cas'
> >>> not recognized
> >>>
> >>> </cas:authenticationFailure>
> >>>
> >>> </cas:serviceResponse>
> >>>
> >>> ]]]]
> >>>
> >>>
> >>> edu.yale.its.tp.cas.client.filter.CASFilter.doFilter(CASFilter.java:
> >>> 381)
> >>>
> >>>
> >>> org.sakaiproject.util.RequestFilter.doFilter(RequestFilter.java:65
> >>> 8)
> >>>
> >>> root cause
> >>>
> >>> edu.yale.its.tp.cas.client.CASAuthenticationException: Unable to
> >>> validate ProxyTicketValidator
> >>> [[edu.yale.its.tp.cas.client.ProxyTicketValidator proxyList=[null]
> >>> [edu.yale.its.tp.cas.client.ServiceTicketValidator
> >>> casValidateUrl=[https://hscas.his.se/cas/serviceValidate]
> >>> ticket=[ST-408-N0ZlV2izrLYiEZ4qficK-cas]
> >>> service=[http%3A%2F%2Fscio.his.se%2Fsakai-login-tool%2Fcontainer]
> >>> errorCode=[INVALID_TICKET] errorMessage=[ticket
> >>> 'ST-408-N0ZlV2izrLYiEZ4qficK-cas' not recognized] renew=false
> >>> entireResponse=[<cas:serviceResponse
> >>> xmlns:cas='http://www.yale.edu/tp/cas'>
> >>>
> >>> <cas:authenticationFailure code='INVALID_TICKET'>
> >>>
> >>> ticket 'ST-408-N0ZlV2izrLYiEZ4qficK-cas'
> >>> not recognized
> >>>
> >>> </cas:authenticationFailure>
> >>>
> >>> </cas:serviceResponse>
> >>>
> >>> ]]]]
> >>>
> >>>
> >>> edu.yale.its.tp.cas.client.CASReceipt.getReceipt(CASReceipt.java:6
> >>> 2)
> >>>
> >>>
> >>> edu.yale.its.tp.cas.client.filter.CASFilter.getAuthenticatedUser(C
> >>> AS
> >>> Filter.java:455)
> >>>
> >>>
> >>> edu.yale.its.tp.cas.client.filter.CASFilter.doFilter(CASFilter.java:
> >>> 378)
> >>>
> >>>
> >>> org.sakaiproject.util.RequestFilter.doFilter(RequestFilter.java:65
> >>> 8)
> >>>
> >>> note The full stack trace of the root cause is available in the Apache Tomcat/5.5.31 logs.
> >>>
> >>>
> >>>
> >>> This is the log from one of our Sakai nodes:
> >>>
> >>>
> >>>
> >>> 2012-03-23 10:53:49,883 ERROR http-8080-Processor6
> >>> edu.yale.its.tp.cas.client.CASReceipt - validation of
> >>> [[edu.yale.its.tp.cas.client.ProxyTicketValidator proxyList=[null]
> >>> [edu.yale.its.tp.cas.client.ServiceTicketValidator
> >>> casValidateUrl=[https://hscas.his.se/cas/serviceValidate]
> >>> ticket=[ST-408-N0ZlV2izrLYiEZ4qficK-cas]
> >>> service=[http%3A%2F%2Fscio.his.se%2Fsakai-login-tool%2Fcontainer]
> >>> errorCode=[INVALID_TICKET] errorMessage=[ticket
> >>> 'ST-408-N0ZlV2izrLYiEZ4qficK-cas' not recognized] renew=false
> >>> entireResponse=[<cas:serviceResponse
> >>> xmlns:cas='http://www.yale.edu/tp/cas'>
> >>>
> >>> <cas:authenticationFailure code='INVALID_TICKET'>
> >>>
> >>> ticket 'ST-408-N0ZlV2izrLYiEZ4qficK-cas'
> >>> not recognized
> >>>
> >>> </cas:authenticationFailure>
> >>>
> >>> </cas:serviceResponse>
> >>>
> >>> ]]]] was not successful.
> >>>
> >>> 2012-03-23 10:53:49,883 ERROR http-8080-Processor6
> >>> edu.yale.its.tp.cas.client.filter.CASFilter -
> >>> edu.yale.its.tp.cas.client.CASAuthenticationException: Unable to
> >>> validate ProxyTicketValidator
> >>> [[edu.yale.its.tp.cas.client.ProxyTicketValidator proxyList=[null]
> >>> [edu.yale.its.tp.cas.client.ServiceTicketValidator
> >>> casValidateUrl=[https://hscas.his.se/cas/serviceValidate]
> >>> ticket=[ST-408-N0ZlV2izrLYiEZ4qficK-cas]
> >>> service=[http%3A%2F%2Fscio.his.se%2Fsakai-login-tool%2Fcontainer]
> >>> errorCode=[INVALID_TICKET] errorMessage=[ticket
> >>> 'ST-408-N0ZlV2izrLYiEZ4qficK-cas' not recognized] renew=false
> >>> entireResponse=[<cas:serviceResponse
> >>> xmlns:cas='http://www.yale.edu/tp/cas'>
> >>>
> >>> <cas:authenticationFailure code='INVALID_TICKET'>
> >>>
> >>> ticket 'ST-408-N0ZlV2izrLYiEZ4qficK-cas'
> >>> not recognized
> >>>
> >>> </cas:authenticationFailure>
> >>>
> >>> </cas:serviceResponse>
> >>>
> >>> ]]]]
> >>>
> >>> 2012-03-23 10:53:49,884 WARN http-8080-Processor6
> >>> org.sakaiproject.util.RequestFilter - Unable to validate
> >>> ProxyTicketValidator
> >>> [[edu.yale.its.tp.cas.client.ProxyTicketValidator proxyList=[null]
> >>> [edu.yale.its.tp.cas.client.ServiceTicketValidator
> >>> casValidateUrl=[https://hscas.his.se/cas/serviceValidate]
> >>> ticket=[ST-408-N0ZlV2izrLYiEZ4qficK-cas]
> >>> service=[http%3A%2F%2Fscio.his.se%2Fsakai-login-tool%2Fcontainer]
> >>> errorCode=[INVALID_TICKET] errorMessage=[ticket
> >>> 'ST-408-N0ZlV2izrLYiEZ4qficK-cas' not recognized] renew=false
> >>> entireResponse=[<cas:serviceResponse
> >>> xmlns:cas='http://www.yale.edu/tp/cas'>
> >>>
> >>> <cas:authenticationFailure code='INVALID_TICKET'>
> >>>
> >>> ticket 'ST-408-N0ZlV2izrLYiEZ4qficK-cas'
> >>> not recognized
> >>>
> >>> </cas:authenticationFailure>
> >>>
> >>> </cas:serviceResponse>
> >>>
> >>> ]]]]
> >>>
> >>> javax.servlet.ServletException: Unable to validate
> >>> ProxyTicketValidator
> >>> [[edu.yale.its.tp.cas.client.ProxyTicketValidator proxyList=[null]
> >>> [edu.yale.its.tp.cas.client.ServiceTicketValidator
> >>> casValidateUrl=[https://hscas.his.se/cas/serviceValidate]
> >>> ticket=[ST-408-N0ZlV2izrLYiEZ4qficK-cas]
> >>> service=[http%3A%2F%2Fscio.his.se%2Fsakai-login-tool%2Fcontainer]
> >>> errorCode=[INVALID_TICKET] errorMessage=[ticket
> >>> 'ST-408-N0ZlV2izrLYiEZ4qficK-cas' not recognized] renew=false
> >>> entireResponse=[<cas:serviceResponse
> >>> xmlns:cas='http://www.yale.edu/tp/cas'>
> >>>
> >>> <cas:authenticationFailure code='INVALID_TICKET'>
> >>>
> >>> ticket 'ST-408-N0ZlV2izrLYiEZ4qficK-cas'
> >>> not recognized
> >>>
> >>> </cas:authenticationFailure>
> >>>
> >>> </cas:serviceResponse>
> >>>
> >>> ]]]]
> >>>
> >>> at
> >>> edu.yale.its.tp.cas.client.filter.CASFilter.doFilter(CASFilter.java:
> >>> 381)
> >>>
> >>> at
> >>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(A
> >>> pp
> >>> licationFilterChain.java:215)
> >>>
> >>> at
> >>> org.apache.catalina.core.ApplicationFilterChain.doFilter(Applicati
> >>> on
> >>> FilterChain.java:188)
> >>>
> >>> at
> >>> org.sakaiproject.util.RequestFilter.doFilter(RequestFilter.java:65
> >>> 8)
> >>>
> >>> at
> >>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(A
> >>> pp
> >>> licationFilterChain.java:215)
> >>>
> >>> at
> >>> org.apache.catalina.core.ApplicationFilterChain.doFilter(Applicati
> >>> on
> >>> FilterChain.java:188)
> >>>
> >>> at
> >>> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapp
> >>> er
> >>> Valve.java:213)
> >>>
> >>> at
> >>> org.apache.catalina.core.StandardContextValve.invoke(StandardConte
> >>> xt
> >>> Valve.java:172)
> >>>
> >>> at
> >>> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.
> >>> java:127)
> >>>
> >>> at
> >>> org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.
> >>> java:117)
> >>>
> >>> at
> >>> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngine
> >>> Va
> >>> lve.java:108)
> >>>
> >>> at
> >>> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.
> >>> ja
> >>> va:174)
> >>>
> >>> at
> >>> org.apache.coyote.http11.Http11Processor.process(Http11Processor.j
> >>> av
> >>> a:879)
> >>>
> >>> at
> >>> org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.
> >>> processConnection(Http11BaseProtocol.java:665)
> >>>
> >>> at
> >>> org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEn
> >>> dp
> >>> oint.java:528)
> >>>
> >>> at
> >>> org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(Leader
> >>> Fo
> >>> llowerWorkerThread.java:81)
> >>>
> >>> at
> >>> org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(Thre
> >>> ad
> >>> Pool.java:689)
> >>>
> >>> at java.lang.Thread.run(Thread.java:662)
> >>>
> >>> 2012-03-23 10:53:49,884 ERROR http-8080-Processor6
> >>> org.apache.catalina.core.ContainerBase.[Catalina].[sakai1.hs.local].
> >>> [/sakai-login-tool].[sakai.login.container] - Servlet.service()
> >>> for servlet sakai.login.container threw exception
> >>>
> >>> edu.yale.its.tp.cas.client.CASAuthenticationException: Unable to
> >>> validate ProxyTicketValidator
> >>> [[edu.yale.its.tp.cas.client.ProxyTicketValidator proxyList=[null]
> >>> [edu.yale.its.tp.cas.client.ServiceTicketValidator
> >>> casValidateUrl=[https://hscas.his.se/cas/serviceValidate]
> >>> ticket=[ST-408-N0ZlV2izrLYiEZ4qficK-cas]
> >>> service=[http%3A%2F%2Fscio.his.se%2Fsakai-login-tool%2Fcontainer]
> >>> errorCode=[INVALID_TICKET] errorMessage=[ticket
> >>> 'ST-408-N0ZlV2izrLYiEZ4qficK-cas' not recognized] renew=false
> >>> entireResponse=[<cas:serviceResponse
> >>> xmlns:cas='http://www.yale.edu/tp/cas'>
> >>>
> >>> <cas:authenticationFailure code='INVALID_TICKET'>
> >>>
> >>> ticket 'ST-408-N0ZlV2izrLYiEZ4qficK-cas'
> >>> not recognized
> >>>
> >>> </cas:authenticationFailure>
> >>>
> >>> </cas:serviceResponse>
> >>>
> >>>
> >>>
> >>> Does anyone have an idea of what the problem might be here?
> >>>
> >>> Your welcome to request more logs if you need them!
> >>>
> >>>
> >>>
> >>>
> >>>
> >>> Regards
> >>>
> >>> Anders Nordkvist
> >>>
> >>> System administrator
> >>>
> >>> University Of Skövde
> >>>
> >>> Sweden
> >>>
> >>>
> >>>
> >>>
> >>>
> >>>
> >>> _______________________________________________
> >>> sakai-user mailing list
> >>> sakai-user at collab.sakaiproject.org
> >>> http://collab.sakaiproject.org/mailman/listinfo/sakai-user
> >>>
> >>> TO UNSUBSCRIBE: send email to sakai-user-unsubscribe at collab.sakaiproject.org with a subject of "unsubscribe"
> >>>
> >>> _______________________________________________
> >>> sakai-user mailing list
> >>> sakai-user at collab.sakaiproject.org
> >>> http://collab.sakaiproject.org/mailman/listinfo/sakai-user
> >>>
> >>> TO UNSUBSCRIBE: send email to sakai-user-unsubscribe at collab.sakaiproject.org with a subject of "unsubscribe"
> >> _______________________________________________
> >> sakai-user mailing list
> >> sakai-user at collab.sakaiproject.org
> >> http://collab.sakaiproject.org/mailman/listinfo/sakai-user
> >>
> >> TO UNSUBSCRIBE: send email to sakai-user-unsubscribe at collab.sakaiproject.org with a subject of "unsubscribe"
> >
> > _______________________________________________
> > sakai-user mailing list
> > sakai-user at collab.sakaiproject.org
> > http://collab.sakaiproject.org/mailman/listinfo/sakai-user
> >
> > TO UNSUBSCRIBE: send email to sakai-user-unsubscribe at collab.sakaiproject.org with a subject of "unsubscribe"
>
> _______________________________________________
> sakai-user mailing list
> sakai-user at collab.sakaiproject.org
> http://collab.sakaiproject.org/mailman/listinfo/sakai-user
>
> TO UNSUBSCRIBE: send email to sakai-user-unsubscribe at collab.sakaiproject.org with a subject of "unsubscribe"
-------------- next part --------------
A non-text attachment was scrubbed...
Name: headers
Type: application/octet-stream
Size: 4393 bytes
Desc: headers
Url : http://collab.sakaiproject.org/pipermail/sakai-user/attachments/20120403/cc237b7f/attachment-0001.obj
More information about the sakai-user
mailing list