WebRTC to RTP - Streaming stops with error Internal data flow error when we connect RTP endpoint to composite during ongoing WebRTC streaming

gharia commented 4 years ago

KMS Version:

Kurento Media Server version: 6.12.0 Found modules: 'core' version 6.12.0 'elements' version 6.12.0 'filters' version 6.12.0

Ubuntu Version

No LSB modules are available. Distributor ID: Ubuntu Description: Ubuntu 16.04.6 LTS Release: 16.04 Codename: xenial

Other libraries versions:

ii  gstreamer1.5-libav:amd64             1.8.1-1kurento1.16.04                      amd64        libav plugin for GStreamer
ii  gstreamer1.5-nice:amd64              0.1.15-1kurento3.16.04                     amd64        ICE library (GStreamer 1.5 plugin)
ii  gstreamer1.5-plugins-bad:amd64       1.8.1-1kurento4.16.04                      amd64        GStreamer plugins from the "bad" set
ii  gstreamer1.5-plugins-base:amd64      1.8.1-1kurento1.16.04                      amd64        GStreamer plugins from the "base" set
ii  gstreamer1.5-plugins-good:amd64      1.8.1-1kurento2.16.04                      amd64        GStreamer plugins from the "good" set
ii  gstreamer1.5-plugins-ugly:amd64      1.8.1-1kurento1.16.04                      amd64        GStreamer plugins from the "ugly" set
ii  gstreamer1.5-pulseaudio:amd64        1.8.1-1kurento2.16.04                      amd64        GStreamer plugin for PulseAudio
ii  gstreamer1.5-x:amd64                 1.8.1-1kurento1.16.04                      amd64        GStreamer plugins for X11 and Pango
ii  kms-core                             6.12.0-0kurento1.16.04                     amd64        Kurento Core module
ii  kms-elements                         6.12.0-0kurento1.16.04                     amd64        Kurento Elements module
ii  kms-filters                          6.12.0-0kurento1.16.04                     amd64        Kurento Filters module
ii  kms-jsonrpc                          6.12.0-0kurento1.16.04                     amd64        Kurento JSON-RPC library
ii  kmsjsoncpp                           1.6.3-1kurento1.16.04                      amd64        Kurento jsoncpp library
ii  kurento-media-server                 6.12.0-0kurento1.16.04                     amd64        Kurento Media Server
ii  libgstreamer-plugins-bad1.5-0:amd64  1.8.1-1kurento4.16.04                      amd64        GStreamer development files for libraries from the "bad" set
ii  libgstreamer-plugins-base1.5-0:amd64 1.8.1-1kurento1.16.04                      amd64        GStreamer libraries from the "base" set
ii  libgstreamer1.5-0:amd64              1.8.1-1kurento2.16.04                      amd64        Core GStreamer libraries and elements
ii  libnice10:amd64                      0.1.15-1kurento3.16.04                     amd64        ICE library (shared library)
ii  libsrtp0:amd64                       1.6.0-0kurento1.16.04                      amd64        Secure RTP (SRTP) and UST Reference Implementations - shared library
ii  libusrsctp                           0.9.2-1kurento1.16.04                      amd64        sctp-refimpl library
ii  openh264                             1.4.0-1kurento1.16.04                      amd64        OpenH264 library
ii  openh264-gst-plugins-bad-1.5:amd64   1.8.1-1kurento4.16.04                      amd64        GStreamer plugins from openh264
ii  openwebrtc-gst-plugins               0.10.0-1kurento1.16.04                     amd64        OpenWebRTC specific GStreamer plugins

Client libraries

Language: Java
Version: 1.8 (6.12 client library version)

Browsers tested Not applicable. Actually fails on each browser as streaming stops

System description:

Everything is on same server. Kurento, Coturn and application server

KMS location:/usr/bin/kurento-media-server
KMS service file location: /lib/systemd/system/kurento-media-server.service
TURN server: Coturn server, version 4.5.0.3

What steps will reproduce the problem?

Create Setup for WebRTC to RTP streaming. One can use hello-world
Start WebRTC (many to many where the remote peer is in receive-only mode) and connect WebRtcEndpoint to RecorderEndpoint and to HubPort of composite
Now keep broadcasting (streaming) and during ongoing streaming connect RTP to WebRTC, by creating RtpEndpoint and connecting it to a HubPort of the same composite (need to do SDP negotiation on RTP first)
While the WebRTC streaming is going on and at the same time if you connect RtpEndpoint, there will be Internal data flow error and streaming will stop for a few seconds. And eventually, it crashes/disconnecting everyone from application server (which uses kms java client library)

