You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tapestry.apache.org by Moritz Gmelin <mo...@gmx.de> on 2010/10/14 12:01:38 UTC

SessionStateObject lost with 5.2

Hi,

since upgradeing to Tapestry 5.2 (5.2.0 and 5.2.1) we sometimes obseve that the contents of our SessionStateObject gets lost. 
The Session-ID between 2 requests is identical, but the Hashcode of the @SessionState object changes and thus the contents are lost.
If everything works correctly, the getHashCode() of the SessionState object does not change between requests. But in the case where our SessionState objects get lost beweeen requests, obviousely a new SessionState object gets created.
This happens only in very rare cases but if it does, our users get chucked out of their pages.
This has not happened with t5.1.0.5 as far as we can see.

Has anyone else seen this problem yet? Any hints about a possible solution? 

Thanks

Moritz
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
For additional commands, e-mail: users-help@tapestry.apache.org


Re: SessionStateObject lost with 5.2 [fixed]

Posted by Howard Lewis Ship <hl...@gmail.com>.
On Fri, Oct 15, 2010 at 5:52 AM, Moritz Gmelin <mo...@gmx.de> wrote:
> Hi,
>
> Howard was right. It was a race condition.
> Maybe for other to prevent similar problems:
>
> We have an AccessControlDispatcher in our application that was inserted before:ComponentEvent in our application. This AccessControlDispatcher uses the SessionStateObject to check access permissions.
>
> Now sometimes, it could happen that the AccessControlDispatcher is placed after Tapestrys AssetDispatcher, sometimes it was placed before the AssetDispatcher. In the later case, for every asset loaded in a page, the AccessControlDispatcher was questioned which invovles use of the SSO. With many assets on the page there could be problems with multiple threads accessing this SSO at the same time.  (See howards remark about all stateful applications being broken by design).
>
> This issue could be solved by explicitly placing our AccessControlDispatcher before:ComponentEvent and after:AssetDispatcher.
>
> public static void contributeMasterDispatcher(
>                                        OrderedConfiguration<Dispatcher> configuration,
>                                        @InjectService("AccessControlDispatcher") Dispatcher accessController)
>        {
>                configuration.add("AccessControlDispatcher", accessController,
>                        "after:Asset", "before:ComponentEvent");
>        }
>
> Why is it so unpredictable where the dispatcher is placed in the first time?

There's any number of factors that can contribute to different
orderings. I'm surprised these include different executions of the
same code (very surprised) but any other change, such as to the
classpath, can affect this. That's why there is explicit ordering
control.

