Opened 12 years ago
Closed 12 years ago
Last modified 12 years ago
#11224 closed Bug Report - General (fixed)
Duplicate recordings without manual resched - 0.26 regression
Reported by: | Owned by: | gigem | |
---|---|---|---|
Priority: | minor | Milestone: | 0.26.1 |
Component: | MythTV - Scheduling | Version: | 0.26-fixes |
Severity: | medium | Keywords: | |
Cc: | Ticket locked: | no |
Description
I have a number of shows that show during prime time, and then repeat the next day.
Before the first showing, the scheduler correctly identifies the first showing as the one to tape, and the second one is ignored as "earlier". The recording rule is to record all showings, and check for duplicates in 'All recordings'
However, once the first showing has finished being recorded, the second showing is then also incorrectly scheduled to record. This lasts until I force a reschedule (Eg mythutil --resched, have a completed mythfilldatabase run, etc)
This only started with the upgrade from 0.25 to 0.26. The only patches I have locally are to the perl bindings (#11079)
Note that my mythfilldatabase runs hourly via cron, but tv_grab_au is set up to fail except for once a day. If you're running mythfilldatabase hourly (or use EIT), I guess you may not see this because that would trigger the resched before you notice?
Example (FWIW my timezone is GMT+11):
During the recording (forgot to get this before the recording, but mythweb showed much the same)
$ mythbackend --printsched | grep Moral 2012-11-06 20:12:25.540082 I Yes, Minister - The Moral Dimensio 90 GEM 06 19:59-20:30 1 2 2 A 2 -50 2012-11-06 20:12:25.540828 I Yes, Minister - The Moral Dimensio 90 GEM 07 16:30-17:00 1 0 0 A E -50
After 8:30 (end of recording, but before end of the 10 minute soft padding):
$ mythbackend --printsched | grep Moral 2012-11-06 20:30:55.635870 I Yes, Minister - The Moral Dimensio 90 GEM 07 16:30-17:00 1 0 0 A E -50
After the recording is completely finished:
$ mythbackend --printsched | grep Moral 2012-11-06 20:40:53.150762 I Yes, Minister - The Moral Dimensio 90 GEM 07 16:30-17:00 1 2 2 A 2 -50
$ mythutil --resched .... 2012-11-06 20:41:12.522020 I Reschedule command sent to master $ mythbackend --printsched | grep Moral 2012-11-06 20:41:15.419157 I Yes, Minister - The Moral Dimensio 90 GEM 07 16:30-17:00 1 0 0 A R -50
In the logs - notice the "Reschedule interrupted":
Nov 6 20:40:00 guava mythlogserver: mythbackend[3407]: I TVRecEvent tv_rec.cpp:1043 (HandleStateChange?) TVRec(2): Changing from RecordingOnly? to None Nov 6 20:40:00 guava mythlogserver: mythbackend[3407]: I CoreContext? scheduler.cpp:655 (UpdateRecStatus?) Updating status for "Yes, Minister":"The Moral Dimension" on cardid 2 (Recording => Recorded) Nov 6 20:40:00 guava mythlogserver: mythbackend[3407]: I TVRecEvent recordinginfo.cpp:1131 (FinishedRecording?) Finished recording Yes, Minister "The Moral Dimension": channel 1090 Nov 6 20:40:00 guava mythlogserver: mythbackend[3407]: I Scheduler scheduler.cpp:2126 (HandleReschedule?) Reschedule requested for CHECK -3 295 0 UpdateRecStatus2 | Yes, Minister | The Moral Dimension | Jim is forced to back down about exposing bribery used to obtain a lucrative foreign contract when Bernard allows a valuable vase from a foreign government to be undervalued. | Nov 6 20:40:00 guava mythlogserver: mythbackend[3407]: E CoreContext? mainserver.cpp:915 (customEvent) MainServer?: PREVIEW_SUCCESS but no receivers. Nov 6 20:40:01 guava mythlogserver: mythbackend[3407]: I Scheduler scheduler.cpp:2230 (HandleReschedule?) Reschedule interrupted, will retry Nov 6 20:40:01 guava mythlogserver: mythbackend[3407]: I Scheduler scheduler.cpp:2126 (HandleReschedule?) Reschedule requested for PLACE Interrupted Nov 6 20:40:02 guava mythlogserver: mythbackend[3407]: I Scheduler scheduler.cpp:2239 (HandleReschedule?) Scheduled 72 items in 0.7 = 0.00 match + 0.00 check + 0.73 place
Nov 6 20:41:12 guava mythlogserver: mythbackend[3407]: I Scheduler scheduler.cpp:2126 (HandleReschedule?) Reschedule requested for MATCH 0 0 0 - MythUtilCommand? Nov 6 20:41:13 guava mythlogserver: mythbackend[3407]: I Scheduler scheduler.cpp:2239 (HandleReschedule?) Scheduled 72 items in 0.8 = 0.07 match + 0.05 check + 0.68 place
DB rules:
mysql> select * from record where title = 'Yes, Minister'\G * 1. row *
recordid: 295
type: 4
chanid: 1090
starttime: 09:00:00 startdate: 2012-11-06
endtime: 09:30:00 enddate: 2012-11-06
title: Yes, Minister
subtitle: The Moral Dimension
description: Jim is forced to back down about exposing bribery used to obtain a lucrative foreign contract when Bernard allows a valuable vase from a foreign government to be undervalued.
season: 3
episode: 4
category: comedy
profile: Default
recpriority: -50
autoexpire: 1
maxepisodes: 0
maxnewest: 0
startoffset: 0
endoffset: 0
recgroup: Default
dupmethod: 8
dupin: 15
station: GEM
seriesid: 26562466
programid:
inetref: 76829
search: 0
autotranscode: 1
autocommflag: 1 autouserjob1: 0 autouserjob2: 0 autouserjob3: 0 autouserjob4: 0 autometadata: 1
findday: 3
findtime: 20:00:00
findid: 735178
inactive: 0 parentid: 0
transcoder: 70
playgroup: Default prefinput: 0
next_record: 2012-11-06 09:00:00 last_record: 0000-00-00 00:00:00 last_delete: 0000-00-00 00:00:00
storagegroup: Default
avg_delay: 100
filter: 0
Before the recording starts:
mysql> select * from program where subtitle = 'The Moral Dimension' order by starttime\G * 1. row *
chanid: 1090
starttime: 2012-11-06 09:00:00
endtime: 2012-11-06 09:30:00
title: Yes, Minister
subtitle: The Moral Dimension
description: Jim is forced to back down about exposing bribery used to obtain a lucrative foreign contract when Bernard allows a valuable vase from a foreign government to be undervalued.
category: comedy
category_type:
airdate: 1982
stars: 0
previouslyshown: 1 title_pronounce:
stereo: 0
subtitled: 0
hdtv: 0
closecaptioned: 0
partnumber: 0
parttotal: 0
seriesid: 26562466
originalairdate: NULL
showtype:
colorcode:
syndicatedepisodenumber:
programid:
manualid: 0
generic: 0
listingsource: 4
first: 1
last: 0
audioprop:
subtitletypes:
videoprop: WIDESCREEN
* 2. row *
chanid: 1090
starttime: 2012-11-07 05:30:00
endtime: 2012-11-07 06:00:00
title: Yes, Minister
subtitle: The Moral Dimension
description: Jim is forced to back down about exposing bribery used to obtain a lucrative foreign contract when Bernard allows a valuable vase from a foreign government to be undervalued.
category: comedy
category_type:
airdate: 1982
stars: 0
previouslyshown: 1 title_pronounce:
stereo: 0
subtitled: 0
hdtv: 0
closecaptioned: 0
partnumber: 0
parttotal: 0
seriesid: 26562466
originalairdate: NULL
showtype:
colorcode:
syndicatedepisodenumber:
programid:
manualid: 0
generic: 0
listingsource: 4
first: 0
last: 1
audioprop:
subtitletypes:
videoprop: WIDESCREEN
2 rows in set (0.00 sec)
Attachments (6)
Change History (29)
comment:1 Changed 12 years ago by
Status: | new → assigned |
---|
comment:2 Changed 12 years ago by
Doesn't help.
I had a cron job running this evening. The MASH episode finished at 22:05 local time (with another 10 mintues soft-padding). From the logs:
Sat Nov 10 22:00:02 EST 2012 2012-11-10 22:00:10.860948 I M*A*S*H - Farewell, Goodbye and Am 1 ONE 10 19:27-22:05 1 1 1 O 1 0 2012-11-10 22:00:10.861213 I M*A*S*H - Farewell, Goodbye and Am 1 ONE 11 14:58-17:35 1 0 0 A E -10 Sat Nov 10 22:05:02 EST 2012 2012-11-10 22:05:03.227644 I M*A*S*H - Farewell, Goodbye and Am 1 ONE 11 14:58-17:35 1 0 0 A E -10 Sat Nov 10 22:10:02 EST 2012 2012-11-10 22:10:12.699623 I M*A*S*H - Farewell, Goodbye and Am 1 ONE 11 14:58-17:35 1 0 0 A E -10 Sat Nov 10 22:15:03 EST 2012 2012-11-10 22:15:16.663201 I M*A*S*H - Farewell, Goodbye and Am 1 ONE 11 14:58-17:35 1 1 1 A 1 -10
So it was correct at 22:05, but broke at 22:15. There were other recordings going on, but none that finished in the meantime. I'll attach the patch I was using, just to confirm that it was the correct one.
Note that other shows have finished since then, but I still see the repeat of the episode being scheduled to report at 3pm tomorrow.
Will also attach the mythbackend log.
Changed 12 years ago by
Attachment: | 11224-debug1.patch added |
---|
comment:3 Changed 12 years ago by
Hmm. I know what has to be happening on one level, but not why. Please apply this new patch and replace "<myrecordid>" with the value for one of your rules that is showing the problem. This should confirm the what and hopefully shed some light on the why.
When you run this, please also dump the applicable record and oldrecorded entries while the first showing is recording, after it has finished and the problem exists and after you manually force a reschedule to correct the problem.
comment:4 Changed 12 years ago by
OK, applied (on top of the previous patch). I looked in the guide for something that should trigger this, and created a new rule for JAG (id 298). The episode is scheduled for 1pm today with a repeat at 1am tomorrow (UTC+11). (There are also some other records for every other day in the week that you'll see in the logs, but note that these don't have any repeats scheduled)
I'll attach the backend log too.
Before the recording started:
mysql> select * from record where recordid=298\G *************************** 1. row *************************** recordid: 298 type: 4 chanid: 1011 starttime: 02:00:00 startdate: 2012-11-11 endtime: 03:00:00 enddate: 2012-11-11 title: JAG subtitle: Baby, It's Cold Outside description: Former fighter pilot Captain Harmon 'Harm' Rabb and his team of lawyers are charged with the duty of investigating and litigating crimes committed by marine and navy personnel. season: 6 episode: 11 category: drama profile: Default recpriority: 0 autoexpire: 1 maxepisodes: 0 maxnewest: 0 startoffset: 0 endoffset: 0 recgroup: Default dupmethod: 8 dupin: 15 station: ELEVEN seriesid: 20055 programid: inetref: 73710 search: 0 autotranscode: 0 autocommflag: 0 autouserjob1: 0 autouserjob2: 0 autouserjob3: 0 autouserjob4: 0 autometadata: 1 findday: 1 findtime: 13:00:00 findid: 735183 inactive: 0 parentid: 0 transcoder: 70 playgroup: Default prefinput: 0 next_record: 2012-11-11 02:00:00 last_record: 0000-00-00 00:00:00 last_delete: 0000-00-00 00:00:00 storagegroup: Default avg_delay: 100 filter: 0 1 row in set (0.00 sec) mysql> select recordid, chanid, starttime, manualid, oldrecduplicate, recduplicate, findduplicate, oldrecstatus, findid from recordmatch where recordid=298 order by starttime, chanid; +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ | recordid | chanid | starttime | manualid | oldrecduplicate | recduplicate | findduplicate | oldrecstatus | findid | +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ | 298 | 1011 | 2012-11-11 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-11 14:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-12 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-13 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-14 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-15 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-16 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-17 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-18 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ 9 rows in set (0.00 sec) mysql> select * from record where title='JAG' and subtitle = "Baby, It's Cold Outside"\G*************************** 1. row *************************** recordid: 298 type: 4 chanid: 1011 starttime: 02:00:00 startdate: 2012-11-11 endtime: 03:00:00 enddate: 2012-11-11 title: JAG subtitle: Baby, It's Cold Outside description: Former fighter pilot Captain Harmon 'Harm' Rabb and his team of lawyers are charged with the duty of investigating and litigating crimes committed by marine and navy personnel. season: 6 episode: 11 category: drama profile: Default recpriority: 0 autoexpire: 1 maxepisodes: 0 maxnewest: 0 startoffset: 0 endoffset: 0 recgroup: Default dupmethod: 8 dupin: 15 station: ELEVEN seriesid: 20055 programid: inetref: 73710 search: 0 autotranscode: 0 autocommflag: 0 autouserjob1: 0 autouserjob2: 0 autouserjob3: 0 autouserjob4: 0 autometadata: 1 findday: 1 findtime: 13:00:00 findid: 735183 inactive: 0 parentid: 0 transcoder: 70 playgroup: Default prefinput: 0 next_record: 2012-11-11 02:00:00 last_record: 0000-00-00 00:00:00 last_delete: 0000-00-00 00:00:00 storagegroup: Default avg_delay: 100 filter: 0 1 row in set (0.00 sec) mysql> select * from oldrecorded where title='JAG' and subtitle = "Baby, It's Cold Outside"\G*************************** 1. row *************************** chanid: 1011 starttime: 2012-11-11 02:00:00 endtime: 2012-11-11 03:00:00 title: JAG subtitle: Baby, It's Cold Outside description: Former fighter pilot Captain Harmon 'Harm' Rabb and his team of lawyers are charged with the duty of investigating and litigating crimes committed by marine and navy personnel. season: 0 episode: 0 category: drama seriesid: 20055 programid: inetref: 73710 findid: 0 recordid: 298 station: ELEVEN rectype: 4 duplicate: 0 recstatus: -1 reactivate: 0 generic: 0 future: 1 *************************** 2. row *************************** chanid: 1011 starttime: 2012-11-11 14:00:00 endtime: 2012-11-11 15:00:00 title: JAG subtitle: Baby, It's Cold Outside description: Former fighter pilot Captain Harmon 'Harm' Rabb and his team of lawyers are charged with the duty of investigating and litigating crimes committed by marine and navy personnel. season: 0 episode: 0 category: drama seriesid: 20055 programid: inetref: 73710 findid: 0 recordid: 298 station: ELEVEN rectype: 4 duplicate: 0 recstatus: 4 reactivate: 0 generic: 0 future: 1 2 rows in set (0.01 sec) $ mythbackend --printsched | grep "Baby, It's Cold" 2012-11-11 12:43:22.903779 I JAG - Baby, It's Cold Outside 11 ELEVEN 11 13:00-14:00 1 1 1 A 1 0 2012-11-11 12:43:22.904373 I JAG - Baby, It's Cold Outside 11 ELEVEN 12 01:00-02:00 1 0 0 A E 0
After recording has started:
mysql> select recordid, chanid, starttime, manualid, oldrecduplicate, recduplicate, findduplicate, oldrecstatus, findid from recordmatch where recordid=298 order by starttime, chanid; +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ | recordid | chanid | starttime | manualid | oldrecduplicate | recduplicate | findduplicate | oldrecstatus | findid | +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ | 298 | 1011 | 2012-11-11 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-11 14:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-12 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-13 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-14 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-15 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-16 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-17 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-18 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ 9 rows in set (0.00 sec) mysql> select * from record where title='JAG' and subtitle = "Baby, It's Cold Outside"\G*************************** 1. row *************************** recordid: 298 type: 4 chanid: 1011 starttime: 02:00:00 startdate: 2012-11-11 endtime: 03:00:00 enddate: 2012-11-11 title: JAG subtitle: Baby, It's Cold Outside description: Former fighter pilot Captain Harmon 'Harm' Rabb and his team of lawyers are charged with the duty of investigating and litigating crimes committed by marine and navy personnel. season: 6 episode: 11 category: drama profile: Default recpriority: 0 autoexpire: 1 maxepisodes: 0 maxnewest: 0 startoffset: 0 endoffset: 0 recgroup: Default dupmethod: 8 dupin: 15 station: ELEVEN seriesid: 20055 programid: inetref: 73710 search: 0 autotranscode: 0 autocommflag: 0 autouserjob1: 0 autouserjob2: 0 autouserjob3: 0 autouserjob4: 0 autometadata: 1 findday: 1 findtime: 13:00:00 findid: 735183 inactive: 0 parentid: 0 transcoder: 70 playgroup: Default prefinput: 0 next_record: 2012-11-12 02:00:00 last_record: 2012-11-11 01:58:58 last_delete: 0000-00-00 00:00:00 storagegroup: Default avg_delay: 100 filter: 0 1 row in set (0.00 sec) mysql> select * from oldrecorded where title='JAG' and subtitle = "Baby, It's Cold Outside"\G*************************** 1. row *************************** chanid: 1011 starttime: 2012-11-11 02:00:00 endtime: 2012-11-11 03:00:00 title: JAG subtitle: Baby, It's Cold Outside description: Former fighter pilot Captain Harmon 'Harm' Rabb and his team of lawyers are charged with the duty of investigating and litigating crimes committed by marine and navy personnel. season: 0 episode: 0 category: drama seriesid: 20055 programid: inetref: 73710 findid: 0 recordid: 298 station: ELEVEN rectype: 4 duplicate: 0 recstatus: -2 reactivate: 0 generic: 0 future: 0 *************************** 2. row *************************** chanid: 1011 starttime: 2012-11-11 14:00:00 endtime: 2012-11-11 15:00:00 title: JAG subtitle: Baby, It's Cold Outside description: Former fighter pilot Captain Harmon 'Harm' Rabb and his team of lawyers are charged with the duty of investigating and litigating crimes committed by marine and navy personnel. season: 0 episode: 0 category: drama seriesid: 20055 programid: inetref: 73710 findid: 0 recordid: 298 station: ELEVEN rectype: 4 duplicate: 0 recstatus: 4 reactivate: 0 generic: 0 future: 1 2 rows in set (0.00 sec) $ mythbackend --printsched | grep "Baby, It's Cold" 2012-11-11 13:02:06.816920 I JAG - Baby, It's Cold Outside 11 ELEVEN 11 12:59-14:00 1 1 1 A 1 0 2012-11-11 13:02:06.817448 I JAG - Baby, It's Cold Outside 11 ELEVEN 12 01:00-02:00 1 0 0 A E 0
After its finished:
mysql> select * from record where title='JAG' and subtitle = "Baby, It's Cold Outside"\G *************************** 1. row *************************** recordid: 298 type: 4 chanid: 1011 starttime: 02:00:00 startdate: 2012-11-11 endtime: 03:00:00 enddate: 2012-11-11 title: JAG subtitle: Baby, It's Cold Outside description: Former fighter pilot Captain Harmon 'Harm' Rabb and his team of lawyers are charged with the duty of investigating and litigating crimes committed by marine and navy personnel. season: 6 episode: 11 category: drama profile: Default recpriority: 0 autoexpire: 1 maxepisodes: 0 maxnewest: 0 startoffset: 0 endoffset: 0 recgroup: Default dupmethod: 8 dupin: 15 station: ELEVEN seriesid: 20055 programid: inetref: 73710 search: 0 autotranscode: 0 autocommflag: 0 autouserjob1: 0 autouserjob2: 0 autouserjob3: 0 autouserjob4: 0 autometadata: 1 findday: 1 findtime: 13:00:00 findid: 735183 inactive: 0 parentid: 0 transcoder: 70 playgroup: Default prefinput: 0 next_record: 2012-11-11 14:00:00 last_record: 2012-11-11 01:58:58 last_delete: 0000-00-00 00:00:00 storagegroup: Default avg_delay: 100 filter: 0 1 row in set (0.00 sec) mysql> select * from oldrecorded where title='JAG' and subtitle = "Baby, It's Cold Outside"\G *************************** 1. row *************************** chanid: 1011 starttime: 2012-11-11 02:00:00 endtime: 2012-11-11 03:00:00 title: JAG subtitle: Baby, It's Cold Outside description: Former fighter pilot Captain Harmon 'Harm' Rabb and his team of lawyers are charged with the duty of investigating and litigating crimes committed by marine and navy personnel. season: 0 episode: 0 category: drama seriesid: 20055 programid: inetref: 73710 findid: 0 recordid: 298 station: ELEVEN rectype: 4 duplicate: 1 recstatus: -3 reactivate: 0 generic: 0 future: 0 *************************** 2. row *************************** chanid: 1011 starttime: 2012-11-11 14:00:00 endtime: 2012-11-11 15:00:00 title: JAG subtitle: Baby, It's Cold Outside description: Former fighter pilot Captain Harmon 'Harm' Rabb and his team of lawyers are charged with the duty of investigating and litigating crimes committed by marine and navy personnel. season: 0 episode: 0 category: drama seriesid: 20055 programid: inetref: 73710 findid: 0 recordid: 298 station: ELEVEN rectype: 4 duplicate: 0 recstatus: -1 reactivate: 0 generic: 0 future: 1 2 rows in set (0.00 sec) mysql> select recordid, chanid, starttime, manualid, oldrecduplicate, recduplicate, findduplicate, oldrecstatus, findid from recordmatch where recordid=298 order by starttime, chanid; +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ | recordid | chanid | starttime | manualid | oldrecduplicate | recduplicate | findduplicate | oldrecstatus | findid | +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ | 298 | 1011 | 2012-11-11 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-11 14:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-12 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-13 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-14 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-15 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-16 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-17 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-18 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ 9 rows in set (0.00 sec) $ mythbackend --printsched | grep "Baby, It's Cold" 2012-11-11 14:45:48.501864 I JAG - Baby, It's Cold Outside 11 ELEVEN 12 01:00-02:00 1 1 1 A 1 0
After a resched:
mysql> select recordid, chanid, starttime, manualid, oldrecduplicate, recduplicate, findduplicate, oldrecstatus, findid from recordmatch where recordid=298 order by starttime, chanid; +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ | recordid | chanid | starttime | manualid | oldrecduplicate | recduplicate | findduplicate | oldrecstatus | findid | +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ | 298 | 1011 | 2012-11-11 02:00:00 | 0 | 1 | 1 | 0 | -3 | 0 | | 298 | 1011 | 2012-11-11 14:00:00 | 0 | 1 | 1 | 0 | -3 | 0 | | 298 | 1011 | 2012-11-12 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-13 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-14 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-15 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-16 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-17 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 298 | 1011 | 2012-11-18 02:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ 9 rows in set (0.00 sec) mysql> select * from record where title='JAG' and subtitle = "Baby, It's Cold Outside"\G*************************** 1. row *************************** recordid: 298 type: 4 chanid: 1011 starttime: 02:00:00 startdate: 2012-11-11 endtime: 03:00:00 enddate: 2012-11-11 title: JAG subtitle: Baby, It's Cold Outside description: Former fighter pilot Captain Harmon 'Harm' Rabb and his team of lawyers are charged with the duty of investigating and litigating crimes committed by marine and navy personnel. season: 6 episode: 11 category: drama profile: Default recpriority: 0 autoexpire: 1 maxepisodes: 0 maxnewest: 0 startoffset: 0 endoffset: 0 recgroup: Default dupmethod: 8 dupin: 15 station: ELEVEN seriesid: 20055 programid: inetref: 73710 search: 0 autotranscode: 0 autocommflag: 0 autouserjob1: 0 autouserjob2: 0 autouserjob3: 0 autouserjob4: 0 autometadata: 1 findday: 1 findtime: 13:00:00 findid: 735183 inactive: 0 parentid: 0 transcoder: 70 playgroup: Default prefinput: 0 next_record: 2012-11-12 02:00:00 last_record: 2012-11-11 01:58:58 last_delete: 0000-00-00 00:00:00 storagegroup: Default avg_delay: 100 filter: 0 1 row in set (0.00 sec) mysql> select * from oldrecorded where title='JAG' and subtitle = "Baby, It's Cold Outside"\G*************************** 1. row *************************** chanid: 1011 starttime: 2012-11-11 02:00:00 endtime: 2012-11-11 03:00:00 title: JAG subtitle: Baby, It's Cold Outside description: Former fighter pilot Captain Harmon 'Harm' Rabb and his team of lawyers are charged with the duty of investigating and litigating crimes committed by marine and navy personnel. season: 0 episode: 0 category: drama seriesid: 20055 programid: inetref: 73710 findid: 0 recordid: 298 station: ELEVEN rectype: 4 duplicate: 1 recstatus: -3 reactivate: 0 generic: 0 future: 0 *************************** 2. row *************************** chanid: 1011 starttime: 2012-11-11 14:00:00 endtime: 2012-11-11 15:00:00 title: JAG subtitle: Baby, It's Cold Outside description: Former fighter pilot Captain Harmon 'Harm' Rabb and his team of lawyers are charged with the duty of investigating and litigating crimes committed by marine and navy personnel. season: 0 episode: 0 category: drama seriesid: 20055 programid: inetref: 73710 findid: 0 recordid: 298 station: ELEVEN rectype: 4 duplicate: 0 recstatus: 3 reactivate: 0 generic: 0 future: 1 2 rows in set (0.00 sec) $ mythbackend --printsched | grep "Baby, It's Cold" 2012-11-11 14:46:55.556292 I JAG - Baby, It's Cold Outside 11 ELEVEN 12 01:00-02:00 1 0 0 A R 0
comment:5 Changed 12 years ago by
Okay, here's the smoking gun right where I expected it.
Nov 11 14:10:00 guava mythlogserver: mythbackend[30793]: I Scheduler scheduler.cpp:2156 (HandleReschedule) Reschedule requested for CHECK -3 298 0 UpdateRecStatus2 | JAG | Baby, It's Cold Outside | Former fighter pilot Captain Harmon 'Harm' Rabb and his team of lawyers are charged with the duty of investigating and litigating crimes committed by marine and navy personnel. | Nov 11 14:10:00 guava mythlogserver: mythbackend[30793]: I Scheduler scheduler.cpp:2231 (HandleReschedule) CreateTempTables... Nov 11 14:10:00 guava mythlogserver: mythbackend[30793]: I Scheduler scheduler.cpp:2237 (HandleReschedule) UpdateDuplicates... Nov 11 14:10:00 guava mythlogserver: mythbackend[30793]: I Scheduler scheduler.cpp:58 (DumpRecordMatch) Dumping recordmatch Before UpdateDuplicates() Nov 11 14:10:00 guava mythlogserver: mythbackend[30793]: I Scheduler scheduler.cpp:80 (DumpRecordMatch) rid=298, chid=1011, st=Sun Nov 11 02:00:00 2012, mid=0, ord=0, rd=0, fd=0, ors=0, fid=0 Nov 11 14:10:00 guava mythlogserver: mythbackend[30793]: I Scheduler scheduler.cpp:80 (DumpRecordMatch) rid=298, chid=1011, st=Sun Nov 11 14:00:00 2012, mid=0, ord=0, rd=0, fd=0, ors=0, fid=0
ord should be -1 for any programs matching the CHECK reschedule request, but they are being left at 0. That causes them to not be considered for the following duplicate update. So the question is why isn't ord being set to -1. It's not obvious to me why this is happening. Perhaps there's something unique in your guide data or configuration or the scheduler logic is just faulty.
Can you please add "database" to your backend logging to see the actual query being used? Then, try running the query manually in mysql and perhaps see why it's not working as intended.
comment:6 Changed 12 years ago by
Have set this up for this evening (with a different show, so tweaked the debug patch). I also had to add --logLevel debug to get the specific SQL statements in the logs
Only thing odd with my program data (.au) is that none of the TV shows will have program IDs. Also, none of the tv shows have season/episode ids, but by the time the post-show reschedule happens they will (this is because the metadata job runs at the end of the program time, but the resched only runs after the soft-padding is over)
comment:7 Changed 12 years ago by
I'll attach the logs. Note that at 18:03 and 19:03 mythfilldatabase ran (I forgot to turn that off), so I didn't manage to run any of the queries manually while it was broken.
The 18:03 logs seem to show that oldrecduplicate is being set to -1 for all episodes, at least temporarily, but then its reset later? Looking at the code, this is because the description is generic in the guide data and the db update sets it to -1 if the description matches. This was also the case for yesterday's JAG example, but I'll trigger another case overnight where the description isn't the same for every single episode.
Then something resets it to 0 later and it stays like that.
Currently:
mysql> select recordid, chanid, starttime, manualid, oldrecduplicate, recduplicate, findduplicate, oldrecstatus, findid from recordmatch where recordid=125 order by starttime, chanid; +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ | recordid | chanid | starttime | manualid | oldrecduplicate | recduplicate | findduplicate | oldrecstatus | findid | +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ | 125 | 1001 | 2012-11-12 07:00:00 | 0 | 1 | 1 | 0 | -3 | 0 | | 125 | 1001 | 2012-11-12 15:40:00 | 0 | 1 | 1 | 0 | -3 | 0 | | 125 | 1001 | 2012-11-13 07:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 125 | 1001 | 2012-11-13 14:10:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 125 | 1001 | 2012-11-14 07:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 125 | 1001 | 2012-11-15 07:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 125 | 1001 | 2012-11-15 15:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 125 | 1001 | 2012-11-16 07:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 125 | 1001 | 2012-11-17 05:30:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 125 | 1001 | 2012-11-17 08:30:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 125 | 1001 | 2012-11-17 09:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 125 | 1001 | 2012-11-18 05:30:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 125 | 1001 | 2012-11-18 06:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 125 | 1001 | 2012-11-19 07:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 125 | 1001 | 2012-11-20 07:00:00 | 0 | 0 | 0 | 0 | NULL | 0 | +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ 15 rows in set (0.00 sec)
comment:8 Changed 12 years ago by
Okay. Please try to trigger another case, then. We really need to figure why the update recordmatch query isn't working and you trying things manually while the problem exists is our best bet at this point.
oldrecduplicate will never be left to -1 for long. It's merely a special value to tell the following code to recalculate the correct value. This is an optimization added in MythTV 0.26. Calculating oldrecduplicate is pretty expensive, so the code now tries to avoid doing it when the value shouldn't have changed.
Yes, I noticed you had good subtitles and generic descriptions and no programids. I don't think that should be a problem, but we'll see.
comment:9 Changed 12 years ago by
OK, have another one. Breaking bad was shown at 12:03 am today. Its now incorrectly scheduled again for 1:15am on Sat.
mysql> select * from record where recordid=249\G *************************** 1. row *************************** recordid: 249 type: 4 chanid: 0 starttime: 14:13:00 startdate: 2012-10-01 endtime: 15:00:00 enddate: 2012-10-01 title: Breaking Bad subtitle: Mas description: As Skyler reconsiders her objections to him living back at home, Walt mulls over an offer to return to the drug trade. Meanwhile, Hank's obsession with nailing Heisenberg promises trouble for Jesse. season: 3 episode: 5 category: drama profile: Default recpriority: -10 autoexpire: 1 maxepisodes: 0 maxnewest: 0 startoffset: 0 endoffset: 0 recgroup: Default dupmethod: 8 dupin: 15 station: seriesid: 215085156 programid: inetref: 81189 search: 0 autotranscode: 1 autocommflag: 1 autouserjob1: 0 autouserjob2: 0 autouserjob3: 1 autouserjob4: 0 autometadata: 1 findday: 3 findtime: 00:13:00 findid: 735143 inactive: 0 parentid: 0 transcoder: 70 playgroup: Default prefinput: 0 next_record: 2012-11-16 14:15:00 last_record: 2012-11-12 13:01:59 last_delete: 0000-00-00 00:00:00 storagegroup: Default avg_delay: 100 filter: 0 1 row in set (0.00 sec) mysql> select recordid, chanid, starttime, manualid, oldrecduplicate, recduplicate, findduplicate, oldrecstatus, findid from recordmatch where recordid=249 order by starttime, chanid; +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ | recordid | chanid | starttime | manualid | oldrecduplicate | recduplicate | findduplicate | oldrecstatus | findid | +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ | 249 | 1022 | 2012-11-12 13:03:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 249 | 1022 | 2012-11-16 14:15:00 | 0 | 0 | 0 | 0 | NULL | 0 | | 249 | 1022 | 2012-11-19 12:59:00 | 0 | 0 | 0 | 0 | NULL | 0 | +----------+--------+---------------------+----------+-----------------+--------------+---------------+--------------+--------+ 3 rows in set (0.00 sec) mysql> select * from program where title = 'Breaking Bad' and subtitle = 'Abq' order by starttime\G *************************** 1. row *************************** chanid: 1022 starttime: 2012-11-12 13:03:00 endtime: 2012-11-12 13:50:00 title: Breaking Bad subtitle: Abq description: As Hank is unhappy with the pace of his recovery, and Skyler questions Saul's money-laundering scheme, Jesse falls for a fellow rehab patient who he learns is tied to the murder of his late friend, Combo. category: drama category_type: airdate: 2012 stars: 0 previouslyshown: 1 title_pronounce: stereo: 0 subtitled: 1 hdtv: 0 closecaptioned: 0 partnumber: 0 parttotal: 0 seriesid: 215085156 originalairdate: NULL showtype: colorcode: syndicatedepisodenumber: programid: manualid: 0 generic: 0 listingsource: 4 first: 1 last: 0 audioprop: subtitletypes: NORMAL videoprop: WIDESCREEN *************************** 2. row *************************** chanid: 1022 starttime: 2012-11-16 14:15:00 endtime: 2012-11-16 15:00:00 title: Breaking Bad subtitle: Abq description: As Hank is unhappy with the pace of his recovery, and Skyler questions Saul's money-laundering scheme, Jesse falls for a fellow rehab patient who he learns is tied to the murder of his late friend, Combo. category: drama category_type: airdate: 2012 stars: 0 previouslyshown: 1 title_pronounce: stereo: 0 subtitled: 1 hdtv: 0 closecaptioned: 0 partnumber: 0 parttotal: 0 seriesid: 215085156 originalairdate: NULL showtype: colorcode: syndicatedepisodenumber: programid: manualid: 0 generic: 0 listingsource: 4 first: 0 last: 1 audioprop: subtitletypes: NORMAL videoprop: WIDESCREEN 2 rows in set (0.02 sec) mysql> select * from oldrecorded where title = 'Breaking Bad' and subtitle = 'Abq' order by starttime\G *************************** 1. row *************************** chanid: 1022 starttime: 2012-11-12 13:03:00 endtime: 2012-11-12 13:50:00 title: Breaking Bad subtitle: Abq description: As Hank is unhappy with the pace of his recovery, and Skyler questions Saul's money-laundering scheme, Jesse falls for a fellow rehab patient who he learns is tied to the murder of his late friend, Combo. season: 0 episode: 0 category: drama seriesid: 215085156 programid: inetref: 81189 findid: 0 recordid: 249 station: ABC2 / ABC4 rectype: 4 duplicate: 1 recstatus: -3 reactivate: 0 generic: 0 future: 0 *************************** 2. row *************************** chanid: 1022 starttime: 2012-11-16 14:15:00 endtime: 2012-11-16 15:00:00 title: Breaking Bad subtitle: Abq description: As Hank is unhappy with the pace of his recovery, and Skyler questions Saul's money-laundering scheme, Jesse falls for a fellow rehab patient who he learns is tied to the murder of his late friend, Combo. season: 0 episode: 0 category: drama seriesid: 215085156 programid: inetref: 81189 findid: 0 recordid: 249 station: ABC2 / ABC4 rectype: 4 duplicate: 0 recstatus: -1 reactivate: 0 generic: 0 future: 1 2 rows in set (0.04 sec)
comment:10 Changed 12 years ago by
I had to reconstruct the update query from the source, because the debug doesn't display the bound params, but the select query does seem to return rows. (I didn't run the update so that I can get extra info if you want)
I've disabled mythfilldatabase, and since the next recording of this is Sat, this should give time to run any queries that you want.
The logging for update also doesn't seem to log how many rows were updated, but the debug logs seem to show that no rows are updated.
Nov 13 01:00:01 guava mythlogserver: mythbackend[20229]: D Scheduler mythdbcon. cpp:689 (exec) MSqlQuery::exec(SchedCon) ''U''P''D''A''T''E'' ''r''e''c''o''r'' d''m''a''t''c''h'' ''r''m'' ''I''N''N''E''R'' ''J''O''I''N'' ''r''e''c''o''r''d '' ''r'' '' '' '' '' '' '' ''O''N'' ''r''m''.''r''e''c''o''r''d''i''d'' ''='' ' 'r''.''r''e''c''o''r''d''i''d'' ''I''N''N''E''R'' ''J''O''I''N'' ''p''r''o''g'' r''a''m'' ''p'' '' '' '' '' '' '' ''O''N'' ''r''m''.''c''h''a''n''i''d'' ''='' ''p''.''c''h''a''n''i''d'' '' '' '' '' '' '' '' '' '' ''A''N''D'' ''r''m''.''s' 't''a''r''t''t''i''m''e'' ''='' ''p''.''s''t''a''r''t''t''i''m''e'' '' '' '' '' '' '' '' '' '' ''A''N''D'' ''r''m''.''m''a''n''u''a''l''i''d'' ''='' ''p''.''m''a''n''u''a''l''i''d'' ''S''E''T'' ''o''l''d''r''e''c''d''u''p''l''i''c''a''t''e'' ''='' ''-''1'' ''W''H''E''R''E'' ''p''.''g''e''n''e''r''i''c'' ''='' ''0'' '' '' '' '' '' '' ''A''N''D'' ''r''.''t''y''p''e'' ''N''O''T'' ''I''N'' ''(''1'','' ''7'','' ''8'')'' ''A''N''D'' ''p''.''t''i''t''l''e'' ''='' '':''T''I''T''L''E'' ''A''N''D'' ''(''0'' ''O''R'' ''p''.''s''u''b''t''i''t''l''e'' ''='' '':''S''U''B''T''I''T''L''E'' ''O''R'' ''p''.''d''e''s''c''r''i''p''t''i''o''n'' ''='' '':''S''U''B''T''I''T''L''E'' ''O''R'' ''p''.''d''e''s''c''r''i''p''t''i''o''n'' ''='' '':''D''E''S''C''R''I''P'' ''O''R'' ''p''.''s''u''b''t''i''t''l''e'' ''='' '':''D''E''S''C''R''I''P'' '')'' '' mysql> select * from recordmatch rm INNER JOIN record r ON rm.recordid=r.recordid inner join program p on rm.chanid=p.chanid and rm.starttime=p.starttime and rm.manualid=p.manualid where p.generic=0 and r.type not in (1,7,8) and p.title='Breaking Bad' AND (0 or p.subtitle='Abq' or p.description='Abq')\G *************************** 1. row *************************** recordid: 249 chanid: 1022 starttime: 2012-11-12 13:03:00 manualid: 0 oldrecduplicate: 0 recduplicate: 0 findduplicate: 0 oldrecstatus: NULL findid: 0 recordid: 249 type: 4 chanid: 0 starttime: 14:13:00 startdate: 2012-10-01 endtime: 15:00:00 enddate: 2012-10-01 title: Breaking Bad subtitle: Mas description: As Skyler reconsiders her objections to him living back at home, Walt mulls over an offer to return to the drug trade. Meanwhile, Hank's obsession with nailing Heisenberg promises trouble for Jesse. season: 3 episode: 5 category: drama profile: Default recpriority: -10 autoexpire: 1 maxepisodes: 0 maxnewest: 0 startoffset: 0 endoffset: 0 recgroup: Default dupmethod: 8 dupin: 15 station: seriesid: 215085156 programid: inetref: 81189 search: 0 autotranscode: 1 autocommflag: 1 autouserjob1: 0 autouserjob2: 0 autouserjob3: 1 autouserjob4: 0 autometadata: 1 findday: 3 findtime: 00:13:00 findid: 735143 inactive: 0 parentid: 0 transcoder: 70 playgroup: Default prefinput: 0 next_record: 2012-11-16 14:15:00 last_record: 2012-11-12 13:01:59 last_delete: 0000-00-00 00:00:00 storagegroup: Default avg_delay: 100 filter: 0 chanid: 1022 starttime: 2012-11-12 13:03:00 endtime: 2012-11-12 13:50:00 title: Breaking Bad subtitle: Abq description: As Hank is unhappy with the pace of his recovery, and Skyler questions Saul's money-laundering scheme, Jesse falls for a fellow rehab patient who he learns is tied to the murder of his late friend, Combo. category: drama category_type: airdate: 2012 stars: 0 previouslyshown: 1 title_pronounce: stereo: 0 subtitled: 1 hdtv: 0 closecaptioned: 0 partnumber: 0 parttotal: 0 seriesid: 215085156 originalairdate: NULL showtype: colorcode: syndicatedepisodenumber: programid: manualid: 0 generic: 0 listingsource: 4 first: 1 last: 0 audioprop: subtitletypes: NORMAL videoprop: WIDESCREEN *************************** 2. row *************************** recordid: 249 chanid: 1022 starttime: 2012-11-16 14:15:00 manualid: 0 oldrecduplicate: 0 recduplicate: 0 findduplicate: 0 oldrecstatus: NULL findid: 0 recordid: 249 type: 4 chanid: 0 starttime: 14:13:00 startdate: 2012-10-01 endtime: 15:00:00 enddate: 2012-10-01 title: Breaking Bad subtitle: Mas description: As Skyler reconsiders her objections to him living back at home, Walt mulls over an offer to return to the drug trade. Meanwhile, Hank's obsession with nailing Heisenberg promises trouble for Jesse. season: 3 episode: 5 category: drama profile: Default recpriority: -10 autoexpire: 1 maxepisodes: 0 maxnewest: 0 startoffset: 0 endoffset: 0 recgroup: Default dupmethod: 8 dupin: 15 station: seriesid: 215085156 programid: inetref: 81189 search: 0 autotranscode: 1 autocommflag: 1 autouserjob1: 0 autouserjob2: 0 autouserjob3: 1 autouserjob4: 0 autometadata: 1 findday: 3 findtime: 00:13:00 findid: 735143 inactive: 0 parentid: 0 transcoder: 70 playgroup: Default prefinput: 0 next_record: 2012-11-16 14:15:00 last_record: 2012-11-12 13:01:59 last_delete: 0000-00-00 00:00:00 storagegroup: Default avg_delay: 100 filter: 0 chanid: 1022 starttime: 2012-11-16 14:15:00 endtime: 2012-11-16 15:00:00 title: Breaking Bad subtitle: Abq description: As Hank is unhappy with the pace of his recovery, and Skyler questions Saul's money-laundering scheme, Jesse falls for a fellow rehab patient who he learns is tied to the murder of his late friend, Combo. category: drama category_type: airdate: 2012 stars: 0 previouslyshown: 1 title_pronounce: stereo: 0 subtitled: 1 hdtv: 0 closecaptioned: 0 partnumber: 0 parttotal: 0 seriesid: 215085156 originalairdate: NULL showtype: colorcode: syndicatedepisodenumber: programid: manualid: 0 generic: 0 listingsource: 4 first: 0 last: 1 audioprop: subtitletypes: NORMAL videoprop: WIDESCREEN 2 rows in set (0.00 sec)
comment:11 Changed 12 years ago by
Actually, looking at my other logs and the code, bind values *are* meant to be substituted. So it looks like the issue might be that the bound values aren't being applied? I'm not familiar with the QT mysql bindings, but nothing immediately looks wrong (although I'm not sure why MSqlBindings is used rather than just setting values on the query object directly - currently the cost sets up the bindings, then iterates through to apply them to the object, and then on ->exec the msql class just does the same thing
In case it matters, I'm running ubuntu 12.04
comment:12 Changed 12 years ago by
I think you've found it. I vaguely recall that Qt is pretty anal about the bindings, including not liking a binding to be used more than once. Please try 11224-debug2.patch. IIRC and it is the problem, this patch should fix it.
Changed 12 years ago by
Attachment: | 11224-debug2.patch added |
---|
comment:13 follow-up: 15 Changed 12 years ago by
Yeah, that's it. I set up a recording that hasn't started yet so I can't be sure, but I deleted a show, and I've noticed that that caused a CHECK that has now the correct query in the logs (ie with params)
That also explains why noone else saw this - most of the rest of the world uses programids.
(Side note - deleting a show triggers the CHECK reschedule but undeleting it doesn't - is that a separate bug?)
Will update this evening when the recording in question has finished
comment:14 Changed 12 years ago by
Yeah, that fixed it:
Nov 13 12:10:00 guava mythlogserver: mythbackend[18663]: I Scheduler scheduler.cpp:2159 (HandleReschedule) Reschedule requested for CHECK -3 300 0 UpdateRecStatus2 | The Love Boat | The Lady from Laramie | All aboard, the Love Boat is ready to set sail! What madcap misadventures and romantic rendezvous await the crew and passengers of the Pacific Princess? | Nov 13 12:10:00 guava mythlogserver: mythbackend[18663]: D Scheduler mythdbcon.cpp:689 (exec) MSqlQuery::exec(SchedCon) UPDATE recordmatch rm INNER JOIN record r ON rm.recordid = r.recordid INNER JOIN program p ON rm.chanid = p.chanid AND rm.starttime = p.starttime AND rm.manualid = p.manualid SET oldrecduplicate = -1 WHERE p.generic = 0 AND r.type NOT IN (1, 7, 8) AND p.title = 'The Love Boat' AND (0 OR p.subtitle = 'The Lady from Laramie' OR p.description = 'The Lady from Laramie' OR p.description = 'All aboard, the Love Boat is ready to set sail! What madcap misadventures and romantic rendezvous await the crew and passengers of the Pacific Princess?' OR p.subtitle = 'All aboard, the Love Boat is ready to set sail! What madcap misadventures and romantic rendezvous await the crew and passengers of the Pacific Princess?' )
without the odd per-character quoting too.
and the "Before UpdateDuplicates?()" debug dump has:
Nov 13 12:10:00 guava mythlogserver: mythbackend[18663]: I Scheduler scheduler.cpp:81 (DumpRecordMatch) rid=300, chid=1011, st=Mon Nov 12 15:00:00 2012, mid=0, ord=-1, rd=0, fd=0, ors=0, fid=0 Nov 13 12:10:00 guava mythlogserver: mythbackend[18663]: D Scheduler mythdbcon.cpp:759 (seekDebug) MSqlQuery::next(DBManager32) Result: "recordid = 300, chanid = 1011, starttime = 2012-11-13T00:00:00, manualid = 0, oldrecduplicate = -1, recduplicate = 0, findduplicate = 0, oldrecstatus = 0, findid = 0" Nov 13 12:10:00 guava mythlogserver: mythbackend[18663]: I Scheduler scheduler.cpp:81 (DumpRecordMatch) rid=300, chid=1011, st=Tue Nov 13 00:00:00 2012, mid=0, ord=-1, rd=0, fd=0, ors=0, fid=0 Nov 13 12:10:00 guava mythlogserver: mythbackend[18663]: D Scheduler mythdbcon.cpp:759 (seekDebug) MSqlQuery::next(DBManager32) Result: "recordid = 300, chanid = 1011, starttime = 2012-11-13T15:00:00, manualid = 0, oldrecduplicate = -1, recduplicate = 0, findduplicate = 0, oldrecstatus = 0, findid = 0"
as expected.
comment:15 Changed 12 years ago by
Replying to Bradley Baetz <bbaetz@…>:
(Side note - deleting a show triggers the CHECK reschedule but undeleting it doesn't - is that a separate bug?)
Yes, that's a separate bug.
Replying to Bradley Baetz <bbaetz@…>:
Yeah, that fixed it:
Yay.
without the odd per-character quoting too.
Cool. I was wondering why that was happening.
I'll commit the fixes shortly.
comment:16 Changed 12 years ago by
Resolution: | → fixed |
---|---|
Status: | assigned → closed |
comment:23 Changed 12 years ago by
Milestone: | unknown → 0.26.1 |
---|
I'm hoping this is a simple race condition. In TVRec::FinishedRecording?(), you should see the following two chunks of code:
Please try reversing the order of them. When you do that, please also run the backend with -v schedule.