[mythtv-users] DVB failing to generate recordings - please help!

Neil Bird neil at fnxweb.com
Wed Mar 8 13:49:27 UTC 2006 

   Can anyone give me any clues as to where to look?


   This seems to be cropping up a bit, but the symptoms are either slightly 
different, or the thread peters out without any solution or hints.

   My new DVB card (Nova-T, FC3, Myth 0.19 + AT's svnfixes) works fine (well, 
slightly jerky on occasion) through LiveTV, and recordings thus generated are 
available as expected.  My original PVR-350 is still working a treat (only 
recording via s-video [from Sky digibox], I don't wont analogue recordings).

   But any *schedule* I have set up that uses the DVB card simply fails to 
create a .mpg.  No errors I can see, d/b says it's there, so front-end thniks 
it's there, but no file on the HD.  I *did* manage to get it to work a couple 
of times when I first installed it, but never since.


   Can ANYONE see anything amiss in the following log?  It was supposed to 
record “Planet Earth” followed by another prog. off the DVB (tuner 2, but 
source 3 for some reason [prob. due to several attempts to get the DVB 
channels in properly]) and “Midsomer Murders” off the PVR-350.  MM came out 
OK, PE and the prog. after it didn't generate files.

   There are no delete or unlink refs,. to the files in question.  In fact, no 
refs. to the file names other than the later preview errors.  Nor are there 
and 'warning' or 'error' messages I can see for that day (aside again from the 
preview errors).

...

2006-03-05 20:59:01.049 TVRec(2): StartRecording(Planet Earth)
2006-03-05 20:59:01.051 TVRec(2): ClearFlags(AskAllowRecording,) -> 
RunMainLoop,RingBufferReset,
2006-03-05 20:59:01.143 TVRec(2): StartedRecording(0x9429460) 
fn(/usr/mythtv/recordings/3506_20060305205900.mpg)
2006-03-05 20:59:01.148 TVRec(2): ClearFlags(CancelNextRecording,) -> 
RunMainLoop,RingBufferReset,
2006-03-05 20:59:01.149 write -> 14 51 
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2006-03-05 20:59:01.152 write -> 16 51 
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2006-03-05 20:59:01.151 TVRec(2): Changing from None to RecordingOnly
2006-03-05 20:59:01.155 TVRec(2): 
ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,RingBufferReset,
2006-03-05 20:59:01.156 TVRec(2): SetFlags(AskAllowRecording,) -> 
RunMainLoop,AskAllowRecording,RingBufferReset,
2006-03-05 20:59:01.157 TVRec(2): Request: Program(yes) channel() input() 
flags(Recording,)
2006-03-05 20:59:01.159 TVRec(2): ClearFlags(PENDINGACTIONS,) -> 
RunMainLoop,AskAllowRecording,RingBufferReset,
2006-03-05 20:59:01.166 DVB#0 Opening DVB channel
2006-03-05 20:59:01.167 DVB#0 SetChannelByString(1)
2006-03-05 20:59:01.181 DVB#0 Frequency: 778000000 BW: 8MHz HP: 3/4 LP: 3/4C: 
QAM-16 TM: 2K H: None GI: 1/32
2006-03-05 20:59:01.183 DVB#0 Old Params: freq(666000000) type(OFDM)
2006-03-05 20:59:01.185 DVB#0 New Params: freq(778000000) type(OFDM)
2006-03-05 20:59:01.218 dvbchannel.cpp:wait_for_backend: Status: Signal,
2006-03-05 20:59:01.219 DVB#0 DVBChannel::Tune: Frequency tuning successful.
2006-03-05 20:59:01.221 DVB#0 Tuned to frequency for channel 1.
2006-03-05 20:59:01.222 TVRec(2): Starting Signal Monitor
2006-03-05 20:59:01.223 TVRec(2): SetupSignalMonitor(1, 0)
2006-03-05 20:59:01.224 DVB#0 Opening DVB channel
2006-03-05 20:59:01.245 SM(0)::AddFlags: Seen() Match() Wait(Sig,SNR,BER,UB,)
2006-03-05 20:59:01.249 DVBSM(0)::constructor(): initial flags 0x7400000
2006-03-05 20:59:01.250 TVRec(2): Signal monitor successfully created
2006-03-05 20:59:01.251 TVRec(2): Setting up table monitoring.
2006-03-05 20:59:01.252 TVRec(2): MPEG program number: 4172
2006-03-05 20:59:01.254 DTVSM(0)::SetProgramNumber(4172):
2006-03-05 20:59:01.255 SM(0)::RemoveFlags: Seen(PMT,) Match(PMT,) Wait()
2006-03-05 20:59:01.256 SM(0)::AddFlags: Seen() Match() Wait(PMT,)
2006-03-05 20:59:01.257 SM(0)::AddFlags: Seen() Match() Wait(PAT,PMT,)
2006-03-05 20:59:01.258 TVRec(2): Successfully set up MPEG table monitoring.
2006-03-05 20:59:01.259 SM(0)::Start: begin
2006-03-05 20:59:01.296 SM(0)::Start: end
2006-03-05 20:59:01.310 TVRec(2): SetFlags(SignalMonitorRunning,) -> 
RunMainLoop,AskAllowRecording,SignalMonitorRunning,RingBufferReset,
2006-03-05 20:59:01.312 TVRec(2): ClearFlags(WaitingForSignal,) -> 
RunMainLoop,AskAllowRecording,SignalMonitorRunning,RingBufferReset,
2006-03-05 20:59:01.314 TVRec(2): SetFlags(WaitingForSignal,) -> 
RunMainLoop,AskAllowRecording,WaitingForSignal,SignalMonitorRunning,RingBufferReset,
2006-03-05 20:59:01.315 TVRec(2): ClearFlags(NeedToStartRecorder,) -> 
RunMainLoop,AskAllowRecording,WaitingForSignal,SignalMonitorRunning,RingBufferReset,
2006-03-05 20:59:01.316 TVRec(2): SetFlags(NeedToStartRecorder,) -> 
RunMainLoop,AskAllowRecording,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,RingBufferReset,
2006-03-05 20:59:01.377 Started recording: Planet Earth "1/11 - From Pole to 
Pole": channel 3506 on cardid 2, sourceid 3
2006-03-05 20:59:01.397 TVRec(1): StartRecording(Midsomer Murders)
2006-03-05 20:59:01.399 TVRec(1): ClearFlags(AskAllowRecording,) -> 
RunMainLoop,RingBufferReset,
2006-03-05 20:59:01.562 TVRec(1): StartedRecording(0x9600cd0) 
fn(/usr/mythtv/recordings/103_20060305205900.mpg)
2006-03-05 20:59:01.567 write -> 14 51 
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2006-03-05 20:59:01.568 write -> 16 51 
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2006-03-05 20:59:01.567 TVRec(1): ClearFlags(CancelNextRecording,) -> 
RunMainLoop,RingBufferReset,
2006-03-05 20:59:01.570 TVRec(1): Changing from None to RecordingOnly
2006-03-05 20:59:01.571 TVRec(1): 
ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop,RingBufferReset,
2006-03-05 20:59:01.572 TVRec(1): SetFlags(AskAllowRecording,) -> 
RunMainLoop,AskAllowRecording,RingBufferReset,
2006-03-05 20:59:01.573 TVRec(1): Request: Program(yes) channel() input() 
flags(Recording,)
2006-03-05 20:59:01.574 TVRec(1): ClearFlags(PENDINGACTIONS,) -> 
RunMainLoop,AskAllowRecording,RingBufferReset,
2006-03-05 20:59:01.576 Global TVFormat Setting 'PAL'
2006-03-05 20:59:01.578 Input #0: 'Composite 0' schan() tun() v4l1(PAL) v4l2(PAL)
2006-03-05 20:59:01.579 Input #1: 'Composite 1' schan() tun() v4l1(PAL) v4l2(PAL)
2006-03-05 20:59:01.580 Input #2: 'Composite 2' schan() tun() v4l1(PAL) v4l2(PAL)
2006-03-05 20:59:01.581 Input #3: 'Composite 3' schan() tun() v4l1(PAL) v4l2(PAL)
2006-03-05 20:59:01.582 Input #4: 'Tuner 0' schan() tun() v4l1(PAL) v4l2(PAL)
2006-03-05 20:59:01.583 Input #5: 'Composite 4' schan() tun() v4l1(PAL) v4l2(PAL)
2006-03-05 20:59:01.584 Input #6: 'S-Video 0' schan(102) tun(101) v4l1(PAL) 
v4l2(PAL)
2006-03-05 20:59:01.585 Input #7: 'S-Video 1' schan() tun() v4l1(PAL) v4l2(PAL)
2006-03-05 20:59:01.586 Input #8: 'S-Video 2' schan() tun() v4l1(PAL) v4l2(PAL)
2006-03-05 20:59:01.587 Input #9: 'S-Video 3' schan() tun() v4l1(PAL) v4l2(PAL)
2006-03-05 20:59:01.588 Channel(/dev/video1): SetFormat(Default) fmt(PAL) input(6)
2006-03-05 20:59:01.589 Channel(/dev/video1)::SwitchToInput(in 6, '')
2006-03-05 20:59:01.642 Channel(/dev/video1): SetInputAndFormat(6, PAL) v4l v2
2006-03-05 20:59:01.644 Channel(/dev/video1)::SetChannelByString(103)
2006-03-05 20:59:01.646 ChannelBase(/dev/video1)::SetCachedATSCInfo(): RESET
2006-03-05 20:59:01.642 AutoExpire: Adding Programs to 'Do Not Expire' List
2006-03-05 20:59:01.663     3506 @ Sun Mar 5 20:59:00 2006 in use by recorder 
on pvr.fnxweb.co.uk
2006-03-05 20:59:01.664     103 @ Sun Mar 5 20:59:00 2006 in use by recorder 
on pvr.fnxweb.co.uk
2006-03-05 20:59:01.662 Channel(/dev/video1): SetFormat(Default) fmt(PAL) input(6)
2006-03-05 20:59:01.663 read  <- 13 35      QUERY_REMOTEENCODER 1[]:[]GET_STATE
2006-03-05 20:59:01.676 write -> 13 1       4
2006-03-05 20:59:01.678 External channel change: /usr/local/bin/skychannel 103
2006-03-05 20:59:01.689 Waiting for External Tuning program to exit
2006-03-05 20:59:01.690 read  <- 13 34      QUERY_RECORDER 1[]:[]GET_RECORDING
2006-03-05 20:59:02.723 ret_pid(24863) child(24863) status(0x0)
2006-03-05 20:59:02.726 External Tuning program no longer running
2006-03-05 20:59:02.727 External Tuning program exited with no error
2006-03-05 20:59:02.729 ChannelBase(/dev/video1)::SetCachedATSCInfo(103_0): 103_0
2006-03-05 20:59:02.729 TVRec(1): ClearFlags(NeedToStartRecorder,) -> 
RunMainLoop,AskAllowRecording,RingBufferReset,
2006-03-05 20:59:02.730 TVRec(1): SetFlags(NeedToStartRecorder,) -> 
RunMainLoop,AskAllowRecording,NeedToStartRecorder,RingBufferReset,
2006-03-05 20:59:02.731 TVRec(1): Starting Recorder
2006-03-05 20:59:02.857 TVRec(1): Using profile 'Default' to record
2006-03-05 20:59:02.874 RecBase(/dev/video1): SetRingBuffer(0xaef9d670) 
'/usr/mythtv/recordings/103_20060305205900.mpg'
2006-03-05 20:59:02.878 RecBase(/dev/video1): SetRecording(0x9600cd0) 
title(Midsomer Murders)
2006-03-05 20:59:02.889 write -> 13 1196    Midsomer Murders[]:[]Vixen's 
Run[]:[]Hang on a minute: a country ...
2006-03-05 20:59:02.946 VBI service:1, packet size:0, io size:0
2006-03-05 20:59:02.950 Started recording: Midsomer Murders "Vixen's Run": 
channel 103 on cardid 1, sourceid 1
2006-03-05 20:59:02.956 read  <- 13 35      QUERY_REMOTEENCODER 2[]:[]GET_STATE
2006-03-05 20:59:02.957 write -> 13 1       4
2006-03-05 20:59:02.959 write -> 14 45 
BACKEND_MESSAGE[]:[]SCHEDULE_CHANGE[]:[]empty
2006-03-05 20:59:02.959 write -> 16 45 
BACKEND_MESSAGE[]:[]SCHEDULE_CHANGE[]:[]empty
2006-03-05 20:59:02.960 TVRec(1): SetFlags(RecorderRunning,) -> 
RunMainLoop,AskAllowRecording,NeedToStartRecorder,RecorderRunning,RingBufferReset,
2006-03-05 20:59:02.961 TVRec(1): ClearFlags(NeedToStartRecorder,) -> 
RunMainLoop,AskAllowRecording,RecorderRunning,RingBufferReset,
2006-03-05 20:59:02.965 read  <- 13 34      QUERY_RECORDER 2[]:[]GET_RECORDING
2006-03-05 20:59:02.969 write -> 13 1515    Planet Earth[]:[]1/11 - From Pole 
to Pole[]:[]This latest blockbu...
2006-03-05 20:59:02.976 read  <- 13 35      QUERY_REMOTEENCODER 1[]:[]GET_STATE
2006-03-05 20:59:02.977 write -> 13 1       4
2006-03-05 20:59:03.002 read  <- 13 34      QUERY_RECORDER 1[]:[]GET_RECORDING
2006-03-05 20:59:03.004 write -> 13 1196    Midsomer Murders[]:[]Vixen's 
Run[]:[]Hang on a minute: a country ...
2006-03-05 20:59:03.011 read  <- 13 35      QUERY_REMOTEENCODER 2[]:[]GET_STATE
2006-03-05 20:59:03.012 write -> 13 1       4
2006-03-05 20:59:03.018 read  <- 13 34      QUERY_RECORDER 2[]:[]GET_RECORDING
2006-03-05 20:59:03.020 write -> 13 1515    Planet Earth[]:[]1/11 - From Pole 
to Pole[]:[]This latest blockbu...
2006-03-05 20:59:24.110 JobQueue::GetJobsInQueue: findJobs search bitmask 28, 
found 2 total jobs
2006-03-05 20:59:24.115 JobQueue::GetJobsInQueue: Ignore 'Flag Commercials' 
Job for 104 @ 20060303212900 in Finished state.
2006-03-05 20:59:24.117 JobQueue::GetJobsInQueue: Ignore 'Flag Commercials' 
Job for 440 @ 20060304222900 in Finished state.
2006-03-05 21:00:01.721 AutoExpire: Adding Programs to 'Do Not Expire' List
2006-03-05 21:00:01.724     3506 @ Sun Mar 5 20:59:00 2006 in use by recorder 
on pvr.fnxweb.co.uk
2006-03-05 21:00:01.726     103 @ Sun Mar 5 20:59:00 2006 in use by recorder 
on pvr.fnxweb.co.uk

...

Lots of (among other things):

2006-03-05 21:05:02.169     3506 @ Sun Mar 5 20:59:00 2006 in use by recorder 
on pvr.fnxweb.co.uk
2006-03-05 21:05:02.171     103 @ Sun Mar 5 20:59:00 2006 in use by recorder 
on pvr.fnxweb.co.uk

...


2006-03-05 21:59:08.869     3506 @ Sun Mar 5 20:59:00 2006 in use by recorder 
on pvr.fnxweb.co.uk
2006-03-05 21:59:08.870     103 @ Sun Mar 5 20:59:00 2006 in use by recorder 
on pvr.fnxweb.co.uk
2006-03-05 21:59:29.258 TVRec(2): SetFlags(AskAllowRecording,) -> 
RunMainLoop,AskAllowRecording,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,RingBufferReset,
2006-03-05 21:59:29.259 TVRec(2): ClearFlags(AskAllowRecording,) -> 
RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,RingBufferReset,
2006-03-05 22:00:02.509 JobQueue::GetJobsInQueue: findJobs search bitmask 28, 
found 2 total jobs
2006-03-05 22:00:02.512 JobQueue::GetJobsInQueue: Ignore 'Flag Commercials' 
Job for 104 @ 20060303212900 in Finished state.
2006-03-05 22:00:02.514 JobQueue::GetJobsInQueue: Ignore 'Flag Commercials' 
Job for 440 @ 20060304222900 in Finished state.
2006-03-05 22:00:02.581 TVRec(2): StartRecording(Two Pints of Lager and a 
Packet of Crisps)
2006-03-05 22:00:02.583 TVRec(2): ClearFlags(AskAllowRecording,) -> 
RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,RingBufferReset,
2006-03-05 22:00:02.584 TVRec(2): Changing from RecordingOnly to None
2006-03-05 22:00:02.585 TVRec(2): 
ClearFlags(FrontendReady,CancelNextRecording,) -> 
RunMainLoop,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,RingBufferReset,
2006-03-05 22:00:02.586 TVRec(2): SetFlags(AskAllowRecording,) -> 
RunMainLoop,AskAllowRecording,WaitingForSignal,NeedToStartRecorder,SignalMonitorRunning,RingBufferReset,
2006-03-05 22:00:02.587 TVRec(2): Request: Program(no) channel() input() 
flags(CloseRec,KillRingBuffer,)
2006-03-05 22:00:02.590 TVRec(2): TeardownSignalMonitor() -- begin
2006-03-05 22:00:02.591 DVBSM(0)::Stop: begin
2006-03-05 22:00:02.592 SM(0)::Stop: begin
2006-03-05 22:00:02.602 SM(0)::Stop: end
2006-03-05 22:00:02.604 DVBSM(0)::Stop: end
2006-03-05 22:00:02.605 DVBSM(0)::Stop: begin
2006-03-05 22:00:02.607 SM(0)::Stop: begin
2006-03-05 22:00:02.608 SM(0)::Stop: end
2006-03-05 22:00:02.609 DVBSM(0)::Stop: end
2006-03-05 22:00:02.610 DVBSM(0)::Stop: begin
2006-03-05 22:00:02.611 SM(0)::Stop: begin
2006-03-05 22:00:02.613 SM(0)::Stop: end
2006-03-05 22:00:02.614 DVBSM(0)::Stop: end
2006-03-05 22:00:02.615 DVBSM(0)::Stop: begin
2006-03-05 22:00:02.616 SM(0)::Stop: begin
2006-03-05 22:00:02.617 SM(0)::Stop: end
2006-03-05 22:00:02.618 DVBSM(0)::Stop: end
2006-03-05 22:00:02.619 SM(0)::Stop: begin
2006-03-05 22:00:02.620 SM(0)::Stop: end
2006-03-05 22:00:02.615 TVRec(2): TeardownSignalMonitor() -- end
2006-03-05 22:00:02.622 TVRec(2): ClearFlags(SignalMonitorRunning,) -> 
RunMainLoop,AskAllowRecording,WaitingForSignal,NeedToStartRecorder,RingBufferReset,
2006-03-05 22:00:02.623 TVRec(2): ClearFlags(WaitingForSignal,) -> 
RunMainLoop,AskAllowRecording,NeedToStartRecorder,RingBufferReset,
2006-03-05 22:00:02.626 TVRec(2): FinishedRecording(Planet Earth) in recgroup: 
Wildlife
2006-03-05 22:00:02.629 Finished recording Planet Earth "1/11 - From Pole to 
Pole": channel 3506
2006-03-05 22:00:02.644 TVRec(2): ClearFlags(PENDINGACTIONS,) -> 
RunMainLoop,AskAllowRecording,RingBufferReset,
2006-03-05 22:00:02.646 TVRec(2): ClearFlags(CancelNextRecording,) -> 
RunMainLoop,AskAllowRecording,RingBufferReset,
2006-03-05 22:00:02.766 TVRec(2): StartedRecording(0x94aba78) 
fn(/usr/mythtv/recordings/3501_20060305220000.mpg)
2006-03-05 22:00:02.771 TVRec(2): ClearFlags(CancelNextRecording,) -> 
RunMainLoop,AskAllowRecording,RingBufferReset,
2006-03-05 22:00:02.773 TVRec(2): Changing from None to RecordingOnly
2006-03-05 22:00:02.774 TVRec(2): 
ClearFlags(FrontendReady,CancelNextRecording,) -> 
RunMainLoop,AskAllowRecording,RingBufferReset,
2006-03-05 22:00:02.775 TVRec(2): SetFlags(AskAllowRecording,) -> 
RunMainLoop,AskAllowRecording,RingBufferReset,
2006-03-05 22:00:02.776 TVRec(2): Request: Program(yes) channel() input() 
flags(Recording,)
2006-03-05 22:00:02.777 TVRec(2): ClearFlags(PENDINGACTIONS,) -> 
RunMainLoop,AskAllowRecording,RingBufferReset,

.. then alleged start of next prog.

-- 
[neil at fnx ~]# rm -f .signature
[neil at fnx ~]# ls -l .signature
ls: .signature: No such file or directory
[neil at fnx ~]# exit

More information about the mythtv-users mailing list