OS 2.8.5 - Uncaught PDOException

[irrsinn.de]

Hallo!

Wir haben bei zwei großen Restaurants, die wir betreuen auf die 2.8.5 umgestellt. OS läuft auf einer separaten Linux Maschine.
Wenn die Installation "unter Last" kommen, kommt es hin und wieder bei großen Bestellungen vor, dass man keinen Orderbon auslösen kann. Der Knopf erscheint inaktiv, bzw. es passiert einfach nichts. In einem solchen Fall kann man nur zurück gehen, verliert dann aber die Bestellung.

Zeitgleich tritt im error.log des Apache2 folgende Fehlermeldung auf:

[Sat Jun 08 19:00:12.114791 2024] [php:error] [pid 177744] [client 192.168.140.181:50620] PHP Fatal error: Uncaught PDOException: SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transa
ction in /var/www/html/php/commonutils.php:454\nStack trace:\n#0 /var/www/html/php/commonutils.php(454): PDOStatement->execute()\n#1 /var/www/html/php/workreceipts.php(19): CommonUtils::execSql()\n#2 /var/www/html/php/printqueue.php(206)
: Workreceipts::getNextWorkReceiptId()\n#3 /var/www/html/php/queuecontent.php(797): PrintQueue::queueWorkPrintJob()\n#4 /var/www/html/php/queuecontent.php(714): QueueContent->createAWorkReceiptAndQueueWorkPrint()\n#5 /var/www/html/php/qu
euecontent.php(648): QueueContent->doWorkPrintCore()\n#6 /var/www/html/php/queuecontent.php(1562): QueueContent->doWorkPrint()\n#7 /var/www/html/php/queuecontent.php(1239): QueueContent->addProductListToQueueCore()\n#8 /var/www/html/php/
queuecontent.php(90): QueueContent->addProductListToQueue()\n#9 /var/www/html/php/contenthandler.php(75): QueueContent->handleCommand()\n#10 {main}\n thrown in /var/www/html/php/commonutils.php on line 454, referer: http://192.168.140.1
/waiter.html

Hin und wieder tritt im Log auch die unten stehende Fehlermeldung auf, diese scheint aber keine Auswirkung auf den Ablauf zu haben:

[Sat Jun 08 19:00:19.254836 2024] [php:notice] [pid 174820] [client 192.168.140.176:56075] Insert performance value '452' went wrong: SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting tra
nsaction, referer: http://192.168.140.1/paydesk.html?t=731&v=2.8.5

Wir haben die von der Webseite Empfohlenen Einstellungen für die php.ini übernommen und die Werte in der apache.conf der große der Installation entsprechend angepasst. Die älteren Versionen von Odersprinter zeigten dieses Verhalten nicht.

Hat irgendjemand die selben Probleme?

[pichel]

Hallo,

zunächst einmal zum letzten Punkt: Wenn Performance-Daten nicht eingefügt werden können, hat das überhaupt keinen Einfluss auf die Funktionsweise der Software. Es fehlt dann nur ein Messpunkt der Daten zur Performancemessung, wie sie in in der Statistikansicht eingesehen werden können.

Aber nun zum eigentlichen Deadlock-Problem. In der Software verwende ich Transaktionen für bestimmte Aktionen. Transaktionen können als eine logische Einheit betrachtet werden, weil sie den Datenbestand nach fehlerfreier und vollständiger Ausführung in einem konsistenten Zustand hinterlassen. Transaktionen werden also entweder vollständig und fehlerfrei oder gar nicht ausgeführt. Wenn man aber stets nur einem Prozess bzw. Verbindung Schreibberechtigung zu erteilt und ansonsten die gesamte Datenbank für alle anderen Prozesse einzufriert, reduziert man die Leistungsfähigkeit und das kann bei vielen gleichzeitigen Zugriffen bis zur Unbenutzbarkeit führen. Aus dem Grund gibt es verschiedene Stufen des Isolierung bei Transaktionen. Leider kann es dann aber bei vielen gleichzeitigen Zugriffen immer passieren, dass es zu einem Deadlock kommt: zwei Prozesse warten jeweils auf den anderen, um fortzufahren.

Beispiel:

Code: Alles auswählen

Verbindung 1: lockt key(1), lockt key(2);
Verbindung 2: lockt key(2), lockt key(1);

