Avaya SIP Out Of Service Problem.

[joel2121]

I have had Avaya Sip line working for almost 6 months between my 2 Branch offices on one side I have Panasonic TDE 100 PBX whereas on the other side its Avaya IP 500 V2.
From last 30 days or so the sip lines have problem. The moment I restart Avaya IP PBX the SIP Lines work ie idle and after 6 minutes the lines go out of service. Neither Avaya or Pansonic or Watchguard (Firewall) technicians have been able to rectify the problem.
Please help in this issue.

 

[hairlessupportmonkey]

There would be some event in Monitor showing the trunk dropping. since its only 6 mins worth of waiting, just watch monitor...

ACSS - SME
General Geek

 

[Gunnaro]

A bit thin description on the setup, but it sounds like changes were made to the network. Upgrades of firewalls, rules added or deleted, new network added, new DSL provider, other....?

- In the initial 6 minutes, can you place calls between the sites?
- How do you connect the sites, vpn site-site or port forwarding?

I'd start with the firewalls, find out what was changed ~30 days ago.


Kind regards

Gunnar
__________________________________________________________________
Hippos have bad eyesight, but considering their weight, it’s hardly their problem

 

[hairlessupportmonkey]

Im almost inclined to think the VPN tunnels are not stable due to broadband...

ACSS - SME
General Geek

 

[joel2121]

Hi,
In the initial 6 minutes the calls between sip is possible no problems dialing on both the sides but immediately after 6 minutes of reboot in Avaya system status the line shows out of service also no changes were done on both firewalls no policy added deleted.
when a person dials from Panasonic side in can see in Avaya system status the call landing but it doesn't get to the extension dialed. Panasonic unified console doesn't have system status similar to Avaya.

 

[joel2121]

341412mS CMCallEvt: 262.1031.0 10 Hazel.0: StateChange: END=A CMCSOGConnReq->CMCSConnected
341413mS CMTARGET: 262.1031.0 10 Hazel.0: ~CMTargetHandler f4f19950 ep f4f04388
341414mS CMCallEvt: 0.1034.0 10 Alog Trunk:2: StateChange: END=B CMCSConnReq->CMCSConnected
341416mS CMLineTx: v=2
CMConnectAck
Line: type=AnalogueLine 2 Call: lid=0 id=1034 in=0
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Hazel
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=302
IE CMIEDeviceDetail (231) LOCALE=aru HW=15 VER=8 class=CMDeviceH323Phone type=88 number=8011 channel=0 rx_gain=32 tx_gain=32 ep_callid=1031 ipaddr=192.168.2.10 apps=0
341420mS CMMap: a=1.2 b=0.0 PCGS CPReserveCodec (pcp[116]b0r1) true
341420mS CMMap: a=1.2 b=0.0 PCGS CPReserveCodec (pcp[116]b0r1) true
341420mS CMMap: PCG::MapBChan pcp[116]b0r1 cp_b f58871d8 other_cp_b f585cf78 type CGTypeSimple
341421mS CMMap: a=1.2 b=0.18 M12
341802mS RES: Sun 24/8/2014 13:24:14 FreeMem=57342376 56989720(1) CachedMem=352656 CMMsg=6(9) Buff=5200 1428 999 12444 5 Links=1889 BTree=0 CPU=1/5/14499/17441/18256/3
341802mS RES2: IP 500 V2 8.1(85) Tasks=50 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=99 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=93 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
341802mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
342705mS H323Evt: Recv: RegistrationRequest 192.168.2.78; Endpoints registered: 38; Endpoints in registration: 0
343407mS SIP Reg/Opt Tx: 17
OPTIONS sip:192.168.1.85 SIP/2.0
Via: SIP/2.0/UDP 192.168.3.15:5060;rport;branch=z9hG4bKe81b86e84f02e46944965d210f68e38c
From: <sip:192.168.3.15>;tag=342b20e8e026d222
To: <sip:192.168.1.85>
Call-ID: ad4931b978013a232994cc9c793d0277
CSeq: 2089262204 OPTIONS
Contact: <sip:192.168.3.15:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
Supported: timer
User-Agent: IP Office 8.1 (85)
Content-Length: 0

