Unable to run ./manage.py listen

[edcohen08]

I've followed the example use cases on an otherwise empty django app and I can run the server fine but when I run ./manage.py listen

I get the following error:

> Traceback (most recent call last):
>   File "<string>", line 1, in <module>
>   File "/Users/eddie/.pyenv/versions/3.10.2/lib/python3.10/multiprocessing/spawn.py", line 116, in spawn_main
>     exitcode = _main(fd, parent_sentinel)
>   File "/Users/eddie/.pyenv/versions/3.10.2/lib/python3.10/multiprocessing/spawn.py", line 126, in _main
>     self = reduction.pickle.load(from_parent)
>   File "/Users/eddie/Documents/django-playing/pubsub/.venv/lib/python3.10/site-packages/pgpubsub/listen.py", line 16, in <module>
>     from pgpubsub.models import Notification
>   File "/Users/eddie/Documents/django-playing/pubsub/.venv/lib/python3.10/site-packages/pgpubsub/models.py", line 10, in <module>
>     class Notification(models.Model):
>   File "/Users/eddie/Documents/django-playing/pubsub/.venv/lib/python3.10/site-packages/django/db/models/base.py", line 127, in __new__
>     app_config = apps.get_containing_app_config(module)
>   File "/Users/eddie/Documents/django-playing/pubsub/.venv/lib/python3.10/site-packages/django/apps/registry.py", line 260, in get_containing_app_config
>     self.check_apps_ready()
>   File "/Users/eddie/Documents/django-playing/pubsub/.venv/lib/python3.10/site-packages/django/apps/registry.py", line 138, in check_apps_ready
>     raise AppRegistryNotReady("Apps aren't loaded yet.")
> django.core.exceptions.AppRegistryNotReady: Apps aren't loaded yet.

I've made sure I ran the migrate command and added pgpubsub and pgtrigger to the installed apps. I commented out anywhere that I use the library but still hit this issue on listen.

[PaulGilmartin]

Thanks for raising this. I haven't experienced that error personally but I will try to investigate this week and let you know if I can help! Can you tell me anything more about the environment you're using? Is it just a virtualenv? Or are you using docker at all?

[PaulGilmartin]

@edcohen08 How have you defined your Postgres database and how is your django application pointing to it?

[metalaureate]

@PaulGilmartin I have this same problem and would very much like to use your module.

I'm using conda environment on a Mac M1. I could try a docker environment if you want to give me the versioning I should try.

I confirmed the trigger was defined in the db.

The db is defined in settings as per usual.

I am also running websockets and django q.

System check identified no issues (0 silenced).
November 02, 2022 - 21:14:15
Django version 4.0, using settings 'api.settings'
Starting ASGI/Channels version 3.0.4 development server at http://0.0.0.0:9000/
Quit the server with CONTROL-C.
21:14:15 [Q] INFO Process-1 guarding cluster artist-speaker-wolfram-avocado
21:14:15 [Q] INFO Q Cluster artist-speaker-wolfram-avocado running.

app.py

from django.apps import AppConfig
class MirrorConfig(AppConfig):
    default_auto_field = 'django.db.models.BigAutoField'
    name = 'mirror'
    def ready(self):
        import mirror.listeners

channels.py

from dataclasses import dataclass

from pgpubsub.channel import TriggerChannel
from mirror.models import ComFeed

@dataclass
class ComFeedChannel(TriggerChannel):
    model = ComFeed

listeners.py

import pgpubsub
from mirror.channels import ComFeedChannel
from mirror.models import ComFeed

@pgpubsub.post_insert_listener(ComFeedChannel)
def emit_feed_change(old: ComFeed, new: ComFeed):
    print(f'Logging pubsub action {new.token_id}')