Wenn nun beide Prozesse gleichzeitig ausgeführt werden, wird über Verbindung 1 der (1) gelockt, über Verbindung 2 der (2). Jeder der beiden Prozesse wartet nun auf den jeweils anderen um den nächsten Key zu locken. Das führt zu einem Deadlock.

Diese Art von Problemen sind nur sehr schwer zu lösen, weil sie selten und meist nur unter Hochlast auftreten, wenn also keine Zeit für eine ausführliche Fehleranalyse oder Backup der DB-Situation (Tabellen,Logs, usw.) vorhanden ist. Wenn man verstanden hat, wie die Situation zustandegekommen ist, kann man sie die Reihenfolge der Key-Locks verhindern.

So wie ich die meisten Transaktionen in OrderSprinter verwende, bestimmt die Reihenfolge der Zugriffe auf die Tabellen vermutlich auch die Reihenfolge der Locks innerhalb der Transaktionen. Wenn es eine bestimmte Stelle im Source-Code gibt, die immer wieder zu den Deadlocks führt, wäre ich bereit, mir die genauer anzuschauen und ggfs. zu verbessern. Ansonsten muss ich leider eingestehen, dass mir die schlicht die Zeit dafür fehlt, dass genauer zu investigieren.

Gruß,

Stefan

[irrsinn.de]

Hallo!

Wir debuggen das mal weiter. Wir haben zusätzlich festgestellt, dass bei Hochlast, bei einem kleinen Teil der Buchungen, laut Anzeige auf dem Tablet, alles geklappt zu haben scheint (Kellner drückt "Arbeitsbon" und Tablett springt zurück zur Tischauswahl) tatsächlich fehlt aber die Buchung und es wird kein Arbeitsbon gedruckt. Das fatale ist, dass dies scheinbar ein Edgecase zu sein scheint und wirklich selten auftritt - bei größeren Bestellungen scheinbar häufiger als bei kleinen.

Vielen Dank, für die rasche Antwort und einen schönen Sonntag.

Gruß Lutz

[irrsinn.de]

Hallo Stefan,

wir haben mal angefangen das ausführlicher zu debuggen. Die PDOException flog als MySQL folgende Statements ausführen sollte:

Code: Alles auswählen

 SET SESSION sql_mode = 'STRICT_TRANS_TABLES,NO_ENGINE_SUBSTITUTION';
SELECT count(id) as countid FROM os_config WHERE name='usetse';
SELECT setting as setting FROM os_config WHERE name='usetse';
SELECT count(id) as countid FROM os_config WHERE name='tseurl';
SELECT setting as setting FROM os_config WHERE name='tseurl';
SELECT count(id) as countid FROM os_config WHERE name='tsepin';
SELECT setting as setting FROM os_config WHERE name='tsepin';
SELECT count(id) as countid FROM os_config WHERE name='tsepuk';
SELECT setting as setting FROM os_config WHERE name='tsepuk';
SELECT count(id) as countid FROM os_config WHERE name='sn';
SELECT setting as setting FROM os_config WHERE name='sn';
SELECT count(id) as countid FROM os_config WHERE name='tseurl';
SELECT setting as setting FROM os_config WHERE name='tseurl';
SELECT count(id) as countid FROM os_config WHERE name='tsepass';
SELECT setting as setting FROM os_config WHERE name='tsepass';
SELECT count(id) as countid FROM os_config WHERE name='hotelinterface';
SELECT setting as setting FROM os_config WHERE name='hotelinterface';
SELECT value FROM os_work WHERE item='lastsyncwithguest';
SELECT count(id) as countid FROM os_config WHERE name='payprinttype';
SELECT setting as setting FROM os_config WHERE name='payprinttype';
SELECT IF(UNIX_TIMESTAMP(NOW())-COALESCE((SELECT value from os_work where item='lastprtserveraccess'),0) < '40','ACTIVE','NOTACTIVE') as status;

Wir haben daraufhin die Werte der /etc/mysql/madriadb.conf.d/50-server.cnf angepasst:

key_buffer_site = 256M (vorher 128M)
max_allowed_packet = 1G (war vorher auskommentiert)
table_cache = 128 (war vorher auskommentiert und stand auf 64)

außerdem hinzugefügt:
innodb_buffer_pool_size = 4G
innodb_log_file_size = 1G
innodb_log_buffer_size = 512M

Nun warten wir, dass mal wieder richtig Druck auf das System kommt um zu schauen ob es damit besser läuft.