OpenDCT: An open source digital cable tuner.

[EnterNoEscape]

I have not forgotten about your request. I even now have the right infrastructure to test this at home. It's just that it's a little harder to get this going than it looks like on the surface because I really want to give the HDHomeRun devices their own proper capture device implementation and detection method. Things are starting to firm up on how those devices are safely manipulated while the program is running, but we're still looking at a few weeks at least before I can start to tackle your specific request.

[nyplayer]

ever since they have converted some channels to H264 I am seeing this a lot.

 DCTCaptureDeviceImpl - Starting the encoding for the channel '794' from the device 'DCT-HDHomeRun Prime Tuner 13147C7B-1' to the file '\\NYPLAYER\SAGEN\DeathbyGossipWithWendyWilliams-HerLastChristmas-23274419-0.ts'...
INFO   | jvm 1    | 2016/02/05 08:08:41.745 | 08:08:41.715 [SageTVRequestHandler-204:DCT-HDHomeRun Prime Tuner 131A192A-2 > DCT-HDHomeRun Prime Tuner 13147C7B-1] INFO  DCTCaptureDeviceImpl - HDHomeRun is now locked.
INFO   | jvm 1    | 2016/02/05 08:08:41.745 | 08:08:41.724 [SageTVRequestHandler-204:DCT-HDHomeRun Prime Tuner 131A192A-2 > DCT-HDHomeRun Prime Tuner 13147C7B-1] INFO  DCTCaptureDeviceImpl - Configuring and starting the new RTP producer...
INFO   | jvm 1    | 2016/02/05 08:08:41.745 | 08:08:41.726 [RTCPClient-211] INFO  RTCPClient - RTCP client thread is running.
INFO   | jvm 1    | 2016/02/05 08:08:41.745 | 08:08:41.726 [NIORTPProducerImpl-212:DCT-HDHomeRun Prime Tuner 13147C7B-1] INFO  NIORTPProducerImpl - Producer thread is running.
INFO   | jvm 1    | 2016/02/05 08:08:41.745 | 08:08:41.726 [PacketsMonitor-214:NIORTPProducerImpl-212:DCT-HDHomeRun Prime Tuner 13147C7B-1] INFO  NIORTPProducerImpl - Producer packet monitoring thread is running.
INFO   | jvm 1    | 2016/02/05 08:08:41.745 | 08:08:41.727 [SageTVRequestHandler-204:DCT-HDHomeRun Prime Tuner 131A192A-2 > DCT-HDHomeRun Prime Tuner 13147C7B-1] INFO  DCTCaptureDeviceImpl - Configuring and starting the new SageTV consumer...
INFO   | jvm 1    | 2016/02/05 08:08:41.745 | 08:08:41.728 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] INFO  FFmpegSageTVConsumerImpl - FFmpeg consumer thread is now running.
INFO   | jvm 1    | 2016/02/05 08:08:41.745 | 08:08:41.728 [TuningMonitor-217:DCT-HDHomeRun Prime Tuner 13147C7B-1] INFO  DCTCaptureDeviceImpl - Tuning monitoring thread started.
INFO   | jvm 1    | 2016/02/05 08:08:42.452 | 08:08:42.439 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] INFO  FFmpegSageTVConsumerImpl - Before avformat_find_stream_info() pos=20680 bytes_read=20680 seek_count=0. probesize: 800128 analyzeduration: 800000.
INFO   | jvm 1    | 2016/02/05 08:08:42.856 | 08:08:42.844 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] ERROR ffmpeg - [h264 @ 07311e40] non-existing SPS 0 referenced in buffering period
INFO   | jvm 1    | 2016/02/05 08:08:42.856 | 08:08:42.844 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] ERROR ffmpeg - [h264 @ 07311e40] non-existing PPS 0 referenced
INFO   | jvm 1    | 2016/02/05 08:08:42.856 | 08:08:42.845 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] ERROR ffmpeg - [h264 @ 07311e40] non-existing SPS 0 referenced in buffering period
INFO   | jvm 1    | 2016/02/05 08:08:42.856 | 08:08:42.845 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] ERROR ffmpeg - [h264 @ 07311e40] non-existing PPS 0 referenced
INFO   | jvm 1    | 2016/02/05 08:08:42.856 | 08:08:42.845 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] ERROR ffmpeg - [h264 @ 07311e40] decode_slice_header error
INFO   | jvm 1    | 2016/02/05 08:08:42.856 | 08:08:42.845 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] ERROR ffmpeg - [h264 @ 07311e40] no frame!
INFO   | jvm 1    | 2016/02/05 08:08:42.957 | 08:08:42.873 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] ERROR ffmpeg - [h264 @ 07311e40] non-

