Bladeren bron

Add filter by event type and documentation.

Signed-off-by: David Calavera <david.calavera@gmail.com>
David Calavera 9 jaren geleden
bovenliggende
commit
851fe00c64

+ 19 - 6
api/client/events.go

@@ -58,16 +58,29 @@ func (cli *DockerCli) CmdEvents(args ...string) error {
 
 // streamEvents decodes prints the incoming events in the provided output.
 func streamEvents(input io.Reader, output io.Writer) error {
+	return decodeEvents(input, func(event eventtypes.Message, err error) error {
+		if err != nil {
+			return err
+		}
+		printOutput(event, output)
+		return nil
+	})
+}
+
+type eventProcessor func(event eventtypes.Message, err error) error
+
+func decodeEvents(input io.Reader, ep eventProcessor) error {
 	dec := json.NewDecoder(input)
 	for {
 		var event eventtypes.Message
-		if err := dec.Decode(&event); err != nil {
-			if err == io.EOF {
-				break
-			}
-			return err
+		err := dec.Decode(&event)
+		if err != nil && err == io.EOF {
+			break
+		}
+
+		if procErr := ep(event, err); procErr != nil {
+			return procErr
 		}
-		printOutput(event, output)
 	}
 	return nil
 }

+ 14 - 9
api/client/stats.go

@@ -11,8 +11,9 @@ import (
 	"time"
 
 	"github.com/docker/docker/api/types"
+	"github.com/docker/docker/api/types/events"
+	"github.com/docker/docker/api/types/filters"
 	Cli "github.com/docker/docker/cli"
-	"github.com/docker/docker/pkg/jsonmessage"
 	"github.com/docker/go-units"
 )
 
@@ -189,7 +190,11 @@ func (cli *DockerCli) CmdStats(args ...string) error {
 			err   error
 		}
 		getNewContainers := func(c chan<- watch) {
-			options := types.EventsOptions{}
+			f := filters.NewArgs()
+			f.Add("type", "container")
+			options := types.EventsOptions{
+				Filters: f,
+			}
 			resBody, err := cli.client.Events(options)
 			if err != nil {
 				c <- watch{err: err}
@@ -197,15 +202,15 @@ func (cli *DockerCli) CmdStats(args ...string) error {
 			}
 			defer resBody.Close()
 
-			dec := json.NewDecoder(resBody)
-			for {
-				var j *jsonmessage.JSONMessage
-				if err := dec.Decode(&j); err != nil {
+			decodeEvents(resBody, func(event events.Message, err error) error {
+				if err != nil {
 					c <- watch{err: err}
-					return
+					return nil
 				}
-				c <- watch{j.ID[:12], j.Status, nil}
-			}
+
+				c <- watch{event.ID[:12], event.Action, nil}
+				return nil
+			})
 		}
 		go func(stopChan chan<- error) {
 			cChan := make(chan watch)

+ 31 - 13
daemon/events/filter.go

@@ -18,16 +18,16 @@ func NewFilter(filter filters.Args) *Filter {
 
 // Include returns true when the event ev is included by the filters
 func (ef *Filter) Include(ev events.Message) bool {
-	if ev.Type != events.ContainerEventType && ev.Type != events.ImageEventType {
-		return false
-	}
 	return ef.filter.ExactMatch("event", ev.Action) &&
+		ef.filter.ExactMatch("type", ev.Type) &&
 		ef.matchContainer(ev) &&
-		ef.isImageIncluded(ev) &&
-		ef.isLabelFieldIncluded(ev.Actor.Attributes)
+		ef.matchVolume(ev) &&
+		ef.matchNetwork(ev) &&
+		ef.matchImage(ev) &&
+		ef.matchLabels(ev.Actor.Attributes)
 }
 
-func (ef *Filter) isLabelFieldIncluded(attributes map[string]string) bool {
+func (ef *Filter) matchLabels(attributes map[string]string) bool {
 	if !ef.filter.Include("label") {
 		return true
 	}
@@ -35,18 +35,36 @@ func (ef *Filter) isLabelFieldIncluded(attributes map[string]string) bool {
 }
 
 func (ef *Filter) matchContainer(ev events.Message) bool {
-	return ef.filter.FuzzyMatch("container", ev.Actor.ID) ||
-		ef.filter.FuzzyMatch("container", ev.Actor.Attributes["name"])
+	return ef.fuzzyMatchName(ev, events.ContainerEventType)
+}
+
+func (ef *Filter) matchVolume(ev events.Message) bool {
+	return ef.fuzzyMatchName(ev, events.VolumeEventType)
+}
+
+func (ef *Filter) matchNetwork(ev events.Message) bool {
+	return ef.fuzzyMatchName(ev, events.NetworkEventType)
 }
 
-// The image filter will be matched against both event.ID (for image events)
-// and event.From (for container events), so that any container that was created
+func (ef *Filter) fuzzyMatchName(ev events.Message, eventType string) bool {
+	return ef.filter.FuzzyMatch(eventType, ev.Actor.ID) ||
+		ef.filter.FuzzyMatch(eventType, ev.Actor.Attributes["name"])
+}
+
+// matchImage matches against both event.Actor.ID (for image events)
+// and event.Actor.Attributes["image"] (for container events), so that any container that was created
 // from an image will be included in the image events. Also compare both
 // against the stripped repo name without any tags.
-func (ef *Filter) isImageIncluded(ev events.Message) bool {
-	id := ev.ID
+func (ef *Filter) matchImage(ev events.Message) bool {
+	id := ev.Actor.ID
+	nameAttr := "image"
 	var imageName string
-	if n, ok := ev.Actor.Attributes["image"]; ok {
+
+	if ev.Type == events.ImageEventType {
+		nameAttr = "name"
+	}
+
+	if n, ok := ev.Actor.Attributes[nameAttr]; ok {
 		imageName = n
 	}
 	return ef.filter.ExactMatch("image", id) ||

+ 6 - 0
docs/misc/deprecated.md

@@ -12,6 +12,12 @@ parent = "mn_use_docker"
 
 The following list of features are deprecated.
 
+### Ambiguous event fields in API
+**Deprecated In Release: v1.10**
+
+The fields `ID`, `Status` and `From` in the events API have been deprecated in favor of a more rich structure.
+See the events API documentation for the new format.
+
 ### `-f` flag on `docker tag`
 **Deprecated In Release: v1.10**
 

+ 56 - 8
docs/reference/api/docker_remote_api_v1.22.md

@@ -2263,17 +2263,24 @@ Status Codes:
 
 `GET /events`
 
-Get container events from docker, either in real time via streaming, or via
-polling (using since).
+Get container events from docker, either in real time via streaming, or via polling (using since).
 
 Docker containers report the following events:
 
-    attach, commit, copy, create, destroy, die, exec_create, exec_start, export, kill, oom, pause, rename, resize, restart, start, stop, top, unpause
+    attach, commit, copy, create, destroy, die, exec_create, exec_start, export, kill, oom, pause, rename, resize, restart, start, stop, top, unpause, update
 
-and Docker images report:
+Docker images report the following events:
 
     delete, import, pull, push, tag, untag
 
+Docker volumes report the following events:
+
+    create, mount, unmount, destroy
+
+Docker networks report the following events:
+
+    create, connect, disconnect, destroy
+
 **Example request**:
 
     GET /events?since=1374067924
@@ -2283,10 +2290,48 @@ and Docker images report:
     HTTP/1.1 200 OK
     Content-Type: application/json
 
-    {"status":"pull","id":"busybox:latest","time":1442421700,"timeNano":1442421700598988358}
-    {"status":"create","id":"5745704abe9caa5","from":"busybox","time":1442421716,"timeNano":1442421716853979870}
-    {"status":"attach","id":"5745704abe9caa5","from":"busybox","time":1442421716,"timeNano":1442421716894759198}
-    {"status":"start","id":"5745704abe9caa5","from":"busybox","time":1442421716,"timeNano":1442421716983607193}
+    [
+	    {
+		"action": "pull",
+		"type": "image", 
+		"actor": {
+			"id": "busybox:latest",
+			"attributes": {}
+		}
+		"time": 1442421700,
+		"timeNano": 1442421700598988358
+	    },
+            {
+		"action": "create",
+		"type": "container",
+		"actor": {
+			"id": "5745704abe9caa5",
+			"attributes": {"image": "busybox"}
+		}
+		"time": 1442421716,
+		"timeNano": 1442421716853979870
+	    },
+            {
+		"action": "attach",
+		"type": "container",
+		"actor": {
+			"id": "5745704abe9caa5",
+			"attributes": {"image": "busybox"}
+		}
+		"time": 1442421716,
+		"timeNano": 1442421716894759198
+	    },
+            {
+		"action": "start",
+		"type": "container",
+		"actor": {
+			"id": "5745704abe9caa5",
+			"attributes": {"image": "busybox"}
+		}
+		"time": 1442421716,
+		"timeNano": 1442421716983607193
+	    }
+    ]
 
 Query Parameters:
 
@@ -2297,6 +2342,9 @@ Query Parameters:
   -   `event=<string>`; -- event to filter
   -   `image=<string>`; -- image to filter
   -   `label=<string>`; -- image and container label to filter
+  -   `type=<string>`; -- either `container` or `image` or `volume` or `network`
+  -   `volume=<string>`; -- volume to filter
+  -   `network=<string>`; -- network to filter
 
 Status Codes:
 

+ 63 - 42
docs/reference/commandline/events.md

@@ -19,14 +19,22 @@ parent = "smn_cli"
       --since=""         Show all events created since timestamp
       --until=""         Stream events until this timestamp
 
-Docker containers will report the following events:
+Docker containers report the following events:
 
-    attach, commit, copy, create, destroy, die, exec_create, exec_start, export, kill, oom, pause, rename, resize, restart, start, stop, top, unpause
+    attach, commit, copy, create, destroy, die, exec_create, exec_start, export, kill, oom, pause, rename, resize, restart, start, stop, top, unpause, update
 
-and Docker images will report:
+Docker images report the following events:
 
     delete, import, pull, push, tag, untag
 
+Docker volumes report the following events:
+
+    create, mount, unmount, destroy
+
+Docker networks report the following events:
+
+    create, connect, disconnect, destroy
+
 The `--since` and `--until` parameters can be Unix timestamps, date formatted
 timestamps, or Go duration strings (e.g. `10m`, `1h30m`) computed
 relative to the client machine’s time. If you do not provide the --since option,
@@ -57,9 +65,12 @@ container container 588a23dac085 *AND* the event type is *start*
 The currently supported filters are:
 
 * container (`container=<name or id>`)
-* event (`event=<event type>`)
+* event (`event=<event action>`)
 * image (`image=<tag or id>`)
 * label (`label=<key>` or `label=<key>=<value>`)
+* type (`type=<container or image or volume or network>`)
+* volume (`volume=<name or id>`)
+* network (`network=<name or id>`)
 
 ## Examples
 
@@ -77,68 +88,78 @@ You'll need two shells for this example.
 
 **Shell 1: (Again .. now showing events):**
 
-    2014-05-10T17:42:14.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) start
-    2014-05-10T17:42:14.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) die
-    2014-05-10T17:42:14.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) stop
-    2014-05-10T17:42:14.999999999Z07:00 7805c1d35632: (from redis:2.8) die
-    2014-05-10T17:42:14.999999999Z07:00 7805c1d35632: (from redis:2.8) stop
+    2015-05-12T11:51:30.999999999Z07:00 container start 4386fb97867d (image=ubuntu-1:14.04)
+    2015-05-12T11:51:30.999999999Z07:00 container die 4386fb97867d (image=ubuntu-1:14.04)
+    2015-05-12T15:52:12.999999999Z07:00 container stop 4386fb97867d (image=ubuntu-1:14.04)
+    2015-05-12T15:53:45.999999999Z07:00 container die 7805c1d35632 (image=redis:2.8)
+    2015-05-12T15:54:03.999999999Z07:00 container stop 7805c1d35632 (image=redis:2.8)
 
 **Show events in the past from a specified time:**
 
     $ docker events --since 1378216169
-    2014-03-10T17:42:14.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) die
-    2014-05-10T17:42:14.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) stop
-    2014-05-10T17:42:14.999999999Z07:00 7805c1d35632: (from redis:2.8) die
-    2014-03-10T17:42:14.999999999Z07:00 7805c1d35632: (from redis:2.8) stop
+    2015-05-12T11:51:30.999999999Z07:00 container die 4386fb97867d (image=ubuntu-1:14.04)
+    2015-05-12T15:52:12.999999999Z07:00 container stop 4386fb97867d (image=ubuntu-1:14.04)
+    2015-05-12T15:53:45.999999999Z07:00 container die 7805c1d35632 (image=redis:2.8)
+    2015-05-12T15:54:03.999999999Z07:00 container stop 7805c1d35632 (image=redis:2.8)
 
     $ docker events --since '2013-09-03'
-    2014-09-03T17:42:14.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) start
-    2014-09-03T17:42:14.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) die
-    2014-05-10T17:42:14.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) stop
-    2014-05-10T17:42:14.999999999Z07:00 7805c1d35632: (from redis:2.8) die
-    2014-09-03T17:42:14.999999999Z07:00 7805c1d35632: (from redis:2.8) stop
+    2015-05-12T11:51:30.999999999Z07:00 container start 4386fb97867d (image=ubuntu-1:14.04)
+    2015-05-12T11:51:30.999999999Z07:00 container die 4386fb97867d (image=ubuntu-1:14.04)
+    2015-05-12T15:52:12.999999999Z07:00 container stop 4386fb97867d (image=ubuntu-1:14.04)
+    2015-05-12T15:53:45.999999999Z07:00 container die 7805c1d35632 (image=redis:2.8)
+    2015-05-12T15:54:03.999999999Z07:00 container stop 7805c1d35632 (image=redis:2.8)
 
     $ docker events --since '2013-09-03T15:49:29'
-    2014-09-03T15:49:29.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) die
-    2014-05-10T17:42:14.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) stop
-    2014-05-10T17:42:14.999999999Z07:00 7805c1d35632: (from redis:2.8) die
-    2014-09-03T15:49:29.999999999Z07:00 7805c1d35632: (from redis:2.8) stop
+    2015-05-12T11:51:30.999999999Z07:00 container die 4386fb97867d (image=ubuntu-1:14.04)
+    2015-05-12T15:52:12.999999999Z07:00 container stop 4386fb97867d (image=ubuntu-1:14.04)
+    2015-05-12T15:53:45.999999999Z07:00 container die 7805c1d35632 (image=redis:2.8)
+    2015-05-12T15:54:03.999999999Z07:00 container stop 7805c1d35632 (image=redis:2.8)
 
 This example outputs all events that were generated in the last 3 minutes,
 relative to the current time on the client machine:
 
     $ docker events --since '3m'
-    2015-05-12T11:51:30.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) die
-    2015-05-12T15:52:12.999999999Z07:00 4 4386fb97867d: (from ubuntu-1:14.04) stop
-    2015-05-12T15:53:45.999999999Z07:00  7805c1d35632: (from redis:2.8) die
-    2015-05-12T15:54:03.999999999Z07:00  7805c1d35632: (from redis:2.8) stop
+    2015-05-12T11:51:30.999999999Z07:00 container die 4386fb97867d (image=ubuntu-1:14.04)
+    2015-05-12T15:52:12.999999999Z07:00 container stop 4386fb97867d (image=ubuntu-1:14.04)
+    2015-05-12T15:53:45.999999999Z07:00 container die 7805c1d35632 (image=redis:2.8)
+    2015-05-12T15:54:03.999999999Z07:00 container stop 7805c1d35632 (image=redis:2.8)
 
 **Filter events:**
 
     $ docker events --filter 'event=stop'
