3G config problem

ZhengWeiWei83103 · ‎08-19-2010

HI guys:

i have config the Cisco 881GC-W with PCEX-3G-HSPA card

i have not create the 3G connect to internet

here is debug :

debug ppp chat

debug ppp negotiation

3G_Test#ping 1.1.1.1

Type escape sequence to abort.
Sending 5, 100-byte ICMP Echos to 1.1.1.1, timeout is 2 seconds:
...
*Aug 19 08:43:01.659: CHAT3: Attempting async line dialer script
*Aug 19 08:43:01.659: CHAT3: Dialing using Modem script: gsm & System script: none
*Aug 19 08:43:01.659: CHAT3: process started
*Aug 19 08:43:01.659: CHAT3: Asserting DTR
*Aug 19 08:43:01.663: CHAT3: Chat script gsm started
*Aug 19 08:43:01.663: CHAT3: Sending string: ATDT#777
*Aug 19 08:43:01.663: CHAT3: Chat script gsm finished, status = Success.
*Aug 19 08:43:04.731: %LINK-3-UPDOWN: Interface Cellular0, changed state to up.
Success rate is 0 percent (0/5)
3G_Test#
*Aug 19 08:43:04.731: Ce0 PPP: Using dialer call direction
*Aug 19 08:43:04.731: Ce0 PPP: Treating connection as a callout
*Aug 19 08:43:04.731: Ce0 PPP: Session handle[27000040] Session id[22]
*Aug 19 08:43:04.731: Ce0 PPP: Phase is ESTABLISHING, Active Open
*Aug 19 08:43:04.731: Ce0 PPP: Authorization required
*Aug 19 08:43:04.731: Ce0 PPP: No remote authentication for call-out
*Aug 19 08:43:04.731: Ce0 LCP: O CONFREQ [Closed] id 211 len 20
*Aug 19 08:43:04.731: Ce0 LCP:    ACCM 0x000A0000 (0x0206000A0000)
*Aug 19 08:43:04.731: Ce0 LCP:    MagicNumber 0x2710E450 (0x05062710E450)
*Aug 19 08:43:04.731: Ce0 LCP:    PFC (0x0702)
*Aug 19 08:43:04.731: Ce0 LCP:    ACFC (0x0802)
*Aug 19 08:43:06.715: Ce0 LCP: Timeout: State REQsent
*Aug 19 08:43:06.715: Ce0 LCP: O CONFREQ [REQsent] id 212 len 20
*Aug 19 08:43:06.715: Ce0 LCP:    ACCM 0x000A0000 (0x0206000A0000)
*Aug 19 08:43:06.715: Ce0 LCP:    MagicNumber 0x2710E450 (0x05062710E450)
*Aug 19 08:43:06.715: Ce0 LCP:    PFC (0x0702)
*Aug 19 08:43:06.715: Ce0 LCP:    ACFC (0x0802)
*Aug 19 08:43:08.731: Ce0 LCP: Timeout: State REQsent
*Aug 19 08:43:08.731: Ce0 LCP: O CONFREQ [REQsent] id 213 len 20
*Aug 19 08:43:08.731: Ce0 LCP:    ACCM 0x000A0000 (0x0206000A0000)
*Aug 19 08:43:08.731: Ce0 LCP:    MagicNumber 0x2710E450 (0x05062710E450)
*Aug 19 08:43:08.731: Ce0 LCP:    PFC (0x0702)
*Aug 19 08:43:08.731: Ce0 LCP:    ACFC (0x0802)
*Aug 19 08:43:10.747: Ce0 LCP: Timeout: State REQsent
*Aug 19 08:43:10.747: Ce0 LCP: O CONFREQ [REQsent] id 214 len 20
*Aug 19 08:43:10.747: Ce0 LCP:    ACCM 0x000A0000 (0x0206000A0000)
*Aug 19 08:43:10.747: Ce0 LCP:    MagicNumber 0x2710E450 (0x05062710E450)
*Aug 19 08:43:10.747: Ce0 LCP:    PFC (0x0702)
*Aug 19 08:43:10.747: Ce0 LCP:    ACFC (0x0802)
*Aug 19 08:43:12.763: Ce0 LCP: Timeout: State REQsent
*Aug 19 08:43:12.763: Ce0 LCP: O CONFREQ [REQsent] id 215 len 20
*Aug 19 08:43:12.763: Ce0 LCP:    ACCM 0x000A0000 (0x0206000A0000)
*Aug 19 08:43:12.763: Ce0 LCP:    MagicNumber 0x2710E450 (0x05062710E450)
*Aug 19 08:43:12.763: Ce0 LCP:    PFC (0x0702)
*Aug 19 08:43:12.763: Ce0 LCP:    ACFC (0x0802)
*Aug 19 08:43:14.779: Ce0 LCP: Timeout: State REQsent
*Aug 19 08:43:14.779: Ce0 LCP: O CONFREQ [REQsent] id 216 len 20
*Aug 19 08:43:14.779: Ce0 LCP:    ACCM 0x000A0000 (0x0206000A0000)
*Aug 19 08:43:14.779: Ce0 LCP:    MagicNumber 0x2710E450 (0x05062710E450)
*Aug 19 08:43:14.779: Ce0 LCP:    PFC (0x0702)
*Aug 19 08:43:14.779: Ce0 LCP:    ACFC (0x0802)
*Aug 19 08:43:16.795: Ce0 LCP: Timeout: State REQsent
*Aug 19 08:43:16.795: Ce0 LCP: O CONFREQ [REQsent] id 217 len 20
*Aug 19 08:43:16.795: Ce0 LCP:    ACCM 0x000A0000 (0x0206000A0000)
*Aug 19 08:43:16.795: Ce0 LCP:    MagicNumber 0x2710E450 (0x05062710E450)
*Aug 19 08:43:16.795: Ce0 LCP:    PFC (0x0702)
*Aug 19 08:43:16.795: Ce0 LCP:    ACFC (0x0802)
*Aug 19 08:43:18.811: Ce0 LCP: Timeout: State REQsent
*Aug 19 08:43:18.811: Ce0 LCP: O CONFREQ [REQsent] id 218 len 20
*Aug 19 08:43:18.811: Ce0 LCP:    ACCM 0x000A0000 (0x0206000A0000)
*Aug 19 08:43:18.811: Ce0 LCP:    MagicNumber 0x2710E450 (0x05062710E450)
*Aug 19 08:43:18.811: Ce0 LCP:    PFC (0x0702)
*Aug 19 08:43:18.811: Ce0 LCP:    ACFC (0x0802)
*Aug 19 08:43:20.827: Ce0 LCP: Timeout: State REQsent
*Aug 19 08:43:20.827: Ce0 LCP: O CONFREQ [REQsent] id 219 len 20
*Aug 19 08:43:20.827: Ce0 LCP:    ACCM 0x000A0000 (0x0206000A0000)
*Aug 19 08:43:20.827: Ce0 LCP:    MagicNumber 0x2710E450 (0x05062710E450)
*Aug 19 08:43:20.827: Ce0 LCP:    PFC (0x0702)
*Aug 19 08:43:20.827: Ce0 LCP:    ACFC (0x0802)
*Aug 19 08:43:22.843: Ce0 LCP: Timeout: State REQsent
*Aug 19 08:43:22.843: Ce0 LCP: O CONFREQ [REQsent] id 220 len 20
*Aug 19 08:43:22.843: Ce0 LCP:    ACCM 0x000A0000 (0x0206000A0000)
*Aug 19 08:43:22.843: Ce0 LCP:    MagicNumber 0x2710E450 (0x05062710E450)
*Aug 19 08:43:22.843: Ce0 LCP:    PFC (0x0702)
*Aug 19 08:43:22.843: Ce0 LCP:    ACFC (0x0802)
*Aug 19 08:43:24.859: Ce0 LCP: Timeout: State REQsent
*Aug 19 08:43:24.859: Ce0 PPP: Sending Acct Event[Down] id[1A]
*Aug 19 08:43:24.859: Ce0 LCP: State is Closed
*Aug 19 08:43:24.859: Ce0 PPP: Phase is DOWN
*Aug 19 08:43:24.859: Ce0 LCP: State is Listen
*Aug 19 08:43:26.859: %LINK-5-CHANGED: Interface Cellular0, changed state to reset
*Aug 19 08:43:26.859: Ce0 LCP: State is Closed
*Aug 19 08:43:31.931: %LINK-3-UPDOWN: Interface Cellular0, changed state to down
3G_Test#
3G_Test#

