BCM50 & IPO connection using H323

[serajeg]

Hi all,
I have an issue getting a BCM50 R3.0 & Avaya IPO500v2 to talk to each other using h323 trunks
BCM calls to IPO are successful but when I try to call any extension within the BCM from IPO I get "NUMBER BUSY"
I checked the target line private & public rcv in BCM & they are OK.
it seems that the problem is in the IPO side as I used the BCM monitor during call initiation & noting hit the BCM.
any ideas?

 

[hairlessupportmonkey]

check your IP routes and shortcodes.

ACSS - SME

 

[DBrewsky]

In BCM Monitor, which tab are you looking at to "not" see the call coming in?

--DB

http://support.csctech.us

Remote Support Specialist

 

[serajeg]

hairlessupportmonkey: I checked the SC & it is as folllows:

Code: 1XX
Feat: Dial
Tel No.: 1N
LGID: 2

I only have one default IP route & I am not sure if it is correctly configured.

I upladed the h323 trunk config, SC, IP route & IPO monitor log to this link:

http://www.mediafire.com/?3qbicyh6r8zv380

 

[hairlessupportmonkey]

Ah - your IP route points to RemoteManager

change that to LAN1

ACSS - SME

 

[hairlessupportmonkey]

Also, in the H323 Line - set the codec to Auto.

ACSS - SME

 

[serajeg]

I changed the IP route to LAN1 & the H323 codec to auto & nothing changed

 

[Lodde]

I have looked at the trace and you are dialling from User 500 to the number 61.

If you take a look in your IPO monitor trace you will see that when you dial 61 it hits the SC 6N and then the IPO sends a Setup with just dialling number 1, because of your SC.
You also receive a reply back stating "invalid number format".

 

[serajeg]