343407mS SIP Tx: UDP 192.168.3.15:5060 -> 192.168.1.85:5060
0000 4f 50 54 49 4f 4e 53 20 73 69 70 3a 31 39 32 2e OPTIONS sip:192.
0010 31 36 38 2e 31 2e 38 35 20 53 49 50 2f 32 2e 30 168.1.85 SIP/2.0
0020 0d 0a 56 69 61 3a 20 53 49 50 2f 32 2e 30 2f 55 ..Via: SIP/2.0/U
0030 44 50 20 31 39 32 2e 31 36 38 2e 33 2e 31 35 3a DP 192.168.3.15:
0040 35 30 36 30 3b 72 70 6f 72 74 3b 62 72 61 6e 63 5060;rport;branc
0050 68 3d 7a 39 68 47 34 62 4b 65 38 31 62 38 36 65 h=z9hG4bKe81b86e
0060 38 34 66 30 32 65 34 36 39 34 34 39 36 35 64 32 84f02e46944965d2
0070 31 30 66 36 38 65 33 38 63 0d 0a 46 72 6f 6d 3a 10f68e38c..From:
0080 20 3c 73 69 70 3a 31 39 32 2e 31 36 38 2e 33 2e <sip:192.168.3.
0090 31 35 3e 3b 74 61 67 3d 33 34 32 62 32 30 65 38 15>;tag=342b20e8
00a0 65 30 32 36 64 32 32 32 0d 0a 54 6f 3a 20 3c 73 e026d222..To: <s
00b0 69 70 3a 31 39 32 2e 31 36 38 2e 31 2e 38 35 3e ip:192.168.1.85>
00c0 0d 0a 43 61 6c 6c 2d 49 44 3a 20 61 64 34 39 33 ..Call-ID: ad493
00d0 31 62 39 37 38 30 31 33 61 32 33 32 39 39 34 63 1b978013a232994c
00e0 63 39 63 37 39 33 64 30 32 37 37 0d 0a 43 53 65 c9c793d0277..CSe
00f0 71 3a 20 32 30 38 39 32 36 32 32 30 34 20 4f 50 q: 2089262204 OP
0100 54 49 4f 4e 53 0d 0a 43 6f 6e 74 61 63 74 3a 20 TIONS..Contact:
0110 3c 73 69 70 3a 31 39 32 2e 31 36 38 2e 33 2e 31 <sip:192.168.3.1
0120 35 3a 35 30 36 30 3b 74 72 61 6e 73 70 6f 72 74 5:5060;transport
0130 3d 75 64 70 3e 0d 0a 4d 61 78 2d 46 6f 72 77 61 =udp>..Max-Forwa
0140 72 64 73 3a 20 37 30 0d 0a 41 6c 6c 6f 77 3a 20 rds: 70..Allow:
0150 49 4e 56 49 54 45 2c 20 41 43 4b 2c 20 43 41 4e INVITE, ACK, CAN
0160 43 45 4c 2c 20 4f 50 54 49 4f 4e 53 2c 20 42 59 CEL, OPTIONS, BY
0170 45 2c 20 52 45 46 45 52 2c 20 4e 4f 54 49 46 59 E, REFER, NOTIFY
0180 2c 20 49 4e 46 4f 2c 20 55 50 44 41 54 45 0d 0a , INFO, UPDATE..
0190 53 75 70 70 6f 72 74 65 64 3a 20 74 69 6d 65 72 Supported: timer
01a0 0d 0a 55 73 65 72 2d 41 67 65 6e 74 3a 20 49 50 ..User-Agent: IP
01b0 20 4f 66 66 69 63 65 20 38 2e 31 20 28 38 35 29 Office 8.1 (85)
01c0 0d 0a 43 6f 6e 74 65 6e 74 2d 4c 65 6e 67 74 68 ..Content-Length
01d0 3a 20 30 0d 0a 0d 0a : 0....
343482mS H323Evt: Recv: RegistrationRequest 192.168.2.185; Endpoints registered: 38; Endpoints in registration: 0
343508mS CD: CALL: 262.1031.0 BState=Connected Cut=3 Music=0.0 Aend="Hazel(302)" (0.0) Bend="Line 2" [Line 2] (1.2) CalledNum=0504873053 () CallingNum=302 (Hazel) Internal=0 Time=7531 AState=Connected
344807mS H323Evt: Recv: RegistrationRequest 192.168.2.182; Endpoints registered: 38; Endpoints in registration: 0
345808mS H323Evt: Recv: RegistrationRequest 192.168.2.148; Endpoints registered: 38; Endpoints in registration: 0
346802mS RES: Sun 24/8/2014 13:24:20 FreeMem=57342432 56989720(1) CachedMem=352712 CMMsg=6(9) Buff=5200 1428 999 12444 5 Links=1888 BTree=0 CPU=1/4/14499/17392/18256/3
346803mS RES2: IP 500 V2 8.1(85) Tasks=50 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=97 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=93 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
346803mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
346808mS H323Evt: Recv: RegistrationRequest 192.168.2.87; Endpoints registered: 38; Endpoints in registration: 0
347810mS H323Evt: Recv: RegistrationRequest 192.168.2.37; Endpoints registered: 38; Endpoints in registration: 0
348537mS H323Evt: Recv: RegistrationRequest 192.168.2.171; Endpoints registered: 38; Endpoints in registration: 0
349928mS H323Evt: Recv: RegistrationRequest 192.168.2.74; Endpoints registered: 38; Endpoints in registration: 0
350693mS H323Evt: Recv: RegistrationRequest 192.168.2.238; Endpoints registered: 38; Endpoints in registration: 0
351748mS H323Evt: Recv: RegistrationRequest 192.168.2.199; Endpoints registered: 38; Endpoints in registration: 0
354070mS H323Evt: Recv: RegistrationRequest 192.168.2.198; Endpoints registered: 38; Endpoints in registration: 0
356939mS H323Evt: Recv: RegistrationRequest 192.168.2.116; Endpoints registered: 38; Endpoints in registration: 0
358128mS H323Evt: Recv: RegistrationRequest 192.168.2.95; Endpoints registered: 38; Endpoints in registration: 0
359407mS SIP Reg/Opt Tx: 17
OPTIONS sip:192.168.1.85 SIP/2.0
Via: SIP/2.0/UDP 192.168.3.15:5060;rport;branch=z9hG4bKe81b86e84f02e46944965d210f68e38c
From: <sip:192.168.3.15>;tag=342b20e8e026d222
To: <sip:192.168.1.85>
Call-ID: ad4931b978013a232994cc9c793d0277
CSeq: 2089262204 OPTIONS
Contact: <sip:192.168.3.15:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
Supported: timer
User-Agent: IP Office 8.1 (85)
Content-Length: 0

