recording gaps - tuner lost

[EnterNoEscape]

Originally Posted by Narflex

The only reason I can think this would happen is if OpenDCT is shortening the file length at certain points in time. SageTV assumes that recording files always grow in size and will never be smaller than any size they have had before (during playback only, if you stop and transcode it later, that's fine).

Can the OpenDCT dev weigh in on that point? If you don't think OpenDCT is doing this, then I'll create a JAR file that has more debugging to verify my theory is correct...because I'm wrong sometimes of course.

The only situation in which the file size might shrink is if for any reason the file goes missing (it would be illogical to cause the file system to just write zeros up to the last known offset). However there is no indication in the logs that that the file was re-created. There would be a message whether it was successful or failed. All writing is done using FileChannel.

I am currently testing some code that makes sure the file is actually growing and re-opens the file if it's not. Speaking to someone who has worked with Java a lot more than I have, is there any real concern that an IOException might not be thrown if the data isn't actually being written out?

[cat6man]

Originally Posted by Narflex

This is very interesting...here's the failure:

Wed 4/20 10:45:40.776 [Pusher@3ffcb577] Error with MiniPlayer, closing UI: java.io.EOFException
Wed 4/20 10:45:40.776 [Pusher@3ffcb577] java.io.EOFException
Wed 4/20 10:45:40.777 [Pusher@3ffcb577] 	at sage.BufferedFileChannel.read(BufferedFileChannel.java:183)
Wed 4/20 10:45:40.777 [Pusher@3ffcb577] 	at sage.FastMpeg2Reader.read(FastMpeg2Reader.java:987)
Wed 4/20 10:45:40.777 [Pusher@3ffcb577] 	at sage.FastMpeg2Reader.transfer(FastMpeg2Reader.java:880)
Wed 4/20 10:45:40.777 [Pusher@3ffcb577] 	at sage.MiniPlayer.pushBuffer0(MiniPlayer.java:3339)
Wed 4/20 10:45:40.777 [Pusher@3ffcb577] 	at sage.MiniPlayer$1.run(MiniPlayer.java:2076)
Wed 4/20 10:45:40.777 [Pusher@3ffcb577] 	at java.lang.Thread.run(Thread.java:745)

That exception occurs when it's trying to read from the file...but then the file is shorter than is expected. This should NOT be happening, because it checks the length of the file before it does this read. It also isn't relying on any other information (such as asking OpenDCT how many bytes it's recorded)...so this check should be very solid.

The reason it works if you wait 20 seconds is that then there's enough data in the file so it can never get to the end of it....although I would assume that if you waited 20 seconds to start playback, and then skipped forward until you hit live...that you would encounter the same problem. Please verify that's the case, because if not, that's a very important data point.

The only reason I can think this would happen is if OpenDCT is shortening the file length at certain points in time. SageTV assumes that recording files always grow in size and will never be smaller than any size they have had before (during playback only, if you stop and transcode it later, that's fine).

Can the OpenDCT dev weigh in on that point? If you don't think OpenDCT is doing this, then I'll create a JAR file that has more debugging to verify my theory is correct...because I'm wrong sometimes of course.

I'm glad it is an "very interesting" problem and not cockpit error on my part.
It certainly behaves as if it is running out of data (hence my underflow comment). I'll test a long pause before watching than a skip ahead to catch up close to realtime or live TV.

edit: more info.........running ubuntu 14 on intel NUC, recording directories are on USB mounted hard drives (3 internal hard drives mounted in a Mediasonic ProBox HF2-SU3S2, with a single usb3 between ProBox and intel NUC, each usb drive mounted separately in fstab)

[Narflex]

Originally Posted by EnterNoEscape

The only situation in which the file size might shrink is if for any reason the file goes missing (it would be illogical to cause the file system to just write zeros up to the last known offset). However there is no indication in the logs that that the file was re-created. There would be a message whether it was successful or failed. All writing is done using FileChannel.

I am currently testing some code that makes sure the file is actually growing and re-opens the file if it's not. Speaking to someone who has worked with Java a lot more than I have, is there any real concern that an IOException might not be thrown if the data isn't actually being written out?

You don't need to worry about checking for file's growing...SageTV already handles that and if it stops growing, it will stop and restart the capture process in a brand new file (unless you are just doing that to verify things for this issue). And there should never be an IOException on a file channel write unless you run out of diskspace (assuming you've already opened it successfully and have permissions to write). At least in my experience that's the case....so in 'normal' operation, they should never occur.

[cat6man]

i tried recording, waiting a few minutes, then watching and skipping ahead to near-realtime..........the 2nd time i tried this, it crashed the hd300 in about 10s........the first time it went 60s without crashing.

not sure if it matters but the first time (no crash), i skipped ahead in 30s increments.
the 2nd time (crashed hd300), i skipped ahead in ~3min increments.

do you want me to dig out the logs for these?

[Narflex]

Originally Posted by cat6man

i tried recording, waiting a few minutes, then watching and skipping ahead to near-realtime..........the 2nd time i tried this, it crashed the hd300 in about 10s........the first time it went 60s without crashing.

not sure if it matters but the first time (no crash), i skipped ahead in 30s increments.
the 2nd time (crashed hd300), i skipped ahead in ~3min increments.

do you want me to dig out the logs for these?

No, because we will end up seeing the same thing in the log file. Thanks for verifying they crash in that case as well though, it gives more weight to my theory.

EnterNoEscape, Let me know if you think you figured out the problem on your end...or if you want me to create a modified Sage.jar for cat6man so we can have more solid data on what's happening with the file size.

[EnterNoEscape]

Originally Posted by Narflex

No, because we will end up seeing the same thing in the log file. Thanks for verifying they crash in that case as well though, it gives more weight to my theory.

EnterNoEscape, Let me know if you think you figured out the problem on your end...or if you want me to create a modified Sage.jar for cat6man so we can have more solid data on what's happening with the file size.

I really can't recreate the issue. As far as I know cat6man is the only person experiencing it. I was trying to seek to the edge on my HD300 up for 15 minutes and I can't get it to crash at all. I even monitored some of the files I recorded last night external to the program (PowerShell) to see if they were doing anything strange, not once did they shrink in size. I even tried deliberately making the file shrink at random and the playback was terrible, but it didn't crash my HD300 even while trying to skip back, then forward to as close as possible to live several times.

I'm using FileChannel in a very normal way. The writes are always appending. There aren't any situations that I see that would cause the file to be shrinking. I read a little more on FileChannel just so I could understand how one might end up with a smaller file and it looks like the only way I could end up doing that is if I used the truncate method or if I just used the default options which will truncate the file on opening; which I don't.

cat6man,

Were you having the playback issues before I had you disable upload ID? I noticed that it wasn't mentioned prior at least in this thread. I thought you mentioned the HD300 playback issues in the other thread.

[EnterNoEscape]

cat6man,

Have you already tried re-enabling upload id by changing consumer.ffmpeg.upload_id_enabled to true in opendct.properties? I'm interested if that fixes the HD300 live playback or not.

Also try MPEG-PS. Stop the SageTV service, then change the entries in Sage.properties for OpenDCT capture devices that look like mmc/encoders/<unique_id>/100/0/encode_digital_tv_as_program_stream to true.

I really don't think that OpenDCT is doing anything odd. I feel like a lot more people would have noticed this. There are some users I know leave the live stream running all night and don't wake up to the extender crashed.


Narflex,

I was finally able to crash my HD300, but I had to deliberately shrink the file while it was playing live. I saw the entry:

Fri 4/22 16:21:12.579 [Pusher@180f2b1] Pusher thread is starting
Fri 4/22 16:21:12.586 [Pusher@180f2b1] Miniplayer pusher using buffer size of 131072
Fri 4/22 16:21:12.588 [VideoFrame-0023a500070e@72f10c] isRec=true rd=17770 base=0 eos=false
Fri 4/22 16:21:12.592 [Pusher@180f2b1] Adjusting peek buffer size to: 131072
Fri 4/22 16:21:12.594 [VideoFrame-0023a500070e@72f10c] VF thread is now waiting for 0:39:04.941
Fri 4/22 16:21:12.973 [Pusher@180f2b1] playPush0()
Fri 4/22 16:21:13.465 [Pusher@180f2b1] Error with MiniPlayer, closing UI: java.io.EOFException
Fri 4/22 16:21:13.470 [Pusher@180f2b1] pushBuffer call failed; terminating push loop

I couldn't find the stack trace, so I don't really know where mine came from, but probably not the same place as cat6man. I was combing over the code related to that stack trace. I have to agree that it generally shouldn't do anything strange unless the file shrinks. I can see that it checks that the last known size of the file will be able to fill remaining space in the buffer, if it doesn't, it checks the current size of the file, if the buffer can't be filled with what's available, it passes back how much there actually is available to be read. The only thing that I can see that could really throw a wrench in this is if RandomAccessFile returns an incorrect file length value which I understand is dependent on what the file system returns.

[EnterNoEscape]

cat6man,

I released a new beta (0.5.2) of OpenDCT that aggregates the output from FFmpeg which basically means that writes will not be smaller than 256k. Often FFmpeg will use the write callback to write out data in sizes less than 1k. This change had a positive effect on the overall accuracy of Comskip on live detection. If I'm reading things right, the random read buffer in use by SageTV is 64k. This change should ensure that every newly read file length is always well ahead of the actual amount that the buffer could possibly buffer. If this works out for you, my finger would be pointing at the file system reporting an incorrect value for the length of the file or FileChannel is being a little too intelligent by allocating space beyond what's needed.

[cat6man]

thanks folks..........i was away this weekend and will get on the suggestions in the morning

by the way, would a hd300 log help by having any additional debugging info that would help?

[cat6man]

ran beta as requested, tested on hd200 down here in basement and live TV still crashes and requires hd200/300 power cycle.

log attached

[Narflex]

cat6man,

What type of filesystem are you using for your recording directory? (sorry if you already explained this, I didn't see it) Is it just local drives, local raid, SMB, NFS, some other network drives, etc.?

[cat6man]

great question, but before I answer more specifically, it made me think to try to remove the USB recording drives and leave only /var/media/tv on the NUC's SSD drive..........and voila, live tv works fine

so, it does look like the mounted USB drives are the problem when used as 'recording directories' (for live tv only, they seem fine for recordings)

the usb drives are ntfs (from a previous life) and mounted in fstab

UUID=90E0C299E0C284C6 /media/m/Media ntfs nofail,auto,noatime,rw,user 0 0
UUID=0EECAA53ECAA353D /media/m/Media2 ntfs nofail,auto,noatime,rw,user 0 0
UUID=F078FBA578FB692C /media/m/Media3 ntfs nofail,auto,noatime,rw,user 0 0

next, i'm going to reformat one as ext4 and see if that works ok.
maybe this is a weird windows and linux won't play nice together issue

in any case, thanks for the clues and debugging help!

edit: more info.........running ubuntu 14 on intel NUC, recording directories are on USB mounted hard drives (3 internal hard drives mounted in a Mediasonic ProBox HF2-SU3S2, with a single usb3 between ProBox and intel NUC, each usb drive mounted separately in fstab)

[cat6man]

changed 1 of my 3 usb drives from ntfs to ext4 and edited fstab.
verified that livetv did NOT crash the hd300 a couple of times, so now i'm reformatting the other 2 usb drives to ext4.

after i confirm that they are all happy with livetv (no reason to think otherwise), i'll go back and reduce some timers and see how much i can speed up livetv acquiring and changing channels with the hdhr-prime..........happy family members also

[EnterNoEscape]

Originally Posted by cat6man

changed 1 of my 3 usb drives from ntfs to ext4 and edited fstab.
verified that livetv did NOT crash the hd300 a couple of times, so now i'm reformatting the other 2 usb drives to ext4.

after i confirm that they are all happy with livetv (no reason to think otherwise), i'll go back and reduce some timers and see how much i can speed up livetv acquiring and changing channels with the hdhr-prime..........happy family members also

I feel like if this isn't a sticky, it should be somewhere as a cautionary about using NTFS-3g mounted drives for recordings on Linux. I'll say that I feel better.

[cat6man]

Originally Posted by EnterNoEscape

I feel like if this isn't a sticky, it should be somewhere as a cautionary about using NTFS-3g mounted drives for recordings on Linux. I'll say that I feel better.

agreed..............the other thing i would add, which may only be for non-experts, is to have 'nofail' in fstab for mounting drives, then 'sudo mount -a' to test drive mounting...........there is nothing like screwing up fstab and not being able to boot at all (been there, done that)