VMPro Disconnected Calls

[TomasBill22]

Hi ...

We have IP office release 8.1.(63) and voice mail pro 8.1.9501.0 with essential, preferred and advanced edition will showed valid on IPO manager. We created a short code to the module using voice mail collect and when dial this shortcode its goes to the destination based on the call flow but when calling the number from outside, the VM Pro disconnected the call .I have tried uninstalling and re installing voice mail pro without any luck. I will appreciate if someone has a clue to on how i can resolve this issue.
The destenation on ICR is set to the Module name.
There is a Ping from the VM Pro Server to IPO.
The firewall on the VM Pro Server is off.

The followin is the trace from dbgview:

27/05 21:47:08.471 DbgOut (01,5) 6996,4992: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
27/05 21:47:10.855 DbgOut (01,5) 6996,5516: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_DETACH)
27/05 21:47:47.130 vmprov5s (19,1) 1b54,17a4: VMIsMAPIAvailable returning [0]
27/05 21:47:47.130 DbgOut (01,5) 6996,7072: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
27/05 21:47:47.130 DbgOut (01,5) 6996,6980: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
27/05 21:47:47.141 vmprov5s (66,2) 1b54,1b44: CMAPIImpl::Connect[2915]: Error 0x80004005 [MAPI_E_CALL_FAILED] from MAPIInitialize trying to initialize MAPI support
27/05 21:47:47.141 vmprov5s (19,2) 1b54,1b44: Error (hr=0x80004005 [MAPI_E_CALL_FAILED]) from MAPIConnect
27/05 21:47:47.141 DbgOut (01,5) 6996,6980: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_DETACH)
27/05 21:47:47.141 vmprov5s (66,2) 1b54,1ba0: CMAPIImpl::Connect[2915]: Error 0x80004005 [MAPI_E_CALL_FAILED] from MAPIInitialize trying to initialize MAPI support
27/05 21:47:47.141 vmprov5s (19,2) 1b54,1ba0: Error (hr=0x80004005 [MAPI_E_CALL_FAILED]) from MAPIConnect
27/05 21:47:47.141 DbgOut (01,5) 6996,7072: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_DETACH)
27/05 21:47:50.788 DbgOut (01,5) 6996,3028: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_DETACH)
27/05 21:48:14.246 DbgOut (01,5) 6996,7104: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
27/05 21:48:29.098 DbgOut (01,5) 6996,4992: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_DETACH)

Whats The Problem and How I can Solve it ?

 

[tlpeter]

I think it connects to another vmpro machine then.
Open monitor and go to status and then go to voicemail sessions.
Check which IP address is used.

BAZINGA!

I'm not insane, my mother had me tested!

 

[TomasBill22]

Hi ...

The IP Address of the PC Voicemail Server is 130.10.254.8
and this IP is shown in Voicemail Status on the Monitor

Thanks.

 

[TomasBill22]

Hi tlpeter ...

the strange thing that its disconnect me when I ringing the number but its show that is connected.
I check the Server, there is no antivirous and the firewall is off.
So I dont no really whats the problem.

Thanks

 

[tlpeter]

Try a different PC or server and leave it default.
Add a simple module and test it.
I'd it works then make an expert of the current call flows on the other server and import them on the temporally server.
Then try again.

BAZINGA!

I'm not insane, my mother had me tested!

 

[TomasBill22]

Hello tlpeter,

Here is the trace from Monitor:


