Google Groups no longer supports new Usenet posts or subscriptions. Historical content remains viewable.
Dismiss

pppd problems

291 views
Skip to first unread message

cerr

unread,
Jul 10, 2012, 3:12:50 PM7/10/12
to
Hi,

I'm trying to establish a ppp connection with a wireless usb stick modem to Rogers Wireless (Canada).
I wrote a chat script where I copied the talk data from a Windows log (where connection can be established succesfully). The chat script looks like:

'ABORT' 'BUSY'
'ABORT' 'ERROR'
'ABORT' 'NO ANSWER'
'ABORT' 'NO CARRIER'
'ABORT' 'NO DIALTONE'

'' 'AT'
'OK' 'AT&FE0V1X1&D2&C1S0=0'
'OK' 'AT'
'OK' 'ATS0=0'
'OK' 'AT'
'OK' 'AT&FE0V1X1&D2&C1S0=0'
'OK' 'AT'
#'OK' 'AT+CGDCONT=1,"IP","vpn.com"'
#'OK' 'AT'
'OK' 'ATDT*###'
#'NO CARRIER' 'ATH E1'
#'OK' 'AT&FE0V1X1&D2&C1S0=0'
#'OK' 'AT'
#'OK' 'ATS0=0'
'' 'CONNECT'

and when I dial, I always get (from syslog):
Jul 10 19:13:02 E10_semiosOffice local2.info chat[696]: send (ATDT*###^M)
Jul 10 19:13:02 E10_semiosOffice local2.info chat[696]: send (CONNECT^M)
Jul 10 19:13:02 E10_semiosOffice daemon.debug pppd[690]: Script /usr/sbin/chat -v -t6 -f /etc/ppp/peers/rogers_chat finished (pid 695), status = 0x0
Jul 10 19:13:02 E10_semiosOffice daemon.info pppd[690]: Serial connection established.
Jul 10 19:13:02 E10_semiosOffice daemon.debug pppd[690]: using channel 1
Jul 10 19:13:02 E10_semiosOffice daemon.info pppd[690]: Using interface ppp0
Jul 10 19:13:02 E10_semiosOffice daemon.notice pppd[690]: Connect: ppp0 <--> /dev/ttyUSB2
Jul 10 19:13:03 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x51f07ab7> <pcomp> <accomp>]
Jul 10 19:13:06 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x51f07ab7> <pcomp> <accomp>]
Jul 10 19:13:09 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x51f07ab7> <pcomp> <accomp>]
Jul 10 19:13:12 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x51f07ab7> <pcomp> <accomp>]
Jul 10 19:13:15 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x51f07ab7> <pcomp> <accomp>]
Jul 10 19:13:18 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x51f07ab7> <pcomp> <accomp>]
Jul 10 19:13:21 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x51f07ab7> <pcomp> <accomp>]
Jul 10 19:13:25 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x51f07ab7> <pcomp> <accomp>]
Jul 10 19:13:28 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x51f07ab7> <pcomp> <accomp>]
Jul 10 19:13:31 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x51f07ab7> <pcomp> <accomp>]
Jul 10 19:13:34 E10_semiosOffice daemon.warn pppd[690]: LCP: timeout sending Config-Requests
Jul 10 19:13:34 E10_semiosOffice daemon.notice pppd[690]: Connection terminated.
Jul 10 19:13:34 E10_semiosOffice daemon.warn pppd[690]: Receive serial link is not 8-bit clean:
Jul 10 19:13:34 E10_semiosOffice daemon.warn pppd[690]: Problem: all had bit 7 set to 0
Jul 10 19:13:35 E10_semiosOffice daemon.notice pppd[690]: Modem hangup
Jul 10 19:13:35 E10_semiosOffice daemon.info pppd[690]: Exit.

Why is this? What are these LCP messages?
What am I doing wrong?
Help, tips and suggestions would be appreciated!

Thanks,
Ron

Fork

unread,
Jul 10, 2012, 5:59:53 PM7/10/12
to
On 07/10/2012 09:12 PM, cerr wrote:
> LCP: timeout sending Config-Requests

Try here:

http://ubuntuforums.org/showthread.php?t=1423194

cerr

unread,
Jul 10, 2012, 6:42:11 PM7/10/12
to
Fork wrote:

> Try here:
>
> http://ubuntuforums.org/showthread.php?t=1423194

Hi Fork,

Thanks for your reply, I've acxtually found this thread before too but
he's talking about replacing a router and i'm seeing this error when I
try to dial up unsing pppd with a GSM modem.
Any other clues?
Anyone?

Thanks,
Ron

--- Posted via news://freenews.netfront.net/ - Complaints to ne...@netfront.net ---

Moe Trin

unread,
Jul 10, 2012, 9:50:52 PM7/10/12
to
On Tue, 10 Jul 2012, in the Usenet newsgroup alt.os.linux, in article
<5ee29d69-4f0f-473a...@googlegroups.com>, cerr wrote:

>I wrote a chat script where I copied the talk data from a Windows log
>(where connection can be established succesfully).

Perfect technique - minor transcription error

> The chat script looks like:

[set up five ABORT conditions]

May be overkill, but OK

>'' 'AT'
>'OK' 'AT&FE0V1X1&D2&C1S0=0'

OK I guess. You SHOULD be able to reduce that to

'' AT&FE0V1X1&D2&C1S0=0

"AT" is a Hayes command _prefix_ - it says what follows (up to the
carriage return) is a command. So a bare AT does.... nothing. (If
you get back an "OK", it does say that you can talk to the modem, but
that's all.) On a POTS modem, the 'E0V1&D2&C1S0=0' probably isn't
needed as those would be default settings included in the &F - but
they aren't likely to be hurting anything here.

>'OK' 'AT'
>'OK' 'ATS0=0'
>'OK' 'AT'
>'OK' 'AT&FE0V1X1&D2&C1S0=0'
>'OK' 'AT'

First, the AT is as above. Second, the S0=0 command is already at the
end of the first init string above. Third, the next three lines are
unneeded duplicates of above and can go. Last, the quotes aren't
hurting, but aren't needed (no spaces or special characters to protect).

>#'OK' 'AT+CGDCONT=1,"IP","vpn.com"'
>#'OK' 'AT'

For a wireless modem, that first line _probably_ doesn't want to be
commented out - it's often needed to (help) start the ppp device on the
link. The AT is as above.

>'OK' 'ATDT*###'

Probably OK (wireless modems don't follow standards and are weird).

>#'NO CARRIER' 'ATH E1'
>#'OK' 'AT&FE0V1X1&D2&C1S0=0'
>#'OK' 'AT'
>#'OK' 'ATS0=0'

More unnecessary stuff

>'' 'CONNECT'

Almost certainly wrong. This _PROBABLY_ wants to be

'CONNECT' ''

or more likely

'CONNECT' '\d\c'

>and when I dial, I always get (from syslog):
>Jul 10 19:13:02 E10_semiosOffice local2.info chat[696]: send
> (ATDT*###^M)
>Jul 10 19:13:02 E10_semiosOffice local2.info chat[696]: send
> (CONNECT^M)

and that's the likely error. You don't want to _send_ that word down
the wire, but want to _receive_ that word from the modem indicating
that it found another modem to talk to.

>Jul 10 19:13:34 E10_semiosOffice daemon.warn pppd[690]: LCP: timeout
> sending Config-Requests
>Jul 10 19:13:34 E10_semiosOffice daemon.notice pppd[690]: Connection
> terminated.
>Jul 10 19:13:34 E10_semiosOffice daemon.warn pppd[690]: Receive serial
> link is not 8-bit clean:
>Jul 10 19:13:34 E10_semiosOffice daemon.warn pppd[690]: Problem: all
> had bit 7 set to 0

The other end of the link isn't a ppp daemon - and while _may_ be a
modem-to-modem connection, there's nothing listening at the far end.
That _might_ also be related to the commented out "AT+CGDCONT=1" line.

This was a problem with a lot of people setting up Linux ppp links in
the late 1990s or so. The terminal server (the thing at the other end
of the modem link) was configured to support windoze, and that meant
being in "AutoPPP" mode. The idea is/was as soon as the modem link
came up, you started sending ppp frames. But the server would drop
into text mode if you sent ANY ASCII characters - and it would present
a "Login:" prompt - except that nothing else was configured and no
matter what you sent, you got exactly no-where. Well, you're sending
an entire word and carriage return. Don't Do That!!! ;-) (For
some reason, people using Linux assumed that - even though they never
did so with windoze - they _had_ to find that "Login:" prompt. This
misunderstanding caused no end of problems. But I digress)

The sequence " '' CONNECT " says wait for nothing (the '' ) and send
the word CONNECT. The first replacement often worked - " CONNECT ''"
says wait for the modems to report connecting, send nothing (except
that it did send a carriage return which got some servers unhappy).
The second replacement was the answer: " CONNECT '\d\c' " says wait for
that CONNECT stanza, wait an additional second ( "\d" ) then _don't_
send the normal carriage return ( "\c" ) at the end of things. That's
mentioned well down in the 'chat' man-page and is specific to Linux.

>Why is this?

Above

>What are these LCP messages?

sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x51f07ab7> <pcomp>
<accomp>]

Normal - your pppd is sending a message that it wants to configure the
datalink, doesn't need certain characters escaped, the "magic" is a
randomly chosen 32 bit number used to detect the link being looped
back, and pcomp and accomp are two data compression functions. It's
sort of hinted at in the pppd man-page. What would normally happen is
that the peer pppd would respond to this/these requests and reply with
it's own set of requests which your modem would respond to - then you'd
go on to negotiating an Internet Protocol link running on top of this,
and away you go.

>What am I doing wrong?

Some how, you got a transcription problem between what windoze was
doing and what you needed to put into the chat file. In summary,
you can _probably_ boil that chat file down to

ABORT BUSY
ABORT ERROR
ABORT 'NO ANSWER'
ABORT 'NO CARRIER'
ABORT 'NO DIALTONE'
'' 'AT&FE0V1X1&D2&C1S0=0'
OK 'AT+CGDCONT=1,"IP","vpn.com"'
OK 'ATDT*###'
CONNECT '\d\c'

and that should work.

Old guy

cerr

unread,
Jul 11, 2012, 2:16:01 PM7/11/12
to
On Tuesday, July 10, 2012 12:12:50 PM UTC-7, cerr wrote:
> Hi,
>
> I&#39;m trying to establish a ppp connection with a wireless usb stick modem to Rogers Wireless (Canada).
> I wrote a chat script where I copied the talk data from a Windows log (where connection can be established succesfully). The chat script looks like:
>
> &#39;ABORT&#39; &#39;BUSY&#39;
> &#39;ABORT&#39; &#39;ERROR&#39;
> &#39;ABORT&#39; &#39;NO ANSWER&#39;
> &#39;ABORT&#39; &#39;NO CARRIER&#39;
> &#39;ABORT&#39; &#39;NO DIALTONE&#39;
>
> &#39;&#39; &#39;AT&#39;
> &#39;OK&#39; &#39;AT&amp;FE0V1X1&amp;D2&amp;C1S0=0&#39;
> &#39;OK&#39; &#39;AT&#39;
> &#39;OK&#39; &#39;ATS0=0&#39;
> &#39;OK&#39; &#39;AT&#39;
> &#39;OK&#39; &#39;AT&amp;FE0V1X1&amp;D2&amp;C1S0=0&#39;
> &#39;OK&#39; &#39;AT&#39;
> #&#39;OK&#39; &#39;AT+CGDCONT=1,&quot;IP&quot;,&quot;vpn.com&quot;&#39;
> #&#39;OK&#39; &#39;AT&#39;
> &#39;OK&#39; &#39;ATDT*###&#39;
> #&#39;NO CARRIER&#39; &#39;ATH E1&#39;
> #&#39;OK&#39; &#39;AT&amp;FE0V1X1&amp;D2&amp;C1S0=0&#39;
> #&#39;OK&#39; &#39;AT&#39;
> #&#39;OK&#39; &#39;ATS0=0&#39;
> &#39;&#39; &#39;CONNECT&#39;
>
> and when I dial, I always get (from syslog):
> Jul 10 19:13:02 E10_semiosOffice local2.info chat[696]: send (ATDT*###^M)
> Jul 10 19:13:02 E10_semiosOffice local2.info chat[696]: send (CONNECT^M)
> Jul 10 19:13:02 E10_semiosOffice daemon.debug pppd[690]: Script /usr/sbin/chat -v -t6 -f /etc/ppp/peers/rogers_chat finished (pid 695), status = 0x0
> Jul 10 19:13:02 E10_semiosOffice daemon.info pppd[690]: Serial connection established.
> Jul 10 19:13:02 E10_semiosOffice daemon.debug pppd[690]: using channel 1
> Jul 10 19:13:02 E10_semiosOffice daemon.info pppd[690]: Using interface ppp0
> Jul 10 19:13:02 E10_semiosOffice daemon.notice pppd[690]: Connect: ppp0 &lt;--&gt; /dev/ttyUSB2
> Jul 10 19:13:03 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 &lt;asyncmap 0x0&gt; &lt;magic 0x51f07ab7&gt; &lt;pcomp&gt; &lt;accomp&gt;]
> Jul 10 19:13:06 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 &lt;asyncmap 0x0&gt; &lt;magic 0x51f07ab7&gt; &lt;pcomp&gt; &lt;accomp&gt;]
> Jul 10 19:13:09 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 &lt;asyncmap 0x0&gt; &lt;magic 0x51f07ab7&gt; &lt;pcomp&gt; &lt;accomp&gt;]
> Jul 10 19:13:12 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 &lt;asyncmap 0x0&gt; &lt;magic 0x51f07ab7&gt; &lt;pcomp&gt; &lt;accomp&gt;]
> Jul 10 19:13:15 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 &lt;asyncmap 0x0&gt; &lt;magic 0x51f07ab7&gt; &lt;pcomp&gt; &lt;accomp&gt;]
> Jul 10 19:13:18 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 &lt;asyncmap 0x0&gt; &lt;magic 0x51f07ab7&gt; &lt;pcomp&gt; &lt;accomp&gt;]
> Jul 10 19:13:21 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 &lt;asyncmap 0x0&gt; &lt;magic 0x51f07ab7&gt; &lt;pcomp&gt; &lt;accomp&gt;]
> Jul 10 19:13:25 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 &lt;asyncmap 0x0&gt; &lt;magic 0x51f07ab7&gt; &lt;pcomp&gt; &lt;accomp&gt;]
> Jul 10 19:13:28 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 &lt;asyncmap 0x0&gt; &lt;magic 0x51f07ab7&gt; &lt;pcomp&gt; &lt;accomp&gt;]
> Jul 10 19:13:31 E10_semiosOffice daemon.debug pppd[690]: sent [LCP ConfReq id=0x1 &lt;asyncmap 0x0&gt; &lt;magic 0x51f07ab7&gt; &lt;pcomp&gt; &lt;accomp&gt;]
> Jul 10 19:13:34 E10_semiosOffice daemon.warn pppd[690]: LCP: timeout sending Config-Requests
> Jul 10 19:13:34 E10_semiosOffice daemon.notice pppd[690]: Connection terminated.
> Jul 10 19:13:34 E10_semiosOffice daemon.warn pppd[690]: Receive serial link is not 8-bit clean:
> Jul 10 19:13:34 E10_semiosOffice daemon.warn pppd[690]: Problem: all had bit 7 set to 0
> Jul 10 19:13:35 E10_semiosOffice daemon.notice pppd[690]: Modem hangup
> Jul 10 19:13:35 E10_semiosOffice daemon.info pppd[690]: Exit.
>
> Why is this? What are these LCP messages?
> What am I doing wrong?
> Help, tips and suggestions would be appreciated!
>
> Thanks,
> Ron

Hi Moe,

Awesome and Thanks for this extensive explanation of things! You're a great ressource, Thanks very much!
I changed the chat script as you recommended to :
ABORT BUSY
ABORT ERROR
ABORT 'NO ANSWER'
ABORT 'NO CARRIER'
ABORT 'NO DIALTONE'
'' 'AT&FE0V1X1&D2&C1S0=0'
OK 'AT+CGDCONT=1,"IP","vpn.com"'
OK 'ATDT*###'
CONNECT '\d\c'

But now, the dial doesn't seem to work, look what I get in syslog:
Jul 11 17:37:38 E10_semiosOffice local2.info chat[14589]: abort on (BUSY)
Jul 11 17:37:38 E10_semiosOffice local2.info chat[14589]: abort on (ERROR)
Jul 11 17:37:38 E10_semiosOffice local2.info chat[14589]: abort on (NO ANSWER)
Jul 11 17:37:38 E10_semiosOffice local2.info chat[14589]: abort on (NO CARRIER)
Jul 11 17:37:38 E10_semiosOffice local2.info chat[14589]: abort on (NO DIALTONE)
Jul 11 17:37:38 E10_semiosOffice local2.info chat[14589]: send (AT&FE0V1X1&D2&C1S0=0^M)
Jul 11 17:37:39 E10_semiosOffice local2.info chat[14589]: expect (OK)
Jul 11 17:37:39 E10_semiosOffice local2.info chat[14589]: ^M
Jul 11 17:37:39 E10_semiosOffice local2.info chat[14589]: OK
Jul 11 17:37:39 E10_semiosOffice local2.info chat[14589]: -- got it
Jul 11 17:37:39 E10_semiosOffice local2.info chat[14589]: send (AT+CGDCONT=1,"IP","vpn.com"^M)
Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: expect (OK)
Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: ^M
Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: ^M
Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: OK
Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: -- got it
Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: send (ATDT*###^M)
Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: expect (CONNECT)
Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: ^M
Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: ^M
Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: ERROR
Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: -- failed
Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: Failed (ERROR)
Jul 11 17:37:40 E10_semiosOffice daemon.debug pppd[14585]: Script /usr/sbin/chat -v -t6 -f /etc/ppp/peers/rogers_chat finished (pid 14588), status = 0x5
Jul 11 17:37:40 E10_semiosOffice daemon.err pppd[14585]: Connect script failed
Jul 11 17:37:41 E10_semiosOffice daemon.info pppd[14585]: Exit.

cerr

unread,
Jul 11, 2012, 3:11:58 PM7/11/12
to
[snip]
Ok, I found some documentation from Sierra Wireless and looks like my dial command should be ATD*#99# but as an answer I get OK in stead of CONNECT.
I cxhanged my chat script accordingly and what I get now is:

Jul 11 19:16:10 E10_semiosOffice local2.info chat[813]: send (ATDT*#99#^M)
Jul 11 19:16:10 E10_semiosOffice local2.info chat[813]: expect (OK)
Jul 11 19:16:10 E10_semiosOffice local2.info chat[813]: ^M
Jul 11 19:16:10 E10_semiosOffice local2.info chat[813]: ^M
Jul 11 19:16:10 E10_semiosOffice local2.info chat[813]: OK
Jul 11 19:16:10 E10_semiosOffice local2.info chat[813]: -- got it
Jul 11 19:16:10 E10_semiosOffice local2.info chat[813]: send (\d)
Jul 11 19:16:11 E10_semiosOffice daemon.debug pppd[809]: Script /usr/sbin/chat -v -t6 -f /etc/ppp/peers/rogers_chat finished (pid 812), status = 0x0
Jul 11 19:16:11 E10_semiosOffice daemon.info pppd[809]: Serial connection established.
Jul 11 19:16:11 E10_semiosOffice daemon.debug pppd[809]: using channel 1
Jul 11 19:16:11 E10_semiosOffice daemon.info pppd[809]: Using interface ppp0
Jul 11 19:16:11 E10_semiosOffice daemon.notice pppd[809]: Connect: ppp0 <--> /dev/ttyUSB0
Jul 11 19:16:12 E10_semiosOffice daemon.debug pppd[809]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb1a39818> <pcomp> <accomp>]
Jul 11 19:16:15 E10_semiosOffice daemon.debug pppd[809]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb1a39818> <pcomp> <accomp>]
Jul 11 19:16:18 E10_semiosOffice daemon.debug pppd[809]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb1a39818> <pcomp> <accomp>]
Jul 11 19:16:21 E10_semiosOffice daemon.debug pppd[809]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb1a39818> <pcomp> <accomp>]
Jul 11 19:16:24 E10_semiosOffice daemon.debug pppd[809]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb1a39818> <pcomp> <accomp>]
Jul 11 19:16:27 E10_semiosOffice daemon.debug pppd[809]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb1a39818> <pcomp> <accomp>]
Jul 11 19:16:30 E10_semiosOffice daemon.debug pppd[809]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb1a39818> <pcomp> <accomp>]
Jul 11 19:16:33 E10_semiosOffice daemon.debug pppd[809]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb1a39818> <pcomp> <accomp>]
Jul 11 19:16:36 E10_semiosOffice daemon.debug pppd[809]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb1a39818> <pcomp> <accomp>]
Jul 11 19:16:39 E10_semiosOffice daemon.debug pppd[809]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb1a39818> <pcomp> <accomp>]
Jul 11 19:16:42 E10_semiosOffice daemon.warn pppd[809]: LCP: timeout sending Config-Requests
Jul 11 19:16:42 E10_semiosOffice daemon.notice pppd[809]: Connection terminated.
Jul 11 19:16:43 E10_semiosOffice daemon.notice pppd[809]: Modem hangup
Jul 11 19:16:43 E10_semiosOffice daemon.info pppd[809]: Exit.

