Project

General

Profile

Graceperiod expired with TBS6984

Added by Hugo Rodenburg almost 12 years ago

Hi all,

I've been a happy TVheadend user for quite a while. Thanks for the wonderful piece of software! In the past I've been using TVheadend with an IPTV provider. However we recently moved to a new place, and decided the switch the setup to DVB-S configuration (also no IPTV services available at our new location).

The configuration consists of a dish satellite with 3 quad LNB's, connected to 4 DiseqC switches, which are then connected to the card. At the moment 2 cables are connected (adapter21 and adapter22). Also our building supplies a single dvb-s feed (1 cable) as an central service of the building and is connected to adapter24 (just to clarify the logs).

The dish is setup/aligned by a friend, which installs them on a daily job and tested it with an professional measuring device, so I think this should be fine.

The tvheadend server is running Ubuntu 12.04 x64, with the latest TBS drivers available at the moment.
In the TVheadend web interface I've configured the diseqc switches for each adapter, then added the services and mapped them to channels. All working fine.

However, sometimes, like this morning when I try to open an radio stream using VLC, the chosen adapter won't be able to get a lock on the transponder (or so it seems to me). After a few retries from VLC, it finally starts streaming and will stay streaming without interruptions for the whole day (which indicated to me the signal is fine). Currently I'm running tvheadend compiled from the git repo at version: 3.3.225~gb42cbe5.

The log shows:

Jan  4 08:17:08 lbk-utr-rt01 tvheadend[17568]: Service: Subscription "HTTP": Adding adapter "_dev_dvb_adapter24_TurboSight_TBS_6984_DVBS_S2_frontend12343500_H_satconf_4" for service "TurboSight TBS 6984 24 (GSO)/CANALDIGITAAL: 12,343,500 kHz Horizontal (a24 LNB1)/NL-3FM" 
Jan  4 08:17:08 lbk-utr-rt01 tvheadend[17568]: Service: Subscription "HTTP": Adding adapter "_dev_dvb_adapter22_TurboSight_TBS_6984_DVBS_S2_frontend12343500_H_satconf_2" for service "TurboSight TBS 6984 22/CANALDIGITAAL: 12,343,500 kHz Horizontal (a22 LNB1)/NL-3FM" 
Jan  4 08:17:08 lbk-utr-rt01 tvheadend[17568]: Service: Subscription "HTTP": Adding adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend12343500_H_satconf_1" for service "TurboSight TBS 6984 21/CANALDIGITAAL: 12,343,500 kHz Horizontal (a21 LNB1)/NL-3FM" 
Jan  4 08:17:08 lbk-utr-rt01 tvheadend[17568]: Service: Subscription "HTTP": Probing adapter "_dev_dvb_adapter22_TurboSight_TBS_6984_DVBS_S2_frontend12343500_H_satconf_2" without stealing for service "TurboSight TBS 6984 22/CANALDIGITAAL: 12,343,500 kHz Horizontal (a22 LNB1)/NL-3FM" 
Jan  4 08:17:09 lbk-utr-rt01 tvheadend[17568]: dvb: "/dev/dvb/adapter22" tuning via s2api to "CANALDIGITAAL: 12,343,500 kHz Horizontal (a22 LNB1)" (1743500, 27500000 Baud, 3/4, SYS_DVBS, QPSK) for Transport start

Jan  4 08:17:09 lbk-utr-rt01 tvheadend[17568]: viasat_baltic: install table handlers
Jan  4 08:17:09 lbk-utr-rt01 tvheadend[17568]: uk_freesat: install table handlers
Jan  4 08:17:09 lbk-utr-rt01 tvheadend[17568]: eit: install table handlers
Jan  4 08:17:09 lbk-utr-rt01 tvheadend[17568]: cwc: TurboSight TBS 6984 22/CANALDIGITAAL: 12,343,500 kHz Horizontal (a22 LNB1)/NL-3FM using CWC 172.30.50.8:15050
Jan  4 08:17:09 lbk-utr-rt01 tvheadend[17568]: subscription: "HTTP" subscribing on "NL-3FM", weight: 100, adapter: "TurboSight TBS 6984 22", network: "CANALDIGITAAL", mux: "CANALDIGITAAL: 12,343,500 kHz Horizontal (a22 LNB1)", provider: "CANALDIGITAAL", service: "NL-3FM", quality: 100
Jan  4 08:17:14 lbk-utr-rt01 tvheadend[17568]: dvb: "CANALDIGITAAL: 12,343,500 kHz Horizontal (a22 LNB" on adapter "TurboSight TBS 6984 22", status changed to Faint signal
Jan  4 08:17:19 lbk-utr-rt01 tvheadend[17568]: Service: TurboSight TBS 6984 22/CANALDIGITAAL: 12,343,500 kHz Horizontal (a22 LNB1)/NL-3FM: Status changed to [Graceperiod expired] 

Jan  4 08:17:20 lbk-utr-rt01 tvheadend[17568]: Service: Subscription "HTTP": Adding adapter "_dev_dvb_adapter24_TurboSight_TBS_6984_DVBS_S2_frontend12343500_H_satconf_4" for service "TurboSight TBS 6984 24 (GSO)/CANALDIGITAAL: 12,343,500 kHz Horizontal (a24 LNB1)/NL-3FM" 
Jan  4 08:17:20 lbk-utr-rt01 tvheadend[17568]: Service: Subscription "HTTP": Adding adapter "_dev_dvb_adapter22_TurboSight_TBS_6984_DVBS_S2_frontend12343500_H_satconf_2" for service "TurboSight TBS 6984 22/CANALDIGITAAL: 12,343,500 kHz Horizontal (a22 LNB1)/NL-3FM" 
Jan  4 08:17:20 lbk-utr-rt01 tvheadend[17568]: Service: Subscription "HTTP": Adding adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend12343500_H_satconf_1" for service "TurboSight TBS 6984 21/CANALDIGITAAL: 12,343,500 kHz Horizontal (a21 LNB1)/NL-3FM" 
Jan  4 08:17:20 lbk-utr-rt01 tvheadend[17568]: webui: Couldn't start streaming /stream/channelid/455?ticket=3CC2310D5A379C5D5F5FF1E269BE127FB40DA5E3, No input detected
Jan  4 08:17:20 lbk-utr-rt01 tvheadend[17568]: subscription: "HTTP" unsubscribing from "NL-3FM" 

The message "status changed to Faint signal" indicates a bad signal, but I find this hard to believe. A few moments later it is streaming really well from the same adapter:

