Scheduler logs "Error preparing query" and does not auto-recover

[JanCeuleers]

mythbackend.log

• Platform: Ubuntu 20.04

• MythTV version: v31.0+fixes

• Package version: v31.0+fixes.202105172232.f8c59ee69d~ubuntu20.04.1

• Component: Backend (scheduler)

Multiple users, including myself, are reporting on the users mailing list that recordings are failing at unpredictable times. It is unclear what triggers this condition. Symptoms include:

• Scheduled recordings do not occur.
• The list of upcoming recordings is empty.
• The scheduler logs "Error preparing query", and does not recover its database connection.
• Running mythutil --resched does NOT cause the backend to recover.
• Restarting the backend does recover from this issue (until it next occurs, which might be hours or days later).

I attach multiple days' worth of logs, since I don't know how to select a sensible subset. You can find occurrences of the issue by searching for "Error preparing query", noting that the first hit is NOT an example of this issue because in this instance the backend does manage to reestablish its database connection.

[billmeek]

The cause (at least for MySQL) is a new error code introduced in 8.0.24. The existing logic
in libs/libmythbase/mythdbcon.cpp didn't automatically reconnect to the server.

https://dev.mysql.com/doc/mysql-errors/8.0/en/server-error-reference.html

  Error number: 4031; Symbol: ER_CLIENT_INTERACTION_TIMEOUT; SQLSTATE: HY000

  Message: The client was disconnected by the server because of inactivity. See wait_timeout
  and interactive_timeout for configuring this behavior.

  ER_CLIENT_INTERACTION_TIMEOUT was added in 8.0.24.

Until the fix is released, increasing the default 8 hour wait_timeout is a known workaround
From users on the Forum.

[mysqld]
wait_timeout = 172800

The 4031 error code has a different meaning in MariaDB. Open issue for MythTV:
https://mariadb.com/kb/en/mariadb-error-codes

[JanCeuleers]

I just found out that this issue does not only affect the backend as I initially reported, but also the frontend. That is: I just came back to a frontend that had been left running idle for many hours, and it could not find any recordings. Restarting the frontend recovered from this situation.

The frontend's logfile also contains the signature "Error preparing query" lines.

Once again I attach an unfiltered mythfrontend.log -- as I said you can find an occurrence of this issue by searching for "Error preparing query".
mythfrontend.log

[mtraxiot]

I also have the same issue, let me know if you need any more examples:
as above to recover , I need to restart backend service almost every other day.

E Scheduler mythdbcon.cpp:843 (prepare) Error preparing query: DELETE recordmatch FROM recordmatch, channel WHERE recordmatch.chanid = channel.chanid
E Scheduler mythdbcon.cpp:845 (prepare) Driver error was [2/0]:#012QMYSQL3: Unable to prepare statement#012Database error was:#12

[xipmix]

Another data point.
I updated my mariadb server to use the longer timeout, and restarted it.
However I neglected to restart mythtv-backend.service as well.
This caused the mythtv-status service to stop, and errors to appear like

mythbackend[1025679]: E HttpServer64 mythdbcon.cpp:843 (prepare) Error preparing query: SELECT data FROM settings WHERE value = :KEY AND hostname ...

I restarted the backend, and mythtv-status. and things seemed to come good again.
Versions

• Ubuntu 20.04.2 LTS amd64
• libmysqlclient21 8.0.25-0ubuntu0.20.04.1
• mariadb-client-core-10.3 1:10.3.29-0ubuntu0.20.04.1
• mariadb-server 1:10.3.29-0ubuntu0.20.04.1.

mythtv 2:31.0+fixes.202105172232.f8c59ee69d~ubuntu20.04.1