Tvheadend

Looks like I was able to reproduce the mux creation problem while capturing NIT using dvbsnoop. I believe the logs corroborate the stale data theory.

Feb 26 21:48:32 [   INFO]:serviceprobe:       Kanal 5 HD (D): checking...
Feb 26 21:48:34 [  DEBUG]:dvb: "/dev/dvb/adapter3" tuning via s2api to "Telenor: 10,778,000 kHz Vertical (Thor (Canal Digital))" (1028000, 25000000 Baud, 3/4, SYS_DVBS2, PSK_8) for Transport start
Feb 26 21:48:34 [  DEBUG]:cwc: TurboSight TBS 6984 DVBS/S2 frontend/Telenor: 10,778,000 kHz Vertical (Thor (Canal Digital))/Kanal 5 HD (D) using CWC 127.0.0.1:10001
Feb 26 21:48:34 [  DEBUG]:Service: TurboSight TBS 6984 DVBS/S2 frontend/Telenor: 10,778,000 kHz Vertical (Thor (Canal Digital))/Kanal 5 HD (D): Status changed to [Hardware input] 
Feb 26 21:48:34 [   INFO]:subscription: "serviceprobe" direct subscription to adapter: "TurboSight TBS 6984 DVBS/S2 frontend", network: "Telenor", mux: "Telenor: 10,778,000 kHz Vertical (Thor (Canal Digital))", provider: "Telenor", service: "Kanal 5 HD (D)", quality: 100
Feb 26 21:48:34 [ NOTICE]:dvb: New mux "Sirius: 12,379,620 kHz Horizontal (Thor (Canal Digital))" created by automatic mux discovery
Feb 26 21:48:34 [ NOTICE]:dvb: New mux "Sirius: 11,842,560 kHz Horizontal (Thor (Canal Digital))" created by automatic mux discovery
Feb 26 21:48:34 [ NOTICE]:dvb: New mux "Sirius: 12,245,000 kHz Vertical (Thor (Canal Digital))" created by automatic mux discovery
Feb 26 21:48:34 [ NOTICE]:dvb: New mux "Sirius: 11,900,000 kHz Vertical (Thor (Canal Digital))" created by automatic mux discovery
Feb 26 21:48:34 [ NOTICE]:dvb: New mux "Sirius: 11,958,000 kHz Horizontal (Thor (Canal Digital))" created by automatic mux discovery

------------------------------------------------------------
SECT-Packet: 00007547   PID: 16 (0x0010), Length: 344 (0x0158)
Time received: Tue 2013-02-26  21:48:33.139
------------------------------------------------------------
PID:  16 (0x0010)  [= assigned for: DVB Network Information Table (NIT), Stuffing Table (ST)]

Guess table from table id...
NIT-decoding....
Table_ID: 64 (0x40)  [= Network Information Table (NIT) - actual network]

<...snip...>

    Transport_stream_ID: 2 (0x0002)
    Original_network_ID: 85 (0x0055)  [= Sirius Satellite System European Coverage | NSAB (Teracom)]
    reserved_1: 15 (0x0f)
    Transport_descriptor_length: 54 (0x0036)

            DVB-DescriptorTag: 67 (0x43)  [= satellite_delivery_system_descriptor]
            descriptor_length: 11 (0x0b)
            Frequency: 19102050 (=  12.37962 GHz)
            Orbital_position: 80 (=   5.0)
            West_East_flag: 1 (0x01)  [= EAST]
            Polarisation: 0 (0x00)  [= linear - horizontal]
            Kind: 0 (0x00)  [= DVB-S]
            fixed ('00'): 0 (0x00)
            Modulation_type: 1 (0x01)  [= QPSK]
            Symbol_rate: 2576384 (=  27.5000)
            FEC_inner: 3 (0x03)  [= 3/4 conv. code rate]

A bit more context can be found in the pastebins below.

TVH log snippet:
http://pastebin.com/ncspSCWm

dvbsnoop snippet:
http://pastebin.com/2q639Xgj

I've been running the patch for 36 hours now and was just about to confirm it fixed the issue as no bad muxes were added. (Typically I'll get bad muxes in a 4h run.)

When trying to watch a channel though I noticed I now always seem to get "Graceperiod Expired". Adapter bandwidth shows 0kb/s so maybe there's no data at all coming through which could also explain no bad muxes. "Graceperiod Expired" issue is discussed here:
https://www.lonelycoder.com/redmine/boards/5/topics/7037?r=7880

Isn't this patch missing something like a dvb_adapter_start_dvr() to re-open the dvr device again after closing on each re-tune?

I pulled from git last night and built 3.5.52~g819b8c8. Unfortunately I still got a bad mux created when running over night.

