Description of problem: goferd appears to be running normally, but errors are shown in the logs after upgrading goferd from 6.3 version to 6.4 Version-Release number of selected component (if applicable): gofer-2.12.1-1 How reproducible: Everytime Steps to Reproduce: 1. Fresh OS install (only tested on RHEL7) 2. Register to a Satellite and install katello-agent from sat-tools 6.3 3. Disable sat-tools-6.3 and enable sat-tools-6.4 4. Upgrade katello-agent 5. systemctl status goferd Actual results: systemd[1]: Starting Gofer Agent... [INFO][Thread-1] gofer.rmi.store:108 - Using: /var/lib/gofer/messaging/pending/demo [WARNING][MainThread] gofer.agent.plugin:647 - plugin:demo, DISABLED [INFO][Thread-2] gofer.rmi.store:108 - Using: /var/lib/gofer/messaging/pending/katello [ERROR][MainThread] gofer.agent.plugin:703 - plugin:katello, import failed [ERROR][MainThread] gofer.agent.plugin:703 - Traceback (most recent call last): [ERROR][MainThread] gofer.agent.plugin:703 - File "/usr/lib/python2.7/site-packages/gofer/agent/plugin.py", line 687, in _load [ERROR][MainThread] gofer.agent.plugin:703 - plugin.impl = __import__(path, {}, {}, [path.split('.')[-1]]) [ERROR][MainThread] gofer.agent.plugin:703 - ImportError: No module named katello.agent.goferd.plugin [INFO][MainThread] gofer.agent.main:92 - agent started. Expected results: No errors Additional info:
Taft, Thanks for the report. Did you notice any impact on the user workflows? e.g. Were you able to install/update/remove packages, groups, errata...etc?
Brad, Yeah can't push packages to a host via katello-agent: Checked yum data on client to ensure connectivity to Satellite: foreman-ssl_access_ssl.log: 10.12.213.129 - - [30/Oct/2018:14:22:17 -0400] "GET /rhsm/consumers/0b166023-f6bb-443e-97a5-a80d578e651b/release HTTP/1.1" 200 20 "-" "RHSM/1.0 (cmd=yum)" - Initiated upgrade on dhclient package from the Satellite: Id: 7dc24b0b-6a38-4712-bc83-1739bbaf6fb2 Label: Actions::Katello::Host::Package::Update Status: running Cancel Result: pending Started at: 2018-10-30 18:23:50 UTC Ended at: Plan Run Finalize Execution History 3: Actions::Pulp::Consumer::ContentUpdate (waiting for Pulp to start the task) [ 1408.27s / 12.40s ] Cancel Started at: 2018-10-30 18:23:51 UTC Ended at: 2018-10-30 18:47:19 UTC Real time: 1408.27s Execution time (excluding suspended state): 12.40s Input: --- consumer_uuid: 0b166023-f6bb-443e-97a5-a80d578e651b type: rpm args: - dhclient-4.2.5-58.el7_4.4.x86_64 remote_user: admin remote_cp_user: admin Output: --- pulp_tasks: - exception: task_type: _href: "/pulp/api/v2/tasks/272d7d68-90bf-407b-bda1-8d41b4ad1c46/" task_id: 272d7d68-90bf-407b-bda1-8d41b4ad1c46 tags: - pulp:consumer:0b166023-f6bb-443e-97a5-a80d578e651b - pulp:action:unit_update finish_time: _ns: task_status start_time: traceback: spawned_tasks: [] progress_report: {} queue: agent.dq2 state: waiting worker_name: agent result: error: _id: "$oid": 5bd8a1b7882c103ec4f5ea40 id: 5bd8a1b7882c103ec4f5ea40 poll_attempts: total: 107 failed: 0 ========================================================================================================================================== I'll leave this task running to be sure it won't be needed for further information. Also, all services on the Satellite are working: [root@batman httpd]# foreman-maintain service status Running Status Services ================================================================================ Get status of applicable services: Displaying the following service(s): rh-mongodb34-mongod, postgresql, qdrouterd, qpidd, squid, pulp_celerybeat, pulp_resource_manager, pulp_streamer, pulp_workers, smart_proxy_dynflow_core, tomcat, dynflowd, goferd, httpd, puppetserver, foreman-proxy | displaying rh-mongodb34-mongod ● rh-mongodb34-mongod.service - High-performance, schema-free document-oriented database Loaded: loaded (/usr/lib/systemd/system/rh-mongodb34-mongod.service; enabled; vendor preset: disabled) Active: active (running) since Thu 2018-10-25 10:48:34 EDT; 5 days ago Process: 1115 ExecStart=/opt/rh/rh-mongodb34/root/usr/libexec/mongodb-scl-helper enable $RH_MONGODB34_SCLS_ENABLED -- /opt/rh/rh-mongodb34/root/usr/bin/mongod $OPTIONS run (code=exited, status=0/SUCCESS) Main PID: 1368 (mongod) Tasks: 81 Memory: 6.6G CGroup: /system.slice/rh-mongodb34-mongod.service └─1368 /opt/rh/rh-mongodb34/root/usr/bin/mongod -f /etc/opt/rh/rh-mongodb34/mongod.conf run Oct 30 09:11:00 batman.usersys.redhat.com mongod.27017[1368]: [conn53] command pulp_database.$cmd command: update { update: "workers", ordered: true, updates: [ { q: { _id: "reserved_resource_worker-6.redhat.com" }, u: { $set: { last_heartbeat: new Date(1540905060465) } }, multi: false, upsert: true } ] } numYields:0 reslen:59 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 3 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 444899 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { W: 1 }, acquireWaitCount: { W: 1 }, timeAcquiringMicros: { W: 202 } } } protocol:op_query 445ms Oct 30 10:18:02 batman.usersys.redhat.com mongod.27017[1368]: [conn57] update pulp_database.workers query: { _id: "reserved_resource_worker-3.redhat.com" } planSummary: IDHACK update: { $set: { last_heartbeat: new Date(1540909082592) } } keysExamined:1 docsExamined:1 nMatched:1 nModified:1 numYields:0 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 102498 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { W: 1 } } } 102ms Oct 30 10:18:02 batman.usersys.redhat.com mongod.27017[1368]: [conn57] command pulp_database.$cmd command: update { update: "workers", ordered: true, updates: [ { q: { _id: "reserved_resource_worker-3.redhat.com" }, u: { $set: { last_heartbeat: new Date(1540909082592) } }, multi: false, upsert: true } ] } numYields:0 reslen:59 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 102498 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { W: 1 } } } protocol:op_query 103ms Oct 30 11:20:40 batman.usersys.redhat.com mongod.27017[1368]: [conn57] update pulp_database.workers query: { _id: "reserved_resource_worker-3.redhat.com" } planSummary: IDHACK update: { $set: { last_heartbeat: new Date(1540912840161) } } keysExamined:1 docsExamined:1 nMatched:1 nModified:1 numYields:0 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 233372 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { W: 1 } } } 233ms Oct 30 11:20:40 batman.usersys.redhat.com mongod.27017[1368]: [conn57] command pulp_database.$cmd command: update { update: "workers", ordered: true, updates: [ { q: { _id: "reserved_resource_worker-3.redhat.com" }, u: { $set: { last_heartbeat: new Date(1540912840161) } }, multi: false, upsert: true } ] } numYields:0 reslen:59 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 233372 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { W: 1 } } } protocol:op_query 234ms Oct 30 14:26:33 batman.usersys.redhat.com mongod.27017[1368]: [conn8052] received client metadata from 127.0.0.1:45190 conn8052: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.4.9" }, os: { type: "Linux", name: "Red Hat Enterprise Linux Server release 7.5 (Maipo)", architecture: "x86_64", version: "Kernel 3.10.0-862.14.4.el7.x86_64" } } Oct 30 14:26:55 batman.usersys.redhat.com mongod.27017[1368]: [conn8053] received client metadata from 127.0.0.1:45206 conn8053: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.4.9" }, os: { type: "Linux", name: "Red Hat Enterprise Linux Server release 7.5 (Maipo)", architecture: "x86_64", version: "Kernel 3.10.0-862.14.4.el7.x86_64" } } Oct 30 14:45:08 batman.usersys.redhat.com mongod.27017[1368]: [conn51] update pulp_database.workers query: { _id: "reserved_resource_worker-2.redhat.com" } planSummary: IDHACK update: { $set: { last_heartbeat: new Date(1540925108740) } } keysExamined:1 docsExamined:1 nMatched:1 nModified:1 numYields:0 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 113321 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { W: 1 } } } 113ms Oct 30 14:45:08 batman.usersys.redhat.com mongod.27017[1368]: [conn51] command pulp_database.$cmd command: update { update: "workers", ordered: true, updates: [ { q: { _id: "reserved_resource_worker-2.redhat.com" }, u: { $set: { last_heartbeat: new Date(1540925108740) } }, multi: false, upsert: true } ] } numYields:0 reslen:59 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 113321 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { W: 1 } } } protocol:op_query 114ms Oct 30 14:48:58 batman.usersys.redhat.com mongod.27017[1368]: [conn8066] received client metadata from 127.0.0.1:46250 conn8066: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.4.9" }, os: { type: "Linux", name: "Red Hat Enterprise Linux Server release 7.5 (Maipo)", architecture: "x86_64", version: "Kernel 3.10.0-862.14.4.el7.x86_64" } } | displaying postgresql ● postgresql.service - PostgreSQL database server Loaded: loaded (/etc/systemd/system/postgresql.service; enabled; vendor preset: disabled) Active: active (running) since Thu 2018-10-25 10:48:08 EDT; 5 days ago Process: 1179 ExecStart=/usr/bin/pg_ctl start -D ${PGDATA} -s -o -p ${PGPORT} -w -t 300 (code=exited, status=0/SUCCESS) Process: 1142 ExecStartPre=/usr/bin/postgresql-check-db-dir ${PGDATA} (code=exited, status=0/SUCCESS) Main PID: 1272 (postgres) Tasks: 48 Memory: 1.3G CGroup: /system.slice/postgresql.service ├─1272 /usr/bin/postgres -D /var/lib/pgsql/data -p 5432 ├─1366 postgres: logger process ├─1412 postgres: checkpointer process ├─1413 postgres: writer process ├─1414 postgres: wal writer process ├─1415 postgres: autovacuum launcher process ├─1416 postgres: stats collector process ├─1595 postgres: foreman foreman [local] idle ├─1603 postgres: foreman foreman [local] idle ├─1604 postgres: foreman foreman [local] idle ├─1610 postgres: foreman foreman [local] idle ├─2763 postgres: candlepin candlepin 127.0.0.1(46432) idl ├─2764 postgres: candlepin candlepin 127.0.0.1(46434) idl ├─2765 postgres: candlepin candlepin 127.0.0.1(46436) idl ├─2821 postgres: candlepin candlepin 127.0.0.1(46450) idl ├─2822 postgres: candlepin candlepin 127.0.0.1(46452) idl ├─2976 postgres: foreman foreman [local] idle ├─2983 postgres: foreman foreman [local] idle ├─2984 postgres: foreman foreman [local] idle ├─2988 postgres: foreman foreman [local] idle ├─3005 postgres: foreman foreman [local] idle ├─3006 postgres: foreman foreman [local] idle ├─4163 postgres: foreman foreman [local] idle ├─4168 postgres: foreman foreman [local] idle ├─4169 postgres: foreman foreman [local] idle ├─4478 postgres: foreman foreman [local] idle ├─5024 postgres: foreman foreman [local] idle ├─5025 postgres: foreman foreman [local] idle ├─5026 postgres: foreman foreman [local] idle ├─5027 postgres: foreman foreman [local] idle ├─5029 postgres: foreman foreman [local] idle ├─5049 postgres: foreman foreman [local] idle ├─5057 postgres: foreman foreman [local] idle ├─5087 postgres: foreman foreman [local] idle ├─5488 postgres: foreman foreman [local] idle ├─6515 postgres: foreman foreman [local] idle ├─7041 postgres: foreman foreman [local] idle ├─7047 postgres: foreman foreman [local] idle ├─7048 postgres: foreman foreman [local] idle ├─7147 postgres: foreman foreman [local] idle ├─8440 postgres: foreman foreman [local] idle ├─8446 postgres: foreman foreman [local] idle ├─8447 postgres: foreman foreman [local] idle ├─8658 postgres: candlepin candlepin 127.0.0.1(54232) idl ├─8659 postgres: candlepin candlepin 127.0.0.1(54233) idl ├─8660 postgres: candlepin candlepin 127.0.0.1(54234) idl ├─8661 postgres: candlepin candlepin 127.0.0.1(54240) idl └─8662 postgres: candlepin candlepin 127.0.0.1(54242) idl Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable. | displaying qdrouterd ● qdrouterd.service - Qpid Dispatch router daemon Loaded: loaded (/usr/lib/systemd/system/qdrouterd.service; enabled; vendor preset: disabled) Active: active (running) since Thu 2018-10-25 18:41:42 EDT; 4 days ago Main PID: 26811 (qdrouterd) Tasks: 9 Memory: 21.7M CGroup: /system.slice/qdrouterd.service └─26811 /usr/sbin/qdrouterd -c /etc/qpid-dispatch/qdrouterd.conf Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable. / displaying qpidd ● qpidd.service - An AMQP message broker daemon. Loaded: loaded (/usr/lib/systemd/system/qpidd.service; enabled; vendor preset: disabled) Active: active (running) since Thu 2018-10-25 18:41:22 EDT; 4 days ago Docs: man:qpidd(1) http://qpid.apache.org/ Main PID: 26751 (qpidd) Tasks: 10 Memory: 45.6M CGroup: /system.slice/qpidd.service └─26751 /usr/sbin/qpidd --config /etc/qpid/qpidd.conf Oct 30 14:48:59 batman.usersys.redhat.com qpidd[26751]: 2018-10-30 14:48:59 [Security] debug ACL: Lookup for id:anonymous action:access objectType:exchange name:celeryev with params { } Oct 30 14:48:59 batman.usersys.redhat.com qpidd[26751]: 2018-10-30 14:48:59 [Security] debug ACL: Lookup for id:anonymous action:access objectType:exchange name:celeryev with params { } Oct 30 14:48:59 batman.usersys.redhat.com qpidd[26751]: 2018-10-30 14:48:59 [Security] debug ACL: No successful match, defaulting to the decision mode allow Oct 30 14:48:59 batman.usersys.redhat.com qpidd[26751]: 2018-10-30 14:48:59 [Broker] debug anonymous.22221275-7124-4151-8abc-db47c4249fa5:0: receiver marked completed: 418966 incomplete: { } unknown-completed: { [0,418966] } Oct 30 14:48:59 batman.usersys.redhat.com qpidd[26751]: 2018-10-30 14:48:59 [Security] debug ACL: No successful match, defaulting to the decision mode allow Oct 30 14:48:59 batman.usersys.redhat.com qpidd[26751]: 2018-10-30 14:48:59 [Broker] debug anonymous.22221275-7124-4151-8abc-db47c4249fa5:0: receiver marked completed: 418966 incomplete: { } unknown-completed: { [0,418966] } Oct 30 14:48:59 batman.usersys.redhat.com qpidd[26751]: 2018-10-30 14:48:59 [Broker] debug : receive completed for msg seq=418967 Oct 30 14:48:59 batman.usersys.redhat.com qpidd[26751]: 2018-10-30 14:48:59 [Broker] debug : receive completed for msg seq=418967 Oct 30 14:48:59 batman.usersys.redhat.com qpidd[26751]: 2018-10-30 14:48:59 [Broker] debug anonymous.22221275-7124-4151-8abc-db47c4249fa5:0: receiver marked completed: 418967 incomplete: { } unknown-completed: { [0,418967] } Oct 30 14:48:59 batman.usersys.redhat.com qpidd[26751]: 2018-10-30 14:48:59 [Broker] debug anonymous.22221275-7124-4151-8abc-db47c4249fa5:0: receiver marked completed: 418967 incomplete: { } unknown-completed: { [0,418967] } / displaying squid ● squid.service - Squid caching proxy Loaded: loaded (/usr/lib/systemd/system/squid.service; enabled; vendor preset: disabled) Active: active (running) since Thu 2018-10-25 10:47:51 EDT; 5 days ago Process: 2110 ExecReload=/usr/sbin/squid $SQUID_OPTS -k reconfigure -f $SQUID_CONF (code=exited, status=0/SUCCESS) Process: 1177 ExecStart=/usr/sbin/squid $SQUID_OPTS -f $SQUID_CONF (code=exited, status=0/SUCCESS) Process: 1106 ExecStartPre=/usr/libexec/squid/cache_swap.sh (code=exited, status=0/SUCCESS) Main PID: 1183 (squid) Tasks: 18 Memory: 18.0M CGroup: /system.slice/squid.service ├─1183 /usr/sbin/squid -f /etc/squid/squid.conf └─1185 (squid-1) -f /etc/squid/squid.conf Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable. / displaying pulp_celerybeat ● pulp_celerybeat.service - Pulp's Celerybeat Loaded: loaded (/usr/lib/systemd/system/pulp_celerybeat.service; enabled; vendor preset: disabled) Active: active (running) since Thu 2018-10-25 10:47:51 EDT; 5 days ago Main PID: 1168 (celery) Tasks: 5 Memory: 50.8M CGroup: /system.slice/pulp_celerybeat.service └─1168 /usr/bin/python /usr/bin/celery beat --app=pulp.server.async.celery_instance.celery --scheduler=pulp.server.async.scheduler.Scheduler Oct 30 13:15:15 batman.usersys.redhat.com pulp[1168]: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controllers.repository.queue_download_deferred) Oct 30 13:25:15 batman.usersys.redhat.com pulp[1168]: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controllers.repository.queue_download_deferred) Oct 30 13:35:15 batman.usersys.redhat.com pulp[1168]: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controllers.repository.queue_download_deferred) Oct 30 13:45:15 batman.usersys.redhat.com pulp[1168]: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controllers.repository.queue_download_deferred) Oct 30 13:55:15 batman.usersys.redhat.com pulp[1168]: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controllers.repository.queue_download_deferred) Oct 30 14:05:15 batman.usersys.redhat.com pulp[1168]: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controllers.repository.queue_download_deferred) Oct 30 14:15:15 batman.usersys.redhat.com pulp[1168]: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controllers.repository.queue_download_deferred) Oct 30 14:25:15 batman.usersys.redhat.com pulp[1168]: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controllers.repository.queue_download_deferred) Oct 30 14:35:15 batman.usersys.redhat.com pulp[1168]: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controllers.repository.queue_download_deferred) Oct 30 14:45:15 batman.usersys.redhat.com pulp[1168]: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controllers.repository.queue_download_deferred) / displaying pulp_resource_manager ● pulp_resource_manager.service - Pulp Resource Manager Loaded: loaded (/usr/lib/systemd/system/pulp_resource_manager.service; enabled; vendor preset: disabled) Active: active (running) since Thu 2018-10-25 10:47:51 EDT; 5 days ago Main PID: 1169 (celery) Tasks: 15 Memory: 107.0M CGroup: /system.slice/pulp_resource_manager.service ├─1169 /usr/bin/python /usr/bin/celery worker -A pulp.server.async.app -n resource_manager@%h -Q resource_manager -c 1 --events --umask 18 --pidfile=/var/run/pulp/resource_manager.pid └─2292 /usr/bin/python /usr/bin/celery worker -A pulp.server.async.app -n resource_manager@%h -Q resource_manager -c 1 --events --umask 18 --pidfile=/var/run/pulp/resource_manager.pid Oct 29 23:04:38 batman.usersys.redhat.com pulp[2292]: celery.app.trace:INFO: [a15691c8] Task pulp.server.async.tasks._queue_reserved_task[a15691c8-2163-4ff3-93a5-e919be6d1e7a] succeeded in 0.0613477489678s: None Oct 29 23:04:39 batman.usersys.redhat.com pulp[2292]: celery.app.trace:INFO: [eefe2f39] Task pulp.server.async.tasks._queue_reserved_task[eefe2f39-7c81-492a-9ce0-8a1184ed826e] succeeded in 0.311454733019s: None Oct 29 23:04:40 batman.usersys.redhat.com pulp[1169]: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._queue_reserved_task[52f13ae5-ce7c-4035-aec4-2f17d27188a7] Oct 29 23:04:40 batman.usersys.redhat.com pulp[2292]: celery.app.trace:INFO: [52f13ae5] Task pulp.server.async.tasks._queue_reserved_task[52f13ae5-ce7c-4035-aec4-2f17d27188a7] succeeded in 0.0589094400057s: None Oct 29 23:04:41 batman.usersys.redhat.com pulp[1169]: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._queue_reserved_task[d817fb9a-6f0d-408f-bf68-95527c705aa5] Oct 29 23:04:41 batman.usersys.redhat.com pulp[2292]: celery.app.trace:INFO: [d817fb9a] Task pulp.server.async.tasks._queue_reserved_task[d817fb9a-6f0d-408f-bf68-95527c705aa5] succeeded in 0.0423962179921s: None Oct 29 23:05:07 batman.usersys.redhat.com pulp[1169]: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._queue_reserved_task[77407a98-72c8-4c57-8c6c-bb3ab70b94b4] Oct 29 23:05:07 batman.usersys.redhat.com pulp[2292]: celery.app.trace:INFO: [77407a98] Task pulp.server.async.tasks._queue_reserved_task[77407a98-72c8-4c57-8c6c-bb3ab70b94b4] succeeded in 0.0206409830134s: None Oct 30 14:06:56 batman.usersys.redhat.com pulp[1169]: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._queue_reserved_task[0a0771ae-b1c8-405d-94f9-b7d01b2d030b] Oct 30 14:06:56 batman.usersys.redhat.com pulp[2292]: celery.app.trace:INFO: [0a0771ae] Task pulp.server.async.tasks._queue_reserved_task[0a0771ae-b1c8-405d-94f9-b7d01b2d030b] succeeded in 0.0685426379787s: None - displaying pulp_streamer ● pulp_streamer.service - The Pulp lazy content loading streamer Loaded: loaded (/usr/lib/systemd/system/pulp_streamer.service; enabled; vendor preset: disabled) Active: active (running) since Thu 2018-10-25 10:47:51 EDT; 5 days ago Main PID: 1175 (pulp_streamer) Tasks: 5 Memory: 68.8M CGroup: /system.slice/pulp_streamer.service └─1175 /usr/bin/python /usr/bin/pulp_streamer --nodaemon --syslog --prefix=pulp_streamer --pidfile= --python /usr/share/pulp/wsgi/streamer.tac Oct 30 14:39:25 batman.usersys.redhat.com pulp_streamer[1175]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): cdn.redhat.com Oct 30 14:39:26 batman.usersys.redhat.com pulp_streamer[1175]: pulp.streamer.server:INFO: Trying URL: https://cdn.redhat.com/content/dist/rhel/server/7/7Server/x86_64/satellite/6.3/os/Packages/python-pulp-bindings-2.13.4.14-1.el7sat.noarch.rpm Oct 30 14:39:26 batman.usersys.redhat.com pulp_streamer[1175]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (2): cdn.redhat.com Oct 30 14:39:26 batman.usersys.redhat.com pulp_streamer[1175]: nectar.downloaders.threaded:INFO: Download succeeded: https://cdn.redhat.com/content/dist/rhel/server/7/7Server/x86_64/satellite/6.3/os/Packages/pulp-admin-client-2.13.4.14-1.el7sat.noarch.rpm. Oct 30 14:39:26 batman.usersys.redhat.com pulp_streamer[1175]: [-] 127.0.0.1 - - [30/Oct/2018:18:39:25 +0000] "GET /var/lib/pulp/content/units/rpm/19/cb222d7ae1a89cae86fb5e60396f55fb5ca203dd32854462b9483952a453e1/pulp-admin-client-2.13.4.14-1.el7sat.noarch.rpm HTTP/1.1" 200 130300 "-" "urlgrabber/3.10 yum/3.4.3" Oct 30 14:39:26 batman.usersys.redhat.com pulp_streamer[1175]: nectar.downloaders.threaded:INFO: Download succeeded: https://cdn.redhat.com/content/dist/rhel/server/7/7Server/x86_64/satellite/6.3/os/Packages/python-pulp-bindings-2.13.4.14-1.el7sat.noarch.rpm. Oct 30 14:39:26 batman.usersys.redhat.com pulp_streamer[1175]: [-] 127.0.0.1 - - [30/Oct/2018:18:39:25 +0000] "GET /var/lib/pulp/content/units/rpm/3d/58958b0acc758ffc35aef81b0d26e1b67aef34d1673b1353250672c9ddad4b/python-pulp-bindings-2.13.4.14-1.el7sat.noarch.rpm HTTP/1.1" 200 115292 "-" "urlgrabber/3.10 yum/3.4.3" Oct 30 14:39:26 batman.usersys.redhat.com pulp_streamer[1175]: pulp.streamer.server:INFO: Trying URL: https://cdn.redhat.com/content/dist/rhel/server/7/7Server/x86_64/satellite/6.3/os/Packages/python-pulp-client-lib-2.13.4.14-1.el7sat.noarch.rpm Oct 30 14:39:27 batman.usersys.redhat.com pulp_streamer[1175]: nectar.downloaders.threaded:INFO: Download succeeded: https://cdn.redhat.com/content/dist/rhel/server/7/7Server/x86_64/satellite/6.3/os/Packages/python-pulp-client-lib-2.13.4.14-1.el7sat.noarch.rpm. Oct 30 14:39:27 batman.usersys.redhat.com pulp_streamer[1175]: [-] 127.0.0.1 - - [30/Oct/2018:18:39:26 +0000] "GET /var/lib/pulp/content/units/rpm/d1/f7420e0af01ea50dafac60c15f3137bf7e69ae3b8380589bf85f46185cb95b/python-pulp-client-lib-2.13.4.14-1.el7sat.noarch.rpm HTTP/1.1" 200 204276 "-" "urlgrabber/3.10 yum/3.4.3" - displaying pulp_workers ● pulp_workers.service - Pulp Celery Workers Loaded: loaded (/usr/lib/systemd/system/pulp_workers.service; enabled; vendor preset: disabled) Active: active (exited) since Thu 2018-10-25 10:48:01 EDT; 5 days ago Process: 1146 ExecStart=/usr/bin/python -m pulp.server.async.manage_workers start (code=exited, status=0/SUCCESS) Main PID: 1146 (code=exited, status=0/SUCCESS) Tasks: 0 Memory: 0B CGroup: /system.slice/pulp_workers.service Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable. - displaying smart_proxy_dynflow_core ● smart_proxy_dynflow_core.service - Foreman smart proxy dynflow core service Loaded: loaded (/usr/lib/systemd/system/smart_proxy_dynflow_core.service; enabled; vendor preset: disabled) Drop-In: /etc/systemd/system/smart_proxy_dynflow_core.service.d └─90-limits.conf Active: active (running) since Thu 2018-10-25 10:48:53 EDT; 5 days ago Docs: https://github.com/theforeman/smart_proxy_dynflow Process: 1104 ExecStart=/usr/bin/smart_proxy_dynflow_core -d -p /var/run/foreman-proxy/smart_proxy_dynflow_core.pid (code=exited, status=0/SUCCESS) Main PID: 2424 (ruby) Tasks: 12 Memory: 63.6M CGroup: /system.slice/smart_proxy_dynflow_core.service └─2424 ruby /usr/bin/smart_proxy_dynflow_core -d -p /var/run/foreman-proxy/smart_proxy_dynflow_core.pid Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable. - displaying tomcat ● tomcat.service - Apache Tomcat Web Application Container Loaded: loaded (/usr/lib/systemd/system/tomcat.service; enabled; vendor preset: disabled) Active: active (running) since Thu 2018-10-25 10:47:51 EDT; 5 days ago Main PID: 1141 (java) Tasks: 160 Memory: 1.3G CGroup: /system.slice/tomcat.service └─1141 /usr/lib/jvm/jre/bin/java -Xms1024m -Xmx4096m -classpath /usr/share/tomcat/bin/bootstrap.jar:/usr/share/tomcat/bin/tomcat-juli.jar:/usr/share/java/commons-daemon.jar -Dcatalina.base=/usr/share/tomcat -Dcatalina.home=/usr/share/tomcat -Djava.endorsed.dirs= -Djava.io.tmpdir=/var/cache/tomcat/temp -Djava.util.logging.config.file=/usr/share/tomcat/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager org.apache.catalina.startup.Bootstrap start Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable. - displaying dynflowd ● dynflowd.service - Foreman jobs daemon Loaded: loaded (/usr/lib/systemd/system/dynflowd.service; enabled; vendor preset: disabled) Active: active (running) since Thu 2018-10-25 10:49:15 EDT; 5 days ago Docs: https://theforeman.org Process: 1102 ExecStart=/usr/sbin/dynflowd start (code=exited, status=0/SUCCESS) Tasks: 19 Memory: 1.1G CGroup: /system.slice/dynflowd.service ├─2670 dynflow_executor_monitor └─2671 dynflow_executor Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable. - displaying goferd ● goferd.service - Gofer Agent Loaded: loaded (/usr/lib/systemd/system/goferd.service; enabled; vendor preset: disabled) Active: active (running) since Thu 2018-10-25 10:47:51 EDT; 5 days ago Main PID: 1126 (python) Tasks: 8 Memory: 137.2M CGroup: /system.slice/goferd.service └─1126 /usr/bin/python /usr/bin/goferd --foreground Oct 30 14:44:29 batman.usersys.redhat.com goferd[1126]: [ERROR][worker-0] gofer.messaging.adapter.connect:33 - connect: proton+amqps://subscription.rhsm.redhat.com:5647, failed: Connection amqps://subscription.rhsm.redhat.com:5647 disconnected: Condition('proton:io', 'recv: Connection refused') Oct 30 14:44:29 batman.usersys.redhat.com goferd[1126]: [INFO][worker-0] gofer.messaging.adapter.connect:35 - retry in 106 seconds Oct 30 14:46:16 batman.usersys.redhat.com goferd[1126]: [INFO][worker-0] gofer.messaging.adapter.connect:28 - connecting: proton+amqps://subscription.rhsm.redhat.com:5647 Oct 30 14:46:16 batman.usersys.redhat.com goferd[1126]: [INFO][worker-0] gofer.messaging.adapter.proton.connection:87 - open: URL: amqps://subscription.rhsm.redhat.com:5647|SSL: ca: /etc/rhsm/ca/redhat-uep.pem|key: None|certificate: /etc/pki/consumer/bundle.pem|host-validation: None Oct 30 14:46:16 batman.usersys.redhat.com goferd[1126]: [ERROR][worker-0] gofer.messaging.adapter.connect:33 - connect: proton+amqps://subscription.rhsm.redhat.com:5647, failed: Connection amqps://subscription.rhsm.redhat.com:5647 disconnected: Condition('proton:io', 'recv: Connection refused') Oct 30 14:46:16 batman.usersys.redhat.com goferd[1126]: [INFO][worker-0] gofer.messaging.adapter.connect:35 - retry in 106 seconds Oct 30 14:48:03 batman.usersys.redhat.com goferd[1126]: [INFO][worker-0] gofer.messaging.adapter.connect:28 - connecting: proton+amqps://subscription.rhsm.redhat.com:5647 Oct 30 14:48:03 batman.usersys.redhat.com goferd[1126]: [INFO][worker-0] gofer.messaging.adapter.proton.connection:87 - open: URL: amqps://subscription.rhsm.redhat.com:5647|SSL: ca: /etc/rhsm/ca/redhat-uep.pem|key: None|certificate: /etc/pki/consumer/bundle.pem|host-validation: None Oct 30 14:48:03 batman.usersys.redhat.com goferd[1126]: [ERROR][worker-0] gofer.messaging.adapter.connect:33 - connect: proton+amqps://subscription.rhsm.redhat.com:5647, failed: Connection amqps://subscription.rhsm.redhat.com:5647 disconnected: Condition('proton:io', 'recv: Connection refused') Oct 30 14:48:03 batman.usersys.redhat.com goferd[1126]: [INFO][worker-0] gofer.messaging.adapter.connect:35 - retry in 106 seconds \ displaying httpd ● httpd.service - The Apache HTTP Server Loaded: loaded (/usr/lib/systemd/system/httpd.service; enabled; vendor preset: disabled) Active: active (running) since Thu 2018-10-25 10:48:12 EDT; 5 days ago Docs: man:httpd(8) man:apachectl(8) Process: 16029 ExecReload=/usr/sbin/httpd $OPTIONS -k graceful (code=exited, status=0/SUCCESS) Main PID: 1103 (httpd) Status: "Total requests: 0; Current requests/sec: 0; Current traffic: 0 B/sec" Tasks: 245 Memory: 2.3G CGroup: /system.slice/httpd.service ├─ 1103 /usr/sbin/httpd -DFOREGROUND ├─ 1581 Passenger RackApp: /usr/share/foreman ├─ 4153 Passenger RackApp: /usr/share/foreman ├─ 7029 Passenger RackApp: /usr/share/foreman ├─ 7955 /usr/sbin/httpd -DFOREGROUND ├─ 8430 Passenger RackApp: /usr/share/foreman ├─16068 (wsgi:pulp) -DFOREGROUND ├─16069 (wsgi:pulp) -DFOREGROUND ├─16070 (wsgi:pulp) -DFOREGROUND ├─16071 (wsgi:pulp-cont -DFOREGROUND ├─16072 (wsgi:pulp-cont -DFOREGROUND ├─16073 (wsgi:pulp-cont -DFOREGROUND ├─16074 (wsgi:pulp_forg -DFOREGROUND ├─16075 PassengerWatchdog ├─16078 PassengerHelperAgent ├─16086 PassengerLoggingAgent ├─16093 /usr/sbin/httpd -DFOREGROUND ├─16094 /usr/sbin/httpd -DFOREGROUND ├─16095 /usr/sbin/httpd -DFOREGROUND ├─16096 /usr/sbin/httpd -DFOREGROUND ├─16097 /usr/sbin/httpd -DFOREGROUND ├─16098 /usr/sbin/httpd -DFOREGROUND ├─16099 /usr/sbin/httpd -DFOREGROUND ├─16100 /usr/sbin/httpd -DFOREGROUND ├─16375 /bin/bash /usr/bin/tfm-ruby /usr/share/gems/gems/passenger-4.0.18/helper-scripts/rack-preloader.rb ├─16383 scl enable tfm bash /tmp/tmp.kjzeJ0xLns ├─16384 /bin/bash /var/tmp/sclkEy04T ├─16408 bash /tmp/tmp.kjzeJ0xLns ├─16409 Passenger AppPreloader: /usr/share/foreman ├─16585 /usr/sbin/httpd -DFOREGROUND ├─16643 /usr/sbin/httpd -DFOREGROUND ├─17700 /usr/sbin/httpd -DFOREGROUND ├─17843 /usr/sbin/httpd -DFOREGROUND ├─17897 /usr/sbin/httpd -DFOREGROUND ├─18709 /usr/sbin/httpd -DFOREGROUND └─19706 /usr/sbin/httpd -DFOREGROUND Oct 30 14:06:50 batman.usersys.redhat.com pulp[16069]: kombu.transport.qpid:INFO: Connected to qpid with SASL mechanism ANONYMOUS Oct 30 14:06:55 batman.usersys.redhat.com pulp[16069]: kombu.transport.qpid:INFO: Connected to qpid with SASL mechanism ANONYMOUS Oct 30 14:23:50 batman.usersys.redhat.com pulp[16068]: kombu.transport.qpid:INFO: Connected to qpid with SASL mechanism ANONYMOUS Oct 30 14:23:51 batman.usersys.redhat.com pulp[16068]: gofer.messaging.adapter.connect:INFO: connecting: qpid+ssl://localhost:5671 Oct 30 14:23:51 batman.usersys.redhat.com pulp[16068]: gofer.messaging.adapter.qpid.connection:INFO: open: URL: ssl://localhost|SSL: ca: /etc/pki/katello/certs/katello-default-ca.crt|key: None|certificate: /etc/pki/katello/qpid_client_striped.crt|host-validation: False Oct 30 14:23:51 batman.usersys.redhat.com pulp[16068]: gofer.messaging.adapter.qpid.connection:INFO: opened: qpid+ssl://localhost:5671 Oct 30 14:23:51 batman.usersys.redhat.com pulp[16068]: gofer.messaging.adapter.connect:INFO: connected: qpid+ssl://localhost:5671 Oct 30 14:23:51 batman.usersys.redhat.com pulp[16068]: gofer.messaging.adapter.connect:INFO: connecting: qpid+ssl://localhost:5671 Oct 30 14:23:51 batman.usersys.redhat.com pulp[16068]: gofer.messaging.adapter.connect:INFO: connected: qpid+ssl://localhost:5671 Oct 30 14:23:51 batman.usersys.redhat.com pulp[16068]: gofer.messaging.adapter.qpid.connection:INFO: closed: qpid+ssl://localhost:5671 \ displaying puppetserver ● puppetserver.service - puppetserver Service Loaded: loaded (/usr/lib/systemd/system/puppetserver.service; enabled; vendor preset: disabled) Active: active (running) since Thu 2018-10-25 10:49:08 EDT; 5 days ago Process: 1174 ExecStart=/opt/puppetlabs/server/apps/puppetserver/bin/puppetserver start (code=exited, status=0/SUCCESS) Main PID: 1224 (java) Tasks: 75 Memory: 1.6G CGroup: /system.slice/puppetserver.service └─1224 /usr/bin/java -Xms2G -Xmx2G -XX:MaxPermSize=256m -Djava.security.egd=/dev/urandom -XX:OnOutOfMemoryError=kill -9 %p -cp /opt/puppetlabs/server/apps/puppetserver/puppet-server-release.jar:/opt/puppetlabs/server/apps/puppetserver/jruby-1_7.jar:/opt/puppetlabs/server/data/puppetserver/jars/* clojure.main -m puppetlabs.trapperkeeper.main --config /etc/puppetlabs/puppetserver/conf.d --bootstrap-config /etc/puppetlabs/puppetserver/services.d/,/opt/puppetlabs/server/apps/puppetserver/config/services.d/ --restart-file /opt/puppetlabs/server/data/puppetserver/restartcounter Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable. \ displaying foreman-proxy ● foreman-proxy.service - Foreman Proxy Loaded: loaded (/usr/lib/systemd/system/foreman-proxy.service; enabled; vendor preset: disabled) Active: active (running) since Thu 2018-10-25 10:48:33 EDT; 5 days ago Main PID: 1130 (ruby) Tasks: 8 Memory: 827.4M CGroup: /system.slice/foreman-proxy.service └─1130 ruby /usr/share/foreman-proxy/bin/smart-proxy --no-daemonize Oct 30 14:40:25 batman.usersys.redhat.com smart-proxy[1130]: dhcp-12-213-135.gsslab.rdu.redhat.com - - [30/Oct/2018:14:40:24 EDT] "POST /compliance/arf/1 HTTP/1.1" 200 0 Oct 30 14:40:25 batman.usersys.redhat.com smart-proxy[1130]: - -> /compliance/arf/1 Oct 30 14:44:59 batman.usersys.redhat.com smart-proxy[1130]: dhcp-12-213-135.gsslab.rdu.redhat.com - - [30/Oct/2018:14:44:58 EDT] "POST /compliance/arf/2 HTTP/1.1" 200 0 Oct 30 14:44:59 batman.usersys.redhat.com smart-proxy[1130]: - -> /compliance/arf/2 Oct 30 14:45:03 batman.usersys.redhat.com smart-proxy[1130]: dhcp-12-213-107.gsslab.rdu.redhat.com - - [30/Oct/2018:14:45:02 EDT] "POST /compliance/arf/2 HTTP/1.1" 200 0 Oct 30 14:45:03 batman.usersys.redhat.com smart-proxy[1130]: - -> /compliance/arf/2 Oct 30 14:45:22 batman.usersys.redhat.com smart-proxy[1130]: dhcp-12-213-107.gsslab.rdu.redhat.com - - [30/Oct/2018:14:45:22 EDT] "POST /compliance/arf/1 HTTP/1.1" 200 0 Oct 30 14:45:22 batman.usersys.redhat.com smart-proxy[1130]: - -> /compliance/arf/1 Oct 30 14:45:24 batman.usersys.redhat.com smart-proxy[1130]: dhcp-12-213-135.gsslab.rdu.redhat.com - - [30/Oct/2018:14:45:23 EDT] "POST /compliance/arf/1 HTTP/1.1" 200 0 Oct 30 14:45:24 batman.usersys.redhat.com smart-proxy[1130]: - -> /compliance/arf/1 \ All services are running [OK] --------------------------------------------------------------------------------
Brad, I let the task sit overnight just to be sure it wasn't due to my infrastructure being slow. Here is the task this morning: Action: Actions::Pulp::Consumer::ContentUpdate State: waiting for Pulp to start the task Input: {"consumer_uuid"=>"0b166023-f6bb-443e-97a5-a80d578e651b", "type"=>"rpm", "args"=>["dhclient-4.2.5-58.el7_4.4.x86_64"], "remote_user"=>"admin", "remote_cp_user"=>"admin"} Output: {"pulp_tasks"=> [{"exception"=>nil, "task_type"=>nil, "_href"=>"/pulp/api/v2/tasks/272d7d68-90bf-407b-bda1-8d41b4ad1c46/", "task_id"=>"272d7d68-90bf-407b-bda1-8d41b4ad1c46", "tags"=> ["pulp:consumer:0b166023-f6bb-443e-97a5-a80d578e651b", "pulp:action:unit_update"], "finish_time"=>nil, "_ns"=>"task_status", "start_time"=>nil, "traceback"=>nil, "spawned_tasks"=>[], "progress_report"=>{}, "queue"=>"agent.dq2", "state"=>"waiting", "worker_name"=>"agent", "result"=>nil, "error"=>nil, "_id"=>{"$oid"=>"5bd8a1b7882c103ec4f5ea40"}, "id"=>"5bd8a1b7882c103ec4f5ea40"}], "poll_attempts"=>{"total"=>3897, "failed"=>0}}
The reported issue is not reproducible with below steps: 1. Installed satellite6.3 2. Registered a rhel7.5 client 3. Package install from satellite to client - working fine 4. Upgraded Satellite 6.3 -> 6.4 via foreman-maintain 5. Re-validated step 3- working fine 6. Upgraded client with 6.4 tools bits 7. Performed step3 again and didn't see the issue. Note: we explicitly tried package push and pull and it was working fine before and after 6.4 sat/client upgrade
Additionally, client is pointed to gofer-2.12.1-1 after upgrade
@Taft: Hey, As per comment5 issue is not reproducible. Could you please review steps in comment5 to ensure if we are following similar steps as you or is there any deviation ?
The root cause is that the new version of katello-agent was missing a 'Requires' for a particular version of katello-host-tools which underwent some code reorganization in 6.4. In other words the 3.3.5 katello-agent and the 3.3.1 katello-host-tools rpm are not compatible. A workaround is to 'yum upgrade katello-host-tools' and restart goferd: 'systemctl restart goferd' until we release a new katello-agent RPM with the corrected dependency.
[root@drone73 ~]# systemctl status goferd -l ● goferd.service - Gofer Agent Loaded: loaded (/usr/lib/systemd/system/goferd.service; enabled; vendor preset: disabled) Active: active (running) since Fri 2018-12-14 09:16:20 EST; 9min ago Main PID: 31730 (python) CGroup: /system.slice/goferd.service └─31730 /usr/bin/python /usr/bin/goferd --foreground Dec 14 09:16:20 drone73.usersys.redhat.com systemd[1]: Starting Gofer Agent... Dec 14 09:16:20 drone73.usersys.redhat.com goferd[31730]: [INFO][Thread-1] gofer.rmi.store:108 - Using: /var/lib/gofer/messaging/pending/demo Dec 14 09:16:20 drone73.usersys.redhat.com goferd[31730]: [WARNING][MainThread] gofer.agent.plugin:647 - plugin:demo, DISABLED Dec 14 09:16:20 drone73.usersys.redhat.com goferd[31730]: [INFO][Thread-2] gofer.rmi.store:108 - Using: /var/lib/gofer/messaging/pending/katello Dec 14 09:16:20 drone73.usersys.redhat.com goferd[31730]: [ERROR][MainThread] gofer.agent.plugin:703 - plugin:katello, import failed Dec 14 09:16:20 drone73.usersys.redhat.com goferd[31730]: [ERROR][MainThread] gofer.agent.plugin:703 - Traceback (most recent call last): Dec 14 09:16:20 drone73.usersys.redhat.com goferd[31730]: [ERROR][MainThread] gofer.agent.plugin:703 - File "/usr/lib/python2.7/site-packages/gofer/agent/plugin.py", line 687, in _load Dec 14 09:16:20 drone73.usersys.redhat.com goferd[31730]: [ERROR][MainThread] gofer.agent.plugin:703 - plugin.impl = __import__(path, {}, {}, [path.split('.')[-1]]) Dec 14 09:16:20 drone73.usersys.redhat.com goferd[31730]: [ERROR][MainThread] gofer.agent.plugin:703 - ImportError: No module named katello.agent.goferd.plugin Dec 14 09:16:20 drone73.usersys.redhat.com goferd[31730]: [INFO][MainThread] gofer.agent.main:92 - agent started. [root@drone73 ~]# rpm -qa | grep katello-host katello-host-tools-3.1.0-2.el7sat.noarch katello-host-tools-fact-plugin-3.1.0-2.el7sat.noarch Updating to the latest katello-host-tools: [root@drone73 ~]# yum update katello-host-tools Loaded plugins: enabled_repos_upload, package_upload, product-id, search-disabled-repos, subscription-manager rhel-7-server-rpms | 2.0 kB 00:00:00 rhel-7-server-satellite-tools-6.4-rpms | 2.1 kB 00:00:00 Resolving Dependencies There are unfinished transactions remaining. You might consider running yum-complete-transaction, or "yum-complete-transaction --cleanup-only" and "yum history redo last", first to finish them. If those don't work you'll have to try removing/installing packages by hand (maybe package-cleanup can help). --> Running transaction check ---> Package katello-host-tools.noarch 0:3.1.0-2.el7sat will be updated ---> Package katello-host-tools.noarch 0:3.3.5-3.el7sat will be an update --> Finished Dependency Resolution Dependencies Resolved ====================================================================================================================== Package Arch Version Repository Size ====================================================================================================================== Updating: katello-host-tools noarch 3.3.5-3.el7sat rhel-7-server-satellite-tools-6.4-rpms 31 k Transaction Summary ====================================================================================================================== Upgrade 1 Package Total download size: 31 k Is this ok [y/d/N]: y Downloading packages: Delta RPMs disabled because /usr/bin/applydeltarpm not installed. katello-host-tools-3.3.5-3.el7sat.noarch.rpm | 31 kB 00:00:00 Running transaction check Running transaction test Transaction test succeeded Running transaction Updating : katello-host-tools-3.3.5-3.el7sat.noarch 1/2 Cleanup : katello-host-tools-3.1.0-2.el7sat.noarch 2/2 Loaded plugins: product-id Loaded plugins: product-id Uploading Package Profile rhel-7-server-rpms/7Server/x86_64/productid | 2.1 kB 00:00:00 Verifying : katello-host-tools-3.3.5-3.el7sat.noarch 1/2 Verifying : katello-host-tools-3.1.0-2.el7sat.noarch 2/2 Updated: katello-host-tools.noarch 0:3.3.5-3.el7sat Complete! Uploading Enabled Repositories Report Loaded plugins: product-id You have mail in /var/spool/mail/root [root@drone73 ~]# rpm -qa | grep katello-agent katello-agent-3.3.5-3.el7sat.noarch No more errors with the latest katello-host-tools rpm. Issue appears to be fixed: [root@drone73 ~]# rpm -qa | grep katello-agent katello-agent-3.3.5-3.el7sat.noarch [root@drone73 ~]# systemctl restart goferd [root@drone73 ~]# systemctl status goferd -l ● goferd.service - Gofer Agent Loaded: loaded (/usr/lib/systemd/system/goferd.service; enabled; vendor preset: disabled) Active: active (running) since Fri 2018-12-14 09:29:15 EST; 5s ago Main PID: 32206 (python) CGroup: /system.slice/goferd.service └─32206 /usr/bin/python /usr/bin/goferd --foreground Dec 14 09:29:16 drone73.usersys.redhat.com goferd[32206]: [INFO][worker-0] gofer.messaging.adapter.proton.connection:87 - open: URL: amqps://batman.usersys.redhat.com:5647|SSL: ca: /etc/rhsm/ca/katello-default-ca.pem|key: None|certificate: /etc/pki/consumer/bundle.pem|host-validation: None Dec 14 09:29:16 drone73.usersys.redhat.com goferd[32206]: [INFO][MainThread] gofer.agent.main:92 - agent started. Dec 14 09:29:16 drone73.usersys.redhat.com goferd[32206]: [INFO][worker-0] gofer.messaging.adapter.proton.connection:92 - opened: proton+amqps://batman.usersys.redhat.com:5647 Dec 14 09:29:16 drone73.usersys.redhat.com goferd[32206]: [INFO][worker-0] gofer.messaging.adapter.connect:30 - connected: proton+amqps://batman.usersys.redhat.com:5647 Dec 14 09:29:16 drone73.usersys.redhat.com goferd[32206]: [INFO][worker-0] gofer.messaging.adapter.proton.connection:131 - closed: proton+amqps://batman.usersys.redhat.com:5647 Dec 14 09:29:16 drone73.usersys.redhat.com goferd[32206]: [INFO][pulp.agent.7fc523c5-4916-4ead-94f4-fef139c1f65c] gofer.messaging.adapter.connect:28 - connecting: proton+amqps://batman.usersys.redhat.com:5647 Dec 14 09:29:16 drone73.usersys.redhat.com goferd[32206]: [INFO][pulp.agent.7fc523c5-4916-4ead-94f4-fef139c1f65c] gofer.messaging.adapter.proton.connection:87 - open: URL: amqps://batman.usersys.redhat.com:5647|SSL: ca: /etc/rhsm/ca/katello-default-ca.pem|key: None|certificate: /etc/pki/consumer/bundle.pem|host-validation: None Dec 14 09:29:16 drone73.usersys.redhat.com goferd[32206]: [INFO][worker-0] gofer.agent.plugin:379 - plugin:katello, attached => pulp.agent.7fc523c5-4916-4ead-94f4-fef139c1f65c Dec 14 09:29:17 drone73.usersys.redhat.com goferd[32206]: [INFO][pulp.agent.7fc523c5-4916-4ead-94f4-fef139c1f65c] gofer.messaging.adapter.proton.connection:92 - opened: proton+amqps://batman.usersys.redhat.com:5647 Dec 14 09:29:17 drone73.usersys.redhat.com goferd[32206]: [INFO][pulp.agent.7fc523c5-4916-4ead-94f4-fef139c1f65c] gofer.messaging.adapter.connect:30 - connected: proton+amqps://batman.usersys.redhat.com:5647 Looks fixed to me with the latest release of katello-host-tools.
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHSA-2019:1222