100+ queries very sporadically

Hello,

I am new to the forums, so I may be a little off with the proper post ‘format.’ Feel free to correct me, I will not take it personal.

So, I have a session table typically has 20K rows in it and on every webpage hit (a few per second), one SELECT and one UPDATE are executed in the same connection. In addition, a ‘DELETE on data more than 2 weeks old’ is performed 5% of the time.

Sometimes, I can get locked out for 100+ sec, meanwhile, the person sitting next to me can access the data immediately.

Here is the info for the table, and the slow queries:

  1. show create table session:
    session | CREATE TABLE session (
    ctr int(10) unsigned NOT NULL auto_increment,
    session_id varchar(40) NOT NULL,
    ip_address varchar(16) NOT NULL,
    user_agent varchar(50) NOT NULL,
    referrer_user_id int(10) unsigned default NULL,
    referrer_addr varchar(100) default NULL,
    last_activity int(10) unsigned NOT NULL,
    session_data text NOT NULL,
    PRIMARY KEY (ctr),
    UNIQUE KEY idx_session_id (session_id),
    KEY idx_selects (session_id,user_agent,last_activity)
    ) ENGINE=InnoDB AUTO_INCREMENT=24402 DEFAULT CHARSET=latin1 |

  2. slow select:

Query_time: 85 Lock_time: 0 Rows_sent: 1 Rows_examined: 18370

SELECT *
FROM session
WHERE session_id = ‘06a05c42d9a58515d2bac592c3bdfc8b’
AND last_activity > 1234638681
AND user_agent = ‘Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv’;

  1. slow update:

Query_time: 128 Lock_time: 0 Rows_sent: 0 Rows_examined: 0

