search

DDVTECH / mistserver

The official mistserver source repository - www.mistserver.com
The Unlicense
383 stars 133 forks source link

Unusable TSSRT - multiple streams over one port #174

Closed Taiwan22 closed 1 year ago

Taiwan22 commented 1 year ago

Hello, I’m looking for a good streaming server with a quality SRT implementation. I decided to try your open-source server. SRT itself works quite well. But there is one BIG problem. I don’t know if it’s supposed to be like this, or if it’s some bug.

The problem is that when I try to broadcast multiple SRT streams over one port, when ONE stream ends, it restarts ALL the other streams. I tried everything. Setting up through “Protocols”, creating a separate SRT push stream, separate input and output ports. But the problem is the same.

It seems the problem is mostly when one stream is closed due to inactivity.

Here is LOG where inactivity of "cam2" caused to end also "cam1"

Mon 15 May 2023, 22:25:16 | HIGH | Angel process for cam2 exiting Mon 15 May 2023, 22:25:16 | ERROR | Overwriting old page for MstSTATEcam2 Mon 15 May 2023, 22:25:16 | INFO | Input for stream cam2 shut down cleanly Mon 15 May 2023, 22:25:16 | HIGH | Done waiting for child for stream cam2 Mon 15 May 2023, 22:25:16 | HIGH | Received signal Child exited (17) from process 3017304 Mon 15 May 2023, 22:25:16 | HIGH | Angel process for cam1 exiting Mon 15 May 2023, 22:25:16 | ERROR | Overwriting old page for MstSTATEcam1 Mon 15 May 2023, 22:25:16 | INFO | Input for stream cam1 shut down cleanly Mon 15 May 2023, 22:25:16 | HIGH | Done waiting for child for stream cam1 Mon 15 May 2023, 22:25:16 | HIGH | Received signal Child exited (17) from process 3017242 Mon 15 May 2023, 22:25:16 | INFO | Input closing clean, reason: source disconnected for non-resumable stream Mon 15 May 2023, 22:25:16 | MEDIUM | Valid tracks count changed from 2 to 0 Mon 15 May 2023, 22:25:16 | INFO | Should remove track 1 Mon 15 May 2023, 22:25:16 | INFO | Disconnected track 1 Mon 15 May 2023, 22:25:16 | INFO | Should remove track 0 Mon 15 May 2023, 22:25:16 | INFO | Disconnected track 0 Mon 15 May 2023, 22:25:16 | HIGH | Closing thread for socket -1 Mon 15 May 2023, 22:25:16 | WARN | Dropping input track 0: disconnect request from buffer Mon 15 May 2023, 22:25:16 | MEDIUM | disconnect Mon 15 May 2023, 22:25:16 | HIGH | Socket 17 closed Mon 15 May 2023, 22:25:16 | INFO | Client handler shutting down, exit reason: set inactive Mon 15 May 2023, 22:25:16 | INFO | Exit reason: signal Terminated (15) from process 3017304 Mon 15 May 2023, 22:25:16 | HIGH | Closing thread for socket -1 Mon 15 May 2023, 22:25:16 | MEDIUM | disconnect Mon 15 May 2023, 22:25:16 | HIGH | Socket 4 closed Mon 15 May 2023, 22:25:16 | INFO | Client handler shutting down, exit reason: set inactive Mon 15 May 2023, 22:25:16 | INFO | Received signal Terminated (15) from process 3017304 Mon 15 May 2023, 22:25:16 | INFO | Input closing clean, reason: no activity for 30 seconds

Sometimes when I stop one stream, the second one is working, but when I try to start the first stream again, it restarts both... 

Hope this helps to solve it.

Rokamun commented 1 year ago

Hey there,

Thanks for the report! I can confirm I'm seeing it happen as well, and no it's not supposed to. I think we're accidentally closing the entire port instead just the streamID one. We'll have a look at it.

Rokamun commented 1 year ago

Hey,

Thanks for the patience, it should be fixed in the development builds together with several other tweaks!

cac86fff575b5eceee8ad4c4edf2673aa32c7ed6

Is the commit specifically

Taiwan22 commented 1 year ago

Hi, I've tested the development branch, and the issue seems to persist. I hope i did it right. My version shows: 3.2-4-gcac86fff Generic_64

My test setup is: MistServer: Protocols: HTTP, HLS, RTMP, TS over SRT Streams: camtest and camtest1 - both just push://, buffer: 5000, Maximum live keep...:5000, Resume support: Disabled

Larix(android) camtest SRT ---> MistServer ---> OBS SRT input camtest and RTMP input camtest ---> OBS broadcast SRT camtest1 ---> MistServer ---> VLC SRT input camtest1

And when i stop OBS broadcast it shuts down both streams.

