Skip to content

Commit 57247f8

Browse files
Merge pull request openshift#1150 from petr-muller/ota-1418-insight-lifecycle-3
OTA-1418: USC: Drop unknown insights after grace period
2 parents 7afbeb0 + dad69f3 commit 57247f8

File tree

2 files changed

+190
-26
lines changed

2 files changed

+190
-26
lines changed

pkg/updatestatus/updatestatuscontroller.go

Lines changed: 69 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,10 @@ import (
2727
updatestatus "github.com/openshift/cluster-version-operator/pkg/updatestatus/api"
2828
)
2929

30+
const (
31+
unknownInsightGracePeriod = 60 * time.Second
32+
)
33+
3034
// informerMsg is the communication structure between informers and the update status controller. It contains the UID of
3135
// the insight and the insight itself, serialized as YAML. Passing serialized avoids shared data access problems. Until
3236
// we have the Status API we need to serialize ourselves anyway.
@@ -74,6 +78,9 @@ func isStatusInsightKey(k string) bool {
7478
return strings.HasPrefix(k, "usc.")
7579
}
7680

81+
// insightExpirations is UID -> expiration time map
82+
type insightExpirations map[string]time.Time
83+
7784
// updateStatusController is a controller that collects insights from informers and maintains a ConfigMap with the insights
7885
// until we have a proper UpdateStatus API. The controller maintains an internal desired content of the ConfigMap (even
7986
// if it does not exist in the cluster) and updates it in the cluster when new insights are received, or when the ConfigMap
@@ -100,11 +107,20 @@ type updateStatusController struct {
100107
sync.Mutex
101108
cm *corev1.ConfigMap
102109

110+
// unknownInsightExpirations is a map of informer -> map of UID -> expiration time. It is used to track insights
111+
// that were reported by informers but are no longer known to them. The API keeps unknown insights until they
112+
// expire. If an insight is reported as known again before it expires, it is removed from the map.
113+
// TODO (muller): Needs to periodically rebuilt to avoid leaking memory
114+
unknownInsightExpirations map[string]insightExpirations
115+
103116
// processed is the number of insights processed, used for testing
104117
processed int
105118
}
106119

107120
recorder events.Recorder
121+
// TODO: Get rid of this and use `clock.Clock` in all controllers, passed from start.go main function's
122+
// controllercmd.ControllerContext
123+
now func() time.Time
108124
}
109125

