Cisco Support Community
cancel
Showing results for 
Search instead for 
Did you mean: 
Announcements

Welcome to Cisco Support Community. We would love to have your feedback.

For an introduction to the new site, click here. And see here for current known issues.

New Member

Callback to Windows98

Hello,

I have not found a solution regarding callback to Windows 98 and W2000. I have tested with Cisco 3640 with both 11.3 and 12.1 IOS. My error-messages is provided from a debug below. Is my problem related to bug CSCdj81013?

Aug 13 15:52:08.149: Modem 0/10 Mica: received dialstring 0230438

Aug 13 15:52:08.181: CSM: MODEM_REPORT from 2/0:30, call_id=0xA003, event=0x3, cause=0x0, dchan_idb=0x60FF0FC0

Aug 13 15:52:08.181: Modem 0/10 CSM: (CSM_PROC_OC_ISDN_PROCESSING_CALL)<--ISDN_BCHAN_ASSIGNED

Aug 13 15:52:08.213: Modem 0/10 Mica: in modem state CALL_SETUP

Aug 13 15:52:22.349: CSM: MODEM_REPORT from 2/0:30, call_id=0xA003, event=0x4, cause=0x0, dchan_idb=0x60FF0FC0

Aug 13 15:52:22.349: Modem 0/10 CSM: MODEM_REPORT rcvd DEV_CONNECTED for call_id 0xA003

Aug 13 15:52:22.349: Modem 0/10 CSM: (CSM_PROC_OC_ISDN_CONNECT_PENDING)<--ISDN_CONNECTED

Aug 13 15:52:22.393: Modem 0/10 Mica: in modem state CONNECT

Aug 13 15:52:29.709: Modem 0/10 Mica: in modem state LINK

Aug 13 15:52:33.973: Modem 0/10 Mica: in modem state TERMINATING

Aug 13 15:52:34.009: Modem 0/10 CSM: (CSM_PROC_WAIT_FOR_CARRIER)<--MODEM_DISCONNECTED

Aug 13 15:52:34.009: Modem 0/10 Mica: in modem state IDLE

Aug 13 15:52:34.013: Modem 0/10 CSM: (CSM_PROC_WAIT_FOR_CARRIER)<--QUEUED_DISCONNECT

Aug 13 15:52:34.037: Modem 0/10 Mica: DISCONNECT after 00:00:12, due to reason (0x6104) No end of answer-back tone.

Aug 13 15:52:34.249: Se2/0:30 LCP: State is Closed

Aug 13 15:52:34.249: Se2/0:30 PPP: Phase is DOWN

Aug 13 15:52:38.109: CHAT11: Timeout expecting: CONNECT

Aug 13 15:52:38.109: CHAT11: Chat script CALLMEBACK finished, status = Connection timed out; remote host not responding

Aug 13 15:52:38.109: TTY11: Line reset by "Callback Process"

Aug 13 15:52:38.109: TTY11: Modem: READY->HANGUP

Aug 13 15:52:39.069: TTY11: dropping DTR, hanging up

Aug 13 15:52:39.069: Modem 0/10 CSM: (CSM_PROC_IDLE)<--ASYNC_DTR_DOWN

Aug 13 15:52:39.069: tty11: Modem: HANGUP->IDLE

4 REPLIES
Cisco Employee

Re: Callback to Windows98

We need to see the following debug for a call to find the exact probelm.

debug modem

debug modem csm

debug callback

debug dialer

debug ppp authentication

debug ppp negotiation

debug ppp cbcp

term mon

Along with running config.

New Member

Re: Callback to Windows98

Hello,

The configuration is:

version 11.3

service timestamps debug datetime msec localtime

service timestamps log datetime msec localtime

service password-encryption

!

hostname pronova_3640

!

aaa new-model

aaa authentication login default tacacs+ enable local

aaa authentication ppp tacplus tacacs+

aaa authorization exec default if-authenticated tacacs+

aaa authorization network default tacacs+

aaa accounting network netuse start-stop tacacs+

enable secret 5 $1$LbRG$4JkzH614Ad26lcTr/cZd70

!

username dotcom password 7 15190A025621202D

memory-size iomem 15

ip subnet-zero

no ip source-route

no ip finger

ip host pix 172.26.1.2

ip host gts 213.187.208.253

ip name-server 213.187.209.252

virtual-profile aaa

isdn switch-type primary-net5

chat-script CALLBACK ABORT ERROR ABORT BUSY "" "AT" OK "ATDT \T" TIMEOUT 30 CONNECT \c

chat-script offhook "" "ATH1" OK \c

chat-script callme ABORT ERROR ABORT BUSY "" "ATZ" OK "ATDT \T" TIMEOUT 30 CONNECT \c

!

clock timezone MET 1

clock summer-time MET recurring last Sun Mar 2:00 last Sun Oct 2:00

!

!

controller E1 2/0

framing NO-CRC4

pri-group timeslots 1-31

!

!

process-max-time 200

!

interface Loopback0

ip address 172.26.200.254 255.255.255.0

ip broadcast-address 172.26.200.255

no ip directed-broadcast

!

interface FastEthernet1/0

no ip address

ip broadcast-address 10.10.10.255

no ip directed-broadcast

full-duplex

!

!

interface Serial2/0:15

description 0114424943

no ip address

no ip directed-broadcast

encapsulation ppp

isdn switch-type primary-net5

isdn incoming-voice modem

ppp authentication chap tacplus

!

interface Group-Async1

ip unnumbered Loopback0

no ip directed-broadcast

encapsulation ppp

ip tcp header-compression passive

async mode interactive

peer default ip address pool test

no cdp enable

ppp callback accept

ppp authentication chap tacplus

group-range 1 12

!

ip local pool test 172.26.200.200 172.26.200.253

tacacs-server host 172.26.0.10

tacacs-server key radiogold949

snmp-server community propub RO 10

snmp-server community propri RW 10

banner motd ^C

Welcome to "pronova_3640". Autherized personel only!

All login attempts are logged!^C

!

line con 0

transport input none

line 1 12

no flush-at-activation

autoselect during-login

autoselect ppp

script modem-off-hook offhook

script callback callme

modem InOut

transport preferred none

transport input all

transport output none

callback forced-wait 10

line aux 0

line vty 0 4

access-class 10 in

exec-timeout 5 0

!

ntp clock-period 17179758

ntp server 192.36.144.23

end

The debug is:

pronova_3640#

Aug 30 17:00:48.215: CSM: MODEM_REPORT from 2/0:3, call_id=0x1D, event=0x1, cause=0x0, dchan_idb=0x60FF0FC0

Aug 30 17:00:48.215: CSM: Next free modem = 0/4; statbits = 10020

Aug 30 17:00:48.215: Modem 0/4 CSM: modem is allocated, modems free=11

Aug 30 17:00:48.215: Modem 0/4 CSM: Incoming call from 11230426 to Unknown, id 0x1D

Aug 30 17:00:48.215: Modem 0/4 CSM: (CSM_PROC_IDLE)<--ISDN_CALL

Aug 30 17:00:48.303: CSM: MODEM_REPORT from 2/0:3, call_id=0x1D, event=0x4, cause=0x0, dchan_idb=0x60FF0FC0

Aug 30 17:00:48.303: Modem 0/4 CSM: MODEM_REPORT rcvd DEV_CONNECTED for call_id 0x1D

Aug 30 17:00:48.303: Modem 0/4 CSM: (CSM_PROC_MODEM_RESERVED)<--ISDN_CONNECTED

Aug 30 17:00:48.303: Modem 0/4 Mica: configured for Answer mode, with Null signaling, 0x0 tone detection.

Aug 30 17:00:48.471: Modem 0/4 Mica: in modem state CALL_SETUP

Aug 30 17:00:48.495: Modem 0/4 Mica: in modem state CONNECT

Aug 30 17:00:48.899: Modem 0/4 Mica: in modem state LINK

Aug 30 17:00:58.875: Modem 0/4 Mica: in modem state TRAINUP

Aug 30 17:01:00.943: Modem 0/4 Mica: in modem state EC_NEGOTIATING

Aug 30 17:01:01.371: Modem 0/4 CSM: (CSM_PROC_WAIT_FOR_CARRIER)<--MODEM_CONNECTED

Aug 30 17:01:01.371: Modem 0/4 Mica: in modem state STEADY

Aug 30 17:01:01.387: Modem 0/4 Mica: CONNECT at 33600/28800 (Tx/Rx), V34+, LAPM, V42bis

Aug 30 17:01:02.127: TTY5: DSR came up

Aug 30 17:01:02.127: tty5: Modem: IDLE->READY

Aug 30 17:01:02.135: TTY5: EXEC creation

Aug 30 17:01:04.583: TTY5: Autoselect(2) sample 7E

Aug 30 17:01:04.583: TTY5: Autoselect(2) sample 7EFF

Aug 30 17:01:04.583: TTY5: Autoselect(2) sample 7EFF7D

Aug 30 17:01:04.583: TTY5: Autoselect(2) sample 7EFF7D23

Aug 30 17:01:04.583: TTY5 Autoselect cmd: ppp negotiate

Aug 30 17:01:04.583: TTY5: EXEC creation

Aug 30 17:01:05.091: As5 LCP: I CONFREQ [Closed] id 2 len 23

Aug 30 17:01:05.091: As5 LCP: ACCM 0x000A0000 (0x0206000A0000)

Aug 30 17:01:05.091: As5 LCP: MagicNumber 0x008B5CD2 (0x0506008B5CD2)

Aug 30 17:01:05.091: As5 LCP: PFC (0x0702)

Aug 30 17:01:05.091: As5 LCP: ACFC (0x0802)

Aug 30 17:01:05.091: As5 LCP: Callback 6 (0x0D0306)

Aug 30 17:01:05.091: As5 LCP: Lower layer not up, Fast Starting

Aug 30 17:01:05.091: As5 PPP: Treating connection as a dedicated line

Aug 30 17:01:05.091: As5 PPP: Phase is ESTABLISHING, Active Open

Aug 30 17:01:05.091: Modem 0/4 Mica: PPP escape_map: Tx map = FFFFFFFF, Rx map = 0

Aug 30 17:01:05.091: As5 LCP: O CONFREQ [Closed] id 12 len 25

Aug 30 17:01:05.095: As5 LCP: ACCM 0x000A0000 (0x0206000A0000)

Aug 30 17:01:05.095: As5 LCP: AuthProto CHAP (0x0305C22305)

Aug 30 17:01:05.095: As5 LCP: MagicNumber 0x1BEBA0AA (0x05061BEBA0AA)

Aug 30 17:01:05.095: As5 LCP: PFC (0x0702)

Aug 30 17:01:05.095: As5 LCP: ACFC (0x0802)

Aug 30 17:01:05.095: As5 LCP: O CONFACK [REQsent] id 2 len 23

Aug 30 17:01:05.095: As5 LCP: ACCM 0x000A0000 (0x0206000A0000)

Aug 30 17:01:05.095: As5 LCP: MagicNumber 0x008B5CD2 (0x0506008B5CD2)

Aug 30 17:01:05.095: As5 LCP: PFC (0x0702)

Aug 30 17:01:05.095: As5 LCP: ACFC (0x0802)

Aug 30 17:01:05.095: As5 LCP: Callback 6 (0x0D0306)

Aug 30 17:01:05.095: %LINK-3-UPDOWN: Interface Async5, changed state to up

Aug 30 17:01:05.271: As5 LCP: I CONFACK [ACKsent] id 12 len 25

Aug 30 17:01:05.271: As5 LCP: ACCM 0x000A0000 (0x0206000A0000)

Aug 30 17:01:05.271: As5 LCP: AuthProto CHAP (0x0305C22305)

Aug 30 17:01:05.271: As5 LCP: MagicNumber 0x1BEBA0AA (0x05061BEBA0AA)

Aug 30 17:01:05.271: As5 LCP: PFC (0x0702)

Aug 30 17:01:05.271: As5 LCP: ACFC (0x0802)

Aug 30 17:01:05.271: As5 LCP: State is Open

Aug 30 17:01:05.271: Modem 0/4 Mica: PPP escape_map: Tx map = A0000, Rx map = 0

Aug 30 17:01:05.271: As5 MCB: Initialize

Aug 30 17:01:05.271: As5 MCB: Flush

Aug 30 17:01:05.271: As5 PPP: Phase is AUTHENTICATING, by this end

Aug 30 17:01:05.275: As5 CHAP: O CHALLENGE id 5 len 33 from "pronova_3640"

Aug 30 17:01:05.395: As5 CHAP: I RESPONSE id 5 len 25 from "roma"

Aug 30 17:01:05.803: As5 CHAP: O SUCCESS id 5 len 4

Aug 30 17:01:05.803: As5 MCB: Start

Aug 30 17:01:05.803: As5 MCB: User roma Callback Number - Server 0230426

Aug 30 17:01:05.803: As5 MCB: Newstate 0-INIT -> 2-WAIT_RESPONSE

Aug 30 17:01:05.803: Async5 PPP: O MCB Request(1) id 3 len 7

Aug 30 17:01:05.807: Async5 MCB: O 1 3 0 7 3 3 0

Aug 30 17:01:05.807: As5 MCB: O Request Id 3 Callback Type Server-Num delay 0

Aug 30 17:01:05.807: As5 PPP: Phase is CBCP

Aug 30 17:01:06.155: %LINEPROTO-5-UPDOWN: Line protocol on Interface Async5, changed state to up

Aug 30 17:01:07.135: Async5 PPP: I MCB Response(2) id 3 len 7

Aug 30 17:01:07.135: Async5 MCB: I 2 3 0 7 3 3 F

Aug 30 17:01:07.135: As5 MCB: Received response

Aug 30 17:01:07.135: As5 MCB: Response CBK-Server-Num 3 3 15

Aug 30 17:01:07.135: Async5 PPP: O MCB Ack(3) id 4 len 7

Aug 30 17:01:07.135: Async5 MCB: O 3 4 0 7 3 3 F

Aug 30 17:01:07.135: As5 MCB: O Ack Id 4 Callback Type Server-Num delay 15

Aug 30 17:01:07.135: As5 MCB: Negotiated MCB with peer

Aug 30 17:01:07.135: As5 MCB: Newstate 2-WAIT_RESPONSE -> 3-WAIT_TERMINATE

Aug 30 17:01:07.243: As5 LCP: I TERMREQ [Open] id 3 len 4

Aug 30 17:01:07.243: As5 LCP: O TERMACK [Open] id 3 len 4

Aug 30 17:01:07.243: As5 MCB: Peer terminating the link

Aug 30 17:01:07.243: As5 MCB: Newstate 3-WAIT_TERMINATE -> 5-WAIT_LINKDOWN

Aug 30 17:01:07.243: As5 PPP: Phase is TERMINATING

Aug 30 17:01:07.243: As5 MCB: Link terminated by peer, Callback Needed

Aug 30 17:01:07.243: As5 MCB: Newstate 5-WAIT_LINKDOWN -> 6-CALLING

Aug 30 17:01:07.243: As5 MCB: Initiate Callback for roma at 0230426 using Async

Aug 30 17:01:07.247: As5 MCB: Async-callback in progress

Aug 30 17:01:07.247: TTY5 Callback PPP process creation

