[MDEV-31902] spider/bugfix.mdev_20100, spider/bugfix.mdev_20502, spider/bugfix.mdev_26544, spider/bugfix.mdev_26582, spider/bugfix.mdev_27184, spider/bugfix.mdev_27239, spider/bugfix.mdev_27240, spider/bugfix.mdev_29484 fail Created: 2023-08-11  Updated: 2024-02-06

Status: Open
Project: MariaDB Server
Component/s: Storage Engine - Spider
Affects Version/s: 11.1.1
Fix Version/s: 11.1

Type: Bug Priority: Major
Reporter: Timofey Turenko Assignee: Yuchen Pei
Resolution: Unresolved Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-33322 Check of testcase failed for random s... Open

 Description   

looks like wrong privileges for test user

logs example https://mdbe-ci-repo.mariadb.net/bb-logs/MariaDBServerCommunityProduction/11.1.1/rhel_7_gcp/mtr-psproto-test/22924/

spider/bugfix.mdev_26544                 w7 [ fail ]
        Test ended at 2023-08-10 20:52:58
 
CURRENT_TEST: spider/bugfix.mdev_26544
mysqltest: At line 22: query 'INSERT INTO tbl_a (a) VALUES (0)' failed with wrong errno ER_DBACCESS_DENIED_ERROR (1044): 'Access denied for user ''@'localhost' to database 'auto_test_remote'', instead of ER_CONNECT_TO_FOREIGN_DATA_SOURCE (1429)...
 
The result from queries just before the failure was:
#
# MDEV-26544 Assertion `part_share->auto_inc_initialized' failed in ha_partition::get_auto_increment on INSERT
#
for master_1
for child2
for child3
connection master_1;
CREATE DATABASE auto_test_remote;
USE auto_test_remote;
CREATE TABLE `tbl_a` (
`a` INT AUTO_INCREMENT, KEY(`a`)
) ENGINE=Spider DEFAULT CHARSET=utf8
PARTITION BY LIST COLUMNS (`a`) (
PARTITION `pt1` DEFAULT
);
INSERT INTO tbl_a (a) VALUES (0);
 
Warnings from just before the error:
Error 1044 Access denied for user ''@'localhost' to database 'auto_test_remote' 
Error 1044 Access denied for user ''@'localhost' to database 'auto_test_remote'
 
 - saving '/var/tmp/mtr/7/log/spider/bugfix.mdev_26544/' to '/var/tmp/mtr/log/bugfix.mdev_26544/'
 
Retrying test spider/bugfix.mdev_26544, attempt(2/3)...
 
worker[7] > Restart  - not started
spider/bugfix.mdev_26539                 w3 [ pass ]    328
worker[3] > Restart [mysqld.1.1 - pid: 19807, winpid: 19807] - using different config file
worker[3] > Restart [mysqld.2.1 - pid: 19813, winpid: 19813] - using different config file
spider/bugfix.mdev_26582                 w1 [ fail ]
        Test ended at 2023-08-10 20:52:58
 
CURRENT_TEST: spider/bugfix.mdev_26582
mysqltest: At line 17: query 'INSERT INTO t VALUES (0)' failed with wrong errno ER_SPECIFIC_ACCESS_DENIED_ERROR (1227): 'Access denied; you need (at least one of) the SUPER privilege(s) for this operation', instead of ER_CONNECT_TO_FOREIGN_DATA_SOURCE (1429)...
 
The result from queries just before the failure was:
#
# MDEV-26582 SIGSEGV in spider_db_bulk_insert and spider_db_connect and spider_db_before_query, and hang in "End of update loop" / "Reset for next command" query states
#
CREATE DATABASE IF NOT EXISTS auto_test_local;
USE auto_test_local;
CREATE TABLE t (i CHAR) ENGINE=SPIDER;
INSERT INTO t VALUES (0);
 
Warnings from just before the error:
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation
 
 - skipping '/var/tmp/mtr/1/log/spider/bugfix.mdev_26582/'
 
Retrying test spider/bugfix.mdev_26582, attempt(2/3)...
 
worker[1] > Restart  - not started
spider/bugfix.mdev_27184                 w4 [ fail ]
        Test ended at 2023-08-10 20:52:59
 
CURRENT_TEST: spider/bugfix.mdev_27184
mysqltest: At line 21: query 'INSERT INTO tbl_a VALUES
(0xF5A7),(0xF5A8),(0xF5A9),(0xF5AA),(0xF5AB),(0xF5AC),(0xF5AD),(0xF5AE),
(0xF5A7),(0xF5A8),(0xF5A9),(0xF5AA),(0xF5AB),(0xF5AC),(0xF5AD),(0xF5AE)' failed with wrong errno ER_SPECIFIC_ACCESS_DENIED_ERROR (1227): 'Access denied; you need (at least one of) the SUPER privilege(s) for this operation', instead of ER_CONNECT_TO_FOREIGN_DATA_SOURCE (1429)...
 
