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:
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:
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:
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:
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.
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
And mine $grep . /proc/sys/fs/file-* /proc/sys/fs/file-max:50644 /proc/sys/fs/file-nr:1088 0 50644
\Kartsa
Kartsa kirjoitti:
Carlos Javier Borroto kirjoitti:
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:
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.
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.
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
And mine $grep . /proc/sys/fs/file-* /proc/sys/fs/file-max:50644 /proc/sys/fs/file-nr:1088 0 50644
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:
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
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).
Artur Skawina kirjoitti:
Kartsa 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 do not recall seeing this earlier. This came when fourth simultaneous recording started.
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).
So, why did I ran out of filters? Why did it happen? Why doesn't it happen on my other vdr box? And what does it cause? The recording did succeed.
\Kartsa
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:
ERROR: /dev/dvb/adapter0/demux0: Too many open files
I do not recall seeing this earlier. This came when fourth simultaneous recording started.
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-}
IOW you ran out of filters. yes, the error code should probably be different (eg EBUSY).
So, why did I ran out of filters? Why did it happen? Why doesn't it happen on my other vdr box? And what does it cause? The recording did succeed.
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)...
-
Artur Skawina -
Carlos Javier Borroto -
Gavin Hamill -
Kartsa -
Patrick Cernko