Upgrade from Tomcat 7 to Tomcat 8

1,681 views
Skip to first unread message

Billy Bacon

unread,
Jul 5, 2016, 12:40:39 PM7/5/16
to memcached-session-manager
Hi Martin,

I'm in the process of upgrading our sites to use Tomcat 8; after deploying to a load balanced environment, I'm seeing ConcurrentModificationExceptions spewing in my logs. I've included the memcached-session-manager-tc8 and memcached-session-manager version 1.9.5 libraries in the tomcat/lib folder, along with spymemcached-2.12.0. 

I've also changed the Kryo version to 1.9.5 (msm-kryo-serializer) which is included in my WEB-INF/lib folder. 

Everything else is the same and has been working for several years now. I didn't see any other things I needed to do on the wiki. I was wondering if you had any ideas as to why the app is throwing exceptions noted below in the stack traces I've included.

Keep in mind there's zero load on this app right now.

Thanks for any help.

- Billy -

log4j:WARN No appenders could be found for logger (com.amazonaws.AmazonWebServiceClient).
log4j:WARN Please initialize the log4j system properly.
05-Jul-2016 16:06:26.783 INFO [localhost-startStop-1] de.javakaffee.web.msm.MemcachedSessionService.startInternal  starts initialization... (configured nodes definition session-dev-test-p2.6iuvwz.cfg.use1.cache.amazonaws.com:11211, failover nodes null)
2016-07-05 16:06:26.854 INFO net.spy.memcached.MemcachedConnection:  Added {QA sa=session-dev-test-p2.6iuvwz.cfg.use1.cache.amazonaws.com/10.0.128.30:11211, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null, toWrite=0, interested=0} to connect queue
05-Jul-2016 16:06:26.862 INFO [localhost-startStop-1] de.javakaffee.web.msm.RequestTrackingHostValve.<init> Setting ignorePattern to .*\.(png|gif|jpg|css|js|ico)$
05-Jul-2016 16:06:26.873 INFO [localhost-startStop-1] de.javakaffee.web.msm.MemcachedSessionService.setLockingMode Setting lockingMode to null
05-Jul-2016 16:06:26.881 INFO [localhost-startStop-1] de.javakaffee.web.msm.MemcachedSessionService.createTranscoderFactory Creating transcoder factory de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory
05-Jul-2016 16:06:26.890 INFO [localhost-startStop-1] de.javakaffee.web.msm.serializer.kryo.KryoTranscoder.<init> Starting with initialBufferSize 102400, maxBufferSize 2048000 and defaultSerializerFactory de.javakaffee.web.msm.serializer.kryo.DefaultFieldSerializerFactory
05-Jul-2016 16:06:26.902 INFO [localhost-startStop-1] de.javakaffee.web.msm.MemcachedSessionService.startInternal --------
-  finished initialization:
- sticky: true
- operation timeout: 1000
- node ids: []
- failover node ids: []
- storage key prefix: null
--------
2016-07-05 16:06:27,129 INFO  [localhost-startStop-1] GuiceActionBeanContextFactory: Will use ActionBeanContext subclass com.alexandria.library.stripes.extensions.LibrarianActionBeanContext
05-Jul-2016 16:06:27.344 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /var/lib/tomcat8/webapps/ROOT has finished in 9,555 ms
05-Jul-2016 16:06:27.352 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
05-Jul-2016 16:06:27.361 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]
05-Jul-2016 16:06:27.369 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 10110 ms
05-Jul-2016 16:06:29.724 WARNING [msm-storage-thread-1] de.javakaffee.web.msm.BackupSessionTask.call FAILED for session id 7F7496BB35B5E83748766DC16A57B76D
 de.javakaffee.web.msm.TranscoderDeserializationException: com.esotericsoftware.kryo.KryoException: java.util.ConcurrentModificationException
Serialization trace:
classes (java.net.URLClassLoader)
classloader (java.security.ProtectionDomain)
context (java.security.AccessControlContext)
acc (org.apache.catalina.loader.WebappClassLoader)
referent (java.util.ResourceBundle$LoaderReference)
loaderRef (java.util.ResourceBundle$CacheKey)
cacheKey (java.util.PropertyResourceBundle)
bundle (javax.servlet.jsp.jstl.fmt.LocalizationContext)
at de.javakaffee.web.msm.serializer.kryo.KryoTranscoder.serializeAttributes(KryoTranscoder.java:233)
at de.javakaffee.web.msm.TranscoderService.serializeAttributes(TranscoderService.java:151)
at de.javakaffee.web.msm.BackupSessionTask.serializeAttributes(BackupSessionTask.java:180)
at de.javakaffee.web.msm.BackupSessionTask.call(BackupSessionTask.java:110)
at de.javakaffee.web.msm.BackupSessionTask.call(BackupSessionTask.java:51)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
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)
Caused by: com.esotericsoftware.kryo.KryoException: java.util.ConcurrentModificationException
Serialization trace:
classes (java.net.URLClassLoader)
classloader (java.security.ProtectionDomain)
context (java.security.AccessControlContext)
acc (org.apache.catalina.loader.WebappClassLoader)
referent (java.util.ResourceBundle$LoaderReference)
loaderRef (java.util.ResourceBundle$CacheKey)
cacheKey (java.util.PropertyResourceBundle)
bundle (javax.servlet.jsp.jstl.fmt.LocalizationContext)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:101)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:552)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:80)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:628)
at com.esotericsoftware.kryo.serializers.DefaultArraySerializers$ObjectArraySerializer.write(DefaultArraySerializers.java:366)
at com.esotericsoftware.kryo.serializers.DefaultArraySerializers$ObjectArraySerializer.write(DefaultArraySerializers.java:307)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:552)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:80)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeObjectOrNull(Kryo.java:606)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:87)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:552)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:80)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:552)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:80)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:552)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:80)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:552)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:80)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:628)
at com.esotericsoftware.kryo.serializers.MapSerializer.write(MapSerializer.java:113)
at com.esotericsoftware.kryo.serializers.MapSerializer.write(MapSerializer.java:39)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:534)
at de.javakaffee.web.msm.serializer.kryo.KryoTranscoder.serializeAttributes(KryoTranscoder.java:230)
... 8 more
Caused by: java.util.ConcurrentModificationException
at java.util.Vector$Itr.checkForComodification(Vector.java:1184)
at java.util.Vector$Itr.next(Vector.java:1137)
at com.esotericsoftware.kryo.serializers.CollectionSerializer.write(CollectionSerializer.java:92)
at com.esotericsoftware.kryo.serializers.CollectionSerializer.write(CollectionSerializer.java:40)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:552)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:80)
... 38 more

