goharbor / harbor

An open source trusted cloud native registry project that stores, signs, and scans content.
https://goharbor.io
Apache License 2.0
23.99k stars 4.75k forks source link

Unable to start harbor-db container after calling `restore` to rollback data via db-migrator. #3737

Closed steveal closed 6 years ago

steveal commented 6 years ago

docker info Server Version: 17.03.0-ce Storage Driver: overlay

[root@localhost harbor]# docker-compose version docker-compose version 1.10.0-rc2, build fb241d0 docker-py version: 2.0.1 CPython version: 2.7.9 OpenSSL version: OpenSSL 1.0.1t 3 May 2016


I want to update harbor from v1.1.2 to v1.3.0-rc1
I use offline file to update

Harbor work fine after I update from v1.1.2 and v1.2.2
the vmware/harbor-db-migrator:1.2 process well

But when i use

10.45.80.1/vmware/harbor-db-migrator         1.3                            6cac2b89f086        2 weeks ago         1.11 GB

to update the database, it failed.

Below is my log

backup and update

[root@localhost data]# docker run -ti --rm -e DB_USR=root -e DB_PWD=root123 -v /home/harbor/harbor/data/database:/var/lib/mysql -v /path/to/backup:/harbor-migration/backup 10.45.80.1/vmware/harbor-db-migrator:1.3 backup
Trying to start mysql server...
Waiting for MySQL start...
2017-12-04  5:15:17 139689153484736 [Note] mysqld (mysqld 10.2.10-MariaDB) starting as process 6 ...
2017-12-04  5:15:18 139689153484736 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-12-04  5:15:18 139689153484736 [Note] InnoDB: Uses event mutexes
2017-12-04  5:15:18 139689153484736 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-12-04  5:15:18 139689153484736 [Note] InnoDB: Number of pools: 1
2017-12-04  5:15:18 139689153484736 [Note] InnoDB: Using SSE2 crc32 instructions
2017-12-04  5:15:18 139689153484736 [Note] InnoDB: Initializing buffer pool, total size = 256M, instances = 1, chunk size = 128M
2017-12-04  5:15:18 139689153484736 [Note] InnoDB: Completed initialization of buffer pool
2017-12-04  5:15:18 139688157370112 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-12-04  5:15:18 139689153484736 [Note] InnoDB: Highest supported file format is Barracuda.
2017-12-04  5:15:18 139689153484736 [Note] InnoDB: Upgrading redo log: 2*50331648 bytes; LSN=8265507021
2017-12-04  5:15:18 139689153484736 [Note] InnoDB: Starting to delete and rewrite log files.
Waiting for MySQL start...
2017-12-04  5:15:18 139689153484736 [Note] InnoDB: Setting log file ./ib_logfile101 size to 50331648 bytes
2017-12-04  5:15:18 139689153484736 [Note] InnoDB: Setting log file ./ib_logfile1 size to 50331648 bytes
2017-12-04  5:15:18 139689153484736 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
2017-12-04  5:15:18 139689153484736 [Note] InnoDB: New log files created, LSN=8265507021
2017-12-04  5:15:19 139689153484736 [Note] InnoDB: 128 out of 128 rollback segments are active.
2017-12-04  5:15:19 139689153484736 [Note] InnoDB: Creating sys_virtual system tables.
2017-12-04  5:15:19 139689153484736 [Note] InnoDB: Creating shared tablespace for temporary tables
2017-12-04  5:15:19 139689153484736 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-12-04  5:15:19 139689153484736 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-12-04  5:15:19 139689153484736 [Note] InnoDB: Waiting for purge to start
2017-12-04  5:15:19 139689153484736 [Note] InnoDB: 5.7.20 started; log sequence number 0
2017-12-04  5:15:19 139687721146112 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2017-12-04  5:15:19 139687721146112 [Note] InnoDB: Cannot open '/var/lib/mysql/ib_buffer_pool' for reading: No such file or directory
2017-12-04  5:15:19 139689153484736 [Note] Plugin 'FEEDBACK' is disabled.
2017-12-04  5:15:19 139689153484736 [Note] Server socket created on IP: '::'.
2017-12-04  5:15:19 139689153484736 [ERROR] Missing system table mysql.roles_mapping; please run mysql_upgrade to create it
2017-12-04  5:15:19 139689153484736 [ERROR] Incorrect definition of table mysql.event: expected column 'sql_mode' at position 14 to have type set('REAL_AS_FLOAT','PIPES_AS_CONCAT','ANSI_QUOTES','IGNORE_SPACE','IGNORE_BAD_TABLE_OPTIONS','ONLY_FULL_GROUP_BY','NO_UNSIGNED_SUBTRACTION','NO_DIR_IN_CREATE','POSTGRESQL','ORACLE','MSSQL','DB2','MAXDB','NO_KEY_OPTIONS','NO_TABLE_OPTIONS','NO_FIELD_OPTIONS','MYSQL323','MYSQL40','ANSI','NO_AUTO_VALUE_ON_ZERO','NO_BACKSLASH_ESCAPES','STRICT_TRANS_TABLES','STRICT_ALL_TABLES','NO_ZERO_IN_DATE','NO_ZERO_DATE','INVALID_DATES','ERROR_FOR_DIVISION_BY_ZERO','TRADITIONAL','NO_AUTO_CREATE_USER','HIGH_NOT_PRECEDENCE','NO_ENGINE_SUBSTITUTION','PAD_CHAR_TO_FULL_LENGTH'), found type set('REAL_AS_FLOAT','PIPES_AS_CONCAT','ANSI_QUOTES','IGNORE_SPACE','NOT_USED','ONLY_FULL_GROUP_BY','NO_UNSIGNED_SUBTRACTION','NO_DIR_IN_CREATE','POSTGRESQL','ORACLE','MSSQL','DB2','MAXDB','NO_KEY_OPTIONS','NO_TABLE_OPTIONS','NO_FIELD_OPTIONS','MYSQL323','MYSQL40','ANSI','NO_AUTO_VALUE_ON_ZERO','NO_BACKSLASH_ESCAPES','STRICT_TRANS_TABLES','STRICT_A
2017-12-04  5:15:19 139689153484736 [ERROR] mysqld: Event Scheduler: An error occurred when initializing system tables. Disabling the Event Scheduler.
2017-12-04  5:15:19 139688988972800 [Warning] Failed to load slave replication state from table mysql.gtid_slave_pos: 1146: Table 'mysql.gtid_slave_pos' doesn't exist
2017-12-04  5:15:19 139689153484736 [Note] Reading of all Master_info entries succeded
2017-12-04  5:15:19 139689153484736 [Note] Added new Master_info '' to hash table
2017-12-04  5:15:19 139689153484736 [Note] mysqld: ready for connections.
Version: '10.2.10-MariaDB'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Source distribution
Performing backup...
Backup performed.
[root@localhost data]# docker run -ti --rm -e DB_USR=root -e DB_PWD=root123 -v /home/harbor/harbor/data/database:/var/lib/mysql 10.45.80.1/vmware/harbor-db-migrator:1.3 up head
Please backup before upgrade.
Enter y to continue updating or n to abort:y
Trying to start mysql server...
Waiting for MySQL start...
2017-12-04  5:16:41 139946010208192 [Note] mysqld (mysqld 10.2.10-MariaDB) starting as process 6 ...
2017-12-04  5:16:41 139946010208192 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-12-04  5:16:41 139946010208192 [Note] InnoDB: Uses event mutexes
2017-12-04  5:16:41 139946010208192 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-12-04  5:16:41 139946010208192 [Note] InnoDB: Number of pools: 1
2017-12-04  5:16:41 139946010208192 [Note] InnoDB: Using SSE2 crc32 instructions
2017-12-04  5:16:41 139946010208192 [Note] InnoDB: Initializing buffer pool, total size = 256M, instances = 1, chunk size = 128M
2017-12-04  5:16:41 139946010208192 [Note] InnoDB: Completed initialization of buffer pool
2017-12-04  5:16:41 139945016530688 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-12-04  5:16:41 139946010208192 [Note] InnoDB: Highest supported file format is Barracuda.
2017-12-04  5:16:41 139946010208192 [Note] InnoDB: Starting crash recovery from checkpoint LSN=8265509439
Waiting for MySQL start...
2017-12-04  5:16:42 139946010208192 [Note] InnoDB: 128 out of 128 rollback segments are active.
2017-12-04  5:16:42 139946010208192 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2017-12-04  5:16:42 139946010208192 [Note] InnoDB: Creating shared tablespace for temporary tables
2017-12-04  5:16:42 139946010208192 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-12-04  5:16:42 139946010208192 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-12-04  5:16:42 139946010208192 [Note] InnoDB: 5.7.20 started; log sequence number 8265509448
2017-12-04  5:16:42 139944370620160 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2017-12-04  5:16:42 139944370620160 [Note] InnoDB: Cannot open '/var/lib/mysql/ib_buffer_pool' for reading: No such file or directory
2017-12-04  5:16:42 139946010208192 [Note] Plugin 'FEEDBACK' is disabled.
2017-12-04  5:16:42 139946010208192 [Note] Recovering after a crash using tc.log
2017-12-04  5:16:42 139946010208192 [Note] Starting crash recovery...
2017-12-04  5:16:42 139946010208192 [Note] Crash recovery finished.
2017-12-04  5:16:42 139946010208192 [Note] Server socket created on IP: '::'.
2017-12-04  5:16:42 139946010208192 [ERROR] Missing system table mysql.roles_mapping; please run mysql_upgrade to create it
2017-12-04  5:16:42 139946010208192 [ERROR] Incorrect definition of table mysql.event: expected column 'sql_mode' at position 14 to have type set('REAL_AS_FLOAT','PIPES_AS_CONCAT','ANSI_QUOTES','IGNORE_SPACE','IGNORE_BAD_TABLE_OPTIONS','ONLY_FULL_GROUP_BY','NO_UNSIGNED_SUBTRACTION','NO_DIR_IN_CREATE','POSTGRESQL','ORACLE','MSSQL','DB2','MAXDB','NO_KEY_OPTIONS','NO_TABLE_OPTIONS','NO_FIELD_OPTIONS','MYSQL323','MYSQL40','ANSI','NO_AUTO_VALUE_ON_ZERO','NO_BACKSLASH_ESCAPES','STRICT_TRANS_TABLES','STRICT_ALL_TABLES','NO_ZERO_IN_DATE','NO_ZERO_DATE','INVALID_DATES','ERROR_FOR_DIVISION_BY_ZERO','TRADITIONAL','NO_AUTO_CREATE_USER','HIGH_NOT_PRECEDENCE','NO_ENGINE_SUBSTITUTION','PAD_CHAR_TO_FULL_LENGTH'), found type set('REAL_AS_FLOAT','PIPES_AS_CONCAT','ANSI_QUOTES','IGNORE_SPACE','NOT_USED','ONLY_FULL_GROUP_BY','NO_UNSIGNED_SUBTRACTION','NO_DIR_IN_CREATE','POSTGRESQL','ORACLE','MSSQL','DB2','MAXDB','NO_KEY_OPTIONS','NO_TABLE_OPTIONS','NO_FIELD_OPTIONS','MYSQL323','MYSQL40','ANSI','NO_AUTO_VALUE_ON_ZERO','NO_BACKSLASH_ESCAPES','STRICT_TRANS_TABLES','STRICT_A
2017-12-04  5:16:42 139946010208192 [ERROR] mysqld: Event Scheduler: An error occurred when initializing system tables. Disabling the Event Scheduler.
2017-12-04  5:16:42 139945537996544 [Warning] Failed to load slave replication state from table mysql.gtid_slave_pos: 1146: Table 'mysql.gtid_slave_pos' doesn't exist
2017-12-04  5:16:42 139946010208192 [Note] Reading of all Master_info entries succeded
2017-12-04  5:16:42 139946010208192 [Note] Added new Master_info '' to hash table
2017-12-04  5:16:42 139946010208192 [Note] mysqld: ready for connections.
Version: '10.2.10-MariaDB'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Source distribution
Performing upgrade head...
INFO  [alembic.runtime.migration] Context impl MySQLImpl.
INFO  [alembic.runtime.migration] Will assume non-transactional DDL.
1.2.0
INFO  [alembic.runtime.migration] Context impl MySQLImpl.
INFO  [alembic.runtime.migration] Will assume non-transactional DDL.
INFO  [alembic.runtime.migration] Running upgrade 1.2.0 -> 1.3.0, 1.2.0 to 1.3.0
/usr/lib/python2.7/site-packages/sqlalchemy/engine/default.py:470: Warning: (1146L, "Table 'mysql.column_stats' doesn't exist")
  cursor.execute(statement, parameters)
INFO  [alembic.runtime.migration] Context impl MySQLImpl.
INFO  [alembic.runtime.migration] Will assume non-transactional DDL.
1.3.0 (head)
Upgrade performed.
0
[root@localhost data]# 

rollback

[root@localhost data]# docker run -ti --rm -e DB_USR=root -e DB_PWD=root123 -v /home/harbor/harbor/data/database:/var/lib/mysql -v /path/to/backup:/harbor-migration/backup 10.45.80.1/vmware/harbor-db-migrator:1.3 restore
Trying to start mysql server...
Waiting for MySQL start...
2017-12-04  5:20:16 140314657937344 [Note] mysqld (mysqld 10.2.10-MariaDB) starting as process 6 ...
2017-12-04  5:20:16 140314657937344 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-12-04  5:20:16 140314657937344 [Note] InnoDB: Uses event mutexes
2017-12-04  5:20:16 140314657937344 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-12-04  5:20:16 140314657937344 [Note] InnoDB: Number of pools: 1
2017-12-04  5:20:16 140314657937344 [Note] InnoDB: Using SSE2 crc32 instructions
2017-12-04  5:20:16 140314657937344 [Note] InnoDB: Initializing buffer pool, total size = 256M, instances = 1, chunk size = 128M
2017-12-04  5:20:16 140314657937344 [Note] InnoDB: Completed initialization of buffer pool
2017-12-04  5:20:16 140313739482880 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-12-04  5:20:16 140314657937344 [Note] InnoDB: Highest supported file format is Barracuda.
2017-12-04  5:20:16 140314657937344 [Note] InnoDB: Starting crash recovery from checkpoint LSN=8265509467
2017-12-04  5:20:16 140314657937344 [Note] InnoDB: Ignoring data file './registry/project.ibd' with space ID 28, since the redo log references ./registry/project.ibd with space ID 9.
2017-12-04  5:20:16 140314657937344 [Note] InnoDB: Ignoring data file './registry/replication_target.ibd' with space ID 29, since the redo log references ./registry/replication_target.ibd with space ID 21.
2017-12-04  5:20:17 140314657937344 [Note] InnoDB: Starting final batch to recover 36 pages from redo log.
Waiting for MySQL start...
2017-12-04  5:20:17 140314657937344 [Note] InnoDB: 128 out of 128 rollback segments are active.
2017-12-04  5:20:17 140314657937344 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2017-12-04  5:20:17 140314657937344 [Note] InnoDB: Creating shared tablespace for temporary tables
2017-12-04  5:20:17 140314657937344 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-12-04  5:20:17 140314657937344 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-12-04  5:20:17 140314657937344 [Note] InnoDB: Waiting for purge to start
2017-12-04  5:20:17 140314657937344 [Note] InnoDB: 5.7.20 started; log sequence number 8265572217
2017-12-04  5:20:17 140312756352768 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2017-12-04  5:20:17 140312756352768 [Note] InnoDB: Cannot open '/var/lib/mysql/ib_buffer_pool' for reading: No such file or directory
2017-12-04  5:20:17 140314657937344 [Note] Plugin 'FEEDBACK' is disabled.
2017-12-04  5:20:17 140314657937344 [Note] Recovering after a crash using tc.log
2017-12-04  5:20:17 140314657937344 [Note] Starting crash recovery...
2017-12-04  5:20:17 140314657937344 [Note] Crash recovery finished.
2017-12-04  5:20:17 140314657937344 [Note] Server socket created on IP: '::'.
2017-12-04  5:20:17 140314657937344 [ERROR] Missing system table mysql.roles_mapping; please run mysql_upgrade to create it
2017-12-04  5:20:17 140314657937344 [ERROR] Incorrect definition of table mysql.event: expected column 'sql_mode' at position 14 to have type set('REAL_AS_FLOAT','PIPES_AS_CONCAT','ANSI_QUOTES','IGNORE_SPACE','IGNORE_BAD_TABLE_OPTIONS','ONLY_FULL_GROUP_BY','NO_UNSIGNED_SUBTRACTION','NO_DIR_IN_CREATE','POSTGRESQL','ORACLE','MSSQL','DB2','MAXDB','NO_KEY_OPTIONS','NO_TABLE_OPTIONS','NO_FIELD_OPTIONS','MYSQL323','MYSQL40','ANSI','NO_AUTO_VALUE_ON_ZERO','NO_BACKSLASH_ESCAPES','STRICT_TRANS_TABLES','STRICT_ALL_TABLES','NO_ZERO_IN_DATE','NO_ZERO_DATE','INVALID_DATES','ERROR_FOR_DIVISION_BY_ZERO','TRADITIONAL','NO_AUTO_CREATE_USER','HIGH_NOT_PRECEDENCE','NO_ENGINE_SUBSTITUTION','PAD_CHAR_TO_FULL_LENGTH'), found type set('REAL_AS_FLOAT','PIPES_AS_CONCAT','ANSI_QUOTES','IGNORE_SPACE','NOT_USED','ONLY_FULL_GROUP_BY','NO_UNSIGNED_SUBTRACTION','NO_DIR_IN_CREATE','POSTGRESQL','ORACLE','MSSQL','DB2','MAXDB','NO_KEY_OPTIONS','NO_TABLE_OPTIONS','NO_FIELD_OPTIONS','MYSQL323','MYSQL40','ANSI','NO_AUTO_VALUE_ON_ZERO','NO_BACKSLASH_ESCAPES','STRICT_TRANS_TABLES','STRICT_A
2017-12-04  5:20:17 140314657937344 [ERROR] mysqld: Event Scheduler: An error occurred when initializing system tables. Disabling the Event Scheduler.
2017-12-04  5:20:17 140314501818112 [Warning] Failed to load slave replication state from table mysql.gtid_slave_pos: 1146: Table 'mysql.gtid_slave_pos' doesn't exist
2017-12-04  5:20:17 140314657937344 [Note] Reading of all Master_info entries succeded
2017-12-04  5:20:17 140314657937344 [Note] Added new Master_info '' to hash table
2017-12-04  5:20:17 140314657937344 [Note] mysqld: ready for connections.
Version: '10.2.10-MariaDB'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Source distribution
Performing restore...
2017-12-04  5:20:18 140314501515008 [ERROR] Incorrect definition of table mysql.proc: expected column 'sql_mode' at position 14 to have type set('REAL_AS_FLOAT','PIPES_AS_CONCAT','ANSI_QUOTES','IGNORE_SPACE','IGNORE_BAD_TABLE_OPTIONS','ONLY_FULL_GROUP_BY','NO_UNSIGNED_SUBTRACTION','NO_DIR_IN_CREATE','POSTGRESQL','ORACLE','MSSQL','DB2','MAXDB','NO_KEY_OPTIONS','NO_TABLE_OPTIONS','NO_FIELD_OPTIONS','MYSQL323','MYSQL40','ANSI','NO_AUTO_VALUE_ON_ZERO','NO_BACKSLASH_ESCAPES','STRICT_TRANS_TABLES','STRICT_ALL_TABLES','NO_ZERO_IN_DATE','NO_ZERO_DATE','INVA
2017-12-04  5:20:18 140314501515008 [ERROR] Incorrect definition of table mysql.event: expected column 'sql_mode' at position 14 to have type set('REAL_AS_FLOAT','PIPES_AS_CONCAT','ANSI_QUOTES','IGNORE_SPACE','IGNORE_BAD_TABLE_OPTIONS','ONLY_FULL_GROUP_BY','NO_UNSIGNED_SUBTRACTION','NO_DIR_IN_CREATE','POSTGRESQL','ORACLE','MSSQL','DB2','MAXDB','NO_KEY_OPTIONS','NO_TABLE_OPTIONS','NO_FIELD_OPTIONS','MYSQL323','MYSQL40','ANSI','NO_AUTO_VALUE_ON_ZERO','NO_BACKSLASH_ESCAPES','STRICT_TRANS_TABLES','STRICT_ALL_TABLES','NO_ZERO_IN_DATE','NO_ZERO_DATE','INVALID_DATES','ERROR_FOR_DIVISION_BY_ZERO','TRADITIONAL','NO_AUTO_CREATE_USER','HIGH_NOT_PRECEDENCE','NO_ENGINE_SUBSTITUTION','PAD_CHAR_TO_FULL_LENGTH'), found type set('REAL_AS_FLOAT','PIPES_AS_CONCAT','ANSI_QUOTES','IGNORE_SPACE','NOT_USED','ONLY_FULL_GROUP_BY','NO_UNSIGNED_SUBTRACTION','NO_DIR_IN_CREATE','POSTGRESQL','ORACLE','MSSQL','DB2','MAXDB','NO_KEY_OPTIONS','NO_TABLE_OPTIONS','NO_FIELD_OPTIONS','MYSQL323','MYSQL40','ANSI','NO_AUTO_VALUE_ON_ZERO','NO_BACKSLASH_ESCAPES','STRICT_TRANS_TABLES','STRICT_A
Restore performed.

harbor-db mysql.log

Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 0 [Note] mysqld (mysqld 5.6.35) starting as process 1 ...
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Plugin 'FEDERATED' is disabled.
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] InnoDB: Using atomics to ref count buffer pool pages
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] InnoDB: The InnoDB memory heap is disabled
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] InnoDB: Memory barrier is not used
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] InnoDB: Compressed tables use zlib 1.2.8
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] InnoDB: Using Linux native AIO
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] InnoDB: Using CPU crc32 instructions
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] InnoDB: Initializing buffer pool, size = 128.0M
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] InnoDB: Completed initialization of buffer pool
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] InnoDB: Highest supported file format is Barracuda.
Dec  4 13:24:49 172.18.0.1 mysql[1279]: InnoDB: No valid checkpoint found.
Dec  4 13:24:49 172.18.0.1 mysql[1279]: InnoDB: If you are attempting downgrade from MySQL 5.7.9 or later,
Dec  4 13:24:49 172.18.0.1 mysql[1279]: InnoDB: please refer to http://dev.mysql.com/doc/refman/5.6/en/upgrading-downgrading.html
Dec  4 13:24:49 172.18.0.1 mysql[1279]: InnoDB: If this error appears when you are creating an InnoDB database,
Dec  4 13:24:49 172.18.0.1 mysql[1279]: InnoDB: the problem may be that during an earlier attempt you managed
Dec  4 13:24:49 172.18.0.1 mysql[1279]: InnoDB: to create the InnoDB data files, but log file creation failed.
Dec  4 13:24:49 172.18.0.1 mysql[1279]: InnoDB: If that is the case, please refer to
Dec  4 13:24:49 172.18.0.1 mysql[1279]: InnoDB: http://dev.mysql.com/doc/refman/5.6/en/error-creating-innodb.html
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [ERROR] Plugin 'InnoDB' init function returned error.
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [ERROR] Unknown/unsupported storage engine: InnoDB
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [ERROR] Aborting
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Binlog end
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'partition'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_FT_DELETED'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_METRICS'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_CMPMEM'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_CMP_RESET'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_CMP'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_LOCKS'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'INNODB_TRX'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'BLACKHOLE'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'ARCHIVE'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'MRG_MYISAM'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'MyISAM'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'CSV'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'MEMORY'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'sha256_password'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'mysql_old_password'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'mysql_native_password'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] Shutting down plugin 'binlog'
Dec  4 13:24:49 172.18.0.1 mysql[1279]: 2017-12-04 05:24:49 1 [Note] mysqld: Shutdown complete
reasonerjt commented 6 years ago

Root cause is after running upgrade the data file no longer work for mysql:5.6 image. @ninjadq please investigate if there's a fix, we probably need to treat this as a limitation.

ninjadq commented 6 years ago

Yes, there is a compatible problem when Mysql restore data from file dumped by MariaDB

We should restore & backup data using the same db.

I'll update this on document.

ninjadq commented 6 years ago

fixed in #3907