[EnterNoEscape]

Originally Posted by nyplayer

ever since they have converted some channels to H264 I am seeing this a lot.

 DCTCaptureDeviceImpl - Starting the encoding for the channel '794' from the device 'DCT-HDHomeRun Prime Tuner 13147C7B-1' to the file '\\NYPLAYER\SAGEN\DeathbyGossipWithWendyWilliams-HerLastChristmas-23274419-0.ts'...
INFO   | jvm 1    | 2016/02/05 08:08:41.745 | 08:08:41.715 [SageTVRequestHandler-204:DCT-HDHomeRun Prime Tuner 131A192A-2 > DCT-HDHomeRun Prime Tuner 13147C7B-1] INFO  DCTCaptureDeviceImpl - HDHomeRun is now locked.
INFO   | jvm 1    | 2016/02/05 08:08:41.745 | 08:08:41.724 [SageTVRequestHandler-204:DCT-HDHomeRun Prime Tuner 131A192A-2 > DCT-HDHomeRun Prime Tuner 13147C7B-1] INFO  DCTCaptureDeviceImpl - Configuring and starting the new RTP producer...
INFO   | jvm 1    | 2016/02/05 08:08:41.745 | 08:08:41.726 [RTCPClient-211] INFO  RTCPClient - RTCP client thread is running.
INFO   | jvm 1    | 2016/02/05 08:08:41.745 | 08:08:41.726 [NIORTPProducerImpl-212:DCT-HDHomeRun Prime Tuner 13147C7B-1] INFO  NIORTPProducerImpl - Producer thread is running.
INFO   | jvm 1    | 2016/02/05 08:08:41.745 | 08:08:41.726 [PacketsMonitor-214:NIORTPProducerImpl-212:DCT-HDHomeRun Prime Tuner 13147C7B-1] INFO  NIORTPProducerImpl - Producer packet monitoring thread is running.
INFO   | jvm 1    | 2016/02/05 08:08:41.745 | 08:08:41.727 [SageTVRequestHandler-204:DCT-HDHomeRun Prime Tuner 131A192A-2 > DCT-HDHomeRun Prime Tuner 13147C7B-1] INFO  DCTCaptureDeviceImpl - Configuring and starting the new SageTV consumer...
INFO   | jvm 1    | 2016/02/05 08:08:41.745 | 08:08:41.728 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] INFO  FFmpegSageTVConsumerImpl - FFmpeg consumer thread is now running.
INFO   | jvm 1    | 2016/02/05 08:08:41.745 | 08:08:41.728 [TuningMonitor-217:DCT-HDHomeRun Prime Tuner 13147C7B-1] INFO  DCTCaptureDeviceImpl - Tuning monitoring thread started.
INFO   | jvm 1    | 2016/02/05 08:08:42.452 | 08:08:42.439 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] INFO  FFmpegSageTVConsumerImpl - Before avformat_find_stream_info() pos=20680 bytes_read=20680 seek_count=0. probesize: 800128 analyzeduration: 800000.
INFO   | jvm 1    | 2016/02/05 08:08:42.856 | 08:08:42.844 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] ERROR ffmpeg - [h264 @ 07311e40] non-existing SPS 0 referenced in buffering period
INFO   | jvm 1    | 2016/02/05 08:08:42.856 | 08:08:42.844 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] ERROR ffmpeg - [h264 @ 07311e40] non-existing PPS 0 referenced
INFO   | jvm 1    | 2016/02/05 08:08:42.856 | 08:08:42.845 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] ERROR ffmpeg - [h264 @ 07311e40] non-existing SPS 0 referenced in buffering period
INFO   | jvm 1    | 2016/02/05 08:08:42.856 | 08:08:42.845 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] ERROR ffmpeg - [h264 @ 07311e40] non-existing PPS 0 referenced
INFO   | jvm 1    | 2016/02/05 08:08:42.856 | 08:08:42.845 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] ERROR ffmpeg - [h264 @ 07311e40] decode_slice_header error
INFO   | jvm 1    | 2016/02/05 08:08:42.856 | 08:08:42.845 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] ERROR ffmpeg - [h264 @ 07311e40] no frame!
INFO   | jvm 1    | 2016/02/05 08:08:42.957 | 08:08:42.873 [FFmpegSageTVConsumerImpl-216:DCT-HDHomeRun Prime Tuner 13147C7B-1] ERROR ffmpeg - [h264 @ 07311e40] non-

