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

rocksdb.add_index_inplace_sstfilewriter, rocksdb.bulk_load_rev_cf failed in buildbot (timeout, crash)

Details

    Description

      http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest-big/builds/1218/steps/test_1/logs/stdio

      rocksdb.add_index_inplace_sstfilewriter  w1 [ fail ]  timeout after 7200 seconds
      		 
              Test ended at 2017-09-23 18:11:07
      		 
       
      		 
      Test case timeout after 7200 seconds
      		 
       
      		 
      == /mnt/buildbot/build/mariadb-10.2.9/mysql-test/var/1/log/add_index_inplace_sstfilewriter.log == 
      drop table if exists t1;
      		 
      CREATE TABLE t1(pk CHAR(5) PRIMARY KEY, a char(30), b char(30)) COLLATE 'latin1_bin';
      		 
      set rocksdb_bulk_load=1;
      		 
      set rocksdb_bulk_load_size=100000;
      		 
      LOAD DATA INFILE <input_file> INTO TABLE t1;
      		 
      set rocksdb_bulk_load=0;
      		 
      select count(pk) from t1;
      		 
      count(pk)
      		 
      3000000
      		 
      select count(a) from t1;
      		 
      count(a)
      		 
      3000000
      		 
      select count(b) from t1;
      		 
      count(b)
      		 
      3000000
      		 
      ALTER TABLE t1 ADD INDEX kb(b), ALGORITHM=INPLACE;
      		 
      ALTER TABLE t1 ADD INDEX kb_copy(b), ALGORITHM=COPY;
      		 
       
      		 
       == /mnt/buildbot/build/mariadb-10.2.9/mysql-test/var/1/tmp/analyze-timeout-mysqld.1.err ==
      		 
      mysqltest: Could not open connection 'default' after 500 attempts: 2002 Can't connect to local MySQL server through socket '/mnt/buildbot/build/mariadb-10.2.9/mysql-test/var/tmp/1/mysqld.1' (111)

      http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest-big/builds/1218/steps/test_1/logs/mysqld.1.err.1

      CURRENT_TEST: rocksdb.add_index_inplace_sstfilewriter
      		 
      2017-09-23 18:11:08 139752104999168 [Note] /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld (mysqld 10.2.9-MariaDB-log) starting as process 12410 ...
      		 
      2017-09-23 18:11:08 139752104999168 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4162)
      		 
      2017-09-23 18:11:08 139752104999168 [Warning] setrlimit could not change the size of core files to 'infinity';  We may not be able to generate a core file on signals
      		 
      2017-09-23 18:11:08 139752104999168 [Note] RocksDB: Got ENOENT when listing column families
      		 
      2017-09-23 18:11:08 139752104999168 [Note] RocksDB:   assuming that we're creating a new database
      		 
      2017-09-23 18:11:08 139752104999168 [Note] RocksDB: Column Families at start:
      		 
      2017-09-23 18:11:08 139752104999168 [Note]   cf=default
      		 
      2017-09-23 18:11:08 139752104999168 [Note]     write_buffer_size=67108864
      		 
      2017-09-23 18:11:08 139752104999168 [Note]     target_file_size_base=67108864
      		 
      2017-09-23 18:11:08 139752104999168 [Note] RocksDB: creating a column family __system__
      		 
      2017-09-23 18:11:08 139752104999168 [Note]     write_buffer_size=67108864
      		 
      2017-09-23 18:11:08 139752104999168 [Note]     target_file_size_base=67108864
      		 
      2017-09-23 18:11:08 139752104999168 [Note] RocksDB: Table_store: loaded DDL data for 0 tables
      		 
      2017-09-23 18:11:08 139752104999168 [Note] RocksDB: global statistics using get_sched_indexer_t indexer
      		 
      2017-09-23 18:11:08 139752104999168 [Note] MyRocks storage engine plugin has been successfully initialized.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'SEQUENCE' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'partition' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'InnoDB' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_LOCKS' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_CMPMEM' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_CMP_PER_INDEX' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_CMP' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_BUFFER_PAGE_LRU' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_SYS_FOREIGN_COLS' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_TRX' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_SYS_FOREIGN' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_SYS_TABLES' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_MUTEXES' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_METRICS' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'user_variables' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_BUFFER_POOL_STATS' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_SYS_VIRTUAL' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'INNODB_BUFFER_PAGE' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Plugin 'FEEDBACK' is disabled.
      		 
      2017-09-23 18:11:08 139752104999168 [Warning] /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld: unknown variable 'loose-feedback-debug-startup-interval=20'
      		 
      2017-09-23 18:11:08 139752104999168 [Warning] /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld: unknown variable 'loose-feedback-debug-first-interval=60'
      		 
      2017-09-23 18:11:08 139752104999168 [Warning] /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld: unknown variable 'loose-feedback-debug-interval=60'
      		 
      2017-09-23 18:11:08 139752104999168 [Warning] /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld: unknown option '--loose-pam-debug'
      		 
      2017-09-23 18:11:08 139752104999168 [Warning] /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld: unknown option '--loose-enable-rocksdb_lock_info'
      		 
      2017-09-23 18:11:08 139752104999168 [Warning] /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld: unknown variable 'loose-debug-sync-timeout=300'
      		 
      2017-09-23 18:11:08 139752104999168 [Note] Server socket created on IP: '127.0.0.1'.
      		 
      2017-09-23 18:11:08 139752104999168 [Note] /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld: ready for connections.
      		 
      Version: '10.2.9-MariaDB-log'  socket: '/mnt/buildbot/build/mariadb-10.2.9/mysql-test/var/tmp/1/mysqld.1.sock'  port: 16000  MariaDB Server
      		 
      2017-09-23 18:11:09 139751855527680 [Note] RocksDB: Manual memtable flush.
      		 
      2017-09-23 18:13:33 139751855527680 [Note] RocksDB: Begin index creation (0,257)
      		 
      170923 20:11:12 [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.2.9-MariaDB-log
      		 
      key_buffer_size=1048576
      		 
      read_buffer_size=131072
      		 
      max_used_connections=1
      		 
      max_threads=153
      		 
      thread_count=2
      		 
      It is possible that mysqld could use up to 
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 62992 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 0x49000
      		 
      /usr/lib/x86_64-linux-gnu/libasan.so.2(+0x4a077)[0x7f1a9188b077]
      		 
      /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld(my_print_stacktrace+0xcc)[0x558e0e4e85dc]
      		 
      /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld(handle_fatal_signal+0x6ec)[0x558e0d5b5e9c]
      		 
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7f1a902b7390]
      		 
      /lib/x86_64-linux-gnu/libc.so.6(__poll+0x2d)[0x7f1a8f94cb5d]
      		 
      /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld(_Z26handle_connections_socketsv+0x4b7)[0x558e0cf79347]
      		 
      /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld(_Z11mysqld_mainiPPc+0x41a8)[0x558e0cf87808]
      		 
      /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf0)[0x7f1a8f872830]
      		 
      /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld(_start+0x29)[0x558e0cf6ca59]
      		 
      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.

      http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest-big/builds/1218/steps/test_2/logs/stdio

      rocksdb.bulk_load_rev_cf                 w2 [ fail ]  timeout after 7200 seconds
      		 
              Test ended at 2017-09-24 01:37:01
      		 
       
      		 
      Test case timeout after 7200 seconds
      		 
       
      		 
      == /mnt/buildbot/build/mariadb-10.2.9/mysql-test/var/2/log/bulk_load_rev_cf.log == 
      a CHAR(30),
      		 
      b CHAR(30),
      		 
      PRIMARY KEY(pk) COMMENT "rev:cf1",
      		 
      KEY(a)
      		 
      ) COLLATE 'latin1_bin' PARTITION BY KEY() PARTITIONS 4;
      		 
      connect  other,localhost,root,,;
      		 
      set session transaction isolation level repeatable read;
      		 
      select * from information_schema.rocksdb_dbstats where stat_type='DB_NUM_SNAPSHOTS';
      		 
      STAT_TYPE	VALUE
      		 
      DB_NUM_SNAPSHOTS	0
      		 
      start transaction with consistent snapshot;
      		 
      select * from information_schema.rocksdb_dbstats where stat_type='DB_NUM_SNAPSHOTS';
      		 
      STAT_TYPE	VALUE
      		 
      DB_NUM_SNAPSHOTS	1
      		 
      connection default;
      		 
      set rocksdb_bulk_load=1;
      		 
      set rocksdb_bulk_load_size=100000;
      		 
      LOAD DATA INFILE <input_file> INTO TABLE t1;
      		 
      LOAD DATA INFILE <input_file> INTO TABLE t2;
      		 
      LOAD DATA INFILE <input_file> INTO TABLE t3;
      		 
       
      		 
       == /mnt/buildbot/build/mariadb-10.2.9/mysql-test/var/2/tmp/analyze-timeout-mysqld.1.err ==
      		 
      mysqltest: Could not open connection 'default' after 500 attempts: 2002 Can't connect to local MySQL server through socket '/mnt/buildbot/build/mariadb-10.2.9/mysql-test/var/tmp/2/mysqld.1' (111)

      http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest-big/builds/1218/steps/test_2/logs/mysqld.1.err.2

      CURRENT_TEST: rocksdb.bulk_load_rev_cf
      		 
      2017-09-23 23:36:05 140244040525568 [Note] RocksDB: Manual memtable flush.
      		 
      2017-09-23 23:36:05 140244040525568 [Note] RocksDB: creating a column family rev:cf1
      		 
      2017-09-23 23:36:05 140244040525568 [Note]     write_buffer_size=67108864
      		 
      2017-09-23 23:36:05 140244040525568 [Note]     target_file_size_base=67108864
      		 
      170924  1:36:07 [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.2.9-MariaDB-log
      		 
      key_buffer_size=1048576
      		 
      read_buffer_size=131072
      		 
      max_used_connections=2
      		 
      max_threads=153
      		 
      thread_count=3
      		 
      It is possible that mysqld could use up to 
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 62992 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 0x49000
      		 
      /usr/lib/x86_64-linux-gnu/libasan.so.2(+0x4a077)[0x7f8d2a0ce077]
      		 
      /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld(my_print_stacktrace+0xcc)[0x557a55fcd5dc]
      		 
      /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld(handle_fatal_signal+0x6ec)[0x557a5509ae9c]
      		 
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7f8d28afa390]
      		 
      /lib/x86_64-linux-gnu/libc.so.6(__poll+0x2d)[0x7f8d2818fb5d]
      		 
      /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld(_Z26handle_connections_socketsv+0x4b7)[0x557a54a5e347]
      		 
      /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld(_Z11mysqld_mainiPPc+0x41a8)[0x557a54a6c808]
      		 
      /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf0)[0x7f8d280b5830]
      		 
      /mnt/buildbot/build/mariadb-10.2.9/sql/mysqld(_start+0x29)[0x557a54a51a59]
      		 
      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

      Attachments

        Issue Links

          relates to

          Bug - A problem which impairs or prevents the functions of the product. MDEV-13599 rocksdb.add_index_inplace_sstfilewriter failed in buildbot (AddressSanitizer failed))

          • Major - Major loss of function.
          • Closed

          Activity

            Ascending order - Click to sort in descending order
            View 6 older comments
            psergei Sergei Petrunia added a comment -

            Taking another test for comparison, again from http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest-big/builds/1275/steps/test_2/logs/stdio.

            rocksdb.bulk_load_rev_cf                 w2 [ pass ]  6,077,539

            On my machine (same release+ASAN build and --mem) I get:

            rocksdb.bulk_load_rev_cf                 [ pass ]  715,123

            psergei Sergei Petrunia added a comment - Taking another test for comparison, again from http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest-big/builds/1275/steps/test_2/logs/stdio . rocksdb.bulk_load_rev_cf w2 [ pass ] 6,077,539 On my machine (same release+ASAN build and --mem) I get: rocksdb.bulk_load_rev_cf [ pass ] 715,123
            psergei Sergei Petrunia added a comment -

            Checking other execution time difference on the same pairs of machines:
            http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest-big/builds/1275/steps/test_2/logs/stdio
            gives

            main.log_tables-big                      w1 [ pass ]  163,080 -- psergey-desktop
            		 
            main.log_tables-big                      [ pass ]  163,047    -- BB


            main.sum_distinct-big 'innodb'           [ pass ]  194,068      -- psergey-desktop
            		 
            main.sum_distinct-big 'innodb'           w1 [ pass ]  408,281  -- BB

            psergei Sergei Petrunia added a comment - Checking other execution time difference on the same pairs of machines: http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest-big/builds/1275/steps/test_2/logs/stdio gives main.log_tables-big w1 [ pass ] 163,080 -- psergey-desktop main.log_tables-big [ pass ] 163,047 -- BB main.sum_distinct-big 'innodb' [ pass ] 194,068 -- psergey-desktop main.sum_distinct-big 'innodb' w1 [ pass ] 408,281 -- BB
            psergei Sergei Petrunia added a comment -

            So

            • for regular tests fulltest2 build is 1x-2x slower than my machine
            • but for MyRocks tests it is 8.5x slower
              not sure why is it so much slower for MyRocks.
            psergei Sergei Petrunia added a comment - So for regular tests fulltest2 build is 1x-2x slower than my machine but for MyRocks tests it is 8.5x slower not sure why is it so much slower for MyRocks.
            psergei Sergei Petrunia added a comment -

            add_index_inplace_sstfilewriter has been scaled down by me in

            commit e5678c3fac27af7ca5a8503cccf1fdf3ad4f6fce
            		 
            Author:	Sergei Petrunia <psergey@askmonty.org>  Sun Oct 29 13:21:23 2017
            		 
            Committer:	Sergei Petrunia <psergey@askmonty.org>  Sun Oct 29 13:21:23 2017
            		 
             
            		 
            MDEV-13904: rocksdb.add_index_inplace_sstfilewriter timed out

            I wasn't able to find mentions of it timing out after that.

            psergei Sergei Petrunia added a comment - add_index_inplace_sstfilewriter has been scaled down by me in commit e5678c3fac27af7ca5a8503cccf1fdf3ad4f6fce Author: Sergei Petrunia <psergey@askmonty.org> Sun Oct 29 13:21:23 2017 Committer: Sergei Petrunia <psergey@askmonty.org> Sun Oct 29 13:21:23 2017   MDEV-13904: rocksdb.add_index_inplace_sstfilewriter timed out I wasn't able to find mentions of it timing out after that.
            psergei Sergei Petrunia added a comment -

            Down-scaled rocksdb.bulk_load* by 2x, too.
            The tests are not run by the buildbot ATM so it is impossible to check if they started to work in BB

            psergei Sergei Petrunia added a comment - Down-scaled rocksdb.bulk_load* by 2x, too. The tests are not run by the buildbot ATM so it is impossible to check if they started to work in BB

            People

              psergei Sergei Petrunia
              alice Alice Sherepa
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.