IP Office - IP Office (H.323) voice problem

[rmakru]

Hello there !
I have a problem……
Two IP Office's , IP phones … and I call from the first IP Office to the second one.
The protocol is H.323.
When my colleague answer me we don't hear one another. So there is silence.
There is a gatekeeper (telephone station Nortel in Middle) and IP Office's (in different towns) register on it.
IP Office's and the gatekeeper are in 3 different towns which are very far from one another :-)
The interesting thing is when I call from Nortel to any IP Office and from any IP Office to Nortel there is not any problem.
I made test call from IP Office to IP Office and there are a few fragments from log from the second IP Office where they answer me. You can see it in the body of the letter here.
PLEASE have a look at all these things and let me know if you have any idea...


There ara as usual:

CMLineRx: v=1
CMSetup
……………………………..
CMLineTx: v=1
CMProceeding
…………………………………..
………………………………….
CMExtnTx: v=82323, p1=0
CMConnectAck

Then we have the most interesting fragments:

198195600mS CMLineTx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=1 id=1 in=1
IE CMIEPrimitiveData (7)
198195603mS PRN: H245LCSE::HandleClose --- Incoming logical channel 2 does not exist
198195604mS CMLineRx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=1 id=1 in=1
IE CMIEPrimitiveData (7)
198195606mS CMMap: a=6.1 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder resource busy 1, total 4

A few times there :
198195823mS CMMap: PCG::UnmapBChan pcp[90]b0r1 cp_b 0 other_cp_b 0
198195823mS CMMap: PCG::MapBChan pcp[90]b0r1 cp_b 0 other_cp_b 0 type CGTypeSimple

And again:
198196221mS CMMap: a=6.17 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder resource busy 2, total 4

Also I have
198196223mS CMLineTx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=1 id=1 in=1
IE CMIEPrimitiveData (7)
198196224mS H323Evt: AudioEndPoint::Configure detectNwFaxPackets set to 0
198196224mS CMMap: PCG::UnmapBChan pcp[90]b0r1 cp_b 0 other_cp_b 0
198196225mS CMMap: PCG::MapBChan pcp[90]b0r1 cp_b 0 other_cp_b 0 type CGTypeSimple
198196225mS CMMap: Mapper:elayedFreeCodec f5a6f624 found cp pcp[90]b0r1 use_reserved_codec 0 local_reserved_codec 0, is_mapped_b 0
198196225mS CMMap: a=6.1 b=0.0 Mapper::FreeCodec freed CMRTVocoder resource busy 1, total 4
198196225mS CMMap: Mapper:elayedFreeCodec f5a6d924 found cp pcp[89]b0r1 use_reserved_codec 0 local_reserved_codec 0, is_mapped_b 0
198196226mS CMMap: a=6.17 b=0.0 Mapper::FreeCodec freed CMRTVocoder resource busy 0, total 4


So tell me which way I can solve the problem please !

[deville]

Hi,

Sounds like a network problem.
Do your H323 Line use "Direct Media Path" ?
How your 3 sites are connected ? Through a MPLS, IPSEC VPN ?
From site with first IPO, can you ping second IPO ?

[makrur]

Hi,

Sounds like a network problem.
Do your H323 Line use "Direct Media Path" ?
How your 3 sites are connected ? Through a MPLS, IPSEC VPN ?
From site with first IPO, can you ping second IPO ?

Thank you for reply !
We don't use "Direct Media Path" on both IPO's
Our 3 sites are connected through VPN so look ...
IP phones (172.30.0.0/24)----IPO(192.168.X.0/24)-----router(VPN)---IPnet of provider-----(VPN)router -----(Gatekeeper Nortel)-------router(VPN)---IPnet of provider (the same)---(VPN)router-----(192.168.Y.0/24)IPO---------(172.30.0.0/24)IP phones.
Yes, we can ping 192.168.Y.0/24 from 192.168.X.0/24 . But ping ... it is a ICMP pacckets only you know ))), So it is very interesting problem ....
Try to guess what problem is please
Thanks !!!!!!!!!!

[deville]

Hi,

Can you start a monitor on 1st IPO with all H323 debug on, try to make a call, and post it ?

[makrur]

I have already has it

Look

Part 1


