Performance Probs mit Domain Access (views) und Organic Groups

Kein Monitoring ist schonmal suboptimal.

Installier mal das Devel Modul und schau nach welche Abfragen die meiste Performance ziehen. Ggf. muss man sich in dem Zuge auch mal die MySQL Konfiguration anschauen.

Dass die Deaktivierung mancher Module Performance bringt ist relativ klar, gerade wenn es um Berechtigungen geht, da alle damit zusammenhängenden Abfragen dann über deutlich weniger Tabellen laufen.

@ Alexander: Erst einmal vielen Dank für die schnelle Antwort.

Meine Frage zu den Traces - im speziellen zu den Traces der cache und menu Aufrufe - : gibt es eine Erklährung, warum gerade die gelisteten Aufrufe soviel Performance 'fressen', oder kann ich hier mit Konfigurationseinstellungen oder weiteren Tests dem Problem weiter auf den Grund gehen?

Aufbauend auf der oben beschriebenen Konfiguration habe ich hier zwei Messungen durchgeführt:
a) Aufruf von My Account bei akzeptabler Performance
b) nach der Aktivierung von OG Modulen Modulen ein weiterer Aufruf von My Account - nachdem sich die Reaktionszeit etwa verdreifacht hat.

-----------------------------------------------------
a) Aufruf von My Account bei akzeptabler Performance
-----------------------------------------------------
ms # where query

30,39 1 cache set insert into drupal cache menue
25 1 menu tree page data select m.load functions
24,55 1 cache set update drupal cache menu set data
22.44 1 cache set update drupal cache set data
21,15 1 cache set insert into drupal cache
7,63 1 menu local task select * from drupal menu router where tab root
6,31 1 drupal lookup path select dst from drupal url alias where
6,19 1 cache get select data, created, headers,
5,91 1 drupal lookup path select dst from drupal url alias where
5,84 1 drupal lookup path select dst from drupal url alias where
5,75 1 performance log summary db
5,72 1 cache get select data, created, headers, expire, serialized
5,02 16 user load select * from drupal users
4,57 16 user load select r.rid, r.name from drupal role r inner join drupal
4,08 1 block list select distinct b. * from drupal blocks b left join ...

----------------------------------------------------
b) Aktivierung von ORGANIC-GROUP modulen
----------------------------------------------------

- og content type admin: set to active
- organic groups action: set to active
- subgroups for organic groups: set to active

- trigger: set to active
- book: set to active

The OG Content Type Admin module was enabled successfully. Default settings were initialized.
The configuration options have been saved.
The user is being redirected to http://mmmmmm.net/cserver/?q=admin/build/modules.

----------------------------------
--> nach der Aktivierung von OG Modulen Modulen ein weiterer Aufruf von My Account - die Reaktionszeit hat sich etwa verdreifacht

Executed 2489 queries in 3099.8 milliseconds. Queries taking longer than 5 ms and queries executed more than once, are highlighted. Page execution time was 7567.07 ms.

ms # where query

123,15 1 cache set insert into drupal cache menu
120,1 1 cache set update drupal cache menu set data
116,76 1 menu navigation links rebuild select * from drupal menu links where router path not in
107,95 1 cache set insert into drupal cahce menu
27,3 2 cache set update drupal cache set data
25,97 1 cache set update drupal cache menu set data
23,72 1 menu tree page data select m.load functions, m.to arg function
23,68 2 cache set update drupal cache set data
22.43 1 cache set update drupal cache set data
22.38 2 cache set update drupal cache set data
22,27 1 cache set insert into drupal cache
20,43 2 cache set update drupal cache
14,53 1 trigger get hook aids select aa.aid, a.type from drupal trigger assignment
12,16 1 menu navigatin links rebuild select ml.link path, ml.mlid, ml.router path ml.updated from..
8,87 3 cache set update drupal cache content
8,02 3 cache set insert into drupal cache content
7,7 4 taxonomy get vocabularies select v.vid v.*, n.type
7,52 1 menu router build insert into drupal menu router
6,99 1 menu router build inser into drupal menu router
6,96 2 cache clear all delete from drupal cahce menu
6,91 3 cache set update drupal cache content set data
6,87 4 taxonomy get vocabularies select v.vid, v.*, n.type
6,79 5 og forum schema update drupal system set weight 2
6,76 5 db table exists show tables like drupal content node field
6,69 10 menue update parental status select mlid from drupal menu links
6,69 1 menu link save select from drupal menu links
6,63 1 menu link save update drupal menu links set menu name

Hm.. ich habe gerade keine passende Drupal-Installation mit diesen Modulen bei der Hand, um mir mal auf mir bekannter Hardware in einem vergleichbaren System ein paar Zahlen zu saugen.
Ich kann dir bestenfalls anbieten mir mal selbst ein Bild zu verschaffen, wenn du mir diverse Zugangsdaten (MySQL root, SSH root, Drupal Admin, ..) anvertrauen magst.