2016-07-05 16:23:24,150 WARN  [http-nio-8080-exec-5] XMemcachedClient: XMemcachedClient use Text protocol
2016-07-05 16:23:24,180 INFO  [http-nio-8080-exec-5] SelectorManager: Creating 2 reactors...
2016-07-05 16:23:24,186 WARN  [http-nio-8080-exec-5] AbstractController: The Controller started at localhost/127.0.0.1:0 ...
2016-07-05 16:23:24,207 WARN  [Xmemcached-Reactor-0] AbstractController: Add a session: 10.0.129.193:11211
05-Jul-2016 16:23:24.919 WARNING [msm-storage-thread-1] de.javakaffee.web.msm.BackupSessionTask.call FAILED for session id 7B8D1D3EC8E0452009CD6A5CD3002A87
 de.javakaffee.web.msm.TranscoderDeserializationException: com.esotericsoftware.kryo.KryoException: java.util.ConcurrentModificationException
Serialization trace:
classes (sun.misc.Launcher$ExtClassLoader)
parent (sun.misc.Launcher$AppClassLoader)
classloader (java.security.ProtectionDomain)
context (java.security.AccessControlContext)
acc (java.net.URLClassLoader)
classloader (java.security.ProtectionDomain)
context (java.security.AccessControlContext)
acc (org.apache.catalina.loader.WebappClassLoader)
referent (java.util.ResourceBundle$LoaderReference)
loaderRef (java.util.ResourceBundle$CacheKey)
cacheKey (java.util.PropertyResourceBundle)
bundle (javax.servlet.jsp.jstl.fmt.LocalizationContext)
at de.javakaffee.web.msm.serializer.kryo.KryoTranscoder.serializeAttributes(KryoTranscoder.java:233)
at de.javakaffee.web.msm.TranscoderService.serializeAttributes(TranscoderService.java:151)
at de.javakaffee.web.msm.BackupSessionTask.serializeAttributes(BackupSessionTask.java:180)
at de.javakaffee.web.msm.BackupSessionTask.call(BackupSessionTask.java:110)
at de.javakaffee.web.msm.BackupSessionTask.call(BackupSessionTask.java:51)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
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)
Caused by: com.esotericsoftware.kryo.KryoException: java.util.ConcurrentModificationException
Serialization trace:
classes (sun.misc.Launcher$ExtClassLoader)
parent (sun.misc.Launcher$AppClassLoader)
classloader (java.security.ProtectionDomain)
context (java.security.AccessControlContext)
acc (java.net.URLClassLoader)
classloader (java.security.ProtectionDomain)
context (java.security.AccessControlContext)
acc (org.apache.catalina.loader.WebappClassLoader)
referent (java.util.ResourceBundle$LoaderReference)
loaderRef (java.util.ResourceBundle$CacheKey)
cacheKey (java.util.PropertyResourceBundle)
bundle (javax.servlet.jsp.jstl.fmt.LocalizationContext)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:101)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:552)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:80)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:552)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:80)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:628)
at com.esotericsoftware.kryo.serializers.DefaultArraySerializers$ObjectArraySerializer.write(DefaultArraySerializers.java:366)
at com.esotericsoftware.kryo.serializers.DefaultArraySerializers$ObjectArraySerializer.write(DefaultArraySerializers.java:307)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:552)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:80)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeObjectOrNull(Kryo.java:606)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:87)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:552)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:80)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:628)
at com.esotericsoftware.kryo.serializers.DefaultArraySerializers$ObjectArraySerializer.write(DefaultArraySerializers.java:366)
at com.esotericsoftware.kryo.serializers.DefaultArraySerializers$ObjectArraySerializer.write(DefaultArraySerializers.java:307)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:552)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:80)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeObjectOrNull(Kryo.java:606)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:87)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:552)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:80)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:552)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:80)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:552)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:80)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:552)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:80)
at com.esotericsoftware.kryo.serializers.FieldSerializer.write(FieldSerializer.java:518)
at com.esotericsoftware.kryo.Kryo.writeClassAndObject(Kryo.java:628)
at com.esotericsoftware.kryo.serializers.MapSerializer.write(MapSerializer.java:113)
at com.esotericsoftware.kryo.serializers.MapSerializer.write(MapSerializer.java:39)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:534)
at de.javakaffee.web.msm.serializer.kryo.KryoTranscoder.serializeAttributes(KryoTranscoder.java:230)
... 8 more
Caused by: java.util.ConcurrentModificationException
at java.util.Vector$Itr.checkForComodification(Vector.java:1184)
at java.util.Vector$Itr.next(Vector.java:1137)
at com.esotericsoftware.kryo.serializers.CollectionSerializer.write(CollectionSerializer.java:92)
at com.esotericsoftware.kryo.serializers.CollectionSerializer.write(CollectionSerializer.java:40)
at com.esotericsoftware.kryo.Kryo.writeObject(Kryo.java:552)
at com.esotericsoftware.kryo.serializers.ObjectField.write(ObjectField.java:80)
... 53 more


Martin Grotzke

unread,
Jul 5, 2016, 12:50:37 PM7/5/16
to memcached-session-manager

