Can't Use With Restream due to Random Echo Not Matched about owncast HOT 43 CLOSED

Thanks for testing and reporting! So the bug is in the RTMP library https://github.com/yutopp/go-rtmp/blob/9b52215ac9e0edf55aa3be632cdd12b4c36cd4c8/handshake/handshake.go#L102.

According to the wiki page of RTMP:

C2 and S2 are an echo of S1 and C1 respectively, except with the second 4 bytes being the time the respective message was received (instead of 0). After C2 and S2 are received the handshake is considered complete.

Sounds straightforward enough. I'll fork it and dig into it and see what that means and see if I can fix it. Thanks again, this was a good find! But sorry it didn't work for you. Next time!

from owncast.

Thanks for working and pursing this! If you ever need me to test something, let me know

from owncast.

I will see about testing it on Wednesday night, as that’s when the next time I’ll be using it is. But if I get a chance before then, I’ll let you know!

from owncast.

Yup, that’s the one! You’re always welcome to point to my instance, but it makes sense to make sure your setup is happy since I’ve been running it and (aside from whatever happened last night) it’s been functioning ok. So it would be good to make sure this updated branch runs in your environment, too. Though I doubt there’s enough different to make any incompatibilities. A week or so ago we did the great merging of the config files, too, so it’ll be good to make sure your config file is happy with that.

from owncast.

Was just able to reproduce it with that setup. Digging into it...

from owncast.

Also, great news! Finally Restream success! haha

from owncast.

Sure! Thanks! Going to merge this into master.

from owncast.

The library has a SkipHandshakeVerification that skips these checks. I enabled it and while it does indeed skip the checks, the video doesn't come through at all. It connects, I looked at the two items that are supposed to match up, and they are indeed very different. Same length, different content.

I'm guessing there's different versions of the protocol (or at least the handshake) that we're running into here. I'm seeing murmurs of a "RTMP with digest handshake" and I'm wondering if that's what we're not yet supporting.

As an aside, I found another RTMP client for iOS (Wirecast Go) that's doing the same thing, so I'm using that to test. But it's the exact same error as you're seeing with Restream.

from owncast.

As a random test I tried against another RTMP implementation, and same error happens.
https://github.com/c-bata/rtmp/blob/c02335130af64a017980bc9a99c2d1ab40abc094/conn.go#L189

from owncast.

When trying to find details of the handshake with digest spec I'm finding a lot of stuff like this.

from owncast.

Digging around I found this implementation in Node. It looks to be the most straightforward example of it in use. I'm going to try to use this as a guide and write our own handshake. https://github.com/illuspas/Node-Media-Server/blob/master/node_rtmp_handshake.js

from owncast.

Update!

So I've made some progress. Using the RTMP implementation from https://github.com/nareix/joy5/ I'm able to accept incoming RTMP streams from Restream and Wirecast Go. The bad news is only a single frame comes through and then the RTMP stream is garbage after that. I'm guessing it has something to do with the new way that I'm handling that stream and writing it for use in the Transcoder. However, OBS is working fine still.

It kind of sucks that the core of RTMP is having to be pulled out, but better to do it now than later.

from owncast.

More progress! Currently as it stands:

• Able to accept this digested RTMP from Restream and it works now.
• It's able to be passed to the transcoder and and be handled in the video pipeline.

Things not working or are concerns:

• I don't know yet when a RTMP connection is closed, so I can't fire the offline handlers. Internally it's using a net.Conn, and I'm trying to find what the best way of determining a closed Conn is. There must be better options than just randomly trying to read from the connection and looking for an EOF? That's what I'm looking into now.
• I'm having to tell the RTMP pipeline to output as ts instead of the flv as before on the way to the transcoder. I'm concerned this is an additional level of processing that will increase CPU usage. I don't know for sure, as I haven't done any real testing on a server as I'm still trying to wrap all this up.

@graywolf336 If you're interested and want to test, I can push up a branch and just turn off the offline handling as I continue to try to figure that out. It's pretty bleeding edge because I haven't even tested it on my own server, but maybe it's worth testing!

from owncast.

from owncast.

The branch is up at https://github.com/gabek/owncast/tree/gek/rtmp-v2. I'm doing my first testing with it now. It doesn't go offline when you disconnect because I haven't figured that out yet, so if something gets stuck after disconnecting you might have to restart the service.

from owncast.

Ok, I just pushed up an update to that branch that heavy-handedly checks the connection state in order to find when it's disconnected. It seems to be working ok, it just feels wrong.

from owncast.

@graywolf336 Looking forward to seeing how things go tonight! I did some time with a stream last night with the new RTMP branch and that part seemed to be working ok. But one issue arose that I think only testing will help surface. At one point when streaming the viewer count jumped from 5 to > 50, and then all those "viewers" eventually timed out and it went back to 5. But from that point on people were mentioning that (non-video) requests were taking a really long time. I have more detail in #44. So hopefully more testing can help track this down as well as making sure RTMP is happy for you.

from owncast.

I'll let you know when we get it setup and ready to go tonight. I could even point it at an instance of yours if you wanted to monitor it.

And just to confirm, it is the branch gek/rtmp-v2?

from owncast.

Oh, FYI! I added a enableVerboseLogging flag. So enable that if you want detailed logging.

from owncast.

Okay, I'll clear my config and copy the default/example one to start fresh. I'll do a $15 instance from DO so I can do several bitrates. Anything you would like me to test in regards to that?

from owncast.

videoSettings:
  chunkLengthInSeconds: 4
  streamingKey: cltmemphis2
  offlineContent: static/offline.m4v # Is displayed when a stream ends

  streamQualities:
    # Pass through the exact video and audio that you're streaming.
    - full:
      videoPassthrough: true
      audioPassthrough: true

    # Transcode the video to a lower bitrate and resize
    - low:
      videoBitrate: 700
      scaledWidth: 600
      audioPassthrough: true
      encoderPreset: superfast

from owncast.

And here is the output from that ffmpeg command generated:

bradley@owncast-test:~/go/src/github.com/gabek/owncast$ cat static/offline.m4v | /snap/bin/ffmpeg -hide_banner -i pipe:  -map v:0 -c:v:0 copy -map a:0 -c:a:0 copy -map v:0 -c:v:1 libx264 -b:v:1 700k -map a:0 -c:a:1 copy -filter:v:1 "scale=600:-2" -sws_flags bilinear -preset superfast  -var_stream_map "v:0,a:0 v:1,a:1 " -f hls -hls_time 10 -hls_list_size 30 -hls_delete_threshold 10 -hls_flags delete_segments+program_date_time+temp_file+append_list -tune zerolatency -sc_threshold 0 -master_pl_name stream.m3u8 -strftime 1 -hls_segment_filename webroot/hls/%v/stream-%s.ts -max_muxing_queue_size 400 webroot/hls/%v/stream.m3u8
Error: unable to open display
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x5616ac8e1680] stream 0, timescale not set
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from 'pipe:':
  Metadata:
    major_brand     : M4V
    minor_version   : 1
    compatible_brands: M4V M4A isommp42
    creation_time   : 2020-06-24T05:39:23.000000Z
    title           : Owncast Offline
    keywords        : 6-16-20
    artist          : Gabe Kangas
  Duration: 00:00:08.05, start: 0.000000, bitrate: N/A
    Stream #0:0(eng): Audio: aac (LC) (mp4a / 0x6134706D), 48000 Hz, stereo, fltp, 112 kb/s (default)
    Metadata:
      creation_time   : 2020-06-24T05:39:23.000000Z
      handler_name    : Core Media Audio
    Stream #0:1(und): Video: h264 (Main) (avc1 / 0x31637661), yuv420p(tv, smpte170m/smpte170m/bt709, progressive), 854x480 [SAR 1:1 DAR 427:240], 518 kb/s, 23.98 fps, 23.98 tbr, 24k tbn, 48k tbc (default)
    Metadata:
      creation_time   : 2020-06-24T05:39:23.000000Z
      handler_name    : Core Media Video
    Stream #0:2: Video: mjpeg, yuvj420p(pc, bt470bg/unknown/unknown), 854x480 [SAR 72:72 DAR 427:240], 90k tbr, 90k tbn, 90k tbc
Stream mapping:
  Stream #0:1 -> #0:0 (copy)
  Stream #0:0 -> #0:1 (copy)
  Stream #0:1 -> #0:2 (h264 (native) -> h264 (libx264))
  Stream #0:0 -> #0:3 (copy)
[libx264 @ 0x5616ac93a240] using SAR=3099/3092
[libx264 @ 0x5616ac93a240] using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX FMA3 BMI2 AVX2 AVX512
[libx264 @ 0x5616ac93a240] profile High, level 2.2
[libx264 @ 0x5616ac93a240] 264 - core 152 r2854 e9a5903 - H.264/MPEG-4 AVC codec - Copyleft 2003-2017 - http://www.videolan.org/x264.html - options: cabac=1 ref=1 deblock=1:0:0 analyse=0x3:0x3 me=dia subme=1 psy=1 psy_rd=1.00:0.00 mixed_ref=0 me_range=16 chroma_me=1 trellis=0 8x8dct=1 cqm=0 deadzone=21,11 fast_pskip=1 chroma_qp_offset=0 threads=2 lookahead_threads=2 sliced_threads=1 slices=2 nr=0 decimate=1 interlaced=0 bluray_compat=0 constrained_intra=0 bframes=0 weightp=1 keyint=250 keyint_min=23 scenecut=0 intra_refresh=0 rc=abr mbtree=0 bitrate=700 ratetol=1.0 qcomp=0.60 qpmin=0 qpmax=69 qpstep=4 ip_ratio=1.40 aq=1:1.00
[hls @ 0x5616ac934140] Opening 'webroot/hls/0/stream-1594243488.ts' for writing
[hls @ 0x5616ac934140] Opening 'webroot/hls/1/stream-1594243488.ts' for writing
Output #0, hls, to 'webroot/hls/%v/stream.m3u8':
  Metadata:
    major_brand     : M4V
    minor_version   : 1
    compatible_brands: M4V M4A isommp42
    artist          : Gabe Kangas
    title           : Owncast Offline
    keywords        : 6-16-20
    encoder         : Lavf58.20.100
    Stream #0:0(und): Video: h264 (Main) (avc1 / 0x31637661), yuv420p(tv, smpte170m/smpte170m/bt709, progressive), 854x480 [SAR 1:1 DAR 427:240], q=2-31, 518 kb/s, 23.98 fps, 23.98 tbr, 90k tbn, 24k tbc (default)
    Metadata:
      creation_time   : 2020-06-24T05:39:23.000000Z
      handler_name    : Core Media Video
    Stream #0:1(eng): Audio: aac (LC) (mp4a / 0x6134706D), 48000 Hz, stereo, fltp, 112 kb/s (default)
    Metadata:
      creation_time   : 2020-06-24T05:39:23.000000Z
      handler_name    : Core Media Audio
    Stream #0:2(und): Video: h264 (libx264), yuv420p, 600x338 [SAR 72163:72000 DAR 427:240], q=-1--1, 700 kb/s, 23.98 fps, 90k tbn, 23.98 tbc (default)
    Metadata:
      creation_time   : 2020-06-24T05:39:23.000000Z
      handler_name    : Core Media Video
      encoder         : Lavc58.35.100 libx264
    Side data:
      cpb: bitrate max/min/avg: 0/0/700000 buffer size: 0 vbv_delay: -1
    Stream #0:3(eng): Audio: aac (LC) (mp4a / 0x6134706D), 48000 Hz, stereo, fltp, 112 kb/s (default)
    Metadata:
      creation_time   : 2020-06-24T05:39:23.000000Z
      handler_name    : Core Media Audio
