Restart Under Traffic Jam

[invoso.com]

Two problems:

 

1st problem - restart VG and first connections.

After restart in first connections VG need several seconds to start services and in this time hanging up like in this log:

055441.062 6 3 1 RunModule start Evaluate, [DDI], iModuleIdx=29, previous: vgm=105, vgs=1:1

055441.062 6 3 1 state [DDI] Evaluate [$RV_DNIS]

055441.062 6 3 1 rv replace start [$RV_DNIS]

055441.062 6 3 1 rv replace end [222054699]

055441.062 6 3 1 eval [222054699]

055441.062 6 3 1 eval InvokeMember Eval returned

055441.062 6 3 1 creating new (non-global) rv : DDI

055441.062 6 3 1 Eval Expr result:[222054699] stored in RV[DDI]

055441.062 6 3 1 path {222054699} found (at offset 5879)

055441.062 6 3 1 FindNextVgmTitleInPathList: next module title is=[\manager_main.vgs|]

055441.062 6 3 1 script and module specified

055441.062 6 3 1 NewVgsVgm_Goto_Setup dest=\manager_main.vgs|, return=|, lSaveSourceOnCallStack=0

055441.062 6 3 1 rv add start ScriptEnd_Time|2013-04-17 05:54:41

055441.062 6 3 1 rv add 2013-04-17 05:54:41

055441.062 6 3 1 rv add start ScriptEnd_Goto_Script|\manager_main.vgs

055441.062 6 3 1 rv add C:\Program Files\VoiceGuide\Scripts\manager\manager_main.vgs

055441.062 6 3 1 rv add start ScriptEnd_Goto_Module|

055441.062 6 3 1 rv add

055441.062 6 3 1 WriteToLogFiles_CurrScriptOnly begin

055441.062 6 3 1 WriteToLogFiles_DoWrite begin : strLogFnameLessSuffix=\prepaid_2011_10_14

055441.062 6 3 1 WriteToLogFiles_DoWrite : log subdirectory exists, strLogFnameLessSuffix=log\prepaid_2011_10_14

055445.000 20 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

055446.250 20 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

055447.500 20 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

055448.750 20 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

055456.250 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

055457.500 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

055458.750 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

055500.000 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

055501.250 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

055502.500 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

055503.750 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

055505.000 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

055506.250 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

055507.500 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

055508.750 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

055510.000 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

055511.093 6 3 1 WriteToLogFiles_DoWrite completed

055511.093 6 dict clsStringDictionaryThreadSafe contructor with dictin. dict.Count=8

055511.093 6 3 1 rv add start ScriptStart_Time|2013-04-17 05:54:41

055511.093 6 3 1 rv add 2013-04-17 05:54:41

055511.093 6 3 1 rv add start ScriptStart_CalledFrom_Script|\prepaid_2011_10_14.vgp

055511.093 6 3 1 rv add prepaid_2011_10_14.vgp

055511.093 6 3 1 rv add start ScriptStart_CalledFrom_Module|DDI

055511.093 6 3 1 rv add DDI

055511.109 6 3 1 FindFullPathToScript_VgsOrVgp start [\manager_main.vgs]

055511.140 6 VgsScriptLoad load start [manager_main.vgs] iVgsLoadCounter=2

055511.140 6 VgsScriptLoad iVgsId=2

055511.203 6 VgsScriptLoad about to do ProcessVgsEntry loop

055511.468 6 3 1 loaded [\manager_main.vgs] into:2

055511.468 6 3 1 ScriptToRunOnHangup=[\manager_termination.vgs] in NewVgsVgm_SetVgsVgm 1

055511.468 6 3 1 StartModuleDefault=[DDI]

055511.468 6 3 1 ScriptToRunOnHangup=[\manager_termination.vgs] in NewVgsVgm_SetVgsVgm NewVgsVgm_SetActualVgsVgm

055511.468 6 3 1 t timer clear (force=False)

055511.468 6 3 1 RunModule start Evaluate, [DDI], iModuleIdx=159, previous: vgm=159, vgs=2:2

055511.468 6 3 1 state [DDI] Evaluate [$RV_DNIS]

