Avaya Support Forums

Avaya Support Forums (http://support.avaya.com/forums/index.php)
-   Small and Medium Business Communications (http://support.avaya.com/forums/forumdisplay.php?f=6)
-   -   IP Office - IP Office (H.323) voice problem (http://support.avaya.com/forums/showthread.php?t=212)

rmakru 06-28-2010 02:33 AM

IP Office - IP Office (H.323) voice problem
 
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::DelayedFreeCodec 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::DelayedFreeCodec 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 06-28-2010 08:39 AM

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 06-29-2010 10:30 AM

Quote:

Originally Posted by deville (Post 579)
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 :confused::confused::confused:
Thanks !!!!!!!!!!

deville 06-30-2010 01:50 AM

Hi,

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

makrur 06-30-2010 06:42 AM

I have already has it :p

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 06-30-2010 06:43 AM

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 06-30-2010 06:44 AM

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::DelayedFreeCodec 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::DelayedFreeCodec 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 06-30-2010 06:44 AM

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::DelayedFreeCodec 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::DelayedFreeCodec 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::DelayedFreeCodec 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 06-30-2010 06:45 AM

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 06-30-2010 08:52 AM

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 ?


All times are GMT -7. The time now is 07:58 AM.