[mythtv-users] Ever since reboot, recordings are not saved

Fri Mar 27 21:21:29 UTC 2015

Hoi David,

Friday, March 27, 2015, 10:01:04 PM, you wrote:

> My MythTV box has been working for quite some time (currently running
> Ubuntu 14.04, MythTV 2:0.27.0+fixes.20140324.8, PVR-350 capture card,
> SchedulesDirect, Comcast Digital)  The fact that I'm still using a
> PVR-350 says something on it's own.  A few months ago I had an OS hard
> drive failure and had to rebuild it, but it's been pretty reliable
> besides that.

> Last week, I brought down the server to replace a noisy fan.  Ever since
> then, no recordings have been saved.  They're scheduled but there's no
> new recordings on the hard drive. 

> The logs look like it's recording things:
> Mar 26 09:10:02 stalker mythbackend: mythbackend[1637]: I ProcessRequest
> mainserver.cpp:1420 (HandleAnnounce) MainServer::ANN Monitor
> Mar 26 09:10:02 stalker mythbackend: mythbackend[1637]: I ProcessRequest
> mainserver.cpp:1422 (HandleAnnounce) adding: stalker as a client (events: 0)
> Mar 26 09:14:00 stalker mythbackend: mythbackend[1637]: I Scheduler
> scheduler.cpp:2098 (HandleReschedule) Reschedule requested for PLACE
> PrepareToRecord
> Mar 26 09:14:00 stalker mythbackend: mythbackend[1637]: I Scheduler
> scheduler.cpp:2211 (HandleReschedule) Scheduled 1033 items in 0.3 = 0.00
> match + 0.00 check + 0.29 place
> Mar 26 09:14:30 stalker mythbackend: mythbackend[1637]: I TVRecEvent
> tv_rec.cpp:1567 (HandlePendingRecordings) TVRec[1]: ASK_RECORDING 1 29 0 0
> Mar 26 09:15:00 stalker mythbackend: mythbackend[1637]: I TVRecEvent
> tv_rec.cpp:1050 (HandleStateChange) TVRec[1]: Changing from None to
> RecordingOnly
> Mar 26 09:15:00 stalker mythbackend: mythbackend[1637]: I TVRecEvent
> mythdbcon.cpp:409 (PurgeIdleConnections) New DB connection, total: 7
> Mar 26 09:15:00 stalker mythbackend: mythbackend[1637]: I TVRecEvent
> tv_rec.cpp:3602 (TuningCheckForHWChange) TVRec[1]: HW Tuner: 1->1
> Mar 26 09:15:00 stalker mythbackend: mythbackend[1637]: I TVRecEvent
> recorders/v4lchannel.cpp:558 (SetInputAndFormat)
> V4LChannel[1](/dev/video0): SetInputAndFormat(1, NTSC) (v4l v2)
> input_switch: 0 mode_switch: 1
> Mar 26 09:15:00 stalker mythbackend: mythbackend[1637]: N Scheduler
> autoexpire.cpp:264 (CalcParams) AutoExpire: CalcParams(): Max required
> Free Space: 6.0 GB w/freq: 15 min
> Mar 26 09:15:00 stalker mythbackend: mythbackend[1637]: I Scheduler
> scheduler.cpp:2648 (HandleRecordingStatusChange) Tuning recording: "The
> Daily Show With Jon Stewart":"Kirby Dick & Amy Ziering": channel 1061 on
> cardid 1, sourceid 1

> I later saw:
> Mar 26 09:45:00 stalker mythbackend: mythbackend[1637]: I CoreContext
> scheduler.cpp:704 (UpdateRecStatus) Updating status for "The Daily Show
> With Jon Stewart":"Kirby Dick & Amy Ziering" on cardid 1 (Tuning =>
> Recorder Failed)
> Mar 26 09:45:00 stalker mythbackend: mythbackend[1637]: I Scheduler
> scheduler.cpp:2098 (HandleReschedule) Reschedule requested for CHECK -9
> 44 0 UpdateRecStatus2 | The Daily Show With Jon Stewart | Kirby Dick &
> Amy Ziering | Kirby Dick and Amy Ziering. | EP002930532503
> Mar 26 09:45:00 stalker mythbackend: mythbackend[1637]: I TVRecEvent
> tv_rec.cpp:1050 (HandleStateChange) TVRec[1]: Changing from
> RecordingOnly to None
> Mar 26 09:45:00 stalker mythbackend: mythbackend[1637]: I Scheduler
> scheduler.cpp:2211 (HandleReschedule) Scheduled 1031 items in 0.3 = 0.00
> match + 0.01 check + 0.26 place

