Vor längerer Zeit rief mich ein businessaffiner Herr an, dessen (nicht von mir in die Welt gesetzter oder betreuter) Magento-Shop mit der Och-Nö-Report-Zahl auf altbackenem Original-Template aufwartete mit der Bitte, den Shop zu reparieren. Als ich 1-2 Stunden ansetzte, um mir den Fehler anzusehen (und ihn ggf. auch in dieser Zeit auch zu beheben), fragte er, wo denn da sein „Benefit“ sei. Im Weiteren kam noch der Begriff „Approach“ vor und das Deutlichmachen, dass er mich nur für das Fehlerausmerzen, nicht für das Fehlerfinden bezahlen wolle, denn wo kämen wir denn da hin… Ich finde, ich habe einige Karmapunkte verdient, weil ich so freundlich war, das Gespräch noch mit Grußformel zu beenden.

Zum Thema Fehlerfinden möchte ich daher eine Geschichte aus einem anderen Shop (mit einer sehr netten Shopbetreiberin) erzählen.

Die Geschichte der Fehlermeldung:

Warning: simplexml_load_string(): Entity: line 84: parser error : StartTag: invalid element name in /lib/Varien/Simplexml/Config.php on line 383

Dieser Fehler trat auf, nachdem der Cache aktiviert wurde – und brachte das Magento Fehler-Log-File in kürzester Zeit auf eine beachtliche Dateigröße.

Soso. lib/Varien/Simplexml… und simplexml_load_string. Kann ja nicht so schwer sein. Invalides XML. Das ist auffindbar.

Also ab in die XML-Files von Magento, auf der Suche nach dem Bösewicht. Überraschung: alle XML-Dateien sind in Ordnung. Nicht immer hübsch, aber fehlerfrei.

Hm.

Also doch mal die Klasse ansehen, die den Fehler protokolliert. In der Zeile 383 geht es um den Cache… Der ist zu diesem Zeitpunkt schon geschrieben worden, denn beim Aktualisieren oder Neuerstellen des Caches tritt der Fehler nicht auf, erst wenn man eine Seite des Shops lädt.

In Zeile 383 passiert dieses (man beachte den netten Doku-Kommentar, dessen Aufforderung man glatt nachgehen möchte…):

Okay. Fehler tritt also auf, wenn XML aus dem Cache geladen wird – und validiert wird in simplexml_load_string().

Nun hat der Magento-Cache ja allerlei Dateien und ich möchte gerne wissen, welcher problematisch ist.

Also in den Core-Code einen Log schreiben, Cache leeren, Seite laden und ganz schnell wieder rückgängig machen:

Und dann steht folgendes im Log:

2015-06-12T06:50:21+00:00 DEBUG (7): ********************************* config_global
2015-06-12T06:50:21+00:00 ERR (3): Warning: simplexml_load_string(): Entity: line 84: parser error : StartTag: invalid element name  in /lib/Varien/Simplexml/Config.php on line 384
2015-06-12T06:50:21+00:00 ERR (3): Warning: simplexml_load_string(): 1</dimension_spec><thumb_upload_resize>0</thumb_upload_resize></general><image><  in /lib/Varien/Simplexml/Config.php on line 384
2015-06-12T06:50:21+00:00 ERR (3): Warning: simplexml_load_string():                                                                                ^  in /lib/Varien/Simplexml/Config.php on line 384
2015-06-12T06:50:22+00:00 DEBUG (7): ********************************* config_theme

Also suchen nach dem dem Cache „config_global“…

Fein. Datei öffnen und validieren. Dahaaa:

Irgendein Modul verwendet im Path eine Zahl – wahrscheinlich in Unkenntnis, dass aus diesem Path XML gebildet wird oder in Unkenntnis, dass XML nunmal keine Zahlen und Sonderzeichen als Tags erlaubt.

Die fantastische Suche von PHPStorm nach dem Knoten, der den Fehler auslöst, war erfolglos. Also muss, da ja auch Konfigurationsdaten aus der core_config_data-Tabelle eingesammelt werden, dort der Fehler zu finden zu sein. Vielleicht ein altes Modul, dessen config-Dateien gelöscht wurden. Hm.

