Fehler #113
Performance Order Controller
0%
Description
Wir haben hier das Problem, dass das Einfügen einer Positionszeile zu lange dauert und je mehr Menschen mit der kivi arbeiten es noch länger dauert. In den Anhängen hab ich zwei Logs.
1.er log. Person gibt alleine Positionen ein ca 20-30
2.er log. Zweite Person ruft immer wieder Kontoauszug verbuchen auf. 1. Person gibt den gleichen Auftrag erneut ein
Files
History
Updated by Bernd Bleßmann almost 9 years ago
Hallo Werner,
Wir haben hier das Problem, dass das Einfügen einer Positionszeile zu lange dauert und je mehr Menschen mit der kivi arbeiten es noch länger dauert. In den Anhängen hab ich zwei Logs.
welchen Stand des Controllers verwendet ihr? Ist der Patch, den ich für Euch erstellt hatte, eingespielt oder ist das ohne diesen?
Sorry - wie Kontoauszug verbuchen funktioniert, weiß ich nicht und logs mit 20000 bzw. 30000 Zeilen durchzusehen finde ich jetzt ein bisschen heftig. Kannst Du Deine Interpretation dazu mal zusammenfassen? Passiert das auch in anderen Szenarien?
1.er log. Person gibt alleine Positionen ein ca 20-30
2.er log. Zweite Person ruft immer wieder Kontoauszug verbuchen auf. 1. Person gibt den gleichen Auftrag erneut ein
Viele Grüße
Bernd
Updated by G. Richardson almost 9 years ago
Werner Hahn schrieb:
Wir haben hier das Problem, dass das Einfügen einer Positionszeile zu lange dauert und je mehr Menschen mit der kivi arbeiten es noch länger dauert. In den Anhängen hab ich zwei Logs.
Hast du auch alle Debug-Einstellungen ausgeschaltet? Da taucht z.B. immer sowas wie dump_query auf, du hast wohl mindestens global_level = QUERY aktiv. Nur so eine Idee.
Die interessanten Queries, die man sich anschauen sollte, und die von Rose generiert werden, tauchen dort eh nicht auf.
Updated by Werner Hahn almost 9 years ago
Hallo
ich hatte das gestern mit Jan besprochen, der wollte die Debugmeldungen haben.
Das Problem genau ist, dass wenn ich enter drücke es ,zwar nicht lange, aber zu lange dauert dass es möglich ist die nächste nummer einzugeben ohne sich zu verhaspeln, d.h. oft wird dann angefangen die nächste nummer einzugeben und die erste stelle wird abgeschnitten.
Bisher ist es möglich positionen ohne pause einzugeben 1.artikelnummer->enter->enter->2.Artikelnummer->enter->enter3.usw ohne Pause jetzt muss ich einen tick Pause machen. Je mehr Leute mit kivitendo arbeiten je größer wird die Pause.
Debug ist auf
global_level = TRACE QUERY REQUEST_TIMER
vielleicht ist etwas anderes hilfreicher.
vielleicht kann man auch das javascript aus der basic.html in einen kivi namespace auslagern, sodass der browser das cached?
so ist es auf jedenfall noch nicht zufriedenstellend doppelt so lange wie bisher und führt zu fehleingaben
Updated by G. Richardson almost 9 years ago
Also die zentrale Datenbankabfrage ist ja die Suche nach dem Artikel anhand der Artikelnummer oder Beschreibung. Ihr habt ja nicht so viele Artikel, anders als bei den Kunden, aber die Artikelsuche würde ich mir als erstes anschauen. Die ist schon mal überhaupt nicht optimiert und kann auch keine Datenbankindizes nutzen. Du lädst in dem Schritt ja glaube ich auch noch ein paar andere Infos, ich hab was von Preisgruppen gehört, führe doch mal Folgendes in der console aus, da sollten dann die von Rose generierten SQL-Statements rausfallen. Und ersetze das "MYPARTNUMBER" durch eine Beispielartikelnummer aus eurem Bestand.
$Rose::DB::Object::Manager::Debug = 1;
$Rose::DB::Object::Debug = 1;
use SL::Controller::Part;
my $cont = SL::Controller::Part->new;
$::form->{filter}{'all:substr:multi::ilike'} = 'MYPARTNUMBER';
$::form->{prefer_exact} = 1;
$::form->{obsolete} = 0;
$cont->action_ajax_autocomplete();
Wenn die Abfrage sehr imperformant und das der Grund ist, gibt es für euren Anwendungsfall da noch Optimierungspotential.
Updated by Werner Hahn almost 9 years ago
Die Artikelsuche ist glaub ich nicht das Problem, auch wenns schön wäre wenn die schneller geht und ab der ersten ziffer schon sofort Vorschläge hat (wie bei google). Wenn da noch was möglich ist freun wir uns.
LOG: 1. Paar Artikelnr '11' 2. u.3. Artikelnr '11215' (genau) 4. Artikelnr '1' 5. Artikelnr '11215' (genau)
Bei 1 und 4 dauerte es schon so 0-3 sec bis das fertig war
2015-12-04 15:43:04.059 2461 [2443] sub0: \ Form::create_http_response in SL/Form.pm:418 called from SL/Controller/Base.pm:131
2015-12-04 15:43:04.060 2461 [2443] sub0: / Form::create_http_response in SL/Form.pm:450
2015-12-04 15:44:22.175 2461 [2443] sub0: \ Form::create_http_response in SL/Form.pm:418 called from SL/Controller/Base.pm:131
2015-12-04 15:44:22.175 2461 [2443] sub0: / Form::create_http_response in SL/Form.pm:450
2015-12-04 15:45:33.892 2461 [2443] sub0: \ Form::create_http_response in SL/Form.pm:418 called from SL/Controller/Base.pm:131
2015-12-04 15:45:33.892 2461 [2443] sub0: / Form::create_http_response in SL/Form.pm:450
2015-12-04 15:46:48.946 2461 [2443] sub0: \ Form::create_http_response in SL/Form.pm:418 called from SL/Controller/Base.pm:131
2015-12-04 15:46:48.947 2461 [2443] sub0: / Form::create_http_response in SL/Form.pm:450
2015-12-04 15:47:39.090 2461 [2443] sub0: \ Form::create_http_response in SL/Form.pm:418 called from SL/Controller/Base.pm:131
2015-12-04 15:47:39.090 2461 [2443] sub0: / Form::create_http_response in SL/Form.pm:450
Bei Bernd seinem orginal ist es noch deutlicher wenn versucht wird flüssig ohne pause die positionen einzugeben auch wenn ich nicht so schnell tippe
Updated by Jan Büren almost 9 years ago
Die Postgres-Werte sind auch annähernd gut an den RAM optimiert?
shared_buffers und effective_cache_size
https://wiki.postgresql.org/wiki/Tuning_Your_PostgreSQL_Server
Ferner sind auch mehr als 2 Kerne für die Maschinen zugewiesen und prinzipiell wird weder beim Wirts- noch beim Gastsystem in SWAP ausgelagert?
Wie schnell dreht eine einzelne Platte, wie schnell das RAID?
Hier Werte für SSD-Platten:
$ hdparm -Tt /dev/sda /dev/sda: Timing cached reads: 33328 MB in 2.00 seconds = 16682.56 MB/sec Timing buffered disk reads: 1554 MB in 3.00 seconds = 517.91 MB/sec
Wie schnell dreht das RAID10?
Unser RAID1 schafft noch 3/4 der SSD-Performance:
time dd of=testfile if=/dev/zero bs=1M count=10000000800 ^C11032+0 Datensätze ein 11032+0 Datensätze aus 11567890432 Bytes (12 GB) kopiert, 33,8864 s, 341 MB/s
Holt Postgres schon das Meiste aus dem RAM raus oder ist das noch konservativ eingestellt?
Bei 8GB RAM kann man sicherlich so verteilen:
shared_buffers = 2GB effective_cache_size = 4GB
Die Standard-Werte von Debian sind hier sehr konservativ.
Falls der Server unter Last auslagert, kann man dies sehr gut mit free feststellen. Ferner kann top nochmal nach Hauptspeicher-Auslastung sortiert werden.
Meine Standard-Checks sind hier
$ free -m $ top (gefolgt mit großem M)
Updated by Jan Büren almost 9 years ago
Vielleicht denke ich zu old school. Heutzutage hat man doch die:
sessionStorage and localStorage capabilities of HTML 5.
Die Tabelle parts kann auch gerne im Browser-Cache landen ...
Updated by Sven Schöling almost 9 years ago
Moin Werner,
wie am Telefon besprochen mache bitte die logs mal mit den Optionen:
[devel]
global = REQUEST REQUEST_TIMER
das loggt den jeweiligen Request und die Zeit die die brauchen, dadurch lässt sich sehr viel besser nachvollziehen welche Requests lange dauern und/oder andere blocken.
Updated by Werner Hahn almost 9 years ago
- File kivitendo-debug1.log kivitendo-debug1.log added
- File kivitendo-debug2.log kivitendo-debug2.log added
- File kivitendo-debug3.log kivitendo-debug3.log added
Hab jetzt die Logs erstellt.
Log1 ich gebe alleine eine Rechnung ein
Log2 eine Mitarbeiterin gibt alleine eine Rechnung ein
Log3 eine Mitarbeiterin gibt eine Rechnung ein auf zwei anderen Clients wird immer wieder Kontosuzugverbuchen angestossen
Wenn man alleine arbeitet kann man sich durchaus an den Rythmus von Kivitendo gewöhnen
Bei Log3 hats alles deutlich verzögert nicht immer aber es ist schwierig einen flüssigen Rythmus zu finden und es ist nicht möglich blind zu tippen.
Werner
Updated by Bernd Bleßmann almost 9 years ago
- File action_add_item.log action_add_item.log added
Hi Werner,
Werner Hahn schrieb:
Hab jetzt die Logs erstellt.
Log1 ich gebe alleine eine Rechnung ein
Log2 eine Mitarbeiterin gibt alleine eine Rechnung ein
Log3 eine Mitarbeiterin gibt eine Rechnung ein auf zwei anderen Clients wird immer wieder Kontosuzugverbuchen angestossen
Ich habe mal für log3 die relevanten Requests mit Zeiten extrahiert - nur der Übersicht halber. Für die Analyse muss man natürlich sehen, was sonst noch so los ist. Relevant: damit meine ich hier die "controller: Order, action: add_item", denn das sind die, die den Artikel hinzufügen und danach den Focus wieder auf das Eingabefeld das Partpickers setzen.
Hier sind die Zeiten für diese Requests, sortiert:
0.32723
0.33684
0.386846
0.389577
0.389788
0.404126
0.410691
0.481287
0.495391
0.500738
0.504685
0.514757
0.579243
0.620899
0.624994
0.651551
0.654329
0.680844
0.706547
0.719991
0.741116
0.752883
0.798339
0.897373
1.466361
Updated by Werner Hahn almost 9 years ago
- File df1_add_item_time.txt df1_add_item_time.txt added
- File df2_add_item_time.txt df2_add_item_time.txt added
- File df3.log.bz2 df3.log.bz2 added
- File df3_add_item_time.txt df3_add_item_time.txt added
- File extract_requests.pl extract_requests.pl added
- Status changed from Neu to Erledigt
Bernd und ich haben jetzt nochmal deren Installation auf kiebitz getestet, und die Zeiten dort sind deutlich besser. Der Testaufbau war ähnlich aufgebaut Bei Test3 haben 3 Leute gleichzeitig Rechnungen getippt.
Ich hab nochmal Bernds extract_request drangehängt. Es ist schon deutlich bei df1 wo nur einer eine rechnung eingibt. Also muss ich mich woanders hier auf die Suche machen.(Netzwerk, Proxmox und VM, Postgres, Apache)