[MDEV-24485] galera.galera_bf_kill_debug MTR failed: A long semaphore wait - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 10.5.9, 10.4(EOL), 10.6
Fix Version/s: 10.6.22, 10.11.12, 11.4.6, 11.8.2
Component/s: Galera, Tests
Labels:
None
Environment:
kvm-rpm-centos74-amd64-debug

Description

galera.galera_bf_kill_debug failed on BB 10.5 CS: "A long semaphore wait".
It seems to be a sporadic issue.

10.5.9, 39378e1366f78b38c05e45103b9fb9c829cc5f4f, kvm-rpm-centos74-amd64-debug
galera.galera_bf_kill_debug 'innodb' w2 [ fail ] Found warnings/errors in server log file!
Test ended at 2020-12-21 19:46:40
line
2020-12-21 19:45:52 0 [Warning] InnoDB: A long semaphore wait:
2020-12-21 19:46:07 0 [Warning] InnoDB: A long semaphore wait:
2020-12-21 19:46:22 0 [Warning] InnoDB: A long semaphore wait:
2020-12-21 19:46:37 0 [Warning] InnoDB: A long semaphore wait:
^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
ok

- skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'

Retrying test galera.galera_bf_kill_debug, attempt(2/3)...

worker[2] > Restart - not started
worker[2] > Restart - not started

10.5 Server logs.

But on BB 10.6 CS it failed with another output: "safe_mutex: Found wrong usage of mutex 'LOCK_thd_kill' and 'mutex'".

stdio.log:

10.6.0, 30dc4287ec3d46bae7593f56383b9f3738e3c4e6, kvm-rpm-centos74-amd64-debug
galera.galera_bf_kill_debug 'innodb' w2 [ fail ] Found warnings/errors in server log file!
Test ended at 2020-12-19 12:47:06
line
safe_mutex: Found wrong usage of mutex 'LOCK_thd_kill' and 'mutex'
^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
ok

- skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'

Retrying test galera.galera_bf_kill_debug, attempt(2/3)...

worker[2] > Restart - not started
worker[2] > Restart - not started
galera.galera_bf_kill_debug 'innodb' w2 [ retry-pass ] 2059

Retrying test galera.galera_bf_kill_debug, attempt(3/3)...

galera.galera_bf_kill_debug 'innodb' w2 [ retry-fail ] Found warnings/errors in server log file!
Test ended at 2020-12-19 12:47:14
line
safe_mutex: Found wrong usage of mutex 'mutex' and 'LOCK_thd_data'
^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
ok

- skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'
worker[2] > Restart - using different config file
worker[2] > Restart - using different config file

10.6 Server logs.

Attachments

- Sort By Name
- Sort By Date
- Ascending
- Descending
- Thumbnails
- List
- Download All

MDEV-24485_105_logs_201221.zip
896 kB
2020-12-23 21:32
MDEV-24485_106_logs_201219.zip
872 kB
2020-12-23 21:32

Issue Links

blocks

MDEV-22122 Galera test failures on 10.5

Open

Activity

Ascending order - Click to sort in descending order

Stepan Patryshev (Inactive) created issue - 2020-12-23 21:29

Stepan Patryshev (Inactive) made changes - 2020-12-23 21:29

Field	Original Value	New Value
Link		This issue blocks MDEV-22122 [ MDEV-22122 ]

Stepan Patryshev (Inactive) made changes - 2020-12-23 21:32

Attachment		MDEV-24485_106_logs_201219.zip [ 55455 ]
Attachment		MDEV-24485_105_logs_201221.zip [ 55456 ]

Stepan Patryshev (Inactive) made changes - 2020-12-23 21:32

Description

galera.galera_bf_kill_debug failed on [BB 10.5 CS|http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/5475]: "A long semaphore wait".
It seems to be a sporadic issue.