359407mS SIP Tx: UDP 192.168.3.15:5060 -> 192.168.1.85:5060
0000 4f 50 54 49 4f 4e 53 20 73 69 70 3a 31 39 32 2e OPTIONS sip:192.
0010 31 36 38 2e 31 2e 38 35 20 53 49 50 2f 32 2e 30 168.1.85 SIP/2.0
0020 0d 0a 56 69 61 3a 20 53 49 50 2f 32 2e 30 2f 55 ..Via: SIP/2.0/U
0030 44 50 20 31 39 32 2e 31 36 38 2e 33 2e 31 35 3a DP 192.168.3.15:
0040 35 30 36 30 3b 72 70 6f 72 74 3b 62 72 61 6e 63 5060;rport;branc
0050 68 3d 7a 39 68 47 34 62 4b 65 38 31 62 38 36 65 h=z9hG4bKe81b86e
0060 38 34 66 30 32 65 34 36 39 34 34 39 36 35 64 32 84f02e46944965d2
0070 31 30 66 36 38 65 33 38 63 0d 0a 46 72 6f 6d 3a 10f68e38c..From:
0080 20 3c 73 69 70 3a 31 39 32 2e 31 36 38 2e 33 2e <sip:192.168.3.
0090 31 35 3e 3b 74 61 67 3d 33 34 32 62 32 30 65 38 15>;tag=342b20e8
00a0 65 30 32 36 64 32 32 32 0d 0a 54 6f 3a 20 3c 73 e026d222..To: <s
00b0 69 70 3a 31 39 32 2e 31 36 38 2e 31 2e 38 35 3e ip:192.168.1.85>
00c0 0d 0a 43 61 6c 6c 2d 49 44 3a 20 61 64 34 39 33 ..Call-ID: ad493
00d0 31 62 39 37 38 30 31 33 61 32 33 32 39 39 34 63 1b978013a232994c
00e0 63 39 63 37 39 33 64 30 32 37 37 0d 0a 43 53 65 c9c793d0277..CSe
00f0 71 3a 20 32 30 38 39 32 36 32 32 30 34 20 4f 50 q: 2089262204 OP
0100 54 49 4f 4e 53 0d 0a 43 6f 6e 74 61 63 74 3a 20 TIONS..Contact:
0110 3c 73 69 70 3a 31 39 32 2e 31 36 38 2e 33 2e 31 <sip:192.168.3.1
0120 35 3a 35 30 36 30 3b 74 72 61 6e 73 70 6f 72 74 5:5060;transport
0130 3d 75 64 70 3e 0d 0a 4d 61 78 2d 46 6f 72 77 61 =udp>..Max-Forwa
0140 72 64 73 3a 20 37 30 0d 0a 41 6c 6c 6f 77 3a 20 rds: 70..Allow:
0150 49 4e 56 49 54 45 2c 20 41 43 4b 2c 20 43 41 4e INVITE, ACK, CAN
0160 43 45 4c 2c 20 4f 50 54 49 4f 4e 53 2c 20 42 59 CEL, OPTIONS, BY
0170 45 2c 20 52 45 46 45 52 2c 20 4e 4f 54 49 46 59 E, REFER, NOTIFY
0180 2c 20 49 4e 46 4f 2c 20 55 50 44 41 54 45 0d 0a , INFO, UPDATE..
0190 53 75 70 70 6f 72 74 65 64 3a 20 74 69 6d 65 72 Supported: timer
01a0 0d 0a 55 73 65 72 2d 41 67 65 6e 74 3a 20 49 50 ..User-Agent: IP
01b0 20 4f 66 66 69 63 65 20 38 2e 31 20 28 38 35 29 Office 8.1 (85)
01c0 0d 0a 43 6f 6e 74 65 6e 74 2d 4c 65 6e 67 74 68 ..Content-Length
01d0 3a 20 30 0d 0a 0d 0a : 0....
361407mS Sip: SIP Line (17) No response to SIP Options Messages - setting trunk out of service
361408mS Sip: SIPDialog f4eed520 deleted, dialogs 0
361807mS RES: Sun 24/8/2014 13:24:34 FreeMem=57337592 56966904(1) CachedMem=370688 CMMsg=6(9) Buff=5200 1428 999 12444 5 Links=1693 BTree=0 CPU=3/5/14499/17395/18256/3
361807mS RES2: IP 500 V2 8.1(85) Tasks=50 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=96 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=93 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
361807mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
362690mS CMCallEvt: 0.1035.0 -1 BaseEP: NEW CMEndpoint f4ef4248 TOTAL NOW=3 CALL_LIST=1
362690mS CMCallEvt: 0.1035.0 -1 PP3 Control Roo.-1: NEW CMExtnEndpoint f4ef4248, Name=PP3 Control Roo, Extn=132, Phys Extn=132
362691mS CMCallEvt: CREATE CALL:11 (f4f14280)
362691mS CMCallEvt: 0.1036.0 -1 BaseEP: NEW CMEndpoint f4f021e0 TOTAL NOW=4 CALL_LIST=1
362693mS CMExtnEvt: PP3 Control Roo: CMExtnHandler::SetCurrent( id: 0->1035 )
362694mS CMExtnRx: v=132, p1=0
CMSetup
Line: type=IPLine 250 Call: lid=311 id=1035 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[132] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIEFastStartInfoData (6) 10 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=PP3 Control Roo
362694mS CMCallEvt: 311.1035.0 11 PP3 Control Roo.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
362694mS CMExtnEvt: v=13 State, new=Dialling old=Idle,0,0,PP3 Control Roo
362695mS CMTARGET: 311.1035.0 11 PP3 Control Roo.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=132 dir=out complete=0 ses=0
362695mS CMTARGET: 311.1035.0 11 PP3 Control Roo.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
362695mS CMCallEvt: 311.1035.0 11 PP3 Control Roo.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
362698mS CMExtnTx: v=132, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=311 id=1035 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIESecurityData (253) 2 item(s)
Timed: 24/08/14 13:24
362698mS CMExtnTx: v=132, p1=8060
CMFacility
Line: type=IPLine 250 Call: lid=311 id=13 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
362699mS CMExtnTx: v=132, p1=0
CMSetupAck
Line: type=IPLine 250 Call: lid=311 id=1035 in=0
Timed: 24/08/14 13:24
362700mS CD: CALL: 311.1035.0 BState=Idle Cut=1 Music=3.0 Aend="PP3 Control Roo(132)" (0.0) Bend="" [] (0.0) CalledNum= () CallingNum=132 (PP3 Control Roo) Internal=1 Time=9 AState=DialInitiated
362703mS H323Evt: SetOperational 12 192.168.2.10:0 to 0
362703mS CMMap: PCG::AddToneGenerator g D1[1] for cp[117]b0r1 append pcp[118]b0r1 (total 1)
362703mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[118]b0r1 Configure 0.0
362704mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[118]b0r1 ConnectIndication 0.0
362704mS CMMap: a=0.0 b=0.0 pcp[117]b0r1 RTPD1
362704mS H323Evt: SetOperational 12 192.168.2.10:49154 to 1
363286mS PRN: PP3 Control Roo: Feature Key Pressed 3CPLFeatureRedial
363551mS CMExtnRx: v=132, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=311 id=1035 in=0
Called[133] Type=Default (100) Reason=CMDRdirect SndComp
363551mS CMTARGET: 311.1035.0 11 PP3 Control Roo.0: LOOKUP CALL ROUTE: type=100 called_party=133 sub= calling=132 dir=out complete=1 ses=0
363551mS CMTARGET: 311.1035.0 11 PP3 Control Roo.0: ADD TARGET (N): number=133 type=100 depth=1 nobar=1 setorig=1 ses=0
363551mS CMTARGET: 311.1035.0 11 PP3 Control Roo.0: SET USER: PP1/PP2 Control orig=1
363551mS CMTARGET: 311.1035.0 11 PP3 Control Roo.0: ADD USER: PP1/PP2 Control depth=1 disallow_cw=0 dnd=0 real_call=1 group_call=0 type(CMNTypeDefault) incl(0x0) excpt(0x0), allow_redir(1) remote=00000000 simult 0 (0)
363552mS CMCallEvt: 0.1037.0 -1 BaseEP: NEW CMEndpoint f4f0c838 TOTAL NOW=5 CALL_LIST=2
363552mS CMCallEvt: 0.1037.0 -1 PP1/PP2 Control.-1: NEW CMExtnEndpoint f4f0c838, Name=PP1/PP2 Control, Extn=133, Phys Extn=133
363554mS CMTARGET: 325.1037.0 11 PP1/PP2 Control.0: ADD PRIMARY
363554mS CMTARGET: 311.1035.0 11 PP3 Control Roo.0: CancelTimer CMTCDialToneTimeout
363554mS CMTARGET: 311.1035.0 11 PP3 Control Roo.0: INITIAL TARGETING SUCCEEDED
363554mS CMTARGET: 311.1035.0 11 PP3 Control Roo.0: GetNoAnswerTimer:14
363555mS CMCallEvt: 311.1035.0 11 PP3 Control Roo.0: StateChange: END=A CMCSDialling->CMCSDialled
363555mS CMExtnEvt: v=13 State, new=Proceeding old=Dialling,0,0,PP3 Control Roo
363556mS CMExtnTx: v=132, p1=0
CMProceeding
Line: type=IPLine 250 Call: lid=311 id=1035 in=0
Timed: 24/08/14 13:24
363557mS CMCallEvt: 0.1036.0 11 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
363558mS CMCallEvt: 325.1037.0 11 PP1/PP2 Control.0: StateChange: END=T CMCSIdle->CMCSOffering
363559mS CMExtnEvt: PP1/PP2 Control: CMExtnHandler::SetCurrent( id: 0->1037 )
363560mS CMExtnTx: v=133, p1=0
CMSetup
Line: type=IPLine 250 Call: lid=325 id=1037 in=0
Called[133] Type=Default (100) Reason=CMDRdirect SndComp Calling[132] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIEFastStartInfoData (6) 6 item(s)
IE CMIECallSignalChannelData (8) unknown
IE CMIEMediaWaitForConnect (16) CMIEMediaWaitForConnect
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=PP3 Control Roo
IE CMIECalledPartyName (224)(Type=CMNameDefault) name=PP1/PP2 Control
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=PP3 Control Roo
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=132
IE CMIEDeviceDetail (231) LOCALE=aru HW=15 VER=8 class=CMDeviceH323Phone type=88 number=8060 channel=0 rx_gain=32 tx_gain=32 ep_callid=1035 ipaddr=192.168.2.10 apps=0
IE CMIEMohSourceId (247) MOH Source = 255
Display [PP3 Control Roo>PP1/PP2 Control]
Timed: 24/08/14 13:24
Locale: aru
363560mS CMExtnRx: v=133, p1=0
CMAlerting
Line: type=IPLine 250 Call: lid=325 id=1037 in=0
363560mS CMCallEvt: 325.1037.0 11 PP1/PP2 Control.0: StateChange: END=T CMCSOffering->CMCSRinging
363561mS CMExtnEvt: v=29 State, new=Ringing old=Idle,0,0,PP1/PP2 Control
363561mS CMCallEvt: 0.1036.0 11 TargetingEP: StateChange: END=B CMCSOffering->CMCSRinging
363562mS CMCallEvt: 311.1035.0 11 PP3 Control Roo.0: StateChange: END=A CMCSDialled->CMCSRingBack
363562mS CMExtnEvt: v=13 State, new=Alerting old=Proceeding,0,0,PP3 Control Roo
363563mS CMExtnTx: v=132, p1=0
CMAlerting
Line: type=IPLine 250 Call: lid=311 id=1035 in=0
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=PP1/PP2 Control
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=133
IE CMIEDeviceDetail (231) LOCALE=aru HW=15 VER=8 class=CMDeviceH323Phone type=88 number=8074 channel=0 rx_gain=32 tx_gain=32 ep_callid=1037 ipaddr=192.168.2.10 apps=0
Timed: 24/08/14 13:24
363566mS CD: CALL: 311.1035.0 BState=Ringing Cut=1 Music=2.0 Aend="PP3 Control Roo(132)" (0.0) Bend="PP1/PP2 Control(133)" [PP1/PP2 Control(133)] (0.0) CalledNum=133 (PP1/PP2 Control) CallingNum=132 (PP3 Control Roo) Internal=1 Time=875 AState=Ringin
363569mS CMMap: a=0.0 b=0.0 pcp[117]b0r1 RTPD0
363569mS H323Evt: SetOperational 12 192.168.2.10:49154 to 0
363569mS CMMap: PCG::AddToneGenerator g R1[3] for cp[117]b0r1 append pcp[120]b0r1 (total 1)
363569mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[120]b0r1 Configure 0.0
363569mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[120]b0r1 ConnectIndication 0.0
363570mS CMMap: a=0.0 b=0.0 pcp[117]b0r1 RTPR1
363570mS H323Evt: SetOperational 12 192.168.2.10:49154 to 1
363699mS H323Evt: RTP(50t): 192.168.2.10/49154 192.168.2.193/51752 CODEC=Alaw64K(4) PKTSZ=160 RFC2833=off AGE=996 SENT=50 (avg size=160) RECV=39 (avg size=160)
365788mS H323Evt: Recv: RegistrationRequest 192.168.2.227; Endpoints registered: 38; Endpoints in registration: 0
366330mS CMExtnEvt: Jayan/Gururajan: No user activity
366808mS H323Evt: Recv: RegistrationRequest 192.168.2.218; Endpoints registered: 38; Endpoints in registration: 0
367785mS H323Evt: Recv: RegistrationRequest 192.168.2.172; Endpoints registered: 38; Endpoints in registration: 0
367810mS RES: Sun 24/8/2014 13:24:41 FreeMem=57287200 56966392(1) CachedMem=320808 CMMsg=6(9) Buff=5200 1428 999 12444 5 Links=1586 BTree=0 CPU=1/5/14499/17079/18256/3
367810mS RES2: IP 500 V2 8.1(85) Tasks=50 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=97 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=93 TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
367811mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
367823mS CMExtnTx: v=302, p1=8011
CMFacility
Line: type=IPLine 250 Call: lid=262 id=6 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
367823mS CMExtnRx: v=302, p1=0
CMReleaseComp
Line: type=IPLine 250 Call: lid=262 id=1031 in=0
367823mS CMCallEvt: 262.1031.0 10 Hazel.0: StateChange: END=A CMCSConnected->CMCSCompleted
367824mS CMExtnEvt: v=6 State, new=PortRecoverDelay old=Connected,0,0,Hazel
367826mS CMExtnTx: v=302, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=262 id=1031 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 24/08/14 13:24
367826mS PRN: CDR - TCPSend maxqueuesize=3000 framecount=0 operational=1
367827mS CMLOGGING: CALL:2014/08/2413:24,00:00:26,000,302,O,0504873053,0504873053,Hazel,,,0,,""n/a,0
367827mS CD: CALL: 262.1031.0 BState=Connected Cut=2 Music=0.0 Aend="PLine 2" (0.0) Bend="Line 2" [Line 2] (1.2) CalledNum=0504873053 () CallingNum=302 (Hazel) Internal=0 Time=31850 AState=Idle
367828mS CD: CALL: 262.1031.0 Deleted
367829mS CMExtnEvt: Hazel: CALL LOST (CMCauseNormal)
367829mS CMExtnEvt: Hazel: Extn(302) Calling Party Number(302) Type(CMNTypeInternal)
367829mS CMExtnEvt: Hazel: CMExtnHandler::SetCurrent( id: 1031->0 )
367830mS CMCallEvt: 262.1031.0 -1 Hazel.-1: StateChange: END=X CMCSCompleted->CMCSDelete
367832mS CMCallEvt: 0.1034.0 -1 Alog Trunk:2: StateChange: END=X CMCSConnected->CMCSDelete
367832mS CMCallEvt: 0.1034.0 -1 BaseEP: DELETE CMEndpoint f4efa908 TOTAL NOW=4 CALL_LIST=1
367832mS CMCallEvt: END CALL:10 (f4f036b0)
367833mS CMCallEvt: 262.1031.0 -1 BaseEP: DELETE CMEndpoint f4f04388 TOTAL NOW=3 CALL_LIST=1
367836mS CMMap: PCG::UnmapBChan pcp[79]b1r0 cp_b f585cf78 other_cp_b f58871d8
367836mS CMMap: a=0.18 b=1.2 M02
367836mS CMMap: PlatformConnectionAudioSAP:isconnectVoice rtpRelay ID: 1 Close success
367836mS H323Evt: SetOperational 11 192.168.2.10:49152 to 0
367836mS CMMap: PCG::UnmapBChan pcp[116]b0r1 cp_b 0 other_cp_b 0
367837mS H323Evt: RTP(END): 192.168.2.10/49152 192.168.2.218/51752 CODEC=Alaw64K(4) PKTSZ=160 RFC2833=off AGE=31847 SENT=1541 RECV=1552 RTdelay=0 jitter=0 loss=0 remotejitter=0 remoteloss=0
367838mS CMMap: a=0.18 b=0.0 Mapper::FreeCodec freed CMRTVocoder resource busy 1, total 20
368817mS H323Evt: Recv: RegistrationRequest 192.168.2.25; Endpoints registered: 38; Endpoints in registration: 0
369818mS H323Evt: Recv: RegistrationRequest 192.168.2.179; Endpoints registered: 38; Endpoints in registration: 0
369830mS CMExtnEvt: Hazel: Recover Timer reason=CMTRWrapUp
369830mS CMExtnEvt: v=6 State, new=Idle old=PortRecoverDelay,0,0,Hazel
369830mS CMExtnTx: v=302, p1=0
CMVoiceMailStatus
Line: type=IPLine 250 Call: lid=0 id=-1 in=0
Called[Hazel Msgs=41 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000041] Type=Default Plan=Default
Display [Hazel Msgs=41]
Timed: 24/08/14 13:24
370842mS H323Evt: Recv: RegistrationRequest 192.168.2.20; Endpoints registered: 38; Endpoints in registration: 0
371847mS H323Evt: Recv: RegistrationRequest 192.168.2.28; Endpoints registered: 38; Endpoints in registration: 0
372873mS H323Evt: Recv: RegistrationRequest 192.168.2.26; Endpoints registered: 38; Endpoints in registration: 0
373554mS CMTARGET: 311.1035.0 11 PP3 Control Roo.0: TimerExpired cause=CMTCCoverageTimeout
373554mS CMTARGET: 311.1035.0 11 PP3 Control Roo.0: GetNoAnswerTimer:14

 