Lodde: this was because I get "NUMBER BUSY" once I press 6 so I did not complete dialing.
beolw you could find another log when I complet dialing with the same "Invalid number format" I could not figure out why I get this.
45685mS PRN: 500: Digit Pressed 6
45686mS CMCallEvt: 0.1014.0 -1 BaseEP: NEW CMEndpoint f56b98c4 TOTAL NOW=5 CALL_LIST=2
45686mS CMCallEvt: 0.1014.0 -1 Extn500.-1: NEW CMExtnEndpoint f56b98c4, Name=Extn500, Extn=500, Phys Extn=500
45686mS CMCallEvt: CREATE CALL:7 (f56b9424)
45686mS CMCallEvt: 0.1015.0 -1 BaseEP: NEW CMEndpoint f56b8010 TOTAL NOW=6 CALL_LIST=2
45688mS CMExtnEvt: Extn500: CMExtnHandler::SetCurrent( id: 0->1014 )
45688mS CMExtnRx: v=500, p1=0
CMSetup
Line: type=DigitalExtn 2 Call: lid=0 id=1014 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[500] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Extn500
45688mS CMCallEvt: 0.1014.0 7 Extn500.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
45688mS CMExtnEvt: v=1 State, new=Connected old=Idle,0,0,Extn500
45689mS CMTARGET: 0.1014.0 7 Extn500.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=500 dir=out complete=0 ses=0
45689mS CMTARGET: 0.1014.0 7 Extn500.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
45689mS CMCallEvt: 0.1014.0 7 Extn500.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
45690mS CMExtnEvt: v=1 State, new=Dialling old=Connected,0,0,Extn500
45690mS CMExtnTx: v=500, p1=0
CMSetupAck
Line: type=DigitalExtn 2 Call: lid=0 id=1014 in=0
BChan: slot=0 chan=1
Timed: 12/01/11 15:24
45690mS CMExtnRx: v=500, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1014 in=0
Called[6] Type=Default (100) Reason=CMDRdirect
45691mS CD: CALL: 0.1014.0 BState=Idle Cut=0 Music=0.0 Aend="Extn500(500)" (0.1) Bend="" [] (0.0) CalledNum=6 () CallingNum=500 (Extn500) Internal=1 Time=5 AState=Dialling
46193mS RES: Wed 12/1/2011 15:24:36 FreeMem=71208888(1) CMMsg=3 (4) Buff=200 959 1000 7463 5 Links=4564
46194mS RES2: IP 500 V2 6.0(8) Tasks=39 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=48 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 ASC=1 SYS=MNTD OPT=UMNT
46348mS PRN: 500: Digit Pressed 1
46348mS CMExtnRx: v=500, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1014 in=0
Called[1] Type=Default (100) Reason=CMDRdirect
46873mS PRN: 500: Digit Pressed 0
46873mS CMExtnRx: v=500, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1014 in=0
Called[0] Type=Default (100) Reason=CMDRdirect
47098mS PRN: 500: Digit Pressed 0
47098mS CMExtnRx: v=500, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1014 in=0
Called[0] Type=Default (100) Reason=CMDRdirect
47098mS CMTARGET: 0.1014.0 7 Extn500.0: CancelTimer CMTCDelayedProcessing
47099mS CMTARGET: 0.1014.0 7 Extn500.0: LOOKUP CALL ROUTE: type=100 called_party=6100 sub= calling=500 dir=out complete=0 ses=0
47099mS CMTARGET: 0.1014.0 7 Extn500.0: ADD TARGET (N): number=6100 type=100 depth=1 nobar=1 setorig=1 ses=0
47099mS CMTARGET: 0.1014.0 7 Extn500.0: SYS SC: 6100 2 100 sc=type=Dial code=6N, num=N callinfop->sending_complete=0 secondary_dialtone=
47100mS CMARS: FindActiveARSByGroupID GroupID=2 - Not Found
47100mS CMLRQ: FindActiveLRQByGroupID GroupID=2 - Not Found
47100mS CMMap: a=0.18 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder resource busy 1, total 10
47101mS CMCallEvt: 0.1016.0 -1 BaseEP: NEW CMEndpoint f56b44a4 TOTAL NOW=7 CALL_LIST=3
47102mS CMTARGET: DIAL LINE: 7 GROUP = 2 SUCCESS = f56b44a4
47102mS CMTARGET: 0.1014.0 7 Extn500.0: CancelTimer CMTCDialToneTimeout
47103mS CMTARGET: 0.1014.0 7 Extn500.0: INITIAL TARGETING SUCCEEDED
47103mS CMTARGET: 0.1014.0 7 Extn500.0: GetNoAnswerTimer:20
47103mS CMCallEvt: 0.1015.0 7 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
47104mS CMCallEvt: 0.1016.0 7 H323TrunkEP: StateChange: END=T CMCSIdle->CMCSOffering
47104mS CMLineTx: v=17
CMSetup
Line: type=IPLine 17 Call: lid=0 id=1016 in=0
Called[100] Type=Unknown (0) Reason=CMDRdirect Calling[500] Type=Unknown Plan=Unknown
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
BChan: slot=0 chan=1
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
CallingName.Invoke.CodePageISO8859-1
invokeId 14625
user 'Extn500' presentation Allowed
IE CMIECallSignalChannelData (8) unknown
Display [Extn500>100]
Timed: 12/01/11 15:24
Locale: enu
47105mS CD: CALL: 0.1014.0 BState=Idle Cut=0 Music=0.0 Aend="Extn500(500)" (0.1) Bend="Line 17" [Line 17] (0.0) CalledNum=6100 () CallingNum=500 (Extn500) Internal=0 Time=1419 AState=Dialling
47106mS H323Evt: v=0 stacknum=17 State, new=NullState, old=NullState id=-1
47107mS H323Evt: v=0 stacknum=17 State, new=Initiated, old=NullState id=1016
47131mS H323Evt: v=0 stacknum=17 State, new=NullState, old=Initiated id=1016
47132mS CMLineRx: v=17
CMReleaseComp
Line: type=IPLine 17 Call: lid=0 id=1016 in=0
Cause=28, Invalid number format
47132mS CMCallEvt: 0.1015.0 7 TargetingEP: RequestEnd 0.1016.0 7 H323TrunkEP
47132mS CMTARGET: 0.1014.0 7 Extn500.0: CancelTimer CMTCNoAnswerTimeout
47132mS CMCallEvt: 0.1015.0 -1 BaseEP: DELETE CMEndpoint f56b8010 TOTAL NOW=6 CALL_LIST=3
47133mS CMCallEvt: 0.1016.0 7 H323TrunkEP: StateChange: END=B CMCSOffering->CMCSCompleted
47134mS CMLOGGING: CALL:2011/01/1215:24,00:00:00,000,500,O,100,6100,Extn500,,,0,,""n/a,0
47135mS CD: CALL: 0.1014.0 BState=Disconnecting Cut=0 Music=0.0 Aend="Extn500(500)" (0.1) Bend="Line 17" [Line 17] (267.1) CalledNum=100 () CallingNum=500 (Extn500) Internal=0 Time=1449 AState=Dialling
47135mS CD: CALL: 0.1014.0 Deleted
47135mS CMExtnEvt: Extn500: CALL LOST (CMCauseInvalidFormatNumber)
47135mS CMExtnEvt: Extn500: Extn(500) Calling Party Number(500) Type(CMNTypeInternal)
47136mS CMCallEvt: 0.1014.0 -1 Extn500.0: StateChange: END=X CMCSDialling->CMCSCompletedTone
47136mS CMExtnEvt: v=1 State, new=CMESCompleted old=Dialling,0,0,Extn500
47137mS CMCallEvt: 0.1016.0 -1 H323TrunkEP: StateChange: END=X CMCSCompleted->CMCSDelete
47137mS CMCallEvt: END CALL:7 (f56b9424)
47138mS CMCallEvt: 0.1016.0 -1 BaseEP: DELETE CMEndpoint f56b44a4 TOTAL NOW=5 CALL_LIST=2
47139mS CMMap: a=21.40 b=0.0 DTMF::AllocateRAS allocated CMRTTonegen resource busy 8, total 8
47139mS CMMap: a=21.40 b=1.255 T
47139mS CMMap: a=21.40 b=0.1 M2
47140mS CMMap: a=0.18 b=0.0 Mapper::FreeCodec freed CMRTVocoder resource busy 0, total 10
49876mS CMTARGET: 0.1010.0 5 Extn207.0: TimerExpired cause=CMTCDialToneTimeout
49876mS CMLOGGING: CALL:2011/01/1215:24,00:00:00,000,207,O,,,Extn207,,,1,,""n/a,0
49876mS CD: CALL: 0.1010.0 BState=Idle Cut=1 Music=3.0 Aend="Extn207(207)" (0.7) Bend="" [] (0.0) CalledNum= () CallingNum=207 (Extn207) Internal=1 Time=30007 AState=DialInitiated
49877mS CD: CALL: 0.1010.0 Deleted
49877mS CMExtnEvt: Extn207: CALL LOST (CMCauseDialToneTimeout)
49877mS CMExtnEvt: Extn207: Extn(207) Calling Party Number(207) Type(CMNTypeInternal)
49878mS CMCallEvt: 0.1010.0 -1 Extn207.0: StateChange: END=X CMCSDialling->CMCSCompletedTone
49878mS CMExtnEvt: v=1 State, new=CMESCompleted old=Dialling,0,0,Extn207
49878mS CMCallEvt: 0.1011.0 -1 BaseEP: DELETE CMEndpoint f56fa8e4 TOTAL NOW=4 CALL_LIST=1
49878mS CMCallEvt: END CALL:5 (f5705730)
49879mS CMMap: a=0.7 b=0.0 D0
49880mS CMMap: a=21.40 b=0.7 M2
49900mS CMTARGET: 0.1012.0 6 Extn208.0: TimerExpired cause=CMTCDialToneTimeout
49900mS CMLOGGING: CALL:2011/01/1215:24,00:00:00,000,208,O,,,Extn208,,,1,,""n/a,0
49900mS CD: CALL: 0.1012.0 BState=Idle Cut=1 Music=3.0 Aend="Extn208(208)" (0.8) Bend="" [] (0.0) CalledNum= () CallingNum=208 (Extn208) Internal=1 Time=30008 AState=DialInitiated
49901mS CD: CALL: 0.1012.0 Deleted
49901mS CMExtnEvt: Extn208: CALL LOST (CMCauseDialToneTimeout)
49901mS CMExtnEvt: Extn208: Extn(208) Calling Party Number(208) Type(CMNTypeInternal)
49901mS CMCallEvt: 0.1012.0 -1 Extn208.0: StateChange: END=X CMCSDialling->CMCSCompletedTone
49902mS CMExtnEvt: v=2 State, new=CMESCompleted old=Dialling,0,0,Extn208
49902mS CMCallEvt: 0.1013.0 -1 BaseEP: DELETE CMEndpoint f56f1c24 TOTAL NOW=3 CALL_LIST=0
49902mS CMCallEvt: END CALL:6 (f56f3038)
49903mS CMMap: a=0.8 b=0.0 D0
49903mS CMMap: a=21.40 b=0.8 M2
50203mS PRN: Created WAV file MOH Source 1
50318mS PRN: Loading HoldMusic.wav from ipaddr=255.255.255.255
52448mS CMExtnRx: v=500, p1=0
CMReleaseComp
Line: type=DigitalExtn 2 Call: lid=0 id=1014 in=0
52448mS CMCallEvt: 0.1014.0 -1 Extn500.0: StateChange: END=X CMCSCompletedTone->CMCSCompleted
52449mS CMExtnEvt: v=1 State, new=PortRecoverDelay old=CMESCompleted,0,0,Extn500
52449mS CMExtnEvt: Extn500: CALL LOST (CMCauseForceClear)
52449mS CMExtnEvt: Extn500: Extn(500) Calling Party Number(500) Type(CMNTypeInternal)
52449mS CMExtnEvt: Extn500: CMExtnHandler::SetCurrent( id: 1014->0 )
52450mS CMCallEvt: 0.1014.0 -1 Extn500.-1: StateChange: END=X CMCSCompleted->CMCSDelete
52450mS CMTARGET: 0.1014.0 -1 BaseEP: ~CMTargetHandler f56b5ba4 ep f56b98c4
52450mS CMCallEvt: 0.1014.0 -1 BaseEP: DELETE CMEndpoint f56b98c4 TOTAL NOW=2 CALL_LIST=0
52451mS CMMap: a=21.40 b=0.1 M0
52691mS RES: Wed 12/1/2011 15:24:43 FreeMem=70448172(1) CMMsg=3 (4) Buff=200 951 1000 7463 5 Links=3824
52691mS RES2: IP 500 V2 6.0(8) Tasks=39 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=49 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 ASC=1 SYS=MNTD OPT=UMNT
54450mS CMExtnEvt: Extn500: Recover Timer reason=CMTRWrapUp
54450mS CMExtnEvt: v=1 State, new=Idle old=PortRecoverDelay,0,0,Extn500
54450mS CMExtnTx: v=500, p1=0
CMVoiceMailStatus
Line: type=DigitalExtn 2 Call: lid=0 id=-1 in=0
Called[Extn500 Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Extn500 Msgs=0]
Timed: 12/01/11 15:24

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

 

