[mythtv-commits] Ticket #12106: EIT: slow tuning on a channel restarts activescan (mplex eit starvation)

[MythTV]

#12106: EIT: slow tuning on a channel restarts activescan (mplex eit starvation)
--------------------------------------+----------------------------------
     Reporter:  angela.schmid@…       |      Owner:  dekarl
         Type:  Bug Report - General  |     Status:  new
     Priority:  minor                 |  Milestone:  unknown
    Component:  MythTV - EIT          |    Version:  Unspecified
     Severity:  medium                |   Keywords:  eit mplex starvation
Ticket locked:  0                     |
--------------------------------------+----------------------------------
 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?

--
Ticket URL: <https://code.mythtv.org/trac/ticket/12106>
MythTV <http://www.mythtv.org>
MythTV Media Center