-    2014-05-10T17:42:14.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) stop
-    2014-09-03T17:42:14.999999999Z07:00 7805c1d35632: (from redis:2.8) stop
+    2014-05-10T17:42:14.999999999Z07:00 container stop 4386fb97867d (image=ubuntu-1:14.04)
+    2014-09-03T17:42:14.999999999Z07:00 container stop 7805c1d35632 (image=redis:2.8)
 
     $ docker events --filter 'image=ubuntu-1:14.04'
-    2014-05-10T17:42:14.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) start
-    2014-05-10T17:42:14.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) die
-    2014-05-10T17:42:14.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) stop
+    2014-05-10T17:42:14.999999999Z07:00 container start 4386fb97867d (image=ubuntu-1:14.04)
+    2014-05-10T17:42:14.999999999Z07:00 container die 4386fb97867d (image=ubuntu-1:14.04)
+    2014-05-10T17:42:14.999999999Z07:00 container stop 4386fb97867d (image=ubuntu-1:14.04)
 
     $ docker events --filter 'container=7805c1d35632'
-    2014-05-10T17:42:14.999999999Z07:00 7805c1d35632: (from redis:2.8) die
-    2014-09-03T15:49:29.999999999Z07:00 7805c1d35632: (from redis:2.8) stop
+    2014-05-10T17:42:14.999999999Z07:00 container die 7805c1d35632 (image=redis:2.8)
+    2014-09-03T15:49:29.999999999Z07:00 container stop 7805c1d35632 (image= redis:2.8)
 
     $ docker events --filter 'container=7805c1d35632' --filter 'container=4386fb97867d'
