Systemctl hates mysqld: refuses to start Fedora 16 (LONG)

[R. G. Newbury]

Well I am stumped. I have a puzzler which needs the brain-power and 
knowledge which hangs around here.

  Systemctl on fedora 16 will NOT start mysqld.

  The problem started on Thursday evening when I rebooted. Uptime was 
then 60 days. Mysqld was running, but mythfrontend was having difficulty 
connecting. This was *before* the UTC problem arose. No updates since 
about January.

  Startup of mysqld fails with a permissions error, attempting to write 
to /tmp,  which is chmod 1777, that is, world writeable and readable! 
There is  nothing wrong with the mysql setup. If I run each command from 
the  command line, mysqld starts without problem. That is to say: there 
is  nothing wrong with the mysqld setup. I repeat: there is nothing 
wrong  with the mysqld setup.

But mysqld startup FAILS when initiated by systemctl.

  In order to avoid unhelpful responses/questions relating to the many
  many many other ways in which one can have mysqld fail to start, I 
will list the sanity checks which I have used to ensure that everything
  lines up properly: I have checked my.cnf and use the same command line
  switches, and folders and permissions throughout. Everything run as
  root. Selinux disabled. And mysqld *will* start properly from the
  commandline, just NOT by way of systemctl. See log extract below.

