Hänger beim schnellen Buchen mehrerer Rechnungen

[bibi@…]

ok - das ist etwas syntetisch, ist mir aber so passiert und lässt sich (hin und wieder) reproduzieren:

Ich mache drei oder vier Tabs auf, bereite drei oder vier Rechnungen vor und buche diese dann direkt hintereinander. In zumindest zwei der Tabs kommt keine Antwort mehr und auch ein neuer Tab reagiert nicht mehr z.B. beim Rechnungsbericht.

Ich weiß hier nicht genau, wie ich das weiter debuggen kann. Breche ich die wartenden Postgres-Prozesse (ps ax sagt "LOCK TABLE waiting" bzw. "PARSE TABLE waiting") mit kill ab, bekomme ich folgende Meldungen:

get_objects() - DBD::Pg::st execute failed: FATAL:  breche Verbindung ab aufgrund von Anweisung des Administrators
LINE 83:   defaults t1
           ^
SSL connection has been closed unexpectedly at /usr/share/perl5/Rose/DB/Object/Manager.pm line 2014.
 at /usr/local/src/lxoffice-git-bernd/bin/mozilla/is.pl line 442

LOCK TABLE defaults
FATAL: breche Verbindung ab aufgrund von Anweisung des Administrators
SSL connection has been closed unexpectedly

und

SELECT * FROM defaults
FATAL: breche Verbindung ab aufgrund von Anweisung des Administrators
LINE 1: SELECT * FROM defaults
^
SSL connection has been closed unexpectedly

Ich habe mal ein bisschen versucht zu debuggen. Manchmal kommt es zu einem Deadlock, der auch von postgresql erkannt wird. Dann erscheint eine Fehlermeldung im Browser. Zwei Prozesse warten dann gegenseitig auf einen exklusiven Lock auf defaults. Die Code-Stelle mit dem Lock ist offenbar SL::TransNumber::create_unique. Wenn die Fehlermeldung kommt, dann kann man danach aber auch weiterarbeiten.

Doch meistens hängt das System wie oben beschrieben. Ein (oder zwei) Prozesse warten dabei auf den exklusiven Lock auf defaults, den sie aber nicht bekommen, weil ein zweiter (oder dritter) Prozess einen AccessShareLock? auf defaults hält und irgendwo hängt ("idle in transaction"). Diese Stelle ist vermutlich "if (SL::DB::Default->get->payments_changeable == 0)" (bin/mozilla/is.pl:442) oder davor. (Ich habe geschaut, was das letzte Statement des hängenden Prozesses war und was dann an DB-Operationen danach kommt).

Wenn jmd. noch Ideen zum besseren Debuggen hat, bin ich dankbar.

Das Problem läßt sich auch einfacher nachstellen, indem eine große Kundenliste (5000) per CSV importiert und dann eine Rechnung bucht. Also erst "Test und Vorschau" und dann "Import". Etwas warten und dann im anderen Tab die vorbereitete Rechnung buchen.

Ich vermute mal, dass das Problem was mit Rose zu tun hat und damit, dass es ein anderes Datenbank-Handle verwendet. Warum allerdings kein Deadlock erkannt wird und der Prozeß einfach nur hängt, verstehe ich nicht. Evtl. gibt es keine Verbindung zur DB mehr, aber keine Ahnung warum.

Ich hab mich gerade mit Mosu drüber unterhalten. Wir haben beide nicht genug Erfahrung damit um das aus der Hüfte zu beantworten. Ich werde einen Testcase bauen mit dem man das provozieren kann zur weiteren Untersuchung.

So, was ich bisher so rausgefunden habe.

1. Die eigentlichen Deadlocks kommen von Datenbankhandles die in Legacycode aufgemacht wurden, und dann dem Garbagecollector überlassen wurden. Es ist zwar garantiert dass dann ein rollback und disconnect auf denen aufgerufen wird, aber nicht wann. Das hat dazu geführt, dass der Rechnung buchen Request nicht die normalen 3 Hanlde aufgemacht hat ($::auth, $::form->get_standard_dbh, SL::DB->dbh) sondern mindestens 5, von denen zwei am Ende noch offen waren. Diese zwei waren das dann die die Deadlocks provoziert haben.

Ich pushe gleich einen Fix der das zumindest im aktuellen Fall behebt.

