Назад | Перейти на главную страницу

Вращение журнала Elastic Beanstalk вызывает перезапуск Apache

Я уже проработал AWS Elastic Beanstalk - Apache постоянно перезагружается

Наши экземпляры эластичного beanstalk сообщают следующее сообщение в error_log

[Mon Jun 26 22:01:01.878892 2017] [mpm_prefork:notice] [pid 8595] AH00173: SIGHUP received.  Attempting to restart
*** Error in (wsgi:wsgi)    ': double free or corruption (out): 0x00007f564cced560 ***

иногда последовательность ошибок будет выглядеть примерно так:

[Tue Jun 27 00:01:01.215260 2017] [:error] [pid 6429] [remote XX.XXX.XX.195:29773] mod_wsgi (pid=6429): Exception occurred processing WSGI script '/opt/python/current/app/site/settings/wsgi/__init__.py'.
[Tue Jun 27 00:01:01.215320 2017] [:error] [pid 6429] [remote XX.XXX.XX.195:29773] OSError: failed to write data
[Tue Jun 27 00:01:01.222407 2017] [:error] [pid 6430] [remote XX.XXX.XX.60:53313] mod_wsgi (pid=6430): Exception occurred processing WSGI script '/opt/python/current/app/site/settings/wsgi/__init__.py'.
[Tue Jun 27 00:01:01.222460 2017] [:error] [pid 6430] [remote XX.XXX.XX.60:53313] OSError: failed to write data
[Tue Jun 27 00:01:04.554810 2017] [core:warn] [pid 8595] AH00045: child process 7614 still did not exit, sending a SIGTERM
[Tue Jun 27 00:01:04.554850 2017] [core:warn] [pid 8595] AH00045: child process 7615 still did not exit, sending a SIGTERM
[Tue Jun 27 00:01:05.555958 2017] [mpm_prefork:notice] [pid 8595] AH00173: SIGHUP received.  Attempting to restart
*** Error in (wsgi:wsgi)    ': double free or corruption (out): 0x00007f5640cae900 ***
*** Error in (wsgi:wsgi)    ': double free or corruption (out): 0x00007f78649b7970 ***

Это будет продолжаться почти каждый час. Обычное сообщение:

[Mon Jun 26 22:01:01.878892 2017] [mpm_prefork:notice] [pid 8595] AH00173: SIGHUP received.  Attempting to restart

Я искал mpm_prefork module conf block ... и его нет, поэтому используются все значения по умолчанию.

Я искал logrotation команда выполняется elastic beanstalk

/var/log/httpd/* {
size 10M
missingok
notifempty
rotate 5
sharedscripts
compress
dateext
dateformat -%s
create
postrotate
    /sbin/service httpd reload > /dev/null 2>/dev/null || true
endscript
olddir /var/log/httpd/rotated
}

Довольно стандартный материал. Мое понимание reload это пытается изящный перезапуск ...

Я могу вручную вызвать сообщение об ошибке, выполнив sudo apachectl -k restart хотя я не могу найти, где это будет выполняться во время ротации журнала.

У нас есть нисходящие сервисы, которые, кажется, выдают исключения в момент, когда этот сервер вешает все свои соединения.

Итак, мой вопрос: что еще может вызвать SIGHUP в пределах mpm_prefork в течение logrotate? Насколько я могу судить, это не должно происходить вне состояния ошибки.

Apache / 2.4.18 (Amazon) mod_wsgi / 3.5 Python / 3.4.3

Вкратце, похоже, что текущая конфигурация логротации Elastic Beanstalk нарушена, что приводит к простою службы, Ошибка 504 Время ответа сервера истекло. Давайте взглянем.

Размножение

Создаем простейшее приложение Python WSGI.

application.py

import time


def application(environ, start_response):
    # somewhat realistic response duration
    time.sleep(0.5)

    status = '200 OK'
    response_headers = [('Content-type', 'text/plain')]
    start_response(status, response_headers)
    return [b'Hello world!\n']

Заархивируйте это в application.zip. Затем создайте приложение и среду Elastic Beanstalk Python, загрузите архив. Убедитесь, что вы используете имеющуюся пару ключей. Остальные настройки оставьте по умолчанию. Подождите, пока это будет сделано (несколько минут).

ssh в базовый экземпляр EC2 (см. идентификатор экземпляра в журнале EB). Тип (httpdпост-действие logrotate, см. ниже):

sudo /sbin/service httpd reload

Затем на вашем компьютере запустите:

siege -v -b -c 10 -t 10S http://your-test-eb.you-aws-region.elasticbeanstalk.com/

И пока он запускается, повторите команду перезагрузки пару раз.

Тогда вы должны увидеть что-то вроде следующего:

** SIEGE 3.0.8
** Preparing 10 concurrent users for battle.
The server is now under siege...
HTTP/1.1 200   0.63 secs:      13 bytes ==> GET  /
HTTP/1.1 200   0.65 secs:      13 bytes ==> GET  /
HTTP/1.1 200   0.64 secs:      13 bytes ==> GET  /
HTTP/1.1 200   0.60 secs:      13 bytes ==> GET  /
...

Вот что происходит, когда ты reload.

HTTP/1.1 504   0.06 secs:       0 bytes ==> GET  /
HTTP/1.1 504   0.07 secs:       0 bytes ==> GET  /
HTTP/1.1 504   0.08 secs:       0 bytes ==> GET  /
HTTP/1.1 504   0.10 secs:       0 bytes ==> GET  /
HTTP/1.1 504   0.11 secs:       0 bytes ==> GET  /
HTTP/1.1 504   0.66 secs:       0 bytes ==> GET  /
HTTP/1.1 504   0.19 secs:       0 bytes ==> GET  /
HTTP/1.1 504   0.20 secs:       0 bytes ==> GET  /
HTTP/1.1 504   0.09 secs:       0 bytes ==> GET  /

Потом выздоравливает.

HTTP/1.1 200   1.25 secs:      13 bytes ==> GET  /
HTTP/1.1 200   1.24 secs:      13 bytes ==> GET  /
HTTP/1.1 200   1.26 secs:      13 bytes ==> GET  /
...

Lifting the server siege..      done.

Transactions:                 75 hits
Availability:              81.52 %
Elapsed time:               9.40 secs
Data transferred:           0.00 MB
Response time:              1.21 secs
Transaction rate:           7.98 trans/sec
Throughput:             0.00 MB/sec
Concurrency:                9.68
Successful transactions:      75
Failed transactions:          17
Longest transaction:        4.27
Shortest transaction:       0.06

Обратите внимание, что ELB, похоже, не влияет на проблему, и то же самое может быть воспроизведено с помощью двух сеансов SSH с базовым EC2 и (Amazon AMI не имеет siege):

ab -v 4 -c 10 -t 10 http://your-test-eb.you-aws-region.elasticbeanstalk.com/

Причина

/etc/cron.hourly/cron.logrotate.elasticbeanstalk.httpd.conf

#!/bin/sh
test -x /usr/sbin/logrotate || exit 0
/usr/sbin/logrotate /etc/logrotate.elasticbeanstalk.hourly/logrotate.elasticbeanstalk.httpd.conf

/etc/logrotate.elasticbeanstalk.hourly/logrotate.elasticbeanstalk.httpd.conf

/var/log/httpd/* {
size 10M
missingok
notifempty
rotate 5
sharedscripts
compress
dateext
dateformat -%s
create
postrotate
    /sbin/service httpd reload > /dev/null 2>/dev/null || true
endscript
olddir /var/log/httpd/rotated
}

Уведомление postrotate. /sbin/service это просто оболочка System V для скриптов в /etc/init.d/. На его странице руководства говорится:

service запускает сценарий инициализации System V в максимально предсказуемой среде, удаляя большинство переменных среды и с текущим рабочим каталогом, установленным на /.

Обратите внимание, что reload не стандартный Apache команда обслуживания. Это дополнение к дистрибутиву. Заглянем в сценарий инициализации, /etc/init.d/httpd. Соответствующая часть следует:

reload() {
        echo -n $"Reloading $prog: "
        check13 || exit 1
        killproc -p ${pidfile} $httpd -HUP
        RETVAL=$?
        echo
}

Как видите, он отправляет HUP сигнал для Apache, который интерпретируется как Перезагрузить сейчас:

Отправка HUP или restart сигнал родителю заставляет его убить своих детей, как в TERM, но родитель не выходит. Он перечитывает свои файлы конфигурации и повторно открывает все файлы журналов. Затем он порождает новый набор детей и продолжает показывать хиты.

TERM довольно хорошо объясняет 504-е. Но как это, наверное, должно было быть сделано? Изящный перезапуск, поскольку он также повторно открывает журналы, но не прекращает обслуживание запросов:

В USR1 или graceful signal заставляет родительский процесс посоветовать дочерним процессам выйти после их текущего запроса (или немедленно выйти, если они ничего не обслуживают). Родитель перечитывает свои файлы конфигурации и повторно открывает файлы журнала. Когда каждый дочерний элемент умирает, родитель заменяет его дочерним элементом из нового поколения конфигурации, который немедленно начинает обслуживать новые запросы.

...

Код был написан для минимизации времени, в течение которого сервер не может обслуживать новые запросы (они будут помещены в очередь операционной системой, поэтому они ни в коем случае не потеряны), и для соблюдения ваших параметров настройки.

Обходной путь

Можно использовать .ebextensions заменить /etc/logrotate.elasticbeanstalk.hourly/logrotate.elasticbeanstalk.httpd.conf. В корневом каталоге создайте .ebextensions / 10_logs.config со следующим содержимым (в основном замените «перезагрузить» на «изящный»):

files:
    "/etc/logrotate.elasticbeanstalk.hourly/logrotate.elasticbeanstalk.httpd.conf":
        mode: "000644"
        owner: root
        group: root
        content: |
            /var/log/httpd/* {
                size 10M
                missingok
                notifempty
                rotate 5
                sharedscripts
                compress
                dateext
                dateformat -%s
                create
                postrotate
                    /sbin/service httpd graceful > /dev/null 2>/dev/null || true
                endscript
                olddir /var/log/httpd/rotated
            }

И повторно разверните среду Elastic Beanstalk. Обратите внимание, однако, что с последующими плавными перезапусками менее чем за секунду я смог (время от времени) производить 503 Сервис недоступен, что, однако, не относится к ротации журналов, поскольку при равномерно распределенных плавных перезапусках ошибок не было.