Voicemail Pro Integration with SQL Express : No Fields appear 5

[Jhon88]

Hi All Masters,

I try to integrate voicemail pro with sql express. database connection successfully, table connection too but not for fields. no fields appear.

here the picture and mod files.
Database structure:

database connection:

no fields:

ODBC setting:

mod file for voicemail call flow can find here


Any help will be full appreciate. Thanks

 

[intrigrant]

Do not use the wizard and enter the SQL commands in the SQL box

 

[Jhon88]

I tried this SQL command but it doesn't works:

SELECT ID, EXTN, NIPP, NAMA, DEPT,
FROM NIPP
WHERE (NIPP = "$KEY") ;

 

[janni78]

First of all giving a column that same name as your table doesn't really make sense but it probably works.

The correct SQL syntax should be

SELECT ID, EXTN, NIPP, NAMA, DEPT
FROM NIPP
WHERE NIPP = '$KEY';

"Trying is the first step to failure..." - Homer

 

[Jhon88]

Hi Janni78,

I tried your syntax and the call flow going to failure (speak fail2).
for simulation :
1. I tried entry correct NIPP code
2. I Tried entry false NIPP code,
both experiments go to call flow speak fail2.

detail config for menu "Get data"

and menu "DBD-CPO"

Menu "transfer spesific extn"

 

[janni78]

Well, you need to use the vm debug tool to see what's going wrong in the logs.
It's much better than me guessing =)

[URL unfurl="true"]http://marketingtools.avaya.com/knowledgebase/tools/debug[/url]

"Trying is the first step to failure..." - Homer

 

[intrigrant]

First of all use a ODBC tool to check if ODBC returns any data, then focus on VM Pro

 

[Jhon88]

Hi @Janni78 and @Intrigrant,

I found this log when run debugview, when I execute voicemail module and insert NIPP code 1112 then call flow to speak-file2 (play belum_terdaftar.WAV): found Invalid column name '1112' error in this log.

=============================================================================
18/07 09:08:24.113 vmprov5s (06,3) f1c,1220: VMServer:rocessReceiveBuffer: Received new sequenced call request for session 00000065 (received from 192.168.3.222:4098)
18/07 09:08:24.116 vmprov5s (09,5) f1c,1220: new VMAIL Client [09727FB8] [Connections 0 - 1]
18/07 09:08:24.175 vmprov5s (23,5) f1c, 8ec: Succeeded in loading cached sound bite "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Wavs\welcome.WAV" [aLaw] fro cache
18/07 09:08:24.177 vmprov5s (06,5) f1c, 8ec: VMClient::RxOpen - Created dialog 0330F000
18/07 09:08:24.177 vmprov5s (06,5) f1c, 8ec: VMClient::RxOpen 09727F58 SQL_express (4), session=00000065, dialog=0330F000, Fallback number is ""
18/07 09:08:26.677 vmprov5s (09,5) f1c,1220: PBX <Pel3C3A73FF255C (MASTER:192.168.3.222 - SLAVE:0.0.0.0 [INACTIVE]) [9.0.1.0 build 845]> is licensed for CPA.
18/07 09:08:30.236 vmprov5s (1b,5) f1c, 8ec: IClient:tmfDetect 09727FB8 '1 (49)' at 720, length 480 - session:00000065
18/07 09:08:30.255 DbgOut (01,5) 3868,6532: DllMain(hinstDLL=0x017D0000, fdwReason=DLL_THREAD_ATTACH)
18/07 09:08:30.257 DbgOut (01,5) 3868,7272: DllMain(hinstDLL=0x017D0000, fdwReason=DLL_THREAD_ATTACH)
18/07 09:08:30.612 vmprov5s (1b,5) f1c, 8ec: IClient:tmfDetect 09727FB8 '1 (49)' at 400, length 480 - session:00000065
18/07 09:08:30.986 vmprov5s (1b,5) f1c, 8ec: IClient:tmfDetect 09727FB8 '1 (49)' at 1000, length 480 - session:00000065
18/07 09:08:31.614 vmprov5s (1b,5) f1c, 8ec: IClient:tmfDetect 09727FB8 '2 (50)' at 200, length 480 - session:00000065
18/07 09:08:31.673 vmprov5s (17,2) f1c,2b94: Database Error: TmodClrObjects:vtExecute[721]: Failed to "execute the query "SELECT ID, EXTN, NIPP, NAMA, DEPT

FROM NIPP

WHERE NIPP = "1112" ; "", error -2147217900 [0x80040e14] - Invalid column name '1112'. [source=Microsoft SQL Server Native Client 10.0] [[0]: Error number -2147217900 [80040e14] - Invalid column name '1112'., native number 207 - 42S22].
18/07 09:08:31.673 vmprov5s (09,2) f1c,2b94: Session: 00000065 - Database execute failed: TmodClrObjects:vtExecute[721]: Failed to "execute the query "SELECT ID, EXTN, NIPP, NAMA, DEPT

FROM NIPP

WHERE NIPP = "1112" ; "", error -2147217900 [0x80040e14] - Invalid column name '1112'. [source=Microsoft SQL Server Native Client 10.0] [[0]: Error number -2147217900 [80040e14] - Invalid column name '1112'., native number 207 - 42S22].
18/07 09:08:31.685 vmprov5s (23,5) f1c,2b94: Succeeded in loading cached sound bite "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Wavs\belum_terdaftar.WAV" [aLaw] fro cache
18/07 09:08:40.081 vmprov5s (22,2) f1c,2b94: Failed to locate CHUNK "ALCH" in WAVE file "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Wavs\TTSMSG24.WAV"
18/07 09:08:40.099 vmprov5s (23,5) f1c,2b94: Normalized wave file "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Wavs\TTSMSG24.WAV" - Took 17 ms to normalize, maximum energy was 6.993573 and used factor 1.498391 to normalize, skipped 0 samples of silence (0 at beginning, 0 at end), ulaw_companding=false compandingLaw(default=-1,pcm=1,alaw=6,ulaw=7)=1, return is 1
18/07 09:08:40.165 vmprov5s (22,2) f1c,2b94: Failed to locate CHUNK "ALCH" in WAVE file "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Wavs\TTSMSG24.WAV"
18/07 09:08:40.166 vmprov5s (23,5) f1c,2b94: Normalized wave file "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Wavs\TTSMSG24.WAV" - rewritten at 0.180000 FS
18/07 09:08:40.250 vmprov5s (09,5) f1c, 8ec: Session: 00000065 - ~IClient [Call duration: 16 secs, 0 missed packets] [Connections 0 - 0] [Buffer pool(0:1000 1:250 2:2500 3:1496) allocated:4, seq:0] [Links:11757 from 12000] [CMMsg:0 left from 0] [VM:1 NODES:0 SN:0 SCO:4 SBL:0 TASKS:8 FILES:0 Msgs:0]
18/07 09:08:49.600 DbgOut (01,5) 3868,6532: DllMain(hinstDLL=0x017D0000, fdwReason=DLL_THREAD_DETACH)
===========================================================================

to @Intrigrant : any help to run and config ODBC Querry tool..? because help file can not be opened.

 

[janni78]

Your query is still invalid, you should have '1112' and not "1112".

Also I don't think you need the ;

"Trying is the first step to failure..." - Homer

 

[Jhon88]

Hi Janni78,

Thanks for your suggestion, it works by change to '1112' and then speak module say correct NIPP.
==============================
SELECT ID, EXTN, NIPP, NAMA, DEPT
FROM NIPP
WHERE NIPP = '$KEY';
==============================

I compare when using 2 different database:
MSAccess use "$Key";
Sql server express use '$key';

The next step after get correct NIPP from database is forward the incoming call to extension 18 (in field number 2 in table NIPP). I changed table format with this data:

I try DB-CP0 module with $DBD[2]
and set Transfer spesific menu with $CP0
but when i run VMpro and get NIPP Correct message then the incoming call disconnect (loss) not transfer to extension 18.

Any suggestion how to get ring in extension 18 from field number 2 in table NIPP.

 

[janni78]

To be fair my first post had the correct SQL syntax which you said you tried

So what does VM debug say about DBD-CP0 and the transfer?
I expect you to have looked at it, as now you've learned how useful it can be.

"Trying is the first step to failure..." - Homer

 

[Jhon88]

HI Janni78,

You are right, very usefull debugview app.

I send 2 logs detail from debugview and avaya sysmonitor to compare and get details.

