[Freeswitch-users] Error with media ptime

leonardo alves telteclistas at gmail.com
Fri Apr 30 20:21:17 PDT 2010


Actually,

I tougth it was working but it is not.
If when I answer the call and stay in silence everything works ok. But if I
say something or there is any noise in the room shows in the freeswitch
console the [WARNING] mod_sofia.c:999 and the call starts to get choppy.

The command that I am running in the freeswitch console is this:
bgapi originate
{ignore_early_media=true,originate_timeout=60}sofia/gateway/nettophone/18197713136
&playback(/usr/local/freeswitch/sounds/en/us/callie/ivr/8000/ivr-sample_submenu.wav)

Reading the debug of the call what I could understand is while the ptime of
the call is in 20ms everything works good, but when it changes to 30ms the
call starts to get choppy. And it gets changed after the warning.

 On the file vars.xml I also tried this configuration:
<X-PRE-PROCESS cmd="set" data="outbound_codec_prefs=PCMU at 20i,PCMA at 20i"/>
But after the warning it still changes the ptime to 30 and the call starts
to get choppy.

Does anyone knows what else I could do ? Thanks for any ideas.

Here is the debug of the call:
2010-04-30 21:40:09.656257 [DEBUG] mod_sofia.c:140
sofia/external/18197713136 SOFIA ROUTING
2010-04-30 21:40:09.656257 [DEBUG] switch_ivr_originate.c:66
(sofia/external/18197713136) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2010-04-30 21:40:09.656257 [DEBUG] switch_core_session.c:1022 Send signal
sofia/external/18197713136 [BREAK]
2010-04-30 21:40:09.656257 [DEBUG] switch_core_state_machine.c:341
(sofia/external/18197713136) State ROUTING going to sleep
2010-04-30 21:40:09.656257 [DEBUG] switch_core_state_machine.c:314
(sofia/external/18197713136) Running State Change CS_CONSUME_MEDIA
2010-04-30 21:40:09.656257 [DEBUG] switch_core_state_machine.c:360
(sofia/external/18197713136) State CONSUME_MEDIA
2010-04-30 21:40:09.656257 [DEBUG] switch_core_state_machine.c:360
(sofia/external/18197713136) State CONSUME_MEDIA going to sleep
send 1085 bytes to udp/[66.33.157.119]:5060 at 02:40:09.657682:
   ------------------------------------------------------------------------
   INVITE sip:18197713136 at 66.33.157.119 <sip%3A18197713136 at 66.33.157.119>SIP/2.0
   Via: SIP/2.0/UDP 10.1.1.1:5080;rport;branch=z9hG4bKBB4KpNNHQUFyS
   Max-Forwards: 70
   From: "" <sip:cust_USERNAME at 66.33.157.119<sip%3Acust_USERNAME at 66.33.157.119>
;transport=udp>;tag=BBvj27gt2ZFQB
   To: <sip:18197713136 at 66.33.157.119 <sip%3A18197713136 at 66.33.157.119>>
   Call-ID: b36e59ea-cf6d-122d-0a9c-0026b97cdbb8
   CSeq: 130222468 INVITE
   Contact: <sip:gw+nettophone at 10.1.1.1:5080;transport=udp;gw=nettophone>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
REGISTER, REFER, NOTIFY
   Supported: timer, precondition, path, replaces
   Allow-Events: talk, hold, refer
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 270
   X-FS-Support: update_display
   Remote-Party-ID:
<sip:0000000000 at 66.33.157.119<sip%3A0000000000 at 66.33.157.119>
>;party=calling;screen=yes;privacy=off
   v=0
   o=FreeSWITCH 1272653081 1272653082 IN IP4 10.1.1.1
   s=FreeSWITCH
   c=IN IP4 10.1.1.1
   t=0 0
   m=audio 28528 RTP/AVP 0 8 101 13
   a=rtpmap:0 PCMU/8000
   a=rtpmap:8 PCMA/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=rtpmap:13 CN/8000
   a=ptime:20
   ------------------------------------------------------------------------
2010-04-30 21:40:09.656257 [DEBUG] sofia.c:4172 Channel
sofia/external/18197713136 entering state [calling][0]
recv 411 bytes from udp/[66.33.157.119]:5060 at 02:40:09.703164:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 10.1.1.1:5080
;branch=z9hG4bKBB4KpNNHQUFyS;received=10.1.1.1;rport=5080
   From: "" <sip:cust_USERNAME at 66.33.157.119<sip%3Acust_USERNAME at 66.33.157.119>
