Does the DVR rewrite timestamps on an HDHR recording?

Have a recording that appears normal in the DVR UI, no interruption, yet the timestamps are messed up. Easy to see by looking at the comskip log. Note the lines beginning with jump and strange that shows the pts jumping all over the place.

################################################################
Generated using donator Comskip 0.82.011
Time at start of run:
Wed Oct  4 21:12:51 2023
################################################################
Mpeg:	/shares/dvr/TV/Quantum Leap/Quantum Leap S02E01 This Took Too Long 2023-10-04-1959.mpg
Exe	comskip.exe
Logo:	/shares/dvr/Logs/comskip/7135/video.logo.txt
Ini:	comskip.ini

Detection Methods to be used:
	1) Black Frame
	2) Logo - Give up after 2000 seconds
	3) Resolution Change
	4) Closed Captions
	5) Aspect Ratio
	6) Silence

ComSkip throttles back from -0001 to -0001.
The time is now 2112 so it's full speed ahead!

Input #0, mpegts, from '/shares/dvr/TV/Quantum Leap/Quantum Leap S02E01 This Took Too Long 2023-10-04-1959.mpg':
  Duration: 01:02:31.21, start: 33356.904489, bitrate: 6184 kb/s
  Program 1 
  Stream #0:0[0x31]: Video: h264 (High) ([27][0][0][0] / 0x001B), yuv420p(tv, progressive), 1280x720 [SAR 1:1 DAR 16:9], Closed Captions, 59.94 fps, 59.94 tbr, 90k tbn
  Stream #0:1[0x33](eng): Audio: ac3 (AC-3 / 0x332D4341), 48000 Hz, 5.1(side), fltp, 384 kb/s
  Stream #0:2[0x34](spa): Audio: ac3 (AC-3 / 0x332D4341), 48000 Hz, stereo, fltp, 96 kb/s
  Stream #0:3[0x3b]: Data: scte_35
Frame Rate set to 59.940 f/s
Initial video pts =      0.150
Initial video offset =      2.374 (video start = 33359.129, format start = 33356.904)
Initial audio pts =      0.000
Frame: 6 Channels:  6
Strange video pts step of 1.58268 instead of 0.01668 at frame 23760
Strange audio pts step of 1.58050 instead of 0.00000 at frame 23905
Jump in base apts from 398.59596 to 400.17592, delta=1.57995
Strange video pts step of 3.52668 instead of 0.01668 at frame 24480
Strange audio pts step of 5.52250 instead of 0.00000 at frame 24733
Jump in base apts from 410.10746 to 415.62946, delta=5.52199
Strange audio pts step of 30471.91660 instead of 0.00000 at frame 24839
Jump in base apts from 419.59010 to 30891.50616, delta=30471.91607
Strange video pts step of 30474.27010 instead of 0.01668 at frame 24839
Strange audio pts step of 238.69347 instead of 0.00000 at frame 24991
Jump in base apts from 30893.87688 to 31132.56988, delta=238.69300
Strange video pts step of -30457.60579 instead of 0.01668 at frame 134883
Strange audio pts step of 0.09650 instead of 0.00000 at frame 134885
Jump in base apts from 32965.96740 to 32966.06330, delta=0.09590
Strange audio pts step of 0.03250 instead of 0.00000 at frame 134885
Strange audio pts step of 0.03250 instead of 0.00000 at frame 134897
Jump in base apts from 32966.21765 to 32966.28159, delta=0.06394
Strange audio pts step of -30457.58394 instead of 0.00000 at frame 134897
Jump in base apts from 32966.28159 to 2508.69714, delta=-30457.58444
Panic: Audio buffer overflow, resetting audio buffer
Parsed 209206 video frames and 238995 audio frames at   254.83 fps
WARNING: Actual framerate (55.807) different from specified framerate (59.940)
Internal frame numbers will be different from .txt frame numbers
WARNING: Complex timeline or errors in the recording!!!!
Results may be wrong, .ref input will be misaligned. .txt editing will produce wrong results
Use .edl output if possible
209206 Frames Processed
################################################################
Time at end of run:
Wed Oct  4 21:27:02 2023
################################################################
Signal stats from the recording
"SignalStats": {
    "SS": {
        "Initial": 94,
        "Last": 96,
        "Min": 89,
        "Max": 97,
        "Sum": 177655,
        "GoodCount": 1871,
        "BadCount": 0
    },
    "SNQ": {
        "Initial": 100,
        "Last": 100,
        "Min": 100,
        "Max": 100,
        "Sum": 187100,
        "GoodCount": 1871,
        "BadCount": 0
    },
    "SEQ": {
        "Initial": 100,
        "Last": 100,
        "Min": 100,
        "Max": 100,
        "Sum": 187100,
        "GoodCount": 1871,
        "BadCount": 0
    },
    "BPS": {
        "Initial": 2463552,
        "Last": 6886816,
        "Min": 81216,
        "Max": 6924416,
        "Sum": 11576154144,
        "GoodCount": 1871,
        "BadCount": 0
    },
    "PPS": {
        "Initial": 211,
        "Last": 589,
        "Min": 29,
        "Max": 592,
        "Sum": 995356,
        "GoodCount": 1871,
        "BadCount": 0
    },
    "TSERR": {
        "Initial": 0,
        "Last": 0,
        "Min": 0,
        "Max": 0,
        "Sum": 0,
        "GoodCount": 1871,
        "BadCount": 0
    },
    "NETERR": {
        "Initial": 0,
        "Last": 0,
        "Min": 0,
        "Max": 0,
        "Sum": 0,
        "GoodCount": 1871,
        "BadCount": 0
    },
    "DVRBUF": {
        "Initial": 0,
        "Last": 0,
        "Min": 0,
        "Max": 0,
        "Sum": 0,
        "GoodCount": 0,
        "BadCount": 0
    },
    "DVRDROP": {
        "Initial": 0,
        "Last": 0,
        "Min": 0,
        "Max": 0,
        "Sum": 0,
        "GoodCount": 0,
        "BadCount": 0
    },
    "STREAMTIMEOUT": {
        "Initial": 0,
        "Last": 0,
        "Min": 0,
        "Max": 0,
        "Sum": 0,
        "GoodCount": 0,
        "BadCount": 0
    },
    "Grade": {
        "GoodCount": 1871,
        "BadCount": 0
    },
    "NetworkGrade": {
        "GoodCount": 1871,
        "BadCount": 0
    },
    "SignalGrade": {
        "GoodCount": 1871,
        "BadCount": 0
    },
    "StreamGrade": {
        "GoodCount": 1871,
        "BadCount": 0
    }
}, "BufferStats": {
    "BufferPct": {
        "Initial": 0,
        "Last": 0,
        "Min": 0,
        "Max": 0,
        "Sum": 0,
        "GoodCount": 0,
        "BadCount": 1874
    },
    "BufferDrop": {
        "Initial": 0,
        "Last": 0,
        "Min": 0,
        "Max": 0,
        "Sum": 0,
        "GoodCount": 1874,
        "BadCount": 0
    }
},

