[MDEV-24135] Valgrind / ASAN warnings and retry-pass/retry-fail info do not go to MTR XML, XML can contain illegal symbols Created: 2020-11-05  Updated: 2021-04-12  Resolved: 2021-04-12

Status: Closed
Project: MariaDB Server
Component/s: Tests
Fix Version/s: 10.2.38, 10.3.29, 10.4.19, 10.5.10

Type: Task Priority: Major
Reporter: Timofey Turenko Assignee: Anel Husakovic
Resolution: Fixed Votes: 0
Labels: None

Attachments: HTML File jenkins     File mtr.log     File mtr_apr01.log     XML File mtr_apr01.xml     File mtr_big.log     XML File mtr_big.xml     File mtr_big_apr09.log     XML File mtr_big_apr09.xml     File mtr_galera.log     XML File mtr_galera.xml     File mtr_retry_pass2.log     HTML File stdio (9)    
Issue Links:
Blocks
Issue split

 Description   

If MTR is started with Valgrind and test fails due to Valgrind warnings, XML file from MTR contains only ne-line message like CURRENT_TEST: main.analyze_stmt_orderby, but whole output can be visible only from Console log (so, it is not going to Jenkins report or test results DB viewer)

Also if test case is restarted by MTR result can be retry-fail or retry-pass - such situation is not translated to XML (restarted case is mentioned only ones - there is no way to see e.g. initial failure logs if test is 'retry-pass')

another issue: every test can be executed with different parameters, e.g.: 

innod.101_compatibility "innodb,32k" [ failed ]
 
innod.101_compatibility "innodb,16k" [ passed ]
 
innod.101_compatibility "innodb,8k" [ passed ]

If warning, comment etc contains symbols that are illegal for XML such symbols go to CDATA filed and generated XML is malformed

 Comments   
Comment by Timofey Turenko [ 2020-11-05 ]

please also check what can happen for MSAN test runs

Comment by Alexey Bychko (Inactive) [ 2020-11-06 ]

and for ASAN please

Comment by Timofey Turenko [ 2020-12-08 ]

the same happens also with other tests:

e.g. for toku_add_index.1522 test: https://mdbe-ci-repo.mariadb.net/bb-logs/MariaDBServerCommunity/10.2-Debug--2020-12-06-06-33-16/ubuntu/focal/mtr-psproto-test/mtr.log

tokudb_add_index.1522                    w1 [ fail ]
 
        Test ended at 2020-12-06 08:26:15
 
 
 
CURRENT_TEST: tokudb_add_index.1522
 
 
 
 
 
Failed to start mysqld.1
 
mysqltest failed but provided no output
 
 
 
 
 
 - skipping '/var/tmp/mtr/1/log/tokudb_add_index.1522/'
 
 
 
Retrying test tokudb_add_index.1522, attempt(2/3)...
 
 
 
***Warnings generated in error logs during shutdown after running tests: tokudb_add_index.1522
 
 
 
2020-12-06  8:26:14 140353668523968 [ERROR] Couldn't load plugins from 'ha_tokudb.so'.
 
2020-12-06  8:26:14 140353668523968 [ERROR] /home/timofey_turenko_mariadb_com/MariaDBEnterprise/bin/mysqld: unknown option '--tokudb'
 
2020-12-06  8:26:14 140353668523968 [ERROR] Aborting
 
 
 
worker[6] mysql-test-run: WARNING: Process [mysqld.1 - pid: 185137, winpid: 185137, exit: 512] died after mysql-test-run waited 0.3 seconds for /var/tmp/mtr/6/run/mysqld.1.pid to be created.

but XML has only one line:

 
 
<testcase assertions="" classname="tokudb_add_index" name="1522" status="MTR_RES_FAILED" time="0.000">
 
<failure message="" type="MTR_RES_FAILED">
 
<![CDATA[ CURRENT_TEST: tokudb_add_index.1522 ]]>
 
</failure>
 
</testcase>

https://mdbe-ci-repo.mariadb.net/bb-logs/MariaDBServerCommunity/10.2-Debug--2020-12-06-06-33-16/ubuntu/focal/mtr-psproto-test/mtr.xml

Comment by Anel Husakovic [ 2021-01-20 ]

Hi,
how exactly you run the test and inspect the XML file (from where) ?
Also, are there any versions which are working good (with error reported)?
What is desired version to fix (10.2 I assume) ?
Can you please test what will happen if you remove this line ?

Comment by Timofey Turenko [ 2021-01-21 ]

command is:

sudo su - mysql -s /bin/bash -c ' export WSREP_PROVIDER=/usr/lib/galera/libgalera_smm.so; cd /home/timofey_turenko_mariadb_com/MariaDBEnterprise/mysql-test && perl mysql-test-run.pl --ps-protocol --max-test-fail=0 --retry=3 --parallel=auto --max-save-core=0 --max-save-datadir=1 --force --vardir=/var/tmp/mtr --xml-report=mtr.xml '

(bb link https://mdbe-buildbot.mariadb.net/#/builders/17/builds/16104)

fix should go to all versions of CS and ES starting from 10.2

should I try with reverted commit cd927dd34555a34e733a01bf5af52470f57ce906 ? or just remove unlink $path_current_testlog; ?

Comment by Anel Husakovic [ 2021-01-21 ]

Thanks,
just try to delete that line please.

Comment by Timofey Turenko [ 2021-01-22 ]

tried to delete the line, result is not good at all:

<?xml version="1.0" encoding="UTF-8"?>
 
<testsuites disabled="50" errors="" failures="31" name="" tests="412" time="2606.738">
 
	<testsuite disabled="35" errors="" failures="22" hostname="mdbci-p1wjzu5y-1611308259-build" id="0" name="galera" package="" skipped="57" tests="375" time="1568.538" timestamp="2021-01-22T14:03:41Z">
 
		<testcase assertions="" classname="galera" name="GAL-382" status="MTR_RES_PASSED" time="2.085" />
 
		<testcase assertions="" classname="galera" name="GAL-401" status="MTR_RES_PASSED" time="16.588" />
 
		<testcase assertions="" classname="galera" name="GAL-419" status="MTR_RES_FAILED" time="0.000">
 
			<failure message="" type="MTR_RES_FAILED">
 
<![CDATA[CURRENT_TEST: galera.galera_log_output_csv
 
CURRENT_TEST: galera.galera_forced_binlog_format
 
CURRENT_TEST: galera.galera_nbo_temporary_table
 
CURRENT_TEST: galera.galera_var_innodb_disallow_writes
 
find: Must separate multiple arguments to -type using: ','
 
find: Must separate multiple arguments to -type using: ','
 
CURRENT_TEST: galera.mdev_18730
 
The test '/home/turenko/MariaDBEnterprise/mysql-test/suite/galera/t/mdev_18730.test' is not supported by this installation
 
Detected in file ./include/have_debug_sync.inc at line 3
 
included from /home/turenko/MariaDBEnterprise/mysql-test/suite/galera/t/mdev_18730.test at line 18:
 
reason: debug_sync is not available
 
CURRENT_TEST: galera.MDEV-22021
 
CURRENT_TEST: galera.galera_multirow_rollback
 
CURRENT_TEST: galera.mysql-wsrep#198
 
CURRENT_TEST: galera.MW-44
 
CURRENT_TEST: galera.galera_wsrep_new_cluster
 
CURRENT_TEST: galera.mysql-wsrep-features#128
 
CURRENT_TEST: galera.GAL-419
 
2021-01-22 13:35:22 0 [Warning] WSREP: option --wsrep-causal-reads is deprecated
 
2021-01-22 13:35:22 0 [Note] /home/turenko/MariaDBEnterprise/bin/mariadbd (mysqld 10.5.8-5-MariaDB-enterprise-log) starting as process 348865 ...
 
2021-01-22 13:35:22 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 32190)
 
2021-01-22 13:35:22 0 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
 
2021-01-22 13:35:22 0 [Warning] WSREP: wsrep_sst_receive_address is set to '127.0.0.1:16004' which makes it impossible for another host to reach this one. Please set it to the address which this node can be connected at by other cluster members.
 
Segmentation fault (core dumped)]]>
 
			</failure>
 
		</testcase>
 
		<testcase assertions="" classname="galera" name="GAL-480" status="MTR_RES_PASSED" time="2.332" />
 
		<testcase assertions="" classname="galera" name="GCF-1081" status="MTR_RES_SKIPPED" time="0.000">
 
			<disabled message="MDEV-18283 Galera test failure on galera.GCF-1081" type="MTR_RES_SKIPPED"/>
 
		</testcase>
 
		<testcase assertions="" classname="galera" name="GCF-329A" status="MTR_RES_FAILED" time="0.000">
 
			<failure message="" type="MTR_RES_FAILED">
 
<![CDATA[CURRENT_TEST: galera.galera_log_output_csv
 
CURRENT_TEST: galera.galera_forced_binlog_format
 
CURRENT_TEST: galera.galera_nbo_temporary_table
 
CURRENT_TEST: galera.galera_var_innodb_disallow_writes
 
find: Must separate multiple arguments to -type using: ','
 
find: Must separate multiple arguments to -type using: ','
 
CURRENT_TEST: galera.mdev_18730
 
The test '/home/turenko/MariaDBEnterprise/mysql-test/suite/galera/t/mdev_18730.test' is not supported by this installation
 
Detected in file ./include/have_debug_sync.inc at line 3
 
included from /home/turenko/MariaDBEnterprise/mysql-test/suite/galera/t/mdev_18730.test at line 18:
 
reason: debug_sync is not available
 
CURRENT_TEST: galera.MDEV-22021
 
CURRENT_TEST: galera.galera_multirow_rollback
 
CURRENT_TEST: galera.mysql-wsrep#198
 
CURRENT_TEST: galera.MW-44
 
CURRENT_TEST: galera.galera_wsrep_new_cluster
 
CURRENT_TEST: galera.mysql-wsrep-features#128
 
CURRENT_TEST: galera.GAL-419
 
2021-01-22 13:35:22 0 [Warning] WSREP: option --wsrep-causal-reads is deprecated
 
2021-01-22 13:35:22 0 [Note] /home/turenko/MariaDBEnterprise/bin/mariadbd (mysqld 10.5.8-5-MariaDB-enterprise-log) starting as process 348865 ...
 
2021-01-22 13:35:22 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 32190)
 
2021-01-22 13:35:22 0 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
 
2021-01-22 13:35:22 0 [Warning] WSREP: wsrep_sst_receive_address is set to '127.0.0.1:16004' which makes it impossible for another host to reach this one. Please set it to the address which this node can be connected at by other cluster members.
 
Segmentation fault (core dumped)
 
CURRENT_TEST: galera.GCF-329A]]>
 
			</failure>
 
		</testcase>
 
		<testcase assertions="" classname="galera" name="GCF-329B" status="MTR_RES_PASSED" time="18.893" />
 
		<testcase assertions="" classname="galera" name="GCF-360" status="MTR_RES_PASSED" time="5.507" />
 
		<testcase assertions="" classname="galera" name="GCF-421" status="MTR_RES_SKIPPED" time="0.000">
 
			<skipped message="Requires debug build" type="MTR_RES_SKIPPED"/>
 
		</testcase>
 
		<testcase assertions="" classname="galera" name="GCF-546" status="MTR_RES_SKIPPED" time="0.000">
 
			<skipped message="Requires debug build" type="MTR_RES_SKIPPED"/>
 
		</testcase>
 
		<testcase assertions="" classname="galera" name="GCF-563" status="MTR_RES_SKIPPED" time="0.000">
 
			<skipped message="Requires debug build" type="MTR_RES_SKIPPED"/>
 
		</testcase>
 
		<testcase assertions="" classname="galera" name="GCF-849" status="MTR_RES_PASSED" time="9.342" />
 
....

Comment by Roel Van de Paar [ 2021-01-30 ]

Discussed this with tturenko today.

Instead of going for an XML based solution, we will go for uniqueID's for all *SAN bugs similar to uniqueID's implemented in pquery framework for crashing/asserting bugs. This will allow easy filtering, better (near 100%) bug mapping quality, etc.

Timeline; at least 4 weeks before we start with this due to other ongoing work. Roel will implement uniqueID's into Bash script, Timofey will implement automation to check logs using the same tool.

Comment by Anel Husakovic [ 2021-02-01 ]

tturenko can you please check this commit e54c5641b7 ? It should solve this problem.
Commit message explains how is done doing from source and *Notes* related to this MDEV.
I lost a lot of time trying to figure out right test case since valgrind confused me and you did a test with tokudb_add_index.1522 not related to valgrind.
So I'm adding you as a reviewer.
If the test is not good, please provide just single test case to play with (not --max-test-fail=0 please).

Comment by Roel Van de Paar [ 2021-02-01 ]

julien.fritsch tturenko ack. Lodged TODO-2756, so this issue can be used for XML side only.

Comment by Timofey Turenko [ 2021-02-01 ]

I tried to run tests from you branch: first result is malformed XML https://mdbe-ci-repo.mariadb.net/bb-logs/MariaDBServerCommunity/bb-10.2-anel-MDEV-24135/ubuntu/focal/mtr-galera-test/mtr.xml

here is parser output https://mdbe-buildbot.mariadb.net/#/builders/21/builds/17436

test `galera.galera_log_output_csv 'innodb' ` failed, there are a lot of lines from Valgrid.

Another test run https://mdbe-ci-repo.mariadb.net/bb-logs/MariaDBServerCommunity/bb-10.2-anel-MDEV-24135/ubuntu/focal/mtr-engines-test/mtr.log and XML https://mdbe-ci-repo.mariadb.net/bb-logs/MariaDBServerCommunity/bb-10.2-anel-MDEV-24135/ubuntu/focal/mtr-engines-test/mtr.xml
In this case there are Valgrind output:

 
 
