Hi,
I've been stress testing ARC Linux 3.8 (same happens for 3.9-rc3 as well). The
setup has 3 telnet sessions, each running find . -name "*" in a loop.
The platform is a FPGA @ 80 MHz, running a single core ARC700 so kernel .config
has !SMP and PREEMPT_NONE.
After ~10 mins of run, I see that one of the telnet session gets stuck (and later
the 2nd one as well), while system is still alive, 3rd telnet is running find merrily.
[ARCLinux]$ ps
....
7 root 0:00 inetd
62 root 0:00 -/bin/sh
64 root 1:34 telnetd -i -l /bin/sh
65 root 0:00 /bin/sh
75 root 1:47 telnetd -i -l /bin/sh
76 root 0:00 /bin/sh
79 root 0:53 telnetd -i -l /bin/sh
80 root 0:00 /bin/sh
281 root 0:00 find / -name * <--- stuck
358 root 0:03 find / -name * <--- stuck
377 root 0:00 find / -name *
378 root 0:00 ps
Hung find task is sitting in the schedule() call in n_tty_write()
[ARCLinux]$ cat /proc/281/stack
[<8065945e>] n_tty_write+0x23a/0x424
[<80655cd4>] tty_write+0x1ac/0x2d4
[<805976ba>] vfs_write+0x92/0x110
[<80597816>] sys_write+0x4e/0x88
[<8050e780>] ret_from_system_call+0x0/0x4
This task never resumes out of schedule() - verified by putting a hardware
breakpoint on next insn - using a JTAG host debugger.
Attached are .config, /proc/281/sched, /proc/schedstat, /proc/sched_debug
My knowledge of schedular is close to none, hence any tips to debug this further
would be much appreciated.
TIA,
-Vineet
Hi,
Any thoughts: I observe the same issue even with CONFIG_PREEMPT and
CONFIG_PREEMPT_COUNT
-Vineet
On 03/30/2013 06:05 PM, Vineet Gupta wrote:
> Hi,
>
> I've been stress testing ARC Linux 3.8 (same happens for 3.9-rc3 as well). The
> setup has 3 telnet sessions, each running find . -name "*" in a loop.
> The platform is a FPGA @ 80 MHz, running a single core ARC700 so kernel .config
> has !SMP and PREEMPT_NONE.
>
> After ~10 mins of run, I see that one of the telnet session gets stuck (and later
> the 2nd one as well), while system is still alive, 3rd telnet is running find merrily.
>
> [ARCLinux]$ ps
> ....
> 7 root 0:00 inetd
> 62 root 0:00 -/bin/sh
> 64 root 1:34 telnetd -i -l /bin/sh
> 65 root 0:00 /bin/sh
> 75 root 1:47 telnetd -i -l /bin/sh
> 76 root 0:00 /bin/sh
> 79 root 0:53 telnetd -i -l /bin/sh
> 80 root 0:00 /bin/sh
> 281 root 0:00 find / -name * <--- stuck
> 358 root 0:03 find / -name * <--- stuck
> 377 root 0:00 find / -name *
> 378 root 0:00 ps
>
> Hung find task is sitting in the schedule() call in n_tty_write()
>
> [ARCLinux]$ cat /proc/281/stack
> [<8065945e>] n_tty_write+0x23a/0x424
> [<80655cd4>] tty_write+0x1ac/0x2d4
> [<805976ba>] vfs_write+0x92/0x110
> [<80597816>] sys_write+0x4e/0x88
> [<8050e780>] ret_from_system_call+0x0/0x4
>
> This task never resumes out of schedule() - verified by putting a hardware
> breakpoint on next insn - using a JTAG host debugger.
>
> Attached are .config, /proc/281/sched, /proc/schedstat, /proc/sched_debug
>
> My knowledge of schedular is close to none, hence any tips to debug this further
> would be much appreciated.
>
>
> TIA,
> -Vineet
>
On Mon, 2013-04-01 at 19:27 +0530, Vineet Gupta wrote:
> Hi,
>
> Any thoughts: I observe the same issue even with CONFIG_PREEMPT and
> CONFIG_PREEMPT_COUNT
>
> -Vineet
>
> On 03/30/2013 06:05 PM, Vineet Gupta wrote:
> > Hi,
> >
> > I've been stress testing ARC Linux 3.8 (same happens for 3.9-rc3 as well). The
> > setup has 3 telnet sessions, each running find . -name "*" in a loop.
> > The platform is a FPGA @ 80 MHz, running a single core ARC700 so kernel .config
> > has !SMP and PREEMPT_NONE.
> >
> > After ~10 mins of run, I see that one of the telnet session gets stuck (and later
> > the 2nd one as well), while system is still alive, 3rd telnet is running find merrily.
> >
> > [ARCLinux]$ ps
> > ....
> > 7 root 0:00 inetd
> > 62 root 0:00 -/bin/sh
> > 64 root 1:34 telnetd -i -l /bin/sh
> > 65 root 0:00 /bin/sh
> > 75 root 1:47 telnetd -i -l /bin/sh
> > 76 root 0:00 /bin/sh
> > 79 root 0:53 telnetd -i -l /bin/sh
> > 80 root 0:00 /bin/sh
> > 281 root 0:00 find / -name * <--- stuck
> > 358 root 0:03 find / -name * <--- stuck
> > 377 root 0:00 find / -name *
> > 378 root 0:00 ps
> >
> > Hung find task is sitting in the schedule() call in n_tty_write()
> >
> > [ARCLinux]$ cat /proc/281/stack
> > [<8065945e>] n_tty_write+0x23a/0x424
> > [<80655cd4>] tty_write+0x1ac/0x2d4
> > [<805976ba>] vfs_write+0x92/0x110
> > [<80597816>] sys_write+0x4e/0x88
> > [<8050e780>] ret_from_system_call+0x0/0x4
Likely the writer is stuck because the receive buffer is full and the
reader is hung. What are the respective shells and telnetd doing?
Regards,
Peter Hurley
PS - include the controlling tty column in your ps output :)
Hi Peter,
On 04/01/2013 08:40 PM, Peter Hurley wrote:
> On Mon, 2013-04-01 at 19:27 +0530, Vineet Gupta wrote:
>> Hi,
>>
>> Any thoughts: I observe the same issue even with CONFIG_PREEMPT and
>> CONFIG_PREEMPT_COUNT
>>
>> -Vineet
>>
>> On 03/30/2013 06:05 PM, Vineet Gupta wrote:
>>> Hi,
>>>
>>> I've been stress testing ARC Linux 3.8 (same happens for 3.9-rc3 as well). The
>>> setup has 3 telnet sessions, each running find . -name "*" in a loop.
>>> The platform is a FPGA @ 80 MHz, running a single core ARC700 so kernel .config
>>> has !SMP and PREEMPT_NONE.
>>>
>>> After ~10 mins of run, I see that one of the telnet session gets stuck (and later
>>> the 2nd one as well), while system is still alive, 3rd telnet is running find merrily.
>>>
>>> [ARCLinux]$ ps
>>> ....
>>> 7 root 0:00 inetd
>>> 62 root 0:00 -/bin/sh
>>> 64 root 1:34 telnetd -i -l /bin/sh
>>> 65 root 0:00 /bin/sh
>>> 75 root 1:47 telnetd -i -l /bin/sh
>>> 76 root 0:00 /bin/sh
>>> 79 root 0:53 telnetd -i -l /bin/sh
>>> 80 root 0:00 /bin/sh
>>> 281 root 0:00 find / -name * <--- stuck
>>> 358 root 0:03 find / -name * <--- stuck
>>> 377 root 0:00 find / -name *
>>> 378 root 0:00 ps
>>>
>>> Hung find task is sitting in the schedule() call in n_tty_write()
>>>
>>> [ARCLinux]$ cat /proc/281/stack
>>> [<8065945e>] n_tty_write+0x23a/0x424
>>> [<80655cd4>] tty_write+0x1ac/0x2d4
>>> [<805976ba>] vfs_write+0x92/0x110
>>> [<80597816>] sys_write+0x4e/0x88
>>> [<8050e780>] ret_from_system_call+0x0/0x4
> Likely the writer is stuck because the receive buffer is full and the
> reader is hung. What are the respective shells and telnetd doing?
telnetd is in select syscall - waiting for new connections ?
shell is wait(2)ing - likely on the child "find" task.
/ # cat /proc/62/stack
[<8059e26a>] do_select+0x4b6/0x59c
[<8059e4f8>] core_sys_select+0x1a8/0x690
[<8059ea74>] sys_pselect6+0x94/0x254
[<80505fb4>] ret_from_system_call+0x0/0x4
/ # cat /proc/63/stack
[<80513a4a>] do_wait+0x166/0x188
[<80513ace>] sys_wait4+0x62/0xac
[<80505fb4>] ret_from_system_call+0x0/0x4
/ # cat /proc/445/stack
[<8064c7f2>] n_tty_write+0x23a/0x424
[<80649038>] tty_write+0x1a0/0x2b4
[<8058a4b6>] vfs_write+0x92/0x110
[<8058a612>] sys_write+0x4e/0x88
[<80505fb4>] ret_from_system_call+0x0/0x4
> PS - include the controlling tty column in your ps output :)
S UID PID PPID VSZ RSS TTY STIME TIME CMD
S 0 62 47 1768 488 0:0 16:01 00:01:44 telnetd -i -l /bin/sh
S 0 63 62 1768 512 pts2 16:01 00:00:00 /bin/sh
S 0 445 63 1840 488 pts2 16:30 00:00:00 find / -name *
Thx,
-Vineet
On 04/01/2013 08:40 PM, Peter Hurley wrote:
> On Mon, 2013-04-01 at 19:27 +0530, Vineet Gupta wrote:
>> Hi,
>>
>> Any thoughts: I observe the same issue even with CONFIG_PREEMPT and
>> CONFIG_PREEMPT_COUNT
>>
>> -Vineet
>>
>> On 03/30/2013 06:05 PM, Vineet Gupta wrote:
>>> Hi,
>>>
>>> I've been stress testing ARC Linux 3.8 (same happens for 3.9-rc3 as well). The
>>> setup has 3 telnet sessions, each running find . -name "*" in a loop.
>>> The platform is a FPGA @ 80 MHz, running a single core ARC700 so kernel .config
>>> has !SMP and PREEMPT_NONE.
>>>
>>> After ~10 mins of run, I see that one of the telnet session gets stuck (and later
>>> the 2nd one as well), while system is still alive, 3rd telnet is running find merrily.
>>>
>>> [ARCLinux]$ ps
>>> ....
>>> 7 root 0:00 inetd
>>> 62 root 0:00 -/bin/sh
>>> 64 root 1:34 telnetd -i -l /bin/sh
>>> 65 root 0:00 /bin/sh
>>> 75 root 1:47 telnetd -i -l /bin/sh
>>> 76 root 0:00 /bin/sh
>>> 79 root 0:53 telnetd -i -l /bin/sh
>>> 80 root 0:00 /bin/sh
>>> 281 root 0:00 find / -name * <--- stuck
>>> 358 root 0:03 find / -name * <--- stuck
>>> 377 root 0:00 find / -name *
>>> 378 root 0:00 ps
>>>
>>> Hung find task is sitting in the schedule() call in n_tty_write()
>>>
>>> [ARCLinux]$ cat /proc/281/stack
>>> [<8065945e>] n_tty_write+0x23a/0x424
>>> [<80655cd4>] tty_write+0x1ac/0x2d4
>>> [<805976ba>] vfs_write+0x92/0x110
>>> [<80597816>] sys_write+0x4e/0x88
>>> [<8050e780>] ret_from_system_call+0x0/0x4
> Likely the writer is stuck because the receive buffer is full and the
> reader is hung. What are the respective shells and telnetd doing?
I've added a couple of printk's around that schedule() call and in one pathetic
case all 3 find tasks never return:
S 0 58 47 1768 488 0:0 00:00 00:03:50 telnetd -i -l /bin/sh
S 0 59 58 1768 520 pts0 00:00 00:00:01 /bin/sh
S 0 61 47 1768 488 0:0 00:00 00:03:45 telnetd -i -l /bin/sh
S 0 62 61 1768 528 pts1 00:00 00:00:01 /bin/sh
S 0 65 47 1768 488 0:0 00:00 00:03:23 telnetd -i -l /bin/sh
S 0 66 65 1776 528 pts2 00:00 00:00:01 /bin/sh
S 0 833 66 1840 488 pts2 00:58 00:00:01 find / -name * <--
S 0 871 62 1832 480 pts1 01:01 00:00:00 find / -name * <--
S 0 881 59 1840 488 pts0 01:01 00:00:02 find / -name * <--
---> 833 8e21c580
<--- 833 8e21c580
---> 833 8e21c580
---> 871 8e21c840
<--- 871 8e21c840
---> 871 8e21c840
---> 881 8e21c2c0
<--- 881 8e21c2c0
---> 881 8e21c2c0
I don't undersand how the receive buffer full/empty is coming into play - that
schedule() call is not a wait queue or something, it's an unconditional yield,
expecting sched to unconditionally return at some point - unless ofcourse - that
itself relies on some buffer r/w ISR semantics triggering an ISR, which makes the
task runnable again causing schdule() to return.
-Vineet
On Tue, 2013-04-02 at 18:56 +0530, Vineet Gupta wrote:
> On 04/01/2013 08:40 PM, Peter Hurley wrote:
> > On Mon, 2013-04-01 at 19:27 +0530, Vineet Gupta wrote:
> >> On 03/30/2013 06:05 PM, Vineet Gupta wrote:
> >>> Hung find task is sitting in the schedule() call in n_tty_write()
> >>>
> >>> [ARCLinux]$ cat /proc/281/stack
> >>> [<8065945e>] n_tty_write+0x23a/0x424
> >>> [<80655cd4>] tty_write+0x1ac/0x2d4
> >>> [<805976ba>] vfs_write+0x92/0x110
> >>> [<80597816>] sys_write+0x4e/0x88
> >>> [<8050e780>] ret_from_system_call+0x0/0x4
> > Likely the writer is stuck because the receive buffer is full and the
> > reader is hung. What are the respective shells and telnetd doing?
>
> I don't undersand how the receive buffer full/empty is coming into play - that
> schedule() call is not a wait queue or something
If n_tty_write() blocks [the schedule() call], then it is on a wait
queue (tty->write_wait) which is woken by pty's unthrottle() called from
n_tty_read from the linked pty when space becomes available in the
receive buffer.
Please, try this patch maybe it can help localize your problem.
drivers/tty/n_tty.c | 1 +
1 file changed, 1 insertion(+)
diff --git a/drivers/tty/n_tty.c b/drivers/tty/n_tty.c
index 05e72be..28f15d0 100644
--- a/drivers/tty/n_tty.c
+++ b/drivers/tty/n_tty.c
@@ -230,6 +230,7 @@ static void reset_buffer_flags(struct tty_struct *tty)
ldata->canon_head = ldata->canon_data = ldata->erasing = 0;
bitmap_zero(ldata->read_flags, N_TTY_BUF_SIZE);
n_tty_set_room(tty);
+ check_unthrottle(tty);
}
/**
Hi Ilya
On 04/03/2013 11:14 AM, Ilya Zykov wrote:
> Please, try this patch maybe it can help localize your problem.
>
> drivers/tty/n_tty.c | 1 +
> 1 file changed, 1 insertion(+)
>
> diff --git a/drivers/tty/n_tty.c b/drivers/tty/n_tty.c
> index 05e72be..28f15d0 100644
> --- a/drivers/tty/n_tty.c
> +++ b/drivers/tty/n_tty.c
> @@ -230,6 +230,7 @@ static void reset_buffer_flags(struct tty_struct *tty)
> ldata->canon_head = ldata->canon_data = ldata->erasing = 0;
> bitmap_zero(ldata->read_flags, N_TTY_BUF_SIZE);
> n_tty_set_room(tty);
> + check_unthrottle(tty);
> }
>
> /**
Thanks for the patch - but it didn't help at all - I see the same lockup.
I'm no tty expert so don't understand how this patch would help - care to elaborate ?
Thx,
-Vineet
[ --cc Ingo and Peter Z. as this is not scheduler-related]
On Tue, 2013-04-02 at 18:56 +0530, Vineet Gupta wrote:
> On 04/01/2013 08:40 PM, Peter Hurley wrote:
> > On Mon, 2013-04-01 at 19:27 +0530, Vineet Gupta wrote:
> >> Hi,
> >>
> >> Any thoughts: I observe the same issue even with CONFIG_PREEMPT and
> >> CONFIG_PREEMPT_COUNT
I'll see if I can reproduce this over the weekend on an old single-core
laptop I still have.
There were some race conditions in the N_TTY line discipline which I
recently fixed. Those changes are in linux-next. Can you test if this is
reproducible on linux-next?
Assuming I don't reproduce this on the laptop, the only other
explanation I can think of right now is that ARCLinux is not properly
handling signal-driven i/o (assuming the BusyBox /bin/sh uses SIGIO). Do
you know if there is anything special about the way ARCLinux handle
signals?
Regards,
Peter Hurley
On 04/06/2013 01:22 AM, Peter Hurley wrote:
> I'll see if I can reproduce this over the weekend on an old single-core laptop I
> still have.
TIA for doing this.
> There were some race conditions in the N_TTY line discipline which I
> recently fixed. Those changes are in linux-next. Can you test if this is
> reproducible on linux-next?
I tried today's -next and I see the same issue :-(
> Assuming I don't reproduce this on the laptop, the only other
> explanation I can think of right now is that ARCLinux is not properly
> handling signal-driven i/o (assuming the BusyBox /bin/sh uses SIGIO). Do
> you know if there is anything special about the way ARCLinux handle
> signals?
No, it's pretty standard stuff - we are uClibc based though - as opposed to glibc
so there might be some subtleties - but we do run LTP open posix regularly. Also
the test setup is a slowish 80MHz FPGA so this is not something many people have
in their regular test setups.
I'll start reading the relevant code myself - and will be willing to take any
debug/test patches which help with troubleshooting of this issue.
Just to re-iterate, my test setup has a minimal busybox based rootfs, 3 telnet
sessions, each running a
while true; do find / -name "*" ; done
I'm running out of ramfs, no external disk/nfs mounts to reduce the peripheral I/O
slowing down the find (although NFS stuff will be caches anyways after first fetch).
Also please make sure you have CONFIG_PREEMPT_COUNT otherwise there's a
possibility (atleast on ARC builds) that a stale register causes timer list to be
corrupted in mod_timer().
Thx,
-Vineet