freeswitch icon indicating copy to clipboard operation
freeswitch copied to clipboard

no audio in A leg after multiple re-invites in B-leg (transfer on remote sbc)

Open wmasilva opened this issue 3 years ago • 1 comments

Describe the bug call between source A and destination B, once the call is stablish, B side, that is behind a SBC transfers the call internally, FS receives the multiples re-invites from the SBC (3pcc is enabled to proxy mode in sofia profile to handle the invites without sdp,... ), FS processes the sip re-invites but the media received from B is not sent to A leg.

In resume, the issue is that A leg doesn't receive the audio from B leg, but B leg is receiving the audio from A leg. In the pcap file we can see that B leg is sending rtp when the sdp is a=sendrecv.

RTP call flow in pcap: A FS B [ REMOTE SBC EXTENSION B <----> FINAL DESTINATION] [1] -----RTP FROM A-----------> -----------------------------------------------------------------------------> [2]<---------------------------<---------------- RTP FROM EXTENSION B [3] ?1? <--------------- RTP MUSIC ON HOLD [4] ?2? <-----------------------------------------------RTP FROM FINAL DESTINATION

A don't get the RTP stream ?1? and ?2?.

Attach sipp scenario that emulates the behaviour of the SBC side.

To Reproduce . start freeswitch with attached freeswitch.xml . Run sipp scenario: sipp -sf uas_pcap_reinvite_call_g711.xml -d 300000 -i 192.168.1.65 . register an account . dial 133

Expected behavior after the re-invites A leg should have audio from B leg.

Package version or git hash FreeSWITCH (Version 1.10.8-dev git 6e5822e 2022-07-06 17:22:28Z 64bit) is ready

Trace logs see log and pcap file.

base_setup.zip debug_log_pcap.zip

wmasilva avatar Jul 13 '22 15:07 wmasilva

doing a git bisect i found that the issue was introduced at:

badd59d609b5d5583c01d543e0d6b3a9cb365df1 is the first bad commit
commit badd59d609b5d5583c01d543e0d6b3a9cb365df1
Author: Anthony Minessale <[email protected]>
Date:   Tue Apr 14 19:52:38 2020 +0000

    [core, mod_verto] remove CF_VIDEO_ONLY and pay attention to the streams instead and add CF_NO_RECOVER flag for verto

:040000 040000 964ae6d7e758532f8b18635782e5ab111af20508 9dc57e16c6916d07872ea7e7b994b45050514d1c M	src

The bisect log:


root@debian:/usr/src/freeswitch# git bisect log
git bisect start
# good: [ce87856c91c01394d973fdcbfd4a9a45b210bba1] [mod_sofia] Remove redundant sip_from->a_url checks
git bisect good ce87856c91c01394d973fdcbfd4a9a45b210bba1
# bad: [4555731ee37880545df3ea62b4a762551b7bfad6] version bump
git bisect bad 4555731ee37880545df3ea62b4a762551b7bfad6
# bad: [d2ccb93f3ebe32774de8efd2bbcc511c5ebca641] [mod_sofia] don't auto unhold via media format for non-sip
git bisect bad d2ccb93f3ebe32774de8efd2bbcc511c5ebca641
# good: [b2a8f9ce9fc6bbff5928b016654bfd1b4836ca44] [core] change estimator CUSUM design params for loss to reduce oscillations. rename var.
git bisect good b2a8f9ce9fc6bbff5928b016654bfd1b4836ca44
# good: [902fa2c3da3e39f8f3cda4b57397d019f12b3bee] [mod_verto] add debug controls for verto
git bisect good 902fa2c3da3e39f8f3cda4b57397d019f12b3bee
# good: [902fa2c3da3e39f8f3cda4b57397d019f12b3bee] [mod_verto] add debug controls for verto
git bisect good 902fa2c3da3e39f8f3cda4b57397d019f12b3bee
# good: [6da4f147de3cd6b9ee1da0858a816a398dec8c8e] [Unit-Tests] Fix switch_core_video test to use temporary path for generated files and clean them up. Ignore test runtime dirs.
git bisect good 6da4f147de3cd6b9ee1da0858a816a398dec8c8e
# good: [3ce9a9a3930f5a59442af87d4ac31d0829f337ce] [core] fix long sql stmts may be skipped, introduced in 2e88c67c9de5452c7e442d8e7fd35ca0172ad569 in 2009
git bisect good 3ce9a9a3930f5a59442af87d4ac31d0829f337ce
# bad: [8a6a6fca4776acfda1a0276fda6cfe1860e78a83] [core] flush all the rtp on transfers
git bisect bad 8a6a6fca4776acfda1a0276fda6cfe1860e78a83
# bad: [f8004e1d664b838d15e2d8b47369abac39013def] [core] fix possible looping recover
git bisect bad f8004e1d664b838d15e2d8b47369abac39013def
# bad: [badd59d609b5d5583c01d543e0d6b3a9cb365df1] [core, mod_verto] remove CF_VIDEO_ONLY and pay attention to the streams instead and add CF_NO_RECOVER flag for verto
git bisect bad badd59d609b5d5583c01d543e0d6b3a9cb365df1
# first bad commit: [badd59d609b5d5583c01d543e0d6b3a9cb365df1] [core, mod_verto] remove CF_VIDEO_ONLY and pay attention to the streams instead and add CF_NO_RECOVER flag for verto

