| 2013-10-29 23:34:29 |
Raghavendra D Prabhu |
description |
Got the following with memcheck:
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.034 20352== Thread 3:
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.034 20352== Invalid write of size 8
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.034 20352== at 0x650919A: gcomm::GMCast::handle_up(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (gmcast_proto.hpp:119)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.034 20352== by 0x652CD5B: gcomm::Protostack::dispatch(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (protostack.cpp:60)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x655AE9A: gcomm::AsioProtonet::dispatch(void const* const&, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (asio_protonet.cpp:250)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x653866F: gcomm::AsioTcpSocket::read_handler(asio::error_code const&, unsigned long) (asio_tcp.cpp:433)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x654ED84: asio::detail::read_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, boost::array<asio::mutable_buffer, 1ul>, boost::_bi::bind_t<unsigned long, boost::_mfi::mf2<unsigned long, gcomm::AsioTcpSocket, asio::error_code const&, unsigned long>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> >, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, asio::error_code const&, unsigned long>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > >::operator()(asio::error_code const&, unsigned long, int) (mem_fn_template.hpp:265)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x654FA95: asio::detail::reactive_socket_recv_op<asio::detail::consuming_buffers<asio::mutable_buffer, boost::array<asio::mutable_buffer, 1ul> >, asio::detail::read_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, boost::array<asio::mutable_buffer, 1ul>, boost::_bi::bind_t<unsigned long, boost::_mfi::mf2<unsigned long, gcomm::AsioTcpSocket, asio::error_code const&, unsigned long>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> >, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, asio::error_code const&, unsigned long>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > >::do_complete(asio::detail::task_io_service*, asio::detail::task_io_service_operation*, asio::error_code, unsigned long) (bind_handler.hpp:96)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x6563E88: asio::detail::task_io_service::run(asio::error_code&) (task_io_service_operation.hpp:34)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x655BDD5: gcomm::AsioProtonet::event_loop(gu::datetime::Period const&) (io_service.ipp:56)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x6576456: GCommConn::run() (gcs_gcomm.cpp:440)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x6579D28: GCommConn::run_fn(void*) (gcs_gcomm.cpp:206)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x381C407850: start_thread (in /lib64/libpthread-2.12.so)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x381C0E894C: clone (in /lib64/libc-2.12.so)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== Address 0x1c23d1e8 is 168 bytes inside a block of size 176 free'd
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== at 0x4A063F0: free (vg_replace_malloc.c:446)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64FE151: gcomm::GMCast::handle_failed(gcomm::gmcast::Proto*) (gmcast.cpp:670)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64FE99E: gcomm::GMCast::check_liveness() (gmcast.cpp:1004)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64FFAE6: gcomm::GMCast::handle_stable_view(gcomm::View const&) (gmcast.cpp:1399)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64DEF06: gcomm::evs::Proto::deliver_reg_view() (protolay.hpp:317)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64EBCC8: gcomm::evs::Proto::shift_to(gcomm::evs::Proto::State, bool) (evs_proto.cpp:2331)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64E963E: gcomm::evs::Proto::handle_gap(gcomm::evs::GapMessage const&, std::_Rb_tree_iterator<std::pair<gcomm::UUID const, gcomm::evs::Node> >) (evs_proto.cpp:2949)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64F100A: gcomm::evs::Proto::handle_msg(gcomm::evs::Message const&, gcomm::Datagram const&) (evs_proto.cpp:1955)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64F1FF5: gcomm::evs::Proto::handle_up(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (evs_proto.cpp:2043)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x650A19D: gcomm::Protolay::send_up(gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (protolay.hpp:277)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x6509149: gcomm::GMCast::handle_up(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (gmcast.cpp:1212)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x652CD5B: gcomm::Protostack::dispatch(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (protostack.cpp:60)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352==
=============================================================================================
# 2013-10-29T10:05:14 [18883] Copyright (c) 2010,2011 Oracle and/or its affiliates. All rights reserved. Use is subject to license terms.
# 2013-10-29T10:05:14 [18883] Please see http://forge.mysql.com/wiki/Category:RandomQueryGenerator for more information on this test framework.
# 2013-10-29T10:05:14 [18883] Starting
# 2013-10-29T10:05:14 [18883] # /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/pxcgen/runall-new.pl \
# 2013-10-29T10:05:14 [18883] # --queries=100000000 \
# 2013-10-29T10:05:14 [18883] # --seed=random \
# 2013-10-29T10:05:14 [18883] # --short_column_names \
# 2013-10-29T10:05:14 [18883] # --mysqld=--skip-performance-schema \
# 2013-10-29T10:05:14 [18883] # --mysqld=--log-output=none \
# 2013-10-29T10:05:14 [18883] # --mysqld=--sql_mode=ONLY_FULL_GROUP_BY \
# 2013-10-29T10:05:14 [18883] # --grammar=conf/galera/galera_stress.yy \
# 2013-10-29T10:05:14 [18883] # --gendata=conf/galera/galera_stress.zz \
# 2013-10-29T10:05:14 [18883] # --threads=16 \
# 2013-10-29T10:05:14 [18883] # --valgrind \
# 2013-10-29T10:05:14 [18883] # --reporter=ValgrindErrors,Shutdown,Backtrace,ErrorLog,ErrorLogAlarm,Deadlock \
# 2013-10-29T10:05:14 [18883] # --validator=MarkErrorLog \
# 2013-10-29T10:05:14 [18883] # --mysqld=--innodb-buffer-pool-populate \
# 2013-10-29T10:05:14 [18883] # --mysqld=--innodb_flush_method=O_DIRECT \
# 2013-10-29T10:05:14 [18883] # --mysqld=--innodb_change_buffering=none \
# 2013-10-29T10:05:14 [18883] # --mysqld=--innodb_lock_wait_timeout=100 \
# 2013-10-29T10:05:14 [18883] # --mysqld=--lock_wait_timeout=500 \
# 2013-10-29T10:05:14 [18883] # --mysqld=--innodb_adaptive_hash_index_partitions=1 \
# 2013-10-29T10:05:14 [18883] # --mysqld=--thread_handling=pool-of-threads \
# 2013-10-29T10:05:14 [18883] # --mysqld=--wsrep_retry_autocommit=0 \
# 2013-10-29T10:05:14 [18883] # --mysqld=--wsrep_slave_threads=8 \
# 2013-10-29T10:05:14 [18883] # --mysqld=--wsrep_causal_reads=ON \
# 2013-10-29T10:05:14 [18883] # --mysqld=--innodb_flush_log_at_trx_commit=1 \
# 2013-10-29T10:05:14 [18883] # --mysqld=--transaction-isolation=READ-UNCOMMITTED \
# 2013-10-29T10:05:14 [18883] # --mysqld=--innodb_file_per_table=1 \
# 2013-10-29T10:05:14 [18883] # --rows=10000 \
# 2013-10-29T10:05:14 [18883] # --galera=ms \
# 2013-10-29T10:05:14 [18883] # --mysqld=--wsrep-provider=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/lib/libgalera_smm.so \
# 2013-10-29T10:05:14 [18883] # --mtr-build-thread=194 \
# 2013-10-29T10:05:14 [18883] # --mask=26283 \
# 2013-10-29T10:05:14 [18883] # --duration=120 \
# 2013-10-29T10:05:14 [18883] # --basedir1=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64 \
# 2013-10-29T10:05:14 [18883] # --gendata=conf/galera/galera_stress.zz \
# 2013-10-29T10:05:14 [18883] # --grammar=conf/galera/galera_stress.yy \
# 2013-10-29T10:05:14 [18883] # --seed=time \
# 2013-10-29T10:05:14 [18883] # --vardir1=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3
# 2013-10-29T10:05:14 [18883] master_port : 11940 slave_port : 11942 ports : 11940 11942 MTR_BUILD_THREAD : 194
# 2013-10-29T10:05:14 [18883] /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/pxcgen Revno: 923
# 2013-10-29T10:05:14 [18883] /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/pxcgen Revision-Id: raghavendra.prabhu@percona.com-20131010221406-i3iiizd71tsude63
# 2013-10-29T10:05:14 [18883] /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64 does not look like a bzr branch, cannot get revision info.
# 2013-10-29T10:05:14 [18883] Creating MySQL 5.5.34 database at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data
# 2013-10-29T10:05:20 [18883] Creating MySQL 5.5.34 database at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node1/data
# 2013-10-29T10:05:26 [18883] MySQL Version:5.5.34
# 2013-10-29T10:05:26 [18883] Binary: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/bin/mysqld
# 2013-10-29T10:05:26 [18883] Type: Release
# 2013-10-29T10:05:26 [18883] Datadir: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data
# 2013-10-29T10:05:26 [18883] Tmpdir: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/tmp
# 2013-10-29T10:05:26 [18883] Corefile: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data/core.
# 2013-10-29T10:05:26 [18883] Starting MySQL 5.5.34: valgrind --time-stamp=yes --leak-check=yes --suppressions=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/mysql-test/valgrind.supp "/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/bin/mysqld" "--no-defaults" "--basedir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64" "--datadir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data" "--lc-messages-dir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/share" "--character-sets-dir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/share/charsets" "--tmpdir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/tmp" "--core-file" "--max-allowed-packet=128Mb" "--port=11940" "--socket=/tmp/RQGmysql.11940.sock" "--pid-file=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/mysql.pid" "--general-log" "--general-log-file=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/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:4808&pc.ignore_sb=true' --wsrep_sst_receive_address=127.0.0.1:4811 --skip-performance-schema --log-output=none --sql_mode=ONLY_FULL_GROUP_BY --innodb-buffer-pool-populate --innodb_flush_method=O_DIRECT --innodb_change_buffering=none --innodb_lock_wait_timeout=100 --lock_wait_timeout=500 --innodb_adaptive_hash_index_partitions=1 --thread_handling=pool-of-threads --wsrep_retry_autocommit=0 --wsrep_slave_threads=8 --wsrep_causal_reads=ON --innodb_flush_log_at_trx_commit=1 --transaction-isolation=READ-UNCOMMITTED --innodb_file_per_table=1 --wsrep-provider=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/lib/libgalera_smm.so
# 2013-10-29T10:05:40 [18883] Cluster size after starting node 0: 1
# 2013-10-29T10:05:40 [18883] MySQL Version:5.5.34
# 2013-10-29T10:05:40 [18883] Binary: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/bin/mysqld
# 2013-10-29T10:05:40 [18883] Type: Release
# 2013-10-29T10:05:40 [18883] Datadir: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node1/data
# 2013-10-29T10:05:40 [18883] Tmpdir: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node1/tmp
# 2013-10-29T10:05:40 [18883] Corefile: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node1/data/core.
# 2013-10-29T10:05:40 [18883] Starting MySQL 5.5.34: valgrind --time-stamp=yes --leak-check=yes --suppressions=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/mysql-test/valgrind.supp "/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/bin/mysqld" "--no-defaults" "--basedir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64" "--datadir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node1/data" "--lc-messages-dir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/share" "--character-sets-dir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/share/charsets" "--tmpdir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node1/tmp" "--core-file" "--max-allowed-packet=128Mb" "--port=11941" "--socket=/tmp/RQGmysql.11941.sock" "--pid-file=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node1/mysql.pid" "--general-log" "--general-log-file=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/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:4808?gmcast.listen_addr=tcp://127.0.0.1:4809&pc.ignore_sb=true' --wsrep_sst_receive_address=127.0.0.1:4812 --skip-performance-schema --log-output=none --sql_mode=ONLY_FULL_GROUP_BY --innodb-buffer-pool-populate --innodb_flush_method=O_DIRECT --innodb_change_buffering=none --innodb_lock_wait_timeout=100 --lock_wait_timeout=500 --innodb_adaptive_hash_index_partitions=1 --thread_handling=pool-of-threads --wsrep_retry_autocommit=0 --wsrep_slave_threads=8 --wsrep_causal_reads=ON --innodb_flush_log_at_trx_commit=1 --transaction-isolation=READ-UNCOMMITTED --innodb_file_per_table=1 --wsrep-provider=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/lib/libgalera_smm.so
# 2013-10-29T10:06:07 [18883] Cluster size after starting node 1: 2
# 2013-10-29T10:06:07 [18883] Converting --seed=time to --seed=1383041167
# 2013-10-29T10:06:07 [18883] -------------------------------
# 2013-10-29T10:06:07 [18883] Configuration
# 2013-10-29T10:06:07 [18883] debug_server => ['', '']
# 2013-10-29T10:06:07 [18883] dsn => ['dbi:mysql:host=127.0.0.1:port=11940:user=root:database=test']
# 2013-10-29T10:06:07 [18883] duration => 120
# 2013-10-29T10:06:07 [18883] gendata => conf/galera/galera_stress.zz
# 2013-10-29T10:06:07 [18883] generator => FromGrammar
# 2013-10-29T10:06:07 [18883] grammar => conf/galera/galera_stress.yy
# 2013-10-29T10:06:07 [18883] mask => 26283
# 2013-10-29T10:06:07 [18883] queries => 100000000
# 2013-10-29T10:06:07 [18883] reporters => ['ValgrindErrors', 'Shutdown', 'Backtrace', 'ErrorLog', 'ErrorLogAlarm', 'Deadlock']
# 2013-10-29T10:06:07 [18883] rows => 10000
# 2013-10-29T10:06:07 [18883] seed => 1383041167
# 2013-10-29T10:06:07 [18883] servers => ['DBServer::MySQL::MySQLd=ARRAY(0x166abd8)', 'DBServer::MySQL::MySQLd=ARRAY(0x16960f0)']
# 2013-10-29T10:06:07 [18883] short_column_names => 1
# 2013-10-29T10:06:07 [18883] threads => 16
# 2013-10-29T10:06:07 [18883] valgrind => 1
# 2013-10-29T10:06:07 [18883] validators => ['MarkErrorLog']
# 2013-10-29T10:06:07 [18883] views => ['', '']
# 2013-10-29T10:06:07 [18883] # Creating MySQL table: test.table10000_innodb_int; engine: innodb; rows: 10000 .
# 2013-10-29T10:06:30 [18883] # Progress: loaded 10000 out of 10000 rows
# 2013-10-29T10:06:31 [18883] # Creating MySQL table: test.table10000_innodb_int_autoinc; engine: innodb; rows: 10000 .
# 2013-10-29T10:06:51 [18883] # Progress: loaded 10000 out of 10000 rows
# 2013-10-29T10:06:51 [18883] # Creating MySQL table: test.table10000_innodb_key_pk_parts_2_int; engine: innodb; rows: 10000 .
# 2013-10-29T10:07:13 [18883] # Progress: loaded 10000 out of 10000 rows
# 2013-10-29T10:07:13 [18883] # Creating MySQL table: test.table10000_innodb_key_pk_parts_2_int_autoinc; engine: innodb; rows: 10000 .
# 2013-10-29T10:07:52 [18883] # Progress: loaded 10000 out of 10000 rows
# 2013-10-29T10:07:52 [18883] Reporters: ValgrindErrors, Shutdown, Backtrace, ErrorLog, ErrorLogAlarm, Deadlock
# 2013-10-29T10:10:02 [18883] Validators: MarkErrorLog
# 2013-10-29T10:10:02 [18883] Caching schema metadata for dbi:mysql:host=127.0.0.1:port=11940:user=root:database=test
# 2013-10-29T10:10:07 [18883] Starting 16 processes, 100000000 queries each, duration 120 seconds.
# 2013-10-29T10:10:07 [18883] GenTest::ErrorFilter(25400) started
# 2013-10-29T10:10:07 [25402] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:07 [25404] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:08 [25408] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:08 [25412] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:08 [25407] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:08 [25401] Started periodic reporting process...
# 2013-10-29T10:10:08 [25401] ErrorLogAlarm Reporter will monitor the log file /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data/../mysql.err
# 2013-10-29T10:10:08 [25411] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:09 [25410] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:11 [25412] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:11 [25414] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:11 [25420] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:11 [25416] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:11 [25418] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:12 [25410] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:12 [25410] Child worker process completed successfully.
# 2013-10-29T10:10:13 [25415] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:13 [25419] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:13 [25420] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:13 [25420] Child worker process completed successfully.
# 2013-10-29T10:10:13 [25402] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:13 [25402] Child worker process completed successfully.
# 2013-10-29T10:10:13 [25413] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:13 [25409] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:13 [25417] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:13 [25415] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:13 [25415] Child worker process completed successfully.
# 2013-10-29T10:10:13 [25409] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:13 [25409] Child worker process completed successfully.
# 2013-10-29T10:10:13 [25419] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:13 [25419] Child worker process completed successfully.
# 2013-10-29T10:10:13 [25413] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:13 [25413] Child worker process completed successfully.
# 2013-10-29T10:10:13 [25414] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:13 [25414] Child worker process completed successfully.
# 2013-10-29T10:10:14 [25400] Query: INSERT IGNORE INTO `table10000_innodb_key_pk_parts_2_int_autoinc` ( `c0` , `c0` ) VALUES ( 192 , 33 ) , ( 6 , 249 ) failed: 1110 Column '%s' specified twice. Further errors of this kind will be suppressed.
# 2013-10-29T10:10:15 [25407] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:15 [25407] Child worker process completed successfully.
# 2013-10-29T10:10:15 [25416] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:15 [25416] Child worker process completed successfully.
# 2013-10-29T10:10:15 [25408] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:15 [25408] Child worker process completed successfully.
# 2013-10-29T10:10:16 [25418] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:16 [25418] Child worker process completed successfully.
# 2013-10-29T10:10:17 [25411] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:17 [25411] Child worker process completed successfully.
# 2013-10-29T10:10:19 [25417] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:19 [25417] Child worker process completed successfully.
# 2013-10-29T10:10:19 [25404] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:19 [25404] Child worker process completed successfully.
# 2013-10-29T10:10:34 [25412] Child worker process completed successfully.
# 2013-10-29T10:10:34 [25400] Query: UPDATE IGNORE `table10000_innodb_key_pk_parts_2_int_autoinc` AS X SET `c3` = 9 WHERE X . `c3` IN ( 3288268800 , 8 , 2 , 1289486336 , 'd' ) ORDER BY `c0`,`c1`,`c2`,`c3`,`pk` LIMIT 5 failed: 1213 Deadlock found when trying to get lock; try restarting transaction. Further errors of this kind will be suppressed.
# 2013-10-29T10:10:35 [18883] Killing periodic reporting process with pid 25401...
# 2013-10-29T10:10:35 [18883] Kill GenTest::ErrorFilter(25400)
# 2013-10-29T10:10:35 [18883] Valgrind: Issues detected (error count: 0). Relevant messages from log file '/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data/../mysql.err':
# 2013-10-29T10:10:35 [18883] ==00:00:00:00.000 20352== Memcheck, a memory error detector
# 2013-10-29T10:10:35 [18883] ==00:00:00:00.000 20352== Copyright (C) 2002-2012, and GNU GPL'd, by Julian Seward et al.
# 2013-10-29T10:10:35 [18883] ==00:00:00:00.000 20352== Using Valgrind-3.8.1 and LibVEX; rerun with -h for copyright info
# 2013-10-29T10:10:35 [18883] ==00:00:00:00.000 20352== Command: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/bin/mysqld --no-defaults --basedir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64 --datadir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data --lc-messages-dir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/share --character-sets-dir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/share/charsets --tmpdir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/tmp --core-file --max-allowed-packet=128Mb --port=11940 --socket=/tmp/RQGmysql.11940.sock --pid-file=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/mysql.pid --general-log --general-log-file=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/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:4808&pc.ignore_sb=true --wsrep_sst_receive_address=127.0.0.1:4811 --skip-performance-schema --log-output=none --sql_mode=ONLY_FULL_GROUP_BY --innodb-buffer-pool-populate --innodb_flush_method=O_DIRECT --innodb_change_buffering=none --innodb_lock_wait_timeout=100 --lock_wait_timeout=500 --innodb_adaptive_hash_index_partitions=1 --thread_handling=pool-of-threads --wsrep_retry_autocommit=0 --wsrep_slave_threads=8 --wsrep_causal_reads=ON --innodb_flush_log_at_trx_commit=1 --transaction-isolation=READ-UNCOMMITTED --innodb_file_per_table=1 --wsrep-provider=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/lib/libgalera_smm.so
# 2013-10-29T10:10:35 [18883] ==00:00:00:00.000 20352==
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.034 20352== Thread 3:
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.034 20352== Invalid write of size 8
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.034 20352== at 0x650919A: gcomm::GMCast::handle_up(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (gmcast_proto.hpp:119)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.034 20352== by 0x652CD5B: gcomm::Protostack::dispatch(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (protostack.cpp:60)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x655AE9A: gcomm::AsioProtonet::dispatch(void const* const&, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (asio_protonet.cpp:250)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x653866F: gcomm::AsioTcpSocket::read_handler(asio::error_code const&, unsigned long) (asio_tcp.cpp:433)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x654ED84: asio::detail::read_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, boost::array<asio::mutable_buffer, 1ul>, boost::_bi::bind_t<unsigned long, boost::_mfi::mf2<unsigned long, gcomm::AsioTcpSocket, asio::error_code const&, unsigned long>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> >, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, asio::error_code const&, unsigned long>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > >::operator()(asio::error_code const&, unsigned long, int) (mem_fn_template.hpp:265)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x654FA95: asio::detail::reactive_socket_recv_op<asio::detail::consuming_buffers<asio::mutable_buffer, boost::array<asio::mutable_buffer, 1ul> >, asio::detail::read_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, boost::array<asio::mutable_buffer, 1ul>, boost::_bi::bind_t<unsigned long, boost::_mfi::mf2<unsigned long, gcomm::AsioTcpSocket, asio::error_code const&, unsigned long>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> >, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, asio::error_code const&, unsigned long>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > >::do_complete(asio::detail::task_io_service*, asio::detail::task_io_service_operation*, asio::error_code, unsigned long) (bind_handler.hpp:96)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x6563E88: asio::detail::task_io_service::run(asio::error_code&) (task_io_service_operation.hpp:34)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x655BDD5: gcomm::AsioProtonet::event_loop(gu::datetime::Period const&) (io_service.ipp:56)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x6576456: GCommConn::run() (gcs_gcomm.cpp:440)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x6579D28: GCommConn::run_fn(void*) (gcs_gcomm.cpp:206)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x381C407850: start_thread (in /lib64/libpthread-2.12.so)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x381C0E894C: clone (in /lib64/libc-2.12.so)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== Address 0x1c23d1e8 is 168 bytes inside a block of size 176 free'd
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== at 0x4A063F0: free (vg_replace_malloc.c:446)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64FE151: gcomm::GMCast::handle_failed(gcomm::gmcast::Proto*) (gmcast.cpp:670)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64FE99E: gcomm::GMCast::check_liveness() (gmcast.cpp:1004)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64FFAE6: gcomm::GMCast::handle_stable_view(gcomm::View const&) (gmcast.cpp:1399)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64DEF06: gcomm::evs::Proto::deliver_reg_view() (protolay.hpp:317)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64EBCC8: gcomm::evs::Proto::shift_to(gcomm::evs::Proto::State, bool) (evs_proto.cpp:2331)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64E963E: gcomm::evs::Proto::handle_gap(gcomm::evs::GapMessage const&, std::_Rb_tree_iterator<std::pair<gcomm::UUID const, gcomm::evs::Node> >) (evs_proto.cpp:2949)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64F100A: gcomm::evs::Proto::handle_msg(gcomm::evs::Message const&, gcomm::Datagram const&) (evs_proto.cpp:1955)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64F1FF5: gcomm::evs::Proto::handle_up(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (evs_proto.cpp:2043)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x650A19D: gcomm::Protolay::send_up(gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (protolay.hpp:277)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x6509149: gcomm::GMCast::handle_up(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (gmcast.cpp:1212)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x652CD5B: gcomm::Protostack::dispatch(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (protostack.cpp:60)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352==
# 2013-10-29T10:10:35 [18883] Shutting down server on port 11941 via DBI...
# 2013-10-29T10:10:35 [18883] Shutting down server with pid 21532 with SIGTERM...
# 2013-10-29T10:10:35 [18883] Waiting for mysqld with pid 21532 to terminate...
+++++++++++++++++++++++++++
# 2013-10-29T10:11:02 [18883] ... waiting complete. Just in case, killing server with pid 21532 with SIGKILL ...
# 2013-10-29T10:11:02 [18883] Shutting down server on port 11940 via DBI...
# 2013-10-29T10:11:02 [18883] Shutting down server with pid 20352 with SIGTERM...
# 2013-10-29T10:11:02 [18883] Waiting for mysqld with pid 20352 to terminate...
+++++++++++++++
# 2013-10-29T10:11:17 [18883] ... waiting complete. Just in case, killing server with pid 20352 with SIGKILL ...
# 2013-10-29T10:11:17 [18883] Test completed with failure status STATUS_VALGRIND_FAILURE (108)
# 2013-10-29T10:11:17 [18883] GenTest exited with exit status STATUS_VALGRIND_FAILURE (108)
# 2013-10-29T10:11:17 [18883] Stopping server on port 11940
# 2013-10-29T10:11:17 [18883] Stale connection. Reconnecting
# 2013-10-29T10:11:17 [18883] Reconnect failed due to 2003:Can't connect to MySQL server on '127.0.0.1' (111)
# 2013-10-29T10:11:17 [18883] Server would not shut down properly. Terminate it
# 2013-10-29T10:11:17 [18883] Terminated process 20352
# 2013-10-29T10:11:17 [18883] Stopping server on port 11941
# 2013-10-29T10:11:17 [18883] Stale connection. Reconnecting
# 2013-10-29T10:11:17 [18883] Reconnect failed due to 2003:Can't connect to MySQL server on '127.0.0.1' (111)
# 2013-10-29T10:11:17 [18883] Server would not shut down properly. Terminate it
# 2013-10-29T10:11:17 [18883] Terminated process 21532
# 2013-10-29T10:11:17 [18883] [18883] /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/pxcgen/runall-new.pl will exit with exit status STATUS_VALGRIND_FAILURE (108) |
Got the following with memcheck:
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.034 20352== Thread 3:
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.034 20352== Invalid write of size 8
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.034 20352== at 0x650919A: gcomm::GMCast::handle_up(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (gmcast_proto.hpp:119)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.034 20352== by 0x652CD5B: gcomm::Protostack::dispatch(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (protostack.cpp:60)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x655AE9A: gcomm::AsioProtonet::dispatch(void const* const&, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (asio_protonet.cpp:250)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x653866F: gcomm::AsioTcpSocket::read_handler(asio::error_code const&, unsigned long) (asio_tcp.cpp:433)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x654ED84: asio::detail::read_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, boost::array<asio::mutable_buffer, 1ul>, boost::_bi::bind_t<unsigned long, boost::_mfi::mf2<unsigned long, gcomm::AsioTcpSocket, asio::error_code const&, unsigned long>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> >, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, asio::error_code const&, unsigned long>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > >::operator()(asio::error_code const&, unsigned long, int) (mem_fn_template.hpp:265)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x654FA95: asio::detail::reactive_socket_recv_op<asio::detail::consuming_buffers<asio::mutable_buffer, boost::array<asio::mutable_buffer, 1ul> >, asio::detail::read_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, boost::array<asio::mutable_buffer, 1ul>, boost::_bi::bind_t<unsigned long, boost::_mfi::mf2<unsigned long, gcomm::AsioTcpSocket, asio::error_code const&, unsigned long>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> >, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, asio::error_code const&, unsigned long>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > >::do_complete(asio::detail::task_io_service*, asio::detail::task_io_service_operation*, asio::error_code, unsigned long) (bind_handler.hpp:96)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x6563E88: asio::detail::task_io_service::run(asio::error_code&) (task_io_service_operation.hpp:34)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x655BDD5: gcomm::AsioProtonet::event_loop(gu::datetime::Period const&) (io_service.ipp:56)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x6576456: GCommConn::run() (gcs_gcomm.cpp:440)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x6579D28: GCommConn::run_fn(void*) (gcs_gcomm.cpp:206)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x381C407850: start_thread (in /lib64/libpthread-2.12.so)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x381C0E894C: clone (in /lib64/libc-2.12.so)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== Address 0x1c23d1e8 is 168 bytes inside a block of size 176 free'd
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== at 0x4A063F0: free (vg_replace_malloc.c:446)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64FE151: gcomm::GMCast::handle_failed(gcomm::gmcast::Proto*) (gmcast.cpp:670)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64FE99E: gcomm::GMCast::check_liveness() (gmcast.cpp:1004)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64FFAE6: gcomm::GMCast::handle_stable_view(gcomm::View const&) (gmcast.cpp:1399)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64DEF06: gcomm::evs::Proto::deliver_reg_view() (protolay.hpp:317)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64EBCC8: gcomm::evs::Proto::shift_to(gcomm::evs::Proto::State, bool) (evs_proto.cpp:2331)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64E963E: gcomm::evs::Proto::handle_gap(gcomm::evs::GapMessage const&, std::_Rb_tree_iterator<std::pair<gcomm::UUID const, gcomm::evs::Node> >) (evs_proto.cpp:2949)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64F100A: gcomm::evs::Proto::handle_msg(gcomm::evs::Message const&, gcomm::Datagram const&) (evs_proto.cpp:1955)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64F1FF5: gcomm::evs::Proto::handle_up(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (evs_proto.cpp:2043)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x650A19D: gcomm::Protolay::send_up(gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (protolay.hpp:277)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x6509149: gcomm::GMCast::handle_up(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (gmcast.cpp:1212)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x652CD5B: gcomm::Protostack::dispatch(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (protostack.cpp:60)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352==
=============================================================================================
Complete error log:
# 2013-10-29T10:05:14 [18883] Copyright (c) 2010,2011 Oracle and/or its affiliates. All rights reserved. Use is subject to license terms.
# 2013-10-29T10:05:14 [18883] Please see http://forge.mysql.com/wiki/Category:RandomQueryGenerator for more information on this test framework.
# 2013-10-29T10:05:14 [18883] Starting
# 2013-10-29T10:05:14 [18883] # /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/pxcgen/runall-new.pl \
# 2013-10-29T10:05:14 [18883] # --queries=100000000 \
# 2013-10-29T10:05:14 [18883] # --seed=random \
# 2013-10-29T10:05:14 [18883] # --short_column_names \
# 2013-10-29T10:05:14 [18883] # --mysqld=--skip-performance-schema \
# 2013-10-29T10:05:14 [18883] # --mysqld=--log-output=none \
# 2013-10-29T10:05:14 [18883] # --mysqld=--sql_mode=ONLY_FULL_GROUP_BY \
# 2013-10-29T10:05:14 [18883] # --grammar=conf/galera/galera_stress.yy \
# 2013-10-29T10:05:14 [18883] # --gendata=conf/galera/galera_stress.zz \
# 2013-10-29T10:05:14 [18883] # --threads=16 \
# 2013-10-29T10:05:14 [18883] # --valgrind \
# 2013-10-29T10:05:14 [18883] # --reporter=ValgrindErrors,Shutdown,Backtrace,ErrorLog,ErrorLogAlarm,Deadlock \
# 2013-10-29T10:05:14 [18883] # --validator=MarkErrorLog \
# 2013-10-29T10:05:14 [18883] # --mysqld=--innodb-buffer-pool-populate \
# 2013-10-29T10:05:14 [18883] # --mysqld=--innodb_flush_method=O_DIRECT \
# 2013-10-29T10:05:14 [18883] # --mysqld=--innodb_change_buffering=none \
# 2013-10-29T10:05:14 [18883] # --mysqld=--innodb_lock_wait_timeout=100 \
# 2013-10-29T10:05:14 [18883] # --mysqld=--lock_wait_timeout=500 \
# 2013-10-29T10:05:14 [18883] # --mysqld=--innodb_adaptive_hash_index_partitions=1 \
# 2013-10-29T10:05:14 [18883] # --mysqld=--thread_handling=pool-of-threads \
# 2013-10-29T10:05:14 [18883] # --mysqld=--wsrep_retry_autocommit=0 \
# 2013-10-29T10:05:14 [18883] # --mysqld=--wsrep_slave_threads=8 \
# 2013-10-29T10:05:14 [18883] # --mysqld=--wsrep_causal_reads=ON \
# 2013-10-29T10:05:14 [18883] # --mysqld=--innodb_flush_log_at_trx_commit=1 \
# 2013-10-29T10:05:14 [18883] # --mysqld=--transaction-isolation=READ-UNCOMMITTED \
# 2013-10-29T10:05:14 [18883] # --mysqld=--innodb_file_per_table=1 \
# 2013-10-29T10:05:14 [18883] # --rows=10000 \
# 2013-10-29T10:05:14 [18883] # --galera=ms \
# 2013-10-29T10:05:14 [18883] # --mysqld=--wsrep-provider=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/lib/libgalera_smm.so \
# 2013-10-29T10:05:14 [18883] # --mtr-build-thread=194 \
# 2013-10-29T10:05:14 [18883] # --mask=26283 \
# 2013-10-29T10:05:14 [18883] # --duration=120 \
# 2013-10-29T10:05:14 [18883] # --basedir1=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64 \
# 2013-10-29T10:05:14 [18883] # --gendata=conf/galera/galera_stress.zz \
# 2013-10-29T10:05:14 [18883] # --grammar=conf/galera/galera_stress.yy \
# 2013-10-29T10:05:14 [18883] # --seed=time \
# 2013-10-29T10:05:14 [18883] # --vardir1=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3
# 2013-10-29T10:05:14 [18883] master_port : 11940 slave_port : 11942 ports : 11940 11942 MTR_BUILD_THREAD : 194
# 2013-10-29T10:05:14 [18883] /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/pxcgen Revno: 923
# 2013-10-29T10:05:14 [18883] /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/pxcgen Revision-Id: raghavendra.prabhu@percona.com-20131010221406-i3iiizd71tsude63
# 2013-10-29T10:05:14 [18883] /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64 does not look like a bzr branch, cannot get revision info.
# 2013-10-29T10:05:14 [18883] Creating MySQL 5.5.34 database at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data
# 2013-10-29T10:05:20 [18883] Creating MySQL 5.5.34 database at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node1/data
# 2013-10-29T10:05:26 [18883] MySQL Version:5.5.34
# 2013-10-29T10:05:26 [18883] Binary: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/bin/mysqld
# 2013-10-29T10:05:26 [18883] Type: Release
# 2013-10-29T10:05:26 [18883] Datadir: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data
# 2013-10-29T10:05:26 [18883] Tmpdir: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/tmp
# 2013-10-29T10:05:26 [18883] Corefile: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data/core.
# 2013-10-29T10:05:26 [18883] Starting MySQL 5.5.34: valgrind --time-stamp=yes --leak-check=yes --suppressions=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/mysql-test/valgrind.supp "/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/bin/mysqld" "--no-defaults" "--basedir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64" "--datadir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data" "--lc-messages-dir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/share" "--character-sets-dir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/share/charsets" "--tmpdir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/tmp" "--core-file" "--max-allowed-packet=128Mb" "--port=11940" "--socket=/tmp/RQGmysql.11940.sock" "--pid-file=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/mysql.pid" "--general-log" "--general-log-file=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/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:4808&pc.ignore_sb=true' --wsrep_sst_receive_address=127.0.0.1:4811 --skip-performance-schema --log-output=none --sql_mode=ONLY_FULL_GROUP_BY --innodb-buffer-pool-populate --innodb_flush_method=O_DIRECT --innodb_change_buffering=none --innodb_lock_wait_timeout=100 --lock_wait_timeout=500 --innodb_adaptive_hash_index_partitions=1 --thread_handling=pool-of-threads --wsrep_retry_autocommit=0 --wsrep_slave_threads=8 --wsrep_causal_reads=ON --innodb_flush_log_at_trx_commit=1 --transaction-isolation=READ-UNCOMMITTED --innodb_file_per_table=1 --wsrep-provider=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/lib/libgalera_smm.so
# 2013-10-29T10:05:40 [18883] Cluster size after starting node 0: 1
# 2013-10-29T10:05:40 [18883] MySQL Version:5.5.34
# 2013-10-29T10:05:40 [18883] Binary: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/bin/mysqld
# 2013-10-29T10:05:40 [18883] Type: Release
# 2013-10-29T10:05:40 [18883] Datadir: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node1/data
# 2013-10-29T10:05:40 [18883] Tmpdir: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node1/tmp
# 2013-10-29T10:05:40 [18883] Corefile: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node1/data/core.
# 2013-10-29T10:05:40 [18883] Starting MySQL 5.5.34: valgrind --time-stamp=yes --leak-check=yes --suppressions=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/mysql-test/valgrind.supp "/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/bin/mysqld" "--no-defaults" "--basedir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64" "--datadir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node1/data" "--lc-messages-dir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/share" "--character-sets-dir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/share/charsets" "--tmpdir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node1/tmp" "--core-file" "--max-allowed-packet=128Mb" "--port=11941" "--socket=/tmp/RQGmysql.11941.sock" "--pid-file=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node1/mysql.pid" "--general-log" "--general-log-file=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/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:4808?gmcast.listen_addr=tcp://127.0.0.1:4809&pc.ignore_sb=true' --wsrep_sst_receive_address=127.0.0.1:4812 --skip-performance-schema --log-output=none --sql_mode=ONLY_FULL_GROUP_BY --innodb-buffer-pool-populate --innodb_flush_method=O_DIRECT --innodb_change_buffering=none --innodb_lock_wait_timeout=100 --lock_wait_timeout=500 --innodb_adaptive_hash_index_partitions=1 --thread_handling=pool-of-threads --wsrep_retry_autocommit=0 --wsrep_slave_threads=8 --wsrep_causal_reads=ON --innodb_flush_log_at_trx_commit=1 --transaction-isolation=READ-UNCOMMITTED --innodb_file_per_table=1 --wsrep-provider=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/lib/libgalera_smm.so
# 2013-10-29T10:06:07 [18883] Cluster size after starting node 1: 2
# 2013-10-29T10:06:07 [18883] Converting --seed=time to --seed=1383041167
# 2013-10-29T10:06:07 [18883] -------------------------------
# 2013-10-29T10:06:07 [18883] Configuration
# 2013-10-29T10:06:07 [18883] debug_server => ['', '']
# 2013-10-29T10:06:07 [18883] dsn => ['dbi:mysql:host=127.0.0.1:port=11940:user=root:database=test']
# 2013-10-29T10:06:07 [18883] duration => 120
# 2013-10-29T10:06:07 [18883] gendata => conf/galera/galera_stress.zz
# 2013-10-29T10:06:07 [18883] generator => FromGrammar
# 2013-10-29T10:06:07 [18883] grammar => conf/galera/galera_stress.yy
# 2013-10-29T10:06:07 [18883] mask => 26283
# 2013-10-29T10:06:07 [18883] queries => 100000000
# 2013-10-29T10:06:07 [18883] reporters => ['ValgrindErrors', 'Shutdown', 'Backtrace', 'ErrorLog', 'ErrorLogAlarm', 'Deadlock']
# 2013-10-29T10:06:07 [18883] rows => 10000
# 2013-10-29T10:06:07 [18883] seed => 1383041167
# 2013-10-29T10:06:07 [18883] servers => ['DBServer::MySQL::MySQLd=ARRAY(0x166abd8)', 'DBServer::MySQL::MySQLd=ARRAY(0x16960f0)']
# 2013-10-29T10:06:07 [18883] short_column_names => 1
# 2013-10-29T10:06:07 [18883] threads => 16
# 2013-10-29T10:06:07 [18883] valgrind => 1
# 2013-10-29T10:06:07 [18883] validators => ['MarkErrorLog']
# 2013-10-29T10:06:07 [18883] views => ['', '']
# 2013-10-29T10:06:07 [18883] # Creating MySQL table: test.table10000_innodb_int; engine: innodb; rows: 10000 .
# 2013-10-29T10:06:30 [18883] # Progress: loaded 10000 out of 10000 rows
# 2013-10-29T10:06:31 [18883] # Creating MySQL table: test.table10000_innodb_int_autoinc; engine: innodb; rows: 10000 .
# 2013-10-29T10:06:51 [18883] # Progress: loaded 10000 out of 10000 rows
# 2013-10-29T10:06:51 [18883] # Creating MySQL table: test.table10000_innodb_key_pk_parts_2_int; engine: innodb; rows: 10000 .
# 2013-10-29T10:07:13 [18883] # Progress: loaded 10000 out of 10000 rows
# 2013-10-29T10:07:13 [18883] # Creating MySQL table: test.table10000_innodb_key_pk_parts_2_int_autoinc; engine: innodb; rows: 10000 .
# 2013-10-29T10:07:52 [18883] # Progress: loaded 10000 out of 10000 rows
# 2013-10-29T10:07:52 [18883] Reporters: ValgrindErrors, Shutdown, Backtrace, ErrorLog, ErrorLogAlarm, Deadlock
# 2013-10-29T10:10:02 [18883] Validators: MarkErrorLog
# 2013-10-29T10:10:02 [18883] Caching schema metadata for dbi:mysql:host=127.0.0.1:port=11940:user=root:database=test
# 2013-10-29T10:10:07 [18883] Starting 16 processes, 100000000 queries each, duration 120 seconds.
# 2013-10-29T10:10:07 [18883] GenTest::ErrorFilter(25400) started
# 2013-10-29T10:10:07 [25402] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:07 [25404] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:08 [25408] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:08 [25412] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:08 [25407] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:08 [25401] Started periodic reporting process...
# 2013-10-29T10:10:08 [25401] ErrorLogAlarm Reporter will monitor the log file /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data/../mysql.err
# 2013-10-29T10:10:08 [25411] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:09 [25410] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:11 [25412] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:11 [25414] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:11 [25420] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:11 [25416] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:11 [25418] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:12 [25410] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:12 [25410] Child worker process completed successfully.
# 2013-10-29T10:10:13 [25415] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:13 [25419] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:13 [25420] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:13 [25420] Child worker process completed successfully.
# 2013-10-29T10:10:13 [25402] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:13 [25402] Child worker process completed successfully.
# 2013-10-29T10:10:13 [25413] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:13 [25409] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:13 [25417] Loading Validator GenTest::Validator::MarkErrorLog.
# 2013-10-29T10:10:13 [25415] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:13 [25415] Child worker process completed successfully.
# 2013-10-29T10:10:13 [25409] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:13 [25409] Child worker process completed successfully.
# 2013-10-29T10:10:13 [25419] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:13 [25419] Child worker process completed successfully.
# 2013-10-29T10:10:13 [25413] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:13 [25413] Child worker process completed successfully.
# 2013-10-29T10:10:13 [25414] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:13 [25414] Child worker process completed successfully.
# 2013-10-29T10:10:14 [25400] Query: INSERT IGNORE INTO `table10000_innodb_key_pk_parts_2_int_autoinc` ( `c0` , `c0` ) VALUES ( 192 , 33 ) , ( 6 , 249 ) failed: 1110 Column '%s' specified twice. Further errors of this kind will be suppressed.
# 2013-10-29T10:10:15 [25407] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:15 [25407] Child worker process completed successfully.
# 2013-10-29T10:10:15 [25416] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:15 [25416] Child worker process completed successfully.
# 2013-10-29T10:10:15 [25408] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:15 [25408] Child worker process completed successfully.
# 2013-10-29T10:10:16 [25418] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:16 [25418] Child worker process completed successfully.
# 2013-10-29T10:10:17 [25411] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:17 [25411] Child worker process completed successfully.
# 2013-10-29T10:10:19 [25417] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:19 [25417] Child worker process completed successfully.
# 2013-10-29T10:10:19 [25404] MarkErrorLog found errorlog at /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data//../mysql.err
# 2013-10-29T10:10:19 [25404] Child worker process completed successfully.
# 2013-10-29T10:10:34 [25412] Child worker process completed successfully.
# 2013-10-29T10:10:34 [25400] Query: UPDATE IGNORE `table10000_innodb_key_pk_parts_2_int_autoinc` AS X SET `c3` = 9 WHERE X . `c3` IN ( 3288268800 , 8 , 2 , 1289486336 , 'd' ) ORDER BY `c0`,`c1`,`c2`,`c3`,`pk` LIMIT 5 failed: 1213 Deadlock found when trying to get lock; try restarting transaction. Further errors of this kind will be suppressed.
# 2013-10-29T10:10:35 [18883] Killing periodic reporting process with pid 25401...
# 2013-10-29T10:10:35 [18883] Kill GenTest::ErrorFilter(25400)
# 2013-10-29T10:10:35 [18883] Valgrind: Issues detected (error count: 0). Relevant messages from log file '/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data/../mysql.err':
# 2013-10-29T10:10:35 [18883] ==00:00:00:00.000 20352== Memcheck, a memory error detector
# 2013-10-29T10:10:35 [18883] ==00:00:00:00.000 20352== Copyright (C) 2002-2012, and GNU GPL'd, by Julian Seward et al.
# 2013-10-29T10:10:35 [18883] ==00:00:00:00.000 20352== Using Valgrind-3.8.1 and LibVEX; rerun with -h for copyright info
# 2013-10-29T10:10:35 [18883] ==00:00:00:00.000 20352== Command: /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/bin/mysqld --no-defaults --basedir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64 --datadir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/data --lc-messages-dir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/share --character-sets-dir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/share/charsets --tmpdir=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/tmp --core-file --max-allowed-packet=128Mb --port=11940 --socket=/tmp/RQGmysql.11940.sock --pid-file=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/node0/mysql.pid --general-log --general-log-file=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/118/tmp.IYfrgu1q0D/current1_3/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:4808&pc.ignore_sb=true --wsrep_sst_receive_address=127.0.0.1:4811 --skip-performance-schema --log-output=none --sql_mode=ONLY_FULL_GROUP_BY --innodb-buffer-pool-populate --innodb_flush_method=O_DIRECT --innodb_change_buffering=none --innodb_lock_wait_timeout=100 --lock_wait_timeout=500 --innodb_adaptive_hash_index_partitions=1 --thread_handling=pool-of-threads --wsrep_retry_autocommit=0 --wsrep_slave_threads=8 --wsrep_causal_reads=ON --innodb_flush_log_at_trx_commit=1 --transaction-isolation=READ-UNCOMMITTED --innodb_file_per_table=1 --wsrep-provider=/mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/Percona-XtraDB-Cluster-5.5.34-23.7.6.566.Linux.x86_64/lib/libgalera_smm.so
# 2013-10-29T10:10:35 [18883] ==00:00:00:00.000 20352==
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.034 20352== Thread 3:
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.034 20352== Invalid write of size 8
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.034 20352== at 0x650919A: gcomm::GMCast::handle_up(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (gmcast_proto.hpp:119)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.034 20352== by 0x652CD5B: gcomm::Protostack::dispatch(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (protostack.cpp:60)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x655AE9A: gcomm::AsioProtonet::dispatch(void const* const&, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (asio_protonet.cpp:250)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x653866F: gcomm::AsioTcpSocket::read_handler(asio::error_code const&, unsigned long) (asio_tcp.cpp:433)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x654ED84: asio::detail::read_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, boost::array<asio::mutable_buffer, 1ul>, boost::_bi::bind_t<unsigned long, boost::_mfi::mf2<unsigned long, gcomm::AsioTcpSocket, asio::error_code const&, unsigned long>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> >, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, asio::error_code const&, unsigned long>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > >::operator()(asio::error_code const&, unsigned long, int) (mem_fn_template.hpp:265)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x654FA95: asio::detail::reactive_socket_recv_op<asio::detail::consuming_buffers<asio::mutable_buffer, boost::array<asio::mutable_buffer, 1ul> >, asio::detail::read_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, boost::array<asio::mutable_buffer, 1ul>, boost::_bi::bind_t<unsigned long, boost::_mfi::mf2<unsigned long, gcomm::AsioTcpSocket, asio::error_code const&, unsigned long>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> >, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, asio::error_code const&, unsigned long>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > >::do_complete(asio::detail::task_io_service*, asio::detail::task_io_service_operation*, asio::error_code, unsigned long) (bind_handler.hpp:96)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x6563E88: asio::detail::task_io_service::run(asio::error_code&) (task_io_service_operation.hpp:34)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x655BDD5: gcomm::AsioProtonet::event_loop(gu::datetime::Period const&) (io_service.ipp:56)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x6576456: GCommConn::run() (gcs_gcomm.cpp:440)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x6579D28: GCommConn::run_fn(void*) (gcs_gcomm.cpp:206)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x381C407850: start_thread (in /lib64/libpthread-2.12.so)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x381C0E894C: clone (in /lib64/libc-2.12.so)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== Address 0x1c23d1e8 is 168 bytes inside a block of size 176 free'd
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== at 0x4A063F0: free (vg_replace_malloc.c:446)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64FE151: gcomm::GMCast::handle_failed(gcomm::gmcast::Proto*) (gmcast.cpp:670)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64FE99E: gcomm::GMCast::check_liveness() (gmcast.cpp:1004)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64FFAE6: gcomm::GMCast::handle_stable_view(gcomm::View const&) (gmcast.cpp:1399)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64DEF06: gcomm::evs::Proto::deliver_reg_view() (protolay.hpp:317)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64EBCC8: gcomm::evs::Proto::shift_to(gcomm::evs::Proto::State, bool) (evs_proto.cpp:2331)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64E963E: gcomm::evs::Proto::handle_gap(gcomm::evs::GapMessage const&, std::_Rb_tree_iterator<std::pair<gcomm::UUID const, gcomm::evs::Node> >) (evs_proto.cpp:2949)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64F100A: gcomm::evs::Proto::handle_msg(gcomm::evs::Message const&, gcomm::Datagram const&) (evs_proto.cpp:1955)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x64F1FF5: gcomm::evs::Proto::handle_up(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (evs_proto.cpp:2043)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x650A19D: gcomm::Protolay::send_up(gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (protolay.hpp:277)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x6509149: gcomm::GMCast::handle_up(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (gmcast.cpp:1212)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352== by 0x652CD5B: gcomm::Protostack::dispatch(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (protostack.cpp:60)
# 2013-10-29T10:10:35 [18883] ==00:00:00:24.035 20352==
# 2013-10-29T10:10:35 [18883] Shutting down server on port 11941 via DBI...
# 2013-10-29T10:10:35 [18883] Shutting down server with pid 21532 with SIGTERM...
# 2013-10-29T10:10:35 [18883] Waiting for mysqld with pid 21532 to terminate...
+++++++++++++++++++++++++++
# 2013-10-29T10:11:02 [18883] ... waiting complete. Just in case, killing server with pid 21532 with SIGKILL ...
# 2013-10-29T10:11:02 [18883] Shutting down server on port 11940 via DBI...
# 2013-10-29T10:11:02 [18883] Shutting down server with pid 20352 with SIGTERM...
# 2013-10-29T10:11:02 [18883] Waiting for mysqld with pid 20352 to terminate...
+++++++++++++++
# 2013-10-29T10:11:17 [18883] ... waiting complete. Just in case, killing server with pid 20352 with SIGKILL ...
# 2013-10-29T10:11:17 [18883] Test completed with failure status STATUS_VALGRIND_FAILURE (108)
# 2013-10-29T10:11:17 [18883] GenTest exited with exit status STATUS_VALGRIND_FAILURE (108)
# 2013-10-29T10:11:17 [18883] Stopping server on port 11940
# 2013-10-29T10:11:17 [18883] Stale connection. Reconnecting
# 2013-10-29T10:11:17 [18883] Reconnect failed due to 2003:Can't connect to MySQL server on '127.0.0.1' (111)
# 2013-10-29T10:11:17 [18883] Server would not shut down properly. Terminate it
# 2013-10-29T10:11:17 [18883] Terminated process 20352
# 2013-10-29T10:11:17 [18883] Stopping server on port 11941
# 2013-10-29T10:11:17 [18883] Stale connection. Reconnecting
# 2013-10-29T10:11:17 [18883] Reconnect failed due to 2003:Can't connect to MySQL server on '127.0.0.1' (111)
# 2013-10-29T10:11:17 [18883] Server would not shut down properly. Terminate it
# 2013-10-29T10:11:17 [18883] Terminated process 21532
# 2013-10-29T10:11:17 [18883] [18883] /mnt/workspace/PXC-5.5-mrandgen/BTYPE/release/Host/centos6-64/pxcgen/runall-new.pl will exit with exit status STATUS_VALGRIND_FAILURE (108) |
|
