Re: mein leidiges ppp Problem

From: Christoph Kukulies <kuku(at)gilberto.physik.rwth-aachen.de>
Date: Sat, 18 Apr 1998 16:47:22 +0200

On Fri, Apr 17, 1998 at 08:23:06PM +0200, J Wunsch wrote:
> As Christoph Kukulies wrote:
>
> > Nur haben wir einen Linux user, der es 'ums Verrecken' nicht schafft,
> > eine Verbindung herzustellen. Ich habe im Moment wieder einen
> > laengeren log in FreeBSD-questions gepostet und Doug White hilft mir
> > auch soweit er kann aber es ist ein Stochern im Nebel.
>
> Beschaff die Logs von beiden Seiten, am besten mit xntp-gesicherten
> Timestamps, so daß man sie gegeneinander vergleichen kann. Poste mal
> die Stellen, wo sie sich nicht treffen, hier.
>
> > Wer betreibt einen dialup server mit FreeBSD und pppd?
>
> sax.sax.de. Bei uns hat sich bislang noch niemand über unlösbare
> Probleme beklagt, und wir haben von DOSen, Windosen, Macs, wohl auch
> Amigas bis hin zu Linux und FreeBSD alles an Clients. Wir benutzen
> zwar pro Host einen speziellen Account, um den pppd anzuwerfen (der
> sich zuvor in einem Perlscript noch die Parameter aus
> /etc/sliphome/slip.hosts holt, so daß wir unabhängig von PPP oder SLIP
> die per-Host-Konfiguration nur an einer Stelle pflegen müssen), aber
> das dürfte ja bei Dir nicht das Problem sein.
>
> Ich kann einigermaßen PPP-Logs lesen (kein Wunder, nachdem ich sppp
> praktisch von Grund auf neugeschrieben habe ;), wenngleich ich mich zu
> erinnern glaube, daß die vom pppd nicht sonderlich schön aussehen.

Peer: Motorola 3400 Pro
Server: Philips 33.6er (Type im Moment nicht zur Hand)

Failing site:
-------------

Problem site: < PPP_FLAGS="57600 mru 1524 modem debug kdebug 4 defaultroute crtscts noipdefault asyncmap 20A0000 escape FF"

Site that works:
----------------

OK-site: PPP_FLAGS="38400 mru 1500 modem debug kdebug 0 defaultroute crtscts noipdefault asyncmap 20A0000 escape FF"