wmasilva avatar Aug 01 '22 17:08 wmasilva

hi,

Not sure the implications.. it could be fix adding in the if condition the flag SWITCH_MEDIA_FLOW_INACTIVE.

In switch_core_media.c:3474

if (audio_flow != SWITCH_MEDIA_FLOW_SENDRECV && audio_flow != SWITCH_MEDIA_FLOW_SENDONLY && audio_flow != SWITCH_MEDIA_FLOW_INACTIVE) {
    return SWITCH_STATUS_SUCCESS;
}

I've add extra debug to understand why is inactive flag enabled and i found that issue could be in the sip negotiation with address 0.0.0.0, it puts the b channel to inactive status, and no SIP message is generated to that side notifying the inative status...

My code:


	if (type == SWITCH_MEDIA_TYPE_AUDIO) {
		switch_media_flow_t audio_flow = switch_core_session_media_flow(session, SWITCH_MEDIA_TYPE_AUDIO);
		const char *smode_str = NULL;

		switch (audio_flow) {
		case SWITCH_MEDIA_FLOW_SENDONLY:
			smode_str = "sendonly";
			break;
		case SWITCH_MEDIA_FLOW_RECVONLY:
			smode_str = "recvonly";
			break;
		case SWITCH_MEDIA_FLOW_INACTIVE:
			smode_str = "inactive";
			break;
		case SWITCH_MEDIA_FLOW_DISABLED:
			smode_str = "disabled";
			break;
		case SWITCH_MEDIA_FLOW_SENDRECV:
			smode_str = "sendrecv";
			break;
		default:
			smode_str = "unknown";
			break;
		}
		switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_CRIT, "%s:%d audio flow is %s \n", engine->cur_payload_map->remote_sdp_ip, engine->cur_payload_map->remote_sdp_port, smode_str);
		if (audio_flow != SWITCH_MEDIA_FLOW_SENDRECV && audio_flow != SWITCH_MEDIA_FLOW_SENDONLY && audio_flow != SWITCH_MEDIA_FLOW_INACTIVE) {
			return SWITCH_STATUS_SUCCESS;
		}
	}

Attach the call log. 20220830_freeswitch_log_verbose_inactive.txt

The call is made from a yealink phone (extension 1000) to destination 133, and the destination side is the running SIPP scenario.

wmasilva avatar Aug 30 '22 16:08 wmasilva

found the issue, it is because the a=inactive in ACK from B leg, it makes the A leg stream to inactive and it don't change back to sendrecv if B leg stream is active again.

it is done in: https://github.com/signalwire/freeswitch/blob/7c18cc08d401ac9851b5d7343b0e2abf081dbcb0/src/switch_core_media.c#L4890

and when A leg media stream change to inactive no SIP message is send to the device, it should, no?

I'm think of a simple solution, is to add a channel variable to disable this behaviour, something like:

if (!switch_channel_var_true(session->channel, "rtp_ignore_response_stream_media_mode")) {
...
}

What do you think?

Thanks.

wmasilva avatar Aug 31 '22 09:08 wmasilva

Set this channel variable rtp_pass_codecs_on_stream_change=true

jakubkarolczyk avatar Sep 08 '22 15:09 jakubkarolczyk

Set this channel variable rtp_pass_codecs_on_stream_change=true

