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

The execution of SHOW ENGINE INNODB STATUS to show locked mutexes could cause a server exit.

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Done
    • Priority: Low
    • Resolution: Fixed
    • Affects Version/s: 5.7.27-30, 8.0.18-9
    • Fix Version/s: 5.7.29-32, 8.0.19-10
    • Component/s: None
    • Labels:

      Description

      MySQL crashed with the stack trace below:

       

      2019-11-22T12:26:55.759278Z 8748327 [Note] Start binlog_dump to master_thread_id(8748327) slave_server(10027034), pos(, 4)
      12:27:30 UTC - mysqld got signal 11 ;
      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.
      Attempting to collect some information that could help diagnose the problem.
      As this is a crash and something is definitely wrong, the information
      collection process might fail.
      Please help us make Percona Server better by reporting any
      bugs at https://bugs.percona.com/key_buffer_size=8388608
      read_buffer_size=131072
      max_used_connections=852
      max_threads=3001
      thread_count=563
      connection_count=563
      It is possible that mysqld could use up to 
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 1202862 K  bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.Thread pointer: 0x7f16b0271410
      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 = 7f1639d30e80 thread_stack 0x40000
      /usr/sbin/mysqld(my_print_stacktrace+0x2c)[0x56004f56dc5c]
      /usr/sbin/mysqld(handle_fatal_signal+0x489)[0x56004f3a4d89]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x110e0)[0x7f1cc8acc0e0]
      /usr/sbin/mysqld(_Z20sync_mutex_to_string10latch_id_tRKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEE+0x162)[0x56004f777b52]
      /usr/sbin/mysqld(+0xf4b600)[0x56004f76c600]
      /usr/sbin/mysqld(_Z16sync_array_printP8_IO_FILE+0xed)[0x56004f76ce2d]
      /usr/sbin/mysqld(_Z10sync_printP8_IO_FILE+0x19)[0x56004f777799]
      /usr/sbin/mysqld(_Z25srv_printf_innodb_monitorP8_IO_FILEmPmS1_+0x1d4)[0x56004f753cb4]
      /usr/sbin/mysqld(+0xdfed12)[0x56004f61fd12]
      /usr/sbin/mysqld(_Z14ha_show_statusP3THDP10handlerton12ha_stat_type+0x368)[0x56004ee7a788]
      /usr/sbin/mysqld(_Z21mysql_execute_commandP3THDb+0x1822)[0x56004f2c65a2]
      /usr/sbin/mysqld(_Z11mysql_parseP3THDP12Parser_stateb+0x435)[0x56004f2cc9a5]
      /usr/sbin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0x1034)[0x56004f2cdad4]
      /usr/sbin/mysqld(_Z10do_commandP3THD+0x1b7)[0x56004f2cf097]
      /usr/sbin/mysqld(handle_connection+0x2a8)[0x56004f38bb68]
      /usr/sbin/mysqld(pfs_spawn_thread+0x1b4)[0x56004f588374]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x74a4)[0x7f1cc8ac24a4]
      /lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7f1cc67e5d0f]Trying to get some variables.
      Some pointers may be invalid and cause the dump to abort.
      Query (7f16b017a928): SHOW ENGINE INNODB STATUS
      Connection ID (thread ID): 8748658
      Status: NOT_KILLEDYou may download the Percona Server operations manual by visiting
      http://www.percona.com/software/percona-server/. You may find information
      in the manual which will help you identify the cause of the crash.
      

       

      And this is the piece of code affected:

       

      /** String representation of the filename and line number where the
      latch was created
      @param[in]      id              Latch ID
      @param[in]      created         Filename and line number where it was crated
      @return the string representation */
      std::string sync_mutex_to_string(latch_id_t id, const std::string &created) {
        std::ostringstream msg;
      
        msg << "Mutex " << sync_latch_get_name(id) << " "
            << "created " << created;
      
        return (msg.str());
      }
      

       

      It seems that the lack of protection(mutex) of created variable is causing the crash. The created variable is passed by reference, but then that reference is de-referenced by some other thread, and by the time this function reads it, it's gone and hence causes the SIGSEGV (signal 11).

      It seems it is happening on a very specific latch since I can not reproduce even with the debug version:

      master [localhost] {msandbox} ((none)) > select @@version;
      +------------------------------+
      | @@version                    |
      +------------------------------+
      | 5.7.27-30-debug-log-valgrind |
      +------------------------------+
      1 row in set (0.00 sec)
      

       

        Smart Checklist

          Attachments

            Issue Links

              Activity

                People

                Assignee:
                kamil.holubicki Kamil Holubicki
                Reporter:
                vinicius.grippa Vinicius Grippa
                Votes:
                3 Vote for this issue
                Watchers:
                12 Start watching this issue

                  Dates

                  Created:
                  Updated:
                  Resolved:

                    Time Tracking

                    Estimated:
                    Original Estimate - Not Specified
                    Not Specified
                    Remaining:
                    Remaining Estimate - 0 minutes
                    0m
                    Logged:
                    Time Spent - 3 days, 4 hours, 10 minutes
                    3d 4h 10m