[linux-dvb] Re: some records stops before the programmed end

["Jörg Wiedenfeld" <wiedenfeld@gmx.de>]

Hi Klaus,
thanks for your help.

> AFAIK that's some debug output from the driver.
> I usually make the following change to DVB/driver/dvb.c to get rid of
these:
> 
> --- dvb.c.001   Tue Aug 14 08:32:13 2001
> +++ dvb.c       Wed Aug 15 10:57:50 2001
> @@ -955,7 +955,7 @@
>  
>          case DATA_COMMON_INTERFACE:
>                  CI_handle(dvb, (u8 *)dvb->saa->debi, dvb->debilen);
> -#if 1
> +#if 0
>          {
>                  int i;
Fine, I will change this.



>  
> > 2.Why stops some records to early ?
> > There is no system in it. Some records stops after 10 minutes,
> > other x minutes before the movie stops :-(.
> > When I watch these records they don't have any drops in picture
> > or klicks in the sound. Sometimes I find a vdr process which
> > use 99% cpu. What is the solution for that problem ?
> 
> Are there any useful log messages when a recording ends prematurely? 


Ups sorry,
There are two cases in the messages log after the records stops:

first case:
<schnipp>
Aug 21 03:10:00 pach vdr[7509]: timer 8 start
Aug 21 03:10:00 pach vdr[7509]: switching to channel 7
Aug 21 03:10:02 pach vdr[7509]: ERROR: channel 7 not sync'ed on DVB card 2!
Aug 21 03:10:02 pach vdr[7509]: retrying
Aug 21 03:10:02 pach vdr[7509]: Title: 'Jets - Leben am Limit' Subtitle:
'Gefährliche Freundschaft'
Aug 21 03:10:02 pach vdr[7509]: record
/video/Seven_Days/2001-08-21.03.10.50.50.rec
Aug 21 03:10:02 pach vdr[7509]: creating directory /video/Seven_Days
Aug 21 03:10:02 pach vdr[7509]: creating directory
/video/Seven_Days/2001-08-21.03.10.50.50.rec
Aug 21 03:10:02 pach vdr[7509]: recording to
'/video/Seven_Days/2001-08-21.03.10.50.50.rec/001.vdr'
Aug 21 03:10:02 pach vdr[8602]: output thread started (pid=8602)
Aug 21 03:10:02 pach vdr[8603]: input thread started (pid=8603)
Aug 21 03:10:08 pach vdr[8603]: buffer usage: 76%
Aug 21 03:10:08 pach last message repeated 4 times
Aug 21 03:10:08 pach vdr[8603]: buffer usage: 77%
Aug 21 03:10:08 pach last message repeated 5 times
Aug 21 03:10:08 pach vdr[8603]: buffer usage: 78%
Aug 21 03:10:08 pach last message repeated 4 times
Aug 21 03:10:08 pach vdr[8603]: buffer usage: 79%
Aug 21 03:10:08 pach last message repeated 4 times
Aug 21 03:10:08 pach vdr[8603]: buffer usage: 80%
...
Aug 21 03:10:08 pach vdr[8603]: buffer usage: 98%
Aug 21 03:10:08 pach last message repeated 5 times
Aug 21 03:10:08 pach vdr[8603]: buffer usage: 99%
Aug 21 03:10:08 pach last message repeated 5 times
Aug 21 03:10:08 pach vdr[8603]: buffer usage: 100%
Aug 21 03:10:11 pach vdr[8603]: ERROR (dvbapi.c,549): DVB driver buffer
overflow
</schnipp>
after this top show vdr with 99% load

or the second cases:
<schnipp>
Aug 20 15:24:30 pach kernel: dvb: 2 dvb(s) found!
Aug 20 15:24:30 pach su: (to vdr) root on none
Aug 20 15:24:30 pach PAM-unix2[11510]: session started for user vdr,
service su 
Aug 20 15:24:30 pach vdr[11511]: VDR version 0.92 started
Aug 20 15:24:30 pach vdr[11511]: loading /video/setup.conf
Aug 20 15:24:30 pach vdr[11511]: loading /video/channels.conf
Aug 20 15:24:30 pach vdr[11511]: loading /video/timers.conf
Aug 20 15:24:30 pach vdr[11511]: loading /video/commands.conf
Aug 20 15:24:30 pach vdr[11511]: probing /dev/ost/qpskfe0
Aug 20 15:24:30 pach vdr[11513]: EIT processing thread started
(pid=11513) - master
Aug 20 15:24:30 pach vdr[11511]: probing /dev/ost/qpskfe1
Aug 20 15:24:32 pach vdr[11514]: EIT processing thread started (pid=11514)
Aug 20 15:24:32 pach vdr[11511]: probing /dev/ost/qpskfe2
Aug 20 15:24:32 pach vdr[11511]: probing /dev/ost/qamfe2
Aug 20 15:24:32 pach vdr[11511]: found 2 video devices
Aug 20 15:24:32 pach vdr[11511]: setting primary DVB to 1
Aug 20 15:24:32 pach vdr[11511]: switching to channel 5
Aug 20 15:24:32 pach vdr[11515]: LIRC remote control thread started
(pid=11515)
Aug 20 15:24:32 pach vdr[11511]: SVDRP listening on port 2001
Aug 20 15:24:32 pach vdr[11511]: setting watchdog timer to 60 seconds
...
Aug 20 15:54:49 pach vdr[11511]: timer 7 start
Aug 20 15:54:49 pach vdr[11511]: switching to channel 5
Aug 20 15:54:49 pach vdr[11511]: waiting for EPG info...
Aug 20 15:54:51 pach vdr[11511]: got EPG info after 2 seconds
Aug 20 15:54:51 pach vdr[11511]: Title: 'Star Trek - Das nächste
Jahrhundert' Subtitle: 'Der schüchterne Reginald'
Aug 20 15:54:51 pach vdr[11511]: record
/video/Star_Trek_-_Das_nächste_Jahrhundert/2001-08-20.15.50.50.50.rec
Aug 20 15:54:51 pach vdr[11511]: creating directory
/video/Star_Trek_-_Das_nächste_Jahrhundert/2001-08-20.15.50.50.50.rec
Aug 20 15:54:51 pach vdr[11511]: recording to
'/video/Star_Trek_-_Das_nächste_Jahrhundert/2001-08-20.15.50.50.50.rec/001.vdr'
Aug 20 15:54:52 pach vdr[11518]: output thread started (pid=11518)
Aug 20 15:54:52 pach vdr[11519]: input thread started (pid=11519)
Aug 20 15:54:53 pach vdr[11511]: max. latency time 4 seconds
Aug 20 15:54:54 pach vdr[11519]: buffer usage: 76%
Aug 20 15:54:54 pach last message repeated 4 times
Aug 20 15:54:54 pach vdr[11519]: buffer usage: 77%
...
Aug 20 15:54:55 pach vdr[11519]: buffer usage: 97%
Aug 20 15:54:55 pach last message repeated 4 times
Aug 20 15:54:55 pach vdr[11519]: buffer usage: 98%
Aug 20 15:54:55 pach last message repeated 4 times
Aug 20 15:54:55 pach vdr[11519]: buffer usage: 99%
Aug 20 15:54:55 pach last message repeated 4 times
Aug 20 15:54:55 pach vdr[11519]: buffer usage: 100%
Aug 20 15:54:56 pach vdr[11519]: ERROR (dvbapi.c,549): DVB driver buffer
overflow
Aug 20 15:55:33 pach vdr[11519]: ERROR: video data stream broken
Aug 20 15:55:33 pach vdr[11519]: initiating emergency exit
Aug 20 15:55:33 pach vdr[11511]: emergency exit requested - shutting down
Aug 20 15:55:33 pach vdr[11511]: saved setup to /video/setup.conf
Aug 20 15:55:33 pach vdr[11513]: EIT processing thread ended (pid=11513)
- master
Aug 20 15:55:33 pach vdr[11514]: EIT processing thread ended (pid=11514)
Aug 20 15:55:36 pach vdr[11519]: ERROR (dvbapi.c,552): Bad file descriptor
Aug 20 15:55:36 pach vdr[11519]: input thread ended (pid=11519)
Aug 20 15:55:36 pach vdr[11511]: buffer stats: 1048575 (100%) used
Aug 20 15:55:36 pach vdr[11511]: max. latency time 4 seconds
Aug 20 15:55:36 pach vdr[11511]: exiting
Aug 20 15:55:36 pach vdr[11511]: emergency exit!
Aug 20 15:55:36 pach PAM-unix2[11510]: session finished for user vdr,
service su 
Aug 20 15:55:36 pach logger: restarting VDR:
/usr/local/2.4.4-SMP/vdr/VDR/vdr
Aug 20 15:55:46 pach kernel: dvb: 2 dvb(s) released.
Aug 20 15:55:46 pach kernel: free irqs
Aug 20 15:55:46 pach kernel: VES1893: detach_client
Aug 20 15:55:46 pach kernel: i2c-core.o: client [VES1893] unregistered.
Aug 20 15:55:46 pach kernel: i2c-core.o: client [SP5659] unregistered.
Aug 20 15:55:46 pach kernel: i2c-core.o: adapter unregistered: saa7146(1)
Aug 20 15:55:46 pach kernel: free irqs
Aug 20 15:55:46 pach kernel: VES1893: detach_client
Aug 20 15:55:46 pach kernel: i2c-core.o: client [VES1893] unregistered.
Aug 20 15:55:46 pach kernel: i2c-core.o: client [SP5659] unregistered.
Aug 20 15:55:46 pach kernel: i2c-core.o: adapter unregistered: saa7146(2)
Aug 20 15:55:46 pach kernel: i2c-core.o: driver unregistered: VES1820
DVB demodulator
Aug 20 15:55:46 pach kernel: i2c-core.o: driver unregistered: VES1893
DVB demodulator
Aug 20 15:55:46 pach kernel: i2c-core.o: driver unregistered: L64781 DVB
demodulator
Aug 20 15:55:46 pach kernel: L64781: cleanup
Aug 20 15:55:46 pach kernel: i2c-core.o: driver unregistered: stv0299
DVB demodulator
Aug 20 15:55:46 pach kernel: i2c-core.o: driver unregistered: tda8083
DVB demodulator
Aug 20 15:55:46 pach kernel: i2c-core.o: driver unregistered: i2c TV
tuner driver
Aug 20 15:55:47 pach kernel: i2c-core.o: i2c core module
Aug 20 15:55:47 pach kernel: Linux video capture interface: v1.00
Aug 20 15:55:47 pach kernel: i2c-core.o: driver VES1893 DVB demodulator
registered.
Aug 20 15:55:47 pach kernel: i2c-core.o: driver VES1820 DVB demodulator
registered.
Aug 20 15:55:47 pach kernel: i2c-core.o: driver L64781 DVB demodulator
registered.
Aug 20 15:55:47 pach kernel: L64781: init done
Aug 20 15:55:47 pach kernel: i2c-core.o: driver tda8083 DVB demodulator
registered.
Aug 20 15:55:47 pach kernel: i2c-core.o: driver stv0299 DVB demodulator
registered.
Aug 20 15:55:47 pach kernel: i2c-core.o: driver i2c TV tuner driver
registered.
Aug 20 15:55:47 pach kernel: saa7146_core.o: saa7146(1): bus:0, rev:1,
mem:0xd0c8f000.
Aug 20 15:55:47 pach kernel: i2c-core.o: client [VES1893] registered to
adapter [saa7146(1)](pos. 0).
Aug 20 15:55:47 pach kernel: VES1893: attaching VES1893 at 0x10 to
adapter saa7146(1)
Aug 20 15:55:47 pach kernel: tuner: chip found @ 0x61
Aug 20 15:55:47 pach kernel: i2c-core.o: client [i2c tv tuner chip]
registered to adapter [saa7146(1)](pos. 1).
Aug 20 15:55:47 pach kernel: i2c-core.o: adapter saa7146(1) registered
as adapter 0.
Aug 20 15:55:47 pach kernel: saa7146_core.o: saa7146(2): bus:2, rev:1,
mem:0xd1112000.
Aug 20 15:55:47 pach kernel: i2c-core.o: client [VES1893] registered to
adapter [saa7146(2)](pos. 0).
Aug 20 15:55:48 pach kernel: VES1893: attaching VES1893 at 0x10 to
adapter saa7146(2)
Aug 20 15:55:48 pach kernel: tuner: chip found @ 0x61
Aug 20 15:55:48 pach kernel: i2c-core.o: client [i2c tv tuner chip]
registered to adapter [saa7146(2)](pos. 1).
Aug 20 15:55:48 pach kernel: i2c-core.o: adapter saa7146(2) registered
as adapter 1.
Aug 20 15:55:48 pach kernel: mon_current=c6b3e000
Aug 20 15:55:50 pach kernel: dvb0: AV7111 - firm f0240009, rtsl
b0250018, vid 71010068, app 00010002
Aug 20 15:55:50 pach kernel: mon_current=cfddc000
Aug 20 15:55:52 pach kernel: dvb1: AV7111 - firm f0240009, rtsl
b0250018, vid 71010068, app 00010002
Aug 20 15:55:53 pach kernel: dvb: 2 dvb(s) found!
Aug 20 15:55:53 pach su: (to vdr) root on none
Aug 20 15:55:53 pach PAM-unix2[11653]: session started for user vdr,
service su 
Aug 20 15:55:53 pach vdr[11654]: VDR version 0.92 started
Aug 20 15:55:53 pach vdr[11654]: loading /video/setup.conf
Aug 20 15:55:53 pach vdr[11654]: loading /video/channels.conf
Aug 20 15:55:53 pach vdr[11654]: loading /video/timers.conf
Aug 20 15:55:53 pach vdr[11654]: loading /video/commands.conf
Aug 20 15:55:53 pach vdr[11654]: probing /dev/ost/qpskfe0
Aug 20 15:55:53 pach vdr[11656]: EIT processing thread started
(pid=11656) - master
Aug 20 15:55:53 pach vdr[11654]: probing /dev/ost/qpskfe1
Aug 20 15:55:53 pach vdr[11657]: EIT processing thread started (pid=11657)
Aug 20 15:55:53 pach vdr[11654]: probing /dev/ost/qpskfe2
Aug 20 15:55:53 pach vdr[11654]: probing /dev/ost/qamfe2
Aug 20 15:55:53 pach vdr[11654]: found 2 video devices
Aug 20 15:55:53 pach vdr[11654]: setting primary DVB to 1
Aug 20 15:55:53 pach vdr[11654]: switching to channel 5
Aug 20 15:55:53 pach vdr[11658]: LIRC remote control thread started
(pid=11658)
Aug 20 15:55:53 pach vdr[11654]: SVDRP listening on port 2001
Aug 20 15:55:53 pach vdr[11654]: setting watchdog timer to 60 seconds
Aug 20 15:55:59 pach vdr[11654]: timer 7 start
Aug 20 15:55:59 pach vdr[11654]: switching to channel 5
Aug 20 15:56:00 pach vdr[11654]: Title: 'Star Trek - Das nächste
Jahrhundert' Subtitle: 'Der schüchterne Reginald'
Aug 20 15:56:00 pach vdr[11654]: record
/video/Star_Trek_-_Das_nächste_Jahrhundert/2001-08-20.15.50.50.50.rec
Aug 20 15:56:00 pach vdr[11654]: recording to
'/video/Star_Trek_-_Das_nächste_Jahrhundert/2001-08-20.15.50.50.50.rec/002.vdr'
Aug 20 15:56:00 pach vdr[11660]: output thread started (pid=11660)
Aug 20 15:56:00 pach vdr[11661]: input thread started (pid=11661)
Aug 20 15:56:01 pach vdr[11654]: max. latency time 1 seconds
Aug 20 15:58:05 pach kernel: process 11657 (     vdr) exits perhaps
unexpectedly with signal 11?
Aug 20 15:58:05 pach kernel: process 11654 (     vdr) exits perhaps
unexpectedly with signal 11?
Aug 20 15:58:05 pach kernel: process 11658 (     vdr) exits perhaps
unexpectedly with signal 11?
Aug 20 15:58:05 pach kernel: process 11661 (     vdr) exits perhaps
unexpectedly with signal 11?
Aug 20 15:58:05 pach kernel: process 11660 (     vdr) exits perhaps
unexpectedly with signal 11?
Aug 20 15:58:05 pach PAM-unix2[11653]: session finished for user vdr,
service su 
Aug 20 15:58:05 pach kernel: process 11656 (     vdr) exits perhaps
unexpectedly with signal 11?
Aug 20 15:58:05 pach logger: restarting VDR:
/usr/local/2.4.4-SMP/vdr/VDR/vdr
...
</schnipp>
vdr will restart and restart

It seems, vdr can't store the data to disk in time.
But my IDE disk is in DMA mode and the cpu is
low on load.

My system:
P-III 700Mhz
128MB
80GB Maxtor (reiserfs for the video partition)
2 old DVB-s cards


Thanks a lot

Jörg

------
Jörg Wiedenfeld <wiedenfeld@gmx.de>



--
Info:
To unsubscribe send a mail to listar@linuxtv.org with "unsubscribe linux-dvb" as subject.