Strange Behaviour In Line Status Panel

[mehdi_h]

Hi,

 

I wanted to let you know about something that I have exeperienced today. While I have no calls engaged in VG , I see that the call length of line 13 is still going, here the value is 6140 and still going. Is that normal?

 

Please find below a screen shot and the appropiate logs.

 

Tkx

Mh

screenshot.zip

[SupportTeam]

There was some timing issue here that prevented a reporting flag being cleared - so incorrect call length was reported in the monitoring app. We are going to fix this in upcoming release.

Possible reason why this came up on your system is that it appears like there was something running on this system which blocks writing to disk for a long time - around 30 seconds, and basically stopped the 'normal priority' processing threads in VoiceGuide from running in timely fashion, and this affected other things as well.

Do you have other software installed on this system that has a tendency to block writes to log files?

We have created a version which has more logging in the functions that write to log files on disk. Please update this system to this new version and post traces when using this new version. This will let us better see where the delay actually is:
[old link removed]




134450.984 6 qScr max time =00:01:46.9531250

135712.734 6 qScr max items=561

140730.031 6 4 3 RunModule start Hangup the Call, [HangupMZA], iModuleIdx=52, previous: vgm=55, vgs=4
140730.031 6 4 3 HangupCall, source=Hangup Module, WorkModeScript=Running_AfterHangup, yLineStateAppPov=[idle], lPlayId=0, lRecId=0
140730.031 6 4 3 moduleTitle=[HangupMZA]
140730.031 6 4 3 ScriptWorkingMode set Idle_WaitingForNextCall, (called from HangupCall_AlreadyOnHook)
140730.031 6 4 3 HangupCall WorkingModeScript=AfterHangupRun.
140730.031 6 4 3 AllScritpsCompleted_Cleanup start
140730.031 6 4 3 ScriptWorkingMode set Idle_WaitingForNextCall, (called from AllScritpsCompleted_Cleanup)
140730.031 6 4 3 WriteToLogFiles_CurrScriptOnly begin
140730.031 6 4 3 WriteToLogFiles_DoWrite begin : strLogFnameLessSuffix=C:\Program Files\VoiceGuide\Scripts\save_hangup_VAD
140730.031 6 4 3 WriteToLogFiles_DoWrite : log subdirectory does not exist: C:\Program Files\VoiceGuide\Scripts\log
140730.046 11 db PerformWork_RunCoreSql cmd_CoreSql.ExecuteNonQuery returned
140730.062 18 29 15 ev Dialogic 135,TDX_SETHOOK, crn=20000089, 0,0,0,DX_ONHOOK,,
140730.062 18 29 15 qScr add evScriptEvent 135 TDX_SETHOOK
140730.062 18 29 15 ev CallState TDX_SETHOOK_DX_ONHOOK, crn=20000089, iEvent=2 ,1,0,32,,,]. vgEngine v7.1.3699.20074 (2010-02-16 11:09:08.70)
140730.062 18 29 15 qScr add evCallState 2 TDX_SETHOOK_DX_ONHOOK
140732.875 4 27 14 timer EV_TIMEOUT_AFTERIDLE_ALLOWOUT
140732.875 4 27 14 qScr add evScriptEvent 9013 EV_TIMEOUT_AFTERIDLE_ALLOWOUT
140734.906 4 10 6 timer EV_TIMEOUT_REPLAYMSG
140734.906 4 10 6 qScr add evScriptEvent 9005 EV_TIMEOUT_REPLAYMSG
140737.953 21 14 8 timer EV_TIMEOUT_GOTOMODULE
140737.953 21 14 8 qScr add evScriptEvent 9002 EV_TIMEOUT_GOTOMODULE
140739.156 18 24 13 ev Dialogic 133,TDX_CALLP, crn=20000081, 8,0,0,CR_NOANS,,
140739.156 18 24 13 qScr add evScriptEvent 133 TDX_CALLP
140739.968 21 29 15 timer EV_TIMEOUT_WAITFORIDLEAFTERDropCall
140739.968 21 29 15 qScr add evScriptEvent 9101 EV_TIMEOUT_WAITFORIDLEAFTERDropCall
140757.203 6 4 3 LineState_Reinit_AndReleaseCall: crn=20000082
140757.203 6 4 3 LineState_Reinit_CleanLineState : begin
140757.203 6 4 3 ls set Null_InGuardTimeAfterEndOfCall (scriptstate=LS_MODULE_TRANSITION)
140757.203 6 4 3 ScriptWorkingMode set Idle_WaitingForNextCall, (called from LineState_Reinit_CleanLineState)
140757.203 6 4 3 strThisCallIsInboundOrOutbound clear. (LineState_Reinit_CleanLineState)
140757.203 6 4 3 qTel add cmd_ReleaseCall [0,0,0,0,0][||||]
140757.203 6 4 3 t timer set 3 sec : EV_TIMEOUT_AFTERIDLE_ALLOWOUT
140757.203 7 4 3 qTel run cmd_ReleaseCall
140757.203 6 4 3 timer set completed lTimeLeft250msUnits=12, iTimeoutCode=9013
140757.203 6 4 3 state Waiting for a call...
140757.203 6 4 3 ScriptWorkingMode set Idle_WaitingForNextCall, (called from LineState_Reinit_AndReleaseCall)
140757.203 7 4 3 ev CallState GCEV_RELEASECALL, crn=20000082, iEvent=2137 ,0,0,0,GCST_NULL,,]. vgEngine v7.1.3699.20074 (2010-02-16 11:09:08.70)
140757.203 6 29 15 qScr run evScriptEvent sCode=[TDX_SETHOOK] iActionID=0, crn=20000089[0|0|0|0|0][DX_ONHOOK|||||]
140757.203 7 4 3 qScr add evCallState 2137 GCEV_RELEASECALL
140757.203 6 29 15 scriptevent TDX_SETHOOK param1:DX_ONHOOK, param2:, param3:
140757.203 6 29 15 LsEndingCall TDX_SETHOOK 0 DX_ONHOOK
140757.203 6 29 15 qScr run evCallState sCode=[TDX_SETHOOK_DX_ONHOOK] iActionID=0, crn=20000089[1|0|32|0|0][|||||]