********** SysMonitor v9.0.1.0 build 845 [connected to 130.10.254.7 ] **********
18:20:03 187109944mS PRN: Monitor Status IP 500 V2 8.1(63)
18:20:03 187109944mS PRN: LAW=A PRI=0, BRI=0, ALOG=4, VCOMP=10, MDM=0, WAN=0, MODU=0 LANM=0 CkSRC=0 VMAIL=1(VER=3 TYP=1) 1-X=0 CALLS=0(TOT=246)
18:20:09 187115386mS CMCallEvt: 0.1836.0 -1 BaseEP: NEW CMEndpoint f51b8bd8 TOTAL NOW=1 CALL_LIST=0
18:20:09 187115386mS CMCallEvt: CREATE CALL:247 (f51c7f78)
18:20:09 187115386mS CMCallEvt: 0.1837.0 -1 BaseEP: NEW CMEndpoint f51a678c TOTAL NOW=2 CALL_LIST=0
18:20:09 187115389mS CMLineRx: v=15
CMSetup
Line: type=AnalogueLine 15 Call: lid=15 id=4 in=1
Called[] Type=Unknown (0) Reason=CMDRdirect SndComp Calling[90799045906] Type=Unknown Plan=ALOG Pres=Allowed (0)
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
BChan: slot=7 chan=3
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=15 channel=0 rx_gain=32 tx_gain=32 ep_callid=4 ipaddr=130.10.254.7 apps=8 loc=0 em_loc=0
18:20:09 187115389mS CD: CALL: 15.4.1 BState=Idle Cut=1 Music=0.0 Aend="Line 15" (7.3) Bend="" [] (0.0) CalledNum= () CallingNum=90799045906 () Internal=0 Time=3 AState=Idle
18:20:09 187115389mS CMCallEvt: 15.4.1 247 Alog Trunk:15: StateChange: END=A CMCSIdle->CMCSDialInitiated
18:20:09 187115389mS CMTARGET: 15.4.1 247 Alog Trunk:15: LOOKUP CALL ROUTE: type=0 called_party= sub= calling=90799045906 dir=in complete=1 ses=0
18:20:09 187115390mS CMTARGET: 15.4.1 247 Alog Trunk:15: SET BESTMATCH: length 0 vs -1 match= dest=VM:BetterVM
18:20:09 187115390mS CMCallEvt: Priority hike: call 247 priority 0->1
18:20:09 187115390mS CMTARGET: 15.4.1 247 Alog Trunk:15: LOOKUP ICR: DDI=5922727 CGPN=90799045906 (Destination VM:BetterVM ) => CDPN=VM:BetterVM
18:20:09 187115391mS CMTARGET: 15.4.1 247 Alog Trunk:15: ADD TARGET (N): number=VM:BetterVM type=0 depth=1 nobar=1 setorig=1 ses=0
18:20:09 187115391mS CMTARGET: 15.4.1 247 Alog Trunk:15: ADD VM TARGET
18:20:09 187115391mS CMTARGET: **** 15.4.1 247 Alog Trunk:15: MakeVoicemailTarget pbx=<null> local=1 type=1
18:20:09 187115392mS CMCallEvt: 0.1838.0 -1 BaseEP: NEW CMEndpoint f51c8464 TOTAL NOW=3 CALL_LIST=1
18:20:09 187115392mS CMTARGET: 0.1838.0 247 RAS.0: ADD PRIMARY
18:20:09 187115392mS CMTARGET: 15.4.1 247 Alog Trunk:15: ADD VM TARGET: SUCCEEDED
18:20:09 187115392mS CMTARGET: 15.4.1 247 Alog Trunk:15: INITIAL TARGETING SUCCEEDED
18:20:09 187115392mS CMTARGET: 15.4.1 247 Alog Trunk:15: GetNoAnswerTimer:15
18:20:09 187115393mS CMCallEvt: 15.4.1 247 Alog Trunk:15: StateChange: END=A CMCSDialInitiated->CMCSDialled
18:20:09 187115394mS CMLineTx: v=15
CMProceeding
Line: type=AnalogueLine 15 Call: lid=15 id=4 in=1
18:20:09 187115394mS CMCallEvt: 0.1837.0 247 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
18:20:09 187115394mS CMCallEvt: 0.1838.0 247 RAS.0: StateChange: END=T CMCSIdle->CMCSOffering
18:20:09 187115395mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 0->1838 )
18:20:09 187115395mS CMExtnTx: v=RAS, p1=0
CMSetup
Line: type=RAS 1 Call: lid=0 id=1011 in=0
Called[BetterVM] Type=Voicemail (102) Reason=CMDRX_Attendant SndComp Calling[90799045906] Type=Unknown Plan=ALOG Pres=Allowed (0)
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
BChan: slot=21 chan=42
IE CMIERespondingPartyNumber (230)(P:0 S:3 T:0 N:101 R:4) number=90799045906
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=15 channel=0 rx_gain=32 tx_gain=32 ep_callid=4 ipaddr=130.10.254.7 apps=8 loc=0 em_loc=0
IE CMIEIcrPriorityDetail (239) Priority = 1
IE CMIEDIDNumber (245)(P:100 S:100 T:100 N:100 R:4) number=5922727
IE CMIEMohSourceId (247) MOH Source = 1
Display [90799045906>BetterVM]
Timed: 31/05/14 18:20
Locale: ara
18:20:09 187115395mS CMMap: a=21.42 b=1.254 T
18:20:09 187115397mS CMExtnRx: v=RAS, p1=0
CMConnect
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=BetterVM
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:102 N:100 R:4) number=BetterVM
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=8 class=CMDeviceVoicemail type=0 number=0 channel=42 rx_gain=32 tx_gain=32 ep_callid=1838 ipaddr=130.10.254.7 apps=8 loc=0 em_loc=0
18:20:09 187115397mS CMCallEvt: 0.1838.0 247 RAS.0: StateChange: END=T CMCSOffering->CMCSConnReq
18:20:09 187115397mS CMCallEvt: 0.1837.0 247 TargetingEP: RequestEnd 0.1838.0 247 RAS.0
18:20:09 187115397mS CMTARGET: 15.4.1 247 Alog Trunk:15: CancelTimer CMTCNoAnswerTimeout
18:20:09 187115398mS CMExtnEvt: v=1011 State, new=Connected old=Idle,0,0,RAS
18:20:09 187115398mS CMCallEvt: 15.4.1 247 Alog Trunk:15: StateChange: END=A CMCSDialled->CMCSOGConnReq
18:20:09 187115399mS CMLineTx: v=15
CMConnect
Line: type=AnalogueLine 15 Call: lid=15 id=4 in=1
BChan: slot=21 chan=42
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=BetterVM
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:102 N:100 R:4) number=BetterVM
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=8 class=CMDeviceVoicemail type=0 number=0 channel=42 rx_gain=32 tx_gain=32 ep_callid=1838 ipaddr=130.10.254.7 apps=8 loc=0 em_loc=0
18:20:09 187115399mS CMLineRx: v=15
CMConnectAck
Line: type=AnalogueLine 15 Call: lid=15 id=4 in=1
BChan: slot=7 chan=3
18:20:09 187115399mS CMCallEvt: 15.4.1 247 Alog Trunk:15: StateChange: END=A CMCSOGConnReq->CMCSConnected
18:20:09 187115399mS CMTARGET: 15.4.1 247 Alog Trunk:15: ~CMTargetHandler f51c0a34 ep f51b8bd8
18:20:09 187115400mS CMCallEvt: 0.1838.0 247 RAS.0: StateChange: END=B CMCSConnReq->CMCSConnected
18:20:09 187115401mS CMExtnTx: v=RAS, p1=0
CMConnectAck
Line: type=RAS 1 Call: lid=0 id=1011 in=0
BChan: slot=21 chan=42
18:20:09 187115402mS CMCallEvt: 0.1837.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete
18:20:09 187115402mS CMCallEvt: 0.1837.0 -1 BaseEP: DELETE CMEndpoint f51a678c TOTAL NOW=2 CALL_LIST=1
18:20:09 187115402mS CD: CALL: 15.4.1 BState=Connected Cut=3 Music=0.0 Aend="Line 15" (7.3) Bend="BetterVM(BetterVM)" [VoiceMail] (21.42) CalledNum=BetterVM () CallingNum=90799045906 () Internal=0 Time=16 AState=Connected
18:20:09 187115404mS CMMap: PCG::MapBChan pcp[70]b1r0 cp_b f594b640 other_cp_b 0 type CGTypeSimple
18:20:09 187115405mS CMMap: PCG::MapBChan pcp[22]b1r0 cp_b f596c22c other_cp_b f594b640 type CGTypeSimple
18:20:09 187115405mS CMMap: a=7.3 b=21.42 M12
18:20:09 187115408mS CMLineRx: v=15
CMConnectAck
Line: type=AnalogueLine 15 Call: lid=15 id=4 in=1
BChan: slot=7 chan=3
IE CMIERespondingPartyNumber (230)(P:0 S:3 T:0 N:101 R:4) number=90799045906
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=15 channel=0 rx_gain=32 tx_gain=32 ep_callid=4 ipaddr=130.10.254.7 apps=8 loc=0 em_loc=0
18:20:09 187115529mS RES: Sat 31/5/2014 18:20:09 FreeMem=60110464(2) CMMsg=5 (6) Buff=5200 958 998 12463 5 Links=9750 BTree=0 CPU=17/27/12029/30577/35705/2
18:20:09 187115529mS RES2: IP 500 V2 8.1(63) Tasks=47 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=83 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=17 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
18:20:09 187115529mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
18:20:12 187118011mS CMExtnEvt: CC 2: No user activity
18:20:20 187126396mS CMExtnEvt: CC 1: No user activity
18:20:25 187131497mS CMExtnEvt: Rec: No user activity

