MySQL Query Analyzer - first impressions

I've now been playing with MySQL Enterprise Monitor in its latest guise (which includes the Query Analyzer) for a number of days. To be honest, this is pretty amazing stuff.

Once installed, all you have to do is point your applications to port 4040 on the database server instead of the default of port 3306 and in a few minutes you'll start to see the queries being logged in the Query Analyzer tab. You can sort them by database, by execution time, by execution count, or any of the other table headings in the output. You can also filter by partial query as well as a variety of other filters.

"Ho hum" I hear you say? Yes you could probably just take a look at the processlist on your db server to see what it is doing now, but the statistics Query Analyzer provides can be extremely powerful. Two examples:

#1 - Badly performing query

I installed Quan (Query Analyzer) and within about 20 minutes it became clear I had a query that was averaging 14 seconds to run. This query doesn't get run all that often, every 5 minutes or so, but it uses a table that is the most active table on our system.

OK, click on the query and it pops up a full view, showing the query with literals replaced by place holders. If you have Example Queries configured, you can check to see if there is an example showing all of the data, and if you have Example Explain configured, you will also be able to get a full breakdown of what indexes will be used in resolving the query.

With a few minutes of checking the query and fine tuning it I was able to get it down to 0.15 seconds on average. That is almost a 100 fold improvement. Yes, I could probably have done something about it earlier, as I knew it was sub-optimal, but seeing it showing at the top of the list of queries hogging resources lifts the sense of urgency.

#2 - Excessive executions of query

While looking at the first one I noticed another query starting to work its way up the list. This one was a relatively simple query, but was clocking up more than 2,000 executions a minute. Now unlike the first I wasn't all that sure where this query was being run, but using the 'full' display format I could look for that exact string in the codebase, and was quickly able to identify where it was being called.

A little more searching and I found that the query was within a loop where it would get exactly the same information each time, because the variable data was set outside of the loop! Fix that and it now runs around 10-15 times a minute.

I could have discovered this one without Quan. Probably. If I'd done a code review that could have taken days if not weeks. If I wasn't so bored with the code review that I managed to understand the implications of the query within the loop. Instead I was able to find and fix it within minutes, and then be able to verify that the problem was resolved within a few more minutes.

Think on this one for a minute. To display the particular page in question there were up to 200 unnecessary queries. That is a lot of running around in circles. I'm now going hunting for the author of that gem with a big stick - and hoping that it wasn't me :)

Quan should be in every DBA's toolkit. It is an absolute must.

If I get my act together I'll put up some before and after screen shots.

*DISCLAIMER: I am an employee of Sun Microsystems, part of the team responsible for the MySQL.com websites, so I am almost certainly biased. MySQL.com is a pretty busy website though and we like to think that it hits our software pretty hard.

Behind the scenes at MySQL.com

Many people know I work for MySQL (now a part of Sun Microsystems). Since working in the team that brings you www.mysql.com and its related sites, I've been able to get access to pre-release versions of all of the software that MySQL make. I have tried to keep pretty quiet about what I do for a day job - mainly because I didn't think anyone would be all that interested. I've since found out that people are intensely interested in what we do behind the scenes at MySQL.com. So I figured I should probably let people in on a few secrets - at least those that are for public disclosure.

I'm not sure how often I'll be blogging, or what about, but I hope you will find it interesting.

Vale Gryphon - Goodbye old friend

I had to have my dog, Gryphon, put down tonight. I've mentioned him before in this blog - forgive me if I don't feel like grabbing the URL for you, I'm sure if you are interested you can find it yourself.

Gryphon was a 12 1/2 year old German Shepherd Dog. He was also the most lovable and yet most annoying pet I've had so far. There is nothing like having a full body cuddle with 45kg of dog to make you feel the world is worth living. Well, I had one last cuddle with poor Gryph as the needle went in and he went to sleep, never to wake.

There are no words for how wretched I feel at the moment. I wrestled with the timing of his end, but in the end it was clear that if he couldn't walk two steps without assistance, and the side-effects of the medication were now becoming an issue in their own right, the time was here. As mentioned before, I did not hesitate, no matter how hard it was for me. He didn't deserve to suffer and so I acted.

I'm probably being a bit blunt for some of you who don't like to be confronted with the reality of life, but there is no getting around the facts. Gryphon had a great life and contributed to me having a great life. Such devotion and mutual joy requires reciprocal dedication and strength of resolve when the hard decisions must be made.

So now I need to have a drink or two in Gryphon's honour, and I hope some of you out there will join me.

On badly behaved crawlers

For the last few weeks my main system has had to be rebooted on a daily, and sometimes twice daily basis. Having other things on my mind I didn't bother getting too fussed, thinking perhaps I had some dodgy RAM or a disk on the way out - both things I could live with until they finally became terminal. As I started to look at the pattern of failure though, it started to look like there was a deliberate denial of service attack on the site. So I began active monitoring as well as log analysis.

Now I have no problem with search engines crawling my site. Mostly (apart from some well known exceptions) they behave themselves, abide by the robots.txt rules, and don't flood the system with requests. Above all, they perform a useful function to both me and my readers. I do have a problem with a crawler that I have identified as the cause of the system failures.

Brandwatch is apparantly involved in "Online Reputation Management and Brand Tracking in Social Media". They have a crawler that will just swamp a reasonably small site. No pacing, no maximum number of requests per second, just blast away at the fastest possible rate they can and if you happen to be the target then you'd better be ready for a connection storm. If you are having problems and see the string 'magpie-crawler' in your logs, then you may well be one of their victims. Worse, they perform no useful function for me or my readers. They sell information to their clients on who is talking about them. That's right, they are trawling my site in order to sell information to someone who is worried I might be saying something negative. Well I am. Brandwatch is a menace. And they need to get their crawler fixed. Until they do I have blocked 80.82.139.128/27 from my servers and I'd urge others to do the same until they wake up. What is particularly galling is that on their blog they have a piece on how bad Google Search is. Sheesh, at least Google's crawlers are well behaved and don't interfere with the running of the site.

Not happy, Jan!

* P.S. - No I haven't put in URLs. I don't want to advertise them any more than they deserve.

Book Review: Resplendent - Stephen Baxter

Title: RESPLENDENT
Publisher: Gollancz
Author: Stephen Baxter
Edition released: 2006
ISBN: 978-0-5750-7983-0
544 pages
Reviewed by: Adam Donnison

RESPLENDENT is book four of the DESTINY'S CHILDREN series and is a collection of short stories around the same theme, sorted into a timeline order. Each story stands on its own and has a short link paragraph added at the end to tie the book together into a novel-length anthology.

Starting around AD 5,300 and ending at AD 1,000,000 RESPLENDENT covers the period of humanity after the Qax have left, freeing humanity to begin rebuilding a society and expanding their frontiers.

Each story is eminently readable, although trying to read the entire anthology in a single session shows quite clearly that this is a collection of parts rather than an integrated whole. This is not to take away from the work in any way, and like all Baxter's work, this is great science fiction. Having the stories in the time order rather than published order also provides a continuing narrative that gives this a novel-like feeling, despite the occasional jumps in the story. The link pieces do well to cover the gaps.

Some stories could have been left out without affecting the story, indeed, may well have had a positive effect given the similarity that some of the clustered pieces show. If you are a Stephen Baxter fan, then RESPLENDENT is a convenient and effective collection of his shorter works published over the period 2000 to 2006, ending with a previously unpublished piece to bring the final threads together.

:: Next >>