ion-sfu-gstreamer-receive does not receive media

[TariqueNasrullah]

environment.

• Sfu server running on docker [degest: c68aae022ee7], running on port 5551
• Signaling server running on docker.
• SDK Version: latest on master
• Browser: Chrome on macos

Command

go run example/on-sfu-gstreamer-receive/main.go -addr "localhost:5551" -session "ion" 

What happened?

• rtc.OnTrack user defined function (ref) never called.
• sample code does not define a OnTrackEvent, log shows following
  ERROR default: [rtc.go:662] [ion-sdk-go.(*RTC).onSingalHandle] s.OnTrackEvent == nil

Detailed log

admin@admins-MacBook-Pro gstreamer-receive % go run main.go -addr "localhost:5551" -session "ion"
# github.com/pion/ion-sdk-go/pkg/gstreamer-sink
gst.c:57:18: warning: 'g_memdup' is deprecated: Use 'g_memdup2' instead [-Wdeprecated-declarations]
/opt/homebrew/Cellar/glib/2.70.1/include/glib-2.0/glib/gstrfuncs.h:256:1: note: 'g_memdup' has been explicitly marked deprecated here
/opt/homebrew/Cellar/glib/2.70.1/include/glib-2.0/glib/gversionmacros.h:1057:49: note: expanded from macro 'GLIB_DEPRECATED_IN_2_68_FOR'
/opt/homebrew/Cellar/glib/2.70.1/include/glib-2.0/glib/gmacros.h:1144:32: note: expanded from macro 'GLIB_DEPRECATED_FOR'
/opt/homebrew/Cellar/glib/2.70.1/include/glib-2.0/glib/gmacros.h:1112:44: note: expanded from macro 'G_DEPRECATED_FOR'
[2021-11-28 00:54:35.262]  INFO default: [connector.go:104] [ion-sdk-go.NewConnector] gRPC connected: localhost:5551 
[2021-11-28 00:54:35.263]  INFO default: [rtc.go:166] [ion-sdk-go.(*RTC).Join] [C=>S] sid=ion uid=XwYh 
[2021-11-28 00:54:35.263]  INFO default: [rtc.go:699] [ion-sdk-go.(*RTC).SendJoin] [C=>S] [XwYh] sid=ion 
[2021-11-28 00:54:35.286]  INFO default: [rtc.go:620] [ion-sdk-go.(*RTC).onSingalHandle] [XwYh] [join] success 
[2021-11-28 00:54:35.286]  INFO default: [rtc.go:621] [ion-sdk-go.(*RTC).onSingalHandle] payload.Reply.Description=type:"answer" sdp:"v=0\r\no=- 2191063313708287422 1638039275 IN IP4 0.0.0.0\r\ns=-\r\nt=0 0\r\na=fingerprint:sha-256 EF:AD:AC:B6:FF:9E:1D:4A:90:23:F9:7B:F3:D1:7C:C5:78:E0:B8:EE:D4:26:F7:22:62:69:BC:DE:85:64:2B:88\r\na=ice-lite:ice-lite\r\na=group:BUNDLE 0\r\nm=application 9 UDP/DTLS/SCTP webrtc-datachannel\r\nc=IN IP4 0.0.0.0\r\na=setup:active\r\na=mid:0\r\na=sendrecv\r\na=sctp-port:5000\r\na=ice-ufrag:mbMDrsqAnoBOqNMn\r\na=ice-pwd:sntwnAkHgFrvYgusDZbdTmqSeCTzECoJ\r\n" 
[2021-11-28 00:54:35.287] DEBUG default: [rtc.go:529] [ion-sdk-go.(*RTC).setRemoteSDP] id=XwYh r.rtc.trickle cand=udp4 host 192.168.0.110:63874 
[2021-11-28 00:54:35.287] DEBUG default: [rtc.go:726] [ion-sdk-go.(*RTC).SendTrickle] [C=>S] [XwYh] candidate=udp4 host 192.168.0.110:63874 target=0 
[2021-11-28 00:54:35.290]  INFO default: [rtc.go:658] [ion-sdk-go.(*RTC).onSingalHandle] [XwYh] [trickle] type=PUBLISHER candidate={candidate:2878742611 1 udp 2130706431 127.0.0.1 5000 typ host 0x1400048e0d0 0x14000490088 <nil>} 
[2021-11-28 00:54:35.290] DEBUG default: [rtc.go:311] [ion-sdk-go.(*RTC).trickle] [S=>C] id=XwYh candidate={candidate:2878742611 1 udp 2130706431 127.0.0.1 5000 typ host 0x1400048e0d0 0x14000490088 <nil>} target=0 
[2021-11-28 00:54:35.321] DEBUG default: [rtc.go:726] [ion-sdk-go.(*RTC).SendTrickle] [C=>S] [XwYh] candidate=udp4 srflx 118.179.74.139:55734 related 0.0.0.0:55734 target=0 
[2021-11-28 00:54:35.533]  INFO default: [rtc.go:643] [ion-sdk-go.(*RTC).onSingalHandle] [XwYh] [description] got offer call s.OnNegotiate sdp={Type:offer SDP:v=0
o=- 7415381412671533942 1638039275 IN IP4 0.0.0.0
s=-
t=0 0
a=fingerprint:sha-256 8D:86:E6:1E:3B:89:CA:60:DE:40:14:96:EF:EB:2F:25:29:73:72:5E:E2:92:A5:F6:20:F2:17:0D:EF:72:B0:3B
a=ice-lite:ice-lite
a=group:BUNDLE 0
m=application 9 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 0.0.0.0
a=setup:actpass
a=mid:0
a=sendrecv
a=sctp-port:5000
a=ice-ufrag:cOEMAWBiZZSOUhYO
a=ice-pwd:MgWsEtUzcKCJuyXXRgcewzaZYPUTjAYw
 parsed:<nil>} 
