administrative pooled sessions appear to autologout under load.

classic Classic list List threaded Threaded
4 messages Options
Reply | Threaded
Open this post in threaded view
|

administrative pooled sessions appear to autologout under load.

Ian Boston
Hi,

I am seeing some (almost all) of our scripted (Perl over http) integration tests failing under load.

The exception that happens totally randomly is

08.01.2010 19:03:23.145 *WARN* [0:0:0:0:0:0:0:1%0 [1262977403031] POST /system/userManager/user.create.html HTTP/1.1] org.sakaiproject.kernel.user.servlet.CreateSakaiUserServlet this session has been closed javax.jcr.RepositoryException: this session has been closed
        at org.apache.jackrabbit.core.SessionImpl.sanityCheck(SessionImpl.java:397)
        at org.apache.jackrabbit.core.SessionImpl.itemExists(SessionImpl.java:889)
        at org.apache.sling.jcr.base.internal.PooledSession.itemExists(PooledSession.java:236)
        at org.sakaiproject.kernel.util.JcrUtils.deepGetOrCreateNode(JcrUtils.java:69)
        at org.sakaiproject.kernel.util.JcrUtils.deepGetOrCreateNode(JcrUtils.java:118)
        at org.sakaiproject.kernel.message.MessageUserPostProcessor.process(MessageUserPostProcessor.java:95)
        at org.sakaiproject.kernel.user.servlet.CreateSakaiUserServlet.handleOperation(CreateSakaiUserServlet.java:315)
        at org.apache.sling.jackrabbit.usermanager.impl.post.AbstractAuthorizablePostServlet.doPost(AbstractAuthorizablePostServlet.java:127)
        at org.apache.sling.api.servlets.SlingAllMethodsServlet.mayService(SlingAllMethodsServlet.java:143)


The session in this example is a session that was acquired using repository.loginAdministrative(null) and has not been logged out.
This is separate from the request session.

I think this is due to a recent change since about 80% of the tests are now failing, last week we only had about 1% failure. (1 test actually).

Is this related to changes to the Pooled Sessions ?
Has the timeout changed causing the admin session to logout ?

I will do some debugging but if anything springs to mind please shout (at me :))

Ian
Reply | Threaded
Open this post in threaded view
|

Re: administrative pooled sessions appear to autologout under load.

Felix Meschberger-2
Hi,

If your are using Commons Auth and Engine trunk, this is potentially
related to a duplicate call to Session.logout() which may cause the
session to really logout.

This may be a bug in the pooling implementation, which should not allow
for duplicate logout.

Anyway, I had these spurious errors, too (SLING-1272). I "fixed" the
issues by disabling session pooling alltogether. And actually, this also
brought me to propose the removal of Session pooling support.

Regards
Felix

[1] https://issues.apache.org/jira/browse/SLING-1272

On 08.01.2010 20:19, Ian Boston wrote:

> Hi,
>
> I am seeing some (almost all) of our scripted (Perl over http) integration tests failing under load.
>
> The exception that happens totally randomly is
>
> 08.01.2010 19:03:23.145 *WARN* [0:0:0:0:0:0:0:1%0 [1262977403031] POST /system/userManager/user.create.html HTTP/1.1] org.sakaiproject.kernel.user.servlet.CreateSakaiUserServlet this session has been closed javax.jcr.RepositoryException: this session has been closed
> at org.apache.jackrabbit.core.SessionImpl.sanityCheck(SessionImpl.java:397)
> at org.apache.jackrabbit.core.SessionImpl.itemExists(SessionImpl.java:889)
> at org.apache.sling.jcr.base.internal.PooledSession.itemExists(PooledSession.java:236)
> at org.sakaiproject.kernel.util.JcrUtils.deepGetOrCreateNode(JcrUtils.java:69)
> at org.sakaiproject.kernel.util.JcrUtils.deepGetOrCreateNode(JcrUtils.java:118)
> at org.sakaiproject.kernel.message.MessageUserPostProcessor.process(MessageUserPostProcessor.java:95)
> at org.sakaiproject.kernel.user.servlet.CreateSakaiUserServlet.handleOperation(CreateSakaiUserServlet.java:315)
> at org.apache.sling.jackrabbit.usermanager.impl.post.AbstractAuthorizablePostServlet.doPost(AbstractAuthorizablePostServlet.java:127)
> at org.apache.sling.api.servlets.SlingAllMethodsServlet.mayService(SlingAllMethodsServlet.java:143)
>
>
> The session in this example is a session that was acquired using repository.loginAdministrative(null) and has not been logged out.
> This is separate from the request session.
>
> I think this is due to a recent change since about 80% of the tests are now failing, last week we only had about 1% failure. (1 test actually).
>
> Is this related to changes to the Pooled Sessions ?
> Has the timeout changed causing the admin session to logout ?
>
> I will do some debugging but if anything springs to mind please shout (at me :))
>
> Ian
Reply | Threaded
Open this post in threaded view
|