The result from queries just before the failure was:
#
# MDEV-27184 Assertion `(old_top == initial_top (av) && old_size == 0) ||
# ((unsigned long) (old_size) >= MINSIZE && prev_inuse (old_top) &&
# ((unsigned long) old_end & (pagesize - 1)) == 0)' failed,
# Assertion `str.alloced_length() >= str.length() + data_len' failed
#
for master_1
for child2
for child3
connection master_1;
CREATE DATABASE auto_test_remote;
USE auto_test_remote;
CREATE TABLE tbl_a (a FLOAT) ENGINE=SPIDER;
INSERT INTO tbl_a VALUES
(0xF5A7),(0xF5A8),(0xF5A9),(0xF5AA),(0xF5AB),(0xF5AC),(0xF5AD),(0xF5AE),
(0xF5A7),(0xF5A8),(0xF5A9),(0xF5AA),(0xF5AB),(0xF5AC),(0xF5AD),(0xF5AE);
 
Warnings from just before the error:
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation
 
 - skipping '/var/tmp/mtr/4/log/spider/bugfix.mdev_27184/'
 
Retrying test spider/bugfix.mdev_27184, attempt(2/3)...
 
worker[4] > Restart  - not started
spider/bugfix.mdev_27239                 w6 [ fail ]
        Test ended at 2023-08-10 20:52:59
 
CURRENT_TEST: spider/bugfix.mdev_27239
--- /usr/share/mariadb-test/plugin/spider/spider/bugfix/r/mdev_27239.result	2023-06-05 20:45:45.000000000 +0200
+++ /usr/share/mariadb-test/plugin/spider/spider/bugfix/r/mdev_27239.reject	2023-08-10 20:52:58.961422042 +0200
@@ -9,10 +9,8 @@
 CREATE TABLE tbl_a (a INT) ENGINE=SPIDER;
 FLUSH TABLE tbl_a WITH READ LOCK;
 Warnings:
-Error	1429	Unable to connect to foreign data source: localhost
-Error	1429	Unable to connect to foreign data source: localhost
-Error	1429	Unable to connect to foreign data source: localhost
-Error	1429	Unable to connect to foreign data source: localhost
+Error	1044	Access denied for user ''@'localhost' to database 'auto_test_local'
+Error	1044	Access denied for user ''@'localhost' to database 'auto_test_local'
 BEGIN;
 DROP DATABASE auto_test_local;
 for master_1
 
mysqltest: Result length mismatch
 
 - skipping '/var/tmp/mtr/6/log/spider/bugfix.mdev_27239/'
 
Retrying test spider/bugfix.mdev_27239, attempt(2/3)...
 
worker[6] > Restart  - not started
spider/bugfix.mdev_26544                 w7 [ retry-fail ]
        Test ended at 2023-08-10 20:52:59
 
CURRENT_TEST: spider/bugfix.mdev_26544
mysqltest: At line 22: query 'INSERT INTO tbl_a (a) VALUES (0)' failed with wrong errno ER_DBACCESS_DENIED_ERROR (1044): 'Access denied for user ''@'localhost' to database 'auto_test_remote'', instead of ER_CONNECT_TO_FOREIGN_DATA_SOURCE (1429)...
 
The result from queries just before the failure was:
#
# MDEV-26544 Assertion `part_share->auto_inc_initialized' failed in ha_partition::get_auto_increment on INSERT
#
for master_1
for child2
for child3
connection master_1;
CREATE DATABASE auto_test_remote;
USE auto_test_remote;
CREATE TABLE `tbl_a` (
`a` INT AUTO_INCREMENT, KEY(`a`)
) ENGINE=Spider DEFAULT CHARSET=utf8
PARTITION BY LIST COLUMNS (`a`) (
PARTITION `pt1` DEFAULT
);
INSERT INTO tbl_a (a) VALUES (0);
 
Warnings from just before the error:
Error 1044 Access denied for user ''@'localhost' to database 'auto_test_remote' 
Error 1044 Access denied for user ''@'localhost' to database 'auto_test_remote'
 
 - skipping '/var/tmp/mtr/7/log/spider/bugfix.mdev_26544/'
 
Test spider/bugfix.mdev_26544 has failed 2 times, no more retries!
 
worker[7] > Restart  - using different config file
spider/bugfix.mdev_27240                 w2 [ fail ]
        Test ended at 2023-08-10 20:52:59
 