What is the expected result? There should not be Internal data flow error and the streaming should not pause/stop if during ongoing streaming we connect RtpEndpoint to composite (which is connected to WebRtcEndpoint)

What happens instead? It stops streaming for a few seconds. And if this occurs regularly (RTP connects while ongoing WebRTC streaming), like 10 times in 1 minute, then eventually it crashes the application server and/or kurento and we need to restart both of them.

Does it happen with one of the tutorials? Have not tested with tutorial

Please provide any additional information below Following are the logs when the mentioned scenario occurs:

2019-11-15T15:26:28,408330 13534 0x00007f47dc816700 warning basesrc                   gstbasesrc.c:2948 gst_base_src_loop() <audiotestsrc109>  error: Internal data flow error.
2019-11-15T15:26:28,408387 13534 0x00007f47dc816700 warning basesrc                   gstbasesrc.c:2948 gst_base_src_loop() <audiotestsrc109>  error: streaming task paused, reason not-linked (-1)
2019-11-15T15:26:28,410894 13534 0x00007f4ad43e3240   error KurentoMediaPipelineImpl  MediaPipelineImpl.cpp:69 processBusMessage()  Error code 1: 'Internal data flow error.', element: audiotestsrc109, parent: pipeline0
2019-11-15T15:26:28,410950 13534 0x00007f4ad43e3240   error KurentoMediaPipelineImpl  MediaPipelineImpl.cpp:72 processBusMessage()  Debugging info: gstbasesrc.c(2948): gst_base_src_loop (): /GstPipeline:pipeline0/KmsCompositeMixer:kmscompositemixer0/KmsAudioMixer:kmsaudiomixer0/GstAudioTestSrc:audiotestsrc109:
streaming task paused, reason not-linked (-1)

gharia commented 4 years ago

Even sometimes I observe the Internal data flow error when no RTP endpoint is connecting. It is intermittent. @igracia @j1elo I would appreciate it if you can give some hints regarding how can I fix this.

j1elo commented 4 years ago

Judging by the logs, the error is raised from the audiotestsrc element, and "streaming task paused, reason not-linked" makes me think that the problem happens in this link: https://github.com/Kurento/kms-core/blob/dee9f41c4f2a0b0ba45d0233f3c7d149f02c0007/src/gst-plugins/kmsaudiomixer.c#L845

You might want to print some debug info around there to have a clearer picture of what is going on. The audiotestsrc connects with a capsfilter, so I guess the caps are being changed in an incompatible way when the new endpoint is connected.

You could also increment the debug level for audiotestsrc, maybe also basesrc; probably there is some useful information in there: https://doc-kurento.readthedocs.io/en/latest/features/logging.html#logging-levels-and-components

You would set something like

export GST_DEBUG="${GST_DEBUG:-3},audiotestsrc:5,basesrc:5"

in /etc/default/kurento-media-server

gharia commented 4 years ago

Hey @j1elo ,

As you are aware, from our discussion on the Google group at https://groups.google.com/d/msg/kurento/fOj3iO1kycc/uoxCGMtfBAAJ, I am testing the new pipeline setup with DispatcherOneToMany. Not sure it is related, but this bug re-surfaced during testing.

Description:

Few consumers (4-6) are connected on WebRtc from Chrome and Firefox
One RTP client connected from a utility (jar file)
A presenter/broadcaster joins in and starts audio broadcasting (We have only audio). Up to this point no issue.
But as soon as another presenter/broadcaster joins in, the streaming stops for almost 3-5 minutes and after that, it resumes from both the presenters

Following is out overall pipeline:

