Hi Michael,
I'm not sure it's reproducible, it appeared after a system upgrade, i don't
know if it's the case for new installations
I believe it's the systemd issue, not the mysql issue because starting the
mysqld server with running `mysqld_safe` and stopping it with mysqladmin -uroot
-p shutdown are immediate, both take seconds
Please find attached files with output of the commands
Best regards,
Marek
--------------------------------------------
On Thu, 1/10/15, Michael Biebl <[email protected]> wrote:
Subject: Re: Bug#800588: systemd: slow start/stop
To: "marek sowinski" <[email protected]>, [email protected]
Date: Thursday, 1 October, 2015, 13:48
control: tags -1 + moreinfo
Am 01.10.2015 um 13:19 schrieb marek sowinski:
> Package: systemd
> Version: 226-3
> Severity: important
>
> Dear Maintainer,
>
> * What led up to the situation?
> when restarting, stopping or starting mysql it takes 10
minutes to complete the action
> * What exactly did you do (or not do) that
was effective (or
> ineffective)?
> it happens when:
> /etc/init.d/mysql restart
> /etc/init.d/mysql stop
> /etc/init.d/mysql start
> service mysql start
>
Is this problem reproducible?
Are you sure this is not mysql simply taking 10 mins to
restart?
What's the output of "systemctl status mysql.service"
and "journalctl -u mysql.service"
--
Why is it that all of the instruments seeking intelligent
life in the
universe are pointed away from Earth?
systemctl status mysql.service
â mysql.service - MySQL Community Server
Loaded: loaded (/lib/systemd/system/mysql.service; enabled; vendor preset:
enabled)
Active: failed (Result: signal) since Fri 2015-10-02 17:23:55 IST; 1min 9s
ago
Process: 6875 ExecStartPost=/usr/share/mysql/mysql-systemd-start post
(code=exited, status=0/SUCCESS)
Process: 6874 ExecStart=/usr/bin/mysqld_safe (code=killed, signal=KILL)
Process: 6871 ExecStartPre=/usr/share/mysql/mysql-systemd-start pre
(code=exited, status=0/SUCCESS)
Main PID: 6874 (code=killed, signal=KILL)
Oct 02 17:13:56 debian-virtual mysqld[7290]: 2015-10-02 17:13:56 7289 [Note]
- '127.0.0.1' resolves to '127.0.0.1';
Oct 02 17:13:56 debian-virtual mysqld[7290]: 2015-10-02 17:13:56 7289 [Note]
Server socket created on IP: '127.0.0.1'.
Oct 02 17:13:56 debian-virtual mysqld[7290]: 2015-10-02 17:13:56 7289 [Note]
Event Scheduler: Loaded 0 events
Oct 02 17:13:56 debian-virtual mysqld[7290]: 2015-10-02 17:13:56 7289 [Note]
/usr/sbin/mysqld: ready for connections.
Oct 02 17:13:56 debian-virtual mysqld[7290]: Version: '5.6.25-4' socket:
'/var/run/mysqld/mysqld.sock' port: 3306 (Debian)
Oct 02 17:23:55 debian-virtual systemd[1]: mysql.service: State 'stop-sigterm'
timed out. Killing.
Oct 02 17:23:55 debian-virtual systemd[1]: mysql.service: Main process exited,
code=killed, status=9/KILL
Oct 02 17:23:55 debian-virtual systemd[1]: Stopped MySQL Community Server.
Oct 02 17:23:55 debian-virtual systemd[1]: mysql.service: Unit entered failed
state.
Oct 02 17:23:55 debian-virtual systemd[1]: mysql.service: Failed with result
'signal'.
Oct 02 17:13:55 debian-virtual systemd[1]: Stopping MySQL Community Server...
Oct 02 17:13:55 debian-virtual mysqld_safe[6874]: Could not open required
defaults file: /etc/mysql/debian.cnf
Oct 02 17:13:55 debian-virtual mysqld_safe[6874]: Fatal error in defaults
handling. Program aborted
Oct 02 17:13:55 debian-virtual mysqld_safe[6874]: 151002 17:13:55 mysqld_safe
Number of processes running now: 1
Oct 02 17:13:55 debian-virtual mysqld_safe[6874]: 151002 17:13:55 mysqld_safe
mysqld process hanging, pid 7216 - killed
Oct 02 17:13:55 debian-virtual mysqld_safe[6874]: 151002 17:13:55 mysqld_safe
mysqld restarted
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 0 [Warning]
TIMESTAMP with implicit DEFAULT value is deprecated. Please use
--explicit_defaults_for_timestamp server option (see documenta
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 0 [Note]
/usr/sbin/mysqld (mysqld 5.6.25-4) starting as process 7289 ...
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Warning]
Buffered warning: Changed limits: max_open_files: 1024 (requested 5000)
Oct 02 17:13:55 debian-virtual mysqld[7290]:
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Warning]
Buffered warning: Changed limits: table_open_cache: 431 (requested 2000)
Oct 02 17:13:55 debian-virtual mysqld[7290]:
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Note]
Plugin 'FEDERATED' is disabled.
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [ERROR]
Function 'innodb' already exists
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Warning]
Couldn't load plugin named 'innodb' with soname 'ha_innodb.so'.
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [ERROR]
Function 'federated' already exists
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Warning]
Couldn't load plugin named 'federated' with soname 'ha_federated.so'.
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [ERROR]
Function 'blackhole' already exists
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Warning]
Couldn't load plugin named 'blackhole' with soname 'ha_blackhole.so'.
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [ERROR]
Function 'archive' already exists
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Warning]
Couldn't load plugin named 'archive' with soname 'ha_archive.so'.
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Note]
InnoDB: Using atomics to ref count buffer pool pages
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Note]
InnoDB: The InnoDB memory heap is disabled
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Note]
InnoDB: Mutexes and rw_locks use GCC atomic builtins
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Note]
InnoDB: Memory barrier is not used
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Note]
InnoDB: Compressed tables use zlib 1.2.8
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Note]
InnoDB: Using Linux native AIO
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Note]
InnoDB: Using CPU crc32 instructions
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Note]
InnoDB: Initializing buffer pool, size = 128.0M
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Note]
InnoDB: Completed initialization of buffer pool
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Note]
InnoDB: Highest supported file format is Barracuda.
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Note]
InnoDB: The log sequence numbers 5139275840 and 5139275840 in ibdata files do
not match the log sequence number 5139275850 in
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Note]
InnoDB: Database was not shutdown normally!
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Note]
InnoDB: Starting crash recovery.
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Note]
InnoDB: Reading tablespace information from the .ibd files...
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Note]
InnoDB: Restoring possible half-written data pages
Oct 02 17:13:55 debian-virtual mysqld[7290]: 2015-10-02 17:13:55 7289 [Note]
InnoDB: from the doublewrite buffer...
Oct 02 17:13:56 debian-virtual mysqld[7290]: 2015-10-02 17:13:56 7289 [Note]
InnoDB: 128 rollback segment(s) are active.
Oct 02 17:13:56 debian-virtual mysqld[7290]: 2015-10-02 17:13:56 7289 [Note]
InnoDB: Waiting for purge to start
Oct 02 17:13:56 debian-virtual mysqld[7290]: 2015-10-02 17:13:56 7289 [Note]
InnoDB: 5.6.25 started; log sequence number 5139275850
Oct 02 17:13:56 debian-virtual mysqld[7290]: 2015-10-02 17:13:56 7289 [Note]
Server hostname (bind-address): '127.0.0.1'; port: 3306
Oct 02 17:13:56 debian-virtual mysqld[7290]: 2015-10-02 17:13:56 7289 [Note]
- '127.0.0.1' resolves to '127.0.0.1';
Oct 02 17:13:56 debian-virtual mysqld[7290]: 2015-10-02 17:13:56 7289 [Note]
Server socket created on IP: '127.0.0.1'.
Oct 02 17:13:56 debian-virtual mysqld[7290]: 2015-10-02 17:13:56 7289 [Note]
Event Scheduler: Loaded 0 events
Oct 02 17:13:56 debian-virtual mysqld[7290]: 2015-10-02 17:13:56 7289 [Note]
/usr/sbin/mysqld: ready for connections.
Oct 02 17:13:56 debian-virtual mysqld[7290]: Version: '5.6.25-4' socket:
'/var/run/mysqld/mysqld.sock' port: 3306 (Debian)
Oct 02 17:23:55 debian-virtual systemd[1]: mysql.service: State 'stop-sigterm'
timed out. Killing.
Oct 02 17:23:55 debian-virtual systemd[1]: mysql.service: Main process exited,
code=killed, status=9/KILL
Oct 02 17:23:55 debian-virtual systemd[1]: Stopped MySQL Community Server.
Oct 02 17:23:55 debian-virtual systemd[1]: mysql.service: Unit entered failed
state.
Oct 02 17:23:55 debian-virtual systemd[1]: mysql.service: Failed with result
'signal'.