********** SysMonitor v9.0.1.0 build 845 [connected to 130.10.254.7 ] **********
18:21:04 187170790mS PRN: Monitor Status IP 500 V2 8.1(63)
18:21:04 187170790mS PRN: LAW=A PRI=0, BRI=0, ALOG=4, VCOMP=10, MDM=0, WAN=0, MODU=0 LANM=0 CkSRC=0 VMAIL=1(VER=3 TYP=1) 1-X=0 CALLS=1(TOT=247)
18:21:30 187196036mS CMExtnRx: v=RAS, p1=0
CMReleaseComp
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
18:21:30 187196036mS CMCallEvt: 0.1838.0 247 RAS.0: StateChange: END=B CMCSConnected->CMCSCompleted
18:21:30 187196037mS CMExtnEvt: v=1011 State, new=PortRecoverDelay old=Connected,0,0,RAS
18:21:30 187196037mS CMLOGGING: CALL:2014/05/3118:20,00:01:20,000,90799045906,I,BetterVM,,,,,0,,""n/a,0
18:21:30 187196038mS CD: CALL: 15.4.1 BState=Disconnecting Cut=1 Music=0.0 Aend="Line 15" (7.3) Bend="BetterVM(BetterVM)" [VoiceMail] (21.42) CalledNum=BetterVM () CallingNum=90799045906 () Internal=0 Time=80651 AState=Connected
18:21:30 187196038mS CD: CALL: 15.4.1 Deleted
18:21:30 187196039mS CMCallEvt: 15.4.1 -1 Alog Trunk:15: StateChange: END=X CMCSConnected->CMCSDelete
18:21:30 187196040mS CMCallEvt: 15.4.1 -1 BaseEP: DELETE CMEndpoint f51b8bd8 TOTAL NOW=1 CALL_LIST=0
18:21:30 187196040mS CMExtnEvt: RAS: CALL LOST (CMCauseNormal)
18:21:30 187196040mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 1838->0 )
18:21:30 187196040mS CMCallEvt: 0.1838.0 -1 RAS.-1: StateChange: END=X CMCSCompleted->CMCSDelete
18:21:30 187196041mS CMExtnEvt: v=1011 State, new=Idle old=PortRecoverDelay,0,0,RAS
18:21:30 187196041mS CMExtnTx: v=RAS, p1=0
CMReleaseComp
Line: type=RAS 1 Call: lid=0 id=1011 in=0
BChan: slot=21 chan=42
Cause=16, Normal call clearing
18:21:30 187196042mS CMMap: a=21.42 b=0.0 T0
18:21:30 187196043mS CMCallEvt: END CALL:247 (f51c7f78)
18:21:30 187196044mS CMCallEvt: 0.1838.0 -1 BaseEP: DELETE CMEndpoint f51c8464 TOTAL NOW=0 CALL_LIST=0
18:21:30 187196045mS CMMap: PCG::UnmapBChan pcp[70]b1r0 cp_b f594b640 other_cp_b f596c22c
18:21:30 187196045mS CMMap: a=21.42 b=7.3 M02
18:21:30 187196045mS CMMap: PCG::UnmapBChan pcp[22]b1r0 cp_b f596c22c other_cp_b 0
18:21:30 187196533mS RES: Sat 31/5/2014 18:21:30 FreeMem=60140748(2) CMMsg=5 (6) Buff=5200 960 999 12463 5 Links=9765 BTree=0 CPU=9/13/12029/31062/35705/3
18:21:30 187196533mS RES2: IP 500 V2 8.1(63) Tasks=46 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=80 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=17 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
18:21:30 187196533mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)

