[mythtv-users] Strange Error Message in Log
Roger Siddons
dizygotheca at ntlworld.com
Sat May 12 22:08:26 UTC 2012
On Sat, 12 May 2012 21:37:56 +0100, Alan Chandler
<alan at chandlerfamily.org.uk> wrote:
> I am tracking down another problem (which I will report separately to
> the list) when I cam across the following in my backend log for today
>
> 2012-05-12 19:15:33.915813 N [26047/26071] Expire autoexpire.cpp:263
> (CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 3.0 GB
> w/freq: 14 min
> 2012-05-12 19:17:04.328460 E [26047/26058] EIT mythdb.cpp:192 (DBError)
> - DB Error (change_program):
> Query was:
> UPDATE program SET starttime = ?, endtime = ? WHERE chanid = ?
> AND starttime = ?
> Bindings were:
> :CHANID=1081, :NEWEND=2012-05-14T13:40:00, :NEWSTART=2012-05-14T13:00:00,
> :OLDSTART=2012-05-14T12:00:00
> Driver error was [2/1062]:
> QMYSQL3: Unable to execute statement
> Database error was:
> Duplicate entry '1081-2012-05-14 13:00:00-0' for key 'PRIMARY'
>
> 2012-05-12 19:18:23.779159 I [26047/26069] Scheduler scheduler.cpp:2011
> (HandleReschedule) - Reschedule requested for id -1.
> 2012-05-12 19:18:24.419806 I [26047/26069] Scheduler scheduler.cpp:2069
> (HandleReschedule) - Scheduled 141 items in 0.6 = 0.31 match + 0.33 place
> 2012-05-12 19:18:41.203334 I [26047/26070] HouseKeeping
> housekeeper.cpp:225 (RunHouseKeeping) - Running housekeeping thread
> 2012-05-12 19:19:29.555847 I [26047/26064] TVRecEvent tv_rec.cpp:1518
> (HandlePendingRecordings) - TVRec(21): ASK_RECORDING 21 29 0 0
> 2012-05-12 19:19:29.564286 I [26047/26068] TVRecEvent tv_rec.cpp:1518
> (HandlePendingRecordings) - TVRec(24): ASK_RECORDING 24 29 0 0
> 2012-05-12 19:19:29.899042 I [26047/26067] TVRecEvent tv_rec.cpp:1518
> (HandlePendingRecordings) - TVRec(23): ASK_RECORDING 23 29 0 0
> 2012-05-12 19:19:29.899175 I [26047/26066] TVRecEvent tv_rec.cpp:1518
> (HandlePendingRecordings) - TVRec(22): ASK_RECORDING 22 29 0 0
> 2012-05-12 19:19:59.759659 I [26047/26064] TVRecEvent tv_rec.cpp:1014
> (HandleStateChange) - TVRec(21): Changing from None to RecordingOnly
> 2012-05-12 19:19:59.760574 I [26047/26064] TVRecEvent tv_rec.cpp:3456
> (TuningCheckForHWChange) - TVRec(21): HW Tuner: 21->21
> 2012-05-12 19:20:06.344388 N [26047/26069] Scheduler autoexpire.cpp:263
> (CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 3.0 GB
> w/freq: 7 min
> 2012-05-12 19:20:06.344451 I [26047/26069] Scheduler scheduler.cpp:2460
> (HandleRecordingStatusChange) - Tuning recording: "Britain's Got
> Talent":"The Final": channel 1003 on ca
> rdid 21, sourceid 1
> 2012-05-12 19:20:36.633274 E [26047/26058] EIT mythdb.cpp:192 (DBError)
> - DB Error (change_program):
> Query was:
> UPDATE program SET starttime = ?, endtime = ? WHERE chanid = ?
> AND starttime = ?
> Bindings were:
> :CHANID=1081, :NEWEND=2012-05-14T13:40:00, :NEWSTART=2012-05-14T13:00:00,
> :OLDSTART=2012-05-14T12:00:00
> Driver error was [2/1062]:
> QMYSQL3: Unable to execute statement
> Database error was:
> Duplicate entry '1081-2012-05-14 13:00:00-0' for key 'PRIMARY'
>
> 2012-05-12 19:21:56.285571 I [26047/26069] Scheduler scheduler.cpp:2011
> (HandleReschedule) - Reschedule requested for id -1.
> 2012-05-12 19:21:56.823969 I [26047/26069] Scheduler scheduler.cpp:2069
> (HandleReschedule) - Scheduled 141 items in 0.5 = 0.28 match + 0.25 place
>
>
> It may or may not be related to the other problem. (I have a NOVA-TD-500
> which seems to sometimes lockup the second tuner with a hard lockup -
> requiring a reboot of my server to clear). The "Britain's Got Talent"
> program its trying to start recording ended up being 0 bytes log (ie it
> didn't record it)
>
> What does database failure mean? (I realise that the primary key already
> exists is what it means, what I mean is what in Mythtv terms does it
> mean).
>
I too noticed this error today but I suspect it's a minor EIT update
problem. I've been running 0.25fixes for a month and my logs show;
tilda at htpc:~$ grep DBError -i /var/log/mythtv/mythbackend.log -2
Apr 13 14:09:38 htpc mythbackend[1599]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
Apr 13 14:09:38 htpc mythbackend[1599]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 0 items in 0.1 = 0.01 match + 0.11 place
Apr 13 14:09:50 htpc mythbackend[1599]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-04-17T13:20:00,
:NEWSTART=2012-04-17T11:30:00,#012:OLDSTART=2012-04-17T09:30:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-04-17 11:30:00-0' for key
'PRIMARY'
Apr 13 14:11:21 htpc mythbackend[1599]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
Apr 13 14:16:25 htpc mythbackend[1599]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
--
Apr 19 19:59:00 htpc mythbackend[1465]: I CoreContext scheduler.cpp:634
(UpdateRecStatus) Updating status for Stuff:"A Horizon Guide to Materials"
on cardid 1 (Tuning => Recording)
Apr 19 19:59:00 htpc mythbackend[1465]: I TVRecEvent tv_rec.cpp:3950
(TuningNewRecorder) TVRec(1): rec->GetPathname():
'/media/tv1/recordings/1009_20120419195900.mpg'
Apr 19 19:59:01 htpc mythbackend[1465]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-04-19T22:25:00,
:NEWSTART=2012-04-19T21:20:00,#012:OLDSTART=2012-04-19T20:50:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-04-19 21:20:00-0' for key
'PRIMARY'
Apr 19 20:00:23 htpc mythbackend[1465]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
Apr 19 20:01:05 htpc mythbackend[1465]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
--
Apr 26 20:37:49 htpc mythbackend[1318]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
Apr 26 20:37:55 htpc mythbackend[1318]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 420 items in 5.8 = 0.75 match + 5.03 place
Apr 26 20:39:07 htpc mythbackend[1318]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-04-27T17:30:00,
:NEWSTART=2012-04-27T15:25:00,#012:OLDSTART=2012-04-27T14:30:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-04-27 15:25:00-0' for key
'PRIMARY'
Apr 26 20:40:17 htpc mythbackend[1318]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
Apr 26 20:41:18 htpc mythbackend[1318]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
--
Apr 27 06:07:11 htpc mythbackend[1460]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 472 items in 3.5 = 0.52 match + 2.94 place
Apr 27 06:08:15 htpc mythbackend[1460]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
Apr 27 06:09:10 htpc mythbackend[1460]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-04-27T16:25:00,
:NEWSTART=2012-04-27T15:25:00,#012:OLDSTART=2012-04-27T14:30:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-04-27 15:25:00-0' for key
'PRIMARY'
Apr 27 06:11:05 htpc mythbackend[1460]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
Apr 27 06:11:08 htpc mythbackend[1460]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 471 items in 3.4 = 0.49 match + 2.87 place
--
Apr 27 20:54:03 htpc mythbackend[1445]: N Expire autoexpire.cpp:263
(CalcParams) AutoExpire: CalcParams(): Max required Free Space: 3.0 GB
w/freq: 14 min
Apr 27 20:54:03 htpc mythbackend[1445]: N Expire autoexpire.cpp:640
(SendDeleteMessages) Expiring 962 MB for 1071 at 2012-04-05T10:04:00 =>
"Show Me Show Me":"Peas and Castles"
Apr 27 20:54:04 htpc mythbackend[1445]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-04-30T13:40:00,
:NEWSTART=2012-04-30T12:30:00,#012:OLDSTART=2012-04-30T10:30:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-04-30 12:30:00-0' for key
'PRIMARY'
Apr 27 20:54:10 htpc mythbackend[1445]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id 0.
Apr 27 20:54:13 htpc mythbackend[1445]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 418 items in 2.9 = 0.00 match + 2.94 place
--
Apr 27 21:00:01 htpc mythbackend[1445]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id 0.
Apr 27 21:00:04 htpc mythbackend[1445]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 416 items in 3.1 = 0.00 match + 3.05 place
Apr 27 21:00:42 htpc mythbackend[1445]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-01T14:15:00,
:NEWSTART=2012-05-01T10:00:00,#012:OLDSTART=2012-05-01T09:30:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-01 10:00:00-0' for key
'PRIMARY'
Apr 27 21:01:09 htpc mythbackend[1445]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-04-30T13:10:00,
:NEWSTART=2012-04-30T12:30:00,#012:OLDSTART=2012-04-30T10:30:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-04-30 12:30:00-0' for key
'PRIMARY'
Apr 27 21:02:24 htpc mythbackend[1445]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
Apr 27 21:02:28 htpc mythbackend[1445]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 416 items in 3.5 = 0.48 match + 3.00 place
--
Apr 27 21:06:06 htpc mythbackend[1445]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 416 items in 3.7 = 0.50 match + 3.16 place
Apr 27 21:07:46 htpc mythbackend[1445]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
Apr 27 21:08:40 htpc mythbackend[1445]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-01T13:30:00,
:NEWSTART=2012-05-01T10:00:00,#012:OLDSTART=2012-05-01T09:30:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-01 10:00:00-0' for key
'PRIMARY'
Apr 27 21:09:02 htpc mythbackend[1445]: N Expire autoexpire.cpp:263
(CalcParams) AutoExpire: CalcParams(): Max required Free Space: 3.0 GB
w/freq: 14 min
Apr 27 21:11:04 htpc mythbackend[1445]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
--
May 1 18:01:29 htpc mythbackend[1772]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 304 items in 4.3 = 1.09 match + 3.25 place
May 1 18:02:41 htpc mythbackend[1772]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
May 1 18:04:25 htpc mythbackend[1772]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-01T23:30:00,
:NEWSTART=2012-05-01T14:55:00,#012:OLDSTART=2012-05-01T14:15:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-01 14:55:00-0' for key
'PRIMARY'
May 1 18:05:27 htpc mythbackend[1772]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 1 18:05:31 htpc mythbackend[1772]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 353 items in 3.9 = 1.21 match + 2.73 place
--
May 1 18:09:32 htpc mythbackend[1772]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 1 18:09:40 htpc mythbackend[1772]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 402 items in 8.8 = 2.09 match + 6.68 place
May 1 18:09:55 htpc mythbackend[1772]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1706, :NEWEND=2012-05-05T15:40:00,
:NEWSTART=2012-05-05T13:15:00,#012:OLDSTART=2012-05-05T11:30:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1706-2012-05-05 13:15:00-0' for key
'PRIMARY'
May 1 18:09:58 htpc mythbackend[1772]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-01T23:30:00,
:NEWSTART=2012-05-01T14:55:00,#012:OLDSTART=2012-05-01T14:15:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-01 14:55:00-0' for key
'PRIMARY'
May 1 18:12:46 htpc mythbackend[1772]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
May 1 18:13:17 htpc mythbackend[1772]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
--
May 1 19:06:05 htpc mythbackend[1395]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 1 19:06:12 htpc mythbackend[1395]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 396 items in 6.6 = 0.88 match + 5.69 place
May 1 19:09:16 htpc mythbackend[1395]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-01T23:30:00,
:NEWSTART=2012-05-01T14:55:00,#012:OLDSTART=2012-05-01T14:15:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-01 14:55:00-0' for key
'PRIMARY'
May 1 19:10:04 htpc mythbackend[1395]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
May 1 19:10:42 htpc mythbackend[1395]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
--
May 1 19:19:20 htpc mythbackend[1395]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 396 items in 6.8 = 0.93 match + 5.82 place
May 1 19:20:15 htpc mythbackend[1395]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
May 1 19:22:08 htpc mythbackend[1395]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-01T23:30:00,
:NEWSTART=2012-05-01T14:55:00,#012:OLDSTART=2012-05-01T14:15:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-01 14:55:00-0' for key
'PRIMARY'
May 1 19:23:27 htpc mythbackend[1395]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 1 19:23:34 htpc mythbackend[1395]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 396 items in 6.1 = 0.90 match + 5.19 place
--
May 2 18:41:13 htpc mythbackend[1369]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 2 18:41:16 htpc mythbackend[1369]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 386 items in 3.5 = 0.67 match + 2.85 place
May 2 18:42:17 htpc mythbackend[1369]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-03T23:30:00,
:NEWSTART=2012-05-03T20:35:00,#012:OLDSTART=2012-05-03T18:10:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-03 20:35:00-0' for key
'PRIMARY'
May 2 18:43:14 htpc mythbackend[1369]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
May 2 18:46:05 htpc mythbackend[1369]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
--
May 3 07:21:09 htpc mythbackend[1323]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 3 07:21:15 htpc mythbackend[1323]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 376 items in 6.9 = 2.43 match + 4.49 place
May 3 07:21:40 htpc mythbackend[1323]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-03T23:30:00,
:NEWSTART=2012-05-03T20:35:00,#012:OLDSTART=2012-05-03T18:10:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-03 20:35:00-0' for key
'PRIMARY'
May 3 07:22:23 htpc mythbackend[1323]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
May 3 07:25:20 htpc mythbackend[1323]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
--
May 3 16:59:05 htpc mythbackend[1333]: E CoreContext programinfo.cpp:2278
(GetPlaybackURL) ProgramInfo(1704_20120413183200.mpg): GetPlaybackURL:
'1704_20120413183200.mpg' should be local, but it can not be found.
May 3 16:59:05 htpc mythbackend[1333]: E CoreContext mainserver.cpp:2582
(DoHandleDeleteRecording) ERROR when trying to delete file:
GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/htpc/1704_20120413183200.mpg.
File doesn't exist. Database metadata will not be removed.
May 3 16:59:07 htpc mythbackend[1333]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-03T22:00:00,
:NEWSTART=2012-05-03T20:35:00,#012:OLDSTART=2012-05-03T18:10:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-03 20:35:00-0' for key
'PRIMARY'
May 3 16:59:13 htpc mythbackend[1333]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id 0.
May 3 16:59:16 htpc mythbackend[1333]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 395 items in 2.4 = 0.00 match + 2.40 place
--
May 3 17:05:26 htpc mythbackend[1333]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 3 17:05:30 htpc mythbackend[1333]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 395 items in 3.3 = 0.57 match + 2.74 place
May 3 17:06:26 htpc mythbackend[1333]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-03T22:00:00,
:NEWSTART=2012-05-03T20:35:00,#012:OLDSTART=2012-05-03T18:10:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-03 20:35:00-0' for key
'PRIMARY'
May 3 17:06:37 htpc mythbackend[1333]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-04T17:45:00,
:NEWSTART=2012-05-04T16:50:00,#012:OLDSTART=2012-05-04T16:15:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-04 16:50:00-0' for key
'PRIMARY'
May 3 17:08:07 htpc mythbackend[1333]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
May 3 17:08:12 htpc mythbackend[1333]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
--
May 3 17:19:36 htpc mythbackend[1333]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 3 17:19:39 htpc mythbackend[1333]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 395 items in 3.6 = 0.60 match + 3.03 place
May 3 17:20:21 htpc mythbackend[1333]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-04T20:30:00,
:NEWSTART=2012-05-04T19:15:00,#012:OLDSTART=2012-05-04T18:35:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-04 19:15:00-0' for key
'PRIMARY'
May 3 17:23:20 htpc mythbackend[1333]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
May 3 17:25:38 htpc mythbackend[1333]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
--
May 3 18:30:03 htpc mythbackend[1427]: I CoreContext scheduler.cpp:634
(UpdateRecStatus) Updating status for "Tom Wrigglesworth's Open Letters"
on cardid 1 (Tuning => Recording)
May 3 18:30:03 htpc mythbackend[1427]: I TVRecEvent tv_rec.cpp:3953
(TuningNewRecorder) TVRec(1): rec->GetPathname():
'/media/tv2/recordings/1704_20120503183000.mpg'
May 3 18:30:04 htpc mythbackend[1427]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-03T22:00:00,
:NEWSTART=2012-05-03T20:35:00,#012:OLDSTART=2012-05-03T18:10:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-03 20:35:00-0' for key
'PRIMARY'
May 3 18:30:06 htpc mythbackend[1427]: N Expire autoexpire.cpp:263
(CalcParams) AutoExpire: CalcParams(): Max required Free Space: 3.0 GB
w/freq: 14 min
May 3 18:30:06 htpc mythbackend[1427]: N Expire autoexpire.cpp:640
(SendDeleteMessages) Expiring 356 MB for 1704 at 2012-04-10T18:31:00 =>
"Ed Reardon's Week"
--
May 4 18:15:27 htpc mythbackend[1360]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 4 18:15:30 htpc mythbackend[1360]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 390 items in 3.5 = 0.74 match + 2.74 place
May 4 18:17:59 htpc mythbackend[1360]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-06T22:45:00,
:NEWSTART=2012-05-06T21:15:00,#012:OLDSTART=2012-05-06T20:00:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-06 21:15:00-0' for key
'PRIMARY'
May 4 18:18:38 htpc mythbackend[1360]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
May 4 18:19:04 htpc mythbackend[1360]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
--
May 4 19:31:20 htpc mythbackend[1360]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 4 19:31:24 htpc mythbackend[1360]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 387 items in 3.6 = 0.64 match + 2.94 place
May 4 19:33:52 htpc mythbackend[1360]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-08T05:30:00,
:NEWSTART=2012-05-08T02:15:00,#012:OLDSTART=2012-05-08T00:15:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-08 02:15:00-0' for key
'PRIMARY'
May 4 19:34:25 htpc mythbackend[1360]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
May 4 19:34:52 htpc mythbackend[1360]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
--
May 4 19:44:03 htpc mythbackend[1360]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 387 items in 3.3 = 0.56 match + 2.74 place
May 4 19:44:28 htpc mythbackend[1360]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
May 4 19:46:22 htpc mythbackend[1360]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-08T03:30:00,
:NEWSTART=2012-05-08T02:15:00,#012:OLDSTART=2012-05-08T00:15:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-08 02:15:00-0' for key
'PRIMARY'
May 4 19:47:22 htpc mythbackend[1360]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 4 19:47:26 htpc mythbackend[1360]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 387 items in 3.5 = 0.61 match + 2.87 place
--
May 4 19:59:00 htpc mythbackend[1360]: I CoreContext scheduler.cpp:634
(UpdateRecStatus) Updating status for "Dirty Great Machines" on cardid 1
(Tuning => Recording)
May 4 19:59:00 htpc mythbackend[1360]: I TVRecEvent tv_rec.cpp:3953
(TuningNewRecorder) TVRec(1): rec->GetPathname():
'/media/tv2/recordings/1005_20120504195900.mpg'
May 4 19:59:20 htpc mythbackend[1360]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-08T03:30:00,
:NEWSTART=2012-05-08T02:15:00,#012:OLDSTART=2012-05-08T00:15:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-08 02:15:00-0' for key
'PRIMARY'
May 4 19:59:37 htpc mythbackend[1360]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
May 4 20:01:13 htpc mythbackend[1360]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
--
May 6 06:42:03 htpc mythbackend[1448]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 418 items in 3.9 = 0.55 match + 3.37 place
May 6 06:43:21 htpc mythbackend[1448]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
May 6 06:44:40 htpc mythbackend[1448]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-07T21:00:00,
:NEWSTART=2012-05-07T17:15:00,#012:OLDSTART=2012-05-07T17:00:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-07 17:15:00-0' for key
'PRIMARY'
May 6 06:46:05 htpc mythbackend[1448]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 6 06:46:09 htpc mythbackend[1448]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 416 items in 3.5 = 0.56 match + 2.96 place
--
May 8 13:49:42 htpc mythbackend[1412]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 8 13:49:45 htpc mythbackend[1412]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 413 items in 3.4 = 0.60 match + 2.77 place
May 8 13:50:39 htpc mythbackend[1412]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1705, :NEWEND=2012-05-12T17:30:00,
:NEWSTART=2012-05-12T17:00:00,#012:OLDSTART=2012-05-12T14:45:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1705-2012-05-12 17:00:00-0' for key
'PRIMARY'
May 8 13:53:12 htpc mythbackend[1412]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 8 13:53:15 htpc mythbackend[1412]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 413 items in 3.1 = 0.47 match + 2.59 place
--
May 8 17:53:07 htpc mythbackend[1412]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 8 17:53:11 htpc mythbackend[1412]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 417 items in 3.5 = 0.60 match + 2.86 place
May 8 17:54:06 htpc mythbackend[1412]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1081, :NEWEND=2012-05-09T13:50:00,
:NEWSTART=2012-05-09T13:00:00,#012:OLDSTART=2012-05-09T12:50:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1081-2012-05-09 13:00:00-0' for key
'PRIMARY'
May 8 17:55:51 htpc mythbackend[1412]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 8 17:55:54 htpc mythbackend[1412]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 417 items in 3.8 = 0.69 match + 3.12 place
--
May 11 14:41:08 htpc mythbackend[1457]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 11 14:41:11 htpc mythbackend[1457]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 479 items in 3.2 = 0.49 match + 2.68 place
May 11 14:41:44 htpc mythbackend[1457]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1013, :NEWEND=2012-05-16T06:20:00,
:NEWSTART=2012-05-16T05:50:00,#012:OLDSTART=2012-05-16T05:25:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1013-2012-05-16 05:50:00-0' for key
'PRIMARY'
May 11 14:43:05 htpc mythbackend[1457]: N Expire autoexpire.cpp:263
(CalcParams) AutoExpire: CalcParams(): Max required Free Space: 1.0 GB
w/freq: 15 min
May 11 14:45:40 htpc mythbackend[1457]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
--
May 12 01:07:15 htpc mythbackend[1394]: I Scheduler scheduler.cpp:2010
(HandleReschedule) Reschedule requested for id -1.
May 12 01:07:19 htpc mythbackend[1394]: I Scheduler scheduler.cpp:2068
(HandleReschedule) Scheduled 484 items in 4.0 = 1.25 match + 2.79 place
May 12 01:07:58 htpc mythbackend[1394]: E EIT mythdb.cpp:192 (DBError) DB
Error (change_program):#012Query was:#012UPDATE program SET starttime =
?, endtime = ? WHERE chanid = ? AND starttime =
?#012Bindings were:#012:CHANID=1013, :NEWEND=2012-05-16T06:15:00,
:NEWSTART=2012-05-16T05:50:00,#012:OLDSTART=2012-05-16T05:25:00#012Driver
error was [2/1062]:#012QMYSQL3: Unable to execute statement#012Database
error was:#012Duplicate entry '1013-2012-05-16 05:50:00-0' for key
'PRIMARY'
May 12 01:08:09 htpc mythbackend[1394]: I HouseKeeping housekeeper.cpp:225
(RunHouseKeeping) Running housekeeping thread
May 12 01:11:11 htpc mythbackend[1394]: N Expire autoexpire.cpp:263
(CalcParams) AutoExpire: CalcParams(): Max required Free Space: 1.0 GB
w/freq: 15 min
I also use a Nova TD 500 but I don't think it's related to your failed
recording. To me it seems that myth isn't handling an EIT program
reschedule properly. The vast majority occur on chan id 1081 (BBC
Parliament), some on Radio 5 Live and a single one on C4+1. I never
watch/listen/record off Parliament/R5 but I imagine they are susceptible
to rescheduling (all those MP's droning on and on...)
I don't know if this is new to 0.25 or was in 0.24 as well. It seems minor
but maybe someone familiar with the EIT update code/algorithm could
comment.
More information about the mythtv-users
mailing list