Erster Reflex war es auf ne übel konfigurierte DB zu schieben. Aber der Rest der Page Generation Time sieht auch nicht eben vielversprechend aus..

To change the world
Start with one step
However small
First step is hardest of all
DMB

webseiter.de

Ich klinke mich hier mal ein...

Ich habe auch mittels des trace und des Devel Moduls festgestellt, dass die Funktion
cache_set (CORE) im 20-30ms Bereich irgendwas macht.

Was sei macht, weiss ich inzwischen auch, nämlich massig (1-3 MB Textdaten pro Update/Insert) Daten in die Datenbank schieben/updaten.

Grob vermutet würde ich auf die "locales"-Tabellen schliessen !?

Allerdings entzieht sich mir der Sinn, warum diese (bei Nichtbearbeitung) erneuert werden müssen.

Ist diesbezüglich etwas bekannt?
Auf die aufsummierten ~100ms pro Aufruf könnt ich durchaus verzichten.

MfG
Passer

eigentlich sollte das Locale Modul nicht bei jedem Mal den Cache abspeichern, genauso der MENU_ROUTER Cache sollte definitiv auch nicht aufgebaut werden.

ich habe mir mal die Module heruntergeladen und folgendes entdeckt

Das ist nicht nur BÖSE, das ist ÜBERBÖSE!
Alle Cache werden bei jedem Aufruf gelöscht.

Hier die entsprechende Issue.
http://drupal.org/node/330135

Ich würde das Modul nicht verwenden :)
--------------
Blog www.freeblogger.org: Deutscher IRC-Channel: irc.freenode.net #drupal.de ... Jabber-me: dwehner@im.calug.de
SirFiChi ist auch dein Halbgott.

Das OG-;odul ist bei mir leider nicht im Einsatz.

Gibt es einen nicht zu umständlichen Weg zu gucken, was die ressourcenfressenden cache_set Methoden aufruft?

ich hatte ja eigentlich nicht dir geantwortet :)

Hast du wirklich bei jedem Page Request ein cache_set?

Könntest du mal mit dem Devel Modul die queries ausgeben.
Damit siehst du wovon die Funktion ausgeführt wird: Spalte "where"
--------------
Blog www.freeblogger.org: Deutscher IRC-Channel: irc.freenode.net #drupal.de ... Jabber-me: dwehner@im.calug.de
SirFiChi ist auch dein Halbgott.

3.17 1 locale_refresh_cache SELECT s.source, t.translation, t.locale FROM locales_source s INNER JOIN locales_target t ON s.lid = t.lid WHERE t.locale = 'de' AND LENGTH(s.source) < 75
0.82 3 db_lock_table LOCK TABLES cache WRITE
28.21 1 cache_set
0.12 6 db_unlock_tables UNLOCK TABLES
2.77 1 locale_refresh_cache SELECT s.source, t.translation, t.locale FROM locales_source s INNER JOIN locales_target t ON s.lid = t.lid WHERE t.locale = 'ru' AND LENGTH(s.source) < 75
0.3 3 db_lock_table LOCK TABLES cache WRITE
22.81 1 cache_set

Jetzt weiss ich zumindets schonmal, dass die "locale_refresh_cache" Methode böse ist
(Ich Depp hab die Abfragen stets nach Dauer und nicht nach Quelle sortiert)

Danke für den Hinweis. Ich hoffe, ich finde so eine Lösung.

PS.
Es kommt scheinbar bei jedem node Aufruf.

Ach ja, ich vergass.
Es handelt sich um Drupal 5.

---------------------------
Vielleicht bin ich ja ein Idiot, aber es liegt an
-
if (!$cache) {
watchdog("locale","DEBUG: CACHE IS OFF CALLING"); //von mir
locale_refresh_cache();
$cache = cache_get("locale:$locale", 'cache');
}
-

$cache ist also aus !?
Was sich auch mit meine Einstellungen deckt.
Der Cache ist aus (admin/settings/performance), da ich den Cache so verstanden habe, dass die Seiten quasi statisch in der DB gehalten werden. Da ich aber über ein verschiedene Module/Eigenetwicklungen auch für anonyme Benutzer spezifischen statischen Inhalt bereitstelle, dachte ich, dass das Caching Contraproduktiv wäre.

Evt sollte ich mir das nochmal anlesen.
---
Nachtrag:
$cache = cache_get("locale:$locale", 'cache');

=> SELECT data, created, headers, expire FROM cache WHERE cid = 'locale:'

liefert anscheinend ein leeres data zurück. Aber WARUM?

-----------------
Also entwede rist das n Bug oder ich hab mir das irgendwodurch kaputtoptimiert:
SELECT data, created, headers, expire FROM cache WHERE cid = 'locale:'

liefert nie etwas zurück, weil es keine Spalte gibt, wo cid='locale:' ist
wohl aber gibt es
'locale:de'
'locale:en'

