Being a QA Engineer, how would you feel if you had access to a framework which can generate 80+ crashes – a mix of hitting developer introduced assertions (situations that should not happen), and serious unforeseen binary crashes – for the world’s most popular open source database software – each and ever hour? What if you could do this running on a medium spec machine – even a laptop?
The seniors amongst you may object “But… generating a crash or assertion is one thing – creating a repeatable testcase for the same is quite another.”
Introducing pquery, mtr_to_sql, reducer.sh (the pquery-enabled version), and more:
80+ coredumps per hour. Fully automatic testcase creation. Near-100% testcase reproducibility. C++ core. 15 Seconds run time per trial. Up to 20-25k lines of SQL executed per trial. CLI testcases. Compatible with sporadic issues. High-end automation of many aspects.
It all started when we realized how slow RQG really is. The Random Query Generator by Philip Stoev is a fantastic tool, and it has been greatly expanded over the years, but though it is a Swiss army knife in what you can do with it, when it comes to speed it is not the fastest. The Perl backend – combined with much random-ness – has made the system slow. At least when compared with the ultra-fast execution of C++ code.
I discussed things with Alexey Bychko, and before long pquery was born. The C++ core code of pquery is Alexey’s creation. It easily executes 20k random lines of SQL in 15-20 seconds, with full logging (including errors) turned on. Though the tool looks fairly simple when reviewing the code, it is incredibly powerful.
Now, one thing which people being introduced to QA for MySQL (or any other large software with many features/functions/options etc.) have to grasp is “random spread testing”. If your random spread (and the amount of samples) is large enough (read: ‘sufficient’), it is relatively easy to get a good “overall quality” estimate of your software by doing a few runs (taking usually around 1-3 days – or longer if various options are being tested).
So,we now had speed (pquery) and near-perfect testcase simplification/reduction & reproducibility (the new pquery adaption of reducer.sh) – but we needed one thing more: SQL which would cover… well… every area of mysqld. A fast framework without matching grammars is not worth much…
Converting the grammars from RQG seemed like a mammoth task – and we would really just be re-writing RQG in C. And creating a new SQL generator was an almost hopeless venture (I gave it a short try) – given the huge variety and complexity when constructing SQL statements.
I took the cheeky road. And it paid off. mtr_to_sql.sh was born.
The MTR testcases included (and delivered) with the MySQL server download contain individual tests for nearly every possible SQL syntax possible, including ones that – ought to – error out (but not crash). Not only that, there are specific MTR testcases for each feature, not to mention the many MTR testcases that were added to cover bug regression testing. Where there is smoke…
1 2 3 4 5 6 7 8 9 10 11 12 13 14 | [roel@localhost 5.6]$ pwd /bzr/5.6 [roel@localhost 5.6]$ find . | grep ".test$" | wc -l 3867 [roel@localhost 5.6]$ cat ~/percona-qa/mtr_to_sql.sh | grep BZR_PATH | head -n1 BZR_PATH="/bzr/5.6/mysql-test" [roel@localhost 5.6]$ time ~/percona-qa/mtr_to_sql.sh Done! Generated /tmp/mtr_to_sql.yy for RQG, and /tmp/mtr_to_sql.sql for pquery (SQL is indentical in both, but first is formatted for use with RQG) real 0m20.150s user 1m2.951s sys 0m1.214s [roel@localhost 5.6]$ cat /tmp/mtr_to_sql.sql | wc -l 107541 |
107.5K of high-quality SQL. Covering every possible functionality and buggy area out there. Free.
Let the testing begin!
I was quite dumbfounded when (after further tuning and scripting) we started seeing 50+, then 80+ cores per hour. Sig11’s (crashes), Sig6’s (asserts), server hangs, character set issues, error log errors and so on. Many crashes and issues in optimized code. Fun.
Our best weeks yet?
Pquery update: 220+ bugs logged, of which 140+ in MySQL, 60+ in Percona, 10+ in TokuTek (with limited TokuTek testing) #mysql #percona #qa
— Roel Van de Paar (@RoelVandePaar) November 21, 2014
Last week @rameshvs02 & @RoelVandePaar logged 70+ bugs. Today reducer.sh was updated w/ pquery functionality. Testcases on their way! #mysql
— Roel Van de Paar (@RoelVandePaar) October 27, 2014
All of the above can be done on commodity hardware, running a single server, running single-threaded SQL (single client) and with no special mysqld options activated.
Compare this to RQG. Even with combinations.pl running hundreds if not thousands of mysqld — option combinations, and with nearly-everything-is-random-sql, it still comes nowhere near even one tenth of that number/speed. And this is even when using high-end hardware, 8 simultaneous mysqld servers, up to 20-25 client threads and at times special grammar-mix tools like MaxiGen etc.
In preparation for the Twitter week mentioned above we started running 4-5 simultaneous pquery run’s (5x mysqld, still all single threaded; a single client per mysqld) in different shell screen sessions, controlled by cron jobs.
A whole set of automation scripts were quickly added to handle the huge influx in bugs (you can get all for free (GPLv2) at $bzr branch lp:percona-qa – see pquery*.sh files), and now you can quickly review a list of issues pquery discovered. For writing this article, I started a run and in it’s first hour it found exactly 85 crashes. Here is a report from around ~2h;
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 | [roel@localhost 830147]$ ~/percona-qa/pquery-results.sh ================ Sorted unique issue strings (Approx 439 trials executed, 167 remaining reducer scripts) btr0btr.ic line 143 (Seen 31 times: reducers 123,124,135,150,159,164,16,173,175,178,179,18,196,199,224,22,238,245,286,310,319,324,366,388,38,401,67,73,78,88,9) btr0btr.ic line 169 (Seen 1 times: reducers 158) btr0cur.cc line 769 (Seen 1 times: reducers 304) buf0buf.cc line 2738 (Seen 2 times: reducers 113,257) fsp0fsp.cc line 1899 (Seen 5 times: reducers 145,174,409,69,85) . is_set (Seen 32 times: reducers 112,165,170,192,203,218,231,249,24,253,259,273,278,280,289,329,331,333,336,338,363,371,373,379,384,398,404,44,47,6,72,82) .length % 4 (Seen 4 times: reducers 169,220,307,80) m_lock .= __null .... thd->mdl_context.is_lock_owner.m_namespace, ...., ...., MDL_SHARED(Seen 3 times: reducers 297,403,86) row0quiesce.cc line 683 (Seen 1 times: reducers 97) row0umod.cc line 338 (Seen 1 times: reducers 357) .slen % 2 (Seen 21 times: reducers 106,122,131,144,221,250,251,252,275,282,296,316,318,32,359,375,39,405,407,43,46) .slen % 4 (Seen 5 times: reducers 103,382,76,7,81) sort_field->length >= length (Seen 1 times: reducers 138) timer == __null (Seen 36 times: reducers 133,139,149,160,161,181,183,184,185,20,212,227,229,234,244,260,266,274,292,294,295,298,301,308,326,327,330,343,346,364,367,400,48,50,59,99) .tlen % 2 (Seen 8 times: reducers 117,119,200,205,213,217,285,35) .tlen % 4 (Seen 3 times: reducers 25,355,365) trx0roll.cc line 264 (Seen 1 times: reducers 40) Z21mysql_execute_commandP3THD (Seen 4 times: reducers 182,237,291,393) ZN13Bounded_queueIhhE4pushEPh (Seen 3 times: reducers 101,118,214) ZN8Protocol13end_statementEv (Seen 4 times: reducers 211,410,42,61) ================ |
For these (standard by now) pquery runs, we use pquery-run.sh. It starts a server, executes and monitors the pquery binary, and then checks on the outcome:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 | [roel@localhost percona-qa]$ ./pquery-run.sh [07:23:21] [0] Workdir: /sda/459689 | Rundir: /dev/shm/459689 | Basedir: /sda/Percona-Server-5.6.21-rel69.0-687.Linux.x86_64-debug [07:23:21] [0] mysqld Start Timeout: 60 | Client Threads: 1 | Queries/Thread: 25000 | Trials: 100000 | Save coredump trials only: TRUE [07:23:21] [0] Pquery timeout: 15 | SQL file used: /home/roel/percona-qa/pquery/main-new.sql [07:23:21] [0] MYSAFE: --maximum-bulk_insert_buffer_size=1M --maximum-join_buffer_size=1M --maximum-max_heap_table_size=1M --maximum-max_join_size=1M --maximum-myisam_max_sort_file_size=1M --maximum-myisam_mmap_size=1M --maximum-myisam_sort_buffer_size=1M --maximum-optimizer_trace_max_mem_size=1M --maximum-preload_buffer_size=1M --maximum-query_alloc_block_size=1M --maximum-query_prealloc_size=1M --maximum-range_alloc_block_size=1M --maximum-read_buffer_size=1M --maximum-read_rnd_buffer_size=1M --maximum-sort_buffer_size=1M --maximum-tmp_table_size=1M --maximum-transaction_alloc_block_size=1M --maximum-transaction_prealloc_size=1M --log-output=none --sql_mode=ONLY_FULL_GROUP_BY [07:23:21] [0] Archiving a copy of this script (/home/roel/percona-qa/pquery-run.sh) in the workdir (/sda/459689) for later reference... [07:23:21] [0] Archiving a copy of the infile used for this run (/home/roel/percona-qa/pquery/main-new.sql) in the workdir (/sda/459689) for later reference... [07:23:21] [0] Generating datadir template (using mysql_install_db)... [07:23:29] [0] Making a copy of mysqld used to /sda/459689/mysqld (handy for core file analysis and manual bundle creation)... [07:23:29] [0] Storing a copy of ldd files for mysqld in same directory also... [07:23:29] [0] Starting pquery testing iterations... [07:23:29] [0] ====== TRIAL #1 ====== [07:23:29] [0] Ensuring there are no relevant servers running... [07:23:29] [0] Clearing rundir... [07:23:29] [0] Generating new workdir /dev/shm/459689/1... [07:23:29] [0] Copying datadir from template... [07:23:29] [0] Starting mysqld. Error log is stored at /dev/shm/459689/1/log/master.err [07:23:29] [0] Waiting for mysqld (pid: 10879) to fully start... [07:23:31] [0] Server started ok. Client: /sda/Percona-Server-5.6.21-rel69.0-687.Linux.x86_64-debug/bin/mysql -uroot -S/dev/shm/459689/1/socket.sock [07:23:31] [0] Starting pquery (log stored in /dev/shm/459689/1/pquery.log)... [07:23:31] [0] pquery running... ./pquery-run.sh: line 150: 10879 Aborted (core dumped) $CMD > ${RUNDIR}/${TRIAL}/log/master.err 2>&1 <---- success! [07:23:32] [0] Cleaning up... [07:23:36] [0] pquery summary: 578/769 queries failed (24.84% were successful) [07:23:36] [0] mysqld core detected at /dev/shm/459689/1/data/core.10879.1000.1000.6.1414700611.mysqld [07:23:36] [1] Copying rundir from /dev/shm/459689/1 to /sda/459689/1 [07:23:36] [1] ====== TRIAL #2 ====== [...] |
(The MYSAFE settings are some generic settings specifically suited for QA testing – kindly provided by Shane Bester)
Within the scripts many QA-goodies are already built-in: automated gdb query extraction from the core and the error log (each added 3x to the end of the sql trace to ensure maximum reproducibility), unique issue classification using bug-relevant strings, /dev/shm execution for optimal speed, etc. – it is all based/build on many years of mysqld QA experience.
If you can’t wait to spin off some I-crashed-mysqld (it’s easy you know…) bugs of your own, download the tools at lp:percona-qa ($bzr branch lp:percona-qa) and checkout the various pquery* scripts. Some shown in use above.
And, when you’re ready for slightly more serious feature testing – add whatever statements your feature uses to the sql file (or you may even replace it), plus the relevant mysqld options modifications to pquery-run.sh (i.e. set the $MYEXTRA string). You can also use sql-interleave.sh/sql-interleave-switch.sh to interleave new sql into the main sql file(s). This script is available in the pquery/ directory of the percona-qa branch mentioned above. Soon you will see fireworks.
Enjoy the show!
You know one fun MySQL crash I saw once? It was remarkably (if brain-damagedly) simple: A field definition declared NOT NULL DEFAULT NULL, in MySQL 5.6.
…Yes, I know, the originator of this definition was seriously unclear on the concept of NOT NULL. But it shouldn’t have crashed MySQL.
I look forward to using this for the RocksDB engine for MySQL. When extracting SQL from mtr is anything done to preserve concurrency specified in the mtr tests?
I am getting following error:
/usr/lib64/libperconaserverclient.so.18: version `libperconaserverclient_18′ not found (required by /home/ec2-user/percona-qa/pquery/pquery)
I am trying to run:
${PQUERY_BIN} –infile=${RUNDIR}/${TRIAL}/${TRIAL}.sql –database=test –threads=${THREADS} –queries_per_thread=${QUERIES_PER_THREAD} –logdir=${RUNDIR}/${TRIAL} –log_all_queries –log_failed_queries –user=root –addr=some_ip –port=3306 >${RUNDIR}/${TRIAL}/pquery.log 2>&1 &
(libperconaserverclient.so.18 and libmysqlclient.so are present in /usr/lib64)
@Mark Cool! Re: concurrency – no, not atm. Interesting idea/question. As an alternative, running pquery –threads=x (where x>1 and likely best >100) would likely exhaustively random-cover any concurrency-related triggers if the test runs long enough. Even an hour per trial in this case seems plenty (and you will have likely hit many assertions before the hour is over). Alternatively or additionally, you could further limit the SQL to just the “interesting parts” so that all areas that ought to be covered definitely are. Multi-threaded testcase reduction is possible, but not straightforward, –threads=1 cases (and there are plenty) are easier to reduce. See pquery-prep-red.sh, then pquery-clean-known.sh and finally pquery-results.sh, then execute reducer{trialnr}.sh, as generated by pquery-prep.sh (and assuming all the time that pquery-run.sh was used to do the original run with x trials). Also, past experience shows that many (maybe as high as 85-90%) of multi-threaded (i.e. –threads=x) testcases are (or in some limited cases “can be made to be”) single-thread (i.e. client side – mysqld always having it’s background threads) reproducible.
@Shivam – easy fix; $ export LD_LIBRARY_PATH=${BASEDIR}/lib where ${BASEDIR} is your mysqld’s basedir (or your specific location). Depending on whether your are testing upstream mysqld or Percona Server, you would want to swap between using the pquery (Percona) or pquery-ms (MySQL) binary. Alternatively, see compile information in pquery subdirectory to self-compile pquery, potentially with libs included! As a side note, I may recommend using export LD_PRELOAD=/usr/lib64/libjemalloc.so.1 to use jemalloc (depending on what flavor of mysqld you are testing). Also, you may want to use pquery-run.sh instead – this wrapper script around pquery allows automated pquery runs with all bells and whisles included ($ cd ~; bzr branch lp:percona-qa; vi ~/percona-qa/pquery-run.sh). See reply to Mark above on further steps after pquery-run.sh. In pquery-run.sh you need to set some settings like basedir, pquery or pquery-ms binary etc. See in-script for details.
Thanks for the help. It worked.
I am creating a wrapper script like pquery-run.sh. Can you elaborate on how to identify *different* bugs/segmentation faults by using pquery with same main.sql file?
So far I have been able to hit the same segmentation fault again and again with following command:
./pquery-ms –infile=./main.sql –database=test –threads=2 –queries_per_thread=10000 –log_all_queries –log_failed_queries –user=root –port=3306 –addr=127.0.0.1
I am unclear about your statement: “80+ coredumps per hour”. Aren’t they for the same issue?
@Shivam – Great you got it working! The 80 coredumps per hour? These are many different issues. Offcourse there are duplicates, and it looks like you are hitting a particularly nasty one, but in general you should see a spread. As a good example, see the ~/percona-qa/pquery-results.sh run above, taken after about 2 hours of running; 20 different issues with a bunch of duplicates thereof. The duplicates are handy in a way, as they produce[d] different testcases for the same assertion/crash.
Back to the segfault you keep hitting again and again. Those are ones that we call “qa blockers” – and we tag them on our launchpad with “qablock”. There are several things that you can do with these; 1) ask developers to fix them (or hire Percona to do it for you), or 2) workaround the issue by disabling the particular sql needed to trigger this bug in the sql file you use. This is quite easy to do. Firstly, you need to find out what queries are triggering your issue. Two actions; a) check one of the produced error logs near the end for the “Query: …” statement and b) use gdb to extract all queries that where running at the time of the assertion/crash (we already have scripts for this… see extract_query.gdb and this (including last comment – the variable name changed). Finally, remove or remark these queries in the sql file (and log a bug for the issue seen so it will get fixed in time).
But, for many of these sort of things “we’ve been there, and done that” and all this is already highly automated in percona-qa (except manually disabling qablock sql in the sql files, this is easy/quick to do). Here’s how I suggest going about things; 1) use pquery-run.sh (it uses /dev/shm for nice fast processing), 2) go to the workdir produced by it (as set by you in the $WORKDIR variable in pquery-run.sh) and run ~/percona-qa/pquery-prep-red.sh – this will produce nice testcase reducer scripts ready-to-run … it will auto-extract the query from the error log *and* from the coredump and add these to the end of the pquery sql trace (in the numbered subdirectories) – btw, you could get the to-remark queries from here if that makes sense. 3) Step 3 is optional depending on what you are running: If you are using Percona Server or upstream MySQL, simply run ~/percona-qa/pquery-clean-known.sh. 4) Run ~/percona-qa/pquery-results.sh – see the example in the main text above – based on unique bug text strings, it will ‘classify’ each issue and give you a nice output as to the newly found issues. Don’t be suprised to see only a handful if you are using Percona Server or upstream MySQL and have run the cleaner script pquery-clean-known.sh, as we have logged literally hundreds of bugs over the last months already. Yet, you’re running dual-threaded so you may see new fireworks :). 5) Run the individual reducer scripts. These will reduce your testcase from 30k+ lines to a few hundred, to <5-25, often within the space of an hour/a few hours. Reducer is a powerfull tool. Yet, as you are running two threads, a bit more work may be needed. See how you go (and let us know!). Also, you may like to checkout ~/percona-qa/reproducing_and_simplification.txt which has lots of goodies on how to get testcases to "work" in the first place. Our reproducibility is very high, ~100%, with the occasional "looser" here or there, but in those cases we still have the coredump/stacks from the original trial run and so it's sometimes easy for devs to do a code analysis and find/fix the bug that way.
I hope this answers the questions you had. Looks like a blog post on pquery and it's framework's use would be a good idea too. In short; it is all there already, ready to use. If you have some cool updates, feel free to contribute too. Anyone is free to push to the tree, but please 1) test your changes, 2) be prepared to have changes revoked in case it breaks our integration etc. 🙂
Enjoy!
Followup article: https://www.percona.com/blog/2015/03/17/free-mysql-qa-and-bash-linux-training-series/
Static binaries now available! See https://www.percona.com/blog/2015/04/09/pquery-binaries-with-statically-included-client-libs-now-available/
All, please note we have moved percona-qa to GitHub:
https://github.com/Percona-QA/percona-qa
To clone it, use:
$ sudo yum install git
$ cd ~
$ git clone https://github.com/Percona-QA/percona-qa.git
reducer.sh was also put directly into this repository (and it is maintained there), so *no* need anymore to separately fetch lp:randgen.
And the pquery Github link (though it’s probably best to use the framework) is here; https://github.com/Percona-QA/pquery/