Include security options in the container created event

pkg/kubelet/dockertools/docker_manager.go

@@ -18,6 +18,7 @@ package dockertools
 
 import (
 	"bytes"
+	"crypto/md5"
 	"encoding/json"
 	"errors"
 	"fmt"
@@ -111,7 +112,7 @@ var (
 	podInfraContainerImagePullPolicy = api.PullIfNotPresent
 
 	// Default set of seccomp security options.
-	defaultSeccompOpt = []dockerOpt{{"seccomp", "unconfined"}}
+	defaultSeccompOpt = []dockerOpt{{"seccomp", "unconfined", ""}}
 )
 
 type DockerManager struct {
@@ -579,6 +580,10 @@ func (dm *DockerManager) runContainer(
 	if err != nil {
 		return kubecontainer.ContainerID{}, err
 	}
+	fmtSecurityOpts, err := dm.fmtDockerOpts(securityOpts)
+	if err != nil {
+		return kubecontainer.ContainerID{}, err
+	}
 
 	// Pod information is recorded on the container as labels to preserve it in the event the pod is deleted
 	// while the Kubelet is down and there is no information available to recover the pod.
@@ -658,7 +663,7 @@ func (dm *DockerManager) runContainer(
 			CPUShares:  cpuShares,
 			Devices:    devices,
 		},
-		SecurityOpt: securityOpts,
+		SecurityOpt: fmtSecurityOpts,
 	}
 
 	// Set sysctls if requested
@@ -733,7 +738,21 @@ func (dm *DockerManager) runContainer(
 	if len(createResp.Warnings) != 0 {
 		glog.V(2).Infof("Container %q of pod %q created with warnings: %v", container.Name, format.Pod(pod), createResp.Warnings)
 	}
-	dm.recorder.Eventf(ref, api.EventTypeNormal, events.CreatedContainer, "Created container with docker id %v", utilstrings.ShortenString(createResp.ID, 12))
+
+	createdEventMsg := fmt.Sprintf("Created container with docker id %v", utilstrings.ShortenString(createResp.ID, 12))
+	if len(securityOpts) > 0 {
+		var msgs []string
+		for _, opt := range securityOpts {
+			glog.Errorf("Logging security options: %+v", opt)
+			msg := opt.msg
+			if msg == "" {
+				msg = opt.value
+			}
+			msgs = append(msgs, fmt.Sprintf("%s=%s", opt.key, truncateMsg(msg, 256)))
+		}
+		createdEventMsg = fmt.Sprintf("%s; Security:[%s]", createdEventMsg, strings.Join(msgs, " "))
+	}
+	dm.recorder.Eventf(ref, api.EventTypeNormal, events.CreatedContainer, createdEventMsg)
 
 	if err = dm.client.StartContainer(createResp.ID); err != nil {
 		dm.recorder.Eventf(ref, api.EventTypeWarning, events.FailedToStartContainer,
@@ -1056,25 +1075,12 @@ func (dm *DockerManager) checkVersionCompatibility() error {
 	return nil
 }
 
-func (dm *DockerManager) getSecurityOpts(pod *api.Pod, ctrName string) ([]string, error) {
+func (dm *DockerManager) fmtDockerOpts(opts []dockerOpt) ([]string, error) {
 	version, err := dm.APIVersion()
 	if err != nil {
 		return nil, err
 	}
 
-	var securityOpts []dockerOpt
-	if seccompOpts, err := dm.getSeccompOpts(pod, ctrName, version); err != nil {
-		return nil, err
-	} else {
-		securityOpts = append(securityOpts, seccompOpts...)
-	}
-
-	if appArmorOpts, err := dm.getAppArmorOpts(pod, ctrName); err != nil {
-		return nil, err
-	} else {
-		securityOpts = append(securityOpts, appArmorOpts...)
-	}
-
 	const (
 		// Docker changed the API for specifying options in v1.11
 		optSeparatorChangeVersion = "1.23" // Corresponds to docker 1.11.x
@@ -1089,19 +1095,44 @@ func (dm *DockerManager) getSecurityOpts(pod *api.Pod, ctrName string) ([]string
 		sep = optSeparatorOld
 	}
 
-	opts := make([]string, len(securityOpts))
+	fmtOpts := make([]string, len(opts))
-	for i, opt := range securityOpts {
+	for i, opt := range opts {
-		opts[i] = fmt.Sprintf("%s%c%s", opt.key, sep, opt.value)
+		fmtOpts[i] = fmt.Sprintf("%s%c%s", opt.key, sep, opt.value)
 	}
-	return opts, nil
+	return fmtOpts, nil
+}
+
+func (dm *DockerManager) getSecurityOpts(pod *api.Pod, ctrName string) ([]dockerOpt, error) {
+	var securityOpts []dockerOpt
+	if seccompOpts, err := dm.getSeccompOpts(pod, ctrName); err != nil {
+		return nil, err
+	} else {
+		securityOpts = append(securityOpts, seccompOpts...)
+	}
+
+	if appArmorOpts, err := dm.getAppArmorOpts(pod, ctrName); err != nil {
+		return nil, err
+	} else {
+		securityOpts = append(securityOpts, appArmorOpts...)
+	}
+
+	return securityOpts, nil
 }
 
 type dockerOpt struct {
+	// The key-value pair passed to docker.
 	key, value string
+	// The alternative value to use in log/event messages.
+	msg string
 }
 
 // Get the docker security options for seccomp.
-func (dm *DockerManager) getSeccompOpts(pod *api.Pod, ctrName string, version kubecontainer.Version) ([]dockerOpt, error) {
+func (dm *DockerManager) getSeccompOpts(pod *api.Pod, ctrName string) ([]dockerOpt, error) {
+	version, err := dm.APIVersion()
+	if err != nil {
+		return nil, err
+	}
+
 	// seccomp is only on docker versions >= v1.10
 	if result, err := version.Compare(dockerV110APIVersion); err != nil {
 		return nil, err
@@ -1144,8 +1175,10 @@ func (dm *DockerManager) getSeccompOpts(pod *api.Pod, ctrName string, version ku
 	if err := json.Compact(b, file); err != nil {
 		return nil, err
 	}
+	// Rather than the full profile, just put the filename & md5sum in the event log.
+	msg := fmt.Sprintf("%s(md5:%x)", name, md5.Sum(file))
 
-	return []dockerOpt{{"seccomp", b.String()}}, nil
+	return []dockerOpt{{"seccomp", b.String(), msg}}, nil
 }
 
 // Get the docker security options for AppArmor.
@@ -1158,7 +1191,7 @@ func (dm *DockerManager) getAppArmorOpts(pod *api.Pod, ctrName string) ([]docker
 
 	// Assume validation has already happened.
 	profileName := strings.TrimPrefix(profile, apparmor.ProfileNamePrefix)
-	return []dockerOpt{{"apparmor", profileName}}, nil
+	return []dockerOpt{{"apparmor", profileName, ""}}, nil
 }
 
 type dockerExitError struct {
@@ -2557,3 +2590,15 @@ func (dm *DockerManager) getVersionInfo() (versionInfo, error) {
 		daemonVersion: daemonVersion,
 	}, nil
 }
+
+// Truncate the message if it exceeds max length.
+func truncateMsg(msg string, max int) string {
+	if len(msg) <= max {
+		return msg
+	}
+	glog.V(2).Infof("Truncated %s", msg)
+	const truncatedMsg = "..TRUNCATED.."
+	begin := (max - len(truncatedMsg)) / 2
+	end := len(msg) - (max - (len(truncatedMsg) + begin))
+	return msg[:begin] + truncatedMsg + msg[end:]
+}

pkg/kubelet/dockertools/docker_manager_test.go

@@ -44,6 +44,7 @@ import (
 	"k8s.io/kubernetes/pkg/client/record"
 	kubecontainer "k8s.io/kubernetes/pkg/kubelet/container"
 	containertest "k8s.io/kubernetes/pkg/kubelet/container/testing"
+	"k8s.io/kubernetes/pkg/kubelet/events"
 	"k8s.io/kubernetes/pkg/kubelet/images"
 	"k8s.io/kubernetes/pkg/kubelet/network"
 	"k8s.io/kubernetes/pkg/kubelet/network/mock_network"
@@ -58,6 +59,7 @@ import (
 	"k8s.io/kubernetes/pkg/util/flowcontrol"
 	"k8s.io/kubernetes/pkg/util/intstr"
 	"k8s.io/kubernetes/pkg/util/sets"
+	utilstrings "k8s.io/kubernetes/pkg/util/strings"
 )
 
 type fakeHTTP struct {
@@ -1754,19 +1756,8 @@ func TestSecurityOptsOperator(t *testing.T) {
 	dm110, _ := newTestDockerManagerWithVersion("1.10.1", "1.22")
 	dm111, _ := newTestDockerManagerWithVersion("1.11.0", "1.23")
 
-	pod := &api.Pod{
+	secOpts := []dockerOpt{{"seccomp", "unconfined", ""}}
-		ObjectMeta: api.ObjectMeta{
+	opts, err := dm110.fmtDockerOpts(secOpts)
-			UID:       "12345678",
-			Name:      "foo",
-			Namespace: "new",
-		},
-		Spec: api.PodSpec{
-			Containers: []api.Container{
-				{Name: "bar"},
-			},
-		},
-	}
-	opts, err := dm110.getSecurityOpts(pod, "bar")
 	if err != nil {
 		t.Fatalf("error getting security opts for Docker 1.10: %v", err)
 	}
@@ -1774,7 +1765,7 @@ func TestSecurityOptsOperator(t *testing.T) {
 		t.Fatalf("security opts for Docker 1.10: expected %v, got: %v", expected, opts)
 	}
 
-	opts, err = dm111.getSecurityOpts(pod, "bar")
+	opts, err = dm111.fmtDockerOpts(secOpts)
 	if err != nil {
 		t.Fatalf("error getting security opts for Docker 1.11: %v", err)
 	}
@@ -1838,7 +1829,9 @@ func TestGetSecurityOpts(t *testing.T) {
 
 	dm, _ := newTestDockerManagerWithVersion("1.11.1", "1.23")
 	for i, test := range tests {
-		opts, err := dm.getSecurityOpts(test.pod, containerName)
+		securityOpts, err := dm.getSecurityOpts(test.pod, containerName)
+		assert.NoError(t, err, "TestCase[%d]: %s", i, test.msg)
+		opts, err := dm.fmtDockerOpts(securityOpts)
 		assert.NoError(t, err, "TestCase[%d]: %s", i, test.msg)
 		assert.Len(t, opts, len(test.expectedOpts), "TestCase[%d]: %s", i, test.msg)
 		for _, opt := range test.expectedOpts {
@@ -1849,6 +1842,10 @@ func TestGetSecurityOpts(t *testing.T) {
 
 func TestSeccompIsUnconfinedByDefaultWithDockerV110(t *testing.T) {
 	dm, fakeDocker := newTestDockerManagerWithVersion("1.10.1", "1.22")
+	// We want to capture events.
+	recorder := record.NewFakeRecorder(20)
+	dm.recorder = recorder
+
 	pod := &api.Pod{
 		ObjectMeta: api.ObjectMeta{
 			UID:       "12345678",
@@ -1884,6 +1881,10 @@ func TestSeccompIsUnconfinedByDefaultWithDockerV110(t *testing.T) {
 		t.Fatalf("unexpected error %v", err)
 	}
 	assert.Contains(t, newContainer.HostConfig.SecurityOpt, "seccomp:unconfined", "Pods with Docker versions >= 1.10 must not have seccomp disabled by default")
+
+	cid := utilstrings.ShortenString(fakeDocker.Created[1], 12)
+	assert.NoError(t, expectEvent(recorder, api.EventTypeNormal, events.CreatedContainer,
+		fmt.Sprintf("Created container with docker id %s; Security:[seccomp=unconfined]", cid)))
 }
 
 func TestUnconfinedSeccompProfileWithDockerV110(t *testing.T) {
@@ -2017,6 +2018,7 @@ func TestSeccompLocalhostProfileIsLoaded(t *testing.T) {
 	tests := []struct {
 		annotations    map[string]string
 		expectedSecOpt string
+		expectedSecMsg string
 		expectedError  string
 	}{
 		{
@@ -2024,12 +2026,14 @@ func TestSeccompLocalhostProfileIsLoaded(t *testing.T) {
 				api.SeccompPodAnnotationKey: "localhost/test",
 			},
 			expectedSecOpt: `seccomp={"foo":"bar"}`,
+			expectedSecMsg: "seccomp=test(md5:21aeae45053385adebd25311f9dd9cb1)",
 		},
 		{
 			annotations: map[string]string{
 				api.SeccompPodAnnotationKey: "localhost/sub/subtest",
 			},
 			expectedSecOpt: `seccomp={"abc":"def"}`,
+			expectedSecMsg: "seccomp=sub/subtest(md5:07c9bcb4db631f7ca191d6e0bca49f76)",
 		},
 		{
 			annotations: map[string]string{
@@ -2039,8 +2043,12 @@ func TestSeccompLocalhostProfileIsLoaded(t *testing.T) {
 		},
 	}
 
-	for _, test := range tests {
+	for i, test := range tests {
 		dm, fakeDocker := newTestDockerManagerWithVersion("1.11.0", "1.23")
+		// We want to capture events.
+		recorder := record.NewFakeRecorder(20)
+		dm.recorder = recorder
+
 		_, filename, _, _ := goruntime.Caller(0)
 		dm.seccompProfileRoot = path.Join(path.Dir(filename), "fixtures", "seccomp")
 
@@ -2084,6 +2092,11 @@ func TestSeccompLocalhostProfileIsLoaded(t *testing.T) {
 			t.Fatalf("unexpected error %v", err)
 		}
 		assert.Contains(t, newContainer.HostConfig.SecurityOpt, test.expectedSecOpt, "The compacted seccomp json profile should be loaded.")
+
+		cid := utilstrings.ShortenString(fakeDocker.Created[1], 12)
+		assert.NoError(t, expectEvent(recorder, api.EventTypeNormal, events.CreatedContainer,
+			fmt.Sprintf("Created container with docker id %s; Security:[%s]", cid, test.expectedSecMsg)),
+			"testcase %d", i)
 	}
 }
 
@@ -2158,6 +2171,76 @@ func TestCheckVersionCompatibility(t *testing.T) {
 	}
 }
 
+func TestCreateAppArmorContanier(t *testing.T) {
+	dm, fakeDocker := newTestDockerManagerWithVersion("1.11.1", "1.23")
+	// We want to capture events.
+	recorder := record.NewFakeRecorder(20)
+	dm.recorder = recorder
+
+	pod := &api.Pod{
+		ObjectMeta: api.ObjectMeta{
+			UID:       "12345678",
+			Name:      "foo",
+			Namespace: "new",
+			Annotations: map[string]string{
+				apparmor.ContainerAnnotationKeyPrefix + "test": apparmor.ProfileNamePrefix + "test-profile",
+			},
+		},
+		Spec: api.PodSpec{
+			Containers: []api.Container{
+				{Name: "test"},
+			},
+		},
+	}
+
+	runSyncPod(t, dm, fakeDocker, pod, nil, false)
+
+	verifyCalls(t, fakeDocker, []string{
+		// Create pod infra container.
+		"create", "start", "inspect_container", "inspect_container",
+		// Create container.
+		"create", "start", "inspect_container",
+	})
+
+	fakeDocker.Lock()
+	if len(fakeDocker.Created) != 2 ||
+		!matchString(t, "/k8s_POD\\.[a-f0-9]+_foo_new_", fakeDocker.Created[0]) ||
+		!matchString(t, "/k8s_test\\.[a-f0-9]+_foo_new_", fakeDocker.Created[1]) {
+		t.Errorf("unexpected containers created %v", fakeDocker.Created)
+	}
+	fakeDocker.Unlock()
+
+	// Verify security opts.
+	newContainer, err := fakeDocker.InspectContainer(fakeDocker.Created[1])
+	if err != nil {
+		t.Fatalf("unexpected error %v", err)
+	}
+	securityOpts := newContainer.HostConfig.SecurityOpt
+	assert.Contains(t, securityOpts, "apparmor=test-profile", "Container should have apparmor security opt")
+
+	cid := utilstrings.ShortenString(fakeDocker.Created[1], 12)
+	assert.NoError(t, expectEvent(recorder, api.EventTypeNormal, events.CreatedContainer,
+		fmt.Sprintf("Created container with docker id %s; Security:[seccomp=unconfined apparmor=test-profile]", cid)))
+}
+
+func expectEvent(recorder *record.FakeRecorder, eventType, reason, msg string) error {
+	expected := fmt.Sprintf("%s %s %s", eventType, reason, msg)
+	var events []string
+	// Drain the event channel.
+	for {
+		select {
+		case event := <-recorder.Events:
+			if event == expected {
+				return nil
+			}
+			events = append(events, event)
+		default:
+			// No more events!
+			return fmt.Errorf("Event %q not found in [%s]", expected, strings.Join(events, ", "))
+		}
+	}
+}
+
 func TestNewDockerVersion(t *testing.T) {
 	cases := []struct {
 		value string