[mythtv-users] Zero-length recording files and DVB-T (Avermedia 771) live TV channel lock problems

Tue Mar 21 18:00:58 UTC 2006

I recently downloaded and upgraded to Myth0.19 and I
am having all sorts of trouble that I didn't have with
Myth0.18.  Thanks for any solutions or work-arounds.

Here is the mythbackend info:

version:/usr/local/mythtv/bin/mythbackend --version
Library API version: 0.19.20060226-1
Source code version: 9415
Options compiled in:
 linux release using_v4l using_oss using_alsa
using_arts using_ivtv using_dbox2 using_lirc
using_joystick_menu using_dvb using_dvb_eit using_x11
using_xv using_xrandr using_frontend using_backend

I am using an Avermedia 771 DVB-T card:

0000:02:0e.0 Multimedia video controller: Brooktree
Corporation Bt878 Video Capture (rev 11)
0000:02:0e.1 Multimedia controller: Brooktree
Corporation Bt878 Audio Capture (rev 11)

With live TV, I can't seem to get the channels to lock
on.  Sometimes a timeout message comes on screen and
other times I get a "video error" message.

In this sequence, I don't get sync, then I change the
channel and do get sync (BBC2 missing link), then I
change the channel to BBC1 and don't get sync.

2006-03-21 17:52:19.226 MainServer::HandleAnnounce
Monitor
2006-03-21 17:52:19.239 adding: myth as a client
(events: 0)
2006-03-21 17:52:19.275 MainServer::HandleAnnounce
Monitor
2006-03-21 17:52:19.280 adding: myth as a client
(events: 1)
2006-03-21 17:52:19.280 MainServer::HandleAnnounce
Playback
2006-03-21 17:52:19.297 adding: myth as a client
(events: 0)
2006-03-21 17:52:19.313 TVRec(1): Changing from None
to WatchingLiveTV
2006-03-21 17:52:42.910 TVRec(1): PauseRecorder()
called with no recorder
2006-03-21 17:52:43.287 Finished recording Simply
Delicious: channel 1029
0: start_time: 857.475 duration: -9223372036854.775
stream: start_time: 9527.500 duration:
-9223372036854.775 bitrate=0 kb/s
2006-03-21 17:52:46.687 AFD: Opened codec 0x83311e0,
id(MPEG1VIDEO) type(Video)
2006-03-21 17:52:46.709 NVP: Disabling Audio,
params(-1,-1,-1)
2006-03-21 17:52:46.717 NVP: Disabling Audio,
params(0,-1,-1)
2006-03-21 17:54:58.506 TVRec(1): PauseRecorder()
called with no recorder
2006-03-21 17:54:58.702 Finished recording Neighbours:
channel 1000
2006-03-21 17:54:59.557 SIParser: Setting
ATSCStreamData
2006-03-21 17:54:59.620 SIParser: Setting
DVBStreamData
2006-03-21 17:54:59.631 DVB#0 DVB SI Table Parser
Started
2006-03-21 17:54:59.636 SIParser:
SetStreamData(0x82e9ec0)
2006-03-21 17:54:59.644 SIParser: Setting
ATSCStreamData
2006-03-21 17:54:59.804 Finished recording Weakest
Link: channel 1001
2006-03-21 17:54:59.907 Finished recording Weakest
Link: channel 1001
0: start_time: 857.475 duration: -9223372036854.775
stream: start_time: 9527.500 duration:
-9223372036854.775 bitrate=0 kb/s
2006-03-21 17:55:02.130 AFD: Opened codec 0x82fb8b0,
id(MPEG1VIDEO) type(Video)
2006-03-21 17:55:02.149 NVP: Disabling Audio,
params(-1,-1,-1)
2006-03-21 17:55:02.157 NVP: Disabling Audio,
params(0,-1,-1)
0: start_time: 857.475 duration: -9223372036854.775
stream: start_time: 9527.500 duration:
-9223372036854.775 bitrate=0 kb/s
2006-03-21 17:55:06.283 AFD: Opened codec 0x822d6a0,
id(MPEG1VIDEO) type(Video)
2006-03-21 17:55:06.304 NVP: Disabling Audio,
params(-1,-1,-1)
2006-03-21 17:55:06.312 NVP: Disabling Audio,
params(0,-1,-1)
2006-03-21 17:55:07.844 Finished recording Weakest
Link: channel 1001
[mpegts @ 0xb7507f40]Parser not found for Codec Id:
94212 !
[mpegts @ 0xb7507f40]Parser not found for Codec Id:
94212 !
[mpegts @ 0xb7507f40]Parser not found for Codec Id:
94212 !
[mpegts @ 0xb7507f40]Parser not found for Codec Id:
94212 !
0: start_time: 5332.240 duration: 0.637
1: start_time: 5332.204 duration: 0.639
2: start_time: 5332.204 duration: 0.673
3: start_time: 5332.204 duration: 0.673
4: start_time: 5332.204 duration: 0.673
5: start_time: 5332.204 duration: 0.673
6: start_time: 5332.204 duration: 0.673
7: start_time: 5332.204 duration: 0.673
8: start_time: 5332.204 duration: 0.673
9: start_time: 5332.204 duration: 0.673
stream: start_time: 59246.711 duration: 7.475
bitrate=4545 kb/s
2006-03-21 17:55:11.199 AFD: Opened codec 0x83311e0,
id(MPEG2VIDEO) type(Video)
2006-03-21 17:55:11.214 AFD: Opened codec 0x8224b30,
id(MP3) type(Audio)
2006-03-21 17:55:11.223 AFD: Opened codec 0x822af50,
id(DVB_SUBTITLE) type(Subtitle)
2006-03-21 17:55:11.231 AFD: Opened codec 0x8304810,
id(MP3) type(Audio)
[mpeg2video @ 0xb7424a64]ac-tex damaged at 9 35
2006-03-21 17:55:53.944 TVRec(1): Changing from
WatchingLiveTV to None
2006-03-21 17:55:54.091 Finished recording Neighbours:
channel 1000
2006-03-21 17:55:54.209 Finished recording Neighbours:
channel 1000

