Uploaded image for project: 'Qpid'
  1. Qpid
  2. QPID-7507

AMQSession_0_10.isQueueExist() fails with NPE if SessionException does not have a cause

    XMLWordPrintableJSON

Details

    Description

      Running a test against a Java Broker that was accepting connections but then failing *because the source tree was in a inconsistent build state), I ran into the following NPE.

      #isQueueExist assumes the SessionException always has a cause, but as we see here this assumption is a unsafe.

      /Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/bin/java -Dprofile.virtualhostnode.context.blueprint='{type:ProvidedStore,globalAddressDomains:${dollar.sign}{qpid.globalAddressDomains}}' -DQPID_HOME=/Users/keith/src/qpid-java/systests/target/qpid-broker/6.2.0-SNAPSHOT -DQPID_WORK=/Users/keith/src/qpid-java/systests/target/qpid-broker/6.2.0-SNAPSHOT/work -Dqpid.globalAddressDomains=[] -Djava.naming.provider.url=test-profiles/test-provider.properties -Dtest.output.dir=/Users/keith/src/qpid-java/systests/target/surefire-reports/java-mms.0-10 -Djava.naming.factory.initial=org.apache.qpid.jndi.PropertiesFileInitialContextFactory -Dbroker.config=/Users/keith/src/qpid-java/systests/target/qpid-broker/6.2.0-SNAPSHOT/etc/config-systests.json -Dmax_prefetch=1000 -Dqpid.dest_syntax=BURL -Dtest.port=0 -Dtest.hport=0 -Dtest.port.ssl=0 -Dtest.port.alt=0 -Dtest.port.alt.ssl=0 -Dtest.exclude=true -Dtest.mem=512M -Dprofile.clustered=false -Dprofile=java-mms.0-10 -Dbroker.language=java -Dbroker.type=internal -Dbroker.stopped=Exception -Dbroker.ready=BRK-1004 "-Dbroker.amqpTcpPortRegEx=BRK-1002 : Starting : Listening on TCP port (\d+)" "-Dbroker.httpTcpPortRegEx=MNG-1002 : Starting : HTTP : Listening on TCP port (\d+)" "-Dbroker.amqpTlsPortRegEx=BRK-1002 : Starting : Listening on SSL port (\d+)" "-Dbroker.httpTlsPortRegEx=MNG-1002 : Starting : HTTP : Listening on SSL port (\d+)" "-Dbroker.command=\"/Users/keith/src/qpid-java/systests/target/qpid-broker/6.2.0-SNAPSHOT/bin/qpid-server\" -sp \"@STORE_PATH\" -st @STORE_TYPE -prop test.port=@PORT -prop \"qpid.work_dir=@QPID_WORK\"" "-Dbroker.command.windows=\"/Users/keith/src/qpid-java/systests/target/qpid-broker/6.2.0-SNAPSHOT/bin/qpid-server.bat\" -sp \"@STORE_PATH\" -st @STORE_TYPE -prop test.port=@PORT -prop \"qpid.work_dir=@QPID_WORK\"" "-Dtest.excludes=Excludes JavaExcludes java-mms.0-10.excludes JavaTransientExcludes Java010Excludes" -Dbroker.version=v0_10 -Dtest.amqp_port_protocols=[\"AMQP_0_8\",\"AMQP_0_9\",\"AMQP_0_9_1\",\"AMQP_0_10\"] -Dbroker.persistent=false -Dvirtualhostnode.type=Memory -Dvirtualhostnode.context.blueprint={\"type\":\"ProvidedStore\",\"globalAddressDomains\":\"[]\"} -Dbroker.clean.between.tests=true -Dqpid.test_receive_timeout=1000 -Didea.launcher.port=7533 "-Didea.launcher.bin.path=/Applications/IntelliJ IDEA 15.app/Contents/bin" -Didea.junit.sm_runner -Dfile.encoding=UTF-8 -classpath "/Applications/IntelliJ IDEA 15.app/Contents/lib/idea_rt.jar:/Applications/IntelliJ IDEA 15.app/Contents/plugins/junit/lib/junit-rt.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/charsets.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/deploy.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/ext/dnsns.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/ext/localedata.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/ext/sunec.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/ext/sunjce_provider.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/ext/sunpkcs11.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/ext/zipfs.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/htmlconverter.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/javaws.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/jce.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/jfr.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/jfxrt.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/jsse.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/management-agent.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/plugin.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/resources.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/jre/lib/rt.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/lib/ant-javafx.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/lib/dt.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/lib/javafx-doclet.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/lib/javafx-mx.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/lib/jconsole.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/lib/sa-jdi.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_79.jdk/Contents/Home/lib/tools.jar:/Users/keith/src/qpid-java/systests/target/test-classes:/Users/keith/src/qpid-java/systests/target/classes:/Users/keith/src/qpid-java/qpid-test-utils/target/classes:/Users/keith/src/qpid-java/client/target/classes:/Users/keith/src/qpid-java/common/target/classes:/Users/keith/.m2/repository/org/apache/geronimo/specs/geronimo-jms_1.1_spec/1.1.1/geronimo-jms_1.1_spec-1.1.1.jar:/Users/keith/src/qpid-java/jca/target/classes:/Users/keith/.m2/repository/org/apache/geronimo/specs/geronimo-j2ee-connector_1.5_spec/2.0.0/geronimo-j2ee-connector_1.5_spec-2.0.0.jar:/Users/keith/.m2/repository/org/apache/geronimo/specs/geronimo-jta_1.1_spec/1.1.1/geronimo-jta_1.1_spec-1.1.1.jar:/Users/keith/src/qpid-java/broker/target/classes:/Users/keith/src/qpid-java/broker-core/target/classes:/Users/keith/.m2/repository/commons-cli/commons-cli/1.2/commons-cli-1.2.jar:/Users/keith/src/qpid-java/broker-plugins/websocket/target/classes:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-websocket/8.1.17.v20150415/jetty-websocket-8.1.17.v20150415.jar:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-io/8.1.17.v20150415/jetty-io-8.1.17.v20150415.jar:/Users/keith/src/qpid-java/broker-core/target/test-classes:/Users/keith/.m2/repository/com/fasterxml/jackson/core/jackson-core/2.5.3/jackson-core-2.5.3.jar:/Users/keith/.m2/repository/com/fasterxml/jackson/core/jackson-databind/2.5.3/jackson-databind-2.5.3.jar:/Users/keith/.m2/repository/com/fasterxml/jackson/core/jackson-annotations/2.5.0/jackson-annotations-2.5.0.jar:/Users/keith/.m2/repository/org/apache/bcel/bcel/5.2/bcel-5.2.jar:/Users/keith/.m2/repository/com/google/guava/guava/18.0/guava-18.0.jar:/Users/keith/src/qpid-java/broker-plugins/access-control/target/classes:/Users/keith/src/qpid-java/broker-plugins/amqp-0-8-protocol/target/classes:/Users/keith/src/qpid-java/broker-plugins/amqp-0-10-protocol/target/classes:/Users/keith/src/qpid-java/broker-plugins/amqp-1-0-protocol/target/classes:/Users/keith/src/qpid-java/broker-plugins/amqp-msg-conv-0-8-to-0-10/target/classes:/Users/keith/src/qpid-java/broker-plugins/amqp-msg-conv-0-8-to-1-0/target/classes:/Users/keith/src/qpid-java/broker-plugins/amqp-msg-conv-0-10-to-1-0/target/classes:/Users/keith/src/qpid-java/broker-plugins/derby-store/target/classes:/Users/keith/.m2/repository/org/apache/derby/derby/10.11.1.1/derby-10.11.1.1.jar:/Users/keith/src/qpid-java/broker-plugins/jdbc-provider-bone/target/classes:/Users/keith/.m2/repository/com/jolbox/bonecp/0.7.1.RELEASE/bonecp-0.7.1.RELEASE.jar:/Users/keith/src/qpid-java/broker-plugins/jdbc-store/target/classes:/Users/keith/src/qpid-java/broker-plugins/logging-logback/target/classes:/Users/keith/src/qpid-java/broker-plugins/management-http/target/classes:/Users/keith/.m2/repository/org/apache/geronimo/specs/geronimo-servlet_3.0_spec/1.0/geronimo-servlet_3.0_spec-1.0.jar:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-server/8.1.17.v20150415/jetty-server-8.1.17.v20150415.jar:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-continuation/8.1.17.v20150415/jetty-continuation-8.1.17.v20150415.jar:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-http/8.1.17.v20150415/jetty-http-8.1.17.v20150415.jar:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-servlet/8.1.17.v20150415/jetty-servlet-8.1.17.v20150415.jar:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-security/8.1.17.v20150415/jetty-security-8.1.17.v20150415.jar:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-servlets/8.1.17.v20150415/jetty-servlets-8.1.17.v20150415.jar:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-client/8.1.17.v20150415/jetty-client-8.1.17.v20150415.jar:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-util/8.1.17.v20150415/jetty-util-8.1.17.v20150415.jar:/Users/keith/.m2/repository/org/webjars/bower/dstore/1.1.1/dstore-1.1.1.jar:/Users/keith/.m2/repository/org/webjars/bower/dgrid/1.0.0/dgrid-1.0.0.jar:/Users/keith/src/qpid-java/broker-plugins/memory-store/target/classes:/Users/keith/src/qpid-java/bdbstore/target/classes:/Users/keith/.m2/repository/com/sleepycat/je/5.0.104/je-5.0.104.jar:/Users/keith/.m2/repository/junit/junit/4.11/junit-4.11.jar:/Users/keith/.m2/repository/org/hamcrest/hamcrest-core/1.3/hamcrest-core-1.3.jar:/Users/keith/.m2/repository/org/mockito/mockito-all/1.9.5/mockito-all-1.9.5.jar:/Users/keith/.m2/repository/ch/qos/logback/logback-classic/1.1.3/logback-classic-1.1.3.jar:/Users/keith/.m2/repository/ch/qos/logback/logback-core/1.1.3/logback-core-1.1.3.jar:/Users/keith/.m2/repository/org/slf4j/slf4j-api/1.7.12/slf4j-api-1.7.12.jar" com.intellij.rt.execution.application.AppMain com.intellij.rt.execution.junit.JUnitStarter -ideVersion5 -junit3 org.apache.qpid.server.logging.ConsumerLoggingTest,testSubscriptionSuspend
      17:08:31,399 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
      17:08:31,399 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback-test.xml] at [file:/Users/keith/src/qpid-java/systests/target/classes/logback-test.xml]
      17:08:31,679 |-INFO in ch.qos.logback.classic.joran.action.ContextNameAction - Setting logger context name as [qpid-systests]
      17:08:31,680 |-INFO in ch.qos.logback.core.joran.action.DefinePropertyAction - About to instantiate property definer of type [org.apache.qpid.test.utils.LogbackSocketPortNumberDefiner]
      17:08:31,685 |-INFO in ch.qos.logback.core.joran.action.DefinePropertyAction - Popping property definer for property named [receiverPort] from the object stack
      17:08:31,685 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender]
      17:08:31,688 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [RootSiftAppender]
      17:08:31,714 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.sift.MDCBasedDiscriminator] for [discriminator] property
      17:08:31,725 |-INFO in ch.qos.logback.classic.joran.action.ReceiverAction - About to instantiate receiver of type [ch.qos.logback.classic.net.server.ServerSocketReceiver]
      17:08:31,738 |-INFO in ch.qos.logback.classic.net.server.RemoteAppenderServerRunner@4832eebb - listening on 0.0.0.0:15002
      17:08:31,738 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [qpid.message] to INFO
      17:08:31,738 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.apache.qpid] to DEBUG
      17:08:31,738 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to WARN
      17:08:31,738 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [RootSiftAppender] to Logger[ROOT]
      17:08:31,739 |-INFO in ch.qos.logback.core.joran.action.ShutdownHookAction - About to instantiate shutdown hook of type [ch.qos.logback.core.hook.DelayingShutdownHook]
      17:08:31,740 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
      17:08:31,741 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@12768ace - Registering current configuration as safe fallback point
      SLF4J: The following set of substitute loggers may have been accessed
      SLF4J: during the initialization phase. Logging calls during this
      SLF4J: phase were not honored. However, subsequent logging calls to these
      SLF4J: loggers will work as normally expected.
      SLF4J: See also http://www.slf4j.org/codes.html#substituteLogger
      SLF4J: org.apache.qpid.test.utils.PortHelper
      17:08:31,746 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender]
      17:08:31,748 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE-testrun]
      17:08:31,756 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
      17:08:31,790 |-INFO in ch.qos.logback.core.FileAppender[FILE-testrun] - File property is set to [/Users/keith/src/qpid-java/systests/target/surefire-reports/java-mms.0-10/TEST-testrun.txt]17:08:31,807 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender]
      17:08:31,807 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE-org.apache.qpid.server.logging.ConsumerLoggingTest.testSubscriptionSuspend]
      17:08:31,808 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
      17:08:31,808 |-INFO in ch.qos.logback.core.FileAppender[FILE-org.apache.qpid.server.logging.ConsumerLoggingTest.testSubscriptionSuspend] - File property is set to [/Users/keith/src/qpid-java/systests/target/surefire-reports/java-mms.0-10/TEST-org.apache.qpid.server.logging.ConsumerLoggingTest.testSubscriptionSuspend.txt]
      MESSAGE[Broker] BRK-1006 : Using configuration : /var/folders/tb/k1325lym8xj_730059b69j0h0000gq/T/qpid-work-org.apache.qpid.server.logging.ConsumerLoggingTest.testSubscriptionSuspend-0-1110265283396383920/config.json
      MESSAGE[Broker] BRK-1001 : Startup : Version: 6.2.0-SNAPSHOT Build: Unversioned directory
      MESSAGE[Broker] BRK-1010 : Platform : JVM : Oracle Corporation version: 1.7.0_79-b15 OS : Mac OS X version: 10.12.1 arch: x86_64 cores: 8
      MESSAGE[Broker] BRK-1011 : Maximum Memory : Heap : 1,908,932,608 bytes Direct : 1,908,932,608 bytes
      MESSAGE[Broker] BRK-1017 : Process : PID : 5175
      MESSAGE[Broker] BRK-1002 : Starting : Listening on TCP port 57906
      MESSAGE[Broker] MNG-1001 : Web Management Startup
      MESSAGE[Broker] MNG-1002 : Starting : HTTP : Listening on TCP port 57907
      MESSAGE[Broker] MNG-1004 : Web Management Ready
      MESSAGE[Broker] BRK-1004 : Qpid Broker Ready
      
      java.lang.NullPointerException
      	at org.apache.qpid.client.AMQSession_0_10.isQueueExist(AMQSession_0_10.java:1162)
      	at org.apache.qpid.client.AMQSession_0_10.isQueueExist(AMQSession_0_10.java:1129)
      	at org.apache.qpid.client.AMQSession.resolveAddress(AMQSession.java:624)
      	at org.apache.qpid.client.AMQSession.registerConsumer(AMQSession.java:3080)
      	at org.apache.qpid.client.AMQSession.access$700(AMQSession.java:98)
      	at org.apache.qpid.client.AMQSession$6.execute(AMQSession.java:2143)
      	at org.apache.qpid.client.AMQSession$6.execute(AMQSession.java:2118)
      	at org.apache.qpid.client.AMQConnectionDelegate_0_10.executeRetrySupport(AMQConnectionDelegate_0_10.java:493)
      	at org.apache.qpid.client.AMQConnection.executeRetrySupport(AMQConnection.java:809)
      	at org.apache.qpid.client.failover.FailoverRetrySupport.execute(FailoverRetrySupport.java:90)
      	at org.apache.qpid.client.AMQSession.createConsumerImpl(AMQSession.java:2172)
      	at org.apache.qpid.client.AMQSession.createConsumer(AMQSession.java:1027)
      	at org.apache.qpid.client.AMQConnection.retrieveVirtualHostPropertiesIfNecessary(AMQConnection.java:881)
      	at org.apache.qpid.client.AMQConnection.createSession(AMQConnection.java:868)
      	at org.apache.qpid.client.AMQConnection.createSession(AMQConnection.java:843)
      	at org.apache.qpid.client.AMQConnection.createSession(AMQConnection.java:837)
      	at org.apache.qpid.client.AMQConnection.createSession(AMQConnection.java:91)
      	at org.apache.qpid.server.logging.ConsumerLoggingTest.setUp(ConsumerLoggingTest.java:74)
      	at junit.framework.TestCase.runBare(TestCase.java:139)
      	at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:120)
      	at junit.framework.TestResult$1.protect(TestResult.java:122)
      	at junit.framework.TestResult.runProtected(TestResult.java:142)
      	at junit.framework.TestResult.run(TestResult.java:125)
      	at junit.framework.TestCase.run(TestCase.java:129)
      	at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:156)
      	at junit.framework.TestSuite.runTest(TestSuite.java:255)
      	at junit.framework.TestSuite.run(TestSuite.java:250)
      	at org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:84)
      	at org.junit.runner.JUnitCore.run(JUnitCore.java:160)
      	at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:69)
      	at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:234)
      	at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:74)
      	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.lang.reflect.Method.invoke(Method.java:606)
      	at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144)
      
      17:08:34,051 |-INFO in ch.qos.logback.core.hook.DelayingShutdownHook@f8f516e - Logback context being closed via shutdown hook
      17:08:34,052 |-ERROR in ch.qos.logback.classic.net.server.RemoteAppenderServerRunner@4832eebb - listener: java.net.SocketException: Socket closed
      17:08:34,052 |-INFO in ch.qos.logback.classic.net.server.RemoteAppenderServerRunner@4832eebb - shutting down
      
      Process finished with exit code 255
      

      Attachments

        Activity

          People

            Unassigned Unassigned
            kwall Keith Wall
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: