Seektable built during recording is broken; fixed by rebuilding seektable

[Ian Macdonald <ian@…>]

Since the installation of a self-compiled 0.22-fixes as an upgrade from 0.21-fixes, new non-commflagged recordings have a duration that is approximately 80% (the actual amount varies between 78-85%) of their actual duration.

The programme is recorded in its entirety, but the data in the recordedseek table is incorrect. A 30 minute recording will typically display as just over 24 minutes if 'Info' is pressed.

Running mythcommflag over the recording in question immediately fixes the problem.

The recordedseek table isn't corrupt, but I have repaired and optimised it anyway, for the sake of completeness. I would like to reiterate that only new recordings are affected and only those that are not automatically comflagged.

The system in question is running a 2.6.22.9 Linux kernel. Whilst old, this has functioned perfectly for years with earlier versions of MythTV.

The box contains 2 PVR-350s and 2 PVR-150s. Recordings made by all cards are affected.

The driver in use is ivtv 1.4.1, the latest, which I integrated into the kernel tree in place of the in-tree 1.0.0 in an attempt to fix the problem. This hasn't helped, however.

Similarly, at the suggestion of a developer on #mythtv-users, I tried a 2.6.32.4 kernel, but that didn't help, either. A newer kernel isn't really an option anyway, due to complicating factors with lirc.

MythTV was built with the following options:

./configure --enable-proc-opt --disable-altivec --disable-amd3dnow --disable-amd3dnowext --disable-audio-oss --disable-audio-jack --disable-joystick-menu --disable-firewire --disable-hdhomerun --disable-hdpvr --disable-dvb --with-bindings=perl,python

[chris.rouch@…]

I see a similar problem.

System - up to date centos 5.4, with the latest atrpms of 0.22 Hardware - 2x pvr500. ivtv is the latest available from atrpms Signal - Ziggo analog cable in Holland

Channels configured for commercial flagging record correctly. Channels configured as commercial free (i.e. bbc1 and bbc2) show an incorrect length - e.g a 50 minute recording is shown to be around 15 minutes - and stops playing after 15 minutes.

Running mythcommflag manually does not help. However running mythtranscode (either from the frontend or from a terminal window on the backend) does fix the problem.

This is only for recordings made after I upgraded.

At Mike Dean's prompting I followed the instructions in http://www.mythtv.org/wiki/User_Manual:Periodic_Maintenance#Optimize_the_Database. This made no difference.

[rkdart@…]

I have what I think is the same problem as well. I'm using Fedora 11 with the ATRPMS packages on a single master backend and Fedora 12 with RPM Fusion mythfrontend packages as well as some Mythbuntu boxes with their version of the frontend. Seems like it might be a problem with the recordings themselves somehow, or at least the way the frontend is parsing them. The recordings that are having problems all seem to be from the last week (since Jan. 31).

As examples, I have one recording that was extremely short in reported duration (about 5 minutes on a 30 minute recording), and one that was too long by about 4-5 minutes (on a 30 minute recording). Both the Fedora and Mythbuntu frontends have the exact same seeking problems. Looking at most of my newer recorded programs, the reported times vary from about 15% to 700%+ of the correct times.

For the two examples mentioned above, the one that is reporting longer than actual was recorded on a Hauppage PVR-250, and the one reporting shorter than actual was recorded using a Pinnacle PCTV HD 800i (it was a HD program recorded OTA, and was sandwiched between two other shows with the same resolution on the same channel, both of which reported correctly). I also ran the optimize_mythdb.pl script and that didn't fix anything for me.

Here's what I think is the relevant log snippet from the first (reported longer than actual -- 36m43s reported but actual seems to be 31m46s) recording:

2010-02-06 10:13:01.392 AFD: Recording has no position -- using libavformat seeking.
2010-02-06 10:13:01.392 Input #0, mpeg, from 'myth://192.168.10.4:6543/3061_20100204223000.mpg':
2010-02-06 10:13:01.392   Duration: 00:36:43.01, start: 0.189278, bitrate: 4516 kb/s
2010-02-06 10:13:01.392     Stream #0.0[0x1e0]: Video: mpeg2video, yuv420p, 720x480 [PAR 8:9 DAR 4:3], 1001/60000, 6000 kb/s, 29.97 tbr, 90k tbn, 59.94 tbc

And here's what ffmpeg -i 3061_20100204223000.mpg says about the same recording (note that it displays the correct duration):

Seems stream 0 codec frame rate differs from container frame rate: 59.94 (60000/1001) -> 29.97 (30000/1001)
Input #0, mpeg, from '3061_20100204223000.mpg':
  Duration: 00:31:46.11, start: 0.189278, bitrate: 5219 kb/s
    Stream #0.0[0x1e0]: Video: mpeg2video, yuv420p, 720x480 [PAR 8:9 DAR 4:3], 6000 kb/s, 29.97 tbr, 90k tbn, 59.94 tbc
    Stream #0.1[0x1c0]: Audio: mp2, 48000 Hz, 2 channels, s16, 384 kb/s

Here is the log from the second recording (HD OTA) that's reported much shorter than actual (it reports a correct duration here but shows up as 5:34 on the OSD popup, and does not allow me to seek past 5:34 at all):

2010-02-06 10:42:41.568 Input #0, mpegts, from 'myth://192.168.10.4:6543/2251_20100131210000.mpg':
2010-02-06 10:42:41.568 MythSocket(15ede50:33): writeBlock(0x140231094289624, 58)
2010-02-06 10:42:41.568   Duration: 00:29:58.66, start: 41395.903622, bitrate: 13898 kb/s
2010-02-06 10:42:41.569     Stream #0.0[0x31]: Video: mpeg2video, yuv420p, 1280x720 [PAR 1:1 DAR 16:9], 1001/120000, 19000 kb/s, 59.94 tbr, 90k tbn, 119.88 tbc
2010-02-06 10:42:41.569     Stream #0.1[0x34]: Audio: ac3, 48000 Hz, stereo, s16, 384 kb/s
2010-02-06 10:42:41.569     Stream #0.2[0x35]: Audio: ac3, 48000 Hz, stereo, s16, 384 kb/s
2010-02-06 10:42:41.569 AFD: Position map found
2010-02-06 10:42:41.569 AFD: Successfully opened decoder for file: "myth://192.168.10.4:6543/2251_20100131210000.mpg". novideo(0)

Here's from ffmpeg -i 2251_20100131210000.mpg

Seems stream 0 codec frame rate differs from container frame rate: 119.88 (120000/1001) -> 59.94 (60000/1001)
Input #0, mpegts, from '2251_20100131210000.mpg':
  Duration: 00:29:58.66, start: 41395.903622, bitrate: 13898 kb/s
  Program 1 
    Stream #0.0[0x31]: Video: mpeg2video, yuv420p, 1280x720 [PAR 1:1 DAR 16:9], 19000 kb/s, 59.94 tbr, 90k tbn, 119.88 tbc
    Stream #0.1[0x34](eng): Audio: ac3, 48000 Hz, stereo, s16, 384 kb/s
    Stream #0.2[0x35](eng): Audio: ac3, 48000 Hz, stereo, s16, 384 kb/s

Finally, here's a log from another HD show immediately before the one reporting 5:34 for the OSD, same channel -- and which works fine (correct end time reported on OSD)

2010-02-06 12:09:01.166 Position map filled from DB to: 107769
2010-02-06 12:09:01.167 Dec: SyncPositionMap prerecorded, from DB: 7053 entries
2010-02-06 12:09:01.167 Dec: SyncPositionMap, new totframes: 107769, new length: 1797, posMap size: 7053
2010-02-06 12:09:01.167 Input #0, mpegts, from 'myth://192.168.10.4:6543/2251_20100131203000.mpg':
2010-02-06 12:09:01.167   Duration: 00:29:58.43, start: 39596.132589, bitrate: 14474 kb/s
2010-02-06 12:09:01.167     Stream #0.0[0x31]: Video: mpeg2video, yuv420p, 1280x720 [PAR 1:1 DAR 16:9], 1001/120000, 19000 kb/s, 59.94 tbr, 90k tbn, 119.88 tbc
2010-02-06 12:09:01.167     Stream #0.1[0x34]: Audio: ac3, 48000 Hz, 2 channels (FL|FR|FC|LFE|SL|SR), s16, 448 kb/s
2010-02-06 12:09:01.167     Stream #0.2[0x35]: Audio: ac3, 48000 Hz, stereo, s16, 192 kb/s
2010-02-06 12:09:01.167 AFD: Position map found
2010-02-06 12:09:01.168 AFD: Successfully opened decoder for file: "myth://192.168.10.4:6543/2251_20100131203000.mpg". novideo(0)

I'm happy to give any suggestions a try or get more log files, if anybody has any ideas...

[rkdart@…]

After upgrading both the backend and frontends (via apt/yum) and running mythcommflag on the affected videos from one of the frontend machines, the problem is no longer present... presumably there was something broken at some point with the backend packages or database when the recordings were made, which caused this. Running the command

find ./ -name *.mpg -mtime -8 -execdir mythcommflag --rebuild --file {} \;

inside my recordings directory seemed to fix everything that was wrong, though, and newly recorded programs are recording fine now (this is also after having run the database optimization/repair script, which may have been part of the problem).

[ian@…]

This looks like the standard recordedseek corruption problem to me, because your new recordings are fine after repair.

Chris and I have the problem that all of our new recordings -- and only our new recordings -- are about 80% of the actual length; never much more or less than that.

I still have the problem here. mythcommflag continues to fix individual recordings, but all fresh non-comflagged recordings are still affected.

[Stuart Auchterlonie]

Bumping open 0.22 milestone tickets to 0.24

[danielk]

This appears to have been fixed at some point according to a comment from the reporter 4 months ago. Since we don't know if this was a local problem or one of the few keyframe flagging fixes that have gone in since this was initially reported I'm marking this as invalid (though at some point this ticket was not invalid.)

[anonymous]

This hasn't been fixed. I still see the same error with the latest 0.23 from atrpms. A ~40 minute show will appear to be ~10 minutes long. Manually running mythtranscode fixes the problem. This is using two PVR-500s to capture the video.

[otto at kolsi dot fi]

I've seen this problem with DVB recordings ever since I started using Myth (0.19 time). It hasn't been fixed by any version change, ffmpeg sync or anything. I don't think it is db table corruption issue, I e.g. do MySQL optimize/repair nightly. Symptoms are exactly the same, original time shown is too short but running mythcommflag "fixes" the issue.

[OliHenning]

Ok, there, i can also confirm this problem.

I have a Hauppauge PVR-500 (double-Tuner, Analog-TV, OnBoard?-MPEG-Enocder) I'm in Switzerland, so i'm using PAL 50HZ.

I analyzed a bit and observed, that mythbackend is making entries in the MySQL-Table "recordedseek" while the recording is running. It makes seek-entries of type '9' which means 'GOP' (Group of Pictures).

Info: With this Information in the table, mythfrontend is able to seek quickly to a specific timepoint in a recording, as every MPEG-Decoding has to start at the beginning of a GOP (we have to hit the 'exact' Byte-Position in the Multi-100-Megabytes-MPEG-File !). Additionally, mythfrontend can quickly calculate the length of the movie in hh:mm:ss (simply make a

SELECT max(mark) FROM seektable WHERE type=9 AND chanid=... AND starttime=...

or so)

BUT: These seektable-entries 'while-recording' are wrong. I dumped the entries of a recording right after the recording, then i did a rebuild of these seek-entries as follows:

mythtranscode -b -i 1004_20100731012300.mpg

and then i dumped the entries again. And there are differendes:

After Recording: 3936 Rows
After Transcode: 3996 Rows

After Recording: mark-values (=25Hz Frames) from 0 to 47403
After Transcode: mark-values (=25Hz Frames) from 0 to 47940

After Recording: Recording-Length min:sec = 31:34 (=47403/25 Seconds)
After Transcode: Recording-Length min:sec = 31:56 (=47940/25 Seconds)

After Recording: delta between two mark-values: random (between 1 and 42, but mostly 12)
After Transcode: delta between two mark-values: ALWAYS 12

So, in my optinion, mythbackend (while recording running) is not able to identify the GOP-Frames in the MPEG-Stream correctly while mythtranscode does.

what do you mean

Greeting from switzerland

[robertm]

I'm really not exactly sure who to assign this to. Please feel free to reassign or bump.

[danielk]

I'm going to need a 60 second PVR-150/250/500 recording to diagnose this.

Otto, DVB recordings are processed using a different code path so that would need it's own ticket, also with a sample of the recording.

[anonymous]

I've made a short recording available here: ​http://hogberg.dyndns.org/3_20100820224900.mpg

It was recorded using a PVR-150 on Linux 2.6.31-22-generic (ubuntu karmic).

MythTV Version   : 25609
MythTV Branch    : branches/release-0-23-fixes
Network Protocol : 23056
Library API      : 0.23.1.201000710-1
QT Version       : 4.5.2
Options compiled in:
 linux debug using_oss using_alsa using_pulse using_jack using_pulseoutput using_backend using_dvb using_firewire using_frontend using_glx_proc_addr_arb using_hdhomerun using_hdpvr using_iptv using_ivtv using_joystick_menu using_libudev using_lirc using_mheg using_opengl_video using_opengl_vsync using_qtdbus using_qtwebkit using_v4l using_x11 using_xrandr using_xv using_xvmc using_xvmc_vld using_xvmcw using_bindings_perl using_bindings_python using_opengl using_ffmpeg_threads using_libavc_5_3 using_live using_mheg

[beirdo]

Well, since I am now also experiencing this (or something closely related), I'm stealing this ticket.

[anonymous]

Thank you for working on this. Here is some information to help you out.

I'm using a HdHomeRun? to record into mythtv. I'm using mythicalLibrarian to export my recordings to XBMC.

Episode file used for testing: /home/mythtv/Videos/Episodes/Caprica/Season 1/Caprica S01E11 (Retribution).mpg mythtv reports recording duration of 49 minutes 33 seconds. XBMC reports 59 minutes 57 seconds

Comskip version 1 file: /home/mythtv/Videos/Episodes/Caprica/Season 1/Caprica S01E11 (Retribution).txt

FILE PROCESSING COMPLETE
------------------------
8763 13008
30197 34807
43895 48602
58300 63913
74064 77335

xbmc.edl file: /home/xbmc/.xbmc/temp/xbmc.edl

292.000    434.000    0
1007.000    1161.000    0
1464.000    1621.000    0
1945.000    2132.000    0
2471.000    2580.000    0

All of the following information which is not in bold was based off of on-screen information Comskip 1: frames 8763 13008 Viewing time in XBMC of actual commercial: 6:04 to 9:10 XBMC placed it at: 4:52- 7:14 MythTV placed it at: 4:52 - 7.13(calculated end time from duration) MythTv? duration: 2:21 and was correct

Comskip 2: frames 30197 34807 Viewing time in XBMC of actual commercial: 20:32-23:47 XBMC placed it at: 16:47 - 19:21 MythTV placed it at: 16:47 - 19.20(calculated end time from duration) MythTv? duration: 2:33 and was correct

Comskip 3: frames 43895 48602 Viewing time in XBMC of actual commercial: 29:49-33:01 XBMC placed it at: 24:24 - 27:04 MythTV placed it at: 24:27 - 27:04(calculated end time from duration) MythTv? duration: 2:37 and was correct

Comskip 4 frames 58300 63913 Viewing time in XBMC of actual commercial: 39:29-42.55 XBMC placed it at: 32:25 - 35:26 MythTv? placed it at: 32:25 - 35:32(calculated end time from duration) MythTv? duration: 3:07 and was correct

Comskip 5 frames 74064 77335 Viewing time in XBMC of actual commercial: 49:58-53-22 XBMC placed it at: 41.11 - 43.01 MythTv? placed it at 41:11 - 43:00(calculated end time from duration) MythTv? duration: 1:49 and was correct

Here is a picture of my desktop which shows many different readers reading the same file. Top left My Windows virtual machine without proper codecs with Windows Media Player, you can see it displays 59:56. Bottom left My XBMC-Live media center in VNC :0, you can see that it has 59:57. Top right of left screen Mac OSX virtual machine had problems playing the file. Bottom right of left screen, Ubuntu Media Player displays 1:06:05 for it's runtime. Top left of the right screen, you can see a VNC into my media center on :1 with actual MythTV playing the file and it displays 49:33. Bottom of right screen, you can see a terminal into my XBMC-live displaying ffmpeg. runtime: 59:57:31 Far right top of left screen, you can see a terminal displaying the files.

Bottom line: I think MythTv? is using comskip information or some other method of calculating the runtime. The runtime is wrong, but the comskips match up with the improper runtime.

[beirdo]

That doesn't seem to be related. Sorry.

[beirdo]

(In [26839]) Prevent HandleKeyframe? from attempting to put negative file offsets into the position map (and thus the recordedseek table in the db) as they get crammed into unsigned 64-bit numbers, giving extremely large offset values, which are incorrect.

Also, keep FindPSKeyFrame from trying to put in negative offsets. The value of (bufstart - bufptr) is always <= 0. The desired offset within the buffer is actually (bufptr - bufstart).

The combination of these two was found while investigating borked seektables on MPEG2-PS recordings.

Refs #7978

[beirdo]

Attached is a patch that fixes this problem for me completely. It seems that as an optimization, we skip over the rest of the PES packet as soon as we see a slice header. However, it seems that this can cause issues in some setups, as apparently more than one frame is in the PES packet.

[beirdo]

If one of the original posters with this issue with ivtv (particularly recently) could confirm that this fixes it for them as well, I will tidy it up and commit to trunk.

Thanks.

[beirdo]

(In [26850]) Stop skipping the rest of the video when encountering a slice header in parsing in FindPSKeyFrames. On some ivtv setups, and also on saa7164 (aka HVR-2250), this can at times miss a large number of frames in the frame count, as it seems more than one frame is passed back at once in the PES packet (it looks like), and this optimization would skip them. The net result was the frame count being off by a fairly large margin, often showing 1/3 to 1/10 of the actual frame number. This didn't seem to be a change in FFmpeg code, nor in ours, but apparently in driver/firmware behavior.

This function can use a rework after release, but for now, this seems to fix the issue at hand.

Fixes #7978

[beirdo]

(In [26854]) Backport [26839] and [26850] to 0.23-fixes

This should fix the cases of screwy seektables on ivtv recordings (and other MPEG2-PS) that happen due to frames not being counted.

Refs #7978

[outleradam@…]

Replying to beirdo:

That doesn't seem to be related. Sorry.

It is very related. I'm playing the same file on multiple platforms. As you can see mythtv has aproximately 80% length as compared to other players. This seriously affects playback on exported recordings.

MythTv? is saying the recording is 80% of it's length. Commercial skips are being calculated using the same mythtv method which determines 80% length. However, ffmpeg does not use that same calculation which turns a 1 hour show into a 49 minute show.

The key to figuring out this problem will also involve reworking comskip.

[beirdo]

This is not the same issue. This is not caused by a faulty seeklist being built during recording an MPEG2-PS file, which is what was originally reported. Please open a new bug if you have a different issue from what was originally reported.

As you are recording a totally different type of file (MPEG2-TS), the code traversed to create the seeklist is different. These are not the same issue.