[Solved] Backend cannot start normally because Database Schema Update failed

[nwwoods]

I have a clean install of Ubuntu 24.04 to which I added MythTV Backend Setup and have the same issue reported a couple of other times - as the subject lines says - Backend cannot start normally because Database Schema Update failed.

I can get to the backend setup on port 6544 and it takes me to the Setupdb page where this error is reported. It is successfully connected to the database and mythconverg is there but schema version is 1379 which the mythbackend log suggests is around 72 versions old.

Below is mythbackend.log from the last attempt. Sorry if I am not posting in the right way.
Some of the same observations as the other thread --

• * it seems to be thinking it is a slave backend. It is specified as 127.0.0.1 and the Master Backend is checked on the General tab under Host Address backend setup, so I am perplexed why it thinks it is a slave.
  * I presume this is why it cannot upgrade the database.
  * Hostname is HVmedia and is there in matching case in all places I can find it.
  * I tried the clearing of cache suggested in the other thread, there was no cache to clear.
  * I tried uninstalling and reinstalling, no difference.

I've been a MythTV user for many years but never ran into this before.

Code: Select all

2024-11-21T16:02:22.743373-07:00 HVmedia mythbackend: mythbackend[1294321]: N CoreContext mythbackend_main_helpers.cpp:849 (run_setup_webserver) MythBackend Web App only mode exiting
2024-11-21T16:02:22.743567-07:00 HVmedia mythbackend: mythbackend[1294321]: I CoreContext bonjourregister.cpp:32 (~BonjourRegister) Bonjour: De-registering service '_http._tcp.' on 'mythbackend on HVmedia'
2024-11-21T16:02:22.743625-07:00 HVmedia mythbackend: mythbackend[1294321]: I CoreContext mythbackend.cpp:176 (main) Restarting mythbackend
2024-11-21T16:02:22.849769-07:00 HVmedia mythbackend: mythbackend[1294321]: C thread_unknown mythcommandlineparser.cpp:2904 (ConfigureLogging) mythbackend version: fixes/34 [v34.0+fixes.20240210.e3e165a1-0ubuntu6] wwwdotmythtvdotorg
2024-11-21T16:02:22.849881-07:00 HVmedia mythbackend: mythbackend[1294321]: C thread_unknown mythcommandlineparser.cpp:2908 (ConfigureLogging) Qt version: compile: 5.15.12, runtime: 5.15.13
2024-11-21T16:02:22.849915-07:00 HVmedia mythbackend: mythbackend[1294321]: I thread_unknown mythcommandlineparser.cpp:2910 (ConfigureLogging) Ubuntu 24.04.1 LTS (x86_64)
2024-11-21T16:02:22.849967-07:00 HVmedia mythbackend: mythbackend[1294321]: N thread_unknown mythcommandlineparser.cpp:2912 (ConfigureLogging) Enabled verbose msgs:  general
2024-11-21T16:02:22.850006-07:00 HVmedia mythbackend: mythbackend[1294321]: N thread_unknown logging.cpp:644 (logStart) Setting Log Level to LOG_INFO
2024-11-21T16:02:22.850045-07:00 HVmedia mythbackend: mythbackend[1294321]: I Logger logging.cpp:262 (run) Added logging to the console
2024-11-21T16:02:22.949915-07:00 HVmedia mythbackend: mythbackend[1294321]: I LogForward loggingserver.cpp:217 (SyslogLogger) Added syslogging
2024-11-21T16:02:22.950021-07:00 HVmedia mythbackend: mythbackend[1294321]: I thread_unknown signalhandling.cpp:183 (SetHandlerPrivate) Setup Interrupt handler
2024-11-21T16:02:22.950075-07:00 HVmedia mythbackend: mythbackend[1294321]: I thread_unknown signalhandling.cpp:183 (SetHandlerPrivate) Setup Terminated handler
2024-11-21T16:02:22.950120-07:00 HVmedia mythbackend: mythbackend[1294321]: I thread_unknown signalhandling.cpp:183 (SetHandlerPrivate) Setup Segmentation fault handler
2024-11-21T16:02:22.950149-07:00 HVmedia mythbackend: mythbackend[1294321]: I thread_unknown signalhandling.cpp:183 (SetHandlerPrivate) Setup Aborted handler
2024-11-21T16:02:22.950184-07:00 HVmedia mythbackend: mythbackend[1294321]: I thread_unknown signalhandling.cpp:183 (SetHandlerPrivate) Setup Floating point exception handler
2024-11-21T16:02:22.950217-07:00 HVmedia mythbackend: mythbackend[1294321]: I thread_unknown signalhandling.cpp:183 (SetHandlerPrivate) Setup Illegal instruction handler
2024-11-21T16:02:22.950250-07:00 HVmedia mythbackend: mythbackend[1294321]: I thread_unknown signalhandling.cpp:183 (SetHandlerPrivate) Setup Bus error handler
2024-11-21T16:02:22.950281-07:00 HVmedia mythbackend: mythbackend[1294321]: I thread_unknown signalhandling.cpp:183 (SetHandlerPrivate) Setup Real-time signal 0 handler
2024-11-21T16:02:22.950321-07:00 HVmedia mythbackend: mythbackend[1294321]: I thread_unknown signalhandling.cpp:183 (SetHandlerPrivate) Setup Hangup handler
2024-11-21T16:02:22.950350-07:00 HVmedia mythbackend: mythbackend[1294321]: N thread_unknown mythdirs.cpp:234 (InitializeMythDirs) Using runtime prefix = /usr
2024-11-21T16:02:22.950392-07:00 HVmedia mythbackend: mythbackend[1294321]: N thread_unknown mythdirs.cpp:235 (InitializeMythDirs) Using configuration directory = /home/mythtv/.mythtv
2024-11-21T16:02:22.950427-07:00 HVmedia mythbackend: mythbackend[1294321]: I CoreContext mythcorecontext.cpp:264 (Init) Assumed character encoding: en_US.UTF-8
2024-11-21T16:02:22.950459-07:00 HVmedia mythbackend: mythbackend[1294321]: I CoreContext mythcontext.cpp:595 (LoadDatabaseSettings) Empty LocalHostName. This is typical.
2024-11-21T16:02:22.950492-07:00 HVmedia mythbackend: mythbackend[1294321]: I CoreContext mythcontext.cpp:650 (LoadDatabaseSettings) Using a profile name of: 'HVmedia' (Usually the same as this host's name.)
2024-11-21T16:02:22.950529-07:00 HVmedia mythbackend: mythbackend[1294321]: I CoreContext mythcontext.cpp:891 (TestDBconnection) Start up testing connections. DB localhost, BE , attempt 0, status dbAwake, Delay: 2000
2024-11-21T16:02:23.950948-07:00 HVmedia mythbackend: mythbackend[1294321]: N CoreContext mythcorecontext.cpp:1825 (InitLocale) Setting QT default locale to en_US
2024-11-21T16:02:23.951116-07:00 HVmedia mythbackend: mythbackend[1294321]: I CoreContext mythcorecontext.cpp:1858 (SaveLocaleDefaults) Current locale en_US
2024-11-21T16:02:23.951165-07:00 HVmedia mythbackend: mythbackend[1294321]: N CoreContext mythlocale.cpp:120 (LoadDefaultsFromXML) Reading locale defaults from /usr/share/mythtv//locales/en_us.xml
2024-11-21T16:02:23.951214-07:00 HVmedia mythbackend: mythbackend[1294321]: I CoreContext mythpowerdbus.cpp:544 (AcquireLock) PowerDBus: Failed to delay sleep,shutdown: Permission denied
2024-11-21T16:02:23.951252-07:00 HVmedia mythbackend: mythbackend[1294321]: I CoreContext mythpowerdbus.cpp:372 (DeviceAdded) PowerDBus: Added UPower.Device '/org/freedesktop/UPower/devices/battery_hidpp_battery_0'
2024-11-21T16:02:23.951293-07:00 HVmedia mythbackend: mythbackend[1294321]: I CoreContext mythpower.cpp:354 (PowerLevelChanged) Power: On AC power
2024-11-21T16:02:23.951335-07:00 HVmedia mythbackend: mythbackend[1294321]: I CoreContext mythpower.cpp:136 (Init) Power: Supported actions: None
2024-11-21T16:02:23.951372-07:00 HVmedia mythbackend: mythbackend[1294321]: I CoreContext mythtranslation.cpp:62 (load) Loading en_us translation for module mythfrontend
2024-11-21T16:02:23.951403-07:00 HVmedia mythbackend: mythbackend[1294321]: I CoreContext schemawizard.cpp:117 (Compare) Current MythTV Schema Version (DBSchemaVer): 1307
2024-11-21T16:02:23.951437-07:00 HVmedia mythbackend: mythbackend[1294321]: W CoreContext dbcheck.cpp:400 (UpgradeTVDatabaseSchema) Not allowed to upgrade the database.
2024-11-21T16:02:23.951484-07:00 HVmedia mythbackend: mythbackend[1294321]: I CoreContext schemawizard.cpp:296 (PromptForUpgrade) Console is non-interactive, can't prompt user...
2024-11-21T16:02:23.951520-07:00 HVmedia mythbackend: mythbackend[1294321]: E CoreContext mythbackend_main_helpers.cpp:563 (run_backend) Couldn't upgrade database to new schema on slave backend.
2024-11-21T16:02:23.951563-07:00 HVmedia mythbackend: mythbackend[1294321]: N CoreContext mythbackend_main_helpers.cpp:799 (run_setup_webserver) ***********************************************************************
2024-11-21T16:02:23.951599-07:00 HVmedia mythbackend: mythbackend[1294321]: N CoreContext mythbackend_main_helpers.cpp:800 (run_setup_webserver) ***** MythBackend starting in Web App only mode for initial setup *****
2024-11-21T16:02:23.951638-07:00 HVmedia mythbackend: mythbackend[1294321]: N CoreContext mythbackend_main_helpers.cpp:801 (run_setup_webserver) ***** Use http://<yourBackend>:6544 to perform setup              *****
2024-11-21T16:02:23.951673-07:00 HVmedia mythbackend: mythbackend[1294321]: N CoreContext mythbackend_main_helpers.cpp:802 (run_setup_webserver) ***********************************************************************
2024-11-21T16:02:23.951709-07:00 HVmedia mythbackend: mythbackend[1294321]: I CoreContext mythhttpthreadpool.cpp:16 (MythHTTPThreadPool) HTTPPool: Using maximum 8 threads
2024-11-21T16:02:23.951747-07:00 HVmedia mythbackend: mythbackend[1294321]: W HTTPServer mythhttps.cpp:56 (InitSSLServer) SSL: SSL Host key file (/home/mythtv/.mythtv/certificates/key.pem) does not exist or is not readable
2024-11-21T16:02:24.050865-07:00 HVmedia mythbackend: mythbackend[1294321]: I HTTPServer mythcorecontext.cpp:461 (ConnectCommandSocket) MythCoreContext::ConnectCommandSocket(): Connecting to backend server: 127.0.0.1:6543 (try 1 of 1)
2024-11-21T16:02:24.050946-07:00 HVmedia mythbackend: mythbackend[1294321]: E MythSocketThread(-1) mythsocket.cpp:681 (ConnectToHostReal) MythSocket(749b9400ad30:-1): Failed to connect to (127.0.0.1:6543) Connection refused
2024-11-21T16:02:24.051011-07:00 HVmedia mythbackend: mythbackend[1294321]: E HTTPServer mythcorecontext.cpp:529 (ConnectCommandSocket) Connection to master server timed out.#012#011#011#011Either the server is down or the master server settings#012#011#011#011in mythtv-settings does not contain the proper IP address
2024-11-21T16:02:24.051079-07:00 HVmedia mythbackend: mythbackend[1294321]: I HTTPServer serverpool.cpp:417 (listen) Listening on TCP 0.0.0.0:6544
2024-11-21T16:02:24.051121-07:00 HVmedia mythbackend: mythbackend[1294321]: I HTTPServer serverpool.cpp:417 (listen) Listening on TCP [::]:6544
2024-11-21T16:02:24.051163-07:00 HVmedia mythbackend: mythbackend[1294321]: I HTTPServer serverpool.cpp:417 (listen) Listening on TCP 0.0.0.0:6744
2024-11-21T16:02:24.051202-07:00 HVmedia mythbackend: mythbackend[1294321]: I HTTPServer serverpool.cpp:417 (listen) Listening on TCP [::]:6744
2024-11-21T16:02:24.752138-07:00 HVmedia mythbackend: mythbackend[1294321]: I HTTP0 mythhttpmetaservice.cpp:126 (MythHTTPMetaService) Service '/services/' introspection complete
2024-11-21T16:02:24.752288-07:00 HVmedia mythbackend: mythbackend[1294321]: I HTTP0 mythhttpmetaservice.cpp:126 (MythHTTPMetaService) Service 'Myth' introspection complete
2024-11-21T16:02:24.752342-07:00 HVmedia mythbackend: mythbackend[1294321]: I HTTP0 mythhttpmetaservice.cpp:126 (MythHTTPMetaService) Service 'Config' introspection complete
2024-11-21T16:02:24.952569-07:00 HVmedia mythbackend: mythbackend[1294321]: I HTTPServer bonjourregister.cpp:116 (BonjourCallback) Bonjour: Service registration complete: name 'mythbackend on HVmedia' type '_http._tcp.' domain: 'local.'
2024-11-21T16:02:29.759145-07:00 HVmedia mythbackend: mythbackend[1294321]: I HTTP2 mythhttpmetaservice.cpp:126 (MythHTTPMetaService) Service 'Dvr' introspection complete

[nwwoods]

Full settings table. I do notice in some table entries the hostname is fully lowercased and others it is mixed case, thought the lowercased all seem to be for date & time formats.

Code: Select all

+-------------------------------+----------------+----------+
| value                         | LEFT(data, 40) | hostname |
+-------------------------------+----------------+----------+
| Country                       | US             | NULL     |
| DataDirectMessage             |                | NULL     |
| DBSchemaVer                   | 1307           | NULL     |
| DefaultTranscoder             | 0              | NULL     |
| FreqTable                     | us-bcast       | NULL     |
| HaveRepeats                   | 0              | NULL     |
| ISO639Language0               | eng            | NULL     |
| ISO639Language1               | eng            | NULL     |
| Language                      | en_US          | NULL     |
| MasterServerName              | HVmedia        | NULL     |
| mythfilldatabaseLastRunEnd    |                | NULL     |
| mythfilldatabaseLastRunStart  |                | NULL     |
| mythfilldatabaseLastRunStatus |                | NULL     |
| TVFormat                      | NTSC           | NULL     |
| VbiFormat                     | None           | NULL     |
| AllowConnFromAll              | 0              | HVmedia  |
| AllowLinkLocal                | 0              | HVmedia  |
| BackendServerAddr             | 127.0.0.1      | HVmedia  |
| BackendServerIP               |                | HVmedia  |
| BackendServerIP6              |                | HVmedia  |
| BackendServerPort             | 6543           | HVmedia  |
| BackendStatusPort             | 6544           | HVmedia  |
| DateFormat                    | ddd MMM d yyyy | hvmedia  |
| ListenOnAllIps                | 1              | HVmedia  |
| MythArchiveDateFormat         | %a %b %d %Y    | hvmedia  |
| MythArchiveTimeFormat         | %I:%M %p       | hvmedia  |
| MythArchiveVideoFormat        | NTSC           | hvmedia  |
| SecurityPin                   | 0000           | HVmedia  |
| ShortDateFormat               | M/d            | hvmedia  |
| TimeFormat                    | h:mm AP        | hvmedia  |
+-------------------------------+----------------+----------+

[nwwoods]

If I run mythbackend as mythfilldatabase suggests, I get the following:

Code: Select all

024-11-21 17:46:53.872497 N  Setting QT default locale to en_US
2024-11-21 17:46:53.872505 I  Current locale en_US
2024-11-21 17:46:53.872547 N  Reading locale defaults from /usr/share/mythtv//locales/en_us.xml
2024-11-21 17:46:53.887380 I  PowerDBus: Added UPower.Device '/org/freedesktop/UPower/devices/battery_hidpp_battery_0'
2024-11-21 17:46:53.888496 I  Power: On AC power
2024-11-21 17:46:53.898640 I  Power: Supported actions: Suspend,Restart,Shutdown
2024-11-21 17:46:53.899476 I  Loading en_us translation for module mythfrontend
2024-11-21 17:46:53.901809 I  Current MythTV Schema Version (DBSchemaVer): 1307
2024-11-21 17:46:53.901823 W  Not allowed to upgrade the database.
2024-11-21 17:46:53.903330 E  Couldn't upgrade database to new schema on slave backend.
2024-11-21 17:46:53.903333 N  ***********************************************************************
2024-11-21 17:46:53.903334 N  ***** MythBackend starting in Web App only mode for initial setup *****
2024-11-21 17:46:53.903335 N  ***** Use http://<yourBackend>:6544 to perform setup              *****
2024-11-21 17:46:53.903335 N  ***********************************************************************
2024-11-21 17:46:53.903390 I  HTTPPool: Using maximum 8 threads
2024-11-21 17:46:53.922276 W  SSL: SSL Host key file (/home/mythtv/.mythtv/certificates/key.pem) does not exist or is not readable
2024-11-21 17:46:53.925476 I  MythCoreContext::ConnectCommandSocket(): Connecting to backend server: 127.0.0.1:6543 (try 1 of 1)
2024-11-21 17:46:53.926043 E  MythSocket(78255c00ab70:-1): Failed to connect to (127.0.0.1:6543) Connection refused
2024-11-21 17:46:53.926162 E  Connection to master server timed out.
			Either the server is down or the master server settings
			in mythtv-settings does not contain the proper IP address

2024-11-21 17:46:53.927505 E  Failed listening on TCP 0.0.0.0:6544 - Error 8: The bound address is already in use
2024-11-21 17:46:53.927534 E  Failed listening on TCP 0.0.0.0:6744 - Error 8: The bound address is already in use
^C2024-11-21 17:47:29.320106 C  Received Interrupt: Code 128, PID 0, UID 0, Value 0x00000000
2024-11-21 17:47:29.320122 N  MythBackend Web App only mode exiting
2024-11-21 17:47:29.321290 I  PowerDBus: Closing interfaces
2024-11-21 17:47:29.322681 I  Exiting

[bill6502]

Try adding these:

Code: Select all

curl --header Accept:Application/json --data Key=BackendServerIP --data Value=127.0.0.1 --data HostName=HVmedia localhost:6544/Myth/PutSetting
curl --header Accept:Application/json --data Key=MasterServerIP --data Value=127.0.0.1 --data HostName=_GLOBAL_ localhost:6544/Myth/PutSetting

The old way of determining if a BE was a Master was to compare the MasterServerIP and BackendServerIP
or ...IP6.

Restart the BE, see if it updates or reports an error.

[nwwoods]

Thank you, yes, the BE updated and I moved to the other setup tabs.

Now I am stuck on configuring the grabber. I have been using the Schedules Direct JSON API and set it accordingly, but the tv_grab command it generates seems to have a bad filespec for the temp file?

Code: Select all

$ sudo -u mythtv tv_grab_zz_sdjson --configure --config-file "null/PHX.xmltv"
Failed to write to null/PHX.xmltv.TMP at /usr/share/perl5/XMLTV/Configure.pm line 187.

[nwwoods]

I should add that I got the capture card configured and have successfully scanned channels and setup a default storage group. I can bring up the frontend and tune channels, get audio, etc. So except for the program guide I think I am there.

[nwwoods]

I got the grabber configured by deleting "null/" from the filespec and looks like I got a good .xmltv file (PHX.xmltv).

I see it needs to be in the .mythtv directory in order for mythfilldatabase to work. ok. I think I remember running into this before. One does this so infrequently it is hard to recall.

[nwwoods]

Looks like this is now solved.

[pgbennett]

I have created an issue over the null directory prompt
https://github.com/MythTV/mythtv/issues/976