it looks like it's been happening on our CI server too... :-(
-- Rob
2009/7/13 Rafael Schloming <rafa...@redhat.com>:
> Is anyone else seeing this? I've attached the log.
>
> --Rafael
>
> Testcase: testServerPublishInvalidQueueSuccess took 30.067 sec
> FAILED
> Incorrect exception expected:<class javax.jms.IllegalStateException> but
> was:<class org.apache.qpid.AMQTimeoutException>
> junit.framework.AssertionFailedError: Incorrect exception expected:<class
> javax.jms.IllegalStateException> but was:<class
> org.apache.qpid.AMQTimeoutException>
> at
> org.apache.qpid.server.security.acl.SimpleACLTest.testServerPublishInvalidQueueSuccess(SimpleACLTest.java:624)
> at
> org.apache.qpid.test.utils.QpidTestCase.runBare(QpidTestCase.java:204)
> at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:249)
>
> main 2009-07-13 13:55:36,210 INFO [qpid.test.utils.QpidTestCase] ==========
> start SimpleACLTest.testServerPublishInvalidQueueSuccess ==========
> main 2009-07-13 13:55:36,210 INFO [qpid.test.utils.QpidTestCase] stopping
> broker: vm
> main 2009-07-13 13:55:36,228 INFO [qpid.server.registry.ApplicationRegistry]
> Initialising Application Registry:1
> main 2009-07-13 13:55:36,228 INFO
> [qpid.server.management.NoopManagedObjectRegistry] Management is disabled
> main 2009-07-13 13:55:36,229 WARN [server.security.access.ACLManager] Plugin
> handling security section principal-databases is
> main 2009-07-13 13:55:36,229 WARN [server.security.access.ACLManager] Plugin
> handling security section access is
> main 2009-07-13 13:55:36,229 WARN [server.security.access.ACLManager] Plugin
> handling security section jmx is
> main 2009-07-13 13:55:36,229 INFO
> [security.auth.database.ConfigurationFilePrincipalDatabaseManager]
> Initialising PrincipleDatabase authentication manager
> main 2009-07-13 13:55:36,229 INFO
> [security.auth.database.PlainPasswordFilePrincipalDatabase]
> PlainPasswordFile using file
> /var/lib/ptolemy/projects/qpid/checkout/java/build/etc/passwd
> main 2009-07-13 13:55:36,229 INFO
> [security.auth.database.PlainPasswordFilePrincipalDatabase] Created
> user:guest
> main 2009-07-13 13:55:36,229 INFO
> [security.auth.database.PlainPasswordFilePrincipalDatabase] Created
> user:client
> main 2009-07-13 13:55:36,229 INFO
> [security.auth.database.PlainPasswordFilePrincipalDatabase] Created
> user:server
> main 2009-07-13 13:55:36,230 INFO
> [security.auth.database.PlainPasswordFilePrincipalDatabase] Created
> user:admin
> main 2009-07-13 13:55:36,230 INFO
> [security.auth.database.ConfigurationFilePrincipalDatabaseManager]
> Initialised principal database 'passwordfile' successfully
> main 2009-07-13 13:55:36,230 INFO
> [security.auth.manager.PrincipalDatabaseAuthenticationManager] Initialising
> Default PrincipleDatabase authentication manager.
> main 2009-07-13 13:55:36,230 INFO
> [security.auth.manager.PrincipalDatabaseAuthenticationManager] Initialised
> AMQPLAIN SASL provider successfully
> main 2009-07-13 13:55:36,230 INFO
> [security.auth.manager.PrincipalDatabaseAuthenticationManager] Initialised
> PLAIN SASL provider successfully
> main 2009-07-13 13:55:36,230 INFO
> [security.auth.manager.PrincipalDatabaseAuthenticationManager] Initialised
> CRAM-MD5 SASL provider successfully
> main 2009-07-13 13:55:36,230 INFO
> [security.auth.manager.PrincipalDatabaseAuthenticationManager] Additional
> SASL providers successfully registered.
> main 2009-07-13 13:55:36,230 WARN
> [security.access.management.AMQUserManagementMBean] Access rights contains
> user 'user' but there is no authentication data for that user
> main 2009-07-13 13:55:36,230 DEBUG
> [security.access.management.AMQUserManagementMBean] Setting Access
> Rights:{admin=admin, user=readwrite, guest=readonly}
> main 2009-07-13 13:55:36,232 DEBUG [qpid.server.virtualhost.VirtualHost]
> Loading configuration for virtualhost: development
> main 2009-07-13 13:55:36,234 INFO [qpid.server.virtualhost.VirtualHost]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@1bc8159 with
> routing key 'queue' to
> exchange:org.apache.qpid.server.virtualhost.virtualh...@d03465
> main 2009-07-13 13:55:36,234 DEBUG [qpid.server.exchange.DirectExchange]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@1bc8159 with
> routing key 'queue' to exchange:DirectExchange[amq.direct]
> main 2009-07-13 13:55:36,234 DEBUG [qpid.server.exchange.DirectExchange]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@1bc8159 with
> routing key 'queue' to exchange:DirectExchange[<<default>>]
> main 2009-07-13 13:55:36,235 INFO [qpid.server.virtualhost.VirtualHost]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@11fda7c with
> routing key 'ping' to
> exchange:org.apache.qpid.server.virtualhost.virtualh...@d03465
> main 2009-07-13 13:55:36,235 DEBUG [qpid.server.exchange.DirectExchange]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@11fda7c with
> routing key 'ping' to exchange:DirectExchange[amq.direct]
> main 2009-07-13 13:55:36,235 DEBUG [qpid.server.exchange.DirectExchange]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@11fda7c with
> routing key 'ping' to exchange:DirectExchange[<<default>>]
> main 2009-07-13 13:55:36,235 INFO [qpid.server.store.MemoryMessageStore]
> Using capacity 50000 for hash tables
> main 2009-07-13 13:55:36,236 INFO
> [security.auth.manager.PrincipalDatabaseAuthenticationManager] Initialising
> 'development' PrincipleDatabase authentication manager.
> main 2009-07-13 13:55:36,236 WARN [server.security.access.ACLManager] Plugin
> handling security section principal-databases is
> main 2009-07-13 13:55:36,236 WARN [server.security.access.ACLManager] Plugin
> handling security section access is
> main 2009-07-13 13:55:36,236 WARN [server.security.access.ACLManager] Plugin
> handling security section jmx is
> main 2009-07-13 13:55:36,239 DEBUG [qpid.server.virtualhost.VirtualHost]
> Loading configuration for virtualhost: test
> main 2009-07-13 13:55:36,240 INFO [qpid.server.virtualhost.VirtualHost]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@114ae94 with
> routing key 'queue' to
> exchange:org.apache.qpid.server.virtualhost.virtualh...@d1a022
> main 2009-07-13 13:55:36,240 DEBUG [qpid.server.exchange.DirectExchange]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@114ae94 with
> routing key 'queue' to exchange:DirectExchange[amq.direct]
> main 2009-07-13 13:55:36,241 DEBUG [qpid.server.exchange.DirectExchange]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@114ae94 with
> routing key 'queue' to exchange:DirectExchange[<<default>>]
> main 2009-07-13 13:55:36,242 INFO [qpid.server.virtualhost.VirtualHost]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@682b10 with
> routing key 'ping' to
> exchange:org.apache.qpid.server.virtualhost.virtualh...@d1a022
> main 2009-07-13 13:55:36,242 DEBUG [qpid.server.exchange.DirectExchange]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@682b10 with
> routing key 'ping' to exchange:DirectExchange[amq.direct]
> main 2009-07-13 13:55:36,242 DEBUG [qpid.server.exchange.DirectExchange]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@682b10 with
> routing key 'ping' to exchange:DirectExchange[<<default>>]
> main 2009-07-13 13:55:36,242 INFO [qpid.server.store.MemoryMessageStore]
> Using capacity 50000 for hash tables
> main 2009-07-13 13:55:36,243 INFO
> [security.auth.manager.PrincipalDatabaseAuthenticationManager] Initialising
> 'test' PrincipleDatabase authentication manager.
> main 2009-07-13 13:55:36,243 WARN [server.security.access.ACLManager] Plugin
> handling security section principal-databases is
> main 2009-07-13 13:55:36,243 WARN [server.security.access.ACLManager] Plugin
> handling security section access is
> main 2009-07-13 13:55:36,243 WARN [server.security.access.ACLManager] Plugin
> handling security section jmx is
> main 2009-07-13 13:55:36,244 WARN [server.security.access.ACLManager] Plugin
> handling security section access is
> main 2009-07-13 13:55:36,244 WARN [server.security.access.ACLManager] Plugin
> handling security section access_control_list is
> main 2009-07-13 13:55:36,251 DEBUG [qpid.server.virtualhost.VirtualHost]
> Loading configuration for virtualhost: localhost
> main 2009-07-13 13:55:36,254 INFO [qpid.server.virtualhost.VirtualHost]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@167a256 with
> routing key 'test-ping' to
> exchange:org.apache.qpid.server.virtualhost.virtualh...@d2ee0f
> main 2009-07-13 13:55:36,254 DEBUG [qpid.server.exchange.DirectExchange]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@167a256 with
> routing key 'test-ping' to exchange:DirectExchange[test.direct]
> main 2009-07-13 13:55:36,254 DEBUG [qpid.server.exchange.DirectExchange]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@167a256 with
> routing key 'test-ping' to exchange:DirectExchange[<<default>>]
> main 2009-07-13 13:55:36,255 INFO [qpid.server.virtualhost.VirtualHost]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@b495e with routing
> key 'queue' to
> exchange:org.apache.qpid.server.virtualhost.virtualh...@d2ee0f
> main 2009-07-13 13:55:36,255 DEBUG [qpid.server.exchange.DirectExchange]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@b495e with routing
> key 'queue' to exchange:DirectExchange[amq.direct]
> main 2009-07-13 13:55:36,255 DEBUG [qpid.server.exchange.DirectExchange]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@b495e with routing
> key 'queue' to exchange:DirectExchange[<<default>>]
> main 2009-07-13 13:55:36,257 INFO [qpid.server.virtualhost.VirtualHost]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@fde259 with
> routing key 'test-queue' to
> exchange:org.apache.qpid.server.virtualhost.virtualh...@d2ee0f
> main 2009-07-13 13:55:36,257 DEBUG [qpid.server.exchange.DirectExchange]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@fde259 with
> routing key 'test-queue' to exchange:DirectExchange[test.direct]
> main 2009-07-13 13:55:36,257 DEBUG [qpid.server.exchange.DirectExchange]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@fde259 with
> routing key 'test-queue' to exchange:DirectExchange[<<default>>]
> main 2009-07-13 13:55:36,259 INFO [qpid.server.virtualhost.VirtualHost]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@176578 with
> routing key 'ping' to
> exchange:org.apache.qpid.server.virtualhost.virtualh...@d2ee0f
> main 2009-07-13 13:55:36,259 DEBUG [qpid.server.exchange.DirectExchange]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@176578 with
> routing key 'ping' to exchange:DirectExchange[amq.direct]
> main 2009-07-13 13:55:36,259 DEBUG [qpid.server.exchange.DirectExchange]
> Binding queue:org.apache.qpid.server.queue.simpleamqqu...@176578 with
> routing key 'ping' to exchange:DirectExchange[<<default>>]
> main 2009-07-13 13:55:36,259 INFO [qpid.server.store.MemoryMessageStore]
> Using capacity 50000 for hash tables
> main 2009-07-13 13:55:36,259 INFO
> [security.auth.manager.PrincipalDatabaseAuthenticationManager] Initialising
> 'localhost' PrincipleDatabase authentication manager.
> main 2009-07-13 13:55:36,259 WARN [server.security.access.ACLManager] Plugin
> handling security section principal-databases is
> main 2009-07-13 13:55:36,260 WARN [server.security.access.ACLManager] Plugin
> handling security section access is
> main 2009-07-13 13:55:36,260 WARN [server.security.access.ACLManager] Plugin
> handling security section jmx is
> main 2009-07-13 13:55:36,260 INFO
> [qpid.client.transport.TransportConnection] Creating InVM Qpid.AMQP
> listening on port 1
> main 2009-07-13 13:55:36,260 INFO
> [qpid.client.transport.TransportConnection] Creating Qpid protocol provider:
> org.apache.qpid.server.protocol.AMQPFastProtocolHandler
> main 2009-07-13 13:55:36,260 DEBUG
> [qpid.server.protocol.AMQPFastProtocolHandler] AMQPFastProtocolHandler
> created
> main 2009-07-13 13:55:36,260 INFO
> [qpid.client.transport.TransportConnection] Created VMBroker Instance:1
> main 2009-07-13 13:55:36,260 INFO
> [qpid.client.transport.TransportConnection] Created InVM Qpid.AMQP listening
> on port 1
> main 2009-07-13 13:55:36,261 INFO [apache.qpid.client.AMQConnection]
> Connection:amqp://server:*****...@clientid/test?brokerlist='vm://:1?retries='0''
> main 2009-07-13 13:55:36,261 INFO [qpid.client.state.StateWaiter] New
> StateWaiter :AMQState: id = 1 name: CONNECTION_NOT_STARTED:[AMQState: id = 4
> name: CONNECTION_OPEN, AMQState: id = 6 name: CONNECTION_CLOSED]
> main 2009-07-13 13:55:36,261 INFO
> [qpid.client.transport.VmPipeTransportConnection] Attempting connection to
> vm:1
> main 2009-07-13 13:55:36,261 DEBUG [apache.qpid.pool.PoolingFilter] Init
> called on PoolingFilter AsynchronousReadFilter
> main 2009-07-13 13:55:36,261 DEBUG [apache.qpid.pool.PoolingFilter] Init
> called on PoolingFilter AsynchronousWriteFilter
> main 2009-07-13 13:55:36,261 INFO
> [qpid.server.protocol.AMQPFastProtocolHandler] Protocol session created
> for:anonymous(9171467)
> main 2009-07-13 13:55:36,261 INFO
> [qpid.server.protocol.AMQPFastProtocolHandler] Session opened
> for:anonymous(9171467)
> main 2009-07-13 13:55:36,261 DEBUG [apache.qpid.pool.PoolingFilter] Init
> called on PoolingFilter AsynchronousReadFilter
> main 2009-07-13 13:55:36,261 DEBUG [apache.qpid.pool.PoolingFilter] Init
> called on PoolingFilter AsynchronousWriteFilter
> main 2009-07-13 13:55:36,261 DEBUG [qpid.client.protocol.AMQProtocolHandler]
> Protocol session created for session 29344491
> main 2009-07-13 13:55:36,261 INFO
> [qpid.client.handler.ClientMethodDispatcherImpl] New Method
> Dispatcher:org.apache.qpid.client.protocol.amqprotocolsess...@960369
> main 2009-07-13 13:55:36,261 INFO [qpid.client.state.AMQStateManager]
> Setting
> ProtocolSession:org.apache.qpid.client.protocol.amqprotocolsess...@960369
> main 2009-07-13 13:55:36,261 DEBUG [apache.qpid.framing.AMQDataBlockEncoder]
> Encoded frame byte-buffer is '0x414d515001010009'
> pool-76-thread-4 2009-07-13 13:55:36,261 DEBUG
> [apache.qpid.framing.AMQDataBlockEncoder] Encoded frame byte-buffer is
> '0x0100000000002e000a000a00090000000000000017414d51504c41494e20504c41494e204352414d2d4d443500000005656e5f5553ce'
> pool-76-thread-4 2009-07-13 13:55:36,262 DEBUG
> [qpid.server.protocol.AMQPFastProtocolHandler] Message sent:
> HeapBuffer[pos=0 lim=54 cap=54: 01 00 00 00 00 00 2E 00 0A 00 0A 00 09 00 00
> 00 00 00 00 00 17 41 4D 51 50 4C 41 49 4E 20 50 4C 41 49 4E 20 43 52 41 4D
> 2D 4D 44 35 00 00 00 05 65 6E 5F 55 53 CE]
> pool-76-thread-4 2009-07-13 13:55:36,262 DEBUG
> [qpid.server.protocol.AMQPFastProtocolHandler] Message sent: Frame
> channelId: 0, bodyFrame: [ConnectionStartBodyImpl: versionMajor=0,
> versionMinor=9, serverProperties=null, mechanisms...@d854d8,
> locales...@aa5123]
> pool-76-thread-4 2009-07-13 13:55:36,262 INFO [qpid.protocol] RECV:
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891] Frame
> channelId: 0, bodyFrame: [ConnectionStartBodyImpl: versionMajor=0,
> versionMinor=9, serverProperties=null, mechanisms...@4578e0,
> locales...@102f5c2]
> pool-76-thread-4 2009-07-13 13:55:36,262 DEBUG
> [qpid.client.protocol.AMQProtocolHandler] (28641425)Method frame received:
> [ConnectionStartBodyImpl: versionMajor=0, versionMinor=9,
> serverProperties=null, mechanisms...@4578e0, locales...@102f5c2]
> pool-76-thread-4 2009-07-13 13:55:36,262 DEBUG
> [qpid.client.handler.ConnectionStartMethodHandler] public void
> methodReceived(AMQStateManager stateManager, AMQProtocolSession
> protocolSession, AMQMethodEvent evt): called
> pool-76-thread-4 2009-07-13 13:55:36,262 INFO
> [qpid.client.handler.ClientMethodDispatcherImpl] New Method
> Dispatcher:org.apache.qpid.client.protocol.amqprotocolsess...@960369
> pool-76-thread-4 2009-07-13 13:55:36,262 DEBUG
> [qpid.client.handler.ConnectionStartMethodHandler] mechanism = CRAM-MD5
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [qpid.client.state.AMQStateManager] State changing to AMQState: id = 2 name:
> CONNECTION_NOT_TUNED from old state AMQState: id = 1 name:
> CONNECTION_NOT_STARTED
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [qpid.client.state.AMQStateManager] Notififying State change to 1 :
> [org.apache.qpid.client.state.statewai...@14e8dd]
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [apache.qpid.framing.FieldTable] FieldTable::writeToBuffer: Writing encoded
> length of 180...
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [apache.qpid.framing.FieldTable] {instance=[LONG_STRING: clientid],
> product=[LONG_STRING: qpid], version=[LONG_STRING: 0.5],
> platform=[LONG_STRING: Java(TM) SE Runtime Environment, 1.6.0_13-b03, Sun
> Microsystems Inc., i386, Linux, 2.6.18-128.1.14.el5, unknown]}
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [apache.qpid.framing.FieldTable] Writing Property:instance Type:LONG_STRING
> Value:clientid
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [apache.qpid.framing.FieldTable] Buffer Position:15 Remaining:200
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [apache.qpid.framing.FieldTable] Writing Property:product Type:LONG_STRING
> Value:qpid
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [apache.qpid.framing.FieldTable] Buffer Position:37 Remaining:178
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [apache.qpid.framing.FieldTable] Writing Property:version Type:LONG_STRING
> Value:0.5
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [apache.qpid.framing.FieldTable] Buffer Position:54 Remaining:161
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [apache.qpid.framing.FieldTable] Writing Property:platform Type:LONG_STRING
> Value:Java(TM) SE Runtime Environment, 1.6.0_13-b03, Sun Microsystems Inc.,
> i386, Linux, 2.6.18-128.1.14.el5, unknown
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [apache.qpid.framing.FieldTable] Buffer Position:70 Remaining:145
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [apache.qpid.framing.AMQDataBlockEncoder] Encoded frame byte-buffer is
> '0x010000000000cf000a000b000000b408696e7374616e63655300000008636c69656e7469640770726f647563745300000004717069640776657273696f6e5300000003302e3508706c6174666f726d530000006f4a61766128544d292053452052756e74696d6520456e7669726f6e6d656e742c20312e362e305f31332d6230332c2053756e204d6963726f73797374656d7320496e632e2c20693338362c204c696e75782c20322e362e31382d3132382e312e31342e656c352c20756e6b6e6f776e084352414d2d4d44350000000005656e5f5553ce'
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG [qpid.protocol] SEND:
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891] Frame
> channelId: 0, bodyFrame: [ConnectionStartOkBodyImpl:
> clientProperties={instance=[LONG_STRING: clientid], product=[LONG_STRING:
> qpid], version=[LONG_STRING: 0.5], platform=[LONG_STRING: Java(TM) SE
> Runtime Environment, 1.6.0_13-b03, Sun Microsystems Inc., i386, Linux,
> 2.6.18-128.1.14.el5, unknown]}, mechanism=CRAM-MD5, response=null,
> locale=en_US]
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [apache.qpid.framing.FieldTable] FieldTable::PropFieldTable(buffer,180):
> Read type 'LONG_STRING', key 'instance', value 'clientid'
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [apache.qpid.framing.FieldTable] FieldTable::PropFieldTable(buffer,180):
> Read type 'LONG_STRING', key 'product', value 'qpid'
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [apache.qpid.framing.FieldTable] FieldTable::PropFieldTable(buffer,180):
> Read type 'LONG_STRING', key 'version', value '0.5'
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [apache.qpid.framing.FieldTable] FieldTable::PropFieldTable(buffer,180):
> Read type 'LONG_STRING', key 'platform', value 'Java(TM) SE Runtime
> Environment, 1.6.0_13-b03, Sun Microsystems Inc., i386, Linux,
> 2.6.18-128.1.14.el5, unknown'
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [apache.qpid.framing.FieldTable] FieldTable::FieldTable(buffer,180): Done.
> pool-76-thread-4 2009-07-13 13:55:36,263 DEBUG
> [qpid.server.protocol.AMQProtocolSession] Frame Received: Frame channelId:
> 0, bodyFrame: [ConnectionStartOkBodyImpl:
> clientProperties={instance=[LONG_STRING: clientid], product=[LONG_STRING:
> qpid], version=[LONG_STRING: 0.5], platform=[LONG_STRING: Java(TM) SE
> Runtime Environment, 1.6.0_13-b03, Sun Microsystems Inc., i386, Linux,
> 2.6.18-128.1.14.el5, unknown]}, mechanism=CRAM-MD5, response=null,
> locale=en_US]
> pool-76-thread-4 2009-07-13 13:55:36,263 INFO
> [qpid.server.handler.ConnectionStartOkMethodHandler] SASL Mechanism
> selected: CRAM-MD5
> pool-76-thread-4 2009-07-13 13:55:36,263 INFO
> [qpid.server.handler.ConnectionStartOkMethodHandler] Locale selected: en_US
> pool-76-thread-4 2009-07-13 13:55:36,264 DEBUG
> [qpid.server.state.AMQStateManager] State changing to CONNECTION_NOT_AUTH
> from old state CONNECTION_NOT_STARTED
> pool-76-thread-4 2009-07-13 13:55:36,264 DEBUG
> [apache.qpid.framing.AMQDataBlockEncoder] Encoded frame byte-buffer is
> '0x01000000000034000a00140000002c3c323335313234343331373932393535373837312e3132343735303737333632363440766d706970653a313ece'
> pool-76-thread-4 2009-07-13 13:55:36,264 DEBUG
> [qpid.server.protocol.AMQPFastProtocolHandler] Message sent:
> HeapBuffer[pos=0 lim=60 cap=60: 01 00 00 00 00 00 34 00 0A 00 14 00 00 00 2C
> 3C 32 33 35 31 32 34 34 33 31 37 39 32 39 35 35 37 38 37 31 2E 31 32 34 37
> 35 30 37 37 33 36 32 36 34 40 76 6D 70 69 70 65 3A 31 3E CE]
> pool-76-thread-4 2009-07-13 13:55:36,264 DEBUG
> [qpid.server.protocol.AMQPFastProtocolHandler] Message sent: Frame
> channelId: 0, bodyFrame: [ConnectionSecureBodyImpl: challenge...@c444cf]
> pool-76-thread-4 2009-07-13 13:55:36,264 INFO [qpid.protocol] RECV:
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891] Frame
> channelId: 0, bodyFrame: [ConnectionSecureBodyImpl: challenge...@1819341]
> pool-76-thread-4 2009-07-13 13:55:36,264 DEBUG
> [qpid.client.protocol.AMQProtocolHandler] (28641425)Method frame received:
> [ConnectionSecureBodyImpl: challenge...@1819341]
> pool-76-thread-4 2009-07-13 13:55:36,264 DEBUG
> [apache.qpid.framing.AMQDataBlockEncoder] Encoded frame byte-buffer is
> '0x0100000000002f000a001500000027736572766572203630393534623366373839346534643066643765646232393437393239663938ce'
> pool-76-thread-4 2009-07-13 13:55:36,264 DEBUG [qpid.protocol] SEND:
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891] Frame
> channelId: 0, bodyFrame: [ConnectionSecureOkBodyImpl: response...@1ea9b6e]
> pool-76-thread-4 2009-07-13 13:55:36,264 DEBUG
> [qpid.server.protocol.AMQProtocolSession] Frame Received: Frame channelId:
> 0, bodyFrame: [ConnectionSecureOkBodyImpl: response...@1828b22]
> pool-76-thread-4 2009-07-13 13:55:36,264 INFO
> [qpid.server.handler.ConnectionSecureOkMethodHandler] Connected as: server
> pool-76-thread-4 2009-07-13 13:55:36,264 DEBUG
> [qpid.server.state.AMQStateManager] State changing to CONNECTION_NOT_TUNED
> from old state CONNECTION_NOT_AUTH
> pool-76-thread-4 2009-07-13 13:55:36,265 INFO
> [qpid.server.handler.ConnectionStartOkMethodHandler] Framesize set to 65535
> pool-76-thread-4 2009-07-13 13:55:36,265 DEBUG
> [apache.qpid.framing.AMQDataBlockEncoder] Encoded frame byte-buffer is
> '0x0100000000000c000a001effff0000ffff0000ce'
> pool-76-thread-4 2009-07-13 13:55:36,265 DEBUG
> [qpid.server.protocol.AMQPFastProtocolHandler] Message sent:
> HeapBuffer[pos=0 lim=20 cap=20: 01 00 00 00 00 00 0C 00 0A 00 1E FF FF 00 00
> FF FF 00 00 CE]
> pool-76-thread-4 2009-07-13 13:55:36,265 DEBUG
> [qpid.server.protocol.AMQPFastProtocolHandler] Message sent: Frame
> channelId: 0, bodyFrame: [ConnectionTuneBodyImpl: channelMax=65535,
> frameMax=65535, heartbeat=0]
> pool-76-thread-4 2009-07-13 13:55:36,265 INFO [qpid.protocol] RECV:
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891] Frame
> channelId: 0, bodyFrame: [ConnectionTuneBodyImpl: channelMax=65535,
> frameMax=65535, heartbeat=0]
> pool-76-thread-4 2009-07-13 13:55:36,265 DEBUG
> [qpid.client.protocol.AMQProtocolHandler] (28641425)Method frame received:
> [ConnectionTuneBodyImpl: channelMax=65535, frameMax=65535, heartbeat=0]
> pool-76-thread-4 2009-07-13 13:55:36,265 DEBUG
> [qpid.client.handler.ConnectionTuneMethodHandler] ConnectionTune frame
> received
> pool-76-thread-4 2009-07-13 13:55:36,265 DEBUG
> [qpid.client.state.AMQStateManager] State changing to AMQState: id = 3 name:
> CONNECTION_NOT_OPENED from old state AMQState: id = 2 name:
> CONNECTION_NOT_TUNED
> pool-76-thread-4 2009-07-13 13:55:36,265 DEBUG
> [qpid.client.state.AMQStateManager] Notififying State change to 1 :
> [org.apache.qpid.client.state.statewai...@14e8dd]
> pool-76-thread-4 2009-07-13 13:55:36,265 DEBUG
> [apache.qpid.framing.AMQDataBlockEncoder] Encoded frame byte-buffer is
> '0x0100000000000c000a001fffff0000ffff0000ce'
> pool-76-thread-4 2009-07-13 13:55:36,265 DEBUG [qpid.protocol] SEND:
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891] Frame
> channelId: 0, bodyFrame: [ConnectionTuneOkBodyImpl: channelMax=65535,
> frameMax=65535, heartbeat=0]
> pool-76-thread-4 2009-07-13 13:55:36,265 DEBUG
> [apache.qpid.framing.AMQDataBlockEncoder] Encoded frame byte-buffer is
> '0x0100000000000c000a0028052f746573740001ce'
> pool-76-thread-4 2009-07-13 13:55:36,265 DEBUG [qpid.protocol] SEND:
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891] Frame
> channelId: 0, bodyFrame: [ConnectionOpenBodyImpl: virtualHost=/test,
> capabilities=null, insist=true]
> pool-76-thread-4 2009-07-13 13:55:36,265 DEBUG
> [qpid.server.protocol.AMQProtocolSession] Frame Received: Frame channelId:
> 0, bodyFrame: [ConnectionTuneOkBodyImpl: channelMax=65535, frameMax=65535,
> heartbeat=0]
> pool-76-thread-4 2009-07-13 13:55:36,265 DEBUG
> [qpid.server.handler.ConnectionTuneOkMethodHandler]
> [ConnectionTuneOkBodyImpl: channelMax=65535, frameMax=65535, heartbeat=0]
> pool-76-thread-4 2009-07-13 13:55:36,265 DEBUG
> [qpid.server.state.AMQStateManager] State changing to CONNECTION_NOT_OPENED
> from old state CONNECTION_NOT_TUNED
> pool-76-thread-4 2009-07-13 13:55:36,265 DEBUG
> [qpid.server.protocol.AMQProtocolSession] Frame Received: Frame channelId:
> 0, bodyFrame: [ConnectionOpenBodyImpl: virtualHost=/test, capabilities=null,
> insist=true]
> pool-76-thread-4 2009-07-13 13:55:36,266 DEBUG
> [qpid.server.state.AMQStateManager] State changing to CONNECTION_OPEN from
> old state CONNECTION_NOT_OPENED
> pool-76-thread-4 2009-07-13 13:55:36,266 DEBUG
> [apache.qpid.framing.AMQDataBlockEncoder] Encoded frame byte-buffer is
> '0x0100000000000a000a0029052f74657374ce'
> pool-76-thread-4 2009-07-13 13:55:36,266 DEBUG
> [qpid.server.protocol.AMQPFastProtocolHandler] Message sent:
> HeapBuffer[pos=0 lim=18 cap=18: 01 00 00 00 00 00 0A 00 0A 00 29 05 2F 74 65
> 73 74 CE]
> pool-76-thread-4 2009-07-13 13:55:36,266 DEBUG
> [qpid.server.protocol.AMQPFastProtocolHandler] Message sent: Frame
> channelId: 0, bodyFrame: [ConnectionOpenOkBodyImpl: knownHosts=/test]
> pool-76-thread-4 2009-07-13 13:55:36,266 INFO [qpid.protocol] RECV:
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891] Frame
> channelId: 0, bodyFrame: [ConnectionOpenOkBodyImpl: knownHosts=/test]
> pool-76-thread-4 2009-07-13 13:55:36,266 DEBUG
> [qpid.client.protocol.AMQProtocolHandler] (28641425)Method frame received:
> [ConnectionOpenOkBodyImpl: knownHosts=/test]
> pool-76-thread-4 2009-07-13 13:55:36,266 DEBUG
> [qpid.client.state.AMQStateManager] State changing to AMQState: id = 4 name:
> CONNECTION_OPEN from old state AMQState: id = 3 name: CONNECTION_NOT_OPENED
> pool-76-thread-4 2009-07-13 13:55:36,266 DEBUG
> [qpid.client.state.AMQStateManager] Notififying State change to 1 :
> [org.apache.qpid.client.state.statewai...@14e8dd]
> main 2009-07-13 13:55:36,266 DEBUG [qpid.protocol] SEND:
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891] AMQP1109
> main 2009-07-13 13:55:36,266 DEBUG [apache.qpid.client.AMQConnection] Are we
> connected:true
> main 2009-07-13 13:55:36,266 DEBUG
> [apache.qpid.client.AMQConnectionDelegate_8_0] Write channel open frame for
> channel id 1
> main 2009-07-13 13:55:36,267 DEBUG [apache.qpid.framing.AMQDataBlockEncoder]
> Encoded frame byte-buffer is '0x010001000000050014000a00ce'
> pool-76-thread-3 2009-07-13 13:55:36,267 DEBUG
> [qpid.server.protocol.AMQProtocolSession] Frame Received: Frame channelId:
> 1, bodyFrame: [ChannelOpenBodyImpl: outOfBand=null]
> pool-76-thread-3 2009-07-13 13:55:36,267 DEBUG
> [apache.qpid.framing.AMQDataBlockEncoder] Encoded frame byte-buffer is
> '0x010001000000180014000b000000100d7749ba017143e5b2899189884e6a9ece'
> pool-76-thread-3 2009-07-13 13:55:36,267 DEBUG
> [qpid.server.protocol.AMQPFastProtocolHandler] Message sent:
> HeapBuffer[pos=0 lim=32 cap=32: 01 00 01 00 00 00 18 00 14 00 0B 00 00 00 10
> 0D 77 49 BA 01 71 43 E5 B2 89 91 89 88 4E 6A 9E CE]
> pool-76-thread-3 2009-07-13 13:55:36,267 DEBUG
> [qpid.server.protocol.AMQPFastProtocolHandler] Message sent: Frame
> channelId: 1, bodyFrame: [ChannelOpenOkBodyImpl: channelid...@7beded]
> pool-76-thread-3 2009-07-13 13:55:36,267 INFO [qpid.protocol] RECV:
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891] Frame
> channelId: 1, bodyFrame: [ChannelOpenOkBodyImpl: channelid...@4163e1]
> pool-76-thread-3 2009-07-13 13:55:36,267 DEBUG
> [qpid.client.protocol.AMQProtocolHandler] (28641425)Method frame received:
> [ChannelOpenOkBodyImpl: channelid...@4163e1]
> main 2009-07-13 13:55:36,267 DEBUG [qpid.protocol] SEND:
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891] Frame
> channelId: 1, bodyFrame: [ChannelOpenBodyImpl: outOfBand=null]
> main 2009-07-13 13:55:36,267 DEBUG [apache.qpid.framing.AMQDataBlockEncoder]
> Encoded frame byte-buffer is '0x0100010000000b003c000a0000000003e800ce'
> pool-76-thread-2 2009-07-13 13:55:36,267 DEBUG
> [qpid.server.protocol.AMQProtocolSession] Frame Received: Frame channelId:
> 1, bodyFrame: [BasicQosBodyImpl: prefetchSize=0, prefetchCount=1000,
> global=false]
> pool-76-thread-2 2009-07-13 13:55:36,267 DEBUG
> [apache.qpid.framing.AMQDataBlockEncoder] Encoded frame byte-buffer is
> '0x01000100000004003c000bce'
> pool-76-thread-2 2009-07-13 13:55:36,267 DEBUG
> [qpid.server.protocol.AMQPFastProtocolHandler] Message sent:
> HeapBuffer[pos=0 lim=12 cap=12: 01 00 01 00 00 00 04 00 3C 00 0B CE]
> pool-76-thread-2 2009-07-13 13:55:36,267 DEBUG
> [qpid.server.protocol.AMQPFastProtocolHandler] Message sent: Frame
> channelId: 1, bodyFrame: [BasicQosOkBodyImpl: ]
> pool-76-thread-2 2009-07-13 13:55:36,267 INFO [qpid.protocol] RECV:
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891] Frame
> channelId: 1, bodyFrame: [BasicQosOkBodyImpl: ]
> pool-76-thread-2 2009-07-13 13:55:36,267 DEBUG
> [qpid.client.protocol.AMQProtocolHandler] (28641425)Method frame received:
> [BasicQosOkBodyImpl: ]
> main 2009-07-13 13:55:36,267 DEBUG [qpid.protocol] SEND:
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891] Frame
> channelId: 1, bodyFrame: [BasicQosBodyImpl: prefetchSize=0,
> prefetchCount=1000, global=false]
> main 2009-07-13 13:55:36,268 INFO
> [apache.qpid.client.BasicMessageProducer_0_8] MessageProducer
> org.apache.qpid.client.basicmessageproducer_...@1045431 using publish mode :
> ASYNC_PUBLISH_ALL
> main 2009-07-13 13:55:36,268 DEBUG [apache.qpid.framing.AMQDataBlockEncoder]
> Encoded frame byte-buffer is
> '0x0100010000001d0028000a00000a616d712e646972656374066469726563741000000000ce'
> pool-76-thread-2 2009-07-13 13:55:36,268 DEBUG
> [qpid.server.protocol.AMQProtocolSession] Frame Received: Frame channelId:
> 1, bodyFrame: [ExchangeDeclareBodyImpl: ticket=0, exchange=amq.direct,
> type=direct, passive=false, durable=false, autoDelete=false, internal=false,
> nowait=true, arguments=null]
> pool-76-thread-2 2009-07-13 13:55:36,268 DEBUG
> [qpid.server.handler.ExchangeDeclareHandler] Request to declare exchange of
> type direct with name amq.direct
> main 2009-07-13 13:55:36,268 DEBUG [qpid.protocol] SEND:
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891] Frame
> channelId: 1, bodyFrame: [ExchangeDeclareBodyImpl: ticket=0,
> exchange=amq.direct, type=direct, passive=false, durable=false,
> autoDelete=false, internal=false, nowait=true, arguments=null]
> main 2009-07-13 13:55:36,268 DEBUG
> [apache.qpid.client.BasicMessageProducer_0_8] Sending content body frames to
> direct://amq.direct/Invalid/Invalid?routingkey='Invalid'&durable='true'
> main 2009-07-13 13:55:36,268 DEBUG
> [apache.qpid.client.BasicMessageProducer_0_8] Sending content header frame
> to direct://amq.direct/Invalid/Invalid?routingkey='Invalid'&durable='true'
> main 2009-07-13 13:55:36,268 DEBUG [apache.qpid.framing.FieldTable]
> FieldTable::writeToBuffer: Writing encoded length of 0...
> main 2009-07-13 13:55:36,268 DEBUG [apache.qpid.framing.FieldTable] {}
> main 2009-07-13 13:55:36,268 DEBUG [apache.qpid.framing.AMQDataBlockEncoder]
> Encoded frame byte-buffer is
> '0x0100010000001a003c002800000a616d712e64697265637407496e76616c696400ce0200010000005d003c00000000000000000004f9d00a746578742f706c61696e055554462d38000000000100002749443a64326561356464362d333333622d333337612d393161662d30343933633339653063393000000122754166cc06736572766572ce0300010000000474657374ce'
> main 2009-07-13 13:55:36,268 DEBUG [qpid.protocol] SEND:
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891]
> org.apache.qpid.framing.CompositeAMQDataBlock{ 0=[Frame channelId: 1,
> bodyFrame: [BasicPublishBodyImpl: ticket=0, exchange=amq.direct,
> routingKey=Invalid, mandatory=false, immediate=false]] 1=[Frame channelId:
> 1, bodyFrame: org.apache.qpid.framing.contentheaderb...@1336cdf] 2=[Frame
> channelId: 1, bodyFrame: org.apache.qpid.framing.contentb...@130d02c]}
> pool-76-thread-4 2009-07-13 13:55:36,268 DEBUG
> [apache.qpid.framing.BasicContentHeaderProperties] Property flags: 63952
> pool-76-thread-4 2009-07-13 13:55:36,268 DEBUG
> [qpid.server.protocol.AMQProtocolSession] Frame Received: Frame channelId:
> 1, bodyFrame: [BasicPublishBodyImpl: ticket=0, exchange=amq.direct,
> routingKey=Invalid, mandatory=false, immediate=false]
> pool-76-thread-4 2009-07-13 13:55:36,268 DEBUG
> [qpid.server.handler.BasicPublishMethodHandler] Publish received on channel
> 1
> pool-76-thread-4 2009-07-13 13:55:36,269 INFO
> [qpid.server.protocol.AMQProtocolSession] Closing connection due to:
> Permission denied [error code 403: access refused]
> pool-76-thread-4 2009-07-13 13:55:36,269 INFO
> [apache.qpid.server.AMQChannel] No consumers to unsubscribe on channel
> [anonymous(9171467)(server):1]
> pool-76-thread-4 2009-07-13 13:55:36,269 DEBUG
> [qpid.server.state.AMQStateManager] State changing to CONNECTION_CLOSING
> from old state CONNECTION_OPEN
> pool-76-thread-4 2009-07-13 13:55:36,269 DEBUG
> [qpid.server.protocol.AMQProtocolSession] Frame Received: Frame channelId:
> 1, bodyFrame: org.apache.qpid.framing.contentheaderb...@1b30ac0
> pool-76-thread-4 2009-07-13 13:55:36,269 INFO
> [qpid.server.protocol.AMQProtocolSession] Channel[1] awaiting closure.
> Should close socket as client did not close-ok :Frame channelId: 1,
> bodyFrame: org.apache.qpid.framing.contentheaderb...@1b30ac0
> pool-76-thread-4 2009-07-13 13:55:36,269 DEBUG
> [qpid.server.protocol.AMQProtocolSession] Waiting for last write to join.
> pool-76-thread-3 2009-07-13 13:55:36,269 DEBUG
> [apache.qpid.framing.AMQDataBlockEncoder] Encoded frame byte-buffer is
> '0x0100010000003d000a00320193325065726d697373696f6e2064656e696564205b6572726f7220636f6465203430333a2061636365737320726566757365645d003c0028ce'
> pool-76-thread-3 2009-07-13 13:55:36,269 DEBUG
> [qpid.server.protocol.AMQPFastProtocolHandler] Message sent:
> HeapBuffer[pos=0 lim=69 cap=69: 01 00 01 00 00 00 3D 00 0A 00 32 01 93 32 50
> 65 72 6D 69 73 73 69 6F 6E 20 64 65 6E 69 65 64 20 5B 65 72 72 6F 72 20 63
> 6F 64 65 20 34 30 33 3A 20 61 63 63 65 73 73 20 72 65 66 75 73 65 64 5D 00
> 3C 00 28 CE]
> pool-76-thread-3 2009-07-13 13:55:36,269 DEBUG
> [qpid.server.protocol.AMQPFastProtocolHandler] Message sent: Frame
> channelId: 1, bodyFrame: [ConnectionCloseBodyImpl: replyCode=403,
> replyText=Permission denied [error code 403: access refused], classId=60,
> methodId=40]
> pool-76-thread-3 2009-07-13 13:55:36,269 INFO [qpid.protocol] RECV:
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891] Frame
> channelId: 1, bodyFrame: [ConnectionCloseBodyImpl: replyCode=403,
> replyText=Permission denied [error code 403: access refused], classId=60,
> methodId=40]
> pool-76-thread-3 2009-07-13 13:55:36,269 DEBUG
> [qpid.client.protocol.AMQProtocolHandler] (28641425)Method frame received:
> [ConnectionCloseBodyImpl: replyCode=403, replyText=Permission denied [error
> code 403: access refused], classId=60, methodId=40]
> pool-76-thread-3 2009-07-13 13:55:36,269 INFO
> [qpid.client.handler.ConnectionCloseMethodHandler] ConnectionClose frame
> received
> pool-76-thread-3 2009-07-13 13:55:36,269 DEBUG
> [apache.qpid.framing.AMQDataBlockEncoder] Encoded frame byte-buffer is
> '0x01000000000004000a0033ce'
> pool-76-thread-3 2009-07-13 13:55:36,269 DEBUG [qpid.protocol] SEND:
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891] Frame
> channelId: 0, bodyFrame: [ConnectionCloseOkBodyImpl: ]
> pool-76-thread-3 2009-07-13 13:55:36,269 INFO
> [qpid.client.handler.ConnectionCloseMethodHandler] Error :403: access
> refused:pool-76-thread-3
> pool-76-thread-3 2009-07-13 13:55:36,269 ERROR
> [qpid.client.state.AMQStateManager] No Waiters for error saving as last
> error:Permission denied [error code 403: access refused] [error code 403:
> access refused]
> pool-76-thread-3 2009-07-13 13:55:36,269 DEBUG
> [qpid.client.protocol.AMQProtocolSession] Waiting for last write to join.
> pool-76-thread-3 2009-07-13 13:55:36,269 DEBUG
> [qpid.client.protocol.AMQProtocolSession] Closing protocol session
> pool-76-thread-4 2009-07-13 13:55:36,270 DEBUG
> [qpid.server.protocol.AMQProtocolSession] REALLY Closing protocol
> session:(VM_PIPE, R: anonymous(9171467), L: vm:1, S: vm:1)
> pool-76-thread-4 2009-07-13 13:55:36,270 DEBUG
> [qpid.server.state.AMQStateManager] State changing to CONNECTION_CLOSED from
> old state CONNECTION_CLOSING
> pool-76-thread-4 2009-07-13 13:55:36,270 DEBUG
> [qpid.server.protocol.AMQProtocolSession] Frame Received: Frame channelId:
> 1, bodyFrame: org.apache.qpid.framing.contentb...@ffdb99
> pool-76-thread-4 2009-07-13 13:55:36,270 INFO
> [qpid.server.protocol.AMQProtocolSession] Channel[1] awaiting closure.
> Should close socket as client did not close-ok :Frame channelId: 1,
> bodyFrame: org.apache.qpid.framing.contentb...@ffdb99
> pool-76-thread-4 2009-07-13 13:55:36,270 DEBUG
> [qpid.server.protocol.AMQProtocolSession] Waiting for last write to join.
> pool-76-thread-4 2009-07-13 13:55:36,270 DEBUG
> [qpid.server.protocol.AMQProtocolSession] REALLY Closing protocol
> session:(VM_PIPE, R: anonymous(9171467), L: vm:1, S: vm:1)
> pool-76-thread-4 2009-07-13 13:55:36,270 DEBUG
> [qpid.server.state.AMQStateManager] State changing to CONNECTION_CLOSED from
> old state CONNECTION_CLOSED
> pool-76-thread-4 2009-07-13 13:55:36,270 INFO
> [qpid.server.protocol.AMQPFastProtocolHandler] Protocol Session closed
> for:anonymous(9171467)
> pool-76-thread-4 2009-07-13 13:55:36,270 DEBUG
> [apache.qpid.pool.PoolingFilter] Destroy called on PoolingFilter
> AsynchronousWriteFilter
> pool-76-thread-4 2009-07-13 13:55:36,270 DEBUG
> [apache.qpid.pool.PoolingFilter] Destroy called on PoolingFilter
> AsynchronousReadFilter
> pool-76-thread-3 2009-07-13 13:55:36,270 DEBUG
> [qpid.client.state.AMQStateManager] State changing to AMQState: id = 6 name:
> CONNECTION_CLOSED from old state AMQState: id = 4 name: CONNECTION_OPEN
> pool-76-thread-3 2009-07-13 13:55:36,270 DEBUG
> [qpid.client.state.AMQStateManager] Notififying State change to 0 : []
> pool-76-thread-2 2009-07-13 13:55:36,270 DEBUG
> [qpid.client.protocol.AMQProtocolHandler] Session closed called with
> failover state currently FailoverState: NOT STARTED
> pool-76-thread-2 2009-07-13 13:55:36,270 DEBUG
> [apache.qpid.jms.FailoverPolicy] All failover methods exhausted
> pool-76-thread-2 2009-07-13 13:55:36,270 DEBUG
> [qpid.client.protocol.AMQProtocolHandler] Failover not allowed by policy.
> pool-76-thread-2 2009-07-13 13:55:36,270 DEBUG
> [apache.qpid.jms.FailoverPolicy] All failover methods exhausted
> pool-76-thread-2 2009-07-13 13:55:36,270 DEBUG
> [qpid.client.protocol.AMQProtocolHandler] Failover Policy:
> Failover not allowed
> Failover policy methods
>>Single Server:
> Max Retries:0
> Current Retry:0
> vm://:1?retries='0'
>
> pool-76-thread-2 2009-07-13 13:55:36,270 DEBUG
> [qpid.client.protocol.AMQProtocolHandler] sessionClose() not allowed to
> failover
> pool-76-thread-2 2009-07-13 13:55:36,271 DEBUG
> [apache.qpid.client.AMQConnection] exceptionReceived done
> by:pool-76-thread-2
> org.apache.qpid.AMQDisconnectedException: Server closed connection and
> reconnection not permitted.
> at
> org.apache.qpid.client.protocol.AMQProtocolHandler.sessionClosed(AMQProtocolHandler.java:329)
> at
> org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.sessionClosed(AbstractIoFilterChain.java:677)
> at
> org.apache.mina.common.support.AbstractIoFilterChain.callNextSessionClosed(AbstractIoFilterChain.java:321)
> at
> org.apache.mina.common.support.AbstractIoFilterChain.access$900(AbstractIoFilterChain.java:54)
> at
> org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.sessionClosed(AbstractIoFilterChain.java:781)
> at
> org.apache.mina.filter.codec.ProtocolCodecFilter.sessionClosed(ProtocolCodecFilter.java:280)
> at
> org.apache.mina.common.support.AbstractIoFilterChain.callNextSessionClosed(AbstractIoFilterChain.java:321)
> at
> org.apache.mina.common.support.AbstractIoFilterChain.access$900(AbstractIoFilterChain.java:54)
> at
> org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.sessionClosed(AbstractIoFilterChain.java:781)
> at org.apache.qpid.pool.Event$CloseEvent.process(Event.java:147)
> at org.apache.qpid.pool.Job.processAll(Job.java:114)
> at org.apache.qpid.pool.Job.run(Job.java:153)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> at java.lang.Thread.run(Thread.java:619)
> pool-76-thread-2 2009-07-13 13:55:36,271 INFO
> [apache.qpid.client.AMQConnection] StateManager had an exception for us to
> use a cause of our Disconnected Exception
> pool-76-thread-2 2009-07-13 13:55:36,271 ERROR
> [apache.qpid.client.AMQConnection] Throwable Received but no listener set:
> Permission denied [error code 403: access refused] [error code 403: access
> refused]
> pool-76-thread-2 2009-07-13 13:55:36,271 INFO
> [apache.qpid.client.AMQConnection] Closing AMQConnection due to :Permission
> denied [error code 403: access refused] [error code 403: access refused]
> IoReceiver - /127.0.0.1:55632 2009-07-13 13:56:05,996 DEBUG
> [apache.qpid.transport.Connection] connection closed: conn:147358f
> IoReceiver - /127.0.0.1:55633 2009-07-13 13:56:06,221 DEBUG
> [apache.qpid.transport.Connection] connection closed: conn:1f08ed8
> pool-76-thread-2 2009-07-13 13:56:06,273 DEBUG
> [qpid.client.protocol.AMQProtocolHandler] Protocol Session
> [org.apache.qpid.client.protocol.amqprotocolhand...@1b50891] closed
> pool-76-thread-2 2009-07-13 13:56:06,273 DEBUG
> [apache.qpid.pool.PoolingFilter] Destroy called on PoolingFilter
> AsynchronousWriteFilter
> pool-76-thread-2 2009-07-13 13:56:06,273 DEBUG
> [apache.qpid.pool.PoolingFilter] Destroy called on PoolingFilter
> AsynchronousReadFilter
> main 2009-07-13 13:56:06,274 INFO
> [qpid.client.transport.TransportConnection] Killing all VM Brokers
> main 2009-07-13 13:56:06,274 INFO [qpid.server.registry.ApplicationRegistry]
> Shuting down
> ApplicationRegistry(1):org.apache.qpid.server.registry.configurationfileapplicationregis...@3c67e
> main 2009-07-13 13:56:06,274 INFO [qpid.server.registry.ApplicationRegistry]
> Shutting down
> ApplicationRegistry:org.apache.qpid.server.registry.configurationfileapplicationregis...@3c67e
> main 2009-07-13 13:56:06,274 INFO [qpid.test.utils.QpidTestCase] stopping
> broker: vm
> main 2009-07-13 13:56:06,274 INFO [qpid.test.utils.QpidTestCase] ==========
> stop SimpleACLTest.testServerPublishInvalidQueueSuccess ==========
>
>
>
> ---------------------------------------------------------------------
> Apache Qpid - AMQP Messaging Implementation
> Project: http://qpid.apache.org
> Use/Interact: mailto:dev-subscr...@qpid.apache.org
>
---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project: http://qpid.apache.org
Use/Interact: mailto:dev-subscr...@qpid.apache.org
