[PATCH] libmythdb: Fix 5 second pause on mythfrontend exit

[lvr@…]

This works around the 5 second delay on exit caused by Qt checking which threads opened a mysql connection but did not close one.

Only pool mysql connections created my the UI thread.

The pool is freed by the cleanup guard which executes on the main thread. Therefore any pooled mysql connection made by a different thread will trigger the problem. For instance, ImageLoadThread? calls MythUIImage::LoadImage? which in turn needs the theme directory name from the settings database. Multiple images are loaded during statup, each creating a parallel mysql connection, which are then pooled when the thread exits. At exit, Qt complains after all mysql connections are closed that the ImageLoadThreads? didn't close their mysql connection.

[danielk]

The patch isn't correct, these pooled connections should have already been cleaned up when the cleanup guard executes and the the wait and error message indicates that there is some thread that isn't calling MThread::RunEpilog?().

Please attach a mythfrontend log when this issue occurs, we should be printing out the names of threads that aren't shut down properly.

[lvr@…]

The following log is from yesterdays git fixes/0.24 mythfrontend with a small patch to output the name of the thread that opened the DB connections. Notice the 5 second pause while deleting the last pooled connection.

NB this bug report doesn't apply to git master, only to fixes/0.24 which doesn't have MThread.

2012-01-12 12:56:19.989 Deleting UPnP client...
2012-01-12 12:56:19.990 UPnp - Destructor
2012-01-12 12:56:19.990 UPnp::CleanUp() - disabling SSDP notifications
2012-01-12 12:56:20.530 UPnp::CleanUp() - deleted SSDP
2012-01-12 12:56:20.604 Deleting gContext...
2012-01-12 12:56:20.605 MythSocket(852b388:46): DownRef: -1
2012-01-12 12:56:20.605 MythSocket(852b388:46): state change Connected -> Idle
2012-01-12 12:56:20.605 MythSocket(852b388:-1): delete socket
2012-01-12 12:56:20.605 MythSocket(853c3a0:47): DownRef: 0
2012-01-12 12:56:20.605 ~MDBManager deleting pool connection opened by main
2012-01-12 12:56:20.605 ~MDBManager deletied pool connection
2012-01-12 12:56:20.605 ~MDBManager deleting pool connection opened by ImageLoadThread shared/4_stars.png
2012-01-12 12:56:20.605 ~MDBManager deletied pool connection
2012-01-12 12:56:20.605 ~MDBManager deleting pool connection opened by ImageLoadThread shared/9_stars.png
2012-01-12 12:56:20.605 ~MDBManager deletied pool connection
2012-01-12 12:56:20.605 ~MDBManager deleting pool connection opened by ImageLoadThread shared/2_stars.png
2012-01-12 12:56:20.605 ~MDBManager deletied pool connection
2012-01-12 12:56:20.605 ~MDBManager deleting pool connection opened by ImageLoadThread shared/5_stars.png
Error in my_thread_global_end(): 3 threads didn't exit
2012-01-12 12:56:25.605 ~MDBManager deletied pool connection
2012-01-12 12:56:25.607 Deleted gContext.
2012-01-12 12:56:25.620 MythSocketThread: readyread thread exit

This is the patch to print the thread names:

diff --git a/mythtv/libs/libmythdb/mythdbcon.cpp b/mythtv/libs/libmythdb/mythdbcon.cpp
index aa7c231..14ba232 100644
--- a/mythtv/libs/libmythdb/mythdbcon.cpp
+++ b/mythtv/libs/libmythdb/mythdbcon.cpp
@@ -8,6 +8,7 @@
 #include <QSqlError>
 #include <QSqlField>
 #include <QSqlRecord>
+#include <QThread>
 
 // MythTV
 #include "compat.h"
@@ -115,6 +116,7 @@ bool MSqlDatabase::OpenDatabase()
         }
         if (connected)
         {
+            m_owner = QThread::currentThread()->objectName();
             VERBOSE(VB_GENERAL,
                     QString("Connected to database '%1' at host: %2")
                             .arg(m_db.databaseName()).arg(m_db.hostName()));
@@ -235,7 +237,12 @@ MDBManager::MDBManager()
 MDBManager::~MDBManager()
 {
     while (!m_pool.isEmpty())
-        delete m_pool.takeFirst();
+    {
+        MSqlDatabase *db = m_pool.takeFirst();
+        VERBOSE(VB_IMPORTANT, "~MDBManager deleting pool connection opened by " + db->m_owner);
+        delete db;
+        VERBOSE(VB_IMPORTANT, "~MDBManager deletied pool connection");
+    }
     delete m_sem;
 
     delete m_schedCon;
diff --git a/mythtv/libs/libmythdb/mythdbcon.h b/mythtv/libs/libmythdb/mythdbcon.h
index 8bc921d..aada908 100644
--- a/mythtv/libs/libmythdb/mythdbcon.h
+++ b/mythtv/libs/libmythdb/mythdbcon.h
@@ -34,6 +34,7 @@ class MPUBLIC MSqlDatabase
     QString m_name;
     QSqlDatabase m_db;
     QDateTime m_lastDBKick;
+    QString m_owner;
 };
 
 /// \brief DB connection pool, used by MSqlQuery. Do not use directly.
diff --git a/mythtv/libs/libmythui/mythuiimage.cpp b/mythtv/libs/libmythui/mythuiimage.cpp
index 3ffd4e6..4734c5d 100644
--- a/mythtv/libs/libmythui/mythuiimage.cpp
+++ b/mythtv/libs/libmythui/mythuiimage.cpp
@@ -84,6 +84,7 @@ class ImageLoadThread : public QRunnable
 
     void run()
     {
+        QThread::currentThread()->setObjectName("ImageLoadThread " + m_filename);
         QString tmpFilename;
         if (!(m_filename.startsWith("myth://")))
             tmpFilename = m_filename;
diff --git a/mythtv/programs/mythfrontend/main.cpp b/mythtv/programs/mythfrontend/main.cpp
index 0335dda..0aa2112 100644
--- a/mythtv/programs/mythfrontend/main.cpp
+++ b/mythtv/programs/mythfrontend/main.cpp
@@ -155,8 +155,10 @@ namespace
             g_pUPnp = NULL;
         }
 
+        VERBOSE(VB_GENERAL, "Deleting gContext...");
         delete gContext;
         gContext = NULL;
+        VERBOSE(VB_GENERAL, "Deleted gContext.");
 
         signal(SIGHUP, SIG_DFL);
         signal(SIGUSR1, SIG_DFL);
@@ -1071,6 +1073,7 @@ static void log_rotate_handler(int)
 
 int main(int argc, char **argv)
 {
+    QThread::currentThread()->setObjectName("main");
     bool bPromptForBackend    = false;
     bool bBypassAutoDiscovery = false;
     bool upgradeAllowed = false;

[sphery]

FWIW, the DB-driver-using code has been completely reworked in master to use a per-thread connection pool. IMHO, it's not worth messing with 0.24-fixes to try implement a hack that yields the same result as the fix in master--especially since DB code is so critical to MythTV's operation. This seems like a "closed/fixed" (in master) ticket to me. The MThread::RunEpilog?() danielk mentioned is actually part of the restructuring, but this ticket/patch seems to be for 0.24-fixes, only, right?

Ref 42626b12b and b008d6122 , among others.

[Lawrence Rust <lvr@…>]

This is a pretty trivial change that improves the user experience for 0.24 users, especially when exiting the FE to the mythwelcome screen or during shutdown.

True, it's fixed in master but then production systems aren't generally in a position to run master yet.

[danielk]

I didn't realise this was a ticket against 0.24-fixes. This is a problem fixed in master and the proposed solution for 0.24 is could cause more serious problems than the slow shutdown of mfe with newer versions of Qt.