diff --git a/integration/daemon/daemon_test.go b/integration/daemon/daemon_test.go index b6e00c81b9..f4565c9616 100644 --- a/integration/daemon/daemon_test.go +++ b/integration/daemon/daemon_test.go @@ -9,7 +9,6 @@ import ( "os/exec" "path/filepath" "runtime" - "strings" "syscall" "testing" @@ -22,6 +21,7 @@ import ( "gotest.tools/v3/assert" is "gotest.tools/v3/assert/cmp" "gotest.tools/v3/icmd" + "gotest.tools/v3/poll" "gotest.tools/v3/skip" ) @@ -169,27 +169,40 @@ func TestDaemonProxy(t *testing.T) { skip.If(t, runtime.GOOS == "windows", "cannot start multiple daemons on windows") skip.If(t, os.Getenv("DOCKER_ROOTLESS") != "", "cannot connect to localhost proxy in rootless environment") - var received string - proxyServer := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - received = r.Host - w.Header().Set("Content-Type", "application/json") - _, _ = w.Write([]byte("OK")) - })) - defer proxyServer.Close() + newProxy := func(rcvd *string, t *testing.T) *httptest.Server { + s := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + *rcvd = r.Host + w.Header().Set("Content-Type", "application/json") + _, _ = w.Write([]byte("OK")) + })) + t.Cleanup(s.Close) + return s + } const userPass = "myuser:mypassword@" // Configure proxy through env-vars t.Run("environment variables", func(t *testing.T) { - t.Setenv("HTTP_PROXY", proxyServer.URL) - t.Setenv("HTTPS_PROXY", proxyServer.URL) - t.Setenv("NO_PROXY", "example.com") + t.Parallel() - d := daemon.New(t) - c := d.NewClientT(t) - defer func() { _ = c.Close() }() ctx := context.Background() - d.Start(t) + var received string + proxyServer := newProxy(&received, t) + + d := daemon.New(t, daemon.WithEnvVars( + "HTTP_PROXY="+proxyServer.URL, + "HTTPS_PROXY="+proxyServer.URL, + "NO_PROXY=example.com", + )) + c := d.NewClientT(t) + + d.Start(t, "--iptables=false") + defer d.Stop(t) + + info := d.Info(t) + assert.Check(t, is.Equal(info.HTTPProxy, proxyServer.URL)) + assert.Check(t, is.Equal(info.HTTPSProxy, proxyServer.URL)) + assert.Check(t, is.Equal(info.NoProxy, "example.com")) _, err := c.ImagePull(ctx, "example.org:5000/some/image:latest", types.ImagePullOptions{}) assert.ErrorContains(t, err, "", "pulling should have failed") @@ -199,39 +212,49 @@ func TestDaemonProxy(t *testing.T) { _, err = c.ImagePull(ctx, "example.com/some/image:latest", types.ImagePullOptions{}) assert.ErrorContains(t, err, "", "pulling should have failed") assert.Equal(t, received, "example.org:5000", "should not have used proxy") - - info := d.Info(t) - assert.Equal(t, info.HTTPProxy, proxyServer.URL) - assert.Equal(t, info.HTTPSProxy, proxyServer.URL) - assert.Equal(t, info.NoProxy, "example.com") - d.Stop(t) }) // Configure proxy through command-line flags t.Run("command-line options", func(t *testing.T) { - t.Setenv("HTTP_PROXY", "http://"+userPass+"from-env-http.invalid") - t.Setenv("http_proxy", "http://"+userPass+"from-env-http.invalid") - t.Setenv("HTTPS_PROXY", "https://"+userPass+"myuser:mypassword@from-env-https.invalid") - t.Setenv("https_proxy", "https://"+userPass+"myuser:mypassword@from-env-https.invalid") - t.Setenv("NO_PROXY", "ignore.invalid") - t.Setenv("no_proxy", "ignore.invalid") + t.Parallel() - d := daemon.New(t) - d.Start(t, "--http-proxy", proxyServer.URL, "--https-proxy", proxyServer.URL, "--no-proxy", "example.com") + ctx := context.Background() + var received string + proxyServer := newProxy(&received, t) - logs, err := d.ReadLogFile() - assert.NilError(t, err) - assert.Assert(t, is.Contains(string(logs), "overriding existing proxy variable with value from configuration")) - for _, v := range []string{"http_proxy", "HTTP_PROXY", "https_proxy", "HTTPS_PROXY", "no_proxy", "NO_PROXY"} { - assert.Assert(t, is.Contains(string(logs), "name="+v)) - assert.Assert(t, !strings.Contains(string(logs), userPass), "logs should not contain the non-sanitized proxy URL: %s", string(logs)) - } + d := daemon.New(t, daemon.WithEnvVars( + "HTTP_PROXY="+"http://"+userPass+"from-env-http.invalid", + "http_proxy="+"http://"+userPass+"from-env-http.invalid", + "HTTPS_PROXY="+"https://"+userPass+"myuser:mypassword@from-env-https-invalid", + "https_proxy="+"https://"+userPass+"myuser:mypassword@from-env-https-invalid", + "NO_PROXY=ignore.invalid", + "no_proxy=ignore.invalid", + )) + d.Start(t, "--iptables=false", "--http-proxy", proxyServer.URL, "--https-proxy", proxyServer.URL, "--no-proxy", "example.com") + defer d.Stop(t) c := d.NewClientT(t) - defer func() { _ = c.Close() }() - ctx := context.Background() - _, err = c.ImagePull(ctx, "example.org:5001/some/image:latest", types.ImagePullOptions{}) + info := d.Info(t) + assert.Check(t, is.Equal(info.HTTPProxy, proxyServer.URL)) + assert.Check(t, is.Equal(info.HTTPSProxy, proxyServer.URL)) + assert.Check(t, is.Equal(info.NoProxy, "example.com")) + + ok, _ := d.ScanLogsT(ctx, t, daemon.ScanLogsMatchAll( + "overriding existing proxy variable with value from configuration", + "http_proxy", + "HTTP_PROXY", + "https_proxy", + "HTTPS_PROXY", + "no_proxy", + "NO_PROXY", + )) + assert.Assert(t, ok) + + ok, logs := d.ScanLogsT(ctx, t, daemon.ScanLogsMatchString(userPass)) + assert.Assert(t, !ok, "logs should not contain the non-sanitized proxy URL: %s", logs) + + _, err := c.ImagePull(ctx, "example.org:5001/some/image:latest", types.ImagePullOptions{}) assert.ErrorContains(t, err, "", "pulling should have failed") assert.Equal(t, received, "example.org:5001") @@ -239,44 +262,49 @@ func TestDaemonProxy(t *testing.T) { _, err = c.ImagePull(ctx, "example.com/some/image:latest", types.ImagePullOptions{}) assert.ErrorContains(t, err, "", "pulling should have failed") assert.Equal(t, received, "example.org:5001", "should not have used proxy") - - info := d.Info(t) - assert.Equal(t, info.HTTPProxy, proxyServer.URL) - assert.Equal(t, info.HTTPSProxy, proxyServer.URL) - assert.Equal(t, info.NoProxy, "example.com") - - d.Stop(t) }) // Configure proxy through configuration file t.Run("configuration file", func(t *testing.T) { - t.Setenv("HTTP_PROXY", "http://"+userPass+"from-env-http.invalid") - t.Setenv("http_proxy", "http://"+userPass+"from-env-http.invalid") - t.Setenv("HTTPS_PROXY", "https://"+userPass+"myuser:mypassword@from-env-https.invalid") - t.Setenv("https_proxy", "https://"+userPass+"myuser:mypassword@from-env-https.invalid") - t.Setenv("NO_PROXY", "ignore.invalid") - t.Setenv("no_proxy", "ignore.invalid") - - d := daemon.New(t) - c := d.NewClientT(t) - defer func() { _ = c.Close() }() + t.Parallel() ctx := context.Background() + var received string + proxyServer := newProxy(&received, t) + + d := daemon.New(t, daemon.WithEnvVars( + "HTTP_PROXY="+"http://"+userPass+"from-env-http.invalid", + "http_proxy="+"http://"+userPass+"from-env-http.invalid", + "HTTPS_PROXY="+"https://"+userPass+"myuser:mypassword@from-env-https-invalid", + "https_proxy="+"https://"+userPass+"myuser:mypassword@from-env-https-invalid", + "NO_PROXY=ignore.invalid", + "no_proxy=ignore.invalid", + )) + c := d.NewClientT(t) + configFile := filepath.Join(d.RootDir(), "daemon.json") configJSON := fmt.Sprintf(`{"proxies":{"http-proxy":%[1]q, "https-proxy": %[1]q, "no-proxy": "example.com"}}`, proxyServer.URL) assert.NilError(t, os.WriteFile(configFile, []byte(configJSON), 0644)) - d.Start(t, "--config-file", configFile) + d.Start(t, "--iptables=false", "--config-file", configFile) + defer d.Stop(t) - logs, err := d.ReadLogFile() - assert.NilError(t, err) - assert.Assert(t, is.Contains(string(logs), "overriding existing proxy variable with value from configuration")) - for _, v := range []string{"http_proxy", "HTTP_PROXY", "https_proxy", "HTTPS_PROXY", "no_proxy", "NO_PROXY"} { - assert.Assert(t, is.Contains(string(logs), "name="+v)) - assert.Assert(t, !strings.Contains(string(logs), userPass), "logs should not contain the non-sanitized proxy URL: %s", string(logs)) - } + info := d.Info(t) + assert.Check(t, is.Equal(info.HTTPProxy, proxyServer.URL)) + assert.Check(t, is.Equal(info.HTTPSProxy, proxyServer.URL)) + assert.Check(t, is.Equal(info.NoProxy, "example.com")) - _, err = c.ImagePull(ctx, "example.org:5002/some/image:latest", types.ImagePullOptions{}) + d.ScanLogsT(ctx, t, daemon.ScanLogsMatchAll( + "overriding existing proxy variable with value from configuration", + "http_proxy", + "HTTP_PROXY", + "https_proxy", + "HTTPS_PROXY", + "no_proxy", + "NO_PROXY", + )) + + _, err := c.ImagePull(ctx, "example.org:5002/some/image:latest", types.ImagePullOptions{}) assert.ErrorContains(t, err, "", "pulling should have failed") assert.Equal(t, received, "example.org:5002") @@ -284,17 +312,11 @@ func TestDaemonProxy(t *testing.T) { _, err = c.ImagePull(ctx, "example.com/some/image:latest", types.ImagePullOptions{}) assert.ErrorContains(t, err, "", "pulling should have failed") assert.Equal(t, received, "example.org:5002", "should not have used proxy") - - info := d.Info(t) - assert.Equal(t, info.HTTPProxy, proxyServer.URL) - assert.Equal(t, info.HTTPSProxy, proxyServer.URL) - assert.Equal(t, info.NoProxy, "example.com") - - d.Stop(t) }) // Conflicting options (passed both through command-line options and config file) t.Run("conflicting options", func(t *testing.T) { + ctx := context.Background() const ( proxyRawURL = "https://" + userPass + "example.org" proxyURL = "https://xxxxx:xxxxx@example.org" @@ -308,43 +330,34 @@ func TestDaemonProxy(t *testing.T) { err := d.StartWithError("--http-proxy", proxyRawURL, "--https-proxy", proxyRawURL, "--no-proxy", "example.com", "--config-file", configFile, "--validate") assert.ErrorContains(t, err, "daemon exited during startup") - logs, err := d.ReadLogFile() - assert.NilError(t, err) + expected := fmt.Sprintf( `the following directives are specified both as a flag and in the configuration file: http-proxy: (from flag: %[1]s, from file: %[1]s), https-proxy: (from flag: %[1]s, from file: %[1]s), no-proxy: (from flag: example.com, from file: example.com)`, proxyURL, ) - assert.Assert(t, is.Contains(string(logs), expected)) + poll.WaitOn(t, d.PollCheckLogs(ctx, daemon.ScanLogsMatchString(expected))) }) // Make sure values are sanitized when reloading the daemon-config t.Run("reload sanitized", func(t *testing.T) { + t.Parallel() + + ctx := context.Background() const ( proxyRawURL = "https://" + userPass + "example.org" proxyURL = "https://xxxxx:xxxxx@example.org" ) d := daemon.New(t) - d.Start(t, "--http-proxy", proxyRawURL, "--https-proxy", proxyRawURL, "--no-proxy", "example.com") + d.Start(t, "--iptables=false", "--http-proxy", proxyRawURL, "--https-proxy", proxyRawURL, "--no-proxy", "example.com") defer d.Stop(t) err := d.Signal(syscall.SIGHUP) assert.NilError(t, err) - logs, err := d.ReadLogFile() - assert.NilError(t, err) + poll.WaitOn(t, d.PollCheckLogs(ctx, daemon.ScanLogsMatchAll("Reloaded configuration:", proxyURL))) - // FIXME: there appears to ba a race condition, which causes ReadLogFile - // to not contain the full logs after signaling the daemon to reload, - // causing the test to fail here. As a workaround, check if we - // received the "reloaded" message after signaling, and only then - // check that it's sanitized properly. For more details on this - // issue, see https://github.com/moby/moby/pull/42835/files#r713120315 - if !strings.Contains(string(logs), "Reloaded configuration:") { - t.Skip("Skipping test, because we did not find 'Reloaded configuration' in the logs") - } - - assert.Assert(t, is.Contains(string(logs), proxyURL)) - assert.Assert(t, !strings.Contains(string(logs), userPass), "logs should not contain the non-sanitized proxy URL: %s", string(logs)) + ok, logs := d.ScanLogsT(ctx, t, daemon.ScanLogsMatchString(userPass)) + assert.Assert(t, !ok, "logs should not contain the non-sanitized proxy URL: %s", logs) }) } diff --git a/testutil/daemon/daemon.go b/testutil/daemon/daemon.go index 98230960c6..360c39c89d 100644 --- a/testutil/daemon/daemon.go +++ b/testutil/daemon/daemon.go @@ -1,8 +1,10 @@ package daemon // import "github.com/docker/docker/testutil/daemon" import ( + "bufio" "context" "encoding/json" + "io" "net/http" "os" "os/exec" @@ -19,11 +21,13 @@ import ( "github.com/docker/docker/container" "github.com/docker/docker/pkg/ioutils" "github.com/docker/docker/pkg/stringid" + "github.com/docker/docker/pkg/tailfile" "github.com/docker/docker/testutil/request" "github.com/docker/go-connections/sockets" "github.com/docker/go-connections/tlsconfig" "github.com/pkg/errors" "gotest.tools/v3/assert" + "gotest.tools/v3/poll" ) // LogT is the subset of the testing.TB interface used by the daemon. @@ -273,6 +277,7 @@ func (d *Daemon) NewClientT(t testing.TB, extraOpts ...client.Opt) *client.Clien c, err := d.NewClient(extraOpts...) assert.NilError(t, err, "[%s] could not create daemon client", d.id) + t.Cleanup(func() { c.Close() }) return c } @@ -296,10 +301,105 @@ func (d *Daemon) Cleanup(t testing.TB) { cleanupNetworkNamespace(t, d) } +// TailLogsT attempts to tail N lines from the daemon logs. +// If there is an error the error is only logged, it does not cause an error with the test. +func (d *Daemon) TailLogsT(t LogT, n int) { + lines, err := d.TailLogs(n) + if err != nil { + t.Logf("[%s] %v", d.id, err) + return + } + for _, l := range lines { + t.Logf("[%s] %s", d.id, string(l)) + } +} + +// PollCheckLogs is a poll.Check that checks the daemon logs using the passed in match function. +func (d *Daemon) PollCheckLogs(ctx context.Context, match func(s string) bool) poll.Check { + return func(t poll.LogT) poll.Result { + ok, _, err := d.ScanLogs(ctx, match) + if err != nil { + return poll.Error(err) + } + if !ok { + return poll.Continue("waiting for daemon logs match") + } + return poll.Success() + } +} + +// ScanLogsMatchString returns a function that can be used to scan the daemon logs for the passed in string (`contains`). +func ScanLogsMatchString(contains string) func(string) bool { + return func(line string) bool { + return strings.Contains(line, contains) + } +} + +// ScanLogsMatchAll returns a function that can be used to scan the daemon logs until *all* the passed in strings are matched +func ScanLogsMatchAll(contains ...string) func(string) bool { + matched := make(map[string]bool) + return func(line string) bool { + for _, c := range contains { + if strings.Contains(line, c) { + matched[c] = true + } + } + return len(matched) == len(contains) + } +} + +// ScanLogsT uses `ScanLogs` to match the daemon logs using the passed in match function. +// If there is an error or the match fails, the test will fail. +func (d *Daemon) ScanLogsT(ctx context.Context, t testing.TB, match func(s string) bool) (bool, string) { + t.Helper() + ok, line, err := d.ScanLogs(ctx, match) + assert.NilError(t, err) + return ok, line +} + +// ScanLogs scans the daemon logs and passes each line to the match function. +func (d *Daemon) ScanLogs(ctx context.Context, match func(s string) bool) (bool, string, error) { + stat, err := d.logFile.Stat() + if err != nil { + return false, "", err + } + rdr := io.NewSectionReader(d.logFile, 0, stat.Size()) + + scanner := bufio.NewScanner(rdr) + for scanner.Scan() { + if match(scanner.Text()) { + return true, scanner.Text(), nil + } + select { + case <-ctx.Done(): + return false, "", ctx.Err() + default: + } + } + return false, "", scanner.Err() +} + +// TailLogs tails N lines from the daemon logs +func (d *Daemon) TailLogs(n int) ([][]byte, error) { + logF, err := os.Open(d.logFile.Name()) + if err != nil { + return nil, errors.Wrap(err, "error opening daemon log file after failed start") + } + + defer logF.Close() + lines, err := tailfile.TailFile(logF, n) + if err != nil { + return nil, errors.Wrap(err, "error tailing log daemon logs") + } + + return lines, nil +} + // Start starts the daemon and return once it is ready to receive requests. func (d *Daemon) Start(t testing.TB, args ...string) { t.Helper() if err := d.StartWithError(args...); err != nil { + d.TailLogsT(t, 20) d.DumpStackAndQuit() // in case the daemon is stuck t.Fatalf("[%s] failed to start daemon with arguments %v : %v", d.id, d.args, err) }