Opened 11 years ago
Closed 11 years ago
Last modified 11 years ago
#11108 closed Bug Report - General (fixed)
RecordPreRoll doesn't work
Reported by: | 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)
Change History (18)
Changed 11 years ago by
Attachment: | schedpatch.diff added |
---|
comment:1 Changed 11 years ago by
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 11 years ago by
Attachment: | PATCH-backend added |
---|
More complete patch. This should fix the bug and handle all cases. Tested on my setup.
comment:2 Changed 11 years ago by
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 11 years ago by
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 11 years ago by
Status: | new → infoneeded_new |
---|
The reporter has enabled extra logging and is waiting for the problem to occur with the current code.
comment:5 Changed 11 years ago by
Resolution: | → Works for me |
---|---|
Status: | infoneeded_new → closed |
No response from original submitter.
comment:6 Changed 11 years ago by
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 years ago by
Resolution: | Works for me |
---|---|
Status: | closed → 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 years ago by
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 years ago by
Resolution: | → Works for me |
---|---|
Status: | new → closed |
Please re-open this ticket if you can reproduce the issue on a recent version of MythTV.
comment:10 Changed 11 years ago by
Resolution: | Works for me |
---|---|
Status: | closed → new |
comment:11 Changed 11 years ago by
Status: | new → assigned |
---|
Changed 11 years ago by
Attachment: | mythtv-11108-1.patch added |
---|
Refactor, simplify and slightly enhance scheduler timing logic
comment:12 Changed 11 years ago by
Resolution: | → fixed |
---|---|
Status: | assigned → closed |
comment:13 Changed 11 years ago by
Milestone: | unknown → 0.27 |
---|
Lightly tested patch that solves the issue for me