[debian-mysql] Bug#798259: mysql-server-5.6: mysqld_safe does not report configuration errors, returns success exit code
Felipe Sateler
fsateler at debian.org
Mon Sep 7 13:21:08 UTC 2015
Package: mysql-server-5.6
Version: 5.6.25-3
Severity: important
Hi,
When my.cnf contains an unsupported option (maybe because a previous
version supported it [like log-slow-queries]), mysqld exits immediately.
However, mysqld_safe does not report back that error, and returns a
success exit code.
Steps to reproduce:
% sudo vim /etc/mysql/my.cnf
# add an unknown option like log-slow-queries = /tmp/mysql.slow
% sudo env -i mysqld_safe --log-error=error.log
150907 09:52:52 mysqld_safe Can't log to error log and syslog at the same time. Remove all --log-error configuration options for --syslog to take effect.
150907 09:52:52 mysqld_safe Logging to '/var/lib/mysql/error.log'.
150907 09:52:52 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
150907 09:52:54 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended
% echo $?
0
% ls error.log
ls: cannot access error.log: No such file or directory
% tail /var/log/{mysql.err,mysql/error.log}
==> /var/log/mysql.err <==
==> /var/log/mysql/error.log <==
% # Give up, run mysql directly
% sudo env -i `which mysqld`
2015-09-07 09:55:17 0 [Warning] Using unique option prefix key_buffer instead of key_buffer_size is deprecated and will be removed in a future release. Please use the full name instead.
2015-09-07 09:55:17 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2015-09-07 09:55:17 0 [Note] /usr/sbin/mysqld (mysqld 5.6.25-3) starting as process 16342 ...
% echo $?
7
% # Huh, why did this fail
% sudo env -i `which mysqld` --verbose
2015-09-07 09:56:38 0 [Warning] Using unique option prefix key_buffer instead of key_buffer_size is deprecated and will be removed in a future release. Please use the full name instead.
2015-09-07 09:56:38 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2015-09-07 09:56:38 0 [Note] /usr/sbin/mysqld (mysqld 5.6.25-3) starting as process 16411 ...
2015-09-07 09:56:38 16411 [Warning] Using unique option prefix myisam-recover instead of myisam-recover-options is deprecated and will be removed in a future release. Please use the full name instead.
2015-09-07 09:56:38 16411 [Note] Plugin 'FEDERATED' is disabled.
2015-09-07 09:56:38 16411 [ERROR] Function 'innodb' already exists
2015-09-07 09:56:38 16411 [Warning] Couldn't load plugin named 'innodb' with soname 'ha_innodb.so'.
2015-09-07 09:56:38 16411 [ERROR] Function 'federated' already exists
2015-09-07 09:56:38 16411 [Warning] Couldn't load plugin named 'federated' with soname 'ha_federated.so'.
2015-09-07 09:56:38 16411 [ERROR] Function 'blackhole' already exists
2015-09-07 09:56:38 16411 [Warning] Couldn't load plugin named 'blackhole' with soname 'ha_blackhole.so'.
2015-09-07 09:56:38 16411 [ERROR] Function 'archive' already exists
2015-09-07 09:56:38 16411 [Warning] Couldn't load plugin named 'archive' with soname 'ha_archive.so'.
2015-09-07 09:56:38 16411 [Note] InnoDB: Using atomics to ref count buffer pool pages
2015-09-07 09:56:38 16411 [Note] InnoDB: The InnoDB memory heap is disabled
2015-09-07 09:56:38 16411 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2015-09-07 09:56:38 16411 [Note] InnoDB: Memory barrier is not used
2015-09-07 09:56:38 16411 [Note] InnoDB: Compressed tables use zlib 1.2.8
2015-09-07 09:56:38 16411 [Note] InnoDB: Using Linux native AIO
2015-09-07 09:56:38 16411 [Note] InnoDB: Using CPU crc32 instructions
2015-09-07 09:56:38 16411 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2015-09-07 09:56:38 16411 [Note] InnoDB: Completed initialization of buffer pool
2015-09-07 09:56:38 16411 [Note] InnoDB: Highest supported file format is Barracuda.
2015-09-07 09:56:38 16411 [Note] InnoDB: 128 rollback segment(s) are active.
2015-09-07 09:56:38 16411 [Note] InnoDB: Waiting for purge to start
2015-09-07 09:56:38 16411 [Note] InnoDB: 5.6.25 started; log sequence number 4067979378
2015-09-07 09:56:38 16411 [ERROR] /usr/sbin/mysqld: unknown variable 'log-slow-queries=/tmp/mysql.slow'
2015-09-07 09:56:38 16411 [ERROR] Aborting
2015-09-07 09:56:38 16411 [Note] Binlog end
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'partition'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'ARCHIVE'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_FT_DELETED'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_METRICS'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_CMPMEM'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_CMP_RESET'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_CMP'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_LOCKS'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'INNODB_TRX'
2015-09-07 09:56:38 16411 [Note] Shutting down plugin 'InnoDB'
2015-09-07 09:56:38 16411 [Note] InnoDB: FTS optimize thread exiting.
2015-09-07 09:56:38 16411 [Note] InnoDB: Starting shutdown...
2015-09-07 09:56:40 16411 [Note] InnoDB: Shutdown completed; log sequence number 4067979388
2015-09-07 09:56:40 16411 [Note] Shutting down plugin 'BLACKHOLE'
2015-09-07 09:56:40 16411 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
2015-09-07 09:56:40 16411 [Note] Shutting down plugin 'CSV'
2015-09-07 09:56:40 16411 [Note] Shutting down plugin 'MyISAM'
2015-09-07 09:56:40 16411 [Note] Shutting down plugin 'MRG_MYISAM'
2015-09-07 09:56:40 16411 [Note] Shutting down plugin 'MEMORY'
2015-09-07 09:56:40 16411 [Note] Shutting down plugin 'sha256_password'
2015-09-07 09:56:40 16411 [Note] Shutting down plugin 'mysql_old_password'
2015-09-07 09:56:40 16411 [Note] Shutting down plugin 'mysql_native_password'
2015-09-07 09:56:40 16411 [Note] Shutting down plugin 'binlog'
2015-09-07 09:56:40 16411 [Note] /usr/sbin/mysqld: Shutdown complete
===
So, there are a two things going on wrong here:
1. mysqld_safe does not report back the unsucessful return value from
mysqld
2. mysqld decides that a fatal error is not worth reporting unless
--verbose is given
This leads to extra problems because:
3. The unit file tries to connect to the server but it does not check if
the server is running first, and thus waits 90 seconds before failing.
4. Neither the systemd nor the mysql logs show why the start fails
(or the apt output either, for that matter).
-- System Information:
Debian Release: stretch/sid
APT prefers unstable
APT policy: (500, 'unstable'), (500, 'testing'), (1, 'experimental')
Architecture: amd64 (x86_64)
Foreign Architectures: i386
Kernel: Linux 4.1.0-2-amd64 (SMP w/4 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
Versions of packages mysql-server-5.6 depends on:
ii adduser 3.113+nmu3
ii debconf [debconf-2.0] 1.5.57
ii init-system-helpers 1.23
ii initscripts 2.88dsf-59.2
ii libaio1 0.3.110-1
ii libc6 2.19-19
ii libdbi-perl 1.633-1
ii libgcc1 1:5.2.1-16
ii libstdc++6 5.2.1-16
ii libwrap0 7.6.q-25
ii lsb-base 4.1+Debian14
ii mysql-client-5.6 5.6.25-3
ii mysql-common 5.6.25-3
ii mysql-server-core-5.6 5.6.25-3
ii passwd 1:4.2-3
ii perl 5.20.2-6
ii psmisc 22.21-2.1
ii zlib1g 1:1.2.8.dfsg-2+b1
Versions of packages mysql-server-5.6 recommends:
ii libhtml-template-perl 2.95-2
Versions of packages mysql-server-5.6 suggests:
ii heirloom-mailx [mailx] 12.5-5
ii tinyca 0.7.5-5
-- debconf information:
* mysql-server/error_setting_password:
mysql-server-5.6/postrm_remove_databases: false
mysql-server-5.6/start_on_boot: true
mysql-server-5.6/really_downgrade: false
mysql-server/password_mismatch:
mysql-server/no_upgrade_when_using_ndb:
mysql-server-5.6/nis_warning:
More information about the pkg-mysql-maint
mailing list