MySQL Query Logging (M1+M2)

MySQL Query Logging (M1+M2)

Als aan een shop flink ontwikkeld is en/of de nodige extensies geïnstalleerd zijn, kan het gebeuren dat de Magento-frontend niet meer zo snel reageert als voorheen. De oorzaak hiervan moet vaak gezocht worden in onnodige MySQL-query’s.

Als de PHP-code en templates van Magento optimaal zijn ingericht, dan is het namelijk zo dat veel HTML-blokken gecachet kunnen worden. Als een bezoeker dan een pagina opvraagt, kunnen veel blokken uit de cache gehaald worden. Voor blokken uit de cache is het niet nodig de MySQL-database te raadplegen. Dat scheelt dus load op de databaseserver, en de pagina laadt veel sneller.


Een veelgemaakte fout is dat de menunavigatie niet uit de cache komt, terwijl er vrij zware MySQL-query’s nodig zijn om deze navigatie op te bouwen.

Hier gaan we uitleggen hoe je erachter kunt komen welke MySQL-query’s allemaal uitgevoerd worden om één pagina op te bouwen. Hiervoor heb je een omgeving nodig waar geen andere bezoekers zijn, dus bijvoorbeeld een staging-omgeving. We doen dit door de querylog tijdelijk aan te zetten.
We tonen de commando’s steeds als Linux shell-commando’s, maar je kunt het natuurlijk ook via je eigen tools doen. We gaan er steeds vanuit dat je start vanuit de basisdirectory van Magento.

Zet Query Logging aan in Magento 2.2 en hoger

  1. Voer uit in SSH, in de Magento 2 root:
    bin/magento --include-all-queries=true --include-call-stack=true dev:query-log:enable

Zet Query Logging aan in Magento 2.0 en 2.1

  1. Maak een backup van het bestand app/etc/di.xml
  2. Volg de instructies op https://devdocs.magento.com/guides/v2.1/config-guide/log/log-db.html
    In de rest van deze handleiding gebruiken we het bestand debug/pdo_mysql.log in plaats van log/db.log
  3. Wis de configuratie cache:
    bin/magento cache:clean config

Zet Query Logging aan in Magento 1

Voer nu achtereenvolgens deze stappen uit:

  1. Maak de directory app/code/local/Varien/Db/Adapter/Pdo
    mkdir -p app/code/local/Varien/Db/Adapter/Pdo
  2. Kopieer het bestand  lib/Varien/Db/Adapter/Pdo/Mysql.php naar  die directory
    cp lib/Varien/Db/Adapter/Pdo/Mysql.php app/code/local/Varien/Db/Adapter/Pdo/
  3. Open de kopie van het bestand in een text editor
    nano app/code/local/Varien/Db/Adapter/Pdo/Mysql.php
  4. Pas de volgende regels aan, bovenaan in het bestand
    protected $_debug = true;
    protected $_logAllQueries = true;
    protected $_logCallStack = true;

Lees de log

  1. In Magento 1 heet het log bestand var/debug/pdo_mysql.log in Magento 2 is het var/debug/db.log
  2. Ga met je browser naar een pagina in de shop in deze (staging)omgeving die traag is, ververs de pagina nog eens voor de zekerheid door in de URL balk van je browser te klikken en op Enter te duwen. Laat je browser openstaan.
  3. Verwijder het bestand var/debug/pdo_mysql.log. Nu de pagina een keer geladen is, en veel blokken gecachet zouden moeten zijn, gaan we met een schone querylog beginnen.
    rm var/debug/db.log
  4. Klik in je browser nog een keer op de adresbalk, en druk één keer op Enter.
  5. Nu kunnen we het bestand bekijken in een teksteditor
    nano var/debug/pdo_mysql.log

In het bestand vind je blokken met steeds achtereenvolgens deze informatie:

## 201X-XX-XX XX:XX:XX = De datum en tijd van query
## 3890 ## QUERY
TIME: 0.1234           = De benodigde tijd om deze query uit te voeren, in seconden.
TRACE: #1 Varien_Db_.. = Door welke bestand de code was uitgevoerd, meerdere regels.

De eerste paar blokken hebben te maken met het leggen van de verbinding met de MySQL-server; dit zou maar enkele honderdsten van seconden mogen duren.
Daarna wordt het interessanter. Richt je eerst op de blokken waarbij de benodigde tijd hoog is, bijvoorbeeld meer dan 1 seconde. De TRACE staat eigenlijk in omgekeerde volgorde. De laatste trace-regel van het blok is het opstarten van Magento, en van onder naar boven ga je dan steeds dieper de code in. De eerste twee regels van de TRACE zijn van de Database Adapter die de query daadwerkelijk uitvoert. Aan het einde van de trace-regels staan steeds de bestandsnaam en het regelnummer. Van onder naar boven wordt dus steeds een nieuw bestand of functie aangeroepen. Probeer uit te vinden waarom de query wordt uitgevoerd en wat je moet doen om te zorgen dat het niet elke keer opnieuw hoeft te gebeuren, bijvoorbeeld het verbeteren van de block caching. Sommige SQL-query’s zijn misschien ook totaal overbodig, of worden gedaan door extensies die op die plek eigenlijk niet nodig zijn.

Als je iets verbeterd hebt, voer dan stappen van “Lees de Log” opnieuw uit, en kijk of je verschillen ziet.
Als je klaar ben met je onderzoek naar de SQL-query’s, vergeet dan niet om de Query Logging weer uit te zetten:

Query Logging uitzetten – Magento 2.2 en hoger

  1. Voer uit in SSH, in de Magento 2 root:
    bin/magento dev:query-log:disable
    rm var/debug/db.log

De volgende keer dat je weer de query’s wilt bekijken, moet je de handleiding weer vanaf het begin volgen.

Query Logging uitzetten – Magento 2.0 en 2.1

  1. Zet je backup van het bestand app/etc/di.xml terug.
  2. Wis de configuratie cache:
    bin/magento cache:clean config
    rm var/debug/db.log

De volgende keer dat je weer de query’s wilt bekijken, moet je de handleiding weer vanaf het begin volgen.

Query Logging uitzetten – Magento 1

  1. Gooi dan het aangepaste PHP-bestand en de log weg:
    rm app/code/local/Varien/Db/Adapter/Pdo/Mysql.php
    rm var/debug/pdo_mysql.log

De volgende keer dat je weer de query’s wilt bekijken, moet je de handleiding weer vanaf het begin volgen.

 

Over de auteur
Jeroen Vermeulen
Jeroen heeft bij gerenommeerde hostingbedrijven en tijdens opleidingen en cursussen een zeer gedegen kennis opgedaan van hosting, Magento, de techniek en alles wat er verder bij komt kijken. De afgelopen jaren heeft hij zich met veel succes bewezen als één van de top-Magento-programmeurs van de Benelux en hij geniet dan ook een aanzienlijke bekendheid op dat vlak.