055511.468 6 3 1 rv replace start [$RV_DNIS]

055511.468 6 3 1 rv replace end [222054699]

055511.468 6 3 1 eval [222054699]

 

We have several databases as data source for VG so I need to test each script using each database to be sure that customs calling to our system will be not surprised 10 second waiting time without any response or prompt.

 

 

2nd problem:

 

Restart VG under traffic sometimes will blocking some channels and it is no way to free hanged up channel (changing to maintenance or out of service without success - only pending status).

Our provider's switch try to connect 30 calls to first E1 trunk and not see that one or few channels are unavailable, so not redirecting next connections to second E1 before has not more as 30 connections.

 

Probably problem with restart under traffic is connected with situation described in 1st case?

[SupportTeam]

Please post ktTel trace file that covers the service restart and the entire vgEngine trace file.

 

Please .ZIP up traces before posting.

 

How big is the manager_main.vgs script? Can you post that file here? Does it always take over 20 seconds to load?

[SupportTeam]

The 3 E1s should be reconfigured by your provider so that calls are presented in 'Round Robin"/'Circular' fashion across all the E1s that handle incoming calls.

 

This will have the effect that each incoming call channel on system gets the same number of calls.

[invoso.com]

main script has 53KB and next script has 67 KB.

ktTel_vgEngine.zip

[invoso.com]

It happen today again. VG hang up and after restart 7 from 30 channels was blocked and no way to free them.

 

I try use "Hang up" button in Line Status Monitor but it help only in one case in 7 not.

 

I understand that to many connection in one moment can be to complicated for application.

Maybe stronger tool to terminate calls in Line Status Monitor can help?

[SupportTeam]

Please post ktTel trace file for that day and advise restart time.

 

Please .ZIP up traces before posting.

[invoso.com]

Attached log file

0422_ktTel_part.zip

[SupportTeam]

Could you please try this version of VoiceGuide when restarting the system while there are calls coming in over the E1 trunks:

[old link removed]

After doing the restart under those conditions please post the ktTel trace as before (.ZIPed).

[invoso.com]

still problems with restart when traffic is high,

 

When I start system under traffic some channels hanging up and no way to reset.

 

We have 2 servers and traffic balance between them.

 

But when we restart server each time VG need several minutes to start properly, but callers have no signal and hanging up so VG not forwarding and channels are unavailable.

 

we need tool to hard reset of channel. no way to reset now.

 

Hangup line button is not good enough,

[SupportTeam]

But when we restart server each time VG need several minutes to start properly, but callers have no signal and hanging up so VG not forwarding and channels are unavailable.

 

Yes, it takes a while to start/restart. Until the restart is completed the E1 trunks would not be functioning - so the Telco/PBX/Switch should not be sending any calls to the VoiceGuide system.

 

You should ask the Telco or Switch Admin as to what happens to those calls when the E1 connection is down.

 

 

Please post the ktTel trace as before (.ZIPed) that capture system restart and first hundred or so of calls arriving on the system after restart. We can then see how the system is behaving.

[invoso.com]

After VG restart first connection has long start procedure.

 

In this time some caller thing that nobody answer call.

 

 

Below log file show where VG waiting at first start.

 

180845.203 6 2 1 FindNextVgmTitleInPathList: next module title is=[C:\Program Files\VoiceGuide\Scripts\manager\manager_main.vgs|]

180845.203 6 2 1 script and module specified

180845.203 6 2 1 NewVgsVgm_Goto_Setup dest=C:\Program Files\VoiceGuide\Scripts\manager\manager_main.vgs|, return=|, lSaveSourceOnCallStack=0

180845.203 6 2 1 rv add start ScriptEnd_Time|2013-06-02 18:08:45

180845.203 6 2 1 rv add 2013-06-02 18:08:45

180845.203 6 2 1 rv add start ScriptEnd_Goto_Script|C:\Program Files\VoiceGuide\Scripts\manager\manager_main.vgs

180845.203 6 2 1 rv add C:\Program Files\VoiceGuide\Scripts\manager\manager_main.vgs

180845.203 6 2 1 rv add start ScriptEnd_Goto_Module|