[intrigrant]

If you add a trace then please make it a useful one with a filter for the specific problem.
As it is a SIP problem then disable everything except the SIP messages, start a trace 5.5 minutes after the reboot of IP Office and stop it shortly after the line goes out of service. Then you might have captured the problem.
To my guess the problem is that the keep alive packets send by IP Office or the replies from the other end are blocked within the VPN.
Happens most often due to "H.323 fixups" or whatever these netowork morons call it. The tunnel must be 100% transparent to all data traffic.

 

[nbfd731]

361407mS Sip: SIP Line (17) No response to SIP Options Messages - setting trunk out of service
361408mS Sip: SIPDialog f4eed520 deleted, dialogs 0

ACSS SME

 

[Gunnaro]

-> 361407mS Sip: SIP Line (17) No response to SIP Options Messages - setting trunk out of service

OPTIONS, that is a keep alive mechanism.
Don't see any response from the other side, that's why your line goes down.

But your trace is a bit short, so we don't see if it ever got a response.
You should do as Intrigrant instructed.



Kind regards

Gunnar
__________________________________________________________________
Hippos have bad eyesight, but considering their weight, it’s hardly their problem

 

[Gunnaro]

@nbfd731, didn't mean to echo you
(making cappuccino while typing slows me down)

Kind regards

Gunnar
__________________________________________________________________
Hippos have bad eyesight, but considering their weight, it’s hardly their problem

 

[intrigrant]

This is usefull information with respect to the problem.

 

[intrigrant]

And some more from Avaya:

5.10. SIP Options

Avaya IP Office sends SIP OPTIONS messages periodically to determine if the SIP connection is active.
The rate at which the messages are sent is determined by the combination of the Binding Refresh Time (in seconds) set on the Network Topology tab in Section 5.1 and the SIP_OPTIONS_PERIOD parameter (in minutes)that can be set on the Source Number tab of the NoUser user.

The OPTIONS period is determined in the following manner:

If no SIP_OPTIONS_PERIOD parameter is defined and the Binding Refresh Time is 0, then the default value of 42 seconds is used.
To establish a period less than 42 seconds, do not define a SIP_OPTIONS_PERIOD parameter and set the Binding Refresh Time to a value less than 42 secs .
The OPTIONS message period will be equal to the Binding Refresh Time.

To establish a period greater than 42 seconds, a SIP_OPTIONS_PERIOD parameter must be defined.The Binding Refresh Time must be set to a value greater than 42 secs.
The OPTIONS message period will be the smaller of the Binding Refresh Time or the SIP_OPTIONS_PERIOD.

To configure the SIP_OPTIONS_PERIOD parameter, navigate to User noUser in the Navigation/Group Panes.
Select the Source Numbers tab in the Details Pane. Click the Add button.
At the bottom of the Details Pane, the Source Number field will appear. Enter SIP_OPTIONS_PERIOD =X, where X is the desired value in minutes. Click OK.

 

[joel2121]

Currently I unchecked the option of Check OOS in Avaya IP 500.

And I am able to make SIP calls from Panasonic to Avaya.
But the same doesn't work for Avaya to Panasonic

It disconnects immediately.

9/1/14 2:34:27 PM-126ms Extension = 141, Switchhook, Status = Off
9/1/14 2:34:27 PM-127ms Call Ref = 177, Originator State = Incoming Alerting, Type = Trunk, Destination State = Alerting, Type = User
9/1/14 2:34:27 PM-138ms Line = 17, Channel = 1, SIP Message = Response, Call Ref = 177, Direction = From Switch, From = 452@192.168.1.85, To = 141@192.168.1.85, Response = 200 OK
9/1/14 2:34:29 PM-157ms Line = 17, Channel = 1, SIP Message = Ack, Call Ref = 177, Direction = To Switch, From = 452@192.168.1.85, To = 141@192.168.1.85
9/1/14 2:34:29 PM-159ms Call Ref = 177, Originator State = Connected, Type = Trunk, Destination State = Connected, Type = User
9/1/14 2:34:29 PM-159ms Call Ref = 177, Answered, Extension = 141
9/1/14 2:34:32 PM-705ms Line = 17, Channel = 1, SIP Message = Bye, Call Ref = 177, Direction = To Switch, From = 452@192.168.1.85, To = 141@192.168.1.85
9/1/14 2:34:32 PM-707ms Line = 17, Channel = 1, SIP Message = Response, Call Ref = 177, Direction = From Switch, From = 452@192.168.1.85, To = 141@192.168.1.85, Response = 200 OK
9/1/14 2:34:32 PM-711ms Call Ref = 177, Originator State = Clearing, Type = Trunk, Destination State = Connected, Type = User
9/1/14 2:34:32 PM-711ms Call Ref = 177, Disconnect from Originator End
9/1/14 2:34:36 PM-797ms Call Ref = 180, Short Code Matched = User, 4xx
9/1/14 2:34:36 PM-800ms Call Ref = 180, Originator State = Dialling, Type = User, Destination State = Seized, Type = Target List
9/1/14 2:34:36 PM-806ms Line = 17, Channel = 1, SIP Message = Invite, Call Ref = 180, Direction = From Switch, From = 141@192.168.1.85, To = 452@192.168.1.86
9/1/14 2:34:41 PM-408ms Call Ref = 180, Originator State = Dialling, Type = User, Destination State = Clearing, Type = Trunk
9/1/14 2:34:41 PM-408ms Call Ref = 180, Disconnect from Destination End

 

[hairlessupportmonkey]

Can you give us a run down of your network topology?



ACSS - SME
General Geek

 

[amriddle01]

Disconnect from Destination End", the Panasonic bins the call off

 

[joel2121]

SIP lines between Panasonic TDE 100 and Avaya IP 500V2.
There are interlinked between 2 offices through watchguard BOVPN.

The SIP lines were working fine for around 5 months. Once we restarted the Panasonic PBX the Virtual 16-Channel SIP Trunk Card V-SIPGW16 was showing out of service.
After reconfiguring the same we were finally able to put it to INS state.

Now the problem is I am able to do a call from Panasonic to Avaya
But I am not able to make a call from Avaya to Panasonic

 

[amriddle01]

Nice... it's still the Panasonic dropping the call though, so focus your attention there to see why