Bug 17250
| Summary: | doesn't log after syslogd restart | ||
|---|---|---|---|
| Product: | Branch 4.1 | Reporter: | Ivan Zakharyaschev <imz> |
| Component: | klogd | Assignee: | Dmitry V. Levin <ldv> |
| Status: | CLOSED NOTABUG | QA Contact: | qa-4.1 <qa-4.1> |
| Severity: | critical | ||
| Priority: | P2 | CC: | stanv |
| Version: | unspecified | ||
| Hardware: | all | ||
| OS: | Linux | ||
| Bug Depends on: | 17720, 17716, 17717, 17718 | ||
| Bug Blocks: | |||
This was also true on syslogd-1.4.1-alt19, klogd-1.4.1-alt19. У меня что-то не получается воспроизвести
rpm -q syslogd klogd
syslogd-1.4.1-alt28
klogd-1.4.1-alt28
# service klogd status
klogd is running
# service syslogd status
syslogd is running
# tail -f /var/log/kernel/warnings (*1)
# echo '<4>Before syslogd reload' >/dev/kmsg
в (*1) появилось: Oct 27 11:10:37 stanv kernel: Before syslogd reload
В /etc/logrotate.d/syslog идет вызов:
/sbin/reload-syslog >/dev/null
вызовим его:
# /sbin/reload-syslog
Stopping system logger service: [ DONE ]
Starting system logger service: [ DONE ]
# echo '<4>After syslogd reload' >/dev/kmsg
в (*1) появилось: Oct 27 11:16:42 stanv kernel: After syslogd reload
аналогично и для #service syslogd restart
в разговоре с vsu@
->вообще патч на восстановление соединения у нас вроде бы давно приложен
->и /dev/log в чруте klogd наблюдается
->у меня, кстати, это работает правильно
->ну сделай strace -p $klogd_pid и посмотри, что с ним происходит
Process 6018 attached - interrupt to quit
read(4, "<4>Test\n", 4095) = 8
time(NULL) = 1225117143
write(3, "<4>Oct 27 17:19:03 kernel: Test\0", 32) = -1 ECONNREFUSED (Connection refused)
close(3) = 0
socket(PF_FILE, SOCK_DGRAM, 0) = 3
connect(3, {sa_family=AF_FILE, path="/dev/log"}, 10) = 0
write(3, "<4>Oct 27 17:19:03 kernel: Test\0", 32) = 32
read(4,
->вообще reload, т.е. посылает SIGHUP
->при этом вроде и соединение не рвётся
->странно
Функция vsyslog(), определённая в syslog.c и используемая klogd, содержит следующий код:
/* output the message to the local logger */
result = write(LogFile, tbuf, cnt + 1);
if (result == -1
&& (errno == ECONNRESET || errno == ENOTCONN || errno == ECONNREFUSED)) {
closelog();
openlog(LogTag, LogStat | LOG_NDELAY, LogFacility);
result = write(LogFile, tbuf, cnt + 1);
}
Начиная с 1.4.1-alt17, файл CHANGES содержит следующую строку:
- klogd will reconnect to the logger (mostly syslogd) after it went away.
Остаётся предположить, что сокет /var/lib/klogd/dev/log не проинициализирован правильно из-за того, что со ссылкой /etc/syslog.d/klogd что-то случилось.
P.S. Я точно знаю, что этой проблемы нет, и если бы Reporter не имел хорошую репутацию, то я бы закрыл этот баг сразу как NOTABUG.
(In reply to comment #2) > ->ну сделай strace -p $klogd_pid и посмотри, что с ним происходит # strace -p 2819 Process 2819 attached - interrupt to quit read(4, "<4>After syslogd reload\n", 4095) = 24 connect(3, {sa_family=AF_FILE, path="/dev/log"}, 10) = -1 EACCES (Permission denied) time(NULL) = 1225197029 write(3, "<4>Oct 28 15:30:29 kernel: After"..., 48) = -1 ENOTCONN (Transport endpoint is not connected) close(3) = 0 socket(PF_FILE, SOCK_DGRAM, 0) = 3 connect(3, {sa_family=AF_FILE, path="/dev/log"}, 10) = -1 EACCES (Permission denied) write(3, "<4>Oct 28 15:30:29 kernel: After"..., 48) = -1 ENOTCONN (Transport endpoint is not connected) read(4, (In reply to comment #3) > Остаётся предположить, что сокет /var/lib/klogd/dev/log не проинициализирован > правильно из-за того, что со ссылкой /etc/syslog.d/klogd что-то случилось. # l /var/lib/klogd/dev/log /etc/syslog.d/klogd srw-rw-rw- 1 root root 0 Oct 26 12:02 /var/lib/klogd/dev/log= lrwxrwxrwx 1 root root 22 Sep 19 14:48 /etc/syslog.d/klogd -> /var/lib/klogd/dev/log= # lsof /var/lib/klogd/dev/log /dev/log COMMAND PID USER FD TYPE DEVICE SIZE NODE NAME syslogd 28270 syslogd 3u unix 0xb5a93c80 22814548 /dev/log syslogd 28270 syslogd 40u unix 0xb8480ac0 22814550 /var/lib/klogd/dev/log # (In reply to comment #4) > connect(3, {sa_family=AF_FILE, path="/dev/log"}, 10) = -1 EACCES (Permission denied) Это совсем другое дело: испортились права на /dev/log, /dev или /. (In reply to comment #6) > (In reply to comment #4) > > connect(3, {sa_family=AF_FILE, path="/dev/log"}, 10) = -1 EACCES (Permission denied) > > Это совсем другое дело: испортились права на /dev/log, /dev или /. Например, у группы klogd и каталога /var/lib/klogd/dev отличаются gid'ы. (In reply to comment #7) > Например, у группы klogd и каталога /var/lib/klogd/dev отличаются gid'ы. > Да, так и есть. Спасибо! я бы не скоро это понял: # pidof klogd 2819 # fgrep -i gid /proc/2819/status Tgid: 2819 Gid: 26 26 26 26 # fgrep klogd /etc/group klogd:x:261: # fgrep :26: /etc/group shadow:x:26: # l -d /var/lib/klogd/dev/log /var/lib/klogd/dev /var/lib/klogd /var/lib /var / /dev/log /dev drwxr-xr-x 10 root root 4260 Oct 26 12:02 /dev/ srw-rw-rw- 1 root root 0 Oct 26 12:02 /dev/log= drwx--x--- 2 root klogd 72 Oct 26 12:02 /var/lib/klogd/dev/ srw-rw-rw- 1 root root 0 Oct 26 12:02 /var/lib/klogd/dev/log= drwxr-xr-x 41 root root 1120 Oct 11 15:18 /var/lib/ drwxr-xr-x 32 root root 840 Sep 20 03:19 /var/ drwxr-xr-x 25 root root 592 Sep 19 20:02 // drwx--x--- 3 root klogd 72 Oct 4 2007 /var/lib/klogd/ # Теперь мне нужно понять, почему klogd не с тем gid. А ещё трудность этой ситуации в том, что сначала klogd работает, но перестаёт после перезапуска syslogd. Если бы он сразу отваливался, было бы удобно. (In reply to comment #8) > Теперь мне нужно понять, почему klogd не с тем gid. > > А ещё трудность этой ситуации в том, что сначала klogd работает, но перестаёт > после перезапуска syslogd. Если бы он сразу отваливался, было бы удобно. Вот я сделал # service klogd restart Stopping kernel logger service: [ DONE ] Starting kernel logger service: [ DONE ] с gid ситуация такая же: # pidof klogd 18943 # fgrep -i gid /proc/18943/status Tgid: 18943 Gid: 26 26 26 26 но он почему-то работает: во время "echo '<4>After klogd restart' >/dev/kmsg" видим: # strace -p 18943 Process 18943 attached - interrupt to quit read(4, "<4>After klogd restart\n", 4095) = 23 time(NULL) = 1225199147 write(3, "<4>Oct 28 16:05:47 kernel: After"..., 47) = 47 read(4, При start не происходит всех тех проверок прав, что происходит при переподсоединении. Кажется, для предсказуемости лучше, чтобы при start происходили настолько же жёсткие проверки, как и при переподсоединении. Ну а откуда береётся gid 26 вместо 261, я тоже пока не понял. (In reply to comment #8) > (In reply to comment #7) > > > Например, у группы klogd и каталога /var/lib/klogd/dev отличаются gid'ы. > > > > Да, так и есть. Т.е. всё-таки не совсем так: у процесса почему-то gid не совпадает с gid под именем klogd. А с каталогами всё хорошо. > # pidof klogd > 2819 > # fgrep -i gid /proc/2819/status > Tgid: 2819 > Gid: 26 26 26 26 > # fgrep klogd /etc/group > klogd:x:261: > # fgrep :26: /etc/group > shadow:x:26: > # l -d /var/lib/klogd/dev/log /var/lib/klogd/dev /var/lib/klogd /var/lib /var / /dev/log /dev > drwxr-xr-x 10 root root 4260 Oct 26 12:02 /dev/ > srw-rw-rw- 1 root root 0 Oct 26 12:02 /dev/log= > drwx--x--- 2 root klogd 72 Oct 26 12:02 /var/lib/klogd/dev/ > srw-rw-rw- 1 root root 0 Oct 26 12:02 /var/lib/klogd/dev/log= > drwxr-xr-x 41 root root 1120 Oct 11 15:18 /var/lib/ > drwxr-xr-x 32 root root 840 Sep 20 03:19 /var/ > drwxr-xr-x 25 root root 592 Sep 19 20:02 // > drwx--x--- 3 root klogd 72 Oct 4 2007 /var/lib/klogd/ > # > > Теперь мне нужно понять, почему klogd не с тем gid. > > А ещё трудность этой ситуации в том, что сначала klogd работает, но перестаёт > после перезапуска syslogd. Если бы он сразу отваливался, было бы удобно. > (In reply to comment #9) > Ну а откуда береётся gid 26 вместо 261, я тоже пока не понял. А, это просто -- рассогласовались /etc/passwd и группа klogd: # fgrep klogd /etc/passwd klogd:*:108:26::/dev/null:/dev/null # fgrep klogd /etc/group klogd:x:261: # Наверное, по моей вине когда-то. Not a bug, но можно придумать улучшения (текущая ситуация, что по сути из-за опечатки эта проблема была, но не была замечена кучу времени, не очень хороша): в klogd: https://bugzilla.altlinux.org/show_bug.cgi?id=17716 https://bugzilla.altlinux.org/show_bug.cgi?id=17717 более системные проверки: https://bugzilla.altlinux.org/show_bug.cgi?id=17718 https://bugzilla.altlinux.org/show_bug.cgi?id=17719 https://bugzilla.altlinux.org/show_bug.cgi?id=17720 |
Description
Ivan Zakharyaschev 2008-09-21 17:37:18 MSD