Got an issue with PPPD on one of our system, we have a PC that is used to talk to remote sites via a dial up connection, the modem can both connect out to the sites and the sites also dial back in. Currently I'm having an issue where some times a site ether dials in or we dial out, and it connects, but then blocks the modem and throws and error to kern.log.
Aug 26 14:23:57 TM-SCADA kernel: [191233.503745] INFO: task pppd:8142 blocked for more than 120 seconds.
Aug 26 14:23:57 TM-SCADA kernel: [191233.503750] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug 26 14:23:57 TM-SCADA kernel: [191233.503753] pppd D ffffffff8180cb40 0 8142 1 0x00000000
Aug 26 14:23:57 TM-SCADA kernel: [191233.503759] ffff8800ac1f5dc8 0000000000000086 ffff8800ac1f5fd8 00000000000137c0
Aug 26 14:23:57 TM-SCADA kernel: [191233.503765] ffff8800ac1f4010 00000000000137c0 00000000000137c0 00000000000137c0
Aug 26 14:23:57 TM-SCADA kernel: [191233.503770] ffff8800ac1f5fd8 00000000000137c0 ffffffff81c13020 ffff880135df5b80
Aug 26 14:23:57 TM-SCADA kernel: [191233.503775] Call Trace:
Aug 26 14:23:57 TM-SCADA kernel: [191233.503784] [<ffffffff8166ba29>] schedule+0x29/0x70
Aug 26 14:23:57 TM-SCADA kernel: [191233.503790] [<ffffffff813db005>] tty_ldisc_ref_wait+0x65/0xb0
Aug 26 14:23:57 TM-SCADA kernel: [191233.503796] [<ffffffff813f3061>] ? uart_ioctl+0xd1/0x1c0
Aug 26 14:23:57 TM-SCADA kernel: [191233.503801] [<ffffffff81076960>] ? wake_up_bit+0x40/0x40
Aug 26 14:23:57 TM-SCADA kernel: [191233.503806] [<ffffffff813d3fa0>] tty_ioctl+0x2c0/0x9a0
Aug 26 14:23:57 TM-SCADA kernel: [191233.503810] [<ffffffff811d0549>] ? fcntl_setlk+0x69/0x200
Aug 26 14:23:57 TM-SCADA kernel: [191233.503815] [<ffffffff81195f79>] do_vfs_ioctl+0x99/0x330
Aug 26 14:23:57 TM-SCADA kernel: [191233.503820] [<ffffffff81195212>] ? do_fcntl+0x232/0x410
Aug 26 14:23:57 TM-SCADA kernel: [191233.503823] [<ffffffff811962b1>] sys_ioctl+0xa1/0xb0
Aug 26 14:23:57 TM-SCADA kernel: [191233.503829] [<ffffffff81674e69>] system_call_fastpath+0x16/0x1b
The syslog trace stops at "Serial connection established".
Aug 28 06:00:03 TM-SCADA pppd[10358]: pppd 2.4.5 started by root, uid 0
Aug 28 06:00:04 TM-SCADA chat[10360]: abort on (NO CARRIER)
Aug 28 06:00:04 TM-SCADA chat[10360]: abort on (NO DIALTONE)
Aug 28 06:00:04 TM-SCADA chat[10360]: abort on (ERROR)
Aug 28 06:00:04 TM-SCADA chat[10360]: abort on (NO ANSWER)
Aug 28 06:00:04 TM-SCADA chat[10360]: abort on (BUSY)
Aug 28 06:00:04 TM-SCADA chat[10360]: abort on (Username/Password Incorrect)
Aug 28 06:00:04 TM-SCADA chat[10360]: send (atz^M)
Aug 28 06:00:04 TM-SCADA chat[10360]: expect (OK)
Aug 28 06:00:04 TM-SCADA chat[10360]: atz^M^M
Aug 28 06:00:04 TM-SCADA chat[10360]: OK
Aug 28 06:00:04 TM-SCADA chat[10360]: -- got it
Aug 28 06:00:04 TM-SCADA chat[10360]: send (atx0^M)
Aug 28 06:00:04 TM-SCADA chat[10360]: expect (OK)
Aug 28 06:00:04 TM-SCADA chat[10360]: ^M
Aug 28 06:00:04 TM-SCADA chat[10360]: atx0^M^M
Aug 28 06:00:04 TM-SCADA chat[10360]: OK
Aug 28 06:00:04 TM-SCADA chat[10360]: -- got it
Aug 28 06:00:04 TM-SCADA chat[10360]: send (atdt0123456789^M)
Aug 28 06:00:04 TM-SCADA chat[10360]: expect (CONNECT/ARQ)
Aug 28 06:00:04 TM-SCADA chat[10360]: ^M
Aug 28 06:00:30 TM-SCADA chat[10360]: atdt0123456789^M^M
Aug 28 06:00:30 TM-SCADA chat[10360]: CONNECT/ARQ
Aug 28 06:00:30 TM-SCADA chat[10360]: -- got it
Aug 28 06:00:30 TM-SCADA pppd[10358]: Serial connection established.
I've only found two ways to release the modem in this condition, the first is to turn the modem off and on again, the second is to delete the serial lock file, and then SIGKILL pppd. Now I could write into our software to do the latter if the modem is locked, but I would rather stop it from locking in the first place if at all possible. The reason I put this issue in the askubuntu is because we used to use OpenSuse and never had an issue with it, admittedly that was version 11.2 or earlier so its still and old kernel, but I figured I would ask here first anyway.
Any suggestions of places to look would be appreciated.