With Recordings, I am getting a zero-length file. 
Here is the log of the attempted recording:

2006-03-21 15:59:02.993 TVRec(1): Changing from None
to RecordingOnly
2006-03-21 15:59:03.041 TVRec(1): HW Tuner: 1->1
2006-03-21 15:59:03.114 Started recording: Delhi Belly
"Seafood": channel 1029 on cardid 1, sourceid 1
2006-03-21 15:59:03.525 SIParser: Setting
ATSCStreamData
2006-03-21 15:59:03.541 SIParser: Setting
DVBStreamData
2006-03-21 15:59:03.549 DVB#0 DVB SI Table Parser
Started
2006-03-21 15:59:03.557 SIParser:
SetStreamData(0x8264450)
2006-03-21 15:59:03.566 SIParser: Setting
ATSCStreamData
2006-03-21 16:32:00.453 TVRec(1): Changing from
RecordingOnly to None
2006-03-21 16:32:01.232 Reschedule requested for id 0.
2006-03-21 16:32:01.233 Finished recording Delhi Belly
"Seafood": channel 1029
2006-03-21 16:32:01.279 Scheduled 20 items in 0.0 =
0.01 match + 0.04 place
2006-03-21 16:32:01.290 Preview Error: Previewer file
'/myth/record//1029_20060321155900.mpg' is not valid.
2006-03-21 16:32:01.336 Finished recording Delhi Belly
"Seafood": channel 1029
2006-03-21 16:32:14.353 JobQueue: Commercial Flagging
Starting for Delhi Belly "Seafood" recorded from
channel 1029 at Tue Mar 21 15:59:00 2006
2006-03-21 16:32:15.286 Using runtime prefix =
/usr/local
2006-03-21 16:32:15.362 New DB connection, total: 1
2006-03-21 16:32:15.390 Connected to database
'mythconverg' at host: localhost
2006-03-21 16:32:15.408 New DB connection, total: 2
2006-03-21 16:32:15.412 Connected to database
'mythconverg' at host: localhost
2006-03-21 16:32:15.423
RingBuf(/myth/record//1029_20060321155900.mpg):
Invalid file (fd 9) when opening
'/myth/record//1029_20060321155900.mpg'. 12 retries
remaining.
2006-03-21 16:32:15.930
RingBuf(/myth/record//1029_20060321155900.mpg):
Invalid file (fd 9) when opening
'/myth/record//1029_20060321155900.mpg'. 11 retries
remaining.
2006-03-21 16:32:16.436
RingBuf(/myth/record//1029_20060321155900.mpg):
Invalid file (fd 9) when opening
'/myth/record//1029_20060321155900.mpg'. 10 retries
remaining.
2006-03-21 16:32:16.942
RingBuf(/myth/record//1029_20060321155900.mpg):
Invalid file (fd 9) when opening
'/myth/record//1029_20060321155900.mpg'. 9 retries
remaining.
2006-03-21 16:32:17.448
RingBuf(/myth/record//1029_20060321155900.mpg):
Invalid file (fd 9) when opening
'/myth/record//1029_20060321155900.mpg'. 8 retries
remaining.
2006-03-21 16:32:17.954
RingBuf(/myth/record//1029_20060321155900.mpg):
Invalid file (fd 9) when opening
'/myth/record//1029_20060321155900.mpg'. 7 retries
remaining.
2006-03-21 16:32:18.459
RingBuf(/myth/record//1029_20060321155900.mpg):
Invalid file (fd 9) when opening
'/myth/record//1029_20060321155900.mpg'. 6 retries
remaining.
2006-03-21 16:32:18.965
RingBuf(/myth/record//1029_20060321155900.mpg):
Invalid file (fd 9) when opening
'/myth/record//1029_20060321155900.mpg'. 5 retries
remaining.
2006-03-21 16:32:19.471
RingBuf(/myth/record//1029_20060321155900.mpg):
Invalid file (fd 9) when opening
'/myth/record//1029_20060321155900.mpg'. 4 retries
remaining.
2006-03-21 16:32:20.027
RingBuf(/myth/record//1029_20060321155900.mpg):
Invalid file (fd 9) when opening
'/myth/record//1029_20060321155900.mpg'. 3 retries
remaining.
2006-03-21 16:32:20.541
RingBuf(/myth/record//1029_20060321155900.mpg):
Invalid file (fd 9) when opening
'/myth/record//1029_20060321155900.mpg'. 2 retries
remaining.
2006-03-21 16:32:21.047
RingBuf(/myth/record//1029_20060321155900.mpg):
Invalid file (fd 9) when opening
'/myth/record//1029_20060321155900.mpg'. 1 retries
remaining.
2006-03-21 16:32:21.553
RingBuf(/myth/record//1029_20060321155900.mpg):
Invalid file (fd 9) when opening
'/myth/record//1029_20060321155900.mpg'. 0 retries
remaining.
2006-03-21 16:32:22.096 Connecting to backend server:
127.0.0.1:6543 (try 1 of 5)
2006-03-21 16:32:22.121 Using protocol version 27
2006-03-21 16:32:22.135 MainServer::HandleAnnounce
Monitor
2006-03-21 16:32:22.138 adding: myth as a client
(events: 0)
2006-03-21 16:32:22.198 NVP::OpenFile(): Error, file
not found: /myth/record//1029_20060321155900.mpg
2006-03-21 16:32:22.214 Unknown socket closing
2006-03-21 16:32:22.224 JobQueue: Commercial Flagging
Finished, 0 break(s) found.
2006-03-21 16:32:22.233 Preview Error: Previewer file
'/myth/record//1029_20060321155900.mpg' is not valid.

In my syslog and dmesg I am getting some strange logs:

syslog:

Mar 21 15:59:03 localhost kernel: [4316013.243000]
bt878(0): irq FBUS risc_pc=36472008

dmesg:
[4316012.902000] bt878(0): irq FBUS risc_pc=364721e8