[Lodde]

OK, but I do not understand, you said before that you have a SC:
Code: 1XX
Feat: Dial
Tel No.: 1N
LGID: 2

But you start to dial with a 6 and it seems like you also have a SC that starts with 6N ??

What happens if you do not start with a 6 and instead 1 as your SC ?

 

[serajeg]

Itreid both SC wit the same result, below is the log for 1XX SC:

142319mS PRN: 500: Digit Pressed 1
142320mS CMCallEvt: 0.1017.0 -1 BaseEP: NEW CMEndpoint f56bc5b4 TOTAL NOW=3 CALL_LIST=0
142320mS CMCallEvt: 0.1017.0 -1 Extn500.-1: NEW CMExtnEndpoint f56bc5b4, Name=Extn500, Extn=500, Phys Extn=500
142320mS CMCallEvt: CREATE CALL:8 (f56faea0)
142320mS CMCallEvt: 0.1018.0 -1 BaseEP: NEW CMEndpoint f56f9a8c TOTAL NOW=4 CALL_LIST=0
142322mS CMExtnEvt: Extn500: CMExtnHandler::SetCurrent( id: 0->1017 )
142322mS CMExtnRx: v=500, p1=0
CMSetup
Line: type=DigitalExtn 2 Call: lid=0 id=1017 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[500] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Extn500
142322mS CMCallEvt: 0.1017.0 8 Extn500.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
142323mS CMExtnEvt: v=1 State, new=Connected old=Idle,0,0,Extn500
142323mS CMTARGET: 0.1017.0 8 Extn500.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=500 dir=out complete=0 ses=0
142323mS CMTARGET: 0.1017.0 8 Extn500.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
142324mS CMCallEvt: 0.1017.0 8 Extn500.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
142324mS CMExtnEvt: v=1 State, new=Dialling old=Connected,0,0,Extn500
142324mS CMExtnTx: v=500, p1=0
CMSetupAck
Line: type=DigitalExtn 2 Call: lid=0 id=1017 in=0
BChan: slot=0 chan=1
Timed: 12/01/11 18:03
142325mS CMExtnRx: v=500, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1017 in=0
Called[1] Type=Default (100) Reason=CMDRdirect
142326mS CD: CALL: 0.1017.0 BState=Idle Cut=0 Music=0.0 Aend="Extn500(500)" (0.1) Bend="" [] (0.0) CalledNum=1 () CallingNum=500 (Extn500) Internal=1 Time=5 AState=Dialling
142690mS RES: Wed 12/1/2011 18:03:54 FreeMem=71100032(2) CMMsg=3 (4) Buff=200 951 1000 7463 5 Links=3631
142690mS RES2: IP 500 V2 6.0(8) Tasks=39 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=45 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 ASC=1 SYS=MNTD OPT=UMNT
142932mS PRN: 500: Digit Pressed 0
142932mS CMExtnRx: v=500, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1017 in=0
Called[0] Type=Default (100) Reason=CMDRdirect
143157mS PRN: 500: Digit Pressed 0
143157mS CMExtnRx: v=500, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1017 in=0
Called[0] Type=Default (100) Reason=CMDRdirect
144157mS CMTARGET: 0.1017.0 8 Extn500.0: TimerExpired cause=CMTCDelayedProcessing
144157mS CMTARGET: 0.1017.0 8 Extn500.0: LOOKUP CALL ROUTE: type=100 called_party=100 sub= calling=500 dir=out complete=0 ses=0
144157mS CMTARGET: 0.1017.0 8 Extn500.0: ADD TARGET (N): number=100 type=100 depth=1 nobar=1 setorig=1 ses=0
144158mS CMTARGET: 0.1017.0 8 Extn500.0: SYS SC: 100 3 00 sc=type=Dial code=1XX, num=1N callinfop->sending_complete=0 secondary_dialtone=
144158mS CMARS: FindActiveARSByGroupID GroupID=2 - Not Found
144158mS CMLRQ: FindActiveLRQByGroupID GroupID=2 - Not Found
144159mS CMMap: a=0.18 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder resource busy 1, total 10
144159mS CMCallEvt: 0.1019.0 -1 BaseEP: NEW CMEndpoint f56b9a60 TOTAL NOW=5 CALL_LIST=1
144160mS CMTARGET: DIAL LINE: 8 GROUP = 2 SUCCESS = f56b9a60
144161mS CMTARGET: 0.1017.0 8 Extn500.0: CancelTimer CMTCDialToneTimeout
144161mS CMTARGET: 0.1017.0 8 Extn500.0: INITIAL TARGETING SUCCEEDED
144161mS CMTARGET: 0.1017.0 8 Extn500.0: GetNoAnswerTimer:20
144161mS CMCallEvt: 0.1018.0 8 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
144162mS CMCallEvt: 0.1019.0 8 H323TrunkEP: StateChange: END=T CMCSIdle->CMCSOffering
144163mS CMLineTx: v=17
CMSetup
Line: type=IPLine 17 Call: lid=0 id=1019 in=0
Called[100] Type=Unknown (0) Reason=CMDRdirect Calling[500] Type=Unknown Plan=Unknown
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
CallingName.Invoke.CodePageISO8859-1
invokeId 14626
user 'Extn500' presentation Allowed
IE CMIECallSignalChannelData (8) unknown
Display [Extn500>100]
Timed: 12/01/11 18:03
Locale: enu
144163mS CD: CALL: 0.1017.0 BState=Idle Cut=0 Music=0.0 Aend="Extn500(500)" (0.1) Bend="Line 17" [Line 17] (0.0) CalledNum=100 () CallingNum=500 (Extn500) Internal=0 Time=1843 AState=Dialling
144164mS H323Evt: v=0 stacknum=17 State, new=NullState, old=NullState id=-1
144165mS H323Evt: v=0 stacknum=17 State, new=Initiated, old=NullState id=1019
144187mS H323Evt: v=0 stacknum=17 State, new=NullState, old=Initiated id=1019
144188mS CMLineRx: v=17
CMReleaseComp
Line: type=IPLine 17 Call: lid=0 id=1019 in=0
Cause=28, Invalid number format
144188mS CMCallEvt: 0.1018.0 8 TargetingEP: RequestEnd 0.1019.0 8 H323TrunkEP
144188mS CMTARGET: 0.1017.0 8 Extn500.0: CancelTimer CMTCNoAnswerTimeout
144188mS CMCallEvt: 0.1018.0 -1 BaseEP: DELETE CMEndpoint f56f9a8c TOTAL NOW=4 CALL_LIST=1
144189mS CMCallEvt: 0.1019.0 8 H323TrunkEP: StateChange: END=B CMCSOffering->CMCSCompleted
144190mS CMLOGGING: CALL:2011/01/1218:03,00:00:00,000,500,O,100,100,Extn500,,,0,,""n/a,0
144191mS CD: CALL: 0.1017.0 BState=Disconnecting Cut=0 Music=0.0 Aend="Extn500(500)" (0.1) Bend="Line 17" [Line 17] (267.1) CalledNum=100 () CallingNum=500 (Extn500) Internal=0 Time=1870 AState=Dialling
144191mS CD: CALL: 0.1017.0 Deleted
144191mS CMExtnEvt: Extn500: CALL LOST (CMCauseInvalidFormatNumber)
144191mS CMExtnEvt: Extn500: Extn(500) Calling Party Number(500) Type(CMNTypeInternal)
144192mS CMCallEvt: 0.1017.0 -1 Extn500.0: StateChange: END=X CMCSDialling->CMCSCompletedTone
144192mS CMExtnEvt: v=1 State, new=CMESCompleted old=Dialling,0,0,Extn500
144192mS CMCallEvt: 0.1019.0 -1 H323TrunkEP: StateChange: END=X CMCSCompleted->CMCSDelete
144193mS CMCallEvt: END CALL:8 (f56faea0)
144194mS CMCallEvt: 0.1019.0 -1 BaseEP: DELETE CMEndpoint f56b9a60 TOTAL NOW=3 CALL_LIST=0
144195mS CMMap: a=21.39 b=0.1 M2
144195mS CMMap: a=0.18 b=0.0 Mapper::FreeCodec freed CMRTVocoder resource busy 0, total 10
147569mS CMExtnRx: v=500, p1=0
CMReleaseComp
Line: type=DigitalExtn 2 Call: lid=0 id=1017 in=0
147569mS CMCallEvt: 0.1017.0 -1 Extn500.0: StateChange: END=X CMCSCompletedTone->CMCSCompleted
147570mS CMExtnEvt: v=1 State, new=PortRecoverDelay old=CMESCompleted,0,0,Extn500
147570mS CMExtnEvt: Extn500: CALL LOST (CMCauseForceClear)
147570mS CMExtnEvt: Extn500: Extn(500) Calling Party Number(500) Type(CMNTypeInternal)
147570mS CMExtnEvt: Extn500: CMExtnHandler::SetCurrent( id: 1017->0 )
147571mS CMCallEvt: 0.1017.0 -1 Extn500.-1: StateChange: END=X CMCSCompleted->CMCSDelete
147571mS CMTARGET: 0.1017.0 -1 BaseEP: ~CMTargetHandler f56baf7c ep f56bc5b4
147571mS CMCallEvt: 0.1017.0 -1 BaseEP: DELETE CMEndpoint f56bc5b4 TOTAL NOW=2 CALL_LIST=0
147573mS CMMap: a=21.39 b=0.1 M0
147690mS RES: Wed 12/1/2011 18:03:59 FreeMem=71121884(2) CMMsg=3 (4) Buff=200 951 1000 7463 5 Links=3633
147690mS RES2: IP 500 V2 6.0(8) Tasks=39 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=46 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 ASC=1 SYS=MNTD OPT=UMNT
149571mS CMExtnEvt: Extn500: Recover Timer reason=CMTRWrapUp
149571mS CMExtnEvt: v=1 State, new=Idle old=PortRecoverDelay,0,0,Extn500
149571mS CMExtnTx: v=500, p1=0
CMVoiceMailStatus
Line: type=DigitalExtn 2 Call: lid=0 id=-1 in=0
Called[Extn500 Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Extn500 Msgs=0]
Timed: 12/01/11 18:04

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

 