Sorry, but I have no idea why this is happening. Perhaps some serializer was changed between the versions? The stacktrace shows that the WebappClassLoader gets serialized, which is probably not what you want. In fact I wonder if this was the case before as well, or if serialization is changed. Need to think about how to proceed, perhaps you have an idea?


--

---
You received this message because you are subscribed to the Google Groups "memcached-session-manager" group.
To unsubscribe from this group and stop receiving emails from it, send an email to memcached-session-...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Billy Bacon

unread,
Jul 5, 2016, 1:42:17 PM7/5/16
to memcached-session-manager
Serializer changed between versions... not sure. All I changed was what was mentioned, and looking at the wiki and what's under my Tomcat/lib folder, I have all the proper jar versions listed. I do see that on the wiki it's stating spymemcache 2.11.1 and I'm using 2.12.0. Could that be causing issues or no chance?

Not sure why or why not the WebappClassLoader is getting serialized, or what would cause that. I have a couple other sites still running the tomcat 7 configurations but I don't see any way for me to verify if this has always been happening since the only trace I find of WebappClassLoader in the logs is in the stacks I sent you for tomcat 8. I don't have any stacks in my tomcat 7 environment.

How can I determine if serialization changed?

Thanks Martin. 

Billy Bacon

unread,
Jul 5, 2016, 4:14:05 PM7/5/16
to memcached-session-manager
Rolling back the msm-kryo-serializer to 1.8.0, which is what we've been running for a few years now spews the following errors and isn't compatible with 1.9.5.

log4j:WARN No appenders could be found for logger (com.amazonaws.AmazonWebServiceClient).

log4j:WARN Please initialize the log4j system properly.

log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.

05-Jul-2016 20:05:13.723 INFO [localhost-startStop-1] de.javakaffee.web.msm.MemcachedSessionService.startInternal  starts initialization... (configured nodes definition session-dev-test-p2.6iuvwz.cfg.use1.cache.amazonaws.com:11211, failover nodes null)

2016-07-05 20:05:13.801 INFO net.spy.memcached.MemcachedConnection:  Added {QA sa=/10.0.128.30:11211, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null, toWrite=0, interested=0} to connect queue

2016-07-05 20:05:13.813 INFO net.spy.memcached.MemcachedConnection:  Connection state changed for sun.nio.ch.SelectionKeyImpl@7748262d

2016-07-05 20:05:13.824 INFO net.spy.memcached.MemcachedConnection:  Added {QA sa=/10.0.128.30:11211, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null, toWrite=0, interested=0} to connect queue

2016-07-05 20:05:13.828 INFO net.spy.memcached.MemcachedConnection:  Connection state changed for sun.nio.ch.SelectionKeyImpl@99dfa19

05-Jul-2016 20:05:13.830 INFO [localhost-startStop-1] de.javakaffee.web.msm.RequestTrackingHostValve.<init> Setting ignorePattern to .*\.(png|gif|jpg|css|js|ico)$

05-Jul-2016 20:05:13.840 INFO [localhost-startStop-1] de.javakaffee.web.msm.MemcachedSessionService.setLockingMode Setting lockingMode to null

05-Jul-2016 20:05:13.848 INFO [localhost-startStop-1] de.javakaffee.web.msm.MemcachedSessionService.createTranscoderFactory Creating transcoder factory de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory

05-Jul-2016 20:05:13.857 SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.startInternal The session manager failed to start

 org.apache.catalina.LifecycleException: Failed to start component [de.javakaffee.web.msm.MemcachedBackupSessionManager[]]

at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:153)

at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5289)

at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)

at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:725)

at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:701)

at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:717)

at org.apache.catalina.startup.HostConfig.deployDirectory(HostConfig.java:1092)

at org.apache.catalina.startup.HostConfig$DeployDirectory.run(HostConfig.java:1834)

at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

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)

Caused by: java.lang.NoSuchMethodError: org.apache.catalina.Container.getLoader()Lorg/apache/catalina/Loader;

at de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory.createTranscoder(KryoTranscoderFactory.java:48)

at de.javakaffee.web.msm.MemcachedSessionService.createTranscoderService(MemcachedSessionService.java:495)

at de.javakaffee.web.msm.MemcachedSessionService.startInternal(MemcachedSessionService.java:450)

at de.javakaffee.web.msm.MemcachedBackupSessionManager.startInternal(MemcachedBackupSessionManager.java:537)

at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)

... 12 more


05-Jul-2016 20:05:13.861 SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.startInternal Context [] startup failed due to previous errors

2016-07-05 20:05:13,936 WARN  [localhost-startStop-1] XMemcachedClient: XMemcachedClient use Text protocol

2016-07-05 20:05:13,979 INFO  [localhost-startStop-1] SelectorManager: Creating 2 reactors...

2016-07-05 20:05:14,000 WARN  [localhost-startStop-1] AbstractController: The Controller started at localhost/127.0.0.1:0 ...

2016-07-05 20:05:14,018 WARN  [Xmemcached-Reactor-0] AbstractController: Add a session: 10.0.129.193:11211

2016-07-05 20:05:14,025 WARN  [Xmemcached-Reactor-1] AbstractController: Remove a session: 10.0.129.193:11211

2016-07-05 20:05:14,028 INFO  [localhost-startStop-1] AbstractController: Controller has been stopped.

05-Jul-2016 20:05:14.036 WARNING [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [com.google.inject.internal.util.$Finalizer] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:

 java.lang.Object.wait(Native Method)

 java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)

 java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)

 com.google.inject.internal.util.$Finalizer.run(Finalizer.java:114)

05-Jul-2016 20:05:14.036 WARNING [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [java-sdk-http-connection-reaper] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:

 java.lang.Thread.sleep(Native Method)

 com.amazonaws.http.IdleConnectionReaper.run(IdleConnectionReaper.java:112)

05-Jul-2016 20:05:14.037 WARNING [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Memcached IO over {MemcachedConnection to /10.0.128.30:11211}] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:

 sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)

 sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)

 sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)

 sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)

 sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)

 net.spy.memcached.MemcachedConnection.handleIO(MemcachedConnection.java:312)

 net.spy.memcached.MemcachedConnection.run(MemcachedConnection.java:1073)

05-Jul-2016 20:05:14.037 WARNING [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [pool-2-thread-1] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:

 sun.misc.Unsafe.park(Native Method)

 java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)

 java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)

 java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)

 java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)

 java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)

 java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)

 java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

 java.lang.Thread.run(Thread.java:745)

05-Jul-2016 20:05:14.050 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /var/lib/tomcat8/webapps/ROOT has finished in 7,383 ms

05-Jul-2016 20:05:14.052 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]

05-Jul-2016 20:05:14.064 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]

05-Jul-2016 20:05:14.065 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 7618 ms

2016-07-05 20:05:18.828 INFO net.spy.memcached.ConfigurationPoller:  Starting configuration poller.

2016-07-05 20:05:18.829 INFO net.spy.memcached.ConfigurationPoller:  Endpoint to use for configuration access in this poll NodeEndPoint - HostName:session-dev-test-p2.6iuvwz.0001.use1.cache.amazonaws.com IpAddress:10.0.128.30 Port:11211

2016-07-05 20:05:18.834 WARN net.spy.memcached.ConfigurationPoller:  Change in configuration - Existing configuration: Version:-1  CacheNode List:

 New configuration:Version:3  CacheNode List: session-dev-test-p2.6iuvwz.0001.use1.cache.amazonaws.com:11211

2016-07-05 20:05:18.835 INFO net.spy.memcached.ConfigurationPoller:  Notifying observers about configuration change.

05-Jul-2016 20:06:11.924 INFO [java-sdk-http-connection-reaper] org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading Illegal access: this web application instance has been stopped already. Could not load [org.apache.http.pool.AbstractConnPool$3]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.

 java.lang.IllegalStateException: Illegal access: this web application instance has been stopped already. Could not load [org.apache.http.pool.AbstractConnPool$3]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.

at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading(WebappClassLoaderBase.java:1325)

at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForClassLoading(WebappClassLoaderBase.java:1313)

at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1178)

at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1139)

at org.apache.http.pool.AbstractConnPool.closeIdle(AbstractConnPool.java:541)

at org.apache.http.impl.conn.PoolingClientConnectionManager.closeIdleConnections(PoolingClientConnectionManager.java:288)

at com.amazonaws.http.IdleConnectionReaper.run(IdleConnectionReaper.java:127)


05-Jul-2016 20:06:11.924 INFO [java-sdk-http-connection-reaper] org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading Illegal access: this web application instance has been stopped already. Could not load [org.apache.log4j.spi.ThrowableInformation]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.

 java.lang.IllegalStateException: Illegal access: this web application instance has been stopped already. Could not load [org.apache.log4j.spi.ThrowableInformation]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.

at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading(WebappClassLoaderBase.java:1325)

at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForClassLoading(WebappClassLoaderBase.java:1313)

at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1178)

at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1139)

at org.apache.log4j.spi.LoggingEvent.<init>(LoggingEvent.java:165)

at org.apache.log4j.Category.forcedLog(Category.java:391)

at org.apache.log4j.Category.log(Category.java:856)

at org.apache.commons.logging.impl.Log4JLogger.debug(Log4JLogger.java:166)

at com.amazonaws.http.IdleConnectionReaper.run(IdleConnectionReaper.java:133)


Exception in thread "java-sdk-http-connection-reaper" java.lang.NoClassDefFoundError: org/apache/log4j/spi/ThrowableInformation

at org.apache.log4j.spi.LoggingEvent.<init>(LoggingEvent.java:165)

at org.apache.log4j.Category.forcedLog(Category.java:391)

at org.apache.log4j.Category.log(Category.java:856)

at org.apache.commons.logging.impl.Log4JLogger.debug(Log4JLogger.java:166)

at com.amazonaws.http.IdleConnectionReaper.run(IdleConnectionReaper.java:133)

Caused by: java.lang.ClassNotFoundException: Illegal access: this web application instance has been stopped already. Could not load [org.apache.log4j.spi.ThrowableInformation]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.

at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForClassLoading(WebappClassLoaderBase.java:1315)

at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1178)

at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1139)

... 5 more

Caused by: java.lang.IllegalStateException: Illegal access: this web application instance has been stopped already. Could not load [org.apache.log4j.spi.ThrowableInformation]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.

at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading(WebappClassLoaderBase.java:1325)

at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForClassLoading(WebappClassLoaderBase.java:1313)

... 7 more


Martin Grotzke

unread,
Jul 5, 2016, 4:28:05 PM7/5/16
to memcached-session-manager

In 1.9.0 kryo was pushed from 1.x to 2.x/3.x - definitely not compatible.

Martin Grotzke

unread,
Jul 5, 2016, 4:39:52 PM7/5/16
to memcached-session-manager

Still not sure about serializers. I remember some issues with the CGLibProxySerializer that were hard to solve while upgrading to kryo 2, perhaps a bug got introduced.
Can you provide a reproducable sample? I know this is a lot of work but would allow me to debug this.
An alternative would be to use a patched kryo serializer that sets kryo trace logging (for both old and new versions) at that both traces can be compared.
Another possibility might be to test serialization just on business objects, might be easier to analyze.
You could also share stuff privately if privacy is a concern.

Cheers,
Martin

Billy Bacon

unread,
Jul 5, 2016, 5:04:06 PM7/5/16
to memcached-session-manager
Thanks for the notes here, Martin.

Some good news and some not so good news...

I change the kryo dependency to version 1.9.0 and that appears to have made the ConcurrentModificationException(s) go away, and from a log standpoint, things look happy.

The bad news is that session persistence doesn't appear to be working. Textbook use case I have.... 2 tomcat instances (EC2's). I tail the access logs to verify what server I was sent to and login. Hit the authenticated home page a few times to verify the server again. Manually terminate that tomcat instance. Hit the homepage again and I'm sent to the login page b/c my session was lost. 

I've always used the following configuration in my context.xml...

<Manager className="de.javakaffee.web.msm.MemcachedBackupSessionManager" enabled="${memcached.session.enabled}"
memcachedNodes="${memcached.session.nodes}" requestUriIgnorePattern=".*\.(png|gif|jpg|css|js|ico)$"
transcoderFactoryClass="de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory"/>

I do have sticky sessions configured in my Elasticbeanstalk environment (Enable session stickiness with a cookie expiration of 1800 seconds). I did notice a slightly different configuration from this page, then what I've been using for some time now.


So I tried this configuration as well, but both produce the same results; a lost session and logout.

<Manager className="de.javakaffee.web.msm.MemcachedBackupSessionManager" enabled="${memcached.session.enabled}"
memcachedNodes="${memcached.session.nodes}" requestUriIgnorePattern=".*\.(png|gif|jpg|css|js|ico)$"
transcoderFactoryClass="de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory"
sessionBackupAsync="true"
sticky="true"
copyCollectionsForSerialization="false"/>

I also have the AmazonElastiCacheClusterClient jar in my Tomcat/lib folder.

Providing a reproducible sample will be extremely difficult b/c of the db connectivity and authentication mechanism. I'm not sure how I would provide you an entire system so that you could run it locally. I open to suggestions based on previous experiences.

Anything stick out regarding my configurations above, versions and use case? At face value it looks like the original issues/exceptions are gone but I'm uncertain if things are failing silently and producing the lost session result.

Billy Bacon

unread,
Jul 5, 2016, 5:30:55 PM7/5/16
to memcached-session-manager
Ok, I just realized after reading through the dos more that the 3 attributes I added are all the defaults so that <Manager> configuration is basically identical so that can't be the issue why my session is lost.

So I must be missing something else...


On Tuesday, July 5, 2016 at 3:04:06 PM UTC-6, Billy Bacon wrote:
Thanks for the notes here, Martin.

Some good news and some not so good news...

I change the kryo dependency to version 1.9.0 and that appears to have made the ConcurrentModificationException(s) go away, and from a log standpoint, things look happy.

The bad news is that session persistence doesn't appear to be working. Textbook use case I have.... 2 tomcat instances (EC2's). I tail the access logs to verify what server I was sent to and login. Hit the authenticated home page a few times to verify the server again. Manually terminate that tomcat instance. Hit the homepage again and I'm sent to the login page b/c my session was lost. 

I've always used the following configuration in my context.xml...

<Manager className="de.javakaffee.web.msm.MemcachedBackupSessionManager" enabled="${memcached.session.enabled}"
memcachedNodes="${memcached.session.nodes}" requestUriIgnorePattern=".*\.(png|gif|jpg|css|js|ico)$"
transcoderFactoryClass="de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory"/>

I do have sticky sessions configured in my Elasticbeanstalk environment (Enable session stickiness with a cookie expiration of 1800 seconds). I did notice a slightly different configuration from this page, then what I've been using for some time now.


So I tried this configuration as well, but both produce the same results; a lost session and logout.

<Manager className="de.javakaffee.web.msm.MemcachedBackupSessionManager" enabled="${memcached.session.enabled}"
memcachedNodes="${memcached.session.nodes}" requestUriIgnorePattern=".*\.(png|gif|jpg|css|js|ico)$"
transcoderFactoryClass="de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory"
sessionBackupAsync="true"
sticky="true"
copyCollectionsForSerialization="false"/>

I also have the AmazonElastiCacheClusterClient jar in my Tomcat/lib folder.

Providing a reproducible sample will be extremely difficult b/c of the db connectivity and authentication mechanism. I'm not sure how I would provide you an entire system so that you could run it locally. I open to suggestions based on previous experiences.

Anything stick out regarding my configurations above, versions and use case? At face value it looks like the original issues/exceptions are gone but I'm uncertain if things are failing silently and producing the lost session result.

To unsubscribe from this group and stop receiving emails from it, send an email to memcached-session-manager+unsub...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--

---
You received this message because you are subscribed to the Google Groups "memcached-session-manager" group.
To unsubscribe from this group and stop receiving emails from it, send an email to memcached-session-manager+unsub...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--

---
You received this message because you are subscribed to the Google Groups "memcached-session-manager" group.
To unsubscribe from this group and stop receiving emails from it, send an email to memcached-session-manager+unsub...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--

---
You received this message because you are subscribed to the Google Groups "memcached-session-manager" group.
To unsubscribe from this group and stop receiving emails from it, send an email to memcached-session-manager+unsub...@googlegroups.com.

Billy Bacon

unread,
Jul 5, 2016, 5:46:03 PM7/5/16
to memcached-se...@googlegroups.com
Martin - I've turned up the logging levels in Tomcat to get some more details on what's going on and the logs are showing that my JSESSIONID is not being found in Memcache, when I kill the tomcat I started on, and therefore I get a new session id and that's why I'm logged out of my application.

I started on tomcat-a (tomcat-a.log), search for the session id 'C99158CFCFD1674D026C428AB5B5546A'. That was my initial login session. I then terminated tomcat-a, refreshed the screen and I was sent to tomcat-b (tomcat-b.log) where you'll see it states... 

05-Jul-2016 21:37:14.057 FINE [http-nio-8080-exec-7] de.javakaffee.web.msm.MemcachedSessionService.loadFromMemcached Loading session from memcached: C99158CFCFD1674D026C428AB5B5546A
05-Jul-2016 21:37:14.066 FINE [http-nio-8080-exec-7] de.javakaffee.web.msm.MemcachedSessionService.loadFromMemcached Session C99158CFCFD1674D026C428AB5B5546A not found in memcached.

Any ideas as to what is causing this?

- Billy -

