If you've ever used MySQL, you've probably used either the SHOW STATUS; query or the equivalent mysqladmin status command at least once.
$ mysqladmin status
Uptime: 569459 Threads: 2 Questions: 17666 Slow queries: 3 Opens: 118
Flush tables: 1 Open tables: 111 Queries per second avg: 0.31
Notice anything funny there? You should. Pulling out the trusty calculator tells me 17666 / 569459 is in fact closer to .0310, not 0.31. This a a classic case of floating point string printing gone wrong. Why does this happen? Turns out the internal printf() function used by MySQL doesn't support %f, the normal format specifier for floats. So instead, the float is printed using two integers separated by a period. Of course, this is total failsauce if you don't zero-pad your values.
The fix is easy; simply make sure you zero-pad the printed value right of the decimal point if doing division and modulo tricks. Here is the patch with a couple of extra lines of context to see what is going on:
diff -r -U8 mysql-5.5.12-original/sql/sql_parse.cc mysql-5.5.12/sql/sql_parse.cc
--- mysql-5.5.12-original/sql/sql_parse.cc 2011-04-11 05:44:03.000000000 -0500
+++ mysql-5.5.12/sql/sql_parse.cc 2011-05-17 09:07:28.000000000 -0500
@@ -1303,17 +1303,17 @@
if (!(uptime= (ulong) (thd->start_time - server_start_time)))
queries_per_second1000= 0;
else
queries_per_second1000= thd->query_id * LL(1000) / uptime;
length= my_snprintf(buff, buff_len - 1,
"Uptime: %lu Threads: %d Questions: %lu "
"Slow queries: %lu Opens: %lu Flush tables: %lu "
- "Open tables: %u Queries per second avg: %u.%u",
+ "Open tables: %u Queries per second avg: %u.%03u",
uptime,
(int) thread_count, (ulong) thd->query_id,
current_global_status_var.long_query_count,
current_global_status_var.opened_tables,
refresh_version,
cached_open_tables(),
(uint) (queries_per_second1000 / 1000),
(uint) (queries_per_second1000 % 1000));
Now the values print as expected when the decimal portion is less than 100:
$ mysqladmin status
Uptime: 3 Threads: 1 Questions: 2 Slow queries: 0 Opens: 33
Flush tables: 1 Open tables: 26 Queries per second avg: 0.666
$ mysqladmin status
Uptime: 50 Threads: 1 Questions: 3 Slow queries: 0 Opens: 33
Flush tables: 1 Open tables: 26 Queries per second avg: 0.060
I filed a bug report with the above patch, and got at least one piece of quick feedback, so we'll see if it gets fixed anytime soon. I also looked quickly for any other suspect format specifiers (the regex was '[ud]\.%[ud]') and didn't see any.
Shockingly this bug has been around since some changes in April 2007. I can't believe I was the only one noticing this and expecting it to get fixed at any time. I guess it just finally pissed me off enough today to do something about it.
Comments (0)