Jan  4 08:22:21 lbk-utr-rt01 tvheadend[17568]: Service: Subscription "HTTP": Adding adapter "_dev_dvb_adapter24_TurboSight_TBS_6984_DVBS_S2_frontend12343500_H_satconf_4" for service "TurboSight TBS 6984 24 (GSO)/CANALDIGITAAL: 12,343,500 kHz Horizontal (a24 LNB1)/NL-3FM" 
Jan  4 08:22:21 lbk-utr-rt01 tvheadend[17568]: Service: Subscription "HTTP": Adding adapter "_dev_dvb_adapter22_TurboSight_TBS_6984_DVBS_S2_frontend12343500_H_satconf_2" for service "TurboSight TBS 6984 22/CANALDIGITAAL: 12,343,500 kHz Horizontal (a22 LNB1)/NL-3FM" 
Jan  4 08:22:21 lbk-utr-rt01 tvheadend[17568]: Service: Subscription "HTTP": Adding adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend12343500_H_satconf_1" for service "TurboSight TBS 6984 21/CANALDIGITAAL: 12,343,500 kHz Horizontal (a21 LNB1)/NL-3FM" 
Jan  4 08:22:21 lbk-utr-rt01 tvheadend[17568]: Service: Subscription "HTTP": Probing adapter "_dev_dvb_adapter22_TurboSight_TBS_6984_DVBS_S2_frontend12343500_H_satconf_2" without stealing for service "TurboSight TBS 6984 22/CANALDIGITAAL: 12,343,500 kHz Horizontal (a22 LNB1)/NL-3FM" 
Jan  4 08:22:22 lbk-utr-rt01 tvheadend[17568]: dvb: "/dev/dvb/adapter22" tuning via s2api to "CANALDIGITAAL: 12,343,500 kHz Horizontal (a22 LNB1)" (1743500, 27500000 Baud, 3/4, SYS_DVBS, QPSK) for Transport start
Jan  4 08:22:22 lbk-utr-rt01 tvheadend[17568]: viasat_baltic: install table handlers
Jan  4 08:22:22 lbk-utr-rt01 tvheadend[17568]: uk_freesat: install table handlers
Jan  4 08:22:22 lbk-utr-rt01 tvheadend[17568]: eit: install table handlers
Jan  4 08:22:22 lbk-utr-rt01 tvheadend[17568]: cwc: TurboSight TBS 6984 22/CANALDIGITAAL: 12,343,500 kHz Horizontal (a22 LNB1)/NL-3FM using CWC 172.30.50.8:15050
Jan  4 08:22:22 lbk-utr-rt01 tvheadend[17568]: subscription: "HTTP" subscribing on "NL-3FM", weight: 100, adapter: "TurboSight TBS 6984 22", network: "CANALDIGITAAL", mux: "CANALDIGITAAL: 12,343,500 kHz Horizontal (a22 LNB1)", provider: "CANALDIGITAAL", service: "NL-3FM", quality: 100
Jan  4 08:22:22 lbk-utr-rt01 tvheadend[17568]: Service: TurboSight TBS 6984 22/CANALDIGITAAL: 12,343,500 kHz Horizontal (a22 LNB1)/NL-3FM: Status changed to [Hardware input] 
Jan  4 08:22:22 lbk-utr-rt01 tvheadend[17568]: Service: TurboSight TBS 6984 22/CANALDIGITAAL: 12,343,500 kHz Horizontal (a22 LNB1)/NL-3FM: Status changed to [Hardware input] [Input on service] 
Jan  4 08:22:22 lbk-utr-rt01 tvheadend[17568]: eit: begin processing
Jan  4 08:22:22 lbk-utr-rt01 tvheadend[17568]: Service: TurboSight TBS 6984 22/CANALDIGITAAL: 12,343,500 kHz Horizontal (a22 LNB1)/NL-3FM: Status changed to [Hardware input] [Input on service] [Demuxed packets] 
Jan  4 08:22:22 lbk-utr-rt01 tvheadend[17568]: cwc: Insert only one new ECM channel 1862 for service id 2057
Jan  4 08:22:22 lbk-utr-rt01 tvheadend[17568]: PSI: Service "TurboSight TBS 6984 22/CANALDIGITAAL: 12,343,500 kHz Horizontal (a22 LNB1)/Animal Planet/TLC" PMT (version 9) updated, New CA stream, New CAID
Jan  4 08:22:22 lbk-utr-rt01 tvheadend[17568]: cwc: Sending ECM (channel 1862) section=0/0, for service NL-3FM (seqno: 7487) PID 1862
Jan  4 08:22:23 lbk-utr-rt01 tvheadend[17568]: cwc: es->es_nok 0      t->tht_prefcapid 1862
Jan  4 08:22:23 lbk-utr-rt01 tvheadend[17568]: cwc: Received ECM reply (channel 1862) for service "NL-3FM" even: e9.81.53.bd.52.c4.91.a7 odd: 37.b3.bb.a5.95.d4.3a.a3 (seqno: 7487 Req delay: 324 ms)
Jan  4 08:22:23 lbk-utr-rt01 tvheadend[17568]: cwc: Obtained key for service "NL-3FM" in 324 ms, from 172.30.50.8:15050

What could be causing this? Should I really recheck my hardware/cables? Could there something be wrong with my diseqc config?
Does someone has a hint on how to debug further?

Also the log shows quite a number of "status changed to Bad/Faint signal" messages. Is this normal behaviour? (ie the adapter changed to different diseqc input or transponder?). Or should this not be happening?

I also have another system with an TBS6981 card, connected to the same dish (the other 2 cables) which has exactly the same issues.

femon shows the following info:
A high snr ratio is a good thing?

femon -a 22 -H
FE: TurboSight TBS 6984 DVBS/S2 frontend (DVBS)
status SCVYL | signal  74% | snr  84% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  74% | snr  84% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  74% | snr  84% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  74% | snr  83% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  74% | snr  85% | ber 0 | unc 0 | FE_HAS_LOCK

If you're still reading, thanks!
Hopefully someone can push me in the right direction to get this sorted out! If more information is needed, don't hesitate to ask.

Thanks in advance.

Hugo


Replies (29)

RE: Graceperiod expired with TBS6984 - Added by Hugo Rodenburg almost 12 years ago

Hi,

I still haven't this figured this out. With my XBMC frontend I sometimes get "no input detected" when changing channels. After some time, the channel automatically starts playing/streaming.
The following is found in the logs on the tvheadend server.

Jan 11 09:43:20 lbk-utr-rt01 tvheadend[13707]: Service: TurboSight TBS 6984 21/CANALDIGITAAL: 12,187,000 kHz Horizontal (a21 LNB2)/RTL7 HD: Status changed to [Graceperiod expired]

And repeats this message a few times.
After about 40 seconds, the adapters succeeds, and the channel start playing. And will play for hours without any problem. This happens on multiple inputs on the adapter.

