Repository: opencontainers/runc
Pull request #3291 (2021-11-22 09:15:42)

notify_socket.go: use sd_notify_barrier mechanism
Add synchronization to how runc reports container readiness to systemd.

It was previously possible for runc to terminate  immediately after sending the READY signal. This was sometimes too quick for systemd to find out the sender's cgroup. As a consequence, systemd would ignore the READY signal.

Fixes: #3293

kolyshkin: Overall this looks good to me. Is there any way to have a test for this @indyjo ?
indyjo: What I can imagine is to write a test against a mocked NOTIFY_SOCKET server, i.e. a mocked systemd. Concerning how to do it I think I need some guidance. I could try adding a `notify_socket_test.go` alongside  `notify_socket.go`. I also noticed there are "bats tests" in `tests/integration`, but I'm completely unfamiliar with that framework. What do you think would be a good approach?

Also, my code is currently assuming that whoever listens on the other end of NOTIFY_SOCKET actually understands and honors the `BARRIER=1` protocol. This is certainly the case with recent systemd versions (the feature seems to be about two years old). Other implementations might not. For example, [sdnotify-proxy](https://github.com/coreos/sdnotify-proxy) is too simple. Currently, this would lead to `runc` running into the 5 second timeout and failing to start a container.

Is this behavior a) accepted or should I b) ignore the timeout case or should there be c) a command-line option to suppress the sd_notify_barrier feature?
indyjo: I have added a test (notify_socket_test.go). The question of how to deal with sd_notify_barrier timeouts is still open. `crun` waits for 30 seconds and then ignores the error ([see PR](https://github.com/containers/crun/pull/791)). `systemd-notify` waits for 5 seconds and then fails ([source](https://github.com/systemd/systemd/blob/e6f48be8d4432924028ca0d5ee5289626a2fd7bb/src/notify/notify.c#L277)).
kolyshkin: > * reverse the order of commits (first remove bytes.Buffer usage, then add your changes)

I'm asking for this because it makes the git log -p smaller (and, consequently, it will be easier to figure out what was changed, especially a few years from now).
indyjo: Thanks for clarifying, @kolyshkin! The two commits are now in the preferred order. 

Should we discuss how to handle the case where the supervising process doesn't (correctly) handle the `sd_notify_barrier` mechanism and `runc` fails with a timeout? I'm leaning towards simply doing what `crun` does, although the 30s timeout seems extreme.
kolyshkin: > I'm leaning towards simply doing what `crun` does

I tend to agree.

> although the 30s timeout seems extreme.

I guess on an overloaded system 5s might not be enough, so the timeout should be way above the reasonable expected reply time.

But let's ask @giuseppe -- why you ended up with 30s timeout?
giuseppe: > But let's ask @giuseppe -- why you ended up with 30s timeout?

I've copied the timeout you set here: https://github.com/opencontainers/runc/blob/master/libcontainer/cgroups/systemd/common.go#L345  :smile: 

Although I've decided to ignore any error, so it is equivalent to the version without `sd_notify_barrier` where it would not raise an error and because I am not sure as well what a correct value would be for the timeout
indyjo: Committed the proposed solution (as a separate commit for your convenience, @kolyshkin). Wait 30s and warn but ignore on timeout. Just tell me and I'll merge the two commits into one.
kolyshkin: LGTM @indyjo; please squash the last two commits and let's get it merged (after 1.1.0 I guess)
indyjo: Here you go, @kolyshkin, and happy new year!
kolyshkin: @AkihiroSuda PTAL
kolyshkin: @opencontainers/runc-maintainers PTAL
kolyshkin: @opencontainers/runc-maintainers @AkihiroSuda PTAL
MofX: Does it really make sense to implement the barrier-machanism inside of runc?
1. This will fail if systemd is too old (I guess this does not matter, because it only triggers a warning?)
2. For non-detached containers, if systemd-notify or any other binary, that uses sd_notify_barrier is used inside of the container it will fail, because the pipe and the barrier message is not relayed to systemd leading to a timeout in sd_notify_barrier.
3. For detached containers, sd_notify_barrier can or cannot timeout, depending on a race. If I don't miss anything, runc terminates, after it received the ready message (and relayed it to systemd). After the patch it will also do the barrier synchronization. A process using sd_notify_barrier will most likely work with this PR, if it is able to send the barrier message with it's own pipe fd before runc terminates. I think the recv from the socket with read (in contrast to recv) just closes open handles. But if runc terminates before it read the BUFFER message and the pipe fd, sd_notify_barrier will timeout. 
indyjo: Hi @MofX, let me give my point of view. And sorry about not answering fo so long.

First of all, whether this patch ends up in an official release or not is not absolutely critical for me. The company I work for, KUKA, maintains their own patched version of `runc`. We have made good experiences so far, but of course we only test a very limited scenario.

> 1. This will fail if systemd is too old (I guess this does not matter, because it only triggers a warning?)

Probably true. The protocol basically mandates the use of the barrier, though. There is no way for a client to query whether it's supported.

Concerning your point 2 and 3:

I don't know enough about `runc` to understand the implications of detached and detached containers. It is true, however, that `systemd-notify` inside a container can still fail. That's because this patch doesn't address the barrier mechanism between runc and the container, but between runc and its supervising process.

Actually, we never observed any _timeout_ happening in `systemd-notify`. The way `systemd-notify` may fail is that sometimes `runc` has already closed the connection directly after receiving the READY state, causing a "Connection refused" when `systemd-notify` tries to establish the barrier. We usually disable the barrier mechanism for this reason, when running `systemd-notify` in a container, using the `--no-block` option. That's a separate issue, though.
indyjo: @kolyshkin May I ask if there's a chance of including this in v1.1.2?
kolyshkin: > @kolyshkin May I ask if there's a chance of including this in v1.1.2?

The target milestone is set for 1.2.0 (which I hope will be released some time in the summer). We can definitely do a backport to 1.1.x once this is merged, and so it will also be included into latest 1.1.x (whatever that would be).

We need more reviews on this, @opencontainers/runc-maintainers PTAL 🙏🏻 
kolyshkin: @indyjo can you please rebase it (this will also re-run the CI on golang 1.18)?
indyjo: > @indyjo can you please rebase it (this will also re-run the CI on golang 1.18)?

@kolyshkin Technically, it's done. There's a failing check though: `ci / centos-7`.


indyjo: Friendly reminder that there's still a chance for this baby to be merged before its first birthday! 🎂
Is there anything I can help with? @kolyshkin @thaJeztah @cyphar @AkihiroSuda 
AkihiroSuda: The last rebase was 6 months ago, could you rebase again to ensure CI is still green? Thanks 

Patch:
diff --git a/notify_socket.go b/notify_socket.go
index 28c6c0ae..559340e5 100644
--- a/notify_socket.go
+++ b/notify_socket.go
@@ -2,6 +2,8 @@ package main
 
 import (
 	"bytes"
+	"errors"
+	"io"
 	"net"
 	"os"
 	"path"
@@ -11,7 +13,9 @@ import (
 
 	"github.com/opencontainers/runc/libcontainer"
 	"github.com/opencontainers/runtime-spec/specs-go"
+	"github.com/sirupsen/logrus"
 	"github.com/urfave/cli"
+	"golang.org/x/sys/unix"
 )
 
 type notifySocket struct {
@@ -141,29 +145,79 @@ func (n *notifySocket) run(pid1 int) error {
 				return nil
 			}
 		case b := <-fileChan:
-			var out bytes.Buffer
-			_, err = out.Write(b)
-			if err != nil {
-				return err
-			}
+			return notifyHost(client, b, pid1)
+		}
+	}
+}
 
-			_, err = out.Write([]byte{'\n'})
-			if err != nil {
-				return err
-			}
+// notifyHost tells the host (usually systemd) that the container reported READY.
+// Also sends MAINPID and BARRIER.
+func notifyHost(client *net.UnixConn, ready []byte, pid1 int) error {
+	_, err := client.Write(append(ready, '\n'))
+	if err != nil {
+		return err
+	}
 
-			_, err = client.Write(out.Bytes())
-			if err != nil {
-				return err
-			}
+	// now we can inform systemd to use pid1 as the pid to monitor
+	newPid := "MAINPID=" + strconv.Itoa(pid1)
+	_, err = client.Write([]byte(newPid + "\n"))
+	if err != nil {
+		return err
+	}
 
-			// now we can inform systemd to use pid1 as the pid to monitor
-			newPid := "MAINPID=" + strconv.Itoa(pid1)
-			_, err := client.Write([]byte(newPid + "\n"))
-			if err != nil {
-				return err
-			}
-			return nil
-		}
+	// wait for systemd to acknowledge the communication
+	return sdNotifyBarrier(client)
+}
+
+// errUnexpectedRead is reported when actual data was read from the pipe used
+// to synchronize with systemd. Usually, that pipe is only closed.
+var errUnexpectedRead = errors.New("unexpected read from synchronization pipe")
+
+// sdNotifyBarrier performs synchronization with systemd by means of the sd_notify_barrier protocol.
+func sdNotifyBarrier(client *net.UnixConn) error {
+	// Create a pipe for communicating with systemd daemon.
+	pipeR, pipeW, err := os.Pipe()
+	if err != nil {
+		return err
+	}
+
+	// Get the FD for the unix socket file to be able to do perform syscall.Sendmsg.
+	clientFd, err := client.File()
+	if err != nil {
+		return err
+	}
+
+	// Send the write end of the pipe along with a BARRIER=1 message.
+	fdRights := unix.UnixRights(int(pipeW.Fd()))
+	err = unix.Sendmsg(int(clientFd.Fd()), []byte("BARRIER=1"), fdRights, nil, 0)
+	if err != nil {
+		return &os.SyscallError{Syscall: "sendmsg", Err: err}
+	}
+
+	// Close our copy of pipeW.
+	err = pipeW.Close()
+	if err != nil {
+		return err
+	}
+
+	// Expect the read end of the pipe to be closed after 30 seconds.
+	err = pipeR.SetReadDeadline(time.Now().Add(30 * time.Second))
+	if err != nil {
+		return nil
+	}
+
+	// Read a single byte expecting EOF.
+	var buf [1]byte
+	n, err := pipeR.Read(buf[:])
+	if n != 0 || err == nil {
+		return errUnexpectedRead
+	} else if errors.Is(err, os.ErrDeadlineExceeded) {
+		// Probably the other end doesn't support the sd_notify_barrier protocol.
+		logrus.Warn("Timeout after waiting 30s for barrier. Ignored.")
+		return nil
+	} else if err == io.EOF { //nolint:errorlint // comparison with io.EOF is legit.
+		return nil
+	} else {
+		return err
 	}
 }


