mythbackend 107% CPU 5 minutes after starting

Have a MythTV related problem? Ask for help from other MythTV users here.

Moderator: Forum Moderators

Post Reply
sndguru
Newcomer
Posts: 4
Joined: Sat Mar 15, 2014 3:21 am
Australia

mythbackend 107% CPU 5 minutes after starting

Post by sndguru »

Help! please....

I've been using MythTV since Dec 2005, and am pretty proud of my stats

Code: Select all

Number of shows: 767
Number of episodes: 23977
First recording: Tuesday December 27th, 2005
Last recording: Saturday March 15th, 2014
Total Running Time: 8 years 2 months 16 days 18 hrs 57 mins
Total Recorded: 1 year 10 months 3 days 12 hrs 39 mins
Percent of time spent recording: 5%
MythTV was the reason I turned to linux and I say what, I've never turned back, I've learnt so much having a machine on 24/7 and as you can see above, I've had a ball. But onto my problem.

The past couple of weeks I've been failing to create recordings intermittently, and I believe this to be because the mythbackend process takes over 100% of one of my CPU cores. Now I've been trying to find out why this is but can seem to put my finger on it. I've monitored the log file during the increase of processor and it fails to log anything. So I change it to verbose logging and still can't see the entry that triggers the issue.

Any chance I could trouble you guys to have a glance at my issue please. Attached is my full verbose log file, yeah sorry for the size :( . If you do a search for "root 8391 4" (that's "root", 6 six spaces, "8391", two spaces, "4") through the file, you'll find about the moment the process goes nuts. I had a "ps aux" process logging to the file every second.

Code: Select all

#!/bin/bash
for (( ; ; ))
do
  ps aux | grep mythbackend.pid | grep -v grep >> /var/log/mythtv/mythbackendverbose.log
  sleep 1
done
Note: Keep in mind these is a quad core system and 25% is 100% of one core.

Thank you for your time.
sndguru
Attachments
mythbackendverbose3.7z
Third attempt after removing my video library storage (to reduce log size), also truncated to upload it to the forum
(242.63 KiB) Downloaded 96 times
sndguru
Newcomer
Posts: 4
Joined: Sat Mar 15, 2014 3:21 am
Australia

Re: mythbackend 107% CPU 5 minutes after starting

Post by sndguru »

For those of you who don't want to go to the effort of downloading my log file, hopefully I've grabbed the information below.

Startup....

Code: Select all

2014-03-15 10:48:02.813 mythbackend version: branches/release-0-23-fixes/mythtv/ [25469] http://www.mythtv.org
2014-03-15 10:48:02.857 (old)Settings::ReadSettings(settings.txt) - No such file
2014-03-15 10:48:02.873 Using runtime prefix = /usr
2014-03-15 10:48:02.881 Using configuration directory = /root/.mythtv
2014-03-15 10:48:02.890 (old)Settings::ReadSettings(/usr/share/mythtv/mysql.txt) - No such file
2014-03-15 10:48:02.898 (old)Settings::ReadSettings(/usr/etc/mythtv/mysql.txt) - No such file
2014-03-15 10:48:02.906 (old)Settings::ReadSettings(/root/.mythtv/mysql.txt) - No such file
2014-03-15 10:48:02.915 (old)Settings::ReadSettings(./mysql.txt) - No such file
2014-03-15 10:48:02.923 Unable to read configuration file mysql.txt
2014-03-15 10:48:02.931 Empty LocalHostName.
2014-03-15 10:48:02.939 Using localhost value of nebuchadnezzar.lanchbury.id.au
2014-03-15 10:48:02.948 Clearing Settings Cache.
2014-03-15 10:48:02.956 MCP::DefaultUPnP() - No default UPnP backend
2014-03-15 10:48:02.964 Clearing Settings Cache.
2014-03-15 10:48:02.980 New DB connection, total: 1
2014-03-15 10:48:02.993 Connected to database 'mythconverg' at host: localhost
2014-03-15 10:48:02.998 Closing DB connection named 'DBManager0'
2014-03-15 10:48:03.006 Clearing Settings Cache.
2014-03-15 10:48:03.014 Enabling Settings Cache.
2014-03-15 10:48:03.023 Clearing Settings Cache.
2014-03-15 10:48:03.032 Connected to database 'mythconverg' at host: localhost
2014-03-15 10:48:03.040 MSqlQuery::exec(DBManager0) SELECT data FROM settings WHERE value = 'backendserverip' AND hostname = 'nebuchadnezzar.lanchbury.id.au' <<<< Returns 1 row(s)
2014-03-15 10:48:03.048 MSqlQuery::next(DBManager0) Result: "data = 172.17.2.22"
2014-03-15 10:48:03.057 MSqlQuery::exec(DBManager0) SELECT data FROM settings WHERE value = 'masterserverip' AND hostname = 'nebuchadnezzar.lanchbury.id.au' <<<< Returns 0 row(s)
2014-03-15 10:48:03.065 MSqlQuery::exec(DBManager0) SELECT data FROM settings WHERE value = 'masterserverip' AND hostname IS NULL <<<< Returns 1 row(s)
2014-03-15 10:48:03.073 MSqlQuery::next(DBManager0) Result: "data = 172.17.2.22"
2014-03-15 10:48:03.081 Disabling Settings Cache.
2014-03-15 10:48:03.089 Clearing Settings Cache.
2014-03-15 10:48:03.099 MSqlQuery::exec(DBManager0) SELECT data FROM settings WHERE value = 'mythfillfixprogramidshasrunonce' AND hostname = 'nebuchadnezzar.lanchbury.id.au' <<<< Returns 1 row(s)
2014-03-15 10:48:03.106 MSqlQuery::next(DBManager0) Result: "data = 1"
2014-03-15 10:48:03.115 MSqlQuery::exec(DBManager0) SELECT data FROM settings WHERE value = 'dbschemaautoupgrade' AND hostname = 'nebuchadnezzar.lanchbury.id.au' <<<< Returns 0 row(s)
2014-03-15 10:48:03.123 MSqlQuery::exec(DBManager0) SELECT data FROM settings WHERE value = 'dbschemaautoupgrade' AND hostname IS NULL <<<< Returns 0 row(s)
2014-03-15 10:48:03.131 MSqlQuery::exec(DBManager0) SELECT data FROM settings WHERE value = 'dbschemaver' AND hostname = 'nebuchadnezzar.lanchbury.id.au' <<<< Returns 0 row(s)
2014-03-15 10:48:03.140 MSqlQuery::exec(DBManager0) SELECT data FROM settings WHERE value = 'dbschemaver' AND hostname IS NULL <<<< Returns 1 row(s)
2014-03-15 10:48:03.148 MSqlQuery::next(DBManager0) Result: "data = 1254"
2014-03-15 10:48:03.156 Current MythTV Schema Version (DBSchemaVer): 1254
2014-03-15 10:48:03.164 Enabling Settings Cache.
2014-03-15 10:48:03.173 Clearing Settings Cache.
2014-03-15 10:48:03.182 MSqlQuery::exec(DBManager0) SELECT data FROM settings WHERE value = 'backendserverport' AND hostname = 'nebuchadnezzar.lanchbury.id.au' <<<< Returns 1 row(s)
2014-03-15 10:48:03.189 MSqlQuery::next(DBManager0) Result: "data = 6543"
2014-03-15 10:48:03.198 MSqlQuery::exec(DBManager0) SELECT data FROM settings WHERE value = 'backendserverip' AND hostname = 'nebuchadnezzar.lanchbury.id.au' <<<< Returns 1 row(s)
2014-03-15 10:48:03.206 MSqlQuery::next(DBManager0) Result: "data = 172.17.2.22"
2014-03-15 10:48:03.215 MSqlQuery::exec(DBManager0) SELECT data FROM settings WHERE value = 'masterserverip' AND hostname = 'nebuchadnezzar.lanchbury.id.au' <<<< Returns 0 row(s)
2014-03-15 10:48:03.258 MSqlQuery::exec(DBManager0) SELECT data FROM settings WHERE value = 'masterserverip' AND hostname IS NULL <<<< Returns 1 row(s)
2014-03-15 10:48:03.275 MSqlQuery::next(DBManager0) Result: "data = 172.17.2.22"
2014-03-15 10:48:03.283 MythBackend: Starting up as the master server.
CPU 2.4 (about average) up to 6.3

Code: Select all

root      8391  2.4  0.3 2601756 32748 ?       Ssl  10:48   0:18 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:26.838 PESPacket: Failed CRC check 0x9b030026 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:26.841 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.837128
2014-03-15 11:00:26.886 PESPacket: Failed CRC check 0x9b030026 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:26.891 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.86954
root      8391  2.4  0.3 2601756 32748 ?       Ssl  10:48   0:18 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:27.839 PESPacket: Failed CRC check 0x9b030027 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:27.841 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.839304
2014-03-15 11:00:27.853 PESPacket: Failed CRC check 0x9b030027 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:27.858 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.871196
2014-03-15 11:00:28.067 MSqlQuery::exec(DBManager0) SELECT chanid, starttime, lastupdatetime, recusage, hostname FROM inuseprograms <<<< Returns 0 row(s)
2014-03-15 11:00:28.074 AutoExpire: ExpireLiveTV(10000)
2014-03-15 11:00:28.083 AutoExpire: FillDBOrdered: Adding Short LiveTV programs in starttime order
2014-03-15 11:00:28.092 MSqlQuery::exec(DBManager2) SELECT recorded.chanid, starttime,   endtime,            title,           subtitle,    description,        hostname,        channum,     name,               callsign,        seriesid,    programid,          recorded.recpriority,         progstart,          progend,         filesize,    recgroup,           storagegroup,    basename FROM recorded LEFT JOIN channel ON recorded.chanid = channel.chanid WHERE recgroup = 'LiveTV' AND endtime < DATE_ADD(starttime, INTERVAL '2' MINUTE) AND endtime <= DATE_ADD(NOW(), INTERVAL '-1' MINUTE)  AND deletepending = 0 ORDER BY autoexpire DESC, starttime ASC <<<< Returns 0 row(s)
2014-03-15 11:00:28.099 AutoExpire: SendDeleteMessages. Nothing to expire.
root      8391  2.4  0.3 2601756 32748 ?       Ssl  10:48   0:18 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:28.840 PESPacket: Failed CRC check 0x9b030028 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:28.849 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.842
2014-03-15 11:00:28.869 PESPacket: Failed CRC check 0x9b030028 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:28.874 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.872852
root      8391  2.4  0.3 2601756 32748 ?       Ssl  10:48   0:18 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:29.841 PESPacket: Failed CRC check 0x9b030029 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:29.848 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.843136
2014-03-15 11:00:29.886 PESPacket: Failed CRC check 0x9b030029 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:29.890 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.874507
root      8391  2.4  0.3 2601756 32748 ?       Ssl  10:48   0:18 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:30.838 PESPacket: Failed CRC check 0x9b030030 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:30.848 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.843749
2014-03-15 11:00:30.851 PESPacket: Failed CRC check 0x9b030030 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:30.865 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.873559
root      8391  2.4  0.3 2601756 32748 ?       Ssl  10:48   0:18 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:31.839 PESPacket: Failed CRC check 0x9b030031 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:31.876 PESPacket: Failed CRC check 0x9b030031 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:31.889 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.847455
2014-03-15 11:00:31.906 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.875737
root      8391  2.4  0.3 2601756 32748 ?       Ssl  10:48   0:18 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:32.840 PESPacket: Failed CRC check 0x9b030032 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:32.847 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.84807
2014-03-15 11:00:32.875 PESPacket: Failed CRC check 0x9b030032 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:32.881 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.877914
root      8391  2.4  0.3 2601756 32748 ?       Ssl  10:48   0:18 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:33.846 PESPacket: Failed CRC check 0x9b030033 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:33.855 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.849206
2014-03-15 11:00:33.892 PESPacket: Failed CRC check 0x9b030033 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:33.897 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.879571
root      8391  2.4  0.3 2601756 32748 ?       Ssl  10:48   0:18 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:34.847 PESPacket: Failed CRC check 0x9b030034 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:34.855 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.850343
2014-03-15 11:00:34.858 PESPacket: Failed CRC check 0x9b030034 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:34.871 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.878626
root      8391  2.4  0.3 2601756 32748 ?       Ssl  10:48   0:18 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:35.848 PESPacket: Failed CRC check 0x9b030035 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:35.854 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.851478
2014-03-15 11:00:35.883 PESPacket: Failed CRC check 0x9b030035 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:35.887 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.880801
root      8391  2.4  0.3 2601756 32748 ?       Ssl  10:48   0:18 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:36.848 PESPacket: Failed CRC check 0x9b030036 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:36.849 PESPacket: Failed CRC check 0x9b030036 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:36.870 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.853134
2014-03-15 11:00:36.879 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.881414
root      8391  2.4  0.3 2601756 32748 ?       Ssl  10:48   0:18 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:37.849 PESPacket: Failed CRC check 0x9b030037 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:37.849 PESPacket: Failed CRC check 0x9b030037 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:37.862 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.879422
2014-03-15 11:00:37.870 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.852859
root      8391  2.4  0.3 2601756 32748 ?       Ssl  10:48   0:18 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:38.852 PESPacket: Failed CRC check 0x9b030038 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:38.861 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.854509
2014-03-15 11:00:38.882 PESPacket: Failed CRC check 0x9b030038 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:38.920 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.883158
root      8391  2.4  0.3 2601756 32748 ?       Ssl  10:48   0:18 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:39.850 PESPacket: Failed CRC check 0x9b030039 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:39.852 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.855121
2014-03-15 11:00:39.881 PESPacket: Failed CRC check 0x9b030039 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:39.886 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.883773
2014-03-15 11:00:40.857 PESPacket: Failed CRC check 0x9b030040 != 0xec357263 for StreamID = 0x70
root      8391  2.4  0.3 2601756 32748 ?       Ssl  10:48   0:18 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:40.860 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.856258
2014-03-15 11:00:40.897 PESPacket: Failed CRC check 0x9b030040 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:40.902 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.884387
2014-03-15 11:00:41.857 PESPacket: Failed CRC check 0x9b030041 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:41.860 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.856868
2014-03-15 11:00:41.864 PESPacket: Failed CRC check 0x9b030041 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:41.877 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.884477
root      8391  2.4  0.3 2601756 32748 ?       Ssl  10:48   0:18 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:42.858 PESPacket: Failed CRC check 0x9b030042 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:42.868 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.858512
2014-03-15 11:00:42.888 PESPacket: Failed CRC check 0x9b030042 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:42.893 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.884577
root      8391  2.4  0.3 2601756 32748 ?       Ssl  10:48   0:18 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:43.859 PESPacket: Failed CRC check 0x9b030043 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:43.867 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.860157
2014-03-15 11:00:43.904 PESPacket: Failed CRC check 0x9b030043 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:43.936 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.889453
root      8391  2.5  0.3 2601756 32748 ?       Ssl  10:48   0:19 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:44.857 PESPacket: Failed CRC check 0x9b030044 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:44.859 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.86076
2014-03-15 11:00:44.862 PESPacket: Failed CRC check 0x9b030044 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:44.875 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.889536
root      8391  2.6  0.3 2601756 32748 ?       Ssl  10:48   0:20 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:45.860 PESPacket: Failed CRC check 0x9b030045 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:45.866 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.861884
2014-03-15 11:00:45.888 PESPacket: Failed CRC check 0x9b030045 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:45.891 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.889619
root      8391  2.8  0.3 2601756 32748 ?       Ssl  10:48   0:21 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:46.861 PESPacket: Failed CRC check 0x9b030046 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:46.866 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.863007
2014-03-15 11:00:46.903 PESPacket: Failed CRC check 0x9b030046 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:46.924 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.893347
root      8391  2.9  0.3 2601756 32748 ?       Ssl  10:48   0:22 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:47.864 PESPacket: Failed CRC check 0x9b030047 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:47.874 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.862081
2014-03-15 11:00:47.885 PESPacket: Failed CRC check 0x9b030047 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:47.891 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.892386
root      8391  3.0  0.3 2601756 32748 ?       Ssl  10:48   0:23 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:48.865 PESPacket: Failed CRC check 0x9b030048 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:48.882 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.864245
2014-03-15 11:00:48.902 PESPacket: Failed CRC check 0x9b030048 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:48.907 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.894028
root      8391  3.2  0.3 2601756 32748 ?       Ssl  10:48   0:24 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:49.871 PESPacket: Failed CRC check 0x9b030049 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:49.881 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.865887
2014-03-15 11:00:49.919 PESPacket: Failed CRC check 0x9b030049 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:49.923 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.895671
root      8391  3.3  0.3 2601756 32748 ?       Ssl  10:48   0:25 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:50.869 PESPacket: Failed CRC check 0x9b030050 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:50.873 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.867009
2014-03-15 11:00:50.884 PESPacket: Failed CRC check 0x9b030050 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:50.889 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.896792
root      8391  3.4  0.3 2601756 32748 ?       Ssl  10:48   0:26 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:51.870 PESPacket: Failed CRC check 0x9b030051 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:51.872 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.868131
2014-03-15 11:00:51.901 PESPacket: Failed CRC check 0x9b030051 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:51.905 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.897913
root      8391  3.6  0.3 2601756 32748 ?       Ssl  10:48   0:27 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:52.873 PESPacket: Failed CRC check 0x9b030052 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:52.888 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.869252
2014-03-15 11:00:52.917 PESPacket: Failed CRC check 0x9b030052 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:52.922 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.900597
root      8391  3.7  0.3 2601756 32748 ?       Ssl  10:48   0:28 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:53.874 PESPacket: Failed CRC check 0x9b030053 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:53.880 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.869856
2014-03-15 11:00:53.883 PESPacket: Failed CRC check 0x9b030053 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:53.896 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.902761
root      8391  3.8  0.3 2601756 32748 ?       Ssl  10:48   0:29 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:54.878 PESPacket: Failed CRC check 0x9b030054 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:54.885 PESPacket: Failed CRC check 0x9b030054 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:54.896 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.872025
2014-03-15 11:00:54.904 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.901801
root      8391  4.0  0.3 2601756 32748 ?       Ssl  10:48   0:31 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:55.876 PESPacket: Failed CRC check 0x9b030055 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:55.879 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.87367
2014-03-15 11:00:55.924 PESPacket: Failed CRC check 0x9b030055 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:55.929 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.904485
root      8391  4.1  0.3 2601756 32748 ?       Ssl  10:48   0:32 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:56.876 PESPacket: Failed CRC check 0x9b030056 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:56.890 PESPacket: Failed CRC check 0x9b030056 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:56.903 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.904567
2014-03-15 11:00:56.895 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.875833
root      8391  4.2  0.3 2601756 32748 ?       Ssl  10:48   0:33 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:57.877 PESPacket: Failed CRC check 0x9b030057 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:57.886 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.877477
2014-03-15 11:00:57.915 PESPacket: Failed CRC check 0x9b030057 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:57.920 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.907253
root      8391  4.4  0.3 2601756 32748 ?       Ssl  10:48   0:34 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:58.903 PESPacket: Failed CRC check 0x9b030058 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:58.911 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.880162
2014-03-15 11:00:58.931 PESPacket: Failed CRC check 0x9b030058 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:58.936 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.909919
root      8391  4.5  0.3 2601756 32748 ?       Ssl  10:48   0:35 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:00:59.890 PESPacket: Failed CRC check 0x9b030059 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:59.894 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.881805
2014-03-15 11:00:59.930 PESPacket: Failed CRC check 0x9b030059 != 0xec357263 for StreamID = 0x70
2014-03-15 11:00:59.935 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.909894
root      8391  4.6  0.3 2601756 32748 ?       Ssl  10:48   0:36 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:01:00.887 PESPacket: Failed CRC check 0x9b030100 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:00.893 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.88397
2014-03-15 11:01:00.896 PESPacket: Failed CRC check 0x9b030100 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:00.910 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.912058
root      8391  4.7  0.3 2601756 32748 ?       Ssl  10:48   0:37 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:01:01.891 PESPacket: Failed CRC check 0x9b030101 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:01.901 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.886134
2014-03-15 11:01:01.923 PESPacket: Failed CRC check 0x9b030101 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:01.993 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.918391
root      8391  4.9  0.3 2601756 32748 ?       Ssl  10:48   0:38 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:01:02.782 MSqlQuery::exec(DBManager4) SELECT chanid, m.default_authority FROM channel c LEFT JOIN dtv_multiplex m ON (c.mplexid = m.mplexid) <<<< Returns 31 row(s)
2014-03-15 11:01:02.784 MSqlQuery::next(DBManager4) Result: "chanid = 1007, default_authority = "
2014-03-15 11:01:02.792 MSqlQuery::next(DBManager4) Result: "chanid = 1071, default_authority = "
2014-03-15 11:01:02.801 MSqlQuery::next(DBManager4) Result: "chanid = 1072, default_authority = "
2014-03-15 11:01:02.809 MSqlQuery::next(DBManager4) Result: "chanid = 1073, default_authority = "
2014-03-15 11:01:02.817 MSqlQuery::next(DBManager4) Result: "chanid = 1070, default_authority = "
2014-03-15 11:01:02.826 MSqlQuery::next(DBManager4) Result: "chanid = 1074, default_authority = "
2014-03-15 11:01:02.834 MSqlQuery::next(DBManager4) Result: "chanid = 1078, default_authority = "
2014-03-15 11:01:02.842 MSqlQuery::next(DBManager4) Result: "chanid = 1003, default_authority = "
2014-03-15 11:01:02.851 MSqlQuery::next(DBManager4) Result: "chanid = 1032, default_authority = "
2014-03-15 11:01:02.859 MSqlQuery::next(DBManager4) Result: "chanid = 1033, default_authority = "
2014-03-15 11:01:02.867 MSqlQuery::next(DBManager4) Result: "chanid = 1034, default_authority = "
2014-03-15 11:01:02.876 MSqlQuery::next(DBManager4) Result: "chanid = 1030, default_authority = "
2014-03-15 11:01:02.884 MSqlQuery::next(DBManager4) Result: "chanid = 1009, default_authority = "
2014-03-15 11:01:02.892 MSqlQuery::next(DBManager4) Result: "chanid = 1099, default_authority = "
2014-03-15 11:01:02.892 PESPacket: Failed CRC check 0x9b030102 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:02.901 MSqlQuery::next(DBManager4) Result: "chanid = 1094, default_authority = "
2014-03-15 11:01:02.908 PESPacket: Failed CRC check 0x9b030102 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:02.926 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.918473
2014-03-15 11:01:02.917 MSqlQuery::next(DBManager4) Result: "chanid = 1090, default_authority = "
2014-03-15 11:01:02.942 MSqlQuery::next(DBManager4) Result: "chanid = 1092, default_authority = "
2014-03-15 11:01:02.909 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.88882
2014-03-15 11:01:02.951 MSqlQuery::next(DBManager4) Result: "chanid = 1095, default_authority = "
2014-03-15 11:01:02.967 MSqlQuery::next(DBManager4) Result: "chanid = 1001, default_authority = "
2014-03-15 11:01:02.976 MSqlQuery::next(DBManager4) Result: "chanid = 1010, default_authority = "
2014-03-15 11:01:02.984 MSqlQuery::next(DBManager4) Result: "chanid = 1014, default_authority = "
2014-03-15 11:01:02.992 MSqlQuery::next(DBManager4) Result: "chanid = 1012, default_authority = "
2014-03-15 11:01:03.001 MSqlQuery::next(DBManager4) Result: "chanid = 1011, default_authority = "
2014-03-15 11:01:03.009 MSqlQuery::next(DBManager4) Result: "chanid = 1015, default_authority = "
2014-03-15 11:01:03.017 MSqlQuery::next(DBManager4) Result: "chanid = 1024, default_authority = "
2014-03-15 11:01:03.026 MSqlQuery::next(DBManager4) Result: "chanid = 1002, default_authority = "
2014-03-15 11:01:03.034 MSqlQuery::next(DBManager4) Result: "chanid = 1022, default_authority = "
2014-03-15 11:01:03.042 MSqlQuery::next(DBManager4) Result: "chanid = 1021, default_authority = "
2014-03-15 11:01:03.051 MSqlQuery::next(DBManager4) Result: "chanid = 1023, default_authority = "
2014-03-15 11:01:03.059 MSqlQuery::next(DBManager4) Result: "chanid = 1044, default_authority = "
2014-03-15 11:01:03.067 MSqlQuery::next(DBManager4) Result: "chanid = 1100, default_authority = "
2014-03-15 11:01:03.076 MSqlQuery::exec(DBManager4) SELECT chanid, default_authority FROM channel <<<< Returns 31 row(s)
2014-03-15 11:01:03.114 MSqlQuery::next(DBManager4) Result: "chanid = 1007, default_authority = "
2014-03-15 11:01:03.126 MSqlQuery::next(DBManager4) Result: "chanid = 1071, default_authority = "
2014-03-15 11:01:03.134 MSqlQuery::next(DBManager4) Result: "chanid = 1072, default_authority = "
2014-03-15 11:01:03.142 MSqlQuery::next(DBManager4) Result: "chanid = 1073, default_authority = "
2014-03-15 11:01:03.151 MSqlQuery::next(DBManager4) Result: "chanid = 1070, default_authority = "
2014-03-15 11:01:03.159 MSqlQuery::next(DBManager4) Result: "chanid = 1074, default_authority = "
2014-03-15 11:01:03.167 MSqlQuery::next(DBManager4) Result: "chanid = 1078, default_authority = "
2014-03-15 11:01:03.176 MSqlQuery::next(DBManager4) Result: "chanid = 1003, default_authority = "
2014-03-15 11:01:03.184 MSqlQuery::next(DBManager4) Result: "chanid = 1032, default_authority = "
2014-03-15 11:01:03.192 MSqlQuery::next(DBManager4) Result: "chanid = 1033, default_authority = "
2014-03-15 11:01:03.201 MSqlQuery::next(DBManager4) Result: "chanid = 1034, default_authority = "
2014-03-15 11:01:03.209 MSqlQuery::next(DBManager4) Result: "chanid = 1030, default_authority = "
2014-03-15 11:01:03.217 MSqlQuery::next(DBManager4) Result: "chanid = 1009, default_authority = CRID://perth.nine.nine.au"
2014-03-15 11:01:03.226 MSqlQuery::next(DBManager4) Result: "chanid = 1099, default_authority = CRID://perth.go.nine.au"
2014-03-15 11:01:03.234 MSqlQuery::next(DBManager4) Result: "chanid = 1094, default_authority = crid://nine.com.au"
2014-03-15 11:01:03.242 MSqlQuery::next(DBManager4) Result: "chanid = 1090, default_authority = CRID://perth.ninehd.nine.au"
2014-03-15 11:01:03.251 MSqlQuery::next(DBManager4) Result: "chanid = 1092, default_authority = crid://nine.com.au"
2014-03-15 11:01:03.259 MSqlQuery::next(DBManager4) Result: "chanid = 1095, default_authority = "
2014-03-15 11:01:03.267 MSqlQuery::next(DBManager4) Result: "chanid = 1001, default_authority = crid://perth.onehd.ten.au"
2014-03-15 11:01:03.276 MSqlQuery::next(DBManager4) Result: "chanid = 1010, default_authority = crid://perth.ten.ten.au"
2014-03-15 11:01:03.284 MSqlQuery::next(DBManager4) Result: "chanid = 1014, default_authority = crid://perth.tvsn.ten.au"
2014-03-15 11:01:03.292 MSqlQuery::next(DBManager4) Result: "chanid = 1012, default_authority = crid://perth.onehd12.ten.au"
2014-03-15 11:01:03.301 MSqlQuery::next(DBManager4) Result: "chanid = 1011, default_authority = crid://perth.11.ten.au"
2014-03-15 11:01:03.309 MSqlQuery::next(DBManager4) Result: "chanid = 1015, default_authority = crid://perth.spree.ten.au"
2014-03-15 11:01:03.317 MSqlQuery::next(DBManager4) Result: "chanid = 1024, default_authority = CRID://perthabcnews24.abc.net.au"
2014-03-15 11:01:03.326 MSqlQuery::next(DBManager4) Result: "chanid = 1002, default_authority = CRID://perth2.abc.net.au"
2014-03-15 11:01:03.334 MSqlQuery::next(DBManager4) Result: "chanid = 1022, default_authority = CRID://perth22.abc.net.au"
2014-03-15 11:01:03.342 MSqlQuery::next(DBManager4) Result: "chanid = 1021, default_authority = CRID://perth21.abc.net.au"
2014-03-15 11:01:03.351 MSqlQuery::next(DBManager4) Result: "chanid = 1023, default_authority = CRID://perth23.abc.net.au"
2014-03-15 11:01:03.359 MSqlQuery::next(DBManager4) Result: "chanid = 1044, default_authority = crid://perth.wtv.community.au"
2014-03-15 11:01:03.367 MSqlQuery::next(DBManager4) Result: "chanid = 1100, default_authority = "
2014-03-15 11:01:03.380 MSqlQuery::exec(DBManager1) SELECT title,          subtitle,      description,        category,       category_type,        starttime,      endtime,        subtitletypes+0,audioprop+0,   videoprop+0,        seriesid,       programid,        partnumber,     parttotal,        syndicatedepisodenumber,        airdate,        originalairdate,        previouslyshown,listingsource FROM program WHERE chanid   = '1092' AND       manualid = 0       AND       ( ( starttime >= '2014-03-15T11:00:59' AND starttime <  '2014-03-15T11:41:19' ) OR         ( endtime   >  '2014-03-15T11:00:59' AND endtime   <= '2014-03-15T11:41:19' ) ) <<<< Returns 1 row(s)
2014-03-15 11:01:03.406 MSqlQuery::next(DBManager1) Result: "title = NutriBullet, subtitle = , description = Breaks down fruit and vegetable cell walls to turn ordinary foods into Super Foods for a healthier you., category = Leisure/Hobbies, category_type = tvshow, starttime = 2014-03-15T11:00:59, endtime = 2014-03-15T11:41:19, subtitletypes+0 = 0, audioprop+0 = 1, videoprop+0 = 0, seriesid = crid://nine.com.au/x-nut, programid = crid://nine.com.au/x-nut00ba2830nb3n2, partnumber = 0, parttotal = 0, syndicatedepisodenumber = , airdate = 0, originalairdate = , previouslyshown = 0, listingsource = 1"
2014-03-15 11:01:03.417 GM : NutriBullet new best match NutriBullet with score 11000
2014-03-15 11:01:03.426 EIT: accept match[0]: 11000 'NutriBullet' vs. 'NutriBullet'
2014-03-15 11:01:03.435 MSqlQuery::exec(DBManager1) UPDATE program SET title          = 'NutriBullet',     subtitle      = '',     description    = 'Breaks down fruit and vegetable cell walls to turn ordinary foods into Super Foods for a healthier you.',     category       = 'Leisure/Hobbies',  category_type = 'tvshow',     starttime      = '2014-03-15T11:00:59', endtime       = '2014-03-15T11:41:19',     closecaptioned = 'false',        subtitled     = 'false',     stereo         = 'true',    hdtv          = 'false',     subtitletypes  = '0',     audioprop      = '1', videoprop     = '0',     partnumber     = '0',    parttotal     = '0',     syndicatedepisodenumber = '',     airdate        = '0000',   originalairdate='',     listingsource  = '1',     seriesid       = 'crid://nine.com.au/x-nut',  programid     = 'crid://nine.com.au/x-nut00ba2830nb3n2',     previouslyshown = 'false' WHERE chanid    = '1092' AND       starttime = '2014-03-15T11:00:59' 
2014-03-15 11:01:03.446 MSqlQuery::exec(DBManager1) SELECT title,          subtitle,      description,        category,       category_type,        starttime,      endtime,        subtitletypes+0,audioprop+0,   videoprop+0,        seriesid,       programid,        partnumber,     parttotal,        syndicatedepisodenumber,        airdate,        originalairdate,        previouslyshown,listingsource FROM program WHERE chanid   = '1095' AND       manualid = 0       AND       ( ( starttime >= '2014-03-15T11:00:59' AND starttime <  '2014-03-15T11:41:19' ) OR         ( endtime   >  '2014-03-15T11:00:59' AND endtime   <= '2014-03-15T11:41:19' ) ) <<<< Returns 1 row(s)
2014-03-15 11:01:03.451 MSqlQuery::next(DBManager1) Result: "title = NutriBullet, subtitle = , description = Breaks down fruit and vegetable cell walls to turn ordinary foods into Super Foods for a healthier you., category = Leisure/Hobbies, category_type = tvshow, starttime = 2014-03-15T11:00:59, endtime = 2014-03-15T11:41:19, subtitletypes+0 = 0, audioprop+0 = 1, videoprop+0 = 0, seriesid = , programid = , partnumber = 0, parttotal = 0, syndicatedepisodenumber = , airdate = 0, originalairdate = , previouslyshown = 0, listingsource = 1"
2014-03-15 11:01:03.459 GM : NutriBullet new best match NutriBullet with score 11000
root      8391  5.0  0.4 2601756 32808 ?       Ssl  10:48   0:39 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:01:03.467 EIT: accept match[0]: 11000 'NutriBullet' vs. 'NutriBullet'
2014-03-15 11:01:03.476 MSqlQuery::exec(DBManager1) UPDATE program SET title          = 'NutriBullet',     subtitle      = '',     description    = 'Breaks down fruit and vegetable cell walls to turn ordinary foods into Super Foods for a healthier you.',     category       = 'Leisure/Hobbies',  category_type = 'tvshow',     starttime      = '2014-03-15T11:00:59', endtime       = '2014-03-15T11:41:19',     closecaptioned = 'false',        subtitled     = 'false',     stereo         = 'true',    hdtv          = 'false',     subtitletypes  = '0',     audioprop      = '1', videoprop     = '0',     partnumber     = '0',    parttotal     = '0',     syndicatedepisodenumber = '',     airdate        = '0000',   originalairdate='',     listingsource  = '1',     seriesid       = '',  programid     = '',     previouslyshown = 'false' WHERE chanid    = '1095' AND       starttime = '2014-03-15T11:00:59' 
2014-03-15 11:01:03.506 EITHelper: Added 2 events
2014-03-15 11:01:03.895 PESPacket: Failed CRC check 0x9b030103 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:03.900 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.890475
2014-03-15 11:01:03.922 MSqlQuery::exec(DBManager3) SELECT title,          subtitle,      description,        category,       category_type,        starttime,      endtime,        subtitletypes+0,audioprop+0,   videoprop+0,        seriesid,       programid,        partnumber,     parttotal,        syndicatedepisodenumber,        airdate,        originalairdate,        previouslyshown,listingsource FROM program WHERE chanid   = '1092' AND       manualid = 0       AND       ( ( starttime >= '2014-03-15T11:41:19' AND starttime <  '2014-03-15T12:20:56' ) OR         ( endtime   >  '2014-03-15T11:41:19' AND endtime   <= '2014-03-15T12:20:56' ) ) <<<< Returns 2 row(s)
2014-03-15 11:01:03.926 MSqlQuery::next(DBManager3) Result: "title = Total Gym XLS, subtitle = , description = Gain the body you’ve always wanted with the home gym that has totally delivered for 40 years., category = Leisure/Hobbies, category_type = tvshow, starttime = 2014-03-15T11:41:19, endtime = 2014-03-15T12:20:00, subtitletypes+0 = 0, audioprop+0 = 1, videoprop+0 = 0, seriesid = crid://nine.com.au/x-togy, programid = crid://nine.com.au/x-togy00ba2830tgx5n2, partnumber = 0, parttotal = 0, syndicatedepisodenumber = , airdate = 0, originalairdate = , previouslyshown = 0, listingsource = 1"
2014-03-15 11:01:03.934 MSqlQuery::next(DBManager3) Result: "title = Pearl Hair Remover, subtitle = , description = The true long-term solution for hair-free skin ? say goodbye to waxing, razors, chemicals, and pain!, category = Leisure/Hobbies, category_type = tvshow, starttime = 2014-03-15T12:20:00, endtime = 2014-03-15T13:00:00, subtitletypes+0 = 0, audioprop+0 = 1, videoprop+0 = 0, seriesid = crid://nine.com.au/x-prl, programid = crid://nine.com.au/x-prl00ba2830phr3n2, partnumber = 0, parttotal = 0, syndicatedepisodenumber = , airdate = 0, originalairdate = , previouslyshown = 0, listingsource = 1"
2014-03-15 11:01:03.937 PESPacket: Failed CRC check 0x9b030103 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:03.942 GM : Total Gym XLS new best match Total Gym XLS with score 10883
2014-03-15 11:01:03.950 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.922211
2014-03-15 11:01:03.959 EIT: accept match[0]: 10883 'Total Gym XLS' vs. 'Total Gym XLS'
2014-03-15 11:01:03.984 MSqlQuery::exec(DBManager3) UPDATE program SET starttime = '2014-03-15T12:20:56',     endtime   = '2014-03-15T13:00:00' WHERE chanid    = '1092' AND       starttime = '2014-03-15T12:20:00'
2014-03-15 11:01:04.001 MSqlQuery::exec(DBManager3) UPDATE credits SET starttime = '2014-03-15T12:20:56' WHERE chanid    = '1092' AND       starttime = '2014-03-15T12:20:00'
2014-03-15 11:01:04.009 MSqlQuery::exec(DBManager3) UPDATE program SET title          = 'Total Gym XLS',     subtitle      = '',     description    = 'Gain the body you’ve always wanted with the home gym that has totally delivered for 40 years.',     category       = 'Leisure/Hobbies',  category_type = 'tvshow',     starttime      = '2014-03-15T11:41:19', endtime       = '2014-03-15T12:20:56',     closecaptioned = 'false',        subtitled     = 'false',     stereo         = 'true',    hdtv          = 'false',     subtitletypes  = '0',     audioprop      = '1', videoprop     = '0',     partnumber     = '0',    parttotal     = '0',     syndicatedepisodenumber = '',     airdate        = '0000',   originalairdate='',     listingsource  = '1',     seriesid       = 'crid://nine.com.au/x-togy',  programid     = 'crid://nine.com.au/x-togy00ba2830tgx5n2',     previouslyshown = 'false' WHERE chanid    = '1092' AND       starttime = '2014-03-15T11:41:19' 
2014-03-15 11:01:04.017 EITHelper: Added 1 events
2014-03-15 11:01:04.430 MSqlQuery::exec(DBManager0) SELECT title,          subtitle,      description,        category,       category_type,        starttime,      endtime,        subtitletypes+0,audioprop+0,   videoprop+0,        seriesid,       programid,        partnumber,     parttotal,        syndicatedepisodenumber,        airdate,        originalairdate,        previouslyshown,listingsource FROM program WHERE chanid   = '1095' AND       manualid = 0       AND       ( ( starttime >= '2014-03-15T11:41:19' AND starttime <  '2014-03-15T12:20:56' ) OR         ( endtime   >  '2014-03-15T11:41:19' AND endtime   <= '2014-03-15T12:20:56' ) ) <<<< Returns 2 row(s)
2014-03-15 11:01:04.474 MSqlQuery::next(DBManager0) Result: "title = Total Gym XLS, subtitle = , description = Gain the body you’ve always wanted with the home gym that has totally delivered for 40 years., category = Leisure/Hobbies, category_type = tvshow, starttime = 2014-03-15T11:41:19, endtime = 2014-03-15T12:20:00, subtitletypes+0 = 0, audioprop+0 = 1, videoprop+0 = 0, seriesid = , programid = , partnumber = 0, parttotal = 0, syndicatedepisodenumber = , airdate = 0, originalairdate = , previouslyshown = 0, listingsource = 1"
root      8391  5.1  0.4 2601756 32816 ?       Ssl  10:48   0:40 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:01:04.492 MSqlQuery::next(DBManager0) Result: "title = Pearl Hair Remover, subtitle = , description = The true long-term solution for hair-free skin ? say goodbye to waxing, razors, chemicals, and pain!, category = Leisure/Hobbies, category_type = tvshow, starttime = 2014-03-15T12:20:00, endtime = 2014-03-15T13:00:00, subtitletypes+0 = 0, audioprop+0 = 1, videoprop+0 = 0, seriesid = , programid = , partnumber = 0, parttotal = 0, syndicatedepisodenumber = , airdate = 0, originalairdate = , previouslyshown = 0, listingsource = 1"
2014-03-15 11:01:04.500 GM : Total Gym XLS new best match Total Gym XLS with score 10883
2014-03-15 11:01:04.509 EIT: accept match[0]: 10883 'Total Gym XLS' vs. 'Total Gym XLS'
2014-03-15 11:01:04.517 MSqlQuery::exec(DBManager0) UPDATE program SET starttime = '2014-03-15T12:20:56',     endtime   = '2014-03-15T13:00:00' WHERE chanid    = '1095' AND       starttime = '2014-03-15T12:20:00'
2014-03-15 11:01:04.525 MSqlQuery::exec(DBManager0) UPDATE credits SET starttime = '2014-03-15T12:20:56' WHERE chanid    = '1095' AND       starttime = '2014-03-15T12:20:00'
2014-03-15 11:01:04.535 MSqlQuery::exec(DBManager0) UPDATE program SET title          = 'Total Gym XLS',     subtitle      = '',     description    = 'Gain the body you’ve always wanted with the home gym that has totally delivered for 40 years.',     category       = 'Leisure/Hobbies',  category_type = 'tvshow',     starttime      = '2014-03-15T11:41:19', endtime       = '2014-03-15T12:20:56',     closecaptioned = 'false',        subtitled     = 'false',     stereo         = 'true',    hdtv          = 'false',     subtitletypes  = '0',     audioprop      = '1', videoprop     = '0',     partnumber     = '0',    parttotal     = '0',     syndicatedepisodenumber = '',     airdate        = '0000',   originalairdate='',     listingsource  = '1',     seriesid       = '',  programid     = '',     previouslyshown = 'false' WHERE chanid    = '1095' AND       starttime = '2014-03-15T11:41:19' 
2014-03-15 11:01:04.542 EITHelper: Added 1 events
2014-03-15 11:01:04.893 PESPacket: Failed CRC check 0x9b030104 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:04.900 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.891612
2014-03-15 11:01:04.920 PESPacket: Failed CRC check 0x9b030104 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:04.925 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.92335
root      8391  5.3  0.4 2601756 32816 ?       Ssl  10:48   0:41 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:01:05.897 PESPacket: Failed CRC check 0x9b030105 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:05.900 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.892749
2014-03-15 11:01:05.936 PESPacket: Failed CRC check 0x9b030105 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:05.958 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.925533
root      8391  5.4  0.4 2601756 32816 ?       Ssl  10:48   0:42 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:01:06.897 PESPacket: Failed CRC check 0x9b030106 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:06.908 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.894934
2014-03-15 11:01:06.919 PESPacket: Failed CRC check 0x9b030106 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:06.924 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.927733
root      8391  5.5  0.4 2601756 32816 ?       Ssl  10:48   0:43 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:01:07.907 PESPacket: Failed CRC check 0x9b030107 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:07.915 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.897638
2014-03-15 11:01:07.935 PESPacket: Failed CRC check 0x9b030107 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:07.940 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.929917
root      8391  5.6  0.4 2601756 32816 ?       Ssl  10:48   0:44 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:01:08.907 PESPacket: Failed CRC check 0x9b030108 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:08.915 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.899301
2014-03-15 11:01:08.952 PESPacket: Failed CRC check 0x9b030108 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:08.957 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.932101
root      8391  5.8  0.4 2601756 32816 ?       Ssl  10:48   0:45 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:01:09.925 PESPacket: Failed CRC check 0x9b030109 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:09.931 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.902526
2014-03-15 11:01:09.968 PESPacket: Failed CRC check 0x9b030109 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:09.973 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.936888
root      8391  5.9  0.4 2601756 32816 ?       Ssl  10:48   0:46 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:01:10.928 PESPacket: Failed CRC check 0x9b030110 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:10.931 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.904704
2014-03-15 11:01:10.934 PESPacket: Failed CRC check 0x9b030110 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:10.971 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.941064
root      8391  6.0  0.4 2601756 32816 ?       Ssl  10:48   0:47 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:01:11.929 PESPacket: Failed CRC check 0x9b030111 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:11.939 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.908446
2014-03-15 11:01:11.951 PESPacket: Failed CRC check 0x9b030111 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:11.955 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.942723
root      8391  6.1  0.4 2601756 32816 ?       Ssl  10:48   0:48 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:01:12.930 PESPacket: Failed CRC check 0x9b030112 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:12.938 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.911145
2014-03-15 11:01:12.967 PESPacket: Failed CRC check 0x9b030112 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:12.971 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.946984
2014-03-15 11:01:13.598 MSqlQuery::exec(DBManager2) DELETE FROM eit_cache WHERE chanid  = '1033'   AND       status  = '1'
2014-03-15 11:01:13.637 MSqlQuery::exec(DBManager2) REPLACE INTO eit_cache        ( chanid,  eventid,  endtime,  status) VALUES ('1033', '0', '1394852473', '2')
2014-03-15 11:01:13.655 MSqlQuery::exec(DBManager4) DELETE FROM eit_cache WHERE chanid  = '1071'   AND       status  = '1'
2014-03-15 11:01:13.663 MSqlQuery::exec(DBManager4) REPLACE INTO eit_cache        ( chanid,  eventid,  endtime,  status) VALUES ('1071', '0', '1394852473', '2')
2014-03-15 11:01:13.672 MSqlQuery::exec(DBManager1) DELETE FROM eit_cache WHERE chanid  = '1074'   AND       status  = '1'
2014-03-15 11:01:13.680 MSqlQuery::exec(DBManager1) REPLACE INTO eit_cache        ( chanid,  eventid,  endtime,  status) VALUES ('1074', '0', '1394852473', '2')
2014-03-15 11:01:13.689 MSqlQuery::exec(DBManager3) DELETE FROM eit_cache WHERE chanid  = '1078'   AND       status  = '1'
2014-03-15 11:01:13.697 MSqlQuery::exec(DBManager3) REPLACE INTO eit_cache        ( chanid,  eventid,  endtime,  status) VALUES ('1078', '0', '1394852473', '2')
2014-03-15 11:01:13.705 MSqlQuery::exec(DBManager0) REPLACE INTO eit_cache        ( chanid,  eventid,  tableid,  version,  endtime) VALUES ('1092', '46609', '78', '11', '1394854879')
2014-03-15 11:01:13.713 MSqlQuery::exec(DBManager2) REPLACE INTO eit_cache        ( chanid,  eventid,  tableid,  version,  endtime) VALUES ('1092', '48322', '78', '11', '1394857256')
root      8391  6.3  0.4 2601756 32824 ?       Ssl  10:48   0:49 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackendverbose.log -v all --pidfile /var/run/mythbackend.pid
2014-03-15 11:01:13.722 MSqlQuery::exec(DBManager4) DELETE FROM eit_cache WHERE chanid  = '1092'   AND       status  = '1'
2014-03-15 11:01:13.730 MSqlQuery::exec(DBManager4) REPLACE INTO eit_cache        ( chanid,  eventid,  endtime,  status) VALUES ('1092', '2', '1394852473', '2')
2014-03-15 11:01:13.738 EITCache: Wrote 2 modified entries of 409 for channel 1092 to database.
2014-03-15 11:01:13.747 MSqlQuery::exec(DBManager1) DELETE FROM eit_cache WHERE chanid  = '1094'   AND       status  = '1'
2014-03-15 11:01:13.755 MSqlQuery::exec(DBManager1) REPLACE INTO eit_cache        ( chanid,  eventid,  endtime,  status) VALUES ('1094', '0', '1394852473', '2')
2014-03-15 11:01:13.763 MSqlQuery::exec(DBManager3) REPLACE INTO eit_cache        ( chanid,  eventid,  tableid,  version,  endtime) VALUES ('1095', '46609', '78', '21', '1394854879')
2014-03-15 11:01:13.772 MSqlQuery::exec(DBManager0) REPLACE INTO eit_cache        ( chanid,  eventid,  tableid,  version,  endtime) VALUES ('1095', '48322', '78', '21', '1394857256')
2014-03-15 11:01:13.781 MSqlQuery::exec(DBManager2) DELETE FROM eit_cache WHERE chanid  = '1095'   AND       status  = '1'
2014-03-15 11:01:13.788 MSqlQuery::exec(DBManager2) REPLACE INTO eit_cache        ( chanid,  eventid,  endtime,  status) VALUES ('1095', '2', '1394852473', '2')
2014-03-15 11:01:13.796 EITCache: Wrote 2 modified entries of 409 for channel 1095 to database.
2014-03-15 11:01:13.804 TVRec(16): SetChannel(14) -- begin
2014-03-15 11:01:13.813 TVRec(16): ClearFlags(RingBufferReady,) -> RunMainLoop,WaitingForSignal,SignalMonitorRunning,EITScannerRunning,
2014-03-15 11:01:13.821 TVRec(16): Request: Program(no) channel(14) input() flags(EITScan,)
2014-03-15 11:01:13.830 MSqlQuery::exec(DBManager4) SELECT channel.chanid FROM channel, capturecard, cardinput WHERE channel.channum      = '14'           AND       channel.sourceid     = cardinput.sourceid AND       cardinput.inputname  = 'DVBInput'             AND       cardinput.cardid     = capturecard.cardid AND       capturecard.cardid   = '16'            AND       capturecard.hostname = 'nebuchadnezzar.lanchbury.id.au' <<<< Returns 1 row(s)
2014-03-15 11:01:13.839 MSqlQuery::exec(DBManager1) DELETE FROM eit_cache WHERE chanid  = '1033'   AND       status  = '1'
2014-03-15 11:01:13.846 MSqlQuery::exec(DBManager1) REPLACE INTO eit_cache        ( chanid,  eventid,  endtime,  status) VALUES ('1033', '0', '1394852473', '2')
2014-03-15 11:01:13.855 MSqlQuery::exec(DBManager3) DELETE FROM eit_cache WHERE chanid  = '1071'   AND       status  = '1'
2014-03-15 11:01:13.888 MSqlQuery::exec(DBManager3) REPLACE INTO eit_cache        ( chanid,  eventid,  endtime,  status) VALUES ('1071', '0', '1394852473', '2')
2014-03-15 11:01:13.906 MSqlQuery::exec(DBManager0) DELETE FROM eit_cache WHERE chanid  = '1074'   AND       status  = '1'
2014-03-15 11:01:13.913 MSqlQuery::exec(DBManager0) REPLACE INTO eit_cache        ( chanid,  eventid,  endtime,  status) VALUES ('1074', '0', '1394852473', '2')
2014-03-15 11:01:13.922 MSqlQuery::exec(DBManager2) DELETE FROM eit_cache WHERE chanid  = '1078'   AND       status  = '1'
2014-03-15 11:01:13.928 PESPacket: Failed CRC check 0x9b030113 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:13.938 DTVSM(/dev/dvb/adapter1/frontend0): Time Offset: -0.914369
2014-03-15 11:01:13.933 PESPacket: Failed CRC check 0x9b030113 != 0xec357263 for StreamID = 0x70
2014-03-15 11:01:13.930 MSqlQuery::exec(DBManager2) REPLACE INTO eit_cache        ( chanid,  eventid,  endtime,  status) VALUES ('1078', '0', '1394852473', '2')
2014-03-15 11:01:13.954 DTVSM(/dev/dvb/adapter0/frontend0): Time Offset: -0.949168
2014-03-15 11:01:13.964 MSqlQuery::exec(DBManager4) DELETE FROM eit_cache WHERE chanid  = '1092'   AND       status  = '1'
2014-03-15 11:01:13.980 MSqlQuery::exec(DBManager4) REPLACE INTO eit_cache        ( chanid,  eventid,  endtime,  status) VALUES ('1092', '0', '1394852473', '2')
2014-03-15 11:01:13.989 MSqlQuery::exec(DBManager1) DELETE FROM eit_cache WHERE chanid  = '1094'   AND       status  = '1'
2014-03-15 11:01:13.996 MSqlQuery::exec(DBManager1) REPLACE INTO eit_cache        ( chanid,  eventid,  endtime,  status) VALUES ('1094', '0', '1394852473', '2')
2014-03-15 11:01:14.006 MSqlQuery::exec(DBManager3) DELETE FROM eit_cache WHERE chanid  = '1095'   AND       status  = '1'
2014-03-15 11:01:14.013 MSqlQuery::exec(DBManager3) REPLACE INTO eit_cache        ( chanid,  eventid,  endtime,  status) VALUES ('1095', '0', '1394852474', '2')
2014-03-15 11:01:14.021 TVRec(16): TeardownSignalMonitor() -- begin
2014-03-15 11:01:14.029 DVBSM(/dev/dvb/adapter2/frontend0): Stop() -- begin
2014-03-15 11:01:14.038 SM(/dev/dvb/adapter2/frontend0)::Stop: begin
2014-03-15 11:01:14.077 SM(/dev/dvb/adapter2/frontend0)::Stop: end
2014-03-15 11:01:14.079 DVBSH(/dev/dvb/adapter2/frontend0): RemoveListener(0x7f1e6401ec18) -- begin
2014-03-15 11:01:14.088 DVBSH(/dev/dvb/adapter2/frontend0): RemoveListener(0x7f1e6401ec18) -- locked
2014-03-15 11:01:14.135 DVBSH(/dev/dvb/adapter2/frontend0): RunTS(): shutdown
2014-03-15 11:01:14.138 PIDInfo(/dev/dvb/adapter2/frontend0): Closing filter for pid 0x0
2014-03-15 11:01:14.146 PIDInfo(/dev/dvb/adapter2/frontend0): Closing filter for pid 0x10
2014-03-15 11:01:14.154 PIDInfo(/dev/dvb/adapter2/frontend0): Closing filter for pid 0x11
2014-03-15 11:01:14.163 PIDInfo(/dev/dvb/adapter2/frontend0): Closing filter for pid 0x14
2014-03-15 11:01:14.172 DVBSH(/dev/dvb/adapter2/frontend0): RunTS(): end
2014-03-15 11:01:14.179 DVBSH(/dev/dvb/adapter2/frontend0): RemoveListener(0x7f1e6401ec18) -- end
2014-03-15 11:01:14.188 DVBSM(/dev/dvb/adapter2/frontend0): Stop() -- end
2014-03-15 11:01:14.196 SM(/dev/dvb/adapter2/frontend0)::Stop: begin
2014-03-15 11:01:14.204 SM(/dev/dvb/adapter2/frontend0)::Stop: end
2014-03-15 11:01:14.213 TVRec(16): TeardownSignalMonitor() -- end
2014-03-15 11:01:14.221 TVRec(16): ClearFlags(SignalMonitorRunning,) -> RunMainLoop,WaitingForSignal,EITScannerRunning,
2014-03-15 11:01:14.229 TVRec(16): ClearFlags(WaitingForSignal,) -> RunMainLoop,EITScannerRunning,
2014-03-15 11:01:14.238 TVRec(16): ClearFlags(PENDINGACTIONS,) -> RunMainLoop,EITScannerRunning,
2014-03-15 11:01:14.246 TVRec(16): No recorder yet, calling TuningFrequency
2014-03-15 11:01:14.254 DVBChan(16:/dev/dvb/adapter2/frontend0): Opening DVB channel
2014-03-15 11:01:14.263 DVBChan(16:/dev/dvb/adapter2/frontend0): SetChannelByString(14): 
User avatar
stuarta
Developer
Posts: 220
Joined: Wed Feb 05, 2014 5:13 pm
Great Britain

Re: mythbackend 107% CPU 5 minutes after starting

Post by stuarta »

Do you get constant streams of these errors?

"2014-03-15 11:01:05.897 PESPacket: Failed CRC check 0x9b030105 != 0xec357263 for StreamID = 0x70"

Just printing these log messages will hammer you system
I note you are on 0.23, i'm fairly sure we've put code into newer releases to not be so verbose
sndguru
Newcomer
Posts: 4
Joined: Sat Mar 15, 2014 3:21 am
Australia

Re: mythbackend 107% CPU 5 minutes after starting

Post by sndguru »

Thanks stuarta for looking into my problem, I can see myself how hard it is to find the issue.
stuarta wrote:Do you get constant streams of these errors?
"2014-03-15 11:01:05.897 PESPacket: Failed CRC check 0x9b030105 != 0xec357263 for StreamID = 0x70"
Just printing these log messages will hammer you system
I note you are on 0.23, i'm fairly sure we've put code into newer releases to not be so verbose
Day to day I don't have it on verbose logging, it was just to try and see whats happening. So my processor goes nuts even with standard logging.

Code: Select all

[nathan@nebuchadnezzar ~]$ grep "Failed CRC" /var/log/mythtv/mythbackend.log
[nathan@nebuchadnezzar ~]$ head /var/log/mythtv/mythbackend.log
2014-03-16 03:15:20.781 Program #1377 not found in PAT!
Program Association Table
 PSIP tableID(0x0) length(45) extension(0x320)
      version(0) current(1) section(0) last_section(0)
         tsid: 800
 programCount: 9
  program number     0 has PID 0x  10   data  0x 0 0x 0 0xe0 0x10
  program number   801 has PID 0x 401   data  0x 3 0x21 0xe4 0x 1
  program number   802 has PID 0x 402   data  0x 3 0x22 0xe4 0x 2
  program number   803 has PID 0x 408   data  0x 3 0x23 0xe4 0x 8
[nathan@nebuchadnezzar ~]$ tail /var/log/mythtv/mythbackend.log
  program number   803 has PID 0x 408   data  0x 3 0x23 0xe4 0x 8
  program number   804 has PID 0x 409   data  0x 3 0x24 0xe4 0x 9
  program number   805 has PID 0x 400   data  0x 3 0x25 0xe4 0x 0
  program number   814 has PID 0x 403   data  0x 3 0x2e 0xe4 0x 3
  program number   815 has PID 0x 404   data  0x 3 0x2f 0xe4 0x 4
  program number   816 has PID 0x 405   data  0x 3 0x30 0xe4 0x 5

2014-03-27 13:49:56.288 Reschedule requested for id -1.
2014-03-27 13:49:57.534 Scheduled 77 items in 1.2 = 0.03 match + 1.14 place
2014-03-27 13:50:20.657 AutoExpire: CalcParams(): Max required Free Space: 5.0 GB w/freq: 15 min
[nathan@nebuchadnezzar ~]$ ps aux | grep mythbackend.pid
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root      5398  101  1.6 2560944 138072 ?      Ssl  Mar15 17392:19 /usr/bin/mythbackend --daemon --logfile /var/log/mythtv/mythbackend.log --pidfile /var/run/mythbackend.pid
As you can see my system hasn't generated any Failed CRC messages in the past 6 days

I understand I'm on a old system, I'm saving my penny's to buy a new server that will do VT-d visualization so I can pass my TV tuners down to a virtual system which will make keeping an up to date system much easier. But that's still a number of months away so it would be good to control the process in the mean time.
User avatar
stuarta
Developer
Posts: 220
Joined: Wed Feb 05, 2014 5:13 pm
Great Britain

Re: mythbackend 107% CPU 5 minutes after starting

Post by stuarta »

sndguru wrote: I understand I'm on a old system, I'm saving my penny's to buy a new server that will do VT-d visualization so I can pass my TV tuners down to a virtual system which will make keeping an up to date system much easier. But that's still a number of months away so it would be good to control the process in the mean time.
That sounds like a challenge, trying to pass tuners through to a virtual machine. I'd be interested to see how you get on, but be warned, it's probably going to be challenging. What would be easier is having network attached tuners. They are much easier to work with on a VM
User avatar
rwagner
Developer
Posts: 217
Joined: Thu Feb 06, 2014 11:37 pm
United States of America

Re: mythbackend 107% CPU 5 minutes after starting

Post by rwagner »

stuarta wrote:That sounds like a challenge, trying to pass tuners through to a virtual machine.
The mailing list is full of failed attempts, and any LinuxTV dev will basically tell you don't do it.
sndguru wrote:a virtual system which will make keeping an up to date system much easier
Isolation makes keeping an up to date system much easier (due to not worrying about different applications fighting over dependencies), but where virtual machines require isolation due to their basic nature, isolation can be had in a wide range of grades without resorting to a full on virtual machine.
User avatar
stuarta
Developer
Posts: 220
Joined: Wed Feb 05, 2014 5:13 pm
Great Britain

Re: mythbackend 107% CPU 5 minutes after starting

Post by stuarta »

rwagner wrote: Isolation makes keeping an up to date system much easier (due to not worrying about different applications fighting over dependencies), but where virtual machines require isolation due to their basic nature, isolation can be had in a wide range of grades without resorting to a full on virtual machine.
I have 0.27 and master both running on the same physical hardware, each taking 1 tuner from 2 dual tuners (so each has 1x DVB-T and 1x DVB-S2). It's definitely doable without resorting to VM's
Post Reply