I'm trying to run T.37 Store and Forward Fax on a Cisco 2611. It has
NM-2V and VIC-2BRI-S/T-TE for the fax part. I've previously tried to use
this box for traditional VoIP (see my post yesterday about a problem
that was fixed with off-list help) and it seems to work fine. Extract
from show version:
System image file is "flash:c2600-is4-mz.123-6.bin"
cisco 2611 (MPC860) processor (revision 0x203) with 61440K/4096K bytes
of memory.
Basic Rate ISDN software, Version 1.1.
2 Ethernet/IEEE 802.3 interface(s)
3 ISDN Basic Rate interface(s)
4 Voice TE BRI interface(s)
I've attached the entire config file (sans passwords) below. It's mostly
based on Cisco's documentation for 12.2T. (There doesn't seem to be
12.3-specific fax documentation).
The 2611 is 192.168.1.102. I have an SMTP server set up at 192.168.1.103
which is set up to receive and forward all mail sent to
*@fax.unicast.org. The MX record is also set up properly. I'm starting
with the on-ramp fax gateway for now.
When I call the number (32580668) with a regular phone, the 2611 doesn't
pick up the call.
What follows is config file as well as debug bri-interface and debug
voice ivr all output (very long). I've turned off AAA and I don't
understand why it doesn't pick up the call.
Thanks,
Guan
config file:
Current configuration : 2623 bytes
!
version 12.3
service timestamps debug datetime msec
service timestamps log datetime msec
no service password-encryption
no service dhcp
!
hostname jefferson
!
boot-start-marker
boot-end-marker
!
! enable secret
!
clock timezone CET 1
clock summer-time CEST recurring
no aaa new-model
ip subnet-zero
ip cef
!
!
ip name-server 192.168.1.103
ip name-server 212.54.64.170
ip name-server 212.54.64.171
!
isdn switch-type basic-net3
!
!
!
voice class codec 1
codec preference 1 g711alaw
codec preference 2 g729br8
codec preference 3 g729r8
codec preference 4 g723r63
codec preference 5 g723r53
codec preference 6 g711ulaw
!
voice class codec 2
codec preference 1 g711alaw
codec preference 2 g723r63
codec preference 3 g723r53
codec preference 4 g729br8
codec preference 5 g729r8
codec preference 7 gsmfr
codec preference 8 gsmefr
codec preference 9 g711ulaw
!
!
!
!
!
!
!
!
!
fax receive called-subscriber $d$
fax interface-type fax-mail
mta send server 192.168.1.103 port 25
mta send subject "Fax"
mta send origin-prefix "Cisco-Powered Fax System"
mta send postmaster guan-postmaster@unicast.org
mta send mail-from hostname fax.unicast.org
mta send mail-from username $s$
mta send return-receipt-to username $s$
!
!
!
!
interface Loopback0
no ip address
!
interface Ethernet0/0
ip address 192.168.1.102 255.255.255.0
ip access-group 1 in
ip access-group 1 out
no ip mroute-cache
full-duplex
no cdp enable
!
interface BRI0/0
no ip address
no ip mroute-cache
shutdown
isdn switch-type basic-net3
no cdp enable
!
interface Ethernet0/1
description Built-in hub in Engvej Speedstream router
no ip address
no ip mroute-cache
shutdown
full-duplex
no cdp enable
!
interface BRI1/0
no ip address
isdn switch-type basic-net3
isdn incoming-voice voice
isdn answer1 32580668
isdn calling-number 32848286
!
interface BRI1/1
no ip address
shutdown
isdn switch-type basic-net3
!
ip http server
ip classless
!
!
access-list 1 permit any
!!
call application voice onramp flash:app_faxmail_onramp.tcl
!
voice-port 1/0/0
no echo-cancel enable
compand-type a-law
no comfort-noise
cptone DK
!
voice-port 1/0/1
compand-type a-law
cptone DK
!
!
!
dial-peer voice 2 pots
application onramp
incoming called-number 32580668
direct-inward-dial
!
dial-peer voice 3 mmoip
application onramp out-bound
destination-pattern 32580668
information-type fax
session target mailto:$d$@fax.unicast.org
dsn success
!
sip-ua
sip-server ipv4:192.168.1.101
!
!
line con 0
exec-timeout 0 0
line aux 0
line vty 0 4
password vtpassword
login
!
!
!
end
Serial console debug output:
jefferson#
*Mar 1 00:02:52.074: BRI1/0 : received datagramsize 43
*Mar 1 00:02:52.090: //3/EE5E21958008/APPL:/AppManagerCCAPI_Interface:
*Mar 1 00:02:52.090: //-1//TCL2:/TclGetInterp: Script onramp
*Mar 1 00:02:52.094: //-1//APPL:/AppNewLeg:
*Mar 1 00:02:52.094: //-1//APPL:LG-1:/AppNewLeg: New Leg[0x824DCC78]
*Mar 1 00:02:52.094: //-1//APPL:/AppSaveRawMsg:
*Mar 1 00:02:52.094: //3//APPL:LP:HN0002A03E:/AppPushLegORConnection:
Pushing LEG[3 ][NULL ][LEG_INCINIT(1)][Cause(0)][UC=1 ] Onto
{HAN[TCL_HAND][.NULL}*Mar 1 00:02:52.098: //-1//APPL:/AppNewEvent: New
event 0x83101344
*Mar 1 00:02:52.098: //3//APPL:/AppProcessEvent: Event 0x83101344
CC_EV_CALL_SETUP_IND[28]:
*Mar 1 00:02:52.098: //3//APPL:/AppProcessEvent: LEG[3
][TCL_HAND][LEG_INCINIT(1)][Cause(0)][UC=1 ]
*Mar 1 00:02:52.098: //3//TCL2:/TclInterpHandler: Tcl handler
0x824D9AEC processing CC_EV_CALL_SETUP_IND
*Mar 1 00:02:52.098: //3//TCL2:/TclInterpDriver:
*Mar 1 00:02:52.102: //3//TCL2:/TclEventPreprocessing:
*Mar 1 00:02:52.102: //-1//TCL2:/TclIncomingCallBlock:
*Mar 1 00:02:52.102: //3//TCL2:/SettlementValidateCall: target=,
tokenp=0x0
*Mar 1 00:02:52.102: //3//TCL2:/MakeTransition: FSM Transtion: ([1
]CALL_INIT,[28]ev_setup_indication)---([9 ]act_Setup)--->([3 ]SAMESTATE)
*Mar 1 00:02:52.106: //3//TCL2:/tcl_infotagCmd: infotag set
med_language 1
*Mar 1 00:02:52.106: //3//TCL2:/tcl_setInfoCmd: set med_language 1
*Mar 1 00:02:52.106: //3//TCL2:/vtw_ms_language: argc 3 argindex 2
*Mar 1 00:02:52.110: //3//TCL2:/tcl_infotagCmd: infotag get
cfg_avpair_exists authentication
*Mar 1 00:02:52.110: //3//TCL2:/tcl_getInfoCmd: get cfg_avpair_exists
authentication
*Mar 1 00:02:52.110: //3//TCL2:/vtr_cf_avpair_exists: argc 3 argindex 2
*Mar 1 00:02:52.110: //3//TCL2:/tcl_PutsCmd:
Authentication control is 0
*Mar 1 00:02:52.114:
*Mar 1 00:02:52.114: //3//TCL2:/tcl_infotagCmd: infotag get
cfg_avpair_exists accounting
*Mar 1 00:02:52.114: //3//TCL2:/tcl_getInfoCmd: get cfg_avpair_exists
accounting
*Mar 1 00:02:52.114: //3//TCL2:/vtr_cf_avpair_exists: argc 3 argindex 2
*Mar 1 00:02:52.114: //3//TCL2:/tcl_PutsCmd:
Accounting control is 0
*Mar 1 00:02:52.118:
*Mar 1 00:02:52.118: //3//TCL2:/tcl_infotagCmd: infotag get
cfg_avpair_exists authen-method
*Mar 1 00:02:52.118: //3//TCL2:/tcl_getInfoCmd: get
*Mar 1 00:02:52.118: BRI1/0 : received datagramsize 3cfg_avpair_exists
authen-method
*Mar 1 00:02:52.118: //3//TCL2:/vtr_cf_avpair_exists: argc 3 argindex 2
*Mar 1 00:02:52.122: //3//TCL2:/tcl_PutsCmd:
Authentication method is 0
*Mar 1 00:02:52.122:
*Mar 1 00:02:52.122: //3//TCL2:/tcl_infotagCmd: infotag get
cfg_avpair_exists password
*Mar 1 00:02:52.122: //3//TCL2:/tcl_getInfoCmd: get cfg_avpair_exists
password
*Mar 1 00:02:52.122: //3//TCL2:/vtr_cf_avpair_exists: argc 3 argindex 2
*Mar 1 00:02:52.126: //3//TCL2:/tcl_PutsCmd:
Default password is
*Mar 1 00:02:52.126:
*Mar 1 00:02:52.126: //3//TCL2:/tcl_infotagCmd: infotag get
cfg_avpair_exists accounting-list
*Mar 1 00:02:52.126: //3//TCL2:/tcl_getInfoCmd: get cfg_avpair_exists
accounting-list
*Mar 1 00:02:52.130: //3//TCL2:/vtr_cf_avpair_exists: argc 3 argindex 2
*Mar 1 00:02:52.130: //3//TCL2:/tcl_PutsCmd: Accounting method is fax
*Mar 1 00:02:52.130:
*Mar 1 00:02:52.134: //3//TCL2:/tcl_infotagCmd: infotag get
cfg_avpair_exists authen-list
*Mar 1 00:02:52.134: //3//TCL2:/tcl_getInfoCmd: get cfg_avpair_exists
authen-list
*Mar 1 00:02:52.134: //3//TCL2:/vtr_cf_avpair_exists: argc 3 argindex 2
*Mar 1 00:02:52.138: //3//TCL2:/tcl_infotagCmd: infotag get leg_ani
*Mar 1 00:02:52.138: //3//TCL2:/tcl_getInfoCmd: get leg_ani
*Mar 1 00:02:52.138: //3//TCL2:/vtr_lg_ani: argc 2 argindex 2
*Mar 1 00:02:52.142: //3//TCL2:/tcl_infotagCmd: infotag get leg_dnis
*Mar 1 00:02:52.142: //3//TCL2:/tcl_getInfoCmd: get leg_dnis
*Mar 1 00:02:52.142: //3//TCL2:/vtr_lg_dnis: argc 2 argindex 2
*Mar 1 00:02:52.142: //3//TCL2:/tcl_infotagCmd: infotag
*Mar 1 00:02:52.146: BRI1/0 : received datagramsize 4get leg_isdid
*Mar 1 00:02:52.146: //3//TCL2:/tcl_getInfoCmd: get leg_isdid
*Mar 1 00:02:52.146: //3//TCL2:/vtr_lg_incdid: argc 2 argindex 2
*Mar 1 00:02:52.146: //3//TCL2:/tcl_infotagCmd: infotag get leg_dnis
*Mar 1 00:02:52.146: //3//TCL2:/tcl_getInfoCmd: get leg_dnis
*Mar 1 00:02:52.150: //3//TCL2:/vtr_lg_dnis: argc 2 argindex 2
*Mar 1 00:02:52.150: //3//TCL2:/tcl_PutsCmd:
destination is 32580668
*Mar 1 00:02:52.154:
*Mar 1 00:02:52.154: //3//TCL2:/tcl_legCmd: leg proceeding leg_incoming
*Mar 1 00:02:52.158: //3//TCL2:/tcl_callProceedingCmd: proceeding
leg_incoming
*Mar 1 00:02:52.158: //3//TCL2:/vtd_lg_incoming: argc 2
*Mar 1 00:02:52.158: //3//TCL2:/vtd_lg_incoming: Legs [3 ]
*Mar 1 00:02:52.158: //3//TCL2:/tcl_parseCallID_vartag: VARTAG
Translation Leg Count=1
*Mar 1 00:02:52.158: //3//TCL2:/tcl_legCmd: leg setup 32580668 callInfo
leg_incoming
*Mar 1 00:02:52.162: //3//TCL2:/tcl_callSetupCmd: setup 32580668
callInfo leg_incoming
*Mar 1 00:02:52.162: //3//TCL2:/vtd_lg_incoming: argc 4
*Mar 1 00:02:52.162: //3//TCL2:/vtd_lg_incoming: Legs [3 ]
*Mar 1 00:02:52.162: //3//TCL2:/tcl_parseCallID_vartag: VARTAG
Translation Leg Count=1
*Mar 1 00:02:52.166: //-1//APPL:/AppSaveRawMsg:
*Mar 1 00:02:52.170: //-1//PCM
:LP:HN0002A082:HN0002A03E:/InitiateCallSetup: Mode 1 RedirectMode 1
Incoming leg[3] AlertTime -1 Destinations(1) [ 32580668 ]
*Mar 1 00:02:52.170:
//-1//APPL:LP:HN0002A082:HN0002A03E:/AppPushHandler: Pushing
{HAN[CS_HAND ][NULL ] ( )} Onto {HAN[TCL_HAND][NULL ] (
LEG[3}*Mar 1 00:02:52.170:
//3//APPL:LP:HN0002A082:/AppPushLegORConnection: Pushing LEG[3
][TCL_HAND][LEG_INCPROCEED(3)][Cause(0)][UC=1 ] Onto {HAN[CS_HAND
][.T}*Mar 1 00:02:52.174: Redirect Cap is LEG_REDIR_UNKNOWN
*Mar 1 00:02:52.174: Redirect Cap is LEG_REDIR_UNKNOWN
*Mar 1 00:02:52.174: //-1//APPL:/AppSaveRawMsg:
*Mar 1 00:02:52.174: //-1//PCM :HN0002A08E:/InitiateCallSetup:
Destination 0 guid : EE5E2195.14EE11CC.80089483.E9D5DAA3
*Mar 1 00:02:52.174: incoming_guid :
00000000.00000000.00000000.00000000
*Mar 1 00:02:52.178: //-1//PCM :HN0002A08E:/DNInitiate:
Destination[32580668]
*Mar 1 00:02:52.178:
//-1//APPL:LP:HN0002A08E:HN0002A082:/AppPushHandler: Pushing
{HAN[DN_HAND ][NULL ] ( )} Onto {HAN[CS_HAND ][TCL_HAND] (
LEG[.3}*Mar 1 00:02:52.178: //-1//PCM :HN0002A08E:/DNQueuePeers: Matched
peers(1)
*Mar 1 00:02:52.182: //-1//PCM :HN0002A08E:/DNSetupPeer: Destination
0x8310B004
*Mar 1 00:02:52.182: //-1//PCM :HN0002A08E:/DNSetupPeer: dialpeer tags
for Rotary = 3
*Mar 1 00:02:52.182: //-1//PCM :HN0002A08E:/DNSetupPeer:
*Mar 1 00:02:52.182: Destination SetupPeer cid(3), destPat(32580668),
match(8), prefix(), peer(82FB0298) hiddenLeg(-1)
*Mar 1 00:02:52.182: //-1//PCM :HN0002A08E:/DNSetupPeer: Found outbound
application (onramp) in dialpeer
*Mar 1 00:02:52.186: //-1//APPL:/AppNewEvent: New event 0x83101C74
*Mar 1 00:02:52.186: //-1//APPL:/AppFreeEvent: Freeing event 0x83101344
CC_EV_CALL_SETUP_IND[28]
*Mar 1 00:02:52.198: BRI1/0 : sending datagramsize 3
*Mar 1 00:02:52.202: //-1//APPL:HN0002A08E:/AppProcessEvent: Event
0x83101C74 APP_EV_OUTBOUND_APP[102]:
*Mar 1 00:02:52.202: //-1//APPL:HN0002A08E:/AppProcessEvent:
HAN[DN_HAND][CS_HAND ][FALSE] [UC=1 ]
*Mar 1 00:02:52.202: //-1//PCM :HN0002A08E:/DNHandler:
(DN_MAPPING[0])--(APP_EV_OUTBOUND_APP[102])--IGNORED-->>(DN_MAPPING[0])
*Mar 1 00:02:52.202: //-1//PCM :HN0002A082:/CS_OutboundApp: Event 102,
in State 0
*Mar 1 00:02:52.202: //-1//PCM :HN0002A082:/CSDiscReturnAndEmptyLegALL:
*Mar 1 00:02:52.206: //3//APPL:/ah_put_in_the_bag: Bag of Objects:
LEG[3 ][CS_HAND ][LEG_INCPROCEED(3)][Cause(0)][UC=1 ]
*Mar 1 00:02:52.206: //-1//PCM :HN0002A082:/CS_OutboundApp: out bound
peer tag (3)
*Mar 1 00:02:52.206: //-1//APPL:/ah_call_app:
*Mar 1 00:02:52.206:
//-1//APPL:LP:HN00000000:HN0002A082:/AppPushHandler: Pushing
{HAN[xferHand][NULL ] ( )} Onto {HAN[CS_HAND ][TCL_HAND] (
LEG[3}*Mar 1 00:02:52.210:
//3//APPL:LP:HN00000000:/AppPushLegORConnection: Pushing LEG[3
][CS_HAND ][LEG_INCPROCEED(3)][Cause(0)]
*Mar 1 00:02:52.210: BRI1/0 : received datagramsize 3[UC=1 ] Onto
{HAN[xferHand][CS_HAND ] ( )}
*Mar 1 00:02:52.210: //-1//APPL:HN00000000:/ah_transfer_out_handoff:
*Mar 1 00:02:52.214: //3//APPL:/AppPopLegORConnectionOffAll: Popping
LEG[3 ][xferHand][LEG_INCPROCEED(3)][Cause(0)][UC=1 ] Off
{HAN[xferHand][CS_HAND ] }*Mar 1 00:02:52.214:
//3//APPL:/AppPopLegORConnectionOffAll: Popping LEG[3
][xferHand][LEG_INCPROCEED(3)][Cause(0)][UC=1 ] Off {HAN[CS_HAND
][TCL_HAND] }*Mar 1 00:02:52.218:
//3//APPL:/AppPopLegORConnectionOffAll: Popping LEG[3
][xferHand][LEG_INCPROCEED(3)][Cause(0)][UC=1 ] Off
{HAN[TCL_HAND][NULL ] }*Mar 1 00:02:52.218:
//3//APPL:/AppManagerCCAPI_Interface:
*Mar 1 00:02:52.218: //-1//TCL2:/TclGetInterp: Script onramp
*Mar 1 00:02:52.222: //3//APPL:LP:HN0002A0BE:/AppPushLegORConnection:
Pushing LEG[3 ][NULL ][LEG_INCPROCEED(3)][Cause(0)][UC=1 ] Onto
{HAN[TCL_HAND][.N}*Mar 1 00:02:52.222: //3//APPL:/AppMediaDestroy:
*Mar 1 00:02:52.222: //-1//APPL:/AppFreeEvent: Freeing event 0x83101C74
APP_EV_OUTBOUND_APP[102]
*Mar 1 00:02:52.222: //-1//PCM :HN0002A082:/CallSetupHandler:
(CS_SETTING[0])
-----(CS_EV_OUTBOUNDAPP[17])------->>>(CS_OUTBOUND_HANDOFF[13])
*Mar 1 00:02:52.226: %ISDN-6-LAYER2UP: Layer 2 for Interface BR1/0, TEI
65 changed to up
*Mar 1 00:02:52.230: BRI1/0 : sending datagramsize 11
*Mar 1 00:02:52.230: //-1//APPL:/AppNewEvent: New event 0x831025A4
*Mar 1 00:02:52.234: //3//APPL:/AppProcessEvent: Event 0x831025A4
CC_EV_CALL_HANDOFF[19]:
*Mar 1 00:02:52.234: //3//APPL:/AppProcessEvent: LEG[3
][TCL_HAND][LEG_INCPROCEED(3)][Cause(0)][UC=1 ]
*Mar 1 00:02:52.234: //3//TCL2:/TclInterpHandler: Tcl handler
0x83108340 processing CC_EV_CALL_HANDOFF
*Mar 1 00:02:52.234: //3//TCL2:/TclInterpDriver:
*Mar 1 00:02:52.234: //3//TCL2:/TclEventPreprocessing:
*Mar 1 00:02:52.238: //3//APPL:/AppTypeAheadFlush: There were 0 in
buffer.
*Mar 1 00:02:52.238: //3//TCL2:/MakeTransition: FSM Transtion: ([1
]CALL_INIT,[19]ev_handoff)---([-1]IGNORE)--->([1 ]CALL_INIT)
*Mar 1 00:02:52.238: //-1//APPL:/AppFreeEvent: Freeing event 0x831025A4
CC_EV_CALL_HANDOFF[19]
*Mar 1 00:02:52.238: //-1//APPL:/AppNewEvent: New event 0x83102ED4
*Mar 1 00:02:52.238: //-1//APPL:/AppFreeEvent: Freeing event 0x83102ED4
APP_EV_NULL[0]
*Mar 1 00:02:52.242: //-1//APPL:/AppNewEvent: New event 0x83103804
*Mar 1 00:02:52.242: //-1//APPL:/AppFreeEvent: Freeing event 0x83103804
APP_EV_NULL[0]
*Mar 1 00:02:52.242: //-1//APPL:/AppNewEvent: New event 0x83104134
*Mar 1 00:02:52.242: //-1//APPL:/AppFreeEvent: Freeing event 0x83104134
APP_EV_NULL[0]
*Mar 1 00:02:52.246: BRI1/0 : received datagramsize 4
*Mar 1 00:03:02.090: BRI1/0 : received datagramsize 4
*Mar 1 00:03:02.250: BRI1/0 : received datagramsize 4
*Mar 1 00:03:02.250: BRI1/0 : sending datagramsize 4
*Mar 1 00:03:02.254: BRI1/0 : sending datagramsize 4
*Mar 1 00:03:02.262: BRI1/0 : received datagramsize 4
*Mar 1 00:03:07.134: BRI1/0 : received datagramsize 3
*Mar 1 00:03:12.267: BRI1/0 : sending datagramsize 4
*Mar 1 00:03:12.271: BRI1/0 : received datagramsize 4
*Mar 1 00:03:12.271: BRI1/0 : sending datagramsize 4
*Mar 1 00:03:12.279: BRI1/0 : received datagramsize 4
*Mar 1 00:03:15.356: BRI1/0 : received datagramsize 12
*Mar 1 00:03:15.356: BRI1/0 : sending datagramsize 4
*Mar 1 00:03:15.368: BRI1/0 : sending datagramsize 8
*Mar 1 00:03:15.368: //-1//APPL:/AppNewEvent: New event 0x83104A64
*Mar 1 00:03:15.372: //3//APPL:/AppProcessEvent: Event 0x83104A64
CC_EV_CALL_DISCONNECTED[15]:
*Mar 1 00:03:15.372: //3//APPL:/AppProcessEvent: LEG[3
][TCL_HAND][LEG_INCPROCEED(3)][Cause(16)][UC=1 ]
*Mar 1 00:03:15.372: //3//TCL2:/TclInterpHandler: Tcl handler
0x83108340 processing CC_EV_CALL_DISCONNECTED
*Mar 1 00:03:15.372: //3//TCL2:/TclInterpDriver:
*Mar 1 00:03:15.372: //3//TCL2:/TclEventPreprocessing:
*Mar 1 00:03:15.372: //3//TCL2:/MakeTransition: FSM Transtion: ([1
]CALL_INIT,[15]ev_disconnected)---([7 ]act_Cleanup)--->([3 ]SAMESTATE)
*Mar 1 00:03:15.376: //3//TCL2:/tcl_callCmd: call close
*Mar 1 00:03:15.376: //3//TCL2:/tcl_closeCallCmd: close
{HAN[TCL_HAND][NULL ] ( LEG[3
][TCL_HAND][LEG_INCPROCEED(3)][Cause(16)][UC=1 ])}
*Mar 1 00:03:15.376: //-1//APPL:/AppFreeEvent: Freeing event 0x83104A64
CC_EV_CALL_DISCONNECTED[15]
*Mar 1 00:03:15.380: //-1//APPL:/AppNewEvent: New event 0x83105394
*Mar 1 00:03:15.380: //-1//TCL2:HN0002A0BE:/TclCallProcess: Interp Done
*Mar 1 00:03:15.380: //3//TCL2:/TclInterpCleanup: Terminate TRUE
Terminated FALSE{HAN[TCL_HAND][NULL ] ( LEG[3
][TCL_HAND][LEG_INCPROCEED(3)][.Cau}*Mar 1 00:03:15.380: BRI1/0 :
received datagramsize 4
*Mar 1 00:03:15.380: //3//TCL2:/TclInterpCleanup:
*Mar 1 00:03:15.384: TclInterpCleanup: pInterp->lastFailureCause=16,
pLeg->discCause=16
*Mar 1 00:03:15.384: //-1//APPL:/AppFreeEvent: Freeing event 0x83105394
APP_EV_TCLINTERP_DONE[101]
*Mar 1 00:03:15.384: //-1//APPL:/AppNewEvent: New event 0x830FA504
*Mar 1 00:03:15.384: //-1//APPL:/AppFreeEvent: Freeing event 0x830FA504
APP_EV_NULL[0]
*Mar 1 00:03:15.396: //-1//APPL:/AppNewEvent: New event 0x830FAE34
*Mar 1 00:03:15.396: //-1//APPL:HN00000000:/AppProcessEvent: Event
0x830FAE34 CC_EV_CALL_DISCONNECT_NOTIFY[17]:
*Mar 1 00:03:15.396: //-1//APPL:HN00000000:/AppProcessEvent:
HAN[xferHan][CS_HAND ][FALSE] [UC=0 ]
*Mar 1 00:03:15.396: //-1//APPL:HN00000000:/ah_handler_func:
*Mar 1 00:03:15.396: //-1//APPL:HN00000000:/act_notify:
*Mar 1 00:03:15.396: //-1//APPL:HN00000000:/ah_transfer_complete:
Returning 0 legs
*Mar 1 00:03:15.400: //-1//APPL:/AppFreeEvent: Freeing event 0x830FAE34
CC_EV_CALL_DISCONNECT_NOTIFY[17]
*Mar 1 00:03:15.400: //-1//APPL:/AppNewEvent: New event 0x830FB764
*Mar 1 00:03:15.400: //-1//PCM :HN0002A082:/CS_OUTBOUND_XferDone:
*Mar 1 00:03:15.400: //-1//PCM :HN0002A08E:/DNCleanup: Terminate=TRUE
Status DN_SUCCESS
*Mar 1 00:03:15.404: //-1//PCM :HN0002A08E:/DNSettlementCleanup: cid(3)
trans=0x0, provider=0
*Mar 1 00:03:15.404: //-1//APPL:HN0002A08E:/AppPopHandler: Poping
{HAN[DN_HAND ][CS_HAND ] ( )}
*Mar 1 00:03:15.404: //-1//PCM :HN0002A08E:/DNSetFree:
*Mar 1 00:03:15.404: //-1//APPL:HN00000000:/ah_cleanup_xfer:
*Mar 1 00:03:15.404: //-1//APPL:HN00000000:/AppPopHandler: Poping
{HAN[xferHand][CS_HAND ] ( )}
*Mar 1 00:03:15.408: //-1//APPL:HN00000000:/ah_xfer_set_free:
*Mar 1 00:03:15.408: //-1//APPL:HN00000000:/ah_free_xfer:
*Mar 1 00:03:15.408: //-1//APPL:/AppFreeEvent: Freeing event 0x830FB764
APP_EV_XFER_DONE[94]
*Mar 1 00:03:15.408: //-1//PCM :HN0002A082:/CSReturnIFDone:
CallSetup[0x8286BB40] handlercount=0 Waits=0 #Objects=0 (CS_CLEANUP)
*Mar 1 00:03:15.408: CallSetupDump: CallSetup[0x8286BB40] State:
CS_CLEANUP[12] #Handler=0 #Waits=0#Objects=0
*Mar 1 00:03:15.408: All Destinations:
*Mar 1 00:03:15.412: WaitList of Destinations:
*Mar 1 00:03:15.412: Handler Tree{HAN[CS_HAND ][TCL_HAND] ( )}
*Mar 1 00:03:15.412:
*Mar 1 00:03:15.412: Handler Tree Trace
*Mar 1 00:03:15.412: //-1//APPL:/AppNewEvent: New event 0x830FC094
*Mar 1 00:03:15.412: //-1//PCM :HN0002A082:/CSReturnIFDone: CallSetup
Returning(ls_008 Status CS_INCOMING_DISCONNECT)
*Mar 1 00:03:15.412: //-1//PCM :HN0002A082:/CallSetupHandler:
(CS_OUTBOUND_HANDOFF[13])
-----(CS_EV_XFERDONE[16])------->>>(CS_CLEANUP[12])
*Mar 1 00:03:15.416: //-1//TCL2:HN0002A03E:/TclInterpHandler: Tcl
handler 0x824D9AEC processing APP_EV_CALLSETUP_DONE
*Mar 1 00:03:15.416: //-1//TCL2:HN0002A03E:/TclInterpDriver:
*Mar 1 00:03:15.416: //-1//TCL2:HN0002A03E:/TclEventPreprocessing:
*Mar 1 00:03:15.416: //-1//TCL2:HN0002A03E:/MakeTransition: FSM
Transtion: ([3 ]SAMESTATE,[92]ev_setup_done)---([1 ]act_PCDone)--->([4
]CALL_CLOSED)
*Mar 1 00:03:15.416: //-1//TCL2:HN0002A03E:/tcl_callCmd: call close
*Mar 1 00:03:15.420: //-1//TCL2:HN0002A03E:/tcl_closeCallCmd: close
{HAN[TCL_HAND][NULL ] ( HAN[CS_HAND][TCL_HAND][TRUE] [UC=1 ])}
*Mar 1 00:03:15.420: //-1//TCL2:HN0002A03E:/tcl_fsmCmd: fsm setstate
CALL_CLOSED
*Mar 1 00:03:15.420: //-1//TCL2:HN0002A03E:/tcl_setStateCmd: setstate
CALL_CLOSED
*Mar 1 00:03:15.424: //-1//PCM :HN0002A082:/CallSetupCleanup:
Terminate=FALSE
*Mar 1 00:03:15.424: //-1//PCM :HN0002A082:/CallSetupCleanup: State
CS_CLEANUP
*Mar 1 00:03:15.424: //-1//APPL:HN0002A082:/AppPopHandler: Poping
{HAN[CS_HAND ][TCL_HAND] ( )}
*Mar 1 00:03:15.424: //-1//APPL:/AppFreeEvent: Freeing event 0x830FC094
APP_EV_CALLSETUP_DONE[92]
*Mar 1 00:03:15.424: //-1//APPL:/AppNewEvent: New event 0x830FC9C4
*Mar 1 00:03:15.428: //-1//TCL2:HN0002A03E:/TclCallProcess: Interp Done
*Mar 1 00:03:15.428: //-1//TCL2:HN0002A03E:/TclInterpCleanup: Terminate
TRUE Terminated FALSE{HAN[TCL_HAND][NULL ] ( )}
*Mar 1 00:03:15.428: //-1//TCL2:HN0002A03E:/TclFreeInterp:
{HAN[TCL_HAND][NULL ] ( )}
*Mar 1 00:03:15.428: //-1//APPL:/AppObjCleanupObjectTable:
*Mar 1 00:03:15.428: //-1//APPL:/AppManagerFreeProcess:
pProcess(0x830E9660)=2
*Mar 1 00:03:15.432: //-1//APPL:/AppFreeEvent: Freeing event 0x830FC9C4
APP_EV_TCLINTERP_DONE[101]
*Mar 1 00:03:15.432: //-1//APPL:/AppNewEvent: New event 0x830FD2F4
*Mar 1 00:03:15.432: //3//APPL:/AppProcessEvent: Event 0x830FD2F4
CC_EV_CALL_DISCONNECT_DONE[16]:
*Mar 1 00:03:15.432: //3//APPL:/AppProcessEvent: LEG[3
][TCL_HAND][LEG_DISCONNECTING(9)][Cause(16)][UC=1 ]
*Mar 1 00:03:15.432: //3//TCL2:/TclInterpHandler: Tcl handler
0x83108340 processing CC_EV_CALL_DISCONNECT_DONE
*Mar 1 00:03:15.436: //3//TCL2:/TclInterpCleaner:
*Mar 1 00:03:15.436: //3//APPL:/AppFreeLeg: Call Id 3
*Mar 1 00:03:15.436: //-1//APPL:/AppFreeEvent: Freeing event 0x830FD2F4
CC_EV_CALL_DISCONNECT_DONE[16]
*Mar 1 00:03:15.436: //-1//APPL:/AppNewEvent: New event 0x830FDC24
*Mar 1 00:03:15.436: //-1//TCL2:HN0002A0BE:/TclCallProcess: Interp Done
*Mar 1 00:03:15.440: //-1//TCL2:HN0002A0BE:/TclInterpCleanup: Terminate
TRUE Terminated TRUE{HAN[TCL_HAND][NULL ] ( )}
*Mar 1 00:03:15.440: //-1//TCL2:HN0002A0BE:/TclFreeInterp:
{HAN[TCL_HAND][NULL ] ( )}
*Mar 1 00:03:15.440: //-1//APPL:/AppObjCleanupObjectTable:
*Mar 1 00:03:15.440: //-1//APPL:/AppManagerFreeProcess:
pProcess(0x830E9660)=1
*Mar 1 00:03:15.440: //-1//APPL:/AppFreeEvent: Freeing event 0x830FDC24
APP_EV_TCLINTERP_DONE[101]
*Mar 1 00:03:15.444: //-1//APPL:/AppNewEvent: New event 0x830FE554
*Mar 1 00:03:15.444: //-1//APPL:/AppFreeEvent: Freeing event 0x830FE554
APP_EV_NULL[0]>
*Mar 1 00:03:25.376: BRI1/0 : received datagramsize 4
*Mar 1 00:03:25.380: BRI1/0 : sending datagramsize 4
*Mar 1 00:03:30.344: BRI1/0 : received datagramsize 3
*Mar 1 00:03:30.344: %ISDN-6-LAYER2DOWN: Layer 2 for Interface BR1/0,
TEI 65 changed to down
*Mar 1 00:03:30.344: BRI1/0 : sending datagramsize 3
NM-2V and VIC-2BRI-S/T-TE for the fax part. I've previously tried to use
this box for traditional VoIP (see my post yesterday about a problem
that was fixed with off-list help) and it seems to work fine. Extract
from show version:
System image file is "flash:c2600-is4-mz.123-6.bin"
cisco 2611 (MPC860) processor (revision 0x203) with 61440K/4096K bytes
of memory.
Basic Rate ISDN software, Version 1.1.
2 Ethernet/IEEE 802.3 interface(s)
3 ISDN Basic Rate interface(s)
4 Voice TE BRI interface(s)
I've attached the entire config file (sans passwords) below. It's mostly
based on Cisco's documentation for 12.2T. (There doesn't seem to be
12.3-specific fax documentation).
The 2611 is 192.168.1.102. I have an SMTP server set up at 192.168.1.103
which is set up to receive and forward all mail sent to
*@fax.unicast.org. The MX record is also set up properly. I'm starting
with the on-ramp fax gateway for now.
When I call the number (32580668) with a regular phone, the 2611 doesn't
pick up the call.
What follows is config file as well as debug bri-interface and debug
voice ivr all output (very long). I've turned off AAA and I don't
understand why it doesn't pick up the call.
Thanks,
Guan
config file:
Current configuration : 2623 bytes
!
version 12.3
service timestamps debug datetime msec
service timestamps log datetime msec
no service password-encryption
no service dhcp
!
hostname jefferson
!
boot-start-marker
boot-end-marker
!
! enable secret
!
clock timezone CET 1
clock summer-time CEST recurring
no aaa new-model
ip subnet-zero
ip cef
!
!
ip name-server 192.168.1.103
ip name-server 212.54.64.170
ip name-server 212.54.64.171
!
isdn switch-type basic-net3
!
!
!
voice class codec 1
codec preference 1 g711alaw
codec preference 2 g729br8
codec preference 3 g729r8
codec preference 4 g723r63
codec preference 5 g723r53
codec preference 6 g711ulaw
!
voice class codec 2
codec preference 1 g711alaw
codec preference 2 g723r63
codec preference 3 g723r53
codec preference 4 g729br8
codec preference 5 g729r8
codec preference 7 gsmfr
codec preference 8 gsmefr
codec preference 9 g711ulaw
!
!
!
!
!
!
!
!
!
fax receive called-subscriber $d$
fax interface-type fax-mail
mta send server 192.168.1.103 port 25
mta send subject "Fax"
mta send origin-prefix "Cisco-Powered Fax System"
mta send postmaster guan-postmaster@unicast.org
mta send mail-from hostname fax.unicast.org
mta send mail-from username $s$
mta send return-receipt-to username $s$
!
!
!
!
interface Loopback0
no ip address
!
interface Ethernet0/0
ip address 192.168.1.102 255.255.255.0
ip access-group 1 in
ip access-group 1 out
no ip mroute-cache
full-duplex
no cdp enable
!
interface BRI0/0
no ip address
no ip mroute-cache
shutdown
isdn switch-type basic-net3
no cdp enable
!
interface Ethernet0/1
description Built-in hub in Engvej Speedstream router
no ip address
no ip mroute-cache
shutdown
full-duplex
no cdp enable
!
interface BRI1/0
no ip address
isdn switch-type basic-net3
isdn incoming-voice voice
isdn answer1 32580668
isdn calling-number 32848286
!
interface BRI1/1
no ip address
shutdown
isdn switch-type basic-net3
!
ip http server
ip classless
!
!
access-list 1 permit any
!!
call application voice onramp flash:app_faxmail_onramp.tcl
!
voice-port 1/0/0
no echo-cancel enable
compand-type a-law
no comfort-noise
cptone DK
!
voice-port 1/0/1
compand-type a-law
cptone DK
!
!
!
dial-peer voice 2 pots
application onramp
incoming called-number 32580668
direct-inward-dial
!
dial-peer voice 3 mmoip
application onramp out-bound
destination-pattern 32580668
information-type fax
session target mailto:$d$@fax.unicast.org
dsn success
!
sip-ua
sip-server ipv4:192.168.1.101
!
!
line con 0
exec-timeout 0 0
line aux 0
line vty 0 4
password vtpassword
login
!
!
!
end
Serial console debug output:
jefferson#
*Mar 1 00:02:52.074: BRI1/0 : received datagramsize 43
*Mar 1 00:02:52.090: //3/EE5E21958008/APPL:/AppManagerCCAPI_Interface:
*Mar 1 00:02:52.090: //-1//TCL2:/TclGetInterp: Script onramp
*Mar 1 00:02:52.094: //-1//APPL:/AppNewLeg:
*Mar 1 00:02:52.094: //-1//APPL:LG-1:/AppNewLeg: New Leg[0x824DCC78]
*Mar 1 00:02:52.094: //-1//APPL:/AppSaveRawMsg:
*Mar 1 00:02:52.094: //3//APPL:LP:HN0002A03E:/AppPushLegORConnection:
Pushing LEG[3 ][NULL ][LEG_INCINIT(1)][Cause(0)][UC=1 ] Onto
{HAN[TCL_HAND][.NULL}*Mar 1 00:02:52.098: //-1//APPL:/AppNewEvent: New
event 0x83101344
*Mar 1 00:02:52.098: //3//APPL:/AppProcessEvent: Event 0x83101344
CC_EV_CALL_SETUP_IND[28]:
*Mar 1 00:02:52.098: //3//APPL:/AppProcessEvent: LEG[3
][TCL_HAND][LEG_INCINIT(1)][Cause(0)][UC=1 ]
*Mar 1 00:02:52.098: //3//TCL2:/TclInterpHandler: Tcl handler
0x824D9AEC processing CC_EV_CALL_SETUP_IND
*Mar 1 00:02:52.098: //3//TCL2:/TclInterpDriver:
*Mar 1 00:02:52.102: //3//TCL2:/TclEventPreprocessing:
*Mar 1 00:02:52.102: //-1//TCL2:/TclIncomingCallBlock:
*Mar 1 00:02:52.102: //3//TCL2:/SettlementValidateCall: target=,
tokenp=0x0
*Mar 1 00:02:52.102: //3//TCL2:/MakeTransition: FSM Transtion: ([1
]CALL_INIT,[28]ev_setup_indication)---([9 ]act_Setup)--->([3 ]SAMESTATE)
*Mar 1 00:02:52.106: //3//TCL2:/tcl_infotagCmd: infotag set
med_language 1
*Mar 1 00:02:52.106: //3//TCL2:/tcl_setInfoCmd: set med_language 1
*Mar 1 00:02:52.106: //3//TCL2:/vtw_ms_language: argc 3 argindex 2
*Mar 1 00:02:52.110: //3//TCL2:/tcl_infotagCmd: infotag get
cfg_avpair_exists authentication
*Mar 1 00:02:52.110: //3//TCL2:/tcl_getInfoCmd: get cfg_avpair_exists
authentication
*Mar 1 00:02:52.110: //3//TCL2:/vtr_cf_avpair_exists: argc 3 argindex 2
*Mar 1 00:02:52.110: //3//TCL2:/tcl_PutsCmd:
Authentication control is 0
*Mar 1 00:02:52.114:
*Mar 1 00:02:52.114: //3//TCL2:/tcl_infotagCmd: infotag get
cfg_avpair_exists accounting
*Mar 1 00:02:52.114: //3//TCL2:/tcl_getInfoCmd: get cfg_avpair_exists
accounting
*Mar 1 00:02:52.114: //3//TCL2:/vtr_cf_avpair_exists: argc 3 argindex 2
*Mar 1 00:02:52.114: //3//TCL2:/tcl_PutsCmd:
Accounting control is 0
*Mar 1 00:02:52.118:
*Mar 1 00:02:52.118: //3//TCL2:/tcl_infotagCmd: infotag get
cfg_avpair_exists authen-method
*Mar 1 00:02:52.118: //3//TCL2:/tcl_getInfoCmd: get
*Mar 1 00:02:52.118: BRI1/0 : received datagramsize 3cfg_avpair_exists
authen-method
*Mar 1 00:02:52.118: //3//TCL2:/vtr_cf_avpair_exists: argc 3 argindex 2
*Mar 1 00:02:52.122: //3//TCL2:/tcl_PutsCmd:
Authentication method is 0
*Mar 1 00:02:52.122:
*Mar 1 00:02:52.122: //3//TCL2:/tcl_infotagCmd: infotag get
cfg_avpair_exists password
*Mar 1 00:02:52.122: //3//TCL2:/tcl_getInfoCmd: get cfg_avpair_exists
password
*Mar 1 00:02:52.122: //3//TCL2:/vtr_cf_avpair_exists: argc 3 argindex 2
*Mar 1 00:02:52.126: //3//TCL2:/tcl_PutsCmd:
Default password is
*Mar 1 00:02:52.126:
*Mar 1 00:02:52.126: //3//TCL2:/tcl_infotagCmd: infotag get
cfg_avpair_exists accounting-list
*Mar 1 00:02:52.126: //3//TCL2:/tcl_getInfoCmd: get cfg_avpair_exists
accounting-list
*Mar 1 00:02:52.130: //3//TCL2:/vtr_cf_avpair_exists: argc 3 argindex 2
*Mar 1 00:02:52.130: //3//TCL2:/tcl_PutsCmd: Accounting method is fax
*Mar 1 00:02:52.130:
*Mar 1 00:02:52.134: //3//TCL2:/tcl_infotagCmd: infotag get
cfg_avpair_exists authen-list
*Mar 1 00:02:52.134: //3//TCL2:/tcl_getInfoCmd: get cfg_avpair_exists
authen-list
*Mar 1 00:02:52.134: //3//TCL2:/vtr_cf_avpair_exists: argc 3 argindex 2
*Mar 1 00:02:52.138: //3//TCL2:/tcl_infotagCmd: infotag get leg_ani
*Mar 1 00:02:52.138: //3//TCL2:/tcl_getInfoCmd: get leg_ani
*Mar 1 00:02:52.138: //3//TCL2:/vtr_lg_ani: argc 2 argindex 2
*Mar 1 00:02:52.142: //3//TCL2:/tcl_infotagCmd: infotag get leg_dnis
*Mar 1 00:02:52.142: //3//TCL2:/tcl_getInfoCmd: get leg_dnis
*Mar 1 00:02:52.142: //3//TCL2:/vtr_lg_dnis: argc 2 argindex 2
*Mar 1 00:02:52.142: //3//TCL2:/tcl_infotagCmd: infotag
*Mar 1 00:02:52.146: BRI1/0 : received datagramsize 4get leg_isdid
*Mar 1 00:02:52.146: //3//TCL2:/tcl_getInfoCmd: get leg_isdid
*Mar 1 00:02:52.146: //3//TCL2:/vtr_lg_incdid: argc 2 argindex 2
*Mar 1 00:02:52.146: //3//TCL2:/tcl_infotagCmd: infotag get leg_dnis
*Mar 1 00:02:52.146: //3//TCL2:/tcl_getInfoCmd: get leg_dnis
*Mar 1 00:02:52.150: //3//TCL2:/vtr_lg_dnis: argc 2 argindex 2
*Mar 1 00:02:52.150: //3//TCL2:/tcl_PutsCmd:
destination is 32580668
*Mar 1 00:02:52.154:
*Mar 1 00:02:52.154: //3//TCL2:/tcl_legCmd: leg proceeding leg_incoming
*Mar 1 00:02:52.158: //3//TCL2:/tcl_callProceedingCmd: proceeding
leg_incoming
*Mar 1 00:02:52.158: //3//TCL2:/vtd_lg_incoming: argc 2
*Mar 1 00:02:52.158: //3//TCL2:/vtd_lg_incoming: Legs [3 ]
*Mar 1 00:02:52.158: //3//TCL2:/tcl_parseCallID_vartag: VARTAG
Translation Leg Count=1
*Mar 1 00:02:52.158: //3//TCL2:/tcl_legCmd: leg setup 32580668 callInfo
leg_incoming
*Mar 1 00:02:52.162: //3//TCL2:/tcl_callSetupCmd: setup 32580668
callInfo leg_incoming
*Mar 1 00:02:52.162: //3//TCL2:/vtd_lg_incoming: argc 4
*Mar 1 00:02:52.162: //3//TCL2:/vtd_lg_incoming: Legs [3 ]
*Mar 1 00:02:52.162: //3//TCL2:/tcl_parseCallID_vartag: VARTAG
Translation Leg Count=1
*Mar 1 00:02:52.166: //-1//APPL:/AppSaveRawMsg:
*Mar 1 00:02:52.170: //-1//PCM
:LP:HN0002A082:HN0002A03E:/InitiateCallSetup: Mode 1 RedirectMode 1
Incoming leg[3] AlertTime -1 Destinations(1) [ 32580668 ]
*Mar 1 00:02:52.170:
//-1//APPL:LP:HN0002A082:HN0002A03E:/AppPushHandler: Pushing
{HAN[CS_HAND ][NULL ] ( )} Onto {HAN[TCL_HAND][NULL ] (
LEG[3}*Mar 1 00:02:52.170:
//3//APPL:LP:HN0002A082:/AppPushLegORConnection: Pushing LEG[3
][TCL_HAND][LEG_INCPROCEED(3)][Cause(0)][UC=1 ] Onto {HAN[CS_HAND
][.T}*Mar 1 00:02:52.174: Redirect Cap is LEG_REDIR_UNKNOWN
*Mar 1 00:02:52.174: Redirect Cap is LEG_REDIR_UNKNOWN
*Mar 1 00:02:52.174: //-1//APPL:/AppSaveRawMsg:
*Mar 1 00:02:52.174: //-1//PCM :HN0002A08E:/InitiateCallSetup:
Destination 0 guid : EE5E2195.14EE11CC.80089483.E9D5DAA3
*Mar 1 00:02:52.174: incoming_guid :
00000000.00000000.00000000.00000000
*Mar 1 00:02:52.178: //-1//PCM :HN0002A08E:/DNInitiate:
Destination[32580668]
*Mar 1 00:02:52.178:
//-1//APPL:LP:HN0002A08E:HN0002A082:/AppPushHandler: Pushing
{HAN[DN_HAND ][NULL ] ( )} Onto {HAN[CS_HAND ][TCL_HAND] (
LEG[.3}*Mar 1 00:02:52.178: //-1//PCM :HN0002A08E:/DNQueuePeers: Matched
peers(1)
*Mar 1 00:02:52.182: //-1//PCM :HN0002A08E:/DNSetupPeer: Destination
0x8310B004
*Mar 1 00:02:52.182: //-1//PCM :HN0002A08E:/DNSetupPeer: dialpeer tags
for Rotary = 3
*Mar 1 00:02:52.182: //-1//PCM :HN0002A08E:/DNSetupPeer:
*Mar 1 00:02:52.182: Destination SetupPeer cid(3), destPat(32580668),
match(8), prefix(), peer(82FB0298) hiddenLeg(-1)
*Mar 1 00:02:52.182: //-1//PCM :HN0002A08E:/DNSetupPeer: Found outbound
application (onramp) in dialpeer
*Mar 1 00:02:52.186: //-1//APPL:/AppNewEvent: New event 0x83101C74
*Mar 1 00:02:52.186: //-1//APPL:/AppFreeEvent: Freeing event 0x83101344
CC_EV_CALL_SETUP_IND[28]
*Mar 1 00:02:52.198: BRI1/0 : sending datagramsize 3
*Mar 1 00:02:52.202: //-1//APPL:HN0002A08E:/AppProcessEvent: Event
0x83101C74 APP_EV_OUTBOUND_APP[102]:
*Mar 1 00:02:52.202: //-1//APPL:HN0002A08E:/AppProcessEvent:
HAN[DN_HAND][CS_HAND ][FALSE] [UC=1 ]
*Mar 1 00:02:52.202: //-1//PCM :HN0002A08E:/DNHandler:
(DN_MAPPING[0])--(APP_EV_OUTBOUND_APP[102])--IGNORED-->>(DN_MAPPING[0])
*Mar 1 00:02:52.202: //-1//PCM :HN0002A082:/CS_OutboundApp: Event 102,
in State 0
*Mar 1 00:02:52.202: //-1//PCM :HN0002A082:/CSDiscReturnAndEmptyLegALL:
*Mar 1 00:02:52.206: //3//APPL:/ah_put_in_the_bag: Bag of Objects:
LEG[3 ][CS_HAND ][LEG_INCPROCEED(3)][Cause(0)][UC=1 ]
*Mar 1 00:02:52.206: //-1//PCM :HN0002A082:/CS_OutboundApp: out bound
peer tag (3)
*Mar 1 00:02:52.206: //-1//APPL:/ah_call_app:
*Mar 1 00:02:52.206:
//-1//APPL:LP:HN00000000:HN0002A082:/AppPushHandler: Pushing
{HAN[xferHand][NULL ] ( )} Onto {HAN[CS_HAND ][TCL_HAND] (
LEG[3}*Mar 1 00:02:52.210:
//3//APPL:LP:HN00000000:/AppPushLegORConnection: Pushing LEG[3
][CS_HAND ][LEG_INCPROCEED(3)][Cause(0)]
*Mar 1 00:02:52.210: BRI1/0 : received datagramsize 3[UC=1 ] Onto
{HAN[xferHand][CS_HAND ] ( )}
*Mar 1 00:02:52.210: //-1//APPL:HN00000000:/ah_transfer_out_handoff:
*Mar 1 00:02:52.214: //3//APPL:/AppPopLegORConnectionOffAll: Popping
LEG[3 ][xferHand][LEG_INCPROCEED(3)][Cause(0)][UC=1 ] Off
{HAN[xferHand][CS_HAND ] }*Mar 1 00:02:52.214:
//3//APPL:/AppPopLegORConnectionOffAll: Popping LEG[3
][xferHand][LEG_INCPROCEED(3)][Cause(0)][UC=1 ] Off {HAN[CS_HAND
][TCL_HAND] }*Mar 1 00:02:52.218:
//3//APPL:/AppPopLegORConnectionOffAll: Popping LEG[3
][xferHand][LEG_INCPROCEED(3)][Cause(0)][UC=1 ] Off
{HAN[TCL_HAND][NULL ] }*Mar 1 00:02:52.218:
//3//APPL:/AppManagerCCAPI_Interface:
*Mar 1 00:02:52.218: //-1//TCL2:/TclGetInterp: Script onramp
*Mar 1 00:02:52.222: //3//APPL:LP:HN0002A0BE:/AppPushLegORConnection:
Pushing LEG[3 ][NULL ][LEG_INCPROCEED(3)][Cause(0)][UC=1 ] Onto
{HAN[TCL_HAND][.N}*Mar 1 00:02:52.222: //3//APPL:/AppMediaDestroy:
*Mar 1 00:02:52.222: //-1//APPL:/AppFreeEvent: Freeing event 0x83101C74
APP_EV_OUTBOUND_APP[102]
*Mar 1 00:02:52.222: //-1//PCM :HN0002A082:/CallSetupHandler:
(CS_SETTING[0])
-----(CS_EV_OUTBOUNDAPP[17])------->>>(CS_OUTBOUND_HANDOFF[13])
*Mar 1 00:02:52.226: %ISDN-6-LAYER2UP: Layer 2 for Interface BR1/0, TEI
65 changed to up
*Mar 1 00:02:52.230: BRI1/0 : sending datagramsize 11
*Mar 1 00:02:52.230: //-1//APPL:/AppNewEvent: New event 0x831025A4
*Mar 1 00:02:52.234: //3//APPL:/AppProcessEvent: Event 0x831025A4
CC_EV_CALL_HANDOFF[19]:
*Mar 1 00:02:52.234: //3//APPL:/AppProcessEvent: LEG[3
][TCL_HAND][LEG_INCPROCEED(3)][Cause(0)][UC=1 ]
*Mar 1 00:02:52.234: //3//TCL2:/TclInterpHandler: Tcl handler
0x83108340 processing CC_EV_CALL_HANDOFF
*Mar 1 00:02:52.234: //3//TCL2:/TclInterpDriver:
*Mar 1 00:02:52.234: //3//TCL2:/TclEventPreprocessing:
*Mar 1 00:02:52.238: //3//APPL:/AppTypeAheadFlush: There were 0 in
buffer.
*Mar 1 00:02:52.238: //3//TCL2:/MakeTransition: FSM Transtion: ([1
]CALL_INIT,[19]ev_handoff)---([-1]IGNORE)--->([1 ]CALL_INIT)
*Mar 1 00:02:52.238: //-1//APPL:/AppFreeEvent: Freeing event 0x831025A4
CC_EV_CALL_HANDOFF[19]
*Mar 1 00:02:52.238: //-1//APPL:/AppNewEvent: New event 0x83102ED4
*Mar 1 00:02:52.238: //-1//APPL:/AppFreeEvent: Freeing event 0x83102ED4
APP_EV_NULL[0]
*Mar 1 00:02:52.242: //-1//APPL:/AppNewEvent: New event 0x83103804
*Mar 1 00:02:52.242: //-1//APPL:/AppFreeEvent: Freeing event 0x83103804
APP_EV_NULL[0]
*Mar 1 00:02:52.242: //-1//APPL:/AppNewEvent: New event 0x83104134
*Mar 1 00:02:52.242: //-1//APPL:/AppFreeEvent: Freeing event 0x83104134
APP_EV_NULL[0]
*Mar 1 00:02:52.246: BRI1/0 : received datagramsize 4
*Mar 1 00:03:02.090: BRI1/0 : received datagramsize 4
*Mar 1 00:03:02.250: BRI1/0 : received datagramsize 4
*Mar 1 00:03:02.250: BRI1/0 : sending datagramsize 4
*Mar 1 00:03:02.254: BRI1/0 : sending datagramsize 4
*Mar 1 00:03:02.262: BRI1/0 : received datagramsize 4
*Mar 1 00:03:07.134: BRI1/0 : received datagramsize 3
*Mar 1 00:03:12.267: BRI1/0 : sending datagramsize 4
*Mar 1 00:03:12.271: BRI1/0 : received datagramsize 4
*Mar 1 00:03:12.271: BRI1/0 : sending datagramsize 4
*Mar 1 00:03:12.279: BRI1/0 : received datagramsize 4
*Mar 1 00:03:15.356: BRI1/0 : received datagramsize 12
*Mar 1 00:03:15.356: BRI1/0 : sending datagramsize 4
*Mar 1 00:03:15.368: BRI1/0 : sending datagramsize 8
*Mar 1 00:03:15.368: //-1//APPL:/AppNewEvent: New event 0x83104A64
*Mar 1 00:03:15.372: //3//APPL:/AppProcessEvent: Event 0x83104A64
CC_EV_CALL_DISCONNECTED[15]:
*Mar 1 00:03:15.372: //3//APPL:/AppProcessEvent: LEG[3
][TCL_HAND][LEG_INCPROCEED(3)][Cause(16)][UC=1 ]
*Mar 1 00:03:15.372: //3//TCL2:/TclInterpHandler: Tcl handler
0x83108340 processing CC_EV_CALL_DISCONNECTED
*Mar 1 00:03:15.372: //3//TCL2:/TclInterpDriver:
*Mar 1 00:03:15.372: //3//TCL2:/TclEventPreprocessing:
*Mar 1 00:03:15.372: //3//TCL2:/MakeTransition: FSM Transtion: ([1
]CALL_INIT,[15]ev_disconnected)---([7 ]act_Cleanup)--->([3 ]SAMESTATE)
*Mar 1 00:03:15.376: //3//TCL2:/tcl_callCmd: call close
*Mar 1 00:03:15.376: //3//TCL2:/tcl_closeCallCmd: close
{HAN[TCL_HAND][NULL ] ( LEG[3
][TCL_HAND][LEG_INCPROCEED(3)][Cause(16)][UC=1 ])}
*Mar 1 00:03:15.376: //-1//APPL:/AppFreeEvent: Freeing event 0x83104A64
CC_EV_CALL_DISCONNECTED[15]
*Mar 1 00:03:15.380: //-1//APPL:/AppNewEvent: New event 0x83105394
*Mar 1 00:03:15.380: //-1//TCL2:HN0002A0BE:/TclCallProcess: Interp Done
*Mar 1 00:03:15.380: //3//TCL2:/TclInterpCleanup: Terminate TRUE
Terminated FALSE{HAN[TCL_HAND][NULL ] ( LEG[3
][TCL_HAND][LEG_INCPROCEED(3)][.Cau}*Mar 1 00:03:15.380: BRI1/0 :
received datagramsize 4
*Mar 1 00:03:15.380: //3//TCL2:/TclInterpCleanup:
*Mar 1 00:03:15.384: TclInterpCleanup: pInterp->lastFailureCause=16,
pLeg->discCause=16
*Mar 1 00:03:15.384: //-1//APPL:/AppFreeEvent: Freeing event 0x83105394
APP_EV_TCLINTERP_DONE[101]
*Mar 1 00:03:15.384: //-1//APPL:/AppNewEvent: New event 0x830FA504
*Mar 1 00:03:15.384: //-1//APPL:/AppFreeEvent: Freeing event 0x830FA504
APP_EV_NULL[0]
*Mar 1 00:03:15.396: //-1//APPL:/AppNewEvent: New event 0x830FAE34
*Mar 1 00:03:15.396: //-1//APPL:HN00000000:/AppProcessEvent: Event
0x830FAE34 CC_EV_CALL_DISCONNECT_NOTIFY[17]:
*Mar 1 00:03:15.396: //-1//APPL:HN00000000:/AppProcessEvent:
HAN[xferHan][CS_HAND ][FALSE] [UC=0 ]
*Mar 1 00:03:15.396: //-1//APPL:HN00000000:/ah_handler_func:
*Mar 1 00:03:15.396: //-1//APPL:HN00000000:/act_notify:
*Mar 1 00:03:15.396: //-1//APPL:HN00000000:/ah_transfer_complete:
Returning 0 legs
*Mar 1 00:03:15.400: //-1//APPL:/AppFreeEvent: Freeing event 0x830FAE34
CC_EV_CALL_DISCONNECT_NOTIFY[17]
*Mar 1 00:03:15.400: //-1//APPL:/AppNewEvent: New event 0x830FB764
*Mar 1 00:03:15.400: //-1//PCM :HN0002A082:/CS_OUTBOUND_XferDone:
*Mar 1 00:03:15.400: //-1//PCM :HN0002A08E:/DNCleanup: Terminate=TRUE
Status DN_SUCCESS
*Mar 1 00:03:15.404: //-1//PCM :HN0002A08E:/DNSettlementCleanup: cid(3)
trans=0x0, provider=0
*Mar 1 00:03:15.404: //-1//APPL:HN0002A08E:/AppPopHandler: Poping
{HAN[DN_HAND ][CS_HAND ] ( )}
*Mar 1 00:03:15.404: //-1//PCM :HN0002A08E:/DNSetFree:
*Mar 1 00:03:15.404: //-1//APPL:HN00000000:/ah_cleanup_xfer:
*Mar 1 00:03:15.404: //-1//APPL:HN00000000:/AppPopHandler: Poping
{HAN[xferHand][CS_HAND ] ( )}
*Mar 1 00:03:15.408: //-1//APPL:HN00000000:/ah_xfer_set_free:
*Mar 1 00:03:15.408: //-1//APPL:HN00000000:/ah_free_xfer:
*Mar 1 00:03:15.408: //-1//APPL:/AppFreeEvent: Freeing event 0x830FB764
APP_EV_XFER_DONE[94]
*Mar 1 00:03:15.408: //-1//PCM :HN0002A082:/CSReturnIFDone:
CallSetup[0x8286BB40] handlercount=0 Waits=0 #Objects=0 (CS_CLEANUP)
*Mar 1 00:03:15.408: CallSetupDump: CallSetup[0x8286BB40] State:
CS_CLEANUP[12] #Handler=0 #Waits=0#Objects=0
*Mar 1 00:03:15.408: All Destinations:
*Mar 1 00:03:15.412: WaitList of Destinations:
*Mar 1 00:03:15.412: Handler Tree{HAN[CS_HAND ][TCL_HAND] ( )}
*Mar 1 00:03:15.412:
*Mar 1 00:03:15.412: Handler Tree Trace
*Mar 1 00:03:15.412: //-1//APPL:/AppNewEvent: New event 0x830FC094
*Mar 1 00:03:15.412: //-1//PCM :HN0002A082:/CSReturnIFDone: CallSetup
Returning(ls_008 Status CS_INCOMING_DISCONNECT)
*Mar 1 00:03:15.412: //-1//PCM :HN0002A082:/CallSetupHandler:
(CS_OUTBOUND_HANDOFF[13])
-----(CS_EV_XFERDONE[16])------->>>(CS_CLEANUP[12])
*Mar 1 00:03:15.416: //-1//TCL2:HN0002A03E:/TclInterpHandler: Tcl
handler 0x824D9AEC processing APP_EV_CALLSETUP_DONE
*Mar 1 00:03:15.416: //-1//TCL2:HN0002A03E:/TclInterpDriver:
*Mar 1 00:03:15.416: //-1//TCL2:HN0002A03E:/TclEventPreprocessing:
*Mar 1 00:03:15.416: //-1//TCL2:HN0002A03E:/MakeTransition: FSM
Transtion: ([3 ]SAMESTATE,[92]ev_setup_done)---([1 ]act_PCDone)--->([4
]CALL_CLOSED)
*Mar 1 00:03:15.416: //-1//TCL2:HN0002A03E:/tcl_callCmd: call close
*Mar 1 00:03:15.420: //-1//TCL2:HN0002A03E:/tcl_closeCallCmd: close
{HAN[TCL_HAND][NULL ] ( HAN[CS_HAND][TCL_HAND][TRUE] [UC=1 ])}
*Mar 1 00:03:15.420: //-1//TCL2:HN0002A03E:/tcl_fsmCmd: fsm setstate
CALL_CLOSED
*Mar 1 00:03:15.420: //-1//TCL2:HN0002A03E:/tcl_setStateCmd: setstate
CALL_CLOSED
*Mar 1 00:03:15.424: //-1//PCM :HN0002A082:/CallSetupCleanup:
Terminate=FALSE
*Mar 1 00:03:15.424: //-1//PCM :HN0002A082:/CallSetupCleanup: State
CS_CLEANUP
*Mar 1 00:03:15.424: //-1//APPL:HN0002A082:/AppPopHandler: Poping
{HAN[CS_HAND ][TCL_HAND] ( )}
*Mar 1 00:03:15.424: //-1//APPL:/AppFreeEvent: Freeing event 0x830FC094
APP_EV_CALLSETUP_DONE[92]
*Mar 1 00:03:15.424: //-1//APPL:/AppNewEvent: New event 0x830FC9C4
*Mar 1 00:03:15.428: //-1//TCL2:HN0002A03E:/TclCallProcess: Interp Done
*Mar 1 00:03:15.428: //-1//TCL2:HN0002A03E:/TclInterpCleanup: Terminate
TRUE Terminated FALSE{HAN[TCL_HAND][NULL ] ( )}
*Mar 1 00:03:15.428: //-1//TCL2:HN0002A03E:/TclFreeInterp:
{HAN[TCL_HAND][NULL ] ( )}
*Mar 1 00:03:15.428: //-1//APPL:/AppObjCleanupObjectTable:
*Mar 1 00:03:15.428: //-1//APPL:/AppManagerFreeProcess:
pProcess(0x830E9660)=2
*Mar 1 00:03:15.432: //-1//APPL:/AppFreeEvent: Freeing event 0x830FC9C4
APP_EV_TCLINTERP_DONE[101]
*Mar 1 00:03:15.432: //-1//APPL:/AppNewEvent: New event 0x830FD2F4
*Mar 1 00:03:15.432: //3//APPL:/AppProcessEvent: Event 0x830FD2F4
CC_EV_CALL_DISCONNECT_DONE[16]:
*Mar 1 00:03:15.432: //3//APPL:/AppProcessEvent: LEG[3
][TCL_HAND][LEG_DISCONNECTING(9)][Cause(16)][UC=1 ]
*Mar 1 00:03:15.432: //3//TCL2:/TclInterpHandler: Tcl handler
0x83108340 processing CC_EV_CALL_DISCONNECT_DONE
*Mar 1 00:03:15.436: //3//TCL2:/TclInterpCleaner:
*Mar 1 00:03:15.436: //3//APPL:/AppFreeLeg: Call Id 3
*Mar 1 00:03:15.436: //-1//APPL:/AppFreeEvent: Freeing event 0x830FD2F4
CC_EV_CALL_DISCONNECT_DONE[16]
*Mar 1 00:03:15.436: //-1//APPL:/AppNewEvent: New event 0x830FDC24
*Mar 1 00:03:15.436: //-1//TCL2:HN0002A0BE:/TclCallProcess: Interp Done
*Mar 1 00:03:15.440: //-1//TCL2:HN0002A0BE:/TclInterpCleanup: Terminate
TRUE Terminated TRUE{HAN[TCL_HAND][NULL ] ( )}
*Mar 1 00:03:15.440: //-1//TCL2:HN0002A0BE:/TclFreeInterp:
{HAN[TCL_HAND][NULL ] ( )}
*Mar 1 00:03:15.440: //-1//APPL:/AppObjCleanupObjectTable:
*Mar 1 00:03:15.440: //-1//APPL:/AppManagerFreeProcess:
pProcess(0x830E9660)=1
*Mar 1 00:03:15.440: //-1//APPL:/AppFreeEvent: Freeing event 0x830FDC24
APP_EV_TCLINTERP_DONE[101]
*Mar 1 00:03:15.444: //-1//APPL:/AppNewEvent: New event 0x830FE554
*Mar 1 00:03:15.444: //-1//APPL:/AppFreeEvent: Freeing event 0x830FE554
APP_EV_NULL[0]>
*Mar 1 00:03:25.376: BRI1/0 : received datagramsize 4
*Mar 1 00:03:25.380: BRI1/0 : sending datagramsize 4
*Mar 1 00:03:30.344: BRI1/0 : received datagramsize 3
*Mar 1 00:03:30.344: %ISDN-6-LAYER2DOWN: Layer 2 for Interface BR1/0,
TEI 65 changed to down
*Mar 1 00:03:30.344: BRI1/0 : sending datagramsize 3