-    2014-09-03T15:49:29.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) die
-    2014-05-10T17:42:14.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) stop
-    2014-05-10T17:42:14.999999999Z07:00 7805c1d35632: (from redis:2.8) die
-    2014-09-03T15:49:29.999999999Z07:00 7805c1d35632: (from redis:2.8) stop
+    2014-09-03T15:49:29.999999999Z07:00 container die 4386fb97867d (image=ubuntu-1:14.04)
+    2014-05-10T17:42:14.999999999Z07:00 container stop 4386fb97867d (image=ubuntu-1:14.04)
+    2014-05-10T17:42:14.999999999Z07:00 container die 7805c1d35632 (image=redis:2.8)
+    2014-09-03T15:49:29.999999999Z07:00 container stop 7805c1d35632 (image=redis:2.8)
 
     $ docker events --filter 'container=7805c1d35632' --filter 'event=stop'
-    2014-09-03T15:49:29.999999999Z07:00 7805c1d35632: (from redis:2.8) stop
+    2014-09-03T15:49:29.999999999Z07:00 container stop 7805c1d35632 (image=redis:2.8)
 
     $ docker events --filter 'container=container_1' --filter 'container=container_2'
-    2014-09-03T15:49:29.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) die
-    2014-05-10T17:42:14.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) stop
-    2014-05-10T17:42:14.999999999Z07:00 7805c1d35632: (from redis:2.8) die
-    2014-09-03T15:49:29.999999999Z07:00 7805c1d35632: (from redis:2.8) stop
+    2014-09-03T15:49:29.999999999Z07:00 container die 4386fb97867d (image=ubuntu-1:14.04)
+    2014-05-10T17:42:14.999999999Z07:00 container stop 4386fb97867d (image=ubuntu-1:14.04)
+    2014-05-10T17:42:14.999999999Z07:00 container die 7805c1d35632 (imager=redis:2.8)
+    2014-09-03T15:49:29.999999999Z07:00 container stop 7805c1d35632 (image=redis:2.8)
+
+    $ docker events --filter 'type=volume'
+    2015-12-23T21:05:28.136212689Z volume create test-event-volume-local (driver=local)
+    2015-12-23T21:05:28.383462717Z volume mount test-event-volume-local (read/write=true, container=562fe10671e9273da25eed36cdce26159085ac7ee6707105fd534866340a5025, destination=/foo, driver=local, propagation=rprivate)
+    2015-12-23T21:05:28.650314265Z volume unmount test-event-volume-local (container=562fe10671e9273da25eed36cdce26159085ac7ee6707105fd534866340a5025, driver=local)
+    2015-12-23T21:05:28.716218405Z volume destroy test-event-volume-local (driver=local)
+
+    $ docker events --filter 'type=network'
+    2015-12-23T21:38:24.705709133Z network create 8b111217944ba0ba844a65b13efcd57dc494932ee2527577758f939315ba2c5b (name=test-event-network-local, type=bridge)
+    2015-12-23T21:38:25.119625123Z network connect 8b111217944ba0ba844a65b13efcd57dc494932ee2527577758f939315ba2c5b (name=test-event-network-local, container=b4be644031a3d90b400f88ab3d4bdf4dc23adb250e696b6328b85441abe2c54e, type=bridge)