debug view log details, when press 1112 then get data from NIPP table then play correct NIPP wav file (nipp-betul.WAV), after that disconnect incoming call:
============================
19/07 16:56:13.133 vmprov5s (06,3) f1c,1220: VMServer:rocessReceiveBuffer: Received new sequenced call request for session 00000097 (received from 192.168.3.222:4098)
19/07 16:56:13.136 vmprov5s (09,5) f1c,1220: new VMAIL Client [09B6A070] [Connections 0 - 1]
19/07 16:56:13.146 vmprov5s (23,5) f1c, bdc: Succeeded in loading cached sound bite "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Wavs\welcome.WAV" [aLaw] fro cache
19/07 16:56:13.147 vmprov5s (06,5) f1c, bdc: VMClient::RxOpen - Created dialog 097C8810
19/07 16:56:13.147 vmprov5s (06,5) f1c, bdc: VMClient::RxOpen 09B6A010 SQL_express (4), session=00000097, dialog=097C8810, Fallback number is ""
19/07 16:56:16.629 vmprov5s (1b,5) f1c, bdc: IClient:tmfDetect 09B6A070 '1 (49)' at 800, length 480 - session:00000097
19/07 16:56:16.644 DbgOut (01,5) 3868,7780: DllMain(hinstDLL=0x017D0000, fdwReason=DLL_THREAD_ATTACH)
19/07 16:56:16.645 DbgOut (01,5) 3868,8112: DllMain(hinstDLL=0x017D0000, fdwReason=DLL_THREAD_ATTACH)
19/07 16:56:17.138 vmprov5s (1b,5) f1c, bdc: IClient:tmfDetect 09B6A070 '1 (49)' at 280, length 480 - session:00000097
19/07 16:56:17.512 vmprov5s (1b,5) f1c, bdc: IClient:tmfDetect 09B6A070 '1 (49)' at 800, length 480 - session:00000097
19/07 16:56:18.503 vmprov5s (1b,5) f1c, bdc: IClient:tmfDetect 09B6A070 '2 (50)' at 400, length 480 - session:00000097
19/07 16:56:18.534 vmprov5s (23,5) f1c,1424: Succeeded in loading cached sound bite "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Wavs\nipp-betul.WAV" [aLaw] fro cache
19/07 16:56:24.518 vmprov5s (09,5) f1c, bdc: Session: 00000097 - ~IClient [Call duration: 11 secs, 0 missed packets] [Connections 0 - 0] [Buffer pool(0:1000 1:250 2:2500 3:1496) allocated:4, seq:0] [Links:11756 from 12000] [CMMsg:0 left from 0] [VM:0 NODES:0 SN:0 SCO:7 SBL:0 TASKS:8 FILES:0 Msgs:0]
19/07 16:56:35.141 DbgOut (01,5) 8116,8700: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
19/07 16:56:35.142 DbgOut (01,5) 8116,10908: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
19/07 16:56:35.142 DbgOut (01,5) 8116,10472: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
19/07 16:56:36.010 DbgOut (01,5) 3868,7780: DllMain(hinstDLL=0x017D0000, fdwReason=DLL_THREAD_DETACH)


============= syslog from Avaya SysMonitor ========