On Tue, Jul 5, 2016 at 3:30 PM Billy Bacon <billy...@gmail.com> wrote:
Ok, I just realized after reading through the dos more that the 3 attributes I added are all the defaults so that <Manager> configuration is basically identical so that can't be the issue why my session is lost.

So I must be missing something else...


On Tuesday, July 5, 2016 at 3:04:06 PM UTC-6, Billy Bacon wrote:
Thanks for the notes here, Martin.

Some good news and some not so good news...

I change the kryo dependency to version 1.9.0 and that appears to have made the ConcurrentModificationException(s) go away, and from a log standpoint, things look happy.

The bad news is that session persistence doesn't appear to be working. Textbook use case I have.... 2 tomcat instances (EC2's). I tail the access logs to verify what server I was sent to and login. Hit the authenticated home page a few times to verify the server again. Manually terminate that tomcat instance. Hit the homepage again and I'm sent to the login page b/c my session was lost. 

I've always used the following configuration in my context.xml...

<Manager className="de.javakaffee.web.msm.MemcachedBackupSessionManager" enabled="${memcached.session.enabled}"
memcachedNodes="${memcached.session.nodes}" requestUriIgnorePattern=".*\.(png|gif|jpg|css|js|ico)$"
transcoderFactoryClass="de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory"/>

I do have sticky sessions configured in my Elasticbeanstalk environment (Enable session stickiness with a cookie expiration of 1800 seconds). I did notice a slightly different configuration from this page, then what I've been using for some time now.


So I tried this configuration as well, but both produce the same results; a lost session and logout.

<Manager className="de.javakaffee.web.msm.MemcachedBackupSessionManager" enabled="${memcached.session.enabled}"
memcachedNodes="${memcached.session.nodes}" requestUriIgnorePattern=".*\.(png|gif|jpg|css|js|ico)$"
transcoderFactoryClass="de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory"
sessionBackupAsync="true"
sticky="true"
copyCollectionsForSerialization="false"/>

I also have the AmazonElastiCacheClusterClient jar in my Tomcat/lib folder.

Providing a reproducible sample will be extremely difficult b/c of the db connectivity and authentication mechanism. I'm not sure how I would provide you an entire system so that you could run it locally. I open to suggestions based on previous experiences.

Anything stick out regarding my configurations above, versions and use case? At face value it looks like the original issues/exceptions are gone but I'm uncertain if things are failing silently and producing the lost session result.

To unsubscribe from this group and stop receiving emails from it, send an email to memcached-session-...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--

---
You received this message because you are subscribed to the Google Groups "memcached-session-manager" group.
To unsubscribe from this group and stop receiving emails from it, send an email to memcached-session-...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--

---
You received this message because you are subscribed to the Google Groups "memcached-session-manager" group.
To unsubscribe from this group and stop receiving emails from it, send an email to memcached-session-...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--

---
You received this message because you are subscribed to the Google Groups "memcached-session-manager" group.
To unsubscribe from this group and stop receiving emails from it, send an email to memcached-session-...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--

---
You received this message because you are subscribed to the Google Groups "memcached-session-manager" group.
To unsubscribe from this group and stop receiving emails from it, send an email to memcached-session-...@googlegroups.com.
tomcat-a.log
tomcat-b.log

Billy Bacon

unread,
Jul 5, 2016, 10:29:20 PM7/5/16
to memcached-se...@googlegroups.com
Last post for the night until I pick this back up in the morning... I tried using a patch release newer than what we were using originally, 1.8.3 (from 1.8.2), only the tc8 version, along with kryo 1.8.3 and I'm still losing my session when I terminate the Tomcat I start on. So I'm starting to believe this has something to do with the Tomcat 8 valve or manager that's causing the issue. Hopefully you have some insight after reading my posts. Thank you for the continued help Martin.

- Billy -

Billy Bacon

unread,
Jul 6, 2016, 10:46:32 AM7/6/16
to memcached-se...@googlegroups.com
Martin,

I'm at a loss here at what to try next. Unfortunately, it appears that Tomcat 7 was never working as advertised either. Not sure how/why/when it stopped working but I'm certain it did 3-4 years ago when I implemented these bits. I tried the same use case in our Tomcat 7 environment and I was logged out of my application when I killed the tomcat I started on.

So the good news is that it doesn't appear to be a jump from tc7 to tc8 after testing this out in another environment. I also tried a non-sticky configuration and that is throwing exceptions after the app is deployed...

