Bug #86896 dpkg: error processing package mysql-server (--configure)
Submitted: 2 Jul 2017 12:03 Modified: 3 Jul 2017 7:47
Reporter: Laurent C. Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Installing Severity:S2 (Serious)
Version:5.7.18-0ubuntu0.16.04.1 OS:Ubuntu (16.04)
Assigned to: Lars Tangvald CPU Architecture:Any

[2 Jul 2017 12:03] Laurent C. 
Description:
Hi,

After an apt-get upgrade, the MySQL has fail to install.
Bellow logs from apt-get install -f to try to fix it :

# apt-get -f install
Reading package lists... Done
Building dependency tree       
Reading state information... Done
The following packages were automatically installed and are no longer required:
0 upgraded, 0 newly installed, 0 to remove and 10 not upgraded.
2 not fully installed or removed.
After this operation, 0 B of additional disk space will be used.
Setting up mysql-server-5.7 (5.7.18-0ubuntu0.16.04.1) ...
dpkg: error processing package mysql-server-5.7 (--configure):
 subprocess installed post-installation script returned error exit status 1
dpkg: dependency problems prevent configuration of mysql-server:
 mysql-server depends on mysql-server-5.7; however:
  Package mysql-server-5.7 is not configured yet.

dpkg: error processing package mysql-server (--configure):
 dependency problems - leaving unconfigured
Errors were encountered while processing:
 mysql-server-5.7
 mysql-server
E: Sub-process /usr/bin/dpkg returned an error code (1)

Bellow, logs from mysq.error :

2017-07-02T09:48:58.559984Z 0 [Note] Server hostname (bind-address): '10.69.116.115'; port: 3306
2017-07-02T09:48:58.559992Z 0 [Note]   - '10.69.116.115' resolves to '10.69.116.115';
2017-07-02T09:48:58.560017Z 0 [Note] Server socket created on IP: '10.69.116.115'.
2017-07-02T09:48:58.560038Z 0 [ERROR] Could not create unix socket lock file /tmp/user/0/tmp.DKas35TBIH/mysqld.sock.lock.
2017-07-02T09:48:58.560042Z 0 [ERROR] Unable to setup unix socket lock file.
2017-07-02T09:48:58.560045Z 0 [ERROR] Aborting

My my.cnf :

[mysqld_safe]
socket		= /var/run/mysqld/mysqld.sock
nice		= 0

[mysqld]
#
# * Basic Settings
#
user		= mysql
pid-file	= /var/run/mysqld/mysqld.pid
socket		= /var/run/mysqld/mysqld.sock
port		= 3306
basedir		= /usr
datadir		= /data/mysql
tmpdir		= /tmp
lc-messages-dir	= /usr/share/mysql
skip-external-locking
skip-name-resolve
#
# Instead of skip-networking the default is now to listen only on
# localhost which is more compatible and is not less secure.
bind-address		= 10.69.116.115

Apparmor config :

