You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Filip Hanik - Dev Lists <de...@hanik.com> on 2011/07/07 18:03:01 UTC
Re: getAllClusterSessions gives OptionalDataException
On 6/28/2011 2:31 AM, Konstantin Kolinko wrote:
> 2011/6/23 Ronald Klop<ro...@base.nl>:
>> Hi,
>>
>> I have an exception when one on my Tomcat nodes restarts. The session are
>> not synced and user complain about being logged out. I was running 6.0.32
>> and had the problem. Now I'm running a custom build of 6.0.33 from
>> yesterday. I added a little code which prints ' SEVERE: name=user'. The key
>> on which the sync fails while reading the value.
>>
>> I looked into the java code in ObjectInputStream and it looks like some
>> inconsistency in the ObjectStream.
>>
>> I have 4 nodes on Debian 5, sun-java6-jdk 6-22-0lenny1, seen the problem on
>> Tomcat 6.0.29, 6.0.32 and a custom build 6.0.33. I can't reproduce this
>> (yet) on my test environment, so debugging it is difficult without upset
>> customers.
>>
>> <Engine name="Catalina" defaultHost="xxx.xxx.xxx">
>> <Realm className="org.apache.catalina.realm.UserDatabaseRealm"
>> resourceName="UserDatabase" />
>> <Cluster
>> className="org.apache.catalina.ha.tcp.SimpleTcpCluster">
>> <Channel
>> className="org.apache.catalina.tribes.group.GroupChannel">
>> <Membership
>> className="org.apache.catalina.tribes.membership.McastService" port="47727"
>> />
>> </Channel>
>> </Cluster>
>> <Host name="xxx.xxx.xxx"
>> appBase="/data/webapps/crm-LIVE/deployed"
>> unpackWARs="true" autoDeploy="false"
>> xmlValidation="false" xmlNamespaceAware="true">
>> </Host>
>> </Engine>
>>
>> Can I provide more information? Where should I look.
>>
>> NB: In some previous mails about another problem I thought that might be the
>> reason for my logout problem, that is why I tried 6.0.33-dev.
>>
>> Ronald.
>>
>> Jun 23, 2011 5:49:47 PM org.apache.catalina.ha.session.DeltaManager
>> getAllClusterSessions
>> WARNING: Manager [crm.realworks.nl#], requesting session state from
>> org.apache.catalina.tribes.membership.MemberImpl[tcp://{10, 0, 10,
>> 110}:4000,{10, 0, 10, 110},4000, alive=45370885,id={-34 112 102 -93 -87 -88
>> 77 18 -113 -30 62 8 62 -65 -112 -13 }, payload={}, command={}, domain={}, ].
>> This operation will timeout if no session state has been received within 60
>> seconds.
>> Jun 23, 2011 5:49:47 PM org.apache.catalina.ha.session.DeltaManager
>> waitForSendAllSessions
>> INFO: Manager [crm.realworks.nl#]; session state send at 6/23/11 5:49 PM
>> received in 304 ms.
>> Jun 23, 2011 5:49:47 PM org.apache.catalina.ha.session.DeltaManager
>> getAllClusterSessions
>> WARNING: Manager [crm.realworks.nl#]: Drop message SESSION-ACCESSED inside
>> GET_ALL_SESSIONS sync phase start date 6/23/11 5:49 PM message date 6/23/11
>> 5:49 PM
>> Jun 23, 2011 5:49:47 PM org.apache.catalina.ha.session.DeltaSession
>> readObject
>> SEVERE: name=user.
>> Jun 23, 2011 5:49:47 PM org.apache.catalina.ha.session.DeltaManager
>> deserializeSessions
>> SEVERE: IOException while loading persisted sessions:
>> java.io.OptionalDataException
>> java.io.OptionalDataException
>> at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1348)
>> at java.io.ObjectInputStream.readObject(ObjectInputStream.java:350)
>> at java.util.HashMap.readObject(HashMap.java:1029)
> (...)
>
> Looking at ObjectInputStream sourced, the OptionalDataException is
> thrown when the source stream is truncated.
>
> It might be related to the following issue, fixed in Tomcat 7, but
> never proposed for backport yet:
> https://issues.apache.org/bugzilla/show_bug.cgi?id=50646
> "Tribes ByteMessage will get corrupted if message size exceeds the
> underlying buffer size"
that's what I thought, but the SessionMessage doesn't use ByteMessage
> Best regards,
> Konstantin Kolinko
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: getAllClusterSessions gives OptionalDataException
Posted by Ronald Klop <ro...@base.nl>.
Op vrijdag, 8 juli 2011 21:55 schreef Christopher Schultz <ch...@christopherschultz.net>:
>
>
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA1
>
> Ronald,
>
> On 7/8/2011 5:33 AM, Ronald Klop wrote:
> > After some fun with debugging Tomcat on my live server (because I
> > couldn't reproduce it in test) it looks like a concurrency bug in my
> > own code.
>
> D'oh.
>
> > I think I modify a HashMap which is serialized in the session. For
> > some reason I don't get a ConcurrentModificationException, but in the
> > byte[] in DeltaManager.handleALL_SESSION_DATA I had a HashMap with
> > size 5, but I only saw 4 elements which gave the
> > OptionalDataException. I now use a synchronized map and don't see
> > the exception anymore (after 1 day of testing, so I don't cheer too
> > loud yet).
>
> Definitely get back to us with an update. It would be nice to know that
> this problem turned out to be caused by the webapp and not Tomcat in
> some way.
>
> - -chris
>
>
>
>
>
Hi,
Today we had to do an update during work hours and all sessions were ok. So I consider this OptionalDataException solved for me.
It was a not synchronized Map in the session which is updated more frequently now than in the past and triggered a race condition now.
Greetings and thanks for responses and tips,
Ronald.
Re: getAllClusterSessions gives OptionalDataException
Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
Ronald,
On 7/8/2011 5:33 AM, Ronald Klop wrote:
> After some fun with debugging Tomcat on my live server (because I
> couldn't reproduce it in test) it looks like a concurrency bug in my
> own code.
D'oh.
> I think I modify a HashMap which is serialized in the session. For
> some reason I don't get a ConcurrentModificationException, but in the
> byte[] in DeltaManager.handleALL_SESSION_DATA I had a HashMap with
> size 5, but I only saw 4 elements which gave the
> OptionalDataException. I now use a synchronized map and don't see
> the exception anymore (after 1 day of testing, so I don't cheer too
> loud yet).
Definitely get back to us with an update. It would be nice to know that
this problem turned out to be caused by the webapp and not Tomcat in
some way.
- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.10 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/
iEYEARECAAYFAk4XYMcACgkQ9CaO5/Lv0PCmwACgub9BSbILSjSDFwnMej4p0JrR
f2wAnRZ4CmlvaiYfHVaN8oUTx+FWhytb
=b7Ol
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: getAllClusterSessions gives OptionalDataException
Posted by Ronald Klop <ro...@base.nl>.
Op donderdag, 7 juli 2011 18:03 schreef Filip Hanik - Dev Lists <de...@hanik.com>:
>
>
> On 6/28/2011 2:31 AM, Konstantin Kolinko wrote:
> > 2011/6/23 Ronald Klop<ro...@base.nl>:
> >> Hi,
> >>
> >> I have an exception when one on my Tomcat nodes restarts. The session are
> >> not synced and user complain about being logged out. I was running 6.0.32
> >> and had the problem. Now I'm running a custom build of 6.0.33 from
> >> yesterday. I added a little code which prints ' SEVERE: name=user'. The key
> >> on which the sync fails while reading the value.
> >>
> >> I looked into the java code in ObjectInputStream and it looks like some
> >> inconsistency in the ObjectStream.
> >>
> >> I have 4 nodes on Debian 5, sun-java6-jdk 6-22-0lenny1, seen the problem on
> >> Tomcat 6.0.29, 6.0.32 and a custom build 6.0.33. I can't reproduce this
> >> (yet) on my test environment, so debugging it is difficult without upset
> >> customers.
> >>
> >> <Engine name="Catalina" defaultHost="xxx.xxx.xxx">
> >> <Realm className="org.apache.catalina.realm.UserDatabaseRealm"
> >> resourceName="UserDatabase" />
> >> <Cluster
> >> className="org.apache.catalina.ha.tcp.SimpleTcpCluster">
> >> <Channel
> >> className="org.apache.catalina.tribes.group.GroupChannel">
> >> <Membership
> >> className="org.apache.catalina.tribes.membership.McastService" port="47727"
> >> />
> >> </Channel>
> >> </Cluster>
> >> <Host name="xxx.xxx.xxx"
> >> appBase="/data/webapps/crm-LIVE/deployed"
> >> unpackWARs="true" autoDeploy="false"
> >> xmlValidation="false" xmlNamespaceAware="true">
> >> </Host>
> >> </Engine>
> >>
> >> Can I provide more information? Where should I look.
> >>
> >> NB: In some previous mails about another problem I thought that might be the
> >> reason for my logout problem, that is why I tried 6.0.33-dev.
> >>
> >> Ronald.
> >>
> >> Jun 23, 2011 5:49:47 PM org.apache.catalina.ha.session.DeltaManager
> >> getAllClusterSessions
> >> WARNING: Manager [crm.realworks.nl#], requesting session state from
> >> org.apache.catalina.tribes.membership.MemberImpl[tcp://{10, 0, 10,
> >> 110}:4000,{10, 0, 10, 110},4000, alive=45370885,id={-34 112 102 -93 -87 -88
> >> 77 18 -113 -30 62 8 62 -65 -112 -13 }, payload={}, command={}, domain={}, ].
> >> This operation will timeout if no session state has been received within 60
> >> seconds.
> >> Jun 23, 2011 5:49:47 PM org.apache.catalina.ha.session.DeltaManager
> >> waitForSendAllSessions
> >> INFO: Manager [crm.realworks.nl#]; session state send at 6/23/11 5:49 PM
> >> received in 304 ms.
> >> Jun 23, 2011 5:49:47 PM org.apache.catalina.ha.session.DeltaManager
> >> getAllClusterSessions
> >> WARNING: Manager [crm.realworks.nl#]: Drop message SESSION-ACCESSED inside
> >> GET_ALL_SESSIONS sync phase start date 6/23/11 5:49 PM message date 6/23/11
> >> 5:49 PM
> >> Jun 23, 2011 5:49:47 PM org.apache.catalina.ha.session.DeltaSession
> >> readObject
> >> SEVERE: name=user.
> >> Jun 23, 2011 5:49:47 PM org.apache.catalina.ha.session.DeltaManager
> >> deserializeSessions
> >> SEVERE: IOException while loading persisted sessions:
> >> java.io.OptionalDataException
> >> java.io.OptionalDataException
> >> at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1348)
> >> at java.io.ObjectInputStream.readObject(ObjectInputStream.java:350)
> >> at java.util.HashMap.readObject(HashMap.java:1029)
> > (...)
> >
> > Looking at ObjectInputStream sourced, the OptionalDataException is
> > thrown when the source stream is truncated.
> >
> > It might be related to the following issue, fixed in Tomcat 7, but
> > never proposed for backport yet:
> > https://issues.apache.org/bugzilla/show_bug.cgi?id=50646
> > "Tribes ByteMessage will get corrupted if message size exceeds the
> > underlying buffer size"
> that's what I thought, but the SessionMessage doesn't use ByteMessage
>
> > Best regards,
> > Konstantin Kolinko
>
>
>
>
>
Hi Konstantin,
The 'Tribes ByteMessage' issue didn't solve my problem.
But. After some fun with debugging Tomcat on my live server (because I couldn't reproduce it in test) it looks like a concurrency bug in my own code. I think I modify a HashMap which is serialized in the session. For some reason I don't get a ConcurrentModificationException, but in the byte[] in DeltaManager.handleALL_SESSION_DATA I had a HashMap with size 5, but I only saw 4 elements which gave the OptionalDataException.
I now use a synchronized map and don't see the exception anymore (after 1 day of testing, so I don't cheer too loud yet).
Ronald.