Nach Update auf OTRS 2.1.5 Sysconfig extrem langsam

[Andre Bauer]

Ich habe gestern unser Produktivsystem von Version 2.0.5 auf die
aktuelle OTRS 2.1.5 Version umgestellt. Seit dem ist die Sysconfig
beim Laden und Ausführen von Änderungen extrem langsam. Das restliche
System läuft aber erfreulich schnell.

Ich hatte die lahmende Sysconfig auch schon bei meinem Testsystem
festgestellt, dachte aber dass es dort mit der schwachen Hardware
zusammen hängt.

Versuche ich ein paar Werte (gleichzeitig) über die Sysconfig zu
ändern, geht die Systemlast (Apache) auf 100%. Ich habe es heute so
geschafft eine Server Load von 15(!!!) zu erreichen. Beim ändern eines
einzelnen Wertes komm ich aber auch schon über 1.

Das Ganze verhällt sich unter Mod_perl sowie Mod_fastcgi gleich.

Unter OTRS 2.0.4 hatte ich diese Probleme auf dem selben Rechner
nicht.

Im Apache error.log findet sich öfter folgender Eintrag, wenn ich mit
der Sysconfig arbeite:

:Apache2 IO flush: (103) Software caused connection abort at -e line 0

Ansonsten geben die Logs leider nichts her.


Hat einer eine Lösung für das Problem parat?

[larf]

Hi,

Es ging mir schon unter OTRS 2.1.4 ähnlich. Von Seiten OTRS wurde mir dazu gesagt, dass das "normal" sei, da mittlerweile eben alles über die Datenbank gehandelt wird.

Interessant wäre aber, ob du schon einmal das SQL-Benchmarkt benutzt hast.
Meines zeigt hier überall Werte mit ":-)".

[Andre Bauer]

Nein, auf der selben Hardware lief die Sysconfig ja unter OTRS 2.0.4 noch flüssig.

Das ist also auf jeden Fall nicht "normal".

Das SQL Benchmark ist unerheblich, weil die Daten in XML/PM Dateien abgelegt sind, welche du unter $OTRSHOME/Kernel/Config/Files findest...

[A_W]

DB hat damit offenkundig nichts zu tun.

Habe das gleiche Verhalten beobachtet und per logging / binäres Suchen
gefunden, dass die xml files
# 1) gecached werden (sollten),
# 2) die cached variante auch angefasst wird,
# 3) dann aber doch entschjieden wird, xml neu zu parsen

Und das xml-Parsen dauert (warum auch immer) teilweise extrem lange.
Also local host, file system, flotte Kiste, nutzt alles nichts.
log file siehe unten.


OTRS 2.2.1


Andreas


