Bug 29666 - Не протоколирует локальные сообщения syslog
: Не протоколирует локальные сообщения syslog
Status: CLOSED FIXED
: Sisyphus
(All bugs in Sisyphus/rsyslog)
: unstable
: all Linux
: P3 critical
Assigned To:
:
:
:
:
:
  Show dependency tree
 
Reported: 2013-12-24 07:58 by
Modified: 2014-01-13 05:36 (History)


Attachments
Отчёт system-report о машине (6.99 KB, application/octet-stream)
2013-12-24 07:58, Evgenii Terechkov
no flags Details


Note

You need to log in before you can comment on or make changes to this bug.


Description From 2013-12-24 07:58:38
Created an attachment (id=6012) [details]
Отчёт system-report о машине

Установил на OpenVZ CT пакеты rsyslog, rsyslog-server-listen (при этом
удалились syslogd sysklogd klogd), запустил. Всё хорошо, сообщения
протоколируются.

Однако после перезагрузки перестали протоколироваться локально-сгенерированные
сообщения (например, через команду logger). Сообщения от удалённых хостов
пишутся.

При (ре)старте rsyslog в /v/l/s/messages такая ругань:
=========================================================
rsyslogd: cannot create '/dev/log': Address already in use
=========================================================
и действительно:
=========================================================
root@newmons ~ # lsof /dev/log
COMMAND  PID USER   FD   TYPE             DEVICE SIZE/OFF      NODE NAME
minilogd 133 root    8u  unix 0xffff880270397b00      0t0 956630925 /dev/log
=========================================================
Если убить minilogd и сказать service restart/reload rsyslogd, ничего не
меняется, /dev/log по прежнему занят minilogd.

Однако если остановить rsyslogd, убить minilogd и запустить rsyslogd -n (или
rsyslog -4 -w -x -n, как указано в /e/sysconfig/rsyslog плюс опция -n), то
rsyslog открывает /dev/log и локальные сообщения начинают протоколироваться.

Я подозреваю, проблема как-то связана с косвенным вызовом initlog из
/etc/init.d/rsyslogd
------- Comment #1 From 2013-12-24 08:06:09 -------
На другой машине с rsyslog (но уже физической под systemd, а не под
openvz/sysvinit) локальные сообщения протоколируются. Там вот так:

========================================================================
root@thinkpad ~ #lsof /dev/log
COMMAND   PID USER   FD   TYPE             DEVICE SIZE/OFF NODE NAME
systemd     1 root   30u  unix 0xffff88013094e780      0t0 1377 /dev/log
systemd-j 733 root    5u  unix 0xffff88013094e780      0t0 1377 /dev/log
========================================================================

состав пакетов rsyslog* идентичен.
------- Comment #2 From 2013-12-24 11:34:02 -------
С syslog-ng из сизифа такой проблемы не наблюдается.
------- Comment #3 From 2014-01-10 02:40:32 -------
Будьте добры, проверьте rsyslog из задания #111581
------- Comment #4 From 2014-01-10 06:09:49 -------
Попробовал свежий 7.4.8-alt1 из Сизифа и alt2 из #111581. На свежем контейнере
openvz - воспроизвелось оба раза.

Попробовал и на физической машинке (i586, std-pae, установил пакеты rsyslog,
rsyslog-server-listen без всякой настройки) - тоже воспроизводится.

Что интересно: если после запуска rsyslogd (сервисом, а не в режиме foreground)
убить занимающий /dev/log minilogd (проверяю всю дорогу посредством lsof
/dev/log) а потом сделать service rsyslog stop, то видно, что /dev/log снова
занимается новым процессом minilogd. Что утверждает меня в мысли, что что-то не
так в консерватории (SysVinit).
------- Comment #5 From 2014-01-10 06:16:06 -------
На этой же физической машине вернул обратно syslogd klogd, запустил - сокет
занялся, всё протоколируется нормально (без перезагрузки и на rsyslog
переключался и обратно на syslogd).
------- Comment #6 From 2014-01-10 19:34:05 -------
Для начала уберите SysSock.Unlink="off" из /etc/rsyslog.d/00_common.conf,
должно помоч.
Я добавил этот параметр в конфиг, потому что мне не понравилось поведение
rsyslog при остановке сервиса, он при выходе удаляет все дополнительные сокеты,
 указанные для chroot-сервисов в /etc/syslog.d/*

Изначальную проблему - обработку директории /etc/syslog.d/* и добавление
дополнительных сокетов логирования я попытался решить внешними средствам без
модификации исходников - перед стартом сервиса запускается генератор конфига
/etc/rsyslog.d/00_extrasockets.conf
Потом я обнаружил что все эти дополнительные сокеты удалаются при остановке
rsyslog. Т.к. такого поведения у sysklogd я не замечал, добавил параметр
SysSock.Unlink="off".
В принципе, rsyslog снова создает ранее удалённые сокеты, и все должно
работать, Но мне не понравилось удаление файлов из чужих пакетов.

to ldv@: не могли бы вы немного объяснить по работе syslogd?
Я вижу в исходниках два массива, funixn и funix.
В функции die

        /* Close the UNIX sockets. */
        for (i = 0; i < nfunix; i++)
                if (funix[i] != -1)
                        close(funix[i]);
        /* Close the inet socket. */
        if (InetInuse) close(inetm);

        /* Clean-up files. */
        for (i = 0; i < nfunix; i++)
                if (funixn[i] && funix[i] != -1)
                        (void)unlink(funixn[i]);

Т.е. файлы сокетов funixn[i] будут удаляться только если funix[i] не равно -1.
У меня создалось впечатление, что весь массив funix состоит из -1.
Не могу понять, почему он так заполняется.
Я правильно понял, что в sysklogd не выполняется удаление дополнительных
сокетов chroot-сервисов unlink(funixn[i]), т.к. funix[i]  всегда = -1?


аналогичный код в imuxsock.c(в rsyslog) выглядит так:

        /* Close the UNIX sockets. */
       for (i = 0; i < nfd; i++)
                if (listeners[i].fd != -1)
                        close(listeners[i].fd);

       /* Clean-up files. */
       for(i = startIndexUxLocalSockets; i < nfd; i++)
                if (listeners[i].sockName && listeners[i].fd != -1) {
                        /* If systemd passed us a socket it is systemd's job to
clean it up.
                         * Do not unlink it -- we will get same socket (node)
from systemd
                         * e.g. on restart again.
                         */
                        if (sd_fds > 0 &&
                            listeners[i].fd >= SD_LISTEN_FDS_START &&
                            listeners[i].fd <  SD_LISTEN_FDS_START + sd_fds)
                                continue;

                        if(listeners[i].bUnlink) {
                                DBGPRINTF("imuxsock: unlinking unix socket
file[%d] %s\n", i, listeners[i].sockName);
                                unlink((char*) listeners[i].sockName);
                        }
                }

        discardLogSockets();
        nfd = 1;


Возможно я вообще не там ищу проблему и ошибаюсь. Тогда прошу направить на путь
истинный.
------- Comment #7 From 2014-01-10 19:48:58 -------
скорее всего вызов discardLogSockets() в конце все удаляет. нужно ли его звать?
------- Comment #8 From 2014-01-10 19:49:46 -------
извиняюсь, ошибочно выставил fixed.
------- Comment #9 From 2014-01-10 20:01:15 -------
(In reply to comment #6)
> to ldv@: не могли бы вы немного объяснить по работе syslogd?
> Я вижу в исходниках два массива, funixn и funix.
> В функции die

В некотором смысле совершенно все равно, что делает syslogd в функции die,
поскольку он к этому времени уже глубоко в чруте, и никаких прав удалять файлы
сокетов у него нет.
------- Comment #10 From 2014-01-10 20:10:28 -------
Мне скорее всего не удастся засунуть rsyslog в чрут.
Т.е. удаление сокетов при выходе - это правильное поведение? даже для sysklogd,
если он не в чруте? И можно оставить такое поведение в rsyslog или запретить
удаление?
------- Comment #11 From 2014-01-10 20:29:43 -------
(In reply to comment #10)
> Мне скорее всего не удастся засунуть rsyslog в чрут.
> Т.е. удаление сокетов при выходе - это правильное поведение? даже для sysklogd,
> если он не в чруте? И можно оставить такое поведение в rsyslog или запретить
> удаление?

На удаление сокетов при завершении все равно нельзя полагаться, поскольку в
случае аварийного завершения это удаление может и не произойти.
Все равно при старте эти сокеты (если они есть) необходимо удалять, так что
сильно заморачиваться с удалением при завершении не стоит.
------- Comment #12 From 2014-01-10 20:53:21 -------
тогда последний вопрос :)
правильно ли я сделал 
http://git.altlinux.org/people/shaba/packages/?p=rsyslog.git;a=commitdiff;h=f9ab85c8840fddf5f5b293d8eab041eebf9e2d62

или надо откатить?
------- Comment #13 From 2014-01-10 21:13:40 -------
(In reply to comment #12)
> тогда последний вопрос :)
> правильно ли я сделал 
> http://git.altlinux.org/people/shaba/packages/?p=rsyslog.git;a=commitdiff;h=f9ab85c8840fddf5f5b293d8eab041eebf9e2d62

Правильно.

> или надо откатить?

Откатывать нельзя апстримить? :)
------- Comment #14 From 2014-01-10 21:47:27 -------
rsyslog-7.4.8-alt3 -> sisyphus:

* Fri Jan 10 2014 Alexey Shabalin <shaba@altlinux> 7.4.8-alt3
- drop SysSock.Unlink=off option (ALT#29666)

* Fri Jan 10 2014 Alexey Shabalin <shaba@altlinux> 7.4.8-alt2
- fixed run for SysV
------- Comment #15 From 2014-01-13 05:36:12 -------
Проверил, работает. Спасибо!