% ./manage.py listen
LOCAL
LOCAL
Traceback (most recent call last):
  File "<string>", line 1, in <module>
  File "/Users/sjhill/opt/anaconda3/envs/mm/lib/python3.9/multiprocessing/spawn.py", line 116, in spawn_main
    exitcode = _main(fd, parent_sentinel)
  File "/Users/sjhill/opt/anaconda3/envs/mm/lib/python3.9/multiprocessing/spawn.py", line 126, in _main
    self = reduction.pickle.load(from_parent)
  File "/Users/sjhill/opt/anaconda3/envs/mm/lib/python3.9/site-packages/pgpubsub/listen.py", line 16, in <module>
    from pgpubsub.models import Notification
  File "/Users/sjhill/opt/anaconda3/envs/mm/lib/python3.9/site-packages/pgpubsub/models.py", line 10, in <module>
    class Notification(models.Model):
  File "/Users/sjhill/opt/anaconda3/envs/mm/lib/python3.9/site-packages/django/db/models/base.py", line 108, in __new__
    app_config = apps.get_containing_app_config(module)
  File "/Users/sjhill/opt/anaconda3/envs/mm/lib/python3.9/site-packages/django/apps/registry.py", line 253, in get_containing_app_config
    self.check_apps_ready()
  File "/Users/sjhill/opt/anaconda3/envs/mm/lib/python3.9/site-packages/django/apps/registry.py", line 136, in check_apps_ready
    raise AppRegistryNotReady("Apps aren't loaded yet.")
django.core.exceptions.AppRegistryNotReady: Apps aren't loaded yet.

[metalaureate]

I fixed this by modifying your listen.py file based the last answer here: https://stackoverflow.com/questions/33186413/djangodjango-core-exceptions-appregistrynotready-apps-arent-loaded-yet

Add to the head of listen.py

import os
import django
os.environ.setdefault("DJANGO_SETTINGS_MODULE", "api.settings")
django.setup()

[PaulGilmartin]

@metalaureate thank you very much for showing an interest in the library!

