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

TokuDB crashes when mysqld process hits max open files limit

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: On Hold
    • Priority: Medium
    • Resolution: Unresolved
    • Affects Version/s: 5.7.26-29
    • Fix Version/s: None
    • Component/s: TokuDB
    • Labels:
      None

      Description

      TokuDB engine turns out to be very susceptible to an open files limit scenario and it will crash in some scenarios when this limit is hit.

      An example reproducible test case is as follows.

      • Install Percona Server 5.7 with TokuDB engine enabled
      • Create ~5000 simple tables using TokuDB engine
      • The default open_files_limit of 5000
      • Verify per process limit is 5k:
        # cat /proc/$(pgrep -x mysqld)/limits
        Limit                     Soft Limit           Hard Limit           Units     
        ...
        Max open files            5000                 5000                 files     
        
      • Open many tables in loop, like with:
        # for i in {1..3000}; do mysql db5 -e "select count(*) from tk$i" > /dev/null; done
        

        the server will start to complain with messages like:

        ERROR 1016 (HY000) at line 1: Can't open file: './db5/tk1651.frm' (errno: 24 - Too many open files)
        
      • Try LOAD DATA command to one of the tables, it should fail with:
        mysql> LOAD DATA INFILE "/var/lib/mysql-files/tk1.txt" INTO TABLE db2.tk30;
        ERROR 1016 (HY000): Can't open file: './db2/tk30.frm' (errno: 24 - Too many open files)
        
      • Flush one table to free up some table descriptors and try the load again:
        mysql> flush tables db5.tk249;
        Query OK, 0 rows affected (0.01 sec)
        
        mysql> LOAD DATA INFILE "/var/lib/mysql-files/tk1.txt" INTO TABLE db2.tk30;
        ERROR 2013 (HY000): Lost connection to MySQL server during query
        

      The server crashes with trace:

      /mnt/workspace/percona-server-5.7-redhat-binary-rocks-new/label_exp/min-centos-6-x64/test/rpmbuild/BUILD/percona-server-5.7.26-29/percona-server-5.7.26-29/storage/tokudb/PerconaFT/src/loader.cc:311 toku_loader_create_loade
      r: Assertion `rval == 0' failed (errno=24) (rval=24)
      : Too many open files
      Backtrace: (Note: toku_do_assert=0x0x7fd3d0116af0)
      /usr/lib64/mysql/plugin/ha_tokudb.so(_Z19db_env_do_backtraceP8_IO_FILE+0x1b)[0x7fd3d00ff7fb]
      /usr/lib64/mysql/plugin/ha_tokudb.so(+0xdd983)[0x7fd3d00ff983]
      /usr/lib64/mysql/plugin/ha_tokudb.so(+0xdda12)[0x7fd3d00ffa12]
      /usr/lib64/mysql/plugin/ha_tokudb.so(_Z25toku_loader_create_loaderP13__toku_db_envP13__toku_db_txnPP13__toku_loaderP9__toku_dbiPS7_PjS9_jb+0x57f)[0x7fd3d0146f4f]
      /usr/lib64/mysql/plugin/ha_tokudb.so(+0x12589e)[0x7fd3d014789e]
      /usr/lib64/mysql/plugin/ha_tokudb.so(_Z17toku_loader_closeP13__toku_loader+0x1da)[0x7fd3d014780a]
      /usr/lib64/mysql/plugin/ha_tokudb.so(_ZN9ha_tokudb15end_bulk_insertEb+0x54d)[0x7fd3d009e40d]
      /usr/sbin/mysqld(_Z10mysql_loadP3THDP12sql_exchangeP10TABLE_LISTR4ListI4ItemES8_S8_15enum_duplicatesb+0x189d)[0xe26dcd]
      /usr/sbin/mysqld(_Z21mysql_execute_commandP3THDb+0x3e39)[0xc44cd9]
      /usr/sbin/mysqld(_Z11mysql_parseP3THDP12Parser_stateb+0x435)[0xc486e5]
      /usr/sbin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0xb27)[0xc492e7]
      /usr/sbin/mysqld(_Z10do_commandP3THD+0x1b7)[0xc4ad47]
      /usr/sbin/mysqld(handle_connection+0x2a8)[0xd088c8]
      /usr/sbin/mysqld(pfs_spawn_thread+0x1b4)[0xef8984]
      /lib64/libpthread.so.0(+0x7aa1)[0x7fd3fe760aa1]
      /lib64/libc.so.6(clone+0x6d)[0x7fd3fca57c4d]
      Engine status:
      BUILD_ID = 0
      Env panic code: 24
      Env panic string: /mnt/workspace/percona-server-5.7-redhat-binary-rocks-new/label_exp/min-centos-6-x64/test/rpmbuild/BUILD/percona-server-5.7.26-29/percona-server-5.7.26-29/storage/tokudb/PerconaFT/src/loader.cc:311 toku_loader_create_loa
      der: Assertion `rval == 0' failed (errno=24) (rval=24)
      
      time of environment creation: Mon Jul 29 03:31:53 2019
      time of engine startup: Mon Jul 29 07:11:47 2019
      time now: Mon Jul 29 07:12:59 2019
      db opens: 4948
      db closes: 3
      num open dbs now: 4945
      max open dbs: 4947
      (...)
      

      Another case with LOAD DATA, command and open files limit hit, though I could not reproduce this exact one:

      /mnt/workspace/percona-server-5.7-redhat-binary-rocks/label_exp/min-centos-7-x64/rpmbuild/BUILD/percona-server-5.7.22-22/percona-server-5.7.22-22/storage/tokudb/ha_tokudb.cc:1301 open_main_dictionary: Assertion `Handlerton: share->file ==
       NULL ' failed (errno=0)
      : Success
      Backtrace: (Note: toku_do_assert=0x0x7fcfe111c020)
      /usr/lib64/mysql/plugin/ha_tokudb.so(_Z19db_env_do_backtraceP8_IO_FILE+0x2e)[0x7fcfe111a04e]
      /usr/lib64/mysql/plugin/ha_tokudb.so(+0x102183)[0x7fcfe111a183]
      /usr/lib64/mysql/plugin/ha_tokudb.so(+0x102cd4)[0x7fcfe111acd4]
      /usr/lib64/mysql/plugin/ha_tokudb.so(+0x104018)[0x7fcfe111c018]
      /usr/lib64/mysql/plugin/ha_tokudb.so(_Z21toku_hton_assert_failPKcS0_S0_ii+0x88)[0x7fcfe106eaf8]
      /usr/lib64/mysql/plugin/ha_tokudb.so(_ZN9ha_tokudb20open_main_dictionaryEPKcbP13__toku_db_txn+0x277)[0x7fcfe1085387]
      /usr/lib64/mysql/plugin/ha_tokudb.so(_ZN9ha_tokudb16initialize_shareEPKci+0x24c)[0x7fcfe109832c]
      /usr/lib64/mysql/plugin/ha_tokudb.so(_ZN9ha_tokudb4openEPKcij+0x5b6)[0x7fcfe109aba6]
      /usr/sbin/mysqld(_ZN7handler7ha_openEP5TABLEPKcii+0x33)[0x801bb3]
      /usr/sbin/mysqld[0x12ec95e]
      /usr/sbin/mysqld(_ZN7handler7ha_openEP5TABLEPKcii+0x33)[0x801bb3]
      /usr/sbin/mysqld(_Z21open_table_from_shareP3THDP11TABLE_SHAREPKcjjjP5TABLEb+0x796)[0xd65ac6]
      /usr/sbin/mysqld(_Z10open_tableP3THDP10TABLE_LISTP18Open_table_context+0xf81)[0xc66811]
      /usr/sbin/mysqld(_Z11open_tablesP3THDPP10TABLE_LISTPjjP19Prelocking_strategy+0x612)[0xc6d782]
      /usr/sbin/mysqld(_Z20open_and_lock_tablesP3THDP10TABLE_LISTjP19Prelocking_strategy+0x44)[0xc6dfa4]
      /usr/sbin/mysqld(_Z10mysql_loadP3THDP12sql_exchangeP10TABLE_LISTR4ListI4ItemES8_S8_15enum_duplicatesb+0x1bf)[0xe42c1f]
      /usr/sbin/mysqld(_Z21mysql_execute_commandP3THDb+0x3ef3)[0xcc4b33]
      /usr/sbin/mysqld(_Z11mysql_parseP3THDP12Parser_state+0x5e5)[0xcc8785]
      /usr/sbin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0xabd)[0xcc934d]
      /usr/sbin/mysqld(_Z10do_commandP3THD+0x1df)[0xccad6f]
      /usr/sbin/mysqld(handle_connection+0x2b8)[0xd936d8]
      /usr/sbin/mysqld(pfs_spawn_thread+0x1b4)[0xf0d114]
      /lib64/libpthread.so.0(+0x7dd5)[0x7fd298161dd5]
      /lib64/libc.so.6(clone+0x6d)[0x7fd2963acead]
      Engine status:
      BUILD_ID = 0
      Env panic code: 18446744073709551615
      Env panic string: /mnt/workspace/percona-server-5.7-redhat-binary-rocks/label_exp/min-centos-7-x64/rpmbuild/BUILD/percona-server-5.7.22-22/percona-server-5.7.22-22/storage/tokudb/ha_tokudb.cc:1301 open_main_dictionary: Assertion `Handlert
      on: share->file == NULL ' failed (errno=0)
      (...)
      Query (7eb5167fc030): LOAD DATA CONCURRENT LOCAL INFILE (...)
      

        Smart Checklist

          Attachments

            Activity

              People

              Assignee:
              Unassigned
              Reporter:
              przemyslaw.malkowski@percona.com Przemyslaw Malkowski
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Dates

                Created:
                Updated: