Upstream 5.6 --repeat=2 test failures

Bug #1664219 reported by Laurynas Biveinis on 2017-02-13
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona Server moved to https://jira.percona.com/projects/PS
Status tracked in 5.7
5.5
Invalid
Undecided
Unassigned
5.6
Fix Released
Low
Laurynas Biveinis
5.7
Fix Released
Low
Laurynas Biveinis

Bug Description

On 5.6 trunk, with --repeat=2:

rpl.rpl_auto_increment 'mix' w3 [ fail ]
        Test ended at 2017-02-11 11:31:10

CURRENT_TEST: rpl.rpl_auto_increment
mysqltest: In included file "./extra/rpl_tests/rpl_auto_increment.test":
included from ./extra/rpl_tests/rpl_auto_increment.test at line 220:
At line 219: command "copy_file" failed with error 1. my_errno=17

tags: added: ci upstream

rpl.rpl_timezone 'mix' w3 [ fail ]
        Test ended at 2017-02-11 11:33:01

CURRENT_TEST: rpl.rpl_timezone
mysqltest: At line 200: command "copy_file" failed with error 1. my_errno=17

rpl.rpl_stop_slave_threads_error 'mix' w3 [ fail ]
        Test ended at 2017-02-11 11:35:23

CURRENT_TEST: rpl.rpl_stop_slave_threads_error
Unable to open '/mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/mysql-test/var/3/tmp/slave_log.err': No such file or directory
mysqltest: In included file "./include/search_pattern.inc":
included from ./include/search_pattern.inc at line 44:
At line 32: command "perl" failed with error 2. my_errno=2

rpl.rpl_spec_variables 'mix' w3 [ fail ]
        Test ended at 2017-02-11 11:39:48

CURRENT_TEST: rpl.rpl_spec_variables
mysqltest: At line 150: command "copy_file" failed with error 1. my_errno=17

Download full text (3.5 KiB)

pl.rpl_extra_row_data 'row' w4 [ fail ]
        Test ended at 2017-02-11 12:00:19

CURRENT_TEST: rpl.rpl_extra_row_data
--- /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/mysql-test/suite/rpl/r/rpl_extra_row_data.result 2017-02-03 15:30:26.036481345 +0300
+++ /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/mysql-test/var/4/log/rpl_extra_row_data.reject 2017-02-11 20:00:18.928352053 +0300
@@ -18,16 +18,16 @@
 create table raw_data(txt varchar(1000));
 select replace(txt, '\r', '') from raw_data where txt like '%### Extra row data format%' order by txt;
 replace(txt, '\r', '')
-### Extra row data format: 0, len: 0 :
-### Extra row data format: 1, len: 1 :0x01
-### Extra row data format: 2, len: 2 :0x0202
-### Extra row data format: 3, len: 3 :0x030303
-### Extra row data format: 4, len: 4 :0x04040404
-### Extra row data format: 5, len: 5 :0x0505050505
-### Extra row data format: 6, len: 6 :0x060606060606
-### Extra row data format: 7, len: 7 :0x07070707070707
-### Extra row data format: 8, len: 8 :0x0808080808080808
-### Extra row data format: 9, len: 9 :0x090909090909090909
+### Extra row data format: 87, len: 87 :0x575757575757575757575757575757575757575757575757575757575757575757575757575757575757575757575757575757575757575757575757575757575757575757575757575757575757575757575757575757
+### Extra row data format: 88, len: 88 :0x58585858585858585858585858585858585858585858585858585858585858585858585858585858585858585858585858585858585858585858585858585858585858585858585858585858585858585858585858585858
+### Extra row data format: 89, len: 89 :0x5959595959595959595959595959595959595959595959595959595959595959595959595959595959595959595959595959595959595959595959595959595959595959595959595959595959595959595959595959595959
+### Extra row data format: 90, len: 90 :0x5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A5A
+### Extra row data format: 91, len: 91 :0x5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B5B
+### Extra row data format: 92, len: 92 :0x5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C5C
+### Extra row data format: 93, len: 93 :0x5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D5D
+### Extra row data format: 94, len: 94 :0x5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E5E
+### Extra row data format: 95, len: 95 :0x5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F5F...

Read more...

rpl.rpl_temporary_error_table_repository 'row' w4 [ fail ]
        Test ended at 2017-02-11 12:32:10

