Login | Register For Free | Help
Search for: (Advanced)

Mailing List Archive: MythTV: Users

Cancelled recordings in 0.25

 

 

MythTV users RSS feed   Index | Next | Previous | View Threaded


bwobbones at gmail

Apr 21, 2012, 9:31 PM

Post #1 of 2 (273 views)
Permalink
Cancelled recordings in 0.25

Hi,

Since upgrading to 0.25 a couple of weeks ago (on Mythbuntu 11.10) some of
my recordings are not working. In 'Upcoming recordings' I can see that the
recordings have been successfully set and will record but sometimes the
recording doesn't happen (about twice a week across all of my recordings).

I happened to notice the other day that while we were watching TV and the
"Myth wants to record, what do you want to do?" box came up. I left it at
it's default "Let it record and change channels" and the channel didn't
change. The recording also didn't appear in my recordings list. I
selected to manually record (pressing 'r') and then the recording was
there. I looked into the logs (see below - it's The Biggest Loser that's
failing) and can see that the recording was cancelled, but not why. Could
it be that there are two programmes recording at the same time and there's
some kind of race?

It's really frustrating that I can't trust the recording mechanism, it's
our highest use feature and my WAF is dropping significantly. Any ideas?

[mythbackend.log]
Apr 4 18:49:08 mythtv-desktop mythbackend[5654]: I ProcessRequest
recorderbase.cpp:386 (GetKeyframePositions)
RecBase(8:/dev/dvb/adapter0/frontend0):
GetKeyframePositions(27882,9223372036854775807,#15) out of 2339
Apr 4 18:52:09 mythtv-desktop mythbackend[5654]: I HouseKeeping
housekeeper.cpp:225 (RunHouseKeeping) Running housekeeping thread
Apr 4 18:54:24 mythtv-desktop mythbackend[5654]: I Scheduler
scheduler.cpp:2010 (HandleReschedule) Reschedule requested for id 0.
Apr 4 18:54:24 mythtv-desktop mythbackend[5654]: I Scheduler
scheduler.cpp:2068 (HandleReschedule) Scheduled 18 items in 0.8 = 0.02
match + 0.76 place
Apr 4 18:54:29 mythtv-desktop mythbackend[5654]: I TVRecEvent
tv_rec.cpp:1518 (HandlePendingRecordings) TVRec(10): ASK_RECORDING 10 29 0 0
Apr 4 18:54:30 mythtv-desktop mythbackend[5654]: I TVRecEvent
tv_rec.cpp:1518 (HandlePendingRecordings) TVRec(8): ASK_RECORDING 8 29 0 0
Apr 4 18:54:55 mythtv-desktop mythbackend[5654]: N ProcessRequest
mainserver.cpp:3825 (HandleRecorderQuery) Received: CANCEL_NEXT_RECORDING 0
Apr 4 18:54:55 mythtv-desktop mythbackend[5654]: I ProcessRequest
recorderbase.cpp:386 (GetKeyframePositions)
RecBase(8:/dev/dvb/adapter0/frontend0):
GetKeyframePositions(28062,9223372036854775807,#725) out of 3064
Apr 4 18:55:00 mythtv-desktop mythbackend[5654]: I TVRecEvent
tv_rec.cpp:1014 (HandleStateChange) TVRec(10): Changing from None to
RecordingOnly
Apr 4 18:55:00 mythtv-desktop mythbackend[5654]: I TVRecEvent
mythdbcon.cpp:395 (PurgeIdleConnections) New DB connection, total: 12
Apr 4 18:55:00 mythtv-desktop mythbackend[5654]: I TVRecEvent
tv_rec.cpp:3456 (TuningCheckForHWChange) TVRec(10): HW Tuner: 10->10
Apr 4 18:55:00 mythtv-desktop mythbackend[5654]: N Scheduler
autoexpire.cpp:263 (CalcParams) AutoExpire: CalcParams(): Max required Free
Space: 3.0 GB w/freq: 7 min
Apr 4 18:55:00 mythtv-desktop mythbackend[5654]: I Scheduler
scheduler.cpp:2459 (HandleRecordingStatusChange) Tuning recording: "ABC
News": channel 1002 on cardid 10, sourceid 1
Apr 4 18:55:00 mythtv-desktop mythbackend[5654]: N Scheduler
autoexpire.cpp:263 (CalcParams) AutoExpire: CalcParams(): Max required Free
Space: 3.0 GB w/freq: 7 min
Apr 4 18:55:00 mythtv-desktop mythbackend[5654]: I Scheduler
scheduler.cpp:2459 (HandleRecordingStatusChange) Started recording: "The
Biggest Loser": channel 1010 on cardid 8, sourceid 1
Apr 4 18:55:00 mythtv-desktop mythbackend[5654]: I CoreContext
scheduler.cpp:634 (UpdateRecStatus) Updating status for "ABC News" on
cardid 10 (Tuning => Recording)
Apr 4 18:55:01 mythtv-desktop mythbackend[5654]: I TVRecEvent
tv_rec.cpp:3950 (TuningNewRecorder) TVRec(10): rec->GetPathname():
'/opt/data/video/1002_20120404185500.mpg'
Apr 4 18:57:15 mythtv-desktop mythbackend[5654]: I HouseKeeping
housekeeper.cpp:225 (RunHouseKeeping) Running housekeeping thread
Apr 4 18:59:10 mythtv-desktop mythbackend[5654]: I ProcessRequest
recorderbase.cpp:386 (GetKeyframePositions)
RecBase(8:/dev/dvb/adapter0/frontend0):
GetKeyframePositions(36756,9223372036854775807,#531) out of 3595
Apr 4 19:01:49 mythtv-desktop mythbackend[5654]: I ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) MainServer::ANN Playback
Apr 4 19:01:49 mythtv-desktop mythbackend[5654]: I ProcessRequest
mainserver.cpp:1362 (HandleAnnounce) adding: mythtv-desktop as a client
(events: 0)
Apr 4 19:01:49 mythtv-desktop mythbackend[5654]: I ProcessRequest
mainserver.cpp:1475 (HandleAnnounce) MainServer::HandleAnnounce FileTransfer
Apr 4 19:01:49 mythtv-desktop mythbackend[5654]: I ProcessRequest
mainserver.cpp:1477 (HandleAnnounce) adding: mythtv-desktop as a remote
file transfer
Apr 4 19:01:49 mythtv-desktop mythbackend[5654]: W ProcessRequest
mainserver.cpp:5801 (connectionClosed) MainServer: Unknown socket closing
MythSocket(0xffffffffacd5ca88)
Apr 4 19:01:49 mythtv-desktop mythbackend[5654]: E ProcessRequest
mythsocket.cpp:358 (writeStringList) MythSocket(ffffffffacd5ca88:-1):
writeStringList: Error, socket went unconnected.#012#011#011#011We wrote 0
of 10 bytes with 1 errors#012#011#011#011starts with: 2 ok
Apr 4 19:01:53 mythtv-desktop mythbackend[5654]: I ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) MainServer::ANN Playback
Apr 4 19:01:53 mythtv-desktop mythbackend[5654]: I ProcessRequest
mainserver.cpp:1362 (HandleAnnounce) adding: mythtv-desktop as a client
(events: 0)
Apr 4 19:01:53 mythtv-desktop mythbackend[5654]: I ProcessRequest
mainserver.cpp:1475 (HandleAnnounce) MainServer::HandleAnnounce FileTransfer
Apr 4 19:01:53 mythtv-desktop mythbackend[5654]: I ProcessRequest
mainserver.cpp:1477 (HandleAnnounce) adding: mythtv-desktop as a remote
file transfer
Apr 4 19:01:53 mythtv-desktop mythbackend[5654]: E ProcessRequest
mainserver.cpp:6068 (LocalFilePath) ERROR: LocalFilePath unable to find
local path for 'frogman_blue_one.png'.
Apr 4 19:01:53 mythtv-desktop mythbackend[5654]: E ProcessRequest
mainserver.cpp:1547 (HandleAnnounce) Empty filename, cowardly aborting!
Apr 4 19:01:53 mythtv-desktop mythbackend[5654]: W Socket
mainserver.cpp:5801 (connectionClosed) MainServer: Unknown socket closing
MythSocket(0xffffffffacd07280)
Apr 4 19:01:54 mythtv-desktop mythbackend[5654]: I ProcessRequest
mainserver.cpp:1360 (HandleAnnounce) MainServer::ANN Playback
Apr 4 19:01:54 mythtv-desktop mythbackend[5654]: I ProcessRequest
mainserver.cpp:1362 (HandleAnnounce) adding: mythtv-desktop as a client
(events: 0)
Apr 4 19:01:54 mythtv-desktop mythbackend[5654]: I ProcessRequest
mainserver.cpp:1475 (HandleAnnounce) MainServer::HandleAnnounce FileTransfer
Apr 4 19:01:54 mythtv-desktop mythbackend[5654]: I ProcessRequest
mainserver.cpp:1477 (HandleAnnounce) adding: mythtv-desktop as a remote
file transfer
Apr 4 19:01:54 mythtv-desktop mythbackend[5654]: E ProcessRequest
mainserver.cpp:6068 (LocalFilePath) ERROR: LocalFilePath unable to find
local path for 'frogman_blue_one.png'.
Apr 4 19:01:54 mythtv-desktop mythbackend[5654]: E ProcessRequest
mainserver.cpp:1547 (HandleAnnounce) Empty filename, cowardly aborting!
Apr 4 19:01:54 mythtv-desktop mythbackend[5654]: W Socket
mainserver.cpp:5801 (connectionClosed) MainServer: Unknown socket closing
MythSocket(0xffffffffacd5bd28)

[mythfrontend.log]
Apr 4 18:30:29 mythtv-desktop mythfrontend[1984]: I CoreContext
mythrender_vdpau.cpp:587 (CheckOutputSurfaces) VDPAU: Added 2 output
surfaces (total 4, max 4)
Apr 4 18:30:29 mythtv-desktop mythfrontend[1984]: N CoreContext
mythplayer.cpp:2079 (PrebufferEnoughFrames) Player(q): Waited 103ms for
video buffers ADAAAADLAAAAdA
Apr 4 18:30:29 mythtv-desktop mythfrontend[1984]: N CoreContext
mythplayer.cpp:2079 (PrebufferEnoughFrames) Player(q): Waited 206ms for
video buffers ADAAAADLAAAAdA
Apr 4 18:30:29 mythtv-desktop mythfrontend[1984]: N CoreContext
mythplayer.cpp:2079 (PrebufferEnoughFrames) Player(q): Waited 308ms for
video buffers ADAAAADLAAAAdA
Apr 4 18:30:29 mythtv-desktop mythfrontend[1984]: N CoreContext
mythplayer.cpp:2079 (PrebufferEnoughFrames) Player(q): Waited 411ms for
video buffers ADAAAADLAAAAdA
Apr 4 18:30:29 mythtv-desktop mythfrontend[1984]: N CoreContext
mythplayer.cpp:2079 (PrebufferEnoughFrames) Player(q): Waited 513ms for
video buffers ADAAAADLAAAAdA
Apr 4 18:32:22 mythtv-desktop mythfrontend[1984]: I CoreContext
weatherSource.cpp:424 (startUpdate) Starting update of yrno-XML
Apr 4 18:32:22 mythtv-desktop mythfrontend[1984]: I CoreContext
weatherSource.cpp:424 (startUpdate) Starting update of wunderground
Apr 4 18:47:22 mythtv-desktop mythfrontend[1984]: I CoreContext
weatherSource.cpp:424 (startUpdate) Starting update of yrno-XML
Apr 4 18:47:22 mythtv-desktop mythfrontend[1984]: I CoreContext
weatherSource.cpp:424 (startUpdate) Starting update of wunderground
Apr 4 18:54:30 mythtv-desktop mythfrontend[1984]: I CoreContext
tv_play.cpp:8787 (customEvent) TV: ASK_RECORDING 10 29 0 0 hasrec: 0
haslater: 0
Apr 4 18:54:30 mythtv-desktop mythfrontend[1984]: I CoreContext
tv_play.cpp:8787 (customEvent) TV: ASK_RECORDING 10 29 0 0 hasrec: 0
haslater: 0
Apr 4 18:54:30 mythtv-desktop mythfrontend[1984]: I CoreContext
tv_play.cpp:8787 (customEvent) TV: ASK_RECORDING 8 29 0 0 hasrec: 0
haslater: 0
Apr 4 18:54:30 mythtv-desktop mythfrontend[1984]: I CoreContext
tv_play.cpp:8787 (customEvent) TV: ASK_RECORDING 8 29 0 0 hasrec: 0
haslater: 0
Apr 4 19:01:49 mythtv-desktop mythfrontend[1984]: I CoreContext
mythcorecontext.cpp:1177 (CheckProtoVersion) Using protocol version 72
Apr 4 19:01:53 mythfrontend[1984]: last message repeated 3 times
Apr 4 19:01:53 mythtv-desktop mythfrontend[1984]: E CoreContext
remotefile.cpp:172 (openSocket) RemoteFile::openSocket(file data socket):
Failed to open socket, error was filetransfer_filename_empty
Apr 4 19:01:53 mythtv-desktop mythfrontend[1984]: E CoreContext
mythuihelper.cpp:1349 (LoadScaleImage) MythUIHelper: LoadScaleImage(myth://
ChannelIcon [at] 192:6543/home/myth/.shepherd/icons/frogman_blue_one.png)
failed to load remote image
Apr 4 19:01:53 mythtv-desktop mythfrontend[1984]: E CoreContext
mythuihelper.cpp:1398 (LoadScaleImage) MythUIHelper: LoadScaleImage(myth://
ChannelIcon [at] 192:6543/home/myth/.shepherd/icons/frogman_blue_one.png)
invalid image dimensions
Apr 4 19:01:54 mythtv-desktop mythfrontend[1984]: I CoreContext
mythcorecontext.cpp:1177 (CheckProtoVersion) Using protocol version 72
Apr 4 19:01:54 mythtv-desktop mythfrontend[1984]: I CoreContext
mythcorecontext.cpp:1177 (CheckProtoVersion) Using protocol version 72

Greg


stichnot at gmail

Apr 23, 2012, 1:10 PM

Post #2 of 2 (238 views)
Permalink
Re: Cancelled recordings in 0.25 [In reply to]

On Sat, Apr 21, 2012 at 9:31 PM, Greg Lucas-Smith <bwobbones [at] gmail> wrote:
>   I happened to notice the other day that while we were watching TV and the
> "Myth wants to record, what do you want to do?" box came up.  I left it at
> it's default "Let it record and change channels" and the channel didn't
> change.  The recording also didn't appear in my recordings list.  I selected
> to manually record (pressing 'r') and then the recording was there.  I
> looked into the logs (see below - it's The Biggest Loser that's failing) and
> can see that the recording was cancelled, but not why.  Could it be that
> there are two programmes recording at the same time and there's some kind of
> race?

There appears to be a mythbackend deadlock associated with that "Myth
wants to record" popup during Live TV. Hopefully, that will turn out
to be the source of the recording failures you're seeing.

http://code.mythtv.org/trac/ticket/10647

Jim
_______________________________________________
mythtv-users mailing list
mythtv-users [at] mythtv
http://www.mythtv.org/mailman/listinfo/mythtv-users

MythTV users RSS feed   Index | Next | Previous | View Threaded
 
 


Interested in having your list archived? Contact Gossamer Threads
 
  Web Applications & Managed Hosting Powered by Gossamer Threads Inc.