VDR-1.3.37: retuning -- possibly a fix for VDSB
Commit Message
Klaus Schmidinger wrote:
> Thomas Rausch wrote:
>
>> After 6 hours I must say that my VDR did not bring yet back the error.
>> So far otherwise always. I want to hope that it functions now. :)
>>
>> In the LOG comes however repeatedly:
>>
>> Jan 3 18:15:43 cat vdr[16675]: ERROR: frontend 0 lost lock
>> Jan 3 18:15:43 cat vdr[16675]: frontend 0 regained lock
>> Jan 3 18:16:03 cat vdr[16675]: ERROR: frontend 0 lost lock
>> Jan 3 18:16:03 cat vdr[16675]: frontend 0 regained lock
>> Jan 3 18:16:25 cat vdr[16675]: ERROR: frontend 0 lost lock
>> Jan 3 18:16:26 cat vdr[16675]: frontend 0 regained lock
>> Jan 3 18:16:45 cat vdr[16675]: ERROR: frontend 0 lost lock
>> Jan 3 18:16:45 cat vdr[16675]: frontend 0 regained lock
>> Jan 3 18:17:06 cat vdr[16675]: ERROR: frontend 0 lost lock
>> Jan 3 18:17:06 cat vdr[16675]: frontend 0 regained lock
>
>
> Apparently the FE_GET_EVENT ioctl() sometimes delivers a different
> status value than FE_READ_STATUS. I ran some tests, comparing both
> values and whenever VDR reported a lost lock, the current FE_READ_STATUS
> value still had the FE_HAS_LOCK set correctly.
>
> Following an old recommendation of Holger Wächtler I finally changed
> the frontend status handling so that it polls the frontend and reads
> any pending event (but simply discards it), and then reads the actual
> status via FE_READ_STATUS.
>
> With the attached patch (which is again a complete patch against
> dvbdevice.c of version 1.3.37) I don't get these spurious "lost lock"
> messages any more.
>
> I've also increased the timeout for polling the event queue to 10ms,
> because 1ms seemed a little hard to me. This had no effect on the
> "lost lock" problem, however, so the change in status handling really
> is what fixed it.
>
> Please try whether this also helps in your case.
Unfortunately this broke the CAM menu handling, so here's
a slightly different version.
Sorry about that...
Klaus
Comments
Klaus Schmidinger schrieb:
> Unfortunately this broke the CAM menu handling, so here's
> a slightly different version.
I bring this Patch in only today after 22 o'clock, since up to then
still some recordings are activated and I want to see whether it up to
then run.
I had yesterday unfortunately still #define WAIT_FOR_TUNER_LOCK there
then unfortunately after 8 hours (EPGScanTimeout = 1) nothing more was
recording.
Jan 3 23:15:05 cat vdr[16671]: timer 25 (23 2255-0020 'Serien~Six Feet Under~Six Feet Under - Gestorben wird immer') start
Jan 3 23:15:05 cat vdr[16671]: Title: 'Die Kuckelkorns - Ein Leben für den Tod' Subtitle: ''
Jan 3 23:15:05 cat vdr[16671]: record /video/Serien/Six_Feet_Under/Six_Feet_Under_-_Gestorben_wird_immer/_/2006-01-03.22.55.50.99.rec
Jan 3 23:15:05 cat vdr[16671]: creating directory /video/Serien/Six_Feet_Under/Six_Feet_Under_-_Gestorben_wird_immer
Jan 3 23:15:05 cat vdr[16671]: creating directory /video/Serien/Six_Feet_Under/Six_Feet_Under_-_Gestorben_wird_immer/_
Jan 3 23:15:05 cat vdr[16671]: creating directory /video/Serien/Six_Feet_Under/Six_Feet_Under_-_Gestorben_wird_immer/_/2006-01-03.22.55.50.99.rec
Jan 3 23:15:05 cat vdr[16671]: recording to '/video/Serien/Six_Feet_Under/Six_Feet_Under_-_Gestorben_wird_immer/_/2006-01-03.22.55.50.99.rec/001.vdr'
Jan 3 23:15:10 cat vdr[16671]: ERROR: device 1 has no lock, can't attach receiver (WAIT_FOR_TUNER_LOCK)!
Jan 3 23:15:10 cat vdr[16671]: buffer stats: 0 (0%) used
Jan 3 23:15:11 cat vdr[16671]: timer 25 (23 2255-0020 'Serien~Six Feet Under~Six Feet Under - Gestorben wird immer') stop
Jan 3 23:15:11 cat vdr[16671]: switching device 1 to channel 23
Jan 3 23:15:11 cat vdr[16671]: DEBUG-TOM: Frage: 0, Karte/Kanal: 1/23
Jan 3 23:15:11 cat vdr[16671]: timer 25 (23 2255-0020 'Serien~Six Feet Under~Six Feet Under - Gestorben wird immer') start
Jan 3 23:15:11 cat vdr[16671]: record /video/Serien/Six_Feet_Under/Six_Feet_Under_-_Gestorben_wird_immer/_/2006-01-03.22.55.50.99.rec
Jan 3 23:15:11 cat vdr[16671]: cFileName::SetOffset: removing zero-sized file /video/Serien/Six_Feet_Under/Six_Feet_Under_-_Gestorben_wird_immer/_/2006-01-03.22.55.50.99.rec/001.vdr
Jan 3 23:15:11 cat vdr[16671]: recording to '/video/Serien/Six_Feet_Under/Six_Feet_Under_-_Gestorben_wird_immer/_/2006-01-03.22.55.50.99.rec/001.vdr'
Jan 3 23:15:16 cat vdr[16671]: ERROR: device 1 has no lock, can't attach receiver (WAIT_FOR_TUNER_LOCK)!
Jan 3 23:15:16 cat vdr[16671]: buffer stats: 0 (0%) used
Jan 3 23:15:17 cat vdr[16671]: timer 25 (23 2255-0020 'Serien~Six Feet Under~Six Feet Under - Gestorben wird immer') stop
Jan 3 23:15:17 cat vdr[16671]: switching device 1 to channel 23
Jan 3 23:15:17 cat vdr[16671]: DEBUG-TOM: Frage: 0, Karte/Kanal: 1/23
Jan 3 23:15:17 cat vdr[16671]: timer 25 (23 2255-0020 'Serien~Six Feet Under~Six Feet Under - Gestorben wird immer') start
Jan 3 23:15:17 cat vdr[16671]: record /video/Serien/Six_Feet_Under/Six_Feet_Under_-_Gestorben_wird_immer/_/2006-01-03.22.55.50.99.rec
Jan 3 23:15:17 cat vdr[16671]: cFileName::SetOffset: removing zero-sized file /video/Serien/Six_Feet_Under/Six_Feet_Under_-_Gestorben_wird_immer/_/2006-01-03.22.55.50.99.rec/001.vdr
Jan 3 23:15:17 cat vdr[16671]: recording to '/video/Serien/Six_Feet_Under/Six_Feet_Under_-_Gestorben_wird_immer/_/2006-01-03.22.55.50.99.rec/001.vdr'
Jan 3 23:15:23 cat vdr[16671]: ERROR: device 1 has no lock, can't attach receiver (WAIT_FOR_TUNER_LOCK)!
Jan 3 23:15:23 cat vdr[16671]: buffer stats: 0 (0%) used
Jan 3 23:15:24 cat vdr[16671]: timer 25 (23 2255-0020 'Serien~Six Feet Under~Six Feet Under - Gestorben wird immer') stop
Jan 3 23:15:24 cat vdr[16671]: switching device 1 to channel 23
Jan 3 23:15:24 cat vdr[16671]: DEBUG-TOM: Frage: 0, Karte/Kanal: 1/23
Thomas Rausch wrote:
> Klaus Schmidinger schrieb:
>
>> Unfortunately this broke the CAM menu handling, so here's
>> a slightly different version.
>
>
> I bring this Patch in only today after 22 o'clock, since up to then
> still some recordings are activated and I want to see whether it up to
> then run.
Please be sure to test the very latest one (vdr.1.3.37-tunertimeout4.diff).
Klaus
Klaus Schmidinger schrieb:
> Please be sure to test the very latest one
> (vdr.1.3.37-tunertimeout4.diff).
Yes. ;)
The preceding Patch (from yesterday) had unfortunately again :(
Jan 4 20:45:00 cat vdr[18309]: switching device 1 to channel 16
Jan 4 20:45:00 cat vdr[18309]: DEBUG-TOM: Frage: 0, Karte/Kanal: 1/16
Jan 4 20:45:00 cat vdr[18309]: timer 6 (16 2045-2115
'Serien~Bernd~BRAVO BERND~der etwas andere Sandmann') start
Jan 4 20:45:00 cat vdr[18309]: Title: 'BRAVO BERND' Subtitle: 'der
etwas andere Sandmann'
Jan 4 20:45:00 cat vdr[18309]: record
/video/Serien/Bernd/BRAVO_BERND/der_etwas_andere_Sandmann/2006-01-04.20.45.99.99.rec
Jan 4 20:45:00 cat vdr[18309]: creating directory
/video/Serien/Bernd/BRAVO_BERND/der_etwas_andere_Sandmann/2006-01-04.20.45.99.99.rec
Jan 4 20:45:01 cat vdr[18309]: recording to
'/video/Serien/Bernd/BRAVO_BERND/der_etwas_andere_Sandmann/2006-01-04.20.45.99.99.rec/001.vdr'
Jan 4 20:45:01 cat vdr[18387]: file writer thread started (pid=18387,
tid=835598)
Jan 4 20:45:01 cat vdr[18388]: recording thread started (pid=18388,
tid=851983)
Jan 4 20:45:01 cat vdr[18389]: receiver on device 1 thread started
(pid=18389, tid=868368)
Jan 4 20:45:01 cat vdr[18390]: TS buffer on device 1 thread started
(pid=18390, tid=884753)
Jan 4 20:45:04 cat vdr[18316]: ERROR: frontend 1 lost lock
Jan 4 20:45:04 cat vdr[18316]: frontend 1 regained lock
Jan 4 20:45:25 cat vdr[18316]: ERROR: frontend 1 lost lock
Jan 4 20:45:25 cat vdr[18316]: frontend 1 regained lock
Jan 4 20:45:32 cat vdr[18387]: ERROR: video data stream broken
Jan 4 20:45:32 cat vdr[18387]: initiating emergency exit
Jan 4 20:45:32 cat vdr[18309]: emergency exit requested - shutting down
That was the 1. failed recording within 15 hours (5 other recordings ok).
Thomas
@@ -47,6 +40,13 @@
#define DEV_DVB_AUDIO "audio"
#define DEV_DVB_CA "ca"
+#define DVBS_TUNE_TIMEOUT 2000 //ms
+#define DVBS_LOCK_TIMEOUT 2000 //ms
+#define DVBC_TUNE_TIMEOUT 5000 //ms
+#define DVBC_LOCK_TIMEOUT 2000 //ms
+#define DVBT_TUNE_TIMEOUT 9000 //ms
+#define DVBT_LOCK_TIMEOUT 2000 //ms
+
class cDvbName {
private:
char buffer[PATH_MAX];
@@ -73,6 +73,9 @@
enum eTunerStatus { tsIdle, tsSet, tsTuned, tsLocked };
int fd_frontend;
int cardIndex;
+ int tuneTimeout;
+ int lockTimeout;
+ time_t lastTimeoutReport;
fe_type_t frontendType;
cCiHandler *ciHandler;
cChannel channel;
@@ -81,7 +84,7 @@
cMutex mutex;
cCondVar locked;
cCondVar newSet;
- bool GetFrontendEvent(dvb_frontend_event &Event, int TimeoutMs = 0);
+ bool GetFrontendStatus(fe_status_t &Status, int TimeoutMs = 0);
bool SetFrontend(void);
virtual void Action(void);
public:
@@ -98,6 +101,9 @@
cardIndex = CardIndex;
frontendType = FrontendType;
ciHandler = CiHandler;
+ tuneTimeout = 0;
+ lockTimeout = 0;
+ lastTimeoutReport = 0;
diseqcCommands = NULL;
tunerStatus = tsIdle;
if (frontendType == FE_QPSK)
@@ -125,6 +131,7 @@
if (Tune)
tunerStatus = tsSet;
channel = *Channel;
+ lastTimeoutReport = 0;
newSet.Broadcast();
}
@@ -140,26 +147,20 @@
return tunerStatus >= tsLocked;
}
-bool cDvbTuner::GetFrontendEvent(dvb_frontend_event &Event, int TimeoutMs)
+bool cDvbTuner::GetFrontendStatus(fe_status_t &Status, int TimeoutMs)
{
if (TimeoutMs) {
- struct pollfd pfd;
- pfd.fd = fd_frontend;
- pfd.events = POLLIN | POLLPRI;
- do {
- int stat = poll(&pfd, 1, TimeoutMs);
- if (stat == 1)
- break;
- if (stat < 0) {
- if (errno == EINTR)
- continue;
- esyslog("ERROR: frontend %d poll failed: %m", cardIndex);
- }
+ cPoller Poller(fd_frontend);
+ if (Poller.Poll(TimeoutMs)) {
+ // just to clear the event queue - we'll read the actual status below
+ dvb_frontend_event Event;
+ CHECK(ioctl(fd_frontend, FE_GET_EVENT, &Event));
+ }
+ else
return false;
- } while (0);
}
do {
- int stat = ioctl(fd_frontend, FE_GET_EVENT, &Event);
+ int stat = ioctl(fd_frontend, FE_READ_STATUS, &Status);
if (stat == 0)
return true;
if (stat < 0) {
@@ -245,6 +246,9 @@
Frontend.inversion = fe_spectral_inversion_t(channel.Inversion());
Frontend.u.qpsk.symbol_rate = channel.Srate() * 1000UL;
Frontend.u.qpsk.fec_inner = fe_code_rate_t(channel.CoderateH());
+
+ tuneTimeout = DVBS_TUNE_TIMEOUT;
+ lockTimeout = DVBS_LOCK_TIMEOUT;
}
break;
case FE_QAM: { // DVB-C
@@ -256,6 +260,9 @@
Frontend.u.qam.symbol_rate = channel.Srate() * 1000UL;
Frontend.u.qam.fec_inner = fe_code_rate_t(channel.CoderateH());
Frontend.u.qam.modulation = fe_modulation_t(channel.Modulation());
+
+ tuneTimeout = DVBC_TUNE_TIMEOUT;
+ lockTimeout = DVBC_LOCK_TIMEOUT;
}
break;
case FE_OFDM: { // DVB-T
@@ -271,6 +278,9 @@
Frontend.u.ofdm.transmission_mode = fe_transmit_mode_t(channel.Transmission());
Frontend.u.ofdm.guard_interval = fe_guard_interval_t(channel.Guard());
Frontend.u.ofdm.hierarchy_information = fe_hierarchy_t(channel.Hierarchy());
+
+ tuneTimeout = DVBT_TUNE_TIMEOUT;
+ lockTimeout = DVBT_LOCK_TIMEOUT;
}
break;
default:
@@ -286,29 +296,57 @@
void cDvbTuner::Action(void)
{
- dvb_frontend_event event;
+ cTimeMs Timer;
+ bool LostLock = false;
+ fe_status_t Status = (fe_status_t)0;
while (Running()) {
- bool hasEvent = GetFrontendEvent(event, 1);
-
+ bool StatusChanged = false;
+ fe_status_t NewStatus;
+ if (GetFrontendStatus(NewStatus, 10)) {
+ StatusChanged = NewStatus != Status;
+ Status = NewStatus;
+ }
cMutexLock MutexLock(&mutex);
switch (tunerStatus) {
case tsIdle:
break;
case tsSet:
- if (hasEvent)
- continue;
tunerStatus = SetFrontend() ? tsTuned : tsIdle;
+ Timer.Set(tuneTimeout);
continue;
case tsTuned:
+ if (Timer.TimedOut()) {
+ tunerStatus = tsSet;
+ diseqcCommands = NULL;
+ if (time(NULL) - lastTimeoutReport > 60) { // let's not get too many of these
+ esyslog("ERROR: frontend %d timed out while tuning", cardIndex);
+ lastTimeoutReport = time(NULL);
+ }
+ continue;
+ }
case tsLocked:
- if (hasEvent) {
- if (event.status & FE_REINIT) {
+ if (StatusChanged) {
+ if (Status & FE_REINIT) {
tunerStatus = tsSet;
- esyslog("ERROR: frontend %d was reinitialized - re-tuning", cardIndex);
+ diseqcCommands = NULL;
+ esyslog("ERROR: frontend %d was reinitialized", cardIndex);
+ lastTimeoutReport = 0;
}
- if (event.status & FE_HAS_LOCK) {
+ else if (Status & FE_HAS_LOCK) {
+ if (LostLock) {
+ esyslog("frontend %d regained lock", cardIndex);
+ LostLock = false;
+ }
tunerStatus = tsLocked;
locked.Broadcast();
+ lastTimeoutReport = 0;
+ }
+ else if (tunerStatus == tsLocked) {
+ LostLock = true;
+ esyslog("ERROR: frontend %d lost lock", cardIndex);
+ tunerStatus = tsTuned;
+ Timer.Set(lockTimeout);
+ lastTimeoutReport = 0;
}
continue;
}