Jan 11 09:44:07 lbk-utr-rt01 tvheadend[13707]: Service: TurboSight TBS 6984 21/CANALDIGITAAL: 12,187,000 kHz Horizontal (a21 LNB2)/RTL7 HD: Status changed to [Hardware input] [Input on service] [Demuxed packets] [Reassembled packets] 

Jan 11 09:44:07 lbk-utr-rt01 tvheadend13707: dvb: "CANALDIGITAAL: 12,187,000 kHz Horizontal (a21 LNB" on adapter "TurboSight TBS 6984 21", status changed to OK

Anyone else experiencing this? Or does anyone know what this might be causing this?

Thanks in advance.

Hugo

Configuration mix-up by auto mux discovery - Added by Hugo Rodenburg almost 12 years ago

Hi again,

I might have find an issue which is causing this behavior.
It seems that for some reason the auto mux discovery is mixing up the configuration.
In this case, on the second (22) adapter, the settings are different than on the first. Adjusted by the auto mux discovery.
It seems the discovery function cannot make up it's mind because the settings are going back and forth.
PSK_8 and DVBS2 are the correct parameters.
And LNB2 is pointed at Astra 23.5 btw.

root@lbk-utr-rt01:/home/hts/.hts/tvheadend# grep '11,739,000' /var/log/syslog | grep 'updated by automatic mux discovery' | grep a21 | tail
Jan 27 20:31:47 lbk-utr-rt01 tvheadend[6305]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a21 LNB2)" updated by automatic mux discovery ( PSK_8->QPSK,  SYS_DVBS2->SYS_DVBS,  ROLLOFF_25->ROLLOFF_35, )
Jan 27 20:36:06 lbk-utr-rt01 tvheadend[6305]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a21 LNB2)" updated by automatic mux discovery ( QPSK->PSK_8,  SYS_DVBS->SYS_DVBS2,  ROLLOFF_35->ROLLOFF_25, )
Jan 27 20:50:11 lbk-utr-rt01 tvheadend[17099]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a21 LNB2)" updated by automatic mux discovery ( PSK_8->QPSK,  SYS_DVBS2->SYS_DVBS,  ROLLOFF_25->ROLLOFF_35, )
Jan 27 20:54:53 lbk-utr-rt01 tvheadend[17099]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a21 LNB2)" updated by automatic mux discovery ( QPSK->PSK_8,  SYS_DVBS->SYS_DVBS2,  ROLLOFF_35->ROLLOFF_25, )
Jan 27 20:58:07 lbk-utr-rt01 tvheadend[17099]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a21 LNB2)" updated by automatic mux discovery ( PSK_8->QPSK, )
Jan 27 20:59:39 lbk-utr-rt01 tvheadend[17099]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a21 LNB2)" updated by automatic mux discovery ( QPSK->PSK_8, )
Jan 27 20:59:46 lbk-utr-rt01 tvheadend[17099]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a21 LNB2)" updated by automatic mux discovery ( PSK_8->QPSK,  SYS_DVBS2->SYS_DVBS,  ROLLOFF_25->ROLLOFF_35, )
Jan 27 20:59:56 lbk-utr-rt01 tvheadend[17099]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a21 LNB2)" updated by automatic mux discovery ( QPSK->PSK_8,  SYS_DVBS->SYS_DVBS2,  ROLLOFF_35->ROLLOFF_25, )
Jan 27 21:03:27 lbk-utr-rt01 tvheadend[17099]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a21 LNB2)" updated by automatic mux discovery ( PSK_8->QPSK,  SYS_DVBS2->SYS_DVBS,  ROLLOFF_25->ROLLOFF_35, )
Jan 27 21:14:21 lbk-utr-rt01 tvheadend[17099]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a21 LNB2)" updated by automatic mux discovery ( QPSK->PSK_8,  SYS_DVBS->SYS_DVBS2,  ROLLOFF_35->ROLLOFF_25, )
root@lbk-utr-rt01:/home/hts/.hts/tvheadend# grep '11,739,000' /var/log/syslog | grep 'updated by automatic mux discovery' | grep a22 | tail    
Jan 27 14:56:29 lbk-utr-rt01 tvheadend[3262]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a22 LNB2)" updated by automatic mux discovery ( QPSK->PSK_8,  SYS_DVBS->SYS_DVBS2,  ROLLOFF_35->ROLLOFF_25, )
Jan 27 14:56:49 lbk-utr-rt01 tvheadend[3262]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a22 LNB2)" updated by automatic mux discovery ( PSK_8->QPSK,  SYS_DVBS2->SYS_DVBS,  ROLLOFF_25->ROLLOFF_35, )
Jan 27 15:01:50 lbk-utr-rt01 tvheadend[3262]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a22 LNB2)" updated by automatic mux discovery ( QPSK->PSK_8,  SYS_DVBS->SYS_DVBS2,  ROLLOFF_35->ROLLOFF_25, )
Jan 27 15:02:48 lbk-utr-rt01 tvheadend[3262]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a22 LNB2)" updated by automatic mux discovery ( PSK_8->QPSK,  SYS_DVBS2->SYS_DVBS,  ROLLOFF_25->ROLLOFF_35, )
Jan 27 15:06:35 lbk-utr-rt01 tvheadend[3262]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a22 LNB2)" updated by automatic mux discovery ( QPSK->PSK_8,  SYS_DVBS->SYS_DVBS2,  ROLLOFF_35->ROLLOFF_25, )
Jan 27 15:08:15 lbk-utr-rt01 tvheadend[3262]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a22 LNB2)" updated by automatic mux discovery ( PSK_8->QPSK, )
Jan 27 15:38:38 lbk-utr-rt01 tvheadend[3262]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a22 LNB2)" updated by automatic mux discovery ( QPSK->PSK_8, )
Jan 27 15:50:38 lbk-utr-rt01 tvheadend[3262]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a22 LNB2)" updated by automatic mux discovery ( PSK_8->QPSK,  SYS_DVBS2->SYS_DVBS,  ROLLOFF_25->ROLLOFF_35, )
Jan 27 15:51:38 lbk-utr-rt01 tvheadend[3262]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a22 LNB2)" updated by automatic mux discovery ( QPSK->PSK_8,  SYS_DVBS->SYS_DVBS2,  ROLLOFF_35->ROLLOFF_25, )
Jan 27 21:32:07 lbk-utr-rt01 tvheadend[17099]: dvb: Configuration for mux "CANALDIGITAAL: 11,739,000 kHz Vertical (a22 LNB2)" updated by automatic mux discovery ( PSK_8->QPSK,  SYS_DVBS2->SYS_DVBS,  ROLLOFF_25->ROLLOFF_35, )