ktTel:

140730.062 10184 29 r Dialogic TDX_SETHOOK 135 (0 0 0 DX_ONHOOK )
140730.062 10184 29 CTelProxy::Event_CallState TDX_SETHOOK_DX_ONHOOK iLineCallState=1, hCall=536871049 m_pktTelProxyClient=006917D4
140730.062 10184 29 r CallState TDX_SETHOOK_DX_ONHOOK
140730.062 10184 29 ec ec_stream not enabled. ec_stopch not called
140739.156 10184 24 CtEventProcess idx=800 : evttype=133(133), crn=0, data=08DA19C8(088618A0), len=0(0) q: 0/6
140739.156 10184 24 ev TDX_CALLP (Call Progress Completed)
140739.156 10184 24 TDX_CALLP CR_NOANS (called line did not answer)
140739.156 10184 24 r Dialogic TDX_CALLP 133 (8 0 0 CR_NOANS )
140757.203 9596 4 fn ReleaseCall(sLineId=4, crn=20000082, Param1=0)
140757.203 9596 4 TelDriver_ReleaseCall channelType=analog. just signal back that ReleaseCall completed
140757.203 9596 4 CTelProxy::Event_CallState GCEV_RELEASECALL iLineCallState=0, hCall=536871042 m_pktTelProxyClient=006917D4
140757.203 9596 4 r CallState GCEV_RELEASECALL
140757.203 9596 4 TelDriver_ReleaseCall Event_CallState returned.
140809.671 10184 10 CtEventProcess idx=801 : evttype=134(134), crn=0, data=08DA19F8(0E593288), len=16(16) q: 0/6
140809.671 10184 10 ev TDX_CST (CST Event Received)

[mehdi_h]

I have installed that version and let you know after I have that probleme again.

BTW I have avast installed on my VG system, do you think that could be the reason?

 

Mh

[SupportTeam]

If you have any other application that is monitoring writes to hard disk then that could be causing the disk write delays that we are seeing.

[mehdi_h]

Hi Support team,

 

As requested I have installed your version and the probleme occured again.

Please be aware that I have installed Avast antivirus on that machine.

I have attached the logs.

 

 

Thank you.

Mh

[SupportTeam]

No files were attached to post.

 

Please try attaching them again.

[mehdi_h]

Sorry here they are.

 

Thank you

Mh

0313_1648_vgEngine.zip

[mehdi_h]

Here is a screen shot of what happens today. Logs attached.

 

Thank you

Mh

[SupportTeam]

Could you please .ZIP up and post traces which cover the time from 1pm till 7pm on 22nd March.

[mehdi_h]

To cover this period I have 20 log files of 10Mo each.

Do you wnat them all? I can post them here they are too large.

please advice.

Mh

[SupportTeam]

Can you make them available for download from somewhere else and post the link to download here?

[mehdi_h]

Hi Support Team,

Here is the link to download the log files.


[old link removed]

tkx

[SupportTeam]

Looks like the 3 lines stopped making outgoing calls as there was a problem with sound file playback.

 

The other lines do not seem to be affected in any way, and the result is that the number of ports making outbound calls is reduced.

 

This is a different issue then the one found in traces earlier on.

 

Can you .ZIP up and post the ktTel file for the 03-22 day?

 

Which Dialogic cards and Dialogic drivers are used on this system?

 

134235.734 19 32 17 ev Dialogic 135,TDX_SETHOOK, crn=200064c2, 0,0,0,DX_OFFHOOK,CALL_OUTBOUND,

134235.734 19 32 17 qScr add evScriptEvent 135 TDX_SETHOOK

134235.734 6 32 17 qScr run evScriptEvent sCode=[TDX_SETHOOK] iActionID=0, crn=200064c2[0|0|0|0|0][DX_OFFHOOK|CALL_OUTBOUND||||]

134235.734 6 32 17 scriptevent TDX_SETHOOK param1:DX_OFFHOOK, param2:CALL_OUTBOUND, param3:

