EIT: slow tuning on a channel restarts activescan (mplex eit starvation)

[angela.schmid@…]

I have a single tuner configured to active scan 35+ mplex. One mplex produces problems, that it takes 5+ seconds to tune a channel in 98% of the cases. After (maybe just before) the EITTransportTimeout (3 minutes) on this mplex (channel 331) StartActiveScan? is restarted. As the starting channel is taken randomly and it stops frequently after scanning channel 331, the next mplex's (from activeScanChannels list) have a very small chance to be scanned (mplex eit starvation), causing them not to be scanned for a couple of days.

I added some debugging and reduced the channels to be actively scanned in eitscanner.cpp:

--- a/mythtv/libs/libmythtv/eitscanner.cpp
+++ b/mythtv/libs/libmythtv/eitscanner.cpp
@@ -119,7 +119,7 @@ void EITScanner::run(void)
         if (activeScan && (MythDate::current() > activeScanNextTrig))
         {
             // if there have been any new events, tell scheduler to run.
-            if (eitCount)
+            if (eitCount || true)
             {
                 LOG(VB_EIT, LOG_INFO,
                     LOC_ID + QString("Added %1 EIT Events").arg(eitCount));
@@ -130,7 +130,12 @@ void EITScanner::run(void)
             if (activeScanNextChan == activeScanChannels.end())
                 activeScanNextChan = activeScanChannels.begin();

-            if (!(*activeScanNextChan).isEmpty())
+                    LOG(VB_EIT, LOG_INFO,
+                        LOC_ID + QString("Before looking for EIT data on "
+                                         "multiplex of channel %1")
+                        .arg(*activeScanNextChan));
+
+                               if (!(*activeScanNextChan).isEmpty())
             {
                 eitHelper->WriteEITCache();
                 if (rec->QueueEITChannelChange(*activeScanNextChan))
@@ -222,6 +227,8 @@ void EITScanner::StopPassiveScan(void)
     eitHelper->WriteEITCache();
     eitHelper->SetChannelID(0);
     eitHelper->SetSourceID(0);
+
+    LOG(VB_EIT, LOG_INFO, LOC_ID + "Stopped passive scan.");
 }

 void EITScanner::StartActiveScan(TVRec *_rec, uint max_seconds_per_source)
@@ -242,6 +249,7 @@ void EITScanner::StartActiveScan(TVRec *_rec, uint max_seconds_per_source)
             "      useonairguide        = 1                AND "
             "      useeit               = 1                AND "
             "      channum             != ''               AND "
+            "      channum             in('331', '91', '146') AND "
             "      cardinput.cardid     = :CARDID "
             "GROUP BY mplexid "
             "ORDER BY cardinput.sourceid, mplexid, "
@@ -298,4 +306,6 @@ void EITScanner::StopActiveScan(void)
         activeScanCond.wait(&lock, 100);

     rec = NULL;
+
+       LOG(VB_EIT, LOG_INFO, LOC_ID + "Stopped active scan.");
 }

During the test no recordings were programmed. Two logs attached.

egrep "Now looking for EIT data on multiplex of channel|EIT Events|StartActiveScan called with|Started" \
    mythbackend.20140331000721.22379.log \
   >mythbackend.20140331000721.22379_1.log

egrep "Now looking for EIT data on multiplex of channel|EIT Events|StartActiveScan called with|Started|Stopped|Locked" \
    mythbackend.20140331000721.22379.log \
   >mythbackend.20140331000721.22379_2.log

The difference between "Now looking for EIT data on multiplex of channel" and "Started passive scan" shows the time to tune. Look at the end of the logs, where channel 331 took 4.5 seconds and scanning continued with the next mplex. All other scans on channel 331 caused StartActiveScan? to restart.

Why does StartActiveScan? stop run and restart? How can it be fixed?

[angela.schmid@…]

I disabled EIT scanning on this multiplex

mythtv/libs/libmythtv/eitscanner.cpp
@@ -242,6 +249,7 @@ void EITScanner::StartActiveScan(TVRec *_rec, uint max_seconds_per_source)
             "      useonairguide        = 1                AND "
             "      useeit               = 1                AND "
             "      channum             != ''               AND "
+            "      mplexid             != 13               AND "
             "      cardinput.cardid     = :CARDID "

During the last 6 days, I noticed 4 other channels with tuning times >5 seconds, but only about 5% of the times that it happened. Restarting active scanning 1-2 times a day. There were no recordings running on the configured tuner.

Is the tuning delay the cause, that active scanning restarts?

[Karl Egly]

Does you provider provide a Full SI transport? It should be signaled in the network_information_table, see #11809. I'm wondering if starting the active scan on the Full SI transport would be a viable workaround.

[angela.schmid@…]

Unfortunately my cable provider sends a crippled EPG for about two years, no cure in sight.

On one specific mplex it sends a 7 days EPG: Table_ID: 78 (0x4e) [= Event Information Table (EIT) - actual transport stream, present/following] Table_ID: 79 (0x4f) [= Event Information Table (EIT) - other transport stream, present/following] Table_ID: 80 (0x50) [= Event Information Table (EIT) - actual transport stream, schedule] Table_ID: 81 (0x51) [= Event Information Table (EIT) - actual transport stream, schedule] Table_ID: 96 (0x60) [= Event Information Table (EIT) - other transport stream, schedule] Table_ID: 97 (0x61) [= Event Information Table (EIT) - other transport stream, schedule]

However, subtitles (episodetitles) are only provided in Table_ID: 78 (0x4e) [= Event Information Table (EIT) - actual transport stream, present/following] Table_ID: 79 (0x4f) [= Event Information Table (EIT) - other transport stream, present/following]

On all other mplex a one day EPG with subtitles is send Table_ID: 78 (0x4e) [= Event Information Table (EIT) - actual transport stream, present/following] Table_ID: 79 (0x4f) [= Event Information Table (EIT) - other transport stream, present/following] Table_ID: 80 (0x50) [= Event Information Table (EIT) - actual transport stream, schedule] Table_ID: 96 (0x60) [= Event Information Table (EIT) - other transport stream, schedule]

Therefor I have to scan all mplex, to get a 7 days EPG and having subtitles for one day. Before I have been scanning this specific 7 days mplex only, by editing the query in eitscanner.cpp. Since I noticed that other mplex send one day subtitles, I started scanning all mplex. Thereafter I noticed the described behavior.

​https://code.mythtv.org/trac/ticket/11809, wouldn’t solve my problem. I left a message there.

I moved two weeks ago to Ubuntu 14.04, upgraded the DVB drivers and think everything is faster and more stable. I haven’t noticed tuning issues, even after I set the signal and channel timeouts from 3/6 to 1/1 second.

For me the issue doesn’t exist anymore. Still I am curious where in the source Myth decides to restart active EIT scanning and why. Still I see the following issues in the algorithm: After recording on a configured EIT card, active EIT scanning is restarted with a random channel, instead of restarting the killed channel. If EIT channel scanning is 5 minutes and you have 40+ mplex it could take a long time the killed channel is rescanned, maybe missing the latest changes. In my case, after a tuning issue, the next channel, due to random selection, has a very low chance to be selected (starvation).

[gigem]

Fixed in master with commit [36a1ff5a] and in fixes/29 with commit [57757c1d].

[David Engel <dengel@…>]

In 36a1ff5a6/mythtv:

Fix a couple more EIT issues.

Reset the next scan time after a tuning failure. This causes scanning
to resume after a reasonable time instead of 1 year as previously
done.

Start on a random channel the first time scanning is done. After
that, resume on the next channel. This ensures that channels
immediately after a channel the fails to tune get scanned in a timely
manner.

Fixes #12106
Fixes #13269

[David Engel <dengel@…>]

In 57757c1d99/mythtv:

Fix a couple more EIT issues.

Reset the next scan time after a tuning failure. This causes scanning
to resume after a reasonable time instead of 1 year as previously
done.

Start on a random channel the first time scanning is done. After
that, resume on the next channel. This ensures that channels
immediately after a channel the fails to tune get scanned in a timely
manner.

Refs #12106
Refs #13269

(cherry picked from commit 36a1ff5a6fdefe4da0e4c39c6605ddb87611baea)

[David Engel <dengel@…>]

In 57757c1d99/mythtv:

Fix a couple more EIT issues.

Reset the next scan time after a tuning failure. This causes scanning
to resume after a reasonable time instead of 1 year as previously
done.

Start on a random channel the first time scanning is done. After
that, resume on the next channel. This ensures that channels
immediately after a channel the fails to tune get scanned in a timely
manner.

Refs #12106
Refs #13269

(cherry picked from commit 36a1ff5a6fdefe4da0e4c39c6605ddb87611baea)

[David Engel <dengel@…>]

In 36a1ff5a6/mythtv:

Fix a couple more EIT issues.

Reset the next scan time after a tuning failure. This causes scanning
to resume after a reasonable time instead of 1 year as previously
done.

Start on a random channel the first time scanning is done. After
that, resume on the next channel. This ensures that channels
immediately after a channel the fails to tune get scanned in a timely
manner.

Fixes #12106
Fixes #13269

[David Engel <dengel@…>]

In 57757c1d99/mythtv:

Fix a couple more EIT issues.

Reset the next scan time after a tuning failure. This causes scanning
to resume after a reasonable time instead of 1 year as previously
done.

Start on a random channel the first time scanning is done. After
that, resume on the next channel. This ensures that channels
immediately after a channel the fails to tune get scanned in a timely
manner.

Refs #12106
Refs #13269

(cherry picked from commit 36a1ff5a6fdefe4da0e4c39c6605ddb87611baea)