[MDEV-17896] Assertion `pfs->get_refcount() > 0' failed in release_table_share after a flow of DDL/DML - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 10.4(EOL)
Fix Version/s: 10.2.28, 10.1.43, 10.3.19, 10.4.9
Component/s: Admin statements, Server
Labels:
None

Description

Notes:
The attached test case is for reproducing/debugging only, do not put it into the regression suite, create a proper one instead.
The test case is ~800 queries consisting of seemingly random DDL and some DML. Some of queries are supposed to fail and do fail, which is why the test case starts with --disable_abort_on_error. Yet, I cannot remove anything from there, including the failing statements.
The test fails for me every time, but if it doesn't for you, run with --repeat=N, it can still be non-deterministic, even though there is no obvious concurrency involved.
Run in shm. The failure happens when it runs on disk, too, but it takes forever on disk (e.g. on my machine ~10 minutes on disk vs ~17 seconds in shm).
Not reproducible on 10.3, although it's possible that the test case is just not good enough for 10.3.
There is no crash or on a non-debug version; otherwise whether it behaves correctly or not, is hard to tell with such a test case.

10.4 790b6f5a
mysqld: /data/src/10.4/storage/perfschema/pfs_instr_class.cc:1380: void release_table_share(PFS_table_share*): Assertion `pfs->get_refcount() > 0' failed.
190219 20:21:39 [ERROR] mysqld got signal 6 ;

#7 0x00007f8bc86b5ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
#8 0x000055fc4651b46c in release_table_share (pfs=0x7f8bc7cd6bc0) at /data/src/10.4/storage/perfschema/pfs_instr_class.cc:1380
#9 0x000055fc46540fa2 in release_table_share_v1 (share=0x7f8bc7cd6bc0) at /data/src/10.4/storage/perfschema/pfs.cc:1586
#10 0x000055fc461465d2 in tdc_delete_share_from_hash (element=0x7f8b70413f00) at /data/src/10.4/sql/table_cache.cc:518
#11 0x000055fc46146f60 in tdc_purge (all=true) at /data/src/10.4/sql/table_cache.cc:722
#12 0x000055fc45e408ea in purge_tables (purge_flag=false) at /data/src/10.4/sql/sql_base.cc:337
#13 0x000055fc45e409fa in close_cached_tables (thd=0x7f8b68000b00, tables=0x0, wait_for_refresh=true, timeout=86400) at /data/src/10.4/sql/sql_base.cc:364
#14 0x000055fc460877da in reload_acl_and_cache (thd=0x7f8b68000b00, options=4, tables=0x0, write_to_binlog=0x7f8bc006e9d0) at /data/src/10.4/sql/sql_reload.cc:339
#15 0x000055fc45ee7453 in mysql_execute_command (thd=0x7f8b68000b00) at /data/src/10.4/sql/sql_parse.cc:5677
#16 0x000055fc45eeefa0 in mysql_parse (thd=0x7f8b68000b00, rawbuf=0x7f8b68013e38 "FLUSH TABLES", length=12, parser_state=0x7f8bc006f1f0, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8129
#17 0x000055fc45eda6da in dispatch_command (command=COM_QUERY, thd=0x7f8b68000b00, packet=0x7f8b6800a4c1 "FLUSH TABLES", packet_length=12, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1808
#18 0x000055fc45ed8fe4 in do_command (thd=0x7f8b68000b00) at /data/src/10.4/sql/sql_parse.cc:1358
#19 0x000055fc4604e247 in do_handle_one_connection (connect=0x55fc498cc1e0) at /data/src/10.4/sql/sql_connect.cc:1399
#20 0x000055fc4604dfb8 in handle_one_connection (arg=0x55fc498cc1e0) at /data/src/10.4/sql/sql_connect.cc:1302
#21 0x000055fc46541753 in pfs_spawn_thread (arg=0x55fc4992e370) at /data/src/10.4/storage/perfschema/pfs.cc:1862
#22 0x00007f8bca38c494 in start_thread (arg=0x7f8bc0070700) at pthread_create.c:333
#23 0x00007f8bc877293f in clone () from /lib/x86_64-linux-gnu/libc.so.6

Attachments

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

mdev17896.test
92 kB
2019-02-19 18:29

Activity

Ascending order - Click to sort in descending order

