SRTP - Can't provide secure audio requested in SDP offer

System:
Ubuntu 12.04 LTS 64Bit
Asterisk 11.2.1
FreePBX 2.11

Hi Guys,
I have a problem to issue calls with SRTP.
The FreePBX configured to work with TLS and libSRTP installed well. I used this tutorial to configuration: https://wiki.asterisk.org/wiki/display/AST/Secure+Calling+Tutorial
When I am initiating new call with TLS only the calls working well, when SRTP added and initiate new call, I received this error:

== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
[2013-04-21 10:39:00] WARNING[16542][C-00000352]: sip/sdp_crypto.c:170 sdp_crypto_activate: Could not set SRTP policies
[2013-04-21 10:39:00] WARNING[16542][C-00000352]: sip/sdp_crypto.c:170 sdp_crypto_activate: Could not set SRTP policies
[2013-04-21 10:39:00] WARNING[16542][C-00000352]: chan_sip.c:10427 process_sdp: Can’t provide secure audio requested in SDP offer

When I tried to Google it, I could not find any relevant posts to solve this issue.
If more information needed, just let me know and I will upload it.

Thanks,
Noy

Do you have Asterisk compiled for SRTP and do you have the SRTP packages installed on your OS?

Hi Tony,

Thank you for your replied, Yes the Asterisk compiled after marking res_srtp [*] under Resource Modules.
Following trace, maybe it can help.

[code][2013-04-22 07:23:35] DEBUG[2936]: logger.c:1294 ast_create_callid: CALL_ID [C-000003c6] created by thread.
[2013-04-22 07:23:35] DEBUG[2936]: acl.c:979 ast_ouraddrfor: For destination ‘84.111.xx.xx’, our source address is ‘173.203.xx.xx’.
[2013-04-22 07:23:35] DEBUG[2936]: chan_sip.c:4021 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_TLS with address 173.203.xx.xx:5061
[2013-04-22 07:23:35] DEBUG[2936]: chan_sip.c:8721 sip_alloc: Allocating new SIP dialog for 80bcaeee3f014a69ba4b4f8d32d741d5 - INVITE (No RTP)
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-000003c6] bound to thread.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:27866 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: sip/reqresp_parser.c:1550 parse_sip_options: Begin: parsing SIP “Supported: 100rel, replaces, norefersub, gruu”
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: sip/reqresp_parser.c:1566 parse_sip_options: Found SIP option: -100rel-
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: sip/reqresp_parser.c:1574 parse_sip_options: Matched SIP option: 100rel
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: sip/reqresp_parser.c:1566 parse_sip_options: Found SIP option: -replaces-
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: sip/reqresp_parser.c:1574 parse_sip_options: Matched SIP option: replaces
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: sip/reqresp_parser.c:1566 parse_sip_options: Found SIP option: -norefersub-
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: sip/reqresp_parser.c:1574 parse_sip_options: Matched SIP option: norefersub
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: sip/reqresp_parser.c:1566 parse_sip_options: Found SIP option: -gruu-
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: sip/reqresp_parser.c:1574 parse_sip_options: Matched SIP option: gruu
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:17845 check_via: NAT detected for 192.168.xx.xx:56511 / 84.111.xx.xx:56511
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:3864 __sip_xmit: Trying to put ‘SIP/2.0 401’ onto TLS socket destined for 84.111.xx.xx:56511
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-000003c6] being removed from thread.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-000003c6] bound to thread.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:27866 handle_incoming: **** Received ACK (6) - Command in SIP ACK
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:4556 __sip_ack: Stopping retransmission on ‘80bcaeee3f014a69ba4b4f8d32d741d5’ of Response 2279: Match Not Found
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-000003c6] being removed from thread.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-000003c6] bound to thread.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:27866 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:17845 check_via: NAT detected for 192.168.xx.xx:56511 / 84.111.xx.xx:56511
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: rtp_engine.c:283 ast_rtp_instance_new: Using engine ‘asterisk’ for RTP instance ‘0x7fcf3002a588’
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: res_rtp_asterisk.c:1732 ast_rtp_new: Allocated port 13348 for RTP instance ‘0x7fcf3002a588’
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: rtp_engine.c:292 ast_rtp_instance_new: RTP instance ‘0x7fcf3002a588’ is setup and ready to go
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: res_rtp_asterisk.c:3851 ast_rtp_prop_set: Setup RTCP on RTP instance ‘0x7fcf3002a588’
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:5725 do_setnat: Setting NAT on RTP to On
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:10000 process_sdp: Processing session-level SDP v=0… UNSUPPORTED OR FAILED.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:10000 process_sdp: Processing session-level SDP o=- 3575614999 3575614999 IN IP4 192.168.xx.xx… OK.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:10000 process_sdp: Processing session-level SDP s=Blink 0.2.10 (Windows)… UNSUPPORTED OR FAILED.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:10000 process_sdp: Processing session-level SDP c=IN IP4 192.168.xx.xx… OK.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:10000 process_sdp: Processing session-level SDP t=0 0… UNSUPPORTED OR FAILED.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 0 based on m type on 0x7fcf484d9630
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 8 based on m type on 0x7fcf484d9630
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 based on m type on 0x7fcf484d9630
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtcp:50005… UNSUPPORTED OR FAILED.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000… OK.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000… OK.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000… OK.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-15… UNSUPPORTED OR FAILED.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: sip/sdp_crypto.c:105 sdp_crypto_setup: local_key64 fHb/j+JhgbvQfRjjLCHY5bBaeduL+0HCit35+VBN len 40
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: res_srtp.c:498 ast_srtp_add_stream: Adding new policy for SSRC 257472013
[2013-04-22 07:23:35] WARNING[2936][C-000003c6]: res_srtp.c:500 ast_srtp_add_stream: Failed to add SRTP stream for SSRC 257472013
[2013-04-22 07:23:35] WARNING[2936][C-000003c6]: sip/sdp_crypto.c:170 sdp_crypto_activate: Could not set SRTP policies
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:v+iGNfNzL+aD4JZ33v7i6tAigLlDTycSIrvWTWGl… UNSUPPORTED OR FAILED.
[2013-04-22 07:23:35] WARNING[2936][C-000003c6]: sip/sdp_crypto.c:170 sdp_crypto_activate: Could not set SRTP policies
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:dmEo1rpcPiB4P1zfOrJyqOwTZ32hRLil+kP/W7xW… UNSUPPORTED OR FAILED.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=sendrecv… OK.
[2013-04-22 07:23:35] WARNING[2936][C-000003c6]: chan_sip.c:10427 process_sdp: Can’t provide secure audio requested in SDP offer
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:3864 __sip_xmit: Trying to put ‘SIP/2.0 488’ onto TLS socket destined for 84.111.xx.xx:56511
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:25116 handle_request_invite: No compatible codecs for this SIP call.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:28168 handle_request_do: SIP message could not be handled, bad request: 80bcaeee3f014a69ba4b4f8d32d741d5
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-000003c6] being removed from thread.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-000003c6] bound to thread.
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:27866 handle_incoming: **** Received ACK (6) - Command in SIP ACK
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: chan_sip.c:4556 __sip_ack: Stopping retransmission on ‘80bcaeee3f014a69ba4b4f8d32d741d5’ of Response 2280: Match Not Found
[2013-04-22 07:23:35] DEBUG[2936][C-000003c6]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-000003c6] being removed from thread.

[/code]

I am really appreciate your assistance.

Thanks,
Noy