it may be a ppp link problem,because Chat script gsm finished, status = Success,but i dont't understand why cell 0 didn't UP

here is my config:

chat-script gsm "" "ATDT#777"

interface Cellular0
ip address negotiated
ip nat outside
ip virtual-reassembly
encapsulation ppp
dialer in-band
dialer string gsm
dialer-group 1
async mode interactive
ppp chap hostname card
ppp chap password 0 card
ppp ipcp dns request

interface Vlan1
ip address 192.168.1.1 255.255.255.0
ip nat inside
ip virtual-reassembly
!
ip forward-protocol nd
ip route 0.0.0.0 0.0.0.0 Cellular0
ip http server
ip http secure-server
!
ip nat inside source list 1 interface Cellular0 overload
!
access-list 1 permit any
dialer-list 1 protocol ip list 1

control-plane
!
!
line con 0
no modem enable
line aux 0
line 2
no activation-character
no exec
transport preferred none
transport input all
line 3
script dialer gsm
no exec
line vty 0 4
login

anyone can help me ?thanks!

mavespig · ‎10-20-2010

Hi Weiwei,
hopefully you already solved your issue (as the original post is 3 months old), but for the sake of documentation:

What you can see in the PPP debugs is that IOS is sending packets to the modem (O CONFREQ) but there is no packet coming back.
It looks like there is no communication between modem and IOS.
Under the line 3, you have only "no exec" and the gsm chatscript.
I'd configure "modem inout" as well, to establish bidirectional communication.

