[Top][All Lists]
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: [bug-inetutils] syslog - blocks all procceses by a infinite read aft
From: |
Daniel Lehne |
Subject: |
Re: [bug-inetutils] syslog - blocks all procceses by a infinite read after poll |
Date: |
Fri, 02 Mar 2012 10:59:19 +0200 |
User-agent: |
Mozilla/5.0 (Windows NT 5.1; rv:10.0.2) Gecko/20120216 Thunderbird/10.0.2 |
On 01.3.2012 г. 13:35, D. Lehne wrote:
Hello,
in relation to a feature of circular log (clog) for syslog, i've seen
a strange behavior on the system resulting by syslog.
The system is a:
Linux 4S 2.6.33.7.2-rt30-A4-2011.02.0 #1 PREEMPT RT Tue Feb 7 17:39:13
CET 2012 armv6l GNU/Linux
Syslog is from inetutil-1.6:
address@hidden:~#ldd /sbin/syslogd
libresolv.so.2 => /lib/libresolv.so.2 (0x40026000)
libnsl.so.1 => /lib/libnsl.so.1 (0x4003a000)
libc.so.6 => /lib/libc.so.6 (0x40056000)
/lib/ld-linux.so.3 (0x40000000)
After syslog started the following situation happens. Syslog returns
from poll(), by an unknown sender, for a /proc/kmsg event of the fd
but there is no data to read and syslog reads infinite. All other
processes sending to syslog (like /dev/log) are blocked until a
message is sended to /proc/kmsg. This lock happens once after 20 or
more restarts, that means it is really rarly.
This is the strace of syslog:
address@hidden:~#cat /tmp/sys1trace
read(3,<unfinished ...>
address@hidden:~#ls -l /proc/498/fd
lr-x------ 1 root root 64 Feb 28 15:54 3 -> /proc/kmsg
This is a strace of a application:
address@hidden:/proc/496#cat /tmp/armtrace
send(6, "<134>Feb 28 13:47:19 : 28/02/12 "..., 99,
MSG_NOSIGNAL<unfinished ...>
The file discriptor handling is done in main():
for (;;)
{
int nready;
nready = poll (fdarray, nfds, -1);
if (nready == 0) /* ?? noop */
continue;
...
for (i = 0; i< nfds; i++)
if (fdarray[i].revents& (POLLIN | POLLPRI))
{
int result;
size_t len;
if (fdarray[i].fd == -1)
continue;
else if (fdarray[i].fd == fklog)
{
result = read (fdarray[i].fd,&kline[kline_len],
sizeof (kline) - kline_len - 1);
...
The file discriptor fklog represent /proc/kmsg. The fdarray consist
actually only of 2 active file descriptors, one is proc/kmsg and the
other dev/log. The read function blocks further processing.
The kernel man says for /proc/kmsg:
/proc/kmsg
..., and only one process should read this file. This
file should not be read if a syslog process is running which uses the
syslog(2) sys‐
tem call facility to log kernel messages.
My questions are the following:
1. Which other processes are working with /proc/kmsg?
2. Why poll() is used and not ppoll() ?
3. My patch is working with pwritev(), does it have influences on
poll() ?
4. Any suggest for a further/better debugging?
Best regards!
Hello,
once again after further investigation the following results. The read()
of /proc/kmsg seem to wait infinite on the wait_event_interruptible()
function, because the expression (log_start - log_end) wouldn't become
true. My opinion is, that O_NONBLOCK would fix this, once kernel code
could not interrupted. With the disadvantage of losing a /proc/kmsg line.
/linux-2.6.33/fs/proc/kmsg.c:
static ssize_t kmsg_read(struct file *file, char __user *buf,
size_t count, loff_t *ppos)
{
if ((file->f_flags & O_NONBLOCK) && !do_syslog(9, NULL, 0))
return -EAGAIN;
return do_syslog(2, buf, count);
}
and linux-2.6.33/kernel/printk.c:
int do_syslog(int type, char __user *buf, int len)
{
...
error = security_syslog(type);
if (error)
return error;
...
switch (type) {
...
case 2: /* Read from log */
...
error = wait_event_interruptible(log_wait,
(log_start -
log_end));
if (error)
goto out;
i = 0;
raw_spin_lock_irq(&logbuf_lock);
while (!error && (log_start != log_end) && i < len) {
c = LOG_BUF(log_start);
log_start++;
raw_spin_unlock_irq(&logbuf_lock);
error = __put_user(c,buf);
buf++;
i++;
cond_resched();
raw_spin_lock_irq(&logbuf_lock);
}
raw_spin_unlock_irq(&logbuf_lock);
if (!error)
error = i;
break;
...
case 9: /* Number of chars in the log buffer */
error = log_end - log_start;
...
return error;
}
Wait Queues <include/linux/wait.h> <SLEEPS>
...., it's used to guarantee that if you are checking for a condition,
and going to sleep if it's not true, that there is no gap between the
check and the sleeping.
*Queuing*
... There is a macro to do this: `wait_event_interruptible()'
<include/linux/sched.h>. The first argument is the wait queue head,
and the second is an expression which is evaluated; the macro
returns 0 when this expression is true, or -ERESTARTSYS if a signal
is received.
Best regards!