********** Warning: Logging to Screen Started **********
17:02:37 29439823mS PRN: 26: Digit Pressed *
17:02:37 29439824mS CMCallEvt: 0.1201.0 -1 BaseEP: NEW CMEndpoint f4dbe568 TOTAL NOW=1 CALL_LIST=0
17:02:37 29439824mS CMCallEvt: 0.1201.0 -1 test.-1: NEW CMExtnEndpoint f4dbe568, Name=test, Extn=26, Phys Extn=26
17:02:37 29439824mS CMCallEvt: CREATE CALL:68 (f4dbe028)
17:02:37 29439824mS CMCallEvt: 0.1202.0 -1 BaseEP: NEW CMEndpoint f4dbc9c0 TOTAL NOW=2 CALL_LIST=0
17:02:37 29439826mS CMExtnEvt: test: CMExtnHandler::SetCurrent( id: 0->1201 )
17:02:37 29439826mS CMExtnRx: v=26, p1=0
CMSetup
Line: type=DigitalExtn 4 Call: lid=0 id=1201 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[26] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=CallIndSigCon CMTR=64 CMST=Default CMU1=ALaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=test
17:02:37 29439826mS CMCallEvt: 0.1201.0 68 test.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
17:02:37 29439827mS CMExtnEvt: v=1 State, new=Dialling old=Idle,0,0,test
17:02:37 29439827mS CMTARGET: 0.1201.0 68 test.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=26 dir=out complete=0 ses=0
17:02:37 29439827mS CMTARGET: 0.1201.0 68 test.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
17:02:37 29439827mS CMCallEvt: 0.1201.0 68 test.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
17:02:37 29439828mS CMExtnTx: v=26, p1=0
CMSetupAck
Line: type=DigitalExtn 4 Call: lid=0 id=1201 in=0
BChan: slot=20 chan=1
Timed: 19/07/18 17:02
17:02:37 29439828mS CMExtnRx: v=26, p1=0
CMInformation
Line: type=DigitalExtn 4 Call: lid=0 id=1201 in=0
Called[*] Type=Default (100) Reason=CMDRdirect
17:02:37 29439829mS CMTARGET: 0.1201.0 68 test.0: Setting Hard Timer 4000
17:02:37 29439829mS CMTARGET: 0.1201.0 68 test.0: LOOKUP CALL ROUTE: type=100 called_party=* sub= calling=26 dir=out complete=0 ses=0
17:02:37 29439829mS CMTARGET: 0.1201.0 68 test.0: ADD TARGET (N): number=* type=100 depth=1 nobar=1 setorig=1 ses=0
17:02:37 29439830mS CD: CALL: 0.1201.0 BState=Idle Cut=0 Music=0.0 Aend="test(26)" (20.1) Bend="" [] (0.0) CalledNum=* () CallingNum=26 (test) Internal=1 Time=6 AState=Dialling
17:02:38 29440183mS PRN: 26: Digit Pressed 0
17:02:38 29440183mS CMExtnRx: v=26, p1=0
CMInformation
Line: type=DigitalExtn 4 Call: lid=0 id=1201 in=0
Called[0] Type=Default (100) Reason=CMDRdirect
17:02:38 29440184mS CMTARGET: 0.1201.0 68 test.0: Setting Hard Timer 4000
17:02:38 29440184mS CMTARGET: 0.1201.0 68 test.0: LOOKUP CALL ROUTE: type=100 called_party=*0 sub= calling=26 dir=out complete=0 ses=0
17:02:38 29440184mS CMTARGET: 0.1201.0 68 test.0: ADD TARGET (N): number=*0 type=100 depth=1 nobar=1 setorig=1 ses=0
17:02:38 29440464mS H323Evt: Shared tcp socket for line 17 disconnected
17:02:38 29440720mS PRN: 26: Digit Pressed 3
17:02:38 29440720mS CMExtnRx: v=26, p1=0
CMInformation
Line: type=DigitalExtn 4 Call: lid=0 id=1201 in=0
Called[3] Type=Default (100) Reason=CMDRdirect
17:02:38 29440720mS CMTARGET: 0.1201.0 68 test.0: Setting Hard Timer 4000
17:02:38 29440721mS CMTARGET: 0.1201.0 68 test.0: LOOKUP CALL ROUTE: type=100 called_party=*03 sub= calling=26 dir=out complete=0 ses=0
17:02:38 29440721mS CMTARGET: 0.1201.0 68 test.0: ADD TARGET (N): number=*03 type=100 depth=1 nobar=1 setorig=1 ses=0
17:02:38 29440721mS CMTARGET: 0.1201.0 68 test.0: SYS SC: *03 3 sc=type=VoicemailCollect code=*03, num="SQL_express" callinfop->sending_complete=0 secondary_dialtone=
17:02:38 29440722mS CMTARGET: 0.1201.0 68 test.0: ADD VM TARGET
17:02:38 29440722mS CMTARGET: **** 0.1201.0 68 test.0: MakeVoicemailTarget pbx=<null> local=1 type=1
17:02:38 29440722mS CMCallEvt: 0.1203.0 -1 BaseEP: NEW CMEndpoint f4da7b20 TOTAL NOW=3 CALL_LIST=1
17:02:38 29440722mS CMTARGET: 0.1203.0 68 RAS.0: ADD PRIMARY
17:02:38 29440723mS CMTARGET: 0.1201.0 68 test.0: ADD VM TARGET: SUCCEEDED
17:02:38 29440723mS CMTARGET: 0.1201.0 68 test.0: CancelTimer CMTCDelayedProcessing
17:02:38 29440723mS CMTARGET: 0.1201.0 68 test.0: INITIAL TARGETING SUCCEEDED
17:02:38 29440723mS CMTARGET: 0.1201.0 68 test.0: GetNoAnswerTimer:15
17:02:38 29440723mS CMCallEvt: 0.1202.0 68 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
17:02:38 29440724mS CMCallEvt: 0.1203.0 68 RAS.0: StateChange: END=T CMCSIdle->CMCSOffering
17:02:38 29440724mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 0->1203 )
17:02:38 29440724mS CMExtnTx: v=RAS, p1=0
CMSetup
Line: type=RAS 1 Call: lid=0 id=1013 in=0
Called[SQL_express] Type=Voicemail (102) Reason=CMDRX_Attendant Calling[26] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=CallIndSigCon CMTR=64 CMST=Default CMU1=ALaw
BChan: slot=21 chan=43
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=test
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=test
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=26
IE CMIEDeviceDetail (231) c0a803de000004b1 LOCALE=enu HW=14 VER=9 class=CMDeviceStdPhone type=76 number=49 channel=0 features=0x10000420 rx_gain=32 tx_gain=32
ep_callid=1201 ipaddr=192.168.3.222 apps=0 loc=0 em_a_loc=1 em_d_loc=0 features2=0x0 is_spcall=0 ignores_dtmf=0 avgsid=
IE CMIEMohSourceId (247) MOH Source = 255
Display [test>SQL_express]
Timed: 19/07/18 17:02
Locale: enu
17:02:38 29440724mS CMMap: a=21.43 b=1.254 T
17:02:38 29440726mS CMExtnRx: v=RAS, p1=0
CMConnect
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=SQL_express
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:102 N:100 R:4 DC:228) number=SQL_express
IE CMIEDeviceDetail (231) c0a803de000004b3 LOCALE=enu HW=14 VER=9 class=CMDeviceVoicemail type=0 number=0 channel=43 features=0x0 rx_gain=32 tx_gain=32
ep_callid=1203 ipaddr=192.168.3.222 apps=0 loc=0 em_a_loc=0 em_d_loc=0 features2=0x0 is_spcall=0 ignores_dtmf=0 avgsid=
17:02:38 29440726mS CMCallEvt: 0.1203.0 68 RAS.0: StateChange: END=T CMCSOffering->CMCSConnReq
17:02:38 29440726mS CMCallEvt: 0.1202.0 68 TargetingEP: RequestEnd 0.1203.0 68 RAS.0
17:02:38 29440727mS CMTARGET: 0.1201.0 68 test.0: CancelTimer CMTCNoAnswerTimeout
17:02:38 29440727mS CMExtnEvt: v=1013 State, new=Connected old=Idle,0,0,RAS
17:02:38 29440728mS CMCallEvt: 0.1201.0 68 test.0: StateChange: END=A CMCSDialling->CMCSOGConnReq
17:02:38 29440728mS CMExtnEvt: v=1 State, new=Connected old=Dialling,0,0,test
17:02:38 29440728mS CMExtnTx: v=26, p1=0
CMConnect
Line: type=DigitalExtn 4 Call: lid=0 id=1201 in=0
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=SQL_express
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:102 N:100 R:4 DC:228) number=SQL_express
IE CMIEDeviceDetail (231) c0a803de000004b3 LOCALE=enu HW=14 VER=9 class=CMDeviceVoicemail type=0 number=0 channel=43 features=0x0 rx_gain=32 tx_gain=32
ep_callid=1203 ipaddr=192.168.3.222 apps=0 loc=0 em_a_loc=0 em_d_loc=0 features2=0x0 is_spcall=0 ignores_dtmf=0 avgsid=
Timed: 19/07/18 17:02
17:02:38 29440728mS CMExtnRx: v=26, p1=0
CMConnectAck
Line: type=DigitalExtn 4 Call: lid=0 id=1201 in=0
17:02:38 29440728mS CMCallEvt: 0.1201.0 68 test.0: StateChange: END=A CMCSOGConnReq->CMCSConnected
17:02:38 29440728mS CMTARGET: 0.1201.0 68 test.0: ~CMTargetHandler f4db36b8 ep f4dbe568
17:02:38 29440729mS CMCallEvt: 0.1203.0 68 RAS.0: StateChange: END=B CMCSConnReq->CMCSConnected
17:02:38 29440730mS CMExtnTx: v=RAS, p1=0
CMConnectAck
Line: type=RAS 1 Call: lid=0 id=1013 in=0
BChan: slot=21 chan=43
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=test
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=26
IE CMIEDeviceDetail (231) c0a803de000004b1 LOCALE=enu HW=14 VER=9 class=CMDeviceStdPhone type=76 number=49 channel=0 features=0x10000420 rx_gain=32 tx_gain=32
ep_callid=1201 ipaddr=192.168.3.222 apps=0 loc=0 em_a_loc=1 em_d_loc=0 features2=0x0 is_spcall=0 ignores_dtmf=0 avgsid=
17:02:38 29440731mS CMCallEvt: 0.1202.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete
17:02:38 29440731mS CMCallEvt: 0.1202.0 -1 BaseEP: DELETE CMEndpoint f4dbc9c0 TOTAL NOW=2 CALL_LIST=1
17:02:38 29440731mS CD: CALL: 0.1201.0 BState=Connected Cut=3 Music=0.0 Aend="test(26)" (20.1) Bend="SQL_express(SQL_express)" [VoiceMail] (21.43) CalledNum=SQL_express () CallingNum=26 (test) Internal=1 Time=907 AState=Connected
17:02:38 29440732mS CMMap: PCG::MapBChan pcp[96]b1r0 cp_b f509d3a4 other_cp_b 0 type CGTypeSimple
17:02:38 29440732mS CMMap: PCG::MapBChan pcp[46]b1r0 cp_b f55176c4 other_cp_b f509d3a4 type CGTypeSimple
17:02:38 29440732mS CMMap: a=20.1 b=21.43 M12