You're going to see that with H.264 because of how the protocol is allowed to reference frames within the stream. All this mean in reality is that the first key frame has not been located yet or for some reason a key frame was missing/broken. I would imagine this mostly is seen when a recording starts. Is this resulting in any bad recordings?

On that note: H.264 content sometimes takes a very long time ( > 5 seconds) to actually send a key frame and this is enough time to in some cases exhaust the circular buffers default size. The next public beta addresses this by allowing the circular buffer to expand during the detection period up to 3 times in size. That should be more than enough to get the job done. The reason for it being dynamic is because it's an incredible waste of memory to have a huge "just in case" sized buffer.

[nyplayer]

Originally Posted by EnterNoEscape

You're going to see that with H.264 because of how the protocol is allowed to reference frames within the stream. All this mean in reality is that the first key frame has not been located yet or for some reason a key frame was missing/broken. I would imagine this mostly is seen when a recording starts. Is this resulting in any bad recordings?

No problems with recordings that I have seen.

[jgsouthard]

After about three weeks of totally clean recordings, I got Halt in Recording errors last night on one recording. The recording continued and completed successfully, after starting ~30 seconds late and hiccuping twice during recording. Checking the logs, I'm seeing the occurrence of errors that I haven't noticed before.

I'm running OpenDCT 0.4.18. I've attached wrapper.log, my opendct.properties file, and a text file showing which properties I've changed from defaults.

The Halts occurred 2016/02/04 at time 22:01:52 and again at time 22:06 (approx.).

Here are the errors I'm seeing:

INFO   | jvm 1    | 2016/02/04 22:01:52.518 | 22:01:52.486 [FFmpegSageTVConsumerImpl-3041:DCT-HDHomeRun Prime Tuner 132277E9-0] ERROR ffmpeg - [mpegts @ 16f71f60] Application provided invalid, non monotonically increasing dts to muxer in stream 2: 7025726316 >= 7025669693
INFO   | jvm 1    | 2016/02/04 22:01:52.518 | 22:01:52.486 [FFmpegSageTVConsumerImpl-3041:DCT-HDHomeRun Prime Tuner 132277E9-0] ERROR FFmpegSageTVConsumerImpl - Error -22 while writing packet at input stream offset 224563556.
INFO   | jvm 1    | 2016/02/04 22:01:52.518 | 22:01:52.486 [FFmpegSageTVConsumerImpl-3041:DCT-HDHomeRun Prime Tuner 132277E9-0] ERROR ffmpeg - [mpegts @ 16f71f60] Application provided invalid, non monotonically increasing dts to muxer in stream 2: 7025726316 >= 7025672573
INFO   | jvm 1    | 2016/02/04 22:01:52.518 | 22:01:52.486 [FFmpegSageTVConsumerImpl-3041:DCT-HDHomeRun Prime Tuner 132277E9-0] ERROR FFmpegSageTVConsumerImpl - Error -22 while writing packet at input stream offset -1.
INFO   | jvm 1    | 2016/02/04 22:01:52.518 | 22:01:52.486 [FFmpegSageTVConsumerImpl-3041:DCT-HDHomeRun Prime Tuner 132277E9-0] ERROR ffmpeg - [mpegts @ 16f71f60] Application provided invalid, non monotonically increasing dts to muxer in stream 2: 7025726316 >= 7025675453
INFO   | jvm 1    | 2016/02/04 22:01:52.518 | 22:01:52.486 [FFmpegSageTVConsumerImpl-3041:DCT-HDHomeRun Prime Tuner 132277E9-0] ERROR FFmpegSageTVConsumerImpl - Error -22 while writing packet at input stream offset -1.