CURRENT_TEST: rpl.rpl_temporary_error_table_repository
mysqltest: In included file "./include/wait_for_status_var.inc":
included from ./include/wait_for_status_var.inc at line 88:
At line 88:

The result from queries just before the failure was:
include/master-slave.inc
Warnings:
Note #### Sending passwords in plain text without SSL/TLS is extremely insecure.
Note #### Storing MySQL user name or password information in the master info repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START SLAVE; see the 'START SLAVE Syntax' in the MySQL Manual for more information.
[connection master]
[connection master]
CREATE TABLE t1 (c1 INT PRIMARY KEY, c2 INT) ENGINE= InnoDB;
include/stop_slave.inc
SET @saved_slave_transaction_retries = @@GLOBAL.slave_transaction_retries;
SET @saved_innodb_lock_wait_timeout = @@GLOBAL.innodb_lock_wait_timeout;
SET @saved_master_info_repository = @@GLOBAL.master_info_repository;
SET @saved_relay_log_info_repository = @@GLOBAL.relay_log_info_repository;
SET @@GLOBAL.innodb_lock_wait_timeout = 1;
SET @@GLOBAL.master_info_repository = TYPE;
SET @@GLOBAL.relay_log_info_repository = TYPE;
[connection slave1]
BEGIN;
INSERT INTO t1 VALUES (7,0);
[connection master]
INSERT INTO t1 VALUES (7,7);
[connection slave]
SET @@GLOBAL.slave_transaction_retries = 0;
include/start_slave.inc
### Specified retry number is expected ###
**** ERROR: failed while waiting for Slave_retried_transactions = 0 ****

binlog.binlog_gtid_errors 'mix' w1 [ fail ]
        Test ended at 2017-02-11 12:59:03

CURRENT_TEST: binlog.binlog_gtid_errors
--- /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/mysql-test/suite/binlog/r/binlog_gtid_errors.result 2017-02-03 15:30:25.590498270 +0300
+++ /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/mysql-test/var/1/log/binlog_gtid_errors.reject 2017-02-11 20:59:03.426849774 +0300
@@ -2,7 +2,7 @@
 # Readable.
 SELECT @@GLOBAL.GTID_EXECUTED;
 @@GLOBAL.GTID_EXECUTED
-
+c59fc9da-f083-11e6-b336-bb5b93ce5334:1-13
 SELECT @@SESSION.GTID_EXECUTED;
 @@SESSION.GTID_EXECUTED

mysqltest: Result content mismatch

binlog.binlog_mysqlbinlog-cp932 'mix' w2 [ fail ]
        Test ended at 2017-02-11 12:59:24

CURRENT_TEST: binlog.binlog_mysqlbinlog-cp932
mysqltest: At line 19: command "copy_file" failed with error 1. my_errno=17

The result from queries just before the failure was:
RESET MASTER;
create table t3 (f text character set utf8);
create table t4 (f text character set cp932);
flush logs;
safe_process[12528]: Child process: 12529, exit: 1

binlog.binlog_checksum 'mix' w2 [ fail ]
        Test ended at 2017-02-11 12:59:38

CURRENT_TEST: binlog.binlog_checksum
mysqltest: At line 25: command "copy_file" failed with error 1. my_errno=17

The result from queries just before the failure was:
set @save_binlog_checksum = @@global.binlog_checksum;
set @save_master_verify_checksum = @@global.master_verify_checksum;
set @@global.binlog_checksum = CRC32;
set @@global.master_verify_checksum = 1;
reset master;
must be master-bin.000001
show binary logs;
Log_name File_size
master-bin.000001 #
create table t1 (a int);
flush logs;
safe_process[12987]: Child process: 12988, exit: 1

binlog.binlog_row_mix_tmp_table 'mix' w1 [ fail ]
        Test ended at 2017-02-11 13:02:43

CURRENT_TEST: binlog.binlog_row_mix_tmp_table
mysqltest: In included file "./extra/binlog_tests/tmp_table.test":
included from ./extra/binlog_tests/tmp_table.test at line 88:
At line 88: command "copy_file" failed with error 1. my_errno=17

