[mythtv-users] Log says MythTV's recording; file sometimes written, sometimes not, sometimes partial
Zed Lopez
zed.lopez at gmail.com
Wed Dec 16 23:06:51 UTC 2009
Hi all,
Sometimes, the log says MythTV is recording something, but the file
never gets written at all, or only part of what should have been
recorded really gets written to the file.
(I apologize for the length of what follows. I tried to keep it as
brief as I could, but I'm afraid I'm guessing as to what log messages
are really relevant to my problem.)
Some of the time, everything works perfectly, so it doesn't seem to be
a permissions issue. The issue persisted after I changed what disk
mythtv was recording to to a 1.5TB disk with more than a TB to spare,
so there's no issue with space availability.
I'm using an HVR-2250 dual DTV-tuner attached to an antenna. I tried
updating everything to the latest -- the latest kernel release for
Ubuntu 8.10 (Intrepid), built the latest saa7164 stable
(saa7164-stable-da41142e212f), the latest MythTV 0.22 package from the
Mythbuntu trunk-0.22 Ubuntu PPA repository. I'm using the 1.03
firmware available at http://www.steventoth.net/linux/hvr22xx/ (there
is new firmware from Hauppage as of 2009-11-30, but no updated
extraction script and I didn't look into figuring out extracting the
new firmware.) But even after all these updates, I'm seeing the same
problem. Here's the system/package info:
zed at box:~$ uname -a
Linux box 2.6.27-16-generic #1 SMP Tue Dec 1 17:56:54 UTC 2009 i686 GNU/Linux
zed at box:~$ aptitude show mythtv
Package: mythtv
State: installed
Automatically installed: no
Version: 0.22.0+fixes22957-0ubuntu0+mythbuntu1
[...]
Last night, I was running at debug level "most", and also running a
script that recorded the output of ls -lrt|tail -4 on my recordings
directory every 5 minutes. The mythtv log say it recorded Jeopardy
from 18:58 to 19:32 (I have 2 minutes over on both sides configured)
and The Sing-Off from 19:58 to 22:02, but it never wrote anything for
Jeopardy, and recorded only about 15 minutes of The Sing-Off starting
around 21:17. Here it seems to describe recording Jeopardy
correctly.
2009-12-15 18:58:02.247 TVRec(8): StartRecording(Jeopardy!)
2009-12-15 18:58:02.295 RecordingInfo: StartedRecording: Recording to
'/srv/mythtv/1071_20091215185800.mpg'
2009-12-15 18:58:02.373 TVRec(8): StartedRecording(0xb2c37a58)
fn(/srv/mythtv/1071_20091215185800.mpg)
2009-12-15 18:58:02.380 MythEvent: RECORDING_LIST_CHANGE
2009-12-15 18:58:02.384 TVRec(8): ClearFlags(CancelNextRecording,) ->
RunMainLoop,
2009-12-15 18:58:02.388 TVRec(8): Changing from None to Watching RecordingOnly
2009-12-15 18:58:02.400 TVRec(8):
ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,
2009-12-15 18:58:02.416 TVRec(8): Request: Program(yes) channel()
input() flags(Recording,)
2009-12-15 18:58:02.434 TVRec(8): HW Tuner: 8->8
2009-12-15 18:58:02.445 TVRec(8): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,
2009-12-15 18:58:02.461 TVRec(8): No recorder yet, calling TuningFrequency
[...]
2009-12-15 18:58:02.558 TVRec(8): Starting Signal Monitor
2009-12-15 18:58:02.565 TVRec(8): SetupSignalMonitor(1, 0)
[...]
2009-12-15 18:58:02.692 TVRec(8): Signal monitor successfully created
2009-12-15 18:58:02.704 TVRec(8): Setting up table monitoring.
2009-12-15 18:58:02.743 Using profile 'Live TV' to record
2009-12-15 18:58:02.756 TVRec(8): ATSC channel: 7_1
[...]
2009-12-15 18:58:02.832 TVRec(8): Successfully set up ATSC table monitoring.
2009-12-15 18:58:02.848 SM(/dev/dvb/adapter0/frontend0)::Start: begin
2009-12-15 18:58:02.860 SM(/dev/dvb/adapter0/frontend0)::AddFlags:
Seen() Match() Wait(Sig,)
2009-12-15 18:58:02.860 SM(/dev/dvb/adapter0/frontend0)::Start: end
2009-12-15 18:58:02.880 TVRec(8): SetFlags(SignalMonitorRunning,) ->
RunMainLoop,SignalMonitorRunning,
2009-12-15 18:58:02.890 TVRec(8): ClearFlags(WaitingForSignal,) ->
RunMainLoop,SignalMonitorRunning,
2009-12-15 18:58:02.904 TVRec(8): SetFlags(WaitingForSignal,) ->
RunMainLoop,WaitingForSignal,SignalMonitorRunning,
2009-12-15 18:58:02.920 TVRec(8): ClearFlags(NeedToStartRecorder,) ->
RunMainLoop,WaitingForSignal,SignalMonitorRunning,
2009-12-15 18:58:02.936 TVRec(8): SetFlags(NeedToStartRecorder,) ->
RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,
2009-12-15 18:58:02.940 SM(/dev/dvb/adapter0/frontend0)::AddFlags:
Seen() Match() Wait(Sig,)
2009-12-15 18:58:02.972 AutoExpire: Cardid 8: is starting a recording
on an unknown fsID soon.
2009-12-15 18:58:02.984 AutoExpire: CalcParams()
2009-12-15 18:58:02.998 Cardid 8: max bitrate 142089 KB/min
2009-12-15 18:58:03.009 Maximal bitrate of busy encoders is 142089 KB/min
--- GetFilesystemInfos directory list start ---
Dir: box:/srv/mythtv
Location: Local
fsID : 2009-12-15 18:58:03.040
SM(/dev/dvb/adapter0/frontend0)::AddFlags: Seen() Match() Wait(Sig,)1
dirID : 3
BlkSize : 4096
TotalKB : 1464682076
UsedKB : 298529380
FreeKB : 1166152696
--- GetFilesystemInfos directory list end ---
2009-12-15 18:58:03.164 fsID #1: Total: 1396.8 GB Used: 284.7 GB
Free: 1112.1 GB
2009-12-15 18:58:03.175 SM(/dev/dvb/adapter0/frontend0)::AddFlags:
Seen() Match() Wait(Sig,)
2009-12-15 18:58:03.178 Cardid 8: max bitrate 18945 Kb/sec, fsID 1
max is now 142089 KB/min
2009-12-15 18:58:03.201 Max of 142089 KB/min for fsID 1 is higher
than the existing Max of 0 so we'll use this Max instead
2009-12-15 18:58:03.210 AutoExpire: CalcParams(): Max required Free
Space: 3.0 GB w/freq: 15 min
2009-12-15 18:58:03.225 Started recording: Jeopardy!: channel 1071 on
cardid 8, sourceid 1
[...juming to end...]
2009-12-15 19:32:00.214 TVRec(8): TeardownSignalMonitor() -- end
2009-12-15 19:32:00.217 TVRec(8): ClearFlags(SignalMonitorRunning,) ->
RunMainLoop,WaitingForSignal,NeedToStartRecorder,
2009-12-15 19:32:00.244 TVRec(8): ClearFlags(WaitingForSignal,) ->
RunMainLoop,NeedToStartRecorder,
2009-12-15 19:32:00.256 TVRec(8): FinishedRecording(Jeopardy!) in
recgroup: Default
2009-12-15 19:32:00.265 MythEvent: UPDATE_RECORDING_STATUS 8 1071
2009-12-15T19:00:00 -3 2009-12-15T19:32:00
2009-12-15 19:32:00.277 Finished recording Jeopardy!: channel 1071
But the recording directory monitoring log shows that it never wrote
anything for /srv/mythtv/1071_20091215185800.mpg. Then, according to
the log, at 19:58, it looks like it begins to record The Sing-Off:
2009-12-15 19:58:02.759 TVRec(9): StartRecording(The Sing-Off)
2009-12-15 19:58:02.771 RecordingInfo: StartedRecording: Recording to
'/srv/mythtv/2111_20091215195800.mpg'
2009-12-15 19:58:02.802 TVRec(9): StartedRecording(0xb2c759b8)
fn(/srv/mythtv/2111_20091215195800.mpg)
2009-12-15 19:58:02.808 MythEvent: RECORDING_LIST_CHANGE
2009-12-15 19:58:02.821 TVRec(9): ClearFlags(CancelNextRecording,) ->
RunMainLoop,
2009-12-15 19:58:02.828 TVRec(9): Changing from None to Watching RecordingOnly
2009-12-15 19:58:02.836 TVRec(9):
ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,
2009-12-15 19:58:02.844 TVRec(9): Request: Program(yes) channel()
input() flags(Recording,)
2009-12-15 19:58:02.853 TVRec(9): HW Tuner: 9->9
2009-12-15 19:58:02.860 TVRec(9): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,
2009-12-15 19:58:02.868 TVRec(9): No recorder yet, calling TuningFrequency
[...]
2009-12-15 19:58:03.041 TVRec(9): Starting Signal Monitor
2009-12-15 19:58:03.049 TVRec(9): SetupSignalMonitor(1, 0)
[...]
2009-12-15 19:58:03.137 TVRec(9): Signal monitor successfully created
2009-12-15 19:58:03.144 TVRec(9): Setting up table monitoring.
2009-12-15 19:58:03.156 Using profile 'Live TV' to record
2009-12-15 19:58:03.169 TVRec(9): ATSC channel: 11_1
2009-12-15 19:58:03.177 DTVSM(/dev/dvb/adapter1/frontend0)::SetChannel(11, 1):
2009-12-15 19:58:03.186 SM(/dev/dvb/adapter1/frontend0)::RemoveFlags:
Seen(PAT,PMT,VCT,Crypt,) Match(PAT,PMT,VCT,Crypt,) Wait()
2009-12-15 19:58:03.196 SM(/dev/dvb/adapter1/frontend0)::AddFlags:
Seen() Match() Wait(PAT,VCT,)
2009-12-15 19:58:03.207 SM(/dev/dvb/adapter1/frontend0)::AddFlags:
Seen() Match() Wait(MGT,)
2009-12-15 19:58:03.213 TVRec(9): Successfully set up ATSC table monitoring.
2009-12-15 19:58:03.224 SM(/dev/dvb/adapter1/frontend0)::Start: begin
2009-12-15 19:58:03.233 SM(/dev/dvb/adapter1/frontend0)::AddFlags:
Seen() Match() Wait(Sig,)
2009-12-15 19:58:03.233 SM(/dev/dvb/adapter1/frontend0)::Start: end
2009-12-15 19:58:03.245 TVRec(9): SetFlags(SignalMonitorRunning,) ->
RunMainLoop,SignalMonitorRunning,
2009-12-15 19:58:03.255 TVRec(9): ClearFlags(WaitingForSignal,) ->
RunMainLoop,SignalMonitorRunning,
2009-12-15 19:58:03.261 TVRec(9): SetFlags(WaitingForSignal,) ->
RunMainLoop,WaitingForSignal,SignalMonitorRunning,
2009-12-15 19:58:03.269 TVRec(9): ClearFlags(NeedToStartRecorder,) ->
RunMainLoop,WaitingForSignal,SignalMonitorRunning,
2009-12-15 19:58:03.277 TVRec(9): SetFlags(NeedToStartRecorder,) ->
RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,
2009-12-15 19:58:03.288 AutoExpire: Cardid 9: is starting a recording
on an unknown fsID soon.
2009-12-15 19:58:03.301 AutoExpire: CalcParams()
2009-12-15 19:58:03.311 Cardid 9: max bitrate 142089 KB/min
2009-12-15 19:58:03.318 Maximal bitrate of busy encoders is 142089 KB/min
--- GetFilesystemInfos directory list start ---
Dir: box:/srv/mythtv
Location: Local
fsID : 1
dirID : 3
BlkSize : 4096
TotalKB : 1464682076
UsedKB : 2009-12-15 19:58:03.313
SM(/dev/dvb/adapter1/frontend0)::AddFlags: Seen() Match()
Wait(Sig,)298529380
FreeKB : 1166152696
--- GetFilesystemInfos directory list end ---
2009-12-15 19:58:03.413 fsID #1: Total: 1396.8 GB Used: 284.7 GB
Free: 1112.1 GB
2009-12-15 19:58:03.436 Cardid 9: max bitrate 18945 Kb/sec, fsID 1
max is now 142089 KB/min
2009-12-15 19:58:03.445 Max of 142089 KB/min for fsID 1 is higher
than the existing Max of 0 so we'll use this Max instead
2009-12-15 19:58:03.453 AutoExpire: CalcParams(): Max required Free
Space: 3.0 GB w/freq: 15 min
2009-12-15 19:58:03.462 Started recording: The Sing-Off "Big Hits &
Guilty Pleasures": channel 2111 on cardid 9, sourceid 2
Nothing is written to /srv/mythtv/2111_20091215195800.mpg at this
point. But something happens at 20:48.
2009-12-15 20:48:00.938 TVRec(9): Got good signal
2009-12-15 20:48:00.949 TVRec(9): TeardownSignalMonitor() -- begin
2009-12-15 20:48:00.941 PIDInfo(/dev/dvb/adapter1/frontend0): Opening
filter for pid 0x31
2009-12-15 20:48:00.984 PIDInfo(/dev/dvb/adapter1/frontend0): Opening
filter for pid 0x34
2009-12-15 20:48:00.992 PIDInfo(/dev/dvb/adapter1/frontend0): Opening
filter for pid 0x35
2009-12-15 20:48:00.986 DVBSM(/dev/dvb/adapter1/frontend0): Stop() -- begin
2009-12-15 20:48:01.016 SM(/dev/dvb/adapter1/frontend0)::Stop: begin
2009-12-15 20:48:01.038 SM(/dev/dvb/adapter1/frontend0)::Stop: end
2009-12-15 20:48:01.044 DVBSH(/dev/dvb/adapter1/frontend0):
RemoveListener(0x9e81c3c) -- begin
2009-12-15 20:48:01.053 DVBSH(/dev/dvb/adapter1/frontend0):
RemoveListener(0x9e81c3c) -- locked
2009-12-15 20:48:01.061 DVBSH(/dev/dvb/adapter1/frontend0): RunTS(): shutdown
2009-12-15 20:48:01.069 PIDInfo(/dev/dvb/adapter1/frontend0): Closing
filter for pid 0x0
2009-12-15 20:48:01.079 PIDInfo(/dev/dvb/adapter1/frontend0): Closing
filter for pid 0x30
2009-12-15 20:48:01.090 PIDInfo(/dev/dvb/adapter1/frontend0): Closing
filter for pid 0x31
2009-12-15 20:48:01.104 PIDInfo(/dev/dvb/adapter1/frontend0): Closing
filter for pid 0x34
2009-12-15 20:48:01.116 PIDInfo(/dev/dvb/adapter1/frontend0): Closing
filter for pid 0x35
2009-12-15 20:48:01.124 PIDInfo(/dev/dvb/adapter1/frontend0): Closing
filter for pid 0x1ffb
2009-12-15 20:48:01.347 DVBSH(/dev/dvb/adapter1/frontend0): RunTS(): end
2009-12-15 20:48:01.352 DVBSH(/dev/dvb/adapter1/frontend0):
RemoveListener(0x9e81c3c) -- end
2009-12-15 20:48:01.360 DVBSM(/dev/dvb/adapter1/frontend0): Stop() -- end
2009-12-15 20:48:01.368 SM(/dev/dvb/adapter1/frontend0)::Stop: begin
2009-12-15 20:48:01.376 SM(/dev/dvb/adapter1/frontend0)::Stop: end
2009-12-15 20:48:01.388 TVRec(9): TeardownSignalMonitor() -- end
2009-12-15 20:48:01.400 TVRec(9): ClearFlags(SignalMonitorRunning,) ->
RunMainLoop,WaitingForSignal,NeedToStartRecorder,
2009-12-15 20:48:01.414 TVRec(9): ClearFlags(WaitingForSignal,) ->
RunMainLoop,NeedToStartRecorder,
2009-12-15 20:48:01.429 TVRec(9): EIT scanning disabled for all
sources on this card.
2009-12-15 20:48:01.437 TVRec(9): Starting Recorder
2009-12-15 20:48:01.449 Using profile 'Default' to record
2009-12-15 20:48:01.469 RecBase(9:/dev/dvb/adapter1/frontend0):
SetRingBuffer(0x9e81aa0) '/srv/mythtv/2111_20091215195800.mpg'
2009-12-15 20:48:01.476 Adding Source #1 ATSC chan 11-1
2009-12-15 20:48:01.484 Adding Source #2 ATSC chan 11-2
2009-12-15 20:48:01.495 Adding Source #3 ATSC chan 11-3
2009-12-15 20:48:01.505 DVBRec(9:/dev/dvb/adapter1/frontend0): SetPAT(3 on 0x30)
[...]
2009-12-15 20:48:01.684 RecBase(9:/dev/dvb/adapter1/frontend0):
SetRecording(0xb2c759b8) title(The Sing-Off)
2009-12-15 20:48:01.699 DVBRec(9:/dev/dvb/adapter1/frontend0): Card
opened successfully fd(-1)
2009-12-15 20:48:01.712 DVBSH(/dev/dvb/adapter1/frontend0):
AddListener(0x9e81c3c) -- begin
2009-12-15 20:48:01.714 TVRec(9):
SetFlags(RecorderRunning,RingBufferReady,) ->
RunMainLoop,NeedToStartRecorder,RecorderRunning,RingBufferReady,
2009-12-15 20:48:01.724 DVBSH(/dev/dvb/adapter1/frontend0):
AddListener(0x9e81c3c) -- locked
2009-12-15 20:48:01.734 TVRec(9): ClearFlags(NeedToStartRecorder,) ->
RunMainLoop,RecorderRunning,RingBufferReady,
2009-12-15 20:48:01.744 DVBSH(/dev/dvb/adapter1/frontend0):
AddListener(0x9e81c3c) -- end
2009-12-15 20:48:01.757 DevRdB(/dev/dvb/adapter1/frontend0): buffer size 9400 KB
2009-12-15 20:48:01.792 DVBSH(/dev/dvb/adapter1/frontend0): RunTS(): begin
/srv/mythtv/2111_20091215195800.mpg gets created at 20:48, but just 18811468
bytes are written to it, and it doesn't get updated after 20:48.
There are a whole lot of these then:
2009-12-15 20:48:17.165 DVBRec(9:/dev/dvb/adapter1/frontend0): PID
0x34 discontinuity detected
2009-12-15 20:48:17.173 DVBRec(9:/dev/dvb/adapter1/frontend0): PID
0x31 discontinuity detected
2009-12-15 20:48:17.181 DVBRec(9:/dev/dvb/adapter1/frontend0): PID
0x31 discontinuity detected
Meanwhile, it starts recording Gordon Ramsay at 20:58:
2009-12-15 20:58:02.616 TVRec(8): StartRecording(Gordon Ramsay: Cookalong Live)
2009-12-15 20:58:02.630 RecordingInfo: StartedRecording: Recording to
'/srv/mythtv/1021_20091215205800.mpg'
2009-12-15 20:58:02.659 TVRec(8): StartedRecording(0xb2c3e720)
fn(/srv/mythtv/1021_20091215205800.mpg)
[...]
2009-12-15 20:58:05.274 RecBase(8:/dev/dvb/adapter0/frontend0):
SetRingBuffer(0x9e70848) '/srv/mythtv/1021_20091215205800.mpg'
[...]
2009-12-15 20:58:05.438 RecBase(8:/dev/dvb/adapter0/frontend0):
SetRecording(0xb2c3e720) title(Gordon Ramsay: Cookalong Live)
2009-12-15 20:58:05.449 DVBRec(8:/dev/dvb/adapter0/frontend0): Card
opened successfully fd(-1)
This file really appears, and its update times are as expected.
Between 21:11 and 21:16, the existing Sing-Off file,
2111_20091215195800.mpg is deleted, and by 21:21 it has started a new
one. I don't recognize a smoking gun in the log indicating either of
these events. In that time window, the log explicitly says MythTV's
not autoexpiring it:
2009-12-15 21:12:52.128 AutoExpire: Skipping 1071 @ Tue Dec 15
18:58:00 2009 because it is in Don't Expire List
2009-12-15 21:12:52.144 AutoExpire: Skipping 2111 @ Tue Dec 15
19:58:00 2009 because it is in Don't Expire List
2009-12-15 21:12:52.156 AutoExpire: Skipping 1021 @ Tue Dec 15
20:58:00 2009 because it is in Don't Expire List
2009-12-15 21:12:52.166 fsID #1: Total: 1396.8 GB Used: 286.3 GB
Free: 1110.6 GB
2009-12-15 21:12:52.180 AutoExpire: SendDeleteMessages. Nothing to expire.
The Sing-Off stops getting written to at 21:28, at 1623596764
bytes. At that time, the log was getting a lot of these:
2009-12-15 21:28:01.707 DVBRec(9:/dev/dvb/adapter1/frontend0): PID
0x31 discontinuity detected
2009-12-15 21:28:04.820 DVBRec(9:/dev/dvb/adapter1/frontend0): PID
0x31 discontinuity detected
I can see that the file hadn't been touched again at 22:01; at 22:02
it is touched, and has a final size of 1623599396 bytes, an increase
of just 2632 bytes.
Here the log shows finishing both The Sing-Off and Gordon Ramsay:
2009-12-15 22:02:00.540 TVRec(9): ClearFlags(FinishRecording,) ->
RunMainLoop,RecorderRunning,RingBufferReady,
2009-12-15 22:02:00.548 TVRec(9): Changing from Watching RecordingOnly to None
2009-12-15 22:02:00.552 TVRec(9):
ClearFlags(FrontendReady,CancelNextRecording,) ->
RunMainLoop,RecorderRunning,RingBufferReady,
2009-12-15 22:02:00.557 TVRec(9): Request: Program(no) channel()
input() flags(CloseRec,KillRingBuffer,)
2009-12-15 22:02:00.582 TVRec(9): FinishedRecording(The Sing-Off) in
recgroup: Default
2009-12-15 22:02:00.584 MythEvent: UPDATE_RECORDING_STATUS 9 2111
2009-12-15T20:00:00 -3 2009-12-15T22:02:00
2009-12-15 22:02:00.594 MythEvent: RESCHEDULE_RECORDINGS 0
2009-12-15 22:02:00.595 Finished recording The Sing-Off "Big Hits &
Guilty Pleasures": channel 2111
2009-12-15 22:02:00.606 Reschedule requested for id 0.
2009-12-15 22:02:00.623 Recording designated 1080i/p because width was 1920
2009-12-15 22:02:00.623 BuildWorkList...
2009-12-15 22:02:00.648 MythEvent: DONE_RECORDING 9 7440 27736
2009-12-15 22:02:00.659 AddNewRecords...
2009-12-15 22:02:00.716 DVBSH(/dev/dvb/adapter1/frontend0):
RemoveListener(0x9e81c3c) -- begin
2009-12-15 22:02:00.730 DVBSH(/dev/dvb/adapter1/frontend0):
RemoveListener(0x9e81c3c) -- locked
2009-12-15 22:02:00.769 DVBSH(/dev/dvb/adapter1/frontend0): RunTS(): shutdown
2009-12-15 22:02:00.786 PIDInfo(/dev/dvb/adapter1/frontend0): Closing
filter for pid 0x0
2009-12-15 22:02:00.787 |-- Start DB Query...
2009-12-15 22:02:00.793 PIDInfo(/dev/dvb/adapter1/frontend0): Closing
filter for pid 0x30
2009-12-15 22:02:00.920 PIDInfo(/dev/dvb/adapter1/frontend0): Closing
filter for pid 0x31
2009-12-15 22:02:00.889 TVRec(8): ClearFlags(FinishRecording,) ->
RunMainLoop,RecorderRunning,RingBufferReady,
2009-12-15 22:02:00.984 PIDInfo(/dev/dvb/adapter1/frontend0): Closing
filter for pid 0x34
2009-12-15 22:02:01.029 TVRec(8): Changing from Watching RecordingOnly to None
2009-12-15 22:02:01.040 PIDInfo(/dev/dvb/adapter1/frontend0): Closing
filter for pid 0x35
2009-12-15 22:02:01.068 TVRec(8):
ClearFlags(FrontendReady,CancelNextRecording,) ->
RunMainLoop,RecorderRunning,RingBufferReady,
2009-12-15 22:02:01.088 PIDInfo(/dev/dvb/adapter1/frontend0): Closing
filter for pid 0x40
2009-12-15 22:02:01.103 |-- 126 results in 0.297183 sec. Processing...
2009-12-15 22:02:01.116 TVRec(8): Request: Program(no) channel()
input() flags(CloseRec,KillRingBuffer,)
2009-12-15 22:02:01.126 PIDInfo(/dev/dvb/adapter1/frontend0): Closing
filter for pid 0x50
2009-12-15 22:02:01.160 PIDInfo(/dev/dvb/adapter1/frontend0): Closing
filter for pid 0x1ffb
2009-12-15 22:02:01.160 TVRec(8): FinishedRecording(Gordon Ramsay:
Cookalong Live) in recgroup: Default
2009-12-15 22:02:01.154 +-- Cleanup...
2009-12-15 22:02:01.177 MythEvent: UPDATE_RECORDING_STATUS 8 1021
2009-12-15T21:00:00 -3 2009-12-15T22:02:00
2009-12-15 22:02:01.186 AddNotListed...
2009-12-15 22:02:01.199 Finished recording Gordon Ramsay: Cookalong
Live: channel 1021
One thing I notice is that the only times the DVBRec "Card opened
successfully" messages appear are at 20:48 for The Sing-Off and 20:58
for Gordon Ramsay, and not for Jeopardy, for The Sing-Off at 19:58 or
between 21:16 and 21:21 when it resumed writing the new one. But
there's nothing like a "failed to open card" message in the other
cases.
If you'd like to know more, then bless your heart, and you can find the
whole log spanning this time, 18:58-22:02 at:
http://sites.google.com/site/zedlopez/stuff/mythbackendlog.txt
And the output of my filesystem monitor script so you can see the
bizarre behavior I'm reporting at:
http://sites.google.com/site/zedlopez/stuff/mythrecordingdirchanges.txt
Any suggestions?
More information about the mythtv-users
mailing list