Mit folgendem MySQL-Befehl findet man alle Einträge in der path-Spalte der core_config_data-Tabelle, in denen eine Zahl vorkommt.

SELECT * FROM core_config_data WHERE path REGEXP '[0-9]+'

Und hier finden sich dann path-Werte, die nett gemeint, aber nicht durchdacht sind, so z.B. ‚manufacturers/image/13‘.

Da ich doch neugierig war, wie die dahin gekommen sind, bin ich fündig geworden in Projektdateien, die nicht im PHPStorm-Projekt lagen. Das Template hat Sample-Daten mitinstalliert – und diese Inserts waren in der sample-data.sql zu finden.

INSERT INTO `#__core_config_data` (`config_id`, `scope`, `scope_id`, `path`, `value`) VALUES
....
(111, 'default', 0, 'manufacturers/image/13', 'manufacturers/manuf1.jpg'),
(112, 'default', 0, 'manufacturers/image/10', 'manufacturers/manuf2.jpg'),
(113, 'default', 0, 'manufacturers/image/14', 'manufacturers/manuf3.jpg'),
(114, 'default', 0, 'manufacturers/image/11', 'manufacturers/manuf4.jpg'),
(115, 'default', 0, 'manufacturers/image/12', 'manufacturers/manuf5.jpg'),
(116, 'default', 0, 'manufacturers/image/9', 'manufacturers/manuf6.jpg'),
(117, 'default', 0, 'manufacturers/general/attr_code', 'manufacturer'),
(118, 'default', 0, 'manufacturers/general/thumb_w', '179'),
(119, 'default', 0, 'manufacturers/general/thumb_h', '168'),
(120, 'default', 0, 'manufacturers/general/dimension_spec', '1'),
(121, 'default', 0, 'manufacturers/general/thumb_upload_resize', '0'),
(122, 'default', 0, 'manufacturers/image/15', 'manufacturers/manuf1.jpg'),
(123, 'default', 0, 'manufacturers/image/16', 'manufacturers/manuf2.jpg'),
(124, 'default', 0, 'manufacturers/image/17', 'manufacturers/manuf3.jpg');

Und die Moral von der Geschicht: traue fertigen Templates nicht.

Und die Erkenntnis: Magento validiert den Cache nicht beim Erstellen. Wieder was gelernt.

Nun hat das Entfernen der fehlerhaften Datenbankeinträge ein paar Sekunden gedauert. Nach Ansicht des werten Herrn aus dem Eingangssatz hätte ich also eine Minute Arbeitszeit in Rechnung stellen können.

Der werte Herr war im Übrigen kein Einzelfall. Und in meinem E-Mail-Ordner „Anfragen“ gibt es auch einen Ordner namens „Anfragen/lustig“. Und dort findet sich eine Anfrage von einem anderen Herrn, der allerlei Erweiterungen in seinem (nicht von mir in die Welt gesetzten oder betreuten) Shop installiert hatte, so dass jetzt an allerlei Stellen allerlei Dinge nicht so funktionierten, wie sie sollten. Auch hier habe ich von „Bug-Suche nach Aufwand“ gesprochen, die man erstmal auf X Std. begrenzen kann. Drauf er: „Eigentlich wollte ich ein Angebot für eine Fehlerbehebung und nicht für die Suche.“ Und außerdem: „Ich dachte Sie wären Entwicklerin und tiefer im Thema drin. Dieses Suchen und Probieren ist genau die Art von Lösung, die ich nicht suche. Das führt zu keinem Ergebnis. Trotzdem danke.“. Bitteschön… (Unnötig zu erwähnen, dass die Fehler bis heute nicht behoben sind…).

Und ein Dank an dieser Stelle für alle freundlichen und wertschätzenden Menschen, die Bug-Suchen-nach-Aufwand ganz sicher auch nicht mögen, aber die zusammengebissenen Zähne nicht an mir auslassen.