erdnaxe / galene-stream

Gateway to send UDP, RTMP, SRT or RIST streams to Galène videoconference server.
MIT License
24 stars 5 forks source link

VP8 is not working anymore + some error lines #19

Open ynerant opened 10 months ago

ynerant commented 10 months ago

I am trying to use galene-stream v0.6 with Python 3.11.5 and Galène 0.7.2. I run an up-to-date Arch Linux, with gstreamer 1.22.5.

I am running this command:

galene-stream -i rtmp://localhost:1935/live/test -o wss://galene.myserver.eu/ws -g test -u PC --debug

And publishing to the RTMP server using OBS.

When I try to run the server, I am getting two gstreamer errors once the input stream loaded and before the WebRTC session negociated (between "Waiting for incoming stream" and "Setting local description"):

0:00:05.497522029 27907 0x7f1214001450 WARN         audio-resampler audio-resampler.c:274:convert_taps_gint16_c: can't find exact taps
0:00:05.515739311 27907 0x7f1214001220 WARN                  vpxenc gstvpxenc.c:2287:gst_vpx_enc_handle_frame:<vp8enc0> decreasing pts 0:00:00.000000000 previous buffer was 0:00:00.000000000 enforce increasing pts
0:00:05.671909719 27907 0x7f1214001990 WARN                GST_PADS gstpad.c:4361:gst_pad_peer_query:<nicesrc0:src> could not send sticky events

The local and remote SDP can be found below. Please note that the remote SDP does not have any video source, and has a line m=video 0 UDP/TLS/RTP/SAVPF 0 that indicates that video is deactivated.

When the remote SDP is sent, I got a new error:

0:00:05.706262782 27907 0x55d768850340 WARN               webrtcbin gstwebrtcbin.c:6671:_set_description_task:<send> returning error: media 0 is missing or contains an empty 'mid' attribute

Which is consistent to the previous notice.

Here is the full pipeline: pipeline

GST trace log can be downloaded there: trace.log

And then the (redacted) log output:

2023-09-09 18:31:30,779 [asyncio] DEBUG Using selector: EpollSelector
2023-09-09 18:31:30,779 [galene_stream.galene] INFO Connecting to WebSocket
2023-09-09 18:31:30,826 [websockets.client] DEBUG = connection is CONNECTING
2023-09-09 18:31:30,887 [websockets.client] DEBUG > GET /ws HTTP/1.1
2023-09-09 18:31:30,887 [websockets.client] DEBUG > Host: REDACTED
2023-09-09 18:31:30,887 [websockets.client] DEBUG > Upgrade: websocket
2023-09-09 18:31:30,887 [websockets.client] DEBUG > Connection: Upgrade
2023-09-09 18:31:30,887 [websockets.client] DEBUG > Sec-WebSocket-Key: REDACTED
2023-09-09 18:31:30,887 [websockets.client] DEBUG > Sec-WebSocket-Version: 13
2023-09-09 18:31:30,888 [websockets.client] DEBUG > Sec-WebSocket-Extensions: permessage-deflate; client_max_window_bits
2023-09-09 18:31:30,888 [websockets.client] DEBUG > User-Agent: Python/3.11 websockets/10.4
2023-09-09 18:31:30,914 [websockets.client] DEBUG < HTTP/1.1 101 Switching Protocols
2023-09-09 18:31:30,914 [websockets.client] DEBUG < Server: nginx/1.22.1
2023-09-09 18:31:30,914 [websockets.client] DEBUG < Date: Sat, 09 Sep 2023 16:31:30 GMT
2023-09-09 18:31:30,914 [websockets.client] DEBUG < Connection: upgrade
2023-09-09 18:31:30,914 [websockets.client] DEBUG < Upgrade: websocket
2023-09-09 18:31:30,914 [websockets.client] DEBUG < Sec-WebSocket-Accept: REDACTED
2023-09-09 18:31:30,914 [websockets.client] DEBUG < Strict-Transport-Security: max-age=31536000; includeSubDomains
2023-09-09 18:31:30,914 [websockets.client] DEBUG = connection is OPEN
2023-09-09 18:31:30,914 [galene_stream.galene] INFO Handshaking
2023-09-09 18:31:30,914 [websockets.client] DEBUG > TEXT '{"type": "handshake", "version": ["2", "1"], "REDACTED"}' [86 bytes]
2023-09-09 18:31:30,940 [websockets.client] DEBUG < TEXT '{"type":"handshake","version":["2"]}\n' [37 bytes]
2023-09-09 18:31:30,940 [galene_stream.galene] INFO Joining group
2023-09-09 18:31:30,940 [websockets.client] DEBUG > TEXT '{"type": "join", "kind": "join", "group": "REDACTED"…, "password": null}' [85 bytes]
2023-09-09 18:31:30,966 [websockets.client] DEBUG < TEXT '{"type":"joined","kind":"join","username":"REDACTED",,...}]}}\n' [328 bytes]
2023-09-09 18:31:30,966 [websockets.client] DEBUG < TEXT '{"type":"user","kind":"add","id":"REDACTED","present","token"]}\n' [124 bytes]
2023-09-09 18:31:30,966 [websockets.client] DEBUG < TEXT '{"type":"user","kind":"add","id":"REDACTED","present","token"]}\n' [126 bytes]
2023-09-09 18:31:30,966 [websockets.client] DEBUG < TEXT '{"type":"user","kind":"add","id":"REDACTED",…"present","token"]}\n' [129 bytes]
2023-09-09 18:31:30,966 [galene_stream.webrtc] INFO Starting pipeline
2023-09-09 18:31:31,023 [galene_stream.galene] INFO Waiting for incoming stream...
2023-09-09 18:31:33,273 [galene_stream.webrtc] INFO Setting local description
2023-09-09 18:31:33,274 [galene_stream.galene] DEBUG Sending local SDP offer to remote: v=0
o=- 6795048358972891961 0 IN IP4 0.0.0.0
s=-
t=0 0
a=ice-options:trickle
a=group:BUNDLE video0 audio1
m=video 9 UDP/TLS/RTP/SAVPF 97 98
c=IN IP4 0.0.0.0
a=setup:actpass
a=ice-ufrag:R176lJk/04bE4QY+4IwRB3sSKA/2ZXNa
a=ice-pwd:jcpMRGKHODGI/loN42xN8ltau7DXVJ4m
a=rtcp-mux
a=rtcp-rsize
a=sendonly
a=rtpmap:97 VP8/90000
a=rtcp-fb:97 nack
a=rtcp-fb:97 nack pli
a=rtcp-fb:97 ccm fir
a=rtcp-fb:97 transport-cc
a=framerate:30
a=rtpmap:98 rtx/90000
a=fmtp:98 apt=97
a=ssrc-group:FID 3083717338 3577005091
a=ssrc:3083717338 msid:user3012637810@host-796d73ee webrtctransceiver0
a=ssrc:3083717338 cname:user3012637810@host-796d73ee
a=ssrc:3577005091 msid:user3012637810@host-796d73ee webrtctransceiver0
a=ssrc:3577005091 cname:user3012637810@host-796d73ee
a=mid:video0
a=fingerprint:sha-256 D8:1A:1A:74:39:DD:C5:75:B6:B2:8F:44:8E:A0:ED:07:12:89:2D:08:2B:F0:5F:3B:97:6A:A1:49:1B:57:E6:49
a=rtcp-mux-only
m=audio 0 UDP/TLS/RTP/SAVPF 96 99
c=IN IP4 0.0.0.0
a=setup:actpass
a=ice-ufrag:R176lJk/04bE4QY+4IwRB3sSKA/2ZXNa
a=ice-pwd:jcpMRGKHODGI/loN42xN8ltau7DXVJ4m
a=bundle-only
a=rtcp-mux
a=rtcp-rsize
a=sendonly
a=rtpmap:96 OPUS/48000/2
a=rtcp-fb:96 nack
a=rtcp-fb:96 transport-cc
a=fmtp:96 sprop-stereo=1;sprop-maxcapturerate=48000
a=rtpmap:99 rtx/48000
a=fmtp:99 apt=96
a=ssrc-group:FID 1177089590 2117980649
a=ssrc:1177089590 msid:user3012637810@host-796d73ee webrtctransceiver1
a=ssrc:1177089590 cname:user3012637810@host-796d73ee
a=ssrc:2117980649 msid:user3012637810@host-796d73ee webrtctransceiver1
a=ssrc:2117980649 cname:user3012637810@host-796d73ee
a=mid:audio1
a=fingerprint:sha-256 D8:1A:1A:74:39:DD:C5:75:B6:B2:8F:44:8E:A0:ED:07:12:89:2D:08:2B:F0:5F:3B:97:6A:A1:49:1B:57:E6:49
a=rtcp-mux-only

2023-09-09 18:31:33,274 [websockets.client] DEBUG > TEXT '{"type": "offer", "id": "174ec84ba415313daf2817...\\n", "label": "video"}' [2002 bytes]
2023-09-09 18:31:33,277 [galene_stream.galene] DEBUG Sending new ICE candidate to remote
2023-09-09 18:31:33,277 [websockets.client] DEBUG > TEXT '{"type": "ice", "id": "174ec84ba415313daf2817ea...", "sdpMLineIndex": 0}}' [192 bytes]
2023-09-09 18:31:33,277 [galene_stream.galene] DEBUG Sending new ICE candidate to remote
2023-09-09 18:31:33,278 [websockets.client] DEBUG > TEXT '{"type": "ice", "id": "174ec84ba415313daf2817ea...", "sdpMLineIndex": 0}}' [203 bytes]
2023-09-09 18:31:33,278 [galene_stream.galene] DEBUG Sending new ICE candidate to remote
2023-09-09 18:31:33,278 [websockets.client] DEBUG > TEXT '{"type": "ice", "id": "174ec84ba415313daf2817ea...", "sdpMLineIndex": 0}}' [208 bytes]
2023-09-09 18:31:33,278 [galene_stream.galene] DEBUG Sending new ICE candidate to remote
2023-09-09 18:31:33,278 [websockets.client] DEBUG > TEXT '{"type": "ice", "id": "174ec84ba415313daf2817ea...", "sdpMLineIndex": 0}}' [166 bytes]
2023-09-09 18:31:33,278 [galene_stream.galene] DEBUG Sending new ICE candidate to remote
2023-09-09 18:31:33,278 [websockets.client] DEBUG > TEXT '{"type": "ice", "id": "174ec84ba415313daf2817ea...", "sdpMLineIndex": 0}}' [177 bytes]
2023-09-09 18:31:33,279 [galene_stream.galene] DEBUG Sending new ICE candidate to remote
2023-09-09 18:31:33,279 [websockets.client] DEBUG > TEXT '{"type": "ice", "id": "174ec84ba415313daf2817ea...", "sdpMLineIndex": 0}}' [182 bytes]
2023-09-09 18:31:33,279 [galene_stream.galene] DEBUG Sending new ICE candidate to remote
2023-09-09 18:31:33,279 [websockets.client] DEBUG > TEXT '{"type": "ice", "id": "174ec84ba415313daf2817ea...", "sdpMLineIndex": 0}}' [178 bytes]
2023-09-09 18:31:33,279 [galene_stream.galene] DEBUG Sending new ICE candidate to remote
2023-09-09 18:31:33,279 [websockets.client] DEBUG > TEXT '{"type": "ice", "id": "174ec84ba415313daf2817ea...", "sdpMLineIndex": 0}}' [189 bytes]
2023-09-09 18:31:33,280 [galene_stream.galene] DEBUG Sending new ICE candidate to remote
2023-09-09 18:31:33,280 [websockets.client] DEBUG > TEXT '{"type": "ice", "id": "174ec84ba415313daf2817ea...", "sdpMLineIndex": 0}}' [194 bytes]
2023-09-09 18:31:33,302 [websockets.client] DEBUG < TEXT '{"type":"answer","id":"174ec84ba415313daf2817ea...\\na=recvonly\\r\\n"}\n' [687 bytes]
2023-09-09 18:31:33,302 [galene_stream.galene] DEBUG Receiving SDP from remote: v=0
o=- 5233890902212268019 1694277093 IN IP4 0.0.0.0
s=-
t=0 0
a=fingerprint:sha-256 89:DB:0E:3A:BD:A7:C5:5F:9E:C4:57:56:78:1B:B7:61:00:3D:2E:6E:18:16:03:61:81:75:25:D7:47:D3:D3:6F
a=group:BUNDLE audio1
m=video 0 UDP/TLS/RTP/SAVPF 0
c=IN IP4 0.0.0.0
m=audio 9 UDP/TLS/RTP/SAVPF 96
c=IN IP4 0.0.0.0
a=setup:active
a=mid:audio1
a=ice-ufrag:eZBHQAiZMpZbaYrK
a=ice-pwd:GPWuJPKHwTYitNuJwyHLSsMSgstmzXvV
a=rtcp-mux
a=rtcp-rsize
a=rtpmap:96 OPUS/48000/2
a=fmtp:96 sprop-stereo=1;sprop-maxcapturerate=48000
a=rtcp-fb:96 nack 
a=rtcp-fb:96 transport-cc 
a=recvonly