[2021-11-28 00:54:35.533] DEBUG default: [rtc.go:332] [ion-sdk-go.(*RTC).negotiate] [S=>C] id=XwYh Negotiate sdp={offer v=0
o=- 7415381412671533942 1638039275 IN IP4 0.0.0.0
s=-
t=0 0
a=fingerprint:sha-256 8D:86:E6:1E:3B:89:CA:60:DE:40:14:96:EF:EB:2F:25:29:73:72:5E:E2:92:A5:F6:20:F2:17:0D:EF:72:B0:3B
a=ice-lite:ice-lite
a=group:BUNDLE 0
m=application 9 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 0.0.0.0
a=setup:actpass
a=mid:0
a=sendrecv
a=sctp-port:5000
a=ice-ufrag:cOEMAWBiZZSOUhYO
a=ice-pwd:MgWsEtUzcKCJuyXXRgcewzaZYPUTjAYw
 <nil>} 
[2021-11-28 00:54:35.534]  INFO default: [rtc.go:774] [ion-sdk-go.(*RTC).SendAnswer] [C=>S] [XwYh] sdp={answer v=0
o=- 8076618041328987101 1638039275 IN IP4 0.0.0.0
s=-
t=0 0
a=fingerprint:sha-256 39:56:41:A4:33:AA:83:1B:83:0A:4E:93:00:00:55:49:2D:CD:21:26:3F:4A:C8:AD:CB:1C:1E:04:F1:F9:1C:6D
a=group:BUNDLE 0
m=application 9 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 0.0.0.0
a=setup:active
a=mid:0
a=sendrecv
a=sctp-port:5000
a=ice-ufrag:egFJZRHuAzhQUcku
a=ice-pwd:nIAoogUFkLtuBodOrejzJvjKGrkALBvS
 0x140004cc240} 
