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

innodb.innodb-32k-crash failed in buildbot with CORRUPT LOG RECORD FOUND

    XMLWordPrintable

    Details

      Description

      http://buildbot.askmonty.org/buildbot/builders/kvm-bintar-trusty-x86/builds/7095

      innodb.innodb-32k-crash 'innodb'         w3 [ fail ]
              Test ended at 2018-08-10 12:02:49
       
      CURRENT_TEST: innodb.innodb-32k-crash
       
       
      Server [mysqld.1 - pid: 3163, winpid: 3163, exit: 256] failed during test run
      Server log from this test:
      ----------SERVER LOG START-----------
      2018-08-10 12:02:47 3056940800 [Note] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld (mysqld 10.2.17-MariaDB-log) starting as process 3109 ...
      2018-08-10 12:02:47 3056940800 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4182)
      2018-08-10 12:02:47 3056940800 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
      2018-08-10 12:02:47 3056940800 [Note] Plugin 'SEQUENCE' is disabled.
      2018-08-10 12:02:47 3056940800 [Note] Plugin 'partition' is disabled.
      2018-08-10 12:02:47 3056940800 [Note] InnoDB: innodb_page_size=32768
      2018-08-10 12:02:47 3056940800 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
      2018-08-10 12:02:47 3056940800 [Note] InnoDB: Uses event mutexes
      2018-08-10 12:02:47 3056940800 [Note] InnoDB: Compressed tables use zlib 1.2.3
      2018-08-10 12:02:47 3056940800 [Note] InnoDB: Using Linux native AIO
      2018-08-10 12:02:47 3056940800 [Note] InnoDB: Number of pools: 1
      2018-08-10 12:02:47 3056940800 [Note] InnoDB: Using generic crc32 instructions
      2018-08-10 12:02:47 3056940800 [Note] InnoDB: Initializing buffer pool, total size = 32M, instances = 1, chunk size = 32M
      2018-08-10 12:02:47 3056940800 [Note] InnoDB: Completed initialization of buffer pool
      2018-08-10 12:02:47 2864409408 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
      2018-08-10 12:02:47 3056940800 [Note] InnoDB: Highest supported file format is Barracuda.
      2018-08-10 12:02:47 3056940800 [Note] InnoDB: 128 out of 128 rollback segments are active.
      2018-08-10 12:02:47 3056940800 [Note] InnoDB: Creating shared tablespace for temporary tables
      2018-08-10 12:02:47 3056940800 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
      2018-08-10 12:02:47 3056940800 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
      2018-08-10 12:02:48 3056940800 [Note] InnoDB: 5.7.23 started; log sequence number 3116674
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_MUTEXES' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_CMP' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'FEEDBACK' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'user_variables' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
      2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
      2018-08-10 12:02:48 3056940800 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown variable 'loose-feedback-debug-startup-interval=20'
      2018-08-10 12:02:48 3056940800 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown variable 'loose-feedback-debug-first-interval=60'
      2018-08-10 12:02:48 3056940800 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown variable 'loose-feedback-debug-interval=60'
      2018-08-10 12:02:48 3056940800 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown option '--loose-pam-debug'
      2018-08-10 12:02:48 3056940800 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown variable 'loose-debug-sync-timeout=300'
      2018-08-10 12:02:48 2759842624 [Note] InnoDB: Loading buffer pool(s) from /run/shm/var_auto_0FDL/3/mysqld.1/data/ib_buffer_pool
      2018-08-10 12:02:48 3056940800 [Note] Server socket created on IP: '127.0.0.1'.
      2018-08-10 12:02:48 2759842624 [Note] InnoDB: Buffer pool(s) load completed at 180810 12:02:48
      2018-08-10 12:02:48 3056940800 [Note] Reading of all Master_info entries succeded
      2018-08-10 12:02:48 3056940800 [Note] Added new Master_info '' to hash table
      2018-08-10 12:02:48 3056940800 [Note] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: ready for connections.
      Version: '10.2.17-MariaDB-log'  socket: '/usr/local/mariadb-10.2.17-linux-i686/mysql-test/var/tmp/3/mysqld.1.sock'  port: 16040  MariaDB Server
      2018-08-10 12:02:49 3057477376 [Note] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld (mysqld 10.2.17-MariaDB-log) starting as process 3164 ...
      2018-08-10 12:02:49 3057477376 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4182)
      2018-08-10 12:02:49 3057477376 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'SEQUENCE' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'partition' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] InnoDB: innodb_page_size=32768
      2018-08-10 12:02:49 3057477376 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
      2018-08-10 12:02:49 3057477376 [Note] InnoDB: Uses event mutexes
      2018-08-10 12:02:49 3057477376 [Note] InnoDB: Compressed tables use zlib 1.2.3
      2018-08-10 12:02:49 3057477376 [Note] InnoDB: Using Linux native AIO
      2018-08-10 12:02:49 3057477376 [Note] InnoDB: Number of pools: 1
      2018-08-10 12:02:49 3057477376 [Note] InnoDB: Using generic crc32 instructions
      2018-08-10 12:02:49 3057477376 [Note] InnoDB: Initializing buffer pool, total size = 32M, instances = 1, chunk size = 32M
      2018-08-10 12:02:49 3057477376 [Note] InnoDB: Completed initialization of buffer pool
      2018-08-10 12:02:49 2865457984 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
      2018-08-10 12:02:49 3057477376 [Note] InnoDB: Highest supported file format is Barracuda.
      2018-08-10 12:02:49 3057477376 [Note] InnoDB: Starting crash recovery from checkpoint LSN=3116674
      2018-08-10 12:02:49 3057477376 [ERROR] InnoDB: ############### CORRUPT LOG RECORD FOUND ##################
      2018-08-10 12:02:49 3057477376 [Note] InnoDB: Log record type 1, page 4:97. Log parsing proceeded successfully up to 5721161. Previous log record type 1, is multi 1 Recv offset 636496, prev 636490
      2018-08-10 12:02:49 3057477376 [Note] InnoDB: Hex dump starting 100 bytes before and ending 0 bytes after the corrupted record:
       len 106; hex 636363636363636363636363636363636363636363636363636363636363636363630104613ffe00010461401200010461402600010461403a00010461404e00010461406200010461407600010461408a00010461409e0001046140b20001046140c60001046140da00; asc cccccccccccccccccccccccccccccccccc  a?    a@    a@&   a@:   a@N   a@b   a@v   a@    a@    a@    a@    a@  ;
      2018-08-10 12:02:49 3057477376 [Note] InnoDB: Set innodb_force_recovery to ignore this error.
      2018-08-10 12:02:49 3057477376 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
      2018-08-10 12:02:49 3057477376 [Note] InnoDB: Starting shutdown...
      2018-08-10 12:02:49 3057477376 [ERROR] Plugin 'InnoDB' init function returned error.
      2018-08-10 12:02:49 3057477376 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_MUTEXES' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_CMP' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'FEEDBACK' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'user_variables' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
      2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
      2018-08-10 12:02:49 3057477376 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown variable 'loose-feedback-debug-startup-interval=20'
      2018-08-10 12:02:49 3057477376 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown variable 'loose-feedback-debug-first-interval=60'
      2018-08-10 12:02:49 3057477376 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown variable 'loose-feedback-debug-interval=60'
      2018-08-10 12:02:49 3057477376 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown option '--loose-pam-debug'
      2018-08-10 12:02:49 3057477376 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown variable 'loose-debug-sync-timeout=300'
      2018-08-10 12:02:49 3057477376 [ERROR] Unknown/unsupported storage engine: InnoDB
      2018-08-10 12:02:49 3057477376 [ERROR] Aborting
       
      ----------SERVER LOG END-------------
      mysqltest failed but provided no output
      The result from queries just before the failure was:
      < snip >
      UPDATE t1 SET ka=@d,la=@d,ma=@d,na=@d,oa=@d,pa=@d;
      UPDATE t1 SET qa=@d,ra=@d,sa=@d,ta=@d,ua=@d;
      UPDATE t1 SET va=@d,wa=@d,xa=@d,ya=@d,za=@d;
      COMMIT;
      BEGIN;
      UPDATE t2 SET a=@l,b=@l,c=@l,d=@l,e=@l;
      UPDATE t2 SET f=@l,g=@l,h=@l,i=@l,j=@l;
      UPDATE t2 SET k=@l,l=@l,m=@l,n=@l,o=@l;
      UPDATE t2 SET p=@l,q=@l,r=@l,s=@l,t=@l,u=@l;
      UPDATE t2 SET v=@l,w=@l,x=@l,y=@l,z=@l;
      UPDATE t2 SET aa=@l,ba=@l,ca=@l,da=@l;
      UPDATE t2 SET ea=@l,fa=@l,ga=@l,ha=@l,ia=@l,ja=@l;
      UPDATE t2 SET ka=@l,la=@l,ma=@l,na=@l,oa=@l,pa=@l;
      UPDATE t2 SET qa=@l,ra=@l,sa=@l,ta=@l,ua=@l;
      UPDATE t2 SET va=@l,wa=@l,xa=@l,ya=@l,za=@l;
      COMMIT;
      BEGIN;
      INSERT INTO t1 SELECT * from t2;
      BEGIN;
      UPDATE t1 SET a=@e,b=@e,c=@e,d=@e,e=@e;
      

        Attachments

          Activity

            People

            Assignee:
            marko Marko Mäkelä
            Reporter:
            elenst Elena Stepanova
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved: