13:34:19,825 [main:jboss.web.deployment:war=lams-admin.war,id=1845789335 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Initializing filter 'HibernateFilter' 13:34:19,880 [main:jboss.web.deployment:war=lams-admin.war,id=1845789335 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Filter 'HibernateFilter' configured successfully 13:34:19,884 [main:jboss.web.deployment:war=lams-admin.war,id=1845789335 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Initializing filter 'LocaleFilter' 13:34:19,893 [main:jboss.web.deployment:war=lams-admin.war,id=1845789335 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Filter 'LocaleFilter' configured successfully 13:34:26,012 [main:jboss.web.deployment:war=lams-central.war,id=492141160 WebModule] INFO org.lamsfoundation.lams.contentrepository.service.SimpleRepository - Repository singleton being created. 13:34:28,330 [main:jboss.web.deployment:war=lams-central.war,id=492141160 WebModule] DEBUG org.lamsfoundation.lams.tool.qa.QaQueContent - org.apache.log4j.Logger@3525a2 org.lamsfoundation.lams.tool.qa.QaQueContentin constructor: QaQueContent() 13:34:28,364 [main:jboss.web.deployment:war=lams-central.war,id=492141160 WebModule] DEBUG org.lamsfoundation.lams.tool.qa.QaQueContent - org.apache.log4j.Logger@3525a2 org.lamsfoundation.lams.tool.qa.QaQueContent$$EnhancerByCGLIB$$af1dd89bin constructor: QaQueContent() 13:34:28,368 [main:jboss.web.deployment:war=lams-central.war,id=492141160 WebModule] DEBUG org.lamsfoundation.lams.tool.qa.QaQueContent - org.apache.log4j.Logger@3525a2 org.lamsfoundation.lams.tool.qa.QaQueContentin constructor: QaQueContent() 13:34:32,179 [main:jboss.web.deployment:war=lams-central.war,id=492141160 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Initializing filter 'hibernateFilter' 13:34:32,180 [main:jboss.web.deployment:war=lams-central.war,id=492141160 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Filter 'hibernateFilter' configured successfully 13:34:32,181 [main:jboss.web.deployment:war=lams-central.war,id=492141160 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Initializing filter 'LocaleFilter' 13:34:32,181 [main:jboss.web.deployment:war=lams-central.war,id=492141160 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Filter 'LocaleFilter' configured successfully 13:34:35,532 [main:jboss.web.deployment:war=lams-learning.war,id=-529931424 WebModule] INFO org.lamsfoundation.lams.contentrepository.service.SimpleRepository - Repository singleton being created. 13:34:36,200 [main:jboss.web.deployment:war=lams-learning.war,id=-529931424 WebModule] DEBUG org.lamsfoundation.lams.tool.qa.QaQueContent - org.apache.log4j.Logger@3525a2 org.lamsfoundation.lams.tool.qa.QaQueContentin constructor: QaQueContent() 13:34:36,206 [main:jboss.web.deployment:war=lams-learning.war,id=-529931424 WebModule] DEBUG org.lamsfoundation.lams.tool.qa.QaQueContent - org.apache.log4j.Logger@3525a2 org.lamsfoundation.lams.tool.qa.QaQueContent$$EnhancerByCGLIB$$af1dd89bin constructor: QaQueContent() 13:34:36,207 [main:jboss.web.deployment:war=lams-learning.war,id=-529931424 WebModule] DEBUG org.lamsfoundation.lams.tool.qa.QaQueContent - org.apache.log4j.Logger@3525a2 org.lamsfoundation.lams.tool.qa.QaQueContentin constructor: QaQueContent() 13:34:37,266 [main:jboss.web.deployment:war=lams-learning.war,id=-529931424 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Initializing filter 'LocaleFilter' 13:34:37,267 [main:jboss.web.deployment:war=lams-learning.war,id=-529931424 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Filter 'LocaleFilter' configured successfully 13:34:40,392 [main:jboss.web.deployment:war=lams-monitoring.war,id=-1115738038 WebModule] INFO org.lamsfoundation.lams.contentrepository.service.SimpleRepository - Repository singleton being created. 13:34:40,906 [main:jboss.web.deployment:war=lams-monitoring.war,id=-1115738038 WebModule] DEBUG org.lamsfoundation.lams.tool.qa.QaQueContent - org.apache.log4j.Logger@3525a2 org.lamsfoundation.lams.tool.qa.QaQueContentin constructor: QaQueContent() 13:34:40,911 [main:jboss.web.deployment:war=lams-monitoring.war,id=-1115738038 WebModule] DEBUG org.lamsfoundation.lams.tool.qa.QaQueContent - org.apache.log4j.Logger@3525a2 org.lamsfoundation.lams.tool.qa.QaQueContent$$EnhancerByCGLIB$$af1dd89bin constructor: QaQueContent() 13:34:40,912 [main:jboss.web.deployment:war=lams-monitoring.war,id=-1115738038 WebModule] DEBUG org.lamsfoundation.lams.tool.qa.QaQueContent - org.apache.log4j.Logger@3525a2 org.lamsfoundation.lams.tool.qa.QaQueContentin constructor: QaQueContent() 13:34:42,139 [main:jboss.web.deployment:war=lams-monitoring.war,id=-1115738038 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Initializing filter 'HibernateFilter' 13:34:42,139 [main:jboss.web.deployment:war=lams-monitoring.war,id=-1115738038 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Filter 'HibernateFilter' configured successfully 13:34:42,140 [main:jboss.web.deployment:war=lams-monitoring.war,id=-1115738038 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Initializing filter 'LocaleFilter' 13:34:42,140 [main:jboss.web.deployment:war=lams-monitoring.war,id=-1115738038 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Filter 'LocaleFilter' configured successfully 13:34:44,043 [main:jboss.web.deployment:war=lams-tool-lachat11.war,id=-1797262198 WebModule] INFO org.lamsfoundation.lams.contentrepository.service.SimpleRepository - Repository singleton being created. 13:34:44,264 [main:jboss.web.deployment:war=lams-tool-lachat11.war,id=-1797262198 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Initializing filter 'hibernateFilter' 13:34:44,264 [main:jboss.web.deployment:war=lams-tool-lachat11.war,id=-1797262198 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Filter 'hibernateFilter' configured successfully 13:34:44,265 [main:jboss.web.deployment:war=lams-tool-lachat11.war,id=-1797262198 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Initializing filter 'LocaleFilter' 13:34:44,265 [main:jboss.web.deployment:war=lams-tool-lachat11.war,id=-1797262198 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Filter 'LocaleFilter' configured successfully 13:34:46,195 [main:jboss.web.deployment:war=lams-tool-lafrum11.war,id=-407601002 WebModule] INFO org.lamsfoundation.lams.contentrepository.service.SimpleRepository - Repository singleton being created. 13:34:46,690 [main:jboss.web.deployment:war=lams-tool-lafrum11.war,id=-407601002 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Initializing filter 'LocaleFilter' 13:34:46,691 [main:jboss.web.deployment:war=lams-tool-lafrum11.war,id=-407601002 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Filter 'LocaleFilter' configured successfully 13:34:48,767 [main:jboss.web.deployment:war=lams-tool-lamc11.war,id=1678674824 WebModule] INFO org.lamsfoundation.lams.contentrepository.service.SimpleRepository - Repository singleton being created. 13:34:48,957 [main:jboss.web.deployment:war=lams-tool-lamc11.war,id=1678674824 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Initializing filter 'hibernateFilter' 13:34:48,958 [main:jboss.web.deployment:war=lams-tool-lamc11.war,id=1678674824 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Filter 'hibernateFilter' configured successfully 13:34:48,958 [main:jboss.web.deployment:war=lams-tool-lamc11.war,id=1678674824 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Initializing filter 'LocaleFilter' 13:34:48,958 [main:jboss.web.deployment:war=lams-tool-lamc11.war,id=1678674824 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Filter 'LocaleFilter' configured successfully 13:34:50,674 [main:jboss.web.deployment:war=lams-tool-lanb11.war,id=-1760985818 WebModule] INFO org.lamsfoundation.lams.contentrepository.service.SimpleRepository - Repository singleton being created. 13:34:50,816 [main:jboss.web.deployment:war=lams-tool-lanb11.war,id=-1760985818 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Initializing filter 'hibernateFilter' 13:34:50,816 [main:jboss.web.deployment:war=lams-tool-lanb11.war,id=-1760985818 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Filter 'hibernateFilter' configured successfully 13:34:50,816 [main:jboss.web.deployment:war=lams-tool-lanb11.war,id=-1760985818 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Initializing filter 'LocaleFilter' 13:34:50,817 [main:jboss.web.deployment:war=lams-tool-lanb11.war,id=-1760985818 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Filter 'LocaleFilter' configured successfully 13:34:52,359 [main:jboss.web.deployment:war=lams-tool-lantbk11.war,id=-1828316031 WebModule] INFO org.lamsfoundation.lams.contentrepository.service.SimpleRepository - Repository singleton being created. 13:34:52,549 [main:jboss.web.deployment:war=lams-tool-lantbk11.war,id=-1828316031 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Initializing filter 'hibernateFilter' 13:34:52,550 [main:jboss.web.deployment:war=lams-tool-lantbk11.war,id=-1828316031 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Filter 'hibernateFilter' configured successfully 13:34:52,550 [main:jboss.web.deployment:war=lams-tool-lantbk11.war,id=-1828316031 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Initializing filter 'LocaleFilter' 13:34:52,550 [main:jboss.web.deployment:war=lams-tool-lantbk11.war,id=-1828316031 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Filter 'LocaleFilter' configured successfully 13:34:54,153 [main:jboss.web.deployment:war=lams-tool-laqa11.war,id=-1715025790 WebModule] INFO org.lamsfoundation.lams.contentrepository.service.SimpleRepository - Repository singleton being created. 13:34:54,256 [main:jboss.web.deployment:war=lams-tool-laqa11.war,id=-1715025790 WebModule] DEBUG org.lamsfoundation.lams.tool.qa.QaQueContent - org.apache.log4j.Logger@3525a2 org.lamsfoundation.lams.tool.qa.QaQueContentin constructor: QaQueContent() 13:34:54,261 [main:jboss.web.deployment:war=lams-tool-laqa11.war,id=-1715025790 WebModule] DEBUG org.lamsfoundation.lams.tool.qa.QaQueContent - org.apache.log4j.Logger@3525a2 org.lamsfoundation.lams.tool.qa.QaQueContent$$EnhancerByCGLIB$$af1dd89bin constructor: QaQueContent() 13:34:54,261 [main:jboss.web.deployment:war=lams-tool-laqa11.war,id=-1715025790 WebModule] DEBUG org.lamsfoundation.lams.tool.qa.QaQueContent - org.apache.log4j.Logger@3525a2 org.lamsfoundation.lams.tool.qa.QaQueContentin constructor: QaQueContent() 13:34:54,321 [main:jboss.web.deployment:war=lams-tool-laqa11.war,id=-1715025790 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Initializing filter 'hibernateFilter' 13:34:54,322 [main:jboss.web.deployment:war=lams-tool-laqa11.war,id=-1715025790 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Filter 'hibernateFilter' configured successfully 13:34:54,322 [main:jboss.web.deployment:war=lams-tool-laqa11.war,id=-1715025790 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Initializing filter 'LocaleFilter' 13:34:54,323 [main:jboss.web.deployment:war=lams-tool-laqa11.war,id=-1715025790 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Filter 'LocaleFilter' configured successfully 13:34:56,545 [main:jboss.web.deployment:war=lams-tool-larsrc11.war,id=-1496816156 WebModule] INFO org.lamsfoundation.lams.contentrepository.service.SimpleRepository - Repository singleton being created. 13:34:56,951 [main:jboss.web.deployment:war=lams-tool-larsrc11.war,id=-1496816156 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Initializing filter 'LocaleFilter' 13:34:56,951 [main:jboss.web.deployment:war=lams-tool-larsrc11.war,id=-1496816156 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Filter 'LocaleFilter' configured successfully 13:34:58,959 [main:jboss.web.deployment:war=lams-tool-lasbmt11.war,id=1047168744 WebModule] INFO org.lamsfoundation.lams.contentrepository.service.SimpleRepository - Repository singleton being created. 13:34:59,257 [main:jboss.web.deployment:war=lams-tool-lasbmt11.war,id=1047168744 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Initializing filter 'LocaleFilter' 13:34:59,257 [main:jboss.web.deployment:war=lams-tool-lasbmt11.war,id=1047168744 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Filter 'LocaleFilter' configured successfully 13:35:01,185 [main:jboss.web.deployment:war=lams-tool-lascrb11.war,id=568634290 WebModule] INFO org.lamsfoundation.lams.contentrepository.service.SimpleRepository - Repository singleton being created. 13:35:01,423 [main:jboss.web.deployment:war=lams-tool-lascrb11.war,id=568634290 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Initializing filter 'hibernateFilter' 13:35:01,423 [main:jboss.web.deployment:war=lams-tool-lascrb11.war,id=568634290 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Filter 'hibernateFilter' configured successfully 13:35:01,424 [main:jboss.web.deployment:war=lams-tool-lascrb11.war,id=568634290 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Initializing filter 'LocaleFilter' 13:35:01,424 [main:jboss.web.deployment:war=lams-tool-lascrb11.war,id=568634290 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Filter 'LocaleFilter' configured successfully 13:35:03,063 [main:jboss.web.deployment:war=lams-tool-lasurv11.war,id=-1330570536 WebModule] INFO org.lamsfoundation.lams.contentrepository.service.SimpleRepository - Repository singleton being created. 13:35:03,748 [main:jboss.web.deployment:war=lams-tool-lasurv11.war,id=-1330570536 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Initializing filter 'LocaleFilter' 13:35:03,749 [main:jboss.web.deployment:war=lams-tool-lasurv11.war,id=-1330570536 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Filter 'LocaleFilter' configured successfully 13:35:05,363 [main:jboss.web.deployment:war=lams-tool-lavote11.war,id=1617641116 WebModule] INFO org.lamsfoundation.lams.contentrepository.service.SimpleRepository - Repository singleton being created. 13:35:05,514 [main:jboss.web.deployment:war=lams-tool-lavote11.war,id=1617641116 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Initializing filter 'hibernateFilter' 13:35:05,514 [main:jboss.web.deployment:war=lams-tool-lavote11.war,id=1617641116 WebModule] INFO org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Filter 'hibernateFilter' configured successfully 13:35:05,515 [main:jboss.web.deployment:war=lams-tool-lavote11.war,id=1617641116 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Initializing filter 'LocaleFilter' 13:35:05,515 [main:jboss.web.deployment:war=lams-tool-lavote11.war,id=1617641116 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Filter 'LocaleFilter' configured successfully 13:35:05,777 [main:jboss.web.deployment:war=lams-www.war,id=-1998041594 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Initializing filter 'LocaleFilter' 13:35:05,778 [main:jboss.web.deployment:war=lams-www.war,id=-1998041594 WebModule] INFO org.lamsfoundation.lams.web.filter.LocaleFilter - Filter 'LocaleFilter' configured successfully 13:36:42,191 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/services/VerificationService' 13:36:42,191 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:36:42,191 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:36:42,271 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Using SessionFactory 'coreSessionFactory' for OpenSessionInViewFilter 13:36:42,274 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Opening single Hibernate Session in OpenSessionInViewFilter 13:36:42,581 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Closing single Hibernate Session in OpenSessionInViewFilter 13:36:42,597 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/services/VerificationService' 13:36:42,597 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:36:42,597 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:36:42,597 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Using SessionFactory 'coreSessionFactory' for OpenSessionInViewFilter 13:36:42,598 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Opening single Hibernate Session in OpenSessionInViewFilter 13:36:43,397 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Closing single Hibernate Session in OpenSessionInViewFilter 13:37:15,556 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/LoginRequest' 13:37:15,556 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:37:15,557 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:37:15,595 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Using SessionFactory 'coreSessionFactory' for OpenSessionInViewFilter 13:37:15,598 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Opening single Hibernate Session in OpenSessionInViewFilter 13:37:15,649 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Closing single Hibernate Session in OpenSessionInViewFilter 13:37:15,650 [http-0.0.0.0-8080-1:] INFO org.lamsfoundation.lams.integration.security.LoginRequestValve - There are 2 headers in the response 13:37:15,651 [http-0.0.0.0-8080-1:] INFO org.lamsfoundation.lams.integration.security.LoginRequestValve - X-Powered-By = Servlet 2.4; JBoss-4.0.2 (build: CVSTag=JBoss_4_0_2 date=200505022023)/Tomcat-5.5 13:37:15,651 [http-0.0.0.0-8080-1:] INFO org.lamsfoundation.lams.integration.security.LoginRequestValve - Set-Cookie = JSESSIONID=0C36F5BD794308FD56AB66F85400E03E; Path=/ 13:37:15,651 [http-0.0.0.0-8080-1:] INFO org.lamsfoundation.lams.integration.security.LoginRequestValve - LOGIN REQUEST DETECTED - BUT NO LOGIN IS CARRIED OUT 13:37:21,876 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/services/LearningDesignRepositoryService' 13:37:21,877 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:37:21,877 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:37:21,877 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Using SessionFactory 'coreSessionFactory' for OpenSessionInViewFilter 13:37:21,877 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Opening single Hibernate Session in OpenSessionInViewFilter 13:37:21,914 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Closing single Hibernate Session in OpenSessionInViewFilter 13:37:21,935 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/services/LearningDesignRepositoryService' 13:37:21,935 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:37:21,935 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:37:21,936 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Using SessionFactory 'coreSessionFactory' for OpenSessionInViewFilter 13:37:21,936 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Opening single Hibernate Session in OpenSessionInViewFilter 13:37:22,048 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.integration.service.IntegrationService - http://hilbert.mat.uc.pt/Moodle/mod/lamstwo/userinfo.php?un=moodle&ts=1174397842047&hs=17f55577e7a520ee200ad795ff63a23cd3c1cb48 13:37:22,077 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.webservice.LearningDesignRepositorySoapBindingImpl - Fail to fetch user data from external server:moodler - Unexpected return HTTP Status:401 org.lamsfoundation.lams.integration.UserInfoFetchException: Fail to fetch user data from external server:moodler - Unexpected return HTTP Status:401 at org.lamsfoundation.lams.integration.service.IntegrationService.getUserDataFromExtServer(IntegrationService.java:238) at org.lamsfoundation.lams.integration.service.IntegrationService.createExtUserUseridMap(IntegrationService.java:177) at org.lamsfoundation.lams.integration.service.IntegrationService.getExtUserUseridMap(IntegrationService.java:130) at org.lamsfoundation.lams.integration.service.IntegrationService$$FastClassByCGLIB$$24924e31.invoke() at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:149) at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:685) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170) at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:623) at org.lamsfoundation.lams.integration.service.IntegrationService$$EnhancerByCGLIB$$281dd714_2.getExtUserUseridMap() at org.lamsfoundation.lams.webservice.LearningDesignRepositorySoapBindingImpl.getLearningDesigns(LearningDesignRepositorySoapBindingImpl.java:161) at org.lamsfoundation.lams.webservice.LearningDesignRepositorySoapBindingSkeleton.getLearningDesigns(LearningDesignRepositorySoapBindingSkeleton.java:115) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.apache.axis.providers.java.RPCProvider.invokeMethod(RPCProvider.java:397) at org.apache.axis.providers.java.RPCProvider.processMessage(RPCProvider.java:186) at org.apache.axis.providers.java.JavaProvider.invoke(JavaProvider.java:323) at org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:32) at org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:118) at org.apache.axis.SimpleChain.invoke(SimpleChain.java:83) at org.apache.axis.handlers.soap.SOAPService.invoke(SOAPService.java:454) at org.apache.axis.server.AxisServer.invoke(AxisServer.java:281) at org.apache.axis.transport.http.AxisServlet.doPost(AxisServlet.java:699) at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) at org.apache.axis.transport.http.AxisServletBase.service(AxisServletBase.java:327) at javax.servlet.http.HttpServlet.service(HttpServlet.java:810) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173) at org.springframework.orm.hibernate3.support.OpenSessionInViewFilter.doFilterInternal(OpenSessionInViewFilter.java:174) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:77) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173) at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:81) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178) at org.jboss.web.tomcat.security.CustomPrincipalValve.invoke(CustomPrincipalValve.java:39) at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:153) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:407) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:407) at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:59) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105) at org.lamsfoundation.lams.integration.security.SingleSignOn.invoke(SingleSignOn.java:89) at org.lamsfoundation.lams.integration.security.LoginRequestValve.invoke(LoginRequestValve.java:67) at org.apache.catalina.valves.FastCommonAccessLogValve.invoke(FastCommonAccessLogValve.java:481) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148) at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:856) at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:744) at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527) at org.apache.tomcat.util.net.MasterSlaveWorkerThread.run(MasterSlaveWorkerThread.java:112) at java.lang.Thread.run(Thread.java:619) 13:37:22,091 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Closing single Hibernate Session in OpenSessionInViewFilter 13:38:37,402 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/' 13:38:37,402 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:37,403 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:38:37,531 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.security.JspRedirectStrategy - ===>LOGIN PAGE: there is no auth obj in session, auth obj created. session id: 0C36F5BD794308FD56AB66F85400E03E 13:38:37,539 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/index.jsp' 13:38:37,539 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:37,540 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:38:37,541 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.security.JspRedirectStrategy - ===>LOGIN PAGE: accessing login page before login succeed, display login page. session id: 0C36F5BD794308FD56AB66F85400E03E 13:38:37,547 [http-0.0.0.0-8080-2:] ERROR org.lamsfoundation.lams.web.session.SessionManager - Failed on finding current system session with null sessionId 13:38:37,550 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.web.filter.LocaleFilter - Locale set from server is pt,BR 13:38:37,555 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.security.JspRedirectStrategy - Set locale information for login page:pt 13:38:37,616 [http-0.0.0.0-8080-2:] ERROR org.lamsfoundation.lams.web.session.SessionManager - Failed on finding current system session with null sessionId 13:38:37,825 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/www/news.html' 13:38:37,825 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:37,825 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:38:37,826 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - ==>Couldn't find the sso cookie 13:38:37,827 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - ==>Created one - ff808081116f8e0901116f921a820049 13:38:37,827 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - SessionManager: cookie is null, generating a new session 13:38:37,830 [http-0.0.0.0-8080-1:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - SessionManager: creating new session ff808081116f8e0901116f921a83004a 13:38:37,895 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/css/defaultHTML.css' 13:38:37,896 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:37,896 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:38:37,981 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/includes/javascript/flash_detect.js' 13:38:37,981 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:37,981 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:38:37,983 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams//favicon.ico' 13:38:37,983 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:37,984 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:38:37,997 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/includes/javascript/browser_detect.js' 13:38:37,997 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:37,998 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:38:38,014 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/includes/javascript/sha1.js' 13:38:38,014 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:38,015 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:38:38,040 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams//images/css/lams_login.gif' 13:38:38,040 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:38,041 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:38:38,043 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/diagonal_bg.gif' 13:38:38,043 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:38,044 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:38:38,054 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/top_bg.jpg' 13:38:38,055 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:38,055 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:38:38,066 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/body_bg.jpg' 13:38:38,066 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:38,066 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:38:38,072 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/warning.gif' 13:38:38,073 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:38,073 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:38:38,078 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/lams_login_bar.jpg' 13:38:38,078 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:38,079 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:38:38,094 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/btn_off.gif' 13:38:38,094 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:38,095 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:38:38,097 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/footer_bg.jpg' 13:38:38,097 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:38,098 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:38:43,879 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/j_security_check' 13:38:43,879 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:43,879 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:38:43,880 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - ==>Couldn't find the sso cookie 13:38:43,880 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - ==>Created one - ff808081116f8e0901116f923228004b 13:38:43,880 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - SessionManager: cookie is not null, currentSessionId=0C36F5BD794308FD56AB66F85400E03E session=null 13:38:43,883 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - SessionManager: creating new session 0C36F5BD794308FD56AB66F85400E03E 13:38:43,909 [http-0.0.0.0-8080-2:] INFO org.lamsfoundation.lams.security.UniversalLoginModule - initialize 13:38:43,912 [http-0.0.0.0-8080-2:] INFO org.lamsfoundation.lams.security.UniversalLoginModule - login 13:38:43,913 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.security.UniversalLoginModule - ===> validatePassword() called: 969f64b52f259b9ca66e34225cef9fd7984684c8 : 13:38:44,058 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.security.UniversalLoginModule - ===> authenticating user: lams 13:38:44,074 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.security.UniversalLoginModule - ===>dsJndiName = java:/jdbc/lams-ds 13:38:44,074 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.security.UniversalLoginModule - ===>principalsQuery = select password from lams_user where login=? 13:38:44,074 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.security.UniversalLoginModule - ===>rolesQuery = SELECT DISTINCT r.name,'Roles' FROM lams_user u LEFT OUTER JOIN lams_user_organisation uo USING(user_id) LEFT OUTER JOIN lams_user_organisation_role urr USING(user_organisation_id) LEFT OUTER JOIN lams_role r USING (role_id) WHERE u.login=? 13:38:44,074 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.security.UniversalLoginModule - ===> authentication type :LAMS 13:38:44,077 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.security.UniversalLoginModule - ===> LAMS:: user:lams:969f64b52f259b9ca66e34225cef9fd7984684c8 authenticated! 13:38:44,097 [http-0.0.0.0-8080-2:] INFO org.lamsfoundation.lams.security.UniversalLoginModule - User 'lams' authenticated, loginOk=true 13:38:44,098 [http-0.0.0.0-8080-2:] INFO org.lamsfoundation.lams.security.UniversalLoginModule - commit, loginOk=true 13:38:44,098 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.security.UniversalLoginModule - ===> getRoleSets() called: java:/jdbc/lams-ds: SELECT DISTINCT r.name,'Roles' FROM lams_user u LEFT OUTER JOIN lams_user_organisation uo USING(user_id) LEFT OUTER JOIN lams_user_organisation_role urr USING(user_organisation_id) LEFT OUTER JOIN lams_role r USING (role_id) WHERE u.login=? 13:38:44,128 [http-0.0.0.0-8080-2:] INFO org.lamsfoundation.lams.security.UniversalLoginModule - Assign user to role SYSADMIN 13:38:44,128 [http-0.0.0.0-8080-2:] INFO org.lamsfoundation.lams.security.UniversalLoginModule - Found SYSADMIN 13:38:44,128 [http-0.0.0.0-8080-2:] INFO org.lamsfoundation.lams.security.UniversalLoginModule - Assign user to role AUTHOR 13:38:44,140 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/index.jsp' 13:38:44,141 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:44,141 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:44,141 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:44,143 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:44,144 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - SessionManager: cookie is not null, currentSessionId=0C36F5BD794308FD56AB66F85400E03E session=org.lamsfoundation.lams.web.session.SessionManager$SessionImpl@3589 13:38:44,144 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Using SessionFactory 'coreSessionFactory' for OpenSessionInViewFilter 13:38:44,145 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Opening single Hibernate Session in OpenSessionInViewFilter 13:38:44,145 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.web.filter.LocaleFilter - Locale set from user lang/country is pt,BR 13:38:44,213 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Closing single Hibernate Session in OpenSessionInViewFilter 13:38:44,241 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/css/defaultHTML_learner.css' 13:38:44,241 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:44,242 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:44,243 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:44,243 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:44,331 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/loading.gif' 13:38:44,331 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:44,331 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:44,331 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:44,331 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:44,355 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/favicon.ico' 13:38:44,355 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:44,356 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:44,356 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:44,464 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/index.do' 13:38:44,464 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:44,464 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:44,464 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:44,464 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:44,465 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - SessionManager: cookie is not null, currentSessionId=0C36F5BD794308FD56AB66F85400E03E session=org.lamsfoundation.lams.web.session.SessionManager$SessionImpl@3589 13:38:44,465 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Using SessionFactory 'coreSessionFactory' for OpenSessionInViewFilter 13:38:44,465 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Opening single Hibernate Session in OpenSessionInViewFilter 13:38:44,466 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.web.filter.LocaleFilter - Locale set from user lang/country is pt,BR 13:38:44,525 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.web.IndexAction - User:lams 13:38:44,526 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.web.IndexAction - user is author 13:38:44,528 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.web.IndexAction - set headerLinks in request 13:38:44,641 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.web.IndexAction - archived date: null 13:38:44,733 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.web.IndexAction - archived date: null 13:38:44,787 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.web.IndexAction - archived date: null 13:38:44,970 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Closing single Hibernate Session in OpenSessionInViewFilter 13:38:45,090 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/includes/javascript/getSysInfo.js' 13:38:45,091 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:45,092 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:45,092 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:45,093 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:45,138 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/includes/javascript/openUrls.js' 13:38:45,138 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:45,139 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:45,139 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:45,139 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:45,159 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/lams_logo.gif' 13:38:45,160 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:45,161 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:45,161 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:45,161 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:45,166 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/user.jpg' 13:38:45,167 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:45,168 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:45,168 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:45,168 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:45,173 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/selected_left.jpg' 13:38:45,173 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:45,174 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:45,175 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:45,175 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:45,174 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/selected_bg.jpg' 13:38:45,178 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:45,179 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:45,179 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:45,179 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:45,186 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/selected_right.jpg' 13:38:45,186 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:45,188 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:45,188 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:45,189 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:45,190 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/button_highlight_left.jpg' 13:38:45,191 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:45,191 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:45,191 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:45,191 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:45,194 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/button_highlight_right.jpg' 13:38:45,196 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:45,196 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:45,197 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:45,197 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:45,200 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/button_highlight_bg.jpg' 13:38:45,204 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:45,205 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:45,205 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:45,205 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:45,208 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/button_left.jpg' 13:38:45,209 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:45,210 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:45,210 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:45,211 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:45,213 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/button_bg.jpg' 13:38:45,214 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:45,226 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/button_right.jpg' 13:38:45,226 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:45,226 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:45,226 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:45,226 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:45,233 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:45,234 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:45,234 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:45,239 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/mycourses_greentab.jpg' 13:38:45,239 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:45,240 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:45,241 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:45,241 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:45,244 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/manage_groups.jpg' 13:38:45,248 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:45,250 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:45,250 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:45,251 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:51,119 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/admin/sysadminstart.do' 13:38:51,119 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:51,120 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:51,120 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:51,120 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - SessionManager: cookie is not null, currentSessionId=0C36F5BD794308FD56AB66F85400E03E session=org.lamsfoundation.lams.web.session.SessionManager$SessionImpl@3589 13:38:51,121 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.web.filter.LocaleFilter - Locale set from user lang/country is pt,BR 13:38:51,121 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Using SessionFactory 'coreSessionFactory' for OpenSessionInViewFilter 13:38:51,121 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Opening single Hibernate Session in OpenSessionInViewFilter 13:38:51,562 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams//includes/javascript/changeStyle.js' 13:38:51,563 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:51,564 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:51,564 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:51,564 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:51,566 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Closing single Hibernate Session in OpenSessionInViewFilter 13:38:53,697 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/admin/serverlist.do' 13:38:53,697 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:53,697 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:53,697 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:53,698 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - SessionManager: cookie is not null, currentSessionId=0C36F5BD794308FD56AB66F85400E03E session=org.lamsfoundation.lams.web.session.SessionManager$SessionImpl@3589 13:38:53,698 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.web.filter.LocaleFilter - Locale set from user lang/country is pt,BR 13:38:53,699 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Using SessionFactory 'coreSessionFactory' for OpenSessionInViewFilter 13:38:53,699 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Opening single Hibernate Session in OpenSessionInViewFilter 13:38:53,784 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Closing single Hibernate Session in OpenSessionInViewFilter 13:38:53,818 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/green_bg.jpg' 13:38:53,818 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:53,819 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:53,819 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:53,820 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:38:53,826 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/greyfade_bg.jpg' 13:38:53,826 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:38:53,827 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:38:53,828 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:38:53,828 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:39:01,304 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/admin/servermaintain.do' 13:39:01,305 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:39:01,305 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:39:01,305 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:39:01,306 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - SessionManager: cookie is not null, currentSessionId=0C36F5BD794308FD56AB66F85400E03E session=org.lamsfoundation.lams.web.session.SessionManager$SessionImpl@3589 13:39:01,306 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.web.filter.LocaleFilter - Locale set from user lang/country is pt,BR 13:39:01,306 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Using SessionFactory 'coreSessionFactory' for OpenSessionInViewFilter 13:39:01,306 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Opening single Hibernate Session in OpenSessionInViewFilter 13:39:01,448 [http-0.0.0.0-8080-2:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Closing single Hibernate Session in OpenSessionInViewFilter 13:39:01,464 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/help.jpg' 13:39:01,465 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:39:01,465 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:39:01,466 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:39:01,466 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:39:54,438 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/images/css/btn_over.gif' 13:39:54,439 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:39:54,440 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:39:54,440 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:39:54,440 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:39:57,889 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/admin/serversave.do' 13:39:57,889 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:39:57,889 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:39:57,889 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:39:57,889 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - SessionManager: cookie is not null, currentSessionId=0C36F5BD794308FD56AB66F85400E03E session=org.lamsfoundation.lams.web.session.SessionManager$SessionImpl@3589 13:39:57,890 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.web.filter.LocaleFilter - Locale set from user lang/country is pt,BR 13:39:57,890 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Using SessionFactory 'coreSessionFactory' for OpenSessionInViewFilter 13:39:57,890 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Opening single Hibernate Session in OpenSessionInViewFilter 13:39:57,952 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Closing single Hibernate Session in OpenSessionInViewFilter 13:40:02,679 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/home.do' 13:40:02,680 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:40:02,680 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:40:02,680 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - principal - lams 13:40:02,680 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Found cached principal 'lams' with auth type 'FORM' 13:40:02,681 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - SessionManager: cookie is not null, currentSessionId=0C36F5BD794308FD56AB66F85400E03E session=org.lamsfoundation.lams.web.session.SessionManager$SessionImpl@3589 13:40:02,681 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Using SessionFactory 'coreSessionFactory' for OpenSessionInViewFilter 13:40:02,681 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Opening single Hibernate Session in OpenSessionInViewFilter 13:40:02,681 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.web.filter.LocaleFilter - Locale set from user lang/country is pt,BR 13:40:02,690 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.security.JspRedirectStrategy - ===>LOGIN PAGE: there is no auth obj in session, auth obj created. session id: 0C36F5BD794308FD56AB66F85400E03E 13:40:02,691 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.util.CustomizedOpenSessionInViewFilter - Closing single Hibernate Session in OpenSessionInViewFilter 13:40:02,698 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/index.jsp' 13:40:02,698 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:40:02,698 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for cached principal for ff808081116f8e0901116f923228004b 13:40:02,698 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - No cached principal found, erasing SSO cookie 13:40:02,700 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.security.JspRedirectStrategy - ===>LOGIN PAGE: accessing login page before login succeed, display login page. session id: 0C36F5BD794308FD56AB66F85400E03E 13:40:02,701 [http-0.0.0.0-8080-4:] ERROR org.lamsfoundation.lams.web.session.SessionManager - Failed on finding current system session with null sessionId 13:40:02,701 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.web.filter.LocaleFilter - Locale set from server is pt,BR 13:40:02,701 [http-0.0.0.0-8080-4:] DEBUG org.lamsfoundation.lams.security.JspRedirectStrategy - Set locale information for login page:pt 13:40:02,714 [http-0.0.0.0-8080-4:] ERROR org.lamsfoundation.lams.web.session.SessionManager - Failed on finding current system session with null sessionId 13:40:02,718 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Process request for '/lams/www/news.html' 13:40:02,718 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - Checking for SSO cookie 13:40:02,718 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.integration.security.SingleSignOn - SSO cookie is not present 13:40:02,718 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - ==>Couldn't find the sso cookie 13:40:02,718 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - ==>Created one - ff808081116f8e0901116f93661e004c 13:40:02,718 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - SessionManager: cookie is null, generating a new session 13:40:02,719 [http-0.0.0.0-8080-3:] DEBUG org.lamsfoundation.lams.web.session.SessionManager - SessionManager: creating new session ff808081116f8e0901116f93661e004d