If it did, you will see it in the DVR logs.

By default, it will not, but if it sees that the duration between the first timestamp and the last timestamp in the file is more than twice the duration of the thing that was recorded, it will issue a rewrite to try to recover the recording.

Log looks normal.

2023/10/04 19:59:30.089478 [DVR] Starting job 1696474770-688 Quantum Leap on ch=[703]
2023/10/04 19:59:30.634686 [TNR] Opened connection to 1323AADB/0 for ch703 KCRADT
2023/10/04 19:59:30.707513 [DVR] Recording for job 1696474770-688 from 1323AADB ch703 into "TV/Quantum Leap/Quantum Leap S02E01 This Took Too Long 2023-10-04-1959.mpg" for 1h2m29.910390799s
2023/10/04 19:59:31.006588 [IDX] Generating video index for job 1696474770-688
2023/10/04 21:02:00.002842 [TNR] Closed connection to 1323AADB/0 for ch703 KCRADT
2023/10/04 21:02:00.092286 [SNR] Signal statistics for "TV/Quantum Leap/Quantum Leap S02E01 This Took Too Long 2023-10-04-1959.mpg": ss=94%,89%-97% snq=100% seq=100% bps=6187148,81216-6924416 pps=531,29-592
2023/10/04 21:02:00.174851 [SNR] Buffer statistics for "TV/Quantum Leap/Quantum Leap S02E01 This Took Too Long 2023-10-04-1959.mpg": buf=0% drop=0%
2023/10/04 21:02:00.195802 [DVR] Finished job 1696474770-688 Quantum Leap
2023/10/04 21:02:00.361845 [DVR] Processing file-7135: TV/Quantum Leap/Quantum Leap S02E01 This Took Too Long 2023-10-04-1959.mpg
2023/10/04 21:12:51.518047 [DVR] Running commercial detection on file 7135 (TV/Quantum Leap/Quantum Leap S02E01 This Took Too Long 2023-10-04-1959.mpg)
2023/10/04 21:27:03.010573 [DVR] Commercial detection for Quantum Leap S02E01 This Took Too Long 2023-10-04-1959.mpg finished with 14 markers in 14m11.492792397s.

Displays as full duration in Channels DVR and in my video editor


Capture

I semi rescued it by remuxing it with ffmpeg.
That dropped 15,048 frames or 4 minutes, 11 seconds from the recording, but it's now playable.

@eric
Does this mean anything in the debug recoding log for this recording?
PAT and PMT contiguous=false

at=2023-10-04T19:59:31.069228029-07:00 loc=188 pkt=2 pid=48 what=pat_and_pmt offset=0 length=376 contiguous=true changed=true packets=2
at=2023-10-04T20:06:46.395569278-07:00 loc=344410360 pkt=1831971 pid=48 what=pat_and_pmt offset=344382912 length=27636 contiguous=false changed=true packets=2
at=2023-10-04T20:41:19.897583793-07:00 loc=1870710732 pkt=9950590 pid=48 what=pat_and_pmt offset=1870625944 length=84976 contiguous=false changed=true packets=2

That's the whole log (HDHR recording)

No, it doesn't mean anything in particular.

OK, thanks.
The last two lines correspond to the times where the PTS jumped ahead and then behind by over 30,000 seconds.

Jump in base apts from 419.59010 to 30891.50616, delta=30471.91607
Jump in base apts from 32966.28159 to 2508.69714, delta=-30457.58444

Just to close this one out.
I forgot I had a pass for this show on my TiVo which recorded the episode.
Playback on the TiVo shows the source (Comcast) was at fault.
The TiVo does play it back, just skips over the parts that remuxing the Channels DVR recording had removed.

This topic was automatically closed 365 days after the last reply. New replies are no longer allowed.