Re: [sr-dev] rtpengine trouble

Richard Fuchs writes: below, -- juha Apr 7 15:53:13 siika /usr/sbin/sip-proxy[6799]: INFO: INVITE <sip:jh@test.tutpro.com> is to local user &lt;jh(a)test.tutpro.com&gt; Apr 7 15:53:13 siika /usr/sbin/sip-proxy[6799]: INFO: ===== rtpengine_offer(replace-session-connection replace-origin via-branch=1 trust-address) Apr 7 15:53:13 siika rtpengine[12409]: Got valid command from 127.0.0.1:57950: offer - { "sdp": "v=0#015#012o=- 105525634 1836351013 IN IP4 192.168.43.146#015#012s=-#015#012c=IN IP4 192.168.43.146#015#012t=0 0#015#012a=tool:baresip 0.4.10#015#012m=audio 10610 RTP/SAVPF 96 97 98 8 0 101#015#012b=AS:125#015#012a=rtpmap:96 opus/48000/2#015#012a=fmtp:96 stereo=1;sprop-stereo=1#015#012a=rtpmap:97 speex/16000#015#012a=fmtp:97 mode="7";vbr=off;cng=on#015#012a=rtpmap:98 speex/8000#015#012a=fmtp:98 mode="7";vbr=off;cng=on#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=sendrecv#015#012a=label:1#015#012a=rtcp-rsize#015#012a=ssrc:721305898 cname:sip:test@test.tutpro.com#015#012a=crypto:0 AES_CM_128_HMAC_SHA1_80 inline:T3nlFkYcttcBj2043AyD91nlYRj5NornYHkq7yh+#015#012a=ptime:20#015#012", "flags": [ "trust-address" ], "replace": [ "session-connection", "origin" ], "call-id": "01a67cc3213c924f", "via-branch": "z9hG4bK07531aad8821f685", "received-from": [ "IP4", "192.98.102.30" ], "from-tag": "7fd43a78aa5b5497", "command": "offer" } Apr 7 15:53:13 siika rtpengine[12409]: [01a67cc3213c924f] Creating new call Apr 7 15:53:13 siika rtpengine[12409]: [01a67cc3213c924f] Opened ports 50000..50001 for media relay Apr 7 15:53:13 siika rtpengine[12409]: [01a67cc3213c924f] Opened ports 50002..50003 for media relay Apr 7 15:53:13 siika rtpengine[12409]: [01a67cc3213c924f] Returning to SIP proxy: d3:sdp959:v=0#015#012o=- 105525634 1836351013 IN IP4 192.98.102.30#015#012s=-#015#012c=IN IP4 192.98.102.30#015#012t=0 0#015#012a=tool:baresip 0.4.10#015#012a=ice-lite#015#012m=audio 50000 RTP/SAVPF 96 97 98 8 0 101#015#012b=AS:125#015#012a=rtpmap:96 opus/48000/2#015#012a=fmtp:96 stereo=1;sprop-stereo=1#015#012a=rtpmap:97 speex/16000#015#012a=fmtp:97 mode="7";vbr=off;cng=on#015#012a=rtpmap:98 speex/8000#015#012a=fmtp:98 mode="7";vbr=off;cng=on#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=label:1#015#012a=rtcp-rsize#015#012a=ssrc:721305898 cname:sip:test@test.tutpro.com#015#012a=ptime:20#015#012a=sendrecv#015#012a=rtcp:50001#015#012a=crypto:0 AES_CM_128_HMAC_SHA1_80 inline:T3nlFkYcttcBj2043AyD91nlYRj5NornYHkq7yh+#015#012a=setup:actpass#015#012a=fingerprint:sha-1 13:DC:F9:F7:3A:18:43:89:36:DD:B0:B7:A5:44:5E:B1:67:56:41:C6#015#012a=ice-ufrag:BKSxeEUb#015#012a=ice-pwd:lr1GnviPc1t3xBqM1yWaQJRrrHWD#015#012a=candidate:yjWbVwOpZHzPlWwB 1 UDP 2130706432 192.98.102.30 50000 typ host#015#012a=candidate:yjWbVwOpZHzPlWwB 2 UDP 2130706431 192.98.102.30 50001 typ host#015#0126:result2:oke Apr 7 15:53:13 siika /usr/sbin/sip-proxy[6799]: INFO: Routing INVITE <sip:le9dho0j@hj2m0mult01v.invalid;transport=ws> to contact via <sip:192.98.102.30:34664;transport=WS> Apr 7 15:53:21 siika rtpengine[12409]: [01a67cc3213c924f port 50000] Successful STUN binding request from 192.98.104.1:54576 Apr 7 15:53:21 siika rtpengine[12409]: [01a67cc3213c924f port 50001] Successful STUN binding request from 192.98.104.1:34509 Apr 7 15:53:21 siika rtpengine[12409]: [01a67cc3213c924f port 50000] DTLS handshake successful Apr 7 15:53:21 siika rtpengine[12409]: [01a67cc3213c924f port 50000] DTLS-SRTP successfully negotiated Apr 7 15:53:21 siika rtpengine[12409]: [01a67cc3213c924f port 50001] DTLS handshake successful Apr 7 15:53:21 siika rtpengine[12409]: [01a67cc3213c924f port 50001] DTLS-SRTP successfully negotiated Apr 7 15:53:21 siika /usr/sbin/sip-proxy[6799]: INFO: ===== rtpengine_answer(replace-session-connection replace-origin via-branch=2 trust-address) Apr 7 15:53:21 siika rtpengine[12409]: Got valid command from 127.0.0.1:57950: answer - { "sdp": "v=0#015#012o=- 4128609880524945129 2 IN IP4 127.0.0.1#015#012s=-#015#012t=0 0#015#012a=msid-semantic: WMS Ge7wfuPeDpQ8jRC6NbxYEz97Ipw9QK0WrooB#015#012m=audio 54576 RTP/SAVPF 96 0 8 101#015#012c=IN IP4 192.98.104.1#015#012a=rtcp:34509 IN IP4 192.98.104.1#015#012a=candidate:1937193501 1 udp 2113937151 192.98.104.1 54576 typ host generation 0#015#012a=candidate:451549855 1 udp 2113937151 192.98.102.39 50856 typ host generation 0#015#012a=candidate:1603072777 1 udp 2113937151 192.168.43.146 55551 typ host generation 0#015#012a=candidate:1937193501 2 udp 2113937150 192.98.104.1 34509 typ host generation 0#015#012a=candidate:451549855 2 udp 2113937150 192.98.102.39 35743 typ host generation 0#015#012a=candidate:1603072777 2 udp 2113937150 192.168.43.146 53835 typ host generation 0#015#012a=ice-ufrag:dJbBYDEMzX+cIyp0#015#012a=ice-pwd:kPd0kKQjb5XxyFum2fdSTDmq#015#012a=fingerprint:sha-256 6C:31:49:8D:B3:74:9E:84:C8:D7:D9:E5:3A:27:7B:1B:6C:F1:B0:BD:6F:9C:8A:ED:FB:4D:4E:CB:7F:D6:06:9E#015#012a=setup:active#015#012a=mid:audio#015#012a=sendrecv#015#012a=rtpmap:96 opus/48000/2#015#012a=fmtp:96 minptime=10#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=maxptime:60#015#012a=ssrc:834916748 cname:l6uQ8e42H/tsIlt0#015#012a=ssrc:834916748 msid:Ge7wfuPeDpQ8jRC6NbxYEz97Ipw9QK0WrooB 3e6a6582-0f28-4030-9d3e-2242e092354f#015#012a=ssrc:834916748 mslabel:Ge7wfuPeDpQ8jRC6NbxYEz97Ipw9QK0WrooB#015#012a=ssrc:834916748 label:3e6a6582-0f28-4030-9d3e-2242e092354f#015#012", "flags": [ "trust-address" ], "replace": [ "session-connection", "origin" ], "call-id": "01a67cc3213c924f", "via-branch": "z9hG4bK07531aad8821f685", "received-from": [ "IP4", "192.98.102.30" ], "from-tag": "7fd43a78aa5b5497", "to-tag": "d6ms4tiim9", "command": "answer" } Apr 7 15:53:21 siika rtpengine[12409]: [01a67cc3213c924f] DTLS: Peer certificate accepted Apr 7 15:53:21 siika rtpengine[12409]: [01a67cc3213c924f] DTLS: Peer certificate accepted Apr 7 15:53:21 siika rtpengine[12409]: [01a67cc3213c924f] Returning to SIP proxy: d3:sdp1342:v=0#015#012o=- 4128609880524945129 2 IN IP4 192.98.102.30#015#012s=-#015#012t=0 0#015#012a=msid-semantic: WMS Ge7wfuPeDpQ8jRC6NbxYEz97Ipw9QK0WrooB#015#012m=audio 50002 RTP/SAVPF 96 0 8 101#015#012c=IN IP4 192.98.102.30#015#012a=candidate:1937193501 1 udp 2113937151 192.98.104.1 54576 typ host generation 0#015#012a=candidate:451549855 1 udp 2113937151 192.98.102.39 50856 typ host generation 0#015#012a=candidate:1603072777 1 udp 2113937151 192.168.43.146 55551 typ host generation 0#015#012a=candidate:1937193501 2 udp 2113937150 192.98.104.1 34509 typ host generation 0#015#012a=candidate:451549855 2 udp 2113937150 192.98.102.39 35743 typ host generation 0#015#012a=candidate:1603072777 2 udp 2113937150 192.168.43.146 53835 typ host generation 0#015#012a=ice-ufrag:dJbBYDEMzX+cIyp0#015#012a=ice-pwd:kPd0kKQjb5XxyFum2fdSTDmq#015#012a=mid:audio#015#012a=rtpmap:96 opus/48000/2#015#012a=fmtp:96 minptime=10#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=maxptime:60#015#012a=ssrc:834916748 cname:l6uQ8e42H/tsIlt0#015#012a=ssrc:834916748 msid:Ge7wfuPeDpQ8jRC6NbxYEz97Ipw9QK0WrooB 3e6a6582-0f28-4030-9d3e-2242e092354f#015#012a=ssrc:834916748 mslabel:Ge7wfuPeDpQ8jRC6NbxYEz97Ipw9QK0WrooB#015#012a=ssrc:834916748 label:3e6a6582-0f28-4030-9d3e-2242e092354f#015#012a=sendrecv#015#012a=rtcp:50003#015#012a=candidate:yjWbVwOpZHzPlWwB 1 UDP 2130706432 192.98.102.30 50002 typ host#015#012a=candidate:yjWbVwOpZHzPlWwB 2 UDP 2130706431 192.98.102.30 50003 typ host#015#0126:result2:oke Apr 7 15:53:21 siika /usr/sbin/sip-proxy[6801]: INFO: Routing in-dialog ACK <sip:le9dho0j@hj2m0mult01v.invalid;transport=ws> from <sip:test@test.tutpro.com> to <sip:192.98.102.30:34664;transport=WS> based on gruu Apr 7 15:53:21 siika rtpengine[12409]: [01a67cc3213c924f port 50000] Successful STUN binding request from 192.98.102.39:50856 Apr 7 15:53:21 siika rtpengine[12409]: [01a67cc3213c924f port 50001] Successful STUN binding request from 192.98.102.39:35743 Apr 7 15:53:21 siika rtpengine[12409]: [01a67cc3213c924f port 50000] Successful STUN binding request from 192.168.43.146:55551 Apr 7 15:53:21 siika rtpengine[12409]: [01a67cc3213c924f port 50001] Successful STUN binding request from 192.168.43.146:53835 Apr 7 15:53:22 siika rtpengine[12409]: [01a67cc3213c924f port 50000] Successful STUN binding request from 192.98.104.1:54576 Apr 7 15:53:22 siika rtpengine[12409]: [01a67cc3213c924f port 50001] Successful STUN binding request from 192.98.104.1:34509 Apr 7 15:53:22 siika rtpengine[12409]: [01a67cc3213c924f port 50000] Successful STUN binding request from 192.98.102.39:50856 Apr 7 15:53:22 siika rtpengine[12409]: [01a67cc3213c924f port 50001] Successful STUN binding request from 192.98.102.39:35743 Apr 7 15:53:23 siika rtpengine[12409]: [01a67cc3213c924f port 50000] Successful STUN binding request from 192.98.104.1:54576 Apr 7 15:53:23 siika rtpengine[12409]: [01a67cc3213c924f port 50001] Successful STUN binding request from 192.98.104.1:34509 Apr 7 15:53:23 siika rtpengine[12409]: [01a67cc3213c924f port 50000] Successful STUN binding request from 192.168.43.146:55551 Apr 7 15:53:23 siika rtpengine[12409]: [01a67cc3213c924f port 50001] Successful STUN binding request from 192.168.43.146:53835 Apr 7 15:53:24 siika rtpengine[12409]: [01a67cc3213c924f port 50000] Successful STUN binding request from 192.98.104.1:54576 Apr 7 15:53:24 siika rtpengine[12409]: [01a67cc3213c924f port 50001] Successful STUN binding request from 192.98.104.1:34509 Apr 7 15:53:24 siika rtpengine[12409]: [01a67cc3213c924f port 50000] Successful STUN binding request from 192.98.102.39:50856 Apr 7 15:53:24 siika rtpengine[12409]: [01a67cc3213c924f port 50001] Successful STUN binding request from 192.98.102.39:35743 Apr 7 15:53:25 siika rtpengine[12409]: [01a67cc3213c924f port 50000] Confirmed peer information for port 50000 - 192.98.104.1:54576 Apr 7 15:53:25 siika rtpengine[12409]: [01a67cc3213c924f port 50002] Confirmed peer information for port 50002 - 192.98.102.30:10610 Apr 7 15:53:25 siika rtpengine[12409]: [01a67cc3213c924f port 50002] Kernelizing media stream with local port 50002 Apr 7 15:53:25 siika rtpengine[12409]: [01a67cc3213c924f port 50000] Kernelizing media stream with local port 50000 Apr 7 15:53:25 siika rtpengine[12409]: [01a67cc3213c924f port 50000] Successful STUN binding request from 192.98.104.1:54576 Apr 7 15:53:25 siika rtpengine[12409]: [01a67cc3213c924f port 50001] Successful STUN binding request from 192.98.104.1:34509 Apr 7 15:53:25 siika rtpengine[12409]: [01a67cc3213c924f port 50001] Confirmed peer information for port 50001 - 192.98.104.1:34509 Apr 7 15:53:25 siika /usr/sbin/sip-proxy[6801]: INFO: ===== rtpengine_delete() Apr 7 15:53:25 siika rtpengine[12409]: Got valid command from 127.0.0.1:38149: delete - { "call-id": "01a67cc3213c924f", "received-from": [ "IP4", "192.98.102.30" ], "from-tag": "7fd43a78aa5b5497", "command": "delete" } Apr 7 15:53:25 siika rtpengine[12409]: [01a67cc3213c924f] Deleting full call Apr 7 15:53:25 siika rtpengine[12409]: [01a67cc3213c924f] Final packet stats: Apr 7 15:53:25 siika rtpengine[12409]: [01a67cc3213c924f] --- Tag 'd6ms4tiim9', created 0:12 ago, in dialogue with '7fd43a78aa5b5497' Apr 7 15:53:25 siika rtpengine[12409]: [01a67cc3213c924f] ------ Media #1, port 50002 <> 192.98.102.30:10610, 186 p, 48401 b, 0 e Apr 7 15:53:25 siika rtpengine[12409]: [01a67cc3213c924f] ------ Media #1, port 50003 <> 192.168.43.146:10611 (RTCP), 0 p, 0 b, 0 e Apr 7 15:53:25 siika rtpengine[12409]: [01a67cc3213c924f] --- Tag '7fd43a78aa5b5497', created 0:12 ago, in dialogue with 'd6ms4tiim9' Apr 7 15:53:25 siika rtpengine[12409]: [01a67cc3213c924f] ------ Media #1, port 50000 <> 192.98.104.1:54576, 194 p, 64134 b, 0 e Apr 7 15:53:25 siika rtpengine[12409]: [01a67cc3213c924f] ------ Media #1, port 50001 <> 192.98.104.1:34509 (RTCP), 5 p, 502 b, 0 e Apr 7 15:53:25 siika rtpengine[12409]: [01a67cc3213c924f] Returning to SIP proxy: d6:result2:oke