********** SysMonitor v10.1.0.0.0 build 237 [connected to 192.168.3.222 (Pel3C3A73FF255C)] **********
17:02:40 29442504mS PRN: Monitor Status IP 500 9.0.1.0 build 845
17:02:40 29442504mS PRN: LAW=A PRI=0, BRI=0, ALOG=4, VCOMP=32, MDM=0, WAN=0, MODU=0 LANM=0 CkSRC=0 VMAIL=1(VER=3 TYP=1) 1-X=0 CALLS=1(TOT=68)
17:02:41 29443620mS PRN: 26: Digit Pressed 1
17:02:41 29443620mS CMExtnRx: v=26, p1=0
CMInformation
Line: type=DigitalExtn 4 Call: lid=0 id=1201 in=0
Called[1] Type=Default (100) Reason=CMDRdirect
17:02:41 29443620mS CMExtnTx: v=RAS, p1=0
CMInformation
Line: type=RAS 1 Call: lid=0 id=1013 in=0
Called[1] Type=Default (100) Reason=CMDRdirect
BChan: slot=21 chan=43
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=test
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=26
IE CMIEDeviceDetail (231) c0a803de000004b1 LOCALE=enu HW=14 VER=9 class=CMDeviceStdPhone type=76 number=49 channel=0 features=0x10000420 rx_gain=32 tx_gain=32
ep_callid=1201 ipaddr=192.168.3.222 apps=0 loc=0 em_a_loc=1 em_d_loc=0 features2=0x0 is_spcall=0 ignores_dtmf=0 avgsid=
17:02:41 29443970mS PRN: 26: Digit Pressed 1
17:02:41 29443970mS CMExtnRx: v=26, p1=0
CMInformation
Line: type=DigitalExtn 4 Call: lid=0 id=1201 in=0
Called[1] Type=Default (100) Reason=CMDRdirect
17:02:41 29443971mS CMExtnTx: v=RAS, p1=0
CMInformation
Line: type=RAS 1 Call: lid=0 id=1013 in=0
Called[1] Type=Default (100) Reason=CMDRdirect
BChan: slot=21 chan=43
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=test
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=26
IE CMIEDeviceDetail (231) c0a803de000004b1 LOCALE=enu HW=14 VER=9 class=CMDeviceStdPhone type=76 number=49 channel=0 features=0x10000420 rx_gain=32 tx_gain=32
ep_callid=1201 ipaddr=192.168.3.222 apps=0 loc=0 em_a_loc=1 em_d_loc=0 features2=0x0 is_spcall=0 ignores_dtmf=0 avgsid=
17:02:42 29444333mS PRN: 26: Digit Pressed 1
17:02:42 29444333mS CMExtnRx: v=26, p1=0
CMInformation
Line: type=DigitalExtn 4 Call: lid=0 id=1201 in=0
Called[1] Type=Default (100) Reason=CMDRdirect
17:02:42 29444334mS CMExtnTx: v=RAS, p1=0
CMInformation
Line: type=RAS 1 Call: lid=0 id=1013 in=0
Called[1] Type=Default (100) Reason=CMDRdirect
BChan: slot=21 chan=43
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=test
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=26
IE CMIEDeviceDetail (231) c0a803de000004b1 LOCALE=enu HW=14 VER=9 class=CMDeviceStdPhone type=76 number=49 channel=0 features=0x10000420 rx_gain=32 tx_gain=32
ep_callid=1201 ipaddr=192.168.3.222 apps=0 loc=0 em_a_loc=1 em_d_loc=0 features2=0x0 is_spcall=0 ignores_dtmf=0 avgsid=
17:02:42 29444833mS PRN: 26: Digit Pressed 2
17:02:42 29444833mS CMExtnRx: v=26, p1=0
CMInformation
Line: type=DigitalExtn 4 Call: lid=0 id=1201 in=0
Called[2] Type=Default (100) Reason=CMDRdirect
17:02:42 29444834mS CMExtnTx: v=RAS, p1=0
CMInformation
Line: type=RAS 1 Call: lid=0 id=1013 in=0
Called[2] Type=Default (100) Reason=CMDRdirect
BChan: slot=21 chan=43
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=test
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=26
IE CMIEDeviceDetail (231) c0a803de000004b1 LOCALE=enu HW=14 VER=9 class=CMDeviceStdPhone type=76 number=49 channel=0 features=0x10000420 rx_gain=32 tx_gain=32
ep_callid=1201 ipaddr=192.168.3.222 apps=0 loc=0 em_a_loc=1 em_d_loc=0 features2=0x0 is_spcall=0 ignores_dtmf=0 avgsid=
17:02:48 29450860mS CMExtnRx: v=RAS, p1=0
CMFacility
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
Called[CLAIM] Type=ACD (103) Reason=CMDRdirect
17:02:48 29450860mS CMExtnTx: v=26, p1=0
CMFacility
Line: type=DigitalExtn 4 Call: lid=0 id=1201 in=0
Called[CLAIM] Type=ACD (103) Reason=CMDRdirect
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=SQL_express
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:102 N:100 R:4 DC:228) number=SQL_express
IE CMIEDeviceDetail (231) c0a803de000004b3 LOCALE=enu HW=14 VER=9 class=CMDeviceVoicemail type=0 number=0 channel=43 features=0x0 rx_gain=32 tx_gain=32
ep_callid=1203 ipaddr=192.168.3.222 apps=0 loc=0 em_a_loc=0 em_d_loc=0 features2=0x0 is_spcall=0 ignores_dtmf=0 avgsid=
Timed: 19/07/18 17:02
17:02:48 29450862mS CD: CALL: 0.1201.0 BState=Connected Cut=3 Music=0.0 Aend="test(26)" (20.1) Bend="SQL_express(SQL_express)" [VoiceMail] (21.43) CalledNum=SQL_express () CallingNum=26 (test) Internal=1 Time=11038 AState=Connected
17:02:48 29450979mS CMExtnRx: v=RAS, p1=0
CMTransfer
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
Called[1112] Type=Default (100) Reason=CMDRdirect SndComp Calling[Inbound via DB] Type=Default Plan=Default
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Inbound via DB
17:02:48 29450979mS CMCallEvt: 0.1203.0 68 RAS.0: Transfer CMCauseTransfer
17:02:48 29450979mS PRN: CDR - ResetQueueSize=500
17:02:48 29450980mS PRN: CDR - TCPSend maxqueuesize=500 framecount=500 operational=0
17:02:48 29450980mS ERR: CDRServer discarding - framecount=500
17:02:48 29450980mS CD: CALL: 0.1201.0 BState=Connected Cut=3 Music=0.0 Aend="test(26)" (20.1) Bend="SQL_express(SQL_express)" [VoiceMail] (21.43) CalledNum=SQL_express () CallingNum=26 (test) Internal=1 Time=11156 AState=Connected
17:02:48 29450980mS CMTARGET: 0.1201.0 68 test.0: ADD TARGET (N): number=1112 type=100 depth=1 nobar=1 setorig=1 ses=0
17:02:48 29450981mS CMTARGET: 0.1201.0 68 test.0: TARGET: Not in dial plan
17:02:48 29450981mS CMTARGET: 0.1201.0 68 test.0: PrepareTransferTargets Found 0 target
17:02:48 29450981mS CMExtnRx: v=RAS, p1=0
CMReleaseComp
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
17:02:48 29450982mS CMCallEvt: 0.1203.0 68 RAS.0: StateChange: END=B CMCSConnected->CMCSCompleted
17:02:48 29450982mS CMExtnEvt: v=1013 State, new=PortRecoverDelay old=Connected,0,0,RAS
17:02:48 29450983mS PRN: CDR - TCPSend maxqueuesize=500 framecount=500 operational=0
17:02:48 29450983mS CMLOGGING: CALL:2018/07/1917:02,00:00:10,000,InboundviaDB,O,1112,*03,test,,,1,,""n/a,0
17:02:48 29450984mS CD: CALL: 0.1201.0 BState=Disconnecting Cut=1 Music=0.0 Aend="test(26)" (20.1) Bend="SQL_express(SQL_express)" [VoiceMail] (21.43) CalledNum=SQL_express () CallingNum=Inbound via DB (Inbound via DB) Internal=1 Time=11159 AState=Conn
ected
17:02:48 29450984mS CD: CALL: 0.1201.0 Deleted
17:02:48 29450984mS CMExtnEvt: test: CALL LOST (CMCauseNormal)
17:02:48 29450984mS CMExtnEvt: test: Extn(26) Calling Party Number(Inbound via DB) Type(CMNTypeDefault)
17:02:48 29450985mS CMCallEvt: 0.1201.0 -1 test.0: StateChange: END=X CMCSConnected->CMCSCompletedTone
17:02:48 29450985mS CMExtnEvt: v=1 State, new=CMESCompleted old=Connected,0,0,test
17:02:48 29450985mS CMExtnEvt: RAS: CALL LOST (CMCauseNormal)
17:02:48 29450985mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 1203->0 )
17:02:48 29450986mS CMCallEvt: 0.1203.0 -1 RAS.-1: StateChange: END=X CMCSCompleted->CMCSDelete
17:02:48 29450986mS CMExtnEvt: v=1013 State, new=Idle old=PortRecoverDelay,0,0,RAS
17:02:48 29450986mS CMExtnTx: v=RAS, p1=0
CMReleaseComp
Line: type=RAS 1 Call: lid=0 id=1013 in=0
BChan: slot=21 chan=43
Cause=16, Normal call clearing
17:02:48 29450986mS CMMap: a=21.43 b=0.0 T0
17:02:48 29450988mS CMCallEvt: END CALL:68 (f4dbe028)
17:02:48 29450988mS CMCallEvt: 0.1203.0 -1 BaseEP: DELETE CMEndpoint f4da7b20 TOTAL NOW=1 CALL_LIST=0
17:02:48 29450990mS CMMap: PCG::UnmapBChan pcp[96]b1r0 cp_b f509d3a4 other_cp_b f55176c4
17:02:48 29450990mS CMMap: a=21.43 b=20.1 M02
17:02:48 29450990mS CMMap: PCG::UnmapBChan pcp[46]b1r0 cp_b f55176c4 other_cp_b 0
17:02:48 29450991mS CMMap: a=21.11 b=0.0 DTMF::AllocateRAS allocated CMRTVoicemail resource busy 3, total 45
17:02:48 29450991mS CMMap: a=21.11 b=1.255 T
17:02:48 29450991mS CMMap: a=21.11 b=20.1 M22
17:02:49 29451357mS RES: Thu 19/7/2018 17:02:49 FreeMem=53682072 53571072(3) CachedMem=111000 CMMsg=6(7) Buff=5200 1348 1000 7420 5 Links=3071 BTree=13266 CPU=04.84% CPUStats=1/3/11368/13530/14559/0/0 MCR=0 MCW=0
17:02:49 29451357mS RES2: IP 500 9.0.1.0 build 845 Tasks=46 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=55 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 TCP=17(TLS=4) TAPI=0 CF=UMNT
17:02:49 29451357mS RES4: XML MemObjs=56 PoolMem=2097152(1) FreeMem=2081932(1)