[2023-06-08 20:15:50] MistInBuffer:camtest1 (3303741) INFO: Disconnected track 0 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:477) [2023-06-08 20:15:50] MistInBuffer:camtest1 (3303741) INFO: Should remove track 0 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:317) [2023-06-08 20:15:50] MistInBuffer:camtest1 (3303741) INFO: Disconnected track 1 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:477) [2023-06-08 20:15:50] MistOutTSSRT:camtest1 (3303612) WARN: Dropping H264 track 0@k7 (nextP=4294967295, lastP=4): disappeared from metadata (/home/MistDEV/mistserver/src/output/output.cpp:1884) [2023-06-08 20:15:50] MistInBuffer:camtest1 (3303741) INFO: Should remove track 1 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:317) [2023-06-08 20:15:50] MistInBuffer:camtest1 (3303741) INFO: Input closing clean, reason: source disconnected for non-resumable stream (/home/MistDEV/mistserver/src/input/input.cpp:774) [2023-06-08 20:15:50] MistOutTSSRT (3303612) INFO: Received signal Terminated (15) from process 3303741 (/home/MistDEV/mistserver/lib/config.cpp:612) [2023-06-08 20:15:50] MistOutTSSRT:camtest (3303612) INFO: Client handler shutting down, exit reason: set inactive (/home/MistDEV/mistserver/src/output/output.cpp:1795) [2023-06-08 20:15:50] MistOutTSSRT:camtest (3303612) INFO: Client handler shutting down, exit reason: set inactive (/home/MistDEV/mistserver/src/output/output.cpp:1795) [2023-06-08 20:15:50] MistOutTSSRT (3303612) INFO: Exit reason: signal Terminated (15) from process 3303741 (/home/MistDEV/mistserver/src/output/output_tssrt.cpp:516) [2023-06-08 20:15:50] MistOutTSSRT:camtest1 (3303612) INFO: Client handler shutting down, exit reason: set inactive (/home/MistDEV/mistserver/src/output/output.cpp:1795) [2023-06-08 20:15:51] MistInBuffer:camtest (3303731) INFO: Disconnected track 0 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:477) [2023-06-08 20:15:51] MistInBuffer:camtest (3303731) INFO: Should remove track 0 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:317) [2023-06-08 20:15:51] MistInBuffer:camtest (3303731) INFO: Disconnected track 1 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:477) [2023-06-08 20:15:51] MistInBuffer:camtest (3303731) INFO: Should remove track 1 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:317) [2023-06-08 20:15:51] MistOutRTMP:camtest (3303735) WARN: Dropping AAC track 1@k29 (nextP=4294967295, lastP=0): disappeared from metadata (/home/MistDEV/mistserver/src/output/output.cpp:1884) [2023-06-08 20:15:51] MistOutRTMP:camtest (3303735) WARN: Dropping H264 track 0@k30 (nextP=4294967295, lastP=24): disappeared from metadata (/home/MistDEV/mistserver/src/output/output.cpp:1884) [2023-06-08 20:15:51] MistOutRTMP:camtest (3303735) INFO: Buffer completely played out (/home/MistDEV/mistserver/src/output/output.cpp:1949) [2023-06-08 20:15:51] MistOutRTMP:camtest (3303735) INFO: Client handler shutting down, exit reason: end of stream (/home/MistDEV/mistserver/src/output/output.cpp:1795) [2023-06-08 20:15:51] MistInBuffer:camtest (3303731) INFO: Input closing clean, reason: source disconnected for non-resumable stream (/home/MistDEV/mistserver/src/input/input.cpp:774) [2023-06-08 20:15:51] MistOutRTMP:camtest (3303735) INFO: Exit reason: end of stream (/home/MistDEV/mistserver/src/output/mist_out.cpp:73) [2023-06-08 20:15:51] MistInBuffer:camtest (3303730) INFO: Input for stream camtest shut down cleanly (/home/MistDEV/mistserver/src/input/input.cpp:529) [2023-06-08 20:15:51] MistInBuffer:camtest (3303730) ERROR: Overwriting old page for MstSTATEcamtest (/home/MistDEV/mistserver/lib/shared_memory.cpp:494) [2023-06-08 20:15:51] MistInBuffer:camtest1 (3303740) INFO: Input for stream camtest1 shut down cleanly (/home/MistDEV/mistserver/src/input/input.cpp:529) [2023-06-08 20:15:51] MistInBuffer:camtest1 (3303740) ERROR: Overwriting old page for MstSTATEcamtest1 (/home/MistDEV/mistserver/lib/shared_memory.cpp:494) [2023-06-08 20:15:51] MistController (3303550) INFO: Stream camtest became inactive (/home/MistDEV/mistserver/src/controller/controller_statistics.cpp:169) [2023-06-08 20:15:51] MistController (3303550) INFO: Stream camtest1 became inactive (/home/MistDEV/mistserver/src/controller/controller_statistics.cpp:169) [2023-06-08 20:15:54] MistController (3303550) CONF: Starting connector: {"acceptable":"0","connector":"TSSRT","port":10080}

Rokamun commented 1 year ago

Hmm, could you do a check if there were any MistServer processes still active from the previous build? This is behaviour I'd expect from the development build before the patch.

I've tried replicating the setup, though I did use a different input for SRT than Larix (I used gstreamer), though considering the problem seems to be in MistServer closing down the connections I doubt that's going to be impactful.

I've got a gstreamer script generating a SRT feed pushing it into MistServer using Port 8889 and streamname cam1 (gstreamer -- SRT --> Mistserver (cam1) )

OBS then pulls this stream (through SRT using port 8889 and RTMP). Then pushes this to stream cam2 (MistServer -- SRT + RTMP --> OBS (mix srt+rtmp input) -- SRT --> MistServer (cam2) )

That is the same as what you're doing as far as I've understood it. The log is at the bottom.

What I'm seeing is cam1 being unaffected whether i stop the OBS push or not..

This is all cac86fff575b5eceee8ad4c4edf2673aa32c7ed6 as well, the usual suspect is an older process still being active so the update hasn't happened yet.

You could also try downloading the development build from our build system and see if that works differently for you: https://r.mistserver.org/dl/mistserver_64Vdev.tar.gz

An alternative/work around is to setup 2 SRT ports, one for incoming streams and one for outgoing. This does speed up the SRT process in general so it's not a bad method. It doesn't solve the bug you're experiencing though.

The changes would be adding another TS over SRT protocol in the protocol panel and setting this to only allow outgoing streams. Then set your original one to only incoming streams.

LOG:

++START CAM1 PUSH HERE++

