Fatal Error bei Aufruf von Produkt-Listings

Hallo liebe Community,

ich habe in meinem Shopware Shop (aktuelle Version 5.4.2) seit gestern Vormittag plötzlich das Problem, dass alle Seiten mit Produkt-Listing (Kategorie-Seiten, Hersteller-Seite, Suchergebnisse) nicht mehr geladen werden (HTTP Error 500). Der Shop ist relativ neu, lief aber seit der Erstinbetriebnahme vor ca. 3 Monaten ohne Probleme.

Nicht vom Problem betroffen sind alle anderen Shopware-Seiten (Kundenbereich, Shopseiten, Formulare, Produktdetailseiten, Warenkorb, Checkout,…).
Es wurden seit ca. zwei Wochen weder Einstellungen verändert noch Plugins installiert oder ge-updated.

Nach „Aktivierung“ des Frontend Error Reporters erhalte ich folgende Meldung:

Fatal error : Uncaught RuntimeException: Could not connect to database. Message from SQL Server: SQLSTATE[HY000] [2002] Connection refused in /var/www/shop.linx.co.at/engine/Shopware/Components/DependencyInjection/Bridge/Db.php:78 Stack trace: #0 /var/www/shop.linx.co.at/engine/Shopware/Kernel.php(313): Shopware\Components\DependencyInjection\Bridge\Db::createPDO(Array) #1 /var/www/shop.linx.co.at/engine/Shopware/Components/HttpCache/AppCache.php(262): Shopware\Kernel->boot() #2 /var/www/shop.linx.co.at/vendor/symfony/http-kernel/HttpCache/HttpCache.php(443): Shopware\Components\HttpCache\AppCache->forward(Object(Symfony\Component\HttpFoundation\Request), true) #3 /var/www/shop.linx.co.at/vendor/symfony/http-kernel/HttpCache/HttpCache.php(339): Symfony\Component\HttpKernel\HttpCache\HttpCache->fetch(Object(Symfony\Component\HttpFoundation\Request), true) #4 /var/www/shop.linx.co.at/engine/Shopware/Components/HttpCache/AppCache.php(189): Symfony\Component\HttpKernel\HttpCache\HttpCache->lookup(Object(Symfony\Component\HttpF in  /var/www/shop.linx.co.at/engine/Shopware/Components/DependencyInjection/Bridge/Db.php  on line  78

Beziehungsweise zeitweise auch:

Fatal error : Uncaught PDOException: SQLSTATE[HY000]: General error: 2006 MySQL server has gone away in /var/www/shop.linx.co.at/vendor/doctrine/dbal/lib/Doctrine/DBAL/Connection.php:852 Stack trace: #0 /var/www/shop.linx.co.at/vendor/doctrine/dbal/lib/Doctrine/DBAL/Connection.php(852): PDO->query(‚SELECT template…‘) #1 /var/www/shop.linx.co.at/vendor/doctrine/dbal/lib/Doctrine/DBAL/Query/QueryBuilder.php(206): Doctrine\DBAL\Connection->executeQuery(‚SELECT template…‘, Array, Array) #2 /var/www/shop.linx.co.at/engine/Shopware/Components/Theme/Inheritance.php(502): Doctrine\DBAL\Query\QueryBuilder->execute() #3 /var/www/shop.linx.co.at/engine/Shopware/Components/Theme/Inheritance.php(239): Shopware\Components\Theme\Inheritance->fetchTemplates() #4 /var/www/shop.linx.co.at/engine/Shopware/Components/Theme/EventListener/ConfigLoader.php(81): Shopware\Components\Theme\Inheritance->getSmartyDirectories(Object(Shopware\Models\Shop\Template)) #5 /var/www/shop.linx.co.at/engine/Library/Enlight/Event/Handler/Default.php(91): Sh in  /var/www/shop.linx.co.at/vendor/doctrine/dbal/lib/Doctrine/DBAL/DBALException.php  on line  131

Fatal error : Uncaught PDOException: SQLSTATE[HY000]: General error: 2006 MySQL server has gone away in /var/www/shop.linx.co.at/engine/Shopware/Components/Session/PdoSessionHandler.php:343 Stack trace: #0 /var/www/shop.linx.co.at/engine/Shopware/Components/Session/PdoSessionHandler.php(343): PDOStatement->execute() #1 [internal function]: Shopware\Components\Session\PdoSessionHandler->write(‚f8c91e9890244b4…‘, ‚Shopware|a:8:{s…‘) #2 [internal function]: session_write_close() #3 {main} thrown in  /var/www/shop.linx.co.at/engine/Shopware/Components/Session/PdoSessionHandler.php  on line  343

 