[stdio.log|http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/5475/steps/mtr-galera/logs/stdio]:
{code:title=10.5.9, 39378e1366f78b38c05e45103b9fb9c829cc5f4f, kvm-rpm-centos74-amd64-debug}
galera.galera_bf_kill_debug 'innodb' w2 [ fail ] Found warnings/errors in server log file!
        Test ended at 2020-12-21 19:46:40
line
2020-12-21 19:45:52 0 [Warning] InnoDB: A long semaphore wait:
2020-12-21 19:46:07 0 [Warning] InnoDB: A long semaphore wait:
2020-12-21 19:46:22 0 [Warning] InnoDB: A long semaphore wait:
2020-12-21 19:46:37 0 [Warning] InnoDB: A long semaphore wait:
^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
ok

- skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'

Retrying test galera.galera_bf_kill_debug, attempt(2/3)...

worker[2] > Restart - not started
worker[2] > Restart - not started
{code}

But on [BB 10.6 CS|http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/5471] it failed with another output: "safe_mutex: Found wrong usage of mutex 'LOCK_thd_kill' and 'mutex'".

[stdio.log|http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/5471/steps/mtr-galera/logs/stdio]:
{code:title=10.6.0, 30dc4287ec3d46bae7593f56383b9f3738e3c4e6, kvm-rpm-centos74-amd64-debug}
galera.galera_bf_kill_debug 'innodb' w2 [ fail ] Found warnings/errors in server log file!
        Test ended at 2020-12-19 12:47:06
line
safe_mutex: Found wrong usage of mutex 'LOCK_thd_kill' and 'mutex'
^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
ok

- skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'

Retrying test galera.galera_bf_kill_debug, attempt(2/3)...

worker[2] > Restart - not started
worker[2] > Restart - not started
galera.galera_bf_kill_debug 'innodb' w2 [ retry-pass ] 2059

Retrying test galera.galera_bf_kill_debug, attempt(3/3)...

galera.galera_bf_kill_debug 'innodb' w2 [ retry-fail ] Found warnings/errors in server log file!
        Test ended at 2020-12-19 12:47:14
line
safe_mutex: Found wrong usage of mutex 'mutex' and 'LOCK_thd_data'
^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
ok

- skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'
worker[2] > Restart - using different config file
worker[2] > Restart - using different config file
{code}

galera.galera_bf_kill_debug failed on [BB 10.5 CS|http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/5475]: "A long semaphore wait".
It seems to be a sporadic issue.

[stdio.log|http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/5475/steps/mtr-galera/logs/stdio]:
{code:title=10.5.9, 39378e1366f78b38c05e45103b9fb9c829cc5f4f, kvm-rpm-centos74-amd64-debug}
galera.galera_bf_kill_debug 'innodb' w2 [ fail ] Found warnings/errors in server log file!
        Test ended at 2020-12-21 19:46:40
line
2020-12-21 19:45:52 0 [Warning] InnoDB: A long semaphore wait:
2020-12-21 19:46:07 0 [Warning] InnoDB: A long semaphore wait:
2020-12-21 19:46:22 0 [Warning] InnoDB: A long semaphore wait:
2020-12-21 19:46:37 0 [Warning] InnoDB: A long semaphore wait:
^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
ok

- skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'

Retrying test galera.galera_bf_kill_debug, attempt(2/3)...

worker[2] > Restart - not started
worker[2] > Restart - not started
{code}

*[10.5 Server logs|^~~MDEV-24485~~_105_logs_201221.zip]*.

But on [BB 10.6 CS|http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/5471] it failed with another output: "safe_mutex: Found wrong usage of mutex 'LOCK_thd_kill' and 'mutex'".

[stdio.log|http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/5471/steps/mtr-galera/logs/stdio]:
{code:title=10.6.0, 30dc4287ec3d46bae7593f56383b9f3738e3c4e6, kvm-rpm-centos74-amd64-debug}
galera.galera_bf_kill_debug 'innodb' w2 [ fail ] Found warnings/errors in server log file!
        Test ended at 2020-12-19 12:47:06
line
safe_mutex: Found wrong usage of mutex 'LOCK_thd_kill' and 'mutex'
^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
ok

- skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'

Retrying test galera.galera_bf_kill_debug, attempt(2/3)...

worker[2] > Restart - not started
worker[2] > Restart - not started
galera.galera_bf_kill_debug 'innodb' w2 [ retry-pass ] 2059

Retrying test galera.galera_bf_kill_debug, attempt(3/3)...

galera.galera_bf_kill_debug 'innodb' w2 [ retry-fail ] Found warnings/errors in server log file!
        Test ended at 2020-12-19 12:47:14
line
safe_mutex: Found wrong usage of mutex 'mutex' and 'LOCK_thd_data'
^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
ok

- skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'
worker[2] > Restart - using different config file
worker[2] > Restart - using different config file
{code}

*[10.6 Server logs|^~~MDEV-24485~~_106_201219.zip]*.

Stepan Patryshev (Inactive) made changes - 2020-12-23 21:34

Description

galera.galera_bf_kill_debug failed on [BB 10.5 CS|http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/5475]: "A long semaphore wait".
It seems to be a sporadic issue.

[stdio.log|http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/5475/steps/mtr-galera/logs/stdio]:
{code:title=10.5.9, 39378e1366f78b38c05e45103b9fb9c829cc5f4f, kvm-rpm-centos74-amd64-debug}
galera.galera_bf_kill_debug 'innodb' w2 [ fail ] Found warnings/errors in server log file!
        Test ended at 2020-12-21 19:46:40
line
2020-12-21 19:45:52 0 [Warning] InnoDB: A long semaphore wait:
2020-12-21 19:46:07 0 [Warning] InnoDB: A long semaphore wait:
2020-12-21 19:46:22 0 [Warning] InnoDB: A long semaphore wait:
2020-12-21 19:46:37 0 [Warning] InnoDB: A long semaphore wait:
^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
ok

- skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'

Retrying test galera.galera_bf_kill_debug, attempt(2/3)...

worker[2] > Restart - not started
worker[2] > Restart - not started
{code}

*[10.5 Server logs|^~~MDEV-24485~~_105_logs_201221.zip]*.

But on [BB 10.6 CS|http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/5471] it failed with another output: "safe_mutex: Found wrong usage of mutex 'LOCK_thd_kill' and 'mutex'".

[stdio.log|http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/5471/steps/mtr-galera/logs/stdio]:
{code:title=10.6.0, 30dc4287ec3d46bae7593f56383b9f3738e3c4e6, kvm-rpm-centos74-amd64-debug}
galera.galera_bf_kill_debug 'innodb' w2 [ fail ] Found warnings/errors in server log file!
        Test ended at 2020-12-19 12:47:06
line
safe_mutex: Found wrong usage of mutex 'LOCK_thd_kill' and 'mutex'
^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
ok

- skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'

Retrying test galera.galera_bf_kill_debug, attempt(2/3)...

worker[2] > Restart - not started
worker[2] > Restart - not started
galera.galera_bf_kill_debug 'innodb' w2 [ retry-pass ] 2059

Retrying test galera.galera_bf_kill_debug, attempt(3/3)...

galera.galera_bf_kill_debug 'innodb' w2 [ retry-fail ] Found warnings/errors in server log file!
        Test ended at 2020-12-19 12:47:14
line
safe_mutex: Found wrong usage of mutex 'mutex' and 'LOCK_thd_data'
^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
ok

- skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'
worker[2] > Restart - using different config file
worker[2] > Restart - using different config file
{code}

*[10.6 Server logs|^~~MDEV-24485~~_106_201219.zip]*.

galera.galera_bf_kill_debug failed on [BB 10.5 CS|http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/5475]: "A long semaphore wait".
It seems to be a sporadic issue.

[stdio.log|http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/5475/steps/mtr-galera/logs/stdio]:
{code:title=10.5.9, 39378e1366f78b38c05e45103b9fb9c829cc5f4f, kvm-rpm-centos74-amd64-debug}
galera.galera_bf_kill_debug 'innodb' w2 [ fail ] Found warnings/errors in server log file!
        Test ended at 2020-12-21 19:46:40