/data/mysql/ r,
/data/mysql/** rwk,

And fstab config :
...
/dev/mapper/rootvg-lv_tmp /tmp            ext4    nodev,nosuid    0       2
UUID=78b64b3d-6668-49b2-9ced-83c05dd5bf5b /data ext4    nodev 0       2

How to repeat:
After each apt-get update/install
[3 Jul 2017 6:14] Lars Tangvald 
Hi,

Looks like maybe your system changes the location of tmp files in a way the install can't handle correctly.

Can you check if this is blocked by apparmor, by running:
 dmesg -T | grep mysql
and looking for any "DENIED" messages (the command simply looks for "mysql" in your syslog)?

Also run:
 mktemp -d
and say what it outputs (this command creates a tmp directory).
[3 Jul 2017 6:18] Lars Tangvald 
Note: This is an issue with the native Ubuntu packages (named mysql-server-5.7, not mysql-community-server), but if this is a packaging bug it's likely to apply to our packages as well.
[3 Jul 2017 6:58] Laurent C. 
Hi,

This does not seem to come from apparmor, all is allowed :

Jul  3 08:40:49 lcdrappsdev01v kernel: [312811.534717] audit: type=1400 audit(1499064049.559:207): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/sbin/mysqld" pid=6892 comm="apparmor_parser"
Jul  3 08:40:57 lcdrappsdev01v systemd[1]: Stopped MySQL Community Server.
Jul  3 08:40:57 lcdrappsdev01v kernel: [312819.506198] audit: type=1400 audit(1499064057.531:213): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/sbin/mysqld" pid=6972 comm="apparmor_parser"
Jul  3 08:40:57 lcdrappsdev01v kernel: [312819.531109] audit: type=1400 audit(1499064057.555:214): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/proc/6990/status" pid=6990 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul  3 08:40:57 lcdrappsdev01v kernel: [312819.531155] audit: type=1400 audit(1499064057.555:215): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/sys/devices/system/node/" pid=6990 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul  3 08:40:57 lcdrappsdev01v kernel: [312819.531178] audit: type=1400 audit(1499064057.555:216): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/sys/devices/system/node/node0/meminfo" pid=6990 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul  3 08:40:57 lcdrappsdev01v kernel: [312819.531229] audit: type=1400 audit(1499064057.555:217): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/proc/6990/status" pid=6990 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jul  3 08:40:57 lcdrappsdev01v kernel: [312819.683033] audit: type=1400 audit(1499064057.707:218): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/sbin/mysqld" pid=7004 comm="apparmor_parser"
Jul  3 08:40:58 lcdrappsdev01v systemd[1]: Starting MySQL Community Server...
Jul  3 08:40:58 lcdrappsdev01v kernel: [312820.004978] audit: type=1400 audit(1499064058.031:219): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/proc/7067/status" pid=7067 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=111 ouid=111
Jul  3 08:40:58 lcdrappsdev01v kernel: [312820.005020] audit: type=1400 audit(1499064058.031:220): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/sys/devices/system/node/" pid=7067 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=111 ouid=0
Jul  3 08:40:58 lcdrappsdev01v kernel: [312820.005044] audit: type=1400 audit(1499064058.031:221): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/sys/devices/system/node/node0/meminfo" pid=7067 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=111 ouid=0
Jul  3 08:40:58 lcdrappsdev01v kernel: [312820.005090] audit: type=1400 audit(1499064058.031:222): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/proc/7067/status" pid=7067 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=111 ouid=111
Jul  3 08:40:59 lcdrappsdev01v systemd[1]: Started MySQL Community Server.
Jul  3 08:40:59 lcdrappsdev01v systemd[1]: Stopping MySQL Community Server...
Jul  3 08:41:00 lcdrappsdev01v systemd[1]: Stopped MySQL Community Server.
Jul  3 08:41:05 lcdrappsdev01v systemd[1]: Starting MySQL Community Server...
Jul  3 08:41:05 lcdrappsdev01v kernel: [312827.393299] audit: type=1400 audit(1499064065.419:227): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/proc/7271/status" pid=7271 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=111 ouid=111
Jul  3 08:41:05 lcdrappsdev01v kernel: [312827.393342] audit: type=1400 audit(1499064065.419:228): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/sys/devices/system/node/" pid=7271 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=111 ouid=0
Jul  3 08:41:05 lcdrappsdev01v kernel: [312827.393364] audit: type=1400 audit(1499064065.419:229): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/sys/devices/system/node/node0/meminfo" pid=7271 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=111 ouid=0
Jul  3 08:41:05 lcdrappsdev01v kernel: [312827.393412] audit: type=1400 audit(1499064065.419:230): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/proc/7271/status" pid=7271 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=111 ouid=111
Jul  3 08:41:06 lcdrappsdev01v systemd[1]: Started MySQL Community Server.

# mktemp -d
/tmp/user/0/tmp.341mwoLDgn

I have same error, on the second serveur with same version (ubuntu & mysql).

I have set -x to /var/lib/dpkg/info/mysql-server-5.7.postinst, bellow last line from upgrade :
+ existingdatabase=1
+ touch /var/lib/mysql/debian-5.7.flag
+ '[' configure = configure ']'
+ APP_PROFILE=/etc/apparmor.d/usr.sbin.mysqld
+ '[' -f /etc/apparmor.d/usr.sbin.mysqld ']'
+ LOCAL_APP_PROFILE=/etc/apparmor.d/local/usr.sbin.mysqld
+ test -e /etc/apparmor.d/local/usr.sbin.mysqld
+ aa-status --enabled
+ apparmor_parser -r -T -W /etc/apparmor.d/usr.sbin.mysqld
+ deb-systemd-helper unmask mysql.service
+ deb-systemd-helper --quiet was-enabled mysql.service
+ deb-systemd-helper enable mysql.service
+ '[' configure = configure ']'
+ '[' -x /etc/init.d/mysql ']'
+ update-rc.d mysql defaults 19 21
+ '[' -x /etc/init.d/mysql ']
+ '[' -x /etc/init.d/mysql ']'
+ invoke-rc.d mysql start
+ '[' configure = configure ']'
+ '[' 1 = 1 ']'
+ test_sysmaint_access
+ mysql --defaults-file=/etc/mysql/debian.cnf
+ invoke stop
+ pathfind invoke-rc.d
+ OLDIFS=' 	
'
+ IFS=:
+ for p in '$PATH'
+ '[' -x /usr/local/sbin/invoke-rc.d ']'
+ for p in '$PATH'
+ '[' -x /usr/local/bin/invoke-rc.d ']'
+ for p in '$PATH'
+ '[' -x /usr/sbin/invoke-rc.d ']'
+ IFS=' 	
'
+ return 0
+ invoke-rc.d mysql stop
+ set_mysql_pw debian-sys-maint ****************
+ set_mysql_pw_user=debian-sys-maint
+ set_mysql_pw_pass=****************
++ mktemp --tmpdir=/var/lib/mysql-files/
+ set_mysql_pw_passfile=/var/lib/mysql-files/tmp.8aRoaBl6Gu
+ chown mysql:mysql /var/lib/mysql-files/tmp.8aRoaBl6Gu
+ echo 'USE mysql;'
+ echo 'UPDATE user SET authentication_string=PASSWORD('\''****************'\'') WHERE user='\''debian-sys-maint'\'';'
+ echo 'FLUSH PRIVILEGES;'
+ echo 'SHUTDOWN;'
+ run_init_sql /var/lib/mysql-files/tmp.8aRoaBl6Gu
++ mktemp -d
+ tmpdir=/tmp/user/0/tmp.NHwIWD8RKi
+ chown mysql:mysql /tmp/user/0/tmp.NHwIWD8RKi
+ mysqld --user=mysql --init-file=/var/lib/mysql-files/tmp.8aRoaBl6Gu --socket=/tmp/user/0/tmp.NHwIWD8RKi/mysqld.sock --pid-file=/tmp/user/0/tmp.NHwIWD8RKi/mysqld.pid
dpkg: error processing package mysql-server-5.7 (--configure):
 subprocess installed post-installation script returned error exit status 1
dpkg: dependency problems prevent configuration of mysql-server:
 mysql-server depends on mysql-server-5.7; however:
  Package mysql-server-5.7 is not configured yet.

dpkg: error processing package mysql-server (--configure):
 dependency problems - leaving unconfigured
Errors were encountered while processing:
 mysql-server-5.7
 mysql-server
E: Sub-process /usr/bin/dpkg returned an error code (1)

I have truncated password from log for security :)
owner seem right : drwx------ 2 mysql mysql 4096 Jul  3 08:48 tmp.NHwIWD8RKi
[3 Jul 2017 7:21] Lars Tangvald 
Maybe the mysql user isn't allow to enter /tmp/user/0 (I assume you  have this set as TMPDIR on your system).

i.e. if -x is set on tmp/user/0, mysql isn't allowed to touch tmp/user/0/dir/foo, even if it owns tmp/user/0/dir

What are the modes for /tmp/user and /tmp/user/0?
[3 Jul 2017 7:47] Laurent C. 
Well done ! I did not think about it

/tmp/user/0 not have write permissions, chmod 777 on this and apt-get install -f work fine now !

I think it comes from my setup, I close the ticket.
Thanks for all
[3 Jul 2017 7:54] Lars Tangvald 
Great!
Note that you shouldn't need write permission set for tmp/user/0, only the +x flag, so for example 755 instead of 777

--
Lars