Video stops playing

mike48085 · August 3, 2019, 4:18am

What's the best way? OK, getting late - you want me to email. Will do.

eric · August 3, 2019, 4:22am

You can go to http://localhost:8089/log to get the log file.

mike48085 · August 3, 2019, 4:29am

Just sent...

eric · August 3, 2019, 4:37am

It looks like you don’t have the hack enabled that @tmm1 listed above. Could you enable it and see if that improves the situation?

mike48085 · August 3, 2019, 12:03pm

I still get stoppages when I click on various spots on the timeline. Sometimes it is a 2-5 second delay before playing, other times more than 30 seconds and no playback. That's with hardware transcoding enabled.

Do you want me to send another log file?

I have never used Powershell before. Did I do it correctly this time?

Jackamus · August 3, 2019, 12:29pm

Updated to 2019.08.03.0221 and what a big difference in quality. So much better. Although the video looks a little "soft". Watched a TV show for an hour and on hardware encoding the video unexpectedly stopped playing. Switched to software encoding and it stopped playing shortly after seeking past a commercial break. Switched server quality down to 8mpbs using software encoding and hardware encoding and so far there has been no unexpected stops in the video. I have no idea why lowering to 8mbps works better for me. However, as noted before, 10mbps was never an issue.

tmm1 · August 3, 2019, 3:10pm

Can you open the javascript console in your browser, and when it stops playing see if any error messages are shown in there?

tmm1 · August 3, 2019, 3:13pm

Yes if it says true then it worked.

If you're trying to watch older recordings you may need to click the gear icon for then and click Generate Streaming Index first

mike48085 · August 3, 2019, 5:25pm

No, I don't believe errors are showing up in the javascript console. Here are the last console readings as my video just now stopped on its own. I hit the gear icon to regen the index before I started the video:

VIDEOJS: Cast APIs are available
bundle.js:23 event {Type: "activities.set", Name: "7-file3998-ip127.0.0.1---10000-1080-1", Value: "Streaming recording ABC World News Tonight With David Muir 2019-08-01 2019-08-01-1830.mpg."}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852492075}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852494083}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852496080}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852498073}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852500074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852502074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852504074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852506074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852508074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852510075}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852512073}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852514074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852516074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852518073}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852520074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852522073}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852524073}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852526073}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852528074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852530074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852532074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852534074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852536073}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852538073}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852540074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852542076}
bundle.js:23 event {Type: "activities.set", Name: "7-file3998-ip127.0.0.1---10000-1080-1", Value: "Watching recording ABC World News Tonight With Dav….mpg from 127.0.0.1 (Transcoder Starting: 4m24s)."}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852548073}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852550075}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852552074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852554074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852556073}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852558074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852560074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852564074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852566074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852568075}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852570074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852576075}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852578074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852580074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852600074}
bundle.js:23 event {Type: "activities.set", Name: "7-file3998-ip127.0.0.1---10000-1080-1", Value: "Watching recording ABC World News Tonight With Dav…mpg from 127.0.0.1 (Transcoder Starting: 21m36s)."}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852632074}
bundle.js:23 event {Type: "activities.set", Name: "7-file3998-ip127.0.0.1---10000-1080-1", Value: "Watching recording ABC World News Tonight With Dav…m 127.0.0.1 (Transcoder Running: 26m41s @ 2.06x)."}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852664074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852666074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852668074}
bundle.js:23 event {Type: "files.updated", Name: "3998", UpdatedAt: 1564852670076}

eric · August 3, 2019, 5:46pm

The next time this happens where it stops could you send the DVR log to [email protected]?

Jackamus · August 3, 2019, 6:22pm

Yes, I will.

eric · August 3, 2019, 9:56pm

I've just released v2019.08.03.2112 that has another small improvement for OTA recordings using the new streaming.indexed_transcoding. It will require that you select "Regenerate Video Index" for the recording and then check the logs to see when it finishes before you will be able to see the impact of the change.

Note: Regarding the speed of these changes and number of steps to use them, the new transcoder is under active development and we had not intended for people to test it out this soon but decided it was worth seeing if it fixes these issues that you have been seeing with the pausing. Some of these rough edges (like having to regenerate the indexes) will be fixed before we roll this out more widely.

Jackamus · August 3, 2019, 10:17pm

I will update and report back. What does "Regenerate Video Index" actually do? I haven't sent any logs yet because for two shows I ran for two hours never had an issue.

eric · August 3, 2019, 10:56pm

It reprocesses a file that we use to make sure that we seek to accurate positions while transcoding.

You'll see messages in the logs after you run "Regenerate Video Index" like:

2019/08/03 14:46:57 [IDX] Generating video index for file-2130: Formula 1 Racing Rolex Hungarian Grand Prix Qualifying 2019-08-03-0554.mpg
2019/08/03 14:48:57 [IDX] Finished video index generation for file-2130 in 119s

Jackamus · August 3, 2019, 11:11pm

The update installed and I did Regenerate to two files.

019/08/03 18:30:31 [IDX] Generating video index for file-747: Animal Kingdom S04E10 2019-07-30 Exit Strategy 2019-07-30-2059.mpg
2019/08/03 18:30:33 [IDX] Generating video index for file-693: Animal Kingdom S04E09 2019-07-23 SHTF 2019-07-23-2059.mpg
2019/08/03 18:31:11 [NAT] Successfully mapped port 8089 using upnp
2019/08/03 18:36:48 [IDX] Finished video index generation for file-693 in 374s
2019/08/03 18:38:15 [IDX] Finished video index generation for file-747 in 464s

Jackamus · August 4, 2019, 2:52pm

I have not had the issue since updating. I believe this update has corrected the issue.

eric · August 4, 2019, 7:42pm

That’s great news! Please let us know if you run into anything else funny going on.

mike48085 · August 5, 2019, 2:26pm

I still get stoppages when clicking on random locations in the progress bar.

Version 2019.08.04.2357, new transcoder, hardware transcoding on, file re-indexed before viewing.

Last few lines of log file:

[hls @ 00000000012ac980] Non-monotonous DTS in output stream 0:0; previous: 172876087, current: 172876087; changing to 172876088. This may result in incorrect timestamps in the output file.
[h264_qsv @ 00000000012b0580] Warning during encoding: incompatible video parameters (5)
    Last message repeated 1 times
[hls @ 00000000012ac980] Non-monotonous DTS in output stream 0:0; previous: 172891102, current: 172891102; changing to 172891103. This may result in incorrect timestamps in the output file.
[h264_qsv @ 00000000012b0580] Warning during encoding: incompatible video parameters (5)
    Last message repeated 1 times
[hls @ 00000000012ac980] Non-monotonous DTS in output stream 0:0; previous: 172906117, current: 172906117; changing to 172906118. This may result in incorrect timestamps in the output file.
[h264_qsv @ 00000000012b0580] Warning during encoding: incompatible video parameters (5)
    Last message repeated 1 times
[hls @ 00000000012ac980] Non-monotonous DTS in output stream 0:0; previous: 172921132, current: 172921132; changing to 172921133. This may result in incorrect timestamps in the output file.
[h264_qsv @ 00000000012b0580] Warning during encoding: incompatible video parameters (5)
[hls @ 00000000012ac980] Non-monotonous DTS in output stream 0:0; previous: 172936147, current: 172936147; changing to 172936148. This may result in incorrect timestamps in the output file.
[hls @ 00000000012ac980] Non-monotonous DTS in output stream 0:0; previous: 172951162, current: 172951162; changing to 172951163. This may result in incorrect timestamps in the output file.
[h264_qsv @ 00000000012b0580] Warning during encoding: incompatible video parameters (5)
2019/08/05 10:19:04 [ENC] Segment 440 has unexpected duration 155. expected=1.618 actual=10.294 expected_pts=551.261000-552.879000 actual_pts=1916.307544-1926.567789
2019/08/05 10:19:04 [ENC] Segment 440 using encoded segment 440 (10.293611): duration=10.282789 video_duration=10.260244 video_pid=256 video_pts=1916.307544-1926.567789 pts=1916.285000-1926.567789 file=D:\! Channels_DVR\Streaming\file4022-ip127.0.0.1---10000-1080-1\encoder-286-064584134\stream440.ts
2019/08/05 10:19:04 [ENC] Encoded segment 440 at 551.2610-552.8790 (1916.3075-1926.5678) for 10.294 as D:\! Channels_DVR\Streaming\file4022-ip127.0.0.1---10000-1080-1\encoder-286-064584134\stream440.ts to D:\! Channels_DVR\Streaming\file4022-ip127.0.0.1---10000-1080-1\stream440.ts
2019/08/05 10:19:05 [ENC] Segment 441 has unexpected duration 156. expected=1.168 actual=10.427 expected_pts=552.879000-554.047000 actual_pts=1926.601156-1936.994878
2019/08/05 10:19:05 [ENC] Segment 441 using encoded segment 441 (10.427089): duration=10.405878 video_duration=10.393722 video_pid=256 video_pts=1926.601156-1936.994878 pts=1926.589000-1936.994878 file=D:\! Channels_DVR\Streaming\file4022-ip127.0.0.1---10000-1080-1\encoder-286-064584134\stream441.ts
2019/08/05 10:19:05 [ENC] Encoded segment 441 at 552.8790-554.0470 (1926.6012-1936.9949) for 10.427 as D:\! Channels_DVR\Streaming\file4022-ip127.0.0.1---10000-1080-1\encoder-286-064584134\stream441.ts to D:\! Channels_DVR\Streaming\file4022-ip127.0.0.1---10000-1080-1\stream441.ts
2019/08/05 10:19:06 [ENC] Segment 442 has unexpected duration 157. expected=1.251 actual=10.427 expected_pts=554.047000-555.298000 actual_pts=1937.028244-1947.421956
2019/08/05 10:19:06 [ENC] Segment 442 using encoded segment 442 (10.427078): duration=10.422289 video_duration=10.393711 video_pid=256 video_pts=1937.028244-1947.421956 pts=1936.999667-1947.421956 file=D:\! Channels_DVR\Streaming\file4022-ip127.0.0.1---10000-1080-1\encoder-286-064584134\stream442.ts
2019/08/05 10:19:06 [ENC] Encoded segment 442 at 554.0470-555.2980 (1937.0282-1947.4220) for 10.427 as D:\! Channels_DVR\Streaming\file4022-ip127.0.0.1---10000-1080-1\encoder-286-064584134\stream442.ts to D:\! Channels_DVR\Streaming\file4022-ip127.0.0.1---10000-1080-1\stream442.ts
2019/08/05 10:19:07 [ENC] Stopped encoder for The Good Fight S01E10 2017-04-16 Chaos 2019-08-04-2200.mpg in D:\! Channels_DVR\Streaming\file4022-ip127.0.0.1---10000-1080-1\encoder-286-064584134 after encoding 286 to 442

eric · August 5, 2019, 4:59pm

Could you post this recording on Dropbox or google Drive and send the link to [email protected]? There’s something unusual going on with it.

mike48085 · August 5, 2019, 7:09pm

OK, let me work on it.