Closed GoogleCodeExporter closed 8 years ago
I agree that it seems weird that those negative times are logged. I need to
check what's happening there.
Besides this, do you experience unexpected behavior?
Original comment by martin.grotzke
on 22 Dec 2013 at 7:30
This is my configuration in tomcat1.
<Manager className="de.javakaffee.web.msm.MemcachedBackupSessionManager"
memcachedNodes="n1:192.168.1.110:11211,n2:192.168.1.110:11212,n3:192.168.1.110:11213"
failoverNodes="n1"
requestUriIgnorePattern=".*\.(ico|png|gif|jpg|css|js)$"
transcoderFactoryClass="de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory"
/>
This is my configuration in nginx.
user www-data;
worker_processes 1;
error_log /var/log/nginx/error.log;
pid /var/run/nginx.pid;
events {
worker_connections 1024;
# multi_accept on;
}
http {
include /etc/nginx/mime.types;
access_log /var/log/nginx/access.log;
sendfile on;
#tcp_nopush on;
#keepalive_timeout 0;
keepalive_timeout 65;
tcp_nodelay on;
gzip on;
gzip_disable "MSIE [1-6]\.(?!.*SV1)";
include /etc/nginx/conf.d/*.conf;
include /etc/nginx/sites-enabled/*;
log_format main '$remote_addr - $remote_user [$time_local] $status '
'"$request" $body_bytes_sent "$http_referer" '
'"$http_user_agent" "$http_x_forwarded_for"';
upstream zxl_server {
ip_hash;
server 192.168.1.196:8000;
server 192.168.1.196:8001;
server 192.168.1.196:8002;
}
server {
listen 80;
server_name 192.168.1.110;
access_log /var/log/nginx/zxl.server.access.log main;
location / {
proxy_pass http://zxl_server;
}
}
}
Besides this,I discover that the msm will be initialized one more times.The
following is a log.
---------------------------------------output-----------------------------------
--
Using CATALINA_BASE: "D:\AlreadyInstalled\apache-tomcat-1"
Using CATALINA_HOME: "D:\AlreadyInstalled\apache-tomcat-1"
Using CATALINA_TMPDIR: "D:\AlreadyInstalled\apache-tomcat-1\temp"
Using JRE_HOME: "C:\Program Files\Java\jdk1.6.0_23"
Using CLASSPATH: "D:\AlreadyInstalled\apache-tomcat-1\bin\bootstrap.jar"
2013-12-23 0:25:40 org.apache.catalina.core.AprLifecycleListener init
信息: Loaded APR based Apache Tomcat Native library 1.1.27 using APR version
1.4.6.
2013-12-23 0:25:40 org.apache.catalina.core.AprLifecycleListener init
信息: APR capabilities: IPv6 [true], sendfile [true], accept filters [false],
random [true].
2013-12-23 0:25:41 org.apache.catalina.core.AprLifecycleListener initializeSSL
信息: OpenSSL successfully initialized with version OpenSSL 1.0.1d 5 Feb 2013
2013-12-23 0:25:41 org.apache.coyote.http11.Http11AprProtocol init
信息: Initializing Coyote HTTP/1.1 on http-8000
2013-12-23 0:25:41 org.apache.coyote.ajp.AjpAprProtocol init
信息: Initializing Coyote AJP/1.3 on ajp-9000
2013-12-23 0:25:41 org.apache.catalina.startup.Catalina load
信息: Initialization processed in 1310 ms
2013-12-23 0:25:41 org.apache.catalina.core.StandardService start
信息: Starting service Catalina
2013-12-23 0:25:41 org.apache.catalina.core.StandardEngine start
信息: Starting Servlet Engine: Apache Tomcat/6.0.37
2013-12-23 0:25:41 org.apache.catalina.startup.HostConfig deployDescriptor
信息: Deploying configuration descriptor host-manager.xml
2013-12-23 0:25:41 de.javakaffee.web.msm.MemcachedSessionService startInternal
信息: MemcachedSessionService starts initialization... (configured nodes
definition
n1:192.168.1.110:11211,n2:192.168.1.110:11212,n3:192.168.1.110:11213, failover
nodes n1)
2013-12-23 00:25:41.973 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11211, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 00:25:41.975 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11212, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 00:25:41.976 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11213, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 0:25:41 de.javakaffee.web.msm.MemcachedBackupSessionManager
getSessionCookieName
良好: Using session cookie name from context: JSESSIONID
2013-12-23 00:25:41.983 INFO net.spy.memcached.MemcachedConnection: Connection
state changed for sun.nio.ch.SelectionKeyImpl@1742700
2013-12-23 0:25:41 de.javakaffee.web.msm.RequestTrackingHostValve <init>
信息: Setting ignorePattern to .*\.(ico|png|gif|jpg|css|js)$
2013-12-23 00:25:42.002 INFO net.spy.memcached.MemcachedConnection: Connection
state changed for sun.nio.ch.SelectionKeyImpl@9b42e6
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService setLockingMode
信息: Setting lockingMode to null
2013-12-23 00:25:42.007 INFO net.spy.memcached.MemcachedConnection: Connection
state changed for sun.nio.ch.SelectionKeyImpl@14520eb
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService
createTranscoderFactory
信息: Creating transcoder factory
de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService
loadTranscoderFactoryClass
良好: Loading transcoder factory class
de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory using classloader
WebappClassLoader
context: /host-manager
delegate: false
repositories:
----------> Parent Classloader:
org.apache.catalina.loader.StandardClassLoader@1eed786
2013-12-23 0:25:42 de.javakaffee.web.msm.serializer.kryo.KryoTranscoder <init>
信息: Starting with initialBufferSize 102400 and maxBufferSize 2048000
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService startInternal
信息: MemcachedSessionService finished initialization, sticky true, operation
timeout 1000, with node ids [n2, n3] and failover node ids [n1]
2013-12-23 0:25:42 org.apache.catalina.startup.HostConfig deployDescriptor
信息: Deploying configuration descriptor manager.xml
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService startInternal
信息: MemcachedSessionService starts initialization... (configured nodes
definition
n1:192.168.1.110:11211,n2:192.168.1.110:11212,n3:192.168.1.110:11213, failover
nodes n1)
2013-12-23 00:25:42.133 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11211, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 00:25:42.134 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11212, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 00:25:42.135 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11213, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedBackupSessionManager
getSessionCookieName
良好: Using session cookie name from context: JSESSIONID
2013-12-23 00:25:42.135 INFO net.spy.memcached.MemcachedConnection: Connection
state changed for sun.nio.ch.SelectionKeyImpl@b122a1
2013-12-23 0:25:42 de.javakaffee.web.msm.RequestTrackingHostValve <init>
信息: Setting ignorePattern to .*\.(ico|png|gif|jpg|css|js)$
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService setLockingMode
信息: Setting lockingMode to null
2013-12-23 00:25:42.136 INFO net.spy.memcached.MemcachedConnection: Connection
state changed for sun.nio.ch.SelectionKeyImpl@1589e56
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService
createTranscoderFactory
信息: Creating transcoder factory
de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService
loadTranscoderFactoryClass
良好: Loading transcoder factory class
de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory using classloader
WebappClassLoader
context: /manager
delegate: false
repositories:
----------> Parent Classloader:
org.apache.catalina.loader.StandardClassLoader@1eed786
2013-12-23 00:25:42.137 INFO net.spy.memcached.MemcachedConnection: 2013-12-23
0:25:42 de.javakaffee.web.msm.serializer.kryo.KryoTranscoder <init>
信息: Starting with initialBufferSize 102400 and maxBufferSize 2048000
Connection state changed for sun.nio.ch.SelectionKeyImpl@1033a6f
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService startInternal
信息: MemcachedSessionService finished initialization, sticky true, operation
timeout 1000, with node ids [n2, n3] and failover node ids [n1]
2013-12-23 0:25:42 org.apache.catalina.startup.HostConfig deployWAR
信息: Deploying web application archive TestApache.war
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService startInternal
信息: MemcachedSessionService starts initialization... (configured nodes
definition
n1:192.168.1.110:11211,n2:192.168.1.110:11212,n3:192.168.1.110:11213, failover
nodes n1)
2013-12-23 00:25:42.188 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11211, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 00:25:42.189 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11212, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 00:25:42.190 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11213, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedBackupSessionManager
getSessionCookieName
良好: Using session cookie name from context: JSESSIONID
2013-12-23 00:25:42.191 INFO net.spy.memcached.MemcachedConnection: Connection
state changed for sun.nio.ch.SelectionKeyImpl@10b9279
2013-12-23 0:25:42 de.javakaffee.web.msm.RequestTrackingHostValve <init>
信息: Setting ignorePattern to .*\.(ico|png|gif|jpg|css|js)$
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService setLockingMode
信息: Setting lockingMode to null
2013-12-23 00:25:42.193 INFO net.spy.memcached.MemcachedConnection: Connection
state changed for sun.nio.ch.SelectionKeyImpl@bd6a5f
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService
createTranscoderFactory
信息: Creating transcoder factory
de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService
loadTranscoderFactoryClass
良好: Loading transcoder factory class
de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory using classloader
WebappClassLoader
context: /TestApache
delegate: false
repositories:
/WEB-INF/classes/
----------> Parent Classloader:
org.apache.catalina.loader.StandardClassLoader@1eed786
2013-12-23 0:25:42 de.javakaffee.web.msm.serializer.kryo.KryoTranscoder <init>
信息: Starting with initialBufferSize 102400 and maxBufferSize 2048000
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService startInternal
信息: MemcachedSessionService finished initialization, sticky true, operation
timeout 1000, with node ids [n2, n3] and failover node ids [n1]
2013-12-23 00:25:42.196 INFO net.spy.memcached.MemcachedConnection: Connection
state changed for sun.nio.ch.SelectionKeyImpl@192a848
2013-12-23 0:25:42 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory docs
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService startInternal
信息: MemcachedSessionService starts initialization... (configured nodes
definition
n1:192.168.1.110:11211,n2:192.168.1.110:11212,n3:192.168.1.110:11213, failover
nodes n1)
2013-12-23 00:25:42.226 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11211, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 00:25:42.227 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11212, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 00:25:42.228 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11213, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedBackupSessionManager
getSessionCookieName
良好: Using session cookie name from context: JSESSIONID
2013-12-23 00:25:42.228 INFO net.spy.memcached.MemcachedConnection: Connection
state changed for sun.nio.ch.SelectionKeyImpl@19eda2c
2013-12-23 0:25:42 de.javakaffee.web.msm.RequestTrackingHostValve <init>
信息: Setting ignorePattern to .*\.(ico|png|gif|jpg|css|js)$
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService setLockingMode
信息: Setting lockingMode to null
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService
createTranscoderFactory
信息: Creating transcoder factory
de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory
2013-12-23 00:25:42.230 INFO2013-12-23 0:25:42
de.javakaffee.web.msm.MemcachedSessionService loadTranscoderFactoryClass
良好: Loading transcoder factory class
de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory using classloader
WebappClassLoader
context: /docs
delegate: false
repositories:
----------> Parent Classloader:
org.apache.catalina.loader.StandardClassLoader@1eed786
net.spy.memcached.MemcachedConnection: Connection state changed for sun.nio.ch.SelectionKeyImpl@1cef4f7
2013-12-23 0:25:42 de.javakaffee.web.msm.serializer.kryo.KryoTranscoder <init>
信息: Starting with initialBufferSize 102400 and maxBufferSize 2048000
2013-12-23 00:25:42.231 INFO net.spy.memcached.MemcachedConnection: Connection
state changed for sun.nio.ch.SelectionKeyImpl@59a34
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService startInternal
信息: MemcachedSessionService finished initialization, sticky true, operation
timeout 1000, with node ids [n2, n3] and failover node ids [n1]
2013-12-23 0:25:42 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory examples
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService startInternal
信息: MemcachedSessionService starts initialization... (configured nodes
definition
n1:192.168.1.110:11211,n2:192.168.1.110:11212,n3:192.168.1.110:11213, failover
nodes n1)
2013-12-23 00:25:42.343 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11211, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 00:25:42.344 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11212, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 00:25:42.344 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11213, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedBackupSessionManager
getSessionCookieName
良好: Using session cookie name from context: JSESSIONID
2013-12-23 0:25:42 de.javakaffee.web.msm.RequestTrackingHostValve <init>
信息: Setting ignorePattern to .*\.(ico|png|gif|jpg|css|js)$
2013-12-23 00:25:42.345 INFO net.spy.memcached.MemcachedConnection: Connection
state changed for sun.nio.ch.SelectionKeyImpl@18c74
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService setLockingMode
信息: Setting lockingMode to null
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService
createTranscoderFactory
信息: Creating transcoder factory
de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory
2013-12-23 00:25:42.347 2013-12-23 0:25:42
de.javakaffee.web.msm.MemcachedSessionService loadTranscoderFactoryClass
良好: Loading transcoder factory class
de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory using classloader
WebappClassLoader
context: /examples
delegate: false
repositories:
/WEB-INF/classes/
----------> Parent Classloader:
org.apache.catalina.loader.StandardClassLoader@1eed786
INFO net.spy.memcached.MemcachedConnection: Connection state changed for
sun.nio.ch.SelectionKeyImpl@18c3679
2013-12-23 00:25:42.348 INFO net.spy.memcached.MemcachedConnection: Connection
state changed for sun.nio.ch.SelectionKeyImpl@4c47db
2013-12-23 0:25:42 de.javakaffee.web.msm.serializer.kryo.KryoTranscoder <init>
信息: Starting with initialBufferSize 102400 and maxBufferSize 2048000
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService startInternal
信息: MemcachedSessionService finished initialization, sticky true, operation
timeout 1000, with node ids [n2, n3] and failover node ids [n1]
2013-12-23 0:25:42 org.apache.catalina.startup.HostConfig deployDirectory
信息: Deploying web application directory ROOT
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService startInternal
信息: MemcachedSessionService starts initialization... (configured nodes
definition
n1:192.168.1.110:11211,n2:192.168.1.110:11212,n3:192.168.1.110:11213, failover
nodes n1)
2013-12-23 00:25:42.382 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11211, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 00:25:42.383 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11212, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 00:25:42.384 INFO net.spy.memcached.MemcachedConnection: Added {QA
sa=/192.168.1.110:11213, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null,
toWrite=0, interested=0} to connect queue
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedBackupSessionManager
getSessionCookieName
良好: Using session cookie name from context: JSESSIONID
2013-12-23 00:25:42.385 INFO net.spy.memcached.MemcachedConnection: Connection
state changed for sun.nio.ch.SelectionKeyImpl@21e554
2013-12-23 0:25:42 de.javakaffee.web.msm.RequestTrackingHostValve <init>
信息: Setting ignorePattern to .*\.(ico|png|gif|jpg|css|js)$
2013-12-23 00:25:42.386 2013-12-23 0:25:42
de.javakaffee.web.msm.MemcachedSessionService setLockingMode
信息: Setting lockingMode to null
INFO net.spy.memcached.MemcachedConnection: Connection state changed for
sun.nio.ch.SelectionKeyImpl@19a029e
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService
createTranscoderFactory
信息: Creating transcoder factory
de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService
loadTranscoderFactoryClass
良好: Loading transcoder factory class
de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory using classloader
WebappClassLoader
context:
delegate: false
repositories:
----------> Parent Classloader:
org.apache.catalina.loader.StandardClassLoader@1eed786
2013-12-23 00:25:42.386 INFO net.spy.memcached.MemcachedConnection: Connection
state changed for sun.nio.ch.SelectionKeyImpl@15718f2
2013-12-23 0:25:42 de.javakaffee.web.msm.serializer.kryo.KryoTranscoder <init>
信息: Starting with initialBufferSize 102400 and maxBufferSize 2048000
2013-12-23 0:25:42 de.javakaffee.web.msm.MemcachedSessionService startInternal
信息: MemcachedSessionService finished initialization, sticky true, operation
timeout 1000, with node ids [n2, n3] and failover node ids [n1]
2013-12-23 0:25:42 org.apache.coyote.http11.Http11AprProtocol start
信息: Starting Coyote HTTP/1.1 on http-8000
2013-12-23 0:25:42 org.apache.coyote.ajp.AjpAprProtocol start
信息: Starting Coyote AJP/1.3 on ajp-9000
2013-12-23 0:25:42 org.apache.catalina.startup.Catalina start
信息: Server startup in 771 ms
-----------------------------------------output---------------------------------
-
Why the msm is initialized more than one time?
In addition,the logs also look like abnormal when I send a request to one of
the tomcat instances.The request also is handled more than one time.The
following is a log.
-------------------------------------------output-------------------------------
-
2013-12-23 0:26:09 de.javakaffee.web.msm.RequestTrackingHostValve invoke
良好: >>>>>> Request starting: GET /TestApache/servlet/testServlet
(requestedSessionId 57ECC0A95D81E7146D39980FBAC87B98-n3) ==================
2013-12-23 0:26:09 de.javakaffee.web.msm.RequestTrackingHostValve invoke
良好: >>>>>> Request starting: GET /TestApache/servlet/testServlet
(requestedSessionId 57ECC0A95D81E7146D39980FBAC87B98-n3) ==================
####session第一次获取前
2013-12-23 0:26:09 de.javakaffee.web.msm.SessionIdFormat createSessionId
良好: Creating new session id with orig id 'ping' and memcached id 'n3'.
2013-12-23 0:26:09 de.javakaffee.web.msm.NodeAvailabilityCache
updateIsNodeAvailable
良好: CacheLoader returned node availability 'true' for node 'n3'.
2013-12-23 0:26:09 de.javakaffee.web.msm.MemcachedSessionService
loadFromMemcached
良好: Loading session from memcached: 57ECC0A95D81E7146D39980FBAC87B98-n3
2013-12-23 0:26:09 de.javakaffee.web.msm.MemcachedSessionService
loadFromMemcached
良好: Session 57ECC0A95D81E7146D39980FBAC87B98-n3 not found in memcached.
####session第一次获取后:null
####session第二次获取前
2013-12-23 0:26:09 de.javakaffee.web.msm.MemcachedSessionService createSession
良好: createSession invoked: null
2013-12-23 0:26:09 de.javakaffee.web.msm.SessionIdFormat createSessionId
良好: Creating new session id with orig id 'ping' and memcached id 'n2'.
2013-12-23 0:26:09 de.javakaffee.web.msm.NodeAvailabilityCache
updateIsNodeAvailable
良好: CacheLoader returned node availability 'true' for node 'n2'.
2013-12-23 0:26:09 de.javakaffee.web.msm.SessionIdFormat createSessionId
良好: Creating new session id with orig id '63F2661F123086C8D6EC9CF65F75C5D5'
and memcached id 'n2'.
sessionCreated:63F2661F123086C8D6EC9CF65F75C5D5-n2
2013-12-23 0:26:09 de.javakaffee.web.msm.MemcachedSessionService createSession
良好: Created new session with id 63F2661F123086C8D6EC9CF65F75C5D5-n2
####session第二次获取后:org.apache.catalina.session.StandardSessionFacad
e@f07355
####username第一次获取前
####username第一次获取后:null
####username第一次设置前
attributeAdded:[name:username:zxl]
####username第一次设置后:null
2013-12-23 0:26:09 de.javakaffee.web.msm.MemcachedSessionService backupSession
良好: No session found in session map for 63F2661F123086C8D6EC9CF65F75C5D5-n2
2013-12-23 0:26:09 de.javakaffee.web.msm.RequestTrackingHostValve
logDebugRequestSessionCookie
良好: Have request session cookie: domain=null, maxAge=-1, path=null,
value=57ECC0A95D81E7146D39980FBAC87B98-n3, version=0, secure=false
2013-12-23 0:26:09 de.javakaffee.web.msm.RequestTrackingHostValve
logDebugResponseCookie
良好: Request finished, with Set-Cookie header:
JSESSIONID=63F2661F123086C8D6EC9CF65F75C5D5-n2; Path=/TestApache
2013-12-23 0:26:09 de.javakaffee.web.msm.RequestTrackingHostValve invoke
良好: <<<<<< Request finished: GET /TestApache/servlet/testServlet
==================
2013-12-23 0:26:09 de.javakaffee.web.msm.BackupSessionService backupSession
良好: Starting for session id 63F2661F123086C8D6EC9CF65F75C5D5-n2
2013-12-23 0:26:09 de.javakaffee.web.msm.RequestTrackingHostValve
logDebugRequestSessionCookie
良好: Have request session cookie: domain=null, maxAge=-1, path=null,
value=57ECC0A95D81E7146D39980FBAC87B98-n3, version=0, secure=false
2013-12-23 0:26:09 de.javakaffee.web.msm.BackupSessionTask call
良好: Starting for session id 63F2661F123086C8D6EC9CF65F75C5D5-n2
2013-12-23 0:26:09 de.javakaffee.web.msm.RequestTrackingHostValve
logDebugResponseCookie
良好: Request finished, with Set-Cookie header:
JSESSIONID=63F2661F123086C8D6EC9CF65F75C5D5-n2; Path=/TestApache
2013-12-23 0:26:09 de.javakaffee.web.msm.RequestTrackingHostValve invoke
良好: <<<<<< Request finished: GET /TestApache/servlet/testServlet
==================
2013-12-23 0:26:10 de.javakaffee.web.msm.BackupSessionTask doBackupSession
良好: Trying to store session in memcached:
63F2661F123086C8D6EC9CF65F75C5D5-n2
2013-12-23 0:26:10 de.javakaffee.web.msm.BackupSessionTask call
良好: Finished for session id 63F2661F123086C8D6EC9CF65F75C5D5-n2, returning
status SUCCESS
--------------------------------------output-----------------------------
I hope you can find your way to solve the problem.Thank you stand my poor
English.
Original comment by 150349...@qq.com
on 23 Dec 2013 at 5:12
Perhaps the duplicate log output is just a logging issue and misleading.
Do you experience unexpected behavior?
Original comment by martin.grotzke
on 1 Jan 2014 at 11:41
I want to make clear the principle of 'failoverNodes' by source code, but the
repeated logs disrupted tracking process.
Now,I have 3 nodes,And this is the configuration of each node as follows.
<Context>
<Manager className="de.javakaffee.web.msm.MemcachedBackupSessionManager"
memcachedNodes="n1:10.100.10.21:11211,n2:10.100.10.22:11211,n3:10.100.10.23:11211"
failoverNodes="n1"//In the node of IP 22 is n2 and In the node of IP 23 is n3
requestUriIgnorePattern=".*\.(ico|png|gif|jpg|css|js)$"
transcoderFactoryClass="de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory"
/>
</Context>
I want to know that the session of node1 is a backup in which Memcache nodes,
and what is strategy.I did not find the details in the project document.I need
some help, thank you very much.
Original comment by 150349...@qq.com
on 2 Jan 2014 at 5:10
You've configured failoverNodes correctly.
I just updated the documentation (SetupAndConfiguration):
> This attribute must contain the ids of the memcached nodes that must only be
used for session backup when none of the other memcached nodes are available.
Therefore, you should list those memcached nodes, that are running on the same
machine as this tomcat. E.g. if you have tomcat1 and memcached1 (n1) running on
host1, and tomcat2 and memcached2 (n2) on host2, then you set n1 as failover
node for tomcat1, so that tomcat1 does only store sessions in memcached1 if
memcached2 is not available (for tomcat2 failoverNodes would be set to n2).
With this setting host1 could completely crash and sessions from tomcat1 would
still be available.
Is this description more clear now?
Original comment by martin.grotzke
on 2 Jan 2014 at 8:28
Your critical analysis helped me a great deal.But I still have some questions.
I did some testing before.In the above configuration, when 3 Tomcat and 3
memcached instances were normal,the session of tomcat1 will backup in the
memcached2,the session of tomcat2 will backup in the memcached3 and the session
of tomcat3 will backup in the memcached1.
When I killed the tomcat1,the request arrived tomcat2.Because the session of
tomcat1 was backup in the memcached2,the session will be acquired from
memcached2 and stored in the tomcat2.Now,the session only be stored in the
memcached2 and tomcat2.When the session is expired,the new session will be
created in tomcat2 and stored in the memcached3.
This is normal?
Original comment by 150349...@qq.com
on 2 Jan 2014 at 3:30
Node selection for new sessions happens randomly, like
pickRandomFrom(memcachedNodes.subtract(failoverNodes)).
If a session after a tomcat failover is stored in a memcached node that is
configured as failoverNode this is an oversight and should be fixed. Can you
please verify this and submit a separate issue if it's reproducible?
Original comment by martin.grotzke
on 2 Jan 2014 at 7:02
Now I have completely make clear the strategies for 'failoverNodes',and the
problem about that session only be stored in the tomcat2 and memcached2 before
can be reproduced, I will open a new separate issue.
Thanks to your help.But what about the negative memcachedExpirationTime?
Original comment by 150349...@qq.com
on 3 Jan 2014 at 5:01
Thanx for submitting the issue!
I just checked the negative memcachedExpirationTime, and it was caused by
tomcats internal "processExpiresFrequency": tomcat doesn't expire() sessions as
soon as they reached their timeout, but they're expired according to the
configured processExpiresFrequency, which is 6 by default. Because tomcats
background process runs every 10 seconds, and processExpiresFrequency is 6 by
default, a session with timeout 5 minutes will be exipire'd 60 seconds after
the session reached its timeout.
This lead to the negative memcachedExpirationTime.
I just changed the expiration time that is set for sessions in memcached to
respect the offset caused by processExpiresFrequency so that msm should no
longer print any negative memcachedExpirationTime.
Original comment by martin.grotzke
on 3 Jan 2014 at 10:01
Original comment by martin.grotzke
on 3 Jan 2014 at 10:08
Original comment by martin.grotzke
on 2 Feb 2014 at 2:08
Original issue reported on code.google.com by
150349...@qq.com
on 22 Dec 2013 at 5:17