The result from queries just before the failure was:
RESET MASTER;
create table foo (a int);
flush logs;
create temporary table tmp1_foo like foo;
create temporary table tmp2_foo (a int);
insert into tmp1_foo values (1), (2), (3), (4);
replace into tmp2_foo values (1), (2), (3), (4);
update tmp1_foo set a=2*a-1;
update tmp2_foo set a=2*a;
delete from tmp1_foo where a < 5;
delete from tmp2_foo where a < 5;
insert into foo select * from tmp1_foo;
insert into foo select * from tmp2_foo;
truncate table tmp1_foo;
truncate table tmp2_foo;
flush logs;
select * from foo;
a
5
7
6
8
drop table foo;
create table foo (a int);
safe_process[19373]: Child process: 19374, exit: 1

main.ctype_ldml w2 [ fail ]
        Test ended at 2017-02-11 13:05:42

CURRENT_TEST: main.ctype_ldml
--- /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/mysql-test/r/ctype_ldml.result 2017-02-03 15:30:25.446503734 +0300
+++ /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/mysql-test/var/2/log/ctype_ldml.reject 2017-02-11 21:05:41.907197827 +0300
@@ -1137,4 +1137,4 @@
 # Bug#14197426 PARSE ERRORS IN LOADABLE UCA / LDML COLLATIONS ARE SILENTLY IGNORED
 #
 # Search for occurrences of [ERROR] Syntax error at '[strength tertiary]'
-Occurances : 1
+Occurances : 2

mysqltest: Result content mismatch

safe_process[25357]: Child process: 25359, exit: 1

binlog.binlog_stm_tmp_table 'stmt' w4 [ fail ]
        Test ended at 2017-02-11 13:07:07

CURRENT_TEST: binlog.binlog_stm_tmp_table
mysqltest: In included file "./extra/binlog_tests/tmp_table.test":
included from ./extra/binlog_tests/tmp_table.test at line 88:
At line 88: command "copy_file" failed with error 1. my_errno=17

Download full text (4.2 KiB)

perfschema.dml_setup_instruments w1 [ pass ] 81
perfschema.dml_setup_instruments w1 [ fail ]
        Test ended at 2017-02-11 13:31:33

CURRENT_TEST: perfschema.dml_setup_instruments
--- /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/mysql-test/suite/perfschema/r/dml_setup_instruments.result 2017-02-03 15:30:25.972483774 +0300
+++ /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/mysql-test/var/1/log/dml_setup_instruments.reject 2017-02-11 21:31:33.529195863 +0300
@@ -4,31 +4,31 @@
   and name not in ('wait/synch/mutex/sql/DEBUG_SYNC::mutex')
 order by name limit 10;
 NAME ENABLED TIMED
-wait/synch/mutex/sql/Cversion_lock YES YES
-wait/synch/mutex/sql/Delayed_insert::mutex YES YES
-wait/synch/mutex/sql/Event_scheduler::LOCK_scheduler_state YES YES
-wait/synch/mutex/sql/Gtid_state YES YES
-wait/synch/mutex/sql/hash_filo::lock YES YES
-wait/synch/mutex/sql/LOCK_active_mi YES YES
-wait/synch/mutex/sql/LOCK_audit_mask YES YES
-wait/synch/mutex/sql/LOCK_connection_count YES YES
-wait/synch/mutex/sql/LOCK_crypt YES YES
-wait/synch/mutex/sql/LOCK_delayed_create YES YES
+wait/synch/mutex/sql/Cversion_lock YES NO
+wait/synch/mutex/sql/Delayed_insert::mutex YES NO
+wait/synch/mutex/sql/Event_scheduler::LOCK_scheduler_state YES NO
+wait/synch/mutex/sql/Gtid_state YES NO
+wait/synch/mutex/sql/hash_filo::lock YES NO
+wait/synch/mutex/sql/LOCK_active_mi YES NO
+wait/synch/mutex/sql/LOCK_audit_mask YES NO
+wait/synch/mutex/sql/LOCK_connection_count YES NO
+wait/synch/mutex/sql/LOCK_crypt YES NO
+wait/synch/mutex/sql/LOCK_delayed_create YES NO
 select * from performance_schema.setup_instruments
 where name like 'Wait/Synch/Rwlock/sql/%'
   and name not in ('wait/synch/rwlock/sql/CRYPTO_dynlock_value::lock')
 order by name limit 10;
 NAME ENABLED TIMED
