Супервизор Dotcloud показывает ошибку, но процесс запущен

Моя установка dotcloud (django-celery с rabbitmq) работала нормально неделю назад - процессы запускались нормально, а журналы были чистыми. Однако я недавно повторил попытку (без обновления кода), и теперь в журналах говорится, что процессы не запускаются, даже если они кажутся запущенными.

Журнал супервизора

dotcloud@hack-default-www-0:/var/log/supervisor$ more supervisord.log
2012-06-03 10:51:51,836 CRIT Set uid to user 1000
2012-06-03 10:51:51,836 WARN Included extra file "/etc/supervisor/conf.d/uwsgi.c
onf" during parsing
2012-06-03 10:51:51,836 WARN Included extra file "/home/dotcloud/current/supervi
sord.conf" during parsing
2012-06-03 10:51:51,938 INFO RPC interface 'supervisor' initialized
2012-06-03 10:51:51,938 WARN cElementTree not installed, using slower XML parser
 for XML-RPC
2012-06-03 10:51:51,938 CRIT Server 'unix_http_server' running without any HTTP
authentication checking
2012-06-03 10:51:51,946 INFO daemonizing the supervisord process
2012-06-03 10:51:51,947 INFO supervisord started with pid 144
2012-06-03 10:51:53,128 INFO spawned: 'celerycam' with pid 159
2012-06-03 10:51:53,133 INFO spawned: 'apnsd' with pid 161
2012-06-03 10:51:53,148 INFO spawned: 'djcelery' with pid 164
2012-06-03 10:51:53,168 INFO spawned: 'uwsgi' with pid 167
2012-06-03 10:51:53,245 INFO exited: djcelery (exit status 1; not expected)
2012-06-03 10:51:53,247 INFO exited: celerycam (exit status 1; not expected)
2012-06-03 10:51:54,698 INFO spawned: 'celerycam' with pid 176
2012-06-03 10:51:54,698 INFO success: apnsd entered RUNNING state, process has s
tayed up for > than 1 seconds (startsecs)
2012-06-03 10:51:54,705 INFO spawned: 'djcelery' with pid 177
2012-06-03 10:51:54,706 INFO success: uwsgi entered RUNNING state, process has s
tayed up for > than 1 seconds (startsecs)
2012-06-03 10:51:54,731 INFO exited: djcelery (exit status 1; not expected)
2012-06-03 10:51:54,754 INFO exited: celerycam (exit status 1; not expected)
2012-06-03 10:51:56,760 INFO spawned: 'celerycam' with pid 178
2012-06-03 10:51:56,765 INFO spawned: 'djcelery' with pid 179
2012-06-03 10:51:56,790 INFO exited: celerycam (exit status 1; not expected)
2012-06-03 10:51:56,791 INFO exited: djcelery (exit status 1; not expected)
2012-06-03 10:51:59,798 INFO spawned: 'celerycam' with pid 180
2012-06-03 10:52:00,538 INFO spawned: 'djcelery' with pid 181
2012-06-03 10:52:00,565 INFO exited: celerycam (exit status 1; not expected)
2012-06-03 10:52:00,571 INFO gave up: celerycam entered FATAL state, too many st
art retries too quickly
2012-06-03 10:52:00,573 INFO exited: djcelery (exit status 1; not expected)
2012-06-03 10:52:01,575 INFO gave up: djcelery entered FATAL state, too many sta
rt retries too quickly
dotcloud@hack-default-www-0:/var/log/supervisor$

Журнал djerror:

dotcloud@hack-default-www-0:/var/log/supervisor$ more djcelery_error.log
Traceback (most recent call last):
  File "hack/manage.py", line 2, in 
    from django.core.management import execute_manager
ImportError: No module named django.core.management
Traceback (most recent call last):
  File "hack/manage.py", line 2, in 
    from django.core.management import execute_manager
ImportError: No module named django.core.management
Traceback (most recent call last):
  File "hack/manage.py", line 2, in 
    from django.core.management import execute_manager
ImportError: No module named django.core.management
Traceback (most recent call last):
  File "hack/manage.py", line 2, in 
    from django.core.management import execute_manager
ImportError: No module named django.core.management
dotcloud@hack-default-www-0:/var/log/supervisor$

Statusctrl показывает, что некоторые процессы запущены, но идентификаторы pid-ов разные. Кроме того, функция сельдерея, похоже, работает нормально. Сообщения обрабатываются, и я вижу, что сообщения обрабатываются в интерфейсе администратора django (работает dj celery cam).

# supervisorctl status
apnsd                            RUNNING    pid 225, uptime 0:00:44
celerycam                        RUNNING    pid 224, uptime 0:00:44
djcelery                         RUNNING    pid 226, uptime 0:00:44

Файл Supervisord.conf:

[program:djcelery]
directory = /home/dotcloud/current/
command = python hack/manage.py celeryd -E -l info -c 2
stderr_logfile = /var/log/supervisor/%(program_name)s_error.log
stdout_logfile = /var/log/supervisor/%(program_name)s.log