Trial 1: (failing)
--------
Apr 16 13:30:42 testuser-rem kernel: PPP: version 2.2.0 (dynamic channel allocation)
Apr 16 13:30:42 testuser-rem kernel: PPP Dynamic channel allocation code copyright 1995 Caldera, Inc.
Apr 16 13:30:42 testuser-rem kernel: PPP line discipline registered.
Apr 16 13:30:42 testuser-rem kernel: registered device ppp0
Apr 16 13:30:42 testuser-rem syslog: IPX support is not present in the kernel
Apr 16 13:30:42 testuser-rem pppd[302]: pppd 2.2.0 started by root, uid 0
Apr 16 13:30:44 testuser-rem chat[309]: timeout set to 5 seconds
Apr 16 13:30:44 testuser-rem chat[309]: abort on (\nBUSY\r)
Apr 16 13:30:44 testuser-rem chat[309]: abort on (\nNO CARRIER\r)
Apr 16 13:30:44 testuser-rem chat[309]: abort on (\nRING\r\n\r\nRING\r)
Apr 16 13:30:44 testuser-rem chat[309]: abort on (\nNO DIALTONE\r)
Apr 16 13:30:44 testuser-rem chat[309]: abort on (\nERROR\r)
Apr 16 13:30:44 testuser-rem chat[309]: send (+++ATZ^M)
Apr 16 13:30:44 testuser-rem chat[309]: expect (OK)
Apr 16 13:30:44 testuser-rem chat[309]: ATZ^M^M
Apr 16 13:30:44 testuser-rem chat[309]: OK -- got it
Apr 16 13:30:44 testuser-rem chat[309]: send (AT&F0E0^M)
Apr 16 13:30:44 testuser-rem chat[309]: timeout set to 45 seconds
Apr 16 13:30:44 testuser-rem chat[309]: expect (OK)
Apr 16 13:30:44 testuser-rem chat[309]: ^M
Apr 16 13:30:44 testuser-rem chat[309]: AT&F0E0^M^M
Apr 16 13:30:44 testuser-rem chat[309]: OK -- got it
Apr 16 13:30:44 testuser-rem chat[309]: send (ATLXDT0241888888^M)
Apr 16 13:30:45 testuser-rem chat[309]: expect (CONNECT)
Apr 16 13:30:45 testuser-rem chat[309]: ^M
Apr 16 13:31:11 testuser-rem chat[309]: ^M
Apr 16 13:31:11 testuser-rem chat[309]: CONNECT -- got it
Apr 16 13:31:11 testuser-rem chat[309]: send (^M)
Apr 16 13:31:11 testuser-rem chat[309]: timeout set to 10 seconds
Apr 16 13:31:11 testuser-rem chat[309]: expect (ogin:)
Apr 16 13:31:11 testuser-rem chat[309]: ^M
Apr 16 13:31:11 testuser-rem chat[309]: ^M^M
Apr 16 13:31:11 testuser-rem chat[309]: FreeBSD (xxxxxx.yyyyyy.yyyyyy.de) (ttyd0)^M^M
Apr 16 13:31:11 testuser-rem chat[309]: ^M^M
Apr 16 13:31:11 testuser-rem chat[309]: login: -- got it
Apr 16 13:31:11 testuser-rem chat[309]: send (testuser^M)
Apr 16 13:31:11 testuser-rem chat[309]: expect (assword:)
Apr 16 13:31:11 testuser-rem chat[309]: ^M
Apr 16 13:31:11 testuser-rem chat[309]: ^M
Apr 16 13:31:11 testuser-rem chat[309]: ^M^M
Apr 16 13:31:11 testuser-rem chat[309]: FreeBSD (xxxxx.yyyyyy.yyyyyyyyyyy.de) (ttyd0)^M^M
Apr 16 13:31:11 testuser-rem chat[309]: ^M^M
Apr 16 13:31:11 testuser-rem chat[309]: login: testuser^M
Apr 16 13:31:11 testuser-rem chat[309]: Password: -- got it
Apr 16 13:31:11 testuser-rem chat[309]: send (???????^M)
Apr 16 13:31:12 testuser-rem pppd[302]: Serial connection established.
Apr 16 13:31:13 testuser-rem kernel: ppp: write frame, count = 28
Apr 16 13:31:13 testuser-rem kernel: FF 03 C0 21 01 01 00 18 ...!....
Apr 16 13:31:13 testuser-rem kernel: 01 04 05 F4 02 06 02 0A ........
Apr 16 13:31:13 testuser-rem kernel: 00 00 05 06 B9 BE EE 96 ........
Apr 16 13:31:13 testuser-rem kernel: 07 02 08 02 ....
Apr 16 13:31:13 testuser-rem pppd[302]: Using interface ppp0
Apr 16 13:31:13 testuser-rem pppd[302]: Connect: ppp0 <--> /dev/modem
Apr 16 13:31:13 testuser-rem pppd[302]: sent [LCP ConfReq id=0x1 <mru 1524> <asyncmap 0x20a0000> <magic 0xb9beee96> <pcomp> <accomp>]
Apr 16 13:31:13 testuser-rem kernel: ppp: write frame, count = 14
Apr 16 13:31:13 testuser-rem kernel: FF 03 C0 21 03 01 00 0A ...!....
Apr 16 13:31:13 testuser-rem kernel: 05 06 82 7D 2D B3 ...}-.
Apr 16 13:31:13 testuser-rem pppd[302]: rcvd [LCP ConfReq id=0x1 <mru 1524> <asyncmap 0x20a0000> <magic 0xb9beee96> <pcomp> <accomp>]
Apr 16 13:31:13 testuser-rem pppd[302]: sent [LCP ConfNak id=0x1 <magic 0x827d2db3>]
Apr 16 13:31:13 testuser-rem pppd[302]: rcvd [LCP ConfNak id=0x1 <magic 0x827d2db3>]
Apr 16 13:31:13 testuser-rem pppd[302]: sent [LCP ConfReq id=0x2 <mru 1524> <asyncmap 0x20a0000> <magic 0xa955635f> <pcomp> <accomp>]
Apr 16 13:31:13 testuser-rem kernel: ppp: write frame, count = 28
Apr 16 13:31:13 testuser-rem kernel: FF 03 C0 21 01 02 00 18 ...!....
Apr 16 13:31:13 testuser-rem kernel: 01 04 05 F4 02 06 02 0A ........
Apr 16 13:31:13 testuser-rem kernel: 00 00 05 06 A9 55 63 5F .....Uc_
Apr 16 13:31:13 testuser-rem kernel: 07 02 08 02 ....
Apr 16 13:31:14 testuser-rem kernel: ppp: write frame, count = 14
Apr 16 13:31:14 testuser-rem kernel: FF 03 C0 21 03 02 00 0A ...!....
Apr 16 13:31:14 testuser-rem kernel: 05 06 C5 97 01 A4 ......
Apr 16 13:31:14 testuser-rem pppd[302]: rcvd [LCP ConfReq id=0x2 <mru 1524> <asyncmap 0x20a0000> <magic 0xa955635f> <pcomp> <accomp>]
Apr 16 13:31:14 testuser-rem pppd[302]: sent [LCP ConfNak id=0x2 <magic 0xc59701a4>]
Apr 16 13:31:14 testuser-rem kernel: ppp: write frame, count = 28
Apr 16 13:31:14 testuser-rem kernel: FF 03 C0 21 01 03 00 18 ...!....
Apr 16 13:31:14 testuser-rem kernel: 01 04 05 F4 02 06 02 0A ........
Apr 16 13:31:14 testuser-rem kernel: 00 00 05 06 CC D8 76 FB ......v.
Apr 16 13:31:14 testuser-rem kernel: 07 02 08 02 ....
Apr 16 13:31:14 testuser-rem pppd[302]: rcvd [LCP ConfNak id=0x2 <magic 0xc59701a4>]
Apr 16 13:31:14 testuser-rem pppd[302]: sent [LCP ConfReq id=0x3 <mru 1524> <asyncmap 0x20a0000> <magic 0xccd876fb> <pcomp> <accomp>]
Apr 16 13:31:14 testuser-rem pppd[302]: rcvd [LCP ConfReq id=0x3 <mru 1524> <asyncmap 0x20a0000> <magic 0xccd876fb> <pcomp> <accomp>]
Apr 16 13:31:14 testuser-rem pppd[302]: sent [LCP ConfNak id=0x3 <magic 0x48b7ef37>]
Apr 16 13:31:14 testuser-rem kernel: ppp: write frame, count = 14
Apr 16 13:31:14 testuser-rem kernel: FF 03 C0 21 03 03 00 0A ...!....
Apr 16 13:31:14 testuser-rem kernel: 05 06 48 B7 EF 37 ..H..7
Apr 16 13:31:15 testuser-rem kernel: ppp: write frame, count = 28
Apr 16 13:31:15 testuser-rem kernel: FF 03 C0 21 01 04 00 18 ...!....
Apr 16 13:31:15 testuser-rem kernel: 01 04 05 F4 02 06 02 0A ........
Apr 16 13:31:15 testuser-rem kernel: 00 00 05 06 F0 D6 E0 BD ........
Apr 16 13:31:15 testuser-rem kernel: 07 02 08 02 ....
Apr 16 13:31:15 testuser-rem pppd[302]: rcvd [LCP ConfNak id=0x3 <magic 0x48b7ef37>]
Apr 16 13:31:15 testuser-rem pppd[302]: sent [LCP ConfReq id=0x4 <mru 1524> <asyncmap 0x20a0000> <magic 0xf0d6e0bd> <pcomp> <accomp>]
Apr 16 13:31:15 testuser-rem pppd[302]: rcvd [LCP ConfReq id=0x4 <mru 1524> <asyncmap 0x20a0000> <magic 0xf0d6e0bd> <pcomp> <accomp>]
Apr 16 13:31:15 testuser-rem pppd[302]: sent [LCP ConfNak id=0x4 <magic 0x20410fff>]
Apr 16 13:31:15 testuser-rem kernel: ppp: write frame, count = 14
Apr 16 13:31:15 testuser-rem kernel: FF 03 C0 21 03 04 00 0A ...!....
Apr 16 13:31:15 testuser-rem kernel: 05 06 20 41 0F FF .. A..
Apr 16 13:31:15 testuser-rem kernel: ppp: write frame, count = 28
Apr 16 13:31:15 testuser-rem kernel: FF 03 C0 21 01 05 00 18 ...!....
Apr 16 13:31:15 testuser-rem kernel: 01 04 05 F4 02 06 02 0A ........
Apr 16 13:31:15 testuser-rem kernel: 00 00 05 06 19 D7 B6 6F .......o
Apr 16 13:31:15 testuser-rem kernel: 07 02 08 02 ....
Apr 16 13:31:15 testuser-rem pppd[302]: rcvd [LCP ConfNak id=0x4 <magic 0x20410fff>]
Apr 16 13:31:15 testuser-rem pppd[302]: sent [LCP ConfReq id=0x5 <mru 1524> <asyncmap 0x20a0000> <magic 0x19d7b66f> <pcomp> <accomp>]
Apr 16 13:31:15 testuser-rem pppd[302]: rcvd [LCP ConfReq id=0x5 <mru 1524> <asyncmap 0x20a0000> <magic 0x19d7b66f> <pcomp> <accomp>]
Apr 16 13:31:15 testuser-rem pppd[302]: sent [LCP ConfNak id=0x5 <magic 0xe5b47bda>]
Apr 16 13:31:15 testuser-rem pppd[302]: rcvd [LCP ConfNak id=0x5 <magic 0xe5b47bda>]
Apr 16 13:31:15 testuser-rem pppd[302]: Serial line is looped back.
Apr 16 13:31:15 testuser-rem pppd[302]: sent [LCP TermReq id=0x6]
Apr 16 13:31:15 testuser-rem kernel: ppp: write frame, count = 14
Apr 16 13:31:15 testuser-rem kernel: FF 03 C0 21 03 05 00 0A ...!....
Apr 16 13:31:15 testuser-rem kernel: 05 06 E5 B4 7B DA ....{.
Apr 16 13:31:15 testuser-rem kernel: ppp: write frame, count = 8
Apr 16 13:31:15 testuser-rem kernel: FF 03 C0 21 05 06 00 04 ...!....
Apr 16 13:31:15 testuser-rem pppd[302]: rcvd [LCP ConfReq id=0x1 <mru 1500> <auth pap> <magic 0x3b60122d> <pcomp> <accomp>]
Apr 16 13:31:15 testuser-rem pppd[302]: rcvd [LCP TermAck id=0x6]
Apr 16 13:31:15 testuser-rem pppd[302]: Connection terminated.
Apr 16 13:31:15 testuser-rem pppd[302]: Exit.
Apr 16 13:32:41 testuser-rem kernel: PPP: ppp line discipline successfully unregistered

Trial 2: (failing)
Apr 16 13:32:41 testuser-rem kernel: PPP: ppp line discipline successfully unregistered
Apr 16 13:39:57 testuser-rem kernel: PPP: version 2.2.0 (dynamic channel allocation)
Apr 16 13:39:57 testuser-rem kernel: PPP Dynamic channel allocation code copyright 1995 Caldera, Inc.
Apr 16 13:39:57 testuser-rem kernel: PPP line discipline registered.
Apr 16 13:39:57 testuser-rem kernel: registered device ppp0
Apr 16 13:39:57 testuser-rem syslog: IPX support is not present in the kernel
Apr 16 13:39:57 testuser-rem pppd[351]: pppd 2.2.0 started by root, uid 0
Apr 16 13:39:58 testuser-rem chat[358]: timeout set to 5 seconds
Apr 16 13:39:58 testuser-rem chat[358]: abort on (\nBUSY\r)
Apr 16 13:39:58 testuser-rem chat[358]: abort on (\nNO CARRIER\r)
Apr 16 13:39:58 testuser-rem chat[358]: abort on (\nRING\r\n\r\nRING\r)
Apr 16 13:39:58 testuser-rem chat[358]: abort on (\nNO DIALTONE\r)
Apr 16 13:39:58 testuser-rem chat[358]: abort on (\nERROR\r)
Apr 16 13:39:58 testuser-rem chat[358]: send (+++ATZ^M)
Apr 16 13:39:59 testuser-rem chat[358]: expect (OK)
Apr 16 13:39:59 testuser-rem chat[358]: ^M
Apr 16 13:39:59 testuser-rem chat[358]: OK -- got it
Apr 16 13:39:59 testuser-rem chat[358]: send (AT&F0E0^M)
Apr 16 13:39:59 testuser-rem chat[358]: timeout set to 45 seconds
Apr 16 13:39:59 testuser-rem chat[358]: expect (OK)
Apr 16 13:39:59 testuser-rem chat[358]: ^M
Apr 16 13:39:59 testuser-rem chat[358]: AT&F0E0^M^M
Apr 16 13:39:59 testuser-rem chat[358]: OK -- got it
Apr 16 13:39:59 testuser-rem chat[358]: send (ATLXDT0241888888^M)
Apr 16 13:39:59 testuser-rem chat[358]: expect (CONNECT)
Apr 16 13:39:59 testuser-rem chat[358]: ^M
Apr 16 13:40:25 testuser-rem chat[358]: ^M
Apr 16 13:40:25 testuser-rem chat[358]: CONNECT -- got it
Apr 16 13:40:25 testuser-rem chat[358]: send (^M)
Apr 16 13:40:25 testuser-rem chat[358]: timeout set to 10 seconds
Apr 16 13:40:25 testuser-rem chat[358]: expect (ogin:)
Apr 16 13:40:25 testuser-rem chat[358]: ^M
Apr 16 13:40:25 testuser-rem chat[358]: ^M^M
Apr 16 13:40:25 testuser-rem chat[358]: FreeBSD (xxxxx.yyyyyy.yyyyyyyyyyy.de) (ttyd0)^M^M
Apr 16 13:40:25 testuser-rem chat[358]: ^M^M
Apr 16 13:40:25 testuser-rem chat[358]: login: -- got it
Apr 16 13:40:25 testuser-rem chat[358]: send (xxxxxxxx^M)
Apr 16 13:40:26 testuser-rem chat[358]: expect (assword:)
Apr 16 13:40:26 testuser-rem chat[358]: ^M
Apr 16 13:40:26 testuser-rem chat[358]: ^M^M
Apr 16 13:40:26 testuser-rem chat[358]: FreeBSD (xxxxx.yyyyyy.yyyyyyyyyyy.de) (ttyd0)^M^M
Apr 16 13:40:26 testuser-rem chat[358]: ^M^M
Apr 16 13:40:26 testuser-rem chat[358]: login: xxxxxxxx^M
Apr 16 13:40:26 testuser-rem pppd[351]: Serial connection established.
Apr 16 13:40:26 testuser-rem chat[358]: Password: -- got it
Apr 16 13:40:26 testuser-rem chat[358]: send (xxxxxxxx^M)
Apr 16 13:40:27 testuser-rem kernel: ppp: write frame, count = 28
Apr 16 13:40:27 testuser-rem kernel: FF 03 C0 21 01 01 00 18 ...!....
Apr 16 13:40:27 testuser-rem kernel: 01 04 05 F4 02 06 02 0A ........
Apr 16 13:40:27 testuser-rem kernel: 00 00 05 06 9D 88 6B 8B ......k.
Apr 16 13:40:27 testuser-rem kernel: 07 02 08 02 ....
Apr 16 13:40:27 testuser-rem pppd[351]: Using interface ppp0
Apr 16 13:40:27 testuser-rem pppd[351]: Connect: ppp0 <--> /dev/modem
Apr 16 13:40:27 testuser-rem pppd[351]: sent [LCP ConfReq id=0x1 <mru 1524> <asyncmap 0x20a0000> <magic 0x9d886b8b> <pcomp> <accomp>]
Apr 16 13:40:27 testuser-rem pppd[351]: rcvd [LCP ConfReq id=0x1 <mru 1524> <asyncmap 0x20a0000> <magic 0x9d886b8b> <pcomp> <accomp>]
Apr 16 13:40:27 testuser-rem pppd[351]: sent [LCP ConfNak id=0x1 <magic 0x2d678004>]
Apr 16 13:40:27 testuser-rem kernel: ppp: write frame, count = 14
Apr 16 13:40:27 testuser-rem kernel: FF 03 C0 21 03 01 00 0A ...!....
Apr 16 13:40:27 testuser-rem kernel: 05 06 2D 67 80 04 ..-g..
Apr 16 13:40:27 testuser-rem kernel: ppp: write frame, count = 28
Apr 16 13:40:27 testuser-rem kernel: FF 03 C0 21 01 02 00 18 ...!....
Apr 16 13:40:27 testuser-rem kernel: 01 04 05 F4 02 06 02 0A ........
Apr 16 13:40:27 testuser-rem kernel: 00 00 05 06 15 BB 35 DC ......5.
Apr 16 13:40:27 testuser-rem kernel: 07 02 08 02 ....
Apr 16 13:40:27 testuser-rem pppd[351]: rcvd [LCP ConfNak id=0x1 <magic 0x2d678004>]
Apr 16 13:40:27 testuser-rem pppd[351]: sent [LCP ConfReq id=0x2 <mru 1524> <asyncmap 0x20a0000> <magic 0x15bb35dc> <pcomp> <accomp>]
Apr 16 13:40:28 testuser-rem pppd[351]: rcvd [LCP ConfReq id=0x2 <mru 1524> <asyncmap 0x20a0000> <magic 0x15bb35dc> <pcomp> <accomp>]
Apr 16 13:40:28 testuser-rem pppd[351]: sent [LCP ConfNak id=0x2 <magic 0xd949eedd>]
Apr 16 13:40:28 testuser-rem kernel: ppp: write frame, count = 14
Apr 16 13:40:28 testuser-rem kernel: FF 03 C0 21 03 02 00 0A ...!....
Apr 16 13:40:28 testuser-rem kernel: 05 06 D9 49 EE DD ...I..
Apr 16 13:40:28 testuser-rem kernel: ppp: write frame, count = 28
Apr 16 13:40:28 testuser-rem kernel: FF 03 C0 21 01 03 00 18 ...!....
Apr 16 13:40:28 testuser-rem kernel: 01 04 05 F4 02 06 02 0A ........
Apr 16 13:40:28 testuser-rem kernel: 00 00 05 06 0F B4 AE 40 .......@
Apr 16 13:40:28 testuser-rem kernel: 07 02 08 02 ....
Apr 16 13:40:28 testuser-rem pppd[351]: rcvd [LCP ConfNak id=0x2 <magic 0xd949eedd>]
Apr 16 13:40:28 testuser-rem pppd[351]: sent [LCP ConfReq id=0x3 <mru 1524> <asyncmap 0x20a0000> <magic 0xfb4ae40> <pcomp> <accomp>]
Apr 16 13:40:28 testuser-rem pppd[351]: rcvd [LCP ConfReq id=0x3 <mru 1524> <asyncmap 0x20a0000> <magic 0xfb4ae40> <pcomp> <accomp>]
Apr 16 13:40:28 testuser-rem pppd[351]: sent [LCP ConfNak id=0x3 <magic 0x63bf7598>]
Apr 16 13:40:28 testuser-rem pppd[351]: rcvd [LCP ConfNak id=0x3 <magic 0x63bf7598>]
Apr 16 13:40:28 testuser-rem pppd[351]: sent [LCP ConfReq id=0x4 <mru 1524> <asyncmap 0x20a0000> <magic 0x35323e0a> <pcomp> <accomp>]
Apr 16 13:40:28 testuser-rem kernel: ppp: write frame, count = 14
Apr 16 13:40:28 testuser-rem kernel: FF 03 C0 21 03 03 00 0A ...!....
Apr 16 13:40:28 testuser-rem kernel: 05 06 63 BF 75 98 ..c.u.
Apr 16 13:40:28 testuser-rem kernel: ppp: write frame, count = 28
Apr 16 13:40:28 testuser-rem kernel: FF 03 C0 21 01 04 00 18 ...!....
Apr 16 13:40:28 testuser-rem kernel: 01 04 05 F4 02 06 02 0A ........
Apr 16 13:40:28 testuser-rem kernel: 00 00 05 06 35 32 3E 0A ....52>.
Apr 16 13:40:28 testuser-rem kernel: 07 02 08 02 ....
Apr 16 13:40:28 testuser-rem kernel: ppp: write frame, count = 14
Apr 16 13:40:28 testuser-rem kernel: FF 03 C0 21 03 04 00 0A ...!....
Apr 16 13:40:28 testuser-rem kernel: 05 06 19 F6 F7 C8 ......
Apr 16 13:40:28 testuser-rem kernel: ppp: write frame, count = 28
Apr 16 13:40:28 testuser-rem kernel: FF 03 C0 21 01 05 00 18 ...!....
Apr 16 13:40:28 testuser-rem kernel: 01 04 05 F4 02 06 02 0A ........
Apr 16 13:40:28 testuser-rem kernel: 00 00 05 06 D5 D5 FD 04 ........
Apr 16 13:40:28 testuser-rem kernel: 07 02 08 02 ....
Apr 16 13:40:28 testuser-rem pppd[351]: rcvd [LCP ConfReq id=0x4 <mru 1524> <asyncmap 0x20a0000> <magic 0x35323e0a> <pcomp> <accomp>]
Apr 16 13:40:28 testuser-rem pppd[351]: sent [LCP ConfNak id=0x4 <magic 0x19f6f7c8>]
Apr 16 13:40:28 testuser-rem pppd[351]: rcvd [LCP ConfNak id=0x4 <magic 0x19f6f7c8>]
Apr 16 13:40:28 testuser-rem pppd[351]: sent [LCP ConfReq id=0x5 <mru 1524> <asyncmap 0x20a0000> <magic 0xd5d5fd04> <pcomp> <accomp>]
Apr 16 13:40:31 testuser-rem kernel: ppp: write frame, count = 28
Apr 16 13:40:31 testuser-rem kernel: FF 03 C0 21 01 05 00 18 ...!....
Apr 16 13:40:31 testuser-rem kernel: 01 04 05 F4 02 06 02 0A ........
Apr 16 13:40:31 testuser-rem kernel: 00 00 05 06 D5 D5 FD 04 ........
Apr 16 13:40:31 testuser-rem kernel: 07 02 08 02 ....
Apr 16 13:40:31 testuser-rem pppd[351]: sent [LCP ConfReq id=0x5 <mru 1524> <asyncmap 0x20a0000> <magic 0xd5d5fd04> <pcomp> <accomp>]
Apr 16 13:40:34 testuser-rem kernel: ppp: write frame, count = 28
Apr 16 13:40:34 testuser-rem kernel: FF 03 C0 21 01 05 00 18 ...!....
Apr 16 13:40:34 testuser-rem kernel: 01 04 05 F4 02 06 02 0A ........
Apr 16 13:40:34 testuser-rem kernel: 00 00 05 06 D5 D5 FD 04 ........
Apr 16 13:40:34 testuser-rem kernel: 07 02 08 02 ....
Apr 16 13:40:34 testuser-rem pppd[351]: sent [LCP ConfReq id=0x5 <mru 1524> <asyncmap 0x20a0000> <magic 0xd5d5fd04> <pcomp> <accomp>]
Apr 16 13:40:35 testuser-rem kernel: ppp: write frame, count = 12
Apr 16 13:40:35 testuser-rem kernel: FF 03 C0 21 04 01 00 08 ...!....
Apr 16 13:40:35 testuser-rem kernel: 03 04 C0 23 ...#
Apr 16 13:40:35 testuser-rem pppd[351]: rcvd [LCP ConfReq id=0x1 <mru 1500> <auth pap> <magic 0x6d8f2eb> <pcomp> <accomp>]
Apr 16 13:40:35 testuser-rem pppd[351]: sent [LCP ConfRej id=0x1 <auth pap>]
Apr 16 13:40:35 testuser-rem pppd[351]: rcvd [LCP ConfReq id=0x1 <mru 1500> <auth pap> <magic 0x6d8f2eb> <pcomp> <accomp>]
Apr 16 13:40:35 testuser-rem pppd[351]: sent [LCP ConfRej id=0x1 <auth pap>]
Apr 16 13:40:35 testuser-rem pppd[351]: rcvd [LCP ConfAck id=0x5 <mru 1524> <asyncmap 0x20a0000> <magic 0xd5d5fd04> <pcomp> <accomp>]
Apr 16 13:40:35 testuser-rem pppd[351]: rcvd [LCP ConfAck id=0x5 <mru 1524> <asyncmap 0x20a0000> <magic 0xd5d5fd04> <pcomp> <accomp>]
Apr 16 13:40:35 testuser-rem kernel: ppp: write frame, count = 12
Apr 16 13:40:35 testuser-rem kernel: FF 03 C0 21 04 01 00 08 ...!....
Apr 16 13:40:35 testuser-rem kernel: 03 04 C0 23 ...#
Apr 16 13:40:35 testuser-rem kernel: ppp: write frame, count = 12
Apr 16 13:40:35 testuser-rem kernel: FF 03 C0 21 04 01 00 08 ...!....
Apr 16 13:40:35 testuser-rem kernel: 03 04 C0 23 ...#
Apr 16 13:40:35 testuser-rem kernel: ppp: write frame, count = 22
Apr 16 13:40:35 testuser-rem kernel: FF 03 C0 21 02 02 00 12 ...!....
Apr 16 13:40:35 testuser-rem kernel: 01 04 05 DC 05 06 06 D8 ........
Apr 16 13:40:35 testuser-rem kernel: F2 EB 07 02 08 02 ......
Apr 16 13:40:35 testuser-rem kernel: ppp: write frame, count = 20
Apr 16 13:40:35 testuser-rem kernel: FF 03 80 21 01 01 00 10 ...!....
Apr 16 13:40:35 testuser-rem kernel: 03 06 00 00 00 00 02 06 ........
Apr 16 13:40:35 testuser-rem kernel: 00 2D 0F 01 .-..
Apr 16 13:40:35 testuser-rem pppd[351]: rcvd [LCP ConfReq id=0x1 <mru 1500> <auth pap> <magic 0x6d8f2eb> <pcomp> <accomp>]
Apr 16 13:40:35 testuser-rem pppd[351]: sent [LCP ConfRej id=0x1 <auth pap>]
Apr 16 13:40:35 testuser-rem pppd[351]: rcvd [LCP ConfReq id=0x2 <mru 1500> <magic 0x6d8f2eb> <pcomp> <accomp>]
Apr 16 13:40:35 testuser-rem pppd[351]: sent [LCP ConfAck id=0x2 <mru 1500> <magic 0x6d8f2eb> <pcomp> <accomp>]
Apr 16 13:40:35 testuser-rem pppd[351]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <compress VJ 0f 01>]
Apr 16 13:40:35 testuser-rem pppd[351]: rcvd [LCP TermReq id=0x3]
Apr 16 13:40:35 testuser-rem pppd[351]: LCP terminated at peer's request
Apr 16 13:40:35 testuser-rem pppd[351]: sent [LCP TermAck id=0x3]
Apr 16 13:40:35 testuser-rem kernel: ppp: write frame, count = 8
Apr 16 13:40:35 testuser-rem kernel: FF 03 C0 21 06 03 00 04 ...!....
Apr 16 13:40:35 testuser-rem pppd[351]: Hangup (SIGHUP)
Apr 16 13:40:35 testuser-rem pppd[351]: Modem hangup
Apr 16 13:40:35 testuser-rem pppd[351]: Connection terminated.
Apr 16 13:40:35 testuser-rem pppd[351]: Exit.
Apr 16 13:41:56 testuser-rem kernel: PPP: ppp line discipline successfully unregistered