mhhh
=> $locale ist "";
aber warum? eine Standardsprache ist gesetzt

Eine spätere Abfrage verriet mir grade, dass $locale sehr wohl gesetzt wird. nur eben später...

Scheint n Drupal Bug zu sein :D

----
FAZIT:
PATCH für das locale Modul:
function locale($string) {
global $locale;
static $locale_t;

+ if (empty($locale))
+ $locale = locale_initialize();

// Store database cached translations in a static var.
----
Ergebnis:
50-60 ms Zeitersparnis bei jeder Seite (das läppert sich!)

abstruß

global $local wird in http://api.drupal.org/api/function/_drupal_bootstrap_full/5 gesetzt und diese Funktion wird eigentlich immer aufgerufen.
--------------
Blog www.freeblogger.org: Deutscher IRC-Channel: irc.freenode.net #drupal.de ... Jabber-me: dwehner@im.calug.de
SirFiChi ist auch dein Halbgott.

"eigentlich", aber scheinbar nicht zwingend vor dem Aufruf von locale($string).

Vor dem initialisieren der $locale kommen ja ncoh einige andere Methoden.
Logisch, dass durch diese scheinbar irgendwo die locale() Funktion aufgerufen wird.
Nur weiss ich jetzt nicht, ob dieses Problem durch irgendwelche Module ( _module_load_all()?)
oder durch einen bestehenden Bug im Kern ausgelöst wird.

Wenn ich mal Zeit hab, werd ich mal ein taufrisches Drupal5 mit einer watchdog Ausgabe versehen, die mir an der bessagten Stelle den Inhalt der $locale ausgibt.
Da sich aber ein Problem des Threadstarters trotz den bei mir nicht genutzten OGs deckt, nehme ich fast an, dass es ein Kernbug von Version 5+6 ist.

Status:
zu bestätigen

das wäre heftig, und hätte eigentlich schon jemand bemerkt.

verwendest du sonstige Module?
--------------
Blog www.freeblogger.org: Deutscher IRC-Channel: irc.freenode.net #drupal.de ... Jabber-me: dwehner@im.calug.de
SirFiChi ist auch dein Halbgott.

Zu viele, um sie aufzuzählen ;)

Da gcuke ich mir lieber erstmal n nacktes frisches Drupal an und hoffe, dass der Fehler da auch aauftritt, denn wenn ncith freue ich mich auf eine fröhliche Suche in den Modulen

UPDATE:
zumindest bei einem nackten Drupal kommt der Fehler nicht vor.

Deshalb musste ich bei meiner Version weitergucken und bin bei dem Stand gelandet, dass vor der Initialisierung der $locale einmal die t()-Funktion aufgerufen wird:
Watchdog meldet mir bei einem entsprechenden Aufruf
"t() Empty locale: Role"
Wobei "Role" der aufgerufene String ist.

=> Nun ja, Role ist ja ein recht häufiges Drupal Wort und mit backtracing komm ich auch nur auf sowas wie:
"t() Called by Func: include_once"
juchhei

Also wenn jemand Tipps hat zum zurücklaufen der Aufrufe, immer her damit...

UPDATE
Nach dem guten alten Such-Mal-Nach Logik:
Methode: _drupal_bootstrap_full()
WARNUNG common 8 Jun 2009 - 20:38 4locale_initialize admin
Fehler Lokalisierung 8 Jun 2009 - 20:38 Empty locale admin
Warnung common 8 Jun 2009 - 20:38 3module_load_all admin

=> durch die Methode module_load_all();
wird also irgendwie, irgendwo t('Role') aufgerufen...
und weiter gehts...

Methode:

129 Now Loading autolocale admin
Empty locale admin
128 Now Loading autoassignrole
=> Böses autoassignrole

Zeile 9:
define("AUTOASSIGNROLE_ROLE_USER_TITLE", t("Role"));
das wirds wohl gewesen sein

schau mal auch nach

Damit wird auch jedes mal der Cache neu aufgebaut
--------------
Blog www.freeblogger.org: Deutscher IRC-Channel: irc.freenode.net #drupal.de ... Jabber-me: dwehner@im.calug.de
SirFiChi ist auch dein Halbgott.

s.h. http://drupal.org/node/485524
--------------
Blog www.freeblogger.org: Deutscher IRC-Channel: irc.freenode.net #drupal.de ... Jabber-me: dwehner@im.calug.de
SirFiChi ist auch dein Halbgott.

jepp, just nach meinem Post hier von mir dort eingetragen ;)

"Best Regards
Passer"

MfG
Passer

ups... dachte ich mir schon irgendwie ^^

der Patch ist ja nicht das Problem :)
--------------
Blog www.freeblogger.org: Deutscher IRC-Channel: irc.freenode.net #drupal.de ... Jabber-me: dwehner@im.calug.de
SirFiChi ist auch dein Halbgott.