Low rtp-timeout-sec hangs up call in ringing state - expected behaviour?
Hi, I have been testing inbound calls to a Nokia phone with handover to a cellphone number if I get MEDIA_TIMEOUT on the B leg of the call, and had to set rtp-timeout to a very low 6 seconds in order to get "fast" handover. This introduces an interesting side-effect that hangs up calls even in the ringing state after 6 seconds. Is this the desired behaviour of rtp-timeout-sec? My initial guess was that rtp-timeout-sec should only be valid for established calls where the two endpoints have exchanged rtp at some point but have stopped exchanging media. As far as I know a phone call in ringing state has not shared any RTP with the other endpoint until it gets early media or is answered. Should rtp-timeout-sec really be valid even when ringing? It seems to me that setting rtp-timeout-sec to 60 seconds would add an absolute time limit on ringing phone calls to 60 seconds, which I believe is not the actual purpose of this limit. Could anyone please share their thoughts on this matter? Thanks, Mikael
Are you geting 183+sdp from the nokia? the media timer only operates once media is established and only counts against you if the channel is being read from and that does not happen until you get a 183 or 200 w/sdp try putting a debug line in switch_rtp.c around 1520 printf("MISSED PACKETS %u/%u\n", rtp_session->missed_count, rtp_session->max_missed_packets); but try updating first there was a recent fix that may have prevented a timer surge at the beginning of calls. On Tue, Apr 28, 2009 at 6:20 AM, Mikael Aleksander Bjerkeland < mikael@bjerkeland.com> wrote:
Hi,
I have been testing inbound calls to a Nokia phone with handover to a cellphone number if I get MEDIA_TIMEOUT on the B leg of the call, and had to set rtp-timeout to a very low 6 seconds in order to get "fast" handover. This introduces an interesting side-effect that hangs up calls even in the ringing state after 6 seconds. Is this the desired behaviour of rtp-timeout-sec? My initial guess was that rtp-timeout-sec should only be valid for established calls where the two endpoints have exchanged rtp at some point but have stopped exchanging media. As far as I know a phone call in ringing state has not shared any RTP with the other endpoint until it gets early media or is answered. Should rtp-timeout-sec really be valid even when ringing?
It seems to me that setting rtp-timeout-sec to 60 seconds would add an absolute time limit on ringing phone calls to 60 seconds, which I believe is not the actual purpose of this limit. Could anyone please share their thoughts on this matter?
Thanks, Mikael
_______________________________________________ Freeswitch-users mailing list Freeswitch-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Anthony Minessale II FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/ AIM: anthm MSN:anthony_minessale@hotmail.com <MSN%3Aanthony_minessale@hotmail.com> GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com<PAYPAL%3Aanthony.minessale@gmail.com> IRC: irc.freenode.net #freeswitch FreeSWITCH Developer Conference sip:888@conference.freeswitch.org <sip%3A888@conference.freeswitch.org> iax:guest@conference.freeswitch.org/888 googletalk:conf+888@conference.freeswitch.org<googletalk%3Aconf%2B888@conference.freeswitch.org> pstn:213-799-1400
The scenario I was referring to was actually an outbound call from a locally registered SIP phone to a cellphone. The same thing happens whether I use a SIP or PRI trunk. After 6 s it hangs up. I get SDP on 183 no matter whether I'm calling a cellphone or a fixed line. I also get ringing indication. The 183+sdp is passed on to the Nokia and after 6 s the call is hung up. Both the SIP and PRI trunks claim to send early media but there seems to be no audio/RTP. If I answer the call in 6 s it's not dropped because the media path was established before RTP timeout. The same thing happens on latest trunk. I added the debug line at 1520 and did make && /etc/init.d/freeswitch stop && make install && /etc/init.d/freeswitch start but the debug line didn't show up anywhere in the CLI. Is my upstream provider doing something wrong in sending early media in these cases? Seems pretty odd. It can be avoided by setting a higher rtp-timeout-sec but it will still be an absolute timeout on ringing. A transcript of the log: send 1293 bytes to udp/[1.1.1.1]:5060 at 13:55:56.451865: ------------------------------------------------------------------------ INVITE sip:21651019@domain.appsvrslip11.prigw.com SIP/2.0 Via: SIP/2.0/UDP 2.2.2.2;rport;branch=z9hG4bKm3t6teHv30rBK Route: <sip:21651019@1.1.1.1> Max-Forwards: 69 From: "someone" <sip:23695000@2.2.2.2>;tag=m2SepeSZ63e3g To: <sip:21651019@domain.appsvrslip11.prigw.com> Call-ID: 23302ac7-ae9f-122c-198f-001ec9e8d9bc CSeq: 114345142 INVITE Contact: <sip:mod_sofia@2.2.2.2:5060> User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-13175M Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH Supported: timer, precondition, path, replaces Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 383 P-Asserted-Identity: "someone" <sip:23695000@2.2.2.2> v=0 o=FreeSWITCH 3718974841365302606 4309079514688066219 IN IP4 2.2.2.2 s=FreeSWITCH c=IN IP4 2.2.2.2 t=0 0 m=audio 52706 RTP/AVP 9 8 0 3 101 13 a=rtpmap:9 G722/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 m=video 52752 RTP/AVP 99 a=rtpmap:99 H264/90000 ------------------------------------------------------------------------ 2009-04-28 15:55:56 [DEBUG] sofia.c:2912 sofia_handle_sip_i_state() Channel sofia/external-eth1/21651019@domain.appsvrslip11.prigw.com;fs_path=sip:21651019@1.1.1.1 entering state [calling][0] recv 305 bytes from udp/[1.1.1.1]:5060 at 13:55:56.482864: ------------------------------------------------------------------------ SIP/2.0 100 Trying From: "someone"<sip:23695000@2.2.2.2>;tag=m2SepeSZ63e3g To: <sip:21651019@domain.appsvrslip11.prigw.com> Call-ID: 23302ac7-ae9f-122c-198f-001ec9e8d9bc CSeq: 114345142 INVITE Via: SIP/2.0/UDP 2.2.2.2;rport=5060;branch=z9hG4bKm3t6teHv30rBK Content-Length: 0 ------------------------------------------------------------------------ recv 1035 bytes from udp/[1.1.1.1]:5060 at 13:55:58.296906: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress From: "someone"<sip:23695000@2.2.2.2>;tag=m2SepeSZ63e3g To: <sip:21651019@domain.appsvrslip11.prigw.com>;tag=20134330840200942815366 Call-ID: 23302ac7-ae9f-122c-198f-001ec9e8d9bc CSeq: 114345142 INVITE Via: SIP/2.0/UDP 2.2.2.2;rport=5060;branch=z9hG4bKm3t6teHv30rBK content-type: application/sdp contact: <sip:1.1.1.1:5060;nt_end_pt=YM0 +~K!-.f0vfc830~P68.cio~H9zwgW0VyisWTdcaM26c610Xbo1.nfS.5NQt3mO~~70!-.f0vft815;nt_server_host=1.1.1.1> supported: 100rel x-nt-party-id: -/ allow: ACK allow: BYE allow: CANCEL allow: INVITE allow: OPTIONS allow: INFO allow: SUBSCRIBE allow: REFER allow: NOTIFY allow: PRACK server: CS2000_NGSS/9.0 Content-Length: 300 v=0 o=IWSPM 573585738 573585738 IN IP4 84.20.97.100 s=- e=unknown@invalid.net t=0 0 m=audio 45954 RTP/AVP 8 0 18 101 c=IN IP4 84.20.97.100 a=ptime:20 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 m=video 0 RTP/AVP 99 c=IN IP4 2.2.2.2 a=rtpmap:99 H264/90000 ------------------------------------------------------------------------ 2009-04-28 15:55:58 [DEBUG] sofia.c:2912 sofia_handle_sip_i_state() Channel sofia/external-eth1/21651019@domain.appsvrslip11.prigw.com;fs_path=sip:21651019@1.1.1.1 entering state [proceeding][183] 2009-04-28 15:55:58 [DEBUG] sofia.c:2919 sofia_handle_sip_i_state() Remote SDP: v=0 o=IWSPM 573585738 573585738 IN IP4 84.20.97.100 s=- e=unknown@invalid.net t=0 0 m=audio 45954 RTP/AVP 8 0 18 101 c=IN IP4 84.20.97.100 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 m=video 0 RTP/AVP 99 c=IN IP4 2.2.2.2 a=rtpmap:99 H264/90000 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2931 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000:20]/[G722:9:8000:20] 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2931 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000:20]/[PCMA:8:8000:20] 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:1912 sofia_glue_tech_set_codec() Set Codec sofia/external-eth1/21651019@domain.appsvrslip11.prigw.com;fs_path=sip:21651019@1.1.1.1 PCMA/8000 20 ms 160 samples 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2891 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2146 sofia_glue_activate_rtp() AUDIO RTP [sofia/external-eth1/21651019@domain.appsvrslip11.prigw.com;fs_path=sip:21651019@1.1.1.1] 2.2.2.2 port 52706 -> 84.20.97.100 port 45954 codec: 8 ms: 20 2009-04-28 15:55:58 [DEBUG] switch_rtp.c:906 switch_rtp_create() Starting timer [soft] 160 bytes per 20ms 2009-04-28 15:55:58 [NOTICE] sofia_glue.c:2573 sofia_glue_tech_media() Pre-Answer sofia/external-eth1/21651019@domain.appsvrslip11.prigw.com;fs_path=sip:21651019@1.1.1.1! 2009-04-28 15:55:58 [DEBUG] switch_channel.c:1736 switch_channel_perform_mark_pre_answered() Send signal sofia/internal/mikael-nokia@fs.voip.domain [BREAK] 2009-04-28 15:55:58 [DEBUG] switch_ivr_originate.c:1972 switch_ivr_originate() sofia/internal/mikael-nokia@fs.voip.domain receive message [PROGRESS] 2009-04-28 15:55:58 [INFO] mod_sofia.c:1377 sofia_receive_message() Asked to send early media by sofia/internal/mikael-nokia@fs.voip.domain 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2931 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000:20]/[G722:9:8000:20] 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2931 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000:20]/[PCMA:8:8000:20] 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:1912 sofia_glue_tech_set_codec() Set Codec sofia/internal/mikael-nokia@fs.voip.domain PCMA/8000 20 ms 160 samples 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2891 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 98 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2146 sofia_glue_activate_rtp() AUDIO RTP [sofia/internal/mikael-nokia@fs.voip.domain] 10.100.4.192 port 58072 -> 10.247.3.253 port 49152 codec: 8 ms: 20 2009-04-28 15:55:58 [DEBUG] switch_rtp.c:906 switch_rtp_create() Starting timer [soft] 160 bytes per 20ms 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2325 sofia_glue_activate_rtp() Set comfort noise payload to 13 2009-04-28 15:55:58 [NOTICE] sofia_glue.c:2573 sofia_glue_tech_media() Pre-Answer sofia/internal/mikael-nokia@fs.voip.domain! 2009-04-28 15:55:58 [INFO] mod_sofia.c:1420 sofia_receive_message() Ring SDP: v=0 o=FreeSWITCH 1240868886 1240868887 IN IP4 10.100.4.192 s=FreeSWITCH c=IN IP4 10.100.4.192 t=0 0 m=audio 58072 RTP/AVP 8 98 13 a=rtpmap:8 PCMA/8000 a=rtpmap:98 telephone-event/8000 a=fmtp:98 0-16 a=rtpmap:13 CN/8000 a=ptime:20 a=sendrecv El mar, 28-04-2009 a las 07:50 -0500, Anthony Minessale escribió:
Are you geting 183+sdp from the nokia? the media timer only operates once media is established and only counts against you if the channel is being read from and that does not happen until you get a 183 or 200 w/sdp
try putting a debug line in switch_rtp.c around 1520 printf("MISSED PACKETS %u/%u\n", rtp_session->missed_count, rtp_session->max_missed_packets);
but try updating first there was a recent fix that may have prevented a timer surge at the beginning of calls.
On Tue, Apr 28, 2009 at 6:20 AM, Mikael Aleksander Bjerkeland <mikael@bjerkeland.com> wrote: Hi,
I have been testing inbound calls to a Nokia phone with handover to a cellphone number if I get MEDIA_TIMEOUT on the B leg of the call, and had to set rtp-timeout to a very low 6 seconds in order to get "fast" handover. This introduces an interesting side-effect that hangs up calls even in the ringing state after 6 seconds. Is this the desired behaviour of rtp-timeout-sec? My initial guess was that rtp-timeout-sec should only be valid for established calls where the two endpoints have exchanged rtp at some point but have stopped exchanging media. As far as I know a phone call in ringing state has not shared any RTP with the other endpoint until it gets early media or is answered. Should rtp-timeout-sec really be valid even when ringing?
It seems to me that setting rtp-timeout-sec to 60 seconds would add an absolute time limit on ringing phone calls to 60 seconds, which I believe is not the actual purpose of this limit. Could anyone please share their thoughts on this matter?
Thanks, Mikael
_______________________________________________ Freeswitch-users mailing list Freeswitch-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Anthony Minessale II
FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/
AIM: anthm MSN:anthony_minessale@hotmail.com GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com IRC: irc.freenode.net #freeswitch
FreeSWITCH Developer Conference sip:888@conference.freeswitch.org iax:guest@conference.freeswitch.org/888 googletalk:conf+888@conference.freeswitch.org pstn:213-799-1400 _______________________________________________ Freeswitch-users mailing list Freeswitch-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
as soon as FS sees 183 it expects media. if they send 183 and no media it will most certainly timeout On Tue, Apr 28, 2009 at 9:33 AM, Mikael Aleksander Bjerkeland < mikael@bjerkeland.com> wrote:
The scenario I was referring to was actually an outbound call from a locally registered SIP phone to a cellphone. The same thing happens whether I use a SIP or PRI trunk. After 6 s it hangs up.
I get SDP on 183 no matter whether I'm calling a cellphone or a fixed line. I also get ringing indication. The 183+sdp is passed on to the Nokia and after 6 s the call is hung up. Both the SIP and PRI trunks claim to send early media but there seems to be no audio/RTP. If I answer the call in 6 s it's not dropped because the media path was established before RTP timeout.
The same thing happens on latest trunk. I added the debug line at 1520 and did make && /etc/init.d/freeswitch stop && make install && /etc/init.d/freeswitch start but the debug line didn't show up anywhere in the CLI.
Is my upstream provider doing something wrong in sending early media in these cases? Seems pretty odd. It can be avoided by setting a higher rtp-timeout-sec but it will still be an absolute timeout on ringing.
A transcript of the log:
send 1293 bytes to udp/[1.1.1.1]:5060 at 13:55:56.451865:
------------------------------------------------------------------------ INVITE sip:21651019@domain.appsvrslip11.prigw.com<sip%3A21651019@domain.appsvrslip11.prigw.com>SIP/2.0 Via: SIP/2.0/UDP 2.2.2.2;rport;branch=z9hG4bKm3t6teHv30rBK Route: <sip:21651019@1.1.1.1 <sip%3A21651019@1.1.1.1>> Max-Forwards: 69 From: "someone" <sip:23695000@2.2.2.2 <sip%3A23695000@2.2.2.2>
;tag=m2SepeSZ63e3g To: <sip:21651019@domain.appsvrslip11.prigw.com<sip%3A21651019@domain.appsvrslip11.prigw.com>
Call-ID: 23302ac7-ae9f-122c-198f-001ec9e8d9bc CSeq: 114345142 INVITE Contact: <sip:mod_sofia@2.2.2.2:5060> User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-13175M Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH Supported: timer, precondition, path, replaces Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 383 P-Asserted-Identity: "someone" <sip:23695000@2.2.2.2<sip%3A23695000@2.2.2.2>
v=0 o=FreeSWITCH 3718974841365302606 4309079514688066219 IN IP4 2.2.2.2 s=FreeSWITCH c=IN IP4 2.2.2.2 t=0 0 m=audio 52706 RTP/AVP 9 8 0 3 101 13 a=rtpmap:9 G722/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 m=video 52752 RTP/AVP 99 a=rtpmap:99 H264/90000
------------------------------------------------------------------------ 2009-04-28 15:55:56 [DEBUG] sofia.c:2912 sofia_handle_sip_i_state() Channel sofia/external-eth1/21651019@domain.appsvrslip11.prigw.com;fs_path= sip:21651019@1.1.1.1 <sip%3A21651019@1.1.1.1> entering state [calling][0] recv 305 bytes from udp/[1.1.1.1]:5060 at 13:55:56.482864:
------------------------------------------------------------------------ SIP/2.0 100 Trying From: "someone"<sip:23695000@2.2.2.2 <sip%3A23695000@2.2.2.2>
;tag=m2SepeSZ63e3g To: <sip:21651019@domain.appsvrslip11.prigw.com<sip%3A21651019@domain.appsvrslip11.prigw.com>
Call-ID: 23302ac7-ae9f-122c-198f-001ec9e8d9bc CSeq: 114345142 INVITE Via: SIP/2.0/UDP 2.2.2.2;rport=5060;branch=z9hG4bKm3t6teHv30rBK Content-Length: 0
------------------------------------------------------------------------ recv 1035 bytes from udp/[1.1.1.1]:5060 at 13:55:58.296906:
------------------------------------------------------------------------ SIP/2.0 183 Session Progress From: "someone"<sip:23695000@2.2.2.2 <sip%3A23695000@2.2.2.2>
;tag=m2SepeSZ63e3g To: <sip:21651019@domain.appsvrslip11.prigw.com<sip%3A21651019@domain.appsvrslip11.prigw.com> ;tag=20134330840200942815366 Call-ID: 23302ac7-ae9f-122c-198f-001ec9e8d9bc CSeq: 114345142 INVITE Via: SIP/2.0/UDP 2.2.2.2;rport=5060;branch=z9hG4bKm3t6teHv30rBK content-type: application/sdp contact: <sip:1.1.1.1:5060;nt_end_pt=YM0
+~K!-.f0vfc830~P68.cio~H9zwgW0VyisWTdcaM26c610Xbo1.nfS.5NQt3mO~~70!-.f0vft815;nt_server_host=1.1.1.1> supported: 100rel x-nt-party-id: -/ allow: ACK allow: BYE allow: CANCEL allow: INVITE allow: OPTIONS allow: INFO allow: SUBSCRIBE allow: REFER allow: NOTIFY allow: PRACK server: CS2000_NGSS/9.0 Content-Length: 300
v=0 o=IWSPM 573585738 573585738 IN IP4 84.20.97.100 s=- e=unknown@invalid.net t=0 0 m=audio 45954 RTP/AVP 8 0 18 101 c=IN IP4 84.20.97.100 a=ptime:20 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 m=video 0 RTP/AVP 99 c=IN IP4 2.2.2.2 a=rtpmap:99 H264/90000
------------------------------------------------------------------------ 2009-04-28 15:55:58 [DEBUG] sofia.c:2912 sofia_handle_sip_i_state() Channel sofia/external-eth1/21651019@domain.appsvrslip11.prigw.com;fs_path= sip:21651019@1.1.1.1 <sip%3A21651019@1.1.1.1> entering state [proceeding][183] 2009-04-28 15:55:58 [DEBUG] sofia.c:2919 sofia_handle_sip_i_state() Remote SDP: v=0 o=IWSPM 573585738 573585738 IN IP4 84.20.97.100 s=- e=unknown@invalid.net t=0 0 m=audio 45954 RTP/AVP 8 0 18 101 c=IN IP4 84.20.97.100 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 m=video 0 RTP/AVP 99 c=IN IP4 2.2.2.2 a=rtpmap:99 H264/90000
2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2931 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000:20]/[G722:9:8000:20] 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2931 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000:20]/[PCMA:8:8000:20] 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:1912 sofia_glue_tech_set_codec() Set Codec sofia/external-eth1/21651019@domain.appsvrslip11.prigw.com;fs_path= sip:21651019@1.1.1.1 <sip%3A21651019@1.1.1.1> PCMA/8000 20 ms 160 samples 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2891 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2146 sofia_glue_activate_rtp() AUDIO RTP [sofia/external-eth1/21651019@domain.appsvrslip11.prigw.com;fs_path= sip:21651019@1.1.1.1 <sip%3A21651019@1.1.1.1>] 2.2.2.2 port 52706 -> 84.20.97.100 port 45954 codec: 8 ms: 20 2009-04-28 15:55:58 [DEBUG] switch_rtp.c:906 switch_rtp_create() Starting timer [soft] 160 bytes per 20ms 2009-04-28 15:55:58 [NOTICE] sofia_glue.c:2573 sofia_glue_tech_media() Pre-Answer sofia/external-eth1/21651019@domain.appsvrslip11.prigw.com;fs_path= sip:21651019@1.1.1.1 <sip%3A21651019@1.1.1.1>! 2009-04-28 15:55:58 [DEBUG] switch_channel.c:1736 switch_channel_perform_mark_pre_answered() Send signal sofia/internal/mikael-nokia@fs.voip.domain [BREAK] 2009-04-28 15:55:58 [DEBUG] switch_ivr_originate.c:1972 switch_ivr_originate() sofia/internal/mikael-nokia@fs.voip.domain receive message [PROGRESS] 2009-04-28 15:55:58 [INFO] mod_sofia.c:1377 sofia_receive_message() Asked to send early media by sofia/internal/mikael-nokia@fs.voip.domain 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2931 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000:20]/[G722:9:8000:20] 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2931 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000:20]/[PCMA:8:8000:20] 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:1912 sofia_glue_tech_set_codec() Set Codec sofia/internal/mikael-nokia@fs.voip.domain PCMA/8000 20 ms 160 samples 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2891 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 98 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2146 sofia_glue_activate_rtp() AUDIO RTP [sofia/internal/mikael-nokia@fs.voip.domain] 10.100.4.192 port 58072 -> 10.247.3.253 port 49152 codec: 8 ms: 20 2009-04-28 15:55:58 [DEBUG] switch_rtp.c:906 switch_rtp_create() Starting timer [soft] 160 bytes per 20ms 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2325 sofia_glue_activate_rtp() Set comfort noise payload to 13 2009-04-28 15:55:58 [NOTICE] sofia_glue.c:2573 sofia_glue_tech_media() Pre-Answer sofia/internal/mikael-nokia@fs.voip.domain! 2009-04-28 15:55:58 [INFO] mod_sofia.c:1420 sofia_receive_message() Ring SDP: v=0 o=FreeSWITCH 1240868886 1240868887 IN IP4 10.100.4.192 s=FreeSWITCH c=IN IP4 10.100.4.192 t=0 0 m=audio 58072 RTP/AVP 8 98 13 a=rtpmap:8 PCMA/8000 a=rtpmap:98 telephone-event/8000 a=fmtp:98 0-16 a=rtpmap:13 CN/8000 a=ptime:20 a=sendrecv
El mar, 28-04-2009 a las 07:50 -0500, Anthony Minessale escribió:
Are you geting 183+sdp from the nokia? the media timer only operates once media is established and only counts against you if the channel is being read from and that does not happen until you get a 183 or 200 w/sdp
try putting a debug line in switch_rtp.c around 1520 printf("MISSED PACKETS %u/%u\n", rtp_session->missed_count, rtp_session->max_missed_packets);
but try updating first there was a recent fix that may have prevented a timer surge at the beginning of calls.
On Tue, Apr 28, 2009 at 6:20 AM, Mikael Aleksander Bjerkeland <mikael@bjerkeland.com> wrote: Hi,
I have been testing inbound calls to a Nokia phone with handover to a cellphone number if I get MEDIA_TIMEOUT on the B leg of the call, and had to set rtp-timeout to a very low 6 seconds in order to get "fast" handover. This introduces an interesting side-effect that hangs up calls even in the ringing state after 6 seconds. Is this the desired behaviour of rtp-timeout-sec? My initial guess was that rtp-timeout-sec should only be valid for established calls where the two endpoints have exchanged rtp at some point but have stopped exchanging media. As far as I know a phone call in ringing state has not shared any RTP with the other endpoint until it gets early media or is answered. Should rtp-timeout-sec really be valid even when ringing?
It seems to me that setting rtp-timeout-sec to 60 seconds would add an absolute time limit on ringing phone calls to 60 seconds, which I believe is not the actual purpose of this limit. Could anyone please share their thoughts on this matter?
Thanks, Mikael
_______________________________________________ Freeswitch-users mailing list Freeswitch-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE: http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Anthony Minessale II
FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/
AIM: anthm MSN:anthony_minessale@hotmail.com <MSN%3Aanthony_minessale@hotmail.com> GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com<PAYPAL%3Aanthony.minessale@gmail.com> IRC: irc.freenode.net #freeswitch
FreeSWITCH Developer Conference sip:888@conference.freeswitch.org <sip%3A888@conference.freeswitch.org> iax:guest@conference.freeswitch.org/888 googletalk:conf+888@conference.freeswitch.org<googletalk%3Aconf%2B888@conference.freeswitch.org> pstn:213-799-1400 _______________________________________________ Freeswitch-users mailing list Freeswitch-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_______________________________________________ Freeswitch-users mailing list Freeswitch-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Anthony Minessale II FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/ AIM: anthm MSN:anthony_minessale@hotmail.com <MSN%3Aanthony_minessale@hotmail.com> GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com<PAYPAL%3Aanthony.minessale@gmail.com> IRC: irc.freenode.net #freeswitch FreeSWITCH Developer Conference sip:888@conference.freeswitch.org <sip%3A888@conference.freeswitch.org> iax:guest@conference.freeswitch.org/888 googletalk:conf+888@conference.freeswitch.org<googletalk%3Aconf%2B888@conference.freeswitch.org> pstn:213-799-1400
Thanks! I'll notify them of the problem and see if there's a way around it. 2009/4/28 Anthony Minessale <anthony.minessale@gmail.com>
as soon as FS sees 183 it expects media.
if they send 183 and no media it will most certainly timeout
On Tue, Apr 28, 2009 at 9:33 AM, Mikael Aleksander Bjerkeland < mikael@bjerkeland.com> wrote:
The scenario I was referring to was actually an outbound call from a locally registered SIP phone to a cellphone. The same thing happens whether I use a SIP or PRI trunk. After 6 s it hangs up.
I get SDP on 183 no matter whether I'm calling a cellphone or a fixed line. I also get ringing indication. The 183+sdp is passed on to the Nokia and after 6 s the call is hung up. Both the SIP and PRI trunks claim to send early media but there seems to be no audio/RTP. If I answer the call in 6 s it's not dropped because the media path was established before RTP timeout.
The same thing happens on latest trunk. I added the debug line at 1520 and did make && /etc/init.d/freeswitch stop && make install && /etc/init.d/freeswitch start but the debug line didn't show up anywhere in the CLI.
Is my upstream provider doing something wrong in sending early media in these cases? Seems pretty odd. It can be avoided by setting a higher rtp-timeout-sec but it will still be an absolute timeout on ringing.
A transcript of the log:
send 1293 bytes to udp/[1.1.1.1]:5060 at 13:55:56.451865:
------------------------------------------------------------------------ INVITE sip:21651019@domain.appsvrslip11.prigw.com<sip%3A21651019@domain.appsvrslip11.prigw.com>SIP/2.0 Via: SIP/2.0/UDP 2.2.2.2;rport;branch=z9hG4bKm3t6teHv30rBK Route: <sip:21651019@1.1.1.1 <sip%3A21651019@1.1.1.1>> Max-Forwards: 69 From: "someone" <sip:23695000@2.2.2.2 <sip%3A23695000@2.2.2.2>
;tag=m2SepeSZ63e3g To: <sip:21651019@domain.appsvrslip11.prigw.com<sip%3A21651019@domain.appsvrslip11.prigw.com>
Call-ID: 23302ac7-ae9f-122c-198f-001ec9e8d9bc CSeq: 114345142 INVITE Contact: <sip:mod_sofia@2.2.2.2:5060> User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-13175M Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH Supported: timer, precondition, path, replaces Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 383 P-Asserted-Identity: "someone" <sip:23695000@2.2.2.2<sip%3A23695000@2.2.2.2>
v=0 o=FreeSWITCH 3718974841365302606 4309079514688066219 IN IP4 2.2.2.2 s=FreeSWITCH c=IN IP4 2.2.2.2 t=0 0 m=audio 52706 RTP/AVP 9 8 0 3 101 13 a=rtpmap:9 G722/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 m=video 52752 RTP/AVP 99 a=rtpmap:99 H264/90000
------------------------------------------------------------------------ 2009-04-28 15:55:56 [DEBUG] sofia.c:2912 sofia_handle_sip_i_state() Channel sofia/external-eth1/21651019@domain.appsvrslip11.prigw.com;fs_path= sip:21651019@1.1.1.1 <sip%3A21651019@1.1.1.1> entering state [calling][0] recv 305 bytes from udp/[1.1.1.1]:5060 at 13:55:56.482864:
------------------------------------------------------------------------ SIP/2.0 100 Trying From: "someone"<sip:23695000@2.2.2.2 <sip%3A23695000@2.2.2.2>
;tag=m2SepeSZ63e3g To: <sip:21651019@domain.appsvrslip11.prigw.com<sip%3A21651019@domain.appsvrslip11.prigw.com>
Call-ID: 23302ac7-ae9f-122c-198f-001ec9e8d9bc CSeq: 114345142 INVITE Via: SIP/2.0/UDP 2.2.2.2;rport=5060;branch=z9hG4bKm3t6teHv30rBK Content-Length: 0
------------------------------------------------------------------------ recv 1035 bytes from udp/[1.1.1.1]:5060 at 13:55:58.296906:
------------------------------------------------------------------------ SIP/2.0 183 Session Progress From: "someone"<sip:23695000@2.2.2.2 <sip%3A23695000@2.2.2.2>
;tag=m2SepeSZ63e3g To: <sip:21651019@domain.appsvrslip11.prigw.com<sip%3A21651019@domain.appsvrslip11.prigw.com> ;tag=20134330840200942815366 Call-ID: 23302ac7-ae9f-122c-198f-001ec9e8d9bc CSeq: 114345142 INVITE Via: SIP/2.0/UDP 2.2.2.2;rport=5060;branch=z9hG4bKm3t6teHv30rBK content-type: application/sdp contact: <sip:1.1.1.1:5060;nt_end_pt=YM0
+~K!-.f0vfc830~P68.cio~H9zwgW0VyisWTdcaM26c610Xbo1.nfS.5NQt3mO~~70!-.f0vft815;nt_server_host=1.1.1.1> supported: 100rel x-nt-party-id: -/ allow: ACK allow: BYE allow: CANCEL allow: INVITE allow: OPTIONS allow: INFO allow: SUBSCRIBE allow: REFER allow: NOTIFY allow: PRACK server: CS2000_NGSS/9.0 Content-Length: 300
v=0 o=IWSPM 573585738 573585738 IN IP4 84.20.97.100 s=- e=unknown@invalid.net t=0 0 m=audio 45954 RTP/AVP 8 0 18 101 c=IN IP4 84.20.97.100 a=ptime:20 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 m=video 0 RTP/AVP 99 c=IN IP4 2.2.2.2 a=rtpmap:99 H264/90000
------------------------------------------------------------------------ 2009-04-28 15:55:58 [DEBUG] sofia.c:2912 sofia_handle_sip_i_state() Channel sofia/external-eth1/21651019@domain.appsvrslip11.prigw.com;fs_path= sip:21651019@1.1.1.1 <sip%3A21651019@1.1.1.1> entering state [proceeding][183] 2009-04-28 15:55:58 [DEBUG] sofia.c:2919 sofia_handle_sip_i_state() Remote SDP: v=0 o=IWSPM 573585738 573585738 IN IP4 84.20.97.100 s=- e=unknown@invalid.net t=0 0 m=audio 45954 RTP/AVP 8 0 18 101 c=IN IP4 84.20.97.100 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 m=video 0 RTP/AVP 99 c=IN IP4 2.2.2.2 a=rtpmap:99 H264/90000
2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2931 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000:20]/[G722:9:8000:20] 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2931 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000:20]/[PCMA:8:8000:20] 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:1912 sofia_glue_tech_set_codec() Set Codec sofia/external-eth1/21651019@domain.appsvrslip11.prigw.com;fs_path= sip:21651019@1.1.1.1 <sip%3A21651019@1.1.1.1> PCMA/8000 20 ms 160 samples 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2891 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2146 sofia_glue_activate_rtp() AUDIO RTP [sofia/external-eth1/21651019@domain.appsvrslip11.prigw.com;fs_path= sip:21651019@1.1.1.1 <sip%3A21651019@1.1.1.1>] 2.2.2.2 port 52706 -> 84.20.97.100 port 45954 codec: 8 ms: 20 2009-04-28 15:55:58 [DEBUG] switch_rtp.c:906 switch_rtp_create() Starting timer [soft] 160 bytes per 20ms 2009-04-28 15:55:58 [NOTICE] sofia_glue.c:2573 sofia_glue_tech_media() Pre-Answer sofia/external-eth1/21651019@domain.appsvrslip11.prigw.com;fs_path= sip:21651019@1.1.1.1 <sip%3A21651019@1.1.1.1>! 2009-04-28 15:55:58 [DEBUG] switch_channel.c:1736 switch_channel_perform_mark_pre_answered() Send signal sofia/internal/mikael-nokia@fs.voip.domain [BREAK] 2009-04-28 15:55:58 [DEBUG] switch_ivr_originate.c:1972 switch_ivr_originate() sofia/internal/mikael-nokia@fs.voip.domain receive message [PROGRESS] 2009-04-28 15:55:58 [INFO] mod_sofia.c:1377 sofia_receive_message() Asked to send early media by sofia/internal/mikael-nokia@fs.voip.domain 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2931 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000:20]/[G722:9:8000:20] 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2931 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000:20]/[PCMA:8:8000:20] 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:1912 sofia_glue_tech_set_codec() Set Codec sofia/internal/mikael-nokia@fs.voip.domain PCMA/8000 20 ms 160 samples 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2891 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 98 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2146 sofia_glue_activate_rtp() AUDIO RTP [sofia/internal/mikael-nokia@fs.voip.domain] 10.100.4.192 port 58072 -> 10.247.3.253 port 49152 codec: 8 ms: 20 2009-04-28 15:55:58 [DEBUG] switch_rtp.c:906 switch_rtp_create() Starting timer [soft] 160 bytes per 20ms 2009-04-28 15:55:58 [DEBUG] sofia_glue.c:2325 sofia_glue_activate_rtp() Set comfort noise payload to 13 2009-04-28 15:55:58 [NOTICE] sofia_glue.c:2573 sofia_glue_tech_media() Pre-Answer sofia/internal/mikael-nokia@fs.voip.domain! 2009-04-28 15:55:58 [INFO] mod_sofia.c:1420 sofia_receive_message() Ring SDP: v=0 o=FreeSWITCH 1240868886 1240868887 IN IP4 10.100.4.192 s=FreeSWITCH c=IN IP4 10.100.4.192 t=0 0 m=audio 58072 RTP/AVP 8 98 13 a=rtpmap:8 PCMA/8000 a=rtpmap:98 telephone-event/8000 a=fmtp:98 0-16 a=rtpmap:13 CN/8000 a=ptime:20 a=sendrecv
El mar, 28-04-2009 a las 07:50 -0500, Anthony Minessale escribió:
Are you geting 183+sdp from the nokia? the media timer only operates once media is established and only counts against you if the channel is being read from and that does not happen until you get a 183 or 200 w/sdp
try putting a debug line in switch_rtp.c around 1520 printf("MISSED PACKETS %u/%u\n", rtp_session->missed_count, rtp_session->max_missed_packets);
but try updating first there was a recent fix that may have prevented a timer surge at the beginning of calls.
On Tue, Apr 28, 2009 at 6:20 AM, Mikael Aleksander Bjerkeland <mikael@bjerkeland.com> wrote: Hi,
I have been testing inbound calls to a Nokia phone with handover to a cellphone number if I get MEDIA_TIMEOUT on the B leg of the call, and had to set rtp-timeout to a very low 6 seconds in order to get "fast" handover. This introduces an interesting side-effect that hangs up calls even in the ringing state after 6 seconds. Is this the desired behaviour of rtp-timeout-sec? My initial guess was that rtp-timeout-sec should only be valid for established calls where the two endpoints have exchanged rtp at some point but have stopped exchanging media. As far as I know a phone call in ringing state has not shared any RTP with the other endpoint until it gets early media or is answered. Should rtp-timeout-sec really be valid even when ringing?
It seems to me that setting rtp-timeout-sec to 60 seconds would add an absolute time limit on ringing phone calls to 60 seconds, which I believe is not the actual purpose of this limit. Could anyone please share their thoughts on this matter?
Thanks, Mikael
_______________________________________________ Freeswitch-users mailing list Freeswitch-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE: http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Anthony Minessale II
FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/
AIM: anthm MSN:anthony_minessale@hotmail.com <MSN%3Aanthony_minessale@hotmail.com> GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com<PAYPAL%3Aanthony.minessale@gmail.com> IRC: irc.freenode.net #freeswitch
FreeSWITCH Developer Conference sip:888@conference.freeswitch.org <sip%3A888@conference.freeswitch.org> iax:guest@conference.freeswitch.org/888 googletalk:conf+888@conference.freeswitch.org<googletalk%3Aconf%2B888@conference.freeswitch.org> pstn:213-799-1400 _______________________________________________ Freeswitch-users mailing list Freeswitch-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE: http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_______________________________________________ Freeswitch-users mailing list Freeswitch-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Anthony Minessale II
FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/
AIM: anthm MSN:anthony_minessale@hotmail.com <MSN%3Aanthony_minessale@hotmail.com> GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com<PAYPAL%3Aanthony.minessale@gmail.com> IRC: irc.freenode.net #freeswitch
FreeSWITCH Developer Conference sip:888@conference.freeswitch.org <sip%3A888@conference.freeswitch.org> iax:guest@conference.freeswitch.org/888 googletalk:conf+888@conference.freeswitch.org<googletalk%3Aconf%2B888@conference.freeswitch.org> pstn:213-799-1400
_______________________________________________ Freeswitch-users mailing list Freeswitch-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
participants (3)
-
Anthony Minessale
-
Mikael Aleksander Bjerkeland
-
Mikael Bjerkeland