Aug 30 17:01:07.247: As5 AAA/ACCT: Using PPP accounting list ""

Aug 30 17:01:07.247: TTY5 Callback process initiated, user: dialstring 0230426

Aug 30 17:01:07.455: Modem 0/4 Mica: in modem state TERMINATING

Aug 30 17:01:07.519: Modem 0/4 CSM: (CSM_PROC_CONNECTED)<--MODEM_DISCONNECTED

Aug 30 17:01:07.519: Modem 0/4 Mica: in modem state IDLE

Aug 30 17:01:07.519: Modem 0/4 CSM: (CSM_PROC_CONNECTED)<--QUEUED_DISCONNECT

Aug 30 17:01:07.547: Modem 0/4 Mica: DISCONNECT after 00:00:19, due to reason (0xA220) EC rcvd DISC frame.

Aug 30 17:01:07.735: Se2/0:3 LCP: State is Closed

Aug 30 17:01:07.735: Se2/0:3 PPP: Phase is DOWN

Aug 30 17:01:07.735: Serial2/0:3: disconnecting call

Aug 30 17:01:08.175: %LINEPROTO-5-UPDOWN: Line protocol on Interface Async5, changed state to down

Aug 30 17:01:09.247: TTY5: Async Int reset: Dropping DTR

Aug 30 17:01:09.247: Modem 0/4 CSM: (CSM_PROC_IDLE)<--ASYNC_DTR_DOWN

Aug 30 17:01:10.183: As5 LCP: TIMEout: Time 0xB702038 State TERMsent

Aug 30 17:01:10.183: As5 LCP: State is Closed

Aug 30 17:01:10.183: As5 PPP: Phase is DOWN

Aug 30 17:01:10.183: As5 PPP: Phase is ESTABLISHING, Passive Open

Aug 30 17:01:10.183: Modem 0/4 Mica: PPP escape_map: Tx map = FFFFFFFF, Rx map = 0

Aug 30 17:01:10.183: As5 LCP: State is Listen

Aug 30 17:01:11.247: %LINK-5-CHANGED: Interface Async5, changed state to reset

Aug 30 17:01:11.247: As5 LCP: State is Closed

Aug 30 17:01:11.247: As5 PPP: Phase is DOWN

Aug 30 17:01:11.251: As5 IPCP: Remove route to 172.26.200.224

Aug 30 17:01:14.247: Modem 0/4 CSM: (CSM_PROC_IDLE)<--ASYNC_DTR_DOWN

Aug 30 17:01:14.247: TTY5 Callback forced wait = 10 seconds

Aug 30 17:01:16.247: %LINK-3-UPDOWN: Interface Async5, changed state to down

Aug 30 17:01:16.247: As5 LCP: State is Closed

Aug 30 17:01:16.247: As5 PPP: Phase is DOWN

Aug 30 17:01:24.247: Modem 0/4 CSM: received ASYNC_DTR_UP for line 5

Aug 30 17:01:24.247: CHAT5: Asserting DTR

Aug 30 17:01:24.247: Modem 0/4 CSM: received ASYNC_DTR_UP for line 5

Aug 30 17:01:24.247: CHAT5: Chat script offhook started

Aug 30 17:01:24.283: CHAT5: Chat script offhook finished, status = Success

Aug 30 17:01:24.283: CHAT5: Asserting DTR

Aug 30 17:01:24.283: Modem 0/4 CSM: received ASYNC_DTR_UP for line 5

Aug 30 17:01:24.283: CHAT5: Chat script callme started

Aug 30 17:01:24.359: Modem 0/4 CSM: Called Number Rcvd = 0230426

Aug 30 17:01:24.359: Modem 0/4 CSM: (CSM_PROC_IDLE)<--MODEM_DIAL_OUT

Aug 30 17:01:24.359: Modem 0/4 Mica: configured for Originate mode, with Null signaling, 0x1 tone detection.