;transport=udp>;tag=BBvj27gt2ZFQB
   To: <sip:18197713136 at 66.33.157.119 <sip%3A18197713136 at 66.33.157.119>
>;tag=ccid-713620800-1-574
   Call-ID: b36e59ea-cf6d-122d-0a9c-0026b97cdbb8
   CSeq: 130222468 INVITE
   Contact: <sip:66.33.157.119:5060>
   Server: Net2Phone Carrier
   Content-Length: 0
   ------------------------------------------------------------------------
recv 657 bytes from udp/[66.33.157.119]:5060 at 02:40:11.008062:
   ------------------------------------------------------------------------
   SIP/2.0 183 Session Progress
   Via: SIP/2.0/UDP 10.1.1.1:5080
;branch=z9hG4bKBB4KpNNHQUFyS;received=10.1.1.1;rport=5080
   From: "" <sip:cust_USERNAME at 66.33.157.119<sip%3Acust_USERNAME at 66.33.157.119>
;transport=udp>;tag=BBvj27gt2ZFQB
   To: <sip:18197713136 at 66.33.157.119 <sip%3A18197713136 at 66.33.157.119>
>;tag=ccid-713620800-1-574
   Call-ID: b36e59ea-cf6d-122d-0a9c-0026b97cdbb8
   CSeq: 130222468 INVITE
   Contact: <sip:66.33.157.119:5060>
   Server: Net2Phone Carrier
   Content-Length: 203
   Content-Type: application/sdp
   v=0
   o=44952 713620800 713620800 IN IP4 169.132.188.43
   s=SIP Call
   c=IN IP4 169.132.188.43
   t=0 0
   m=audio 22696 RTP/AVP 0 101
   a=rtpmap:0 PCMU/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-11
   ------------------------------------------------------------------------
2010-04-30 21:40:11.008120 [INFO] sofia.c:662 Update Callee ID to
"18197713136" <18197713136>
2010-04-30 21:40:11.008120 [DEBUG] sofia.c:4172 Channel
sofia/external/18197713136 entering state [proceeding][183]
2010-04-30 21:40:11.008120 [DEBUG] sofia.c:4183 Remote SDP:
v=0
o=44952 713620800 713620800 IN IP4 169.132.188.43
s=SIP Call
c=IN IP4 169.132.188.43
t=0 0
m=audio 22696 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11
2010-04-30 21:40:11.008120 [DEBUG] sofia_glue.c:3674 Audio Codec Compare
[PCMU:0:8000:20]/[PCMU:0:8000:20]
2010-04-30 21:40:11.008120 [DEBUG] sofia_glue.c:2372 Set Codec
sofia/external/18197713136 PCMU/8000 20 ms 160 samples
2010-04-30 21:40:11.008120 [DEBUG] sofia_glue.c:3607 Set 2833 dtmf send
payload to 101
2010-04-30 21:40:11.008120 [DEBUG] sofia_glue.c:2612 AUDIO RTP
[sofia/external/18197713136] 10.1.1.1 port 28528 -> 169.132.188.43 port
22696 codec: 0 ms: 20
2010-04-30 21:40:11.008120 [DEBUG] switch_rtp.c:1346 Starting timer [soft]
160 bytes per 20ms
2010-04-30 21:40:11.012070 [DEBUG] sofia_glue.c:2818 Set 2833 dtmf send
payload to 101
2010-04-30 21:40:11.012070 [DEBUG] sofia_glue.c:2823 Set 2833 dtmf receive
payload to 101
2010-04-30 21:40:11.012070 [NOTICE] sofia_glue.c:3227 Pre-Answer
sofia/external/18197713136!
recv 681 bytes from udp/[66.33.157.119]:5060 at 02:40:18.227385:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.1.1.1:5080
;branch=z9hG4bKBB4KpNNHQUFyS;received=10.1.1.1;rport=5080
   From: "" <sip:cust_USERNAME at 66.33.157.119<sip%3Acust_USERNAME at 66.33.157.119>
;transport=udp>;tag=BBvj27gt2ZFQB
   To: <sip:18197713136 at 66.33.157.119 <sip%3A18197713136 at 66.33.157.119>
>;tag=ccid-713620800-1-574
   Allow: ACK,BYE,CANCEL,INVITE,OPTIONS
   Call-ID: b36e59ea-cf6d-122d-0a9c-0026b97cdbb8
   CSeq: 130222468 INVITE
   Contact: <sip:66.33.157.119:5060>
   Server: Net2Phone Carrier
   Content-Length: 203
   Content-Type: application/sdp
   v=0
   o=44952 713620800 713620800 IN IP4 169.132.188.43
   s=SIP Call
   c=IN IP4 169.132.188.43
   t=0 0
   m=audio 22696 RTP/AVP 0 101
   a=rtpmap:0 PCMU/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-11
   ------------------------------------------------------------------------
