On 08/01/2016 04:14 PM, Rick Langston wrote:
> Strange, If I restart the service "/bin/systemctl status
> pulp_celerybeat.service" it will eventually start. Any ideas?
I'm glad it eventually restarts:) that is strange though that fails at
first but eventually works.
Can you send the output of foreman-debug? This will create an an archive
with system information and log files that we can peruse to debug further.
>
>
> On Monday, August 1, 2016 at 12:19:27 PM UTC-5, Chris Duryee wrote:
>>
>>
>>
>> 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.
