« Back to TCL-API

Media Record: Detecting silence

Combination View Flat View Tree View
Threads [ Previous | Next ]
I have a TCL application that places an outbound call to a telephone number and plays a recorded message to the called number.  I need to be able to detect when the person answering the call has finished saying hello before my application starts playing the audio.  I'm using media record with finalsilence set to 2seconds but this never causes the media record call to terminate with a status of ms_109 as expected.  VAD is enabled on the dial peer that the application is using.  Is there anything else to configure? what debug command can i use to get more information on why it's not detecting the silence after the initial greetings from the called number? Any help would be appreciated.
Thanks

I don't think Tcl can detect person answering the call has finished saying hello. I will do this way if I want to setup delay timer.


timer start named_timer $delay delay_timer

you can make delay configurable from IOS

if [infotag get cfg_avpair_exists delay-timer] {
set delay [string trim [infotag get cfg_avpair delay-timer]]

} else {
set delay 1
# in second
}

Do it when leg setup returns "ls_000"

Thanks,

Yawming

Have you received "ev_media_done" ?

Thanks for the response.
Yes, I realize TCL won't be able to detect hello and that was only an example. What I need it to do is tell me when it detect silence, which according to documentation, specifying a final silence value will cause it to terminate with status ms_109, and this is not happening. right now it only terminates when max recording time is reached. VAD is enabled but I don't know what else to activate or debug to get more information on why it isn't detecting silence after finalSilence has expired. I hope this clarifies it.

Did you receive ev_media_done ?

For Tcl related debug check
deb voip app ?

Yes, I do receive the ev_media_done event but the status is ms_106 (max record timeout reached). I was expecting ms_109

That's a good sign actually. Can you post how you setup the "media record" and dial-peer config ?

I was mistaken. I'm getting ev_recorder event and not ev_media_done. In any case, I'll post the log soon. Here's the output after issuing media record