[2021-11-28 00:54:35.534] DEBUG default: [rtc.go:726] [ion-sdk-go.(*RTC).SendTrickle] [C=>S] [XwYh] candidate=udp4 host 192.168.0.110:62101 target=0 
[2021-11-28 00:54:35.535]  INFO default: [rtc.go:658] [ion-sdk-go.(*RTC).onSingalHandle] [XwYh] [trickle] type=SUBSCRIBER candidate={candidate:2878742611 1 udp 2130706431 127.0.0.1 5000 typ host 0x14000076510 0x1400003c500 <nil>} 
[2021-11-28 00:54:35.535] DEBUG default: [rtc.go:311] [ion-sdk-go.(*RTC).trickle] [S=>C] id=XwYh candidate={candidate:2878742611 1 udp 2130706431 127.0.0.1 5000 typ host 0x14000076510 0x1400003c500 <nil>} target=1 
[2021-11-28 00:54:35.560] DEBUG default: [rtc.go:726] [ion-sdk-go.(*RTC).SendTrickle] [C=>S] [XwYh] candidate=udp4 srflx 118.179.74.139:60299 related 0.0.0.0:60299 target=0 
[2021-11-28 00:54:35.560]  INFO default: [transport.go:63] [ion-sdk-go.NewTransport.func1] gather candidate done 
[2021-11-28 00:54:35.600] DEBUG default: [rtc.go:726] [ion-sdk-go.(*RTC).SendTrickle] [C=>S] [XwYh] candidate=udp4 srflx 118.179.74.139:59889 related 0.0.0.0:59889 target=0 
[2021-11-28 00:54:35.963] DEBUG default: [rtc.go:726] [ion-sdk-go.(*RTC).SendTrickle] [C=>S] [XwYh] candidate=udp4 srflx 118.179.74.139:56597 related 0.0.0.0:56597 target=0 
[2021-11-28 00:54:35.963]  INFO default: [transport.go:63] [ion-sdk-go.NewTransport.func1] gather candidate done 
[2021-11-28 00:54:49.109]  INFO default: [rtc.go:643] [ion-sdk-go.(*RTC).onSingalHandle] [XwYh] [description] got offer call s.OnNegotiate sdp={Type:offer SDP:v=0
o=- 7415381412671533942 1638039276 IN IP4 0.0.0.0
s=-
t=0 0
a=fingerprint:sha-256 8D:86:E6:1E:3B:89:CA:60:DE:40:14:96:EF:EB:2F:25:29:73:72:5E:E2:92:A5:F6:20:F2:17:0D:EF:72:B0:3B
a=ice-lite:ice-lite
a=group:BUNDLE 0 1 2
m=application 9 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 0.0.0.0
a=setup:actpass
a=mid:0
a=sendrecv
a=sctp-port:5000
a=ice-ufrag:cOEMAWBiZZSOUhYO
a=ice-pwd:MgWsEtUzcKCJuyXXRgcewzaZYPUTjAYw
a=candidate:2878742611 1 udp 2130706431 127.0.0.1 5000 typ host
a=candidate:2878742611 2 udp 2130706431 127.0.0.1 5000 typ host
a=end-of-candidates
m=audio 9 UDP/TLS/RTP/SAVPF 111
c=IN IP4 0.0.0.0
a=setup:actpass
a=mid:1
a=ice-ufrag:cOEMAWBiZZSOUhYO
a=ice-pwd:MgWsEtUzcKCJuyXXRgcewzaZYPUTjAYw
a=rtcp-mux
a=rtcp-rsize
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10;useinbandfec=1
a=rtcp-fb:111 transport-cc 
a=ssrc:889011178 cname:21a580d6-9081-4ace-ba74-3b5400963b50
a=ssrc:889011178 msid:21a580d6-9081-4ace-ba74-3b5400963b50 c663474b-8ff5-4cdd-870e-9ee640afcd25
a=ssrc:889011178 mslabel:21a580d6-9081-4ace-ba74-3b5400963b50
a=ssrc:889011178 label:c663474b-8ff5-4cdd-870e-9ee640afcd25
a=msid:21a580d6-9081-4ace-ba74-3b5400963b50 c663474b-8ff5-4cdd-870e-9ee640afcd25
a=sendonly
m=video 9 UDP/TLS/RTP/SAVPF 96
c=IN IP4 0.0.0.0
a=setup:actpass
a=mid:2
a=ice-ufrag:cOEMAWBiZZSOUhYO
a=ice-pwd:MgWsEtUzcKCJuyXXRgcewzaZYPUTjAYw
a=rtcp-mux
a=rtcp-rsize
a=rtpmap:96 VP8/90000
a=rtcp-fb:96 goog-remb 
a=rtcp-fb:96 transport-cc 
a=rtcp-fb:96 ccm fir
a=rtcp-fb:96 nack 
a=rtcp-fb:96 nack pli
a=ssrc:2992309753 cname:21a580d6-9081-4ace-ba74-3b5400963b50
a=ssrc:2992309753 msid:21a580d6-9081-4ace-ba74-3b5400963b50 ca3e8c31-7c74-4c88-a768-2992fc6bcc12
a=ssrc:2992309753 mslabel:21a580d6-9081-4ace-ba74-3b5400963b50
a=ssrc:2992309753 label:ca3e8c31-7c74-4c88-a768-2992fc6bcc12
a=msid:21a580d6-9081-4ace-ba74-3b5400963b50 ca3e8c31-7c74-4c88-a768-2992fc6bcc12
a=sendonly
 parsed:<nil>} 
