Bug #97168 Upgrade 5.7 to 8.0 fails: "Data Dictionary upgrade from MySQL 5.7 in progress"
Submitted: 9 Oct 2019 23:33 Modified: 11 Oct 2019 20:49
Reporter: Adam Friedman Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server Severity:S1 (Critical)
Version:8.0 OS:Ubuntu (18.04)
Assigned to: Bogdan Kecman CPU Architecture:Any

[9 Oct 2019 23:33] Adam Friedman
Description:
Ran the mysql upgrade shell to conduct a check before upgrading from 5.7 to 8.0. Only errors found was my use of three system variables that will be removed:
"13) Removed system variables
  Error: Following system variables that were detected as being used will be
    removed. Please update your system to not rely on them before the upgrade.
  More information:
    https://dev.mysql.com/doc/refman/8.0/en/added-deprecated-removed.html#optvars-removed

  query_cache_limit - is set and will be removed
  query_cache_size - is set and will be removed
  query_cache_type - is set and will be removed"

Otherwise, all looked good. 

=== But upon installing the binaries and an attempt to start mysql server, this error occurs every time:

   Active: failed (Result: exit-code) since Wed 2019-10-09 22:52:36 UTC; 10ms ago
     Docs: man:mysqld(8)
           http://dev.mysql.com/doc/refman/en/using-systemd.html
  Process: 3022 ExecStart=/usr/sbin/mysqld (code=exited, status=1/FAILURE)
  Process: 2986 ExecStartPre=/usr/share/mysql-8.0/mysql-systemd-start pre (code=exited, status=0/SUCCESS)
 Main PID: 3022 (code=exited, status=1/FAILURE)
   Status: "Data Dictionary upgrade from MySQL 5.7 in progress"

Oct 09 22:52:33 db-1-staging systemd[1]: Starting MySQL Community Server...
Oct 09 22:52:33 db-1-staging mysql-systemd-start[2986]: /usr/share/mysql-8.0/mysql-systemd-start: line 39: /lib/apparmor/profile-load: No such file or directory
Oct 09 22:52:36 db-1-staging systemd[1]: mysql.service: Main process exited, code=exited, status=1/FAILURE
Oct 09 22:52:36 db-1-staging systemd[1]: mysql.service: Failed with result 'exit-code'.
Oct 09 22:52:36 db-1-staging systemd[1]: Failed to start MySQL Community Server.
Job for mysql.service failed because the control process exited with error code.
See "systemctl status mysql.service" and "journalctl -xe" for details.

==== FYI here is the full output of the upgrade shell:

mysqlsh> util.checkForServerUpgrade()

The MySQL server at 127.0.0.1, version 5.7.26-log - MySQL Community Server
(GPL), will now be checked for compatibility issues for upgrade to MySQL
8.0.16...

1) Usage of old temporal type
  No issues found

2) Usage of db objects with names conflicting with reserved keywords in 8.0
  No issues found

3) Usage of utf8mb3 charset
  Warning: The following objects use the utf8mb3 character set. It is
    recommended to convert them to use utf8mb4 instead, for improved Unicode
    support.
  More information:
    https://dev.mysql.com/doc/refman/8.0/en/charset-unicode-utf8mb3.html

  elstats_app_MA--orig_ids - schema's default character set: utf8
  tester - schema's default character set: utf8
  elstats_app.ap_candidates.TestFlag - column's default character set: utf8
  elstats_app.ap_candidates.FirstName - column's default character set: utf8
  elstats_app.ap_candidates.MiddleName - column's default character set: utf8
  [.... etc etc ....]

4) Table names in the mysql schema conflicting with new tables in 8.0
  No issues found

5) Foreign key constraint names longer than 64 characters
  No issues found

6) Usage of obsolete MAXDB sql_mode flag
  No issues found

7) Usage of obsolete sql_mode flags
  No issues found

8) ENUM/SET column definitions containing elements longer than 255 characters
  No issues found

9) Usage of partitioned tables in shared tablespaces
  No issues found

10) Usage of removed functions
  No issues found

11) Usage of removed GROUP BY ASC/DESC syntax
  No issues found

12) Removed system variables for error logging to the system log configuration
  No issues found

13) Removed system variables
  Error: Following system variables that were detected as being used will be
    removed. Please update your system to not rely on them before the upgrade.
  More information:
    https://dev.mysql.com/doc/refman/8.0/en/added-deprecated-removed.html#optvars-removed

  query_cache_limit - is set and will be removed
  query_cache_size - is set and will be removed
  query_cache_type - is set and will be removed

