HyperKitty async tasks runner: systemd qcluster service fails eventually
Ubuntu 20.04 mailman3 3.2.2-1 python3-django-hyperkitty 1.3.0-1ubuntu1
According to Hyperkitty Asynchronous tasks paragraph, we can start a qcluster systemd service file:
[Unit]
Description=HyperKitty async tasks runner
After=network.target remote-fs.target
[Service]
ExecStart=/usr/bin/django-admin qcluster --pythonpath <django_project_path> --settings settings
User=<user>
Group=<group>
Restart=always
[Install]
WantedBy=multi-user.target
Starting it works fine:
# systemctl restart qcluster
# systemctl status qcluster
● qcluster.service - HyperKitty async tasks runner
Loaded: loaded (/etc/systemd/system/qcluster.service; enabled; vendor preset: enabled)
Active: active (running) since Wed 2019-12-04 15:09:46 CET; 2ms ago
Main PID: 1055959 ((go-admin))
Tasks: 0 (limit: 9284)
Memory: 0B
CGroup: /system.slice/qcluster.service
└─1055959 (go-admin)
Dec 04 15:09:46 samsung4-ubuntu systemd[1]: Started HyperKitty async tasks runner.
However, the service fails after a few seconds:
# systemctl status qcluster
● qcluster.service - HyperKitty async tasks runner
Loaded: loaded (/etc/systemd/system/qcluster.service; enabled; vendor preset: enabled)
Active: failed (Result: exit-code) since Wed 2019-12-04 15:09:48 CET; 1min 1s ago
Process: 1055961 ExecStart=/usr/bin/django-admin qcluster --pythonpath <django_project_path> --settings settings (code=exited, status=1/FAILURE)
Main PID: 1055961 (code=exited, status=1/FAILURE)
Dec 04 15:09:48 samsung4-ubuntu systemd[1]: qcluster.service: Service RestartSec=100ms expired, scheduling restart.
Dec 04 15:09:48 samsung4-ubuntu systemd[1]: qcluster.service: Scheduled restart job, restart counter is at 5.
Dec 04 15:09:48 samsung4-ubuntu systemd[1]: Stopped HyperKitty async tasks runner.
Dec 04 15:09:48 samsung4-ubuntu systemd[1]: qcluster.service: Start request repeated too quickly.
Dec 04 15:09:48 samsung4-ubuntu systemd[1]: qcluster.service: Failed with result 'exit-code'.
Dec 04 15:09:48 samsung4-ubuntu systemd[1]: Failed to start HyperKitty async tasks runner.
The corresponding log file is empty and I cannot find any issue in the other logs. Any suggestion?
Also, another doc paragraph Running the task queue (required) talks about another required command "python manage.py qcluster"; so which one is it?
On 12/4/19 6:15 AM, actionmystique@gmail.com wrote:
Ubuntu 20.04 mailman3 3.2.2-1 python3-django-hyperkitty 1.3.0-1ubuntu1
According to Hyperkitty Asynchronous tasks paragraph, we can start a qcluster systemd service file: ... [Service] ExecStart=/usr/bin/django-admin qcluster --pythonpath <django_project_path> --settings settings User=<user> Group=<group> Restart=always
Did you replace <django_project_path>, <user> and <group> with appropriate values?
...
Starting it works fine: ... However, the service fails after a few seconds:
# systemctl status qcluster ● qcluster.service - HyperKitty async tasks runner Loaded: loaded (/etc/systemd/system/qcluster.service; enabled; vendor preset: enabled) Active: failed (Result: exit-code) since Wed 2019-12-04 15:09:48 CET; 1min 1s ago Process: 1055961 ExecStart=/usr/bin/django-admin qcluster --pythonpath <django_project_path> --settings settings (code=exited, status=1/FAILURE) Main PID: 1055961 (code=exited, status=1/FAILURE)
It appears you haven't replaced <django_project_path> with the actual path to the directory containing your Django settings.py file
Also, <user> and <group> should be those of the Mailman user, probably 'list' in Debian/Ubuntu packages.
...
Also, another doc paragraph Running the task queue (required) talks about another required command "python manage.py qcluster"; so which one is it?
They should be the same thing. Usually manage.py is just configured to run the django-admin command for the particular project.
-- Mark Sapiro <mark@msapiro.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
Mark Sapiro wrote:
Did you replace <django_project_path>, <user> and <group> with appropriate values? Yes, I did, otherwise qcluster service would not be able to start in the first place because it needs to be able to read settings.py (with the proper permissions) which is located in the django project.
They should be the same thing. Usually manage.py is just configured to run the django-admin command for the particular project. You're right, running either command manually is successful and lead to the same result:
<django_project_path># python3 manage.py qcluster
10:49:41 [Q] INFO Q Cluster-1130205 starting.
10:49:41 [Q] INFO Process-1:1 ready for work at 1130235
10:49:41 [Q] INFO Process-1:2 ready for work at 1130236
10:49:41 [Q] INFO Process-1:3 ready for work at 1130237
10:49:41 [Q] INFO Process-1:4 ready for work at 1130238
10:49:41 [Q] INFO Process-1:5 monitoring at 1130239
10:49:41 [Q] INFO Process-1 guarding cluster at 1130234
10:49:41 [Q] INFO Q Cluster-1130205 running.
10:49:41 [Q] INFO Process-1:6 pushing tasks at 1130240
If I replace:
ExecStart=/usr/bin/django-admin qcluster --pythonpath <django_project_path>
--settings settings
with:
WorkingDirectory=<django_project_path>
ExecStart=python3 manage.py qcluster
I get the same systemd service issue.
If I remove the remote-fs.target from After=..., I get the following error:
# systemctl daemon-reload
# systemctl restart qcluster
# systemctl status qcluster
● qcluster.service - HyperKitty async tasks runner
Loaded: loaded (/etc/systemd/system/qcluster.service; enabled; vendor preset: enabled)
Active: active (running) since Thu 2019-12-05 11:08:54 CET; 282ms ago
Main PID: 1132324 (python3)
Tasks: 1 (limit: 9284)
Memory: 22.5M
CGroup: /system.slice/qcluster.service
└─1132324 python3 /usr/bin/django-admin qcluster --pythonpath <django_project_path> --settings settings
Dec 05 11:08:54 samsung4-ubuntu django-admin[1132324]: configure_logging(settings.LOGGING_CONFIG, settings.LOGGING)
Dec 05 11:08:54 samsung4-ubuntu django-admin[1132324]: File "/usr/lib/python3/dist-packages/django/utils/log.py", line 76, in configure_logging
Dec 05 11:08:54 samsung4-ubuntu django-admin[1132324]: logging_config_func(logging_settings)
Dec 05 11:08:54 samsung4-ubuntu django-admin[1132324]: File "/usr/lib/python3.7/logging/config.py", line 800, in dictConfig
Dec 05 11:08:54 samsung4-ubuntu django-admin[1132324]: dictConfigClass(config).configure()
Dec 05 11:08:54 samsung4-ubuntu django-admin[1132324]: File "/usr/lib/python3.7/logging/config.py", line 571, in configure
Dec 05 11:08:54 samsung4-ubuntu django-admin[1132324]: '%r' % name) from e
Dec 05 11:08:54 samsung4-ubuntu django-admin[1132324]: ValueError: Unable to configure handler 'file'
Dec 05 11:08:54 samsung4-ubuntu systemd[1]: qcluster.service: Main process exited, code=exited, status=1/FAILURE
Dec 05 11:08:54 samsung4-ubuntu systemd[1]: qcluster.service: Failed with result 'exit-code'.
This issue seems related to logging; I configured the following in /etc/mailman3/mailman.cfg:
[logging.debian]
format: %(asctime)s (%(process)d) %(message)s
datefmt: %b %d %H:%M:%S %Y
propagate: no
level: debug
path: mailman.log
[logging.root]
level: debug
[logging.archiver]
level: debug
[logging.bounce]
level: debug
[logging.config]
level: debug
[logging.database]
level: debug
[logging.debug]
level: debug
[logging.error]
level: debug
[logging.fromusenet]
level: debug
[logging.http]
level: debug
[logging.locks]
level: debug
[logging.mischief]
level: debug
[logging.plugins]
level: debug
[logging.runner]
level: debug
[logging.smtp]
level: debug
[logging.subscribe]
level: debug
[logging.vette]
level: debug
The first part of my reply has been swallowed by |..., and appears when expanding it.
If I remove all special logging settings and restart both mailman3 & qcluster, the latter fails with the original issue.
/var/log/syslog qcluster messages are not helpful and nothing appears in any /var/log/mailman3 log file. Isn't there a way to trace the systemd service command?
I think I have a lead: after having removed Restart=always which masked the details about the systemd service failure, I get:
# systemctl status qcluster
● qcluster.service - HyperKitty async tasks runner
Loaded: loaded (/etc/systemd/system/qcluster.service; enabled; vendor preset: enabled)
Active: failed (Result: exit-code) since Thu 2019-12-05 15:04:06 CET; 2s ago
Process: 1199893 ExecStart=/usr/bin/django-admin qcluster --pythonpath <django_project_path> --settings settings (code=exited, status=1/FAILURE)
Main PID: 1199893 (code=exited, status=1/FAILURE)
Dec 05 15:04:06 samsung4-ubuntu django-admin[1199893]: configure_logging(settings.LOGGING_CONFIG, settings.LOGGING)
Dec 05 15:04:06 samsung4-ubuntu django-admin[1199893]: File "/usr/lib/python3/dist-packages/django/utils/log.py", line 76, in configure_logging
Dec 05 15:04:06 samsung4-ubuntu django-admin[1199893]: logging_config_func(logging_settings)
Dec 05 15:04:06 samsung4-ubuntu django-admin[1199893]: File "/usr/lib/python3.7/logging/config.py", line 800, in dictConfig
Dec 05 15:04:06 samsung4-ubuntu django-admin[1199893]: dictConfigClass(config).configure()
Dec 05 15:04:06 samsung4-ubuntu django-admin[1199893]: File "/usr/lib/python3.7/logging/config.py", line 571, in configure
Dec 05 15:04:06 samsung4-ubuntu django-admin[1199893]: '%r' % name) from e
Dec 05 15:04:06 samsung4-ubuntu django-admin[1199893]: ValueError: Unable to configure handler 'file'
Dec 05 15:04:06 samsung4-ubuntu systemd[1]: qcluster.service: Main process exited, code=exited, status=1/FAILURE
Dec 05 15:04:06 samsung4-ubuntu systemd[1]: qcluster.service: Failed with result 'exit-code'.
The file handler is configured that way in settings.py
LOGGING = {
'version': 1,
'disable_existing_loggers': False,
'filters': {
'require_debug_false': {
'()': 'django.utils.log.RequireDebugFalse'
}
},
'handlers': {
...
'file':{
'level': 'INFO',
#'class': 'logging.handlers.RotatingFileHandler',
'class': 'logging.handlers.WatchedFileHandler',
### 'filename': os.path.join(BASE_DIR, 'logs', 'mailmansuite.log'),
'filename': '/var/log/mailman3/mailmansuite.log',
'formatter': 'verbose',
},
...
'formatters': {
'verbose': {
'format': '%(levelname)s %(asctime)s %(process)d %(name)s %(message)s'
},
...
Anything suspicious?
On 12/5/19 6:17 AM, actionmystique@gmail.com wrote:
I think I have a lead: after having removed
Restart=alwayswhich masked the details about the systemd service failure, I get: ...> Dec 05 15:04:06 samsung4-ubuntu django-admin[1199893]: File "/usr/lib/python3.7/logging/config.py", line 571, in configure Dec 05 15:04:06 samsung4-ubuntu django-admin[1199893]: '%r' % name) from e Dec 05 15:04:06 samsung4-ubuntu django-admin[1199893]: ValueError: Unable to configure handler 'file' ... ... 'file':{ 'level': 'INFO', #'class': 'logging.handlers.RotatingFileHandler', 'class': 'logging.handlers.WatchedFileHandler', ### 'filename': os.path.join(BASE_DIR, 'logs', 'mailmansuite.log'), 'filename': '/var/log/mailman3/mailmansuite.log',
Does the mailman user, 'list' or whatever you have for User=<user> and Group=<group> in the systemd service file have permission to create/write /var/log/mailman3/mailmansuite.log?
-- Mark Sapiro <mark@msapiro.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
spot on :-) Changing the permissions of /var/log/mailman3/mailmansuite.log to list:list solves this issue:
# systemctl status qcluster
● qcluster.service - HyperKitty async tasks runner
Loaded: loaded (/etc/systemd/system/qcluster.service; enabled; vendor preset: enabled)
Active: active (running) since Fri 2019-12-06 10:53:23 CET; 1h 33min ago
Main PID: 1314343 (python3)
Tasks: 8 (limit: 9284)
Memory: 108.4M
CGroup: /system.slice/qcluster.service
├─1314343 python3 /usr/bin/django-admin qcluster --pythonpath <django_project_path> --settings settings
├─1314370 python3 /usr/bin/django-admin qcluster --pythonpath <django_project_path> --settings settings
├─1314371 python3 /usr/bin/django-admin qcluster --pythonpath <django_project_path> --settings settings
├─1314372 python3 /usr/bin/django-admin qcluster --pythonpath <django_project_path> --settings settings
├─1314373 python3 /usr/bin/django-admin qcluster --pythonpath <django_project_path> --settings settings
├─1314374 python3 /usr/bin/django-admin qcluster --pythonpath <django_project_path> --settings settings
├─1314375 python3 /usr/bin/django-admin qcluster --pythonpath <django_project_path> --settings settings
└─1314376 python3 /usr/bin/django-admin qcluster --pythonpath <django_project_path> --settings settings
Dec 06 10:53:23 samsung4-ubuntu systemd[1]: Started HyperKitty async tasks runner.
Dec 06 10:53:24 samsung4-ubuntu django-admin[1314343]: 10:53:24 [Q] INFO Q Cluster-1314343 starting.
Dec 06 10:53:24 samsung4-ubuntu django-admin[1314343]: 10:53:24 [Q] INFO Process-1:1 ready for work at 1314371
Dec 06 10:53:24 samsung4-ubuntu django-admin[1314343]: 10:53:24 [Q] INFO Process-1:2 ready for work at 1314372
Dec 06 10:53:24 samsung4-ubuntu django-admin[1314343]: 10:53:24 [Q] INFO Process-1:3 ready for work at 1314373
Dec 06 10:53:24 samsung4-ubuntu django-admin[1314343]: 10:53:24 [Q] INFO Process-1:4 ready for work at 1314374
Dec 06 10:53:24 samsung4-ubuntu django-admin[1314343]: 10:53:24 [Q] INFO Process-1:5 monitoring at 1314375
Dec 06 10:53:24 samsung4-ubuntu django-admin[1314343]: 10:53:24 [Q] INFO Process-1 guarding cluster at 1314370
Dec 06 10:53:24 samsung4-ubuntu django-admin[1314343]: 10:53:24 [Q] INFO Process-1:6 pushing tasks at 1314376
Dec 06 10:53:24 samsung4-ubuntu django-admin[1314343]: 10:53:24 [Q] INFO Q Cluster-1314343 running.
It seems that this file is created during the installation of one of mailman3 binary packages.
There is another systemd service called mailman3-web.service provided by mailman3-web binary package:
# more /lib/systemd/system/mailman3-web.service
[Unit]
Description=Mailman3-web uWSGI service
After=network.target
Documentation=file:///usr/share/doc/mailman3-web/README.rst
[Service]
ExecStart=/usr/bin/uwsgi --plugin python3 --ini /etc/mailman3/uwsgi.ini
Restart=on-failure
KillSignal=SIGQUIT
Type=notify
StandardError=syslog
NotifyAccess=all
User=root
Group=root
[Install]
WantedBy=multi-user.target
It also needs access to /var/log/mailman3/mailmansuite.log, so the final correct permissions for that file must be something like list:<gid> with <gid> being defined in /etc/mailman3/uwsgi.ini.
However, there is an attach-daemon = ./manage.py qcluster line which seems to perform the job of the previously defined qcluster.service, doesn't it?
participants (3)
-
actionmystique＠gmail.com -
jean-christophe manciot
-
Mark Sapiro