Cisco Support Community
cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
Community Member

SIP Incoming Calls Dropping

Hello

I have recently replaced my PSTN telephone with SIP provided over DSL.  I am using an iPad client is-phone lite as well as a PC client provided by the telecoms provider without problems and I have been trying for a few days to configure a SPA514G desk phone too.

The problem with the SPA514G, despite of having played with many settings is that although outgoing calls work ok, incoming calls are dropped immediately after the call is answered.  I have been trying to debug this and below is some debugging information I grabbed, hoping it will allow someone to give me some idea on what settings to change.  M y understanding is that the call gets estabilshed and then, for some reason the SPA514G sends BYE (see bold).  I repeat this only happens with incoming calls; outgoing calls work ok.

Please note 192.168.10.1 is the internal IP of the SPA514G, 10.224.50.81 is the IP address of the telecoms provider DSL modem which also acts like a firewall.  All telephone numbers and names have been replaced by X's.


Date Time Priority Hostname  Message
10-06-2013 00:46:06 Local3.Debug 192.168.10.1 PHN_setAudioPath(0)
10-06-2013 00:46:05 Local0.Info 192.168.10.1
10-06-2013 00:46:05 Local0.Info 192.168.10.1
10-06-2013 00:46:05 Local0.Info 192.168.10.1 [0]CC:NewCallState 0/13
10-06-2013 00:46:05 Local0.Info 192.168.10.1 [0]CC:NewCallState 0/13
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 CC:Ended
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 [0:0]AUD Rel Call
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 sa disconn 0
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 ucId: 0, bRtpTxEnable: 1, ucNumRtpTxEnable--: 0
10-06-2013 00:46:05 Local0.Info 192.168.10.1
10-06-2013 00:46:05 Local0.Info 192.168.10.1
10-06-2013 00:46:05 Local7.Debug 192.168.10.1 SIP/2.0 200 OK To: "XXX XXXXXXX XXXXXXXXXX X XXXXXXXX" ;tag=751994e1e6e953b4i0 From: ;tag=h7g4Esbg_813498695-1381009744501- Call-ID: BW0049045010610131083935365@10.224.50.81 CSeq: 88879420 BYE Via: SIP/2.0/UDP 10.224.42.132:5060;branch=z9hG4bK1xdsn9374lnv6hfx7zbsyye9w Server: Cisco/SPA514G-7.5.5 Content-Length: 0
10-06-2013 00:46:05 Local0.Info 192.168.10.1 [0:5060]->10.224.42.132:5060{384)
10-06-2013 00:46:05 Local0.Info 192.168.10.1 [0:5060]->10.224.42.132:5060{384)
10-06-2013 00:46:05 Local0.Info 192.168.10.1
10-06-2013 00:46:05 Local0.Info 192.168.10.1
10-06-2013 00:46:05 Local7.Debug 192.168.10.1 BYE sip:XXXXXXXX@192.168.10.1:5060 SIP/2.0 Max-Forwards: 8 Via: SIP/2.0/UDP 10.224.42.132:5060;branch=z9hG4bK1xdsn9374lnv6hfx7zbsyye9w To: "XXX XXXXXXX XXXXXXXXXX X XXXXXXXX" ;tag=751994e1e6e953b4i0 From: ;tag=h7g4Esbg_813498695-1381009744501- Call-ID: BW0049045010610131083935365@10.224.50.81 CSeq: 88879420 BYE Reason: Q.850 ;cause=1;text="Interworking unspecified" Content-Length: 0
10-06-2013 00:46:05 Local0.Info 192.168.10.1 [0:5060]<<10.224.42.132:5060
10-06-2013 00:46:05 Local0.Info 192.168.10.1 [0:5060]<<10.224.42.132:5060
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 [0:0]RTP Up (pt=18 dpt=18 16474->10.224.42.7:45548)
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 Remote loopback mode: None. Type None.
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 Local loopback mode: None. Type: None.
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 isConference: 0
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 ucId: 0, bRtpTxEnable: 0, ucNumRtpTxEnable++: 1
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 kosmos_update_dsp_channel_profile(tcid=0, n=5, pucDpt=0x94f73510, txPt=18)
10-06-2013 00:46:05 Local2.Debug 192.168.10.1
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 0
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 13
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 142
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 8
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 18
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 Codec list:
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 Already have tcid 0
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 ptime adjusted to 20ms.
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 c->ucState=13
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 AUD_startRtpTx(). [0:0]. 10.224.42.7:45548. Local port 16474. Payload type 18. Payload size 20 ms.
10-06-2013 00:46:05 Local0.Info 192.168.10.1
10-06-2013 00:46:05 Local0.Info 192.168.10.1
10-06-2013 00:46:05 Local0.Info 192.168.10.1 [0]CC:NewCallState 13/12
10-06-2013 00:46:05 Local0.Info 192.168.10.1 [0]CC:NewCallState 13/12
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 CC:Connected
10-06-2013 00:46:05 Local0.Info 192.168.10.1
10-06-2013 00:46:05 Local0.Info 192.168.10.1
10-06-2013 00:46:05 Local7.Debug 192.168.10.1 ACK sip:XXXXXXXX@192.168.10.1:5060 SIP/2.0 Max-Forwards: 8 Via: SIP/2.0/UDP 10.224.42.132:5060;branch=z9hG4bKm4ftxmqse1t3vtxkdsgitvv8g To: "XXX XXXXXXX XXXXXXXXXX X XXXXXXXX" ;tag=751994e1e6e953b4i0 From: ;tag=h7g4Esbg_813498695-1381009744501- Call-ID: BW0049045010610131083935365@10.224.50.81 CSeq: 88879419 ACK Contact: Content-Length: 0
10-06-2013 00:46:05 Local0.Info 192.168.10.1 [0:5060]<<10.224.42.132:5060
10-06-2013 00:46:05 Local0.Info 192.168.10.1 [0:5060]<<10.224.42.132:5060
10-06-2013 00:46:05 Local0.Info 192.168.10.1
10-06-2013 00:46:05 Local0.Info 192.168.10.1
10-06-2013 00:46:05 Local7.Debug 192.168.10.1 SIP/2.0 200 OK To: "XXX XXXXXXX XXXXXXXXXX X XXXXXXXX" ;tag=751994e1e6e953b4i0 From: ;tag=h7g4Esbg_813498695-1381009744501- Call-ID: BW0049045010610131083935365@10.224.50.81 CSeq: 88879419 INVITE Via: SIP/2.0/UDP 10.224.42.132:5060;branch=z9hG4bKcf1vq3f34141rzozcdgzx4kmh Record-Route: Contact: "XXXXXXXX" Server: Cisco/SPA514G-7.5.5 Content-Length: 226 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE Supported: 100rel, replaces Content-Type: application/sdp v=0 o=- 6306 6306 IN IP4 192.168.10.1 s=- c=IN IP4 192.168.10.1 t=0 0 m=audio 16474 RTP/AVP 18 100 a=rtpmap:18 G729a/8000 a=fmtp:18 annexb=no a=rtpmap:100 telephone-event/8000 a=fmtp:100 0-15 a=ptime:20 a=sendrecv
10-06-2013 00:46:05 Local0.Info 192.168.10.1 [0:5060]->10.224.42.132:5060{859)
10-06-2013 00:46:05 Local0.Info 192.168.10.1 [0:5060]->10.224.42.132:5060{859)
10-06-2013 00:46:05 Local0.Info 192.168.10.1 Respond 200 OK in SIP_dlgSessCmdProc
10-06-2013 00:46:05 Local0.Info 192.168.10.1 Respond 200 OK in SIP_dlgSessCmdProc
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 [0:0]RTP Rx Up. tcid 0.
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 kosmos_update_dsp_channel_profile(tcid=0, n=5, pucDpt=0x94f73510, txPt=18)
10-06-2013 00:46:05 Local2.Debug 192.168.10.1
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 0
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 13
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 142
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 8
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 18
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 Codec list:
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 AUD_startRtpRx: Grabbed new tcid 0
10-06-2013 00:46:05 Local2.Debug 192.168.10.1 AUD_startRtpRx(). [0:0]. Port 16474. Ip 0x0. Tx txPayloadType 18.
10-06-2013 00:46:05 Local0.Info 192.168.10.1
10-06-2013 00:46:05 Local0.Info 192.168.10.1
10-06-2013 00:46:05 Local0.Info 192.168.10.1 [0]CC:NewCallState 12/10
10-06-2013 00:46:05 Local0.Info 192.168.10.1 [0]CC:NewCallState 12/10
10-06-2013 00:46:05 Local3.Debug 192.168.10.1 [CCTRL]record lcr phone=XXXXXXXX exten=0
10-06-2013 00:46:05 Local3.Debug 192.168.10.1 PHN_setAudioPath(3)
10-06-2013 00:46:00 Local3.Debug 192.168.10.1 fu:0:0ee3c, 5.1.1 1
10-06-2013 00:46:00 Local0.Info 192.168.10.1
10-06-2013 00:46:00 Local0.Info 192.168.10.1
10-06-2013 00:46:00 Local7.Debug 192.168.10.1 SIP/2.0 400 Missing Subscription-State Via: SIP/2.0/UDP 192.168.10.1:5060;received=10.229.44.12;branch=z9hG4bK-138c1560 To: ;tag=i8f1vygrdnqj5l9xkbuf6mxh6jkdtcsg From: "XXXXXXXX" ;tag=7a16dcd062678eb9o0 Call-ID: b5a18efc-3d8aa27d@192.168.10.1 CSeq: 1 NOTIFY Content-Length: 0
10-06-2013 00:46:00 Local0.Info 192.168.10.1 [0:5060]<<10.224.42.132:5060
10-06-2013 00:46:00 Local0.Info 192.168.10.1 [0:5060]<<10.224.42.132:5060
10-06-2013 00:46:00 Local0.Info 192.168.10.1
10-06-2013 00:46:00 Local0.Info 192.168.10.1
10-06-2013 00:46:00 Local7.Debug 192.168.10.1 NOTIFY sip:sbg.fmc.cyta.com.cy SIP/2.0 Via: SIP/2.0/UDP 192.168.10.1:5060;branch=z9hG4bK-138c1560 From: "XXXXXXXX" ;tag=7a16dcd062678eb9o0 To: Call-ID: b5a18efc-3d8aa27d@192.168.10.1 CSeq: 1 NOTIFY Max-Forwards: 70 Contact: "XXXXXXXX" Event: keep-alive User-Agent: Cisco/SPA514G-7.5.5 Content-Length: 0
10-06-2013 00:46:00 Local0.Info 192.168.10.1 [0:5060]->10.224.42.132:5060{405)
10-06-2013 00:46:00 Local0.Info 192.168.10.1 [0:5060]->10.224.42.132:5060{405)
10-06-2013 00:46:00 Local0.Info 192.168.10.1 [0]Reg Addr Change(0) 0:0->ae02a84:5060
10-06-2013 00:46:00 Local0.Info 192.168.10.1 [0]Reg Addr Change(0) 0:0->ae02a84:5060
10-06-2013 00:46:00 Local0.Info 192.168.10.1
10-06-2013 00:46:00 Local0.Info 192.168.10.1
10-06-2013 00:46:00 Local7.Debug 192.168.10.1 SIP/2.0 180 Ringing To: "XXX XXXXXXX XXXXXXXXXX X XXXXXXXX" ;tag=751994e1e6e953b4i0 From: ;tag=h7g4Esbg_813498695-1381009744501- Call-ID: BW0049045010610131083935365@10.224.50.81 CSeq: 88879419 INVITE Via: SIP/2.0/UDP 10.224.42.132:5060;branch=z9hG4bKcf1vq3f34141rzozcdgzx4kmh Record-Route: Contact: "XXXXXXXX" Server: Cisco/SPA514G-7.5.5 Content-Length: 0
10-06-2013 00:46:00 Local0.Info 192.168.10.1 [0:5060]->10.224.42.132:5060{498)
10-06-2013 00:46:00 Local0.Info 192.168.10.1 [0:5060]->10.224.42.132:5060{498)
10-06-2013 00:46:00 Local2.Debug 192.168.10.1 [0:0]AUD ALLOC CALL (port=16474)
10-06-2013 00:46:00 Local1.Debug 192.168.10.1 In InitVoipMetrics
10-06-2013 00:46:00 Local1.Debug 192.168.10.1 In InitRemoteVoipMetrics
10-06-2013 00:46:00 Local2.Debug 192.168.10.1 SDP RTPMAP 100 --> 142
10-06-2013 00:46:00 Local3.Debug 192.168.10.1 dhcp opt 125: ""
10-06-2013 00:46:00 Local3.Debug 192.168.10.1 dhcp opt 43: ""
10-06-2013 00:46:00 Local3.Debug 192.168.10.1 dhcp opt 60: ""
10-06-2013 00:46:00 Local3.Debug 192.168.10.1 dhcp opt 150: ""
10-06-2013 00:46:00 Local3.Debug 192.168.10.1 dhcp opt 159: ""
10-06-2013 00:46:00 Local3.Debug 192.168.10.1 dhcp opt 160: ""
10-06-2013 00:46:00 Local3.Debug 192.168.10.1 dhcp opt 66: ""
10-06-2013 00:46:00 Local3.Debug 192.168.10.1 fhs:04:0:0004:upg:app:2:7.5.5
10-06-2013 00:46:00 Local3.Debug 192.168.10.1 fhs:03:0:0003:upg:app:1:7.5.5
10-06-2013 00:46:00 Local0.Info 192.168.10.1 START_RING in CC_refresh
10-06-2013 00:46:00 Local0.Info 192.168.10.1 START_RING in CC_refresh
10-06-2013 00:46:00 Local3.Debug 192.168.10.1 [CCTRL]record lcr phone=XXXXXXXX exten=0 type=0
10-06-2013 00:46:00 Local0.Info 192.168.10.1
10-06-2013 00:46:00 Local0.Info 192.168.10.1
10-06-2013 00:46:00 Local0.Info 192.168.10.1 [0]CC:NewCallState 10/0
10-06-2013 00:46:00 Local0.Info 192.168.10.1 [0]CC:NewCallState 10/0
10-06-2013 00:46:00 Local2.Debug 192.168.10.1 pc(0)=0 not in codec list
10-06-2013 00:46:00 Local0.Info 192.168.10.1 +++++ find idle call i = 0, caid=0 (asked 0)
10-06-2013 00:46:00 Local0.Info 192.168.10.1 +++++ find idle call i = 0, caid=0 (asked 0)
10-06-2013 00:46:00 Local0.Info 192.168.10.1
10-06-2013 00:46:00 Local0.Info 192.168.10.1
10-06-2013 00:46:00 Local7.Debug 192.168.10.1 SIP/2.0 100 Trying To: "XXX XXXXXXX XXXXXXXXXX X XXXXXXXX" From: ;tag=h7g4Esbg_813498695-1381009744501- Call-ID: BW0049045010610131083935365@10.224.50.81 CSeq: 88879419 INVITE Via: SIP/2.0/UDP 10.224.42.132:5060;branch=z9hG4bKcf1vq3f34141rzozcdgzx4kmh Record-Route: Server: Cisco/SPA514G-7.5.5 Content-Length: 0
10-06-2013 00:46:00 Local0.Info 192.168.10.1 [0:5060]->10.224.42.132:5060{420)
10-06-2013 00:46:00 Local0.Info 192.168.10.1 [0:5060]->10.224.42.132:5060{420)
10-06-2013 00:46:00 Local0.Info 192.168.10.1
10-06-2013 00:46:00 Local0.Info 192.168.10.1
10-06-2013 00:46:00 Local7.Debug 192.168.10.1 INVITE sip:XXXXXXXX@192.168.10.1:5060 SIP/2.0 Max-Forwards: 8 Via: SIP/2.0/UDP 10.224.42.132:5060;branch=z9hG4bKcf1vq3f34141rzozcdgzx4kmh To: "XXX XXXXXXX XXXXXXXXXX X XXXXXXXX" From: ;tag=h7g4Esbg_813498695-1381009744501- Call-ID: BW0049045010610131083935365@10.224.50.81 CSeq: 88879419 INVITE Contact: Record-Route: Min-Se: 600 P-Asserted-Identity: P-Called-Party-ID: Privacy: none Session-Expires: 1800 Content-Type: application/sdp Content-Length: 296 Allow: ACK, BYE, CANCEL, INVITE, OPTIONS, PRACK, REFER, NOTIFY, INFO, UPDATE Accept: application/media_control+xml Accept: application/sdp Accept: application/x-broadworks-call-center+xml Accept: multipart/mixed v=0 o=BroadWorks 50028954 1 IN IP4 10.224.42.132 s=- c=IN IP4 10.224.42.7 t=0 0 m=audio 45548 RTP/AVP 18 8 100 a=rtpmap:18 G72...
10-06-2013 00:46:00 Local0.Info 192.168.10.1 [0:5060]<<10.224.42.132:5060
10-06-2013 00:46:00 Local0.Info 192.168.10.1 [0:5060]<<10.224.42.132:5060
10-06-2013 00:46:00 Local2.Debug 192.168.10.1 SDP RTPMAP 100 --> 142
10-06-2013 00:46:00 Local3.Debug 192.168.10.1 fhs:02:0:0002:upg:app:0:7.5.5
10-06-2013 00:46:00 Local3.Debug 192.168.10.1 fhs:01:0:0001:upg:app:M:7.5.2
10-06-2013 00:46:00 Local3.Debug 192.168.10.1 fbr:0:3000:3000:0ee22:0006:0005:7.5.5
10-06-2013 00:46:00 Local3.Debug 192.168.10.1 fls:faffffffff:1:85:2912
10-06-2013 00:46:00 Local3.Debug 192.168.10.1 fs:052180:052180:262144

