signalwire / freeswitch

FreeSWITCH is a Software Defined Telecom Stack enabling the digital transformation from proprietary telecom switches to a versatile software implementation that runs on any commodity hardware. From a Raspberry PI to a multi-core server, FreeSWITCH can unlock the telecommunications potential of any device.
https://freeswitch.com/#getting-started
Other
3.65k stars 1.44k forks source link

ERR - has no write codec #480

Open wpichler opened 4 years ago

wpichler commented 4 years ago

Hi all,

following scenario: Incoming call with late offer (SIP INVITE without SDP - SDP comes with ACK after 200 OK From Freeswitch side) - ALAW in every sdp. Call gets forwarded to Carrier (SIP INVITE with SDP (with alaw) -> 183 from carrier with SDP (with alaw)) Then freeswitch does throw an ERR - with "has no write codec".

Alaw is in every sdp.

Does freeswitch not allow late offers ? dump.pcap.zip

Attached the pcap dump

Here the relevant part from the logs: 1e1f8d60-5f93-11ea-a093-8f217ad8eb18 2020-03-06 11:13:27.863203 [DEBUG] switch_ivr_bridge.c:1684 (sofia/public/+4369910000503) State Change CS_SOFT_EXECUTE -> CS_CONSUME_MEDIA 1e1f8d60-5f93-11ea-a093-8f217ad8eb18 2020-03-06 11:13:27.863203 [DEBUG] switch_core_state_machine.c:585 (sofia/public/+4369910000503) Running State Change CS_CONSUME_MEDIA (Cur 185 Tot 842517) 1e1f8d60-5f93-11ea-a093-8f217ad8eb18 2020-03-06 11:13:27.863203 [DEBUG] switch_core_state_machine.c:663 (sofia/public/+4369910000503) State CONSUME_MEDIA 1e1f8d60-5f93-11ea-a093-8f217ad8eb18 2020-03-06 11:13:27.863203 [DEBUG] switch_ivr_bridge.c:1062 sofia/public/+4369910000503 CUSTOM HOLD 1e1f8d60-5f93-11ea-a093-8f217ad8eb18 2020-03-06 11:13:27.863203 [DEBUG] switch_core_state_machine.c:663 (sofia/public/+4369910000503) State CONSUME_MEDIA going to sleep 1e1f8d60-5f93-11ea-a093-8f217ad8eb18 2020-03-06 11:13:27.863203 [DEBUG] switch_ivr_bridge.c:1794 (sofia/public/+4369910000503) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 1e1f8d60-5f93-11ea-a093-8f217ad8eb18 2020-03-06 11:13:27.863203 [DEBUG] switch_core_state_machine.c:585 (sofia/public/+4369910000503) Running State Change CS_EXCHANGE_MEDIA (Cur 185 Tot 842517) 1e1f8d60-5f93-11ea-a093-8f217ad8eb18 2020-03-06 11:13:27.863203 [DEBUG] switch_core_state_machine.c:654 (sofia/public/+4369910000503) State EXCHANGE_MEDIA 1e1f8d60-5f93-11ea-a093-8f217ad8eb18 2020-03-06 11:13:27.863203 [DEBUG] mod_sofia.c:663 SOFIA EXCHANGE_MEDIA 2020-03-06 11:13:27.883199 [NOTICE] switch_cpp.cpp:1443 Successful query: INSERT INTO cc_callroutes(cdrid, dialstr, weight, destination, routeid, callerid, display_callerid, pulsing, trunkid) VALUES (103735676, '{sdp_m_per_ptime=true,fax_enable_t38=true,fax_enable_t38_request=true,t38_passthru=true,bridge_answer_timeout=60}{absolute_codec_string=\'PCMA\'}sofia/gateway/Colt1/${EXTEN}', 10, '436606769746', 430, '43662234134807', '43662234134807', '1', 1),(103735676, '{sdp_m_per_ptime=true,fax_enable_t38=true,bridge_answer_timeout=60}{absolute_codec_string=\'PCMU,PCMA\'}sofia/gateway/MNM42/${EXTEN}', 5, '436606769746', 578, '43662234134807', '43662234134807', '1', 42) 1f2bd376-5f93-11ea-a135-8f217ad8eb18 2020-03-06 11:13:27.883199 [DEBUG] switch_cpp.cpp:755 CoreSession::setVariable(api_hangup_hook, lua PDIDCallHangup.lua 1f2bd376-5f93-11ea-a135-8f217ad8eb18) 2020-03-06 11:13:27.883199 [NOTICE] switch_cpp.cpp:1443 AllowNonProfite is set to True2020-03-06 11:13:27.883199 [NOTICE] switch_cpp.cpp:1443 do execute route #1 with profit 0.3000 1f2bd376-5f93-11ea-a135-8f217ad8eb18 2020-03-06 11:13:27.883199 [DEBUG] switch_cpp.cpp:755 CoreSession::setVariable(sip_cid_in_1xx, false) 1e1f8d60-5f93-11ea-a093-8f217ad8eb18 2020-03-06 11:13:27.903195 [ERR] switch_core_media.c:15698 sofia/public/+4369910000503 has no write codec. 1e1f8d60-5f93-11ea-a093-8f217ad8eb18 2020-03-06 11:13:27.903195 [NOTICE] switch_core_media.c:15699 Hangup sofia/public/+4369910000503 [CS_EXCHANGE_MEDIA] [INCOMPATIBLE_DESTINATION] 1d805e02-5f93-11ea-a032-8f217ad8eb18 2020-03-06 11:13:27.903195 [DEBUG] switch_ivr_bridge.c:824 sofia/public/+4369910000503 ending bridge by request from write function