Ein Fehler beim aufwärmen des HTTP Cache ist mir auch aufgefallen. Über die Console funktioniert dies einwandfrei. Führe ich das Aufwärmen aber manuell über das Backend durch, erhalte ich folgende Fehlermeldung:

    Fehler

    Indexierung fehlgeschlagen, weitere Informationen findest du im Log.
    500
    Internal Server Error

 

Ein Blick in die aktuellste /var/log/core_production-xxxx zeigt folgenden Fehler (nur ein kleiner Auszug):

[2018-05-04 00:15:11] core.ERROR: Read timed out after 3 seconds {„exception“:„[object] (Zend_Http_Client_Adapter_Exception(code: 1000): Read timed out after 3 seconds at /var/www/shop.linx.co.at/engine/Library/Zend/Http/Client/Adapter/Socket.php:495)“} {„uid“:„701d1a6“}
[2018-05-04 00:15:15] core.ERROR: Read timed out after 3 seconds {„exception“:„[object] (Zend_Http_Client_Adapter_Exception(code: 1000): Read timed out after 3 seconds at /var/www/shop.linx.co.at/engine/Library/Zend/Http/Client/Adapter/Socket.php:495)“} {„uid“:„701d1a6“}
[2018-05-04 00:15:15] core.ERROR: Reverse proxy returned invalid status code {„response“:"\n\n

\n\n\n\n



",„code“:503} {„uid“:„1f3642d“}
 

Was ich bereits versucht habe:

  • Alle Plugins einzeln deaktiviert, danach jeweils Cache (komplett) geleert und SEO-Index neu aufgebaut
  • MySQL thread_stack auf 256K erhöht, MySQL max_allowed_packet auf 32M erhöht
  • PHP.ini Werte erhöht (max_execution_time auf 300, max_input_vars auf 3000, memory_limit auf 512M)

Diese Schritte haben bis jetzt alle nichts gebracht. Ich hoffe, dass mir hier jemand weiterhelfen kann.

Sieht so aus, als ob der MySQL-Server instabil läuft. Schau’ am besten mal im MySQL-Error-Log nach; empfehlen würde ich auch, da0 Du mit mysqltuner schaust, ob Du die Konfiguration optimieren kannst.

Timme Hosting - schnelles nginx-Hosting

www.timmehosting.de

Hallo und danke für die schnelle Antwort :slight_smile:

Nachdem ich MySQLTuner installiert und über die InnoDB von Shopware laufen lassen habe erhalte ich folgendes Ergebnis:

[OK] Logged in using credentials from debian maintenance account.
 >>  MySQLTuner 1.6.0 - Major Hayden

>> Bug reports, feature requests, and downloads at http://mysqltuner.com/

>> Run with ‚–help‘ for additional options and output filtering

[–] Skipped version check for MySQLTuner script

[OK] Currently running supported MySQL version 5.7.22-0ubuntu0.16.04.1

[OK] Operating on 64-bit architecture

-------- Storage Engine Statistics -------------------------------------------
[–] Status: +ARCHIVE +BLACKHOLE +CSV -FEDERATED +InnoDB +MRG_MYISAM
[–] Data in InnoDB tables: 60M (Tables: 284)
[!!] Total fragmented tables: 12

-------- Security Recommendations  -------------------------------------------
[OK] There is no anonymous account in all database users
ERROR 1054 (42S22) at line 1: Unknown column ‚password‘ in ‚where clause‘
[OK] All database users have passwords assigned
ERROR 1054 (42S22) at line 1: Unknown column ‚password‘ in ‚where clause‘
[!!] User ‚shopwareadmin@%‘ hasn’t specific host restriction.
[–] There is 605 basic passwords in the list.
ERROR 1054 (42S22) at line 1: Unknown column ‚password‘ in ‚where clause‘
ERROR 1054 (42S22) at line 1: Unknown column ‚password‘ in ‚where clause‘
ERROR 1054 (42S22) at line 1: Unknown column ‚password‘ in ‚where clause‘
… -> Diese Fehlermeldung wiederholt sich ca. 600 (!!!) Mal

-------- Performance Metrics -------------------------------------------------
[–] Up for: 18m 57s (1K q [1.045 qps], 60 conn, TX: 12M, RX: 1M)
[–] Reads / Writes: 94% / 6%
[–] Binary logging is disabled
[–] Total buffers: 192.0M global + 1.1M per thread (151 max threads)
[OK] Maximum reached memory usage: 205.5M (0.64% of installed RAM)
[OK] Maximum possible memory usage: 361.9M (1.13% of installed RAM)
[OK] Slow queries: 0% (0/1K)
[OK] Highest usage of available connections: 7% (12/151)
[!!] Aborted connections: 3.33%  (2/60)
[!!] Query cache is disabled
[OK] Sorts requiring temporary tables: 0% (0 temp sorts / 84 sorts)
[!!] Joins performed without indexes: 148
[OK] Temporary tables created on disk: 3% (3 on disk / 83 total)
[OK] Thread cache hit rate: 76% (14 created / 60 connections)
[OK] Table cache hit rate: 67% (247 open / 367 opened)
[OK] Open file limit used: 0% (6/1K)
[OK] Table locks acquired immediately: 100% (100 immediate / 100 locks)

-------- MyISAM Metrics -----------------------------------------------------
[!!] Key buffer used: 18.2% (3M used / 16M cache)
[OK] Key buffer size / total MyISAM indexes: 16.0M/43.0K
[!!] Read Key buffer hit rate: 50.0% (6 cached / 3 reads)

-------- InnoDB Metrics -----------------------------------------------------
[–] InnoDB is enabled.
[OK] InnoDB buffer pool / data size: 128.0M/60.4M
[OK] InnoDB buffer pool instances: 1
[!!] InnoDB Used buffer: 13.86% (1135 used/ 8191 total)
[OK] InnoDB Read buffer efficiency: 99.22% (135037 hits/ 136096 total)
[!!] InnoDB Write buffer efficiency: 0.00% (0 hits/ 1 total)
[OK] InnoDB log waits: 0.00% (0 waits / 48 writes)

-------- AriaDB Metrics -----------------------------------------------------
[–] AriaDB is disabled.

-------- Replication Metrics -------------------------------------------------
[–] No replication slave(s) for this server.
[–] This is a standalone server…

-------- Recommendations -----------------------------------------------------
General recommendations:
    Run OPTIMIZE TABLE to defragment tables for better performance
    Restrict Host for user@% to user@SpecificDNSorIp
    MySQL started within last 24 hours - recommendations may be inaccurate
    Reduce or eliminate unclosed connections and network issues
    Adjust your join queries to always utilize indexes
Variables to adjust:
    query_cache_type (=1)
    join_buffer_size (> 256.0K, or always use indexes with joins)

Abgesehen von dem Fehler, der sich ca. 600 Mal wiederholt, gibt es hier einige Statusmeldungen mit Warnung. Leider kenne ich mich mit SQL nicht genügend aus, um hier etwas bestimmtes herauslesen zu können.

Ich habe zuerst einmal gleich die Datenbank optimieren lassen ( mysqlcheck -o ), und siehe da, der Fehler scheint (vorerst?!) einmal behoben.
Zur Sicherheit habe ich MySQLTuner noch einmal laufen lassen, einige der oben stehenden Warnhinweise sind immer noch vorhanden.

Bei den vorgeschlagenen Optimierungen ist sogar noch etwas dazu gekommen:

-------- Recommendations -----------------------------------------------------
General recommendations:
    Run OPTIMIZE TABLE to defragment tables for better performance
    Restrict Host for user@% to user@SpecificDNSorIp
    MySQL started within last 24 hours - recommendations may be inaccurate
    Adjust your join queries to always utilize indexes
    Increase table_open_cache gradually to avoid file descriptor limits
    Read this before increasing table_open_cache over 64: http://bit.ly/1mi7c4C
    Beware that open_files_limit (1024) variable
    should be greater than table_open_cache ( 431)

Variables to adjust:
    query_cache_type (=1)
    join_buffer_size (> 256.0K, or always use indexes with joins)
    table_open_cache (> 431)

Die Fett hervorgehobenen Werte werde ich auch noch überprüfen und den Shop die kommenden Tage beobachten, bevor ich ihn online schalte.

Ist deiner Meinung nach noch etwas dramatisches dabei? Wie gesagt, von den ganzen [!!] Warnmeldungen verstehe ich leider viele nicht ganz…

 

Danke und liebe Grüße,

Jürgen

Hi Jürgen,

mit den MySQLTuner Empfehlungen solltest Du vorsichtig sein - diese sind für reine Datenbank Server brauchbar - bei einem System, bei welchem auch noch Web und andere Dienste laufen, sind manche Empfehlungen möglicherweise sogar kontraproduktiv, da Du für die anderen Dienste keine System-Ressourcen mehr übrig hast.

Wenn Dein SQL Server instabil läuft, solltest Du zunächst Optimierungsparameter, die z.B. deutlich mehr RAM in Anspruch nehmen, wieder entfernen und danach prüfen, ob sich das System stabilisiert.

Gerne kannst Du auch mal Deine my.cnf posten - für Empfehlungen sind jedoch auch Angaben zum System (Hardware, Anzahl Kerne, RAM, usw.) hilfreich.

VG