Mar 21 18:42:16 AccessTokenFilter.java:55 DEBUG filter.AccessTokenFilter - Triggering Access Token Filter for path : /lms/web/nyr/getContentUrl
Mar 21 18:42:16 SapiSSOService.java:137 INFO service.SapiSSOService - Invalid Bearer Token or User Id
Mar 21 18:42:16 RBSOrganizationServiceClient.java:132 INFO client.RBSOrganizationServiceClient - Entering into getParentByOrganizationId of OrganizationServiceClient :8a72098d80932d440180a6f1a13a0036
Mar 21 18:42:16 RetryTemplate.java:324 DEBUG support.RetryTemplate - Retry: count=0
Mar 21 18:42:16 CompositeLog.java:147 DEBUG client.RestTemplate - HTTP GET https://org-service.nightly.savvasrealizedev.com/org-service/v1/organizations/8a72098d80932d440180a6f1a13a0036/parenttree
Mar 21 18:42:16 CompositeLog.java:147 DEBUG client.RestTemplate - Accept=[application/json, application/cbor, application/*+json]
Mar 21 18:42:18 CompositeLog.java:147 DEBUG client.RestTemplate - Response 200 OK
Mar 21 18:42:18 CompositeLog.java:147 DEBUG client.RestTemplate - Reading to [com.pst.lms.dto.RumbaOrgSummary]
Mar 21 18:42:18 RBSOrganizationServiceClient.java:160 INFO client.RBSOrganizationServiceClient - ParentOrganization rbs call returned with HttpStatus : 200 OK
Mar 21 18:42:18 AbstractPlatformTransactionManager.java:370 DEBUG hibernate5.HibernateTransactionManager - Creating new transaction with name [com.savvas.core.sso.dao.SapiSSODao.findTenantIdFromDistrict]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
Mar 21 18:42:18 HibernateTransactionManager.java:484 DEBUG hibernate5.HibernateTransactionManager - Opened new Session [SessionImpl(2018243554<open>)] for Hibernate transaction
Mar 21 18:42:18 TransactionImpl.java:53 DEBUG internal.TransactionImpl - On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
Mar 21 18:42:18 TransactionImpl.java:81 DEBUG internal.TransactionImpl - begin
Mar 21 18:42:18 HibernateTransactionManager.java:570 DEBUG hibernate5.HibernateTransactionManager - Exposing Hibernate transaction as JDBC [org.springframework.orm.hibernate5.HibernateTransactionManager$$Lambda$231/181936142@9823b5e]
Mar 21 18:42:18 SqlStatementLogger.java:144 DEBUG hibernate.SQL - SELECT ot.tenant_id, tn.nyr_date, tn.version
FROM school.organization_tenant ot JOIN school.tenant_nyr_date tn ON ot.tenant_id = tn.tenant_id
WHERE ot.district_id IN (?) AND tn.selected = 2
Mar 21 18:42:18 BasicBinder.java:64 TRACE sql.BasicBinder - binding parameter [1] as [VARCHAR] - [8a72071d7e51ae88017e7aef435101c6]
Mar 21 18:42:18 DelegatingBasicLogger.java:384 DEBUG loader.Loader - Result set row: 0
Mar 21 18:42:18 Loader.java:1593 DEBUG loader.Loader - Result row:
Mar 21 18:42:18 BasicExtractor.java:60 TRACE sql.BasicExtractor - extracted value ([tenant_id] : [OTHER]) - [a8222d65-b85c-4f2a-950e-b9c95ca2e0e6]
Mar 21 18:42:18 BasicExtractor.java:60 TRACE sql.BasicExtractor - extracted value ([nyr_date] : [TIMESTAMP]) - [2022-01-01 00:00:00.0]
Mar 21 18:42:18 BasicExtractor.java:60 TRACE sql.BasicExtractor - extracted value ([version] : [VARCHAR]) - [v22]
Mar 21 18:42:18 AbstractPlatformTransactionManager.java:740 DEBUG hibernate5.HibernateTransactionManager - Initiating transaction commit
Mar 21 18:42:18 HibernateTransactionManager.java:638 DEBUG hibernate5.HibernateTransactionManager - Committing Hibernate transaction on Session [SessionImpl(2018243554<open>)]
Mar 21 18:42:18 TransactionImpl.java:98 DEBUG internal.TransactionImpl - committing
Mar 21 18:42:18 HibernateTransactionManager.java:745 DEBUG hibernate5.HibernateTransactionManager - Closing Hibernate Session [SessionImpl(2018243554<open>)] after transaction
Mar 21 18:42:18 OpenSessionInViewFilter.java:192 DEBUG support.OpenSessionInViewFilter - Using SessionFactory 'lmsSessionFactory' for OpenSessionInViewFilter
Mar 21 18:42:18 OpenSessionInViewFilter.java:144 DEBUG support.OpenSessionInViewFilter - Opening Hibernate Session in OpenSessionInViewFilter
Mar 21 18:42:18 AntPathRequestMatcher.java:177 DEBUG matcher.AntPathRequestMatcher - Checking match of request : '/web/nyr/getContentUrl'; against '/web/api/v1/legacy/**'
Mar 21 18:42:18 FilterChainProxy.java:328 DEBUG web.FilterChainProxy - /web/nyr/getContentUrl at position 1 of 10 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
Mar 21 18:42:18 HttpSessionSecurityContextRepository.java:173 DEBUG context.HttpSessionSecurityContextRepository - No HttpSession currently exists
Mar 21 18:42:18 HttpSessionSecurityContextRepository.java:117 DEBUG context.HttpSessionSecurityContextRepository - No SecurityContext was available from the HttpSession: null. A new one will be created.
Mar 21 18:42:18 FilterChainProxy.java:328 DEBUG web.FilterChainProxy - /web/nyr/getContentUrl at position 2 of 10 in additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
Mar 21 18:42:18 FilterChainProxy.java:328 DEBUG web.FilterChainProxy - /web/nyr/getContentUrl at position 3 of 10 in additional filter chain; firing Filter: 'HeaderWriterFilter'
Mar 21 18:42:18 FilterChainProxy.java:328 DEBUG web.FilterChainProxy - /web/nyr/getContentUrl at position 4 of 10 in additional filter chain; firing Filter: 'BasicAuthenticationFilter'
Mar 21 18:42:18 BasicAuthenticationFilter.java:163 DEBUG www.BasicAuthenticationFilter - Basic Authentication Authorization header found for user 'user1'
Mar 21 18:42:18 ProviderManager.java:194 DEBUG authentication.ProviderManager - Authentication attempt using org.springframework.security.authentication.dao.DaoAuthenticationProvider
Mar 21 18:42:18 BasicAuthenticationFilter.java:172 DEBUG www.BasicAuthenticationFilter - Authentication success: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@835ce3c4: Principal: org.springframework.security.core.userdetails.User@6a68dc6: Username: user1; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: ROLE_BASIC_AUTH; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@b364: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: null; Granted Authorities: ROLE_BASIC_AUTH
Mar 21 18:42:18 FilterChainProxy.java:328 DEBUG web.FilterChainProxy - /web/nyr/getContentUrl at position 5 of 10 in additional filter chain; firing Filter: 'RequestCacheAwareFilter'
Mar 21 18:42:18 HttpSessionRequestCache.java:95 DEBUG savedrequest.HttpSessionRequestCache - saved request doesn't match
Mar 21 18:42:18 FilterChainProxy.java:328 DEBUG web.FilterChainProxy - /web/nyr/getContentUrl at position 6 of 10 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter'
Mar 21 18:42:18 FilterChainProxy.java:328 DEBUG web.FilterChainProxy - /web/nyr/getContentUrl at position 7 of 10 in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter'
Mar 21 18:42:18 AnonymousAuthenticationFilter.java:106 DEBUG authentication.AnonymousAuthenticationFilter - SecurityContextHolder not populated with anonymous token, as it already contained: 'org.springframework.security.authentication.UsernamePasswordAuthenticationToken@835ce3c4: Principal: org.springframework.security.core.userdetails.User@6a68dc6: Username: user1; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: ROLE_BASIC_AUTH; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@b364: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: null; Granted Authorities: ROLE_BASIC_AUTH'
Mar 21 18:42:18 FilterChainProxy.java:328 DEBUG web.FilterChainProxy - /web/nyr/getContentUrl at position 8 of 10 in additional filter chain; firing Filter: 'SessionManagementFilter'
Mar 21 18:42:18 CompositeSessionAuthenticationStrategy.java:87 DEBUG session.CompositeSessionAuthenticationStrategy - Delegating to org.springframework.security.web.authentication.session.ChangeSessionIdAuthenticationStrategy@10ad91e4
Mar 21 18:42:18 HttpSessionSecurityContextRepository.java:426 DEBUG context.HttpSessionSecurityContextRepository - HttpSession being created as SecurityContext is non-default
Mar 21 18:42:18 HttpSessionSecurityContextRepository.java:376 DEBUG context.HttpSessionSecurityContextRepository - SecurityContext 'org.springframework.security.core.context.SecurityContextImpl@835ce3c4: Authentication: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@835ce3c4: Principal: org.springframework.security.core.userdetails.User@6a68dc6: Username: user1; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: ROLE_BASIC_AUTH; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@b364: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: null; Granted Authorities: ROLE_BASIC_AUTH' stored to HttpSession: 'org.apache.catalina.session.StandardSessionFacade@458e72cb
Mar 21 18:42:18 FilterChainProxy.java:328 DEBUG web.FilterChainProxy - /web/nyr/getContentUrl at position 9 of 10 in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
Mar 21 18:42:18 FilterChainProxy.java:328 DEBUG web.FilterChainProxy - /web/nyr/getContentUrl at position 10 of 10 in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
Mar 21 18:42:18 AntPathRequestMatcher.java:177 DEBUG matcher.AntPathRequestMatcher - Checking match of request : '/web/nyr/getContentUrl'; against '/web/api/basicauth/**'
Mar 21 18:42:18 AntPathRequestMatcher.java:177 DEBUG matcher.AntPathRequestMatcher - Checking match of request : '/web/nyr/getContentUrl'; against '/web/api/autoassigncourse/**'
Mar 21 18:42:18 AntPathRequestMatcher.java:177 DEBUG matcher.AntPathRequestMatcher - Checking match of request : '/web/nyr/getContentUrl'; against '/web/api/v1/demoserver/**'
Mar 21 18:42:18 AntPathRequestMatcher.java:177 DEBUG matcher.AntPathRequestMatcher - Checking match of request : '/web/nyr/getContentUrl'; against '/web/files/**'
Mar 21 18:42:18 AntPathRequestMatcher.java:177 DEBUG matcher.AntPathRequestMatcher - Checking match of request : '/web/nyr/getContentUrl'; against '/web/s3migration/**'
Mar 21 18:42:18 AntPathRequestMatcher.java:177 DEBUG matcher.AntPathRequestMatcher - Checking match of request : '/web/nyr/getContentUrl'; against '/web/api/v1/rollover/**'
Mar 21 18:42:18 AntPathRequestMatcher.java:177 DEBUG matcher.AntPathRequestMatcher - Checking match of request : '/web/nyr/getContentUrl'; against '/web/nyr/getContentUrl/**'
Mar 21 18:42:18 AbstractSecurityInterceptor.java:219 DEBUG intercept.FilterSecurityInterceptor - Secure object: FilterInvocation: URL: /web/nyr/getContentUrl; Attributes: [hasRole('ROLE_BASIC_AUTH')]
Mar 21 18:42:18 AbstractSecurityInterceptor.java:348 DEBUG intercept.FilterSecurityInterceptor - Previously Authenticated: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@835ce3c4: Principal: org.springframework.security.core.userdetails.User@6a68dc6: Username: user1; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: ROLE_BASIC_AUTH; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@b364: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: null; Granted Authorities: ROLE_BASIC_AUTH
Mar 21 18:42:18 AffirmativeBased.java:66 DEBUG vote.AffirmativeBased - Voter: org.springframework.security.web.access.expression.WebExpressionVoter@11a8f16b, returned: 1
Mar 21 18:42:18 AbstractSecurityInterceptor.java:243 DEBUG intercept.FilterSecurityInterceptor - Authorization successful
Mar 21 18:42:18 AbstractSecurityInterceptor.java:256 DEBUG intercept.FilterSecurityInterceptor - RunAsManager did not change Authentication object
Mar 21 18:42:18 FilterChainProxy.java:313 DEBUG web.FilterChainProxy - /web/nyr/getContentUrl reached end of additional filter chain; proceeding with original chain
Mar 21 18:42:18 LogFormatUtils.java:119 DEBUG servlet.DispatcherServlet - GET "/lms/web/nyr/getContentUrl", parameters={}
Mar 21 18:42:18 AbstractHandlerMapping.java:515 DEBUG annotation.RequestMappingHandlerMapping - Mapped to com.pst.controllers.NYRController#getContentURL(String)
Mar 21 18:42:18 HibernateTransactionManager.java:426 DEBUG hibernate5.HibernateTransactionManager - Found thread-bound Session [SessionImpl(1250850333<open>)] for Hibernate transaction
Mar 21 18:42:18 AbstractPlatformTransactionManager.java:370 DEBUG hibernate5.HibernateTransactionManager - Creating new transaction with name [com.pst.lms.hibernateDao.ContentURLDao.fetchContentURL]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
Mar 21 18:42:18 TransactionImpl.java:53 DEBUG internal.TransactionImpl - On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
Mar 21 18:42:18 TransactionImpl.java:81 DEBUG internal.TransactionImpl - begin
Mar 21 18:42:18 HibernateTransactionManager.java:570 DEBUG hibernate5.HibernateTransactionManager - Exposing Hibernate transaction as JDBC [org.springframework.orm.hibernate5.HibernateTransactionManager$$Lambda$231/181936142@e0da85b]
Mar 21 18:42:18 SqlStatementLogger.java:144 DEBUG hibernate.SQL - SELECT tn.content_url
FROM school.tenant_nyr_date tn
WHERE tn.tenant_id = ? AND tn.selected = 2
Mar 21 18:42:18 BasicBinder.java:64 TRACE sql.BasicBinder - binding parameter [1] as [OTHER] - [a8222d65-b85c-4f2a-950e-b9c95ca2e0e6]
Mar 21 18:42:18 DelegatingBasicLogger.java:384 DEBUG loader.Loader - Result set row: 0
Mar 21 18:42:18 Loader.java:1593 DEBUG loader.Loader - Result row:
Mar 21 18:42:18 BasicExtractor.java:60 TRACE sql.BasicExtractor - extracted value ([content_url] : [VARCHAR]) - [temp_url]
Mar 21 18:42:18 AbstractPlatformTransactionManager.java:740 DEBUG hibernate5.HibernateTransactionManager - Initiating transaction commit
Mar 21 18:42:18 HibernateTransactionManager.java:638 DEBUG hibernate5.HibernateTransactionManager - Committing Hibernate transaction on Session [SessionImpl(1250850333<open>)]
Mar 21 18:42:18 TransactionImpl.java:98 DEBUG internal.TransactionImpl - committing
Mar 21 18:42:18 HibernateTransactionManager.java:751 DEBUG hibernate5.HibernateTransactionManager - Not closing pre-bound Hibernate Session [SessionImpl(1250850333<open>)] after transaction
Mar 21 18:42:18 SessionImpl.java:486 DEBUG internal.SessionImpl - Disconnecting session
Mar 21 18:42:18 AbstractMessageConverterMethodProcessor.java:255 DEBUG annotation.HttpEntityMethodProcessor - Using 'text/plain', given [*/*] and supported [text/plain, */*, application/json, application/*+json, application/cbor]
Mar 21 18:42:18 LogFormatUtils.java:119 DEBUG annotation.HttpEntityMethodProcessor - Writing ["temp_url"]
Mar 21 18:42:18 HstsHeaderWriter.java:169 DEBUG writers.HstsHeaderWriter - Not injecting HSTS header since it did not match the requestMatcher org.springframework.security.web.header.writers.HstsHeaderWriter$SecureRequestMatcher@563f40df
Mar 21 18:42:18 HttpSessionSecurityContextRepository.java:376 DEBUG context.HttpSessionSecurityContextRepository - SecurityContext 'org.springframework.security.core.context.SecurityContextImpl@835ce3c4: Authentication: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@835ce3c4: Principal: org.springframework.security.core.userdetails.User@6a68dc6: Username: user1; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: ROLE_BASIC_AUTH; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@b364: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: null; Granted Authorities: ROLE_BASIC_AUTH' stored to HttpSession: 'org.apache.catalina.session.StandardSessionFacade@458e72cb
Mar 21 18:42:18 FrameworkServlet.java:1131 DEBUG servlet.DispatcherServlet - Completed 200 OK
Mar 21 18:42:18 ExceptionTranslationFilter.java:120 DEBUG access.ExceptionTranslationFilter - Chain processed normally
Mar 21 18:42:18 SecurityContextPersistenceFilter.java:119 DEBUG context.SecurityContextPersistenceFilter - SecurityContextHolder now cleared, as request processing completed
Mar 21 18:42:18 OpenSessionInViewFilter.java:164 DEBUG support.OpenSessionInViewFilter - Closing Hibernate Session in OpenSessionInViewFilter