← Back to team overview

randgen team mailing list archive

[Bug 1220975] [NEW] --sqltrace does not log all used transformer queries to the log

 

Public bug reported:

The --sqltrace function does not correctly log all queries which were
executed against mysqld to the RQG log. The difference seems to be in
the transformed queries. Some are logged, some are not. Issue is easy to
reproduce as described below.

In the example below, sqltrace output goes to /tmp/test1.log, log file
output goes to /tmp/test1.txt

[roel@qaserver rqg]$ cat .bzr/branch/last-revision
893 roel.vandepaar@xxxxxxxxxxx-20130905011549-8w9d4xejwoovmhi6
[roel@qaserver rqg]$ cat test1
ps -ef | grep 'test1' | grep -v grep | awk '{print $2}' | xargs sudo kill -9 > /dev/null 2>&1
rm -Rf /tmp/test1
mkdir /tmp/test1
cd /ssd/rqg
bash -c "set -o pipefail; perl /ssd/rqg/runall.pl --queries=100000000 --seed=24433 --duration=900 --querytimeout=60 --reporter=Shutdown,Backtrace,QueryTimeout,ErrorLog,ErrorLogAlarm --mysqld=--log-output=FILE --mysqld=--general_log_file=/tmp/test1.txt --sqltrace --threads=25 --mysqld=--innodb_file_per_table=1 --validator=Transformer --mysqld=--innodb_adaptive_hash_index_partitions=1 --basedir=/ssd/Percona-Server-5.5.32-rel31.0-564-debug.Linux.x86_64 --grammar=test1.yy --gendata=conf/examples/example.zz --mtr-build-thread=786 --mask=48291 --vardir1=/tmp/test1 > /tmp/test1.log 2>&1"
tail -n1 /tmp/test1.log
[roel@qaserver rqg]$ ./test1
2013-09-05T11:36:25 [21726] /ssd/rqg/runall.pl will exit with exit status STATUS_SERVER_CRASHED (101)   <--- status outcome is not important I think (it also happens with STATUS_ENVIRONMENT_FAILURE for example)
[roel@qaserver rqg]$ grep "transforms" /tmp/test1.txt | wc -l
4607
[roel@qaserver rqg]$ grep "transforms" /tmp/test1.log | wc -l
1054
[roel@qaserver rqg]$ grep "transforms.insert_select" /tmp/test1.txt | wc -l
1925
[roel@qaserver rqg]$ grep "transforms.insert_select" /tmp/test1.log | wc -l
457
[roel@qaserver rqg]$ grep "transforms.insert_select_15171" /tmp/test1.txt
                   10 Query     DROP TABLE IF EXISTS transforms.insert_select_15171
                   10 Query     CREATE TABLE transforms.insert_select_15171 SELECT GET_LOCK('LOCK', 65535)
                   10 Query     SELECT * FROM transforms.insert_select_15171 /* TRANSFORM_OUTCOME_UNORDERED_MATCH */
                   10 Query     DELETE FROM transforms.insert_select_15171
                   10 Query     INSERT INTO transforms.insert_select_15171 SELECT GET_LOCK('LOCK', 65535)
                   10 Query     SELECT * FROM transforms.insert_select_15171 /* TRANSFORM_OUTCOME_UNORDERED_MATCH */
                   10 Query     DELETE FROM transforms.insert_select_15171
                   10 Query     REPLACE INTO transforms.insert_select_15171 SELECT GET_LOCK('LOCK', 65535)
                   10 Query     SELECT * FROM transforms.insert_select_15171 /* TRANSFORM_OUTCOME_UNORDERED_MATCH */
                   10 Query     DROP TABLE transforms.insert_select_15171
[roel@qaserver rqg]$ grep "transforms.insert_select_15171" /tmp/test1.log
[roel@qaserver rqg]$

This is likely reproducible on any MySQL version, but in this case I
used Percona Server (lp:percona-server/5.5) at revid 564
laurynas.biveinis@xxxxxxxxxxx-20130823073534-jcx7aq9dqmpg87zt - the
issue is consistently reproducible on it. If needbe, this server can
easily be build by using the lp:percona-qa/build_percona.sh script and
using the debug version. (i.e. bzr branch lp:percona-server/5.5 -> bzr
branch lp:percona-qa -> go to 5.5 directory -> call percona-
qa/build_percona.sh script with no options -> move resulting debug build
to location of choice after doing cd ..)

** Affects: randgen
     Importance: Critical
     Assignee: John H. Embretsen (johnemb)
         Status: Confirmed

-- 
You received this bug notification because you are a member of Random
Query Generator Team, which is subscribed to Random Query Generator.
https://bugs.launchpad.net/bugs/1220975

Title:
  --sqltrace does not log all used transformer queries to the log

Status in SQL Generator for testing SQL servers (MySQL, JavaDB, PostgreSQL):
  Confirmed

Bug description:
  The --sqltrace function does not correctly log all queries which were
  executed against mysqld to the RQG log. The difference seems to be in
  the transformed queries. Some are logged, some are not. Issue is easy
  to reproduce as described below.

  In the example below, sqltrace output goes to /tmp/test1.log, log file
  output goes to /tmp/test1.txt

  [roel@qaserver rqg]$ cat .bzr/branch/last-revision
  893 roel.vandepaar@xxxxxxxxxxx-20130905011549-8w9d4xejwoovmhi6
  [roel@qaserver rqg]$ cat test1
  ps -ef | grep 'test1' | grep -v grep | awk '{print $2}' | xargs sudo kill -9 > /dev/null 2>&1
  rm -Rf /tmp/test1
  mkdir /tmp/test1
  cd /ssd/rqg
  bash -c "set -o pipefail; perl /ssd/rqg/runall.pl --queries=100000000 --seed=24433 --duration=900 --querytimeout=60 --reporter=Shutdown,Backtrace,QueryTimeout,ErrorLog,ErrorLogAlarm --mysqld=--log-output=FILE --mysqld=--general_log_file=/tmp/test1.txt --sqltrace --threads=25 --mysqld=--innodb_file_per_table=1 --validator=Transformer --mysqld=--innodb_adaptive_hash_index_partitions=1 --basedir=/ssd/Percona-Server-5.5.32-rel31.0-564-debug.Linux.x86_64 --grammar=test1.yy --gendata=conf/examples/example.zz --mtr-build-thread=786 --mask=48291 --vardir1=/tmp/test1 > /tmp/test1.log 2>&1"
  tail -n1 /tmp/test1.log
  [roel@qaserver rqg]$ ./test1
  2013-09-05T11:36:25 [21726] /ssd/rqg/runall.pl will exit with exit status STATUS_SERVER_CRASHED (101)   <--- status outcome is not important I think (it also happens with STATUS_ENVIRONMENT_FAILURE for example)
  [roel@qaserver rqg]$ grep "transforms" /tmp/test1.txt | wc -l
  4607
  [roel@qaserver rqg]$ grep "transforms" /tmp/test1.log | wc -l
  1054
  [roel@qaserver rqg]$ grep "transforms.insert_select" /tmp/test1.txt | wc -l
  1925
  [roel@qaserver rqg]$ grep "transforms.insert_select" /tmp/test1.log | wc -l
  457
  [roel@qaserver rqg]$ grep "transforms.insert_select_15171" /tmp/test1.txt
                     10 Query     DROP TABLE IF EXISTS transforms.insert_select_15171
                     10 Query     CREATE TABLE transforms.insert_select_15171 SELECT GET_LOCK('LOCK', 65535)
                     10 Query     SELECT * FROM transforms.insert_select_15171 /* TRANSFORM_OUTCOME_UNORDERED_MATCH */
                     10 Query     DELETE FROM transforms.insert_select_15171
                     10 Query     INSERT INTO transforms.insert_select_15171 SELECT GET_LOCK('LOCK', 65535)
                     10 Query     SELECT * FROM transforms.insert_select_15171 /* TRANSFORM_OUTCOME_UNORDERED_MATCH */
                     10 Query     DELETE FROM transforms.insert_select_15171
                     10 Query     REPLACE INTO transforms.insert_select_15171 SELECT GET_LOCK('LOCK', 65535)
                     10 Query     SELECT * FROM transforms.insert_select_15171 /* TRANSFORM_OUTCOME_UNORDERED_MATCH */
                     10 Query     DROP TABLE transforms.insert_select_15171
  [roel@qaserver rqg]$ grep "transforms.insert_select_15171" /tmp/test1.log
  [roel@qaserver rqg]$

  This is likely reproducible on any MySQL version, but in this case I
  used Percona Server (lp:percona-server/5.5) at revid 564
  laurynas.biveinis@xxxxxxxxxxx-20130823073534-jcx7aq9dqmpg87zt - the
  issue is consistently reproducible on it. If needbe, this server can
  easily be build by using the lp:percona-qa/build_percona.sh script and
  using the debug version. (i.e. bzr branch lp:percona-server/5.5 -> bzr
  branch lp:percona-qa -> go to 5.5 directory -> call percona-
  qa/build_percona.sh script with no options -> move resulting debug
  build to location of choice after doing cd ..)

To manage notifications about this bug go to:
https://bugs.launchpad.net/randgen/+bug/1220975/+subscriptions


Follow ups

References