iTime Report post Posted 10/21/2015 10:18 PM Hi I have applied the latest patch of VG but could not test the described symptom: when I called in for overall testing, VG failed from the first script. Could you take a look at the log and let me know what was wrong? The script works fine with the previous version I used. Thanks. VGError_AfterUpgrade.zip Share this post Link to post
SupportTeam Report post Posted 10/21/2015 10:43 PM Looks like there is some issue with module [CheckTaskType] - which is a 'Run VBScript' module. Looks like the VBScript in that module completed without calling Run_ResultReturn etc. and the Fail path was not set, so system hung up the call. 143613.761 9 3 1 state [CheckTaskType] RunScript, wait=1, onhold= 143613.770 9 3 1 rv replace start (strlen>500) 143613.776 9 rv dbg rv_retrieve did not find [UserID] ( 55 73 65 72 49 44) 143613.777 9 rv dbg rv_retrieve did not find [AutoNotifyCallID] ( 41 75 74 6f 4e 6f 74 69 66 79 43 61 6c 6c 49 44) 143613.777 9 rv dbg rv_retrieve did not find [AutoNotifyMoveNotificationCallID] ( 41 75 74 6f 4e 6f 74 69 66 79 4d 6f 76 65 4e 6f 74 69 66 69 63 61 74 69 6f 6e 43 61 6c 6c 49 44) 143613.777 9 rv dbg rv_retrieve did not find [IsHiring] ( 49 73 48 69 72 69 6e 67) 143613.777 9 rv dbg rv_retrieve did not find [IsBroadcasting] ( 49 73 42 72 6f 61 64 63 61 73 74 69 6e 67) 143613.778 9 3 1 saving script strIni_moduleRunScript_SaveToFile=True 143613.783 9 3 1 script written to (new file): C:\Program Files (x86)\VoiceGuide\temp\vbs_3_1.vbs 143613.783 9 3 1 runscr waiting. wait=1 143613.785 9 3 1 moh file not specified 143613.785 9 3 1 runscr call ClearScript Execute 143613.785 9 3 1 runscr new VBScriptEngine call 143613.832 9 3 1 runscr .Execute call 143613.848 16 rem remoting link constructor activated: vgServices_CommandLink 143613.851 16 3 1 rem RvSet IsMoveAutoNotify, false 143613.852 16 3 1 rv add IsMoveAutoNotify|false 143613.854 16 3 1 rem RvSet TTSSpeed, 143613.854 16 3 1 rv add TTSSpeed| 143613.855 9 3 1 engineVbs dispose call 143613.857 9 3 1 runscr .Execute returned. iRunWait=1 143613.857 9 3 1 runscr RunWait_1 script completed 143613.857 9 3 1 runscr sModuleClearScriptProcessWasCalledFrom is current module CheckTaskType, clearing setting 143613.857 9 3 1 runscr RunWait_1 taking fail path as script completed and no next module set 143613.863 9 3 1 HangupCall (RunModule_Script_AfterScriptStarted_1) crn_in=0, L1=Connected, L2=Running_Normal, lPlayId=0, lRecId=0 Share this post Link to post
iTime Report post Posted 10/21/2015 10:48 PM Yes, but why all of sudden? This module has been running fine for more than 5 years until now with your previous versions. Did you change functionalities or behaviors of the components? Share this post Link to post
SupportTeam Report post Posted 10/21/2015 11:10 PM The original trace posted on 13th Oct shows that module running fine (see below). So there looks to be an issue with the script for some reason. Currently the script reached this point: 104046.969 20 3 1 rem RvSet TTSSpeed, 0 But does not reach this point: 104046.990 20 3 1 rem RvSet_RvList [PlayWelcomeGetEmpNumber]{4001}[GetAppointment]{}[GreetFilePath]{WAV Files\Login_OutdialLoginGreet.wav,WAV Files\Common_CallingFor.wav}[blnIsAppointmentValid]{true}[blnIsMultipleAppointment]{false}[intRetries]{4}[intRetriesTemp]{5}[EmpName]{ SAMUEL SERGEANT} Can you post the VoiceGuide script itself, or the VBScript from the [CheckTaskType] module ? From trace supplied on 13th Oct: 104038.772 3 3 1 state [CheckTaskType] type: Script_VBScript, iRunWait=1 104038.780 3 3 1 rv replace start (strlen>500) 104038.890 3 rv dbg rv_retrieve did not find [AutoNotifyMoveNotificationCallID] ( 41 75 74 6f 4e 6f 74 69 66 79 4d 6f 76 65 4e 6f 74 69 66 69 63 61 74 69 6f 6e 43 61 6c 6c 49 44) 104038.890 3 rv dbg rv_retrieve did not find [IsBroadcasting] ( 49 73 42 72 6f 61 64 63 61 73 74 69 6e 67) 104038.890 3 3 1 script will be ran from file: C:\Program Files (x86)\VoiceGuide\temp\vbs_3_1.vbs 104038.890 3 3 1 on_hold_file=, iModuleIdx=47 104038.904 3 3 1 delete existing: C:\Program Files (x86)\VoiceGuide\temp\vbs_3_1.vbs 104038.954 3 3 1 current objVbsOrExeProcess (vbsrun) : id=7412, handle=5740, hash=24948291, hasExited=True, startTime=10/9/2015 11:22:53 AM, exitTime=10/9/2015 11:22:55 AM 104038.954 3 3 1 RunVBScriptFile [cscript][C:\Program Files (x86)\VoiceGuide\temp\vbs_3_1.vbs][] timeout=60 (vbsPath=C:\Program Files (x86)\VoiceGuide\temp), start (new Process) 104038.962 3 3 1 objProcess.Start call 104040.510 3 3 1 objProcess.Start returned. handle=5920, id=5536, hash=12601282, starttime=10/12/2015 10:40:39 AM, HasExited=False 104040.584 3 3 1 VBScript started [C:\Program Files (x86)\VoiceGuide\temp\vbs_3_1.vbs], handle=5920, VbsOrExeProcess.WorkingSet=[577536] 104040.592 3 3 1 RunModule_Script_AfterScriptStarted start 104040.592 3 3 1 Run Script waiting. iRunWait=1 (process:5920) 104040.592 3 3 1 t timer set 1 sec : EV_TIMEOUT_CHECKONSTATE 104040.592 3 3 1 moh file not specified 104046.771 20 rem vgRemotingCommandLink constructor start, parmameterless 104046.796 20 remoting link constructor activated: vgServices_CommandLink 104046.874 20 3 1 rem RvSet IsMoveAutoNotify, false 104046.875 20 3 1 rv add IsMoveAutoNotify|false 104046.969 20 3 1 rem RvSet TTSSpeed, 0 104046.969 20 3 1 rv add TTSSpeed|0 104046.990 20 3 1 rem RvSet_RvList [PlayWelcomeGetEmpNumber]{4001}[GetAppointment]{}[GreetFilePath]{WAV Files\Login_OutdialLoginGreet.wav,WAV Files\Common_CallingFor.wav}[blnIsAppointmentValid]{true}[blnIsMultipleAppointment]{false}[intRetries]{4}[intRetriesTemp]{5}[EmpName]{ SAMUEL SERGEANT}[GreetPasswordPath]{WAV Files\Login_OutdialLoginPassword.wav} 104046.991 20 3 1 rvns add PlayWelcomeGetEmpNumber|4001 104046.991 20 3 1 rvns add GetAppointment| 104046.991 20 3 1 rvns add GreetFilePath|WAV Files\Login_OutdialLoginGreet.wav,WAV Files\Common_CallingFor.wav 104046.991 20 3 1 rvns add blnIsAppointmentValid|true 104046.991 20 3 1 rvns add blnIsMultipleAppointment|false 104046.991 20 3 1 rvns add intRetries|4 104046.991 20 3 1 rvns add intRetriesTemp|5 104046.991 20 3 1 rvns add EmpName| SAMUEL SERGEANT 104046.991 20 3 1 rvns add GreetPasswordPath|WAV Files\Login_OutdialLoginPassword.wav 104046.993 20 3 1 rem Run_ResultReturn [success] 7 104046.993 20 3 1 q_scr + cmdRun_ResultReturn 0 104046.993 6 3 1 q_scr run cmdRun_ResultReturn sCode=[] iActionID=0, crn=0 [0|0|0|0|0][success|||||] 00:00:00 max:1|00:00:00.0980124 104046.993 6 3 1 rv add CheckTaskType_ResultReturn|success 104046.993 6 3 1 path {success} found (at offset 3) 104046.993 6 3 1 FindNextVgmTitleInPathList: next module title is=[IsHiringRequested] 104046.993 6 3 1 module's runwait=1, WavPlayWasStarted=0, WavPlayHasNowFinished=0, iRunWait_ExeResult_NextVgm=51 104046.993 6 3 1 t timer clear (force=False) 104046.993 6 3 1 RunModule start Evaluate, [IsHiringRequested], iModuleIdx=51, previous: vgm=47, vgs=1:1 104046.993 6 3 1 state [IsHiringRequested] Evaluate ["$RV[IsHiring]" = "true"] Share this post Link to post
iTime Report post Posted 10/21/2015 11:24 PM Please find the attached vgs file. I also included my VG.ini file just in case it might be erroneous because the file did not have "[ModuleRunScript]" section you mentioned earlier: I added this section to the file by searching other sample file in this forum. I really hope I do not have to make modifications through the entire scripts of mine after the upgrade. Thanks in advance. Script.zip Share this post Link to post
SupportTeam Report post Posted 10/21/2015 11:57 PM That module is doing some database retrieval, so it may be a good idea to check out if the database connectivity is still working when the that RunVBscript module is ran using the new 'ClearScript' approach. Some Admin_TraceLogAdd (http://www.voiceguide.com/vghelp/source/html/com_admin_tracelogadd.htm) calls throughout the script can help debug that. most likely the database connectivity is the issue, as in this call: vg.RvSet RV_LINEID, "TTSSpeed", intTTSSpeed the intTTSSpeed is not even set (this can be seen in vgEngine trace). You can set to execute the RunVBscript modules using the old WSH/Wscript approach instead of using the now default ClearScript interpreter by using this VG.INI setting: [moduleRunScript] Engine=WScript (VoiceGuide service restart is required to read in new VG.INI settings) Share this post Link to post
iTime Report post Posted 10/22/2015 12:23 AM The database connection is fine: VG is sending "SELECT TOP 1..." for checking dial-out table. And Dial-in activity you read from the log moves from [CheckTaskType] directly to [PlayWelcomeGetEmpNumber] without bothering the SQL server. If you see from the old log that worked fine, it shows all the comparison modules (IsHiringRequested, IsBroadcastingRequested etc...) will return false and the final destination is [PleayWelcomeGetEmpNumber.], thus no need to connect to the database. Again, please keep in mind that this script has been working fine and I did not change anything: it stopped working with the patch. Please find the attached log files: I am not sure if this may show some other things, but it is prepared with "Engine=WScript" to retain the old way of scripting. Thanks. TestWithWScript.zip Share this post Link to post
SupportTeam Report post Posted 10/22/2015 01:06 AM The module [CheckTaskType] now runs fine, we can see in trace that it reaches the Run_ResultReturn call to return 'success' : 170234.522 13 3 1 rem RvSet IsMoveAutoNotify, false 170234.558 13 3 1 rv add IsMoveAutoNotify|false 170234.621 13 3 1 rem RvSet TTSSpeed, 0 170234.621 13 3 1 rv add TTSSpeed|0 170234.623 13 3 1 rem Run_ResultReturn [success] 7 But something else happened on this call. The call was ended 200ms after being answered, and looks like the hangup arrived from the remote end... WireShark tracing would be needed here to confirm what SIP messages are exchanged (see www.wireshark.org) 493 170231.480 4720 3 ev GCEV_ANSWERED crn=8000001 (ktTel_HMP30vista v7.4.5, May 12 2015 12:41:49) 494 170231.480 4720 3 set hli->pCTelProxyhli (in GCEV_ANSWERED). current hli->pCTelProxyhli=05CA4A88, pTelClientEvents=05CA4A88 495 170231.480 4720 3 dx_setevtmsk hmp => -1 496 170231.480 4720 3 dx_clrdigbuf => 0 497 170231.480 4720 3 ResetVoiceBackToItsNetwork dxxxB1C1->iptB1T1 498 170231.480 4720 3 Reset_voice_to_ipt begin. dxxxB1C1:2 to iptB1T1:3 (hli->ct_devinfo_dx.ct_devfamily=0) 499 170231.480 4720 hli->linedev=3 hli->voicedev=2 500 170231.480 4720 3 gc_GetNetCRV not called in non-dialogicSR60 versions 501 170231.480 4720 3 r Dialogic GCEV_ANSWERED 2050 (2050 0 0 ) 502 170231.481 4720 3 Event_CallState GCEV_ANSWERED iLineCallState=256, hCall=8000001|134217729 m_pktTelProxyClient=00251130 503 170231.481 4720 3 r CallState GCEV_ANSWERED 504 170231.545 4720 3 ev idx=31 : evttype=2133(2133), crn=0, data=00523748(0ED985C0), len=16(16) q: 0/6 505 170231.545 4720 3 ev GCEV_LISTEN (2133 0x855) no handler. 506 170231.667 4908 extension saved into zStore_GC_PARM_DATA idx=9 507 170231.670 4720 3 ev idx=32 : evttype=2152(2152), crn=8000001, data=00523778(064E4298), len=8(8) q: 0/6 508 170231.670 4720 3 ev GCEV_EXTENSION hmp 509 170231.670 4720 3 zStore_GC_PARM_DATA idx=9, set_ID=12303 parm_ID=2 value_size=4 510 170231.670 4720 3 GCEV_EXTENSION IPSET_IPPROTOCOL_STATE 511 170231.688 4908 extension saved into zStore_GC_PARM_DATA idx=11 512 170231.688 4908 extension saved into zStore_GC_PARM_DATA idx=13 513 170231.690 4720 3 ev idx=33 : evttype=2086(2086), crn=8000001, data=005237A8(064E4298), len=8(8) q: 2/6 514 170231.690 4720 3 ev GCEV_DISCONNECTED crn=8000001 Share this post Link to post
SupportTeam Report post Posted 10/29/2015 01:39 AM Changing the system to run the VBScript modules using the old WSH/Wscript approach fixed the issue of database access problems that were encountered when the new (ClearScript based) approach was used to run the that VBScript. This different issue of calls being ended soon after they are answered (due to SIP Re-INVITE) is continued in this thread: http://voiceguide.com/forums/index.php?showtopic=12141 Share this post Link to post