UPDATE session SET last_activity = 1235848241, user_agent = ‘Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US
; rv’, ip_address = ‘69.15.182.225’, referrer_addr = ‘’, session_data = ‘a:2:{s:11:"url_history";a:5:{i:0;s:3
5:"/support/view/highestSupportAmount/";i:1;s:37:"/support/view/highestSupportAmount/72\ ";i:2;s:37:"/suppor
t/view/highestSupportAmount/36";i:3;s:40:"/support/design/38/skulls-are-still-kool\ ";i:4;s:34:"/support/view
/highestSupportAmount";}s:16:"referrer_user_id";N;}’ WHERE session_id = ‘a73bc2035d2ca7a58844e4ec52e48c3a’;

  1. slow delete:

Query_time: 94 Lock_time: 0 Rows_sent: 0 Rows_examined: 0

DELETE FROM session WHERE last_activity < 1235606350;

I am not sure if this is a locking issue, it looks like it, but I don’t know how to investigate further.

ad2.
explain SELECT *
FROM session
WHERE session_id = ‘06a05c42d9a58515d2bac592c3bdfc8b’
AND last_activity > 1234638681
AND user_agent = ‘Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv’;

ad3.
explain select * from session WHERE session_id = ‘a73bc2035d2ca7a58844e4ec52e48c3a’;

ad4.
explain select * FROM session WHERE last_activity < 1235606350;

Copy & paste results.

ad2.
±—±------------±------±-----±--------------±-----±- -------±-----±-----±------------------------------------- ---------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±------±-----±--------------±-----±- -------±-----±-----±------------------------------------- ---------------+
| 1 | SIMPLE | NULL | NULL | NULL | NULL | NULL | NULL | NULL | Impossible WHERE noticed after reading const tables |
±—±------------±------±-----±--------------±-----±- -------±-----±-----±------------------------------------- ---------------+
1 row in set (0.00 sec)

ad3.
±—±------------±------±-----±--------------±-----±- -------±-----±-----±------------------------------------- ---------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±------±-----±--------------±-----±- -------±-----±-----±------------------------------------- ---------------+
| 1 | SIMPLE | NULL | NULL | NULL | NULL | NULL | NULL | NULL | Impossible WHERE noticed after reading const tables |
±—±------------±------±-----±--------------±-----±- -------±-----±-----±------------------------------------- ---------------+
1 row in set (0.00 sec)

ad4.
±—±------------±------------±-----±--------------±-- —±--------±-----±------±------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±------------±-----±--------------±-- —±--------±-----±------±------------+
| 1 | SIMPLE | ca_sessions | ALL | NULL | NULL | NULL | NULL | 18269 | Using where |
±—±------------±------------±-----±--------------±-- —±--------±-----±------±------------+
1 row in set (0.00 sec)

thank you

Repeat 2 & 3 with valid session_id.

As for 4 You could add index to the last_activity and check query again.

edit:
Check also
explain SELECT *
FROM session
WHERE session_id = ‘06a05c42d9a58515d2bac592c3bdfc8b’
AND user_agent = ‘Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv’
AND last_activity > 1234638681
;
(with valid session_id and user_agent of course)

btw. Your user_agent is too short, 50 chars is not enough

Thank you for your help.

ad2.

explain SELECT *
→ FROM ca_sessions
→ WHERE session_id = ‘1ba4966d04a30c4895ac89bedfd0eced’
→ AND last_activity > 1236803500
→ AND user_agent = ‘Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.4; en’;
±—±------------±------------±------±----------------- ----------±---------------±--------±------±-----±------ +
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±------------±------±----------------- ----------±---------------±--------±------±-----±------ +
| 1 | SIMPLE | ca_sessions | const | idx_session_id,idx_selects | idx_session_id | 42 | const | 1 | |
±—±------------±------------±------±----------------- ----------±---------------±--------±------±-----±------ +
1 row in set (0.00 sec)

ad3.
mysql> explain select * from ca_sessions WHERE session_id = ‘1ba4966d04a30c4895ac89bedfd0eced’;
±—±------------±------------±------±----------------- ----------±---------------±--------±------±-----±------ +
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±------------±------±----------------- ----------±---------------±--------±------±-----±------ +
| 1 | SIMPLE | ca_sessions | const | idx_session_id,idx_selects | idx_session_id | 42 | const | 1 | |
±—±------------±------------±------±----------------- ----------±---------------±--------±------±-----±------ +
1 row in set (0.00 sec)

ad4.
mysql> explain select * FROM ca_sessions WHERE last_activity < 1235606350;
±—±------------±------------±------±----------------- -±------------------±--------±-----±-----±------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±------------±------±----------------- -±------------------±--------±-----±-----±------------+
| 1 | SIMPLE | ca_sessions | range | idx_last_activity | idx_last_activity | 4 | NULL | 1 | Using where |
±—±------------±------------±------±----------------- -±------------------±--------±-----±-----±------------+
1 row in set (0.16 sec)

after adding index on last_activity:
mysql> explain SELECT *
→ FROM ca_sessions
→ WHERE session_id = ‘1ba4966d04a30c4895ac89bedfd0eced’
→ AND last_activity > 1236803500
→ AND user_agent = ‘Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.4; en’;
±—±------------±------------±------±----------------- ----------------------------±---------------±--------±— —±-----±------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±------------±------±----------------- ----------------------------±---------------±--------±— —±-----±------+
| 1 | SIMPLE | ca_sessions | const | idx_session_id,idx_selects,idx_last_activity | idx_session_id | 42 | const | 1 | |
±—±------------±------------±------±----------------- ----------------------------±---------------±--------±— —±-----±------+
1 row in set (0.00 sec)

Also, how long should the user_agent be typically, and why does it matter?

thanks.

Ok, the indexes should be fine. Does this server use query cache ? Xaprb wrote something about mysql freezes: http://www.mysqlperformanceblog.com/2009/03/19/mysql-random- freezes-could-be-the-query-cache/ . It could be also hardware problem (RAID failure). Or someone is running many queries on tables without indexes.

Thanks a lot for your help.

It appears that query_cache_size is disabled, but the query_cache_type is ON, I am not sure if it matters and what it really means.

mysql> show variables like ‘%query%’;
±-----------------------------±--------+
| Variable_name | Value |
±-----------------------------±--------+
| ft_query_expansion_limit | 20 |
| have_query_cache | YES |
| long_query_time | 10 |
| query_alloc_block_size | 8192 |
| query_cache_limit | 1048576 |
| query_cache_min_res_unit | 4096 |
| query_cache_size | 0 |
| query_cache_type | ON |
| query_cache_wlock_invalidate | OFF |
| query_prealloc_size | 8192 |
±-----------------------------±--------+
10 rows in set (0.01 sec)

As for your second point, would it make sense that a query takes 100+ seconds even if tables indexes are not set properly?

Is there anything else that I should try? I am open to any suggestions.

Here is what I tried before:
I launched 100 concurrent connections (with httpd_load) and they all returned in under 1 sec. This is a lot more than our typical usage. So it is not a currency issues, but more of a random locking or random cache cleaning issue.

You could set
query_cache_type = OFF;
This should disable cache (“should”, because there could be bug in mysql and some people have had problems even with query_cache_size = 0)

There are several variables to look at. I think that phpmyadmin gives good hints about those variables. Just look under status tab, and search for:
Handler_read_rnd
Handler_read_rnd_next
Select_full_join
Big values and red color mean that there is something wrong with the queries (and especially with indexes).
There is also Created_tmp_disk_tables and Created_tmp_tables. Second one shows how many temporary tables were made inside memory. As You know memory is faster than disk, so it is better when temporary tables are inside memory. As I remember temporary tables could be created by mysql when there is “order by”.

Is this table innodb or myisam ?

I have set query_cache_type to OFF in global+session. We’ll see how that works out.

It appears that setting SQL_NO_CACHE in select queries did not help because i just recently saw transactions that took 30+ seconds to execute.

We use InnodDB.As for the ‘status’ variables, you’re on to something, here are the red variables (all the ones you mentioned)

Handler_read_rnd 2,984 k
Handler_read_rnd_next 137 M
Select_full_join 7,542
Created_tmp_disk_tables 80 k
Created_tmp_tables 252 k (only one not red)

Do you recommend I analyze each query on the website?

In addition these variables looked fishy as well (and were highlighted red):

Innodb_row_lock_time_avg 3,705
Innodb_row_lock_time_max 52 k
Innodb_row_lock_waits 60

Advice on where I should start?
Thanks for the help.

http://www.xaprb.com/blog/2007/09/18/how-to-debug-innodb-loc k-waits/
Maybe this one will help.

Some queries need indexes, You can find them by enabling logging slow queries and queries not using indexes (both of them have to be enabled).

I enabled log-queries-without-indexes and we’ll see what comes up. As for the article, I tried installing innotop and got a bunch of errors. I’ve asked my support server team to install it. Hopefully, they do soon.

Will keep you updated.

this is a VPS, so i’m wondering how i can track whether outside processes are actually affecting our DB? I’ve used top but that shows pretty minimal load on our system.

I currently have my memory pools at, how can i check what their max’s are?

innodb_buffer_pool_size = 128M
innodb_additional_mem_pool_size = 8M

Also,

innodb_flush_log_at_trx_commit=0

Anything else I should look for?