Elena Stepanova created issue - 2018-12-04 11:58

Elena Stepanova made changes - 2018-12-04 11:58

Field	Original Value	New Value
Summary	[Draft]	[Draft] Assertion `pfs->get_refcount() > 0' failed in

Elena Stepanova made changes - 2018-12-04 11:59

Summary

[Draft] Assertion `pfs->get_refcount() > 0' failed in

[Draft] Assertion `pfs->get_refcount() > 0' failed in release_table_share

Elena Stepanova made changes - 2018-12-04 15:11

Assignee

Elena Stepanova [ elenst ]

Elena Stepanova made changes - 2018-12-06 19:48

Affects Version/s

10.4 [ 22408 ]

Elena Stepanova made changes - 2019-02-19 18:31

Attachment		mdev17896.test [ 47450 ]
Component/s		Admin statements [ 11400 ]
Component/s		Server [ 13907 ]
Fix Version/s		10.4 [ 22408 ]
Assignee	Elena Stepanova [ elenst ]	Sergey Vojtovich [ svoj ]
Description	{noformat:title=10.4 f89a27b4e5} mysqld: /data/src/10.4/storage/perfschema/pfs_instr_class.cc:1380: void release_table_share(PFS_table_share): Assertion `pfs->get_refcount() > 0' failed. 181204 13:56:28 [ERROR] mysqld got signal 6 ; #7 0x00007f10cfedfee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6 #8 0x000055a626f46916 in release_table_share (pfs=0x7f10cf4cf640) at /data/src/10.4/storage/perfschema/pfs_instr_class.cc:1380 #9 0x000055a626f6bbf1 in release_table_share_v1 (share=0x7f10cf4cf640) at /data/src/10.4/storage/perfschema/pfs.cc:1586 #10 0x000055a626b8cedc in tdc_delete_share_from_hash (element=0x7f101c10e290) at /data/src/10.4/sql/table_cache.cc:518 #11 0x000055a626b8e6d9 in tdc_release_share (share=0x7f10280adaa8) at /data/src/10.4/sql/table_cache.cc:996 #12 0x000055a626b8bed1 in intern_close_table (table=0x7f10282150a0) at /data/src/10.4/sql/table_cache.cc:223 #13 0x000055a626b8c2dc in tc_purge (mark_flushed=true) at /data/src/10.4/sql/table_cache.cc:335 #14 0x000055a6268b9c5c in close_cached_tables (thd=0x7f1014000b00, tables=0x0, wait_for_refresh=true, timeout=5) at /data/src/10.4/sql/sql_base.cc:377 #15 0x000055a626af06db in reload_acl_and_cache (thd=0x7f1014000b00, options=4, tables=0x0, write_to_binlog=0x7f10c804ffe0) at /data/src/10.4/sql/sql_reload.cc:344 #16 0x000055a626959939 in mysql_execute_command (thd=0x7f1014000b00) at /data/src/10.4/sql/sql_parse.cc:5627 #17 0x000055a626960d5e in mysql_parse (thd=0x7f1014000b00, rawbuf=0x7f1014013998 "FLUSH TABLES / QNO 5789 CON_ID 20 /", length=37, parser_state=0x7f10c8050600, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8092 #18 0x000055a62694e04c in dispatch_command (command=COM_QUERY, thd=0x7f1014000b00, packet=0x7f101400b311 "FLUSH TABLES / QNO 5789 CON_ID 20 / ", packet_length=38, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1851 #19 0x000055a62694ca70 in do_command (thd=0x7f1014000b00) at /data/src/10.4/sql/sql_parse.cc:1396 #20 0x000055a626ab813e in do_handle_one_connection (connect=0x55a629374950) at /data/src/10.4/sql/sql_connect.cc:1402 #21 0x000055a626ab7ec2 in handle_one_connection (arg=0x55a629374950) at /data/src/10.4/sql/sql_connect.cc:1308 #22 0x000055a626f6c3a2 in pfs_spawn_thread (arg=0x55a629fc4c40) at /data/src/10.4/storage/perfschema/pfs.cc:1862 Trying to get some variables. Some pointers may be invalid and cause the dump to abort. Query (0x7f1014013998): FLUSH TABLES / QNO 5789 CON_ID 20 */ Connection ID (thread ID): 20 Status: NOT_KILLED {noformat} Reproducible locally with the test below, but needs some simplification and check for other versions. {noformat:title=https://github.com/MariaDB/randgen --branch elenst-dev b1facb0360} perl ./runall-new.pl --basedir=/data/bld/10.4 --vardir=/dev/shm/vardir --duration=350 --threads=6 --seed=1543872820 --reporters=Backtrace,ErrorLog,Deadlock --redefine=conf/mariadb/alter_table.yy --redefine=conf/mariadb/instant_add.yy --redefine=conf/mariadb/bulk_insert.yy --redefine=conf/mariadb/versioning.yy --redefine=conf/mariadb/sequences.yy --redefine=conf/mariadb/redefine_temporary_tables.yy --mysqld=--log_output=FILE --mysqld=--max-statement-time=30 --mysqld=--lock-wait-timeout=5 --mysqld=--loose-innodb-lock-wait-timeout=3 --mysqld=--loose-debug_assert_on_not_freed_memory=0 --grammar=conf/runtime/performance_schema.yy --mysqld=--performance-schema --engine=InnoDB {noformat}	Notes: The attached test case is for reproducing/debugging only, do not put it into the regression suite, create a proper one instead. The test case is ~800 queries consisting of seemingly random DDL and some DML. Some of queries are supposed to fail and do fail, which is why the test case starts with {{--disable_abort_on_error}}. Yet, I cannot remove anything from there, including the failing statements. The test fails for me every time, but if it doesn't for you, run with {{--repeat=N}}, it can still be non-deterministic, even though there is no obvious concurrency involved. Run in shm. The failure happens when it runs on disk, too, but it takes forever on disk (e.g. on my machine ~10 minutes on disk vs ~17 seconds in shm). Not reproducible on 10.3, although it's possible that the test case is just not good enough for 10.3. There is no crash or on a non-debug version; otherwise whether it behaves correctly or not, is hard to tell with such a test case. {noformat:title=10.4 790b6f5a} mysqld: /data/src/10.4/storage/perfschema/pfs_instr_class.cc:1380: void release_table_share(PFS_table_share*): Assertion `pfs->get_refcount() > 0' failed. 190219 20:21:39 [ERROR] mysqld got signal 6 ; #7 0x00007f8bc86b5ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6 #8 0x000055fc4651b46c in release_table_share (pfs=0x7f8bc7cd6bc0) at /data/src/10.4/storage/perfschema/pfs_instr_class.cc:1380 #9 0x000055fc46540fa2 in release_table_share_v1 (share=0x7f8bc7cd6bc0) at /data/src/10.4/storage/perfschema/pfs.cc:1586 #10 0x000055fc461465d2 in tdc_delete_share_from_hash (element=0x7f8b70413f00) at /data/src/10.4/sql/table_cache.cc:518 #11 0x000055fc46146f60 in tdc_purge (all=true) at /data/src/10.4/sql/table_cache.cc:722 #12 0x000055fc45e408ea in purge_tables (purge_flag=false) at /data/src/10.4/sql/sql_base.cc:337 #13 0x000055fc45e409fa in close_cached_tables (thd=0x7f8b68000b00, tables=0x0, wait_for_refresh=true, timeout=86400) at /data/src/10.4/sql/sql_base.cc:364 #14 0x000055fc460877da in reload_acl_and_cache (thd=0x7f8b68000b00, options=4, tables=0x0, write_to_binlog=0x7f8bc006e9d0) at /data/src/10.4/sql/sql_reload.cc:339 #15 0x000055fc45ee7453 in mysql_execute_command (thd=0x7f8b68000b00) at /data/src/10.4/sql/sql_parse.cc:5677 #16 0x000055fc45eeefa0 in mysql_parse (thd=0x7f8b68000b00, rawbuf=0x7f8b68013e38 "FLUSH TABLES", length=12, parser_state=0x7f8bc006f1f0, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8129 #17 0x000055fc45eda6da in dispatch_command (command=COM_QUERY, thd=0x7f8b68000b00, packet=0x7f8b6800a4c1 "FLUSH TABLES", packet_length=12, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1808 #18 0x000055fc45ed8fe4 in do_command (thd=0x7f8b68000b00) at /data/src/10.4/sql/sql_parse.cc:1358 #19 0x000055fc4604e247 in do_handle_one_connection (connect=0x55fc498cc1e0) at /data/src/10.4/sql/sql_connect.cc:1399 #20 0x000055fc4604dfb8 in handle_one_connection (arg=0x55fc498cc1e0) at /data/src/10.4/sql/sql_connect.cc:1302 #21 0x000055fc46541753 in pfs_spawn_thread (arg=0x55fc4992e370) at /data/src/10.4/storage/perfschema/pfs.cc:1862 #22 0x00007f8bca38c494 in start_thread (arg=0x7f8bc0070700) at pthread_create.c:333 #23 0x00007f8bc877293f in clone () from /lib/x86_64-linux-gnu/libc.so.6 {noformat}
Summary	[Draft] Assertion `pfs->get_refcount() > 0' failed in release_table_share	Assertion `pfs->get_refcount() > 0' failed in release_table_share after a flow of DDL/DML

