Bug 973331

Hi Dean, please follow http://freedesktop.org/wiki/Software/systemd/Debugging/ to diagnose which service actually blocks.

Following the instructions I have waited 10 minutes and I can not get a command prompt.  From the Virtual Machine Manager window for the IPA server, if I select View, Text Consoles, Serial 1 then I get a blinking block cursor in the upper left hand corner.  If, instead, I select Send Key, Ctrl+Alt+F2 then I get a blinking underscore cursor. Neither display will prompt nor respond to the Enter key.  The display also will not respond to a Crtl+Alt+Delete.

I am sorry, but I do not know how to edit the kernel command line as the next step requests.

OK! I think I got to the kernel command line by typing e while the grub2 menu was displayed.  I added "emergency" and selected f10.  It booted to a prompt and I used "journalctl -bx" to review the systemd journal.  I saw no obvious errors aside from 10 AVCs.  From the prompt I was able to reboot successfully.  Now the system will boot, but it will not shutdown!

Selecting the previous version of the kernel from the GRUB menu allows start up and shut down to behave as expected.

Current version:  3.9.4-301.fc19.x86_64
Previous version: 3.9.2-301.fc19.x86_64

Using the instructions for debugging systemd problems, I executed this sequence:

  systemctl enable debug-shell.service
  reboot
  ...
  yum install --assumeyes bind bind-dyndb-ldap freeipa-server

  cat >/etc/hosts <<EOD
127.0.0.1        localhost.localdomain  localhost
192.168.1.11     ipa.hunter.org         ipa
EOD

  ipa-server-install \\
    --admin-password adminpassword \\
    --domain hunter.org \\
    --ds-password dspassword \\
    --hostname ipa.hunter.org \\
    --idstart 128000000 \\
    --no-forwarders \\
    --realm HUNTER.ORG \\
    --setup-dns \\
    --ssh-trust-dns \\
    --unattended

  firewall-cmd --permanent --zone public --add-service dns
  firewall-cmd --permanent --zone public --add-service http
  firewall-cmd --permanent --zone public --add-service https
  firewall-cmd --permanent --zone public --add-service kerberos
  firewall-cmd --permanent --zone public --add-service kpasswd
  firewall-cmd --permanent --zone public --add-service ldap
  firewall-cmd --permanent --zone public --add-service ldaps
  firewall-cmd --reload
  firewall-cmd --list-all

  echo adminpassword | kinit admin

  ipa config-mod --defaultshell=/bin/bash 

  ipa host-add host.hunter.org \\
    --force \\
    --ip-address=192.168.1.10

  echo first | ipa user-add dean \\
    --first=Dean \\
    --last=Hunter \\
    --password \\
    --uid=128000001

  ipa automountkey-add default auto.direct \\
    --key /mnt/Shared \\
    --info '-fstype=nfs4,sec=krb5p host.hunter.org:/srv/nfs/Shared'

  ipa automountlocation-add VM

  ipa automountkey-add VM auto.direct \\
    --key /mnt/Shared \\
    --info '-fstype=nfs4,sec=krb5p host.hunter.org:/srv/nfs/Shared'

  ipa automountmap-add-indirect VM auto.home \\
    --mount /home
 
  ipa automountkey-add VM auto.home \\
    --key '*' \\
    --info '-fstype=nfs4,sec=krb5p host.hunter.org:/srv/nfs/home/&'

  kdestroy

  reboot

Using:

  systemctl list-jobs

at the debug shell prompt I can see that the ipa.service stop job is running, never finishes, and 41 other jobs are waiting for it.

[root@ipa /]# ps -ef | grep ipa
root      4953     1  0 16:48 ?        00:00:01 /usr/bin/python /usr/sbin/ipactl stop
root      5089  4953  0 16:48 ?        00:00:00 /bin/systemctl stop ipa-otpd.socket

[root@ipa /]#

Lukas or Michal, can you please advise how should we continue with debugging? It seems like "/bin/systemctl stop ipa-otpd.socket" is stuck.

This is how the ipa-otpd.socket is configured:

# cat /usr/lib/systemd/system/ipa-otpd.socket
[Unit]
Description=ipa-otpd socket

