Hi,
I've been experience some esporadic, non reproducable problems with the authentication :/
Basically between two requests, on the same browser (same session), the user is authenticated in one, and on the next the session is null (in the logs "HttpSessionContextIntegrationFilter.doFilter(203) | No HttpSession currently exists") and hence the user is assumed as not being authenticated, it gets authentication as anonymous, so later the access to pages is rejected because it doesn't have the required role.
I'm posting below an excerpt of the logs with acegi security in debug.
Do you have any idea on what migh be the problem?
Could it be any configurations of the application server (weblogic9), web server (Apache), acegi security?...
Thanks in advance and best regards,
Sara
PS1: Atleap version we're using is 0.54.
/* --------- log excerpt -----------------/
2009-03-04 18:29:34,322 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] RegExpBasedFilterInvocationDefinitionMap.lookupAttributes(129) | Converted URL to lowercase, from: '/rw/resource/images/t4t/logo_sonido.jpg'; to: '/rw/resource/images/t4t/logo_sonido.jpg'
2009-03-04 18:29:34,322 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] FilterChainProxy$VirtualFilterChain.doFilter(297) | /rw/resource/images/T4T/logo_sonido.jpg at position 1 of 5 in additional filter chain; firing Filter: 'org.acegisecurity.context.HttpSessionContextIntegrationFilter@aa462'
2009-03-04 18:29:34,322 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] HttpSessionContextIntegrationFilter.doFilter(177) | Obtained from ACEGI_SECURITY_CONTEXT a valid SecurityContext and set to SecurityContextHolder: 'org.acegisecurity.context.SecurityContextImpl@0: Authentication: org.acegisecurity.providers.UsernamePasswordAuthenticationToken@0: Username: internal; Password: [PROTECTED]; Authenticated: true; Details: org.acegisecurity.ui.WebAuthenticationDetails@fffdaa08: RemoteIpAddress: 10.16.111.146; SessionId: TLJ0Jn6cJNWtcRGkC1LJ7prkwyYP9X2vV1cTLLv3X3sQW7QWckd1!459508360!NONE!1236187740399; Granted Authorities: core-commons-enterAdminConsole, core-user-updateOneself, core-user-viewOneself, core-contentResource-load, core-commons-loadScripts, core-commons-login, core-search-search, core-grid-useFilter, core-commons-viewErrorPages, core-commons-viewLoginErrorPage, core-commons-viewPages, core-commons-enterFrontend, contact-perform, news-item-read, testimonials-item-read, forum-forum-read, questionnaire-item-fill, core-siteMap-view, core-search-advanced, core-search-preferences, t4t-students-role'
2009-03-04 18:29:34,322 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] FilterChainProxy$VirtualFilterChain.doFilter(297) | /rw/resource/images/T4T/logo_sonido.jpg at position 2 of 5 in additional filter chain; firing Filter: 'com.blandware.atleap.webapp.acegi.CustomContextHolderAwareRequestFilter@19b7816'
2009-03-04 18:29:34,322 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] FilterChainProxy$VirtualFilterChain.doFilter(297) | /rw/resource/images/T4T/logo_sonido.jpg at position 3 of 5 in additional filter chain; firing Filter: 'org.acegisecurity.providers.anonymous.AnonymousProcessingFilter@1165646'
2009-03-04 18:29:34,322 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] AnonymousProcessingFilter.doFilter(129) | SecurityContextHolder not populated with anonymous token, as it already contained: 'org.acegisecurity.providers.UsernamePasswordAuthenticationToken@0: Username: internal; Password: [PROTECTED]; Authenticated: true; Details: org.acegisecurity.ui.WebAuthenticationDetails@fffdaa08: RemoteIpAddress: 10.16.111.146; SessionId: TLJ0Jn6cJNWtcRGkC1LJ7prkwyYP9X2vV1cTLLv3X3sQW7QWckd1!459508360!NONE!1236187740399; Granted Authorities: core-commons-enterAdminConsole, core-user-updateOneself, core-user-viewOneself, core-contentResource-load, core-commons-loadScripts, core-commons-login, core-search-search, core-grid-useFilter, core-commons-viewErrorPages, core-commons-viewLoginErrorPage, core-commons-viewPages, core-commons-enterFrontend, contact-perform, news-item-read, testimonials-item-read, forum-forum-read, questionnaire-item-fill, core-siteMap-view, core-search-advanced, core-search-preferences, t4t-students-role'
2009-03-04 18:29:34,322 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] FilterChainProxy$VirtualFilterChain.doFilter(297) | /rw/resource/images/T4T/logo_sonido.jpg at position 4 of 5 in additional filter chain; firing Filter: 'com.blandware.atleap.webapp.acegi.CustomExceptionTranslationFilter@11cc512'
2009-03-04 18:29:34,322 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] FilterChainProxy$VirtualFilterChain.doFilter(297) | /rw/resource/images/T4T/logo_sonido.jpg at position 5 of 5 in additional filter chain; firing Filter: 'org.acegisecurity.intercept.web.FilterSecurityInterceptor@1ce60e9'
2009-03-04 18:29:34,337 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] AbstractSecurityInterceptor.beforeInvocation(301) | Secure object: FilterInvocation: URL: /rw/resource/images/T4T/logo_sonido.jpg; ConfigAttributes: [ROLE_ANONYMOUS, core-contentResource-load]
2009-03-04 18:29:34,337 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] AbstractSecurityInterceptor.beforeInvocation(340) | Previously Authenticated: org.acegisecurity.providers.UsernamePasswordAuthenticationToken@0: Username: internal; Password: [PROTECTED]; Authenticated: true; Details: org.acegisecurity.ui.WebAuthenticationDetails@fffdaa08: RemoteIpAddress: 10.16.111.146; SessionId: TLJ0Jn6cJNWtcRGkC1LJ7prkwyYP9X2vV1cTLLv3X3sQW7QWckd1!459508360!NONE!1236187740399; Granted Authorities: core-commons-enterAdminConsole, core-user-updateOneself, core-user-viewOneself, core-contentResource-load, core-commons-loadScripts, core-commons-login, core-search-search, core-grid-useFilter, core-commons-viewErrorPages, core-commons-viewLoginErrorPage, core-commons-viewPages, core-commons-enterFrontend, contact-perform, news-item-read, testimonials-item-read, forum-forum-read, questionnaire-item-fill, core-siteMap-view, core-search-advanced, core-search-preferences, t4t-students-role
2009-03-04 18:29:34,337 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] AbstractSecurityInterceptor.beforeInvocation(358) | Authorization successful
2009-03-04 18:29:34,337 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] AbstractSecurityInterceptor.beforeInvocation(371) | RunAsManager did not change Authentication object
2009-03-04 18:29:34,337 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] FilterChainProxy$VirtualFilterChain.doFilter(288) | /rw/resource/images/T4T/logo_sonido.jpg reached end of additional filter chain; proceeding with original chain
2009-03-04 18:29:34,337 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] RequestUtil.setCookie(343) | Setting cookie 'statisticsCookie' on path '/t4t'
2009-03-04 18:29:34,337 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] ResourceServlet.processRequest(117) | URI: /rw/resource/images/T4T/logo_sonido.jpg
2009-03-04 18:29:34,337 INFO [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] CacheUtil.isGlobalPropertiesLoaded(635) | is global properties loaded
2009-03-04 18:29:34,337 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] CacheUtil.getFromCache(717) | Get from cache compositeKey: global_properties, locale: null, suffix: _globalPropertiesItem
2009-03-04 18:29:34,337 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] CacheUtil.getFromCache(723) | Get from cache, full cache key: /oami.europa.eu/global_properties_globalPropertiesItem
2009-03-04 18:29:34,337 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] CacheUtil.getFromCache(731) | Using cached entry for key :/oami.europa.eu/global_properties_globalPropertiesItem
2009-03-04 18:29:34,353 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] CacheUtil.getFromCache(717) | Get from cache compositeKey: /rw/resource/images/T4T/logo_sonido.jpg, locale: null, suffix: _resource
2009-03-04 18:29:34,353 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] CacheUtil.getFromCache(723) | Get from cache, full cache key: /oami.europa.eu//rw/resource/images/T4T/logo_sonido.jpg_resource
2009-03-04 18:29:34,353 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] CacheUtil.getFromCache(731) | Using cached entry for key :/oami.europa.eu//rw/resource/images/T4T/logo_sonido.jpg_resource
2009-03-04 18:29:34,353 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] ResourceServlet.processRequest(152) | Retrieving resource from Cache with mimeType=image/jpeg and uri=/rw/resource/images/T4T/logo_sonido.jpg and roles=[]
2009-03-04 18:29:34,353 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] ResourceServlet.processRequest(221) | Anonymous user granting access
2009-03-04 18:29:34,353 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] ExceptionTranslationFilter.doFilter(146) | Chain processed normally
2009-03-04 18:29:34,353 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] HttpSessionContextIntegrationFilter.doFilter(285) | SecurityContextHolder set to new context, as request processing completed
(...)
"pings" to the machine /t4t/rw/pages/index.en.do, made from other machine, which should not affect the requests made from another client
(...)
2009-03-04 18:33:49,849 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] RegExpBasedFilterInvocationDefinitionMap.lookupAttributes(129) | Converted URL to lowercase, from: '/actions/t4t/search/t4tsearch.do?query=legislation&timeperiod=0&enteredquery=&pagenumber=&'; to: '/actions/t4t/search/t4tsearch.do?query=legislation&timeperiod=0&enteredquery=&pagenumber=&'
2009-03-04 18:33:49,849 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] RegExpBasedFilterInvocationDefinitionMap.lookupAttributes(141) | Candidate is: '/actions/t4t/search/t4tsearch.do?query=legislation&timeperiod=0&enteredquery=&pagenumber=&'; pattern is \A/j_security_check\.login.*\Z; matched=false
2009-03-04 18:33:49,849 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] RegExpBasedFilterInvocationDefinitionMap.lookupAttributes(141) | Candidate is: '/actions/t4t/search/t4tsearch.do?query=legislation&timeperiod=0&enteredquery=&pagenumber=&'; pattern is \A.*\.do.*\Z; matched=true
2009-03-04 18:33:49,849 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] FilterChainProxy$VirtualFilterChain.doFilter(297) | /actions/T4T/search/t4tSearch.do?query=legislation&timePeriod=0&enteredQuery=&pageNumber=& at position 1 of 5 in additional filter chain; firing Filter: 'org.acegisecurity.context.HttpSessionContextIntegrationFilter@aa462'
2009-03-04 18:33:49,849 DEBUG [[ACTIVE] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)'] HttpSessionContextIntegrationFilter.doFilter(203) | No HttpSession currently exists - new SecurityContext instance associated with SecurityContextHolder
