Skip to content

Commit 394dd0b

Browse files
committed
Revert "test remove dataplane changes to see if race condition fixes"
This reverts commit 08697eb.
1 parent 08697eb commit 394dd0b

File tree

5 files changed

+127
-83
lines changed

5 files changed

+127
-83
lines changed

npm/pkg/dataplane/dataplane.go

Lines changed: 55 additions & 28 deletions
Original file line numberDiff line numberDiff line change
@@ -81,7 +81,8 @@ type DataPlane struct {
8181
func NewDataPlane(nodeName string, ioShim *common.IOShim, cfg *Config, stopChannel <-chan struct{}) (*DataPlane, error) {
8282
metrics.InitializeAll()
8383
if util.IsWindowsDP() {
84-
klog.Infof("[DataPlane] enabling AddEmptySetToLists for Windows")
84+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
85+
// klog.Infof("[DataPlane] enabling AddEmptySetToLists for Windows")
8586
cfg.IPSetManagerCfg.AddEmptySetToLists = true
8687
}
8788

@@ -112,7 +113,8 @@ func NewDataPlane(nodeName string, ioShim *common.IOShim, cfg *Config, stopChann
112113
return nil, ErrInvalidApplyConfig
113114
}
114115
} else {
115-
klog.Info("[DataPlane] dataplane configured to NOT apply in background")
116+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
117+
// klog.Info("[DataPlane] dataplane configured to NOT apply in background")
116118
dp.updatePodCache = newUpdatePodCache(1)
117119
}
118120

@@ -150,7 +152,8 @@ func (dp *DataPlane) FinishBootupPhase() {
150152
dp.applyInfo.Lock()
151153
defer dp.applyInfo.Unlock()
152154

153-
klog.Infof("[DataPlane] finished bootup phase")
155+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
156+
// klog.Infof("[DataPlane] finished bootup phase")
154157
dp.applyInfo.inBootupPhase = false
155158
}
156159

@@ -257,7 +260,8 @@ func (dp *DataPlane) AddToSets(setNames []*ipsets.IPSetMetadata, podMetadata *Po
257260
}
258261

259262
if dp.shouldUpdatePod() && podMetadata.NodeName == dp.nodeName {
260-
klog.Infof("[DataPlane] Updating Sets to Add for pod key %s", podMetadata.PodKey)
263+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
264+
// klog.Infof("[DataPlane] Updating Sets to Add for pod key %s", podMetadata.PodKey)
261265

262266
// lock updatePodCache while reading/modifying or setting the updatePod in the cache
263267
dp.updatePodCache.Lock()
@@ -279,7 +283,8 @@ func (dp *DataPlane) RemoveFromSets(setNames []*ipsets.IPSetMetadata, podMetadat
279283
}
280284

281285
if dp.shouldUpdatePod() && podMetadata.NodeName == dp.nodeName {
282-
klog.Infof("[DataPlane] Updating Sets to Remove for pod key %s", podMetadata.PodKey)
286+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
287+
// klog.Infof("[DataPlane] Updating Sets to Remove for pod key %s", podMetadata.PodKey)
283288

284289
// lock updatePodCache while reading/modifying or setting the updatePod in the cache
285290
dp.updatePodCache.Lock()
@@ -328,23 +333,27 @@ func (dp *DataPlane) ApplyDataPlane() error {
328333
newCount := dp.applyInfo.numBatches
329334
dp.applyInfo.Unlock()
330335

331-
klog.Infof("[DataPlane] [%s] new batch count: %d", contextApplyDP, newCount)
336+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
337+
// klog.Infof("[DataPlane] [%s] new batch count: %d", contextApplyDP, newCount)
332338

333339
if newCount >= dp.ApplyMaxBatches {
334-
klog.Infof("[DataPlane] [%s] applying now since reached maximum batch count: %d", contextApplyDP, newCount)
340+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
341+
// klog.Infof("[DataPlane] [%s] applying now since reached maximum batch count: %d", contextApplyDP, newCount)
335342
return dp.applyDataPlaneNow(contextApplyDP)
336343
}
337344

338345
return nil
339346
}
340347

341348
func (dp *DataPlane) applyDataPlaneNow(context string) error {
342-
klog.Infof("[DataPlane] [ApplyDataPlane] [%s] starting to apply ipsets", context)
349+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
350+
// klog.Infof("[DataPlane] [ApplyDataPlane] [%s] starting to apply ipsets", context)
343351
err := dp.ipsetMgr.ApplyIPSets()
344352
if err != nil {
345353
return fmt.Errorf("[DataPlane] [%s] error while applying IPSets: %w", context, err)
346354
}
347-
klog.Infof("[DataPlane] [ApplyDataPlane] [%s] finished applying ipsets", context)
355+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
356+
// klog.Infof("[DataPlane] [ApplyDataPlane] [%s] finished applying ipsets", context)
348357

349358
// see comment in RemovePolicy() for why this is here
350359
dp.setRemovePolicyFailure(false)
@@ -365,7 +374,8 @@ func (dp *DataPlane) applyDataPlaneNow(context string) error {
365374
}
366375
dp.updatePodCache.Unlock()
367376

368-
klog.Infof("[DataPlane] [ApplyDataPlane] [%s] refreshing endpoints before updating pods", context)
377+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
378+
// klog.Infof("[DataPlane] [ApplyDataPlane] [%s] refreshing endpoints before updating pods", context)
369379

370380
err := dp.refreshPodEndpoints()
371381
if err != nil {
@@ -374,14 +384,16 @@ func (dp *DataPlane) applyDataPlaneNow(context string) error {
374384
return nil
375385
}
376386

377-
klog.Infof("[DataPlane] [ApplyDataPlane] [%s] refreshed endpoints", context)
387+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
388+
// klog.Infof("[DataPlane] [ApplyDataPlane] [%s] refreshed endpoints", context)
378389

379390
// lock updatePodCache while driving goal state to kernel
380391
// prevents another ApplyDataplane call from updating the same pods
381392
dp.updatePodCache.Lock()
382393
defer dp.updatePodCache.Unlock()
383394

384-
klog.Infof("[DataPlane] [ApplyDataPlane] [%s] starting to update pods", context)
395+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
396+
// klog.Infof("[DataPlane] [ApplyDataPlane] [%s] starting to update pods", context)
385397
for !dp.updatePodCache.isEmpty() {
386398
pod := dp.updatePodCache.dequeue()
387399
if pod == nil {
@@ -399,14 +411,16 @@ func (dp *DataPlane) applyDataPlaneNow(context string) error {
399411
}
400412
}
401413

402-
klog.Infof("[DataPlane] [ApplyDataPlane] [%s] finished updating pods", context)
414+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
415+
// klog.Infof("[DataPlane] [ApplyDataPlane] [%s] finished updating pods", context)
403416
}
404417
return nil
405418
}
406419

407420
// AddPolicy takes in a translated NPMNetworkPolicy object and applies on dataplane
408421
func (dp *DataPlane) AddPolicy(policy *policies.NPMNetworkPolicy) error {
409-
klog.Infof("[DataPlane] Add Policy called for %s", policy.PolicyKey)
422+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
423+
// klog.Infof("[DataPlane] Add Policy called for %s", policy.PolicyKey)
410424

411425
if !dp.netPolInBackground {
412426
return dp.addPolicies([]*policies.NPMNetworkPolicy{policy})
@@ -420,10 +434,12 @@ func (dp *DataPlane) AddPolicy(policy *policies.NPMNetworkPolicy) error {
420434
dp.netPolQueue.enqueue(policy)
421435
newCount := dp.netPolQueue.len()
422436

423-
klog.Infof("[DataPlane] [%s] new pending netpol count: %d", contextAddNetPol, newCount)
437+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
438+
// klog.Infof("[DataPlane] [%s] new pending netpol count: %d", contextAddNetPol, newCount)
424439

425440
if newCount >= dp.MaxPendingNetPols {
426-
klog.Infof("[DataPlane] [%s] applying now since reached maximum batch count: %d", contextAddNetPol, newCount)
441+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
442+
// klog.Infof("[DataPlane] [%s] applying now since reached maximum batch count: %d", contextAddNetPol, newCount)
427443
dp.addPoliciesWithRetry(contextAddNetPol)
428444
}
429445
return nil
@@ -433,12 +449,14 @@ func (dp *DataPlane) AddPolicy(policy *policies.NPMNetworkPolicy) error {
433449
// The caller must lock netPolQueue.
434450
func (dp *DataPlane) addPoliciesWithRetry(context string) {
435451
netPols := dp.netPolQueue.dump()
436-
klog.Infof("[DataPlane] adding policies %+v", netPols)
452+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
453+
// klog.Infof("[DataPlane] adding policies %+v", netPols)
437454

438455
err := dp.addPolicies(netPols)
439456
if err == nil {
440457
// clear queue and return on success
441-
klog.Infof("[DataPlane] [%s] added policies successfully", context)
458+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
459+
// klog.Infof("[DataPlane] [%s] added policies successfully", context)
442460
dp.netPolQueue.clear()
443461
return
444462
}
@@ -451,7 +469,8 @@ func (dp *DataPlane) addPoliciesWithRetry(context string) {
451469
err = dp.addPolicies([]*policies.NPMNetworkPolicy{netPol})
452470
if err == nil {
453471
// remove from queue on success
454-
klog.Infof("[DataPlane] [%s] added policy successfully one at a time. policyKey: %s", context, netPol.PolicyKey)
472+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
473+
// klog.Infof("[DataPlane] [%s] added policy successfully one at a time. policyKey: %s", context, netPol.PolicyKey)
455474
dp.netPolQueue.delete(netPol.PolicyKey)
456475
} else {
457476
// keep in queue on failure
@@ -469,7 +488,8 @@ func (dp *DataPlane) addPolicies(netPols []*policies.NPMNetworkPolicy) error {
469488
}
470489

471490
if len(netPols) == 0 {
472-
klog.Infof("[DataPlane] expected to have at least one NetPol in dp.addPolicies()")
491+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
492+
// klog.Infof("[DataPlane] expected to have at least one NetPol in dp.addPolicies()")
473493
return nil
474494
}
475495

@@ -513,7 +533,8 @@ func (dp *DataPlane) addPolicies(netPols []*policies.NPMNetworkPolicy) error {
513533
// Create and add references for Rule IPSets
514534
err = dp.createIPSetsAndReferences(netPol.RuleIPSets, netPol.PolicyKey, ipsets.NetPolType)
515535
if err != nil {
516-
klog.Infof("[DataPlane] error while adding Rule IPSet references: %s", err.Error())
536+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
537+
// klog.Infof("[DataPlane] error while adding Rule IPSet references: %s", err.Error())
517538
return fmt.Errorf("[DataPlane] error while adding Rule IPSet references: %w", err)
518539
}
519540

@@ -526,15 +547,18 @@ func (dp *DataPlane) addPolicies(netPols []*policies.NPMNetworkPolicy) error {
526547
// increment batch and apply IPSets if needed
527548
dp.applyInfo.numBatches++
528549
newCount := dp.applyInfo.numBatches
529-
klog.Infof("[DataPlane] [%s] new batch count: %d", contextAddNetPolBootup, newCount)
550+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
551+
// klog.Infof("[DataPlane] [%s] new batch count: %d", contextAddNetPolBootup, newCount)
530552
if newCount >= dp.ApplyMaxBatches {
531-
klog.Infof("[DataPlane] [%s] applying now since reached maximum batch count: %d", contextAddNetPolBootup, newCount)
532-
klog.Infof("[DataPlane] [%s] starting to apply ipsets", contextAddNetPolBootup)
553+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
554+
// klog.Infof("[DataPlane] [%s] applying now since reached maximum batch count: %d", contextAddNetPolBootup, newCount)
555+
// klog.Infof("[DataPlane] [%s] starting to apply ipsets", contextAddNetPolBootup)
533556
err = dp.ipsetMgr.ApplyIPSets()
534557
if err != nil {
535558
return fmt.Errorf("[DataPlane] [%s] error while applying IPSets: %w", contextAddNetPolBootup, err)
536559
}
537-
klog.Infof("[DataPlane] [%s] finished applying ipsets", contextAddNetPolBootup)
560+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
561+
// klog.Infof("[DataPlane] [%s] finished applying ipsets", contextAddNetPolBootup)
538562

539563
// see comment in RemovePolicy() for why this is here
540564
dp.setRemovePolicyFailure(false)
@@ -574,7 +598,8 @@ func (dp *DataPlane) addPolicies(netPols []*policies.NPMNetworkPolicy) error {
574598

575599
// RemovePolicy takes in network policyKey (namespace/name of network policy) and removes it from dataplane and cache
576600
func (dp *DataPlane) RemovePolicy(policyKey string) error {
577-
klog.Infof("[DataPlane] Remove Policy called for %s", policyKey)
601+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
602+
// klog.Infof("[DataPlane] Remove Policy called for %s", policyKey)
578603

579604
if dp.netPolInBackground {
580605
// make sure to not add this NetPol if we're deleting it
@@ -650,10 +675,12 @@ func (dp *DataPlane) RemovePolicy(policyKey string) error {
650675
// UpdatePolicy takes in updated policy object, calculates the delta and applies changes
651676
// onto dataplane accordingly
652677
func (dp *DataPlane) UpdatePolicy(policy *policies.NPMNetworkPolicy) error {
653-
klog.Infof("[DataPlane] Update Policy called for %s", policy.PolicyKey)
678+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
679+
// klog.Infof("[DataPlane] Update Policy called for %s", policy.PolicyKey)
654680
ok := dp.policyMgr.PolicyExists(policy.PolicyKey)
655681
if !ok {
656-
klog.Infof("[DataPlane] Policy %s is not found.", policy.PolicyKey)
682+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
683+
// klog.Infof("[DataPlane] Policy %s is not found.", policy.PolicyKey)
657684
return dp.AddPolicy(policy)
658685
}
659686

npm/pkg/dataplane/dataplane_linux_test.go

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -94,6 +94,8 @@ func TestNetPolInBackgroundUpdatePolicy(t *testing.T) {
9494
}
9595

9696
func TestNetPolInBackgroundSkipAddAfterRemove(t *testing.T) {
97+
// Sleep for a bit to let IncNumACLRulesBy be resolved to avoid race condition
98+
time.Sleep(100 * time.Millisecond)
9799
metrics.ReinitializeAll()
98100

99101
calls := getBootupTestCalls()

npm/pkg/dataplane/ipsets/ipsetmanager.go

Lines changed: 14 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -93,7 +93,8 @@ func (iMgr *IPSetManager) Reconcile() {
9393
}
9494
numRemovedSets := originalNumSets - len(iMgr.setMap)
9595
if numRemovedSets > 0 {
96-
klog.Infof("[IPSetManager] removed %d empty/unreferenced ipsets, updating toDeleteCache to: %+v", numRemovedSets, iMgr.dirtyCache.printDeleteCache())
96+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
97+
// klog.Infof("[IPSetManager] removed %d empty/unreferenced ipsets, updating toDeleteCache to: %+v", numRemovedSets, iMgr.dirtyCache.printDeleteCache())
9798
}
9899
}
99100

@@ -308,10 +309,11 @@ func (iMgr *IPSetManager) RemoveFromSets(removeFromSets []*IPSetMetadata, ip, po
308309
}
309310
// in case the IP belongs to a new Pod, then ignore this Delete call as this might be stale
310311
if cachedPodKey != podKey {
311-
klog.Infof(
312-
"[IPSetManager] DeleteFromSet: PodOwner has changed for Ip: %s, setName:%s, Old podKey: %s, new podKey: %s. Ignore the delete as this is stale update",
313-
ip, prefixedName, cachedPodKey, podKey,
314-
)
312+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
313+
// klog.Infof(
314+
// "[IPSetManager] DeleteFromSet: PodOwner has changed for Ip: %s, setName:%s, Old podKey: %s, new podKey: %s. Ignore the delete as this is stale update",
315+
// ip, prefixedName, cachedPodKey, podKey,
316+
// )
315317
continue
316318
}
317319

@@ -453,14 +455,16 @@ func (iMgr *IPSetManager) ApplyIPSets() error {
453455
defer iMgr.Unlock()
454456

455457
if iMgr.dirtyCache.numSetsToAddOrUpdate() == 0 && iMgr.dirtyCache.numSetsToDelete() == 0 {
456-
klog.Info("[IPSetManager] No IPSets to apply")
458+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
459+
// klog.Info("[IPSetManager] No IPSets to apply")
457460
return nil
458461
}
459462

460-
klog.Infof(
461-
"[IPSetManager] dirty caches. toAddUpdateCache: %s, toDeleteCache: %s",
462-
iMgr.dirtyCache.printAddOrUpdateCache(), iMgr.dirtyCache.printDeleteCache(),
463-
)
463+
// TODO: Refactor non-error/warning klogs with Zap and set the following logs to "debug" level
464+
// klog.Infof(
465+
// "[IPSetManager] dirty caches. toAddUpdateCache: %s, toDeleteCache: %s",
466+
// iMgr.dirtyCache.printAddOrUpdateCache(), iMgr.dirtyCache.printDeleteCache(),
467+
// )
464468
iMgr.sanitizeDirtyCache()
465469

466470
// Call the appropriate apply ipsets

0 commit comments

Comments
 (0)