Bug 1082018

(sorry, that's "ExecStartPost" and not "xecStartPost" of course in mariadb.service, I mis-pasted it here)

Thanks for reporting. First, are there any issues in the syslog related to mariadb.service? It seems it could be caused by wrong scripts that are now changed as the attached patch shows (you can try to change the two scritps according to the attached file and see if it helps).

You said you did a fresh install, but isn't it possible you had already some configuration present, so you can use non-default options? If so, can you share them, please? Or any other special configuration you have?

Hello,

Thanks for responding. However I can't see the attached file you're referring to unless I'm missing something. I also see comment #1 and #4 but not 2-3, not sure if that's relevant. :)

The installation is fresh although it's possible puppet has made some things non-default. I'll include some more information in case you can use it. Please note if I take ExecStartPost out of mariadb.service the server starts, as it also does if I start it manually (i.e. without systemctl).

---- log ----
> systemctl status mariadb.service
mariadb.service - MariaDB database server
   Loaded: loaded (/usr/lib/systemd/system/mariadb.service; disabled)
   Active: failed (Result: exit-code) since Thu 2014-04-03 14:06:49 EDT; 6s ago
  Process: 10663 ExecStartPost=/usr/libexec/mariadb-wait-ready $MAINPID (code=exited, status=1/FAILURE)
  Process: 10662 ExecStart=/usr/bin/mysqld_safe --basedir=/usr (code=exited, status=0/SUCCESS)
  Process: 10638 ExecStartPre=/usr/libexec/mariadb-prepare-db-dir %n (code=exited, status=0/SUCCESS)
 Main PID: 10662 (code=exited, status=0/SUCCESS)

Apr 03 14:06:46 machine.example.com mysqld_safe[10662]: 140403 14:06:46 mysqld_safe Logging to '/var/lib/mysql/machine.example.com.err'.
Apr 03 14:06:46 machine.example.com mysqld_safe[10662]: 140403 14:06:46 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
Apr 03 14:06:48 machine.example.com systemd[1]: mariadb.service: control process exited, code=exited status=1
Apr 03 14:06:49 machine.example.com mysqld_safe[10662]: 140403 14:06:49 mysqld_safe mysqld from pid file /var/lib/mysql/machine.example.com.pid ended
Apr 03 14:06:49 machine.example.com systemd[1]: Failed to start MariaDB database server.
Apr 03 14:06:49 machine.example.com systemd[1]: Unit mariadb.service entered failed state.
----

---- my.cnf ----[mysqld]
basedir = /usr
datadir = /var/lib/mysql
socket = /var/lib/mysql/mysql.sock

max_connections=200

key_buffer=128M

max_allowed_packet=256M

group_concat_max_len=1M

table_cache=384

sort_buffer_size=1M

read_buffer_size=1M

read_rnd_buffer_size=4M
         
myisam_sort_buffer_size=64M
         
thread_cache_size=8 

query_cache_size=256M

query_cache_limit=4M 

query_cache_type=1 
    
thread_concurrency = 8

open_files_limit=2048

ft_min_word_len=3

server-id = 16

old-passwords

tmp_table_size = 512M
max_heap_table_size = 512M

---- mariadb.service ----

[Unit]
Description=MariaDB database server
After=syslog.target
After=network.target

[Service]
Type=simple
User=mysql
Group=mysql

ExecStartPre=/usr/libexec/mariadb-prepare-db-dir %n
# Note: we set --basedir to prevent probes that might trigger SELinux alarms,
# per bug #547485
ExecStart=/usr/bin/mysqld_safe --basedir=/usr
ExecStartPost=/usr/libexec/mariadb-wait-ready $MAINPID

# Give a reasonable amount of time for the server to start up/shut down
TimeoutSec=300

# Place temp files in a secure directory, not /tmp
PrivateTmp=true

[Install]
WantedBy=multi-user.target

Created attachment 882558 [details]
Recent changes in the mariadb helper scripts

(In reply to John Margaritsanakis from comment #5)
> Thanks for responding. However I can't see the attached file you're
> referring to unless I'm missing something.

I'm sorry, my fault, attaching now.

> I also see comment #1 and #4 but
> not 2-3, not sure if that's relevant. :)

No, there is no information there.

> The installation is fresh although it's possible puppet has made some things
> non-default. I'll include some more information in case you can use it.
> Please note if I take ExecStartPost out of mariadb.service the server
> starts, as it also does if I start it manually (i.e. without systemctl).
<snip>

The failure is most probably caused by /usr/libexec/mariadb-wait-ready, that reads the daemon's pid (while wrongly guess the pid file if not defined in my.cnf), which is unnecessary (the script gets the pid number as an argument).

The attached file is a patch, which we'll use for GA. So to avoid the failure you can either apply these patches or define pid-file explicitly in your /etc/my.cnf:

[mysqld_safe]
pid-file=/var/run/mariadb/mariadb.pid

Either of the way should help you to start the server.

Thanks for the quick answers.

I applied the patch (and checked it was applied correctly). 

I tried to start the server using the default ExecStartPost (/usr/libexec/mariadb-wait-ready $MAINPID) as well as to supply the patch to the .pid file directly (/usr/libexec/mariadb-wait-ready /var/run/mariadb/mariadb.pid). 

I tried it with pid-file=/var/run/mariadb/mariadb.pid in my.cnf and without.

Either way it waits for a long time (I guess 300 secs as per the TimeoutSec setting) then fails:

> systemctl status mariadb.service
mariadb.service - MariaDB database server
   Loaded: loaded (/usr/lib/systemd/system/mariadb.service; enabled)
   Active: failed (Result: signal) since Fri 2014-04-04 10:14:22 EDT; 35s ago
  Process: 7039 ExecStartPost=/usr/libexec/mariadb-wait-ready /var/run/mariadb/mariadb.pid (code=exited, status=1/FAILURE)
  Process: 7037 ExecStart=/usr/bin/mysqld_safe --basedir=/usr (code=killed, signal=KILL)
  Process: 7008 ExecStartPre=/usr/libexec/mariadb-prepare-db-dir %n (code=exited, status=0/SUCCESS)
 Main PID: 7037 (code=killed, signal=KILL)

Apr 04 10:09:22 machine.example.com systemd[1]: mariadb.service: control process exited, code=exited status=1
Apr 04 10:09:22 machine.example.com mysqld_safe[7037]: 140404 10:09:22 mysqld_safe Logging to '/var/lib/mysql/machine.example.com.err'.
Apr 04 10:09:23 machine.example.com mysqld_safe[7037]: 140404 10:09:23 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
Apr 04 10:14:22 machine.example.com systemd[1]: mariadb.service stopping timed out. Killing.
Apr 04 10:14:22 machine.example.com systemd[1]: mariadb.service: main process exited, code=killed, status=9/KILL
Apr 04 10:14:22 machine.example.com systemd[1]: Failed to start MariaDB database server.
Apr 04 10:14:22 machine.example.com systemd[1]: Unit mariadb.service entered failed state.

Ideas?

Hm, that's weird. What about if you ran the following command in a separate terminal during the service is "being started"?

/usr/bin/mysqladmin --no-defaults --socket="/var/lib/mysql/mysql.sock" --user=UNKNOWN_MYSQL_USER ping ; echo $?

(Assuming you meant a real and authenticated user, as otherwise it just says access denied)

mysqld is alive
0

(In reply to John Margaritsanakis from comment #9)
> (Assuming you meant a real and authenticated user, as otherwise it just says
> access denied)

No, I meant using the string "UNKNOWN_MYSQL_USER" literally. In that case it should really print "Access denied for user", but the mariadb-wait-ready should match and exit. However, that is obviously not happening.

I'm starting to get out of ideas how to debug. Well, let's start over. When you comment-out the line "ExecStartPost=/usr/libexec/mariadb-wait-ready $MAINPID" in /usr/lib/systemd/system/mariadb.service, run `systemctl daemon-reload`, then the service starts up, right?

While daemon is running this way, you can try:
1) get the PID of the main process (you read this information from `systemctl status mariadb`)
2) try to run `/usr/libexec/mariadb-wait-ready 1234` (where 1234 is the pid you found in 1
This should end quite fast in case the daemon is running and everything is OK (say in a second). If not (as I'd expect), please try to add `set -x` to the beginning of the /usr/libexec/mariadb-wait-ready script, maybe add some debugging `echo ...` calls, so you can say where the script mariadb-wait-ready doesn't behave like it should.

(Sorry I'm instructing you to do such weird steps, but as I cannot reproduce this with your settings on my system, I don't have much other possibilities how to get known what is happening on your system)

I just installed a fresh RHEL7 VM from the same image as the previous one. 

Post-patch (as per the attachments here) with the ExecStartPost in place, the service runs just fine.

I don't know why I had issues on this one but I think it can be flagged as solved. 

Thanks for all your help, and I hope to see the patched scripts in base soon. :)

Alright, last report.

New system, patched with the attachment.

The mariadb service _won't_ start unless I have a pid-file declaration in /etc/my.cnf. If I uncomment it, it works fine. When I comment it out again it won't restart.

So it looks like you currently need both the updated scripts and the line in the [mysqld_safe] options block.

Thanks for your feedback, I'm glad that you managed to get it work, but I'm still wondering why the patching itself is not enough. Well, it is actually on my system, i.e. it is enough to do only one thing in my environment (with your my.cnf) -- either to define the pid-file in my.cnf or patch the sources.

*** This bug has been marked as a duplicate of bug 1069586 ***