Hi, thanks for the comment but it doesn't work...

wmasilva avatar Sep 08 '22 15:09 wmasilva

Fix your sipp script, you can't perform action exec play_pcap_audio twice or more, it can be only set once.

jakubkarolczyk avatar Sep 08 '22 15:09 jakubkarolczyk

hum... no need you can do it, what will happen is that the previous play_pcap_audio stop and the new one is executed. you can check the pcap file the result rtp is the same as the one played in the sipp script.

wmasilva avatar Sep 08 '22 16:09 wmasilva

to be sure i just test with last code and the issue is still present.

I try using setting it only for remote side: <action application="bridge" data="{absolute_codec_string=PCMA,PCMU}[rtp_disable_hold=true,sip_unhold_nosdp=true,rtp_pass_codecs_on_stream_change=true]sofia/gateway/sipp/${destination_number}"/>

The result is worst.. and call is not end unless i hangup in the phone... the yealink phone answers "488 not acceptable here" and FS don't reply to BLEG it gets stuck and Trying... see call flow.

Screenshot 2022-09-08 at 17 22 37

I also try set using application set: <action application="set" data="rtp_pass_codecs_on_stream_change=true"/>

The result is the same as not setting the variable.. sip level is OK, but no RTP to ALEG when BLEG is transmiting the audio.

I attach fresh data (log and zip with pcap files) fs_no_audio_app_set_rtp_pass_codecs_on_stream_change_true.log fs_no_audio_rtp_pass_codecs_on_stream_change_true.log rtp_pass_codecs_on_stream_pcap.zip

@andywolk can you please re-open the issue?

Thanks.

wmasilva avatar Sep 08 '22 16:09 wmasilva

right, your Yealink does reject pcma and your intention is to do transcoding.

Please check if the fix from the PR below resolves your issue.

https://github.com/signalwire/freeswitch/pull/1804

jakubkarolczyk avatar Sep 09 '22 10:09 jakubkarolczyk

right, your Yealink does reject pcma and your intention is to do transcoding.

Please check if the fix from the PR below resolves your issue.

#1804

hi, sure, testing it now. thanks.

wmasilva avatar Sep 09 '22 10:09 wmasilva

@jakubkarolczyk your patch solves the issue, thanks.

i've test multiple combinations:

Test one, dialstring: <action application="bridge" data="[^^:absolute_codec_string=PCMA,PCMU][rtp_disable_hold=true,sip_unhold_nosdp=true]sofia/gateway/sipp/${destination_number}"/> Result: OK, audio at the end of the call and music on hold between. (NOTE: i had an error on my previous dialstring.. in absolute_codec_string, only PCMA was available to BLEG, so FS ignored the PCMU traffic from BLEG)

Test two, setting the variable using set application:

<action application="set" data="rtp_pass_codecs_on_stream_change=true"/>
<action application="bridge" data="[^^:codec_string=PCMA,PCMU][^^:absolute_codec_string=PCMA,PCMU][rtp_disable_hold=true,sip_unhold_nosdp=true]sofia/gateway/sipp/${destination_number}"/>

Result: OK, audio always.

Test three: onleg_rtp_pass_codecs_on_stream_change

<action application="bridge" data="{absolute_codec_string=PCMA,PCMU}[rtp_disable_hold=true,sip_unhold_nosdp=true,rtp_pass_codecs_on_stream_change=true]sofia/gateway/sipp/${destination_number}"/>

Result: ERROR, same problem as before, yealink reply 486, FS never finish the invite from BLEG ... and no audio after the re-invites. But i think that is a different issue, attach the log here if you want check it.

freeswitch_onleg_rtp_pass_codecs_on_stream_change.log.txt

In conclusion, the patch in https://github.com/signalwire/freeswitch/pull/1804 fix it.

wmasilva avatar Sep 09 '22 11:09 wmasilva

With rtp_pass_codecs_on_stream_change=true FS sends Re-INVITE to A leg on stream change (it changes from sendrcv to inactive) offering PCMA, so the codec your Yeahlink phone rejects replying with 488. If your desired scenario is to transcode on FS between PCMA<->PCMU, you shouldn't use rtp_pass_codecs_on_stream_change chan var. The fix does not require it, these are to separate things.

jakubkarolczyk avatar Sep 09 '22 11:09 jakubkarolczyk