2010-04-30 21:40:18.227023 [DEBUG] sofia.c:4172 Channel
sofia/external/18197713136 entering state [completing][200]
2010-04-30 21:40:18.227023 [DEBUG] sofia.c:4180 Duplicate SDP
v=0
o=44952 713620800 713620800 IN IP4 169.132.188.43
s=SIP Call
c=IN IP4 169.132.188.43
t=0 0
m=audio 22696 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11
send 429 bytes to udp/[66.33.157.119]:5060 at 02:40:18.228604:
   ------------------------------------------------------------------------
   ACK sip:66.33.157.119:5060 SIP/2.0
   Via: SIP/2.0/UDP 10.1.1.1:5080;rport;branch=z9hG4bKcmXcrg6mm45gN
   Max-Forwards: 70
   From: "" <sip:cust_USERNAME at 66.33.157.119<sip%3Acust_USERNAME at 66.33.157.119>
;transport=udp>;tag=BBvj27gt2ZFQB
   To: <sip:18197713136 at 66.33.157.119 <sip%3A18197713136 at 66.33.157.119>
>;tag=ccid-713620800-1-574
   Call-ID: b36e59ea-cf6d-122d-0a9c-0026b97cdbb8
   CSeq: 130222468 ACK
   Contact: <sip:gw+nettophone at 10.1.1.1:5080;transport=udp;gw=nettophone>
   Content-Length: 0
   ------------------------------------------------------------------------
2010-04-30 21:40:18.227023 [DEBUG] sofia.c:4172 Channel
sofia/external/18197713136 entering state [ready][200]
2010-04-30 21:40:18.227023 [NOTICE] sofia.c:4696 Channel
[sofia/external/18197713136] has been answered
2010-04-30 21:40:18.228967 [DEBUG] switch_ivr_originate.c:3210 Originate
Resulted in Success: [sofia/external/18197713136]
2010-04-30 21:40:18.228967 [DEBUG] mod_commands.c:2870
(sofia/external/18197713136) State Change CS_CONSUME_MEDIA -> CS_EXECUTE
2010-04-30 21:40:18.228967 [DEBUG] switch_core_session.c:1022 Send signal
sofia/external/18197713136 [BREAK]
2010-04-30 21:40:18.228967 [DEBUG] switch_core_state_machine.c:314
(sofia/external/18197713136) Running State Change CS_EXECUTE
2010-04-30 21:40:18.228967 [DEBUG] switch_core_state_machine.c:348
(sofia/external/18197713136) State EXECUTE
2010-04-30 21:40:18.228967 [DEBUG] mod_sofia.c:233
sofia/external/18197713136 SOFIA EXECUTE
2010-04-30 21:40:18.228967 [DEBUG] switch_core_state_machine.c:157
sofia/external/18197713136 Standard EXECUTE
EXECUTE sofia/external/18197713136
playback(/usr/local/freeswitch/sounds/en/us/callie/ivr/8000/ivr-sample_submenu.wav)
2010-04-30 21:40:18.229973 [DEBUG] switch_ivr_play_say.c:1152 Codec
Activated L16 at 8000hz 1 channels 20ms
2010-04-30 21:40:18.287128 [DEBUG] switch_rtp.c:2446 Correct ip/port
confirmed.
2010-04-30 21:40:18.486993 [WARNING] mod_sofia.c:999 We were told to use
ptime 20 but what they meant to say was 30
This issue has so far been identified to happen on the following broken
platforms/devices:
Linksys/Sipura aka Cisco
ShoreTel
Sonus/L3
We will try to fix it but some of the devices on this list are so broken who
knows what will happen..
2010-04-30 21:40:18.486993 [DEBUG] sofia_glue.c:2301 Changing Codec from
PCMU at 20ms to PCMU at 30ms
2010-04-30 21:40:18.486993 [DEBUG] switch_rtp.c:1232 RE-Starting timer
[soft] 240 bytes per 30000ms
2010-04-30 21:40:18.486993 [DEBUG] sofia_glue.c:2372 Set Codec
sofia/external/18197713136 PCMU/8000 30 ms 240 samples
send 1081 bytes to udp/[66.33.157.119]:5060 at 02:40:18.487972:
   ------------------------------------------------------------------------
   INVITE sip:66.33.157.119:5060 SIP/2.0
   Via: SIP/2.0/UDP 10.1.1.1:5080;rport;branch=z9hG4bKDXp5SBQrHDv3g
   Max-Forwards: 70
   From: "" <sip:cust_USERNAME at 66.33.157.119<sip%3Acust_USERNAME at 66.33.157.119>
