Bug 1381743

Summary: In RHEL7, systemd-notify --ready fails, but directly using NOTIFY_SOCKET works (& both work in Fedora24)
Product: Red Hat Enterprise Linux 7 Reporter: Ryan Sawhill <rsawhill>
Component: systemdAssignee: systemd-maint
Status: CLOSED ERRATA QA Contact: Frantisek Sumsal <fsumsal>
Severity: medium Docs Contact:
Priority: medium    
Version: 7.3CC: bblaskov, fsumsal, jsynacek, rmetrich, rsawhill, systemd-maint-list
Target Milestone: rcKeywords: Reopened
Target Release: ---   
Hardware: Unspecified   
OS: Linux   
Whiteboard:
Fixed In Version: systemd-219-40.el7 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2017-08-01 09:09:52 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Ryan Sawhill 2016-10-04 21:21:08 UTC
DESCRIPTION OF PROBLEM:

  When building a simple Type=notify service, using python to write directly to the sd_notify socket works; however, using the systemd-notify wrapper command to send READY=1 fails. 


VERSION-RELEASE NUMBER OF SELECTED COMPONENT (IF APPLICABLE):

  [root@r73beta ~]# rpm -qa systemd\*
  systemd-219-26.el7.x86_64
  systemd-sysv-219-26.el7.x86_64
  systemd-libs-219-26.el7.x86_64
  systemd-python-219-26.el7.x86_64

  I tested this on both RHEL 7.2 and RHEL 7.3beta.
  
  
HOW REPRODUCIBLE:

  100%
  
  
STEPS TO REPRODUCE:

1. Create service unit

  [root@r73beta ~]# cat /etc/systemd/system/zz.service
  [Unit]
  Description=Test that systemd-notify works

  [Service]
  Type=notify
  ExecStart=/usr/local/sbin/zz.sh
  TimeoutStartSec=1
  StartLimitInterval=0
  NotifyAccess=all

  [Install]
  WantedBy=multi-user.target

2. Create ExecStart script

  [root@r73beta ~]# cat /usr/local/sbin/zz.sh
  #!/bin/bash
  systemd-notify --status="zz service up and running"
  systemd-notify --ready
  sleep 9d
  
  [root@r73beta ~]# chmod +x /usr/local/sbin/zz.sh

3. Reload daemon and try to start

  [root@r73beta ~]# systemctl daemon-reload
  [root@r73beta ~]# systemctl start zz
  Job for zz.service failed because a timeout was exceeded. See "systemctl status zz.service" and "journalctl -xe" for details.
  [root@r73beta ~]# while :; do systemctl restart zz &>/dev/null && printf . || printf X; done
  XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX^C


ADDITIONAL INFO:

* The short TimeoutStartSec=1 is just to make testing easier. This is an unloaded system so it's not like the message queue is getting backed up. It still doesn't work if I wait for 20s every time.

* Using "systemd-notify READY=1" instead of --ready makes no difference.

* The same test always succeeds in Fedora 24 with systemd-229-15.fc24 (though I have to move StartLimitInterval=0 to the [Unit] section of course).

* Using python to talk directly to the socket, all is well:

  [root@r73beta ~]# sed -i '/ExecStart/s/sh/py/' /etc/systemd/system/zz.service
  [root@r73beta ~]# systemctl daemon-reload
  [root@r73beta ~]# cat /usr/local/sbin/zz.py 
  #!/bin/python2
  import socket
  from os import getenv
  from time import sleep
  s = socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM)
  e = getenv('NOTIFY_SOCKET')
  s.connect(e)
  s.sendall("READY=1")
  s.close()
  sleep(900)
  [root@r73beta ~]# chmod +x /usr/local/sbin/zz.py
  [root@r73beta ~]# systemctl start zz
  [root@r73beta ~]# while :; do systemctl restart zz &>/dev/null && printf . || printf X; done
  .............................................................................^C

Comment 1 Ryan Sawhill 2016-10-04 21:49:30 UTC
One final data point: if I copy /usr/bin/systemd-notify from F24 (again, systemd-229-15.fc24) to RHEL 7.3 and use that, it works.

Comment 2 Jan Synacek 2016-10-18 08:31:53 UTC
I can't reproduce this with systemd-219-30.el7. Could you please verify?

Comment 3 Jan Synacek 2017-05-05 13:05:13 UTC
I'm considering this fixed as per comment 1.

Comment 4 Jan Synacek 2017-05-05 13:05:30 UTC
... per comment 2, I mean.

Comment 5 Ryan Sawhill 2017-05-25 18:21:48 UTC
(In reply to Jan Synacek from comment #2)
> I can't reproduce this with systemd-219-30.el7. Could you please verify?

Uhh what??

Yes if I follow the exact steps from description I can still reproduce. I just tried:

- fresh rhel 7.3 (systemd-219-30.el7)
- updated rhel 7.3 (systemd-219-30.el7_3.9)
- fresh rhel 7.4beta (systemd-219-39.el7)

Everything behaves the same as how I described back on 2016-10-04. `systemd-notify --ready` doesn't work, but writing READY=1 to socket from python works fine.

Comment 6 Lukáš Nykrýn 2017-05-29 11:05:10 UTC
I think that I found the culprit, systemd in upstream adds PPID to every message, ours does not do that. If systemd does not get it, it tries to find the unit from which the message was send, but that is extremely racy.

https://github.com/lnykryn/systemd-rhel/pull/124

Comment 8 Frantisek Sumsal 2017-05-30 10:40:21 UTC
qa_ack+ for RHEL 7.4

Comment 12 errata-xmlrpc 2017-08-01 09:09:52 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2017:2297