[2023-06-09 12:35:28] MistOutTSSRT (28099) INFO: Accepted a socket coming from 127.0.0.1 (../lib/socket_srt.cpp:544)
[2023-06-09 12:35:29] MistOutTSSRT:cam1 (28099) INFO: Connection put into ingest mode (../src/output/output_tssrt.cpp:73)
[2023-06-09 12:35:29] MistOutTSSRT:cam1 (28099) INFO: Waiting for cam1 buffer to be ready... (0) (../src/output/output.cpp:2420)
[2023-06-09 12:35:29] MistOutTSSRT:cam1 (28099) INFO: Reconnecting to cam1 buffer... (0) (../src/output/output.cpp:2424)
[2023-06-09 12:35:29] MistOutTSSRT:cam1 (28149) INFO: Starting /home/warpstar/DMS/build/MistInBuffer -s cam1 push://  (../lib/stream.cpp:633)
[2023-06-09 12:35:29] MistInBuffer:cam1 (28149) INFO: Input booting (../src/input/input.cpp:353)
[2023-06-09 12:35:29] MistInBuffer:cam1 (28150) ERROR: Overwriting old page for MstSTATEcam1 (../lib/shared_memory.cpp:494)
[2023-06-09 12:35:29] MistInBuffer:cam1 (28150) INFO: Starting serve (../src/input/input.cpp:621)
[2023-06-09 12:35:29] MistInBuffer:cam1 (28150) INFO: Input started (../src/input/input.cpp:740)
[2023-06-09 12:35:29] MistInBuffer:cam1 (28150) INFO: Setting maxKeepAway from 0 to new value of 45000 (../src/input/input_buffer.cpp:577)
[2023-06-09 12:35:29] MistSession (28151) INFO: Started new session I0e1379249431660176b966d486071e71e5e17772cec37b713c95040f7f17bda1 in 0.870 ms (../src/session.cpp:270)
[2023-06-09 12:35:30] MistController (27974) INFO: Stream cam1 became active (../src/controller/controller_statistics.cpp:163)

[2023-06-09 12:35:31] MistOutTSSRT (28099) INFO: Accepted a socket coming from 127.0.0.1 (../lib/socket_srt.cpp:544)
[2023-06-09 12:35:33] MistSession (28160) INFO: Started new session 93a57fc2a5c9993f9fc1057409f96274d859827bcbf91616cb2c015b46ff35cf in 0.344 ms (../src/session.cpp:270)
[2023-06-09 12:35:34] MistOutTSSRT:cam1 (28099) INFO: Connection put into egress mode (../src/output/output_tssrt.cpp:83)
[2023-06-09 12:35:35] MistSession (28161) INFO: Started new session 9e06aeb60dd93ce08b7ca972d2cc5c372d3c4344128b9349834b586b4a8b66a1 in 0.744 ms (../src/session.cpp:270)

++START OBS PUSH HERE++

[2023-06-09 12:35:42] MistOutRTMP:cam1 (28158) INFO: Switching UDP socket from IPv6 to IPv4 (../lib/socket.cpp:1785)
[2023-06-09 12:35:44] MistOutTSSRT (28099) INFO: Accepted a socket coming from 127.0.0.1 (../lib/socket_srt.cpp:544)
[2023-06-09 12:35:44] MistOutTSSRT:cam2 (28099) INFO: Connection put into ingest mode (../src/output/output_tssrt.cpp:73)
[2023-06-09 12:35:44] MistOutTSSRT:cam2 (28099) INFO: Waiting for cam2 buffer to be ready... (0) (../src/output/output.cpp:2420)
[2023-06-09 12:35:44] MistOutTSSRT:cam2 (28099) INFO: Reconnecting to cam2 buffer... (0) (../src/output/output.cpp:2424)
[2023-06-09 12:35:44] MistOutTSSRT:cam2 (28223) INFO: Starting /home/warpstar/DMS/build/MistInBuffer -s cam2 push://  (../lib/stream.cpp:633)
[2023-06-09 12:35:44] MistInBuffer:cam2 (28223) INFO: Input booting (../src/input/input.cpp:353)
[2023-06-09 12:35:44] MistInBuffer:cam2 (28224) ERROR: Overwriting old page for MstSTATEcam2 (../lib/shared_memory.cpp:494)
[2023-06-09 12:35:44] MistInBuffer:cam2 (28224) INFO: Starting serve (../src/input/input.cpp:621)
[2023-06-09 12:35:44] MistInBuffer:cam2 (28224) INFO: Input started (../src/input/input.cpp:740)
[2023-06-09 12:35:44] MistInBuffer:cam2 (28224) INFO: Setting maxKeepAway from 0 to new value of 45000 (../src/input/input_buffer.cpp:577)
[2023-06-09 12:35:45] MistSession (28225) INFO: Started new session I9bab2fb97455c7997f27a13dfd35c6a255496ffe6a46c0b02e4f682322710960 in 1.986 ms (../src/session.cpp:270)
[2023-06-09 12:35:45] MistOutTSSRT:cam2 (28099) INFO: Jitter increased from 1099 to 3615268 ms (../lib/dtsc.cpp:2340)
[2023-06-09 12:35:45] MistOutTSSRT:cam2 (28099) INFO: Jitter increased from 1074 to 3615272 ms (../lib/dtsc.cpp:2340)
[2023-06-09 12:35:45] MistController (27974) INFO: Stream cam2 became active (../src/controller/controller_statistics.cpp:163)

++PLAYBACK CHECK++