I find it very confusing that this has never happened to me. I'm not sure if its something in the docker setup I use which meant the apps are registered earlier than they would be otherwise. I'll try to investigate this over the next few days. Great you found a patch in the mean time - that may even be the correct fix (but I'd still like to know how I managed to run it without doing that explicitly).

[metalaureate]

Thank you an official patch would be much appreciated. I agree it’s weird and I wonder if you were to patch it the way I did, you would get a “no reentry” error so you might have to make it conditional on app initialization and either way it feels like a kludge.

[PaulGilmartin]

@metalaureate I started looking at this today. I'm able to reproduce the issue if I just try to run mange.py listen in a pipenv environment. Up until now, I had always been using docker to run the command. I still cannot see what my docker environment is doing to get around this issue which the regular pipenv environment is not. I'll keep trying to dig in to it later today when I'm back from the shops.

Until then, this is my current docker set up. The name of the local project I'm using to test this on is "pgpubsub_pip_2". Maybe you'll be able to spot something in the below which sets up the apps?

docker-compose.yml

version: '3.7'

services:
  web:    
    build:
      context: .
      dockerfile: Dockerfile.dev
    command: python /pgpubsub_pip_2/manage.py listen
    volumes:
      - .:/pgpubsub_pip_2
    ports:
      - 8000:8000
    depends_on:
      - db
    env_file:
      - ./.env.dev
  db:
    image: postgres:12
    environment:
      POSTGRES_PASSWORD: postgres
      POSTGRES_USER: postgres
      POSTGRES_DB: postgres
    volumes:
      - postgres_data:/var/lib/postgresql/data/

volumes:
  postgres_data:

The .env.dev file looks like this:

DEBUG=1
SECRET_KEY=***
DJANGO_ALLOWED_HOSTS=localhost 127.0.0.1 0.0.0.0:8000 *
ENVIRONMENT=development
SQL_ENGINE=django.db.backends.postgresql
SQL_DATABASE=postgres
SQL_USER=postgres
SQL_PASSWORD=postgres
SQL_HOST=db
SQL_PORT=5432
DATABASE=postgres

and Dockerfile.dev looks like this:

FROM python:3.9

ENV PYTHONDONTWRITEBYTECODE 1
ENV PYTHONUNBUFFERED 1

WORKDIR /pgpubsub_pip_2

COPY Pipfile Pipfile.lock /pgpubsub_pip_2/
RUN pip install --upgrade pip
RUN pip install pipenv && pipenv install --system
COPY . /pgpubsub_pip_2/

and my manage.py looks as follows:

#!/usr/bin/env python
"""Django's command-line utility for administrative tasks."""
import os
import sys

def main():
    """Run administrative tasks."""
    os.environ.setdefault('DJANGO_SETTINGS_MODULE', 'pgpubsub_pip_2.settings')
    try:
        from django.core.management import execute_from_command_line
    except ImportError as exc:
        raise ImportError(
            "Couldn't import Django. Are you sure it's installed and "
            "available on your PYTHONPATH environment variable? Did you "
            "forget to activate a virtual environment?"
        ) from exc
    execute_from_command_line(sys.argv)

if __name__ == '__main__':
    main()

With this set up, running docker compose up works as expected:

  pgpubsub_pip_2 docker compose up
[+] Running 3/3
 ⠿ Network pgpubsub_pip_2_default  Created                                                                                                                   0.1s
 ⠿ Container pgpubsub_pip_2-db-1   Created                                                                                                                   0.1s
 ⠿ Container pgpubsub_pip_2-web-1  Created                                                                                                                   0.1s
Attaching to pgpubsub_pip_2-db-1, pgpubsub_pip_2-web-1
pgpubsub_pip_2-db-1   |
pgpubsub_pip_2-db-1   | PostgreSQL Database directory appears to contain a database; Skipping initialization
pgpubsub_pip_2-db-1   |
pgpubsub_pip_2-db-1   | 2022-11-05 13:24:00.392 UTC [1] LOG:  starting PostgreSQL 12.12 (Debian 12.12-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
pgpubsub_pip_2-db-1   | 2022-11-05 13:24:00.393 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
pgpubsub_pip_2-db-1   | 2022-11-05 13:24:00.394 UTC [1] LOG:  listening on IPv6 address "::", port 5432
pgpubsub_pip_2-db-1   | 2022-11-05 13:24:00.398 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
pgpubsub_pip_2-db-1   | 2022-11-05 13:24:00.415 UTC [25] LOG:  database system was shut down at 2022-11-05 13:23:45 UTC
pgpubsub_pip_2-db-1   | 2022-11-05 13:24:00.422 UTC [1] LOG:  database system is ready to accept connections
pgpubsub_pip_2-web-1  | READY
pgpubsub_pip_2-web-1  | Listening on pgpubsub_pip_2.channels.CommentChannel
pgpubsub_pip_2-web-1  | Listening for notifications...
pgpubsub_pip_2-web-1  |

[PaulGilmartin]

@metalaureate I think I've found the issue. It stems from the fact the listen command is using the multiprocessing module:

    def handle(self, *args, **options):
        channel_names = options.get('channels')
        processes = options.get('processes') or 1
        recover = options.get('recover', False)
        for i in range(processes):
            process = multiprocessing.Process(
                name=f'pgpubsub_process_{i}',
                target=listen,
                args=(channel_names, recover),
            )
            process.start()

I found this issue on stack overflow: https://stackoverflow.com/questions/46908035/apps-arent-loaded-yet-exception-occurs-when-using-multi-processing-in-django. It seems like this issue arises on a mac (which both of us are using):

"If you encounter this issue while running Python 3.8 and trying to use multiprocessing package, chances are that it is due to the sub processed are 'spawned' instead of 'forked'. This is a change with Python 3.8 on Mac OS where the default process start method is changed from 'fork' to 'spawn'"

This also explains why I didn't get the issue in Docker - it isn't using the mac python interpreter.

Fortunately the stack post gives a very easy work around, which I have tested and it seems to do the job. I'll update the master branch with a fix as soon as possible!

[PaulGilmartin]

@metalaureate I have now pushed a fix which is available in version 0.0.6 (https://pypi.org/project/django-pgpubsub/0.0.6/). Please let me know if it fixes your issue!

[metalaureate]

Hi @PaulGilmartin Thank you. I get a new error

Traceback (most recent call last):
  File "/Users/sjhill/Documents/yat/projects/mm/api/./manage.py", line 21, in <module>
    main()
  File "/Users/sjhill/Documents/yat/projects/mm/api/./manage.py", line 17, in main
    execute_from_command_line(sys.argv)
  File "/Users/sjhill/opt/anaconda3/envs/mm/lib/python3.9/site-packages/django/core/management/__init__.py", line 425, in execute_from_command_line
    utility.execute()
  File "/Users/sjhill/opt/anaconda3/envs/mm/lib/python3.9/site-packages/django/core/management/__init__.py", line 419, in execute
    self.fetch_command(subcommand).run_from_argv(self.argv)
  File "/Users/sjhill/opt/anaconda3/envs/mm/lib/python3.9/site-packages/django/core/management/base.py", line 373, in run_from_argv
    self.execute(*args, **cmd_options)
  File "/Users/sjhill/opt/anaconda3/envs/mm/lib/python3.9/site-packages/django/core/management/base.py", line 417, in execute
    output = self.handle(*args, **options)
  File "/Users/sjhill/opt/anaconda3/envs/mm/lib/python3.9/site-packages/pgpubsub/management/commands/listen.py", line 35, in handle
    multiprocessing.set_start_method('fork')
  File "/Users/sjhill/opt/anaconda3/envs/mm/lib/python3.9/multiprocessing/context.py", line 243, in set_start_method
    raise RuntimeError('context has already been set')
RuntimeError: context has already been set

[metalaureate]

Please don't give up--this package is such an improvement over Celery for lightweight MVPs that need asynchronous pubsub on db write processes.

[PaulGilmartin]

Ohh damn. Hopefully that isn't too difficult to fix. Let me try see what I can do!

[PaulGilmartin]

And thanks for the kind words. Please feel free to suggest anymore improvements for this library that you'd like to see!

[PaulGilmartin]

@metalaureate I made another fix available at https://pypi.org/project/django-pgpubsub/0.0.7/. Please let me know if it works !

[metalaureate]

Perfect! Thank you! 🙌🎉🎊🍾🥳🍻🎈

[PaulGilmartin]

Great ! Please do feel free to suggest improvements or to give feedback in general - always looking to improve the user experience! I'll close this issue for now.

[metalaureate]

Thank you. I will and will spread the word. One thing I'd love more clarity about--but reflection only of my ignorance not this package--is whether there would be any potential conflict between the Channels set up I have for websockets and this. I don't understand how Channels works too well in Django, but I have one finnicky setup using ASGI which is configured using a consumers.py and then I have this package setting up channels.py and listeners.py as a separate process.

[PaulGilmartin]

I've never used channels so I cannot say at all for certain, but I don't believe there should be any conflict between django-pgpubsub and channels. The message layer for pgpubsub lies entirely within the postgres layer, so is separated from a websocket in that sense.

I do have a dream of eventually integrating this package with channels. It would be great to see postgres trigger actions come straight into the browser!

[metalaureate]

Ah ok my misunderstanding. pgpubsub.channel is not a Django Channel. That clears it up, thank you. Yeah, that would be cool.

[PaulGilmartin]

@metalaureate yeah it isn't a channel in that sense. "Channel" in this library is the python abstraction of postgres' channel concept in the listen/notify protocol: https://www.postgresql.org/docs/current/sql-notify.html