Modify
Warning Please read the Ticket HowTo before creating or commenting on a ticket. Failure to do so may cause your ticket to be rejected or result in a slower response.

Opened 19 months ago

Closed 11 months ago

Last modified 11 months ago

#11108 closed Bug Report - General (fixed)

RecordPreRoll doesn't work

Reported by: mythwiki@… Owned by: gigem
Priority: minor Milestone: 0.27
Component: MythTV - Scheduling Version: 0.25.2
Severity: medium Keywords:
Cc: Ticket locked: no

Description

In mythtv/programs/mythbackend/scheduler.cpp, the method Scheduler::CalcTimeToNextHandleRecordingEvent?(). The fourth parameter, prerollseconds, is not used. So, it returns a number that assumes that parameter is zero. This means that, in Scheduler::run(), the scheduler goes to sleep for too long around the first LOG() line, so the RecordPreRoll? parameter doesn't actually work, because the scheduler sleeps through the intended start time.

I've patched my mythbackend locally to fix the problem, but I don't know whether or not my fix has unintended negative consequences. My lightly tested patch against 0.25.2 is attached.

Attachments (4)

schedpatch.diff (570 bytes) - added by mythwiki@… 19 months ago.
Lightly tested patch that solves the issue for me
PATCH-backend (1.5 KB) - added by mythwiki@… 19 months ago.
More complete patch. This should fix the bug and handle all cases. Tested on my setup.
mythtv-11108-1.patch (14.9 KB) - added by gigem 11 months ago.
Refactor, simplify and slightly enhance scheduler timing logic
mythtv-11108-2.patch (16.3 KB) - added by gigem 11 months ago.
Cleanup revision

Download all attachments as: .zip

Change History (18)

Changed 19 months ago by mythwiki@…

Lightly tested patch that solves the issue for me

comment:1 Changed 19 months ago by mythwiki@…

The patch I posted isn't a general fix. If the RecordPreRoll? is set to more than about 30 seconds, it won't have the desired effect, because it is also not used in the calculation of secs_to_next. I'd suggest that the Scheduler::run() method should be revisited with a particular attention to the behaviour under non-zero values of RecordPreRoll?.

Changed 19 months ago by mythwiki@…

More complete patch. This should fix the bug and handle all cases. Tested on my setup.

comment:2 Changed 17 months ago by mythwiki@…

I bought new hardware for my backend, the old was sluggish. As part of the changeover, I went from LinHES to Mythbuntu, because LinHES doesn't yet ship 64-bit ISOs. While both were 0.25.2 binaries, I do not see the bug with the mythbuntu packaged binaries, so I think this can be closed as WORKSFORME. I don't see why it works, given my analysis of the function, but it seems to be working.

comment:3 Changed 15 months ago by mythwiki@…

No, doesn't work for me. I rarely see RecordPreRoll? behaviour anymore (it's a timing issue, a late wakeup request, so if something else wakes up the thread it might still behave correctly, but that's by accident). This bug is still present.

comment:4 Changed 15 months ago by gigem

  • Status changed from new to infoneeded_new

The reporter has enabled extra logging and is waiting for the problem to occur with the current code.

comment:5 Changed 13 months ago by gigem

  • Resolution set to Works for me
  • Status changed from infoneeded_new to closed

No response from original submitter.

comment:6 Changed 13 months ago by mythwiki@…

I've been running with the enhanced logging options for over 6 weeks now, and haven't seen the issue again. I'll continue watching the logs, and reopen only if the bug reappears and we get more details from the logs.

comment:7 Changed 11 months ago by mythwiki@…

  • Resolution Works for me deleted
  • Status changed from closed to new

My backend has found itself in that state again, with the enhanced logging active. Here is a logging interval around a recording that failed to start at the preroll time of 15 seconds. The program was scheduled to be broadcast starting at 14:00:00 local time.

This isn't a one-off failure, all new recordings are now starting late. The code is v0.25.2, with this patch applied: http://code.mythtv.org/trac/attachment/ticket/11328/keep-first-keyframe-v4-v0.25.patch