2023-09-09 18:31:33,302 [galene_stream.webrtc] INFO Setting remote session description
2023-09-09 18:31:33,304 [websockets.client] DEBUG < TEXT '{"type":"ice","id":"174ec84ba415313daf2817ea2e3...rnameFragment":null}}\n' [204 bytes]
2023-09-09 18:31:33,304 [websockets.client] DEBUG < TEXT '{"type":"ice","id":"174ec84ba415313daf2817ea2e3...rnameFragment":null}}\n' [214 bytes]
2023-09-09 18:31:33,304 [websockets.client] DEBUG < TEXT '{"type":"ice","id":"174ec84ba415313daf2817ea2e3...rnameFragment":null}}\n' [200 bytes]
2023-09-09 18:31:33,304 [websockets.client] DEBUG < TEXT '{"type":"ice","id":"174ec84ba415313daf2817ea2e3...rnameFragment":null}}\n' [201 bytes]
2023-09-09 18:31:33,304 [websockets.client] DEBUG < TEXT '{"type":"ice","id":"174ec84ba415313daf2817ea2e3...rnameFragment":null}}\n' [231 bytes]
2023-09-09 18:31:33,305 [websockets.client] DEBUG < TEXT '{"type":"ice","id":"174ec84ba415313daf2817ea2e3...rnameFragment":null}}\n' [231 bytes]
2023-09-09 18:31:33,305 [websockets.client] DEBUG < TEXT '{"type":"ice","id":"174ec84ba415313daf2817ea2e3...rnameFragment":null}}\n' [229 bytes]
2023-09-09 18:31:33,305 [websockets.client] DEBUG < TEXT '{"type":"ice","id":"174ec84ba415313daf2817ea2e3...rnameFragment":null}}\n' [235 bytes]
2023-09-09 18:31:33,305 [galene_stream.galene] DEBUG Receiving new ICE candidate from remote
2023-09-09 18:31:33,305 [galene_stream.galene] DEBUG Receiving new ICE candidate from remote
2023-09-09 18:31:33,305 [galene_stream.galene] DEBUG Receiving new ICE candidate from remote
2023-09-09 18:31:33,305 [galene_stream.galene] DEBUG Receiving new ICE candidate from remote
2023-09-09 18:31:33,305 [galene_stream.galene] DEBUG Receiving new ICE candidate from remote
2023-09-09 18:31:33,305 [galene_stream.galene] DEBUG Receiving new ICE candidate from remote
2023-09-09 18:31:33,305 [galene_stream.galene] DEBUG Receiving new ICE candidate from remote
2023-09-09 18:31:33,305 [galene_stream.galene] DEBUG Receiving new ICE candidate from remote
2023-09-09 18:31:33,306 [websockets.client] DEBUG < TEXT '{"type":"ice","id":"174ec84ba415313daf2817ea2e3...rnameFragment":null}}\n' [204 bytes]
2023-09-09 18:31:33,306 [websockets.client] DEBUG < TEXT '{"type":"ice","id":"174ec84ba415313daf2817ea2e3...rnameFragment":null}}\n' [201 bytes]
2023-09-09 18:31:33,306 [websockets.client] DEBUG < TEXT '{"type":"ice","id":"174ec84ba415313daf2817ea2e3...rnameFragment":null}}\n' [202 bytes]
2023-09-09 18:31:33,306 [websockets.client] DEBUG < TEXT '{"type":"ice","id":"174ec84ba415313daf2817ea2e3...rnameFragment":null}}\n' [218 bytes]
2023-09-09 18:31:33,306 [galene_stream.galene] DEBUG Receiving new ICE candidate from remote
2023-09-09 18:31:33,306 [galene_stream.galene] DEBUG Receiving new ICE candidate from remote
2023-09-09 18:31:33,306 [galene_stream.galene] DEBUG Receiving new ICE candidate from remote
2023-09-09 18:31:33,306 [galene_stream.galene] DEBUG Receiving new ICE candidate from remote
2023-09-09 18:31:33,365 [galene_stream.galene] DEBUG Sending new ICE candidate to remote
2023-09-09 18:31:33,365 [websockets.client] DEBUG > TEXT '{"type": "ice", "id": "174ec84ba415313daf2817ea...", "sdpMLineIndex": 0}}' [205 bytes]
2023-09-09 18:31:33,366 [galene_stream.galene] DEBUG Sending new ICE candidate to remote
2023-09-09 18:31:33,366 [websockets.client] DEBUG > TEXT '{"type": "ice", "id": "174ec84ba415313daf2817ea...", "sdpMLineIndex": 0}}' [214 bytes]
2023-09-09 18:31:33,367 [galene_stream.galene] DEBUG Sending new ICE candidate to remote
2023-09-09 18:31:33,367 [websockets.client] DEBUG > TEXT '{"type": "ice", "id": "174ec84ba415313daf2817ea...", "sdpMLineIndex": 0}}' [195 bytes]
2023-09-09 18:31:33,388 [galene_stream.galene] DEBUG Sending new ICE candidate to remote
2023-09-09 18:31:33,389 [websockets.client] DEBUG > TEXT '{"type": "ice", "id": "174ec84ba415313daf2817ea...", "sdpMLineIndex": 0}}' [199 bytes]
^C2023-09-09 18:31:40,366 [galene_stream.galene] INFO Closing WebSocket connection
2023-09-09 18:31:40,367 [galene_stream.webrtc] INFO Closing pipeline
0:00:09.639620392 transmission on unparented target pad rtpvp8pay0_src -> ''_''
0:00:09.639706128 transmission on unparented target pad rtpopuspay0_src -> ''_''

