Vg Stops Checking Call Cue

[bgharddisk]

I have had VG for Dialogic running on my box for a couple weeks now. For the most part, it has worked as expected, but it didn't get any use over the weekend. When I added a call to the ( mySQL ) cue this afternoon to make sure it was working, the dialer didn't pull the call from the cue and dial it. VG was running "Waiting for call", but just didnt want to check the cue for some reason. Has anyone else experienced a time out or something similar after having not used the dialer for a couple days?

 

I cleared the cue (2 calls) and restarted the dialer and it started working predictably again when cueing calls.

 

I should have restarted the dialer without clearing the cue to see if it would pull again, but I didn't.

 

Any ideas?

 

Thank You.

[SupportTeam]

Which version of VoiceGuide are you running?

 

Have you setup a mySQL as the database server for the OutDial que system?

 

Can please you post the mySQL database itself here and the connection strings which were setup to use the mySQL database from within VG.

[bgharddisk]

Explain how the problem can have anything to do with the connection string if it works the rest of the time.

 

6.0.3197

 

If by setup you mean adding the connection string to vg.ini then yes

 

DbConnectString_ADO=DRIVER={MySQL ODBC 3.51 Driver};Server=localhost;UID=root;Password=XXX;Database=dialer;Option=3

 

CREATE TABLE `callque` (

`id` int(10) NOT NULL auto_increment,

`PhoneNumber` varchar(50) collate utf8_unicode_ci default NULL,

`ActivateTime` int(4) default NULL,

`DayTimeStart` int(4) default NULL,

`DayTimeStop` int(4) default NULL,

`DaysCallAllowed` varchar(50) collate utf8_unicode_ci default NULL,

`LineSelection` varchar(1000) collate utf8_unicode_ci default NULL,

`Priority` int(4) default NULL,

`AnnounceMessage` varchar(500) collate utf8_unicode_ci default NULL,

`Script` varchar(500) collate utf8_unicode_ci default NULL,

`OnAnswerMachine` varchar(500) collate utf8_unicode_ci default NULL,

`RV` varchar(1000) collate utf8_unicode_ci default NULL,

`AnswerTimeout` int(4) default NULL,

`CallRetriesLeft` int(4) default NULL,

`DelayBetweenRetries` int(4) default NULL,

`OnNotConnected` varchar(1000) collate utf8_unicode_ci default NULL,

`EscalationCalls` varchar(4000) collate utf8_unicode_ci default NULL,

`Options` varchar(1000) collate utf8_unicode_ci default NULL,

PRIMARY KEY (`id`)

)

[SupportTeam]

Are there any traces available from this system which cover the time from when calls were still made till when it was noticed that calls were not sent out?

 

Did you have a chance to test whether calls placed in OutDialQue.mdb database (either directly or when using the XML file or COM command) were dialled out?

The traces would show what happend to database queries issued by VoiceGuide.

[bgharddisk]

From what I can tell, the trace shows VG idling from midnight until 12:30, when I restarted it. Did I miss something?

 

002258.04 0 sys cleanup Start

002258.04 0 sys cleanup End

005258.04 0 sys cleanup Start

005258.04 0 sys cleanup End

012258.04 0 sys cleanup Start

012258.04 0 sys cleanup End

015258.04 0 sys cleanup Start

015258.04 0 sys cleanup End

022258.04 0 sys cleanup Start

022258.04 0 sys cleanup End

025258.04 0 sys cleanup Start

025258.04 0 sys cleanup End

032258.04 0 sys cleanup Start

032258.04 0 sys cleanup End

035258.04 0 sys cleanup Start

035258.04 0 sys cleanup End

042258.04 0 sys cleanup Start

042258.04 0 sys cleanup End

045258.04 0 sys cleanup Start

045258.04 0 sys cleanup End

052258.04 0 sys cleanup Start

052258.04 0 sys cleanup End

055258.04 0 sys cleanup Start

055258.04 0 sys cleanup End

062258.04 0 sys cleanup Start

062258.04 0 sys cleanup End

