When a lot of User access,tomcat print error.net.spy.memcached.internal.CheckedOperationTimeoutException: Operation timed out. - failing node: /127.0.0.1:11211

[GoogleCodeExporter]

When the webapp is running, the MSM is ok.
Just in some case :The tomcat may print sometimes:
WARNING: No validity info available for session 
D0584556F374C85DA69C699F17D6DAF5-n1
and our site page will report the account is unuseful.

But when a lot of users access out site, the tomcat always print a lot of 
error, print :
WARNING: Could not store session BDFE8312275EC5D425F38B3BF3051716-n1 in 
memcached.
Note that this session was relocated to this node because the original node was 
not available.
 Or
java.util.concurrent.ExecutionException: 
net.spy.memcached.internal.CheckedOperationTimeoutException: Operation timed 
out. - failing node: /127.0.0.1:11211
 Or
Nov 21, 2013 11:04:55 AM de.javakaffee.web.msm.MemcachedSessionService 
changeSessionIdOnMemcachedFailover
INFO: Session needs to be relocated as node n1 is not available, loading backup 
session for 2450806B8E31566DA7CBAC904B8C18BB-n1

Our configration is blow:
<Contextpath="" docBase="/usr/local/tomcat-XXX/webapps/XXX" 
sessionCookieDomain=".XXX.com" debug="0" privileged="true" reloadable="true" 
allowlinking="true">
<Manager className="de.javakaffee.web.msm.MemcachedBackupSessionManager"
memcachedNodes="n1:127.0.0.1:11211" 
requestUriIgnorePattern=".*\.(png|gif|jpg|css|js)$"
sessionBackupAsync="false" 
sticky="false"
sessionBackupTimeout="1800000" 
transcoderFactoryClass="de.javakaffee.web.msm.serializer.json.JSONTranscoderFact
ory"/>

What version of the product are you using? On what operating system?
1.6.3 msm installed.
Cent OS5.

Can you give me some suggestions?Thank you very much.

Original issue reported on code.google.com by ache...@gmail.com on 23 Nov 2013 at 2:00

[GoogleCodeExporter]

Can you try increasing the operationTimeout, e.g. to 5000?

Depending on your app you could also try to change sessionBackupAsync to true.

Btw, the sessionBackupTimeout defines how long to wait (block the request) 
until a session is written to memcached, it does NOT define the TTL of sessions 
in memcached (session timeout).

Original comment by martin.grotzke on 25 Nov 2013 at 11:55

[GoogleCodeExporter]

Thanks for your help, I added the parameter:

 <Context path="" docBase="/usr/local/tomcat-XXX/webapps/XXX" sessionCookieDomain=".XXX.com" debug="0"  privileged="true" reloadable="true" allowlinking="true">
            <Manager className="de.javakaffee.web.msm.MemcachedBackupSessionManager"
                    memcachedNodes="n1:XXX.XXX.XXX.XXX:11211" 
                    requestUriIgnorePattern=".*\.(png|gif|jpg|css|js)$"
                    sessionBackupAsync="false"  
                    sticky="false"
                    sessionBackupTimeout="1800000" 
                    operationTimeout="5000"
                    transcoderFactoryClass="de.javakaffee.web.msm.serializer.json.JSONTranscoderFactory"/>
        </Context>

And we try it , tomorrow we will import a lot of users access out site.

Original comment by ache...@gmail.com on 26 Nov 2013 at 1:53

[GoogleCodeExporter]

I changed the config;
sessionBackupAsunc="true“
but the site still print :
Nov 26, 2013 3:47:16 PM de.javakaffee.web.msm.LockingStrategy 
onAfterLoadFromMemcached
WARNING: No validity info available for session 
6A0FA99E47B4CBAAF1A718650830D6C4-n1
sometimes.

Original comment by ache...@gmail.com on 26 Nov 2013 at 7:51

[GoogleCodeExporter]

I don't know exactly which configuration change caused which change in log 
output / behaviour.

What did change after you added operationTimeout="5000"?
what did change after you added sessionBackupAsunc="true" (I assume you still 
have set the operationTimeout)?

Can you tell in which configuration which logs are printed how often 
(considering the number of requests in total)?

Do you know if "No validity info available for session" is logged for sessions 
that were just created (do you know the age of sessions for that this is 
logged)?

Have you checked that all machines have set the same time?

Can you reproduce the issue in a local/test environment?

Original comment by martin.grotzke on 26 Nov 2013 at 11:20

[GoogleCodeExporter]

