{"id":1568,"date":"2009-11-12T12:47:00","date_gmt":"2009-11-12T10:47:00","guid":{"rendered":"http:\/\/code.openark.org\/blog\/?p=1568"},"modified":"2009-12-16T09:10:11","modified_gmt":"2009-12-16T07:10:11","slug":"performance-analysis-with-mycheckpoint","status":"publish","type":"post","link":"https:\/\/code.openark.org\/blog\/mysql\/performance-analysis-with-mycheckpoint","title":{"rendered":"Performance analysis with mycheckpoint"},"content":{"rendered":"

mycheckpoint<\/a> (see announcement<\/a>) allows for both graph presentation and quick SQL access to monitored & analyzed data. I’d like to show the power of combining them both.<\/p>\n

InnoDB performance<\/h4>\n

Taking a look at one of the most important InnoDB metrics: the read hit ratio (we could get the same graph by looking at the HTML report<\/a>):<\/p>\n

\n
SELECT innodb_read_hit_percent FROM sv_report_chart_sample \\G\r\n*************************** 1. row ***************************\r\ninnodb_read_hit_percent: http:\/\/chart.apis.google.com\/chart?cht=lc&chs=400x200&chts=303030,12&chtt=Nov+10,+11:40++-++Nov+11,+08:55+(0+days,+21+hours)&chdl=innodb_read_hit_percent&chdlp=b&chco=ff8c00&chd=s:400664366P6674y7176677677u467773y64ux166666764366646y616666666666644444434444s6u4S331444404433341334433646777666666074736777r1777767764776666F667777617777777777777777yaRi776776mlf667676xgx776766rou67767777u37797777x76676776u6A737464y67467761777666643u66446&chxt=x,y&chxr=1,99.60,100.00&chxl=0:||Nov+10,+15:55|Nov+10,+20:10|Nov+11,+00:25|Nov+11,+04:40|&chxs=0,505050,10<\/pre>\n<\/blockquote>\n
\n
\"\"<\/pre>\n<\/blockquote>\n
We see that read hit is usually high, but occasionally drops low, down to 99.7, or even 99.6. But it seems like most of the time we are above 99.95% read hit ratio. It’s hard to tell about 99.98%.<\/p>\n
Can we know for sure?<\/h4>\n
We can stress our eyes, yet be certain of little. It’s best if we just query for the metrics! mycheckpoint<\/em> provides with all data, accessible by simple SQL queries:<\/p>\n
\n
SELECT SUM(innodb_read_hit_percent > 99.95)\/count(*)\r\n  FROM sv_report_sample;\r\n+-----------------------------------------------+\r\n| SUM(innodb_read_hit_percent > 99.95)\/count(*) |\r\n+-----------------------------------------------+\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 0.7844 |\r\n+-----------------------------------------------+<\/pre>\n<\/blockquote>\n
Yes, most of the time we’re above 99.95% read hit ratio: but not too often!<\/p>\n
I’m more interested in seeing how much time my server’s above 99.98% read hit:<\/p>\n
\n
SELECT SUM(innodb_read_hit_percent > 99.98)\/count(*)\r\n  FROM sv_report_sample;\r\n+-----------------------------------------------+\r\n| SUM(innodb_read_hit_percent > 99.98)\/count(*) |\r\n+-----------------------------------------------+\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 0.3554 |\r\n+-----------------------------------------------+<\/pre>\n<\/blockquote>\n
We can see the server only has 99.98% read hit percent 35% of the time. Need to work on that!<\/p>\n
Disk activity<\/h4>\n
Lower read hit percent means higher number of disk reads; that much is obvious. The first two following graphs present this obvious connection. But the third graph tells us another fact: with increased disk I\/O, we can expect more (and longer) locks.<\/p>\n
Again, this should be very intuitive, when thinking about it this way. The problem sometimes arises when we try to analyze it the other way round: “Hey! InnoDB has a lot of locks! What are we going to do about it?”. Many times, people will look for answers in their transactions<\/em>, their Isolation Level<\/em>, their LOCK IN SHARE MODE<\/em> clauses. But the simple answer can be: “There’s a lot of I\/O, so everything has to wait; therefore we increase the probability for locks; therefore there’s more locks”.<\/p>\n
The answer, then, is to reduce I\/O. The usual stuff: slow queries; indexing; … and, yes, perhaps transactions or tuning.<\/p>\n
The charts below make it quite clear that we have an issue of excessive reads -> less read hit -> increased I\/O -> more locks.<\/p>\n
\n
\"\"\r\n\r\n\"\"\r\n\r\n\"\"\r\n\r\n\"\"<\/pre>\n<\/blockquote>\n
By the way, the above resulted from the fact that, due to a problematic query, all slave stopped replicating. Slaves participated in read-balancing, so when they went stale, all reads were directed at the master (the monitored node).<\/p>\n
You have the metrics at your disposal<\/h4>\n
Looking at the following chart:<\/p>\n
\n
\"\"<\/pre>\n<\/blockquote>\n
It appears that there’s no slow queries. But this may be misleading: perhaps there’s just a little, that don’t show due to the chart’s large scale?<\/p>\n
One could argue that this is the chart’s fault. Perhaps there should be a distinct chart for “slow queries percent”. Perhaps I’ll add one. But we can’t have special charts for everything. It’s would be too tiresome to look at hundreds of charts.<\/p>\n
Anyway, my point is: let’s verify just how many slow queries we have:<\/p>\n
\n
SELECT slow_queries_psec FROM sv_hour ORDER BY id DESC;\r\n+-------------------+\r\n| slow_queries_psec |\r\n+-------------------+\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 3.05 |\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 3.83 |\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 4.39 |\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 4.03 |\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 3.86 |\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 3.56 |\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 3.73 |\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 3.79 |\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 3.58 |\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 3.55 |\r\n...\r\n+-------------------+<\/pre>\n<\/blockquote>\n
So, between 3 and 4 slow queries per second. It doesn’t look too good in this light. Checking on the percentage of slow queries (of total questions):<\/p>\n
\n
SELECT ROUND(100*slow_queries_diff\/questions_diff, 1) AS slow_queries_percent\r\n  FROM sv_hour ORDER BY id DESC LIMIT 10;<\/pre>\n<\/blockquote>\n
Or, since the above calculation is pre-defined in the reports tables:<\/p>\n
\n
SELECT slow_queries_percent FROM sv_report_hour_recent;\r\n+----------------------+\r\n| slow_queries_percent |\r\n+----------------------+\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 0.8 |\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 1.0 |\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 1.2 |\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 1.2 |\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 1.1 |\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 1.0 |\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 1.1 |\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 1.1 |\r\n|\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 1.0 |\r\n...\r\n+----------------------+<\/pre>\n<\/blockquote>\n
Accessible data<\/h4>\n
This is what I’ve been trying to achieve with mycheckpoint<\/em>. As a DBA, consultant and SQL geek I find that direct SQL access works best for me. It’s like loving command line interface over GUI tools. Direct SQL gives you so much more control and information.<\/p>\n
Charting is important, since it’s easy to watch and get first impressions, or find extreme changes. But beware of relying on charts all the time. Scale issues, misleading human interpretation, technology limitations – all these make charts inaccurate.<\/p>\n
mycheckpoint<\/a> allows for both methods, and, I believe, intuitively so.<\/p>\n
<\/propaganda><\/p>\n","protected":false},"excerpt":{"rendered":"
mycheckpoint (see announcement) allows for both graph presentation and quick SQL access to monitored & analyzed data. I’d like to show the power of combining them both. InnoDB performance Taking a look at one of the most important InnoDB metrics: the read hit ratio (we could get the same graph by looking at the HTML […]<\/p>\n","protected":false},"author":2,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"jetpack_post_was_ever_published":false,"_jetpack_newsletter_access":"","_jetpack_dont_email_post_to_subs":false,"_jetpack_newsletter_tier_id":0,"_jetpack_memberships_contains_paywalled_content":false,"_jetpack_memberships_contains_paid_content":false,"footnotes":"","jetpack_publicize_message":"","jetpack_publicize_feature_enabled":true,"jetpack_social_post_already_shared":false,"jetpack_social_options":{"image_generator_settings":{"template":"highway","default_image_id":0,"enabled":false},"version":2}},"categories":[5],"tags":[25,14,46,49,52],"class_list":["post-1568","post","type-post","status-publish","format-standard","hentry","category-mysql","tag-analysis","tag-innodb","tag-monitoring","tag-mycheckpoint","tag-performance"],"jetpack_publicize_connections":[],"jetpack_featured_media_url":"","jetpack_sharing_enabled":true,"jetpack_shortlink":"https:\/\/wp.me\/p2bZZp-pi","_links":{"self":[{"href":"https:\/\/code.openark.org\/blog\/wp-json\/wp\/v2\/posts\/1568","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/code.openark.org\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/code.openark.org\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/code.openark.org\/blog\/wp-json\/wp\/v2\/users\/2"}],"replies":[{"embeddable":true,"href":"https:\/\/code.openark.org\/blog\/wp-json\/wp\/v2\/comments?post=1568"}],"version-history":[{"count":34,"href":"https:\/\/code.openark.org\/blog\/wp-json\/wp\/v2\/posts\/1568\/revisions"}],"predecessor-version":[{"id":1608,"href":"https:\/\/code.openark.org\/blog\/wp-json\/wp\/v2\/posts\/1568\/revisions\/1608"}],"wp:attachment":[{"href":"https:\/\/code.openark.org\/blog\/wp-json\/wp\/v2\/media?parent=1568"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/code.openark.org\/blog\/wp-json\/wp\/v2\/categories?post=1568"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/code.openark.org\/blog\/wp-json\/wp\/v2\/tags?post=1568"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}