update to v.9 produces frozen video

[tvmaster2]

Originally Posted by wnjj

I don't claim to understand how this all works but I'm learning more each time I look into these kinds of issues. From what I can tell, the recording is continuing on just fine. The playback graph (the Directshow playback engine) has stopped for some reason.

Fri 2/10 15:30:54.646 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=313023 base=305785 eos=false
Fri 2/10 15:35:54.702 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=613080 base=605713 eos=false
Fri 2/10 15:40:54.726 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=913104 base=905610 eos=false
Fri 2/10 15:45:54.750 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=1213128 base=1205506 eos=false
Fri 2/10 15:50:54.772 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=1513150 base=1505402 eos=false
Fri 2/10 15:55:54.797 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=1813175 base=1666593 eos=false
Fri 2/10 16:00:54.818 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=2113196 base=1666593 eos=false
Fri 2/10 16:05:54.840 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=2413218 base=1666593 eos=false
Fri 2/10 16:10:54.863 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=2713241 base=1666593 eos=false
Fri 2/10 16:15:54.890 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=3013268 base=1666593 eos=false

The 'rd=' numbers are 'real duration' and represent the length of the actively recording media file. The 'base=' numbers are where the playback position is. Both are in ms. So it looks like it's humming along fine, playing back about 7 seconds behind the recording until between 15:50 and 15:55 (like you said, 15:53) after which the playback 'base' position stops advancing. The recording is continuing it seems.

What I don't see in either the server or client log files is anything suggesting why this is. The messages from VideoFrame.java indicate both recording and playing is still in progress. There is no sign of MediaFile switching or even a need to since the current show doesn't end for quite a while. This doesn't seem to be the issue fixed in the other thread, unfortunately.

Any chance you need to update your video drivers?

Jeff may have to weigh in on this one.

Thanks for going to the trouble in helping to figure this out. As it turns out, recordings ARE being effected, but only on the Colossus tuner, and only if I left live video on the server on the Colossus tuner. At least that's what I've found so far. I'm not sure I completely follow your 'timing' description, but I did notice the RD numbers went from intervals of 30 to intervals of 3. So far, way above my pay grade....

[wnjj]

Originally Posted by tvmaster2

Thanks for going to the trouble in helping to figure this out. As it turns out, recordings ARE being effected, but only on the Colossus tuner, and only if I left live video on the server on the Colossus tuner. At least that's what I've found so far. I'm not sure I completely follow your 'timing' description, but I did notice the RD numbers went from intervals of 30 to intervals of 3. So far, way above my pay grade....

The RD numbers are always going up by 300,000. This is 300,000ms = 300 seconds = 5 minutes so that's working fine.

Normally watching live TV and then changing the channel or stopping will delete the file. If you press 'manual record' before stopping (or before causing the freeze), can you go back and view the recording fine? I suspect you can. This excerpt from the server log shows the file continues growing until you changed the channel:

Fri 2/10 15:25:47.091 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=0 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:25:47.127 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=0 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:25:50.752 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=3559028 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:25:54.572 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=7392724 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:30:54.581 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=308919156 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:35:54.664 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=610530752 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:40:54.688 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=912053236 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:45:54.712 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=1213668780 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:50:54.735 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=1515199160 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:55:54.772 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=1815610564 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 16:00:54.890 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=2117156548 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 16:05:54.911 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=2418760624 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 16:10:54.934 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=2720359436 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 16:15:54.961 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=3021935500 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 16:20:54.988 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=3323526980 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 16:25:55.017 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=3625129552 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts

[tvmaster2]

Originally Posted by wnjj

The RD numbers are always going up by 300,000. This is 300,000ms = 300 seconds = 5 minutes so that's working fine.

Normally watching live TV and then changing the channel or stopping will delete the file. If you press 'manual record' before stopping (or before causing the freeze), can you go back and view the recording fine? I suspect you can. This excerpt from the server log shows the file continues growing until you changed the channel:

Fri 2/10 15:25:47.091 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=0 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:25:47.127 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=0 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:25:50.752 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=3559028 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:25:54.572 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=7392724 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:30:54.581 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=308919156 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:35:54.664 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=610530752 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:40:54.688 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=912053236 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:45:54.712 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=1213668780 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:50:54.735 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=1515199160 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 15:55:54.772 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=1815610564 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 16:00:54.890 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=2117156548 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 16:05:54.911 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=2418760624 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 16:10:54.934 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=2720359436 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 16:15:54.961 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=3021935500 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 16:20:54.988 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=3323526980 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts
Fri 2/10 16:25:55.017 [Seeker@5a5148] RootFile=H:\ fstype=NTFS fileLength=3625129552 file=H:\COLOSSUS recordings\CBCNewsNetworkWithAndrewNichols-59842110-0.ts

OK, I found one show where I was sitting on the channel, live, and then pressed 'Record'. When I came back and looked at the video, one second of REAL TIME was advancing on the SageTV time bar as five seconds. Needless to say the recording stopped well before it's three-hour dwell time.
Any idea what would cause that? The video HAD frozen when I checked it near program end.

[tvmaster2]

Originally Posted by wnjj

I don't claim to understand how this all works but I'm learning more each time I look into these kinds of issues. From what I can tell, the recording is continuing on just fine. The playback graph (the Directshow playback engine) has stopped for some reason.

Fri 2/10 15:30:54.646 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=313023 base=305785 eos=false
Fri 2/10 15:35:54.702 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=613080 base=605713 eos=false
Fri 2/10 15:40:54.726 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=913104 base=905610 eos=false
Fri 2/10 15:45:54.750 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=1213128 base=1205506 eos=false
Fri 2/10 15:50:54.772 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=1513150 base=1505402 eos=false
Fri 2/10 15:55:54.797 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=1813175 base=1666593 eos=false
Fri 2/10 16:00:54.818 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=2113196 base=1666593 eos=false
Fri 2/10 16:05:54.840 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=2413218 base=1666593 eos=false
Fri 2/10 16:10:54.863 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=2713241 base=1666593 eos=false
Fri 2/10 16:15:54.890 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@1b9e444] isRec=true rd=3013268 base=1666593 eos=false

The 'rd=' numbers are 'real duration' and represent the length of the actively recording media file. The 'base=' numbers are where the playback position is. Both are in ms. So it looks like it's humming along fine, playing back about 7 seconds behind the recording until between 15:50 and 15:55 (like you said, 15:53) after which the playback 'base' position stops advancing. The recording is continuing it seems.

What I don't see in either the server or client log files is anything suggesting why this is. The messages from VideoFrame.java indicate both recording and playing is still in progress. There is no sign of MediaFile switching or even a need to since the current show doesn't end for quite a while. This doesn't seem to be the issue fixed in the other thread, unfortunately.

Any chance you need to update your video drivers?

Jeff may have to weigh in on this one.

Haven't heard from Jeff, so I'll update you. Most recordings seem to be made correctly, and I'm narrowing the problem down to the Colossus tuner recordings / live video streams as opposed to those of the HD PVR. However, the occasional recording STILL exhibits the odd timing issue, were every second of real-time = FIVE seconds of Sage time-bar advance, meaning that the SageTV time display jumps five seconds for every second of what should be real-time playback. If you have any thoughts on that. please chime in, as I imagine it's tied to the live playback problems somehow.
The file size for a one-hour show, in gigabytes, is correct, around 3.8gb. So that's weird as well