Ticket #10037: mythrecordingfaillog.txt

File mythrecordingfaillog.txt, 6.4 KB (added by Les Noland <lnoland@…>, 8 years ago)

This is an annotated log-file segment from a test illustrating the problem

Line 
1The following is a description that covers the timeline of a test I did. It involved the following activities:
2 
31. A scheduled recording of the movie "Dante's Peak" is attempted.
42. The recording fails.
53. I reactivate the recording from the Upcoming Recordings menu.
64. It seems to start recording again.
75. A check of recorded shows reveals that it thinks it is still recording but, in fact, there is no recording file.
86. I deleted the file (by pressing "D") and indicated to allow re-record.
97. I switched to LiveTV and tuned the movie which worked fine.
108. I pressed "R" and it began recording (which, eventually ended successfully).
11
12THe following is an excerpt from the backend log covering the above steps (only up to the beginning of step 8 -- the conclusion of the recording isn't
13included:
14Code:
152011-08-24 06:42:15.486 mythbackend: Running housekeeping thread
162011-08-24 07:10:13.987 QueryBasename found no entry for 6410 @ 2011-08-24T07:10:00
172011-08-24 07:10:14.021 QueryBasename found no entry for 6410 @ 2011-08-24T07:10:00
182011-08-24 07:10:14.099 TVRec(10): Changing from None to RecordingOnly
192011-08-24 07:10:14.115 TVRec(10): HW Tuner: 10->10
202011-08-24 07:10:15.397 LFireDev(001692D3FE120000): Buffered packets 2000 (8000 KB)
212011-08-24 07:10:15.642 TVRec(10): rec->GetPathname():
22'/6410_20110824071000.mpg'
23
24============================================================================
25=
262011-08-24 07:10:15.654 TFW, Error: Opening file '/6410_20110824071000.mpg'.
27  eno: Permission denied (13)
28
29NOTE: This makes it look as if it was trying to put the recording file into the root directory where it has no permissions to create files. That makes no sense -- none of my storage directories are the root directory and in the cases where it works properly it certainly doesn't store anything in the root directory.
30============================================================================
31=
32
332011-08-24 07:10:15.670 TVRec(10) Error: RingBuffer '/6410_20110824071000.mpg' not open...
342011-08-24 07:10:15.690 TVRec(10): Changing from RecordingOnly to None
352011-08-24 07:10:15.719 Finished recording Dante's Peak: channel 6410
362011-08-24 07:10:15.742 scheduler: Finished recording: Dante's Peak: channel 6410
372011-08-24 07:16:31.118 ProgramInfo(6410_20110824071000.mpg), Error:
38GetPlaybackURL: '6410_20110824071000.mpg' should be local, but it can not be found.
392011-08-24 07:17:02.010 MainServer::ANN Monitor
402011-08-24 07:17:02.027 adding: MythTVFrontEnd as a client (events: 2)
412011-08-24 07:17:46.392 ProgramInfo(6410_20110824071000.mpg), Error:
42GetPlaybackURL: '6410_20110824071000.mpg' should be local, but it can not be found.
432011-08-24 07:17:46.785 ProgramInfo(6410_20110824071000.mpg), Error:
44GetPlaybackURL: '6410_20110824071000.mpg' should be local, but it can not be found.
452011-08-24 07:17:49.431 Error deleting
46'GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/MythTVFrontEnd/6410_20110824071
47000.mpg' could not open
48   eno: No such file or directory (2)
492011-08-24 07:17:49.453 Delete Error
50'GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/MythTVFrontEnd/6410_20110824071
51000.mpg'
52   eno: No such file or directory (2)
532011-08-24 07:17:54.035 MainServer::ANN Playback
542011-08-24 07:17:54.045 adding: MythTVFrontEnd as a client (events: 0)
552011-08-24 07:17:54.098 TVRec(10): Changing from None to WatchingLiveTV
562011-08-24 07:17:54.135 TVRec(10): HW Tuner: 10->10
572011-08-24 07:17:54.333 LoadFromScheduler(): Error, called from backend.
582011-08-24 07:17:55.619 TVRec(10): Changing from WatchingLiveTV to None
592011-08-24 07:18:06.056 MainServer::ANN Playback
602011-08-24 07:18:06.088 adding: MythTVFrontEnd as a client (events: 0)
612011-08-24 07:18:06.125 TVRec(10): Changing from None to WatchingLiveTV
622011-08-24 07:18:06.150 TVRec(10): HW Tuner: 10->10
632011-08-24 07:18:06.342 LoadFromScheduler(): Error, called from backend.
642011-08-24 07:18:07.696 LFireDev(001692D3FE120000): Buffered packets 2000 (8000 KB)
65
66============================================================================
67==202011-08-24 07:18:08.478 Finished recording The Ranger, the Cook and a Hole in the Sky: channel 6490
68
69NOTE: Just to clarify, this "recording" being ended is the show which was on the initial channel when I changed to LiveTV. It ended when I changed the channel.
70============================================================================
71===
72
732011-08-24 07:18:08.517 scheduler: Finished recording: The Ranger, the Cook and a Hole in the Sky: channel 6490
742011-08-24 07:18:08.582 LoadFromScheduler(): Error, called from backend.
7511-08-24 07:18:08.628 Finished recording The Ranger, the Cook and a Hole in the Sky: channel 6490
762011-08-24 07:18:08.721 LFireDev(001692D3FE120000): Buffered packets 2000 (8000 KB)
772011-08-24 07:18:11.336 RecBase(10:/dev/video):
78GetKeyframePositions(28,9223372036854775807,#0) out of 1
792011-08-24 07:18:11.370 RecBase(10:/dev/video):
80GetKeyframePositions(28,9223372036854775807,#0) out of 1
812011-08-24 07:18:36.488 TVRec(10): HW Tuner: 10->10
822011-08-24 07:18:36.519 LoadFromScheduler(): Error, called from backend.
832011-08-24 07:18:36.576 Finished recording The Ranger, the Cook and a Hole in the Sky: channel 6490
842011-08-24 07:18:38.123 LFireDev(001692D3FE120000): Buffered packets 2000 (8000 KB)
852011-08-24 07:18:38.475 Finished recording Dante's Peak: channel 6410
862011-08-24 07:18:38.506 scheduler: Last message repeated 2 times: Finished
87recording: The Ranger, the Cook and a Hole in the Sky: channel 6490
882011-08-24 07:18:38.530 scheduler: Finished recording: Dante's Peak: channel 6410
892011-08-24 07:18:38.550 LoadFromScheduler(): Error, called from backend.
902011-08-24 07:18:38.608 Finished recording Dante's Peak: channel 6410
912011-08-24 07:18:38.687 LFireDev(001692D3FE120000): Buffered packets 2000 (8000 KB)
922011-08-24 07:18:41.966 RecBase(10:/dev/video):
93GetKeyframePositions(32,9223372036854775807,#0) out of 1
942011-08-24 07:18:41.999 RecBase(10:/dev/video):
95GetKeyframePositions(32,9223372036854775807,#0) out of 1 Error in my_thread_global_end(): 1 threads didn't exit
962011-08-24 07:18:54.024 TVRec(10): SetLiveRecording(1)
972011-08-24 07:18:54.078 TVRec(10): SetLiveRecording() -- record
982011-08-24 07:19:39.197 TVRec(10): Changing from WatchingLiveTV to RecordingOnly Error in my_thread_global_end(): 1 threads didn't exit
992011-08-24 07:20:31.800 New DB connection, total: 4
1002011-08-24 07:20:31.864 Connected to database 'mythconverg' at host:
101192.168.0.235