>
> Thanks
>
> Moritz
>
> Am 14.10.2010 um 23:59 schrieb Howard Lewis Ship:
>
>> I don't ever see Jetty starting strangely ... what else is going on in
>> your application besides Tapestry.
>>
>> Also ... it's always a good idea to "audit" your runtime classpath,
>> make sure there isn't anything odd going on there.
>>
>> On Thu, Oct 14, 2010 at 2:17 PM, Moritz Gmelin <mo...@gmx.de> wrote:
>>> Getting closer.
>>>
>>> In the cases where it happens, the binding and unbinding is called after cleanup from different threads. Threads are named btpool0-1 -btpool0-7.
>>> But as I said, this happens only about every second time I start my jetty server. The other times, the binding- unbinding is called only once for each page request.
>>>
>>> M.
>>>
>>>
>>> 10-10-14 23:13:47.075 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
>>> 10-10-14 23:13:47.075 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btNextpool0-1
>>> 10-10-14 23:13:47.089 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
>>> 10-10-14 23:13:47.089 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-7
>>> 10-10-14 23:13:47.091 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
>>> 10-10-14 23:13:47.091 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-1
>>> 10-10-14 23:13:47.091 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
>>> 10-10-14 23:13:47.092 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-5
>>> 10-10-14 23:13:47.098 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
>>> 10-10-14 23:13:47.098 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-3
>>> 10-10-14 23:13:47.104 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
>>> 10-10-14 23:13:47.105 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-4
>>>
>>> Am 14.10.2010 um 22:04 schrieb Moritz Gmelin:
>>>
>>>> Hi,
>>>>
>>>> I added the logging as you suggested. This is part of the logging for a _SINGLE_ page request. CurrentSessionASO is our SSO.
>>>>
>>>> 10-10-14 21:51:12.049 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 1363402032
>>>> 10-10-14 21:51:12.066 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 1363402032
>>>> 10-10-14 21:51:12.066 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 1363402032
>>>> 10-10-14 21:51:12.069 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 1363402032
>>>> 10-10-14 21:51:12.070 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 1363402032
>>>> 10-10-14 21:51:12.073 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 1363402032
>>>> 10-10-14 21:51:12.074 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 950050904
>>>> 10-10-14 21:51:12.074 [INFO]  de.example.services.AppModule$3.create(AppModule.java:220)      New CurrentSessionASO object created CurrentSessionASO{user:0, account:0, patient:0, project:, hash:950050904} for session 1vsqjhkzdsj37
>>>> 10-10-14 21:51:12.077 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 950050904
>>>> 10-10-14 21:51:12.079 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 1363402032
>>>> 10-10-14 21:51:12.080 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 1363402032
>>>> 10-10-14 21:51:12.080 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 950050904
>>>> 10-10-14 21:51:12.084 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 950050904
>>>>
>>>> You can see that the CurrentSessionASO is bound and unbound many times for a signel page request. Sometimes (as you can see in the log here), a new CurrentSessionASO object is created for the same session. This is done in my ApplicationStateManagerContribution in AppModule. Most often times, there is no new SSO created (correct behaviour).
>>>>
>>>> I'm starting the applcation here locally in a jetty environment. One weird observation is also that about half of the startups of the application the situation is totally different. Then, our SSO is only bound and unbound once per page request, as I would expect. But the other times the situation as above happens, that for every page request binding and unbinding happens about 20 times. and sometimes a new SSO is created inbetween.
>>>>
>>>> Next thing to notice is that this all happens after the cleanup method of the page is called.
>>>>
>>>> Thanks
>>>>
>>>> Moritz
>>>>
>>>>
>>>>
>>>> Am 14.10.2010 um 19:13 schrieb Howard Lewis Ship:
>>>>
>>>>> Tapestry manages persistent state in the HttpSession.  As of 5.2, it
>>>>> doesn't do anything special to handle cases of multiple requests
>>>>> (perhaps due to Ajax) attempting to modify the same SSO in multiple
>>>>> threads.
>>>>>
>>>>> This aligns with Brian Goetz's observation that all stateful web
>>>>> applications are inherently broken:
>>>>>
>>>>> http://www.ibm.com/developerworks/library/j-jtp09238.html
>>>>>
>>>>> I'm not aware of any concerns.  You may want to have your SSO
>>>>> implement the HttpSessionBindingListener interface, and log the
>>>>> details of when it is bound (saved to the HttpSession). That might
>>>>> illuminate what's going on.
>>>>>
>>>>> It may be a bug in your servlet container, it may be a race condition
>>>>> between threads, or it may just be a coding problem in your code.  I
>>>>> hate to say it, but the last option is the most likely (given the
>>>>> total lack of information you've provided).
>>>>>
>>>>> On Thu, Oct 14, 2010 at 3:01 AM, Moritz Gmelin <mo...@gmx.de> wrote:
>>>>>> Hi,
>>>>>>
>>>>>> since upgradeing to Tapestry 5.2 (5.2.0 and 5.2.1) we sometimes obseve that the contents of our SessionStateObject gets lost.
>>>>>> The Session-ID between 2 requests is identical, but the Hashcode of the @SessionState object changes and thus the contents are lost.
>>>>>> If everything works correctly, the getHashCode() of the SessionState object does not change between requests. But in the case where our SessionState objects get lost beweeen requests, obviousely a new SessionState object gets created.
>>>>>> This happens only in very rare cases but if it does, our users get chucked out of their pages.
>>>>>> This has not happened with t5.1.0.5 as far as we can see.
>>>>>>
>>>>>> Has anyone else seen this problem yet? Any hints about a possible solution?
>>>>>>
>>>>>> Thanks
>>>>>>
>>>>>> Moritz
>>>>>> ---------------------------------------------------------------------
>>>>>> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
>>>>>> For additional commands, e-mail: users-help@tapestry.apache.org
>>>>>>
>>>>>>
>>>>>
>>>>>
>>>>>
>>>>> --
>>>>> Howard M. Lewis Ship
>>>>>
>>>>> Creator of Apache Tapestry
>>>>>
>>>>> The source for Tapestry training, mentoring and support. Contact me to
>>>>> learn how I can get you up and productive in Tapestry fast!
>>>>>
>>>>> (971) 678-5210
>>>>> http://howardlewisship.com
>>>>>
>>>>> ---------------------------------------------------------------------
>>>>> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
>>>>> For additional commands, e-mail: users-help@tapestry.apache.org
>>>>>
>>>>
>>>>
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
>>>> For additional commands, e-mail: users-help@tapestry.apache.org
>>>>
>>>
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
>>> For additional commands, e-mail: users-help@tapestry.apache.org
>>>
>>>
>>
>>
>>
>> --
>> Howard M. Lewis Ship
>>
>> Creator of Apache Tapestry
>>
>> The source for Tapestry training, mentoring and support. Contact me to
>> learn how I can get you up and productive in Tapestry fast!
>>
>> (971) 678-5210
>> http://howardlewisship.com
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
>> For additional commands, e-mail: users-help@tapestry.apache.org
>>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
> For additional commands, e-mail: users-help@tapestry.apache.org
>
>



-- 
Howard M. Lewis Ship

Creator of Apache Tapestry

The source for Tapestry training, mentoring and support. Contact me to
learn how I can get you up and productive in Tapestry fast!

(971) 678-5210
http://howardlewisship.com

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
For additional commands, e-mail: users-help@tapestry.apache.org


Re: SessionStateObject lost with 5.2 [fixed]

Posted by Moritz Gmelin <mo...@gmx.de>.
Hi,

Howard was right. It was a race condition. 
Maybe for other to prevent similar problems:

We have an AccessControlDispatcher in our application that was inserted before:ComponentEvent in our application. This AccessControlDispatcher uses the SessionStateObject to check access permissions.

Now sometimes, it could happen that the AccessControlDispatcher is placed after Tapestrys AssetDispatcher, sometimes it was placed before the AssetDispatcher. In the later case, for every asset loaded in a page, the AccessControlDispatcher was questioned which invovles use of the SSO. With many assets on the page there could be problems with multiple threads accessing this SSO at the same time.  (See howards remark about all stateful applications being broken by design).

This issue could be solved by explicitly placing our AccessControlDispatcher before:ComponentEvent and after:AssetDispatcher.

public static void contributeMasterDispatcher(
					OrderedConfiguration<Dispatcher> configuration,
					@InjectService("AccessControlDispatcher") Dispatcher accessController)
	{
		configuration.add("AccessControlDispatcher", accessController,
			"after:Asset", "before:ComponentEvent");
	}

Why is it so unpredictable where the dispatcher is placed in the first time?

Thanks

Moritz

Am 14.10.2010 um 23:59 schrieb Howard Lewis Ship:

> I don't ever see Jetty starting strangely ... what else is going on in
> your application besides Tapestry.
> 
> Also ... it's always a good idea to "audit" your runtime classpath,
> make sure there isn't anything odd going on there.
> 
> On Thu, Oct 14, 2010 at 2:17 PM, Moritz Gmelin <mo...@gmx.de> wrote:
>> Getting closer.
>> 
>> In the cases where it happens, the binding and unbinding is called after cleanup from different threads. Threads are named btpool0-1 -btpool0-7.
>> But as I said, this happens only about every second time I start my jetty server. The other times, the binding- unbinding is called only once for each page request.
>> 
>> M.
>> 
>> 
>> 10-10-14 23:13:47.075 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
>> 10-10-14 23:13:47.075 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btNextpool0-1
>> 10-10-14 23:13:47.089 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
>> 10-10-14 23:13:47.089 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-7
>> 10-10-14 23:13:47.091 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
>> 10-10-14 23:13:47.091 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-1
>> 10-10-14 23:13:47.091 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
>> 10-10-14 23:13:47.092 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-5
>> 10-10-14 23:13:47.098 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
>> 10-10-14 23:13:47.098 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-3
>> 10-10-14 23:13:47.104 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
>> 10-10-14 23:13:47.105 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-4
>> 
>> Am 14.10.2010 um 22:04 schrieb Moritz Gmelin:
>> 
>>> Hi,
>>> 
>>> I added the logging as you suggested. This is part of the logging for a _SINGLE_ page request. CurrentSessionASO is our SSO.
>>> 
>>> 10-10-14 21:51:12.049 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 1363402032
>>> 10-10-14 21:51:12.066 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 1363402032
>>> 10-10-14 21:51:12.066 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 1363402032
>>> 10-10-14 21:51:12.069 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 1363402032
>>> 10-10-14 21:51:12.070 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 1363402032
>>> 10-10-14 21:51:12.073 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 1363402032
>>> 10-10-14 21:51:12.074 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 950050904
>>> 10-10-14 21:51:12.074 [INFO]  de.example.services.AppModule$3.create(AppModule.java:220)      New CurrentSessionASO object created CurrentSessionASO{user:0, account:0, patient:0, project:, hash:950050904} for session 1vsqjhkzdsj37
>>> 10-10-14 21:51:12.077 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 950050904
>>> 10-10-14 21:51:12.079 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 1363402032
>>> 10-10-14 21:51:12.080 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 1363402032
>>> 10-10-14 21:51:12.080 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 950050904
>>> 10-10-14 21:51:12.084 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 950050904
>>> 
>>> You can see that the CurrentSessionASO is bound and unbound many times for a signel page request. Sometimes (as you can see in the log here), a new CurrentSessionASO object is created for the same session. This is done in my ApplicationStateManagerContribution in AppModule. Most often times, there is no new SSO created (correct behaviour).
>>> 
>>> I'm starting the applcation here locally in a jetty environment. One weird observation is also that about half of the startups of the application the situation is totally different. Then, our SSO is only bound and unbound once per page request, as I would expect. But the other times the situation as above happens, that for every page request binding and unbinding happens about 20 times. and sometimes a new SSO is created inbetween.
>>> 
>>> Next thing to notice is that this all happens after the cleanup method of the page is called.
>>> 
>>> Thanks
>>> 
>>> Moritz
>>> 
>>> 
>>> 
>>> Am 14.10.2010 um 19:13 schrieb Howard Lewis Ship:
>>> 
>>>> Tapestry manages persistent state in the HttpSession.  As of 5.2, it
>>>> doesn't do anything special to handle cases of multiple requests
>>>> (perhaps due to Ajax) attempting to modify the same SSO in multiple
>>>> threads.
>>>> 
>>>> This aligns with Brian Goetz's observation that all stateful web
>>>> applications are inherently broken:
>>>> 
>>>> http://www.ibm.com/developerworks/library/j-jtp09238.html
>>>> 
>>>> I'm not aware of any concerns.  You may want to have your SSO
>>>> implement the HttpSessionBindingListener interface, and log the
>>>> details of when it is bound (saved to the HttpSession). That might
>>>> illuminate what's going on.
>>>> 
>>>> It may be a bug in your servlet container, it may be a race condition
>>>> between threads, or it may just be a coding problem in your code.  I
>>>> hate to say it, but the last option is the most likely (given the
>>>> total lack of information you've provided).
>>>> 
>>>> On Thu, Oct 14, 2010 at 3:01 AM, Moritz Gmelin <mo...@gmx.de> wrote:
>>>>> Hi,
>>>>> 
>>>>> since upgradeing to Tapestry 5.2 (5.2.0 and 5.2.1) we sometimes obseve that the contents of our SessionStateObject gets lost.
>>>>> The Session-ID between 2 requests is identical, but the Hashcode of the @SessionState object changes and thus the contents are lost.
>>>>> If everything works correctly, the getHashCode() of the SessionState object does not change between requests. But in the case where our SessionState objects get lost beweeen requests, obviousely a new SessionState object gets created.
>>>>> This happens only in very rare cases but if it does, our users get chucked out of their pages.
>>>>> This has not happened with t5.1.0.5 as far as we can see.
>>>>> 
>>>>> Has anyone else seen this problem yet? Any hints about a possible solution?
>>>>> 
>>>>> Thanks
>>>>> 
>>>>> Moritz
>>>>> ---------------------------------------------------------------------
>>>>> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
>>>>> For additional commands, e-mail: users-help@tapestry.apache.org
>>>>> 
>>>>> 
>>>> 
>>>> 
>>>> 
>>>> --
>>>> Howard M. Lewis Ship
>>>> 
>>>> Creator of Apache Tapestry
>>>> 
>>>> The source for Tapestry training, mentoring and support. Contact me to
>>>> learn how I can get you up and productive in Tapestry fast!
>>>> 
>>>> (971) 678-5210
>>>> http://howardlewisship.com
>>>> 
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
>>>> For additional commands, e-mail: users-help@tapestry.apache.org
>>>> 
>>> 
>>> 
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
>>> For additional commands, e-mail: users-help@tapestry.apache.org
>>> 
>> 
>> 
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
>> For additional commands, e-mail: users-help@tapestry.apache.org
>> 
>> 
> 
> 
> 
> -- 
> Howard M. Lewis Ship
> 
> Creator of Apache Tapestry
> 
> The source for Tapestry training, mentoring and support. Contact me to
> learn how I can get you up and productive in Tapestry fast!
> 
> (971) 678-5210
> http://howardlewisship.com
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
> For additional commands, e-mail: users-help@tapestry.apache.org
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
For additional commands, e-mail: users-help@tapestry.apache.org


Re: SessionStateObject lost with 5.2

Posted by Howard Lewis Ship <hl...@gmail.com>.
I don't ever see Jetty starting strangely ... what else is going on in
your application besides Tapestry.

Also ... it's always a good idea to "audit" your runtime classpath,
make sure there isn't anything odd going on there.

On Thu, Oct 14, 2010 at 2:17 PM, Moritz Gmelin <mo...@gmx.de> wrote:
> Getting closer.
>
> In the cases where it happens, the binding and unbinding is called after cleanup from different threads. Threads are named btpool0-1 -btpool0-7.
> But as I said, this happens only about every second time I start my jetty server. The other times, the binding- unbinding is called only once for each page request.
>
> M.
>
>
> 10-10-14 23:13:47.075 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
> 10-10-14 23:13:47.075 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btNextpool0-1
> 10-10-14 23:13:47.089 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
> 10-10-14 23:13:47.089 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-7
> 10-10-14 23:13:47.091 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
> 10-10-14 23:13:47.091 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-1
> 10-10-14 23:13:47.091 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
> 10-10-14 23:13:47.092 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-5
> 10-10-14 23:13:47.098 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
> 10-10-14 23:13:47.098 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-3
> 10-10-14 23:13:47.104 [DEBUG]   de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)      session 95wqzf1oyaps asoHash 1646600475
> 10-10-14 23:13:47.105 [DEBUG]   de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-4
>
> Am 14.10.2010 um 22:04 schrieb Moritz Gmelin:
>
>> Hi,
>>
>> I added the logging as you suggested. This is part of the logging for a _SINGLE_ page request. CurrentSessionASO is our SSO.
>>
>> 10-10-14 21:51:12.049 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 1363402032
>> 10-10-14 21:51:12.066 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 1363402032
>> 10-10-14 21:51:12.066 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 1363402032
>> 10-10-14 21:51:12.069 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 1363402032
>> 10-10-14 21:51:12.070 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 1363402032
>> 10-10-14 21:51:12.073 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 1363402032
>> 10-10-14 21:51:12.074 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 950050904
>> 10-10-14 21:51:12.074 [INFO]  de.example.services.AppModule$3.create(AppModule.java:220)      New CurrentSessionASO object created CurrentSessionASO{user:0, account:0, patient:0, project:, hash:950050904} for session 1vsqjhkzdsj37
>> 10-10-14 21:51:12.077 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 950050904
>> 10-10-14 21:51:12.079 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 1363402032
>> 10-10-14 21:51:12.080 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 1363402032
>> 10-10-14 21:51:12.080 [DEBUG] de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)        session 1vsqjhkzdsj37 asoHash 950050904
>> 10-10-14 21:51:12.084 [DEBUG] de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)      session 1vsqjhkzdsj37 asoHash 950050904
>>
>> You can see that the CurrentSessionASO is bound and unbound many times for a signel page request. Sometimes (as you can see in the log here), a new CurrentSessionASO object is created for the same session. This is done in my ApplicationStateManagerContribution in AppModule. Most often times, there is no new SSO created (correct behaviour).
>>
>> I'm starting the applcation here locally in a jetty environment. One weird observation is also that about half of the startups of the application the situation is totally different. Then, our SSO is only bound and unbound once per page request, as I would expect. But the other times the situation as above happens, that for every page request binding and unbinding happens about 20 times. and sometimes a new SSO is created inbetween.
>>
>> Next thing to notice is that this all happens after the cleanup method of the page is called.
>>
>> Thanks
>>
>> Moritz
>>
>>
>>
>> Am 14.10.2010 um 19:13 schrieb Howard Lewis Ship:
>>
>>> Tapestry manages persistent state in the HttpSession.  As of 5.2, it
>>> doesn't do anything special to handle cases of multiple requests
>>> (perhaps due to Ajax) attempting to modify the same SSO in multiple
>>> threads.
>>>
>>> This aligns with Brian Goetz's observation that all stateful web
>>> applications are inherently broken:
>>>
>>> http://www.ibm.com/developerworks/library/j-jtp09238.html
>>>
>>> I'm not aware of any concerns.  You may want to have your SSO
>>> implement the HttpSessionBindingListener interface, and log the
>>> details of when it is bound (saved to the HttpSession). That might
>>> illuminate what's going on.
>>>
>>> It may be a bug in your servlet container, it may be a race condition
>>> between threads, or it may just be a coding problem in your code.  I
>>> hate to say it, but the last option is the most likely (given the
>>> total lack of information you've provided).
>>>
>>> On Thu, Oct 14, 2010 at 3:01 AM, Moritz Gmelin <mo...@gmx.de> wrote:
>>>> Hi,
>>>>
>>>> since upgradeing to Tapestry 5.2 (5.2.0 and 5.2.1) we sometimes obseve that the contents of our SessionStateObject gets lost.
>>>> The Session-ID between 2 requests is identical, but the Hashcode of the @SessionState object changes and thus the contents are lost.
>>>> If everything works correctly, the getHashCode() of the SessionState object does not change between requests. But in the case where our SessionState objects get lost beweeen requests, obviousely a new SessionState object gets created.
>>>> This happens only in very rare cases but if it does, our users get chucked out of their pages.
>>>> This has not happened with t5.1.0.5 as far as we can see.
>>>>
>>>> Has anyone else seen this problem yet? Any hints about a possible solution?
>>>>
>>>> Thanks
>>>>
>>>> Moritz
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
>>>> For additional commands, e-mail: users-help@tapestry.apache.org
>>>>
>>>>
>>>
>>>
>>>
>>> --
>>> Howard M. Lewis Ship
>>>
>>> Creator of Apache Tapestry
>>>
>>> The source for Tapestry training, mentoring and support. Contact me to
>>> learn how I can get you up and productive in Tapestry fast!
>>>
>>> (971) 678-5210
>>> http://howardlewisship.com
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
>>> For additional commands, e-mail: users-help@tapestry.apache.org
>>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
>> For additional commands, e-mail: users-help@tapestry.apache.org
>>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
> For additional commands, e-mail: users-help@tapestry.apache.org
>
>



-- 
Howard M. Lewis Ship

Creator of Apache Tapestry

The source for Tapestry training, mentoring and support. Contact me to
learn how I can get you up and productive in Tapestry fast!

(971) 678-5210
http://howardlewisship.com

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
For additional commands, e-mail: users-help@tapestry.apache.org


Re: SessionStateObject lost with 5.2

Posted by Moritz Gmelin <mo...@gmx.de>.
Getting closer.

In the cases where it happens, the binding and unbinding is called after cleanup from different threads. Threads are named btpool0-1 -btpool0-7. 
But as I said, this happens only about every second time I start my jetty server. The other times, the binding- unbinding is called only once for each page request.

M.


10-10-14 23:13:47.075 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)	session 95wqzf1oyaps asoHash 1646600475
10-10-14 23:13:47.075 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-1
10-10-14 23:13:47.089 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)	session 95wqzf1oyaps asoHash 1646600475
10-10-14 23:13:47.089 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-7
10-10-14 23:13:47.091 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)	session 95wqzf1oyaps asoHash 1646600475
10-10-14 23:13:47.091 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-1
10-10-14 23:13:47.091 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)	session 95wqzf1oyaps asoHash 1646600475
10-10-14 23:13:47.092 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-5
10-10-14 23:13:47.098 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)	session 95wqzf1oyaps asoHash 1646600475
10-10-14 23:13:47.098 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-3
10-10-14 23:13:47.104 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1596)	session 95wqzf1oyaps asoHash 1646600475
10-10-14 23:13:47.105 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 95wqzf1oyaps asoHash 1646600475 name sso:de.example.aso.CurrentSessionASO thread btpool0-4