line
2020-12-21 19:45:52 0 [Warning] InnoDB: A long semaphore wait:
2020-12-21 19:46:07 0 [Warning] InnoDB: A long semaphore wait:
2020-12-21 19:46:22 0 [Warning] InnoDB: A long semaphore wait:
2020-12-21 19:46:37 0 [Warning] InnoDB: A long semaphore wait:
^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
ok

- skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'

Retrying test galera.galera_bf_kill_debug, attempt(2/3)...

worker[2] > Restart - not started
worker[2] > Restart - not started
{code}

*[10.5 Server logs|^~~MDEV-24485~~_105_logs_201221.zip]*.

But on [BB 10.6 CS|http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/5471] it failed with another output: "safe_mutex: Found wrong usage of mutex 'LOCK_thd_kill' and 'mutex'".

[stdio.log|http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/5471/steps/mtr-galera/logs/stdio]:
{code:title=10.6.0, 30dc4287ec3d46bae7593f56383b9f3738e3c4e6, kvm-rpm-centos74-amd64-debug}
galera.galera_bf_kill_debug 'innodb' w2 [ fail ] Found warnings/errors in server log file!
        Test ended at 2020-12-19 12:47:06
line
safe_mutex: Found wrong usage of mutex 'LOCK_thd_kill' and 'mutex'
^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
ok

- skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'

Retrying test galera.galera_bf_kill_debug, attempt(2/3)...

worker[2] > Restart - not started
worker[2] > Restart - not started
galera.galera_bf_kill_debug 'innodb' w2 [ retry-pass ] 2059

Retrying test galera.galera_bf_kill_debug, attempt(3/3)...

galera.galera_bf_kill_debug 'innodb' w2 [ retry-fail ] Found warnings/errors in server log file!
        Test ended at 2020-12-19 12:47:14
line
safe_mutex: Found wrong usage of mutex 'mutex' and 'LOCK_thd_data'
^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
ok

- skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'
worker[2] > Restart - using different config file
worker[2] > Restart - using different config file
{code}

*[10.6 Server logs|^~~MDEV-24485~~_106_logs_201219.zip]*.

Stepan Patryshev (Inactive) made changes - 2020-12-23 21:34

Assignee

Stepan Patryshev [ stepan.patryshev ]

Jan Lindström [ jplindst ]

Marko Mäkelä made changes - 2021-03-19 09:42

Fix Version/s		10.4 [ 22408 ]
Affects Version/s		10.4 [ 22408 ]
Affects Version/s	10.6.0 [ 24431 ]

Marko Mäkelä made changes - 2021-03-19 09:50

Comment

