[Freeswitch-users] SRTP switch_core_media.c:4522 Crypto not negotiated but required.

[Miller, Michael]

I'm new to Freeswitch and have udp, tcp and tls only calls working.  However; I am having problems with tls and srtp.

Call flow is bria client -- (udp+rdp) --> freeswitch -- (tls+srtp) --> sbc

In my invite, I send the following SDP from Freeswitcch:
   m=audio 20606 RTP/SAVP 9 8 0
   a=rtpmap:9 G722/8000
   a=rtpmap:8 PCMA/8000
   a=rtpmap:0 PCMU/8000
   a=crypto:5 AES_CM_128_HMAC_SHA1_80 inline:6dYwo00ZMUlaJXkdnTWAVsaqBsxXvVnPBO14sbO7
   a=ptime:20

In the 180 and 200 response, I get:
   m=audio 6206 RTP/SAVP 8
   a=crypto:5 AES_CM_128_HMAC_SHA1_80 inline:MrKNE3L5SSc9yb1o7G5BWJkcpLFvprrctnH/c6go
   a=rtpmap:8 PCMA/8000
   a=sendrecv
   a=maxptime:20

Everything looks good.

After the 200 ok, I see the following in the freeswitch log:
2017-08-17 08:48:34.801061 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_128_HMAC_SHA1_80] in [5 AES_CM_128_HMAC_SHA1_80 inline:MrKNE3L5SSc9yb1o7G5BWJkcpLFvprrctnH/c6go]
2017-08-17 08:48:34.801061 [DEBUG] switch_core_media.c:1400 Found suite AES_CM_128_HMAC_SHA1_80
2017-08-17 08:48:34.801061 [DEBUG] switch_core_media.c:1466 Set Remote Key [5 AES_CM_128_HMAC_SHA1_80 inline:MrKNE3L5SSc9yb1o7G5BWJkcpLFvprrctnH/c6go]
2017-08-17 08:48:34.801061 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2017-08-17 08:48:34.801061 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-08-17 08:48:34.801061 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2017-08-17 08:48:34.801061 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]

After receiving the ACK, I see the following in the fs log:
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[G722:9:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[PCMU:0:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[PCMA:8:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [SILK:122:16000:20:0:1]/[G722:9:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [SILK:122:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [SILK:122:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101 at 8000
2017-08-17 08:48:34.821064 [WARNING] switch_core_media.c:4522 Crypto not negotiated but required.
2017-08-17 08:48:34.821064 [DEBUG] switch_core_media.c:4767 sofia/internal/7202007917 at 10.251.145.154 Set 2833 dtmf send payload to 101 recv payload to 101
2017-08-17 08:48:34.821064 [NOTICE] switch_channel.c:3812 Hangup sofia/internal/7202007917 at 10.251.145.154 [CS_EXECUTE] [INCOMPATIBLE_DESTINATION]
2017-08-17 08:48:34.821064 [DEBUG] switch_ivr_originate.c:3661 sofia/internal/7202007917 at 10.251.145.154 Media Establishment Failed.

My dial-plan looks like:
<include>
	<extension name="CBRNBS703_TLS_7202007909">
		<condition field="destination_number" expression="7202007909"\>
			<action application="set" data="dtmf_type=rfc2833"/>
			<action application="export" data="rtp_secure_media=mandatory:AES_CM_128_HMAC_SHA1_80"/>
			<action application="export" data="sdp_secure_savp_only=true"/>
			<action application="bridge" data="sofia/gateway/cbrnbs703-tls/7202007909 at 4.4.0.181:5061;transport=tls"/>
		</condition>
	</extension>
</include>

Any help would be appreciated.