Search code examples
mysqlkubernetesopenshift-originglusterfs

InnoDB: Header page consists of zero bytes in datafile: ./ibdata1


I am deploying MySQL on openshift (kubernetes) but getting below error

---> 10:01:34     Initializing database ...
---> 10:01:34     Running /opt/rh/rh-mysql57/root/usr/libexec/mysqld --initialize --datadir=/var/lib/mysql/data --ignore-db-dir=lost+found
---> 10:01:35     Starting MySQL server with disabled networking ...
---> 10:01:35     Waiting for MySQL to start ...
2019-10-18T10:01:35.188509Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2019-10-18T10:01:35.188567Z 0 [Warning] 'NO_AUTO_CREATE_USER' sql mode was not set.
2019-10-18T10:01:35.325995Z 0 [Note] /opt/rh/rh-mysql57/root/usr/libexec/mysqld (mysqld 5.7.24) starting as process 40 ...
2019-10-18T10:01:35.430574Z 0 [Note] InnoDB: PUNCH HOLE support available
2019-10-18T10:01:35.430612Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2019-10-18T10:01:35.430621Z 0 [Note] InnoDB: Uses event mutexes
2019-10-18T10:01:35.430627Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2019-10-18T10:01:35.430634Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
2019-10-18T10:01:35.430642Z 0 [Note] InnoDB: Using Linux native AIO
2019-10-18T10:01:35.431024Z 0 [Note] InnoDB: Number of pools: 1
2019-10-18T10:01:35.431174Z 0 [Note] InnoDB: Using CPU crc32 instructions
2019-10-18T10:01:35.433296Z 0 [Note] InnoDB: Initializing buffer pool, total size = 2G, instances = 8, chunk size = 128M
2019-10-18T10:01:35.584269Z 0 [Note] InnoDB: Completed initialization of buffer pool
2019-10-18T10:01:35.610249Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2019-10-18T10:01:35.624480Z 0 [ERROR] InnoDB: Header page consists of zero bytes in datafile: ./ibdata1, Space ID:0, Flags: 0. Please refer to http://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html  for how to resolve the issue.
2019-10-18T10:01:35.624518Z 0 [ERROR] InnoDB: Corrupted page [page id: space=0, page number=0] of datafile './ibdata1' could not be found in the doublewrite buffer.
2019-10-18T10:01:35.624667Z 0 [ERROR] InnoDB: Plugin initialization aborted with error Data structure corruption
---> 10:01:36     Waiting for MySQL to start ...
2019-10-18T10:01:36.225356Z 0 [ERROR] Plugin 'InnoDB' init function returned error.
2019-10-18T10:01:36.225372Z 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2019-10-18T10:01:36.225377Z 0 [ERROR] Failed to initialize builtin plugins.
2019-10-18T10:01:36.225380Z 0 [ERROR] Aborting
2019-10-18T10:01:36.225393Z 0 [Note] Binlog end
2019-10-18T10:01:36.225454Z 0 [Note] Shutting down plugin 'CSV'
2019-10-18T10:01:36.233760Z 0 [Note] /opt/rh/rh-mysql57/root/usr/libexec/mysqld: Shutdown complete

I searched on google and they recommend to do following

rm -rf /var/lib/mysql/ib_logfile*

but as you know in docker and kubernetes world as soon as pod is not able to come up we cant login to pod and delete these files. Due to this error MySQL pod is not coming up.

I am using glusterfs and i deleted PVC and recreated but still same error.

Update1: After recommendation of @Crou i did following changes

  • I downloaded new "centos/mysql-57-centos7:5.7" image and retry still same issue
  • I used mysql:5.7 image and now its throwing following error

  • I deleted PVC and recreated with different size but still same error.

[ERROR] --initialize specified but the data directory has files in it. Aborting. [ERROR] Aborting


