Merge pull request #46135 from thaJeztah/23.0_backport_fix_daemon_integration_test

[23.0 backport] Improve test daemon logging, and fix TestDaemonProxy integration tests
This commit is contained in:
Sebastiaan van Stijn 2023-08-04 18:06:04 +02:00 committed by GitHub
commit ed8f0053e8
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
2 changed files with 203 additions and 90 deletions

View file

@ -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"
)
@ -185,27 +185,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
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"))
}))
defer proxyServer.Close()
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")
@ -215,39 +228,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")
@ -255,44 +278,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")
@ -300,17 +328,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"
@ -324,43 +346,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)
})
}

View file

@ -1,8 +1,10 @@
package daemon // import "github.com/docker/docker/testutil/daemon"
import (
"bufio"
"context"
"encoding/json"
"io"
"net/http"
"os"
"os/exec"
@ -18,11 +20,13 @@ import (
"github.com/docker/docker/client"
"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.
@ -272,6 +276,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
}
@ -295,10 +300,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)
}