In this case I could not get a lock on the channel on adapter22 because it changed the configuration with incorrect parameters.
When I adjusted the prio of the adapters, so that adapter21 would be chosen, the channel locks and streaming started.

To verify, I checked the configuration files of the adapters, and they match the output of the log file.

root@lbk-utr-rt01:/home/hts/.hts/tvheadend/dvbmuxes/_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend# cat _dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_5         
{
        "quality": 100,
        "enabled": 1,
        "status": "Bad signal",
        "transportstreamid": 3202,
        "originalnetworkid": 3,
        "network": "CANALDIGITAAL",
        "frequency": 11739000,
        "initialscan": 0,
        "symbol_rate": 27500000,
        "fec": "2/3",
        "polarisation": "Vertical",
        "modulation": "PSK_8",
        "delivery_system": "SYS_DVBS2",
        "rolloff": "ROLLOFF_25",
        "satconf": "5" 
}

root@lbk-utr-rt01:/home/hts/.hts/tvheadend/dvbmuxes# cat _dev_dvb_adapter22_TurboSight_TBS_6984_DVBS_S2_frontend/_dev_dvb_adapter22_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_8
{
        "quality": 100,
        "enabled": 1,
        "status": "Faint signal",
        "transportstreamid": 3202,
        "originalnetworkid": 3,
        "network": "CANALDIGITAAL",
        "frequency": 11739000,
        "initialscan": 0,
        "symbol_rate": 27500000,
        "fec": "3/4",
        "polarisation": "Vertical",
        "modulation": "QPSK",
        "delivery_system": "SYS_DVBS",
        "rolloff": "ROLLOFF_35",
        "satconf": "8" 
}

root@lbk-utr-rt01:/home/hts/.hts/tvheadend# cat dvbsatconf/_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend/5
{
        "id": "5",
        "port": 1,
        "name": "a21 LNB2",
        "comment": "a21 LNB2",
        "lnb": "Universal" 
}
root@lbk-utr-rt01:/home/hts/.hts/tvheadend# cat dvbsatconf/_dev_dvb_adapter22_TurboSight_TBS_6984_DVBS_S2_frontend/8 
{
        "id": "8",
        "port": 1,
        "name": "a22 LNB2",
        "comment": "a22 LNB2",
        "lnb": "Universal" 
}

Could there be something wrong with the auto update mechanism? Should I file a bug?
I will see if I can make an up-to-date list of muxes from lyngsat/kingofsat and put them in the source so I can disable the mux discovery.
If this goed well I may even submit an pull request so an up-to-date list of muxes is in tvheadend. But I haven't looked at the code of the standard defined muxes yet.

Thanks for any help.

Hugo

RE: Graceperiod expired with TBS6984 - Added by Adam Sutton almost 12 years ago

Hugo,

Please don't submit bug reports, pull requests etc... for the tuning files we don't maintain them we simply pull the latest set from linuxtv (also the owner of those files has recently changed and they should be more actively managed now).

With regard to the mux auto update stuff, definitely something weird going on there. I'm in the process of doing some updates to the scanning code and one thing I was going to do was add some more detailed debug, might need that to understand what is happening. However in the mean time feel free to submit a bug report for this as its clearly wrong.

Adam

RE: Graceperiod expired with TBS6984 - Added by Hugo Rodenburg almost 12 years ago

Hi Adam,

Thanks for your reply.
After a short look I already noticed the that the tuning files are from a different source, so I won't file pull requests etc.
I will submit a bug report for the mux update stuff. I have no idea how the update mechanism works, but perhaps with more detailed/verbose debug logging this issue can be traced?

However I came to the conclusion it does not relate to my issue explained in my first post. I still haven't figured out what is causing this.
Adam, you are (also) using an TBS 6981 card, right? What kernel version and driver version are you using?
I'm using: Ubuntu 12.04 AMD64 3.2.0-36-generic. And driver version: 121119

Any idea how I can track down this issue?

Thanks.

Hugo

RE: Graceperiod expired with TBS6984 - Added by Adam Sutton almost 12 years ago

Hugo,

One thing that would be interesting to look at is I've added a bandwidth field to the adapter part of the status page. It would be nice to see whether there is any traffic flowing when you're seeing these grace period expired issues.

I'm using exactly the same kernel ver as you, but can't remember of the top of my head what driver version it is, but I updated recently. However the only time I've had these issues are very occasionally after TVH startup, once its been running a few mins its always been fine. So I have always thought there could be a software issue here, but since my server is rarely stopped I've never had the inclination to investigate further.

Adam

RE: Graceperiod expired with TBS6984 - Added by Hugo Rodenburg almost 12 years ago

Hi Adam,

When the issue occurs, the status page lists the following information:
State: alternating between "testing" and "bad"
Errors: remains "0"
Bandwith: remains "0"

The system is 24/7 running, so tvheadend is running practically all the time, so it's not just an startup issue.

Maybe (and more like probably) I am completely wrong, but I suspect the diseqc mechanism. I assume that when opening an channel, the software sends an command for port selection to the diseqc switch, and then tune's the lnb at the right frequency. Is this assumption correct?
What if the diseqc command fails, or isn't correctly issued? This also would explain the behaviour in bug: #1586
Is there a way to check what commands are issued to the switch?
By the way I'm using Spaun switches, which supposed to be good quality switches.

Hugo

RE: Graceperiod expired with TBS6984 - Added by Hugo Rodenburg almost 12 years ago

I just noticed you're probably referencing to the bandwith option in your commit from yesterday. I will update my version and report back with my findings.

RE: Graceperiod expired with TBS6984 - Added by Adam Sutton almost 12 years ago

Indeed, that new info will give an indication of whether there is actually data flowing in from the adapter. What I'm trying to distinguish is whether there is actually nothing being received at all OR TVH is seeing nothing for the relevant service. The latter could be caused by a software processing bug, i.e. the data is there TVH just isn't recognising it as such.

If no data is being received by the adapter, that's far more likely to indicate an error outside of TVH (at least at the point of failure). But you could be right that its possible the diseqc commands have gone wrong and that we're not actually on the right switch port. I believe that the latest code does allow you to set it to resend commands several times to increase chance of success. Unfortunately there are 2 variants of diseqc (actually its more) one is not answered, i.e. you send the command and hope. The other does provide feedback, but we don't currently support that. So its basically hit and hope (hence teh addition of the retries).

#1586 is probably a diff issue and the way TVH is dealing with muxes internally, buts its not impossible.

Adam

RE: Graceperiod expired with TBS6984 - Added by Hugo Rodenburg over 11 years ago

Hi Adam,

Sorry for the delay (quite busy at work), but I do have some testing results.
When the error occurs, the status page displays no traffic flowing through the adapter (the bandwith column remains 0). Also see attached screenshot. The log shows errors similar to above (graceperiod expired messages).
However, when I briefly disable the adapter on the adapter page, and enable it again, the channel starts streaming after about 2 seconds from that adapter. This method resolved it about 4 times successfully when the issue occurred.

The log file information:

Feb 10 09:45:03 lbk-utr-rt01 tvheadend[16290]: htsp: using timeshift buffer (60 mins)
Feb 10 09:45:03 lbk-utr-rt01 tvheadend[16290]: Service: Subscription "172.30.50.26 [ xbmc | XBMC Media Center ]": Adding adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_1" for service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance" 
Feb 10 09:45:03 lbk-utr-rt01 tvheadend[16290]: Service: Subscription "172.30.50.26 [ xbmc | XBMC Media Center ]": Probing adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_1" without stealing for service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance" 
Feb 10 09:45:03 lbk-utr-rt01 tvheadend[16290]: diseqc: fe_fd 20, lnb_num 0, voltage 0, band 1, version 0, repeats 0
Feb 10 09:45:04 lbk-utr-rt01 tvheadend[16290]: diseqc: sending E0 10 39 F0 0 0
Feb 10 09:45:04 lbk-utr-rt01 tvheadend[16290]: diseqc: sending E0 10 38 F1 0 0
Feb 10 09:45:04 lbk-utr-rt01 tvheadend[16290]: dvb: "/dev/dvb/adapter21" tuning via s2api to "ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)" (1139000, 27500000 Baud, 3/4, SYS_DVBS, QPSK) for Transport start
Feb 10 09:45:04 lbk-utr-rt01 tvheadend[16290]: viasat_baltic: install table handlers
Feb 10 09:45:04 lbk-utr-rt01 tvheadend[16290]: uk_freesat: install table handlers
Feb 10 09:45:04 lbk-utr-rt01 tvheadend[16290]: eit: install table handlers
Feb 10 09:45:04 lbk-utr-rt01 tvheadend[16290]: cwc: TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance using CWC 172.30.50.8:15050
Feb 10 09:45:04 lbk-utr-rt01 tvheadend[16290]: subscription: "172.30.50.26 [ xbmc | XBMC Media Center ]" subscribing on "MTV Dance", weight: 150, adapter: "TurboSight TBS 6984 21", network: "ASTRA 1", mux: "ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)", provider: "MTV Networks Europe", service: "MTV Dance", quality: 100
Feb 10 09:45:04 lbk-utr-rt01 tvheadend[16290]: Service: TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance: Status changed to [Hardware input]
Feb 10 09:45:04 lbk-utr-rt01 tvheadend[16290]: eit: begin processing
Feb 10 09:45:09 lbk-utr-rt01 tvheadend[16290]: dvb: "ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)" on adapter "TurboSight TBS 6984 21", status changed to Faint signal
Feb 10 09:45:24 lbk-utr-rt01 tvheadend[16290]: Service: TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance: Status changed to [Hardware input] [Graceperiod expired]
Feb 10 09:45:26 lbk-utr-rt01 tvheadend[16290]: Service: Subscription "172.30.50.26 [ xbmc | XBMC Media Center ]": Adding adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_1" for service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance" 
Feb 10 09:45:28 lbk-utr-rt01 tvheadend[16290]: Service: Subscription "172.30.50.26 [ xbmc | XBMC Media Center ]": Adding adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_1" for service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance" 
Feb 10 09:45:28 lbk-utr-rt01 tvheadend[16290]: Service: Subscription "172.30.50.26 [ xbmc | XBMC Media Center ]": Probing adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_1" without stealing for service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance" 
Feb 10 09:45:28 lbk-utr-rt01 tvheadend[16290]: cwc: TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance using CWC 172.30.50.8:15050
Feb 10 09:45:48 lbk-utr-rt01 tvheadend[16290]: Service: TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance: Status changed to [Graceperiod expired]
Feb 10 09:45:50 lbk-utr-rt01 tvheadend[16290]: Service: Subscription "172.30.50.26 [ xbmc | XBMC Media Center ]": Adding adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_1" for service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance" 
Feb 10 09:45:52 lbk-utr-rt01 tvheadend[16290]: Service: Subscription "172.30.50.26 [ xbmc | XBMC Media Center ]": Adding adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_1" for service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance" 
Feb 10 09:45:52 lbk-utr-rt01 tvheadend[16290]: Service: Subscription "172.30.50.26 [ xbmc | XBMC Media Center ]": Probing adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_1" without stealing for service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance" 
Feb 10 09:45:52 lbk-utr-rt01 tvheadend[16290]: cwc: TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance using CWC 172.30.50.8:15050
Feb 10 09:46:12 lbk-utr-rt01 tvheadend[16290]: Service: TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance: Status changed to [Graceperiod expired]
Feb 10 09:46:14 lbk-utr-rt01 tvheadend[16290]: Service: Subscription "172.30.50.26 [ xbmc | XBMC Media Center ]": Adding adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_1" for service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance" 
Feb 10 09:46:16 lbk-utr-rt01 tvheadend[16290]: Service: Subscription "172.30.50.26 [ xbmc | XBMC Media Center ]": Adding adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_1" for service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance" 
Feb 10 09:46:16 lbk-utr-rt01 tvheadend[16290]: Service: Subscription "172.30.50.26 [ xbmc | XBMC Media Center ]": Probing adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_1" without stealing for service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance" 
Feb 10 09:46:16 lbk-utr-rt01 tvheadend[16290]: cwc: TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance using CWC 172.30.50.8:15050
Feb 10 09:46:36 lbk-utr-rt01 tvheadend[16290]: Service: TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance: Status changed to [Graceperiod expired]
Feb 10 09:46:37 lbk-utr-rt01 tvheadend[16290]: Service: Subscription "172.30.50.26 [ xbmc | XBMC Media Center ]": Adding adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_1" for service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance" 
Feb 10 09:46:39 lbk-utr-rt01 tvheadend[16290]: Service: Subscription "172.30.50.26 [ xbmc | XBMC Media Center ]": Adding adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_1" for service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance" 
Feb 10 09:46:39 lbk-utr-rt01 tvheadend[16290]: Service: Subscription "172.30.50.26 [ xbmc | XBMC Media Center ]": Probing adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_1" without stealing for service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance" 
Feb 10 09:46:39 lbk-utr-rt01 tvheadend[16290]: cwc: TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance using CWC 172.30.50.8:15050
Feb 10 09:46:55 lbk-utr-rt01 tvheadend[16290]: dvb: Adapter "TurboSight TBS 6984 21" Disabled
Feb 10 09:46:55 lbk-utr-rt01 tvheadend[16290]: eit: processing cancelled
Feb 10 09:46:55 lbk-utr-rt01 tvheadend[16290]: dvb: /dev/dvb/adapter21 closing frontend
Feb 10 09:46:55 lbk-utr-rt01 tvheadend[16290]: dvb: /dev/dvb/adapter21 stopping thread
Feb 10 09:46:55 lbk-utr-rt01 tvheadend[16290]: dvb: /dev/dvb/adapter21 stopped thread
Feb 10 09:46:57 lbk-utr-rt01 tvheadend[16290]: dvb: "CANALDIGITAAL: 12,129,000 kHz Vertical (a22 LNB2)" on adapter "TurboSight TBS 6984 22", status changed to Bursty FEC
Feb 10 09:46:58 lbk-utr-rt01 tvheadend[16290]: dvb: TurboSight TBS 6984 22: FE_READ_UNCORRECTED_BLOCKS returns delta updates (delta=-4091)
Feb 10 09:46:58 lbk-utr-rt01 tvheadend[16290]: dvb: Adapter "TurboSight TBS 6984 21" Enabled
Feb 10 09:46:59 lbk-utr-rt01 tvheadend[16290]: Service: TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance: Status changed to [Graceperiod expired]
Feb 10 09:47:01 lbk-utr-rt01 tvheadend[16290]: Service: Subscription "172.30.50.26 [ xbmc | XBMC Media Center ]": Adding adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_1" for service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance" 
Feb 10 09:47:03 lbk-utr-rt01 tvheadend[16290]: Service: Subscription "172.30.50.26 [ xbmc | XBMC Media Center ]": Adding adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_1" for service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance" 
Feb 10 09:47:03 lbk-utr-rt01 tvheadend[16290]: Service: Subscription "172.30.50.26 [ xbmc | XBMC Media Center ]": Probing adapter "_dev_dvb_adapter21_TurboSight_TBS_6984_DVBS_S2_frontend11739000_V_satconf_1" without stealing for service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance" 
Feb 10 09:47:03 lbk-utr-rt01 tvheadend[16290]: dvb: /dev/dvb/adapter21 opened frontend /dev/dvb/adapter21/frontend0
Feb 10 09:47:03 lbk-utr-rt01 tvheadend[16290]: dvb: /dev/dvb/adapter21 started dvr thread
Feb 10 09:47:03 lbk-utr-rt01 tvheadend[16290]: diseqc: fe_fd 20, lnb_num 0, voltage 0, band 1, version 0, repeats 0
Feb 10 09:47:04 lbk-utr-rt01 tvheadend[16290]: diseqc: sending E0 10 39 F0 0 0
Feb 10 09:47:04 lbk-utr-rt01 tvheadend[16290]: diseqc: sending E0 10 38 F1 0 0
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: dvb: "/dev/dvb/adapter21" tuning via s2api to "ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)" (1139000, 27500000 Baud, 3/4, SYS_DVBS, QPSK) for Transport start
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: viasat_baltic: install table handlers
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: uk_freesat: install table handlers
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: eit: install table handlers
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: cwc: TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance using CWC 172.30.50.8:15050
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: Service: TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance: Status changed to [Hardware input]
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: Service: TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance: Status changed to [Hardware input] [Input on service]
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: eit: begin processing
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: Service: TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance: Status changed to [Hardware input] [Input on service] [Demuxed packets]
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: cwc: Insert only one new ECM channel 6413 for service id 28655
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: epg: now/next 1256063/0 set on MTV Hits
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: epg: arm channel timer @ 1360486200 for MTV Hits
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: epg: inform HTSP of now event change on MTV Hits
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: cwc: Sending ECM (channel 6413) section=0/0, for service MTV Dance (seqno: 17732) PID 6413
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux ": 11,626,500 kHz Vertical (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux ": 11,082,250 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: epg: now/next 1256063/1256065 set on MTV Hits
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: epg: arm channel timer @ 1360486200 for MTV Hits
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: cwc: es->es_nok 0      t->tht_prefcapid 6413
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: cwc: Received ECM reply (channel 6413) for service "MTV Dance" even: 4f.29.47.bf.56.7f.c4.99 odd: 07.bf.3c.02.a5.99.74.b2 (seqno: 17732 Req delay: 64 ms)
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: cwc: Obtained key for service "MTV Dance" in 64 ms, from 172.30.50.8:15050
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: epg: now/next 0/1256069 set on MTV Dance
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: epg: arm channel timer @ 1360686600 for MTV Dance
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: PSI: Service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Hits" PMT (version 14) updated, PCR PID changed, New elementary stream, New CA stream, New CAID, PIDs reordered
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: epg: now/next 1256073/1256069 set on MTV Dance
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: epg: arm channel timer @ 1360486200 for MTV Dance
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: epg: inform HTSP of now event change on MTV Dance
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: Service: TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/MTV Dance: Status changed to [Hardware input] [Input on service] [Demuxed packets] [Reassembled packets]
Feb 10 09:47:05 lbk-utr-rt01 tvheadend[16290]: PSI: Service "TurboSight TBS 6984 21/ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)/NICKELODEON France" PMT (version 14) updated, PCR PID changed, New elementary stream, Language changed, New CA stream, New CAID, Parent PID changed, PIDs reordered
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 11,797,500 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 11,719,500 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 12,031,500 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 12,070,500 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 11,758,500 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 11,914,500 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 11,992,500 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 12,304,500 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 12,382,500 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 11,875,500 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 11,332,250 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 10,920,750 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 12,148,500 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 12,460,500 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 12,480,000 kHz Vertical (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 10,861,750 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 12,344,000 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: Configuration for mux "ASTRA 1: 12,515,250 kHz Horizontal (a21 LNB1)" updated by automatic mux discovery
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: dvb: "ASTRA 1: 11,739,000 kHz Vertical (a21 LNB1)" on adapter "TurboSight TBS 6984 21", status changed to OK
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: epg: now/next 1256063/1256093 set on MTV Hits
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: epg: arm channel timer @ 1360486200 for MTV Hits
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: epg: now/next 1256073/1256095 set on MTV Dance
Feb 10 09:47:06 lbk-utr-rt01 tvheadend[16290]: epg: arm channel timer @ 1360486200 for MTV Dance

Notice also the "updated mux" messages. This is quite strange because these options are disabled on all adapters. But this is might be a completely different "issue".

RE: Graceperiod expired with TBS6984 - Added by John Smith over 11 years ago

Hello. Just wanted to let you know that I'm facing similar issues and would be happy to help debug. I'm also using TBS6984 on Ubuntu 12.04 x64. I've got 2 quattro LNBs connected via an EMP multiswitch. I get signal lock even on freq/pol combinations that should only be available on one port of the switch. The signal and snr reported both in "Status" tab and by dvbsnoop is fine (and identical) but I get graceperiod expired and bandwidth is 0. However disabling/enabling the adapters does not help at the moment. Neither does restarting TVH. Rebooting the server is the only reliable way I've found to (temporarily) fix the problem. Let me know if there's anything I can do to help.

RE: Graceperiod expired with TBS6984 - Added by John Smith over 11 years ago

I think my issue requiring reboot may be a slightly different issue. After rebooting and trying some more I now also see a behavior where I sometimes get graceperiod expired for some time before a stream starts working. Disable/enable adapter solves this problem. When checking status tab I've seen a situation where bandwidth on adapter is <>0 but bandwidth on service is 0. (Suggesting that TVH is getting data but can't find my service?) I'll continue testing tomorrow.