[hairlessupportmonkey]

it looks like you have a VCM card in your IPO, but can you confirm you have and have voice networking licences?

ACSS - SME

 

[Lodde]

You need to activate also H323 Send and Receive on the H323 tab in Monitor.

Then I am pretty sure that you will see that the IPO sends a H323 TX Setup on the IP trunk, if everything was working you should then receive a H323 RX Call proceeding.

But I suspect that you instead receives a H323 RX Release Complete with Cause 28.

Which will indicate that the problem is likely in the other end.

 

[serajeg]

hairlessupportmonkey: I have a combo card with 10 VCM channels & netowrking license & I could already receive calls from the BCM.
Lodde: I applied filters for H323 & I get a message from the BCM with "release complete" but no cause 28, please see below:


********** Warning: Logging to Screen Started **********
74356262mS H323Evt: v=0 stacknum=17 State, new=NullState, old=NullState id=-1
74356263mS H323Evt: v=0 stacknum=17 State, new=Initiated, old=NullState id=1045
74356264mS H323Tx: 10 dst=192.168.2.100:1720
H323 Pcol=08(Q931) Reflen=2 ref=0009(Remote)
Message Type = Setup

74356286mS H323Rx: 10 src=192.168.2.100:1720
H323 Pcol=08(Q931) Reflen=2 ref=0009(Local)
Message Type = ReleaseComplete