> Mar 26 20:18:06 stalker mythbackend: mythbackend[32103]: I Scheduler
> scheduler.cpp:2211 (HandleReschedule) Scheduled 995 items in 0.3 = 0.01
> match + 0.00 check + 0.32 place
> Mar 26 20:18:06 stalker mythbackend: mythbackend[32103]: I TVRecEvent
> tv_rec.cpp:1050 (HandleStateChange) TVRec[1]: Changing from None to
> RecordingOnly
> Mar 26 20:18:06 stalker mythbackend: mythbackend[32103]: I TVRecEvent
> tv_rec.cpp:3602 (TuningCheckForHWChange) TVRec[1]: HW Tuner: 1->1
> Mar 26 20:18:06 stalker mythbackend: mythbackend[32103]: I TVRecEvent
> recorders/v4lchannel.cpp:558 (SetInputAndFormat)
> V4LChannel[1](/dev/video0): SetInputAndFormat(1, NTSC) (v4l v2)
> input_switch: 0 mode_switch: 1
> Mar 26 20:18:06 stalker mythbackend: mythbackend[32103]: I
> ProcessRequest mainserver.cpp:1420 (HandleAnnounce) MainServer::ANN Monitor
> Mar 26 20:18:06 stalker mythbackend: mythbackend[32103]: I
> ProcessRequest mainserver.cpp:1422 (HandleAnnounce) adding: stalker as a
> client (events: 0)
> Mar 26 20:18:06 stalker mythbackend: mythbackend[32103]: N Scheduler
> autoexpire.cpp:264 (CalcParams) AutoExpire: CalcParams(): Max required
> Free Space: 6.0 GB w/freq: 15 min
> Mar 26 20:18:06 stalker mythbackend: mythbackend[32103]: I Scheduler
> scheduler.cpp:2648 (HandleRecordingStatusChange) Tuning recording:
> Bones:"The Psychic in the Soup": channel 1013 on cardid 1, sourceid 1
> Mar 26 20:18:06 stalker mythbackend: mythbackend[32103]: E HttpServer60
> programinfo.cpp:2358 (GetPlaybackURL)
> ProgramInfo(1013_20150327001800.mpg): GetPlaybackURL:
> '1013_20150327001800.mpg' should be local, but it can not be found.
> Mar 26 20:18:06 stalker mythbackend: mythbackend[32103]: I
> MetadataDownload metadatadownload.cpp:280 (runGrabber) Running Grabber:
> /usr/share/mythtv/metadata/Television/ttvdb.py -l en -a US -N Bones The
> Psychic in the Soup
> Mar 26 20:18:07 stalker mythbackend: mythbackend[32103]: I
> MetadataDownload metadatacommon.cpp:1176 (ParseMetadataItem) Result
> Found, Season 10 Episode 11
> Mar 26 20:18:07 stalker mythbackend: mythbackend[32103]: I
> MetadataDownload metadatadownload.cpp:175 (run) Returning Metadata
> Results: Bones 0 0

> Mar 26 21:07:16 stalker mythbackend: mythbackend[3251]: I TVRecEvent
> tv_rec.cpp:1050 (HandleStateChange) TVRec[1]: Changing from None to
> RecordingOnly
> Mar 26 21:07:16 stalker mythbackend: mythbackend[3251]: I TVRecEvent
> tv_rec.cpp:3602 (TuningCheckForHWChange) TVRec[1]: HW Tuner: 1->1
> Mar 26 21:07:16 stalker mythbackend: mythbackend[3251]: I TVRecEvent
> recorders/v4lchannel.cpp:558 (SetInputAndFormat)
> V4LChannel[1](/dev/video0): SetInputAndFormat(1, NTSC) (v4l v2) input_swi
> tch: 0 mode_switch: 1
> Mar 26 21:07:16 stalker mythbackend: mythbackend[3251]: N Scheduler
> autoexpire.cpp:264 (CalcParams) AutoExpire: CalcParams(): Max required
> Free Space: 6.0 GB w/freq: 15 min
> Mar 26 21:07:16 stalker mythbackend: mythbackend[3251]: I Scheduler
> scheduler.cpp:2648 (HandleRecordingStatusChange) Tuning recording: "How
> I Met Your Mother":Milk: channel 1124 on cardid 1,
> sourceid 1

> I do see lots of "E CoreContext mainserver.cpp:2672
> (DoHandleDeleteRecording) ERROR when trying to delete file:
> GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/
> ON/stalker/1004_20140304030000.mpg. File doesn't exist.  Database
> metadata will not be removed." messages, but those are probably legit as
> I did lose some recordings when the server died months ago, and they're
> all older files

> _______________________________________________

What is the free space on the volume? Does mythtv-setup complain about
inaccessible storage volumes on exit?

Tot mails,
  Hika                            mailto:hikavdh at gmail.com

"Zonder hoop kun je niet leven
Zonder leven is er geen hoop
Het eeuwige dilemma
Zeker als je hoop moet vernietigen om te kunnen overleven!"

De lerende Mens