So any answers about missing folders etc are off-track.

  *** Proof of Setup
  # mkdir /var/log/mysqld
  mkdir: cannot create directory `/var/log/mysqld': File exists
  # chown -R mysql:mysql /var/log/mysqld
  # chmod -R 777 /var/log/mysqld
  # chown -R mysql:mysql /run/mysqld
  # chmod -R 777 /run/mysqld
  # chmod -R 1777 /tmp
  # killall mysqld
  mysqld: no process found

  **** Replicate mysqld.service commands:

  # /usr/libexec/mysqld-prepare-db-dir
  # /usr/bin/mysqld_safe --nowatch --datadir=/var/lib/mysql
  --socket=/var/lib/mysql/mysql.sock --pid-file=/run/mysqld/mysqld.pid
  --basedir=/usr/ --log-error=/var/log/mysqld/mysqld.log
  # /usr/libexec/mysqld-wait-ready $MAINPID

  **** and mysqld STARTS
  # ps -ae | grep mysqld
  20853 pts/3    00:00:00 mysqld

  At this point, I can use the console mysql client, etc. etc.
  So the mysqld setup is correct. But this is not what happens under
  systemctl

  ******** COMPARE AND CONTRAST *******
  # killall mysqld

  # systemctl start mysqld.service
  Job failed. See system logs and 'systemctl status' for details.

  *** Edited *** Failure is:
            Process: 25762 ExecStartPost=/usr/libexec/mysqld-wait-ready
  $MAINPID (code=exited, status=1/FAILURE)

  *** Comment out the exec-post command (which is not technically
  required...it just adds some 'settle' time) and reload:

  # systemctl start mysqld.service

  ******* Note that it gives no error....as appears above
  ******** Yes the service IS disabled atm, because of this testing
  # systemctl status mysqld.service
  mysqld.service - MySQL database server
             Loaded: loaded (/lib/systemd/system/mysqld.service; disabled)
             Active: failed since Sun, 01 Jul 2012 12:05:22 -0400; 5s ago
            Process: 26943 ExecStart=/usr/bin/mysqld_safe --nowatch
  --datadir=/var/lib/mysql --socket=/var/lib/mysql/mysql.sock
  --pid-file=/run/mysqld/mysqld.pid --basedir=/usr/
  --log-error=/var/log/mysqld/mysqld.log (code=exited, status=0/SUCCESS)
            Process: 26927 ExecStartPre=/usr/libexec/mysqld-prepare-db-dir
  (code=exited, status=0/SUCCESS)
           Main PID: 27128 (code=exited, status=0/SUCCESS)
             CGroup: name=systemd:/system/mysqld.service

    SO, the operation was a success but the patient died...

  **** mysqld.log

  **** First the command line startup and shutdown:

  120701 12:15:30 mysqld_safe Starting mysqld daemon with databases from
  /var/lib/mysql
  120701 12:15:30 [Note] Plugin 'FEDERATED' is disabled.
  120701 12:15:30 InnoDB: The InnoDB memory heap is disabled
  120701 12:15:30 InnoDB: Mutexes and rw_locks use GCC atomic builtins
  120701 12:15:30 InnoDB: Compressed tables use zlib 1.2.5
  120701 12:15:30 InnoDB: Using Linux native AIO
  120701 12:15:30 InnoDB: Initializing buffer pool, size = 128.0M
  120701 12:15:30 InnoDB: Completed initialization of buffer pool
  120701 12:15:30 InnoDB: highest supported file format is Barracuda.
  120701 12:15:30  InnoDB: Waiting for the background threads to start
  120701 12:15:31 InnoDB: 1.1.8 started; log sequence number 5950198631
  120701 12:15:31 [Note] Server hostname (bind-address): '127.0.0.1';
  port: 3306
  120701 12:15:31 [Note]   - '127.0.0.1' resolves to '127.0.0.1';
  120701 12:15:31 [Note] Server socket created on IP: '127.0.0.1'.
  120701 12:15:31 [Note] Event Scheduler: Loaded 0 events
  120701 12:15:31 [Note] /usr/libexec/mysqld: ready for connections.
  Version: '5.5.24'  socket: '/var/lib/mysql/mysql.sock'  port: 3306
MySQL
  Community Server (GPL)
  120701 12:16:08 [Note] /usr/libexec/mysqld: Normal shutdown

  120701 12:16:08 [Note] Event Scheduler: Purging the queue. 0 events
  120701 12:16:08  InnoDB: Starting shutdown...
  120701 12:16:09  InnoDB: Shutdown completed; log sequence number 
5950198631
  120701 12:16:09 [Note] /usr/libexec/mysqld: Shutdown complete
  120701 12:16:08 [Note] Event Scheduler: Purging the queue. 0 events
  120701 12:16:08  InnoDB: Starting shutdown...

  **** All as expected
  **** Systemctl startup:

  20701 12:23:23 mysqld_safe Starting mysqld daemon with databases from
  /var/lib/mysql
  120701 12:23:23 [Note] Plugin 'FEDERATED' is disabled.
  120701 12:23:23 InnoDB: The InnoDB memory heap is disabled
  120701 12:23:23 InnoDB: Mutexes and rw_locks use GCC atomic builtins
  120701 12:23:23 InnoDB: Compressed tables use zlib 1.2.5
  120701 12:23:23 InnoDB: Using Linux native AIO

  ********** HERE IS THE ERROR

  ^G/usr/libexec/mysqld: Can't create/write to file '/tmp/ibVcsIip'
  (Errcode: 13)
  120701 12:23:23  InnoDB: Error: unable to create temporary file; errno: 13
  120701 12:23:23 [ERROR] Plugin 'InnoDB' init function returned error.
  120701 12:23:23 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE
  failed.
  120701 12:23:23 [ERROR] Unknown/unsupported storage engine: InnoDB
  120701 12:23:23 [ERROR] Aborting

  120701 12:23:23 [Note] /usr/libexec/mysqld: Shutdown complete

  I can find NO other error messages. /tmp is 1777: completely world
  writeable, but systemctl/mysqld cannot write there.

  Sorry for the length. Can anyone shed ANY light on this?

  (And for all our sakes when replying, please PLEASE PLEASE chop off at
  the least everything above the 'HERE IS THE ERROR LINE'. It is all
  background and setup and not relevant to the actual error. It only 
shows *where* the error appears and why 'the usual suspects' are not to 
be considered 'persons of interest'.

  ATM, my workaround is to disable mysqld.service, and start mysqld as 
an  /etc/rc.d/init.d service by calling mysqld-prepare-db-dir and
  mysqld_safe from there. It's a bodge (and that's what I call it!) And
  without mysql, my mythbox is useless.

  I want to know why mysqld cannot write to /tmp when started by
  systemctl on Fedora 16. (Everything works properly in Fedora 17). 
(Anyone know if Lennart reads this list?)


  Geoff

[Dale Dellutri]

On Mon, Jul 2, 2012 at 8:55 AM, R. G. Newbury <newbury(a)mandamus.org&gt; wrote:
> ...
>   **** Systemctl startup:
>
>   20701 12:23:23 mysqld_safe Starting mysqld daemon with databases from
>   /var/lib/mysql
>   120701 12:23:23 [Note] Plugin 'FEDERATED' is disabled.
>   120701 12:23:23 InnoDB: The InnoDB memory heap is disabled
>   120701 12:23:23 InnoDB: Mutexes and rw_locks use GCC atomic builtins
>   120701 12:23:23 InnoDB: Compressed tables use zlib 1.2.5
>   120701 12:23:23 InnoDB: Using Linux native AIO
>
>   ********** HERE IS THE ERROR
>
>   ^G/usr/libexec/mysqld: Can't create/write to file '/tmp/ibVcsIip'
>   (Errcode: 13)
>   120701 12:23:23  InnoDB: Error: unable to create temporary file; errno: 13
>   120701 12:23:23 [ERROR] Plugin 'InnoDB' init function returned error.
>   120701 12:23:23 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE
>   failed.
>   120701 12:23:23 [ERROR] Unknown/unsupported storage engine: InnoDB
>   120701 12:23:23 [ERROR] Aborting
>
>   120701 12:23:23 [Note] /usr/libexec/mysqld: Shutdown complete 
Did you see this bugzilla?
  https://bugzilla.redhat.com/show_bug.cgi?id=782513
  Bug 782513 - Propose that you turn on PrivateTmp=true in service
file for mysql
The workaround is:
  I've edited the unit file to remove PrivateTmp, after which mysql starts
  #PrivateTmp=true
Relevant?

-- 
Dale Dellutri

[Neil Bird]

Around about 02/07/12 14:55, R. G. Newbury typed ...
>     Systemctl on fedora 16 will NOT start mysqld. 
   Bit behind, dunno if you've come to a conclusion yourself ...

   I've not had to do this myself, so I don't know how well, if at all, 
it'll work.  I would try:

strace -f -p PidOfSystemd -efile

   .. in one window to see what file ops. are *actually* occurring, and what 
error codes are *actually* coming back.

   Then try the systemctl command in another to start it.  This presumes one 
systemd process is running the show and actually trying to perform the 
start.  It also presumes you can see the signal through the noise:  as I 
say, I've not had to strace systemd yet, so I know know what sort of spew 
you get when the mentioned file is accessed.  It may be a red-herring error 
message falling out of another failure.

-- 
[neil@fnx ~]# rm -f .signature
[neil@fnx ~]# ls -l .signature
ls: .signature: No such file or directory
[neil@fnx ~]# exit