Bug #46823 rpl_ndb.rpl_ndb_extraCol test fails on PB-2 with a timeout
Submitted: 20 Aug 11:53 Modified: 28 Aug 15:56
Reporter: Andrei Elkin
Status: Verified
Category:Tests: Cluster Severity:S3 (Non-critical)
Version:5.1 OS:Any
Assigned to: Target Version:
Tags: test failure

[20 Aug 11:53] Andrei Elkin
Description:
Failure on PB-2

http://pb2.norway.sun.com/web.py?template=mysql_show_test_failure&test_failure_id=2281242

has these details

Where 	Build 	Test 	Run 	Suite 	Case 	Mode 	When
mysql-5.1-bugteam
490158	binary-gcc-sol10-x86-tar-gz
490347 loki07	test-gcc-sol10-x86
490691 tyr38	n_mix	rpl_ndb	rpl_ndb_extraCol	None	2009-08-13 22:56:34
rpl_ndb.rpl_ndb_extraCol                 w3 [ fail ]  timeout after 900 seconds
     
Test case timeout after 900 seconds

How to repeat:
Look at the url.
[28 Aug 15:56] Andrei Elkin
The issue can relate to timing that NDB is prone to or
to a server problem, as the following piece of log, - "found core" - taken from the
url-ed page,
shows:
Test case timeout after 900 seconds

==
/export/home/pb2/test/sb_6-692645-1250202797.88/mysql-5.1.38-solaris10-i386-test/mysql-test/var/3/log/rpl_ndb_extraCol.log
== 
*** connect to master and drop columns ***
ALTER TABLE t14 DROP COLUMN c2;
ALTER TABLE t14 DROP COLUMN c4;
*** Select from Master ***
SELECT * FROM t14 ORDER BY c1;
c1	c3	c5
1	Replication Testing Extra Col	Kyle
2	This Test Should work	JOE
3	If is does not, I will open a bug	QA
*** Select from Slave ***
SELECT * FROM t14 ORDER BY c1;
c1	c3	c5	c6	c7
1	Replication Testing Extra Col	Kyle	NULL	CURRENT_TIMESTAMP
2	This Test Should work	JOE	NULL	CURRENT_TIMESTAMP
3	If is does not, I will open a bug	QA	NULL	CURRENT_TIMESTAMP
*** Drop t14  ***
DROP TABLE t14;
*** Create t15 on slave  ***
STOP SLAVE;
RESET SLAVE;

 ==
/export/home/pb2/test/sb_6-692645-1250202797.88/mysql-5.1.38-solaris10-i386-test/mysql-test/var/3/tmp/analyze-timeout-mysqld.1.1.err
==
mysqltest: Could not open connection 'default' after 500 attempts: 2002 Can't connect to
local MySQL server through socket
'/export/home/pb2/test/sb_6-692645-1250202797.88/tmp/2RmOPqti7z/3/mysqld.1.1.sock' (146)

 ==
/export/home/pb2/test/sb_6-692645-1250202797.88/mysql-5.1.38-solaris10-i386-test/mysql-test/var/3/tmp/analyze-timeout-mysqld.1.slave.err
==
mysqltest: Could not open connection 'default' after 500 attempts: 2002 Can't connect to
local MySQL server through socket
'/export/home/pb2/test/sb_6-692645-1250202797.88/tmp/2RmOPqti7z/3/mysqld.1.slave.sock'
(146)

 ==
/export/home/pb2/test/sb_6-692645-1250202797.88/mysql-5.1.38-solaris10-i386-test/mysql-test/var/3/tmp/analyze-timeout-mysqld.2.1.err
==
mysqltest: Could not open connection 'default' after 500 attempts: 2002 Can't connect to
local MySQL server through socket
'/export/home/pb2/test/sb_6-692645-1250202797.88/tmp/2RmOPqti7z/3/mysqld.2.1.sock' (146)

 - saving
'/export/home/pb2/test/sb_6-692645-1250202797.88/mysql-5.1.38-solaris10-i386-test/mysql-test/var/3/log/rpl_ndb.rpl_ndb_extraCol/'
to
'/export/home/pb2/test/sb_6-692645-1250202797.88/mysql-5.1.38-solaris10-i386-test/mysql-test/var/log/rpl_ndb.rpl_ndb_extraCol/'
 - found 'core', moving it to
'/export/home/pb2/test/sb_6-692645-1250202797.88/mysql-5.1.38-solaris10-i386-test/mysql-test/var/log/rpl_ndb.rpl_ndb_extraCol'
 - found 'core' (3/5)