MVP Forward Skip during recording show problem

[Major Hostility]

I was watching a show that was still recording last night and found a problem at one point when I tried to skip forward during a commercial break.

I was trying to do a basic 1s skip forward, but it ended up skipping quite a bit further. When I reviewed the log file, it looks like it failed to call mvpVideoDuration before it computed the skip distance so it skipped to the wrong location.

Here are the relevant log sections:

Code:

... here is the last skip from the previous commercial break ... note that the stream duration is set at 2869 10/17/2005 8:46:50 PM.093 VERBOSE [57] Request 200000 bytes (file size:2166824896 file location: 1547143240) 10/17/2005 8:46:50 PM.093 VERBOSE [57] about to check 10/17/2005 8:46:50 PM.093 VERBOSE [57] ...livetv mode 10/17/2005 8:46:50 PM.109 VERBOSE [56] MVP data read: 1 (4) 10/17/2005 8:46:50 PM.109 VERBOSE [56] User pressed: 15 10/17/2005 8:46:50 PM.109 VERBOSE [56] Skipping forward: 1 10/17/2005 8:46:50 PM.109 VERBOSE [56] mvpVideoDuration: 2869 10/17/2005 8:46:50 PM.109 VERBOSE [56] MVPSetPlaybackPosition() request to set position to: 2057 seconds 10/17/2005 8:46:50 PM.109 VERBOSE [56] MVP not sending frame 10/17/2005 8:46:50 PM.109 VERBOSE [56] MVP request processed 10/17/2005 8:46:50 PM.171 VERBOSE [56] MVP data read: 1 (9) 10/17/2005 8:46:50 PM.171 VERBOSE [56] PACK9: 0000005C3A9588000000 10/17/2005 8:46:50 PM.171 VERBOSE [56] MVP request processed 10/17/2005 8:46:50 PM.281 VERBOSE [57] Stream Length: 2166939584 10/17/2005 8:46:50 PM.281 VERBOSE [57] Stream Duration: 2869 10/17/2005 8:46:50 PM.281 VERBOSE [57] requestedPositionInSeconds: 2057 10/17/2005 8:46:50 PM.281 VERBOSE [57] Set position to:1553640545 10/17/2005 8:46:50 PM.296 VERBOSE [57] Received request to seek to pos:1553640545 10/17/2005 8:46:50 PM.328 VERBOSE [57] Request 200000 bytes (file size:2166958016 file location: 1553640545) ... 5 minutes of regular show viewing log data omitted here 10/17/2005 8:51:49 PM.796 VERBOSE [57] Request 200000 bytes (file size:2392690624 file location: 1782840545) 10/17/2005 8:51:49 PM.796 VERBOSE [57] about to check 10/17/2005 8:51:49 PM.796 VERBOSE [57] ...livetv mode 10/17/2005 8:51:49 PM.875 VERBOSE [56] MVP data read: 1 (9) 10/17/2005 8:51:49 PM.875 VERBOSE [56] PACK9: 0000006A470A21000000 10/17/2005 8:51:49 PM.875 VERBOSE [56] MVP request processed 10/17/2005 8:51:50 PM.031 VERBOSE [57] Request 200000 bytes (file size:2392862656 file location: 1783040545) 10/17/2005 8:51:50 PM.031 VERBOSE [57] about to check 10/17/2005 8:51:50 PM.031 VERBOSE [57] ...livetv mode 10/17/2005 8:51:50 PM.062 VERBOSE [56] MVP data read: 1 (4) ... here is a skip forward at the beginning of the next commercial break ... note that we don't see a call to mvpVideoDuration ... and that the Stream Duration value is the same as it was ... 5 minutes earlier although Stream Length has updated to ... reflect newly recorded material 10/17/2005 8:51:50 PM.062 VERBOSE [56] User pressed: 43 10/17/2005 8:51:50 PM.062 VERBOSE [56] Skipping forward: 1 10/17/2005 8:51:50 PM.062 VERBOSE [56] MVPSetPlaybackPosition() request to set position to: 2390 seconds 10/17/2005 8:51:50 PM.062 VERBOSE [56] MVP not sending frame 10/17/2005 8:51:50 PM.062 VERBOSE [56] MVP request processed 10/17/2005 8:51:50 PM.359 VERBOSE [56] MVP data read: 1 (9) 10/17/2005 8:51:50 PM.359 VERBOSE [56] PACK9: 0000006A4A1761000000 10/17/2005 8:51:50 PM.359 VERBOSE [56] MVP request processed 10/17/2005 8:51:50 PM.437 VERBOSE [57] Stream Length: 2393169856 10/17/2005 8:51:50 PM.437 VERBOSE [57] Stream Duration: 2869 10/17/2005 8:51:50 PM.437 VERBOSE [57] requestedPositionInSeconds: 2390 10/17/2005 8:51:50 PM.437 VERBOSE [57] Set position to:1993613090 10/17/2005 8:51:50 PM.453 VERBOSE [57] Received request to seek to pos:1993613090 10/17/2005 8:51:50 PM.484 VERBOSE [57] Request 200000 bytes (file size:2393206720 file location: 1993613090) 10/17/2005 8:51:50 PM.484 VERBOSE [57] about to check 10/17/2005 8:51:50 PM.484 VERBOSE [57] ...livetv mode 10/17/2005 8:51:50 PM.546 VERBOSE [57] Request 200000 bytes (file size:2393288640 file location: 1993813090) 10/17/2005 8:51:50 PM.546 VERBOSE [57] about to check 10/17/2005 8:51:50 PM.546 VERBOSE [57] ...livetv mode 10/17/2005 8:51:50 PM.546 VERBOSE [56] MVP data read: 1 (9) 10/17/2005 8:51:50 PM.546 VERBOSE [56] PACK9: 00000076D72C62000000 10/17/2005 8:51:50 PM.546 VERBOSE [56] MVP request processed 10/17/2005 8:51:50 PM.578 VERBOSE [56] MVP data read: 1 (7) 10/17/2005 8:51:50 PM.578 VERBOSE [56] MVP request processed 10/17/2005 8:51:50 PM.640 VERBOSE [56] MVP data read: 1 (9) 10/17/2005 8:51:50 PM.640 VERBOSE [56] PACK9: 00000076DA39A2000000 10/17/2005 8:51:50 PM.640 VERBOSE [56] MVP request processed 10/17/2005 8:51:50 PM.640 VERBOSE [57] Request 200000 bytes (file size:2393405376 file location: 1994013090) ... Request 200000 bytes entries removed to shorten log ... At this point I realized we had skipped forward too far ... and requested a back skip ... Note that mvpVideoDuration is called this time, and that ... the duration is now correct 10/17/2005 8:51:53 PM.406 VERBOSE [57] Request 200000 bytes (file size:2395647936 file location: 1998013090) 10/17/2005 8:51:53 PM.406 VERBOSE [57] about to check 10/17/2005 8:51:53 PM.406 VERBOSE [57] ...livetv mode 10/17/2005 8:51:53 PM.625 VERBOSE [56] MVP data read: 1 (4) 10/17/2005 8:51:53 PM.625 VERBOSE [56] User pressed: 14 10/17/2005 8:51:53 PM.625 VERBOSE [56] Skipping back: 1 10/17/2005 8:51:53 PM.625 VERBOSE [56] mvpVideoDuration: 3173 10/17/2005 8:51:53 PM.625 VERBOSE [56] MVPSetPlaybackPosition() request to set position to: 2636 seconds 10/17/2005 8:51:53 PM.625 VERBOSE [56] MVP not sending frame 10/17/2005 8:51:53 PM.625 VERBOSE [56] MVP request processed 10/17/2005 8:51:53 PM.765 VERBOSE [56] MVP data read: 1 (9) 10/17/2005 8:51:53 PM.765 VERBOSE [56] PACK9: 000000771A4FE2000000 10/17/2005 8:51:53 PM.765 VERBOSE [56] MVP request processed 10/17/2005 8:51:53 PM.859 VERBOSE [57] Stream Length: 2395971520 10/17/2005 8:51:53 PM.859 VERBOSE [57] Stream Duration: 3173 10/17/2005 8:51:53 PM.859 VERBOSE [57] requestedPositionInSeconds: 2636 10/17/2005 8:51:53 PM.859 VERBOSE [57] Set position to:1990476182 10/17/2005 8:51:53 PM.875 VERBOSE [57] Received request to seek to pos:1990476182 10/17/2005 8:51:53 PM.906 VERBOSE [57] Request 200000 bytes (file size:2395987904 file location: 1990476182)