(python:27158): libnice-WARNING **: 18:31:40.436: Agent 0x5558a7be0280 : We still have alive TURN refreshes. Consider using nice_agent_close_async() to prune them before releasing the agent.
2023-09-09 18:31:40,441 [websockets.client] DEBUG = connection is CLOSING
2023-09-09 18:31:40,441 [websockets.client] DEBUG > CLOSE 1000 (OK) [2 bytes]
2023-09-09 18:31:40,467 [websockets.client] DEBUG < CLOSE 1000 (OK) [2 bytes]
2023-09-09 18:31:40,469 [websockets.client] DEBUG = connection is CLOSED

OBS can't be the cause of that, I tried to replace the pipeline with:

webrtcbin name=send bundle-policy=max-bundle
videotestsrc ! videoconvert ! vp8enc deadline=1 target-bitrate=1048576 ! rtpvp8pay pt=97 ! send.
audiotestsrc ! audioconvert ! audioresample ! opusenc ! rtpopuspay pt=96 ! send.

And it does not change anything, and I don't see nor hear anything on Galène.

If I try to deactivate the video stream from the pipeline, then the two first error lines are still there, but the WebRTC negociation is working and sound is transmitted. But, an error line is spamming the output console:

rtpsession gstrtpsession.c:2435:gst_rtp_session_chain_send_rtp_common:<rtpsession0> Can't determine running time for this packet without knowing configured latency

And one strange thing: if I am using VP9 instead of VP8 (replacing vp8enc by vp9enc and rtpvp8pay by rtpvp9pay), then the video stream is working (but with a very strong CPU usage), but the error lines are still there.

I also tested the same versions under Ubuntu.

Is there something broken with the newest versions of Gstreamer? Or did I make something wrong?

erdnaxe commented 10 months ago

I believe that you are using Galène on master branch which disables VP8: https://github.com/jech/galene/commit/69445d67f5a05c4d1eeedad041373ca75199bdea#diff-2b7814d3fca2e99e56c51b6ff2aa313ea6e9da6424804240aa8ad891fdfe0900L173

Can you try to add ["vp8", "opus"] to your Galène group codecs?