7 Replies Latest reply on Nov 16, 2005 1:22 PM by pedrot

    JMSSecurityException in MDB after sometime running

    pedrot

      I received a Exception on MDB after it has been running some hours without problem. The MBD had processed many messages before the problem ocorred.
      Someone has some suggestion?

      more details:

      2005-11-07 20:53:27,331 WARN [org.jboss.mq.SpyConnectionConsumer] Connection consumer closing due to error in listening thread SpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:1/c9630a3184e3b2f5210bcfd63cf54363 destination=QUEUE.request messageSelector=null Local Create] messages=0 waitingForMessage=false internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:1/c9630a3184e3b2f5210bcfd63cf54363 destination=QUEUE.request messageSelector=null Local Create] id=1,5,jboss] sessionPool=org.jboss.jms.asf.StdServerSessionPool@1263b07 connection=Connection@9744710[token=ConnectionToken:ID:1/c9630a3184e3b2f5210bcfd63cf54363 rcvstate=STARTED]]
      javax.jms.JMSSecurityException: User session is not valid
      at org.jboss.mq.security.SecurityManager.authorize(SecurityManager.java:230)
      at org.jboss.mq.security.ServerSecurityInterceptor.authorizeRead(ServerSecurityInterceptor.java:233)
      at org.jboss.mq.security.ServerSecurityInterceptor.receive(ServerSecurityInterceptor.java:98)
      at org.jboss.mq.server.TracingInterceptor.receive(TracingInterceptor.java:570)
      at org.jboss.mq.server.JMSServerInvoker.receive(JMSServerInvoker.java:226)
      at org.jboss.mq.il.jvm.JVMServerIL.receive(JVMServerIL.java:244)
      at org.jboss.mq.Connection.receive(Connection.java:909)
      at org.jboss.mq.SpyConnectionConsumer.run(SpyConnectionConsumer.java:238)
      at java.lang.Thread.run(Thread.java:534)


      Note: after the error just one more message was processed, then the service stopped running

        • 1. Re: JMSSecurityException in MDB after sometime running

          http://wiki.jboss.org/wiki/Wiki.jsp?page=JBossHelp
          One stacktrace out of context is not enough.

          • 2. Re: JMSSecurityException in MDB after sometime running
            pedrot

            what more information do you need?
            I have a lot of logs about the error.

            • 3. Re: JMSSecurityException in MDB after sometime running

              Then why don't you post them?
              AFTER you have been through this
              http://wiki.jboss.org/wiki/Wiki.jsp?page=HelpExpertSystem

              • 4. Re: JMSSecurityException in MDB after sometime running
                pedrot

                This error ocurred in stress test, after thousands messages being processed.

                2005-11-07 18:40:31,404 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 4 sendo construida
                2005-11-07 18:40:31,404 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
                2005-11-07 18:40:31,419 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 4 enviada
                2005-11-07 18:40:31,419 DEBUG [br.com.dm.distribuidor.comando.DistribuirClienteCommand] MDB: Cliente recebido do distribuidor: 5
                2005-11-07 18:40:31,419 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
                2005-11-07 18:40:31,419 DEBUG [br.com.dm.distribuidor.comando.DistribuirClienteCommand] MDB: Enviando mensagem com o cliente: 5
                2005-11-07 18:40:31,419 DEBUG [br.com.dm.distribuidor.comando.DistribuirClienteCommand] Comandos ClienteAAtender criados: 5
                2005-11-07 18:40:32,201 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 4 sendo construida
                2005-11-07 18:40:32,201 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
                2005-11-07 18:40:32,201 DEBUG [br.com.d


                005-11-07 20:53:27,331 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 2 sendo construida
                2005-11-07 20:53:27,331 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 4 sendo construida
                2005-11-07 20:53:27,331 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
                2005-11-07 20:53:27,331 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
                2005-11-07 20:53:27,331 WARN [org.jboss.mq.SpyConnectionConsumer] Connection consumer closing due to error in listening thread SpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:1/c9630a3184e3b2f5210bcfd63cf54363 destination=QUEUE.request messageSelector=null Local Create] messages=0 waitingForMessage=false internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:1/c9630a3184e3b2f5210bcfd63cf54363 destination=QUEUE.request messageSelector=null Local Create] id=1,5,jboss] sessionPool=org.jboss.jms.asf.StdServerSessionPool@1263b07 connection=Connection@9744710[token=ConnectionToken:ID:1/c9630a3184e3b2f5210bcfd63cf54363 rcvstate=STARTED]]
                javax.jms.JMSSecurityException: User session is not valid
                at org.jboss.mq.security.SecurityManager.authorize(SecurityManager.java:230)
                at org.jboss.mq.security.ServerSecurityInterceptor.authorizeRead(ServerSecurityInterceptor.java:233)
                at org.jboss.mq.security.ServerSecurityInterceptor.receive(ServerSecurityInterceptor.java:98)
                at org.jboss.mq.server.TracingInterceptor.receive(TracingInterceptor.java:570)
                at org.jboss.mq.server.JMSServerInvoker.receive(JMSServerInvoker.java:226)
                at org.jboss.mq.il.jvm.JVMServerIL.receive(JVMServerIL.java:244)
                at org.jboss.mq.Connection.receive(Connection.java:909)
                at org.jboss.mq.SpyConnectionConsumer.run(SpyConnectionConsumer.java:238)
                at java.lang.Thread.run(Thread.java:534)
                2005-11-07 20:53:27,346 DEBUG [br.com.dm.distribuidor.comando.DistribuirClienteCommand] MDB: Cliente recebido do distribuidor: 824
                2005-11-07 20:53:27,346 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 2 enviada
                2005-11-07 20:53:27,346 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 4 enviada
                2005-11-07 20:53:27,377 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
                2005-11-07 20:53:27,377 DEBUG [br.com.dm.distribuidor.comando.DistribuirClienteCommand] MDB: Enviando mensagem com o cliente: 824
                2005-11-07 20:53:27,377

                • 5. Re: JMSSecurityException in MDB after sometime running
                  pedrot

                  more logs(server.log):

                  2005-11-07 20:53:26,799 DEBUG [br.com.dm.distribuidor.comando.DistribuirClienteCommand] Comandos ClienteAAtender criados: 48933
                  2005-11-07 20:53:26,987 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 1 sendo construida
                  2005-11-07 20:53:27,002 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
                  2005-11-07 20:53:27,002 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 1 enviada
                  2005-11-07 20:53:27,002 DEBUG [br.com.dm.distribuidor.comando.DistribuirClienteCommand] MDB: Cliente recebido do distribuidor: 823
                  2005-11-07 20:53:27,002 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
                  2005-11-07 20:53:27,002 DEBUG [br.com.dm.distribuidor.comando.DistribuirClienteCommand] MDB: Enviando mensagem com o cliente: 823
                  2005-11-07 20:53:27,002 DEBUG [br.com.dm.distribuidor.comando.DistribuirClienteCommand] Comandos ClienteAAtender criados: 48934
                  2005-11-07 20:53:27,331 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 2 sendo construida
                  2005-11-07 20:53:27,331 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 4 sendo construida
                  2005-11-07 20:53:27,331 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
                  2005-11-07 20:53:27,331 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
                  2005-11-07 20:53:27,331 WARN [org.jboss.mq.SpyConnectionConsumer] Connection consumer closing due to error in listening thread SpyConnectionConsumer[sub=Subscription[subId=-2147483648connection=ConnectionToken:ID:1/c9630a3184e3b2f5210bcfd63cf54363 destination=QUEUE.request messageSelector=null Local Create] messages=0 waitingForMessage=false internalThread=Thread[Connection Consumer for dest Subscription[subId=-2147483648connection=ConnectionToken:ID:1/c9630a3184e3b2f5210bcfd63cf54363 destination=QUEUE.request messageSelector=null Local Create] id=1,5,jboss] sessionPool=org.jboss.jms.asf.StdServerSessionPool@1263b07 connection=Connection@9744710[token=ConnectionToken:ID:1/c9630a3184e3b2f5210bcfd63cf54363 rcvstate=STARTED]]
                  javax.jms.JMSSecurityException: User session is not valid
                  at org.jboss.mq.security.SecurityManager.authorize(SecurityManager.java:230)
                  at org.jboss.mq.security.ServerSecurityInterceptor.authorizeRead(ServerSecurityInterceptor.java:233)
                  at org.jboss.mq.security.ServerSecurityInterceptor.receive(ServerSecurityInterceptor.java:98)
                  at org.jboss.mq.server.TracingInterceptor.receive(TracingInterceptor.java:570)
                  at org.jboss.mq.server.JMSServerInvoker.receive(JMSServerInvoker.java:226)
                  at org.jboss.mq.il.jvm.JVMServerIL.receive(JVMServerIL.java:244)
                  at org.jboss.mq.Connection.receive(Connection.java:909)
                  at org.jboss.mq.SpyConnectionConsumer.run(SpyConnectionConsumer.java:238)
                  at java.lang.Thread.run(Thread.java:534)
                  2005-11-07 20:53:27,346 DEBUG [br.com.dm.distribuidor.comando.DistribuirClienteCommand] MDB: Cliente recebido do distribuidor: 824
                  2005-11-07 20:53:27,346 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 2 enviada
                  2005-11-07 20:53:27,346 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 4 enviada
                  2005-11-07 20:53:27,377 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
                  2005-11-07 20:53:27,377 DEBUG [br.com.dm.distribuidor.comando.DistribuirClienteCommand] MDB: Enviando mensagem com o cliente: 824
                  2005-11-07 20:53:27,377 DEBUG [br.com.dm.distribuidor.comando.DistribuirClienteCommand] Comandos ClienteAAtender criados: 48935
                  2005-11-07 20:53:27,768 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 5 sendo construida
                  2005-11-07 20:53:27,768 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 1 sendo construida
                  2005-11-07 20:53:27,768 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
                  2005-11-07 20:53:27,768 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
                  2005-11-07 20:53:27,784 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 1 enviada
                  2005-11-07 20:53:27,784 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 5 enviada
                  2005-11-07 20:53:27,971 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 2 sendo construida
                  2005-11-07 20:53:27,987 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
                  2005-11-07 20:53:27,987 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 2 enviada
                  2005-11-07 20:53:33,347 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 3 sendo construida
                  2005-11-07 20:53:33,347 DEBUG [org.jboss.mq.referenceable.SpyDestinationObjectFactory] SpyDestinationObjectFactory->getObjectInstance()
                  2005-11-07 20:53:33,347 DEBUG [br.com.dm.ccenter.presentation.controller.action.AtendimentoAction] Mensagem pedindo atendimento para o usuario: Operador 3 enviada
                  2005-11-07 20:54:29,522 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 21:01:59,548 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 21:09:29,543 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 21:16:59,585 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 21:24:29,604 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 21:31:59,624 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 21:39:29,645 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 21:46:59,665 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 21:54:29,685 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 22:01:59,705 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 22:09:29,725 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 22:16:59,721 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 22:24:29,720 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 22:31:59,728 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 22:39:29,737 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 22:46:59,745 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 22:54:29,754 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 23:01:59,763 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 23:09:29,771 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 23:16:59,780 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 23:24:29,837 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 23:32:00,082 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 23:39:30,117 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 23:47:00,146 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
                  2005-11-07 23:54:30,175 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000

                  • 6. Re: JMSSecurityException in MDB after sometime running

                    You clearly haven't read any of the instructions/links I have posted so far.
                    e.g.

                    "adrian@jboss.org" wrote:

                    AFTER you have been through this
                    http://wiki.jboss.org/wiki/Wiki.jsp?page=HelpExpertSystem

                    Your don't even provide the answer to the first questions (versions?)

                    Your responses are too quick to have even read them let alone comtemplate them
                    and you aren't providing the information suggested on those links let alone the more
                    specific information from "READ THIS FIRST" at the top of the forum.

                    I can tell you the error message says the server disconnected the client for some reason
                    (since its session id has been removed from the security manager).
                    I would expect to see that reason in the logs.

                    All I see is some DEBUG messages in a language I don't understand
                    (but would be irrelevant even if I did) and you doing some jndi lookups for a jms destination.

                    This is the third attempt to help you help yourself. Enough!

                    • 7. Re: JMSSecurityException in MDB after sometime running
                      pedrot

                      Sorry, I forgot the versions

                      I´m using Windows XP
                      Jboss 4.0.2
                      JRE 1.4.2.08

                      After has removed the security on JMS the problem stop.

                      http://wiki.jboss.org/wiki/Wiki.jsp?page=JBossASTuningSliming