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

Every MTR test case fails at check-testcase stage on macOS 10.13.6

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Open (View Workflow)
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: 10.3
    • Fix Version/s: None
    • Component/s: Tests
    • Labels:
    • Environment:
      macOS 10.13.6 High Sierra

      Description

      Something weird happens in ./include/check-testcase.test starting from 10.3 for simple builds from current GitHub code on macOS 10.13.6 using this cmake command line:

      Yuliyas-Air:buildtmp Valerii$ cmake .. -DCMAKE_INSTALL_PREFIX=/Users/Valerii/dbs/maria10.3 -DCMAKE_BUILD_TYPE=RelWithDebInfo -DENABLE_DTRACE=1

      As a result, every test case I try fails like this:

      Yuliyas-Air:mysql-test Valerii$ ./mtr innodb.innodb_autoinc_lock_mode_zero
      Logging: ./mtr  innodb.innodb_autoinc_lock_mode_zero
      VS config:
      vardir: /Users/Valerii/dbs/maria10.3/mysql-test/var
      Checking leftover processes...
      Removing old var directory...
      Creating var directory '/Users/Valerii/dbs/maria10.3/mysql-test/var'...
      Checking supported features...
      MariaDB Version 10.3.33-MariaDB
       - SSL connections supported
       - binaries built with wsrep patch
      Collecting tests...
      Installing system database...
       
      ==============================================================================
       
      TEST                                      RESULT   TIME (ms) or COMMENT
      --------------------------------------------------------------------------
       
      worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
      worker[1] mysql-test-run: WARNING: Check-testcase failed, this could also be caused by the previous test run by this worker thread
      innodb.innodb_autoinc_lock_mode_zero 'innodb' [ fail ]
              Test ended at 2022-01-23 11:51:39
       
      CURRENT_TEST: innodb.innodb_autoinc_lock_mode_zero
       
       
      The server [mysqld.1 - pid: 82333, winpid: 82333, exit: 256] crashed while running 'check testcase before test'
      Server log from this test:
      ----------SERVER LOG START-----------
      $ /Users/Valerii/dbs/maria10.3/bin/mysqld --defaults-group-suffix=.1 --defaults-file=/Users/Valerii/dbs/maria10.3/mysql-test/var/my.cnf --log-output=file --innodb --innodb-cmpmem --innodb-cmp-per-index --innodb-trx --innodb-locks --innodb-lock-waits --innodb-metrics --innodb-buffer-pool-stats --innodb-buffer-page --innodb-buffer-page-lru --innodb-sys-columns --innodb-sys-fields --innodb-sys-foreign --innodb-sys-foreign-cols --innodb-sys-indexes --innodb-sys-tables --innodb-sys-virtual --loose-innodb-autoinc-lock-mode=0 --core-file --loose-debug-sync-timeout=300
      2022-01-23 11:51:39 0 [Note] /Users/Valerii/dbs/maria10.3/bin/mysqld (mysqld 10.3.33-MariaDB-log) starting as process 82334 ...
      2022-01-23 11:51:39 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 32186)
      2022-01-23 11:51:39 0 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
      2022-01-23 11:51:39 0 [Warning] Setting lower_case_table_names=2 because file system for /Users/Valerii/dbs/maria10.3/mysql-test/var/mysqld.1/data/ is case insensitive
      2022-01-23 11:51:39 0 [Note] Plugin 'partition' is disabled.
      2022-01-23 11:51:39 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
      2022-01-23 11:51:39 0 [Note] InnoDB: Uses event mutexes
      2022-01-23 11:51:39 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
      2022-01-23 11:51:39 0 [Note] InnoDB: Number of pools: 1
      2022-01-23 11:51:39 0 [Note] InnoDB: Using SSE2 crc32 instructions
      2022-01-23 11:51:39 0 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M
      2022-01-23 11:51:39 0 [Note] InnoDB: Completed initialization of buffer pool
      2022-01-23 11:51:39 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
      2022-01-23 11:51:39 0 [Note] InnoDB: Creating shared tablespace for temporary tables
      2022-01-23 11:51:39 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
      2022-01-23 11:51:39 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
      2022-01-23 11:51:39 0 [Note] InnoDB: Waiting for purge to start
      2022-01-23 11:51:39 0 [Note] InnoDB: 10.3.33 started; log sequence number 1636014; transaction id 33
      2022-01-23 11:51:39 0 [Note] InnoDB: Loading buffer pool(s) from /Users/Valerii/dbs/maria10.3/mysql-test/var/mysqld.1/data/ib_buffer_pool
      2022-01-23 11:51:39 0 [Note] Plugin 'SEQUENCE' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'INNODB_CMP' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'FEEDBACK' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'user_variables' is disabled.
      2022-01-23 11:51:39 0 [Note] InnoDB: Buffer pool(s) load completed at 220123 11:51:39
      2022-01-23 11:51:39 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
      2022-01-23 11:51:39 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
      2022-01-23 11:51:39 0 [Warning] /Users/Valerii/dbs/maria10.3/bin/mysqld: unknown variable 'loose-feedback-debug-startup-interval=20'
      2022-01-23 11:51:39 0 [Warning] /Users/Valerii/dbs/maria10.3/bin/mysqld: unknown variable 'loose-feedback-debug-first-interval=60'
      2022-01-23 11:51:39 0 [Warning] /Users/Valerii/dbs/maria10.3/bin/mysqld: unknown variable 'loose-feedback-debug-interval=60'
      2022-01-23 11:51:39 0 [Warning] /Users/Valerii/dbs/maria10.3/bin/mysqld: unknown option '--loose-pam-debug'
      2022-01-23 11:51:39 0 [Warning] /Users/Valerii/dbs/maria10.3/bin/mysqld: unknown variable 'loose-debug-sync-timeout=300'
      2022-01-23 11:51:39 0 [Note] Server socket created on IP: '127.0.0.1'.
      2022-01-23 11:51:39 0 [Note] Reading of all Master_info entries succeeded
      2022-01-23 11:51:39 0 [Note] Added new Master_info '' to hash table
      2022-01-23 11:51:39 0 [Note] /Users/Valerii/dbs/maria10.3/bin/mysqld: ready for connections.
      Version: '10.3.33-MariaDB-log'  socket: '/Users/Valerii/dbs/maria10.3/mysql-test/var/tmp/mysqld.1.sock'  port: 16000  Source distribution
      ----------SERVER LOG END-------------
      mysqltest failed but provided no output
       
       
       - saving '/Users/Valerii/dbs/maria10.3/mysql-test/var/log/innodb.innodb_autoinc_lock_mode_zero-innodb/' to '/Users/Valerii/dbs/maria10.3/mysql-test/var/log/innodb.innodb_autoinc_lock_mode_zero-innodb/'
      --------------------------------------------------------------------------
      The servers were restarted 0 times
      Spent 0.000 of 4 seconds executing testcases
       
      Failure: Failed 1/1 tests, 0.00% were successful.
       
      Failing test(s): innodb.innodb_autoinc_lock_mode_zero
       
      The log files in var/log may give you some hint of what went wrong.
       
      If you want to report this error, please read first the documentation
      at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html
       
      mysql-test-run: *** ERROR: there were failing test cases
      

      The same test works on older versions like 10.2 or 10.1:

      Yuliyas-Air:mysql-test Valerii$ cd ../../maria10.1/mysql-test/
      Yuliyas-Air:mysql-test Valerii$ ./mtr innodb.innodb_autoinc_lock_mode_zero
      Logging: ./mtr  innodb.innodb_autoinc_lock_mode_zero
      vardir: /Users/Valerii/dbs/maria10.1/mysql-test/var
      Checking leftover processes...
      Removing old var directory...
      Creating var directory '/Users/Valerii/dbs/maria10.1/mysql-test/var'...
      Checking supported features...
      MariaDB Version 10.1.49-MariaDB
       - SSL connections supported
      Sphinx 'indexer' binary not found, sphinx suite will be skipped
      Collecting tests...
      Installing system database...
       
      ==============================================================================
       
      TEST                                      RESULT   TIME (ms) or COMMENT
      --------------------------------------------------------------------------
       
      worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
      innodb.innodb_autoinc_lock_mode_zero 'innodb_plugin' [ pass ]     47
      innodb.innodb_autoinc_lock_mode_zero 'xtradb' [ pass ]     21
      --------------------------------------------------------------------------
      The servers were restarted 1 times
      Spent 0.068 of 10 seconds executing testcases
       
      Completed: All 2 tests were successful.
      

      So, we have a regression of a kind somewhere. On 10.6 (with patches added as per MDEV-27579 and built to use openssl 1.1:

      Yuliyas-Air:buildtmp Valerii$ cmake .. -DCMAKE_INSTALL_PREFIX=/Users/Valerii/dbs/maria10.6 -DCMAKE_BUILD_TYPE=RelWithDebInfo -DBUILD_CONFIG=mysql_release -DFEATURE_SET=community -DWITH_EMBEDDED_SERVER=OFF -DPLUGIN_TOKUDB=NO -DWITH_SSL=/opt/local/libexec/openssl11 -DENABLE_DTRACE=1
      

      tests also work without this issue:

      Yuliyas-Air:mysql-test Valerii$ cd ../../maria10.6/mysql-test/
      Yuliyas-Air:mysql-test Valerii$ ./mtr innodb.innodb_autoinc_lock_mode_zero
      Logging: ./mtr  innodb.innodb_autoinc_lock_mode_zero
      VS config:
      vardir: /Users/Valerii/dbs/maria10.6/mysql-test/var
      Checking leftover processes...
       - found old pid 80202 in 'mysqld.1.pid', killing it...
         process did not exist!
      Removing old var directory...
      Creating var directory '/Users/Valerii/dbs/maria10.6/mysql-test/var'...
      Checking supported features...
      MariaDB Version 10.6.6-MariaDB
       - SSL connections supported
       - binaries built with wsrep patch
      Collecting tests...
      Installing system database...
       
      ==============================================================================
       
      TEST                                      RESULT   TIME (ms) or COMMENT
      --------------------------------------------------------------------------
       
      worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
      innodb.innodb_autoinc_lock_mode_zero 'innodb' [ pass ]     63
      --------------------------------------------------------------------------
      The servers were restarted 0 times
      Spent 0.063 of 16 seconds executing testcases
       
      Completed: All 1 tests were successful.
      

        Attachments

          Activity

            People

            Assignee:
            Unassigned Unassigned
            Reporter:
            valerii Valerii Kravchuk
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Dates

              Created:
              Updated:

                Git Integration

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