[Socket]
ListenStream=/var/kerberos/krb5kdc/DEFAULT.socket
ExecStopPre=/usr/bin/unlink /var/kerberos/krb5kdc/DEFAULT.socket
SocketMode=0600
Accept=true

[Install]
WantedBy=krb5kdc.service

Well, we will need more information to figure out what is wrong. Please provide some logs, preferably with systemd_log.level=debug. Please use how to article on systemd debugging [1]. It would be great to see the difference between 3.9.4 and 3.9.2 kernels. 


[1] http://freedesktop.org/wiki/Software/systemd/Debugging/

I hope I did this correctly:

1) Requested a reboot from the graphical console

2) Ctrl+Alt+F9 and killed the "/bin/systemctl stop ipa-otpd.socket" process

3) Used the grub menu to edit the line that starts with:

   linux   /vmlinuz-....

   and appended:

   systemd.log_level=debug systemd.log_target=kmsg log_buf_len=1M

4) Waited for the boot to complete and the CPU activity to reach its idle state

5) Requested a reboot from the graphical console

6) Ctrl+Alt+F9, "dmesg >dmesg.txt", and killed the "/bin/systemctl stop ipa-otpd.socket" process

7) Waited for the boot to complete

8) scp'ed /dmesg.txt

I am sorry, but since the rebuild of comment 5 the problem occurs on both the current and previous versions of the kernel.

Created attachment 760200 [details]
dmesg.txt

Michal, did the information that Dean provided help?

ipa.service should include ordering dependency After= on all of its dependencies. When stopping services, ipactl should call systemctl using --no-block option in order to remedy deadlock during shutdown transaction.

Thanks for cooperation Michal, I will create an upstream ticket to fix it.

Upstream ticket:
https://fedorahosted.org/freeipa/ticket/3729

To work around the problem, stop IPA before rebooting:

  systemctl stop ipa.service

Thanks for the workaround.

Note that there is already a patch submitted upstream and ideally we would to have this issue fixed with next bugfixing update for Fedora 19.

Fixed upstream:

master: fb166e8f5c0a959f0f1dd9ceb5d9cc8ddd3e7ef6
ipa-3-2: f99bbb97e71cec50754c756d06a905cb879fdf4d

Yay!

freeipa-3.2.2-1.fc19 has been submitted as an update for Fedora 19.
https://admin.fedoraproject.org/updates/freeipa-3.2.2-1.fc19

Package freeipa-3.2.2-1.fc19:
* should fix your issue,
* was pushed to the Fedora 19 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing freeipa-3.2.2-1.fc19'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2013-13224/freeipa-3.2.2-1.fc19
then log in and leave karma (feedback).

Correction verified and karma updated.

However, now none of the NFS services are starting:

[root@ipa19 ~]# systemctl list-units | grep nfs
[root@ipa19 ~]# systemctl start nfs-server.service
[root@ipa19 ~]# systemctl start nfs-secure-server.service
[root@ipa19 ~]# systemctl start nfs-secure.service
[root@ipa19 ~]# systemctl list-units | grep nfs
proc-fs-nfsd.mount          loaded active mounted   RPC Pipe File System
nfs-idmap.service           loaded active running   NFSv4 ID-name mapping daemon
nfs-mountd.service          loaded active running   NFS Mount Daemon
nfs-rquotad.service         loaded active running   NFS Remote Quota Server
nfs-secure-server.service   loaded active running   Secure NFS Server
nfs-secure.service          loaded active running   Secure NFS
nfs-server.service          loaded active exited    NFS Server
[root@ipa19 ~]# 

And there has never been any response to 972363.

Thanks for verification! I am really not sure why there is no response in Bug 972363 - I tried to bring this Bug to attention via other channels.

Reading the unit files shows that the NFS server should be enabled via nfs.target rather than via nfs-server.service and nfs-lock.service as I had previously learned.  However, I believe there is still an error with the NFS secure client as described in Bug 972363.

I know NFS is off the subject of this bug report, but I wanted to let y'all know because I only use NFS through IPA auto mount.

Thank you to the team for the fixes.  Now I can begin upgrading my network to Fedora 19.

freeipa-3.2.2-1.fc19 has been pushed to the Fedora 19 stable repository.  If problems still persist, please make note of it in this bug report.