So I'm basically back at square 1 :(

Moe Trin

unread,
Jul 11, 2012, 10:10:54 PM7/11/12
to
On Wed, 11 Jul 2012, in the Usenet newsgroup alt.os.linux, in article
<45a9131f-abb9-48c7...@googlegroups.com>, cerr wrote:

[including some of the previous message to add comments/explanations]

>I changed the chat script as you recommended to :

>But now, the dial doesn't seem to work, look what I get in syslog:

OK, this looks a bit more "normal" but notice the times

] '' 'AT&FE0V1X1&D2&C1S0=0'

wait for nothing, send the init string

>Jul 11 17:37:38 E10_semiosOffice local2.info chat[14589]: send
> (AT&FE0V1X1&D2&C1S0=0^M)

] OK 'AT+CGDCONT=1,"IP","vpn.com"'

when the modem replys, send next bit

>Jul 11 17:37:39 E10_semiosOffice local2.info chat[14589]: expect (OK)
>Jul 11 17:37:39 E10_semiosOffice local2.info chat[14589]: OK
>Jul 11 17:37:39 E10_semiosOffice local2.info chat[14589]: -- got it
>Jul 11 17:37:39 E10_semiosOffice local2.info chat[14589]: send
> (AT+CGDCONT=1,"IP","vpn.com"^M)

