Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

WebRTC (sip.js + kamailio) Audio issue #983

Closed
chiragd opened this issue Apr 30, 2020 · 20 comments
Closed

WebRTC (sip.js + kamailio) Audio issue #983

chiragd opened this issue Apr 30, 2020 · 20 comments

Comments

@chiragd
Copy link

chiragd commented Apr 30, 2020

Hi all,

I'm having trouble with both sip.js and jssip + kamailio + asterisk. When I make a call from the web to a sip phone I get audio both ways.

When I make a call from a sip phone to the web, the session connects, but there is no audio in either direction.

I'm at a bit of a loss as to what might be wrong. Calls in either direction for SIP to SIP have audio.

Here are the logs from a call with successful audio from Web to SIP

rtpengine[29002]: [7hspuengl0tsrn4hovlv] Received command 'offer' from 127.0.0.1:39612 rtpengine[29002]: [7hspuengl0tsrn4hovlv] Creating new call rtpengine[29002]: [7hspuengl0tsrn4hovlv] Replying to 'offer' from 127.0.0.1:39612 rtpengine[29002]: [066c05c0-c555-4502-ab9e-71d511395a51] Received command 'offer' from 127.0.0.1:57036 rtpengine[29002]: [066c05c0-c555-4502-ab9e-71d511395a51] Creating new call rtpengine[29002]: [066c05c0-c555-4502-ab9e-71d511395a51] Replying to 'offer' from 127.0.0.1:57036 rtpengine[29002]: [066c05c0-c555-4502-ab9e-71d511395a51] Received command 'answer' from 127.0.0.1:49806 rtpengine[29002]: [066c05c0-c555-4502-ab9e-71d511395a51] Replying to 'answer' from 127.0.0.1:49806 /usr/local/sbin/kamailio[20437]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588203682;method=INVITE;from_tag=c6cc5cdf-8626-4bcb-9684-d15747316ae6;to_tag=zRfePsSxQ8PPe03ovjrCSnj6.kEl5FoP;call_id=066c05c0-c555-4502-ab9e-71d511395a51;code=200;reason=OK;src_user=user4;src_domain=[ASTERISK_PUBLIC_IP];src_ip=[ASTERISK_PRIVATE_IP];dst_ouser=user1;dst_user=user1;dst_domain=[SIP_DEVICE_PUBLIC_IP] rtpengine[29002]: [7hspuengl0tsrn4hovlv] Received command 'answer' from 127.0.0.1:57036 rtpengine[29002]: [7hspuengl0tsrn4hovlv] Replying to 'answer' from 127.0.0.1:57036 /usr/local/sbin/kamailio[20453]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588203682;method=INVITE;from_tag=449rsqjsjo;to_tag=6ae5dfbc-567f-43de-8840-599ea9a9331e;call_id=7hspuengl0tsrn4hovlv;code=200;reason=OK;src_user=user4;src_domain=sip.mydomain.com;src_ip=[BROWSER_PUBLIC_IP];dst_ouser=451005;dst_user=1005;dst_domain=sip.mydomain.com rtpengine[29002]: [7hspuengl0tsrn4hovlv port 31342] SRTP output wanted, but no crypto suite was negotiated rtpengine[29002]: [7hspuengl0tsrn4hovlv port 31362] Unknown STUN attribute: 0xc057 rtpengine[29002]: [7hspuengl0tsrn4hovlv port 31362] ICE negotiated: peer for component 1 is [BROWSER_PUBLIC_IP]:38966 rtpengine[29002]: [7hspuengl0tsrn4hovlv port 31362] DTLS: Peer certificate accepted rtpengine[29002]: [7hspuengl0tsrn4hovlv port 31362] DTLS-SRTP successfully negotiated rtpengine[29002]: [7hspuengl0tsrn4hovlv port 31362] DTLS-SRTP successfully negotiated rtpengine[29002]: [7hspuengl0tsrn4hovlv port 31362] Unknown STUN attribute: 0xc057 rtpengine[29002]: last message repeated 3 times rtpengine[29002]: [066c05c0-c555-4502-ab9e-71d511395a51 port 31376] Confirmed peer address as [SIP_DEVICE_PUBLIC_IP]:64418 rtpengine[29002]: [7hspuengl0tsrn4hovlv port 31342] Confirmed peer address as [ASTERISK_PUBLIC_IP]:25954 rtpengine[29002]: [7hspuengl0tsrn4hovlv port 31362] Confirmed peer address as [BROWSER_PUBLIC_IP]:38966 rtpengine[29002]: [066c05c0-c555-4502-ab9e-71d511395a51 port 31388] Confirmed peer address as [ASTERISK_PUBLIC_IP]:31054 rtpengine[29002]: [066c05c0-c555-4502-ab9e-71d511395a51 port 31377] Confirmed peer address as [SIP_DEVICE_PUBLIC_IP]:64419 rtpengine[29002]: [066c05c0-c555-4502-ab9e-71d511395a51 port 31389] Confirmed peer address as [ASTERISK_PUBLIC_IP]:31055 rtpengine[29002]: [7hspuengl0tsrn4hovlv port 31343] Confirmed peer address as [ASTERISK_PUBLIC_IP]:25955 rtpengine[29002]: [7hspuengl0tsrn4hovlv port 31362] Unknown STUN attribute: 0xc057 rtpengine[29002]: [c1649969-9a71-4c21-92d6-4af9be12a899] Call branch '15276b4f-b69f-4908-99c9-e770beeb0f3a' deleted, no more branches remaining rtpengine[29002]: [c1649969-9a71-4c21-92d6-4af9be12a899] Final packet stats: rtpengine[29002]: [c1649969-9a71-4c21-92d6-4af9be12a899] --- Tag '', created 0:32 ago for branch 'z9hG4bKPj458df8ff-9533-4052-87dc-efd78a494a690', in dialogue with '15276b4f-b69f-4908-99c9-e770beeb0f3a' rtpengine[29002]: [c1649969-9a71-4c21-92d6-4af9be12a899] ------ Media #1 (audio over RTP/SAVPF) using unknown codec rtpengine[29002]: [c1649969-9a71-4c21-92d6-4af9be12a899] --------- Port 31314 <> [::]:0 , 0 p, 0 b, 0 e, 1588203658 last_packet rtpengine[29002]: [c1649969-9a71-4c21-92d6-4af9be12a899] --- Tag '15276b4f-b69f-4908-99c9-e770beeb0f3a', created 0:32 ago for branch '', in dialogue with '' rtpengine[29002]: [c1649969-9a71-4c21-92d6-4af9be12a899] ------ Media #1 (audio over RTP/AVP) using unknown codec rtpengine[29002]: [c1649969-9a71-4c21-92d6-4af9be12a899] --------- Port 31328 <> [ASTERISK_PRIVATE_IP]:29290, 0 p, 0 b, 0 e, 1588203658 last_packet rtpengine[29002]: [c1649969-9a71-4c21-92d6-4af9be12a899] --------- Port 31329 <> [ASTERISK_PRIVATE_IP]:29291 (RTCP), 0 p, 0 b, 0 e, 1588203658 last_packet rtpengine[29002]: [7hspuengl0tsrn4hovlv port 31362] Unknown STUN attribute: 0xc057 rtpengine[29002]: [7hspuengl0tsrn4hovlv port 31362] Unknown STUN attribute: 0xc057 Apr 30 00:41:35 mars /usr/local/sbin/kamailio[20452]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588203695;method=BYE;from_tag=zRfePsSxQ8PPe03ovjrCSnj6.kEl5FoP;to_tag=c6cc5cdf-8626-4bcb-9684-d15747316ae6;call_id=066c05c0-c555-4502-ab9e-71d511395a51;code=200;reason=OK;src_user=user1;src_domain=sip.mydomain.com;src_ip=[SIP_DEVICE_PUBLIC_IP];dst_ouser=user4;dst_user=asterisk;dst_domain=[ASTERISK_PRIVATE_IP] rtpengine[29002]: [7hspuengl0tsrn4hovlv] Received command 'delete' from 127.0.0.1:45406 rtpengine[29002]: [7hspuengl0tsrn4hovlv] Scheduling deletion of call branch '6ae5dfbc-567f-43de-8840-599ea9a9331e' in 30 seconds rtpengine[29002]: [7hspuengl0tsrn4hovlv] Replying to 'delete' from 127.0.0.1:45406 /usr/local/sbin/kamailio[20453]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588203695;method=BYE;from_tag=6ae5dfbc-567f-43de-8840-599ea9a9331e;to_tag=449rsqjsjo;call_id=7hspuengl0tsrn4hovlv;code=200;reason=OK;src_user=451005;src_domain=sip.mydomain.com;src_ip=[ASTERISK_PRIVATE_IP];dst_ouser=user4;dst_user=ufo2tm19;dst_domain=v9mg9emv989r.invalid

Here are the logs from an unsuccessful call from SIP to Web:

rtpengine[29002]: [1e82d51a-692f-4d25-ab2a-82c1d04b49be] Received command 'offer' from 127.0.0.1:45406 rtpengine[29002]: [1e82d51a-692f-4d25-ab2a-82c1d04b49be] Creating new call rtpengine[29002]: [1e82d51a-692f-4d25-ab2a-82c1d04b49be] Replying to 'offer' from 127.0.0.1:45406 rtpengine[29002]: [1e82d51a-692f-4d25-ab2a-82c1d04b49be] Received command 'offer' from 127.0.0.1:45406 rtpengine[29002]: [1e82d51a-692f-4d25-ab2a-82c1d04b49be] Replying to 'offer' from 127.0.0.1:45406 rtpengine[29002]: [1e82d51a-692f-4d25-ab2a-82c1d04b49be port 31398] Unknown STUN attribute: 0xc057 rtpengine[29002]: [1e82d51a-692f-4d25-ab2a-82c1d04b49be] Received command 'answer' from 127.0.0.1:45406 rtpengine[29002]: [1e82d51a-692f-4d25-ab2a-82c1d04b49be] Replying to 'answer' from 127.0.0.1:45406 /usr/local/sbin/kamailio[20452]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588204231;method=INVITE;from_tag=36319a77-de59-4932-9dd0-dce8a5e1be90;to_tag=18i8obqm8h;call_id=1e82d51a-692f-4d25-ab2a-82c1d04b49be;code=200;reason=OK;src_user=user1;src_domain=[ASTERISK_PUBLIC_IP];src_ip=[ASTERISK_PRIVATE_IP];dst_ouser=user4;dst_user=6ph0bkfs;dst_domain=virem4qg2pdl.invalid /usr/local/sbin/kamailio[20454]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588204231;method=INVITE;from_tag=CgiA1iVlaO4z7kTmo.B2pzBfaUPqEusE;to_tag=26cee0c6-0b8d-4302-a81e-e86789af011c;call_id=4exJZRW8gztd32RU0id5W4fL7wkDWGM2;code=200;reason=OK;src_user=user1;src_domain=sip.mydomain.com;src_ip=[SIP_DEVICE_PUBLIC_IP];dst_ouser=451004;dst_user=1004;dst_domain=sip.mydomain.com rtpengine[29002]: [1e82d51a-692f-4d25-ab2a-82c1d04b49be port 31398] Unknown STUN attribute: 0xc057 rtpengine[29002]: [1e82d51a-692f-4d25-ab2a-82c1d04b49be port 31398] Unknown STUN attribute: 0xc057 rtpengine[29002]: [1e82d51a-692f-4d25-ab2a-82c1d04b49be port 31398] ICE negotiated: peer for component 1 is 79.66.176.56:46472 rtpengine[29002]: [1e82d51a-692f-4d25-ab2a-82c1d04b49be port 31398] Unknown STUN attribute: 0xc057 rtpengine[29002]: last message repeated 3 times /usr/local/sbin/kamailio[20454]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588204240;method=BYE;from_tag=CgiA1iVlaO4z7kTmo.B2pzBfaUPqEusE;to_tag=26cee0c6-0b8d-4302-a81e-e86789af011c;call_id=4exJZRW8gztd32RU0id5W4fL7wkDWGM2;code=200;reason=OK;src_user=user1;src_domain=sip.mydomain.com;src_ip=[SIP_DEVICE_PUBLIC_IP];dst_ouser=451004;dst_user=;dst_domain=[ASTERISK_PRIVATE_IP] rtpengine[29002]: [1e82d51a-692f-4d25-ab2a-82c1d04b49be] Received command 'delete' from 127.0.0.1:45406 rtpengine[29002]: [1e82d51a-692f-4d25-ab2a-82c1d04b49be] Scheduling deletion of call branch '36319a77-de59-4932-9dd0-dce8a5e1be90' in 30 seconds rtpengine[29002]: [1e82d51a-692f-4d25-ab2a-82c1d04b49be] Replying to 'delete' from 127.0.0.1:45406 /usr/local/sbin/kamailio[20453]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588204240;method=BYE;from_tag=36319a77-de59-4932-9dd0-dce8a5e1be90;to_tag=18i8obqm8h;call_id=1e82d51a-692f-4d25-ab2a-82c1d04b49be;code=200;reason=OK;src_user=user1;src_domain=[ASTERISK_PUBLIC_IP];src_ip=[ASTERISK_PRIVATE_IP];dst_ouser=user4;dst_user=6ph0bkfs;dst_domain=virem4qg2pdl.invalid

Any advise would be much appreciated - thanks!
@rfuchs
Copy link
Member

rfuchs commented May 1, 2020

