events_cache_test.go

Documentation: k8s.io/client-go/tools/record

     1  /*
     2  Copyright 2015 The Kubernetes Authors.
     3  
     4  Licensed under the Apache License, Version 2.0 (the "License");
     5  you may not use this file except in compliance with the License.
     6  You may obtain a copy of the License at
     7  
     8      http://www.apache.org/licenses/LICENSE-2.0
     9  
    10  Unless required by applicable law or agreed to in writing, software
    11  distributed under the License is distributed on an "AS IS" BASIS,
    12  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
    13  See the License for the specific language governing permissions and
    14  limitations under the License.
    15  */
    16  
    17  package record
    18  
    19  import (
    20  	"reflect"
    21  	"strconv"
    22  	"strings"
    23  	"testing"
    24  	"time"
    25  
    26  	"github.com/google/go-cmp/cmp"
    27  	v1 "k8s.io/api/core/v1"
    28  	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
    29  	testclocks "k8s.io/utils/clock/testing"
    30  )
    31  
    32  func makeObjectReference(kind, name, namespace string) v1.ObjectReference {
    33  	return v1.ObjectReference{
    34  		Kind:       kind,
    35  		Name:       name,
    36  		Namespace:  namespace,
    37  		UID:        "C934D34AFB20242",
    38  		APIVersion: "version",
    39  		FieldPath:  "spec.containers{mycontainer}",
    40  	}
    41  }
    42  
    43  func makeEvent(reason, message string, involvedObject v1.ObjectReference) v1.Event {
    44  	eventTime := metav1.Now()
    45  	event := v1.Event{
    46  		Reason:         reason,
    47  		Message:        message,
    48  		InvolvedObject: involvedObject,
    49  		Source: v1.EventSource{
    50  			Component: "kubelet",
    51  			Host:      "kublet.node1",
    52  		},
    53  		Count:          1,
    54  		FirstTimestamp: eventTime,
    55  		LastTimestamp:  eventTime,
    56  		Type:           v1.EventTypeNormal,
    57  	}
    58  	return event
    59  }
    60  
    61  func makeEvents(num int, template v1.Event) []v1.Event {
    62  	events := []v1.Event{}
    63  	for i := 0; i < num; i++ {
    64  		events = append(events, template)
    65  	}
    66  	return events
    67  }
    68  
    69  func makeUniqueEvents(num int) []v1.Event {
    70  	events := []v1.Event{}
    71  	kind := "Pod"
    72  	for i := 0; i < num; i++ {
    73  		reason := strings.Join([]string{"reason", strconv.Itoa(i)}, "-")
    74  		message := strings.Join([]string{"message", strconv.Itoa(i)}, "-")
    75  		name := strings.Join([]string{"pod", strconv.Itoa(i)}, "-")
    76  		namespace := strings.Join([]string{"ns", strconv.Itoa(i)}, "-")
    77  		involvedObject := makeObjectReference(kind, name, namespace)
    78  		events = append(events, makeEvent(reason, message, involvedObject))
    79  	}
    80  	return events
    81  }
    82  
    83  func makeSimilarEvents(num int, template v1.Event, messagePrefix string) []v1.Event {
    84  	events := makeEvents(num, template)
    85  	for i := range events {
    86  		events[i].Message = strings.Join([]string{messagePrefix, strconv.Itoa(i), events[i].Message}, "-")
    87  	}
    88  	return events
    89  }
    90  
    91  func setCount(event v1.Event, count int) v1.Event {
    92  	event.Count = int32(count)
    93  	return event
    94  }
    95  
    96  func validateEvent(messagePrefix string, actualEvent *v1.Event, expectedEvent *v1.Event, t *testing.T) (*v1.Event, error) {
    97  	recvEvent := *actualEvent
    98  	expectCompression := expectedEvent.Count > 1
    99  	t.Logf("%v - expectedEvent.Count is %d\n", messagePrefix, expectedEvent.Count)
   100  	// Just check that the timestamp was set.
   101  	if recvEvent.FirstTimestamp.IsZero() || recvEvent.LastTimestamp.IsZero() {
   102  		t.Errorf("%v - timestamp wasn't set: %#v", messagePrefix, recvEvent)
   103  	}
   104  	actualFirstTimestamp := recvEvent.FirstTimestamp
   105  	actualLastTimestamp := recvEvent.LastTimestamp
   106  	if actualFirstTimestamp.Equal(&actualLastTimestamp) {
   107  		if expectCompression {
   108  			t.Errorf("%v - FirstTimestamp (%q) and LastTimestamp (%q) must be different to indicate event compression happened, but were the same. Actual Event: %#v", messagePrefix, actualFirstTimestamp, actualLastTimestamp, recvEvent)
   109  		}
   110  	} else {
   111  		if expectedEvent.Count == 1 {
   112  			t.Errorf("%v - FirstTimestamp (%q) and LastTimestamp (%q) must be equal to indicate only one occurrence of the event, but were different. Actual Event: %#v", messagePrefix, actualFirstTimestamp, actualLastTimestamp, recvEvent)
   113  		}
   114  	}
   115  	// Temp clear time stamps for comparison because actual values don't matter for comparison
   116  	recvEvent.FirstTimestamp = expectedEvent.FirstTimestamp
   117  	recvEvent.LastTimestamp = expectedEvent.LastTimestamp
   118  
   119  	recvEvent.ReportingController = expectedEvent.ReportingController
   120  
   121  	// Check that name has the right prefix.
   122  	if n, en := recvEvent.Name, expectedEvent.Name; !strings.HasPrefix(n, en) {
   123  		t.Errorf("%v - Name '%v' does not contain prefix '%v'", messagePrefix, n, en)
   124  	}
   125  	recvEvent.Name = expectedEvent.Name
   126  	if e, a := expectedEvent, &recvEvent; !reflect.DeepEqual(e, a) {
   127  		t.Errorf("%v - diff: %s", messagePrefix, cmp.Diff(e, a))
   128  	}
   129  	recvEvent.FirstTimestamp = actualFirstTimestamp
   130  	recvEvent.LastTimestamp = actualLastTimestamp
   131  	return actualEvent, nil
   132  }
   133  
   134  // TestEventAggregatorByReasonFunc ensures that two events are aggregated if they vary only by event.message
   135  func TestEventAggregatorByReasonFunc(t *testing.T) {
   136  	event1 := makeEvent("end-of-world", "it was fun", makeObjectReference("Pod", "pod1", "other"))
   137  	event2 := makeEvent("end-of-world", "it was awful", makeObjectReference("Pod", "pod1", "other"))
   138  	event3 := makeEvent("nevermind", "it was a bug", makeObjectReference("Pod", "pod1", "other"))
   139  
   140  	aggKey1, localKey1 := EventAggregatorByReasonFunc(&event1)
   141  	aggKey2, localKey2 := EventAggregatorByReasonFunc(&event2)
   142  	aggKey3, _ := EventAggregatorByReasonFunc(&event3)
   143  
   144  	if aggKey1 != aggKey2 {
   145  		t.Errorf("Expected %v equal %v", aggKey1, aggKey2)
   146  	}
   147  	if localKey1 == localKey2 {
   148  		t.Errorf("Expected %v to not equal %v", aggKey1, aggKey3)
   149  	}
   150  	if aggKey1 == aggKey3 {
   151  		t.Errorf("Expected %v to not equal %v", aggKey1, aggKey3)
   152  	}
   153  }
   154  
   155  // TestEventAggregatorByReasonMessageFunc validates the proper output for an aggregate message
   156  func TestEventAggregatorByReasonMessageFunc(t *testing.T) {
   157  	expectedPrefix := "(combined from similar events): "
   158  	event1 := makeEvent("end-of-world", "it was fun", makeObjectReference("Pod", "pod1", "other"))
   159  	actual := EventAggregatorByReasonMessageFunc(&event1)
   160  	if !strings.HasPrefix(actual, expectedPrefix) {
   161  		t.Errorf("Expected %v to begin with prefix %v", actual, expectedPrefix)
   162  	}
   163  }
   164  
   165  // TestEventCorrelator validates proper counting, aggregation of events
   166  func TestEventCorrelator(t *testing.T) {
   167  	firstEvent := makeEvent("first", "i am first", makeObjectReference("Pod", "my-pod", "my-ns"))
   168  	duplicateEvent := makeEvent("duplicate", "me again", makeObjectReference("Pod", "my-pod", "my-ns"))
   169  	uniqueEvent := makeEvent("unique", "snowflake", makeObjectReference("Pod", "my-pod", "my-ns"))
   170  	similarEvent := makeEvent("similar", "similar message", makeObjectReference("Pod", "my-pod", "my-ns"))
   171  	similarEvent.InvolvedObject.FieldPath = "spec.containers{container1}"
   172  	aggregateEvent := makeEvent(similarEvent.Reason, EventAggregatorByReasonMessageFunc(&similarEvent), similarEvent.InvolvedObject)
   173  	similarButDifferentContainerEvent := similarEvent
   174  	similarButDifferentContainerEvent.InvolvedObject.FieldPath = "spec.containers{container2}"
   175  	scenario := map[string]struct {
   176  		previousEvents  []v1.Event
   177  		newEvent        v1.Event
   178  		expectedEvent   v1.Event
   179  		intervalSeconds int
   180  		expectedSkip    bool
   181  	}{
   182  		"create-a-single-event": {
   183  			previousEvents:  []v1.Event{},
   184  			newEvent:        firstEvent,
   185  			expectedEvent:   setCount(firstEvent, 1),
   186  			intervalSeconds: 5,
   187  		},
   188  		"the-same-event-should-just-count": {
   189  			previousEvents:  makeEvents(1, duplicateEvent),
   190  			newEvent:        duplicateEvent,
   191  			expectedEvent:   setCount(duplicateEvent, 2),
   192  			intervalSeconds: 5,
   193  		},
   194  		"the-same-event-should-just-count-even-if-more-than-aggregate": {
   195  			previousEvents:  makeEvents(defaultAggregateMaxEvents, duplicateEvent),
   196  			newEvent:        duplicateEvent,
   197  			expectedEvent:   setCount(duplicateEvent, defaultAggregateMaxEvents+1),
   198  			intervalSeconds: 30, // larger interval induces aggregation but not spam.
   199  		},
   200  		"the-same-event-is-spam-if-happens-too-frequently": {
   201  			previousEvents:  makeEvents(defaultSpamBurst+1, duplicateEvent),
   202  			newEvent:        duplicateEvent,
   203  			expectedSkip:    true,
   204  			intervalSeconds: 1,
   205  		},
   206  		"create-many-unique-events": {
   207  			previousEvents:  makeUniqueEvents(30),
   208  			newEvent:        uniqueEvent,
   209  			expectedEvent:   setCount(uniqueEvent, 1),
   210  			intervalSeconds: 5,
   211  		},
   212  		"similar-events-should-aggregate-event": {
   213  			previousEvents:  makeSimilarEvents(defaultAggregateMaxEvents-1, similarEvent, similarEvent.Message),
   214  			newEvent:        similarEvent,
   215  			expectedEvent:   setCount(aggregateEvent, 1),
   216  			intervalSeconds: 5,
   217  		},
   218  		"similar-events-many-times-should-count-the-aggregate": {
   219  			previousEvents:  makeSimilarEvents(defaultAggregateMaxEvents, similarEvent, similarEvent.Message),
   220  			newEvent:        similarEvent,
   221  			expectedEvent:   setCount(aggregateEvent, 2),
   222  			intervalSeconds: 5,
   223  		},
   224  		"events-from-different-containers-do-not-aggregate": {
   225  			previousEvents:  makeEvents(1, similarButDifferentContainerEvent),
   226  			newEvent:        similarEvent,
   227  			expectedEvent:   setCount(similarEvent, 1),
   228  			intervalSeconds: 5,
   229  		},
   230  		"similar-events-whose-interval-is-greater-than-aggregate-interval-do-not-aggregate": {
   231  			previousEvents:  makeSimilarEvents(defaultAggregateMaxEvents-1, similarEvent, similarEvent.Message),
   232  			newEvent:        similarEvent,
   233  			expectedEvent:   setCount(similarEvent, 1),
   234  			intervalSeconds: defaultAggregateIntervalInSeconds,
   235  		},
   236  	}
   237  
   238  	for testScenario, testInput := range scenario {
   239  		eventInterval := time.Duration(testInput.intervalSeconds) * time.Second
   240  		clock := testclocks.SimpleIntervalClock{Time: time.Now(), Duration: eventInterval}
   241  		correlator := NewEventCorrelator(&clock)
   242  		for i := range testInput.previousEvents {
   243  			event := testInput.previousEvents[i]
   244  			now := metav1.NewTime(clock.Now())
   245  			event.FirstTimestamp = now
   246  			event.LastTimestamp = now
   247  			result, err := correlator.EventCorrelate(&event)
   248  			if err != nil {
   249  				t.Errorf("scenario %v: unexpected error playing back prevEvents %v", testScenario, err)
   250  			}
   251  			// if we are skipping the event, we can avoid updating state
   252  			if !result.Skip {
   253  				correlator.UpdateState(result.Event)
   254  			}
   255  		}
   256  
   257  		// update the input to current clock value
   258  		now := metav1.NewTime(clock.Now())
   259  		testInput.newEvent.FirstTimestamp = now
   260  		testInput.newEvent.LastTimestamp = now
   261  		result, err := correlator.EventCorrelate(&testInput.newEvent)
   262  		if err != nil {
   263  			t.Errorf("scenario %v: unexpected error correlating input event %v", testScenario, err)
   264  		}
   265  
   266  		// verify we did not get skip from filter function unexpectedly...
   267  		if result.Skip != testInput.expectedSkip {
   268  			t.Errorf("scenario %v: expected skip %v, but got %v", testScenario, testInput.expectedSkip, result.Skip)
   269  			continue
   270  		}
   271  
   272  		// we wanted to actually skip, so no event is needed to validate
   273  		if testInput.expectedSkip {
   274  			continue
   275  		}
   276  
   277  		// validate event
   278  		_, err = validateEvent(testScenario, result.Event, &testInput.expectedEvent, t)
   279  		if err != nil {
   280  			t.Errorf("scenario %v: unexpected error validating result %v", testScenario, err)
   281  		}
   282  	}
   283  }
   284  
   285  func TestEventSpamFilter(t *testing.T) {
   286  	spamKeyFuncBasedOnObjectsAndReason := func(e *v1.Event) string {
   287  		return strings.Join([]string{
   288  			e.Source.Component,
   289  			e.Source.Host,
   290  			e.InvolvedObject.Kind,
   291  			e.InvolvedObject.Namespace,
   292  			e.InvolvedObject.Name,
   293  			string(e.InvolvedObject.UID),
   294  			e.InvolvedObject.APIVersion,
   295  			e.Reason,
   296  		},
   297  			"")
   298  	}
   299  	burstSize := 1
   300  	eventInterval := time.Duration(1) * time.Second
   301  	originalEvent := makeEvent("original", "i am first", makeObjectReference("Pod", "my-pod", "my-ns"))
   302  	differentReasonEvent := makeEvent("duplicate", "me again", makeObjectReference("Pod", "my-pod", "my-ns"))
   303  	spamEvent := makeEvent("original", "me again", makeObjectReference("Pod", "my-pod", "my-ns"))
   304  	testCases := map[string]struct {
   305  		newEvent      v1.Event
   306  		expectedEvent v1.Event
   307  		expectedSkip  bool
   308  		spamKeyFunc   EventSpamKeyFunc
   309  	}{
   310  		"event should be reported as spam if object reference is the same for default spam filter": {
   311  			newEvent:     differentReasonEvent,
   312  			expectedSkip: true,
   313  		},
   314  		"event should not be reported as spam if object reference is the same, but reason is different for custom spam filter": {
   315  			newEvent:      differentReasonEvent,
   316  			expectedEvent: differentReasonEvent,
   317  			expectedSkip:  false,
   318  			spamKeyFunc:   spamKeyFuncBasedOnObjectsAndReason,
   319  		},
   320  		"event should  be reported as spam if object reference and reason is the same, but message is different for custom spam filter": {
   321  			newEvent:     spamEvent,
   322  			expectedSkip: true,
   323  			spamKeyFunc:  spamKeyFuncBasedOnObjectsAndReason,
   324  		},
   325  	}
   326  
   327  	for testDescription, testInput := range testCases {
   328  		c := testclocks.SimpleIntervalClock{Time: time.Now(), Duration: eventInterval}
   329  		correlator := NewEventCorrelatorWithOptions(CorrelatorOptions{
   330  			Clock:       &c,
   331  			SpamKeyFunc: testInput.spamKeyFunc,
   332  			BurstSize:   burstSize,
   333  		})
   334  		// emitting original event
   335  		result, err := correlator.EventCorrelate(&originalEvent)
   336  		if err != nil {
   337  			t.Errorf("scenario %v: unexpected error correlating originalEvent %v", testDescription, err)
   338  		}
   339  		// if we are skipping the event, we can avoid updating state
   340  		if !result.Skip {
   341  			correlator.UpdateState(result.Event)
   342  		}
   343  
   344  		result, err = correlator.EventCorrelate(&testInput.newEvent)
   345  		if err != nil {
   346  			t.Errorf("scenario %v: unexpected error correlating input event %v", testDescription, err)
   347  		}
   348  
   349  		// verify we did not get skip from filter function unexpectedly...
   350  		if result.Skip != testInput.expectedSkip {
   351  			t.Errorf("scenario %v: expected skip %v, but got %v", testDescription, testInput.expectedSkip, result.Skip)
   352  			continue
   353  		}
   354  
   355  		// we wanted to actually skip, so no event is needed to validate
   356  		if testInput.expectedSkip {
   357  			continue
   358  		}
   359  
   360  		// validate event
   361  		_, err = validateEvent(testDescription, result.Event, &testInput.expectedEvent, t)
   362  		if err != nil {
   363  			t.Errorf("scenario %v: unexpected error validating result %v", testDescription, err)
   364  		}
   365  	}
   366  }
   367
View as plain text