====================================
from var/log/otrs:
====================================
[Mon Sep 24 15:11:29 2007][Info][ModPerl::ROOT::ModPerl::Registry::opt_otrs_bin_cgi_2dbin_index_2epl::handler] AW__ start: bin/cgi-bin/index.pl with $Debug = 1;
[Mon Sep 24 15:11:29 2007][Info][Kernel::Modules::AdminSysConfig::new] AW__ start: Kernel/Modules/AdminSysConfig.pm::new
[Mon Sep 24 15:11:29 2007][Debug][Kernel::Modules::AdminSysConfig::new][49] AW__ fetch 82 common objects
[Mon Sep 24 15:11:30 2007][Debug][Kernel::System::Config::new][84] AW__ start debug logging; Kernel/System/Config.pm::new
[Mon Sep 24 15:11:30 2007][Debug][Kernel::System::Config::_Init][134] AW__ in: Kernel/System/Config.pm::_Init
[Mon Sep 24 15:11:30 2007][Debug][Kernel::System::Config::_Init][155] AW__ foreach; File=/opt/otrs/Kernel/Config/Files/Framework.xml
[Mon Sep 24 15:11:30 2007][Debug][Kernel::System::Config::_Init][182] AW__ ConfigFile: length=241696, md5=980187011b2127e655c819972a0903b7
[Mon Sep 24 15:11:30 2007][Debug][Kernel::System::Config::_Init][189] AW__ read in FileCache=/opt/otrs/var/tmp/SysConfig-Cache_Kernel_Config_Files_Framework.xml-980187011b2127e655c819972a0903b7.pm)
[Mon Sep 24 15:11:30 2007][Debug][Kernel::System::Config::_Init][202] AW__ length(ConfigFileCache)=679320, try to eval it...
[Mon Sep 24 15:11:30 2007][Debug][Kernel::System::Config::_Init][221] AW__ eval failed. CacheFileUsed = 0 (why?!! ...).
[Mon Sep 24 15:11:37 2007][Debug][Kernel::System::Config::_Init][155] AW__ foreach; File=/opt/otrs/Kernel/Config/Files/FrameworkITSMCore.xml
[Mon Sep 24 15:11:37 2007][Debug][Kernel::System::Config::_Init][182] AW__ ConfigFile: length=1596, md5=42386a3249033af46888cabeeb9cd9fd
[Mon Sep 24 15:11:37 2007][Debug][Kernel::System::Config::_Init][189] AW__ read in FileCache=/opt/otrs/var/tmp/SysConfig-Cache_Kernel_Config_Files_FrameworkITSMCore.xml-42386a3249033af46888cabeeb9cd9fd.pm)
[Mon Sep 24 15:11:37 2007][Debug][Kernel::System::Config::_Init][202] AW__ length(ConfigFileCache)=3739, try to eval it...
[Mon Sep 24 15:11:37 2007][Debug][Kernel::System::Config::_Init][221] AW__ eval failed. CacheFileUsed = 0 (why?!! ...).
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][155] AW__ foreach; File=/opt/otrs/Kernel/Config/Files/GeneralCatalog.xml
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][182] AW__ ConfigFile: length=1190, md5=d259dcbaebbf4d8ce51803e011d06c91
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][189] AW__ read in FileCache=/opt/otrs/var/tmp/SysConfig-Cache_Kernel_Config_Files_GeneralCatalog.xml-d259dcbaebbf4d8ce51803e011d06c91.pm)
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][202] AW__ length(ConfigFileCache)=3839, try to eval it...
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][221] AW__ eval failed. CacheFileUsed = 0 (why?!! ...).
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][155] AW__ foreach; File=/opt/otrs/Kernel/Config/Files/ITSMConfigItem.xml
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][182] AW__ ConfigFile: length=14186, md5=2ef68ff8671d8ce533c834d6bbc2edcc
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][189] AW__ read in FileCache=/opt/otrs/var/tmp/SysConfig-Cache_Kernel_Config_Files_ITSMConfigItem.xml-2ef68ff8671d8ce533c834d6bbc2edcc.pm)
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][202] AW__ length(ConfigFileCache)=42953, try to eval it...
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][221] AW__ eval failed. CacheFileUsed = 0 (why?!! ...).
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][155] AW__ foreach; File=/opt/otrs/Kernel/Config/Files/ITSMCore.xml
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][182] AW__ ConfigFile: length=4681, md5=bcec8e920515226304847167c2e0ca84
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][189] AW__ read in FileCache=/opt/otrs/var/tmp/SysConfig-Cache_Kernel_Config_Files_ITSMCore.xml-bcec8e920515226304847167c2e0ca84.pm)
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][202] AW__ length(ConfigFileCache)=15184, try to eval it...
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][221] AW__ eval failed. CacheFileUsed = 0 (why?!! ...).
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][155] AW__ foreach; File=/opt/otrs/Kernel/Config/Files/ITSMLocation.xml
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][182] AW__ ConfigFile: length=5959, md5=ef9e50a381b0914557546c04bdf370da
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][189] AW__ read in FileCache=/opt/otrs/var/tmp/SysConfig-Cache_Kernel_Config_Files_ITSMLocation.xml-ef9e50a381b0914557546c04bdf370da.pm)
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][202] AW__ length(ConfigFileCache)=19084, try to eval it...
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][221] AW__ eval failed. CacheFileUsed = 0 (why?!! ...).
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][155] AW__ foreach; File=/opt/otrs/Kernel/Config/Files/ITSMService.xml
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][182] AW__ ConfigFile: length=6383, md5=d411292c4f02bd228b298cc02f089dc0
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][189] AW__ read in FileCache=/opt/otrs/var/tmp/SysConfig-Cache_Kernel_Config_Files_ITSMService.xml-d411292c4f02bd228b298cc02f089dc0.pm)
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][202] AW__ length(ConfigFileCache)=19789, try to eval it...
[Mon Sep 24 15:11:38 2007][Debug][Kernel::System::Config::_Init][221] AW__ eval failed. CacheFileUsed = 0 (why?!! ...).
[Mon Sep 24 15:11:39 2007][Debug][Kernel::System::Config::_Init][155] AW__ foreach; File=/opt/otrs/Kernel/Config/Files/ITSMTicket.xml
[Mon Sep 24 15:11:39 2007][Debug][Kernel::System::Config::_Init][182] AW__ ConfigFile: length=32593, md5=aaa7da950c265c1c669533ef7ba1d206
[Mon Sep 24 15:11:39 2007][Debug][Kernel::System::Config::_Init][189] AW__ read in FileCache=/opt/otrs/var/tmp/SysConfig-Cache_Kernel_Config_Files_ITSMTicket.xml-aaa7da950c265c1c669533ef7ba1d206.pm)
[Mon Sep 24 15:11:39 2007][Debug][Kernel::System::Config::_Init][202] AW__ length(ConfigFileCache)=93802, try to eval it...
[Mon Sep 24 15:11:39 2007][Debug][Kernel::System::Config::_Init][221] AW__ eval failed. CacheFileUsed = 0 (why?!! ...).
[Mon Sep 24 15:11:40 2007][Debug][Kernel::System::Config::_Init][155] AW__ foreach; File=/opt/otrs/Kernel/Config/Files/LinkObject2.xml
[Mon Sep 24 15:11:40 2007][Debug][Kernel::System::Config::_Init][182] AW__ ConfigFile: length=4962, md5=1b0092d2ca54561c9c433816a655247a
[Mon Sep 24 15:11:40 2007][Debug][Kernel::System::Config::_Init][189] AW__ read in FileCache=/opt/otrs/var/tmp/SysConfig-Cache_Kernel_Config_Files_LinkObject2.xml-1b0092d2ca54561c9c433816a655247a.pm)
[Mon Sep 24 15:11:40 2007][Debug][Kernel::System::Config::_Init][202] AW__ length(ConfigFileCache)=14035, try to eval it...
[Mon Sep 24 15:11:40 2007][Debug][Kernel::System::Config::_Init][221] AW__ eval failed. CacheFileUsed = 0 (why?!! ...).
[Mon Sep 24 15:11:40 2007][Debug][Kernel::System::Config::_Init][155] AW__ foreach; File=/opt/otrs/Kernel/Config/Files/Ticket.xml
[Mon Sep 24 15:11:40 2007][Debug][Kernel::System::Config::_Init][182] AW__ ConfigFile: length=434819, md5=14ff184c9d41492e1f824906742cebce
[Mon Sep 24 15:11:40 2007][Debug][Kernel::System::Config::_Init][189] AW__ read in FileCache=/opt/otrs/var/tmp/SysConfig-Cache_Kernel_Config_Files_Ticket.xml-14ff184c9d41492e1f824906742cebce.pm)
[Mon Sep 24 15:11:40 2007][Debug][Kernel::System::Config::_Init][202] AW__ length(ConfigFileCache)=1196471, try to eval it...
[Mon Sep 24 15:11:41 2007][Debug][Kernel::System::Config::_Init][221] AW__ eval failed. CacheFileUsed = 0 (why?!! ...).
[Mon Sep 24 15:11:41 2007][Debug][Kernel::System::Config::_Init][246] AW__ no cache file, so parse /opt/otrs/Kernel/Config/Files/Ticket.xml
[Mon Sep 24 15:11:52 2007][Debug][Kernel::System::Config::_Init][268] AW__ parsing ready.
[Mon Sep 24 15:11:52 2007][Debug][Kernel::System::Config::_Init][155] AW__ foreach; File=/opt/otrs/Kernel/Config/Files/TicketITSMService.xml
[Mon Sep 24 15:11:52 2007][Debug][Kernel::System::Config::_Init][182] AW__ ConfigFile: length=953, md5=a4b1a6ce798008131d9a2d3cf5b99afe
[Mon Sep 24 15:11:52 2007][Debug][Kernel::System::Config::_Init][189] AW__ read in FileCache=/opt/otrs/var/tmp/SysConfig-Cache_Kernel_Config_Files_TicketITSMService.xml-a4b1a6ce798008131d9a2d3cf5b99afe.pm)
[Mon Sep 24 15:11:52 2007][Debug][Kernel::System::Config::_Init][202] AW__ length(ConfigFileCache)=2385, try to eval it...
[Mon Sep 24 15:11:52 2007][Debug][Kernel::System::Config::_Init][221] AW__ eval failed. CacheFileUsed = 0 (why?!! ...).
[Mon Sep 24 15:11:52 2007][Debug][Kernel::System::Config::_Init][155] AW__ foreach; File=/opt/otrs/Kernel/Config/Files/TicketITSMTicket.xml
[Mon Sep 24 15:11:52 2007][Debug][Kernel::System::Config::_Init][182] AW__ ConfigFile: length=23506, md5=c2bf1984bc442c9f4aa676d12830a279
[Mon Sep 24 15:11:52 2007][Debug][Kernel::System::Config::_Init][189] AW__ read in FileCache=/opt/otrs/var/tmp/SysConfig-Cache_Kernel_Config_Files_TicketITSMTicket.xml-c2bf1984bc442c9f4aa676d12830a279.pm)
[Mon Sep 24 15:11:52 2007][Debug][Kernel::System::Config::_Init][202] AW__ length(ConfigFileCache)=66561, try to eval it...
[Mon Sep 24 15:11:52 2007][Debug][Kernel::System::Config::_Init][221] AW__ eval failed. CacheFileUsed = 0 (why?!! ...).
[Mon Sep 24 15:11:53 2007][Debug][Kernel::System::Config::_Init][299] AW__ read all config files
[Mon Sep 24 15:11:53 2007][Debug][Kernel::System::Config::_Init][311] AW__ ready
[Mon Sep 24 15:11:56 2007][Notice][Kernel::System::Web::InterfaceAgent::Run] Response::Agent: 27s taken (URL:Action=AdminSysConfig:root@localhost)

[Schojo]

Ja ich fürchte da haben wir alle mit zu kämpfen...damals auf OTRS 1.3 war die auch noch genial schnell...aber jetzt

Naja ich versuch seitdem das meiste über die internen Config-Files zu machen, weil die Sysconfig schon sehr lahm ist. Naja hauptsache es bleibt bei der Sysconfig, das System an sich ist nämlich schön schnell

[Andre Bauer]

Updated einfach auf die aktuelle Version. Dort funktioniert es wie es soll.

[Schojo]

Naja es geht, eben auf 2.2.3 aktualisiert...

Ein bisschen schneller ist es tatsächlich!