74356287mS H323Evt: v=0 stacknum=17 State, new=NullState, old=Initiated id=1045

below is a complete detailed H323 capture:


********** Warning: Logging to Screen Started **********
74046844mS H323Evt: v=0 stacknum=17 State, new=NullState, old=NullState id=-1
74046844mS H323Evt: v=0 stacknum=17 State, new=Initiated, old=NullState id=1042
74046845mS H323Tx: 9 dst=192.168.2.100:1720
H323 Pcol=08(Q931) Reflen=2 ref=0008(Remote)
Message Type = Setup

74046845mS H323Tx: dst=192.168.2.100:1720
H323 Pcol=08(Q931) Reflen=2 ref=0008(Remote)
Message Type = Setup
InformationElement = BearerCapability
0000 04 03 80 90 a3 .....
InformationElement = Display
0000 28 0b 45 78 74 6e 35 30 30 3e 31 31 30 (.Extn500>110
InformationElement = CallingPartyNumber
0000 6c 04 80 35 30 30 l..500
InformationElement = CalledPartyNumber
0000 70 04 80 31 31 30 p..110
InformationElement = UU
0000 7e 00 90 05 20 b8 06 00 08 91 4a 00 05 01 40 06 ~... .....J...@.
0010 00 45 00 78 00 74 00 6e 00 35 00 30 00 30 22 c0 .E.x.t.n.5.0.0".
0020 b4 00 2a 00 08 49 50 20 35 30 30 20 56 32 06 36 ..*..IP 500 V2.6
0030 2e 30 20 28 38 29 00 01 01 00 44 30 c0 a8 02 64 .0 (8)....D0...d
0040 06 b8 00 47 20 01 80 3a 38 11 d9 81 f3 00 e0 07 ...G ..:8.......
0050 05 9c f1 00 d5 0d 80 00 07 00 c0 a8 02 dc 10 07 ................
0060 11 00 47 20 01 80 3a 38 11 d9 81 f4 00 e0 07 05 ..G ..:8........
0070 9c f1 01 00 01 80 01 00 01 00 11 80 14 01 12 60 ...............`
0080 00 01 10 39 29 00 00 09 00 30 45 78 74 6e 35 30 ...9)....0Extn50
0090 30 01 80 0..
UserInformation = {
h323-uu-pdu = {
h323-message-body = setup = {
protocolIdentifier = 0.0.8.2250.0.5
sourceAddress = { 1 item(s)
[0] = h323-ID =
0045 0078 0074 006e 0035 0030 0030 Extn500
}
sourceInfo = {
vendor = {
vendor = {
t35CountryCode = 180
t35Extension = 0
manufacturerCode = 10752
}
productId =
49 50 20 35 30 30 20 56 32 IP 500 V2
versionId =
36 2e 30 20 28 38 29 6.0 (8)
}
terminal = {
}
mc = false
undefinedNode = false
}
destinationAddress = { 1 item(s)
[0] = dialedDigits =
31 31 30 110
}
destCallSignalAddress = ipAddress = {
ip =
c0 a8 02 64 ...d
port = 1720
}
activeMC = false
conferenceID =
47 20 01 80 3a 38 11 d9 81 f3 00 e0 07 05 9c f1 G ..:8..........
conferenceGoal = create
callType = pointToPoint
sourceCallSignalAddress = ipAddress = {
ip =
c0 a8 02 dc ....
port = 4103
}
callIdentifier = {
guid =
47 20 01 80 3a 38 11 d9 81 f4 00 e0 07 05 9c f1 G ..:8..........
}
mediaWaitForConnect = false
canOverlapSend = true
multipleCalls = false
maintainConnection = false
}
h4501SupplementaryService = { 1 item(s)
[0] =
60 00 01 10 39 29 00 00 09 00 30 45 78 74 6e 35 `...9)....0Extn5
30 30 00
}
h245Tunneling = true
}
}
74046867mS H323Rx: 9 src=192.168.2.100:1720
H323 Pcol=08(Q931) Reflen=2 ref=0008(Local)
Message Type = ReleaseComplete