Many of these errors occurred at 22:01:52 (the first halt), and then it looks like OpenDCT reset/retuned the tuner and the recording restarted. But then it halted again at about 22:06 and again reset/retuned the tuner and the recording continued. It isn't clear to me why the second halt occurred, since there seem to be no errors at that point.

Any hints as to what might be going on with this, or any properties changes that might help? I noticed in an earlier post that it was now recommended to set consumer.ffmpeg.upload_id_enabled=false, but I still have it set to true since that was the default in v0.4.18. Should I make that change?

[EnterNoEscape]

I'm starting to wonder just how reliable upload id is when SageTV is close to it's heap size limits. SageTV did not stop responding as far as I can tell. I can't figure out anything from that log file either.

Can you post all of the log files from yesterday under C:\ProgramData\OpenDCT\logs\archive?

[jgsouthard]

Originally Posted by EnterNoEscape

I'm starting to wonder just how reliable upload id is when SageTV is close to it's heap size limits. SageTV did not stop responding as far as I can tell. I can't figure out anything from that log file either.

Can you post all of the log files from yesterday under C:\ProgramData\OpenDCT\logs\archive?

Thanks. Here are the two log archives from yesterday.

[EnterNoEscape]

Based on what I'm seeing in that log, it looks like in the first failure might have been the stream became corrupted. Unfortunately I do not know why, but the errors basically mean that the packets are taking longer than expected to come in or possibly there's a hangup writing them out. The same thread that runs FFmpeg also writes the results, so either end could cause this error. I feel like I becoming more experienced in understanding FFmpeg errors than I ever thought I would be.

The second failure looks like it happened because nothing or very little was written to the file. I have to assume this because I don't see the log entry indicating that the first few bytes were written.

When we get to the third tuning attempt, whatever was causing this issue seems to have cleared up and suddenly everything is working ok. The fact that detection itself worked without issue all 3 times and the errors only came once it came time to write the data to disk, means to me that either upload id wasn't actually writing the data/failing in some silent way, your disk was very congested at the time of the recording or there was some other issue outside of the program .

[jgsouthard]

Originally Posted by EnterNoEscape

Based on what I'm seeing in that log, it looks like in the first failure might have been the stream became corrupted. Unfortunately I do not know why, but the errors basically mean that the packets are taking longer than expected to come in or possibly there's a hangup writing them out. The same thread that runs FFmpeg also writes the results, so either end could cause this error. I feel like I becoming more experienced in understanding FFmpeg errors than I ever thought I would be.

The second failure looks like it happened because nothing or very little was written to the file. I have to assume this because I don't see the log entry indicating that the first few bytes were written.

When we get to the third tuning attempt, whatever was causing this issue seems to have cleared up and suddenly everything is working ok. The fact that detection itself worked without issue all 3 times and the errors only came once it came time to write the data to disk, means to me that either upload id wasn't actually writing the data/failing in some silent way, your disk was very congested at the time of the recording or there was some other issue outside of the program .

Thanks for looking into this so promptly. For now I'll assume that it was an anomaly since I haven't been seeing the issue in general.

[KryptoNyte]

I have seen (1) halted recording so far in the last 7 days, almost near the end of the recording. It was different that I've seen previously, where one entire Prime disappears from the network. This time the Prime was still present, Sage recovered from this without consequence and went on to record the rest of the scheduled recordings for the day.

I'd put this one on the cable company.

[EnterNoEscape]

If you're interested in possibly finding out why it happened, post the logs from the day it happened. While there are some situations OpenDCT alone isn't going to be able to address, there are bound to be some issues that can be fixed or minimized. I generally don't want people seeing halted recordings unless it is due to a usage related delay in writing the data out to the hard drive.

This doesn't really help anyone, but I personally haven't seen any halts except for the CGMS-A thing I've mentioned a few times and that only happens on my InfiniTV 4. Having a web interface is really going to clear these things up quickly for anyone wanting to know why their recording halted/failed. The log files contain similar data, but you have to hunt for it. Unfortunately the web interface keeps getting push out because of other more pressing issues.

[KryptoNyte]

Emailed logs. This Sage Server has (2) Prime tuners, OpenDCT_0.4.17_x86, java 1.7.80 32 bit.

I also included the Sage message of the halted recording w/time.

[EnterNoEscape]

I saw a smattering of these type of warnings when the halt was detected. It doesn't look like SageTV actually re-tuned the channel even though the message would suggest it. My best guess is the issue is exactly what you said, or a signal quality issue from demodulation.

10:38:45.289 [FFmpegSageTVConsumerImpl-52254:DCT-HDHomeRun Prime Tuner 131B5A52-0] WARN  ffmpeg - [mpegts @ 0a6b3040] PES packet size mismatch

I also see that infrequently a few packets didn't make it in on other recordings. To try to help with this (and not as a result of this log), the default receive buffer size has been increased for the next beta. I suspect with UDP we will always have these problems, which is why I'm going to eventually be taking advantage of the http streaming available on the Prime. TCP by design is actually reliable.

[KryptoNyte]

This was definitely a different kind of halt. In the past, the offending Prime would disappear. Admittedly, when I replaced SageDCT with OpenDCT, I also took that opportunity to upgrade the firmware on both Primes, essentially replacing 2 year old firmware.

Both Primes have been up for over a week now without a power cycle, which is a first in 2 years, regardless of the one single halt. Most notably, the halt didn't affect any other recordings which is fantastic.

Thank you for reviewing those logs!

[nyplayer]

Here are my Logs and properties from my production pc you will notice it finds the connects but they do no say they are ready.

[EnterNoEscape]

I can the the most immediate problem is the HDHomeRun discovery method can't open a port it wants to open. The port is likely 65001 and I don't know if that one is optional. I'll look into it.

Update: It looks like it doesn't matter, that's good.

Update2: I also figure out what SageTV is doing to get the values for the ATSC channels, but the way Silicondust has cleaned up their display names, makes it a little harder than it should be to return correct values for channel scanning.

[nyplayer]

Originally Posted by EnterNoEscape

I can the the most immediate problem is the HDHomeRun discovery method can't open a port it wants to open. The port is likely 65001 and I don't know if that one is optional. I'll look into it.

Update: It looks like it doesn't matter, that's good.

Update2: I also figure out what SageTV is doing to get the values for the ATSC channels, but the way Silicondust has cleaned up their display names, makes it a little harder than it should be to return correct values for channel scanning.

What is weird is that om my test laptop it finds them and makes them ready on my production system it just never makes them ready. I opened all ports tried again same thing.

[nyplayer]

Same Problem ... the big difference between my Sage Production and my test laptops are java versions ... I am on java 1.8 on my laptop and java 1.7 on my production system.

I seem to be getting this error.

INFO | jvm 1 | 2016/02/09 18:15:15.521 | 18:15:15.452 [UPnPDiscovery-33] INFO UpnpManager - Capture device count reached. UPnP discovery thread has stopped.

[iammike]

Hi everyone,

It's been a long time since I last posted to the Sage forums. I tried installing OpenDCT this evening and am having some trouble getting it to work. It would seem to be finding my HDHomerun Prime okay, but I'm getting the "No Signal" message when I try to tune a channel. I installed the .4.18 beta of OpenDCT, my Sage server is on Windows 8.1 and I'm running Sage version 7.1.9. I've also updated my Java to the latest version.

I've uploaded my log and config files. If someone could take a look at the files, and point me in the right direction or make a suggestion, it would be most appreciated.

Incidentally as a long time Sage user (almost 10 years), it's really nice to see tools like this being developed and supported for Sage again. Many thanks to EnterNoEscape.

Mike

[Telecore]

OpenDCT has been working very well for several weeks - but just experienced a problem - tried to change channel to CBS and it locked up - got spinning circle. Rebooted Sage server and repeated and it happened again. This is on my Sage V7 server Win7 x64. CBS came in fine on my Avermedia card, though. Crash logs are attached.