[ This fails for me on 10.4:
{noformat}
galera.galera_bf_lock_wait 'innodb' w57 [ fail ]
Test ended at 2021-03-19 11:21:29

CURRENT_TEST: galera.galera_bf_lock_wait
mysqltest: At line 59: query 'do sleep($sleep_period)' failed: 2013: Lost connection to MySQL server during query
…
mysqld: /mariadb/10.4/wsrep-lib/src/transaction.cpp:123: int wsrep::transaction::start_transaction(const wsrep::transaction_id &): Assertion `active() == false' failed.
…
#7 0x00005604d6c942e6 in wsrep::transaction::start_transaction (this=0x7f5440008090, id=@0x7f54cc1acca8: {id_ = 5336}) at /mariadb/10.4/wsrep-lib/src/transaction.cpp:123
#8 0x00005604d6232fdc in wsrep::client_state::start_transaction (this=<optimized out>, this@entry=0x7f5440008028, id=@0x7f54cc1acca8: {id_ = 5336}) at /mariadb/10.4/wsrep-lib/include/wsrep/client_state.hpp:321
#9 0x00005604d642d743 in wsrep_start_transaction (thd=0x7f5440001e58, trx_id=0) at /mariadb/10.4/sql/wsrep_trans_observer.h:138
#10 wsrep_bf_abort (bf_thd=bf_thd@entry=0x7f54bc000d28, victim_thd=victim_thd@entry=0x7f5440001e58) at /mariadb/10.4/sql/wsrep_thd.cc:352
#11 0x00005604d64345ac in wsrep_thd_bf_abort (bf_thd=0x7f54bc000d28, victim_thd=0x7f5440001e58, signal=1 '\001') at /mariadb/10.4/sql/service_wsrep.cc:215
#12 0x00005604d66cbc9a in bg_wsrep_kill_trx (void_arg=0x7f54bc044790) at /mariadb/10.4/storage/innobase/handler/ha_innodb.cc:18779
#13 0x00005604d62586ce in handle_manager (arg=<optimized out>) at /mariadb/10.4/sql/sql_manager.cc:112
#14 0x00005604d6bcf016 in pfs_spawn_thread (arg=0x5604d9edc788) at /mariadb/10.4/storage/perfschema/pfs.cc:1869
#15 0x00007f54d9bfcea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
#16 0x00007f54d924edef in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
{noformat} ]

Jan Lindström (Inactive) made changes - 2021-04-13 06:05

Status

Open [ 1 ]

In Progress [ 3 ]

Jan Lindström (Inactive) made changes - 2021-04-15 04:39

Assignee

Jan Lindström [ jplindst ]

Seppo Jaakola [ seppo ]

Sergei Golubchik made changes - 2021-05-25 12:51

Fix Version/s

10.6 [ 24028 ]

Sergei Golubchik made changes - 2021-12-06 21:36

Workflow

MariaDB v3 [ 117350 ]

MariaDB v4 [ 144584 ]

JiraAutomate made changes - 2023-12-05 11:48

Status

In Progress [ 3 ]

Stalled [ 10000 ]

Julien Fritsch made changes - 2024-09-10 15:05

Fix Version/s

10.4 [ 22408 ]

Jan Lindström made changes - 2024-11-07 12:21

Assignee

Seppo Jaakola [ seppo ]

Jan Lindström [ JIRAUSER53125 ]

Jan Lindström made changes - 2024-11-07 12:21

Status

Stalled [ 10000 ]

In Progress [ 3 ]

Jan Lindström made changes - 2024-11-08 07:03

Affects Version/s

10.6 [ 24028 ]

Jan Lindström made changes - 2024-11-08 07:04

Fix Version/s

10.6 [ 24028 ]

Jan Lindström made changes - 2024-11-08 07:04

Fix Version/s

10.5 [ 23123 ]

Jan Lindström made changes - 2024-11-08 08:07

Assignee	Jan Lindström [ JIRAUSER53125 ]	Julius Goryavsky [ sysprg ]
Status	In Progress [ 3 ]	In Review [ 10002 ]

Julius Goryavsky made changes - 2025-02-03 12:37

Status

In Review [ 10002 ]

Stalled [ 10000 ]

Julius Goryavsky made changes - 2025-02-03 12:37

Status

Stalled [ 10000 ]

In Progress [ 3 ]

Julius Goryavsky made changes - 2025-02-03 12:38

Fix Version/s		10.6.22 [ 29997 ]
Fix Version/s		10.11.12 [ 29998 ]
Fix Version/s		11.4.6 [ 29999 ]
Fix Version/s	10.6 [ 24028 ]
Resolution		Fixed [ 1 ]
Status	In Progress [ 3 ]	Closed [ 6 ]

JiraAutomate made changes - 2025-02-03 12:38

Fix Version/s

11.8.2 [ 30001 ]

People

Assignee:: Julius Goryavsky

Reporter:: Stepan Patryshev (Inactive)

Votes:: 0 Vote for this issue

Watchers:: 6 Start watching this issue

Dates

Created:: 2020-12-23 21:29

Updated:: 2025-03-13 11:49

Resolved:: 2025-02-03 12:38

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.

MariaDB Server

Details

Description

Attachments

Attachments

Issue Links

Activity

People

Dates

Git Integration