OK, strace showed a problem writing to the log file. Perms changed and now
we have some output…
cat /var/log/qdrouterd.log
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(name=log/ROUTER_LS, identity=log/ROUTER_LS,
type=org.apache.qpid.dispatch.log, enable=default, module=ROUTER_LS)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(name=log/ROUTER_MA, identity=log/ROUTER_MA,
type=org.apache.qpid.dispatch.log, enable=default, module=ROUTER_MA)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(name=log/DISPATCH, identity=log/DISPATCH,
type=org.apache.qpid.dispatch.log, enable=default, module=DISPATCH)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(name=log/ROUTER_HELLO, identity=log/ROUTER_HELLO,
type=org.apache.qpid.dispatch.log, enable=default, module=ROUTER_HELLO)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity: Entity(name=log/SERVER,
identity=log/SERVER, type=org.apache.qpid.dispatch.log, enable=default,
module=SERVER)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(name=log/CONTAINER, identity=log/CONTAINER,
type=org.apache.qpid.dispatch.log, enable=default, module=CONTAINER)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity: Entity(name=log/AGENT,
identity=log/AGENT, type=org.apache.qpid.dispatch.log, enable=default,
module=AGENT)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity: Entity(name=log/ERROR,
identity=log/ERROR, type=org.apache.qpid.dispatch.log, enable=default,
module=ERROR)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity: Entity(name=log/ROUTER,
identity=log/ROUTER, type=org.apache.qpid.dispatch.log, enable=default,
module=ROUTER)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity: Entity(name=log/MESSAGE,
identity=log/MESSAGE, type=org.apache.qpid.dispatch.log, enable=default,
module=MESSAGE)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity: Entity(name=log/CONFIG,
identity=log/CONFIG, type=org.apache.qpid.dispatch.log, enable=default,
module=CONFIG)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(name=container/katello.server, identity=container/katello.server,
type=org.apache.qpid.dispatch.container, containerName=katello.server,
workerThreads=2)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(type=org.apache.qpid.dispatch.router, raIntervalFlux=4,
helloInterval=1, area=0, helloMaxAge=3, remoteLsMaxAge=60,
routerId=katello.server, raInterval=30, mode=interior, mobileAddrMaxAge=60)
Wed Aug 19 12:32:43 2015 SERVER (info) Container Name: katello.server
Wed Aug 19 12:32:43 2015 ROUTER (info) Router started in Interior mode,
area=0 id=katello.server
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(type=org.apache.qpid.dispatch.allocator, heldByThreads=16,
typeSize=2104, transferBatchSize=16, globalFreeListMax=0,
batchesRebalancedToGlobal=0, typeName=qd_log_entry_t,
batchesRebalancedToThreads=0, totalFreeToHeap=0, totalAllocFromHeap=16,
localFreeListMax=32)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(type=org.apache.qpid.dispatch.allocator, heldByThreads=64,
typeSize=88, transferBatchSize=64, globalFreeListMax=0,
batchesRebalancedToGlobal=0, typeName=qd_field_iterator_t,
batchesRebalancedToThreads=0, totalFreeToHeap=0, totalAllocFromHeap=64,
localFreeListMax=128)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(type=org.apache.qpid.dispatch.allocator, heldByThreads=64,
typeSize=32, transferBatchSize=64, globalFreeListMax=0,
batchesRebalancedToGlobal=0, typeName=qd_hash_item_t,
batchesRebalancedToThreads=0, totalFreeToHeap=0, totalAllocFromHeap=64,
localFreeListMax=128)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(type=org.apache.qpid.dispatch.allocator, heldByThreads=64,
typeSize=56, transferBatchSize=64, globalFreeListMax=0,
batchesRebalancedToGlobal=0, typeName=qd_node_t,
batchesRebalancedToThreads=0, totalFreeToHeap=0, totalAllocFromHeap=64,
localFreeListMax=128)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(type=org.apache.qpid.dispatch.allocator, heldByThreads=64,
typeSize=136, transferBatchSize=64, globalFreeListMax=0,
batchesRebalancedToGlobal=0, typeName=qd_bitmask_t,
batchesRebalancedToThreads=0, totalFreeToHeap=0, totalAllocFromHeap=64,
localFreeListMax=128)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(type=org.apache.qpid.dispatch.allocator, heldByThreads=64,
typeSize=56, transferBatchSize=64, globalFreeListMax=0,
batchesRebalancedToGlobal=0, typeName=qd_timer_t,
batchesRebalancedToThreads=0, totalFreeToHeap=0, totalAllocFromHeap=64,
localFreeListMax=128)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(type=org.apache.qpid.dispatch.allocator, heldByThreads=64,
typeSize=216, transferBatchSize=64, globalFreeListMax=0,
batchesRebalancedToGlobal=0, typeName=qd_address_t,
batchesRebalancedToThreads=0, totalFreeToHeap=0, totalAllocFromHeap=64,
localFreeListMax=128)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(type=org.apache.qpid.dispatch.allocator, heldByThreads=64,
typeSize=16, transferBatchSize=64, globalFreeListMax=0,
batchesRebalancedToGlobal=0, typeName=qd_hash_handle_t,
batchesRebalancedToThreads=0, totalFreeToHeap=0, totalAllocFromHeap=64,
localFreeListMax=128)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(type=org.apache.qpid.dispatch.router.address, subscriberCount=0,
deliveriesEgress=0, deliveriesIngress=0, remoteCount=0, inProcess=False,
deliveriesFromContainer=0, deliveriesTransit=0, key=Lqdrouter,
deliveriesToContainer=0)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(type=org.apache.qpid.dispatch.router.address, subscriberCount=0,
deliveriesEgress=0, deliveriesIngress=0, remoteCount=0, inProcess=False,
deliveriesFromContainer=0, deliveriesTransit=0, key=Lqdrouter.ma,
deliveriesToContainer=0)
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(type=org.apache.qpid.dispatch.router.address, subscriberCount=0,
deliveriesEgress=0, deliveriesIngress=0, remoteCount=0, inProcess=False,
deliveriesFromContainer=0, deliveriesTransit=0, key=Lqdhello,
deliveriesToContainer=0)
Wed Aug 19 12:32:43 2015 AGENT (info) Activating management agent on
$management
Wed Aug 19 12:32:43 2015 ROUTER (info) In-Process Address Registered:
$management
Wed Aug 19 12:32:43 2015 ROUTER (info) In-Process Address Registered:
$management
Wed Aug 19 12:32:43 2015 ROUTER (info) In-Process Address Registered:
qdrouter
Wed Aug 19 12:32:43 2015 ROUTER (info) In-Process Address Registered:
qdrouter.ma
Wed Aug 19 12:32:43 2015 ROUTER (info) In-Process Address Registered:
qdhello
Wed Aug 19 12:32:43 2015 ROUTER (info) Router Engine Instantiated:
id=katello.server instance=1439983963 max_routers=1024
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(name=fixedAddress/0, identity=fixedAddress/0,
type=org.apache.qpid.dispatch.fixedAddress, fanout=single, prefix=/closest,
bias=closest)
Wed Aug 19 12:32:43 2015 ROUTER (info) Configured Address: prefix=/closest
phase=0 fanout=QD_SCHEMA_FIXEDADDRESS_FANOUT_SINGLE
bias=QD_SCHEMA_FIXEDADDRESS_BIAS_CLOSEST
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(name=fixedAddress/1, identity=fixedAddress/1,
type=org.apache.qpid.dispatch.fixedAddress, fanout=single, prefix=/unicast,
bias=closest)
Wed Aug 19 12:32:43 2015 ROUTER (info) Configured Address: prefix=/unicast
phase=0 fanout=QD_SCHEMA_FIXEDADDRESS_FANOUT_SINGLE
bias=QD_SCHEMA_FIXEDADDRESS_BIAS_CLOSEST
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(name=fixedAddress/2, identity=fixedAddress/2,
type=org.apache.qpid.dispatch.fixedAddress, fanout=single,
prefix=/exclusive, bias=closest)
Wed Aug 19 12:32:43 2015 ROUTER (info) Configured Address:
prefix=/exclusive phase=0 fanout=QD_SCHEMA_FIXEDADDRESS_FANOUT_SINGLE
bias=QD_SCHEMA_FIXEDADDRESS_BIAS_CLOSEST
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(name=fixedAddress/3, identity=fixedAddress/3,
type=org.apache.qpid.dispatch.fixedAddress, fanout=multiple,
prefix=/multicast, bias=closest)
Wed Aug 19 12:32:43 2015 ROUTER (info) Configured Address:
prefix=/multicast phase=0 fanout=QD_SCHEMA_FIXEDADDRESS_FANOUT_MULTIPLE
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(name=fixedAddress/4, identity=fixedAddress/4,
type=org.apache.qpid.dispatch.fixedAddress, fanout=multiple,
prefix=/broadcast, bias=closest)
Wed Aug 19 12:32:43 2015 ROUTER (info) Configured Address:
prefix=/broadcast phase=0 fanout=QD_SCHEMA_FIXEDADDRESS_FANOUT_MULTIPLE
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(name=fixedAddress/5, identity=fixedAddress/5,
type=org.apache.qpid.dispatch.fixedAddress, fanout=multiple, prefix=/,
bias=closest)
Wed Aug 19 12:32:43 2015 ROUTER (info) Configured Address: prefix=/ phase=0
fanout=QD_SCHEMA_FIXEDADDRESS_FANOUT_MULTIPLE
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(name=listener/0.0.0.0:5647, identity=listener/0.0.0.0:5647,
type=org.apache.qpid.dispatch.listener, requirePeerAuth=True,
allowNoSasl=False, addr=0.0.0.0, saslMechanisms=ANONYMOUS,
maxFrameSize=65536, role=normal,
certDb=/etc/pki/katello/certs/katello-default-ca.crt, allowUnsecured=False,
certFile=/etc/pki/katello/qpid_router_server.crt,
keyFile=/etc/pki/katello/qpid_router_server.key, port=5647)
Wed Aug 19 12:32:43 2015 CONN_MGR (info) Configured Listener: 0.0.0.0:5647
role=normal
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(name=listener/0.0.0.0:5646, identity=listener/0.0.0.0:5646,
type=org.apache.qpid.dispatch.listener,
certFile=/etc/pki/katello/qpid_router_server.crt, addr=0.0.0.0,
saslMechanisms=ANONYMOUS, maxFrameSize=65536, requirePeerAuth=True,
certDb=/etc/pki/katello/certs/katello-default-ca.crt, allowUnsecured=False,
allowNoSasl=False, role=inter-router,
keyFile=/etc/pki/katello/qpid_router_server.key, port=5646)
Wed Aug 19 12:32:43 2015 CONN_MGR (info) Configured Listener: 0.0.0.0:5646
role=inter-router
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity: Entity(name=broker,
identity=connector/katello.server:5671,
type=org.apache.qpid.dispatch.connector,
certFile=/etc/pki/katello/qpid_router_client.crt, addr=katello.server,
allowRedirect=True, saslMechanisms=ANONYMOUS, maxFrameSize=65536,
role=on-demand, certDb=/etc/pki/katello/certs/katello-default-ca.crt,
keyFile=/etc/pki/katello/qpid_router_client.key, port=5671)
Wed Aug 19 12:32:43 2015 CONN_MGR (info) Configured on-demand connector:
katello.server:5671 name=broker
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(name=linkRoutePattern/0, identity=linkRoutePattern/0,
type=org.apache.qpid.dispatch.linkRoutePattern, connector=broker,
prefix=pulp.)
Wed Aug 19 12:32:43 2015 ROUTER (info) Configured Link-route-pattern:
prefix=pulp. connector=broker
Wed Aug 19 12:32:43 2015 AGENT (debug) Add entity:
Entity(name=linkRoutePattern/1, identity=linkRoutePattern/1,
type=org.apache.qpid.dispatch.linkRoutePattern, connector=broker,
prefix=qmf.)
Wed Aug 19 12:32:43 2015 ROUTER (info) Configured Link-route-pattern:
prefix=qmf. connector=broker
Wed Aug 19 12:32:43 2015 SERVER (info) Operational, 2 Threads Running
Wed Aug 19 12:32:43 2015 CONN_MGR (info) Starting on-demand connector:
broker
Wed Aug 19 12:32:44 2015 ROUTER (info) Activating Prefix 'pulp.' for routed
links to 'broker'
Wed Aug 19 12:32:44 2015 ROUTER (info) Activating Prefix 'qmf.' for routed
links to 'broker'
Running a tcpdump capture on the client and katello server after asking for
Katello to 'update-all' or install one package shows no traffic.
/var/log/messages only shows:
Aug 19 11:24:44 katello.server pulp:
gofer.messaging.adapter.qpid.connection:INFO: connecting: URL:
ssl://katello.server|SSL: ca:
/etc/pki/katello/certs/katello-default-ca.crt|key: None|certificate:
/etc/pki/katello/qpid_client_striped.crt|host-validation: False
Aug 19 11:24:44 katello.server pulp:
gofer.messaging.adapter.qpid.connection:INFO: connected:
ssl://katello.server
When asked to install one package the job moves (in 20 seconds) to:
Host did not respond within 20 seconds. Is katello-agent installed and
goferd running on the Host?
When asked to 'update-all' the task moves immediately to 50% and the
poll_attempt count increases:
Action:
Actions::Pulp::Consumer::ContentUpdate
Input:
{"consumer_uuid"=>"90a34ad1-d153-4905-b57b-c1c9442003a7",
"type"=>"rpm",
"args"=>[],
"remote_user"=>"admin-e8886651",
"remote_cp_user"=>"admin",
"locale"=>"en-GB"}
Output:
{"pulp_tasks"=>
[{"exception"=>nil,
"task_type"=>nil,
"_href"=>"/pulp/api/v2/tasks/f78143cb-3be5-44e6-825d-037e0ef1c363/",
"task_id"=>"f78143cb-3be5-44e6-825d-037e0ef1c363",
"tags"=>
["pulp:consumer:90a34ad1-d153-4905-b57b-c1c9442003a7",
"pulp:action:unit_update"],
"finish_time"=>nil,
"_ns"=>"task_status",
"start_time"=>nil,
"traceback"=>nil,
"spawned_tasks"=>[],
"progress_report"=>{},
"queue"=>"agent.dq",
"state"=>"waiting",
"worker_name"=>"agent",
"result"=>nil,
"error"=>nil,
"_id"=>{"$oid"=>"55d4596c388e58985eff62b7"},
"id"=>"55d4596c388e58985eff62b7"}],
"poll_attempts"=>{"total"=>242, "failed"=>0}}
···
On Thursday, 13 August 2015 13:35:59 UTC+1, JC wrote:
>
> The katello-agent and subscription manager install on a the (CentOS6)
> client, and the client can use yum to update itself from Katello, but tasks
> triggered from Katello fail.
>
> Host did not respond within 20 seconds. Is katello-agent installed and goferd running on the Host?
>
>
> I've implemented:
>
> http://projects.theforeman.org/issues/10350 /
> https://bugzilla.redhat.com/show_bug.cgi?id=1217828
>
> # ll /etc/pki/katello/qpid_router*
> -rw-r-----. 1 qdrouterd qdrouterd 5579 Jul 28 15:32
> /etc/pki/katello/qpid_router_client.crt
> -rw-r-----. 1 qdrouterd qdrouterd 1679 Jul 28 15:31
> /etc/pki/katello/qpid_router_client.key
> -rw-r-----. 1 qdrouterd qdrouterd 5579 Jul 28 15:31
> /etc/pki/katello/qpid_router_server.crt
> -rw-r-----. 1 qdrouterd qdrouterd 1675 Jul 28 15:31
> /etc/pki/katello/qpid_router_server.key
>
> But don't see an improvement. I'm also not using ipv6*, so haven't
> modified /etc/qpid-dispatch/qdrouterd.conf (as David LeVene did).
>
> *Well the 'advanced' section for the content host within Katello shows ::1
> (localhost).
>
> Of course I do see, on the Katello server, 5647 being listened to and the
> firewall is open (and turned off for testing on the client):
>
> # netstat -pntl|grep 5647
> tcp 0 0 0.0.0.0:5647 0.0.0.0:*
> LISTEN 48646/qdrouterd
>
> # iptables -nL | grep 5647
> ACCEPT tcp -- 0.0.0.0/0 0.0.0.0/0 multiport
> dports 22,80,443,5647,5671,8140
>
> tcpdump shows a short conversation between server and client:
>
> IP myserver.50035 > mytestclient.5647: tcp 0
> IP mytestclient.5647 > myserver.50035: tcp 0
> IP myserver.50035 > mytestclient.5647: tcp 0
> IP myserver.50035 > mytestclient.5647: tcp 304
> IP mytestclient.5647 > myserver.50035: tcp 0
> IP mytestclient.5647 > myserver.50035: tcp 3665
> IP myserver.50035 > mytestclient.5647: tcp 0
>
> Aug 13 12:50:20 mytestclient goferd: [INFO][Thread-1]
> gofer.messaging.adapter.proton.connection:100 - connecting: URL:
> amqps://myserver.mydomain:5647|SSL: ca:
> /etc/rhsm/ca/katello-server-ca.pem|key: None|certificate:
> /etc/pki/consumer/bundle.pem|host-validation: None
>
> Aug 13 12:50:20 mytestclient goferd: [INFO][Thread-1] root:481 -
> connecting to myserver.mydomain:5647...
>
> Aug 13 12:50:20 mytestclient goferd: [INFO][Thread-1] root:521 -
> Disconnected
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 -
> amqps://myserver.mydomain:5647
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 - Traceback (most recent call
> last):
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 - File
> "/usr/lib/python2.6/site-packages/gofer/messaging/adapter/proton/connection.py",
> line 102, in open
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 - self._impl =
> BlockingConnection(url, ssl_domain=domain)
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 - File
> "/usr/lib64/python2.6/site-packages/proton/utils.py", line 200, in __init__
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 - msg="Opening
> connection")
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 - File
> "/usr/lib64/python2.6/site-packages/proton/utils.py", line 231, in wait
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 - self.container.process()
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 - File
> "/usr/lib64/python2.6/site-packages/proton/__init__.py", line 3729, in
> dispatch
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 -
> ev.dispatch(self.handler)
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 - File
> "/usr/lib64/python2.6/site-packages/proton/__init__.py", line 3654, in
> dispatch
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 - result =
> dispatch(handler, type.method, self)
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 - File
> "/usr/lib64/python2.6/site-packages/proton/__init__.py", line 3543, in
> dispatch
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 - return m(*args)
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 - File
> "/usr/lib64/python2.6/site-packages/proton/utils.py", line 257, in
> on_transport_tail_closed
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 -
> self.on_transport_closed(event)
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 - File
> "/usr/lib64/python2.6/site-packages/proton/utils.py", line 261, in
> on_transport_closed
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 - raise
> ConnectionException("Connection %s disconnected" % self.url);
>
> Aug 13 12:50:20 mytestclient goferd: [ERROR][Thread-1]
> gofer.messaging.adapter.proton.connection:106 - ConnectionException:
> Connection amqps://myserver.mydomain:5647 disconnected
>
> Aug 13 12:50:20 mytestclient goferd: [INFO][Thread-1]
> gofer.messaging.adapter.proton.connection:108 - retry in 29 seconds
>
>
> Can anyone help? Many thanks.
>