Trial3: (failing)
----------------------
Apr 16 13:46:58 testuser-rem kernel: PPP: version 2.2.0 (dynamic channel allocation)
Apr 16 13:46:58 testuser-rem kernel: PPP Dynamic channel allocation code copyright 1995 Caldera, Inc.
Apr 16 13:46:58 testuser-rem kernel: PPP line discipline registered.
Apr 16 13:46:58 testuser-rem kernel: registered device ppp0
Apr 16 13:46:58 testuser-rem syslog: IPX support is not present in the kernel
Apr 16 13:46:58 testuser-rem pppd[410]: pppd 2.2.0 started by root, uid 0
Apr 16 13:47:00 testuser-rem chat[417]: timeout set to 5 seconds
Apr 16 13:47:00 testuser-rem chat[417]: abort on (\nBUSY\r)
Apr 16 13:47:00 testuser-rem chat[417]: abort on (\nNO CARRIER\r)
Apr 16 13:47:00 testuser-rem chat[417]: abort on (\nRING\r\n\r\nRING\r)
Apr 16 13:47:00 testuser-rem chat[417]: abort on (\nNO DIALTONE\r)
Apr 16 13:47:00 testuser-rem chat[417]: abort on (\nERROR\r)
Apr 16 13:47:00 testuser-rem chat[417]: send (+++ATZ^M)
Apr 16 13:47:00 testuser-rem chat[417]: expect (OK)
Apr 16 13:47:00 testuser-rem chat[417]: ATZ^M^M
Apr 16 13:47:00 testuser-rem chat[417]: OK -- got it
Apr 16 13:47:00 testuser-rem chat[417]: send (AT&F0E0^M)
Apr 16 13:47:00 testuser-rem chat[417]: timeout set to 45 seconds
Apr 16 13:47:00 testuser-rem chat[417]: expect (OK)
Apr 16 13:47:00 testuser-rem chat[417]: ^M
Apr 16 13:47:00 testuser-rem chat[417]: AT&F0E0^M^M
Apr 16 13:47:00 testuser-rem chat[417]: OK -- got it
Apr 16 13:47:00 testuser-rem chat[417]: send (ATLXDT0241888888^M)
Apr 16 13:47:01 testuser-rem chat[417]: expect (CONNECT)
Apr 16 13:47:01 testuser-rem chat[417]: ^M
Apr 16 13:47:27 testuser-rem chat[417]: ^M
Apr 16 13:47:27 testuser-rem chat[417]: CONNECT -- got it
Apr 16 13:47:27 testuser-rem chat[417]: send (^M)
Apr 16 13:47:27 testuser-rem chat[417]: timeout set to 10 seconds
Apr 16 13:47:27 testuser-rem chat[417]: expect (ogin:)
Apr 16 13:47:27 testuser-rem chat[417]: ^M
Apr 16 13:47:27 testuser-rem chat[417]: ^M^M
Apr 16 13:47:27 testuser-rem chat[417]: FreeBSD (xxxxxx.yyyyyy.yyyyyy.de) (ttyd0)^M^M
Apr 16 13:47:27 testuser-rem chat[417]: ^M^M
Apr 16 13:47:27 testuser-rem chat[417]: login: -- got it
Apr 16 13:47:27 testuser-rem chat[417]: send (xxxxxxxx^M)
Apr 16 13:47:27 testuser-rem chat[417]: expect (assword:)
Apr 16 13:47:27 testuser-rem chat[417]: ^M
Apr 16 13:47:27 testuser-rem chat[417]: ^M^M
Apr 16 13:47:27 testuser-rem chat[417]: FreeBSD (xxxxxx.yyyyyy.yyyyyy.de) (ttyd0)^M^M
Apr 16 13:47:27 testuser-rem chat[417]: ^M^M
Apr 16 13:47:27 testuser-rem chat[417]: login: xxxxxxxx^M
Apr 16 13:47:28 testuser-rem pppd[410]: Serial connection established.
Apr 16 13:47:28 testuser-rem chat[417]: Password: -- got it
Apr 16 13:47:28 testuser-rem chat[417]: send (xxxxxxxx^M)
Apr 16 13:47:29 testuser-rem kernel: ppp: write frame, count = 28
Apr 16 13:47:29 testuser-rem kernel: FF 03 C0 21 01 01 00 18 ...!....
Apr 16 13:47:29 testuser-rem kernel: 01 04 05 F4 02 06 02 0A ........
Apr 16 13:47:29 testuser-rem kernel: 00 00 05 06 B0 93 9B FF ........
Apr 16 13:47:29 testuser-rem kernel: 07 02 08 02 ....
Apr 16 13:47:29 testuser-rem pppd[410]: Using interface ppp0
Apr 16 13:47:29 testuser-rem pppd[410]: Connect: ppp0 <--> /dev/modem
Apr 16 13:47:29 testuser-rem pppd[410]: sent [LCP ConfReq id=0x1 <mru 1524> <asyncmap 0x20a0000> <magic 0xb0939bff> <pcomp> <accomp>]
Apr 16 13:47:29 testuser-rem pppd[410]: rcvd [LCP ConfReq id=0x1 <mru 1524> <asyncmap 0x20a0000> <magic 0xb0939bff> <pcomp> <accomp>]
Apr 16 13:47:29 testuser-rem pppd[410]: sent [LCP ConfNak id=0x1 <magic 0x99a35968>]
Apr 16 13:47:29 testuser-rem kernel: ppp: write frame, count = 14
Apr 16 13:47:29 testuser-rem kernel: FF 03 C0 21 03 01 00 0A ...!....
Apr 16 13:47:29 testuser-rem kernel: 05 06 99 A3 59 68 ....Yh
Apr 16 13:47:29 testuser-rem kernel: ppp: write frame, count = 28
Apr 16 13:47:29 testuser-rem kernel: FF 03 C0 21 01 02 00 18 ...!....
Apr 16 13:47:29 testuser-rem kernel: 01 04 05 F4 02 06 02 0A ........
Apr 16 13:47:29 testuser-rem kernel: 00 00 05 06 10 B6 9D 70 .......p
Apr 16 13:47:29 testuser-rem kernel: 07 02 08 02 ....
Apr 16 13:47:29 testuser-rem kernel: ppp: write frame, count = 14
Apr 16 13:47:29 testuser-rem kernel: FF 03 C0 21 03 02 00 0A ...!....
Apr 16 13:47:29 testuser-rem kernel: 05 06 69 D4 00 E1 ..i...
Apr 16 13:47:29 testuser-rem pppd[410]: rcvd [LCP ConfNak id=0x1 <magic 0x99a35968>]
Apr 16 13:47:29 testuser-rem pppd[410]: sent [LCP ConfReq id=0x2 <mru 1524> <asyncmap 0x20a0000> <magic 0x10b69d70> <pcomp> <accomp>]
Apr 16 13:47:29 testuser-rem pppd[410]: rcvd [LCP ConfReq id=0x2 <mru 1524> <asyncmap 0x20a0000> <magic 0x10b69d70> <pcomp> <accomp>]
Apr 16 13:47:29 testuser-rem pppd[410]: sent [LCP ConfNak id=0x2 <magic 0x69d400e1>]
Apr 16 13:47:29 testuser-rem pppd[410]: rcvd [LCP ConfNak id=0x2 <magic 0x69d400e1>]
Apr 16 13:47:29 testuser-rem pppd[410]: sent [LCP ConfReq id=0x3 <mru 1524> <asyncmap 0x20a0000> <magic 0xba5df1f4> <pcomp> <accomp>]
Apr 16 13:47:29 testuser-rem pppd[410]: rcvd [LCP ConfReq id=0x3 <mru 1524> <asyncmap 0x20a0000> <magic 0xba5df1f4> <pcomp> <accomp>]
Apr 16 13:47:29 testuser-rem pppd[410]: sent [LCP ConfNak id=0x3 <magic 0xa295013c>]
Apr 16 13:47:30 testuser-rem pppd[410]: rcvd [LCP ConfNak id=0x3 <magic 0xa295013c>]
Apr 16 13:47:30 testuser-rem pppd[410]: sent [LCP ConfReq id=0x4 <mru 1524> <asyncmap 0x20a0000> <magic 0xc4c40ade> <pcomp> <accomp>]
Apr 16 13:47:29 testuser-rem kernel: ppp: write frame, count = 28
Apr 16 13:47:29 testuser-rem kernel: FF 03 C0 21 01 03 00 18 ...!....
Apr 16 13:47:29 testuser-rem kernel: 01 04 05 F4 02 06 02 0A ........
Apr 16 13:47:29 testuser-rem kernel: 00 00 05 06 BA 5D F1 F4 .....]..
Apr 16 13:47:29 testuser-rem kernel: 07 02 08 02 ....
Apr 16 13:47:29 testuser-rem kernel: ppp: write frame, count = 14
Apr 16 13:47:29 testuser-rem kernel: FF 03 C0 21 03 03 00 0A ...!....
Apr 16 13:47:29 testuser-rem kernel: 05 06 A2 95 01 3C .....<
Apr 16 13:47:30 testuser-rem kernel: ppp: write frame, count = 28
Apr 16 13:47:30 testuser-rem kernel: FF 03 C0 21 01 04 00 18 ...!....
Apr 16 13:47:30 testuser-rem kernel: 01 04 05 F4 02 06 02 0A ........
Apr 16 13:47:30 testuser-rem kernel: 00 00 05 06 C4 C4 0A DE ........
Apr 16 13:47:30 testuser-rem kernel: 07 02 08 02 ....
Apr 16 13:47:30 testuser-rem kernel: ppp: write frame, count = 14
Apr 16 13:47:30 testuser-rem kernel: FF 03 C0 21 03 04 00 0A ...!....
Apr 16 13:47:30 testuser-rem kernel: 05 06 E4 81 A6 0C ......
Apr 16 13:47:30 testuser-rem kernel: ppp: write frame, count = 28
Apr 16 13:47:30 testuser-rem pppd[410]: rcvd [LCP ConfReq id=0x4 <mru 1524> <asyncmap 0x20a0000> <magic 0xc4c40ade> <pcomp> <accomp>]
Apr 16 13:47:30 testuser-rem pppd[410]: sent [LCP ConfNak id=0x4 <magic 0xe481a60c>]
Apr 16 13:47:30 testuser-rem pppd[410]: rcvd [LCP ConfNak id=0x4 <magic 0xe481a60c>]
Apr 16 13:47:30 testuser-rem pppd[410]: sent [LCP ConfReq id=0x5 <mru 1524> <asyncmap 0x20a0000> <magic 0x4a2347f8> <pcomp> <accomp>]
Apr 16 13:47:30 testuser-rem kernel: FF 03 C0 21 01 05 00 18 ...!....
Apr 16 13:47:30 testuser-rem kernel: 01 04 05 F4 02 06 02 0A ........
Apr 16 13:47:30 testuser-rem kernel: 00 00 05 06 4A 23 47 F8 ....J#G.
Apr 16 13:47:30 testuser-rem kernel: 07 02 08 02 ....
Apr 16 13:47:32 testuser-rem kernel: ppp: write frame, count = 12
Apr 16 13:47:32 testuser-rem kernel: FF 03 C0 21 04 01 00 08 ...!....
Apr 16 13:47:32 testuser-rem kernel: 03 04 C0 23 ...#
Apr 16 13:47:32 testuser-rem pppd[410]: rcvd [LCP ConfReq id=0x1 <mru 1500> <auth pap> <magic 0x7c22345> <pcomp> <accomp>]
Apr 16 13:47:32 testuser-rem pppd[410]: sent [LCP ConfRej id=0x1 <auth pap>]
Apr 16 13:47:33 testuser-rem pppd[410]: rcvd [LCP ConfAck id=0x5 <mru 1524> <asyncmap 0x20a0000> <magic 0x4a2347f8> <pcomp> <accomp>]
Apr 16 13:47:33 testuser-rem kernel: ppp: write frame, count = 22
Apr 16 13:47:33 testuser-rem kernel: FF 03 C0 21 02 02 00 12 ...!....
Apr 16 13:47:33 testuser-rem kernel: 01 04 05 DC 05 06 07 C2 ........
Apr 16 13:47:33 testuser-rem kernel: 23 45 07 02 08 02 #E....
Apr 16 13:47:33 testuser-rem kernel: ppp: write frame, count = 20
Apr 16 13:47:33 testuser-rem kernel: FF 03 80 21 01 01 00 10 ...!....
Apr 16 13:47:33 testuser-rem kernel: 03 06 00 00 00 00 02 06 ........
Apr 16 13:47:33 testuser-rem kernel: 00 2D 0F 01 .-..
Apr 16 13:47:33 testuser-rem pppd[410]: rcvd [LCP ConfReq id=0x2 <mru 1500> <magic 0x7c22345> <pcomp> <accomp>]
Apr 16 13:47:33 testuser-rem pppd[410]: sent [LCP ConfAck id=0x2 <mru 1500> <magic 0x7c22345> <pcomp> <accomp>]
Apr 16 13:47:33 testuser-rem pppd[410]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <compress VJ 0f 01>]
Apr 16 13:47:33 testuser-rem pppd[410]: rcvd [LCP TermReq id=0x3]
Apr 16 13:47:33 testuser-rem pppd[410]: LCP terminated at peer's request
Apr 16 13:47:33 testuser-rem pppd[410]: sent [LCP TermAck id=0x3]
Apr 16 13:47:33 testuser-rem kernel: ppp: write frame, count = 8
Apr 16 13:47:33 testuser-rem kernel: FF 03 C0 21 06 03 00 04 ...!....
Apr 16 13:47:33 testuser-rem pppd[410]: Hangup (SIGHUP)
Apr 16 13:47:33 testuser-rem pppd[410]: Modem hangup
Apr 16 13:47:33 testuser-rem pppd[410]: Connection terminated.
Apr 16 13:47:33 testuser-rem pppd[410]: Exit.

