search

MythTV / mythtv

The official MythTV repository
https://www.mythtv.org
GNU General Public License v2.0
706 stars 347 forks source link

Git pulled from 31st Oct with new database fails to start backend #275

Closed bib1963 closed 3 years ago

bib1963 commented 3 years ago

What steps will reproduce the bug?

/opt/mythtv/bin/mythbackend -d --noupnp -p /home/mythtv/.mythbackend.pid --logpath /home/mythtv/logs

How often does it reproduce? Is there a required condition?

Always

What is the expected behaviour?

Should start

2020-10-31 14:40:16.203769 C [28069/28069] thread_unknown mythcommandlineparser.cpp:2631 (ConfigureLogging) - mythbackend version: master [v32-Pre-1622-g946170e1ab] www.mythtv.org 2020-10-31 14:40:16.203783 C [28069/28069] thread_unknown mythcommandlineparser.cpp:2633 (ConfigureLogging) - Qt version: compile: 5.12.7, runtime: 5.12.7 2020-10-31 14:40:16.203817 I [28069/28069] thread_unknown mythcommandlineparser.cpp:2635 (ConfigureLogging) - openSUSE Leap 15.2 (x86_64) 2020-10-31 14:40:16.203818 N [28069/28069] thread_unknown mythcommandlineparser.cpp:2637 (ConfigureLogging) - Enabled verbose msgs: general 2020-10-31 14:40:16.203903 N [28069/28069] thread_unknown logging.cpp:711 (logStart) - Setting Log Level to LOG_INFO 2020-10-31 14:40:16.214188 I [28069/28071] Logger logging.cpp:297 (run) - Added logging to the console 2020-10-31 14:40:16.214484 I [28069/28070] LogForward loggingserver.cpp:113 (FileLogger) - Added logging to /home/mythtv/logs/mythbackend.20201031144016.28069.log 2020-10-31 14:40:16.214733 I [28069/28069] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Interrupt handler 2020-10-31 14:40:16.214741 I [28069/28069] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Terminated handler 2020-10-31 14:40:16.214746 I [28069/28069] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Segmentation fault handler 2020-10-31 14:40:16.214751 I [28069/28069] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Aborted handler 2020-10-31 14:40:16.214755 I [28069/28069] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Bus error handler 2020-10-31 14:40:16.214764 I [28069/28069] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Floating point exception handler 2020-10-31 14:40:16.214769 I [28069/28069] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Illegal instruction handler 2020-10-31 14:40:16.214779 I [28069/28069] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Real-time signal 0 handler 2020-10-31 14:40:16.214785 I [28069/28069] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Hangup handler 2020-10-31 14:40:16.214906 N [28069/28069] thread_unknown mythdirs.cpp:203 (InitializeMythDirs) - Using runtime prefix = /opt/mythtv-20201031 2020-10-31 14:40:16.214908 N [28069/28069] thread_unknown mythdirs.cpp:205 (InitializeMythDirs) - Using configuration directory = /home/mythtv/.mythtv 2020-10-31 14:40:16.214938 I [28069/28069] CoreContext mythcorecontext.cpp:280 (Init) - Assumed character encoding: en_GB.UTF-8 2020-10-31 14:40:16.215154 I [28069/28069] CoreContext mythcontext.cpp:632 (LoadDatabaseSettings) - Using a profile name of: 'ns1' (Usually the same as this host's name.) 2020-10-31 14:40:16.215185 I [28069/28069] CoreContext mythcontext.cpp:881 (TestDBconnection) - Start up testing connections. DB ns1, BE , attempt 0, status dbAwake, Delay: 2000 2020-10-31 14:40:17.226385 N [28069/28069] CoreContext mythcorecontext.cpp:1834 (InitLocale) - Setting QT default locale to en_US 2020-10-31 14:40:17.226393 I [28069/28069] CoreContext mythcorecontext.cpp:1867 (SaveLocaleDefaults) - Current locale en_US 2020-10-31 14:40:17.226422 N [28069/28069] CoreContext mythlocale.cpp:122 (LoadDefaultsFromXML) - Reading locale defaults from /opt/mythtv-20201031/share/mythtv//locales/en_us.xml 2020-10-31 14:40:17.237851 I [28069/28069] CoreContext platforms/mythpowerdbus.cpp:537 (AcquireLock) - PowerDBus: Failed to delay sleep,shutdown: Permission denied 2020-10-31 14:40:17.240118 I [28069/28069] CoreContext platforms/mythpowerdbus.cpp:366 (DeviceAdded) - PowerDBus: Added UPower.Device '/org/freedesktop/UPower/devices/keyboard_hidpp_battery_0' 2020-10-31 14:40:17.240123 I [28069/28069] CoreContext mythpower.cpp:374 (PowerLevelChanged) - Power: Unknown power source 2020-10-31 14:40:17.240685 I [28069/28069] CoreContext platforms/mythpowerdbus.cpp:366 (DeviceAdded) - PowerDBus: Added UPower.Device '/org/freedesktop/UPower/devices/mouse_hidpp_battery_1' 2020-10-31 14:40:17.254128 I [28069/28069] CoreContext mythpower.cpp:131 (Init) - Power: Supported actions: None 2020-10-31 14:40:17.254726 I [28069/28069] CoreContext mythtranslation.cpp:64 (load) - Loading en_us translation for module mythfrontend 2020-10-31 14:40:17.256506 I [28069/28069] CoreContext schemawizard.cpp:119 (Compare) - Current MythTV Schema Version (DBSchemaVer): 1366 2020-10-31 14:40:17.256660 I [28069/28069] CoreContext mythtranslation.cpp:64 (load) - Loading en_us translation for module mythfrontend 2020-10-31 14:40:17.257468 I [28069/28069] CoreContext platforms/mythpowerdbus.cpp:72 (~MythPowerDBus) - PowerDBus: Closing interfaces 2020-10-31 14:40:17.257713 I [28069/28069] CoreContext mythcontext.cpp:1658 (~MythContext) - Exiting

or from a previous failed attempt: 2020-10-31 14:32:09.198810 C [27336/27336] thread_unknown mythcommandlineparser.cpp:2631 (ConfigureLogging) - mythbackend version: master [v32-Pre-1622-g946170e1ab] www.mythtv.org 2020-10-31 14:32:09.198822 C [27336/27336] thread_unknown mythcommandlineparser.cpp:2633 (ConfigureLogging) - Qt version: compile: 5.12.7, runtime: 5.12.7 2020-10-31 14:32:09.198855 I [27336/27336] thread_unknown mythcommandlineparser.cpp:2635 (ConfigureLogging) - openSUSE Leap 15.2 (x86_64) 2020-10-31 14:32:09.198857 N [27336/27336] thread_unknown mythcommandlineparser.cpp:2637 (ConfigureLogging) - Enabled verbose msgs: general 2020-10-31 14:32:09.198935 N [27336/27336] thread_unknown logging.cpp:711 (logStart) - Setting Log Level to LOG_INFO 2020-10-31 14:32:09.209203 I [27336/27338] Logger logging.cpp:297 (run) - Added logging to the console 2020-10-31 14:32:09.209494 I [27336/27337] LogForward loggingserver.cpp:113 (FileLogger) - Added logging to /home/mythtv/logs/mythbackend.20201031143209.27336.log 2020-10-31 14:32:09.209744 I [27336/27336] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Interrupt handler 2020-10-31 14:32:09.209751 I [27336/27336] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Terminated handler 2020-10-31 14:32:09.209756 I [27336/27336] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Segmentation fault handler 2020-10-31 14:32:09.209761 I [27336/27336] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Aborted handler 2020-10-31 14:32:09.209766 I [27336/27336] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Bus error handler 2020-10-31 14:32:09.209774 I [27336/27336] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Floating point exception handler 2020-10-31 14:32:09.209780 I [27336/27336] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Illegal instruction handler 2020-10-31 14:32:09.209792 I [27336/27336] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Real-time signal 0 handler 2020-10-31 14:32:09.209799 I [27336/27336] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Hangup handler 2020-10-31 14:32:09.209923 N [27336/27336] thread_unknown mythdirs.cpp:203 (InitializeMythDirs) - Using runtime prefix = /opt/mythtv-20201031 2020-10-31 14:32:09.209925 N [27336/27336] thread_unknown mythdirs.cpp:205 (InitializeMythDirs) - Using configuration directory = /home/mythtv/.mythtv 2020-10-31 14:32:09.209953 I [27336/27336] CoreContext mythcorecontext.cpp:280 (Init) - Assumed character encoding: en_GB.UTF-8 2020-10-31 14:32:09.210157 I [27336/27336] CoreContext mythcontext.cpp:632 (LoadDatabaseSettings) - Using a profile name of: 'ns1' (Usually the same as this host's name.) 2020-10-31 14:32:09.210188 I [27336/27336] CoreContext mythcontext.cpp:881 (TestDBconnection) - Start up testing connections. DB ns1, BE , attempt 0, status dbAwake, Delay: 2000 2020-10-31 14:32:10.221532 N [27336/27336] CoreContext mythcorecontext.cpp:1834 (InitLocale) - Setting QT default locale to en_US 2020-10-31 14:32:10.221539 I [27336/27336] CoreContext mythcorecontext.cpp:1867 (SaveLocaleDefaults) - Current locale en_US 2020-10-31 14:32:10.221569 N [27336/27336] CoreContext mythlocale.cpp:122 (LoadDefaultsFromXML) - Reading locale defaults from /opt/mythtv-20201031/share/mythtv//locales/en_us.xml 2020-10-31 14:32:10.233407 I [27336/27336] CoreContext platforms/mythpowerdbus.cpp:537 (AcquireLock) - PowerDBus: Failed to delay sleep,shutdown: Permission denied 2020-10-31 14:32:10.235168 I [27336/27336] CoreContext platforms/mythpowerdbus.cpp:366 (DeviceAdded) - PowerDBus: Added UPower.Device '/org/freedesktop/UPower/devices/keyboard_hidpp_battery_0' 2020-10-31 14:32:10.235173 I [27336/27336] CoreContext mythpower.cpp:374 (PowerLevelChanged) - Power: Unknown power source 2020-10-31 14:32:10.235755 I [27336/27336] CoreContext platforms/mythpowerdbus.cpp:366 (DeviceAdded) - PowerDBus: Added UPower.Device '/org/freedesktop/UPower/devices/mouse_hidpp_battery_1' 2020-10-31 14:32:10.248719 I [27336/27336] CoreContext mythpower.cpp:131 (Init) - Power: Supported actions: None 2020-10-31 14:32:10.249331 I [27336/27336] CoreContext mythtranslation.cpp:64 (load) - Loading en_us translation for module mythfrontend 2020-10-31 14:32:10.250945 I [27336/27336] CoreContext schemawizard.cpp:119 (Compare) - Current MythTV Schema Version (DBSchemaVer): 1366 2020-10-31 14:32:10.251108 I [27336/27336] CoreContext mythtranslation.cpp:64 (load) - Loading en_us translation for module mythfrontend 2020-10-31 14:32:10.252257 E [27336/27342] MythSocketThread(-1) mythsocket.cpp:694 (ConnectToHostReal) - MythSocket(1abfed0:-1): Failed to connect to (::1:6543) Connection refused 2020-10-31 14:32:10.253273 I [27336/27336] CoreContext platforms/mythpowerdbus.cpp:72 (~MythPowerDBus) - PowerDBus: Closing interfaces 2020-10-31 14:32:10.253519 I [27336/27336] CoreContext mythcontext.cpp:1658 (~MythContext) - Exiting

What do you see instead?

Additional information

The backend database IS set up correctly. I set it to listen on ipv4 & ipv6 loopbacks, routable IP addrress

bib1963 commented 3 years ago

And more debug...

mythtv@eth7 ~$ /opt/mythtv/bin/mythbackend --noupnp -p /home/mythtv/.mythbackend.pid --logpath /home/mythtv/logs -v database,general,network,socket,system

2020-10-31 14:54:45.423601 C mythbackend version: master [v32-Pre-1622-g946170e1ab] www.mythtv.org 2020-10-31 14:54:45.423610 C Qt version: compile: 5.12.7, runtime: 5.12.7 2020-10-31 14:54:45.423630 I openSUSE Leap 15.2 (x86_64) 2020-10-31 14:54:45.423631 N Enabled verbose msgs: general database network socket system 2020-10-31 14:54:45.423668 N Setting Log Level to LOG_INFO 2020-10-31 14:54:45.434017 I Added logging to the console 2020-10-31 14:54:45.434324 I Setup Interrupt handler 2020-10-31 14:54:45.434328 I Setup Terminated handler 2020-10-31 14:54:45.434332 I Setup Segmentation fault handler 2020-10-31 14:54:45.434335 I Setup Aborted handler 2020-10-31 14:54:45.434338 I Setup Bus error handler 2020-10-31 14:54:45.434343 I Setup Floating point exception handler 2020-10-31 14:54:45.434347 I Setup Illegal instruction handler 2020-10-31 14:54:45.434353 I Setup Real-time signal 0 handler 2020-10-31 14:54:45.434357 I Setup Hangup handler 2020-10-31 14:54:45.434427 N Using runtime prefix = /opt/mythtv-20201031 2020-10-31 14:54:45.434428 N Using configuration directory = /home/mythtv/.mythtv 2020-10-31 14:54:45.434451 I Assumed character encoding: en_GB.UTF-8 2020-10-31 14:54:45.434623 I Using a profile name of: 'ns1' (Usually the same as this host's name.) 2020-10-31 14:54:45.434628 I Clearing Settings Cache. 2020-10-31 14:54:45.434637 I Added logging to /home/mythtv/logs/mythbackend.20201031145445.28820.log 2020-10-31 14:54:45.434658 I Start up testing connections. DB ns1, BE , attempt 0, status dbAwake, Delay: 2000 No setting found for this machine's BackendServerIP. Please run setup on this machine and modify the first page of the general settings. 2020-10-31 14:54:46.438908 I Clearing Settings Cache. 2020-10-31 14:54:46.441468 I Database object created: DBManager0 2020-10-31 14:54:46.441476 I New DB connection, total: 1 2020-10-31 14:54:46.442346 I [DBManager0] Connected to database 'mythtvdb' at host: ns1 2020-10-31 14:54:46.443245 I Closing DB connection named 'DBManager0' 2020-10-31 14:54:46.443286 I Clearing Settings Cache. 2020-10-31 14:54:46.443296 I Clearing Settings Cache. 2020-10-31 14:54:46.443325 I Database object created: DBManager1 2020-10-31 14:54:46.443328 I New DB connection, total: 1 2020-10-31 14:54:46.443953 I [DBManager1] Connected to database 'mythtvdb' at host: ns1 2020-10-31 14:54:46.444442 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'language' AND hostname = 'ns1' <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.444628 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'language' AND hostname IS NULL <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.444788 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'country' AND hostname = 'ns1' <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.444934 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'country' AND hostname IS NULL <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.444961 N Setting QT default locale to en_US 2020-10-31 14:54:46.444966 I Current locale en_US 2020-10-31 14:54:46.444996 N Reading locale defaults from /opt/mythtv-20201031/share/mythtv//locales/en_us.xml 2020-10-31 14:54:46.445300 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'country' AND hostname = 'ns1' <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.445445 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'country' AND hostname IS NULL <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.445590 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'freqtable' AND hostname = 'ns1' <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.445731 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'freqtable' AND hostname IS NULL <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.445876 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'iso639language0' AND hostname = 'ns1' <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.446019 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'iso639language0' AND hostname IS NULL <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.446162 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'iso639language1' AND hostname = 'ns1' <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.446303 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'iso639language1' AND hostname IS NULL <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.446445 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'language' AND hostname = 'ns1' <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.446586 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'language' AND hostname IS NULL <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.446732 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'tvformat' AND hostname = 'ns1' <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.446875 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'tvformat' AND hostname IS NULL <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.447020 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'vbiformat' AND hostname = 'ns1' <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.447182 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'vbiformat' AND hostname IS NULL <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.447330 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'dateformat' AND hostname = 'ns1' <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.447480 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'mytharchivedateformat' AND hostname = 'ns1' <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.447631 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'mytharchivetimeformat' AND hostname = 'ns1' <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.447779 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'mytharchivevideoformat' AND hostname = 'ns1' <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.447928 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'shortdateformat' AND hostname = 'ns1' <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.448078 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'timeformat' AND hostname = 'ns1' <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.448094 I Enabling Settings Cache. 2020-10-31 14:54:46.448095 I Clearing Settings Cache. 2020-10-31 14:54:46.455219 I PowerDBus: Added UPower.Device '/org/freedesktop/UPower/devices/keyboard_hidpp_battery_0' 2020-10-31 14:54:46.455224 I Power: Unknown power source 2020-10-31 14:54:46.455766 I PowerDBus: Added UPower.Device '/org/freedesktop/UPower/devices/mouse_hidpp_battery_1' 2020-10-31 14:54:46.468379 I Power: Supported actions: Suspend,Restart,Shutdown 2020-10-31 14:54:46.468756 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'language' AND hostname = 'ns1' <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.468927 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'language' AND hostname IS NULL <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.469002 I Loading en_us translation for module mythfrontend 2020-10-31 14:54:46.469155 E setHttpProxy() - failed to find a network proxy 2020-10-31 14:54:46.469300 I MSqlQuery::exec(DBManager1) SELECT CONVERT_TZ(NOW(), 'SYSTEM', 'Etc/UTC') <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.469497 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'dbschemaver' AND hostname = 'ns1' <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.469682 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'dbschemaver' AND hostname IS NULL <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.469839 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'masterservername' AND hostname = 'ns1' <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.469986 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'masterservername' AND hostname IS NULL <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.470002 I Disabling Settings Cache. 2020-10-31 14:54:46.470003 I Clearing Settings Cache. 2020-10-31 14:54:46.470098 I MSqlQuery::exec(DBManager1) SELECT GET_LOCK('schemaLock', '1') <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.470248 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'dbschemaautoupgrade' AND hostname = 'ns1' <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.470385 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'dbschemaautoupgrade' AND hostname IS NULL <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.470541 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'dbschemaver' AND hostname = 'ns1' <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.470681 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'dbschemaver' AND hostname IS NULL <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.470692 I Current MythTV Schema Version (DBSchemaVer): 1366 2020-10-31 14:54:46.470694 I Enabling Settings Cache. 2020-10-31 14:54:46.470694 I Clearing Settings Cache. 2020-10-31 14:54:46.470775 I MSqlQuery::exec(DBManager1) SELECT RELEASE_LOCK('schemaLock') <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.470842 I Loading en_us translation for module mythfrontend 2020-10-31 14:54:46.470858 I MythSocket(a70940:-1): MythSocket(-1, 0x0) ctor 2020-10-31 14:54:46.471125 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'masterservername' AND hostname = 'ns1' <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.471288 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'masterservername' AND hostname IS NULL <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.471446 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'backendserverport' AND hostname = 'eth7' <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.471599 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'backendserveraddr' AND hostname = 'eth7' <<<< Took 0ms, Returned 1 row(s) 2020-10-31 14:54:46.472068 I MythSocket(a70940:-1): IP is local, using loopback address instead 2020-10-31 14:54:46.472073 I MythSocket(a70940:-1): attempting connect() to (::1:6543) 2020-10-31 14:54:46.472168 E MythSocket(a70940:-1): Failed to connect to (::1:6543) Connection refused 2020-10-31 14:54:46.472179 I MythSocket(a70940:-1): MythSocket dtor : cb 0x0 2020-10-31 14:54:46.472475 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'backendserverport' AND hostname = 'ns1' <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.472631 I MSqlQuery::exec(DBManager1) SELECT data FROM settings WHERE value = 'backendserveraddr' AND hostname = 'ns1' <<<< Took 0ms, Returned 0 row(s) 2020-10-31 14:54:46.473104 I PowerDBus: Closing interfaces 2020-10-31 14:54:46.473463 I Exiting 2020-10-31 14:54:46.567240 I Removed logging to /home/mythtv/logs/mythbackend.20201031145445.28820.log

root@eth7 # netstat -anp | grep :65 | wc -l 0

So, nothing already listening on that port.

bib1963 commented 3 years ago

Okay, it seems like it will not run as mythtv, only root.

bib1963 commented 3 years ago

And only runs from the foreground, not background.

bib1963 commented 3 years ago

It may help, my system has a single interface with multiple reverse DNS hostname, IPv4 & IPv6 addresses.

bib1963 commented 3 years ago

I can kind of manage to get it started, however...

It usually fails to fully start the backend, in that the network ports are not opened up, log below. Restart it, and it may then work as normal. Start it again and it may fail.

When it fails, running lsof, gives the following:

root@eth7 ~# lsof | grep dvb/adap mythbacke 24463 mythtv 13u CHR 212,0 0t0 25087 /dev/dvb/adapter2/frontend0 mythbacke 24463 24464 LogForwar mythtv 13u CHR 212,0 0t0 25087 /dev/dvb/adapter2/frontend0 mythbacke 24463 24465 Logger mythtv 13u CHR 212,0 0t0 25087 /dev/dvb/adapter2/frontend0 mythbacke 24463 24466 QLibProxy mythtv 13u CHR 212,0 0t0 25087 /dev/dvb/adapter2/frontend0 mythbacke 24463 24469 QDBusConn mythtv 13u CHR 212,0 0t0 25087 /dev/dvb/adapter2/frontend0 mythbacke 24463 24474 TVRecEven mythtv 13u CHR 212,0 0t0 25087 /dev/dvb/adapter2/frontend0 mythbacke 24463 24475 EIT mythtv 13u CHR 212,0 0t0 25087 /dev/dvb/adapter2/frontend0

And the logs from that start:

2020-11-01 11:00:33.767555 C [24463/24463] thread_unknown mythcommandlineparser.cpp:2631 (ConfigureLogging) - mythbackend version: master [v32-Pre-1622-g946170e1ab] www.mythtv.org
2020-11-01 11:00:33.767568 C [24463/24463] thread_unknown mythcommandlineparser.cpp:2633 (ConfigureLogging) - Qt version: compile: 5.12.7, runtime: 5.12.7
2020-11-01 11:00:33.767595 I [24463/24463] thread_unknown mythcommandlineparser.cpp:2635 (ConfigureLogging) - openSUSE Leap 15.2 (x86_64)
2020-11-01 11:00:33.767597 N [24463/24463] thread_unknown mythcommandlineparser.cpp:2637 (ConfigureLogging) - Enabled verbose msgs:  general
2020-11-01 11:00:33.767680 N [24463/24463] thread_unknown logging.cpp:711 (logStart) - Setting Log Level to LOG_INFO
2020-11-01 11:00:33.778042 I [24463/24465] Logger logging.cpp:297 (run) - Added logging to the console
2020-11-01 11:00:33.778415 I [24463/24464] LogForward loggingserver.cpp:113 (FileLogger) - Added logging to /home/mythtv/logs/mythbackend.20201101110033.24463.log
2020-11-01 11:00:33.778683 I [24463/24463] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Interrupt handler
2020-11-01 11:00:33.778690 I [24463/24463] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Terminated handler
2020-11-01 11:00:33.778696 I [24463/24463] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Segmentation fault handler
2020-11-01 11:00:33.778701 I [24463/24463] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Aborted handler
2020-11-01 11:00:33.778705 I [24463/24463] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Bus error handler
2020-11-01 11:00:33.778714 I [24463/24463] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Floating point exception handler
2020-11-01 11:00:33.778720 I [24463/24463] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Illegal instruction handler
2020-11-01 11:00:33.778734 I [24463/24463] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Real-time signal 0 handler
2020-11-01 11:00:33.778740 I [24463/24463] thread_unknown signalhandling.cpp:179 (SetHandlerPrivate) - Setup Hangup handler
2020-11-01 11:00:33.778881 N [24463/24463] thread_unknown mythdirs.cpp:203 (InitializeMythDirs) - Using runtime prefix = /opt/mythtv-20201031
2020-11-01 11:00:33.778882 N [24463/24463] thread_unknown mythdirs.cpp:205 (InitializeMythDirs) - Using configuration directory = /home/mythtv/.mythtv
2020-11-01 11:00:33.778911 I [24463/24463] CoreContext mythcorecontext.cpp:280 (Init) - Assumed character encoding: en_GB.UTF-8
2020-11-01 11:00:33.779137 I [24463/24463] CoreContext mythcontext.cpp:632 (LoadDatabaseSettings) - Using a profile name of: 'ns1' (Usually the same as this host's name.)
2020-11-01 11:00:33.779170 I [24463/24463] CoreContext mythcontext.cpp:881 (TestDBconnection) - Start up testing connections. DB ns1, BE , attempt 0, status dbAwake, Delay: 2000
2020-11-01 11:00:34.791903 N [24463/24463] CoreContext mythcorecontext.cpp:1834 (InitLocale) - Setting QT default locale to en_GB
2020-11-01 11:00:34.791912 I [24463/24463] CoreContext mythcorecontext.cpp:1867 (SaveLocaleDefaults) - Current locale en_GB
2020-11-01 11:00:34.791951 N [24463/24463] CoreContext mythlocale.cpp:122 (LoadDefaultsFromXML) - Reading locale defaults from /opt/mythtv-20201031/share/mythtv//locales/en_gb.xml
2020-11-01 11:00:34.809833 I [24463/24463] CoreContext platforms/mythpowerdbus.cpp:537 (AcquireLock) - PowerDBus: Failed to delay sleep,shutdown: Permission denied
2020-11-01 11:00:34.811842 I [24463/24463] CoreContext platforms/mythpowerdbus.cpp:366 (DeviceAdded) - PowerDBus: Added UPower.Device '/org/freedesktop/UPower/devices/keyboard_hidpp_battery_0'
2020-11-01 11:00:34.811848 I [24463/24463] CoreContext mythpower.cpp:374 (PowerLevelChanged) - Power: Unknown power source
2020-11-01 11:00:34.812415 I [24463/24463] CoreContext platforms/mythpowerdbus.cpp:366 (DeviceAdded) - PowerDBus: Added UPower.Device '/org/freedesktop/UPower/devices/mouse_hidpp_battery_1'
2020-11-01 11:00:34.828712 I [24463/24463] CoreContext mythpower.cpp:131 (Init) - Power: Supported actions: None
2020-11-01 11:00:34.829529 I [24463/24463] CoreContext mythtranslation.cpp:64 (load) - Loading en_gb translation for module mythfrontend
2020-11-01 11:00:34.831920 I [24463/24463] CoreContext schemawizard.cpp:119 (Compare) - Current MythTV Schema Version (DBSchemaVer): 1366
2020-11-01 11:00:34.832143 I [24463/24463] CoreContext mythtranslation.cpp:64 (load) - Loading en_gb translation for module mythfrontend
2020-11-01 11:00:34.832975 N [24463/24463] CoreContext main_helpers.cpp:620 (run_backend) - MythBackend: Starting up as the master server.
2020-11-01 11:00:36.227073 I [24463/24463] CoreContext cardutil.cpp:1178 (SetDeliverySystem) - CardUtil[1]: Set delivery system: DVB-T2
bib1963 commented 3 years ago

And it is also failing to record from a schedule. Live tv is okay.

bennettpeter commented 3 years ago

I just built latest master and started it with no problem, on my existing master database. What do you mean by "with new database" ? If you are setting up from scratch with a new database you have to first run mythtv-setup and set up the ip addresses, capture cards etc. Are you trying to run mythbackend before doing that?

bib1963 commented 3 years ago

Peter, I am not a newbie. I've picked up a lot of bugs in the past.

The point I was making about a new database, is that it was clean, yes, I did run mythtv-setup.

If you had looked at the log output properly, you would have seen things had been configured.

What I am finding is that starting up the backend, occasionally finds that the not all cards are opened, and none of the listening ports are either.

To me, it looks like the threads are not syncing properly. It looks like there is a deadlock happening, since when trying to shut it down when this happens, also fails.

bennettpeter commented 3 years ago

I just created a new database, ran mythtv-setup, set up ip address, added one storage directory for Default. Exited mythtv-setup and started mythbackend with your command, and not under root: mythbackend -d --noupnp -p /tmp/.mythbackend.pid --logpath /tmp https://pastebin.com/0wW0KLQa It runs fine. It did try to run mythfilldatabase, which failed as I had not set it up. Started mythfrontend - works fine.