-wait/synch/rwlock/sql/Binlog_relay_IO_delegate::lock YES YES
-wait/synch/rwlock/sql/Binlog_storage_delegate::lock YES YES
-wait/synch/rwlock/sql/Binlog_transmit_delegate::lock YES YES
-wait/synch/rwlock/sql/gtid_commit_rollback YES YES
-wait/synch/rwlock/sql/LOCK_consistent_snapshot YES YES
-wait/synch/rwlock/sql/LOCK_dboptions YES YES
-wait/synch/rwlock/sql/LOCK_grant YES YES
-wait/synch/rwlock/sql/LOCK_system_variables_hash YES YES
-wait/synch/rwlock/sql/LOCK_sys_init_connect YES YES
-wait/synch/rwlock/sql/LOCK_sys_init_slave YES YES
+wait/synch/rwlock/sql/Binlog_relay_IO_delegate::lock YES NO
+wait/synch/rwlock/sql/Binlog_storage_delegate::lock YES NO
+wait/synch/rwlock/sql/Binlog_transmit_delegate::lock YES NO
+wait/synch/rwlock/sql/gtid_commit_rollback YES NO
+wait/synch/rwlock/sql/LOCK_consistent_snapshot YES NO
+wait/synch/rwlock/sql/LOCK_dboptions YES NO
+wait/synch/rwlock/sql/LOCK_grant YES NO
+wait/synch/rwlock/sql/LOCK_system_variables_hash YES NO
+wait/synch/rwlock/sql/LOCK_sys_init_connect YES NO
+wait/synch/rwlock/sql/LOCK_sys_init_slave YES NO
 select * from performance_schema.setup_instruments
 where name like 'Wait/Synch/Cond/sql/%'
   and name not in (
@@ -36,16 +36,16 @@
 'wait/synch/cond/sql/DEBUG_SYNC::cond')
 order by name limit 10;
 NAME ENABLED TIMED
-wait/synch/cond/sql/COND_connection_count YE...

Read more...

engines/funcs.tc_partition_list_directory w1 [ pass ] 7
engines/funcs.tc_partition_list_directory w1 [ fail ]
        Test ended at 2017-02-11 13:33:32

CURRENT_TEST: engines/funcs.tc_partition_list_directory
mysqltest: At line 4: command "mkdir" failed with error 1. my_errno=17

The result from queries just before the failure was:
DROP TABLE IF EXISTS t1;
safe_process[1878]: Child process: 1879, exit: 1

Server [mysqld.1 - pid: 32120, winpid: 32120] log:
Server log from this test:
----------SERVER LOG START-----------
----------SERVER LOG END-------------

main.ctype_gbk_binlog w1 [ pass ] 28
main.ctype_gbk_binlog w1 [ fail ]
        Test ended at 2017-02-11 13:34:38

CURRENT_TEST: main.ctype_gbk_binlog
mysqltest: At line 31: command "copy_file" failed with error 1. my_errno=17

The result from queries just before the failure was:
RESET MASTER;
SET NAMES gbk;
CREATE TABLE t1 (
f1 BLOB
) ENGINE=MyISAM DEFAULT CHARSET=gbk;
CREATE PROCEDURE p1(IN val BLOB)
BEGIN
SET @tval = val;
SET @sql_cmd = CONCAT_WS(' ', 'insert into t1(f1) values(?)');
PREPARE stmt FROM @sql_cmd;
EXECUTE stmt USING @tval;
DEALLOCATE PREPARE stmt;
END|
SET @`tcontent`:=_binary 0x50434B000900000000000000E9000000 COLLATE `binary`/*!*/;
CALL p1(@`tcontent`);
FLUSH LOGS;
DROP PROCEDURE p1;
RENAME TABLE t1 to t2;
safe_process[3411]: Child process: 3412, exit: 1

innodb.innodb_upd_stats_if_needed_not_inited w4 [ fail ]
        Test ended at 2017-02-11 14:11:52

CURRENT_TEST: innodb.innodb_upd_stats_if_needed_not_inited
--- /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/mysql-test/suite/innodb/r/innodb_upd_stats_if_needed_not_inited.result 2017-02-03 15:30:25.771491402 +0300
+++ /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/mysql-test/var/4/log/innodb_upd_stats_if_needed_not_inited.reject 2017-02-11 22:11:52.079906100 +0300
@@ -11,5 +11,6 @@
 DELETE FROM parent;
 SET SESSION DEBUG='-d,test_upd_stats_if_needed_not_inited';
 test_upd_stats_if_needed_not_inited was executed
+test_upd_stats_if_needed_not_inited was executed
 DROP TABLE child;
 DROP TABLE parent;

mysqltest: Result length mismatch

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-2236

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers