Re: strange PPP negotiation problem with GPRS mobile phone

Alessandro de Manzano <[email protected]>
Newsgroups gmane.os.freebsd.devel.mobile
Message-ID <[email protected]>
On Mon, Jun 30, 2003 at 12:44:51PM -0700, Doug White wrote:

> Quick analysis: It doesn't like something in the negotiation, since it
> rejects config attempts. Usually its supposed to tell you what it didn't
> like, but I'm not seeing that in the printout.

Ok, now after the kind help of Mr. Speyerer I've reached the following
phase:

Now PPP seems to negotiate some IP address, but after about a second it
still close the session...

Could someone, please, help me understanding what's wrong now according
to this log ? ;)


Many thanks forever :))



Jun 30 23:27:13 asusmobile ppp[274]: Phase: Using interface: tun0 
Jun 30 23:27:13 asusmobile ppp[274]: Phase: deflink: Created in closed state 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: default: ident user-ppp VERSION (built COMPILATIONDATE) 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: default: set device /dev/cuaa0 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: default: set speed 115200 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: default: set dial ABORT BUSY ABORT NO\sCARRIER TIMEOUT 5            "" AT OK-AT-OK ATE1Q0 OK \dATDT\T TIMEOUT 40 CONNECT 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: default: set timeout 180 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: default: enable dns 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: default: disable ipv6cp 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: default: disable mppe 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: vodagprs: set speed 57600 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: vodagprs: set dial ABORT BUSY ABORT NO\sCARRIER TIMEOUT 5            "" ATZ OK-AT-OK ATE1Q0 OK AT+CGDCONT=1,\"IP\",\"web.omnitel.it\",,0,0  OK  AT+CGQREQ=1,0,0,0,0,0  OK ATD*99***1#  TIMEOUT 85 CONNECT 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: vodagprs: set phone 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: vodagprs: set login 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: vodagprs: set authname 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: vodagprs: set authkey 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: vodagprs: set timeout 0 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: vodagprs: add default HISADDR 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: vodagprs: disable dns 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: vodagprs: disable vjcomp 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: vodagprs: disable deflate 
Jun 30 23:27:15 asusmobile ppp[274]: tun0: Command: vodagprs: disable protocomp 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Phase: PPP Started (background mode). 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Phase: bundle: Establish 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Phase: deflink: closed -> opening 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Phase: deflink: Connected! 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Phase: deflink: opening -> dial 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: deflink: Dial attempt 1 of 1 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Send: ATZ^M 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Expect(5): OK 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Received: ATZ^M^M 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Received: OK^M 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Send: ATE1Q0^M 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Expect(5): OK 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Received: ATE1Q0^M^M 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Received: OK^M 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Send: AT+CGDCONT=1,"IP","web.omnitel.it",,0,0^M 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Expect(5): OK 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Received: AT+CGDCONT=1,"IP","web.omnitel.it",,0,0^M^M 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Received: OK^M 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Send: AT+CGQREQ=1,0,0,0,0,0^M 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Expect(5): OK 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Received: AT+CGQREQ=1,0,0,0,0,0^M^M 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Received: OK^M 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Send: ATD*99***1#^M 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Expect(85): CONNECT 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Received: ATD*99***1#^M^M 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Chat: Received: CONNECT^M 
Jun 30 23:27:15 asusmobile ppp[275]: tun0: Phase: deflink: dial -> carrier 
Jun 30 23:27:16 asusmobile ppp[275]: tun0: Phase: deflink: /dev/cuaa0: CD detected 
Jun 30 23:27:16 asusmobile ppp[275]: tun0: Phase: deflink: carrier -> login 
Jun 30 23:27:16 asusmobile ppp[275]: tun0: Phase: deflink: login -> lcp 
Jun 30 23:27:16 asusmobile ppp[275]: tun0: LCP: FSM: Using "deflink" as a transport 
Jun 30 23:27:16 asusmobile ppp[275]: tun0: LCP: deflink: State change Initial --> Closed 
Jun 30 23:27:16 asusmobile ppp[275]: tun0: LCP: deflink: State change Closed --> Stopped 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP: deflink: LayerStart 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP: deflink: SendConfigReq(1) state = Stopped 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  ACFCOMP[2] 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  ACCMAP[6] 0x00000000 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  MRU[4] 1500 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  MAGICNUM[6] 0x570341ed 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP: deflink: State change Stopped --> Req-Sent 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP: deflink: RecvConfigRej(1) state = Req-Sent 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP: deflink: SendIdent(0) state = Req-Sent 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  MAGICNUM 570341ed 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  TEXT user-ppp 3.1 (built Jun 15 2003) 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  ACFCOMP[2] 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP: deflink: SendConfigReq(2) state = Req-Sent 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  ACCMAP[6] 0x00000000 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  MRU[4] 1500 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  MAGICNUM[6] 0x570341ed 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP: deflink: RecvConfigReq(32) state = Req-Sent 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  ACCMAP[6] 0x00000000 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  AUTHPROTO[4] 0xc023 (PAP) 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  MAGICNUM[6] 0x003aaa33 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP: deflink: SendConfigAck(32) state = Req-Sent 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  ACCMAP[6] 0x00000000 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  AUTHPROTO[4] 0xc023 (PAP) 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  MAGICNUM[6] 0x003aaa33 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP: deflink: State change Req-Sent --> Ack-Sent 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP: deflink: RecvConfigAck(2) state = Ack-Sent 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  ACCMAP[6] 0x00000000 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  MRU[4] 1500 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  MAGICNUM[6] 0x570341ed 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP: deflink: State change Ack-Sent --> Opened 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP: deflink: LayerUp 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP: deflink: SendIdent(1) state = Opened 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  MAGICNUM 570341ed 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: LCP:  TEXT user-ppp 3.1 (built Jun 15 2003) 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: Phase: bundle: Authenticate 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: Phase: deflink: his = PAP, mine = none 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: Phase: Pap Output:  ******** 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: Warning: Sending empty PAP authname! 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: Phase: Pap Input: SUCCESS () 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: CCP: FSM: Using "deflink" as a transport 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: CCP: deflink: State change Initial --> Closed 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: CCP: deflink: LayerStart. 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: CCP: deflink: SendConfigReq(1) state = Closed 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: CCP:  PRED1[2]  
Jun 30 23:27:17 asusmobile ppp[275]: tun0: CCP: deflink: State change Closed --> Req-Sent 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: Phase: deflink: lcp -> open 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: Phase: bundle: Network 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP: FSM: Using "deflink" as a transport 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP: deflink: State change Initial --> Closed 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP: deflink: LayerStart. 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP: deflink: SendConfigReq(1) state = Closed 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP:  IPADDR[6] 127.0.0.1 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP: deflink: State change Closed --> Req-Sent 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP: deflink: RecvConfigReq(33) state = Req-Sent 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP:  IPADDR[6] 192.168.100.101 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP:  COMPPROTO[6] 16 VJ slots with slot compression 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP: deflink: SendConfigAck(33) state = Req-Sent 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP:  IPADDR[6] 192.168.100.101 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP:  COMPPROTO[6] 16 VJ slots with slot compression 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP: deflink: State change Req-Sent --> Ack-Sent 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP: deflink: RecvConfigReq(33) state = Ack-Sent 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP:  IPADDR[6] 192.168.100.101 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP:  COMPPROTO[6] 16 VJ slots with slot compression 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP: deflink: SendConfigAck(33) state = Ack-Sent 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP:  IPADDR[6] 192.168.100.101 
Jun 30 23:27:17 asusmobile ppp[275]: tun0: IPCP:  COMPPROTO[6] 16 VJ slots with slot compression 
Jun 30 23:27:19 asusmobile ppp[275]: tun0: LCP: deflink: RecvTerminateReq(34) state = Opened 
Jun 30 23:27:19 asusmobile ppp[275]: tun0: LCP: deflink: LayerDown 
Jun 30 23:27:19 asusmobile ppp[275]: tun0: LCP: deflink: SendTerminateAck(34) state = Opened 
Jun 30 23:27:19 asusmobile ppp[275]: tun0: LCP: deflink: State change Opened --> Stopping 
Jun 30 23:27:19 asusmobile ppp[275]: tun0: CCP: deflink: State change Req-Sent --> Starting 
Jun 30 23:27:19 asusmobile ppp[275]: tun0: CCP: deflink: LayerFinish. 
Jun 30 23:27:19 asusmobile ppp[275]: tun0: CCP: deflink: State change Starting --> Initial 
Jun 30 23:27:19 asusmobile ppp[275]: tun0: Phase: deflink: open -> lcp 
Jun 30 23:27:19 asusmobile ppp[275]: tun0: IPCP: deflink: State change Ack-Sent --> Starting 
Jun 30 23:27:19 asusmobile ppp[275]: tun0: IPCP: deflink: LayerFinish. 
Jun 30 23:27:19 asusmobile ppp[275]: tun0: IPCP: Connect time: 2 secs: 0 octets in, 0 octets out 
Jun 30 23:27:19 asusmobile ppp[275]: tun0: IPCP: 0 packets in, 0 packets out 
Jun 30 23:27:19 asusmobile ppp[275]: tun0: IPCP:  total 0 bytes/sec, peak 0 bytes/sec on Mon Jun 30 23:27:17 2003 
Jun 30 23:27:19 asusmobile ppp[275]: tun0: IPCP: deflink: State change Starting --> Initial 
Jun 30 23:27:19 asusmobile ppp[275]: tun0: Phase: bundle: Terminate 
Jun 30 23:27:20 asusmobile ppp[275]: tun0: Phase: deflink: Carrier lost 
Jun 30 23:27:20 asusmobile ppp[275]: tun0: LCP: deflink: State change Stopping --> Starting 
Jun 30 23:27:20 asusmobile ppp[275]: tun0: LCP: deflink: LayerFinish 
Jun 30 23:27:20 asusmobile ppp[275]: tun0: LCP: deflink: State change Starting --> Initial 
Jun 30 23:27:20 asusmobile ppp[275]: tun0: Phase: deflink: Disconnected! 
Jun 30 23:27:20 asusmobile ppp[275]: tun0: Phase: deflink: lcp -> logout 
Jun 30 23:27:20 asusmobile ppp[275]: tun0: Phase: deflink: Disconnected! 
Jun 30 23:27:20 asusmobile ppp[275]: tun0: Phase: deflink: logout -> hangup 
Jun 30 23:27:20 asusmobile ppp[275]: tun0: Phase: deflink: Connect time: 5 secs: 240 octets in, 354 octets out 
Jun 30 23:27:20 asusmobile ppp[275]: tun0: Phase: deflink: 10 packets in, 11 packets out 
Jun 30 23:27:20 asusmobile ppp[275]: tun0: Phase:  total 118 bytes/sec, peak 133 bytes/sec on Mon Jun 30 23:27:18 2003 
Jun 30 23:27:21 asusmobile ppp[275]: tun0: Phase: deflink: hangup -> closed 
Jun 30 23:27:21 asusmobile ppp[275]: tun0: Phase: bundle: Dead 
Jun 30 23:27:21 asusmobile ppp[275]: tun0: Phase: PPP Terminated (normal). 
Jun 30 23:27:21 asusmobile ppp[274]: tun0: Phase: Parent: Child failed (errdead) 
Jun 30 23:27:21 asusmobile ppp[275]: tun0: Chat: Parent notified of failure 


-- 

bye!

Ale

_______________________________________________
[email protected] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-mobile
To unsubscribe, send any mail to "[email protected]"
lmpx.com only provides a reader for public news (NNTP) servers. It is not affiliated with the servers or forums shown here and is not responsible for the content of articles, which is written by their respective authors.