[hls @ 0x5616ac934140] Cannot use rename on non file protocol, this may lead to races and temporary partial files
[hls @ 0x5616ac934140] Opening 'webroot/hls/0/stream.m3u8' for writing
[hls @ 0x5616ac934140] Opening 'webroot/hls/1/stream.m3u8' for writing
[hls @ 0x5616ac934140] Opening 'webroot/hls/stream.m3u8' for writing
Segmentation fault (core dumped)

from owncast.

Interesting, a segfault! What version of ffmpeg are you running?

I'm on 4.2.2 locally and 4.3-static (https://johnvansickle.com/ffmpeg/) on my server.

When I ran with ffmpeg 4.1.5 I got the same segfault.

from owncast.

Updating to 4.2.2 worked..but then I got this

INFO[2020-07-09T00:34:54Z] Incoming RTMP connected.
TRAC[2020-07-09T00:34:54Z] Video transcoder started with 2 stream variants.
PANI[2020-07-09T00:34:56Z] exit status 1 cat /tmp/streampipe.ts | /snap/bin/ffmpeg -hide_banner -i pipe:  -map v:0 -c:v:0 copy -map a:0 -c:a:0 copy -map v:0 -c:v:1 libx264 -b:v:1 700k -map a:0 -c:a:1 copy -filter:v:1 "scale=600:-2" -sws_flags bilinear -preset superfast  -var_stream_map "v:0,a:0 v:1,a:1 " -f hls -hls_time 4 -hls_list_size 30 -hls_delete_threshold 10 -hls_flags delete_segments+program_date_time+temp_file -tune zerolatency -sc_threshold 0 -master_pl_name stream.m3u8 -strftime 1 -hls_segment_filename webroot/hls/%v/stream-%s.ts -max_muxing_queue_size 400 webroot/hls/%v/stream.m3u8
panic: (*logrus.Entry) (0x1e23d40,0xc0001b62a0)

goroutine 34 [running]:
github.com/sirupsen/logrus.Entry.log(0xc0000aa000, 0xc0001ad8c0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/home/bradley/go/pkg/mod/github.com/sirupsen/[email protected]/entry.go:259 +0x335
github.com/sirupsen/logrus.(*Entry).Log(0xc000547570, 0x0, 0xc000027ec0, 0x1, 0x1)
	/home/bradley/go/pkg/mod/github.com/sirupsen/[email protected]/entry.go:287 +0xeb
github.com/sirupsen/logrus.(*Entry).Logln(0xc000547570, 0xc000000000, 0xc000027f88, 0x2, 0x2)
	/home/bradley/go/pkg/mod/github.com/sirupsen/[email protected]/entry.go:378 +0xd1
github.com/sirupsen/logrus.(*Logger).Logln(0xc0000aa000, 0x0, 0xc000027f88, 0x2, 0x2)
	/home/bradley/go/pkg/mod/github.com/sirupsen/[email protected]/logger.go:240 +0x7d
github.com/sirupsen/logrus.(*Logger).Panicln(...)
	/home/bradley/go/pkg/mod/github.com/sirupsen/[email protected]/logger.go:281
github.com/sirupsen/logrus.Panicln(...)
	/home/bradley/go/pkg/mod/github.com/sirupsen/[email protected]/exported.go:219
github.com/gabek/owncast/core/ffmpeg.(*Transcoder).Start(0xc000085200)
	/home/bradley/go/src/github.com/gabek/owncast/core/ffmpeg/transcoder.go:72 +0x207
created by github.com/gabek/owncast/core/rtmp.handlePublish
	/home/bradley/go/src/github.com/gabek/owncast/core/rtmp/rtmp.go:67 +0x27a
exit status 2

Will try it after this event

from owncast.

@gabek wonder if there is a way to get the output of the ffmpeg command when it errors out, would be helpful for us to know when people report things.

from owncast.

Good idea. I just pushed a change to the branch that logs the output to transcoder.log. While not as convenient as just displaying it directly, if the log is really long then it might be a bit unwieldy.

from owncast.

I compared the command that you're running with the command that I'm running and they're the same, so I'm a bit at a loss what could be wrong. Hopefully the output from ffmpeg gives us some next steps.

from owncast.

Yes, that does indeed help! Here is the output of it

Error: unable to open display
[mpegts @ 0x55ff8d56e680] PES packet size mismatch
Input #0, mpegts, from 'pipe:':
  Duration: N/A, start: 61.726000, bitrate: 427 kb/s
  Program 1
    Stream #0:0[0x100]: Audio: aac (LC) ([15][0][0][0] / 0x000F), 48000 Hz, stereo, fltp, 427 kb/s
Stream map 'v:0' matches no streams.
To ignore this, add a trailing '?' to the map.

from owncast.

Is that coming from Restream? It seems to think there's no video. I'll add that recommendation to ignore missing audio and/or video, but I'm guessing there's supposed to be video :)