dragos-oancea commented 4 years ago

shouldn't be an UPDATE in those traces ?

wpichler commented 4 years ago

Here is the link to the RFC's https://tools.ietf.org/html/rfc6337#page-11

When i interpret this correct - then freeswitch should send a 1xx-rel Response (183 for example) - so the other end will answer with a PRACK with SDP.

I will try to generate a 183 here to see what happens

briankwest commented 4 years ago

100 rel is disabled by default.

wpichler commented 4 years ago

but the main question remain the same - we send an sdp - we got an sdp - so why this ERR here ?

Also - why does freeswitch response with a 200OK in this case ? Is it because of 100 rel was disabled - and the invite did contain Support for 100rel (but there is no Require 100rel in the INVITE) ?

xrobau commented 4 years ago

I'm pretty sure this is a new and interesting freeswitch bug, and it's easy (albeit complex to set up) to duplicate, actually.

Starting with the assumption that 'swrox1' is a generic freeswitch server, with nothing unusual set on it that talks to a sip provider (lets call them Soognalwire) and you will also need a 3CX instance.

This is where it gets tricky and you have NO IDEA HOW LONG IT TOOK ME to get to this point of being able to reproduce the problem.

3CX Config

Now you can do a sanity check: From 500, call 501. It will ring for 1 second, and then send a call out to swrox1, which should send it to the carrier, and everything works.

Now you're set up to trigger the bug!

  1. Call in from carrier->swrox1->3cx so 500 rings.

  2. Answer Ext 500. (Mumbling profanities at yourself is optional, but highly recommended)

  3. Do a blind transfer to 501.

  4. Watch swrox1 error with this, even though both legs have sent an offer of alaw/ulaw/etc to each other happily

    2020-08-21 14:01:10.546005 [ERR] switch_core_media.c:15696 sofia/default/+61402077155 has no write codec.

  5. Feel sad and look wistfully at the bottle of scotch nearby.

Turning off those two options in the trunk settings makes the SDP be offered in the original invite of the blind transfer, and the problem is not triggered.

I have gone as far as hard-coding alaw absoloutely everywhere, including upstream carriers and handsets, and this still happens.

I suspect that there could be an issue with switch_code_codec_ready() there, but it's beyond my skillset to diagnose!