For example:
line 3
 exec-timeout 0 0
 script dialer gsm
 login
 modem InOut
 no exec
 transport input all
 transport output all

Cheers
Marco

Gerald Krause · ‎11-10-2010

Hi,

I have not an solution but rather a similar problem with that kind of hardware (881GW with PCEX-3G-HSPA). I have a working config for only *one* successful 3G dial-in: after losing the established 3G connection (e.g. forcing a "clear int dial 1"), the router can not re-establish the 3G connection until I reboot the device. It seems that the communication between IOS and the modem is some kind of damaged:

Config:

=====

!
chat-script GSM "" AT OK "ATDT*99*1#"
!
interface Cellular0
no ip address
ip virtual-reassembly in
encapsulation ppp
dialer in-band
dialer pool-member 1
async mode interactive
no ppp lcp fast-start
!
!
interface Dialer1
ip address negotiated
encapsulation ppp
dialer pool 1
dialer idle-timeout 0
dialer string GSM
dialer-group 1
no ppp lcp fast-start
ppp chap refuse
ppp pap sent-username USER password TEST
!
ip route 0.0.0.0 0.0.0.0 Dialer1
!
dialer-list 1 protocol ip permit
!
line 3
exec-timeout 0 0
script dialer GSM
modem InOut
no exec
!

1st login - successful:

================