Am 14.10.2010 um 22:04 schrieb Moritz Gmelin:

> Hi,
> 
> I added the logging as you suggested. This is part of the logging for a _SINGLE_ page request. CurrentSessionASO is our SSO.
> 
> 10-10-14 21:51:12.049 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 1vsqjhkzdsj37 asoHash 1363402032
> 10-10-14 21:51:12.066 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)	session 1vsqjhkzdsj37 asoHash 1363402032
> 10-10-14 21:51:12.066 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 1vsqjhkzdsj37 asoHash 1363402032
> 10-10-14 21:51:12.069 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)	session 1vsqjhkzdsj37 asoHash 1363402032
> 10-10-14 21:51:12.070 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 1vsqjhkzdsj37 asoHash 1363402032
> 10-10-14 21:51:12.073 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)	session 1vsqjhkzdsj37 asoHash 1363402032
> 10-10-14 21:51:12.074 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 1vsqjhkzdsj37 asoHash 950050904
> 10-10-14 21:51:12.074 [INFO]	de.example.services.AppModule$3.create(AppModule.java:220)	New CurrentSessionASO object created CurrentSessionASO{user:0, account:0, patient:0, project:, hash:950050904} for session 1vsqjhkzdsj37
> 10-10-14 21:51:12.077 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)	session 1vsqjhkzdsj37 asoHash 950050904
> 10-10-14 21:51:12.079 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 1vsqjhkzdsj37 asoHash 1363402032
> 10-10-14 21:51:12.080 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)	session 1vsqjhkzdsj37 asoHash 1363402032
> 10-10-14 21:51:12.080 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 1vsqjhkzdsj37 asoHash 950050904
> 10-10-14 21:51:12.084 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)	session 1vsqjhkzdsj37 asoHash 950050904
> 
> You can see that the CurrentSessionASO is bound and unbound many times for a signel page request. Sometimes (as you can see in the log here), a new CurrentSessionASO object is created for the same session. This is done in my ApplicationStateManagerContribution in AppModule. Most often times, there is no new SSO created (correct behaviour).
> 
> I'm starting the applcation here locally in a jetty environment. One weird observation is also that about half of the startups of the application the situation is totally different. Then, our SSO is only bound and unbound once per page request, as I would expect. But the other times the situation as above happens, that for every page request binding and unbinding happens about 20 times. and sometimes a new SSO is created inbetween.
> 
> Next thing to notice is that this all happens after the cleanup method of the page is called. 
> 
> Thanks
> 
> Moritz
> 
> 
> 
> Am 14.10.2010 um 19:13 schrieb Howard Lewis Ship:
> 
>> Tapestry manages persistent state in the HttpSession.  As of 5.2, it
>> doesn't do anything special to handle cases of multiple requests
>> (perhaps due to Ajax) attempting to modify the same SSO in multiple
>> threads.
>> 
>> This aligns with Brian Goetz's observation that all stateful web
>> applications are inherently broken:
>> 
>> http://www.ibm.com/developerworks/library/j-jtp09238.html
>> 
>> I'm not aware of any concerns.  You may want to have your SSO
>> implement the HttpSessionBindingListener interface, and log the
>> details of when it is bound (saved to the HttpSession). That might
>> illuminate what's going on.
>> 
>> It may be a bug in your servlet container, it may be a race condition
>> between threads, or it may just be a coding problem in your code.  I
>> hate to say it, but the last option is the most likely (given the
>> total lack of information you've provided).
>> 
>> On Thu, Oct 14, 2010 at 3:01 AM, Moritz Gmelin <mo...@gmx.de> wrote:
>>> Hi,
>>> 
>>> since upgradeing to Tapestry 5.2 (5.2.0 and 5.2.1) we sometimes obseve that the contents of our SessionStateObject gets lost.
>>> The Session-ID between 2 requests is identical, but the Hashcode of the @SessionState object changes and thus the contents are lost.
>>> If everything works correctly, the getHashCode() of the SessionState object does not change between requests. But in the case where our SessionState objects get lost beweeen requests, obviousely a new SessionState object gets created.
>>> This happens only in very rare cases but if it does, our users get chucked out of their pages.
>>> This has not happened with t5.1.0.5 as far as we can see.
>>> 
>>> Has anyone else seen this problem yet? Any hints about a possible solution?
>>> 
>>> Thanks
>>> 
>>> Moritz
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
>>> For additional commands, e-mail: users-help@tapestry.apache.org
>>> 
>>> 
>> 
>> 
>> 
>> -- 
>> Howard M. Lewis Ship
>> 
>> Creator of Apache Tapestry
>> 
>> The source for Tapestry training, mentoring and support. Contact me to
>> learn how I can get you up and productive in Tapestry fast!
>> 
>> (971) 678-5210
>> http://howardlewisship.com
>> 
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
>> For additional commands, e-mail: users-help@tapestry.apache.org
>> 
> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
> For additional commands, e-mail: users-help@tapestry.apache.org
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
For additional commands, e-mail: users-help@tapestry.apache.org


Re: SessionStateObject lost with 5.2

Posted by Moritz Gmelin <mo...@gmx.de>.
Hi,

I added the logging as you suggested. This is part of the logging for a _SINGLE_ page request. CurrentSessionASO is our SSO.

10-10-14 21:51:12.049 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 1vsqjhkzdsj37 asoHash 1363402032
10-10-14 21:51:12.066 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)	session 1vsqjhkzdsj37 asoHash 1363402032
10-10-14 21:51:12.066 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 1vsqjhkzdsj37 asoHash 1363402032
10-10-14 21:51:12.069 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)	session 1vsqjhkzdsj37 asoHash 1363402032
10-10-14 21:51:12.070 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 1vsqjhkzdsj37 asoHash 1363402032
10-10-14 21:51:12.073 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)	session 1vsqjhkzdsj37 asoHash 1363402032
10-10-14 21:51:12.074 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 1vsqjhkzdsj37 asoHash 950050904
10-10-14 21:51:12.074 [INFO]	de.example.services.AppModule$3.create(AppModule.java:220)	New CurrentSessionASO object created CurrentSessionASO{user:0, account:0, patient:0, project:, hash:950050904} for session 1vsqjhkzdsj37
10-10-14 21:51:12.077 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)	session 1vsqjhkzdsj37 asoHash 950050904
10-10-14 21:51:12.079 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 1vsqjhkzdsj37 asoHash 1363402032
10-10-14 21:51:12.080 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)	session 1vsqjhkzdsj37 asoHash 1363402032
10-10-14 21:51:12.080 [DEBUG]	de.example.aso.CurrentSessionASO.valueBound(CurrentSessionASO.java:1587)	session 1vsqjhkzdsj37 asoHash 950050904
10-10-14 21:51:12.084 [DEBUG]	de.example.aso.CurrentSessionASO.valueUnbound(CurrentSessionASO.java:1595)	session 1vsqjhkzdsj37 asoHash 950050904

