Django background worker, doesn't work as expected

huxaiphaer · October 23, 2023, 7:20pm

I created a background worker in DJango, it has no yaml file, but it doesn’t seem to be working as expected.

In the startup command I added this ;

celery --app pixsar worker --loglevel=info --concurrency 2 & celery -A pixsar beat

Here are the logs I get,

ct 22 04:17:10 PM   -------------- celery@srv-ckluuhg710pc73eb227g-7d8f45c48f-r9hgp v5.1.2 (sun-harmonics)
Oct 22 04:17:10 PM  --- ***** -----
Oct 22 04:17:10 PM  -- ******* ---- Linux-6.2.0-1012-aws-x86_64-with-glibc2.28 2023-10-22 13:17:10
Oct 22 04:17:10 PM  - *** --- * ---
Oct 22 04:17:10 PM  - ** ---------- [config]
Oct 22 04:17:10 PM  - ** ---------- .> app:         pixsar:0x7f64b493bd30
Oct 22 04:17:10 PM  - ** ---------- .> transport:   redis://red-cjgglkc1ja0c73cq6h70:6379//
Oct 22 04:17:10 PM  - ** ---------- .> results:     redis://red-cjgglkc1ja0c73cq6h70:6379/
Oct 22 04:17:10 PM  - *** --- * --- .> concurrency: 2 (prefork)
Oct 22 04:17:10 PM  -- ******* ---- .> task events: OFF (enable -E to monitor tasks in this worker)
Oct 22 04:17:10 PM  --- ***** -----
Oct 22 04:17:10 PM   -------------- [queues]
Oct 22 04:17:10 PM                  .> celery           exchange=celery(direct) key=celery
Oct 22 04:17:10 PM  
Oct 22 04:17:10 PM  
Oct 22 04:17:10 PM  [tasks]
Oct 22 04:17:10 PM    . events.tasks.generate_video_for_stopped_events
Oct 22 04:17:10 PM  
Oct 22 04:17:11 PM  [2023-10-22 13:17:11,129: INFO/MainProcess] Connected to redis://red-cjgglkc1ja0c73cq6h70:6379//
Oct 22 04:17:11 PM  [2023-10-22 13:17:11,145: INFO/MainProcess] mingle: searching for neighbors
Oct 22 04:17:12 PM  [2023-10-22 13:17:12,196: INFO/MainProcess] mingle: all alone
Oct 22 04:17:12 PM  [2023-10-22 13:17:12,381: WARNING/MainProcess] /opt/render/project/src/.venv/lib/python3.10/site-packages/celery/fixups/django.py:203: UserWarning: Using settings.DEBUG leads to a memory
Oct 22 04:17:12 PM              leak, never use this setting in production environments!
Oct 22 04:17:12 PM    warnings.warn('''Using settings.DEBUG leads to a memory
Oct 22 04:17:12 PM  
Oct 22 04:17:12 PM  [2023-10-22 13:17:12,381: INFO/MainProcess] celery@srv-ckluuhg710pc73eb227g-7d8f45c48f-r9hgp ready.
Oct 23 10:37:20 PM  ==> Deploying...
Oct 23 10:38:12 PM  Your service is live 🎉
Oct 23 10:38:12 PM  ==> Using Node version 14.17.0 (default)
Oct 23 10:38:12 PM  ==> Docs on specifying a Node version: https://render.com/docs/node-version
Oct 23 10:38:16 PM  ==> Running 'celery --app pixsar worker --loglevel=info --concurrency 2 & celery -A pixsar beat'
Oct 23 10:38:28 PM  [2023-10-23 19:38:28,786: INFO/MainProcess] Task events.tasks.generate_video_for_stopped_events[afd85b78-24ee-4a19-aa9e-abbd22176126] received
Oct 23 10:38:28 PM  
Oct 23 10:38:28 PM   -------------- celery@srv-ckluuhg710pc73eb227g-6dbb59c96-zgz4x v5.1.2 (sun-harmonics)
Oct 23 10:38:28 PM  --- ***** -----
Oct 23 10:38:28 PM  -- ******* ---- Linux-6.2.0-1012-aws-x86_64-with-glibc2.28 2023-10-23 19:38:28
Oct 23 10:38:28 PM  - *** --- * ---
Oct 23 10:38:28 PM  - ** ---------- [config]
Oct 23 10:38:28 PM  - ** ---------- .> app:         pixsar:0x7f5b94323c40
Oct 23 10:38:28 PM  - ** ---------- .> transport:   redis://red-cjgglkc1ja0c73cq6h70:6379//
Oct 23 10:38:28 PM  - ** ---------- .> results:     redis://red-cjgglkc1ja0c73cq6h70:6379/
Oct 23 10:38:28 PM  - *** --- * --- .> concurrency: 2 (prefork)
Oct 23 10:38:28 PM  -- ******* ---- .> task events: OFF (enable -E to monitor tasks in this worker)
Oct 23 10:38:28 PM  --- ***** -----
Oct 23 10:38:28 PM   -------------- [queues]
Oct 23 10:38:28 PM                  .> celery           exchange=celery(direct) key=celery
Oct 23 10:38:28 PM  
Oct 23 10:38:28 PM  
Oct 23 10:38:28 PM  [tasks]
Oct 23 10:38:28 PM    . events.tasks.generate_video_for_stopped_events
Oct 23 10:38:28 PM  
Oct 23 10:38:29 PM  [2023-10-23 19:38:29,377: INFO/MainProcess] Connected to redis://red-cjgglkc1ja0c73cq6h70:6379//
Oct 23 10:38:29 PM  [2023-10-23 19:38:29,385: INFO/MainProcess] mingle: searching for neighbors
Oct 23 10:38:29 PM  [2023-10-23 19:38:29,399: INFO/MainProcess] sync with celery@srv-ckluuhg710pc73eb227g-6dbb59c96-zgz4x
Oct 23 10:38:30 PM  [2023-10-23 19:38:30,405: INFO/MainProcess] mingle: sync with 1 nodes
Oct 23 10:38:30 PM  [2023-10-23 19:38:30,406: INFO/MainProcess] mingle: sync complete
Oct 23 10:38:30 PM  [2023-10-23 19:38:30,440: WARNING/MainProcess] /opt/render/project/src/.venv/lib/python3.10/site-packages/celery/fixups/django.py:203: UserWarning: Using settings.DEBUG leads to a memory
Oct 23 10:38:30 PM              leak, never use this setting in production environments!
Oct 23 10:38:30 PM    warnings.warn('''Using settings.DEBUG leads to a memory
Oct 23 10:38:30 PM  
Oct 23 10:38:30 PM  [2023-10-23 19:38:30,440: INFO/MainProcess] celery@srv-ckluuhg710pc73eb227g-6dbb59c96-zgz4x ready.
Oct 23 10:38:47 PM  [2023-10-23 19:38:47,934: ERROR/MainProcess] Process 'ForkPoolWorker-2' pid:70 exited with 'signal 9 (SIGKILL)'
Oct 23 10:38:47 PM  [2023-10-23 19:38:47,971: ERROR/MainProcess] Task handler raised error: WorkerLostError('Worker exited prematurely: signal 9 (SIGKILL) Job: 0.')
Oct 23 10:38:47 PM  Traceback (most recent call last):
Oct 23 10:38:47 PM    File "/opt/render/project/src/.venv/lib/python3.10/site-packages/billiard/pool.py", line 1265, in mark_as_worker_lost
Oct 23 10:38:47 PM      raise WorkerLostError(
Oct 23 10:38:47 PM  billiard.exceptions.WorkerLostError: Worker exited prematurely: signal 9 (SIGKILL) Job: 0.
Oct 23 10:39:12 PM  
Oct 23 10:39:12 PM  worker: Warm shutdown (MainProcess)
Oct 23 10:39:28 PM  [2023-10-23 19:39:28,833: INFO/MainProcess] Task events.tasks.generate_video_for_stopped_events[67a0da6a-222d-4d41-915a-6ef4d3822b26] received
Oct 23 10:39:36 PM  [2023-10-23 19:39:36,085: ERROR/MainProcess] Process 'ForkPoolWorker-2' pid:87 exited with 'signal 9 (SIGKILL)'
Oct 23 10:39:36 PM  [2023-10-23 19:39:36,122: ERROR/MainProcess] Task handler raised error: WorkerLostError('Worker exited prematurely: signal 9 (SIGKILL) Job: 0.')
Oct 23 10:39:36 PM  Traceback (most recent call last):
Oct 23 10:39:36 PM    File "/opt/render/project/src/.venv/lib/python3.10/site-packages/billiard/pool.py", line 1265, in mark_as_worker_lost
Oct 23 10:39:36 PM      raise WorkerLostError(
Oct 23 10:39:36 PM  billiard.exceptions.WorkerLostError: Worker exited prematurely: signal 9 (SIGKILL) Job: 0.
Oct 23 10:40:28 PM  [2023-10-23 19:40:28,876: INFO/MainProcess] Task events.tasks.generate_video_for_stopped_events[98a25f73-7e30-4938-85ef-85dea4b6c345] received
Oct 23 10:40:38 PM  [2023-10-23 19:40:38,009: ERROR/MainProcess] Process 'ForkPoolWorker-3' pid:106 exited with 'signal 9 (SIGKILL)'
Oct 23 10:40:38 PM  [2023-10-23 19:40:38,059: ERROR/MainProcess] Task handler raised error: WorkerLostError('Worker exited prematurely: signal 9 (SIGKILL) Job: 1.')
Oct 23 10:40:38 PM  Traceback (most recent call last):
Oct 23 10:40:38 PM    File "/opt/render/project/src/.venv/lib/python3.10/site-packages/billiard/pool.py", line 1265, in mark_as_worker_lost
Oct 23 10:40:38 PM      raise WorkerLostError(
Oct 23 10:40:38 PM  billiard.exceptions.WorkerLostError: Worker exited prematurely: signal 9 (SIGKILL) Job: 1.
Oct 23 10:41:28 PM  [2023-10-23 19:41:28,916: INFO/MainProcess] Task events.tasks.generate_video_for_stopped_events[5a2de8e4-5592-4fe9-aff7-b67a27d05433] received
Oct 23 10:41:36 PM  [2023-10-23 19:41:36,566: ERROR/MainProcess] Process 'ForkPoolWorker-4' pid:125 exited with 'signal 9 (SIGKILL)'
Oct 23 10:41:36 PM  [2023-10-23 19:41:36,578: ERROR/MainProcess] Task handler raised error: WorkerLostError('Worker exited prematurely: signal 9 (SIGKILL) Job: 2.')
Oct 23 10:41:36 PM  Traceback (most recent call last):
Oct 23 10:41:36 PM    File "/opt/render/project/src/.venv/lib/python3.10/site-packages/billiard/pool.py", line 1265, in mark_as_worker_lost
Oct 23 10:41:36 PM      raise WorkerLostError(
Oct 23 10:41:36 PM  billiard.exceptions.WorkerLostError: Worker exited prematurely: signal 9 (SIGKILL) Job: 2.
Oct 23 10:42:28 PM  [2023-10-23 19:42:28,958: INFO/MainProcess] Task events.tasks.generate_video_for_stopped_events[e9cf5813-ff05-44b0-a36c-879bbc79926f] received
Oct 23 10:42:44 PM  [2023-10-23 19:42:44,564: ERROR/MainProcess] Process 'ForkPoolWorker-5' pid:144 exited with 'signal 9 (SIGKILL)'
Oct 23 10:42:44 PM  [2023-10-23 19:42:44,577: ERROR/MainProcess] Task handler raised error: WorkerLostError('Worker exited prematurely: signal 9 (SIGKILL) Job: 3.')
Oct 23 10:42:44 PM  Traceback (most recent call last):
Oct 23 10:42:44 PM    File "/opt/render/project/src/.venv/lib/python3.10/site-packages/billiard/pool.py", line 1265, in mark_as_worker_lost
Oct 23 10:42:44 PM      raise WorkerLostError(
Oct 23 10:42:44 PM  billiard.exceptions.WorkerLostError: Worker exited prematurely: signal 9 (SIGKILL) Job: 3.
Oct 23 10:43:29 PM  [2023-10-23 19:43:29,010: INFO/MainProcess] Task events.tasks.generate_video_for_stopped_events[0e5397ab-b8da-4e52-8b79-abb9bd985eed] received
Oct 23 10:43:44 PM  [2023-10-23 19:43:44,887: ERROR/MainProcess] Process 'ForkPoolWorker-6' pid:163 exited with 'signal 9 (SIGKILL)'
Oct 23 10:43:44 PM  [2023-10-23 19:43:44,899: ERROR/MainProcess] Task handler raised error: WorkerLostError('Worker exited prematurely: signal 9 (SIGKILL) Job: 4.')
Oct 23 10:43:44 PM  Traceback (most recent call last):
Oct 23 10:43:44 PM    File "/opt/render/project/src/.venv/lib/python3.10/site-packages/billiard/pool.py", line 1265, in mark_as_worker_lost
Oct 23 10:43:44 PM      raise WorkerLostError(
Oct 23 10:43:44 PM  billiard.exceptions.WorkerLostError: Worker exited prematurely: signal 9 (SIGKILL) Job: 4

Here;s the setup I have in my settings.py ,


# Add celery settings.
CELERY_BROKER_URL = os.getenv('CELERY_BROKER_URL')
CELERY_RESULT_BACKEND = os.getenv('CELERY_RESULT_BACKEND')
CELERY_ACCEPT_CONTENT = ['json']
CELERY_TASK_SERIALIZER = 'json'
CELERY_RESULT_SERIALIZER = 'json'
CELERY_TIMEZONE = 'UTC'

CELERY_BEAT_SCHEDULE = {
    'generate_video_for_stopped_events_every_10_min': {
        'task': 'events.tasks.generate_video_for_stopped_events',
        'schedule': timedelta(minutes=1),
    },
}

But locally, you could run the celery beat show the logs, if there happens to be any error you see it as well.

Regarding the environment variables are st as well, for REDIS am using the one from render.com
What am I missing here ?

mmaddex · October 23, 2023, 8:32pm

Hi there,

I see this in the error logs you’ve provided

Oct 22 04:10:44 PM ==> Running 'celery -app pixsar worker --loglevel=info --concurrency 2 'Oct 22 04:10:46 PM Usage: celery [OPTIONS] COMMAND [ARGS]...Oct 22 04:10:46 PM Try 'celery --help' for help.Oct 22 04:10:46 PM Oct 22 04:10:46 PM Error: no such option: -a

Could you try updating your start command with an extra dash (i.e. ... --app... )

Give that a try and let me know if it helps.

Regards,

Matt

huxaiphaer · October 24, 2023, 11:46am

Hi, I actually added that, It could have been a pasting issue, my command is here ;

celery --app pixsar worker --loglevel=info --concurrency 2

But the logs apparently are ;


23-4031-9ee4-451fd8f7e3b8] received
Oct 23 09:55:34 PM  
Oct 23 09:55:34 PM   -------------- celery@srv-ckluuhg710pc73eb227g-647445d9b4-mml88 v5.1.2 (sun-harmonics)
Oct 23 09:55:34 PM  --- ***** -----
Oct 23 09:55:34 PM  -- ******* ---- Linux-6.2.0-1012-aws-x86_64-with-glibc2.28 2023-10-23 19:55:34
Oct 23 09:55:34 PM  - *** --- * ---
Oct 23 09:55:34 PM  - ** ---------- [config]
Oct 23 09:55:34 PM  - ** ---------- .> app:         pixsar:0x7ff1a4f53d60
Oct 23 09:55:34 PM  - ** ---------- .> transport:   redis://red-cjgglkc1ja0c73cq6h70:6379//
Oct 23 09:55:34 PM  - ** ---------- .> results:     redis://red-cjgglkc1ja0c73cq6h70:6379/
Oct 23 09:55:34 PM  - *** --- * --- .> concurrency: 2 (prefork)
Oct 23 09:55:34 PM  -- ******* ---- .> task events: OFF (enable -E to monitor tasks in this worker)
Oct 23 09:55:34 PM  --- ***** -----
Oct 23 09:55:34 PM   -------------- [queues]
Oct 23 09:55:34 PM                  .> celery           exchange=celery(direct) key=celery
Oct 23 09:55:34 PM  
Oct 23 09:55:34 PM  
Oct 23 09:55:34 PM  [tasks]
Oct 23 09:55:34 PM    . events.tasks.generate_video_for_stopped_events
Oct 23 09:55:34 PM  
Oct 23 09:55:34 PM  [2023-10-23 19:55:34,572: INFO/MainProcess] Connected to redis://red-cjgglkc1ja0c73cq6h70:6379//
Oct 23 09:55:34 PM  [2023-10-23 19:55:34,579: INFO/MainProcess] mingle: searching for neighbors
Oct 23 09:55:34 PM  [2023-10-23 19:55:34,590: INFO/MainProcess] sync with celery@srv-ckluuhg710pc73eb227g-647445d9b4-mml88
Oct 23 09:55:35 PM  [2023-10-23 19:55:35,598: INFO/MainProcess] mingle: sync with 1 nodes
Oct 23 09:55:35 PM  [2023-10-23 19:55:35,598: INFO/MainProcess] mingle: sync complete
Oct 23 09:55:35 PM  [2023-10-23 19:55:35,622: WARNING/MainProcess] /opt/render/project/src/.venv/lib/python3.10/site-packages/celery/fixups/django.py:203: UserWarning: Using settings.DEBUG leads to a memory
Oct 23 09:55:35 PM              leak, never use this setting in production environments!
Oct 23 09:55:35 PM    warnings.warn('''Using settings.DEBUG leads to a memory
Oct 23 09:55:35 PM  
Oct 23 09:55:35 PM  [2023-10-23 19:55:35,622: INFO/MainProcess] celery@srv-ckluuhg710pc73eb227g-647445d9b4-mml88 ready.
Oct 23 09:55:36 PM  [2023-10-23 19:55:36,973: ERROR/MainProcess] Process 'ForkPoolWorker-18' pid:391 exited with 'signal 9 (SIGKILL)'
Oct 23 09:55:36 PM  [2023-10-23 19:55:36,985: ERROR/MainProcess] Task handler raised error: WorkerLostError('Worker exited prematurely: signal 9 (SIGKILL) Job: 16.')
Oct 23 09:55:36 PM  Traceback (most recent call last):
Oct 23 09:55:36 PM    File "/opt/render/project/src/.venv/lib/python3.10/site-packages/billiard/pool.py", line 1265, in mark_as_worker_lost
Oct 23 09:55:36 PM      raise WorkerLostError(
Oct 23 09:55:36 PM  billiard.exceptions.WorkerLostError: Worker exited prematurely: signal 9 (SIGKILL) Job: 16.
Oct 23 09:56:25 PM  
Oct 23 09:56:25 PM  worker: Warm shutdown (MainProcess)
Oct 23 09:56:30 PM  [2023-10-23 19:56:30,615: INFO/MainProcess] missed heartbeat from celery@srv-ckluuhg710pc73eb227g-6dbb59c96-zgz4x

I think there’s something extra wrong, on my local it works very well, here I can’t seem to get the exact logs, secondly, how best can I route to flower, it’s also included

huxaiphaer · October 24, 2023, 12:45pm

After a clear build and deploy triggered, Now the logs are as follows ;

ct 24 01:56:40 PM  Your service is live 🎉
Oct 24 01:56:42 PM  ==> Running 'celery --app pixsar worker --loglevel=info --concurrency 2'
Oct 24 01:56:49 PM  
Oct 24 01:56:49 PM   -------------- celery@srv-ckluuhg710pc73eb227g-985d57fdb-j42sn v5.1.2 (sun-harmonics)
Oct 24 01:56:49 PM  --- ***** -----
Oct 24 01:56:49 PM  -- ******* ---- Linux-6.2.0-1012-aws-x86_64-with-glibc2.28 2023-10-24 11:56:49
Oct 24 01:56:49 PM  - *** --- * ---
Oct 24 01:56:49 PM  - ** ---------- [config]
Oct 24 01:56:49 PM  - ** ---------- .> app:         pixsar:0x7f083d683d00
Oct 24 01:56:49 PM  - ** ---------- .> transport:   redis://red-cjgglkc1ja0c73cq6h70:6379//
Oct 24 01:56:49 PM  - ** ---------- .> results:     redis://red-cjgglkc1ja0c73cq6h70:6379/
Oct 24 01:56:49 PM  - *** --- * --- .> concurrency: 2 (prefork)
Oct 24 01:56:49 PM  -- ******* ---- .> task events: OFF (enable -E to monitor tasks in this worker)
Oct 24 01:56:49 PM  --- ***** -----
Oct 24 01:56:49 PM   -------------- [queues]
Oct 24 01:56:49 PM                  .> celery           exchange=celery(direct) key=celery
Oct 24 01:56:49 PM  
Oct 24 01:56:49 PM  
Oct 24 01:56:49 PM  [tasks]
Oct 24 01:56:49 PM    . events.tasks.generate_video_for_stopped_events
Oct 24 01:56:49 PM  
Oct 24 01:56:49 PM  [2023-10-24 11:56:49,776: INFO/MainProcess] Connected to redis://red-cjgglkc1ja0c73cq6h70:6379//
Oct 24 01:56:49 PM  [2023-10-24 11:56:49,787: INFO/MainProcess] mingle: searching for neighbors
Oct 24 01:56:49 PM  [2023-10-24 11:56:49,815: INFO/MainProcess] sync with celery@srv-ckluuhg710pc73eb227g-985d57fdb-j42sn
Oct 24 01:56:50 PM  [2023-10-24 11:56:50,822: INFO/MainProcess] mingle: sync with 1 nodes
Oct 24 01:56:50 PM  [2023-10-24 11:56:50,822: INFO/MainProcess] mingle: sync complete
Oct 24 01:56:50 PM  [2023-10-24 11:56:50,851: WARNING/MainProcess] /opt/render/project/src/.venv/lib/python3.10/site-packages/celery/fixups/django.py:203: UserWarning: Using settings.DEBUG leads to a memory
Oct 24 01:56:50 PM              leak, never use this setting in production environments!
Oct 24 01:56:50 PM    warnings.warn('''Using settings.DEBUG leads to a memory
Oct 24 01:56:50 PM  
Oct 24 01:56:50 PM  [2023-10-24 11:56:50,851: INFO/MainProcess] celery@srv-ckluuhg710pc73eb227g-985d57fdb-j42sn ready.
Oct 24 01:57:40 PM  
Oct 24 01:57:40 PM  worker: Warm shutdown (MainProcess)

But am not sure if the command is triggered, every after 1 minute?

mmaddex · October 24, 2023, 8:46pm

Hi there,

Could you try following the guidance from those logs and disable DEBUG to avoid a memory leak?

Regards,

Matt

system · November 23, 2023, 12:46pm

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.

Topic		Replies	Views
Background worker	11	1864	April 13, 2024
Can't see my Celery tasks running after deployement	4	2772	December 2, 2022
About build issue	2	214	August 27, 2023
Logging for Worker stoppedd working	2	304	September 9, 2022
How to connect Celery(Redis) and Django	2	263	September 15, 2023

Django background worker, doesn't work as expected

Related topics