ansible-openwisp2 icon indicating copy to clipboard operation
ansible-openwisp2 copied to clipboard

Published 20 hours ago • verified publisher icon openwisp

[bug] daphne errors on `supervisorctl restart daphne:asgi0`

Open asmodehn opened this issue 6 months ago • 5 comments

Describe the bug

RUNNING HANDLER [openwisp.openwisp2 : Restart daphne] **************************************************************************************************************
fatal: [10.0.5.4]: FAILED! => {"changed": true, "cmd": ["supervisorctl", "restart", "daphne:asgi0"], "delta": "0:00:01.358892", "end": "2025-06-05 09:30:20.324525", "msg": "non-zero return code", "rc": 7, "start": "2025-06-05 09:30:18.965633", "stderr": "", "stderr_lines": [], "stdout": "daphne:asgi0: stopped\ndaphne:asgi0: ERROR (spawn error)", "stdout_lines": ["daphne:asgi0: stopped", "daphne:asgi0: ERROR (spawn error)"]}

Steps To Reproduce Still unsure. deploying openwisp 1.1.1 or master with this role (slightly modified - currently tracking this issue down...) does trigger it for me...

Expected behavior ansible playbook should work "out of the box"...

Logs

daphne.log

/opt/openwisp2/env/lib/python3.11/site-packages/openwisp_utils/admin_theme/system_info.py:4: UserWarning: pkg_resources is deprecated as an API. See https://setuptools.pypa.io/en/latest/pkg_resources.html. The pkg_resources package is slated for removal as early as 2025-11-30. Refrain from using this package or pin to Setuptools<81.
  import pkg_resources