74046867mS H323Rx: src=192.168.2.100:1720
H323 Pcol=08(Q931) Reflen=2 ref=0008(Local)
Message Type = ReleaseComplete
InformationElement = CAUSE
0000 08 02 80 9c ....
InformationElement = UU
0000 7e 00 26 05 25 80 06 00 08 91 4a 00 04 11 18 11 ~.&.%.....J.....
0010 00 47 20 01 80 3a 38 11 d9 81 f4 00 e0 07 05 9c .G ..:8.........
0020 f1 01 00 01 40 10 80 01 00 ....@....
UserInformation = {
h323-uu-pdu = {
h323-message-body = releaseComplete = {
protocolIdentifier = 0.0.8.2250.0.4
callIdentifier = {
guid =
47 20 01 80 3a 38 11 d9 81 f4 00 e0 07 05 9c f1 G ..:8..........
}
presentationIndicator = presentationAllowed
screeningIndicator = 2
}
h245Tunneling = false
}
}
74046867mS H323Evt: v=0 stacknum=17 State, new=NullState, old=Initiated id=1042

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

 

[Lodde]

Yes, you do recieve a Cause 28, it is in this segment:
InformationElement = CAUSE 0000 08 02 80 9c

It is the Avaya Monitor app that "translates" it to cause 28 and it is not visible now when you only have H323 messages in the trace.

You need to make a similar trace in the other end (BCM)if that is possible.

 

[Lodde]

Also check Supplementary Services on your IP trunk in IP Office. If yuo have choosen H450, try instead with None.

Because if the other end do not support H450, the call will fail.

 

[serajeg]

I tried to chose H450 & none with the same result.

unfortunately the BCM does not have a detaied tracing tool, just the BCM monitor which could not provide this information.

 

[tlpeter]

Change your shortcode in:
1XX
dial
1XX
linegroup id 2

Perhaps that will work?


When you pay peanuts, you get monkeys!

honey, i fried the IP Office !!!

Sarcasm, it's only one of the services I offer.

 

[Lodde]

The SC you already have is working as it should, the IPO sends the call to the IP trunk. In the latest trace you dial from User 500 to User 110.

The problem is not in the IPO.

 

[Lodde]

Maybe it is not possible to have these 2 systems talking to each other with H323, see this thread:

http://www.tek-tips.com/viewthread.cfm?qid=1603605&page=5