********** Warning: Logging to Screen Stopped **********

 

[janni78]

Set log level to Debug in VM Pro client, that way it should show what happens in each VM Pro step.

"Trying is the first step to failure..." - Homer

 

[Jhon88]

Hi Janni78,

Thanks you so much for your suggestion, I tried to set Avaya sysmon to only capture VM pro data like this picture:

then I simulate vmpro and capture sysmon log with some schenarios.
First I want to get right fields table:
I changed DBD-CPO data with $DBD[1] then get VMAIL: VMMESSAGE Transfer request [1112@inbound via DB]
I changed DBD-CPO data with $DBD[2] then get VMAIL: VMMESSAGE Transfer request [18 @inbound via DB]
I changed DBD-CPO data with $DBD[3] then get VMAIL: VMMESSAGE Transfer request [jhon88 @inbound via DB]

detail log:
=================
09:54:19 2313169mS CMExtnTx: v=26, p1=0
CMFacility
Line: type=DigitalExtn 4 Call: lid=0 id=1029 in=0
Called[CLAIM] Type=ACD (103) Reason=CMDRdirect
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=SQL_express
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:102 N:100 R:4 DC:228) number=SQL_express
IE CMIEDeviceDetail (231) c0a803de00000407 LOCALE=enu HW=14 VER=9 class=CMDeviceVoicemail type=0 number=0 channel=43 features=0x0 rx_gain=32 tx_gain=32
ep_callid=1031 ipaddr=192.168.3.222 apps=0 loc=0 em_a_loc=0 em_d_loc=0 features2=0x0 is_spcall=0 ignores_dtmf=0 avgsid=
Timed: 20/07/18 09:54
[highlight #8AE234] 09:54:19 2313266mS VMAIL: VMMESSAGE Transfer request [18 @inbound via DB][/highlight]
09:54:19 2313266mS CMExtnRx: v=RAS, p1=0
CMTransfer
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
Called[18] Type=Default (100) Reason=CMDRdirect SndComp Calling[inbound via DB] Type=Default Plan=Default
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=inbound via DB
09:54:19 2313266mS PRN: CDR - ResetQueueSize=500
09:54:19 2313267mS PRN: CDR - TCPSend maxqueuesize=500 framecount=500 operational=0
09:54:19 2313267mS ERR: CDRServer discarding - framecount=500
09:54:19 2313270mS CMExtnTx: v=RAS, p1=0
CMReleaseComp
Line: type=RAS 1 Call: lid=0 id=1013 in=0
Called[SQL_express] Type=Voicemail (102) Reason=CMDRX_Attendant Calling[26] Type=Internal Plan=Default
BChan: slot=21 chan=43
Cause=126, Transfer(IPO)
===============================================

So I think my VMpro module is right with DBD-CPO data $DBD[2], but why system does not transfer to extension 18.
Finally I observe message VMAIL: VMMESSAGE Transfer request [18 @inbound via DB] [highlight #EF2929]why any space after 18..?[/highlight] then I look back to NIPP table design and find NIPP type data as nchar(10). I think this cause the problem, so I change NIPP type data as int. then try to simulate again.
Finally It works perfect.

detail log:
=================
09:54:19 2313169mS CMExtnTx: v=26, p1=0
CMFacility
Line: type=DigitalExtn 4 Call: lid=0 id=1029 in=0
Called[CLAIM] Type=ACD (103) Reason=CMDRdirect
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=SQL_express
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:102 N:100 R:4 DC:228) number=SQL_express
IE CMIEDeviceDetail (231) c0a803de00000407 LOCALE=enu HW=14 VER=9 class=CMDeviceVoicemail type=0 number=0 channel=43 features=0x0 rx_gain=32 tx_gain=32
ep_callid=1031 ipaddr=192.168.3.222 apps=0 loc=0 em_a_loc=0 em_d_loc=0 features2=0x0 is_spcall=0 ignores_dtmf=0 avgsid=
Timed: 20/07/18 09:54
[highlight #8AE234] 09:54:19 2313266mS VMAIL: VMMESSAGE Transfer request [18@inbound via DB][/highlight]
09:54:19 2313266mS CMExtnRx: v=RAS, p1=0
CMTransfer
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
Called[18] Type=Default (100) Reason=CMDRdirect SndComp Calling[inbound via DB] Type=Default Plan=Default
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=inbound via DB
09:54:19 2313266mS PRN: CDR - ResetQueueSize=500
09:54:19 2313267mS PRN: CDR - TCPSend maxqueuesize=500 framecount=500 operational=0
09:54:19 2313267mS ERR: CDRServer discarding - framecount=500
09:54:19 2313270mS CMExtnTx: v=RAS, p1=0
CMReleaseComp
Line: type=RAS 1 Call: lid=0 id=1013 in=0
Called[SQL_express] Type=Voicemail (102) Reason=CMDRX_Attendant Calling[26] Type=Internal Plan=Default
BChan: slot=21 chan=43
Cause=126, Transfer(IPO)
===============================================
as a thank you to this forum, I am sharing this complete module of integration experiments in order to be useful for others. all module can download in this link
many thanks for all to support this forum and special thanks to @Janni78.

 

[tlpeter]

A pink star for letting know the solution.


BAZINGA!

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

 

[janni78]

Nice find !

If you're only storing numbers in the field int's are the way to go.
nchar uses blanks to fill the field size, nvarchar might have worked since it only stores the actual length even though is supports larger strings.

"Trying is the first step to failure..." - Homer