2010/5/24 J.C. Roberts <list-jcr@designtools.org>:
quoted text
> On Mon, 24 May 2010 00:00:07 +0200 patrick kristensen
> <kristensenpatrickv@gmail.com> wrote:
>> I have managed to get a working connection with the following script
>>
>>
>> /etc/ppp/ppp.conf
>>
>> default:
>>  set log Phase Chat LCP IPCP CCP tun command
>>  set device /dev/cuaU0
>>  set speed 460800
>>  set dial "ABORT BUSY ABORT NO\sCARRIER TIMEOUT 5 \"\" AT OK-AT-OK
>> ATE1Q0 OK \dATDT\T TIMEOUT 40 CONNECT"
>>
>> esp:
>>       set device /dev/cuaU0
>>       set speed 460800
>>       set timeout 0
>>       set dial "ABORT BUSY TIMEOUT 5 \
>>               \"\" \
>>               AT OK-AT-OK \
>>               AT+CPIN=\\"7291\\" OK-AT-OK \
>>               AT+CFUN=1 OK-AT-OK \
>>               AT+CGDCONT=1,\\"IP\\",\\"movistar.es\\" OK-AT-OK \
>>               \dATDT*99***1# TIMEOUT 30 CONNECT"
>>
>>
>>       set ifaddr 0 81.47.192.13 255.255.255.255
>>       add default HISADDR
>>       enable dns
>>
>> #     ./.
>>
>> Setting 'set ifaddr to 0.0.0.0/0 0.0.0.0/0 255.255.255.255' gave me an
>> ipadress to MYADDR but i did not get a route.
>> Setting 'set ifaddr 0.0.0.0/0 194.179.1.100 (which was DNS)
>> 255.255.255.255' made it possible to nslookup movistar.es.
>> After nslookup the APN and hardcoding the ip to HISADDR i got a
>> working connection.
>> The APN (Movistar (Telefonica) Spain) is correct
>> (http://www.vysoo.com/apn.php#415 and other sources). (I have not been
>> able to find other data networks for movistar as with your example
>> with Verizon)
>> This setup works so far (i can ping external addresses).
>> My understanding of ppp(8) is that it should have been enough to 'set
>> ifaddr 0 0 255.255.255.255 (0)' and 'add default HISADDR' (if the
>> CGDCONT is correct).
>> I appreciate any input on the script and log.
>
> It seems your routing is hosed. As the ppp(8) manual states, if you
> use "add" it will not overwrite your default route (typically stored
> in /etc/mygate). When you want to overwrite the default route, you need
> to use "add!" such as:
>
>    add! default HISADDR
>
> Typically, you want to overwrite the default route, but note, you'll
> probably see some harmless warnings for routes that ppp cannot
> overwrite (such as IPv6 when it's not supported by your provider).
>
> As for setting up the interface addresses, you should define all four
> parts, rather than defining only three as you have done above.
>
>    set ifaddr 10.0.0.1/0 10.0.0.2/0 0.0.0.0 0.0.0.0
>               part#1     part#2     part#3  part#4
>
> In your script above, your part#1 of "0" is *DEMANDING* that your
> address be 0.0.0.0/32 and nothing else, or in other words, you are
> *DEMANDING* that you become the default route for the remote system.
> Needless to say the remote system will just laugh at you and refuse
> to change it's default route (i.e. address your end as 0.0.0.0).
>
> Setting the netmask (part#3) to 0.0.0.0 forces ppp to assign an
> appropriate netmask. Since it is a point-to-point link and some
> operating systems/kernels do not understand a POINTTOPOINT netmask,
> you'll typically end up with 255.255.255.255 or 255.255.255.0 for the
> netmask of your tun0 interface *even* if the remote gateway address is
> outside of the netmask.
>
> Using part#4 is important. This the address you *SUGGEST* that your
> side should be, but you *DEMAND* your side gets and address defined by
> part#1 (the /0 netmask on part#1 says any IP address).
>
> Additionally, part#4 is also the "trigger" address when using '-auto'
> mode to connect or reconnect.
>
> Lastly, there's no point in defining 'device' 'speed' and 'dial' in the
> "default:" section of your config file since you are redefining them in
> the "esp:" section.
>
> Once you have the above corrected, look at your CHAP settings. Though
> you were able to negotiate IP addresses (according to the log), it
> seems your provider wanted to use CHAP authentication. If you made the
> previous corrections and you still cannot connect, then you may need
> to use CHAP:
>
>        set authname myusername
>        set authkey mypassword
>        set login
>
> Not all providers require PAP/CHAP authentication through 'authname'
> 'authkey' and 'login' because the real authentication is being done by
> device identifiers (MEID and/or IMEI).
>
>        jcr
>
> --
> The OpenBSD Journal - http://www.undeadly.org
>

I used the 'add! default' and the 'TRIGGER ADDR' in several attempts
but removed them when they didnt seem to change anything, however i
understand that they should be there.

Setting 'set ifaddr 0.0.0.0/0 0.0.0.0-255.255.255.254 0.0.0.0 0.0.0.0'
works however i can still not set HISADDR to '0.0.0.0/0' to get an
ipaddres offer to HISADDR. I assume setting a range has the same
affect as setting HISADDR with changeable bits but i dont understand
why 0.0.0.0/0 or any variation doesnt give me an address.

These set ifaddr does not work
0.0.0.0/0 0.0.0.0/0 0.0.0.0 0.0.0.0
0.0.0.0/0 0.0.0.0/32 0.0.0.0 0.0.0.0
0.0.0.0 0.0.0.0 0.0.0.0.0 0.0.0.0
0.0.0.0/0 0.0.0.0/0 0.0.0.0 0.0.0.0/0
etc

These works
0.0.0.0/0 81.47.192.13 0.0.0.0 0.0.0.0
0.0.0.0/0 0.0.0.0-255.255.255.254 0.0.0.0 0.0.0.0


/etc/ppp/ppp.conf

default:
 set log Phase Chat LCP IPCP CCP tun command

esp:
	set device /dev/cuaU0
	set speed 460800
	set timeout 0
	set authname movistar
	set authkey movistar
	set login
	set dial "ABORT BUSY TIMEOUT 5 \
		\"\" \
		AT OK-AT-OK \
		AT+CPIN=\\\"7291\\\" OK-AT-OK \
		AT+CFUN=1 OK-AT-OK \
		AT+CGDCONT=1,\\\"IP\\\",\\\"movistar.es\\\" OK-AT-OK \
		\\dATDT*99***1# TIMEOUT 30 CONNECT"


	set ifaddr 0.0.0.0/0 0.0.0.0-255.255.255.254 0.0.0.0 0.0.0.0
	add! default HISADDR
	enable dns

#	./.

/var/log/ppp.log

May 24 15:58:04 x200s ppp[1494]: Phase: Using interface: tun0
May 24 15:58:04 x200s ppp[1494]: Phase: deflink: Created in closed state
May 24 15:58:04 x200s ppp[1494]: tun0: Command: esp: set device /dev/cuaU0
May 24 15:58:04 x200s ppp[1494]: tun0: Command: esp: set speed 460800
May 24 15:58:04 x200s ppp[1494]: tun0: Command: esp: set timeout 0
May 24 15:58:04 x200s ppp[1494]: tun0: Command: esp: set authname movistar
May 24 15:58:04 x200s ppp[1494]: tun0: Command: esp: set authkey ********
May 24 15:58:04 x200s ppp[1494]: tun0: Command: esp: set login
May 24 15:58:04 x200s ppp[1494]: tun0: Command: esp: set dial ABORT
BUSY TIMEOUT 5 		"" 		AT OK-AT-OK 		AT+CPIN=\\"7291\\" OK-AT-OK
		AT+CFUN=1 OK-AT-OK 		AT+CGDCONT=1,\\"IP\\",\\"movistar.es\\"
OK-AT-OK 		\\dATDT*99***1# TIMEOUT 30 CONNECT
May 24 15:58:04 x200s ppp[1494]: tun0: Command: esp: set ifaddr
0.0.0.0/0 0.0.0.0-255.255.255.254 0.0.0.0 0.0.0.0
May 24 15:58:04 x200s ppp[1494]: tun0: IPCP: Selected IP address 88.161.80.31
May 24 15:58:04 x200s ppp[1494]: tun0: Command: esp: add default HISADDR
May 24 15:58:04 x200s ppp[1494]: tun0: Command: esp: enable dns
May 24 15:58:04 x200s ppp[6277]: tun0: Phase: PPP Started (auto mode).
May 24 15:58:04 x200s ppp[6277]: tun0: Phase: bundle: Establish
May 24 15:58:04 x200s ppp[6277]: tun0: Phase: deflink: closed -> opening
May 24 15:58:04 x200s ppp[6277]: tun0: Phase: deflink: Connected!
May 24 15:58:04 x200s ppp[6277]: tun0: Phase: deflink: opening -> dial
May 24 15:58:04 x200s ppp[6277]: tun0: Chat: deflink: Dial attempt 1 of 1
May 24 15:58:04 x200s ppp[6277]: tun0: Chat: Send: AT\^M
May 24 15:58:04 x200s ppp[6277]: tun0: Chat: Expect(5): OK
May 24 15:58:04 x200s ppp[6277]: tun0: Chat: Received: \^M
May 24 15:58:04 x200s ppp[6277]: tun0: Chat: Received: *EMRDY: 1\^M
May 24 15:58:04 x200s ppp[6277]: tun0: Chat: Received: AT\^M\^M
May 24 15:58:04 x200s ppp[6277]: tun0: Chat: Received: OK\^M
May 24 15:58:04 x200s ppp[6277]: tun0: Chat: Send: AT+CPIN="7291"\^M
May 24 15:58:04 x200s ppp[6277]: tun0: Chat: Expect(5): OK
May 24 15:58:05 x200s ppp[6277]: tun0: Chat: Received: AT+CPIN="7291"\^M\^M
May 24 15:58:05 x200s ppp[6277]: tun0: Chat: Received: OK\^M
May 24 15:58:05 x200s ppp[6277]: tun0: Chat: Send: AT+CFUN=1\^M
May 24 15:58:05 x200s ppp[6277]: tun0: Chat: Expect(5): OK
May 24 15:58:05 x200s ppp[6277]: tun0: Chat: Received: AT+CFUN=1\^M\^M
May 24 15:58:05 x200s ppp[6277]: tun0: Chat: Received: OK\^M
May 24 15:58:05 x200s ppp[6277]: tun0: Chat: Send:
AT+CGDCONT=1,"IP","movistar.es"\^M
May 24 15:58:05 x200s ppp[6277]: tun0: Chat: Expect(5): OK
May 24 15:58:06 x200s ppp[6277]: tun0: Chat: Received:
AT+CGDCONT=1,"IP","movistar.es"\^M\^M
May 24 15:58:06 x200s ppp[6277]: tun0: Chat: Received: OK\^M
May 24 15:58:06 x200s ppp[6277]: tun0: Chat: Send: ATDT*99***1#\^M
May 24 15:58:08 x200s ppp[6277]: tun0: Chat: Expect(30): CONNECT
May 24 15:58:08 x200s ppp[6277]: tun0: Chat: Received:
ATDT*99***1#\^M~\M^?}#\M-@!}!}!} }9}#}%\M-B#}%}(}"}'}"}"}&} } } }
}%}&\M-*\M-A&\M-KF\M-8~\^M
May 24 15:58:08 x200s ppp[6277]: tun0: Chat: Received: CONNECT\^M
May 24 15:58:08 x200s ppp[6277]: tun0: Phase: deflink: dial -> carrier
May 24 15:58:09 x200s ppp[6277]: tun0: Phase: deflink: carrier -> login
May 24 15:58:09 x200s ppp[6277]: tun0: Phase: deflink: login -> lcp
May 24 15:58:09 x200s ppp[6277]: tun0: LCP: FSM: Using "deflink" as a
transport
May 24 15:58:09 x200s ppp[6277]: tun0: LCP: deflink: State change
Initial --> Closed
May 24 15:58:09 x200s ppp[6277]: tun0: LCP: deflink: State change
Closed --> Stopped
May 24 15:58:09 x200s ppp[6277]: tun0: LCP: deflink: RecvConfigReq(2)
state = Stopped
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x05)
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  ACFCOMP[2]
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  PROTOCOMP[2]
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  ACCMAP[6] 0x00000000
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  MAGICNUM[6] 0xaac126cb
May 24 15:58:09 x200s ppp[6277]: tun0: LCP: deflink: SendConfigReq(1)
state = Stopped
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  ACFCOMP[2]
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  PROTOCOMP[2]
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  ACCMAP[6] 0x00000000
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  MRU[4] 1500
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  MAGICNUM[6] 0x2adc6148
May 24 15:58:09 x200s ppp[6277]: tun0: LCP: deflink: SendConfigAck(2)
state = Stopped
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x05)
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  ACFCOMP[2]
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  PROTOCOMP[2]
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  ACCMAP[6] 0x00000000
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  MAGICNUM[6] 0xaac126cb
May 24 15:58:09 x200s ppp[6277]: tun0: LCP: deflink: LayerStart
May 24 15:58:09 x200s ppp[6277]: tun0: LCP: deflink: State change
Stopped --> Ack-Sent
May 24 15:58:09 x200s ppp[6277]: tun0: LCP: deflink: RecvConfigReq(3)
state = Ack-Sent
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x05)
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  ACFCOMP[2]
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  PROTOCOMP[2]
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  ACCMAP[6] 0x00000000
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  MAGICNUM[6] 0xaac126cb
May 24 15:58:09 x200s ppp[6277]: tun0: LCP: deflink: SendConfigAck(3)
state = Ack-Sent
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x05)
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  ACFCOMP[2]
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  PROTOCOMP[2]
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  ACCMAP[6] 0x00000000
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  MAGICNUM[6] 0xaac126cb
May 24 15:58:09 x200s ppp[6277]: tun0: LCP: deflink: RecvConfigAck(1)
state = Ack-Sent
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  ACFCOMP[2]
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  PROTOCOMP[2]
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  ACCMAP[6] 0x00000000
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  MRU[4] 1500
May 24 15:58:09 x200s ppp[6277]: tun0: LCP:  MAGICNUM[6] 0x2adc6148
May 24 15:58:09 x200s ppp[6277]: tun0: LCP: deflink: State change
Ack-Sent --> Opened
May 24 15:58:09 x200s ppp[6277]: tun0: LCP: deflink: LayerUp
May 24 15:58:09 x200s ppp[6277]: tun0: Phase: bundle: Authenticate
May 24 15:58:09 x200s ppp[6277]: tun0: Phase: deflink: his = CHAP
0x05, mine = none
May 24 15:58:09 x200s ppp[6277]: tun0: Phase: Chap Input: CHALLENGE
(34 bytes from Kermit)
May 24 15:58:09 x200s ppp[6277]: tun0: Phase: Chap Output: RESPONSE
(movistar)
May 24 15:58:09 x200s ppp[6277]: tun0: Phase: Chap Input: SUCCESS
(Congratulations!)
May 24 15:58:18 x200s ppp[6277]: tun0: IPCP: Using trigger address 0.0.0.0
May 24 15:58:18 x200s ppp[6277]: tun0: CCP: FSM: Using "deflink" as a
transport
May 24 15:58:18 x200s ppp[6277]: tun0: CCP: deflink: State change
Initial --> Closed
May 24 15:58:18 x200s ppp[6277]: tun0: CCP: deflink: LayerStart.
May 24 15:58:18 x200s ppp[6277]: tun0: CCP: MPPE: Not usable without CHAP81
May 24 15:58:18 x200s ppp[6277]: tun0: CCP: deflink: SendConfigReq(1)
state = Closed
May 24 15:58:18 x200s ppp[6277]: tun0: CCP:  DEFLATE[4] win 15
May 24 15:58:18 x200s ppp[6277]: tun0: CCP:  PRED1[2]
May 24 15:58:18 x200s ppp[6277]: tun0: CCP: deflink: State change
Closed --> Req-Sent
May 24 15:58:18 x200s ppp[6277]: tun0: Phase: deflink: lcp -> open
May 24 15:58:18 x200s ppp[6277]: tun0: Phase: bundle: Network
May 24 15:58:18 x200s ppp[6277]: tun0: IPCP: FSM: Using "deflink" as a
transport
May 24 15:58:18 x200s ppp[6277]: tun0: IPCP: deflink: State change
Initial --> Closed
May 24 15:58:18 x200s ppp[6277]: tun0: IPCP: deflink: LayerStart.
May 24 15:58:18 x200s ppp[6277]: tun0: IPCP: deflink: SendConfigReq(1)
state = Closed
May 24 15:58:18 x200s ppp[6277]: tun0: IPCP:  IPADDR[6] 0.0.0.0
May 24 15:58:18 x200s ppp[6277]: tun0: IPCP:  COMPPROTO[6] 16 VJ slots
with slot compression
May 24 15:58:18 x200s ppp[6277]: tun0: IPCP:  PRIDNS[6] 80.58.61.250
May 24 15:58:18 x200s ppp[6277]: tun0: IPCP:  SECDNS[6] 255.255.255.255
May 24 15:58:18 x200s ppp[6277]: tun0: IPCP: deflink: State change
Closed --> Req-Sent
May 24 15:58:18 x200s ppp[6277]: tun0: LCP: deflink:
RecvProtocolRej(1) state = Opened
May 24 15:58:18 x200s ppp[6277]: tun0: LCP: deflink: -- Protocol
0x80fd (Compression Control Protocol) was rejected!
May 24 15:58:18 x200s ppp[6277]: tun0: CCP: deflink: State change
Req-Sent --> Stopped
May 24 15:58:21 x200s ppp[6277]: tun0: IPCP: deflink: SendConfigReq(1)
state = Req-Sent
May 24 15:58:21 x200s ppp[6277]: tun0: IPCP:  IPADDR[6] 0.0.0.0
May 24 15:58:21 x200s ppp[6277]: tun0: IPCP:  COMPPROTO[6] 16 VJ slots
with slot compression
May 24 15:58:21 x200s ppp[6277]: tun0: IPCP:  PRIDNS[6] 80.58.61.250
May 24 15:58:21 x200s ppp[6277]: tun0: IPCP:  SECDNS[6] 255.255.255.255
May 24 15:58:24 x200s ppp[6277]: tun0: IPCP: deflink: SendConfigReq(1)
state = Req-Sent
May 24 15:58:24 x200s ppp[6277]: tun0: IPCP:  IPADDR[6] 0.0.0.0
May 24 15:58:24 x200s ppp[6277]: tun0: IPCP:  COMPPROTO[6] 16 VJ slots
with slot compression
May 24 15:58:24 x200s ppp[6277]: tun0: IPCP:  PRIDNS[6] 80.58.61.250
May 24 15:58:24 x200s ppp[6277]: tun0: IPCP:  SECDNS[6] 255.255.255.255
May 24 15:58:27 x200s ppp[6277]: tun0: IPCP: deflink: SendConfigReq(1)
state = Req-Sent
May 24 15:58:27 x200s ppp[6277]: tun0: IPCP:  IPADDR[6] 0.0.0.0
May 24 15:58:27 x200s ppp[6277]: tun0: IPCP:  COMPPROTO[6] 16 VJ slots
with slot compression
May 24 15:58:27 x200s ppp[6277]: tun0: IPCP:  PRIDNS[6] 80.58.61.250
May 24 15:58:27 x200s ppp[6277]: tun0: IPCP:  SECDNS[6] 255.255.255.255
May 24 15:58:30 x200s ppp[6277]: tun0: IPCP: deflink: SendConfigReq(1)
state = Req-Sent
May 24 15:58:30 x200s ppp[6277]: tun0: IPCP:  IPADDR[6] 0.0.0.0
May 24 15:58:30 x200s ppp[6277]: tun0: IPCP:  COMPPROTO[6] 16 VJ slots
with slot compression
May 24 15:58:30 x200s ppp[6277]: tun0: IPCP:  PRIDNS[6] 80.58.61.250
May 24 15:58:30 x200s ppp[6277]: tun0: IPCP:  SECDNS[6] 255.255.255.255
May 24 15:58:34 x200s ppp[6277]: tun0: IPCP: deflink: LayerFinish.
May 24 15:58:34 x200s ppp[6277]: tun0: IPCP: Connect time: 16 secs: 0
octets in, 0 octets out
May 24 15:58:34 x200s ppp[6277]: tun0: IPCP: 0 packets in, 0 packets out
May 24 15:58:34 x200s ppp[6277]: tun0: IPCP:  total 0 bytes/sec, peak
0 bytes/sec on Mon May 24 15:58:18 2010
May 24 15:58:34 x200s ppp[6277]: tun0: IPCP: deflink: State change
Req-Sent --> Stopped
May 24 15:58:44 x200s ppp[6277]: tun0: IPCP: deflink: RecvConfigReq(1)
state = Stopped
May 24 15:58:44 x200s ppp[6277]: tun0: IPCP: 0.0.0.0: Address invalid
or already in use
May 24 15:58:53 x200s ppp[6277]: tun0: IPCP:   [EMPTY]
May 24 15:58:53 x200s ppp[6277]: tun0: IPCP: deflink: SendConfigReq(1)
state = Stopped
May 24 15:58:53 x200s ppp[6277]: tun0: IPCP:  IPADDR[6] 0.0.0.0
May 24 15:58:53 x200s ppp[6277]: tun0: IPCP:  COMPPROTO[6] 16 VJ slots
with slot compression
May 24 15:58:53 x200s ppp[6277]: tun0: IPCP:  PRIDNS[6] 80.58.61.250
May 24 15:58:53 x200s ppp[6277]: tun0: IPCP:  SECDNS[6] 255.255.255.255
May 24 15:58:53 x200s ppp[6277]: tun0: IPCP: deflink: SendConfigNak(1)
state = Stopped
May 24 15:58:53 x200s ppp[6277]: tun0: IPCP:  IPADDR[6] 88.161.80.31
May 24 15:58:53 x200s ppp[6277]: tun0: IPCP: deflink: LayerStart.
May 24 15:58:53 x200s ppp[6277]: tun0: IPCP: deflink: State change
Stopped --> Req-Sent
May 24 15:58:53 x200s ppp[6277]: tun0: IPCP: deflink: RecvConfigReq(2)
state = Req-Sent
May 24 15:58:53 x200s ppp[6277]: tun0: IPCP: 0.0.0.0: Address invalid
or already in use
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:   [EMPTY]
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: deflink: SendConfigNak(2)
state = Req-Sent
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:  IPADDR[6] 88.161.80.31
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: deflink: RecvConfigReq(3)
state = Req-Sent
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:   [EMPTY]
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: deflink: SendConfigAck(3)
state = Req-Sent
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:   [EMPTY]
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: deflink: State change
Req-Sent --> Ack-Sent
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: deflink: RecvConfigReq(4)
state = Ack-Sent
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:   [EMPTY]
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: deflink: SendConfigAck(4)
state = Ack-Sent
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:   [EMPTY]
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: deflink: RecvConfigReq(5)
state = Ack-Sent
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:   [EMPTY]
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: deflink: SendConfigAck(5)
state = Ack-Sent
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:   [EMPTY]
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: deflink: RecvConfigReq(6)
state = Ack-Sent
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:   [EMPTY]
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: deflink: SendConfigAck(6)
state = Ack-Sent
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:   [EMPTY]
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: deflink: RecvConfigReq(7)
state = Ack-Sent
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:   [EMPTY]
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: deflink: SendConfigAck(7)
state = Ack-Sent
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:   [EMPTY]
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: deflink: RecvConfigNak(1)
state = Ack-Sent
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:  IPADDR[6] 88.28.33.87
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:  IPADDR[6] changing
address: 0.0.0.0  --> 88.28.33.87
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:  PRIDNS[6] 80.58.4.97
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:  SECDNS[6] 80.58.61.250
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: Primary nameserver set to
80.58.4.97
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: Secondary nameserver set
to 80.58.61.250
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: deflink: SendConfigReq(2)
state = Ack-Sent
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:  IPADDR[6] 88.28.33.87
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:  COMPPROTO[6] 16 VJ slots
with slot compression
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:  PRIDNS[6] 80.58.4.97
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:  SECDNS[6] 80.58.61.250
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: deflink: RecvConfigAck(2)
state = Ack-Sent
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:  IPADDR[6] 88.28.33.87
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:  COMPPROTO[6] 16 VJ slots
with slot compression
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:  PRIDNS[6] 80.58.4.97
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP:  SECDNS[6] 80.58.61.250
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: deflink: State change
Ack-Sent --> Opened
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: deflink: LayerUp.
May 24 15:59:03 x200s ppp[6277]: tun0: IPCP: myaddr 88.28.33.87
hisaddr = 88.161.80.31
May 24 15:59:03 x200s ppp[6277]: tun0: Warning: 0.0.0.0: Change route
failed: errno: No such process
May 24 15:59:03 x200s ppp[6277]: tun0: Warning: ff01:6::: Change route
failed: errno: Network is unreachable
May 24 15:59:03 x200s ppp[6277]: tun0: Warning: ff02:6::: Change route
failed: errno: Network is unreachable
May 24 15:59:03 x200s ppp[6277]: tun0: Warning: ff02:6::: Change route
failed: errno: Network is unreachable