CURRENT_TEST: spider/bugfix.mdev_27240
mysqltest: At line 18: query 'LOCK TABLE tbl_a READ' failed with wrong errno ER_SPECIFIC_ACCESS_DENIED_ERROR (1227): 'Access denied; you need (at least one of) the SUPER privilege(s) for this operation', instead of ER_CONNECT_TO_FOREIGN_DATA_SOURCE (1429)...
 
The result from queries just before the failure was:
for master_1
for child2
for child3
CREATE DATABASE auto_test_local;
USE auto_test_local;
CREATE TABLE tbl_a (a INT KEY) ENGINE=SPIDER;
SELECT a.z FROM tbl_a AS a,tbl_a b WHERE a.z=b.z;
ERROR 42S22: Unknown column 'a.z' in 'field list'
ALTER TABLE tbl_a CHANGE c c INT;
ERROR 42S22: Unknown column 'c' in 'tbl_a'
LOCK TABLE tbl_a READ;
 
Warnings from just before the error:
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation 
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation 
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation 
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation
 
 - skipping '/var/tmp/mtr/2/log/spider/bugfix.mdev_27240/'
 
Retrying test spider/bugfix.mdev_27240, attempt(2/3)...
 
worker[2] > Restart  - not started
***Warnings generated in error logs during shutdown after running tests: spider/bugfix.mdev_27240
 
2023-08-10 20:52:59 6 [Warning] WSREP: handlerton rollback failed, thd 6 565 conf 0 SQL LOCK TABLE tbl_a READ
 
spider/bugfix.mdev_26582                 w1 [ retry-fail ]
        Test ended at 2023-08-10 20:53:02
 
CURRENT_TEST: spider/bugfix.mdev_26582
mysqltest: At line 17: query 'INSERT INTO t VALUES (0)' failed with wrong errno ER_SPECIFIC_ACCESS_DENIED_ERROR (1227): 'Access denied; you need (at least one of) the SUPER privilege(s) for this operation', instead of ER_CONNECT_TO_FOREIGN_DATA_SOURCE (1429)...
 
The result from queries just before the failure was:
#
# MDEV-26582 SIGSEGV in spider_db_bulk_insert and spider_db_connect and spider_db_before_query, and hang in "End of update loop" / "Reset for next command" query states
#
CREATE DATABASE IF NOT EXISTS auto_test_local;
USE auto_test_local;
CREATE TABLE t (i CHAR) ENGINE=SPIDER;
INSERT INTO t VALUES (0);
 
Warnings from just before the error:
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation
 
 - skipping '/var/tmp/mtr/1/log/spider/bugfix.mdev_26582/'
 
Test spider/bugfix.mdev_26582 has failed 2 times, no more retries!
 
worker[1] > Restart  - using different config file
spider/bugfix.mdev_28854                 w8 [ pass ]    160
worker[8] > Restart [mysqld.1.1 - pid: 20362, winpid: 20362] - using different config file
worker[8] > Restart [mysqld.2.1 - pid: 20386, winpid: 20386] - using different config file
spider/bugfix.mdev_28996                 w5 [ pass ]    460
worker[5] > Restart [mysqld.1.1 - pid: 20388, winpid: 20388] - using different config file
worker[5] > Restart [mysqld.2.1 - pid: 20399, winpid: 20399] - using different config file
spider/bugfix.mdev_27184                 w4 [ retry-fail ]
        Test ended at 2023-08-10 20:53:03
 
CURRENT_TEST: spider/bugfix.mdev_27184
mysqltest: At line 21: query 'INSERT INTO tbl_a VALUES
(0xF5A7),(0xF5A8),(0xF5A9),(0xF5AA),(0xF5AB),(0xF5AC),(0xF5AD),(0xF5AE),
(0xF5A7),(0xF5A8),(0xF5A9),(0xF5AA),(0xF5AB),(0xF5AC),(0xF5AD),(0xF5AE)' failed with wrong errno ER_SPECIFIC_ACCESS_DENIED_ERROR (1227): 'Access denied; you need (at least one of) the SUPER privilege(s) for this operation', instead of ER_CONNECT_TO_FOREIGN_DATA_SOURCE (1429)...
 
