Hack MySQL Blog

Optimizing Oracle Performance by Cary Millsap and Jeff Holt uses Oracle to make its points, but these points apply also to MySQL. The primary lesson I took away from this book is: all else aside, optimize/fix the user-action that provides the most economic benefit to the company; do this by profiling just that action and optimizing/fixing the most time-consuming events even if they are “idle” or “wait” events.

The authors call the aforementioned approach to performance optimization “Method R”. It’s meant to be deterministic and teachable unlike “Method C”–the conventional method–whereby one uses their best judgment and experience to find the cause(s) of problems and fix them. I agree, and Method R is fundamentally, imho, just the scientific method in practice. Therefore, I like Method R because it puts “science” back into “computer science.”

The book also discusses queueing theory. It’s a whirlwind tour (~60 pages) but the authors provide everything you need to get started, including helper scripts and Excel worksheets. I’m pretty sure that I’ll be working with this theory more in my job; when I do, I’ll begin with what the authors have given me (“stand on the shoulders of giants“).

One criticism/clarification comes to mind: Method R is reactive. Let’s say your MySQL configuration is terrible so you’re not getting the most from your server as you could. Method R may indirectly expose this only if the configuration is the root cause of a slow user-action. So the configuration is only examined and fixed if the user deems their action unacceptably slow. However, users don’t always complain; sometimes they just “live with it” because they don’t care or they don’t think it can be fixed or they’re afraid to complain or it’s always been that way so they’re not even aware that things could be better. Thus, I think a more holistic view of performance optimization requires both a proactive method and a reactive method. Method R is a great reactive method, but someone should be checking stuff even when there doesn’t seem to be a problem. The authors don’t say “Method R is all you ever need to do”–I’m just making a clarification here.

Oracle extended SQL traces are used throughout the book to investigate performance issues. Does MySQL have anything similar? Nothing as cohesive comes to my mind (correct me if I’m wrong). I think we can achieve the same thing via microslow logs, the community PROFILE feature, session status values, and scripts to glue it all together. That’s a lot a of disparate pieces. I’d rather have MySQL extended SQL traces (in a format more easily parsable than Oracle’s).

In summary, Optimizing Oracle Performance is a must-read for any database professional. I think its emphases on providing the business the most “bang for its buck” and the deterministic nature of Method R are timeless and timely lessons for those of us who earn our livings by engaging in the science of computing.

Like I said earlier, every tiny change that the test suite reveals after code changes is significant. I caught a very subtle “bug” today in recent changes to mk-query-digest (a.k.a. mqd). If you like to read about subtle bugs, read on.

An mqd test on sample file slow023.txt began to differ after some pretty extensive code changes of late:

< # Query 1: 0 QPS, 0x concurrency, ID 0x8E38374648788E52 at byte 0 ________
---
> # Query 1: 0 QPS, 0x concurrency, ID 0x2CFD93750B99C734 at byte 0 ________

The ID which depends on the query’s fingerprint has changed. It’s very important that we don’t suddenly change these on users because these IDs are pivotal in trend analyses with mqd’s --review-history option. First some background info on the recent code changes and then the little story about how I tracked down the source of this change.

mqd internals used to run like this: call parser module (like SlowLogParser) and pass it an array of callbacks which it ran events through. Now this has changed so there’s a single, unified pipeline of “callbacks” (they’re technically no longer callbacks). The first process in the pipeline is usually a parser module which returns each event and then mqd keeps pumping the events through the pipeline (in contrast to before where the parser module did the pumping). So “obviously” this has nothing to do with query fingerprinting or ID making which is done in code that has not changed. Thus, this “bug” was very perplexing at first.

First step: see what value make_checksum(), which makes the query IDs, used to get and gets now by using the Perl debugger:

DB<3> x $item
0 'select count(*) as a from x '


DB<12> x $item
0 'select count(*) as a from x'

The difference is that single trailing space. But why has this space suddenly disappeared in the new (later) rev? Something in fingerprint() must have changed, which is the sub that makes that query. Use the debugger again to step through fingerprint() while a watch is set on the var:

1574: $query =~ s/\A\s+//; # Chop off leading whitespace
DB<6>
Watchpoint 0: $query changed:
old value: ' select count(*) as A from X
'
new value: 'select count(*) as A from X
'
QueryRewriter::fingerprint(bin/mk-query-digest:1575):
1575: chomp $query; # Kill trailing whitespace
DB<6>
QueryRewriter::fingerprint(bin/mk-query-digest:1576):
1576: $query =~ tr[ \n\t\r\f][ ]s; # Collapse whitespace
DB<6>
Watchpoint 0: $query changed:
old value: 'select count(*) as A from X
'
new value: 'select count(*) as A from X '

Notice that the var did not change after the line “# Kill trailing whitespace” was executed. The trailing newline was removed and reduced to a single trailing space when “# Collapse whitespace” was executed. The new rev:

1585: $query =~ s/\A\s+//; # Chop off leading whitespace
DB<4>
Watchpoint 0: $query changed:
old value: ' select count(*) as A from X
'
new value: 'select count(*) as A from X
'
QueryRewriter::fingerprint(../mk-query-digest:1586):
1586: chomp $query; # Kill trailing whitespace
DB<4>
Watchpoint 0: $query changed:
old value: 'select count(*) as A from X
'
new value: 'select count(*) as A from X'

Notice how chomp in the new rev removed all trailing whitespace; the result of chomp has changed, but why? In case you didn’t know, chomp actually chomps any trailing $INPUT_RECORD_SEPARATOR, not just newlines. It just so happens that many of the parser modules change $INPUT_RECORD_SEPARATOR.

The root of this subtle but very important change is due to the fact that the parser modules no longer call the pipeline callbacks. When they did, their changes to $INPUT_RECORD_SEPARATOR were visible to the callbacks, and operations like fingerprint() are part of the callbacks. Now that they do not, their changes to $INPUT_RECORD_SEPARATOR are “invisible” and operations like fingerprint() see a different (i.e. the default) $INPUT_RECORD_SEPARATOR.

Conclusion in brief: an issue of scope at the beginning of mk-query-digest affects chomp causing fingerprint() and make_checksum() to generate different query IDs at the end of the script.

This is far from deeply technical but little things that should be simple but aren’t annoy me. I found that MySQL Sandbox --prompt_prefix and --prompt_body don’t “just work.” I wanted the prompt to be mysql \v> . So I tried:

make_sandbox_from_source /mysql/src/mysql-4.0.30 single --prompt_body=' \v> '
sh: -c: line 0: syntax error near unexpected token `newline'
sh: -c: line 0: `make_sandbox /mysql/src/mysql-4.0.30/4.0.30 --prompt_body= \v> '

Maybe my shell knowledge is more terrible than I realize so I verified that ‘ \v> ‘ does not need special escaping:

echo ' \v> '
\v>

Ok, so clearly it’s the fault of make_sandbox_from_source. I tried and tried to do this on the command line but failed. I decided to try ~/.msandboxrc, specifying:

prompt_prefix=mysql
prompt_body= \v>

That didn’t work either; it created the prompt 'mysql4.0.30>. The leading space for prompt_body is ignored and there’s an errant apostrophe at the start. The final working version is:

prompt_prefix=mysql
prompt_body=\v> '

You can’t see it but there’s a trailing space after “mysql” for the prompt_prefix which is not ignored (unlike leading space for the prompt_body).

I made changes to mk-query-digest yesterday that I didn’t expect to cause any adverse affects. On the contrary, several tests began to fail because a single new but harmless line began to appear in the expected output: “Databases 0″. Perhaps I’m preaching to the choir, as you are all fantastic, thorough and flawless programmers, but as for myself I’ve learned to never take a single failed test for granted.

One time a test failed because some values differed by a millisecond or two. Being curious I investigated and found that our standard deviation equation was just shy of perfect. I fixed it and spent hours cross-checking the myriad tiny values with my TI calculator. Probably no one cared about 0.023 vs. 0.022 but it’s the cultivation of a disposition towards perfection that matters.

My innocuous changes yesterday introduced a case of Perl auto-vivification. Doing:

my ($db_for_show) = $sample->{db} ? $sample->{db} : keys %{$stats->{db}->{unq}};

can auto-vivify $stats->{db}. Before yesterday, this was done before the report for those stats were printed; changes yesterday made this happen after the report. Thus the report did it’s job and reported db or “Databases 0″. It’s been fixed, and just in time since I’m doing Maatkit’s October release today.

I’ve begun a MySQL features timeline which is a quick reference showing as of what version MySQL features were added, changed or removed. The manual tells us this, of course, but I wanted a quicker reference. The list is far from complete as there’s a huge number of features to cover. I’ll continue to improve it and help is appreciated. Send me a quick email saying “feature x added/removed/changed as of version y” and I’ll do the rest. — If someone has already done this, please give me the url so I don’t reinvent the wheel.