[2023-06-09 12:35:58] MistOutHTTP (28229) INFO: Received request: /json_cam1.js => HTTP (cam1) (../src/output/output_http.cpp:205)
[2023-06-09 12:35:58] MistSession (28231) INFO: Started new session ace9e2e0e98f8d81d852c5cf9564413ae43e8bd6d4fa0a61ae52e35858693b3b in 4.369 ms (../src/session.cpp:270)
[2023-06-09 12:35:58] MistOutHTTP (28233) INFO: Received request: /json_cam1.js => HTTP (cam1) (../src/output/output_http.cpp:205)
[2023-06-09 12:35:59] MistSession (28235) INFO: Started new session 4a26a178f880e84cf5e83bfb087f5252dd076ff9c228f5c0e1aef8bd5ab37769 in 1.857 ms (../src/session.cpp:270)
[2023-06-09 12:35:59] MistOutHTTP (28236) INFO: Received request: /cam1.mp4 => MP4 (cam1) (../src/output/output_http.cpp:205)
[2023-06-09 12:35:59] MistOutMP4:cam1 (28236) INFO: Switching to Websocket mode (../src/output/output_http.cpp:306)
[2023-06-09 12:36:00] MistOutHTTP:cam1 (28229) INFO: Received request: /json_cam2.js => HTTP (cam2) (../src/output/output_http.cpp:205)
[2023-06-09 12:36:00] MistSession (28244) INFO: Started new session 2b9d28d640efacff88e22775541ffdddcba20178e10e97852ba11043e08d2da1 in 1.678 ms (../src/session.cpp:270)
[2023-06-09 12:36:00] MistOutHTTP (28245) INFO: Received request: /json_cam2.js => HTTP (cam2) (../src/output/output_http.cpp:205)
[2023-06-09 12:36:00] MistSession (28247) INFO: Started new session b45e0af4aab5b6de09a7a91b80a7dbe2f219667674878894d573c30567a84249 in 4.106 ms (../src/session.cpp:270)
[2023-06-09 12:36:00] MistOutHTTP (28248) INFO: Received request: /cam2.mp4 => MP4 (cam2) (../src/output/output_http.cpp:205)
[2023-06-09 12:36:00] MistOutMP4:cam2 (28248) INFO: Switching to Websocket mode (../src/output/output_http.cpp:306)
[2023-06-09 12:36:08] MistOutMP4:cam1 (28236) INFO: Switching UDP socket from IPv6 to IPv4 (../lib/socket.cpp:1785)
[2023-06-09 12:36:08] MistOutHTTP:cam1 (28233) INFO: Switching UDP socket from IPv6 to IPv4 (../lib/socket.cpp:1785)

++STOP OBS PUSH HERE++

[2023-06-09 12:36:09] MistOutMP4:cam2 (28248) INFO: Switching UDP socket from IPv6 to IPv4 (../lib/socket.cpp:1785)
[2023-06-09 12:36:09] MistOutHTTP:cam2 (28245) INFO: Switching UDP socket from IPv6 to IPv4 (../lib/socket.cpp:1785)
[2023-06-09 12:36:18] MistSession (28231) INFO: Shutting down session ace9e2e0e98f8d81d852c5cf9564413ae43e8bd6d4fa0a61ae52e35858693b3b: Session inactive for 15 seconds (../src/session.cpp:428)
[2023-06-09 12:36:18] MistOutHTTP:cam2 (28229) INFO: Switching UDP socket from IPv6 to IPv4 (../lib/socket.cpp:1785)
[2023-06-09 12:36:18] MistController (27974) ACCS: Session <ace9e2e0e98f8d81d852c5cf9564413ae43e8bd6d4fa0a61ae52e35858693b3b> cam1 () from ::1 ended after 18s, avg 0KB/s up 0KB/s down.
[2023-06-09 12:36:18] MistInBuffer:cam2 (28224) INFO: Disconnected track 1 (../src/input/input_buffer.cpp:477)
[2023-06-09 12:36:18] MistInBuffer:cam2 (28224) INFO: Should remove track 1 (../src/input/input_buffer.cpp:317)
[2023-06-09 12:36:18] MistInBuffer:cam2 (28224) INFO: Disconnected track 0 (../src/input/input_buffer.cpp:477)
[2023-06-09 12:36:18] MistInBuffer:cam2 (28224) INFO: Should remove track 0 (../src/input/input_buffer.cpp:317)
[2023-06-09 12:36:18] MistInBuffer:cam2 (28224) INFO: Input closing clean, reason: source disconnected for non-resumable streaINFO|MistOutMP4|28248|../src/output/output.cpp:457|cam2|Automatically seeking to resume playback (../src/input/input.cpp:774)
[2023-06-09 12:36:18] MistOutMP4:cam2 (28248) WARN: Sync-seeking impossible (main track invalid); performing regular seek instead (../src/output/output.cpp:794)
[2023-06-09 12:36:18] MistOutMP4:cam2 (28248) INFO: Buffer completely played out (../src/output/output.cpp:1949)
[2023-06-09 12:36:18] MistOutMP4:cam2 (28248) INFO: Client handler shutting down, exit reason: end of stream (../src/output/output.cpp:1795)
[2023-06-09 12:36:18] MistInBuffer:cam2 (28223) INFO: Input for stream cam2 shut down cleanly (../src/input/input.cpp:529)
[2023-06-09 12:36:18] MistInBuffer:cam2 (28223) ERROR: Overwriting old page for MstSTATEcam2 (../lib/shared_memory.cpp:494)
[2023-06-09 12:36:19] MistController (27974) INFO: Stream cam2 became inactive (../src/controller/controller_statistics.cpp:169)
Taiwan22 commented 1 year ago

I've tested it again, and it seems that it is fine until I'm not watching the second stream in VLC. Then, when I stop it, it shuts down both.

I've also checked line numbers from the log, and they match the cpp file. So the build is the last development....

