Uploaded image for project: 'Percona Server'
  1. Percona Server
  2. PS-5028

Assertion `!innodb_was_used || innodb_slow_log_enabled()' failed.

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: On Hold
    • Priority: High
    • Resolution: Unresolved
    • Affects Version/s: 5.7, 8.0
    • Fix Version/s: None
    • Component/s: None
    • Labels:
      None

      Description

      The following testcase, repeated/executed twice;

      SET GLOBAL  slow_query_log_use_global_control="log_slow_verbosity,long_query_time";
      SET SESSION log_slow_filter='full_join,tmp_table,tmp_table_on_disk,filesort,filesort_on_disk';
      SET GLOBAL  long_query_time=0;
      SET GLOBAL  slow_query_log=ON;
      SET GLOBAL  log_output=FILE;
      SET SESSION log_slow_verbosity='microtime,innodb,query_plan';
      SELECT event_name from information_schema.events; 
      SET global slow_query_log='ON';
      # REPEAT ALL THE ABOVE ONCE MORE #

      Produces;

      2018-11-16T02:47:11.049116Z 0 [System] [MY-010931] [Server] /sda/PS131118-percona-server-8.0.12-1-linux-x86_64-debug/bin/mysqld: ready for connections. Version: '8.0.12-1-debug'  socket: '/sda/PS131118-percona-server-8.0.12-1-linux-x86_64-debug/socket.sock'  port: 13093  MySQL Community Server (GPL).
      mysqld: /git/PS-8.0-trunk_dbg/sql/sql_class.h:1503: bool THD::innodb_slow_log_data_logged() const: Assertion `!innodb_was_used || innodb_slow_log_enabled()' failed.
      02:50:33 UTC - mysqld got signal 6 ;
      
      Core was generated by `/sda/PS131118-percona-server-8.0.12-1-linux-x86_64-debug/bin/mysqld --no-defaul'.
      Program terminated with signal SIGABRT, Aborted.
      #0  __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
      [Current thread is 1 (Thread 0x7f6afbe90700 (LWP 17604))]
      (gdb) bt
      #0  __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
      #1  0x0000561781f1fc17 in my_write_core (sig=6) at /git/PS-8.0-trunk_dbg/mysys/stacktrace.cc:278
      #2  0x0000561780e9048e in handle_fatal_signal (sig=6) at /git/PS-8.0-trunk_dbg/sql/signal_handler.cc:254
      #3  <signal handler called>
      #4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
      #5  0x00007f6afbed1801 in __GI_abort () at abort.c:79
      #6  0x00007f6afbec139a in __assert_fail_base (fmt=0x7f6afc0487d8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", 
          assertion=assertion@entry=0x5617828c5ac0 "!innodb_was_used || innodb_slow_log_enabled()", 
          file=file@entry=0x5617828c5a98 "/git/PS-8.0-trunk_dbg/sql/sql_class.h", line=line@entry=1503, 
          function=function@entry=0x5617828c6760 <THD::innodb_slow_log_data_logged() const::__PRETTY_FUNCTION__> "bool THD::innodb_slow_log_data_logged() const") at assert.c:92
      #7  0x00007f6afbec1412 in __GI___assert_fail (assertion=0x5617828c5ac0 "!innodb_was_used || innodb_slow_log_enabled()", 
          file=0x5617828c5a98 "/git/PS-8.0-trunk_dbg/sql/sql_class.h", line=1503, 
          function=0x5617828c6760 <THD::innodb_slow_log_data_logged() const::__PRETTY_FUNCTION__> "bool THD::innodb_slow_log_data_logged() const") at assert.c:101
      #8  0x0000561780ada45b in THD::innodb_slow_log_data_logged (this=0x7f6ac8424000) at /git/PS-8.0-trunk_dbg/sql/sql_class.h:1503
      #9  0x0000561780ad3c14 in File_query_log::write_slow (this=0x7f6aefb92e30, thd=0x7f6ac8424000, current_utime=1542336633851080, 
          user_host=0x7f6afbe8eee0 "root[root] @ localhost []", query_utime=1390, lock_utime=890, is_command=false, 
          sql_text=0x7f6ac85dc028 "SELECT event_name from information_schema.events", sql_text_len=48)
          at /git/PS-8.0-trunk_dbg/sql/log.cc:731
      #10 0x0000561780ad5b83 in Log_to_file_event_handler::log_slow (this=0x7f6aefb92a00, thd=0x7f6ac8424000, 
          current_utime=1542336633851080, user_host=0x7f6afbe8eee0 "root[root] @ localhost []", user_host_len=25, query_utime=1390, 
          lock_utime=890, is_command=false, sql_text=0x7f6ac85dc028 "SELECT event_name from information_schema.events", sql_text_len=48)
          at /git/PS-8.0-trunk_dbg/sql/log.cc:1219
      #11 0x0000561780ad62e0 in Query_logger::slow_log_write (this=0x5617845a2700 <query_logger>, thd=0x7f6ac8424000, 
          query=0x7f6ac85dc028 "SELECT event_name from information_schema.events", query_length=48) at /git/PS-8.0-trunk_dbg/sql/log.cc:1308
      #12 0x0000561780ad7759 in log_slow_do (thd=0x7f6ac8424000) at /git/PS-8.0-trunk_dbg/sql/log.cc:1711
      #13 0x0000561780ad7789 in log_slow_statement (thd=0x7f6ac8424000) at /git/PS-8.0-trunk_dbg/sql/log.cc:1715
      #14 0x0000561780cce30c in dispatch_command (thd=0x7f6ac8424000, com_data=0x7f6afbe8fc70, command=COM_QUERY)
          at /git/PS-8.0-trunk_dbg/sql/sql_parse.cc:2032
      #15 0x0000561780ccb33e in do_command (thd=0x7f6ac8424000) at /git/PS-8.0-trunk_dbg/sql/sql_parse.cc:1262
      #16 0x0000561780e7cbf0 in handle_connection (arg=0x7f6aaa744a30)
          at /git/PS-8.0-trunk_dbg/sql/conn_handler/connection_handler_per_thread.cc:317
      #17 0x0000561782010f20 in pfs_spawn_thread (arg=0x7f6aaa4bb120) at /git/PS-8.0-trunk_dbg/storage/perfschema/pfs.cc:2836
      #18 0x00007f6afdad56db in start_thread (arg=0x7f6afbe90700) at pthread_create.c:463
      #19 0x00007f6afbfb288f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      This bug is pursuant to PS-4788. It reproduces on 8.0.12 trunk 2018-11-13, and also reproduces on PS 5.7.23.

        Smart Checklist

          Attachments

            Issue Links

              Activity

                People

                • Assignee:
                  laurynas.biveinis Laurynas Biveinis
                  Reporter:
                  roel.vandepaar Roel Van de Paar (Inactive)
                • Votes:
                  0 Vote for this issue
                  Watchers:
                  3 Start watching this issue

                  Dates

                  • Created:
                    Updated:

                    Time Tracking

                    Estimated:
                    Original Estimate - Not Specified
                    Not Specified
                    Remaining:
                    Remaining Estimate - Not Specified
                    Not Specified
                    Logged:
                    Time Spent - 15 minutes
                    15m