Red Hat Bugzilla – Bug 699114
FIXED_IN_GIT: stopping mysql doesn't work
Last modified: 2011-07-31 00:01:47 EDT
Created attachment 494387 [details] dmesg Description of problem: Since a few day I am not able to shut down my fedora 15 install properly. The X-Server is terminated and I just got a blinking cursor in the upper left. I am able to switch to different ttys but I could not login. I use xfce and gdm to start my desktop environment. I tried other methods to shut down like 'halt' or 'init 0' but both did yield just the same result as any other method from gdm or from within xfce. Version-Release number of selected component (if applicable): rpm -qa | grep systemd systemd-sysv-25-1.fc15.x86_64 systemd-gtk-25-1.fc15.x86_64 systemd-25-1.fc15.x86_64 systemd-units-25-1.fc15.x86_64 I am not sure if systemd is responsible for this at all. How reproducible: Always Actual results: Non-responsive machine which doesn't shut down Expected results: Clean shutdown! Additional info:
Created attachment 494388 [details] systemd-analyze plot > boot.svg
Just for the record a yum downgrade systemd* solved this issue for me. So it seems to be a regression in 25-1
Please boot with systemd.log_level=debug and systemd.log_target=kmsg on the kernel command line. Then symlink "/lib/systemd/system/rescue.target" to "/etc/systemd/system/kbrequest.target". Then reload, and shutdown. If shutdown hangs, Press Alt-UpArrow. You should get a shell prompt. Please use "dmesg" to acquire the log output, save it somewhere, and attach here. You should always be able to shut down the machine with clean file systems with "systemctl poweroff -f".
As I said I could switch to different virtual consoles but I could not enter anything at the login prompt and therefore could not access a root-console and so I am not able to save dmesg. Is there perhaps another way to save it?
Created attachment 494621 [details] dmesg with systemd.log_level=debug and systemd.log_target=kmsg and after try shutdown I've boot system with systemd.log_level=debug and systemd.log_target=kmsg in kernel parameters. Try shutdown (from KDE). System freeze. I've connect on ssh and run dmesg > dmesg.log.
This bug is affected to me too.
And yes, systemctl poweroff -f works fine.
I can confirm the problem. (after upgrade from 24-1 to 25-1)
(In reply to comment #3) > If shutdown hangs, Press Alt-UpArrow. You should get a shell prompt. This trick doesn't work here - I can't get a shell. When I press alt + up arrow I only see a black screen. When I switch to second tty and then back I can see some messages about stopping mysql. Best regards, Michal
Alexei, your output shows nothing wrong. Can you make sure to wait for 3min when this hangs, because that's the timeout systemd has for everything. Can somebody please do what I asked for in comment #3. Michal, have you linked /etc/systemd/system/kbrequest.target as suggested in comment #3? Only then Alt-UpArrow will spawn a shell.
(In reply to comment #10) > Michal, have you linked /etc/systemd/system/kbrequest.target as suggested in > comment #3? Only then Alt-UpArrow will spawn a shell. Yes $ ls -la [..] lrwxrwxrwx 1 root root 33 04-26 18:20 kbrequest.target -> /lib/systemd/system/rescue.target but I never waited 3 minutes to see shell - so maybe it is about timeout. Will try again later.
(In reply to comment #11) > (In reply to comment #10) > > Michal, have you linked /etc/systemd/system/kbrequest.target as suggested in > > comment #3? Only then Alt-UpArrow will spawn a shell. > > Yes > > $ ls -la > [..] > lrwxrwxrwx 1 root root 33 04-26 18:20 kbrequest.target -> > /lib/systemd/system/rescue.target Did you reload systemd with "systemctl daemon-reload"? Anybody else can get me some useful output from the shutdown?
(In reply to comment #12) > Did you reload systemd with "systemctl daemon-reload"? No, I had to add systemd.log_level=* to grub config and I rebooted system - should be enough I guess :) Maybe I need to enable something in /etc/systemd/system.conf ? CrashShell?
Lennart, I wrote a small shell script, but can't running from cron, because systemd halted crond.service... (Sorry my very poor english.) #!/bin/bash outfile='/root/systemd.debug.txt' { separator='----------------------------------' cmd='rpm -q kernel selinux-policy systemd' echo "$cmd" $cmd echo "$separator" grubconf='/boot/grub/grub.conf' echo "$grubconf" echo cat "$grubconf" echo "$separator" cmd='dmesg' echo "$cmd" $cmd } >"$outfile" sync systemctl poweroff -f exit 0 How I running it? (If I use Alt-UpArrow, home position flashing cursor is off, my monitor is totally black.)
Created attachment 495281 [details] dmesg after 3 minutes wait This dmesg after 3 minutes waiting. Alt-UpArrow or Alt-DownArrow don't work. But I've switched on second console (Alt-Ctrl-F2), login (after symlink from comment #3) and get dmesg there.
(In reply to comment #15) > Alt-UpArrow or Alt-DownArrow don't work. But I've switched on second console > (Alt-Ctrl-F2), login (after symlink from comment #3) and get dmesg there. I wonder why I can not use this console - in my case TTY2 doesn't accept any chars.
(In reply to comment #16) > in my case TTY2 doesn't accept any chars. Same problem here.
(In reply to comment #15) > This dmesg after 3 minutes waiting. This one is useless. systemd did not even begin to shutdown, because you broke your kdm configuration: [ 135.777880] kdm[4001]: Failed to execute shutdown command "systemctl poweroff -f" Please test with the original kdmrc setting HaltCmd=/sbin/poweroff
Hooray, I can reproduce this! 1) systemctl start mysqld.service 2) init 6 No timeout kicks in. I can still login via ssh and see: # systemctl list-jobs | grep running 1118 mysqld.service stop running # systemctl status mysqld.service mysqld.service - SYSV: MySQL database server. Loaded: loaded (/etc/rc.d/init.d/mysqld) Active: deactivating (stop-sigterm) since Wed, 27 Apr 2011 19:18:44 +0200; 3min 24s ago Process: 2056 ExecStop=/etc/rc.d/init.d/mysqld stop (code=exited, status=0/SUCCESS) Process: 1708 ExecStart=/etc/rc.d/init.d/mysqld start (code=exited, status=0/SUCCESS) Main PID: 1943 CGroup: name=systemd:/system/mysqld.service dmesg has this to say about mysql: [ 48.374889] systemd[1]: Trying to enqueue job mysqld.service/start/replace [ 48.375172] systemd[1]: Installed new job mysqld.service/start as 937 [ 48.375180] systemd[1]: Enqueued job mysqld.service/start as 937 [ 48.375665] systemd[1]: About to execute: /etc/rc.d/init.d/mysqld start [ 48.397532] systemd[1]: Forked /etc/rc.d/init.d/mysqld as 1708 [ 48.397574] systemd[1]: mysqld.service changed dead -> start [ 48.397926] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Properties.Get() on /org/freedesktop/systemd1/unit/mysqld_2eservice [ 50.797472] systemd[1]: Received SIGCHLD from PID 1708 (mysqld). [ 50.811571] systemd[1]: Got SIGCHLD for process 1708 (mysqld) [ 50.811649] systemd[1]: Child 1708 belongs to mysqld.service [ 50.811657] systemd[1]: mysqld.service: control process exited, code=exited status=0 [ 50.811661] systemd[1]: mysqld.service got final SIGCHLD for state start [ 50.812925] systemd[1]: mysqld.service: Supervising process 1943 which is not our child. We'll most likely not notice when it exits. [ 50.813277] systemd[1]: mysqld.service changed start -> running [ 50.813288] systemd[1]: Job mysqld.service/start finished, result=done [ 117.953131] systemd[1]: Failed to load configuration for mysql.service: No such file or directory [ 117.953342] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Properties.GetAll() on /org/freedesktop/systemd1/unit/mysql_2eservice [ 120.557064] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Properties.GetAll() on /org/freedesktop/systemd1/unit/mysqld_2eservice [ 127.551008] systemd[1]: Installed new job mysqld.service/stop as 1118 [ 130.387791] systemd[1]: About to execute: /etc/rc.d/init.d/mysqld stop [ 130.419169] systemd[1]: Forked /etc/rc.d/init.d/mysqld as 2056 [ 130.419237] systemd[1]: mysqld.service changed running -> stop [ 131.367790] systemd[1]: Received SIGCHLD from PID 1747 (mysqld_safe). [ 131.368782] systemd[1]: Got SIGCHLD for process 1747 (mysqld_safe) [ 131.466527] systemd[1]: Received SIGCHLD from PID 2056 (mysqld). [ 131.466573] systemd[1]: Got SIGCHLD for process 2056 (mysqld) [ 131.466647] systemd[1]: Child 2056 belongs to mysqld.service [ 131.466658] systemd[1]: mysqld.service: control process exited, code=exited status=0 [ 131.466666] systemd[1]: mysqld.service got final SIGCHLD for state stop [ 131.466687] systemd[1]: mysqld.service changed stop -> stop-sigterm [ 131.471123] systemd[1]: mysqld.service: cgroup is empty I wonder what this really means: Supervising process 1943 which is not our child. We'll most likely not notice when it exits.
Created attachment 495291 [details] dmesg with default shutdown settings in kdm Yes, I'm sorry. I've changed this options and attach new dmesg. I've get dmesg only over ssh.
Instead of shutting down, to reproduce the problem it is sufficient to try to stop the running mysqld.service. It will go into the stop-sigterm state and stay there forever, with no processes in the cgroup.
I can confirm this, too.
*** Bug 700173 has been marked as a duplicate of this bug. ***
Regarding: "Supervising process 1943 which is not our child. We'll most likely not notice when it exits." So, MySQL puts a PID in the PID file that is not a child of init. That means if it dies systemd will not get a SIGCHLD for it and thus not detect that it is gone. Normally that shouldn't hurt much though, because we also get a notification when the cgroup becomes empty. That means we won't be be able to collect exit status and stuff, but we will still notice when mysql is gone. That's the theory at least, alas it doesn't seem to work. Michal, thanks for tracking this down, I'll try to reproduce this here, too.
Fixed in git.
Thanks a lot for this fix and for the debugging, Michal and Lennart. Is there an easy way to incorporate this patch into the package? Are you perhaps going to release a new version soon? Is it better to patch the 25-1 package or even use the git-master for a new package.
Lennart, Michal thanks for fix.
*** Bug 700341 has been marked as a duplicate of this bug. ***
Great that you manage to track down the root of the problem. I hope that systemd v26 will be available soon. [192548.839883] systemd[1]: Reloading. [192549.222885] systemd[1]: mysqld.service: Supervising process 999 which is not our child. We'll most likely not notice when it exits. :) (In reply to comment #13) > (In reply to comment #12) > > Did you reload systemd with "systemctl daemon-reload"? > > No, I had to add systemd.log_level=* to grub config and I rebooted system - > should be enough I guess :) > > Maybe I need to enable something in /etc/systemd/system.conf ? CrashShell? Any tips for the future how to run this shell?
systemd-26-1.fc15 has been submitted as an update for Fedora 15. https://admin.fedoraproject.org/updates/systemd-26-1.fc15
This bug is fixed in new packages. Really many thanks. P.S. I've added karma in bodhi.
Thanks! Best regards, Michal
systemd-26-1.fc15 has been pushed to the Fedora 15 stable repository. If problems still persist, please make note of it in this bug report.
i can start and stop mysqld from the init script but i am getting lots of these error messages. Jun 20 16:24:00 host01 systemd[1]: mysqld.service: Supervising process 1357 which is not our child. We'll most likely not notice when it exits. Jun 20 16:26:33 host01 systemd[1]: mysqld.service: Supervising process 1954 which is not our child. We'll most likely not notice when it exits. Jun 20 16:31:05 host01 systemd[1]: mysqld.service: Supervising process 2285 which is not our child. We'll most likely not notice when it exits. $ ps axu | egrep 1357\|1954\|2285 mysql 2285 0.1 2.0 486140 41416 ? Sl 16:31 0:01 /usr/libexec/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysqld.log --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/lib/mysql/mysql.sock 501 2356 0.0 0.0 106308 784 pts/0 S+ 16:51 0:00 egrep --color=auto 1357|1954|2285