***Warnings generated in error logs during shutdown after running tests: engines/funcs.ta_drop_index engines/funcs.ta_2part_diff_to_pk engines/funcs.ta_column_from_unsigned engines/funcs.ta_column_to_unsigned engines/funcs.se_join_natural_right engines/funcs.ta_column_to_not_null engines/funcs.ta_add_string_unique_index
 
 
 
==35305== 208 bytes in 1 blocks are still reachable in loss record 2 of 5
 
==35305==    at 0x483DD99: calloc (in /usr/lib/x86_64-linux-gnu/valgrind/vgpreload_memcheck-amd64-linux.so)
 
==35305==    by 0xC9E6AE: my_thread_init (my_thr_init.c:295)
 
==35305==    by 0xC9E6AE: my_thread_init (my_thr_init.c:270)
 
==35305==    by 0x59096C: kill_server_thread (mysqld.cc:2046)
 
==35305==    by 0xC64286: pfs_spawn_thread (pfs.cc:1869)
 
==35305==    by 0x4D89608: start_thread (pthread_create.c:477)
 
==35305==    by 0x5210292: clone (clone.S:95)

but there is no any single failed test (probably it is a separate issue to investigate)

Comment by Dmitriy Karpovskiy (Inactive) [ 2021-02-02 ]

The problem of generating XML is not simple. The generation of XML and the main log (output of all tests and their status) is different. The XML gets data from the internal part of MariaDB, but the warnings are generated in the external part of MariaDB. https://github.com/MariaDB/server/blob/10.2/mysql-test/mysql-test-run.pl#L969 this is the output of exceptions to the main log. https://github.com/MariaDB/server/blob/10.2/mysql-test/mysql-test-run.pl#L5152 this is the formation of data in XML.

Accordingly, to solve this problem, you need to pass data from the external log to the XML generation. But there is a problem in understanding the logic of sockets, in which the warning data is stored.

I tried passing these sockets to the XML generation function, but it was not successful.

Comment by Anel Husakovic [ 2021-02-02 ]

Hi tturenko,
thanks for the update.
Just note that I don't have access to https://mdbe-buildbot.mariadb.net so I couldn't see the results .
But no problem. I tested with galera.galera_log_output_csv in case when valgrind option is invoked and could produce.
So the meaning of this patch is to enable warnings to be present and the patch 2f05fe1b55b is adding this. Can you please test it?
If you are OK with this, I will push it, but with different commit message.

The result of xml file:

$ cat mysql-test/mtr_galera_with_warnings2.xml 
<?xml version="1.0" encoding="UTF-8"?>
 
<testsuites disabled="0" errors="" failures="1" name="" tests="2" time="0.000">
 
	<testsuite disabled="" errors="" failures="1" hostname="anel" id="0" name="galera" package="" skipped="" tests="1" time="0.000" timestamp="2021-02-02T10:09:10Z">
 
		<testcase assertions="" classname="galera" name="galera_log_output_csv" status="MTR_RES_FAILED" time="0.000">
 
			<failure message="" type="MTR_RES_FAILED">
 
<![CDATA[CURRENT_TEST: galera.galera_log_output_csvline
 
==8407== Thread 4:
 
==8407== Syscall param sendmsg(msg.msg_iov[0]) points to uninitialised byte(s)
 
==8407==    at 0x69716F7: sendmsg (sendmsg.c:28)
 
==8407==    by 0xB104DE0: send (socket_ops.ipp:1169)
 
==8407==    by 0xB104DE0: non_blocking_send (socket_ops.ipp:1243)
 
==8407==    by 0xB104DE0: asio::detail::reactive_socket_send_op_base<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2ul> > >::do_perform(asio::detail::reactor_op*) (reactive_socket_send_op.hpp:55)
 
==8407==    by 0xB105EE0: perform (reactor_op.hpp:39)
 
==8407==    by 0xB105EE0: asio::detail::epoll_reactor::start_op(int, int, asio::detail::epoll_reactor::descriptor_state*&, asio::detail::reactor_op*, bool, bool) (epoll_reactor.ipp:230)
 
==8407==    by 0xB10694A: asio::detail::reactive_socket_service_base::start_op(asio::detail::reactive_socket_service_base::base_implementation_type&, int, asio::detail::reactor_op*, bool, bool, bool) (reactive_socket_service_base.ipp:212)
 
==8407==    by 0xB1110F3: async_send<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (reactive_socket_service_base.hpp:215)
 
==8407==    by 0xB1110F3: async_send<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (stream_socket_service.hpp:329)
 
==8407==    by 0xB1110F3: async_write_some<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (basic_stream_socket.hpp:731)
 
==8407==    by 0xB1110F3: asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, std::tr1::array<asio::const_buffer, 2ul>, asio::detail::transfer_all_t, 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) (write.hpp:180)
 
==8407==    by 0xB0FF981: async_write<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > (write.hpp:623)
 
==8407==    by 0xB0FF981: gcomm::AsioTcpSocket::write_one(std::tr1::array<asio::const_buffer, 2ul> const&) (asio_tcp.cpp:703)
 
==8407==    by 0xB100823: gcomm::AsioTcpSocket::write_handler(asio::error_code const&, unsigned long) (asio_tcp.cpp:370)
 
==8407==    by 0xB111389: call<boost::shared_ptr<gcomm::AsioTcpSocket>, const asio::error_code, long unsigned int> (mem_fn_template.hpp:271)
 
==8407==    by 0xB111389: operator()<boost::shared_ptr<gcomm::AsioTcpSocket> > (mem_fn_template.hpp:286)
 
==8407==    by 0xB111389: operator()<boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list2<const asio::error_code&, long unsigned int const&> > (bind.hpp:398)
 
==8407==    by 0xB111389: operator()<asio::error_code, long unsigned int> (bind_template.hpp:102)
 
==8407==    by 0xB111389: asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, std::tr1::array<asio::const_buffer, 2ul>, asio::detail::transfer_all_t, 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) (write.hpp:191)
 
==8407==    by 0xB1115AF: operator() (bind_handler.hpp:126)
 
==8407==    by 0xB1115AF: asio_handler_invoke<asio::detail::binder2<asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > >, asio::error_code, long unsigned int> > (handler_invoke_hook.hpp:68)
 
==8407==    by 0xB1115AF: invoke<asio::detail::binder2<asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > >, asio::error_code, long unsigned int>, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > (handler_invoke_helpers.hpp:37)
 
==8407==    by 0xB1115AF: asio_handler_invoke<asio::detail::binder2<asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > >, asio::error_code, long unsigned int>, asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > (write.hpp:564)
 
==8407==    by 0xB1115AF: invoke<asio::detail::binder2<asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > >, asio::error_code, long unsigned int>, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (handler_invoke_helpers.hpp:37)
 
==8407==    by 0xB1115AF: asio::detail::reactive_socket_send_op<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2ul> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, std::tr1::array<asio::const_buffer, 2ul>, asio::detail::transfer_all_t, 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 const&, unsigned long) (reactive_socket_send_op.hpp:106)
 
==8407==    by 0xB123D47: complete (task_io_service_operation.hpp:37)
 
==8407==    by 0xB123D47: do_run_one (task_io_service.ipp:371)
 
==8407==    by 0xB123D47: run (task_io_service.ipp:148)
 
==8407==    by 0xB123D47: run (io_service.ipp:58)
 
==8407==    by 0xB123D47: gcomm::AsioProtonet::event_loop(gu::datetime::Period const&) (asio_protonet.cpp:116)
 
==8407==    by 0xB13AB13: GCommConn::run() (gcs_gcomm.cpp:433)
 
==8407==    by 0xB1434A8: GCommConn::run_fn(void*) (gcs_gcomm.cpp:174)
 
==8407==    by 0x69666DA: start_thread (pthread_create.c:463)
 
==8407==    by 0x762971E: clone (clone.S:95)
 
==8407==  Address 0x16064c5c is 204 bytes inside a block of size 480 alloc'd
 
==8407==    at 0x4DA517F: operator new(unsigned long) (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
 
==8407==    by 0xB10D582: allocate (new_allocator.h:111)
 
==8407==    by 0xB10D582: allocate (alloc_traits.h:130)
 
==8407==    by 0xB10D582: _M_allocate_node (stl_deque.h:602)
 
==8407==    by 0xB10D582: std::deque<gcomm::Datagram, std::allocator<gcomm::Datagram> >::_M_push_back_aux(gcomm::Datagram const&) (deque.tcc:487)
 
==8407==    by 0xB0FAF6A: push_back (stl_deque.h:1552)
 
==8407==    by 0xB0FAF6A: push_back (fair_send_queue.hpp:41)
 
==8407==    by 0xB0FAF6A: gcomm::AsioTcpSocket::send(int, gcomm::Datagram const&) (asio_tcp.cpp:469)
 
==8407==    by 0xB0A9DF3: gcomm::GMCast::send(gcomm::GMCast::RelayEntry const&, int, gcomm::Datagram&) (gmcast.cpp:1314)
 
==8407==    by 0xB0AB8AA: gcomm::GMCast::handle_down(gcomm::Datagram&, gcomm::ProtoDownMeta const&) (gmcast.cpp:1655)
 
==8407==    by 0xB0A0A03: gcomm::Protolay::send_down(gcomm::Datagram&, gcomm::ProtoDownMeta const&) (protolay.hpp:299)
 
==8407==    by 0xB086361: gcomm::evs::Proto::send_user(gcomm::Datagram&, unsigned char, gcomm::Order, long, long, unsigned long) (evs_proto.cpp:1550)
 
==8407==    by 0xB087CFB: gcomm::evs::Proto::handle_down(gcomm::Datagram&, gcomm::ProtoDownMeta const&) (evs_proto.cpp:2658)
 
==8407==    by 0xB0A0A03: gcomm::Protolay::send_down(gcomm::Datagram&, gcomm::ProtoDownMeta const&) (protolay.hpp:299)
 
==8407==    by 0xB0DAA26: gcomm::pc::Proto::handle_down(gcomm::Datagram&, gcomm::ProtoDownMeta const&) (pc_proto.cpp:1605)
 
==8407==    by 0xB0A0A03: gcomm::Protolay::send_down(gcomm::Datagram&, gcomm::ProtoDownMeta const&) (protolay.hpp:299)
 
==8407==    by 0xB13A754: send_down (protolay.hpp:299)
 
==8407==    by 0xB13A754: gcomm_send(gcs_backend*, void const*, unsigned long, gcs_msg_type) (gcs_gcomm.cpp:541)
 
==8407==    by 0xB12EFB4: core_handle_comp_msg (gcs_core.cpp:768)
 
==8407==    by 0xB12EFB4: gcs_core_recv(gcs_core*, gcs_act_rcvd*, long long) (gcs_core.cpp:1118)
 
==8407==    by 0xB1346B1: gcs_recv_thread(void*) (gcs.cpp:1277)
 
==8407==    by 0x69666DA: start_thread (pthread_create.c:463)
 
==8407==    by 0x762971E: clone (clone.S:95)
 
==8407== Syscall param sendmsg(msg.msg_iov[1]) points to uninitialised byte(s)
 
==8407==    at 0x69716F7: sendmsg (sendmsg.c:28)
 
==8407==    by 0xB104DE0: send (socket_ops.ipp:1169)
 
==8407==    by 0xB104DE0: non_blocking_send (socket_ops.ipp:1243)
 
==8407==    by 0xB104DE0: asio::detail::reactive_socket_send_op_base<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2ul> > >::do_perform(asio::detail::reactor_op*) (reactive_socket_send_op.hpp:55)
 
==8407==    by 0xB105EE0: perform (reactor_op.hpp:39)
 
==8407==    by 0xB105EE0: asio::detail::epoll_reactor::start_op(int, int, asio::detail::epoll_reactor::descriptor_state*&, asio::detail::reactor_op*, bool, bool) (epoll_reactor.ipp:230)
 
==8407==    by 0xB10694A: asio::detail::reactive_socket_service_base::start_op(asio::detail::reactive_socket_service_base::base_implementation_type&, int, asio::detail::reactor_op*, bool, bool, bool) (reactive_socket_service_base.ipp:212)
 
==8407==    by 0xB1110F3: async_send<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (reactive_socket_service_base.hpp:215)
 
==8407==    by 0xB1110F3: async_send<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (stream_socket_service.hpp:329)
 
==8407==    by 0xB1110F3: async_write_some<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (basic_stream_socket.hpp:731)
 
==8407==    by 0xB1110F3: asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, std::tr1::array<asio::const_buffer, 2ul>, asio::detail::transfer_all_t, 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) (write.hpp:180)
 
==8407==    by 0xB0FF981: async_write<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > (write.hpp:623)
 
==8407==    by 0xB0FF981: gcomm::AsioTcpSocket::write_one(std::tr1::array<asio::const_buffer, 2ul> const&) (asio_tcp.cpp:703)
 
==8407==    by 0xB100823: gcomm::AsioTcpSocket::write_handler(asio::error_code const&, unsigned long) (asio_tcp.cpp:370)
 
==8407==    by 0xB111389: call<boost::shared_ptr<gcomm::AsioTcpSocket>, const asio::error_code, long unsigned int> (mem_fn_template.hpp:271)
 
==8407==    by 0xB111389: operator()<boost::shared_ptr<gcomm::AsioTcpSocket> > (mem_fn_template.hpp:286)
 
==8407==    by 0xB111389: operator()<boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list2<const asio::error_code&, long unsigned int const&> > (bind.hpp:398)
 
==8407==    by 0xB111389: operator()<asio::error_code, long unsigned int> (bind_template.hpp:102)
 
==8407==    by 0xB111389: asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, std::tr1::array<asio::const_buffer, 2ul>, asio::detail::transfer_all_t, 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) (write.hpp:191)
 
==8407==    by 0xB1115AF: operator() (bind_handler.hpp:126)
 