RE: Graceperiod expired with TBS6984 - Added by John Smith over 11 years ago

I've spent hours trying to find a conclusive pattern today and failed. This is what I think I see right now:
- With 2 adapters enabled (2 disabled), no autodetect muxes or idle scanning
- Use 1 VLC window to switch between 2 channels on same adapter (stop one stream then open next)-> no problems
- Open a 2nd VLC window to watch HD channel from other adapter (HD/bitrate seems to be significant for the frequency of failures)
- With the 2nd VLC now streaming HD, use 1st VLC window again to switch channels-> intermittent problems
- Problems seem more frequent if stop/start of streams is done quickly (in VLC, press stop icon then short pause for unsubscription then press ctrl-2 for previous stream)

Sorry if I'm bloating the thread but I think this is a real problem and I'm eager to help.

RE: Graceperiod expired with TBS6984 - Added by John Smith over 11 years ago

Bloating time again ;) I think I may have made an interesting observation. I changed the dvb_fe_tune_s2 function to include the frontend check after tuning. After doing this, I have not been able to reproduce the most frequent failure mode where there was no data at all coming from the adapter after switching channel.

I don't understand this and I wouldn't call it conclusive since this thing seems to be timing sensitive and somewhat difficult to reproduce but maybe it's a hint.

@Hugo - Any chance you can try the same thing and see if it does anything for you?

