strange delays on console logouts (tty != 1)

strange delays on console logouts (tty != 1)

[Jorge Bernal]

Since some days ago I'm using the console more than X and I have a
strange problem.

On tty's != 1 it takes a long time (~20-30 secs) from logout to next
login but on tty1 it takes a normal time.

If I launch getty on tty9 and logout (in tty9) getty ends inmediately
and I can start it again and get another login.

I'm not sure if it actually has something to do with the kernel (maybe
with /sbin/init). dmesg doesn't say anything about that.

Thanks,
	Koke

-- 
"Sólo el éxito diferencia al genio del loco"

Blog: http://www.amedias.org/koke
Web Personal: http://sindominio.net/~koke/
JID: koke@zgzjabber.ath.cx

Re: strange delays on console logouts (tty != 1)

[Chris Wedgwood]

On Fri, Apr 30, 2004 at 09:53:51PM +0200, Jorge Bernal wrote:

> On tty's != 1 it takes a long time (~20-30 secs) from logout to next
> login but on tty1 it takes a normal time.

Oddly I've seen the same thing off-and-on for quite some time now
(early 2.6.x or beofe, I can't be sure).  For me it affects all tty's.

> If I launch getty on tty9 and logout (in tty9) getty ends
> inmediately and I can start it again and get another login.

For me I see this on all tty's most (but not all) of the time.

> I'm not sure if it actually has something to do with the kernel
> (maybe with /sbin/init). dmesg doesn't say anything about that.

When (ie. during the 'dead time') I see this the tty isn't used by
anyone and even more rarely the tty will get stuck so that when init
gets around starting a getty, it exits immediately and then init
rate-limits by noy respwaning a console for 5 minutes.

I'm not sure who is to blame here, it looks like some tty's get into a
state that either init or the getty doesn't like and don't want to
come unstuck easily (stty sane > /dev/tty<foo> sometimes helps).

I need to get an init working as pid != 1 with debugging so I can
figure out what init thinks here.  I've just been so short of time.


 --cw

Re: strange delays on console logouts (tty != 1)

[Petr Vandrovec]

On Sat, May 01, 2004 at 02:46:17PM -0700, Chris Wedgwood wrote:
> On Fri, Apr 30, 2004 at 09:53:51PM +0200, Jorge Bernal wrote:
> 
> I'm not sure who is to blame here, it looks like some tty's get into a
> state that either init or the getty doesn't like and don't want to
> come unstuck easily (stty sane > /dev/tty<foo> sometimes helps).
> 
> I need to get an init working as pid != 1 with debugging so I can
> figure out what init thinks here.  I've just been so short of time.

I do not think that it is init... 

If I did analysis correct, problem is that:

(1) agetty (at least from util-linux 2.12 from current debian unstable)
opens /dev/console and calls VT_OPENQRY to find first unopened VT. I have
no idea why it does this, especially as it causes problems when more than
one agetty is started simultaneously. I cannot believe that there is
no better way how to detect whether tty is in use or not (as comment
in the agetty suggests). Even spawning fuser /dev/ttyX looks less racy
to me. This race between different agetty starting in parallel is reason
why some gettys are missing after bootup. As they all use 10 sec timeout it
takes some time until all my 24 gettys come up.

(2) tty hangup is scheduled for work_queue.

(3) when you have bad luck then scheduled hangup work runs AFTER newly
created agetty calls VT_OPENQRY, and you get an error that ttyX is already
in use...

When I just put /dev/ttyX instead of ttyX into /etc/inittab, problem
disappears (as then VT_OPENQRY code in agetty is not triggered) and
everything works as it should - except 'w', so I just disabled OPENQRY
code in agetty instead as final solution.

I think that we should concentrate on how is it possible that init can
spawn agetty and agetty can parse whole /var/run/utmp, open /dev/console
and issue VT_OPENQRY before work scheduled before init was even notified
is done. It looks to me like that someone schedules some job on the
workqueue although that job apparently deserves its own kernel thread
due to time it takes.
						Best regards,
							Petr Vandrovec

Re: strange delays on console logouts (tty != 1)

[Chris Wedgwood]

On Sun, May 02, 2004 at 01:24:48AM +0200, Petr Vandrovec wrote:

> I do not think that it is init...

No, it's not.

> (1) agetty (at least from util-linux 2.12 from current debian
> unstable) opens /dev/console and calls VT_OPENQRY to find first
> unopened VT.

yes, this i discovered too

> I have no idea why it does this, especially as it causes problems
> when more than one agetty is started simultaneously. I cannot
> believe that there is no better way how to detect whether tty is in
> use or not (as comment in the agetty suggests).

read below

> (2) tty hangup is scheduled for work_queue.

> (3) when you have bad luck then scheduled hangup work runs AFTER
> newly created agetty calls VT_OPENQRY, and you get an error that
> ttyX is already in use...

Unless I misunderstand you, I'm not conviced... it get tty's 'stuck',
they never come right even after hours or days.

> I think that we should concentrate on how is it possible that init
> can spawn agetty and agetty can parse whole /var/run/utmp, open
> /dev/console and issue VT_OPENQRY before work scheduled before init
> was even notified is done. It looks to me like that someone
> schedules some job on the workqueue although that job apparently
> deserves its own kernel thread due to time it takes.

Yes, as far as the kernel is concerned this needs checking.

By comments (from before I got this email) and a pointer to the fix I
use...


I see unused tty's (such as tty4) and ioctl(..., VT_OPENQRY, ...)
returning numbers like 8 --- which agetty barfs on.

The solution I hacked up was to have agetty use vhangup on the tty and
not even use the ioctl which seems fragile at the best of time.  The
present patch is at:

	http://stupidest.org/patches/util-linux-2.12-agetty-vhangup.001.patch

(ugly URL, sorry about that).

I've cc'd Andries Brouwer his his comments as he is the util-linux
maintainer.



Thanks,

  --cw

Re: strange delays on console logouts (tty != 1)

[Petr Vandrovec]

On Sat, May 01, 2004 at 04:44:44PM -0700, Chris Wedgwood wrote:
> On Sun, May 02, 2004 at 01:24:48AM +0200, Petr Vandrovec wrote:
> 
> > I do not think that it is init...
> 
> No, it's not.

Though it would be nice to be able to strace init too...

> > (3) when you have bad luck then scheduled hangup work runs AFTER
> > newly created agetty calls VT_OPENQRY, and you get an error that
> > ttyX is already in use...
> 
> Unless I misunderstand you, I'm not conviced... it get tty's 'stuck',
> they never come right even after hours or days.

It is strange. After logout it always comes up after 10 seconds delay in first
agetty run expires. Only on first start some of them need more than one attempt
to come up.

Do not you start some multithreaded daemons from shell which gets later
'stuck'? Maybe that controlling terminal handling is not 100% yet. Do not
some daemons "randomly" disappear since you use vhangup in agetty? ;-) AFAIK
controlling terminal is not available through /proc :-(
						Best regards,
							Petr Vandrovec

Re: strange delays on console logouts (tty != 1)

[Chris Wedgwood]

On Sun, May 02, 2004 at 02:36:50AM +0200, Petr Vandrovec wrote:

> Though it would be nice to be able to strace init too...

it has potential problems with what signals can be sent to pid 1 are
restricted

> It is strange. After logout it always comes up after 10 seconds
> delay in first agetty run expires.

that's usually but now always the case for me ... based on feedback
it's not always the case of others either

> Do not you start some multithreaded daemons from shell which gets
> later 'stuck'?

no

> Maybe that controlling terminal handling is not 100% yet. Do not
> some daemons "randomly" disappear since you use vhangup in agetty?

no

also, login uses vhangup too --- and has done for some time, so i
don't expect that this will change much at all

> AFAIK controlling terminal is not available through /proc :-(

i'm not sure it would be useful if it was, i guess maybe some of of
O_EXCL open hack might work to say we want to open the tty and fail if
anyone else has it open though

al?


  --cw

Re: strange delays on console logouts (tty != 1)

[Andries Brouwer]

On Sat, May 01, 2004 at 04:44:44PM -0700, Chris Wedgwood wrote:
> On Sun, May 02, 2004 at 01:24:48AM +0200, Petr Vandrovec wrote:
> 
> > (1) agetty (at least from util-linux 2.12 from current debian
> > unstable) opens /dev/console and calls VT_OPENQRY to find first
> > unopened VT.
> 
> yes, this i discovered too

Thank you for cc-ing me.
However, my agetty source does not contain the string VT_OPENQRY.
I suppose this is a private Debian change. Maybe you should
contact Debian people to find out who did this and why.
(And/or try the vanilla agetty to see whether the problems go away.)

Andries


[Just found the Debian patch. Strange, broken code.]

Re: strange delays on console logouts (tty != 1)

[Andrew Morton]

Petr Vandrovec <vandrove@vc.cvut.cz> wrote:
>
> (2) tty hangup is scheduled for work_queue.

This is the problem, isn't it?

>From what context is tty_hangup() invoked?  (stick a dump_stack() in there>?)

If possible, we should simply call do_tty_hangup() synchronously and only
do the schedule_work() thing when the hangup is initiated from the hardware
side.

Re: strange delays on console logouts (tty != 1)

[Russell King]

On Sat, May 01, 2004 at 06:03:47PM -0700, Andrew Morton wrote:
> Petr Vandrovec <vandrove@vc.cvut.cz> wrote:
> >
> > (2) tty hangup is scheduled for work_queue.
> 
> This is the problem, isn't it?
> 
> >From what context is tty_hangup() invoked?  (stick a dump_stack() in there>?)

>From IRQ context.  It's tty_vhangup() which is invoked from user context,
and calls do_tty_hangup() synchronously.

-- 
Russell King
 Linux kernel    2.6 ARM Linux   - http://www.arm.linux.org.uk/
 maintainer of:  2.6 PCMCIA      - http://pcmcia.arm.linux.org.uk/
                 2.6 Serial core

Re: strange delays on console logouts (tty != 1)

[Andrew Morton]

Russell King <rmk+lkml@arm.linux.org.uk> wrote:
>
> On Sat, May 01, 2004 at 06:03:47PM -0700, Andrew Morton wrote:
> > Petr Vandrovec <vandrove@vc.cvut.cz> wrote:
> > >
> > > (2) tty hangup is scheduled for work_queue.
> > 
> > This is the problem, isn't it?
> > 
> > >From what context is tty_hangup() invoked?  (stick a dump_stack() in there>?)
> 
> >From IRQ context.  It's tty_vhangup() which is invoked from user context,
> and calls do_tty_hangup() synchronously.
> 

But Chris and Petr are talking about virtual terminals on the local
console, are they not?

If so, how is tty_hangup() getting involved?

Re: strange delays on console logouts (tty != 1)

[Russell King]

On Sun, May 02, 2004 at 01:13:37AM -0700, Andrew Morton wrote:
> Russell King <rmk+lkml@arm.linux.org.uk> wrote:
> >
> > On Sat, May 01, 2004 at 06:03:47PM -0700, Andrew Morton wrote:
> > > Petr Vandrovec <vandrove@vc.cvut.cz> wrote:
> > > >
> > > > (2) tty hangup is scheduled for work_queue.
> > > 
> > > This is the problem, isn't it?
> > > 
> > > >From what context is tty_hangup() invoked?  (stick a dump_stack() in there>?)
> > 
> > >From IRQ context.  It's tty_vhangup() which is invoked from user context,
> > and calls do_tty_hangup() synchronously.
> > 
> 
> But Chris and Petr are talking about virtual terminals on the local
> console, are they not?
> 
> If so, how is tty_hangup() getting involved?

The only way it could be invoked is via SAK, which obviously isn't
happening here.

However, login _does_ call sys_vhangup() which in turn calls tty_vhangup()
so I suspect that the statement "tty hangup is scheduled for work_queue"
is based on the _assumption_ that sys_vhangup() calls tty_hangup()
rather than the function it actually does.

-- 
Russell King
 Linux kernel    2.6 ARM Linux   - http://www.arm.linux.org.uk/
 maintainer of:  2.6 PCMCIA      - http://pcmcia.arm.linux.org.uk/
                 2.6 Serial core

Re: strange delays on console logouts (tty != 1)

[Russell King]

On Sun, May 02, 2004 at 09:17:51AM +0100, Russell King wrote:
> > If so, how is tty_hangup() getting involved?
> 
> The only way it could be invoked is via SAK, which obviously isn't
> happening here.
> 
> However, login _does_ call sys_vhangup() which in turn calls tty_vhangup()
> so I suspect that the statement "tty hangup is scheduled for work_queue"
> is based on the _assumption_ that sys_vhangup() calls tty_hangup()
> rather than the function it actually does.

Ok, the VT_OPENQRY crap is a debian modification to agetty.  As far as
I can see, there is no code in agetty which calls sys_vhangup().

So the question to Petr is: how did you determine that the tty was
being hung up?

-- 
Russell King
 Linux kernel    2.6 ARM Linux   - http://www.arm.linux.org.uk/
 maintainer of:  2.6 PCMCIA      - http://pcmcia.arm.linux.org.uk/
                 2.6 Serial core

Re: strange delays on console logouts (tty != 1)

[Russell King]

On Sun, May 02, 2004 at 10:37:21AM +0100, Russell King wrote:
> On Sun, May 02, 2004 at 09:17:51AM +0100, Russell King wrote:
> > > If so, how is tty_hangup() getting involved?
> > 
> > The only way it could be invoked is via SAK, which obviously isn't
> > happening here.
> > 
> > However, login _does_ call sys_vhangup() which in turn calls tty_vhangup()
> > so I suspect that the statement "tty hangup is scheduled for work_queue"
> > is based on the _assumption_ that sys_vhangup() calls tty_hangup()
> > rather than the function it actually does.
> 
> Ok, the VT_OPENQRY crap is a debian modification to agetty.  As far as
> I can see, there is no code in agetty which calls sys_vhangup().

And a further follow-up...

Looking in the debian bug system reveals these two bugs:

     * #216658: getty: opens tty without checking if something else is there,
       killing keyboard input
     * #226443: util-linux: [getty] Logout is really long with kernel 2.6

The first one is of particular note, because it is the cause of the GROSS
hack in agetty, which according to the comments is also in gdm.

I wonder really if the problem was elsewhere, and if Debian wanted to
take care of this problem, why they didn't just take the serial line
locking solution (really: s/serial line/tty/) and apply it to
agetty / gdm.

-- 
Russell King
 Linux kernel    2.6 ARM Linux   - http://www.arm.linux.org.uk/
 maintainer of:  2.6 PCMCIA      - http://pcmcia.arm.linux.org.uk/
                 2.6 Serial core

Re: strange delays on console logouts (tty != 1)

[Petr Vandrovec]

On Sun, May 02, 2004 at 11:17:29AM +0100, Russell King wrote:
> On Sun, May 02, 2004 at 10:37:21AM +0100, Russell King wrote:
> > On Sun, May 02, 2004 at 09:17:51AM +0100, Russell King wrote:
> > > > If so, how is tty_hangup() getting involved?
> > > 
> > > The only way it could be invoked is via SAK, which obviously isn't
> > > happening here.
> > > 
> > > However, login _does_ call sys_vhangup() which in turn calls tty_vhangup()
> > > so I suspect that the statement "tty hangup is scheduled for work_queue"
> > > is based on the _assumption_ that sys_vhangup() calls tty_hangup()
> > > rather than the function it actually does.
> > 
> > Ok, the VT_OPENQRY crap is a debian modification to agetty.  As far as
> > I can see, there is no code in agetty which calls sys_vhangup().
> 
> And a further follow-up...

Yes, I was wrong. It was not race with descriptor closing. It was my looking
at agetty which broke things: if you do not watch logout, login prompt
will come up immediately.

Problem is even more stupid: agetty will not come up while you are watching
that terminal. It opens /dev/console so it has some handle on which it
can issue VT_OPENQRY, but if you have /dev/console configured to use just
currently visible tty, it finds itself using that tty (daca4000 is tty3's
tty and da9c4000 is tty2's tty).

Another problem with this is that some daemons do not detach from tty you
start them on - currently vmnet-natd is one I catched (but it was first
daemon I looked at, so there can be other too). So when you do
'/etc/init.d/vmware restart' on some tty, that tty will not come back after
logout until you'll kill vmnet-natd (I'll fix that ASAP).

And third problem is that agetty's loop around VT_OPENQRY has small problem:
When agetty finds that some tty below one it needs is not opened, it opens it.
Later it finds that tty it wants is busy - so it calls error(), but without
closing lower ttys, which are now kept opened during 10 seconds timeout in
agetty's error(). This effectively blocks all lower-numbered agettys from
their terminals until this one succeeds (or until it is stopped by init).

					Best regards,
						Petr Vandrovec
 
/* Watch TTY3 */

init(3062): Opening tty daca4000, use count 1
getty(3062): Opening tty daca4000, use count 2
getty(3062): VT_OPENQRY issued, returning 11
getty(3062): Releasing tty daca4000, use count 2
Call Trace:
 [<c01fe46b>] con_close+0x51/0xce
 [<c01ed85d>] release_dev+0x670/0x684
 [<c0150331>] unmap_page_range+0x3d/0x63
 [<c0165171>] filp_dtor+0x0/0x158
 [<c0155a93>] exit_mmap+0x1d2/0x27f
 [<c01edcef>] tty_release+0x7/0xa
 [<c016550b>] __fput+0xc8/0xd9
 [<c0163c97>] filp_close+0x4f/0x7a
 [<c0121eda>] put_files_struct+0x7c/0xd0
 [<c0123065>] do_exit+0x27a/0x871
 [<c01236e1>] do_group_exit+0x3a/0x1e0
 [<c0129821>] sys_nanosleep+0xa3/0x11d
 [<c0104567>] syscall_call+0x7/0xb

getty(3062): Releasing tty daca4000, use count 1
Call Trace:
 [<c01fe46b>] con_close+0x51/0xce
 [<c01ed85d>] release_dev+0x670/0x684
 [<c0150331>] unmap_page_range+0x3d/0x63
 [<c0165171>] filp_dtor+0x0/0x158
 [<c017dcef>] dput+0x1b/0x5ef
 [<c0155a93>] exit_mmap+0x1d2/0x27f
 [<c01654cc>] __fput+0x89/0xd9
 [<c01edcef>] tty_release+0x7/0xa
 [<c016550b>] __fput+0xc8/0xd9
 [<c0163c97>] filp_close+0x4f/0x7a
 [<c0121eda>] put_files_struct+0x7c/0xd0
 [<c0123065>] do_exit+0x27a/0x871
 [<c01236e1>] do_group_exit+0x3a/0x1e0
 [<c0129821>] sys_nanosleep+0xa3/0x11d
 [<c0104567>] syscall_call+0x7/0xb

/* 10sec delay in agetty, switch to TTY2 */

init(3067): Opening tty da9c4000, use count 2
getty(3067): Opening tty da9c4000, use count 3
getty(3067): VT_OPENQRY issued, returning 3
getty(3067): Releasing tty da9c4000, use count 3
Call Trace:
 [<c01fe46b>] con_close+0x51/0xce
 [<c01ed85d>] release_dev+0x670/0x684
 [<c0174d5a>] permission+0x36/0x38
 [<c016531e>] get_empty_filp+0x55/0xc1
 [<c0119e29>] recalc_task_prio+0x8c/0x19e
 [<c02f7bf2>] schedule+0x356/0x6c6
 [<c01edcef>] tty_release+0x7/0xa
 [<c016550b>] __fput+0xc8/0xd9
 [<c0163c97>] filp_close+0x4f/0x7a
 [<c0104567>] syscall_call+0x7/0xb

getty(3067): Releasing tty da9c4000, use count 2
Call Trace:
 [<c01fe46b>] con_close+0x51/0xce
 [<c01ed85d>] release_dev+0x670/0x684
 [<c0174d5a>] permission+0x36/0x38
 [<c0119e29>] recalc_task_prio+0x8c/0x19e
 [<c02f7bf2>] schedule+0x356/0x6c6
 [<c017dcef>] dput+0x1b/0x5ef
 [<c01654cc>] __fput+0x89/0xd9
 [<c01edcef>] tty_release+0x7/0xa
 [<c016550b>] __fput+0xc8/0xd9
 [<c0163c97>] filp_close+0x4f/0x7a
 [<c0104567>] syscall_call+0x7/0xb

getty(3067): Opening tty daca4000, use count 1

/* Voila, agetty on tty3 came up */

Re: strange delays on console logouts (tty != 1)

[Chris Wedgwood]

On Sun, May 02, 2004 at 11:17:29AM +0100, Russell King wrote:

> The first one is of particular note, because it is the cause of the
> GROSS hack in agetty, which according to the comments is also in
> gdm.

I've emailed the debian util-linux maintainer about this.

> I wonder really if the problem was elsewhere, and if Debian wanted
> to take care of this problem, why they didn't just take the serial
> line locking solution (really: s/serial line/tty/) and apply it to
> agetty / gdm.

It locking really the way to do this?  What's wrong with vhangup?


On Sun, May 02, 2004 at 03:54:24PM +0200, Andries Brouwer wrote:

> However, my agetty source does not contain the string VT_OPENQRY.  I
> suppose this is a private Debian change. Maybe you should contact
> Debian people to find out who did this and why.

Sorry, I used 'apt-get source' to get the source code and completely
forgot about the fact it would patch the package.

> (And/or try the vanilla agetty to see whether the problems go away.)

Vanilla will work as expected.  It still doesn't seem to prevent the
case where someone could terminate and leave a process running that
would take input later on though...  at least not that I can see.


Anyhow, this for not is clearly a userspace issue so sorry about all
the noise people.


   --cw

Re: strange delays on console logouts (tty != 1)

[Russell King]

On Sun, May 02, 2004 at 10:53:26AM -0700, Chris Wedgwood wrote:
> On Sun, May 02, 2004 at 11:17:29AM +0100, Russell King wrote:
> 
> > The first one is of particular note, because it is the cause of the
> > GROSS hack in agetty, which according to the comments is also in
> > gdm.
> 
> I've emailed the debian util-linux maintainer about this.
> 
> > I wonder really if the problem was elsewhere, and if Debian wanted
> > to take care of this problem, why they didn't just take the serial
> > line locking solution (really: s/serial line/tty/) and apply it to
> > agetty / gdm.
> 
> It locking really the way to do this?  What's wrong with vhangup?

As I read the original problem, you have gdm running on what it thought
was a free tty at the time.  agetty starts up and takes control of the
tty.

If you vhangup, what does gdm do...  Hopefully it should restart and
find another tty to use, but I'm not convinced this is a really elegant
solution.

Couple that with the way that agetty is supposed to support "dial-in"
lines (according to the man page), and realise that dial-in means modem
and modems can also dial out, so correct locking with (eg) minicom is
probably a good idea _anyway_.

-- 
Russell King
 Linux kernel    2.6 ARM Linux   - http://www.arm.linux.org.uk/
 maintainer of:  2.6 PCMCIA      - http://pcmcia.arm.linux.org.uk/
                 2.6 Serial core

Re: strange delays on console logouts (tty != 1)

[Chris Wedgwood]

On Sun, May 02, 2004 at 07:01:15PM +0100, Russell King wrote:

> As I read the original problem, you have gdm running on what it
> thought was a free tty at the time.  agetty starts up and takes
> control of the tty.

Heh, I wasn't thinking about gdm, I was thinking more about rogue
programs keeping the tty open after the user has gone.

On Sun, May 02, 2004 at 07:04:25PM +0100, Russell King wrote:

> Oh, and also on this note, vhangup may be a good idea just before
> displaying the issue message.

I was more concerned about security issues with an evil program
hanging out.  Since login is actually where the password is read and
it does use vhangup, then we don't need to worry.

So yes, using tty locking would seem the the sensible solution.


   --cw

Re: strange delays on console logouts (tty != 1)

[Russell King]

On Sun, May 02, 2004 at 10:53:26AM -0700, Chris Wedgwood wrote:
> It locking really the way to do this?  What's wrong with vhangup?

Oh, and also on this note, vhangup may be a good idea just before
displaying the issue message.  However, please note that vhangup
without the correct termios settings will drop DTR, which can
hang up a connected modem.

See login(8) for an example how to do this properly.

-- 
Russell King
 Linux kernel    2.6 ARM Linux   - http://www.arm.linux.org.uk/
 maintainer of:  2.6 PCMCIA      - http://pcmcia.arm.linux.org.uk/
                 2.6 Serial core

Re: strange delays on console logouts (tty != 1)

[Chris Wedgwood]

On Fri, Apr 30, 2004 at 09:53:51PM +0200, Jorge Bernal wrote:

> On tty's != 1 it takes a long time (~20-30 secs) from logout to next
> login but on tty1 it takes a normal time.

Can you check your logs and see if getty is complaining about the tty
being already in use?

or perhaps try something like (not actually tested in this form):

   for i in `seq 1 1000` ; do \
       echo before > /dev/tty7 ; \
       strace -ttogetty-trace.$i getty 38400 tty7 linux ; \
       echo after > /dev/tty7 ; \
   done

switch to tty7 (or whatever you use, make sure nothing else like is
using it --- that means comment out of inittab) and then see if you
see delays between the 'before' and the actually logic prompt --- or
as I see in some cases the getty exist without printing anything.

If this is the case for you then I'll have a quick poke at why getty
things the tty is in use (which is what is apparently causing it
here).

Please let me know what getty (version, etc) you are using and what
distro and other relevant things as it might be a bug specific to some
distro's and not others as few people have reported this.



Thanks,

  --cw

Re: strange delays on console logouts (tty != 1)

[Jorge Bernal]

On Sat, May 01, 2004 at 03:20:40PM -0700, Chris Wedgwood wrote:
> On Fri, Apr 30, 2004 at 09:53:51PM +0200, Jorge Bernal wrote:
> or perhaps try something like (not actually tested in this form):
> 
>    for i in `seq 1 1000` ; do \
>        echo before > /dev/tty7 ; \
>        strace -ttogetty-trace.$i getty 38400 tty7 linux ; \
>        echo after > /dev/tty7 ; \
>    done
> 

[02:11]~$ logout
after
before
after
before

Debian GNU/Linux testing/unstable tuxland.amedias.org tty9

tuxland.amedias.org login: koke
Password:
Last login: Sun May  2 02:11:06 2004 on tty9
Linux tuxland.amedias.org 2.6.5 #2 Sun Apr 11 14:20:11 CEST 2004 i686
GNU/Linux
No mail.

[02:11]~$ logout
after
before
after
before
after
before
after
before
after
before
after
before
after
before

...
And after 8 after/befores, the login appears again. The delay is after
the "before".

In the strace logs I can see a lot of alarms() and read(3,...). Note: fd
3 corresponds to /var/run/utmp

A bit of the log
02:11:08.850311 alarm(1)                = 0
02:11:08.850345 fcntl64(3, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET,
start=0, len=0}) = 0
02:11:08.850386 read(3,
"\7\0\0\0\7\2\0\0tty9\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 384) = 384
02:11:08.850442 fcntl64(3, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET,
start=0, len=0}) = 0


> Please let me know what getty (version, etc) you are using and what
> distro and other relevant things as it might be a bug specific to some
> distro's and not others as few people have reported this.
> 

I don't know where to look at the getty version, but I'm using Debian
Sid with util-linux=2.12-6 (the package which contains getty)

Something curious: I have just discovered that:
tuxland:~/gettylog# ps aux | grep tty9
root       998  0.0  0.1  2080  712 tty4     R    02:25   0:00 grep tty9
tuxland:~/gettylog# last | head
koke     tty9                          Sun May  2 02:24    gone - no logout
koke     tty9                          Sun May  2 02:11 - 02:24  (00:12)
[...]


> 
> 
> Thanks,
> 
>   --cw
> 

-- 
"Sólo el éxito diferencia al genio del loco"

Blog: http://www.amedias.org/koke
Web Personal: http://sindominio.net/~koke/
JID: koke@zgzjabber.ath.cx