Opened 9 years ago

Closed 9 years ago

#10852 closed Bug Report - General (Duplicate)

Scheduled recording on same channel as Live TV fails to record

Reported by: Josh Triplett <josh@…> Owned by:
Priority: minor Milestone: unknown
Component: MythTV - General Version: 0.25.1
Severity: medium Keywords:
Cc: Ticket locked: no

Description

On our MythTV 0.25.1 setup, we had a recording scheduled, and had left LiveTV watching that channel as well. Afterward, we found that the recording did not occur. The logs from mythbackend suggest a database error with a duplicate key, perhaps due to a conflict between the LiveTV and scheduled recording of the same show:

2012-06-22 21:50:26.745348 I [20679/20698] HouseKeeping housekeeper.cpp:225 (RunHouseKeeping) - Running housekeeping thread
2012-06-22 21:55:28.747339 I [20679/20698] HouseKeeping housekeeper.cpp:225 (RunHouseKeeping) - Running housekeeping thread
2012-06-22 21:59:30.840654 I [20679/20690] TVRecEvent tv_rec.cpp:1521 (HandlePendingRecordings) - TVRec(5): ASK_RECORDING 5 28 0 0
2012-06-22 21:59:59.267710 N [20679/20697] Scheduler autoexpire.cpp:263 (CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 2.0 GB w/freq: 15 min
2012-06-22 21:59:59.285787 I [20679/20697] Scheduler scheduler.cpp:2460 (HandleRecordingStatusChange) - Started recording: "Common Law":"Performance Anxiety": channel 2050 on cardid 5, sourceid 2
2012-06-22 21:59:59.539678 I [20679/20690] TVRecEvent tv_rec.cpp:1014 (HandleStateChange) - TVRec(5): Changing from WatchingLiveTV to None
2012-06-22 22:00:00.236618 E [20679/29261] DeviceReadBuffer DeviceReadBuffer.cpp:460 (Poll) - DevRdB(/dev/video0): poll error
2012-06-22 22:00:00.252230 E [20679/29209] RecThread mpegrecorder.cpp:1010 (run) - MPEGRec(/dev/video0): Device error detected
2012-06-22 22:00:02.803605 E [20679/29302] DeviceReadBuffer DeviceReadBuffer.cpp:460 (Poll) - DevRdB(/dev/video0): poll error
2012-06-22 22:00:03.306276 I [20679/29209] RecThread mythdbcon.cpp:395 (PurgeIdleConnections) - New DB connection, total: 15
2012-06-22 22:00:04.295687 I [20679] ProcessRequest mainserver.cpp:1360 (HandleAnnounce) - MainServer::ANN Playback
2012-06-22 22:00:04.295699 I [20679] ProcessRequest mainserver.cpp:1362 (HandleAnnounce) - adding: mythfe3 as a client (events: 0)
2012-06-22 22:00:04.297899 I [20679/20692] TVRecEvent tv_rec.cpp:1014 (HandleStateChange) - TVRec(6): Changing from None to WatchingLiveTV
2012-06-22 22:00:04.313785 I [20679/20692] TVRecEvent mythdbcon.cpp:395 (PurgeIdleConnections) - New DB connection, total: 14
2012-06-22 22:00:04.331717 I [20679/20692] TVRecEvent tv_rec.cpp:3459 (TuningCheckForHWChange) - TVRec(6): HW Tuner: 6->6
2012-06-22 22:00:04.416519 I [20679/20692] TVRecEvent v4lchannel.cpp:661 (SetInputAndFormat) - V4LChannel(/dev/video2): SetInputAndFormat(7, NTSC) (v4l v2) input_switch: 0 mode_switch: 0
2012-06-22 22:00:04.520681 N [20679/20679] CoreContext autoexpire.cpp:263 (CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 2.0 GB w/freq: 15 min
2012-06-22 22:00:05.568611 N [20679/20679] CoreContext autoexpire.cpp:263 (CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 2.0 GB w/freq: 15 min
2012-06-22 22:00:05.912278 I [20679] ProcessRequest mainserver.cpp:1360 (HandleAnnounce) - MainServer::ANN Playback
2012-06-22 22:00:05.912289 I [20679] ProcessRequest mainserver.cpp:1362 (HandleAnnounce) - adding: mythfe3 as a client (events: 0)
2012-06-22 22:00:05.915575 I [20679] ProcessRequest mainserver.cpp:1475 (HandleAnnounce) - MainServer::HandleAnnounce FileTransfer
2012-06-22 22:00:05.915585 I [20679] ProcessRequest mainserver.cpp:1477 (HandleAnnounce) - adding: mythfe3 as a remote file transfer
2012-06-22 22:00:06.788900 I [20679/20709] Socket mythdbcon.cpp:395 (PurgeIdleConnections) - New DB connection, total: 15
2012-06-22 22:00:08.588839 I [20679/29301] ProcessRequest recorderbase.cpp:386 (GetKeyframePositions) - RecBase(6:/dev/video2): GetKeyframePositions(31,9223372036854775807,#1) out of 3
2012-06-22 22:00:30.749291 I [20679/20698] HouseKeeping housekeeper.cpp:225 (RunHouseKeeping) - Running housekeeping thread
2012-06-22 22:02:20.571523 N [20679/20699] Expire autoexpire.cpp:640 (SendDeleteMessages) - Expiring 0 MB for 2050 at 2012-06-22T22:00:04 => "Common Law":"Performance Anxiety"
2012-06-22 22:03:20.570659 N [20679/20699] Expire autoexpire.cpp:263 (CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 2.0 GB w/freq: 15 min
2012-06-22 22:03:20.573219 N [20679/20699] Expire autoexpire.cpp:640 (SendDeleteMessages) - Expiring 443 MB for 2050 at 2012-06-21T21:46:25 => "Burn Notice":"Mixed Messages"
2012-06-22 22:04:50.234078 I [20679] ProcessRequest mainserver.cpp:1360 (HandleAnnounce) - MainServer::ANN Playback
2012-06-22 22:04:50.234088 I [20679] ProcessRequest mainserver.cpp:1362 (HandleAnnounce) - adding: mythfe4 as a client (events: 0)
2012-06-22 22:04:50.239647 I [20679] ProcessRequest mainserver.cpp:1475 (HandleAnnounce) - MainServer::HandleAnnounce FileTransfer
2012-06-22 22:04:50.239654 I [20679] ProcessRequest mainserver.cpp:1477 (HandleAnnounce) - adding: mythfe4 as a remote file transfer
2012-06-22 22:05:35.751128 I [20679/20698] HouseKeeping housekeeper.cpp:225 (RunHouseKeeping) - Running housekeeping thread
2012-06-22 22:06:42.573310 E [20679/29310] RecThread mythdb.cpp:192 (DBError) - DB Error (Resolution insert):
Query was:
INSERT INTO recordedmarkup    (chanid, starttime, mark, type, data)    VALUES ( ?, ?, ?, ?, ?);
Bindings were:
:CHANID=2050, :DATA=720, :MARK=11865, :STARTTIME=2012-06-22T22:00:05, :TYPE=30
Driver error was [2/1062]:
QMYSQL3: Unable to execute statement
Database error was:
Duplicate entry '2050-2012-06-22 22:00:05-30-11865' for key 'PRIMARY'

2012-06-22 22:06:42.573629 E [20679/29310] RecThread mythdb.cpp:192 (DBError) - DB Error (Resolution insert):
Query was:
INSERT INTO recordedmarkup    (chanid, starttime, mark, type, data)    VALUES ( ?, ?, ?, ?, ?);
Bindings were:
:CHANID=2050, :DATA=480, :MARK=11865, :STARTTIME=2012-06-22T22:00:05, :TYPE=31
Driver error was [2/1062]:
QMYSQL3: Unable to execute statement
Database error was:
Duplicate entry '2050-2012-06-22 22:00:05-31-11865' for key 'PRIMARY'

2012-06-22 22:06:42.574009 E [20679/29310] RecThread mythdb.cpp:192 (DBError) - DB Error (Frame rate insert):
Query was:
INSERT INTO recordedmarkup    (chanid, starttime, mark, type, data)    VALUES ( ?, ?, ?, ?, ?);
Bindings were:
:CHANID=2050, :DATA=29970, :MARK=11865, :STARTTIME=2012-06-22T22:00:05, :TYPE=32
Driver error was [2/1062]:
QMYSQL3: Unable to execute statement
Database error was:
Duplicate entry '2050-2012-06-22 22:00:05-32-11865' for key 'PRIMARY'

2012-06-22 22:10:40.753043 I [20679/20698] HouseKeeping housekeeper.cpp:225 (RunHouseKeeping) - Running housekeeping thread
2012-06-22 22:15:45.754944 I [20679/20698] HouseKeeping housekeeper.cpp:225 (RunHouseKeeping) - Running housekeeping thread
2012-06-22 22:17:46.120568 I [20679/20692] TVRecEvent tv_rec.cpp:1014 (HandleStateChange) - TVRec(6): Changing from WatchingLiveTV to None
2012-06-22 22:17:46.717677 E [20679/29311] DeviceReadBuffer DeviceReadBuffer.cpp:460 (Poll) - DevRdB(/dev/video2): poll error
2012-06-22 22:17:46.717742 E [20679/29310] RecThread mpegrecorder.cpp:1010 (run) - MPEGRec(/dev/video2): Device error detected
2012-06-22 22:17:49.291491 E [20679/29329] DeviceReadBuffer DeviceReadBuffer.cpp:460 (Poll) - DevRdB(/dev/video2): poll error
2012-06-22 22:17:53.451527 E [20679/29266] ProcessRequest programinfo.cpp:2278 (GetPlaybackURL) - ProgramInfo(1008_20090406210000.mpg): GetPlaybackURL: '1008_20090406210000.mpg' should be local, but it can not be found.
2012-06-22 22:18:09.955803 I [20679] ProcessRequest mainserver.cpp:1360 (HandleAnnounce) - MainServer::ANN Playback
2012-06-22 22:18:09.955815 I [20679] ProcessRequest mainserver.cpp:1362 (HandleAnnounce) - adding: mythfe3 as a client (events: 0)
2012-06-22 22:18:10.195460 I [20679/20690] TVRecEvent tv_rec.cpp:1014 (HandleStateChange) - TVRec(5): Changing from None to WatchingLiveTV
2012-06-22 22:18:10.198419 I [20679/20690] TVRecEvent tv_rec.cpp:3459 (TuningCheckForHWChange) - TVRec(5): HW Tuner: 5->5
2012-06-22 22:18:10.273114 I [20679/20690] TVRecEvent v4lchannel.cpp:661 (SetInputAndFormat) - V4LChannel(/dev/video0): SetInputAndFormat(6, NTSC) (v4l v2) input_switch: 0 mode_switch: 0
2012-06-22 22:18:10.309702 N [20679/20679] CoreContext autoexpire.cpp:263 (CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 2.0 GB w/freq: 15 min
2012-06-22 22:18:10.663359 N [20679/20679] CoreContext autoexpire.cpp:263 (CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 2.0 GB w/freq: 15 min
2012-06-22 22:18:10.735306 E [20679/20690] TVRecEvent recordinginfo.cpp:966 (InsertProgram) - RecordingInfo::InsertProgram(ProgramInfo(2050_20120622221810.mpg): channame(USA Network (Pacific)) startts(Fri Jun 22 22:00:00 2012) endts(Fri Jun 22 23:00:00 2012)
             recstartts(Fri Jun 22 22:18:10 2012) recendts(Fri Jun 22 23:00:00 2012)
             title(Common Law)): recording already exists...
2012-06-22 22:18:10.956248 I [20679] ProcessRequest mainserver.cpp:1360 (HandleAnnounce) - MainServer::ANN Playback
2012-06-22 22:18:10.956259 I [20679] ProcessRequest mainserver.cpp:1362 (HandleAnnounce) - adding: mythfe3 as a client (events: 0)
2012-06-22 22:18:10.959562 I [20679] ProcessRequest mainserver.cpp:1475 (HandleAnnounce) - MainServer::HandleAnnounce FileTransfer
2012-06-22 22:18:10.959569 I [20679] ProcessRequest mainserver.cpp:1477 (HandleAnnounce) - adding: mythfe3 as a remote file transfer
2012-06-22 22:18:12.952543 I [20679] ProcessRequest mainserver.cpp:1360 (HandleAnnounce) - MainServer::ANN Playback
2012-06-22 22:18:12.952560 I [20679] ProcessRequest mainserver.cpp:1362 (HandleAnnounce) - adding: mythfe3 as a client (events: 0)
2012-06-22 22:18:12.956549 I [20679] ProcessRequest mainserver.cpp:1475 (HandleAnnounce) - MainServer::HandleAnnounce FileTransfer
2012-06-22 22:18:12.956565 I [20679] ProcessRequest mainserver.cpp:1477 (HandleAnnounce) - adding: mythfe3 as a remote file transfer
2012-06-22 22:18:13.614044 I [20679/29339] ProcessRequest recorderbase.cpp:386 (GetKeyframePositions) - RecBase(5:/dev/video0): GetKeyframePositions(31,9223372036854775807,#1) out of 3
2012-06-22 22:18:13.788511 I [20679] ProcessRequest recorderbase.cpp:386 (GetKeyframePositions) - RecBase(5:/dev/video0): GetKeyframePositions(31,9223372036854775807,#2) out of 4
2012-06-22 22:19:00.963045 I [20679/20690] TVRecEvent tv_rec.cpp:1014 (HandleStateChange) - TVRec(5): Changing from WatchingLiveTV to None
2012-06-22 22:19:01.345266 E [20679/29340] DeviceReadBuffer DeviceReadBuffer.cpp:460 (Poll) - DevRdB(/dev/video0): poll error
2012-06-22 22:19:01.345311 E [20679/29338] RecThread mpegrecorder.cpp:1010 (run) - MPEGRec(/dev/video0): Device error detected
2012-06-22 22:19:03.915440 E [20679/29344] DeviceReadBuffer DeviceReadBuffer.cpp:460 (Poll) - DevRdB(/dev/video0): poll error
2012-06-22 22:19:09.835981 E [20679/29266] ProcessRequest programinfo.cpp:2278 (GetPlaybackURL) - ProgramInfo(1008_20090406210000.mpg): GetPlaybackURL: '1008_20090406210000.mpg' should be local, but it can not be found.
2012-06-22 22:19:19.664018 N [20679/20699] Expire autoexpire.cpp:263 (CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
2012-06-22 22:19:38.112755 E [20679/29266] ProcessRequest programinfo.cpp:2278 (GetPlaybackURL) - ProgramInfo(1008_20090406210000.mpg): GetPlaybackURL: '1008_20090406210000.mpg' should be local, but it can not be found.
2012-06-22 22:20:19.667777 N [20679/20699] Expire autoexpire.cpp:640 (SendDeleteMessages) - Expiring 0 MB for 2050 at 2012-06-22T22:18:10 => "Common Law":"Performance Anxiety"
2012-06-22 22:20:19.667982 N [20679/20699] Expire autoexpire.cpp:640 (SendDeleteMessages) - Expiring 30 MB for 2050 at 2012-06-22T22:18:11 => "Common Law":"Performance Anxiety"
2012-06-22 22:20:33.020409 I [20679] ProcessRequest mainserver.cpp:1360 (HandleAnnounce) - MainServer::ANN Playback
2012-06-22 22:20:33.020420 I [20679] ProcessRequest mainserver.cpp:1362 (HandleAnnounce) - adding: mythfe3 as a client (events: 0)
2012-06-22 22:20:33.023727 I [20679] ProcessRequest mainserver.cpp:1475 (HandleAnnounce) - MainServer::HandleAnnounce FileTransfer
2012-06-22 22:20:33.023734 I [20679] ProcessRequest mainserver.cpp:1477 (HandleAnnounce) - adding: mythfe3 as a remote file transfer
2012-06-22 22:20:50.756986 I [20679/20698] HouseKeeping housekeeper.cpp:225 (RunHouseKeeping) - Running housekeeping thread
2012-06-22 22:22:48.513826 I [20679/20706] PreviewGeneratorQueue mythdbcon.cpp:395 (PurgeIdleConnections) - New DB connection, total: 14
2012-06-22 22:22:52.696826 I [20679] ProcessRequest mainserver.cpp:1360 (HandleAnnounce) - MainServer::ANN Monitor
2012-06-22 22:22:52.696842 I [20679] ProcessRequest mainserver.cpp:1362 (HandleAnnounce) - adding: myth as a client (events: 0)
2012-06-22 22:22:52.697695 I [20679] ProcessRequest mainserver.cpp:1360 (HandleAnnounce) - MainServer::ANN Monitor
2012-06-22 22:22:52.697711 I [20679] ProcessRequest mainserver.cpp:1362 (HandleAnnounce) - adding: myth as a client (events: 1)

Change History (3)

comment:1 Changed 9 years ago by Steven Adeff <adeffs.mythtv@…>

did you check your LiveTV recordings group? There is a bug where these recordings get put in the LiveTV group, and if you exit from LiveTV the recording will stop, also this is regardless of channel being recorded.

see ticket 10726 http://code.mythtv.org/trac/ticket/10726

comment:2 Changed 9 years ago by Josh Triplett <josh@…>

Yes, that ticket precisely describes the behavior I observed. I had searched for an existing ticket before submitting this one, but didn't find that one.

Please feel free to mark this as a duplicate of #10726.

comment:3 Changed 9 years ago by Kenni Lund [kenni a kelu dot dk]

Resolution: Duplicate
Status: newclosed

Duplicate of #10726.

Note: See TracTickets for help on using tickets.