Trying to run an upgrade on a virtual Ubuntu Xenial machine. I'm trying to upgrade from 5.6 to 5.7 using aptitude install mysql-server.
All went well until it tried to boot up mysqld which failed.
The MySQL error log shows the following, repeated 2-3 times:
2017-03-14T15:57:22.066525Z 0 [Warning] Changed limits: max_open_files: 1024 (requested 5000)
2017-03-14T15:57:22.066581Z 0 [Warning] Changed limits: table_open_cache: 431 (requested 2000)
2017-03-14T15:57:22.215229Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-03-14T15:57:22.217094Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.17-0ubuntu0.16.04.1) starting as process 3620 ...
2017-03-14T15:57:22.220724Z 0 [Note] InnoDB: PUNCH HOLE support available
2017-03-14T15:57:22.220750Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-03-14T15:57:22.220760Z 0 [Note] InnoDB: Uses event mutexes
2017-03-14T15:57:22.220771Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-03-14T15:57:22.220783Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-03-14T15:57:22.220796Z 0 [Note] InnoDB: Using Linux native AIO
2017-03-14T15:57:22.220999Z 0 [Note] InnoDB: Number of pools: 1
2017-03-14T15:57:22.221079Z 0 [Note] InnoDB: Not using CPU crc32 instructions
2017-03-14T15:57:22.222384Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2017-03-14T15:57:22.232778Z 0 [Note] InnoDB: Completed initialization of buffer pool
2017-03-14T15:57:22.234829Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-03-14T15:57:22.247455Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2017-03-14T15:57:22.247958Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 42118565388
2017-03-14T15:57:22.247975Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 42118565397
2017-03-14T15:57:22.248327Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 42118565397
2017-03-14T15:57:22.248340Z 0 [Note] InnoDB: Database was not shutdown normally!
2017-03-14T15:57:22.248348Z 0 [Note] InnoDB: Starting crash recovery.
2017-03-14T15:57:22.423202Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2017-03-14T15:57:22.423257Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2017-03-14T15:57:22.423320Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-03-14T15:57:22.625954Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-03-14T15:57:22.627678Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2017-03-14T15:57:22.627711Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2017-03-14T15:57:22.628073Z 0 [Note] InnoDB: Creating sys_virtual system tables.
2017-03-14 15:57:22 0xb72c4700 InnoDB: Assertion failure in thread 3073132288 in file os0file.cc line 1687
InnoDB: Failing assertion: offset > 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
15:57:22 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.
key_buffer_size=16777216
read_buffer_size=131072
max_used_connections=0
max_threads=151
thread_count=0
connection_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 75717 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
With the backtrace:
Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0 thread_stack 0x30000
/usr/sbin/mysqld(my_print_stacktrace+0x3c)[0x8a8499c]
/usr/sbin/mysqld(handle_fatal_signal+0x426)[0x837e776]
[0xb7726c14]
[0xb7726c31]
/lib/i386-linux-gnu/libc.so.6(gsignal+0x39)[0xb730dea9]
/lib/i386-linux-gnu/libc.so.6(abort+0x157)[0xb730f407]
/usr/sbin/mysqld[0x8355255]
/usr/sbin/mysqld[0x8c179d1]
/usr/sbin/mysqld[0x8c1c42f]
/usr/sbin/mysqld(_Z17os_file_read_funcR9IORequestiPvym+0x21)[0x8c1cb91]
/usr/sbin/mysqld(_Z11os_aio_funcR9IORequestmPKciPvymbP10fil_node_tS3_+0x16e)[0x8c1d6ae]
/usr/sbin/mysqld(_Z6fil_ioRK9IORequestbRK9page_id_tRK11page_size_tmmPvS8_+0x78b)[0x8e0be2b]
/usr/sbin/mysqld(_Z13buf_read_pageRK9page_id_tRK11page_size_t+0xde)[0x8db882e]
/usr/sbin/mysqld(_Z16buf_page_get_genRK9page_id_tRK11page_size_tmP11buf_block_tmPKcmP5mtr_tb+0x4f3)[0x8d84bf3]
/usr/sbin/mysqld(_Z19xdes_get_descriptormmRK11page_size_tP5mtr_t+0x1c2)[0x8e104a2]
/usr/sbin/mysqld[0x8e13293]
/usr/sbin/mysqld(_Z14fseg_free_pagePhmmbP5mtr_t+0x15d)[0x8e14bbd]
/usr/sbin/mysqld[0x8bd2401]
/usr/sbin/mysqld(_Z22ibuf_free_excess_pagesv+0xf7)[0x8bd2927]
/usr/sbin/mysqld(_Z19fseg_create_generalmmmmP5mtr_t+0x9c8)[0x8e18c38]
/usr/sbin/mysqld(_Z11fseg_createmmmP5mtr_t+0x25)[0x8e18d65]
/usr/sbin/mysqld(_Z10btr_createmmRK11page_size_tyP12dict_index_tPK12btr_create_tP5mtr_t+0x16d)[0x8d4e54d]
/usr/sbin/mysqld[0x8dc4282]
/usr/sbin/mysqld(_Z22dict_create_index_stepP9que_thr_t+0x6b)[0x8dc448b]
/usr/sbin/mysqld(_Z15que_run_threadsP9que_thr_t+0x1016)[0x8c4b866]
/usr/sbin/mysqld(_Z12que_eval_sqlP11pars_info_tPKcmP5trx_t+0xa2)[0x8c4bdb2]
/usr/sbin/mysqld(_Z32dict_create_or_check_sys_virtualv+0x74e)[0x8dc195e]
/usr/sbin/mysqld(_Z34innobase_start_or_create_for_mysqlv+0x44b6)[0x8ce6b86]
/usr/sbin/mysqld[0x8b96e9e]
/usr/sbin/mysqld(_Z24ha_initialize_handlertonP13st_plugin_int+0x52)[0x83cc0d2]
/usr/sbin/mysqld[0x885d5c2]
/usr/sbin/mysqld(_Z11plugin_initPiPPci+0x60f)[0x886554f]
/usr/sbin/mysqld[0x8376bc5]
/usr/sbin/mysqld(_Z11mysqld_mainiPPc+0x83b)[0x837849b]
/usr/sbin/mysqld(main+0x27)[0x8356d97]
/lib/i386-linux-gnu/libc.so.6(__libc_start_main+0xf7)[0xb72fa637]
/usr/sbin/mysqld[0x836e900]
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
I added innodb_force_recovery = 1 into the config file which gives some of the recovery information pre-error, but even without this flag the error still occurs. I haven't attempted to try the other recovery modes, because the documentation doesn't point towards any of the other modes helping with sys_virtual_tables specifically (and some of them seem to be able to do permanent damage).
There's about 10GB of space free in the partition, so I know it's not a issue of disk size.
I'm not sure it's a problem with memory either:
# cat /proc/meminfo
MemTotal: 2520008 kB
MemFree: 2070012 kB
MemAvailable: 2116656 kB
What's wrong with the upgrade, is there any option to continue it, or is it worth trying to downgrade back 5.6? (Aptitude/apt-get currently prevents this, as it wants to finish configuring the install for 5.7 before doing anything else, which fails).
Best Answer
I would never let aptitude upgrade my mysql servers automatically- it may be ok for a small non-important installation, but I would like to do it manually to be able to have 100% control of the process- create a backup first, change configuration options, etc. It normally is a safe process, but you do not want to suffer when something wrong happens.
It is difficult to say why it is happening, it is failing an assert in a low-level file read operation: https://github.com/mysql/mysql-server/blob/71f48ab393bce80a59e5a2e498cd1f46f6b43f9a/storage/innobase/include/os0file.h
What happens if you try to upgrade manually? (mysql_upgrade command) I would try that first. Not that before crashing, it was also recovering for not being shutdown cleanly, so there may be a previous root cause. If the server starts- I would dump its contents with mysqldump, and then delete its contents, start from 0, then reimport. It will avoid many headaches, if there is some kind of tablespace corruption going on.