Rtpengine forwards SSL trafic on RTP on call hold

[virmis]

Hi,

I'm using 3.3.0.0+0~mr3.4.2.1 and kamailio 4.2.0-pre1 (x86_64/linux) 44e298

When Sipml client presses on hold asterisk receives SSL traffic on RTP instance:
[Oct 3 12:41:47] ERROR[4493][C-00000059]: res_rtp_asterisk.c:1936 __rtp_recvfrom: Received SSL traffic on RTP instance '0x7f9cfc4aa6e8' without an SSL session
[Oct 3 12:41:47] ERROR[4493][C-00000059]: res_rtp_asterisk.c:1936 __rtp_recvfrom: Received SSL traffic on RTP instance '0x7f9cfc4aa6e8' without an SSL session
[Oct 3 12:41:47] WARNING[4493][C-00000059]: res_rtp_asterisk.c:4197 ast_rtp_read: RTP Read error: Unspecified. Hanging up.
[Oct 3 12:41:47] WARNING[4493][C-00000059]: res_rtp_asterisk.c:4197 ast_rtp_read: RTP Read error: Unspecified. Hanging up.

rtpengine log shows:
Oct 3 12:41:47 localhost rtpengine[3772]: Got valid command from 127.0.0.1:41616: offer - { "sdp": "v=0#015#012o=- 3161846126406615600 3 IN IP4 127.0.0.1#015#012s=Doubango Telecom - chrome#015#012t=0 0#015#012a=msid-semantic: WMS pGwX5Qn9NlVMDtJYyEwwQQ6pvQj9ZiqLDG6x#015#012m=audio 55508 UDP/TLS/RTP/SAVPF 0#015#012c=IN IP4 10.15.38.22#015#012a=rtcp:62638 IN IP4 10.15.38.22#015#012a=candidate:852255240 1 udp 2122260223 10.15.38.22 55508 typ host generation 0#015#012a=candidate:852255240 2 udp 2122260222 10.15.38.22 62638 typ host generation 0#015#012a=ice-ufrag:WNYhlfivFdT+aRoo#015#012a=ice-pwd:gPQbOMQScANKN+22dpskNBeH#015#012a=fingerprint:sha-256 1E:74:90:87:9B:DF:F9:EF:F4:B0:F8:4E:CB:35:B3:AF:44:DB:D2:BB:31:EF:5B:5F:03:B0:3B:F5:34:6B:DF:BE#015#012a=setup:active#015#012a=mid:audio#015#012a=sendonly#015#012a=rtpmap:0 PCMU/8000#015#012a=ssrc:3600308564 cname:/HlU0tr3/SI8jof1#015#012a=ssrc:3600308564 msid:pGwX5Qn9NlVMDtJYyEwwQQ6pvQj9ZiqLDG6x 5059faa4-c28d-498d-a37f-4a99ae4471cd#015#012a=ssrc:3600308564 mslabel:pGwX5Qn9NlVMDtJYyEwwQQ6pvQj9ZiqLDG6x#015#012a=ssrc:3600308564 label:5059faa4-c28d-498d-a37f-4a99ae4471cd#015#012", "ICE": "remove", "flags": [ "force", "trust-address" ], "replace": [ "origin", "session-connection" ], "transport-protocol": "RTP/AVP", "call-id": "44e3f66b7017c3c840df18a55637c152@10.15.26.113:5060", "received-from": [ "IP4", "10.15.38.22" ], "from-tag": "zIaE6fQu094GLubHaDmv", "to-tag": "as365a4e0c", "command": "offer" }
Oct 3 12:41:47 localhost rtpengine[3772]: Unknown flag encountered: 'force'
Oct 3 12:41:47 localhost rtpengine[3772]: [44e3f66b7017c3c840df18a55637c152@10.15.26.113:5060] Returning to SIP proxy: d3:sdp522:v=0#015#012o=- 3161846126406615600 3 IN IP4 10.15.26.112#015#012s=Doubango Telecom - chrome#015#012t=0 0#015#012a=msid-semantic: WMS pGwX5Qn9NlVMDtJYyEwwQQ6pvQj9ZiqLDG6x#015#012m=audio 30010 RTP/AVP 0#015#012c=IN IP4 10.15.26.112#015#012a=mid:audio#015#012a=rtpmap:0 PCMU/8000#015#012a=ssrc:3600308564 cname:/HlU0tr3/SI8jof1#015#012a=ssrc:3600308564 msid:pGwX5Qn9NlVMDtJYyEwwQQ6pvQj9ZiqLDG6x 5059faa4-c28d-498d-a37f-4a99ae4471cd#015#012a=ssrc:3600308564 mslabel:pGwX5Qn9NlVMDtJYyEwwQQ6pvQj9ZiqLDG6x#015#012a=ssrc:3600308564 label:5059faa4-c28d-498d-a37f-4a99ae4471cd#015#012a=sendonly#015#012a=rtcp:30011#015#0126:result2:oke

[rfuchs]

More information please. What happened in this call previously and who's sending what kind of RTP traffic where?

[virmis]

Cisco phone <---> asterisk <---> kamailio + rtpengine <---> sipml5

Cisco phone calls to sipml5, sipml5 answers, call is established, then sipml5 presses hold this happen.

[rfuchs]

So rtpengine was talking SRTP to sipml and RTP to asterisk. Then sipml went sendonly, and then rtpengine started sending SRTP to asterisk? Is that what you're saying?

[virmis]

yes, that's right

[virmis]

Here's trace from asterisk:
https://www.dropbox.com/s/pkbfeumgboqt9y3/glue.pcap?dl=0

[rfuchs]

The pcap shows that the call is hung up (BYE in packet 1411) before the re-invite to sendonly (1412). Also there's no RTP packets after this point.

I tried reproducing what you describe but I can't.

[virmis]

What can be wrong? Maybe I'm calling rtpengine_manage with wrong options?

[rfuchs]

Can you make a pcap of the other side as well, and also post the full rtpengine log for the entire call please. I'm guessing that packet 1409 is what triggers the error in asterisk.

[virmis]

Hi,

took pcap from kamailio to sipml5, also here's log files from rtpengine and from sipml5:
https://www.dropbox.com/sh/mt4zu396frb3be0/AACZriVHq5h7xL4DbcmLV1Jqa?dl=0

[rfuchs]

Can you please try apply the following patch, recompile and see if that fixes your issue?

diff --git a/daemon/call.c b/daemon/call.c
index 548f98c..c60cd6c 100644
--- a/daemon/call.c
+++ b/daemon/call.c
@@ -611,8 +611,7 @@ static int stream_packet(struct stream_fd *sfd, str *s, struct sockaddr_in6 *fsi

        if (MEDIA_ISSET(media, DTLS) && is_dtls(s)) {
                ret = dtls(stream, s, fsin);
-               if (!ret)
-                       goto done;
+               goto done;
        }

        if (PS_ISSET(stream, STUN) && is_stun(s)) {

[virmis]

Did not work, still getting the same.

[rfuchs]

Anything helpful in the logs? I can't see to find any actual logs in what you've uploaded earlier, there's only some MacOS specific files that I don't know what to do with.

[virmis]

Sorry. Moved from pages to txt files:
https://www.dropbox.com/sh/mt4zu396frb3be0/AACZriVHq5h7xL4DbcmLV1Jqa?dl=0

[rfuchs]

I've finally been able to reproduce this and the above commit should fix this issue for you. Let me know if there's any more problems.