4 Replies Latest reply on Dec 17, 2005 10:34 AM by Brian Stansberry

    Strange exception in HTTP-Session replication

    Dirk Müller Newbie

      Hi,

      I found the following lines in my debug output, I'm wondering if this is a deadlock? Version is 4.0.3SP1. We have two JBoss nodes (192.168.130.62:7850, 192.168.130.63:7850), this log is from 192.168.130.63:7850.

      09:29:07,215 INFO [STDOUT] org.jboss.cache.lock.TimeoutException: read lock for /JSESSION/localhost/ROOT/TbFhducYwMPVAK3ONtUM7A** could not
      be acquired by Thread[TP-Processor8,5,jboss] after 15000 ms. Locks: Read lock owners: []
      Write lock owner: <192.168.130.63:7850>:2
      , lock info: write owner=<192.168.130.63:7850>:2 (activeReaders=0, activeWriter=Thread[TP-Processor8,5,jboss], waitingReaders=0, waitingWrit
      ers=0, waitingUpgrader=0)


      The write lock owner 192.168.130.63:7850 is the machine itself, even the same thread, and it can't acquire a read lock? Is this usual? Is this a misconfiguration?

      Thanks in advance,
      Dirk

        • 1. Re: Strange exception in HTTP-Session replication
          Ben Wang Master

          This is unusual. Should not happen. Can you reproduce it?

          -Ben

          • 2. Re: Strange exception in HTTP-Session replication
            Dirk Müller Newbie

            Yes, without problems, just need to start both nodes:

            12:44:50,211 ERROR [IdentityLock] read lock for /JSESSION/localhost/ROOT/gcTJP89MyXji07wLwJgkGA** could not be acquired by Thread[TP-Process
            or2,5,jboss] after 15000 ms. Locks: Read lock owners: []
            Write lock owner: <192.168.130.63:7850>:2
            , lock info: write owner=<192.168.130.63:7850>:2 (activeReaders=0, activeWriter=Thread[TP-Processor2,5,jboss], waitingReaders=0, waitingWrit
            ers=0, waitingUpgrader=0)

            Dirk

            • 3. Re: Strange exception in HTTP-Session replication
              Dirk Müller Newbie

              Hi!
              Has anyone an idea on that problem?


              I also found the following exception and I'm wondering if both belong together in any way ...

              09:39:18,926 INFO [STDOUT] java.util.ConcurrentModificationException
              09:39:18,928 INFO [STDOUT] at java.util.HashMap$HashIterator.nextEntry(HashMap.java:782)
              09:39:18,928 INFO [STDOUT] at java.util.HashMap$EntryIterator.next(HashMap.java:824)
              09:39:18,928 INFO [STDOUT] at java.util.HashMap.writeObject(HashMap.java:978)
              09:39:18,928 INFO [STDOUT] at sun.reflect.GeneratedMethodAccessor73.invoke(Unknown Source)
              09:39:18,929 INFO [STDOUT] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
              09:39:18,929 INFO [STDOUT] at java.lang.reflect.Method.invoke(Method.java:324)
              09:39:18,929 INFO [STDOUT] at java.io.ObjectStreamClass.invokeWriteObject(ObjectStreamClass.java:809)
              09:39:18,929 INFO [STDOUT] at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1296)
              09:39:18,929 INFO [STDOUT] at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1247)
              09:39:18,930 INFO [STDOUT] at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1052)
              09:39:18,930 INFO [STDOUT] at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:278)
              09:39:18,930 INFO [STDOUT] at org.jboss.web.tomcat.tc5.session.SessionBasedClusteredSession.writeExternal(SessionBasedClusteredSession.
              java:288)
              09:39:18,930 INFO [STDOUT] at org.jboss.web.tomcat.tc5.session.JBossCacheService.externalizeSession(JBossCacheService.java:771)
              09:39:18,930 INFO [STDOUT] at org.jboss.web.tomcat.tc5.session.JBossCacheService.putSession(JBossCacheService.java:229)
              09:39:18,930 INFO [STDOUT] at org.jboss.web.tomcat.tc5.session.SessionBasedClusteredSession.processSessionRepl(SessionBasedClusteredSes
              sion.java:165)
              09:39:18,931 INFO [STDOUT] at org.jboss.web.tomcat.tc5.session.JBossCacheManager.processSessionRepl(JBossCacheManager.java:606)
              09:39:18,931 INFO [STDOUT] at org.jboss.web.tomcat.tc5.session.JBossCacheManager.storeSession(JBossCacheManager.java:375)
              09:39:18,931 INFO [STDOUT] at org.jboss.web.tomcat.tc5.session.InstantSnapshotManager.snapshot(InstantSnapshotManager.java:38)
              09:39:18,931 INFO [STDOUT] at org.jboss.web.tomcat.tc5.session.ClusteredSessionValve.invoke(ClusteredSessionValve.java:91)
              09:39:18,931 INFO [STDOUT] at org.jboss.web.tomcat.tc5.session.JvmRouteValve.invoke(JvmRouteValve.java:73)
              09:39:18,931 INFO [STDOUT] at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:59)
              09:39:18,932 INFO [STDOUT] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
              09:39:18,932 INFO [STDOUT] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
              09:39:18,932 INFO [STDOUT] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
              09:39:18,932 INFO [STDOUT] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
              09:39:18,932 INFO [STDOUT] at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:307)
              09:39:18,933 INFO [STDOUT] at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:385)
              09:39:18,933 INFO [STDOUT] at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:748)
              09:39:18,933 INFO [STDOUT] at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:678)
              09:39:18,933 INFO [STDOUT] at org.apache.jk.common.SocketConnection.runIt(ChannelSocket.java:871)
              09:39:18,933 INFO [STDOUT] at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
              09:39:18,933 INFO [STDOUT] at java.lang.Thread.run(Thread.java:534)


              Maybe this happens if I try to modify a HashMap that is stored in the ClusteredSession object while it is replicated?!

              Thanks in advance,

              Dirk :)

              p.s. this exception occured running only ONE node

              • 4. Re: Strange exception in HTTP-Session replication
                Brian Stansberry Master

                 


                Maybe this happens if I try to modify a HashMap that is stored in the ClusteredSession object while it is replicated?!


                There was no synchronization on the attribute Map itself while it was being serialized for replication, so concurrently adding/removing an attribute could raise an exception. This is a bug in 4.0.3 and 4.0.3SP1, see http://jira.jboss.com/jira/browse/JBAS-2571. This is fixed in CVS.