Mar 12 05:42:49 [  DEBUG]:dvb: /dev/dvb/adapter3 started dvr thread
Mar 12 05:42:51 [  DEBUG]:dvb: "/dev/dvb/adapter3" tuning via s2api to "Viasat: 12,284,000 kHz Vertical (Sirius (Viasat))" (1684000, 27500000 Baud, 3/4, SYS_DVBS, QPSK) for Autoscan
Mar 12 05:42:55 [  DEBUG]:dvb: Configuration for mux "SIRIUS: 12,284,000 kHz Vertical (Sirius (Viasat))" updated by automatic mux discovery
Mar 12 05:43:09 [  DEBUG]:dvb: /dev/dvb/adapter3 stopping thread
Mar 12 05:43:09 [  DEBUG]:dvb: /dev/dvb/adapter3 stopped thread
Mar 12 05:43:09 [  DEBUG]:dvb: /dev/dvb/adapter3 started dvr thread
Mar 12 05:43:11 [  DEBUG]:dvb: "/dev/dvb/adapter3" tuning via s2api to "Telenor: 10,872,000 kHz Horizontal (Thor (Canal Digital))" (1122000, 25000000 Baud, 3/4, SYS_DVBS2, PSK_8) for Autoscan
Mar 12 05:43:11 [ NOTICE]:dvb: New mux "SIRIUS: 12,283,700 kHz Vertical (Thor (Canal Digital))" created by automatic mux discovery
Mar 12 05:43:11 [  DEBUG]:PSI: Service "TurboSight TBS 6984 DVBS/S2 frontend/Telenor: 10,872,000 kHz Horizontal (Thor (Canal Digital))/Yle TV1" PMT (version 9) updated, Stream deleted, PIDs reordered
Mar 12 05:43:12 [  DEBUG]:dvb: /dev/dvb/adapter3 stopping thread
Mar 12 05:43:12 [  DEBUG]:dvb: /dev/dvb/adapter3 stopped thread
Mar 12 05:43:12 [  DEBUG]:dvb: /dev/dvb/adapter3 started dvr thread

Have you seen this, "full TS in Linux: known issue or new one?"?
http://thread.gmane.org/gmane.linux.drivers.video-input-infrastructure/19432

Not sure if it's old and fixed or what the status is but I just tried the attached script and confirmed my expectation. I'm getting thousands of TS packets from the last tuned mux before getting good data from the new mux. Maybe this issue isn't a TVH bug after all but a Linux or TBS problem? Most likely a real problem for TVH users either way.

John,

Thanks for that link, this is what I'd long feared was the problem but no one could definitively answer whether or not we thought this would happen. I had already suggested that we should discard at least the SI table data for a small period of time immediately after locking.

I'll read that thread fully and see what ideas others have.

Adam

I haven't been able to let this one go and I found this ancient thread:
http://www.linuxtv.org/mailinglists/linux-dvb/2004/05-2004/msg00254.html

"Full ACK. The frontend API is specified to be asynchronous, if userland sets filters before the frontend reports successful tuning it's its own fault"

I wrote a simple test program and I have not been able to reproduce the stale data if the demuxer is configured after tuning. If I configure the demuxer before tuning, I get lots of data from the "last" (actually currently) tuned mux before tuning has been updated. This might actually start to make sense and there may be an elegant solution after all.

dvb_fe_tune() first calls dvb_fe_stop() to flush the pipes it then calls dvb_adapter_start() before frontend tuning is done. dvb_adapter_start() will start the dvr thread. The dvr thread will configure the demuxer. I'm guessing the dvr thread is up and running with configured demuxer before the new tuning is done, filling the recently flushed buffers again. Makes sense?

The solution would be to make sure that tuning is initiated and lock has been confirmed before the demuxer is configured.

That's interesting, I actually wrote the code to work like that a few days ago while I was messing about. But I didn't commit it as I was just hacking. I put a "wait for lock" loop in the dvr_adapter_input_dvr() routine. I'll have a look at doing a cleaner solution and if you could test that I'd really appreciate it.

Adam

Can you try this, its a bit of a hack. It blocks the tune process until lock, this is a horrible hack as its done while holding the global lock so slow tuning will wreak havoc with performance! Also its untested ;)

If that appears to do the business though I'll have a re-think about how best to handle the tuning at the fact we need to handle the async nature better than we do.

http://pastebin.com/raw.php?i=YZkBSYWy

Adam

Sure. It's running now and I'll check for bad muxes in the morning.

I had to hardcode count to avoid it being 0.

count  = 100;// * tda->tda_grace_period; 

Ah yes, forgot that was zero by default.

Adam

Sorry to say I still had new bad muxes this morning. (Possibly with lower failure rate.)

I've been looking at the code some more today. Is the tda_table_feed queue flushed anywhere?

No it doesn't, I hadn't spotted that as I saw a flush call to the table code, but it turns out this will not flush the raw feed Q as you rightly point out.

Try this:

http://pastebin.com/raw.php?i=Q2wfDdpw

It should ensure that Q is emptied on fe_stop().

Adam

I applied it on top of your earlier "horrible hack" and restarted. I'll check again tomorrow. It took 7h last night before I got a bad mux created.

ta

I've actually done a proper reworking of the code, though it needs some testing and thinking through (to make sure its right). So "if" this looks good then I'll add this minor mod and think about pushing to master.

Adam

Good news. No bad muxes this morning after 18h. Looks like this might have done it even if it's not 100% guaranteed.

There's a deadlock on tda_delivery_mutex when subscribing to a service though. dvb_service_start() calls dvb_fe_tune() with the mutex already locked.