diff --git a/api/server/httputils/write_log_stream.go b/api/server/httputils/write_log_stream.go index 5793a99ff4..891e5f02b3 100644 --- a/api/server/httputils/write_log_stream.go +++ b/api/server/httputils/write_log_stream.go @@ -3,6 +3,7 @@ package httputils import ( "fmt" "io" + "net/url" "sort" "strings" @@ -85,6 +86,7 @@ func (s byKey) Swap(i, j int) { func stringAttrs(a backend.LogAttributes) string { var ss byKey for k, v := range a { + k, v := url.QueryEscape(k), url.QueryEscape(v) ss = append(ss, k+"="+v) } sort.Sort(ss) diff --git a/client/parse_logs.go b/client/parse_logs.go new file mode 100644 index 0000000000..e427f80a77 --- /dev/null +++ b/client/parse_logs.go @@ -0,0 +1,41 @@ +package client + +// parse_logs.go contains utility helpers for getting information out of docker +// log lines. really, it only contains ParseDetails right now. maybe in the +// future there will be some desire to parse log messages back into a struct? +// that would go here if we did + +import ( + "net/url" + "strings" + + "github.com/pkg/errors" +) + +// ParseLogDetails takes a details string of key value pairs in the form +// "k=v,l=w", where the keys and values are url query escaped, and each pair +// is separated by a comma, returns a map. returns an error if the details +// string is not in a valid format +// the exact form of details encoding is implemented in +// api/server/httputils/write_log_stream.go +func ParseLogDetails(details string) (map[string]string, error) { + pairs := strings.Split(details, ",") + detailsMap := make(map[string]string, len(pairs)) + for _, pair := range pairs { + p := strings.SplitN(pair, "=", 2) + // if there is no equals sign, we will only get 1 part back + if len(p) != 2 { + return nil, errors.New("invalid details format") + } + k, err := url.QueryUnescape(p[0]) + if err != nil { + return nil, err + } + v, err := url.QueryUnescape(p[1]) + if err != nil { + return nil, err + } + detailsMap[k] = v + } + return detailsMap, nil +} diff --git a/client/parse_logs_test.go b/client/parse_logs_test.go new file mode 100644 index 0000000000..ac7f61679d --- /dev/null +++ b/client/parse_logs_test.go @@ -0,0 +1,36 @@ +package client + +import ( + "reflect" + "testing" + + "github.com/pkg/errors" +) + +func TestParseLogDetails(t *testing.T) { + testCases := []struct { + line string + expected map[string]string + err error + }{ + {"key=value", map[string]string{"key": "value"}, nil}, + {"key1=value1,key2=value2", map[string]string{"key1": "value1", "key2": "value2"}, nil}, + {"key+with+spaces=value%3Dequals,asdf%2C=", map[string]string{"key with spaces": "value=equals", "asdf,": ""}, nil}, + {"key=,=nothing", map[string]string{"key": "", "": "nothing"}, nil}, + {"=", map[string]string{"": ""}, nil}, + {"errors", nil, errors.New("invalid details format")}, + } + for _, tc := range testCases { + tc := tc // capture range variable + t.Run(tc.line, func(t *testing.T) { + t.Parallel() + res, err := ParseLogDetails(tc.line) + if err != nil && (err.Error() != tc.err.Error()) { + t.Fatalf("unexpected error parsing logs:\nExpected:\n\t%v\nActual:\n\t%v", tc.err, err) + } + if !reflect.DeepEqual(tc.expected, res) { + t.Errorf("result does not match expected:\nExpected:\n\t%#v\nActual:\n\t%#v", tc.expected, res) + } + }) + } +} diff --git a/daemon/cluster/executor/container/adapter.go b/daemon/cluster/executor/container/adapter.go index ae27194e21..ad3e1b55d9 100644 --- a/daemon/cluster/executor/container/adapter.go +++ b/daemon/cluster/executor/container/adapter.go @@ -405,11 +405,11 @@ func (c *containerAdapter) logs(ctx context.Context, options api.LogSubscription apiOptions := &types.ContainerLogsOptions{ Follow: options.Follow, - // TODO(stevvooe): Parse timestamp out of message. This - // absolutely needs to be done before going to production with - // this, at it is completely redundant. + // Always say yes to Timestamps and Details. we make the decision + // of whether to return these to the user or not way higher up the + // stack. Timestamps: true, - Details: false, // no clue what to do with this, let's just deprecate it. + Details: true, } if options.Since != nil { diff --git a/daemon/cluster/executor/container/controller.go b/daemon/cluster/executor/container/controller.go index 5d2ce1e7cd..79657d2b56 100644 --- a/daemon/cluster/executor/container/controller.go +++ b/daemon/cluster/executor/container/controller.go @@ -523,10 +523,18 @@ func (r *controller) Logs(ctx context.Context, publisher exec.LogPublisher, opti stream = api.LogStreamStderr } + // parse the details out of the Attrs map + attrs := []api.LogAttr{} + for k, v := range msg.Attrs { + attr := api.LogAttr{Key: k, Value: v} + attrs = append(attrs, attr) + } + if err := publisher.Publish(ctx, api.LogMessage{ Context: msgctx, Timestamp: tsp, Stream: stream, + Attrs: attrs, Data: msg.Line, }); err != nil { return errors.Wrap(err, "failed to publish log message") diff --git a/daemon/cluster/services.go b/daemon/cluster/services.go index b7b40c5f7c..0bfc417860 100644 --- a/daemon/cluster/services.go +++ b/daemon/cluster/services.go @@ -430,9 +430,17 @@ func (c *Cluster) ServiceLogs(ctx context.Context, selector *backend.LogSelector if err != nil { m.Err = err } + // copy over all of the details + for _, d := range msg.Attrs { + m.Attrs[d.Key] = d.Value + } + // we have the final say over context details (in case there + // is a conflict (if the user added a detail with a context's + // key for some reason)) m.Attrs[contextPrefix+".node.id"] = msg.Context.NodeID m.Attrs[contextPrefix+".service.id"] = msg.Context.ServiceID m.Attrs[contextPrefix+".task.id"] = msg.Context.TaskID + switch msg.Stream { case swarmapi.LogStreamStdout: m.Source = "stdout" diff --git a/hack/dockerfile/binaries-commits b/hack/dockerfile/binaries-commits index 13a941ab52..5c110b7065 100644 --- a/hack/dockerfile/binaries-commits +++ b/hack/dockerfile/binaries-commits @@ -11,5 +11,5 @@ VNDR_COMMIT=c56e082291115e369f77601f9c071dd0b87c7120 BINDATA_COMMIT=a0ff2567cfb70903282db057e799fd826784d41d # CLI -DOCKERCLI_REPO=https://github.com/aaronlehmann/cli -DOCKERCLI_COMMIT=0e2b9d30814eaecd6518bfb112bb4adef0265d4b +DOCKERCLI_REPO=https://github.com/dperny/cli +DOCKERCLI_COMMIT=7230906e0e297999eb33da74e0279c5cf41a119e diff --git a/integration-cli/docker_cli_service_logs_test.go b/integration-cli/docker_cli_service_logs_test.go index 1e9e7b4005..65c3d0802f 100644 --- a/integration-cli/docker_cli_service_logs_test.go +++ b/integration-cli/docker_cli_service_logs_test.go @@ -55,8 +55,14 @@ func (s *DockerSwarmSuite) TestServiceLogs(c *check.C) { // output. func countLogLines(d *daemon.Swarm, name string) func(*check.C) (interface{}, check.CommentInterface) { return func(c *check.C) (interface{}, check.CommentInterface) { - result := icmd.RunCmd(d.Command("service", "logs", "-t", name)) + result := icmd.RunCmd(d.Command("service", "logs", "-t", "--raw", name)) result.Assert(c, icmd.Expected{}) + // if this returns an emptystring, trying to split it later will return + // an array containing emptystring. a valid log line will NEVER be + // emptystring because we ask for the timestamp. + if result.Stdout() == "" { + return 0, check.Commentf("Empty stdout") + } lines := strings.Split(strings.TrimSpace(result.Stdout()), "\n") return len(lines), check.Commentf("output, %q", string(result.Stdout())) } @@ -277,7 +283,7 @@ func (s *DockerSwarmSuite) TestServiceLogsTTY(c *check.C) { // and make sure we have all the log lines waitAndAssert(c, defaultReconciliationTimeout, countLogLines(d, name), checker.Equals, 2) - cmd := d.Command("service", "logs", name) + cmd := d.Command("service", "logs", "--raw", name) result = icmd.RunCmd(cmd) // for some reason there is carriage return in the output. i think this is // just expected. @@ -332,3 +338,50 @@ func (s *DockerSwarmSuite) TestServiceLogsNoHangDeletedContainer(c *check.C) { // Expected defaults to false c.Assert(result, icmd.Matches, icmd.Expected{}) } + +func (s *DockerSwarmSuite) TestServiceLogsDetails(c *check.C) { + d := s.AddDaemon(c, true, true) + + name := "TestServiceLogsDetails" + + result := icmd.RunCmd(d.Command( + // create a service + "service", "create", + // name it $name + "--name", name, + // add an environment variable + "--env", "asdf=test1", + // add a log driver (without explicitly setting a driver, log-opt doesn't work) + "--log-driver", "json-file", + // add a log option to print the environment variable + "--log-opt", "env=asdf", + // busybox image, shell string + "busybox", "sh", "-c", + // make a log line + "echo LogLine; while true; do sleep 1; done;", + )) + + result.Assert(c, icmd.Expected{}) + id := strings.TrimSpace(result.Stdout()) + c.Assert(id, 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, 1) + + // First, test without pretty printing + // call service logs with details. set raw to skip pretty printing + result = icmd.RunCmd(d.Command("service", "logs", "--raw", "--details", name)) + // in this case, we should get details and we should get log message, but + // there will also be context as details (which will fall after the detail + // we inserted in alphabetical order + c.Assert(result, icmd.Matches, icmd.Expected{Out: "asdf=test1"}) + c.Assert(result, icmd.Matches, icmd.Expected{Out: "LogLine"}) + + // call service logs with details. this time, don't pass raw + result = icmd.RunCmd(d.Command("service", "logs", "--details", id)) + // in this case, we should get details space logmessage as well. the context + // is part of the pretty part of the logline + c.Assert(result, icmd.Matches, icmd.Expected{Out: "asdf=test1 LogLine"}) +}