You can see that the CurrentSessionASO is bound and unbound many times for a signel page request. Sometimes (as you can see in the log here), a new CurrentSessionASO object is created for the same session. This is done in my ApplicationStateManagerContribution in AppModule. Most often times, there is no new SSO created (correct behaviour).

I'm starting the applcation here locally in a jetty environment. One weird observation is also that about half of the startups of the application the situation is totally different. Then, our SSO is only bound and unbound once per page request, as I would expect. But the other times the situation as above happens, that for every page request binding and unbinding happens about 20 times. and sometimes a new SSO is created inbetween.

Next thing to notice is that this all happens after the cleanup method of the page is called. 

Thanks

Moritz



Am 14.10.2010 um 19:13 schrieb Howard Lewis Ship:

> Tapestry manages persistent state in the HttpSession.  As of 5.2, it
> doesn't do anything special to handle cases of multiple requests
> (perhaps due to Ajax) attempting to modify the same SSO in multiple
> threads.
> 
> This aligns with Brian Goetz's observation that all stateful web
> applications are inherently broken:
> 
> http://www.ibm.com/developerworks/library/j-jtp09238.html
> 
> I'm not aware of any concerns.  You may want to have your SSO
> implement the HttpSessionBindingListener interface, and log the
> details of when it is bound (saved to the HttpSession). That might
> illuminate what's going on.
> 
> It may be a bug in your servlet container, it may be a race condition
> between threads, or it may just be a coding problem in your code.  I
> hate to say it, but the last option is the most likely (given the
> total lack of information you've provided).
> 
> On Thu, Oct 14, 2010 at 3:01 AM, Moritz Gmelin <mo...@gmx.de> wrote:
>> Hi,
>> 
>> since upgradeing to Tapestry 5.2 (5.2.0 and 5.2.1) we sometimes obseve that the contents of our SessionStateObject gets lost.
>> The Session-ID between 2 requests is identical, but the Hashcode of the @SessionState object changes and thus the contents are lost.
>> If everything works correctly, the getHashCode() of the SessionState object does not change between requests. But in the case where our SessionState objects get lost beweeen requests, obviousely a new SessionState object gets created.
>> This happens only in very rare cases but if it does, our users get chucked out of their pages.
>> This has not happened with t5.1.0.5 as far as we can see.
>> 
>> Has anyone else seen this problem yet? Any hints about a possible solution?
>> 
>> Thanks
>> 
>> Moritz
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
>> For additional commands, e-mail: users-help@tapestry.apache.org
>> 
>> 
> 
> 
> 
> -- 
> Howard M. Lewis Ship
> 
> Creator of Apache Tapestry
> 
> The source for Tapestry training, mentoring and support. Contact me to
> learn how I can get you up and productive in Tapestry fast!
> 
> (971) 678-5210
> http://howardlewisship.com
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
> For additional commands, e-mail: users-help@tapestry.apache.org
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
For additional commands, e-mail: users-help@tapestry.apache.org


Re: SessionStateObject lost with 5.2

Posted by Howard Lewis Ship <hl...@gmail.com>.
Tapestry manages persistent state in the HttpSession.  As of 5.2, it
doesn't do anything special to handle cases of multiple requests
(perhaps due to Ajax) attempting to modify the same SSO in multiple
threads.

This aligns with Brian Goetz's observation that all stateful web
applications are inherently broken:

http://www.ibm.com/developerworks/library/j-jtp09238.html

I'm not aware of any concerns.  You may want to have your SSO
implement the HttpSessionBindingListener interface, and log the
details of when it is bound (saved to the HttpSession). That might
illuminate what's going on.

It may be a bug in your servlet container, it may be a race condition
between threads, or it may just be a coding problem in your code.  I
hate to say it, but the last option is the most likely (given the
total lack of information you've provided).

On Thu, Oct 14, 2010 at 3:01 AM, Moritz Gmelin <mo...@gmx.de> wrote:
> Hi,
>
> since upgradeing to Tapestry 5.2 (5.2.0 and 5.2.1) we sometimes obseve that the contents of our SessionStateObject gets lost.
> The Session-ID between 2 requests is identical, but the Hashcode of the @SessionState object changes and thus the contents are lost.
> If everything works correctly, the getHashCode() of the SessionState object does not change between requests. But in the case where our SessionState objects get lost beweeen requests, obviousely a new SessionState object gets created.
> This happens only in very rare cases but if it does, our users get chucked out of their pages.
> This has not happened with t5.1.0.5 as far as we can see.
>
> Has anyone else seen this problem yet? Any hints about a possible solution?
>
> Thanks
>
> Moritz
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
> For additional commands, e-mail: users-help@tapestry.apache.org
>
>



-- 
Howard M. Lewis Ship

Creator of Apache Tapestry

The source for Tapestry training, mentoring and support. Contact me to
learn how I can get you up and productive in Tapestry fast!

(971) 678-5210
http://howardlewisship.com

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tapestry.apache.org
For additional commands, e-mail: users-help@tapestry.apache.org