Solution

  • After different retries i am able to solve issues, Following are findings

    • I observed that when first time i recreate PVC and deploy mysql it take too much time at this line

      Running /opt/rh/rh-mysql57/root/usr/libexec/mysqld --initialize --datadir=/var/lib/mysql/data --ignore-db-dir=lost+found

    • During this time LiveProbe time exaust and it restart the container, which result in subjected error.

    • I increased the time of initialDelaySeconds under livenessProbe to 240, this time it started mysql after 4 mins

    • After 4 minutes it shows Starting MySQL server with disabled networking and start doing further.

    My applications are able to connect it but i dont know what would be the impact of this?

    ---> 16:18:24     Running /opt/rh/rh-mysql57/root/usr/libexec/mysqld --initialize --datadir=/var/lib/mysql/data --ignore-db-dir=lost+found
    ---> 16:22:15     Starting MySQL server with disabled networking ...
    ---> 16:22:15     Waiting for MySQL to start ...
    2019-10-18T16:22:15.752499Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
    2019-10-18T16:22:15.772646Z 0 [Note] /opt/rh/rh-mysql57/root/usr/libexec/mysqld (mysqld 5.7.24) starting as process 69 ...
    2019-10-18T16:22:15.849580Z 0 [Note] InnoDB: PUNCH HOLE support available
    2019-10-18T16:22:15.849613Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
    2019-10-18T16:22:15.849617Z 0 [Note] InnoDB: Uses event mutexes
    2019-10-18T16:22:15.849621Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
    2019-10-18T16:22:15.849624Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
    2019-10-18T16:22:15.849629Z 0 [Note] InnoDB: Using Linux native AIO
    2019-10-18T16:22:15.850236Z 0 [Note] InnoDB: Number of pools: 1
    2019-10-18T16:22:15.850459Z 0 [Note] InnoDB: Using CPU crc32 instructions
    2019-10-18T16:22:15.852211Z 0 [Note] InnoDB: Initializing buffer pool, total size = 2G, instances = 8, chunk size = 128M
    2019-10-18T16:22:15.978704Z 0 [Note] InnoDB: Completed initialization of buffer pool
    2019-10-18T16:22:16.005183Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
    2019-10-18T16:22:16.208237Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
    2019-10-18T16:22:16.402086Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
    2019-10-18T16:22:16.414708Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
    ---> 16:22:17     Waiting for MySQL to start ...
    ---> 16:22:18     Waiting for MySQL to start ...
    2019-10-18T16:22:18.601639Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
    2019-10-18T16:22:18.608922Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
    2019-10-18T16:22:18.608943Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
    2019-10-18T16:22:18.609240Z 0 [Note] InnoDB: Waiting for purge to start
    2019-10-18T16:22:18.659387Z 0 [Note] InnoDB: 5.7.24 started; log sequence number 2592555
    2019-10-18T16:22:18.659667Z 0 [Note] Plugin 'FEDERATED' is disabled.
    2019-10-18T16:22:18.663687Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/data/ib_buffer_pool
    2019-10-18T16:22:18.808093Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
    2019-10-18T16:22:18.808117Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory.
    2019-10-18T16:22:18.825225Z 0 [Warning] CA certificate ca.pem is self signed.
    2019-10-18T16:22:18.828435Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory.
    2019-10-18T16:22:18.885079Z 0 [Note] InnoDB: Buffer pool(s) load completed at 191018 16:22:18
    2019-10-18T16:22:18.948358Z 0 [Warning] 'user' entry 'root@localhost' ignored in --skip-name-resolve mode.
    2019-10-18T16:22:18.948397Z 0 [Warning] 'user' entry 'mysql.session@localhost' ignored in --skip-name-resolve mode.
    2019-10-18T16:22:18.948404Z 0 [Warning] 'user' entry 'mysql.sys@localhost' ignored in --skip-name-resolve mode.
    2019-10-18T16:22:18.948428Z 0 [Warning] 'db' entry 'performance_schema mysql.session@localhost' ignored in --skip-name-resolve mode.
    2019-10-18T16:22:18.948435Z 0 [Warning] 'db' entry 'sys mysql.sys@localhost' ignored in --skip-name-resolve mode.
    2019-10-18T16:22:18.948448Z 0 [Warning] 'proxies_priv' entry '@ root@localhost' ignored in --skip-name-resolve mode.
    2019-10-18T16:22:19.034170Z 0 [Warning] 'tables_priv' entry 'user mysql.session@localhost' ignored in --skip-name-resolve mode.
    2019-10-18T16:22:19.034191Z 0 [Warning] 'tables_priv' entry 'sys_config mysql.sys@localhost' ignored in --skip-name-resolve mode.
    2019-10-18T16:22:19.633088Z 0 [Note] Event Scheduler: Loaded 0 events
    2019-10-18T16:22:19.633217Z 1 [Note] Event Scheduler: scheduler thread started with id 1
    2019-10-18T16:22:19.633316Z 0 [Note] /opt/rh/rh-mysql57/root/usr/libexec/mysqld: ready for connections.
    Version: '5.7.24'  socket: '/tmp/mysql.sock'  port: 0  MySQL Community Server (GPL)
    2019-10-18T16:22:19.634316Z 3 [Note] Your password has expired. To log in you must change it using a client that supports expired passwords.
    ---> 16:22:19     MySQL started successfully
    ---> 16:22:19     Setting password for MySQL root user ...