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

Tests innodb.log_encrypt_3_mk innodb.innodb-wl6742 innodb.innodb-wl6045-1 innodb.log_encrypt_3_rk fail

    Details

    • Type: Bug
    • Status: On Hold
    • Priority: Medium
    • Resolution: Unresolved
    • Affects Version/s: 5.7.24-26
    • Fix Version/s: None
    • Component/s: None
    • Environment:

      Description

      I see the following test failures with current Percona Server 5.7 from GitHub:

      [openxs@fc23 percona-server]$ git branch
      * 5.7
      [openxs@fc23 percona-server]$ git log -1
      commit 6062aeb2a67aef7e2f8fb91cdb972aeee39a82b7 (HEAD -> 5.7, origin/HEAD, origin/5.7)
      Merge: 49f3b278812 bb46036fb36
      Author: Przemyslaw Skibinski <przemyslaw.skibinski@percona.com>
      Date:   Thu Dec 6 10:26:20 2018 +0100
      
          Merge pull request #2752 from inikep/5.7-percona_bug1289599
      
          PS-5100: percona_bug1289599 fails if USER is not defined (5.7)
      [openxs@fc23 percona-server]$
      

      on up to date Fedora 27 box:

      Failing test(s): innodb.log_encrypt_3_mk innodb.innodb-wl6742 innodb.innodb-wl6045-1 innodb.log_encrypt_3_rk

      For example:

      [openxs@fc23 mysql-test]$ ./mtr innodb.innodb-wl6742
      Logging: ./mtr  innodb.innodb-wl6742
      2018-12-07T11:14:33.949639Z 0 [Warning] Changed limits: max_open_files: 1024 (requested 5000)
      2018-12-07T11:14:33.949736Z 0 [Warning] Changed limits: table_open_cache: 431 (requested 2000)
      MySQL Version 5.7.24
      Checking supported features...
       - SSL connections supported
      Collecting tests...
      Checking leftover processes...
      Removing old var directory...
      Creating var directory '/home/openxs/dbs/p5.7/mysql-test/var'...
      Installing system database...
      ...
      worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
      [100%] innodb.innodb-wl6742                     [ fail ]
              Test ended at 2018-12-07 13:15:02
      
      CURRENT_TEST: innodb.innodb-wl6742
      --- /home/openxs/dbs/p5.7/mysql-test/suite/innodb/r/innodb-wl6742.result       2016-02-25 12:44:41.000000000 +0300
      +++ /home/openxs/dbs/p5.7/mysql-test/var/log/innodb-wl6742.reject       2018-12-07 14:15:02.126726907 +0300
      @@ -1291,17 +1291,17 @@
       Note   1003    /* select#1 */ select `test`.`t1`.`c1` AS `c1`,`test`.`t1`.`c2` AS `c2`,`test`.`t1`.`c3` AS `c3`,`test`.`t1`.`c4` AS `c4` from `test`.`t1`
       EXPLAIN SELECT COUNT(*) FROM t1;
       id     select_type     table   partitions      type    possible_keys   key    key_len  ref     rows    filtered        Extra
      -1      SIMPLE  NULL    NULL    NULL    NULL    NULL    NULL    NULL    NULL   NULL     Select tables optimized away
      +1      SIMPLE  t1      NULL    index   NULL    k2      5       NULL    9      100.00   Using index
       Warnings:
       Note   1003    /* select#1 */ select count(0) AS `COUNT(*)` from `test`.`t1`
       EXPLAIN SELECT COUNT(*) FROM t3;
       id     select_type     table   partitions      type    possible_keys   key    key_len  ref     rows    filtered        Extra
      -1      SIMPLE  NULL    NULL    NULL    NULL    NULL    NULL    NULL    NULL   NULL     Select tables optimized away
      +1      SIMPLE  t3      p0,p1,p2,p3     index   NULL    k2      5       NULL   9100.00  Using index
       Warnings:
       Note   1003    /* select#1 */ select count(0) AS `COUNT(*)` from `test`.`t3`
       EXPLAIN SELECT COUNT(c1) FROM t1;
       id     select_type     table   partitions      type    possible_keys   key    key_len  ref     rows    filtered        Extra
      -1      SIMPLE  NULL    NULL    NULL    NULL    NULL    NULL    NULL    NULL   NULL     Select tables optimized away
      +1      SIMPLE  t1      NULL    index   NULL    k2      5       NULL    9      100.00   Using index
       Warnings:
       Note   1003    /* select#1 */ select count(`test`.`t1`.`c1`) AS `COUNT(c1)` from `test`.`t1`
       EXPLAIN SELECT COUNT(c2) FROM t1;
      @@ -1336,26 +1336,26 @@
       Note   1003    /* select#1 */ select avg(`test`.`t3`.`c1`) AS `AVG(c1)`,max(`test`.`t3`.`c1`) AS `MAX(c1)`,min(`test`.`t3`.`c2`) AS `MIN(c2)`,avg(`test`.`t3`.`c3`) AS `AVG(c3)`,sum(`test`.`t3`.`c4`) AS `SUM(c4)` from `test`.`t3`
       EXPLAIN SELECT c1, c2 FROM t1 WHERE c1 > ((SELECT COUNT(*) FROM t1) / 2);
       id     select_type     table   partitions      type    possible_keys   key    key_len  ref     rows    filtered        Extra
      -1      PRIMARY t1      NULL    index   PRIMARY k2      5       NULL    #      100.00   Using where; Using index
      -2      SUBQUERY        NULL    NULL    NULL    NULL    NULL    NULL    NULL   #NULL    Select tables optimized away
      +1      PRIMARY t1      NULL    range   PRIMARY PRIMARY 4       NULL    #      100.00   Using where
      +2      SUBQUERY        t1      NULL    index   NULL    k2      5       NULL   #100.00  Using index
       Warnings:
       Note   1003    /* select#1 */ select `test`.`t1`.`c1` AS `c1`,`test`.`t1`.`c2` AS `c2` from `test`.`t1` where (`test`.`t1`.`c1` > <cache>(((/* select#2 */ select count(0) from `test`.`t1`) / 2)))
       EXPLAIN SELECT c1, c2 FROM t1 WHERE c1 > ((SELECT COUNT(*) FROM t3) / 2);
       id     select_type     table   partitions      type    possible_keys   key    key_len  ref     rows    filtered        Extra
      -1      PRIMARY t1      NULL    index   PRIMARY k2      5       NULL    #      100.00   Using where; Using index
      -2      SUBQUERY        NULL    NULL    NULL    NULL    NULL    NULL    NULL   #NULL    Select tables optimized away
      +1      PRIMARY t1      NULL    range   PRIMARY PRIMARY 4       NULL    #      100.00   Using where
      +2      SUBQUERY        t3      p0,p1,p2,p3     index   NULL    k2      5      NULL     #       100.00  Using index
       Warnings:
       Note   1003    /* select#1 */ select `test`.`t1`.`c1` AS `c1`,`test`.`t1`.`c2` AS `c2` from `test`.`t1` where (`test`.`t1`.`c1` > <cache>(((/* select#2 */ select count(0) from `test`.`t3`) / 2)))
       EXPLAIN SELECT COUNT(c2) FROM t1 WHERE c1 > ((SELECT COUNT(*) FROM t1) / 2);
       id     select_type     table   partitions      type    possible_keys   key    key_len  ref     rows    filtered        Extra
      -1      PRIMARY t1      NULL    index   PRIMARY k2      5       NULL    #      100.00   Using where; Using index
      -2      SUBQUERY        NULL    NULL    NULL    NULL    NULL    NULL    NULL   #NULL    Select tables optimized away
      +1      PRIMARY t1      NULL    range   PRIMARY PRIMARY 4       NULL    #      100.00   Using where
      +2      SUBQUERY        t1      NULL    index   NULL    k2      5       NULL   #100.00  Using index
       Warnings:
       Note   1003    /* select#1 */ select count(`test`.`t1`.`c2`) AS `COUNT(c2)` from `test`.`t1` where (`test`.`t1`.`c1` > <cache>(((/* select#2 */ select count(0) from `test`.`t1`) / 2)))
       EXPLAIN SELECT COUNT(c2) FROM t1 WHERE c1 > ((SELECT COUNT(*) FROM t3) / 2);
       id     select_type     table   partitions      type    possible_keys   key    key_len  ref     rows    filtered        Extra
      -1      PRIMARY t1      NULL    index   PRIMARY k2      5       NULL    #      100.00   Using where; Using index
      -2      SUBQUERY        NULL    NULL    NULL    NULL    NULL    NULL    NULL   #NULL    Select tables optimized away
      +1      PRIMARY t1      NULL    range   PRIMARY PRIMARY 4       NULL    #      100.00   Using where
      +2      SUBQUERY        t3      p0,p1,p2,p3     index   NULL    k2      5      NULL     #       100.00  Using index
       Warnings:
       Note   1003    /* select#1 */ select count(`test`.`t1`.`c2`) AS `COUNT(c2)` from `test`.`t1` where (`test`.`t1`.`c1` > <cache>(((/* select#2 */ select count(0) from `test`.`t3`) / 2)))
       EXPLAIN SELECT COUNT(*) FROM t1 WHERE c1 > (SELECT AVG(c1) FROM t1);
      
      mysqltest: Result content mismatch
      
      safe_process[25537]: Child process: 25538, exit: 1
      
      
      
      Server [mysqld.1 - pid: 25508, winpid: 25508] log:
      Server log from this test:
      ----------SERVER LOG START-----------
      2018-12-07T11:14:49.058111Z 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4162)
      2018-12-07T11:14:49.058183Z 0 [Warning] Changed limits: table_open_cache: 431 (requested 2000)
      2018-12-07T11:14:49.230869Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
      2018-12-07T11:14:49.232971Z 0 [Warning] Insecure configuration for --secure-file-priv: Data directory is accessible through --secure-file-priv. Consider choosing a different directory.
      2018-12-07T11:14:49.233027Z 0 [Warning] Insecure configuration for --secure-file-priv: Location is accessible to all OS users. Consider choosing a different directory.
      2018-12-07T11:14:49.233098Z 0 [Note] /home/openxs/dbs/p5.7/bin/mysqld (mysqld 5.7.24-26-log) starting as process 25509 ...
      2018-12-07T11:14:49.237189Z 0 [Note] InnoDB: PUNCH HOLE support available
      2018-12-07T11:14:49.237218Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
      2018-12-07T11:14:49.237228Z 0 [Note] InnoDB: Uses event mutexes
      2018-12-07T11:14:49.237237Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
      2018-12-07T11:14:49.237246Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
      2018-12-07T11:14:49.237255Z 0 [Note] InnoDB: Using Linux native AIO
      2018-12-07T11:14:49.237601Z 0 [Note] InnoDB: Number of pools: 1
      2018-12-07T11:14:49.237740Z 0 [Note] InnoDB: Not using CPU crc32 instructions
      2018-12-07T11:14:49.239697Z 0 [Note] InnoDB: Initializing buffer pool, total size = 24M, instances = 1, chunk size = 24M
      2018-12-07T11:14:49.241391Z 0 [Note] InnoDB: Completed initialization of buffer pool
      2018-12-07T11:14:49.242460Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
      2018-12-07T11:14:49.254634Z 0 [Note] InnoDB: Crash recovery did not find the parallel doublewrite buffer at /home/openxs/dbs/p5.7/mysql-test/var/mysqld.1/data/xb_doublewrite
      2018-12-07T11:14:49.255703Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
      2018-12-07T11:14:49.495456Z 0 [Note] InnoDB: Created parallel doublewrite buffer at /home/openxs/dbs/p5.7/mysql-test/var/mysqld.1/data/xb_doublewrite, size 3932160 bytes
      2018-12-07T11:14:49.502953Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
      2018-12-07T11:14:49.503103Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
      2018-12-07T11:14:49.745882Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
      2018-12-07T11:14:49.747176Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
      2018-12-07T11:14:49.747200Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
      2018-12-07T11:14:49.747894Z 0 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.7.24-26 started; log sequence number 1356216
      2018-12-07T11:14:49.748070Z 0 [Note] InnoDB: Loading buffer pool(s) from /home/openxs/dbs/p5.7/mysql-test/var/mysqld.1/data/ib_buffer_pool
      2018-12-07T11:14:49.748515Z 0 [Note] Plugin 'FEDERATED' is disabled.
      2018-12-07T11:14:49.751139Z 0 [Note] InnoDB: Buffer pool(s) load completed at 181207 14:14:49
      2018-12-07T11:14:49.751168Z 0 [Warning] unknown variable 'loose-mysqlx-port=13009'
      2018-12-07T11:14:49.751182Z 0 [Warning] unknown variable 'loose-mysqlx-socket=/home/openxs/dbs/p5.7/mysql-test/var/tmp/mysqlx.1.sock'
      2018-12-07T11:14:49.751191Z 0 [Warning] unknown variable 'loose-sha256_password_auto_generate_rsa_keys=0'
      2018-12-07T11:14:49.751199Z 0 [Warning] unknown variable 'loose-debug-sync-timeout=600'
      2018-12-07T11:14:49.751876Z 0 [Note] Salting uuid generator variables, current_pid: 25509, server_start_time: 1544181289, bytes_sent: 0,
      2018-12-07T11:14:49.752020Z 0 [Note] Generated uuid: '4ff31a1f-fa11-11e8-9c19-485b3952834f', server_start_time: 7180145182456330702, bytes_sent: 40206128
      2018-12-07T11:14:49.752045Z 0 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: 4ff31a1f-fa11-11e8-9c19-485b3952834f.
      2018-12-07T11:14:49.780704Z 0 [Warning] CA certificate /home/openxs/dbs/p5.7/mysql-test/std_data/cacert.pem is self signed.
      2018-12-07T11:14:49.783069Z 0 [Note] Server hostname (bind-address): '*'; port: 13001
      2018-12-07T11:14:49.783135Z 0 [Note] IPv6 is available.
      2018-12-07T11:14:49.783147Z 0 [Note]   - '::' resolves to '::';
      2018-12-07T11:14:49.783184Z 0 [Note] Server socket created on IP: '::'.
      2018-12-07T11:14:49.810646Z 0 [Note] Failed to start slave threads for channel ''
      2018-12-07T11:14:49.820039Z 0 [Note] Event Scheduler: Loaded 0 events
      2018-12-07T11:14:49.820293Z 0 [Note] /home/openxs/dbs/p5.7/bin/mysqld: ready for connections.
      Version: '5.7.24-26-log'  socket: '/home/openxs/dbs/p5.7/mysql-test/var/tmp/mysqld.1.sock'  port: 13001  MySQL Community Server (GPL)
      2018-12-07T11:14:58.801110Z 3 [ERROR] Got error 155 when reading table './test/t4'
      ----------SERVER LOG END-------------
      
      
       - the logfile can be found in '/home/openxs/dbs/p5.7/mysql-test/var/log/innodb.innodb-wl6742/innodb-wl6742.log'
      --------------------------------------------------------------------------
      The servers were restarted 0 times
      Spent 0.000 of 29 seconds executing testcases
      
      Completed: Failed 1/1 tests, 0.00% were successful.
      
      Failing test(s): innodb.innodb-wl6742
      
      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
      

       

        Smart Checklist

          Attachments

            Activity

              People

              • Assignee:
                Unassigned
                Reporter:
                openxs2 Valerii
              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated: