Student Success Plan
  1. Student Success Plan
  2. SSP-1848

Race condition in first time login for user with incorrect school_id

    Details

      Description

      SSP-1750 apparently didn't fix this one completely. E.g. pick a student in the demo data and modify their record to move their person record out of the way, then change their external_person.school_id to a value that won't match what uPortal expects. This mimics a situation where a deployer can't map schoolId out of AD, just username. First time login for such a student can result in MyGPS, for example, rendering in anonymous mode. Or for a coach it can result in clobbering of the SSP session such that the SSP portlet doesn't render or randomly errors out after rendering.

      To reproduce locally, I did this:

      update person set username = username ||'foo', school_id = school_id||'foo' 
      where school_id = 'jjohnson215';
      
      update external_person set school_id = school_id||'bar' 
      where school_id = 'jjohnson215';
      

      Then I tried impersonating jjohnson215 and I would get an anonymous MyGPS UI. The stack trace on the server:

      DEV: 20:49:52.508 [http-8080-6] INFO  o.j.s.service.impl.PersonServiceImpl - Successfully Created Account for jjohnson215
      DEV: 20:49:52.508 [http-8080-6] DEBUG o.j.s.s.impl.SecurityServiceImpl - Using the No Authentication Admin User
      DEV: 20:49:52.508 [http-8080-6] DEBUG o.j.s.s.impl.SecurityServiceImpl - Using the No Authentication Admin User
      DEV: 20:49:52.588 [http-8080-5] WARN  o.h.e.jdbc.spi.SqlExceptionHelper - SQL Error: 0, SQLState: 23505
      DEV: 20:49:52.588 [http-8080-5] ERROR o.h.e.jdbc.spi.SqlExceptionHelper - ERROR: duplicate key value violates unique constraint "unique_person_username"
        Detail: Key (username)=(jjohnson215) already exists.
      DEV: 20:49:52.610 [http-8080-5] INFO  o.h.e.j.b.internal.AbstractBatchImpl - HHH000010: On release of batch it still contained JDBC statements
      DEV: 20:49:52.637 [http-8080-6] DEBUG o.j.ssp.security.UserDetailsService - Loaded User: org.jasig.ssp.security.SspUser@4e2e08af: Username: jjohnson215; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: ROLE_MY_GPS_TOOL
      DEV: 20:49:52.638 [http-8080-5] WARN  o.j.s.s.u.UPortalPreAuthenticatedProcessingFilter - Cleared security context due to exception
      org.jasig.ssp.security.exception.UnableToCreateAccountException: Unable to Create Account for login.
      	at org.jasig.ssp.service.impl.PersonServiceImpl.createUserAccount(PersonServiceImpl.java:230) ~[PersonServiceImpl.class:na]
      	at org.jasig.ssp.service.impl.PersonServiceImpl.createUserAccount(PersonServiceImpl.java:129) ~[PersonServiceImpl.class:na]
      	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.6.0_37]
      	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) ~[na:1.6.0_37]
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) ~[na:1.6.0_37]
      	at java.lang.reflect.Method.invoke(Method.java:597) ~[na:1.6.0_37]
      	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:319) ~[spring-aop-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) ~[spring-aop-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) ~[spring-aop-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110) ~[spring-tx-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) ~[spring-aop-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) ~[spring-aop-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at $Proxy262.createUserAccount(Unknown Source) ~[na:na]
      	at org.jasig.ssp.security.UserDetailsService.loadUserDetails(UserDetailsService.java:76) ~[UserDetailsService.class:na]
      	at org.jasig.ssp.security.UserDetailsService.loadUserDetails(UserDetailsService.java:133) ~[UserDetailsService.class:na]
      	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.6.0_37]
      	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) ~[na:1.6.0_37]
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) ~[na:1.6.0_37]
      	at java.lang.reflect.Method.invoke(Method.java:597) ~[na:1.6.0_37]
      	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:319) ~[spring-aop-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) ~[spring-aop-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) ~[spring-aop-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110) ~[spring-tx-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) ~[spring-aop-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) ~[spring-aop-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at $Proxy280.loadUserDetails(Unknown Source) ~[na:na]
      	at org.springframework.security.web.authentication.preauth.PreAuthenticatedAuthenticationProvider.authenticate(PreAuthenticatedAuthenticationProvider.java:80) ~[spring-security-web-3.1.3.RELEASE.jar:3.1.3.RELEASE]
      	at org.springframework.security.authentication.ProviderManager.authenticate(ProviderManager.java:156) ~[spring-security-core-3.1.3.RELEASE.jar:3.1.3.RELEASE]
      	at org.jasig.ssp.security.uportal.UPortalPreAuthenticatedProcessingFilter.doAuthenticate(UPortalPreAuthenticatedProcessingFilter.java:176) [UPortalPreAuthenticatedProcessingFilter.class:na]
      	at org.jasig.ssp.security.uportal.UPortalPreAuthenticatedProcessingFilter.doFilter(UPortalPreAuthenticatedProcessingFilter.java:94) [UPortalPreAuthenticatedProcessingFilter.class:na]
      	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) [spring-security-web-3.1.3.RELEASE.jar:3.1.3.RELEASE]
      	at org.springframework.security.oauth2.provider.authentication.OAuth2AuthenticationProcessingFilter.doFilter(OAuth2AuthenticationProcessingFilter.java:131) [spring-security-oauth2-1.0.5.RELEASE.jar:na]
      	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) [spring-security-web-3.1.3.RELEASE.jar:3.1.3.RELEASE]
      	at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87) [spring-security-web-3.1.3.RELEASE.jar:3.1.3.RELEASE]
      	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) [spring-security-web-3.1.3.RELEASE.jar:3.1.3.RELEASE]
      	at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192) [spring-security-web-3.1.3.RELEASE.jar:3.1.3.RELEASE]
      	at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160) [spring-security-web-3.1.3.RELEASE.jar:3.1.3.RELEASE]
      	at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346) [spring-web-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:259) [spring-web-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.35]
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.35]
      	at org.jasig.ssp.security.uportal.RequestAndResponseAccessFilter.doFilter(RequestAndResponseAccessFilter.java:61) [RequestAndResponseAccessFilter.class:na]
      	at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346) [spring-web-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:259) [spring-web-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.35]
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.35]
      	at org.jasig.ssp.security.RequestCleanupServletFilter.doFilter(RequestCleanupServletFilter.java:40) [RequestCleanupServletFilter.class:na]
      	at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346) [spring-web-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:259) [spring-web-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.35]
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.35]
      	at org.springframework.orm.hibernate4.support.OpenSessionInViewFilter.doFilterInternal(OpenSessionInViewFilter.java:119) [spring-orm-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76) [spring-web-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.35]
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.35]
      	at ch.qos.logback.classic.helpers.MDCInsertingServletFilter.doFilter(MDCInsertingServletFilter.java:51) [logback-classic-1.0.0.jar:na]
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.35]
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.35]
      	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) [catalina.jar:6.0.35]
      	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina.jar:6.0.35]
      	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina.jar:6.0.35]
      	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [catalina.jar:6.0.35]
      	at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:615) [catalina.jar:6.0.35]
      	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina.jar:6.0.35]
      	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) [catalina.jar:6.0.35]
      	at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859) [tomcat-coyote.jar:6.0.35]
      	at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:602) [tomcat-coyote.jar:6.0.35]
      	at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489) [tomcat-coyote.jar:6.0.35]
      	at java.lang.Thread.run(Thread.java:680) [na:1.6.0_37]
      Caused by: java.lang.RuntimeException: org.jasig.ssp.service.ObjectNotFoundException: Person not found with schoolId: jjohnson215
      	at org.jasig.ssp.util.transaction.WithTransactionImpl.doWorkUnchecked(WithTransactionImpl.java:70) ~[WithTransactionImpl.class:na]
      	at org.jasig.ssp.util.transaction.WithTransactionImpl.withNewTransactionAndUncheckedExceptionsReadOnly(WithTransactionImpl.java:45) ~[WithTransactionImpl.class:na]
      	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.6.0_37]
      	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) ~[na:1.6.0_37]
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) ~[na:1.6.0_37]
      	at java.lang.reflect.Method.invoke(Method.java:597) ~[na:1.6.0_37]
      	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:319) ~[spring-aop-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) ~[spring-aop-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) ~[spring-aop-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110) ~[spring-tx-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) ~[spring-aop-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) ~[spring-aop-3.1.2.RELEASE.jar:3.1.2.RELEASE]
      	at $Proxy268.withNewTransactionAndUncheckedExceptionsReadOnly(Unknown Source) ~[na:na]
      	at org.jasig.ssp.service.impl.PersonServiceImpl.create(PersonServiceImpl.java:387) ~[PersonServiceImpl.class:na]
      	at org.jasig.ssp.service.impl.PersonServiceImpl.createUserAccount(PersonServiceImpl.java:189) ~[PersonServiceImpl.class:na]
      	... 68 common frames omitted
      Caused by: org.jasig.ssp.service.ObjectNotFoundException: Person not found with schoolId: jjohnson215
      	at org.jasig.ssp.dao.PersonDao.getBySchoolId(PersonDao.java:169) ~[PersonDao.class:na]
      	at org.jasig.ssp.service.impl.PersonServiceImpl$4.call(PersonServiceImpl.java:391) ~[PersonServiceImpl$4.class:na]
      	at org.jasig.ssp.service.impl.PersonServiceImpl$4.call(PersonServiceImpl.java:387) ~[PersonServiceImpl$4.class:na]
      	at org.jasig.ssp.util.transaction.WithTransactionImpl.doWork(WithTransactionImpl.java:61) ~[WithTransactionImpl.class:na]
      	at org.jasig.ssp.util.transaction.WithTransactionImpl.doWorkUnchecked(WithTransactionImpl.java:66) ~[WithTransactionImpl.class:na]
      	... 82 common frames omitted
      

      A successful fix won't necessarily eliminate all stack traces, but will result in the UI rendering correctly and will result in a new person record _with person.school_id sourced from external_person.school_id, not the uPortal account, i.e. person.school_id should be 'jjohnson215bar' in the example above.

        Issue Links

          Activity

          Hide
          Dan McCallum added a comment -

          Testing a fix...

          Show
          Dan McCallum added a comment - Testing a fix...
          Hide
          Dan McCallum added a comment - - edited

          Fixed in rel-2-0-patches for 2.0.1 and in rel-2-1-patches for 2.1.0. Still needs to be merged up into master for 2.2.0. Leaving merge labels attached pending QA.

          Show
          Dan McCallum added a comment - - edited Fixed in rel-2-0-patches for 2.0.1 and in rel-2-1-patches for 2.1.0. Still needs to be merged up into master for 2.2.0. Leaving merge labels attached pending QA.
          Hide
          Dan McCallum added a comment -

          Cherry-picked into master for 2.2.0. Leaving merge-to-2-2 label attached pending QA.

          Show
          Dan McCallum added a comment - Cherry-picked into master for 2.2.0. Leaving merge-to-2-2 label attached pending QA.

            People

            • Assignee:
              Dan McCallum
              Reporter:
              Dan McCallum
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: