On 08/01/2016 10:52 AM, Chris Duryee wrote:
>
>
> On 08/01/2016 09:49 AM, Rick Langston wrote:
>> Thank you for help on this
>>
>> yes here is the actual capture
>>
>
> Thanks for the capture of the logs.
>
> What is the output of systemctl status qpidd.service? I am curious if
> only celerybeat is unable to connect, or if there is some other issue.
one more thing to check, as root please run:
qpid-stat --ssl-certificate /etc/pki/katello/certs/java-client.crt
--ssl-key /etc/pki/katello/private/java-client.key -b
"amqps://$(hostname -f):5671" -q
If qpid is accepting connections, it should output some stuff about queues.
>
> If you want to restart qpidd, the best way is to just do a
> katello-service stop. A number of other services depend on qpid, so it's
> easiest to just down everything, ensure qpidd is stopped, then bring it
> all back up via the script.
>
>> command line output
>> [root@dscaprv01 tmp]# systemctl restart pulp_celerybeat.service
>> [root@dscaprv01 tmp]# systemctl status pulp_celerybeat.service
>> ● pulp_celerybeat.service - Pulp's Celerybeat
>> Loaded: loaded (/usr/lib/systemd/system/pulp_celerybeat.service;
>> enabled; vendor preset: disabled)
>> Active: active (running) since Mon 2016-08-01 08:34:20 CDT; 7s ago
>> Main PID: 5887 (celery)
>> CGroup: /system.slice/pulp_celerybeat.service
>> └─5887 /usr/bin/python /usr/bin/celery beat
>> --app=pulp.server.async.celery_instance.celery
>> --scheduler=pulp.server.async.scheduler.Scheduler
>>
>> Aug 01 08:34:20 dscaprv01.corp.acxiom.net systemd[1]: Started Pulp's
>> Celerybeat.
>> Aug 01 08:34:20 dscaprv01.corp.acxiom.net systemd[1]: Starting Pulp's
>> Celerybeat...
>> Aug 01 08:34:25 dscaprv01.corp.acxiom.net pulp[5887]: celery.beat:INFO:
>> beat: Starting...
>> Aug 01 08:34:25 dscaprv01.corp.acxiom.net pulp[5887]:
>> pulp.server.db.connection:INFO: Attempting to connect to localhost:27017
>> Aug 01 08:34:25 dscaprv01.corp.acxiom.net pulp[5887]:
>> pulp.server.async.scheduler:INFO: Worker Timeout Monitor Started
>> Aug 01 08:34:25 dscaprv01.corp.acxiom.net pulp[5887]:
>> pulp.server.db.connection:INFO: Attempting to connect to localhost:27017
>> Aug 01 08:34:26 dscaprv01.corp.acxiom.net pulp[5887]:
>> pulp.server.db.connection:INFO: Write concern for Mongo connection: {}
>> [root@dscaprv01 tmp]# systemctl status pulp_celerybeat.service
>> ● pulp_celerybeat.service - Pulp's Celerybeat
>> Loaded: loaded (/usr/lib/systemd/system/pulp_celerybeat.service;
>> enabled; vendor preset: disabled)
>> Active: inactive (dead) since Mon 2016-08-01 08:34:31 CDT; 18s ago
>> Process: 5887 ExecStart=/usr/bin/celery beat
>> --app=pulp.server.async.celery_instance.celery
>> --scheduler=pulp.server.async.scheduler.Scheduler (code=exited,
>> status=0/SUCCESS)
>> Main PID: 5887 (code=exited, status=0/SUCCESS)
>>
>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net pulp[5887]: celery.beat:CRITICAL:
>> (5887-79264) raise Timeout("Connection attach timed out")
>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net pulp[5887]: celery.beat:CRITICAL:
>> (5887-79264) Timeout: Connection attach timed out
>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net celery[5887]: celery beat v3.1.11
>> (Cipater) is starting.
>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net celery[5887]: __ - ... __
>> - _
>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net celery[5887]: Configuration ->
>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net celery[5887]: . broker ->
>> qpid://dscaprv01.corp.acxiom.net:5671//
>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net celery[5887]: . loader ->
>> celery.loaders.app.AppLoader
>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net celery[5887]: . scheduler ->
>> pulp.server.async.scheduler.Scheduler
>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net celery[5887]: . logfile ->
>> [stderr]@%INFO
>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net celery[5887]: . maxinterval ->
>> now (0s)
>>
>> /var/log/messages output
>>
>> ==> /var/log/messages <==
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) beat
>> raised exception <class 'qpid.messaging.exceptions.Timeout'>:
>> Timeout('Connection attach timed out',)
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168)
>> Traceback (most recent call last):
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/celery/apps/beat.py", line 112, in
>> start_scheduler
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168)
>> beat.start()
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/celery/beat.py", line 462, in start
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168)
>> interval = self.scheduler.tick()
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/pulp/server/async/scheduler.py", line
>> 265, in tick
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) ret
>> = self.call_tick(self, celerybeat_name)
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/pulp/server/async/scheduler.py", line
>> 230, in call_tick
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) ret
>> = super(Scheduler, self).tick()
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/celery/beat.py", line 220, in tick
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168)
>> next_time_to_run = self.maybe_due(entry, self.publisher)
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/kombu/utils/__init__.py", line 325, in
>> __get__
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168)
>> value = obj.__dict__[self.__name__] = self.__get(obj)
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/celery/beat.py", line 342, in publisher
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168)
>> return self.Publisher(self._ensure_connected())
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/celery/beat.py", line 326, in
>> _ensure_connected
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168)
>> _error_handler, self.app.conf.BROKER_CONNECTION_MAX_RETRIES
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/kombu/connection.py", line 369, in
>> ensure_connection
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168)
>> interval_start, interval_step, interval_max, callback)
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/kombu/utils/__init__.py", line 246, in
>> retry_over_time
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168)
>> return fun(*args, **kwargs)
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/kombu/connection.py", line 237, in connect
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168)
>> return self.connection
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/kombu/connection.py", line 741, in
>> connection
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168)
>> self._connection = self._establish_connection()
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/kombu/connection.py", line 696, in
>> _establish_connection
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) conn
>> = self.transport.establish_connection()
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/kombu/transport/qpid.py", line 1600, in
>> establish_connection
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) conn
>> = self.Connection(**opts)
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/kombu/transport/qpid.py", line 1261, in
>> __init__
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168)
>> self._qpid_conn = establish(**self.connection_options)
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/qpid/messaging/endpoints.py", line 112,
>> in establish
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168)
>> conn.open(timeout=timeout)
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "<string>", line 6, in open
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/qpid/messaging/endpoints.py", line 323,
>> in open
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168)
>> self.attach(timeout=timeout)
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "<string>", line 6, in attach
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) File
>> "/usr/lib/python2.7/site-packages/qpid/messaging/endpoints.py", line 343,
>> in attach
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168)
>> raise Timeout("Connection attach timed out")
>> Aug 1 08:45:03 dscaprv01 pulp: celery.beat:CRITICAL: (7070-59168) Timeout:
>> Connection attach timed out
>> Aug 1 08:45:03 dscaprv01 celery: celery beat v3.1.11 (Cipater) is starting.
>> Aug 1 08:45:03 dscaprv01 celery: __ - ... __ - _
>> Aug 1 08:45:03 dscaprv01 celery: Configuration ->
>> Aug 1 08:45:03 dscaprv01 celery: . broker ->
>> qpid://dscaprv01.corp.acxiom.net:5671//
>> Aug 1 08:45:03 dscaprv01 celery: . loader -> celery.loaders.app.AppLoader
>> Aug 1 08:45:03 dscaprv01 celery: . scheduler ->
>> pulp.server.async.scheduler.Scheduler
>> Aug 1 08:45:03 dscaprv01 celery: . logfile -> [stderr]@%INFO
>> Aug 1 08:45:03 dscaprv01 celery: . maxinterval -> now (0s)
>>
>>
>> On Monday, August 1, 2016 at 8:43:45 AM UTC-5, Chris Duryee wrote:
>>>
>>>
>>>
>>> On 08/01/2016 09:39 AM, Rick Langston wrote:
>>>> The backend service all say ok but when a run a katelli-service status I
>>>> can see that celery.bet fails to status. if I restart the server it and
>>>> immediately check the status it says running but checking the status
>>> again
>>>> shows it timed out.
>>>>
>>>
>>> Is this the sequence of events?
>>>
>>> * service pulp_celerybeat start (outputs success)
>>> * service pulp_celerybeat status (outputs success)
>>> * wait some number of seconds
>>> * service pulp_celerybeat status (outputs error)
>>>
>>>>
>>>> No memory errros noted
>>>>
>>>>
>>>> [root@dscaprv01 tmp]# systemctl status pulp_celerybeat.service
>>>> ● pulp_celerybeat.service - Pulp's Celerybeat
>>>> Loaded: loaded (/usr/lib/systemd/system/pulp_celerybeat.service;
>>>> enabled; vendor preset: disabled)
>>>> Active: inactive (dead) since Mon 2016-08-01 08:34:31 CDT; 18s ago
>>>> Process: 5887 ExecStart=/usr/bin/celery beat
>>>> --app=pulp.server.async.celery_instance.celery
>>>> --scheduler=pulp.server.async.scheduler.Scheduler (code=exited,
>>>> status=0/SUCCESS)
>>>> Main PID: 5887 (code=exited, status=0/SUCCESS)
>>>>
>>>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net pulp[5887]:
>>> celery.beat:CRITICAL:
>>>> (5887-79264) raise Timeout("Connection attach timed out")
>>>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net pulp[5887]:
>>> celery.beat:CRITICAL:
>>>> (5887-79264) Timeout: Connection attach timed out
>>>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net celery[5887]: celery beat
>>> v3.1.11
>>>> (Cipater) is starting.
>>>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net celery[5887]: __ - ...
>>> __
>>>> - _
>>>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net celery[5887]: Configuration
>>> ->
>>>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net celery[5887]: . broker ->
>>>> qpid://dscaprv01.corp.acxiom.net:5671//
>>>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net celery[5887]: . loader ->
>>>> celery.loaders.app.AppLoader
>>>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net celery[5887]: . scheduler ->
>>>> pulp.server.async.scheduler.Scheduler
>>>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net celery[5887]: . logfile ->
>>>> [stderr]@%INFO
>>>> Aug 01 08:34:30 dscaprv01.corp.acxiom.net celery[5887]: . maxinterval
>>> ->
>>>> now (0s)
>>>>
>>>>
>>>> On Monday, August 1, 2016 at 8:22:46 AM UTC-5, Chris Duryee wrote:
>>>>>
>>>>>
>>>>>
>>>>> On 08/01/2016 08:50 AM, Rick Langston wrote:
>>>>>> I do see this issue in messages but not sure if its related
>>>>>>
>>>>>> Aug 1 07:25:16 dscaprv01 pulp: celery.beat:CRITICAL: (28691-76416)
>>> beat
>>>>>> raised exception <class 'qpid.messaging.exceptions.Timeout'>:
>>>>>> Timeout('Connection attach timed out',)
>>>>>> Aug 1 07:25:16 dscaprv01 pulp: celery.beat:CRITICAL: (28691-76416)
>>>>>> Traceback (most recent call last):
>>>>>> Aug 1 07:25:16 dscaprv01 pulp: celery.beat:CRITICAL: (28691-76416)
>>>>> File
>>>>>> "/usr/lib/python2.7/site-packages/celery/apps/beat.py", line 112, in
>>>>>> start_scheduler
>>>>>> Aug 1 07:25:16 dscaprv01 pulp: celery.beat:CRITICAL: (28691-76416)
>>>
>>>>>> beat.start()
>>>>>>
>>>>>
>>>>>
>>>>> That is the likely culprit:)
>>>>>
>>>>> Next time your task hangs, check in the "/about" page on your Katello
>>>>> instance and ensure everything under "Backend System Status" says "OK"
>>>>> with no further message.
>>>>>
>>>>> If there are pulp errors, a possible quick fix is to ensure qpidd is
>>>>> still running, then restart pulp_workers, pulp_celerybeat and
>>>>> pulp_resource_manager. I suspect your task will get picked up after
>>> that.
>>>>>
>>>>> Also, please check dmesg for out-of-memory errors. There are some other
>>>>> possible things we can check, but I would be curious first about the
>>>>> backend system status output.
>>>>>
>>>>>>
>>>>>> On Monday, August 1, 2016 at 7:12:26 AM UTC-5, Chris Duryee wrote:
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> On 08/01/2016 07:54 AM, Rick Langston wrote:
>>>>>>>> Hello
>>>>>>>>
>>>>>>>> I seem to be having some odd behavior with this version. With a
>>> fresh
>>>>>>>> install on centos 7 I have setup a product which completes normally
>>>>> but
>>>>>>>> when I discover a repo and save them i get these meta data task that
>>>>>>> seem
>>>>>>>> to just wait forever. Any ideas what can be the culprit
>>>>>>>>
>>>>>>>
>>>>>>> Are there any related errors in /var/log/messages?
>>>>>>>
>>>>>>>>
>>>>>>>> Action:
>>>>>>>>
>>>>>>>> Actions::Pulp::Repository::DistributorPublish
>>>>>>>>
>>>>>>>> State: waiting for Pulp to start the task
>>>>>>>> Input:
>>>>>>>>
>>>>>>>> {"pulp_id"=>"test-centos-6_updates_x86_64",
>>>>>>>> "distributor_type_id"=>"yum_distributor",
>>>>>>>> "source_pulp_id"=>nil,
>>>>>>>> "dependency"=>nil,
>>>>>>>> "remote_user"=>"admin",
>>>>>>>> "remote_cp_user"=>"admin",
>>>>>>>> "locale"=>"en"}
>>>>>>>>
>>>>>>>> Output:
>>>>>>>>
>>>>>>>> {"pulp_tasks"=>
>>>>>>>> [{"exception"=>nil,
>>>>>>>> "task_type"=>"pulp.server.managers.repo.publish.publish",
>>>>>>>>
>>>>> "_href"=>"/pulp/api/v2/tasks/a40815d5-9ba4-463a-8216-338cdcc4b1cc/",
>>>>>>>> "task_id"=>"a40815d5-9ba4-463a-8216-338cdcc4b1cc",
>>>>>>>> "tags"=>
>>>>>>>> ["pulp:repository:test-centos-6_updates_x86_64",
>>>>>>> "pulp:action:publish"],
>>>>>>>> "finish_time"=>nil,
>>>>>>>> "_ns"=>"task_status",
>>>>>>>> "start_time"=>nil,
>>>>>>>> "traceback"=>nil,
>>>>>>>> "spawned_tasks"=>[],
>>>>>>>> "progress_report"=>{},
>>>>>>>> "queue"=>"None.dq",
>>>>>>>> "state"=>"waiting",
>>>>>>>> "worker_name"=>nil,
>>>>>>>> "result"=>nil,
>>>>>>>> "error"=>nil,
>>>>>>>> "_id"=>{"$oid"=>"579f32aa95c48c6a54257674"},
>>>>>>>> "id"=>"579f32aa95c48c6a54257674"}],
>>>>>>>> "poll_attempts"=>{"total"=>100, "failed"=>0}}
>>>>>>>>
>>>>>>>
>>>>>>
>>>>>
>>>>
>>>
>>
>
--
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 [email protected].
To post to this group, send email to [email protected].
Visit this group at https://groups.google.com/group/foreman-users.
For more options, visit https://groups.google.com/d/optout.
