Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-14154

Failing assertion: slot->last_run <= current_time in fts0opt.cc

    Details

      Description

      Note: The bug report was initially filed due to a buildbot failure on 10.0 tree. According to buildbot cross-reference, the test stopped failing some time at the end of 2017 – maybe the test has changed, or something else did. I'm keeping it here for the record though, the second part of the description relates to one of those old test failures.

      The first part is the same assertion failure which happened on the current 10.3 (as of 2018-06-20) during non-buildbot concurrent tests. It's not reproducible so far, but for it we have a full stack trace, coredump, binary, datadir and logs.

      Failure on current 10.3

      10.3 956b296248acbe35aa87f056ccf99dbb999eea02

      2018-06-20 04:01:30 0x7f9d927fc700  InnoDB: Assertion failure in file /home/travis/src/storage/innobase/fts/fts0opt.cc line 2844
      InnoDB: Failing assertion: slot->last_run <= current_time
       
      Thread 1 (Thread 0x7f9d927fc700 (LWP 23704)):
      #0  0x00007f9dc9dd4611 in pthread_kill () from /lib/x86_64-linux-gnu/libpthread.so.0
      #1  0x000055e3c07716a3 in my_write_core (sig=6) at /home/travis/src/mysys/stacktrace.c:481
      #2  0x000055e3bffc735f in handle_fatal_signal (sig=6) at /home/travis/src/sql/signal_handler.cc:305
      #3  <signal handler called>
      #4  0x00007f9dc9214c37 in raise () from /lib/x86_64-linux-gnu/libc.so.6
      #5  0x00007f9dc9218028 in abort () from /lib/x86_64-linux-gnu/libc.so.6
      #6  0x000055e3c0409095 in ut_dbg_assertion_failed (expr=0x55e3c0b185f8 "slot->last_run <= current_time", file=0x55e3c0b17a48 "/home/travis/src/storage/innobase/fts/fts0opt.cc", line=2844) at /home/travis/src/storage/innobase/ut/ut0dbg.cc:61
      #7  0x000055e3c054ff0f in fts_optimize_how_many (tables=0x55e3c2e16c98) at /home/travis/src/storage/innobase/fts/fts0opt.cc:2844
      #8  0x000055e3c0550522 in fts_optimize_thread (arg=0x55e3c2e109c0) at /home/travis/src/storage/innobase/fts/fts0opt.cc:3101
      #9  0x00007f9dc9dcf184 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
      #10 0x00007f9dc92dbffd in clone () from /lib/x86_64-linux-gnu/libc.so.6
      

      All threads' stack traces are attached as threads_full.
      Coredump, datadir etc. are available separately.

      Old innodb_fts.innodb-fts-fic failure on 10.0

      innodb_fts.innodb-fts-fic 'xtradb'       w1 [ fail ]
              Test ended at 2017-08-28 20:34:08
       
      CURRENT_TEST: innodb_fts.innodb-fts-fic
      mysqltest: At line 181: query 'CREATE FULLTEXT INDEX idx2 ON articles (body)' failed: 2013: Lost connection to MySQL server during query
       
      The result from queries just before the failure was:
      < snip >
      1	aaaa	DBMS stands for DataBase ...
      drop table articles;
      CREATE TABLE articles (
      FTS_DOC_ID BIGINT UNSIGNED NOT NULL ,
      title VARCHAR(200),
      body TEXT
      ) ENGINE=InnoDB;
      CREATE FULLTEXT INDEX idx on articles (title);
      INSERT INTO articles  VALUES (9, 'MySQL Tutorial','DBMS stands for DataBase ...');
      UPDATE articles set title = 'bbbb'  WHERE MATCH(title) AGAINST ('tutorial' IN NATURAL LANGUAGE MODE);
      ERROR HY000: Invalid InnoDB FTS Doc ID
      UPDATE articles set title = 'bbbb', FTS_DOC_ID=8  WHERE MATCH(title) AGAINST ('tutorial' IN NATURAL LANGUAGE MODE);
      ERROR HY000: Invalid InnoDB FTS Doc ID
      UPDATE articles set title = 'bbbb', FTS_DOC_ID=10  WHERE MATCH(title) AGAINST ('tutorial' IN NATURAL LANGUAGE MODE);
      SELECT * FROM articles WHERE MATCH (title) AGAINST ('bbbb' IN NATURAL LANGUAGE MODE);
      FTS_DOC_ID	title	body
      10	bbbb	DBMS stands for DataBase ...
      SELECT * FROM articles WHERE MATCH (title) AGAINST ('tutorial' IN NATURAL LANGUAGE MODE);
      FTS_DOC_ID	title	body
      CREATE FULLTEXT INDEX idx2 ON articles (body);
       
      More results from queries before failure can be found in /dev/shm/var/1/log/innodb-fts-fic.log
       
       
      Server [mysqld.1 - pid: 26345, winpid: 26345, exit: 256] failed during test run
      Server log from this test:
      

      ----------SERVER LOG START-----------
      2017-08-28 20:33:54 aa7f9b40 InnoDB: FTS Optimize Removing table test/articles
      2017-08-28 20:33:55 aa7f9b40 InnoDB: FTS Optimize Removing table test/articles
      2017-08-28 20:33:55 aa7f9b40 InnoDB: FTS Optimize Removing table test/articles
      2017-08-28 20:33:55 aa7f9b40 InnoDB: FTS Optimize Removing table test/articles
      2017-08-28 20:33:55 aa7f9b40 InnoDB: FTS Optimize Removing table test/articles
      2017-08-28 20:33:54 b17c3b40 InnoDB: A new Doc ID must be supplied while updating FTS indexed columns.
      InnoDB: FTS Doc ID must be larger than 9 for table`test`.`articles`
      2017-08-28 20:33:54 aa7f9b40  InnoDB: Assertion failure in thread 2860489536 in file fts0opt.cc line 2856
      InnoDB: Failing assertion: slot->last_run <= current_time
      InnoDB: We intentionally generate a memory trap.
      InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
      InnoDB: If you get repeated assertion failures or crashes, even
      InnoDB: immediately after the mysqld startup, there may be
      InnoDB: corruption in the InnoDB tablespace. Please refer to
      InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
      InnoDB: about forcing recovery.
      "170828 20:33:54 [ERROR] mysqld got signal 6 ;
      This could be because you hit a bug. It is also possible that this binary
      or one of the libraries it was linked against is corrupt, improperly built,
      or misconfigured. This error can also be caused by malfunctioning hardware.
       
      To report this bug, see https://mariadb.com/kb/en/reporting-bugs
       
      We will try our best to scrape up some info that will hopefully help
      diagnose the problem, but since we have already crashed, 
      something is definitely wrong and this may fail.
       
      Server version: 10.0.33-MariaDB-1~xenial
      key_buffer_size=1048576
      read_buffer_size=131072
      max_used_connections=1
      max_threads=153
      thread_count=1
      It is possible that mysqld could use up to 
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 61689 K  bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x0
      Attempting backtrace. You can use the following information to find out
      where mysqld died. If you see no messages after this, something went
      terribly wrong...
      stack_bottom = 0x0 thread_stack 0x48000
      /usr/sbin/mysqld(my_print_stacktrace+0x36)[0x87dc6a6]
      /usr/sbin/mysqld(handle_fatal_signal+0x3b3)[0x83639b3]
      [0xb7769c14]
      [0xb7769c31]
      /lib/i386-linux-gnu/libc.so.6(gsignal+0x39)[0xb70b2e89]
      /lib/i386-linux-gnu/libc.so.6(abort+0x157)[0xb70b43e7]
      /usr/sbin/mysqld[0x8647ecc]
      /usr/sbin/mysqld[0x864c1d8]
      /lib/i386-linux-gnu/libpthread.so.0(+0x62b5)[0xb76832b5]
      /lib/i386-linux-gnu/libc.so.6(clone+0x6e)[0xb716e16e]
      The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
      information that should help you find out what is causing the crash.
      Writing a core file
      ----------SERVER LOG END-------------
      

      Logs are not available.

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                marko Marko Mäkelä
                Reporter:
                elenst Elena Stepanova
              • Votes:
                1 Vote for this issue
                Watchers:
                4 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: