After retries, use netlink data even if the dump is still interrupted by robmry · Pull Request #48598 · moby/moby

robmry · 2024-10-07T17:41:03Z

- What I did

fix networking: investigate EINTR regression after updating github.com/vishvananda/netlink to v1.3.0 #48400

Before version 1.2.1, the vishvananda/netlink package ignored NLM_F_DUMP_INTR in netlink responses. In 1.2.1, it started to return EINTR and no data in that case.

#48407 wrapped affected netlink calls in the nlwrap package. So, there would be up-to 5 attempts to make a request, get EINTR, and retry. After 5 attempts, the EINTR was returned and the caller would handle the failure.

Now, the netlink package returns data along with netlink.ErrDumpInterrupted in this case.

So, after 5 attempts, the nlwrap functions now discard the error and return the last set of data they got - which may be incomplete or inconsistent. But, this matches the behaviour of vishvananda/netlink prior to version 1.2.1, in which the NLM_F_DUMP_INTR flag was ignored.

If this ever happens, a stack trace will be logged.

- How I did it

Pick up the visvananda/netlink package at its current-latest commit, which:
- fixes timeouts, and
- returns data along with netlink.ErrDumpInterrupted when it encounters an NLM_F_DUMP_INTR error (rather than discarding results and returning EINTR).
- Full diff: vishvananda/netlink@v1.3.0...084abd9
Fix godoc comments in the nlwrap package.
In nlwrap, after maxRetries, discard ErrDumpInterrupted, log a stack trace, and return data.

- How to verify it

Not tested directly, but after temporarily changing the nlh.AddrList wrapper to:

--- a/internal/nlwrap/nlwrap_linux.go
+++ b/internal/nlwrap/nlwrap_linux.go
@@ -82,6 +82,7 @@ func discardErrDumpInterrupted(err error) error {
 func (nlh Handle) AddrList(link netlink.Link, family int) (addrs []netlink.Addr, err error) {
        retryOnIntr(func() error {
                addrs, err = nlh.Handle.AddrList(link, family) //nolint:forbidigo
+               err = netlink.ErrDumpInterrupted
                return err
        })
        return addrs, discardErrDumpInterrupted(err)
 }

... checked that daemon startup continued normally, with log messages like this:

INFO[2024-10-07T13:00:44.099150679Z] netlink call interrupted after 5 attempts
WARN[2024-10-07T13:00:44.099197470Z] discarding ErrDumpInterrupted: results may be incomplete or inconsistent
github.com/docker/docker/internal/nlwrap.discardErrDumpInterrupted
	/go/src/github.com/docker/docker/internal/nlwrap/nlwrap_linux.go:75
github.com/docker/docker/internal/nlwrap.Handle.AddrList
	/go/src/github.com/docker/docker/internal/nlwrap/nlwrap_linux.go:88
github.com/docker/docker/daemon.ifaceAddrs.func1
	/go/src/github.com/docker/docker/daemon/daemon_linux.go:166
github.com/docker/docker/daemon.ifaceAddrs
	/go/src/github.com/docker/docker/daemon/daemon_linux.go:178
github.com/docker/docker/daemon.initBridgeDriver
	/go/src/github.com/docker/docker/daemon/daemon_unix.go:949
github.com/docker/docker/daemon.configureNetworking
	/go/src/github.com/docker/docker/daemon/daemon_unix.go:886
github.com/docker/docker/daemon.(*Daemon).initNetworkController
	/go/src/github.com/docker/docker/daemon/daemon_unix.go:850
github.com/docker/docker/daemon.(*Daemon).restore
	/go/src/github.com/docker/docker/daemon/daemon.go:580
github.com/docker/docker/daemon.NewDaemon
	/go/src/github.com/docker/docker/daemon/daemon.go:1241
main.(*daemonCLI).start
	/go/src/github.com/docker/docker/cmd/dockerd/daemon.go:257
main.runDaemon
	/go/src/github.com/docker/docker/cmd/dockerd/docker_unix.go:13
main.newDaemonCommand.func1
	/go/src/github.com/docker/docker/cmd/dockerd/docker.go:49
github.com/spf13/cobra.(*Command).execute
	/go/src/github.com/docker/docker/vendor/github.com/spf13/cobra/command.go:985
github.com/spf13/cobra.(*Command).ExecuteC
	/go/src/github.com/docker/docker/vendor/github.com/spf13/cobra/command.go:1117
github.com/spf13/cobra.(*Command).Execute
	/go/src/github.com/docker/docker/vendor/github.com/spf13/cobra/command.go:1041
github.com/spf13/cobra.(*Command).ExecuteContext
	/go/src/github.com/docker/docker/vendor/github.com/spf13/cobra/command.go:1034
main.main
	/go/src/github.com/docker/docker/cmd/dockerd/docker.go:113
runtime.main
	/usr/local/go/src/runtime/proc.go:271
runtime.goexit
	/usr/local/go/src/runtime/asm_arm64.s:1222

- Description for the changelog

n/a

…93d350 Particularly for: - Preserve results when NLM_F_DUMP_INTR is set (1018). - Fix SetSendTimeout/SetReceiveTimeout (1012). full diff: vishvananda/netlink@v1.3.0...084abd9 Signed-off-by: Rob Murray <[email protected]>

Signed-off-by: Rob Murray <[email protected]>

akerouanton · 2024-10-08T18:20:18Z

internal/nlwrap/nlwrap_linux.go

+		// error. Discard the error and return the data. This restores the behaviour of
+		// the netlink package prior to v1.2.1, in which NLM_F_DUMP_INTR was ignored in
+		// the netlink response.
+		log.G(context.TODO()).Warnf("discarding ErrDumpInterrupted: %+v", perrors.WithStack(err))


Wondering if the stack trace really needs to be logged as a Warning. Since this was the old behavior, I think we'd know by now if it was really causing any issue. I'd rather log that with debug level.

Maybe we wouldn't know though - "sometimes on my host" issues might have been written off as "can't repro"?

I think it's unlikely we'll see failures after five retries. But, if we do, it's probably something we want to know about. And, without a stack trace, there's no way to work out whether the error relates to any observed misbehaviour.

So, I think it's worth keeping the stack trace at (at-least) info level - at least for 28.x, in case there is an issue in the real world?

Fine, let's keep it as a Warning then.

Do we need a tracking issue for updating it after 28.0?

I don't think so ... either we'll see lots of errors with stack traces or, I think more likely, we won't see any.

If we don't see any, might as well leave it in - in case an environment where it's a problem crops up. If we do see the error happening a lot, it'll need addressing anyway.

thaJeztah · 2024-10-08T20:14:37Z

vendor.mod

 	github.com/tonistiigi/go-archvariant v1.0.0
 	github.com/vbatts/tar-split v0.11.5
-	github.com/vishvananda/netlink v1.3.0
+	github.com/vishvananda/netlink v1.3.1-0.20240922070040-084abd93d350


Did we have any pending PRs still in nettlink?

Otherwise I want to give it a try as well to see if they're willing to tag a new release.

Nothing pending. So, yes, it's probably worth asking.

I left a comment on your last merged PR 🤞

No response yet ... shall we merge this to get tests running with it, and before it rots - then update the release tag when one's available?

thaJeztah

LGTM

one minor suggestion, but no blocker if you want this merged

thaJeztah · 2024-10-14T20:06:27Z

internal/nlwrap/nlwrap_linux.go

 	"errors"

 	"github.com/containerd/log"
+	perrors "github.com/pkg/errors"


We could also swap out one for the other, instead of importing both (looks like it's only using 'errors.Is' which I think is an alias in pkg/errors)

thaJeztah · 2024-10-14T20:06:55Z

internal/nlwrap/nlwrap_linux.go

+		// error. Discard the error and return the data. This restores the behaviour of
+		// the netlink package prior to v1.2.1, in which NLM_F_DUMP_INTR was ignored in
+		// the netlink response.
+		log.G(context.TODO()).Warnf("discarding ErrDumpInterrupted: %+v", perrors.WithStack(err))


Do we need a tracking issue for updating it after 28.0?

Returning possibly inconsistent data avoids retrying indefinitely, and matches the behaviour of vishvananda/netlink prior to version 1.2.1, in which the NLM_F_DUMP_INTR flag was ignored. Signed-off-by: Rob Murray <[email protected]>

thaJeztah

LGTM, thanks!

thaJeztah · 2024-10-15T12:57:02Z

internal/nlwrap/nlwrap_linux.go

-// The wrapped functions currently return EINTR when NLM_F_DUMP_INTR flagged
-// in a netlink response, meaning something changed during the dump so results
-// may be incomplete or inconsistent.
+// When netlink.ErrDumpInterrupted is returned, the wrapped functions retry up to


Oh! Definitely not an issue, but if you put these things in square brackets, then pkg.go.dev will use them as docs-links, i.e.

Suggested change

// When netlink.ErrDumpInterrupted is returned, the wrapped functions retry up to

// When [netlink.ErrDumpInterrupted] is returned, the wrapped functions retry up to

Will make netlink.ErrDumpInterrupted a clickable link to the pkg.go.dev documentation of netlink (which is pretty neat).

(Custom reference links are also supported)

robmry added 2 commits October 7, 2024 18:32

Fix comments

2f02f45

Signed-off-by: Rob Murray <[email protected]>

robmry added area/networking Networking kind/bugfix PR's that fix bugs labels Oct 7, 2024

robmry added this to the 28.0.0 milestone Oct 7, 2024

robmry self-assigned this Oct 7, 2024

robmry marked this pull request as ready for review October 8, 2024 08:04

robmry requested review from akerouanton and thaJeztah October 8, 2024 08:04

akerouanton reviewed Oct 8, 2024

View reviewed changes

thaJeztah reviewed Oct 8, 2024

View reviewed changes

akerouanton approved these changes Oct 9, 2024

View reviewed changes

thaJeztah approved these changes Oct 14, 2024

View reviewed changes

robmry force-pushed the netlink_dump_interrupted branch from 5bd1d1b to a0a0bba Compare October 15, 2024 10:36

thaJeztah approved these changes Oct 15, 2024

View reviewed changes

thaJeztah merged commit 2c68149 into moby:master Oct 15, 2024

robmry deleted the netlink_dump_interrupted branch October 15, 2024 13:44

This was referenced Nov 25, 2024

vendor: github.com/vishvananda/netlink v1.3.0 #48368

Merged

[27.x backport] vendor: vendor: github.com/vishvananda/netlink v1.3.x (084abd93d) and fix compatibility #48938

Merged

thaJeztah added the process/cherry-picked label Dec 19, 2024

robmry mentioned this pull request Jan 24, 2025

netlink walk calls may return EINTR (regression) containernetworking/plugins#1121

Closed

taylorsilva mentioned this pull request Jan 28, 2025

containerd task execution sometimes fails with EINTR - interrupted system call concourse/concourse#9027

Closed

	// When netlink.ErrDumpInterrupted is returned, the wrapped functions retry up to
	// When [netlink.ErrDumpInterrupted] is returned, the wrapped functions retry up to

Conversation

robmry commented Oct 7, 2024

Uh oh!

Choose a reason for hiding this comment

Uh oh!

robmry Oct 8, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

thaJeztah left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

thaJeztah left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

robmry Oct 8, 2024 •

edited

Loading