14) System variables with new default values
  Warning: Following system variables that are not defined in your
    configuration file will have new default values. Please review if you rely on
    their current values and if so define them before performing upgrade.
  More information:
    https://mysqlserverteam.com/new-defaults-in-mysql-8-0/

  back_log - default value will change
  character_set_server - default value will change from latin1 to utf8mb4
  collation_server - default value will change from latin1_swedish_ci to
    utf8mb4_0900_ai_ci
  event_scheduler - default value will change from OFF to ON
  explicit_defaults_for_timestamp - default value will change from OFF to ON
  innodb_autoinc_lock_mode - default value will change from 1 (consecutive) to
    2 (interleaved)
  innodb_flush_method - default value will change from NULL to fsync (Unix),
    unbuffered (Windows)
  innodb_flush_neighbors - default value will change from 1 (enable) to 0
    (disable)
  innodb_max_dirty_pages_pct - default value will change from 75 (%)  90 (%)
  innodb_max_dirty_pages_pct_lwm - default value will change from_0 (%) to 10
    (%)
  innodb_undo_log_truncate - default value will change from OFF to ON
  innodb_undo_tablespaces - default value will change from 0 to 2
  log_error_verbosity - default value will change from 3 (Notes) to 2 (Warning)
  log_slave_updates - default value will change from OFF to ON
  master_info_repository - default value will change from FILE to TABLE
  max_error_count - default value will change from 64 to 1024
  optimizer_trace_max_mem_size - default value will change from 16KB to 1MB
  performance_schema_consumer_events_transactions_current - default value will
    change from OFF to ON
  performance_schema_consumer_events_transactions_history - default value will
    change from OFF to ON
  relay_log_info_repository - default value will change from FILE to TABLE
  server_id - default value will change from 0 to 1
  slave_rows_search_algorithms - default value will change from 'INDEX_SCAN,
    TABLE_SCAN' to 'INDEX_SCAN, HASH_SCAN'
  table_open_cache - default value will change from 2000 to 4000
  transaction_write_set_extraction - default value will change from OFF to
    XXHASH64

15) Schema inconsistencies resulting from file removal or corruption
  No issues found

16) Issues reported by 'check table x for upgrade' command
  No issues found

17) New default authentication plugin considerations
  Warning: The new default authentication plugin 'caching_sha2_password' offers
    more secure password hashing than previously used 'mysql_native_password'
    (and consequent improved client connection authentication). However, it also
    has compatibility implications that may affect existing MySQL installations.
    If your MySQL installation must serve pre-8.0 clients and you encounter
    compatibility issues after upgrading, the simplest way to address those
    issues is to reconfigure the server to revert to the previous default
    authentication plugin (mysql_native_password). For example, use these lines
    in the server option file:

    [mysqld]
    default_authentication_plugin=mysql_native_password

    However, the setting should be viewed as temporary, not as a long term or
    permanent solution, because it causes new accounts created with the setting
    in effect to forego the improved authentication security.
    If you are using replication please take time to understand how the
    authentication plugin changes may impact you.
  More information:
    https://dev.mysql.com/doc/refman/8.0/en/upgrading-from-previous-series.html#upgrade-cachin...
    https://dev.mysql.com/doc/refman/8.0/en/upgrading-from-previous-series.html#upgrade-cachin...

Errors:   3
Warnings: 428
Notices:  0

How to repeat:
Go through the upgrade process? I imagine that some corruption of the `mysql` system database has occurred, or there is a permission problem?

Suggested fix:
I am really unsure.
[10 Oct 2019 10:29] Lars Tangvald
Hi,

The service line about the missing apparmor loader shouldn't be fatal, but is a bit odd on a Ubuntu 18.04 system. Is apparmor installed?

Could you check in the error log at /var/log/mysql/error.log if there are any lines with "ERROR" in them? They might show what the issue is.
[10 Oct 2019 10:42] Bogdan Kecman
Hi Adam,

As Lars said, the apparmor should not be fatal, can you upload the whole mysql error log.

thanks
[10 Oct 2019 15:02] Adam Friedman
Here is the corresponding entry in /var/log/mysql/error.log:

2019-10-10T14:52:19.124803Z 0 [Warning] [MY-011070] [Server] 'Disabling symbolic links using --skip-symbolic-links (or equivalent) is the default. Consider not using this option as it' is deprecated and will be removed in a future release.
2019-10-10T14:52:19.124834Z 0 [Warning] [MY-011068] [Server] The syntax 'expire-logs-days' is deprecated and will be removed in a future release. Please use binlog_expire_logs_seconds instead.
2019-10-10T14:52:19.126852Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.17) starting as process 855
2019-10-10T14:52:19.126909Z 0 [Warning] [MY-010339] [Server] Using pre 5.5 semantics to load error messages from /usr/share/mysql/. If this is not intended, refer to the documentation for valid usage of --lc-messages-dir and --language parameters.
2019-10-10T14:52:19.126929Z 0 [ERROR] [MY-010342] [Server] Can't read from messagefile '/usr/share/mysql/errmsg.sys'
2019-10-10T14:52:19.137755Z 1 [System] [MY-011012] [Server] Starting upgrade of data directory.
 100 200
 100 200