using HISADDR 0.0.0.0/0
/var/log/ppp.log

May 24 16:02:03 x200s ppp[18052]: Phase: Using interface: tun0
May 24 16:02:03 x200s ppp[18052]: Phase: deflink: Created in closed state
May 24 16:02:03 x200s ppp[18052]: tun0: Command: esp: set device /dev/cuaU0
May 24 16:02:03 x200s ppp[18052]: tun0: Command: esp: set speed 460800
May 24 16:02:03 x200s ppp[18052]: tun0: Command: esp: set timeout 0
May 24 16:02:03 x200s ppp[18052]: tun0: Command: esp: set authname movistar
May 24 16:02:03 x200s ppp[18052]: tun0: Command: esp: set authkey ********
May 24 16:02:03 x200s ppp[18052]: tun0: Command: esp: set login
May 24 16:02:03 x200s ppp[18052]: tun0: Command: esp: set dial ABORT
BUSY TIMEOUT 5 		"" 		AT OK-AT-OK 		AT+CPIN=\\"7291\\" OK-AT-OK
		AT+CFUN=1 OK-AT-OK 		AT+CGDCONT=1,\\"IP\\",\\"movistar.es\\"
OK-AT-OK 		\\dATDT*99***1# TIMEOUT 30 CONNECT
May 24 16:02:03 x200s ppp[18052]: tun0: Command: esp: set ifaddr
0.0.0.0/0 0.0.0.0/0 0.0.0.0 0.0.0.0
May 24 16:02:03 x200s ppp[18052]: tun0: Command: esp: add default HISADDR
May 24 16:02:03 x200s ppp[18052]: tun0: Command: esp: enable dns
May 24 16:02:03 x200s ppp[8641]: tun0: Phase: PPP Started (auto mode).
May 24 16:02:03 x200s ppp[8641]: tun0: Phase: bundle: Establish
May 24 16:02:03 x200s ppp[8641]: tun0: Phase: deflink: closed -> opening
May 24 16:02:03 x200s ppp[8641]: tun0: Phase: deflink: Connected!
May 24 16:02:03 x200s ppp[8641]: tun0: Phase: deflink: opening -> dial
May 24 16:02:03 x200s ppp[8641]: tun0: Chat: deflink: Dial attempt 1 of 1
May 24 16:02:03 x200s ppp[8641]: tun0: Chat: Send: AT\^M
May 24 16:02:03 x200s ppp[8641]: tun0: Chat: Expect(5): OK
May 24 16:02:03 x200s ppp[8641]: tun0: Chat: Received: \^M
May 24 16:02:03 x200s ppp[8641]: tun0: Chat: Received: *EMRDY: 1\^M
May 24 16:02:03 x200s ppp[8641]: tun0: Chat: Received: AT\^M\^M
May 24 16:02:03 x200s ppp[8641]: tun0: Chat: Received: OK\^M
May 24 16:02:03 x200s ppp[8641]: tun0: Chat: Send: AT+CPIN="7291"\^M
May 24 16:02:03 x200s ppp[8641]: tun0: Chat: Expect(5): OK
May 24 16:02:03 x200s ppp[8641]: tun0: Chat: Received: AT+CPIN="7291"\^M\^M
May 24 16:02:03 x200s ppp[8641]: tun0: Chat: Received: OK\^M
May 24 16:02:03 x200s ppp[8641]: tun0: Chat: Send: AT+CFUN=1\^M
May 24 16:02:03 x200s ppp[8641]: tun0: Chat: Expect(5): OK
May 24 16:02:03 x200s ppp[8641]: tun0: Chat: Received: AT+CFUN=1\^M\^M
May 24 16:02:03 x200s ppp[8641]: tun0: Chat: Received: OK\^M
May 24 16:02:03 x200s ppp[8641]: tun0: Chat: Send:
AT+CGDCONT=1,"IP","movistar.es"\^M
May 24 16:02:03 x200s ppp[8641]: tun0: Chat: Expect(5): OK
May 24 16:02:05 x200s ppp[8641]: tun0: Chat: Received:
AT+CGDCONT=1,"IP","movistar.es"\^M\^M
May 24 16:02:05 x200s ppp[8641]: tun0: Chat: Received: OK\^M
May 24 16:02:05 x200s ppp[8641]: tun0: Chat: Send: ATDT*99***1#\^M
May 24 16:02:07 x200s ppp[8641]: tun0: Chat: Expect(30): CONNECT
May 24 16:02:07 x200s ppp[8641]: tun0: Chat: Received:
ATDT*99***1#\^M~\M^?}#\M-@!}!}!} }9}#}%\M-B#}%}(}"}'}"}"}&} } } }
}%}&}6}^w\M-Y\M-Ww~\^M
May 24 16:02:07 x200s ppp[8641]: tun0: Chat: Received: CONNECT\^M
May 24 16:02:07 x200s ppp[8641]: tun0: Phase: deflink: dial -> carrier
May 24 16:02:08 x200s ppp[8641]: tun0: Phase: deflink: carrier -> login
May 24 16:02:08 x200s ppp[8641]: tun0: Phase: deflink: login -> lcp
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: FSM: Using "deflink" as a
transport
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink: State change
Initial --> Closed
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink: State change
Closed --> Stopped
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink: RecvConfigReq(2)
state = Stopped
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x05)
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  ACFCOMP[2]
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  PROTOCOMP[2]
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  ACCMAP[6] 0x00000000
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  MAGICNUM[6] 0x167e77d9
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink: SendConfigReq(1)
state = Stopped
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  ACFCOMP[2]
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  PROTOCOMP[2]
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  ACCMAP[6] 0x00000000
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  MRU[4] 1500
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  MAGICNUM[6] 0x0c1c002c
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink: SendConfigAck(2)
state = Stopped
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x05)
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  ACFCOMP[2]
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  PROTOCOMP[2]
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  ACCMAP[6] 0x00000000
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  MAGICNUM[6] 0x167e77d9
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink: LayerStart
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink: State change
Stopped --> Ack-Sent
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink: RecvConfigReq(3)
state = Ack-Sent
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x05)
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  ACFCOMP[2]
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  PROTOCOMP[2]
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  ACCMAP[6] 0x00000000
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  MAGICNUM[6] 0x167e77d9
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink: SendConfigAck(3)
state = Ack-Sent
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x05)
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  ACFCOMP[2]
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  PROTOCOMP[2]
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  ACCMAP[6] 0x00000000
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  MAGICNUM[6] 0x167e77d9
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink: RecvConfigAck(1)
state = Ack-Sent
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  ACFCOMP[2]
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  PROTOCOMP[2]
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  ACCMAP[6] 0x00000000
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  MRU[4] 1500
May 24 16:02:08 x200s ppp[8641]: tun0: LCP:  MAGICNUM[6] 0x0c1c002c
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink: State change
Ack-Sent --> Opened
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink: LayerUp
May 24 16:02:08 x200s ppp[8641]: tun0: Phase: bundle: Authenticate
May 24 16:02:08 x200s ppp[8641]: tun0: Phase: deflink: his = CHAP
0x05, mine = none
May 24 16:02:08 x200s ppp[8641]: tun0: Phase: Chap Input: CHALLENGE
(52 bytes from Kermit)
May 24 16:02:08 x200s ppp[8641]: tun0: Phase: Chap Output: RESPONSE
(movistar)
May 24 16:02:08 x200s ppp[8641]: tun0: Phase: Chap Input: SUCCESS
(Congratulations!)
May 24 16:02:08 x200s ppp[8641]: tun0: IPCP: Using trigger address 0.0.0.0
May 24 16:02:08 x200s ppp[8641]: tun0: CCP: FSM: Using "deflink" as a
transport
May 24 16:02:08 x200s ppp[8641]: tun0: CCP: deflink: State change
Initial --> Closed
May 24 16:02:08 x200s ppp[8641]: tun0: CCP: deflink: LayerStart.
May 24 16:02:08 x200s ppp[8641]: tun0: CCP: MPPE: Not usable without CHAP81
May 24 16:02:08 x200s ppp[8641]: tun0: CCP: deflink: SendConfigReq(1)
state = Closed
May 24 16:02:08 x200s ppp[8641]: tun0: CCP:  DEFLATE[4] win 15
May 24 16:02:08 x200s ppp[8641]: tun0: CCP:  PRED1[2]
May 24 16:02:08 x200s ppp[8641]: tun0: CCP: deflink: State change
Closed --> Req-Sent
May 24 16:02:08 x200s ppp[8641]: tun0: Phase: deflink: lcp -> open
May 24 16:02:08 x200s ppp[8641]: tun0: Phase: bundle: Network
May 24 16:02:08 x200s ppp[8641]: tun0: IPCP: FSM: Using "deflink" as a
transport
May 24 16:02:08 x200s ppp[8641]: tun0: IPCP: deflink: State change
Initial --> Closed
May 24 16:02:08 x200s ppp[8641]: tun0: IPCP: deflink: LayerStart.
May 24 16:02:08 x200s ppp[8641]: tun0: IPCP: deflink: SendConfigReq(1)
state = Closed
May 24 16:02:08 x200s ppp[8641]: tun0: IPCP:  IPADDR[6] 0.0.0.0
May 24 16:02:08 x200s ppp[8641]: tun0: IPCP:  COMPPROTO[6] 16 VJ slots
with slot compression
May 24 16:02:08 x200s ppp[8641]: tun0: IPCP:  PRIDNS[6] 80.58.61.250
May 24 16:02:08 x200s ppp[8641]: tun0: IPCP:  SECDNS[6] 255.255.255.255
May 24 16:02:08 x200s ppp[8641]: tun0: IPCP: deflink: State change
Closed --> Req-Sent
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink:
RecvProtocolRej(1) state = Opened
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink: -- Protocol
0x80fd (Compression Control Protocol) was rejected!
May 24 16:02:08 x200s ppp[8641]: tun0: CCP: deflink: State change
Req-Sent --> Stopped
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink:
RecvTerminateReq(1) state = Opened
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink: LayerDown
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink:
SendTerminateAck(1) state = Opened
May 24 16:02:08 x200s ppp[8641]: tun0: LCP: deflink: State change
Opened --> Stopping
May 24 16:02:08 x200s ppp[8641]: tun0: CCP: deflink: State change
Stopped --> Closed
May 24 16:02:08 x200s ppp[8641]: tun0: CCP: deflink: State change
Closed --> Initial
May 24 16:02:08 x200s ppp[8641]: tun0: Phase: deflink: open -> lcp
May 24 16:02:08 x200s ppp[8641]: tun0: Warning: ff01:6::: Change route
failed: errno: Network is unreachable
May 24 16:02:08 x200s ppp[8641]: tun0: Warning: ff02:6::: Change route
failed: errno: Network is unreachable
May 24 16:02:08 x200s ppp[8641]: tun0: Warning: ff02:6::: Change route
failed: errno: Network is unreachable
May 24 16:02:08 x200s ppp[8641]: tun0: IPCP: deflink: State change
Req-Sent --> Starting
May 24 16:02:08 x200s ppp[8641]: tun0: IPCP: deflink: LayerFinish.
May 24 16:02:08 x200s ppp[8641]: tun0: IPCP: Connect time: 0 secs: 0
octets in, 0 octets out
May 24 16:02:08 x200s ppp[8641]: tun0: IPCP: 0 packets in, 0 packets out
May 24 16:02:08 x200s ppp[8641]: tun0: IPCP:  total 0 bytes/sec, peak
0 bytes/sec on Mon May 24 16:02:08 2010
May 24 16:02:08 x200s ppp[8641]: tun0: IPCP: deflink: State change
Starting --> Initial
May 24 16:02:08 x200s ppp[8641]: tun0: Phase: bundle: Terminate
May 24 16:02:11 x200s ppp[8641]: tun0: LCP: deflink: LayerFinish
May 24 16:02:11 x200s ppp[8641]: tun0: LCP: deflink: State change
Stopping --> Stopped
May 24 16:02:11 x200s ppp[8641]: tun0: LCP: deflink: State change
Stopped --> Closed
May 24 16:02:11 x200s ppp[8641]: tun0: LCP: deflink: State change
Closed --> Initial
May 24 16:02:11 x200s ppp[8641]: tun0: Phase: deflink: Disconnected!
May 24 16:02:11 x200s ppp[8641]: tun0: Phase: deflink: lcp -> logout
May 24 16:02:11 x200s ppp[8641]: tun0: Phase: deflink: logout -> hangup
May 24 16:02:11 x200s ppp[8641]: tun0: Phase: deflink: Disconnected!
May 24 16:02:12 x200s ppp[8641]: tun0: Phase: deflink: Connect time: 9
secs: 346 octets in, 287 octets out
May 24 16:02:12 x200s ppp[8641]: tun0: Phase: deflink: 11 packets in,
8 packets out
May 24 16:02:12 x200s ppp[8641]: tun0: Phase:  total 70 bytes/sec,
peak 121 bytes/sec on Mon May 24 16:02:08 2010
May 24 16:02:12 x200s ppp[8641]: tun0: Phase: deflink: hangup -> closed
May 24 16:02:12 x200s ppp[8641]: tun0: Phase: bundle: Dead