Somehow the logs you posted ended up being all in one line, which makes it impossible to read. Also run rtpengine with log-level 7 for more information. (Logs from Asterisk/Kamailio aren't really relevant.)

@chiragd
Copy link
Author

chiragd commented May 1, 2020

Thanks Richard. I'll try to tidy up the logs for you so they're easier to read. I'll try a higher log level too and report back. Thanks!

@chiragd
Copy link
Author

chiragd commented May 2, 2020 •
edited

Hi Richard,

I've set the log level to 7 and here are two log dumps. One shows a successful call with audio (webrtc -> SIP).

The second shows an unsuccessful call without audio (SIP -> WebRTC).

All of my devices register to kamailio. All SIP traffic is forwarded to asterisk. If the call is for a device registered at Kamailio the asterisk service will pass the call back to kamailio in order to reach the contact.

Having read the logs myself, it looks to me like the SRTP isn't negotiating properly for the SIP -> WEBRTC call therefore there is no audio. I'm guessing there is a problem in my Kamailio config. Here I ask kamailio to secure audio coming and going from kamailio to the public, but to decrypt once it is 'inside' my network and talking to asterisk. If you have any advice on obvious places I should be checking, I would appreciate it.

Thanks in advance!

Successful call (with audio)

`rtpengine[31922]: [0cukd02a3alg80sgnnt7] Received command 'offer' from 127.0.0.1:40611

rtpengine[31922]: [0cukd02a3alg80sgnnt7] Dump for 'offer' from 127.0.0.1:40611: { "sdp": "v=0#015#012o=- 4131318426602582682 2 IN IP4 127.0.0.1#015#012s=-#15#012t=0 0#015#012a=group:BUNDLE 0#015#012a=msid-semantic: WMS PRsKRyqY6ZlONK5Yot1c3J3ARV2klnoY3rS6#015#012m=audio 9 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126#015#012c=IN IP4 0.0.0.0#015#012a=rtcp:9 IN IP4 0.0.0.0#015#012a=candidate:2993348229 1 udp 2113937151 c3d14e13-6148-4c1b-91dd-ad09088dd88e.local 43770 typ host generation 0 network-cost 999#015#012a=ice-ufrag:4Phd#015#012a=ice-pwd:2bdvsdOdmnndEOlcERFqBr6X#015#012a=ice-options ...

rtpengine[31922]: [0cukd02a3alg80sgnnt7] ... :trickle#015#012a=fingerprint:sha-256 E6:75:58:D7:87:A7:8E:9C:20:84:3D:16:37:75:E0:CF:8D:C9:4E:FD:CB:63:0D:CF:40:A2:CD:D6:49:73:7D:56#015#012a=setup:actpass#015#012a=mid:0#015#012a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level#015#012a=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time#015#012a=extmap:3 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01#015#012a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:mid#015#012a=extmap:5 urn:ietf:params:rtp-hdrext:sdes:rtp-stream-id#015#012a=extmap:6 urn:ietf:params ...

rtpengine[31922]: [0cukd02a3alg80sgnnt7] ... :rtp-hdrext:sdes:repaired-rtp-stream-id#015#012a=sendrecv#015#012a=msid:PRsKRyqY6ZlONK5Yot1c3J3ARV2klnoY3rS6 559f7b72-d137-46a9-bc88-302ffeddfa57#015#012a=rtcp-mux#015#012a=rtpmap:111 opus/48000/2#015#012a=rtcp-fb:111 transport-cc#015#012a=fmtp:111 minptime=10;useinbandfec=1#015#012a=rtpmap:103 ISAC/16000#015#012a=rtpmap:104 ISAC/32000#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:106 CN/32000#015#012a=rtpmap:105 CN/16000#015#012a=rtpmap:13 CN/8000#015#012a=rtpmap:110 telephone-event/48000#015#012a=rtpmap:112 telephone-event/32000#015#012a=rt ...

rtpengine[31922]: [0cukd02a3alg80sgnnt7] ... pmap:113 telephone-event/16000#015#012a=rtpmap:126 telephone-event/8000#015#012a=ssrc:520167085 cname:xh5JFSrjRIxjWM1N#015#012a=ssrc:520167085 msid:PRsKRyqY6ZlONK5Yot1c3J3ARV2klnoY3rS6 559f7b72-d137-46a9-bc88-302ffeddfa57#015#012a=ssrc:520167085 mslabel:PRsKRyqY6ZlONK5Yot1c3J3ARV2klnoY3rS6#015#012a=ssrc:520167085 label:559f7b72-d137-46a9-bc88-302ffeddfa57#015#012", "codec-offer": "opus", "DTLS": "off", "ICE": "remove", "flags": [ "trust-address", "SDES-off" ], "replace": [ "origin", "session-connection" ], "transport-protocol": "R ...

rtpengine[31922]: [0cukd02a3alg80sgnnt7] ... TP/AVP", "rtcp-mux": [ "demux" ], "call-id": "0cukd02a3alg80sgnnt7", "via-branch": "z9hG4bK49943950", "received-from": [ "IP4", "[HOME_WIFI_IP]" ], "from-tag": "t6asnauh8j", "command": "offer" }

rtpengine[31922]: [0cukd02a3alg80sgnnt7] Creating new call

rtpengine[31922]: [0cukd02a3alg80sgnnt7] Opened ports 30000..30001 for media relay

rtpengine[31922]: [0cukd02a3alg80sgnnt7] Opened ports 30012..30013 for media relay

rtpengine[31922]: [0cukd02a3alg80sgnnt7] Replying to 'offer' from 127.0.0.1:40611

rtpengine[31922]: [0cukd02a3alg80sgnnt7] Response dump for 'offer' to 127.0.0.1:40611: { "sdp": "v=0#015#012o=- 4131318426602582682 2 IN IP4 [KAMAILIO_PUBLIC_IP]#15#012s=-#15#012t=0 0#015#012a=msid-semantic: WMS PRsKRyqY6ZlONK5Yot1c3J3ARV2klnoY3rS6#015#012m=audio 30000 RTP/AVP 111 103 104 9 0 8 106 105 13 110 112 113 126#015#012c=IN IP4 [KAMAILIO_PUBLIC_IP]#15#012a=msid:PRsKRyqY6ZlONK5Yot1c3J3ARV2klnoY3rS6 559f7b72-d137-46a9-bc88-302ffeddfa57#015#012a=rtpmap:111 opus/48000/2#015#012a=rtcp-fb:111 transport-cc#015#012a=fmtp:111 minptime=10;useinbandfec=1#015#012a=rtpmap:103 ISAC/16000#015#012a=rtpmap:104 ISAC/32000#015#012 ...

rtpengine[31922]: [0cukd02a3alg80sgnnt7] ... a=rtpmap:9 G722/8000#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:106 CN/32000#015#012a=rtpmap:105 CN/16000#015#012a=rtpmap:13 CN/8000#015#012a=rtpmap:110 telephone-event/48000#015#012a=rtpmap:112 telephone-event/32000#015#012a=rtpmap:113 telephone-event/16000#015#012a=rtpmap:126 telephone-event/8000#015#012a=ssrc:520167085 cname:xh5JFSrjRIxjWM1N#015#012a=ssrc:520167085 msid:PRsKRyqY6ZlONK5Yot1c3J3ARV2klnoY3rS6 559f7b72-d137-46a9-bc88-302ffeddfa57#015#012a=ssrc:520167085 mslabel:PRsKRyqY6ZlONK5Yot1c3J3ARV2klnoY3rS6#015#012a=ssrc:520167085 label: ...

rtpengine[31922]: [0cukd02a3alg80sgnnt7] ... 559f7b72-d137-46a9-bc88-302ffeddfa57#015#012a=sendrecv#015#012a=rtcp:30001#015#012", "result": "ok" }

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] Received command 'offer' from 127.0.0.1:44938

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] Dump for 'offer' from 127.0.0.1:44938: { "sdp": "v=0#015#012o=- 1591671912 1591671912 IN IP4 [ASTERISK_PRIVATE_IP]#15#012s=Asterisk#015#012c=IN IP4 [ASTERISK_PRIVATE_IP]#15#012t=0 0#015#012m=audio 19404 RTP/AVP 107 0 8 3 9 101#015#012a=rtpmap:107 opus/48000/2#015#012a=fmtp:107 useinbandfec=1#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:3 GSM/8000#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=ptime:20#015#012a=maxptime:20#015#012a=sendrecv#015#012", "replace": [ "origin", "session-connection" ], "call-id": "f3c5aac4-a630-4b82 ...

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] ... -8d76-6efd816e3127", "via-branch": "z9hG4bKPj80e44a12-c8a7-4f66-a15b-913af17a40540", "received-from": [ "IP4", "[ASTERISK_PRIVATE_IP]" ], "from-tag": "d624dd29-c97f-46a6-af1b-186a9785b076", "command": "offer" }

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] Creating new call

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] Opened ports 30026..30027 for media relay

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] Opened ports 30040..30041 for media relay

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] Replying to 'offer' from 127.0.0.1:44938

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] Response dump for 'offer' to 127.0.0.1:44938: { "sdp": "v=0#015#012o=- 1591671912 1591671912 IN IP4 [KAMAILIO_PUBLIC_IP]#15#012s=Asterisk#015#012c=IN IP4 [KAMAILIO_PUBLIC_IP]#15#012t=0 0#015#012m=audio 30026 RTP/AVP 107 0 8 3 9 101#015#012a=rtpmap:107 opus/48000/2#015#012a=fmtp:107 useinbandfec=1#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:3 GSM/8000#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=ptime:20#015#012a=maxptime:20#015#012a=sendrecv#015#012a=rtcp:30027#015#012a=ice-ufrag:QV0hErfH#015#012a=ice-pwd:11x8eJ8jzbA9Ai0WOWEEkNt9Gu#015#012a ...

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] ... =candidate:PwrmTTF5dLnqiVQ4 1 UDP 2130706431 [KAMAILIO_PUBLIC_IP] 30026 typ host#015#012a=candidate:PwrmTTF5dLnqiVQ4 2 UDP 2130706430 [KAMAILIO_PUBLIC_IP] 30027 typ host#015#012", "result": "ok" }

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] Received command 'answer' from 127.0.0.1:48718

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] Dump for 'answer' from 127.0.0.1:48718: { "sdp": "v=0#015#012o=- 152687901396954277 152687901396954278 IN IP4 [HOME_SIP_DEVICE_LOCAL_IP]#15#012s=-#15#012c=IN IP4 [HOME_SIP_DEVICE_LOCAL_IP]#15#012t=0 0#015#012a=sendrecv#015#012m=audio 18000 RTP/AVP 0 8 9 101#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=ptime:20#015#012a=sendrecv#015#012", "replace": [ "origin", "session-connection" ], "call-id": "f3c5aac4-a630-4b82-8d76-6efd816e3127", "via-branch": "z9hG4bKPj80e44a12-c8a7-4f66-a15b-913af17a405 ...

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] ... 40", "received-from": [ "IP4", "[HOME_WIFI_IP]" ], "from-tag": "d624dd29-c97f-46a6-af1b-186a9785b076", "to-tag": "1195654424", "command": "answer" }

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] Shutting down ICE agent (nothing to do)

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] Replying to 'answer' from 127.0.0.1:48718

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] Response dump for 'answer' to 127.0.0.1:48718: { "sdp": "v=0#015#012o=- 152687901396954277 152687901396954278 IN IP4 [KAMAILIO_PUBLIC_IP]#15#012s=-#15#012c=IN IP4 [KAMAILIO_PUBLIC_IP]#15#012t=0 0#015#012m=audio 30040 RTP/AVP 0 8 9 101#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=ptime:20#015#012a=sendrecv#015#012a=rtcp:30041#015#012a=candidate:PwrmTTF5dLnqiVQ4 1 UDP 2130706431 [KAMAILIO_PUBLIC_IP] 30040 typ host#015#012a=candidate:PwrmTTF5dLnqiVQ4 2 UDP 2130706430 [KAMAILIO_PUBLIC_IP] 30041 typ ...

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] ... host#015#012", "result": "ok" }

/usr/local/sbin/kamailio[28325]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588439975;method=INVITE;from_tag=d624dd29-c97f-46a6-af1b-186a9785b076;to_tag=1195654424;call_id=f3c5aac4-a630-4b82-8d76-6efd816e3127;code=200;reason=OK;src_user=user4;src_domain=[ASTERISK_PUBLIC_IP];src_ip=[ASTERISK_PRIVATE_IP];dst_ouser=user1;dst_user=user1;dst_domain=[HOME_SIP_DEVICE_LOCAL_IP]

rtpengine[31922]: [0cukd02a3alg80sgnnt7] Received command 'answer' from 127.0.0.1:56759

rtpengine[31922]: [0cukd02a3alg80sgnnt7] Dump for 'answer' from 127.0.0.1:56759: { "sdp": "v=0#015#012o=- 1739338394 4 IN IP4 [ASTERISK_PRIVATE_IP]#15#012s=Asterisk#015#012c=IN IP4 [ASTERISK_PRIVATE_IP]#15#012t=0 0#015#012m=audio 28414 RTP/AVP 111 0 8 9 126#015#012a=rtpmap:111 opus/48000/2#015#012a=fmtp:111 useinbandfec=1#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:126 telephone-event/8000#015#012a=fmtp:126 0-16#015#012a=ptime:20#015#012a=maxptime:20#015#012a=sendrecv#015#012", "codec-offer": "opus", "DTLS": "passive", "ICE": "force", "flags": [ "SDES-off" ], "replace": [ "origin", "s ...

rtpengine[31922]: [0cukd02a3alg80sgnnt7] ... ession-connection" ], "transport-protocol": "RTP/SAVPF", "rtcp-mux": [ "offer" ], "call-id": "0cukd02a3alg80sgnnt7", "via-branch": "z9hG4bK49943950", "received-from": [ "IP4", "[ASTERISK_PRIVATE_IP]" ], "from-tag": "t6asnauh8j", "to-tag": "529600f7-2e1e-40b5-a687-bb27e7c15381", "command": "answer" }

rtpengine[31922]: [0cukd02a3alg80sgnnt7] Shutting down ICE agent (nothing to do)

rtpengine[31922]: [0cukd02a3alg80sgnnt7] Replying to 'answer' from 127.0.0.1:56759

rtpengine[31922]: [0cukd02a3alg80sgnnt7] Response dump for 'answer' to 127.0.0.1:56759: { "sdp": "v=0#015#012o=- 1739338394 4 IN IP4 [KAMAILIO_PUBLIC_IP]#15#012s=Asterisk#015#012c=IN IP4 [KAMAILIO_PUBLIC_IP]#15#012t=0 0#015#012m=audio 30012 RTP/SAVPF 111 0 8 9 126#015#012a=rtpmap:111 opus/48000/2#015#012a=fmtp:111 useinbandfec=1#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:126 telephone-event/8000#015#012a=fmtp:126 0-16#015#012a=ptime:20#015#012a=maxptime:20#015#012a=sendrecv#015#012a=rtcp:30012#015#012a=rtcp-mux#015#012a=setup:passive#015#012a=fingerprint:sha-1 C2:10:D7:B8:88:8D:8B:B8:5A:C3:FE:54:12:C3 ...

rtpengine[31922]: [0cukd02a3alg80sgnnt7] ... :A9:B3:E2:25:A4:4D#015#012a=ice-ufrag:qkvoYqP9#015#012a=ice-pwd:sKt03CMS6de06R5hArHTmyVKSq#015#012a=candidate:PwrmTTF5dLnqiVQ4 1 UDP 2130706431 [KAMAILIO_PUBLIC_IP] 30012 typ host#015#012", "result": "ok" }

/usr/local/sbin/kamailio[28338]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588439975;method=INVITE;from_tag=t6asnauh8j;to_tag=529600f7-2e1e-40b5-a687-bb27e7c15381;call_id=0cukd02a3alg80sgnnt7;code=200;reason=OK;src_user=user4;src_domain=sip.mydomain.com;src_ip=[HOME_WIFI_IP];dst_ouser=451005;dst_user=1005;dst_domain=sip.mydomain.com

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30000] SRTP output wanted, but no crypto suite was negotiated

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Unknown STUN attribute: 0xc057

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Created candidate pair PwrmTTF5dLnqiVQ4:00ffff000038b0424f31:1 between [KAMAILIO_PUBLIC_IP] and [HOME_WIFI_IP]:46138, type prflx

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Triggering check for PwrmTTF5dLnqiVQ4:00ffff000038b0424f31:1

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] ICE pair PwrmTTF5dLnqiVQ4:00ffff000038b0424f31:1 has been nominated by peer

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] ICE not completed yet

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Successful STUN binding request from [HOME_WIFI_IP]:46138

rtpengine[31922]: [0cukd02a3alg80sgnnt7/t6asnauh8j/1] Sending ICE/STUN request for candidate pair PwrmTTF5dLnqiVQ4:00ffff000038b0424f31:1 from [KAMAILIO_PUBLIC_IP] to [HOME_WIFI_IP]:46138

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Received ICE/STUN response code 0 for candidate pair PwrmTTF5dLnqiVQ4:00ffff000038b0424f31:1 from [HOME_WIFI_IP]:46138 to [KAMAILIO_PUBLIC_IP]

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Setting ICE candidate pair PwrmTTF5dLnqiVQ4:00ffff000038b0424f31:1 as succeeded

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Best succeeded ICE pair with all components is PwrmTTF5dLnqiVQ4:00ffff000038b0424f31:1

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] ICE completed, using pair PwrmTTF5dLnqiVQ4:00ffff000038b0424f31:1

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] ICE negotiated: peer for component 1 is [HOME_WIFI_IP]:46138

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] DTLS: Peer certificate accepted

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] DTLS handshake successful

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] DTLS-SRTP successfully negotiated

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] SRTP keys, incoming:

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] --- AES_CM_128_HMAC_SHA1_80 key /2aJ89KFwp+Eu7K6uhLptA== salt Wdhm2ibZ7JpIIepA1Ck=

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] SRTP keys, outgoing:

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] --- AES_CM_128_HMAC_SHA1_80 key GtN+Qk9hz4iS8tYEmfx1EQ== salt u1ARSI9tQHCMK/JgM68=

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] DTLS-SRTP successfully negotiated

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] SRTP keys, incoming:

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] --- AES_CM_128_HMAC_SHA1_80 key /2aJ89KFwp+Eu7K6uhLptA== salt Wdhm2ibZ7JpIIepA1Ck=

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] SRTP keys, outgoing:

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] --- AES_CM_128_HMAC_SHA1_80 key GtN+Qk9hz4iS8tYEmfx1EQ== salt u1ARSI9tQHCMK/JgM68=

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Unknown STUN attribute: 0xc057

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Successful STUN binding request from [HOME_WIFI_IP]:46138

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Unknown STUN attribute: 0xc057

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Successful STUN binding request from [HOME_WIFI_IP]:46138

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Unknown STUN attribute: 0xc057

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Successful STUN binding request from [HOME_WIFI_IP]:46138

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Unknown STUN attribute: 0xc057

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Successful STUN binding request from [HOME_WIFI_IP]:46138

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30000] Confirmed peer address as [ASTERISK_PUBLIC_IP]:28414

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127 port 30026] Confirmed peer address as [HOME_WIFI_IP]:51920

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Confirmed peer address as [HOME_WIFI_IP]:46138

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127 port 30040] Confirmed peer address as [ASTERISK_PUBLIC_IP]:19404

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Unknown STUN attribute: 0xc057

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30012] Successful STUN binding request from [HOME_WIFI_IP]:46138

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127 port 30041] Confirmed peer address as [ASTERISK_PUBLIC_IP]:19405

rtpengine[31922]: [0cukd02a3alg80sgnnt7 port 30001] Confirmed peer address as [ASTERISK_PUBLIC_IP]:28415

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127 port 30027] Confirmed peer address as [HOME_WIFI_IP]:51921

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] Received command 'delete' from 127.0.0.1:53558

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] Dump for 'delete' from 127.0.0.1:53558: { "call-id": "f3c5aac4-a630-4b82-8d76-6efd816e3127", "received-from": [ "IP4", "[HOME_WIFI_IP]" ], "from-tag": "1195654424", "command": "delete" }

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] Scheduling deletion of call branch '1195654424' in 30 seconds

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] Replying to 'delete' from 127.0.0.1:53558

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] Response dump for 'delete' to 127.0.0.1:53558: { "created": 1588439972, "last signal": 1588439975, "tags": { "1195654424": { "tag": "1195654424", "via-branch": "z9hG4bKPj80e44a12-c8a7-4f66-a15b-913af17a40540", "created": 1588439972, "in dialogue with": "d624dd29-c97f-46a6-af1b-186a9785b076", "medias": [ { "index": 1, "type": "audio", "protocol": "RTP/AVP", "streams": [ { "local port": 30026, "endpoint": { "family": "IPv4", "address": "[HOME_WIFI_IP]", "port": 51920 }, "advertised endpoint": { "fam ...

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] ... ily": "IPv4", "address": "[HOME_SIP_DEVICE_LOCAL_IP]", "port": 18000 }, "last packet": 1588439980, "flags": [ "RTP", "filled", "confirmed", "kernelized", "no kernel support" ], "stats": { "packets": 274, "bytes": 47128, "errors": 0 } }, { "local port": 30027, "endpoint": { "family": "IPv4", "address": "[HOME_WIFI_IP]", "port": 51921 }, "advertised endpoint": { "family": "IPv4", "address": "[HOME_SIP_DEVICE_LOCAL_IP]", "port": 18001 }, "last packet": 1588439980, "flags": [ "RTCP", "filled", "confirmed", "kernelized", "no kern ...

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] ... el support" ], "stats": { "packets": 2, "bytes": 108, "errors": 0 } } ], "flags": [ "initialized", "send", "recv" ] } ] }, "d624dd29-c97f-46a6-af1b-186a9785b076": { "tag": "d624dd29-c97f-46a6-af1b-186a9785b076", "created": 1588439972, "in dialogue with": "1195654424", "medias": [ { "index": 1, "type": "audio", "protocol": "RTP/AVP", "streams": [ { "local port": 30040, "endpoint": { "family": "IPv4", "address": "[ASTERISK_PUBLIC_IP]", "port": 19404 }, "advertised endpoint": { "family": "IPv4", "address ...

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] ... ": "[ASTERISK_PRIVATE_IP]", "port": 19404 }, "last packet": 1588439980, "flags": [ "RTP", "filled", "confirmed", "kernelized", "no kernel support" ], "stats": { "packets": 270, "bytes": 46440, "errors": 0 } }, { "local port": 30041, "endpoint": { "family": "IPv4", "address": "[ASTERISK_PUBLIC_IP]", "port": 19405 }, "advertised endpoint": { "family": "IPv4", "address": "[ASTERISK_PRIVATE_IP]", "port": 19405 }, "last packet": 1588439980, "flags": [ "RTCP", "filled", "confirmed" ], "stats": { "packets": 1, "bytes": ...

rtpengine[31922]: [f3c5aac4-a630-4b82-8d76-6efd816e3127] ... 64, "errors": 0 } } ], "flags": [ "initialized", "send", "recv" ] } ] } }, "totals": { "RTP": { "packets": 544, "bytes": 93568, "errors": 0 }, "RTCP": { "packets": 3, "bytes": 172, "errors": 0 } }, "result": "ok" }
/usr/local/sbin/kamailio[28339]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588439980;method=BYE;from_tag=1195654424;to_tag=d624dd29-c97f-46a6-af1b-186a9785b076;call_id=f3c5aac4-a630-4b82-8d76-6efd816e3127;code=200;reason=OK;src_user=user1;src_domain=sip.mydomain.com;src_ip=[HOME_WIFI_IP];dst_ouser=user4;dst_user=asterisk;dst_domain=[ASTERISK_PRIVATE_IP]

rtpengine[31922]: [0cukd02a3alg80sgnnt7] Received command 'delete' from 127.0.0.1:44938

rtpengine[31922]: [0cukd02a3alg80sgnnt7] Dump for 'delete' from 127.0.0.1:44938: { "codec-offer": "opus", "DTLS": "passive", "ICE": "force", "transport-protocol": "RTP/SAVPF", "call-id": "0cukd02a3alg80sgnnt7", "received-from": [ "IP4", "[ASTERISK_PRIVATE_IP]" ], "from-tag": "529600f7-2e1e-40b5-a687-bb27e7c15381", "command": "delete" }

rtpengine[31922]: [0cukd02a3alg80sgnnt7] Scheduling deletion of call branch '529600f7-2e1e-40b5-a687-bb27e7c15381' in 30 seconds

rtpengine[31922]: [0cukd02a3alg80sgnnt7] Replying to 'delete' from 127.0.0.1:44938

rtpengine[31922]: [0cukd02a3alg80sgnnt7] Response dump for 'delete' to 127.0.0.1:44938: { "created": 1588439972, "last signal": 1588439975, "tags": { "529600f7-2e1e-40b5-a687-bb27e7c15381": { "tag": "529600f7-2e1e-40b5-a687-bb27e7c15381", "via-branch": "z9hG4bK49943950", "created": 1588439972, "in dialogue with": "t6asnauh8j", "medias": [ { "index": 1, "type": "audio", "protocol": "RTP/AVP", "streams": [ { "local port": 30000, "endpoint": { "family": "IPv4", "address": "[ASTERISK_PUBLIC_IP]", "port": 28414 }, "advertised endpoint": { "family ...

rtpengine[31922]: [0cukd02a3alg80sgnnt7] ... ": "IPv4", "address": "[ASTERISK_PRIVATE_IP]", "port": 28414 }, "last packet": 1588439980, "flags": [ "RTP", "filled", "confirmed", "kernelized", "no kernel support" ], "stats": { "packets": 274, "bytes": 40359, "errors": 0 } }, { "local port": 30001, "endpoint": { "family": "IPv4", "address": "[ASTERISK_PUBLIC_IP]", "port": 28415 }, "advertised endpoint": { "family": "IPv4", "address": "[ASTERISK_PRIVATE_IP]", "port": 28415 }, "last packet": 1588439980, "flags": [ "RTCP", "filled", "confirmed", "kernelized", "no ...

rtpengine[31922]: [0cukd02a3alg80sgnnt7] ... kernel support" ], "stats": { "packets": 1, "bytes": 78, "errors": 0 } } ], "flags": [ "initialized", "send", "recv" ] } ] }, "t6asnauh8j": { "tag": "t6asnauh8j", "created": 1588439972, "in dialogue with": "529600f7-2e1e-40b5-a687-bb27e7c15381", "medias": [ { "index": 1, "type": "audio", "protocol": "RTP/SAVPF", "streams": [ { "local port": 30012, "endpoint": { "family": "IPv4", "address": "[HOME_WIFI_IP]", "port": 46138 }, "advertised endpoint": { "family": "IPv4", "address": "0.0.0.0", "port": ...

rtpengine[31922]: [0cukd02a3alg80sgnnt7] ... 9 }, "crypto suite": "AES_CM_128_HMAC_SHA1_80", "last packet": 1588439980, "flags": [ "RTP", "RTCP", "filled", "confirmed", "kernelized", "no kernel support", "DTLS fingerprint verified" ], "stats": { "packets": 272, "bytes": 20005, "errors": 0 } }, { "local port": 30013, "endpoint": { "family": "IPv6", "address": "::", "port": 0 }, "advertised endpoint": { "family": "IPv6", "address": "::", "port": 0 }, "crypto suite": "AES_CM_128_HMAC_SHA1_80", "last packet": 1588439972, "flags": [ "RTCP", "fa ...

rtpengine[31922]: [0cukd02a3alg80sgnnt7] ... llback RTCP", "filled" ], "stats": { "packets": 0, "bytes": 0, "errors": 0 } } ], "flags": [ "initialized", "send", "recv", "rtcp-mux", "DTLS-SRTP", "DTLS role passive", "ICE" ] } ] } }, "totals": { "RTP": { "packets": 546, "bytes": 60364, "errors": 0 }, "RTCP": { "packets": 1, "bytes": 78, "errors": 0 } }, "result": "ok" }

/usr/local/sbin/kamailio[28341]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588439980;method=BYE;from_tag=529600f7-2e1e-40b5-a687-bb27e7c15381;to_tag=t6asnauh8j;call_id=0cukd02a3alg80sgnnt7;code=200;reason=OK;src_user=451005;src_domain=sip.mydomain.com;src_ip=[ASTERISK_PRIVATE_IP];dst_ouser=user4;dst_user=6voj2k4q;dst_domain=kq89fj3k07eh.invalid`

Unsuccessful Call (no audio)

`rtpengine[25407]: Adding a proxy for control ng stats:127.0.0.1

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Received command 'offer' from 127.0.0.1:39835

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Dump for 'offer' from 127.0.0.1:39835: { "sdp": "v=0#015#012o=- 3797355275 3797355275 IN IP4 192.168.0.43#015#012s=pjmedia#015#012c=IN IP4 192.168.0.43#015#012t=0 0#015#012m=audio 4000 RTP/AVP 99 0 8 3 101#015#012c=IN IP4 192.168.0.43#015#012a=rtcp:4001 IN IP4 192.168.0.43#015#012a=sendrecv#015#012a=rtpmap:99 SILK/24000#015#012a=fmtp:99 useinbandfec=0#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:3 GSM/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012", "replace": [ "origin", "session-connection" ], "call-id": "roz5al5-jvB-kHa5INi3WlnsBV ...

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] ... Lo0wjy", "via-branch": "z9hG4bKPjbn-XJQwRPMMwBuvXokl7iQKqGLvQ2isr0", "received-from": [ "IP4", "[HOME_PUBLIC_IP]" ], "from-tag": "CZGMPY-xmZMGG3xl2DbfErzdtaV9y.dU", "command": "offer" }

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Creating new call

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Opened ports 30000..30001 for media relay

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Opened ports 30016..30017 for media relay

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Replying to 'offer' from 127.0.0.1:39835

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Response dump for 'offer' to 127.0.0.1:39835: { "sdp": "v=0#015#012o=- 3797355275 3797355275 IN IP4 [KAMAILIO_PUBLIC_IP]#15#012s=pjmedia#015#012c=IN IP4 [KAMAILIO_PUBLIC_IP]#15#012t=0 0#015#012m=audio 30000 RTP/AVP 99 0 8 3 101#015#012c=IN IP4 [KAMAILIO_PUBLIC_IP]#15#012a=rtpmap:99 SILK/24000#015#012a=fmtp:99 useinbandfec=0#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:3 GSM/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=sendrecv#015#012a=rtcp:30001#015#012a=ice-ufrag:vaeby7lB#015#012a=ice-pwd:zfptqrFZsItr4nxEM60yvGCZOR#015#012a=candidate:z35w1mU6zpAmOpH4 1 UD ...

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] ... P 2130706431 [KAMAILIO_PUBLIC_IP] 30000 typ host#015#012a=candidate:z35w1mU6zpAmOpH4 2 UDP 2130706430 [KAMAILIO_PUBLIC_IP] 30001 typ host#015#012", "result": "ok" }

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] Received command 'offer' from 127.0.0.1:45406

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] Dump for 'offer' from 127.0.0.1:45406: { "sdp": "v=0#015#012o=- 424009316 424009316 IN IP4 [ASTERISK_PRIVATE_IP]#15#012s=Asterisk#015#012c=IN IP4 [ASTERISK_PRIVATE_IP]#15#012t=0 0#015#012m=audio 32626 RTP/AVP 107 0 8 3 9 101#015#012a=rtpmap:107 opus/48000/2#015#012a=fmtp:107 useinbandfec=1#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:3 GSM/8000#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=ptime:20#015#012a=maxptime:20#015#012a=sendrecv#015#012", "codec-offer": "opus", "DTLS": "passive", "ICE": "force", "flags": [ "SDES-off" ...

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] ... ], "replace": [ "origin", "session-connection" ], "transport-protocol": "RTP/SAVPF", "rtcp-mux": [ "offer" ], "call-id": "bddf771e-8f40-4f2d-a088-ccbb86e81766", "via-branch": "z9hG4bKPj7e59468d-bafe-4541-8090-cb2b50fd3fea0", "received-from": [ "IP4", "[ASTERISK_PRIVATE_IP]" ], "from-tag": "9a58f0b6-2987-4f61-ab9f-796bbc91b5dc", "command": "offer" }

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] Creating new call

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] Opened ports 30028..30029 for media relay

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] Opened ports 30048..30049 for media relay

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] Replying to 'offer' from 127.0.0.1:45406

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] Response dump for 'offer' to 127.0.0.1:45406: { "sdp": "v=0#015#012o=- 424009316 424009316 IN IP4 [KAMAILIO_PUBLIC_IP]#15#012s=Asterisk#015#012c=IN IP4 [KAMAILIO_PUBLIC_IP]#15#012t=0 0#015#012m=audio 30028 RTP/SAVPF 107 0 8 3 9 101#015#012a=rtpmap:107 opus/48000/2#015#012a=fmtp:107 useinbandfec=1#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:3 GSM/8000#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=ptime:20#015#012a=maxptime:20#015#012a=sendrecv#015#012a=rtcp:30029#015#012a=rtcp-mux#015#012a=setup:actpass#015#012a=fingerprint:sha-1 4F:0D:2E:1E: ...

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] ... 02:00:99:43:E4:6C:3B:2E:5E:66:22:D9:D4:36:18:B4#015#012a=ice-ufrag:WvVtIiW6#015#012a=ice-pwd:HA58iwzlU7ZEbXdGBNFnCOHzhB#015#012a=candidate:z35w1mU6zpAmOpH4 1 UDP 2130706431 [KAMAILIO_PUBLIC_IP] 30028 typ host#015#012a=candidate:z35w1mU6zpAmOpH4 2 UDP 2130706430 [KAMAILIO_PUBLIC_IP] 30029 typ host#015#012", "result": "ok" }

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Unknown STUN attribute: 0xc057

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Created candidate pair z35w1mU6zpAmOpH4:00ffff000038b0424f31:1 between [KAMAILIO_PUBLIC_IP] and [HOME_PUBLIC_IP]:36069, type prflx

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Triggering check for z35w1mU6zpAmOpH4:00ffff000038b0424f31:1

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Successful STUN binding request from [HOME_PUBLIC_IP]:36069

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] Received command 'answer' from 127.0.0.1:44298

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] Dump for 'answer' from 127.0.0.1:44298: { "sdp": "v=0#015#012o=- 569447330679785565 2 IN IP4 127.0.0.1#015#012s=-#15#012t=0 0#015#012a=msid-semantic: WMS APsyNpd2bZeVyz7QHrQ92hj8uvag9j24mDS8#015#012m=audio 9 RTP/SAVPF 107 0 8 9 101#015#012c=IN IP4 0.0.0.0#015#012a=rtcp:9 IN IP4 0.0.0.0#015#012a=candidate:2993348229 1 udp 2113937151 c3d14e13-6148-4c1b-91dd-ad09088dd88e.local 33701 typ host generation 0 network-cost 999#015#012a=ice-ufrag:IdUX#015#012a=ice-pwd:SJZowqxd6skxzXzU1iDmizKf#015#012a=ice-options:trickle#015#012a=fingerprint:sha-256 05:AB:1F:DA:9B:DF:4C:83:B ...

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] ... 7:C8:20:F9:AB:7E:9D:89:64:CC:CB:32:8A:23:8B:44:9B:98:6C:A7:0C:6D:52:C5#015#012a=setup:active#015#012a=mid:0#015#012a=sendrecv#015#012a=msid:APsyNpd2bZeVyz7QHrQ92hj8uvag9j24mDS8 27e5f690-5804-44ba-9444-a48f9ba2f3d2#015#012a=rtcp-mux#015#012a=rtpmap:107 opus/48000/2#015#012a=fmtp:107 minptime=10;useinbandfec=1#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=ssrc:2015014729 cname:DjWMNYGfBIufVWRG#015#012a=ssrc:2015014729 msid:APsyNpd2bZeVyz7QHrQ92hj8uvag9j24mDS8 27e5f690-5804-44ba-9444-a48f ...

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] ... 9ba2f3d2#015#012a=ssrc:2015014729 mslabel:APsyNpd2bZeVyz7QHrQ92hj8uvag9j24mDS8#015#012a=ssrc:2015014729 label:27e5f690-5804-44ba-9444-a48f9ba2f3d2#015#012", "codec-offer": "opus", "DTLS": "off", "ICE": "remove", "flags": [ "trust-address", "SDES-off" ], "replace": [ "origin", "session-connection" ], "transport-protocol": "RTP/AVP", "rtcp-mux": [ "demux" ], "call-id": "bddf771e-8f40-4f2d-a088-ccbb86e81766", "via-branch": "z9hG4bKPj7e59468d-bafe-4541-8090-cb2b50fd3fea0", "received-from": [ "IP4", "[HOME_PUBLIC_IP]" ], ...

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] ... "from-tag": "9a58f0b6-2987-4f61-ab9f-796bbc91b5dc", "to-tag": "spmrgb7imc", "command": "answer" }

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] Shutting down ICE agent (nothing to do)

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] Replying to 'answer' from 127.0.0.1:44298

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] Response dump for 'answer' to 127.0.0.1:44298: { "sdp": "v=0#015#012o=- 569447330679785565 2 IN IP4 [KAMAILIO_PUBLIC_IP]#15#012s=-#15#012t=0 0#015#012a=msid-semantic: WMS APsyNpd2bZeVyz7QHrQ92hj8uvag9j24mDS8#015#012m=audio 30048 RTP/AVP 107 0 8 9 101#015#012c=IN IP4 [KAMAILIO_PUBLIC_IP]#15#012a=mid:0#015#012a=msid:APsyNpd2bZeVyz7QHrQ92hj8uvag9j24mDS8 27e5f690-5804-44ba-9444-a48f9ba2f3d2#015#012a=rtpmap:107 opus/48000/2#015#012a=fmtp:107 minptime=10;useinbandfec=1#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:101 telephone-event/8000#015 ...

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] ... #012a=ssrc:2015014729 cname:DjWMNYGfBIufVWRG#015#012a=ssrc:2015014729 msid:APsyNpd2bZeVyz7QHrQ92hj8uvag9j24mDS8 27e5f690-5804-44ba-9444-a48f9ba2f3d2#015#012a=ssrc:2015014729 mslabel:APsyNpd2bZeVyz7QHrQ92hj8uvag9j24mDS8#015#012a=ssrc:2015014729 label:27e5f690-5804-44ba-9444-a48f9ba2f3d2#015#012a=sendrecv#015#012a=rtcp:30049#015#012", "result": "ok" }
/usr/local/sbin/kamailio[20454]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588366479;method=INVITE;from_tag=9a58f0b6-2987-4f61-ab9f-796bbc91b5dc;to_tag=spmrgb7imc;call_id=bddf771e-8f40-4f2d-a088-ccbb86e81766;code=200;reason=OK;src_user=user1;src_domain=[ASTERISK_PUBLIC_IP];src_ip=[ASTERISK_PRIVATE_IP];dst_ouser=user4;dst_user=g17j94jl;dst_domain=d81svquri41a.invalid

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Received command 'answer' from 127.0.0.1:57036

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Dump for 'answer' from 127.0.0.1:57036: { "sdp": "v=0#015#012o=- 3797355275 3797355277 IN IP4 [ASTERISK_PRIVATE_IP]#15#012s=Asterisk#015#012c=IN IP4 [ASTERISK_PRIVATE_IP]#15#012t=0 0#015#012m=audio 18926 RTP/AVP 0 8 3 101#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:3 GSM/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=ptime:20#015#012a=maxptime:150#015#012a=sendrecv#015#012", "replace": [ "origin", "session-connection" ], "call-id": "roz5al5-jvB-kHa5INi3WlnsBVLo0wjy", "via-branch": "z9hG4bKPjbn-XJQwRPMMwBuvXokl7iQKqGLvQ2isr0", "re ...
rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] ... ceived-from": [ "IP4", "[ASTERISK_PRIVATE_IP]" ], "from-tag": "CZGMPY-xmZMGG3xl2DbfErzdtaV9y.dU", "to-tag": "6dfe0a44-1d88-4d09-a012-336a5b2149bc", "command": "answer" }
rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Shutting down ICE agent (nothing to do)

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Replying to 'answer' from 127.0.0.1:57036

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Response dump for 'answer' to 127.0.0.1:57036: { "sdp": "v=0#015#012o=- 3797355275 3797355277 IN IP4 [KAMAILIO_PUBLIC_IP]#15#012s=Asterisk#015#012c=IN IP4 [KAMAILIO_PUBLIC_IP]#15#012t=0 0#015#012m=audio 30016 RTP/AVP 0 8 3 101#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:3 GSM/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=ptime:20#015#012a=maxptime:150#015#012a=sendrecv#015#012a=rtcp:30017#015#012a=candidate:z35w1mU6zpAmOpH4 1 UDP 2130706431 [KAMAILIO_PUBLIC_IP] 30016 typ host#015#012a=candidate:z35w1mU6zpAmOpH4 2 UDP 2130706430 [KAMAILIO_PUBLIC_IP] 300 ...

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] ... 17 typ host#015#012", "result": "ok" }
/usr/local/sbin/kamailio[20453]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588366479;method=INVITE;from_tag=CZGMPY-xmZMGG3xl2DbfErzdtaV9y.dU;to_tag=6dfe0a44-1d88-4d09-a012-336a5b2149bc;call_id=roz5al5-jvB-kHa5INi3WlnsBVLo0wjy;code=200;reason=OK;src_user=user1;src_domain=sip.mydomain.com;src_ip=[HOME_PUBLIC_IP];dst_ouser=451004;dst_user=1004;dst_domain=sip.mydomain.com
rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Unknown STUN attribute: 0xc057

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Triggering check for z35w1mU6zpAmOpH4:00ffff000038b0424f31:1

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Successful STUN binding request from [HOME_PUBLIC_IP]:36069

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766/spmrgb7imc/1] Sending ICE/STUN request for candidate pair z35w1mU6zpAmOpH4:00ffff000038b0424f31:1 from [KAMAILIO_PUBLIC_IP] to [HOME_PUBLIC_IP]:36069

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Received ICE/STUN response code 0 for candidate pair z35w1mU6zpAmOpH4:00ffff000038b0424f31:1 from [HOME_PUBLIC_IP]:36069 to [KAMAILIO_PUBLIC_IP]

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Setting ICE candidate pair z35w1mU6zpAmOpH4:00ffff000038b0424f31:1 as succeeded

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Best succeeded ICE pair with all components is z35w1mU6zpAmOpH4:00ffff000038b0424f31:1

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30048] SRTP output wanted, but no crypto suite was negotiated

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Unknown STUN attribute: 0xc057

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Successful STUN binding request from [HOME_PUBLIC_IP]:36069

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766/spmrgb7imc/1] Start nominating ICE pairs

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766/spmrgb7imc/1] Nominating ICE pair z35w1mU6zpAmOpH4:00ffff000038b0424f31:1

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766/spmrgb7imc/1] Sending nominating ICE/STUN request for candidate pair z35w1mU6zpAmOpH4:00ffff000038b0424f31:1 from [KAMAILIO_PUBLIC_IP] to [HOME_PUBLIC_IP]:36069

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Received ICE/STUN response code 0 for candidate pair z35w1mU6zpAmOpH4:00ffff000038b0424f31:1 from [HOME_PUBLIC_IP]:36069 to [KAMAILIO_PUBLIC_IP]

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Setting nominated ICE candidate pair z35w1mU6zpAmOpH4:00ffff000038b0424f31:1 as valid

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] ICE completed, using pair z35w1mU6zpAmOpH4:00ffff000038b0424f31:1

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] ICE negotiated: peer for component 1 is [HOME_PUBLIC_IP]:36069

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Unknown STUN attribute: 0xc057

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Successful STUN binding request from [HOME_PUBLIC_IP]:36069

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy port 30016] Confirmed peer address as [HOME_PUBLIC_IP]:39520

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30048] Confirmed peer address as [ASTERISK_PUBLIC_IP]:32626

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy port 30001] Confirmed peer address as [ASTERISK_PUBLIC_IP]:18927

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Received command 'offer' from 127.0.0.1:46433

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Dump for 'offer' from 127.0.0.1:46433: { "sdp": "v=0#015#012o=- 3797355275 3797355276 IN IP4 192.168.0.43#015#012s=pjmedia#015#012c=IN IP4 192.168.0.43#015#012t=0 0#015#012m=audio 4000 RTP/AVP 0 101#015#012c=IN IP4 192.168.0.43#015#012a=rtcp:4001 IN IP4 192.168.0.43#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=sendrecv#015#012", "replace": [ "origin", "session-connection" ], "call-id": "roz5al5-jvB-kHa5INi3WlnsBVLo0wjy", "received-from": [ "IP4", "[HOME_PUBLIC_IP]" ], "from-tag": "CZGMPY-xmZMGG3xl2DbfErzdtaV9y.dU", ...

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] ... "to-tag": "6dfe0a44-1d88-4d09-a012-336a5b2149bc", "command": "offer" }

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Shutting down ICE agent (nothing to do)

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Replying to 'offer' from 127.0.0.1:46433

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Response dump for 'offer' to 127.0.0.1:46433: { "sdp": "v=0#015#012o=- 3797355275 3797355276 IN IP4 [KAMAILIO_PUBLIC_IP]#15#012s=pjmedia#015#012c=IN IP4 [KAMAILIO_PUBLIC_IP]#15#012t=0 0#015#012m=audio 30000 RTP/AVP 0 101#015#012c=IN IP4 [KAMAILIO_PUBLIC_IP]#15#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=sendrecv#015#012a=rtcp:30001#015#012a=candidate:z35w1mU6zpAmOpH4 1 UDP 2130706431 [KAMAILIO_PUBLIC_IP] 30000 typ host#015#012a=candidate:z35w1mU6zpAmOpH4 2 UDP 2130706430 [KAMAILIO_PUBLIC_IP] 30001 typ host#015#012", "result": "ok" }

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Received command 'answer' from 127.0.0.1:57036

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Dump for 'answer' from 127.0.0.1:57036: { "sdp": "v=0#015#012o=- 3797355275 3797355278 IN IP4 [ASTERISK_PRIVATE_IP]#15#012s=Asterisk#015#012c=IN IP4 [ASTERISK_PRIVATE_IP]#15#012t=0 0#015#012m=audio 18926 RTP/AVP 0 101#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=ptime:20#015#012a=maxptime:150#015#012a=sendrecv#015#012", "replace": [ "origin", "session-connection" ], "call-id": "roz5al5-jvB-kHa5INi3WlnsBVLo0wjy", "via-branch": "z9hG4bKPjvT0FRZpJ1SdpSztbYKv0gMTUEEkzQORz0", "received-from": [ "IP4", "[ASTERISK_PRIVATE_IP]" ], "fr ...

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] ... om-tag": "CZGMPY-xmZMGG3xl2DbfErzdtaV9y.dU", "to-tag": "6dfe0a44-1d88-4d09-a012-336a5b2149bc", "command": "answer" }

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Shutting down ICE agent (nothing to do)

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Replying to 'answer' from 127.0.0.1:57036

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Response dump for 'answer' to 127.0.0.1:57036: { "sdp": "v=0#015#012o=- 3797355275 3797355278 IN IP4 [KAMAILIO_PUBLIC_IP]#15#012s=Asterisk#015#012c=IN IP4 [KAMAILIO_PUBLIC_IP]#15#012t=0 0#015#012m=audio 30016 RTP/AVP 0 101#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=ptime:20#015#012a=maxptime:150#015#012a=sendrecv#015#012a=rtcp:30017#015#012a=candidate:z35w1mU6zpAmOpH4 1 UDP 2130706431 [KAMAILIO_PUBLIC_IP] 30016 typ host#015#012a=candidate:z35w1mU6zpAmOpH4 2 UDP 2130706430 [KAMAILIO_PUBLIC_IP] 30017 typ host#015#012", "result": "ok" }

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30049] SRTCP output wanted, but no crypto suite was negotiated

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30049] Confirmed peer address as [ASTERISK_PUBLIC_IP]:32627

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Received command 'delete' from 127.0.0.1:39835

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Dump for 'delete' from 127.0.0.1:39835: { "call-id": "roz5al5-jvB-kHa5INi3WlnsBVLo0wjy", "received-from": [ "IP4", "[HOME_PUBLIC_IP]" ], "from-tag": "CZGMPY-xmZMGG3xl2DbfErzdtaV9y.dU", "command": "delete" }

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Scheduling deletion of call branch 'CZGMPY-xmZMGG3xl2DbfErzdtaV9y.dU' in 30 seconds

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Replying to 'delete' from 127.0.0.1:39835

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] Response dump for 'delete' to 127.0.0.1:39835: { "created": 1588366476, "last signal": 1588366484, "tags": { "CZGMPY-xmZMGG3xl2DbfErzdtaV9y.dU": { "tag": "CZGMPY-xmZMGG3xl2DbfErzdtaV9y.dU", "created": 1588366476, "in dialogue with": "6dfe0a44-1d88-4d09-a012-336a5b2149bc", "medias": [ { "index": 1, "type": "audio", "protocol": "RTP/AVP", "streams": [ { "local port": 30016, "endpoint": { "family": "IPv4", "address": "[HOME_PUBLIC_IP]", "port": 39520 }, "advertised endpoint": { "family": "IPv4", "addre ...

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] ... ss": "192.168.0.43", "port": 4000 }, "last packet": 1588366485, "flags": [ "RTP", "filled" ], "stats": { "packets": 330, "bytes": 56680, "errors": 0 } }, { "local port": 30017, "endpoint": { "family": "IPv4", "address": "[HOME_PUBLIC_IP]", "port": 39521 }, "advertised endpoint": { "family": "IPv4", "address": "192.168.0.43", "port": 4001 }, "last packet": 1588366484, "flags": [ "RTCP", "filled" ], "stats": { "packets": 3, "bytes": 212, "errors": 0 } } ], "flags": [ "initialized", "send", "recv" ] } ...

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] ... ] }, "6dfe0a44-1d88-4d09-a012-336a5b2149bc": { "tag": "6dfe0a44-1d88-4d09-a012-336a5b2149bc", "via-branch": "z9hG4bKPjbn-XJQwRPMMwBuvXokl7iQKqGLvQ2isr0", "created": 1588366476, "in dialogue with": "CZGMPY-xmZMGG3xl2DbfErzdtaV9y.dU", "medias": [ { "index": 1, "type": "audio", "protocol": "RTP/AVP", "streams": [ { "local port": 30000, "endpoint": { "family": "IPv4", "address": "[ASTERISK_PRIVATE_IP]", "port": 18926 }, "advertised endpoint": { "family": "IPv4", "address": "[ASTERISK_PRIVATE_IP]", "port": 18926 ...

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] ... }, "last packet": 1588366476, "flags": [ "RTP", "filled" ], "stats": { "packets": 0, "bytes": 0, "errors": 0 } }, { "local port": 30001, "endpoint": { "family": "IPv4", "address": "[ASTERISK_PUBLIC_IP]", "port": 18927 }, "advertised endpoint": { "family": "IPv4", "address": "[ASTERISK_PRIVATE_IP]", "port": 18927 }, "last packet": 1588366484, "flags": [ "RTCP", "filled" ], "stats": { "packets": 1, "bytes": 44, "errors": 0 } } ], "flags": [ "initialized", "send", "recv" ] } ] } }, "totals": { "RTP": { "packe ...

rtpengine[25407]: [roz5al5-jvB-kHa5INi3WlnsBVLo0wjy] ... ts": 330, "bytes": 56680, "errors": 0 }, "RTCP": { "packets": 4, "bytes": 256, "errors": 0 } }, "result": "ok" }
45 /usr/local/sbin/kamailio[20453]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588366485;method=BYE;from_tag=CZGMPY-xmZMGG3xl2DbfErzdtaV9y.dU;to_tag=6dfe0a44-1d88-4d09-a012-336a5b2149bc;call_id=roz5al5-jvB-kHa5INi3WlnsBVLo0wjy;code=200;reason=OK;src_user=user1;src_domain=sip.mydomain.com;src_ip=[HOME_PUBLIC_IP];dst_ouser=451004;dst_user=;dst_domain=[ASTERISK_PRIVATE_IP]

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] Received command 'delete' from 127.0.0.1:45406

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] Dump for 'delete' from 127.0.0.1:45406: { "codec-offer": "opus", "DTLS": "passive", "ICE": "force", "transport-protocol": "RTP/SAVPF", "call-id": "bddf771e-8f40-4f2d-a088-ccbb86e81766", "received-from": [ "IP4", "[ASTERISK_PRIVATE_IP]" ], "from-tag": "9a58f0b6-2987-4f61-ab9f-796bbc91b5dc", "command": "delete" }

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] Scheduling deletion of call branch '9a58f0b6-2987-4f61-ab9f-796bbc91b5dc' in 30 seconds

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] Replying to 'delete' from 127.0.0.1:45406

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] Response dump for 'delete' to 127.0.0.1:45406: { "created": 1588366476, "last signal": 1588366479, "tags": { "9a58f0b6-2987-4f61-ab9f-796bbc91b5dc": { "tag": "9a58f0b6-2987-4f61-ab9f-796bbc91b5dc", "created": 1588366476, "in dialogue with": "spmrgb7imc", "medias": [ { "index": 1, "type": "audio", "protocol": "RTP/AVP", "streams": [ { "local port": 30048, "endpoint": { "family": "IPv4", "address": "[ASTERISK_PUBLIC_IP]", "port": 32626 }, "advertised endpoint": { "family": "IPv4", "address": "192.168.16 ...

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] ... 7.249", "port": 32626 }, "last packet": 1588366485, "flags": [ "RTP", "filled", "confirmed" ], "stats": { "packets": 329, "bytes": 26095, "errors": 0 } }, { "local port": 30049, "endpoint": { "family": "IPv4", "address": "[ASTERISK_PUBLIC_IP]", "port": 32627 }, "advertised endpoint": { "family": "IPv4", "address": "[ASTERISK_PRIVATE_IP]", "port": 32627 }, "last packet": 1588366484, "flags": [ "RTCP", "filled", "confirmed" ], "stats": { "packets": 1, "bytes": 40, "errors": 0 } } ], "flags": [ "initialized", ...

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] ... "send", "recv" ] } ] }, "spmrgb7imc": { "tag": "spmrgb7imc", "via-branch": "z9hG4bKPj7e59468d-bafe-4541-8090-cb2b50fd3fea0", "created": 1588366476, "in dialogue with": "9a58f0b6-2987-4f61-ab9f-796bbc91b5dc", "medias": [ { "index": 1, "type": "audio", "protocol": "RTP/SAVPF", "streams": [ { "local port": 30028, "endpoint": { "family": "IPv4", "address": "[HOME_PUBLIC_IP]", "port": 36069 }, "advertised endpoint": { "family": "IPv4", "address": "0.0.0.0", "port": 9 }, "last packet": 1588366479, "flags" ...

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] ... : [ "RTP", "RTCP", "filled" ], "stats": { "packets": 1, "bytes": 64, "errors": 0 } }, { "local port": 30029, "endpoint": { "family": "IPv6", "address": "::", "port": 0 }, "advertised endpoint": { "family": "IPv6", "address": "::", "port": 0 }, "last packet": 1588366476, "flags": [ "RTCP", "fallback RTCP", "filled" ], "stats": { "packets": 0, "bytes": 0, "errors": 0 } } ], "flags": [ "initialized", "send", "recv", "rtcp-mux", "DTLS-SRTP", "DTLS role passive", "ICE" ] } ] } }, "totals": { "RTP": { ...

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766] ... "packets": 330, "bytes": 26159, "errors": 0 }, "RTCP": { "packets": 1, "bytes": 40, "errors": 0 } }, "result": "ok" }

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Unknown STUN attribute: 0xc057

rtpengine[25407]: [bddf771e-8f40-4f2d-a088-ccbb86e81766 port 30028] Successful STUN binding request from [HOME_PUBLIC_IP]:36069`

@chiragd
Copy link
Author

chiragd commented May 2, 2020

In case it helps at all on the SIP -> WEBRTC call Kamailio shows this error:

ALERT: kam-xlog: In the location routing section

/usr/local/sbin/kamailio[5179]: INFO: kam-xlog: MANAGE_BRANCH: new branch [0] to sip:skk4t1tq@lim738jsupu9.invalid;transport=ws

/usr/local/sbin/kamailio[5179]: INFO: kam-xlog: NATMANAGE branch_id:0 ruri: sip:skk4t1tq@lim738jsupu9.invalid;transport=ws, method:INVITE, status:, extra_id: z9hG4bKPj348d439a-1d71-40fc-857c-04b533cfc6c90, rtpengine_manage: replace-origin replace-session-connection via-branch=extra codec-offer=opus rtcp-mux-offer DTLS=passive SDES-off ICE=force RTP/SAVPF

/usr/local/sbin/kamailio[5179]: WARNING: [msg_translator.c:2729]: via_builder(): TCP/TLS connection (id: 0) for WebSocket could not be found

/usr/local/sbin/kamailio[5179]: ERROR: [msg_translator.c:1947]: build_req_buf_from_sip_req(): could not create Via header

/usr/local/sbin/kamailio[5179]: ERROR: tm [t_fwd.c:461]: prepare_new_uac(): could not build request

@chiragd
Copy link
Author

chiragd commented May 4, 2020

If it makes any difference, I took asterisk out of the equation. But still have trouble getting audio for my sip to webrtc call.

@rfuchs
Copy link
Member

rfuchs commented May 5, 2020

So AFAICT what's missing in the non-working case is the DTLS negotiation. You're using DTLS=passive so that would leave DTLS up to the remote endpoint, which never seems to start DTLS. The only suggestions I have would be to try without DTLS=passive and/or try with UDP/TLS/RTP/SAVPF as protocol instead of just RTP/SAVPF

@chiragd
Copy link
Author

chiragd commented May 5, 2020

That didn't seem to help. I tried

DTLS=passive + RTP/SAVPF
DTLS=passive + UDP/TLS/RTP/SAVPF
RTP/SAVPF only

For DTLS=passive + UDP/TLS/RTP/SAVPF I get this error:
emit "peerconnection:setremotedescriptionfailed" [error:DOMException: Failed to execute 'setRemoteDescription' on 'RTCPeerConnection': Failed to set remote offer sdp: Called with SDP without DTLS fingerprint.] +0ms

@rfuchs
Copy link
Member

rfuchs commented May 5, 2020

Did you use transport-protocol=UDP/TLS/RTP/SAVPF ?

@chiragd
Copy link
Author

chiragd commented May 5, 2020 •
edited

yep - no luck :(

Here's my code, I just changed it back to RTP/SAVPF.

 if(isbflagset(FLB_RTPWS)){
                if ($proto =~ "ws") { # web --> SIP
                        xlog("L_INFO","NATMANAGE, FLB_RTPWS is set. Web -> SIP call. Removing DTLS and ICE. Decrypting Audio.");
                        xlog("L_INFO", "NATMANAGE: for method:$rm from FU:$fu to RU:$ru $rd  (IP:$si:$sp) UA:$ua \n");
                        $xavp(r=>$T_branch_idx) = $xavp(r=>$T_branch_idx) + " codec-transcode=opus codec-transcode=PCMU rtcp-mux-demux DTLS=off SDES-off ICE=remove RTP/AVP";
                } else { # SIP --> web
                        xlog("L_INFO","NATMANAGE, FLB_RTPWS is NOT set. SIP -> Web call. Adding DTLS and ICE. Encrypting Audio.");
                        xlog("L_INFO", "NATMANAGE: for method:$rm from FU:$fu to RU:$ru $rd  (IP:$si:$sp) UA:$ua \n");
                        $xavp(r=>$T_branch_idx) = $xavp(r=>$T_branch_idx) + " codec-transcode=opus codec-transcode=PCMU rtcp-mux-offer DTLS=passive SDES-off ICE=force transport-protocol=RTP/SAVPF";
                }
        } else {
                if ($proto =~ "ws") { # web --> web
                        xlog("L_INFO","NATMANAGE, FLB_RTPWS WAS FALSE, Web -> Web call. Encyrpting Audio");
                        xlog("L_INFO", "NATMANAGE: for method:$rm from FU:$fu to RU:$ru $rd  (IP:$si:$sp) UA:$ua \n");
                        $xavp(r=>$T_branch_idx) = $xavp(r=>$T_branch_idx) + " codec-transcode=opus codec-transcode=PCMU rtcp-mux-offer DTLS=passive SDES-off ICE=force transport-protocol=RTP/SAVPF";
                }

@rfuchs
Copy link
Member

rfuchs commented May 5, 2020

There shouldn't be an SDP without fingerprint when you use transport-protocol=UDP/TLS/RTP/SAVPF

Post a debug log from rtpengine

@juha-h
Copy link
Contributor

juha-h commented May 5, 2020 via email

@chiragd
Copy link
Author

chiragd commented May 5, 2020

@juha-h I know - just a comment to help me understand things in terms of my own architecture.

@rfuchs

if(isbflagset(FLB_RTPWS)){
                if ($proto =~ "ws") { # web --> SIP
                        xlog("L_INFO","NATMANAGE, FLB_RTPWS is set. Web -> SIP call. Removing DTLS and ICE. Decrypting Audio.");
                        xlog("L_INFO", "NATMANAGE: for method:$rm from FU:$fu to RU:$ru $rd  (IP:$si:$sp) UA:$ua \n");

                        $xavp(r=>$T_branch_idx) = $xavp(r=>$T_branch_idx) + " codec-transcode=opus codec-transcode=PCMU rtcp-mux-demux DTLS=off SDES-off ICE=remove RTP/AVP";
                } else { # SIP --> web
                        xlog("L_INFO","NATMANAGE, FLB_RTPWS is NOT set. SIP -> Web call. Adding DTLS and ICE. Encrypting Audio.");
                        xlog("L_INFO", "NATMANAGE: for method:$rm from FU:$fu to RU:$ru $rd  (IP:$si:$sp) UA:$ua \n");
                        $xavp(r=>$T_branch_idx) = $xavp(r=>$T_branch_idx) + " codec-transcode=opus codec-transcode=PCMU rtcp-mux-offer DTLS=passive transport-protocol=UDP/TLS/RTP/SAVPF SDES-off ICE=force";
                }
        } else {
                if ($proto =~ "ws") { # web --> web
                        xlog("L_INFO","NATMANAGE, FLB_RTPWS WAS FALSE, Web -> Web call. Encyrpting Audio");
                        xlog("L_INFO", "NATMANAGE: for method:$rm from FU:$fu to RU:$ru $rd  (IP:$si:$sp) UA:$ua \n");
                        $xavp(r=>$T_branch_idx) = $xavp(r=>$T_branch_idx) + " codec-transcode=opus codec-transcode=PCMU rtcp-mux-offer DTLS=passive transport-protocol=UDP/TLS/RTP/SAVPF SDES-off ICE=force";
                }

The above configuration still gives me audio only when calling from Web to SIP and not vice versa.

If I remove DTLS=passive I don't seem to get audio on either call.

@chiragd
Copy link
Author

chiragd commented May 5, 2020

If it helps at all, my config was based on this: https://github.com/havfo/WEBRTC-to-SIP/blob/master/etc/kamailio/kamailio.cfg

@rfuchs
Copy link
Member

rfuchs commented May 5, 2020

I was asking for a log from rtpengine

@chiragd
Copy link
Author

chiragd commented May 6, 2020 •
edited

Sure thing - sorry @rfuchs . Now I get no audio on either call. It does looks like DTLS is negotiating for the SIP -> Web call, but there is no audio.

Now for the Web -> SIP call it looks like DTLS is not negotiating and there is no audio, whereas this used to work before I removed DTLS=passive from the config.

If I have my config as:

if(isbflagset(FLB_RTPWS)){
                if ($proto =~ "ws") { # web --> SIP
                        xlog("L_INFO","NATMANAGE, FLB_RTPWS is set. Web -> SIP call. Removing DTLS and ICE. Decrypting Audio.");
                        xlog("L_INFO", "NATMANAGE: for method:$rm from FU:$fu to RU:$ru $rd  (IP:$si:$sp) UA:$ua \n");

                        $xavp(r=>$T_branch_idx) = $xavp(r=>$T_branch_idx) + " codec-transcode=opus codec-transcode=PCMU rtcp-mux-demux DTLS=off SDES-off ICE=remove RTP/AVP";
                } else { # SIP --> web
                        xlog("L_INFO","NATMANAGE, FLB_RTPWS is NOT set. SIP -> Web call. Adding DTLS and ICE. Encrypting Audio.");
                        xlog("L_INFO", "NATMANAGE: for method:$rm from FU:$fu to RU:$ru $rd  (IP:$si:$sp) UA:$ua \n");
                        $xavp(r=>$T_branch_idx) = $xavp(r=>$T_branch_idx) + " codec-transcode=opus codec-transcode=PCMU rtcp-mux-offer transport-protocol=UDP/TLS/RTP/SAVPF SDES-off ICE=force";
                }
        } else {
                if ($proto =~ "ws") { # web --> web
                        xlog("L_INFO","NATMANAGE, FLB_RTPWS WAS FALSE, Web -> Web call. Encyrpting Audio");
                        xlog("L_INFO", "NATMANAGE: for method:$rm from FU:$fu to RU:$ru $rd  (IP:$si:$sp) UA:$ua \n");
                        $xavp(r=>$T_branch_idx) = $xavp(r=>$T_branch_idx) + " codec-transcode=opus codec-transcode=PCMU rtcp-mux-offer transport-protocol=UDP/TLS/RTP/SAVPF SDES-off ICE=force";
                }

Here's the log from WEB -> SIP:

rtpengine[32571]: [sli5rqpondogmrjkqj6r] Received command 'offer' from 127.0.0.1:56786
rtpengine[32571]: [sli5rqpondogmrjkqj6r] Dump for 'offer' from 127.0.0.1:56786: { "sdp": "v=0#015#012o=- 1349282355457800097 2 IN IP4 127.0.0.1#015#012s=-#015#012t=0 0#015#012a=group:BUNDLE 0#015#012a=msid-semantic: WMS q14pTuuTo2AXdKUFlgAeMjeuoJG1I0XVB5CU#015#012m=audio 47845 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126#015#012c=IN IP4 [HOME_WIFI_PUBLIC_IP]#015#012a=rtcp:9 IN IP4 0.0.0.0#015#012a=candidate:932508327 1 udp 2113937151 e56b8537-9854-4364-9144-01447d910436.local 45157 typ host generation 0 network-cost 999#015#012a=candidate:842163049 1 udp 1677729535 [HOME_WIFI_PUBLIC_IP] 47845 t ...
rtpengine[32571]: [sli5rqpondogmrjkqj6r] ... yp srflx raddr 0.0.0.0 rport 0 generation 0 network-cost 999#015#012a=ice-ufrag:MWYh#015#012a=ice-pwd:ukbcIRRtNAfAtVY9yCNrRidt#015#012a=ice-options:trickle#015#012a=fingerprint:sha-256 8D:66:1A:FB:61:2B:B2:D6:5D:7B:E4:A8:7A:06:E7:32:F2:88:F2:38:9D:99:45:08:5F:B3:A9:19:1C:08:CB:1B#015#012a=setup:actpass#015#012a=mid:0#015#012a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level#015#012a=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time#015#012a=extmap:3 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01#015#012a=e ...
rtpengine[32571]: [sli5rqpondogmrjkqj6r] ... xtmap:4 urn:ietf:params:rtp-hdrext:sdes:mid#015#012a=extmap:5 urn:ietf:params:rtp-hdrext:sdes:rtp-stream-id#015#012a=extmap:6 urn:ietf:params:rtp-hdrext:sdes:repaired-rtp-stream-id#015#012a=sendrecv#015#012a=msid:q14pTuuTo2AXdKUFlgAeMjeuoJG1I0XVB5CU 7500c4d3-4c90-4188-af3f-548dcf0a4d1f#015#012a=rtcp-mux#015#012a=rtpmap:111 opus/48000/2#015#012a=rtcp-fb:111 transport-cc#015#012a=fmtp:111 minptime=10;useinbandfec=1#015#012a=rtpmap:103 ISAC/16000#015#012a=rtpmap:104 ISAC/32000#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:106 C ...
rtpengine[32571]: [sli5rqpondogmrjkqj6r] ... N/32000#015#012a=rtpmap:105 CN/16000#015#012a=rtpmap:13 CN/8000#015#012a=rtpmap:110 telephone-event/48000#015#012a=rtpmap:112 telephone-event/32000#015#012a=rtpmap:113 telephone-event/16000#015#012a=rtpmap:126 telephone-event/8000#015#012a=ssrc:1100118006 cname:5iPymf7Aq3LBzMwM#015#012a=ssrc:1100118006 msid:q14pTuuTo2AXdKUFlgAeMjeuoJG1I0XVB5CU 7500c4d3-4c90-4188-af3f-548dcf0a4d1f#015#012a=ssrc:1100118006 mslabel:q14pTuuTo2AXdKUFlgAeMjeuoJG1I0XVB5CU#015#012a=ssrc:1100118006 label:7500c4d3-4c90-4188-af3f-548dcf0a4d1f#015#012", "codec-transcode": "opus", "codec-t ...
rtpengine[32571]: [sli5rqpondogmrjkqj6r] ... ranscode": "PCMU", "DTLS": "off", "ICE": "remove", "flags": [ "trust-address", "SDES-off" ], "replace": [ "origin", "session-connection" ], "transport-protocol": "RTP/AVP", "rtcp-mux": [ "demux" ], "call-id": "sli5rqpondogmrjkqj6r", "via-branch": "z9hG4bK19372310", "received-from": [ "IP4", "[HOME_WIFI_PUBLIC_IP]" ], "from-tag": "sko2napmc5", "command": "offer" }
rtpengine[32571]: [sli5rqpondogmrjkqj6r] Creating new call
rtpengine[32571]: [sli5rqpondogmrjkqj6r] Opened ports 30056..30057 for media relay
rtpengine[32571]: [sli5rqpondogmrjkqj6r] Opened ports 30072..30073 for media relay
rtpengine[32571]: [sli5rqpondogmrjkqj6r] Learning new ICE candidate 842163049:1
rtpengine[32571]: [sli5rqpondogmrjkqj6r] Created candidate pair GaOI7rNzMURugGN1:842163049:1 between [KAMAILIO_PUBLIC_IP] and [HOME_WIFI_PUBLIC_IP]:47845, type srflx
rtpengine[32571]: [sli5rqpondogmrjkqj6r] Sending ICE/STUN request for candidate pair GaOI7rNzMURugGN1:842163049:1 from [KAMAILIO_PUBLIC_IP] to [HOME_WIFI_PUBLIC_IP]:47845
rtpengine[32571]: [sli5rqpondogmrjkqj6r] Replying to 'offer' from 127.0.0.1:56786
rtpengine[32571]: [sli5rqpondogmrjkqj6r] Response dump for 'offer' to 127.0.0.1:56786: { "sdp": "v=0#015#012o=- 1349282355457800097 2 IN IP4 [KAMAILIO_PUBLIC_IP]#015#012s=-#015#012t=0 0#015#012a=msid-semantic: WMS q14pTuuTo2AXdKUFlgAeMjeuoJG1I0XVB5CU#015#012m=audio 30056 RTP/AVP 111 103 104 9 0 8 106 105 13 110 112 113 126#015#012c=IN IP4 [KAMAILIO_PUBLIC_IP]#015#012a=msid:q14pTuuTo2AXdKUFlgAeMjeuoJG1I0XVB5CU 7500c4d3-4c90-4188-af3f-548dcf0a4d1f#015#012a=rtpmap:111 opus/48000/2#015#012a=rtcp-fb:111 transport-cc#015#012a=fmtp:111 minptime=10;useinbandfec=1#015#012a=rtpmap:103 ISAC/16000#015#012a=rtpmap:104 ISAC/32000#015#012 ...
rtpengine[32571]: [sli5rqpondogmrjkqj6r] ... a=rtpmap:9 G722/8000#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:106 CN/32000#015#012a=rtpmap:105 CN/16000#015#012a=rtpmap:13 CN/8000#015#012a=rtpmap:110 telephone-event/48000#015#012a=rtpmap:112 telephone-event/32000#015#012a=rtpmap:113 telephone-event/16000#015#012a=rtpmap:126 telephone-event/8000#015#012a=ssrc:1100118006 cname:5iPymf7Aq3LBzMwM#015#012a=ssrc:1100118006 msid:q14pTuuTo2AXdKUFlgAeMjeuoJG1I0XVB5CU 7500c4d3-4c90-4188-af3f-548dcf0a4d1f#015#012a=ssrc:1100118006 mslabel:q14pTuuTo2AXdKUFlgAeMjeuoJG1I0XVB5CU#015#012a=ssrc:1100118006 la ...
rtpengine[32571]: [sli5rqpondogmrjkqj6r] ... bel:7500c4d3-4c90-4188-af3f-548dcf0a4d1f#015#012a=sendrecv#015#012a=rtcp:30057#015#012", "result": "ok" }
rtpengine[32571]: [sli5rqpondogmrjkqj6r/sko2napmc5/1] Sending ICE/STUN request for candidate pair GaOI7rNzMURugGN1:842163049:1 from [KAMAILIO_PUBLIC_IP] to [HOME_WIFI_PUBLIC_IP]:47845
rtpengine[32571]: last message repeated 4 times
rtpengine[32571]: [sli5rqpondogmrjkqj6r] Received command 'answer' from 127.0.0.1:57143
rtpengine[32571]: [sli5rqpondogmrjkqj6r] Dump for 'answer' from 127.0.0.1:57143: { "sdp": "v=0#015#012o=- 2301685932275194983 2301685932275194984 IN IP4 192.168.0.18#015#012s=-#015#012c=IN IP4 192.168.0.18#015#012t=0 0#015#012a=sendrecv#015#012m=audio 18000 RTP/AVP 9 0 8 126#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:126 telephone-event/8000#015#012a=fmtp:126 0-15#015#012a=ptime:20#015#012a=sendrecv#015#012", "codec-transcode": "opus", "codec-transcode": "PCMU", "transport-protocol": "UDP/TLS/RTP/SAVPF", "ICE": "force", "flags": [ "SDES-off" ], "replace": [ "ori ...
rtpengine[32571]: [sli5rqpondogmrjkqj6r] ... gin", "session-connection" ], "rtcp-mux": [ "offer" ], "call-id": "sli5rqpondogmrjkqj6r", "via-branch": "z9hG4bK19372310", "received-from": [ "IP4", "[HOME_WIFI_PUBLIC_IP]" ], "from-tag": "sko2napmc5", "to-tag": "312157657", "command": "answer" }
rtpengine[32571]: [sli5rqpondogmrjkqj6r] Replying to 'answer' from 127.0.0.1:57143
rtpengine[32571]: [sli5rqpondogmrjkqj6r] Response dump for 'answer' to 127.0.0.1:57143: { "sdp": "v=0#015#012o=- 2301685932275194983 2301685932275194984 IN IP4 [KAMAILIO_PUBLIC_IP]#015#012s=-#015#012c=IN IP4 [KAMAILIO_PUBLIC_IP]#015#012t=0 0#015#012m=audio 30072 UDP/TLS/RTP/SAVPF 9 0 8 126#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:126 telephone-event/8000#015#012a=fmtp:126 0-15#015#012a=ptime:20#015#012a=sendrecv#015#012a=rtcp:30072#015#012a=rtcp-mux#015#012a=setup:active#015#012a=fingerprint:sha-1 95:45:AE:7A:EC:99:02:74:4B:2C:C0:94:8A:8F:49:60:BA:46:B4:05#015#012a=ice-ufrag:KWyHdoQL#015#012a=ic ...
rtpengine[32571]: [sli5rqpondogmrjkqj6r] ... e-pwd:4i0kDK6CqB1LR7ULLhGi6O8QKE#015#012a=candidate:GaOI7rNzMURugGN1 1 UDP 2130706431 [KAMAILIO_PUBLIC_IP] 30072 typ host#015#012", "result": "ok" }
/usr/local/sbin/kamailio[32546]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588758937;method=INVITE;from_tag=sko2napmc5;to_tag=312157657;call_id=sli5rqpondogmrjkqj6r;code=200;reason=OK;src_user=user4;src_domain=sip.mydomain.com;src_ip=[HOME_WIFI_PUBLIC_IP];dst_ouser=1001;dst_user=user1;dst_domain=192.168.0.18
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30057] Error parsing RTCP header: invalid packet type
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30056] SRTP output wanted, but no crypto suite was negotiated
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] Unknown STUN attribute: 0xc057
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] Triggering check for GaOI7rNzMURugGN1:842163049:1
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] ICE pair GaOI7rNzMURugGN1:842163049:1 has been nominated by peer
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] ICE not completed yet
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] Successful STUN binding request from [HOME_WIFI_PUBLIC_IP]:47845
rtpengine[32571]: [sli5rqpondogmrjkqj6r/sko2napmc5/1] Sending ICE/STUN request for candidate pair GaOI7rNzMURugGN1:842163049:1 from [KAMAILIO_PUBLIC_IP] to [HOME_WIFI_PUBLIC_IP]:47845
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] Received ICE/STUN response code 0 for candidate pair GaOI7rNzMURugGN1:842163049:1 from [HOME_WIFI_PUBLIC_IP]:47845 to [KAMAILIO_PUBLIC_IP]
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] Setting ICE candidate pair GaOI7rNzMURugGN1:842163049:1 as succeeded
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] Best succeeded ICE pair with all components is GaOI7rNzMURugGN1:842163049:1
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] ICE completed, using pair GaOI7rNzMURugGN1:842163049:1
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] DTLS error: 1 (sslv3 alert handshake failure)
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] DTLS error on local port 30072
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] Unknown STUN attribute: 0xc057
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] Successful STUN binding request from [HOME_WIFI_PUBLIC_IP]:47845
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] Unknown STUN attribute: 0xc057
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] Successful STUN binding request from [HOME_WIFI_PUBLIC_IP]:47845
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] Unknown STUN attribute: 0xc057
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] Successful STUN binding request from [HOME_WIFI_PUBLIC_IP]:47845
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] Unknown STUN attribute: 0xc057
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] Successful STUN binding request from [HOME_WIFI_PUBLIC_IP]:47845
rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30056] Confirmed peer address as [HOME_WIFI_PUBLIC_IP]:51920

Here are the logs from SIP -> WEB

rtpengine[32571]: [43391360609f6f6d] Received command 'offer' from 127.0.0.1:59852
rtpengine[32571]: [43391360609f6f6d] Dump for 'offer' from 127.0.0.1:59852: { "sdp": "v=0#015#012o=- 987435363535597193 987435363535597194 IN IP4 192.168.0.18#015#012s=-#015#012c=IN IP4 192.168.0.18#015#012t=0 0#015#012a=sendrecv#015#012m=audio 18000 RTP/AVP 0 8 18 9 2 101#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:18 G729/8000#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:2 G726-32/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:18 annexb=no#015#012a=fmtp:101 0-15#015#012a=ptime:20#015#012a=sendrecv#015#012", "codec-transcode": "opus", "codec-transcode": "PCMU", "transport-protocol": "UDP/TLS ...
rtpengine[32571]: [43391360609f6f6d] ... /RTP/SAVPF", "ICE": "force", "flags": [ "SDES-off" ], "replace": [ "origin", "session-connection" ], "rtcp-mux": [ "offer" ], "call-id": "43391360609f6f6d", "via-branch": "z9hG4bKbde2bdde1cdf3dc490", "received-from": [ "IP4", "[HOME_WIFI_PUBLIC_IP]" ], "from-tag": "b80a5c76e9", "command": "offer" }
rtpengine[32571]: [43391360609f6f6d] Creating new call
rtpengine[32571]: [43391360609f6f6d] Opened ports 30032..30033 for media relay
rtpengine[32571]: [43391360609f6f6d] Opened ports 30046..30047 for media relay
rtpengine[32571]: [43391360609f6f6d] Replying to 'offer' from 127.0.0.1:59852
rtpengine[32571]: [43391360609f6f6d] Response dump for 'offer' to 127.0.0.1:59852: { "sdp": "v=0#015#012o=- 987435363535597193 987435363535597194 IN IP4 [KAMAILIO_PUBLIC_IP]#015#012s=-#015#012c=IN IP4 [KAMAILIO_PUBLIC_IP]#015#012t=0 0#015#012m=audio 30032 UDP/TLS/RTP/SAVPF 0 8 18 9 2 101#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:18 G729/8000#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:2 G726-32/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:18 annexb=no#015#012a=fmtp:101 0-15#015#012a=ptime:20#015#012a=sendrecv#015#012a=rtcp:30033#015#012a=rtcp-mux#015#012a=setup:actpass#015#012a=fingerprint:sha-1 95:45:AE:7A:EC: ...
rtpengine[32571]: [43391360609f6f6d] ... 99:02:74:4B:2C:C0:94:8A:8F:49:60:BA:46:B4:05#015#012a=ice-ufrag:2UtciUPL#015#012a=ice-pwd:YjS9zFtfilJL1Gxong68WFpXxQ#015#012a=candidate:GaOI7rNzMURugGN1 1 UDP 2130706431 [KAMAILIO_PUBLIC_IP] 30032 typ host#015#012a=candidate:GaOI7rNzMURugGN1 2 UDP 2130706430 [KAMAILIO_PUBLIC_IP] 30033 typ host#015#012", "result": "ok" }
rtpengine[32571]: [43391360609f6f6d port 30032] Unknown STUN attribute: 0xc057
rtpengine[32571]: [43391360609f6f6d port 30032] Created candidate pair GaOI7rNzMURugGN1:00ffff000038b0424f31:1 between [KAMAILIO_PUBLIC_IP] and [HOME_WIFI_PUBLIC_IP]:39262, type prflx
rtpengine[32571]: [43391360609f6f6d port 30032] Triggering check for GaOI7rNzMURugGN1:00ffff000038b0424f31:1
rtpengine[32571]: [43391360609f6f6d port 30032] Successful STUN binding request from [HOME_WIFI_PUBLIC_IP]:39262
rtpengine[32571]: [43391360609f6f6d port 30032] DTLS handshake successful
rtpengine[32571]: [43391360609f6f6d port 30032] DTLS-SRTP successfully negotiated
rtpengine[32571]: [43391360609f6f6d port 30032] SRTP keys, incoming:
rtpengine[32571]: [43391360609f6f6d port 30032] --- AES_CM_128_HMAC_SHA1_80 key 1Ol1ZPDteenMzPKfsPvk/w== salt uLrK/OFmTpzRut+xJds=
rtpengine[32571]: [43391360609f6f6d port 30032] SRTP keys, outgoing:
rtpengine[32571]: [43391360609f6f6d port 30032] --- AES_CM_128_HMAC_SHA1_80 key EHr1hwLtSV5QomzARn70dw== salt reyRk4rbZ/wEbkllEkw=
rtpengine[32571]: [43391360609f6f6d port 30032] DTLS-SRTP successfully negotiated
rtpengine[32571]: [43391360609f6f6d port 30032] SRTP keys, incoming:
rtpengine[32571]: [43391360609f6f6d port 30032] --- AES_CM_128_HMAC_SHA1_80 key 1Ol1ZPDteenMzPKfsPvk/w== salt uLrK/OFmTpzRut+xJds=
rtpengine[32571]: [43391360609f6f6d port 30032] SRTP keys, outgoing:
rtpengine[32571]: [43391360609f6f6d port 30032] --- AES_CM_128_HMAC_SHA1_80 key EHr1hwLtSV5QomzARn70dw== salt reyRk4rbZ/wEbkllEkw=
rtpengine[32571]: [43391360609f6f6d] Received command 'answer' from 127.0.0.1:46102
rtpengine[32571]: [43391360609f6f6d] Dump for 'answer' from 127.0.0.1:46102: { "sdp": "v=0#015#012o=- 5982190993242745038 2 IN IP4 127.0.0.1#015#012s=-#015#012t=0 0#015#012a=msid-semantic: WMS fK2WNG9PLsVTjuKmO5Wy1V4C72WxGfJb0Dlb#015#012m=audio 9 UDP/TLS/RTP/SAVPF 0 8 9 101#015#012c=IN IP4 0.0.0.0#015#012a=rtcp:9 IN IP4 0.0.0.0#015#012a=candidate:932508327 1 udp 2113937151 e56b8537-9854-4364-9144-01447d910436.local 36574 typ host generation 0 network-cost 999#015#012a=ice-ufrag:7HKd#015#012a=ice-pwd:Lv3tXPEM0hjeBFeS0i0CPzLS#015#012a=ice-options:trickle#015#012a=fingerprint:sha-256 03:4E:DD:72:E1:81:5B: ...
rtpengine[32571]: [43391360609f6f6d] ... FC:D9:68:A1:05:1C:2F:E1:20:6C:41:FB:F4:B7:D1:D2:3A:0D:D2:9F:F9:B1:69:5A:14#015#012a=setup:active#015#012a=mid:0#015#012a=sendrecv#015#012a=msid:fK2WNG9PLsVTjuKmO5Wy1V4C72WxGfJb0Dlb f99eeaf2-3aeb-4901-aabe-62717e625af0#015#012a=rtcp-mux#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=ssrc:3773648938 cname:kXGyDt70l/ki72oy#015#012a=ssrc:3773648938 msid:fK2WNG9PLsVTjuKmO5Wy1V4C72WxGfJb0Dlb f99eeaf2-3aeb-4901-aabe-62717e625af0#015#012a=ssrc:3773648938 mslabel:fK2WNG9PLsVTjuKmO5Wy1V4C72 ...
rtpengine[32571]: [43391360609f6f6d] ... WxGfJb0Dlb#015#012a=ssrc:3773648938 label:f99eeaf2-3aeb-4901-aabe-62717e625af0#015#012", "codec-transcode": "opus", "codec-transcode": "PCMU", "DTLS": "off", "ICE": "remove", "flags": [ "trust-address", "SDES-off" ], "replace": [ "origin", "session-connection" ], "transport-protocol": "RTP/AVP", "rtcp-mux": [ "demux" ], "call-id": "43391360609f6f6d", "via-branch": "z9hG4bKbde2bdde1cdf3dc490", "received-from": [ "IP4", "[HOME_WIFI_PUBLIC_IP]" ], "from-tag": "b80a5c76e9", "to-tag": "pvmub154m0", "command": "answer" }
rtpengine[32571]: [43391360609f6f6d] Shutting down ICE agent (nothing to do)
rtpengine[32571]: [43391360609f6f6d] Replying to 'answer' from 127.0.0.1:46102
rtpengine[32571]: [43391360609f6f6d] Response dump for 'answer' to 127.0.0.1:46102: { "sdp": "v=0#015#012o=- 5982190993242745038 2 IN IP4 [KAMAILIO_PUBLIC_IP]#015#012s=-#015#012t=0 0#015#012a=msid-semantic: WMS fK2WNG9PLsVTjuKmO5Wy1V4C72WxGfJb0Dlb#015#012m=audio 30046 RTP/AVP 0 8 9 101#015#012c=IN IP4 [KAMAILIO_PUBLIC_IP]#015#012a=mid:0#015#012a=msid:fK2WNG9PLsVTjuKmO5Wy1V4C72WxGfJb0Dlb f99eeaf2-3aeb-4901-aabe-62717e625af0#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:9 G722/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=ssrc:3773648938 cname:kXGyDt70l/ki72oy#015#012a=ssrc:3773648938 msid:fK2 ...
rtpengine[32571]: [43391360609f6f6d] ... WNG9PLsVTjuKmO5Wy1V4C72WxGfJb0Dlb f99eeaf2-3aeb-4901-aabe-62717e625af0#015#012a=ssrc:3773648938 mslabel:fK2WNG9PLsVTjuKmO5Wy1V4C72WxGfJb0Dlb#015#012a=ssrc:3773648938 label:f99eeaf2-3aeb-4901-aabe-62717e625af0#015#012a=sendrecv#015#012a=rtcp:30047#015#012", "result": "ok" }
/usr/local/sbin/kamailio[32562]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588758477;method=INVITE;from_tag=b80a5c76e9;to_tag=pvmub154m0;call_id=43391360609f6f6d;code=200;reason=OK;src_user=user1;src_domain=sip.mydomain.com;src_ip=[HOME_WIFI_PUBLIC_IP];dst_ouser=1004;dst_user=7ia691sn;dst_domain=60adnj1pnc0c.invalid
rtpengine[32571]: [43391360609f6f6d port 30032] Unknown STUN attribute: 0xc057
rtpengine[32571]: [43391360609f6f6d port 30032] Triggering check for GaOI7rNzMURugGN1:00ffff000038b0424f31:1
rtpengine[32571]: [43391360609f6f6d port 30032] Successful STUN binding request from [HOME_WIFI_PUBLIC_IP]:39262
rtpengine[32571]: [43391360609f6f6d/pvmub154m0/1] Sending ICE/STUN request for candidate pair GaOI7rNzMURugGN1:00ffff000038b0424f31:1 from [KAMAILIO_PUBLIC_IP] to [HOME_WIFI_PUBLIC_IP]:39262
rtpengine[32571]: [43391360609f6f6d port 30032] SRTP output wanted, but no crypto suite was negotiated
rtpengine[32571]: [43391360609f6f6d port 30032] Received ICE/STUN response code 0 for candidate pair GaOI7rNzMURugGN1:00ffff000038b0424f31:1 from [HOME_WIFI_PUBLIC_IP]:39262 to [KAMAILIO_PUBLIC_IP]
rtpengine[32571]: [43391360609f6f6d port 30032] Setting ICE candidate pair GaOI7rNzMURugGN1:00ffff000038b0424f31:1 as succeeded
rtpengine[32571]: [43391360609f6f6d port 30032] Best succeeded ICE pair with all components is GaOI7rNzMURugGN1:00ffff000038b0424f31:1
rtpengine[32571]: [43391360609f6f6d port 30032] Unknown STUN attribute: 0xc057
rtpengine[32571]: [43391360609f6f6d port 30032] Successful STUN binding request from [HOME_WIFI_PUBLIC_IP]:39262
rtpengine[32571]: [43391360609f6f6d port 30047] SRTCP output wanted, but no crypto suite was negotiated
rtpengine[32571]: [43391360609f6f6d port 30046] SRTP output wanted, but no crypto suite was negotiated
rtpengine[32571]: [43391360609f6f6d/pvmub154m0/1] Start nominating ICE pairs
rtpengine[32571]: [43391360609f6f6d/pvmub154m0/1] Nominating ICE pair GaOI7rNzMURugGN1:00ffff000038b0424f31:1
rtpengine[32571]: [43391360609f6f6d/pvmub154m0/1] Sending nominating ICE/STUN request for candidate pair GaOI7rNzMURugGN1:00ffff000038b0424f31:1 from [KAMAILIO_PUBLIC_IP] to [HOME_WIFI_PUBLIC_IP]:39262
rtpengine[32571]: [43391360609f6f6d port 30032] Received ICE/STUN response code 0 for candidate pair GaOI7rNzMURugGN1:00ffff000038b0424f31:1 from [HOME_WIFI_PUBLIC_IP]:39262 to [KAMAILIO_PUBLIC_IP]
rtpengine[32571]: [43391360609f6f6d port 30032] Setting nominated ICE candidate pair GaOI7rNzMURugGN1:00ffff000038b0424f31:1 as valid
rtpengine[32571]: [43391360609f6f6d port 30032] ICE completed, using pair GaOI7rNzMURugGN1:00ffff000038b0424f31:1
rtpengine[32571]: [43391360609f6f6d port 30032] Unknown STUN attribute: 0xc057
rtpengine[32571]: [43391360609f6f6d port 30032] Successful STUN binding request from [HOME_WIFI_PUBLIC_IP]:39262
rtpengine[32571]: [43391360609f6f6d port 30032] Unknown STUN attribute: 0xc057
rtpengine[32571]: [43391360609f6f6d port 30032] Successful STUN binding request from [HOME_WIFI_PUBLIC_IP]:39262
 PREC=0x00 TTL=248 ID=32534 PROTO=TCP SPT=49179 DPT=18909 WINDOW=1200 RES=0x00 RST URGP=0 
rtpengine[32571]: [43391360609f6f6d port 30032] Confirmed peer address as [HOME_WIFI_PUBLIC_IP]:39262
rtpengine[32571]: [43391360609f6f6d port 30046] Confirmed peer address as [HOME_WIFI_PUBLIC_IP]:51920
rtpengine[32571]: [43391360609f6f6d] Received command 'delete' from 127.0.0.1:46102
rtpengine[32571]: [43391360609f6f6d] Dump for 'delete' from 127.0.0.1:46102: { "codec-transcode": "opus", "codec-transcode": "PCMU", "DTLS": "off", "ICE": "remove", "transport-protocol": "RTP/AVP", "call-id": "43391360609f6f6d", "received-from": [ "IP4", "[HOME_WIFI_PUBLIC_IP]" ], "from-tag": "pvmub154m0", "command": "delete" }
rtpengine[32571]: [43391360609f6f6d] Scheduling deletion of call branch 'pvmub154m0' in 30 seconds
rtpengine[32571]: [43391360609f6f6d] Replying to 'delete' from 127.0.0.1:46102
rtpengine[32571]: [43391360609f6f6d] Response dump for 'delete' to 127.0.0.1:46102: { "created": 1588758473, "last signal": 1588758477, "tags": { "pvmub154m0": { "tag": "pvmub154m0", "via-branch": "z9hG4bKbde2bdde1cdf3dc490", "created": 1588758473, "in dialogue with": "b80a5c76e9", "medias": [ { "index": 1, "type": "audio", "protocol": "UDP/TLS/RTP/SAVPF", "streams": [ { "local port": 30032, "endpoint": { "family": "IPv4", "address": "[HOME_WIFI_PUBLIC_IP]", "port": 39262 }, "advertised endpoint": { "family": "IPv4", "address": "0.0.0.0", " ...
rtpengine[32571]: [43391360609f6f6d] ... port": 9 }, "last packet": 1588758481, "flags": [ "RTP", "RTCP", "filled", "confirmed", "kernelized", "no kernel support" ], "stats": { "packets": 210, "bytes": 37976, "errors": 0 } }, { "local port": 30033, "endpoint": { "family": "IPv6", "address": "::", "port": 0 }, "advertised endpoint": { "family": "IPv6", "address": "::", "port": 0 }, "last packet": 1588758473, "flags": [ "RTCP", "fallback RTCP", "filled" ], "stats": { "packets": 0, "bytes": 0, "errors": 0 } } ], "flags": [ "initialized",  ...
rtpengine[32571]: [43391360609f6f6d] ... "send", "recv", "rtcp-mux", "DTLS-SRTP", "DTLS role passive", "ICE" ] } ] }, "b80a5c76e9": { "tag": "b80a5c76e9", "created": 1588758473, "in dialogue with": "pvmub154m0", "medias": [ { "index": 1, "type": "audio", "protocol": "RTP/AVP", "streams": [ { "local port": 30046, "endpoint": { "family": "IPv4", "address": "[HOME_WIFI_PUBLIC_IP]", "port": 51920 }, "advertised endpoint": { "family": "IPv4", "address": "192.168.0.18", "port": 18000 }, "last packet": 1588758481, "flags": [ "RTP", "filled", "confirme ...
rtpengine[32571]: [43391360609f6f6d] ... d", "kernelized", "no kernel support" ], "stats": { "packets": 206, "bytes": 35432, "errors": 0 } }, { "local port": 30047, "endpoint": { "family": "IPv4", "address": "[HOME_WIFI_PUBLIC_IP]", "port": 51921 }, "advertised endpoint": { "family": "IPv4", "address": "192.168.0.18", "port": 18001 }, "last packet": 1588758477, "flags": [ "RTCP", "filled" ], "stats": { "packets": 1, "bytes": 44, "errors": 0 } } ], "flags": [ "initialized", "send", "recv" ] } ] } }, "totals": { "RTP": { "packets": 416, "bytes":  ...
rtpengine[32571]: [43391360609f6f6d] ... 73408, "errors": 0 }, "RTCP": { "packets": 1, "bytes": 44, "errors": 0 } }, "result": "ok" }
/usr/local/sbin/kamailio[32544]: NOTICE: acc [acc.c:317]: acc_log_request(): ACC: transaction answered: timestamp=1588758481;method=BYE;from_tag=pvmub154m0;to_tag=b80a5c76e9;call_id=43391360609f6f6d;code=200;reason=OK;src_user=1004;src_domain=sip.mydomain.com;src_ip=[HOME_WIFI_PUBLIC_IP];dst_ouser=user1;dst_user=user1;dst_domain=192.168.0.18
rtpengine[32571]: [43391360609f6f6d port 30047] Error parsing RTCP header: invalid packet type
rtpengine[32571]: [43391360609f6f6d port 30047] Confirmed peer address as [HOME_WIFI_PUBLIC_IP]:51921

If it makes any difference, in the sip.js or jssip logs the mediastreamtrack.readystate shows as "ended"

@rfuchs
Copy link
Member

rfuchs commented May 6, 2020

So in the first case you have

rtpengine[32571]: [sli5rqpondogmrjkqj6r port 30072] DTLS error: 1 (sslv3 alert handshake failure)

That's something received by rtpengine. You'll have to look into why there has been a failure on the other side. You can also try looking at the DTLS packets with Wireshark.

Second case should work. DTLS finishes, ICE finishes. So from rtpengine's POV all is good.

@chiragd
Copy link
Author

chiragd commented May 7, 2020

Thanks @rfuchs . It's on odd one, it does look like media state is live or active, but there is no actual sound in either direction on the SIP -> WEB call.

I know the WEB -> SIP call worked previously so I'm thinking there is something wrong in my kamailio config where it isn't applying the right logic at the right time. So I'm not going to try and debug that.

It turns out that this machine is using quite an old version of RTPEngine: 4.1.0.0+0~mr4.1.0.0.

Just in case that might be some of the cause of my issues, I'm going to start with a fresh install of the latest Kamailio and the latest rtpenging. Any advise you may have for structuring the logic within Kamailio to have RTPengine do the right things on the right legs of the call would be most appreciated.

@chiragd
Copy link
Author

chiragd commented May 25, 2020

@rfuchs I installed a new node with the latest Kamailio and RTP engine and it looks like things are working.

Thanks so much for your help!

@rfuchs
Copy link
Member

rfuchs commented May 25, 2020

Glad to hear 👍

@rfuchs rfuchs closed this as completed May 25, 2020
@vtmjapandev
Copy link

hi @chiragd
You can teach for me how to setup WebRTC (sip.js + kamailio)? Thankyou very much.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@chiragd @rfuchs @juha-h @vtmjapandev