The result from queries just before the failure was:
#
# MDEV-27184 Assertion `(old_top == initial_top (av) && old_size == 0) ||
# ((unsigned long) (old_size) >= MINSIZE && prev_inuse (old_top) &&
# ((unsigned long) old_end & (pagesize - 1)) == 0)' failed,
# Assertion `str.alloced_length() >= str.length() + data_len' failed
#
for master_1
for child2
for child3
connection master_1;
CREATE DATABASE auto_test_remote;
USE auto_test_remote;
CREATE TABLE tbl_a (a FLOAT) ENGINE=SPIDER;
INSERT INTO tbl_a VALUES
(0xF5A7),(0xF5A8),(0xF5A9),(0xF5AA),(0xF5AB),(0xF5AC),(0xF5AD),(0xF5AE),
(0xF5A7),(0xF5A8),(0xF5A9),(0xF5AA),(0xF5AB),(0xF5AC),(0xF5AD),(0xF5AE);
 
Warnings from just before the error:
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation
 
 - skipping '/var/tmp/mtr/4/log/spider/bugfix.mdev_27184/'
 
Test spider/bugfix.mdev_27184 has failed 2 times, no more retries!
 
worker[4] > Restart  - using different config file
spider/bugfix.mdev_27239                 w6 [ retry-fail ]
        Test ended at 2023-08-10 20:53:03
 
CURRENT_TEST: spider/bugfix.mdev_27239
--- /usr/share/mariadb-test/plugin/spider/spider/bugfix/r/mdev_27239.result	2023-06-05 20:45:45.000000000 +0200
+++ /usr/share/mariadb-test/plugin/spider/spider/bugfix/r/mdev_27239.reject	2023-08-10 20:53:03.133709092 +0200
@@ -9,10 +9,8 @@
 CREATE TABLE tbl_a (a INT) ENGINE=SPIDER;
 FLUSH TABLE tbl_a WITH READ LOCK;
 Warnings:
-Error	1429	Unable to connect to foreign data source: localhost
-Error	1429	Unable to connect to foreign data source: localhost
-Error	1429	Unable to connect to foreign data source: localhost
-Error	1429	Unable to connect to foreign data source: localhost
+Error	1044	Access denied for user ''@'localhost' to database 'auto_test_local'
+Error	1044	Access denied for user ''@'localhost' to database 'auto_test_local'
 BEGIN;
 DROP DATABASE auto_test_local;
 for master_1
 
mysqltest: Result length mismatch
 
 - skipping '/var/tmp/mtr/6/log/spider/bugfix.mdev_27239/'
 
Test spider/bugfix.mdev_27239 has failed 2 times, no more retries!
 
spider/bugfix.mdev_29008                 w3 [ pass ]    295
worker[6] > Restart  - using different config file
worker[3] > Restart [mysqld.1.1 - pid: 20445, winpid: 20445] - using different config file
worker[3] > Restart [mysqld.2.1 - pid: 20488, winpid: 20488] - using different config file
spider/bugfix.mdev_29011                 w7 [ pass ]    283
worker[7] > Restart [mysqld.1.1 - pid: 20496, winpid: 20496] - using different config file
worker[7] > Restart [mysqld.2.1 - pid: 20502, winpid: 20502] - using different config file
spider/bugfix.mdev_27240                 w2 [ retry-fail ]
        Test ended at 2023-08-10 20:53:03
 
CURRENT_TEST: spider/bugfix.mdev_27240
mysqltest: At line 18: query 'LOCK TABLE tbl_a READ' failed with wrong errno ER_SPECIFIC_ACCESS_DENIED_ERROR (1227): 'Access denied; you need (at least one of) the SUPER privilege(s) for this operation', instead of ER_CONNECT_TO_FOREIGN_DATA_SOURCE (1429)...
 
The result from queries just before the failure was:
for master_1
for child2
for child3
CREATE DATABASE auto_test_local;
USE auto_test_local;
CREATE TABLE tbl_a (a INT KEY) ENGINE=SPIDER;
SELECT a.z FROM tbl_a AS a,tbl_a b WHERE a.z=b.z;
ERROR 42S22: Unknown column 'a.z' in 'field list'
ALTER TABLE tbl_a CHANGE c c INT;
ERROR 42S22: Unknown column 'c' in 'tbl_a'
LOCK TABLE tbl_a READ;
 
Warnings from just before the error:
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation 
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation 
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation 
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation
 
 - skipping '/var/tmp/mtr/2/log/spider/bugfix.mdev_27240/'
 
Test spider/bugfix.mdev_27240 has failed 2 times, no more retries!
 
worker[2] > Restart  - using different config file
***Warnings generated in error logs during shutdown after running tests: spider/bugfix.mdev_27240
 
2023-08-10 20:53:03 6 [Warning] WSREP: handlerton rollback failed, thd 6 646 conf 0 SQL LOCK TABLE tbl_a READ
 
spider/bugfix.mdev_29484                 w1 [ fail ]
        Test ended at 2023-08-10 20:53:04
 
