Mailing List archive

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

[linux-dvb] Under SuSE 9.2, recordings on budget card crash VDR.



I have a VDR PC with 2 DVB-S cards:

* One full-featured 1.3 card:

0000:01:0a.0 Multimedia controller: Philips Semiconductors SAA7146 (rev 01)
        Subsystem: Technotrend Systemtechnik GmbH Siemens/Technotrend/Hauppauge DVB card rev1.3 or rev1.5
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B-
        Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
        Latency: 32 (3750ns min, 9500ns max)
        Interrupt: pin A routed to IRQ 12
        Region 0: Memory at df002000 (32-bit, non-prefetchable)

Nov 16 18:28:18 vdr kernel: Linux video capture interface: v1.00
Nov 16 18:28:18 vdr kernel: saa7146: register extension 'dvb'.
Nov 16 18:28:18 vdr kernel: ACPI: PCI interrupt 0000:01:0a.0[A] -> GSI 12 (level, low) -> IRQ 12
Nov 16 18:28:18 vdr kernel: saa7146: found saa7146 @ mem e0da4000 (revision 1, irq 12) (0x13c2,0x0000).
Nov 16 18:28:18 vdr kernel: DVB: registering new adapter (Siemens/Technotrend/Hauppauge PCI rev1.3).
Nov 16 18:28:18 vdr kernel: ves1x93: Detected ves1893a rev2
Nov 16 18:28:18 vdr kernel: DVB: registering frontend 0 (VES1893)...
Nov 16 18:28:18 vdr kernel: adapter has MAC addr = 00:d0:5c:1e:8b:ab
Nov 16 18:28:18 vdr kernel: gpioirq unknown type=0 len=0
Nov 16 18:28:18 vdr kernel: DVB: AV7111(0) - firm f0240009, rtsl b0250018, vid 71010068, app 8000261b
Nov 16 18:28:18 vdr kernel: DVB: AV7111(0) - firmware supports CI link layer interface
Nov 16 18:28:18 vdr kernel: av7110(0): adac type set to 0
Nov 16 18:28:18 vdr kernel: saa7146_vv: saa7146 (0): registered device video0 [v4l2]
Nov 16 18:28:18 vdr kernel: av7110: found av7110-0.


* One budget card:

0000:01:08.0 Multimedia controller: Philips Semiconductors SAA7146 (rev 01)
        Subsystem: Technotrend Systemtechnik GmbH Technotrend-Budget / Hauppauge WinTV-NOVA-S DVB card
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B-
        Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
        Latency: 32 (3750ns min, 9500ns max)
        Interrupt: pin A routed to IRQ 5
        Region 0: Memory at df001000 (32-bit, non-prefetchable)

Nov 16 18:28:18 vdr kernel: saa7146: register extension 'budget dvb'.
Nov 16 18:28:18 vdr kernel: ACPI: PCI interrupt 0000:01:08.0[A] -> GSI 5 (level, low) -> IRQ 5
Nov 16 18:28:18 vdr kernel: saa7146: found saa7146 @ mem e0ea6000 (revision 1, irq 5) (0x13c2,0x1003).
Nov 16 18:28:18 vdr kernel: DVB: registering new adapter (TT-Budget/WinTV-NOVA-S  PCI).
Nov 16 18:28:19 vdr kernel: stv0299: try to attach to TT-Budget/WinTV-NOVA-S  PCI
Nov 16 18:28:19 vdr kernel: stv0299: setup for tuner BSRU6, TDQB-S00x
Nov 16 18:28:19 vdr kernel: DVB: registering frontend 1 (STV0299/TSA5059/SL1935 based)...
Nov 16 18:28:19 vdr kernel: adapter has MAC addr = 00:d0:5c:02:1c:94
Nov 16 18:28:19 vdr kernel: NET: Registered protocol family 10
Nov 16 18:28:19 vdr kernel: Disabled Privacy Extensions on device c037f6a0(lo)


Most of the times a recording on the budget card starts,
VDR aborts with the error message "ERROR: video data stream broken":

