1
0
Fork 0
mirror of https://github.com/moby/moby.git synced 2022-11-09 12:21:53 -05:00
moby--moby/daemon/events/events_test.go
Doug Davis 26b1064967 Add context.RequestID to event stream
This PR adds a "request ID" to each event generated, the 'docker events'
stream now looks like this:

```
2015-09-10T15:02:50.000000000-07:00 [reqid: c01e3534ddca] de7c5d4ca927253cf4e978ee9c4545161e406e9b5a14617efb52c658b249174a: (from ubuntu) create
```
Note the `[reqID: c01e3534ddca]` part, that's new.

Each HTTP request will generate its own unique ID. So, if you do a
`docker build` you'll see a series of events all with the same reqID.
This allow for log processing tools to determine which events are all related
to the same http request.

I didn't propigate the context to all possible funcs in the daemon,
I decided to just do the ones that needed it in order to get the reqID
into the events. I'd like to have people review this direction first, and
if we're ok with it then I'll make sure we're consistent about when
we pass around the context - IOW, make sure that all funcs at the same level
have a context passed in even if they don't call the log funcs - this will
ensure we're consistent w/o passing it around for all calls unnecessarily.

ping @icecrime @calavera @crosbymichael

Signed-off-by: Doug Davis <dug@us.ibm.com>
2015-09-24 11:56:37 -07:00

139 lines
3.3 KiB
Go

package events
import (
"fmt"
"testing"
"time"
"github.com/docker/docker/context"
"github.com/docker/docker/pkg/jsonmessage"
)
func TestEventsLog(t *testing.T) {
ctx := context.Background()
e := New()
_, l1 := e.Subscribe()
_, l2 := e.Subscribe()
defer e.Evict(l1)
defer e.Evict(l2)
count := e.SubscribersCount()
if count != 2 {
t.Fatalf("Must be 2 subscribers, got %d", count)
}
e.Log(ctx, "test", "cont", "image")
select {
case msg := <-l1:
jmsg, ok := msg.(*jsonmessage.JSONMessage)
if !ok {
t.Fatalf("Unexpected type %T", msg)
}
if len(e.events) != 1 {
t.Fatalf("Must be only one event, got %d", len(e.events))
}
if jmsg.Status != "test" {
t.Fatalf("Status should be test, got %s", jmsg.Status)
}
if jmsg.ID != "cont" {
t.Fatalf("ID should be cont, got %s", jmsg.ID)
}
if jmsg.From != "image" {
t.Fatalf("From should be image, got %s", jmsg.From)
}
case <-time.After(1 * time.Second):
t.Fatal("Timeout waiting for broadcasted message")
}
select {
case msg := <-l2:
jmsg, ok := msg.(*jsonmessage.JSONMessage)
if !ok {
t.Fatalf("Unexpected type %T", msg)
}
if len(e.events) != 1 {
t.Fatalf("Must be only one event, got %d", len(e.events))
}
if jmsg.Status != "test" {
t.Fatalf("Status should be test, got %s", jmsg.Status)
}
if jmsg.ID != "cont" {
t.Fatalf("ID should be cont, got %s", jmsg.ID)
}
if jmsg.From != "image" {
t.Fatalf("From should be image, got %s", jmsg.From)
}
case <-time.After(1 * time.Second):
t.Fatal("Timeout waiting for broadcasted message")
}
}
func TestEventsLogTimeout(t *testing.T) {
ctx := context.Background()
e := New()
_, l := e.Subscribe()
defer e.Evict(l)
c := make(chan struct{})
go func() {
e.Log(ctx, "test", "cont", "image")
close(c)
}()
select {
case <-c:
case <-time.After(time.Second):
t.Fatal("Timeout publishing message")
}
}
func TestLogEvents(t *testing.T) {
ctx := context.Background()
e := New()
for i := 0; i < eventsLimit+16; i++ {
action := fmt.Sprintf("action_%d", i)
id := fmt.Sprintf("cont_%d", i)
from := fmt.Sprintf("image_%d", i)
e.Log(ctx, action, id, from)
}
time.Sleep(50 * time.Millisecond)
current, l := e.Subscribe()
for i := 0; i < 10; i++ {
num := i + eventsLimit + 16
action := fmt.Sprintf("action_%d", num)
id := fmt.Sprintf("cont_%d", num)
from := fmt.Sprintf("image_%d", num)
e.Log(ctx, action, id, from)
}
if len(e.events) != eventsLimit {
t.Fatalf("Must be %d events, got %d", eventsLimit, len(e.events))
}
var msgs []*jsonmessage.JSONMessage
for len(msgs) < 10 {
m := <-l
jm, ok := (m).(*jsonmessage.JSONMessage)
if !ok {
t.Fatalf("Unexpected type %T", m)
}
msgs = append(msgs, jm)
}
if len(current) != eventsLimit {
t.Fatalf("Must be %d events, got %d", eventsLimit, len(current))
}
first := current[0]
if first.Status != "action_16" {
t.Fatalf("First action is %s, must be action_16", first.Status)
}
last := current[len(current)-1]
if last.Status != "action_79" {
t.Fatalf("Last action is %s, must be action_79", last.Status)
}
firstC := msgs[0]
if firstC.Status != "action_80" {
t.Fatalf("First action is %s, must be action_80", firstC.Status)
}
lastC := msgs[len(msgs)-1]
if lastC.Status != "action_89" {
t.Fatalf("Last action is %s, must be action_89", lastC.Status)
}
}