CURRENT_TEST: spider/bugfix.mdev_29484
mysqltest: At line 32: query 'LOCK TABLES tbl_b READ, tbl_a READ' failed with wrong errno ER_SPECIFIC_ACCESS_DENIED_ERROR (1227): 'Access denied; you need (at least one of) the SUPER privilege(s) for this operation', instead of ER_CONNECT_TO_FOREIGN_DATA_SOURCE (1429)...
 
The result from queries just before the failure was:
< snip >
child2_2
child2_3
for child3
connection child2_1;
CREATE DATABASE auto_test_remote;
USE auto_test_remote;
CREATE TABLE tbl_a (
a INT
) ENGINE=InnoDB DEFAULT CHARSET=utf8;
connection master_1;
CREATE DATABASE auto_test_local;
USE auto_test_local;
CREATE TABLE tbl_a (
a INT
) ENGINE=Spider DEFAULT CHARSET=utf8 COMMENT='table "tbl_a", srv "s_2_1"';
CREATE TABLE tbl_b (
a INT
) ENGINE=Spider DEFAULT CHARSET=utf8;
LOCK TABLES tbl_a WRITE;
LOCK TABLES tbl_b READ, tbl_a READ;
 
More results from queries before failure can be found in /var/tmp/mtr/1/log/mdev_29484.log
 
Warnings from just before the error:
Error 1044 Access denied for user ''@'localhost' to database 'auto_test_local' 
Error 1044 Access denied for user ''@'localhost' to database 'auto_test_local' 
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation 
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation 
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation 
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation
 
 - skipping '/var/tmp/mtr/1/log/spider/bugfix.mdev_29484/'
 
Retrying test spider/bugfix.mdev_29484, attempt(2/3)...
 
worker[1] > Restart  - not started
worker[1] > Restart  - not started
***Warnings generated in error logs during shutdown after running tests: spider/bugfix.mdev_29484
 
2023-08-10 20:53:04 6 [Warning] WSREP: handlerton rollback failed, thd 6 584 conf 0 SQL LOCK TABLES tbl_b READ, tbl_a READ
 
spider/bugfix.mdev_29562                 w8 [ pass ]    299
worker[8] > Restart [mysqld.1.1 - pid: 20922, winpid: 20922] - using different config file
worker[8] > Restart [mysqld.2.1 - pid: 20938, winpid: 20938] - using different config file
spider/bugfix.mdev_29653                 w4 [ pass ]    337
worker[4] > Restart [mysqld.1.1 - pid: 20959, winpid: 20959] - using different config file
worker[4] > Restart [mysqld.2.1 - pid: 21008, winpid: 21008] - using different config file
spider/bugfix.mdev_30191                 w6 [ pass ]    290
worker[6] > Restart [mysqld.1.1 - pid: 20992, winpid: 20992] - using different config file
worker[6] > Restart [mysqld.2.1 - pid: 21015, winpid: 21015] - using different config file
spider/bugfix.mdev_29644                 w5 [ pass ]    640
worker[5] > Restart [mysqld.1.1 - pid: 21033, winpid: 21033] - using different config file
worker[5] > Restart [mysqld.2.1 - pid: 21065, winpid: 21065] - using different config file
spider/bugfix.quick_mode_2               w2 [ pass ]    706
worker[2] > Restart [mysqld.1.1 - pid: 21014, winpid: 21014] - using different config file
worker[2] > Restart [mysqld.2.1 - pid: 21023, winpid: 21023] - using different config file
worker[2] > Restart [mysqld.2.2 - pid: 21037, winpid: 21037] - using different config file
spider/bugfix.quick_mode_0               w3 [ pass ]    658
worker[3] > Restart [mysqld.1.1 - pid: 21082, winpid: 21082] - using different config file
worker[3] > Restart [mysqld.2.1 - pid: 21099, winpid: 21099] - using different config file
worker[3] > Restart [mysqld.2.2 - pid: 21110, winpid: 21110] - using different config file
spider/bugfix.mdev_29484                 w1 [ retry-fail ]
        Test ended at 2023-08-10 20:53:14
 
CURRENT_TEST: spider/bugfix.mdev_29484
mysqltest: At line 32: query 'LOCK TABLES tbl_b READ, tbl_a READ' failed with wrong errno ER_SPECIFIC_ACCESS_DENIED_ERROR (1227): 'Access denied; you need (at least one of) the SUPER privilege(s) for this operation', instead of ER_CONNECT_TO_FOREIGN_DATA_SOURCE (1429)...
 
