Voicemail PRO IVR not playing the prompt files

[202586]

I have an IVR in voice mail pro to check the status of ticket number entered by the caller.
everything was working fine, today we noticed that the wav files which were played as the status messages for the ticket number entered are not being played, the caller hears nothing, there is silence for some time and the IVR plays the next block in the call flow or timeouts if the caller doesn't make a choice depending on which block he is, this is happening for all blocks in the application where the IVR skips prompts and go to next node.

I traced the log using DBgview and this is the output...

23/06 08:07:54.562 vmprov5s (00,6) 1290,142c: <VMServer::NothingHappening> <Result :1>
23/06 08:07:54.562 vmprov5s (02,6) 1290,142c: TestConfigChanged:: Should the config be re-loaded?
23/06 08:07:54.562 vmprov5s (02,6) 1290,142c: TestConfigChanged:: File date has NOT changed, so use current call flow
23/06 08:07:54.562 vmprov5s (02,6) 1290,142c: TestConfigChanged:: Config state is correct <State:5>
23/06 08:07:54.562 vmprov5s (09,4) 1290,142c: New VMAIL Client
23/06 08:07:54.562 DbgOut (01,5) 4752,3208: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
23/06 08:07:54.562 DbgOut (01,5) 4752,7612: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
23/06 08:07:54.562 vmprov5s (0c,6) 1290,142c: New Voicemail Client (VMClient object=047610F0)
23/06 08:07:54.562 vmprov5s (0a,5) 1290, c88: OSThreadFunc entered[VMClient, 04761108]
23/06 08:07:54.562 vmprov5s (0c,6) 1290, c88: Message processing for Voicemail Client (VMClient object=047610F0, session=00000067)
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Configuring for known disconnect tone length of 5s
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Configuring for unreliable disconnect setting IDLE time to 30.000s
23/06 08:07:54.562 vmprov5s (06,5) 1290,1dbc: VMClient::RxOpen 047610F0 DSMAIN (4), session=00000067
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Receive OPEN for session 00000067, call-id 5
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Check flags[13] 0 for advising recording
23/06 08:07:54.562 vmprov5s (06,5) 1290,1dbc: VMClient::RxOpen 047610F0 DSMAIN (4), session=00000067
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Receive OPEN for session 00000067, call-id 5
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Access = ACCESS_UNCLUED_VOICEMAIL:
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Mailbox: DSMAIN
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Calling Party:
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Display String: ??>DSMAIN
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Target Party:
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Greeting Modifier:
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Language: ara
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Call Ident: 5
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Call Status: Unknown (0)
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Call Type: External
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Call Direction: Incoming
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Called Party:
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - DDI Number:
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Calling Party Name:
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Called Party Name:
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Found VMPNode DSMAIN
23/06 08:07:54.562 vmprov5s (09,3) 1290,1dbc: Session: 00000067 - Locale ara does not exist, using alternative locale of en
23/06 08:07:54.562 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:07:54.562 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481A4E0) - entered: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:07:54.562 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (VMAIL A:$CID,$CLI) -> (VMAIL A:5,)
23/06 08:07:54.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - GenerateInfo VMAIL A:5,
23/06 08:07:54.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing request to run node DSMAIN.Welcome.1, current stack depth is 0
23/06 08:07:54.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Found node DSMAIN.Welcome.1, and creating an execution point for it
23/06 08:07:54.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing node DSMAIN.Welcome.1, current stack depth is 1 was 0
23/06 08:07:54.578 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:54.578 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:07:54.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481A5A8) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:07:54.578 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (en\custom\Ar-Welcome) -> (en\custom\Ar-Welcome)
23/06 08:07:54.578 vmprov5s (23,5) 1290,1dbc: Succeeded in loading sound bite C:\Program Files\Avaya\IP Office\Voicemail Pro\VM\Wavs\en\custom\Ar-Welcome.WAV [aLaw]
23/06 08:07:54.578 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (enu\custom\Ar-Welcome) -> (enu\custom\Ar-Welcome)
23/06 08:07:54.578 vmprov5s (23,5) 1290,1dbc: Succeeded in loading sound bite C:\Program Files\Avaya\IP Office\Voicemail Pro\VM\Wavs\enu\custom\Ar-Welcome.WAV [aLaw]
23/06 08:07:54.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481A5A8) - left: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:07:54.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Successfully initiated node DSMAIN.Welcome.1, current stack depth is 1 was 0
23/06 08:07:54.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481A4E0) - left: (session=00000067, parent=04789888), recursive_count=(0)
23/06 08:07:54.578 vmprov5s (06,5) 1290,1dbc: VMClient::RxOpen - Created dialog 04789888
23/06 08:07:54.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - - Internal: !Internal!=N
23/06 08:07:55.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Configuring for known disconnect tone length of 5s
23/06 08:07:55.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Configuring for unreliable disconnect setting IDLE time to 30.000s
23/06 08:07:55.562 vmprov5s (06,5) 1290,1dbc: VMClient::RxActive 047610F0 (session=00000067)
23/06 08:07:55.562 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Receive ACTIVE for session 00000067, call-id 5
23/06 08:07:55.609 vmprov5s (26,6) 1290,142c: PBX <200.200.200.91> - Backup active = FALSE, backing up PBX <0.0.0.0>
23/06 08:07:55.609 vmprov5s (26,6) 1290,142c: POLL from 200.200.200.91:4098 contained the following sync info: bBackupActive=0, ulBackupIp=0.0.0.0, uCentralIP=0.0.0.0, tsPeerVMDNS=, tsPeerIPOName=DATASERVE, buf->data[35]=0, buf[31-34]=0.0.0.0
23/06 08:07:57.562 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '2 (50)' at 800, length 240 - session:00000067
23/06 08:07:57.562 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:07:57.562 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.562 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481A670) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (VMAIL A:$CID,$CLI) -> (VMAIL A:5,)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: GenerateInfo VMAIL A:5,
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing request to run node DSMAIN.LANGUAGE.0, current stack depth is 0
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Found node DSMAIN.LANGUAGE.0, and creating an execution point for it
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing node DSMAIN.LANGUAGE.0, current stack depth is 1 was 0
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481A738) - entered: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing request to run node DSMAIN.LANGUAGE.1, current stack depth is 1
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Found node DSMAIN.LANGUAGE.1, and creating an execution point for it
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing node DSMAIN.LANGUAGE.1, current stack depth is 2 was 1
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481A800) - entered: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing request to run node LANGUAGE, current stack depth is 2
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Found node LANGUAGE, and creating an execution point for it
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing node LANGUAGE, current stack depth is 3 was 2
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481A8C8) - entered: (session=00000067, parent=04789888), recursive_count=(5)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing request to run node LANGUAGE.Start Point.1, current stack depth is 3
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Found node LANGUAGE.Start Point.1, and creating an execution point for it
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing node LANGUAGE.Start Point.1, current stack depth is 4 was 3
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481A990) - entered: (session=00000067, parent=04789888), recursive_count=(6)
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481AA58) - entered: (session=00000067, parent=04789888), recursive_count=(8)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing request to run node LANGUAGE.SELECT LANGUAGE.0, current stack depth is 3
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Found node LANGUAGE.SELECT LANGUAGE.0, and creating an execution point for it
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing node LANGUAGE.SELECT LANGUAGE.0, current stack depth is 4 was 3
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481AB20) - entered: (session=00000067, parent=04789888), recursive_count=(9)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing request to run node LANGUAGE.SELECT LANGUAGE.1, current stack depth is 4
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Found node LANGUAGE.SELECT LANGUAGE.1, and creating an execution point for it
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing node LANGUAGE.SELECT LANGUAGE.1, current stack depth is 5 was 4
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481ABE8) - entered: (session=00000067, parent=04789888), recursive_count=(10)
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481ACB0) - entered: (session=00000067, parent=04789888), recursive_count=(12)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing request to run node LANGUAGE.SELECT LANGUAGE.Body.0, current stack depth is 4
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Found node LANGUAGE.SELECT LANGUAGE.Body.0, and creating an execution point for it
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing node LANGUAGE.SELECT LANGUAGE.Body.0, current stack depth is 5 was 4
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481AD78) - entered: (session=00000067, parent=04789888), recursive_count=(13)
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (DS IVR ARA-Prompts CONVERTED\Ar-Language) -> (DS IVR ARA-Prompts CONVERTED\Ar-Language)
23/06 08:07:57.578 vmprov5s (23,5) 1290,1dbc: Succeeded in loading sound bite C:\Program Files\Avaya\IP Office\Voicemail Pro\VM\Wavs\DS IVR ARA-Prompts CONVERTED\Ar-Language.WAV [aLaw]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (DS IVR ARA-Prompts CONVERTED\Ar-Press1) -> (DS IVR ARA-Prompts CONVERTED\Ar-Press1)
23/06 08:07:57.578 vmprov5s (23,5) 1290,1dbc: Succeeded in loading sound bite C:\Program Files\Avaya\IP Office\Voicemail Pro\VM\Wavs\DS IVR ARA-Prompts CONVERTED\Ar-Press1.WAV [aLaw]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (DS IVR ARA-Prompts CONVERTED\Ar-ForEnglish) -> (DS IVR ARA-Prompts CONVERTED\Ar-ForEnglish)
23/06 08:07:57.578 vmprov5s (23,5) 1290,1dbc: Succeeded in loading sound bite C:\Program Files\Avaya\IP Office\Voicemail Pro\VM\Wavs\DS IVR ARA-Prompts CONVERTED\Ar-ForEnglish.WAV [aLaw]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481AD78) - left: (session=00000067, parent=04789888), recursive_count=(12)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Successfully initiated node LANGUAGE.SELECT LANGUAGE.Body.0, current stack depth is 5 was 4
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481ACB0) - left: (session=00000067, parent=04789888), recursive_count=(11)
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481ABE8) - left: (session=00000067, parent=04789888), recursive_count=(9)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Successfully initiated node LANGUAGE.SELECT LANGUAGE.1, current stack depth is 5 was 4
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481AB20) - left: (session=00000067, parent=04789888), recursive_count=(8)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Successfully initiated node LANGUAGE.SELECT LANGUAGE.0, current stack depth is 5 was 3
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481AA58) - left: (session=00000067, parent=04789888), recursive_count=(7)
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481A990) - left: (session=00000067, parent=04789888), recursive_count=(5)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Successfully initiated node LANGUAGE.Start Point.1, current stack depth is 5 was 3
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481A8C8) - left: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Successfully initiated node LANGUAGE, current stack depth is 5 was 2
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481A800) - left: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Successfully initiated node DSMAIN.LANGUAGE.1, current stack depth is 5 was 1
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481A738) - left: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Successfully initiated node DSMAIN.LANGUAGE.0, current stack depth is 5 was 0
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481A670) - left: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing request to run node LANGUAGE.Switch to English US.0, current stack depth is 5
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Found node LANGUAGE.Switch to English US.0, and creating an execution point for it
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing node LANGUAGE.Switch to English US.0, current stack depth is 6 was 5
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481AE40) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing request to run node LANGUAGE.Switch to English US.1, current stack depth is 6
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Found node LANGUAGE.Switch to English US.1, and creating an execution point for it
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing node LANGUAGE.Switch to English US.1, current stack depth is 7 was 6
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481AF08) - entered: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (ENU) -> (ENU)
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7008) - entered: (session=00000067, parent=04789888), recursive_count=(5)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing request to run node LANGUAGE.ARA-enu.0, current stack depth is 6
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Found node LANGUAGE.ARA-enu.0, and creating an execution point for it
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing node LANGUAGE.ARA-enu.0, current stack depth is 7 was 6
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A70D0) - entered: (session=00000067, parent=04789888), recursive_count=(6)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing request to run node LANGUAGE.ARA-enu.1, current stack depth is 7
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Found node LANGUAGE.ARA-enu.1, and creating an execution point for it
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing node LANGUAGE.ARA-enu.1, current stack depth is 8 was 7
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7198) - entered: (session=00000067, parent=04789888), recursive_count=(7)
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (ARA-enu) -> (ARA-enu)
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7260) - entered: (session=00000067, parent=04789888), recursive_count=(8)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing request to run node DSMAIN.COUNTER.0, current stack depth is 1
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Found node DSMAIN.COUNTER.0, and creating an execution point for it
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing node DSMAIN.COUNTER.0, current stack depth is 2 was 1
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7328) - entered: (session=00000067, parent=04789888), recursive_count=(9)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing request to run node DSMAIN.COUNTER.1, current stack depth is 2
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Found node DSMAIN.COUNTER.1, and creating an execution point for it
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing node DSMAIN.COUNTER.1, current stack depth is 3 was 2
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A73F0) - entered: (session=00000067, parent=04789888), recursive_count=(10)
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A74B8) - entered: (session=00000067, parent=04789888), recursive_count=(12)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing request to run node DSMAIN.GETID.0, current stack depth is 2
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Found node DSMAIN.GETID.0, and creating an execution point for it
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing node DSMAIN.GETID.0, current stack depth is 3 was 2
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7580) - entered: (session=00000067, parent=04789888), recursive_count=(13)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing request to run node DSMAIN.GETID.1, current stack depth is 3
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Found node DSMAIN.GETID.1, and creating an execution point for it
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing node DSMAIN.GETID.1, current stack depth is 4 was 3
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7648) - entered: (session=00000067, parent=04789888), recursive_count=(14)
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7710) - entered: (session=00000067, parent=04789888), recursive_count=(16)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing request to run node DSMAIN.GETID.Body.0, current stack depth is 3
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Found node DSMAIN.GETID.Body.0, and creating an execution point for it
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Executing node DSMAIN.GETID.Body.0, current stack depth is 4 was 3
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:07:57.578 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A77D8) - entered: (session=00000067, parent=04789888), recursive_count=(17)
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (VMAIL A:$CID,$CLI) -> (VMAIL A:5,)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: GenerateInfo VMAIL A:5,
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute ($LOC\custom\Ar-Enterid) -> (enu\custom\Ar-Enterid)
23/06 08:07:57.578 vmprov5s (23,5) 1290,1dbc: Succeeded in loading sound bite C:\Program Files\Avaya\IP Office\Voicemail Pro\VM\Wavs\enu\custom\Ar-Enterid.WAV [aLaw]
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A77D8) - left: (session=00000067, parent=04789888), recursive_count=(16)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Successfully initiated node DSMAIN.GETID.Body.0, current stack depth is 4 was 3
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7710) - left: (session=00000067, parent=04789888), recursive_count=(15)
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7648) - left: (session=00000067, parent=04789888), recursive_count=(13)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Successfully initiated node DSMAIN.GETID.1, current stack depth is 4 was 3
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7580) - left: (session=00000067, parent=04789888), recursive_count=(12)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Successfully initiated node DSMAIN.GETID.0, current stack depth is 4 was 2
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A74B8) - left: (session=00000067, parent=04789888), recursive_count=(11)
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A73F0) - left: (session=00000067, parent=04789888), recursive_count=(9)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Successfully initiated node DSMAIN.COUNTER.1, current stack depth is 4 was 2
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7328) - left: (session=00000067, parent=04789888), recursive_count=(8)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Successfully initiated node DSMAIN.COUNTER.0, current stack depth is 4 was 1
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7260) - left: (session=00000067, parent=04789888), recursive_count=(7)
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7198) - left: (session=00000067, parent=04789888), recursive_count=(6)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Successfully initiated node LANGUAGE.ARA-enu.1, current stack depth is 4 was 7
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A70D0) - left: (session=00000067, parent=04789888), recursive_count=(5)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Successfully initiated node LANGUAGE.ARA-enu.0, current stack depth is 4 was 6
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7008) - left: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481AF08) - left: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Successfully initiated node LANGUAGE.Switch to English US.1, current stack depth is 4 was 6
23/06 08:07:57.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(0481AE40) - left: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:07:57.578 vmprov5s (09,4) 1290,1dbc: Successfully initiated node LANGUAGE.Switch to English US.0, current stack depth is 4 was 5
23/06 08:08:01.062 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '9 (57)' at 320, length 240 - session:00000067
23/06 08:08:01.312 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '9 (57)' at 600, length 240 - session:00000067
23/06 08:08:01.812 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '9 (57)' at 40, length 240 - session:00000067
23/06 08:08:02.062 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '9 (57)' at 280, length 240 - session:00000067
23/06 08:08:02.312 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '# (35)' at 520, length 240 - session:00000067
23/06 08:08:02.312 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing request to run node DSMAIN.Store ID.0, current stack depth is 4
23/06 08:08:02.312 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Found node DSMAIN.Store ID.0, and creating an execution point for it
23/06 08:08:02.312 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing node DSMAIN.Store ID.0, current stack depth is 5 was 4
23/06 08:08:02.312 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:02.312 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A78A0) - entered: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:02.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing request to run node DSMAIN.Store ID.1, current stack depth is 5
23/06 08:08:02.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Found node DSMAIN.Store ID.1, and creating an execution point for it
23/06 08:08:02.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing node DSMAIN.Store ID.1, current stack depth is 6 was 5
23/06 08:08:02.328 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:02.328 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7968) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute ($KEY) -> (9999)
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:08:02.328 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:02.328 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7A30) - entered: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:08:02.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing request to run node DSMAIN.GETPWD.0, current stack depth is 5
23/06 08:08:02.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Found node DSMAIN.GETPWD.0, and creating an execution point for it
23/06 08:08:02.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing node DSMAIN.GETPWD.0, current stack depth is 6 was 5
23/06 08:08:02.328 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:02.328 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7AF8) - entered: (session=00000067, parent=04789888), recursive_count=(5)
23/06 08:08:02.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing request to run node DSMAIN.GETPWD.1, current stack depth is 6
23/06 08:08:02.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Found node DSMAIN.GETPWD.1, and creating an execution point for it
23/06 08:08:02.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing node DSMAIN.GETPWD.1, current stack depth is 7 was 6
23/06 08:08:02.328 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:02.328 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7BC0) - entered: (session=00000067, parent=04789888), recursive_count=(6)
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:08:02.328 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:02.328 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7C88) - entered: (session=00000067, parent=04789888), recursive_count=(8)
23/06 08:08:02.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing request to run node DSMAIN.GETPWD.Body.0, current stack depth is 6
23/06 08:08:02.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Found node DSMAIN.GETPWD.Body.0, and creating an execution point for it
23/06 08:08:02.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing node DSMAIN.GETPWD.Body.0, current stack depth is 7 was 6
23/06 08:08:02.328 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:02.328 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7D50) - entered: (session=00000067, parent=04789888), recursive_count=(9)
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute ($LOC\custom\Ar-Enterpassword) -> (enu\custom\Ar-Enterpassword)
23/06 08:08:02.328 vmprov5s (23,5) 1290,1dbc: Succeeded in loading sound bite C:\Program Files\Avaya\IP Office\Voicemail Pro\VM\Wavs\enu\custom\Ar-Enterpassword.WAV [aLaw]
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7D50) - left: (session=00000067, parent=04789888), recursive_count=(8)
23/06 08:08:02.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Successfully initiated node DSMAIN.GETPWD.Body.0, current stack depth is 7 was 6
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7C88) - left: (session=00000067, parent=04789888), recursive_count=(7)
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7BC0) - left: (session=00000067, parent=04789888), recursive_count=(5)
23/06 08:08:02.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Successfully initiated node DSMAIN.GETPWD.1, current stack depth is 7 was 6
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7AF8) - left: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:08:02.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Successfully initiated node DSMAIN.GETPWD.0, current stack depth is 7 was 5
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7A30) - left: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7968) - left: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:02.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Successfully initiated node DSMAIN.Store ID.1, current stack depth is 7 was 5
23/06 08:08:02.328 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A78A0) - left: (session=00000067, parent=04789888), recursive_count=(0)
23/06 08:08:02.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Successfully initiated node DSMAIN.Store ID.0, current stack depth is 7 was 4
23/06 08:08:05.609 vmprov5s (26,6) 1290,142c: PBX <200.200.200.91> - Backup active = FALSE, backing up PBX <0.0.0.0>
23/06 08:08:05.609 vmprov5s (26,6) 1290,142c: POLL from 200.200.200.91:4098 contained the following sync info: bBackupActive=0, ulBackupIp=0.0.0.0, uCentralIP=0.0.0.0, tsPeerVMDNS=, tsPeerIPOName=DATASERVE, buf->data[35]=0, buf[31-34]=0.0.0.0
23/06 08:08:05.953 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '3 (51)' at 200, length 240 - session:00000067
23/06 08:08:06.203 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '3 (51)' at 1000, length 240 - session:00000067
23/06 08:08:06.828 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '3 (51)' at 640, length 240 - session:00000067
23/06 08:08:07.203 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '3 (51)' at 120, length 240 - session:00000067
23/06 08:08:07.578 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '# (35)' at 760, length 240 - session:00000067
23/06 08:08:07.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing request to run node DSMAIN.Store PWD.0, current stack depth is 7
23/06 08:08:07.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Found node DSMAIN.Store PWD.0, and creating an execution point for it
23/06 08:08:07.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing node DSMAIN.Store PWD.0, current stack depth is 8 was 7
23/06 08:08:07.578 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.578 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7E18) - entered: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:07.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing request to run node DSMAIN.Store PWD.1, current stack depth is 8
23/06 08:08:07.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Found node DSMAIN.Store PWD.1, and creating an execution point for it
23/06 08:08:07.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing node DSMAIN.Store PWD.1, current stack depth is 9 was 8
23/06 08:08:07.578 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.578 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7EE0) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:07.578 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute ($KEY) -> (3333)
23/06 08:08:07.578 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:08:07.578 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.578 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7FA8) - entered: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:08:07.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing request to run node DSMAIN.OpenDBLogin.0, current stack depth is 8
23/06 08:08:07.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Found node DSMAIN.OpenDBLogin.0, and creating an execution point for it
23/06 08:08:07.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing node DSMAIN.OpenDBLogin.0, current stack depth is 9 was 8
23/06 08:08:07.578 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.578 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A8070) - entered: (session=00000067, parent=04789888), recursive_count=(5)
23/06 08:08:07.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing request to run node DSMAIN.OpenDBLogin.1, current stack depth is 9
23/06 08:08:07.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Found node DSMAIN.OpenDBLogin.1, and creating an execution point for it
23/06 08:08:07.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing node DSMAIN.OpenDBLogin.1, current stack depth is 10 was 9
23/06 08:08:07.578 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.578 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A8138) - entered: (session=00000067, parent=04789888), recursive_count=(6)
23/06 08:08:07.578 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.578 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A8138) - left: (session=00000067, parent=04789888), recursive_count=(5)
23/06 08:08:07.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Successfully initiated node DSMAIN.OpenDBLogin.1, current stack depth is 10 was 9
23/06 08:08:07.578 DbgOut (01,5) 4752,3720: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
23/06 08:08:07.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A8070) - left: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:08:07.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Successfully initiated node DSMAIN.OpenDBLogin.0, current stack depth is 10 was 8
23/06 08:08:07.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7FA8) - left: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:07.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7EE0) - left: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:07.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Successfully initiated node DSMAIN.Store PWD.1, current stack depth is 10 was 8
23/06 08:08:07.578 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A7E18) - left: (session=00000067, parent=04789888), recursive_count=(0)
23/06 08:08:07.578 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Successfully initiated node DSMAIN.Store PWD.0, current stack depth is 10 was 7
23/06 08:08:07.578 vmprov5s (0a,5) 1290, e88: OSThreadFunc entered[DatabaseApp, 0477E668]
23/06 08:08:07.593 vmprov5s (02,6) 1290, e88: Session: 00000067, Substitute (Success) -> (Success)
23/06 08:08:07.593 vmprov5s (09,5) 1290, e88: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.593 vmprov5s (09,5) 1290, e88: PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.593 vmprov5s (02,6) 1290, e88: IVRNodePlayer::Begin(047A82D0) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:07.593 vmprov5s (09,4) 1290, e88: Executing request to run node DSMAIN.CHECK LOGIN.0, current stack depth is 9
23/06 08:08:07.593 vmprov5s (09,4) 1290, e88: Found node DSMAIN.CHECK LOGIN.0, and creating an execution point for it
23/06 08:08:07.593 vmprov5s (09,4) 1290, e88: Executing node DSMAIN.CHECK LOGIN.0, current stack depth is 10 was 9
23/06 08:08:07.593 vmprov5s (09,5) 1290, e88: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.593 vmprov5s (09,5) 1290, e88: PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.593 vmprov5s (02,6) 1290, e88: IVRNodePlayer::Begin(047A8398) - entered: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:07.593 vmprov5s (09,4) 1290, e88: Executing request to run node DSMAIN.CHECK LOGIN.1, current stack depth is 10
23/06 08:08:07.593 vmprov5s (09,4) 1290, e88: Found node DSMAIN.CHECK LOGIN.1, and creating an execution point for it
23/06 08:08:07.593 vmprov5s (09,4) 1290, e88: Executing node DSMAIN.CHECK LOGIN.1, current stack depth is 11 was 10
23/06 08:08:07.593 vmprov5s (09,5) 1290, e88: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.593 vmprov5s (09,5) 1290, e88: PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.593 vmprov5s (02,6) 1290, e88: IVRNodePlayer::Begin(047A8460) - entered: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:08:07.593 vmprov5s (02,6) 1290, e88: Session: 00000067, Substitute (SELECT customer_id, pw

FROM ivr_system

WHERE (customer_id = '$CP1') AND (pw = '$CP2') -> (SELECT customer_id, pw

FROM ivr_system

WHERE (customer_id = '9999') AND (pw = '3333')
23/06 08:08:07.593 vmprov5s (09,5) 1290, e88: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.593 vmprov5s (09,5) 1290, e88: PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.593 vmprov5s (02,6) 1290, e88: IVRNodePlayer::Begin(047A8460) - left: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:07.593 vmprov5s (09,4) 1290, e88: Successfully initiated node DSMAIN.CHECK LOGIN.1, current stack depth is 11 was 10
23/06 08:08:07.593 vmprov5s (02,6) 1290, e88: IVRNodePlayer::Begin(047A8398) - left: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:07.593 vmprov5s (09,4) 1290, e88: Successfully initiated node DSMAIN.CHECK LOGIN.0, current stack depth is 11 was 9
23/06 08:08:07.593 vmprov5s (02,6) 1290, e88: IVRNodePlayer::Begin(047A82D0) - left: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:07.593 vmprov5s (0a,5) 1290, e88: OSThreadFunc exited[DatabaseApp, 0477E668]
23/06 08:08:07.593 DbgOut (01,5) 4752,3720: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_DETACH)
23/06 08:08:07.593 DbgOut (01,5) 4752,4960: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
23/06 08:08:07.593 vmprov5s (0a,5) 1290,1360: OSThreadFunc entered[DatabaseApp, 0477EB48]
23/06 08:08:07.593 vmprov5s (02,6) 1290,1360: Session: 00000067, Substitute (Success) -> (Success)
23/06 08:08:07.593 vmprov5s (09,5) 1290,1360: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.593 vmprov5s (09,5) 1290,1360: PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.593 vmprov5s (02,6) 1290,1360: IVRNodePlayer::Begin(047A85F8) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:07.593 vmprov5s (09,4) 1290,1360: Executing request to run node DSMAIN.GET DB RESULT.0, current stack depth is 10
23/06 08:08:07.593 vmprov5s (09,4) 1290,1360: Found node DSMAIN.GET DB RESULT.0, and creating an execution point for it
23/06 08:08:07.593 vmprov5s (09,4) 1290,1360: Executing node DSMAIN.GET DB RESULT.0, current stack depth is 11 was 10
23/06 08:08:07.593 vmprov5s (09,5) 1290,1360: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.593 vmprov5s (09,5) 1290,1360: PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.593 vmprov5s (02,6) 1290,1360: IVRNodePlayer::Begin(047A86C0) - entered: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:07.593 vmprov5s (09,4) 1290,1360: Executing request to run node DSMAIN.GET DB RESULT.1, current stack depth is 11
23/06 08:08:07.593 vmprov5s (09,4) 1290,1360: Found node DSMAIN.GET DB RESULT.1, and creating an execution point for it
23/06 08:08:07.593 vmprov5s (09,4) 1290,1360: Executing node DSMAIN.GET DB RESULT.1, current stack depth is 12 was 11
23/06 08:08:07.593 vmprov5s (09,5) 1290,1360: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.593 vmprov5s (09,5) 1290,1360: PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.593 vmprov5s (02,6) 1290,1360: IVRNodePlayer::Begin(047A8788) - entered: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:08:07.593 vmprov5s (09,5) 1290,1360: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.593 vmprov5s (09,5) 1290,1360: PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.593 vmprov5s (02,6) 1290,1360: IVRNodePlayer::Begin(047A8788) - left: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:07.593 vmprov5s (09,4) 1290,1360: Successfully initiated node DSMAIN.GET DB RESULT.1, current stack depth is 12 was 11
23/06 08:08:07.593 vmprov5s (02,6) 1290,1360: IVRNodePlayer::Begin(047A86C0) - left: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:07.593 vmprov5s (09,4) 1290,1360: Successfully initiated node DSMAIN.GET DB RESULT.0, current stack depth is 12 was 10
23/06 08:08:07.593 vmprov5s (02,6) 1290,1360: IVRNodePlayer::Begin(047A85F8) - left: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:07.593 vmprov5s (0a,5) 1290,1360: OSThreadFunc exited[DatabaseApp, 0477EB48]
23/06 08:08:07.593 DbgOut (01,5) 4752,4960: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_DETACH)
23/06 08:08:07.593 DbgOut (01,5) 4752,5968: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
23/06 08:08:07.593 vmprov5s (0a,5) 1290,1750: OSThreadFunc entered[DatabaseApp, 0477E668]
23/06 08:08:07.593 vmprov5s (02,6) 1290,1750: Session: 00000067, Substitute (9999) -> (9999)
23/06 08:08:07.593 vmprov5s (02,6) 1290,1750: Session: 00000067, Substitute (3333) -> (3333)
23/06 08:08:07.593 vmprov5s (02,6) 1290,1750: Session: 00000067, Substitute (Success) -> (Success)
23/06 08:08:07.593 vmprov5s (09,5) 1290,1750: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.593 vmprov5s (09,5) 1290,1750: PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.593 vmprov5s (02,6) 1290,1750: IVRNodePlayer::Begin(047A8920) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:07.593 vmprov5s (09,4) 1290,1750: Executing request to run node DSMAIN.MAINMENU.0, current stack depth is 11
23/06 08:08:07.593 vmprov5s (09,4) 1290,1750: Found node DSMAIN.MAINMENU.0, and creating an execution point for it
23/06 08:08:07.593 vmprov5s (09,4) 1290,1750: Executing node DSMAIN.MAINMENU.0, current stack depth is 12 was 11
23/06 08:08:07.593 vmprov5s (09,5) 1290,1750: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.593 vmprov5s (09,5) 1290,1750: PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.593 vmprov5s (02,6) 1290,1750: IVRNodePlayer::Begin(047A89E8) - entered: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:07.593 vmprov5s (09,4) 1290,1750: Executing request to run node DSMAIN.MAINMENU.1, current stack depth is 12
23/06 08:08:07.593 vmprov5s (09,4) 1290,1750: Found node DSMAIN.MAINMENU.1, and creating an execution point for it
23/06 08:08:07.593 vmprov5s (09,4) 1290,1750: Executing node DSMAIN.MAINMENU.1, current stack depth is 13 was 12
23/06 08:08:07.593 vmprov5s (09,5) 1290,1750: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.593 vmprov5s (09,5) 1290,1750: PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.593 vmprov5s (02,6) 1290,1750: IVRNodePlayer::Begin(047A8AB0) - entered: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:08:07.593 vmprov5s (02,6) 1290,1750: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:08:07.593 vmprov5s (09,5) 1290,1750: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.593 vmprov5s (09,5) 1290,1750: PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.593 vmprov5s (02,6) 1290,1750: IVRNodePlayer::Begin(047A8B78) - entered: (session=00000067, parent=04789888), recursive_count=(6)
23/06 08:08:07.593 vmprov5s (09,4) 1290,1750: Executing request to run node DSMAIN.MAINMENU.Body.0, current stack depth is 12
23/06 08:08:07.593 vmprov5s (09,4) 1290,1750: Found node DSMAIN.MAINMENU.Body.0, and creating an execution point for it
23/06 08:08:07.593 vmprov5s (09,4) 1290,1750: Executing node DSMAIN.MAINMENU.Body.0, current stack depth is 13 was 12
23/06 08:08:07.593 vmprov5s (09,5) 1290,1750: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:07.593 vmprov5s (09,5) 1290,1750: PlayNode::AddRef, RefCount = [2]
23/06 08:08:07.593 vmprov5s (02,6) 1290,1750: IVRNodePlayer::Begin(047A8C40) - entered: (session=00000067, parent=04789888), recursive_count=(7)
23/06 08:08:07.593 vmprov5s (02,6) 1290,1750: Session: 00000067, Substitute ($LOC\custom\Ar-Customer) -> (enu\custom\Ar-Customer)
23/06 08:08:07.593 vmprov5s (23,5) 1290,1750: Succeeded in loading sound bite C:\Program Files\Avaya\IP Office\Voicemail Pro\VM\Wavs\enu\custom\Ar-Customer.WAV [aLaw]
23/06 08:08:07.593 vmprov5s (02,6) 1290,1750: Session: 00000067, Substitute ($LOC\custom\Ar-Services) -> (enu\custom\Ar-Services)
23/06 08:08:07.593 vmprov5s (23,5) 1290,1750: Succeeded in loading sound bite C:\Program Files\Avaya\IP Office\Voicemail Pro\VM\Wavs\enu\custom\Ar-Services.WAV [aLaw]
23/06 08:08:07.593 vmprov5s (02,6) 1290,1750: Session: 00000067, Substitute ($LOC\custom\Ar-ServiceDesk) -> (enu\custom\Ar-ServiceDesk)
23/06 08:08:07.609 vmprov5s (23,5) 1290,1750: Succeeded in loading sound bite C:\Program Files\Avaya\IP Office\Voicemail Pro\VM\Wavs\enu\custom\Ar-ServiceDesk.WAV [aLaw]
23/06 08:08:07.609 vmprov5s (02,6) 1290,1750: Session: 00000067, Substitute ($LOC\custom\Ar-ChangePassword) -> (enu\custom\Ar-ChangePassword)
23/06 08:08:07.609 vmprov5s (23,5) 1290,1750: Succeeded in loading sound bite C:\Program Files\Avaya\IP Office\Voicemail Pro\VM\Wavs\enu\custom\Ar-ChangePassword.WAV [aLaw]
23/06 08:08:07.609 vmprov5s (02,6) 1290,1750: IVRNodePlayer::Begin(047A8C40) - left: (session=00000067, parent=04789888), recursive_count=(6)
23/06 08:08:07.609 vmprov5s (09,4) 1290,1750: Session: 00000067 - Successfully initiated node DSMAIN.MAINMENU.Body.0, current stack depth is 13 was 12
23/06 08:08:07.609 vmprov5s (02,6) 1290,1750: IVRNodePlayer::Begin(047A8B78) - left: (session=00000067, parent=04789888), recursive_count=(5)
23/06 08:08:07.609 vmprov5s (02,6) 1290,1750: IVRNodePlayer::Begin(047A8AB0) - left: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:07.609 vmprov5s (09,4) 1290,1750: Session: 00000067 - Successfully initiated node DSMAIN.MAINMENU.1, current stack depth is 13 was 12
23/06 08:08:07.609 vmprov5s (02,6) 1290,1750: IVRNodePlayer::Begin(047A89E8) - left: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:07.609 vmprov5s (09,4) 1290,1750: Session: 00000067 - Successfully initiated node DSMAIN.MAINMENU.0, current stack depth is 13 was 11
23/06 08:08:07.609 vmprov5s (02,6) 1290,1750: IVRNodePlayer::Begin(047A8920) - left: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:07.609 vmprov5s (0a,5) 1290,1750: OSThreadFunc exited[DatabaseApp, 0477E668]
23/06 08:08:07.609 DbgOut (01,5) 4752,5968: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_DETACH)
23/06 08:08:15.609 vmprov5s (26,6) 1290,142c: PBX <200.200.200.91> - Backup active = FALSE, backing up PBX <0.0.0.0>
23/06 08:08:15.609 vmprov5s (26,6) 1290,142c: POLL from 200.200.200.91:4098 contained the following sync info: bBackupActive=0, ulBackupIp=0.0.0.0, uCentralIP=0.0.0.0, tsPeerVMDNS=, tsPeerIPOName=DATASERVE, buf->data[35]=0, buf[31-34]=0.0.0.0
23/06 08:08:23.328 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '2 (50)' at 360, length 240 - session:00000067
23/06 08:08:23.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing request to run node DSMAIN.HELPDESK.0, current stack depth is 13
23/06 08:08:23.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Found node DSMAIN.HELPDESK.0, and creating an execution point for it
23/06 08:08:23.328 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing node DSMAIN.HELPDESK.0, current stack depth is 14 was 13
23/06 08:08:23.328 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:23.328 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:23.343 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(048503F0) - entered: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:23.343 vmprov5s (09,4) 1290,1dbc: Executing request to run node DSMAIN.HELPDESK.1, current stack depth is 14
23/06 08:08:23.343 vmprov5s (09,4) 1290,1dbc: Found node DSMAIN.HELPDESK.1, and creating an execution point for it
23/06 08:08:23.343 vmprov5s (09,4) 1290,1dbc: Executing node DSMAIN.HELPDESK.1, current stack depth is 15 was 14
23/06 08:08:23.343 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:23.343 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:08:23.343 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(048504B8) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:23.343 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:08:23.343 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:23.343 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:08:23.343 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(04850580) - entered: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:08:23.343 vmprov5s (09,4) 1290,1dbc: Executing request to run node DSMAIN.HELPDESK.Body.0, current stack depth is 14
23/06 08:08:23.343 vmprov5s (09,4) 1290,1dbc: Found node DSMAIN.HELPDESK.Body.0, and creating an execution point for it
23/06 08:08:23.343 vmprov5s (09,4) 1290,1dbc: Executing node DSMAIN.HELPDESK.Body.0, current stack depth is 15 was 14
23/06 08:08:23.343 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:23.343 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:08:23.343 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(04850648) - entered: (session=00000067, parent=04789888), recursive_count=(5)
23/06 08:08:23.343 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute ($LOC\custom\Ar-Ticketstatus) -> (enu\custom\Ar-Ticketstatus)
23/06 08:08:23.343 vmprov5s (23,5) 1290,1dbc: Succeeded in loading sound bite C:\Program Files\Avaya\IP Office\Voicemail Pro\VM\Wavs\enu\custom\Ar-Ticketstatus.WAV [aLaw]
23/06 08:08:23.343 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute ($LOC\custom\Ar-OpenTicket) -> (enu\custom\Ar-OpenTicket)
23/06 08:08:23.343 vmprov5s (23,5) 1290,1dbc: Succeeded in loading sound bite C:\Program Files\Avaya\IP Office\Voicemail Pro\VM\Wavs\enu\custom\Ar-OpenTicket.WAV [aLaw]
23/06 08:08:23.343 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute ($LOC\custom\Ar-PreviousMenu) -> (enu\custom\Ar-PreviousMenu)
23/06 08:08:23.343 vmprov5s (23,5) 1290,1dbc: Succeeded in loading sound bite C:\Program Files\Avaya\IP Office\Voicemail Pro\VM\Wavs\enu\custom\Ar-PreviousMenu.WAV [aLaw]
23/06 08:08:23.343 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(04850648) - left: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:08:23.343 vmprov5s (09,4) 1290,1dbc: Successfully initiated node DSMAIN.HELPDESK.Body.0, current stack depth is 15 was 14
23/06 08:08:23.343 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(04850580) - left: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:23.343 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(048504B8) - left: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:23.343 vmprov5s (09,4) 1290,1dbc: Successfully initiated node DSMAIN.HELPDESK.1, current stack depth is 15 was 14
23/06 08:08:23.343 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(048503F0) - left: (session=00000067, parent=04789888), recursive_count=(0)
23/06 08:08:23.343 vmprov5s (09,4) 1290,1dbc: Successfully initiated node DSMAIN.HELPDESK.0, current stack depth is 15 was 13
23/06 08:08:25.609 vmprov5s (26,6) 1290,142c: PBX <200.200.200.91> - Backup active = FALSE, backing up PBX <0.0.0.0>
23/06 08:08:25.609 vmprov5s (26,6) 1290,142c: POLL from 200.200.200.91:4098 contained the following sync info: bBackupActive=0, ulBackupIp=0.0.0.0, uCentralIP=0.0.0.0, tsPeerVMDNS=, tsPeerIPOName=DATASERVE, buf->data[35]=0, buf[31-34]=0.0.0.0
23/06 08:08:26.781 DbgOut (01,5) 7900,7240: DllMain(hinstDLL=0x04000000, fdwReason=DLL_THREAD_ATTACH)
23/06 08:08:26.781 DbgOut (01,5) 7900,7240: DllMain(hinstDLL=0x04000000, fdwReason=DLL_THREAD_DETACH)
23/06 08:08:35.609 vmprov5s (26,6) 1290,142c: PBX <200.200.200.91> - Backup active = FALSE, backing up PBX <0.0.0.0>
23/06 08:08:35.609 vmprov5s (26,6) 1290,142c: POLL from 200.200.200.91:4098 contained the following sync info: bBackupActive=0, ulBackupIp=0.0.0.0, uCentralIP=0.0.0.0, tsPeerVMDNS=, tsPeerIPOName=DATASERVE, buf->data[35]=0, buf[31-34]=0.0.0.0
23/06 08:08:36.078 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '1 (49)' at 840, length 240 - session:00000067
23/06 08:08:36.078 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing request to run node DSMAIN.OpenDBTicket.0, current stack depth is 15
23/06 08:08:36.078 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Found node DSMAIN.OpenDBTicket.0, and creating an execution point for it
23/06 08:08:36.078 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing node DSMAIN.OpenDBTicket.0, current stack depth is 16 was 15
23/06 08:08:36.078 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:36.078 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:36.093 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(04850710) - entered: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:36.093 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (VMAIL A:$CID,$CLI) -> (VMAIL A:5,)
23/06 08:08:36.093 vmprov5s (09,4) 1290,1dbc: GenerateInfo VMAIL A:5,
23/06 08:08:36.093 vmprov5s (09,4) 1290,1dbc: Executing request to run node DSMAIN.OpenDBTicket.1, current stack depth is 16
23/06 08:08:36.093 vmprov5s (09,4) 1290,1dbc: Found node DSMAIN.OpenDBTicket.1, and creating an execution point for it
23/06 08:08:36.093 vmprov5s (09,4) 1290,1dbc: Executing node DSMAIN.OpenDBTicket.1, current stack depth is 17 was 16
23/06 08:08:36.093 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:36.093 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:08:36.093 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(048507D8) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:36.093 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:36.093 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:08:36.093 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(048507D8) - left: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:36.093 vmprov5s (09,4) 1290,1dbc: Successfully initiated node DSMAIN.OpenDBTicket.1, current stack depth is 17 was 16
23/06 08:08:36.093 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(04850710) - left: (session=00000067, parent=04789888), recursive_count=(0)
23/06 08:08:36.093 vmprov5s (09,4) 1290,1dbc: Successfully initiated node DSMAIN.OpenDBTicket.0, current stack depth is 17 was 15
23/06 08:08:36.093 DbgOut (01,5) 4752,3940: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
23/06 08:08:36.093 vmprov5s (0a,5) 1290, f64: OSThreadFunc entered[DatabaseApp, 0477E668]
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: Session: 00000067, Substitute (Success) -> (Success)
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, RefCount = [2]
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: IVRNodePlayer::Begin(04850970) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: Session: 00000067, Substitute (VMAIL A:$CID,$CLI) -> (VMAIL A:5,)
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: GenerateInfo VMAIL A:5,
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Executing request to run node DSMAIN.GET TICKET.0, current stack depth is 16
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Found node DSMAIN.GET TICKET.0, and creating an execution point for it
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Executing node DSMAIN.GET TICKET.0, current stack depth is 17 was 16
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, RefCount = [2]
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: IVRNodePlayer::Begin(04850A38) - entered: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Executing request to run node DSMAIN.GET TICKET.1, current stack depth is 17
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Found node DSMAIN.GET TICKET.1, and creating an execution point for it
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Executing node DSMAIN.GET TICKET.1, current stack depth is 18 was 17
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, RefCount = [2]
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: IVRNodePlayer::Begin(04850B00) - entered: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, RefCount = [2]
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: IVRNodePlayer::Begin(04850BC8) - entered: (session=00000067, parent=04789888), recursive_count=(6)
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Executing request to run node DSMAIN.GET TICKET.Body.0, current stack depth is 17
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Found node DSMAIN.GET TICKET.Body.0, and creating an execution point for it
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Executing node DSMAIN.GET TICKET.Body.0, current stack depth is 18 was 17
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, ReleaseRef = [1]

 

