Re-attaching the dispatch router log.
________________________________
From: Adel Boutros <[email protected]>
Sent: Wednesday, February 1, 2017 12:10:45 PM
To: [email protected]
Subject: [Dispatch router 0.7.0] [Proton 0.16.0] SSL commands failing on the
Dispatch Router on Linux
Hello,
We have launched our test suite on the dispatch router 0.7.0 and noticed that
connections on a Listener configured with SASL External was not working anymore.
With the below configuration and script, we have this exception ('SSL Failure:
Unknown error.') which keeps occurring.
If I remove any of the commands except the one failing, the last one fails. It
seems we need to query the Dispatch router once and create 2 entities on it for
the 4th operation to fail. If I replace the "create" commands by "delete"
operation it doesn't seem to fail.
PS: All certificates used here are taken from the qpid-dispatch repository here
https://github.com/apache/qpid-dispatch/tree/0.7.0/tests/ssl_certs
Exception client-side
---------------------------
ConnectionException: Connection amqps://green-lx-slave1:10498/$management
disconnected: Condition('amqp:connection:framing-error', 'SSL Failure: Unknown
error.')
Router config
-------------------------
container {
worker-threads: 4
containerName: qpid.dispatch.router.10501
}
sslProfile {
keyFile: server-private-key.pem
password: server-password
certFile: server-certificate.pem
name: ssl-test-profile
certDb: ca-certificate.pem
}
listener {
host: 0.0.0.0
port: 10498
saslMechanisms: EXTERNAL
sslProfile: ssl-test-profile
authenticatePeer: yes
requireSsl: yes
}
router {
mode: interior
routerId: router.10501
}
log {
module: DEFAULT
enable: trace+
source: false
output: dispatch.10501.log
}
Commands to launch in the below order
--------------------------------------------------------
* Restart Dispatch Router
* Restart Broker
* qdstat -g -b amqp://localhost:10501
* qdmanage --ssl-trustfile=ca-certificate.pem
--ssl-certificate=client-certificate.pem --ssl-key=client-private-key.pem
--ssl-password=client-password --ssl-disable-peer-name-verify -b
amqps://localhost:10498 create --type=address prefix=cluster.SSLMutualQueue
waypoint=true name=cluster.SSLMutualQueue.addr
* qdmanage --ssl-trustfile=ca-certificate.pem
--ssl-certificate=client-certificate.pem --ssl-key=client-private-key.pem
--ssl-password=client-password --ssl-disable-peer-name-verify -b
amqps://localhost:10498 create --type=connector role=route-container
addr=localhost port=10305 name=localhost.10305.connector
sslProfile=ssl-test-profile verifyHostName=no
* (Failing command) qdmanage --ssl-trustfile=ca-certificate.pem
--ssl-certificate=client-certificate.pem --ssl-key=client-private-key.pem
--ssl-password=client-password --ssl-disable-peer-name-verify -b
amqps://localhost:10498 delete --type=autoLink --name
localhost.10305.cluster.SSLMutualQueue.in
Dispatch Router log
---------------------------
See attached file
Regards,
Adel
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity: LogEntity(enable=trace+,
identity=log/DEFAULT, module=DEFAULT, name=log/DEFAULT,
output=/dispatch.10501.log, source=False, timestamp=True,
type=org.apache.qpid.dispatch.log)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
LogEntity(identity=log/ROUTER_LS, module=ROUTER_LS, name=log/ROUTER_LS,
type=org.apache.qpid.dispatch.log)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
LogEntity(identity=log/ROUTER_MA, module=ROUTER_MA, name=log/ROUTER_MA,
type=org.apache.qpid.dispatch.log)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
LogEntity(identity=log/ROUTER_HELLO, module=ROUTER_HELLO,
name=log/ROUTER_HELLO, type=org.apache.qpid.dispatch.log)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
LogEntity(identity=log/SERVER, module=SERVER, name=log/SERVER,
type=org.apache.qpid.dispatch.log)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
LogEntity(identity=log/POLICY, module=POLICY, name=log/POLICY,
type=org.apache.qpid.dispatch.log)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
LogEntity(identity=log/CONTAINER, module=CONTAINER, name=log/CONTAINER,
type=org.apache.qpid.dispatch.log)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
LogEntity(identity=log/AGENT, module=AGENT, name=log/AGENT,
type=org.apache.qpid.dispatch.log)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
LogEntity(identity=log/ERROR, module=ERROR, name=log/ERROR,
type=org.apache.qpid.dispatch.log)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
LogEntity(identity=log/ROUTER_CORE, module=ROUTER_CORE, name=log/ROUTER_CORE,
type=org.apache.qpid.dispatch.log)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
LogEntity(identity=log/ROUTER, module=ROUTER, name=log/ROUTER,
type=org.apache.qpid.dispatch.log)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
LogEntity(identity=log/MESSAGE, module=MESSAGE, name=log/MESSAGE,
type=org.apache.qpid.dispatch.log)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
ContainerEntity(containerName=qpid.dispatch.router.10501,
identity=container/qpid.dispatch.router.10501,
name=container/qpid.dispatch.router.10501,
type=org.apache.qpid.dispatch.container, workerThreads=4)
Wed Feb 1 11:54:52 2017 AGENT (warning) routerId is deprecated, use id instead
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity: RouterEntity(area=0,
helloInterval=1, helloMaxAge=3, mobileAddrMaxAge=60, mode=interior,
raInterval=30, raIntervalFlux=4, remoteLsMaxAge=60, routerId=router.10501,
saslConfigName=qdrouterd, type=org.apache.qpid.dispatch.router, workerThreads=4)
Wed Feb 1 11:54:52 2017 SERVER (info) Container Name: router.10501
Wed Feb 1 11:54:52 2017 CONTAINER (trace) Container Initialized
Wed Feb 1 11:54:52 2017 CONTAINER (trace) Node Type Registered - router
Wed Feb 1 11:54:52 2017 CONTAINER (trace) Node of type 'router' installed as
default node
Wed Feb 1 11:54:52 2017 ROUTER (info) Router started in Interior mode, area=0
id=router.10501
Wed Feb 1 11:54:52 2017 POLICY (trace) Policy Initialized
Wed Feb 1 11:54:52 2017 ROUTER (info) Router Engine Instantiated:
id=router.10501 instance=1485946492 max_routers=128
Wed Feb 1 11:54:52 2017 ROUTER_CORE (info) Router Core thread running.
0/router.10501
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'subscribe'
Wed Feb 1 11:54:52 2017 ROUTER_CORE (info) In-process subscription
M/$management
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'subscribe'
Wed Feb 1 11:54:52 2017 ROUTER_CORE (info) In-process subscription
L/$management
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'subscribe'
Wed Feb 1 11:54:52 2017 ROUTER_CORE (info) In-process subscription L/qdrouter
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'subscribe'
Wed Feb 1 11:54:52 2017 ROUTER_CORE (info) In-process subscription
L/qdrouter.ma
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'subscribe'
Wed Feb 1 11:54:52 2017 ROUTER_CORE (info) In-process subscription T/qdrouter
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'subscribe'
Wed Feb 1 11:54:52 2017 ROUTER_CORE (info) In-process subscription
T/qdrouter.ma
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'subscribe'
Wed Feb 1 11:54:52 2017 ROUTER_CORE (info) In-process subscription L/qdhello
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
RouterNodeEntity(address=amqp:/_topo/0/router.10501, id=router.10501,
instance=1485946492, linkState=[], nextHop=(self),
type=org.apache.qpid.dispatch.router.node, validOrigins=[])
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=48, localFreeListMax=32,
totalAllocFromHeap=48, totalFreeToHeap=0, transferBatchSize=16,
type=org.apache.qpid.dispatch.allocator, typeName=qd_log_entry_t, typeSize=2104)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=128, localFreeListMax=128,
totalAllocFromHeap=128, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qd_field_iterator_t,
typeSize=128)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=128, localFreeListMax=128,
totalAllocFromHeap=128, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qd_hash_item_t, typeSize=32)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qd_node_t, typeSize=56)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=128, localFreeListMax=128,
totalAllocFromHeap=128, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qd_timer_t, typeSize=56)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qdr_action_t, typeSize=160)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qdr_field_t, typeSize=40)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=16, localFreeListMax=32,
totalAllocFromHeap=16, totalFreeToHeap=0, transferBatchSize=16,
type=org.apache.qpid.dispatch.allocator, typeName=qd_buffer_t, typeSize=536)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=16, localFreeListMax=32,
totalAllocFromHeap=16, totalFreeToHeap=0, transferBatchSize=16,
type=org.apache.qpid.dispatch.allocator, typeName=qdr_address_t, typeSize=264)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qd_bitmask_t, typeSize=24)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qd_hash_handle_t, typeSize=16)
Wed Feb 1 11:54:52 2017 AGENT (info) Activating management agent on
$_management_internal
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'subscribe'
Wed Feb 1 11:54:52 2017 ROUTER_CORE (info) In-process subscription
L/$_management_internal
Wed Feb 1 11:54:52 2017 DISPLAYNAME (info) Activating DisplayNameService on
$displayname
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'subscribe'
Wed Feb 1 11:54:52 2017 ROUTER_CORE (info) In-process subscription
L/$displayname
Wed Feb 1 11:54:52 2017 CONN_MGR (info) Created SSL Profile with name
ssl-test-profile
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
SslProfileEntity(certDb=ca-certificate.pem, certFile=server-certificate.pem,
identity=sslProfile/ssl-test-profile, keyFile=server-private-key.pem,
name=ssl-test-profile, password=server-password,
type=org.apache.qpid.dispatch.sslProfile)
Wed Feb 1 11:54:52 2017 CONN_MGR (info) Configured Listener: 0.0.0.0:10498
proto=any, role=normal, sslProfile=ssl-test-profile
Wed Feb 1 11:54:52 2017 SERVER (trace) Listening on 0.0.0.0:10498
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
ListenerEntity(addr=127.0.0.1, authenticatePeer=True, cost=1, host=0.0.0.0,
identity=listener/0.0.0.0:10498, idleTimeoutSeconds=16, maxFrameSize=16384,
port=10498, requireEncryption=False, requireSsl=True, role=normal,
saslMechanisms=EXTERNAL, sslProfile=ssl-test-profile, stripAnnotations=both,
type=org.apache.qpid.dispatch.listener)
Wed Feb 1 11:54:52 2017 CONN_MGR (info) Configured Listener: 0.0.0.0:10499
proto=any, role=normal, sslProfile=ssl-test-profile
Wed Feb 1 11:54:52 2017 SERVER (trace) Listening on 0.0.0.0:10499
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
ListenerEntity(addr=127.0.0.1, authenticatePeer=False, cost=1, host=0.0.0.0,
identity=listener/0.0.0.0:10499, idleTimeoutSeconds=16, maxFrameSize=16384,
port=10499, requireEncryption=False, requireSsl=True, role=normal,
saslMechanisms=ANONYMOUS, sslProfile=ssl-test-profile, stripAnnotations=both,
type=org.apache.qpid.dispatch.listener)
Wed Feb 1 11:54:52 2017 CONN_MGR (info) Configured Listener: 0.0.0.0:10501
proto=any, role=normal
Wed Feb 1 11:54:52 2017 SERVER (trace) Listening on 0.0.0.0:10501
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity: ListenerEntity(addr=0.0.0.0,
authenticatePeer=False, cost=1, host=127.0.0.1,
identity=listener/127.0.0.1:10501, idleTimeoutSeconds=16, maxFrameSize=16384,
port=10501, requireEncryption=False, requireSsl=False, role=normal,
saslMechanisms=ANONYMOUS, stripAnnotations=both,
type=org.apache.qpid.dispatch.listener)
Wed Feb 1 11:54:52 2017 POLICY (info) Policy configured maxConnections: 65535,
policyDir: '', access rules enabled: 'false'
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
PolicyEntity(defaultVhost=$default, enableVhostPolicy=False,
maxConnections=65535, policyDir=, type=org.apache.qpid.dispatch.policy)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
ConsoleEntity(identity=console/0, name=console/0,
type=org.apache.qpid.dispatch.console, wsport=5673)
Wed Feb 1 11:54:52 2017 POLICY (info) Policy fallback defaultVhost is defined:
'$default'
Wed Feb 1 11:54:52 2017 SERVER (info) Operational, 4 Threads Running
Wed Feb 1 11:54:52 2017 POLICY (trace) ALLOW Connection 'localhost:48096'
based on global connection count. nConnections= 1
Wed Feb 1 11:54:52 2017 SERVER (debug) Accepting incoming connection from
localhost:48096 to 0.0.0.0:10501
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:AMQP SASL layer detected
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]: <- SASL
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]: -> SASL
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 -> @sasl-mechanisms(64)
[sasl-server-mechanisms=@PN_SYMBOL[:ANONYMOUS]]
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:RAW:
"\x00\x00\x00+\x02\x01\x00\x00\x00S@\xd0\x00\x00\x00\x1b\x00\x00\x00\x01\xf0\x00\x00\x00\x12\x00\x00\x00\x01\xb3\x00\x00\x00\x09ANONYMOUS"
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 <- @sasl-init(65)
[mechanism=:ANONYMOUS, initial-response=b"anonymous@localhost"]
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:Authenticated user: anonymous with
mechanism ANONYMOUS
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 -> @sasl-outcome(68) [code=0]
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:RAW:
"\x00\x00\x00\x16\x02\x01\x00\x00\x00SD\xd0\x00\x00\x00\x06\x00\x00\x00\x01P\x00"
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:AMQP 1.0 layer detected
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]: <- AMQP
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 <- @open(16)
[container-id="b3d1bde0-1528-40bb-acb4-5f97ec3b9dbe", hostname="localhost",
channel-max=32767]
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]: -> AMQP
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'connection_opened'
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 -> @open(16)
[container-id="router.10501", max-frame-size=16384, channel-max=32767,
idle-time-out=8000, offered-capabilities=:"ANONYMOUS-RELAY",
properties={:product="qpid-dispatch-router", :version="0.7.0"}]
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:RAW:
"\x00\x00\x00|\x02\x00\x00\x00\x00S\x10\xd0\x00\x00\x00l\x00\x00\x00\x0a\xa1\x0crouter.10501@p\x00\x00@\x00`\x7f\xffp\x00\x00\x1f@@@\xa3\x0fANONYMOUS-RELAY@\xd1\x00\x00\x003\x00\x00\x00\x04\xa3\x07product\xa1\x14qpid-dispatch-router\xa3\x07version\xa1\x050.7.0"
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 <- @begin(17)
[next-outgoing-id=0, incoming-window=2147483647, outgoing-window=2147483647]
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 <- @attach(18)
[name="b3d1bde0-1528-40bb-acb4-5f97ec3b9dbe-$management", handle=0, role=false,
snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [durable=0, timeout=0,
dynamic=false], target=@target(41) [address="$management", durable=0,
timeout=0, dynamic=false], initial-delivery-count=0, max-message-size=0]
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 -> @begin(17) [remote-channel=0,
next-outgoing-id=0, incoming-window=61, outgoing-window=2147483647]
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'link_first_attach'
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:RAW: "\x00\x00\x00
\x02\x00\x00\x00\x00S\x11\xd0\x00\x00\x00\x10\x00\x00\x00\x04`\x00\x00R\x00R=p\x7f\xff\xff\xff"
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 -> @attach(18)
[name="b3d1bde0-1528-40bb-acb4-5f97ec3b9dbe-$management", handle=0, role=true,
snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [durable=0, timeout=0,
dynamic=false], target=@target(41) [address="$management", durable=0,
timeout=0, dynamic=false], initial-delivery-count=0, max-message-size=0]
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:RAW:
"\x00\x00\x00\x8d\x02\x00\x00\x00\x00S\x12\xd0\x00\x00\x00}\x00\x00\x00\x0b\xa10b3d1bde0-1528-40bb-acb4-5f97ec3b9dbe-$managementR\x00AP\x02P\x00\x00S(\xd0\x00\x00\x00\x11\x00\x00\x00\x0b@R\x00@R\x00B@@@@@@\x00S)\xd0\x00\x00\x00\x19\x00\x00\x00\x07\xa1\x0b$managementR\x00@R\x00B@@@@R\x00S\x00"
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 -> @flow(19) [next-incoming-id=0,
incoming-window=61, next-outgoing-id=0, outgoing-window=2147483647, handle=0,
delivery-count=0, link-credit=250, drain=false]
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:RAW:
"\x00\x00\x00'\x02\x00\x00\x00\x00S\x13\xd0\x00\x00\x00\x17\x00\x00\x00\x09R\x00R=R\x00p\x7f\xff\xff\xffR\x00R\x00R\xfa@B"
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 <- @attach(18)
[name="b3d1bde0-1528-40bb-acb4-5f97ec3b9dbe-f481771d-78ff-4fc5-930c-dfbaa868689d",
handle=1, role=true, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40)
[durable=0, timeout=0, dynamic=true], target=@target(41) [durable=0, timeout=0,
dynamic=false], initial-delivery-count=0, max-message-size=0]
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'link_first_attach'
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 -> @attach(18)
[name="b3d1bde0-1528-40bb-acb4-5f97ec3b9dbe-f481771d-78ff-4fc5-930c-dfbaa868689d",
handle=1, role=false, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40)
[address="amqp:/_topo/0/router.10501/temp.PL3isoJ5qRBwwW2", durable=0,
timeout=0, dynamic=true], target=@target(41) [durable=0, timeout=0,
dynamic=false], initial-delivery-count=0, max-message-size=0]
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:RAW:
"\x00\x00\x00\xca\x02\x00\x00\x00\x00S\x12\xd0\x00\x00\x00\xba\x00\x00\x00\x0b\xa1Ib3d1bde0-1528-40bb-acb4-5f97ec3b9dbe-f481771d-78ff-4fc5-930c-dfbaa868689dR\x01BP\x02P\x00\x00S(\xd0\x00\x00\x00A\x00\x00\x00\x0b\xa1/amqp:/_topo/0/router.10501/temp.PL3isoJ5qRBwwW2R\x00@R\x00A@@@@@@\x00S)\xd0\x00\x00\x00\x0d\x00\x00\x00\x07@R\x00@R\x00B@@@@R\x00S\x00"
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 <- @flow(19) [next-incoming-id=0,
incoming-window=2147483647, next-outgoing-id=0, outgoing-window=2147483647,
handle=1, delivery-count=0, link-credit=1, drain=false]
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 <- @transfer(20) [handle=0,
delivery-id=0, delivery-tag=b"1", message-format=0, settled=false, more=false]
(261)
"\x00Sp\xd0\x00\x00\x00\x0b\x00\x00\x00\x05BP\x04@BR\x00\x00Ss\xd0\x00\x00\x00S\x00\x00\x00\x0d@@@@\xa1/amqp:/_topo/0/router.10501/temp.PL3isoJ5qRBwwW2S\x01@@\x83\x00\x00\x00\x00\x00\x00\x00\x00\x83\x00\x00\x00\x00\x00\x00\x00\x00@R\x00@\x00St\xd1\x00\x00\x00j\x00\x00\x00\x08\xa1\x09operation\xa1\x05QUERY\xa1\x0aentityType\xa0\x1forg.apache.qpid.dispatch.router\xa1\x04type\xa1\x13org.amqp.management\xa1\x04name\xa1\x04self\x00Sw\xd1\x00\x00\x00\x1d\x00\x00\x00\x02\xa1\x0eattributeNames\xd0\x00\x00\x00\x04\x00\x00\x00\x00"
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'link_flow'
Wed Feb 1 11:54:52 2017 MESSAGE (trace) Received Message{
reply-to='amqp:/_topo/0/router.10501/temp.PL3isoJ5qRBwwW2'
body='\d1\00\00\00\1d\00\00\00\02\a1\0eattri'} on link
b3d1bde0-1528-40bb-acb4-5f97ec3b9dbe-$management
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'link_deliver'
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'send_to'
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 -> @flow(19) [next-incoming-id=1,
incoming-window=61, next-outgoing-id=0, outgoing-window=2147483647, handle=0,
delivery-count=1, link-credit=250, drain=false]
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:RAW:
"\x00\x00\x00'\x02\x00\x00\x00\x00S\x13\xd0\x00\x00\x00\x17\x00\x00\x00\x09R\x01R=R\x00p\x7f\xff\xff\xffR\x00R\x01R\xfa@B"
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 -> @disposition(21) [role=true,
first=0, last=0, settled=true, state=@accepted(36) []]
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:RAW:
"\x00\x00\x00&\x02\x00\x00\x00\x00S\x15\xd0\x00\x00\x00\x16\x00\x00\x00\x05AR\x00R\x00A\x00S$\xd0\x00\x00\x00\x04\x00\x00\x00\x00"
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qd_listener_t, typeSize=32)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qdpn_listener_t, typeSize=48)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=16, localFreeListMax=32,
totalAllocFromHeap=16, totalFreeToHeap=0, transferBatchSize=16,
type=org.apache.qpid.dispatch.allocator, typeName=qdpn_connector_t,
typeSize=600)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qd_connection_t, typeSize=232)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
ConnectionEntity(container=b3d1bde0-1528-40bb-acb4-5f97ec3b9dbe, dir=in,
host=localhost:48096, identity=1, isAuthenticated=True, isEncrypted=False,
opened=True, properties={}, role=normal, sasl=ANONYMOUS, ssl=False,
type=org.apache.qpid.dispatch.connection, user=anonymous)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=256, localFreeListMax=128,
totalAllocFromHeap=256, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qd_work_item_t, typeSize=24)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qd_deferred_call_t,
typeSize=32)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qdr_connection_t,
typeSize=232)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qd_link_t, typeSize=48)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qdr_terminus_t, typeSize=64)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=16, localFreeListMax=32,
totalAllocFromHeap=16, totalFreeToHeap=0, transferBatchSize=16,
type=org.apache.qpid.dispatch.allocator, typeName=qdr_link_t, typeSize=304)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qdr_link_ref_t, typeSize=24)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qd_hash_segment_t,
typeSize=24)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qdr_connection_work_t,
typeSize=56)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=192, localFreeListMax=128,
totalAllocFromHeap=192, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qd_message_t, typeSize=128)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=16, localFreeListMax=32,
totalAllocFromHeap=16, totalFreeToHeap=0, transferBatchSize=16,
type=org.apache.qpid.dispatch.allocator, typeName=qd_message_content_t,
typeSize=640)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qd_composed_field_t,
typeSize=64)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qd_composite_t, typeSize=112)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qdr_delivery_t, typeSize=144)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qdr_general_work_t,
typeSize=64)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qdr_delivery_ref_t,
typeSize=24)
Wed Feb 1 11:54:52 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=128, localFreeListMax=128,
totalAllocFromHeap=128, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qd_parsed_field_t,
typeSize=88)
Wed Feb 1 11:54:52 2017 AGENT (debug) Agent request Message(address=None,
properties={'operation': 'QUERY', 'entityType':
'org.apache.qpid.dispatch.router', 'type': 'org.amqp.management', 'name':
'self'}, body={'attributeNames': []},
reply_to='amqp:/_topo/0/router.10501/temp.PL3isoJ5qRBwwW2', correlation_id=1L)
Wed Feb 1 11:54:52 2017 AGENT (debug) Agent response:
Message(address='amqp:/_topo/0/router.10501/temp.PL3isoJ5qRBwwW2',
properties={'statusDescription': 'OK', 'statusCode': 200}, body={'results':
[[60, None, 4, 4, 'router/None', 1, '0', 3, None, 60, 0, 'router.10501', 30,
'interior', 'org.apache.qpid.dispatch.router', 0, 'qdrouterd', 0, None,
'router/None']], 'attributeNames': [u'mobileAddrMaxAge', u'debugDump',
u'raIntervalFlux', u'workerThreads', u'name', u'helloInterval', u'area',
u'helloMaxAge', u'saslConfigPath', u'remoteLsMaxAge', u'addrCount',
u'routerId', u'raInterval', u'mode', u'type', u'nodeCount', u'saslConfigName',
u'linkCount', u'id', u'identity']}, reply_to=None, correlation_id=1L)
Responding to:
Message(address=None, properties={'operation': 'QUERY', 'entityType':
'org.apache.qpid.dispatch.router', 'type': 'org.amqp.management', 'name':
'self'}, body={'attributeNames': []},
reply_to='amqp:/_topo/0/router.10501/temp.PL3isoJ5qRBwwW2', correlation_id=1L)
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'send_to'
Wed Feb 1 11:54:52 2017 MESSAGE (trace) Sending
Message{to='amqp:/_topo/0/router.10501/temp.PL3isoJ5qRBwwW2'
body='\d1\00\00\01\95\00\00\00\04\a1\07resul'} on link
b3d1bde0-1528-40bb-acb4-5f97ec3b9dbe-f481771d-78ff-4fc5-930c-dfbaa868689d
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 -> @transfer(20) [handle=1,
delivery-id=0, delivery-tag=b"\x00\x00\x00\x00\x00\x00\x00\x00",
message-format=0, settled=true, more=false] (536)
"\x00Ss\xd0\x00\x00\x00;\x00\x00\x00\x06@@\xa1/amqp:/_topo/0/router.10501/temp.PL3isoJ5qRBwwW2@@U\x01\x00St\xd1\x00\x00\x000\x00\x00\x00\x04\xa1\x11statusDescription\xa1\x02OK\xa1\x0astatusCode\x81\x00\x00\x00\x00\x00\x00\x00\xc8\x00Sw\xd1\x00\x00\x01\x95\x00\x00\x00\x04\xa1\x07results\xd0\x00\x00\x00\x85\x00\x00\x00\x01\xd0\x00\x00\x00|\x00\x00\x00\x14U<@U\x04U\x04\xa1\x0brouter/NoneU\x01\xa1\x010U\x03@U<U\x00\xa1\x0crouter.10501U\x1e\xa1\x08interior\xa1\x1forg.apache.qpid.dispatch.routerU\x00\xa1\x09qdrouterdU\x00@\xa1\x0brouter/None\xa1\x0eattributeNames\xd0\x00\x00\x00\xe9\x00\x00\x00\x14\xa1\x10mobileAddrMaxAge\xa1\x09debugDump\xa1\x0eraIntervalFlux\xa1\x0dworkerThreads\xa1\x04name\xa1\x0dhelloInterval\xa1\x04area\xa1\x0bhelloMaxAge\xa1\x0esaslConfigPath\xa1\x0eremoteLsMaxAge\xa1\x09addrCount\xa1\x08routerId\xa1\x0araInterval\xa1\x04mode\xa1\x04type\xa1\x09nodeCount\xa1\x0esaslConfigName\xa1\x09linkCount\xa1\x02id\xa1\x08identity"
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:RAW:
"\x00\x00\x02@\x02\x00\x00\x00\x00S\x14\xd0\x00\x00\x00\x18\x00\x00\x00\x08R\x01R\x00\xa0\x08\x00\x00\x00\x00\x00\x00\x00\x00R\x00AB@@\x00Ss\xd0\x00\x00\x00;\x00\x00\x00\x06@@\xa1/amqp:/_topo/0/router.10501/temp.PL3isoJ5qRBwwW2@@U\x01\x00St\xd1\x00\x00\x000\x00\x00\x00\x04\xa1\x11statusDescription\xa1\x02OK\xa1\x0astatusCode\x81\x00\x00\x00\x00\x00\x00\x00\xc8\x00Sw\xd1\x00\x00\x01\x95\x00\x00\x00\x04\xa1\x07results\xd0\x00\x00\x00\x85\x00\x00\x00\x01\xd0\x00\x00\x00|\x00\x00\x00\x14U<@U\x04U\x04\xa1\x0brouter/NoneU\x01\xa1\x010U\x03@U<U\x00\xa1\x0crouter.10501U\x1e\xa1\x08interior\xa1\x1forg.apache.qpid.dispatch.routerU\x00\xa1\x09qdrouterdU\x00@\xa1\x0brouter/None\xa1\x0eattributeNames\xd0\x00\x00\x00\xe9\x00\x00\x00\x14\xa1\x10mobileAddrMaxAge\xa1\x09debugDump\xa1\x0eraIntervalFlux\xa1\x0dworkerThreads\xa1\x04name\xa1\x0dhelloInterval\xa1\x04area\xa1\x0bhelloMaxAge\xa1\x0esaslConfigPath\xa1\x0eremoteLsMaxAge\xa1\x09addrCount\xa1\x08routerId\xa1\x0araInterval\xa1\x04mode\xa1\x04type\xa1\x09nodeCount\xa1\x0esaslConfigName\xa1\x09linkCount\xa1\x02id\xa1\x08identity"
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'link_flow'
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 <- @flow(19) [next-incoming-id=1,
incoming-window=2147483647, next-outgoing-id=1, outgoing-window=2147483647,
handle=1, delivery-count=1, link-credit=1, drain=false]
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 <- @close(24) []
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]: <- EOS
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:0 -> @close(24) []
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'link_flow'
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]:RAW:
"\x00\x00\x00\x15\x02\x00\x00\x00\x00S\x18\xd0\x00\x00\x00\x05\x00\x00\x00\x01@"
Wed Feb 1 11:54:52 2017 SERVER (trace) [1]: -> EOS
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'link_detach'
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'link_detach'
Wed Feb 1 11:54:52 2017 ROUTER_CORE (trace) Core action 'connection_closed'
Wed Feb 1 11:54:52 2017 POLICY (debug) Connection 'localhost:48096' closed
with resources n_sessions=0, n_senders=0, n_receivers=0. nConnections= 0.
Wed Feb 1 11:54:52 2017 POLICY (trace) ALLOW Connection 'localhost:38826'
based on global connection count. nConnections= 1
Wed Feb 1 11:54:52 2017 SERVER (debug) Accepting incoming connection from
localhost:38826 to 0.0.0.0:10498
Wed Feb 1 11:54:52 2017 SERVER (trace) Configuring SSL on incoming connection
from localhost:38826 to 0.0.0.0:10498
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:Server SSL socket created.
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:SSL/TLS connection detected
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:process_input_ssl( data size=331 )
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:Wrote 331 bytes to BIO Layer, 0
left over
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:Detected read-blocked
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:process_input_ssl() returning 331
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:Read 2221 bytes from BIO Layer
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:process_output_ssl() returning 2221
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:process_input_ssl( data size=1892 )
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:Wrote 1892 bytes to BIO Layer, 0
left over
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:Detected read-blocked
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:process_input_ssl() returning 1892
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:Read 1042 bytes from BIO Layer
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:process_output_ssl() returning 1042
Wed Feb 1 11:54:52 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 ROUTER_CORE (trace) Core action 'send_to'
Wed Feb 1 11:54:53 2017 ROUTER_HELLO (trace) SENT: HELLO(id=router.10501
area=0 inst=1485946492 seen=[])
Wed Feb 1 11:54:53 2017 ROUTER_LS (trace) SENT: RA(id=router.10501 area=0
inst=1485946492 ls_seq=0 mobile_seq=0)
Wed Feb 1 11:54:53 2017 ROUTER_CORE (trace) Core action 'send_to'
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_input_ssl( data size=37 )
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Wrote 37 bytes to BIO Layer, 0 left
over
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Read 8 bytes from SSL socket for app
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:AMQP SASL layer detected
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]: <- SASL
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Application consumed 8 bytes from
peer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Detected read-blocked
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_input_ssl() returning 37
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]: -> SASL
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Gathered 8 bytes from app to send
to peer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Wrote 8 bytes from app to socket
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Read 37 bytes from BIO Layer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 -> @sasl-mechanisms(64)
[sasl-server-mechanisms=@PN_SYMBOL[:EXTERNAL]]
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:RAW:
"\x00\x00\x00*\x02\x01\x00\x00\x00S@\xd0\x00\x00\x00\x1a\x00\x00\x00\x01\xf0\x00\x00\x00\x11\x00\x00\x00\x01\xb3\x00\x00\x00\x08EXTERNAL"
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Gathered 42 bytes from app to send
to peer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Wrote 42 bytes from app to socket
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Read 71 bytes from BIO Layer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 108
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_input_ssl( data size=61 )
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Wrote 61 bytes to BIO Layer, 0 left
over
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Read 32 bytes from SSL socket for
app
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 <- @sasl-init(65)
[mechanism=:EXTERNAL, initial-response=b""]
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Authenticated user:
C=US,ST=NC,L=Raleigh,OU=Dev,O=Client,CN=127.0.0.1 with mechanism EXTERNAL
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Application consumed 32 bytes from
peer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Detected read-blocked
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_input_ssl() returning 61
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 -> @sasl-outcome(68) [code=0]
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:RAW:
"\x00\x00\x00\x16\x02\x01\x00\x00\x00SD\xd0\x00\x00\x00\x06\x00\x00\x00\x01P\x00"
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Gathered 22 bytes from app to send
to peer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Wrote 22 bytes from app to socket
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Read 51 bytes from BIO Layer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 51
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_input_ssl( data size=151 )
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Wrote 151 bytes to BIO Layer, 0
left over
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Read 8 bytes from SSL socket for app
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:AMQP 1.0 layer detected
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]: <- AMQP
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Application consumed 8 bytes from
peer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Read 85 bytes from SSL socket for
app
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 <- @open(16)
[container-id="5dde0372-9d60-44e5-b4c5-03198d409234", hostname="localhost",
channel-max=32767]
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Application consumed 85 bytes from
peer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Detected read-blocked
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_input_ssl() returning 151
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]: -> AMQP
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Gathered 8 bytes from app to send
to peer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Wrote 8 bytes from app to socket
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Read 37 bytes from BIO Layer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 37
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 -> @open(16)
[container-id="router.10501", max-frame-size=16384, channel-max=32767,
idle-time-out=8000, offered-capabilities=:"ANONYMOUS-RELAY",
properties={:product="qpid-dispatch-router", :version="0.7.0"}]
Wed Feb 1 11:54:53 2017 ROUTER_CORE (trace) Core action 'connection_opened'
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:RAW:
"\x00\x00\x00|\x02\x00\x00\x00\x00S\x10\xd0\x00\x00\x00l\x00\x00\x00\x0a\xa1\x0crouter.10501@p\x00\x00@\x00`\x7f\xffp\x00\x00\x1f@@@\xa3\x0fANONYMOUS-RELAY@\xd1\x00\x00\x003\x00\x00\x00\x04\xa3\x07product\xa1\x14qpid-dispatch-router\xa3\x07version\xa1\x050.7.0"
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Gathered 124 bytes from app to send
to peer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Wrote 124 bytes from app to socket
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Read 153 bytes from BIO Layer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 153
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_input_ssl( data size=203 )
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Wrote 203 bytes to BIO Layer, 0
left over
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Read 174 bytes from SSL socket for
app
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 <- @begin(17)
[next-outgoing-id=0, incoming-window=2147483647, outgoing-window=2147483647]
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 <- @attach(18)
[name="5dde0372-9d60-44e5-b4c5-03198d409234-$management", handle=0, role=false,
snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [durable=0, timeout=0,
dynamic=false], target=@target(41) [address="$management", durable=0,
timeout=0, dynamic=false], initial-delivery-count=0, max-message-size=0]
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Application consumed 174 bytes from
peer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Detected read-blocked
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_input_ssl() returning 203
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 ROUTER_CORE (trace) Core action 'link_first_attach'
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 -> @begin(17) [remote-channel=0,
next-outgoing-id=0, incoming-window=61, outgoing-window=2147483647]
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:RAW: "\x00\x00\x00
\x02\x00\x00\x00\x00S\x11\xd0\x00\x00\x00\x10\x00\x00\x00\x04`\x00\x00R\x00R=p\x7f\xff\xff\xff"
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Gathered 32 bytes from app to send
to peer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Wrote 32 bytes from app to socket
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Read 61 bytes from BIO Layer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 61
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 -> @attach(18)
[name="5dde0372-9d60-44e5-b4c5-03198d409234-$management", handle=0, role=true,
snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [durable=0, timeout=0,
dynamic=false], target=@target(41) [address="$management", durable=0,
timeout=0, dynamic=false], initial-delivery-count=0, max-message-size=0]
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:RAW:
"\x00\x00\x00\x8d\x02\x00\x00\x00\x00S\x12\xd0\x00\x00\x00}\x00\x00\x00\x0b\xa105dde0372-9d60-44e5-b4c5-03198d409234-$managementR\x00AP\x02P\x00\x00S(\xd0\x00\x00\x00\x11\x00\x00\x00\x0b@R\x00@R\x00B@@@@@@\x00S)\xd0\x00\x00\x00\x19\x00\x00\x00\x07\xa1\x0b$managementR\x00@R\x00B@@@@R\x00S\x00"
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 -> @flow(19) [next-incoming-id=0,
incoming-window=61, next-outgoing-id=0, outgoing-window=2147483647, handle=0,
delivery-count=0, link-credit=250, drain=false]
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:RAW:
"\x00\x00\x00'\x02\x00\x00\x00\x00S\x13\xd0\x00\x00\x00\x17\x00\x00\x00\x09R\x00R=R\x00p\x7f\xff\xff\xffR\x00R\x00R\xfa@B"
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Gathered 180 bytes from app to send
to peer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Wrote 180 bytes from app to socket
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Read 209 bytes from BIO Layer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 209
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_input_ssl( data size=183 )
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Wrote 183 bytes to BIO Layer, 0
left over
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Read 154 bytes from SSL socket for
app
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 <- @attach(18)
[name="5dde0372-9d60-44e5-b4c5-03198d409234-bd77f35d-0d11-4361-a5da-3c96b7c6f2b4",
handle=1, role=true, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40)
[durable=0, timeout=0, dynamic=true], target=@target(41) [durable=0, timeout=0,
dynamic=false], initial-delivery-count=0, max-message-size=0]
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Application consumed 154 bytes from
peer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Detected read-blocked
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_input_ssl() returning 183
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 ROUTER_CORE (trace) Core action 'link_first_attach'
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 -> @attach(18)
[name="5dde0372-9d60-44e5-b4c5-03198d409234-bd77f35d-0d11-4361-a5da-3c96b7c6f2b4",
handle=1, role=false, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40)
[address="amqp:/_topo/0/router.10501/temp.iWmpG6kT2bwJdJk", durable=0,
timeout=0, dynamic=true], target=@target(41) [durable=0, timeout=0,
dynamic=false], initial-delivery-count=0, max-message-size=0]
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:RAW:
"\x00\x00\x00\xca\x02\x00\x00\x00\x00S\x12\xd0\x00\x00\x00\xba\x00\x00\x00\x0b\xa1I5dde0372-9d60-44e5-b4c5-03198d409234-bd77f35d-0d11-4361-a5da-3c96b7c6f2b4R\x01BP\x02P\x00\x00S(\xd0\x00\x00\x00A\x00\x00\x00\x0b\xa1/amqp:/_topo/0/router.10501/temp.iWmpG6kT2bwJdJkR\x00@R\x00A@@@@@@\x00S)\xd0\x00\x00\x00\x0d\x00\x00\x00\x07@R\x00@R\x00B@@@@R\x00S\x00"
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Gathered 202 bytes from app to send
to peer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Wrote 202 bytes from app to socket
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Read 231 bytes from BIO Layer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 231
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_input_ssl( data size=424 )
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Wrote 424 bytes to BIO Layer, 0
left over
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Read 395 bytes from SSL socket for
app
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 <- @flow(19) [next-incoming-id=0,
incoming-window=2147483647, next-outgoing-id=0, outgoing-window=2147483647,
handle=1, delivery-count=0, link-credit=1, drain=false]
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 <- @transfer(20) [handle=0,
delivery-id=0, delivery-tag=b"1", message-format=0, settled=false, more=false]
(320)
"\x00Sp\xd0\x00\x00\x00\x0b\x00\x00\x00\x05BP\x04@BR\x00\x00Ss\xd0\x00\x00\x00S\x00\x00\x00\x0d@@@@\xa1/amqp:/_topo/0/router.10501/temp.iWmpG6kT2bwJdJkS\x01@@\x83\x00\x00\x00\x00\x00\x00\x00\x00\x83\x00\x00\x00\x00\x00\x00\x00\x00@R\x00@\x00St\xd1\x00\x00\x00p\x00\x00\x00\x06\xa1\x09operation\xa1\x06CREATE\xa1\x04type\xa1.org.apache.qpid.dispatch.router.config.address\xa1\x04name\xa1\x1bcluster.SSLMutualQueue.addr\x00Sw\xd1\x00\x00\x00R\x00\x00\x00\x06\xa1\x06prefix\xa1\x16cluster.SSLMutualQueue\xa1\x08waypointA\xa1\x04name\xa1\x1bcluster.SSLMutualQueue.addr"
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Application consumed 395 bytes from
peer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Detected read-blocked
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_input_ssl() returning 424
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 ROUTER_CORE (trace) Core action 'link_flow'
Wed Feb 1 11:54:53 2017 MESSAGE (trace) Received Message{
reply-to='amqp:/_topo/0/router.10501/temp.iWmpG6kT2bwJdJk'
body='\d1\00\00\00R\00\00\00\06\a1\06prefi'} on link
5dde0372-9d60-44e5-b4c5-03198d409234-$management
Wed Feb 1 11:54:53 2017 ROUTER_CORE (trace) Core action 'link_deliver'
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 -> @flow(19) [next-incoming-id=1,
incoming-window=61, next-outgoing-id=0, outgoing-window=2147483647, handle=0,
delivery-count=1, link-credit=250, drain=false]
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:RAW:
"\x00\x00\x00'\x02\x00\x00\x00\x00S\x13\xd0\x00\x00\x00\x17\x00\x00\x00\x09R\x01R=R\x00p\x7f\xff\xff\xffR\x00R\x01R\xfa@B"
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 -> @disposition(21) [role=true,
first=0, last=0, settled=true, state=@accepted(36) []]
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:RAW:
"\x00\x00\x00&\x02\x00\x00\x00\x00S\x15\xd0\x00\x00\x00\x16\x00\x00\x00\x05AR\x00R\x00A\x00S$\xd0\x00\x00\x00\x04\x00\x00\x00\x00"
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Gathered 77 bytes from app to send
to peer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Wrote 77 bytes from app to socket
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Read 106 bytes from BIO Layer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 106
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 ROUTER_CORE (trace) Core action 'manage_create'
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 ROUTER_CORE (trace) Core action 'send_to'
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 MESSAGE (trace) Sending
Message{to='amqp:/_topo/0/router.10501/temp.iWmpG6kT2bwJdJk'
body='\d1\00\00\00\cc\00\00\00\10\a1\04name\a1'} on link
5dde0372-9d60-44e5-b4c5-03198d409234-bd77f35d-0d11-4361-a5da-3c96b7c6f2b4
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 -> @transfer(20) [handle=1,
delivery-id=0, delivery-tag=b"\x01\x00\x00\x00\x00\x00\x00\x00",
message-format=0, settled=true, more=false] (333)
"\x00Ss\xd0\x00\x00\x00;\x00\x00\x00\x06@@\xa1/amqp:/_topo/0/router.10501/temp.iWmpG6kT2bwJdJk@@S\x01\x00St\xd1\x00\x00\x00.\x00\x00\x00\x04\xa1\x11statusDescription\xa1\x07Created\xa1\x0astatusCodeR\xc9\x00Sw\xd1\x00\x00\x00\xcc\x00\x00\x00\x10\xa1\x04name\xa1\x1bcluster.SSLMutualQueue.addr\xa1\x08identity\xa1\x015\xa1\x04type\xa1.org.apache.qpid.dispatch.router.config.address\xa1\x06prefix\xa1\x16cluster.SSLMutualQueue\xa1\x0cdistribution\xa1\x08balanced\xa1\x08waypointA\xa1\x0cingressPhaseT\x00\xa1\x0begressPhaseT\x01"
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:RAW:
"\x00\x00\x01u\x02\x00\x00\x00\x00S\x14\xd0\x00\x00\x00\x18\x00\x00\x00\x08R\x01R\x00\xa0\x08\x01\x00\x00\x00\x00\x00\x00\x00R\x00AB@@\x00Ss\xd0\x00\x00\x00;\x00\x00\x00\x06@@\xa1/amqp:/_topo/0/router.10501/temp.iWmpG6kT2bwJdJk@@S\x01\x00St\xd1\x00\x00\x00.\x00\x00\x00\x04\xa1\x11statusDescription\xa1\x07Created\xa1\x0astatusCodeR\xc9\x00Sw\xd1\x00\x00\x00\xcc\x00\x00\x00\x10\xa1\x04name\xa1\x1bcluster.SSLMutualQueue.addr\xa1\x08identity\xa1\x015\xa1\x04type\xa1.org.apache.qpid.dispatch.router.config.address\xa1\x06prefix\xa1\x16cluster.SSLMutualQueue\xa1\x0cdistribution\xa1\x08balanced\xa1\x08waypointA\xa1\x0cingressPhaseT\x00\xa1\x0begressPhaseT\x01"
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Gathered 373 bytes from app to send
to peer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Wrote 373 bytes from app to socket
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Read 402 bytes from BIO Layer
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 402
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 ROUTER_CORE (trace) Core action 'link_flow'
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:process_input_ssl( data size=0 )
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:Lower layer closed - shutting down
BIO write side
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:ERROR amqp:connection:framing-error
SSL Failure: Unknown error.
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:0 -> @close(24) [error=@error(29)
[condition=:"amqp:connection:framing-error", description="SSL Failure: Unknown
error."]]
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:RAW:
"\x00\x00\x00]\x02\x00\x00\x00\x00S\x18\xd0\x00\x00\x00M\x00\x00\x00\x01\x00S\x1d\xd0\x00\x00\x00A\x00\x00\x00\x03\xa3\x1damqp:connection:framing-error\xa1\x1bSSL
Failure: Unknown error.@"
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]: <- EOS
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]: -> EOS
Wed Feb 1 11:54:53 2017 POLICY (debug) Connection 'localhost:38826' closed
with resources n_sessions=0, n_senders=0, n_receivers=0. nConnections= 0.
Wed Feb 1 11:54:53 2017 ROUTER_CORE (trace) Core action 'link_detach'
Wed Feb 1 11:54:53 2017 ROUTER_CORE (trace) Core action 'link_detach'
Wed Feb 1 11:54:53 2017 ROUTER_CORE (trace) Core action 'connection_closed'
Wed Feb 1 11:54:53 2017 SERVER (trace) [2]:SSL socket freed.
Wed Feb 1 11:54:53 2017 POLICY (trace) ALLOW Connection 'localhost:38827'
based on global connection count. nConnections= 1
Wed Feb 1 11:54:53 2017 SERVER (debug) Accepting incoming connection from
localhost:38827 to 0.0.0.0:10498
Wed Feb 1 11:54:53 2017 SERVER (trace) Configuring SSL on incoming connection
from localhost:38827 to 0.0.0.0:10498
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:Server SSL socket created.
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:SSL/TLS connection detected
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:process_input_ssl( data size=331 )
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:Wrote 331 bytes to BIO Layer, 0
left over
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:Detected read-blocked
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:process_input_ssl() returning 331
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:Read 2221 bytes from BIO Layer
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:process_output_ssl() returning 2221
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:process_input_ssl( data size=1893 )
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:Wrote 1893 bytes to BIO Layer, 0
left over
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:Detected read-blocked
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:process_input_ssl() returning 1893
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:Read 1042 bytes from BIO Layer
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:process_output_ssl() returning 1042
Wed Feb 1 11:54:53 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 ROUTER_CORE (trace) Core action 'send_to'
Wed Feb 1 11:54:54 2017 ROUTER_HELLO (trace) SENT: HELLO(id=router.10501
area=0 inst=1485946492 seen=[])
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_input_ssl( data size=37 )
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Wrote 37 bytes to BIO Layer, 0 left
over
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Read 8 bytes from SSL socket for app
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:AMQP SASL layer detected
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]: <- SASL
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Application consumed 8 bytes from
peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_input_ssl() returning 37
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]: -> SASL
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Gathered 8 bytes from app to send
to peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Wrote 8 bytes from app to socket
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Read 37 bytes from BIO Layer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 -> @sasl-mechanisms(64)
[sasl-server-mechanisms=@PN_SYMBOL[:EXTERNAL]]
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:RAW:
"\x00\x00\x00*\x02\x01\x00\x00\x00S@\xd0\x00\x00\x00\x1a\x00\x00\x00\x01\xf0\x00\x00\x00\x11\x00\x00\x00\x01\xb3\x00\x00\x00\x08EXTERNAL"
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Gathered 42 bytes from app to send
to peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Wrote 42 bytes from app to socket
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Read 71 bytes from BIO Layer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 108
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_input_ssl( data size=61 )
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Wrote 61 bytes to BIO Layer, 0 left
over
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Read 32 bytes from SSL socket for
app
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 <- @sasl-init(65)
[mechanism=:EXTERNAL, initial-response=b""]
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Authenticated user:
C=US,ST=NC,L=Raleigh,OU=Dev,O=Client,CN=127.0.0.1 with mechanism EXTERNAL
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Application consumed 32 bytes from
peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_input_ssl() returning 61
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 -> @sasl-outcome(68) [code=0]
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:RAW:
"\x00\x00\x00\x16\x02\x01\x00\x00\x00SD\xd0\x00\x00\x00\x06\x00\x00\x00\x01P\x00"
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Gathered 22 bytes from app to send
to peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Wrote 22 bytes from app to socket
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Read 51 bytes from BIO Layer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 51
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_input_ssl( data size=151 )
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Wrote 151 bytes to BIO Layer, 0
left over
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Read 8 bytes from SSL socket for app
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:AMQP 1.0 layer detected
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]: <- AMQP
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Application consumed 8 bytes from
peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Read 85 bytes from SSL socket for
app
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 <- @open(16)
[container-id="a7455c6a-5c72-44ec-b64e-e54f8180dcf2", hostname="localhost",
channel-max=32767]
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Application consumed 85 bytes from
peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_input_ssl() returning 151
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]: -> AMQP
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Gathered 8 bytes from app to send
to peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Wrote 8 bytes from app to socket
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Read 37 bytes from BIO Layer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 37
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 -> @open(16)
[container-id="router.10501", max-frame-size=16384, channel-max=32767,
idle-time-out=8000, offered-capabilities=:"ANONYMOUS-RELAY",
properties={:product="qpid-dispatch-router", :version="0.7.0"}]
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:RAW:
"\x00\x00\x00|\x02\x00\x00\x00\x00S\x10\xd0\x00\x00\x00l\x00\x00\x00\x0a\xa1\x0crouter.10501@p\x00\x00@\x00`\x7f\xffp\x00\x00\x1f@@@\xa3\x0fANONYMOUS-RELAY@\xd1\x00\x00\x003\x00\x00\x00\x04\xa3\x07product\xa1\x14qpid-dispatch-router\xa3\x07version\xa1\x050.7.0"
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Gathered 124 bytes from app to send
to peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Wrote 124 bytes from app to socket
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Read 153 bytes from BIO Layer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 153
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 ROUTER_CORE (trace) Core action 'connection_opened'
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_input_ssl( data size=203 )
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Wrote 203 bytes to BIO Layer, 0
left over
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Read 174 bytes from SSL socket for
app
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 <- @begin(17)
[next-outgoing-id=0, incoming-window=2147483647, outgoing-window=2147483647]
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 <- @attach(18)
[name="a7455c6a-5c72-44ec-b64e-e54f8180dcf2-$management", handle=0, role=false,
snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [durable=0, timeout=0,
dynamic=false], target=@target(41) [address="$management", durable=0,
timeout=0, dynamic=false], initial-delivery-count=0, max-message-size=0]
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Application consumed 174 bytes from
peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_input_ssl() returning 203
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 -> @begin(17) [remote-channel=0,
next-outgoing-id=0, incoming-window=61, outgoing-window=2147483647]
Wed Feb 1 11:54:54 2017 ROUTER_CORE (trace) Core action 'link_first_attach'
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:RAW: "\x00\x00\x00
\x02\x00\x00\x00\x00S\x11\xd0\x00\x00\x00\x10\x00\x00\x00\x04`\x00\x00R\x00R=p\x7f\xff\xff\xff"
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Gathered 32 bytes from app to send
to peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Wrote 32 bytes from app to socket
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Read 61 bytes from BIO Layer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 61
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 -> @attach(18)
[name="a7455c6a-5c72-44ec-b64e-e54f8180dcf2-$management", handle=0, role=true,
snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [durable=0, timeout=0,
dynamic=false], target=@target(41) [address="$management", durable=0,
timeout=0, dynamic=false], initial-delivery-count=0, max-message-size=0]
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:RAW:
"\x00\x00\x00\x8d\x02\x00\x00\x00\x00S\x12\xd0\x00\x00\x00}\x00\x00\x00\x0b\xa10a7455c6a-5c72-44ec-b64e-e54f8180dcf2-$managementR\x00AP\x02P\x00\x00S(\xd0\x00\x00\x00\x11\x00\x00\x00\x0b@R\x00@R\x00B@@@@@@\x00S)\xd0\x00\x00\x00\x19\x00\x00\x00\x07\xa1\x0b$managementR\x00@R\x00B@@@@R\x00S\x00"
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 -> @flow(19) [next-incoming-id=0,
incoming-window=61, next-outgoing-id=0, outgoing-window=2147483647, handle=0,
delivery-count=0, link-credit=250, drain=false]
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:RAW:
"\x00\x00\x00'\x02\x00\x00\x00\x00S\x13\xd0\x00\x00\x00\x17\x00\x00\x00\x09R\x00R=R\x00p\x7f\xff\xff\xffR\x00R\x00R\xfa@B"
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Gathered 180 bytes from app to send
to peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Wrote 180 bytes from app to socket
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Read 209 bytes from BIO Layer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 209
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_input_ssl( data size=183 )
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Wrote 183 bytes to BIO Layer, 0
left over
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Read 154 bytes from SSL socket for
app
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 <- @attach(18)
[name="a7455c6a-5c72-44ec-b64e-e54f8180dcf2-52be9d22-be30-4e78-b7d8-974fb7c3be58",
handle=1, role=true, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40)
[durable=0, timeout=0, dynamic=true], target=@target(41) [durable=0, timeout=0,
dynamic=false], initial-delivery-count=0, max-message-size=0]
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Application consumed 154 bytes from
peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_input_ssl() returning 183
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 ROUTER_CORE (trace) Core action 'link_first_attach'
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 -> @attach(18)
[name="a7455c6a-5c72-44ec-b64e-e54f8180dcf2-52be9d22-be30-4e78-b7d8-974fb7c3be58",
handle=1, role=false, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40)
[address="amqp:/_topo/0/router.10501/temp.pIXQzINTzqYAimB", durable=0,
timeout=0, dynamic=true], target=@target(41) [durable=0, timeout=0,
dynamic=false], initial-delivery-count=0, max-message-size=0]
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:RAW:
"\x00\x00\x00\xca\x02\x00\x00\x00\x00S\x12\xd0\x00\x00\x00\xba\x00\x00\x00\x0b\xa1Ia7455c6a-5c72-44ec-b64e-e54f8180dcf2-52be9d22-be30-4e78-b7d8-974fb7c3be58R\x01BP\x02P\x00\x00S(\xd0\x00\x00\x00A\x00\x00\x00\x0b\xa1/amqp:/_topo/0/router.10501/temp.pIXQzINTzqYAimBR\x00@R\x00A@@@@@@\x00S)\xd0\x00\x00\x00\x0d\x00\x00\x00\x07@R\x00@R\x00B@@@@R\x00S\x00"
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Gathered 202 bytes from app to send
to peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Wrote 202 bytes from app to socket
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Read 231 bytes from BIO Layer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 231
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_input_ssl( data size=468 )
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Wrote 468 bytes to BIO Layer, 0
left over
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Read 439 bytes from SSL socket for
app
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 <- @flow(19) [next-incoming-id=0,
incoming-window=2147483647, next-outgoing-id=0, outgoing-window=2147483647,
handle=1, delivery-count=0, link-credit=1, drain=false]
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 <- @transfer(20) [handle=0,
delivery-id=0, delivery-tag=b"1", message-format=0, settled=false, more=false]
(364)
"\x00Sp\xd0\x00\x00\x00\x0b\x00\x00\x00\x05BP\x04@BR\x00\x00Ss\xd0\x00\x00\x00S\x00\x00\x00\x0d@@@@\xa1/amqp:/_topo/0/router.10501/temp.pIXQzINTzqYAimBS\x01@@\x83\x00\x00\x00\x00\x00\x00\x00\x00\x83\x00\x00\x00\x00\x00\x00\x00\x00@R\x00@\x00St\xd1\x00\x00\x00b\x00\x00\x00\x06\xa1\x09operation\xa1\x06CREATE\xa1\x04type\xa1"org.apache.qpid.dispatch.connector\xa1\x04name\xa1\x19localhost.10305.connector\x00Sw\xd1\x00\x00\x00\x8c\x00\x00\x00\x0c\xa1\x0everifyHostName\xa1\x02no\xa1\x04addr\xa1\x09localhost\xa1\x0asslProfile\xa1\x10ssl-test-profile\xa1\x04role\xa1\x0froute-container\xa1\x04port\xa1\x0510305\xa1\x04name\xa1\x19localhost.10305.connector"
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Application consumed 439 bytes from
peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_input_ssl() returning 468
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 MESSAGE (trace) Received Message{
reply-to='amqp:/_topo/0/router.10501/temp.pIXQzINTzqYAimB'
body='\d1\00\00\00\8c\00\00\00 \a1\0everif'} on link
a7455c6a-5c72-44ec-b64e-e54f8180dcf2-$management
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 ROUTER_CORE (trace) Core action 'link_flow'
Wed Feb 1 11:54:54 2017 ROUTER_CORE (trace) Core action 'link_deliver'
Wed Feb 1 11:54:54 2017 ROUTER_CORE (trace) Core action 'send_to'
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 -> @flow(19) [next-incoming-id=1,
incoming-window=61, next-outgoing-id=0, outgoing-window=2147483647, handle=0,
delivery-count=1, link-credit=250, drain=false]
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:RAW:
"\x00\x00\x00'\x02\x00\x00\x00\x00S\x13\xd0\x00\x00\x00\x17\x00\x00\x00\x09R\x01R=R\x00p\x7f\xff\xff\xffR\x00R\x01R\xfa@B"
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 -> @disposition(21) [role=true,
first=0, last=0, settled=true, state=@accepted(36) []]
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:RAW:
"\x00\x00\x00&\x02\x00\x00\x00\x00S\x15\xd0\x00\x00\x00\x16\x00\x00\x00\x05AR\x00R\x00A\x00S$\xd0\x00\x00\x00\x04\x00\x00\x00\x00"
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Gathered 77 bytes from app to send
to peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Wrote 77 bytes from app to socket
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Read 106 bytes from BIO Layer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 106
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qdr_error_t, typeSize=24)
Wed Feb 1 11:54:54 2017 AGENT (debug) Remove connection entity: 1
Wed Feb 1 11:54:54 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qd_management_context_t,
typeSize=56)
Wed Feb 1 11:54:54 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=16, localFreeListMax=32,
totalAllocFromHeap=16, totalFreeToHeap=0, transferBatchSize=16,
type=org.apache.qpid.dispatch.allocator, typeName=qdr_query_t, typeSize=336)
Wed Feb 1 11:54:54 2017 AGENT (debug) Add entity:
AllocatorEntity(batchesRebalancedToGlobal=0, batchesRebalancedToThreads=0,
globalFreeListMax=0, heldByThreads=64, localFreeListMax=128,
totalAllocFromHeap=64, totalFreeToHeap=0, transferBatchSize=64,
type=org.apache.qpid.dispatch.allocator, typeName=qdr_address_config_t,
typeSize=56)
Wed Feb 1 11:54:54 2017 AGENT (debug) Add entity:
ConnectionEntity(container=a7455c6a-5c72-44ec-b64e-e54f8180dcf2, dir=in,
host=localhost:38827, identity=3, isAuthenticated=True, isEncrypted=True,
opened=True, properties={}, role=normal, sasl=EXTERNAL, ssl=True,
sslCipher=DHE-DSS-AES256-GCM-SHA384, sslProto=TLSv1/SSLv3, sslSsf=256,
type=org.apache.qpid.dispatch.connection,
user=C=US,ST=NC,L=Raleigh,OU=Dev,O=Client,CN=127.0.0.1)
Wed Feb 1 11:54:54 2017 AGENT (debug) Agent request Message(address=None,
properties={'operation': 'CREATE', 'type':
'org.apache.qpid.dispatch.connector', 'name': 'localhost.10305.connector'},
body={'verifyHostName': 'no', 'addr': 'localhost', 'sslProfile':
'ssl-test-profile', 'role': 'route-container', 'port': '10305', 'name':
'localhost.10305.connector'},
reply_to='amqp:/_topo/0/router.10501/temp.pIXQzINTzqYAimB', correlation_id=1L)
Wed Feb 1 11:54:54 2017 CONN_MGR (info) Configured Connector: localhost:10305
proto=any, role=route-container , sslProfile=ssl-test-profile
Wed Feb 1 11:54:54 2017 SERVER (trace) Connecting to localhost:10305
Wed Feb 1 11:54:54 2017 AGENT (debug) Add entity:
ConnectorEntity(addr=localhost, allowRedirect=True, cost=1, host=127.0.0.1,
identity=connector/127.0.0.1:10305:localhost.10305.connector,
idleTimeoutSeconds=16, maxFrameSize=65536, name=localhost.10305.connector,
port=10305, role=route-container, sslProfile=ssl-test-profile,
stripAnnotations=both, type=org.apache.qpid.dispatch.connector,
verifyHostName=0)
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Client SSL socket created.
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]: -> SASL
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Gathered 8 bytes from app to send
to peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Read 325 bytes from BIO Layer
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:process_output_ssl() returning 325
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 AGENT (debug) Agent response:
Message(address='amqp:/_topo/0/router.10501/temp.pIXQzINTzqYAimB',
properties={'statusDescription': 'Created', 'statusCode': 201},
body={'verifyHostName': False, u'cost': 1, 'addr': 'localhost',
u'allowRedirect': True, u'idleTimeoutSeconds': 16, u'maxFrameSize': 65536,
'host': '127.0.0.1', 'sslProfile': 'ssl-test-profile', 'role':
EnumValue('route-container', 2), u'stripAnnotations': EnumValue('both', 2),
'type': 'org.apache.qpid.dispatch.connector', 'port': '10305', u'identity':
'connector/127.0.0.1:10305:localhost.10305.connector', 'name':
'localhost.10305.connector'}, reply_to=None, correlation_id=1L)
Responding to:
Message(address=None, properties={'operation': 'CREATE', 'type':
'org.apache.qpid.dispatch.connector', 'name': 'localhost.10305.connector'},
body={'verifyHostName': 'no', 'addr': 'localhost', 'sslProfile':
'ssl-test-profile', 'role': 'route-container', 'type':
'org.apache.qpid.dispatch.connector', 'port': '10305', 'name':
'localhost.10305.connector'},
reply_to='amqp:/_topo/0/router.10501/temp.pIXQzINTzqYAimB', correlation_id=1L)
Wed Feb 1 11:54:54 2017 ROUTER_CORE (trace) Core action 'send_to'
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 MESSAGE (trace) Sending
Message{to='amqp:/_topo/0/router.10501/temp.pIXQzINTzqYAimB'
body='\d1\00\00\01`\00\00\00\1c\a1\0everif'} on link
a7455c6a-5c72-44ec-b64e-e54f8180dcf2-52be9d22-be30-4e78-b7d8-974fb7c3be58
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 -> @transfer(20) [handle=1,
delivery-id=0, delivery-tag=b"\x02\x00\x00\x00\x00\x00\x00\x00",
message-format=0, settled=true, more=false] (488)
"\x00Ss\xd0\x00\x00\x00;\x00\x00\x00\x06@@\xa1/amqp:/_topo/0/router.10501/temp.pIXQzINTzqYAimB@@U\x01\x00St\xd1\x00\x00\x005\x00\x00\x00\x04\xa1\x11statusDescription\xa1\x07Created\xa1\x0astatusCode\x81\x00\x00\x00\x00\x00\x00\x00\xc9\x00Sw\xd1\x00\x00\x01`\x00\x00\x00\x1c\xa1\x0everifyHostNameB\xa1\x04costU\x01\xa1\x04addr\xa1\x09localhost\xa1\x0dallowRedirectA\xa1\x12idleTimeoutSecondsU\x10\xa1\x0cmaxFrameSize\x81\x00\x00\x00\x00\x00\x01\x00\x00\xa1\x04host\xa1\x09127.0.0.1\xa1\x0asslProfile\xa1\x10ssl-test-profile\xa1\x04role\xa1\x0froute-container\xa1\x10stripAnnotations\xa1\x04both\xa1\x04type\xa1"org.apache.qpid.dispatch.connector\xa1\x04port\xa1\x0510305\xa1\x08identity\xa13connector/127.0.0.1:10305:localhost.10305.connector\xa1\x04name\xa1\x19localhost.10305.connector"
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:RAW:
"\x00\x00\x02\x10\x02\x00\x00\x00\x00S\x14\xd0\x00\x00\x00\x18\x00\x00\x00\x08R\x01R\x00\xa0\x08\x02\x00\x00\x00\x00\x00\x00\x00R\x00AB@@\x00Ss\xd0\x00\x00\x00;\x00\x00\x00\x06@@\xa1/amqp:/_topo/0/router.10501/temp.pIXQzINTzqYAimB@@U\x01\x00St\xd1\x00\x00\x005\x00\x00\x00\x04\xa1\x11statusDescription\xa1\x07Created\xa1\x0astatusCode\x81\x00\x00\x00\x00\x00\x00\x00\xc9\x00Sw\xd1\x00\x00\x01`\x00\x00\x00\x1c\xa1\x0everifyHostNameB\xa1\x04costU\x01\xa1\x04addr\xa1\x09localhost\xa1\x0dallowRedirectA\xa1\x12idleTimeoutSecondsU\x10\xa1\x0cmaxFrameSize\x81\x00\x00\x00\x00\x00\x01\x00\x00\xa1\x04host\xa1\x09127.0.0.1\xa1\x0asslProfile\xa1\x10ssl-test-profile\xa1\x04role\xa1\x0froute-container\xa1\x10stripAnnotations\xa1\x04both\xa1\x04type\xa1"org.apache.qpid.dispatch.connector\xa1\x04port\xa1\x0510305\xa1\x08identity\xa13connector/127.0.0.1:10305:localhost.10305.connector\xa1\x04name\xa1\x19localhost.10305.connector"
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Gathered 528 bytes from app to send
to peer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Wrote 528 bytes from app to socket
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Read 557 bytes from BIO Layer
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 557
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 ROUTER_CORE (trace) Core action 'link_flow'
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:process_input_ssl( data size=0 )
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:Lower layer closed - shutting down
BIO write side
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:ERROR amqp:connection:framing-error
SSL Failure: Unknown error.
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:0 -> @close(24) [error=@error(29)
[condition=:"amqp:connection:framing-error", description="SSL Failure: Unknown
error."]]
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:RAW:
"\x00\x00\x00]\x02\x00\x00\x00\x00S\x18\xd0\x00\x00\x00M\x00\x00\x00\x01\x00S\x1d\xd0\x00\x00\x00A\x00\x00\x00\x03\xa3\x1damqp:connection:framing-error\xa1\x1bSSL
Failure: Unknown error.@"
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]: <- EOS
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]: -> EOS
Wed Feb 1 11:54:54 2017 POLICY (debug) Connection 'localhost:38827' closed
with resources n_sessions=0, n_senders=0, n_receivers=0. nConnections= 0.
Wed Feb 1 11:54:54 2017 ROUTER_CORE (trace) Core action 'link_detach'
Wed Feb 1 11:54:54 2017 ROUTER_CORE (trace) Core action 'link_detach'
Wed Feb 1 11:54:54 2017 ROUTER_CORE (trace) Core action 'connection_closed'
Wed Feb 1 11:54:54 2017 SERVER (trace) [3]:SSL socket freed.
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:process_input_ssl( data size=3361 )
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Wrote 3361 bytes to BIO Layer, 0
left over
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:process_input_ssl() returning 3361
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Read 1659 bytes from BIO Layer
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:process_output_ssl() returning 1659
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 POLICY (trace) ALLOW Connection 'localhost:38829'
based on global connection count. nConnections= 1
Wed Feb 1 11:54:54 2017 SERVER (debug) Accepting incoming connection from
localhost:38829 to 0.0.0.0:10498
Wed Feb 1 11:54:54 2017 SERVER (trace) Configuring SSL on incoming connection
from localhost:38829 to 0.0.0.0:10498
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:Server SSL socket created.
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:SSL/TLS connection detected
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:process_input_ssl( data size=331 )
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:Wrote 331 bytes to BIO Layer, 0
left over
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:process_input_ssl() returning 331
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:Read 2221 bytes from BIO Layer
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:process_output_ssl() returning 2221
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:process_output_ssl() returning 0
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:process_input_ssl( data size=7 )
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:Wrote 7 bytes to BIO Layer, 0 left
over
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:error:140940E5:SSL
routines:ssl3_read_bytes:ssl handshake failure
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:ERROR amqp:connection:framing-error
SSL Failure: error:14094416:SSL routines:ssl3_read_bytes:sslv3 alert
certificate unknown
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]: <- EOS
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]: -> EOS
Wed Feb 1 11:54:54 2017 SERVER (trace) [4]:SSL socket freed.
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:process_input_ssl( data size=1892 )
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:Wrote 1892 bytes to BIO Layer, 0
left over
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:Detected read-blocked
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:process_input_ssl() returning 1892
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:Read 1042 bytes from BIO Layer
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:process_output_ssl() returning 1042
Wed Feb 1 11:54:54 2017 SERVER (trace) [5]:process_output_ssl() returning 0
Wed Feb 1 11:54:55 2017 ROUTER_CORE (trace) Core action 'send_to'
Wed Feb 1 11:54:55 2017 ROUTER_HELLO (trace) SENT: HELLO(id=router.10501
area=0 inst=1485946492 seen=[])
Wed Feb 1 11:54:55 2017 SERVER (trace) [5]:process_output_ssl() returning 0
Wed Feb 1 11:54:55 2017 SERVER (trace) [5]:process_output_ssl() returning 0
Wed Feb 1 11:54:55 2017 SERVER (trace) [5]:process_output_ssl() returning 0
Wed Feb 1 11:54:55 2017 SERVER (trace) [5]:process_input_ssl( data size=37 )
Wed Feb 1 11:54:55 2017 SERVER (trace) [5]:Wrote 37 bytes to BIO Layer, 0 left
over
Wed Feb 1 11:54:55 2017 SERVER (trace) [5]:Read 8 bytes from SSL socket for app
Wed Feb 1 11:54:55 2017 SERVER (trace) [5]:AMQP SASL layer detected
Wed Feb 1 11:54:55 2017 SERVER (trace) [5]: <- SASL
Wed Feb 1 11:54:55 2017 SERVER (trace) [5]:Application consumed 8 bytes from
peer
Wed Feb 1 11:54:55 2017 SERVER (trace) [5]:ERROR amqp:connection:framing-error
SSL Failure: error:140E0197:SSL routines:SSL_shutdown:shutdown while in init
Wed Feb 1 11:54:55 2017 SERVER (trace) [5]: <- EOS
Wed Feb 1 11:54:55 2017 SERVER (trace) [5]: -> EOS
Wed Feb 1 11:54:55 2017 POLICY (debug) Connection 'localhost:38829' closed
with resources n_sessions=0, n_senders=0, n_receivers=0. nConnections= 0.
Wed Feb 1 11:54:55 2017 SERVER (trace) [5]:SSL socket freed.
Wed Feb 1 11:54:56 2017 ROUTER_CORE (trace) Core action 'send_to'
Wed Feb 1 11:54:56 2017 ROUTER_HELLO (trace) SENT: HELLO(id=router.10501
area=0 inst=1485946492 seen=[])
Wed Feb 1 11:54:57 2017 ROUTER_HELLO (trace) SENT: HELLO(id=router.10501
area=0 inst=1485946492 seen=[])
Wed Feb 1 11:54:57 2017 ROUTER_CORE (trace) Core action 'send_to'
Wed Feb 1 11:54:58 2017 ROUTER_CORE (trace) Core action 'send_to'
Wed Feb 1 11:54:58 2017 ROUTER_HELLO (trace) SENT: HELLO(id=router.10501
area=0 inst=1485946492 seen=[])
Wed Feb 1 11:54:59 2017 ROUTER_CORE (trace) Core action 'send_to'
Wed Feb 1 11:54:59 2017 ROUTER_HELLO (trace) SENT: HELLO(id=router.10501
area=0 inst=1485946492 seen=[])
Wed Feb 1 11:54:59 2017 SERVER (trace) Connecting to localhost:10305
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:Client SSL socket created.
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]: -> SASL
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:Gathered 8 bytes from app to send
to peer
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:Detected read-blocked
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:Read 325 bytes from BIO Layer
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:Detected read-blocked
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:process_output_ssl() returning 325
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:Detected read-blocked
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:process_output_ssl() returning 0
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:Detected read-blocked
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:process_output_ssl() returning 0
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:Detected read-blocked
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:process_output_ssl() returning 0
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:Detected read-blocked
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:process_output_ssl() returning 0
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:process_input_ssl( data size=3361 )
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:Wrote 3361 bytes to BIO Layer, 0
left over
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:Detected read-blocked
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:process_input_ssl() returning 3361
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:Detected read-blocked
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:Read 1659 bytes from BIO Layer
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:Detected read-blocked
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:process_output_ssl() returning 1659
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:Detected read-blocked
Wed Feb 1 11:54:59 2017 SERVER (trace) [6]:process_output_ssl() returning 0
Wed Feb 1 11:55:00 2017 ROUTER_CORE (trace) Core action 'send_to'
Wed Feb 1 11:55:00 2017 ROUTER_HELLO (trace) SENT: HELLO(id=router.10501
area=0 inst=1485946492 seen=[])
Wed Feb 1 11:55:00 2017 SERVER (trace) [6]:Detected read-blocked
Wed Feb 1 11:55:00 2017 SERVER (trace) [6]:process_output_ssl() returning 0
Wed Feb 1 11:55:00 2017 SERVER (trace) [6]:Detected read-blocked
Wed Feb 1 11:55:00 2017 SERVER (trace) [6]:process_output_ssl() returning 0
Wed Feb 1 11:55:00 2017 SERVER (trace) [6]:Detected read-blocked
Wed Feb 1 11:55:00 2017 SERVER (trace) [6]:process_output_ssl() returning 0
Wed Feb 1 11:55:00 2017 SERVER (trace) [6]:Detected read-blocked
Wed Feb 1 11:55:00 2017 SERVER (trace) [6]:process_output_ssl() returning 0
Wed Feb 1 11:55:00 2017 SERVER (trace) [6]:process_input_ssl( data size=7 )
Wed Feb 1 11:55:00 2017 SERVER (trace) [6]:Wrote 7 bytes to BIO Layer, 0 left
over
Wed Feb 1 11:55:00 2017 SERVER (trace) [6]:error:140940E5:SSL
routines:ssl3_read_bytes:ssl handshake failure
Wed Feb 1 11:55:00 2017 SERVER (trace) [6]:ERROR amqp:connection:framing-error
SSL Failure: error:14094416:SSL routines:ssl3_read_bytes:sslv3 alert
certificate unknown
Wed Feb 1 11:55:00 2017 SERVER (trace) [6]: <- EOS
Wed Feb 1 11:55:00 2017 SERVER (trace) [6]: -> EOS
Wed Feb 1 11:55:00 2017 SERVER (trace) [6]:SSL socket freed.
Wed Feb 1 11:55:01 2017 ROUTER_CORE (trace) Core action 'send_to'
Wed Feb 1 11:55:01 2017 ROUTER_HELLO (trace) SENT: HELLO(id=router.10501
area=0 inst=1485946492 seen=[])
Wed Feb 1 11:55:02 2017 ROUTER_CORE (trace) Core action 'send_to'
Wed Feb 1 11:55:02 2017 ROUTER_HELLO (trace) SENT: HELLO(id=router.10501
area=0 inst=1485946492 seen=[])
Wed Feb 1 11:55:03 2017 ROUTER_CORE (trace) Core action 'send_to'
Wed Feb 1 11:55:03 2017 ROUTER_HELLO (trace) SENT: HELLO(id=router.10501
area=0 inst=1485946492 seen=[])
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
