[mythtv-commits] Ticket #10852: Scheduled recording on same channel as Live TV fails to record

MythTV noreply at mythtv.org
Sat Jun 23 22:48:47 UTC 2012 

#10852: Scheduled recording on same channel as Live TV fails to record
------------------------------------+--------------------------------------
 Reporter:  Josh Triplett <josh@…>  |           Type:  Bug Report - General
   Status:  new                     |       Priority:  minor
Milestone:  unknown                 |      Component:  MythTV - General
  Version:  0.25.1                  |       Severity:  medium
 Keywords:                          |  Ticket locked:  0
------------------------------------+--------------------------------------
 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)
 }}}

-- 
Ticket URL: <http://code.mythtv.org/trac/ticket/10852>
MythTV <http://code.mythtv.org/trac>
MythTV Media Center

More information about the mythtv-commits mailing list