I simply changed:

  if(0)
    check_frontend (tda->tda_fe_fd, 0, 1);

To:

  if(1)
    check_frontend (tda->tda_fe_fd, 0, 1);

RE: Graceperiod expired with TBS6984 - Added by Hugo Rodenburg over 11 years ago

Hi John,

It's nice to hear I'm not the only person facing this problem. I'm quite an experienced Linux user/admin, but not much of a programmer, so it's hard for me to nail these issues. I'm however more than happy to test and debug possible fixes/patches.

I've just recompiled latest master from git and modified the function as you mention. I will test this on my system and will report back with my findings. Thanks for the effort so far!
Also I have 2 separate systems. One system with an TBS6981 and the other one with an TBS6984. The issue occurs on both systems, so not specific about the TBS6984 card/chipset.

RE: Graceperiod expired with TBS6984 - Added by Adam Sutton over 11 years ago

In theory that function should not be necessary since all it does it wait for the adapter to reach a particular state (no bad thing - we are planning to revamp much of this code anyway shortly). But it doesn't for example resend the tuning command in the event of a failure. So the only issue could be that installing the demux filters (which won't even happen in recent master builds with that card) before the tuning is complete causes a problem.

However I'd be very interested to hear feedback on whether this does indeed change performance. I've definitely seen a few weird events on my TBS6981 that I've never got to the bottom of and mostly live with (since they're fairly rare).

Also if that function can be proven to add a benefit I'm more than happy to tidy up the code and force that action for all tuning events.

Adam

RE: Graceperiod expired with TBS6984 - Added by John Smith over 11 years ago

I've continued looking at this and here's an update:

1. I created a "minimal" test program to stress test channel switching using different sequences and timings. The only confirmed failure mode with no data coming from the adapter was when diseqc setup failed. This was confirmed by redoing diseqc setup on timeout failure. It always solved the problem. Failure rate was in the order of 1 in 1000. A suggested TVH enhancement could be to always do diseqc setup on subscription even if an appropriate mux is supposed to be already tuned.

2. When writing my test program, I discovered, and could easily reproduce, what seems to be a strange timing dependency between open() calls for frontends. There's no clear relation to our specific problem but I have contacted TBS support for clarification.

3. After pulling the latest master from git today, I have a very frequent failure mode on one channel. Data is coming from the adapter, I get to status "[Hardware input] [Input on service] [Demuxed packets]". Dvbsnoop is run in parallel and is showing the correct pid being received. However, the service is never started and eventually I get "[Graceperiod expired]". Execution reaches parse_sc() but it seems like it's continuously failing some sort of startcode scan.

RE: Graceperiod expired with TBS6984 - Added by Hugo Rodenburg over 11 years ago

Hi all,

I've been running the modified version for about one week now, and I have to conclude that I had not a single problem tuning channels. This is a major improvement! Thanks!
To be exactly, I'm running at the moment:
- 3.3.465~g79c134f-dirty
- With the modification as suggested by John
- with the patch suggested by Adam in Issue #1586 (because of another issue).

RE: Graceperiod expired with TBS6984 - Added by Adam Sutton over 11 years ago

John,