[202586]

23/06 08:08:36.078 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:36.093 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(04850710) - entered: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:36.093 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (VMAIL A:$CID,$CLI) -> (VMAIL A:5,)
23/06 08:08:36.093 vmprov5s (09,4) 1290,1dbc: GenerateInfo VMAIL A:5,
23/06 08:08:36.093 vmprov5s (09,4) 1290,1dbc: Executing request to run node DSMAIN.OpenDBTicket.1, current stack depth is 16
23/06 08:08:36.093 vmprov5s (09,4) 1290,1dbc: Found node DSMAIN.OpenDBTicket.1, and creating an execution point for it
23/06 08:08:36.093 vmprov5s (09,4) 1290,1dbc: Executing node DSMAIN.OpenDBTicket.1, current stack depth is 17 was 16
23/06 08:08:36.093 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:36.093 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:08:36.093 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(048507D8) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:36.093 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:36.093 vmprov5s (09,5) 1290,1dbc: PlayNode::AddRef, RefCount = [2]
23/06 08:08:36.093 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(048507D8) - left: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:36.093 vmprov5s (09,4) 1290,1dbc: Successfully initiated node DSMAIN.OpenDBTicket.1, current stack depth is 17 was 16
23/06 08:08:36.093 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(04850710) - left: (session=00000067, parent=04789888), recursive_count=(0)
23/06 08:08:36.093 vmprov5s (09,4) 1290,1dbc: Successfully initiated node DSMAIN.OpenDBTicket.0, current stack depth is 17 was 15
23/06 08:08:36.093 DbgOut (01,5) 4752,3940: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
23/06 08:08:36.093 vmprov5s (0a,5) 1290, f64: OSThreadFunc entered[DatabaseApp, 0477E668]
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: Session: 00000067, Substitute (Success) -> (Success)
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, RefCount = [2]
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: IVRNodePlayer::Begin(04850970) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: Session: 00000067, Substitute (VMAIL A:$CID,$CLI) -> (VMAIL A:5,)
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: GenerateInfo VMAIL A:5,
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Executing request to run node DSMAIN.GET TICKET.0, current stack depth is 16
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Found node DSMAIN.GET TICKET.0, and creating an execution point for it
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Executing node DSMAIN.GET TICKET.0, current stack depth is 17 was 16
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, RefCount = [2]
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: IVRNodePlayer::Begin(04850A38) - entered: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Executing request to run node DSMAIN.GET TICKET.1, current stack depth is 17
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Found node DSMAIN.GET TICKET.1, and creating an execution point for it
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Executing node DSMAIN.GET TICKET.1, current stack depth is 18 was 17
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, RefCount = [2]
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: IVRNodePlayer::Begin(04850B00) - entered: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, RefCount = [2]
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: IVRNodePlayer::Begin(04850BC8) - entered: (session=00000067, parent=04789888), recursive_count=(6)
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Executing request to run node DSMAIN.GET TICKET.Body.0, current stack depth is 17
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Found node DSMAIN.GET TICKET.Body.0, and creating an execution point for it
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Executing node DSMAIN.GET TICKET.Body.0, current stack depth is 18 was 17
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:36.093 vmprov5s (09,5) 1290, f64: PlayNode::AddRef, RefCount = [2]
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: IVRNodePlayer::Begin(04850C90) - entered: (session=00000067, parent=04789888), recursive_count=(7)
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: Session: 00000067, Substitute ($LOC\custom\Ar-EnterTicket) -> (enu\custom\Ar-EnterTicket)
23/06 08:08:36.093 vmprov5s (23,5) 1290, f64: Succeeded in loading sound bite C:\Program Files\Avaya\IP Office\Voicemail Pro\VM\Wavs\enu\custom\Ar-EnterTicket.WAV [aLaw]
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: IVRNodePlayer::Begin(04850C90) - left: (session=00000067, parent=04789888), recursive_count=(6)
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Successfully initiated node DSMAIN.GET TICKET.Body.0, current stack depth is 18 was 17
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: IVRNodePlayer::Begin(04850BC8) - left: (session=00000067, parent=04789888), recursive_count=(5)
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: IVRNodePlayer::Begin(04850B00) - left: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Successfully initiated node DSMAIN.GET TICKET.1, current stack depth is 18 was 17
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: IVRNodePlayer::Begin(04850A38) - left: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:36.093 vmprov5s (09,4) 1290, f64: Successfully initiated node DSMAIN.GET TICKET.0, current stack depth is 18 was 16
23/06 08:08:36.093 vmprov5s (02,6) 1290, f64: IVRNodePlayer::Begin(04850970) - left: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:36.093 vmprov5s (0a,5) 1290, f64: OSThreadFunc exited[DatabaseApp, 0477E668]
23/06 08:08:36.093 DbgOut (01,5) 4752,3940: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_DETACH)
23/06 08:08:36.843 vmprov5s (26,6) 1290,15dc: > VMailBox::ForwardPendingEmails()
23/06 08:08:36.843 vmprov5s (26,6) 1290,15dc: < VMailBox::ForwardPendingEmails()
23/06 08:08:39.953 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '1 (49)' at 1000, length 240 - session:00000067
23/06 08:08:40.703 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '0 (48)' at 1000, length 240 - session:00000067
23/06 08:08:41.328 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '0 (48)' at 240, length 240 - session:00000067
23/06 08:08:41.703 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '0 (48)' at 720, length 240 - session:00000067
23/06 08:08:42.093 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '0 (48)' at 200, length 240 - session:00000067
23/06 08:08:42.718 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '6 (54)' at 720, length 240 - session:00000067
23/06 08:08:43.093 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '6 (54)' at 280, length 240 - session:00000067
23/06 08:08:43.468 vmprov5s (1b,5) 1290,1dbc: IClient:tmfDetect 047611B0 '# (35)' at 120, length 240 - session:00000067
23/06 08:08:43.468 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing request to run node DSMAIN.STORE TICKET.0, current stack depth is 18
23/06 08:08:43.468 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Found node DSMAIN.STORE TICKET.0, and creating an execution point for it
23/06 08:08:43.468 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing node DSMAIN.STORE TICKET.0, current stack depth is 19 was 18
23/06 08:08:43.468 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.468 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.468 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(04850D58) - entered: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:43.468 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing request to run node DSMAIN.STORE TICKET.1, current stack depth is 19
23/06 08:08:43.468 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Found node DSMAIN.STORE TICKET.1, and creating an execution point for it
23/06 08:08:43.468 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing node DSMAIN.STORE TICKET.1, current stack depth is 20 was 19
23/06 08:08:43.468 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.468 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.468 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(04850E20) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:43.468 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute ($KEY) -> (1000066)
23/06 08:08:43.468 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:08:43.468 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.468 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.468 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(04850EE8) - entered: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:08:43.468 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing request to run node DSMAIN.CHECK TICKET.0, current stack depth is 19
23/06 08:08:43.468 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Found node DSMAIN.CHECK TICKET.0, and creating an execution point for it
23/06 08:08:43.468 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing node DSMAIN.CHECK TICKET.0, current stack depth is 20 was 19
23/06 08:08:43.468 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.468 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.468 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A8D08) - entered: (session=00000067, parent=04789888), recursive_count=(5)
23/06 08:08:43.468 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing request to run node DSMAIN.CHECK TICKET.1, current stack depth is 20
23/06 08:08:43.468 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Found node DSMAIN.CHECK TICKET.1, and creating an execution point for it
23/06 08:08:43.468 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Executing node DSMAIN.CHECK TICKET.1, current stack depth is 21 was 20
23/06 08:08:43.468 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.468 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.468 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A8DD0) - entered: (session=00000067, parent=04789888), recursive_count=(6)
23/06 08:08:43.468 vmprov5s (02,6) 1290,1dbc: Session: 00000067, Substitute (SELECT TN,USER_ID, TICKET_STATE_ID, TICKET_PRIORITY_ID FROM TICKET WHERE TN='$CP4' -> (SELECT TN,USER_ID, TICKET_STATE_ID, TICKET_PRIORITY_ID FROM TICKET WHERE TN='1000066'
23/06 08:08:43.468 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.468 vmprov5s (09,5) 1290,1dbc: Session: 00000067 - PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.468 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A8DD0) - left: (session=00000067, parent=04789888), recursive_count=(5)
23/06 08:08:43.468 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Successfully initiated node DSMAIN.CHECK TICKET.1, current stack depth is 21 was 20
23/06 08:08:43.468 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(047A8D08) - left: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:08:43.468 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Successfully initiated node DSMAIN.CHECK TICKET.0, current stack depth is 21 was 19
23/06 08:08:43.468 DbgOut (01,5) 4752,4724: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
23/06 08:08:43.468 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(04850EE8) - left: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:43.468 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(04850E20) - left: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:43.468 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Successfully initiated node DSMAIN.STORE TICKET.1, current stack depth is 21 was 19
23/06 08:08:43.468 vmprov5s (02,6) 1290,1dbc: IVRNodePlayer::Begin(04850D58) - left: (session=00000067, parent=04789888), recursive_count=(0)
23/06 08:08:43.468 vmprov5s (09,4) 1290,1dbc: Session: 00000067 - Successfully initiated node DSMAIN.STORE TICKET.0, current stack depth is 21 was 18
23/06 08:08:43.468 vmprov5s (0a,5) 1290,1274: OSThreadFunc entered[DatabaseApp, 0477E668]
23/06 08:08:43.468 vmprov5s (02,6) 1290,1274: Session: 00000067, Substitute (Success) -> (Success)
23/06 08:08:43.468 vmprov5s (09,5) 1290,1274: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.468 vmprov5s (09,5) 1290,1274: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.468 vmprov5s (02,6) 1290,1274: IVRNodePlayer::Begin(047A8F68) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:43.468 vmprov5s (09,4) 1290,1274: Executing request to run node DSMAIN.GET TICKET DETAILS.0, current stack depth is 20
23/06 08:08:43.468 vmprov5s (09,4) 1290,1274: Found node DSMAIN.GET TICKET DETAILS.0, and creating an execution point for it
23/06 08:08:43.468 vmprov5s (09,4) 1290,1274: Executing node DSMAIN.GET TICKET DETAILS.0, current stack depth is 21 was 20
23/06 08:08:43.468 vmprov5s (09,5) 1290,1274: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.468 vmprov5s (09,5) 1290,1274: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.468 vmprov5s (02,6) 1290,1274: IVRNodePlayer::Begin(047A9030) - entered: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:43.468 vmprov5s (09,4) 1290,1274: Executing request to run node DSMAIN.GET TICKET DETAILS.1, current stack depth is 21
23/06 08:08:43.468 vmprov5s (09,4) 1290,1274: Found node DSMAIN.GET TICKET DETAILS.1, and creating an execution point for it
23/06 08:08:43.468 vmprov5s (09,4) 1290,1274: Executing node DSMAIN.GET TICKET DETAILS.1, current stack depth is 22 was 21
23/06 08:08:43.468 vmprov5s (09,5) 1290,1274: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.468 vmprov5s (09,5) 1290,1274: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.468 vmprov5s (02,6) 1290,1274: IVRNodePlayer::Begin(047A90F8) - entered: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:08:43.468 vmprov5s (09,5) 1290,1274: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.468 vmprov5s (09,5) 1290,1274: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.468 vmprov5s (02,6) 1290,1274: IVRNodePlayer::Begin(047A90F8) - left: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:43.468 vmprov5s (09,4) 1290,1274: Successfully initiated node DSMAIN.GET TICKET DETAILS.1, current stack depth is 22 was 21
23/06 08:08:43.468 vmprov5s (02,6) 1290,1274: IVRNodePlayer::Begin(047A9030) - left: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:43.468 vmprov5s (09,4) 1290,1274: Successfully initiated node DSMAIN.GET TICKET DETAILS.0, current stack depth is 22 was 20
23/06 08:08:43.468 vmprov5s (02,6) 1290,1274: IVRNodePlayer::Begin(047A8F68) - left: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:43.468 vmprov5s (0a,5) 1290,1274: OSThreadFunc exited[DatabaseApp, 0477E668]
23/06 08:08:43.468 DbgOut (01,5) 4752,4724: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_DETACH)
23/06 08:08:43.468 DbgOut (01,5) 4752,2132: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
23/06 08:08:43.468 vmprov5s (0a,5) 1290, 854: OSThreadFunc entered[DatabaseApp, 0477EB48]
23/06 08:08:43.468 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute (1000066) -> (1000066)
23/06 08:08:43.468 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute (59) -> (59)
23/06 08:08:43.468 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute (6) -> (6)
23/06 08:08:43.468 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute (4) -> (4)
23/06 08:08:43.468 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute (Success) -> (Success)
23/06 08:08:43.468 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.468 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.468 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9290) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:43.468 vmprov5s (09,4) 1290, 854: Executing request to run node DSMAIN.StoreDBTicket.0, current stack depth is 21
23/06 08:08:43.468 vmprov5s (09,4) 1290, 854: Found node DSMAIN.StoreDBTicket.0, and creating an execution point for it
23/06 08:08:43.468 vmprov5s (09,4) 1290, 854: Executing node DSMAIN.StoreDBTicket.0, current stack depth is 22 was 21
23/06 08:08:43.468 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.468 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.468 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9358) - entered: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:43.468 vmprov5s (09,4) 1290, 854: Executing request to run node DSMAIN.StoreDBTicket.1, current stack depth is 22
23/06 08:08:43.468 vmprov5s (09,4) 1290, 854: Found node DSMAIN.StoreDBTicket.1, and creating an execution point for it
23/06 08:08:43.468 vmprov5s (09,4) 1290, 854: Executing node DSMAIN.StoreDBTicket.1, current stack depth is 23 was 22
23/06 08:08:43.468 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.468 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.468 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9420) - entered: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:08:43.468 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute (0) -> (0)
23/06 08:08:43.468 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute ($DBD[0]) -> (1000066)
23/06 08:08:43.468 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:08:43.468 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.468 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.468 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A94E8) - entered: (session=00000067, parent=04789888), recursive_count=(6)
23/06 08:08:43.468 vmprov5s (09,4) 1290, 854: Executing request to run node DSMAIN.StoreUserID.0, current stack depth is 22
23/06 08:08:43.468 vmprov5s (09,4) 1290, 854: Found node DSMAIN.StoreUserID.0, and creating an execution point for it
23/06 08:08:43.468 vmprov5s (09,4) 1290, 854: Executing node DSMAIN.StoreUserID.0, current stack depth is 23 was 22
23/06 08:08:43.468 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.468 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.468 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A95B0) - entered: (session=00000067, parent=04789888), recursive_count=(7)
23/06 08:08:43.468 vmprov5s (09,4) 1290, 854: Executing request to run node DSMAIN.StoreUserID.1, current stack depth is 23
23/06 08:08:43.468 vmprov5s (09,4) 1290, 854: Found node DSMAIN.StoreUserID.1, and creating an execution point for it
23/06 08:08:43.468 vmprov5s (09,4) 1290, 854: Executing node DSMAIN.StoreUserID.1, current stack depth is 24 was 23
23/06 08:08:43.468 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.468 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9678) - entered: (session=00000067, parent=04789888), recursive_count=(8)
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute (1) -> (1)
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute ($DBD[1]) -> (59)
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9740) - entered: (session=00000067, parent=04789888), recursive_count=(10)
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Executing request to run node DSMAIN.StoreDBStatus.0, current stack depth is 23
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Found node DSMAIN.StoreDBStatus.0, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Executing node DSMAIN.StoreDBStatus.0, current stack depth is 24 was 23
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9808) - entered: (session=00000067, parent=04789888), recursive_count=(11)
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Executing request to run node DSMAIN.StoreDBStatus.1, current stack depth is 24
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Found node DSMAIN.StoreDBStatus.1, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Executing node DSMAIN.StoreDBStatus.1, current stack depth is 25 was 24
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A98D0) - entered: (session=00000067, parent=04789888), recursive_count=(12)
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute (2) -> (2)
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute ($DBD[2]) -> (6)
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9998) - entered: (session=00000067, parent=04789888), recursive_count=(14)
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Executing request to run node DSMAIN.StoreDBpriority.0, current stack depth is 24
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Found node DSMAIN.StoreDBpriority.0, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Executing node DSMAIN.StoreDBpriority.0, current stack depth is 25 was 24
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9A60) - entered: (session=00000067, parent=04789888), recursive_count=(15)
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Executing request to run node DSMAIN.StoreDBpriority.1, current stack depth is 25
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Found node DSMAIN.StoreDBpriority.1, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Executing node DSMAIN.StoreDBpriority.1, current stack depth is 26 was 25
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9B28) - entered: (session=00000067, parent=04789888), recursive_count=(16)
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute (3) -> (3)
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute ($DBD[3]) -> (4)
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9BF0) - entered: (session=00000067, parent=04789888), recursive_count=(18)
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Executing request to run node DSMAIN.DB STATUS.0, current stack depth is 25
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Found node DSMAIN.DB STATUS.0, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Executing node DSMAIN.DB STATUS.0, current stack depth is 26 was 25
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9CB8) - entered: (session=00000067, parent=04789888), recursive_count=(19)
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Executing request to run node DSMAIN.DB STATUS.1, current stack depth is 26
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Found node DSMAIN.DB STATUS.1, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Executing node DSMAIN.DB STATUS.1, current stack depth is 27 was 26
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9D80) - entered: (session=00000067, parent=04789888), recursive_count=(20)
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: Session: 00000067, Substitute (SELECT DISTINCT ID FROM TICKET_STATE WHERE ID='$CP7' -> (SELECT DISTINCT ID FROM TICKET_STATE WHERE ID='6'
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290, 854: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9D80) - left: (session=00000067, parent=04789888), recursive_count=(19)
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Successfully initiated node DSMAIN.DB STATUS.1, current stack depth is 27 was 26
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9CB8) - left: (session=00000067, parent=04789888), recursive_count=(18)
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Successfully initiated node DSMAIN.DB STATUS.0, current stack depth is 27 was 25
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9BF0) - left: (session=00000067, parent=04789888), recursive_count=(17)
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9B28) - left: (session=00000067, parent=04789888), recursive_count=(15)
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Successfully initiated node DSMAIN.StoreDBpriority.1, current stack depth is 27 was 25
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9A60) - left: (session=00000067, parent=04789888), recursive_count=(14)
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Successfully initiated node DSMAIN.StoreDBpriority.0, current stack depth is 27 was 24
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9998) - left: (session=00000067, parent=04789888), recursive_count=(13)
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A98D0) - left: (session=00000067, parent=04789888), recursive_count=(11)
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Successfully initiated node DSMAIN.StoreDBStatus.1, current stack depth is 27 was 24
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9808) - left: (session=00000067, parent=04789888), recursive_count=(10)
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Successfully initiated node DSMAIN.StoreDBStatus.0, current stack depth is 27 was 23
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9740) - left: (session=00000067, parent=04789888), recursive_count=(9)
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9678) - left: (session=00000067, parent=04789888), recursive_count=(7)
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Successfully initiated node DSMAIN.StoreUserID.1, current stack depth is 27 was 23
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A95B0) - left: (session=00000067, parent=04789888), recursive_count=(6)
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Successfully initiated node DSMAIN.StoreUserID.0, current stack depth is 27 was 22
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A94E8) - left: (session=00000067, parent=04789888), recursive_count=(5)
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9420) - left: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Successfully initiated node DSMAIN.StoreDBTicket.1, current stack depth is 27 was 22
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9358) - left: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:43.484 vmprov5s (09,4) 1290, 854: Successfully initiated node DSMAIN.StoreDBTicket.0, current stack depth is 27 was 21
23/06 08:08:43.484 vmprov5s (02,6) 1290, 854: IVRNodePlayer::Begin(047A9290) - left: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:43.484 vmprov5s (0a,5) 1290, 854: OSThreadFunc exited[DatabaseApp, 0477EB48]
23/06 08:08:43.484 DbgOut (01,5) 4752,3908: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
23/06 08:08:43.484 vmprov5s (0a,5) 1290, f44: OSThreadFunc entered[DatabaseApp, 0477E668]
23/06 08:08:43.484 DbgOut (01,5) 4752,2132: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_DETACH)
23/06 08:08:43.484 vmprov5s (02,6) 1290, f44: Session: 00000067, Substitute (Success) -> (Success)
23/06 08:08:43.484 vmprov5s (09,5) 1290, f44: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290, f44: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290, f44: IVRNodePlayer::Begin(047A9F18) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:43.484 vmprov5s (09,4) 1290, f44: Executing request to run node DSMAIN.GET STATUS DETAILS.0, current stack depth is 26
23/06 08:08:43.484 vmprov5s (09,4) 1290, f44: Found node DSMAIN.GET STATUS DETAILS.0, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290, f44: Executing node DSMAIN.GET STATUS DETAILS.0, current stack depth is 27 was 26
23/06 08:08:43.484 vmprov5s (09,5) 1290, f44: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290, f44: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290, f44: IVRNodePlayer::Begin(04809F98) - entered: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:43.484 vmprov5s (09,4) 1290, f44: Executing request to run node DSMAIN.GET STATUS DETAILS.1, current stack depth is 27
23/06 08:08:43.484 vmprov5s (09,4) 1290, f44: Found node DSMAIN.GET STATUS DETAILS.1, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290, f44: Executing node DSMAIN.GET STATUS DETAILS.1, current stack depth is 28 was 27
23/06 08:08:43.484 vmprov5s (09,5) 1290, f44: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290, f44: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290, f44: IVRNodePlayer::Begin(0480A060) - entered: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:08:43.484 vmprov5s (09,5) 1290, f44: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290, f44: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290, f44: IVRNodePlayer::Begin(0480A060) - left: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:43.484 vmprov5s (09,4) 1290, f44: Successfully initiated node DSMAIN.GET STATUS DETAILS.1, current stack depth is 28 was 27
23/06 08:08:43.484 vmprov5s (02,6) 1290, f44: IVRNodePlayer::Begin(04809F98) - left: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:43.484 vmprov5s (09,4) 1290, f44: Successfully initiated node DSMAIN.GET STATUS DETAILS.0, current stack depth is 28 was 26
23/06 08:08:43.484 vmprov5s (02,6) 1290, f44: IVRNodePlayer::Begin(047A9F18) - left: (session=00000067, parent=04789888), recursive_count=(1)
23/06 08:08:43.484 vmprov5s (0a,5) 1290, f44: OSThreadFunc exited[DatabaseApp, 0477E668]
23/06 08:08:43.484 DbgOut (01,5) 4752,3908: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_DETACH)
23/06 08:08:43.484 DbgOut (01,5) 4752,4512: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
23/06 08:08:43.484 vmprov5s (0a,5) 1290,11a0: OSThreadFunc entered[DatabaseApp, 0477EB48]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute (6) -> (6)
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute (Success) -> (Success)
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480A1F8) - entered: (session=00000067, parent=04789888), recursive_count=(2)
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing request to run node DSMAIN.SetStatus.0, current stack depth is 27
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Found node DSMAIN.SetStatus.0, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing node DSMAIN.SetStatus.0, current stack depth is 28 was 27
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480A2C0) - entered: (session=00000067, parent=04789888), recursive_count=(3)
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing request to run node DSMAIN.SetStatus.1, current stack depth is 28
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Found node DSMAIN.SetStatus.1, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing node DSMAIN.SetStatus.1, current stack depth is 29 was 28
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480A388) - entered: (session=00000067, parent=04789888), recursive_count=(4)
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute (0) -> (0)
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute ($DBD[0]) -> (6)
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480A450) - entered: (session=00000067, parent=04789888), recursive_count=(6)
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing request to run node DSMAIN.STATUS CHECK.0, current stack depth is 28
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Found node DSMAIN.STATUS CHECK.0, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing node DSMAIN.STATUS CHECK.0, current stack depth is 29 was 28
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480A518) - entered: (session=00000067, parent=04789888), recursive_count=(7)
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing request to run node DSMAIN.STATUS CHECK.1, current stack depth is 29
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Found node DSMAIN.STATUS CHECK.1, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing node DSMAIN.STATUS CHECK.1, current stack depth is 30 was 29
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480A5E0) - entered: (session=00000067, parent=04789888), recursive_count=(8)
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing request to run node STATUS CHECK, current stack depth is 30
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Found node STATUS CHECK, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing node STATUS CHECK, current stack depth is 31 was 30
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480A6A8) - entered: (session=00000067, parent=04789888), recursive_count=(9)
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing request to run node STATUS CHECK.Start Point.1, current stack depth is 31
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Found node STATUS CHECK.Start Point.1, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing node STATUS CHECK.Start Point.1, current stack depth is 32 was 31
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480A770) - entered: (session=00000067, parent=04789888), recursive_count=(10)
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480A838) - entered: (session=00000067, parent=04789888), recursive_count=(12)
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing request to run node STATUS CHECK.STATNEW.0, current stack depth is 31
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Found node STATUS CHECK.STATNEW.0, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing node STATUS CHECK.STATNEW.0, current stack depth is 32 was 31
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480A900) - entered: (session=00000067, parent=04789888), recursive_count=(13)
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing request to run node STATUS CHECK.STATNEW.1, current stack depth is 32
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Found node STATUS CHECK.STATNEW.1, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing node STATUS CHECK.STATNEW.1, current stack depth is 33 was 32
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480A9C8) - entered: (session=00000067, parent=04789888), recursive_count=(14)
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing request to run node STATNEW, current stack depth is 33
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Found node STATNEW, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing node STATNEW, current stack depth is 34 was 33
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480AA90) - entered: (session=00000067, parent=04789888), recursive_count=(15)
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing request to run node STATNEW.Start Point.1, current stack depth is 34
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Found node STATNEW.Start Point.1, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing node STATNEW.Start Point.1, current stack depth is 35 was 34
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480AB58) - entered: (session=00000067, parent=04789888), recursive_count=(16)
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480AC20) - entered: (session=00000067, parent=04789888), recursive_count=(18)
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing request to run node STATNEW.STAT NEW.0, current stack depth is 34
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Found node STATNEW.STAT NEW.0, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing node STATNEW.STAT NEW.0, current stack depth is 35 was 34
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480ACE8) - entered: (session=00000067, parent=04789888), recursive_count=(19)
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing request to run node STATNEW.STAT NEW.1, current stack depth is 35
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Found node STATNEW.STAT NEW.1, and creating an execution point for it
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing node STATNEW.STAT NEW.1, current stack depth is 36 was 35
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480ADB0) - entered: (session=00000067, parent=04789888), recursive_count=(20)
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute ($CP10) -> (6)
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute (1) -> (1)
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Comparison '6 == 1' Result: 0
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Tested Condition 'TNEW.Condition', result: 0
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute (False) -> (False)
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.484 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.484 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480AE78) - entered: (session=00000067, parent=04789888), recursive_count=(22)
23/06 08:08:43.484 vmprov5s (09,4) 1290,11a0: Executing request to run node STATNEW.Module Return*.0, current stack depth is 35
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATNEW.Module Return*.0, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATNEW.Module Return*.0, current stack depth is 36 was 35
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480AF40) - entered: (session=00000067, parent=04789888), recursive_count=(23)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATNEW.Module Return*.1, current stack depth is 36
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATNEW.Module Return*.1, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATNEW.Module Return*.1, current stack depth is 37 was 36
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480B008) - entered: (session=00000067, parent=04789888), recursive_count=(24)
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute (Module Return*) -> (Module Return*)
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480B0D0) - entered: (session=00000067, parent=04789888), recursive_count=(25)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATUS CHECK.STATCLOSE.0, current stack depth is 32
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATUS CHECK.STATCLOSE.0, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATUS CHECK.STATCLOSE.0, current stack depth is 33 was 32
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480B198) - entered: (session=00000067, parent=04789888), recursive_count=(26)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATUS CHECK.STATCLOSE.1, current stack depth is 33
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATUS CHECK.STATCLOSE.1, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATUS CHECK.STATCLOSE.1, current stack depth is 34 was 33
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480B260) - entered: (session=00000067, parent=04789888), recursive_count=(27)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATCLOSE, current stack depth is 34
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATCLOSE, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATCLOSE, current stack depth is 35 was 34
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480B328) - entered: (session=00000067, parent=04789888), recursive_count=(28)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATCLOSE.Start Point.1, current stack depth is 35
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATCLOSE.Start Point.1, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATCLOSE.Start Point.1, current stack depth is 36 was 35
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480B3F0) - entered: (session=00000067, parent=04789888), recursive_count=(29)
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480B4B8) - entered: (session=00000067, parent=04789888), recursive_count=(31)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATCLOSE.STATCLOSE.0, current stack depth is 35
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATCLOSE.STATCLOSE.0, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATCLOSE.STATCLOSE.0, current stack depth is 36 was 35
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480B580) - entered: (session=00000067, parent=04789888), recursive_count=(32)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATCLOSE.STATCLOSE.1, current stack depth is 36
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATCLOSE.STATCLOSE.1, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATCLOSE.STATCLOSE.1, current stack depth is 37 was 36
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480B648) - entered: (session=00000067, parent=04789888), recursive_count=(33)
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute ($CP10) -> (6)
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute (2) -> (2)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Comparison '6 == 2' Result: 0
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Tested Condition 'TCLOSESU.Condition', result: 0
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute (False) -> (False)
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480B710) - entered: (session=00000067, parent=04789888), recursive_count=(35)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATCLOSE.Module Return*.0, current stack depth is 36
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATCLOSE.Module Return*.0, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATCLOSE.Module Return*.0, current stack depth is 37 was 36
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480B7D8) - entered: (session=00000067, parent=04789888), recursive_count=(36)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATCLOSE.Module Return*.1, current stack depth is 37
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATCLOSE.Module Return*.1, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATCLOSE.Module Return*.1, current stack depth is 38 was 37
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480B8A0) - entered: (session=00000067, parent=04789888), recursive_count=(37)
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute (Module Return*) -> (Module Return*)
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480B968) - entered: (session=00000067, parent=04789888), recursive_count=(38)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATUS CHECK.STATCLOSEUNSU.0, current stack depth is 33
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATUS CHECK.STATCLOSEUNSU.0, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATUS CHECK.STATCLOSEUNSU.0, current stack depth is 34 was 33
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480BA30) - entered: (session=00000067, parent=04789888), recursive_count=(39)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATUS CHECK.STATCLOSEUNSU.1, current stack depth is 34
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATUS CHECK.STATCLOSEUNSU.1, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATUS CHECK.STATCLOSEUNSU.1, current stack depth is 35 was 34
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480BAF8) - entered: (session=00000067, parent=04789888), recursive_count=(40)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATCLOSEUNSU, current stack depth is 35
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATCLOSEUNSU, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATCLOSEUNSU, current stack depth is 36 was 35
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480BBC0) - entered: (session=00000067, parent=04789888), recursive_count=(41)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATCLOSEUNSU.Start Point.1, current stack depth is 36
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATCLOSEUNSU.Start Point.1, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATCLOSEUNSU.Start Point.1, current stack depth is 37 was 36
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480BC88) - entered: (session=00000067, parent=04789888), recursive_count=(42)
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute (Next) -> (Next)
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480BD50) - entered: (session=00000067, parent=04789888), recursive_count=(44)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATCLOSEUNSU.STAT CLOSE UNSUC.0, current stack depth is 36
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATCLOSEUNSU.STAT CLOSE UNSUC.0, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATCLOSEUNSU.STAT CLOSE UNSUC.0, current stack depth is 37 was 36
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480BE18) - entered: (session=00000067, parent=04789888), recursive_count=(45)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATCLOSEUNSU.STAT CLOSE UNSUC.1, current stack depth is 37
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATCLOSEUNSU.STAT CLOSE UNSUC.1, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATCLOSEUNSU.STAT CLOSE UNSUC.1, current stack depth is 38 was 37
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480BEE0) - entered: (session=00000067, parent=04789888), recursive_count=(46)
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute ($CP10) -> (6)
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute (3) -> (3)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Comparison '6 == 3' Result: 0
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Tested Condition 'TCLOSEUNSU.Condition', result: 0
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute (False) -> (False)
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480BFA8) - entered: (session=00000067, parent=04789888), recursive_count=(48)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATCLOSEUNSU.Module Return*.0, current stack depth is 37
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATCLOSEUNSU.Module Return*.0, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATCLOSEUNSU.Module Return*.0, current stack depth is 38 was 37
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480C070) - entered: (session=00000067, parent=04789888), recursive_count=(49)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATCLOSEUNSU.Module Return*.1, current stack depth is 38
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATCLOSEUNSU.Module Return*.1, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATCLOSEUNSU.Module Return*.1, current stack depth is 39 was 38
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480C138) - entered: (session=00000067, parent=04789888), recursive_count=(50)
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: Session: 00000067, Substitute (Module Return*) -> (Module Return*)
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480C200) - entered: (session=00000067, parent=04789888), recursive_count=(51)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATUS CHECK.STATOPEN.0, current stack depth is 34
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATUS CHECK.STATOPEN.0, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATUS CHECK.STATOPEN.0, current stack depth is 35 was 34
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480C2C8) - entered: (session=00000067, parent=04789888), recursive_count=(52)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing request to run node STATUS CHECK.STATOPEN.1, current stack depth is 35
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Found node STATUS CHECK.STATOPEN.1, and creating an execution point for it
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Executing node STATUS CHECK.STATOPEN.1, current stack depth is 36 was 35
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, ReleaseRef = [1]
23/06 08:08:43.500 vmprov5s (09,5) 1290,11a0: PlayNode::AddRef, RefCount = [2]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480C390) - entered: (session=00000067, parent=04789888), recursive_count=(53)
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer:layIntro(Session: 00000067): We need to play some silence
23/06 08:08:43.500 vmprov5s (23,5) 1290,11a0: Succeeded in loading sound bite C:\Program Files\Avaya\IP Office\Voicemail Pro\VM\Wavs\enu\MC_01.WAV [aLaw]
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480C390) - left: (session=00000067, parent=04789888), recursive_count=(52)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Successfully initiated node STATUS CHECK.STATOPEN.1, current stack depth is 36 was 35
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480C2C8) - left: (session=00000067, parent=04789888), recursive_count=(51)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Successfully initiated node STATUS CHECK.STATOPEN.0, current stack depth is 36 was 34
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480C200) - left: (session=00000067, parent=04789888), recursive_count=(50)
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480C138) - left: (session=00000067, parent=04789888), recursive_count=(49)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Successfully initiated node STATCLOSEUNSU.Module Return*.1, current stack depth is 36 was 38
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480C070) - left: (session=00000067, parent=04789888), recursive_count=(48)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Successfully initiated node STATCLOSEUNSU.Module Return*.0, current stack depth is 36 was 37
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480BFA8) - left: (session=00000067, parent=04789888), recursive_count=(47)
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480BEE0) - left: (session=00000067, parent=04789888), recursive_count=(45)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Successfully initiated node STATCLOSEUNSU.STAT CLOSE UNSUC.1, current stack depth is 36 was 37
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480BE18) - left: (session=00000067, parent=04789888), recursive_count=(44)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Successfully initiated node STATCLOSEUNSU.STAT CLOSE UNSUC.0, current stack depth is 36 was 36
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480BD50) - left: (session=00000067, parent=04789888), recursive_count=(43)
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480BC88) - left: (session=00000067, parent=04789888), recursive_count=(41)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Successfully initiated node STATCLOSEUNSU.Start Point.1, current stack depth is 36 was 36
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480BBC0) - left: (session=00000067, parent=04789888), recursive_count=(40)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Successfully initiated node STATCLOSEUNSU, current stack depth is 36 was 35
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480BAF8) - left: (session=00000067, parent=04789888), recursive_count=(39)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Successfully initiated node STATUS CHECK.STATCLOSEUNSU.1, current stack depth is 36 was 34
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480BA30) - left: (session=00000067, parent=04789888), recursive_count=(38)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Successfully initiated node STATUS CHECK.STATCLOSEUNSU.0, current stack depth is 36 was 33
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480B968) - left: (session=00000067, parent=04789888), recursive_count=(37)
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodePlayer::Begin(0480B8A0) - left: (session=00000067, parent=04789888), recursive_count=(36)
23/06 08:08:43.500 vmprov5s (09,4) 1290,11a0: Successfully initiated node STATCLOSE.Module Return*.1, current stack depth is 36 was 37
23/06 08:08:43.500 vmprov5s (02,6) 1290,11a0: IVRNodeP

 

[202586]

The dbgview is some times showing message We need to play some silence
after the ivrnodeplaye....