065258.04 0 sys cleanup Start

065258.04 0 sys cleanup End

072258.04 0 sys cleanup Start

072258.05 0 sys cleanup End

075258.05 0 sys cleanup Start

075258.05 0 sys cleanup End

082258.05 0 sys cleanup Start

082258.05 0 sys cleanup End

085258.05 0 sys cleanup Start

085258.05 0 sys cleanup End

092258.05 0 sys cleanup Start

092258.05 0 sys cleanup End

095258.05 0 sys cleanup Start

095258.05 0 sys cleanup End

102258.05 0 sys cleanup Start

102258.05 0 sys cleanup End

105258.05 0 sys cleanup Start

105258.05 0 sys cleanup End

112258.05 0 sys cleanup Start

112258.05 0 sys cleanup End

115258.07 0 sys cleanup Start

115258.07 0 sys cleanup End

122258.07 0 sys cleanup Start

122258.07 0 sys cleanup End

123006.39 0 btn Exit (4 lines)

123006.39 1 line state = 900

123006.39 2 line state = 900

123006.41 3 line state = 900

123006.41 4 line state = 900

123006.41 1 state Exiting...

123006.41 2 state Exiting...

123006.43 3 state Exiting...

123006.43 4 state Exiting...

123007.52 0 exit closing all channels start

123007.52 0 exit close dxxxB1C1(1)=> []

123007.54 0 exit close dxxxB1C2(2)=> []

123007.54 0 exit close dxxxB1C3(3)=> []

123007.54 0 exit close dxxxB1C4(4)=> []

123007.54 0 exit closing all channels end

[bgharddisk]

What does this mean? Could it have something to do with the time out effect? This is from todays log.

 

Thank You.

 

075643.79 5 dial rsCallQueADO_FetchComplete pRecordset.RecordCount fail. err=[Operation is not allowed when the object is closed.]

 

000118.19 0 sys cleanup Start

000118.19 0 sys cleanup End

003118.19 0 sys cleanup Start

003118.19 0 sys cleanup End

010118.22 0 sys cleanup Start

010118.22 0 sys cleanup End

013118.22 0 sys cleanup Start

013118.22 0 sys cleanup End

020118.22 0 sys cleanup Start

020118.22 0 sys cleanup End

023118.22 0 sys cleanup Start

023118.24 0 sys cleanup End

030118.25 0 sys cleanup Start

030118.25 0 sys cleanup End

033118.25 0 sys cleanup Start

033118.25 0 sys cleanup End

040118.27 0 sys cleanup Start

040118.27 0 sys cleanup End

043118.27 0 sys cleanup Start

043118.29 0 sys cleanup End

050118.29 0 sys cleanup Start

050118.29 0 sys cleanup End

051026.79 5 dial rsCallQueADO_FetchComplete pRecordset.RecordCount fail. err=[Operation is not allowed when the object is closed.]

053118.30 0 sys cleanup Start

053118.32 0 sys cleanup End

060118.32 0 sys cleanup Start

060118.32 0 sys cleanup End

063118.32 0 sys cleanup Start

063118.32 0 sys cleanup End

064648.79 5 dial rsCallQueADO_FetchComplete pRecordset.RecordCount fail. err=[Operation is not allowed when the object is closed.]

070118.33 0 sys cleanup Start

070118.33 0 sys cleanup End

073118.35 0 sys cleanup Start

073118.35 0 sys cleanup End

075643.79 5 dial rsCallQueADO_FetchComplete pRecordset.RecordCount fail. err=[Operation is not allowed when the object is closed.]

080118.36 0 sys cleanup Start

080118.36 0 sys cleanup End

083118.38 0 sys cleanup Start

083118.38 0 sys cleanup End

085416.79 5 dial rsCallQueADO_FetchComplete pRecordset.RecordCount fail. err=[Operation is not allowed when the object is closed.]

090118.38 0 sys cleanup Start

090118.38 0 sys cleanup End

093118.39 0 sys cleanup Start

093118.39 0 sys cleanup End