180845.203 6 2 1 rv add

180845.203 6 2 1 WriteToLogFiles_CurrScriptOnly begin

180845.203 6 2 1 WriteToLogFiles_DoWrite begin : strLogFnameLessSuffix=C:\Program Files\VoiceGuide\Scripts\Maciej\prepaid_2011_10_14

180845.203 6 2 1 WriteToLogFiles_DoWrite : log subdirectory exists, strLogFnameLessSuffix=C:\Program Files\VoiceGuide\Scripts\Maciej\log\prepaid_2011_10_14

180848.656 20 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

180849.921 20 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

180851.171 20 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

180852.421 20 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

180853.671 20 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

180854.921 20 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

180903.671 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

180904.921 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

180906.171 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

180907.421 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

180908.671 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

180909.921 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

180911.171 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

180912.421 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

180913.671 4 LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts

180913.843 6 2 1 WriteToLogFiles_DoWrite completed

180913.843 6 dict clsStringDictionaryThreadSafe contructor with dictin. dict.Count=8

180913.843 6 2 1 rv add start ScriptStart_Time|2013-06-02 18:08:45

180913.843 6 2 1 rv add 2013-06-02 18:08:45

180913.843 6 2 1 rv add start ScriptStart_CalledFrom_Script|C:\Program Files\VoiceGuide\Scripts\Maciej\prepaid_2011_10_14.vgp

180913.843 6 2 1 rv add C:\Program Files\VoiceGuide\Scripts\Maciej\prepaid_2011_10_14.vgp

180913.843 6 2 1 rv add start ScriptStart_CalledFrom_Module|DDI

180913.843 6 2 1 rv add DDI

180913.843 6 2 1 FindFullPathToScript_VgsOrVgp start [C:\Program Files\VoiceGuide\Scripts\manager\manager_main.vgs]

180913.843 6 VgsScriptLoad load start [C:\Program Files\VoiceGuide\Scripts\manager\manager_main.vgs] iVgsLoadCounter=2

180913.843 6 VgsScriptLoad iVgsId=2

180913.984 6 VgsScriptLoad about to do ProcessVgsEntry loop

180914.171 6 2 1 loaded [C:\Program Files\VoiceGuide\Scripts\manager\manager_main.vgs] into:2

180914.171 6 2 1 ScriptToRunOnHangup=[C:\Program Files (x86)\VoiceGuide\Scripts\manager\manager_termination.vgs] in NewVgsVgm_SetVgsVgm 1

180914.171 6 2 1 StartModuleDefault=[DDI]

180914.171 6 2 1 ScriptToRunOnHangup=[C:\Program Files (x86)\VoiceGuide\Scripts\manager\manager_termination.vgs] in NewVgsVgm_SetVgsVgm NewVgsVgm_SetActualVgsVgm

180914.187 6 2 1 t timer clear (force=False)

180914.187 6 2 1 RunModule start Evaluate, [DDI], iModuleIdx=159, previous: vgm=159, vgs=2:2

180914.187 6 2 1 state [DDI] Evaluate [$RV_DNIS]

 

This show 28 seconds waiting time when VG executing LoadAnyUpdatedScripts exit as bCurrentlyLoadingNewScripts is this because first script have to calling other one?

 

 

How to eliminate startup pause in this case?

 

 

[SupportTeam]

Every restart will incur a service disruption time during which calls will not be answered, and when a script is ran for the first time it has to be loaded by the system

 

28 seconds to load a script is however excessive.

 

On our test systems we have scripts that are 100KB in size loading and initialized ready for use in less then 1 second.

 

What type of system are you using? Can you please advise system specifications.

 

How high is system CPU running at when the script is being loaded for the first time?

 

Is the posted vgEngine trace taken form trace as is? or were other lines removed to only show activity for one channel?

 

If you can post the manager_main.vgs script then we can replicate this on our test systems and see how long it takes to load and initialise that scipt.

[SupportTeam]

The posted traces show no other calls on system for the 30 seconds.

 

So looks like there were no other calls on the system at that time?

 

Or was the trace edited to remove entries made by other calls?