Nov 16 18:26:00 vdr vdr[3218]: switching device 2 to channel 1
Nov 16 18:26:00 vdr vdr[3218]: timer 3 (1 1826-1910 'Science~nano~EPISODE') start
Nov 16 18:26:00 vdr vdr[3218]: Title: 'nano' Subtitle: 'Die Welt von morgen'
Nov 16 18:26:00 vdr vdr[3218]: record /video/Science/nano/Die_Welt_von_morgen/2004-11-16.18:26.02.99.rec
Nov 16 18:26:00 vdr vdr[3218]: creating directory /video/Science/nano/Die_Welt_von_morgen/2004-11-16.18:26.02.99.rec
Nov 16 18:26:18 vdr vdr[3218]: SpinUpDisk took 11.97 seconds
Nov 16 18:26:18 vdr vdr[3218]: recording to '/video/Science/nano/Die_Welt_von_morgen/2004-11-16.18:26.02.99.rec/001.vdr'
Nov 16 18:26:18 vdr vdr[4131]: file writer thread started (pid=4131, tid=98311)
Nov 16 18:26:18 vdr vdr[4132]: recording thread started (pid=4132, tid=114696)
Nov 16 18:26:18 vdr vdr[4133]: receiver on device 2 thread started (pid=4133, tid=131081)
Nov 16 18:26:18 vdr vdr[4134]: TS buffer on device 2 thread started (pid=4134, tid=147466)
Nov 16 18:26:49 vdr vdr[4131]: ERROR: video data stream broken
Nov 16 18:26:49 vdr vdr[4131]: initiating emergency exit
Nov 16 18:26:49 vdr vdr[3218]: emergency exit requested - shutting down
Nov 16 18:26:49 vdr vdr[4132]: recording thread ended (pid=4132, tid=114696)
Nov 16 18:26:49 vdr vdr[4134]: TS buffer on device 2 thread ended (pid=4134, tid=147466)
Nov 16 18:26:49 vdr vdr[4133]: buffer stats: 0 (0%) used
Nov 16 18:26:49 vdr vdr[4133]: receiver on device 2 thread ended (pid=4133, tid=131081)
Nov 16 18:26:49 vdr vdr[4131]: file writer thread ended (pid=4131, tid=98311)
Nov 16 18:26:49 vdr vdr[3218]: buffer stats: 0 (0%) used
Nov 16 18:26:49 vdr vdr[3218]: timer 3 (1 1826-1910 'Science~nano~Die Welt von morgen') stop
Nov 16 18:26:49 vdr vdr[3218]: saved setup to ./setup.conf
Nov 16 18:26:49 vdr vdr[3224]: tuner on device 1 thread ended (pid=3224, tid=16386)
Nov 16 18:26:49 vdr vdr[3225]: Section handler thread ended (pid=3225, tid=32771)
Nov 16 18:26:49 vdr vdr[3227]: tuner on device 2 thread ended (pid=3227, tid=49156)
Nov 16 18:26:50 vdr vdr[3228]: Section handler thread ended (pid=3228, tid=65541)
Nov 16 18:26:50 vdr vdr[3218]: =====================
Nov 16 18:26:50 vdr vdr[3218]: EPG bugfix statistics
Nov 16 18:26:50 vdr vdr[3218]: =====================
Nov 16 18:26:50 vdr vdr[3218]: IF SOMEBODY WHO IS IN CHARGE OF THE EPG DATA FOR ONE OF THE LISTED
Nov 16 18:26:50 vdr vdr[3218]: CHANNELS READS THIS: PLEASE TAKE A LOOK AT THE FUNCTION cEvent::FixEpgBugs()
Nov 16 18:26:50 vdr vdr[3218]: IN VDR/epg.c TO LEARN WHAT'S WRONG WITH YOUR DATA, AND FIX IT!
Nov 16 18:26:50 vdr vdr[3218]: =====================
Nov 16 18:26:50 vdr vdr[3218]: Fix      Hits    Channels
Nov 16 18:26:50 vdr vdr[3218]: 0        297     rbb Berlin, rbb Brandenburg, 3sat, MDR FERNSEHEN, MDR SACHSEN, MDR THÜRINGEN, ...
Nov 16 18:26:50 vdr vdr[3218]: 1        119     RAI 1, TV 5, DW-TV, Bloomberg TV Germany, LibertyTV.com, n-tv
Nov 16 18:26:50 vdr vdr[3218]: 2        7       rbb Brandenburg, rbb Berlin, TV5 Europe, EinsFestival
Nov 16 18:26:50 vdr vdr[3218]: 3        6161    KiKa, DLR-Berlin, NDR FS MV, NDR FS HH, NDR FS SH, NDR FS NDS, ProSieben, SAT.1, ...
Nov 16 18:26:50 vdr vdr[3218]: 4        274     SÜDWEST RP, SR Fernsehen Südwest, SÜDWEST BW, RAI 1, TOON DISNEY, GOURMET TV, ...
Nov 16 18:26:50 vdr vdr[3218]: 5        213     MDR THÜRINGEN, rbb Berlin, rbb Brandenburg, EinsExtra, 3sat, ARD-MHP-TEST-6, ...
Nov 16 18:26:50 vdr vdr[3218]: 6        185     KiKa, rbb Brandenburg, EinsMuXx, rbb Berlin, MDR FERNSEHEN, MDR SACHSEN, MDR THÜRINGEN, ...
Nov 16 18:26:50 vdr vdr[3218]: 7        7296    EinsMuXx, rbb Berlin, EinsFestival, rbb Brandenburg, ARD-Online-Kanal, ARD-MHP-TEST-6, ...
Nov 16 18:26:50 vdr vdr[3218]: =====================
Nov 16 18:26:50 vdr vdr[3218]: exiting
Nov 16 18:26:50 vdr vdr[3218]: emergency exit!


