Op donderdag, 7 juli 2011 18:03 schreef Filip Hanik - Dev Lists
<devli...@hanik.com>:
On 6/28/2011 2:31 AM, Konstantin Kolinko wrote:
> 2011/6/23 Ronald Klop<ronald-mailingl...@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.