mysqld: Duplicate entry 'innodb_system' for key 'name'
2019-10-10T14:52:21.046135Z 1 [ERROR] [MY-011006] [Server] Got error 168 from SE while migrating tablespaces.
2019-10-10T14:52:21.051830Z 0 [ERROR] [MY-010020] [Server] Data Dictionary initialization failed.
2019-10-10T14:52:21.052106Z 0 [ERROR] [MY-010119] [Server] Aborting
2019-10-10T14:52:22.655955Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.17)  MySQL Community Server - GPL.
2019-10-10T14:52:23.594891Z 0 [Warning] [MY-011070] [Server] 'Disabling symbolic links using --skip-symbolic-links (or equivalent) is the default. Consider not using this option as it' is deprecated and will be removed in a future release.
2019-10-10T14:52:23.594920Z 0 [Warning] [MY-011068] [Server] The syntax 'expire-logs-days' is deprecated and will be removed in a future release. Please use binlog_expire_logs_seconds instead.
2019-10-10T14:52:23.598550Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.17) starting as process 979
2019-10-10T14:52:23.598617Z 0 [Warning] [MY-010339] [Server] Using pre 5.5 semantics to load error messages from /usr/share/mysql/. If this is not intended, refer to the documentation for valid usage of --lc-messages-dir and --language parameters.
2019-10-10T14:52:23.598639Z 0 [ERROR] [MY-010342] [Server] Can't read from messagefile '/usr/share/mysql/errmsg.sys'
2019-10-10T14:52:23.609966Z 1 [System] [MY-011012] [Server] Starting upgrade of data directory.
 100 200
 100 200
mysqld: Duplicate entry 'innodb_system' for key 'name'
2019-10-10T14:52:25.325165Z 1 [ERROR] [MY-011006] [Server] Got error 168 from SE while migrating tablespaces.
2019-10-10T14:52:25.331997Z 0 [ERROR] [MY-010020] [Server] Data Dictionary initialization failed.
2019-10-10T14:52:25.332328Z 0 [ERROR] [MY-010119] [Server] Aborting
2019-10-10T14:52:26.866011Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.17)  MySQL Community Server - GPL
[10 Oct 2019 15:17] Adam Friedman
I see this bug may be a duplicate of this one: https://bugs.mysql.com/bug.php?id=90711 -- I have this relic row "innodb_system" in my information_schema.INNODB_SYS_TABLESPACES which seems to be the root of the problem:

mysql> select * from INNODB_SYS_TABLESPACES where name like '%innodb%';
+-------+--------------------------+------+-------------+----------------------+-----------+---------------+------------+---------------+-----------+----------------+
| SPACE | NAME                     | FLAG | FILE_FORMAT | ROW_FORMAT           | PAGE_SIZE | ZIP_PAGE_SIZE | SPACE_TYPE | FS_BLOCK_SIZE | FILE_SIZE | ALLOCATED_SIZE |
+-------+--------------------------+------+-------------+----------------------+-----------+---------------+------------+---------------+-----------+----------------+
|     0 | innodb_system            |    0 | Antelope    | Compact or Redundant |     16384 |             0 | System     |             0 |         0 |              0 |
| 36855 | mysql/innodb_index_stats |   33 | Barracuda   | Dynamic              |     16384 |             0 | Single     |          4096 |    245760 |         245760 |
| 36856 | mysql/innodb_table_stats |   33 | Barracuda   | Dynamic              |     16384 |             0 | Single     |          4096 |     98304 |          98304 |
+-------+--------------------------+------+-------------+----------------------+-----------+---------------+------------+---------------+-----------+----------------+
3 rows in set (0.00 sec)
[11 Oct 2019 18:34] Bogdan Kecman
Hi,

I fear your path to this version you have now led trough some not so good binaries, I fear you were even running some unreleased ones :( .. in any case, I doubt there's anything we can do now except offer a workaround -> dump/restore. Not a very fast or nice or on-line one but... 

all best
[11 Oct 2019 20:49] Adam Friedman
Yes: I solved my problem (or worked around it) by:

[1] Dumping the databases I wanted to keep into an SQL file.
[2] Deleted the /var/lib/mysql data binaries. 
[3] Removed all mysql 5.7 software packages from the system.
[4] Re-installed all newest mysql 5.7 software packages. (This recreated the system tables without the offending relic).
[5] Re-imported from the SQL file I generated in step 1.
[6] Proceeded with normal in-place upgrade path for MySQL 8.

Thanks!