Aug 30 17:01:24.359: Modem 0/4 Mica: received dialstring 0230426

Aug 30 17:01:24.403: CSM: MODEM_REPORT from 2/0:30, call_id=0xA017, event=0x3, cause=0x0, dchan_idb=0x60FF0FC0

Aug 30 17:01:24.403: Modem 0/4 CSM: (CSM_PROC_OC_ISDN_PROCESSING_CALL)<--ISDN_BCHAN_ASSIGNED

Aug 30 17:01:24.455: Modem 0/4 Mica: in modem state CALL_SETUP

Aug 30 17:01:35.746: CSM: MODEM_REPORT from 2/0:30, call_id=0xA017, event=0x4, cause=0x0, dchan_idb=0x60FF0FC0

Aug 30 17:01:35.746: Modem 0/4 CSM: MODEM_REPORT rcvd DEV_CONNECTED for call_id 0xA017

Aug 30 17:01:35.746: Modem 0/4 CSM: (CSM_PROC_OC_ISDN_CONNECT_PENDING)<--ISDN_CONNECTED

Aug 30 17:01:35.786: Modem 0/4 Mica: in modem state CONNECT

Aug 30 17:01:43.834: Modem 0/4 Mica: in modem state LINK

Aug 30 17:01:48.098: Modem 0/4 Mica: in modem state TERMINATING

Aug 30 17:01:48.134: Modem 0/4 CSM: (CSM_PROC_WAIT_FOR_CARRIER)<--MODEM_DISCONNECTED

Aug 30 17:01:48.138: Modem 0/4 Mica: in modem state IDLE

Aug 30 17:01:48.138: Modem 0/4 CSM: (CSM_PROC_WAIT_FOR_CARRIER)<--QUEUED_DISCONNECT

Aug 30 17:01:48.162: Modem 0/4 Mica: DISCONNECT after 00:00:12, due to reason (0x6104) No end of answer-back tone.

Aug 30 17:01:48.346: Se2/0:30 LCP: State is Closed

Aug 30 17:01:48.346: Se2/0:30 PPP: Phase is DOWN

Aug 30 17:01:48.346: Serial2/0:30: disconnecting call

Aug 30 17:01:54.326: CHAT5: Chat script callme finished, status = Connection timed out; remote host not responding

Aug 30 17:01:54.326: TTY5 Callback process chat script fail status=Connection timed out; remote host not responding

Aug 30 17:01:54.326: TTY5: Line reset by "Callback Process"

Aug 30 17:01:54.326: TTY5: Modem: READY->HANGUP

Aug 30 17:01:55.214: TTY5: dropping DTR, hanging up

Aug 30 17:01:55.214: Modem 0/4 CSM: (CSM_PROC_IDLE)<--ASYNC_DTR_DOWN

Aug 30 17:01:55.214: tty5: Modem: HANGUP->IDLE

Aug 30 17:02:00.218: TTY5: restoring DTR

Aug 30 17:02:00.218: Modem 0/4 CSM: received ASYNC_DTR_UP for line 5

Bronze

Re: Callback to Windows98

Here is the problem:

Aug 30 17:01:43.834: Modem 0/4 Mica: in modem state LINK

Aug 30 17:01:48.098: Modem 0/4 Mica: in modem state TERMINATING

Aug 30 17:01:48.162: Modem 0/4 Mica: DISCONNECT after 00:00:12, due to reason (0x6104) No end of answer-back tone.

I would first suggest you upgrade the modem code, if not the IOS, to the latest to ensure this is not a modem bug on our end.

You can find out more info about this disconnect code here:

http://www.cisco.com/warp/public/76/mica-states-drs.html#MICA_DISCONNECT

New Member

Re: Callback to Windows98

This may sound a bit simplistic but have you tried changing the timeout parameter on your chat script from 30 to 60. I had this problem on a 2620 and solved it by increasing the timeout. Give it a try - can't hurt.

98
Views
4
Helpful
4
Replies