Bug 9795

Summary: mysqld service don't start
Product: Mageia Reporter: Filipe Saraiva <mail>
Component: RPM PackagesAssignee: Mageia Bug Squad <bugsquad>
Status: RESOLVED FIXED QA Contact:
Severity: normal    
Priority: Normal CC: alien, andr999, mageia, mageia, thomas
Version: CauldronKeywords: NEEDINFO
Target Milestone: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Source RPM: CVE:
Status comment:

Description Filipe Saraiva 2013-04-19 02:33:46 CEST
Hello, my mysqld service don't start. Check the outputs below. Thanks.

[root@anubis ~]# rpm -qa | grep mysql
perl-DBD-mysql-4.22.0-2.mga3
php-mysql-5.4.13-2.mga3
mysql-MariaDB-5.5.28-13.mga3
php-mysqli-5.4.13-2.mga3
qt4-database-plugin-mysql-4.8.4-7.mga3
php-mysqlnd-5.4.13-2.mga3

[root@anubis ~]# service mysqld start
Starting mysqld (via systemctl):  Job for mysqld.service failed. See 'systemctl status mysqld.service' and 'journalctl -n' for details.                [FAILED]

[root@anubis ~]# systemctl status mysqld.service 
mysqld.service - MySQL database server
          Loaded: loaded (/usr/lib/systemd/system/mysqld.service; disabled)
          Active: failed (Result: start-limit) since Thu, 2013-04-18 21:27:55 BRT; 7s ago
         Process: 10094 ExecStartPost=/usr/sbin/mysqld-wait-ready $MAINPID (code=exited, status=1/FAILURE)
         Process: 9737 ExecStart=/usr/bin/mysqld_safe --nowatch (code=exited, status=0/SUCCESS)
         Process: 9718 ExecStartPre=/usr/sbin/mysqld-prepare-db-dir (code=exited, status=0/SUCCESS)
        Main PID: 9695 (code=exited, status=1/FAILURE)
          CGroup: name=systemd:/system/mysqld.service

Apr 18 21:27:55 anubis mysqld-prepare-db-dir[9320]: chown: alterando o dono de â/var/log/mysqld/mysqld.logâ: Operation denied
Apr 18 21:27:55 anubis mysqld_safe[9339]: /usr/bin/mysqld_safe: line 150: /var/log/mysqld/mysqld.log: Operation denied
Apr 18 21:27:55 anubis mysqld-prepare-db-dir[9320]: chmod: alterando permissões de â/var/log/mysqld/mysqld.logâ: Operation denied
Apr 18 21:27:55 anubis mysqld-prepare-db-dir[9718]: touch: não foi possível tocar â/var/log/mysqld/mysqld.logâ: Operation denied
Apr 18 21:27:55 anubis mysqld_safe[9737]: 130418 21:27:55 mysqld_safe Logging to '/var/log/mysqld/mysqld.log'.
Apr 18 21:27:55 anubis mysqld_safe[9737]: 130418 21:27:55 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
Apr 18 21:27:55 anubis mysqld_safe[9737]: /usr/bin/mysqld_safe: line 110: /var/log/mysqld/mysqld.log: Operation denied
Apr 18 21:27:55 anubis mysqld-prepare-db-dir[9718]: chown: alterando o dono de â/var/log/mysqld/mysqld.logâ: Operation denied
Apr 18 21:27:55 anubis mysqld_safe[9737]: /usr/bin/mysqld_safe: line 150: /var/log/mysqld/mysqld.log: Operation denied
Apr 18 21:27:55 anubis mysqld-prepare-db-dir[9718]: chmod: alterando permissões de â/var/log/mysqld/mysqld.logâ: Operation denied

