Hmm, not sure thats true.  You are not supposed to change codecs before the dialog is complete like this, its a violation of sdp o/a.

On Jun 10, 2014, at 4:50 AM, Kristian Kielhofner <kris@kriskinc.com> wrote:

Hi Mark,

  Thanks for providing the full log.

  While goofy this is perfectly valid behavior. Because your instance of Freeswitch offers pcma and pcmu it's ok for the other side to switch between the two in 183.

  A few things to try:

- Limit your outbound offers to pcma or pcmu only (one codec).

- The remote side appears to support 100rel (PRACK). Try enabling it in Freeswitch. While a long shot it's possible that PRACK'ing the initial received 183 might change the codec swap behavior of the remote end.

- Try Freeswitch 1.4 or master. There's been some significant changes in media/SDP behavior, particularly when the remote end does technically standards compliant but goofy things with multiple codec offers.

  If none of these works you're only option may be to have the carrier take some action. 

On Monday, June 9, 2014, Mark Boots <mark@votomobile.org> wrote:
Hi Kristian,

I've narrowed this INCOMPATIBLE_DESTINATION error down to a specific case:

1 - Freeswitch sends the outgoing call, and offers PCMU/PCMA/GSM
2 - Other end accepts only PCMU
3 - At some point after Pre-answer, the other end issues a 183 Session Progress, changing to only accept PCMA.
4 - Freeswitch attempts to select new codecs but only looks at PCMU, and cancels the call with INCOMPATIBLE_DESTINATION.


Here is the console log and sip trace... Hope it helps!

+Mark