Thank you for your reply.
We used 4 tomcat to run 4 webapps, and the configuration is NOT SAME.
And I looked memcached log:
31 END
<31 get validity:C8026CE4F36C1E3EE29F0058602F9B59-n1
>31 sending key validity:C8026CE4F36C1E3EE29F0058602F9B59-n1
>31 END
<31 set validity:C8026CE4F36C1E3EE29F0058602F9B59-n1 2048 1800 20
>31 STORED
<31 set C8026CE4F36C1E3EE29F0058602F9B59-n1 2048 3600 505
>31 STORED
<31 get ping-n1
>31 END
<31 set validity:003DE48AE9570C5F03D41A0A3C5AC5C4-n1 2048 1800 20
>31 STORED
<31 set 003DE48AE9570C5F03D41A0A3C5AC5C4-n1 2048 3600 102
>31 STORED
<31 get ping-n1
>31 END
<31 get 003DE48AE9570C5F03D41A0A3C5AC5C4-n1
>31 sending key 003DE48AE9570C5F03D41A0A3C5AC5C4-n1
>31 END
<31 get validity:003DE48AE9570C5F03D41A0A3C5AC5C4-n1
>31 sending key validity:003DE48AE9570C5F03D41A0A3C5AC5C4-n1
>31 END
<31 set validity:003DE48AE9570C5F03D41A0A3C5AC5C4-n1 2048 1800 20
>31 STORED
<31 add 003DE48AE9570C5F03D41A0A3C5AC5C4-n1 512 5 1
>31 NOT_STORED
<31 get ping-n1
>31 END
<31 set validity:89B1B5940647DBBA3BB285326C17360B-n1 2048 1800 20
>31 STORED
<31 set 89B1B5940647DBBA3BB285326C17360B-n1 2048 3600 141
>31 STORED

Memcached start cmd：/usr/local/bin/memcached -m 1024 -p 11211 -d -u root -P 
/var/run/memcached.pid -vv

Sometimes the log output is NOT_STORED.And when the session is not stored, out 
progarm will print NullPointerException.We added to the session some list data 
using session.setAttribute();

I will change the tomcat configuration same. 

The request maybe just 1000~1500/Hour, and maybe in somecase there are more and 
more...then the tomcat will output blow:
java.util.concurrent.ExecutionException: 
net.spy.memcached.internal.CheckedOperationTimeoutException: Operation timed 
out. - failing node: /127.0.0.1:11211

server1: memcached
          / \ \ \
server2:T1   T2 T3 T4
          \  |   | /
             Nginx(CDN)
four tomecat access is OK,just the T1,when access a lot ,the question happens.

Original comment by ache...@gmail.com on 27 Nov 2013 at 2:49

[GoogleCodeExporter]

Thanks for your suggestion,after change the tomcat configuration same,the 
output error disappear.
[root@AY130805154445913356Z logs]# tail -1000f catalina.out | grep "No validity"
警告: No validity info available for session 
DE3B70826EC5CE85F31DA3AB936650E7-n1
警告: No validity info available for session 
BF0D449FF3F64F062EA2225CEF2B1551-n1
警告: No validity info available for session 
D10704DAE5DB7224FAF726D18DF5F67B-n1

And the warning also disappear.
There are the output warnings.
And we have a php site also use the memcached session, it get the session from 
memcached, and we are see it's configuration.

server1: memcached----php
          / \ \ \
server2:T1   T2 T3 T4
          \  |   | /
             Nginx(CDN)

Original comment by ache...@gmail.com on 27 Nov 2013 at 5:51

[GoogleCodeExporter]

So you had different system times on different machines?

And now your issues are all solved? Or do you still need s.th. to get 
fixed/improved?

FYI: memcached logs like
  <31 add 003DE48AE9570C5F03D41A0A3C5AC5C4-n1 512 5 1
  >31 NOT_STORED
show "ping" requests (when an http request did not access the session msm pings 
the session in memcached) to push up sessions in memcacheds LRU list so that 
they are not evicted too early.

Regarding the setup of memcached/tomcat/nginx: your memcached (server1) is a 
single point of failure. So if server1 goes down (or you need to restart 
memcached) all sessions will be lost.

An alternative setup would be to run memcacheds and tomcats both on server1 and 
server2.
E.g. you would have m1, tc1 and tc2 on server1 and m2, tc3 and tc4 on server2.
The memcachedNodes config would look like this:
  memcachedNodes="n1:xxx.xxx.xxx.1:11211,n2:xxx.xxx.xxx.2:11211"

See also 
https://code.google.com/p/memcached-session-manager/wiki/FAQ#How_are_sessions_st
ored_in_memcached_in_non-sticky_mode?

Original comment by martin.grotzke on 27 Nov 2013 at 8:33

[GoogleCodeExporter]

Thank you very much.
We are improve the structure of the website.
The warning is much less than before, but it also output.

I know the sugguestion you given is useful, today I will configure it. 

Original comment by ache...@gmail.com on 27 Nov 2013 at 10:35

[GoogleCodeExporter]

After we configured the tomcat as the same configuration, the warning is less.
The msm is running ok.Thanks for your help.

Original comment by ache...@gmail.com on 29 Nov 2013 at 5:47

[GoogleCodeExporter]

Ok, great that it's working.

Original comment by martin.grotzke on 29 Nov 2013 at 8:59

• Changed state: Done