178203055mS CMCallEvt: 0.1020.0 -1 Ext82303.-1: NEW CMExtnEndpoint f577d730, Name=Ext82303, Extn=82303, Phys Extn=82303
178203056mS CMCallEvt: CREATE CALL:8 (f577c9c0)
178203056mS CMCallEvt: 0.1021.0 -1 BaseEP: NEW CMEndpoint f577b77c TOTAL NOW=2 CALL_LIST=0
178203057mS CMExtnEvt: Ext82303: CMExtnHandler::SetCurrent( id: 0->1020 )
178203058mS CMExtnRx: v=82303, p1=0
CMSetup
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[82303] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Ext82303
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=ГлБухгалтер
IE CMIEFastStartInfoData (6)
178203058mS CMCallEvt: 253.1020.0 8 Ext82303.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
178203058mS CMExtnEvt: v=1 State, new=Connected old=Idle,0,0,Ext82303
178203059mS CMTARGET: 253.1020.0 8 Ext82303.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=82303 dir=out complete=0 ses=0
178203059mS CMTARGET: 253.1020.0 8 Ext82303.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
178203059mS CMCallEvt: 253.1020.0 8 Ext82303.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
178203060mS CMExtnEvt: v=1 State, new=Dialling old=Connected,0,0,Ext82303
178203062mS CMExtnTx: v=82303, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
IE CMIEFastStartInfoData (6)
Timed: 24/06/10 08:37
178203062mS CMExtnTx: v=82303, p1=8002
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1 in=1
IE CMIEFastStartInfoData (6)
178203062mS CMExtnTx: v=82303, p1=0
CMSetupAck
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
Timed: 24/06/10 08:37
178203063mS PRN: SendCallStateId Module=0 Button=7 state=2
178203064mS CD: CALL: 253.1020.0 BState=Idle Cut=1 Music=3.0 Aend="Ext82303(82303)" (0.0) Bend="" [] (0.0) CalledNum= () CallingNum=82303 (Ext82303) Internal=1 Time=9 AState=DialInitiated
178203065mS CMMap: PCG::AddToneGenerator g D1[1] for cp[110]b0r1 append pcp[111]b0r1 (total 1)
178203065mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[111]b0r1 Configure 0.0
178203065mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[111]b0r1 ConnectIndication 0.0
178203065mS CMMap: a=0.0 b=0.0 pcp[110]b0r1 RTPD1
178204060mS H323Evt: RTP(50t): 172.30.77.1/49152 172.30.77.4/51356 CODEC=G729A8K(6) PKTSZ=20 RFC2833=off AGE=995 SENT=50 (avg size=20) RECV=19 (avg size=20)
178205593mS PRN: 82303: Digit Pressed 9
178205594mS CMExtnRx: v=82303, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
Called[9] Type=Default (100) Reason=CMDRdirect Keypad[9]
178205595mS CMMap: a=0.0 b=0.0 pcp[110]b0r1 RTPD0
178205658mS RES: Thu 24/6/2010 08:37:35 FreeMem=74557500(2) CMMsg=5 (5) Buff=200 960 1000 7470 5 Links=4295
178205658mS RES2: IP 500 5.0(8) Tasks=32 RTEngine=0 CMRTEngine=0 Timer=42 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1
178207143mS PRN: 82303: Digit Pressed 8
178207144mS CMExtnRx: v=82303, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
178207863mS PRN: 82303: Digit Pressed 2
178207864mS CMExtnRx: v=82303, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
178208823mS H323Evt: Recv: RegistrationRequest 172.30.77.2; Endpoints registered: 3; Endpoints in registration: 0
178209423mS PRN: 82303: Digit Pressed 3
178209423mS CMExtnRx: v=82303, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3]
178209983mS PRN: 82303: Digit Pressed 2
178209983mS CMExtnRx: v=82303, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
178210553mS PRN: 82303: Digit Pressed 3
178210553mS CMExtnRx: v=82303, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3]
178210658mS RES: Thu 24/6/2010 08:37:40 FreeMem=74557336(2) CMMsg=5 (5) Buff=200 960 1000 7470 5 Links=4295
178210658mS RES2: IP 500 5.0(8) Tasks=32 RTEngine=0 CMRTEngine=0 Timer=43 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1
178214553mS CMTARGET: 253.1020.0 8 Ext82303.0: TimerExpired cause=CMTCDelayedProcessing
178214553mS CMTARGET: 253.1020.0 8 Ext82303.0: LOOKUP CALL ROUTE: type=100 called_party=982323 sub= calling=82303 dir=out complete=0 ses=0
178214553mS CMTARGET: 253.1020.0 8 Ext82303.0: ADD TARGET (N): number=982323 type=100 depth=1 nobar=1 setorig=1 ses=0
178214554mS CMTARGET: 253.1020.0 8 Ext82303.0: SYS SC: 982323 2 82323 sc=type=Dial code=9N, num=N callinfop->sending_complete=0 secondary_dialtone=
178214554mS CMARS: FindActiveARSByGroupID GroupID=0 - Not Found

