Greetings. I have a recently assembled Mythtv box, that using a newly purchased PVR 350 as its tuner. It will record without problems. Sometimes the card recordings will end prematurely and any subsequent recordings have a file size of 0 bytes.
Both mythtvbackend and kernel logs show nothing really strange at the time when recordings stop. However when the next recording starts mythbackend starts reporting a whack of device or resource busy errors. The kernel log has nothing out of the ordinary at the time when recording stops. Except for the disappearance of ivtv_unmap_user_dma info messages. This message seems to flood the logs while anything captures from /dev/video0. I've read that the Hauppauge PVR 350 is prone to overheating. Which would explain the random nature of the problem. But my symptoms are not consistent with the Internet's description of an overheating Hauppauge PVR 350. I've tried many kernels, and versions of the ivtv/v4l-dvb driver. Which makes me think the problem lies with the hardware and not the driver. I just want to confirm it before sending the card away. Thanks in advance, Emery Relevant logs: From /var/log/mythtv/mythbackend.log between Nov 8 11:00 and 11:30. A.K.A: From the time the last partially successful capture began, until the time of the first failed capture. The recording stopped prematurely at 11:16 2008-11-08 10:59:07.048 Scheduled 891 items in 6.7 = 0.02 match + 6.69 place 2008-11-08 10:59:29.398 TVRec(1): ASK_RECORDING 1 29 0 0 2008-11-08 11:00:03.051 TVRec(1): Changing from None to RecordingOnly 2008-11-08 11:00:03.205 TVRec(1): HW Tuner: 1->1 2008-11-08 11:00:04.440 ret_pid(11579) child(11579) status(0x0) 2008-11-08 11:00:04.447 External Tuning program exited with no error 2008-11-08 11:00:04.591 AutoExpire: CalcParams(): Max required Free Space: 2.0 GB w/freq: 15 min 2008-11-08 11:00:04.604 Started recording: Horsepower TV "Boneyard Bowtie and Bloo pers": channel 1628 on cardid 1, sourceid 1 2008-11-08 11:00:42.532 JobQueue: Commercial Flagging Starting for Horsepower TV " Boneyard Bowtie and Bloopers" recorded from channel 1628 at Sat Nov 8 11:00:00 2008 2008-11-08 11:00:42.958 Using runtime prefix = /usr 2008-11-08 11:00:42.963 Empty LocalHostName. 2008-11-08 11:00:42.988 Using localhost value of mythtv-backend 2008-11-08 11:00:43.844 Cannot find default UPnP backend 2008-11-08 11:00:43.868 New DB connection, total: 1 2008-11-08 11:00:43.937 Connected to database 'mythconverg' at host: 192.168.15.12 <http://192.168.15.12>1 2008-11-08 11:00:43.997 Closing DB connection named 'DBManager0' 2008-11-08 11:00:44.000 Deleting UPnP client... 2008-11-08 11:00:44.746 Connected to database 'mythconverg' at host: 192.168.15.12 <http://192.168.15.12>1 2008-11-08 11:00:44.770 New DB connection, total: 2 2008-11-08 11:00:44.828 Connected to database 'mythconverg' at host: 192.168.15.12 <http://192.168.15.12>1 2008-11-08 11:00:44.908 Connecting to backend server: 192.168.15.121:6543 <http://192.168.15.121:6543> (try 1 of 5) 2008-11-08 11:00:44.921 Using protocol version 40 2008-11-08 11:00:44.961 MainServer::HandleAnnounce Monitor 2008-11-08 11:00:45.003 adding: mythtv-backend as a client (events: 0) 2008-11-08 11:00:45.040 MainServer::HandleAnnounce Monitor 2008-11-08 11:00:45.053 adding: mythtv-backend as a client (events: 1) 2008-11-08 11:00:45.396 AFD: Opened codec 0x8a6d250, id(MPEG2VIDEO) type(Video) 2008-11-08 11:00:45.457 AFD: codec MP2 has 2 channels 2008-11-08 11:00:45.525 AFD: Opened codec 0x8a6d6d0, id(MP2) type(Audio) 2008-11-08 11:01:43.161 AutoExpire: CalcParams(): Max required Free Space: 2.0 GB w/freq: 15 min 2008-11-08 11:01:53.697 UPnpMedia: BuildMediaMap VIDEO scan starting in :/var/lib/mythtv/videos: 2008-11-08 11:01:53.704 UPnpMedia: BuildMediaMap Done. Found 0 objects *2008-11-08 11:16:33.234 [mpeg2video @ 0xb73a1764]invalid cbp at 35 8 2008-11-08 11:16:33.270 [mpeg2video @ 0xb73a1764]Warning MVs not available *2008-11-08 11:16:35.695 Using runtime prefix = /usr 2008-11-08 11:16:35.837 Empty LocalHostName. 2008-11-08 11:16:35.862 Using localhost value of mythtv-backend 2008-11-08 11:16:36.360 Cannot find default UPnP backend 2008-11-08 11:16:36.496 New DB connection, total: 1 2008-11-08 11:16:36.595 Connected to database 'mythconverg' at host: 192.168.15.12 <http://192.168.15.12> 1 2008-11-08 11:16:36.599 Closing DB connection named 'DBManager0' 2008-11-08 11:16:36.601 Deleting UPnP client... 2008-11-08 11:16:37.662 Connected to database 'mythconverg' at host: 192.168.15.12 <http://192.168.15.12> 1 2008-11-08 11:16:37.666 New DB connection, total: 2 2008-11-08 11:16:37.668 Connected to database 'mythconverg' at host: 192.168.15.121 <http://192.168.15.121> 2008-11-08 11:16:37.673 Current Schema Version: 1214 2008-11-08 11:16:40.519 AFD: Opened codec 0xa165720, id(MPEG2VIDEO) type(Video) 2008-11-08 11:16:40.523 AFD: codec MP2 has 2 channels 2008-11-08 11:16:40.525 AFD: Opened codec 0xa165ba0, id(MP2) type(Audio) 2008-11-08 11:16:40.942 Preview: Grabbed preview '/mythtv/1628_20081108110000.mpg' [EMAIL PROTECTED] 2008-11-08 11:16:43.335 AutoExpire: CalcParams(): Max required Free Space: 2.0 GB w/freq: 15 min 2008-11-08 11:29:00.080 Reschedule requested for id 0. 2008-11-08 11:29:09.865 Scheduled 890 items in 9.8 = 3.11 match + 6.67 place 2008-11-08 11:29:30.083 TVRec(1): ASK_RECORDING 1 29 0 0 2008-11-08 11:30:00.091 TVRec(1): Changing from RecordingOnly to None 2008-11-08 11:30:00.175 Finished recording Horsepower TV "Boneyard Bowtie and Bloopers": channel 1628 2008-11-08 11:30:00.241 Finished recording Horsepower TV "Boneyard Bowtie and Bloopers": channel 1628 2008-11-08 11:30:00.472 Using runtime prefix = /usr 2008-11-08 11:30:00.479 Empty LocalHostName. 2008-11-08 11:30:00.480 Using localhost value of mythtv-backend 2008-11-08 11:30:00.906 Cannot find default UPnP backend 2008-11-08 11:30:00.937 New DB connection, total: 1 2008-11-08 11:30:00.947 Connected to database 'mythconverg' at host: 192.168.15.121 <http://192.168.15.121> 2008-11-08 11:30:00.950 Closing DB connection named 'DBManager0' 2008-11-08 11:30:00.952 Deleting UPnP client... 2008-11-08 11:30:02.066 Connected to database 'mythconverg' at host: 192.168.15.121 <http://192.168.15.121> 2008-11-08 11:30:02.074 New DB connection, total: 2 2008-11-08 11:30:02.101 Connected to database 'mythconverg' at host: 192.168.15.121 <http://192.168.15.121> 2008-11-08 11:30:02.131 Current Schema Version: 1214 2008-11-08 11:30:02.946 TVRec(1): Changing from None to RecordingOnly 2008-11-08 11:30:03.017 TVRec(1): HW Tuner: 1->1 2008-11-08 11:30:04.426 ret_pid(11679) child(11679) status(0x0) 2008-11-08 11:30:04.430 External Tuning program exited with no error *2008-11-08 11:30:04.530 MPEGRec(/dev/video0) Error: Could not set Audio Sampling Frequency to 1 eno: Device or resource busy (16) 2008-11-08 11:30:04.594 MPEGRec(/dev/video0) Error: Could not set Audio L2 Bitrate to 13 eno: Device or resource busy (16) 2008-11-08 11:30:04.652 MPEGRec(/dev/video0) Error: Could not set Video Peak Bitrate to 6000000 eno: Device or resource busy (16) 2008-11-08 11:30:04.653 MPEGRec(/dev/video0) Error: Could not set Video Average Bitrate to 4500000 eno: Device or resource busy (16) 2008-11-08 11:30:04.678 MPEGRec(/dev/video0) Error: Could not set MPEG Stream type to 0 eno: Device or resource busy (16) 2008-11-08 11:30:04.694 MPEGRec(/dev/video0) Error: error reading from: /dev/video0 eno: Device or resource busy (16) 2008-11-08 11:30:04.746 MPEGRec(/dev/video0) Error: error reading from: /dev/video0 eno: Device or resource busy (16) 2008-11-08 11:30:04.768 MPEGRec(/dev/video0) Error: error reading from: /dev/video0 eno: Device or resource busy (16) *The last error repeats as long as the box is scheduled to be recording. ==================================== /var/log/messages regarding ivtv initialization Nov 8 13:32:14 mythtv-backend kernel: [ 45.261591] ivtv: Start initialization, version 1.4.0 Nov 8 13:32:14 mythtv-backend kernel: [ 45.269950] ivtv0: Initializing card #0 Nov 8 13:32:14 mythtv-backend kernel: [ 45.269961] ivtv0: Autodetected Hauppauge card (cx23415 based) Nov 8 13:32:14 mythtv-backend kernel: [ 45.270125] ivtv0 info: base addr: 0xe8000000 Nov 8 13:32:14 mythtv-backend kernel: [ 45.270129] ivtv0 info: Enabling pci device Nov 8 13:32:14 mythtv-backend kernel: [ 45.270160] ivtv 0000:00:0e.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17 Nov 8 13:32:14 mythtv-backend kernel: [ 45.270173] ivtv0 info: Bus Mastering Enabled. Nov 8 13:32:14 mythtv-backend kernel: [ 45.270180] ivtv0: Unreasonably low latency timer, setting to 64 (was 32) Nov 8 13:32:14 mythtv-backend kernel: [ 45.270192] ivtv0 info: 2051 (rev 1) at 00:0e.0, irq: 17, latency: 64, memory: 0xe8000000 Nov 8 13:32:14 mythtv-backend kernel: [ 45.270196] ivtv0 info: attempting ioremap at 0xe8000000 len 0x00800000 Nov 8 13:32:14 mythtv-backend kernel: [ 45.270619] ivtv0 info: attempting ioremap at 0xe9000000 len 0x00800000 Nov 8 13:32:14 mythtv-backend kernel: [ 45.271035] ivtv0 info: attempting ioremap at 0xea000000 len 0x00010000 Nov 8 13:32:14 mythtv-backend kernel: [ 45.271043] ivtv0 info: activating i2c... Nov 8 13:32:14 mythtv-backend kernel: [ 45.271209] ivtv0 info: Active card count: 1. Nov 8 13:32:14 mythtv-backend kernel: [ 45.324118] tveeprom 1-0050: Hauppauge model 48132, rev K268, serial# 10491371 Nov 8 13:32:14 mythtv-backend kernel: [ 45.324125] tveeprom 1-0050: tuner model is LG TAPE H001F MK3 (idx 68, type 47) Nov 8 13:32:14 mythtv-backend kernel: [ 45.324132] tveeprom 1-0050: TV standards NTSC(M) (eeprom 0x08) Nov 8 13:32:14 mythtv-backend kernel: [ 45.324136] tveeprom 1-0050: audio processor is MSP4448 (idx 27) Nov 8 13:32:14 mythtv-backend kernel: [ 45.324142] tveeprom 1-0050: decoder processor is SAA7115 (idx 19) Nov 8 13:32:14 mythtv-backend kernel: [ 45.324147] tveeprom 1-0050: has radio, has IR receiver, has no IR transmitter Nov 8 13:32:14 mythtv-backend kernel: [ 45.324153] ivtv0: Autodetected Hauppauge WinTV PVR-350 Nov 8 13:32:14 mythtv-backend kernel: [ 45.324157] ivtv0 info: NTSC tuner detected Nov 8 13:32:14 mythtv-backend kernel: [ 45.734647] ivtv0 info: Loaded module tuner Nov 8 13:32:14 mythtv-backend kernel: [ 45.977006] ivtv0 info: Loaded module saa7115 Nov 8 13:32:14 mythtv-backend kernel: [ 46.195388] ivtv0 info: Loaded module saa7127 Nov 8 13:32:14 mythtv-backend kernel: [ 46.351040] ivtv0 info: Loaded module msp3400 Nov 8 13:32:14 mythtv-backend kernel: [ 46.375866] saa7115 1-0021: saa7115 found (1f7115d0e100000) @ 0x42 (ivtv i2c driver #0) Nov 8 13:32:14 mythtv-backend kernel: [ 46.440236] input: ImPS/2 Generic Wheel Mouse as /devices/platform/i8042/serio1/input/input5 Nov 8 13:32:14 mythtv-backend kernel: [ 46.542103] parport_pc 00:09: reported by Plug and Play ACPI Nov 8 13:32:14 mythtv-backend kernel: [ 46.542169] parport0: PC-style at 0x378 (0x778), irq 7, dma 3 [PCSPP,TRISTATE,COMPAT,ECP,DMA] Nov 8 13:32:14 mythtv-backend kernel: [ 47.550343] saa7127 1-0044: saa7129 found @ 0x88 (ivtv i2c driver #0) Nov 8 13:32:14 mythtv-backend kernel: [ 47.584955] msp3400 1-0040: MSP4448G-B3 found @ 0x80 (ivtv i2c driver #0) Nov 8 13:32:14 mythtv-backend kernel: [ 47.584962] msp3400 1-0040: msp3400 supports radio, mode is autodetect and autoselect Nov 8 13:32:14 mythtv-backend kernel: [ 48.000521] tuner 1-0043: chip found @ 0x86 (ivtv i2c driver #0) Nov 8 13:32:14 mythtv-backend kernel: [ 48.280417] tda9887 1-0043: creating new instance Nov 8 13:32:14 mythtv-backend kernel: [ 48.280423] tda9887 1-0043: tda988[5/6/7] found Nov 8 13:32:14 mythtv-backend kernel: [ 48.281795] tuner 1-0061: chip found @ 0xc2 (ivtv i2c driver #0) Nov 8 13:32:14 mythtv-backend kernel: [ 48.343503] tuner-simple 1-0061: creating new instance Nov 8 13:32:14 mythtv-backend kernel: [ 48.343511] tuner-simple 1-0061: type set to 47 (LG NTSC (TAPE series)) Nov 8 13:32:14 mythtv-backend kernel: [ 48.357068] ivtv0 info: Allocate DMA encoder MPG stream: 512 x 32768 buffers (16384kB total) Nov 8 13:32:14 mythtv-backend kernel: [ 48.357879] ivtv0 info: Allocate DMA encoder YUV stream: 640 x 32768 buffers (20480kB total) Nov 8 13:32:14 mythtv-backend kernel: [ 48.358981] ivtv0 info: Allocate DMA encoder VBI stream: 61 x 17472 buffers (1040kB total) Nov 8 13:32:14 mythtv-backend kernel: [ 48.359066] ivtv0 info: Allocate DMA encoder PCM stream: 143 x 4608 buffers (643kB total) Nov 8 13:32:14 mythtv-backend kernel: [ 48.359241] ivtv0 info: Allocate DMA decoder MPG stream: 16 x 65536 buffers (1024kB total) Nov 8 13:32:14 mythtv-backend kernel: [ 48.359285] ivtv0 info: Allocate decoder VBI stream: 29 x 2304 buffers (65kB total) Nov 8 13:32:15 mythtv-backend kernel: [ 48.359316] ivtv0 info: Allocate DMA decoder YUV stream: 16 x 65536 buffers (1024kB total) Nov 8 13:32:15 mythtv-backend kernel: [ 48.359718] ivtv0: Registered device video0 for encoder MPG (16384 kB) Nov 8 13:32:15 mythtv-backend kernel: [ 48.359800] ivtv0: Registered device video32 for encoder YUV (20480 kB) Nov 8 13:32:15 mythtv-backend kernel: [ 48.359864] ivtv0: Registered device vbi0 for encoder VBI (1024 kB) Nov 8 13:32:15 mythtv-backend kernel: [ 48.359926] ivtv0: Registered device video24 for encoder PCM (640 kB) Nov 8 13:32:15 mythtv-backend kernel: [ 48.359984] ivtv0: Registered device radio0 for encoder radio Nov 8 13:32:15 mythtv-backend kernel: [ 48.360102] ivtv0: Registered device video16 for decoder MPG (1024 kB) Nov 8 13:32:15 mythtv-backend kernel: [ 48.360167] ivtv0: Registered device vbi8 for decoder VBI (64 kB) Nov 8 13:32:15 mythtv-backend kernel: [ 48.360226] ivtv0: Registered device vbi16 for decoder VOUT Nov 8 13:32:15 mythtv-backend kernel: [ 48.360284] ivtv0: Registered device video48 for decoder YUV (1024 kB) Nov 8 13:32:15 mythtv-backend kernel: [ 48.360290] ivtv0: Initialized card #0: Hauppauge WinTV PVR-350 Nov 8 13:32:15 mythtv-backend kernel: [ 48.360512] Intel ICH 0000:00:02.7: PCI INT C -> GSI 18 (level, low) -> IRQ 18 Nov 8 13:32:15 mythtv-backend kernel: [ 48.360626] ivtv: End initialization ===================================== /var/log/messages: From the same time period covered in the mythtv logs, with "ivtv0 info: ivtv_unmap_user_dma" removed via grep -v Nov 8 11:00:03 mythtv-backend kernel: [32471.867785] ivtv0 info: Input unchanged Nov 8 11:00:03 mythtv-backend kernel: [32471.869123] ivtv0 info: Mute Nov 8 11:00:03 mythtv-backend kernel: [32471.869136] ivtv0 info: v4l2 ioctl: set frequency 980 Nov 8 11:00:03 mythtv-backend kernel: [32471.902239] ivtv0 info: Unmute Nov 8 11:00:03 mythtv-backend kernel: [32471.950615] ivtv0 info: Mute Nov 8 11:00:03 mythtv-backend kernel: [32471.950642] ivtv0 info: v4l2 ioctl: set frequency 980 Nov 8 11:00:03 mythtv-backend kernel: [32471.971029] ivtv0 info: Unmute Nov 8 11:00:04 mythtv-backend kernel: [32473.155303] ivtv0 info: Start encoder stream encoder MPG Nov 8 11:00:04 mythtv-backend kernel: [32473.183982] ivtv0 info: Setup VBI API header 0x0000bd03 pkts 1 buffs 4 ln 24 sz 1456 Nov 8 11:00:04 mythtv-backend kernel: [32473.184085] ivtv0 info: Setup VBI start 0x002fea04 frames 4 fpi 1 Nov 8 11:00:04 mythtv-backend kernel: [32473.187327] ivtv0 info: PGM Index at 0x00180150 with 400 elements Nov 8 11:39:57 mythtv-backend -- MARK -- Nov 8 11:59:57 mythtv-backend -- MARK -- -- Emery Finkelstein <insert randomly selected signature here> _______________________________________________ ivtv-users mailing list [email protected] http://ivtvdriver.org/mailman/listinfo/ivtv-users