!----MistServer Started at Fri Jun  9 14:50:52 2023 ----!
[2023-06-09 14:50:54] MistController (3319088) WARN: Your shared memory is half or less of your RAM (1965 / 3931 MiB). Mist heavily relies on shared memory: please ensure your shared memory is set to a high value, preferably ~95% of your total available RAM. (/home/MistDEV/mistserver/src/controller/controller.cpp:419)
[2023-06-09 14:50:54] MistController (3319088) WARN: Tip: In most cases, you can change the shared memory size by running `mount -o remount,size=3734m /dev/shm` as root. Doing this automatically every boot depends on your distribution: please check your distro's documentation for instructions. (/home/MistDEV/mistserver/src/controller/controller.cpp:428)
[2023-06-09 14:50:54] MistController (3319088) WARN: Could not set IPv6 UDP socket to be dual-stack! Invalid argument (/home/MistDEV/mistserver/lib/socket.cpp:1948)
[2023-06-09 14:50:54] MistController (3319088) INFO: UDP bind success on ::1:4242 (IPv6) (/home/MistDEV/mistserver/lib/socket.cpp:1996)
[2023-06-09 14:50:54] MistController (3319088) INFO: Reloading existing connectors to complete rolling restart (/home/MistDEV/mistserver/src/controller/controller_connectors.cpp:64)
[2023-06-09 14:50:54] MistController (3319088) CONF: Controller started
[2023-06-09 14:50:54] MistController (3319088) CONF: Starting connector: {"acceptable":"0","connector":"TSSRT","debug":6,"port":10080}
[2023-06-09 14:50:54] MistController (3319088) WARN: Attempting to add a mandatory-size field without size (/home/MistDEV/mistserver/lib/util.cpp:1016)
[2023-06-09 14:50:54] MistController (3319088) INFO: IPv6 socket success @ 0.0.0.0:4242 (/home/MistDEV/mistserver/lib/socket.cpp:1412)
[2023-06-09 14:50:54] MistOutTSSRT (3319144) HIGH: Opening SRT connection listener in output mode on 0.0.0.0:10080 (/home/MistDEV/mistserver/lib/socket_srt.cpp:222)
[2023-06-09 14:50:54] MistOutTSSRT (3319144) HIGH: Going to bind a server on 0.0.0.0:10080 (/home/MistDEV/mistserver/lib/socket_srt.cpp:264)
[2023-06-09 14:50:54] MistOutTSSRT (3319144) INFO: Listener SRT socket sucess @ 0.0.0.0:10080 (/home/MistDEV/mistserver/lib/socket_srt.cpp:280)
[2023-06-09 14:50:57] MistController (3319088) UPDR: Self-compiled build. Updater disabled.
...........
CLOSED cam2
[2023-06-09 14:54:18] MistOutTSSRT:cam2 (3319144) HIGH: Socket 28 closed (/home/MistDEV/mistserver/lib/socket.cpp:724)
[2023-06-09 14:54:18] MistOutTSSRT:cam2 (3319144) MEDIUM: Client handler shutting down, exit reason: connection closed (/home/MistDEV/mistserver/src/output/output.cpp:1793)
[2023-06-09 14:54:18] MistOutTSSRT:cam2 (3319144) MEDIUM: disconnect (/home/MistDEV/mistserver/src/output/output.cpp:265)
[2023-06-09 14:54:18] MistOutTSSRT:cam2 (3319144) HIGH: Closing thread for socket -1 (/home/MistDEV/mistserver/src/output/output_tssrt.cpp:416)
[2023-06-09 14:54:18] MistInBuffer:cam2 (3319172) INFO: Disconnected track 0 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:477)
[2023-06-09 14:54:18] MistInBuffer:cam2 (3319172) INFO: Should remove track 0 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:317)
[2023-06-09 14:54:18] MistInBuffer:cam2 (3319172) INFO: Disconnected track 1 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:477)
[2023-06-09 14:54:18] MistInBuffer:cam2 (3319172) INFO: Should remove track 1 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:317)
[2023-06-09 14:54:18] MistInBuffer:cam2 (3319172) MEDIUM: Valid tracks count changed from 2 to 0 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:502)
[2023-06-09 14:54:18] MistInBuffer:cam2 (3319172) INFO: Input closing clean, reason: source disconnected for non-resumable stream (/home/MistDEV/mistserver/src/input/input.cpp:774)
[2023-06-09 14:54:18] MistOutTSSRT (3319144) INFO: Received signal Terminated (15) from process 3319172 (/home/MistDEV/mistserver/lib/config.cpp:612)
[2023-06-09 14:54:18] MistOutTSSRT:cam1 (3319144) INFO: Client handler shutting down, exit reason: set inactive (/home/MistDEV/mistserver/src/output/output.cpp:1795)
[2023-06-09 14:54:18] MistOutTSSRT:cam1 (3319144) HIGH: Socket 17 closed (/home/MistDEV/mistserver/lib/socket.cpp:724)
[2023-06-09 14:54:18] MistOutTSSRT:cam1 (3319144) MEDIUM: disconnect (/home/MistDEV/mistserver/src/output/output.cpp:265)
[2023-06-09 14:54:18] MistOutTSSRT:cam1 (3319144) HIGH: Closing thread for socket -1 (/home/MistDEV/mistserver/src/output/output_tssrt.cpp:416)
[2023-06-09 14:54:18] MistOutTSSRT:cam2 (3319144) INFO: Client handler shutting down, exit reason: set inactive (/home/MistDEV/mistserver/src/output/output.cpp:1795)
[2023-06-09 14:54:18] MistOutTSSRT:cam2 (3319144) HIGH: Socket 39 closed (/home/MistDEV/mistserver/lib/socket.cpp:724)
[2023-06-09 14:54:18] MistOutTSSRT:cam2 (3319144) MEDIUM: disconnect (/home/MistDEV/mistserver/src/output/output.cpp:265)
[2023-06-09 14:54:18] MistOutTSSRT:cam2 (3319144) HIGH: Closing thread for socket -1 (/home/MistDEV/mistserver/src/output/output_tssrt.cpp:416)
[2023-06-09 14:54:18] MistOutTSSRT (3319144) INFO: Exit reason: signal Terminated (15) from process 3319172 (/home/MistDEV/mistserver/src/output/output_tssrt.cpp:516)
[2023-06-09 14:54:18] MistOutTSSRT:cam1 (3319144) INFO: Client handler shutting down, exit reason: set inactive (/home/MistDEV/mistserver/src/output/output.cpp:1795)
[2023-06-09 14:54:18] MistOutTSSRT:cam1 (3319144) HIGH: Socket 5 closed (/home/MistDEV/mistserver/lib/socket.cpp:724)
[2023-06-09 14:54:18] MistOutTSSRT:cam1 (3319144) MEDIUM: disconnect (/home/MistDEV/mistserver/src/output/output.cpp:265)
[2023-06-09 14:54:18] MistOutTSSRT:cam1 (3319144) HIGH: Closing thread for socket -1 (/home/MistDEV/mistserver/src/output/output_tssrt.cpp:416)
[2023-06-09 14:54:18] MistInBuffer:cam1 (3319155) INFO: Disconnected track 0 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:477)
[2023-06-09 14:54:18] MistInBuffer:cam1 (3319155) INFO: Should remove track 0 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:317)
[2023-06-09 14:54:18] MistInBuffer:cam1 (3319155) INFO: Disconnected track 1 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:477)
[2023-06-09 14:54:18] MistInBuffer:cam1 (3319155) INFO: Should remove track 1 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:317)
[2023-06-09 14:54:18] MistInBuffer:cam1 (3319155) MEDIUM: Valid tracks count changed from 2 to 0 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:502)
[2023-06-09 14:54:18] MistInBuffer:cam1 (3319155) INFO: Input closing clean, reason: source disconnected for non-resumable stream (/home/MistDEV/mistserver/src/input/input.cpp:774)
[2023-06-09 14:54:18] MistInBuffer:cam1 (3319154) HIGH: Received signal Child exited (17) from process 3319155 (/home/MistDEV/mistserver/lib/config.cpp:624)
[2023-06-09 14:54:18] MistInBuffer:cam1 (3319154) HIGH: Done waiting for child for stream cam1 (/home/MistDEV/mistserver/src/input/input.cpp:526)
[2023-06-09 14:54:18] MistInBuffer:cam1 (3319154) INFO: Input for stream cam1 shut down cleanly (/home/MistDEV/mistserver/src/input/input.cpp:529)
[2023-06-09 14:54:18] MistInBuffer:cam1 (3319154) ERROR: Overwriting old page for MstSTATEcam1 (/home/MistDEV/mistserver/lib/shared_memory.cpp:494)
[2023-06-09 14:54:18] MistInBuffer:cam1 (3319154) HIGH: Angel process for cam1 exiting (/home/MistDEV/mistserver/src/input/input.cpp:582)
[2023-06-09 14:54:18] MistController (3319088) INFO: Stream cam1 became inactive (/home/MistDEV/mistserver/src/controller/controller_statistics.cpp:169)
[2023-06-09 14:54:18] MistController (3319088) INFO: Stream cam2 became inactive (/home/MistDEV/mistserver/src/controller/controller_statistics.cpp:169)
[2023-06-09 14:54:18] MistInBuffer:cam2 (3319171) HIGH: Received signal Child exited (17) from process 3319172 (/home/MistDEV/mistserver/lib/config.cpp:624)
[2023-06-09 14:54:18] MistInBuffer:cam2 (3319171) HIGH: Done waiting for child for stream cam2 (/home/MistDEV/mistserver/src/input/input.cpp:526)
[2023-06-09 14:54:18] MistInBuffer:cam2 (3319171) INFO: Input for stream cam2 shut down cleanly (/home/MistDEV/mistserver/src/input/input.cpp:529)
[2023-06-09 14:54:18] MistInBuffer:cam2 (3319171) ERROR: Overwriting old page for MstSTATEcam2 (/home/MistDEV/mistserver/lib/shared_memory.cpp:494)
[2023-06-09 14:54:18] MistInBuffer:cam2 (3319171) HIGH: Angel process for cam2 exiting (/home/MistDEV/mistserver/src/input/input.cpp:582)
[2023-06-09 14:54:21] MistController (3319088) CONF: Starting connector: {"acceptable":"0","connector":"TSSRT","debug":6,"port":10080}
[2023-06-09 14:54:21] MistOutTSSRT (3319178) HIGH: Opening SRT connection listener in output mode on 0.0.0.0:10080 (/home/MistDEV/mistserver/lib/socket_srt.cpp:222)