its mean any thing for you ?

Thanks

 

[AACon]

One thing i noticed is that you are sending calls to system with the ARA locale, but errors above show that locale does not exist. It's defaulting to EN, but maybe that is broken as well...

-Austin
ACE: Implement IP Office

 

[TomasBill22]

Hi ...

your suggestion ??!!!

 

[AACon]

I don't know...change the locale?

-Austin
ACE: Implement IP Office

 

[amriddle01]

No offence to anybody intended, but troubleshooting VM Pro issues is pretty run of the mill and certainly doesn't require constant prompting for the next course of action....unless you don't know why you're doing. Troubleshooting via proxy on a forum never works well

 

[intrigrant]

The traces added are as usefull as nothing.
In Monitor enable the PC Voicemail componenet and the shortcode component.
In debugview disable all apps except VM Pro and set the filter to "High Trace".
Only then you can investigate this issue.
BTW if you point the incoming call to *17 and VM Answers with "Enter your vm box number" it is the call flow module which is wrong.

 

[TomasBill22]

Hello All ...

After troubleshooting and trace I found whats the problem and I need a help how to solve this.
the problem is that all the lines sets to Loop start CLID, when I change the Lines to Loap start all the lines is answered by VMPro.
but now the CLID is not shown in the Recording and RCC Reporting and this is the problem.
So How can I solve this ?

 