100118.39 0 sys cleanup Start

100118.39 0 sys cleanup End

103118.39 0 sys cleanup Start

103118.39 0 sys cleanup End

104325.43 1 dial cnCallQueADO_ConnectComplete now wait for rsCallQueADO_FetchComplete

104325.44 1 dial DialOnLine start tel[17068677815] ann[] vgs[c:\voiceguide\Scripts\123b.vgs] am[c:\voiceguide\Scripts\nomachine.vgs] rv[[dname]{Associates}[pname]{eric jonathan}[callid]{53C2C009-A2D8-66C1-04F8-0898E2AC5BD9}[appdate]{January 1st 2006}[apptime]{1:00 AM}[officephone]{954-675-7771}[special]{}] cid[]

104325.44 1 rv clear all

104325.46 1 rv add [dname]{Associates}

104325.46 1 rv add [pname]{eric smith}

104325.46 1 rv add [callid]{53C2C009-A2D8-66C1-04F8-0898E2AC5BD9}

104325.46 1 rv add [appdate]{January 1st 2006}

104325.47 1 rv add [apptime]{1:00 AM}

104325.47 1 rv add [officephone]{954-675-5555}

104325.47 1 rv add [special]{}

104325.49 1 rv add [OutDial_RetriesLeft]{0}

104325.49 1 dial making call tel[17068555555] ann[] vgs[c:\voiceguide\Scripts\123b.vgs] am[c:\voiceguide\Scripts\nomachine.vgs] OnHangup[] rv[[dname]{Associates}[pname]{eric jonathan}[callid]{53C2C009-A2D8-66C1-04F8-0898E2AC5BD9}[appdate]{January 1st 2006}[apptime]{1:00 AM}[officephone]{954-675-7771}[special]{}[OutDial_RetriesLeft]{0}]

104325.49 1 script interpretor: VgMulti v6.0.3179

104325.50 1 state Dialing 17065555555

104325.54 1 lineMakeCall=>[]

104325.54 1 timer set 18 EV_TIMEOUT_MAKECALL_NORESPONSE

104326.07 1 tw DialogicEvent 135,TDX_SETHOOK,0,0,0,DX_OFFHOOK,CALL_OUTBOUND,

104326.07 1 event TDX_SETHOOK, iCode=135 state=5200

104326.07 1 LsWaitAfterDialingOut : 135,TDX_SETHOOK,0,0,0,DX_OFFHOOK,CALL_OUTBOUND,

104337.19 1 tw DialogicEvent 133,TDX_CALLP,7,0,0,CR_BUSY,,

104337.19 1 event BUSY, iCode=133 state=5200

104337.21 1 LsWaitAfterDialingOut : 133,BUSY,7,0,0,CR_BUSY,,

104337.21 1 event CR_BUSY, iCode=133 state=5200

104337.21 1 LsWaitAfterDialingOut : 133,CR_BUSY,7,0,0,,,

104337.22 1 event TDX_CALLP, iCode=133 state=5200

104337.22 1 LsWaitAfterDialingOut : 133,TDX_CALLP,7,0,0,CR_BUSY,,

104337.22 1 DialoutProcessFailedDial start sCalledFrom=[LsWaitAfterDialingOut-CR_BUSY] RetriesLeft=0

104337.24 0 dial callque delete id=8 (ADO)

104337.25 1 rvns add [OutDial_Result]{Uncontactable_Busy}

104337.25 1 timer clear

104337.27 1 rv replace start: [Dim rs, strConnectString, strSQL

Set rs = CreateObject("ADODB.Recordset")

strConnectString = "DRIVER={MySQL ODBC 3.51 Driver};Server=localhost;UID=root;Password=XXX;Database=dialer;Option=3"

rs.ActiveConnection = strConnectString

strSQL = "UPDATE status SET status = 'No Answer' WHERE callid = '$RV[callid]'"

rs.Open strSQL]

