You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Knut Sander <kn...@gmail.com> on 2016/05/20 20:08:25 UTC
Tomcat session replikation reports: IllegalStateException:
setAttribute: Session [..] has already been invalidated
Hi!
We are running Tomcat 7.0.68 with SimpleTcpCluster with two nodes on
different hosts.
server.xml:
[..]
<Engine [..]>
<Cluster className="org.apache.catalina.ha.tcp.SimpleTcpCluster" />
[..]
</Engine>
[..]
Everything works fine, except the messages below in catalina.out.
The problem seems to occur, if a session is modified and invalidated
during the same request (which is quite common imho). The invalidation
is replicated faster than the attribute deltas, so the second node
processes the invalidation and cannot handle the session-attribute
modification afterwards. It would be no problem to forget about the
modifications, because the session is invalid.
Just the reported exception is quite misleading and the not really
helpful for monitoring the logs.
Any suggestions? Did we miss something?
Thanks in advance,
Knut
--- catalina.out ---
May 13, 2016 7:31:14 PM org.apache.catalina.ha.session.DeltaManager
messageReceived
FINE: Manager [localhost#/xxx]: Received SessionMessage of
type=(SESSION-EXPIRED) from
[org.apache.catalina.tribes.membership.MemberImpl[tcp://{10, x, x,
x}:4000,{10, x, x, x},4000, alive=943161, securePort=-1, UDP Port=-1,
id={25 ... -60 }, payload={}, command={}, domain={}, ]]
May 13, 2016 7:31:14 PM org.apache.catalina.ha.session.DeltaManager
handleSESSION_EXPIRED
FINE: Manager [localhost#/xxx]: received session
[012F517D98B33DC5EB3F8CD488558BED] expired.
May 13, 2016 7:31:14 PM org.apache.catalina.ha.tcp.SimpleTcpCluster
messageReceived
FINE: Assuming clocks are synched: Replication for
E43557F686529DC080B27BBB8FF52E6E-1463160674477 took=1 ms.
May 13, 2016 7:31:14 PM org.apache.catalina.ha.session.DeltaManager
messageReceived
FINE: Manager [localhost#/xxx]: Received SessionMessage of
type=(SESSION-MODIFIED) from
[org.apache.catalina.tribes.membership.MemberImpl[tcp://{10, x, x,
x}:4000,{10, x, x, x},4000, alive=943161, securePort=-1, UDP Port=-1,
id={25 ... -60 }, payload={}, command={}, domain={}, ]]
May 13, 2016 7:31:14 PM org.apache.catalina.ha.session.DeltaManager
handleSESSION_CREATED
FINE: Manager [localhost#/xxx]: received session
[E43557F686529DC080B27BBB8FF52E6E] created.
May 13, 2016 7:31:14 PM org.apache.catalina.ha.session.DeltaRequest execute
FINER: Session.setAttribute('xxx', 'yyy')
May 13, 2016 7:31:14 PM org.apache.catalina.ha.session.DeltaManager
messageReceived
SEVERE: Manager [localhost#/xxx]: Unable to receive message through TCP
channel
java.lang.IllegalStateException: setAttribute: Session
[012F517D98B33DC5EB3F8CD488558BED] has already been invalidated
at
org.apache.catalina.session.StandardSession.setAttribute(StandardSession.java:1447)
at
org.apache.catalina.ha.session.DeltaSession.setAttribute(DeltaSession.java:697)
at
org.apache.catalina.ha.session.DeltaRequest.execute(DeltaRequest.java:179)
at
org.apache.catalina.ha.session.DeltaManager.handleSESSION_DELTA(DeltaManager.java:1221)
at
org.apache.catalina.ha.session.DeltaManager.messageReceived(DeltaManager.java:1167)
at
org.apache.catalina.ha.session.DeltaManager.messageDataReceived(DeltaManager.java:918)
at
org.apache.catalina.ha.session.ClusterSessionListener.messageReceived(ClusterSessionListener.java:91)
at
org.apache.catalina.ha.tcp.SimpleTcpCluster.messageReceived(SimpleTcpCluster.java:937)
at
org.apache.catalina.ha.tcp.SimpleTcpCluster.messageReceived(SimpleTcpCluster.java:918)
at
org.apache.catalina.tribes.group.GroupChannel.messageReceived(GroupChannel.java:278)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.messageReceived(ChannelInterceptorBase.java:82)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.messageReceived(ChannelInterceptorBase.java:82)
at
org.apache.catalina.tribes.group.interceptors.TcpFailureDetector.messageReceived(TcpFailureDetector.java:117)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.messageReceived(ChannelInterceptorBase.java:82)
at
org.apache.catalina.tribes.group.ChannelCoordinator.messageReceived(ChannelCoordinator.java:252)
at
org.apache.catalina.tribes.transport.ReceiverBase.messageDataReceived(ReceiverBase.java:287)
at
org.apache.catalina.tribes.transport.nio.NioReplicationTask.drainChannel(NioReplicationTask.java:210)
at
org.apache.catalina.tribes.transport.nio.NioReplicationTask.run(NioReplicationTask.java:99)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
---
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Tomcat session replikation reports: IllegalStateException:
setAttribute: Session [..] has already been invalidated
Posted by Knut Sander <kn...@gmail.com>.
Am 23.05.2016 um 10:57 schrieb Keiichi Fujino:
> Is the channelSendOptions default?
yes, everything is default so I expect channelSendOptions = 8
(SEND_OPTIONS_ASYNCHRONOUS).
> In DeltaManager,
> when the session expired, if there is a change in the session, replicates
> the attributes of session.
> And then, replicates the invalidated of the session.
> Usually, although this order is not reversed,
> if you want to ensure this order, you can set the 6(sync + ACK).
The replication of the invalidate before the attribute delta replication
happens quite regularly in our case.
As far as we understood the replication code, the session expire
triggers a replication message independent to the attribute delta
replication message, which is triggered at the end of the request.
We can try channelSendOptions = 6 (will need some time) but this looks
like quite a bit of overhead, just to get rid of an error message which
isn't a real problem. Why should anyone care for a missed session
attribute update after the session is already invalidated?
> Another point,
> The sticky session is enabled?
yes, our loadbalancer keeps the clients on the same node except the node
fails, so there is no need to replicate the sessions with SYNC and
usually an ACK is not required, too.
> If the sticky session is not enabled,
> when accessing to the non-primary node, the access to an invalid session
> will occur.
The error message occurs on node 2 without any requests to node 2. It is
only triggered by by replication requests from node 1.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Tomcat session replikation reports: IllegalStateException:
setAttribute: Session [..] has already been invalidated
Posted by Keiichi Fujino <kf...@apache.org>.
Is the channelSendOptions default?
In DeltaManager,
when the session expired, if there is a change in the session, replicates
the attributes of session.
And then, replicates the invalidated of the session.
Usually, although this order is not reversed,
if you want to ensure this order, you can set the 6(sync + ACK).
Another point,
The sticky session is enabled?
If the sticky session is not enabled,
when accessing to the non-primary node, the access to an invalid session
will occur.
2016-05-21 5:08 GMT+09:00 Knut Sander <kn...@gmail.com>:
> Hi!
>
> We are running Tomcat 7.0.68 with SimpleTcpCluster with two nodes on
> different hosts.
>
> server.xml:
> [..]
> <Engine [..]>
> <Cluster className="org.apache.catalina.ha.tcp.SimpleTcpCluster" />
> [..]
> </Engine>
> [..]
>
> Everything works fine, except the messages below in catalina.out.
>
> The problem seems to occur, if a session is modified and invalidated
> during the same request (which is quite common imho). The invalidation
> is replicated faster than the attribute deltas, so the second node
> processes the invalidation and cannot handle the session-attribute
> modification afterwards. It would be no problem to forget about the
> modifications, because the session is invalid.
> Just the reported exception is quite misleading and the not really
> helpful for monitoring the logs.
>
> Any suggestions? Did we miss something?
>
> Thanks in advance,
> Knut
>
> --- catalina.out ---
> May 13, 2016 7:31:14 PM org.apache.catalina.ha.session.DeltaManager
> messageReceived
> FINE: Manager [localhost#/xxx]: Received SessionMessage of
> type=(SESSION-EXPIRED) from
> [org.apache.catalina.tribes.membership.MemberImpl[tcp://{10, x, x,
> x}:4000,{10, x, x, x},4000, alive=943161, securePort=-1, UDP Port=-1,
> id={25 ... -60 }, payload={}, command={}, domain={}, ]]
>
> May 13, 2016 7:31:14 PM org.apache.catalina.ha.session.DeltaManager
> handleSESSION_EXPIRED
> FINE: Manager [localhost#/xxx]: received session
> [012F517D98B33DC5EB3F8CD488558BED] expired.
>
> May 13, 2016 7:31:14 PM org.apache.catalina.ha.tcp.SimpleTcpCluster
> messageReceived
> FINE: Assuming clocks are synched: Replication for
> E43557F686529DC080B27BBB8FF52E6E-1463160674477 took=1 ms.
>
> May 13, 2016 7:31:14 PM org.apache.catalina.ha.session.DeltaManager
> messageReceived
> FINE: Manager [localhost#/xxx]: Received SessionMessage of
> type=(SESSION-MODIFIED) from
> [org.apache.catalina.tribes.membership.MemberImpl[tcp://{10, x, x,
> x}:4000,{10, x, x, x},4000, alive=943161, securePort=-1, UDP Port=-1,
> id={25 ... -60 }, payload={}, command={}, domain={}, ]]
>
> May 13, 2016 7:31:14 PM org.apache.catalina.ha.session.DeltaManager
> handleSESSION_CREATED
> FINE: Manager [localhost#/xxx]: received session
> [E43557F686529DC080B27BBB8FF52E6E] created.
>
> May 13, 2016 7:31:14 PM org.apache.catalina.ha.session.DeltaRequest execute
> FINER: Session.setAttribute('xxx', 'yyy')
>
> May 13, 2016 7:31:14 PM org.apache.catalina.ha.session.DeltaManager
> messageReceived
> SEVERE: Manager [localhost#/xxx]: Unable to receive message through TCP
> channel
> java.lang.IllegalStateException: setAttribute: Session
> [012F517D98B33DC5EB3F8CD488558BED] has already been invalidated
> at
>
> org.apache.catalina.session.StandardSession.setAttribute(StandardSession.java:1447)
> at
>
> org.apache.catalina.ha.session.DeltaSession.setAttribute(DeltaSession.java:697)
> at
> org.apache.catalina.ha.session.DeltaRequest.execute(DeltaRequest.java:179)
> at
>
> org.apache.catalina.ha.session.DeltaManager.handleSESSION_DELTA(DeltaManager.java:1221)
> at
>
> org.apache.catalina.ha.session.DeltaManager.messageReceived(DeltaManager.java:1167)
> at
>
> org.apache.catalina.ha.session.DeltaManager.messageDataReceived(DeltaManager.java:918)
> at
>
> org.apache.catalina.ha.session.ClusterSessionListener.messageReceived(ClusterSessionListener.java:91)
> at
>
> org.apache.catalina.ha.tcp.SimpleTcpCluster.messageReceived(SimpleTcpCluster.java:937)
> at
>
> org.apache.catalina.ha.tcp.SimpleTcpCluster.messageReceived(SimpleTcpCluster.java:918)
> at
>
> org.apache.catalina.tribes.group.GroupChannel.messageReceived(GroupChannel.java:278)
> at
>
> org.apache.catalina.tribes.group.ChannelInterceptorBase.messageReceived(ChannelInterceptorBase.java:82)
> at
>
> org.apache.catalina.tribes.group.ChannelInterceptorBase.messageReceived(ChannelInterceptorBase.java:82)
> at
>
> org.apache.catalina.tribes.group.interceptors.TcpFailureDetector.messageReceived(TcpFailureDetector.java:117)
> at
>
> org.apache.catalina.tribes.group.ChannelInterceptorBase.messageReceived(ChannelInterceptorBase.java:82)
> at
>
> org.apache.catalina.tribes.group.ChannelCoordinator.messageReceived(ChannelCoordinator.java:252)
> at
>
> org.apache.catalina.tribes.transport.ReceiverBase.messageDataReceived(ReceiverBase.java:287)
> at
>
> org.apache.catalina.tribes.transport.nio.NioReplicationTask.drainChannel(NioReplicationTask.java:210)
> at
>
> org.apache.catalina.tribes.transport.nio.NioReplicationTask.run(NioReplicationTask.java:99)
> at
>
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> ---
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
> --
> Keiichi.Fujino
> <us...@tomcat.apache.org>
<us...@tomcat.apache.org>