The result from queries just before the failure was:
< snip >
child2_2
child2_3
for child3
connection child2_1;
CREATE DATABASE auto_test_remote;
USE auto_test_remote;
CREATE TABLE tbl_a (
a INT
) ENGINE=InnoDB DEFAULT CHARSET=utf8;
connection master_1;
CREATE DATABASE auto_test_local;
USE auto_test_local;
CREATE TABLE tbl_a (
a INT
) ENGINE=Spider DEFAULT CHARSET=utf8 COMMENT='table "tbl_a", srv "s_2_1"';
CREATE TABLE tbl_b (
a INT
) ENGINE=Spider DEFAULT CHARSET=utf8;
LOCK TABLES tbl_a WRITE;
LOCK TABLES tbl_b READ, tbl_a READ;
 
More results from queries before failure can be found in /var/tmp/mtr/1/log/mdev_29484.log
 
Warnings from just before the error:
Error 1044 Access denied for user ''@'localhost' to database 'auto_test_local' 
Error 1044 Access denied for user ''@'localhost' to database 'auto_test_local' 
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation 
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation 
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation 
Error 1227 Access denied; you need (at least one of) the SUPER privilege(s) for this operation
 
 - skipping '/var/tmp/mtr/1/log/spider/bugfix.mdev_29484/'
 
Test spider/bugfix.mdev_29484 has failed 2 times, no more retries!
 
spider/bugfix.quick_mode_1               w7 [ pass ]    716
worker[1] > Restart  - using different config file
worker[1] > Restart  - using different config file
worker[7] > Restart [mysqld.1.1 - pid: 21088, winpid: 21088] - using different config file
worker[7] > Restart [mysqld.2.1 - pid: 21095, winpid: 21095] - using different config file
worker[7] > Restart [mysqld.2.2 - pid: 21104, winpid: 21104] - using different config file
***Warnings generated in error logs during shutdown after running tests: spider/bugfix.mdev_29484
 
2023-08-10 20:53:13 6 [Warning] WSREP: handlerton rollback failed, thd 6 729 conf 0 SQL LOCK TABLES tbl_b READ, tbl_a READ



 Comments   
Comment by Yuchen Pei [ 2023-08-22 ]

I could not reproduce it locally at the current 11.1
676a913c64431b7118295c8c1188c6329207dbda. I also made a trivial change
to see whether the tests fail in CI: https://github.com/MariaDB/server/commit/6de1e1da85d

...and it seems to pass in CI too.

Comment by Elena Stepanova [ 2023-09-23 ]

Looking at the test, I would guess that it attempts to connect to a server on a default socket (what would it be, /tmp/mysql.sock or something like that?) and expects there isn't one, but in Timofey's case it succeeds to find the server and instead fails to connect to it due to missing permissions.

Comment by Yuchen Pei [ 2024-02-01 ]

Given MDEV-33322 reports similar issues, I took a (another?) look into
the logs including mysqld.1.1.err files in
https://mdbe-ci-repo.mariadb.net/bb-logs/MariaDBServerCommunityProduction/11.1.1/rhel_7_gcp/mtr-psproto-test/22924/logs.tar.gz
but could not spot anything suspicious.

marcel, have you looked into the logs of these failures in your
test runs?

Comment by Marcel Telka [ 2024-02-01 ]

ycp, where exactly should I look? The test log is available here: https://telka.sk/illumos/MDEV-33322/2024-01-30-11:00.log . Should I look somewhere else too?

Comment by Yuchen Pei [ 2024-02-01 ]

Yes, the test log you referred to is the stdout of mtr. I was
referring to files under the var dir during the test (printed out
after "Creating var directory" in a test run, see below):

$ ./mysql-test/mtr --suite spider,spider/*,spider/*/* --skip-test="spider/oracle.*|.*/t\..*" --parallel=6 --big-test --force --max-test-fail=0
Logging: /home/ycp/source/mariadb-server/10.5/src/mysql-test/mysql-test-run.pl  --suite spider,spider/*,spider/*/* --skip-test=spider/oracle.*|.*/t\..* --parallel=6 --big-test --force --max-test-fail=0
VS config: 
vardir: /home/ycp/source/mariadb-server/10.5/build/mysql-test/var
Checking leftover processes...
Removing old var directory...
 - WARNING: Using the 'mysql-test/var' symlink
Creating var directory '/home/ycp/source/mariadb-server/10.5/build/mysql-test/var'...

In particular, the server logs are $worker_num/log/mysqld.X.Y.err
files under the var dir. Sometimes they provide extra info about what
went wrong. One can also grep for e.g.
"CURRENT_TESTS: spider/bugfix.mdev_26544"
in the var dir for such logs.

Comment by Marcel Telka [ 2024-02-01 ]

