Callback Cisco 3640 and Radius help !!!

Unanswered Question

Hi ,


I have a cisco3640 with four bri and 6 digital modems . All dialin users will authorize at the MS IAS Server. The callback to a async modem works fine , but the callback to ISDN failed.


here the debug:



00:54:43: TTY130: Line reset by "Virtual Exec"

00:54:43: TTY130: Modem: (unknown)->READY

00:54:43: TTY130: no timer type 0 to destroy

00:54:43: TTY130: destroy timer type 1

00:54:43: TTY130: no timer type 3 to destroy

00:54:43: TTY130: no timer type 4 to destroy

00:54:43: TTY130: no timer type 2 to destroy

00:54:48: ISDN BR3/1: RX <- DISCONNECT pd = 8 callref = 0x01

00:54:48: Cause i = 0x8090 - Normal call clearing

00:54:48: Facility i = 0x91A11302020E3E020122300AA1053003020100820101

00:54:48: - ETSI Supplementary Service, Invoke, AOC-D Charging Units: 0

00:54:48: Progress Ind i = 0x8288 - In-band info or appropriate now avai

lable

00:54:48: CCBRI_Go Fr L3 pkt (Len=36) :

00:54:48: 45 1 81 96 8 2 80 90 1C 16 91 A1 13 2 2 E 3E 2 1 22 30 A A1 5 30 3 2 1

0 82 1 1 1E 2 82 88

00:54:48:

00:54:48: ISDN BR3/1: LIF_EVENT: ces/callid 1/0x19 HOST_FACILITY_INVOKE

00:54:48: BRI3/1:2: AOC-D Recorded Units = 0

00:54:48: ISDN BR3/1: LIF_EVENT: ces/callid 1/0x19 HOST_DISCONNECT

00:54:48: ISDN BR3/1: Event: Call to <unknown> was hung up.

00:54:48: ISDN BR3/1: process_disc_ack(): call id 0x19, ces 1, call type VOICE c

ause 0x0

Sep 27 12:04:14: %ISDN-6-DISCONNECT: Interface BRI3/1:2 disconnected from 00228

550592107 , call lasted 76 seconds

00:54:48: ISDN: get_isdn_service_state(): idb 0x6136768C bchan 3 is_isdn 1 Not a

Pri

00:54:48: CCBRI_Go Fr Host InPkgInfo (Len=10) :

00:54:48: 6 19 1 0 19 0 8 2 0 8

00:54:48:

00:54:48: ISDN BR3/1: TX -> RELEASE pd = 8 callref = 0x81

00:54:48: Cause i = 0x8090 - Normal call clearing

00:54:48: Modem 1/3 Mica: in modem state TERMINATING

00:54:48: Modem 1/3 Mica: in modem state IDLE

00:54:48: ISDN BR3/1: VOICE_HANGUP Event: call id 0x19, bchan 1, ces 1, cause 0x

10

00:54:48: ISDN BR3/1: Event: Voice hangup call to call id 0x19

00:54:48: Modem 1/3 Mica: DISCONNECT after 00:01:15, due to reason (0xDF06) DS1

network disconnect (no carrier).

00:54:48: ISDN BR3/1: RX <- RELEASE_COMP pd = 8 callref = 0x01

00:54:48: CCBRI_Go Fr L3 pkt (Len=4) :

00:54:48: 5A 1 81 99

00:54:48:

00:54:48: ISDN BR3/1: LIF_EVENT: ces/callid 1/0x19 HOST_DISCONNECT_ACK

00:54:49: ISDN: get_isdn_service_state(): idb 0x6136768C bchan 3 is_isdn 1 Not a

Pri

00:54:49: ISDN BR3/1: HOST_DISCONNECT_ACK: call type is VOICE

00:54:49: ISDN BR3/1: HOST_DISCONNECT_ACK: VOICE ERROR: NULL VDEV Common(0xFC):

bchan 1, call id 19

00:54:49: TTY36: DSR was dropped

00:54:49: tty36: Modem: READY->(unknown)

Sep 27 12:04:14: %LINEPROTO-5-UPDOWN: Line protocol on Interface Async36, change

d state to down

00:54:50: TTY36: dropping DTR, hanging up

00:54:50: TTY36: Async Int reset: Dropping DTR

00:54:50: tty36: Modem: HANGUP->(unknown)

00:54:51: TTY36: cleanup pending. Delaying DTR

Sep 27 12:04:17: %LINK-5-CHANGED: Interface Async36, changed state to reset

00:54:52: TTY36: cleanup pending. Delaying DTR

00:54:53: TTY36: cleanup pending. Delaying DTR

00:54:54: TTY36: cleanup pending. Delaying DTR

00:54:55: TTY36: no timer type 0 to destroy

00:54:55: TTY36: no timer type 1 to destroy

00:54:55: TTY36: no timer type 3 to destroy

00:54:55: TTY36: no timer type 4 to destroy

00:54:55: TTY36: no timer type 2 to destroy

00:54:55: Async36: allowing modem_process to continue hangup

00:54:55: TTY36: restoring DTR

00:54:55: TTY36: autoconfigure probe started

Sep 27 12:04:22: %LINK-3-UPDOWN: Interface Async36, changed state to down

00:54:58: ISDN BR3/0: RX <- SETUP pd = 8 callref = 0x01

00:54:58: Sending Complete

00:54:58: Bearer Capability i = 0x8890

00:54:58: Channel ID i = 0x8A

00:54:58: Calling Party Number i = 0x0083, '00228550592107', Plan:Unknow

n, Type:Unknown

00:54:58: Called Party Number i = 0x81, '711', Plan:ISDN, Type:Unknown

00:54:58: CCBRI_Go Fr L3 pkt (Len=36) :

00:54:58: 5 1 81 90 A1 4 2 88 90 18 1 8A 6C 10 0 83 30 30 32 32 38 35 35 30 35 3

9 32 31 30 37 70 4 81 37 31 31

00:54:58:

00:54:58: ISDN BR3/0: Incoming call id = 0x001A, dsl 24

00:54:58: ISDN BR3/0: LIF_EVENT: ces/callid 1/0x1A HOST_INCOMING_CALL

