TCL fails with incorrect codec?

Version 1
    This document was generated from CDN thread

    Created by: Mark Alliban on 17-01-2012 05:31:14 AM
    Hi,
    I am running a TCL code for our application. The dial-peer has a codec class to prevent all our bandwidth being eaten up by users trying to use g711:
     

    voice class codec 1
     codec preference 1 g729r8
     codec preference 2 g729br8
    dial-peer voice 18 voip


     voice-class codec 1
     incoming called-number .T

     
    However, if a call is sent using g711 or any other unsupported codec, we get problems. The call disconnects and the TCL script terminates, but it does not trigger the ev_disconnected event. I have in my TCL:
     

    proc act_Cleanup { } { 
    puts "act_Cleanup triggered"
    }
    set fsm(any_state,ev_disconnected)         "act_Cleanup           same_state" 


    But this never gets called when I use wrong codec. Any ideas?

    Subject: RE: TCL fails with incorrect codec?
    Replied by: Raghavendra Gutty Veeranagappa on 17-01-2012 07:33:20 AM
    Hi Mark,

    Is TCL script being picked up because i couldn't see TCL script configured under dial-peer, if yes please send us the below logs.

    debug voip app

    Thanks,
    Raghavendra

    Subject: RE: TCL fails with incorrect codec?
    Replied by: Mark Alliban on 17-01-2012 07:54:48 AM
    Yes the TCL is running, I cut the dial-peer for brevity.
    When I do debug voip app the output is extremely long...

    Jan 17 12:52:01.823: //-1//SERV:/AFW_Service_CCInterface: Received Event 24 for service ipCSales modulehandle NULL
    Jan 17 12:52:01.823: //-1//SERV:/AFW_Service_GetExecEnv: Script Name = ipCSales
    Jan 17 12:52:01.823: //-1//SERV:/AFW_Service_GetExecEnv: Using Cached ExecEnv
    Jan 17 12:52:01.823: //-1//AFW_:EE65B772F4000:/AFW_ExecEnv_SetRoot: Execenv = 0x65B772F4
    Jan 17 12:52:01.823: //-1//AFW_:/AFW_M_TclModule_NewDup: 
    Jan 17 12:52:01.823: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x674D6CC8, Type: TclModule, RefCount: 0
    Jan 17 12:52:01.823: //-1//AFW_:HN6750F510:/AFW_M_TclModule_Free:  MOD[TclModule_674D6CC8_0_1733357716] ( )
    Jan 17 12:52:01.823: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x6631C148, Type: FSM, RefCount: 0
    Jan 17 12:52:01.823: //-1//AFW_:/AFW_M_FSM_Free: 
    Jan 17 12:52:01.823: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x65F5FFC4, Type: DataArray, RefCount: 0
    Jan 17 12:52:01.823: //-1//AFW_:/AFW_Process_Lock: pProcess(0x65B766E4)=1
    Jan 17 12:52:01.823: //-1//AFW_:LP:EE65B772F4000:HN6753A468:/AFW_M_Object_SetExecEnv: ObjCount: 1, CmdPending 0
    Jan 17 12:52:01.823: //-1//AFW_:EE65B772F4000:/AFW_ExecEnv_RestoreDataBackup: Restore DataArea from Script
    Jan 17 12:52:01.827: //-1//AFW_:EE65B772F4000:/AFW_ExecEnv_RestoreDataBackup: Restore TokenTable from Script
    Jan 17 12:52:01.827: //-1//AFW_:EE65B772F4000:/AFW_ExecEnv_Initiate: Execenv = 0x65B772F4
    Jan 17 12:52:01.827: //-1//AFW_:/AFW_Leg_New: 
    Jan 17 12:52:01.827: //331519//AFW_:/AFW_M_Leg_SetExecEnv: 
    Jan 17 12:52:01.827: //-1//AFW_:EE65B772F4000:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 1
    Jan 17 12:52:01.827: //-1//AFW_:LP:EE65B772F4000:LG331519:/AFW_M_Object_SetExecEnv: ObjCount: 2, CmdPending 1
    Jan 17 12:52:01.827: //331519//AFW_:/AFW_M_Leg_GetHandle: Leg handle: LEG_331519
    Jan 17 12:52:01.827: //-1//AFW_:EE65B772F4000:/AFW_ExecEnv_AssignCall: Execenv = 0x65B772F4, Leg = 331519, Peer_Tag = 18
    Jan 17 12:52:01.827: //-1//AFW_:/AFW_Event_New: 
    Jan 17 12:52:01.827: //331519//AFW_:/AFW_Process_GetCcqEvent: Received
    Jan 17 12:52:01.827: //-1//AFW_:/AFW_Process_GetCcqEvent:   Event[CC_EV_CALL_SETUP_IND(29)] {
    Jan 17 12:52:01.827: //-1//AFW_:/AFW_Process_GetCcqEvent:     EXECENV[0x65B772F4]
    Jan 17 12:52:01.827: //-1//AFW_:/AFW_Process_GetCcqEvent:     LEG[331519][LEG_INIT(0)][Cause(0)]
    Jan 17 12:52:01.827: //-1//AFW_:/AFW_Process_GetCcqEvent:   }
    Jan 17 12:52:01.827: //331519//SSIN:/AFW_SS_MapEvent: 
    Jan 17 12:52:01.827: //-1//SSIN:/AFW_SS_SIP_MapEvent: 
    Jan 17 12:52:01.827: //331519/E265318F8701/AFW_:/AFW_Leg_UpdateStats: Updating stats for ID 204FB type 0
    Jan 17 12:52:01.827: //331519/E265318F8701/AFW_:/AFW_Object_WalkListeners: 
    Jan 17 12:52:01.827: //331519/E265318F8701/AFW_:/AFW_M_Object_ShowListeners: START
    Jan 17 12:52:01.827: //-1//AFW_:/AFW_M_Object_ShowListeners:  
    Jan 17 12:52:01.827: //331519//AFW_:/AFW_M_Module_GetHandle: Module handle: TclModule_65D0A070_0_1733534824MOD[TclModule_65D0A070_0_1733534824]  (
    Jan 17 12:52:01.827: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331519][LEG_INCINIT(1)][Cause(0)]
    Jan 17 12:52:01.827: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
    Jan 17 12:52:01.827: //331519/E265318F8701/AFW_:/AFW_M_Object_ShowListeners: END
    Jan 17 12:52:01.827: //331519/E265318F8701/AFW_:/AFW_Object_WalkListeners: Entering Module : TclModule
    Jan 17 12:52:01.827: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: TclModule_65D0A070_0_1733534824 ---> TclModule_65D0A070_0_1733534824
    Jan 17 12:52:01.827: //331519//AFW_:/AFW_M_TclModule_Action: 
    Jan 17 12:52:01.827: //331519//AFW_:/AFW_TclModule_DefaultEvHandling: 
    Jan 17 12:52:01.827: //331519/E265318F8701/AFW_:/AFW_Leg_CheckIncomingCallBlock: 
    Jan 17 12:52:01.827: //331519/E265318F8701/AFW_:/AFW_Leg_SettlementValidateCall: target=ras, tokenp=0x0
    Jan 17 12:52:01.827: //331519/E265318F8701/AFW_:/AFW_Leg_IncomingTranslate: 
    Jan 17 12:52:01.827: //331519//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(CALL_INIT[1],ev_setup_indication[29])---[act_Setup]------
    Jan 17 12:52:01.827: //331519//TCL :/tcl_PutsObjCmd: IP Carrier Sales: setup
    Jan 17 12:52:01.827:
    Jan 17 12:52:01.827: //331519//TCL :/tcl_InfotagObjCmd:  infotag get leg_ani
    Jan 17 12:52:01.827: //331519//TCL :/tcl_InfotagGetObjCmd: infotag get leg_ani
    Jan 17 12:52:01.827: //331519//AFW_:/vtr_lg_ani: argc 2 argindex 2
    Jan 17 12:52:01.827: //331519//TCL :/tcl_InfotagObjCmd:  infotag get leg_dnis
    Jan 17 12:52:01.827: //331519//TCL :/tcl_InfotagGetObjCmd: infotag get leg_dnis
    Jan 17 12:52:01.827: //331519//AFW_:/vtr_lg_dnis: argc 2 argindex 2
    Jan 17 12:52:01.827: //331519//TCL :/tcl_InfotagObjCmd:  infotag get leg_remote_signaling_ip_address leg_incoming
    Jan 17 12:52:01.831: //331519//TCL :/tcl_InfotagGetObjCmd: infotag get leg_remote_signaling_ip_address leg_incoming
    Jan 17 12:52:01.831: //331519//AFW_:/vtr_lg_remote_signaling_ip_address: argc 3 argindex 2
    Jan 17 12:52:01.831: //331519//AFW_:/vtd_lg_incoming: argc 3
    Jan 17 12:52:01.831: //331519//AFW_:/vtd_lg_incoming: Legs [331519 ]
    Jan 17 12:52:01.831: //331519//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Jan 17 12:52:01.831: //331519//TCL :/tcl_InfotagObjCmd:  infotag get leg_remoteipaddress leg_incoming
    Jan 17 12:52:01.831: //331519//TCL :/tcl_InfotagGetObjCmd: infotag get leg_remoteipaddress leg_incoming
    Jan 17 12:52:01.831: //331519//AFW_:/vtr_lg_remoteipaddress: argc 3 argindex 2
    Jan 17 12:52:01.831: //331519//AFW_:/vtd_lg_incoming: argc 3
    Jan 17 12:52:01.831: //331519//AFW_:/vtd_lg_incoming: Legs [331519 ]
    Jan 17 12:52:01.831: //331519//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Jan 17 12:52:01.831: //331519//TCL :/tcl_PutsObjCmd: CSP remoteIP Address- ipAddr:192.168.1.100
    Jan 17 12:52:01.831:
    Jan 17 12:52:01.831: //331519//TCL :/tcl_InfotagObjCmd:  infotag get leg_remoteipaddress leg_incoming
    Jan 17 12:52:01.831: //331519//TCL :/tcl_InfotagGetObjCmd: infotag get leg_remoteipaddress leg_incoming
    Jan 17 12:52:01.831: //331519//AFW_:/vtr_lg_remoteipaddress: argc 3 argindex 2
    Jan 17 12:52:01.831: //331519//AFW_:/vtd_lg_incoming: argc 3
    Jan 17 12:52:01.831: //331519//AFW_:/vtd_lg_incoming: Legs [331519 ]
    Jan 17 12:52:01.831: //331519//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Jan 17 12:52:01.831: //331519//TCL :/tcl_PutsObjCmd: CSP remoteIP Address- ipAddr11:192.168.1.100
    Jan 17 12:52:01.831:
    Jan 17 12:52:01.831: //331519//TCL :/tcl_PutsObjCmd: IP carrier sales: act_GotDest 192.168.1.100#55123456789
    Jan 17 12:52:01.831:
    Jan 17 12:52:01.831: //331519//TCL :/tcl_LegObjCmd:  leg proceeding leg_incoming
    Jan 17 12:52:01.831: //331519//TCL :/tcl_LegProceedObjCmd: proceeding leg_incoming
    Jan 17 12:52:01.831: //331519//AFW_:/vtd_lg_incoming: argc 2
    Jan 17 12:52:01.831: //331519//AFW_:/vtd_lg_incoming: Legs [331519 ]
    Jan 17 12:52:01.831: //331519//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Jan 17 12:52:01.831: //331519//TCL :/tcl_AAAObjCmd:  aaa authorize 0 0 204 192.168.1.100#55123456789# leg_incoming avsend
    Jan 17 12:52:01.831: //331519//TCL :/tcl_AuthorizeObjCmd:  authorize 0 0 204 192.168.1.100#55123456789# leg_incoming avsend
    Jan 17 12:52:01.831: //331519//AFW_:/vtd_lg_incoming: argc 7
    Jan 17 12:52:01.831: //331519//AFW_:/vtd_lg_incoming: Legs [331519 ]
    Jan 17 12:52:01.831: //331519//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Jan 17 12:52:01.831: //-1//TCL :/tclSetAvpair: type>>86, Value>>Value:2500
    Jan 17 12:52:01.831: //-1//TCL :/tclSetAvpair: Attr>>h323-ivr-out, Value>>Value:2500
    Jan 17 12:52:01.831: //-1//TCL :/tclSetAvpair: type>>86, Value>>CS Test Authentication
    Jan 17 12:52:01.831: //-1//TCL :/tclSetAvpair: Attr>>h323-ivr-out, Value>>CS Test Authentication
    Jan 17 12:52:01.831: //331519//TCL :/tcl_AuthorizeObjCmd: account=0, password=0,
    Jan 17 12:52:01.831: //331519//TCL :/tcl_AuthorizeObjCmd:    ani=204, dnis=192.168.1.100#55123456789#, methodList=,
    Jan 17 12:52:01.831: //331519//TCL :/tcl_AuthorizeObjCmd:    av-send=avsend, guid=
    Jan 17 12:52:01.831: //-1//AFW_:/AFW_Event_New: 
    Jan 17 12:52:01.831: //331519//AFW_:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 2
    Jan 17 12:52:01.831: //331519//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 12:52:01.831: //331519//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 12:52:01.831: //331519//TCL :/tcl_FSMObjCmd:  fsm setstate SECONDAUTHORIZE
    Jan 17 12:52:01.831: //331519//TCL :/tcl_FSMSetStateObjCmd: setstate setstate SECONDAUTHORIZE
    Jan 17 12:52:01.831: //331519//AFW_:/AFW_FSM_Drive: ACTION END: -------------(SECONDAUTHORIZE[4])---------------
    Jan 17 12:52:01.831: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: TclModule_65D0A070_0_1733534824 ---> TclModule_65D0A070_0_1733534824
    Jan 17 12:52:01.831: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x6633CCD8, Type: Event, RefCount: 0
    Jan 17 12:52:01.831: //331519/E265318F8701/AFW_:/AFW_M_Event_Free: 
    Jan 17 12:52:01.831: //331519//AFW_:/AFW_ExecEnv_CloseIfDone: Cmd Count: 2
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_TclModule_PopulateRadiusVSA: h323-prompt-id
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_TclModule_PopulateRadiusVSA: h323-credit-time 5400 5400
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_TclModule_PopulateRadiusVSA: h323-ivr-in 232355123456789
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_TclModule_PopulateRadiusVSA: h323-preferred-lang
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_TclModule_PopulateRadiusVSA: h323-return-code 13
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_ExecEnv_DecrNPendingCmd:  PendingCmdCount: 1
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_Process_GetAppQEvent: Received
    Jan 17 12:52:01.975: //-1//AFW_:/AFW_Process_GetAppQEvent:   Event[APP_EV_AUTHORIZE_DONE(144)] {
    Jan 17 12:52:01.975: //-1//AFW_:/AFW_Process_GetAppQEvent:     EXECENV[0x65B772F4]
    Jan 17 12:52:01.975: //-1//AFW_:/AFW_Process_GetAppQEvent:     MOD[TclModule_65D0A070_0_1733534824]  (
    Jan 17 12:52:01.975: //-1//AFW_:/AFW_Process_GetAppQEvent:       LEG[331519][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 12:52:01.975: //-1//AFW_:/AFW_Process_GetAppQEvent:     )
    Jan 17 12:52:01.975: //-1//AFW_:/AFW_Process_GetAppQEvent:   }
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_M_TclModule_EventPreProcess: 
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: NULL ---> TclModule_65D0A070_0_1733534824
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_M_TclModule_Action: 
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_TclModule_DefaultEvHandling: 
    Jan 17 12:52:01.975: //331519//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(SECONDAUTHORIZE[4],ev_authorize_done[144])---[act_SecondAuthorized]------
    Jan 17 12:52:01.979: //331519//TCL :/tcl_PutsObjCmd: IP carrier sales: act_SecondAuthorize
    Jan 17 12:52:01.979:
    Jan 17 12:52:01.979: //331519//TCL :/tcl_InfotagObjCmd:  infotag get aaa_avpair_exists h323-return-code
    Jan 17 12:52:01.979: //331519//TCL :/tcl_InfotagGetObjCmd: infotag get aaa_avpair_exists h323-return-code
    Jan 17 12:52:01.979: //331519//AFW_:/vtr_ra_avpair_exists: argc 3 argindex 2
    Jan 17 12:52:01.979: //331519//TCL :/tcl_InfotagObjCmd:  infotag get aaa_avpair h323-return-code
    Jan 17 12:52:01.979: //331519//TCL :/tcl_InfotagGetObjCmd: infotag get aaa_avpair h323-return-code
    Jan 17 12:52:01.979: //331519//AFW_:/vtr_ra_avpair: argc 3 argindex 2
    Jan 17 12:52:01.979: //331519//TCL :/tcl_InfotagObjCmd:  infotag get aaa_avpair h323-ivr-in
    Jan 17 12:52:01.979: //331519//TCL :/tcl_InfotagGetObjCmd: infotag get aaa_avpair h323-ivr-in
    Jan 17 12:52:01.979: //331519//AFW_:/vtr_ra_avpair: argc 3 argindex 2
    Jan 17 12:52:01.979: //331519//TCL :/tcl_PutsObjCmd: destination in auth 232355123456789
    Jan 17 12:52:01.979:
    Jan 17 12:52:01.979: //331519//TCL :/tcl_LegObjCmd:  leg setup 232355123456789 callInfo leg_incoming
    Jan 17 12:52:01.979: //331519//CSPK:/tcl_LegSetupObjCmd: leg setup 232355123456789 callInfo leg_incoming
    Jan 17 12:52:01.979: //331519//AFW_:/vtd_lg_incoming: argc 4
    Jan 17 12:52:01.979: //331519//AFW_:/vtd_lg_incoming: Legs [331519 ]
    Jan 17 12:52:01.979: //331519//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Jan 17 12:52:01.979: //-1//AFW_:/AFW_Util_GetTgCicValue: CIC Not  found for tag(53)
    Jan 17 12:52:01.979: //-1//CSPK:/tclSetCallInfoParams: accountNum=0000
    Jan 17 12:52:01.979: //-1//CSPK:/tclSetControlParams: Notify Signaling Mask=30
    Jan 17 12:52:01.979: //331519//CSPK:/C_CallSetup_Start: ControlInfo = 0x66823990, callInfo = 0x66E520A8, destination[0]=232355123456789
    Jan 17 12:52:01.979: //331519//CSPK:/C_CallSetup_Start: configured mode=rotary (1)
    Jan 17 12:52:01.979: //331519//CSPK:/C_CallSetup_Start: configured reroutemode=rotary (1)
    Jan 17 12:52:01.979: //-1//Call:/AFW_CallSetup_New: 
    Jan 17 12:52:01.979: //-1//AFW_:/AFW_FSM_New: 
    Jan 17 12:52:01.979: //-1//AFW_:LP:EE65B772F4000:HN6753A504:/AFW_M_Object_SetExecEnv: ObjCount: 3, CmdPending 1
    Jan 17 12:52:01.979: //331519//AFW_:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 2
    Jan 17 12:52:01.979: //331519//AFW_:/AFW_M_Module_GetHandle: Module handle: CallSetup_66124A2C_0_1733534980
    Jan 17 12:52:01.979: //331519//Call:/AFW_CallSetup_AddDest:  232355123456789
    Jan 17 12:52:01.979: //331519//Call:/AFW_CallSetup_SetIntWrkLeg: 
    Jan 17 12:52:01.979: //331519/E265318F8701/AFW_:/AFW_Leg_SignalPeerGet: Leg [331519]
    Jan 17 12:52:01.979: //-1//AFW_:/C_PackageSession_GetSigPeer: 
    Jan 17 12:52:01.979: //331519/E265318F8701/AFW_:/C_PackageSession_GetSigPeer: No Interworking module on Leg, no signal peer
    Jan 17 12:52:01.979: //331519//Call:/AFW_M_CallSetup_Initiate: 
    Jan 17 12:52:01.979: //331519//Call:/CallSetupInitiate: 
    Jan 17 12:52:01.979: //331519//Call:/CS_Placecall: 
    Jan 17 12:52:01.979: //-1//Dest:/AFW_Destination_New: 
    Jan 17 12:52:01.979: //-1//AFW_:/AFW_FSM_New: 
    Jan 17 12:52:01.979: //-1//AFW_:/AFW_FSM_New: 
    Jan 17 12:52:01.979: //-1//AFW_:LP:EE65B772F4000:HN6753A504:/AFW_M_Object_SetExecEnv: ObjCount: 4, CmdPending 2
    Jan 17 12:52:01.979: //331519//AFW_:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 3
    Jan 17 12:52:01.979: //331519//AFW_:/AFW_M_Module_GetHandle: Module handle: Destination_6613EB60_0_1733534980
    Jan 17 12:52:01.979: //331519//Dest:/AFW_Destination_AddDest: 
    Jan 17 12:52:01.983: //-1//Dest:/AFW_Destination_AddDest: adding destination "232355123456789"
    Jan 17 12:52:01.983: //331519//Dest:/AFW_Destination_SetIntWrkLeg: LEG[331519 ][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 12:52:01.983: //331519//Dest:/TermInterworking: current state IW_STATE_INIT, Keep IntWrkLeg
    Jan 17 12:52:01.983: //331519//Dest:/DestSetIntWrkLeg:
    Jan 17 12:52:01.983: //331519//Dest:/AFW_M_Destination_Initiate: 
    Jan 17 12:52:01.983: //-1//AFW_:/AFW_Util_SaveRawMsg: 
    Jan 17 12:52:01.983: //331519//Dest:/AFW_M_Destination_Initiate: Outgoing guid : E265318F.404011E1.8701EBB1.0CE07E9F
    Jan 17 12:52:01.983:  Incoming_guid : 00000000.00000000.00000000.00000000
    Jan 17 12:52:01.983: //331519//Dest:/DestSetupInitiate: 
    Jan 17 12:52:01.983: //331519//Dest:/DestMatchDialPeer: 
    Jan 17 12:52:01.983: //331519//Dest:/DestMatchDialPeer: src carrier id:, tgt carrier id:
    Jan 17 12:52:01.983: //331519//Dest:/DestQueuePeers: Matched peers:
    Jan 17 12:52:01.983: //-1//Dest:/DestQueuePeers:  2323
    Jan 17 12:52:01.983: //-1//Dest:/DestQueuePeers:  18
    Jan 17 12:52:01.983: //-1//Dest:/DestQueuePeers: , Total(2)
    Jan 17 12:52:01.983: //331519//Dest:/DestDialPeerRotary: 
    Jan 17 12:52:01.983: //331519//Dest:/DestOutboundCallUsingPeer: dest(232355123456789), numexpDest(232355123456789), numDestDigits(4)
    Jan 17 12:52:01.983: //331519//Dest:/DestOutboundCallUsingPeer:    prefix(), peer tag(2323)
    Jan 17 12:52:01.983: //331519//Dest:/DestCheckTeleUnassBusy: 
    Jan 17 12:52:01.983: //331519//Dest:/DestSetup: 
    Jan 17 12:52:01.983: //-1//AFW_:/AFW_Leg_New: 
    Jan 17 12:52:01.983: //331520/E265318F8701/AFW_:/AFW_Leg_NewSetupRequest: ccCallSetupRequest done
    Jan 17 12:52:01.983: //331520/E265318F8701/AFW_:/AFW_M_Leg_SetExecEnv: 
    Jan 17 12:52:01.983: //331519//AFW_:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 4
    Jan 17 12:52:01.983: //-1/E265318F8701/AFW_:LP:EE65B772F4000:LG331520:/AFW_M_Object_SetExecEnv: ObjCount: 5, CmdPending 4
    Jan 17 12:52:01.983: //331520/E265318F8701/AFW_:/AFW_M_Leg_GetHandle: Leg handle: LEG_331520
    Jan 17 12:52:01.983: //331520/E265318F8701/AFW_:/AFW_Leg_UpdateStats: Updating stats for ID 204FB type 3
    Jan 17 12:52:01.983: //331519//Dest:/DestSetup: Destination setup success
    Jan 17 12:52:01.983: //331519//Dest:/AFW_M_Destination_Initiate: attempting call to destination 232355123456789
    Jan 17 12:52:01.983: //331519//Call:/CS_Placecall: Call placed to 232355123456789
    Jan 17 12:52:01.983: //331519//TCL :/tcl_InfotagObjCmd:  infotag get last_command_handle
    Jan 17 12:52:01.983: //331519//TCL :/tcl_InfotagGetObjCmd: infotag get last_command_handle
    Jan 17 12:52:01.983: //331519//AFW_:/vtr_last_command_handle: argc 2
    Jan 17 12:52:01.983: //331519//AFW_:/vtr_last_command_handle:
    Jan 17 12:52:01.983: //-1//Tcl :/tcl_parseModuleHandle: strModuleHandle CallSetup_66124A2C_0_1733534980Last created/used handler 0x66124A2C handle CallSetup_66124A2C_0_1733534980
    Jan 17 12:52:01.983: //331519//AFW_:/AFW_FSM_Drive: ACTION END: -------------(PLACECALL[5])---------------
    Jan 17 12:52:01.983: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: TclModule_65D0A070_0_1733534824 ---> NULL
    Jan 17 12:52:01.983: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x676A9348, Type: Event, RefCount: 0
    Jan 17 12:52:01.983: //331519//AFW_:/AFW_M_Event_Free: 
    Jan 17 12:52:01.983: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x6689FADC, Type: DataList, RefCount: 0
    Jan 17 12:52:01.983: //331519//AFW_:/AFW_ExecEnv_CloseIfDone: Cmd Count: 4
    Jan 17 12:52:01.983: //-1//AFW_:/AFW_Event_New: 
    Jan 17 12:52:01.983: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x676A41B8, Type: Event, RefCount: 0
    Jan 17 12:52:01.983: //-1//AFW_:/AFW_M_Event_Free: 
    Jan 17 12:52:01.983: //-1//AFW_:/AFW_M_Event_Free: Null or invalid event context: for event APP_EV_NULL
    Jan 17 12:52:01.987: //-1//AFW_:/AFW_Event_New: 
    Jan 17 12:52:01.987: //331520/E265318F8701/AFW_:/AFW_Process_GetCcqEvent: Received
    Jan 17 12:52:01.987: //-1//AFW_:/AFW_Process_GetCcqEvent:   Event[CC_EV_CALL_PROCEEDING(26)] {
    Jan 17 12:52:01.987: //-1//AFW_:/AFW_Process_GetCcqEvent:     EXECENV[0x65B772F4]
    Jan 17 12:52:01.987: //-1//AFW_:/AFW_Process_GetCcqEvent:     LEG[331520][LEG_OUTINIT(7)][Cause(0)]
    Jan 17 12:52:01.987: //-1//AFW_:/AFW_Process_GetCcqEvent:   }
    Jan 17 12:52:01.987: //331520/E265318F8701/SSIN:/AFW_SS_MapEvent: 
    Jan 17 12:52:01.987: //-1//SSIN:/AFW_SS_SIP_MapEvent: 
    Jan 17 12:52:01.987: //331520/E265318F8701/AFW_:/AFW_M_Leg_EventPreProcess: LEG[331520 ][LEG_OUTINIT(7)][Cause(0)]
    Jan 17 12:52:01.987: //331520/E265318F8701/AFW_:/AFW_Object_WalkListeners: 
    Jan 17 12:52:01.987: //331520/E265318F8701/AFW_:/AFW_M_Object_ShowListeners: START
    Jan 17 12:52:01.987: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[Destination_6613EB60_0_1733534980]  (
    Jan 17 12:52:01.987: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331520][LEG_OUTINIT(7)][Cause(0)]
    Jan 17 12:52:01.987: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331519][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 12:52:01.987: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
    Jan 17 12:52:01.987: //331520/E265318F8701/AFW_:/AFW_M_Object_ShowListeners: END
    Jan 17 12:52:01.987: //331520/E265318F8701/AFW_:/AFW_Object_WalkListeners: Entering Module : Destination
    Jan 17 12:52:01.987: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: NULL ---> Destination_6613EB60_0_1733534980
    Jan 17 12:52:01.987: //331519//Dest:/AFW_M_Destination_Action: 
    Jan 17 12:52:01.987: //331519//Dest:/AFW_Destination_Action: 
    Jan 17 12:52:01.991: //331519//Dest:/OB_FSM_Drive: 
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_6613EB60_0_1733534980 ---> Destination_6613EB60_0_1733534980
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(OB_STATE_SETTING[3],ev_proceeding[26])---[C_Action]------
    Jan 17 12:52:01.991: //331519//Dest:/OB_Setting_Proceeding: 
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_FSM_Drive: ACTION END: -------------(OB_STATE_SETTING[3])---------------
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_6613EB60_0_1733534980 ---> Destination_6613EB60_0_1733534980
    Jan 17 12:52:01.991: //331519//Dest:/IW_FSM_Drive: 
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_6613EB60_0_1733534980 ---> Destination_6613EB60_0_1733534980
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(IW_STATE_INIT[1],ev_proceeding[26])---[C_Action]------
    Jan 17 12:52:01.991: //331519//Dest:/IW_InitProc_Proceeding: 
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_FSM_Drive: ACTION END: -------------(IW_STATE_INIT[1])---------------
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_6613EB60_0_1733534980 ---> Destination_6613EB60_0_1733534980
    Jan 17 12:52:01.991: //331519//Dest:/DestIsEventNotified: 
    Jan 17 12:52:01.991: //331519//Dest:/DestComplete: peer #:2323 IW State IW_STATE_INIT, OB State OB_STATE_SETTING
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_6613EB60_0_1733534980 ---> NULL
    Jan 17 12:52:01.991: //331520/E265318F8701/AFW_:/AFW_Object_WalkListeners: Event Interceptd : Destination
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_Object_WalkListeners: 
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_M_Object_ShowListeners: START
    Jan 17 12:52:01.991: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[CallSetup_66124A2C_0_1733534980]  (
    Jan 17 12:52:01.991: //-1//AFW_:/AFW_M_Object_ShowListeners:     MOD[Destination_6613EB60_0_1733534980]  (
    Jan 17 12:52:01.991: //-1//AFW_:/AFW_M_Object_ShowListeners:       LEG[331520][LEG_OUTPROCEED(8)][Cause(0)]
    Jan 17 12:52:01.991: //-1//AFW_:/AFW_M_Object_ShowListeners:       LEG[331519][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 12:52:01.991: //-1//AFW_:/AFW_M_Object_ShowListeners:     )
    Jan 17 12:52:01.991: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_M_Object_ShowListeners: END
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_Object_WalkListeners: Entering Module : CallSetup
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: NULL ---> CallSetup_66124A2C_0_1733534980
    Jan 17 12:52:01.991: //331519//Call:/AFW_M_CallSetup_Action: 
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(S_PLACECALL[2],ev_proceeding[26])---[C_Action]------
    Jan 17 12:52:01.991: //331519//Call:/CS_Placecall_CallSignal: 
    Jan 17 12:52:01.991: //331519//Call:/CS_Placecall_CallSignal:  Event notified to parent
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_FSM_Drive: ACTION END: -------------(S_PLACECALL[2])---------------
    Jan 17 12:52:01.991: //331519//Call:/CS_Complete: Can't complete
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: CallSetup_66124A2C_0_1733534980 ---> NULL
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_Object_WalkListeners: Event Interceptd : CallSetup
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_Object_WalkListeners: 
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_M_Object_ShowListeners: START
    Jan 17 12:52:01.991: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[TclModule_65D0A070_0_1733534824]  (
    Jan 17 12:52:01.991: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331519][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 12:52:01.991: //-1//AFW_:/AFW_M_Object_ShowListeners:     MOD[CallSetup_66124A2C_0_1733534980]  (
    Jan 17 12:52:01.991: //-1//AFW_:/AFW_M_Object_ShowListeners:       MOD[Destination_6613EB60_0_1733534980]  (
    Jan 17 12:52:01.991: //-1//AFW_:/AFW_M_Object_ShowListeners:         LEG[331520][LEG_OUTPROCEED(8)][Cause(0)]
    Jan 17 12:52:01.991: //-1//AFW_:/AFW_M_Object_ShowListeners:         LEG[331519][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 12:52:01.991: //-1//AFW_:/AFW_M_Object_ShowListeners:       )
    Jan 17 12:52:01.991: //-1//AFW_:/AFW_M_Object_ShowListeners:     )
    Jan 17 12:52:01.991: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_M_Object_ShowListeners: END
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_Object_WalkListeners: Entering Module : TclModule
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: NULL ---> TclModule_65D0A070_0_1733534824
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_M_TclModule_Action: 
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_TclModule_DefaultEvHandling: 
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(PLACECALL[5],ev_proceeding[26])---[act_Proceeding]------
    Jan 17 12:52:01.991: //331519//TCL :/tcl_PutsObjCmd: IP carrier sales: act_Proceeding
    Jan 17 12:52:01.991:
    Jan 17 12:52:01.991: //331519//TCL :/tcl_AAAObjCmd:  aaa authorize 0 0 204 192.168.1.100#55123456789# leg_incoming avsend
    Jan 17 12:52:01.991: //331519//TCL :/tcl_AuthorizeObjCmd:  authorize 0 0 204 192.168.1.100#55123456789# leg_incoming avsend
    Jan 17 12:52:01.991: //331519//AFW_:/vtd_lg_incoming: argc 7
    Jan 17 12:52:01.991: //331519//AFW_:/vtd_lg_incoming: Legs [331519 ]
    Jan 17 12:52:01.991: //331519//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Jan 17 12:52:01.991: //-1//TCL :/tclSetAvpair: type>>86, Value>>Value:2601
    Jan 17 12:52:01.991: //-1//TCL :/tclSetAvpair: Attr>>h323-ivr-out, Value>>Value:2601
    Jan 17 12:52:01.991: //-1//TCL :/tclSetAvpair: type>>86, Value>>CS Test Authentication
    Jan 17 12:52:01.991: //-1//TCL :/tclSetAvpair: Attr>>h323-ivr-out, Value>>CS Test Authentication
    Jan 17 12:52:01.991: //331519//TCL :/tcl_AuthorizeObjCmd: account=0, password=0,
    Jan 17 12:52:01.991: //331519//TCL :/tcl_AuthorizeObjCmd:    ani=204, dnis=192.168.1.100#55123456789#, methodList=,
    Jan 17 12:52:01.991: //331519//TCL :/tcl_AuthorizeObjCmd:    av-send=avsend, guid=
    Jan 17 12:52:01.991: //-1//AFW_:/AFW_Event_New: 
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 5
    Jan 17 12:52:01.991: //331519//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 12:52:01.995: //331519//AFW_:/AFW_FSM_Drive: ACTION END: -------------(PLACECALL[5])---------------
    Jan 17 12:52:01.995: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: TclModule_65D0A070_0_1733534824 ---> NULL
    Jan 17 12:52:01.995: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x67598944, Type: Event, RefCount: 0
    Jan 17 12:52:01.995: //331520/E265318F8701/AFW_:/AFW_M_Event_Free: 
    Jan 17 12:52:01.995: //331519//AFW_:/AFW_ExecEnv_CloseIfDone: Cmd Count: 5
    Jan 17 12:52:02.007: //331519//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 12:52:02.007: //331519//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 12:52:02.007: //331519//AFW_:/AFW_TclModule_PopulateRadiusVSA: reply-message
    Access denied (external check failed).
    Jan 17 12:52:02.007: //331519//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 12:52:02.007: //331519//AFW_:/AFW_ExecEnv_DecrNPendingCmd:  PendingCmdCount: 4
    Jan 17 12:52:02.007: //331519//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 12:52:02.007: //331519//AFW_:/AFW_Process_GetAppQEvent: Received
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_Process_GetAppQEvent:   Event[APP_EV_AUTHORIZE_DONE(144)] {
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_Process_GetAppQEvent:     EXECENV[0x65B772F4]
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_Process_GetAppQEvent:     MOD[TclModule_65D0A070_0_1733534824]  (
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_Process_GetAppQEvent:       LEG[331519][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_Process_GetAppQEvent:       MOD[CallSetup_66124A2C_0_1733534980]  (
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_Process_GetAppQEvent:         MOD[Destination_6613EB60_0_1733534980]  (
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_Process_GetAppQEvent:           LEG[331520][LEG_OUTPROCEED(8)][Cause(0)]
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_Process_GetAppQEvent:           LEG[331519][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_Process_GetAppQEvent:         )
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_Process_GetAppQEvent:       )
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_Process_GetAppQEvent:     )
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_Process_GetAppQEvent:   }
    Jan 17 12:52:02.007: //331519//AFW_:/AFW_M_TclModule_EventPreProcess: 
    Jan 17 12:52:02.007: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: NULL ---> TclModule_65D0A070_0_1733534824
    Jan 17 12:52:02.007: //331519//AFW_:/AFW_M_TclModule_Action: 
    Jan 17 12:52:02.007: //331519//AFW_:/AFW_TclModule_DefaultEvHandling: 
    Jan 17 12:52:02.007: //331519//AFW_:/AFW_FSM_Drive: FSM no match for (PLACECALL[5],ev_authorize_done[144])
    Jan 17 12:52:02.007: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: TclModule_65D0A070_0_1733534824 ---> NULL
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x65EFE704, Type: Event, RefCount: 0
    Jan 17 12:52:02.007: //331519//AFW_:/AFW_M_Event_Free: 
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x66945250, Type: DataList, RefCount: 0
    Jan 17 12:52:02.007: //331519//AFW_:/AFW_ExecEnv_CloseIfDone: Cmd Count: 4
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_Event_New: 
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x66340E18, Type: Event, RefCount: 0
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_M_Event_Free: 
    Jan 17 12:52:02.007: //-1//AFW_:/AFW_M_Event_Free: Null or invalid event context: for event APP_EV_NULL
    Jan 17 12:52:02.475: //-1//AFW_:/AFW_Event_New: 
    Jan 17 12:52:02.475: //331520/E265318F8701/AFW_:/AFW_Process_GetCcqEvent: Received
    Jan 17 12:52:02.475: //-1//AFW_:/AFW_Process_GetCcqEvent:   Event[CC_EV_CALL_DISCONNECTED(16)] {
    Jan 17 12:52:02.475: //-1//AFW_:/AFW_Process_GetCcqEvent:     EXECENV[0x65B772F4]
    Jan 17 12:52:02.475: //-1//AFW_:/AFW_Process_GetCcqEvent:     LEG[331520][LEG_OUTPROCEED(8)][Cause(0)]
    Jan 17 12:52:02.475: //-1//AFW_:/AFW_Process_GetCcqEvent:   }
    Jan 17 12:52:02.475: //331520/E265318F8701/SSIN:/AFW_SS_MapEvent: 
    Jan 17 12:52:02.475: //-1//SSIN:/AFW_SS_SIP_MapEvent: 
    Jan 17 12:52:02.475: //331520/E265318F8701/AFW_:/AFW_Object_WalkListeners: 
    Jan 17 12:52:02.475: //331520/E265318F8701/AFW_:/AFW_M_Object_ShowListeners: START
    Jan 17 12:52:02.475: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[Destination_6613EB60_0_1733534980]  (
    Jan 17 12:52:02.475: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331520][LEG_OUTPROCEED(8)][Cause(28)]
    Jan 17 12:52:02.475: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331519][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 12:52:02.475: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
    Jan 17 12:52:02.475: //331520/E265318F8701/AFW_:/AFW_M_Object_ShowListeners: END
    Jan 17 12:52:02.475: //331520/E265318F8701/AFW_:/AFW_Object_WalkListeners: Entering Module : Destination
    Jan 17 12:52:02.475: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: NULL ---> Destination_6613EB60_0_1733534980
    Jan 17 12:52:02.475: //331519//Dest:/AFW_M_Destination_Action: 
    Jan 17 12:52:02.475: //331519//Dest:/AFW_Destination_Action: 
    Jan 17 12:52:02.475: //331519//Dest:/OB_FSM_Drive: 
    Jan 17 12:52:02.475: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_6613EB60_0_1733534980 ---> Destination_6613EB60_0_1733534980
    Jan 17 12:52:02.475: //331519//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(OB_STATE_SETTING[3],ev_disconnected[16])---[C_Action]------
    Jan 17 12:52:02.475: //331519//Dest:/OB_Setting_Disconnected: 
    Jan 17 12:52:02.475: //331519//Dest:/OBDiscContinue: 
    Jan 17 12:52:02.475: //331519//Dest:/Dest_AAA_CheckAccounting:
    Jan 17 12:52:02.475: //331519//Dest:/Dest_AAA_CheckAccounting: Accounting to be disabled for callID=331520
    Jan 17 12:52:02.475: //331520/E265318F8701/AFW_:/AFW_Leg_Disconnect: Disconnecting Leg: LEG_331520, Cause 28
    Jan 17 12:52:02.479: //331520/E265318F8701/AFW_:/AFW_Leg_UpdateStats: Updating stats for ID 204FB type 2
    Jan 17 12:52:02.479: //-1//Dest:/DestStatusFromDiscCause: mapped "invalid number (28)"(28) to DEST_INVALID_NUMBER(4)
    Jan 17 12:52:02.479: //331519//AFW_:/AFW_FSM_Drive: ACTION END: -------------(OB_STATE_DISCONNECTING[6])---------------
    Jan 17 12:52:02.479: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_6613EB60_0_1733534980 ---> Destination_6613EB60_0_1733534980
    Jan 17 12:52:02.479: //331519//Dest:/IW_FSM_Drive: 
    Jan 17 12:52:02.479: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_6613EB60_0_1733534980 ---> Destination_6613EB60_0_1733534980
    Jan 17 12:52:02.479: //331519//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(IW_STATE_INIT[1],ev_disconnected[16])---[C_Action]------
    Jan 17 12:52:02.479: //331519//Dest:/IW_InitProc_Disconnect: 
    Jan 17 12:52:02.479: //331519//AFW_:/AFW_FSM_Drive: ACTION END: -------------(IW_STATE_INIT[1])---------------
    Jan 17 12:52:02.479: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_6613EB60_0_1733534980 ---> Destination_6613EB60_0_1733534980
    Jan 17 12:52:02.479: //331519//Dest:/DestIsEventNotified: 
    Jan 17 12:52:02.479: //331519//Dest:/DestComplete: peer #:2323 IW State IW_STATE_INIT, OB State OB_STATE_DISCONNECTING
    Jan 17 12:52:02.479: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_6613EB60_0_1733534980 ---> NULL
    Jan 17 12:52:02.479: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x64968CA8, Type: Event, RefCount: 0
    Jan 17 12:52:02.479: //331520/E265318F8701/AFW_:/AFW_M_Event_Free: 
    Jan 17 12:52:02.479: //331519//AFW_:/AFW_ExecEnv_CloseIfDone: Cmd Count: 4
    Jan 17 12:52:02.479: //-1//AFW_:/AFW_Event_New: 
    Jan 17 12:52:02.479: //331520/E265318F8701/AFW_:/AFW_Process_GetCcqEvent: Received
    Jan 17 12:52:02.479: //-1//AFW_:/AFW_Process_GetCcqEvent:   Event[CC_EV_CALL_DISCONNECT_DONE(17)] {
    Jan 17 12:52:02.479: //-1//AFW_:/AFW_Process_GetCcqEvent:     EXECENV[0x65B772F4]
    Jan 17 12:52:02.479: //-1//AFW_:/AFW_Process_GetCcqEvent:     LEG[331520][LEG_OUTDISCONNECTING(11)][Cause(28)]
    Jan 17 12:52:02.479: //-1//AFW_:/AFW_Process_GetCcqEvent:   }
    Jan 17 12:52:02.479: //-1//SSIN:/AFW_SS_MapEvent: No mapping required
    Jan 17 12:52:02.479: //331520/E265318F8701/AFW_:/AFW_Object_WalkListeners: 
    Jan 17 12:52:02.479: //331520/E265318F8701/AFW_:/AFW_M_Object_ShowListeners: START
    Jan 17 12:52:02.479: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[Destination_6613EB60_0_1733534980]  (
    Jan 17 12:52:02.479: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331520][LEG_DISCONNECTED(12)][Cause(28)]
    Jan 17 12:52:02.479: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331519][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 12:52:02.479: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
    Jan 17 12:52:02.479: //331520/E265318F8701/AFW_:/AFW_M_Object_ShowListeners: END
    Jan 17 12:52:02.479: //331520/E265318F8701/AFW_:/AFW_Object_WalkListeners: Entering Module : Destination
    Jan 17 12:52:02.479: //331519//AFW_:/AFW_Module_UnListen:  NumObjects: 1
    Jan 17 12:52:02.479: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: NULL ---> Destination_6613EB60_0_1733534980
    Jan 17 12:52:02.479: //331519//Dest:/AFW_M_Destination_Action: 
    Jan 17 12:52:02.479: //331519//Dest:/AFW_Destination_Action: 
    Jan 17 12:52:02.479: //331519//Dest:/OB_FSM_Drive: 
    Jan 17 12:52:02.479: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_6613EB60_0_1733534980 ---> Destination_6613EB60_0_1733534980
    Jan 17 12:52:02.479: //331519//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(OB_STATE_DISCONNECTING[6],ev_disconnect_done[17])---[C_Action]------
    Jan 17 12:52:02.479: //331519//Dest:/OB_Disconnecting_DiscDone: 
    Jan 17 12:52:02.479: //331519//Dest:/DestDialPeerRotary: 
    Jan 17 12:52:02.479: //331519//Dest:/DestOutboundCallUsingPeer: dest(232355123456789), numexpDest(232355123456789), numDestDigits(0)
    Jan 17 12:52:02.479: //331519//Dest:/DestOutboundCallUsingPeer:    prefix(), peer tag(18)
    Jan 17 12:52:02.479: //331519//Dest:/DestCheckTeleUnassBusy: 
    Jan 17 12:52:02.479: //331519//Dest:/DestSetup: 
    Jan 17 12:52:02.479: //-1//SSIN:/AFW_SS_H450_PrepareCIInform: 
    Jan 17 12:52:02.479: //-1//AFW_:/AFW_Leg_New: 
    Jan 17 12:52:02.479: //331521/E265318F8701/AFW_:/AFW_Leg_NewSetupRequest: ccCallSetupRequest done
    Jan 17 12:52:02.479: //331521/E265318F8701/AFW_:/AFW_M_Leg_SetExecEnv: 
    Jan 17 12:52:02.479: //331519//AFW_:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 5
    Jan 17 12:52:02.483: //-1/E265318F8701/AFW_:LP:EE65B772F4000:LG331521:/AFW_M_Object_SetExecEnv: ObjCount: 6, CmdPending 5
    Jan 17 12:52:02.483: //331521/E265318F8701/AFW_:/AFW_M_Leg_GetHandle: Leg handle: LEG_331521
    Jan 17 12:52:02.483: //331521/E265318F8701/AFW_:/AFW_Leg_UpdateStats: Updating stats for ID 204FB type 3
    Jan 17 12:52:02.483: //331519//Dest:/DestSetup: Destination setup success
    Jan 17 12:52:02.483: //331519//AFW_:/AFW_FSM_Drive: ACTION END: -------------(OB_STATE_SETTING[3])---------------
    Jan 17 12:52:02.483: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_6613EB60_0_1733534980 ---> Destination_6613EB60_0_1733534980
    Jan 17 12:52:02.483: //331519//Dest:/IW_FSM_Drive: 
    Jan 17 12:52:02.483: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_6613EB60_0_1733534980 ---> Destination_6613EB60_0_1733534980
    Jan 17 12:52:02.483: //331519//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(IW_STATE_INIT[1],ev_disconnect_done[17])---[C_Action]------
    Jan 17 12:52:02.483: //331519//Dest:/IW_InitProc_Disconnect: 
    Jan 17 12:52:02.483: //331519//AFW_:/AFW_FSM_Drive: ACTION END: -------------(IW_STATE_INIT[1])---------------
    Jan 17 12:52:02.483: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_6613EB60_0_1733534980 ---> Destination_6613EB60_0_1733534980
    Jan 17 12:52:02.483: //331519//Dest:/DestIsEventNotified: 
    Jan 17 12:52:02.483: //331519//Dest:/DestComplete: peer #:18 IW State IW_STATE_INIT, OB State OB_STATE_SETTING
    Jan 17 12:52:02.483: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_6613EB60_0_1733534980 ---> NULL
    Jan 17 12:52:02.483: //331520/E265318F8701/AFW_:/AFW_Object_WalkListeners:
    Jan 17 12:52:02.483: //331520/E265318F8701/AFW_:/AFW_M_Object_ShowListeners: START
    Jan 17 12:52:02.483: //331520/E265318F8701/AFW_:/AFW_M_Object_ShowListeners: END
    Jan 17 12:52:02.483: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x6496B570, Type: Event, RefCount: 0
    Jan 17 12:52:02.483: //331520/E265318F8701/AFW_:/AFW_M_Event_Free: 
    Jan 17 12:52:02.483: //331520/E265318F8701/AFW_:/AFW_M_Event_Free:  CC_EV_CALL_DISCONNECT_DONE for a Leg: LEG_331520
    Jan 17 12:52:02.483: //331519//AFW_:/AFW_ExecEnv_DecrNPendingCmd:  PendingCmdCount: 4
    Jan 17 12:52:02.483: //-1//AFW_:/AFW_M_Object_UnSetExecEnv: ObjCount: 5, CmdPending 4
    Jan 17 12:52:02.483: //331520/E265318F8701/AFW_:/AFW_M_Event_Free: ExecEnv objCount: 5
    Jan 17 12:52:02.483: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x661743B4, Type: Leg, RefCount: 0
    Jan 17 12:52:02.483: //331520/E265318F8701/AFW_:/AFW_M_Leg_Free: 
    Jan 17 12:52:02.483: //331519//AFW_:/AFW_ExecEnv_CloseIfDone: Cmd Count: 4
    Jan 17 12:52:02.483: //-1//AFW_:/AFW_Event_New: 
    Jan 17 12:52:02.483: //331521/E265318F8701/AFW_:/AFW_Process_GetCcqEvent: Received
    Jan 17 12:52:02.483: //-1//AFW_:/AFW_Process_GetCcqEvent:   Event[CC_EV_CALL_DISCONNECTED(16)] {
    Jan 17 12:52:02.483: //-1//AFW_:/AFW_Process_GetCcqEvent:     EXECENV[0x65B772F4]
    Jan 17 12:52:02.483: //-1//AFW_:/AFW_Process_GetCcqEvent:     LEG[331521][LEG_OUTINIT(7)][Cause(0)]
    Jan 17 12:52:02.483: //-1//AFW_:/AFW_Process_GetCcqEvent:   }
    Jan 17 12:52:02.483: //331521/E265318F8701/SSIN:/AFW_SS_MapEvent: 
    Jan 17 12:52:02.483: //-1//SSIN:/AFW_SS_H323_MapEvent: 
    Jan 17 12:52:02.483: //-1//SSIN:/SS_H323_GetNonStandardRerouteRequest: 
    Jan 17 12:52:02.483: //331521/E265318F8701/AFW_:/AFW_Object_WalkListeners: 
    Jan 17 12:52:02.483: //331521/E265318F8701/AFW_:/AFW_M_Object_ShowListeners: START
    Jan 17 12:52:02.483: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[Destination_6613EB60_0_1733534980]  (
    Jan 17 12:52:02.483: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331519][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 12:52:02.483: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331521][LEG_OUTINIT(7)][Cause(41)]
    Jan 17 12:52:02.483: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
    Jan 17 12:52:02.483: //331521/E265318F8701/AFW_:/AFW_M_Object_ShowListeners: END
    Jan 17 12:52:02.483: //331521/E265318F8701/AFW_:/AFW_Object_WalkListeners: Entering Module : Destination
    Jan 17 12:52:02.483: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: NULL ---> Destination_6613EB60_0_1733534980
    Jan 17 12:52:02.483: //331519//Dest:/AFW_M_Destination_Action: 
    Jan 17 12:52:02.483: //331519//Dest:/AFW_Destination_Action: 
    Jan 17 12:52:02.483: //331519//Dest:/OB_FSM_Drive: 
    Jan 17 12:52:02.483: //331519//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_6613EB60_0_1733534980 ---> Destination_6613EB60_0_1733534980
    Jan 17 12:52:02.483: //331519//AFW_:/AFW_FSM_Drive: Null or invalid event context: for event APP_EV_NULL

    Subject: RE: TCL fails with incorrect codec?
    Replied by: Raghavendra Gutty Veeranagappa on 17-01-2012 08:15:19 AM
    Hi Mark,

    i can see ev_disconnected event in the logs but not sure why script not able to get the event, could you please send your script for more analysis.

    Jan 17 12:52:02.475: //331519//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(OB_STATE_SETTING[3],ev_disconnected[16])---[C_Action]------
    Jan 17 12:52:02.475: //331519//Dest:/OB_Setting_Disconnected

    Thanks,
    Raghavendra

    Subject: RE: TCL fails with incorrect codec?
    Replied by: Mark Alliban on 17-01-2012 08:37:05 AM
    Weird thign is, when I use the correct codec g729, it does trigger the disconnect properly. Everything works as it should.
    TCL code:


    proc init { } {
    global param
    global timerFactor
    global glogcount
    global Realcall
    global i
    global cFlag
    global NCounter
    global ani
    set Realcall 0
    set glogcount 0
    set cFlag 0
    set NCounter 0
    set ani 0
    set i 1
    set param1(interruptPrompt) true
    set param1(abortKey)        *
    set param1(terminationKey)  #
    set param(interruptPrompt) true
    set param(abortKey) *
    set param(terminationKey) #
    set param(dialPlan) true
    }
      
    proc act_Setup { } {
    global param
    global dest
    global ani

    puts "IP Carrier Sales: setup"
    set ani [infotag get leg_ani] 
    set callInfo(notifyEvents) "ev_connected ev_proceeding ev_progress ev_alert"
    set dest1 [infotag get leg_dnis]
    regsub -nocase ^00 $dest1 "" dest1
    set ipAddr [infotag get leg_remote_signaling_ip_address leg_incoming]
    if {$ipAddr == ""} {
      set ipAddr [infotag get leg_remoteipaddress leg_incoming]
      puts "CSP remoteIP Address- ipAddr:$ipAddr"
      if {$ipAddr == ""} {
       puts "Call  has NULL remote IP address"
       fsm setstate CALLDISCONNECT
       return 0
      }
    }
    set dest $ipAddr#$dest1
    set ipAddr11 [infotag get leg_remoteipaddress leg_incoming]
    puts "CSP remoteIP Address- ipAddr11:$ipAddr11"
    act_GotDest
    fsm setstate SECONDAUTHORIZE


    proc act_Connected { } {
    global dest
    global glogcount
    global Realcall
    global cFlag
    global ani
    set cFlag 1
    puts "IP carrier sales: act_Connected"
    set avsend(h323-ivr-out,0) "CS Test Authentication"
    set avsend(h323-ivr-out,1) "Value:2600"
    set account "0"
    set pin "0"
    aaa authorize $account $pin $ani "$dest#" leg_incoming avsend
    }

    proc act_alert { } {
    global dest
    global ani
    puts "IP carrier sales: act_Alerting"
    set avsend(h323-ivr-out,0) "CS Test Authentication"
    set avsend(h323-ivr-out,1) "Value:2602"
    set account "0"
    set pin "0"
    aaa authorize $account $pin $ani "$dest#" leg_incoming avsend
    leg alert leg_incoming
    }

    proc act_Proceeding { } {
    global dest
    global ani
    puts "IP carrier sales: act_Proceeding"
    set avsend(h323-ivr-out,0) "CS Test Authentication"
    set avsend(h323-ivr-out,1) "Value:2601"
    set account "0"
    set pin "0"
    aaa authorize $account $pin $ani "$dest#" leg_incoming avsend
    }

    proc act_Progress { } {
    global dest
    puts "IP carrier sales: act_Progress"
    }

    proc act_GotDest { } {
    global dest
    global orgdest
    global ani
    set orgdest $dest
    puts "IP carrier sales: act_GotDest $dest"
    leg proceeding leg_incoming
    set avsend(h323-ivr-out,0) "CS Test Authentication"
    set avsend(h323-ivr-out,1) "Value:2500"
    set account "0"
    set pin "0"
    aaa authorize $account $pin $ani "$dest#" leg_incoming avsend
    return
    }
            
    proc act_CallSetupDone { } {
    global timerFactor
    global destination
    global i
    global Dcause
    global status
    puts "IP carrier sales: act_CallSetupDone"
    set param2(enableReporting) true
    set outbound_leg_id [infotag get leg_outgoing]
    leg collectdigits $outbound_leg_id param2
    set inbound_leg_id [infotag get leg_incoming]
    leg collectdigits $inbound_leg_id param2
    set status [infotag get evt_status]
    if { $status == "ls_000"} {
      puts "Connected"
      set r_content [infotag get evt_status]
      puts $r_content
    } else {
      if { $i < 3} {
       incr i
       set status [infotag get evt_status]
       puts "Disconnected $status "
       act_GotDest1
       fsm setstate SECONDAUTHORIZE
      } else {
       puts " i Value: $i"
       set i 1
       puts "Disconnected before connected"
       set status "di_107"
       act_Closeall
       call close
      }
    }
    }

    proc act_GotDest1 { } {
    global orgdest
    global i
    global ani
    puts "IP carrier sales: act_GotDest1 $orgdest"
    puts "Trying Carrier $i"
    set status [infotag get evt_status]   
    set avsend(h323-ivr-out,0) "CS Test Authentication"
    set avsend(h323-ivr-out,1) "Value:250$i"
    set account "0"
    set pin "0"
    aaa authorize $account $pin $ani "$orgdest#" leg_incoming avsend
    return
    }

    proc act_EvFeatureReceived { } {
    global timerFactor
    puts "IP carrier sales: EvFeatureReceived "
    set featureType [infotag get evt_feature_type]
    if {  $featureType == "media_inactivity" } {
      puts "media inactivity or silence is detected" 
      set inactivity_type [infotag get evt_feature_param media_inactivity_type]
      if {  $inactivity_type == "no media received" } {       
       puts "media inactivity, RTCP packet was previously received"
      }
      if {  $inactivity_type == "no control info received" } {
       puts "media inactivity, no RTCP packet was previously received "
      }
    } elseif { $featureType == "media_activity" } {
      puts "media activity detected and call is back alive, VOIP RTP starts receiving RTP/RTCP packets"
    } else {
      puts "other Events have been detected"
    }
    }

    proc act_ActiveTimer { } {
    global Realcall
    set Realcall 1
    puts "IP carrier sales: act_ActiveTimer"
    fsm setstate CALLACTIVE
    }

    proc act_SecondAuthorized { } {
    global account
    global destination
    global noTimeLimit
    global creditTime
    global warnTime
    global promptFlag2
    global fcnt
    global retryCnt
    global noPlay
    global commandHandle
    global i
    global Dcause
    global NCounter
    global ani
    puts "IP carrier sales: act_SecondAuthorize"
    set callInfo(accountNum) "0000"
    if { [infotag get aaa_avpair_exists h323-return-code] } {
      set returnCode [infotag get aaa_avpair h323-return-code]
    } else {
      puts "!! No return code from radius!!!"
      act_Cleanup
      fsm setstate CALLDISCONNECT
      return
    }
    if {$returnCode == 13} {
      set destination [infotag get aaa_avpair h323-ivr-in]
      puts "destination in auth $destination "
      set callInfo(notifyEvents) "ev_connected ev_proceeding ev_progress ev_alert"
      if {$i > 1} {
       set Dcause    [infotag get evt_last_disconnect_cause]
       set avsend(h323-ivr-out,0) "CS Disc cause"
       set avsend(h323-ivr-out,1) "Value:2801:$Dcause-"
       set account "0"
       set pin "0"
       aaa authorize $account $pin $ani "$destination#" leg_incoming avsend
       puts "Send Disc cause $Dcause"
      }
      leg setup $destination callInfo leg_incoming
      set commandHandle [infotag get last_command_handle]
      return
    }
    }

    proc act_Play { } {
    puts "IP carrier sales: act_Play"
    media play leg_incoming "tftp://213.166.21.221/prompts/en/enprm_please_wait_repeat.au"
    }

    proc act_DigitPressed { } {
    global dest
    global ani
    set evtDigit [infotag get evt_digit]
    puts "Init Digit pressed: $evtDigit"
    if ([string equal $evtDigit "T"]) {
      puts "Timeout"
    } else {
      puts "Digit pressed: $evtDigit"
      set avsend(h323-ivr-out,0) "CS Test Authentication"
      set avsend(h323-ivr-out,1) "Value:2700"
      set account "0"
      set pin "0"
      aaa authorize $account $pin $ani "$evtDigit#" leg_incoming avsend
    }
    }

    proc act_CDisconnect { } {
    puts "IP carrier sales: act_CDisconnect"
    set status [infotag get evt_status]
    puts "Disconnection Cause $status"
    }

    proc act_Cleanup { } {
    global i
    global cFlag
    global dest
    global NCounter
    global status
    global ani
    puts "IP carrier sales: act_Cleanup"
    set status [infotag get evt_status]
    if { $cFlag == 1 } {
      puts "WAS ACTIVE Status in call leg disconnected: $status"
      set avsend(h323-ivr-out,0) "CS Test Authentication"
      set avsend(h323-ivr-out,1) "Value:2800:$status-"
      set account "0"
      set pin "0"
      aaa authorize $account $pin $ani "$dest#" leg_incoming avsend
      set cFlag 0
    } else {
      act_Closeall
      puts "CALL NOT CONNECTED Status in call leg disconnected: $status"
    }
    puts "Call Disconnected"
    set i 1
    set NCounter 0
    call close
    }

    proc act_Closeall { } {
    global dest
    global status
    global ani
    puts "IP carrier sales: act_CloseAll"
    set avsend(h323-ivr-out,0) "CS Test Authentication"
    set avsend(h323-ivr-out,1) "Value:2900:$status-"
    set account "0"
    set pin "0"
    aaa authorize $account $pin $ani "$dest#" leg_incoming avsend
    }

    init
    #----------------------------------
    #   State Machine
    #----------------------------------
    set fsm(any_state,ev_disconnected)         "act_Cleanup           same_state"
    set fsm(CALL_INIT,ev_setup_indication)     "act_Setup             GETDEST"
    set fsm(GETDEST,ev_collectdigits_done)     "act_GotDest           SECONDAUTHORIZE"
    set fsm(GETDEST1,ev_collectdigits_done)    "act_GotDest1          SECONDAUTHORIZE"
    set fsm(SECONDAUTHORIZE,ev_authorize_done) "act_SecondAuthorized  PLACECALL"
    set fsm(PLACECALL,ev_setup_done)           "act_CallSetupDone     CALLACTIVE"
    set fsm(PLACECALL,ev_connected)            "act_Connected         same_state"
    set fsm(PLACECALL,ev_proceeding)           "act_Proceeding        same_state"
    set fsm(PLACECALL,ev_progress)             "act_Progress          same_state"
    set fsm(PLACECALL,ev_alert)                "act_alert             same_state"
    set fsm(any_state,ev_digit_end)            "act_DigitPressed      same_state"
    set fsm(CALLACTIVE,ev_disconnected)        "act_Cleanup           CALLDISCONNECT"
    set fsm(CALLDISCONNECT,ev_disconnected)    "act_Cleanup           same_state"
    set fsm(CALLDISCONNECT,ev_disconnect_done) "act_Cleanup           same_state"
    fsm define fsm CALL_INIT
    # End the application

    Subject: RE: TCL fails with incorrect codec?
    Replied by: Raghavendra Gutty Veeranagappa on 17-01-2012 08:52:54 AM
    Hi,

    could you please let me know why This event is handled at this state
    Jan 17 12:52:02.007: //331519//AFW_:/AFW_FSM_Drive: FSM no match for (PLACECALL[5],ev_authorize_done[144])

    BTW can you try placing below line in fsm state machine

    set fsm(PLACECALL,ev_disconnected) "act_Cleanup CALLDISCONNECT"

    Thanks,
    Raghavendra

    Subject: RE: TCL fails with incorrect codec?
    Replied by: Mark Alliban on 17-01-2012 09:14:25 AM
    could you please let me know why This event is handled at this state
    Jan 17 12:52:02.007: //331519//AFW_:/AFW_FSM_Drive: FSM no match for (PLACECALL[5],ev_authorize_done[144])

    I don't know - this is code I inherited. It doesn't seem to cause any problems, though. Everything works as expected when the right codec is used.
     
    Putting in set fsm(PLACECALL,ev_disconnected) "act_Cleanup CALLDISCONNECT":
     

    Jan 17 14:03:30.180: %SYS-5-CONFIG_I: Configured from console by idn on vty1 (192.168.1.100)
    Jan 17 14:03:32.873: //-1//SERV:/AFW_Service_CCInterface: Received Event 24 for service ipCSales modulehandle NULL
    Jan 17 14:03:32.873: //-1//SERV:/AFW_Service_GetExecEnv: Script Name = ipCSales
    Jan 17 14:03:32.873: //-1//SERV:/AFW_Service_GetExecEnv: Using Cached ExecEnv
    Jan 17 14:03:32.873: //-1//AFW_:EE65B778DC000:/AFW_ExecEnv_SetRoot: Execenv = 0x65B778DC
    Jan 17 14:03:32.873: //-1//AFW_:/AFW_M_TclModule_NewDup:  
    Jan 17 14:03:32.873: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x65D097D0, Type: TclModule, RefCount: 0
    Jan 17 14:03:32.873: //-1//AFW_:HN67928D80:/AFW_M_TclModule_Free:  MOD[TclModule_65D097D0_0_1737656636] ( )
    Jan 17 14:03:32.873: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x6767B694, Type: FSM, RefCount: 0
    Jan 17 14:03:32.873: //-1//AFW_:/AFW_M_FSM_Free:  
    Jan 17 14:03:32.873: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x65EB4214, Type: DataArray, RefCount: 0
    Jan 17 14:03:32.873: //-1//AFW_:/AFW_Process_Lock: pProcess(0x65B75D64)=1
    Jan 17 14:03:32.873: //-1//AFW_:LP:EE65B778DC000:HN67951D8C:/AFW_M_Object_SetExecEnv: ObjCount: 1, CmdPending 0
    Jan 17 14:03:32.873: //-1//AFW_:EE65B778DC000:/AFW_ExecEnv_RestoreDataBackup: Restore DataArea from Script
    Jan 17 14:03:32.877: //-1//AFW_:EE65B778DC000:/AFW_ExecEnv_RestoreDataBackup: Restore TokenTable from Script
    Jan 17 14:03:32.877: //-1//AFW_:EE65B778DC000:/AFW_ExecEnv_Initiate: Execenv = 0x65B778DC
    Jan 17 14:03:32.877: //-1//AFW_:/AFW_Leg_New:  
    Jan 17 14:03:32.877: //331525//AFW_:/AFW_M_Leg_SetExecEnv:  
    Jan 17 14:03:32.877: //-1//AFW_:EE65B778DC000:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 1
    Jan 17 14:03:32.877: //-1//AFW_:LP:EE65B778DC000:LG331525:/AFW_M_Object_SetExecEnv: ObjCount: 2, CmdPending 1
    Jan 17 14:03:32.877: //331525//AFW_:/AFW_M_Leg_GetHandle: Leg handle: LEG_331525
    Jan 17 14:03:32.877: //-1//AFW_:EE65B778DC000:/AFW_ExecEnv_AssignCall: Execenv = 0x65B778DC, Leg = 331525, Peer_Tag = 18
    Jan 17 14:03:32.877: //-1//AFW_:/AFW_Event_New:  
    Jan 17 14:03:32.877: //331525//AFW_:/AFW_Process_GetCcqEvent: Received 
    Jan 17 14:03:32.877: //-1//AFW_:/AFW_Process_GetCcqEvent:   Event[CC_EV_CALL_SETUP_IND(29)] {
    Jan 17 14:03:32.877: //-1//AFW_:/AFW_Process_GetCcqEvent:     EXECENV[0x65B778DC]
    Jan 17 14:03:32.877: //-1//AFW_:/AFW_Process_GetCcqEvent:     LEG[331525][LEG_INIT(0)][Cause(0)]
    Jan 17 14:03:32.877: //-1//AFW_:/AFW_Process_GetCcqEvent:   }
    Jan 17 14:03:32.877: //331525//SSIN:/AFW_SS_MapEvent:  
    Jan 17 14:03:32.877: //-1//SSIN:/AFW_SS_SIP_MapEvent:  
    Jan 17 14:03:32.877: //331525/E00F6D438707/AFW_:/AFW_Leg_UpdateStats: Updating stats for ID 204FD type 0
    Jan 17 14:03:32.877: //331525/E00F6D438707/AFW_:/AFW_Object_WalkListeners:  
    Jan 17 14:03:32.877: //331525/E00F6D438707/AFW_:/AFW_M_Object_ShowListeners: START
    Jan 17 14:03:32.877: //-1//AFW_:/AFW_M_Object_ShowListeners:   
    Jan 17 14:03:32.877: //331525//AFW_:/AFW_M_Module_GetHandle: Module handle: TclModule_66E95898_0_1737825676MOD[TclModule_66E95898_0_1737825676]  (
    Jan 17 14:03:32.877: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331525][LEG_INCINIT(1)][Cause(0)]
    Jan 17 14:03:32.877: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
    Jan 17 14:03:32.877: //331525/E00F6D438707/AFW_:/AFW_M_Object_ShowListeners: END
    Jan 17 14:03:32.877: //331525/E00F6D438707/AFW_:/AFW_Object_WalkListeners: Entering Module : TclModule
    Jan 17 14:03:32.877: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: TclModule_66E95898_0_1737825676 ---> TclModule_66E95898_0_1737825676
    Jan 17 14:03:32.877: //331525//AFW_:/AFW_M_TclModule_Action:  
    Jan 17 14:03:32.877: //331525//AFW_:/AFW_TclModule_DefaultEvHandling:  
    Jan 17 14:03:32.877: //331525/E00F6D438707/AFW_:/AFW_Leg_CheckIncomingCallBlock:  
    Jan 17 14:03:32.877: //331525/E00F6D438707/AFW_:/AFW_Leg_SettlementValidateCall: target=ras, tokenp=0x0
    Jan 17 14:03:32.877: //331525/E00F6D438707/AFW_:/AFW_Leg_IncomingTranslate:  
    Jan 17 14:03:32.877: //331525//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(CALL_INIT[1],ev_setup_indication[29])---[act_Setup]------
    Jan 17 14:03:32.881: //331525//TCL :/tcl_PutsObjCmd: IP Carrier Sales: setup
    Jan 17 14:03:32.881: 
    Jan 17 14:03:32.881: //331525//TCL :/tcl_InfotagObjCmd:  infotag get leg_ani 
    Jan 17 14:03:32.881: //331525//TCL :/tcl_InfotagGetObjCmd: infotag get leg_ani 
    Jan 17 14:03:32.881: //331525//AFW_:/vtr_lg_ani: argc 2 argindex 2
    Jan 17 14:03:32.881: //331525//TCL :/tcl_InfotagObjCmd:  infotag get leg_dnis 
    Jan 17 14:03:32.881: //331525//TCL :/tcl_InfotagGetObjCmd: infotag get leg_dnis 
    Jan 17 14:03:32.881: //331525//AFW_:/vtr_lg_dnis: argc 2 argindex 2
    Jan 17 14:03:32.881: //331525//TCL :/tcl_InfotagObjCmd:  infotag get leg_remote_signaling_ip_address leg_incoming 
    Jan 17 14:03:32.881: //331525//TCL :/tcl_InfotagGetObjCmd: infotag get leg_remote_signaling_ip_address leg_incoming 
    Jan 17 14:03:32.881: //331525//AFW_:/vtr_lg_remote_signaling_ip_address: argc 3 argindex 2
    Jan 17 14:03:32.881: //331525//AFW_:/vtd_lg_incoming: argc 3
    Jan 17 14:03:32.881: //331525//AFW_:/vtd_lg_incoming: Legs [331525 ]
    Jan 17 14:03:32.881: //331525//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Jan 17 14:03:32.881: //331525//TCL :/tcl_InfotagObjCmd:  infotag get leg_remoteipaddress leg_incoming 
    Jan 17 14:03:32.881: //331525//TCL :/tcl_InfotagGetObjCmd: infotag get leg_remoteipaddress leg_incoming 
    Jan 17 14:03:32.881: //331525//AFW_:/vtr_lg_remoteipaddress: argc 3 argindex 2
    Jan 17 14:03:32.881: //331525//AFW_:/vtd_lg_incoming: argc 3
    Jan 17 14:03:32.881: //331525//AFW_:/vtd_lg_incoming: Legs [331525 ]
    Jan 17 14:03:32.881: //331525//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Jan 17 14:03:32.881: //331525//TCL :/tcl_PutsObjCmd: CSP remoteIP Address- ipAddr:192.168.1.100
    Jan 17 14:03:32.881: 
    Jan 17 14:03:32.881: //331525//TCL :/tcl_InfotagObjCmd:  infotag get leg_remoteipaddress leg_incoming 
    Jan 17 14:03:32.881: //331525//TCL :/tcl_InfotagGetObjCmd: infotag get leg_remoteipaddress leg_incoming 
    Jan 17 14:03:32.881: //331525//AFW_:/vtr_lg_remoteipaddress: argc 3 argindex 2
    Jan 17 14:03:32.881: //331525//AFW_:/vtd_lg_incoming: argc 3
    Jan 17 14:03:32.881: //331525//AFW_:/vtd_lg_incoming: Legs [331525 ]
    Jan 17 14:03:32.881: //331525//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Jan 17 14:03:32.881: //331525//TCL :/tcl_PutsObjCmd: CSP remoteIP Address- ipAddr11:192.168.1.100
    Jan 17 14:03:32.881: 
    Jan 17 14:03:32.881: //331525//TCL :/tcl_PutsObjCmd: IP carrier sales: act_GotDest 192.168.1.100#55123456789
    Jan 17 14:03:32.881: 
    Jan 17 14:03:32.881: //331525//TCL :/tcl_LegObjCmd:  leg proceeding leg_incoming 
    Jan 17 14:03:32.881: //331525//TCL :/tcl_LegProceedObjCmd: proceeding leg_incoming 
    Jan 17 14:03:32.881: //331525//AFW_:/vtd_lg_incoming: argc 2
    Jan 17 14:03:32.881: //331525//AFW_:/vtd_lg_incoming: Legs [331525 ]
    Jan 17 14:03:32.881: //331525//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Jan 17 14:03:32.881: //331525//TCL :/tcl_AAAObjCmd:  aaa authorize 0 0 204 192.168.1.100#55123456789# leg_incoming avsend 
    Jan 17 14:03:32.881: //331525//TCL :/tcl_AuthorizeObjCmd:  authorize 0 0 204 192.168.1.100#55123456789# leg_incoming avsend 
    Jan 17 14:03:32.881: //331525//AFW_:/vtd_lg_incoming: argc 7
    Jan 17 14:03:32.881: //331525//AFW_:/vtd_lg_incoming: Legs [331525 ]
    Jan 17 14:03:32.881: //331525//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Jan 17 14:03:32.881: //-1//TCL :/tclSetAvpair: type>>86, Value>>Value:2500
    Jan 17 14:03:32.881: //-1//TCL :/tclSetAvpair: Attr>>h323-ivr-out, Value>>Value:2500
    Jan 17 14:03:32.881: //-1//TCL :/tclSetAvpair: type>>86, Value>>CS Test Authentication
    Jan 17 14:03:32.881: //-1//TCL :/tclSetAvpair: Attr>>h323-ivr-out, Value>>CS Test Authentication
    Jan 17 14:03:32.881: //331525//TCL :/tcl_AuthorizeObjCmd: account=0, password=0,
    Jan 17 14:03:32.881: //331525//TCL :/tcl_AuthorizeObjCmd:    ani=204, dnis=192.168.1.100#55123456789#, methodList=,
    Jan 17 14:03:32.881: //331525//TCL :/tcl_AuthorizeObjCmd:    av-send=avsend, guid=
    Jan 17 14:03:32.881: //-1//AFW_:/AFW_Event_New:  
    Jan 17 14:03:32.881: //331525//AFW_:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 2
    Jan 17 14:03:32.881: //331525//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 14:03:32.881: //331525//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 14:03:32.885: //331525//TCL :/tcl_FSMObjCmd:  fsm setstate SECONDAUTHORIZE 
    Jan 17 14:03:32.885: //331525//TCL :/tcl_FSMSetStateObjCmd: setstate setstate SECONDAUTHORIZE 
    Jan 17 14:03:32.885: //331525//AFW_:/AFW_FSM_Drive: ACTION END: -------------(SECONDAUTHORIZE[4])---------------
    Jan 17 14:03:32.885: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: TclModule_66E95898_0_1737825676 ---> TclModule_66E95898_0_1737825676
    Jan 17 14:03:32.885: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x6759C25C, Type: Event, RefCount: 0
    Jan 17 14:03:32.885: //331525/E00F6D438707/AFW_:/AFW_M_Event_Free:  
    Jan 17 14:03:32.885: //331525//AFW_:/AFW_ExecEnv_CloseIfDone: Cmd Count: 2
    Jan 17 14:03:32.997: //331525//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 14:03:32.997: //331525//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 14:03:32.997: //331525//AFW_:/AFW_TclModule_PopulateRadiusVSA: h323-prompt-id 
    Jan 17 14:03:33.001: //331525//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 14:03:33.001: //331525//AFW_:/AFW_TclModule_PopulateRadiusVSA: h323-credit-time 5400 5400
    Jan 17 14:03:33.001: //331525//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 14:03:33.001: //331525//AFW_:/AFW_TclModule_PopulateRadiusVSA: h323-ivr-in 232355123456789
    Jan 17 14:03:33.001: //331525//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 14:03:33.001: //331525//AFW_:/AFW_TclModule_PopulateRadiusVSA: h323-preferred-lang 
    Jan 17 14:03:33.001: //331525//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 14:03:33.001: //331525//AFW_:/AFW_TclModule_PopulateRadiusVSA: h323-return-code 13
    Jan 17 14:03:33.001: //331525//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 14:03:33.001: //331525//AFW_:/AFW_ExecEnv_DecrNPendingCmd:  PendingCmdCount: 1
    Jan 17 14:03:33.001: //331525//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 14:03:33.001: //331525//AFW_:/AFW_Process_GetAppQEvent: Received 
    Jan 17 14:03:33.001: //-1//AFW_:/AFW_Process_GetAppQEvent:   Event[APP_EV_AUTHORIZE_DONE(144)] {
    Jan 17 14:03:33.001: //-1//AFW_:/AFW_Process_GetAppQEvent:     EXECENV[0x65B778DC]
    Jan 17 14:03:33.001: //-1//AFW_:/AFW_Process_GetAppQEvent:     MOD[TclModule_66E95898_0_1737825676]  (
    Jan 17 14:03:33.001: //-1//AFW_:/AFW_Process_GetAppQEvent:       LEG[331525][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 14:03:33.001: //-1//AFW_:/AFW_Process_GetAppQEvent:     )
    Jan 17 14:03:33.001: //-1//AFW_:/AFW_Process_GetAppQEvent:   }
    Jan 17 14:03:33.001: //331525//AFW_:/AFW_M_TclModule_EventPreProcess:  
    Jan 17 14:03:33.001: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: NULL ---> TclModule_66E95898_0_1737825676
    Jan 17 14:03:33.001: //331525//AFW_:/AFW_M_TclModule_Action:  
    Jan 17 14:03:33.001: //331525//AFW_:/AFW_TclModule_DefaultEvHandling:  
    Jan 17 14:03:33.001: //331525//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(SECONDAUTHORIZE[4],ev_authorize_done[144])---[act_SecondAuthorized]------
    Jan 17 14:03:33.001: //331525//TCL :/tcl_PutsObjCmd: IP carrier sales: act_SecondAuthorize
    Jan 17 14:03:33.001: 
    Jan 17 14:03:33.001: //331525//TCL :/tcl_InfotagObjCmd:  infotag get aaa_avpair_exists h323-return-code 
    Jan 17 14:03:33.001: //331525//TCL :/tcl_InfotagGetObjCmd: infotag get aaa_avpair_exists h323-return-code 
    Jan 17 14:03:33.001: //331525//AFW_:/vtr_ra_avpair_exists: argc 3 argindex 2
    Jan 17 14:03:33.001: //331525//TCL :/tcl_InfotagObjCmd:  infotag get aaa_avpair h323-return-code 
    Jan 17 14:03:33.001: //331525//TCL :/tcl_InfotagGetObjCmd: infotag get aaa_avpair h323-return-code 
    Jan 17 14:03:33.001: //331525//AFW_:/vtr_ra_avpair: argc 3 argindex 2
    Jan 17 14:03:33.001: //331525//TCL :/tcl_InfotagObjCmd:  infotag get aaa_avpair h323-ivr-in 
    Jan 17 14:03:33.001: //331525//TCL :/tcl_InfotagGetObjCmd: infotag get aaa_avpair h323-ivr-in 
    Jan 17 14:03:33.001: //331525//AFW_:/vtr_ra_avpair: argc 3 argindex 2
    Jan 17 14:03:33.001: //331525//TCL :/tcl_PutsObjCmd: destination in auth 232355123456789 
    Jan 17 14:03:33.001: 
    Jan 17 14:03:33.001: //331525//TCL :/tcl_LegObjCmd:  leg setup 232355123456789 callInfo leg_incoming 
    Jan 17 14:03:33.001: //331525//CSPK:/tcl_LegSetupObjCmd: leg setup 232355123456789 callInfo leg_incoming 
    Jan 17 14:03:33.001: //331525//AFW_:/vtd_lg_incoming: argc 4
    Jan 17 14:03:33.001: //331525//AFW_:/vtd_lg_incoming: Legs [331525 ]
    Jan 17 14:03:33.001: //331525//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Jan 17 14:03:33.001: //-1//AFW_:/AFW_Util_GetTgCicValue: CIC Not  found for tag(53)
    Jan 17 14:03:33.001: //-1//CSPK:/tclSetCallInfoParams: accountNum=0000
    Jan 17 14:03:33.005: //-1//CSPK:/tclSetControlParams: Notify Signaling Mask=30
    Jan 17 14:03:33.005: //331525//CSPK:/C_CallSetup_Start: ControlInfo = 0x66E7A2A4, callInfo = 0x6663545C, destination[0]=232355123456789
    Jan 17 14:03:33.005: //331525//CSPK:/C_CallSetup_Start: configured mode=rotary (1)
    Jan 17 14:03:33.005: //331525//CSPK:/C_CallSetup_Start: configured reroutemode=rotary (1)
    Jan 17 14:03:33.005: //-1//Call:/AFW_CallSetup_New:  
    Jan 17 14:03:33.005: //-1//AFW_:/AFW_FSM_New:  
    Jan 17 14:03:33.005: //-1//AFW_:LP:EE65B778DC000:HN67951E10:/AFW_M_Object_SetExecEnv: ObjCount: 3, CmdPending 1
    Jan 17 14:03:33.005: //331525//AFW_:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 2
    Jan 17 14:03:33.005: //331525//AFW_:/AFW_M_Module_GetHandle: Module handle: CallSetup_65BBE700_0_1737825808
    Jan 17 14:03:33.005: //331525//Call:/AFW_CallSetup_AddDest:  232355123456789 
    Jan 17 14:03:33.005: //331525//Call:/AFW_CallSetup_SetIntWrkLeg:  
    Jan 17 14:03:33.005: //331525/E00F6D438707/AFW_:/AFW_Leg_SignalPeerGet: Leg [331525] 
    Jan 17 14:03:33.005: //-1//AFW_:/C_PackageSession_GetSigPeer:  
    Jan 17 14:03:33.005: //331525/E00F6D438707/AFW_:/C_PackageSession_GetSigPeer: No Interworking module on Leg, no signal peer
    Jan 17 14:03:33.005: //331525//Call:/AFW_M_CallSetup_Initiate:  
    Jan 17 14:03:33.005: //331525//Call:/CallSetupInitiate:  
    Jan 17 14:03:33.005: //331525//Call:/CS_Placecall:  
    Jan 17 14:03:33.005: //-1//Dest:/AFW_Destination_New:  
    Jan 17 14:03:33.005: //-1//AFW_:/AFW_FSM_New:  
    Jan 17 14:03:33.005: //-1//AFW_:/AFW_FSM_New:  
    Jan 17 14:03:33.005: //-1//AFW_:LP:EE65B778DC000:HN67951E10:/AFW_M_Object_SetExecEnv: ObjCount: 4, CmdPending 2
    Jan 17 14:03:33.005: //331525//AFW_:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 3
    Jan 17 14:03:33.005: //331525//AFW_:/AFW_M_Module_GetHandle: Module handle: Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.005: //331525//Dest:/AFW_Destination_AddDest:  
    Jan 17 14:03:33.005: //-1//Dest:/AFW_Destination_AddDest: adding destination "232355123456789"
    Jan 17 14:03:33.005: //331525//Dest:/AFW_Destination_SetIntWrkLeg: LEG[331525 ][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 14:03:33.005: //331525//Dest:/TermInterworking: current state IW_STATE_INIT, Keep IntWrkLeg
    Jan 17 14:03:33.005: //331525//Dest:/DestSetIntWrkLeg: 
    Jan 17 14:03:33.005: //331525//Dest:/AFW_M_Destination_Initiate:  
    Jan 17 14:03:33.005: //-1//AFW_:/AFW_Util_SaveRawMsg:  
    Jan 17 14:03:33.005: //331525//Dest:/AFW_M_Destination_Initiate: Outgoing guid : E00F6D43.404A11E1.8707EBB1.0CE07E9F
    Jan 17 14:03:33.005:  Incoming_guid : 00000000.00000000.00000000.00000000
    Jan 17 14:03:33.005: //331525//Dest:/DestSetupInitiate:  
    Jan 17 14:03:33.005: //331525//Dest:/DestMatchDialPeer:  
    Jan 17 14:03:33.005: //331525//Dest:/DestMatchDialPeer: src carrier id:, tgt carrier id: 
    Jan 17 14:03:33.005: //331525//Dest:/DestQueuePeers: Matched peers:
    Jan 17 14:03:33.005: //-1//Dest:/DestQueuePeers:  2323
    Jan 17 14:03:33.005: //-1//Dest:/DestQueuePeers:  18
    Jan 17 14:03:33.005: //-1//Dest:/DestQueuePeers: , Total(2)
    Jan 17 14:03:33.005: //331525//Dest:/DestDialPeerRotary:  
    Jan 17 14:03:33.005: //331525//Dest:/DestOutboundCallUsingPeer: dest(232355123456789), numexpDest(232355123456789), numDestDigits(4)
    Jan 17 14:03:33.005: //331525//Dest:/DestOutboundCallUsingPeer:    prefix(), peer tag(2323)
    Jan 17 14:03:33.005: //331525//Dest:/DestCheckTeleUnassBusy:  
    Jan 17 14:03:33.005: //331525//Dest:/DestSetup:  
    Jan 17 14:03:33.005: //-1//AFW_:/AFW_Leg_New:  
    Jan 17 14:03:33.005: //331526/E00F6D438707/AFW_:/AFW_Leg_NewSetupRequest: ccCallSetupRequest done
    Jan 17 14:03:33.005: //331526/E00F6D438707/AFW_:/AFW_M_Leg_SetExecEnv:  
    Jan 17 14:03:33.005: //331525//AFW_:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 4
    Jan 17 14:03:33.005: //-1/E00F6D438707/AFW_:LP:EE65B778DC000:LG331526:/AFW_M_Object_SetExecEnv: ObjCount: 5, CmdPending 4
    Jan 17 14:03:33.005: //331526/E00F6D438707/AFW_:/AFW_M_Leg_GetHandle: Leg handle: LEG_331526
    Jan 17 14:03:33.005: //331526/E00F6D438707/AFW_:/AFW_Leg_UpdateStats: Updating stats for ID 204FD type 3
    Jan 17 14:03:33.005: //331525//Dest:/DestSetup: Destination setup success
    Jan 17 14:03:33.005: //331525//Dest:/AFW_M_Destination_Initiate: attempting call to destination 232355123456789
    Jan 17 14:03:33.005: //331525//Call:/CS_Placecall: Call placed to 232355123456789
    Jan 17 14:03:33.005: //331525//TCL :/tcl_InfotagObjCmd:  infotag get last_command_handle 
    Jan 17 14:03:33.005: //331525//TCL :/tcl_InfotagGetObjCmd: infotag get last_command_handle 
    Jan 17 14:03:33.005: //331525//AFW_:/vtr_last_command_handle: argc 2
    Jan 17 14:03:33.005: //331525//AFW_:/vtr_last_command_handle: 
    Jan 17 14:03:33.009: //-1//Tcl :/tcl_parseModuleHandle: strModuleHandle CallSetup_65BBE700_0_1737825808Last created/used handler 0x65BBE700 handle CallSetup_65BBE700_0_1737825808
    Jan 17 14:03:33.009: //331525//AFW_:/AFW_FSM_Drive: ACTION END: -------------(PLACECALL[5])---------------
    Jan 17 14:03:33.009: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: TclModule_66E95898_0_1737825676 ---> NULL
    Jan 17 14:03:33.009: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x676A0078, Type: Event, RefCount: 0
    Jan 17 14:03:33.009: //331525//AFW_:/AFW_M_Event_Free:  
    Jan 17 14:03:33.009: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x6674D4DC, Type: DataList, RefCount: 0
    Jan 17 14:03:33.009: //331525//AFW_:/AFW_ExecEnv_CloseIfDone: Cmd Count: 4
    Jan 17 14:03:33.009: //-1//AFW_:/AFW_Event_New:  
    Jan 17 14:03:33.009: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x6633B460, Type: Event, RefCount: 0
    Jan 17 14:03:33.009: //-1//AFW_:/AFW_M_Event_Free:  
    Jan 17 14:03:33.009: //-1//AFW_:/AFW_M_Event_Free: Null or invalid event context: for event APP_EV_NULL
    Jan 17 14:03:33.009: //-1//AFW_:/AFW_Event_New:  
    Jan 17 14:03:33.009: //331526/E00F6D438707/AFW_:/AFW_Process_GetCcqEvent: Received 
    Jan 17 14:03:33.009: //-1//AFW_:/AFW_Process_GetCcqEvent:   Event[CC_EV_CALL_PROCEEDING(26)] {
    Jan 17 14:03:33.009: //-1//AFW_:/AFW_Process_GetCcqEvent:     EXECENV[0x65B778DC]
    Jan 17 14:03:33.009: //-1//AFW_:/AFW_Process_GetCcqEvent:     LEG[331526][LEG_OUTINIT(7)][Cause(0)]
    Jan 17 14:03:33.009: //-1//AFW_:/AFW_Process_GetCcqEvent:   }
    Jan 17 14:03:33.009: //331526/E00F6D438707/SSIN:/AFW_SS_MapEvent:  
    Jan 17 14:03:33.009: //-1//SSIN:/AFW_SS_SIP_MapEvent:  
    Jan 17 14:03:33.009: //331526/E00F6D438707/AFW_:/AFW_M_Leg_EventPreProcess: LEG[331526 ][LEG_OUTINIT(7)][Cause(0)]
    Jan 17 14:03:33.009: //331526/E00F6D438707/AFW_:/AFW_Object_WalkListeners:  
    Jan 17 14:03:33.009: //331526/E00F6D438707/AFW_:/AFW_M_Object_ShowListeners: START
    Jan 17 14:03:33.009: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[Destination_65BD07A4_0_1737825808]  (
    Jan 17 14:03:33.009: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331525][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 14:03:33.009: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331526][LEG_OUTINIT(7)][Cause(0)]
    Jan 17 14:03:33.009: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
    Jan 17 14:03:33.009: //331526/E00F6D438707/AFW_:/AFW_M_Object_ShowListeners: END
    Jan 17 14:03:33.009: //331526/E00F6D438707/AFW_:/AFW_Object_WalkListeners: Entering Module : Destination
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: NULL ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.013: //331525//Dest:/AFW_M_Destination_Action:  
    Jan 17 14:03:33.013: //331525//Dest:/AFW_Destination_Action:  
    Jan 17 14:03:33.013: //331525//Dest:/OB_FSM_Drive:  
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(OB_STATE_SETTING[3],ev_proceeding[26])---[C_Action]------
    Jan 17 14:03:33.013: //331525//Dest:/OB_Setting_Proceeding:  
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_FSM_Drive: ACTION END: -------------(OB_STATE_SETTING[3])---------------
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.013: //331525//Dest:/IW_FSM_Drive:  
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(IW_STATE_INIT[1],ev_proceeding[26])---[C_Action]------
    Jan 17 14:03:33.013: //331525//Dest:/IW_InitProc_Proceeding:  
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_FSM_Drive: ACTION END: -------------(IW_STATE_INIT[1])---------------
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.013: //331525//Dest:/DestIsEventNotified:  
    Jan 17 14:03:33.013: //331525//Dest:/DestComplete: peer #:2323 IW State IW_STATE_INIT, OB State OB_STATE_SETTING
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> NULL
    Jan 17 14:03:33.013: //331526/E00F6D438707/AFW_:/AFW_Object_WalkListeners: Event Interceptd : Destination
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_Object_WalkListeners:  
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_M_Object_ShowListeners: START
    Jan 17 14:03:33.013: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[CallSetup_65BBE700_0_1737825808]  (
    Jan 17 14:03:33.013: //-1//AFW_:/AFW_M_Object_ShowListeners:     MOD[Destination_65BD07A4_0_1737825808]  (
    Jan 17 14:03:33.013: //-1//AFW_:/AFW_M_Object_ShowListeners:       LEG[331525][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 14:03:33.013: //-1//AFW_:/AFW_M_Object_ShowListeners:       LEG[331526][LEG_OUTPROCEED(8)][Cause(0)]
    Jan 17 14:03:33.013: //-1//AFW_:/AFW_M_Object_ShowListeners:     )
    Jan 17 14:03:33.013: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_M_Object_ShowListeners: END
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_Object_WalkListeners: Entering Module : CallSetup
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: NULL ---> CallSetup_65BBE700_0_1737825808
    Jan 17 14:03:33.013: //331525//Call:/AFW_M_CallSetup_Action:  
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(S_PLACECALL[2],ev_proceeding[26])---[C_Action]------
    Jan 17 14:03:33.013: //331525//Call:/CS_Placecall_CallSignal:  
    Jan 17 14:03:33.013: //331525//Call:/CS_Placecall_CallSignal:  Event notified to parent 
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_FSM_Drive: ACTION END: -------------(S_PLACECALL[2])---------------
    Jan 17 14:03:33.013: //331525//Call:/CS_Complete: Can't complete
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: CallSetup_65BBE700_0_1737825808 ---> NULL
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_Object_WalkListeners: Event Interceptd : CallSetup
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_Object_WalkListeners:  
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_M_Object_ShowListeners: START
    Jan 17 14:03:33.013: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[TclModule_66E95898_0_1737825676]  (
    Jan 17 14:03:33.013: //-1//AFW_:/AFW_M_Object_ShowListeners:     MOD[CallSetup_65BBE700_0_1737825808]  (
    Jan 17 14:03:33.013: //-1//AFW_:/AFW_M_Object_ShowListeners:       MOD[Destination_65BD07A4_0_1737825808]  (
    Jan 17 14:03:33.013: //-1//AFW_:/AFW_M_Object_ShowListeners:         LEG[331525][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 14:03:33.013: //-1//AFW_:/AFW_M_Object_ShowListeners:         LEG[331526][LEG_OUTPROCEED(8)][Cause(0)]
    Jan 17 14:03:33.013: //-1//AFW_:/AFW_M_Object_ShowListeners:       )
    Jan 17 14:03:33.013: //-1//AFW_:/AFW_M_Object_ShowListeners:     )
    Jan 17 14:03:33.013: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331525][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 14:03:33.013: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_M_Object_ShowListeners: END
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_Object_WalkListeners: Entering Module : TclModule
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: NULL ---> TclModule_66E95898_0_1737825676
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_M_TclModule_Action:  
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_TclModule_DefaultEvHandling:  
    Jan 17 14:03:33.013: //331525//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(PLACECALL[5],ev_proceeding[26])---[act_Proceeding]------
    Jan 17 14:03:33.013: //331525//TCL :/tcl_PutsObjCmd: IP carrier sales: act_Proceeding
    Jan 17 14:03:33.013: 
    Jan 17 14:03:33.013: //331525//TCL :/tcl_AAAObjCmd:  aaa authorize 0 0 204 192.168.1.100#55123456789# leg_incoming avsend 
    Jan 17 14:03:33.013: //331525//TCL :/tcl_AuthorizeObjCmd:  authorize 0 0 204 192.168.1.100#55123456789# leg_incoming avsend 
    Jan 17 14:03:33.013: //331525//AFW_:/vtd_lg_incoming: argc 7
    Jan 17 14:03:33.013: //331525//AFW_:/vtd_lg_incoming: Legs [331525 ]
    Jan 17 14:03:33.013: //331525//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Jan 17 14:03:33.013: //-1//TCL :/tclSetAvpair: type>>86, Value>>Value:2601
    Jan 17 14:03:33.013: //-1//TCL :/tclSetAvpair: Attr>>h323-ivr-out, Value>>Value:2601
    Jan 17 14:03:33.013: //-1//TCL :/tclSetAvpair: type>>86, Value>>CS Test Authentication
    Jan 17 14:03:33.013: //-1//TCL :/tclSetAvpair: Attr>>h323-ivr-out, Value>>CS Test Authentication
    Jan 17 14:03:33.017: //331525//TCL :/tcl_AuthorizeObjCmd: account=0, password=0,
    Jan 17 14:03:33.017: //331525//TCL :/tcl_AuthorizeObjCmd:    ani=204, dnis=192.168.1.100#55123456789#, methodList=,
    Jan 17 14:03:33.017: //331525//TCL :/tcl_AuthorizeObjCmd:    av-send=avsend, guid=
    Jan 17 14:03:33.017: //-1//AFW_:/AFW_Event_New:  
    Jan 17 14:03:33.017: //331525//AFW_:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 5
    Jan 17 14:03:33.017: //331525//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 14:03:33.017: //331525//AFW_:/AFW_FSM_Drive: ACTION END: -------------(PLACECALL[5])---------------
    Jan 17 14:03:33.017: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: TclModule_66E95898_0_1737825676 ---> NULL
    Jan 17 14:03:33.017: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x65EF9574, Type: Event, RefCount: 0
    Jan 17 14:03:33.017: //331526/E00F6D438707/AFW_:/AFW_M_Event_Free:  
    Jan 17 14:03:33.017: //331525//AFW_:/AFW_ExecEnv_CloseIfDone: Cmd Count: 5
    Jan 17 14:03:33.029: //331525//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 14:03:33.029: //331525//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 14:03:33.029: //331525//AFW_:/AFW_TclModule_PopulateRadiusVSA: reply-message 
    Access denied (external check failed).
    Jan 17 14:03:33.029: //331525//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 14:03:33.029: //331525//AFW_:/AFW_ExecEnv_DecrNPendingCmd:  PendingCmdCount: 4
    Jan 17 14:03:33.029: //331525//AFW_:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
    Jan 17 14:03:33.029: //331525//AFW_:/AFW_Process_GetAppQEvent: Received 
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_Process_GetAppQEvent:   Event[APP_EV_AUTHORIZE_DONE(144)] {
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_Process_GetAppQEvent:     EXECENV[0x65B778DC]
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_Process_GetAppQEvent:     MOD[TclModule_66E95898_0_1737825676]  (
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_Process_GetAppQEvent:       MOD[CallSetup_65BBE700_0_1737825808]  (
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_Process_GetAppQEvent:         MOD[Destination_65BD07A4_0_1737825808]  (
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_Process_GetAppQEvent:           LEG[331525][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_Process_GetAppQEvent:           LEG[331526][LEG_OUTPROCEED(8)][Cause(0)]
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_Process_GetAppQEvent:         )
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_Process_GetAppQEvent:       )
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_Process_GetAppQEvent:       LEG[331525][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_Process_GetAppQEvent:     )
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_Process_GetAppQEvent:   }
    Jan 17 14:03:33.029: //331525//AFW_:/AFW_M_TclModule_EventPreProcess:  
    Jan 17 14:03:33.029: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: NULL ---> TclModule_66E95898_0_1737825676
    Jan 17 14:03:33.029: //331525//AFW_:/AFW_M_TclModule_Action:  
    Jan 17 14:03:33.029: //331525//AFW_:/AFW_TclModule_DefaultEvHandling:  
    Jan 17 14:03:33.029: //331525//AFW_:/AFW_FSM_Drive: FSM no match for (PLACECALL[5],ev_authorize_done[144])
    Jan 17 14:03:33.029: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: TclModule_66E95898_0_1737825676 ---> NULL
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x6633DD28, Type: Event, RefCount: 0
    Jan 17 14:03:33.029: //331525//AFW_:/AFW_M_Event_Free:  
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x65ED4694, Type: DataList, RefCount: 0
    Jan 17 14:03:33.029: //331525//AFW_:/AFW_ExecEnv_CloseIfDone: Cmd Count: 4
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_Event_New:  
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x64965390, Type: Event, RefCount: 0
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_M_Event_Free:  
    Jan 17 14:03:33.029: //-1//AFW_:/AFW_M_Event_Free: Null or invalid event context: for event APP_EV_NULL
    Jan 17 14:03:33.489: //-1//AFW_:/AFW_Event_New:  
    Jan 17 14:03:33.489: //331526/E00F6D438707/AFW_:/AFW_Process_GetCcqEvent: Received 
    Jan 17 14:03:33.489: //-1//AFW_:/AFW_Process_GetCcqEvent:   Event[CC_EV_CALL_DISCONNECTED(16)] {
    Jan 17 14:03:33.489: //-1//AFW_:/AFW_Process_GetCcqEvent:     EXECENV[0x65B778DC]
    Jan 17 14:03:33.489: //-1//AFW_:/AFW_Process_GetCcqEvent:     LEG[331526][LEG_OUTPROCEED(8)][Cause(0)]
    Jan 17 14:03:33.489: //-1//AFW_:/AFW_Process_GetCcqEvent:   }
    Jan 17 14:03:33.489: //331526/E00F6D438707/SSIN:/AFW_SS_MapEvent:  
    Jan 17 14:03:33.489: //-1//SSIN:/AFW_SS_SIP_MapEvent:  
    Jan 17 14:03:33.489: //331526/E00F6D438707/AFW_:/AFW_Object_WalkListeners:  
    Jan 17 14:03:33.489: //331526/E00F6D438707/AFW_:/AFW_M_Object_ShowListeners: START
    Jan 17 14:03:33.489: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[Destination_65BD07A4_0_1737825808]  (
    Jan 17 14:03:33.489: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331525][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 14:03:33.489: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331526][LEG_OUTPROCEED(8)][Cause(28)]
    Jan 17 14:03:33.489: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
    Jan 17 14:03:33.489: //331526/E00F6D438707/AFW_:/AFW_M_Object_ShowListeners: END
    Jan 17 14:03:33.489: //331526/E00F6D438707/AFW_:/AFW_Object_WalkListeners: Entering Module : Destination
    Jan 17 14:03:33.489: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: NULL ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.489: //331525//Dest:/AFW_M_Destination_Action:  
    Jan 17 14:03:33.489: //331525//Dest:/AFW_Destination_Action:  
    Jan 17 14:03:33.489: //331525//Dest:/OB_FSM_Drive:  
    Jan 17 14:03:33.489: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.489: //331525//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(OB_STATE_SETTING[3],ev_disconnected[16])---[C_Action]------
    Jan 17 14:03:33.489: //331525//Dest:/OB_Setting_Disconnected:  
    Jan 17 14:03:33.489: //331525//Dest:/OBDiscContinue:  
    Jan 17 14:03:33.489: //331525//Dest:/Dest_AAA_CheckAccounting: 
    Jan 17 14:03:33.489: //331525//Dest:/Dest_AAA_CheckAccounting: Accounting to be disabled for callID=331526
    Jan 17 14:03:33.489: //331526/E00F6D438707/AFW_:/AFW_Leg_Disconnect: Disconnecting Leg: LEG_331526, Cause 28
    Jan 17 14:03:33.489: //331526/E00F6D438707/AFW_:/AFW_Leg_UpdateStats: Updating stats for ID 204FD type 2
    Jan 17 14:03:33.489: //-1//Dest:/DestStatusFromDiscCause: mapped "invalid number (28)"(28) to DEST_INVALID_NUMBER(4)
    Jan 17 14:03:33.489: //331525//AFW_:/AFW_FSM_Drive: ACTION END: -------------(OB_STATE_DISCONNECTING[6])---------------
    Jan 17 14:03:33.489: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.489: //331525//Dest:/IW_FSM_Drive:  
    Jan 17 14:03:33.489: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.489: //331525//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(IW_STATE_INIT[1],ev_disconnected[16])---[C_Action]------
    Jan 17 14:03:33.489: //331525//Dest:/IW_InitProc_Disconnect:  
    Jan 17 14:03:33.489: //331525//AFW_:/AFW_FSM_Drive: ACTION END: -------------(IW_STATE_INIT[1])---------------
    Jan 17 14:03:33.489: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.489: //331525//Dest:/DestIsEventNotified:  
    Jan 17 14:03:33.493: //331525//Dest:/DestComplete: peer #:2323 IW State IW_STATE_INIT, OB State OB_STATE_DISCONNECTING
    Jan 17 14:03:33.493: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> NULL
    Jan 17 14:03:33.493: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x64964B68, Type: Event, RefCount: 0
    Jan 17 14:03:33.493: //331526/E00F6D438707/AFW_:/AFW_M_Event_Free:  
    Jan 17 14:03:33.493: //331525//AFW_:/AFW_ExecEnv_CloseIfDone: Cmd Count: 4
    Jan 17 14:03:33.493: //-1//AFW_:/AFW_Event_New:  
    Jan 17 14:03:33.493: //331526/E00F6D438707/AFW_:/AFW_Process_GetCcqEvent: Received 
    Jan 17 14:03:33.493: //-1//AFW_:/AFW_Process_GetCcqEvent:   Event[CC_EV_CALL_DISCONNECT_DONE(17)] {
    Jan 17 14:03:33.493: //-1//AFW_:/AFW_Process_GetCcqEvent:     EXECENV[0x65B778DC]
    Jan 17 14:03:33.493: //-1//AFW_:/AFW_Process_GetCcqEvent:     LEG[331526][LEG_OUTDISCONNECTING(11)][Cause(28)]
    Jan 17 14:03:33.493: //-1//AFW_:/AFW_Process_GetCcqEvent:   }
    Jan 17 14:03:33.493: //-1//SSIN:/AFW_SS_MapEvent: No mapping required
    Jan 17 14:03:33.493: //331526/E00F6D438707/AFW_:/AFW_Object_WalkListeners:  
    Jan 17 14:03:33.493: //331526/E00F6D438707/AFW_:/AFW_M_Object_ShowListeners: START
    Jan 17 14:03:33.493: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[Destination_65BD07A4_0_1737825808]  (
    Jan 17 14:03:33.493: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331525][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 14:03:33.493: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331526][LEG_DISCONNECTED(12)][Cause(28)]
    Jan 17 14:03:33.493: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
    Jan 17 14:03:33.493: //331526/E00F6D438707/AFW_:/AFW_M_Object_ShowListeners: END
    Jan 17 14:03:33.493: //331526/E00F6D438707/AFW_:/AFW_Object_WalkListeners: Entering Module : Destination
    Jan 17 14:03:33.493: //331525//AFW_:/AFW_Module_UnListen:  NumObjects: 1
    Jan 17 14:03:33.493: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: NULL ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.493: //331525//Dest:/AFW_M_Destination_Action:  
    Jan 17 14:03:33.493: //331525//Dest:/AFW_Destination_Action:  
    Jan 17 14:03:33.493: //331525//Dest:/OB_FSM_Drive:  
    Jan 17 14:03:33.493: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.493: //331525//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(OB_STATE_DISCONNECTING[6],ev_disconnect_done[17])---[C_Action]------
    Jan 17 14:03:33.493: //331525//Dest:/OB_Disconnecting_DiscDone:  
    Jan 17 14:03:33.493: //331525//Dest:/DestDialPeerRotary:  
    Jan 17 14:03:33.493: //331525//Dest:/DestOutboundCallUsingPeer: dest(232355123456789), numexpDest(232355123456789), numDestDigits(0)
    Jan 17 14:03:33.493: //331525//Dest:/DestOutboundCallUsingPeer:    prefix(), peer tag(18)
    Jan 17 14:03:33.493: //331525//Dest:/DestCheckTeleUnassBusy:  
    Jan 17 14:03:33.493: //331525//Dest:/DestSetup:  
    Jan 17 14:03:33.493: //-1//SSIN:/AFW_SS_H450_PrepareCIInform:  
    Jan 17 14:03:33.493: //-1//AFW_:/AFW_Leg_New:  
    Jan 17 14:03:33.493: //331527/E00F6D438707/AFW_:/AFW_Leg_NewSetupRequest: ccCallSetupRequest done
    Jan 17 14:03:33.493: //331527/E00F6D438707/AFW_:/AFW_M_Leg_SetExecEnv:  
    Jan 17 14:03:33.493: //331525//AFW_:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 5
    Jan 17 14:03:33.493: //-1/E00F6D438707/AFW_:LP:EE65B778DC000:LG331527:/AFW_M_Object_SetExecEnv: ObjCount: 6, CmdPending 5
    Jan 17 14:03:33.493: //331527/E00F6D438707/AFW_:/AFW_M_Leg_GetHandle: Leg handle: LEG_331527
    Jan 17 14:03:33.493: //331527/E00F6D438707/AFW_:/AFW_Leg_UpdateStats: Updating stats for ID 204FD type 3
    Jan 17 14:03:33.493: //331525//Dest:/DestSetup: Destination setup success
    Jan 17 14:03:33.493: //331525//AFW_:/AFW_FSM_Drive: ACTION END: -------------(OB_STATE_SETTING[3])---------------
    Jan 17 14:03:33.493: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.493: //331525//Dest:/IW_FSM_Drive:  
    Jan 17 14:03:33.493: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.493: //331525//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(IW_STATE_INIT[1],ev_disconnect_done[17])---[C_Action]------
    Jan 17 14:03:33.493: //331525//Dest:/IW_InitProc_Disconnect:  
    Jan 17 14:03:33.493: //331525//AFW_:/AFW_FSM_Drive: ACTION END: -------------(IW_STATE_INIT[1])---------------
    Jan 17 14:03:33.493: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.493: //331525//Dest:/DestIsEventNotified:  
    Jan 17 14:03:33.497: //331525//Dest:/DestComplete: peer #:18 IW State IW_STATE_INIT, OB State OB_STATE_SETTING
    Jan 17 14:03:33.497: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> NULL
    Jan 17 14:03:33.497: //331526/E00F6D438707/AFW_:/AFW_Object_WalkListeners: 
    Jan 17 14:03:33.497: //331526/E00F6D438707/AFW_:/AFW_M_Object_ShowListeners: START
    Jan 17 14:03:33.497: //331526/E00F6D438707/AFW_:/AFW_M_Object_ShowListeners: END
    Jan 17 14:03:33.497: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x65EFDEDC, Type: Event, RefCount: 0
    Jan 17 14:03:33.497: //331526/E00F6D438707/AFW_:/AFW_M_Event_Free:  
    Jan 17 14:03:33.497: //331526/E00F6D438707/AFW_:/AFW_M_Event_Free:  CC_EV_CALL_DISCONNECT_DONE for a Leg: LEG_331526
    Jan 17 14:03:33.497: //331525//AFW_:/AFW_ExecEnv_DecrNPendingCmd:  PendingCmdCount: 4
    Jan 17 14:03:33.497: //-1//AFW_:/AFW_M_Object_UnSetExecEnv: ObjCount: 5, CmdPending 4
    Jan 17 14:03:33.497: //331526/E00F6D438707/AFW_:/AFW_M_Event_Free: ExecEnv objCount: 5
    Jan 17 14:03:33.497: //-1//AFW_:/AFW_Instance_DecrRefCount: Object: 0x671E883C, Type: Leg, RefCount: 0
    Jan 17 14:03:33.497: //331526/E00F6D438707/AFW_:/AFW_M_Leg_Free:  
    Jan 17 14:03:33.497: //331525//AFW_:/AFW_ExecEnv_CloseIfDone: Cmd Count: 4
    Jan 17 14:03:33.497: //-1//AFW_:/AFW_Event_New:  
    Jan 17 14:03:33.497: //331527/E00F6D438707/AFW_:/AFW_Process_GetCcqEvent: Received 
    Jan 17 14:03:33.497: //-1//AFW_:/AFW_Process_GetCcqEvent:   Event[CC_EV_CALL_DISCONNECTED(16)] {
    Jan 17 14:03:33.497: //-1//AFW_:/AFW_Process_GetCcqEvent:     EXECENV[0x65B778DC]
    Jan 17 14:03:33.497: //-1//AFW_:/AFW_Process_GetCcqEvent:     LEG[331527][LEG_OUTINIT(7)][Cause(0)]
    Jan 17 14:03:33.497: //-1//AFW_:/AFW_Process_GetCcqEvent:   }
    Jan 17 14:03:33.497: //331527/E00F6D438707/SSIN:/AFW_SS_MapEvent:  
    Jan 17 14:03:33.497: //-1//SSIN:/AFW_SS_H323_MapEvent:  
    Jan 17 14:03:33.497: //-1//SSIN:/SS_H323_GetNonStandardRerouteRequest:  
    Jan 17 14:03:33.497: //331527/E00F6D438707/AFW_:/AFW_Object_WalkListeners:  
    Jan 17 14:03:33.497: //331527/E00F6D438707/AFW_:/AFW_M_Object_ShowListeners: START
    Jan 17 14:03:33.497: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[Destination_65BD07A4_0_1737825808]  (
    Jan 17 14:03:33.497: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331527][LEG_OUTINIT(7)][Cause(41)]
    Jan 17 14:03:33.497: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[331525][LEG_INCPROCEED(3)][Cause(0)]
    Jan 17 14:03:33.497: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
    Jan 17 14:03:33.497: //331527/E00F6D438707/AFW_:/AFW_M_Object_ShowListeners: END
    Jan 17 14:03:33.497: //331527/E00F6D438707/AFW_:/AFW_Object_WalkListeners: Entering Module : Destination
    Jan 17 14:03:33.497: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: NULL ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.497: //331525//Dest:/AFW_M_Destination_Action:  
    Jan 17 14:03:33.497: //331525//Dest:/AFW_Destination_Action:  
    Jan 17 14:03:33.497: //331525//Dest:/OB_FSM_Drive:  
    Jan 17 14:03:33.497: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.497: //331525//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(OB_STATE_SETTING[3],ev_disconnected[16])---[C_Action]------
    Jan 17 14:03:33.497: //331525//Dest:/OB_Setting_Disconnected:  
    Jan 17 14:03:33.497: //331525//Dest:/OBDiscContinue:  
    Jan 17 14:03:33.497: //331525//Dest:/Dest_AAA_CheckAccounting: 
    Jan 17 14:03:33.497: //331525//Dest:/Dest_AAA_CheckAccounting: accounting to be enabled for callID=331527
    Jan 17 14:03:33.497: //331527/E00F6D438707/AFW_:/AFW_Leg_Disconnect: Disconnecting Leg: LEG_331527, Cause 41
    Jan 17 14:03:33.497: //331527/E00F6D438707/AFW_:/AFW_Leg_UpdateStats: Updating stats for ID 204FD type 2
    Jan 17 14:03:33.497: //-1//Dest:/DestStatusFromDiscCause: mapped "temporary failure (41)"(41) to DEST_CC_FAILED(5)
    Jan 17 14:03:33.497: //331525//AFW_:/AFW_FSM_Drive: ACTION END: -------------(OB_STATE_DISCONNECTING[6])---------------
    Jan 17 14:03:33.497: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.497: //331525//Dest:/IW_FSM_Drive:  
    Jan 17 14:03:33.497: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.497: //331525//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(IW_STATE_INIT[1],ev_disconnected[16])---[C_Action]------
    Jan 17 14:03:33.497: //331525//Dest:/IW_InitProc_Disconnect:  
    Jan 17 14:03:33.497: //331525//AFW_:/AFW_FSM_Drive: ACTION END: -------------(IW_STATE_INIT[1])---------------
    Jan 17 14:03:33.497: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> Destination_65BD07A4_0_1737825808
    Jan 17 14:03:33.497: //331525//Dest:/DestIsEventNotified:  
    Jan 17 14:03:33.497: //331525//Dest:/DestComplete: peer #:18 IW State IW_STATE_INIT, OB State OB_STATE_DISCONNECTING
    Jan 17 14:03:33.497: //331525//AFW_:/AFW_ExecEnv_SetModuleScope: Destination_65BD07A4_0_1737825808 ---> NULL
    Jan 17 14:03:33.497: //-1//AFW_:/AFW_Instance_DecrRefCount: Null or invalid event context: for event APP_EV_NULL

    Subject: RE: TCL fails with incorrect codec?
    Replied by: Raghavendra Gutty Veeranagappa on 17-01-2012 11:31:13 AM
    Hi Mark,

    we need to go in detail to find the issue, please raise developer suppot case.

    Thanks,
    Raghavendra

    Subject: RE: TCL fails with incorrect codec?
    Replied by: Mark Alliban on 17-01-2012 11:34:12 AM
    Hi there,
    How do I do this please??
    Regards,
    Mark.

    Subject: RE: TCL fails with incorrect codec?
    Replied by: Raghavendra Gutty Veeranagappa on 17-01-2012 12:14:28 PM
    Hi Mark,

    you can login to below URL with cisco.com UserID.

    http://tools.cisco.com/ServiceRequestTool/create/

    You need CDN Contract to raise developer support case for more information you can refer below link.
    http://developer.cisco.com/web/devservices/alldevs/supportsubscription

    Thanks,
    Raghavendra

    Subject: RE: TCL fails with incorrect codec?
    Replied by: Mark Alliban on 19-01-2012 08:45:53 AM
    Hmm, I don't know if our IT budget will stretch to $2000 to fix this issue!

    Subject: RE: TCL fails with incorrect codec?
    Replied by: srikanth satturi on 20-01-2012 01:40:05 AM
    Hi

    Did u see ur codec configs, does it look like this

    voice class codec 1
    codec preference 1 g729br8
    codec preference 2 g729r8
    codec preference 3 g711ulaw
    codec preference 4 g711alaw
    !


    And also check for 'dspfarm profile' in your config, refer to this link for dspfarm http://www.cisco.com/en/US/docs/ios/12_4t/12_4t15/it_unitr.html

    And also as u said, as bandwidth is being eaten up  by g711ulaw so u are using g729.  Do u have different voice codec classes for these codecs for example

    voice class codec 2
    codec preference 1 g729br8
    codec preference 2 g729r
    !

    voice class codec 3
    codec preference 1 g711ulaw
    codec preference 2 g711alaw
    !

    and u can use required class in dialpeer. Please check if it helps, thanks.

    Srikanth

    Subject: RE: TCL fails with incorrect codec?
    Replied by: Mark Alliban on 20-01-2012 07:40:05 AM
    Did u see ur codec configs, does it look like this

    voice class codec 1
    codec preference 1 g729br8
    codec preference 2 g729r8
    codec preference 3 g711ulaw
    codec preference 4 g711alaw

    No, it only has preferences 1 and 2 set to g729r8 and g729br8 because I do not want to support g711.

    And also check for 'dspfarm profile' in your config, refer to this link for dspfarm http://www.cisco.com/en/US/docs/ios/12_4t/12_4t15/it_unitr.html

    I do not want to transcode. I want to reject calls using g711.

    Do u have different voice codec classes for these codecs for example

    voice class codec 2
    codec preference 1 g729br8
    codec preference 2 g729r

    voice class codec 3
    codec preference 1 g711ulaw
    codec preference 2 g711alaw

    No, why would I need a voice class codec for something that is not used? The dial-peer does use codec class 1 which only has g729r8 and g729br8. Is there any reason to create a voice class codec 2 containing g711?

    Subject: RE: TCL fails with incorrect codec?
    Replied by: srikanth satturi on 20-01-2012 12:56:11 PM
    oh okay, thought u wanna support two codecs, okay cool.