integration-cli/docker_cli_service_logs_experimental_test.go
c7995fdc
 // +build !windows
 
 package main
 
 import (
 	"bufio"
c2d435e4
 	"fmt"
c7995fdc
 	"io"
 	"os/exec"
 	"strings"
8dc437bd
 	"time"
c7995fdc
 
33968e6c
 	"github.com/docker/docker/integration-cli/checker"
8dc437bd
 	"github.com/docker/docker/integration-cli/daemon"
c7995fdc
 	"github.com/go-check/check"
 )
 
 type logMessage struct {
 	err  error
 	data []byte
 }
 
 func (s *DockerSwarmSuite) TestServiceLogs(c *check.C) {
 	testRequires(c, ExperimentalDaemon)
 
 	d := s.AddDaemon(c, true, true)
 
f8a93d0c
 	// we have multiple services here for detecting the goroutine issue #28915
 	services := map[string]string{
 		"TestServiceLogs1": "hello1",
 		"TestServiceLogs2": "hello2",
 	}
 
 	for name, message := range services {
 		out, err := d.Cmd("service", "create", "--name", name, "busybox",
 			"sh", "-c", fmt.Sprintf("echo %s; tail -f /dev/null", message))
 		c.Assert(err, checker.IsNil)
 		c.Assert(strings.TrimSpace(out), checker.Not(checker.Equals), "")
 	}
c2d435e4
 
 	// make sure task has been deployed.
f8a93d0c
 	waitAndAssert(c, defaultReconciliationTimeout,
39433318
 		d.CheckRunningTaskImages, checker.DeepEquals,
 		map[string]int{"busybox": len(services)})
f8a93d0c
 
 	for name, message := range services {
 		out, err := d.Cmd("service", "logs", name)
 		c.Assert(err, checker.IsNil)
 		c.Logf("log for %q: %q", name, out)
 		c.Assert(out, checker.Contains, message)
 	}
c2d435e4
 }
 