2014-06-09 21:35:39.615207 [DEBUG] switch_ivr_originate.c:2069 Parsing global variables
2014-06-09 21:35:39.615207 [DEBUG] switch_event.c:1661 Parsing variable [plivo_request_uuid]=[004fd8a2-f01e-11e3-844d-22000ad937f0]
2014-06-09 21:35:39.615207 [DEBUG] switch_event.c:1661 Parsing variable [plivo_answer_url]=[http://10.8.0.1/deliverylogs/answer/752471]
2014-06-09 21:35:39.615207 [DEBUG] switch_event.c:1661 Parsing variable [plivo_ring_url]=[http://127.0.0.1/callqueue/ring.php]
2014-06-09 21:35:39.615207 [DEBUG] switch_event.c:1661 Parsing variable [plivo_hangup_url]=[http://127.0.0.1/callqueue/hangup.php]
2014-06-09 21:35:39.615207 [DEBUG] switch_event.c:1661 Parsing variable [origination_caller_id_number]=[12026004299]
2014-06-09 21:35:39.615207 [DEBUG] switch_event.c:1661 Parsing variable [plivo_from]=[12026004299]
2014-06-09 21:35:39.615207 [DEBUG] switch_event.c:1661 Parsing variable [plivo_to]=[0011104555592211972]
2014-06-09 21:35:39.615207 [DEBUG] switch_event.c:1661 Parsing variable [plivo_app]=[true]
2014-06-09 21:35:39.615207 [DEBUG] switch_event.c:1661 Parsing variable [originate_timeout]=[60]
2014-06-09 21:35:39.615207 [DEBUG] switch_event.c:1661 Parsing variable [ignore_early_media]=[true]
2014-06-09 21:35:39.615207 [NOTICE] switch_channel.c:1049 New Channel sofia/external/0011104555592211972 [005052e6-f01e-11e3-bbae-cbf0f4eac998]
2014-06-09 21:35:39.615207 [DEBUG] mod_sofia.c:5237 (sofia/external/0011104555592211972) State Change CS_NEW -> CS_INIT
2014-06-09 21:35:39.615207 [DEBUG] switch_core_session.c:1351 Send signal sofia/external/0011104555592211972 [BREAK]
2014-06-09 21:35:39.615207 [DEBUG] switch_core_state_machine.c:418 (sofia/external/0011104555592211972) Running State Change CS_INIT
2014-06-09 21:35:39.615207 [DEBUG] switch_core_state_machine.c:458 (sofia/external/0011104555592211972) State INIT
2014-06-09 21:35:39.615207 [DEBUG] mod_sofia.c:87 sofia/external/0011104555592211972 SOFIA INIT
2014-06-09 21:35:39.615207 [DEBUG] sofia_glue.c:2746 sofia/external/0011104555592211972 sending invite version: 1.2.24 git 7b74ee3 2014-06-03 00:26:24Z 32bit
Local SDP:
v=0
o=FreeSWITCH 1402325141 1402325142 IN IP4 54.203.245.50
s=FreeSWITCH
c=IN IP4 54.203.245.50
t=0 0
m=audio 24598 RTP/AVP 0 8 3 101 13
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2014-06-09 21:35:39.615207 [DEBUG] mod_sofia.c:127 (sofia/external/0011104555592211972) State Change CS_INIT -> CS_ROUTING
2014-06-09 21:35:39.615207 [DEBUG] switch_core_session.c:1351 Send signal sofia/external/0011104555592211972 [BREAK]
2014-06-09 21:35:39.615207 [DEBUG] switch_core_state_machine.c:458 (sofia/external/0011104555592211972) State INIT going to sleep
send 1071 bytes to udp/[108.59.2.133]:5060 at 21:35:39.620673:
   ------------------------------------------------------------------------
   Via: SIP/2.0/UDP 54.203.245.50:5080;rport;branch=z9hG4bKUNeNtZcZp5ZmB
   Max-Forwards: 70
   From: "" <sip:12026004299@54.203.245.50>;tag=9Z1HtD145Qv3K
   Call-ID: d7aeb7a1-6ac0-1232-718c-22000ad937f0
   CSeq: 60838805 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.2.24+git~20140603T002624Z~7b74ee3955~32bit
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
   Supported: timer, path, replaces
   Allow-Events: talk, hold, conference, refer
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 207
   X-FS-Support: update_display,send_info
   Remote-Party-ID: <sip:12026004299@54.203.245.50>;party=calling;screen=yes;privacy=off
   
   v=0
   o=FreeSWITCH 1402325141 1402325142 IN IP4 54.203.245.50
   s=FreeSWITCH
   c=IN IP4 54.203.245.50
   t=0 0
   m=audio 24598 RTP/AVP 0 8 3 101 13
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=ptime:20
   ------------------------------------------------------------------------
2014-06-09 21:35:39.615207 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/0011104555592211972 [BREAK]
2014-06-09 21:35:39.615207 [DEBUG] switch_core_state_machine.c:418 (sofia/external/0011104555592211972) Running State Change CS_ROUTING
2014-06-09 21:35:39.615207 [DEBUG] sofia.c:5845 Channel sofia/external/0011104555592211972 entering state [calling][0]
2014-06-09 21:35:39.615207 [DEBUG] switch_core_state_machine.c:474 (sofia/external/0011104555592211972) State ROUTING
2014-06-09 21:35:39.615207 [DEBUG] mod_sofia.c:150 sofia/external/0011104555592211972 SOFIA ROUTING
2014-06-09 21:35:39.615207 [DEBUG] switch_ivr_originate.c:67 (sofia/external/0011104555592211972) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2014-06-09 21:35:39.615207 [DEBUG] switch_core_session.c:1351 Send signal sofia/external/0011104555592211972 [BREAK]
2014-06-09 21:35:39.615207 [DEBUG] switch_core_state_machine.c:474 (sofia/external/0011104555592211972) State ROUTING going to sleep
2014-06-09 21:35:39.615207 [DEBUG] switch_core_state_machine.c:418 (sofia/external/0011104555592211972) Running State Change CS_CONSUME_MEDIA
2014-06-09 21:35:39.615207 [DEBUG] switch_core_state_machine.c:493 (sofia/external/0011104555592211972) State CONSUME_MEDIA
2014-06-09 21:35:39.615207 [DEBUG] switch_core_state_machine.c:493 (sofia/external/0011104555592211972) State CONSUME_MEDIA going to sleep
recv 367 bytes from udp/[108.59.2.133]:5060 at 21:35:39.725204:
   ------------------------------------------------------------------------
   SIP/2.0 100 Giving a try
   Via: SIP/2.0/UDP 54.203.245.50:5080;received=54.203.245.50;rport=5080;branch=z9hG4bKUNeNtZcZp5ZmB
   From: "" <sip:12026004299@54.203.245.50>;tag=9Z1HtD145Qv3K
   Call-ID: d7aeb7a1-6ac0-1232-718c-22000ad937f0
   CSeq: 60838805 INVITE
   Server: OpenSIPS (1.8.2-notls (x86_64/linux))
   Content-Length: 0
   
   ------------------------------------------------------------------------
recv 657 bytes from udp/[108.59.2.133]:5060 at 21:35:41.191275:
   ------------------------------------------------------------------------
   SIP/2.0 183 Session Progress
   Via: SIP/2.0/UDP 54.203.245.50:5080;rport;branch=z9hG4bKUNeNtZcZp5ZmB
   From: "" <sip:12026004299@54.203.245.50>;tag=9Z1HtD145Qv3K
   To: <sip:0011104555592211972@108.59.2.133>;tag=9312047651043624688
   Call-ID: d7aeb7a1-6ac0-1232-718c-22000ad937f0
   CSeq: 60838805 INVITE
   Content-Type: application/sdp
   Supported: timer,100rel
   Content-Length: 226
   
   v=0
   o=RISNEXT02 869 1999 IN IP4 80.84.30.41
   s=sip call
   c=IN IP4 80.84.30.41
   t=0 0
   m=audio 42108 RTP/AVP 0 13 101
   a=rtpmap:0 PCMU/8000
   a=rtpmap:13 CN/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=ptime:20
   ------------------------------------------------------------------------
2014-06-09 21:35:41.175213 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/0011104555592211972 [BREAK]
2014-06-09 21:35:41.175213 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/0011104555592211972 [BREAK]
2014-06-09 21:35:41.175213 [DEBUG] sofia.c:5845 Channel sofia/external/0011104555592211972 entering state [proceeding][183]
2014-06-09 21:35:41.175213 [DEBUG] sofia.c:5858 Remote SDP:
v=0
o=RISNEXT02 869 1999 IN IP4 80.84.30.41
s=sip call
c=IN IP4 80.84.30.41
t=0 0
m=audio 42108 RTP/AVP 0 13 101
a=rtpmap:0 PCMU/8000
a=rtpmap:13 CN/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20

2014-06-09 21:35:41.175213 [DEBUG] sofia_glue.c:5284 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
2014-06-09 21:35:41.175213 [DEBUG] sofia_glue.c:3192 Set Codec sofia/external/0011104555592211972 PCMU/8000 20 ms 160 samples 64000 bits
2014-06-09 21:35:41.175213 [DEBUG] switch_core_codec.c:111 sofia/external/0011104555592211972 Original read codec set to PCMU:0
2014-06-09 21:35:41.175213 [DEBUG] sofia_glue.c:5444 Set 2833 dtmf send payload to 101
2014-06-09 21:35:41.175213 [DEBUG] sofia_glue.c:3451 AUDIO RTP [sofia/external/0011104555592211972] 10.217.55.240 port 24598 -> 80.84.30.41 port 42108 codec: 0 ms: 20
2014-06-09 21:35:41.175213 [DEBUG] switch_rtp.c:2040 Starting timer [soft] 160 bytes per 20ms
2014-06-09 21:35:41.175213 [DEBUG] sofia_glue.c:3718 Set 2833 dtmf send payload to 101
2014-06-09 21:35:41.175213 [DEBUG] sofia_glue.c:3724 Set 2833 dtmf receive payload to 101
2014-06-09 21:35:41.175213 [DEBUG] sofia_glue.c:3751 sofia/external/0011104555592211972 Set rtp dtmf delay to 40
2014-06-09 21:35:41.175213 [DEBUG] sofia_glue.c:3757 Set comfort noise payload to 13
2014-06-09 21:35:41.175213 [NOTICE] sofia_glue.c:4362 Pre-Answer sofia/external/0011104555592211972!