Traceback (most recent call last):
  File "/opt/openwisp2/env/bin/daphne", line 8, in <module>
    sys.exit(CommandLineInterface.entrypoint())
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/openwisp2/env/lib/python3.11/site-packages/daphne/cli.py", line 171, in entrypoint
    cls().run(sys.argv[1:])
  File "/opt/openwisp2/env/lib/python3.11/site-packages/daphne/cli.py", line 291, in run
    self.server.run()
  File "/opt/openwisp2/env/lib/python3.11/site-packages/daphne/server.py", line 130, in run
    ep = serverFromString(reactor, str(socket_description))
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/openwisp2/env/lib/python3.11/site-packages/twisted/internet/endpoints.py", line 1844, in serverFromString
    nameOrPlugin, args, kw = _parseServer(description, None)
                             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/openwisp2/env/lib/python3.11/site-packages/twisted/internet/endpoints.py", line 1764, in _parseServer
    plugin = _matchPluginToPrefix(
             ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/openwisp2/env/lib/python3.11/site-packages/twisted/internet/endpoints.py", line 1779, in _matchPluginToPrefix
    raise ValueError(f"Unknown endpoint type: '{endpointType}'")
ValueError: Unknown endpoint type: 'fd'

System Informatioon:

  • Ansible Version:
(Project<3.12>) alexv@lenovo-ryzen-pop:~/Project/deploy$ ansible --version
ansible [core 2.18.6]
  config file = /home/alexv/Project/deploy/ansible.cfg
  configured module search path = ['/home/alexv/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /home/alexv/Project/.direnv/python-3.12/lib/python3.12/site-packages/ansible
  ansible collection location = /home/alexv/Project/deploy/collections
  executable location = /home/alexv/Project/.direnv/python-3.12/bin/ansible
  python version = 3.12.7 (main, Mar 14 2025, 11:01:33) [GCC 11.4.0] (/home/alexv/Project/.direnv/python-3.12/bin/python3)
  jinja version = 3.1.6
  libyaml = True
  • OS:
debian@hostname:/opt/openwisp2/log$ cat /etc/issue
Debian GNU/Linux 12 \n \l
  • Python Version:
(env) debian@hostname:/opt/openwisp2$ python --version
Python 3.11.2
  • Django Version:
(env) debian@hostname:/opt/openwisp2$ pip list | grep -e 'daphne\|Django\|Twisted'
daphne                           4.2.0
Django                           5.2.2
Twisted                          24.11.0

I also remember having it on django 4.2, I will attempt to reproduce that one next, see if I spot something...

asmodehn avatar Jun 05 '25 07:06 asmodehn

I confirm I can reproduce with:

(env) debian@hostname:/opt/openwisp2$ pip list | grep -e 'daphne\|Django\|Twisted'
daphne                           4.2.0
Django                           4.2.22
Twisted                          24.11.0

after installation, just running supervisorctl restart daphne:asgi0 will trigger the error:

(env) debian@hostname:/opt/openwisp2$ sudo supervisorctl start daphne:asgi0
daphne:asgi0: ERROR (spawn error)

same log:

/opt/openwisp2/env/lib/python3.11/site-packages/openwisp_utils/admin_theme/system_info.py:4: UserWarning: pkg_resources is deprecated as an API. See https://setuptools.pypa.io/en/latest/pkg_resources.html. The pkg_resources package is slated for removal as early as 2025-11-30. Refrain from using this package or pin to Setuptools<81.
  import pkg_resources
Traceback (most recent call last):
  File "/opt/openwisp2/env/bin/daphne", line 8, in <module>
    sys.exit(CommandLineInterface.entrypoint())
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/openwisp2/env/lib/python3.11/site-packages/daphne/cli.py", line 171, in entrypoint
    cls().run(sys.argv[1:])
  File "/opt/openwisp2/env/lib/python3.11/site-packages/daphne/cli.py", line 291, in run
    self.server.run()
  File "/opt/openwisp2/env/lib/python3.11/site-packages/daphne/server.py", line 130, in run
    ep = serverFromString(reactor, str(socket_description))
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/openwisp2/env/lib/python3.11/site-packages/twisted/internet/endpoints.py", line 1844, in serverFromString
    nameOrPlugin, args, kw = _parseServer(description, None)
                             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/openwisp2/env/lib/python3.11/site-packages/twisted/internet/endpoints.py", line 1764, in _parseServer
    plugin = _matchPluginToPrefix(
             ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/openwisp2/env/lib/python3.11/site-packages/twisted/internet/endpoints.py", line 1779, in _matchPluginToPrefix
    raise ValueError(f"Unknown endpoint type: '{endpointType}'")
ValueError: Unknown endpoint type: 'fd'

In case this might be helpful:

(env) debian@hostname:/opt/openwisp2$ cat /etc/supervisor/conf.d/daphne.conf 
[fcgi-program:daphne]
user=www-data
socket=unix:///opt/openwisp2/daphne0.sock
directory=/opt/openwisp2
command=/opt/openwisp2/env/bin/daphne --fd 0 -u /opt/openwisp2/daphne%(process_num)d.sock --access-log - --websocket_timeout 3600 --proxy-headers openwisp2.asgi:application
process_name=asgi%(process_num)d
numprocs=1
autostart=true
autorestart=true
stopsignal=INT
redirect_stderr=true
stdout_logfile=/opt/openwisp2/log/daphne.log
stdout_logfile_maxbytes=30MB
stdout_logfile_backups=5

asmodehn avatar Jun 05 '25 08:06 asmodehn

related issue: https://github.com/django/daphne/issues/557

After installing daphne==4.1.2 the obvious logged problem went away, but supervisor still complains (although daphne is started properly it seems). this matches the behavior I had for a while before posting this issue... so it s something else...

root@hostname:/opt/openwisp2# source env/bin/activate
(env) root@hostname:/opt/openwisp2# pip install daphne==4.1.2
Collecting daphne==4.1.2
  Downloading daphne-4.1.2-py3-none-any.whl.metadata (6.5 kB)
Requirement already satisfied: asgiref<4,>=3.5.2 in ./env/lib/python3.11/site-packages (from daphne==4.1.2) (3.8.1)
Requirement already satisfied: autobahn>=22.4.2 in ./env/lib/python3.11/site-packages (from daphne==4.1.2) (24.4.2)
Requirement already satisfied: twisted>=22.4 in ./env/lib/python3.11/site-packages (from twisted[tls]>=22.4->daphne==4.1.2) (24.11.0)
Requirement already satisfied: txaio>=21.2.1 in ./env/lib/python3.11/site-packages (from autobahn>=22.4.2->daphne==4.1.2) (23.1.1)
Requirement already satisfied: cryptography>=3.4.6 in ./env/lib/python3.11/site-packages (from autobahn>=22.4.2->daphne==4.1.2) (43.0.3)
Requirement already satisfied: hyperlink>=21.0.0 in ./env/lib/python3.11/site-packages (from autobahn>=22.4.2->daphne==4.1.2) (21.0.0)
Requirement already satisfied: setuptools in ./env/lib/python3.11/site-packages (from autobahn>=22.4.2->daphne==4.1.2) (80.9.0)
Requirement already satisfied: cffi>=1.12 in ./env/lib/python3.11/site-packages (from cryptography>=3.4.6->autobahn>=22.4.2->daphne==4.1.2) (1.17.1)
Requirement already satisfied: pycparser in ./env/lib/python3.11/site-packages (from cffi>=1.12->cryptography>=3.4.6->autobahn>=22.4.2->daphne==4.1.2) (2.22)
Requirement already satisfied: idna>=2.5 in ./env/lib/python3.11/site-packages (from hyperlink>=21.0.0->autobahn>=22.4.2->daphne==4.1.2) (3.10)
Requirement already satisfied: attrs>=22.2.0 in ./env/lib/python3.11/site-packages (from twisted>=22.4->twisted[tls]>=22.4->daphne==4.1.2) (25.3.0)
Requirement already satisfied: automat>=24.8.0 in ./env/lib/python3.11/site-packages (from twisted>=22.4->twisted[tls]>=22.4->daphne==4.1.2) (25.4.16)
Requirement already satisfied: constantly>=15.1 in ./env/lib/python3.11/site-packages (from twisted>=22.4->twisted[tls]>=22.4->daphne==4.1.2) (23.10.4)
Requirement already satisfied: incremental>=24.7.0 in ./env/lib/python3.11/site-packages (from twisted>=22.4->twisted[tls]>=22.4->daphne==4.1.2) (24.7.2)
Requirement already satisfied: typing-extensions>=4.2.0 in ./env/lib/python3.11/site-packages (from twisted>=22.4->twisted[tls]>=22.4->daphne==4.1.2) (4.14.0)
Requirement already satisfied: zope-interface>=5 in ./env/lib/python3.11/site-packages (from twisted>=22.4->twisted[tls]>=22.4->daphne==4.1.2) (7.2)
Requirement already satisfied: pyopenssl>=21.0.0 in ./env/lib/python3.11/site-packages (from twisted[tls]>=22.4->daphne==4.1.2) (24.2.1)
Requirement already satisfied: service-identity>=18.1.0 in ./env/lib/python3.11/site-packages (from twisted[tls]>=22.4->daphne==4.1.2) (24.2.0)
Requirement already satisfied: pyasn1 in ./env/lib/python3.11/site-packages (from service-identity>=18.1.0->twisted[tls]>=22.4->daphne==4.1.2) (0.6.1)
Requirement already satisfied: pyasn1-modules in ./env/lib/python3.11/site-packages (from service-identity>=18.1.0->twisted[tls]>=22.4->daphne==4.1.2) (0.4.2)
Downloading daphne-4.1.2-py3-none-any.whl (30 kB)
Installing collected packages: daphne
  Attempting uninstall: daphne
    Found existing installation: daphne 4.2.0
    Uninstalling daphne-4.2.0:
      Successfully uninstalled daphne-4.2.0
Successfully installed daphne-4.1.2
(env) root@hostname:/opt/openwisp2# supervisorctl restart daphne:asgi0
daphne:asgi0: ERROR (not running)
daphne:asgi0: ERROR (spawn error)
(env) root@hostname:/opt/openwisp2# rm -f log/daphne.log 
(env) root@hostname:/opt/openwisp2# supervisorctl restart daphne:asgi0
daphne:asgi0: stopped
daphne:asgi0: ERROR (spawn error)
(env) root@hostname:/opt/openwisp2# supervisorctl status daphne:asgi0
daphne:asgi0                     RUNNING   pid 37260, uptime 0:00:21
(env) root@hostname:/opt/openwisp2# tail log/daphne.log 
/opt/openwisp2/env/lib/python3.11/site-packages/openwisp_utils/admin_theme/system_info.py:4: UserWarning: pkg_resources is deprecated as an API. See https://setuptools.pypa.io/en/latest/pkg_resources.html. The pkg_resources package is slated for removal as early as 2025-11-30. Refrain from using this package or pin to Setuptools<81.
  import pkg_resources
/opt/openwisp2/env/lib/python3.11/site-packages/openwisp_utils/admin_theme/system_info.py:4: UserWarning: pkg_resources is deprecated as an API. See https://setuptools.pypa.io/en/latest/pkg_resources.html. The pkg_resources package is slated for removal as early as 2025-11-30. Refrain from using this package or pin to Setuptools<81.
  import pkg_resources
(env) root@hostname:/opt/openwisp2#

So there is nothing obvious in the log about the supervisor/daphne issue. It might be something in their relationship...

I will attempt to change the supervisor config for daphne next, following https://channels.readthedocs.io/en/stable/deploying.html#example-setups ...

asmodehn avatar Jun 05 '25 08:06 asmodehn

Ok, so after fiddling around with this, I think the problem comes from the supervisor configuration for daphne.

FWIW, on my setup (debian 12) supervisor is installed via apt at version 4.2.5

root@hostname:/opt/openwisp2# pip list | grep supervisor
supervisor         4.2.5

And looking at the documentation for supervisor and daphne (django's channels example setup), I believe we should have either :

  1. a program managing his unix socket (no supervisor meddling in the middle, we have only one process after all, straight from nginx to daphne)
  2. a fcgi-program and daphne should not touch the unix socket at all (everything goes in via --fd 0 as per https://supervisord.org/configuration.html#fcgi-program-x-section-settings)
  1. gives:
[program:daphne]
user=www-data
directory=/opt/openwisp2
command=/opt/openwisp2/env/bin/daphne -u /opt/openwisp2/daphne%(process_num)d.sock --access-log - --websocket_timeout 3600 --proxy-headers openwisp2.asgi:application
process_name=asgi%(process_num)d
numprocs=1
[...]

root@hostname:/opt/openwisp2# supervisorctl stop daphne:asgi0
daphne:asgi0: stopped
root@hostname:/opt/openwisp2# supervisorctl start daphne:asgi0
daphne:asgi0: started
  1. gives:
[fcgi-program:daphne]
user=www-data
socket=unix:///opt/openwisp2/daphne0.sock
directory=/opt/openwisp2
command=/opt/openwisp2/env/bin/daphne --fd 0 --access-log - --websocket_timeout 3600 --proxy-headers openwisp2.asgi:application
process_name=asgi%(process_num)d
numprocs=1
[...]

root@hostname:/opt/openwisp2# supervisorctl stop daphne:asgi0
daphne:asgi0: stopped
root@hostname:/opt/openwisp2# supervisorctl start daphne:asgi0
daphne:asgi0: started

Let me know which way seems best for you, and I can make a PR for this.

asmodehn avatar Jun 05 '25 12:06 asmodehn

@asmodehn I think the second solution would be better because we sometimes need to increase the number of daphne processes.

pandafy avatar Jun 06 '25 12:06 pandafy

Quick update on this topic

In my current deployments (on debian12, with some customisations...), running daphne as a [program] works fine, websocket connection can be established.

However I am currently having issues when running daphne as a [fcgi-program], I get NS_ERROR_WEBSOCKET_CONNECTION_REFUSED when trying to connect to the socket (managed by supervisor)

I am using the same nginx and django config in both cases... only the supervisor config changes, like the examples I gave above.

I'll report here when if I find more details about this...

asmodehn avatar Jul 24 '25 15:07 asmodehn