********** Warning: Missed 1 packet(s) **********
178214555mS CMCallEvt: 0.1022.0 -1 BaseEP: NEW CMEndpoint f5770040 TOTAL NOW=3 CALL_LIST=1
178214556mS CMTARGET: DIAL LINE: 8 GROUP = 0 SUCCESS = f5770040
178214556mS CMTARGET: 253.1020.0 8 Ext82303.0: CancelTimer CMTCDialToneTimeout
178214556mS CMTARGET: 253.1020.0 8 Ext82303.0: INITIAL TARGETING SUCCEEDED
178214556mS CMTARGET: 253.1020.0 8 Ext82303.0: GetNoAnswerTimer:15
178214557mS CMCallEvt: 0.1021.0 8 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
178214558mS CMCallEvt: 0.1022.0 8 H323TrunkEP: StateChange: END=T CMCSIdle->CMCSOffering

[makrur]

Part 2


178214559mS CMLineTx: v=1
CMSetup
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
Called[82323] Type=Unknown (0) Reason=CMDRdirect Calling[82303] 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 14632
user 'Ext82303' presentation Allowed
IE CMIEFastStartInfoData (6)
IE CMIECallSignalChannelData (8) unknown
Display [Ext82303>82323]
Timed: 24/06/10 08:37
Locale: rus
178214560mS CD: CALL: 253.1020.0 BState=Idle Cut=0 Music=0.0 Aend="Ext82303(82303)" (0.0) Bend="Line 1" [Line 1] (0.0) CalledNum=982323 () CallingNum=82303 (Ext82303) Internal=0 Time=11505 AState=Dialling
178214561mS H323Evt: v=0 stacknum=1 State, new=NullState, old=NullState id=-1
178214565mS H323Evt: v=0 stacknum=1 State, new=Initiated, old=NullState id=1022
178214845mS H323Evt: v=0 stacknum=1 State, new=OverlapSend, old=Initiated id=1022
178214846mS CMLineRx: v=1
CMSetupAck
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
178214846mS CMCallEvt: 0.1021.0 8 TargetingEP: RequestEnd 0.1022.0 8 H323TrunkEP
178214846mS CMTARGET: 253.1020.0 8 Ext82303.0: CancelTimer CMTCNoAnswerTimeout
178214847mS CMCallEvt: 0.1021.0 -1 BaseEP: DELETE CMEndpoint f577b77c TOTAL NOW=2 CALL_LIST=1
178214847mS CMCallEvt: 0.1022.0 8 H323TrunkEP: StateChange: END=B CMCSOffering->CMCSOverlapRecv
178214848mS CMExtnTx: v=82303, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
IE CMIEFastStartInfoData (6)
Timed: 24/06/10 08:37
178214849mS CMExtnTx: v=82303, p1=8002
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1 in=1
IE CMIEFastStartInfoData (6)
178214849mS CD: CALL: 253.1020.0 BState=Idle Cut=2 Music=0.0 Aend="Ext82303(82303)" (0.0) Bend="Line 1" [Line 1] (251.1) CalledNum=82323 () CallingNum=82303 (Ext82303) Internal=0 Time=11794 AState=Dialling
178215443mS H323Evt: v=0 stacknum=1 State, new=Delivered, old=OverlapSend id=1022
178215444mS CMLineRx: v=1
CMAlerting
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
178215444mS CMCallEvt: 0.1022.0 8 H323TrunkEP: StateChange: END=B CMCSOverlapRecv->CMCSRinging
178215445mS CMCallEvt: 253.1020.0 8 Ext82303.0: StateChange: END=A CMCSDialling->CMCSRingBack
178215445mS CMExtnEvt: v=1 State, new=Alerting old=Dialling,0,0,Ext82303
178215447mS CMExtnTx: v=82303, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
IE CMIEFastStartInfoData (6)
Timed: 24/06/10 08:37
178215447mS CMExtnTx: v=82303, p1=8002
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1 in=1
IE CMIEFastStartInfoData (6)
178215448mS CMExtnTx: v=82303, p1=0
CMAlerting
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=982323
IE CMIEDeviceDetail (231) LOCALE=eng HW=8 VER=5 class=CMDeviceH323Trunk type=0 number=1 channel=0 rx_gain=32 tx_gain=32 ep_callid=1022 ipaddr=172.30.77.1 apps=0
Timed: 24/06/10 08:37
178215448mS PRN: SendCallStateId Module=0 Button=7 state=4
178215450mS CD: CALL: 253.1020.0 BState=Ringing Cut=3 Music=2.0 Aend="Ext82303(82303)" (0.0) Bend="Line 1" [Line 1] (251.1) CalledNum=82323 () CallingNum=82303 (Ext82303) Internal=0 Time=12394 AState=Ringing
178215450mS CMMap: PCG::AddToneGenerator g R1[3] for cp[110]b0r1 append pcp[113]b0r1 (total 1)
178215450mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[113]b0r1 Configure 0.0
178215451mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[113]b0r1 ConnectIndication 0.0
178215451mS CMMap: a=0.0 b=0.0 pcp[110]b0r1 RTPR1
178215658mS RES: Thu 24/6/2010 08:37:45 FreeMem=74540484(2) CMMsg=5 (5) Buff=200 959 1000 7470 5 Links=4241
178215658mS RES2: IP 500 5.0(8) Tasks=32 RTEngine=0 CMRTEngine=0 Timer=43 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1
178219389mS H323Evt: v=0 stacknum=1 State, new=Active, old=Delivered id=1022
178219391mS CMLineRx: v=1
CMConnect
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Main_SS
IE CMIEPrimitiveData (7)
Display [Main_SS]
178219391mS CMCallEvt: 0.1022.0 8 H323TrunkEP: StateChange: END=B CMCSRinging->CMCSConnReq
178219391mS CMCallEvt: 253.1020.0 8 Ext82303.0: StateChange: END=A CMCSRingBack->CMCSOGConnReq
178219391mS CMExtnEvt: v=1 State, new=Connected old=Alerting,0,0,Ext82303
178219392mS CMExtnTx: v=82303, p1=0
CMConnect
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Main_SS
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=982323
IE CMIEDeviceDetail (231) LOCALE=eng HW=8 VER=5 class=CMDeviceH323Trunk type=0 number=1 channel=0 rx_gain=32 tx_gain=32 ep_callid=1022 ipaddr=172.30.77.1 apps=0
Display [Main_SS]
Timed: 24/06/10 08:37
178219392mS CMExtnRx: v=82303, p1=0
CMConnectAck
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
178219393mS CMCallEvt: 253.1020.0 8 Ext82303.0: StateChange: END=A CMCSOGConnReq->CMCSConnected
178219393mS CMTARGET: 253.1020.0 8 Ext82303.0: ~CMTargetHandler
178219394mS CMCallEvt: 0.1022.0 8 H323TrunkEP: StateChange: END=B CMCSConnReq->CMCSConnected
178219395mS CMMap: a=6.1 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder resource busy 1, total 4

[makrur]

Part 3

178219395mS CMLineTx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178219396mS CMLineTx: v=1
CMConnectAck
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
178219396mS CD: CALL: 253.1020.0 BState=Connected Cut=3 Music=0.0 Aend="Ext82303(82303)" (0.0) Bend="Line 1" [Line 1] (251.1) CalledNum=82323 () CallingNum=82303 (Ext82303) Internal=0 Time=16341 AState=Connected
178219397mS CMMap: a=0.0 b=0.0 pcp[110]b0r1 RTPR0
178219397mS CMMap: PCG::MapBChan pcp[110]b0r1 cp_b 0 other_cp_b 0 type CGTypeSimple
178219398mS PRN: SendCallStateId Module=0 Button=7 state=5
178219474mS CMLineRx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178219476mS CMExtnTx: v=82303, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=982323
IE CMIEDeviceDetail (231) LOCALE=eng HW=8 VER=5 class=CMDeviceH323Trunk type=0 number=1 channel=0 rx_gain=32 tx_gain=32 ep_callid=1022 ipaddr=172.30.77.1 apps=0
Timed: 24/06/10 08:37
178219477mS CMLineTx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178219477mS CD: CALL: 253.1020.0 BState=Connected Cut=3 Music=0.0 Aend="Ext82303(82303)" (0.0) Bend="Line 1" [Line 1] (251.1) CalledNum=82323 () CallingNum=82303 (Ext82303) Internal=0 Time=16422 AState=Connected
178219831mS CMLineRx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178219833mS CMExtnTx: v=82303, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=982323
IE CMIEDeviceDetail (231) LOCALE=eng HW=8 VER=5 class=CMDeviceH323Trunk type=0 number=1 channel=0 rx_gain=32 tx_gain=32 ep_callid=1022 ipaddr=172.30.77.1 apps=0
Timed: 24/06/10 08:37
178219834mS CD: CALL: 253.1020.0 BState=Connected Cut=3 Music=0.0 Aend="Ext82303(82303)" (0.0) Bend="Line 1" [Line 1] (251.1) CalledNum=82323 () CallingNum=82303 (Ext82303) Internal=0 Time=16779 AState=Connected
178219836mS CMLineRx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178219838mS CMMap: a=6.17 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder resource busy 2, total 4
178219839mS CMExtnTx: v=82303, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=982323
IE CMIEDeviceDetail (231) LOCALE=eng HW=8 VER=5 class=CMDeviceH323Trunk type=0 number=1 channel=0 rx_gain=32 tx_gain=32 ep_callid=1022 ipaddr=172.30.77.1 apps=0
Timed: 24/06/10 08:37
178219840mS CMLineTx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178219840mS CD: CALL: 253.1020.0 BState=Connected Cut=3 Music=0.0 Aend="Ext82303(82303)" (0.0) Bend="Line 1" [Line 1] (251.1) CalledNum=82323 () CallingNum=82303 (Ext82303) Internal=0 Time=16785 AState=Connected
178219841mS CMMap: PCG::UnmapBChan pcp[110]b0r1 cp_b 0 other_cp_b 0
178219841mS CMMap: PCG::MapBChan pcp[110]b0r1 cp_b 0 other_cp_b 0 type CGTypeSimple
178219841mS CMMap: Mapper:elayedFreeCodec f5a6e720 found cp pcp[110]b0r1 use_reserved_codec 0 local_reserved_codec 0, is_mapped_b 0
178219842mS CMMap: a=6.1 b=0.0 Mapper::FreeCodec freed CMRTVocoder resource busy 1, total 4
178219842mS CMMap: Mapper:elayedFreeCodec f5a6ca20 found cp pcp[112]b0r0 use_reserved_codec 0 local_reserved_codec 0, is_mapped_b 0
178219842mS CMMap: a=6.17 b=0.0 Mapper::FreeCodec freed CMRTVocoder resource busy 0, total 4
178220040mS CMLineRx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178220041mS CMLineTx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178220043mS CMMap: a=6.1 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder resource busy 1, total 4
178220044mS CMExtnTx: v=82303, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=982323
IE CMIEDeviceDetail (231) LOCALE=eng HW=8 VER=5 class=CMDeviceH323Trunk type=0 number=1 channel=0 rx_gain=32 tx_gain=32 ep_callid=1022 ipaddr=172.30.77.1 apps=0
Timed: 24/06/10 08:37
178220045mS CMLineTx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178220045mS CMLineTx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178220046mS CD: CALL: 253.1020.0 BState=Connected Cut=3 Music=0.0 Aend="Ext82303(82303)" (0.0) Bend="Line 1" [Line 1] (251.1) CalledNum=82323 () CallingNum=82303 (Ext82303) Internal=0 Time=16991 AState=Connected