full.log

The screenshot was not taken at the same time as LOG. htop_screen

Rokamun commented 1 year ago

Alright, thanks for double-checking we'll go over it again.

Rokamun commented 1 year ago

Took us longer than expected, but I think we finally narrowed down the issue and solved it. What would happen is that SRT connections over the same port would share jitter settings between all streams over it. While often this would go correctly it could cause crashes if streams were exited at "the right timing".

The fix is available in: 0ec280089487f53dca67d7f652613e1a64b773de

We're expecting to push this as a bugfix release 3.2.2 end of this week or early next.

Taiwan22 commented 1 year ago

Hello, and thank you for all your effort. But the problem is still the same; I don't know how you are testing it. My simplest test setup is to broadcast from my mobile phone as cam1 to OBS, then broadcast from the same OBS as cam2, and receive cam2 in the same OBS. And every time you end one broadcast, it shuts down both.

Here are some logs.

started broadcast from larix as cam1

[2023-07-20 19:25:04] MistOutTSSRT (163142) INFO: Accepted a socket coming from SAME_IP (/home/MistDEV/mistserver/lib/socket_srt.cpp:544)
[2023-07-20 19:25:04] MistOutTSSRT:cam1 (163142) INFO: Connection put into ingest mode (/home/MistDEV/mistserver/src/output/output_tssrt.cpp:73)
[2023-07-20 19:25:04] MistOutTSSRT:cam1 (163142) INFO: Waiting for cam1 buffer to be ready... (0) (/home/MistDEV/mistserver/src/output/output.cpp:2424)
[2023-07-20 19:25:04] MistOutTSSRT:cam1 (163142) INFO: Reconnecting to cam1 buffer... (0) (/home/MistDEV/mistserver/src/output/output.cpp:2428)
[2023-07-20 19:25:04] MistOutTSSRT:cam1 (163209) INFO: Starting /usr/bin/MistInBuffer -s cam1 push:// --buffer 60000 --resume 0  (/home/MistDEV/mistserver/lib/stream.cpp:653)
[2023-07-20 19:25:04] MistInBuffer:cam1 (163209) INFO: Input booting (/home/MistDEV/mistserver/src/input/input.cpp:360)
[2023-07-20 19:25:04] MistInBuffer:cam1 (163210) INFO: Setting bufferTime from 50000 to new value of 60000 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:540)
[2023-07-20 19:25:04] MistInBuffer:cam1 (163210) INFO: Starting serve (/home/MistDEV/mistserver/src/input/input.cpp:639)
[2023-07-20 19:25:04] MistInBuffer:cam1 (163210) INFO: Input started (/home/MistDEV/mistserver/src/input/input.cpp:758)
[2023-07-20 19:25:04] MistInBuffer:cam1 (163210) INFO: Setting maxKeepAway from 0 to new value of 45000 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:577)
[2023-07-20 19:25:05] MistSession (163211) INFO: Started new session I0a7835eb5d3e5d073955e25e787eecb12bbd5e29f9db626a9da22040c1df987b in 0.387 ms (/home/MistDEV/mistserver/src/session.cpp:270)
[2023-07-20 19:25:05] MistController (162882) INFO: Stream cam1 became active (/home/MistDEV/mistserver/src/controller/controller_statistics.cpp:163)