8dc437bd
 // countLogLines returns a closure that can be used with waitAndAssert to
 // verify that a minimum number of expected container log messages have been
 // output.
 func countLogLines(d *daemon.Swarm, name string) func(*check.C) (interface{}, check.CommentInterface) {
 	return func(c *check.C) (interface{}, check.CommentInterface) {
 		out, err := d.Cmd("service", "logs", "-t", name)
 		c.Assert(err, checker.IsNil)
 		lines := strings.Split(strings.TrimSpace(out), "\n")
 		return len(lines), check.Commentf("output, %q", string(out))
 	}
 }
 
 func (s *DockerSwarmSuite) TestServiceLogsCompleteness(c *check.C) {
 	testRequires(c, ExperimentalDaemon)
 	d := s.AddDaemon(c, true, true)
 
 	name := "TestServiceLogsCompleteness"
 
 	// make a service that prints 6 lines
 	out, err := d.Cmd("service", "create", "--name", name, "busybox", "sh", "-c", "for line in $(seq 1 6); do echo log test $line; done; sleep 100000")
 	c.Assert(err, checker.IsNil)
 	c.Assert(strings.TrimSpace(out), checker.Not(checker.Equals), "")
 
 	// make sure task has been deployed.
 	waitAndAssert(c, defaultReconciliationTimeout, d.CheckActiveContainerCount, checker.Equals, 1)
 	// and make sure we have all the log lines
 	waitAndAssert(c, defaultReconciliationTimeout, countLogLines(d, name), checker.Equals, 6)
 
 	args := []string{"service", "logs", name}
 	cmd := exec.Command(dockerBinary, d.PrependHostArg(args)...)
 	r, w := io.Pipe()
 	cmd.Stdout = w
 	cmd.Stderr = w
 	c.Assert(cmd.Start(), checker.IsNil)
 
 	reader := bufio.NewReader(r)
 	// i have heard anecdotal reports that logs may come back from the engine
 	// mis-ordered. if this tests fails, consider the possibility that that
 	// might be occurring
 	for i := 1; i <= 6; i++ {
 		msg := &logMessage{}
 		msg.data, _, msg.err = reader.ReadLine()
 		c.Assert(msg.err, checker.IsNil)
 		c.Assert(string(msg.data), checker.Contains, fmt.Sprintf("log test %v", i))
 	}
 }
 
 func (s *DockerSwarmSuite) TestServiceLogsTail(c *check.C) {
 	testRequires(c, ExperimentalDaemon)
 	d := s.AddDaemon(c, true, true)
 
 	name := "TestServiceLogsTail"
 
 	// make a service that prints 6 lines
 	out, err := d.Cmd("service", "create", "--name", name, "busybox", "sh", "-c", "for line in $(seq 1 6); do echo log test $line; done; sleep 100000")
 	c.Assert(err, checker.IsNil)
 	c.Assert(strings.TrimSpace(out), checker.Not(checker.Equals), "")
 
 	// make sure task has been deployed.
 	waitAndAssert(c, defaultReconciliationTimeout, d.CheckActiveContainerCount, checker.Equals, 1)
 	waitAndAssert(c, defaultReconciliationTimeout, countLogLines(d, name), checker.Equals, 6)
 
 	args := []string{"service", "logs", "--tail=2", name}
 	cmd := exec.Command(dockerBinary, d.PrependHostArg(args)...)
 	r, w := io.Pipe()
 	cmd.Stdout = w
 	cmd.Stderr = w
 	c.Assert(cmd.Start(), checker.IsNil)
 
 	reader := bufio.NewReader(r)
 	// see TestServiceLogsCompleteness for comments about logs being well-
 	// ordered, if this flakes
 	for i := 5; i <= 6; i++ {
 		msg := &logMessage{}
 		msg.data, _, msg.err = reader.ReadLine()
 		c.Assert(msg.err, checker.IsNil)
 		c.Assert(string(msg.data), checker.Contains, fmt.Sprintf("log test %v", i))
 	}
 }
 
 func (s *DockerSwarmSuite) TestServiceLogsSince(c *check.C) {
 	// See DockerSuite.TestLogsSince, which is where this comes from
 	testRequires(c, ExperimentalDaemon)
 	d := s.AddDaemon(c, true, true)
 
 	name := "TestServiceLogsSince"
 
 	out, err := d.Cmd("service", "create", "--name", name, "busybox", "sh", "-c", "for i in $(seq 1 3); do sleep .1; echo log$i; done; sleep 10000000")
 	c.Assert(err, checker.IsNil)
 	c.Assert(strings.TrimSpace(out), checker.Not(checker.Equals), "")
 	waitAndAssert(c, defaultReconciliationTimeout, d.CheckActiveContainerCount, checker.Equals, 1)
 	// wait a sec for the logs to come in
 	waitAndAssert(c, defaultReconciliationTimeout, countLogLines(d, name), checker.Equals, 3)
 
 	out, err = d.Cmd("service", "logs", "-t", name)
 	c.Assert(err, checker.IsNil)
 
 	log2Line := strings.Split(strings.Split(out, "\n")[1], " ")
 	t, err := time.Parse(time.RFC3339Nano, log2Line[0]) // timestamp log2 is written
 	c.Assert(err, checker.IsNil)
 	u := t.Add(50 * time.Millisecond) // add .05s so log1 & log2 don't show up
 	since := u.Format(time.RFC3339Nano)
 
 	out, err = d.Cmd("service", "logs", "-t", fmt.Sprintf("--since=%v", since), name)
 	c.Assert(err, checker.IsNil)
 
 	unexpected := []string{"log1", "log2"}
 	expected := []string{"log3"}
 	for _, v := range unexpected {
 		c.Assert(out, checker.Not(checker.Contains), v, check.Commentf("unexpected log message returned, since=%v", u))
 	}
 	for _, v := range expected {
 		c.Assert(out, checker.Contains, v, check.Commentf("expected log message %v, was not present, since=%v", u))
 	}
 }
 
c2d435e4
 func (s *DockerSwarmSuite) TestServiceLogsFollow(c *check.C) {
 	testRequires(c, ExperimentalDaemon)
 
 	d := s.AddDaemon(c, true, true)
 
 	name := "TestServiceLogsFollow"
 
 	out, err := d.Cmd("service", "create", "--name", name, "busybox", "sh", "-c", "while true; do echo log test; sleep 0.1; done")
c7995fdc
 	c.Assert(err, checker.IsNil)
 	c.Assert(strings.TrimSpace(out), checker.Not(checker.Equals), "")
 
 	// make sure task has been deployed.
48de91a3
 	waitAndAssert(c, defaultReconciliationTimeout, d.CheckActiveContainerCount, checker.Equals, 1)
c7995fdc
 
 	args := []string{"service", "logs", "-f", name}
48de91a3
 	cmd := exec.Command(dockerBinary, d.PrependHostArg(args)...)
c7995fdc
 	r, w := io.Pipe()
 	cmd.Stdout = w
 	cmd.Stderr = w
 	c.Assert(cmd.Start(), checker.IsNil)
 
 	// Make sure pipe is written to
 	ch := make(chan *logMessage)
c2d435e4
 	done := make(chan struct{})
c7995fdc
 	go func() {
 		reader := bufio.NewReader(r)
c2d435e4
 		for {
 			msg := &logMessage{}
 			msg.data, _, msg.err = reader.ReadLine()
 			select {
 			case ch <- msg:
 			case <-done:
 				return
 			}
 		}
c7995fdc
 	}()
 
c2d435e4
 	for i := 0; i < 3; i++ {
 		msg := <-ch
 		c.Assert(msg.err, checker.IsNil)
 		c.Assert(string(msg.data), checker.Contains, "log test")
 	}
 	close(done)
c7995fdc
 
 	c.Assert(cmd.Process.Kill(), checker.IsNil)
 }