*Nov 10 16:28:40.955: Ce0 DDR: rotor dialout [best] least recent failure is also most recent failure
*Nov 10 16:28:40.955: Ce0 DDR: rotor dialout [best] trying untried dialout
*Nov 10 16:28:40.955: Ce0 DDR: rotor dialout [best] also has most recent failure
*Nov 10 16:28:40.955: Ce0 DDR: rotor dialout [best]
*Nov 10 16:28:40.955: Ce0 DDR: Dialing cause ip (s=10.98.3.10, d=17.72.255.12)
*Nov 10 16:28:40.955: Ce0 DDR: Attempting to dial GSM
*Nov 10 16:28:40.955: CHAT3: Attempting async line dialer script
*Nov 10 16:28:40.955: CHAT3: Dialing using Modem script: GSM & System script: none
*Nov 10 16:28:40.955: CHAT3: process started
*Nov 10 16:28:40.955: CHAT3: Asserting DTR
*Nov 10 16:28:40.959: CHAT3: Chat script GSM started
*Nov 10 16:28:40.959: CHAT3: Sending string: AT
*Nov 10 16:28:40.959: CHAT3: Expecting string: OK
*Nov 10 16:28:40.963: CHAT3: Completed match for expect: OK
*Nov 10 16:28:40.963: CHAT3: Sending string: ATDT*99*1#
*Nov 10 16:28:40.963: CHAT3: Chat script GSM finished, status = Success
*Nov 10 16:28:42.039: TTY3: no timer type 1 to destroy
*Nov 10 16:28:42.039: TTY3: no timer type 0 to destroy
*Nov 10 16:28:42.039: TTY3: no timer type 2 to destroy
*Nov 10 16:28:44.039: %LINK-3-UPDOWN: Interface Cellular0, changed state to up
*Nov 10 16:28:44.039: Ce0 DDR: Dialer statechange to up
*Nov 10 16:28:44.039: %DIALER-6-BIND: Interface Ce0 bound to profile Di1
*Nov 10 16:28:44.039: Ce0 DDR: Dialer call has been placed
*Nov 10 16:28:44.039: Ce0 PPP: Sending cstate UP notification
*Nov 10 16:28:44.039: Ce0 PPP: Processing CstateUp message
*Nov 10 16:28:44.067: PPP: Alloc Context [84DAA350]
*Nov 10 16:28:44.067: ppp1 PPP: Phase is ESTABLISHING
*Nov 10 16:28:44.067: ppp1 PPP: Using AAA Unique Id = D
*Nov 10 16:28:44.067: Ce0 PPP: Authorization required
*Nov 10 16:28:44.067: Ce0 PPP: Using dialer call direction
*Nov 10 16:28:44.067: Ce0 PPP: Treating connection as a callout
*Nov 10 16:28:44.067: Ce0 PPP: Session handle[FE000001] Session id[1]
*Nov 10 16:28:44.067: Ce0 LCP: Event[OPEN] State[Initial to Starting]
*Nov 10 16:28:44.071: Ce0 PPP: No remote authentication for call-out
*Nov 10 16:28:44.071: Ce0 LCP: O CONFREQ [Starting] id 1 len 20
*Nov 10 16:28:44.071: Ce0 LCP:    ACCM 0x000A0000 (0x0206000A0000)
*Nov 10 16:28:44.071: Ce0 LCP:    MagicNumber 0x4C781BD5 (0x05064C781BD5)
*Nov 10 16:28:44.071: Ce0 LCP:    PFC (0x0702)
*Nov 10 16:28:44.071: Ce0 LCP:    ACFC (0x0802)
*Nov 10 16:28:44.071: Ce0 LCP: Event[UP] State[Starting to REQsent]
*Nov 10 16:28:44.079: Ce0 LCP: I CONFACK [REQsent] id 1 len 20
*Nov 10 16:28:44.079: Ce0 LCP:    ACCM 0x000A0000 (0x0206000A0000)
*Nov 10 16:28:44.079: Ce0 LCP:    MagicNumber 0x4C781BD5 (0x05064C781BD5)
*Nov 10 16:28:44.079: Ce0 LCP:    PFC (0x0702)
*Nov 10 16:28:44.079: Ce0 LCP:    ACFC (0x0802)

...

