Details
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
Attachments
- jenkins
- 4 kB
- mtr_apr01.log
- 48 kB
- mtr_apr01.xml
- 55 kB
- mtr_big_apr09.log
- 387 kB
- mtr_big_apr09.xml
- 829 kB
- mtr_big.log
- 389 kB
- mtr_big.xml
- 829 kB
- mtr_galera.log
- 51 kB
- mtr_galera.xml
- 56 kB
- mtr_retry_pass2.log
- 385 kB
- mtr.log
- 383 kB
- stdio (9)
- 7 kB
Activity
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)
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>
|
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>
|
|
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=""/>