I was about to test the performance of vdr when I stumbled on this message
ERROR: /dev/dvb/adapter0/demux0: Too many open files
I do not recall seeing this earlier. This came when fourth simultaneous recording started.
Is this a vdr, dvb, or firmware issue? Seems like dvb but I really do not know.
This is what was in the log after the fourth recording
Feb 19 21:53:00 vdr: [2226] timer 4 (7 2153-2200 'TestRec4') start Feb 19 21:53:00 vdr: [2226] record /srv/vdr/TestRec4/2007-02-19.21.53.50.99.rec Feb 19 21:53:00 vdr: [2226] ERROR: /dev/dvb/adapter0/demux0: Too many open files Feb 19 21:53:00 vdr: [2226] ERROR (dvbdevice.c,673): Too many open files Feb 19 21:53:00 vdr: [2226] ERROR: can't set PID 680 on device 1 Feb 19 21:53:00 vdr: [2226] ERROR (dvbdevice.c,688): Bad file descriptor Feb 19 21:53:01 vdr: [2226] timer 4 (7 2153-2200 'TestRec4') stop Feb 19 21:53:01 vdr: [2226] timer 4 (7 2153-2200 'TestRec4') start Feb 19 21:53:01 vdr: [2226] record /srv/vdr/TestRec4/2007-02-19.21.53.50.99.rec Feb 19 21:53:01 vdr: [2226] ERROR: /dev/dvb/adapter0/demux0: Too many open files Feb 19 21:53:01 vdr: [2226] ERROR (dvbdevice.c,673): Too many open files Feb 19 21:53:01 vdr: [2226] ERROR: can't set PID 680 on device 1 Feb 19 21:53:01 vdr: [2226] ERROR (dvbdevice.c,688): Bad file descriptor Feb 19 21:53:02 vdr: [2226] timer 4 (7 2153-2200 'TestRec4') stop Feb 19 21:53:03 vdr: [2226] timer 4 (7 2153-2200 'TestRec4') start Feb 19 21:53:03 vdr: [2226] record /srv/vdr/TestRec4/2007-02-19.21.53.50.99.rec Feb 19 21:53:03 vdr: [2226] ERROR: /dev/dvb/adapter0/demux0: Too many open files Feb 19 21:53:03 vdr: [2226] ERROR (dvbdevice.c,673): Too many open files Feb 19 21:53:03 vdr: [2226] ERROR: can't set PID 680 on device 1 Feb 19 21:53:03 vdr: [2226] ERROR (dvbdevice.c,688): Bad file descriptor Feb 19 21:53:04 vdr: [2226] timer 4 (7 2153-2200 'TestRec4') stop Feb 19 21:53:05 vdr: [2226] timer 4 (7 2153-2200 'TestRec4') start Feb 19 21:53:05 vdr: [2226] record /srv/vdr/TestRec4/2007-02-19.21.53.50.99.rec Feb 19 21:53:05 vdr: [2226] ERROR: /dev/dvb/adapter0/demux0: Too many open files Feb 19 21:53:05 vdr: [2226] ERROR (dvbdevice.c,673): Too many open files Feb 19 21:53:05 vdr: [2226] ERROR: can't set PID 680 on device 1 Feb 19 21:53:05 vdr: [2226] ERROR (dvbdevice.c,688): Bad file descriptor Feb 19 21:53:06 vdr: [2226] timer 4 (7 2153-2200 'TestRec4') stop Feb 19 21:53:07 vdr: [2226] timer 4 (7 2153-2200 'TestRec4') start Feb 19 21:53:07 vdr: [2226] record /srv/vdr/TestRec4/2007-02-19.21.53.50.99.rec Feb 19 21:53:07 vdr: [2226] ERROR: /dev/dvb/adapter0/demux0: Too many open files Feb 19 21:53:07 vdr: [2226] ERROR (dvbdevice.c,673): Too many open files Feb 19 21:53:07 vdr: [2226] ERROR: can't set PID 680 on device 1 Feb 19 21:53:07 vdr: [2226] ERROR (dvbdevice.c,688): Bad file descriptor Feb 19 21:53:08 vdr: [2226] timer 4 (7 2153-2200 'TestRec4') stop Feb 19 21:53:09 vdr: [2226] timer 4 (7 2153-2200 'TestRec4') start Feb 19 21:53:09 vdr: [2226] record /srv/vdr/TestRec4/2007-02-19.21.53.50.99.rec Feb 19 21:53:10 vdr: [2226] ERROR: /dev/dvb/adapter0/demux0: Too many open files Feb 19 21:53:10 vdr: [2226] ERROR (dvbdevice.c,673): Too many open files Feb 19 21:53:10 vdr: [2226] ERROR: can't set PID 680 on device 1 Feb 19 21:53:10 vdr: [2226] ERROR (dvbdevice.c,688): Bad file descriptor Feb 19 21:53:11 vdr: [2226] timer 4 (7 2153-2200 'TestRec4') stop Feb 19 21:53:12 vdr: [2226] timer 4 (7 2153-2200 'TestRec4') start Feb 19 21:53:12 vdr: [2226] record /srv/vdr/TestRec4/2007-02-19.21.53.50.99.rec Feb 19 21:53:12 kernel: dvb-ttpci: StartHWFilter error buf 0b07 0010 0101 b96a ret 0 handle ffff Feb 19 21:53:12 vdr: [2330] ERROR: can't set filter (pid=257, tid=02, mask=FF): Operation not permitted Feb 19 21:53:12 kernel: dvb-ttpci: StartHWFilter error buf 0b07 0010 0104 b96a ret 0 handle ffff Feb 19 21:53:12 vdr: [2330] ERROR: can't set filter (pid=260, tid=02, mask=FF): Operation not permitted Feb 19 21:53:12 vdr: [2330] ERROR: can't set filter (pid=263, tid=02, mask=FF): Device or resource busy Feb 19 21:53:13 vdr: [2330] ERROR: can't set filter (pid=261, tid=02, mask=FF): Device or resource busy Feb 19 21:53:13 vdr: [2330] ERROR: can't set filter (pid=266, tid=02, mask=FF): Device or resource busy Feb 19 21:53:13 vdr: [2330] ERROR: can't set filter (pid=257, tid=02, mask=FF): Device or resource busy a lot of these same lines here just the pid changes Feb 19 21:54:00 vdr: [2226] ERROR: can't set filter (pid=16, tid=40, mask=FF): Device or resource busy Feb 19 21:54:00 vdr: [2226] ERROR: can't set filter (pid=0, tid=00, mask=FF): Device or resource busy Feb 19 21:54:00 vdr: [2226] ERROR (dvbdevice.c,683): Device or resource busy Feb 19 21:54:00 vdr: [2226] ERROR: can't set PID 2321 on device 1 Feb 19 21:54:00 vdr: [2226] timer 5 (8 2154-2200 'TestRec5') start Feb 19 21:54:00 vdr: [2226] record /srv/vdr/TestRec5/2007-02-19.21.54.50.99.rec Feb 19 21:55:48 vdr: [2726] cAudioRepacker(0xC1): skipped 488 bytes to sync on next audio frame Feb 19 21:57:29 vdr: [2749] cAudioRepacker(0xC0): skipped 296 bytes to sync on next audio frame Feb 19 21:57:36 vdr: [2734] cAudioRepacker(0xC0): skipped 488 bytes to sync on next audio frame Feb 19 21:57:36 vdr: [2737] ERROR: unknown picture type '4' Feb 19 21:57:36 vdr: [2749] cAudioRepacker(0xC1): skipped 296 bytes to sync on next audio frame Feb 19 21:57:36 vdr: [2738] cAudioRepacker(0xC0): skipped 488 bytes to sync on next audio frame Feb 19 21:57:36 vdr: [2753] cAudioRepacker(0xC0): skipped 488 bytes to sync on next audio frame Feb 19 21:57:36 vdr: [2749] cAudioRepacker(0xC3): skipped 432 bytes to sync on next audio frame Feb 19 22:00:00 vdr: [2226] timer 1 (1 2150-2200 'TestRec1') stop Feb 19 22:00:00 vdr: [2226] timer 2 (2 2151-2200 'TestRec2') stop Feb 19 22:00:00 vdr: [2226] timer 3 (6 2152-2200 'TestRec3') stop Feb 19 22:00:00 vdr: [2226] timer 4 (7 2153-2200 'TestRec4') stop Feb 19 22:00:01 vdr: [2226] timer 5 (8 2154-2200 'TestRec5') stop Feb 19 22:01:29 vdr: [2226] deleting timer 1 (1 2150-2200 'TestRec1') Feb 19 22:01:29 vdr: [2226] deleting timer 1 (2 2151-2200 'TestRec2') Feb 19 22:01:29 vdr: [2226] deleting timer 1 (6 2152-2200 'TestRec3') Feb 19 22:01:29 vdr: [2226] deleting timer 1 (7 2153-2200 'TestRec4') Feb 19 22:01:29 vdr: [2226] deleting timer 1 (8 2154-2200 'TestRec5') And then it calms down.
And the testrec4 has been recorded on the disk.
\Kartsa
On 2/19/07, Kartsa kari@kniivila.com wrote: I was about to test the performance of vdr when I stumbled on this message
ERROR: /dev/dvb/adapter0/demux0: Too many open files
I'm also having this error, only in my case, is not only related to recording, it also happens sometimes when just changing the channel:
Feb 20 11:02:11 hera vdr: [1027] switching to channel 4 Feb 20 11:02:11 hera vdr: [2812] transfer thread ended (pid=1027, tid=2812) Feb 20 11:02:11 hera vdr: [2814] TS buffer on device 1 thread ended (pid=1027, tid=2814) Feb 20 11:02:11 hera vdr: [2813] buffer stats: 53204 (2%) used Feb 20 11:02:11 hera vdr: [2813] receiver on device 1 thread ended (pid=1027, tid=2813) Feb 20 11:02:11 hera vdr: [1027] buffer stats: 53580 (2%) used Feb 20 11:02:11 hera vdr: [1027] ERROR: can't open filter handle on '/dev/dvb/adapter0/demux0' Feb 20 11:02:11 hera vdr: [1027] ERROR: /dev/dvb/adapter0/demux0: Too many open files Feb 20 11:02:11 hera vdr: [1027] ERROR (dvbdevice.c,687): Too many open files Feb 20 11:02:11 hera vdr: [1027] ERROR: can't set PID 4386 on device 1 Feb 20 11:02:11 hera vdr: [1027] ERROR (dvbdevice.c,712): Bad file descriptor Feb 20 11:02:11 hera vdr: [2821] transfer thread started (pid=1027, tid=2821)
When this happens, I have to keep changing channels until I get a lock and it is completly aleatory, to reproduce this error, I have to make several channel switching until it happens.
My systems specs: Ubuntu Edgy, kernel 2.6.17(the one that comes with the distro), I'm also using the dvb driver that come with the distro kernels. vdr-1.4.4, the one pre-patched be hooch(www.hoochvdr.info).
regards -- Carlos Javier Habana, CUBA
Carlos Javier Borroto wrote:
What hardware are you using? I mean, what driver is being used? Is it dvb-usb-dtt200u ? If so.. 'me too' :)
http://www.linuxtv.org/pipermail/vdr/2006-June/009718.html
I never found a solution, so bought different hardware :)
gdh
On 2/20/07, Gavin Hamill gdh@acentral.co.uk wrote:
What hardware are you using? I mean, what driver is being used? Is it dvb-usb-dtt200u ? If so.. 'me too' :)
I forget that, I'm using a Nexus card, this is my lspci output: 00:09.0 Multimedia controller: Philips Semiconductors SAA7146 (rev 01)
And dmesg: ... [17307906.312000] saa7146: found saa7146 @ mem cec7c000 (revision 1, irq 209) (0x13c2,0x0003). [17307906.592000] DVB: registering new adapter (Technotrend/Hauppauge WinTV Nexus-S rev2.X). .... [17307906.920000] dvb-ttpci: info @ card 0: firm f0240009, rtsl b0250018, vid 71010068, app 80f22623 [17307906.920000] dvb-ttpci: firmware @ card 0 supports CI link layer interface ...
I also forget to say that I'm using xine plugin for output, I don't know is that has something to do, my nexus has the video output broken.
Is funny, these mails were the only results google gave me, when I did a search a few days ago.
On my systems the limits are:
$ grep . /proc/sys/fs/file-* /proc/sys/fs/file-max:21190 /proc/sys/fs/file-nr:4320 0 21190
I never found a solution, so bought different hardware :)
To bad, I can't do the same.
thanks -- Carlos Javier Habana, CUBA
Carlos Javier Borroto kirjoitti:
As it happens so am I. I have Nexus as a ff card and as a second card I have a budget card.
dmesg ..... DVB: registering new adapter (Technotrend/Hauppauge WinTV Nexus-CA rev1.X) DVB: registering new adapter (TT-Budget/WinTV-NOVA-C PCI) .....
The Nexus card is a ff card which I am using for video out. Firmware is the latest with the avsync fix.
And mine $grep . /proc/sys/fs/file-* /proc/sys/fs/file-max:50644 /proc/sys/fs/file-nr:1088 0 50644
\Kartsa
Kartsa kirjoitti:
A small correction. I have two vdr boxes and I reported the wrong one for the hw :) The correct hw is: DVB: registering new adapter (Technotrend/Hauppauge WinTV DVB-C rev2.X) So it is not a Nexus-CA. But it is a ff card and I do not have another card on my second system. And the firmware is the same.
Also correct values for these are $grep . /proc/sys/fs/file-* /proc/sys/fs/file-max:50569 /proc/sys/fs/file-nr:704 0 50569
Kartsa wrote:
grep -20 -r EMFILE * dvb/dvb-core/dmxdev.c-static int dvb_demux_open(struct inode *inode, struct file *file) dvb/dvb-core/dmxdev.c-{ dvb/dvb-core/dmxdev.c- struct dvb_device *dvbdev = file->private_data; dvb/dvb-core/dmxdev.c- struct dmxdev *dmxdev = dvbdev->priv; dvb/dvb-core/dmxdev.c- int i; dvb/dvb-core/dmxdev.c- struct dmxdev_filter *dmxdevfilter; dvb/dvb-core/dmxdev.c- dvb/dvb-core/dmxdev.c- if (!dmxdev->filter) dvb/dvb-core/dmxdev.c- return -EINVAL; dvb/dvb-core/dmxdev.c- dvb/dvb-core/dmxdev.c- if (mutex_lock_interruptible(&dmxdev->mutex)) dvb/dvb-core/dmxdev.c- return -ERESTARTSYS; dvb/dvb-core/dmxdev.c- dvb/dvb-core/dmxdev.c- for (i = 0; i < dmxdev->filternum; i++) dvb/dvb-core/dmxdev.c- if (dmxdev->filter[i].state == DMXDEV_STATE_FREE) dvb/dvb-core/dmxdev.c- break; dvb/dvb-core/dmxdev.c- dvb/dvb-core/dmxdev.c- if (i == dmxdev->filternum) { dvb/dvb-core/dmxdev.c- mutex_unlock(&dmxdev->mutex); dvb/dvb-core/dmxdev.c: return -EMFILE; dvb/dvb-core/dmxdev.c- } dvb/dvb-core/dmxdev.c- dvb/dvb-core/dmxdev.c- dmxdevfilter = &dmxdev->filter[i]; dvb/dvb-core/dmxdev.c- mutex_init(&dmxdevfilter->mutex); dvb/dvb-core/dmxdev.c- file->private_data = dmxdevfilter; dvb/dvb-core/dmxdev.c- dvb/dvb-core/dmxdev.c- dvb_ringbuffer_init(&dmxdevfilter->buffer, NULL, 8192); dvb/dvb-core/dmxdev.c- dmxdevfilter->type = DMXDEV_TYPE_NONE; dvb/dvb-core/dmxdev.c- dvb_dmxdev_filter_state_set(dmxdevfilter, DMXDEV_STATE_ALLOCATED); dvb/dvb-core/dmxdev.c- dmxdevfilter->feed.ts = NULL; dvb/dvb-core/dmxdev.c- init_timer(&dmxdevfilter->timer); dvb/dvb-core/dmxdev.c- dvb/dvb-core/dmxdev.c- mutex_unlock(&dmxdev->mutex); dvb/dvb-core/dmxdev.c- return 0; dvb/dvb-core/dmxdev.c-}
IOW you ran out of filters. yes, the error code should probably be different (eg EBUSY).
Hello,
I would try to check which files are open when it happens. Maybe the cause is something different, e.g. a not well programed plugin.
lsof -p <pid of vdr> is your friend. ;-)
Additionally you should check the currently defined limits on your system(s) with ulimit.
Just my 2 cents,
Kartsa wrote:
you (well, vdr) used more filters than were available (in hw)? less simultaneous recordings, different hw and/or config? ("hw_sections" module parm?). Apparently vdr recovered somehow (eg another recording ended, the filters were opened in a different order etc).
Can't help you much more, I haven't used a FF card in years -- and since then all dvb-related problems vanished... It wasn't 100% reliable when live viewing, not to mention a single recording; a few novas have absolutely no problems w/ ~ 4-6 simultaneous recordings (never counted, but i believe it could go even higher) and this is on really low end hw (P2)...