Session unexpectedly destroyed in Alfresco 4.2.c

[joko71]

Hi all!

We're now in process of migration from 3.2 to 4.2.c Alfresco Community version. So far we've done it in a copy of production environment to weed out possible bugs.

The most unpleasant bug is when session is unexpectedly destroyed. We've been so far unable to find out the cause, but it seems that session gets destroyed after certain Lucene queries are executed.

Session timeout in web.xml is set to 480. Ticket properties in repository.properties are unchanged.

Some other parameters we changed and might be of importance are:

lucene.query.maxClauses=20000
system.acl.maxPermissionCheckTimeMillis=50000

Has anyone else had experience with this?

[joko71]

In the meantime we've migrated to the new 4.2.c Alfresco Community version. Beforementioned behavior is still present, our users have difficulty because their (Alfresco) session terminates unexpectedly and abruptly.

After long investigation, we think we've found finally the cause of this strange behaviour. The problem is in this method in authentication service:

AlfrescoServices.getAuthenticationService().getCurrentTicket();‍

Ticket is created with getNewTicket() method, and retrieved by getCurrentTicket() if needed later. The problem is that getCurrentTicket() ticket method very often "steals" ticket from some other user and gives it to current user. That's why the other user sees his ticket invalidated and session is terminated.

Our solution to the problem is to create ticket with getNewTicket() method, and store it and retrieve it by our code, bypassing erroneous getCurrentTicket() method.

[joko71]

Before said assumption that session or ticket gets stolen by other users is incorrect, due to errors in our log, which led to confusion.

We've discovered that session invalidation problem is under control if we restart production every night. This solution helps, but it's not the final solution. It seems that somehow Alfresco after some time is left without resources needed for new sessions, then this problem arises, sessions for users get terminated.

Any suggestion, similar experiences?

[heiko_robert]

we just encountered a similar issue here. We also set "authentication.ticket.useSingleTicketPerUser=false" to avoid side effects from ticket creations - without success. Did someone already find the needle killing the session after some time?

[joko71]

I've returned after a long time to this (still) unresolved issue. The only thing I know is that somehow unexpectedly new HTTP session is created, losing old one and ticket, which "kicks out" user from the application.

One log line:

10:49:49,524 DEBUG [web.app.ContextListener] HTTP session created: 4B74AC672E5809472A5D6E91BA2D8B2A

For no known reason, new session is created.

[joko71]

I've overrided the original ContextListener class to get calls stack trace, to catch what calls and initiates the session destruction, and here it is:

09:49:02,780 INFO [STDOUT] 09:49:02,779 INFO [test.session.MyWebAppContextListener] *******************sessionDestroyed - STACK TRACE BEGIN *******************
09:49:02,782 INFO [STDOUT] 09:49:02,782 INFO [test.session.MyWebAppContextListener] [java.lang.Thread.getStackTrace(Thread.java:1567),
com.inkubator.common.server.test.session.MyWebAppContextListener.logIt(MyWebAppContextListener.java:41),
com.inkubator.common.server.test.session.MyWebAppContextListener.sessionDestroyed(MyWebAppContextListener.java:35),
org.apache.catalina.session.StandardSession.expire(StandardSession.java:702),
org.apache.catalina.session.StandardSession.expire(StandardSession.java:660),
org.apache.catalina.session.StandardSession.invalidate(StandardSession.java:1115),
org.apache.catalina.session.StandardSessionFacade.invalidate(StandardSessionFacade.java:150),
org.alfresco.web.app.servlet.AuthenticationHelper.authenticate(AuthenticationHelper.java:305),
org.alfresco.web.app.servlet.BaseServlet.servletAuthenticate(BaseServlet.java:149),
org.alfresco.web.app.servlet.BaseServlet.servletAuthenticate(BaseServlet.java:129),
org.alfresco.web.app.servlet.DownloadContentServlet.doGet(DownloadContentServlet.java:129),
javax.servlet.http.HttpServlet.service(HttpServlet.java:617),
javax.servlet.http.HttpServlet.service(HttpServlet.java:717),
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290),
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206),
org.togglz.servlet.TogglzFilter.doFilter(TogglzFilter.java:100),
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235),
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206),
com.inkubator.common.server.filters.GWTCacheControlFilter.doFilter(GWTCacheControlFilter.java:57),
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235),
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206),
org.alfresco.repo.web.filter.beans.NullFilter.doFilter(NullFilter.java:68),
sun.reflect.GeneratedMethodAccessor762.invoke(Unknown Source),
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43),
java.lang.reflect.Method.invoke(Method.java:601),
org.alfresco.repo.management.subsystems.ChainingSubsystemProxyFactory$1.invoke(ChainingSubsystemProxyFactory.java:116),
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172),
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202),
$Proxy649.doFilter(Unknown Source),
org.alfresco.repo.web.filter.beans.BeanProxyFilter.doFilter(BeanProxyFilter.java:82),
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235),
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206),
org.alfresco.web.app.servlet.GlobalLocalizationFilter.doFilter(GlobalLocalizationFilter.java:61),
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235),
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206),
org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96),
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235),
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206),
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:235),
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191),
org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:190),
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:433),
org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:92),
org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.process(SecurityContextEstablishmentValve.java:126),
org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:70),
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127),
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102),
org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:158),
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109),
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:330),
org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:829),
org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:598),
org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447),
java.lang.Thread.run(Thread.java:722)]
09:49:02,797 INFO [STDOUT] 09:49:02,797 INFO [test.session.MyWebAppContextListener] *******************sessionDestroyed - STACK TRACE END *******************

[joko71]

Does this have any connection with this bug?

[ALF-13194] Can't log in to Share 4.0 with only external authentication in the chain because of call... 

[joko71]

It seems this issue is connected to content downloading. I suspect that sometimes &somehow content downloading invalidates the ticket and session gets destroyed.

From the log:

2017-01-25 09:03:39,137 INFO  [STDOUT] (xxxxxxxx:http-0.0.0.0-8080-12) 09:03:39,137 DEBUG [server.utils.XMLUtils] URL for ustrojstvo is /alfresco/download/direct/workspace/SpacesStore/b40abc1d-b056-42bf-be2a-dbe3e693bb32/b40abc1d-b056-42bf-be2a-dbe3e693bb32.xml?property={http://www.alfresco.org/model/content/1.0}content&ticket=TICKET_bdcee9bf5948597f4beb3ebbd2f6f8f8499dd2de

[joko71]

It's me, again, with no progress.

We're still having problems with unexpected ending sessions.

We've found some situations when session ending can be observed more often:

1) Servlet or webscript call. Often happens that logged in user loses the session

2) Recently we added a module that imports documents from external systems. This module was working 24/7, and we've noticed that session losing increased considerably. We then modified the import module to work only outside working hours.

Is it possible that Alfresco get confused if number of threads increases, and sessions and ticket get lost?

[joko71]

We've finally solved this one. The problem was server side object instancing which was improper in web environment, so it happened that different users used same objects and were kicking each other out of the sessions. After a bit of code change, the problem was gone.

This thread can be closed.