[debian-mysql] Bug#663000: Bug#663000: mysql-server: MySQL fails to start after 5.1.61 upgrade, incorrect permissions

Fri Mar 9 07:51:29 UTC 2012

Excerpts from Alex Cartwright's message of Thu Mar 08 13:00:23 -0800 2012:
> Is there any more information that I can provide to help debug this? I
> was talking with someone in #debian irc.freenode.net earlier on today
> and they had the same problem. They resolved it by managing to chown
> said files just before it tried to start MySQL again.
> 
> Right now I'm not sure what extra info I can get for you.
> 

Alex, I'm kind of at a loss for how this is happening. The postinst
directly calls this code on configuring mysql-server-5.1:

    mysql_statedir="/var/lib/mysql"
    ...
    chown -R mysql $mysql_statedir

So you can see where the fact that the binlogs are being chown'ed to
root is rather confusing!

There is one chown that might lead to this:

    mysql_datadir="/usr/share/mysql"
    chown -R 0:0 $mysql_datadir

Perhaps there are links in /usr/share/mysql to your binlogs? Also is it
possible /var/lib/mysql is a symlink?

> Regards
> 
> On 7 March 2012 23:44, Clint Byrum <clint at ubuntu.com> wrote:
> > Excerpts from Alex Cartwright's message of Wed Mar 07 13:32:44 -0800 2012:
> >> Package: mysql-server
> >> Version: 5.1.61-0+squeeze1
> >> Severity: important
> >>
> >> After the recent security upgrade to MySQL 5.1.61, MySQL failed to start
> >> during the "apt-get update && apt-get upgrade" process due to incorrect
> >> permissions being set on the /var/lib/mysql/mysql-bin.* files.
> >>
> >> Instead of being mysql:mysql they were set to root:root, causing MySQL
> >> to fail starting with errors such as:
> >>
> >> Mar  7 20:52:37 lon1 mysqld_safe[16756]: 120307 20:52:37 [ERROR] Failed
> >> to open log (file './mysql-bin.000397', errno 13)
> >> Mar  7 20:52:37 lon1 mysqld_safe[16756]: 120307 20:52:37 [ERROR] Could
> >> not open log file
> >> Mar  7 20:52:37 lon1 mysqld_safe[16756]: 120307 20:52:37 [ERROR] Can't
> >> init tc log
> >> Mar  7 20:52:37 lon1 mysqld_safe[16756]: 120307 20:52:37 [ERROR]
> >> Aborting
> >>
> >> Changing the owner/group to mysql:mysql manually and starting the
> >> "mysql" service got things working, however running update && upgrade
> >> again causes the issue again.
> >>
> >
> > Hi Alex, sorry this is causing you trouble.
> >
> > I was not able to reproduce this in a clean squeeze chroot:
> >
> > (squeeze-amd64)root at clint-MacBookPro:/home/clint# ls -l /var/lib/mysql
> > total 20532
> > -rw-r--r-- 1 root  root         0 Mar  7 15:36 debian-5.1.flag
> > -rw-rw---- 1 mysql mysql  5242880 Mar  7 15:37 ib_logfile0
> > -rw-rw---- 1 mysql mysql  5242880 Mar  7 15:36 ib_logfile1
> > -rw-rw---- 1 mysql mysql 10485760 Mar  7 15:37 ibdata1
> > drwx------ 2 mysql root      4096 Mar  7 15:37 mysql
> > -rw------- 1 root  root         6 Mar  7 15:37 mysql_upgrade_info
> > -rw-rw---- 1 mysql mysql    37810 Mar  7 15:37 mysqld-bin.000001
> > -rw-rw---- 1 mysql mysql       20 Mar  7 15:37 mysqld-bin.index
> > (squeeze-amd64)root at clint-MacBookPro:/home/clint# apt-get upgrade
> > Reading package lists... Done
> > Building dependency tree
> > Reading state information... Done
> > The following packages will be upgraded:
> >  libmysqlclient16 mysql-client-5.1 mysql-common mysql-server-5.1 mysql-server-core-5.1
> > 5 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
> > Need to get 22.8 MB of archives.
> > After this operation, 307 kB disk space will be freed.
> > Do you want to continue [Y/n]?
> > Get:1 http://security.debian.org/ squeeze/updates/main mysql-common all 5.1.61-0+squeeze1 [69.6 kB]
> > Get:2 http://security.debian.org/ squeeze/updates/main libmysqlclient16 amd64 5.1.61-0+squeeze1 [1976 kB]
> > Get:3 http://security.debian.org/ squeeze/updates/main mysql-client-5.1 amd64 5.1.61-0+squeeze1 [10.0 MB]
> > Get:4 http://security.debian.org/ squeeze/updates/main mysql-server-5.1 amd64 5.1.61-0+squeeze1 [6587 kB]
> > Get:5 http://security.debian.org/ squeeze/updates/main mysql-server-core-5.1 amd64 5.1.61-0+squeeze1 [4130 kB]
> > Fetched 22.8 MB in 15s (1432 kB/s)
> > Preconfiguring packages ...
> > (Reading database ... 12360 files and directories currently installed.)
> > Preparing to replace mysql-common 5.1.49-3 (using .../mysql-common_5.1.61-0+squeeze1_all.deb) ...
> > Unpacking replacement mysql-common ...
> > Preparing to replace libmysqlclient16 5.1.49-3 (using .../libmysqlclient16_5.1.61-0+squeeze1_amd64.deb) ...
> > Unpacking replacement libmysqlclient16 ...
> > Preparing to replace mysql-client-5.1 5.1.49-3 (using .../mysql-client-5.1_5.1.61-0+squeeze1_amd64.deb) ...
> > Unpacking replacement mysql-client-5.1 ...
> > Setting up mysql-common (5.1.61-0+squeeze1) ...
> > (Reading database ... 12361 files and directories currently installed.)
> > Preparing to replace mysql-server-5.1 5.1.49-3 (using .../mysql-server-5.1_5.1.61-0+squeeze1_amd64.deb) ...
> > invoke-rc.d: policy-rc.d denied execution of stop.
> > invoke-rc.d: policy-rc.d denied execution of stop.
> > df: Warning: cannot read table of mounted file systems: No such file or directory
> > Unpacking replacement mysql-server-5.1 ...
> > Preparing to replace mysql-server-core-5.1 5.1.49-3 (using .../mysql-server-core-5.1_5.1.61-0+squeeze1_amd64.deb) ...
> > Unpacking replacement mysql-server-core-5.1 ...
> > Setting up libmysqlclient16 (5.1.61-0+squeeze1) ...
> > Setting up mysql-client-5.1 (5.1.61-0+squeeze1) ...
> > Setting up mysql-server-core-5.1 (5.1.61-0+squeeze1) ...
> > Setting up mysql-server-5.1 (5.1.61-0+squeeze1) ...
> > invoke-rc.d: policy-rc.d denied execution of stop.
> > invoke-rc.d: policy-rc.d denied execution of start.
> > (squeeze-amd64)root at clint-MacBookPro:/home/clint# ls -l /var/lib/mysql
> > total 21288
> > -rw-r--r-- 1 mysql mysql        0 Mar  7 15:38 debian-5.1.flag
> > -rw-rw---- 1 mysql mysql  5242880 Mar  7 15:39 ib_logfile0
> > -rw-rw---- 1 mysql mysql  5242880 Mar  7 15:36 ib_logfile1
> > -rw-rw---- 1 mysql mysql 10485760 Mar  7 15:39 ibdata1
> > drwx------ 2 mysql mysql     4096 Mar  7 15:38 mysql
> > -rw------- 1 mysql mysql        6 Mar  7 15:37 mysql_upgrade_info
> > -rw-rw---- 1 mysql mysql    37810 Mar  7 15:37 mysqld-bin.000001
> > -rw-rw---- 1 mysql mysql    19048 Mar  7 15:38 mysqld-bin.000002
> > -rw-rw---- 1 mysql mysql   736801 Mar  7 15:38 mysqld-bin.000003
> > -rw-rw---- 1 mysql mysql      300 Mar  7 15:38 mysqld-bin.000004
> > -rw-rw---- 1 mysql mysql      125 Mar  7 15:38 mysqld-bin.000005
> > -rw-rw---- 1 mysql mysql      849 Mar  7 15:38 mysqld-bin.000006
> > -rw-rw---- 1 mysql mysql      125 Mar  7 15:39 mysqld-bin.000007
> > -rw-rw---- 1 mysql mysql      140 Mar  7 15:39 mysqld-bin.index