Bug 29666

Summary: Не протоколирует локальные сообщения syslog
Product: Sisyphus Reporter: Evgenii Terechkov <evg>
Component: rsyslogAssignee: Alexey Shabalin <shaba>
Status: CLOSED FIXED QA Contact: qa-sisyphus
Severity: critical    
Priority: P3 CC: ldv, shaba
Version: unstable   
Hardware: all   
OS: Linux   
Attachments:
Description Flags
Отчёт system-report о машине none

Description Evgenii Terechkov 2013-12-24 07:58:38 MSK
Created attachment 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 Evgenii Terechkov 2013-12-24 08:06:09 MSK
На другой машине с 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 Evgenii Terechkov 2013-12-24 11:34:02 MSK
С syslog-ng из сизифа такой проблемы не наблюдается.
Comment 3 Alexey Shabalin 2014-01-10 02:40:32 MSK
Будьте добры, проверьте rsyslog из задания #111581
Comment 4 Evgenii Terechkov 2014-01-10 06:09:49 MSK
Попробовал свежий 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 Evgenii Terechkov 2014-01-10 06:16:06 MSK
На этой же физической машине вернул обратно syslogd klogd, запустил - сокет занялся, всё протоколируется нормально (без перезагрузки и на rsyslog переключался и обратно на syslogd).
Comment 6 Alexey Shabalin 2014-01-10 19:34:05 MSK
Для начала уберите 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 Alexey Shabalin 2014-01-10 19:48:58 MSK
скорее всего вызов discardLogSockets() в конце все удаляет. нужно ли его звать?
Comment 8 Alexey Shabalin 2014-01-10 19:49:46 MSK
извиняюсь, ошибочно выставил fixed.
Comment 9 Dmitry V. Levin 2014-01-10 20:01:15 MSK
(In reply to comment #6)
> to ldv@: не могли бы вы немного объяснить по работе syslogd?
> Я вижу в исходниках два массива, funixn и funix.
> В функции die

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

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

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

Правильно.

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

Откатывать нельзя апстримить? :)
Comment 14 Repository Robot 2014-01-10 21:47:27 MSK
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 Evgenii Terechkov 2014-01-13 05:36:12 MSK
Проверил, работает. Спасибо!