from owncast.

Yes sir, that is all coming from Restream. When I use OBS directly to owncast it works perfectly. Wonder what exactly Restream is doing here

from owncast.

The testing I was doing previously was using Restream Studio to just stream the webcam. Let me try pointing OBS -> Restream -> Owncast.

from owncast.

ERRO[2020-07-09T01:46:34Z]/home/bradley/go/src/github.com/gabek/owncast/core/ffmpeg/transcoder.go:76 github.com/gabek/owncast/core/ffmpeg.(*Transcoder).Start() Transcoder error.  See transcoder.log for full output to debug.
PANI[2020-07-09T01:46:34Z]/home/bradley/go/src/github.com/gabek/owncast/core/ffmpeg/transcoder.go:77 github.com/gabek/owncast/core/ffmpeg.(*Transcoder).Start() exit status 1 cat /tmp/streampipe.ts | /snap/bin/ffmpeg -hide_banner -i pipe:  -map v:0 -c:v:0 copy -map a:0 -c:a:0 copy -map v:0 -c:v:1 libx264 -b:v:1 700k -map a:0 -c:a:1 copy -filter:v:1 "scale=600:-2" -sws_flags bilinear -preset superfast  -var_stream_map "v:0?,a:0? v:1?,a:1? " -f hls -hls_time 4 -hls_list_size 30 -hls_delete_threshold 10 -hls_flags delete_segments+program_date_time+temp_file -tune zerolatency -sc_threshold 0 -master_pl_name stream.m3u8 -strftime 1 -hls_segment_filename webroot/hls/%v/stream-%s.ts -max_muxing_queue_size 400 webroot/hls/%v/stream.m3u8 2> transcoder.log
panic: (*logrus.Entry) (0x1e23d00,0xc00055c070)