110126
// newUpdateStatusController creates a new update status controller and returns it. The second return value is a function
@@ -119,6 +135,7 @@ func newUpdateStatusController(
119135
c := &updateStatusController{
120136
configMaps: coreClient.CoreV1().ConfigMaps(uscNamespace),
121137
recorder: uscRecorder,
138+
now: time.Now,
122139
}
123140

124141
startInsightReceiver, sendInsight := c.setupInsightReceiver()
@@ -225,18 +242,66 @@ func (c *updateStatusController) updateInsightInStatusApi(msg informerMsg) {
225242
}
226243

227244
// removeUnknownInsights removes insights from the status API that are no longer reported as known to the informer
228-
// that originally reported them.
245+
// that originally reported them. The insights are kept for a grace period after they are no longer reported as known
246+
// and eventually dropped if they are not reported as known again within that period.
229247
// Assumes the statusApi field is locked.
230248
func (c *updateStatusController) removeUnknownInsights(message informerMsg) {
231249
known := sets.New(message.knownInsights...)
232250
known.Insert(message.uid)
233251
informerPrefix := fmt.Sprintf("usc.%s.", message.informer)
234252
for key := range c.statusApi.cm.Data {
235-
if strings.HasPrefix(key, informerPrefix) && !known.Has(strings.TrimPrefix(key, informerPrefix)) {
236-
delete(c.statusApi.cm.Data, key)
237-
klog.V(2).Infof("USC :: Collector :: Dropped insight %q because it is no longer reported as known by informer %q", key, message.informer)
253+
if strings.HasPrefix(key, informerPrefix) {
254+
uid := strings.TrimPrefix(key, informerPrefix)
255+
c.handleInsightExpiration(message.informer, known.Has(uid), uid)
238256
}
239257
}
258+
259+
if len(c.statusApi.unknownInsightExpirations) > 0 && len(c.statusApi.unknownInsightExpirations[message.informer]) == 0 {
260+
delete(c.statusApi.unknownInsightExpirations, message.informer)
261+
}
262+
if len(c.statusApi.unknownInsightExpirations) == 0 {
263+
c.statusApi.unknownInsightExpirations = nil
264+
}
265+
}
266+
267+
// handleInsightExpiration considers potential expiration of an insight present in the API based on whether the informer
268+
// knows about it.
269+
// If the informer knows about the insight, it is not dropped from the API and any previous expiration is cancelled.
270+
// If the informer does not know about the insight then it is either set to expire in the future if no expiration is
271+
// set yet, or the expiration is checked to see whether the insight should be dropped.
272+
func (c *updateStatusController) handleInsightExpiration(informer string, knows bool, uid string) {
273+
now := c.now()
274+
275+
if knows {
276+
if c.statusApi.unknownInsightExpirations != nil && c.statusApi.unknownInsightExpirations[informer] != nil {
277+
delete(c.statusApi.unknownInsightExpirations[informer], uid)
278+
}
279+
return
280+
}
281+
282+
expireIn := now.Add(unknownInsightGracePeriod)
283+
keepLog := func(expire time.Time) {
284+
klog.V(2).Infof("USC :: Collector :: Keeping insight %q until %s after it is no longer reported as known by informer %q", uid, expire, informer)
285+
}
286+
switch {
287+
// Two cases when we first consider an insight as unknown -> set expiration
288+
case c.statusApi.unknownInsightExpirations == nil:
289+
c.statusApi.unknownInsightExpirations = map[string]insightExpirations{informer: {uid: expireIn}}
290+
keepLog(expireIn)
291+
case c.statusApi.unknownInsightExpirations[informer][uid].IsZero():
292+
c.statusApi.unknownInsightExpirations[informer] = insightExpirations{uid: expireIn}
293+
keepLog(expireIn)
294+
295+
// Already set for expiration but still in grace period -> keep insight
296+
case c.statusApi.unknownInsightExpirations[informer][uid].After(now):
297+
keepLog(c.statusApi.unknownInsightExpirations[informer][uid])
298+
299+
// Already set for expiration and grace period expired -> drop insight
300+
default:
301+
delete(c.statusApi.unknownInsightExpirations[informer], uid)
302+
delete(c.statusApi.cm.Data, fmt.Sprintf("usc.%s.%s", informer, uid))
303+
klog.V(2).Infof("USC :: Collector :: Dropped insight %q because it is no longer reported as known by informer %q", uid, informer)
304+
}
240305
}
241306

242307
func (c *updateStatusController) commitStatusApiAsConfigMap(ctx context.Context) error {

pkg/updatestatus/updatestatuscontroller_test.go

Lines changed: 121 additions & 22 deletions
Original file line numberDiff line numberDiff line change
@@ -17,25 +17,35 @@ import (
1717
)
1818

1919
func Test_updateStatusController(t *testing.T) {
20+
var now = time.Now()
21+
var minus90sec = now.Add(-90 * time.Second)
22+
var minus30sec = now.Add(-30 * time.Second)
23+
var plus30sec = now.Add(30 * time.Second)
24+
var plus60sec = now.Add(1 * time.Minute)
25+
2026
testCases := []struct {
21-
name string
27+
name string
28+
2229
controllerConfigMap *corev1.ConfigMap
30+
unknownExpirations map[string]insightExpirations
2331

2432
informerMsg []informerMsg
25-
expected *corev1.ConfigMap
33+
34+
expectedControllerConfigMap *corev1.ConfigMap
35+
expectedUnknownExpirations map[string]insightExpirations
2636
}{
2737
{
28-
name: "no messages, no state -> no state",
29-
controllerConfigMap: nil,
30-
informerMsg: []informerMsg{},
31-
expected: nil,
38+
name: "no messages, no state -> no state",
39+
controllerConfigMap: nil,
40+
informerMsg: []informerMsg{},
41+
expectedControllerConfigMap: nil,
3242
},
3343
{
3444
name: "no messages, empty state -> empty state",
3545
controllerConfigMap: &corev1.ConfigMap{
3646
Data: map[string]string{},
3747
},
38-
expected: &corev1.ConfigMap{
48+
expectedControllerConfigMap: &corev1.ConfigMap{
3949
Data: map[string]string{},
4050
},
4151
},
@@ -46,7 +56,7 @@ func Test_updateStatusController(t *testing.T) {
4656
"usc.cpi.cv-version": "value",
4757
},
4858
},
49-
expected: &corev1.ConfigMap{
59+
expectedControllerConfigMap: &corev1.ConfigMap{
5060
Data: map[string]string{
5161
"usc.cpi.cv-version": "value",
5262
},
@@ -62,7 +72,7 @@ func Test_updateStatusController(t *testing.T) {
6272
insight: []byte("value"),
6373
},
6474
},
65-
expected: &corev1.ConfigMap{
75+
expectedControllerConfigMap: &corev1.ConfigMap{
6676
Data: map[string]string{
6777
"usc.cpi.cv-version": "value",
6878
},
@@ -102,7 +112,7 @@ func Test_updateStatusController(t *testing.T) {
102112
knownInsights: []string{"kept", "new-item", "another"},
103113
},
104114
},
105-
expected: &corev1.ConfigMap{
115+
expectedControllerConfigMap: &corev1.ConfigMap{
106116
Data: map[string]string{
107117
"usc.cpi.kept": "kept",
108118
"usc.cpi.new-item": "msg1",
@@ -125,7 +135,7 @@ func Test_updateStatusController(t *testing.T) {
125135
insight: []byte("msg from informer two"),
126136
},
127137
},
128-
expected: &corev1.ConfigMap{
138+
expectedControllerConfigMap: &corev1.ConfigMap{
129139
Data: map[string]string{
130140
"usc.one.item": "msg from informer one",
131141
"usc.two.item": "msg from informer two",
@@ -142,7 +152,7 @@ func Test_updateStatusController(t *testing.T) {
142152
insight: []byte("msg from informer one"),
143153
},
144154
},
145-
expected: nil,
155+
expectedControllerConfigMap: nil,
146156
},
147157
{
148158
name: "empty uid -> message gets dropped",
@@ -154,7 +164,7 @@ func Test_updateStatusController(t *testing.T) {
154164
insight: []byte("msg from informer one"),
155165
},
156166
},
157-
expected: nil,
167+
expectedControllerConfigMap: nil,
158168
},
159169
{
160170
name: "empty insight payload -> message gets dropped",
@@ -166,7 +176,7 @@ func Test_updateStatusController(t *testing.T) {
166176
insight: []byte{},
167177
},
168178
},
169-
expected: nil,
179+
expectedControllerConfigMap: nil,
170180
},
171181
{
172182
name: "nil insight payload -> message gets dropped",
@@ -178,10 +188,10 @@ func Test_updateStatusController(t *testing.T) {
178188
insight: nil,
179189
},
180190
},
181-
expected: nil,
191+
expectedControllerConfigMap: nil,
182192
},
183193
{
184-
name: "unknown message gets removed from state",
194+
name: "unknown insight -> not removed from state immediately but set for expiration",
185195
controllerConfigMap: &corev1.ConfigMap{
186196
Data: map[string]string{
187197
"usc.one.old": "payload",
@@ -193,11 +203,88 @@ func Test_updateStatusController(t *testing.T) {
193203
insight: []byte("new payload"),
194204
knownInsights: nil,
195205
}},
196-
expected: &corev1.ConfigMap{
206+
expectedControllerConfigMap: &corev1.ConfigMap{
197207
Data: map[string]string{
208+
"usc.one.old": "payload",
198209
"usc.one.new": "new payload",
199210
},
200211
},
212+
expectedUnknownExpirations: map[string]insightExpirations{
213+
"one": {"old": plus60sec},
214+
},
215+
},
216+
{
217+
name: "unknown insight already set for expiration -> not removed from state while not expired yet",
218+
controllerConfigMap: &corev1.ConfigMap{
219+
Data: map[string]string{
220+
"usc.one.old": "payload",
221+
},
222+
},
223+
unknownExpirations: map[string]insightExpirations{
224+
"one": {"old": plus30sec},
225+
},
226+
informerMsg: []informerMsg{{
227+
informer: "one",
228+
uid: "new",
229+
insight: []byte("new payload"),
230+
knownInsights: nil,
231+
}},
232+
expectedControllerConfigMap: &corev1.ConfigMap{
233+
Data: map[string]string{
234+
"usc.one.old": "payload",
235+
"usc.one.new": "new payload",
236+
},
237+
},
238+
expectedUnknownExpirations: map[string]insightExpirations{
239+
"one": {"old": plus30sec},
240+
},
241+
},
242+
{
243+
name: "previously unknown insight set for expiration is known again -> kept in state and expire dropped",
244+
controllerConfigMap: &corev1.ConfigMap{
245+
Data: map[string]string{
246+
"usc.one.old": "payload",
247+
},
248+
},
249+
unknownExpirations: map[string]insightExpirations{
250+
"one": {"old": minus30sec},
251+
},
252+
informerMsg: []informerMsg{{
253+
informer: "one",
254+
uid: "new",
255+
insight: []byte("new payload"),
256+
knownInsights: []string{"old"},
257+
}},
258+
expectedControllerConfigMap: &corev1.ConfigMap{
259+
Data: map[string]string{
260+
"usc.one.old": "payload",
261+
"usc.one.new": "new payload",
262+
},
263+
},
264+
expectedUnknownExpirations: nil,
265+
},
266+
{
267+
name: "previously unknown insight expired and never became known again -> dropped from state and expire dropped",
268+
controllerConfigMap: &corev1.ConfigMap{
269+
Data: map[string]string{
270+
"usc.one.old": "payload",
271+
},
272+
},
273+
unknownExpirations: map[string]insightExpirations{
274+
"one": {"old": minus90sec},
275+
},
276+
informerMsg: []informerMsg{{
277+
informer: "one",
278+
uid: "new",
279+
insight: []byte("new payload"),
280+
knownInsights: nil,
281+
}},
282+
expectedControllerConfigMap: &corev1.ConfigMap{
283+
Data: map[string]string{
284+
"usc.one.new": "new payload",
285+
},
286+
},
287+
expectedUnknownExpirations: nil,
201288
},
202289
}
203290

@@ -209,9 +296,16 @@ func Test_updateStatusController(t *testing.T) {
209296

210297
controller := updateStatusController{
211298
configMaps: kubeClient.CoreV1().ConfigMaps(uscNamespace),
299+
now: func() time.Time { return now },
212300
}
213301
controller.statusApi.Lock()
214302
controller.statusApi.cm = tc.controllerConfigMap
303+
for informer, expirations := range tc.unknownExpirations {
304+
if controller.statusApi.unknownInsightExpirations == nil {
305+
controller.statusApi.unknownInsightExpirations = make(map[string]insightExpirations)
306+
}
307+
controller.statusApi.unknownInsightExpirations[informer] = expirations
308+
}
215309
controller.statusApi.Unlock()
216310

217311
startInsightReceiver, sendInsight := controller.setupInsightReceiver()
@@ -228,19 +322,24 @@ func Test_updateStatusController(t *testing.T) {
228322

229323
expectedProcessed := len(tc.informerMsg)
230324
var sawProcessed int
231-
var diff string
325+
var diffConfigMap string
326+
var diffExpirations string
232327
backoff := wait.Backoff{Duration: 5 * time.Millisecond, Factor: 2, Steps: 10}
233328
if err := wait.ExponentialBackoff(backoff, func() (bool, error) {
234329
controller.statusApi.Lock()
235330
defer controller.statusApi.Unlock()
236331

237332
sawProcessed = controller.statusApi.processed
238-
diff = cmp.Diff(tc.expected, controller.statusApi.cm)
333+
diffConfigMap = cmp.Diff(tc.expectedControllerConfigMap, controller.statusApi.cm)
334+
diffExpirations = cmp.Diff(tc.expectedUnknownExpirations, controller.statusApi.unknownInsightExpirations)
239335

240-
return diff == "" && sawProcessed == expectedProcessed, nil
336+
return diffConfigMap == "" && diffExpirations == "" && sawProcessed == expectedProcessed, nil
241337
}); err != nil {
242-
if diff != "" {
243-
t.Errorf("controller config map differs from expected:\n%s", diff)
338+
if diffConfigMap != "" {
339+
t.Errorf("controller config map differs from expected:\n%s", diffConfigMap)
340+
}
341+
if diffExpirations != "" {
342+
t.Errorf("expirations differ from expected:\n%s", diffExpirations)
244343
}
245344
if controller.statusApi.processed != len(tc.informerMsg) {
246345
t.Errorf("controller processed %d messages, expected %d", controller.statusApi.processed, len(tc.informerMsg))

0 commit comments

Comments
 (0)