[Major Hostility]

Hey sub I know you're just getting back from break and all, but I was hoping you could take a quick look at the log I posted and let me know if I mis-interpreted something, or if I've tracked down a bug.

Thanks for the great program, and all your time and effort to continue improving it!

[sub]

Do you use comclean?

[Major Hostility]

Do you use comclean?

Nope. I do use comskip, but only after the show is complete, so it hadn't started up yet for this episode.

[sub]

Can you zip and attach the complete log file from above if you have it?

[Major Hostility]

Can you zip and attach the complete log file from above if you have it?

Here's the compressed log I had saved. I believe it represents the entire MVP session from when I first turned on the MVP device until we turned it off after watching the show.

[sub]

Unfortunately that is missing the beginning of the log.

What version of GB-PVR are you using?

[Major Hostility]

Yeah. Sorry about that. I think the original log spanned several days and I just chopped out the section for that viewing session.

I'm currently running:

10/22/2005 8:21:46 AM.156 VERBOSE [2] getValue: /settings/Version : GB-PVR v0.94.13

Would a copy of the startup log from today be helpful at all?

[sub]

When you started playing this recording which was still recording, where did you start playback from - recording screen, or video library?

[Major Hostility]

I'm pretty sure it was from Recordings -> What's New. I only have a couple of shows under "Video Library" that are shows not recorded by GB-PVR.