Mar 26 23:32:59.244: //-1//SERV:/AFW_Service_GetExecEnv: Script Name = Script1
Mar 26 23:32:59.244: //-1//SERV:/AFW_Service_GetExecEnv: Using Cached ExecEnv
Mar 26 23:32:59.244: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetRoot: Execenv = 0x2BE60898
Mar 26 23:32:59.244: //-1//AFW_:/AFW_M_TclModule_NewDup: 
Mar 26 23:32:59.244: //-1//AFW_:HN37154BDC:/AFW_M_TclModule_Free: 
Mar 26 23:32:59.244: //-1//AFW_:HN37154BDC:/AFW_M_Module_GetHandle: Module handle: TclModule_30C775F8_0_924142556MOD[TclModule_30C775F8_0_924142556]    ( )
Mar 26 23:32:59.244: //-1//AFW_:/AFW_M_FSM_Free: 
Mar 26 23:32:59.244: //-1//AFW_:/AFW_Process_Lock: pProcess(0x30A029DC)=1
Mar 26 23:32:59.244: //-1//AFW_:LP:EE2BE60898000:HN37166060:/AFW_M_Object_SetExecEnv: ObjCount: 1, CmdPending 0
Mar 26 23:32:59.244: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_RestoreDataBackup: Restore DataArea from Script
Mar 26 23:32:59.244: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_RestoreDataBackup: Restore TokenTable from Script
Mar 26 23:32:59.244: //-1//AFW_:/AFW_Event_New: Event ID: ev_session_indication
Mar 26 23:32:59.244: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_Initiate: Execenv = 0x2BE60898
Mar 26 23:32:59.244: //-1//AFW_:EE2BE60898000:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
Mar 26 23:32:59.244: //-1//AFW_:EE2BE60898000:/AFW_Process_GetApp0x2BE60898][Script1]
Mar 26 23:32:59.244: //-1//AFW_:/AFW_Process_GetAppQEvent:    
Mar 26 23:32:59.244: //-1//AFW_:EE2BE60898000:/AFW_M_Module_GetHandle: Module handle: TclModule_30C77A48_0_924213344MOD[TclModule_30C77A48_0_924213344]  (
Mar 26 23:32:59.244: //-1//AFW_:/AFW_Process_GetAppQEvent:     )
Mar 26 23:32:59.244: //-1//AFW_:/AFW_Process_GetAppQEvent:   }
Mar 26 23:32:59.244: //-1//AFW_:EE2BE60898000:/AFW_M_TclModule_EventPreProcess:  QEvent: Received
Mar 26 23:32:59.244: //-1//AFW_:/AFW_Process_GetAppQEvent:   Event[APP_EV_SESSION_START_IND(199)] {
Mar 26 23:32:59.244: //-1//AFW_:/AFW_Process_GetAppQEvent:     EXECENV[
Mar 26 23:32:59.244: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: TclModule_30C77A48_0_924213344 ---> TclModule_30C77A48_0_924213344
Mar 26 23:32:59.244: //-1//AFW_:EE2BE60898000:/AFW_M_TclModule_Action: 
Mar 26 23:32:59.244: //-1//AFW_:EE2BE60898000:/AFW_TclModule_DefaultEvHandling: 
Mar 26 23:32:59.244: //-1//AFW_:EE2BE60898000:/AFW_FSM_Drive: ACTION BEGIN: ------(SETUP[1],ev_session_indication[199])---[action_setup]------
Mar 26 23:32:59.244: //-1//TCL :EE2BE60898000:/tcl_PutsObjCmd: action_setup - start
Mar 26 23:32:59.244:
Mar 26 23:32:59.244: //-1//PACK:EE2BE60898000:/tcl_httpiosGeturlObjCmd:  httpios::geturl http://172.20.40.203/webapp/servicemanager.ashx?q=get -command action_http_request_complete -timeout 30
Mar 26 23:32:59.244: //-1//PACK:EE2BE60898000:/tcl_httpiosGeturlObjCmd: Current NS: ::
Mar 26 23:32:59.244: //-1//PACK:EE2BE60898000:/tcl_httpiosGeturlObjCmd: URL: http://172.20.40.203/webapp/servicemanager.ashx?q=get
Mar 26 23:32:59.244: //-1//AFW_:/AFW_Event_New: Event ID: UnknownEvent
Mar 26 23:32:59.244: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 1
Mar 26 23:32:59.248: //-1//TCL :EE2BE60898000:/tcl_PutsObjCmd: action_setup - complete
Mar 26 23:32:59.248:
Mar 26 23:32:59.248: //-1//AFW_:EE2BE60898000:/AFW_FSM_Drive: ACTION END: -------------(SETUP[1])---------------
Mar 26 23:32:59.248: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: TclModule_30C77A48_0_924213344 ---> TclModule_30C77A48_0_924213344
Mar 26 23:32:59.248: //-1//AFW_:EE2BE60898000:/AFW_M_Event_Free: 
Mar 26 23:32:59.248: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_CloseIfDone: Cmd Count: 1
Mar 26 23:32:59.248: //-1//AFW_:/AFW_Event_New: Event ID: ev_any_event
Mar 26 23:32:59.248: //-1//AFW_:/AFW_M_Event_Free: 
Mar 26 23:32:59.248: //-1//AFW_:/AFW_M_Event_Free: Null or invalid event context: for event APP_EV_NULL
Mar 26 23:32:59.416: //-1//AFW_:EE2BE60898000:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
Mar 26 23:32:59.416: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_DecrNPendingCmd:  PendingCmdCount: 0
Mar 26 23:32:59.416: //-1//PACK:/httpios_http_get_cb:
Mar 26 23:32:59.416: httpios_http_get_cb: status: 200
Mar 26 23:32:59.416: //-1//AFW_:EE2BE60898000:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
Mar 26 23:32:59.416: //-1//AFW_:EE2BE60898000:/AFW_Process_GetAppQEvent: Received
Mar 26 23:32:59.416: //-1//AFW_:/AFW_Process_GetAppQEvent:   Event[APP_EV_HTTPCB_EVENT(262)] {
Mar 26 23:32:59.420: //-1//AFW_:/AFW_Process_GetAppQEvent:     EXECENV[0x2BE60898][Script1]
Mar 26 23:32:59.420: //-1//AFW_:/AFW_Process_GetAppQEvent:     MOD[TclModule_30C77A48_0_924213344]  (
Mar 26 23:32:59.420: //-1//AFW_:/AFW_Process_GetAppQEvent:     )
Mar 26 23:32:59.420: //-1//AFW_:/AFW_Process_GetAppQEvent:   }
Mar 26 23:32:59.420: //-1//AFW_:EE2BE60898000:/AFW_M_TclModule_EventPreProcess: 
Mar 26 23:32:59.420: //-1//PACK:EE2BE60898000:/tclhttp_handle_httpcb_event: ret_status(0)
Mar 26 23:32:59.420: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: TclModule_30C77A48_0_924213344 ---> TclModule_30C77A48_0_924213344
Mar 26 23:32:59.420: //-1//PACK:EE2BE60898000:/tclhttp_handle_httpcb_event: MODULE HANDLE: :: 0x30C77A48
Mar 26 23:32:59.420: //-1//TCL :EE2BE60898000:/tcl_PutsObjCmd: action_http_request_complete - starting
Mar 26 23:32:59.420:
Mar 26 23:32:59.420: //-1//PACK:EE2BE60898000:/tcl_httpiosDataObjCmd:  httpios::data ::httpios::httpios_814
Mar 26 23:32:59.424: //-1//TCL :EE2BE60898000:/tcl_LegObjCmd:  leg setup 4016 call_info
Mar 26 23:32:59.424: //-1//CSPK:EE2BE60898000:/tcl_LegSetupObjCmd: leg setup 4016 call_info
Mar 26 23:32:59.424: //-1//CSPK:EE2BE60898000:/C_CallSetup_Start: ControlInfo = 0x33123E44, callInfo = 0x31ACA104, destination[0]=4016
Mar 26 23:32:59.424: //-1//CSPK:EE2BE60898000:/C_CallSetup_Start: configured mode=rotary (1)
Mar 26 23:32:59.424: //-1//CSPK:EE2BE60898000:/C_CallSetup_Start: configured reroutemode=rotary (1)
Mar 26 23:32:59.424: //-1//Call:/AFW_CallSetup_New: 
Mar 26 23:32:59.424: //-1//AFW_:/AFW_FSM_New: 
Mar 26 23:32:59.424: //-1//AFW_:LP:EE2BE60898000:HN37166114:/AFW_M_Object_SetExecEnv: ObjCount: 2, CmdPending 0
Mar 26 23:32:59.424: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 1
Mar 26 23:32:59.424: //-1//AFW_:EE2BE60898000:/AFW_Object_AddListener: adding Module TclModule as listener
Mar 26 23:32:59.424: //-1//AFW_:EE2BE60898000:/AFW_M_Module_GetHandle: Module handle: CallSetup_2CA6157C_0_924213524
Mar 26 23:32:59.424: //-1//Call:EE2BE60898000:/AFW_CallSetup_AddDest:  4016 index 0
Mar 26 23:32:59.424: //-1//Call:EE2BE60898000:/AFW_M_CallSetup_Initiate: 
Mar 26 23:32:59.424: //-1//AFW_:/AFW_Util_CopyMLPPDataToCallInfoContainer: Voice MLPP not configured
Mar 26 23:32:59.424: //-1//Call:EE2BE60898000:/CS_UpdateMLPPInfo: ServiceDomain:[none (0)]  DomainIdentifier:[000000]  PrecedenceLevel:[-1 (PRECEDENCE_LEVEL_NONE)]  NormalizedPrecedence:[0 (INTERNAL_PRECEDENCE_0)]  Preempt Hunt Not Set
Mar 26 23:32:59.424: //-1//Call:EE2BE60898000:/CallSetupInitiate: 
Mar 26 23:32:59.428: //-1//Call:EE2BE60898000:/CS_Placecall: 
Mar 26 23:32:59.428: //-1//AFW_:/AFW_Util_GetUserFromURL:
Mar 26 23:32:59.428:  destination: 4016

Mar 26 23:32:59.428: //-1//AFW_:/AFW_Util_GetUserFromURL:
Mar 26 23:32:59.428:  ret_val : 4016

