Katello 2.4.2 -> 3.0.0 upgrade broke katello-agent everywhere

Support
1

Hi Everyone,

Having a few post-update blues and I'm out of things I can think of to look
at. For the most part everything went pretty well during the update.
However, while updating my capsules I noticed that A. posting package
profiles started to take forever and B. more importantly goferd seemed to
not be working:

I noticed my pulp repos weren't syncing and I couldn't issue any commands,
so I hoped on a box on the same subnet as the katello server and checked
out the katello-agent.

Jun 28 21:47:11 ipatest.internal systemd[1]: Starting Gofer Agent…
> Jun 28 21:47:11 ipatest.internal goferd[13681]: [INFO][Thread-1]
> gofer.rmi.store:114 - Using: /var/lib/gofer/messaging/pending/demo
> Jun 28 21:47:11 ipatest.internal goferd[13681]: [WARNING][MainThread]
> gofer.agent.plugin:639 - plugin:demo, DISABLED
> Jun 28 21:47:11 ipatest.internal goferd[13681]: [INFO][Thread-2]
> gofer.rmi.store:114 - Using: /var/lib/gofer/messaging/pending/katelloplugin
> Jun 28 21:47:11 ipatest.internal goferd[13681]: [INFO][Thread-3]
> gofer.rmi.store:114 - Using: /var/lib/gofer/messaging/pending/katelloplugin
> Jun 28 21:47:11 ipatest.internal goferd[13681]: [INFO][MainThread]
> gofer.agent.plugin:682 - plugin:katelloplugin loaded using:
> /usr/lib/gofer/plugins/katelloplugin.py
> Jun 28 21:47:11 ipatest.internal goferd[13681]: [INFO][MainThread]
> rhsm.connection:778 - Connection built: host=katello.internal port=443
> handler=/rhsm auth=identity_cert ca_dir=/etc/rhsm/ca/ verify
> Jun 28 21:47:17 ipatest.internal goferd[13681]: [INFO][MainThread]
> katelloplugin:177 - Using /etc/rhsm/ca/katello-default-ca.pem as the ca
> cert for qpid connection
> Jun 28 21:47:17 ipatest.internal goferd[13681]: [INFO][MainThread]
> rhsm.connection:778 - Connection built: host=katello.internal port=443
> handler=/rhsm auth=identity_cert ca_dir=/etc/rhsm/ca/ verify
> Jun 28 21:47:17 ipatest.internal goferd[13681]: Loaded plugins:
> fastestmirror, product-id
> Jun 28 21:47:17 ipatest.internal goferd[13681]: [INFO][MainThread]
> katelloplugin:352 - reporting: {'enabled_repos': {'repos': [{'baseurl':
> ['https://katello.internal/pulp/repos/Resilient_Systems/pro
> Jun 28 21:47:42 ipatest.internal goferd[13681]: [INFO][MainThread]
> gofer.agent.main:87 - agent started.
> Jun 28 21:47:42 ipatest.internal goferd[13681]: [INFO][worker-0]
> gofer.messaging.adapter.connect:28 - connecting:
> proton+amqps://katello.internal:5647
> Jun 28 21:47:42 ipatest.internal goferd[13681]: [INFO][worker-0]
> gofer.messaging.adapter.proton.connection:87 - open: URL:
> amqps://katello.internal:5647|SSL: ca: /etc/rhsm/ca/katello-default-ca.pem|
> Jun 28 21:47:42 ipatest.internal goferd[13681]: [INFO][worker-0] root:510
> - connecting to katello.internal:5647…
> Jun 28 21:47:52 ipatest.internal goferd[13681]: [INFO][worker-0] root:559
> - Disconnected
> Jun 28 21:47:52 ipatest.internal goferd[13681]: [ERROR][worker-0]
> gofer.messaging.adapter.connect:33 - connect:
> proton+amqps://katello.internal:5647, failed: Connection
> amqps://katello.internal.resi
> Jun 28 21:47:52 ipatest.internal goferd[13681]: [INFO][worker-0]
> gofer.messaging.adapter.connect:35 - retry in 10 seconds
> Jun 28 21:48:02 ipatest.internal goferd[13681]: [INFO][worker-0]
> gofer.messaging.adapter.connect:28 - connecting:
> proton+amqps://katello.internal:5647
> Jun 28 21:48:03 ipatest.internal goferd[13681]: [INFO][worker-0]
> gofer.messaging.adapter.proton.connection:87 - open: URL:
> amqps://katello.internal:5647|SSL: ca: /etc/rhsm/ca/katello-default-ca.pem|
> Jun 28 21:48:03 ipatest.internal goferd[13681]: [INFO][worker-0] root:510
> - connecting to katello.internal:5647…
> Jun 28 21:48:13 ipatest.internal goferd[13681]: [INFO][worker-0] root:559
> - Disconnected
> Jun 28 21:48:13 ipatest.internal goferd[13681]: [ERROR][worker-0]
> gofer.messaging.adapter.connect:33 - connect:
> proton+amqps://katello.internal:5647, failed: Connection
> amqps://katello.internal.resi
> Jun 28 21:48:13 ipatest.internal goferd[13681]: [INFO][worker-0]
> gofer.messaging.adapter.connect:35 - retry in 12 seconds

There's no firewall involved here and I am able to see a connection
establish and then go away on 5647 on both machines. They are able to
telnet to each other on 5647 as well, and I was able to repro with selinux
off on both and firewalld off.

Curious, I hopped over to katello.internal and enabled / looked at the
qdrouterd log:

> Tue Jun 28 21:47:42 2016 SERVER (debug) Accepting incoming connection from
> ipatest.internal:55332 to 0.0.0.0:5647
> Tue Jun 28 21:47:42 2016 SERVER (trace) Configuring SSL on incoming
> connection from ipatest.internal:55332 to 0.0.0.0:5647
> Tue Jun 28 21:47:42 2016 ROUTER_HELLO (trace) SENT:
> HELLO(id=katello.internal area=0 inst=1467138250 seen=[])
> Tue Jun 28 21:47:43 2016 ROUTER_HELLO (trace) SENT:
> HELLO(id=katello.internal area=0 inst=1467138250 seen=[])
> Tue Jun 28 21:47:45 2016 ROUTER_HELLO (trace) SENT:
> HELLO(id=katello.internal area=0 inst=1467138250 seen=[])
> Tue Jun 28 21:47:46 2016 ROUTER_HELLO (trace) SENT:
> HELLO(id=katello.internal area=0 inst=1467138250 seen=[])
> Tue Jun 28 21:47:47 2016 ROUTER_HELLO (trace) SENT:
> HELLO(id=katello.internal area=0 inst=1467138250 seen=[])

So I thought I'd check ssl, from the ipatest box I did a:
openssl s_client -connect katello.internal:5647 -cert
/etc/pki/consumer/bundle.pem -key /etc/pki/consumer/bundle.pem -CAfile
/etc/rhsm/ca/katello-default-ca.pem -state -debug
and everything seemed to come back OK.

Thought maybe it was something underlying in qpidd, and I did find errors
in that log, but not sure if they're related:

> Jun 28 15:25:35 katello.internal qpidd[18457]: 2016-06-28 15:25:35
> [System] error Connection qpid No protocol received closing
> Jun 28 15:25:35 katello.internal qpidd[18457]: 2016-06-28 15:25:35
> [System] error Connection qpid No protocol received closing
> Jun 28 15:26:20 katello.internal qpidd[18457]: 2016-06-28 15:26:20
> [System] error Connection qpid No protocol received closing
> Jun 28 15:26:20 katello.internal qpidd[18457]: 2016-06-28 15:26:20
> [System] error Connection qpid No protocol received closing
>

The agents show as up as active, but any commands fail.

Anyone have any ideas?

Best,
–Nick Cammorato

2

Good afternoon,

Any news on this front? I'm seeing the same errors within my journal for
gofer.

··· On Wednesday, June 29, 2016 at 2:20:00 AM UTC-4, Nick Cammorato wrote: > > Hi Everyone, > > Having a few post-update blues and I'm out of things I can think of to > look at. For the most part everything went pretty well during the update. > However, while updating my capsules I noticed that A. posting package > profiles started to take forever and B. more importantly goferd seemed to > not be working: > > I noticed my pulp repos weren't syncing and I couldn't issue any commands, > so I hoped on a box on the same subnet as the katello server and checked > out the katello-agent. > > Jun 28 21:47:11 ipatest.internal systemd[1]: Starting Gofer Agent... >> Jun 28 21:47:11 ipatest.internal goferd[13681]: [INFO][Thread-1] >> gofer.rmi.store:114 - Using: /var/lib/gofer/messaging/pending/demo >> Jun 28 21:47:11 ipatest.internal goferd[13681]: [WARNING][MainThread] >> gofer.agent.plugin:639 - plugin:demo, DISABLED >> Jun 28 21:47:11 ipatest.internal goferd[13681]: [INFO][Thread-2] >> gofer.rmi.store:114 - Using: /var/lib/gofer/messaging/pending/katelloplugin >> Jun 28 21:47:11 ipatest.internal goferd[13681]: [INFO][Thread-3] >> gofer.rmi.store:114 - Using: /var/lib/gofer/messaging/pending/katelloplugin >> Jun 28 21:47:11 ipatest.internal goferd[13681]: [INFO][MainThread] >> gofer.agent.plugin:682 - plugin:katelloplugin loaded using: >> /usr/lib/gofer/plugins/katelloplugin.py >> Jun 28 21:47:11 ipatest.internal goferd[13681]: [INFO][MainThread] >> rhsm.connection:778 - Connection built: host=katello.internal port=443 >> handler=/rhsm auth=identity_cert ca_dir=/etc/rhsm/ca/ verify >> Jun 28 21:47:17 ipatest.internal goferd[13681]: [INFO][MainThread] >> katelloplugin:177 - Using /etc/rhsm/ca/katello-default-ca.pem as the ca >> cert for qpid connection >> Jun 28 21:47:17 ipatest.internal goferd[13681]: [INFO][MainThread] >> rhsm.connection:778 - Connection built: host=katello.internal port=443 >> handler=/rhsm auth=identity_cert ca_dir=/etc/rhsm/ca/ verify >> Jun 28 21:47:17 ipatest.internal goferd[13681]: Loaded plugins: >> fastestmirror, product-id >> Jun 28 21:47:17 ipatest.internal goferd[13681]: [INFO][MainThread] >> katelloplugin:352 - reporting: {'enabled_repos': {'repos': [{'baseurl': [' >> https://katello.internal/pulp/repos/Resilient_Systems/pro >> Jun 28 21:47:42 ipatest.internal goferd[13681]: [INFO][MainThread] >> gofer.agent.main:87 - agent started. >> Jun 28 21:47:42 ipatest.internal goferd[13681]: [INFO][worker-0] >> gofer.messaging.adapter.connect:28 - connecting: >> proton+amqps://katello.internal:5647 >> Jun 28 21:47:42 ipatest.internal goferd[13681]: [INFO][worker-0] >> gofer.messaging.adapter.proton.connection:87 - open: URL: >> amqps://katello.internal:5647|SSL: ca: /etc/rhsm/ca/katello-default-ca.pem| >> Jun 28 21:47:42 ipatest.internal goferd[13681]: [INFO][worker-0] root:510 >> - connecting to katello.internal:5647... >> Jun 28 21:47:52 ipatest.internal goferd[13681]: [INFO][worker-0] root:559 >> - Disconnected >> Jun 28 21:47:52 ipatest.internal goferd[13681]: [ERROR][worker-0] >> gofer.messaging.adapter.connect:33 - connect: >> proton+amqps://katello.internal:5647, failed: Connection >> amqps://katello.internal.resi >> Jun 28 21:47:52 ipatest.internal goferd[13681]: [INFO][worker-0] >> gofer.messaging.adapter.connect:35 - retry in 10 seconds >> Jun 28 21:48:02 ipatest.internal goferd[13681]: [INFO][worker-0] >> gofer.messaging.adapter.connect:28 - connecting: >> proton+amqps://katello.internal:5647 >> Jun 28 21:48:03 ipatest.internal goferd[13681]: [INFO][worker-0] >> gofer.messaging.adapter.proton.connection:87 - open: URL: >> amqps://katello.internal:5647|SSL: ca: /etc/rhsm/ca/katello-default-ca.pem| >> Jun 28 21:48:03 ipatest.internal goferd[13681]: [INFO][worker-0] root:510 >> - connecting to katello.internal:5647... >> Jun 28 21:48:13 ipatest.internal goferd[13681]: [INFO][worker-0] root:559 >> - Disconnected >> Jun 28 21:48:13 ipatest.internal goferd[13681]: [ERROR][worker-0] >> gofer.messaging.adapter.connect:33 - connect: >> proton+amqps://katello.internal:5647, failed: Connection >> amqps://katello.internal.resi >> Jun 28 21:48:13 ipatest.internal goferd[13681]: [INFO][worker-0] >> gofer.messaging.adapter.connect:35 - retry in 12 seconds > > > There's no firewall involved here and I am able to see a connection > establish and then go away on 5647 on both machines. They are able to > telnet to each other on 5647 as well, and I was able to repro with selinux > off on both and firewalld off. > > Curious, I hopped over to katello.internal and enabled / looked at the > qdrouterd log: > >> Tue Jun 28 21:47:42 2016 SERVER (debug) Accepting incoming connection >> from ipatest.internal:55332 to 0.0.0.0:5647 >> Tue Jun 28 21:47:42 2016 SERVER (trace) Configuring SSL on incoming >> connection from ipatest.internal:55332 to 0.0.0.0:5647 >> Tue Jun 28 21:47:42 2016 ROUTER_HELLO (trace) SENT: >> HELLO(id=katello.internal area=0 inst=1467138250 seen=[]) >> Tue Jun 28 21:47:43 2016 ROUTER_HELLO (trace) SENT: >> HELLO(id=katello.internal area=0 inst=1467138250 seen=[]) >> Tue Jun 28 21:47:45 2016 ROUTER_HELLO (trace) SENT: >> HELLO(id=katello.internal area=0 inst=1467138250 seen=[]) >> Tue Jun 28 21:47:46 2016 ROUTER_HELLO (trace) SENT: >> HELLO(id=katello.internal area=0 inst=1467138250 seen=[]) >> Tue Jun 28 21:47:47 2016 ROUTER_HELLO (trace) SENT: >> HELLO(id=katello.internal area=0 inst=1467138250 seen=[]) > > > So I thought I'd check ssl, from the ipatest box I did a: > openssl s_client -connect katello.internal:5647 -cert > /etc/pki/consumer/bundle.pem -key /etc/pki/consumer/bundle.pem -CAfile > /etc/rhsm/ca/katello-default-ca.pem -state -debug > and everything seemed to come back OK. > > Thought maybe it was something underlying in qpidd, and I did find errors > in that log, but not sure if they're related: > >> Jun 28 15:25:35 katello.internal qpidd[18457]: 2016-06-28 15:25:35 >> [System] error Connection qpid No protocol received closing >> Jun 28 15:25:35 katello.internal qpidd[18457]: 2016-06-28 15:25:35 >> [System] error Connection qpid No protocol received closing >> Jun 28 15:26:20 katello.internal qpidd[18457]: 2016-06-28 15:26:20 >> [System] error Connection qpid No protocol received closing >> Jun 28 15:26:20 katello.internal qpidd[18457]: 2016-06-28 15:26:20 >> [System] error Connection qpid No protocol received closing >> > > The agents show as up as active, but any commands fail. > > Anyone have any ideas? > > Best, > --Nick Cammorato >
3

Do new clients, cleanly registered face the same problem?

Unfortunately, you are on a version that is 4 versions behind latest and
that makes it harder for us to debug and provide support.

··· On Tue, Aug 22, 2017 at 12:10 AM, Nicholas Carter wrote:

Good afternoon,

Any news on this front? I’m seeing the same errors within my journal for
gofer.

On Wednesday, June 29, 2016 at 2:20:00 AM UTC-4, Nick Cammorato wrote:

Hi Everyone,

Having a few post-update blues and I’m out of things I can think of to
look at. For the most part everything went pretty well during the update.
However, while updating my capsules I noticed that A. posting package
profiles started to take forever and B. more importantly goferd seemed to
not be working:

I noticed my pulp repos weren’t syncing and I couldn’t issue any
commands, so I hoped on a box on the same subnet as the katello server and
checked out the katello-agent.

Jun 28 21:47:11 ipatest.internal systemd[1]: Starting Gofer Agent…

Jun 28 21:47:11 ipatest.internal goferd[13681]: [INFO][Thread-1]
gofer.rmi.store:114 - Using: /var/lib/gofer/messaging/pending/demo
Jun 28 21:47:11 ipatest.internal goferd[13681]: [WARNING][MainThread]
gofer.agent.plugin:639 - plugin:demo, DISABLED
Jun 28 21:47:11 ipatest.internal goferd[13681]: [INFO][Thread-2]
gofer.rmi.store:114 - Using: /var/lib/gofer/messaging/pendi
ng/katelloplugin
Jun 28 21:47:11 ipatest.internal goferd[13681]: [INFO][Thread-3]
gofer.rmi.store:114 - Using: /var/lib/gofer/messaging/pendi
ng/katelloplugin
Jun 28 21:47:11 ipatest.internal goferd[13681]: [INFO][MainThread]
gofer.agent.plugin:682 - plugin:katelloplugin loaded using:
/usr/lib/gofer/plugins/katelloplugin.py
Jun 28 21:47:11 ipatest.internal goferd[13681]: [INFO][MainThread]
rhsm.connection:778 - Connection built: host=katello.internal port=443
handler=/rhsm auth=identity_cert ca_dir=/etc/rhsm/ca/ verify
Jun 28 21:47:17 ipatest.internal goferd[13681]: [INFO][MainThread]
katelloplugin:177 - Using /etc/rhsm/ca/katello-default-ca.pem as the ca
cert for qpid connection
Jun 28 21:47:17 ipatest.internal goferd[13681]: [INFO][MainThread]
rhsm.connection:778 - Connection built: host=katello.internal port=443
handler=/rhsm auth=identity_cert ca_dir=/etc/rhsm/ca/ verify
Jun 28 21:47:17 ipatest.internal goferd[13681]: Loaded plugins:
fastestmirror, product-id
Jun 28 21:47:17 ipatest.internal goferd[13681]: [INFO][MainThread]
katelloplugin:352 - reporting: {‘enabled_repos’: {‘repos’: [{‘baseurl’: ['
https://katello.internal/pulp/repos/Resilient_Systems/pro
Jun 28 21:47:42 ipatest.internal goferd[13681]: [INFO][MainThread]
gofer.agent.main:87 - agent started.
Jun 28 21:47:42 ipatest.internal goferd[13681]: [INFO][worker-0]
gofer.messaging.adapter.connect:28 - connecting:
proton+amqps://katello.internal:5647
Jun 28 21:47:42 ipatest.internal goferd[13681]: [INFO][worker-0]
gofer.messaging.adapter.proton.connection:87 - open: URL:
amqps://katello.internal:5647|SSL: ca: /etc/rhsm/ca/katello-default-c
a.pem|
Jun 28 21:47:42 ipatest.internal goferd[13681]: [INFO][worker-0]
root:510 - connecting to katello.internal:5647…
Jun 28 21:47:52 ipatest.internal goferd[13681]: [INFO][worker-0]
root:559 - Disconnected
Jun 28 21:47:52 ipatest.internal goferd[13681]: [ERROR][worker-0]
gofer.messaging.adapter.connect:33 - connect:
proton+amqps://katello.internal:5647, failed: Connection
amqps://katello.internal.resi
Jun 28 21:47:52 ipatest.internal goferd[13681]: [INFO][worker-0]
gofer.messaging.adapter.connect:35 - retry in 10 seconds
Jun 28 21:48:02 ipatest.internal goferd[13681]: [INFO][worker-0]
gofer.messaging.adapter.connect:28 - connecting:
proton+amqps://katello.internal:5647
Jun 28 21:48:03 ipatest.internal goferd[13681]: [INFO][worker-0]
gofer.messaging.adapter.proton.connection:87 - open: URL:
amqps://katello.internal:5647|SSL: ca: /etc/rhsm/ca/katello-default-c
a.pem|
Jun 28 21:48:03 ipatest.internal goferd[13681]: [INFO][worker-0]
root:510 - connecting to katello.internal:5647…
Jun 28 21:48:13 ipatest.internal goferd[13681]: [INFO][worker-0]
root:559 - Disconnected
Jun 28 21:48:13 ipatest.internal goferd[13681]: [ERROR][worker-0]
gofer.messaging.adapter.connect:33 - connect:
proton+amqps://katello.internal:5647, failed: Connection
amqps://katello.internal.resi
Jun 28 21:48:13 ipatest.internal goferd[13681]: [INFO][worker-0]
gofer.messaging.adapter.connect:35 - retry in 12 seconds

There’s no firewall involved here and I am able to see a connection
establish and then go away on 5647 on both machines. They are able to
telnet to each other on 5647 as well, and I was able to repro with selinux
off on both and firewalld off.

Curious, I hopped over to katello.internal and enabled / looked at the
qdrouterd log:

Tue Jun 28 21:47:42 2016 SERVER (debug) Accepting incoming connection
from ipatest.internal:55332 to 0.0.0.0:5647
Tue Jun 28 21:47:42 2016 SERVER (trace) Configuring SSL on incoming
connection from ipatest.internal:55332 to 0.0.0.0:5647
Tue Jun 28 21:47:42 2016 ROUTER_HELLO (trace) SENT:
HELLO(id=katello.internal area=0 inst=1467138250 seen=[])
Tue Jun 28 21:47:43 2016 ROUTER_HELLO (trace) SENT:
HELLO(id=katello.internal area=0 inst=1467138250 seen=[])
Tue Jun 28 21:47:45 2016 ROUTER_HELLO (trace) SENT:
HELLO(id=katello.internal area=0 inst=1467138250 seen=[])
Tue Jun 28 21:47:46 2016 ROUTER_HELLO (trace) SENT:
HELLO(id=katello.internal area=0 inst=1467138250 seen=[])
Tue Jun 28 21:47:47 2016 ROUTER_HELLO (trace) SENT:
HELLO(id=katello.internal area=0 inst=1467138250 seen=[])

So I thought I’d check ssl, from the ipatest box I did a:
openssl s_client -connect katello.internal:5647 -cert
/etc/pki/consumer/bundle.pem -key /etc/pki/consumer/bundle.pem -CAfile
/etc/rhsm/ca/katello-default-ca.pem -state -debug
and everything seemed to come back OK.

Thought maybe it was something underlying in qpidd, and I did find errors
in that log, but not sure if they’re related:

Jun 28 15:25:35 katello.internal qpidd[18457]: 2016-06-28 15:25:35
[System] error Connection qpid No protocol received closing
Jun 28 15:25:35 katello.internal qpidd[18457]: 2016-06-28 15:25:35
[System] error Connection qpid No protocol received closing
Jun 28 15:26:20 katello.internal qpidd[18457]: 2016-06-28 15:26:20
[System] error Connection qpid No protocol received closing
Jun 28 15:26:20 katello.internal qpidd[18457]: 2016-06-28 15:26:20
[System] error Connection qpid No protocol received closing

The agents show as up as active, but any commands fail.

Anyone have any ideas?

Best,
–Nick Cammorato

–
You received this message because you are subscribed to the Google Groups
"Foreman users" group.
To unsubscribe from this group and stop receiving emails from it, send an
email to foreman-users+unsubscribe@googlegroups.com.
To post to this group, send email to foreman-users@googlegroups.com.
Visit this group at https://groups.google.com/group/foreman-users.
For more options, visit https://groups.google.com/d/optout.

–
Eric D. Helms
Red Hat Engineering