Because my runvdr script used to restart VDR in this case,  it got into a loop
"start VDR / start recording / crash / reload drivers / start VDR / ...".
So obviously reloading the driver *does not* cure the problem.
Also, after a few driver reloads, the system freaks out more and more
and reports errors such as "irq 7: nobody cared!" and
"modprobe: page allocation failure. order:4, mode:0x20".

Interestingly, however, the problem does not occur if the recording starts
a short time after the last reboot.
So obviously rebooting the entire system *does* cure the problem - at least
for a while.

For example, the above crash happened 2 hours and 22 minutes after the last
reboot.

Out of desparation, I changed my runvdr script to reboot when one of the
errors I observed occurs:

   LD_ASSUME_KERNEL=2.4;export LD_ASSUME_KERNEL
   su -c "$VDRCMD" $VDRUSER

   tail -200 /var/log/messages > /tmp/tail_messages
   if  fgrep -q 'emergency exit' /tmp/tail_messages;then init 6;exit 0;fi
   if  fgrep -q 'nobody cared' /tmp/tail_messages;then init 6;exit 0;fi
   if  fgrep -q 'page allocation failure' /tmp/tail_messages;then init 6;exit 0;fi
   if  fgrep -q 'no OSD provider available' /tmp/tail_messages;then init 6;exit 0;fi

Now, my VDR PC reboots almost every time when it starts a recording (which
forced me to increase the safety margin at the start of a recording from 2
to 4 minutes), but immediately after the reboot records the rest just fine.
Also, the "irq 7: nobody cared!" and  "modprobe: page allocation failure. order:4, mode:0x20"
errors have not reoccured a single time since I made the above change.

In the above example, the recording was restarted after the reboot and
finished with just one minor glitch:

Nov 16 18:28:48 vdr vdr[3275]: switching device 2 to channel 1
Nov 16 18:28:48 vdr vdr[3275]: timer 3 (1 1826-1910 'Science~nano~Die Welt von morgen') start
Nov 16 18:28:48 vdr vdr[3275]: Title: 'nano' Subtitle: 'Die Welt von morgen'
Nov 16 18:28:48 vdr vdr[3275]: record /video/Science/nano/Die_Welt_von_morgen/2004-11-16.18:26.02.99.rec
Nov 16 18:28:50 vdr vdr[3292]: channel 20 (KiKa) event 18:30 'SimsalaGrimm' status 4
Nov 16 18:28:51 vdr vdr[3292]: channel 1 (3sat) event 18:00 'Die Rettungsflieger' status 4
Nov 16 18:28:51 vdr vdr[3275]: SpinUpDisk took 3.22 seconds
Nov 16 18:28:51 vdr vdr[3275]: recording to '/video/Science/nano/Die_Welt_von_morgen/2004-11-16.18:26.02.99.rec/002.vdr'
Nov 16 18:28:51 vdr vdr[3956]: file writer thread started (pid=3956, tid=98311)
Nov 16 18:28:51 vdr vdr[3957]: recording thread started (pid=3957, tid=114696)
Nov 16 18:28:51 vdr vdr[3958]: receiver on device 2 thread started (pid=3958, tid=131081)
Nov 16 18:28:51 vdr vdr[3959]: TS buffer on device 2 thread started (pid=3959, tid=147466)
Nov 16 18:29:04 vdr vdr[3292]: channel 1 (3sat) event 18:00 'Die Rettungsflieger' status 1
Nov 16 18:29:34 vdr vdr[3289]: channel 13 (EinsFestival) event 17:00 'Kinder des Schattens' status 1
Nov 16 18:30:03 vdr vdr[3289]: channel 13 (EinsFestival) event 18:30 'Streifzug durch Neuengland' status 4
Nov 16 18:30:07 vdr vdr[3292]: channel 1 (3sat) event 18:30 'nano' status 4
Nov 16 18:40:12 vdr vdr[3956]: ERROR: unknown picture type '4'
Nov 16 18:44:29 vdr vdr[3289]: channel 24 (NDR FS HH) event 18:15 'DAS! - Automobil' status 1
Nov 16 18:45:02 vdr vdr[3289]: channel 24 (NDR FS HH) event 18:45 'DAS!' status 4
Nov 16 18:48:15 vdr vdr[3289]: channel 23 (MDR FERNSEHEN) event 18:20 'Brisant' status 1
Nov 16 18:49:25 vdr vdr[3289]: channel 23 (MDR FERNSEHEN) event 18:50 'Unser Sandmännchen' status 4
Nov 16 18:52:23 vdr vdr[3292]: channel 20 (KiKa) event 18:30 'SimsalaGrimm' status 1
Nov 16 18:52:40 vdr vdr[3292]: channel 20 (KiKa) event 18:30 'SimsalaGrimm' status 4
Nov 16 18:53:43 vdr vdr[3292]: channel 20 (KiKa) event 18:55 'Unser Sandmännchen' status 4
Nov 16 18:55:27 vdr vdr[3289]: channel 23 (MDR FERNSEHEN) event 18:50 'Unser Sandmännchen' status 1
Nov 16 18:56:31 vdr vdr[3289]: channel 23 (MDR FERNSEHEN) event 18:56 'MDR aktuell' status 4
Nov 16 18:58:16 vdr vdr[3289]: channel 14 (EinsMuXx) event 18:00 'Fliege - Die Talkshow' status 1
Nov 16 18:58:17 vdr smartd[3007]: Device: /dev/hda, SMART Usage Attribute: 194 Temperature_Celsius changed from 109 to 115
Nov 16 18:58:18 vdr vdr[3289]: channel 13 (EinsFestival) event 18:30 'Streifzug durch Neuengland' status 1
Nov 16 18:58:23 vdr smartd[3007]: Device: /dev/hdb, SMART Usage Attribute: 194 Temperature_Celsius changed from 127 to 142
Nov 16 18:58:29 vdr smartd[3007]: Device: /dev/hdc, SMART Usage Attribute: 194 Temperature_Celsius changed from 112 to 106
Nov 16 18:58:29 vdr smartd[3007]: Device: /dev/hdd, SMART Usage Attribute: 194 Temperature_Celsius changed from 112 to 103
Nov 16 18:58:39 vdr vdr[3292]: channel 1 (3sat) event 18:30 'nano' status 1
Nov 16 18:59:01 vdr /usr/sbin/cron[3999]: (root) CMD ( rm -f /var/spool/cron/lastrun/cron.hourly)
Nov 16 18:59:36 vdr vdr[3292]: channel 20 (KiKa) event 18:55 'Unser Sandmännchen' status 1
Nov 16 18:59:46 vdr vdr[3289]: channel 23 (MDR FERNSEHEN) event 19:00 'Länderzeit' status 4
Nov 16 18:59:48 vdr vdr[3289]: channel 13 (EinsFestival) event 18:59 'Thüringen Journal' status 4
Nov 16 18:59:49 vdr vdr[3289]: channel 14 (EinsMuXx) event 18:59 'Sachsen-Anhalt heute' status 4
Nov 16 19:00:00 vdr vdr[3292]: channel 1 (3sat) event 19:00 'heute' status 4
Nov 16 19:00:04 vdr vdr[3289]: changing pids of channel 112 from 401+401:402=deu:404 to 101+101:102=deu:404
Nov 16 19:00:04 vdr vdr[3289]: changing pids of channel 113 from 401+401:402=deu:404 to 301+301:302=deu:404
Nov 16 19:00:05 vdr vdr[3289]: changing pids of channel 114 from 401+401:402=deu:404 to 201+201:202=deu:404
Nov 16 19:00:05 vdr vdr[3275]: timer 3 (1 1826-1910 'Science~nano~Die Welt von morgen') set to event Tue 16.11.2004 19:00-19:20 (VPS: 16.11 19:00) 'heute'
Nov 16 19:00:23 vdr vdr[3292]: channel 20 (KiKa) event 19:00 'Wir testen die Besten' status 4
Nov 16 19:10:00 vdr vdr[3957]: recording thread ended (pid=3957, tid=114696)
Nov 16 19:10:01 vdr vdr[3959]: TS buffer on device 2 thread ended (pid=3959, tid=147466)
Nov 16 19:10:01 vdr vdr[3958]: buffer stats: 88548 (4%) used
Nov 16 19:10:01 vdr vdr[3958]: receiver on device 2 thread ended (pid=3958, tid=131081)
Nov 16 19:10:01 vdr vdr[3956]: file writer thread ended (pid=3956, tid=98311)
Nov 16 19:10:01 vdr vdr[3275]: buffer stats: 164312 (3%) used
Nov 16 19:10:01 vdr vdr[3275]: timer 3 (1 1826-1910 'Science~nano~Die Welt von morgen') stop
Nov 16 19:10:01 vdr vdr[3275]: deleting timer 3


I do not remember seeing that problem even once before I installed SuSE 9.2.

It does not occur when a recording starts on the FF card.

I am still using the drivers that come with SuSE 9.2 and I have not tried to
install newer drivers yet.


My questions are:

1) Did anybody else observe this?

2) What is the most likely cause of this problem?

3) Is it likely that this is already fixed in a newer driver version?


Thanks in advance for any advice!   :-)

Carsten.




Home | Main Index | Thread Index