Thansk

Michael

1 REPLY

Re: SIP Incoming Calls Dropping

The BYE is sent from your ISP and received from your SPA:

10-06-2013 00:46:05 Local7.Debug 192.168.10.1 BYE sip:XXXXXXXX@192.168.10.1:5060 SIP/2.0 Max-Forwards: 8 Via: SIP/2.0/UDP 10.224.42.132:5060;branch=z9hG4bK1xdsn9374lnv6hfx7zbsyye9w To: "XXX XXXXXXX XXXXXXXXXX X XXXXXXXX" ;tag=751994e1e6e953b4i0 From: ;tag=h7g4Esbg_813498695-1381009744501- Call-ID:BW0049045010610131083935365@10.224.50.81 CSeq: 88879420 BYE Reason: Q.850 ;cause=1;text="Interworking unspecified" Content-Length: 0


10-06-2013 00:46:05 Local0.Info 192.168.10.1 [0:5060]<<10.224.42.132:5060

10-06-2013 00:46:05 Local0.Info 192.168.10.1 [0:5060]<<10.224.42.132:5060

I'm not sure but the problem could be in the SPA codecs declaration.

The SPA uses the following notation for G.729: a=rtpmap:18 G729a/8000.

The RFC notation is a=rtpmap:18 G729/8000.

Can you trace a working call? Can you try to change the codec notation via Voice-SIP-SDP Payload Types menu?

Regards.

1063
Views
0
Helpful
1
Replies
CreatePlease to create content