Log of 

perl runall-new.pl --basedir=/pxc --galera=ms    --threads=16 --queries=50000  9.26s user 8.95s system 5% cpu 5:10.36 total
Archie% perl runall-new.pl --basedir=/pxc --galera=ms  --reporter=Shutdown,Backtrace,ErrorLog,ErrorLogAlarm,Deadlock --grammar=$HOME/galera_stress.yy --gendata=/tmp/galera_stress.zz --threads=16 --queries=50000 --mysqld=--wsrep-provider=/pxc/lib/libgalera_smm.so  --mysqld=--innodb_flush_method=O_DIRECT   --mysqld=--wsrep-debug=1  --mysqld=--wsrep_provider_options='debug=1'
# 2013-08-30T14:15:57 [1169] Using Log::Log4perl
# 2013-08-30T14:15:57 [1169] Copyright (c) 2010,2011 Oracle and/or its affiliates. All rights reserved. Use is subject to license terms.
# 2013-08-30T14:15:57 [1169] Please see http://forge.mysql.com/wiki/Category:RandomQueryGenerator for more information on this test framework.
# 2013-08-30T14:15:57 [1169] Starting
# 2013-08-30T14:15:57 [1169] # runall-new.pl \
# 2013-08-30T14:15:57 [1169] # --basedir=/pxc \
# 2013-08-30T14:15:57 [1169] # --galera=ms \
# 2013-08-30T14:15:57 [1169] # --reporter=Shutdown,Backtrace,ErrorLog,ErrorLogAlarm,Deadlock \
# 2013-08-30T14:15:57 [1169] # --grammar=/home/raghavendra/galera_stress.yy \
# 2013-08-30T14:15:57 [1169] # --gendata=/tmp/galera_stress.zz \
# 2013-08-30T14:15:57 [1169] # --threads=16 \
# 2013-08-30T14:15:57 [1169] # --queries=50000 \
# 2013-08-30T14:15:57 [1169] # --mysqld=--wsrep-provider=/pxc/lib/libgalera_smm.so \
# 2013-08-30T14:15:57 [1169] # --mysqld=--innodb_flush_method=O_DIRECT \
# 2013-08-30T14:15:57 [1169] # --mysqld=--wsrep-debug=1 \
# 2013-08-30T14:15:57 [1169] # --mysqld=--wsrep_provider_options=debug=1
# 2013-08-30T14:15:57 [1169] master_port : 19300 slave_port : 19302 ports : 19300 19302 MTR_BUILD_THREAD : 930
# 2013-08-30T14:15:57 [1169] /media/Tintin/Work/code/randgen/pxc Revno: 903
# 2013-08-30T14:15:57 [1169] /media/Tintin/Work/code/randgen/pxc Revision-Id: <email address hidden>
# 2013-08-30T14:15:57 [1169] /pxc does not look like a bzr branch, cannot get revision info.
# 2013-08-30T14:15:57 [1169] Creating MySQL 5.5.33 database at /pxc/mysql-test/var/node0/data
# 2013-08-30T14:16:04 [1169] Creating MySQL 5.5.33 database at /pxc/mysql-test/var/node1/data
# 2013-08-30T14:16:10 [1169] MySQL Version:5.5.33
# 2013-08-30T14:16:10 [1169] Binary: /pxc/bin/mysqld
# 2013-08-30T14:16:10 [1169] Type: Debug
# 2013-08-30T14:16:10 [1169] Datadir: /pxc/mysql-test/var/node0/data
# 2013-08-30T14:16:10 [1169] Tmpdir: /pxc/mysql-test/var/node0/tmp
# 2013-08-30T14:16:10 [1169] Corefile: /pxc/mysql-test/var/node0/data/core.
# 2013-08-30T14:16:10 [1169] Starting MySQL 5.5.33: "/pxc/bin/mysqld" "--no-defaults" "--basedir=/pxc" "--datadir=/pxc/mysql-test/var/node0/data" "--lc-messages-dir=/pxc/share/mysql" "--character-sets-dir=/pxc/share/mysql/charsets" "--tmpdir=/pxc/mysql-test/var/node0/tmp" "--core-file" "--max-allowed-packet=128Mb" "--port=19300" "--socket=/pxc/mysql-test/var/node0/mysql.sock" "--pid-file=/pxc/mysql-test/var/node0/mysql.pid" "--general-log" "--general-log-file=/pxc/mysql-test/var/node0/mysql.log" --wsrep_sst_method=rsync --innodb_autoinc_lock_mode=2 --default-storage-engine=InnoDB --innodb_locks_unsafe_for_binlog=1 --binlog-format=row --wsrep_node_incoming_address=127.0.0.1 --wsrep_node_address=127.0.0.1 --wsrep_cluster_address='gcomm://?gmcast.listen_addr=tcp://127.0.0.1:5170&pc.ignore_sb=true' --wsrep_sst_receive_address=127.0.0.1:5173 --wsrep-provider=/pxc/lib/libgalera_smm.so --innodb_flush_method=O_DIRECT --wsrep-debug=1 --wsrep_provider_options=debug=1
# 2013-08-30T14:16:11 [1169] Cluster size after starting node 0: 1
# 2013-08-30T14:16:11 [1169] MySQL Version:5.5.33
# 2013-08-30T14:16:11 [1169] Binary: /pxc/bin/mysqld
# 2013-08-30T14:16:11 [1169] Type: Debug
# 2013-08-30T14:16:11 [1169] Datadir: /pxc/mysql-test/var/node1/data
# 2013-08-30T14:16:11 [1169] Tmpdir: /pxc/mysql-test/var/node1/tmp
# 2013-08-30T14:16:11 [1169] Corefile: /pxc/mysql-test/var/node1/data/core.
# 2013-08-30T14:16:11 [1169] Starting MySQL 5.5.33: "/pxc/bin/mysqld" "--no-defaults" "--basedir=/pxc" "--datadir=/pxc/mysql-test/var/node1/data" "--lc-messages-dir=/pxc/share/mysql" "--character-sets-dir=/pxc/share/mysql/charsets" "--tmpdir=/pxc/mysql-test/var/node1/tmp" "--core-file" "--max-allowed-packet=128Mb" "--port=19301" "--socket=/pxc/mysql-test/var/node1/mysql.sock" "--pid-file=/pxc/mysql-test/var/node1/mysql.pid" "--general-log" "--general-log-file=/pxc/mysql-test/var/node1/mysql.log" --wsrep_sst_method=rsync --innodb_autoinc_lock_mode=2 --default-storage-engine=InnoDB --innodb_locks_unsafe_for_binlog=1 --binlog-format=row --wsrep_node_incoming_address=127.0.0.1 --wsrep_node_address=127.0.0.1 --wsrep_cluster_address='gcomm://127.0.0.1:5170?gmcast.listen_addr=tcp://127.0.0.1:5171&pc.ignore_sb=true' --wsrep_sst_receive_address=127.0.0.1:5174 --wsrep-provider=/pxc/lib/libgalera_smm.so --innodb_flush_method=O_DIRECT --wsrep-debug=1 --wsrep_provider_options=debug=1
# 2013-08-30T14:16:17 [1169] Cluster size after starting node 1: 2
# 2013-08-30T14:16:17 [1169] -------------------------------
# 2013-08-30T14:16:17 [1169] Configuration
# 2013-08-30T14:16:17 [1169]   debug_server => ['', '']
# 2013-08-30T14:16:17 [1169]   dsn => ['dbi:mysql:host=127.0.0.1:port=19300:user=root:database=test']
# 2013-08-30T14:16:17 [1169]   duration => 3600
# 2013-08-30T14:16:17 [1169]   gendata => /tmp/galera_stress.zz
# 2013-08-30T14:16:17 [1169]   generator => FromGrammar
# 2013-08-30T14:16:17 [1169]   grammar => /home/raghavendra/galera_stress.yy
# 2013-08-30T14:16:17 [1169]   queries => 50000
# 2013-08-30T14:16:17 [1169]   reporters => ['Shutdown', 'Backtrace', 'ErrorLog', 'ErrorLogAlarm', 'Deadlock']
# 2013-08-30T14:16:17 [1169]   servers => ['DBServer::MySQL::MySQLd=ARRAY(0x2c4f138)', 'DBServer::MySQL::MySQLd=ARRAY(0x2c4f3d8)']
# 2013-08-30T14:16:17 [1169]   threads => 16
# 2013-08-30T14:16:17 [1169]   views => ['', '']
# 2013-08-30T14:16:17 [1169] # Creating MySQL table: test.table1_innodb_dynamic_int; engine: innodb; rows: 1 .
# 2013-08-30T14:16:17 [1169] # Creating MySQL table: test.table1_innodb_compressed_int; engine: innodb; rows: 1 .
# 2013-08-30T14:16:17 [1169] # Creating MySQL table: test.table1_innodb_default_int; engine: innodb; rows: 1 .
# 2013-08-30T14:16:17 [1169] # Creating MySQL table: test.table1_innodb_dynamic_int_autoinc; engine: innodb; rows: 1 .
# 2013-08-30T14:16:17 [1169] # Creating MySQL table: test.table1_innodb_compressed_int_autoinc; engine: innodb; rows: 1 .
# 2013-08-30T14:16:17 [1169] # Creating MySQL table: test.table1_innodb_default_int_autoinc; engine: innodb; rows: 1 .
# 2013-08-30T14:16:17 [1169] # Creating MySQL table: test.table1_innodb_dynamic_key_pk_parts_2_int; engine: innodb; rows: 1 .
# 2013-08-30T14:16:17 [1169] # Creating MySQL table: test.table1_innodb_compressed_key_pk_parts_2_int; engine: innodb; rows: 1 .
# 2013-08-30T14:16:17 [1169] # Creating MySQL table: test.table1_innodb_default_key_pk_parts_2_int; engine: innodb; rows: 1 .
# 2013-08-30T14:16:17 [1169] # Creating MySQL table: test.table1_innodb_dynamic_key_pk_parts_2_int_autoinc; engine: innodb; rows: 1 .
# 2013-08-30T14:16:17 [1169] # Creating MySQL table: test.table1_innodb_compressed_key_pk_parts_2_int_autoinc; engine: innodb; rows: 1 .
# 2013-08-30T14:16:17 [1169] # Creating MySQL table: test.table1_innodb_default_key_pk_parts_2_int_autoinc; engine: innodb; rows: 1 .
# 2013-08-30T14:16:17 [1169] # Creating MySQL table: test.table100_innodb_dynamic_int; engine: innodb; rows: 100 .
# 2013-08-30T14:16:17 [1169] # Creating MySQL table: test.table100_innodb_compressed_int; engine: innodb; rows: 100 .
# 2013-08-30T14:16:17 [1169] # Creating MySQL table: test.table100_innodb_default_int; engine: innodb; rows: 100 .
# 2013-08-30T14:16:17 [1169] # Creating MySQL table: test.table100_innodb_dynamic_int_autoinc; engine: innodb; rows: 100 .
# 2013-08-30T14:16:18 [1169] # Creating MySQL table: test.table100_innodb_compressed_int_autoinc; engine: innodb; rows: 100 .
# 2013-08-30T14:16:18 [1169] # Creating MySQL table: test.table100_innodb_default_int_autoinc; engine: innodb; rows: 100 .
# 2013-08-30T14:16:18 [1169] # Creating MySQL table: test.table100_innodb_dynamic_key_pk_parts_2_int; engine: innodb; rows: 100 .
# 2013-08-30T14:16:18 [1169] # Creating MySQL table: test.table100_innodb_compressed_key_pk_parts_2_int; engine: innodb; rows: 100 .
# 2013-08-30T14:16:18 [1169] # Creating MySQL table: test.table100_innodb_default_key_pk_parts_2_int; engine: innodb; rows: 100 .
# 2013-08-30T14:16:18 [1169] # Creating MySQL table: test.table100_innodb_dynamic_key_pk_parts_2_int_autoinc; engine: innodb; rows: 100 .
# 2013-08-30T14:16:18 [1169] # Creating MySQL table: test.table100_innodb_compressed_key_pk_parts_2_int_autoinc; engine: innodb; rows: 100 .
# 2013-08-30T14:16:18 [1169] # Creating MySQL table: test.table100_innodb_default_key_pk_parts_2_int_autoinc; engine: innodb; rows: 100 .
# 2013-08-30T14:16:18 [1169] # Creating MySQL table: test.table1000_innodb_dynamic_int; engine: innodb; rows: 1000 .
# 2013-08-30T14:16:18 [1169] # Creating MySQL table: test.table1000_innodb_compressed_int; engine: innodb; rows: 1000 .
# 2013-08-30T14:16:18 [1169] # Creating MySQL table: test.table1000_innodb_default_int; engine: innodb; rows: 1000 .
# 2013-08-30T14:16:19 [1169] # Creating MySQL table: test.table1000_innodb_dynamic_int_autoinc; engine: innodb; rows: 1000 .
# 2013-08-30T14:16:19 [1169] # Creating MySQL table: test.table1000_innodb_compressed_int_autoinc; engine: innodb; rows: 1000 .
# 2013-08-30T14:16:19 [1169] # Creating MySQL table: test.table1000_innodb_default_int_autoinc; engine: innodb; rows: 1000 .
# 2013-08-30T14:16:20 [1169] # Creating MySQL table: test.table1000_innodb_dynamic_key_pk_parts_2_int; engine: innodb; rows: 1000 .
# 2013-08-30T14:16:20 [1169] # Creating MySQL table: test.table1000_innodb_compressed_key_pk_parts_2_int; engine: innodb; rows: 1000 .
# 2013-08-30T14:16:20 [1169] # Creating MySQL table: test.table1000_innodb_default_key_pk_parts_2_int; engine: innodb; rows: 1000 .
# 2013-08-30T14:16:21 [1169] # Creating MySQL table: test.table1000_innodb_dynamic_key_pk_parts_2_int_autoinc; engine: innodb; rows: 1000 .
# 2013-08-30T14:16:21 [1169] # Creating MySQL table: test.table1000_innodb_compressed_key_pk_parts_2_int_autoinc; engine: innodb; rows: 1000 .
# 2013-08-30T14:16:21 [1169] # Creating MySQL table: test.table1000_innodb_default_key_pk_parts_2_int_autoinc; engine: innodb; rows: 1000 .
# 2013-08-30T14:16:22 [1169] Reporters: Shutdown, Backtrace, ErrorLog, ErrorLogAlarm, Deadlock
# 2013-08-30T14:16:22 [1169] Validators: ErrorMessageCorruption
# 2013-08-30T14:16:22 [1169] Caching schema metadata for dbi:mysql:host=127.0.0.1:port=19300:user=root:database=test
# 2013-08-30T14:16:22 [1169] Starting 16 processes, 50000 queries each, duration 3600 seconds.
# 2013-08-30T14:16:22 [1169] GenTest::ErrorFilter(1728) started
# 2013-08-30T14:16:22 [1730] Loading Validator GenTest::Validator::ErrorMessageCorruption.
# 2013-08-30T14:16:22 [1732] Loading Validator GenTest::Validator::ErrorMessageCorruption.
# 2013-08-30T14:16:22 [1734] Loading Validator GenTest::Validator::ErrorMessageCorruption.
# 2013-08-30T14:16:23 [1736] Loading Validator GenTest::Validator::ErrorMessageCorruption.
# 2013-08-30T14:16:23 [1738] Loading Validator GenTest::Validator::ErrorMessageCorruption.
# 2013-08-30T14:16:23 [1728] Query: REPLACE INTO `table1000_innodb_compressed_key_pk_parts_2_int_autoinc` ( `pk` , `pk` ) VALUES ( 0 , 104 ) , ( 'j' , 'j' ) failed: 1110 Column '%s' specified twice. Further errors of this kind will be suppressed.
# 2013-08-30T14:16:23 [1740] Loading Validator GenTest::Validator::ErrorMessageCorruption.
# 2013-08-30T14:16:23 [1728] Query: INSERT  INTO `table100_innodb_default_int` ( `pk` , `col_char_12` ) VALUES ( 3475505152 , 2936078336 ) , ( 3 , 809041920 ) failed: 1062 Duplicate entry '%s' for key '%s'. Further errors of this kind will be suppressed.
# 2013-08-30T14:16:23 [1742] Loading Validator GenTest::Validator::ErrorMessageCorruption.
# 2013-08-30T14:16:23 [1744] Loading Validator GenTest::Validator::ErrorMessageCorruption.
# 2013-08-30T14:16:23 [1746] Loading Validator GenTest::Validator::ErrorMessageCorruption.
# 2013-08-30T14:16:23 [1754] Loading Validator GenTest::Validator::ErrorMessageCorruption.
# 2013-08-30T14:16:23 [1756] Loading Validator GenTest::Validator::ErrorMessageCorruption.
# 2013-08-30T14:16:23 [1728] Query:  INSERT INTO j SELECT * FROM `table1000_innodb_compressed_key_pk_parts_2_int`  failed: 1146 Table '%s' doesn't exist. Further errors of this kind will be suppressed.
# 2013-08-30T14:16:23 [1758] Loading Validator GenTest::Validator::ErrorMessageCorruption.
# 2013-08-30T14:16:23 [1760] Loading Validator GenTest::Validator::ErrorMessageCorruption.
# 2013-08-30T14:16:24 [1762] Loading Validator GenTest::Validator::ErrorMessageCorruption.
# 2013-08-30T14:16:24 [1764] Loading Validator GenTest::Validator::ErrorMessageCorruption.
# 2013-08-30T14:16:24 [1728] Query: ROLLBACK TO SAVEPOINT A failed: 1305 SAVEPOINT %s does not exist. Further errors of this kind will be suppressed.
# 2013-08-30T14:16:24 [1766] Loading Validator GenTest::Validator::ErrorMessageCorruption.
# 2013-08-30T14:16:24 [1729] Started periodic reporting process...
# 2013-08-30T14:16:24 [1729] ErrorLogAlarm Reporter will monitor the log file /pxc/mysql-test/var/node0/data/../mysql.err
# 2013-08-30T14:16:24 [1728] Query: UPDATE IGNORE `table1000_innodb_compressed_int_autoinc` AS X SET `col_char_12` = 7  ORDER BY `col_char_12`,`col_char_12_key`,`col_int`,`col_int_key`,`pk` LIMIT 7 failed: 1213 Deadlock found when trying to get lock; try restarting transaction. Further errors of this kind will be suppressed.
# 2013-08-30T14:16:24 [1766] Query: INSERT IGNORE INTO `table1_innodb_compressed_int_autoinc` ( `col_char_12` ) SELECT `col_char_12_key` FROM `table1000_innodb_dynamic_key_pk_parts_2_int_autoinc` AS X WHERE X . `col_char_12_key` IN ( 'f' , 'y' , 141 , 7 , 3 ) ORDER BY `col_char_12`,`col_char_12_key`,`col_int`,`col_int_key`,`pk` LIMIT 6 failed: 1467 Failed to read auto-increment value from storage engine
# 2013-08-30T14:16:24 [1754] Query: INSERT  INTO `table1_innodb_compressed_int_autoinc` ( `col_char_12` ) SELECT `col_int_key` FROM `table1000_innodb_dynamic_int` AS X WHERE X . `col_int_key` < 3985833984 ORDER BY `col_char_12`,`col_char_12_key`,`col_int`,`col_int_key`,`pk` LIMIT 8 failed: 1467 Failed to read auto-increment value from storage engine
# 2013-08-30T14:16:25 [1728] Query:  DROP TABLE `table100_innodb_compressed_key_pk_parts_2_int_autoinc`  failed: 1051 Unknown table '%s'. Further errors of this kind will be suppressed.
# 2013-08-30T14:16:25 [1728] Query:  CREATE TABLE c LIKE `table1_innodb_dynamic_int_autoinc`  failed: 1050 Table '%s' already exists. Further errors of this kind will be suppressed.
# 2013-08-30T14:16:26 [1728] Query: ALTER TABLE `table100_innodb_dynamic_int_autoinc` MODIFY `col_char_12` BIT  AFTER `col_char_12` failed: 1054 Unknown column '%s' in 'table%d_innodb_dynamic_int_autoinc'. Further errors of this kind will be suppressed.
# 2013-08-30T14:16:34 [1729] ALARM from ErrorLogAlarm reporter: Pattern '^Error:|^ERROR|\[ERROR\]|allocated at line|missing DBUG_RETURN|^safe_mutex:|Invalid.*old.*table or database|InnoDB: Warning|InnoDB: Error:|InnoDB: Operating system error|Error while setting value|\[Warning\] Invalid' was found in error log. Matching line was:
# 2013-08-30T14:16:34 [1729] 130830 14:16:24 [ERROR] WSREP: commit issue, error: 1062 Duplicate entry '10' for key 'PRIMARY'
# 2013-08-30T14:17:18 [1728] Query: UPDATE  `table1_innodb_compressed_key_pk_parts_2_int` AS X SET `col_char_12_key` = 5 WHERE X . `col_int_key` BETWEEN 1 AND 5 ORDER BY `col_char_12`,`col_char_12_key`,`col_int`,`col_int_key`,`pk` LIMIT 6 failed: 1205 Lock wait timeout exceeded; try restarting transaction. Further errors of this kind will be suppressed.
# 2013-08-30T14:19:02 [1728] Query: ALTER TABLE `table1_innodb_compressed_key_pk_parts_2_int_autoinc` MODIFY `col_char_12_key` FLOAT NOT NULL DEFAULT 0 AFTER `col_char_12_key` failed: 1054 Unknown column '%s' in 'table%d_innodb_compressed_key_pk_parts_%d_int_autoinc'. Further errors of this kind will be suppressed.
# 2013-08-30T14:19:03 [1738] Query:  INSERT INTO j SELECT * FROM `table100_innodb_compressed_int_autoinc`  failed: 1467 Failed to read auto-increment value from storage engine