[2021-11-28 00:54:49.110] DEBUG default: [rtc.go:332] [ion-sdk-go.(*RTC).negotiate] [S=>C] id=XwYh Negotiate sdp={offer v=0
o=- 7415381412671533942 1638039276 IN IP4 0.0.0.0
s=-
t=0 0
a=fingerprint:sha-256 8D:86:E6:1E:3B:89:CA:60:DE:40:14:96:EF:EB:2F:25:29:73:72:5E:E2:92:A5:F6:20:F2:17:0D:EF:72:B0:3B
a=ice-lite:ice-lite
a=group:BUNDLE 0 1 2
m=application 9 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 0.0.0.0
a=setup:actpass
a=mid:0
a=sendrecv
a=sctp-port:5000
a=ice-ufrag:cOEMAWBiZZSOUhYO
a=ice-pwd:MgWsEtUzcKCJuyXXRgcewzaZYPUTjAYw
a=candidate:2878742611 1 udp 2130706431 127.0.0.1 5000 typ host
a=candidate:2878742611 2 udp 2130706431 127.0.0.1 5000 typ host
a=end-of-candidates
m=audio 9 UDP/TLS/RTP/SAVPF 111
c=IN IP4 0.0.0.0
a=setup:actpass
a=mid:1
a=ice-ufrag:cOEMAWBiZZSOUhYO
a=ice-pwd:MgWsEtUzcKCJuyXXRgcewzaZYPUTjAYw
a=rtcp-mux
a=rtcp-rsize
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10;useinbandfec=1
a=rtcp-fb:111 transport-cc 
a=ssrc:889011178 cname:21a580d6-9081-4ace-ba74-3b5400963b50
a=ssrc:889011178 msid:21a580d6-9081-4ace-ba74-3b5400963b50 c663474b-8ff5-4cdd-870e-9ee640afcd25
a=ssrc:889011178 mslabel:21a580d6-9081-4ace-ba74-3b5400963b50
a=ssrc:889011178 label:c663474b-8ff5-4cdd-870e-9ee640afcd25
a=msid:21a580d6-9081-4ace-ba74-3b5400963b50 c663474b-8ff5-4cdd-870e-9ee640afcd25
a=sendonly
m=video 9 UDP/TLS/RTP/SAVPF 96
c=IN IP4 0.0.0.0
a=setup:actpass
a=mid:2
a=ice-ufrag:cOEMAWBiZZSOUhYO
a=ice-pwd:MgWsEtUzcKCJuyXXRgcewzaZYPUTjAYw
a=rtcp-mux
a=rtcp-rsize
a=rtpmap:96 VP8/90000
a=rtcp-fb:96 goog-remb 
a=rtcp-fb:96 transport-cc 
a=rtcp-fb:96 ccm fir
a=rtcp-fb:96 nack 
a=rtcp-fb:96 nack pli
a=ssrc:2992309753 cname:21a580d6-9081-4ace-ba74-3b5400963b50
a=ssrc:2992309753 msid:21a580d6-9081-4ace-ba74-3b5400963b50 ca3e8c31-7c74-4c88-a768-2992fc6bcc12
a=ssrc:2992309753 mslabel:21a580d6-9081-4ace-ba74-3b5400963b50
a=ssrc:2992309753 label:ca3e8c31-7c74-4c88-a768-2992fc6bcc12
a=msid:21a580d6-9081-4ace-ba74-3b5400963b50 ca3e8c31-7c74-4c88-a768-2992fc6bcc12
a=sendonly
 <nil>} 