For test spider/bugfix.mdev_27239 failing like this:

spider/bugfix.mdev_27239                 [ fail ]
        Test ended at 2024-02-02 00:48:29
 
CURRENT_TEST: spider/bugfix.mdev_27239
--- /data/builds/oi-userland/components/database/mariadb-106/mariadb-10.6.16/storage/spider/mysql-test/spider/bugfix/r/mdev_27239.result        Wed Nov  8 16:02:00 2023
+++ /data/builds/oi-userland/components/database/mariadb-106/mariadb-10.6.16/storage/spider/mysql-test/spider/bugfix/r/mdev_27239.reject        Fri Feb  2 00:48:29 2024
@@ -9,10 +9,8 @@
 CREATE TABLE tbl_a (a INT) ENGINE=SPIDER;
 FLUSH TABLE tbl_a WITH READ LOCK;
 Warnings:
-Error  1429    Unable to connect to foreign data source: localhost
-Error  1429    Unable to connect to foreign data source: localhost
-Error  1429    Unable to connect to foreign data source: localhost
-Error  1429    Unable to connect to foreign data source: localhost
+Error  1044    Access denied for user ''@'localhost' to database 'auto_test_local'
+Error  1044    Access denied for user ''@'localhost' to database 'auto_test_local'
 BEGIN;
 DROP DATABASE auto_test_local;
 for master_1
 
mysqltest: Result length mismatch
 
 - saving '/data/builds/oi-userland/components/database/mariadb-106/build/amd64/mysql-test/var/log/spider/bugfix.mdev_27239/' to '/data/builds/oi-userland/components/database/mariadb-106/build/amd64/mysql-test/var/log/bugfix.mdev_27239/'

I found this:

CURRENT_TEST: spider/bugfix.mdev_27239
$ /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd --defaults-group-suffix=.1.1 --defaults-file=/data/builds/oi-userland/components/database/mariadb-106/build/amd64/mysql-test/var/my.cnf --log-output=file --loose-innodb --loose-skip-performance-schema --core-file --loose-debug-sync-timeout=300
2024-02-02  0:48:29 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 32184)
2024-02-02  0:48:29 0 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
2024-02-02  0:48:29 0 [Note] Starting MariaDB 10.6.16-MariaDB-log source revision b83c379420a8846ae4b28768d3c81fa354cca056 as process 17791
2024-02-02  0:48:29 0 [Note] Plugin 'SEQUENCE' is disabled.
2024-02-02  0:48:29 0 [Note] InnoDB: Compressed tables use zlib 1.3.1
2024-02-02  0:48:29 0 [Note] InnoDB: Number of pools: 1
2024-02-02  0:48:29 0 [Note] InnoDB: Using generic crc32 instructions
2024-02-02  0:48:29 0 [Note] InnoDB: Initializing buffer pool, total size = 8388608, chunk size = 8388608
2024-02-02  0:48:29 0 [Note] InnoDB: Completed initialization of buffer pool
2024-02-02  0:48:29 0 [ERROR] InnoDB: Failed to set DIRECTIO_ON on file ./ibdata1; OPEN: Inappropriate ioctl for device, continuing anyway.
2024-02-02  0:48:29 0 [ERROR] InnoDB: Failed to set DIRECTIO_ON on file ./ibdata1; OPEN: Inappropriate ioctl for device, continuing anyway.
2024-02-02  0:48:29 0 [Note] InnoDB: 128 rollback segments are active.
2024-02-02  0:48:29 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2024-02-02  0:48:29 0 [ERROR] InnoDB: Failed to set DIRECTIO_ON on file ./ibtmp1; CREATE: Inappropriate ioctl for device, continuing anyway.
2024-02-02  0:48:29 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2024-02-02  0:48:29 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2024-02-02  0:48:29 0 [ERROR] InnoDB: Failed to set DIRECTIO_ON on file ./ibtmp1; OPEN: Inappropriate ioctl for device, continuing anyway.
2024-02-02  0:48:29 0 [Note] InnoDB: 10.6.16 started; log sequence number 43953; transaction id 16
2024-02-02  0:48:29 0 [Note] InnoDB: Loading buffer pool(s) from /tmp/var_auto_21Tl/mysqld.1.1/data/ib_buffer_pool
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_CMP_PER_INDEX' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_CMP' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'THREAD_POOL_WAITS' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'THREAD_POOL_QUEUES' is disabled.
2024-02-02  0:48:29 0 [ERROR] InnoDB: Failed to set DIRECTIO_ON on file ./mysql/innodb_table_stats.ibd; OPEN: Inappropriate ioctl for device, continuing anyway.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_BUFFER_PAGE_LRU' is disabled.
2024-02-02  0:48:29 0 [ERROR] InnoDB: Failed to set DIRECTIO_ON on file ./mysql/innodb_index_stats.ibd; OPEN: Inappropriate ioctl for device, continuing anyway.
2024-02-02  0:48:29 0 [ERROR] InnoDB: Failed to set DIRECTIO_ON on file ./mysql/transaction_registry.ibd; OPEN: Inappropriate ioctl for device, continuing anyway.
2024-02-02  0:48:29 0 [Note] Plugin 'FEEDBACK' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_CMPMEM' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'THREAD_POOL_GROUPS' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_SYS_FOREIGN_COLS' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_BUFFER_POOL_STATS' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_SYS_FOREIGN' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_SYS_TABLES' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.
2024-02-02  0:48:29 0 [Note] InnoDB: Buffer pool(s) load completed at 240202  0:48:29
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_SYS_VIRTUAL' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'user_variables' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'THREAD_POOL_STATS' is disabled.
2024-02-02  0:48:29 0 [Note] Plugin 'unix_socket' is disabled.
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown variable 'loose-feedback-debug-startup-interval=20'
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown variable 'loose-feedback-debug-first-interval=60'
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown variable 'loose-feedback-debug-interval=60'
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown option '--loose-pam-debug'
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown option '--loose-aria'
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown variable 'loose_handlersocket_port=20000'
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown variable 'loose_handlersocket_port_wr=20001'
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown variable 'loose_handlersocket_threads=2'
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown variable 'loose_handlersocket_threads_wr=1'
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown variable 'loose_handlersocket_support_merge_table=0'
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown variable 'loose_handlersocket_direct_update_mode=2'
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown variable 'loose_handlersocket_unlimited_boundary=65536'
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown variable 'loose_handlersocket_bulk_insert=0'
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown variable 'loose_handlersocket_bulk_insert_timeout=0'
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown variable 'loose_handlersocket_general_log=1'
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown variable 'loose_handlersocket_timeout=30'
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown variable 'loose_handlersocket_close_table_interval=2'
2024-02-02  0:48:29 0 [Warning] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: unknown variable 'loose-debug-sync-timeout=300'
2024-02-02  0:48:29 0 [Note] Server socket created on IP: '127.0.0.1'.
2024-02-02  0:48:29 0 [Note] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: ready for connections.
Version: '10.6.16-MariaDB-log'  socket: '/tmp/ywp0bZBUnR/mysqld.1.1.sock'  port: 16000  OpenIndiana package
2024-02-02  0:48:29 0 [Note] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd (initiated by: unknown): Normal shutdown
2024-02-02  0:48:29 0 [Note] InnoDB: FTS optimize thread exiting.
2024-02-02  0:48:29 0 [Note] InnoDB: Starting shutdown...
2024-02-02  0:48:29 0 [Note] InnoDB: Dumping buffer pool(s) to /tmp/var_auto_21Tl/mysqld.1.1/data/ib_buffer_pool
2024-02-02  0:48:29 0 [Note] InnoDB: Restricted to 126 pages due to innodb_buf_pool_dump_pct=25
2024-02-02  0:48:29 0 [Note] InnoDB: Buffer pool(s) dump completed at 240202  0:48:29
2024-02-02  0:48:29 0 [Note] InnoDB: Removed temporary tablespace data file: "./ibtmp1"
2024-02-02  0:48:29 0 [Note] InnoDB: Shutdown completed; log sequence number 44292; transaction id 17
2024-02-02  0:48:29 0 [Note] /data/builds/oi-userland/components/database/mariadb-106/build/amd64/sql/mariadbd: Shutdown complete

Is this what you were looking for?

Comment by Yuchen Pei [ 2024-02-05 ]

Thanks for the log file marcel. I don't see any issue with spider
there. Does the log look the same for the other failed test cases?

marko do you know what the innodb errors are about?

  2024-02-02  0:48:29 0 [ERROR] InnoDB: Failed to set DIRECTIO_ON on file ./mysql/transaction_registry.ibd; OPEN: Inappropriate ioctl for device, continuing anyway.

Comment by Marko Mäkelä [ 2024-02-05 ]

The DIRECTIO_ON messages are the subject of MDEV-33095. I intend to revise this in MDEV-33379, that is, it will give Solaris and its derivatives (as well as IBM AIX) a chance to use O_DIRECT again. marcel, could you test that fix, once it is available?

Comment by Marcel Telka [ 2024-02-06 ]

> Does the log look the same for the other failed test cases?

Yes.

> could you test that fix, once it is available?

Yes, but please note I currently have easy access to 10.6.x environment only.

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