Beim weiteren Testen sind dann noch ein paar weitere Sachen aufgefallen, die bisher nicht beachtet werden.

2. Der Taskserver kennt keine Requestgrenzen. Das ist deshalb schlecht, weil zwei von den drei standardhandles ohne autocommit aufgemacht werden (nur das Rosehandle hat autocommit) und damit bis zum nächsten commit oder rollback Ihren internen State cachen. Normalerweise kennt man das daraus dass Werte nicht gespeichert werden, weil man ein commit vergessen hat, in diesem Fall kommt aber dazu, dass der Taskserver über eine grössere Aufgabe auchmal 200 implizite Locks in der Datenbank anhäuft, die nicht aufgeräumt werden. Das kollidiert dann mit Punkt 3:

3. defaults/instance_conf sind nicht gegen Cacheinvalidierung abgesichert. defaults wird relativ häufig auf lokaler Ebene gebraucht um irgendwelche Mandanteneinstellungen auszulesen. ich habe es nicht komplett verfolgt, aber für einmal Rechnung speichern und danach wieder anzeigen scheint das in der Grössenordnung 10-20 Zugriffe auf defaults zu liegen. Alter Code macht meist ein direktes SELECT * FROM defaults, oder liest ein Feld direkt ein, neuerer Code geht entweder über SL::DB::Default->get oder $::instance_conf die auch nichts weiter macht als defaults einzulesen und zu cachen. Da aber SL::DB::Default->get und $::instance_conf auf verschiedenen Datenbankhandles liegen, werden Änderungen an den Nummernkreisen nicht auf das jeweils andere propagiert. Das ist in der Realität kaum ein Problem, weil sich Mandanteneinstellungen selten ändern und Nummernkreise nicht über die instance_conf ausgelesen werden, wird aber jetzt zum Problem, weil zum Beispiel instance_conf in einem lange laufenden task_server völlig veraltet ist, und Code der SL::DB::Default uns $::instance_conf mixt evtl wiedersprüchliche Informationen kriegt.

4. Die Anzahl der Zugriffe auf default triggern nun einen neuen Bug, dass der Rechnung buchen Prozess ab und zu einfach zu lange bruacht um bei einem aggressiven TaskServer? Prozess genügend Locks auf default zu kriegen. Im form_footer werden mehrere SL::DB::Default->get verwendet, und da die alle eine eigene transaktion aufmachen müssen die sich alle um ein neuen ACCESS SHARE LOCK bemühen. Bei meinen Tests hatte ich eine gewisse chance dass der Servertimeout vorher eintritt.

Was zu machen wäre:

1. Der Taskserver muss vernünftige Requestgrenzen beigebracht kriegen, bei denen globale Cacheresets stattfinden, so wie im Moment am Ende der Hauptrequestschleife von SL::Dispatcher. Vor allem muss Form::disconnect_standard_dbh (oder spätere Äquivalente) getriggert werden.
2. Code der Mandantenkonfiguration braucht, sollte ausschliessliche auf $::instance_conf zugreifen um die Last auf der Tabelle zu verringern. Gleichzeitig muss $::instance_conf einen Invalidierungsmechanismus erhalten, der von Code getriggert werden kann, wenn sich defaults Inhalte ändern, und dem Zustand für die Zeit eines Requests korrekt zu halten. Zwischen Requests wird unkonditional invalidiert.
3. Langfristig sollten get_standard_dbh Zugriffe transformiert werden in das $dbh->begin_work if $was_autocommit = $dbh->{AutoCommit?} .... work ... $dbh->commit if $was_autocommit Idiom, und dann alle Aktionen nur noch das AutoCommit? Handle von Rose benutzen. Dann kann das get_standard_dbh rausfliegen oder auf das Rosehandle gemappt werden, und es wird pro Request nur noch 1 Verbindungen aufgemacht, die dann sogar gecacht werden kann, wenn man sie einfach rollbackt. Ich bau mal ne Wrapperfunktion dafür.
4. Es sollte mal getestet werden ob dei Rose Verbindung im Moment zwischen Requests überhaupt abgerissen wird, das würde nämlich auch die tollen probleme beim upgrade erklären wenn ein fcgi Prozess noch ein offenes Handle hat.

siehe Ticket #2368, das Problem scheint behoben zu sein.