Seite 1 von 1

QMYSQL Plugin & Threads

Verfasst: 20. Februar 2008 13:06
von bjoernt
Hallo,

ich arbeite seit kurzem und sehr gerne ;-) mit QT.
Jedoch habe ich ein QThread <-> QMysql Problem (Vermutung),
das plötzlich innerhalb eines Threads keine Queries abgesetzt werden können.
Vorweg, die Mysql Connection wird im aktuellen Thread erzeugt und von diesem Thread (dispatcher) gibt es auch nur einen.
Connection sharing wird nicht genutzt (eh verboten)

Kurz zum System.
Es gibt einen Serverteil der alle Threads erstellt (RMSServer) und die QConnections einrichtet. Die Thread sprechen untereinander mit Signalen (queued).
Grundlegend funktioniert alles bis plötzlich die SQL Queries nicht mehr gehen.

Wenn kann mit helfen?


Problem :

[20.02.2008 12:32:42.764]
[20.02.2008 12:32:42.765] RMSServer: BuildWorker #0 gets Task ID 9
[20.02.2008 12:32:42.765]
[20.02.2008 12:32:42.770]
[20.02.2008 12:32:42.770]
[20.02.2008 12:32:42.773] Dispatcher: Task with ID 8 as valid task queued.
[20.02.2008 12:32:42.773]
[20.02.2008 12:32:42.774] Dispatcher: *** Received Task object ***
[20.02.2008 12:32:42.774] Dispatcher: Task->ID : 8
[20.02.2008 12:32:42.774] Dispatcher: Task->Type : build
[20.02.2008 12:32:42.774] Dispatcher: Task->Status : queued
[20.02.2008 12:32:42.774] Dispatcher: Task->Log : nolog
[20.02.2008 12:32:42.774]
[20.02.2008 12:32:42.774]
[20.02.2008 12:32:42.775] Dispatcher: Available BuildWorker: 0
[20.02.2008 12:32:42.776] Dispatcher: Available DatabaseWorker: 2
[20.02.2008 12:32:42.776]
[20.02.2008 12:32:42.777] RMSServer: *** Received Task object ***
[20.02.2008 12:32:42.777] RMSServer: Task->ID : 8
[20.02.2008 12:32:42.777] RMSServer: Task->Type : build
[20.02.2008 12:32:42.777] RMSServer: Task->Status : queued
[20.02.2008 12:32:42.777] RMSServer: Task->Log : nolog
[20.02.2008 12:32:42.777]
[20.02.2008 12:32:42.777]
[20.02.2008 12:32:42.777] BuildWorker #1: Received task ID 8
[20.02.2008 12:32:42.777]
[20.02.2008 12:32:42.778] BuildWorker #1: *** Received Task object ***
[20.02.2008 12:32:42.778] BuildWorker #1: Task->ID : 8
[20.02.2008 12:32:42.778] BuildWorker #1: Task->Type : build
[20.02.2008 12:32:42.778] BuildWorker #1: Task->Status : queued
[20.02.2008 12:32:42.778] BuildWorker #1: Task->Log : nolog
[20.02.2008 12:32:42.778]
[20.02.2008 12:32:42.778]
[20.02.2008 12:32:42.779] RMSServer: BuildWorker #1 gets Task ID 8
[20.02.2008 12:32:42.779]
[20.02.2008 12:33:42.757] Dispatcher: *** Received Task object ***
[20.02.2008 12:33:42.757] Dispatcher: Task->ID : 9
[20.02.2008 12:33:42.757] Dispatcher: Task->Type : build
[20.02.2008 12:33:42.757] Dispatcher: Task->Status : progress
[20.02.2008 12:33:42.757] Dispatcher: Task->Log : nolog
[20.02.2008 12:33:42.757]
[20.02.2008 12:33:42.757]
[20.02.2008 12:33:42.787] Dispatcher: Waiting for new tasks..
[20.02.2008 12:33:42.787]
[20.02.2008 12:33:42.793] Dispatcher: *** Received Task object ***
[20.02.2008 12:33:42.793] Dispatcher: Task->ID : 8
[20.02.2008 12:33:42.793] Dispatcher: Task->Type : build
[20.02.2008 12:33:42.793] Dispatcher: Task->Status : progress
[20.02.2008 12:33:42.793] Dispatcher: Task->Log : nolog
[20.02.2008 12:33:42.793]
[20.02.2008 12:33:42.793]
[20.02.2008 12:33:42.794] BuildWorker #0: Task ID 9 executingBuildCMD(d:\projekte\dneu_head1\build.cmd)
[20.02.2008 12:33:42.794] BuildWorker #0: with arguments: SD3 DNEU_2_3PL7_6 DNEU_2_3PL7_6 2.3pl7.6
[20.02.2008 12:33:42.794]
[20.02.2008 12:33:42.796] BuildWorker #1: Task ID 8 executingBuildCMD(d:\projekte\dneu_head\build.cmd)
[20.02.2008 12:33:42.796] BuildWorker #1: with arguments: SD2 DNEU_2_3PL7_6 DNEU_2_3PL7_6 2.3pl7.6
[20.02.2008 12:33:42.796] Dispatcher: *** Received Task object ***
[20.02.2008 12:33:42.796]
[20.02.2008 12:33:42.796] Dispatcher: Task->ID : 9
[20.02.2008 12:33:42.796] Dispatcher: Task->Type : build
[20.02.2008 12:33:42.796] Dispatcher: Task->Status : build
[20.02.2008 12:33:42.796] Dispatcher: Task->Log : Start building 2.3pl7.6 on slot SD3
[20.02.2008 12:33:42.796]
[20.02.2008 12:33:42.796]
[20.02.2008 12:33:42.796]
[20.02.2008 12:33:42.797] Dispatcher: Received information for Task ID 9:
[20.02.2008 12:33:42.797] Start building 2.3pl7.6 on slot SD3
[20.02.2008 12:33:42.797]
[20.02.2008 12:33:42.798] Dispatcher: im running
[20.02.2008 12:33:42.798]
[20.02.2008 12:33:42.798] Dispatcher: current Db connection:qt_sql_default_connection
[20.02.2008 12:33:42.799] Dispatcher: current Db connection:connDispatcher
[20.02.2008 12:33:42.799] Dispatcher: logToDB: Got SQL Error:MySQL server has gone away QMYSQL: Unable to execute query
[20.02.2008 12:33:42.799]
[20.02.2008 12:33:42.800] Dispatcher: logToDB: SQL:
[20.02.2008 12:33:42.800] INSERT INTO log SET item ='task', changer='RMSServer', timestamp='1203507222', context='Received information for Task ID 9:
[20.02.2008 12:33:42.800] Start building 2\.3pl7\.6 on slot SD3
[20.02.2008 12:33:42.800] '
[20.02.2008 12:33:42.801]
[20.02.2008 12:33:42.801]
[20.02.2008 12:33:42.803] Dispatcher: *** Received Task object ***
[20.02.2008 12:33:42.803] Dispatcher: Task->ID : 8
[20.02.2008 12:33:42.803] Dispatcher: Task->Type : build
[20.02.2008 12:33:42.803] Dispatcher: Task->Status : build
[20.02.2008 12:33:42.803] Dispatcher: Task->Log : Start building 2.3pl7.6 on slot SD2
[20.02.2008 12:33:42.803]
[20.02.2008 12:33:42.803]
[20.02.2008 12:33:42.803]
[20.02.2008 12:33:42.804] Dispatcher: Received information for Task ID 8:
[20.02.2008 12:33:42.804] Start building 2.3pl7.6 on slot SD2
[20.02.2008 12:33:42.804]
[20.02.2008 12:33:42.805] Dispatcher: im running
[20.02.2008 12:33:42.805]
[20.02.2008 12:33:42.805] Dispatcher: current Db connection:qt_sql_default_connection
[20.02.2008 12:33:42.806] Dispatcher: current Db connection:connDispatcher
[20.02.2008 12:33:42.806] Dispatcher: logToDB: Got SQL Error:MySQL server has gone away QMYSQL: Unable to execute query
[20.02.2008 12:33:42.806]
[20.02.2008 12:33:42.807] Dispatcher: logToDB: SQL:
[20.02.2008 12:33:42.807] INSERT INTO log SET item ='task', changer='RMSServer', timestamp='1203507222', context='Received information for Task ID 8:
[20.02.2008 12:33:42.807] Start building 2\.3pl7\.6 on slot SD2
[20.02.2008 12:33:42.807] '
[20.02.2008 12:33:42.807]
[20.02.2008 12:33:42.807]
[20.02.2008 12:33:42.810] RMSServer: *** Received Task object ***
[20.02.2008 12:33:42.810] RMSServer: Task->ID : 9
[20.02.2008 12:33:42.810] RMSServer: Task->Type : build
[20.02.2008 12:33:42.810] RMSServer: Task->Status : canceled
[20.02.2008 12:33:42.810] RMSServer: Task->Log : Build for verson 2.3pl7.6 on slot SD3 could not be executed. Aborting.
[20.02.2008 12:33:42.810]
[20.02.2008 12:33:42.810]
[20.02.2008 12:33:42.810]
[20.02.2008 12:33:42.810]
[20.02.2008 12:33:42.811] RMSServer: Removed Task ID 9
[20.02.2008 12:33:42.811]
[20.02.2008 12:33:42.812] RMSServer: *** Received Task object ***
[20.02.2008 12:33:42.812] RMSServer: Task->ID : 8
[20.02.2008 12:33:42.812] RMSServer: Task->Type : build
[20.02.2008 12:33:42.812] RMSServer: Task->Status : canceled
[20.02.2008 12:33:42.812] RMSServer: Task->Log : Build for verson 2.3pl7.6 on slot SD2 could not be executed. Aborting.
[20.02.2008 12:33:42.812]
[20.02.2008 12:33:42.812]
[20.02.2008 12:33:42.812]
[20.02.2008 12:33:42.812]
[20.02.2008 12:33:42.813] RMSServer: Removed Task ID 8
[20.02.2008 12:33:42.813]
[20.02.2008 12:33:42.814] Dispatcher: *** Received Task object ***
[20.02.2008 12:33:42.814] Dispatcher: Task->ID : 9
[20.02.2008 12:33:42.814] Dispatcher: Task->Type : build
[20.02.2008 12:33:42.814] Dispatcher: Task->Status : canceled
[20.02.2008 12:33:42.814] Dispatcher: Task->Log : Build for verson 2.3pl7.6 on slot SD3 could not be executed. Aborting.
[20.02.2008 12:33:42.814]
[20.02.2008 12:33:42.814]
[20.02.2008 12:33:42.814]
[20.02.2008 12:33:42.814]
[20.02.2008 12:33:42.815] Dispatcher: Received information for Task ID 9:
[20.02.2008 12:33:42.815] Build for verson 2.3pl7.6 on slot SD3 could not be executed. Aborting.
[20.02.2008 12:33:42.815]
[20.02.2008 12:33:42.815]
[20.02.2008 12:33:42.816] Dispatcher: im running
[20.02.2008 12:33:42.816]
[20.02.2008 12:33:42.816] Dispatcher: current Db connection:qt_sql_default_connection
[20.02.2008 12:33:42.816] Dispatcher: current Db connection:connDispatcher
[20.02.2008 12:33:42.817] Dispatcher: logToDB: Got SQL Error:MySQL server has gone away QMYSQL: Unable to execute query
[20.02.2008 12:33:42.817]
[20.02.2008 12:33:42.817] Dispatcher: logToDB: SQL:
[20.02.2008 12:33:42.817] INSERT INTO log SET item ='task', changer='RMSServer', timestamp='1203507224', context='Received information for Task ID 9:
[20.02.2008 12:33:42.817] Build for verson 2\.3pl7\.6 on slot SD3 could not be executed\. Aborting\.
[20.02.2008 12:33:42.817]
[20.02.2008 12:33:42.817] '
[20.02.2008 12:33:42.818]
[20.02.2008 12:33:42.818]
[20.02.2008 12:33:42.818] Dispatcher: Task ID 9 removed.
[20.02.2008 12:33:42.818]
[20.02.2008 12:33:42.819] Dispatcher: Available BuildWorker: 1
[20.02.2008 12:33:42.819] Dispatcher: Available DatabaseWorker: 2
[20.02.2008 12:33:42.819]
[20.02.2008 12:33:42.820] Dispatcher: *** Received Task object ***
[20.02.2008 12:33:42.820] Dispatcher: Task->ID : 8
[20.02.2008 12:33:42.820] Dispatcher: Task->Type : build
[20.02.2008 12:33:42.820] Dispatcher: Task->Status : canceled
[20.02.2008 12:33:42.820] Dispatcher: Task->Log : Build for verson 2.3pl7.6 on slot SD2 could not be executed. Aborting.
[20.02.2008 12:33:42.820]
[20.02.2008 12:33:42.820]
[20.02.2008 12:33:42.820]
[20.02.2008 12:33:42.820]
[20.02.2008 12:33:42.821] Dispatcher: Received information for Task ID 8:
[20.02.2008 12:33:42.821] Build for verson 2.3pl7.6 on slot SD2 could not be executed. Aborting.
[20.02.2008 12:33:42.821]
[20.02.2008 12:33:42.821]
[20.02.2008 12:33:42.822] Dispatcher: im running
[20.02.2008 12:33:42.822]
[20.02.2008 12:33:42.822] Dispatcher: current Db connection:qt_sql_default_connection
[20.02.2008 12:33:42.822] Dispatcher: current Db connection:connDispatcher
[20.02.2008 12:33:42.823] Dispatcher: logToDB: Got SQL Error:MySQL server has gone away QMYSQL: Unable to execute query
[20.02.2008 12:33:42.823]
[20.02.2008 12:33:42.823] Dispatcher: logToDB: SQL:
[20.02.2008 12:33:42.823] INSERT INTO log SET item ='task', changer='RMSServer', timestamp='1203507224', context='Received information for Task ID 8:
[20.02.2008 12:33:42.823] Build for verson 2\.3pl7\.6 on slot SD2 could not be executed\. Aborting\.
[20.02.2008 12:33:42.823]
[20.02.2008 12:33:42.823] '
[20.02.2008 12:33:42.824]
[20.02.2008 12:33:42.824]
[20.02.2008 12:33:42.824] Dispatcher: Task ID 8 removed.
[20.02.2008 12:33:42.824]
[20.02.2008 12:33:42.825] Dispatcher: Available BuildWorker: 2
[20.02.2008 12:33:42.825] Dispatcher: Available DatabaseWorker: 2
[20.02.2008 12:33:42.825]
[20.02.2008 12:34:42.800] Dispatcher: Waiting for new tasks..
[20.02.2008 12:34:42.800]
[20.02.2008 12:35:19.698] Dispatcher: Received shutdown...
[20.02.2008 12:35:19.698] BuildWorker #0: Received shutdown...
[20.02.2008 12:35:19.698] BuildWorker #1: Received shutdown...
[20.02.2008 12:35:19.699] BuildWorker #0: Wait thread...
[20.02.2008 12:35:42.833] BuildWorker #0: Shutdown.
[20.02.2008 12:35:42.834] BuildWorker #1: Wait thread...
[20.02.2008 12:35:42.836] BuildWorker #1: Shutdown.
[20.02.2008 12:35:42.837] Dispatcher: Quit.
[20.02.2008 12:35:42.837] RMSServer: Exit.