started view cam1 in OBS

[2023-07-20 19:25:10] MistOutTSSRT (163142) INFO: Accepted a socket coming from SAME_IP (/home/MistDEV/mistserver/lib/socket_srt.cpp:544)
[2023-07-20 19:25:13] MistOutTSSRT:cam1 (163142) INFO: Connection put into egress mode (/home/MistDEV/mistserver/src/output/output_tssrt.cpp:83)
[2023-07-20 19:25:13] MistSession (163213) INFO: Started new session 04f20347af8598356c9a8999ad6baca828d6ffe856a1ce864b92022878482512 in 0.247 ms (/home/MistDEV/mistserver/src/session.cpp:270)

started broadcast from OBS as cam2

[2023-07-20 19:25:15] MistOutTSSRT (163142) INFO: Accepted a socket coming from SAME_IP (/home/MistDEV/mistserver/lib/socket_srt.cpp:544)
[2023-07-20 19:25:16] MistOutTSSRT:cam2 (163142) INFO: Connection put into ingest mode (/home/MistDEV/mistserver/src/output/output_tssrt.cpp:73)
[2023-07-20 19:25:16] MistOutTSSRT:cam2 (163142) INFO: Waiting for cam2 buffer to be ready... (0) (/home/MistDEV/mistserver/src/output/output.cpp:2424)
[2023-07-20 19:25:16] MistOutTSSRT:cam2 (163142) INFO: Reconnecting to cam2 buffer... (0) (/home/MistDEV/mistserver/src/output/output.cpp:2428)
[2023-07-20 19:25:16] MistOutTSSRT:cam2 (163216) INFO: Starting /usr/bin/MistInBuffer -s cam2 push:// --resume 0  (/home/MistDEV/mistserver/lib/stream.cpp:653)
[2023-07-20 19:25:16] MistInBuffer:cam2 (163216) INFO: Input booting (/home/MistDEV/mistserver/src/input/input.cpp:360)
[2023-07-20 19:25:16] MistInBuffer:cam2 (163217) INFO: Starting serve (/home/MistDEV/mistserver/src/input/input.cpp:639)
[2023-07-20 19:25:16] MistInBuffer:cam2 (163217) INFO: Input started (/home/MistDEV/mistserver/src/input/input.cpp:758)
[2023-07-20 19:25:16] MistInBuffer:cam2 (163217) INFO: Setting maxKeepAway from 0 to new value of 45000 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:577)
[2023-07-20 19:25:16] MistSession (163218) INFO: Started new session I8bd665aec60c976b4f29abd5c38303c4ef82cf0416e2d6a6d368429defb02224 in 0.366 ms (/home/MistDEV/mistserver/src/session.cpp:270)
[2023-07-20 19:25:17] MistController (162882) INFO: Stream cam2 became active (/home/MistDEV/mistserver/src/controller/controller_statistics.cpp:163)

started view cam2 in same OBS

[2023-07-20 19:25:21] MistOutTSSRT (163142) INFO: Accepted a socket coming from SAME_IP (/home/MistDEV/mistserver/lib/socket_srt.cpp:544)
[2023-07-20 19:25:24] MistOutTSSRT:cam2 (163142) INFO: Connection put into egress mode (/home/MistDEV/mistserver/src/output/output_tssrt.cpp:83)
[2023-07-20 19:25:24] MistSession (163220) INFO: Started new session a86aaec5f8b684dc916e534b7fed9e99ef2430f6c7bf8a80eebc5bf6d867a41d in 0.253 ms (/home/MistDEV/mistserver/src/session.cpp:270)
[2023-07-20 19:25:31] MistInBuffer:cam2 (163217) INFO: Setting segmentSize from 1900 to new value of 4166 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:569)

ended cam1 broadcast

[2023-07-20 19:25:32] MistInBuffer:cam1 (163210) INFO: Disconnected track 1 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:477)
[2023-07-20 19:25:32] MistInBuffer:cam1 (163210) INFO: Should remove track 1 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:317)
[2023-07-20 19:25:32] MistInBuffer:cam1 (163210) INFO: Disconnected track 0 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:477)
[2023-07-20 19:25:32] MistInBuffer:cam1 (163210) INFO: Should remove track 0 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:317)
[2023-07-20 19:25:32] MistInBuffer:cam1 (163210) INFO: Input closing clean, reason: source disconnected for non-resumable stream (/home/MistDEV/mistserver/src/input/input.cpp:792)
[2023-07-20 19:25:32] MistOutTSSRT (163142) INFO: Received signal Terminated (15) from process 163210 (/home/MistDEV/mistserver/lib/config.cpp:612)
[2023-07-20 19:25:32] MistOutTSSRT (163142) INFO: Received signal Terminated (15) from process 163210 (/home/MistDEV/mistserver/lib/config.cpp:612)
[2023-07-20 19:25:32] MistOutTSSRT (163142) INFO: Exit reason: signal Terminated (15) from process 163210 (/home/MistDEV/mistserver/src/output/output_tssrt.cpp:524)
[2023-07-20 19:25:32] MistOutTSSRT:cam1 (163142) INFO: Client handler shutting down, exit reason: set inactive (/home/MistDEV/mistserver/src/output/output.cpp:1799)
[2023-07-20 19:25:32] MistOutTSSRT:cam2 (163142) INFO: Client handler shutting down, exit reason: set inactive (/home/MistDEV/mistserver/src/output/output.cpp:1799)
[2023-07-20 19:25:32] MistController (162882) INFO: Stream cam1 became inactive (/home/MistDEV/mistserver/src/controller/controller_statistics.cpp:169)
[2023-07-20 19:25:32] MistOutTSSRT:cam2 (163142) INFO: Client handler shutting down, exit reason: set inactive (/home/MistDEV/mistserver/src/output/output.cpp:1799)
[2023-07-20 19:25:33] MistInBuffer:cam2 (163217) INFO: Disconnected track 0 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:477)
[2023-07-20 19:25:33] MistInBuffer:cam2 (163217) INFO: Should remove track 0 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:317)
[2023-07-20 19:25:33] MistInBuffer:cam2 (163217) INFO: Disconnected track 1 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:477)
[2023-07-20 19:25:33] MistInBuffer:cam2 (163217) INFO: Should remove track 1 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:317)
[2023-07-20 19:25:33] MistInBuffer:cam2 (163217) INFO: Input closing clean, reason: source disconnected for non-resumable stream (/home/MistDEV/mistserver/src/input/input.cpp:792)
[2023-07-20 19:25:33] MistInBuffer:cam2 (163216) INFO: Input for stream cam2 shut down cleanly (/home/MistDEV/mistserver/src/input/input.cpp:542)
[2023-07-20 19:25:33] MistInBuffer:cam1 (163209) INFO: Input for stream cam1 shut down cleanly (/home/MistDEV/mistserver/src/input/input.cpp:542)
[2023-07-20 19:25:33] MistController (162882) INFO: Stream cam2 became inactive (/home/MistDEV/mistserver/src/controller/controller_statistics.cpp:169)
[2023-07-20 19:25:36] MistController (162882) CONF: Starting connector: {"acceptable":"0","connector":"TSSRT","port":10080}
[2023-07-20 19:25:36] MistOutTSSRT (163221) INFO: Listener SRT socket sucess @ 0.0.0.0:10080 (/home/MistDEV/mistserver/lib/socket_srt.cpp:280)