Presenters' WebRTCEndpoint > Composite > DispatcherOneToMany > Listeners' WebRTCEndpoint( (which includes both WebRTC and RTP consumers)

SDP offer from WebRtc consumer (from chrome):

v=0
o=- 4319769343296506756 2 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE 0
a=msid-semantic: WMS
m=audio 9 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126
c=IN IP4 0.0.0.0
a=rtcp:9 IN IP4 0.0.0.0
a=ice-ufrag:P2Vt
a=ice-pwd:frbpQ97aOR73A45kahgReoYR
a=ice-options:trickle
a=fingerprint:sha-256 4B:41:CA:CB:4A:27:02:31:48:7F:7A:E1:6B:2D:04:94:E2:A4:A7:4E:D8:36:A2:E2:2F:84:DE:E1:F2:70:4A:32
a=setup:actpass
a=mid:0
a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level
a=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
a=extmap:3 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01
a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:mid
a=extmap:5 urn:ietf:params:rtp-hdrext:sdes:rtp-stream-id
a=extmap:6 urn:ietf:params:rtp-hdrext:sdes:repaired-rtp-stream-id
a=recvonly
a=rtcp-mux
a=rtpmap:111 opus/48000/2
a=rtcp-fb:111 transport-cc
a=fmtp:111 minptime=10;useinbandfec=1
a=rtpmap:103 ISAC/16000
a=rtpmap:104 ISAC/32000
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:106 CN/32000
a=rtpmap:105 CN/16000
a=rtpmap:13 CN/8000
a=rtpmap:110 telephone-event/48000
a=rtpmap:112 telephone-event/32000
a=rtpmap:113 telephone-event/16000
a=rtpmap:126 telephone-event/8000

SDP offer sent from RTP client/consumer (from jar utility):

v=0
t=0 0
m=audio 8978 RTP/AVP 98
c=IN IP4 192.168.2.4
a=recvonly
a=rtpmap:98 opus/48000/2
a=fmtp:98 stereo=0; sprop-stereo=0; useinbandfec=1

Logs:

I have added listeners to the endpoints in our application server code. Following are the logs from those listeners:

17:58:12.706 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t451] INFO  com.benzinga.PresenterSession - [Broadcaster-WebRtcEndpoint::ConnectionStateChanged] source: 59de01ae-b4e2-4b5b-9c49-5a9bb0b31f32_kurento.MediaPipeline/877d6977-f27c-4c23-8cc8-3cc872f75b82_kurento.WebRtcEndpoint, timestamp: 1578679092, tags: [], oldState: DISCONNECTED, newState: CONNECTED
17:58:12.752 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t451] INFO  com.benzinga.PresenterSession - [Broadcaster-WebRtcEndpoint::MediaFlowOutStateChange] source: 59de01ae-b4e2-4b5b-9c49-5a9bb0b31f32_kurento.MediaPipeline/877d6977-f27c-4c23-8cc8-3cc872f75b82_kurento.WebRtcEndpoint, timestamp: 1578679092, tags: [], state: FLOWING, padName: default, mediaType: AUDIO
17:58:12.795 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t452] INFO  com.benzinga.PresenterSession - [Broadcaster-WebRtcEndpoint::MediaTranscodingStateChange] source: 59de01ae-b4e2-4b5b-9c49-5a9bb0b31f32_kurento.MediaPipeline/877d6977-f27c-4c23-8cc8-3cc872f75b82_kurento.WebRtcEndpoint, timestamp: 1578679092, tags: [], state: TRANSCODING, binName: kmsagnosticbin2-673, mediaType: AUDIO
17:58:13.486 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t452] INFO  com.benzinga.PresenterSession - [Broadcaster-WebRtcEndpoint::MediaStateChanged] source: 59de01ae-b4e2-4b5b-9c49-5a9bb0b31f32_kurento.MediaPipeline/877d6977-f27c-4c23-8cc8-3cc872f75b82_kurento.WebRtcEndpoint, timestamp: 1578679093, tags: [], oldState: DISCONNECTED, newState: CONNECTED
17:58:16.714 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t452] INFO  com.benzinga.PresenterSession - [Broadcaster-WebRtcEndpoint::MediaFlowOutStateChange] source: 59de01ae-b4e2-4b5b-9c49-5a9bb0b31f32_kurento.MediaPipeline/877d6977-f27c-4c23-8cc8-3cc872f75b82_kurento.WebRtcEndpoint, timestamp: 1578679096, tags: [], state: NOT_FLOWING, padName: default, mediaType: AUDIO
18:02:50.058 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t456] INFO  com.benzinga.PresenterSession - [Broadcaster-WebRtcEndpoint::MediaFlowOutStateChange] source: 59de01ae-b4e2-4b5b-9c49-5a9bb0b31f32_kurento.MediaPipeline/877d6977-f27c-4c23-8cc8-3cc872f75b82_kurento.WebRtcEndpoint, timestamp: 1578679370, tags: [], state: FLOWING, padName: default, mediaType: AUDIO

As you can see in the above logs, it took almost 5 minutes from NOT_FLOWING (log 17:58:16.714) to FLOWING (log 18:02:50.058).

I have attached the respective kurento logs generated at that time.

kurento.log

Am I stuck with transcoding? I appreciate it if you can point me in the right direction.

Thanks

Kurento / bugtracker

WebRTC to RTP - Streaming stops with error Internal data flow error when we connect RTP endpoint to composite during ongoing WebRTC streaming #412