[makrur]

Part 4

178220046mS CMMap: PCG::UnmapBChan pcp[110]b0r1 cp_b 0 other_cp_b 0
178220047mS CMMap: PCG::MapBChan pcp[110]b0r1 cp_b 0 other_cp_b 0 type CGTypeSimple
178220047mS CMMap: Mapper:elayedFreeCodec f5a6e720 found cp pcp[112]b0r0 use_reserved_codec 0 local_reserved_codec 0, is_mapped_b 0
178220047mS CMMap: a=6.1 b=0.0 Mapper::FreeCodec freed CMRTVocoder resource busy 0, total 4
178220051mS CMLineRx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178220052mS CMMap: a=6.1 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder resource busy 1, total 4
178220053mS CMExtnTx: v=82303, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=982323
IE CMIEDeviceDetail (231) LOCALE=eng HW=8 VER=5 class=CMDeviceH323Trunk type=0 number=1 channel=0 rx_gain=32 tx_gain=32 ep_callid=1022 ipaddr=172.30.77.1 apps=0
Timed: 24/06/10 08:37
178220054mS CMLineTx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178220055mS CD: CALL: 253.1020.0 BState=Connected Cut=3 Music=0.0 Aend="Ext82303(82303)" (0.0) Bend="Line 1" [Line 1] (251.1) CalledNum=82323 () CallingNum=82303 (Ext82303) Internal=0 Time=16999 AState=Connected
178220055mS CMMap: PCG::UnmapBChan pcp[110]b0r1 cp_b 0 other_cp_b 0
178220055mS CMMap: PCG::MapBChan pcp[110]b0r1 cp_b 0 other_cp_b 0 type CGTypeSimple
178220056mS CMMap: Mapper:elayedFreeCodec f5a6e720 found cp pcp[112]b0r0 use_reserved_codec 0 local_reserved_codec 0, is_mapped_b 0
178220056mS CMMap: a=6.1 b=0.0 Mapper::FreeCodec freed CMRTVocoder resource busy 0, total 4
178220088mS CMLineRx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178220089mS CMMap: a=6.1 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder resource busy 1, total 4
178220090mS CMExtnTx: v=82303, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=982323
IE CMIEDeviceDetail (231) LOCALE=eng HW=8 VER=5 class=CMDeviceH323Trunk type=0 number=1 channel=0 rx_gain=32 tx_gain=32 ep_callid=1022 ipaddr=172.30.77.1 apps=0
Timed: 24/06/10 08:37
178220091mS CD: CALL: 253.1020.0 BState=Connected Cut=3 Music=0.0 Aend="Ext82303(82303)" (0.0) Bend="Line 1" [Line 1] (251.1) CalledNum=82323 () CallingNum=82303 (Ext82303) Internal=0 Time=17036 AState=Connected
178220092mS CMMap: PCG::UnmapBChan pcp[110]b0r1 cp_b 0 other_cp_b 0
178220092mS CMMap: PCG::MapBChan pcp[110]b0r1 cp_b 0 other_cp_b 0 type CGTypeSimple
178220092mS CMMap: Mapper:elayedFreeCodec f5a6e720 found cp pcp[112]b0r0 use_reserved_codec 0 local_reserved_codec 0, is_mapped_b 0
178220093mS CMMap: a=6.1 b=0.0 Mapper::FreeCodec freed CMRTVocoder resource busy 0, total 4
178220216mS CMLineRx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178220218mS CMExtnTx: v=82303, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=982323
IE CMIEDeviceDetail (231) LOCALE=eng HW=8 VER=5 class=CMDeviceH323Trunk type=0 number=1 channel=0 rx_gain=32 tx_gain=32 ep_callid=1022 ipaddr=172.30.77.1 apps=0
Timed: 24/06/10 08:37
178220219mS CD: CALL: 253.1020.0 BState=Connected Cut=3 Music=0.0 Aend="Ext82303(82303)" (0.0) Bend="Line 1" [Line 1] (251.1) CalledNum=82323 () CallingNum=82303 (Ext82303) Internal=0 Time=17164 AState=Connected
178220220mS H323Evt: AudioEndPoint::Configure detectNwFaxPackets set to 1
178220220mS CMMap: PCG::MapBChan pcp[112]b0r1 cp_b 0 other_cp_b 0 type CGTypeSimple
178220231mS CMLineRx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178220236mS CMExtnTx: v=82303, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=982323
IE CMIEDeviceDetail (231) LOCALE=eng HW=8 VER=5 class=CMDeviceH323Trunk type=0 number=1 channel=0 rx_gain=32 tx_gain=32 ep_callid=1022 ipaddr=172.30.77.1 apps=0
Timed: 24/06/10 08:37
178220237mS CMLineTx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178220238mS CD: CALL: 253.1020.0 BState=Connected Cut=3 Music=0.0 Aend="Ext82303(82303)" (0.0) Bend="Line 1" [Line 1] (251.1) CalledNum=82323 () CallingNum=82303 (Ext82303) Internal=0 Time=17182 AState=Connected
178220238mS CMMap: PCG::MapBChan pcp[112]b0r1 cp_b 0 other_cp_b 0 type CGTypeSimple
178220422mS PRN: H245LCSE::HandleOpenAck --- No outoging logical channel has the LC number 137
178220658mS RES: Thu 24/6/2010 08:37:50 FreeMem=74543672(2) CMMsg=5 (5) Buff=200 960 1000 7470 5 Links=4227
178220658mS RES2: IP 500 5.0(8) Tasks=32 RTEngine=0 CMRTEngine=0 Timer=45 Poll=0 Ready=1 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1
178221256mS H323Evt: RTP(50t): 192.168.77.9/49154 192.168.69.9/49154 CODEC=G729A8K(6) PKTSZ=20 RFC2833=off AGE=1036 SENT=50 (avg size=20) RECV=0 (avg size=0)
178232496mS CMLineRx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178232498mS CMExtnTx: v=82303, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=982323
IE CMIEDeviceDetail (231) LOCALE=eng HW=8 VER=5 class=CMDeviceH323Trunk type=0 number=1 channel=0 rx_gain=32 tx_gain=32 ep_callid=1022 ipaddr=172.30.77.1 apps=0
Timed: 24/06/10 08:38
178232499mS CMLineTx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178232499mS CD: CALL: 253.1020.0 BState=Connected Cut=3 Music=0.0 Aend="Ext82303(82303)" (0.0) Bend="Line 1" [Line 1] (251.1) CalledNum=82323 () CallingNum=82303 (Ext82303) Internal=0 Time=29444 AState=Connected
178232532mS PRN: H245LCSE::HandleClose --- Incoming logical channel 3 does not exist
178232535mS PRN: H245LCSE::HandleClose --- Incoming logical channel 3 does not exist
178232537mS CMLineRx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178232539mS CMMap: a=6.1 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder resource busy 1, total 4

[makrur]

Part 5

178232540mS CMExtnTx: v=82303, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=982323
IE CMIEDeviceDetail (231) LOCALE=eng HW=8 VER=5 class=CMDeviceH323Trunk type=0 number=1 channel=0 rx_gain=32 tx_gain=32 ep_callid=1022 ipaddr=172.30.77.1 apps=0
Timed: 24/06/10 08:38
178232541mS CMLineTx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178232541mS CMLineRx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178232543mS CMExtnTx: v=82303, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=982323
IE CMIEDeviceDetail (231) LOCALE=eng HW=8 VER=5 class=CMDeviceH323Trunk type=0 number=1 channel=0 rx_gain=32 tx_gain=32 ep_callid=1022 ipaddr=172.30.77.1 apps=0
Timed: 24/06/10 08:38
178232544mS CMLineTx: v=1
CMFacility
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
IE CMIEPrimitiveData (7)
178232544mS CD: CALL: 253.1020.0 BState=Connected Cut=3 Music=0.0 Aend="Ext82303(82303)" (0.0) Bend="Line 1" [Line 1] (251.1) CalledNum=82323 () CallingNum=82303 (Ext82303) Internal=0 Time=29489 AState=Connected
178232545mS CMMap: PCG::UnmapBChan pcp[112]b0r1 cp_b 0 other_cp_b 0
178232545mS CMMap: PCG::UnmapBChan pcp[110]b0r1 cp_b 0 other_cp_b 0
178232546mS CMMap: PCG::MapBChan pcp[110]b0r1 cp_b 0 other_cp_b 0 type CGTypeSimple
178232549mS H323Evt: v=0 stacknum=1 State, new=NullState, old=Active id=1022
178232550mS CMLineRx: v=1
CMReleaseComp
Line: type=IPLine 1 Call: lid=0 id=1022 in=0
Cause=16, Normal call clearing
178232550mS CMCallEvt: 0.1022.0 8 H323TrunkEP: StateChange: END=B CMCSConnected->CMCSCompleted
178232551mS CMExtnTx: v=82303, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
IE CMIEFastStartInfoData (6)
Timed: 24/06/10 08:38
178232552mS CMExtnTx: v=82303, p1=8002
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1 in=1
IE CMIEFastStartInfoData (6)
178232553mS CMLOGGING: CALL:2010/06/2408:37,00:00:13,003,82303,O,82323,982323,Ext82303 ,,,0,,""n/a,0
178232554mS CD: CALL: 253.1020.0 BState=Disconnecting Cut=1 Music=0.0 Aend="Ext82303(82303)" (0.0) Bend="Line 1" [Line 1] (251.1) CalledNum=82323 () CallingNum=82303 (Ext82303) Internal=0 Time=29499 AState=Connected
178232554mS CD: CALL: 253.1020.0 Deleted
178232555mS CMExtnEvt: Ext82303: CALL LOST (CMCauseNormal)
178232555mS CMExtnEvt: Ext82303: Extn(82303) Calling Party Number(82303) Type(CMNTypeInternal)
178232556mS CMCallEvt: 253.1020.0 -1 Ext82303.0: StateChange: END=X CMCSConnected->CMCSCompleted
178232556mS CMExtnEvt: v=1 State, new=PortRecoverDelay old=Connected,0,0,Ext82303
178232556mS CMExtnTx: v=82303, p1=0
CMReleaseComp
Line: type=IPLine 250 Call: lid=253 id=1020 in=0
Called[982323] Type=Default (100) Reason=CMDRdirect Calling[82303] Type=Internal Plan=Default
Cause=16, Normal call clearing
Timed: 24/06/10 08:38
178232557mS CMExtnTx: v=82303, p1=8002
CMFacility
Line: type=IPLine 250 Call: lid=253 id=1 in=1
IE CMIEFastStartInfoData (6)
178232557mS CMExtnEvt: Ext82303: CMExtnHandler::SetCurrent( id: 1020->0 )
178232557mS PRN: SendCallStateId Module=0 Button=7 state=0
178232558mS CMCallEvt: 253.1020.0 -1 Ext82303.-1: StateChange: END=X CMCSCompleted->CMCSDelete
178232559mS CMCallEvt: 253.1020.0 -1 BaseEP: DELETE CMEndpoint f577d730 TOTAL NOW=1 CALL_LIST=0
178232559mS CMCallEvt: 0.1022.0 -1 H323TrunkEP: StateChange: END=X CMCSCompleted->CMCSDelete
178232559mS CMCallEvt: END CALL:8 (f577c9c0)
178232561mS CMCallEvt: 0.1022.0 -1 BaseEP: DELETE CMEndpoint f5770040 TOTAL NOW=0 CALL_LIST=0
178232561mS CMMap: PCG::UnmapBChan pcp[110]b0r1 cp_b 0 other_cp_b 0
178232562mS H323Evt: RTP(END): 172.30.77.1/49152 172.30.77.4/51356 CODEC=G729A8K(6) PKTSZ=20 RFC2833=off AGE=29497 SENT=323 RECV=897 RTdelay=0 jitter=0 loss=0 remotejitter=0 remoteloss=0
178232562mS H323Evt: RTP(END): 192.168.77.9/49154 192.168.69.9/49154 CODEC=G729A8K(6) PKTSZ=20 RFC2833=off AGE=12342 SENT=614 RECV=0 RTdelay=0 jitter=0 loss=0 remotejitter=0 remoteloss=0
178232563mS CMMap: a=6.1 b=0.0 Mapper::FreeCodec freed CMRTVocoder resource busy 0, total 4
178232660mS RES: Thu 24/6/2010 08:38:02 FreeMem=74586844(2) CMMsg=5 (5) Buff=200 959 1000 7470 5 Links=4354
178232660mS RES2: IP 500 5.0(8) Tasks=32 RTEngine=0 CMRTEngine=0 Timer=43 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1
178234558mS CMExtnEvt: Ext82303: Recover Timer reason=CMTRWrapUp
178234558mS CMExtnEvt: v=1 State, new=Idle old=PortRecoverDelay,0,0,Ext82303
178234558mS CMExtnTx: v=82303, p1=0
CMVoiceMailStatus
Line: type=IPLine 250 Call: lid=0 id=-1 in=0
Called[Ext82303 Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Ext82303 Msgs=0]
Timed: 24/06/10 08:38
178234652mS CMCallEvt: 0.1023.0 -1 BaseEP: NEW CMEndpoint f577d730 TOTAL NOW=1 CALL_LIST=0
178234652mS CMCallEvt: 0.1023.0 -1 Ext82303.-1: NEW CMExtnEndpoint f577d730, Name=Ext82303, Extn=82303, Phys Extn=82303

