[debian-mysql] Bug#829489: Bug#829489: mariadb-server-10.0: Fails to stop, package can't be uninstalled/purged

Axel Beckert abe at debian.org
Sun Jul 3 20:07:10 UTC 2016


Hi Otto,

Otto Kekäläinen wrote:
> 2016-07-03 21:42 GMT+03:00 Axel Beckert <abe at debian.org>:
> > Removing mariadb-server-10.0 (10.0.26-1) ...
> > [FAIL] Stopping MariaDB database server: mysqld failed!
> > invoke-rc.d: initscript mysql, action "stop" failed.
> > dpkg: error processing package mariadb-server-10.0 (--purge):
> >  subprocess installed pre-removal script returned error exit status 1
> > [FAIL] Stopping MariaDB database server: mysqld failed!
> > invoke-rc.d: initscript mysql, action "stop" failed.
> 
> What happens here is that the prerm script invokes the MariaDB service
> and tries to stop it. For some reason the mysqld daemon does not
> die,

I see. Hrm.

> and thus the service script emits an error, which the prerm script in
> turn sees as an error code and assumes that prerm step failed,
> aborting further dpkg operations for that package.

Sounds sane.

> There are many potential reasons why mysqld failed to die. Check the
> syslog or /var/log/mysql/* logs.

The latter are already gone since the second try to purge it (after
reinstallation) succeeded.

The syslog looks as if no shutdown has been tried (or the try didn't
reach the daemon):

Here's the according excerpt of "egrep -i 'mysql|mariadb'
/var/log/syslog" which comes from MariaDB:

Jul  3 20:24:55 c6 mysqld_safe[20377]: 160703 20:24:55 [Note] /usr/sbin/mysqld (mysqld 10.0.26-MariaDB-1) starting as process 20407 ...
Jul  3 20:25:01 c6 mysqld_safe[20377]: 160703 20:25:01 [Note] /usr/sbin/mysqld (mysqld 10.0.26-MariaDB-1) starting as process 20436 ...
Jul  3 20:25:03 c6 mysqld_safe[20469]: 160703 20:25:03 [Note] /usr/sbin/mysqld (mysqld 10.0.26-MariaDB-1) starting as process 20468 ...
Jul  3 20:25:06 c6 mysqld_safe: Starting mysqld daemon with databases from /var/lib/mysql
Jul  3 20:25:06 c6 mysqld: 160703 20:25:06 [Note] /usr/sbin/mysqld (mysqld 10.0.26-MariaDB-1) starting as process 20686 ...
Jul  3 20:25:06 c6 mysqld: 160703 20:25:06 [Note] InnoDB: Using mutexes to ref count buffer pool pages
Jul  3 20:25:06 c6 mysqld: 160703 20:25:06 [Note] InnoDB: The InnoDB memory heap is disabled
Jul  3 20:25:06 c6 mysqld: 160703 20:25:06 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
Jul  3 20:25:06 c6 mysqld: 160703 20:25:06 [Note] InnoDB: Memory barrier is not used
Jul  3 20:25:06 c6 mysqld: 160703 20:25:06 [Note] InnoDB: Compressed tables use zlib 1.2.8
Jul  3 20:25:06 c6 mysqld: 160703 20:25:06 [Note] InnoDB: Using Linux native AIO
Jul  3 20:25:06 c6 mysqld: 160703 20:25:06 [Note] InnoDB: Using CPU crc32 instructions
Jul  3 20:25:06 c6 mysqld: 160703 20:25:06 [Note] InnoDB: Initializing buffer pool, size = 128.0M
Jul  3 20:25:06 c6 mysqld: 160703 20:25:06 [Note] InnoDB: Completed initialization of buffer pool
Jul  3 20:25:06 c6 mysqld: 160703 20:25:06 [Note] InnoDB: Highest supported file format is Barracuda.
Jul  3 20:25:06 c6 mysqld: 160703 20:25:06 [Note] InnoDB: 128 rollback segment(s) are active.
Jul  3 20:25:06 c6 mysqld: 160703 20:25:06 [Note] InnoDB: Waiting for purge to start
Jul  3 20:25:06 c6 mysqld: 160703 20:25:06 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.30-76.3 started; log sequence number 1616717
Jul  3 20:25:06 c6 mysqld: 160703 20:25:06 [Note] Plugin 'FEEDBACK' is disabled.
Jul  3 20:25:06 c6 mysqld: 160703 20:25:06 [Note] Server socket created on IP: '127.0.0.1'.
Jul  3 20:25:06 c6 mysqld: 160703 20:25:06 [Note] /usr/sbin/mysqld: ready for connections.
Jul  3 20:25:06 c6 mysqld: Version: '10.0.26-MariaDB-1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Debian unstable
Jul  3 20:25:07 c6 /etc/mysql/debian-start[20755]: Upgrading MySQL tables if necessary.
Jul  3 20:25:07 c6 /etc/mysql/debian-start[20758]: /usr/bin/mysql_upgrade: the '--basedir' option is always ignored
Jul  3 20:25:07 c6 /etc/mysql/debian-start[20758]: Looking for 'mysql' as: /usr/bin/mysql
Jul  3 20:25:07 c6 /etc/mysql/debian-start[20758]: Looking for 'mysqlcheck' as: /usr/bin/mysqlcheck
Jul  3 20:25:07 c6 /etc/mysql/debian-start[20758]: Version check failed. Got the following error when calling the 'mysql' command line client
Jul  3 20:25:07 c6 /etc/mysql/debian-start[20758]: ERROR 1698 (28000): Access denied for user 'debian-sys-maint'@'localhost'
Jul  3 20:25:07 c6 /etc/mysql/debian-start[20758]: FATAL ERROR: Upgrade failed
Jul  3 20:25:07 c6 /etc/mysql/debian-start[20767]: Checking for insecure root accounts.
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: Status information:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: Current dir: /var/lib/mysql/
Jul  3 20:25:12 c6 mysqld: Running threads: 0  Stack size: 196608
Jul  3 20:25:12 c6 mysqld: Current locks:
Jul  3 20:25:12 c6 mysqld: lock: 0x7f6727c17508:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x7f672f23fb88:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x7f672f233b88:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x7f674a87ab88:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x7f674a879788:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x7f674a877988:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x7f674a876588:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x7f673f408d88:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x7f674abfe388:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x7f672f22ff88:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x7f674a873388:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3d260:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3d180:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3c1c0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3c0e0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3c000:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3c380:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3a5c0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3d0a0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3acc0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3af60:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3abe0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3ae80:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3ab00:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3ada0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3b2e0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3b3c0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3b4a0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3aa20:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3a780:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3a940:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3a6a0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3a860:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3b040:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3b120:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3b200:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3cd20:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3cfc0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3cee0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3ce00:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3c9a0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3c8c0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3c7e0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3c700:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3c620:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3cb60:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3c540:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3c460:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3cc40:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3c2a0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3be40:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3bf20:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3bd60:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3bc80:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3b900:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3bba0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3bac0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3b820:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3b9e0:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3b580:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3b660:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3b740:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: lock: 0x1c3ca80:
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: Key caches:
Jul  3 20:25:12 c6 mysqld: default
Jul  3 20:25:12 c6 mysqld: Buffer_size:      16777216
Jul  3 20:25:12 c6 mysqld: Block_size:           1024
Jul  3 20:25:12 c6 mysqld: Division_limit:        100
Jul  3 20:25:12 c6 mysqld: Age_threshold:         300
Jul  3 20:25:12 c6 mysqld: Partitions:              0
Jul  3 20:25:12 c6 mysqld: blocks used:             0
Jul  3 20:25:12 c6 mysqld: not flushed:             0
Jul  3 20:25:12 c6 mysqld: w_requests:              0
Jul  3 20:25:12 c6 mysqld: writes:                  0
Jul  3 20:25:12 c6 mysqld: r_requests:              0
Jul  3 20:25:12 c6 mysqld: reads:                   0
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: handler status:
Jul  3 20:25:12 c6 mysqld: read_key:            0
Jul  3 20:25:12 c6 mysqld: read_next:           0
Jul  3 20:25:12 c6 mysqld: read_rnd             0
Jul  3 20:25:12 c6 mysqld: read_first:          0
Jul  3 20:25:12 c6 mysqld: write:               0
Jul  3 20:25:12 c6 mysqld: delete               0
Jul  3 20:25:12 c6 mysqld: update:              0
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: Table status:
Jul  3 20:25:12 c6 mysqld: Opened tables:          0
Jul  3 20:25:12 c6 mysqld: Open tables:           63
Jul  3 20:25:12 c6 mysqld: Open files:            24
Jul  3 20:25:12 c6 mysqld: Open streams:           0
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: Alarm status:
Jul  3 20:25:12 c6 mysqld: Active alarms:   0
Jul  3 20:25:12 c6 mysqld: Max used alarms: 0
Jul  3 20:25:12 c6 mysqld: Next alarm time: 0
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: Memory status:
Jul  3 20:25:12 c6 mysqld: Non-mmapped space allocated from system: 0
Jul  3 20:25:12 c6 mysqld: Number of free chunks:#011#011#011 1
Jul  3 20:25:12 c6 mysqld: Number of fastbin blocks:#011#011 0
Jul  3 20:25:12 c6 mysqld: Number of mmapped regions:#011#011 0
Jul  3 20:25:12 c6 mysqld: Space in mmapped regions:#011#011 0
Jul  3 20:25:12 c6 mysqld: Maximum total allocated space:#011#011 0
Jul  3 20:25:12 c6 mysqld: Space available in freed fastbin blocks: 0
Jul  3 20:25:12 c6 mysqld: Total allocated space:#011#011#011 0
Jul  3 20:25:12 c6 mysqld: Total free space:#011#011#011 0
Jul  3 20:25:12 c6 mysqld: Top-most, releasable space:#011#011 0
Jul  3 20:25:12 c6 mysqld: Estimated memory (with thread stack):    0
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: Events status:
Jul  3 20:25:12 c6 mysqld: LLA = Last Locked At  LUA = Last Unlocked At
Jul  3 20:25:12 c6 mysqld: WOC = Waiting On Condition  DL = Data Locked
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: Event scheduler status:
Jul  3 20:25:12 c6 mysqld: State      : INITIALIZED
Jul  3 20:25:12 c6 mysqld: Thread id  : 0
Jul  3 20:25:12 c6 mysqld: LLA        : n/a:0
Jul  3 20:25:12 c6 mysqld: LUA        : n/a:0
Jul  3 20:25:12 c6 mysqld: WOC        : NO
Jul  3 20:25:12 c6 mysqld: Workers    : 0
Jul  3 20:25:12 c6 mysqld: Executed   : 0
Jul  3 20:25:12 c6 mysqld: Data locked: NO
Jul  3 20:25:12 c6 mysqld: 
Jul  3 20:25:12 c6 mysqld: Event queue status:
Jul  3 20:25:12 c6 mysqld: Element count   : 0
Jul  3 20:25:12 c6 mysqld: Data locked     : NO
Jul  3 20:25:12 c6 mysqld: Attempting lock : NO
Jul  3 20:25:12 c6 mysqld: LLA             : init_queue:140
Jul  3 20:25:12 c6 mysqld: LUA             : init_queue:150
Jul  3 20:25:12 c6 mysqld: WOC             : NO
Jul  3 20:25:12 c6 mysqld: Next activation : never

This all seems to be from the installation.

But the next log entries I found look like an installation, too, i.e.
no traces from the initial try to uninstall it:

Jul  3 20:37:45 c6 mysqld_safe[1782]: 160703 20:37:45 [Note] /usr/sbin/mysqld (mysqld 10.0.26-MariaDB-1) starting as process 1813 ...
Jul  3 20:37:52 c6 mysqld_safe[1782]: 160703 20:37:52 [Note] /usr/sbin/mysqld (mysqld 10.0.26-MariaDB-1) starting as process 1842 ...
Jul  3 20:37:54 c6 mysqld_safe[1873]: 160703 20:37:54 [Note] /usr/sbin/mysqld (mysqld 10.0.26-MariaDB-1) starting as process 1872 ...
Jul  3 20:39:03 c6 mysqld: 160703 20:39:03 [Note] /usr/sbin/mysqld: Normal shutdown
Jul  3 20:39:03 c6 mysqld: 
Jul  3 20:39:03 c6 mysqld: 160703 20:39:03 [Note] Event Scheduler: Purging the queue. 0 events
Jul  3 20:39:03 c6 mysqld: 160703 20:39:03 [Note] InnoDB: FTS optimize thread exiting.
Jul  3 20:39:03 c6 mysqld: 160703 20:39:03 [Note] InnoDB: Starting shutdown...
Jul  3 20:39:05 c6 mysqld: 160703 20:39:05 [Note] InnoDB: Shutdown completed; log sequence number 1616727
Jul  3 20:39:05 c6 mysqld: 160703 20:39:05 [Note] /usr/sbin/mysqld: Shutdown complete
Jul  3 20:39:05 c6 mysqld: 
Jul  3 20:39:05 c6 mysqld_safe: mysqld from pid file /var/run/mysqld/mysqld.pid ended
Jul  3 20:39:06 c6 mysqld_safe[4742]: 160703 20:39:06 [Note] /usr/sbin/mysqld (mysqld 10.0.26-MariaDB-1) starting as process 4770 ...
Jul  3 20:39:08 c6 mysqld_safe[4742]: 160703 20:39:08 [Note] /usr/sbin/mysqld (mysqld 10.0.26-MariaDB-1) starting as process 4800 ...
Jul  3 20:39:10 c6 mysqld_safe[4830]: 160703 20:39:10 [Note] /usr/sbin/mysqld (mysqld 10.0.26-MariaDB-1) starting as process 4829 ...
Jul  3 20:39:13 c6 mysqld_safe: Starting mysqld daemon with databases from /var/lib/mysql
Jul  3 20:39:13 c6 mysqld: 160703 20:39:13 [Note] /usr/sbin/mysqld (mysqld 10.0.26-MariaDB-1) starting as process 5045 ...
Jul  3 20:39:13 c6 mysqld: 160703 20:39:13 [Note] InnoDB: Using mutexes to ref count buffer pool pages
Jul  3 20:39:13 c6 mysqld: 160703 20:39:13 [Note] InnoDB: The InnoDB memory heap is disabled
Jul  3 20:39:13 c6 mysqld: 160703 20:39:13 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
Jul  3 20:39:13 c6 mysqld: 160703 20:39:13 [Note] InnoDB: Memory barrier is not used
Jul  3 20:39:13 c6 mysqld: 160703 20:39:13 [Note] InnoDB: Compressed tables use zlib 1.2.8
Jul  3 20:39:13 c6 mysqld: 160703 20:39:13 [Note] InnoDB: Using Linux native AIO
Jul  3 20:39:13 c6 mysqld: 160703 20:39:13 [Note] InnoDB: Using CPU crc32 instructions
Jul  3 20:39:13 c6 mysqld: 160703 20:39:13 [Note] InnoDB: Initializing buffer pool, size = 128.0M
Jul  3 20:39:13 c6 mysqld: 160703 20:39:13 [Note] InnoDB: Completed initialization of buffer pool
Jul  3 20:39:13 c6 mysqld: 160703 20:39:13 [Note] InnoDB: Highest supported file format is Barracuda.
Jul  3 20:39:13 c6 mysqld: 160703 20:39:13 [Note] InnoDB: 128 rollback segment(s) are active.
Jul  3 20:39:13 c6 mysqld: 160703 20:39:13 [Note] InnoDB: Waiting for purge to start
Jul  3 20:39:13 c6 mysqld: 160703 20:39:13 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.30-76.3 started; log sequence number 1616747
Jul  3 20:39:13 c6 mysqld: 160703 20:39:13 [Note] Plugin 'FEEDBACK' is disabled.
Jul  3 20:39:13 c6 mysqld: 160703 20:39:13 [Note] Server socket created on IP: '127.0.0.1'.
Jul  3 20:39:13 c6 mysqld: 160703 20:39:13 [Note] /usr/sbin/mysqld: ready for connections.
Jul  3 20:39:13 c6 mysqld: Version: '10.0.26-MariaDB-1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Debian unstable
Jul  3 20:39:14 c6 /etc/mysql/debian-start[5111]: Upgrading MySQL tables if necessary.
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: /usr/bin/mysql_upgrade: the '--basedir' option is always ignored
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: Looking for 'mysql' as: /usr/bin/mysql
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: Looking for 'mysqlcheck' as: /usr/bin/mysqlcheck
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: Phase 1/6: Checking and upgrading mysql database
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: Processing databases
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.column_stats                                 OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.columns_priv                                 OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.db                                           OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.event                                        OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.func                                         OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.gtid_slave_pos                               OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.help_category                                OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.help_keyword                                 OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.help_relation                                OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.help_topic                                   OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.host                                         OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.index_stats                                  OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.innodb_index_stats                           OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.innodb_table_stats                           OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.plugin                                       OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.proc                                         OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.procs_priv                                   OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.proxies_priv                                 OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.roles_mapping                                OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.servers                                      OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.table_stats                                  OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.tables_priv                                  OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.time_zone                                    OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.time_zone_leap_second                        OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.time_zone_name                               OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.time_zone_transition                         OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.time_zone_transition_type                    OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql.user                                         OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: Phase 2/6: Fixing views
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: Processing databases
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: information_schema
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: performance_schema
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: Phase 3/6: Running 'mysql_fix_privilege_tables'
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: Phase 4/6: Fixing table and database names
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: Processing databases
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: information_schema
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: mysql
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: performance_schema
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: Phase 5/6: Checking and upgrading tables
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: Processing databases
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: information_schema
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: performance_schema
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: Phase 6/6: Running 'FLUSH PRIVILEGES'
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5115]: OK
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5142]: Checking for insecure root accounts.
Jul  3 20:39:16 c6 /etc/mysql/debian-start[5146]: Triggering myisam-recover for all MyISAM tables and aria-recover for all Aria tables

And then follows the output from the successful removal:

Jul  3 20:39:46 c6 mysqld: 160703 20:39:46 [Note] /usr/sbin/mysqld: Normal shutdown
Jul  3 20:39:46 c6 mysqld: 
Jul  3 20:39:46 c6 mysqld: 160703 20:39:46 [Note] Event Scheduler: Purging the queue. 0 events
Jul  3 20:39:46 c6 mysqld: 160703 20:39:46 [Note] InnoDB: FTS optimize thread exiting.
Jul  3 20:39:46 c6 mysqld: 160703 20:39:46 [Note] InnoDB: Starting shutdown...
Jul  3 20:39:48 c6 mysqld: 160703 20:39:48 [Note] InnoDB: Shutdown completed; log sequence number 1616757
Jul  3 20:39:48 c6 mysqld: 160703 20:39:48 [Note] /usr/sbin/mysqld: Shutdown complete
Jul  3 20:39:48 c6 mysqld: 
Jul  3 20:39:48 c6 mysqld_safe: mysqld from pid file /var/run/mysqld/mysqld.pid ended

> What do you suggest here? To proceed with pruging the package even if
> the mysqld daemon is running?

No. That'd be the wrong way.

> Users expect the service to stop on removal.

Yes. And that failed.

> Maybe you can come up with some nice logic in the prerm script to
> handle this kind of scenario?

The prerm script looks very straight forward and relies on debhelper
snippets to do the work.

I still suspect some kind of race condition, maybe between initial
startup and first shutdown? But then again, it was probably more than
the half minute when it succeeded. But in that case there was also some
"is already running" message upon reinstallation.

My only ideas so far:

* Maybe a longer timeout to wait for the shutdown could help? (If
  there's some kind of timeout at all.)
* Maybe trying to stop it a second time after some short "sleep"?

Feel free to downgrade the severity to minor, if you think that's a
seldom happening corner case. Didn't happen when I purged
mysql-server-5.6 and dependencies like 15 minutes earlier.

		Regards, Axel
-- 
 ,''`.  |  Axel Beckert <abe at debian.org>, http://people.debian.org/~abe/
: :' :  |  Debian Developer, ftp.ch.debian.org Admin
`. `'   |  4096R: 2517 B724 C5F6 CA99 5329  6E61 2FF9 CD59 6126 16B5
  `-    |  1024D: F067 EA27 26B9 C3FC 1486  202E C09E 1D89 9593 0EDE



More information about the pkg-mysql-maint mailing list