When working with Magento 2, sections of code are often processed unexpectedly. When this happens, developers need to understand the reason for the error and fix it.
Log files are convenient for debugging. In most cases, they help you quickly determine the cause of the error and fix it. In this article, we will examine the types of log files and the specifics of working with them.
Using Logs: Magento 2 Live Site Example
Let’s assume we’re working with a site on Magento 2 that is in production mode (the main “live” mode of Magento 2 sites) and is running on a UNIX-like OS.
Types of Logs
There are two types of logs available to developers: information logs and error logs. An information log can hold information a developer needs for debugging, while error logs hold information about runtime errors. The main information log is saved in your Magento 2 directory: var/log/system.log.
Types of Errors
There are three types of errors:
- handled exceptions,
- non-handled exceptions, and
- fatal runtime errors.
We will consider each of these error types.
Magento 2 has a Psr logging library that implements embedded logging. To log something, you simply have to call the interface Psr\Log\LoggerInterface, which will be implemented using dependency injection of the class Magento\Framework\Logger\Monolog (the dependency is defined in the global app/etc/di.xml).
The interface declares several logging methods, and the class implements them. These methods differ only in terms of the additional information about critical messages shown in the log. The models inherited from AbstractModel, block collections, and helpers have a protected _logger property that can be used for logging. For all remaining classes, you can log using dependency injection in the constructor or using ObjectManager. In the examples below, we will assume that the class has _logger property.
The Principles of Magento Logging
Logging is simple. You just need to call $this->_logger->info(param), where param is some scalar variable that will be logged in the file var/log/system.log.
Calling the error or critical methods will write a scalar variable to this same file. If you pass an object of the class inherited from \Exception as a parameter, then the error will be logged in the file var/log/exception.log. In versions 2.0 and 2.1, the exception’s full trace was recorded to this file, making it possible to easily determine the location of the error and a way to fix it. But starting in version 2.2, only the exception message and the place where it was thrown are recorded.
To get the trace, you need to write $this->_logger->critical($e->_toString());, but the error and trace will be recorded in the file var/log/system.log. Nevertheless, this is convenient when you need to determine the full path to the location where the error occurred and also determine the current values of various parameters in order to understand the reason for the error. Exceptions can only be logged in the catch block of the construct.
try{
..}
catch(\Exception $e){
$this->_logger->critical($e->__toString());
..}.If the developer didn’t use exception handling, then sometimes this handling is already implemented at the core level, in particular when outputting blocks.
When an exception occurs when a block’s content is generated, the block will not be displayed, and a message about the error will be displayed in the file var/log/exception.log. Otherwise, if the exception is intercepted by a top-level handler, the server will return an error and the exception will be logged in a separate file in the directory var/report. If the error occurred when processing an API request, the error will be logged in a separate file in the directory var/report/api.
The cases above considered errors that Magento could process. But if a fatal error occurs when executing code, Magento will not be able to process it, and the error will go to the Web server log. Next, we will look at examples of fatal errors, where they appear, and why they appear.
Fatal Errors and the Reasons Behind Them
By default, these files are located in the server’s /var/log directory, with the rest of the path determined by the type of server (Apache, NGINX, PHP-FPM) and configuration features. On live servers (and others) developers often do not have the data in these directories for security reasons, or the server administrator may redirect logging of fatal errors to other files, which will be available. This is often done if several virtual hosts are implemented on one physical server and access to the hosts is limited to certain users.
Sometimes this log is available in Cpanel, if it is supported by the hosting. Since these errors are fatal, the HTTP request will return a 50x error. These types of errors can occur at the PHP level; they can be caused by insufficient memory allotted to runtime or insufficient disk space; and they can also occur at the Apache or NGINX level. One common error of this kind at the NGINX level is be caused by a connection timeout or buffer overflow, which can only be resolved by changing NGINX settings.
There are often redirect errors at the server level as well, which return 404 server errors. There are other types of 40x errors as well, such as transferring more to POST than the server can handle, but that’s a separate topic.
Let’s summarize what we’ve gone over so far.
- If the executed code isn’t working as expected, you should first check the Magento logs. More often than not, it’s easy to establish the reason for the error from these logs.
- If requests to the server return 40x or 50x errors, you should check the var/report directory and the Web server log, if possible.
- When debugging code, log critical variables and check their values.
- If existing core code isn’t writing all the necessary information to the log (this usually has to do with error handling) then when you are debugging and finding out the reason for the error, you can temporarily add logging. Don’t forget to roll back changes to the core, returning it to its original state after debugging.
- In some cases, logs are the only available means of debugging. For example, cron jobs, API requests, and payment methods can usually only be debugged using logs.
- Keep in mind that logs have the tendency to grow, so don’t forget to periodically delete old Magento log files. The automatic deletion of global logs after a certain period of time is usually configured on servers.
- Don’t forget to remove logging of safety-critical information from the code after debugging. This usually pertains to credit card information, but it could be other information as well.
Useful for you:
Real Examples of Using Logs for Debugging
1. Optimizing a site that has seen a sharp increase in front-end page load speeds after upgrading to version 2.3.
This may be caused by conflicts between obsolete site modules and the new core version of Magento. There is speculation that the problem may be related to the generation of a menu in a custom extension. The menu displays categories and uses flat tables. When researching, you were able to establish that category information is received in the _loadNodes method of the \Magento\Catalog\Model\ResourceModel\Category\Flat class.
The method looks as follows:
protected function _loadNodes($parentNode = null, $recursionLevel = 0, $storeId = 0, $skipMenuFilter = false)
{
$_conn = $this->getConnection();
$startLevel = 1;
$parentPath = '';
if ($parentNode instanceof \Magento\Catalog\Model\Category) {
$parentPath = $parentNode->getPath();
$startLevel = $parentNode->getLevel();
} elseif (is_numeric($parentNode)) {
$selectParent = $_conn->select()->from(
$this->getMainStoreTable($storeId)
)->where(
'entity_id = ?',
$parentNode
)->where(
'store_id = ?',
$storeId
);
$parentNode = $_conn->fetchRow($selectParent);
if ($parentNode) {
$parentPath = $parentNode['path'];
$startLevel = $parentNode['level'];
}
}
$select = $_conn->select()->from(
['main_table' => $this->getMainStoreTable($storeId)],
[
'entity_id',
new \Zend_Db_Expr('main_table.' . $_conn->quoteIdentifier('name')),
new \Zend_Db_Expr('main_table.' . $_conn->quoteIdentifier('path')),
'is_active',
'is_anchor'
]
)->joinLeft(
['url_rewrite' => $this->getTable('url_rewrite')],
'url_rewrite.entity_id = main_table.entity_id AND url_rewrite.is_autogenerated = 1'
. $_conn->quoteInto(' AND url_rewrite.store_id = ?', $storeId)
. $_conn->quoteInto(' AND url_rewrite.entity_type = ?', CategoryUrlRewriteGenerator::ENTITY_TYPE),
['request_path' => 'url_rewrite.request_path']
)->where('main_table.is_active = 1');
if (false == $skipMenuFilter) {
$select->where('main_table.include_in_menu = ?', '1');
}
$select->order('main_table.position');
if ($parentPath) {
$select->where($_conn->quoteInto("main_table.path like ?", "{$parentPath}/%"));
}
if ($recursionLevel != 0) {
$levelField = $_conn->quoteIdentifier('level');
$select->where($levelField . ' <= ?', $startLevel $recursionLevel);
}
$inactiveCategories = $this->getInactiveCategoryIds();
if (!empty($inactiveCategories)) {
$select->where('main_table.entity_id NOT IN (?)', $inactiveCategories);
}
// Allow extensions to modify select (e.g. add custom category attributes to select)
$this->_eventManager->dispatch('catalog_category_flat_loadnodes_before', ['select' => $select]);
$arrNodes = $_conn->fetchAll($select);
$nodes = [];
foreach ($arrNodes as $node) {
$node['id'] = $node['entity_id'];
$nodes[$node['id']] = $this->_categoryFactory->create()->setData($node);
}
return $nodes;
}Since we need to get the request for debugging and optimization, we can modify this method:
protected function _loadNodes($parentNode = null, $recursionLevel = 0, $storeId = 0, $skipMenuFilter = false)
{
$_conn = $this->getConnection();
$startLevel = 1;
$parentPath = '';
if ($parentNode instanceof \Magento\Catalog\Model\Category) {
$parentPath = $parentNode->getPath();
$startLevel = $parentNode->getLevel();
} elseif (is_numeric($parentNode)) {
$selectParent = $_conn->select()->from(
$this->getMainStoreTable($storeId)
)->where(
'entity_id = ?',
$parentNode
)->where(
'store_id = ?',
$storeId
);
$parentNode = $_conn->fetchRow($selectParent);
if ($parentNode) {
$parentPath = $parentNode['path'];
$startLevel = $parentNode['level'];
}
}
$select = $_conn->select()->from(
['main_table' => $this->getMainStoreTable($storeId)],
[
'entity_id',
new \Zend_Db_Expr('main_table.' . $_conn->quoteIdentifier('name')),
new \Zend_Db_Expr('main_table.' . $_conn->quoteIdentifier('path')),
'is_active',
'is_anchor'
]
)->joinLeft(
['url_rewrite' => $this->getTable('url_rewrite')],
'url_rewrite.entity_id = main_table.entity_id AND url_rewrite.is_autogenerated = 1'
. $_conn->quoteInto(' AND url_rewrite.store_id = ?', $storeId)
. $_conn->quoteInto(' AND url_rewrite.entity_type = ?', CategoryUrlRewriteGenerator::ENTITY_TYPE),
['request_path' => 'url_rewrite.request_path']
)->where('main_table.is_active = 1');
if (false == $skipMenuFilter) {
$select->where('main_table.include_in_menu = ?', '1');
}
$select->order('main_table.position');
if ($parentPath) {
$select->where($_conn->quoteInto("main_table.path like ?", "{$parentPath}/%"));
}
if ($recursionLevel != 0) {
$levelField = $_conn->quoteIdentifier('level');
$select->where($levelField . ' <= ?', $startLevel $recursionLevel);
}
$inactiveCategories = $this->getInactiveCategoryIds();
if (!empty($inactiveCategories)) {
$select->where('main_table.entity_id NOT IN (?)', $inactiveCategories);
}
// Allow extensions to modify select (e.g. add custom category attributes to select)
$this->_eventManager->dispatch('catalog_category_flat_loadnodes_before', ['select' => $select]);
$logger = \Magento\Framework\App\ObjectManager::getInstance()->get('Psr\Log\LoggerInterface');
$logger->info($select->__toString());
$arrNodes = $_conn->fetchAll($select);
$nodes = [];
foreach ($arrNodes as $node) {
$node['id'] = $node['entity_id'];
$nodes[$node['id']] = $this->_categoryFactory->create()->setData($node);
}
return $nodes;
}Then, after loading the page without the cache in the var/log/system.log file, we see the following message:
[2019-02-04 15:20:25] main.INFO: SELECT `main_table`.`entity_id`, main_table.`name`, main_table.`path`, `main_table`.`is_active`, `main_table`.`is_anchor`, `url_rewrite`.`request_path` FROM `catalog_category_flat_store_1` AS `main_table`
LEFT JOIN `url_rewrite` ON url_rewrite.entity_id = main_table.entity_id AND url_rewrite.is_autogenerated = 1 AND url_rewrite.store_id = ‘1’ AND url_rewrite.entity_type = ‘category’ WHERE (main_table.is_active = 1) AND (main_table.include_in_menu = ‘1’) AND (main_table.path like ‘1/71/%’) ORDER BY `main_table`.`position` ASC
We received a request in the message that we can optimize. If we need to get back-trace, we can get it as follows:
View code:
[2019-02-04 17:43:29] main.ERROR: Exception: SELECT `main_table`.`entity_id`, main_table.`name`, main_table.`path`, `main_table`.`is_active`, `main_table`.`is_anchor`, `url_rewrite`.`request_path` FROM `catalog_category_flat_store_1` AS `main_table`
LEFT JOIN `url_rewrite` ON url_rewrite.entity_id = main_table.entity_id AND url_rewrite.is_autogenerated = 1 AND url_rewrite.store_id = '1' AND url_rewrite.entity_type = 'category' WHERE (main_table.is_active = 1) AND (main_table.include_in_menu = '1') AND (main_table.path like '1/71/%') ORDER BY `main_table`.`position` ASC
in /var/www/toshno/vendor/magento/module-catalog/Model/ResourceModel/Category/Flat.php:304
Stack trace:
#0 /var/www/toshno/vendor/magento/module-catalog/Model/ResourceModel/Category/Flat.php(376): Magento\Catalog\Model\ResourceModel\Category\Flat->_loadNodes(Object(Magento\Catalog\Model\Category\Interceptor), 0, '1')
#1 /var/www/toshno/vendor/magento/module-catalog/Model/ResourceModel/Category/Flat.php(433): Magento\Catalog\Model\ResourceModel\Category\Flat->getNodes('71', 0, '1')
#2 /var/www/toshno/vendor/magento/module-catalog/Model/Category.php(970): Magento\Catalog\Model\ResourceModel\Category\Flat->getCategories('71', 0, true, false, true)
#3 /var/www/toshno/generated/code/Magento/Catalog/Model/Category/Interceptor.php(466): Magento\Catalog\Model\Category->getCategories('71', 0, true, false, true)
#4 /var/www/toshno/vendor/magento/module-catalog/Helper/Category.php(115): Magento\Catalog\Model\Category\Interceptor->getCategories('71', 0, true, false, true)
#5 /var/www/toshno/app/code/Magentice/Megamenu/Block/Topmenu.php(60): Magento\Catalog\Helper\Category->getStoreCategories(true, false, true)
#6 /var/www/toshno/app/code/Magentice/Megamenu/Block/Topmenu.php(192): Magentice\Megamenu\Block\Topmenu->getStoreCategories(true, false, true)
#7 /var/www/toshno/app/design/frontend/Magentice/enhanced/Magentice_Megamenu/templates/topmenu.phtml(25): Magentice\Megamenu\Block\Topmenu->getMegamenuHtml()
#8 /var/www/toshno/vendor/magento/framework/View/TemplateEngine/Php.php(59): include('/var/www/toshno...')
#9 /var/www/toshno/vendor/magento/framework/View/Element/Template.php(271): Magento\Framework\View\TemplateEngine\Php->render(Object(Magentice\Megamenu\Block\Topmenu), '/var/www/toshno...', Array)
#10 /var/www/toshno/vendor/magento/framework/View/Element/Template.php(301): Magento\Framework\View\Element\Template->fetchView('/var/www/toshno...')
#11 /var/www/toshno/vendor/magento/framework/View/Element/AbstractBlock.php(668): Magento\Framework\View\Element\Template->_toHtml()
#12 /var/www/toshno/vendor/magento/framework/View/Layout.php(557): Magento\Framework\View\Element\AbstractBlock->toHtml()
#13 /var/www/toshno/vendor/magento/framework/View/Layout.php(533): Magento\Framework\View\Layout->_renderBlock('mg.topnav')
#14 /var/www/toshno/generated/code/Magento/Framework/View/Layout/Interceptor.php(206): Magento\Framework\View\Layout->renderNonCachedElement('mg.topnav')
#15 /var/www/toshno/vendor/magento/framework/View/Layout.php(488): Magento\Framework\View\Layout\Interceptor->renderNonCachedElement('mg.topnav')
#16 /var/www/toshno/generated/code/Magento/Framework/View/Layout/Interceptor.php(193): Magento\Framework\View\Layout->renderElement('mg.topnav', true)
#17 /var/www/toshno/vendor/magento/framework/View/Element/AbstractBlock.php(512): Magento\Framework\View\Layout\Interceptor->renderElement('mg.topnav', true)
#18 /var/www/toshno/vendor/magento/module-theme/view/frontend/templates/html/container.phtml(10): Magento\Framework\View\Element\AbstractBlock->getChildHtml()
#19 /var/www/toshno/vendor/magento/framework/View/TemplateEngine/Php.php(59): include('/var/www/toshno...')
#20 /var/www/toshno/vendor/magento/framework/View/Element/Template.php(271): Magento\Framework\View\TemplateEngine\Php->render(Object(Magento\Framework\View\Element\Template), '/var/www/toshno...', Array)
#21 /var/www/toshno/vendor/magento/framework/View/Element/Template.php(301): Magento\Framework\View\Element\Template->fetchView('/var/www/toshno...')
#22 /var/www/toshno/vendor/magento/framework/View/Element/AbstractBlock.php(668): Magento\Framework\View\Element\Template->_toHtml()
#23 /var/www/toshno/vendor/magento/framework/View/Layout.php(557): Magento\Framework\View\Element\AbstractBlock->toHtml()
#24 /var/www/toshno/vendor/magento/framework/View/Layout.php(533): Magento\Framework\View\Layout->_renderBlock('store.menu')
#25 /var/www/toshno/generated/code/Magento/Framework/View/Layout/Interceptor.php(206): Magento\Framework\View\Layout->renderNonCachedElement('store.menu')
#26 /var/www/toshno/vendor/magento/framework/View/Layout.php(488): Magento\Framework\View\Layout\Interceptor->renderNonCachedElement('store.menu')
#27 /var/www/toshno/generated/code/Magento/Framework/View/Layout/Interceptor.php(193): Magento\Framework\View\Layout->renderElement('store.menu', true)
#28 /var/www/toshno/vendor/magento/module-theme/view/frontend/templates/html/sections.phtml(26): Magento\Framework\View\Layout\Interceptor->renderElement('store.menu')
#29 /var/www/toshno/vendor/magento/framework/View/TemplateEngine/Php.php(59): include('/var/www/toshno...')
#30 /var/www/toshno/vendor/magento/framework/View/Element/Template.php(271): Magento\Framework\View\TemplateEngine\Php->render(Object(Magento\Framework\View\Element\Template), '/var/www/toshno...', Array)
#31 /var/www/toshno/vendor/magento/framework/View/Element/Template.php(301): Magento\Framework\View\Element\Template->fetchView('/var/www/toshno...')
#32 /var/www/toshno/vendor/magento/framework/View/Element/AbstractBlock.php(668): Magento\Framework\View\Element\Template->_toHtml()
#33 /var/www/toshno/vendor/magento/framework/View/Layout.php(557): Magento\Framework\View\Element\AbstractBlock->toHtml()
#34 /var/www/toshno/vendor/magento/framework/View/Layout.php(533): Magento\Framework\View\Layout->_renderBlock('navigation.sect...')
#35 /var/www/toshno/generated/code/Magento/Framework/View/Layout/Interceptor.php(206): Magento\Framework\View\Layout->renderNonCachedElement('navigation.sect...')
#36 /var/www/toshno/vendor/magento/framework/View/Layout.php(488): Magento\Framework\View\Layout\Interceptor->renderNonCachedElement('navigation.sect...')
#37 /var/www/toshno/generated/code/Magento/Framework/View/Layout/Interceptor.php(193): Magento\Framework\View\Layout->renderElement('navigation.sect...', true)
#38 /var/www/toshno/vendor/magento/framework/View/Element/AbstractBlock.php(508): Magento\Framework\View\Layout\Interceptor->renderElement('navigation.sect...', true)
#39 [internal function]: Magento\Framework\View\Element\AbstractBlock->getChildHtml('navigation.sect...')
#40 /var/www/toshno/vendor/magento/framework/View/TemplateEngine/Php.php(82): call_user_func_array(Array, Array)
#41 /var/www/toshno/app/design/frontend/Magentice/enhanced/Magentice_Enhanced/templates/html/header.phtml(357): Magento\Framework\View\TemplateEngine\Php->__call('getChildHtml', Array)
#42 /var/www/toshno/vendor/magento/framework/View/TemplateEngine/Php.php(59): include('/var/www/toshno...')
#43 /var/www/toshno/vendor/magento/framework/View/Element/Template.php(271): Magento\Framework\View\TemplateEngine\Php->render(Object(Magentice\Enhanced\Block\Template), '/var/www/toshno...', Array)
#44 /var/www/toshno/vendor/magento/framework/View/Element/Template.php(301): Magento\Framework\View\Element\Template->fetchView('/var/www/toshno...')
#45 /var/www/toshno/vendor/magento/framework/View/Element/AbstractBlock.php(668): Magento\Framework\View\Element\Template->_toHtml()
#46 /var/www/toshno/vendor/magento/framework/View/Layout.php(557): Magento\Framework\View\Element\AbstractBlock->toHtml()
#47 /var/www/toshno/vendor/magento/framework/View/Layout.php(533): Magento\Framework\View\Layout->_renderBlock('enhanced_header')
#48 /var/www/toshno/generated/code/Magento/Framework/View/Layout/Interceptor.php(206): Magento\Framework\View\Layout->renderNonCachedElement('enhanced_header')
#49 /var/www/toshno/vendor/magento/framework/View/Layout.php(488): Magento\Framework\View\Layout\Interceptor->renderNonCachedElement('enhanced_header')
#50 /var/www/toshno/generated/code/Magento/Framework/View/Layout/Interceptor.php(193): Magento\Framework\View\Layout->renderElement('enhanced_header', false)
#51 /var/www/toshno/vendor/magento/framework/View/Layout.php(585): Magento\Framework\View\Layout\Interceptor->renderElement('enhanced_header', false)
#52 /var/www/toshno/vendor/magento/framework/View/Layout.php(535): Magento\Framework\View\Layout->_renderContainer('page.wrapper', false)
#53 /var/www/toshno/generated/code/Magento/Framework/View/Layout/Interceptor.php(206): Magento\Framework\View\Layout->renderNonCachedElement('page.wrapper')
#54 /var/www/toshno/vendor/magento/framework/View/Layout.php(488): Magento\Framework\View\Layout\Interceptor->renderNonCachedElement('page.wrapper')
#55 /var/www/toshno/generated/code/Magento/Framework/View/Layout/Interceptor.php(193): Magento\Framework\View\Layout->renderElement('page.wrapper', false)
#56 /var/www/toshno/vendor/magento/framework/View/Layout.php(585): Magento\Framework\View\Layout\Interceptor->renderElement('page.wrapper', false)
#57 /var/www/toshno/vendor/magento/framework/View/Layout.php(535): Magento\Framework\View\Layout->_renderContainer('root', false)
#58 /var/www/toshno/generated/code/Magento/Framework/View/Layout/Interceptor.php(206): Magento\Framework\View\Layout->renderNonCachedElement('root')
#59 /var/www/toshno/vendor/magento/framework/View/Layout.php(488): Magento\Framework\View\Layout\Interceptor->renderNonCachedElement('root')
#60 /var/www/toshno/generated/code/Magento/Framework/View/Layout/Interceptor.php(193): Magento\Framework\View\Layout->renderElement('root', true)
#61 /var/www/toshno/vendor/magento/framework/View/Layout.php(954): Magento\Framework\View\Layout\Interceptor->renderElement('root')
#62 /var/www/toshno/vendor/magento/framework/Interception/Interceptor.php(58): Magento\Framework\View\Layout->getOutput()
#63 /var/www/toshno/vendor/magento/framework/Interception/Interceptor.php(138): Magento\Framework\View\Layout\Interceptor->___callParent('getOutput', Array)
#64 /var/www/toshno/vendor/magento/framework/Interception/Interceptor.php(153): Magento\Framework\View\Layout\Interceptor->Magento\Framework\Interception\{closure}()
#65 /var/www/toshno/generated/code/Magento/Framework/View/Layout/Interceptor.php(494): Magento\Framework\View\Layout\Interceptor->___callPlugins('getOutput', Array, Array)
#66 /var/www/toshno/vendor/magento/framework/View/Result/Page.php(258): Magento\Framework\View\Layout\Interceptor->getOutput()
#67 /var/www/toshno/vendor/magento/framework/View/Result/Layout.php(171): Magento\Framework\View\Result\Page->render(Object(Magento\Framework\App\Response\Http\Interceptor))
#68 /var/www/toshno/vendor/magento/framework/Interception/Interceptor.php(58): Magento\Framework\View\Result\Layout->renderResult(Object(Magento\Framework\App\Response\Http\Interceptor))
#69 /var/www/toshno/vendor/magento/framework/Interception/Interceptor.php(138): Magento\Framework\View\Result\Page\Interceptor->___callParent('renderResult', Array)
#70 /var/www/toshno/app/code/Potato/Compressor/Plugin/ControllerRenderResultAfter.php(58): Magento\Framework\View\Result\Page\Interceptor->Magento\Framework\Interception\{closure}(Object(Magento\Framework\App\Response\Http\Interceptor))
#71 /var/www/toshno/vendor/magento/framework/Interception/Interceptor.php(135): Potato\Compressor\Plugin\ControllerRenderResultAfter->aroundRenderResult(Object(Magento\Framework\View\Result\Page\Interceptor), Object(Closure), Object(Magento\Framework\App\Response\Http\Interceptor))
#72 /var/www/toshno/vendor/magento/framework/Interception/Interceptor.php(153): Magento\Framework\View\Result\Page\Interceptor->Magento\Framework\Interception\{closure}(Object(Magento\Framework\App\Response\Http\Interceptor))
#73 /var/www/toshno/generated/code/Magento/Framework/View/Result/Page/Interceptor.php(130): Magento\Framework\View\Result\Page\Interceptor->___callPlugins('renderResult', Array, NULL)
#74 /var/www/toshno/vendor/magento/framework/App/Http.php(139): Magento\Framework\View\Result\Page\Interceptor->renderResult(Object(Magento\Framework\App\Response\Http\Interceptor))
#75 /var/www/toshno/generated/code/Magento/Framework/App/Http/Interceptor.php(24): Magento\Framework\App\Http->launch()
#76 /var/www/toshno/vendor/magento/framework/App/Bootstrap.php(258): Magento\Framework\App\Http\Interceptor->launch()
#77 /var/www/toshno/index.php(39): Magento\Framework\App\Bootstrap->run(Object(Magento\Framework\App\Http\Interceptor))
#78 {main} [] []After analyzing the back-trace code and getting the request, we see that it’s possible to reduce category selection by restricting the level of categories that will be displayed in the menu. We can do this with the parameter of the ‘catalog/navigation/max_depth’ configuration. At the same time, we can optimize the request by adding additional indexes on the index table catalog_category_flat_store_1.
This is possible is because this is an index table and is recreated when the index is rebuilt by the createTable() method of the Magento\Catalog\Model\Indexer\Category\Flat\Action\Full class, while the method getFlatTableStructure() gets the table structure. Unfortunately, both methods are protected, so you can’t apply plugins to them, but you can redefine the indexer class using di.xml:
<preference for="Magento\Catalog\Model\Indexer\Category\Flat\Action\Full" type="Web4pro\All\Model\Indexer\Category\Full"/>
And the class looks as follows:
class Full extends \Magento\Catalog\Model\Indexer\Category\Flat\Action\Full
{
protected function getFlatTableStructure($tableName)
{
$table = parent::getFlatTableStructure($tableName);
$table->addIndex('category_active_parent_id',array('is_active','parent_id'),array('type'=>'index'));
$table->addIndex('category_active_menu_level',array('is_active','include_in_menu','level','path'),array('type'=>'index'));
return $table;
}
}After rebuilding the Magento indexes, loading the page without the generated cache significantly sped up. All that remains is to take the logging code that helped solve the problem out of the core files.
2. Migrating a site from Magento 1 to Magento 2. Data was migrated using a migration tool. Products on the Magento 1 site are updated by cron from a CSV file generated by the ERP system. With Magento 1, MAGMI is used for import, but this system can’t be used with Magento 2. Instead of MAGMI, we use the Firebear_ImportExport module, which supports the import of products by cron. The module also supports generating unique SEO URLs for products. However, the cron import task was found to not be ending successfully. When analyzing the exception.log file, the following message about the error was found
View code:
[2019-02-06 08:34:27] main.CRITICAL: URL key for specified store already exists. {"exception":"[object] (Magento\\UrlRewrite\\Model\\Exception\\UrlAlreadyExistsException(code: 0): URL key for specified store already exists. at /home/magento/www/vendor/magento/module-url-rewrite/Model/Storage/DbStorage.php:220, Magento\\Framework\\Exception\\AlreadyExistsException(code: 0): URL key for specified store already exists. at /home/magento/www/vendor/magento/module-url-rewrite/Model/Storage/DbStorage.php:250, Magento\\Framework\\DB\\Adapter\\DuplicateException(code: 1062): SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry 'skinny-charles-3-pc-4803.html-1' for key 'URL_REWRITE_REQUEST_PATH_STORE_ID', query was: INSERT INTO `url_rewrite` (`redirect_type`,`is_autogenerated`,`metadata`,`description`,`entity_type`,`entity_id`,`request_path`,`target_path`,`store_id`) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?) at /home/magento/www/vendor/magento/framework/DB/Adapter/Pdo/Mysql.php:580, Zend_Db_Statement_Exception(code: 23000): SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry 'skinny-charles-3-pc-4803.html-1' for key 'URL_REWRITE_REQUEST_PATH_STORE_ID', query was: INSERT INTO `url_rewrite` (`redirect_type`,`is_autogenerated`,`metadata`,`description`,`entity_type`,`entity_id`,`request_path`,`target_path`,`store_id`) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?, ?) at /home/magento/www/vendor/magento/zendframework1/library/Zend/Db/Statement/Pdo.php:235, PDOException(code: 23000): SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry 'skinny-charles-3-pc-4803.html-1' for key 'URL_REWRITE_REQUEST_PATH_STORE_ID' at /home/magento/www/vendor/magento/zendframework1/library/Zend/Db/Statement/Pdo.php:228)"} []We query the database:
mysql> select * from url_rewrite where request_path = 'skinny-charles-3-pc-4803.html';
---------------- ------------- ----------- ------------------------------- ------------------------------- --------------- ---------- ------------- ------------------ ----------
| url_rewrite_id | entity_type | entity_id | request_path | target_path | redirect_type | store_id | description | is_autogenerated | metadata |
---------------- ------------- ----------- ------------------------------- ------------------------------- --------------- ---------- ------------- ------------------ ----------
| 1509442 | product | 2496 | skinny-charles-3-pc-4803.html | skinny-charles-3-pc-7243.html | 301 | 1 | NULL | 0 | NULL |
---------------- ------------- ----------- ------------------------------- ------------------------------- --------------- ---------- ------------- ------------------ ----------
1 row in set (0,01 sec)
mysql> select * from url_rewrite where request_path = 'skinny-charles-3-pc-7243.html';
---------------- ------------- ----------- ------------------------------- ------------------------------ --------------- ---------- ------------- ------------------ ----------
| url_rewrite_id | entity_type | entity_id | request_path | target_path | redirect_type | store_id | description | is_autogenerated | metadata |
---------------- ------------- ----------- ------------------------------- ------------------------------ --------------- ---------- ------------- ------------------ ----------
| 1508688 | product | 2496 | skinny-charles-3-pc-7243.html | catalog/product/view/id/2496 | 0 | 1 | NULL | 1 | NULL |
---------------- ------------- ----------- ------------------------------- ------------------------------ --------------- ---------- ------------- ------------------ ----------
1 row in set (0,00 sec)It turns out that this URL had already been used for the product with ID 2496, and in the database, there’s a 301 redirect to this product’s page. But later it turned out that this 301 redirect leads to a 404 page anyway since the product had been Disabled and isn’t visible on the front end. This means that this 301 redirect can be deleted from the database without any negative consequences.
3. The following message was found on the site when checking the exception.log file
View code:
2019-02-11 13:00:03] main.CRITICAL: Warning: Missing argument 1 for Magento\Framework\Mview\View\Changelog::clear(), called in /home/magento/www/vendor/magento/framework/Interception/Interceptor.php on line 58 and defined in /home/magento/www/vendor/magento/framework/Mview/View/Changelog.php on line 116 {"exception":"[object] (Exception(code: 0): Warning: Missing argument 1 for Magento\\Framework\\Mview\\View\\Changelog::clear(), called in /home/magento/www/vendor/magento/framework/Interception/Interceptor.php on line 58 and defined in /home/magento/www/vendor/magento/framework/Mview/View/Changelog.php on line 116 at /home/magento/www/vendor/magento/framework/App/ErrorHandler.php:61)"}This error occurs when rebuilding indexes. Since the method is called in the Interceptor trait, the reason for the error is most likely a plugin that was written incorrectly. We check all the plugins defined in di.xml for the class Magento\Framework\Mview\View\Changelog. We find this definition in the Amasty Order Attributes module.
<type name="Magento\Framework\Mview\View\Changelog">
<plugin name="Amasty_Orderattr::ChangelogPlugin" type="Amasty\Orderattr\Model\Indexer\Mview\ChangelogPlugin" />
</type>In module version 3.4.5 this class contains the following method:
public function aroundClear(\Magento\Framework\Mview\View\Changelog $subject, \Closure $proceed)
{
if ($this->isAmastyView($subject)) {
$this->changelog->setViewId($subject->getViewId());
return $this->changelog->clear();
} else {
return $proceed();
}Since the original clear method of the class, Magento\Framework\Mview\View\Changelog looks like this in Magento 2.2.6:
public function clear($versionId)
{
$changelogTableName = $this->resource->getTableName($this->getName());
if (!$this->connection->isTableExists($changelogTableName)) {
throw new ChangelogTableNotExistsException(new Phrase("Table %1 does not exist", [$changelogTableName]));
}
$this->connection->delete($changelogTableName, ['version_id < ?' => (int)$versionId]);
return true;
}Since the method has the mandatory $versionId parameter, this error is thrown when attempting to call the parent method from the plugin. Amasty corrected this error in version 3.4.8, where the plugin method looks as follows:
public function aroundClear(\Magento\Framework\Mview\View\Changelog $subject, \Closure $proceed, $versionId)
{
if ($this->isAmastyView($subject)) {
$this->changelog->setViewId($subject->getViewId());
return $this->changelog->clear($versionId);
} else {
return $proceed($versionId);
}
}As you can see, the problem was caused by incompatibility between the module version and Magento version, and it was solved by updating the module.