[deville]

Hi,

Could you disable all other debug and select just ALL H323 debug (including packet content).

I just saw something strange in your precedent post. IP Phone are in the same subnet on both site ? 172.30.0.0/24 ?

[makrur]

I could disable them but not now since it is not polite to make trouble to the customer too often
Yes IP pones on the both IP offices are in the same network !
And why are you wondered ?
We in Russia can do far more suprising things and dreams come true

[deville]

Well, if you had disable Direct Media Path, theoretically, IP Phones on site A doesn't have to talk to IP Phones on site B. But it is quiet disturbing .
The main problem I see in this is that from the main site, you couldn't act directly in those network ... for example monitoring or simpling pinging.

I don't see why you think it will make trouble to just collect log and make a call ? In the monitor you can click "Clear All" to disable all debug option and then just select H323 options. And then you just have to try a call and save log ?

Maybe I mess something

[makrur]

The main problem I see in this is that from the main site, you couldn't act directly in those network ... for example monitoring or simpling pinging.

I don't need to act directly in those networks.
I didnt created this net for IP Office's. This client asked to solve the problem with voice. That's all
And you really think it is not enough to get the log-file I have already posted here ???

[convergedit]

I am having exactly the same problem I would like to post both IP office configs and monitor info but thinking its a codec issue

FreeCodec pcp[848]b0r1 freed CMRTVocoder resource busy 1