06-Jul-2016 14:34:44.516 SEVERE [http-nio-8080-exec-8] org.apache.coyote.http11.AbstractHttp11Processor.process Error processing request

 java.lang.AbstractMethodError: de.javakaffee.web.msm.serializer.kryo.KryoTranscoder.serializeAttributes(Lde/javakaffee/web/msm/MemcachedBackupSession;Ljava/util/concurrent/ConcurrentMap;)[B


So, where should I look next in trying to troubleshoot this? I'd like to stay with a sticky-session setup for performance reasons of course. Are there any requirements/modifications needed for the Tomcat server.xml file? I'm attaching our TC8 server.xml for reference.

Also, I'm including the Manager configured in my /META-INF/context.xml file for reference in hopes that you can verify I have things configured correctly.

<?xml version="1.0" encoding="UTF-8"?>
<Context path="">

<Manager
className="de.javakaffee.web.msm.MemcachedBackupSessionManager"
enabled="${memcached.session.enabled}"
memcachedNodes="${memcached.session.nodes}"
requestUriIgnorePattern=".*\.(png|gif|jpg|css|js|ico)$"
transcoderFactoryClass="de.javakaffee.web.msm.serializer.kryo.KryoTranscoderFactory"/>
</Context>
${memcached.session.enabled} resolves to true. This is passed in as a jvm argument.
-Dmemcached.session.enabled=true
${memcached.session.nodes} resolves to session-dev-test-p2.6iuvwz.cfg.use1.cache.amazonaws.com:11211.  This is passed in as a jvm argument.
-Dmemcached.session.nodes=session-dev-test-p2.6iuvwz.cfg.use1.cache.amazonaws.com:11211
Please let me know what you think when you've had a moment to review. 
I know this isn't typical but we could setup a Skype screen share to troubleshoot if/when your schedule permits. That would likely be easier and more efficient than attempting to provide a sample app.
I look forward to your response. Thanks Martin.

- Billy -
tc8-server.xml

Martin Grotzke

unread,
Jul 6, 2016, 6:51:53 PM7/6/16
to memcached-se...@googlegroups.com

Hi Billy,

I'm sorry to hear the good news ;-) An option would be to remote debug tomcat / msm to see what's happening during serialization (an alternative to set log trace for kryo). Another option would be to try out java serialization to see if this works and kryo is the issue - I'd say you should try that first.
We can have a Skype call Friday or Saturday evening / night CEST.

Cheers,
Martin

Billy Bacon

unread,
Jul 7, 2016, 1:03:14 PM7/7/16
to memcached-se...@googlegroups.com
Thanks for the note here Martin. I will try out java serialization in replace of kryo and let you know the results. Friday/Saturday evening CEST sounds great. I'll make whatever time you have available work. I'm 8 hours behind you, MDT.

- Billy -

Billy Bacon

unread,
Jul 7, 2016, 2:45:45 PM7/7/16
to memcached-se...@googlegroups.com
Martin - Removing Kryo from the picture results in no improvement. The java serialization doesn't solve the issue. Just to be sure, I just dropped the transcoderFactoryClass attribute from the Manager configuration, resulting in this config:

 <?xml version="1.0" encoding="UTF-8"?> 
   <Context path="">
      <Manager className="de.javakaffee.web.msm.MemcachedBackupSessionManager" 
                       enabled="${memcached.session.enabled}" 
                       memcachedNodes="${memcached.session.nodes}" 
                       requestUriIgnorePattern=".*\.(png|gif|jpg|css|js|ico)$"/> 
  </Context>

One other thing I tried is connecting to our memcache cluster (ElastiCache) via telnet to try and 'get' the session by jsessionId. That results in a 'miss', but I'm not 100% certain what the key is. I just used the jsessionId literally.

> get 8DB3019519C0A2EA398019E8503F2B5F

Is that the key that MSM stores the web session under, or does it have a prefix/suffix?

Let me know what you think and what time(s) might work well for you for that Skype session.

Thanks!

- Billy -

Billy Bacon

unread,
Jul 7, 2016, 3:10:22 PM7/7/16
to memcached-se...@googlegroups.com
I just found that storageKeyPrefix is used to store the session key identifier. The default being 'webappVersion'. What exactly is the webappVersion? I tried the version in my web.xml in the <web-app> tag which is 3.0, that didn't seem to work, nor do I think that's correct anyway. I'm not sure how MSM would know our actual release number so I can't see that being valid either. the example in the docs show...

  • webappVersion  001_foo

Just not sure what 001 would represent in my application.


Billy Bacon

unread,
Jul 7, 2016, 3:36:35 PM7/7/16
to memcached-se...@googlegroups.com
Ok, some more tidbits on what I've tried...

I added a static storage prefix to my Manager configuration:

storageKeyPrefix="static:bacon"

I then turned up the tomcat logging for de.javakaffee.web.msm to FINE and watched all the sessions get polled.... I took one of them...

07-Jul-2016 19:33:20.184 FINE [ContainerBackgroundProcessor[StandardEngine[Catalina]]] de.javakaffee.web.msm.MemcachedSessionService.updateExpirationInMemcached Checking session 1BA503CCCAF3A868A98F8600C17F00BE: 
- isValid: true
- isExpiring: false
- isBackupRunning: false
- isExpirationUpdateRunning: false
- wasAccessedSinceLastBackup: true
- memcachedExpirationTime: 0 

Then went to my telnet session which is connected to my Elasticache cluster and tried to get that session via the following:

get bacon_1BA503CCCAF3A868A98F8600C17F00BE
END

Returning END signifies a miss; so MSM doesn't appear to be adding any session data to memcache, would you agree with that Martin?

Let me know if my steps are accurate.

- Billy - 

Martin Grotzke

unread,
Jul 7, 2016, 6:56:41 PM7/7/16
to memcached-se...@googlegroups.com

Cannot answer your questions out of my head, sorry. Try to run against memcached started with -vv, then stdout tells what's happening. For Skype details I'd suggest 20:30h CEST, then my daughter should sleep already :-) Please have the app locally running for debugging, prepared the ide for remote debugging tomcat / the app, and msm source code checked out so that we can step through sources of necessary.

You could also try to get a very simple app running to verify if it's working at all, you might check out the samples directory in msm.

Cheers,
Martin

Martin Grotzke

unread,
Jul 7, 2016, 7:02:18 PM7/7/16
to memcached-se...@googlegroups.com

Regarding the webapp version you can read up here: https://tomcat.apache.org/tomcat-8.0-doc/config/context.html#Parallel_deployment - probably you're just not using it.

Cheers,
Martin

Billy Bacon

unread,
Jul 8, 2016, 11:43:41 AM7/8/16
to memcached-se...@googlegroups.com
Thanks for this, Martin.

I've sent you a Skype connect invite, hopefully I chose the correct Martin in Germany :-) My handle is billy.bacon.

I have the source checked out, as well as the app running locally, setup for debugging. I've also setup an environment up on AWS Elasticbeanstalk where I can connect my remote debugger to, but I don't think we'll need that since I'm not seeing my sessions saved in my local setup, running tomcat and memcached locally. The remote server debugging isn't very performant either, and stepping through code causes the AWS health check to fail and ultimately terminate the instance b/c it's unresponsive, so I'm not sure if that'll be useful. We'll figure that out as a last resort. I'm hopeful we can detect the issue with my local setup.

Ping me on Skype around 20:30 CEST if you are still available at that time. 

Thanks Martin.