1. This could be problematic, due to the layers in the code it might be difficult to discern the difference between when you actually need to re-tune the mux or not (e.g. don't want to tune on every sub if something else is already actively using that mux etc...)

The better solution I think at this stage is to use the Diseqc repeats to simply resend the command several times on each tuning. But I will take a look at your suggestion when I have time.

2. This reminds me (though its vague) of problems I had with my 6981, its the reason I made the close all FDs optional. I found that whenever I enabled that option one FE would almost always report no signal. And that I was able to reproduce this only if the opening of devices was done in a particular order and if it was within a single process (i.e. running 2 TVH instances one per adapter was always fine).

3. Interesting, but probably something we need to get Andreas to take a look at.

Adam

RE: Graceperiod expired with TBS6984 - Added by John Smith over 11 years ago

1. I agree. (I don't suppose it's possible to just redo diseqc setup without interrupting running services on mux?)

2. I've just received a first positive response from TBS support and I'll provide some more test results to them tomorrow. Good input that you may have experienced similar things on 6981.

3. Ok. Let me know if there's anything I can do.

RE: Graceperiod expired with TBS6984 - Added by Adam Sutton over 11 years ago

1. No, we shouldn't do anything if that mux is already tuned and actually running (as opposed to tuned and nothing coming in). This can be detected, the info is all there, I'm just not sure how easy it is to bring it all together due to the layering in the SW.

2. Let me know what you find, I've got a contact at TBS that I could also bug if necessary.

3. Try contacting Andreas (andoma) on #hts IRC channel.

Adam

RE: Graceperiod expired with TBS6984 - Added by John Smith over 11 years ago

1. I understand. The suggestion was just meant as a workaround in case it's too much work to implement the mux running detection.

2. Thanks. I've now supplied more info to TBS support and am waiting for the next response. I'll keep you updated.

3. This seems to have been an unlucky coincidence not related to TVH version. I'll look into it some more and I might try to contact Andreas once I have a better understanding.

RE: Graceperiod expired with TBS6984 - Added by John Smith over 11 years ago

Here's a short update on item 2 above. I checked the status with TBS support earlier this week and my issue was still in their todo pile. I'll update this thread with any updates I get.

In the meantime I've attached my test program in case anyone else wants to have a try. Channels are hard coded though and would need to be changed.

My output from running the program is:

Iteration: 0, sleep(0)
           0 | 1f |  74% |  90% |     0 |    0   |||              0 | 00 |  74% |   0% |     0 |    0
     5822736 | 1f |  74% |  90% |     0 |    0   |||              0 | 00 |  74% |   0% |     0 |    0
    12757680 | 1f |  74% |  90% |     0 |    0   |||              0 | 00 |  74% |   0% |     0 |    0
    19758048 | 1f |  74% |  90% |     0 |    0   |||              0 | 00 |  74% |   0% |     0 |    0
    26692992 | 1f |  74% |  90% |     0 |    0   |||              0 | 00 |  74% |   0% |     0 |    0
adapter0: OK      adapter1: FAIL    
Iteration: 1, sleep(1)
           0 | 1f |  74% |  90% |     0 |    0   |||              0 | 1f |  74% |  71% |     0 |    0
     1831872 | 1f |  74% |  90% |     0 |    0   |||        1177632 | 1f |  74% |  71% |     0 |    0
     8766816 | 1f |  74% |  90% |     0 |    0   |||        5888160 | 1f |  74% |  71% |     0 |    0
    15701760 | 1f |  74% |  90% |     0 |    0   |||       10664112 | 1f |  74% |  71% |     0 |    0
    22702128 | 1f |  74% |  90% |     0 |    0   |||       15440064 | 1f |  74% |  71% |     0 |    0
adapter0: OK      adapter1: OK      
Iteration: 2, sleep(0)
           0 | 1f |  74% |  90% |     0 |    0   |||              0 | 00 |  74% |   0% |     0 |    0
        4096 | 1f |  74% |  90% |     0 |    0   |||              0 | 00 |  74% |   0% |     0 |    0
     7523760 | 1f |  74% |  90% |     0 |    0   |||              0 | 00 |  74% |   0% |     0 |    0
    14458704 | 1f |  74% |  90% |     0 |    0   |||              0 | 00 |  74% |   0% |     0 |    0
    21459072 | 1f |  74% |  90% |     0 |    0   |||              0 | 00 |  74% |   0% |     0 |    0
adapter0: OK      adapter1: FAIL    
Iteration: 3, sleep(1)
           0 | 1f |  74% |  91% |     0 |    0   |||              0 | 1f |  74% |  71% |     0 |    0
     1570176 | 1f |  74% |  91% |     0 |    0   |||        1046784 | 1f |  74% |  71% |     0 |    0
     8505120 | 1f |  74% |  90% |     0 |    0   |||        5757312 | 1f |  74% |  71% |     0 |    0
    15505488 | 1f |  74% |  90% |     0 |    0   |||       10533264 | 1f |  74% |  71% |     0 |    0
    22440432 | 1f |  74% |  90% |     0 |    0   |||       15309216 | 1f |  74% |  71% |     0 |    0
adapter0: OK      adapter1: OK      
Iteration: 4, sleep(0)
           0 | 1f |  74% |  89% |     0 |    0   |||              0 | 00 |  74% |   0% |     0 |    0
      654240 | 1f |  74% |  90% |     0 |    0   |||              0 | 00 |  74% |   0% |     0 |    0
     7654608 | 1f |  74% |  90% |     0 |    0   |||              0 | 00 |  74% |   0% |     0 |    0
    14589552 | 1f |  74% |  91% |     0 |    0   |||              0 | 00 |  74% |   0% |     0 |    0
    21589920 | 1f |  74% |  91% |     0 |    0   |||              0 | 00 |  74% |   0% |     0 |    0
adapter0: OK      adapter1: FAIL    
Iteration: 5, sleep(1)
           0 | 1f |  74% |  90% |     0 |    0   |||              0 | 1f |  74% |  71% |     0 |    0
     1766448 | 1f |  74% |  90% |     0 |    0   |||        1177632 | 1f |  74% |  71% |     0 |    0
     8766816 | 1f |  74% |  91% |     0 |    0   |||        5953584 | 1f |  74% |  71% |     0 |    0
    15701760 | 1f |  74% |  90% |     0 |    0   |||       10664112 | 1f |  74% |  71% |     0 |    0
    22702128 | 1f |  74% |  90% |     0 |    0   |||       15440064 | 1f |  74% |  71% |     0 |    0
adapter0: OK      adapter1: OK      

Btw, I've also noticed another failure mode where I'm getting bad data off my TBS6984 but I doubt that it's related to the issue in this thread. See TBS forum thread for details.
http://www.tbsdtv.com/forum/viewtopic.php?f=37&t=8278&sid=6985e41aa2a0582eb3a741399b11df3e

test.c (8.05 KB) test.c Test program

RE: Graceperiod expired with TBS6984 - Added by gary tan over 11 years ago

Any update on this? I use openelec so cant make any changes to tvheadend. I'm just using a quad lnb no diseqc. Unfortunately this issue is really annoying as there is no guarantee a recording will start on time because sometimes it suddenly says an input is not available even though the mux frontend is ok and idle scanning is enabled. I have been using a different tv card for the last few months for openelec reasons but went to use my 6984 the other day as there is frequent openelec tbs images now. I dont remember this issue happening a few months ago with the 6984. Nearly has me contemplating switching to windows to get use out of all 4 tuners :(

RE: Graceperiod expired with TBS6984 - Added by John Smith over 11 years ago

John Smith wrote:

Here's a short update on item 2 above. I checked the status with TBS support earlier this week and my issue was still in their todo pile. I'll update this thread with any updates I get.

TBS support was able to reproduce this failure ("timing dependency between open() calls"). I was given a driver patch to test some time ago and the patch does fix the problem when using my test program.

I'm still having multiple issues with my system though and I've now given up trying to get this setup working stably. If inspiration returns I will replace some part of my system before I try again.

RE: Graceperiod expired with TBS6984 - Added by Jamie Dunbar over 11 years ago

I have the same problem with a Kworld card.

(1-25/29)