[clue-tech] Troubleshooting ppp.

[Jim Ockers]

Hi Dave,

Ha ha sorry for the delay I was out playing volleyball. :) Yes I have 
gotten to be quite the PPP debugger over the last 15 years.

David L. Anselmi wrote:
> Anyone know how to troubleshoot ppp (Jim Ockers)?
>
> I have a machine using ppp.  After an upgrade ppp disconnects almost immediately (log below). 
> Except for the length of connection the log looks the same as a successful session.
>
> I did do some upgrades a few days after the previous successful session.  Relevant changes seem to be:
>
> - lrzsz (shouldn't be using any *modem protocol for this connection)
>
> - libpcap and netbase (dependecies of Debian's ppp package)
>
> There aren't any bugs that seem relevant and ppp itself did not get upgraded.
>
> This happens to be using Juno's service, how do I tell whether something has changed on their end?
>
> Jan 24 17:12:03 rocket pppd[1856]: pppd 2.4.4 started by root, uid 0
> Jan 24 17:12:04 rocket chat[1858]: abort on (ERROR)
> Jan 24 17:12:04 rocket chat[1858]: abort on (BUSY)
> Jan 24 17:12:04 rocket chat[1858]: abort on (NO CARRIER)
> Jan 24 17:12:04 rocket chat[1858]: abort on (NO DIALTONE)
> Jan 24 17:12:04 rocket chat[1858]: report (CONNECT)
> Jan 24 17:12:04 rocket chat[1858]: send (ATZ^M)
> Jan 24 17:12:04 rocket chat[1858]: expect (OK)
> Jan 24 17:12:04 rocket chat[1858]: ATZ^M^M
> Jan 24 17:12:04 rocket chat[1858]: OK
> Jan 24 17:12:04 rocket chat[1858]:  -- got it
> Jan 24 17:12:04 rocket chat[1858]: send (ATDT303-357-1145^M)
> Jan 24 17:12:04 rocket chat[1858]: timeout set to 60 seconds
> Jan 24 17:12:04 rocket chat[1858]: expect (CONNECT)
> Jan 24 17:12:04 rocket chat[1858]: ^M
> Jan 24 17:12:35 rocket chat[1858]: ATDT303-357-1145^M^M
> Jan 24 17:12:35 rocket chat[1858]: CONNECT
> Jan 24 17:12:35 rocket chat[1858]:  -- got it
> Jan 24 17:12:35 rocket chat[1858]: send ()
> Jan 24 17:12:35 rocket pppd[1856]: Serial connection established.
> Jan 24 17:12:35 rocket pppd[1856]: Using interface ppp0
> Jan 24 17:12:35 rocket pppd[1856]: Connect: ppp0 <--> /dev/modem
> Jan 24 17:12:37 rocket pppd[1856]: CHAP authentication succeeded:
> Jan 24 17:12:37 rocket pppd[1856]: CHAP authentication succeeded
> Jan 24 17:12:37 rocket kernel: [  614.965250] PPP BSD Compression module registered
> Jan 24 17:12:37 rocket kernel: [  614.991864] PPP Deflate Compression module registered
> Jan 24 17:12:37 rocket pppd[1856]: local  IP address 63.18.32.60
> Jan 24 17:12:37 rocket pppd[1856]: remote IP address 63.3.8.2
> Jan 24 17:12:37 rocket pppd[1856]: primary   DNS address 64.136.52.73
> Jan 24 17:12:37 rocket pppd[1856]: secondary DNS address 64.136.44.73
> Jan 24 17:12:38 rocket pppd[1856]: Terminating on signal 15
> Jan 24 17:12:38 rocket pppd[1856]: Connect time 0.1 minutes.
> Jan 24 17:12:38 rocket pppd[1856]: Sent 240 bytes, received 298 bytes.
> Jan 24 17:12:38 rocket pppd[1856]: Connection terminated.
> Jan 24 17:12:39 rocket pppd[1856]: Exit.
>
> Thanks!
> Dave
> _______________________________________________
> clue-tech mailing list
> clue-tech at cluedenver.org
> http://cluedenver.org/mailman/listinfo/clue-tech
>   

I think your PPP is probably working fine. What is the command line that 
was used to start pppd? Is it running as a child process of some other 
parent process? Is there some way you can make pppd get started by init 
or run it from the command line? (Make sure you use the -detach command 
line option if you start it with init!)

Run "ps -efwww --forest" and then look for pppd, and you will be able to 
see in the "forest" view what its parent and children processes are. I 
think that the logfile above shows a parent process sending pppd a 
SIGTERM. If I knew what the parent process was I could maybe speculate 
about why it sent a sigterm. For instance we have wvdial which spawned 
pppd, and I don't remember what the problem was but I do remember 
troubleshooting one time and finding wvdial was responsible for 
terminating pppd exactly this way.

You could just try running pppd on the command line and not from any 
dialer program and see if it still dies this way. Also you should turn 
on debugging if you haven't already, using the "debug" command line 
option or options file entry. You might need to make sure syslogd is 
sending *.debug to a logfile if you don't seem to be seeing the debug 
messages in the expected place.

Hope this helps,
Jim

-- 
Jim Ockers, P.Eng. (ockers at ockers.net)
Contact info: http://www.ockers.ca/pason.html