Re: administrative pooled sessions appear to autologout under load.

Ian Boston


Sent from my iPhone

On 8 Jan 2010, at 19:46, Felix Meschberger <[hidden email]> wrote:

> Hi,
>
> If your are using Commons Auth and Engine trunk, this is potentially
> related to a duplicate call to Session.logout() which may cause the
> session to really logout.


I guess this might be because the request was made by admin, and so  
the administrative session and the request session were the same  
session. Although that doesn't quite explain the behaviour. Is it  
possible for a pooled session to be shared between concurrent threads  
for the same user ? This would explain the semi random behaviour and  
the administrative session suddently being logged out mid request cycle?


>
> This may be a bug in the pooling implementation, which should not  
> allow
> for duplicate logout.
>
> Anyway, I had these spurious errors, too (SLING-1272). I "fixed" the
> issues by disabling session pooling alltogether. And actually, this  
> also
> brought me to propose the removal of Session pooling support
>


In haven't looked at the pooling code, yet, but would an alternative  
fix be to ensure that administrative sessions are not pooled?


I will try disabling pooling, but I would like to see if I can fix the  
problem, as I can reproduce it quite easilly.

Ian



> Regards
> Felix
>
> [1] https://issues.apache.org/jira/browse/SLING-1272
>
> On 08.01.2010 20:19, Ian Boston wrote:
>> Hi,
>>
>> I am seeing some (almost all) of our scripted (Perl over http)  
>> integration tests failing under load.
>>
>> The exception that happens totally randomly is
>>
>> 08.01.2010 19:03:23.145 *WARN* [0:0:0:0:0:0:0:1%0 [1262977403031]  
>> POST /system/userManager/user.create.html HTTP/1.1]  
>> org.sakaiproject.kernel.user.servlet.CreateSakaiUserServlet this  
>> session has been closed javax.jcr.RepositoryException: this session  
>> has been closed
>>    at org.apache.jackrabbit.core.SessionImpl.sanityCheck
>> (SessionImpl.java:397)
>>    at org.apache.jackrabbit.core.SessionImpl.itemExists
>> (SessionImpl.java:889)
>>    at org.apache.sling.jcr.base.internal.PooledSession.itemExists
>> (PooledSession.java:236)
>>    at org.sakaiproject.kernel.util.JcrUtils.deepGetOrCreateNode
>> (JcrUtils.java:69)
>>    at org.sakaiproject.kernel.util.JcrUtils.deepGetOrCreateNode
>> (JcrUtils.java:118)
>>    at  
>> org.sakaiproject.kernel.message.MessageUserPostProcessor.process
>> (MessageUserPostProcessor.java:95)
>>    at  
>> org.sakaiproject.kernel.user.servlet.CreateSakaiUserServlet.handleOperation(
>> CreateSakaiUserServlet.java:315)
>>    at  
>> org.apache.sling.jackrabbit.usermanager.impl.post.AbstractAuthorizablePostServlet.doPost(
>> AbstractAuthorizablePostServlet.java:127)
>>    at  
>> org.apache.sling.api.servlets.SlingAllMethodsServlet.mayService
>> (SlingAllMethodsServlet.java:143)
>>
>>
>> The session in this example is a session that was acquired using  
>> repository.loginAdministrative(null) and has not been logged out.
>> This is separate from the request session.
>>
>> I think this is due to a recent change since about 80% of the tests  
>> are now failing, last week we only had about 1% failure. (1 test  
>> actually).
>>
>> Is this related to changes to the Pooled Sessions ?
>> Has the timeout changed causing the admin session to logout ?
>>
>> I will do some debugging but if anything springs to mind please  
>> shout (at me :))
>>
>> Ian
Reply | Threaded
Open this post in threaded view
|

Re: administrative pooled sessions appear to autologout under load.

Ian Boston
In reply to this post by Felix Meschberger-2

On 8 Jan 2010, at 19:46, Felix Meschberger wrote:

> Anyway, I had these spurious errors, too (SLING-1272). I "fixed" the
> issues by disabling session pooling alltogether. And actually, this also
> brought me to propose the removal of Session pooling support.


Felix,
Thanks for the pointer.
Disabling pooling reduced the number of integration test failures from 39/45 to 11/45, recent changes to Sling appear to still be breaking some of the regression tests we have. I will continue looking.
Ian