Bug #71092 InnoDB FTS introduced new mutex sync level in 5.6.15, broke UNIV_SYNC_DEBUG
Submitted: 5 Dec 2013 13:06 Modified: 3 Feb 2014 11:34
Reporter: Laurynas Biveinis (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S2 (Serious)
Version:5.6.15 OS:Any
Assigned to: CPU Architecture:Any
Tags: fts, innodb, mutex, UNIV_SYNC_DEBUG

[5 Dec 2013 13:06] Laurynas Biveinis
Description:
After bug 69617 was introduced (where UNIV_SYNC_DEBUG appears to be unconditionally removed from UNIV_DEBUG by mistake), it was only a matter of time before UNIV_SYNC_DEBUG started bitrotting.  This happened with 5.6.15 revision [1] that introduced a new sync level, SYNC_FTS_TOKENIZE, but did not add its handling to sync_thread_add_level().

Thus, if bug 69617 is fixed and debug server is built, a server crashes every time the FTS parallel tokenization thread is created.  In MTR this is seen as crashes on 

    main.alter_table innodb_fts.fulltext
    innodb_fts.innodb_fts_large_records innodb_fts.innodb_fts_misc
    innodb_fts.innodb_fts_misc_1 innodb_fts.innodb_fts_multiple_index
    innodb_fts.innodb_fts_proximity innodb_fts.innodb_fts_transaction
    innodb.innodb-alter innodb_fts.innobase_drop_fts_index_table
    innodb_fts.innodb-fts-ddl innodb_fts.innodb-fts-fic
    innodb_fts.innodb-fts-stopword innodb_fts.innodb_fts_index_table
    innodb_fts.innodb_fts_misc_debug
    innodb_fts.innodb_fts_result_cache_limit
    innodb_fts.innodb_fts_stopword_charset innodb.innodb-wl5980-alter

Sample crash stacktrace:

Thread 1 (Thread 0x7f9520ff9700 (LWP 11184)):
#0  0x00007f953683ef0c in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:62
#1  0x0000000000aa8cc9 in my_write_core (sig=6) at /home/laurynas/percona/src/5.6/mysys/stacktrace.c:422
#2  0x000000000071a613 in handle_fatal_signal (sig=6) at /home/laurynas/percona/src/5.6/sql/signal_handler.cc:248
#3  <signal handler called>
#4  0x00007f9535c82f77 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#5  0x00007f9535c865e8 in __GI_abort () at abort.c:90
#6  0x0000000000ce9df5 in sync_thread_add_level (latch=0x7f9510033298, level=167, relock=0) at /home/laurynas/percona/src/5.6/storage/innobase/sync/sync0sync.cc:1311
#7  0x0000000000ce86b9 in mutex_set_debug_info (mutex=0x7f9510033298, file_name=0x10449b0 "/home/laurynas/percona/src/5.6/storage/innobase/row/row0ftsort.cc", line=565) at /home/laurynas/percona/src/5.6/storage/innobase/sync/sync0sync.cc:614
#8  0x0000000000c56597 in mutex_enter_func (mutex=0x7f9510033298, file_name=0x10449b0 "/home/laurynas/percona/src/5.6/storage/innobase/row/row0ftsort.cc", line=565) at /home/laurynas/percona/src/5.6/storage/innobase/include/sync0sync.ic:215
#9  0x0000000000c56622 in pfs_mutex_enter_func (mutex=0x7f9510033298, file_name=0x10449b0 "/home/laurynas/percona/src/5.6/storage/innobase/row/row0ftsort.cc", line=565) at /home/laurynas/percona/src/5.6/storage/innobase/include/sync0sync.ic:245
#10 0x0000000000c59065 in row_merge_fts_get_next_doc_item (psort_info=0x7f9510033188, doc_item=0x7f9520ff8cd0) at /home/laurynas/percona/src/5.6/storage/innobase/row/row0ftsort.cc:565
#11 0x0000000000c5937a in fts_parallel_tokenization (arg=0x7f9510033188) at /home/laurynas/percona/src/5.6/storage/innobase/row/row0ftsort.cc:635
#12 0x00007f9536839f6e in start_thread (arg=0x7f9520ff9700) at pthread_create.c:311
#13 0x00007f9535d469cd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

[1]

5.6$ bzr log -r 5499
------------------------------------------------------------
revno: 5499
committer: Shaohua Wang <shaohua.wang@oracle.com>
branch nick: mysql-5.6-bug17384979
timestamp: Tue 2013-10-08 11:22:51 +0800
message:
  BUG 17384979 - YIELD ON SCANNER THREAD FOR PARALLEL FTS INDEX CREATE TO MINIMIZE MEMORY USAGE
  
  Solution:
  1. Let scanner thread sleep for a while if fts_doc_list memory exceeds the limit;
  2. Free doc_item once it's tokenized(a mutex is created to protect fts_doc_list).
  
  rb#3335 approved by Jimmy.Yang

How to repeat:
Remove the #undef UNIV_SYNC_DEBUG line from univ.i
Build debug server
Run any of the above testcases

Suggested fix:
Fix bug 69617, add SYNC_FTS_TOKENIZE case to sync_thread_add_level().
[5 Dec 2013 13:08] Laurynas Biveinis
Bug 69617 and 71092 patch

(*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: 69617-71092.patch (text/x-patch), 726 bytes.

[5 Dec 2013 13:11] Laurynas Biveinis
A trivial patch uploaded.  It fixes all the testsuite failures. I am not sure whether it's fully correct, because I didn't analyze whether it is possible for several SYNC_FTS_TOKENIZE mutexes to be locked simultaneously.
[5 Dec 2013 13:57] Umesh Shastry
Hello Laurynas,

Thank you for the bug report and contribution.
Verified as described.

Thanks,
Umesh
[20 Dec 2013 11:10] Erlend Dahl
Fixed along with Bug#69617 5.6.12 removed UNIV_SYNC_DEBUG from UNIV_DEBUG
[3 Feb 2014 11:34] Laurynas Biveinis
5.6$ bzr log -r 5688
------------------------------------------------------------
revno: 5688
committer: Shaohua Wang <shaohua.wang@oracle.com>
branch nick: mysql-5.6-bugfix1
timestamp: Fri 2013-12-13 17:56:54 +0800
message:
  Bug#17033591 5.6.12 REMOVED UNIV_SYNC_DEBUG FROM UNIV_DEBUG
  
  Enable UNIV_SYNC_DEBUG and fix fts test failures.
  
  rb://4139 approved by Marko and Jimmy.