devfs
[Top] [All Lists]

Re[3]: [PATCH] fix initlog/minilogd deadlock on /dev/log access

To: "Pavel Roskin" <proski@xxxxxxx>
Subject: Re[3]: [PATCH] fix initlog/minilogd deadlock on /dev/log access
From: "Andrey Borzenkov" <arvidjaar@xxxxxxx>
Date: Mon, 05 May 2003 09:20:08 +0400
Cc: devfs@xxxxxxxxxxx
In-reply-to: <Pine.LNX.4.55.0305050005230.1278@xxxxxxxxxxxxxxxxxxxxxxxx>
Reply-to: "Andrey Borzenkov" <arvidjaar@xxxxxxx>
Sender: devfs-bounce@xxxxxxxxxxx
> 
> Hello!
> 

thank you for taking time to investigate.

> The problem with the hang on "Finding module dependencies" has been traced
> to a deadlock in the kernel, possibly in devfs.
> 
> One minilogd calls bind() on /dev/log, and the other calls unlink() on the
> same file.  The problem only happens with Linux 2.4.x (not 2.5.x) and only
> if devfs is mounted.
> 
> Given that it's essentially a race condition, we cannot be sure that the
> problem doesn't exist without devfs or on 2.5.x kernels.  However, devfs
> must be involved somehow.
> 
> Since both minilogd processes are in the "D" state, I don't think devfsd
> is involved.  They both are waiting in the kernel.
> 

I could not reproduce D state. Could you send me your stack

> The attached patch can be used as a workaround.  It prevents minilogd
> from doing unlink() while another one is calling bind() on the same file.
> The patch is very ugly and is not meant to be applied.  However, it
> demonstrates where the problem lies.
> 

Yes, I know that it involves several concurrent minilogd. Your
patch fixes just symptom not the reason why it happens :) 

> I think there is more that one program to blame.  We have two initlog
> processes, each calling minilogd.  That's the first problem.
> 

This is the exact problem that was fixed in  my patch. What happens,
is

1) first initlog is started, finds out /dev/log is unavailable,
starts minilogd

2) first initlog calls openlog/syslog/closelog. openlog (which does
connect) updates /dev/log atime. minilogd assumes syslog has been
started and exits

3) on next call initlog finds /dev/log is unavailable and starts
minilogd again;

4) see 2)

to have deadlock we need second initlog somewhere - dammit, I missed
that fact:

# The root filesystem is now read-write, so we can now log
# via syslog() directly..
if [ -n "$IN_INITLOG" ]; then
    IN_INITLOG=
fi

That perfectly explains why it happens at this place. Instead of
logging via single initlog that is parent of rc.sysinit we now
start seperate initlog for every action each one starting minilogd
every time it logs a line. At some point one of them happily hangs.

I am about to clean up initscripts anyway; one  more point to
consider.

> We have minilogd removing /dev/log without trying to find if it's in use.
> This may or may not be OK.  At least it's not OK if the kernel is not
> fixed.  That's the second problem.
> 

there is no way to find out if it is in use without race conditions.
The only way is to try to connect but you can't be sure it won't be
removed and recreated between connect and bind.

> unlink() and bind() can deadlock on devfs.  That's the third problem.  If
> it's a known problem and it was fixed in 2.5.x kernels, it would be really
> nice to propagate the fix to the 2.4.x series, because hanging Red Hat is
> a major annoyance, and it took me months living with even worse
> workarounds and a whole day to track it down.
> 

I do not think it is related to devfs, but who knows ... I still
believe devfs just triggers bad minilogd behaviour that was hidden
before.

> There are some more details in this bug:
> https://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=85621
> 
> I'll try to create a testcase not involving reboot.  Also, I'll be able to
> run the logs produced by Alt-SysRq T through ksymoops.  But I'm going to
> be quite busy next week, so I'll appreciate if someone else beats me as
> that.
> 

I was not able reproduce the D state case, but I can add fourth
problem:

initlogs sleep in connect. For all I can tell this cannot happen -
if socket is not in LISTEN connect should be refused. What I did
was

- stop syslog
- do something like (in zsh)

for i in {1..20}; do
initlog test & initlog test & initlog test &
done

I get many minilogds looping on poll and many initlogs hanging in connect. The 
fact minilogs loops on poll means it listens on SOCKET
but never gets anything to accept. So, what is this socket all
initlogs are trying to connect to?

thank you

-andrey


<Prev in Thread] Current Thread [Next in Thread>