Elena Stepanova made changes - 2019-02-19 18:31

Comment

[ New occurrence:
https://travis-ci.org/elenst/travis-tests/jobs/492700867 [2745 3 2] ]

Elena Stepanova made changes - 2019-02-19 18:31

Comment

[ New occurrences:
https://travis-ci.org/elenst/travis-tests/jobs/487850549 [2658 3 4]
https://travis-ci.org/elenst/travis-tests/jobs/487850548 [2658 2 3] ]

Elena Stepanova made changes - 2019-02-19 18:31

Comment

[ New occurrence: https://travis-ci.org/elenst/travis-tests/jobs/485394926 [2617 2 4] ]

Elena Stepanova made changes - 2019-02-19 18:32

Comment

[ New occurrence: https://travis-ci.org/elenst/travis-tests/jobs/483888921 [2573 3 3] ]

Elena Stepanova made changes - 2019-02-19 18:32

Comment

[ More occurrences:
https://travis-ci.org/elenst/travis-tests/jobs/481744471
https://travis-ci.org/elenst/travis-tests/jobs/481744470 ]

Elena Stepanova made changes - 2019-02-19 18:32

Comment

[ New occurrence: https://travis-ci.org/elenst/travis-tests/jobs/481356189 ]

Elena Stepanova made changes - 2019-02-19 18:32

Comment

[ New occurrence: https://travis-ci.org/elenst/travis-tests/jobs/480867195 ]

Sergey Vojtovich made changes - 2019-06-05 18:31

Assignee

Sergey Vojtovich [ svoj ]

Robert Bindar [ robertbindar ]

Robert Bindar made changes - 2019-10-09 09:12

Status

Open [ 1 ]

In Progress [ 3 ]

Robert Bindar made changes - 2019-10-09 09:12

Assignee	Robert Bindar [ robertbindar ]	Sergey Vojtovich [ svoj ]
Status	In Progress [ 3 ]	In Review [ 10002 ]

Sergey Vojtovich added a comment - 2019-10-09 15:39

Changes requested on zulip.

Sergey Vojtovich added a comment - 2019-10-09 15:39 Changes requested on zulip.

Sergey Vojtovich made changes - 2019-10-09 15:39

Assignee	Sergey Vojtovich [ svoj ]	Robert Bindar [ robertbindar ]
Status	In Review [ 10002 ]	Stalled [ 10000 ]

Robert Bindar made changes - 2019-11-01 09:31

Fix Version/s		10.1.43 [ 23703 ]
Fix Version/s	10.4 [ 22408 ]
Resolution		Fixed [ 1 ]
Status	Stalled [ 10000 ]	Closed [ 6 ]

Robert Bindar made changes - 2019-11-01 09:46

Fix Version/s		10.2.28 [ 23910 ]
Fix Version/s		10.3.19 [ 23908 ]
Fix Version/s		10.4.9 [ 23906 ]

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

Workflow

MariaDB v3 [ 91038 ]

MariaDB v4 [ 155306 ]

People

Assignee:: Robert Bindar

Reporter:: Elena Stepanova

Votes:: 0 Vote for this issue

Watchers:: 4 Start watching this issue

Dates

Created:: 2018-12-04 11:58

Updated:: 2019-11-01 09:46

Resolved:: 2019-11-01 09:31

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

Activity

People

Dates

Git Integration