;transport=udp>;tag=BBvj27gt2ZFQB
   To: <sip:18197713136 at 66.33.157.119 <sip%3A18197713136 at 66.33.157.119>
>;tag=ccid-713620800-1-574
   Call-ID: b36e59ea-cf6d-122d-0a9c-0026b97cdbb8
   CSeq: 130222469 INVITE
   Contact: <sip:gw+nettophone at 10.1.1.1:5080;transport=udp;gw=nettophone>
   User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
REGISTER, REFER, NOTIFY
   Supported: timer, precondition, path, replaces
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 249
   X-Broken-PTIME: Adv=20;Sent=30
   X-FS-Support: update_display
   Remote-Party-ID:
<sip:0000000000 at 66.33.157.119<sip%3A0000000000 at 66.33.157.119>
>;party=calling;screen=yes;privacy=off
   v=0
   o=FreeSWITCH 1272653081 1272653083 IN IP4 10.1.1.1
   s=FreeSWITCH
   c=IN IP4 10.1.1.1
   t=0 0
   m=audio 28528 RTP/AVP 0 101
   a=rtpmap:0 PCMU/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=silenceSupp:off - - - -
   a=ptime:30
   ------------------------------------------------------------------------
2010-04-30 21:40:18.486993 [DEBUG] sofia.c:4172 Channel
sofia/external/18197713136 entering state [calling][0]
2010-04-30 21:40:18.517050 [DEBUG] switch_core_io.c:896 Engaging Write
Buffer at 480 bytes to accommodate 320->480
recv 681 bytes from udp/[66.33.157.119]:5060 at 02:40:18.534493:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.1.1.1:5080
;branch=z9hG4bKDXp5SBQrHDv3g;received=10.1.1.1;rport=5080
   From: "" <sip:cust_USERNAME at 66.33.157.119<sip%3Acust_USERNAME at 66.33.157.119>
;transport=udp>;tag=BBvj27gt2ZFQB
   To: <sip:18197713136 at 66.33.157.119 <sip%3A18197713136 at 66.33.157.119>
>;tag=ccid-713620800-1-574
   Allow: ACK,BYE,CANCEL,INVITE,OPTIONS
   Call-ID: b36e59ea-cf6d-122d-0a9c-0026b97cdbb8
   CSeq: 130222469 INVITE
   Contact: <sip:66.33.157.119:5060>
   Server: Net2Phone Carrier
   Content-Length: 203
   Content-Type: application/sdp
   v=0
   o=44952 713620800 713620800 IN IP4 169.132.188.43
   s=SIP Call
   c=IN IP4 169.132.188.43
   t=0 0
   m=audio 22696 RTP/AVP 0 101
   a=rtpmap:0 PCMU/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-11
   ------------------------------------------------------------------------
send 429 bytes to udp/[66.33.157.119]:5060 at 02:40:18.534747:
   ------------------------------------------------------------------------
   ACK sip:66.33.157.119:5060 SIP/2.0
   Via: SIP/2.0/UDP 10.1.1.1:5080;rport;branch=z9hG4bKe6FyU67Uepjpc
   Max-Forwards: 70
   From: "" <sip:cust_USERNAME at 66.33.157.119<sip%3Acust_USERNAME at 66.33.157.119>
;transport=udp>;tag=BBvj27gt2ZFQB
   To: <sip:18197713136 at 66.33.157.119 <sip%3A18197713136 at 66.33.157.119>
>;tag=ccid-713620800-1-574
   Call-ID: b36e59ea-cf6d-122d-0a9c-0026b97cdbb8
   CSeq: 130222469 ACK
   Contact: <sip:gw+nettophone at 10.1.1.1:5080;transport=udp;gw=nettophone>
   Content-Length: 0
   ------------------------------------------------------------------------
2010-04-30 21:40:18.534975 [DEBUG] sofia.c:4172 Channel
sofia/external/18197713136 entering state [ready][200]
2010-04-30 21:40:18.534975 [DEBUG] sofia.c:4180 Duplicate SDP
v=0
o=44952 713620800 713620800 IN IP4 169.132.188.43
s=SIP Call
c=IN IP4 169.132.188.43
t=0 0
m=audio 22696 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20100430/cf2d255f/attachment-0001.html 


More information about the FreeSWITCH-users mailing list