and so on - does that make a bit more sense?

>Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]:
> send (ATDT*###^M)
>Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: expect
> (CONNECT)
>Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: ^M
>Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: ^M
>Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: ERROR
>Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: -- failed
>Jul 11 17:37:40 E10_semiosOffice local2.info chat[14589]: Failed
> (ERROR)

Now what happened instead is that the modem responded with the word
"ERROR" , and the second abort string you set

] ABORT ERROR

says that if the modem returns this, it didn't like something, so
we're going to bail - and that indeed occurred. OK
In the Hayes language, this often means something like you sent an
unrecognized command, and this is the modem's way of saying "WTF???"

>Ok, I found some documentation from Sierra Wireless and looks like my
>dial command should be ATD*#99# but as an answer I get OK in stead of
>CONNECT.

Arrgggg... well, I told you that wireless modems don't follow
standards ;-) I must admit I've never heard of any modem reporting
a connection with that string - but let's see what happens:

>Jul 11 19:16:11 E10_semiosOffice daemon.debug pppd[809]: Script
> /usr/sbin/chat -v -t6 -f /etc/ppp/peers/rogers_chat finished (pid
> 812), status = 0x0

Minor comment - the "-t 6" says to allow a maximum of six seconds
between the "expect" line and the (hopefully) resulting "got it"
line. That worked OK here, but may occasionally run into the barbed
wire - just be aware of that possibility. What you'd then get is a
message saying "Chat Script Failed" and you'd have to notice that it's
a timeout issue (that is, the "expect" line, but no corresponding "got
it" within the allowed time).

>Jul 11 19:16:11 E10_semiosOffice daemon.info pppd[809]: Serial
> connection established.
>Jul 11 19:16:11 E10_semiosOffice daemon.debug pppd[809]: using channel
> 1
>Jul 11 19:16:11 E10_semiosOffice daemon.info pppd[809]: Using
> interface ppp0
>Jul 11 19:16:11 E10_semiosOffice daemon.notice pppd[809]: Connect:
> ppp0 <--> /dev/ttyUSB0
>Jul 11 19:16:12 E10_semiosOffice daemon.debug pppd[809]: sent [LCP
> ConfReq id=0x1 <asyncmap 0x0> <magic 0xb1a39818> <pcomp> <accomp>]

pppd is happy as a clam - chat handed it a "working" serial link, so
let's try to negotiate with the peer and get things to the next stage

>Jul 11 19:16:42 E10_semiosOffice daemon.warn pppd[809]: LCP: timeout
> sending Config-Requests
Jul 11 19:16:42 E10_semiosOffice daemon.notice pppd[809]: Connection
> terminated.
>Jul 11 19:16:43 E10_semiosOffice daemon.notice pppd[809]: Modem hangup
>Jul 11 19:16:43 E10_semiosOffice daemon.info pppd[809]: Exit.

and we see nothing back from the peer, and therefore bail

>So I'm basically back at square 1 :(

Actually, you're at step 2 - notice you don't see it complaining
about the serial link not being 8-bit clean, etc. The question now
becomes "what went wrong". I'm afraid I can't tell. What this
looks like is that the "peer" at the other end of the link didn't
like something you said - and all that might be is

'AT+CGDCONT=1,"IP","vpn.com"'
'ATD*#99#'

I'm not Rogers Canada, but that first one smells more or less correct,
and the second - no, I've no idea, but the "OK" response instead of
a "CONNECT" doesn't _feel_ right. Your "LCP ConfReq" stuff is about
as normal/generic as can be. OK, I see your later post to the
comp.protocols.ppp newsgroup, and you've got that mess fixed.

>Jul 11 21:22:08 E10_semiosOffice daemon.debug pppd[1236]: sent [LCP
> ConfReq id=0x1 <asyncmap 0x0> <magic 0x85f3960> <pcomp> <accomp>]
>Jul 11 21:22:08 E10_semiosOffice daemon.debug pppd[1236]: rcvd [LCP
> ConfAck id=0x1 <asyncmap 0x0> <magic 0x85f3960> <pcomp> <accomp>]

You say hello, and ask for normal stuff - the peer replies with an
OK - that's good

>Jul 11 21:22:09 E10_semiosOffice daemon.debug pppd[1236]: rcvd [LCP
> ConfReq id=0x1 <mru 1500> <asyncmap 0x0> <magic 0x0> <pcomp> <accomp>
> <auth pap>]
>Jul 11 21:22:09 E10_semiosOffice daemon.debug pppd[1236]: No auth is
> possible
>Jul 11 21:22:09 E10_semiosOffice daemon.debug pppd[1236]: sent [LCP
>ConfRej id=0x1 <auth pap>]

Peer says hello, standard type options, wants you to authenticate to
them using PAP - you decline - game ended right here.

1. Does /etc/ppp/pap-secrets exist and have the correct username and
password (see man pppd in "AUTHENTICATION" section)
2. Does pppd know the username to use? (man pppd "user" option)
3. Make sure you did NOT include the "refuse-pap" (might as well also
check for "require-chap" which might be equally fatal) anywhere.
Adding the 'dump' option will show what options are declared where.

Old guy
0 new messages