[AACon]

Post your configuration. Sounds like your ICR is the issue.

-Austin
ACE: Implement IP Office

 

[TomasBill22]

Hi ...

Any Updates ??

 

[AACon]

I asked you to post your configuration. I have a feeling it's an issue with your ICR. We are all willing to help, but you need to provide good information, so far it's been lack luster.
Post your config, and I'd be happy to look at it.

-Austin
ACE: Implement IP Office

 

[TomasBill22]

Hi ...

in ICR :

Bear Capability: Any Voice
Line group id: 0

In the Destenation:

VM:BetterVM

Thats all.

Attatchment is CFG file uploaded to 4shared
The User: majdi.alqatatsheh@yahoo.com
Pass: Sweet@Heart

Thanks

 

[AACon]

If the MDB file you posted is recent...then that's your problem. I loaded it up, and there is NO module called "BetterVM".
You only have "BHAfter" and "OfficeHours". You need a module called BetterVM, as that is what you are pointing to in your ICR.

-Austin
ACE: Implement IP Office

 

[TomasBill22]

Hi ...

No No ,,, its old.
the new module now is called BetterVM.

Thanks

 

[AACon]

Well put that mdb up there too.

-Austin
ACE: Implement IP Office

 

[TomasBill22]

Hi ...

its now uploaded, but this is not a problem because when i change the lines from loop start CLID to only loop start its connected.

Thanks.

 

[AACon]

Have you tried pointing your ARS to a shortcode? Say *77/Voicemail Collect/"BetterVM"
It dosen't really make sense that when it is in loop start it works, but CLID it does not, unless you are getting some garbage data in the CLID.

-Austin
ACE: Implement IP Office