- Billy -

Martin Grotzke

unread,
Jul 8, 2016, 12:18:30 PM7/8/16
to memcached-se...@googlegroups.com

Great, see you on Skype!

Billy Bacon

unread,
Jul 8, 2016, 5:38:04 PM7/8/16
to memcached-se...@googlegroups.com
Thanks again for the discussion Martin, I truly appreciate it.

To summarize how we got to the bottom of this, here are the steps we performed in order to get the exception to bubble up and indicate that our application had changed since the original integration of msm, and that we were attempting to store something that was not Serializable in our session, which was calling the save session call to memcached to fail. 

1.) Use Java serialization (remove the transcoderFactorClass from the context.xml Manager config), which defaults MSM into using JavaSerializationTranscoderFactory.

2.) Added sessionBackupAysnc="false" so that the application will wait for the Future to return before proceeding. Having things Async didn't allow us to see the exception being thrown as it was spawn off in another thread and never captured.

We were able to debug this all locally, didn't need to remote debug the AWS infrastructure. Once we deployed with this configuration, and turned up FINE logging for de.javakaffee.web.msm ($CATALINA_HOME/conf/logging.properties), we were able to expose the fact that javax.servlet.jsp.jstl.fmt.LocalizationContext was being stored in the HttpSession (by one of my web app filters, for i18n support), and that class does not implement Serializable. This caused the session to never be persisted into memcached.

Luckily the fix was easy after uncovering what was causing the save session to memcached to fail. I was able to set/save that LocalizationContext into the HttpServletRequest instead of the HttpSession, and i18n still works with that change.

Thank you again for the time and tips, Martin. I'll be able to sleep better tonight.

- Billy -

Martin Grotzke

unread,
Jul 8, 2016, 7:34:18 PM7/8/16
to memcached-se...@googlegroups.com

Thanks for the summary, Billy, I'm glad I could help!

Billy Bacon

unread,
Jul 21, 2016, 5:30:42 PM7/21/16
to memcached-se...@googlegroups.com
Hi Martin, 

I ran into another snag with a different web site we use MSM in. This time, I'm not able to reproduce the error locally; performing the same steps we tried a couple weeks back (shutting down tomcat after logging in, then starting it back up and reloading the site... I remained logged in). 

So I tried using the steps we did, outlined above with changing the sessionBackupAsync to false and turned up the logging levels... while watching the logs, I see this SEVERE error logging constantly... not sure what it pertains to or why. I looked at the MemcachedBackupSession source and didn't find anything clear as to why this would be thrown:

21-Jul-2016 21:18:19.330 FINE [http-nio-8080-exec-5] de.javakaffee.web.msm.RequestTrackingHostValve.invoke >>>>>> Request starting: GET /healthcheck (requestedSessionId null) ==================
21-Jul-2016 21:18:19.331 FINE [http-nio-8080-exec-5] de.javakaffee.web.msm.MemcachedSessionService.createSession createSession invoked: null
21-Jul-2016 21:18:19.331 FINE [http-nio-8080-exec-5] de.javakaffee.web.msm.MemcachedSessionService.createSession Created new session with id DC0CCE836EAC57EE88E54619F05C13A1
21-Jul-2016 21:18:19.332 FINE [http-nio-8080-exec-5] de.javakaffee.web.msm.BackupSessionService.backupSession Starting for session id DC0CCE836EAC57EE88E54619F05C13A1
21-Jul-2016 21:18:19.332 FINE [http-nio-8080-exec-5] de.javakaffee.web.msm.BackupSessionTask.call Starting for session id DC0CCE836EAC57EE88E54619F05C13A1
21-Jul-2016 21:18:19.332 SEVERE [http-nio-8080-exec-5] org.apache.coyote.http11.AbstractHttp11Processor.process Error processing request
 java.lang.NoSuchFieldError: attributes
at de.javakaffee.web.msm.MemcachedBackupSession.getAttributesFiltered(MemcachedBackupSession.java:517)
at de.javakaffee.web.msm.BackupSessionTask.call(BackupSessionTask.java:109)
at de.javakaffee.web.msm.BackupSessionTask.call(BackupSessionTask.java:51)
at de.javakaffee.web.msm.BackupSessionService$SynchronousExecutorService.submit(BackupSessionService.java:346)
at de.javakaffee.web.msm.BackupSessionService.backupSession(BackupSessionService.java:205)
at de.javakaffee.web.msm.MemcachedSessionService.backupSession(MemcachedSessionService.java:1040)
at de.javakaffee.web.msm.RequestTrackingHostValve.backupSession(RequestTrackingHostValve.java:230)
at de.javakaffee.web.msm.RequestTrackingHostValve.invoke(RequestTrackingHostValve.java:159)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:676)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:616)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:528)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1099)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:672)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1520)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1476)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)

Any ideas as to why this would be thrown? I'm unable to see if msm is choking on saving anything to Elasticache due to something in the Session that's not Serializable. But when I login (sticky sessions enabled), verify the tomcat I'm on and where the session is created, and then I take that tomcat out of the load balancer, refresh the page, i'm sent to the tomcat and it does not find my session in Elasticache, and therefore I'm logged out. Very similar to what we were seeing with our initial thread.

Thanks for any help :-)

- Billy -

Martin Grotzke

unread,
Jul 22, 2016, 1:01:15 PM7/22/16
to memcached-se...@googlegroups.com

Are you using the latest msm version? I think a similar issue was reported and I fixed it already, you might search msm issues...

Cheers,
Martin

Billy Bacon

unread,
Jul 22, 2016, 1:18:14 PM7/22/16
to memcached-se...@googlegroups.com
You're spot on, Martin. I upgraded to version 1.9.5 and the issue appears to be resolved now, thanks!

Martin Grotzke

unread,
Jul 22, 2016, 4:01:22 PM7/22/16
to memcached-se...@googlegroups.com

Great! :-)

Reply all
Reply to author
Forward
0 new messages