[root@anubis ~]# journalctl -n
-- Logs begin at Sun, 2012-12-02 10:08:32 BRST, end at Thu, 2013-04-18 21:28:41 BRT. --
Apr 18 21:28:41 anubis systemd[1]: mysqld.service: main process exited, code=exited, status=1/FAILURE
Apr 18 21:28:41 anubis systemd[1]: mysqld.service: control process exited, code=exited status=1
Apr 18 21:28:41 anubis systemd[1]: Failed to start MySQL database server.
Apr 18 21:28:41 anubis systemd[1]: Unit mysqld.service entered failed state
Apr 18 21:28:41 anubis systemd[1]: mysqld.service holdoff time over, scheduling restart.
Apr 18 21:28:41 anubis systemd[1]: Stopping MySQL database server...
Apr 18 21:28:41 anubis systemd[1]: Starting MySQL database server...
Apr 18 21:28:41 anubis systemd[1]: mysqld.service start request repeated too quickly, refusing to start.
Apr 18 21:28:41 anubis systemd[1]: Failed to start MySQL database server.
Apr 18 21:28:41 anubis systemd[1]: Unit mysqld.service entered failed state

Reproducible: 

Steps to Reproduce:
Comment 1 Thomas Spuhler 2013-04-19 03:57:11 CEST
no problem here.
Please start it with
systemctl start mysqld
or 
systemctl start mysqld.service

Status: NEW => RESOLVED
CC: (none) => thomas
Resolution: (none) => WORKSFORME

Comment 2 Sander Lepik 2013-04-19 09:17:25 CEST
Well, that's what he did..


Filipe, what does 'ls -l /var/log/mysqld/' show? I think mysql user is not owning log file for some reason.

You can try this as root:

chown -R mysql:mysql /var/log/mysqld

and then try to start MariaDB again.

Does that help?

Keywords: (none) => NEEDINFO
Status: RESOLVED => REOPENED
CC: (none) => sander.lepik
Resolution: WORKSFORME => (none)

Comment 3 Colin Guthrie 2013-04-19 11:32:56 CEST
Technically he started it with "service mysqld start" but that just forwards on to systemctl so it's almost equiv.

I suspect there is indeed some permission problems that prevent the start.

CC: (none) => mageia

Comment 4 Filipe Saraiva 2013-04-19 13:06:53 CEST
Hello Mages,

I did the suggestions, but all failed. See:

From Thomas Spuhler in Comment 1:

[root@anubis ~]# systemctl start mysqld
Job for mysqld.service failed. See 'systemctl status mysqld.service' and 'journalctl -n' for details.
[root@anubis ~]# systemctl start mysqld.service
Job for mysqld.service failed. See 'systemctl status mysqld.service' and 'journalctl -n' for details.

From Sander Lepik in Comment 2:

[root@anubis ~]# ls -l /var/log/mysqld/
total 280
-rw-r----- 1 saned lpadmin 279023 Nov 23 19:58 mysqld.log
[root@anubis ~]# chown -R mysql:mysql /var/log/mysqld
[root@anubis ~]# ls -l /var/log/mysqld/
total 304
-rw-r----- 1 mysql mysql 306198 Abr 19 08:00 mysqld.log
[root@anubis ~]# systemctl start mysqld
Job for mysqld.service failed. See 'systemctl status mysqld.service' and 'journalctl -n' for details.
[root@anubis ~]# service mysqld start
Starting mysqld (via systemctl):  Job for mysqld.service failed. See 'systemctl status mysqld.service' and 'journalctl -n' for details.                [FAILED]

I think this is a permisson problem too, Colin. Well, do you have any idea about the files with permission problem?

Thanks;
Comment 5 Colin Guthrie 2013-04-19 13:20:37 CEST
Check all of /var/lib/mysql* tree too. If the log file was owned by a strange user, then the actual database data may be too... Cant' really think why you'd have such a strangely named log file tho'? Did you do anything interesting on this machine to cause this strange ownership?
Comment 6 Filipe Saraiva 2013-04-19 13:30:15 CEST
Thanks Colin, now it is ok. See:

[root@anubis mysqld]# cd /var/lib/mysql/
[root@anubis mysql]# ls -la
total 28732
drwxr-xr-x  8 mysql mysql       4096 Abr 19 08:00 ./
drwxr-xr-x 54 root  root        4096 Abr  1 17:49 ../
-rw-rw----  1 saned lpadmin    24576 Nov 23 19:58 aria_log.00000001
-rw-rw----  1 saned lpadmin       52 Nov 23 19:58 aria_log_control
-rw-rw----  1 saned lpadmin 18874368 Nov 23 19:58 ibdata1
-rw-rw----  1 saned lpadmin  5242880 Nov 23 19:58 ib_logfile0
-rw-rw----  1 saned lpadmin  5242880 Nov 23 17:23 ib_logfile1
drwx------  2 saned lpadmin     4096 Out 21 15:29 kdebrasil/
drwx------  2 saned lpadmin     4096 Nov 22 10:34 locar/
drwxr-xr-x  2 mysql mysql       4096 Abr 10 19:01 mysql/
drwx------  2 saned lpadmin     4096 Jul 14  2012 performance_schema/
drwxr-xr-x  2 mysql mysql       4096 Abr 10 19:01 test/
drwx------  2 saned lpadmin     4096 Set 19  2012 workshop/
[root@anubis mysql]# cd ..
[root@anubis lib]# chown -R mysql:mysql mysql/
[root@anubis lib]# service mysqld start
Starting mysqld (via systemctl):                  [  OK  ]

Really, I don't know what is this. I am the only user in this machine, it is my production computer. I use mysql only to some works in web development. I never changed in mysql files directly. Well, I am a bit of fear now.

Do you know if 'saned' user and 'lpadmin' group are some system user and group to some software in Mageia installation?

I will close this bug.

Thanks!

Status: REOPENED => RESOLVED
Resolution: (none) => FIXED

Comment 7 Colin Guthrie 2013-04-19 13:49:45 CEST
Yes, saned and lpadmin are users related to printing and scanning.

If so then I suspect the problem is due to upgrading from mysql packages to mariadb packages. This could cause the mysql user to be removed (as part of the mysql package uninstall) and readded under a different uid (when mariadb package is installed). Then at some point cups/saned reuse the group and user id for their own users.

This is only a theory, but knowning the "history" of the machine would enable better guessing. Another possibility would be if you had not formatted /var after resintalling?... It's all somewhat guess work really tho' :D
Comment 8 AL13N 2013-04-19 19:10:13 CEST
won't mysql and mariadb have the same user anyway? i doubt this is the case...

this looks more like an rsynced database from another machine before a mariadb installation. or an install without format...

CC: (none) => alien