+ 0 - 85
integration-cli/docker_cli_build_test.go

@@ -2,7 +2,6 @@ package main
 
 import (
 	"archive/tar"
-	"bufio"
 	"bytes"
 	"encoding/json"
 	"fmt"
@@ -1863,90 +1862,6 @@ func (s *DockerSuite) TestBuildForceRm(c *check.C) {
 
 }
 
-// Test that an infinite sleep during a build is killed if the client disconnects.
-// This test is fairly hairy because there are lots of ways to race.
-// Strategy:
-// * Monitor the output of docker events starting from before
-// * Run a 1-year-long sleep from a docker build.
-// * When docker events sees container start, close the "docker build" command
-// * Wait for docker events to emit a dying event.
-func (s *DockerSuite) TestBuildCancellationKillsSleep(c *check.C) {
-	testRequires(c, DaemonIsLinux)
-	name := "testbuildcancellation"
-
-	observer, err := newEventObserver(c)
-	c.Assert(err, checker.IsNil)
-	err = observer.Start()
-	c.Assert(err, checker.IsNil)
-	defer observer.Stop()
-
-	// (Note: one year, will never finish)
-	ctx, err := fakeContext("FROM busybox\nRUN sleep 31536000", nil)
-	if err != nil {
-		c.Fatal(err)
-	}
-	defer ctx.Close()
-
-	buildCmd := exec.Command(dockerBinary, "build", "-t", name, ".")
-	buildCmd.Dir = ctx.Dir
-
-	stdoutBuild, err := buildCmd.StdoutPipe()
-	if err := buildCmd.Start(); err != nil {
-		c.Fatalf("failed to run build: %s", err)
-	}
-
-	matchCID := regexp.MustCompile("Running in (.+)")
-	scanner := bufio.NewScanner(stdoutBuild)
-
-	outputBuffer := new(bytes.Buffer)
-	var buildID string
-	for scanner.Scan() {
-		line := scanner.Text()
-		outputBuffer.WriteString(line)
-		outputBuffer.WriteString("\n")
-		if matches := matchCID.FindStringSubmatch(line); len(matches) > 0 {
-			buildID = matches[1]
-			break
-		}
-	}
-
-	if buildID == "" {
-		c.Fatalf("Unable to find build container id in build output:\n%s", outputBuffer.String())
-	}
-
-	testActions := map[string]chan bool{
-		"start": make(chan bool),
-		"die":   make(chan bool),
-	}
-
-	go observer.Match(matchEventLine(buildID, "container", testActions))
-
-	select {
-	case <-time.After(10 * time.Second):
-		c.Fatal(observer.TimeoutError(buildID, "start"))
-	case <-testActions["start"]:
-		// ignore, done
-	}
-
-	// Send a kill to the `docker build` command.
-	// Causes the underlying build to be cancelled due to socket close.
-	if err := buildCmd.Process.Kill(); err != nil {
-		c.Fatalf("error killing build command: %s", err)
-	}
-
-	// Get the exit status of `docker build`, check it exited because killed.
-	if err := buildCmd.Wait(); err != nil && !isKilled(err) {
-		c.Fatalf("wait failed during build run: %T %s", err, err)
-	}
-
-	select {
-	case <-time.After(10 * time.Second):
-		c.Fatal(observer.TimeoutError(buildID, "die"))
-	case <-testActions["die"]:
-		// ignore, done
-	}
-}
-
 func (s *DockerSuite) TestBuildRm(c *check.C) {
 	testRequires(c, DaemonIsLinux)
 	name := "testbuildrm"

+ 88 - 0
integration-cli/docker_cli_build_unix_test.go

@@ -3,12 +3,16 @@
 package main
 
 import (
+	"bufio"
+	"bytes"
 	"encoding/json"
 	"io/ioutil"
 	"os"
 	"os/exec"
 	"path/filepath"
+	"regexp"
 	"strings"
+	"time"
 
 	"github.com/docker/docker/pkg/integration/checker"
 	"github.com/docker/go-units"
@@ -115,5 +119,89 @@ func (s *DockerSuite) TestBuildAddChangeOwnership(c *check.C) {
 	if _, err := buildImageFromContext(name, ctx, true); err != nil {
 		c.Fatalf("build failed to complete for TestBuildAddChangeOwnership: %v", err)
 	}
+}
+
+// Test that an infinite sleep during a build is killed if the client disconnects.
+// This test is fairly hairy because there are lots of ways to race.
+// Strategy:
+// * Monitor the output of docker events starting from before
+// * Run a 1-year-long sleep from a docker build.
+// * When docker events sees container start, close the "docker build" command
+// * Wait for docker events to emit a dying event.
+func (s *DockerSuite) TestBuildCancellationKillsSleep(c *check.C) {
+	testRequires(c, DaemonIsLinux)
+	name := "testbuildcancellation"
+
+	observer, err := newEventObserver(c)
+	c.Assert(err, checker.IsNil)
+	err = observer.Start()
+	c.Assert(err, checker.IsNil)
+	defer observer.Stop()
 
+	// (Note: one year, will never finish)
+	ctx, err := fakeContext("FROM busybox\nRUN sleep 31536000", nil)
+	if err != nil {
+		c.Fatal(err)
+	}
+	defer ctx.Close()
+
+	buildCmd := exec.Command(dockerBinary, "build", "-t", name, ".")
+	buildCmd.Dir = ctx.Dir
+
+	stdoutBuild, err := buildCmd.StdoutPipe()
+	if err := buildCmd.Start(); err != nil {
+		c.Fatalf("failed to run build: %s", err)
+	}
+
+	matchCID := regexp.MustCompile("Running in (.+)")
+	scanner := bufio.NewScanner(stdoutBuild)
+
+	outputBuffer := new(bytes.Buffer)
+	var buildID string
+	for scanner.Scan() {
+		line := scanner.Text()
+		outputBuffer.WriteString(line)
+		outputBuffer.WriteString("\n")
+		if matches := matchCID.FindStringSubmatch(line); len(matches) > 0 {
+			buildID = matches[1]
+			break
+		}
+	}
+
+	if buildID == "" {
+		c.Fatalf("Unable to find build container id in build output:\n%s", outputBuffer.String())
+	}
+
+	testActions := map[string]chan bool{
+		"start": make(chan bool),
+		"die":   make(chan bool),
+	}
+
+	matcher := matchEventLine(buildID, "container", testActions)
+	go observer.Match(matcher)
+
+	select {
+	case <-time.After(10 * time.Second):
+		observer.CheckEventError(c, buildID, "start", matcher)
+	case <-testActions["start"]:
+		// ignore, done
+	}
+
+	// Send a kill to the `docker build` command.
+	// Causes the underlying build to be cancelled due to socket close.
+	if err := buildCmd.Process.Kill(); err != nil {
+		c.Fatalf("error killing build command: %s", err)
+	}
+
+	// Get the exit status of `docker build`, check it exited because killed.
+	if err := buildCmd.Wait(); err != nil && !isKilled(err) {
+		c.Fatalf("wait failed during build run: %T %s", err, err)
+	}
+
+	select {
+	case <-time.After(10 * time.Second):
+		observer.CheckEventError(c, buildID, "die", matcher)
+	case <-testActions["die"]:
+		// ignore, done
+	}
 }

+ 83 - 85
integration-cli/docker_cli_events_test.go

@@ -72,13 +72,25 @@ func (s *DockerSuite) TestEventsContainerFailStartDie(c *check.C) {
 	c.Assert(err, checker.NotNil, check.Commentf("Container run with command blerg should have failed, but it did not, out=%s", out))
 
 	out, _ = dockerCmd(c, "events", "--since=0", fmt.Sprintf("--until=%d", daemonTime(c).Unix()))
-	events := strings.Split(out, "\n")
+	events := strings.Split(strings.TrimSpace(out), "\n")
 
 	nEvents := len(events)
 	c.Assert(nEvents, checker.GreaterOrEqualThan, 1) //Missing expected event
 
-	c.Assert(parseEventAction(c, events[nEvents-3]), checker.Equals, "start")
-	c.Assert(parseEventAction(c, events[nEvents-2]), checker.Equals, "die")
+	actions := eventActionsByIDAndType(c, events, "testeventdie", "container")
+
+	var startEvent bool
+	var dieEvent bool
+	for _, a := range actions {
+		switch a {
+		case "start":
+			startEvent = true
+		case "die":
+			dieEvent = true
+		}
+	}
+	c.Assert(startEvent, checker.True, check.Commentf("Start event not found: %v\n%v", actions, events))
+	c.Assert(dieEvent, checker.True, check.Commentf("Die event not found: %v\n%v", actions, events))
 }
 
 func (s *DockerSuite) TestEventsLimit(c *check.C) {
@@ -150,45 +162,6 @@ func (s *DockerSuite) TestEventsContainerEventsSinceUnixEpoch(c *check.C) {
 	c.Assert(containerEvents[4], checker.Equals, "destroy", check.Commentf(out))
 }
 
-func (s *DockerSuite) TestEventsImageUntagDelete(c *check.C) {
-	testRequires(c, DaemonIsLinux)
-
-	observer, err := newEventObserver(c)
-	c.Assert(err, checker.IsNil)
-	err = observer.Start()
-	c.Assert(err, checker.IsNil)
-	defer observer.Stop()
-
-	name := "testimageevents"
-	imageID, err := buildImage(name,
-		`FROM scratch
-		MAINTAINER "docker"`,
-		true)
-	c.Assert(err, checker.IsNil)
-	c.Assert(deleteImages(name), checker.IsNil)
-
-	testActions := map[string]chan bool{
-		"untag":  make(chan bool),
-		"delete": make(chan bool),
-	}
-
-	go observer.Match(matchEventLine(imageID, "image", testActions))
-
-	select {
-	case <-time.After(10 * time.Second):
-		c.Fatal(observer.TimeoutError(imageID, "untag"))
-	case <-testActions["untag"]:
-		// ignore, done
-	}
-
-	select {
-	case <-time.After(10 * time.Second):
-		c.Fatal(observer.TimeoutError(imageID, "delete"))
-	case <-testActions["delete"]:
-		// ignore, done
-	}
-}
-
 func (s *DockerSuite) TestEventsImageTag(c *check.C) {
 	testRequires(c, DaemonIsLinux)
 	time.Sleep(1 * time.Second) // because API has seconds granularity
@@ -205,7 +178,6 @@ func (s *DockerSuite) TestEventsImageTag(c *check.C) {
 	event := strings.TrimSpace(events[0])
 
 	matches := parseEventText(event)
-	c.Assert(matches, checker.Not(checker.IsNil))
 	c.Assert(matchEventID(matches, image), checker.True, check.Commentf("matches: %v\nout:\n%s", matches, out))
 	c.Assert(matches["action"], checker.Equals, "tag")
 }
@@ -224,7 +196,6 @@ func (s *DockerSuite) TestEventsImagePull(c *check.C) {
 	events := strings.Split(strings.TrimSpace(out), "\n")
 	event := strings.TrimSpace(events[len(events)-1])
 	matches := parseEventText(event)
-	c.Assert(matches, checker.Not(checker.IsNil))
 	c.Assert(matches["id"], checker.Equals, "hello-world:latest")
 	c.Assert(matches["action"], checker.Equals, "pull")
 
@@ -348,7 +319,8 @@ func (s *DockerSuite) TestEventsFilterImageLabels(c *check.C) {
 		"events",
 		fmt.Sprintf("--since=%d", since),
 		fmt.Sprintf("--until=%d", daemonTime(c).Unix()),
-		"--filter", fmt.Sprintf("label=%s", label))
+		"--filter", fmt.Sprintf("label=%s", label),
+		"--filter", "type=image")
 
 	events := strings.Split(strings.TrimSpace(out), "\n")
 
@@ -399,46 +371,6 @@ func (s *DockerSuite) TestEventsFilterContainer(c *check.C) {
 	}
 }
 
-func (s *DockerSuite) TestEventsStreaming(c *check.C) {
-	testRequires(c, DaemonIsLinux)
-
-	observer, err := newEventObserver(c)
-	c.Assert(err, checker.IsNil)
-	err = observer.Start()
-	c.Assert(err, checker.IsNil)
-	defer observer.Stop()
-
-	out, _ := dockerCmd(c, "run", "-d", "busybox:latest", "true")
-	containerID := strings.TrimSpace(out)
-
-	testActions := map[string]chan bool{
-		"create":  make(chan bool),
-		"start":   make(chan bool),
-		"die":     make(chan bool),
-		"destroy": make(chan bool),
-	}
-
-	go observer.Match(matchEventLine(containerID, "container", testActions))
-
-	select {
-	case <-time.After(5 * time.Second):
-		c.Fatal(observer.TimeoutError(containerID, "create/start/die"))
-	case <-testActions["create"]:
-	case <-testActions["start"]:
-	case <-testActions["die"]:
-		// ignore, done
-	}
-
-	dockerCmd(c, "rm", containerID)
-
-	select {
-	case <-time.After(5 * time.Second):
-		c.Fatal(observer.TimeoutError(containerID, "destroy"))
-	case <-testActions["destroy"]:
-		// ignore, done
-	}
-}
-
 func (s *DockerSuite) TestEventsCommit(c *check.C) {
 	testRequires(c, DaemonIsLinux)
 	since := daemonTime(c).Unix()
@@ -587,3 +519,69 @@ func (s *DockerRegistrySuite) TestEventsImageFilterPush(c *check.C) {
 	out, _ = dockerCmd(c, "events", "--since=0", "-f", "image="+repoName, "-f", "event=push", "--until="+strconv.Itoa(int(since)))
 	c.Assert(out, checker.Contains, repoName, check.Commentf("Missing 'push' log event for %s", repoName))
 }
+
+func (s *DockerSuite) TestEventsFilterType(c *check.C) {
+	testRequires(c, DaemonIsLinux)
+	since := daemonTime(c).Unix()
+	name := "labelfiltertest"
+	label := "io.docker.testing=image"
+
+	// Build a test image.
+	_, err := buildImage(name, fmt.Sprintf(`
+		FROM busybox:latest
+		LABEL %s`, label), true)
+	c.Assert(err, checker.IsNil, check.Commentf("Couldn't create image"))
+
+	dockerCmd(c, "tag", name, "labelfiltertest:tag1")
+	dockerCmd(c, "tag", name, "labelfiltertest:tag2")
+	dockerCmd(c, "tag", "busybox:latest", "labelfiltertest:tag3")
+
+	out, _ := dockerCmd(
+		c,
+		"events",
+		fmt.Sprintf("--since=%d", since),
+		fmt.Sprintf("--until=%d", daemonTime(c).Unix()),
+		"--filter", fmt.Sprintf("label=%s", label),
+		"--filter", "type=image")
+
+	events := strings.Split(strings.TrimSpace(out), "\n")
+
+	// 2 events from the "docker tag" command, another one is from "docker build"
+	c.Assert(events, checker.HasLen, 3, check.Commentf("Events == %s", events))
+	for _, e := range events {
+		c.Assert(e, checker.Contains, "labelfiltertest")
+	}
+
+	out, _ = dockerCmd(
+		c,
+		"events",
+		fmt.Sprintf("--since=%d", since),
+		fmt.Sprintf("--until=%d", daemonTime(c).Unix()),
+		"--filter", fmt.Sprintf("label=%s", label),
+		"--filter", "type=container")
+	events = strings.Split(strings.TrimSpace(out), "\n")
+
+	// Events generated by the container that builds the image
+	c.Assert(events, checker.HasLen, 3, check.Commentf("Events == %s", events))
+
+	out, _ = dockerCmd(
+		c,
+		"events",
+		fmt.Sprintf("--since=%d", since),
+		fmt.Sprintf("--until=%d", daemonTime(c).Unix()),
+		"--filter", "type=network")
+	events = strings.Split(strings.TrimSpace(out), "\n")
+	c.Assert(len(events), checker.GreaterOrEqualThan, 1, check.Commentf("Events == %s", events))
+}
+
+func (s *DockerSuite) TestEventsFilterImageInContainerAction(c *check.C) {
+	testRequires(c, DaemonIsLinux)
+
+	since := daemonTime(c).Unix()
+	dockerCmd(c, "run", "--name", "test-container", "-d", "busybox", "true")
+	waitRun("test-container")
+
+	out, _ := dockerCmd(c, "events", "--filter", "image=busybox", fmt.Sprintf("--since=%d", since), fmt.Sprintf("--until=%d", daemonTime(c).Unix()))
+	events := strings.Split(strings.TrimSpace(out), "\n")
+	c.Assert(len(events), checker.GreaterThan, 1, check.Commentf(out))
+}

+ 140 - 0
integration-cli/docker_cli_events_unix_test.go

@@ -203,3 +203,143 @@ func (s *DockerSuite) TestNetworkEvents(c *check.C) {
 	c.Assert(netEvents[2], checker.Equals, "disconnect")
 	c.Assert(netEvents[3], checker.Equals, "destroy")
 }
+
+func (s *DockerSuite) TestEventsStreaming(c *check.C) {
+	testRequires(c, DaemonIsLinux)
+
+	observer, err := newEventObserver(c)
+	c.Assert(err, checker.IsNil)
+	err = observer.Start()
+	c.Assert(err, checker.IsNil)
+	defer observer.Stop()
+
+	out, _ := dockerCmd(c, "run", "-d", "busybox:latest", "true")
+	containerID := strings.TrimSpace(out)
+
+	testActions := map[string]chan bool{
+		"create":  make(chan bool),
+		"start":   make(chan bool),
+		"die":     make(chan bool),
+		"destroy": make(chan bool),
+	}
+
+	matcher := matchEventLine(containerID, "container", testActions)
+	go observer.Match(matcher)
+
+	select {
+	case <-time.After(5 * time.Second):
+		observer.CheckEventError(c, containerID, "create", matcher)
+	case <-testActions["create"]:
+		// ignore, done
+	}
+
+	select {
+	case <-time.After(5 * time.Second):
+		observer.CheckEventError(c, containerID, "start", matcher)
+	case <-testActions["start"]:
+		// ignore, done
+	}
+
+	select {
+	case <-time.After(5 * time.Second):
+		observer.CheckEventError(c, containerID, "die", matcher)
+	case <-testActions["die"]:
+		// ignore, done
+	}
+
+	dockerCmd(c, "rm", containerID)
+
+	select {
+	case <-time.After(5 * time.Second):
+		observer.CheckEventError(c, containerID, "destroy", matcher)
+	case <-testActions["destroy"]:
+		// ignore, done
+	}
+}
+
+func (s *DockerSuite) TestEventsImageUntagDelete(c *check.C) {
+	testRequires(c, DaemonIsLinux)
+
+	observer, err := newEventObserver(c)
+	c.Assert(err, checker.IsNil)
+	err = observer.Start()
+	c.Assert(err, checker.IsNil)
+	defer observer.Stop()
+
+	name := "testimageevents"
+	imageID, err := buildImage(name,
+		`FROM scratch
+		MAINTAINER "docker"`,
+		true)
+	c.Assert(err, checker.IsNil)
+	c.Assert(deleteImages(name), checker.IsNil)
+
+	testActions := map[string]chan bool{
+		"untag":  make(chan bool),
+		"delete": make(chan bool),
+	}
+
+	matcher := matchEventLine(imageID, "image", testActions)
+	go observer.Match(matcher)
+
+	select {
+	case <-time.After(10 * time.Second):
+		observer.CheckEventError(c, imageID, "untag", matcher)
+	case <-testActions["untag"]:
+		// ignore, done
+	}
+
+	select {
+	case <-time.After(10 * time.Second):
+		observer.CheckEventError(c, imageID, "delete", matcher)
+	case <-testActions["delete"]:
+		// ignore, done
+	}
+}
+
+func (s *DockerSuite) TestEventsFilterVolumeAndNetworkType(c *check.C) {
+	testRequires(c, DaemonIsLinux)
+
+	since := daemonTime(c).Unix()
+
+	dockerCmd(c, "network", "create", "test-event-network-type")
+	dockerCmd(c, "volume", "create", "--name", "test-event-volume-type")
+
+	out, _ := dockerCmd(c, "events", "--filter", "type=volume", "--filter", "type=network", fmt.Sprintf("--since=%d", since), fmt.Sprintf("--until=%d", daemonTime(c).Unix()))
+	events := strings.Split(strings.TrimSpace(out), "\n")
+	c.Assert(len(events), checker.GreaterOrEqualThan, 2, check.Commentf(out))
+
+	networkActions := eventActionsByIDAndType(c, events, "test-event-network-type", "network")
+	volumeActions := eventActionsByIDAndType(c, events, "test-event-volume-type", "volume")
+
+	c.Assert(volumeActions[0], checker.Equals, "create")
+	c.Assert(networkActions[0], checker.Equals, "create")
+}
+
+func (s *DockerSuite) TestEventsFilterVolumeID(c *check.C) {
+	testRequires(c, DaemonIsLinux)
+
+	since := daemonTime(c).Unix()
+
+	dockerCmd(c, "volume", "create", "--name", "test-event-volume-id")
+	out, _ := dockerCmd(c, "events", "--filter", "volume=test-event-volume-id", fmt.Sprintf("--since=%d", since), fmt.Sprintf("--until=%d", daemonTime(c).Unix()))
+	events := strings.Split(strings.TrimSpace(out), "\n")
+	c.Assert(events, checker.HasLen, 1)
+
+	c.Assert(events[0], checker.Contains, "test-event-volume-id")
+	c.Assert(events[0], checker.Contains, "driver=local")
+}
+
+func (s *DockerSuite) TestEventsFilterNetworkID(c *check.C) {
+	testRequires(c, DaemonIsLinux)
+
+	since := daemonTime(c).Unix()
+
+	dockerCmd(c, "network", "create", "test-event-network-local")
+	out, _ := dockerCmd(c, "events", "--filter", "network=test-event-network-local", fmt.Sprintf("--since=%d", since), fmt.Sprintf("--until=%d", daemonTime(c).Unix()))
+	events := strings.Split(strings.TrimSpace(out), "\n")
+	c.Assert(events, checker.HasLen, 1)
+
+	c.Assert(events[0], checker.Contains, "test-event-network-local")
+	c.Assert(events[0], checker.Contains, "type=bridge")
+}

+ 50 - 30
integration-cli/events_utils.go

@@ -10,6 +10,7 @@ import (
 	"strconv"
 	"strings"
 
+	"github.com/Sirupsen/logrus"
 	"github.com/docker/docker/pkg/integration/checker"
 	"github.com/go-check/check"
 )
@@ -27,13 +28,15 @@ var (
 )
 
 // eventMatcher is a function that tries to match an event input.
-type eventMatcher func(text string)
+type eventMatcher func(text string) bool
 
 // eventObserver runs an events commands and observes its output.
 type eventObserver struct {
-	buffer  *bytes.Buffer
-	command *exec.Cmd
-	stdout  io.Reader
+	buffer             *bytes.Buffer
+	command            *exec.Cmd
+	scanner            *bufio.Scanner
+	startTime          string
+	disconnectionError error
 }
 
 // newEventObserver creates the observer and initializes the command
@@ -45,7 +48,8 @@ func newEventObserver(c *check.C, args ...string) (*eventObserver, error) {
 
 // newEventObserverWithBacklog creates a new observer changing the start time of the backlog to return.
 func newEventObserverWithBacklog(c *check.C, since int64, args ...string) (*eventObserver, error) {
-	cmdArgs := []string{"events", "--since", strconv.FormatInt(since, 10)}
+	startTime := strconv.FormatInt(since, 10)
+	cmdArgs := []string{"events", "--since", startTime}
 	if len(args) > 0 {
 		cmdArgs = append(cmdArgs, args...)
 	}
@@ -56,9 +60,10 @@ func newEventObserverWithBacklog(c *check.C, since int64, args ...string) (*even
 	}
 
 	return &eventObserver{
-		buffer:  new(bytes.Buffer),
-		command: eventsCmd,
-		stdout:  stdout,
+		buffer:    new(bytes.Buffer),
+		command:   eventsCmd,
+		scanner:   bufio.NewScanner(stdout),
+		startTime: startTime,
 	}, nil
 }
 
@@ -75,43 +80,61 @@ func (e *eventObserver) Stop() {
 
 // Match tries to match the events output with a given matcher.
 func (e *eventObserver) Match(match eventMatcher) {
-	scanner := bufio.NewScanner(e.stdout)
-
-	for scanner.Scan() {
-		text := scanner.Text()
+	for e.scanner.Scan() {
+		text := e.scanner.Text()
 		e.buffer.WriteString(text)
 		e.buffer.WriteString("\n")
 
 		match(text)
 	}
-}
 
-// TimeoutError generates an error for a given containerID and event type.
-// It attaches the events command output to the error.
-func (e *eventObserver) TimeoutError(id, event string) error {
-	return fmt.Errorf("failed to observe event `%s` for %s\n%v", event, id, e.output())
+	err := e.scanner.Err()
+	if err == nil {
+		err = io.EOF
+	}
+
+	logrus.Debug("EventObserver scanner loop finished: %v", err)
+	e.disconnectionError = err
 }
 
-// output returns the events command output read until now by the Match goroutine.
-func (e *eventObserver) output() string {
-	return e.buffer.String()
+func (e *eventObserver) CheckEventError(c *check.C, id, event string, match eventMatcher) {
+	var foundEvent bool
+	scannerOut := e.buffer.String()
+
+	if e.disconnectionError != nil {
+		until := strconv.FormatInt(daemonTime(c).Unix(), 10)
+		out, _ := dockerCmd(c, "events", "--since", e.startTime, "--until", until)
+		events := strings.Split(strings.TrimSpace(out), "\n")
+		for _, e := range events {
+			if match(e) {
+				foundEvent = true
+				break
+			}
+		}
+		scannerOut = out
+	}
+	if !foundEvent {
+		c.Fatalf("failed to observe event `%s` for %s. Disconnection error: %v\nout:\n%v", event, id, e.disconnectionError, scannerOut)
+	}
 }
 
 // matchEventLine matches a text with the event regular expression.
 // It returns the action and true if the regular expression matches with the given id and event type.
 // It returns an empty string and false if there is no match.
 func matchEventLine(id, eventType string, actions map[string]chan bool) eventMatcher {
-	return func(text string) {
+	return func(text string) bool {
 		matches := parseEventText(text)
-		if matches == nil {
-			return
+		if len(matches) == 0 {
+			return false
 		}
 
 		if matchIDAndEventType(matches, id, eventType) {
 			if ch, ok := actions[matches["action"]]; ok {
 				close(ch)
+				return true
 			}
 		}
+		return false
 	}
 }
 
@@ -119,12 +142,12 @@ func matchEventLine(id, eventType string, actions map[string]chan bool) eventMat
 // the matchers in a map.
 func parseEventText(text string) map[string]string {
 	matches := eventCliRegexp.FindAllStringSubmatch(text, -1)
+	md := map[string]string{}
 	if len(matches) == 0 {
-		return nil
+		return md
 	}
 
 	names := eventCliRegexp.SubexpNames()
-	md := map[string]string{}
 	for i, n := range matches[0] {
 		md[names[i]] = n
 	}
@@ -135,7 +158,6 @@ func parseEventText(text string) map[string]string {
 // It fails if the text is not in the event format.
 func parseEventAction(c *check.C, text string) string {
 	matches := parseEventText(text)
-	c.Assert(matches, checker.Not(checker.IsNil))
 	return matches["action"]
 }
 
@@ -177,10 +199,9 @@ func parseEvents(c *check.C, out, match string) {
 	events := strings.Split(strings.TrimSpace(out), "\n")
 	for _, event := range events {
 		matches := parseEventText(event)
-		c.Assert(matches, checker.Not(checker.IsNil))
 		matched, err := regexp.MatchString(match, matches["action"])
 		c.Assert(err, checker.IsNil)
-		c.Assert(matched, checker.True)
+		c.Assert(matched, checker.True, check.Commentf("Matcher: %s did not match %s", match, matches["action"]))
 	}
 }
 
@@ -188,11 +209,10 @@ func parseEventsWithID(c *check.C, out, match, id string) {
 	events := strings.Split(strings.TrimSpace(out), "\n")
 	for _, event := range events {
 		matches := parseEventText(event)
-		c.Assert(matches, checker.Not(checker.IsNil))
 		c.Assert(matchEventID(matches, id), checker.True)
 
 		matched, err := regexp.MatchString(match, matches["action"])
 		c.Assert(err, checker.IsNil)
-		c.Assert(matched, checker.True)
+		c.Assert(matched, checker.True, check.Commentf("Matcher: %s did not match %s", match, matches["action"]))
 	}
 }