However, after restarting, it can login despite the blank results from the
JDBC attribute resolver (I'm using cascading attribute resolvers, and
assigning static attributes, depending on which method the user resolved
against):
Before restart:
2016-11-16 18:03:22,205 DEBUG
[org.jasig.services.persondir.support.jdbc.SingleRowJdbcPersonAttributeDao]
- Executed 'SELECT ID,username,Firs
tName,LastName,Email FROM users WHERE {0}' with arguments [testuser] and
got results []
2016-11-16 18:03:22,210 DEBUG
[org.jasig.services.persondir.support.CascadingPersonAttributeDao] -
Retrieved attributes='[]' for query='{user
name=[testuser]}', isFirstQuery=false,
currentlyConsidering='org.jasig.services.persondir.support.jdbc.SingleRowJdbcPersonAttributeDao@e6c2461'
,
resultAttributes='[AttributeNamedPersonImpl[name=testuser,attributes={userType=[internal],
username=[testuser]}]]'
2016-11-16 18:03:22,216 DEBUG
[org.jasig.services.persondir.support.CascadingPersonAttributeDao] -
Aggregated search results '[AttributeNamed
PersonImpl[name=testuser,attributes={userType=[internal],
username=[testuser]}]]' for query='{username=[testuser]}'
2016-11-16 18:03:22,217 DEBUG
[org.jasig.cas.authentication.principal.PersonDirectoryPrincipalResolver] -
Retrieved [2] attribute(s) from the
repository
2016-11-16 18:03:22,230 DEBUG
[org.jasig.cas.web.flow.AuthenticationViaFormAction] - 'principal' cannot
be null.
Check the correctness of @Audit annotation at the following audit point:
execution(public abstract org.jasig.cas.authentication.Authenticatio
n
org.jasig.cas.authentication.AuthenticationManager.authenticate(org.jasig.cas.authentication.AuthenticationTransaction))
java.lang.IllegalArgumentException: 'principal' cannot be null.
Check the correctness of @Audit annotation at the following audit point:
execution(public abstract org.jasig.cas.authentication.Authenticatio
n
org.jasig.cas.authentication.AuthenticationManager.authenticate(org.jasig.cas.authentication.AuthenticationTransaction))
at
org.jasig.inspektr.audit.AuditActionContext.assertNotNull(AuditActionContext.java:80)
at
org.jasig.inspektr.audit.AuditActionContext.<init>(AuditActionContext.java:62)
at
org.jasig.inspektr.audit.AuditTrailManagementAspect.executeAuditCode(AuditTrailManagementAspect.java:153)
at
org.jasig.inspektr.audit.AuditTrailManagementAspect.handleAuditTrail(AuditTrailManagementAspect.java:141)
at sun.reflect.GeneratedMethodAccessor81.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:620)
at
org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:609)
at
org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:68)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:168)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at
com.ryantenney.metrics.spring.MeteredMethodInterceptor.invoke(MeteredMethodInterceptor.java:45)
at
com.ryantenney.metrics.spring.MeteredMethodInterceptor.invoke(MeteredMethodInterceptor.java:32)
at
com.ryantenney.metrics.spring.AbstractMetricMethodInterceptor.invoke(AbstractMetricMethodInterceptor.java:59)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at
com.ryantenney.metrics.spring.TimedMethodInterceptor.invoke(TimedMethodInterceptor.java:48)
at
com.ryantenney.metrics.spring.TimedMethodInterceptor.invoke(TimedMethodInterceptor.java:34)
After restart:
2016-11-16 18:04:48,321 DEBUG
[org.springframework.jdbc.datasource.DataSourceUtils] - Returning JDBC
Connection to DataSource
2016-11-16 18:04:48,323 DEBUG
[org.jasig.services.persondir.support.jdbc.SingleRowJdbcPersonAttributeDao]
- Executed 'SELECT ID,username,FirstName,LastName,Email FROM users WHERE
{0}' with argument
s [testuser] and got results []
2016-11-16 18:04:48,326 DEBUG
[org.jasig.services.persondir.support.CascadingPersonAttributeDao] -
Retrieved attributes='[]' for query='{username=[testuser]}',
isFirstQuery=false, currentlyConsidering='org.jasig.se
rvices.persondir.support.jdbc.SingleRowJdbcPersonAttributeDao@5b528cd',
resultAttributes='[AttributeNamedPersonImpl[name=testuser,attributes={userType=[internal],
username=[testuser]}]]'
2016-11-16 18:04:48,327 DEBUG
[org.jasig.services.persondir.support.CascadingPersonAttributeDao] -
Aggregated search results
'[AttributeNamedPersonImpl[name=testuser,attributes={userType=[internal],
username=[auror
a]}]]' for query='{username=[testuser]}'
2016-11-16 18:04:48,329 DEBUG
[org.jasig.cas.authentication.principal.PersonDirectoryPrincipalResolver] -
Retrieved [2] attribute(s) from the repository
2016-11-16 18:04:48,330 DEBUG
[org.jasig.cas.authentication.PolicyBasedAuthenticationManager] -
org.jasig.cas.authentication.principal.PersonDirectoryPrincipalResolver@108b3d3a
resolved testuser from testuser
2016-11-16 18:04:48,334 DEBUG
[org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - Final
principal resolved for this authentication event is testuser
2016-11-16 18:04:48,335 INFO
[org.jasig.cas.authentication.PolicyBasedAuthenticationManager] -
Authenticated testuser with credentials [testuser].
2016-11-16 18:04:48,336 DEBUG
[org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - Attribute
map for testuser: {userType=internal, username=testuser}
2016-11-16 18:04:48,337 DEBUG
[org.jasig.cas.audit.spi.AssertionAsReturnValuePrincipalResolver] - Trying
to see if target's return value is instance of [Assertion]...
2016-11-16 18:04:48,338 DEBUG
[org.jasig.cas.audit.spi.AssertionAsReturnValuePrincipalResolver] -
Resolving principal from the delegate principal resolver:
[org.jasig.cas.audit.spi.TicketOrCredentialPrincipalReso
lver@51e946a9]...
2016-11-16 18:04:48,339 DEBUG
[org.jasig.cas.audit.spi.TicketOrCredentialPrincipalResolver] - Resolving
argument [AuthenticationTransaction] for audit
2016-11-16 18:04:48,340 DEBUG
[org.jasig.cas.audit.spi.TicketOrCredentialPrincipalResolver] - Resolving
argument [UsernamePasswordCredential] for audit
2016-11-16 18:04:48,353 DEBUG
[org.jasig.cas.authentication.DefaultAuthenticationTransactionManager] -
Successful authentication; Collecting authentication result
[org.jasig.cas.authentication.ImmutableAuthentica
tion@60e79493]
And it works OK!
I'll see if I can break it again and come up with more detailed logs at the
breaking point. I'll keep you updated.
On Tuesday, July 19, 2016 at 3:09:59 PM UTC-7, Jeffrey Wong wrote:
>
> After about a month of working perfectly on 4.2.2 deployed to tomcat7,
> running under java8, randomly the in-memory ticketing system would not
> create any more tickets. Restarting the tomcat instance fixed it, but I'm
> wondering why CAS would randomly break on me after working so well! Using a
> LDAP (AD) backed user base with a mysql backed attribute DB. We have pretty
> minimal traffic, so I'm not sure why I am seeing issues after such a small
> amount of time.
>
> Despite having an <AsyncRoot level="error">, no errors have been thrown at
> the time of issue.
>
> Unfortunately, I've only had the org.springframework.jdbc logger set to
> debug, and all others at info, so I have very minimal logging around the
> issue.
>
> I'm noticing both the ldap auth AND the jdbc handlers returning without
> issues (no errors). ...But no tickets?
>
> Here's a sample of the logs:
>
> 2016-07-19 16:28:16,399 INFO
> [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] -
> <LdapAuthenticationHandler successfully authenticated user1>
> 2016-07-19 16:28:16,400 DEBUG [org.springframework.jdbc.core.JdbcTemplate] -
> <Executing prepared SQL query>
> 2016-07-19 16:28:16,400 DEBUG [org.springframework.jdbc.core.JdbcTemplate] -
> <Executing prepared SQL statement[SELECT
> ID,username,FirstName,LastName,Email FROM User WHERE UserName = ?]>
> 2016-07-19 16:28:16,400 DEBUG
> [org.springframework.jdbc.datasource.DataSourceUtils] - <Fetching JDBC
> Connection from DataSource>
> 2016-07-19 16:28:16,401 DEBUG
> [org.springframework.jdbc.datasource.DataSourceUtils] - <Returning JDBC
> Connection to DataSource>
> 2016-07-19 16:28:19,015 INFO
> [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] -
> <LdapAuthenticationHandler successfully authenticated user2>
> 2016-07-19 16:28:19,015 DEBUG [org.springframework.jdbc.core.JdbcTemplate] -
> <Executing prepared SQL query>
> 2016-07-19 16:28:19,015 DEBUG [org.springframework.jdbc.core.JdbcTemplate] -
> <Executing prepared SQL statement[SELECT
> ID,username,FirstName,LastName,Email FROM User WHERE UserName = ?]>
> 2016-07-19 16:28:19,015 DEBUG
> [org.springframework.jdbc.datasource.DataSourceUtils] - <Fetching JDBC
> Connection from DataSource>
> 2016-07-19 16:28:19,017 DEBUG
> [org.springframework.jdbc.datasource.DataSourceUtils] - <Returning JDBC
> Connection to DataSource>
>
> Immediately before this, I've seen tickets that are created (an audit log
> is posted that a ticket granting ticket has been created and validated, and
> all is good). There are no exceptions thrown between when the tickets were
> able to be created and when there was this bottleneck.
>
> On the front end, after the logs say 'success' without a ticket created,
> they are redirected to the main cas login page. Reproducing this is also
> difficult as it will stop intermittently, without warning.
>
> What are the best ways to debug or resolve these sorts of issues? What
> could be causing this issue?
>
> Thanks in advance,
> Jeff
>
--
- CAS gitter chatroom: https://gitter.im/apereo/cas
- CAS mailing list guidelines: https://apereo.github.io/cas/Mailing-Lists.html
- CAS documentation website: https://apereo.github.io/cas
- CAS project website: https://github.com/apereo/cas
---
You received this message because you are subscribed to the Google Groups "CAS
Community" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
To view this discussion on the web visit
https://groups.google.com/a/apereo.org/d/msgid/cas-user/0c321acb-af7a-4ce5-9364-9302a433b235%40apereo.org.
