lkml.org 
[lkml]   [2010]   [Oct]   [30]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: open() on /dev/tty takes 30 seconds on 2.6.36
On Sat, 30 Oct 2010 09:47:26 +0200 Eli Billauer <eli@billauer.co.il> wrote:

> Hello,
>
> I'm sorry about my previous overconclusive email, but there is a real
> problem with opening TTYs during a few minutes after a system boots
> (Fedora 12 in my case). I'll stick to the facts this time.
>
> The kernel involved is 2.6.36, downloaded a few days ago as "latest
> stable kernel" at kernel.org.
>
> Running strace on sshd with -T and -tt flags, hence showing the time
> each call took, these two lines were found. The number in brackets is
> the time the system call took (not to the time to the next call or
> something).
>
> ...
> 21:35:21.131436 open("/dev/tty", O_RDWR|O_NOCTTY) = -1 ENXIO (No such
> device or address) <30.022532>
> ...
> 21:35:51.175642 open("/dev/pts/0", O_RDWR) = 4 <30.063213>
> ...
>
> So it took 30 seconds just to fail opening /dev/tty.
>
> I then went on to add printk's in pty.c. Among others, I had:
>
> static int ptmx_open(struct inode *inode, struct file *filp)
> {
> struct tty_struct *tty;
> int retval;
> int index;
>
> nonseekable_open(inode, filp);
>
> /* find a device that is not in use. */
> printk(KERN_ALERT "34: ptmx_open to lock\n");
> tty_lock();
> printk(KERN_ALERT "35: ptmx_open locked\n");
>
> [snipped here]
>
> And then found in my /var/log/messages (no log lines between these two):
> Oct 29 16:14:58 ocho kernel: 34: ptmx_open to lock
> Oct 29 16:15:13 ocho kernel: 35: ptmx_open locked
>
> So we can see it took 15 seconds to acquire a lock in this case. In all
> other pairs of lock messages there was no time difference. To me it
> looks like 15 seconds in order to acquire a lock in the kernel is a
> smoking gun.
>

Odd. Presumably someone else was holding big_tty_mutex for 15 seconds.

We can find out who, with the sysrq-d command if you have the time
please. You'll need to enable lockdep and magic sysrq in .config.
Then run `dmesg -n 8' so all messages get printed by the kernel and
then, in the middle of that 15-second delay, do

echo d > /proc/sysrq-trigger
I'll confess that I've never used sysrq-d and am unsure what the output
looks like. Fingers crossed!



\
 
 \ /
  Last update: 2010-10-30 20:51    [W:0.088 / U:0.440 seconds]
©2003-2014 Jasper Spaans. Advertise on this site