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.
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
In 1.9.0 kryo was pushed from 1.x to 2.x/3.x - definitely not compatible.
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
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.
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.
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
<?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:11211Please 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.
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
webappVersion
⇒ 001_foo
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
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
Great, see you on Skype!
Thanks for the summary, Billy, I'm glad I could help!
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
Great! :-)