Open ioweb-gr opened 6 months ago
Is the version you use in testing OpenMage v20.5.0 + Magento Sample Data?
I'm seeing this on a production site using OpenMage v20.5.0 so it's not using Magento Sample Data.
I've made sure it occurs with all 3rd party extensions removed as well.
It seems to come directly from core.
The more joins are added to the same table, the more the time of execution increases.
would it be possible for you to remove some of those attributes from "available in product listing"?
Actually most of them are already set to No
there are 9 visible in the query
I checked them all and only 3 were used in product listing. I changed them to No as well
Even after changing all to No I still get this query
SELECT `operating_system_idx`.`value`, COUNT(operating_system_idx.entity_id) AS `count`
FROM `catalog_product_entity` AS `e`
INNER JOIN `catalog_category_product_index` AS `cat_index` ON cat_index.product_id=e.entity_id AND cat_index.store_id=1 AND cat_index.visibility IN(2, 4) AND cat_index.category_id = '17'
INNER JOIN `catalog_product_index_price` AS `price_index` ON price_index.entity_id = e.entity_id AND price_index.website_id = '1' AND price_index.customer_group_id = 0
INNER JOIN `catalog_product_index_eav` AS `screen_resolution_idx` ON screen_resolution_idx.entity_id = e.entity_id AND screen_resolution_idx.attribute_id = 188 AND screen_resolution_idx.store_id = 1 AND screen_resolution_idx.value = '265'
INNER JOIN `catalog_product_index_eav` AS `screen_type_idx` ON screen_type_idx.entity_id = e.entity_id AND screen_type_idx.attribute_id = 189 AND screen_type_idx.store_id = 1 AND screen_type_idx.value = '39'
INNER JOIN `catalog_product_index_eav` AS `core_count_idx` ON core_count_idx.entity_id = e.entity_id AND core_count_idx.attribute_id = 193 AND core_count_idx.store_id = 1 AND core_count_idx.value = '41'
INNER JOIN `catalog_product_index_eav` AS `ram_idx` ON ram_idx.entity_id = e.entity_id AND ram_idx.attribute_id = 196 AND ram_idx.store_id = 1 AND ram_idx.value = '54'
INNER JOIN `catalog_product_index_eav` AS `primary_camera_idx` ON primary_camera_idx.entity_id = e.entity_id AND primary_camera_idx.attribute_id = 198 AND primary_camera_idx.store_id = 1 AND primary_camera_idx.value = '309'
INNER JOIN `catalog_product_index_eav` AS `megethossim_idx` ON megethossim_idx.entity_id = e.entity_id AND megethossim_idx.attribute_id = 229 AND megethossim_idx.store_id = 1 AND megethossim_idx.value = '164'
INNER JOIN `catalog_product_index_eav` AS `nfcsosto_idx` ON nfcsosto_idx.entity_id = e.entity_id AND nfcsosto_idx.attribute_id = 258 AND nfcsosto_idx.store_id = 1 AND nfcsosto_idx.value = '377'
INNER JOIN `catalog_product_index_eav` AS `operating_system_idx` ON operating_system_idx.entity_id = e.entity_id AND operating_system_idx.attribute_id = 195 AND operating_system_idx.store_id = '1'
GROUP BY `operating_system_idx`.`value`
I'm thinking that the culprit may be here as it's one of the few areas I can see that match the query about count(attribute_code_idx)
//app/code/core/Mage/Catalog/Model/Layer/Filter/Attribute.php:115
protected function _getItemsData()
{
$attribute = $this->getAttributeModel();
$this->_requestVar = $attribute->getAttributeCode();
$key = $this->getLayer()->getStateKey() . '_' . $this->_requestVar;
$data = $this->getLayer()->getAggregator()->getCacheData($key);
if ($data === null) {
$options = $attribute->getFrontend()->getSelectOptions();
$optionsCount = $this->_getResource()->getCount($this);
$data = [];
foreach ($options as $option) {
if (is_array($option['value'])) {
continue;
}
if (Mage::helper('core/string')->strlen($option['value'])) {
// Check filter type
if ($this->_getIsFilterableAttribute($attribute) == self::OPTIONS_ONLY_WITH_RESULTS) {
if (!empty($optionsCount[$option['value']])) {
$data[] = [
'label' => $option['label'],
'value' => $option['value'],
'count' => $optionsCount[$option['value']],
];
}
} else {
$data[] = [
'label' => $option['label'],
'value' => $option['value'],
'count' => $optionsCount[$option['value']] ?? 0,
];
}
}
}
$tags = [
Mage_Eav_Model_Entity_Attribute::CACHE_TAG . ':' . $attribute->getId()
];
$tags = $this->getLayer()->getStateTags($tags);
$this->getLayer()->getAggregator()->saveCacheData($data, $key, $tags);
}
return $data;
}
Check how I replicated it.
I went in a category page with 16 filters in the sidebar's layered navigation (smartphones as products which have a lot of filters)
I progressively started clicking on filters
At around 12 of them even if it was showing only one product. I reached a query like this
SELECT `manufacturer2_idx`.`value`, COUNT(manufacturer2_idx.entity_id) AS `count`
FROM `catalog_product_entity` AS `e`
INNER JOIN `catalog_category_product_index` AS `cat_index`
ON cat_index.product_id = e.entity_id AND cat_index.store_id = 1 AND
cat_index.visibility IN (2, 4) AND cat_index.category_id = '15'
INNER JOIN `catalog_product_index_price` AS `price_index`
ON price_index.entity_id = e.entity_id AND price_index.website_id = '1' AND
price_index.customer_group_id = 0
INNER JOIN `catalog_product_index_eav` AS `screen_resolution_idx`
ON screen_resolution_idx.entity_id = e.entity_id AND screen_resolution_idx.attribute_id = 188 AND
screen_resolution_idx.store_id = 1 AND screen_resolution_idx.value = '249'
INNER JOIN `catalog_product_index_eav` AS `screen_type_idx`
ON screen_type_idx.entity_id = e.entity_id AND screen_type_idx.attribute_id = 189 AND
screen_type_idx.store_id = 1 AND screen_type_idx.value = '37'
INNER JOIN `catalog_product_index_eav` AS `core_count_idx`
ON core_count_idx.entity_id = e.entity_id AND core_count_idx.attribute_id = 193 AND
core_count_idx.store_id = 1 AND core_count_idx.value = '41'
INNER JOIN `catalog_product_index_eav` AS `operating_system_idx`
ON operating_system_idx.entity_id = e.entity_id AND operating_system_idx.attribute_id = 195 AND
operating_system_idx.store_id = 1 AND operating_system_idx.value = '48'
INNER JOIN `catalog_product_index_eav` AS `ram_idx`
ON ram_idx.entity_id = e.entity_id AND ram_idx.attribute_id = 196 AND ram_idx.store_id = 1 AND
ram_idx.value = '52'
INNER JOIN `catalog_product_index_eav` AS `memory_idx`
ON memory_idx.entity_id = e.entity_id AND memory_idx.attribute_id = 197 AND
memory_idx.store_id = 1 AND memory_idx.value = '62'
INNER JOIN `catalog_product_index_eav` AS `primary_camera_idx`
ON primary_camera_idx.entity_id = e.entity_id AND primary_camera_idx.attribute_id = 198 AND
primary_camera_idx.store_id = 1 AND primary_camera_idx.value = '309'
INNER JOIN `catalog_product_index_eav` AS `second_camera_idx`
ON second_camera_idx.entity_id = e.entity_id AND second_camera_idx.attribute_id = 200 AND
second_camera_idx.store_id = 1 AND second_camera_idx.value = '87'
INNER JOIN `catalog_product_index_eav` AS `megethossim_idx`
ON megethossim_idx.entity_id = e.entity_id AND megethossim_idx.attribute_id = 229 AND
megethossim_idx.store_id = 1 AND megethossim_idx.value = '164'
INNER JOIN `catalog_product_index_eav` AS `nfcsosto_idx`
ON nfcsosto_idx.entity_id = e.entity_id AND nfcsosto_idx.attribute_id = 258 AND
nfcsosto_idx.store_id = 1 AND nfcsosto_idx.value = '377'
INNER JOIN `catalog_product_index_eav` AS `manufacturer2_idx`
ON manufacturer2_idx.entity_id = e.entity_id AND manufacturer2_idx.attribute_id = 186 AND
manufacturer2_idx.store_id = '1'
GROUP BY `manufacturer2_idx`.`value`
This query stopped working entirely giving timeout after 1 hour.
Unfortunately on the demo I can only apply 7-8 filters
They're not enough to test this on default
However check this URL:
After disabling cache open up this url which will load slightly fast.
It has 7 filters selected
Try to select the last filter
For me it took a couple of seconds more than the previous request.
Progressively adding more should showcase the issue
ah ok so those attributes are still filterable, I don't know if there's anything possible here, the query is very complex
True it's very complex but I think the problem is still that count query. Since I configured the backend not to show the count, shouldn't this count query be totally eliminated?
It also is a significant issue because it makes filters unusable after a point and also with crawlers in the mix it can bring a whole db server down because they will drill down through all the filters
I posted this on https://dba.stackexchange.com/questions/338347/why-is-this-query-running-so-slowly/338372#338372
Where Dan Black was kind enough to take a look at this. His last suggestion was to set the
optimizer_search_depth = 1
From the default value of 62 as suggested in this KB reference https://mariadb.com/kb/en/entity-attribute-value-implementation/ for EAV implementations.
As it turns out this can also be set for the session only and it made the query run instantly.
I was wondering if we can put this in the mix here because for pretty much all collection related queries that use many joins along so many tables it will give a performance boost.
I'm still exploring this over dba.stackexchange.com if you would like to add some input there as well for this.
I am thinking that basically this is only affecting OpenMage because it's using EAV system which is considered an anti-pattern. Therefore it wouldn't make sense in hosting environments to change this globally, and it may not be good for other types of queries so would it be possible to set it in the OpenMage DB adapter class?
@fballiano I found the way to mitigate this for now.
On local.xml there's a section called
<initStatements><![CDATA[SET NAMES utf8]]></initStatements>
I modified it like this for the site experiencing the issue
<initStatements><![CDATA[SET NAMES utf8;SET SESSION optimizer_search_depth = 1;]]></initStatements>
The problem is successfully mitigated for my case.
The underlying issue is still there though about the multiple joins and we need to find a permanent way to do this for the queries that actually suffer from this and not for the whole connection in my opinion.
For now though this helps
Preconditions (*)
Steps to reproduce (*)
There are no specific steps to reproduce this , we just see it in the slow query logs
We keep observing some long running queries of this format
Which pretty much never stop executing until they timeout
They appear to be related to counting terms for layered navigation.
The related tables range from 200 rows to 2000 rows so they're not extremely big and the execution shouldn't be that slow for any reason.
We have disabled showing the count in layered navigation
Here's another sample query with very long execution time and explain
There also doesn't seem to be any form of lock causing this delay
Expected result (*)
Actual result (*)