I am trying to deploy for development purposes cas server and client(service)
server on my local machine. (each one on different tomcat with different ports)
* if I separate the deployments onto different machines it works as expected)
As soon as I reach protected resource on my client I am being redirect to CAS
login page.
After submitting my user/pass I get this error:
HTTP STATUS ERROR 500:
type Exception report
message String index out of range: -1
description The server encountered an internal error that prevented it from
fulfilling this request.
exception
java.lang.StringIndexOutOfBoundsException: String index out of range: -1
CAS logs:
2014-03-31 14:01:18,963 TRACE
[org.hibernate.validator.metadata.BeanMetaDataImpl] - <Members of the default
group sequence for bean
org.jasig.cas.authentication.principal.RememberMeUsernamePasswordCredentials
are: [interface javax.validation.groups.Default]>
2014-03-31 14:01:18,965 TRACE
[org.hibernate.validator.metadata.BeanMetaDataImpl] - <Members of the default
group sequence for bean
org.jasig.cas.authentication.principal.UsernamePasswordCredentials are:
[interface javax.validation.groups.Default]>
2014-03-31 14:01:18,967 TRACE
[org.hibernate.validator.engine.resolver.JPATraversableResolver] - <Calling
isReachable on object [username: gabia] with node name username>
2014-03-31 14:01:18,970 TRACE [org.hibernate.validator.engine.ConstraintTree] -
<Validating value gabia against constraint defined by
ConstraintDescriptorImpl{annotation=javax.validation.constraints.NotNull,
payloads=[], hasComposingConstraints=true,
isReportAsSingleInvalidConstraint=false, elementType=FIELD,
definedOn=DEFINED_LOCALLY, groups=[interface javax.validation.groups.Default],
attributes={message={javax.validation.constraints.NotNull.message},
payload=[Ljava.lang.Class;@29de629c, groups=[Ljava.lang.Class;@471c053d}}>
2014-03-31 14:01:18,971 TRACE
[org.hibernate.validator.engine.resolver.JPATraversableResolver] - <Calling
isReachable on object [username: gabia] with node name password>
2014-03-31 14:01:18,971 TRACE [org.hibernate.validator.engine.ConstraintTree] -
<Validating value 12345678 against constraint defined by
ConstraintDescriptorImpl{annotation=javax.validation.constraints.Size,
payloads=[], hasComposingConstraints=true,
isReportAsSingleInvalidConstraint=false, elementType=FIELD,
definedOn=DEFINED_LOCALLY, groups=[interface javax.validation.groups.Default],
attributes={message=required.password, min=1,
payload=[Ljava.lang.Class;@304f9726, max=2147483647,
groups=[Ljava.lang.Class;@394c5891}}>
2014-03-31 14:01:18,971 TRACE [org.hibernate.validator.engine.ConstraintTree] -
<Validating value gabia against constraint defined by
ConstraintDescriptorImpl{annotation=javax.validation.constraints.Size,
payloads=[], hasComposingConstraints=true,
isReportAsSingleInvalidConstraint=false, elementType=FIELD,
definedOn=DEFINED_LOCALLY, groups=[interface javax.validation.groups.Default],
attributes={message=required.username, min=1,
payload=[Ljava.lang.Class;@304f9726, max=2147483647,
groups=[Ljava.lang.Class;@394c5891}}>
2014-03-31 14:01:18,971 TRACE [org.hibernate.validator.engine.ConstraintTree] -
<Validating value 12345678 against constraint defined by
ConstraintDescriptorImpl{annotation=javax.validation.constraints.NotNull,
payloads=[], hasComposingConstraints=true,
isReportAsSingleInvalidConstraint=false, elementType=FIELD,
definedOn=DEFINED_LOCALLY, groups=[interface javax.validation.groups.Default],
attributes={message={javax.validation.constraints.NotNull.message},
payload=[Ljava.lang.Class;@29de629c, groups=[Ljava.lang.Class;@471c053d}}>
2014-03-31 14:01:18,972 TRACE
[org.hibernate.validator.metadata.BeanMetaDataImpl] - <Members of the default
group sequence for bean java.lang.Object are: [interface
javax.validation.groups.Default]>
2014-03-31 14:01:19,034 DEBUG
[org.jasig.cas.adaptors.ldap.BindLdapAuthenticationHandler] - <Performing LDAP
bind with credential: CN=Gabi Axel,OU=cas-users,DC=RND,DC=local>
2014-03-31 14:01:19,037 INFO
[org.jasig.cas.authentication.AuthenticationManagerImpl] -
<org.jasig.cas.adaptors.ldap.BindLdapAuthenticationHandler successfully
authenticated [username: gabia]>
2014-03-31 14:01:19,037 DEBUG
[org.jasig.cas.authentication.principal.CredentialsToLDAPAttributePrincipalResolver]
- <Attempting to resolve a principal...>
2014-03-31 14:01:19,037 DEBUG
[org.jasig.cas.authentication.principal.UsernamePasswordCredentialsToPrincipalResolver]
- <Attempting to resolve a principal...>
2014-03-31 14:01:19,038 DEBUG
[org.jasig.cas.authentication.principal.UsernamePasswordCredentialsToPrincipalResolver]
- <Creating SimplePrincipal for [gabia]>
2014-03-31 14:01:19,038 DEBUG
[org.jasig.cas.authentication.principal.CredentialsToLDAPAttributePrincipalResolver]
- <Resolved gabia. Trying LDAP resolve now...>
2014-03-31 14:01:19,038 DEBUG
[org.jasig.cas.authentication.principal.CredentialsToLDAPAttributePrincipalResolver]
- <LDAP search with filter "(sAMAccountName=gabia)">
2014-03-31 14:01:19,039 DEBUG
[org.jasig.cas.authentication.principal.CredentialsToLDAPAttributePrincipalResolver]
- <returning searchcontrols: scope=2; search base=dc=RND,dc=local;
attributes=[sAMAccountName]; timeout=1000>
2014-03-31 14:01:19,052 DEBUG
[org.jasig.cas.authentication.principal.CredentialsToLDAPAttributePrincipalResolver]
- <Resolved gabia to gabia>
2014-03-31 14:01:19,052 DEBUG
[org.jasig.cas.authentication.principal.CredentialsToLDAPAttributePrincipalResolver]
- <Creating SimplePrincipal for [gabia]>
2014-03-31 14:01:19,053 DEBUG
[org.jasig.services.persondir.support.MergingPersonAttributeDaoImpl] - <Created
seed map='{username=[gabia]}' for uid='gabia'>
2014-03-31 14:01:19,053 DEBUG
[org.jasig.services.persondir.support.jdbc.SingleRowJdbcPersonAttributeDao] -
<Adding attribute 'Username' with value '[gabia]' to query builder 'null'>
2014-03-31 14:01:19,053 DEBUG
[org.jasig.services.persondir.support.jdbc.SingleRowJdbcPersonAttributeDao] -
<Generated query builder 'sql=[Username = ?] args=[gabia]' from query Map
{username=[gabia]}.>
2014-03-31 14:01:19,102 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<incremented pending_acquires: 1>
2014-03-31 14:01:19,102 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<incremented pending_acquires: 2>
2014-03-31 14:01:19,102 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<incremented pending_acquires: 3>
2014-03-31 14:01:19,102 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<incremented pending_acquires: 4>
2014-03-31 14:01:19,102 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<incremented pending_acquires: 5>
2014-03-31 14:01:19,102 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<incremented pending_acquires: 6>
2014-03-31 14:01:19,102 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf config: [start -> 6;
min -> 6; max -> 18; inc -> 6; num_acq_attempts -> 5; acq_attempt_delay ->
2000; check_idle_resources_delay -> 30000; mox_resource_age -> 0; max_idle_time
-> 0; excess_max_idle_time -> 120000; destroy_unreturned_resc_time -> 0;
expiration_enforcement_delay -> 30000; break_on_acquisition_failure -> false;
debug_store_checkout_exceptions -> false]>
2014-03-31 14:01:19,103 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<acquire test -- pool size: 0; target_pool_size: 6; desired target? 1>
2014-03-31 14:01:19,103 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<awaitAvailable(): [unknown]>
2014-03-31 14:01:19,103 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<trace com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf [managed: 0,
unused: 0, excluded: 0]>
2014-03-31 14:01:19,287 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<trace com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf [managed: 1,
unused: 1, excluded: 0]>
2014-03-31 14:01:19,288 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<decremented pending_acquires: 5>
2014-03-31 14:01:19,288 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<trace com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf [managed: 2,
unused: 1, excluded: 0] (e.g.
com.mchange.v2.c3p0.impl.NewPooledConnection@27e10af5)>
2014-03-31 14:01:19,288 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<decremented pending_acquires: 4>
2014-03-31 14:01:19,289 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<trace com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf [managed: 2,
unused: 1, excluded: 0] (e.g.
com.mchange.v2.c3p0.impl.NewPooledConnection@27e10af5)>
2014-03-31 14:01:19,289 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<trace com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf [managed: 3,
unused: 2, excluded: 0] (e.g.
com.mchange.v2.c3p0.impl.NewPooledConnection@27e10af5)>
2014-03-31 14:01:19,289 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<decremented pending_acquires: 3>
2014-03-31 14:01:19,304 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<trace com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf [managed: 4,
unused: 3, excluded: 0] (e.g.
com.mchange.v2.c3p0.impl.NewPooledConnection@27e10af5)>
2014-03-31 14:01:19,304 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<decremented pending_acquires: 2>
2014-03-31 14:01:19,306 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<trace com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf [managed: 5,
unused: 4, excluded: 0] (e.g.
com.mchange.v2.c3p0.impl.NewPooledConnection@27e10af5)>
2014-03-31 14:01:19,306 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<decremented pending_acquires: 1>
2014-03-31 14:01:19,306 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<trace com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf [managed: 6,
unused: 5, excluded: 0] (e.g.
com.mchange.v2.c3p0.impl.NewPooledConnection@27e10af5)>
2014-03-31 14:01:19,306 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<decremented pending_acquires: 0>
2014-03-31 14:01:19,314 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<trace com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf [managed: 6,
unused: 5, excluded: 0] (e.g.
com.mchange.v2.c3p0.impl.NewPooledConnection@27e10af5)>
2014-03-31 14:01:19,314 DEBUG
[org.jasig.services.persondir.support.jdbc.SingleRowJdbcPersonAttributeDao] -
<Executed 'select permission, authority from users u left join
user_authority ua on u.id=ua.user_id left join user_permissions up on
u.id=up.user_id where Username=u.username and {0}' with arguments [gabia]
and got results []>
2014-03-31 14:01:19,314 DEBUG
[org.jasig.services.persondir.support.MergingPersonAttributeDaoImpl] -
<Retrieved attributes='[]' for query='{username=[gabia]}', isFirstQuery=false,
currentlyConsidering='org.jasig.services.persondir.support.jdbc.SingleRowJdbcPersonAttributeDao@184c5d75',
resultAttributes='null'>
2014-03-31 14:01:19,314 DEBUG
[org.jasig.services.persondir.support.ldap.LdapPersonAttributeDao] - <Adding
attribute 'sAMAccountName' with value '[gabia]' to query builder 'null'>
2014-03-31 14:01:19,317 DEBUG
[org.jasig.services.persondir.support.ldap.LdapPersonAttributeDao] - <Generated
query builder '(sAMAccountName=gabia)' from query Map {username=[gabia]}.>
2014-03-31 14:01:19,346 DEBUG
[org.jasig.services.persondir.support.MergingPersonAttributeDaoImpl] -
<Retrieved
attributes='[NamedPersonImpl[name=gabia,attributes={mail=[[email protected]]}]]'
for query='{username=[gabia]}', isFirstQuery=false,
currentlyConsidering='org.jasig.services.persondir.support.ldap.LdapPersonAttributeDao@5c78676f',
resultAttributes='[]'>
2014-03-31 14:01:19,346 DEBUG
[org.jasig.services.persondir.support.MergingPersonAttributeDaoImpl] -
<Aggregated search results
'[NamedPersonImpl[name=gabia,attributes={mail=[[email protected]]}]]' for
query='{username=[gabia]}'>
2014-03-31 14:01:19,347 INFO
[org.jasig.cas.authentication.AuthenticationManagerImpl] - <Resolved principal
gabia>
2014-03-31 14:01:19,348 INFO
[org.jasig.cas.authentication.AuthenticationManagerImpl] -
<org.jasig.cas.adaptors.ldap.BindLdapAuthenticationHandler@3549c376
authenticated gabia with credential [username: gabia].>
2014-03-31 14:01:19,348 DEBUG
[org.jasig.cas.authentication.AuthenticationManagerImpl] - <Attribute map for
gabia: {[email protected]}>
Audit trail record BEGIN
=============================================================
WHO: [username: gabia]
WHAT: supplied credentials: [username: gabia]
ACTION: AUTHENTICATION_SUCCESS
APPLICATION: CAS
WHEN: Mon Mar 31 14:01:19 IDT 2014
CLIENT IP ADDRESS: 127.0.0.1
SERVER IP ADDRESS: 127.0.0.1
=============================================================
2014-03-31 14:01:19,358 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - <Added ticket
[TGT-1-sj37t0eZjo96WQ1RByCP1LTkohZIalwfu2SHRZ5EexgI4oj6SB-cas] to registry.>
Audit trail record BEGIN
=============================================================
WHO: [username: gabia]
WHAT: TGT-1-sj37t0eZjo96WQ1RByCP1LTkohZIalwfu2SHRZ5EexgI4oj6SB-cas
ACTION: TICKET_GRANTING_TICKET_CREATED
APPLICATION: CAS
WHEN: Mon Mar 31 14:01:19 IDT 2014
CLIENT IP ADDRESS: 127.0.0.1
SERVER IP ADDRESS: 127.0.0.1
=============================================================
2014-03-31 14:01:19,359 DEBUG
[org.jasig.cas.web.support.CookieRetrievingCookieGenerator] - <Removed cookie
with name [CASPRIVACY]>
2014-03-31 14:01:19,359 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<trace com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf [managed: 6,
unused: 5, excluded: 0] (e.g.
com.mchange.v2.c3p0.impl.NewPooledConnection@27e10af5)>
2014-03-31 14:01:19,359 DEBUG
[org.jasig.cas.web.flow.PasswordPolicyEnforcementAction] - <Checking account
status for password...>
2014-03-31 14:01:19,361 DEBUG
[org.jasig.cas.web.flow.PasswordPolicyEnforcementAction] - <Retrieving number
of days to password expiration date for user gabia>
2014-03-31 14:01:19,361 DEBUG
[org.jasig.cas.adaptors.ldap.LdapPasswordPolicyEnforcer] - <Starting search
with searchFilter: uid=gabia>
2014-03-31 14:01:19,361 DEBUG
[org.jasig.cas.adaptors.ldap.LdapPasswordPolicyEnforcer] - <Returning
attributes pwdChangedTime:passwordwarningdays:maxPwdAge:>
2014-03-31 14:01:19,366 WARN
[org.jasig.cas.adaptors.ldap.LdapPasswordPolicyEnforcer] - <No entry was found
for user gabia. Verify your LPPE settings. If you are not using LPPE, set the
'enabled' property to false. Password policy enforcement is currently turned on
but not configured.>
2014-03-31 14:01:19,367 DEBUG
[org.jasig.cas.adaptors.ldap.LdapPasswordPolicyEnforcer] - <Skipping all
password policy checks...>
2014-03-31 14:01:19,367 DEBUG
[org.jasig.cas.web.flow.PasswordPolicyEnforcementAction] - <Password for gabia
is not expiring>
2014-03-31 14:01:19,367 DEBUG
[org.jasig.cas.web.flow.PasswordPolicyEnforcementAction] - <Switching to flow
event id success for user gabia>
2014-03-31 14:01:19,368 DEBUG
[org.jasig.cas.web.support.CookieRetrievingCookieGenerator] - <Added cookie
with name [CASTGC] and value
[TGT-1-sj37t0eZjo96WQ1RByCP1LTkohZIalwfu2SHRZ5EexgI4oj6SB-cas]>
2014-03-31 14:01:19,371 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - <Attempting to retrieve
ticket [TGT-1-sj37t0eZjo96WQ1RByCP1LTkohZIalwfu2SHRZ5EexgI4oj6SB-cas]>
2014-03-31 14:01:19,371 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - <Ticket
[TGT-1-sj37t0eZjo96WQ1RByCP1LTkohZIalwfu2SHRZ5EexgI4oj6SB-cas] found in
registry.>
2014-03-31 14:01:19,373 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - <Added ticket
[ST-1-gB7eF6G27ksmvMQhp0in-cas] to registry.>
2014-03-31 14:01:19,373 INFO [org.jasig.cas.CentralAuthenticationServiceImpl] -
<Granted service ticket [ST-1-gB7eF6G27ksmvMQhp0in-cas] for service
[http://localhost:8081/login] for user [gabia]>
2014-03-31 14:01:19,373 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - <Attempting to retrieve
ticket [TGT-1-sj37t0eZjo96WQ1RByCP1LTkohZIalwfu2SHRZ5EexgI4oj6SB-cas]>
2014-03-31 14:01:19,373 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - <Ticket
[TGT-1-sj37t0eZjo96WQ1RByCP1LTkohZIalwfu2SHRZ5EexgI4oj6SB-cas] found in
registry.>
Audit trail record BEGIN
=============================================================
WHO: gabia
WHAT: ST-1-gB7eF6G27ksmvMQhp0in-cas for http://localhost:8081/login
ACTION: SERVICE_TICKET_CREATED
APPLICATION: CAS
WHEN: Mon Mar 31 14:01:19 IDT 2014
CLIENT IP ADDRESS: 127.0.0.1
SERVER IP ADDRESS: 127.0.0.1
=============================================================
2014-03-31 14:01:19,382 DEBUG
[org.jasig.cas.web.flow.TerminateWebSessionListener] - <Terminate web session
28F7861B25987C5E66FAA07C6FBED1B6 in 2 seconds>
2014-03-31 14:01:19,385 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<trace com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf [managed: 6,
unused: 5, excluded: 0] (e.g.
com.mchange.v2.c3p0.impl.NewPooledConnection@27e10af5)>
2014-03-31 14:01:19,385 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<trace com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf [managed: 6,
unused: 5, excluded: 0] (e.g.
com.mchange.v2.c3p0.impl.NewPooledConnection@27e10af5)>
2014-03-31 14:01:19,404 DEBUG [org.jasig.cas.web.support.CasArgumentExtractor]
- <Extractor did not generate service.>
2014-03-31 14:01:19,404 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<trace com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf [managed: 6,
unused: 5, excluded: 0] (e.g.
com.mchange.v2.c3p0.impl.NewPooledConnection@27e10af5)>
2014-03-31 14:01:19,404 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<trace com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf [managed: 6,
unused: 5, excluded: 0] (e.g.
com.mchange.v2.c3p0.impl.NewPooledConnection@27e10af5)>
2014-03-31 14:01:19,405 DEBUG
[org.jasig.cas.authentication.principal.SamlService] - <Attempted to extract
Request from HttpServletRequest. Results:>
2014-03-31 14:01:19,405 DEBUG
[org.jasig.cas.authentication.principal.SamlService] - <Request Body: >
2014-03-31 14:01:19,405 DEBUG
[org.jasig.cas.authentication.principal.SamlService] - <Extracted ArtifactId:
null>
2014-03-31 14:01:19,405 DEBUG
[org.jasig.cas.authentication.principal.SamlService] - <Extracted Request Id:
null>
2014-03-31 14:01:19,405 DEBUG [org.jasig.cas.web.support.SamlArgumentExtractor]
- <Extractor generated service for: http://localhost:8081/login>
2014-03-31 14:01:19,405 DEBUG [org.jasig.cas.web.flow.InitialFlowSetupAction] -
<Placing service in FlowScope: http://localhost:8081/login>
2014-03-31 14:01:19,406 DEBUG
[org.jasig.cas.web.flow.GenerateLoginTicketAction] - <Generated login ticket
LT-2-WosTXSh1jiCkXK5Nkb6h9xoB9ZZVkS>
2014-03-31 14:01:19,417 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<trace com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf [managed: 6,
unused: 5, excluded: 0] (e.g.
com.mchange.v2.c3p0.impl.NewPooledConnection@27e10af5)>
2014-03-31 14:01:19,483 DEBUG [org.jasig.cas.web.support.CasArgumentExtractor]
- <Extractor generated service for: http://localhost:8081/login>
2014-03-31 14:01:19,484 DEBUG [org.jasig.cas.web.flow.InitialFlowSetupAction] -
<Placing service in FlowScope: http://localhost:8081/login>
2014-03-31 14:01:19,485 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - <Attempting to retrieve
ticket [TGT-1-sj37t0eZjo96WQ1RByCP1LTkohZIalwfu2SHRZ5EexgI4oj6SB-cas]>
2014-03-31 14:01:19,485 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - <Ticket
[TGT-1-sj37t0eZjo96WQ1RByCP1LTkohZIalwfu2SHRZ5EexgI4oj6SB-cas] found in
registry.>
2014-03-31 14:01:19,486 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - <Added ticket
[ST-2-wqSK6ovwNv21vhyWJXPB-cas] to registry.>
2014-03-31 14:01:19,486 INFO [org.jasig.cas.CentralAuthenticationServiceImpl] -
<Granted service ticket [ST-2-wqSK6ovwNv21vhyWJXPB-cas] for service
[http://localhost:8081/login] for user [gabia]>
2014-03-31 14:01:19,486 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - <Attempting to retrieve
ticket [TGT-1-sj37t0eZjo96WQ1RByCP1LTkohZIalwfu2SHRZ5EexgI4oj6SB-cas]>
2014-03-31 14:01:19,486 DEBUG
[org.jasig.cas.ticket.registry.DefaultTicketRegistry] - <Ticket
[TGT-1-sj37t0eZjo96WQ1RByCP1LTkohZIalwfu2SHRZ5EexgI4oj6SB-cas] found in
registry.>
Audit trail record BEGIN
=============================================================
WHO: gabia
WHAT: ST-2-wqSK6ovwNv21vhyWJXPB-cas for http://localhost:8081/login
ACTION: SERVICE_TICKET_CREATED
APPLICATION: CAS
WHEN: Mon Mar 31 14:01:19 IDT 2014
CLIENT IP ADDRESS: 127.0.0.1
SERVER IP ADDRESS: 127.0.0.1
=============================================================
2014-03-31 14:01:19,487 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<trace com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf [managed: 6,
unused: 5, excluded: 0] (e.g.
com.mchange.v2.c3p0.impl.NewPooledConnection@27e10af5)>
2014-03-31 14:01:19,489 DEBUG
[org.jasig.cas.web.flow.TerminateWebSessionListener] - <Error getting service
from flow state.>
java.lang.IllegalStateException: No active FlowSession to access; this
FlowExecution has ended
at
org.springframework.webflow.engine.impl.FlowExecutionImpl.getActiveSession(FlowExecutionImpl.java:191)
at
org.springframework.webflow.engine.impl.RequestControlContextImpl.getFlowScope(RequestControlContextImpl.java:134)
at
org.jasig.cas.web.support.WebUtils.getService_aroundBody8(WebUtils.java:87)
at
org.jasig.cas.web.support.WebUtils.getService_aroundBody9$advice(WebUtils.java:57)
at org.jasig.cas.web.support.WebUtils.getService(WebUtils.java:1)
at
org.jasig.cas.web.flow.TerminateWebSessionListener.sessionStarted_aroundBody0(TerminateWebSessionListener.java:62)
at
org.jasig.cas.web.flow.TerminateWebSessionListener.sessionStarted_aroundBody1$advice(TerminateWebSessionListener.java:57)
at
org.jasig.cas.web.flow.TerminateWebSessionListener.sessionStarted(TerminateWebSessionListener.java:1)
at
org.springframework.webflow.engine.impl.FlowExecutionListeners.fireSessionStarted(FlowExecutionListeners.java:126)
at
org.springframework.webflow.engine.impl.FlowExecutionImpl.start(FlowExecutionImpl.java:367)
at
org.springframework.webflow.engine.impl.FlowExecutionImpl.start(FlowExecutionImpl.java:225)
at
org.springframework.webflow.executor.FlowExecutorImpl.launchExecution(FlowExecutorImpl.java:140)
at
org.springframework.webflow.mvc.servlet.FlowHandlerAdapter.handle(FlowHandlerAdapter.java:193)
at
org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:923)
at
org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:852)
at
org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882)
at
org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:778)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:621)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:722)
at
org.jasig.cas.web.init.SafeDispatcherServlet.service_aroundBody2(SafeDispatcherServlet.java:128)
at
org.jasig.cas.web.init.SafeDispatcherServlet.service_aroundBody3$advice(SafeDispatcherServlet.java:57)
at
org.jasig.cas.web.init.SafeDispatcherServlet.service(SafeDispatcherServlet.java:1)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at
org.jasig.cas.web.filter.CrossOriginFilter.doFilter(CrossOriginFilter.java:25)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at
org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
at
org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76)
at
org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346)
at
org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:259)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at
com.github.inspektr.common.web.ClientInfoThreadLocalFilter.doFilter(ClientInfoThreadLocalFilter.java:63)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:168)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:99)
at
org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:929)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:407)
at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1002)
at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:585)
at
org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:312)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:724)
2014-03-31 14:01:19,506 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<trace com.mchange.v2.resourcepool.BasicResourcePool@1c92dfaf [managed: 6,
unused: 5, excluded: 0] (e.g.
com.mchange.v2.c3p0.impl.NewPooledConnection@27e10af5)>
2014-03-31 14:01:19,509 DEBUG [org.jasig.cas.web.support.CasArgumentExtractor]
- <Extractor did not generate service.>
2014-03-31 14:01:19,509 DEBUG
[org.jasig.cas.authentication.principal.SamlService] - <Attempted to extract
Request from HttpServletRequest. Results:>
2014-03-31 14:01:19,509 DEBUG
[org.jasig.cas.authentication.principal.SamlService] - <Request Body: >
2014-03-31 14:01:19,509 DEBUG
[org.jasig.cas.authentication.principal.SamlService] - <Extracted ArtifactId:
null>
2014-03-31 14:01:19,509 DEBUG
[org.jasig.cas.authentication.principal.SamlService] - <Extracted Request Id:
null>
2014-03-31 14:01:19,509 DEBUG [org.jasig.cas.web.support.SamlArgumentExtractor]
- <Extractor generated service for: http://localhost:8081/login>
2014-03-31 14:01:19,510 DEBUG [org.jasig.cas.web.flow.InitialFlowSetupAction] -
<Placing service in FlowScope: http://localhost:8081/login>
2014-03-31 14:01:19,510 DEBUG
[org.jasig.cas.web.flow.GenerateLoginTicketAction] - <Generated login ticket
LT-3-tUpCkI1dsAgZY1OxGmlcr1a5UokvcW>
Process finished with exit code -1
----------------------------------------------------
Client(service) logs:
DEBUG http-bio-8081-exec-3
[org.springframework.security.web.savedrequest.HttpSessionRequestCache] -
DefaultSavedRequest added to Session:
DefaultSavedRequest[http://localhost:8081/favicon.ico]
DEBUG http-bio-8081-exec-3
[org.springframework.security.web.access.ExceptionTranslationFilter] - Calling
Authentication entry point.
DEBUG http-bio-8081-exec-3
[org.springframework.security.web.context.HttpSessionSecurityContextRepository]
- SecurityContext is empty or contents are anonymous - context will not be
stored in HttpSession.
DEBUG http-bio-8081-exec-3
[org.springframework.security.web.context.SecurityContextPersistenceFilter] -
SecurityContextHolder now cleared, as request processing completed
DEBUG http-bio-8081-exec-4
[org.springframework.security.web.util.AntPathRequestMatcher] - Checking match
of request : '/login'; against '/resources/**'
DEBUG http-bio-8081-exec-4 [org.springframework.security.web.FilterChainProxy]
- /login?ticket=ST-2-wqSK6ovwNv21vhyWJXPB-cas at position 1 of 10 in additional
filter chain; firing Filter: 'SecurityContextPersistenceFilter'
DEBUG http-bio-8081-exec-4
[org.springframework.security.web.context.HttpSessionSecurityContextRepository]
- HttpSession returned null object for SPRING_SECURITY_CONTEXT
DEBUG http-bio-8081-exec-4
[org.springframework.security.web.context.HttpSessionSecurityContextRepository]
- No SecurityContext was available from the HttpSession:
org.apache.catalina.session.StandardSessionFacade@5f51683. A new one will be
created.
DEBUG http-bio-8081-exec-4 [org.springframework.security.web.FilterChainProxy]
- /login?ticket=ST-2-wqSK6ovwNv21vhyWJXPB-cas at position 2 of 10 in additional
filter chain; firing Filter: 'SingleSignOutFilter'
DEBUG http-bio-8081-exec-4 [org.jasig.cas.client.session.SingleSignOutHandler]
- Recording session for token ST-2-wqSK6ovwNv21vhyWJXPB-cas
DEBUG http-bio-8081-exec-4
[org.jasig.cas.client.session.HashMapBackedSessionMappingStorage] - Attempting
to remove Session=[58E74C0DEFEAD36F19B627BFEB8150D3]
DEBUG http-bio-8081-exec-4
[org.jasig.cas.client.session.HashMapBackedSessionMappingStorage] - No mapping
for session found. Ignoring.
DEBUG http-bio-8081-exec-4 [org.springframework.security.web.FilterChainProxy]
- /login?ticket=ST-2-wqSK6ovwNv21vhyWJXPB-cas at position 3 of 10 in additional
filter chain; firing Filter: 'LogoutFilter'
DEBUG http-bio-8081-exec-4 [org.springframework.security.web.FilterChainProxy]
- /login?ticket=ST-2-wqSK6ovwNv21vhyWJXPB-cas at position 4 of 10 in additional
filter chain; firing Filter: 'CasAuthenticationFilter'
DEBUG http-bio-8081-exec-4
[org.springframework.security.cas.web.CasAuthenticationFilter] -
serviceTicketRequest = true
DEBUG http-bio-8081-exec-4
[org.springframework.security.cas.web.CasAuthenticationFilter] -
requiresAuthentication = true
DEBUG http-bio-8081-exec-4
[org.springframework.security.cas.web.CasAuthenticationFilter] - Request is to
process authentication
DEBUG http-bio-8081-exec-4
[org.springframework.security.cas.web.CasAuthenticationFilter] -
proxyReceptorConfigured = false
DEBUG http-bio-8081-exec-4
[org.springframework.security.cas.web.CasAuthenticationFilter] -
proxyReceptorRequest = false
DEBUG http-bio-8081-exec-4
[org.springframework.security.cas.web.CasAuthenticationFilter] -
serviceTicketRequest = true
DEBUG http-bio-8081-exec-4
[org.springframework.security.authentication.ProviderManager] - Authentication
attempt using
org.springframework.security.cas.authentication.CasAuthenticationProvider
DEBUG http-bio-8081-exec-4
[org.springframework.security.cas.authentication.CasAuthenticationProvider] -
serviceUrl = http://localhost:8081/login
DEBUG http-bio-8081-exec-4
[org.jasig.cas.client.validation.Saml11TicketValidator] - Placing URL
parameters in map.
DEBUG http-bio-8081-exec-4
[org.jasig.cas.client.validation.Saml11TicketValidator] - Calling template URL
attribute map.
DEBUG http-bio-8081-exec-4
[org.jasig.cas.client.validation.Saml11TicketValidator] - Loading custom
parameters from configuration.
DEBUG http-bio-8081-exec-4
[org.jasig.cas.client.validation.Saml11TicketValidator] - Constructing
validation url:
http://localhost:8080/cas/samlValidate?TARGET=http%3A%2F%2Flocalhost%3A8081%2Flogin
DEBUG http-bio-8081-exec-4
[org.jasig.cas.client.validation.Saml11TicketValidator] - Retrieving response
from server.
DEBUG http-bio-8081-exec-4
[org.jasig.cas.client.validation.Saml11TicketValidator] - Server response:
<!DOCTYPE html> <html> <head>
<title>Login</title> <link rel="stylesheet"
href="css/bootstrap.min.css"/> </head> <body> <div
class='row'> <div
id="msg" class="alert alert-danger" style="margin:
auto;width: 50%;margin-top: 10px;"> <h2>Non-secure
Connection</h2> <p>You are currently accessing CAS over a
non-secure connection. Single Sign On WILL NOT WORK. In
order to have single sign on work, you MUST log in over
HTTPS.</p> </div> <div class="col-lg-2
col-lg-offset-5" style='margin-top:60px' id="login"> <form
id="fm1" class="fm-v clearfix well" style="width: 340px;margin: auto;"
action="/login;jsessionid=B1D572FE65AE40F048BC7DD3682961D1?TARGET=http%3A%2F%2Flocalhost%3A8081%2Flogin"
method="post"> <img src="css/images/company-logo.png"/>
<br/> <br/> <h4 class="form-signin-heading">Please sign
in</h4><br/> <div class="form-group">
<input id="username" name="username" class="required form-control" tabindex="1"
placeholder="Username" accesskey="u" type="text" value="" size="25"
autocomplete="false"/> </div>
<div class="form-group"> <input
id="password" name="password" class="required form-control" tabindex="2"
placeholder="Password" type="password" value="" size="25" autocomplete="off"/>
</div> <div class="form-group">
<input type="checkbox" name="rememberMe" id="rememberMe"
value="true"/> <span for="rememberMe">Remember
Me</span> <p></p> </div>
<a href="code"> Forgot Password</a>
<input type="hidden" name="lt" value="LT-3-tUpCkI1dsAgZY1OxGmlcr1a5UokvcW"/>
<input type="hidden" name="execution" value="e1s1"/>
<input type="hidden" name="_eventId" value="submit"/>
<div class="form-group"> <input type="submit"
name="submit" class="btn btn-large btn-primary
pull-right" value="Sign In"/> </div> <div
style='clear:both'></div> <div class="errors">
</div> </form> </div>
</div> <script>
document.getElementById("username").focus(); </script> </body>
</html>
DEBUG http-bio-8081-exec-4
[org.springframework.security.web.context.HttpSessionSecurityContextRepository]
- SecurityContext is empty or contents are anonymous - context will not be
stored in HttpSession.
DEBUG http-bio-8081-exec-4
[org.springframework.security.web.context.SecurityContextPersistenceFilter] -
SecurityContextHolder now cleared, as request processing completed
?????? 31, 2014 2:01:19 PM org.apache.catalina.core.StandardWrapperValve invoke
SEVERE: Servlet.service() for servlet [mvc-dispatcher] in context with path []
threw exception
java.lang.StringIndexOutOfBoundsException: String index out of range: -1
at java.lang.String.substring(String.java:1911)
at
org.jasig.cas.client.validation.Saml11TicketValidator.parseResponseFromServer(Saml11TicketValidator.java:50)
at
org.jasig.cas.client.validation.AbstractUrlBasedTicketValidator.validate(AbstractUrlBasedTicketValidator.java:197)
at
org.springframework.security.cas.authentication.CasAuthenticationProvider.authenticateNow(CasAuthenticationProvider.java:140)
at
org.springframework.security.cas.authentication.CasAuthenticationProvider.authenticate(CasAuthenticationProvider.java:126)
at
org.springframework.security.authentication.ProviderManager.authenticate(ProviderManager.java:156)
at
org.springframework.security.cas.web.CasAuthenticationFilter.attemptAuthentication(CasAuthenticationFilter.java:242)
at
org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:195)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at
org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:105)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at
org.jasig.cas.client.session.SingleSignOutFilter.doFilter(SingleSignOutFilter.java:65)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at
org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at
org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192)
at
org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160)
at
org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346)
at
org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:259)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at
org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
at
org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:168)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:99)
at
org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:929)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:407)
at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1002)
at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:585)
at
org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:312)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:724)
thanks,
ray.
--
You are currently subscribed to [email protected] as:
[email protected]
To unsubscribe, change settings or access archives, see
http://www.ja-sig.org/wiki/display/JSG/cas-user
