[mythtv-commits] Ticket #10802: Error Log Information Missing

[MythTV]

#10802: Error Log Information Missing
----------------------------------+----------------------------
 Reporter:  ewilde@…              |          Owner:  danielk
     Type:  Bug Report - General  |         Status:  new
 Priority:  minor                 |      Milestone:  unknown
Component:  MythTV - Recording    |        Version:  0.25-fixes
 Severity:  medium                |     Resolution:
 Keywords:                        |  Ticket locked:  0
----------------------------------+----------------------------
Changes (by wagnerrp):

 * priority:  major => minor
 * version:  Unspecified => 0.25-fixes


Old description:

> In MythTV 0.25, when a recording fails, the information logged in the
> backend log is absolutely useless at figuring out what the problem is.
> Here is an example:
>
> Jun  5 06:59:33 keck mythbackend[1639]: I TVRecEvent tv_rec.cpp:1518
> (HandlePendingRecordings) TVRec(6): ASK_RECORDING 6 29 0 0
> Jun  5 07:00:06 keck mythbackend[1639]: I CoreContext mythdbcon.cpp:395
> (PurgeIdleConnections) New DB connection, total: 10
> Jun  5 07:00:06 keck mythbackend[1639]: I TVRecEvent tv_rec.cpp:1014
> (HandleStateChange) TVRec(6): Changing from None to RecordingOnly
> Jun  5 07:00:06 keck mythbackend[1639]: I TVRecEvent tv_rec.cpp:3456
> (TuningCheckForHWChange) TVRec(6): HW Tuner: 6->6
> Jun  5 07:02:03 keck mythbackend[1639]: I HouseKeeping
> housekeeper.cpp:225 (RunHouseKeeping) Running housekeeping thread
> Jun  5 07:03:05 keck mythbackend[1639]: I TVRecEvent tv_rec.cpp:1014
> (HandleStateChange) TVRec(6): Changing from RecordingOnly to None
> Jun  5 07:03:05 keck mythbackend[1639]: E ProcessRequest
> programinfo.cpp:2278 (GetPlaybackURL)
> ProgramInfo(5071_20120605070000.mpg): GetPlaybackURL:
> '5071_20120605070000.mpg' should be local, but it can not be found.
> Jun  5 07:03:08 keck mythbackend[1639]: E DeleteThread mainserver.cpp:114
> (delete_file_immediately) Error deleting
> 'GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/keck/5071_20120605070000.mpg':
> No such file or directory
>
> When a problem occurs, the log file is supposed to be the place where you
> turn to diagnose it. What is shown here? That the recording started at
> 07:00:06 and that it stopped at 07:03:05 (it was supposed to run until
> 09:00:00)? That the housekeeping task couldn't find the recording file?
> What else? Did the tuner not get set up? Did it fail to get a lock? Do
> the major/minor channel numbers not match what's in the CVCT? Was there
> no space available? Were the file permissions wrong? Don't be shy. The
> log file already has plenty of stuff in it. Adding a little more, useful
> information isn't going to upset anybody. When a requested operation
> fails for any reason, the log file needs to contain copious information
> about what was going on and what went wrong.
>
> Incidentally, I've marked the priority of this bug as major (but I know
> you'll disagree). When a recording fails and I can't figure out why, it
> is a major problem.

New description:

 In MythTV 0.25, when a recording fails, the information logged in the
 backend log is absolutely useless at figuring out what the problem is.
 Here is an example:

 {{{
 Jun  5 06:59:33 keck mythbackend[1639]: I TVRecEvent tv_rec.cpp:1518
 (HandlePendingRecordings) TVRec(6): ASK_RECORDING 6 29 0 0
 Jun  5 07:00:06 keck mythbackend[1639]: I CoreContext mythdbcon.cpp:395
 (PurgeIdleConnections) New DB connection, total: 10
 Jun  5 07:00:06 keck mythbackend[1639]: I TVRecEvent tv_rec.cpp:1014
 (HandleStateChange) TVRec(6): Changing from None to RecordingOnly
 Jun  5 07:00:06 keck mythbackend[1639]: I TVRecEvent tv_rec.cpp:3456
 (TuningCheckForHWChange) TVRec(6): HW Tuner: 6->6
 Jun  5 07:02:03 keck mythbackend[1639]: I HouseKeeping housekeeper.cpp:225
 (RunHouseKeeping) Running housekeeping thread
 Jun  5 07:03:05 keck mythbackend[1639]: I TVRecEvent tv_rec.cpp:1014
 (HandleStateChange) TVRec(6): Changing from RecordingOnly to None
 Jun  5 07:03:05 keck mythbackend[1639]: E ProcessRequest
 programinfo.cpp:2278 (GetPlaybackURL)
 ProgramInfo(5071_20120605070000.mpg): GetPlaybackURL:
 '5071_20120605070000.mpg' should be local, but it can not be found.
 Jun  5 07:03:08 keck mythbackend[1639]: E DeleteThread mainserver.cpp:114
 (delete_file_immediately) Error deleting
 'GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/keck/5071_20120605070000.mpg':
 No such file or directory
 }}}

 When a problem occurs, the log file is supposed to be the place where you
 turn to diagnose it. What is shown here? That the recording started at
 07:00:06 and that it stopped at 07:03:05 (it was supposed to run until
 09:00:00)? That the housekeeping task couldn't find the recording file?
 What else? Did the tuner not get set up? Did it fail to get a lock? Do the
 major/minor channel numbers not match what's in the CVCT? Was there no
 space available? Were the file permissions wrong? Don't be shy. The log
 file already has plenty of stuff in it. Adding a little more, useful
 information isn't going to upset anybody. When a requested operation fails
 for any reason, the log file needs to contain copious information about
 what was going on and what went wrong.

 Incidentally, I've marked the priority of this bug as major (but I know
 you'll disagree). When a recording fails and I can't figure out why, it is
 a major problem.

--

-- 
Ticket URL: <http://code.mythtv.org/trac/ticket/10802#comment:1>
MythTV <http://code.mythtv.org/trac>
MythTV Media Center