104337.27 1 rvns [PathSysVoice]{C:\voiceguide\system\voice\}[PathApp]{C:\voiceguide\}[PathDataVm]{C:\voiceguide\data\}[PathVgSys]{C:\voiceguide\system\}[dname]{Doctors Associates}[pname]{eric jonathan}[callid]{53C2C009-A2D8-66C1-04F8-0898E2AC5BD9}[appdate]{January 1st 2006}[apptime]{1:00 AM}[officephone]{954-675-7771}[special]{}[OutDial_RetriesLeft]{0}[OutDial_Result]{Uncontactable_Busy}

104337.29 1 vbs replaced rv and ran shell[wscript "C:\voiceguide\temp\vbs_1_OnNotConnected_061024104337.vbs" //I //T:3600]

104337.41 1 VBScript started [wscript "C:\voiceguide\temp\vbs_1_OnNotConnected_061024104337.vbs" //I //T:3600]

104337.41 1 OnNotConnected run ok []

104337.41 1 dial no escalation info

104337.43 1 HangupCall start (CR_BUSY in LsWaitAfterDialingOut)

104337.43 1 rv add [Hangup Time]{10/24/2006 10:43:37 AM}

104337.43 1 state Hanging up call... [CR_BUSY in LsWaitAfterDialingOut]

104337.44 1 HangupCall_Common hCall=0

104337.44 1 rec RecSoundStop ok

104337.44 1 play PlayStop ok

104337.46 1 timer set 2 EV_TIMEOUT_WAITFORIDLEAFTERLINEDROP

104337.46 1 HangupCall : lCallHandle& = 0 - lets close and open line

104337.46 1 state Waiting for a call...

104337.47 1 fnHangupCall end

104337.47 1 tw DialogicEvent 134,TDX_CST,65535,0,0,DE_LCON,,

104337.47 1 event TDX_CST, iCode=134 state=900

104337.49 1 LsAwaitingCalls EV_UNKNOWN_134

104337.50 1 tw DialogicEvent 135,TDX_SETHOOK,0,0,0,DX_ONHOOK,,

104337.50 1 event TDX_SETHOOK, iCode=135 state=900

104337.52 1 LsAwaitingCalls EV_UNKNOWN_135

104337.52 1 event callstate IDLE 1 1,0,0

104337.52 1 WorkingMode@Idle=

104337.54 1 set LineState().hCall = 0 LineEvCallState-LINECALLSTATE_IDLE

104337.54 1 timer clear

104337.54 1 LineState(iLineId).iVgsIdx = 0

104337.55 1 timer set 1 EV_TIMEOUT_TIMETOREINITLINE

104337.64 1 event callstate OFFERING 1 2,0,0

104337.64 1 script interpretor: VgMulti v6.0.3179

104337.64 1 fired OFFERING event to listeners

104337.66 1 set LineState().hCall = 1 in LINECALLSTATE_OFFERING

104337.68 1 cid CallerID vars set (in 'offering' event) [,,]

104337.68 1 call AnswerTheCallIfAllowed from LINECALLSTATE_OFFERING

104337.69 1 do not answer call - still awaiting re-init after last call

104337.69 1 tw ring 1

104337.71 1 ring time since last ring event (sec): 0.00

104337.71 1 do not answer call - still awaiting re-init after last call

104337.72 1 tw DialogicEvent 134,TDX_CST,0,0,0,DE_RINGS,ET_RON,

104337.74 1 event TDX_CST, iCode=134 state=900

104337.74 1 LsAwaitingCalls EV_UNKNOWN_134

104338.63 1 timer fired EV_TIMEOUT_TIMETOREINITLINE

104338.63 1 event EV_TIMEOUT_TIMETOREINITLINE, iCode=9008 state=900

104338.64 1 init atidle reinit : start

104338.64 1 init atidle reinit iConferenceOtherLegLid=-1

104338.66 1 init atidle reinit : reset all LineState variables

104338.66 1 timer set 2 EV_TIMEOUT_AFTERIDLE_ALLOWOUT

104338.68 1 state Waiting for a call...

[SupportTeam]

The errors:

 

rsCallQueADO_FetchComplete pRecordset.RecordCount fail. err=[Operation is not allowed when the object is closed.]

 

indicate that on odd occasions the connection to database did not work.

 

VG makes a connection to database every couple of seconds to see if any calls are queued, so looks like all the other connections worked (almost 11 hours at 1800 connections each hour), and we can see that an outgoing call was made at 104325.43 when an outgoing call became available:

 

104325.43 1 dial cnCallQueADO_ConnectComplete now wait for rsCallQueADO_FetchComplete

104325.44 1 dial DialOnLine start [...]

 

Are there any traces available from this system which cover the time from when calls were still made till when it was noticed that calls were not sent out? Those traces will show us what happened that stopped VG from being able to read calls from the database.

 

What is the daily call volume? For low call volumes it's easier to use the default MSAccess database, it saves time trying to debug ODBC driver related issues which is what usually ends up happening when we try to figure out why a custom OutDial DB source is not working.

 

When posting traces/scripts please .ZIP them up and post them as attachments.

[bgharddisk]

I think I have found the reason the dialer stopped checking the cue. I would post the complete logs for the past few days, but it would take forever to clean personal information from them. If you think it will help, I can email them to you.

 

I believe this is what caused VG to stop checking the cue on the 23rd.

 

Log from the 22nd:

 

12 hours of cleanups then...

 

225258.02 0 sys cleanup Start

225258.02 0 sys cleanup End

225729.74 0 tcpsl StatusLink connect request on socket 0 ID 83908

225729.76 0 tcpsl ERROR on socket 1 (Connection is aborted due to timeout or other failure,C:\WINDOWS\system32\mswinsck.ocx)

225729.76 0 tcpsl ERROR on socket 2 (Connection is aborted due to timeout or other failure,C:\WINDOWS\system32\mswinsck.ocx)

225806.16 0 tcpsl ERROR on socket 3 (Connection is aborted due to timeout or other failure,C:\WINDOWS\system32\mswinsck.ocx)

232258.02 0 sys cleanup Start

232258.02 0 sys cleanup End

 

The same error once on the 21st.

005710.36 0 tcpsl ERROR on socket 2 (Connection is aborted due to timeout or other failure,C:\WINDOWS\system32\mswinsck.ocx)

 

Nothing was being done to the machine at the time. Just Idling with VG running.

 

The daily call volume is 1000 - 3000 (some calls are re-cued depending on status). While the call cue record count / size does not approach the practical limits of msaccess, our call status tables do (with 1000+ new records per day that are never purged). Its not practical for us to use one database for cues and another for status. We would still need an ODBC connection from PHP to msAccess.

 

Looking at the logs over the past few days, I do see a handful lot of these errors each day. "pRecordset.RecordCount fail. err" etc.

 

I dont really mind if it skips a beat every once in a while as long as the cue check frequency isnt causing the Winsock error. Would slowing down the frequency that it checks the call cue reduce the errors? Does the "StatusLink" have anything to do with the vgStatusMonitor? Maybe the status monitor is causing the crash.

 

Thank you for your help.

[SupportTeam]

The socket errors are assosciated with StatusLink connect requests, and not with OutDial ODBC database connections.

 

Still it's strange that you are seeing this in log files. It suggests a connection is attempted to your system on the TCP port 14711 - which is the port used by VoiceGuide to accept StatusLink connect requests.

 

Maybe this was a random port reassign of some other system TCP connection...

 

Were all queued calls made fine before 22:52:58 on 22nd and no calls went out afterwards?

 

Please .ZIP up and email the logs to support@voiceguide.com

 

StatusMonitor would not affect ODBC connections. Try starting the Status Monitor and always keeping it running on the system and see how the ODBC connection behaves with it running all the time and whether you still get the "tcpsl ERROR on socket" errors with it running.

[SupportTeam]

Please .ZIP up and email the logs to support@voiceguide.com

We received the logs, but the logs were for 9 days... where in these logs are we supposed to look? Ie: What was the date/time at which the call was loaded in OutDialQue database but not picked up by the Dialer?