==8407==    by 0xB1115AF: asio_handler_invoke<asio::detail::binder2<asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > >, asio::error_code, long unsigned int> > (handler_invoke_hook.hpp:68)
 
==8407==    by 0xB1115AF: invoke<asio::detail::binder2<asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > >, asio::error_code, long unsigned int>, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > (handler_invoke_helpers.hpp:37)
 
==8407==    by 0xB1115AF: asio_handler_invoke<asio::detail::binder2<asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > >, asio::error_code, long unsigned int>, asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > (write.hpp:564)
 
==8407==    by 0xB1115AF: invoke<asio::detail::binder2<asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > >, asio::error_code, long unsigned int>, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (handler_invoke_helpers.hpp:37)
 
==8407==    by 0xB1115AF: asio::detail::reactive_socket_send_op<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2ul> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, std::tr1::array<asio::const_buffer, 2ul>, asio::detail::transfer_all_t, 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 const&, unsigned long) (reactive_socket_send_op.hpp:106)
 
==8407==    by 0xB123D47: complete (task_io_service_operation.hpp:37)
 
==8407==    by 0xB123D47: do_run_one (task_io_service.ipp:371)
 
==8407==    by 0xB123D47: run (task_io_service.ipp:148)
 
==8407==    by 0xB123D47: run (io_service.ipp:58)
 
==8407==    by 0xB123D47: gcomm::AsioProtonet::event_loop(gu::datetime::Period const&) (asio_protonet.cpp:116)
 
==8407==    by 0xB13AB13: GCommConn::run() (gcs_gcomm.cpp:433)
 
==8407==    by 0xB1434A8: GCommConn::run_fn(void*) (gcs_gcomm.cpp:174)
 
==8407==    by 0x69666DA: start_thread (pthread_create.c:463)
 
==8407==    by 0x762971E: clone (clone.S:95)
 
==8407==  Address 0x160653ba is 106 bytes inside a block of size 134 alloc'd
 
==8407==    at 0x4DA517F: operator new(unsigned long) (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
 
==8407==    by 0xB13A8AC: allocate (new_allocator.h:111)
 
==8407==    by 0xB13A8AC: allocate (alloc_traits.h:130)
 
==8407==    by 0xB13A8AC: _M_allocate (stl_vector.h:172)
 
==8407==    by 0xB13A8AC: _M_range_initialize<unsigned char const*> (stl_vector.h:1323)
 
==8407==    by 0xB13A8AC: _M_initialize_dispatch<unsigned char const*> (stl_vector.h:1299)
 
==8407==    by 0xB13A8AC: vector<unsigned char const*> (stl_vector.h:423)
 
==8407==    by 0xB13A8AC: Buffer<unsigned char const*> (gu_buffer.hpp:36)
 
==8407==    by 0xB13A8AC: gcomm_send(gcs_backend*, void const*, unsigned long, gcs_msg_type) (gcs_gcomm.cpp:513)
 
==8407==    by 0xB12E735: core_msg_send (gcs_core.cpp:257)
 
==8407==    by 0xB12E735: core_msg_send_retry (gcs_core.cpp:294)
 
==8407==    by 0xB12E735: core_handle_uuid_msg (gcs_core.cpp:872)
 
==8407==    by 0xB12E735: gcs_core_recv(gcs_core*, gcs_act_rcvd*, long long) (gcs_core.cpp:1123)
 
==8407==    by 0xB1346B1: gcs_recv_thread(void*) (gcs.cpp:1277)
 
==8407==    by 0x69666DA: start_thread (pthread_create.c:463)
 
==8407==    by 0x762971E: clone (clone.S:95)
 
^ Found warnings in /home/anel/mariadb/builds/10.2/mysql-test/var/log/mysqld.1.err
 
ok
 
line
 
==8444== Thread 4:
 
==8444== Syscall param sendmsg(msg.msg_iov[0]) points to uninitialised byte(s)
 
==8444==    at 0x69716F7: sendmsg (sendmsg.c:28)
 
==8444==    by 0xB104DE0: send (socket_ops.ipp:1169)
 
==8444==    by 0xB104DE0: non_blocking_send (socket_ops.ipp:1243)
 
==8444==    by 0xB104DE0: asio::detail::reactive_socket_send_op_base<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2ul> > >::do_perform(asio::detail::reactor_op*) (reactive_socket_send_op.hpp:55)
 
==8444==    by 0xB105EE0: perform (reactor_op.hpp:39)
 
==8444==    by 0xB105EE0: asio::detail::epoll_reactor::start_op(int, int, asio::detail::epoll_reactor::descriptor_state*&, asio::detail::reactor_op*, bool, bool) (epoll_reactor.ipp:230)
 
==8444==    by 0xB10694A: asio::detail::reactive_socket_service_base::start_op(asio::detail::reactive_socket_service_base::base_implementation_type&, int, asio::detail::reactor_op*, bool, bool, bool) (reactive_socket_service_base.ipp:212)
 
==8444==    by 0xB1110F3: async_send<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (reactive_socket_service_base.hpp:215)
 
==8444==    by 0xB1110F3: async_send<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (stream_socket_service.hpp:329)
 
==8444==    by 0xB1110F3: async_write_some<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (basic_stream_socket.hpp:731)
 
==8444==    by 0xB1110F3: asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, std::tr1::array<asio::const_buffer, 2ul>, asio::detail::transfer_all_t, 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) (write.hpp:180)
 
==8444==    by 0xB0FF981: async_write<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > (write.hpp:623)
 
==8444==    by 0xB0FF981: gcomm::AsioTcpSocket::write_one(std::tr1::array<asio::const_buffer, 2ul> const&) (asio_tcp.cpp:703)
 
==8444==    by 0xB119944: operator() (asio_tcp.cpp:431)
 
==8444==    by 0xB119944: asio_handler_invoke<gcomm::AsioPostForSendHandler> (handler_invoke_hook.hpp:68)
 
==8444==    by 0xB119944: invoke<gcomm::AsioPostForSendHandler, gcomm::AsioPostForSendHandler> (handler_invoke_helpers.hpp:37)
 
==8444==    by 0xB119944: asio::detail::completion_handler<gcomm::AsioPostForSendHandler>::do_complete(asio::detail::task_io_service*, asio::detail::task_io_service_operation*, asio::error_code const&, unsigned long) (completion_handler.hpp:67)
 
==8444==    by 0xB123D47: complete (task_io_service_operation.hpp:37)
 
==8444==    by 0xB123D47: do_run_one (task_io_service.ipp:371)
 
==8444==    by 0xB123D47: run (task_io_service.ipp:148)
 
==8444==    by 0xB123D47: run (io_service.ipp:58)
 
==8444==    by 0xB123D47: gcomm::AsioProtonet::event_loop(gu::datetime::Period const&) (asio_protonet.cpp:116)
 
==8444==    by 0xB13AB13: GCommConn::run() (gcs_gcomm.cpp:433)
 
==8444==    by 0xB1434A8: GCommConn::run_fn(void*) (gcs_gcomm.cpp:174)
 
==8444==    by 0x69666DA: start_thread (pthread_create.c:463)
 
==8444==    by 0x762971E: clone (clone.S:95)
 
==8444==  Address 0x163c258c is 204 bytes inside a block of size 480 alloc'd
 