Mar 26 23:32:59.428: //-1//AFW_:/AFW_Util_CopyMLPPDataToCallInfoContainer: Voice MLPP not configured
Mar 26 23:32:59.428: //-1//Call:EE2BE60898000:/CS_UpdateMLPPInfo: ServiceDomain:[none (0)]  DomainIdentifier:[000000]  PrecedenceLevel:[-1 (PRECEDENCE_LEVEL_NONE)]  NormalizedPrecedence:[0 (INTERNAL_PRECEDENCE_0)]  Preempt Hunt Not Set
Mar 26 23:32:59.428: //-1//Dest:/AFW_Destination_New: 
Mar 26 23:32:59.428: //-1//AFW_:/AFW_FSM_New: 
Mar 26 23:32:59.428: //-1//AFW_:/AFW_FSM_New: 
Mar 26 23:32:59.428: //-1//AFW_:LP:EE2BE60898000:HN37166118:/AFW_M_Object_SetExecEnv: ObjCount: 3, CmdPending 1
Mar 26 23:32:59.428: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 2
Mar 26 23:32:59.428: //-1//AFW_:EE2BE60898000:/AFW_Object_AddListener: adding Module CallSetup as listener
Mar 26 23:32:59.428: //-1//AFW_:EE2BE60898000:/AFW_M_Module_GetHandle: Module handle: Destination_2B221E7C_0_924213528
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/AFW_Destination_AddDest: 
Mar 26 23:32:59.428: //-1//Dest:/AFW_Destination_AddDest: adding destination "4016"
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/AFW_M_Destination_Initiate: 
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/AFW_M_Destination_Initiate: Outgoing guid : DB6B6110.76D211E1.82E295EB.3569DFB3
Mar 26 23:32:59.428:  Incoming_guid : 00000000.00000000.00000000.00000000
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/AFW_M_Destination_Initiate: Outgoing gcid : 00000000.00000000.00000000.00000000
Mar 26 23:32:59.428:  Incoming_gcid : 00000000.00000000.00000000.00000000
Mar 26 23:32:59.428: //-1//AFW_:/AFW_Util_CopyMLPPDataToCallInfoContainer: Voice MLPP not configured
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestUpdateMLPPInfo: ServiceDomain:[none (0)]  DomainIdentifier:[000000]  PrecedenceLevel:[-1 (PRECEDENCE_LEVEL_NONE)]  NormalizedPrecedence:[-1 (PRECEDENCE_LEVEL_NONE)] Preempt Hunt Not Set
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestSetupInitiate: 
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestAddRerouteSetupInfo: 
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestAddTransferSetupInfo: 
Mar 26 23:32:59.428: //-1//AFW_:/AFW_Util_CopyCallDataToCallInfo: copied 4016

Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestMatchDialPeer: 
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestMatchDialPeer: src carrier id:, tgt carrier id:
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestQueuePeers: Matched peers:
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestPeerItemUpdatePreemptInfo: 
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestPeerItemResetLPCORInfo: 
Mar 26 23:32:59.428: //-1//Dest:/DestQueuePeers:  6
Mar 26 23:32:59.428: //-1//Dest:/DestQueuePeers: , Total(1)
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestDialPeerRotary: 
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestOutboundCallUsingPeer: dest(4016), numexpDest(4016), numDestDigits(1)
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestOutboundCallUsingPeer:    prefix(0.200), peer tag(6)
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestUpdatePreemptSetupInfo: 
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestDialPeerFilter: 
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestDialPeerFilter: Checking peer [6]
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestPeerFilterRouteCode: Route Code not available in callInfo
Mar 26 23:32:59.428: //-1//Dest:/DestOutboundCallUsingPeer: Outgoing Tag(6) calling[] called[4016]
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestCheckTeleUnassBusy: 
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestHandleLPCOR: 
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestSetup: 
Mar 26 23:32:59.428: //-1//AFW_:/AFW_Leg_GetTypeDetail:  ***ERROR*** pLeg is NULL
Mar 26 23:32:59.428: //-1//SSIN:/AFW_SS_H450_PrepareCIInform: 
Mar 26 23:32:59.428: //-1//AFW_:/AFW_Util_SaveRawMsg: 
Mar 26 23:32:59.428: //-1//AFW_:/AFW_Leg_New: 
Mar 26 23:32:59.428: //526/DB6B611082E2/AFW_:/AFW_Leg_NewSetupRequest: ccCallSetupRequest done
Mar 26 23:32:59.428: //526/DB6B611082E2/AFW_:/AFW_M_Leg_SetExecEnv: 
Mar 26 23:32:59.428: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_IncrPendingCmd:  PendingCmdCount: 3
Mar 26 23:32:59.428: //-1/DB6B611082E2/AFW_:LP:EE2BE60898000:LG526:/AFW_M_Object_SetExecEnv: ObjCount: 4, CmdPending 3
Mar 26 23:32:59.428: //526/DB6B611082E2/AFW_:/AFW_Object_AddListener: adding Module Destination as listener
Mar 26 23:32:59.428: //526/DB6B611082E2/AFW_:/AFW_M_Leg_GetHandle: Leg handle: LEG_526
Mar 26 23:32:59.428: //526/DB6B611082E2/AFW_:/AFW_Leg_UpdateStats: Updating stats for ID 2FD type 3
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/DestSetup: Destination setup success
Mar 26 23:32:59.428: //-1//Dest:EE2BE60898000:/AFW_M_Destination_Initiate: attempting call to destination 4016
Mar 26 23:32:59.428: //-1//Call:EE2BE60898000:/CS_Placecall: Call placed to 4016 index 0
Mar 26 23:32:59.428: //-1//TCL :EE2BE60898000:/tcl_FSMObjCmd:  fsm setstate INITIATE_CALL
Mar 26 23:32:59.428: //-1//TCL :EE2BE60898000:/tcl_FSMSetStateObjCmd: setstate setstate INITIATE_CALL
Mar 26 23:32:59.428: //-1//TCL :EE2BE60898000:/tcl_PutsObjCmd: action_http_request_complete - complete
Mar 26 23:32:59.428:
Mar 26 23:32:59.428: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: TclModule_30C77A48_0_924213344 ---> TclModule_30C77A48_0_924213344
Mar 26 23:32:59.428: //-1//AFW_:EE2BE60898000:/AFW_M_Event_Free: 
Mar 26 23:32:59.428: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_CloseIfDone: Cmd Count: 3
Mar 26 23:32:59.428: //-1//AFW_:/AFW_Event_New: Event ID: ev_any_event
Mar 26 23:32:59.428: //-1//AFW_:/AFW_M_Event_Free: 
Mar 26 23:32:59.428: //-1//AFW_:/AFW_M_Event_Free: Null or invalid event context: for event APP_EV_NULL
Mar 26 23:32:59.468: //-1//AFW_:/AFW_Event_New: Event ID: ev_any_event
Mar 26 23:32:59.468: //526/DB6B611082E2/AFW_:/AFW_Process_GetCcqEvent: Received
Mar 26 23:32:59.468: //-1//AFW_:/AFW_Process_GetCcqEvent:   Event[CC_EV_CALL_PROCEEDING(31)] {
Mar 26 23:32:59.468: //-1//AFW_:/AFW_Process_GetCcqEvent:     EXECENV[0x2BE60898][Script1]
Mar 26 23:32:59.468: //-1//AFW_:/AFW_Process_GetCcqEvent:     LEG[526][LEG_OUTINIT(7)][Cause(0)]
Mar 26 23:32:59.468: //-1//AFW_:/AFW_Process_GetCcqEvent:   }
Mar 26 23:32:59.468: //526/DB6B611082E2/SSIN:/AFW_SS_MapEvent: 
Mar 26 23:32:59.468: //-1//SSIN:/AFW_SS_H323_MapEvent: 
Mar 26 23:32:59.468: //526/DB6B611082E2/AFW_:/AFW_M_Leg_EventPreProcess: LEG[526    ][LEG_OUTINIT(7)][Cause(0)]
Mar 26 23:32:59.468: //526/DB6B611082E2/AFW_:/AFW_Object_WalkListeners: 
Mar 26 23:32:59.468: //526/DB6B611082E2/AFW_:/AFW_M_Object_ShowListeners: START
Mar 26 23:32:59.468: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[Destination_2B221E7C_0_924213528]  (
Mar 26 23:32:59.472: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[526][LEG_OUTINIT(7)][Cause(0)]
Mar 26 23:32:59.472: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
Mar 26 23:32:59.472: //526/DB6B611082E2/AFW_:/AFW_M_Object_ShowListeners: END
Mar 26 23:32:59.472: //526/DB6B611082E2/AFW_:/AFW_Object_WalkListeners: Entering Module : Destination
Mar 26 23:32:59.472: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: TclModule_30C77A48_0_924213344 ---> Destination_2B221E7C_0_924213528
Mar 26 23:32:59.472: //-1//Dest:EE2BE60898000:/AFW_M_Destination_Action: 
Mar 26 23:32:59.472: //-1//Dest:EE2BE60898000:/AFW_Destination_Action: 
Mar 26 23:32:59.472: //-1//Dest:EE2BE60898000:/OB_FSM_Drive: 
Mar 26 23:32:59.472: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: Destination_2B221E7C_0_924213528 ---> Destination_2B221E7C_0_924213528
Mar 26 23:32:59.472: //-1//AFW_:EE2BE60898000:/AFW_FSM_Drive: ACTION BEGIN: ------(OB_STATE_SETTING[3],ev_proceeding[31])---[C_Action]------
Mar 26 23:32:59.472: //-1//Dest:EE2BE60898000:/OB_Setting_Proceeding: 
Mar 26 23:32:59.472: //-1//AFW_:EE2BE60898000:/AFW_FSM_Drive: ACTION END: -------------(OB_STATE_SETTING[3])---------------
Mar 26 23:32:59.472: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: Destination_2B221E7C_0_924213528 ---> Destination_2B221E7C_0_924213528
Mar 26 23:32:59.472: //-1//Dest:EE2BE60898000:/IW_FSM_Drive: 
Mar 26 23:32:59.472: //-1//Dest:EE2BE60898000:/IW_FSM_Drive: No interworking leg, no need to interwork event
Mar 26 23:32:59.472: //-1//Dest:EE2BE60898000:/DestIsEventNotified: 
Mar 26 23:32:59.472: //-1//Dest:EE2BE60898000:/DestComplete: peer #:6 IW State IW_STATE_INIT, OB State OB_STATE_SETTING
Mar 26 23:32:59.472: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: Destination_2B221E7C_0_924213528 ---> TclModule_30C77A48_0_924213344
Mar 26 23:32:59.472: //526/DB6B611082E2/AFW_:/AFW_M_Event_Free: 
Mar 26 23:32:59.472: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_CloseIfDone: Cmd Count: 3
Mar 26 23:32:59.476: //-1//AFW_:/AFW_Event_New: Event ID: ev_any_event
Mar 26 23:32:59.476: //526/DB6B611082E2/AFW_:/AFW_Process_GetCcqEvent: Received
Mar 26 23:32:59.476: //-1//AFW_:/AFW_Process_GetCcqEvent:   Event[CC_EV_CALL_ALERT(16)] {
Mar 26 23:32:59.476: //-1//AFW_:/AFW_Process_GetCcqEvent:     EXECENV[0x2BE60898][Script1]
Mar 26 23:32:59.476: //-1//AFW_:/AFW_Process_GetCcqEvent:     LEG[526][LEG_OUTPROCEED(8)][Cause(0)]
Mar 26 23:32:59.476: //-1//AFW_:/AFW_Process_GetCcqEvent:   }
Mar 26 23:32:59.476: //526/DB6B611082E2/SSIN:/AFW_SS_MapEvent: 
Mar 26 23:32:59.476: //-1//SSIN:/AFW_SS_H323_MapEvent: 
Mar 26 23:32:59.480: //526/DB6B611082E2/AFW_:/AFW_Object_WalkListeners: 
Mar 26 23:32:59.480: //526/DB6B611082E2/AFW_:/AFW_M_Object_ShowListeners: START
Mar 26 23:32:59.480: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[Destination_2B221E7C_0_924213528]  (
Mar 26 23:32:59.480: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[526][LEG_OUTPROCEED(8)][Cause(0)]
Mar 26 23:32:59.480: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
Mar 26 23:32:59.480: //526/DB6B611082E2/AFW_:/AFW_M_Object_ShowListeners: END
Mar 26 23:32:59.480: //526/DB6B611082E2/AFW_:/AFW_Object_WalkListeners: Entering Module : Destination
Mar 26 23:32:59.480: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: NULL ---> Destination_2B221E7C_0_924213528
Mar 26 23:32:59.480: //-1//Dest:EE2BE60898000:/AFW_M_Destination_Action: 
Mar 26 23:32:59.480: //-1//Dest:EE2BE60898000:/AFW_Destination_Action: 
Mar 26 23:32:59.480: //-1//Dest:EE2BE60898000:/OB_FSM_Drive: 
Mar 26 23:32:59.480: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: Destination_2B221E7C_0_924213528 ---> Destination_2B221E7C_0_924213528
Mar 26 23:32:59.480: //-1//AFW_:EE2BE60898000:/AFW_FSM_Drive: ACTION BEGIN: ------(OB_STATE_SETTING[3],ev_alert[16])---[C_Action]------
Mar 26 23:32:59.480: //-1//Dest:EE2BE60898000:/OB_Setting_Alert: 
Mar 26 23:32:59.480: //-1//Dest:/OB_Setting_Alert: aData bitmask 0x0

Mar 26 23:32:59.480: //-1//AFW_:EE2BE60898000:/AFW_FSM_Drive: ACTION END: -------------(OB_STATE_SETTING[3])---------------
Mar 26 23:32:59.480: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: Destination_2B221E7C_0_924213528 ---> Destination_2B221E7C_0_924213528
Mar 26 23:32:59.480: //-1//Dest:EE2BE60898000:/IW_FSM_Drive: 
Mar 26 23:32:59.480: //-1//Dest:EE2BE60898000:/IW_FSM_Drive: No interworking leg, no need to interwork event
Mar 26 23:32:59.480: //-1//Dest:EE2BE60898000:/DestIsEventNotified: 
Mar 26 23:32:59.480: //-1//Dest:EE2BE60898000:/DestComplete: peer #:6 IW State IW_STATE_INIT, OB State OB_STATE_SETTING
Mar 26 23:32:59.480: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: Destination_2B221E7C_0_924213528 ---> NULL
Mar 26 23:32:59.480: //526/DB6B611082E2/AFW_:/AFW_M_Event_Free: 
Mar 26 23:32:59.480: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_CloseIfDone: Cmd Count: 3
Mar 26 23:32:59.480: //-1//AFW_:/AFW_Event_New: Event ID: ev_any_event
Mar 26 23:32:59.480: //526/DB6B611082E2/AFW_:/AFW_Process_GetCcqEvent: Received
Mar 26 23:32:59.480: //-1//AFW_:/AFW_Process_GetCcqEvent:   Event[CC_EV_CALL_NOTIFY(30)] {
Mar 26 23:32:59.480: //-1//AFW_:/AFW_Process_GetCcqEvent:     EXECENV[0x2BE60898][Script1]
Mar 26 23:32:59.480: //-1//AFW_:/AFW_Process_GetCcqEvent:     LEG[526][LEG_OUTRINGING(9)][Cause(0)]
Mar 26 23:32:59.480: //-1//AFW_:/AFW_Process_GetCcqEvent:   }
Mar 26 23:32:59.480: //-1//SSIN:/AFW_SS_MapEvent: No mapping required
Mar 26 23:32:59.480: //526/DB6B611082E2/AFW_:/AFW_Util_FillDispNotifyData:  Current: notifyData.connected_num.num_string =4016,notifyData.display_info = ,notifyData.connected_num.oct3a = 131
Mar 26 23:32:59.480: //526/DB6B611082E2/AFW_:/AFW_Util_FillDispNotifyData:  Filled : notifyData.connected_num.num_string =4016,notifyData.display_info = ,notifyData.connected_num.oct3a = 131
Mar 26 23:32:59.480: //526/DB6B611082E2/SSIN:/AFW_SS_H450_TransferSupported: remote end is CCM
Mar 26 23:32:59.480: //526/DB6B611082E2/AFW_:/AFW_Object_WalkListeners: 
Mar 26 23:32:59.480: //526/DB6B611082E2/AFW_:/AFW_M_Object_ShowListeners: START
Mar 26 23:32:59.480: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[Destination_2B221E7C_0_924213528]  (
Mar 26 23:32:59.480: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[526][LEG_OUTRINGING(9)][Cause(0)]
Mar 26 23:32:59.480: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
Mar 26 23:32:59.480: //526/DB6B611082E2/AFW_:/AFW_M_Object_ShowListeners: END
Mar 26 23:32:59.480: //526/DB6B611082E2/AFW_:/AFW_Object_WalkListeners: Entering Module : Destination
Mar 26 23:32:59.480: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: NULL ---> Destination_2B221E7C_0_924213528
Mar 26 23:32:59.480: //-1//Dest:EE2BE60898000:/AFW_M_Destination_Action: 
Mar 26 23:32:59.480: //-1//Dest:EE2BE60898000:/AFW_Destination_Action: 
Mar 26 23:32:59.480: //-1//Dest:EE2BE60898000:/OB_FSM_Drive: 
Mar 26 23:32:59.480: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: Destination_2B221E7C_0_924213528 ---> Destination_2B221E7C_0_924213528
Mar 26 23:32:59.480: //-1//AFW_:EE2BE60898000:/AFW_FSM_Drive: ACTION BEGIN: ------(OB_STATE_SETTING[3],UnknownEvent[30])---[C_Action]------
Mar 26 23:32:59.480: //-1//Dest:EE2BE60898000:/OB_Setting_Notify: 
Mar 26 23:32:59.480: //-1//AFW_:EE2BE60898000:/AFW_FSM_Drive: ACTION END: -------------(OB_STATE_SETTING[3])---------------
Mar 26 23:32:59.480: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: Destination_2B221E7C_0_924213528 ---> Destination_2B221E7C_0_924213528
Mar 26 23:32:59.480: //-1//Dest:EE2BE60898000:/IW_FSM_Drive: 
Mar 26 23:32:59.480: //-1//Dest:EE2BE60898000:/IW_FSM_Drive: No interworking leg, no need to interwork event
Mar 26 23:32:59.480: //-1//Dest:EE2BE60898000:/DestIsEventNotified: 
Mar 26 23:32:59.480: //-1//Dest:EE2BE60898000:/DestComplete: peer #:6 IW State IW_STATE_INIT, OB State OB_STATE_SETTING
Mar 26 23:32:59.480: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: Destination_2B221E7C_0_924213528 ---> NULL
Mar 26 23:32:59.480: //526/DB6B611082E2/AFW_:/AFW_M_Event_Free: 
Mar 26 23:32:59.480: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_CloseIfDone: Cmd Count: 3
Mar 26 23:33:00.776: //-1//AFW_:/AFW_Event_New: Event ID: ev_any_event
Mar 26 23:33:00.776: //526/DB6B611082E2/AFW_:/AFW_Process_GetCcqEvent: Received
Mar 26 23:33:00.776: //-1//AFW_:/AFW_Process_GetCcqEvent:   Event[CC_EV_CALL_CONNECTED(17)] {
Mar 26 23:33:00.776: //-1//AFW_:/AFW_Process_GetCcqEvent:     EXECENV[0x2BE60898][Script1]
Mar 26 23:33:00.776: //-1//AFW_:/AFW_Process_GetCcqEvent:     LEG[526][LEG_OUTRINGING(9)][Cause(0)]
Mar 26 23:33:00.776: //-1//AFW_:/AFW_Process_GetCcqEvent:   }
Mar 26 23:33:00.776: //526/DB6B611082E2/SSIN:/AFW_SS_MapEvent: 
Mar 26 23:33:00.776: //-1//SSIN:/AFW_SS_H323_MapEvent: 
Mar 26 23:33:00.776: //526/DB6B611082E2/AFW_:/AFW_Leg_UpdateStats: Updating stats for ID 2FD type 1
Mar 26 23:33:00.776: //526/DB6B611082E2/AFW_:/AFW_Object_WalkListeners: 
Mar 26 23:33:00.776: //526/DB6B611082E2/AFW_:/AFW_M_Object_ShowListeners: START
Mar 26 23:33:00.776: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[Destination_2B221E7C_0_924213528]  (
Mar 26 23:33:00.776: //-1//AFW_:/AFW_M_Object_ShowListeners:     LEG[526][LEG_OUTCONNECTED(10)][Cause(0)]
Mar 26 23:33:00.776: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
Mar 26 23:33:00.776: //526/DB6B611082E2/AFW_:/AFW_M_Object_ShowListeners: END
Mar 26 23:33:00.776: //526/DB6B611082E2/AFW_:/AFW_Object_WalkListeners: Entering Module : Destination
Mar 26 23:33:00.776: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: NULL ---> Destination_2B221E7C_0_924213528
Mar 26 23:33:00.776: //-1//Dest:EE2BE60898000:/AFW_M_Destination_Action: 
Mar 26 23:33:00.776: //-1//Dest:EE2BE60898000:/AFW_Destination_Action: 
Mar 26 23:33:00.776: //-1//Dest:EE2BE60898000:/OB_FSM_Drive: 
Mar 26 23:33:00.776: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: Destination_2B221E7C_0_924213528 ---> Destination_2B221E7C_0_924213528
Mar 26 23:33:00.776: //-1//AFW_:EE2BE60898000:/AFW_FSM_Drive: ACTION BEGIN: ------(OB_STATE_SETTING[3],ev_connected[17])---[C_Action]------
Mar 26 23:33:00.776: //-1//Dest:EE2BE60898000:/OB_Setting_Connect: 
Mar 26 23:33:00.776: //-1//Dest:EE2BE60898000:/DestNotifySharedLnState: callid: 526, peer: 6
Mar 26 23:33:00.776: //-1//Dest:EE2BE60898000:/DestNotifySharedLnState: Shared-Line NOT enabled!
Mar 26 23:33:00.776: //-1//AFW_:EE2BE60898000:/AFW_FSM_Drive: ACTION END: -------------(OB_STATE_DONE[8])---------------
Mar 26 23:33:00.776: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: Destination_2B221E7C_0_924213528 ---> Destination_2B221E7C_0_924213528
Mar 26 23:33:00.776: //-1//Dest:EE2BE60898000:/IW_FSM_Drive: 
Mar 26 23:33:00.776: //-1//Dest:EE2BE60898000:/IW_FSM_Drive: No interworking leg, no need to interwork event
Mar 26 23:33:00.776: //-1//Dest:EE2BE60898000:/DestIsEventNotified: 
Mar 26 23:33:00.776: //-1//Dest:EE2BE60898000:/DestComplete: peer #:6 IW State IW_STATE_INIT, OB State OB_STATE_DONE
Mar 26 23:33:00.780: //-1//AFW_:/AFW_Event_New: Event ID: ev_destination_done
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Module_ReturnArgEv: 
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Module_ReturnArgEv: Return List (remove=TRUE){LEG[526    ][LEG_OUTCONNECTED(10)][Cause(0)]}
Mar 26 23:33:00.780: //526/DB6B611082E2/AFW_:/AFW_Object_RemoveListener: 
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Module_UnListen:  NumObjects: 0
Mar 26 23:33:00.780: //-1//Dest:EE2BE60898000:/DestReturn: Destination Returning(ds_000 Status DEST_ACTIVE)
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: Destination_2B221E7C_0_924213528 ---> NULL
Mar 26 23:33:00.780: //526/DB6B611082E2/AFW_:/AFW_M_Event_Free: 
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_CloseIfDone: Cmd Count: 3
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Process_GetPriorityQEvent: Received
Mar 26 23:33:00.780: //-1//AFW_:/AFW_Process_GetPriorityQEvent:   Event[APP_EV_DESTINATION_DONE(222)] {
Mar 26 23:33:00.780: //-1//AFW_:/AFW_Process_GetPriorityQEvent:     EXECENV[0x2BE60898][Script1]
Mar 26 23:33:00.780: //-1//AFW_:/AFW_Process_GetPriorityQEvent:     MOD[Destination_2B221E7C_0_924213528]  (
Mar 26 23:33:00.780: //-1//AFW_:/AFW_Process_GetPriorityQEvent:     )
Mar 26 23:33:00.780: //-1//AFW_:/AFW_Process_GetPriorityQEvent:   }
Mar 26 23:33:00.780: //-1//Dest:EE2BE60898000:/AFW_M_Destination_EventPreProcess: 
Mar 26 23:33:00.780: //526/DB6B611082E2/Dest:/DestUpdateSuccessStats: 
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Object_WalkListeners: 
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_M_Object_ShowListeners: START
Mar 26 23:33:00.780: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[CallSetup_2CA6157C_0_924213524]  (
Mar 26 23:33:00.780: //-1//AFW_:/AFW_M_Object_ShowListeners:     MOD[Destination_2B221E7C_0_924213528]  (
Mar 26 23:33:00.780: //-1//AFW_:/AFW_M_Object_ShowListeners:     )
Mar 26 23:33:00.780: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_M_Object_ShowListeners: END
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Object_WalkListeners: Entering Module : CallSetup
Mar 26 23:33:00.780: //526/DB6B611082E2/AFW_:/AFW_Object_AddListener: adding Module CallSetup as listener
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Object_RemoveListener: 
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Module_UnListen:  NumObjects: 1
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: NULL ---> CallSetup_2CA6157C_0_924213524
Mar 26 23:33:00.780: //-1//Call:EE2BE60898000:/AFW_M_CallSetup_Action: 
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_FSM_Drive: ACTION BEGIN: ------(S_PLACECALL[2],ev_destination_done[222])---[C_Action]------
Mar 26 23:33:00.780: //-1//Call:EE2BE60898000:/CS_Placecall_DestDone: 
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_FSM_Drive: ACTION END: -------------(S_DONE[13])---------------
Mar 26 23:33:00.780: //-1//AFW_:/AFW_Event_New: Event ID: ev_setup_done
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Module_ReturnArgEv: 
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Module_ReturnArgEv: Return List (remove=TRUE){LEG[526    ][LEG_OUTCONNECTED(10)][Cause(0)]}
Mar 26 23:33:00.780: //526/DB6B611082E2/AFW_:/AFW_Object_RemoveListener: 
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Module_UnListen:  NumObjects: 0
Mar 26 23:33:00.780: //-1//Call:EE2BE60898000:/CS_Complete: CallSetup Returning(ls_000 Status CS_ACTIVE)
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: CallSetup_2CA6157C_0_924213524 ---> NULL
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Object_WalkListeners:
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_M_Object_ShowListeners: START
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_M_Object_ShowListeners: END
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_M_Event_Free: 
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_M_Event_Free:  MODULEDONEEVENT for a Module: Destination_2B221E7C_0_924213528
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Object_RemoveAllListener: 
Mar 26 23:33:00.780: //-1//AFW_:/AFW_M_Object_UnSetExecEnv: ObjCount: 3, CmdPending 3
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_DecrNPendingCmd:  PendingCmdCount: 2
Mar 26 23:33:00.780: //-1//AFW_:HN37166118:/AFW_M_Event_Free: ExecEnv objCount: 3
Mar 26 23:33:00.780: //-1//Dest:HN37166118:/AFW_M_Destination_Free: 
Mar 26 23:33:00.780: //-1//Dest:HN37166118:/DestEmptyPreemptHoldQ: 
Mar 26 23:33:00.780: //-1//AFW_:/AFW_M_FSM_Free: 
Mar 26 23:33:00.780: //-1//AFW_:/AFW_M_FSM_Free: 
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_CloseIfDone: Cmd Count: 2
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Process_GetPriorityQEvent: Received
Mar 26 23:33:00.780: //-1//AFW_:/AFW_Process_GetPriorityQEvent:   Event[APP_EV_CALLSETUP_DONE(220)] {
Mar 26 23:33:00.780: //-1//AFW_:/AFW_Process_GetPriorityQEvent:     EXECENV[0x2BE60898][Script1]
Mar 26 23:33:00.780: //-1//AFW_:/AFW_Process_GetPriorityQEvent:     MOD[CallSetup_2CA6157C_0_924213524]  (
Mar 26 23:33:00.780: //-1//AFW_:/AFW_Process_GetPriorityQEvent:     )
Mar 26 23:33:00.780: //-1//AFW_:/AFW_Process_GetPriorityQEvent:   }
Mar 26 23:33:00.780: //-1//Call:EE2BE60898000:/AFW_M_CallSetup_EventPreProcess: 
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Object_WalkListeners: 
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_M_Object_ShowListeners: START
Mar 26 23:33:00.780: //-1//AFW_:/AFW_M_Object_ShowListeners:   MOD[TclModule_30C77A48_0_924213344]  (
Mar 26 23:33:00.780: //-1//AFW_:/AFW_M_Object_ShowListeners:     MOD[CallSetup_2CA6157C_0_924213524]  (
Mar 26 23:33:00.780: //-1//AFW_:/AFW_M_Object_ShowListeners:     )
Mar 26 23:33:00.780: //-1//AFW_:/AFW_M_Object_ShowListeners:   )
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_M_Object_ShowListeners: END
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Object_WalkListeners: Entering Module : TclModule
Mar 26 23:33:00.780: //526/DB6B611082E2/AFW_:/AFW_Object_AddListener: adding Module TclModule as listener
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Object_RemoveListener: 
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_Module_UnListen:  NumObjects: 1
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: NULL ---> TclModule_30C77A48_0_924213344
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_M_TclModule_Action: 
Mar 26 23:33:00.780: //-1//AFW_:EE2BE60898000:/AFW_TclModule_DefaultEvHandling: 
Mar 26 23:33:00.784: //-1//AFW_:EE2BE60898000:/AFW_TclModule_UpdateSessionMask: Update intwrk-mask for leg [526]'s session
Mar 26 23:33:00.784: //-1//AFW_:EE2BE60898000:/AFW_FSM_Drive: ACTION BEGIN: ------(INITIATE_CALL[3],ev_setup_done[220])---[action_initiate_call_complete]------
Mar 26 23:33:00.784: //-1//TCL :EE2BE60898000:/tcl_PutsObjCmd: action_initiate_call_complete - starting
Mar 26 23:33:00.784:
Mar 26 23:33:00.784: //-1//TCL :EE2BE60898000:/tcl_InfotagObjCmd:  infotag get evt_status
Mar 26 23:33:00.784: //-1//TCL :EE2BE60898000:/tcl_InfotagGetObjCmd: infotag get evt_status
Mar 26 23:33:00.784: //-1//AFW_:EE2BE60898000:/vtr_ev_status: argc 2 argindex 2
Mar 26 23:33:00.784: //-1//TCL :EE2BE60898000:/tcl_InfotagObjCmd:  infotag get evt_legs
Mar 26 23:33:00.784: //-1//TCL :EE2BE60898000:/tcl_InfotagGetObjCmd: infotag get evt_legs
Mar 26 23:33:00.784: //-1//AFW_:EE2BE60898000:/vtr_ev_legs: argc 2
Mar 26 23:33:00.784: //-1//AFW_:EE2BE60898000:/vtr_ev_legs: EVCALLID [526]
Mar 26 23:33:00.784: //-1//TCL :EE2BE60898000:/tcl_InfotagObjCmd:  infotag get leg_dnis 526
Mar 26 23:33:00.784: //-1//TCL :EE2BE60898000:/tcl_InfotagGetObjCmd: infotag get leg_dnis 526
Mar 26 23:33:00.784: //-1//AFW_:EE2BE60898000:/vtr_lg_dnis: argc 3 argindex 2
Mar 26 23:33:00.784: //-1//TCL :EE2BE60898000:/tcl_PutsObjCmd:
Mar 26 23:33:00.788: //526/DB6B611082E2/AFW_:/AFW_M_Event_Free: 
Mar 26 23:33:00.788: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_CloseIfDone: Cmd Count: 1
Mar 26 23:33:00.788: //-1//AFW_:/AFW_Event_New: Event ID: ev_any_event
Mar 26 23:33:00.788: //-1//AFW_:/AFW_M_Event_Free: 
Mar 26 23:33:00.788: //-1//AFW_:/AFW_M_Event_Free: Null or invalid event context: for event APP_EV_NULL
Mar 26 23:33:00.788: //526//MSM :LP:MS294:/mr_associateDone: 
Mar 26 23:33:00.788: //526//MSM :/mr_associateDone: mc=0x2AC656A4, ASSOCIATING, RAM recording, tx_pt=255, rx_pt=255
Mar 26 23:33:00.788: //526//MSM :/mr_associateDone: RAM RECORDING started
Mar 26 23:33:02.600: //-1//AFW_:/AFW_Event_New: Event ID: ev_any_event
Mar 26 23:33:02.600: //-1//AFW_:/AFW_M_Event_Free: 
Mar 26 23:33:02.600: //-1//AFW_:/AFW_M_Event_Free: Null or invalid event context: for event APP_EV_NULL
Mar 26 23:33:02.600: //-1//AFW_:/AFW_Process_GetTimerEvent: Process Shutdown: 0x30A0295C
Mar 26 23:33:04.864: mr_stream_save_voice: data returned from vsp: 32000
Mar 26 23:33:08.868: mr_stream_save_voice: data returned from vsp: 32000
Mar 26 23:33:11.000: //526//MSM :/mr_stop_record: mc=0x2AC656A4, cause=MS_STOP_MAX_TIME, STOPPING, RAM
Mar 26 23:33:11.000: mr_vsp_flush_stream:  stream=0x3314FCB4, cid=0x20E
Mar 26 23:33:11.000: mr_stream_save_voice: data returned from vsp: 17120
Mar 26 23:33:11.000: Flushing for ram recording: cause MS_STOP_MAX_TIME
Mar 26 23:33:11.000: //526//MSM :/mr_stop_record_done: cid=0x20E stopped at 1w3d, dur=10140 (ms), FLUSHING
Mar 26 23:33:11.000: //526//MSW :/msu_recrd_ms_record_complete: callID=0x20E(526), context=0x2B901844, cause=MS_STOP_MAX_TIME, stream_id=1
Mar 26 23:33:11.000: //526//MSW :/msu_recrd_ms_record_complete: Recorded MC:0x2AC656A4 URL ram:tcl_38_526
Mar 26 23:33:11.000: //526//MSW :/msu_call_app: app_cbf=0x255C9D90
        Event = MSW_EV_RECORDER(0), Context 0x31AA9320, Type    MSW_RECRD_TYPE_RECORD(3), Reason  MSW_RECRD_REASON_MAX_TIME(15)
Mar 26 23:33:11.000: //526/DB6B611082E2/AFW_:/AFW_Leg_MediaCallback: 
Mar 26 23:33:11.000: //-1//AFW_:/AFW_Leg_MediaCallback: pLeg=0x31AA9320, pModule=0x30C77A48
Mar 26 23:33:11.000: //-1//AFW_:/AFW_Event_New: Event ID: ev_recorder
Mar 26 23:33:11.000: //526/DB6B611082E2/AFW_:/AFW_Leg_MediaCallback: URL = ram:tcl_38_526
Mar 26 23:33:11.000: //-1//MSW :/msw_mediadone_stats: 
Mar 26 23:33:11.000: //-1//AFW_:EE2BE60898000:/AFW_Event_IsOk: AppEventOk Success - timestamp MATCHED
Mar 26 23:33:11.000: //-1//AFW_:EE2BE60898000:/AFW_Process_GetAppQEvent: Received
Mar 26 23:33:11.000: //-1//AFW_:/AFW_Process_GetAppQEvent:   Event[MSW_EV_RECORDER(178)] {
Mar 26 23:33:11.000: //-1//AFW_:/AFW_Process_GetAppQEvent:     EXECENV[0x2BE60898][Script1]
Mar 26 23:33:11.000: //-1//AFW_:/AFW_Process_GetAppQEvent:     MOD[TclModule_30C77A48_0_924213344]  (
Mar 26 23:33:11.000: //-1//AFW_:/AFW_Process_GetAppQEvent:       LEG[526][LEG_OUTCONNECTED(10)][Cause(0)]
Mar 26 23:33:11.000: //-1//AFW_:/AFW_Process_GetAppQEvent:     )
Mar 26 23:33:11.000: //-1//AFW_:/AFW_Process_GetAppQEvent:   }
Mar 26 23:33:11.000: //-1//AFW_:EE2BE60898000:/AFW_M_TclModule_EventPreProcess: 
Mar 26 23:33:11.000: //-1//AFW_:EE2BE60898000:/AFW_ExecEnv_SetModuleScope: NULL ---> TclModule_30C77A48_0_924213344
Mar 26 23:33:11.000: //-1//AFW_:EE2BE60898000:/AFW_M_TclModule_Action: 
Mar 26 23:33:11.000: //-1//AFW_:EE2BE60898000:/AFW_TclModule_DefaultEvHandling: 
Mar 26 23:33:11.000: //-1//PACK:EE2BE60898000:/tclrecord_update_statearray: URL: ram:tcl_38_526
Mar 26 23:33:11.000: //526/DB6B611082E2/AFW_:/AFW_Leg_DigitReportDisable: Current: 0x0 Input: 0x8
Mar 26 23:33:11.000: //-1//AFW_:EE2BE60898000:/AFW_FSM_Drive:
Mar 26 23:33:11.008: //-1//AFW_:/AFW_M_Httpdata_Free: 
Mar 26 23:33:11.008: //-1//AFW_:/AFW_M_Httpdata_Free:  Token(::httpios::httpios_814) hdata(0x30002480)
Mar 26 23:33:11.008: //-1//SCRI:/cam_sa_stopped: Instance: ExecEnv: 0x2BE60898
Mar 26 23:33:11.008: //-1//AFW_:/AFW_Event_New: Event ID: ev_any_event
Mar 26 23:33:11.008: //-1//AFW_:/AFW_M_Event_Free: 
Mar 26 23:33:11.008: //-1//AFW_:/AFW_M_Event_Free: Null or invalid event context: for event APP_EV_NULL

 
 
 
and here's the dial peer config:
 
chc#show run | begin dial-peer
dial-peer voice 1 pots
 service acme2
 destination-pattern 2002
!
dial-peer voice 2 voip
 service acme2
 incoming called-number 2002
 dtmf-relay h245-alphanumeric
 codec g711ulaw
!
dial-peer voice 3 pots
 service default.c.old
 destination-pattern 2003
 port 0/2/0
!
dial-peer voice 4 pots
 incoming called-number .
 port 0/2/0
!
dial-peer voice 5 pots
 incoming called-number .
 port 0/2/0
!
dial-peer voice 6 voip
 destination-pattern [459]T
 session target ipv4:172.20.40.200
 dtmf-relay h245-alphanumeric
 codec g711ulaw
 vad aggressive
!

From programming guide:

"The script receives an ev_recorder event when the recording terminates after the specified duration, after
the application issues a media stop command, or if terminated by DTMF. If the recording is terminated
by a leg disconnect command, the script does not receive an ev_media_done event; it receives only an
ev_disconnected event for the leg. If the recording is successful, it can be accessed at the location
specified in the URL.
The status of the recording can be accessed using infotag get evt_status after receiving the
ev_media_done event."

Yes. that's correct. In this case i'm getting ev_recorder event because the recording continues til the end (10seconds). the guide doesn't say what event is sent when the recording is terminated due to silence but from the logs, i don't see any other related event and it doesn't look like it terminated it after the finalsilence time expired.

After enabling "Silence Suppression" and "Silence Suppression for Gateways" on the callmanager that my test phone is registered to, the final silence termination worked so that's a good news. The bad news is that it doesn't seem to work for calls going out through the PSTN. Is this a limition of VAD or is there something that can be done?

Not quite familiar with "silence suppression". Maybe you can post it in Cisco Support Community Forum as well

https://supportforums.cisco.com/index.jspa

I don't have a problem with the callmanager settings. My question is regarding the limitation of VAD on the cisco router. ie. if i'm making a call from a cisco router through the PSTN, would continue to work? are there any other known limitations? at the moment it doesn't seems to work and I need to know if there's something on the router that i can change to ensure it work for all outbound calls.

TAC support forum may have more SME to answer these questions.

Thanks !

VAD is a function of voice compression and the audio on a physical line is not compressed. VAD allows a device to save Bandwidth and other resources by not sending compressed packets of silence. On the receiving end when VAD is enabled and no packets are received, the system will automatically generate a background static so the listener won’t notice anything unusual. PSTN lines are either analog or digital representations of analog lines. There is no technology out there that turns of analog lines in between words to save resources.

Leon


From: Cisco Developer Community Forums
Sent: Thursday, April 12, 2012 10:51 AM
To: cdicuser@developer.cisco.com
Subject: New Message from Chris Manuh in Voice Gateway API (VGAPI) - TCL-API: RE: Media Record: Detecting silence

Chris Manuh has created a new message in the forum "TCL-API":

--------------------------------------------------------------
I don't have a problem with the callmanager settings. My question is regarding the limitation of VAD on the cisco router. ie. if i'm making a call from a cisco router through the PSTN, would continue to work? are there any other known limitations? at the moment it doesn't seems to work and I need to know if there's something on the router that i can change to ensure it work for all outbound calls.
--
To respond to this post, please click the following link:

<http://developer.cisco.com/web/vgapi/forums/-/message_boards/view_message/5441174>

or simply reply to this email.