134235.734 6 32 17 LsWaitAfterDialingOut : 135,200064c2,TDX_SETHOOK,0,0,0,DX_OFFHOOK,CALL_OUTBOUND,

 

134242.734 19 32 17 ev CallState TDX_CALLP_CR_CNCT, crn=200064c2, iEvent=2 ,256,2,4,,,]. vgEngine v7.1.3722.40345 (2010-03-11 22:24:51.71)

134242.734 19 32 17 qScr add evCallState 2 TDX_CALLP_CR_CNCT

134242.734 19 32 17 ev Dialogic 133,TDX_CALLP, crn=200064c2, 10,3,0,CR_CNCT,CON_PVD,

134242.734 19 32 17 qScr add evScriptEvent 133 CON_PVD

134242.734 6 32 17 qScr run evCallState sCode=[TDX_CALLP_CR_CNCT] iActionID=0, crn=200064c2[256|2|4|0|0][|||||]

134242.734 19 32 17 qScr add evScriptEvent 133 TDX_CALLP

134242.734 6 32 17 LineEvCallState eLineStateThisEvent=Connected

134242.734 19 32 17 ev Dialogic 134,TDX_CST, crn=200064c2, 1137,0,0,DE_LCON,,

134242.734 6 32 17 LineEvCallState ScriptState=LS_WAITAFTERDIALINGOUT

134242.734 19 32 17 qScr add evScriptEvent 134 TDX_CST

134242.734 6 32 17 ls set Connected (scriptstate=LS_WAITAFTERDIALINGOUT)

134242.734 6 32 17 yLineStateAppPov: Connected crn=200064c2,ev=2,TDX_CALLP_CR_CNCT,2, sParam1=

134242.734 6 32 17 LineEvCallState LINECALLSTATE_CONNECTED begin

134242.734 6 32 17 Set_hCall crn=200064c2, called from LINECALLSTATE_CONNECTED

134242.734 6 32 17 LineEvCallState_Connected_OutBound crn=200064c2, WorkingModeScript=Running_Dialing

134242.734 6 32 17 CDRCallOutcomeSet setting IvrDevState dateThisCallAnswerTime

134242.734 6 32 17 rvns add [OutDial_Result]{ANSWERED}

134242.734 6 32 17 ScriptWorkingMode set Running_Normal, (called from LineEvCallState_Connected_OutBound)

134242.734 6 32 17 dial wait as LineState().sCallProgressOption=[DX_PAMDOPTEN]

134242.734 6 32 17 state Dialing 00466395287..., doing answer detection... (DX_PAMDOPTEN)

 

 

134242.734 6 32 17 state [M1] Playing wav (C:\Program Files\VoiceGuide\Sound\TeamCell.wav)

134242.734 6 32 17 t timer clear (force=False)

134242.734 6 32 17 qTel add cmd_PlayStart [0,0,0,0,0][||||]

134242.734 6 32 17 play start ok, playId=996453

134242.734 7 32 17 qTel run cmd_PlayStart

134242.734 6 32 17 qScr run evScriptEvent sCode=[TDX_CST] iActionID=0, crn=200064c2[1137|0|0|0|0][DE_LCON|||||]

134242.734 6 32 17 scriptevent TDX_CST param1:DE_LCON, param2:, param3:

134242.734 6 32 17 LsPlayMsg EV_UNKNOWN_134,TDX_CST

134242.734 6 32 17 path {TDX_CST} not found

[mehdi_h]

No this is always the same probleme.
Actually the problem occurs often and with diffrent line. I have to stop VG and restard again to fix it.
What could be the issue with the wav file, as I'm usgin exactly the same file for all line ?
I'm using the last dialogic driver that I have downloaded from your site "Dialogic_drivers_for_VoiceGuide_v7.1_XP_2003".

Here is the requested attachement.

[old link removed]

Tkx

[mehdi_h]

it had occur again today. here are the logs

[old link removed]

Tkx
Mh

[SupportTeam]

What model Dialogic cards are used on this system?

[SupportTeam]

In the 0401 traces which was the channel(s) affected?

[mehdi_h]

What model Dialogic cards are used on this system?

 

>> I have 1* D/41JCT and 2* D/120JCT

 

In the 0401 traces which was the channel(s) affected?

>> Channel 25

 

 

tkx

[SupportTeam]

Please update your system to this version of VoiceGuide:

[old link removed]

and post traces as before if you continue to encounter this problem.

[Guest u4910]

I also get lines getting stuck on occasion. When it does happen they go on forever as a connected call until I restart the engine. I downloaded the new version but it fails to start. See the attached engine log.
Please advise.

0409_1513_vgEngine.zip

[SupportTeam]

u4910: Trace shows the software could not start because of DLL mismatch. Please uninstall VoiceGuide then ensure entire VoiceGuide directory is removed, (backup your scripts and config files) and then install VoiceGuide again and replace the config files etc.

If you continue to have problems please start a new thread for your issue.

[Guest u4910]

Thanks, that did the trick. I like the new version so far. Keep up the good work! With a little tweaking this is a great product!