Hi all, I have tried to cope with it myself for about 4 days, then posted to linux-ppp -- and, after a week since the post, I am still nowhere :-( Maybe you could help?
I am trying to set up an outbound PPP on linux into an NT box, which is supposed to call me back. (pppd 2.3.5-2 with mschap and cbcp compiled in, linux 2.0.30-2/Debian, then 2.0.34 with the same problems). I am 2 years using Linux and different PPP dialout/dialin setups, but this is the 1st time I am trying to make it with NT on the other end. Before setting it up in a bulletproof way (with support for BUSY/problems on callback/etc) I just started with the following simple trial script: -- script -- line 1> pppd debug noauth nodetach /dev/ttyS3 callback 08-9390138 user vassilii remotename net-post connect 'chat "" atz "OK" atd036122362 "CONNECT" "" && sleep 1' line 2> pppd debug noauth nodetach kdebug 3 /dev/ttyS3 user vassilii remotename net-post defaultroute connect 'chat -v RING ATA "CONNECT" "\c" && sleep 1' --end of script -- Now, it is not that things are totally not working. chap-secrets file is properly set up. I tried to setup a test acct on NT that doesn't do callback; and then ensured ppp starts OK with it (the second line in the above script then is not needed, of course), and I have a proper internet connection. Now, back to the callback scenario. The dialout completes OK, I see the LCP negotiation progress and then the disconnect; then the remote end calls me back. The second "chat" answers, pppd starts... and this is the point I am stuck at: the peer never sends me an LCP packet my pppd recognizes. I tried to answer with minicom, not pppd/chat, and see if PPP data stream comes in -- it does. I tried all the combinations of `passive' and `silent'. (In the passive case my pppd sends out LCP requests, but never gets an LCP response). After a timeout (I tried to increase it to 30 LCP packets --- no diff :-( ) it hangs up. I had a guess that on the callback all the options must already be negotiated (IPCP etc.), but, after careful examination of both the dialout w/o callback and w/ callbeck LCP sequences, I made sure that nothing except for CHAP auth. and callback negotiation takes place on the outbound call in the callback scenario -- so some LCP *must* take place on the callback stage!!! I tried to enable kdebug 3 to see how pppd reacts to the incoming packets from NT; and discovered they all are recognized as having CRC problems!!! I understand things may be out of sync at the beginning -- while the "CONNECT ..." modem message tail can still be in effect, or, vice versa, if pppd starts up after the peer NT begins its PPP talk and misses some initial peer PPP babble. But why doesn't it recover?? (The log messages attached in the end of the message are the ones generated by the second pppd/chat line in the script). Am I missing something obvious? What can be wrong? Anyone ever set up outbound ppp w/ callback with an NT RAS server? Have any refs to a sample setup? Anything? (I checked all the things like /usr/doc/ppp, HOWTOs (Serial and PPP), sag -- and found nothing :-( I understood from some on irc #debian that the topic is relatively new and unknown... as soon as I get the solution from anywhere I will post it here as well with all the sample conf. files and suggest it for the PPP-FAQ.) Many thanks to all who can shed some light on the issue. vassilii (a.k.a. BACbKA on #debian) -- script -- pppd debug noauth nodetach /dev/ttyS3 callback 08-9390138 user vassilii remotename net-post connect 'chat "" atz "OK" atd036122362 "CONNECT" "" && sleep 1' pppd debug noauth nodetach kdebug 3 /dev/ttyS3 user vassilii remotename net-post defaultroute connect 'chat -v RING ATA "CONNECT" "\c" && sleep 1' -- messages -- Jul 13 12:38:59 Desdemona pppd[189]: pppd 2.3.5 started by root, uid 0 Jul 13 12:39:00 Desdemona chat[191]: expect (RING) Jul 13 12:39:08 Desdemona chat[191]: ^M Jul 13 12:39:08 Desdemona chat[191]: RING Jul 13 12:39:08 Desdemona chat[191]: -- got it Jul 13 12:39:08 Desdemona chat[191]: send (ATA^M) Jul 13 12:39:08 Desdemona chat[191]: expect (CONNECT) Jul 13 12:39:08 Desdemona chat[191]: ^M Jul 13 12:39:08 Desdemona chat[191]: ^M Jul 13 12:39:08 Desdemona chat[191]: NO CARRIER^M Jul 13 12:39:23 Desdemona chat[191]: A^M^M Jul 13 12:39:23 Desdemona chat[191]: CONNECT Jul 13 12:39:23 Desdemona chat[191]: -- got it Jul 13 12:39:23 Desdemona chat[191]: send () Jul 13 12:39:24 Desdemona pppd[189]: Serial connection established. Jul 13 12:39:25 Desdemona kernel: ppp_tty_ioctl: set flags to 30000 Jul 13 12:39:25 Desdemona kernel: ppp_tty_ioctl: set flags to 30000 Jul 13 12:39:25 Desdemona pppd[189]: Using interface ppp0 Jul 13 12:39:25 Desdemona pppd[189]: Connect: ppp0 <--> /dev/ttyS3 Jul 13 12:39:25 Desdemona kernel: ppp_tty_ioctl: set xasyncmap Jul 13 12:39:25 Desdemona kernel: ppp_tty_ioctl: set xmit asyncmap ffffffff Jul 13 12:39:25 Desdemona kernel: ppp_tty_ioctl: set flags to 30000 Jul 13 12:39:25 Desdemona kernel: ppp_tty_ioctl: set mru to 5dc Jul 13 12:39:25 Desdemona kernel: ppp_tty_ioctl: set rcv asyncmap ffffffff Jul 13 12:39:25 Desdemona kernel: ppp_tty_ioctl: set flags to 30000 Jul 13 12:39:55 Desdemona pppd[189]: LCP: timeout sending Config-Requests Jul 13 12:39:55 Desdemona pppd[189]: Connection terminated. Jul 13 12:39:55 Desdemona kernel: ppp: channel ppp0 closing. Jul 13 12:39:56 Desdemona pppd[189]: Exit. -- debug -- Jul 13 12:39:25 Desdemona pppd[189]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xe25e584d> <pcomp> <accomp>] Jul 13 12:39:25 Desdemona kernel: ppp: frame with bad fcs, length = 10 Jul 13 12:39:25 Desdemona kernel: ppp: bad frame, count = 10 Jul 13 12:39:25 Desdemona kernel: FF C0 00 21 E2 5E 58 4D ...!.^XM Jul 13 12:39:25 Desdemona kernel: C9 43 .C Jul 13 12:39:27 Desdemona kernel: ppp: frame with bad fcs, length = 22 Jul 13 12:39:27 Desdemona kernel: ppp: bad frame, count = 22 Jul 13 12:39:27 Desdemona kernel: FF C0 00 21 34 C2 23 80 ...!4.#. Jul 13 12:39:27 Desdemona kernel: 75 49 4E 78 D7 8E D2 BE uINx.... Jul 13 12:39:27 Desdemona kernel: A0 C9 8D 5D 51 BD ...]Q. Jul 13 12:39:28 Desdemona pppd[189]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xe25e584d> <pcomp> <accomp>] Jul 13 12:39:28 Desdemona kernel: ppp: frame with bad fcs, length = 10 Jul 13 12:39:28 Desdemona kernel: ppp: bad frame, count = 10 Jul 13 12:39:28 Desdemona kernel: FF C0 00 21 E2 5E 58 4D ...!.^XM Jul 13 12:39:28 Desdemona kernel: C9 43 .C Jul 13 12:39:31 Desdemona pppd[189]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xe25e584d> <pcomp> <accomp>] Jul 13 12:39:31 Desdemona kernel: ppp: frame with bad fcs, length = 22 Jul 13 12:39:31 Desdemona kernel: ppp: bad frame, count = 22 Jul 13 12:39:31 Desdemona kernel: FF C0 00 21 34 C2 23 80 ...!4.#. Jul 13 12:39:31 Desdemona kernel: 75 49 4E 78 D7 8E D2 BE uINx.... Jul 13 12:39:31 Desdemona kernel: A0 C9 8D 5D 51 BD ...]Q. Jul 13 12:39:31 Desdemona kernel: ppp: frame with bad fcs, length = 10 Jul 13 12:39:31 Desdemona kernel: ppp: bad frame, count = 10 Jul 13 12:39:31 Desdemona kernel: FF C0 00 21 E2 5E 58 4D ...!.^XM Jul 13 12:39:31 Desdemona kernel: C9 43 .C Jul 13 12:39:34 Desdemona pppd[189]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xe25e584d> <pcomp> <accomp>] Jul 13 12:39:34 Desdemona kernel: ppp: frame with bad fcs, length = 10 Jul 13 12:39:34 Desdemona kernel: ppp: bad frame, count = 10 Jul 13 12:39:34 Desdemona kernel: FF C0 00 21 E2 5E 58 4D ...!.^XM Jul 13 12:39:34 Desdemona kernel: C9 43 .C Jul 13 12:39:35 Desdemona kernel: ppp: frame with bad fcs, length = 22 Jul 13 12:39:35 Desdemona kernel: ppp: bad frame, count = 22 Jul 13 12:39:35 Desdemona kernel: FF C0 00 21 34 C2 23 80 ...!4.#. Jul 13 12:39:35 Desdemona kernel: 75 49 4E 78 D7 8E D2 BE uINx.... Jul 13 12:39:35 Desdemona kernel: A0 C9 8D 5D 51 BD ...]Q. Jul 13 12:39:37 Desdemona pppd[189]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xe25e584d> <pcomp> <accomp>] Jul 13 12:39:37 Desdemona kernel: ppp: frame with bad fcs, length = 10 Jul 13 12:39:37 Desdemona kernel: ppp: bad frame, count = 10 Jul 13 12:39:37 Desdemona kernel: FF C0 00 21 E2 5E 58 4D ...!.^XM Jul 13 12:39:37 Desdemona kernel: C9 43 .C Jul 13 12:39:39 Desdemona kernel: ppp: frame with bad fcs, length = 22 Jul 13 12:39:39 Desdemona kernel: ppp: bad frame, count = 22 Jul 13 12:39:39 Desdemona kernel: FF C0 00 21 34 C2 23 80 ...!4.#. Jul 13 12:39:39 Desdemona kernel: 75 49 4E 78 D7 8E D2 BE uINx.... Jul 13 12:39:39 Desdemona kernel: A0 C9 8D 5D 51 BD ...]Q. Jul 13 12:39:40 Desdemona pppd[189]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xe25e584d> <pcomp> <accomp>] Jul 13 12:39:40 Desdemona kernel: ppp: frame with bad fcs, length = 10 Jul 13 12:39:40 Desdemona kernel: ppp: bad frame, count = 10 Jul 13 12:39:40 Desdemona kernel: FF C0 00 21 E2 5E 58 4D ...!.^XM Jul 13 12:39:40 Desdemona kernel: C9 43 .C Jul 13 12:39:43 Desdemona pppd[189]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xe25e584d> <pcomp> <accomp>] Jul 13 12:39:43 Desdemona kernel: ppp: frame with bad fcs, length = 22 Jul 13 12:39:43 Desdemona kernel: ppp: bad frame, count = 22 Jul 13 12:39:43 Desdemona kernel: FF C0 00 21 34 C2 23 80 ...!4.#. Jul 13 12:39:43 Desdemona kernel: 75 49 4E 78 D7 8E D2 BE uINx.... Jul 13 12:39:43 Desdemona kernel: A0 C9 8D 5D 51 BD ...]Q. Jul 13 12:39:43 Desdemona kernel: ppp: frame with bad fcs, length = 10 Jul 13 12:39:43 Desdemona kernel: ppp: bad frame, count = 10 Jul 13 12:39:43 Desdemona kernel: FF C0 00 21 E2 5E 58 4D ...!.^XM Jul 13 12:39:43 Desdemona kernel: C9 43 .C Jul 13 12:39:46 Desdemona pppd[189]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xe25e584d> <pcomp> <accomp>] Jul 13 12:39:46 Desdemona kernel: ppp: frame with bad fcs, length = 10 Jul 13 12:39:46 Desdemona kernel: ppp: bad frame, count = 10 Jul 13 12:39:46 Desdemona kernel: FF C0 00 21 E2 5E 58 4D ...!.^XM Jul 13 12:39:46 Desdemona kernel: C9 43 .C Jul 13 12:39:47 Desdemona kernel: ppp: frame with bad fcs, length = 22 Jul 13 12:39:47 Desdemona kernel: ppp: bad frame, count = 22 Jul 13 12:39:47 Desdemona kernel: FF C0 00 21 34 C2 23 80 ...!4.#. Jul 13 12:39:47 Desdemona kernel: 75 49 4E 78 D7 8E D2 BE uINx.... Jul 13 12:39:47 Desdemona kernel: A0 C9 8D 5D 51 BD ...]Q. Jul 13 12:39:49 Desdemona pppd[189]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xe25e584d> <pcomp> <accomp>] Jul 13 12:39:49 Desdemona kernel: ppp: frame with bad fcs, length = 10 Jul 13 12:39:49 Desdemona kernel: ppp: bad frame, count = 10 Jul 13 12:39:49 Desdemona kernel: FF C0 00 21 E2 5E 58 4D ...!.^XM Jul 13 12:39:49 Desdemona kernel: C9 43 .C Jul 13 12:39:51 Desdemona kernel: ppp: frame with bad fcs, length = 22 Jul 13 12:39:51 Desdemona kernel: ppp: bad frame, count = 22 Jul 13 12:39:51 Desdemona kernel: FF C0 00 21 34 C2 23 80 ...!4.#. Jul 13 12:39:51 Desdemona kernel: 75 49 4E 78 D7 8E D2 BE uINx.... Jul 13 12:39:51 Desdemona kernel: A0 C9 8D 5D 51 BD ...]Q. Jul 13 12:39:52 Desdemona pppd[189]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xe25e584d> <pcomp> <accomp>] Jul 13 12:39:52 Desdemona kernel: ppp: frame with bad fcs, length = 10 Jul 13 12:39:52 Desdemona kernel: ppp: bad frame, count = 10 Jul 13 12:39:52 Desdemona kernel: FF C0 00 21 E2 5E 58 4D ...!.^XM Jul 13 12:39:52 Desdemona kernel: C9 43 .C Jul 13 12:39:55 Desdemona kernel: ppp0 released Jul 13 12:39:55 Desdemona kernel: ppp0: ccp closed -- Unsubscribe? mail -s unsubscribe [EMAIL PROTECTED] < /dev/null