OBS as cam2 reconnect

[2023-07-20 19:25:36] MistOutTSSRT (163221) INFO: Accepted a socket coming from SAME_IP (/home/MistDEV/mistserver/lib/socket_srt.cpp:544)
[2023-07-20 19:25:36] MistOutTSSRT (163221) INFO: Accepted a socket coming from SAME_IP (/home/MistDEV/mistserver/lib/socket_srt.cpp:544)
[2023-07-20 19:25:37] MistOutTSSRT:cam2 (163221) INFO: Connection put into ingest mode (/home/MistDEV/mistserver/src/output/output_tssrt.cpp:73)
[2023-07-20 19:25:37] MistOutTSSRT:cam2 (163221) INFO: Waiting for cam2 buffer to be ready... (0) (/home/MistDEV/mistserver/src/output/output.cpp:2424)
[2023-07-20 19:25:37] MistOutTSSRT:cam2 (163221) INFO: Reconnecting to cam2 buffer... (0) (/home/MistDEV/mistserver/src/output/output.cpp:2428)
[2023-07-20 19:25:37] MistOutTSSRT:cam2 (163229) INFO: Starting /usr/bin/MistInBuffer -s cam2 push:// --resume 0  (/home/MistDEV/mistserver/lib/stream.cpp:653)
[2023-07-20 19:25:37] MistInBuffer:cam2 (163229) INFO: Input booting (/home/MistDEV/mistserver/src/input/input.cpp:360)
[2023-07-20 19:25:37] MistInBuffer:cam2 (163230) INFO: Starting serve (/home/MistDEV/mistserver/src/input/input.cpp:639)
[2023-07-20 19:25:37] MistInBuffer:cam2 (163230) INFO: Input started (/home/MistDEV/mistserver/src/input/input.cpp:758)
[2023-07-20 19:25:37] MistInBuffer:cam2 (163230) INFO: Setting maxKeepAway from 0 to new value of 45000 (/home/MistDEV/mistserver/src/input/input_buffer.cpp:577)
[2023-07-20 19:25:38] MistSession (163231) INFO: Started new session I438e3ef8d3838a1c51d9573a7cfc1fce7c99431af2e298c29d5667b400db6f84 in 0.362 ms (/home/MistDEV/mistserver/src/session.cpp:270)
[2023-07-20 19:25:38] MistController (162882) INFO: Stream cam2 became active (/home/MistDEV/mistserver/src/controller/controller_statistics.cpp:163)

The only way I got it to work was by using a separate port for each input and output stream. So for two streams, I need four ports.

I think the problem is simple in that every time one broadcast ends, it closes the whole connector. "Starting connector: {"acceptable":"0","connector":"TSSRT","port":10080}"

Larix - broadcast cam1: InkedScreenshot_20230720-200540 OBS - input cam1: Snímek obrazovky 2023-07-20 202041 OBS - input cam2: Snímek obrazovky 2023-07-20 202027 OBS - broadcast cam2 Snímek obrazovky 2023-07-20 202009

Rokamun commented 1 year ago

Ah apologies, seems I have been reproducing it wrongly.

I apparently misunderstood the part where OBS would use Cam2 as an input as well. Making the proper changes did get us to reproduce it properly.

The problem being that SRT viewers can send a kill command to the process handling them, which in the case of SRT is the process also handling the inputs. We've made it so this doesn't happen. Though a Nuke command could still close down this port if the process closes too slowly (which is unlikely unless the process crashed and doesn't listen to kill commands).

The adjustments are available here: 41cf557b484361a594286e7ae703d11456455761

Taiwan22 commented 1 year ago

I don't know what to say, but it's working!!!! 👍 🥇  Thank you so much, guys. Thank you for all your effort. I think a good thing is that you fixed a few other issues along the way, so your SRT implementation should be really good now 👍 

BTW, is there some way to support you through a donation?

Thulinma commented 1 year ago

This fix was included in the 3.2.2 release today 👍

Thank you for wanting to support us! It's currently a little tricky for us to accept donations - we're planning to set up a way to automatically handle these and also thank people for their donations by giving them a little bit of roadmap influence... but this is not ready yet. 😅 You can simply transfer something to us through any of these banking details, but we can't provide a receipt for that at the moment: https://mistserver.org/contact#Address