Verfasst: 20. Februar 2008 16:17
von upsala
Ich kann jetzt mal nichts finden. Sind die Connections wirklich Queued-Connections?

Seit Qt4.4 unterstützt Qt im übrigen Postgres/Firebird-Benachrichtigungen wenn sich in einer Tabelle etwas geändert hat. Dann braucht man auch nicht mehr pollen.

Verfasst: 20. Februar 2008 16:18
von solarix
Ohne weitere Infos kann ich nur raten.. sieh dir mal die Server-Konfiguration an:

Code: Alles auswählen

SHOW variables like '%timeout%';
schliesst dir waehrend des 'sleep(60)' der Server die Verbindung ('wait_timeout')? Tritt das Problem immer (kurz nach Programmstart) oder irgendwann sporadisch auf?

Verfasst: 20. Februar 2008 16:31
von upsala
Ich würde mir auch mal die MySQL-Logfiles ansehen

Mysql config

Verfasst: 20. Februar 2008 18:26
von bjoernt
Hallo,

hier schonmal die Konfig von Mysql:

+----------------------------+-------+
| Variable_name | Value |
+----------------------------+-------+
| connect_timeout | 5 |
| delayed_insert_timeout | 300 |
| innodb_lock_wait_timeout | 50 |
| innodb_rollback_on_timeout | OFF |
| interactive_timeout | 28800 |
| net_read_timeout | 30 |
| net_write_timeout | 60 |
| slave_net_timeout | 3600 |
| table_lock_wait_timeout | 50 |
| wait_timeout | 28800 |
+----------------------------+-------+
10 rows in set (0.00 sec)

Mit dem sleep(60) hat es nichts zu tun, wenn z.B. später Aufträge kommen (nach ein paar Minuten) dann ist die connection immer noch da.

Das Problem tritt eigentlich sporadisch auf, aber wenn es aufgetreten ist dann bleibt es permanent.

QObject::connection Teil

Verfasst: 20. Februar 2008 18:28
von bjoernt
Hier der Code wie ich meine connections angelegt habe

Code: Alles auswählen


      //communication from and to dispatcher
      connect(dispatcher, SIGNAL(newTask(Task *)), this, SLOT(processTask(Task *)),Qt::QueuedConnection);
      connect(this, SIGNAL(updateTask(Task *)), dispatcher, SLOT(updateTask(Task *)),Qt::QueuedConnection);

      for (quint8 i=0; i < settings.value("MaxBuildJobsRunningPerHost").toInt(); i++) {
        out(tr("BuildWorker #%1: Creating new thread.").arg(i));
        BuildWorkerHash.insert(i, new BuildWorker(this));
        BuildWorkerHash.value(i)->ID = i;

        //communication from and to BuildWorker thread
        connect(BuildWorkerHash.value(i), SIGNAL(progress(Task *)), dispatcher, SLOT(updateTask(Task *)),Qt::BlockingQueuedConnection);
        connect(BuildWorkerHash.value(i), SIGNAL(done(Task *)), this, SLOT(processTask(Task *)),Qt::BlockingQueuedConnection);
        connect(BuildWorkerHash.value(i), SIGNAL(aborted(Task *)), this, SLOT(processTask(Task *)),Qt::BlockingQueuedConnection);

        //start thread
        BuildWorkerHash.value(i)->start();
      };
      
      //finally start dispatching
      dispatcher->start();


Verfasst: 20. Februar 2008 18:33
von bjoernt
In den LogDateien von Mysql ist leider nichts zu sehen.
Ich kann höchstens erkennen das ein oder mehrere Queries nicht mehr geloggt werden.
Vermutlich gelangen die garnicht erst an den Server.

Wie macht Ihr das mit dem SQL Plugin in euren Anwendungen?