==8444==    at 0x4DA517F: operator new(unsigned long) (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
 
==8444==    by 0xB10D582: allocate (new_allocator.h:111)
 
==8444==    by 0xB10D582: allocate (alloc_traits.h:130)
 
==8444==    by 0xB10D582: _M_allocate_node (stl_deque.h:602)
 
==8444==    by 0xB10D582: std::deque<gcomm::Datagram, std::allocator<gcomm::Datagram> >::_M_push_back_aux(gcomm::Datagram const&) (deque.tcc:487)
 
==8444==    by 0xB0FAF6A: push_back (stl_deque.h:1552)
 
==8444==    by 0xB0FAF6A: push_back (fair_send_queue.hpp:41)
 
==8444==    by 0xB0FAF6A: gcomm::AsioTcpSocket::send(int, gcomm::Datagram const&) (asio_tcp.cpp:469)
 
==8444==    by 0xB0A9DF3: gcomm::GMCast::send(gcomm::GMCast::RelayEntry const&, int, gcomm::Datagram&) (gmcast.cpp:1314)
 
==8444==    by 0xB0AB8AA: gcomm::GMCast::handle_down(gcomm::Datagram&, gcomm::ProtoDownMeta const&) (gmcast.cpp:1655)
 
==8444==    by 0xB0A0A03: gcomm::Protolay::send_down(gcomm::Datagram&, gcomm::ProtoDownMeta const&) (protolay.hpp:299)
 
==8444==    by 0xB086361: gcomm::evs::Proto::send_user(gcomm::Datagram&, unsigned char, gcomm::Order, long, long, unsigned long) (evs_proto.cpp:1550)
 
==8444==    by 0xB0877CD: gcomm::evs::Proto::complete_user(long) (evs_proto.cpp:1660)
 
==8444==    by 0xB09A7D4: gcomm::evs::Proto::handle_user(gcomm::evs::UserMessage const&, std::_Rb_tree_iterator<std::pair<gcomm::UUID const, gcomm::evs::Node> >, gcomm::Datagram const&) (evs_proto.cpp:3715)
 
==8444==    by 0xB09CFA6: gcomm::evs::Proto::handle_msg(gcomm::evs::Message const&, gcomm::Datagram const&, bool) (evs_proto.cpp:2440)
 
==8444==    by 0xB09DCE0: gcomm::evs::Proto::handle_up(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (evs_proto.cpp:2543)
 
==8444==    by 0xB0A06A5: gcomm::Protolay::send_up(gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (protolay.hpp:281)
 
==8444==    by 0xB0B88E2: gcomm::GMCast::handle_up(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (gmcast.cpp:1491)
 
==8444==    by 0xB0EAF52: gcomm::Protostack::dispatch(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (protostack.cpp:63)
 
==8444==    by 0xB1219EC: gcomm::AsioProtonet::dispatch(void const* const&, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (asio_protonet.cpp:127)
 
==8444==    by 0xB0FEC7E: gcomm::AsioTcpSocket::read_handler(asio::error_code const&, unsigned long) (asio_tcp.cpp:548)
 
==8444== Syscall param sendmsg(msg.msg_iov[1]) points to uninitialised byte(s)
 
==8444==    at 0x69716F7: sendmsg (sendmsg.c:28)
 
==8444==    by 0xB104DE0: send (socket_ops.ipp:1169)
 
==8444==    by 0xB104DE0: non_blocking_send (socket_ops.ipp:1243)
 
==8444==    by 0xB104DE0: asio::detail::reactive_socket_send_op_base<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2ul> > >::do_perform(asio::detail::reactor_op*) (reactive_socket_send_op.hpp:55)
 
==8444==    by 0xB105EE0: perform (reactor_op.hpp:39)
 
==8444==    by 0xB105EE0: asio::detail::epoll_reactor::start_op(int, int, asio::detail::epoll_reactor::descriptor_state*&, asio::detail::reactor_op*, bool, bool) (epoll_reactor.ipp:230)
 
==8444==    by 0xB10694A: asio::detail::reactive_socket_service_base::start_op(asio::detail::reactive_socket_service_base::base_implementation_type&, int, asio::detail::reactor_op*, bool, bool, bool) (reactive_socket_service_base.ipp:212)
 
==8444==    by 0xB1110F3: async_send<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (reactive_socket_service_base.hpp:215)
 
==8444==    by 0xB1110F3: async_send<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (stream_socket_service.hpp:329)
 
==8444==    by 0xB1110F3: async_write_some<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (basic_stream_socket.hpp:731)
 
==8444==    by 0xB1110F3: asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, std::tr1::array<asio::const_buffer, 2ul>, asio::detail::transfer_all_t, 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) (write.hpp:180)
 
==8444==    by 0xB0FF981: async_write<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > (write.hpp:623)
 
==8444==    by 0xB0FF981: gcomm::AsioTcpSocket::write_one(std::tr1::array<asio::const_buffer, 2ul> const&) (asio_tcp.cpp:703)
 
==8444==    by 0xB119944: operator() (asio_tcp.cpp:431)
 
==8444==    by 0xB119944: asio_handler_invoke<gcomm::AsioPostForSendHandler> (handler_invoke_hook.hpp:68)
 
==8444==    by 0xB119944: invoke<gcomm::AsioPostForSendHandler, gcomm::AsioPostForSendHandler> (handler_invoke_helpers.hpp:37)
 
==8444==    by 0xB119944: asio::detail::completion_handler<gcomm::AsioPostForSendHandler>::do_complete(asio::detail::task_io_service*, asio::detail::task_io_service_operation*, asio::error_code const&, unsigned long) (completion_handler.hpp:67)
 
==8444==    by 0xB123D47: complete (task_io_service_operation.hpp:37)
 
==8444==    by 0xB123D47: do_run_one (task_io_service.ipp:371)
 
==8444==    by 0xB123D47: run (task_io_service.ipp:148)
 
==8444==    by 0xB123D47: run (io_service.ipp:58)
 
==8444==    by 0xB123D47: gcomm::AsioProtonet::event_loop(gu::datetime::Period const&) (asio_protonet.cpp:116)
 
==8444==    by 0xB13AB13: GCommConn::run() (gcs_gcomm.cpp:433)
 
==8444==    by 0xB1434A8: GCommConn::run_fn(void*) (gcs_gcomm.cpp:174)
 
==8444==    by 0x69666DA: start_thread (pthread_create.c:463)
 
==8444==    by 0x762971E: clone (clone.S:95)
 
==8444==  Address 0x16407f5a is 106 bytes inside a block of size 134 alloc'd
 
==8444==    at 0x4DA517F: operator new(unsigned long) (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
 
==8444==    by 0xB13A8AC: allocate (new_allocator.h:111)
 
==8444==    by 0xB13A8AC: allocate (alloc_traits.h:130)
 
==8444==    by 0xB13A8AC: _M_allocate (stl_vector.h:172)
 
==8444==    by 0xB13A8AC: _M_range_initialize<unsigned char const*> (stl_vector.h:1323)
 
==8444==    by 0xB13A8AC: _M_initialize_dispatch<unsigned char const*> (stl_vector.h:1299)
 
==8444==    by 0xB13A8AC: vector<unsigned char const*> (stl_vector.h:423)
 
==8444==    by 0xB13A8AC: Buffer<unsigned char const*> (gu_buffer.hpp:36)
 
==8444==    by 0xB13A8AC: gcomm_send(gcs_backend*, void const*, unsigned long, gcs_msg_type) (gcs_gcomm.cpp:513)
 
==8444==    by 0xB12E735: core_msg_send (gcs_core.cpp:257)
 
==8444==    by 0xB12E735: core_msg_send_retry (gcs_core.cpp:294)
 
==8444==    by 0xB12E735: core_handle_uuid_msg (gcs_core.cpp:872)
 
==8444==    by 0xB12E735: gcs_core_recv(gcs_core*, gcs_act_rcvd*, long long) (gcs_core.cpp:1123)
 
==8444==    by 0xB1346B1: gcs_recv_thread(void*) (gcs.cpp:1277)
 
==8444==    by 0x69666DA: start_thread (pthread_create.c:463)
 
==8444==    by 0x762971E: clone (clone.S:95)
 
^ Found warnings in /home/anel/mariadb/builds/10.2/mysql-test/var/log/mysqld.2.err
 
ok
 
]]>
 
			</failure>
 
		</testcase>
 
	</testsuite>
 
	<testsuite disabled="" errors="" failures="" hostname="anel" id="1" name="valgrind" package="" skipped="" tests="1" time="0.000" timestamp="2021-02-02T10:09:10Z">
 
		<testcase assertions="" classname="valgrind" name="valgrind_report" status="MTR_RES_PASSED" time="0.000" />
 
	</testsuite>
 
</testsuites>

Comment by Timofey Turenko [ 2021-02-02 ]

first results:

mtr-extra-test:

 
 
jp.jp_alter_ucs2 'innodb'                w6 [ pass ]   7261
 
***Warnings generated in error logs during shutdown after running tests: funcs_1.is_table_constraints_mysql_embedded jp.jp_alter_ucs2
 
==32007== 208 bytes in 1 blocks are still reachable in loss record 2 of 5
 
==32007==    at 0x483DD99: calloc (in /usr/lib/x86_64-linux-gnu/valgrind/vgpreload_memcheck-amd64-linux.so)
 
==32007==    by 0xC9E6AE: my_thread_init (my_thr_init.c:295)
 
==32007==    by 0xC9E6AE: my_thread_init (my_thr_init.c:270)
 
==32007==    by 0x59096C: kill_server_thread (mysqld.cc:2046)
 
==32007==    by 0xC64286: pfs_spawn_thread (pfs.cc:1869)
 
==32007==    by 0x4D89608: start_thread (pthread_create.c:477)
 
==32007==    by 0x5210292: clone (clone.S:95)
 
stress.ddl_memory                        w8 [ pass ]  32479

nothing in the XML https://mdbe-ci-repo.mariadb.net/bb-logs/MariaDBServerCommunity/bb-10.2-anel-MDEV-24135-feb02-01/ubuntu/focal/mtr-extra-test/mtr.xml

waiting for all other tests

Comment by Anel Husakovic [ 2021-02-02 ]

MDEV is stated like this:
If MTR is started with Valgrind and test fails due to Valgrind warnings.
Also we have been working on failed tests.
The example above is for test that is passed.
Please indicate exact conditions which should be satisfied in the xml-report.
Why is important to have warnings catched if the test is successful, do we want that?
If you want to support this case also we need to know in which format warning should be written to XML file (same as in case of failure [ !CDATA ... ] )?

Comment by Timofey Turenko [ 2021-02-02 ]

anel it is not clear for me why test is passed: Valgrind generates warnings

another case:

Console log https://mdbe-ci-repo.mariadb.net/bb-logs/MariaDBServerCommunity/bb-10.2-anel-MDEV-24135-feb02-01/ubuntu/focal/mtr-normal-test/mtr.log :

innodb.row_lock 'innodb'                 w3 [ fail ]  Found warnings/errors in server log file!
 
        Test ended at 2021-02-02 22:58:26
 
line
 
==181243== Thread 29:
 
==181243== Conditional jump or move depends on uninitialised value(s)
 
==181243==    at 0x672787: setup_order(THD*, Bounds_checked_array<Item*>, TABLE_LIST*, List<Item>&, List<Item>&, st_order*, bool) (sql_select.cc:22712)
 
==181243==    by 0x6D121E: mysql_prepare_update(THD*, TABLE_LIST*, Item**, unsigned int, st_order*) (sql_update.cc:1114)
 
==181243==    by 0x6D1609: mysql_update(THD*, TABLE_LIST*, List<Item>&, List<Item>&, Item*, unsigned int, st_order*, unsigned long long, enum_duplicates, bool, unsigned long long*, unsigned long long*) (sql_update.cc:345)
 
==181243==    by 0x62AB68: mysql_execute_command(THD*) (sql_parse.cc:4033)
 
==181243==    by 0x6312D0: mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) (sql_parse.cc:7763)
 
==181243==    by 0x6344E2: dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) (sql_parse.cc:1827)
 
==181243==    by 0x6356FF: do_command(THD*) (sql_parse.cc:1381)
 
==181243==    by 0x709E53: do_handle_one_connection(CONNECT*) (sql_connect.cc:1336)
 
==181243==    by 0x709FE5: handle_one_connection (sql_connect.cc:1241)
 
==181243==    by 0xC64286: pfs_spawn_thread (pfs.cc:1869)
 
==181243==    by 0x4D89608: start_thread (pthread_create.c:477)
 
==181243==    by 0x5210292: clone (clone.S:95)
 
^ Found warnings in /var/tmp/mtr/3/log/mysqld.1.err
 
ok
 
 
 
 - skipping '/var/tmp/mtr/3/log/innodb.row_lock-innodb/'

XML https://mdbe-ci-repo.mariadb.net/bb-logs/MariaDBServerCommunity/bb-10.2-anel-MDEV-24135-feb02-01/ubuntu/focal/mtr-normal-test/mtr.xml :

<testcase assertions="" classname="innodb" name="row_lock" status="MTR_RES_FAILED" time="0.000">
 
<failure message="" type="MTR_RES_FAILED">
 
<![CDATA[ INSERT INTO t2 VALUES (1,1), (2,2); CREATE TABLE t3 (e INT) ENGINE=InnoDB; CREATE TABLE t4 ENGINE=InnoDB AS SELECT * FROM t2; connect con11,localhost,root,,test; BEGIN; UPDATE t1 SET a = 0 WHERE a = ( SELECT e FROM t3 ); connect con12,localhost,root,,test; UPDATE t4 SET d = 1 WHERE d in ( SELECT a FROM t1 ) ORDER BY c LIMIT 6; connection con11; UPDATE t4 SET d = 9; connection con12; ERROR 40001: Deadlock found when trying to get lock; try restarting transaction connection con11; commit; connection default; disconnect con12; disconnect con11; drop table t1,t2,t3,t4; call mtr.add_suppression("Deadlock found when trying to get lock; try restarting transaction"); call mtr.add_suppression("Sort aborted.*"); ]]>
 
</failure>
 
</testcase>

even more: in the log there is the second attempt to run the test: innodb.row_lock 'innodb' w3 [ retry-fail ] Found warnings/errors in server log file!

Comment by Anel Husakovic [ 2021-02-03 ]

Hi tturenko the reason why it repeat is because {{--repeat }} option you have.

$ ./mysql-test/mtr --help|grep retry
 
  retry=N               Retry tests that fail up to N times (default 1).
 
                        failures before stopping, set with the --retry-failure

I couldn't reproduce innodb.row_format

==============================================================================
 
 
 
TEST                                      RESULT   TIME (ms) or COMMENT
 
--------------------------------------------------------------------------
 
 
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
 
innodb.row_lock 'innodb'                 [ pass ]   2297
 
valgrind_report                          [ pass ]       
--------------------------------------------------------------------------

Last thing I could think of is to always append the warnings and the comment to the xml report to the failed tests only- patch 3757b9ffb5e0ff8
Example galera- compare with result above:

$ cat mysql-test/galera_new 
<?xml version="1.0" encoding="UTF-8"?>
 
<testsuites disabled="0" errors="" failures="1" name="" tests="2" time="0.000">
 
	<testsuite disabled="" errors="" failures="1" hostname="anel" id="0" name="galera" package="" skipped="" tests="1" time="0.000" timestamp="2021-02-03T06:21:24Z">
 
		<testcase assertions="" classname="galera" name="galera_log_output_csv" status="MTR_RES_FAILED" time="0.000">
 
			<failure message="" type="MTR_RES_FAILED">
 
<![CDATA[CURRENT_TEST: galera.galera_log_output_csvline
 
==14204== Thread 4:
 
==14204== Syscall param sendmsg(msg.msg_iov[0]) points to uninitialised byte(s)
 
==14204==    at 0x69716F7: sendmsg (sendmsg.c:28)
 
==14204==    by 0xB104DE0: send (socket_ops.ipp:1169)
 
==14204==    by 0xB104DE0: non_blocking_send (socket_ops.ipp:1243)
 
==14204==    by 0xB104DE0: asio::detail::reactive_socket_send_op_base<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2ul> > >::do_perform(asio::detail::reactor_op*) (reactive_socket_send_op.hpp:55)
 
==14204==    by 0xB105EE0: perform (reactor_op.hpp:39)
 
==14204==    by 0xB105EE0: asio::detail::epoll_reactor::start_op(int, int, asio::detail::epoll_reactor::descriptor_state*&, asio::detail::reactor_op*, bool, bool) (epoll_reactor.ipp:230)
 
==14204==    by 0xB10694A: asio::detail::reactive_socket_service_base::start_op(asio::detail::reactive_socket_service_base::base_implementation_type&, int, asio::detail::reactor_op*, bool, bool, bool) (reactive_socket_service_base.ipp:212)
 
==14204==    by 0xB1110F3: async_send<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (reactive_socket_service_base.hpp:215)
 
==14204==    by 0xB1110F3: async_send<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (stream_socket_service.hpp:329)
 
==14204==    by 0xB1110F3: async_write_some<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (basic_stream_socket.hpp:731)
 
==14204==    by 0xB1110F3: asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, std::tr1::array<asio::const_buffer, 2ul>, asio::detail::transfer_all_t, 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) (write.hpp:180)
 
==14204==    by 0xB0FF981: async_write<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > (write.hpp:623)
 
==14204==    by 0xB0FF981: gcomm::AsioTcpSocket::write_one(std::tr1::array<asio::const_buffer, 2ul> const&) (asio_tcp.cpp:703)
 
==14204==    by 0xB119944: operator() (asio_tcp.cpp:431)
 
==14204==    by 0xB119944: asio_handler_invoke<gcomm::AsioPostForSendHandler> (handler_invoke_hook.hpp:68)
 
==14204==    by 0xB119944: invoke<gcomm::AsioPostForSendHandler, gcomm::AsioPostForSendHandler> (handler_invoke_helpers.hpp:37)
 
==14204==    by 0xB119944: asio::detail::completion_handler<gcomm::AsioPostForSendHandler>::do_complete(asio::detail::task_io_service*, asio::detail::task_io_service_operation*, asio::error_code const&, unsigned long) (completion_handler.hpp:67)
 
==14204==    by 0xB123D47: complete (task_io_service_operation.hpp:37)
 
==14204==    by 0xB123D47: do_run_one (task_io_service.ipp:371)
 
==14204==    by 0xB123D47: run (task_io_service.ipp:148)
 
==14204==    by 0xB123D47: run (io_service.ipp:58)
 
==14204==    by 0xB123D47: gcomm::AsioProtonet::event_loop(gu::datetime::Period const&) (asio_protonet.cpp:116)
 
==14204==    by 0xB13AB13: GCommConn::run() (gcs_gcomm.cpp:433)
 
==14204==    by 0xB1434A8: GCommConn::run_fn(void*) (gcs_gcomm.cpp:174)
 
==14204==    by 0x69666DA: start_thread (pthread_create.c:463)
 
==14204==    by 0x762971E: clone (clone.S:95)
 
==14204==  Address 0x1221352c is 204 bytes inside a block of size 480 alloc'd
 
==14204==    at 0x4DA517F: operator new(unsigned long) (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
 
==14204==    by 0xB10D582: allocate (new_allocator.h:111)
 
==14204==    by 0xB10D582: allocate (alloc_traits.h:130)
 
==14204==    by 0xB10D582: _M_allocate_node (stl_deque.h:602)
 
==14204==    by 0xB10D582: std::deque<gcomm::Datagram, std::allocator<gcomm::Datagram> >::_M_push_back_aux(gcomm::Datagram const&) (deque.tcc:487)
 
==14204==    by 0xB0FAF6A: push_back (stl_deque.h:1552)
 
==14204==    by 0xB0FAF6A: push_back (fair_send_queue.hpp:41)
 
==14204==    by 0xB0FAF6A: gcomm::AsioTcpSocket::send(int, gcomm::Datagram const&) (asio_tcp.cpp:469)
 
==14204==    by 0xB0A9DF3: gcomm::GMCast::send(gcomm::GMCast::RelayEntry const&, int, gcomm::Datagram&) (gmcast.cpp:1314)
 
==14204==    by 0xB0AB8AA: gcomm::GMCast::handle_down(gcomm::Datagram&, gcomm::ProtoDownMeta const&) (gmcast.cpp:1655)
 
==14204==    by 0xB0A0A03: gcomm::Protolay::send_down(gcomm::Datagram&, gcomm::ProtoDownMeta const&) (protolay.hpp:299)
 
==14204==    by 0xB086361: gcomm::evs::Proto::send_user(gcomm::Datagram&, unsigned char, gcomm::Order, long, long, unsigned long) (evs_proto.cpp:1550)
 
==14204==    by 0xB087CFB: gcomm::evs::Proto::handle_down(gcomm::Datagram&, gcomm::ProtoDownMeta const&) (evs_proto.cpp:2658)
 
==14204==    by 0xB0A0A03: gcomm::Protolay::send_down(gcomm::Datagram&, gcomm::ProtoDownMeta const&) (protolay.hpp:299)
 
==14204==    by 0xB0DAA26: gcomm::pc::Proto::handle_down(gcomm::Datagram&, gcomm::ProtoDownMeta const&) (pc_proto.cpp:1605)
 
==14204==    by 0xB0A0A03: gcomm::Protolay::send_down(gcomm::Datagram&, gcomm::ProtoDownMeta const&) (protolay.hpp:299)
 
==14204==    by 0xB13A754: send_down (protolay.hpp:299)
 
==14204==    by 0xB13A754: gcomm_send(gcs_backend*, void const*, unsigned long, gcs_msg_type) (gcs_gcomm.cpp:541)
 
==14204==    by 0xB12EFB4: core_handle_comp_msg (gcs_core.cpp:768)
 
==14204==    by 0xB12EFB4: gcs_core_recv(gcs_core*, gcs_act_rcvd*, long long) (gcs_core.cpp:1118)
 
==14204==    by 0xB1346B1: gcs_recv_thread(void*) (gcs.cpp:1277)
 
==14204==    by 0x69666DA: start_thread (pthread_create.c:463)
 
==14204==    by 0x762971E: clone (clone.S:95)
 
==14204== Syscall param sendmsg(msg.msg_iov[1]) points to uninitialised byte(s)
 
==14204==    at 0x69716F7: sendmsg (sendmsg.c:28)
 
==14204==    by 0xB104DE0: send (socket_ops.ipp:1169)
 
==14204==    by 0xB104DE0: non_blocking_send (socket_ops.ipp:1243)
 
==14204==    by 0xB104DE0: asio::detail::reactive_socket_send_op_base<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2ul> > >::do_perform(asio::detail::reactor_op*) (reactive_socket_send_op.hpp:55)
 
==14204==    by 0xB105EE0: perform (reactor_op.hpp:39)
 
==14204==    by 0xB105EE0: asio::detail::epoll_reactor::start_op(int, int, asio::detail::epoll_reactor::descriptor_state*&, asio::detail::reactor_op*, bool, bool) (epoll_reactor.ipp:230)
 
==14204==    by 0xB10694A: asio::detail::reactive_socket_service_base::start_op(asio::detail::reactive_socket_service_base::base_implementation_type&, int, asio::detail::reactor_op*, bool, bool, bool) (reactive_socket_service_base.ipp:212)
 
==14204==    by 0xB1110F3: async_send<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (reactive_socket_service_base.hpp:215)
 
==14204==    by 0xB1110F3: async_send<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (stream_socket_service.hpp:329)
 
==14204==    by 0xB1110F3: async_write_some<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (basic_stream_socket.hpp:731)
 
==14204==    by 0xB1110F3: asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, std::tr1::array<asio::const_buffer, 2ul>, asio::detail::transfer_all_t, 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) (write.hpp:180)
 
==14204==    by 0xB0FF981: async_write<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > (write.hpp:623)
 
==14204==    by 0xB0FF981: gcomm::AsioTcpSocket::write_one(std::tr1::array<asio::const_buffer, 2ul> const&) (asio_tcp.cpp:703)
 
==14204==    by 0xB119944: operator() (asio_tcp.cpp:431)
 
==14204==    by 0xB119944: asio_handler_invoke<gcomm::AsioPostForSendHandler> (handler_invoke_hook.hpp:68)
 
==14204==    by 0xB119944: invoke<gcomm::AsioPostForSendHandler, gcomm::AsioPostForSendHandler> (handler_invoke_helpers.hpp:37)
 
==14204==    by 0xB119944: asio::detail::completion_handler<gcomm::AsioPostForSendHandler>::do_complete(asio::detail::task_io_service*, asio::detail::task_io_service_operation*, asio::error_code const&, unsigned long) (completion_handler.hpp:67)
 
==14204==    by 0xB123D47: complete (task_io_service_operation.hpp:37)
 
==14204==    by 0xB123D47: do_run_one (task_io_service.ipp:371)
 
==14204==    by 0xB123D47: run (task_io_service.ipp:148)
 
==14204==    by 0xB123D47: run (io_service.ipp:58)
 
==14204==    by 0xB123D47: gcomm::AsioProtonet::event_loop(gu::datetime::Period const&) (asio_protonet.cpp:116)
 
==14204==    by 0xB13AB13: GCommConn::run() (gcs_gcomm.cpp:433)
 
==14204==    by 0xB1434A8: GCommConn::run_fn(void*) (gcs_gcomm.cpp:174)
 
==14204==    by 0x69666DA: start_thread (pthread_create.c:463)
 
==14204==    by 0x762971E: clone (clone.S:95)
 
==14204==  Address 0x12213e8a is 106 bytes inside a block of size 134 alloc'd
 
==14204==    at 0x4DA517F: operator new(unsigned long) (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
 
==14204==    by 0xB13A8AC: allocate (new_allocator.h:111)
 
==14204==    by 0xB13A8AC: allocate (alloc_traits.h:130)
 
==14204==    by 0xB13A8AC: _M_allocate (stl_vector.h:172)
 
==14204==    by 0xB13A8AC: _M_range_initialize<unsigned char const*> (stl_vector.h:1323)
 
==14204==    by 0xB13A8AC: _M_initialize_dispatch<unsigned char const*> (stl_vector.h:1299)
 
==14204==    by 0xB13A8AC: vector<unsigned char const*> (stl_vector.h:423)
 
==14204==    by 0xB13A8AC: Buffer<unsigned char const*> (gu_buffer.hpp:36)
 
==14204==    by 0xB13A8AC: gcomm_send(gcs_backend*, void const*, unsigned long, gcs_msg_type) (gcs_gcomm.cpp:513)
 
==14204==    by 0xB12E735: core_msg_send (gcs_core.cpp:257)
 
==14204==    by 0xB12E735: core_msg_send_retry (gcs_core.cpp:294)
 
==14204==    by 0xB12E735: core_handle_uuid_msg (gcs_core.cpp:872)
 
==14204==    by 0xB12E735: gcs_core_recv(gcs_core*, gcs_act_rcvd*, long long) (gcs_core.cpp:1123)
 
==14204==    by 0xB1346B1: gcs_recv_thread(void*) (gcs.cpp:1277)
 
==14204==    by 0x69666DA: start_thread (pthread_create.c:463)
 
==14204==    by 0x762971E: clone (clone.S:95)
 
^ Found warnings in /home/anel/mariadb/builds/10.2/mysql-test/var/log/mysqld.1.err
 
ok
 
line
 
==14241== Thread 4:
 
==14241== Syscall param sendmsg(msg.msg_iov[0]) points to uninitialised byte(s)
 
==14241==    at 0x69716F7: sendmsg (sendmsg.c:28)
 
==14241==    by 0xB104DE0: send (socket_ops.ipp:1169)
 
==14241==    by 0xB104DE0: non_blocking_send (socket_ops.ipp:1243)
 
==14241==    by 0xB104DE0: asio::detail::reactive_socket_send_op_base<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2ul> > >::do_perform(asio::detail::reactor_op*) (reactive_socket_send_op.hpp:55)
 
==14241==    by 0xB105EE0: perform (reactor_op.hpp:39)
 
==14241==    by 0xB105EE0: asio::detail::epoll_reactor::start_op(int, int, asio::detail::epoll_reactor::descriptor_state*&, asio::detail::reactor_op*, bool, bool) (epoll_reactor.ipp:230)
 
==14241==    by 0xB10694A: asio::detail::reactive_socket_service_base::start_op(asio::detail::reactive_socket_service_base::base_implementation_type&, int, asio::detail::reactor_op*, bool, bool, bool) (reactive_socket_service_base.ipp:212)
 
==14241==    by 0xB1110F3: async_send<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (reactive_socket_service_base.hpp:215)
 
==14241==    by 0xB1110F3: async_send<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (stream_socket_service.hpp:329)
 
==14241==    by 0xB1110F3: async_write_some<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (basic_stream_socket.hpp:731)
 
==14241==    by 0xB1110F3: asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, std::tr1::array<asio::const_buffer, 2ul>, asio::detail::transfer_all_t, 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) (write.hpp:180)
 
==14241==    by 0xB0FF981: async_write<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > (write.hpp:623)
 
==14241==    by 0xB0FF981: gcomm::AsioTcpSocket::write_one(std::tr1::array<asio::const_buffer, 2ul> const&) (asio_tcp.cpp:703)
 
==14241==    by 0xB119944: operator() (asio_tcp.cpp:431)
 
==14241==    by 0xB119944: asio_handler_invoke<gcomm::AsioPostForSendHandler> (handler_invoke_hook.hpp:68)
 
==14241==    by 0xB119944: invoke<gcomm::AsioPostForSendHandler, gcomm::AsioPostForSendHandler> (handler_invoke_helpers.hpp:37)
 
==14241==    by 0xB119944: asio::detail::completion_handler<gcomm::AsioPostForSendHandler>::do_complete(asio::detail::task_io_service*, asio::detail::task_io_service_operation*, asio::error_code const&, unsigned long) (completion_handler.hpp:67)
 
==14241==    by 0xB123D47: complete (task_io_service_operation.hpp:37)
 
==14241==    by 0xB123D47: do_run_one (task_io_service.ipp:371)
 
==14241==    by 0xB123D47: run (task_io_service.ipp:148)
 
==14241==    by 0xB123D47: run (io_service.ipp:58)
 
==14241==    by 0xB123D47: gcomm::AsioProtonet::event_loop(gu::datetime::Period const&) (asio_protonet.cpp:116)
 
==14241==    by 0xB13AB13: GCommConn::run() (gcs_gcomm.cpp:433)
 
==14241==    by 0xB1434A8: GCommConn::run_fn(void*) (gcs_gcomm.cpp:174)
 
==14241==    by 0x69666DA: start_thread (pthread_create.c:463)
 
==14241==    by 0x762971E: clone (clone.S:95)
 
==14241==  Address 0x163c284c is 204 bytes inside a block of size 480 alloc'd
 
==14241==    at 0x4DA517F: operator new(unsigned long) (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
 
==14241==    by 0xB10D582: allocate (new_allocator.h:111)
 
==14241==    by 0xB10D582: allocate (alloc_traits.h:130)
 
==14241==    by 0xB10D582: _M_allocate_node (stl_deque.h:602)
 
==14241==    by 0xB10D582: std::deque<gcomm::Datagram, std::allocator<gcomm::Datagram> >::_M_push_back_aux(gcomm::Datagram const&) (deque.tcc:487)
 
==14241==    by 0xB0FAF6A: push_back (stl_deque.h:1552)
 
==14241==    by 0xB0FAF6A: push_back (fair_send_queue.hpp:41)
 
==14241==    by 0xB0FAF6A: gcomm::AsioTcpSocket::send(int, gcomm::Datagram const&) (asio_tcp.cpp:469)
 
==14241==    by 0xB0A9DF3: gcomm::GMCast::send(gcomm::GMCast::RelayEntry const&, int, gcomm::Datagram&) (gmcast.cpp:1314)
 
==14241==    by 0xB0AB8AA: gcomm::GMCast::handle_down(gcomm::Datagram&, gcomm::ProtoDownMeta const&) (gmcast.cpp:1655)
 
==14241==    by 0xB0A0A03: gcomm::Protolay::send_down(gcomm::Datagram&, gcomm::ProtoDownMeta const&) (protolay.hpp:299)
 
==14241==    by 0xB086361: gcomm::evs::Proto::send_user(gcomm::Datagram&, unsigned char, gcomm::Order, long, long, unsigned long) (evs_proto.cpp:1550)
 
==14241==    by 0xB0877CD: gcomm::evs::Proto::complete_user(long) (evs_proto.cpp:1660)
 
==14241==    by 0xB09A7D4: gcomm::evs::Proto::handle_user(gcomm::evs::UserMessage const&, std::_Rb_tree_iterator<std::pair<gcomm::UUID const, gcomm::evs::Node> >, gcomm::Datagram const&) (evs_proto.cpp:3715)
 
==14241==    by 0xB09CFA6: gcomm::evs::Proto::handle_msg(gcomm::evs::Message const&, gcomm::Datagram const&, bool) (evs_proto.cpp:2440)
 
==14241==    by 0xB09DCE0: gcomm::evs::Proto::handle_up(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (evs_proto.cpp:2543)
 
==14241==    by 0xB0A06A5: gcomm::Protolay::send_up(gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (protolay.hpp:281)
 
==14241==    by 0xB0B88E2: gcomm::GMCast::handle_up(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (gmcast.cpp:1491)
 
==14241==    by 0xB0EAF52: gcomm::Protostack::dispatch(void const*, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (protostack.cpp:63)
 
==14241==    by 0xB1219EC: gcomm::AsioProtonet::dispatch(void const* const&, gcomm::Datagram const&, gcomm::ProtoUpMeta const&) (asio_protonet.cpp:127)
 
==14241==    by 0xB0FEC7E: gcomm::AsioTcpSocket::read_handler(asio::error_code const&, unsigned long) (asio_tcp.cpp:548)
 
==14241== Syscall param sendmsg(msg.msg_iov[1]) points to uninitialised byte(s)
 
==14241==    at 0x69716F7: sendmsg (sendmsg.c:28)
 
==14241==    by 0xB104DE0: send (socket_ops.ipp:1169)
 
==14241==    by 0xB104DE0: non_blocking_send (socket_ops.ipp:1243)
 
==14241==    by 0xB104DE0: asio::detail::reactive_socket_send_op_base<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2ul> > >::do_perform(asio::detail::reactor_op*) (reactive_socket_send_op.hpp:55)
 
==14241==    by 0xB105EE0: perform (reactor_op.hpp:39)
 
==14241==    by 0xB105EE0: asio::detail::epoll_reactor::start_op(int, int, asio::detail::epoll_reactor::descriptor_state*&, asio::detail::reactor_op*, bool, bool) (epoll_reactor.ipp:230)
 
==14241==    by 0xB10694A: asio::detail::reactive_socket_service_base::start_op(asio::detail::reactive_socket_service_base::base_implementation_type&, int, asio::detail::reactor_op*, bool, bool, bool) (reactive_socket_service_base.ipp:212)
 
==14241==    by 0xB1110F3: async_send<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (reactive_socket_service_base.hpp:215)
 
==14241==    by 0xB1110F3: async_send<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (stream_socket_service.hpp:329)
 
==14241==    by 0xB1110F3: async_write_some<asio::detail::consuming_buffers<asio::const_buffer, std::tr1::array<asio::const_buffer, 2> >, asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, asio::detail::transfer_all_t, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > > (basic_stream_socket.hpp:731)
 
==14241==    by 0xB1110F3: asio::detail::write_op<asio::basic_stream_socket<asio::ip::tcp, asio::stream_socket_service<asio::ip::tcp> >, std::tr1::array<asio::const_buffer, 2ul>, asio::detail::transfer_all_t, 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) (write.hpp:180)
 
==14241==    by 0xB0FF981: async_write<asio::basic_stream_socket<asio::ip::tcp>, std::tr1::array<asio::const_buffer, 2>, boost::_bi::bind_t<void, boost::_mfi::mf2<void, gcomm::AsioTcpSocket, const asio::error_code&, long unsigned int>, boost::_bi::list3<boost::_bi::value<boost::shared_ptr<gcomm::AsioTcpSocket> >, boost::arg<1> (*)(), boost::arg<2> (*)()> > > (write.hpp:623)
 
==14241==    by 0xB0FF981: gcomm::AsioTcpSocket::write_one(std::tr1::array<asio::const_buffer, 2ul> const&) (asio_tcp.cpp:703)
 
==14241==    by 0xB119944: operator() (asio_tcp.cpp:431)
 
==14241==    by 0xB119944: asio_handler_invoke<gcomm::AsioPostForSendHandler> (handler_invoke_hook.hpp:68)
 
==14241==    by 0xB119944: invoke<gcomm::AsioPostForSendHandler, gcomm::AsioPostForSendHandler> (handler_invoke_helpers.hpp:37)
 
==14241==    by 0xB119944: asio::detail::completion_handler<gcomm::AsioPostForSendHandler>::do_complete(asio::detail::task_io_service*, asio::detail::task_io_service_operation*, asio::error_code const&, unsigned long) (completion_handler.hpp:67)
 
==14241==    by 0xB123D47: complete (task_io_service_operation.hpp:37)
 
==14241==    by 0xB123D47: do_run_one (task_io_service.ipp:371)
 
==14241==    by 0xB123D47: run (task_io_service.ipp:148)
 
==14241==    by 0xB123D47: run (io_service.ipp:58)
 
==14241==    by 0xB123D47: gcomm::AsioProtonet::event_loop(gu::datetime::Period const&) (asio_protonet.cpp:116)
 
==14241==    by 0xB13AB13: GCommConn::run() (gcs_gcomm.cpp:433)
 
==14241==    by 0xB1434A8: GCommConn::run_fn(void*) (gcs_gcomm.cpp:174)
 
==14241==    by 0x69666DA: start_thread (pthread_create.c:463)
 
==14241==    by 0x762971E: clone (clone.S:95)
 
==14241==  Address 0x163e750a is 106 bytes inside a block of size 134 alloc'd
 
==14241==    at 0x4DA517F: operator new(unsigned long) (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
 
==14241==    by 0xB13A8AC: allocate (new_allocator.h:111)
 
==14241==    by 0xB13A8AC: allocate (alloc_traits.h:130)
 
==14241==    by 0xB13A8AC: _M_allocate (stl_vector.h:172)
 
==14241==    by 0xB13A8AC: _M_range_initialize<unsigned char const*> (stl_vector.h:1323)
 
==14241==    by 0xB13A8AC: _M_initialize_dispatch<unsigned char const*> (stl_vector.h:1299)
 
==14241==    by 0xB13A8AC: vector<unsigned char const*> (stl_vector.h:423)
 
==14241==    by 0xB13A8AC: Buffer<unsigned char const*> (gu_buffer.hpp:36)
 
==14241==    by 0xB13A8AC: gcomm_send(gcs_backend*, void const*, unsigned long, gcs_msg_type) (gcs_gcomm.cpp:513)
 
==14241==    by 0xB12E735: core_msg_send (gcs_core.cpp:257)
 
==14241==    by 0xB12E735: core_msg_send_retry (gcs_core.cpp:294)
 
==14241==    by 0xB12E735: core_handle_uuid_msg (gcs_core.cpp:872)
 
==14241==    by 0xB12E735: gcs_core_recv(gcs_core*, gcs_act_rcvd*, long long) (gcs_core.cpp:1123)
 
==14241==    by 0xB1346B1: gcs_recv_thread(void*) (gcs.cpp:1277)
 
==14241==    by 0x69666DA: start_thread (pthread_create.c:463)
 
==14241==    by 0x762971E: clone (clone.S:95)
 
^ Found warnings in /home/anel/mariadb/builds/10.2/mysql-test/var/log/mysqld.2.err
 
ok
 
 
 
mysqltest failed but provided no output
 
The result from queries just before the failure was:
 
< snip >
 
SELECT COUNT(*) > 0 FROM mysql.general_log;
 
COUNT(*) > 0
 
1
 
SELECT 1 = 1 FROM t1;
 
1 = 1
 
1
 
SELECT COUNT(*) = 1 FROM mysql.slow_log WHERE sql_text = 'SELECT 1 = 1 FROM t1';
 
COUNT(*) = 1
 
1
 
connection node_2;
 
SELECT 2 = 2 FROM t1;
 
2 = 2
 
1
 
SELECT COUNT(*) = 1 FROM mysql.slow_log WHERE sql_text = 'SELECT 2 = 2 FROM t1';
 
COUNT(*) = 1
 
1
 
connection node_1;
 
DROP TABLE t1;
 
truncate table mysql.slow_log;
 
truncate table mysql.general_log;
 
 
 
]]>
 
			</failure>
 
		</testcase>
 
	</testsuite>
 
	<testsuite disabled="" errors="" failures="" hostname="anel" id="1" name="valgrind" package="" skipped="" tests="1" time="0.000" timestamp="2021-02-03T06:21:24Z">
 
		<testcase assertions="" classname="valgrind" name="valgrind_report" status="MTR_RES_PASSED" time="0.000" />
 
	</testsuite>
 
</testsuites>

Comment by Timofey Turenko [ 2021-02-03 ]

Roel The main idea of XML is to have DB of failed test cases. XMLs can be processed by huge amount of standard tools like Jenkins, different JUnit tools as well as our own "Failure DB viewer" https://server-test.mariadb.net/ which allows to see whole history of every test case failure over time, different distributions, different MariaDB version. e.g answer for the question "when did'innodb.row_lock test case start to fail in 10.5 ES and when in 10.3 CS"

Comment by Dmitriy Karpovskiy (Inactive) [ 2021-02-03 ]

Solving the problem with non-printing warnings in XML. It is also necessary to additionally save warnings, since there are situations in which the warning variable will not be defined (warnings will be in a different socket).

Comment by Timofey Turenko [ 2021-02-04 ]

my attempt to use code from the latest commit of `bb-10.2-anel-MDEV-24135` branch - 3757b9ffb5e0ff82704d2a30eab08cc7a20e9e53:

https://mdbe-ci-repo.mariadb.net/bb-logs/MariaDBServerCommunity/bb-10.2-anel-MDEV-24135-feb02-01/ubuntu/focal/mtr-normal-test/mtr.log

test case `innodb.innodb_mysql_rbk`:

 
 
innodb.innodb_mysql_rbk 'innodb'         w4 [ fail ]  Found warnings/errors in server log file!
 
        Test ended at 2021-02-02 22:04:34
 
line
 
==140869== Thread 29:
 
==140869== Conditional jump or move depends on uninitialised value(s)
 
==140869==    at 0x672787: setup_order(THD*, Bounds_checked_array<Item*>, TABLE_LIST*, List<Item>&, List<Item>&, st_order*, bool) (sql_select.cc:22712)
 
==140869==    by 0x6D121E: mysql_prepare_update(THD*, TABLE_LIST*, Item**, unsigned int, st_order*) (sql_update.cc:1114)
 
==140869==    by 0x6D1609: mysql_update(THD*, TABLE_LIST*, List<Item>&, List<Item>&, Item*, unsigned int, st_order*, unsigned long long, enum_duplicates, bool, unsigned long long*, unsigned long long*) (sql_update.cc:345)
 
==140869==    by 0x62AB68: mysql_execute_command(THD*) (sql_parse.cc:4033)
 
==140869==    by 0x6312D0: mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) (sql_parse.cc:7763)
 
==140869==    by 0x6344E2: dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) (sql_parse.cc:1827)
 
==140869==    by 0x6356FF: do_command(THD*) (sql_parse.cc:1381)
 
==140869==    by 0x709E53: do_handle_one_connection(CONNECT*) (sql_connect.cc:1336)
 
==140869==    by 0x709FE5: handle_one_connection (sql_connect.cc:1241)
 
==140869==    by 0xC64286: pfs_spawn_thread (pfs.cc:1869)
 
==140869==    by 0x4D89608: start_thread (pthread_create.c:477)
 
==140869==    by 0x5210292: clone (clone.S:95)
 
^ Found warnings in /var/tmp/mtr/4/log/mysqld.1.err

XML: https://mdbe-ci-repo.mariadb.net/bb-logs/MariaDBServerCommunity/bb-10.2-anel-MDEV-24135-feb02-01/ubuntu/focal/mtr-normal-test/mtr.xml

completely unrelated info:

<testcase assertions="" classname="innodb" name="innodb_mysql_rbk" status="MTR_RES_FAILED" time="0.000">
<failure message="" type="MTR_RES_FAILED">
<![CDATA[ connection con2; START TRANSACTION; UPDATE t1 SET b=b+12 WHERE a > 2 ORDER BY a; ERROR HY000: Lock wait timeout exceeded; try restarting transaction ROLLBACK; connection con1; START TRANSACTION; SELECT * FROM t1 WHERE b=3 LIMIT 1 FOR UPDATE; a b 3 3 connection con2; START TRANSACTION; UPDATE t1 SET b=10 WHERE a > 1 ORDER BY a; ERROR HY000: Lock wait timeout exceeded; try restarting transaction SELECT * FROM t1 WHERE b = 10; a b connection default; disconnect con1; disconnect con2; DROP TABLE t1; ]]>
</failure>
</testcase>

in the XML from https://github.com/DmitriyKarpovskiy1/server/commit/beeb3b4b9731adde2510b1b636c2b47f6bb941d9#diff-3b008cd0a0b878ff56de8f6187554a266ecca2140c4e4fc56758dfa1dc2eba6cR971

https://server-test.mariadb.net/?products=MariaDBServerCommunity&show_skipped_results=false&only_last_commits=false&time_interval=-1&test_name=innodb_mysql_rbk&commit_id=&runs_with_additional_tools=true&excluded_target_build_ids=5843&excluded_target_build_ids=5838&excluded_target_build_ids=5817&currentTestResultId=275513150&currentTestCaseId=7026&currentTargetBuildId=5843

<testcase assertions="" classname="innodb" name="innodb_mysql_rbk" status="MTR_RES_FAILED" time="0.000">
 
<failure message="" type="MTR_RES_FAILED">
 
<![CDATA[ connection con2; START TRANSACTION; UPDATE t1 SET b=b+12 WHERE a > 2 ORDER BY a; ERROR HY000: Lock wait timeout exceeded; try restarting transaction ROLLBACK; connection con1; START TRANSACTION; SELECT * FROM t1 WHERE b=3 LIMIT 1 FOR UPDATE; a b 3 3 connection con2; START TRANSACTION; UPDATE t1 SET b=10 WHERE a > 1 ORDER BY a; ERROR HY000: Lock wait timeout exceeded; try restarting transaction SELECT * FROM t1 WHERE b = 10; a b connection default; disconnect con1; disconnect con2; DROP TABLE t1; line ==139296== Thread 29: ==139296== Conditional jump or move depends on uninitialised value(s) ==139296== at 0x672787: setup_order(THD*, Bounds_checked_array<Item*>, TABLE_LIST*, List<Item>&, List<Item>&, st_order*, bool) (sql_select.cc:22712) ==139296== by 0x6D121E: mysql_prepare_update(THD*, TABLE_LIST*, Item**, unsigned int, st_order*) (sql_update.cc:1114) ==139296== by 0x6D1609: mysql_update(THD*, TABLE_LIST*, List<Item>&, List<Item>&, Item*, unsigned int, st_order*, unsigned long long, enum_duplicates, bool, unsigned long long*, unsigned long long*) (sql_update.cc:345) ==139296== by 0x62AB68: mysql_execute_command(THD*) (sql_parse.cc:4033) ==139296== by 0x6312D0: mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) (sql_parse.cc:7763) ==139296== by 0x6344E2: dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) (sql_parse.cc:1827) ==139296== by 0x6356FF: do_command(THD*) (sql_parse.cc:1381) ==139296== by 0x709E53: do_handle_one_connection(CONNECT*) (sql_connect.cc:1336) ==139296== by 0x709FE5: handle_one_connection (sql_connect.cc:1241) ==139296== by 0xC64286: pfs_spawn_thread (pfs.cc:1869) ==139296== by 0x4D89608: start_thread (pthread_create.c:477) ==139296== by 0x5210292: clone (clone.S:95) ^ Found warnings in /var/tmp/mtr/4/log/mysqld.1.err ok ]]>
 
</failure>
 
</testcase>

in both cases I do not understand why do we have these lines:

connection con2;
 
START TRANSACTION;
 
UPDATE t1 SET b=b+12 WHERE a > 2 ORDER BY a;
 
ERROR HY000: Lock wait timeout exceeded; try restarting transaction
 
ROLLBACK;
 
connection con1;
 
START TRANSACTION;
 
SELECT * FROM t1 WHERE b=3 LIMIT 1 FOR UPDATE;
 
a	b
 
3	3
 
connection con2;
 
START TRANSACTION;
 
UPDATE t1 SET b=10 WHERE a > 1 ORDER BY a;
 
ERROR HY000: Lock wait timeout exceeded; try restarting transaction
 
SELECT * FROM t1 WHERE b = 10;
 
a	b
 
connection default;
 
disconnect con1;
 
disconnect con2;
 
DROP TABLE t1;

in the XML!! I do not see it in the console log

https://mdbe-ci-repo.mariadb.net/bb-logs/MariaDBServerCommunity/10.2-print-warnings-in-xml/ubuntu/focal/mtr-normal-test/mtr.log

Comment by Timofey Turenko [ 2021-02-15 ]

anel retested from you branch - I can see Valgrind warnings , but not all:

https://mdbe-ci-repo.mariadb.net/bb-logs/MariaDBServerCommunity/bb-10.2-anel-MDEV-24135-feb13/ubuntu/focal/mtr-psproto-test/mtr.log

test case `101_compatibility` - it has "pass" result 3 times and then failed:

innodb.101_compatibility '4k,innodb'     w2 [ fail ]  Found warnings/errors in server log file!
 
        Test ended at 2021-02-14 13:29:28
 
line
 
==136288== 208 bytes in 1 blocks are still reachable in loss record 2 of 5
 
==136288==    at 0x483DD99: calloc (in /usr/lib/x86_64-linux-gnu/valgrind/vgpreload_memcheck-amd64-linux.so)
 
==136288==    by 0xC9E6AE: my_thread_init (my_thr_init.c:295)
 
==136288==    by 0xC9E6AE: my_thread_init (my_thr_init.c:270)
 
==136288==    by 0x59096C: kill_server_thread (mysqld.cc:2046)
 
==136288==    by 0xC64286: pfs_spawn_thread (pfs.cc:1869)
 
==136288==    by 0x4D89608: start_thread (pthread_create.c:477)
 
==136288==    by 0x5210292: clone (clone.S:95)
 
^ Found warnings in /var/tmp/mtr/2/log/mysqld.1.err
 
ok
 
 
 
 - skipping '/var/tmp/mtr/2/log/innodb.101_compatibility-4k,innodb/'
 
 
 
Retrying test innodb.101_compatibility, attempt(2/3)...

As I understand, test was executed several times with different parameters and failed with `4k,innodb`

Comment by Anel Husakovic [ 2021-02-22 ]

Hi tturenko, sorry I had health problems.
The test 101_compatibility with/without combinations is not deterministic and I cannot repeat it locally.
Please provide some test that you can repeat in your local setup.
To wrap up this MDEV:

  • xml-report as well as mtr statistic in general is done after tests are finished. When tests are finished error logs are stored in var/log/warnings. That's why PR 1753 is not good (regarding the mysql-test-run.pl changes.
  • xml-report doesn't catch warnings. With my patch warnings are obtained from var/log/warnings and that is only needed for this MDEV.
  • Problem with proposed patch (according to the buildbot) is that warnings are not showed in xml-report in case that test is failing and repeated, but I cannot reproduce it locally to see where is the problem :
    mtr command should be: 

    $ ./mtr --mem galera.galera_log_output_csv --valgrind --mem --xml-report=galera2 --retry=3 --retry-failure=3

    However regarding that xml-report should support that, if you look through the code xml-report is catching that with logfile-failed that is occurring in that specific case.

Comment by Timofey Turenko [ 2021-02-25 ]

anel patch is updated. Now it supports retrieval all warnings (including PASS cases with warnings), MTR_RES_RETRY_* statuses and fixes "illegal chars in XML" problem.

Comment by Timofey Turenko [ 2021-03-01 ]

added logs from XML parser

Comment by Timofey Turenko [ 2021-03-23 ]

attaching mtr.log where test `multi_source.info_logs` failed, then it was restarted and retry-pass and restarted ones more with result retry-fail

Comment by Timofey Turenko [ 2021-03-23 ]

one more example: mtr_retry_pass2.log - another example of retry:

spider/bg.direct_aggregate               w4 [ fail ]  timeout after 900 seconds

but then:

 
 
spider/bg.direct_aggregate               w4 [ retry-pass ]    144
 
 
 
Retrying test spider/bg.direct_aggregate, attempt(3/3)...
 
 
 
spider/bg.direct_aggregate               w4 [ retry-pass ]     42

Comment by Timofey Turenko [ 2021-03-26 ]

attached two examples of console and XML - mtr_galera and mtr_big

galera suite has test "wsrep.mdev_7798" which failed and then failed 4 more times. XML shows correct status:
suite was executed with --retry=5 --retry-failure=5

<testcase assertions="" classname="wsrep" name="mdev_7798" status="MTR_RES_FAILED" time="0.000" combinations="">
 
<failure message="" type="MTR_RES_FAILED">
 
<![CDATA[ # # MDEV-7798: mysql.server init script can't stop mysqld when WSREP is # turned off # SELECT @@GLOBAL.WSREP_ON; @@GLOBAL.WSREP_ON 1 SET GLOBAL WSREP_ON= 0; Restart the node. SELECT @@GLOBAL.WSREP_ON; @@GLOBAL.WSREP_ON 1 # End of test. line ==96714==LeakSanitizer has encountered a fatal error. ==96714==HINT: LeakSanitizer does not work under ptrace (strace, gdb, etc) ^ Found warnings in /var/tmp/mtr/log/mysqld.1.err ok ]]>
 
</failure>
 
</testcase>
 
<testcase assertions="" classname="wsrep" name="mdev_7798" status="MTR_RES_RETRY_FAILED" time="0.000" combinations="">
 
<failure message="" type="MTR_RES_RETRY_FAILED">
 
<![CDATA[ # # MDEV-7798: mysql.server init script can't stop mysqld when WSREP is # turned off # SELECT @@GLOBAL.WSREP_ON; @@GLOBAL.WSREP_ON 1 SET GLOBAL WSREP_ON= 0; Restart the node. SELECT @@GLOBAL.WSREP_ON; @@GLOBAL.WSREP_ON 1 # End of test. line ==96778==LeakSanitizer has encountered a fatal error. ==96778==HINT: LeakSanitizer does not work under ptrace (strace, gdb, etc) ^ Found warnings in /var/tmp/mtr/log/mysqld.1.err ok ]]>
 
</failure>
 
</testcase>
 
<testcase assertions="" classname="wsrep" name="mdev_7798" status="MTR_RES_RETRY_FAILED" time="0.000" combinations="">
 
<failure message="" type="MTR_RES_RETRY_FAILED">
 
<![CDATA[ # # MDEV-7798: mysql.server init script can't stop mysqld when WSREP is # turned off # SELECT @@GLOBAL.WSREP_ON; @@GLOBAL.WSREP_ON 1 SET GLOBAL WSREP_ON= 0; Restart the node. SELECT @@GLOBAL.WSREP_ON; @@GLOBAL.WSREP_ON 1 # End of test. line ==96822==LeakSanitizer has encountered a fatal error. ==96822==HINT: LeakSanitizer does not work under ptrace (strace, gdb, etc) ^ Found warnings in /var/tmp/mtr/log/mysqld.1.err ok ]]>
 
</failure>
 
</testcase>
 
<testcase assertions="" classname="wsrep" name="mdev_7798" status="MTR_RES_RETRY_FAILED" time="0.000" combinations="">
 
<failure message="" type="MTR_RES_RETRY_FAILED">
 
<![CDATA[ # # MDEV-7798: mysql.server init script can't stop mysqld when WSREP is # turned off # SELECT @@GLOBAL.WSREP_ON; @@GLOBAL.WSREP_ON 1 SET GLOBAL WSREP_ON= 0; Restart the node. SELECT @@GLOBAL.WSREP_ON; @@GLOBAL.WSREP_ON 1 # End of test. line ==96866==LeakSanitizer has encountered a fatal error. ==96866==HINT: LeakSanitizer does not work under ptrace (strace, gdb, etc) ^ Found warnings in /var/tmp/mtr/log/mysqld.1.err ok ]]>
 
</failure>
 
</testcase>
 
<testcase assertions="" classname="wsrep" name="mdev_7798" status="MTR_RES_RETRY_FAILED" time="0.000" combinations="">
 
<failure message="" type="MTR_RES_RETRY_FAILED">
 
<![CDATA[ # # MDEV-7798: mysql.server init script can't stop mysqld when WSREP is # turned off # SELECT @@GLOBAL.WSREP_ON; @@GLOBAL.WSREP_ON 1 SET GLOBAL WSREP_ON= 0; Restart the node. SELECT @@GLOBAL.WSREP_ON; @@GLOBAL.WSREP_ON 1 # End of test. line ==96910==LeakSanitizer has encountered a fatal error. ==96910==HINT: LeakSanitizer does not work under ptrace (strace, gdb, etc) ^ Found warnings in /var/tmp/mtr/log/mysqld.1.err ok ]]>
 
</failure>
 
</testcase>

another example - MTR big, test case `spider/bg.direct_aggregate`
executed with --retry=3
failed ones and then retry-pass twice:

<testcase assertions="" classname="spider/bg" name="direct_aggregate" status="MTR_RES_FAILED" time="0.000" combinations="">
 
<failure message="" type="MTR_RES_FAILED">
 
<![CDATA[ CURRENT_TEST: spider/bg.direct_aggregate mysqltest got signal 6 read_command_buf (0x631000014808): SELECT M conn->name (0x60300002b068): master_1 Attempting backtrace... stack_bottom = 0x0 thread_stack 0x3c000 /lib/x86_64-linux-gnu/libasan.so.5(+0x6cd30)[0x7f232a551d30] mysys/stacktrace.c:173(my_print_stacktrace)[0x557cc5cb1ced] client/mysqltest.cc:9015(signal_handler)[0x557cc5c08502] sigaction.c:0(__restore_rt)[0x7f232a4d73c0] /lib/x86_64-linux-gnu/libc.so.6(__poll+0x17)[0x7f2329e57ac7] /lib/x86_64-linux-gnu/libasan.so.5(poll+0xaa)[0x7f232a5215ba] pvio/pvio_socket.c:532(pvio_socket_wait_io_or_timeout)[0x557cc5c7fe1d] pvio/pvio_socket.c:318(pvio_socket_read)[0x557cc5c80cf0] libmariadb/ma_pvio.c:255(ma_pvio_read)[0x557cc5c4505d] libmariadb/ma_pvio.c:297(ma_pvio_cache_read)[0x557cc5c4561a] libmariadb/ma_net.c:380(ma_real_read)[0x557cc5c87947] libmariadb/ma_net.c:435(ma_net_read)[0x557cc5c89bef] libmariadb/mariadb_lib.c:200(ma_net_safe_read)[0x557cc5c39c85] libmariadb/mariadb_lib.c:2314(mthd_my_read_query_result)[0x557cc5c4369b] libmariadb/mariadb_lib.c:2371(mysql_read_query_result)[0x557cc5c2e0bd] tests/nonblock-wrappers.h:324(wrap_mysql_read_query_result(st_mysql*))[0x557cc5c09e9d] client/mysqltest.cc:7903(run_query_normal(st_connection*, st_command*, int, char*, int, st_dynamic_string*, st_dynamic_string*))[0x557cc5c2b7d6] client/mysqltest.cc:8686(run_query(st_connection*, st_command*, int))[0x557cc5c2c9fa] client/mysqltest.cc:9511(main)[0x557cc5c04d4c] /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf3)[0x7f2329d690b3] /home/timofey_turenko_mariadb_com/MariaDBEnterprise/bin/mysqltest(_start+0x2e)[0x557cc5c077be] Writing a core file... ]]>
 
</failure>
 
</testcase>
 
<testcase assertions="" classname="spider/bg" name="direct_aggregate" status="MTR_RES_RETRY_PASSED" time="0.206" combinations=""/>
 
<testcase assertions="" classname="spider/bg" name="direct_aggregate" status="MTR_RES_RETRY_PASSED" time="0.096" combinations=""/>

Comment by Timofey Turenko [ 2021-04-06 ]

more examples (after removing MTR_RES_RETRY_* states) - mtr_apr01.log, mtr_apt01.xml
XML looks correct:

<testcase assertions="" classname="wsrep" name="mdev_7798" status="MTR_RES_FAILED" time="0.000" combinations="">
 
<failure message="" type="MTR_RES_FAILED">
 
<![CDATA[ # # MDEV-7798: mysql.server init script can't stop mysqld when WSREP is # turned off # SELECT @@GLOBAL.WSREP_ON; @@GLOBAL.WSREP_ON 1 SET GLOBAL WSREP_ON= 0; Restart the node. SELECT @@GLOBAL.WSREP_ON; @@GLOBAL.WSREP_ON 1 # End of test. line ==97079==LeakSanitizer has encountered a fatal error. ==97079==HINT: LeakSanitizer does not work under ptrace (strace, gdb, etc) ^ Found warnings in /var/tmp/mtr/log/mysqld.1.err ok ]]>
 
</failure>
 
</testcase>
 
<testcase assertions="" classname="wsrep" name="mdev_7798" status="MTR_RES_FAILED" time="0.000" combinations="">
 
<failure message="" type="MTR_RES_FAILED">
 
<![CDATA[ # # MDEV-7798: mysql.server init script can't stop mysqld when WSREP is # turned off # SELECT @@GLOBAL.WSREP_ON; @@GLOBAL.WSREP_ON 1 SET GLOBAL WSREP_ON= 0; Restart the node. SELECT @@GLOBAL.WSREP_ON; @@GLOBAL.WSREP_ON 1 # End of test. line ==97143==LeakSanitizer has encountered a fatal error. ==97143==HINT: LeakSanitizer does not work under ptrace (strace, gdb, etc) ^ Found warnings in /var/tmp/mtr/log/mysqld.1.err ok ]]>
 
</failure>
 
</testcase>

(it looks like test itself is not correct - it does not work with ASAN and should be skipped if "ASAN=YES" or executed somehow without ptrace)

Comment by Timofey Turenko [ 2021-04-09 ]

added mtr_big_apr09.xml and .log generated with latest version of the patch

Example: test `connect.grant` failed, then retry-pass then failed again and again retry-pass:

console:

connect.grant                            w6 [ fail ]
 
        Test ended at 2021-04-09 13:04:05
 
 
 
CURRENT_TEST: connect.grant
 
/home/timofey_turenko_mariadb_com/MariaDBEnterprise/bin/mysqltest: Error on delete of '/var/tmp/mtr/6/mysqld.1/data//test/t1.BIN' (Errcode: 2 "No such file or directory")
 
 
 
 
 
Server [mysqld.2 - pid: 31403, winpid: 31403, exit: 256] failed during test run
 
Server log from this test:
 
----------SERVER LOG START-----------
 
----------SERVER LOG END-------------
 
 
 
 
 
 - saving '/var/tmp/mtr/6/log/connect.grant/' to '/var/tmp/mtr/log/connect.grant/'
 
 
 
Retrying test connect.grant, attempt(2/3)...
 
 
 
spider.spider_fixes_part                 w2 [ pass ]   1717
 
spider/bg.spider_fixes                   w3 [ pass ]   6070
 
spider/bg.direct_update_part             w4 [ pass ]  126623
 
spider/handler.direct_update             w8 [ pass ]  126547
 
spider.direct_update                     w5 [ pass ]  126871
 
wsrep_info.plugin 'innodb'               w1 [ pass ]  126644
 
 
 
MTR's internal check of the test case 'wsrep_info.plugin' failed.
 
This means that the test case does not preserve the state that existed
 
before the test case was executed.  Most likely the test case did not
 
do a proper clean-up. It could also be caused by the previous test run
 
by this thread, if the server wasn't restarted.
 
This is the diff of the states of the servers before and after the
 
test case was executed:
 
mysqltest: Logging to '/var/tmp/mtr/1/tmp/check-mysqld_2.log'.
 
mysqltest: Results saved in '/var/tmp/mtr/1/tmp/check-mysqld_2.result'.
 
mysqltest: Connecting to server localhost:16021 (socket /var/tmp/mtr/tmp/1/mysqld.2.sock) as 'root', connection 'default', attempt 0 ...
 
mysqltest: ... Connected.
 
mysqltest: Start processing test commands from './include/check-testcase.test' ...
 
mysqltest: At line 81: query 'call mtr.check_testcase()' failed: 1047: WSREP has not yet prepared node for application use
 
not ok
 
 
 
spider/handler.direct_update_part        w8 [ pass ]    742
 
spider.direct_update_part                w5 [ pass ]    479
 
spider/bg.spider_fixes_part              w3 [ pass ]   2880
 
spider/bg.function                       w4 [ pass ]   1893
 
spider/handler.function                  w8 [ pass ]    544
 
spider.function                          w5 [ pass ]    493
 
connect.grant                            w6 [ retry-pass ]   2341
 
 
 
Retrying test connect.grant, attempt(3/3)...
 
 
 
spider/bg.ha                             w4 [ pass ]    899
 
spider/handler.ha                        w8 [ pass ]    728
 
spider.ha                                w5 [ pass ]    752
 
connect.grant                            w6 [ retry-fail ]
 
        Test ended at 2021-04-09 13:04:14
 
 
 
CURRENT_TEST: connect.grant
 
/home/timofey_turenko_mariadb_com/MariaDBEnterprise/bin/mysqltest: Error on delete of '/var/tmp/mtr/6/mysqld.1/data//test/t1.BIN' (Errcode: 2 "No such file or directory")
 
/home/timofey_turenko_mariadb_com/MariaDBEnterprise/bin/mysqltest: Error on delete of '/var/tmp/mtr/6/mysqld.1/data//test/t1.CSV' (Errcode: 2 "No such file or directory")
 
/home/timofey_turenko_mariadb_com/MariaDBEnterprise/bin/mysqltest: Error on delete of '/var/tmp/mtr/6/mysqld.1/data//test/t1.DBF' (Errcode: 2 "No such file or directory")
 
/home/timofey_turenko_mariadb_com/MariaDBEnterprise/bin/mysqltest: Error on delete of '/var/tmp/mtr/6/mysqld.1/data//test/t1.FIX' (Errcode: 2 "No such file or directory")
 
/home/timofey_turenko_mariadb_com/MariaDBEnterprise/bin/mysqltest: Error on delete of '/var/tmp/mtr/6/mysqld.1/data//test/t1.VEC' (Errcode: 2 "No such file or directory")
 
mysqltest: In included file "/home/timofey_turenko_mariadb_com/MariaDBEnterprise/mysql-test/plugin/connect/connect/t/grant.inc": 
included from /home/timofey_turenko_mariadb_com/MariaDBEnterprise/mysql-test/plugin/connect/connect/t/grant.test at line 96:
 
At line 33: query 'INSERT INTO t1 VALUES (10)' failed: 1296: Got error 174 'Open(r+b) error 2 on /var/tmp/mtr/6/mysqld.1/data/./test/t1.EXT: No such file or directory' from CONNECT
 
 
 
The result from queries just before the failure was:
 
< snip >
 
DELETE FROM t1;
 
SELECT * FROM t1;
 
a
 
INSERT INTO t1 VALUES(10);
 
TRUNCATE TABLE t1;
 
SELECT * FROM t1;
 
a
 
CREATE VIEW v1 AS SELECT * FROM t1;
 
SELECT * FROM v1;
 
a
 
DROP VIEW v1;
 
DROP TABLE t1;
 
CREATE TABLE t1 (a INT NOT NULL) ENGINE=CONNECT TABLE_TYPE=VEC MAX_ROWS=100 FILE_NAME='t1.EXT';
 
ERROR 42000: Access denied; you need (at least one of) the FILE privilege(s) for this operation
 
connection default;
 
SELECT user();
 
user()
 
root@localhost
 
CREATE TABLE t1 (a INT NOT NULL) ENGINE=CONNECT TABLE_TYPE=VEC MAX_ROWS=100 FILE_NAME='t1.EXT';
 
INSERT INTO t1 VALUES (10);
 
 
 
More results from queries before failure can be found in /var/tmp/mtr/6/log/grant.log
 
 
 
 - skipping '/var/tmp/mtr/6/log/connect.grant/'

XML:

<testcase assertions="" classname="connect" name="grant" status="MTR_RES_FAILED" time="0.000" combinations="">
 
<failure message="" type="MTR_RES_FAILED">
 
<![CDATA[ GRANT ALL PRIVILEGES ON *.* TO user@localhost; REVOKE FILE ON *.* FROM user@localhost; connect user,localhost,user,,; connection user; SELECT user(); user() user@localhost CREATE TABLE t1 (a INT NOT NULL) ENGINE=CONNECT TABLE_TYPE=CSV; Warnings: Warning 1105 No file name. Table will use t1.csv INSERT INTO t1 VALUES (10); SELECT * FROM t1; a 10 UPDATE t1 SET a=20; SELECT * FROM t1; a 20 DELETE FROM t1; SELECT * FROM t1; ]]>
 
</failure>
 
</testcase>
 
<testcase assertions="" classname="connect" name="grant" status="MTR_RES_PASSED" time="2.341" combinations=""/>
 
<testcase assertions="" classname="connect" name="grant" status="MTR_RES_FAILED" time="2.341" combinations="">
 
<failure message="" type="MTR_RES_FAILED">
 
<![CDATA[ GRANT ALL PRIVILEGES ON *.* TO user@localhost; REVOKE FILE ON *.* FROM user@localhost; connect user,localhost,user,,; connection user; SELECT user(); user() user@localhost CREATE TABLE t1 (a INT NOT NULL) ENGINE=CONNECT TABLE_TYPE=CSV; Warnings: Warning 1105 No file name. Table will use t1.csv INSERT INTO t1 VALUES (10); SELECT * FROM t1; a 10 UPDATE t1 SET a=20; SELECT * FROM t1; a 20 DELETE FROM t1; SELECT * FROM t1; ]]>
 
</failure>
 
</testcase>

Comment by Timofey Turenko [ 2021-04-12 ]

Testing according https://github.com/MariaDB/server/pull/1753#issuecomment-808366027 done:

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
 
main.alias                               [ pass ]     46
 
select null into outfile 'f';
 
main.t1                                  [ pass ]      1
 
select null into outfile 'f';
 
main.t2                                  [ fail ]
 
        Test ended at 2021-04-12 17:09:57
 
 
 
CURRENT_TEST: main.t2
 
mysqltest: At line 1: query 'select null into outfile 'f'' failed: 1086: File 'f' already exists
 
 
 
 - saving '/home/turenko/MariaDBEnterprise/mysql-test/var/log/main.t2/' to '/home/turenko/MariaDBEnterprise/mysql-test/var/log/main.t2/'
 
 
 
Retrying test main.t2, attempt(2/5)...
 
 
 
select null into outfile 'f';
 
main.t2                                  [ retry-pass ]      1
 
 
 
Retrying test main.t2, attempt(3/5)...
 
 
 
select null into outfile 'f';
 
main.t2                                  [ retry-fail ]
 
        Test ended at 2021-04-12 17:09:57
 
 
 
CURRENT_TEST: main.t2
 
mysqltest: At line 1: query 'select null into outfile 'f'' failed: 1086: File 'f' already exists
 
 
 
 - saving '/home/turenko/MariaDBEnterprise/mysql-test/var/log/main.t2/' to '/home/turenko/MariaDBEnterprise/mysql-test/var/log/main.t2/'
 
 
 
Retrying test main.t2, attempt(4/5)...
 
 
 
select null into outfile 'f';
 
main.t2                                  [ retry-pass ]      1
 
 
 
Retrying test main.t2, attempt(5/5)...
 
 
 
select null into outfile 'f';
 
main.t2                                  [ retry-fail ]
 
        Test ended at 2021-04-12 17:09:58
 
 
 
CURRENT_TEST: main.t2
 
mysqltest: At line 1: query 'select null into outfile 'f'' failed: 1086: File 'f' already exists
 
 
 
 - saving '/home/turenko/MariaDBEnterprise/mysql-test/var/log/main.t2/' to '/home/turenko/MariaDBEnterprise/mysql-test/var/log/main.t2/'
 
 
 
Only  7  of 3 completed.
 
--------------------------------------------------------------------------
 
The servers were restarted 4 times
 
Spent 0.049 of 5 seconds executing testcases
 
 
 
Completed: Failed 5/7 tests, 28.57% were successful.
 
 
 
Failing test(s): main.t2
 
 
 



<?xml version="1.0" encoding="UTF-8"?>
 
<testsuites disabled="0" errors="" failures="5" name="" tests="7" time="0.051">
 
	<testsuite disabled="" errors="" failures="3" hostname="mdbci-xpuvawsm-1618239416-build" id="0" name="main" package="" skipped="" tests="7" time="0.051" timestamp="2021-04-12T15:09:58Z">
 
		<testcase assertions="" classname="main" name="alias" status="MTR_RES_PASSED" time="0.046" combinations="" />
 
		<testcase assertions="" classname="main" name="t1" status="MTR_RES_PASSED" time="0.001" combinations="" />
 
		<testcase assertions="" classname="main" name="t2" status="MTR_RES_FAILED" time="0.000" combinations="">
 
			<failure message="" type="MTR_RES_FAILED">
 
<![CDATA[CURRENT_TEST: main.t2
 
mysqltest: At line 1: query 'select null into outfile 'f'' failed: 1086: File 'f' already exists
 
]]>
 
			</failure>
 
		</testcase>
 
		<testcase assertions="" classname="main" name="t2" status="MTR_RES_PASSED" time="0.001" combinations="" />
 
		<testcase assertions="" classname="main" name="t2" status="MTR_RES_FAILED" time="0.001" combinations="">
 
			<failure message="" type="MTR_RES_FAILED">
 
<![CDATA[CURRENT_TEST: main.t2
 
mysqltest: At line 1: query 'select null into outfile 'f'' failed: 1086: File 'f' already exists
 
]]>
 
			</failure>
 
		</testcase>
 
		<testcase assertions="" classname="main" name="t2" status="MTR_RES_PASSED" time="0.001" combinations="" />
 
		<testcase assertions="" classname="main" name="t2" status="MTR_RES_FAILED" time="0.001" combinations="">
 
			<failure message="" type="MTR_RES_FAILED">
 
<![CDATA[CURRENT_TEST: main.t2
 
mysqltest: At line 1: query 'select null into outfile 'f'' failed: 1086: File 'f' already exists
 
]]>
 
			</failure>
 
		</testcase>
 
	</testsuite>
 
</testsuites>

Comment by Anel Husakovic [ 2021-04-12 ]

Pushed to 10.2 with commit f776fa96b

Generated at Thu Feb 08 09:27:42 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.