Re: PROBLEM: PPP and other serial port related application hangs in kernel space

From: Ales Teska
Date: Thu Jun 10 2010 - 20:05:06 EST


Here is a stack from 2.6.34 with few debugging options on:

# cat /proc/1390/stack
[<c10f79fb>] tty_ldisc_ref_wait+0x5d/0x75
[<c10f3c54>] tty_ioctl+0x6d1/0x731
[<c1077e6c>] vfs_ioctl+0x22/0x86
[<c10783ba>] do_vfs_ioctl+0x45a/0x4a5
[<c1078431>] sys_ioctl+0x2c/0x45
[<c1198e65>] syscall_call+0x7/0xb
[<ffffffff>] 0xffffffff

[ 841.121579] INFO: task pppd:1390 blocked for more than 120 seconds.
[ 841.122613] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 841.123578] pppd D cec53ea4 0 1390 1139 0x00000000
[ 841.126502] cec53ebc 00000046 c1037b30 cec53ea4 c1198bf6 cec29070 cec291f8 cfdbc520
[ 841.134781] c10f7049 cec53ebc 00000000 cec51800 cec53ec4 cec53ee4 c10f79fb 00000000
[ 841.143007] cec29070 c102b471 c13dc904 c13dc904 d0c35211 cefc6aa0 cec51800 cec53f1c
[ 841.151250] Call Trace:
[ 841.151815] [<c1037b30>] ? trace_hardirqs_on+0xb/0xd
[ 841.152755] [<c1198bf6>] ? _raw_spin_unlock_irqrestore+0x53/0x60
[ 841.153657] [<c10f7049>] ? spin_unlock_irqrestore+0x8/0xa
[ 841.154601] [<c10f79fb>] tty_ldisc_ref_wait+0x5d/0x75
[ 841.155265] [<c102b471>] ? autoremove_wake_function+0x0/0x33
[ 841.156456] [<d0c35211>] ? serial_ioctl+0x0/0x68 [usbserial]
[ 841.157913] [<c10f3c54>] tty_ioctl+0x6d1/0x731
[ 841.158834] [<c102fa77>] ? sched_clock_cpu+0xac/0xbc
[ 841.159658] [<c10f3583>] ? tty_ioctl+0x0/0x731
[ 841.160922] [<c1077e6c>] vfs_ioctl+0x22/0x86
[ 841.161836] [<c10783ba>] do_vfs_ioctl+0x45a/0x4a5
[ 841.162746] [<c1036a5e>] ? put_lock_stats+0xd/0x21
[ 841.163699] [<c1036ac6>] ? lock_release_holdtime+0x54/0x5a
[ 841.164530] [<c100fd87>] ? do_page_fault+0x27c/0x285
[ 841.165898] [<c102e978>] ? up_read+0x16/0x28
[ 841.166820] [<c1078431>] sys_ioctl+0x2c/0x45
[ 841.167452] [<c1198e65>] syscall_call+0x7/0xb
[ 841.168403] no locks held by pppd/1390.

... strangely now I'm getting different message in the dmesg output (and actually +120 seconds from incident).
Ratio of hangs is now higher with this build ...

I will do a test with CONFIG_LOCKDEP & CONFIG_TTY_MUTEX options over the weekend.

Ales

On 9 Jun 2010, at 23:16 , arnd@xxxxxxxx wrote:

> On Wednesday 09 June 2010 22:46:28 Ales Teska wrote:
>> after upgrade of Linux kernel to version 2.6.34 I started to observe following problem
>> - ppp and other serial port related application occasionally (in 1 hour or 1/10 ppp
>> connections) 'hangs' (see description bellow) rendering related serial device unusable.
>> I backtracked this issue to 2.6.32.15.
>> Application remains in the condition marked as 'D' in 'ps' output (waiting for result
>> from kernel space, if I understand that correctly); it stays in this condition forever.
>
> It would be good to find out where exactly the application hangs. Please try a sysrq-t
> (press Alt+SysRq+t simultaneously) or cat /proc/<pid-that-hangs>/stack.
>
> It might also be helpful to try running the kernel with CONFIG_LOCKDEP and/or
> CONFIG_TTY_MUTEX enabled. For the latter one, you need to get the source
> from the tty branch of git://git.kernel.org/pub/scm/linux/kernel/git/arnd/bkl.git
>
>> I also found following information in dmesg:
>> [ 1673.660876] ------------[ cut here ]------------
>> [ 1673.661471] WARNING: at drivers/char/tty_io.c:1278 tty_open+0x213/0x451()
>> [ 1673.662358] Modules linked in: ppp_deflate zlib_deflate bsd_comp ppp_async crc_ccitt ppp_generic slhc ipv6 nvram msr cpuid ledtrig_timer ledtrig_heartbeat ledtrig_default_on geodewdt lm90 hwmon scx200_acb option usbserial ehci_hcd ohci_hcd via_rhine usbcore leds_alix2 mii
>> [ 1673.689168] Pid: 1275, comm: ufoprobe_client Not tainted 2.6.34-486-exiprobes #1
>> [ 1673.690452] Call Trace:
>> [ 1673.690947] [<c10e93af>] ? tty_open+0x213/0x451
>> [ 1673.691926] [<c1018f51>] warn_slowpath_common+0x45/0x5c
>> [ 1673.693006] [<c1018f75>] warn_slowpath_null+0xd/0x10
>> [ 1673.694293] [<c10e93af>] tty_open+0x213/0x451
>> [ 1673.694755] [<c1068105>] chrdev_open+0xe3/0x126
>
> Do you always see this message exactly once before it hangs?
>
> Arnd

Attachment: smime.p7s
Description: S/MIME cryptographic signature