Test patch:
diff --git a/notify_socket_test.go b/notify_socket_test.go
new file mode 100644
index 00000000..81210851
--- /dev/null
+++ b/notify_socket_test.go
@@ -0,0 +1,120 @@
+package main
+
+import (
+	"bytes"
+	"io"
+	"net"
+	"testing"
+	"time"
+
+	"golang.org/x/sys/unix"
+)
+
+// TestNotifyHost tests how runc reports container readiness to the host (usually systemd).
+func TestNotifyHost(t *testing.T) {
+	addr := net.UnixAddr{
+		Name: t.TempDir() + "/testsocket",
+		Net:  "unixgram",
+	}
+
+	server, err := net.ListenUnixgram("unixgram", &addr)
+	if err != nil {
+		t.Fatal(err)
+	}
+	defer server.Close()
+
+	client, err := net.DialUnix("unixgram", nil, &addr)
+	if err != nil {
+		t.Fatal(err)
+	}
+	defer client.Close()
+
+	// run notifyHost in a separate goroutine
+	notifyHostChan := make(chan error)
+	go func() {
+		notifyHostChan <- notifyHost(client, []byte("READY=42"), 1337)
+	}()
+
+	// mock a host process listening for runc's notifications
+	expectRead(t, server, "READY=42\n")
+	expectRead(t, server, "MAINPID=1337\n")
+	expectBarrier(t, server, notifyHostChan)
+}
+
+func expectRead(t *testing.T, r io.Reader, expected string) {
+	var buf [1024]byte
+	n, err := r.Read(buf[:])
+	if err != nil {
+		t.Fatal(err)
+	}
+	if !bytes.Equal(buf[:n], []byte(expected)) {
+		t.Fatalf("Expected to read '%s' but runc sent '%s' instead", expected, buf[:n])
+	}
+}
+
+func expectBarrier(t *testing.T, conn *net.UnixConn, notifyHostChan <-chan error) {
+	var msg, oob [1024]byte
+	n, oobn, _, _, err := conn.ReadMsgUnix(msg[:], oob[:])
+	if err != nil {
+		t.Fatal("Failed to receive BARRIER message", err)
+	}
+	if !bytes.Equal(msg[:n], []byte("BARRIER=1")) {
+		t.Fatalf("Expected to receive 'BARRIER=1' but got '%s' instead.", msg[:n])
+	}
+
+	fd := mustExtractFd(t, oob[:oobn])
+
+	// Test whether notifyHost actually honors the barrier
+	timer := time.NewTimer(500 * time.Millisecond)
+	select {
+	case <-timer.C:
+		// this is the expected case
+		break
+	case <-notifyHostChan:
+		t.Fatal("runc has terminated before barrier was lifted")
+	}
+
+	// Lift the barrier
+	err = unix.Close(fd)
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	// Expect notifyHost to terminate now
+	err = <-notifyHostChan
+	if err != nil {
+		t.Fatal("notifyHost function returned with error", err)
+	}
+}
+
+func mustExtractFd(t *testing.T, buf []byte) int {
+	cmsgs, err := unix.ParseSocketControlMessage(buf)
+	if err != nil {
+		t.Fatal("Failed to parse control message", err)
+	}
+
+	fd := 0
+	seenScmRights := false
+	for _, cmsg := range cmsgs {
+		if cmsg.Header.Type != unix.SCM_RIGHTS {
+			continue
+		}
+		if seenScmRights {
+			t.Fatal("Expected to see exactly one SCM_RIGHTS message, but got a second one")
+		}
+		seenScmRights = true
+		fds, err := unix.ParseUnixRights(&cmsg)
+		if err != nil {
+			t.Fatal("Failed to parse SCM_RIGHTS message", err)
+		}
+		if len(fds) != 1 {
+			t.Fatal("Expected to read exactly one file descriptor, but got", len(fds))
+		}
+		fd = fds[0]
+	}
+	if !seenScmRights {
+		t.Fatal("Control messages didn't contain an SCM_RIGHTS message")
+	}
+
+	return fd
+}