Hi y'all
For quite a while, I (along with Dr Byte) have been trying to isolate issues with client searches taking a long time for a result. Last weekend, Dr Byte coded the search button so that multiple hits, or hitting the Enter/Return keys will not cause additional sending of the search to the database.
Although that fixed that problem, mysql clogging still persists in this manner.
When 2 or more customers perform a search on my website at nearly the same time, they all must be completed before any result is given to the clients. Therefore clogging the mysql so that search results take well of 10 seconds to 30 seconds (depending on how many search at the same time). Of course, it not EXACTLY at the same time, but as long as the first search has started and then someone else searches before the first is done, both are delayed. This is actually no different than before the 'multi-click' removal code on the search button was created by Dr Byte, but in this instance, it's multi searching from more than one client as the problem.
I always watch the (OSX) activity monitor when I do test searches and I see my 8 core meter only using one core for the search at around 80% until the search is completed (2-3 seconds). BUT, when it's clogged with multiple searches, ALL 8 CORES light up at 20-40% until all the searches are completed (10-25 seconds). Why do you think this is happening with so few clients viewing my website and so few searches causing a problem?
Here is my setup:
ZenCart 1.5.1
OSX Mountain Lion Server 10.8.3 (Apache) with 22 GB of memory (and running on an SSD drive).
HTTP Server: Apache/2.2.22 (Unix) DAV/2 PHP/5.3.15 with Suhosin-Patch mod_ssl/2.2.22 OpenSSL/0.9.8x
Database: MySQL 5.5.29-log
LARGE DATABASE of products - nearly 54,000
over a million attributes
mysql-slow.log enabled
Here is the data from mysql-slow.log with a clogged search this morning.
Code:
# Time: 130803 10:22:22
# User@Host: zencart[zencart] @ localhost [127.0.0.1]
# Query_time: 13.694394 Lock_time: 0.000128 Rows_sent: 1 Rows_examined: 440231
SET timestamp=1375539742;
select count(distinct p.products_id) as total FROM (products p, products_description pd, categories c, products_to_categories p2c ) LEFT JOIN meta_tags_products_description mtpd ON mtpd.products_id= p2c.products_id AND mtpd.language_id = 1 WHERE (p.products_status = 1 AND p.products_id = pd.products_id AND pd.language_id = 1 AND p.products_id = p2c.products_id AND p2c.categories_id = c.categories_id AND ((pd.products_name LIKE '%heart%' OR p.products_model LIKE 'heart' OR (mtpd.metatags_keywords LIKE '%heart%' AND mtpd.metatags_keywords !='')) ));
# Time: 130803 10:22:23
# User@Host: zencart[zencart] @ localhost [127.0.0.1]
# Query_time: 14.734967 Lock_time: 0.000107 Rows_sent: 1 Rows_examined: 440231
SET timestamp=1375539743;
select count(distinct p.products_id) as total FROM (products p, products_description pd, categories c, products_to_categories p2c ) LEFT JOIN meta_tags_products_description mtpd ON mtpd.products_id= p2c.products_id AND mtpd.language_id = 1 WHERE (p.products_status = 1 AND p.products_id = pd.products_id AND pd.language_id = 1 AND p.products_id = p2c.products_id AND p2c.categories_id = c.categories_id AND ((pd.products_name LIKE '%love%' OR p.products_model LIKE 'love' OR (mtpd.metatags_keywords LIKE '%love%' AND mtpd.metatags_keywords !='')) ));
# Time: 130803 10:22:34
# User@Host: zencart[zencart] @ localhost [127.0.0.1]
# Query_time: 22.077050 Lock_time: 0.000114 Rows_sent: 1 Rows_examined: 440231
SET timestamp=1375539754;
select count(distinct p.products_id) as total FROM (products p, products_description pd, categories c, products_to_categories p2c ) LEFT JOIN meta_tags_products_description mtpd ON mtpd.products_id= p2c.products_id AND mtpd.language_id = 1 WHERE (p.products_status = 1 AND p.products_id = pd.products_id AND pd.language_id = 1 AND p.products_id = p2c.products_id AND p2c.categories_id = c.categories_id AND ((pd.products_name LIKE '%k-06482%' OR p.products_model LIKE 'k-06482' OR (mtpd.metatags_keywords LIKE '%k-06482%' AND mtpd.metatags_keywords !='')) ));
# Time: 130803 10:22:44
# User@Host: zencart[zencart] @ localhost [127.0.0.1]
# Query_time: 22.086718 Lock_time: 0.000164 Rows_sent: 10 Rows_examined: 437676
SET timestamp=1375539764;
SELECT DISTINCT p.products_image, p.products_quantity , p.products_id, pd.products_name FROM (products p, products_description pd, categories c, products_to_categories p2c ) LEFT JOIN meta_tags_products_description mtpd ON mtpd.products_id= p2c.products_id AND mtpd.language_id = 1 WHERE (p.products_status = 1 AND p.products_id = pd.products_id AND pd.language_id = 1 AND p.products_id = p2c.products_id AND p2c.categories_id = c.categories_id AND ((pd.products_name LIKE '%heart%' OR p.products_model LIKE 'heart' OR (mtpd.metatags_keywords LIKE '%heart%' AND mtpd.metatags_keywords !='')) )) order by pd.products_name limit 10;
# User@Host: zencart[zencart] @ localhost [127.0.0.1]
# Query_time: 21.347180 Lock_time: 0.000178 Rows_sent: 10 Rows_examined: 430999
SET timestamp=1375539764;
SELECT DISTINCT p.products_image, p.products_quantity , p.products_id, pd.products_name FROM (products p, products_description pd, categories c, products_to_categories p2c ) LEFT JOIN meta_tags_products_description mtpd ON mtpd.products_id= p2c.products_id AND mtpd.language_id = 1 WHERE (p.products_status = 1 AND p.products_id = pd.products_id AND pd.language_id = 1 AND p.products_id = p2c.products_id AND p2c.categories_id = c.categories_id AND ((pd.products_name LIKE '%love%' OR p.products_model LIKE 'love' OR (mtpd.metatags_keywords LIKE '%love%' AND mtpd.metatags_keywords !='')) )) order by pd.products_name limit 10;
# Time: 130803 10:22:45
# User@Host: zencart[zencart] @ localhost [127.0.0.1]
# Query_time: 10.872626 Lock_time: 0.000180 Rows_sent: 1 Rows_examined: 440230
SET timestamp=1375539765;
SELECT DISTINCT p.products_image, p.products_quantity , p.products_id, pd.products_name FROM (products p, products_description pd, categories c, products_to_categories p2c ) LEFT JOIN meta_tags_products_description mtpd ON mtpd.products_id= p2c.products_id AND mtpd.language_id = 1 WHERE (p.products_status = 1 AND p.products_id = pd.products_id AND pd.language_id = 1 AND p.products_id = p2c.products_id AND p2c.categories_id = c.categories_id AND ((pd.products_name LIKE '%k-06482%' OR p.products_model LIKE 'k-06482' OR (mtpd.metatags_keywords LIKE '%k-06482%' AND mtpd.metatags_keywords !='')) )) order by pd.products_name limit 10;
and
Code:
# Time: 130803 9:52:16
# User@Host: zencart[zencart] @ localhost [127.0.0.1]
# Query_time: 11.136167 Lock_time: 0.000170 Rows_sent: 1 Rows_examined: 440230
SET timestamp=1375537936;
SELECT DISTINCT p.products_image, p.products_quantity , p.products_id, pd.products_name FROM (products p, products_description pd, categories c, products_to_categories p2c ) LEFT JOIN meta_tags_products_description mtpd ON mtpd.products_id= p2c.products_id AND mtpd.language_id = 1 WHERE (p.products_status = 1 AND p.products_id = pd.products_id AND pd.language_id = 1 AND p.products_id = p2c.products_id AND p2c.categories_id = c.categories_id AND ((pd.products_name LIKE '%t-26460%' OR p.products_model LIKE 't-26460' OR (mtpd.metatags_keywords LIKE '%t-26460%' AND mtpd.metatags_keywords !='')) )) order by pd.products_name limit 10;
# Time: 130803 9:52:17
# User@Host: zencart[zencart] @ localhost [127.0.0.1]
# Query_time: 11.815661 Lock_time: 0.000110 Rows_sent: 1 Rows_examined: 440231
SET timestamp=1375537937;
select count(distinct p.products_id) as total FROM (products p, products_description pd, categories c, products_to_categories p2c ) LEFT JOIN meta_tags_products_description mtpd ON mtpd.products_id= p2c.products_id AND mtpd.language_id = 1 WHERE (p.products_status = 1 AND p.products_id = pd.products_id AND pd.language_id = 1 AND p.products_id = p2c.products_id AND p2c.categories_id = c.categories_id AND ((pd.products_name LIKE '%99094020%' OR p.products_model LIKE '99094020' OR (mtpd.metatags_keywords LIKE '%99094020%' AND mtpd.metatags_keywords !='')) ));
# Time: 130803 9:52:35
# User@Host: zencart[zencart] @ localhost [127.0.0.1]
# Query_time: 24.010266 Lock_time: 0.000101 Rows_sent: 1 Rows_examined: 440231
SET timestamp=1375537955;
select count(distinct p.products_id) as total FROM (products p, products_description pd, categories c, products_to_categories p2c ) LEFT JOIN meta_tags_products_description mtpd ON mtpd.products_id= p2c.products_id AND mtpd.language_id = 1 WHERE (p.products_status = 1 AND p.products_id = pd.products_id AND pd.language_id = 1 AND p.products_id = p2c.products_id AND p2c.categories_id = c.categories_id AND ((pd.products_name LIKE '%99148047%' OR p.products_model LIKE '99148047' OR (mtpd.metatags_keywords LIKE '%99148047%' AND mtpd.metatags_keywords !='')) ));
# Time: 130803 9:52:37
# User@Host: zencart[zencart] @ localhost [127.0.0.1]
# Query_time: 24.066022 Lock_time: 0.000201 Rows_sent: 1 Rows_examined: 440231
SET timestamp=1375537957;
select count(distinct p.products_id) as total FROM (products p, products_description pd, categories c, products_to_categories p2c ) LEFT JOIN meta_tags_products_description mtpd ON mtpd.products_id= p2c.products_id AND mtpd.language_id = 1 WHERE (p.products_status = 1 AND p.products_id = pd.products_id AND pd.language_id = 1 AND p.products_id = p2c.products_id AND p2c.categories_id = c.categories_id AND ((pd.products_name LIKE '%kp-06493%' OR p.products_model LIKE 'kp-06493' OR (mtpd.metatags_keywords LIKE '%kp-06493%' AND mtpd.metatags_keywords !='')) ));
# Time: 130803 9:52:39
# User@Host: zencart[zencart] @ localhost [127.0.0.1]
# Query_time: 22.089239 Lock_time: 0.000151 Rows_sent: 1 Rows_examined: 440233
SET timestamp=1375537959;
SELECT DISTINCT p.products_image, p.products_quantity , p.products_id, pd.products_name FROM (products p, products_description pd, categories c, products_to_categories p2c ) LEFT JOIN meta_tags_products_description mtpd ON mtpd.products_id= p2c.products_id AND mtpd.language_id = 1 WHERE (p.products_status = 1 AND p.products_id = pd.products_id AND pd.language_id = 1 AND p.products_id = p2c.products_id AND p2c.categories_id = c.categories_id AND ((pd.products_name LIKE '%99094020%' OR p.products_model LIKE '99094020' OR (mtpd.metatags_keywords LIKE '%99094020%' AND mtpd.metatags_keywords !='')) )) order by pd.products_name limit 10;
# Time: 130803 9:52:45
# User@Host: zencart[zencart] @ localhost [127.0.0.1]
# Query_time: 10.762785 Lock_time: 0.000168 Rows_sent: 1 Rows_examined: 440233
SET timestamp=1375537965;
SELECT DISTINCT p.products_image, p.products_quantity , p.products_id, pd.products_name FROM (products p, products_description pd, categories c, products_to_categories p2c ) LEFT JOIN meta_tags_products_description mtpd ON mtpd.products_id= p2c.products_id AND mtpd.language_id = 1 WHERE (p.products_status = 1 AND p.products_id = pd.products_id AND pd.language_id = 1 AND p.products_id = p2c.products_id AND p2c.categories_id = c.categories_id AND ((pd.products_name LIKE '%99148047%' OR p.products_model LIKE '99148047' OR (mtpd.metatags_keywords LIKE '%99148047%' AND mtpd.metatags_keywords !='')) )) order by pd.products_name limit 10;
Here is my.cnf that has been tweeked with mysqltuner:
Code:
# The MySQL server
[mysqld]
port = 3306
socket = /tmp/mysql.sock
skip-external-locking
key_buffer_size = 1000M
max_allowed_packet = 1M
table_open_cache = 512
sort_buffer_size = 4M
read_buffer_size = 4M
join_buffer = 16M
# record_buffer = 2M
read_rnd_buffer_size = 8M
myisam_sort_buffer_size = 128M
query_cache_size = 128M
query_cache_limit = 4096M
query_cache_type = 1
# Try number of CPU's*2 for thread_concurrency
# thread_concurrency = 8
interactive_timeout = 20
wait_timeout = 20
max_connections = 100
max_user_connections = 25
max_connect_errors = 25
connect_timeout = 10
thread_cache_size = 256
tmp_table_size = 1024M
max_heap_table_size = 1024M
open_files_limit = 2000
table_cache = 1024
log-error=/var/log/mysqld.log
slow-query-log=1
slow-query-log-file=/var/log/mysql-slow.log
MySQLTuner results this morning:
Code:
-------- General Statistics --------------------------------------------------
[--] Skipped version check for MySQLTuner script
[OK] Currently running supported MySQL version 5.5.29-log
[OK] Operating on 64-bit architecture
-------- Storage Engine Statistics -------------------------------------------
[--] Status: +Archive -BDB -Federated +InnoDB -ISAM -NDBCluster
[--] Data in MyISAM tables: 3G (Tables: 633)
[--] Data in InnoDB tables: 53M (Tables: 37)
[--] Data in PERFORMANCE_SCHEMA tables: 0B (Tables: 17)
[--] Data in MEMORY tables: 0B (Tables: 2)
[!!] Total fragmented tables: 58
-------- Security Recommendations -------------------------------------------
[OK] All database users have passwords assigned
-------- Performance Metrics -------------------------------------------------
[--] Up for: 1d 20h 45m 3s (2M q [12.678 qps], 17K conn, TX: 14B, RX: 1B)
[--] Reads / Writes: 86% / 14%
[--] Total buffers: 2.2G global + 32.2M per thread (100 max threads)
[OK] Maximum possible memory usage: 5.4G (24% of installed RAM)
[OK] Slow queries: 0% (54/2M)
[OK] Highest usage of available connections: 30% (30/100)
[OK] Key buffer size / total MyISAM indexes: 1000.0M/229.8M
[OK] Key buffer hit rate: 100.0% (1B cached / 35K reads)
[OK] Query cache efficiency: 72.3% (1M cached / 1M selects)
[!!] Query cache prunes per day: 171895
[OK] Sorts requiring temporary tables: 0% (66 temp sorts / 66K sorts)
[!!] Joins performed without indexes: 1179
[!!] Temporary tables created on disk: 37% (44K on disk / 117K total)
[OK] Thread cache hit rate: 99% (30 created / 17K connections)
[OK] Table cache hit rate: 43% (955 open / 2K opened)
[OK] Open file limit used: 70% (1K/2K)
[OK] Table locks acquired immediately: 99% (720K immediate / 720K locks)
[!!] Connections aborted: 10%
[OK] InnoDB data size / buffer pool: 53.9M/128.0M
-------- Recommendations -----------------------------------------------------
General recommendations:
Run OPTIMIZE TABLE to defragment tables for better performance
Adjust your join queries to always utilize indexes
Temporary table size is already large - reduce result set size
Reduce your SELECT DISTINCT queries without LIMIT clauses
Your applications are not closing MySQL connections properly
Variables to adjust:
query_cache_size (> 128M)
join_buffer_size (> 16.0M, or always use indexes with joins)
So, my primary question here is why can't mysql perform multiple searches at the same time?
Any help would be greatly appreciated.
thank you,
Bookmarks