goroutine 36 [running]:
github.com/sirupsen/logrus.Entry.log(0xc000130000, 0xc000114f00, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/home/bradley/go/pkg/mod/github.com/sirupsen/[email protected]/entry.go:259 +0x335
github.com/sirupsen/logrus.(*Entry).Log(0xc0000d0000, 0x0, 0xc0000e5e98, 0x1, 0x1)
	/home/bradley/go/pkg/mod/github.com/sirupsen/[email protected]/entry.go:287 +0xeb
github.com/sirupsen/logrus.(*Entry).Logln(0xc0000d0000, 0xc000000000, 0xc0000e5f88, 0x2, 0x2)
	/home/bradley/go/pkg/mod/github.com/sirupsen/[email protected]/entry.go:378 +0xd1
github.com/sirupsen/logrus.(*Logger).Logln(0xc000130000, 0x0, 0xc0000e5f88, 0x2, 0x2)
	/home/bradley/go/pkg/mod/github.com/sirupsen/[email protected]/logger.go:240 +0x7d
github.com/sirupsen/logrus.(*Logger).Panicln(...)
	/home/bradley/go/pkg/mod/github.com/sirupsen/[email protected]/logger.go:281
github.com/sirupsen/logrus.Panicln(...)
	/home/bradley/go/pkg/mod/github.com/sirupsen/[email protected]/exported.go:219
github.com/gabek/owncast/core/ffmpeg.(*Transcoder).Start(0xc00007f920)
	/home/bradley/go/src/github.com/gabek/owncast/core/ffmpeg/transcoder.go:77 +0x2a6
created by github.com/gabek/owncast/core/rtmp.handlePublish
	/home/bradley/go/src/github.com/gabek/owncast/core/rtmp/rtmp.go:67 +0x27a
exit status 2
bradley@owncast-test:~/go/src/github.com/gabek/owncast$ cat transcoder.log
Error: unable to open display
[mpegts @ 0x55ed854e3680] PES packet size mismatch
Input #0, mpegts, from 'pipe:':
  Duration: N/A, start: 715.273000, bitrate: 386 kb/s
  Program 1
    Stream #0:0[0x100]: Audio: aac (LC) ([15][0][0][0] / 0x000F), 48000 Hz, stereo, fltp, 386 kb/s
Stream map 'v:0' matches no streams.
To ignore this, add a trailing '?' to the map.

from owncast.

Yeah, we're going from OBS -> Restream -> Facebook, YouTube

from owncast.

Hah! Previously I mentioned how I couldn't write as flv with this implementation of RTMP? With Restream it only works if I write flv. Restream works fine if I change muxer := ts.NewMuxer(f) -> muxer := flv.NewMuxer(f).

But if I point OBS directly to Owncast it won't work with flv at all. I'll have to figure out what's different between the two.

from owncast.

Oh wow, that’s crazy!

from owncast.

Ok @graywolf336, here's what I've come up with!

It seems like passing along Restream video without transcoding is not an option. I don't know why, it's just... different. So I think that's why I'm seeing all the randomness. It wasn't truly random. It's playable when it's transcoded, and it fails when we pass along the video transparently.

If you get a chance, pull gek/rtmp-v2 and give it a go with Restream and OBS, but with your config not using videoPassthrough and see if it makes a difference.

Hopefully we're getting closer to a solution with Restream! Thanks for dealing with all this back and forth troubleshooting.

from owncast.

@gabek Going to try it this morning. If I don't provide a video scaled width, what happens?

from owncast.

If you don’t provide a width and/or height it’ll just keep the source size.

Oh yeah! We spoke previously about incorrect aspect ratios when it comes to resizing but I think I resolved that with the new transcoder as long as you only specify a width or height but not both. But really you shouldn’t need to specify either unless you actually have a reason to resize.

from owncast.

So far, so good! Currently going good with 35+ minutes of stream from restream.

One thing that i noticed, and we need to look into it in more detail, but it appears the web portal pulls lowest quality stream. Would be nice to have the ability to select which stream quality we could choose 🤔

from owncast.

If you change the order of the qualities to highest first in the config it should use that first and stick with it. My original thought was lowest first for quick startup time but yeah, sometimes it never moves on from the low quality. Sometimes it does. So maybe it’s safer just to keep high first and let players drop down to lower instead of the opposite.

from owncast.

Yeah, the highest quality is first. 🤔 The second bitrate is the lowest one.

I sent you a link to my owncast instance, on Mastodon, in case you wanted to see how it is doing :)

from owncast.

So cool! I popped the url to your high quality variant (/hls/0/stream.m3u8) into Quicktime directly and it's playing great. I wonder what about the web player thinks 1 is a better choice than zero. hmmm.

from owncast.

I think we can mark this as closed when this code is merged. Just will need to add a comment/note to the restream documentation that transcoding is required when using restream.

Do you want me to open an issue about the web player?

from owncast.