OK site: (working site)

Apr 16 13:50:23 testuser-rem kernel: PPP: version 2.2.0 (dynamic channel allocation)
Apr 16 13:50:23 testuser-rem kernel: PPP Dynamic channel allocation code copyright 1995 Caldera, Inc.
Apr 16 13:50:23 testuser-rem kernel: PPP line discipline registered.
Apr 16 13:50:23 testuser-rem kernel: registered device ppp0
Apr 16 13:50:23 testuser-rem syslog: IPX support is not present in the kernel
Apr 16 13:50:23 testuser-rem pppd[436]: pppd 2.2.0 started by root, uid 0
Apr 16 13:50:24 testuser-rem chat[443]: timeout set to 5 seconds
Apr 16 13:50:24 testuser-rem chat[443]: abort on (\nBUSY\r)
Apr 16 13:50:24 testuser-rem chat[443]: abort on (\nNO CARRIER\r)
Apr 16 13:50:24 testuser-rem chat[443]: abort on (\nRING\r\n\r\nRING\r)
Apr 16 13:50:24 testuser-rem chat[443]: abort on (\nNO DIALTONE\r)
Apr 16 13:50:24 testuser-rem chat[443]: abort on (\nERROR\r)
Apr 16 13:50:24 testuser-rem chat[443]: send (+++ATZ^M)
Apr 16 13:50:25 testuser-rem chat[443]: expect (OK)
Apr 16 13:50:25 testuser-rem chat[443]: ^M
Apr 16 13:50:25 testuser-rem chat[443]: OK -- got it
Apr 16 13:50:25 testuser-rem chat[443]: send (AT&F0E0^M)
Apr 16 13:50:25 testuser-rem chat[443]: timeout set to 45 seconds
Apr 16 13:50:25 testuser-rem chat[443]: expect (OK)
Apr 16 13:50:25 testuser-rem chat[443]: ^M
Apr 16 13:50:25 testuser-rem chat[443]: AT&F0E0^M^M
Apr 16 13:50:25 testuser-rem chat[443]: OK -- got it
Apr 16 13:50:25 testuser-rem chat[443]: send (ATLXDT024199999^M)
Apr 16 13:50:25 testuser-rem chat[443]: expect (CONNECT)
Apr 16 13:50:25 testuser-rem chat[443]: ^M
Apr 16 13:50:47 testuser-rem chat[443]: ^M
Apr 16 13:50:47 testuser-rem chat[443]: CONNECT -- got it
Apr 16 13:50:47 testuser-rem chat[443]: send (^M)
Apr 16 13:50:47 testuser-rem chat[443]: timeout set to 10 seconds
Apr 16 13:50:47 testuser-rem chat[443]: expect (ogin:)
Apr 16 13:50:47 testuser-rem chat[443]: ^M
Apr 16 13:50:52 testuser-rem chat[443]: ^M
Apr 16 13:50:52 testuser-rem chat[443]:
Apr 16 13:50:52 testuser-rem last message repeated 23 times
Apr 16 13:50:52 testuser-rem chat[443]: *** RWTH-Aachen Rechenzentrum Terminalserver ***^M
Apr 16 13:50:52 testuser-rem chat[443]: ^M
Apr 16 13:50:52 testuser-rem chat[443]: ^M
Apr 16 13:50:52 testuser-rem chat[443]: Login: -- got it
Apr 16 13:50:52 testuser-rem chat[443]: send (xxxxxxxx^M)
Apr 16 13:50:52 testuser-rem chat[443]: expect (assword:)
Apr 16 13:50:53 testuser-rem chat[443]: xxxxxxxx^M
Apr 16 13:50:53 testuser-rem chat[443]: Password: -- got it
Apr 16 13:50:53 testuser-rem chat[443]: send (xxxxxxxx^M)
Apr 16 13:50:53 testuser-rem pppd[436]: Serial connection established.
Apr 16 13:50:54 testuser-rem pppd[436]: Using interface ppp0
Apr 16 13:50:54 testuser-rem pppd[436]: Connect: ppp0 <--> /dev/modem
Apr 16 13:50:54 testuser-rem pppd[436]: sent [LCP ConfReq id=0x1 <mru 1500> <asyncmap 0x20a0000> <magic 0x21662bd> <pcomp> <accomp>]
Apr 16 13:50:54 testuser-rem pppd[436]: rcvd [LCP ConfReq id=0x1 <mru 1524> <asyncmap 0xa0000> <pcomp> <accomp> < 11 04 05 f4> < 13 09 03 00 c0 7b 63 d9 81>]
Apr 16 13:50:54 testuser-rem pppd[436]: sent [LCP ConfRej id=0x1 < 11 04 05 f4> < 13 09 03 00 c0 7b 63 d9 81>]
Apr 16 13:50:54 testuser-rem pppd[436]: rcvd [LCP ConfAck id=0x1 <mru 1500> <asyncmap 0x20a0000> <magic 0x21662bd> <pcomp> <accomp>]
Apr 16 13:50:54 testuser-rem pppd[436]: rcvd [LCP ConfReq id=0x2 <mru 1524> <asyncmap 0xa0000> <pcomp> <accomp>]
Apr 16 13:50:54 testuser-rem pppd[436]: sent [LCP ConfAck id=0x2 <mru 1524> <asyncmap 0xa0000> <pcomp> <accomp>]
Apr 16 13:50:54 testuser-rem pppd[436]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <compress VJ 0f 01>]
Apr 16 13:50:54 testuser-rem pppd[436]: rcvd [CCP ConfReq id=0x1 < 11 06 00 01 01 03>]
Apr 16 13:50:54 testuser-rem pppd[436]: sent [CCP ConfReq id=0x1]
Apr 16 13:50:54 testuser-rem pppd[436]: sent [CCP ConfRej id=0x1 < 11 06 00 01 01 03>]
Apr 16 13:50:54 testuser-rem pppd[436]: rcvd [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 134.134.179.134
Apr 16 13:50:54 testuser-rem pppd[436]: sent [IPCP ConfAck id=0x1 <compress VJ 0f 01> <addr 134.134.179.134
Apr 16 13:50:54 testuser-rem pppd[436]: rcvd [IPCP ConfNak id=0x1 <addr 123.123.3.123>]
Apr 16 13:50:54 testuser-rem pppd[436]: sent [IPCP ConfReq id=0x2 <addr 123.123.3.123> <compress VJ 0f 01>]
Apr 16 13:50:54 testuser-rem pppd[436]: rcvd [CCP ConfRej id=0x1]
Apr 16 13:50:54 testuser-rem pppd[436]: rcvd [IPCP ConfAck id=0x2 <addr 123.123.3.123> <compress VJ 0f 01>]
Apr 16 13:50:54 testuser-rem pppd[436]: local IP address 123.123.3.123
Apr 16 13:50:54 testuser-rem pppd[436]: remote IP address 134.134.179.134

The corresponding logs on the server side during the
login trials: (The clocks seem to diverge)

Apr 16 14:30:48 agate login: login on ttyd0 as testuser
Apr 16 14:30:48 agate testuser: ppplogin.sh started testuser
Apr 16 14:30:50 agate testuser: before starting pppd: testuser
Apr 16 14:30:51 agate pppd[26396]: pppd 2.2.0 started by testuser, uid 2134
Apr 16 14:30:51 agate pppd[26396]: Connect: ppp0 <--> /dev/ttyd0
Apr 16 14:30:52 agate pppd[26396]: Modem hangup
Apr 16 14:40:02 agate login: login on ttyd0 as testuser
Apr 16 14:40:02 agate testuser: ppplogin.sh started testuser
Apr 16 14:40:04 agate testuser: before starting pppd: testuser
Apr 16 14:40:04 agate pppd[27234]: pppd 2.2.0 started by testuser, uid 2134
Apr 16 14:40:04 agate pppd[27234]: Connect: ppp0 <--> /dev/ttyd0
Apr 16 14:40:11 agate pppd[27234]: peer refused to authenticate
Apr 16 14:40:11 agate pppd[27234]: Connection terminated.
Apr 16 14:47:04 agate login: login on ttyd0 as testuser
Apr 16 14:47:04 agate testuser: ppplogin.sh started testuser
Apr 16 14:47:05 agate testuser: before starting pppd: testuser
Apr 16 14:47:06 agate pppd[27265]: pppd 2.2.0 started by testuser, uid 2134
Apr 16 14:47:06 agate pppd[27265]: Connect: ppp0 <--> /dev/ttyd0
Apr 16 14:47:08 agate pppd[27265]: peer refused to authenticate
Apr 16 14:47:09 agate pppd[27265]: Connection terminated.

Erst mal die logs, die ich schon in die freebsd-questions Liste geschickt
hatte und die Doug schon versucht hatte 'Kaffeesatz zu lesen'.

Mein 'Kunde' ist erst in den naechsten Tagen wieder an seiner
Kiste, so dass ich wohl erst dann dazu komme, auf der FreeBSD server
Seite ausfuehrlichere logs zu siehen.

Aber vielleicht siehst Du so schon was.

Doug meinte irgendwo sieht einer sein eigenes Echo.
Von meiner Linux Kiste lief es auch Angangs nicht, jetzt aber,
nachdem ich dem user sofort ppplogin.sh als log shell anbiete und
nicht warte bis getty das ppp Protokoll erkennt und ppplogin.sh
ausfuehrt. In dem letzteren Fall naemlich, passierte ueberhaupt nix
und das Modem legte nach ein paar Sekunden auf.

welche debug flags sollte ich beim naechsten log einschalten?

pppd debug kdebug <n> - welcher Wert fuer n? 4 gibt eine Menge Zeugs.

/etc/ppp/options ist im MOment:

crtscts # Hardware flow control
###auth login
#mru 1524
123.123.12.1:123.123.12.3 # ip's of local and remote hosts
netmask 255.255.255.0
domain physik.rwth-aachen.de
dns1 123.123.12.12
dns2 123.123.144.2
passive # wait for LCP
modem # modem line
proxyarp # use ARP proxy routing
###-chap

>
> --
> cheers, J"org
>
> joerg_wunsch@uriah.heep.sax.de -- http://www.sax.de/~joerg/ -- NIC: JW11-RIPE
> Never trust an operating system you don't have sources for. ;-)

-- 
Chris Christoph P. U. Kukulies kuku(at)gil.physik.rwth-aachen.de
Received on Sat 18 Apr 1998 - 16:43:18 CEST

search this site