May 28 13:57:30 <<<...>>> I Scheduler scheduler.cpp:1829 (run) sleeping for 60000 ms (interuptable)
May 28 13:58:30 <<<...>>> I Scheduler scheduler.cpp:1829 (run) sleeping for 60000 ms (interuptable)
May 28 13:58:30 <<<...>>> I CoreContext mythdbcon.cpp:395 (PurgeIdleConnections) New DB connection, total: 12
May 28 13:59:30 <<<...>>> I Scheduler mythdbcon.cpp:395 (PurgeIdleConnections) New DB connection, total: 12
May 28 13:59:30 <<<...>>> I Scheduler scheduler.cpp:4416 (FillRecordingDir) Scheduler: FillRecordingDir: Starting
May 28 13:59:30 <<<...>>> I Scheduler scheduler.cpp:4895 (FillRecordingDir) Scheduler: FillRecordingDir: Finished
May 28 13:59:30 <<<...>>> I Scheduler scheduler.cpp:1829 (run) sleeping for 5000 ms (interuptable)
May 28 13:59:30 <<<...>>> I TVRecEvent tv_rec.cpp:1536 (HandlePendingRecordings) TVRec(1): ASK_RECORDING 1 13 0 0
May 28 13:59:30 <<<...>>> I TVRecEvent tv_rec.cpp:1536 (HandlePendingRecordings) TVRec(3): ASK_RECORDING 3 13 0 0
May 28 13:59:35 <<<...>>> I Scheduler scheduler.cpp:1829 (run) sleeping for 5000 ms (interuptable)
May 28 13:59:40 <<<...>>> I Scheduler scheduler.cpp:1829 (run) sleeping for 2000 ms (interuptable)
May 28 13:59:42 <<<...>>> I Scheduler scheduler.cpp:1813 (run) sleeping for 16000 ms (s2n: 17 sr: 16)
May 28 13:59:58 <<<...>>> I TVRecEvent tv_rec.cpp:1029 (HandleStateChange) TVRec(1): Changing from None to RecordingOnly
May 28 13:59:58 <<<...>>> I TVRecEvent mythdbcon.cpp:395 (PurgeIdleConnections) New DB connection, total: 12
May 28 13:59:58 <<<...>>> E CoreContext programinfo.cpp:2278 (GetPlaybackURL) ProgramInfo(2590_20130528140000.mpg): GetPlaybackURL: '2590_20130528140000.mpg' should be local, but it can not be found.
May 28 13:59:58 <<<...>>> I TVRecEvent tv_rec.cpp:3495 (TuningCheckForHWChange) TVRec(1): HW Tuner: 1->1
May 28 13:59:58 <<<...>>> I TVRecEvent v4lchannel.cpp:661 (SetInputAndFormat) V4LChannel(/dev/hdpvr): SetInputAndFormat(1, NTSC) (v4l v2) input_switch: 0 mode_switch: 1
May 28 13:59:58 <<<...>>> N Scheduler autoexpire.cpp:263 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 15 min
May 28 13:59:58 <<<...>>> I Scheduler recordinginfo.cpp:1171 (AddHistory) AddHistory: -10/0, 0, 0, Tue May 28 14:00:00 2013/Divine Design
May 28 13:59:58 <<<...>>> I Scheduler scheduler.cpp:2514 (HandleRecordingStatusChange) Tuning recording: "Divine Design":"Carol and Paul's Living Room": channel 2590 on cardid 1, sourceid 2
May 28 13:59:58 <<<...>>> I Scheduler scheduler.cpp:1813 (run) sleeping for 1000 ms (s2n: 1 sr: 16)
May 28 13:59:59 <<<...>>> I Scheduler scheduler.cpp:1813 (run) sleeping for 566 ms (s2n: 0 sr: 16)
May 28 14:00:00 <<<...>>> I Scheduler recordinginfo.cpp:1171 (AddHistory) AddHistory: 4/0, 0, 0, Tue May 28 14:00:00 2013/Divine Design
May 28 14:00:00 <<<...>>> I Scheduler scheduler.cpp:1813 (run) sleeping for 1000 ms (s2n: 0 sr: 16)
May 28 14:00:01 <<<...>>> I Scheduler scheduler.cpp:1829 (run) sleeping for 60000 ms (interuptable)
May 28 14:00:04 <<<...>>> I CoreContext scheduler.cpp:637 (UpdateRecStatus) Updating status for "Divine Design":"Carol and Paul's Living Room" on cardid 1 (Tuning => Recording)
May 28 14:00:04 <<<...>>> I CoreContext recordinginfo.cpp:1171 (AddHistory) AddHistory: -2/-10, 0, 0, Tue May 28 14:00:00 2013/Divine Design
May 28 14:00:04 <<<...>>> I TVRecEvent tv_rec.cpp:3989 (TuningNewRecorder) TVRec(1): rec->GetPathname(): '/myth/tv3/2590_20130528140000.mpg'
May 28 14:01:01 <<<...>>> I Scheduler scheduler.cpp:1829 (run) sleeping for 60000 ms (interuptable)
May 28 14:02:01 <<<...>>> I Scheduler scheduler.cpp:1829 (run) sleeping for 60000 ms (interuptable)
May 28 14:02:11 <<<...>>> I HouseKeeping housekeeper.cpp:225 (RunHouseKeeping) Running housekeeping thread
May 28 14:03:01 <<<...>>> I Scheduler scheduler.cpp:1829 (run) sleeping for 60000 ms (interuptable)

comment:8 Changed 11 months ago by stuartm

You really need to upgrade before we can help. 0.25 is old and no longer supported. 0.25.2 isn't even the most recent release of the 0.25 branch, that was 0.25.3. We are only supporting 0.26+, 0.26.0 was released 8 months ago and the 0.26-fixes branch contains 171 commits (fixes) on top of that.

comment:9 Changed 11 months ago by wagnerrp

  • Resolution set to Works for me
  • Status changed from new to closed

Please re-open this ticket if you can reproduce the issue on a recent version of MythTV.

comment:10 Changed 11 months ago by gigem

  • Resolution Works for me deleted
  • Status changed from closed to new

comment:11 Changed 11 months ago by gigem

  • Status changed from new to assigned

Changed 11 months ago by gigem

Refactor, simplify and slightly enhance scheduler timing logic

Changed 11 months ago by gigem

Cleanup revision

comment:12 Changed 11 months ago by David Engel <dengel@…>

  • Resolution set to fixed
  • Status changed from assigned to closed

In a2eb931221b0d1fac76da884e779e1120b8a2b81/mythtv:

Refactor timing/sleep handling in the scheduler.

The first main change is to use HandleRecordiing?() and HandleTuning?()
to set the sleep time. The previous code used mostly duplicate code
in CalcTimeToNextHandleRecordingEvent?(). That meant there were two
places that needed to be checked/kept in sync when analyzing/fixing
timing issues.

The next main change is to sleep as long as possible. The previous
code would never sleep for longer than 60 seconds, even if it had
nothing to do.

The last main change is to be more persistent in tyring to apply long
preroll when the tuner is initially busy. The previous code didn't
specifically try to do this and it was hit and miss whether or not
preroll was used in these situations.

The rest is various stylistic changes.

Fixes #11108

comment:13 Changed 11 months ago by gigem

  • Milestone changed from unknown to 0.27

comment:14 Changed 11 months ago by David Engel <dengel@…>

In 27c6b4ed5328db6483f4d6848cdabd37434950d4/mythtv:

Fix issues with earlier scheduler timing refactor.

Fix a few issues, that were intruduced in SHA1:a2eb9312, including the
failure to put inactive slaves to sleep.

Fixes #11578
Refs #11108

Add Comment

Modify Ticket

Action
as closed .
The resolution will be deleted. Next status will be 'new'.
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.