*Nov 10 16:28:47.971: Ce0 IPCP: O CONFREQ [ACKsent] id 4 len 10
*Nov 10 16:28:47.971: Ce0 IPCP: Address 10.99.17.58 (0x03060A63113A)
*Nov 10 16:28:47.971: Ce0 IPCP: Event[Receive ConfNak/Rej] State[ACKsent to ACKsent]
*Nov 10 16:28:48.027: Ce0 IPCP: I CONFACK [ACKsent] id 4 len 10
*Nov 10 16:28:48.027: Ce0 IPCP: Address 10.99.17.58 (0x03060A63113A)
*Nov 10 16:28:48.027: Ce0 IPCP: Event[Receive ConfAck] State[ACKsent to Open]
*Nov 10 16:28:48.027: Ce0 IPCP: State is Open
*Nov 10 16:28:48.027: Di1 IPCP: Install negotiated IP interface address 10.99.17.58
*Nov 10 16:28:48.031: Ce0 DDR: dialer protocol up1#

--> Now I do a "clear int dial 1":

2nd and all further logins - failure:

========================

*Nov 10 17:37:53.467: Ce0 DDR: rotor dialout [best] least recent failure is also most recent failure
*Nov 10 17:37:53.467: Ce0 DDR: rotor dialout [best] also has most recent failure
*Nov 10 17:37:53.467: Ce0 DDR: rotor dialout [best]
*Nov 10 17:37:53.467: Ce0 DDR: Dialing cause ip (s=10.98.3.10, d=10.99.16.254)
*Nov 10 17:37:53.467: Ce0 DDR: Attempting to dial GSM
*Nov 10 17:37:53.467: CHAT3: Attempting async line dialer script
*Nov 10 17:37:53.467: CHAT3: Dialing using Modem script: GSM & System script: none
*Nov 10 17:37:53.471: CHAT3: process started
*Nov 10 17:37:53.471: CHAT3: Asserting DTR
*Nov 10 17:37:53.471: CHAT3: Chat script GSM started
*Nov 10 17:37:53.475: CHAT3: Sending string: AT
*Nov 10 17:37:53.475: CHAT3: Expecting string: OK
*Nov 10 17:37:58.475: CHAT3: Timeout expecting: OK
*Nov 10 17:37:58.475: CHAT3: Chat script GSM finished, status = Connection timed out; remote host not responding
*Nov 10 17:37:58.475: TTY3: Line reset by "Async dialer"
*Nov 10 17:37:58.475: Ce0 DDR: disconnecting call
*Nov 10 17:37:58.475: TTY3: dropping DTR
*Nov 10 17:37:59.475: TTY3: asserting DTR
*Nov 10 17:37:59.475: TTY3: Modem: (unknown)->READY

Maybe somone has some clue how this can happen?

--

Gerald

Gerald Krause · ‎11-10-2010

(probably solved)

After some more time of testing and debugging it seems to be a timing problem. When changing the chat-script from

!

chat-script GSM "" AT OK "ATDT*99*1#"
!

to

!

chat-script GSM ABORT ERROR ABORT BUSY ABORT "NO ANSWER" "" AT OK "ATDT*99*1#" TIMEOUT 30 CONNECT

!

the router is now able to re-establish the 3G connection after any loss of 3G connectivity. So maybe the missing wait time for the CONNECT answer was the problem with my first chat-script what probably makes the system start further steps a little bit early and hence confuse the system.

--

Gerald

mavespig · ‎11-11-2010

Hi Gerald,

yes in your case you are missing the timeout on the chat script.

When IOS sends the chatscript to the modem, it waits to receive an OK back. This usually happens quickly, in some cases it may take a bit more.

I always use one of the following scripts:

- chat-script gsm "" "ATDT*99#" TIMEOUT 60 "CONNECT" <<< this will use the default profile (i.e. profile 1)

- chat-script gsm-profile "" "ATDT*98*2#" TIMEOUT 60 "CONNECT" <<< this will use a specific profile (e.g. *98*4# for profile 4)

Cheers

Marco

Gerald Krause · ‎11-13-2010

Hi Marco,

thx, I found so many 3G/cellular examples which don't wait for the CONNECT string but now I'am a little bite more sensitized concerning the use of AT commands .

--

Gerald