00:54:58: ISDN BR3/0: HOST_INCOMING_CALL: (non-POTS) DATA

00:54:58: ISDN BR3/0: HOST_INCOMING_CALL: (1) call_type = DATA

00:54:58: ISDN BR3/0: HOST_INCOMING_CALL: voice_answer_data = FALSE call type is

DATA

00:54:58: ISDN BR3/0: Event: Received a DATA call from 00228550592107 on B2 at 6

4 Kb/s

00:54:58: ISDN BR3/0: Event: Accepting the call id 0x1A

00:54:58: BR3/0:2 MCB: Initialize

Sep 27 12:04:24: %DIALER-6-BIND: Interface BR3/0:2 bound to profile Di1

00:54:58: ISDN BR3/0: RM returned call_type 0 resource type 0 response 2

00:54:58: CCBRI_Go Fr Host InPkgInfo (Len=9) :

00:54:58: 7 18 1 0 1A 3 18 1 8A

00:54:58:

00:54:58: ISDN BR3/0: isdn_send_connect(): msg 4, call id 0x1A, ces 1 bchan 1, c

all type DATA

Sep 27 12:04:24: %LINK-3-UPDOWN: Interface BRI3/0:2, changed state to up

00:54:58: ISDN: get_isdn_service_state(): idb 0x613270AC bchan 3 is_isdn 1 Not a

Pri

00:54:58: CCBRI_Go Fr Host InPkgInfo (Len=6) :

00:54:58: 4 18 1 0 1A 0

00:54:58:

00:54:58: ISDN BR3/0: TX -> CALL_PROC pd = 8 callref = 0x81

00:54:58: Channel ID i = 0x8A

00:54:58: ISDN BR3/0: TX -> CONNECT pd = 8 callref = 0x81

00:54:58: ISDN BR3/0: RX <- CONNECT_ACK pd = 8 callref = 0x01

00:54:58: Channel ID i = 0x8A

00:54:58: CCBRI_Go Fr L3 pkt (Len=7) :

00:54:58: F 1 81 92 18 1 8A

00:54:58:

00:54:58: ISDN BR3/0: LIF_EVENT: ces/callid 1/0x1A HOST_CONNECT

00:54:58: ISDN BR3/0: Event: Connected to 00228550592107 on B2 at 64 Kb/s

00:54:59: BR3/0:2 MCB: Initialize

00:54:59: BR3/0:2 MCB: Flush

00:54:59: RADIUS/ENCODE(00000001): acct_session_id: 6

00:54:59: RADIUS(00000001): sending

00:54:59: RADIUS: Send to unknown id 12 10.1.2.1:1812, Access-Request, len 150

00:54:59: RADIUS: authenticator 26 A0 60 5E 0C A4 33 95 - 00 00 00 00 00 00 00

00

00:54:59: RADIUS: Framed-Protocol [7] 6 PPP [1]

00:54:59: RADIUS: User-Name [1] 5 (delete)

00:54:59: RADIUS: Vendor, Microsoft [26] 16

00:54:59: RADIUS: MSCHAP_Challenge [11] 10

00:54:59: RADIUS: 26 A0 60 5E 0C A4 [&?`^??]

00:54:59: RADIUS: Vendor, Microsoft [26] 58

00:54:59: RADIUS: MS-CHAP-Response [1] 52 *

00:54:59: RADIUS: NAS-Port [5] 6 30002

00:54:59: RADIUS: NAS-Port-Type [61] 6 ISDN [2]

00:54:59: RADIUS: Calling-Station-Id [31] 16 "00228550592107"

00:54:59: RADIUS: Called-Station-Id [30] 5 "711"

00:54:59: RADIUS: Service-Type [6] 6 Framed [2]

00:54:59: RADIUS: NAS-IP-Address [4] 6 10.3.1.2

00:54:59: RADIUS: Received from id 12 10.1.2.1:1812, Access-Accept, len 169

00:54:59: RADIUS: authenticator A5 D6 8B AA 42 01 3B F3 - 18 64 7E 54 67 94 61

F5

00:54:59: RADIUS: Framed-IP-Address [8] 6 255.255.255.254

00:54:59: RADIUS: Framed-Protocol [7] 6 PPP [1]

00:54:59: RADIUS: Callback-Number [19] 16 "00228550592107"

00:54:59: RADIUS: Service-Type [6] 6 Callback Framed [4]

00:54:59: RADIUS: Class [25] 32

00:54:59: RADIUS: 21 D1 02 A1 00 00 01 37 00 01 0A 01 02 01 01 C2 [!??????7??

??????]

00:54:59: RADIUS: 5B 15 17 13 45 98 00 00 00 00 00 00 [[???E?????

??]

00:54:59: RADIUS: Vendor, Microsoft [26] 40

00:54:59: RADIUS: MS-CHAP-MPPE-Keys [12] 34 *

00:54:59: RADIUS: Vendor, Microsoft [26] 19

00:54:59: RADIUS: MS-CHAP-DOMAIN [10] 13 (delete)

00:54:59: RADIUS: Vendor, Microsoft [26] 12

00:54:59: RADIUS: MS-MPPE-Enc-Policy [7] 6

00:54:59: RADIUS: 00 [?]

00:54:59: RADIUS: Vendor, Microsoft [26] 12

00:54:59: RADIUS: MS-MPPE-Enc-Type [8] 6

00:54:59: RADIUS: 00 [?]

00:54:59: RADIUS: Received from id 1

00:54:59: BR3/0:2 MCB: Start

00:54:59: BR3/0:2 MCB: User tax Callback Number - Server 00228550592107

00:54:59: BR3/0:2 MCB: Newstate 0-INIT -> 2-WAIT_RESPONSE

00:54:59: BR3/0:2 MCB: O Request Id 11 Callback Type Server-Num delay 0

00:54:59: BRI3/0:2 PPP: I MCB Response(2) id 11 len 7

00:54:59: BRI3/0:2 MCB: I 2 B 0 7 3 3 C

00:54:59: BR3/0:2 MCB: Received response

00:54:59: BR3/0:2 MCB: Response CBK-Server-Num 3 3 12

00:54:59: BR3/0:2 MCB: O Ack Id 12 Callback Type Server-Num delay 12

00:54:59: BR3/0:2 MCB: Negotiated MCB with peer

00:54:59: BR3/0:2 MCB: Newstate 2-WAIT_RESPONSE -> 3-WAIT_TERMINATE

00:54:59: BR3/0:2 MCB: Peer terminating the link

00:54:59: BR3/0:2 MCB: Newstate 3-WAIT_TERMINATE -> 5-WAIT_LINKDOWN

00:54:59: BR3/0:2 MCB: Link terminated by peer, Callback Needed

00:54:59: BR3/0:2 MCB: Newstate 5-WAIT_LINKDOWN -> 6-CALLING

00:54:59: BR3/0:2 MCB: Initiate Callback for ^->o`g^@ at 00228550592107 using IS

DN DDR

00:54:59: BR3/0:2 MCB: Dialer callback started

00:55:00: ISDN BR3/0: RX <- DISCONNECT pd = 8 callref = 0x01

00:55:00: Cause i = 0x8090 - Normal call clearing

00:55:00: Facility i = 0x91A11302020E3F020122300AA1053003020100820101

00:55:00: - ETSI Supplementary Service, Invoke, AOC-D Charging Units: 0

00:55:00: ISDN BR3/0: RX <- BAD FRAME(0x00820101)

00:55:00: CCBRI_Go Fr L3 pkt (Len=32) :

00:55:00: 45 1 81 96 8 2 80 90 1C 16 91 A1 13 2 2 E 3F 2 1 22 30 A A1 5 30 3 2 1

0 82 1 1

00:55:00:

00:55:00: ISDN BR3/0: LIF_EVENT: ces/callid 1/0x1A HOST_FACILITY_INVOKE

00:55:00: BRI3/0:2: AOC-D Recorded Units = 0

00:55:00: ISDN BR3/0: LIF_EVENT: ces/callid 1/0x1A HOST_DISCONNECT

00:55:00: ISDN BR3/0: Event: Call to <unknown> was hung up.

00:55:00: ISDN BR3/0: process_disc_ack(): call id 0x1A, ces 1, call type DATA ca

use 0x0

Sep 27 12:04:26: %ISDN-6-CONNECT: Interface BRI3/0:2 is now connected to 0022855

0592107 tax

Sep 27 12:04:26: %ISDN-6-DISCONNECT: Interface BRI3/0:2 disconnected from 00228

550592107 tax, call lasted 1 seconds

00:55:00: ISDN: get_isdn_service_state(): idb 0x613270AC bchan 3 is_isdn 1 Not a

Pri

Sep 27 12:04:26: %LINK-3-UPDOWN: Interface BRI3/0:2, changed state to down

00:55:00: BR3/0:2 MCB: Initialize

Sep 27 12:04:26: %DIALER-6-UNBIND: Interface BR3/0:2 unbound from profile Di1

00:55:00: CCBRI_Go Fr Host InPkgInfo (Len=10) :

00:55:00: 6 18 1 0 1A 0 8 2 0 8

00:55:00:

00:55:00: ISDN BR3/0: TX -> RELEASE pd = 8 callref = 0x81

00:55:00: Cause i = 0x8090 - Normal call clearing

00:55:00: ISDN BR3/0: RX <- RELEASE_COMP pd = 8 callref = 0x01

00:55:00: CCBRI_Go Fr L3 pkt (Len=4) :

00:55:00: 5A 1 81 99

00:55:00:

00:55:00: ISDN BR3/0: LIF_EVENT: ces/callid 1/0x1A HOST_DISCONNECT_ACK

00:55:00: ISDN: get_isdn_service_state(): idb 0x613270AC bchan 3 is_isdn 1 Not a

Pri

00:55:00: ISDN BR3/0: HOST_DISCONNECT_ACK: call type is DATA

00:55:14: ISDN BR3/3: Outgoing call id = 0x8009, dsl 27

00:55:14: ISDN BR3/3: Event: Call to ^->o`l|\ at 64 Kb/s

00:55:14: ISDN BR3/3: process_bri_call(): call id 0x8009, called_number ^->o`l|\

, speed 64, call type DATA

00:55:14: CCBRI_Go Fr Host InPkgInfo (Len=24) :

00:55:14: 1 1B 1 80 9 0 4 2 88 90 18 1 83 70 9 80 DE AD BE EF 60 6C 7C 5C

00:55:14:

00:55:14: CC_CHAN_GetIdleChanbri: dsl 27

00:55:14: Found idle channel B1

00:55:14: ISDN BR3/3: TX -> SETUP pd = 8 callref = 0x05

00:55:14: Bearer Capability i = 0x8890

00:55:14: Channel ID i = 0x83

00:55:14: Called Party Number i = 0x80DEADBEEF, '`l|\\', Plan:Unknown, T

ype:Unknown

00:55:14: ISDN BR3/3: RX <- RELEASE_COMP pd = 8 callref = 0x85

00:55:14: Cause i = 0x819C - Invalid number format (incomplete number)

00:55:14: CCBRI_Go Fr L3 pkt (Len=8) :

00:55:14: 5A 1 5 99 8 2 81 9C

00:55:14:

00:55:14: ISDN BR3/3: LIF_EVENT: ces/callid 1/0x8009 HOST_DISCONNECT_ACK

00:55:14: ISDN BR3/3: Error: Unfound B-channel on Disconnect_Ack - callid 0x8009

00:55:44: ISDN BR3/3: Event: Hangup call to call id 0x8009

00:55:44: ISDN BR3/3: process_disconnect(): call id 0x8009, call type is DATA, b

_idb 0x61377590, ces 1, cause Normal call clearing(0x10)

00:55:44: CCBRI_Go Fr Host InPkgInfo (Len=13) :

00:55:44: 5 1B 0 80 9 3 8 1 90 8 2 80 90

00:55:44:

00:55:44: CC: dsl 27 No CCB Src->HOST cid 0x8009, ev 0x5 ces 1

00:55:44: ISDN BR3/3: LIF_EVENT: ces/callid 1/0x8009 HOST_QUERY_RESPONSE

00:57:35: ISDN BR3/0: RX <- SETUP pd = 8 callref = 0x01

00:57:35: Sending Complete

00:57:35: Bearer Capability i = 0x9090A3

00:57:35: Channel ID i = 0x8A

00:57:35: Progress Ind i = 0x8083 - Origination address is non-ISDN

00:57:35: Calling Party Number i = 0x0083, '00228550592107', Plan:Unknow

n, Type:Unknown

00:57:35: Called Party Number i = 0x81, '711', Plan:ISDN, Type:Unknown

00:57:35: CCBRI_Go Fr L3 pkt (Len=41) :

00:57:35: 5 1 81 90 A1 4 3 90 90 A3 18 1 8A 1E 2 80 83 6C 10 0 83 30 30 32 32 38

35 35 30 35 39 32 31 30 37 70 4 81 37 31 31

00:57:35:

00:57:35: ISDN BR3/0: Incoming call id = 0x001B, dsl 24

00:57:35: ISDN BR3/0: LIF_EVENT: ces/callid 1/0x1B HOST_INCOMING_CALL

00:57:35: ISDN BR3/0: HOST_INCOMING_CALL: (non-POTS) VOICE

00:57:35: ISDN BR3/0: HOST_INCOMING_CALL: (1) call_type = VOICE

00:57:35: ISDN BR3/0: Event: Received a call with a bad bearercap from 002285505

92107 on B2

00:57:35: CCBRI_Go Fr Host InPkgInfo (Len=6) :

00:57:35: 6 18 1 0 1B 0

00:57:35:

00:57:39: ISDN BR3/0: RX <- SETUP pd = 8 callref = 0x01

00:57:39: Sending Complete

00:57:39: Bearer Capability i = 0x9090A3

00:57:39: Channel ID i = 0x8A

00:57:39: Progress Ind i = 0x8083 - Origination address is non-ISDN

00:57:39: Calling Party Number i = 0x0083, '00228550592107', Plan:Unknow

n, Type:Unknown

00:57:39: Called Party Number i = 0x81, '711', Plan:ISDN, Type:Unknown

00:57:39: CCBRI_Go Fr L3 pkt (Len=41) :

00:57:39: 5 1 81 90 A1 4 3 90 90 A3 18 1 8A 1E 2 80 83 6C 10 0 83 30 30 32 32 38

35 35 30 35 39 32 31 30 37 70 4 81 37 31 31

00:57:39:

00:57:39: ISDN BR3/0: Incoming call id = 0x001C, dsl 24

00:57:39: ISDN BR3/0: LIF_EVENT: ces/callid 1/0x1C HOST_INCOMING_CALL

00:57:39: ISDN BR3/0: HOST_INCOMING_CALL: (non-POTS) VOICE

00:57:39: ISDN BR3/0: HOST_INCOMING_CALL: (1) call_type = VOICE

00:57:39: ISDN BR3/0: Event: Received a call with a bad bearercap from 002285505

92107 on B2

00:57:39: CCBRI_Go Fr Host InPkgInfo (Len=6) :

00:57:39: 6 18 1 0 1C 0

00:57:39:

00:57:43: ISDN BR3/1: RX <- SETUP pd = 8 callref = 0x01

00:57:43: Sending Complete

00:57:43: Bearer Capability i = 0x9090A3

00:57:43: Channel ID i = 0x8A

00:57:43: Progress Ind i = 0x8083 - Origination address is non-ISDN

00:57:43: Calling Party Number i = 0x0083, '00228550592107', Plan:Unknow

n, Type:Unknown

00:57:43: Called Party Number i = 0x81, '712', Plan:ISDN, Type:Unknown

00:57:43: CCBRI_Go Fr L3 pkt (Len=41) :

00:57:43: 5 1 81 90 A1 4 3 90 90 A3 18 1 8A 1E 2 80 83 6C 10 0 83 30 30 32 32 38

35 35 30 35 39 32 31 30 37 70 4 81 37 31 32

00:57:43:

00:57:43: ISDN BR3/1: Incoming call id = 0x001D, dsl 25

00:57:43: ISDN BR3/1: LIF_EVENT: ces/callid 1/0x1D HOST_INCOMING_CALL

00:57:43: ISDN BR3/1: HOST_INCOMING_CALL: (non-POTS) VOICE

00:57:43: ISDN BR3/1: HOST_INCOMING_CALL: (1) call_type = VOICE

00:57:43: ISDN BR3/1: HOST_INCOMING_CALL: voice_answer_data = FALSE call type is

VOICE ALAW

00:57:43: ISDN BR3/1: Event: Received a VOICE call from 00228550592107 on B2 at

64 Kb/s

00:57:43: ISDN BR3/1: Event: Accepting the call id 0x1D

00:57:43: ISDN BR3/1: EVENT to CSM:DEV_INCALL: calltype=VOICE, bchan=1

00:57:43: CCBRI_Go Fr Host InPkgInfo (Len=9) :

00:57:43: 7 19 1 0 1D 3 18 1 8A

00:57:43:

00:57:43: CCBRI_Go Fr Host InPkgInfo (Len=6) :

00:57:43: 3 19 1 0 1D 0

00:57:43:

00:57:43: ISDN BR3/1: VOICE_ANS Event: call id 0x1D, bchan 1, ces 1

00:57:43: ISDN BR3/1: isdn_send_connect(): msg 4, call id 0x1D, ces 1 bchan 1, c

all type VOICE

00:57:43: CCBRI_Go Fr Host InPkgInfo (Len=6) :

00:57:43: 4 19 1 0 1D 0

00:57:43:

00:57:43: ISDN BR3/1: TX -> CALL_PROC pd = 8 callref = 0x81

00:57:43: Channel ID i = 0x8A

00:57:43: ISDN BR3/1: TX -> ALERTING pd = 8 callref = 0x81

00:57:43: ISDN BR3/1: TX -> CONNECT pd = 8 callref = 0x81

00:57:43: ISDN BR3/1: RX <- CONNECT_ACK pd = 8 callref = 0x01

00:57:43: Channel ID i = 0x8A

00:57:43: CCBRI_Go Fr L3 pkt (Len=7) :

00:57:43: F 1 81 92 18 1 8A

00:57:43:

00:57:43: ISDN BR3/1: LIF_EVENT: ces/callid 1/0x1D HOST_CONNECT

00:57:43: Modem 1/4 Mica: configured for Answer mode, with Null signaling, 0x0 t

one detection.

00:57:43: ISDN: get_isdn_service_state(): idb 0x6136768C bchan 3 is_isdn 1 Not a

Pri

00:57:43: ISDN BR3/1: Event: Connected to 00228550592107 on B2 at 64 Kb/s

00:57:43: Modem 1/4 Mica: in modem state CALL_SETUP

00:57:44: Modem 1/4 Mica: in modem state CONNECT

00:57:49: Modem 1/4 Mica: in modem state LINK

Sep 27 12:07:15: %ISDN-6-CONNECT: Interface BRI3/1:2 is now connected to 0022855

0592107

00:57:50: Modem 1/4 Mica: in modem state TRAINUP

00:57:57: Modem 1/4 Mica: in modem state EC_NEGOTIATING

00:58:02: Modem 1/4 Mica: in modem state STEADY

00:58:02: Modem 1/4 Mica: CONNECT at 14400/14400 (Tx/Rx), V32bis, Async, None

00:58:03: TTY37: DSR came up

00:58:03: TTY37: no timer type 1 to destroy

00:58:03: TTY37: no timer type 0 to destroy

00:58:03: tty37: Modem: IDLE->(unknown)

Sep 27 12:07:30: %LINK-3-UPDOWN: Interface Async37, changed state to up

00:58:06: Modem 1/4 Mica: PPP escape_map: Tx map = FFFFFFFF, Rx map = 0

00:58:06: Modem 1/4 Mica: PPP escape_map: Tx map = 0, Rx map = 0

00:58:06: As37 MCB: Initialize

00:58:06: MCB: Flush

00:58:07: RADIUS/ENCODE(00000002): Unsupported AAA attribute parent-interface

00:58:07: RADIUS/ENCODE(00000002): Unsupported AAA attribute parent-interface-ty

pe

00:58:07: RADIUS/ENCODE(00000002): acct_session_id: 16

00:58:07: RADIUS(00000002): sending

00:58:07: RADIUS: Send to unknown id 13 10.1.2.1:1812, Access-Request, len 150

00:58:07: RADIUS: authenticator 71 2E 59 6D 0C 24 98 F2 - 00 00 00 00 00 00 00

00

00:58:07: RADIUS: Framed-Protocol [7] 6 PPP [1]

00:58:07: RADIUS: User-Name [1] 5 (delete)

00:58:07: RADIUS: Vendor, Microsoft [26] 16

00:58:07: RADIUS: MSCHAP_Challenge [11] 10

00:58:07: RADIUS: 71 2E 59 6D 0C 24 [q.Ym?$]

00:58:07: RADIUS: Vendor, Microsoft [26] 58

00:58:07: RADIUS: MS-CHAP-Response [1] 52 *

00:58:07: RADIUS: Calling-Station-Id [31] 16 "00228550592107"

00:58:07: RADIUS: Called-Station-Id [30] 5 "712"

00:58:07: RADIUS: NAS-Port [5] 6 1972764709

00:58:07: RADIUS: NAS-Port-Type [61] 6 Async [0]

00:58:07: RADIUS: Service-Type [6] 6 Framed [2]

00:58:07: RADIUS: NAS-IP-Address [4] 6 10.3.1.2

00:58:07: RADIUS: Received from id 13 10.1.2.1:1812, Access-Accept, len 169

00:58:07: RADIUS: authenticator E4 20 DB 8F 7F B8 F1 74 - 52 87 04 E6 29 82 E1

B5

00:58:07: RADIUS: Framed-IP-Address [8] 6 255.255.255.254

00:58:07: RADIUS: Framed-Protocol [7] 6 PPP [1]

00:58:07: RADIUS: Callback-Number [19] 16 "00228550592107"

00:58:07: RADIUS: Service-Type [6] 6 Callback Framed [4]

00:58:07: RADIUS: Class [25] 32

00:58:07: RADIUS: 21 D2 02 A2 00 00 01 37 00 01 0A 01 02 01 01 C2 [!??????7??

??????]

00:58:07: RADIUS: 5B 15 17 13 45 98 00 00 00 00 00 00 [[???E?????

??]

00:58:07: RADIUS: Vendor, Microsoft [26] 40

00:58:07: RADIUS: MS-CHAP-MPPE-Keys [12] 34 *

00:58:07: RADIUS: Vendor, Microsoft [26] 19

00:58:07: RADIUS: MS-CHAP-DOMAIN [10] 13 (delete)

00:58:07: RADIUS: Vendor, Microsoft [26] 12

00:58:07: RADIUS: MS-MPPE-Enc-Policy [7] 6

00:58:07: RADIUS: 00 [?]

00:58:07: RADIUS: Vendor, Microsoft [26] 12

00:58:07: RADIUS: MS-MPPE-Enc-Type [8] 6

00:58:07: RADIUS: 00 [?]

00:58:07: RADIUS: Received from id 2

00:58:07: As37 MCB: Start

00:58:07: As37 MCB: User tax Callback Number - Server 00228550592107

00:58:07: As37 MCB: Newstate 0-INIT -> 2-WAIT_RESPONSE

00:58:07: As37 MCB: O Request Id 1 Callback Type Server-Num delay 0

00:58:07: Async37 PPP: I MCB Response(2) id 1 len 7

00:58:07: Async37 MCB: I 2 1 0 7 3 3 C

00:58:07: As37 MCB: Received response

00:58:07: As37 MCB: Response CBK-Server-Num 3 3 12

00:58:07: As37 MCB: O Ack Id 2 Callback Type Server-Num delay 12

00:58:07: As37 MCB: Negotiated MCB with peer

00:58:07: As37 MCB: Newstate 2-WAIT_RESPONSE -> 3-WAIT_TERMINATE

00:58:07: As37 MCB: Peer terminating the link

00:58:07: As37 MCB: Newstate 3-WAIT_TERMINATE -> 5-WAIT_LINKDOWN

00:58:07: As37 MCB: Link terminated by peer, Callback Needed

00:58:07: As37 MCB: Newstate 5-WAIT_LINKDOWN -> 6-CALLING

00:58:07: As37 MCB: Initiate Callback for ^->o`g^@ at 00228550592107 using Async

DDR

00:58:07: As37 MCB: Dialer callback started

00:58:08: ISDN BR3/1: RX <- DISCONNECT pd = 8 callref = 0x01

00:58:08: Cause i = 0x8090 - Normal call clearing

00:58:08: Facility i = 0x91A11302020E44020122300AA1053003020100820101

00:58:08: - ETSI Supplementary Service, Invoke, AOC-D Charging Units: 0

00:58:08: Progress Ind i = 0x8288 - In-band info or appropriate now avai

lable

00:58:08: CCBRI_Go Fr L3 pkt (Len=36) :

00:58:08: 45 1 81 96 8 2 80 90 1C 16 91 A1 13 2 2 E 44 2 1 22 30 A A1 5 30 3 2 1

0 82 1 1 1E 2 82 88

00:58:08:

00:58:08: ISDN BR3/1: LIF_EVENT: ces/callid 1/0x1D HOST_FACILITY_INVOKE

00:58:08: BRI3/1:2: AOC-D Recorded Units = 0

00:58:08: ISDN BR3/1: LIF_EVENT: ces/callid 1/0x1D HOST_DISCONNECT

00:58:08: ISDN BR3/1: Event: Call to <unknown> was hung up.

00:58:08: ISDN BR3/1: process_disc_ack(): call id 0x1D, ces 1, call type VOICE c

ause 0x0

Sep 27 12:07:33: %ISDN-6-DISCONNECT: Interface BRI3/1:2 disconnected from 00228

550592107 , call lasted 24 seconds

00:58:08: ISDN: get_isdn_service_state(): idb 0x6136768C bchan 3 is_isdn 1 Not a

Pri

00:58:08: CCBRI_Go Fr Host InPkgInfo (Len=10) :

00:58:08: 6 19 1 0 1D 0 8 2 0 8

00:58:08:

00:58:08: ISDN BR3/1: TX -> RELEASE pd = 8 callref = 0x81

00:58:08: Cause i = 0x8090 - Normal call clearing

00:58:08: Modem 1/4 Mica: in modem state TERMINATING

00:58:08: Modem 1/4 Mica: in modem state IDLE

00:58:08: ISDN BR3/1: VOICE_HANGUP Event: call id 0x1D, bchan 1, ces 1, cause 0x

10

00:58:08: ISDN BR3/1: Event: Voice hangup call to call id 0x1D

00:58:08: Modem 1/4 Mica: DISCONNECT after 00:00:23, due to reason (0xDF06) DS1

network disconnect (no carrier).

00:58:08: ISDN BR3/1: RX <- RELEASE_COMP pd = 8 callref = 0x01

00:58:08: CCBRI_Go Fr L3 pkt (Len=4) :

00:58:08: 5A 1 81 99

00:58:08:

00:58:08: ISDN BR3/1: LIF_EVENT: ces/callid 1/0x1D HOST_DISCONNECT_ACK

00:58:08: ISDN: get_isdn_service_state(): idb 0x6136768C bchan 3 is_isdn 1 Not a

Pri

00:58:08: ISDN BR3/1: HOST_DISCONNECT_ACK: call type is VOICE

00:58:08: ISDN BR3/1: HOST_DISCONNECT_ACK: VOICE ERROR: NULL VDEV Common(0xFC):

bchan 1, call id 1D

00:58:09: TTY37: DSR was dropped

00:58:09: tty37: Modem: READY->(unknown)

00:58:09: TTY37: Async Int reset: Dropping DTR

00:58:10: TTY37: dropping DTR, hanging up

00:58:10: tty37: Modem: HANGUP->(unknown)

00:58:11: TTY37: cleanup pending. Delaying DTR

Sep 27 12:07:37: %LINK-5-CHANGED: Interface Async37, changed state to reset

00:58:12: TTY37: cleanup pending. Delaying DTR

00:58:13: TTY37: cleanup pending. Delaying DTR

00:58:14: TTY37: cleanup pending. Delaying DTR

00:58:14: TTY37: no timer type 0 to destroy

00:58:14: TTY37: no timer type 1 to destroy

00:58:14: TTY37: no timer type 3 to destroy

00:58:14: TTY37: no timer type 4 to destroy

00:58:14: TTY37: no timer type 2 to destroy

00:58:14: Async37: allowing modem_process to continue hangup

00:58:15: TTY37: restoring DTR

00:58:15: TTY37: autoconfigure probe started

Sep 27 12:07:42: %LINK-3-UPDOWN: Interface Async37, changed state to down

00:58:26: CHAT37: Attempting async line dialer script

00:58:26: CHAT37: process started

00:58:26: CHAT37: Asserting DTR

00:58:26: ISDN BR3/2: Outgoing call id = 0x800A, dsl 26

00:58:26: Modem 1/4 Mica: configured for Originate mode, with Null signaling, 0x

1 tone detection.

00:58:26: Modem 1/4 Mica: received dialstring T00228550592107

00:58:26: ISDN BR3/2: VOICE_ISDNCALL Event: call id 0x800A, bchan -1, ces 0

00:58:26: ISDN BR3/2: process_bri_call(): call id 0x800A, called_number 00228550

592107, speed 64, call type VOICE

00:58:26: CCBRI_Go Fr Host InPkgInfo (Len=31) :

00:58:26: 1 1A 1 80 A 0 4 3 80 90 A3 18 1 83 70 F 80 30 30 32 32 38 35 35 30 35

39 32 31 30 37

00:58:26:

00:58:26: CC_CHAN_GetIdleChanbri: dsl 26

00:58:26: Found idle channel B1

00:58:26: ISDN BR3/2: TX -> SETUP pd = 8 callref = 0x06

00:58:26: Bearer Capability i = 0x8090A3

00:58:26: Channel ID i = 0x83

00:58:26: Called Party Number i = 0x80, '00228550592107', Plan:Unknown,

Type:Unknown

00:58:26: Modem 1/4 Mica: in modem state CALL_SETUP

00:58:26: ISDN BR3/2: RX <- SETUP_ACK pd = 8 callref = 0x86

00:58:26: Channel ID i = 0x8A

00:58:26: Progress Ind i = 0x8188 - In-band info or appropriate now avai

lable

00:58:26: CCBRI_Go Fr L3 pkt (Len=11) :

00:58:26: D 1 6 B7 18 1 8A 1E 2 81 88

00:58:26:

00:58:26: ISDN BR3/2: LIF_EVENT: ces/callid 1/0x800A HOST_INFORMATION

00:58:30: ISDN Event: dsl 26 call_id 0x800A B channel assigned by switch 1

ISDN BR3/2: RX <- CALL_PROC pd = 8 callref = 0x86

00:58:30: CCBRI_Go Fr L3 pkt (Len=4) :

00:58:30: 2 1 6 98

00:58:30:

00:58:30: ISDN BR3/2: LIF_EVENT: ces/callid 1/0x800A HOST_PROCEEDING

00:58:30: ISDN BR3/2: HOST_PROCEEDING

00:58:30: ISDN BR3/2: HOST_MORE_INFO

00:58:30: B-channel assigned in previous message call id = 0x800A

00:58:30: ISDN BR3/2: HOST_PROCEEDING: VOICE ERROR: Undefined B-IDB(0xFD): bchan

1, call id 800A

00:58:30: ISDN: get_isdn_service_state(): idb 0x613728CC bchan 3 is_isdn 1 Not a

Pri

00:58:30: CCBRI_Go Fr Host InPkgInfo (Len=13) :

00:58:30: 4F 1A 1 80 A 3 8 1 FD 8 2 87 FD

00:58:30:

00:58:31: ISDN BR3/2: RX <- ALERTING pd = 8 callref = 0x86

00:58:31: Progress Ind i = 0x8288 - In-band info or appropriate now avai

lable

00:58:31: Progress Ind i = 0x8288 - In-band info or appropriate now avai

lable

00:58:31: CCBRI_Go Fr L3 pkt (Len=12) :

00:58:31: 1 1 6 94 1E 2 82 88 1E 2 82 88

00:58:31:

00:58:31: ISDN BR3/2: LIF_EVENT: ces/callid 1/0x800A HOST_ALERTING

00:58:31: Modem 1/4 Mica: Detected Dial tone

00:58:32: ISDN BR3/2: RX <- CONNECT pd = 8 callref = 0x86

00:58:32: Date/Time i = 0x02091B0C08

00:58:32: Connected Number i = 0x00833030323238353530353932313037

00:58:32: CCBRI_Go Fr L3 pkt (Len=29) :

00:58:32: 7 1 6 91 29 5 2 9 1B C 8 4C 10 0 83 30 30 32 32 38 35 35 30 35 39 32 3

1 30 37

00:58:32:

00:58:32: ISDN BR3/2: LIF_EVENT: ces/callid 1/0x800A HOST_CONNECT

00:58:32: ISDN: get_isdn_service_state(): idb 0x613728CC bchan 3 is_isdn 1 Not a

Pri

00:58:32: ISDN BR3/2: Event: Connected to <unknown> on B2 at 64 Kb/s

00:58:32: ISDN BR3/2: TX -> CONNECT_ACK pd = 8 callref = 0x06

00:58:32: Modem 1/4 Mica: in modem state CONNECT

00:58:32: ISDN BR3/2: RX <- FACILITY pd = 8 callref = 0x86

00:58:32: Facility i = 0x91A11302020E45020122300AA1053003020101820100

00:58:32: - ETSI Supplementary Service, Invoke, AOC-D Charging Units: 1

00:58:32: CCBRI_Go Fr L3 pkt (Len=28) :

00:58:32: 62 1 6 BD 1C 16 91 A1 13 2 2 E 45 2 1 22 30 A A1 5 30 3 2 1 1 82 1 0

00:58:32:

00:58:32: ISDN BR3/2: LIF_EVENT: ces/callid 1/0x800A HOST_FACILITY_INVOKE

00:58:32: BRI3/2:2: AOC-D Recorded Units = 1

00:58:34: Modem 1/4 Mica: in modem state LINK

00:58:37: Modem 1/4 Mica: in modem state TRAINUP

Sep 27 12:08:04: %ISDN-6-CONNECT: Interface BRI3/2:2 is now connected to unknown

00:58:44: Modem 1/4 Mica: in modem state EC_NEGOTIATING

00:58:54: Modem 1/4 Mica: in modem state STEADY

00:58:54: TTY37: no timer type 1 to destroy

00:58:54: TTY37: no timer type 0 to destroy

00:58:54: Modem 1/4 Mica: CONNECT at 14400/14400 (Tx/Rx), V32bis, Async, None

Sep 27 12:08:22: %LINK-3-UPDOWN: Interface Async37, changed state to up

00:58:56: Modem 1/4 Mica: PPP escape_map: Tx map = FFFFFFFF, Rx map = 0

00:58:57: Modem 1/4 Mica: PPP escape_map: Tx map = 0, Rx map = 0

00:58:57: As37 MCB: Initialize

00:59:05: TTY130: EXEC creation

00:59:05: TTY130: create timer type 1, 600 seconds

00:59:07: TTY130: set timer type 10, 30 seconds

00:59:14: ISDN BR3/2: RX <- FACILITY pd = 8 callref = 0x86

00:59:14: Facility i = 0x91A11302020E46020122300AA1053003020102820100

00:59:14: - ETSI Supplementary Service, Invoke, AOC-D Charging Units: 2

00:59:14: CCBRI_Go Fr L3 pkt (Len=28) :

00:59:14: 62 1 6 BD 1C 16 91 A1 13 2 2 E 46 2 1 22 30 A A1 5 30 3 2 1 2 82 1 0

00:59:14:

00:59:14: ISDN BR3/2: LIF_EVENT: ces/callid 1/0x800A HOST_FACILITY_INVOKE

00:59:14: BRI3/2:2: AOC-D Recorded Units



and here is the actualy config from the cisco 3640. IOS Version 12.2 (8) T



!

version 12.2

service timestamps debug uptime

service timestamps log uptime

no service password-encryption

!

hostname FDK_RAS

!

boot system flash c3640-i-mz.122-8.T5.bin

logging buffered 100000 debugging

aaa new-model

!

!

aaa authentication login default group radius local

aaa authentication login NO_AUTHEN none

aaa authentication ppp default group radius local

aaa authorization network default group radius

aaa session-id common

enable secret 5 $1$Hqz/$p18r5/1LGsohU./tQjCD6.

enable password c

!

modem country mica germany

ip subnet-zero

!

!

ip host Radius 10.1.2.1

!

isdn switch-type basic-net3

chat-script default ""ats0=1&f OK

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

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

!

!

!

interface FastEthernet2/0

ip address 10.3.1.2 255.255.0.0

speed auto

half-duplex

!

interface BRI3/0

no ip address

encapsulation ppp

dialer pool-member 1

isdn oncoming-voie modem

isdn switch-type basic-net3

no cdp enable

ppp authentication ms-chap chap pap

!

interface BRI3/1

no ip address

encapsulation ppp

dialer pool-member 1

isdn switch-type basic-net3

isdn incoming-voice modem

no cdp enable

ppp authentication ms-chap chap pap

!

interface BRI3/2

no ip address

encapsulation ppp

dialer pool-member 1

isdn switch-type basic-net3

isdn incoming-voice modem

no cdp enable

ppp authentication ms-chap chap pap

!

interface BRI3/3

no ip address

encapsulation ppp

dialer pool-member 1

dialer pool-member 2

isdn switch-type basic-net3

isdn incoming-voice modem

no cdp enable

ppp authentication ms-chap chap pap

!

interface Group-Async0

physical-layer async

ip unnumbered FastEthernet2/0

encapsulation ppp

dialer in-band

dialer idle-timeout 900

dialer fast-idle 900

dialer-group 1

async mode dedicated

peer default ip address pool setup_pool

no fair-queue

ppp callback accept

ppp authentication ms-chap chap pap callin

group-range 33 44

!

interface Dialer1

ip unnumbered FastEthernet2/0

encapsulation ppp

dialer pool 1

dialer idle-timeout 900

dialer fast-idle 900

dialer-group 1

peer default ip address pool setup_pool

no cdp enable

ppp callback accept

ppp authentication ms-chap chap pap callin

!

interface Dialer2

ip address 192.168.1.253 255.255.255.252

encapsulation ppp

dialer pool 2

dialer remote-name FDK_RATINGEN

dialer idle-timeout 900

dialer-group 1

ppp chap hostname <delete>

!

ip local pool setup_pool 10.4.0.1 10.4.0.254

ip classless

ip route 0.0.0.0 0.0.0.0 10.3.1.1

ip route 10.11.0.0 255.255.0.0 192.168.1.254

no ip http server

ip pim bidir-enable

!

!

dialer-list 1 protocol ip permit

dialer-list 1 protocol ipx permit

radius-server host 10.1.2.1 auth-port 1812 acct-port 1813 key cisco3640

radius-server retransmit 3

radius-server attribute nas-port format b

radius-server key cisco3640

!

line con 0

login authentication NO_AUTHEN

line 33 44

exec-timeout 0 0

script callback mod

modem InOut

modem autoconfigure discovery

transport input all

autoselect during-login

autoselect ppp

stopbits 1

flowcontrol hardware

line aux 0

line vty 0 4

password c

login authentication NO_AUTHEN

!

!

end



anybody an idea ??


thank you




  • 1
  • 2
  • 3
  • 4
  • 5
Overall Rating: 3 (1 ratings)
Loading.
giedriusa Fri, 09/27/2002 - 06:31
User Badges:

Hi,


I have very similar 3640 configuration except that I have PRI instead of BRI - it works fine. I have come accross similar problem - it appeared to be ISDN provider problem.

Check this - it is definitelly working:


aaa authentication ppp USERS group radius local

aaa authorization network USERS local group radius if-authenticated


modem country mica ireland


interface Serial2/0:15

description ISDN PRI Config

no ip address

encapsulation ppp

no ip route-cache

ip tcp header-compression passive

dialer rotary-group 0

autodetect encapsulation ppp v120 lapb-ta

isdn switch-type primary-net5

isdn incoming-voice modem 64

no fair-queue

no cdp enable

no ppp chap wait

ppp multilink


interface Dialer0

description ISDN user config

ip unnumbered Loopback0

encapsulation ppp

no ip route-cache

ip tcp header-compression passive

no ip mroute-cache

no logging event link-status

dialer in-band

dialer idle-timeout 1200

dialer enable-timeout 3

dialer load-threshold 2 either

dialer-group 1

peer default ip address pool dialup

no fair-queue

no cdp enable

ppp callback permit

ppp authentication pap ms-chap callin USERS

ppp authorization USERS

no ppp chap wait

ppp multilink



radius-server host 139.54.203.6 auth-port 1645 acct-port 1646

radius-server retransmit 3

radius-server key cisco



The only thing I could advise You is to check Your NT1 devices.


Best regards


Giedrius

Hi Giedrius ,


thanks for your answer.

Im absolutly convinced that this config work fine. But i don't now why the analog callback works , and the isdn do not ?

The Cisco 3640 is connceted to a PBX . I have to dial a 0 for a long distance call.


Have look to the debug , and you can see that analog do a callback , and ISDN

failed .


It is possibel that the PBX has a timer problem . do you think also ?


thanks


Hermann

schimekh Sat, 09/28/2002 - 08:30
User Badges:

Hi !


I had a similar problem -

which IOS are you using ?

12.2.8T has a bug - so upgrade to 12.2.11T

this version works fine !



cu

hans

Actions

This Discussion