Media Record: Detecting silence

Version 1
    This document was generated from CDN thread

    Created by: Chris Manuh on 26-03-2012 05:20:44 PM
    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

    Subject: RE: Media Record: Detecting silence
    Replied by: Yaw-Ming Chen on 26-03-2012 05:51:42 PM
    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

    Subject: RE: Media Record: Detecting silence
    Replied by: Yaw-Ming Chen on 26-03-2012 06:02:29 PM
    Have you received "ev_media_done" ?

    Subject: RE: Media Record: Detecting silence
    Replied by: Chris Manuh on 26-03-2012 06:21:19 PM
    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.

    Subject: RE: Media Record: Detecting silence
    Replied by: Yaw-Ming Chen on 26-03-2012 06:34:52 PM
    Did you receive ev_media_done ?

    For Tcl related debug check
    deb voip app ?

    Subject: RE: Media Record: Detecting silence
    Replied by: Chris Manuh on 26-03-2012 07:04:04 PM
    Yes, I do receive the ev_media_done event but the status is ms_106 (max record timeout reached). I was expecting ms_109

    Subject: RE: Media Record: Detecting silence
    Replied by: Yaw-Ming Chen on 26-03-2012 07:15:17 PM
    That's a good sign actually. Can you post how you setup the "media record" and dial-peer config ?

    Subject: RE: Media Record: Detecting silence
    Replied by: Chris Manuh on 26-03-2012 07:36:12 PM
    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
    !


    Subject: RE: Media Record: Detecting silence
    Replied by: Yaw-Ming Chen on 26-03-2012 07:59:42 PM
    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."

    Subject: RE: Media Record: Detecting silence
    Replied by: Chris Manuh on 26-03-2012 08:13:12 PM
    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.

    Subject: RE: Media Record: Detecting silence
    Replied by: Chris Manuh on 12-04-2012 10:19:14 AM
    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?

    Subject: RE: Media Record: Detecting silence
    Replied by: Chris Manuh on 12-04-2012 10:51:41 AM
    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.

    Subject: Re: New Message from Chris Manuh in Voice Gateway API (VGAPI) - TCL-API: RE
    Replied by: LEON MCCALLA on 12-04-2012 12:39:05 PM
    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.

    Subject: RE: Media Record: Detecting silence
    Replied by: Yaw-Ming Chen on 12-04-2012 10:37:18 AM
    Not quite familiar with "silence suppression". Maybe you can post it in Cisco Support Community Forum as well

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

    Subject: RE: Media Record: Detecting silence
    Replied by: Yaw-Ming Chen on 12-04-2012 10:59:14 AM
    TAC support forum may have more SME to answer these questions.

    Thanks !