[program:celerycam]
directory = /home/dotcloud/current/
command = python hack/manage.py celerycam
stderr_logfile = /var/log/supervisor/%(program_name)s_error.log
stdout_logfile = /var/log/supervisor/%(program_name)s.log

http://jefurii.cafejosti.net/blog/2011/01/26/celery-in-virtualenv-with-supervisord/ говорит, что проблема может заключаться в том, что используемый питон неверен, поэтому я явно указал питон в файле супервизора. Теперь он работает, но не объясняет, что я вижу выше и почему мне пришлось изменить свою конфигурацию, когда на прошлой неделе она работала нормально.

Кроме того, не все pid-компоненты совпадают:

2012-06-03 11:19:03,045 CRIT Server 'unix_http_server' running without any HTTP
authentication checking
2012-06-03 11:19:03,051 INFO daemonizing the supervisord process
2012-06-03 11:19:03,052 INFO supervisord started with pid 144
2012-06-03 11:19:04,061 INFO spawned: 'celerycam' with pid 151
2012-06-03 11:19:04,066 INFO spawned: 'apnsd' with pid 153
2012-06-03 11:19:04,085 INFO spawned: 'djcelery' with pid 155
2012-06-03 11:19:04,104 INFO spawned: 'uwsgi' with pid 156
2012-06-03 11:19:05,271 INFO success: celerycam entered RUNNING state, process h
as stayed up for > than 1 seconds (startsecs)
2012-06-03 11:19:05,271 INFO success: apnsd entered RUNNING state, process has s
tayed up for > than 1 seconds (startsecs)
2012-06-03 11:19:05,271 INFO success: djcelery entered RUNNING state, process ha
s stayed up for > than 1 seconds (startsecs)
2012-06-03 11:19:05,271 INFO success: uwsgi entered RUNNING state, process has s
tayed up for > than 1 seconds (startsecs)

статус показывает, что кулачки сельдерея не совпадают:

# supervisorctl status
apnsd                            RUNNING    pid 153, uptime 0:06:17
celerycam                        RUNNING    pid 150, uptime 0:06:17
djcelery                         RUNNING    pid 155, uptime 0:06:17

person Trent    schedule 03.06.2012    source источник


Ответы (1)


Мое первое предположение заключается в том, что вы используете неправильный двоичный файл python (system python вместо virtualenv python), и это вызывает эту ошибку (ниже), потому что этот двоичный файл system python не имеет установленного пакета.

  Traceback (most recent call last):
  File "hack/manage.py", line 2, in 
    from django.core.management import execute_manager
  ImportError: No module named django.core.management

Вы должны изменить свой supervisord.conf на следующее, чтобы убедиться, что вы указываете правильную версию python.

[program:djcelery]
directory = /home/dotcloud/current/
command = /home/dotcloud/env/bin/python hack/manage.py celeryd -E -l info -c 2
stderr_logfile = /var/log/supervisor/%(program_name)s_error.log
stdout_logfile = /var/log/supervisor/%(program_name)s.log

[program:celerycam]
directory = /home/dotcloud/current/
command = /home/dotcloud/env/bin/python hack/manage.py celerycam
stderr_logfile = /var/log/supervisor/%(program_name)s_error.log
stdout_logfile = /var/log/supervisor/%(program_name)s.log

Путь python изменился с python на /home/dotcloud/env/bin/python.

Я не уверен, почему супервизор говорит, что он работает, а это не так, но, надеюсь, это небольшое изменение поможет устранить ваши ошибки и вернуть все к работе снова.

person Ken Cochrane    schedule 03.06.2012
comment
Работает не считая разницы в pid. Журналы показывают супервизор pid 150, celerycam pid 157, apnsd pid 160, djeclery pid 161, uwsgi pid 164, в то время как команда статуса supervisorctl /.dotcloud run hack.worker показывает apnsd 153, celerycam 150 [журналы показывают, что это pid для supervisord ?!], djcelery 155. Необычно то, что раньше это работало на dotcloud (я ничего не менял), но pid неправильные, и та же самая установка дает сбой при другом развертывании dotcloud, поэтому я изначально занимался дальнейшим расследованием (я помещаю для этого отдельный пост) - person Trent; 04.06.2012
comment
@taras, значит, все работает, с той лишь разницей, что PID не совпадают? Это проблема или просто вопрос, почему? - person Ken Cochrane; 04.06.2012
comment
Кажется, все работает нормально - это вопрос, почему, но причина, по которой я заинтересован, заключается в том, что у меня возникают некоторые проблемы с почти идентичной установкой, что побудило меня исследовать, что происходит на работающем сервере и различия между ними. - person Trent; 05.06.2012
comment
@Taras Причина, по которой pid-файлы разные, может быть по ряду причин, но, скорее всего, из-за виртуализации / chroot, которая происходит для разделения вашей службы с другими на хосте. Это всего лишь предположение, но если все работает нормально, я бы не стал об этом беспокоиться. - person Ken Cochrane; 05.06.2012