[2021-11-28 00:54:49.113]  INFO default: [rtc.go:774] [ion-sdk-go.(*RTC).SendAnswer] [C=>S] [XwYh] sdp={answer v=0
o=- 8076618041328987101 1638039276 IN IP4 0.0.0.0
s=-
t=0 0
a=fingerprint:sha-256 39:56:41:A4:33:AA:83:1B:83:0A:4E:93:00:00:55:49:2D:CD:21:26:3F:4A:C8:AD:CB:1C:1E:04:F1:F9:1C:6D
a=group:BUNDLE 0 1 2
m=application 9 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 0.0.0.0
a=setup:active
a=mid:0
a=sendrecv
a=sctp-port:5000
a=ice-ufrag:egFJZRHuAzhQUcku
a=ice-pwd:nIAoogUFkLtuBodOrejzJvjKGrkALBvS
a=candidate:3763971171 1 udp 2130706431 192.168.0.110 62101 typ host
a=candidate:3763971171 2 udp 2130706431 192.168.0.110 62101 typ host
a=candidate:598822833 1 udp 1694498815 118.179.74.139 59889 typ srflx raddr 0.0.0.0 rport 59889
a=candidate:598822833 2 udp 1694498815 118.179.74.139 59889 typ srflx raddr 0.0.0.0 rport 59889
a=candidate:598822833 1 udp 1694498815 118.179.74.139 56597 typ srflx raddr 0.0.0.0 rport 56597
a=candidate:598822833 2 udp 1694498815 118.179.74.139 56597 typ srflx raddr 0.0.0.0 rport 56597
a=end-of-candidates
m=audio 9 UDP/TLS/RTP/SAVPF 111
c=IN IP4 0.0.0.0
a=setup:active
a=mid:1
a=ice-ufrag:egFJZRHuAzhQUcku
a=ice-pwd:nIAoogUFkLtuBodOrejzJvjKGrkALBvS
a=rtcp-mux
a=rtcp-rsize
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10;useinbandfec=1
a=rtcp-fb:111 transport-cc 
a=recvonly
m=video 9 UDP/TLS/RTP/SAVPF 96
c=IN IP4 0.0.0.0
a=setup:active
a=mid:2
a=ice-ufrag:egFJZRHuAzhQUcku
a=ice-pwd:nIAoogUFkLtuBodOrejzJvjKGrkALBvS
a=rtcp-mux
a=rtcp-rsize
a=rtpmap:96 VP8/90000
a=rtcp-fb:96 goog-remb 
a=rtcp-fb:96 transport-cc 
a=rtcp-fb:96 ccm fir
a=rtcp-fb:96 nack 
a=rtcp-fb:96 nack pli
a=recvonly
 0x140003cdb00} 
[2021-11-28 00:54:49.533] ERROR default: [rtc.go:662] [ion-sdk-go.(*RTC).onSingalHandle] s.OnTrackEvent == nil

[adwpc]

should work now.
try:
uncomment stun config in sfu.toml
comment nat1v1

[real-danm]

I'm curious what the difference is between the onTrack and onTrackEvent? What if I have to use nat1to1 ?

[adwpc]

OnTrack trigger when you receive rtp packet
OnTrackEvent show you more meta info about these tracks

[adwpc]

Seems there is an issue in ion-sdk-go when you using nat1v1. cannot work correctly. but worked when using stun config in sfu.

[VPrikalab]

Any Updates? I have same troubles on ion-sdk-go, can`t connect through nat1v1 and stun