Comment 9 Colin Guthrie 2013-04-20 00:24:36 CEST
(In reply to AL13N from comment #8)
> won't mysql and mariadb have the same user anyway? i doubt this is the
> case...

Same user yes, but different package name which means a postun with a 0 argument in the mysql package (last package removed) and %prein with a 0 argument (fresh install) in the mariadb package. Although the package is a replacement it doesn't stop rpm treating it as a removal and a fresh install.
Comment 10 AL13N 2013-04-20 08:27:56 CEST
but if it were upgraded like that, it would be the same number since that is the one that was free'd the last? it would have to install saned between removing mysql and installing mariadb?

perhaps users shouldn't be removed if it's still in use for some files? is this something we could detect?
Comment 11 Colin Guthrie 2013-04-20 23:19:02 CEST
(In reply to AL13N from comment #10)
> but if it were upgraded like that, it would be the same number since that is
> the one that was free'd the last? it would have to install saned between
> removing mysql and installing mariadb?

I don't think the behavour would be overly deterministic here. I don't think users are allocated to the "holes" left behind by removing old users (but I could be wrong). All in all, this is just a suggestion as to one possible explanation. Could be no upgrade was done, so this is really all speculation!

> perhaps users shouldn't be removed if it's still in use for some files? is
> this something we could detect?

Not easily without scanning the whole disk...
Comment 12 andré blais 2013-04-21 01:30:04 CEST
In my past experience (under Mandriva, but I don't think it would have changed),
adding a new ordinary user did not fill in a hole.
It always added an ordinary user after the last ordinary user.
I had to specify the uid in order to fill a hole.
But not sure that it applies to system user accounts (uid under 500), since lpadmin seemed to be using the old uid.

Another explanation is that mysql had been designated for removal but not yet removed, and the reuse of its' uid had been temporarily blocked.
This scenario would allow system uid's to be reused later, in this case by lpadmin.

In either of the above cases, a solution could be to test the uid of the mysql account before removing mysql, and to specify the same uid on recreation of the account on installation of mariadb.

Alternately, find a way of suppressing the removal of the mysql account on upgrade to mariadb.

Maybe even a time delay in the installation of mariadb might work, if it is due to the reuse of the mysql uid being temporarily blocked.

CC: (none) => andre999mga

Comment 13 Colin Guthrie 2013-04-21 02:54:47 CEST
(In reply to andré blais from comment #12)
> Alternately, find a way of suppressing the removal of the mysql account on
> upgrade to mariadb.

Well this is a general problem with package renames really. The main issue is the account removal is in the %postun of the old package, so it's a tricky thing to solve without updating the old package.

Technically, we could do some complex stuff with rpm-helper - i.e. writing a flag in the %pre of the mariadb package and then when the %postun of mysql package is processed we could read said flag and adjust our actions accordingly. That said, we have no idea whether we should just fudge the number argument passed to post scripts in this case or something more. Even then this only covers rpm-helper macros and it wouldn't apply to any hard-coded macros in the old package etc. So really I'd rather see official support for "package renames" built into rpm itself so this could be dealt with holistically.

As this particular rename was done in mga2, I'd rather not spend much time on this until similar issues arise in the future :)
Comment 14 andré blais 2013-04-21 04:48:29 CEST
(In reply to Colin Guthrie from comment #13)
> (In reply to andré blais from comment #12)
> > Alternately, find a way of suppressing the removal of the mysql account on
> > upgrade to mariadb.
> 
> Well this is a general problem with package renames really. The main issue
> is the account removal is in the %postun of the old package, so it's a
> tricky thing to solve without updating the old package.

If I understand correctly,
mariadb %pre would necessarily be run before mysql %postun ?

Then don't we have a potential solution there ?

That is, look for the uid of the mysql account.  If it isn't found, set the uid flag to -1.  (Otherwise containing the uid of the account.)
Then when mariadb is installed, create a mysql account if necessary, using the previous uid if found.
Then all the changes would happen on the mariadb side.

> 
> Technically, we could do some complex stuff with rpm-helper - i.e. writing a
> flag in the %pre of the mariadb package and then when the %postun of mysql
> package is processed we could read said flag and adjust our actions
> accordingly.

That sounds a lot like what seems to me the ideal solution ...
If the rpm process would allow us to reserve ressources (such as accounts or folders) during updates to different package names.
(The complexity would be in rpm* instead of a package spec file.)
Potentially this could be done automatically, if rpm has the intelligence to recognize identical ressources.

Alternately maybe an update flag for package renames.
To signal the rpm process to let the new package do whatever uninstall process is required.  That might be simpler to implement.
Is that how it works for updates with the same name ?

> 
> As this particular rename was done in mga2, I'd rather not spend much time
> on this until similar issues arise in the future :)

Makes sense :)
Comment 15 AL13N 2013-04-21 08:59:28 CEST
i was more thinking along the lines of if the owned directories (with that user?) fail, because files are still in it, we could reject the removal of the user.

because, this isn't only about package renames, it's also about uninstalling and later installing again...

i agree it's not an important issue, but in this way, it could be fixed for the uninstall + later reinstall case...
Comment 16 andré blais 2013-04-22 03:15:41 CEST
(In reply to AL13N from comment #15)
> i was more thinking along the lines of if the owned directories (with that
> user?) fail, because files are still in it, we could reject the removal of
> the user.
> 
> because, this isn't only about package renames, it's also about uninstalling
> and later installing again...
> 
> i agree it's not an important issue, but in this way, it could be fixed for
> the uninstall + later reinstall case...

A plus with that is that it can be very easily determined.
It would require changing the rpm process.
But what if one really wants to totally remove a package ?
It would be useful to add that option as well.