Script failing because of UnknownEvent

Version 1
    This document was generated from CDN thread

    Created by: Adolfo Arizpe on 23-02-2012 08:41:43 PM
    I'm getting an UnknownEvent that is causing my script to die. This happens about one minute after issuing a leg setup:
     

      Feb 24 01:33:03.228: //19526//AFW_:/AFW_FSM_Drive: FSM no match for (CALLACTIVE[4],UnknownEvent[62])
      Feb 24 01:33:03.228: //19526//SERV:/AFW_Service_Process_Space:  Ill behaved Service script is being closed

     
    What could be causing this?
     
    thank you

    Subject: RE: Script failing because of UnknownEvent
    Replied by: Raghavendra Gutty Veeranagappa on 24-02-2012 03:00:30 AM
    Hi Adolfo,

    could you please send us the complete logs to find the issue.

    Thanks,
    Raghavendra

    Subject: RE: Script failing because of UnknownEvent
    Replied by: Adolfo Arizpe on 24-02-2012 11:04:28 AM

    could you please send us the complete logs to find the issue.

     
    Hi Raghavendra,
     
     since the log is quite big, I'm just adding more lines. If you want me to post it all, let me know. Hopefully there will be enough information here:
     
     

    Feb 24 01:29:47.877: //19526/D4145D45B9F2/VXML:/vxml_load_immediate_done:  
       sidp->status=400000000
    Feb 24 01:29:47.877: //19526//AFW_:/vapp_checksessionstate: 
    Feb 24 01:29:47.877: //19526//AFW_:/vapp_checkifdone: Object: 1, Leg: 1
    Feb 24 01:29:48.077: //19526//HIFS:/hifs_http_cb: hifs http read succeeded. size=637, url=http://192.168.0.1:6590/vxmls/check_rate.xml?destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0
    Feb 24 01:29:48.077: //19526//AFW_:/vapp_bgload_done: status=No Error
    Feb 24 01:29:48.081: //19526//HIFS:/hifs_http_cb: hifs ifs file read succeeded. size=637, url=http://192.168.0.1:6590/vxmls/check_rate.xml?destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0
    Feb 24 01:29:48.081: //19526//HIFS:/hifs_free_idata: hifs_free_idata: 0x84C1BFA4
    Feb 24 01:29:48.081: //19526//HIFS:/hifs_hold_idata: hifs_hold_idata: 0x84C1BFA4
    Feb 24 01:29:48.081: //19526//AFW_:/vapp_driver: evtID: 173 vapp record state: 0
    Feb 24 01:29:48.085: //19526//AFW_:/vapp_bgload_done_event: 
    Feb 24 01:29:48.085: //19526//AFW_:/vapp_bgload_done_event: length=637, page loaded=
    <?xml version="1.0"?>
    <vxml version="2.0">
      <form id="rate">
     
     
        <block> 
          <var name="destination" expr="'12341234'" />
          <var name="seconds_available" expr="'480'" />
          <var na
    Feb 24 01:29:48.085: //19526/D4145D45B9F2/VXML:/vxml_is_doc:  
       vxml_is_doc
     
    Feb 24 01:29:48.085: //-1//VXML:/vxml_tree_lock:  
       vxmlp=84ABA320 usage_cnt=0
    Feb 24 01:29:48.089: //0//VXML:/vxml_parse:  
     
    Feb 24 01:29:48.089: vxml_parse: XML_Parse success err=0
    Feb 24 01:29:48.093: //0//VXML:/vxml_session_delete:  
     
    Feb 24 01:29:48.093: vxml_session_delete:mem_mgr_mempool_free: mempool=NULL
    Feb 24 01:29:48.093: vxml_session_delete:mem_mgr_mempool_free: mempool=NULL
    Feb 24 01:29:48.093: //19526/D4145D45B9F2/VXML:/vxml_bgload_post_done:  
       vxmlhandle=84AFC060 status=0 async_status=400000000
    Feb 24 01:29:48.093: //19526/D4145D45B9F2/VXML:/vxml_bgload_post_done:  
       Loading file with url (http://192.168.0.1:6590/vxmls/check_rate.xml?destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0)
    Feb 24 01:29:48.093: //19526/D4145D45B9F2/VXML:/vxml_leave_scope:  
       scope=application
    Feb 24 01:29:48.097: //19526/D4145D45B9F2/VXML:/vxml_tree_delete:  
       vxmlp=84A8665C, usage_cnt=1 url=http://192.168.0.1:6590/vxmls/index.xml?ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx
    Feb 24 01:29:48.097: vxml_tree_delete:mem_mgr_mempool_free: mem_refcnt(84B10DC8)=0 - mempool cleanup
    Feb 24 01:29:48.097: //19526/D4145D45B9F2/VXML:/vxml_stop_fetchaudio:  
     
    Feb 24 01:29:48.097: //19526/D4145D45B9F2/VXML:/vxml_start:  
       vxmlhandle=84AFC060 vapphandle=851B3778 status=0 async_status=80000
    Feb 24 01:29:48.101: //19526/D4145D45B9F2/VXML:/vxml_vxml_proc:    
    <vxml> 
       URI(abs):http://192.168.0.1:6590/vxmls/check_rate.xml?destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/vxmls/check_rate.xml 
       query=destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0 
       base= 
       URI(abs):http://192.168.0.1:6590/vxmls/check_rate.xml?destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/vxmls/check_rate.xml 
       query=destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0 lang=none version=2.0
    Feb 24 01:29:48.105: //19526/D4145D45B9F2/VXML:/vxml_form_proc: 
    Feb 24 01:29:48.105:  <form>: id=rate   scope=dialog 
    Feb 24 01:29:48.105: //19526/D4145D45B9F2/VXML:/vxml_form_init:  
       current scope: dialog 
       vxml_counter_reset:
    Feb 24 01:29:48.109: //19526/D4145D45B9F2/VXML:/vxml_formitem_select:  
       Status=VXML_STATUS_OK,
    Feb 24 01:29:48.109: //19526/D4145D45B9F2/VXML:/vxml_formitem_select:  
        AsyncStatus=VXML_STATUS_OK
    Feb 24 01:29:48.109: //19526/D4145D45B9F2/VXML:/vxml_block_proc: 
    Feb 24 01:29:48.109:   <block>:
    Feb 24 01:29:48.113: //19526/D4145D45B9F2/VXML:/vxml_item_attrs_proc:  
       name=_in849 
             <var>: namep=destination expr='12341234'
    Feb 24 01:29:48.113: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(var destination='12341234') 
             <var>: namep=seconds_available expr='480'
    Feb 24 01:29:48.117: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(var seconds_available='480') 
             <var>: namep=account_id expr='40'
    Feb 24 01:29:48.121: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(var account_id='40') 
             <var>: namep=usage_token expr='D4145D45.5DBD11E1.B9F29F32.7B7E1175'
    Feb 24 01:29:48.121: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(var usage_token='D4145D45.5DBD11E1.B9F29F32.7B7E1175')
    Feb 24 01:29:48.125: //19526/D4145D45B9F2/VXML:/vxml_prompt_proc_real:  
             <prompt>: alternative(arg)=0 bargein=0 count=1 typeaheadflush=0 alternative=0
    Feb 24 01:29:48.125: //19526/D4145D45B9F2/VXML:/vxml_audio_proc:  
             <audio>: 
       URI(abs):/audios/usted-tiene.g729 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/audios/usted-tiene.g729 caching=fast fetchhint=invalid fetchtimeout=0 maxage=-1 maxstale=-1
    Feb 24 01:29:48.129: //19526/D4145D45B9F2/VXML:/vxml_audio_proc:  
             <audio>: 
       URI(abs):/audios/digits/8.g729 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/audios/digits/8.g729 caching=fast fetchhint=invalid fetchtimeout=0 maxage=-1 maxstale=-1
    Feb 24 01:29:48.129: //19526/D4145D45B9F2/VXML:/vxml_audio_proc:  
             <audio>: 
       URI(abs):/audios/minutos.g729 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/audios/minutos.g729 caching=fast fetchhint=invalid fetchtimeout=0 maxage=-1 maxstale=-1
    Feb 24 01:29:48.129: //19526/D4145D45B9F2/VXML:/vxml_vapp_media_play:  
       bargein=0 timeout=0 typeaheadflush=0 vcr=0 rate=0
    Feb 24 01:29:48.129: //19526/D4145D45B9F2/VXML:/vxml_vapp_media_play:  
       str=http://192.168.0.1:6590/audios/usted-tiene.g729 cachable=1 timeout0 maxage=-1 maxstale=-1
    Feb 24 01:29:48.133: //19526/D4145D45B9F2/VXML:/vxml_vapp_media_play:  
       str=http://192.168.0.1:6590/audios/digits/8.g729 cachable=1 timeout0 maxage=-1 maxstale=-1
    Feb 24 01:29:48.133: //19526/D4145D45B9F2/VXML:/vxml_vapp_media_play:  
       str=http://192.168.0.1:6590/audios/minutos.g729 cachable=1 timeout0 maxage=-1 maxstale=-1
    Feb 24 01:29:48.133: //19526//AFW_:/vapp_media_play: 
    Feb 24 01:29:48.133: //19526//AFW_:/vapp_media_play: prompt=http://192.168.0.1:6590/audios/usted-tiene.g729:
    Feb 24 01:29:48.133: //19526//AFW_:/vapp_media_play: prompt=http://192.168.0.1:6590/audios/digits/8.g729:
    Feb 24 01:29:48.133: //19526//AFW_:/vapp_media_play: prompt=http://192.168.0.1:6590/audios/minutos.g729:
    Feb 24 01:29:48.137: //19526//PACK:/Media_Play_Start:  
    Feb 24 01:29:48.137: //19526/D4145D45B9F2/VXML:/vxml_exit_proc:  
             <exit>:
    Feb 24 01:29:48.137: //19526/D4145D45B9F2/VXML:/vxml_nmtokens_proc:  
       name=destination 
       name=seconds_available 
       name=account_id 
       name=usage_token
    Feb 24 01:29:48.145: //19526/D4145D45B9F2/VXML:/vxml_leave_scope:  
       scope=anonymous
    Feb 24 01:29:48.149: //19526/D4145D45B9F2/VXML:/vxml_load_immediate_done:  
       sidp->status=10
    Feb 24 01:29:48.149: //19526/D4145D45B9F2/VXML:/vxml_throw_error_session_event:  
       async_status=10 
    Feb 24 01:29:48.149: //19526//AFW_:/vapp_checksessionstate: 
    Feb 24 01:29:48.149: //19526//AFW_:/vapp_checkifdone: Object: 1, Leg: 1
    Feb 24 01:29:52.027: //19526//AFW_:/vapp_driver: evtID: 137 vapp record state: 0
    Feb 24 01:29:52.027: //19526//AFW_:/vapp_play_done: evID=137 reason=13, protocol=2, status_code=0, dur=3068, rate=0
    Feb 24 01:29:52.027: //19526/D4145D45B9F2/VXML:/vxml_media_done:  
       status 0 async_status 10 duration=3068 rate=0
    Feb 24 01:29:52.027: //19526/D4145D45B9F2/VXML:/vxml_save_lastprompt_info:  
     
    Feb 24 01:29:52.027: //19526/D4145D45B9F2/VXML:/vxml_save_lastprompt_info:  
     
    Feb 24 01:29:52.031: //19526/D4145D45B9F2/VXML:/vxml_vapp_typeahead_flush:  
     
    Feb 24 01:29:52.031: //19526//AFW_:/vapp_typeahead_flush: 
    Feb 24 01:29:52.031: //19526//AFW_:/vapp_notify_play_done: 
    Feb 24 01:29:52.031: //19526/D4145D45B9F2/VXML:/vxml_vapp_vcr_control_disable:  
     
    Feb 24 01:29:52.031: //19526/D4145D45B9F2/VXML:/vxml_throw_error_session_event:  
       async_status=20010 
    Feb 24 01:29:52.031: //19526/D4145D45B9F2/VXML:/vxml_vapp_terminate:  
       vapp_status=0 ref_count 0
    Feb 24 01:29:52.031: //19526/D4145D45B9F2/VXML:/vxml_vapp_terminate:  
        exitstr=destination=12341234,seconds_available=480,account_id=40,usage_token=D4145D45.5DBD11E1.B9F29F32.7B7E1175
    Feb 24 01:29:52.031: //19526//AFW_:/vapp_terminate: 
    Feb 24 01:29:52.035: //19526//AFW_:/vapp_session_exit_event_name: Exit Event vxml.session.complete
    Feb 24 01:29:52.035: //19526//AFW_:/AFW_M_VxmlModule_Terminate: 
    Feb 24 01:29:52.035: //19526//AFW_:/vapp_checksessionstate: 
    Feb 24 01:29:52.035: //19526//AFW_:/vapp_checkifdone: Object: 1, Leg: 1
    Feb 24 01:29:52.048: //19526/D4145D45B9F2/VXML:/vxml_tree_delete:  
       vxmlp=84ABA320, usage_cnt=1 url=http://192.168.0.1:6590/vxmls/check_rate.xml?destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0
    Feb 24 01:29:52.048: vxml_tree_delete:mem_mgr_mempool_free: mem_refcnt(84ECD2D8)=0 - mempool cleanup
    Feb 24 01:29:52.048: //19526/D4145D45B9F2/VXML:/vxml_session_delete:  
     
    Feb 24 01:29:52.048: vxml_session_delete:mem_mgr_mempool_free: mem_refcnt(84869840)=0 - mempool cleanup
    Feb 24 01:29:52.048: vxml_session_delete:mem_mgr_mempool_free: mempool=NULL
    Feb 24 01:29:52.052: //19526//AFW_:/vapp_checksessionstate: 
    Feb 24 01:29:52.052: //19526//AFW_:/vapp_checkifdone: Object: 0, Leg: 0
    Feb 24 01:29:52.052: //19526//AFW_:/AFW_M_TclModule_Action:  
    Feb 24 01:29:52.052: //19526//AFW_:/AFW_TclModule_DefaultEvHandling:  
    Feb 24 01:29:52.052: //19526//PACK:/tclrecord_create_record_token_url:  
    Feb 24 01:29:52.056: //19526//TCL :/tcl_InfotagObjCmd:  infotag get evt_vxmlevent 
    Feb 24 01:29:52.056: //19526//TCL :/tcl_InfotagGetObjCmd: infotag get evt_vxmlevent 
    Feb 24 01:29:52.056: //19526//AFW_:/vtr_ev_vxmlevent: 
    Feb 24 01:29:52.056: //19526//TCL :/tcl_InfotagObjCmd:  infotag get evt_status 
    Feb 24 01:29:52.056: //19526//TCL :/tcl_InfotagGetObjCmd: infotag get evt_status 
    Feb 24 01:29:52.060: //19526//AFW_:/vtr_ev_status: argc 2 argindex 2
    Feb 24 01:29:52.060: //19526//TCL :/tcl_InfotagObjCmd:  infotag get evt_vxmlevent_params transfer_param 
    Feb 24 01:29:52.060: //19526//TCL :/tcl_InfotagGetObjCmd: infotag get evt_vxmlevent_params transfer_param 
    Feb 24 01:29:52.064: //19526//AFW_:/vtr_ev_vxmlevent_params: 
    Feb 24 01:29:52.064: //19526//TCL :/tcl_PutsObjCmd: 
     
       **** *hybrid*  marcando al 12341234 tiempo disponible en segundos: 480 account_id: 40 usage_token D4145D45.5DBD11E1.B9F29F32.7B7E1175  
     
     
    Feb 24 01:29:52.064: 
    Feb 24 01:29:52.064: //19526//TCL :/tcl_LegObjCmd:  leg setup 12341234 callInfo leg_incoming 
    Feb 24 01:29:52.068: //19526//AFW_:/vtd_lg_incoming: argc 4
    Feb 24 01:29:52.068: //19526//AFW_:/vtd_lg_incoming: Legs [19526 ]
    Feb 24 01:29:52.068: //19526//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Feb 24 01:29:52.072: //-1//AFW_:HN29BE12FF:/AFW_M_VxmlModule_Free: 
    Feb 24 01:29:52.076: MOD[VxmlModule_851B3778_13_700322559] ( )
    Feb 24 01:29:59.400: //19526//AFW_:/AFW_M_TclModule_Action:  
    Feb 24 01:29:59.400: //19526//AFW_:/AFW_TclModule_DefaultEvHandling:  
    Feb 24 01:29:59.400: //19526//AFW_:/AFW_TclModule_UpdateSessionMask: Update intwrk-mask for leg [19529]'s session
    Feb 24 01:29:59.400: //19526//AFW_:/AFW_TclModule_UpdateSessionMask: Update intwrk-mask for leg [19526]'s session
    Feb 24 01:29:59.404: //19526//TCL :/tcl_InfotagObjCmd:  infotag get evt_status 
    Feb 24 01:29:59.408: //19526//TCL :/tcl_InfotagGetObjCmd: infotag get evt_status 
    Feb 24 01:29:59.408: //19526//AFW_:/vtr_ev_status: argc 2 argindex 2
    Feb 24 01:29:59.408: //19526//TCL :/tcl_PutsObjCmd: 
     
       ******************** *hybrid* Status of leg setup is ls_000 
     
     
    Feb 24 01:29:59.408: 
    Feb 24 01:29:59.408: //19526//TCL :/tcl_TimerObjCmd:  timer start leg_timer 479 leg_outgoing 
    Feb 24 01:29:59.408: //19526//TCL :/tcl_TimerStartObjCmd: timer start leg_timer 479 leg_outgoing 
    Feb 24 01:29:59.412: //19526//AFW_:/vtd_lg_outgoing: argc 4
    Feb 24 01:29:59.412: //19526//AFW_:/vtd_lg_outgoing: Legs [19529 ]
    Feb 24 01:29:59.412: //19526//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Feb 24 01:29:59.412: //19526//TCL :/tcl_PutsObjCmd: 
     
       ******************** *hybrid* Call status is ls_000, call active 
     
     
    Feb 24 01:29:59.412: 
    Feb 24 01:31:03.225: //19526//AFW_:/AFW_M_TclModule_Action:  
    Feb 24 01:31:03.225: //19526//AFW_:/AFW_TclModule_DefaultEvHandling:  
    Feb 24 01:31:03.233: //19526//TCL :/tcl_InfotagObjCmd:  infotag get evt_last_disconnect_cause 
    Feb 24 01:31:03.233: //19526//TCL :/tcl_InfotagGetObjCmd: infotag get evt_last_disconnect_cause 
    Feb 24 01:31:03.233: //19526//AFW_:/vtr_ev_last_disconnect_cause: argc 2 argindex 2
    Feb 24 01:31:03.237: //19526//TCL :/tcl_PutsObjCmd: 
     
       ******************** *hybrid* (act_HandleOutgoing) Call Duration was: 64 
     
     
    Feb 24 01:31:03.237: 
    Feb 24 01:31:03.237: //19526//PACK:/tcl_httpiosGeturlObjCmd:  ::httpios::geturl http://192.168.0.1:6590/vxmls/call_ended.xml -query call_duration=64&disconnect_cause=di_016&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&id=40&usage_token=D4145D45.5DBD11E1.B9F29F32.7B7E1175&destination=12341234&access_number=1800xxxxxxxxx&ani=21400007 -command act_RequestResultConParams 
    Feb 24 01:31:03.237: //19526//PACK:/tcl_httpiosGeturlObjCmd: Current NS: ::
    Feb 24 01:31:03.241: //19526//PACK:/tcl_httpiosGeturlObjCmd: URL: http://192.168.0.1:6590/vxmls/call_ended.xml 
    Feb 24 01:31:03.241: //19526//TCL :/tcl_PutsObjCmd: 
     
       ******************** *hybrid* (act_HandleOutgoing) Despues de call_ended 
     
     
    Feb 24 01:31:03.241: 
    Feb 24 01:31:03.241: //19526//TCL :/tcl_TimerObjCmd:  timer stop leg_timer leg_outgoing 
    Feb 24 01:31:03.241: //19526//TCL :/tcl_TimerStopObjCmd:  stop leg_timer leg_outgoing 
    Feb 24 01:31:03.245: //19526//AFW_:/vtd_lg_outgoing: argc 3
    Feb 24 01:31:03.245: //19526//AFW_:/vtd_lg_outgoing: Legs [19529 ]
    Feb 24 01:31:03.245: //19526//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Feb 24 01:31:03.245: //19526//TCL :/tcl_InfotagObjCmd:  infotag get evt_legs 
    Feb 24 01:31:03.245: //19526//TCL :/tcl_InfotagGetObjCmd: infotag get evt_legs 
    Feb 24 01:31:03.245: //19526//AFW_:/vtr_ev_legs: argc 2
    Feb 24 01:31:03.245: //19526//AFW_:/vtr_ev_legs: EVCALLID [19529]
    Feb 24 01:31:03.249: //19526//TCL :/tcl_PutsObjCmd: 
     
       ******************** *hybrid* (act_HandleOutgoing) evt_legs: 19529 incoming: 19526
    Feb 24 01:31:03.249: 
    Feb 24 01:31:03.249: //19526//TCL :/tcl_PutsObjCmd: 
     
       ******************** *hybrid* (act_HandleOutgoing) Desconectando al outbound
     
     
    Feb 24 01:31:03.249: 
    Feb 24 01:31:03.249: //19526//TCL :/tcl_ConnectionObjCmd:  connection destroy con_all 
    Feb 24 01:31:03.249: //19526//TCL :/tcl_ConnectionDestroyObjCmd: destroy con_all 
    Feb 24 01:31:03.249: //19526//AFW_:/vtd_co_all: argc 2
    Feb 24 01:31:03.253: //19526//AFW_:/vtd_co_all: Connections [183 ]
    Feb 24 01:31:03.253: //19526//Tcl :/tcl_parseConnID_vartagObj: VARTAG Translation Connection Count=1
    Feb 24 01:31:03.253: //19526//TCL :/tcl_FSMObjCmd:  fsm setstate WEBQUERY 
    Feb 24 01:31:03.253: //19526//TCL :/tcl_FSMSetStateObjCmd: setstate setstate WEBQUERY 
    Feb 24 01:31:03.253: //19526//TCL :/tcl_LegObjCmd:  leg vxmldialog leg_incoming -u http://192.168.0.1:6590/vxmls/prompt_saldo.xml?ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx 
    Feb 24 01:31:03.257: //19526//TCL :/tcl_LegVxmlDialogObjCmd: vxmldialog leg_incoming -u http://192.168.0.1:6590/vxmls/prompt_saldo.xml?ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx 
    Feb 24 01:31:03.257: //19526//AFW_:/vtd_lg_incoming: argc 4
    Feb 24 01:31:03.257: //19526//AFW_:/vtd_lg_incoming: Legs [19526 ]
    Feb 24 01:31:03.257: //19526//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Feb 24 01:31:03.257: //19526//AFW_:/vapp_vxmldialog: Trusted=0, DNIS Map URI=http://192.168.0.1:6590/vxmls/prompt_saldo.xml?ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx, Code = {
     
    }
    Feb 24 01:31:03.257: //-1//AFW_:/AFW_VxmlModule_New:  
    Feb 24 01:31:03.257: //19526//AFW_:/vapp_internal_bgload: url=http://192.168.0.1:6590/vxmls/prompt_saldo.xml?ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx
    Feb 24 01:31:03.269: //19526//AFW_:/AFW_M_TclModule_Action:  
    Feb 24 01:31:03.269: //19526//AFW_:/AFW_TclModule_DefaultEvHandling:  
    Feb 24 01:31:03.269: //19526//AFW_:/AFW_FSM_Drive: FSM no match for (WEBQUERY[7],ev_destroy_done[35])
    Feb 24 01:31:03.518: //19526//HIFS:/hifs_http_cb: hifs http read succeeded. size=3198, url=http://192.168.0.1:6590/vxmls/prompt_saldo.xml?ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx
    Feb 24 01:31:03.518: //19526//AFW_:/vapp_internal_bgload_done: status=No Error
    Feb 24 01:31:03.518: //19526//HIFS:/hifs_http_cb: hifs ifs file read succeeded. size=3198, url=http://192.168.0.1:6590/vxmls/prompt_saldo.xml?ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx
    Feb 24 01:31:03.518: //19526//HIFS:/hifs_free_idata: hifs_free_idata: 0x84C11DA4
    Feb 24 01:31:03.518: //19526//HIFS:/hifs_hold_idata: hifs_hold_idata: 0x84C11DA4
    Feb 24 01:31:03.522: //19526//AFW_:/vapp_driver: evtID: 173 vapp record state: 0
    Feb 24 01:31:03.522: //19526//AFW_:/vapp_internal_bgload_done_event: 
    Feb 24 01:31:03.522: //19526//AFW_:/vapp_internal_bgload_done_event: length=3198, page loaded=
    <?xml version="1.0"?>
    <vxml version="2.0">
     
     
      <var name="primer_digito"/>
     
      <property name="interdigittimeout" value="4s"/> 
     
      <form id="asterisco">
     
         <block>
           <log expr="'\n\n\t\t*******
    Feb 24 01:31:03.526: //-1//VXML:/vxml_tree_lock:  
       vxmlp=84ABA320 usage_cnt=0
    Feb 24 01:31:03.538: //0//VXML:/vxml_parse:  
     
    Feb 24 01:31:03.538: vxml_parse: XML_Parse success err=0
    Feb 24 01:31:03.542: //0//VXML:/vxml_session_delete:  
     
    Feb 24 01:31:03.542: vxml_session_delete:mem_mgr_mempool_free: mempool=NULL
    Feb 24 01:31:03.542: vxml_session_delete:mem_mgr_mempool_free: mempool=NULL
    Feb 24 01:31:03.542: //-1//VXML:/vxml_create:  
       enter url=http://192.168.0.1:6590/vxmls/prompt_saldo.xml?ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx tree_handle=84ABA320
       return_handle_add=84D6F940
    Feb 24 01:31:03.626: //19526/D4145D45B9F2/VXML:/vxml_offramp_mailhdrs_get:  
     
    Feb 24 01:31:03.626: //19526//AFW_:/vapp_get_incoming_gtd_list: 
    Feb 24 01:31:03.626: //19526/D4145D45B9F2/VXML:/vxml_start:  
       vxmlhandle=84AFC060 vapphandle=851B45E8 status=0 async_status=0
    Feb 24 01:31:03.626: //19526/D4145D45B9F2/VXML:/vxml_vxml_proc:    
    <vxml> 
       URI(abs):http://192.168.0.1:6590/vxmls/prompt_saldo.xml?ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/vxmls/prompt_saldo.xml 
       query=ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx 
       base= 
       URI(abs):http://192.168.0.1:6590/vxmls/prompt_saldo.xml?ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/vxmls/prompt_saldo.xml 
       query=ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx lang=none version=2.0 
    <var>: namep=primer_digito
    Feb 24 01:31:03.630: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(var primer_digito)
    Feb 24 01:31:03.630: //19526/D4145D45B9F2/VXML:/vxml_form_proc: 
    Feb 24 01:31:03.634:  <form>: id=asterisco   scope=dialog 
    Feb 24 01:31:03.634: //19526/D4145D45B9F2/VXML:/vxml_form_init:  
       current scope: dialog 
       <var>: namep=ani expr='21400007'
    Feb 24 01:31:03.634: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(var ani='21400007') 
       <var>: namep=access_number expr='1800xxxxxxxxx'
    Feb 24 01:31:03.638: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(var access_number='1800xxxxxxxxx') 
       <var>: namep=call_guid expr='D4145D45.5DBD11E1.B9F29F32.7B7E1175'
    Feb 24 01:31:03.642: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(var call_guid='D4145D45.5DBD11E1.B9F29F32.7B7E1175') 
       vxml_counter_reset: 
       vxml_counter_reset:
    Feb 24 01:31:03.650: //19526/D4145D45B9F2/VXML:/vxml_formitem_select:  
       Status=VXML_STATUS_OK,
    Feb 24 01:31:03.650: //19526/D4145D45B9F2/VXML:/vxml_formitem_select:  
        AsyncStatus=VXML_STATUS_OK
    Feb 24 01:31:03.654: //19526/D4145D45B9F2/VXML:/vxml_block_proc: 
    Feb 24 01:31:03.654:   <block>:
    Feb 24 01:31:03.654: //19526/D4145D45B9F2/VXML:/vxml_item_attrs_proc:  
       name=_in850 
             <log>:
    Feb 24 01:31:03.658:  
     
      **********************  saldo_and_destination form id asterisco *
     
     
    Feb 24 01:31:03.658: //19526/D4145D45B9F2/VXML:/vxml_leave_scope:  
       scope=anonymous
    Feb 24 01:31:03.658: //19526/D4145D45B9F2/VXML:/vxml_formitem_select:  
       Status=VXML_STATUS_OK,
    Feb 24 01:31:03.658: //19526/D4145D45B9F2/VXML:/vxml_formitem_select:  
        AsyncStatus=VXML_STATUS_OK
    Feb 24 01:31:03.658: //19526/D4145D45B9F2/VXML:/vxml_field_proc: 
    Feb 24 01:31:03.658:   <field>: type=digits
    Feb 24 01:31:03.658: //19526/D4145D45B9F2/VXML:/vxml_item_attrs_proc:  
       name=teclazo modal=accept prompt_counter=1
    Feb 24 01:31:03.662: //19526/D4145D45B9F2/VXML:/vxml_prompt_proc_real:  
             <prompt>: alternative(arg)=0 bargein=0 count=1 typeaheadflush=0 alternative=0
    Feb 24 01:31:03.662: //19526/D4145D45B9F2/VXML:/vxml_audio_proc:  
             <audio>: 
       URI(abs):/audios/llamada-terminada.g729 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/audios/llamada-terminada.g729 caching=fast fetchhint=invalid fetchtimeout=0 maxage=-1 maxstale=-1
    Feb 24 01:31:03.662: //19526/D4145D45B9F2/VXML:/vxml_vapp_media_play:  
       bargein=0 timeout=0 typeaheadflush=0 vcr=0 rate=0
    Feb 24 01:31:03.662: //19526/D4145D45B9F2/VXML:/vxml_vapp_media_play:  
       str=http://192.168.0.1:6590/audios/llamada-terminada.g729 cachable=1 timeout0 maxage=-1 maxstale=-1
    Feb 24 01:31:03.662: //19526//AFW_:/vapp_media_play: 
    Feb 24 01:31:03.662: //19526//AFW_:/vapp_media_play: prompt=http://192.168.0.1:6590/audios/llamada-terminada.g729:
    Feb 24 01:31:03.666: //19526//PACK:/Media_Play_Start:  
    Feb 24 01:31:03.666: //19526/D4145D45B9F2/VXML:/vxml_prompt_proc_real:  
                <prompt>: alternative(arg)=0 bargein=1 count=1 typeaheadflush=0 alternative=0
    Feb 24 01:31:03.666: //19526/D4145D45B9F2/VXML:/vxml_audio_proc:  
                <audio>: 
       URI(abs):/audios/marque-el-numero-telefonico-al-que-desea-llamar.g729 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/audios/marque-el-numero-telefonico-al-que-desea-llamar.g729 caching=fast fetchhint=invalid fetchtimeout=0 maxage=-1 maxstale=-1
    Feb 24 01:31:03.666: //19526/D4145D45B9F2/VXML:/vxml_audio_proc:  
                <audio>: 
       URI(abs):/audios/o.g729 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/audios/o.g729 caching=fast fetchhint=invalid fetchtimeout=0 maxage=-1 maxstale=-1
    Feb 24 01:31:03.670: //19526/D4145D45B9F2/VXML:/vxml_audio_proc:  
                <audio>: 
       URI(abs):/audios/para-hacer-una-recarga-oprima.g729 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/audios/para-hacer-una-recarga-oprima.g729 caching=fast fetchhint=invalid fetchtimeout=0 maxage=-1 maxstale=-1
    Feb 24 01:31:03.670: //19526/D4145D45B9F2/VXML:/vxml_audio_proc:  
                <audio>: 
       URI(abs):/audios/asterisco.g729 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/audios/asterisco.g729 caching=fast fetchhint=invalid fetchtimeout=0 maxage=-1 maxstale=-1
    Feb 24 01:31:03.670: //19526/D4145D45B9F2/VXML:/vxml_load_immediate_done:  
       sidp->status=300000000
    Feb 24 01:31:03.674: //19526//AFW_:/vapp_checksessionstate: 
    Feb 24 01:31:03.674: //19526//AFW_:/vapp_checkifdone: Object: 1, Leg: 1
    Feb 24 01:31:03.770: //-1//PACK:/httpios_http_posthead_cb: 
    Feb 24 01:31:03.770: httpios_http_posthead_cb: status: 200
    Feb 24 01:31:03.774: //19526//AFW_:/AFW_M_TclModule_EventPreProcess:  
    Feb 24 01:31:03.774: //19526//PACK:/tclhttp_handle_httpcb_event: ret_status(0)
    Feb 24 01:31:03.778: //19526//PACK:/tclhttp_handle_httpcb_event: MODULE HANDLE: :: 0x00000000
    Feb 24 01:31:06.250: //19526//AFW_:/vapp_driver: evtID: 137 vapp record state: 0
    Feb 24 01:31:06.250: //19526//AFW_:/vapp_play_done: evID=137 reason=13, protocol=2, status_code=0, dur=1816, rate=0
    Feb 24 01:31:06.250: //19526/D4145D45B9F2/VXML:/vxml_media_done:  
       status 0 async_status 300000000 duration=1816 rate=0
    Feb 24 01:31:06.250: //19526/D4145D45B9F2/VXML:/vxml_save_lastprompt_info:  
     
    Feb 24 01:31:06.250: //19526/D4145D45B9F2/VXML:/vxml_save_lastprompt_info:  
     
    Feb 24 01:31:06.250: //19526/D4145D45B9F2/VXML:/vxml_vapp_typeahead_flush:  
     
    Feb 24 01:31:06.254: //19526//AFW_:/vapp_typeahead_flush: 
    Feb 24 01:31:06.254: //19526/D4145D45B9F2/VXML:/vxml_vapp_media_play:  
       bargein=1 timeout=0 typeaheadflush=0 vcr=0 rate=0
    Feb 24 01:31:06.254: //19526/D4145D45B9F2/VXML:/vxml_vapp_media_play:  
       str=http://192.168.0.1:6590/audios/marque-el-numero-telefonico-al-que-desea-llamar.g729 cachable=1 timeout0 maxage=-1 maxstale=-1
    Feb 24 01:31:06.254: //19526/D4145D45B9F2/VXML:/vxml_vapp_media_play:  
       str=http://192.168.0.1:6590/audios/o.g729 cachable=1 timeout0 maxage=-1 maxstale=-1
    Feb 24 01:31:06.254: //19526/D4145D45B9F2/VXML:/vxml_vapp_media_play:  
       str=http://192.168.0.1:6590/audios/para-hacer-una-recarga-oprima.g729 cachable=1 timeout0 maxage=-1 maxstale=-1
    Feb 24 01:31:06.254: //19526/D4145D45B9F2/VXML:/vxml_vapp_media_play:  
       str=http://192.168.0.1:6590/audios/asterisco.g729 cachable=1 timeout0 maxage=-1 maxstale=-1
    Feb 24 01:31:06.258: //19526//AFW_:/vapp_media_play: 
    Feb 24 01:31:06.258: //19526//AFW_:/vapp_media_play: prompt=http://192.168.0.1:6590/audios/marque-el-numero-telefonico-al-que-desea-llamar.g729:
    Feb 24 01:31:06.258: //19526//AFW_:/vapp_media_play: prompt=http://192.168.0.1:6590/audios/o.g729:
    Feb 24 01:31:06.258: //19526//AFW_:/vapp_media_play: prompt=http://192.168.0.1:6590/audios/para-hacer-una-recarga-oprima.g729:
    Feb 24 01:31:06.258: //19526//AFW_:/vapp_media_play: prompt=http://192.168.0.1:6590/audios/asterisco.g729:
    Feb 24 01:31:06.262: //19526//PACK:/Media_Play_Start:  
    Feb 24 01:31:06.262: //19526//AFW_:/vapp_checksessionstate: 
    Feb 24 01:31:06.262: //19526//AFW_:/vapp_checkifdone: Object: 1, Leg: 1
    Feb 24 01:31:12.200: //19526//AFW_:/vapp_driver: evtID: 137 vapp record state: 0
    Feb 24 01:31:12.200: //19526//AFW_:/vapp_play_done: evID=137 reason=7, protocol=2, status_code=0, dur=5908, rate=0
    Feb 24 01:31:12.200: //19526/D4145D45B9F2/VXML:/vxml_media_done:  
       status 18 async_status 300000000 duration=5908 rate=0
    Feb 24 01:31:12.200: //19526/D4145D45B9F2/VXML:/vxml_save_lastprompt_info:  
     
    Feb 24 01:31:12.200: //19526/D4145D45B9F2/VXML:/vxml_save_lastprompt_info:  
     
    Feb 24 01:31:12.200: //19526//AFW_:/vapp_notify_play_done: 
    Feb 24 01:31:12.200: //19526/D4145D45B9F2/VXML:/vxml_vapp_vcr_control_disable:  
     
    Feb 24 01:31:12.204: //19526/D4145D45B9F2/VXML:/vxml_vapp_digit_collect:  
       termchar # minlength 0 maxlength 0 timeout 10000 interdigittimeout 4000 numPatterns=1 abortKey 
    Feb 24 01:31:12.204: //19526//AFW_:/vapp_digit_collect: 
    Feb 24 01:31:12.204: //19526//AFW_:/vapp_digit_collect:  numPatterns 1, minlength 0, maxlength 0, timeout 10000, interDigitTimeout 4000
    Feb 24 01:31:12.204: //19526//AFW_:/vapp_checksessionstate: 
    Feb 24 01:31:12.204: //19526//AFW_:/vapp_checkifdone: Object: 2, Leg: 1
    Feb 24 01:31:12.208: //19526//AFW_:/vapp_driver: evtID: 163 vapp record state: 0
    Feb 24 01:31:12.208: //19526//AFW_:/vapp_digit_collection_done: 
    Feb 24 01:31:12.208: //19526//AFW_:/vapp_digit_collection_done: digits [0], status [0], pattern [v0]
    Feb 24 01:31:12.208: //19526/D4145D45B9F2/VXML:/vxml_digit_collection_done:  
       vxmlp 84ABA320 status 0 async_status 200020000
    Feb 24 01:31:12.208: //19526/D4145D45B9F2/VXML:/vxml_digit_collection_done:  
        digits (0)
    Feb 24 01:31:12.208: //19526/D4145D45B9F2/VXML:/vxml_digit_collection_done:  
        name (v0)
    Feb 24 01:31:12.208: //19526/D4145D45B9F2/VXML:/vxml_bind_lastprompt:  
     
    Feb 24 01:31:12.212: //19526/D4145D45B9F2/VXML:/vxml_digit_collect_process:  
       vxmlp 84ABA320 status 0 async_status 60000
    Feb 24 01:31:12.212: //19526/D4145D45B9F2/VXML:/vxml_start:  
       vxmlhandle=84AFC060 vapphandle=851B45E8 status=0 async_status=60000
    Feb 24 01:31:12.216: //19526/D4145D45B9F2/VXML:/vxml_vxml_proc:    
    <vxml> 
       URI(abs):http://192.168.0.1:6590/vxmls/prompt_saldo.xml?ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/vxmls/prompt_saldo.xml 
       query=ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx 
       base= 
       URI(abs):http://192.168.0.1:6590/vxmls/prompt_saldo.xml?ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/vxmls/prompt_saldo.xml 
       query=ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx lang=none version=2.0
    Feb 24 01:31:12.216: //19526/D4145D45B9F2/VXML:/vxml_field_proc: 
    Feb 24 01:31:12.216:   <field>: type=digits
    Feb 24 01:31:12.220: //19526/D4145D45B9F2/VXML:/vxml_item_attrs_proc:  
       name=teclazo modal=accept prompt_counter=2
    Feb 24 01:31:12.220: //19526/D4145D45B9F2/VXML:/vxml_filled_proc:  
     
    Feb 24 01:31:12.220: <filled>: mode=all
    Feb 24 01:31:12.220: //19526/D4145D45B9F2/VXML:/vxml_if_proc:  
             <if>: cond=teclazo=='*'
    Feb 24 01:31:12.228: //19526/D4145D45B9F2/VXML:/vxml_assign_proc:  
                <assign>: name=primer_digito expr=teclazo 
    Feb 24 01:31:12.228: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(primer_digito=teclazo)
    Feb 24 01:31:12.232: //19526/D4145D45B9F2/VXML:/vxml_goto_proc:  
                <goto>: caching=fast fetchhint=invalid fetchtimeout=0 maxage=-1 maxstale=-1 
       URI kiss main 
       fragmentp=main 
                vxml_dialog_reset:
    Feb 24 01:31:12.232: //19526/D4145D45B9F2/VXML:/vxml_leave_scope:  
       scope=dialog
    Feb 24 01:31:12.236: //19526/D4145D45B9F2/VXML:/vxml_leave_scope:  
       scope=anonymous
    Feb 24 01:31:12.236: //19526/D4145D45B9F2/VXML:/vxml_load_immediate_done:  
       sidp->status=400
    Feb 24 01:31:12.236: //19526/D4145D45B9F2/VXML:/vxml_vxml_proc:    
    <vxml> 
       URI(abs):http://192.168.0.1:6590/vxmls/prompt_saldo.xml?ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/vxmls/prompt_saldo.xml 
       query=ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx 
       base= 
       URI(abs):http://192.168.0.1:6590/vxmls/prompt_saldo.xml?ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/vxmls/prompt_saldo.xml 
       query=ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx lang=none version=2.0
    Feb 24 01:31:12.236: //19526/D4145D45B9F2/VXML:/vxml_form_proc: 
    Feb 24 01:31:12.236:  <form>: id=main   scope=dialog 
    Feb 24 01:31:12.236: //19526/D4145D45B9F2/VXML:/vxml_form_init:  
       current scope: dialog 
       <var>: namep=id expr='40'
    Feb 24 01:31:12.240: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(var id='40') 
       <var>: namep=ani expr='21400007'
    Feb 24 01:31:12.244: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(var ani='21400007') 
       <var>: namep=access_number expr='1800xxxxxxxxx'
    Feb 24 01:31:12.244: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(var access_number='1800xxxxxxxxx') 
       <var>: namep=call_guid expr='D4145D45.5DBD11E1.B9F29F32.7B7E1175'
    Feb 24 01:31:12.248: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(var call_guid='D4145D45.5DBD11E1.B9F29F32.7B7E1175') 
       <var>: namep=destination
    Feb 24 01:31:12.252: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(var destination) 
       vxml_counter_reset: 
       vxml_counter_reset:
    Feb 24 01:31:12.260: //19526/D4145D45B9F2/VXML:/vxml_formitem_select:  
       Status=VXML_STATUS_OK,
    Feb 24 01:31:12.260: //19526/D4145D45B9F2/VXML:/vxml_formitem_select:  
        AsyncStatus=VXML_STATUS_OK
    Feb 24 01:31:12.260: //19526/D4145D45B9F2/VXML:/vxml_block_proc: 
    Feb 24 01:31:12.260:   <block>:
    Feb 24 01:31:12.260: //19526/D4145D45B9F2/VXML:/vxml_item_attrs_proc:  
       name=_in851 
             <log>:
    Feb 24 01:31:12.264:  
     
      **********************  saldo_and_destination form id main *
     
     
    Feb 24 01:31:12.264: //19526/D4145D45B9F2/VXML:/vxml_leave_scope:  
       scope=anonymous
    Feb 24 01:31:12.264: //19526/D4145D45B9F2/VXML:/vxml_formitem_select:  
       Status=VXML_STATUS_OK,
    Feb 24 01:31:12.264: //19526/D4145D45B9F2/VXML:/vxml_formitem_select:  
        AsyncStatus=VXML_STATUS_OK
    Feb 24 01:31:12.268: //19526/D4145D45B9F2/VXML:/vxml_field_proc: 
    Feb 24 01:31:12.268:   <field>: type=digits
    Feb 24 01:31:12.268: //19526/D4145D45B9F2/VXML:/vxml_item_attrs_proc:  
       name=destination_temp modal=accept prompt_counter=1
    Feb 24 01:31:12.268: //19526/D4145D45B9F2/VXML:/vxml_vapp_digit_collect:  
       termchar # minlength 0 maxlength 0 timeout 10000 interdigittimeout 4000 numPatterns=1 abortKey 
    Feb 24 01:31:12.268: //19526//AFW_:/vapp_digit_collect: 
    Feb 24 01:31:12.268: //19526//AFW_:/vapp_digit_collect:  numPatterns 1, minlength 0, maxlength 0, timeout 10000, interDigitTimeout 4000
    Feb 24 01:31:12.268: //19526/D4145D45B9F2/VXML:/vxml_load_immediate_done:  
       sidp->status=200000000
    Feb 24 01:31:12.272: //19526//AFW_:/vapp_checksessionstate: 
    Feb 24 01:31:12.272: //19526//AFW_:/vapp_checkifdone: Object: 2, Leg: 1
    Feb 24 01:31:19.969: //19526//AFW_:/vapp_driver: evtID: 163 vapp record state: 0
    Feb 24 01:31:19.969: //19526//AFW_:/vapp_digit_collection_done: 
    Feb 24 01:31:19.969: //19526//AFW_:/vapp_digit_collection_done: digits [11528112341234], status [0], pattern [v0]
    Feb 24 01:31:19.969: //19526/D4145D45B9F2/VXML:/vxml_digit_collection_done:  
       vxmlp 84ABA320 status 0 async_status 200000000
    Feb 24 01:31:19.969: //19526/D4145D45B9F2/VXML:/vxml_digit_collection_done:  
        digits (11528112341234)
    Feb 24 01:31:19.969: //19526/D4145D45B9F2/VXML:/vxml_digit_collection_done:  
        name (v0)
    Feb 24 01:31:19.973: //19526/D4145D45B9F2/VXML:/vxml_bind_lastprompt:  
     
    Feb 24 01:31:19.973: //19526/D4145D45B9F2/VXML:/vxml_digit_collect_process:  
       vxmlp 84ABA320 status 0 async_status 40000
    Feb 24 01:31:19.973: //19526/D4145D45B9F2/VXML:/vxml_start:  
       vxmlhandle=84AFC060 vapphandle=851B45E8 status=0 async_status=40000
    Feb 24 01:31:19.977: //19526/D4145D45B9F2/VXML:/vxml_vxml_proc:    
    <vxml> 
       URI(abs):http://192.168.0.1:6590/vxmls/prompt_saldo.xml?ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/vxmls/prompt_saldo.xml 
       query=ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx 
       base= 
       URI(abs):http://192.168.0.1:6590/vxmls/prompt_saldo.xml?ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/vxmls/prompt_saldo.xml 
       query=ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx lang=none version=2.0
    Feb 24 01:31:19.977: //19526/D4145D45B9F2/VXML:/vxml_field_proc: 
    Feb 24 01:31:19.981:   <field>: type=digits
    Feb 24 01:31:19.981: //19526/D4145D45B9F2/VXML:/vxml_item_attrs_proc:  
       name=destination_temp modal=accept prompt_counter=2
    Feb 24 01:31:19.981: //19526/D4145D45B9F2/VXML:/vxml_filled_proc:  
     
    Feb 24 01:31:19.981: <filled>: mode=all
    Feb 24 01:31:19.981: //19526/D4145D45B9F2/VXML:/vxml_assign_proc:  
             <assign>: name=destination expr=primer_digito + destination_temp 
    Feb 24 01:31:19.985: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(destination=primer_digito + destination_temp)
    Feb 24 01:31:19.989: //19526/D4145D45B9F2/VXML:/vxml_submit_proc:  
             <submit>: caching=fast fetchhint=invalid fetchtimeout=0 maxage=-1 maxstale=-1 
       URI(abs):/vxmls/check_rate.xml 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/vxmls/check_rate.xml
    Feb 24 01:31:19.989: //19526/D4145D45B9F2/VXML:/vxml_sub_attrs_proc:  
       method=get 
       enctype=application/x-www-form-urlencoded
    Feb 24 01:31:19.989: //19526/D4145D45B9F2/VXML:/vxml_nmtokens_proc:  
       name=destination 
       name=ani 
       name=call_guid 
       name=access_number 
       name=id 
       name=primer_digito
    Feb 24 01:31:19.993: //19526/D4145D45B9F2/VXML:/vxml_vapp_bgload_from_proc:  
       urlp=http://192.168.0.1:6590/vxmls/check_rate.xml?destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0
    Feb 24 01:31:19.993: //19526/D4145D45B9F2/VXML:/vxml_vapp_bgload:  
       url http://192.168.0.1:6590/vxmls/check_rate.xml?destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0 cachable 1 fetchtimeout 0 maxage=-1 maxstale=-1
    Feb 24 01:31:19.997: //19526//AFW_:/vapp_bgload: url=http://192.168.0.1:6590/vxmls/check_rate.xml?destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0
    Feb 24 01:31:19.997: //19526//AFW_:/vxml_update_cleanup_timer: cleaning timer running 0 fetchtimeout 0
    Feb 24 01:31:19.997: //19526/D4145D45B9F2/VXML:/vxml_leave_scope:  
       scope=anonymous
    Feb 24 01:31:19.997: //19526/D4145D45B9F2/VXML:/vxml_load_immediate_done:  
       sidp->status=400000000
    Feb 24 01:31:19.997: //19526//AFW_:/vapp_checksessionstate: 
    Feb 24 01:31:19.997: //19526//AFW_:/vapp_checkifdone: Object: 1, Leg: 1
    Feb 24 01:31:21.171: //19526//HIFS:/hifs_http_cb: hifs http read succeeded. size=637, url=http://192.168.0.1:6590/vxmls/check_rate.xml?destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0
    Feb 24 01:31:21.171: //19526//AFW_:/vapp_bgload_done: status=No Error
    Feb 24 01:31:21.171: //19526//HIFS:/hifs_http_cb: hifs ifs file read succeeded. size=637, url=http://192.168.0.1:6590/vxmls/check_rate.xml?destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0
    Feb 24 01:31:21.171: //19526//HIFS:/hifs_free_idata: hifs_free_idata: 0x84C08AD4
    Feb 24 01:31:21.171: //19526//HIFS:/hifs_hold_idata: hifs_hold_idata: 0x84C08AD4
    Feb 24 01:31:21.175: //19526//AFW_:/vapp_driver: evtID: 173 vapp record state: 0
    Feb 24 01:31:21.175: //19526//AFW_:/vapp_bgload_done_event: 
    Feb 24 01:31:21.175: //19526//AFW_:/vapp_bgload_done_event: length=637, page loaded=
    <?xml version="1.0"?>
    <vxml version="2.0">
      <form id="rate">
     
     
        <block> 
          <var name="destination" expr="'12341234'" />
          <var name="seconds_available" expr="'300'" />
          <var na
    Feb 24 01:31:21.179: //19526/D4145D45B9F2/VXML:/vxml_is_doc:  
       vxml_is_doc
     
    Feb 24 01:31:21.179: //-1//VXML:/vxml_tree_lock:  
       vxmlp=84A8665C usage_cnt=0
    Feb 24 01:31:21.183: //0//VXML:/vxml_parse:  
     
    Feb 24 01:31:21.183: vxml_parse: XML_Parse success err=0
    Feb 24 01:31:21.183: //0//VXML:/vxml_session_delete:  
     
    Feb 24 01:31:21.183: vxml_session_delete:mem_mgr_mempool_free: mempool=NULL
    Feb 24 01:31:21.183: vxml_session_delete:mem_mgr_mempool_free: mempool=NULL
    Feb 24 01:31:21.187: //19526/D4145D45B9F2/VXML:/vxml_bgload_post_done:  
       vxmlhandle=84AFC060 status=0 async_status=400000000
    Feb 24 01:31:21.187: //19526/D4145D45B9F2/VXML:/vxml_bgload_post_done:  
       Loading file with url (http://192.168.0.1:6590/vxmls/check_rate.xml?destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0)
    Feb 24 01:31:21.187: //19526/D4145D45B9F2/VXML:/vxml_leave_scope:  
       scope=application
    Feb 24 01:31:21.191: //19526/D4145D45B9F2/VXML:/vxml_tree_delete:  
       vxmlp=84ABA320, usage_cnt=1 url=http://192.168.0.1:6590/vxmls/prompt_saldo.xml?ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx
    Feb 24 01:31:21.191: vxml_tree_delete:mem_mgr_mempool_free: mem_refcnt(84B10DC8)=0 - mempool cleanup
    Feb 24 01:31:21.191: //19526/D4145D45B9F2/VXML:/vxml_stop_fetchaudio:  
     
    Feb 24 01:31:21.191: //19526/D4145D45B9F2/VXML:/vxml_start:  
       vxmlhandle=84AFC060 vapphandle=851B45E8 status=0 async_status=80000
    Feb 24 01:31:21.191: //19526/D4145D45B9F2/VXML:/vxml_vxml_proc:    
    <vxml> 
       URI(abs):http://192.168.0.1:6590/vxmls/check_rate.xml?destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/vxmls/check_rate.xml 
       query=destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0 
       base= 
       URI(abs):http://192.168.0.1:6590/vxmls/check_rate.xml?destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/vxmls/check_rate.xml 
       query=destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0 lang=none version=2.0
    Feb 24 01:31:21.195: //19526/D4145D45B9F2/VXML:/vxml_form_proc: 
    Feb 24 01:31:21.195:  <form>: id=rate   scope=dialog 
    Feb 24 01:31:21.195: //19526/D4145D45B9F2/VXML:/vxml_form_init:  
       current scope: dialog 
       vxml_counter_reset:
    Feb 24 01:31:21.203: //19526/D4145D45B9F2/VXML:/vxml_formitem_select:  
       Status=VXML_STATUS_OK,
    Feb 24 01:31:21.203: //19526/D4145D45B9F2/VXML:/vxml_formitem_select:  
        AsyncStatus=VXML_STATUS_OK
    Feb 24 01:31:21.203: //19526/D4145D45B9F2/VXML:/vxml_block_proc: 
    Feb 24 01:31:21.203:   <block>:
    Feb 24 01:31:21.203: //19526/D4145D45B9F2/VXML:/vxml_item_attrs_proc:  
       name=_in852 
             <var>: namep=destination expr='12341234'
    Feb 24 01:31:21.207: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(var destination='12341234') 
             <var>: namep=seconds_available expr='300'
    Feb 24 01:31:21.207: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(var seconds_available='300') 
             <var>: namep=account_id expr='40'
    Feb 24 01:31:21.211: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(var account_id='40') 
             <var>: namep=usage_token expr='D4145D45.5DBD11E1.B9F29F32.7B7E1175'
    Feb 24 01:31:21.215: //19526/D4145D45B9F2/VXML:/vxml_expr_eval:  
       expr=(var usage_token='D4145D45.5DBD11E1.B9F29F32.7B7E1175')
    Feb 24 01:31:21.219: //19526/D4145D45B9F2/VXML:/vxml_prompt_proc_real:  
             <prompt>: alternative(arg)=0 bargein=0 count=1 typeaheadflush=0 alternative=0
    Feb 24 01:31:21.219: //19526/D4145D45B9F2/VXML:/vxml_audio_proc:  
             <audio>: 
       URI(abs):/audios/usted-tiene.g729 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/audios/usted-tiene.g729 caching=fast fetchhint=invalid fetchtimeout=0 maxage=-1 maxstale=-1
    Feb 24 01:31:21.219: //19526/D4145D45B9F2/VXML:/vxml_audio_proc:  
             <audio>: 
       URI(abs):/audios/digits/5.g729 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/audios/digits/5.g729 caching=fast fetchhint=invalid fetchtimeout=0 maxage=-1 maxstale=-1
    Feb 24 01:31:21.223: //19526/D4145D45B9F2/VXML:/vxml_audio_proc:  
             <audio>: 
       URI(abs):/audios/minutos.g729 
       scheme=http 
       host=192.168.0.1 
       port=6590 
       path=/audios/minutos.g729 caching=fast fetchhint=invalid fetchtimeout=0 maxage=-1 maxstale=-1
    Feb 24 01:31:21.223: //19526/D4145D45B9F2/VXML:/vxml_vapp_media_play:  
       bargein=0 timeout=0 typeaheadflush=0 vcr=0 rate=0
    Feb 24 01:31:21.223: //19526/D4145D45B9F2/VXML:/vxml_vapp_media_play:  
       str=http://192.168.0.1:6590/audios/usted-tiene.g729 cachable=1 timeout0 maxage=-1 maxstale=-1
    Feb 24 01:31:21.223: //19526/D4145D45B9F2/VXML:/vxml_vapp_media_play:  
       str=http://192.168.0.1:6590/audios/digits/5.g729 cachable=1 timeout0 maxage=-1 maxstale=-1
    Feb 24 01:31:21.223: //19526/D4145D45B9F2/VXML:/vxml_vapp_media_play:  
       str=http://192.168.0.1:6590/audios/minutos.g729 cachable=1 timeout0 maxage=-1 maxstale=-1
    Feb 24 01:31:21.227: //19526//AFW_:/vapp_media_play: 
    Feb 24 01:31:21.227: //19526//AFW_:/vapp_media_play: prompt=http://192.168.0.1:6590/audios/usted-tiene.g729:
    Feb 24 01:31:21.227: //19526//AFW_:/vapp_media_play: prompt=http://192.168.0.1:6590/audios/digits/5.g729:
    Feb 24 01:31:21.227: //19526//AFW_:/vapp_media_play: prompt=http://192.168.0.1:6590/audios/minutos.g729:
    Feb 24 01:31:21.231: //19526//PACK:/Media_Play_Start:  
    Feb 24 01:31:21.231: //19526/D4145D45B9F2/VXML:/vxml_exit_proc:  
             <exit>:
    Feb 24 01:31:21.231: //19526/D4145D45B9F2/VXML:/vxml_nmtokens_proc:  
       name=destination 
       name=seconds_available 
       name=account_id 
       name=usage_token
    Feb 24 01:31:21.239: //19526/D4145D45B9F2/VXML:/vxml_leave_scope:  
       scope=anonymous
    Feb 24 01:31:21.243: //19526/D4145D45B9F2/VXML:/vxml_load_immediate_done:  
       sidp->status=10
    Feb 24 01:31:21.243: //19526/D4145D45B9F2/VXML:/vxml_throw_error_session_event:  
       async_status=10 
    Feb 24 01:31:21.243: //19526//AFW_:/vapp_checksessionstate: 
    Feb 24 01:31:21.243: //19526//AFW_:/vapp_checkifdone: Object: 1, Leg: 1
    Feb 24 01:31:25.638: //19526//AFW_:/vapp_driver: evtID: 137 vapp record state: 0
    Feb 24 01:31:25.638: //19526//AFW_:/vapp_play_done: evID=137 reason=13, protocol=2, status_code=0, dur=3248, rate=0
    Feb 24 01:31:25.638: //19526/D4145D45B9F2/VXML:/vxml_media_done:  
       status 0 async_status 10 duration=3248 rate=0
    Feb 24 01:31:25.638: //19526/D4145D45B9F2/VXML:/vxml_save_lastprompt_info:  
     
    Feb 24 01:31:25.638: //19526/D4145D45B9F2/VXML:/vxml_save_lastprompt_info:  
     
    Feb 24 01:31:25.642: //19526/D4145D45B9F2/VXML:/vxml_vapp_typeahead_flush:  
     
    Feb 24 01:31:25.642: //19526//AFW_:/vapp_typeahead_flush: 
    Feb 24 01:31:25.642: //19526//AFW_:/vapp_notify_play_done: 
    Feb 24 01:31:25.642: //19526/D4145D45B9F2/VXML:/vxml_vapp_vcr_control_disable:  
     
    Feb 24 01:31:25.642: //19526/D4145D45B9F2/VXML:/vxml_throw_error_session_event:  
       async_status=20010 
    Feb 24 01:31:25.642: //19526/D4145D45B9F2/VXML:/vxml_vapp_terminate:  
       vapp_status=0 ref_count 0
    Feb 24 01:31:25.642: //19526/D4145D45B9F2/VXML:/vxml_vapp_terminate:  
        exitstr=destination=12341234,seconds_available=300,account_id=40,usage_token=D4145D45.5DBD11E1.B9F29F32.7B7E1175
    Feb 24 01:31:25.642: //19526//AFW_:/vapp_terminate: 
    Feb 24 01:31:25.642: //19526//AFW_:/vapp_session_exit_event_name: Exit Event vxml.session.complete
    Feb 24 01:31:25.646: //19526//AFW_:/AFW_M_VxmlModule_Terminate: 
    Feb 24 01:31:25.646: //19526//AFW_:/vapp_checksessionstate: 
    Feb 24 01:31:25.646: //19526//AFW_:/vapp_checkifdone: Object: 1, Leg: 1
    Feb 24 01:31:25.658: //19526/D4145D45B9F2/VXML:/vxml_tree_delete:  
       vxmlp=84A8665C, usage_cnt=1 url=http://192.168.0.1:6590/vxmls/check_rate.xml?destination=12341234&ani=21400007&call_guid=D4145D45.5DBD11E1.B9F29F32.7B7E1175&access_number=1800xxxxxxxxx&id=40&primer_digito=0
    Feb 24 01:31:25.658: vxml_tree_delete:mem_mgr_mempool_free: mem_refcnt(84A97724)=0 - mempool cleanup
    Feb 24 01:31:25.658: //19526/D4145D45B9F2/VXML:/vxml_session_delete:  
     
    Feb 24 01:31:25.658: vxml_session_delete:mem_mgr_mempool_free: mem_refcnt(8483521C)=0 - mempool cleanup
    Feb 24 01:31:25.658: vxml_session_delete:mem_mgr_mempool_free: mempool=NULL
    Feb 24 01:31:25.662: //19526//AFW_:/vapp_checksessionstate: 
    Feb 24 01:31:25.662: //19526//AFW_:/vapp_checkifdone: Object: 0, Leg: 0
    Feb 24 01:31:25.662: //19526//AFW_:/AFW_M_TclModule_Action:  
    Feb 24 01:31:25.662: //19526//AFW_:/AFW_TclModule_DefaultEvHandling:  
    Feb 24 01:31:25.662: //19526//PACK:/tclrecord_create_record_token_url:  
    Feb 24 01:31:25.666: //19526//TCL :/tcl_InfotagObjCmd:  infotag get evt_vxmlevent 
    Feb 24 01:31:25.666: //19526//TCL :/tcl_InfotagGetObjCmd: infotag get evt_vxmlevent 
    Feb 24 01:31:25.666: //19526//AFW_:/vtr_ev_vxmlevent: 
    Feb 24 01:31:25.666: //19526//TCL :/tcl_InfotagObjCmd:  infotag get evt_status 
    Feb 24 01:31:25.666: //19526//TCL :/tcl_InfotagGetObjCmd: infotag get evt_status 
    Feb 24 01:31:25.666: //19526//AFW_:/vtr_ev_status: argc 2 argindex 2
    Feb 24 01:31:25.670: //19526//TCL :/tcl_InfotagObjCmd:  infotag get evt_vxmlevent_params transfer_param 
    Feb 24 01:31:25.670: //19526//TCL :/tcl_InfotagGetObjCmd: infotag get evt_vxmlevent_params transfer_param 
    Feb 24 01:31:25.670: //19526//AFW_:/vtr_ev_vxmlevent_params: 
    Feb 24 01:31:25.670: //19526//TCL :/tcl_PutsObjCmd: 
     
       **** *hybrid*  marcando al 12341234 tiempo disponible en segundos: 300 account_id: 40 usage_token D4145D45.5DBD11E1.B9F29F32.7B7E1175  
     
     
    Feb 24 01:31:25.670: 
    Feb 24 01:31:25.674: //19526//TCL :/tcl_LegObjCmd:  leg setup 12341234 callInfo leg_incoming 
    Feb 24 01:31:25.674: //19526//AFW_:/vtd_lg_incoming: argc 4
    Feb 24 01:31:25.674: //19526//AFW_:/vtd_lg_incoming: Legs [19526 ]
    Feb 24 01:31:25.674: //19526//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=1
    Feb 24 01:31:25.682: //-1//AFW_:HN29BF8476:/AFW_M_VxmlModule_Free: 
    Feb 24 01:31:25.682: MOD[VxmlModule_851B45E8_13_700417142] ( )
    Feb 24 01:31:25.682: //19526//AFW_:/AFW_M_TclModule_Action:  
    Feb 24 01:31:25.682: //19526//AFW_:/AFW_TclModule_DefaultEvHandling:  
    Feb 24 01:31:32.017: //19526//AFW_:/AFW_M_TclModule_Action:  
    Feb 24 01:31:32.017: //19526//AFW_:/AFW_TclModule_DefaultEvHandling:  
    Feb 24 01:31:32.017: //19526//AFW_:/AFW_TclModule_UpdateSessionMask: Update intwrk-mask for leg [19530]'s session
    Feb 24 01:31:32.021: //19526//AFW_:/AFW_TclModule_UpdateSessionMask: Update intwrk-mask for leg [19529]'s session
    Feb 24 01:31:32.021: //19526//AFW_:/AFW_TclModule_UpdateSessionMask: Update intwrk-mask for leg [19526]'s session
    Feb 24 01:31:32.021: //19526//TCL :/tcl_InfotagObjCmd:  infotag get evt_status 
    Feb 24 01:31:32.021: //19526//TCL :/tcl_InfotagGetObjCmd: infotag get evt_status 
    Feb 24 01:31:32.021: //19526//AFW_:/vtr_ev_status: argc 2 argindex 2
    Feb 24 01:31:32.025: //19526//TCL :/tcl_PutsObjCmd: 
     
       ******************** *hybrid* Status of leg setup is ls_000 
     
     
    Feb 24 01:31:32.025: 
    Feb 24 01:31:32.025: //19526//TCL :/tcl_TimerObjCmd:  timer start leg_timer 299 leg_outgoing 
    Feb 24 01:31:32.025: //19526//TCL :/tcl_TimerStartObjCmd: timer start leg_timer 299 leg_outgoing 
    Feb 24 01:31:32.025: //19526//AFW_:/vtd_lg_outgoing: argc 4
    Feb 24 01:31:32.025: //19526//AFW_:/vtd_lg_outgoing: Legs [19530 19529 ]
    Feb 24 01:31:32.029: //19526//Tcl :/tcl_parseCallID_vartagObj: VARTAG Translation Leg Count=2
    Feb 24 01:31:32.029: //19526//TCL :/tcl_PutsObjCmd: 
     
       ******************** *hybrid* Call status is ls_000, call active 
     
     
    Feb 24 01:31:32.029: 
    Feb 24 01:33:03.228: //19526//AFW_:/AFW_M_TclModule_Action:  
    Feb 24 01:33:03.228: //19526//AFW_:/AFW_TclModule_DefaultEvHandling:  
    Feb 24 01:33:03.228: //19526//AFW_:/AFW_FSM_Drive: FSM no match for (CALLACTIVE[4],UnknownEvent[62])
    Feb 24 01:33:03.228: //19526//SERV:/AFW_Service_Process_Space:  Ill behaved Service script is being closed
    Feb 24 01:33:03.228: //-1//AFW_:/AFW_ExecEnv_CallClose:  Exec Env state: 1
    Feb 24 01:33:03.228: //-1//AFW_:/AFW_ExecEnv_CallClose:  Terminating ExecEnv's root module
    Feb 24 01:33:03.228: //19526//AFW_:/AFW_M_TclModule_Terminate:  Module is in the state: ACTIVE
    Feb 24 01:33:03.232: //19526//AFW_:/AFW_M_TclModule_Action:  
    Feb 24 01:33:03.232: //19526//AFW_:/AFW_M_TclModule_Action: Module is Terminating
    Feb 24 01:33:03.232: //19526//AFW_:/AFW_TclModule_Cleaner: lastFailureCause 0
    Feb 24 01:33:03.232: //19526//AFW_:/AFW_TclModule_Cleaner: lastFailureCause 0
    Feb 24 01:33:03.232: //19526//AFW_:/AFW_TclModule_Cleaner: lastFailureCause 0
    Feb 24 01:33:03.236: //19526//AFW_:/AFW_M_TclModule_Action:  
    Feb 24 01:33:03.236: //19526//AFW_:/AFW_M_TclModule_Action: Module is Terminating
    Feb 24 01:33:03.268: //19526//AFW_:/AFW_M_TclModule_Action:  
    Feb 24 01:33:03.268: //19526//AFW_:/AFW_M_TclModule_Action: Module is Terminating
    Feb 24 01:33:03.332: //19526//AFW_:/AFW_M_TclModule_Action:  
    Feb 24 01:33:03.332: //19526//AFW_:/AFW_M_TclModule_Action: Module is Terminating
    Feb 24 01:33:03.340: //19526//AFW_:/AFW_M_TclModule_Action:  
    Feb 24 01:33:03.340: //19526//AFW_:/AFW_M_TclModule_Action: Module is Terminating
    Feb 24 01:33:03.344: //19526//AFW_:/AFW_TclModule_ReturnIfDone:  Sending Out APP_EV_TCLMODULE_DONE event
    Feb 24 01:33:03.344: //-1//AFW_:/AFW_ExecEnv_CallClose:  Exec Env state: 3
    Feb 24 01:33:03.344: //19526//AFW_:/AFW_M_TclModule_EventPreProcess:  
    Feb 24 01:33:03.344: //-1//SERV:/AFW_Service_ReleaseExecEnv: Script Name = hybrid cache = true calls = 0
    Feb 24 01:33:03.348: //-1//SCRI:/cam_sa_stopped: Instance: [] ExecEnv: 0x8431AD40

     
     

    Subject: RE: Script failing because of UnknownEvent
    Replied by: Raghavendra Gutty Veeranagappa on 27-02-2012 09:14:41 AM
    Hi Adolfo,

    i think there are two outgoing leg id's passed to the leg_timer, please try to pass one leg id to the timer.

    Feb 24 01:31:32.025: //19526//TCL :/tcl_TimerObjCmd:  timer start leg_timer 299 leg_outgoing
    Feb 24 01:31:32.025: //19526//TCL :/tcl_TimerStartObjCmd: timer start leg_timer 299 leg_outgoing
    Feb 24 01:31:32.025: //19526//AFW_:/vtd_lg_outgoing: argc 4
    Feb 24 01:31:32.025: //19526//AFW_:/vtd_lg_outgoing: Legs [19530 19529 ]

    Thanks,
    Raghavendra

    Subject: RE: Script failing because of UnknownEvent
    Replied by: Adolfo Arizpe on 27-02-2012 11:16:06 AM
    Hi Raghavendra,

    thanks for your answer. Yesterday I noticed that same thing you saw, but being a novice with all this, I wasn't sure this was the cause.

    I decided to try to fix those two outgoing legs and what I did was that in the place where the outgoing call is disconnected I used to have this:

            connection destroy con_all

    but now I have this:

            timer stop leg_timer leg_outgoing
            connection destroy con_all
            leg disconnect leg_outgoing


    The code I was using is based on a Cisco sample that is in the manual, and that code wasn't calling leg disconnect. I suspect that adding that piece of code is what fixed it for me.


    Your suggestion makes me thing that is the case.

    Thank you for your time and your help