Skip to content

Commit

Permalink
fix: adjusted log levels, logger names ans msgs (#51)
Browse files Browse the repository at this point in the history
  • Loading branch information
@mikouaj
mikouaj authored Jun 12, 2024
1 parent 14e618f commit f0ed258
Show file tree
Hide file tree
Showing 7 changed files with 56 additions and 59 deletions.
2 changes: 1 addition & 1 deletion config/default/kustomization.yaml
View file
Original file line number Diff line number Diff line change
Expand Up @@ -31,4 +31,4 @@ patches:
- path: manager_webhook_patch.yaml

# Uncomment below for local development
#- manager_config_dev_patch.yaml
#- path: manager_config_dev_patch.yaml
34 changes: 15 additions & 19 deletions internal/boost/manager.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -86,6 +86,7 @@ type managerImpl struct {
startupCPUBoosts map[string]map[string]StartupCPUBoost
timePolicyBoosts map[boostKey]StartupCPUBoost
maxGoroutines int
log logr.Logger
}

type boostKey struct {
Expand All @@ -105,6 +106,7 @@ func NewManagerWithTicker(client client.Client, ticker TimeTicker) Manager {
startupCPUBoosts: make(map[string]map[string]StartupCPUBoost),
timePolicyBoosts: make(map[boostKey]StartupCPUBoost),
maxGoroutines: DefaultMaxGoroutines,
log: ctrl.Log.WithName("boost-manager"),
}
}

Expand All @@ -116,25 +118,27 @@ func (m *managerImpl) AddStartupCPUBoost(ctx context.Context, boost StartupCPUBo
if _, ok := m.getStartupCPUBoost(boost.Namespace(), boost.Name()); ok {
return errStartupCPUBoostAlreadyExists
}
log := m.loggerFromContext(ctx).WithValues("boost", boost.Name, "namespace", boost.Namespace)
log.V(5).Info("handling startup-cpu-boost create")
log := m.log.WithValues("boost", boost.Name(), "namespace", boost.Namespace())
log.V(5).Info("handling boost registration")
m.addStartupCPUBoost(boost)
metrics.NewBoostConfiguration(boost.Namespace())
log.Info("boost registered successfully")
return nil
}

// RemoveStartupCPUBoost removes a startup-cpu-boost from a manager if registered.
func (m *managerImpl) RemoveStartupCPUBoost(ctx context.Context, namespace, name string) {
m.Lock()
defer m.Unlock()
log := m.loggerFromContext(ctx).WithValues("boost", name, "namespace", namespace)
log.V(5).Info("handling startup-cpu-boost delete")
log := m.log.WithValues("boost", name, "namespace", namespace)
log.V(5).Info("handling boost deletion")
if boosts, ok := m.startupCPUBoosts[namespace]; ok {
delete(boosts, name)
}
key := boostKey{name: name, namespace: namespace}
delete(m.timePolicyBoosts, key)
metrics.DeleteBoostConfiguration(namespace)
log.Info("boost deleted successfully")
}

// StartupCPUBoost returns a startup-cpu-boost with a given name and namespace
Expand All @@ -150,8 +154,7 @@ func (m *managerImpl) StartupCPUBoost(namespace string, name string) (StartupCPU
func (m *managerImpl) StartupCPUBoostForPod(ctx context.Context, pod *corev1.Pod) (StartupCPUBoost, bool) {
m.RLock()
defer m.RUnlock()
log := m.loggerFromContext(ctx).WithValues("pod", pod.Name, "namespace", pod.Namespace)
log.V(5).Info("handling startup-cpu-boost pod lookup")
m.log.V(5).Info("handling boost pod lookup")
nsBoosts, ok := m.startupCPUBoosts[pod.Namespace]
if !ok {
return nil, false
Expand All @@ -169,13 +172,12 @@ func (m *managerImpl) SetStartupCPUBoostReconciler(reconciler reconcile.Reconcil
}

func (m *managerImpl) Start(ctx context.Context) error {
log := m.loggerFromContext(ctx)
defer m.ticker.Stop()
log.V(2).Info("Starting")
m.log.Info("starting")
for {
select {
case <-m.ticker.Tick():
log.V(5).Info("tick...")
m.log.V(5).Info("tick...")
m.validateTimePolicyBoosts(ctx)
case <-ctx.Done():
return nil
Expand Down Expand Up @@ -220,7 +222,6 @@ func (m *managerImpl) validateTimePolicyBoosts(ctx context.Context) {
revertTasks := make(chan *podRevertTask, m.maxGoroutines)
reconcileTasks := make(chan *reconcile.Request, m.maxGoroutines)
errors := make(chan error, m.maxGoroutines)
log := m.loggerFromContext(ctx)

go func() {
for _, boost := range m.timePolicyBoosts {
Expand All @@ -241,11 +242,12 @@ func (m *managerImpl) validateTimePolicyBoosts(ctx context.Context) {
go func() {
defer wg.Done()
for task := range revertTasks {
log = log.WithValues("boost", task.boost.Name(), "namespace", task.boost.Namespace(), "pod", task.pod.Name)
log.V(5).Info("updating pod with initial resources")
log := m.log.WithValues("boost", task.boost.Name(), "namespace", task.boost.Namespace(), "pod", task.pod.Name)
log.V(5).Info("reverting pod resources")
if err := task.boost.RevertResources(ctx, task.pod); err != nil {
errors <- fmt.Errorf("pod %s/%s: %w", task.pod.Namespace, task.pod.Name, err)
} else {
log.Info("pod resources reverted successfully")
reconcileTasks <- &reconcile.Request{
NamespacedName: types.NamespacedName{
Name: task.boost.Name(),
Expand All @@ -263,7 +265,7 @@ func (m *managerImpl) validateTimePolicyBoosts(ctx context.Context) {

go func() {
for err := range errors {
log.Error(err, "failed to revert resources")
m.log.Error(err, "pod resources reversion failed")
}
}()

Expand All @@ -275,12 +277,6 @@ func (m *managerImpl) validateTimePolicyBoosts(ctx context.Context) {
}
}

// loggerFromContext returns a pre-configured logger from the given context
func (m *managerImpl) loggerFromContext(ctx context.Context) logr.Logger {
return ctrl.LoggerFrom(ctx).
WithName("boost-manager")
}

func dedupeReconcileRequests(reconcileTasks chan *reconcile.Request) []reconcile.Request {
result := make([]reconcile.Request, 0, len(reconcileTasks))
requests := make(map[reconcile.Request]bool)
Expand Down
11 changes: 6 additions & 5 deletions internal/boost/startupcpuboost.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -155,25 +155,26 @@ func (b *StartupCPUBoostImpl) UpsertPod(ctx context.Context, pod *corev1.Pod) er
b.Lock()
defer b.Unlock()
log := b.loggerFromContext(ctx).WithValues("pod", pod.Name)
log.V(5).Info("upserting a pod")
log.V(5).Info("handling pod upsert")
_, existing := b.pods[pod.Name]
b.pods[pod.Name] = pod
statsEvent := StartupCPUBoostStatsEvent{StartupCPUBoostStatsPodCreateEvent, pod}
if existing {
statsEvent.Type = StartupCPUBoostStatsPodUpdateEvent
}
b.updateStats(statsEvent)

log.V(5).Info("pod upserted successfully")
condPolicy, ok := b.durationPolicies[duration.PodConditionPolicyName]
if !ok {
log.V(5).Info("skipping pod update as podCondition policy is missing")
log.V(5).Info("pod duration policy not found, skipping resource reversion")
return nil
}
if valid := b.validatePolicyOnPod(ctx, condPolicy, pod); !valid {
log.V(2).Info("updating pod with initial resources")
log.V(5).Info("reverting pod resources")
if err := b.revertResources(ctx, pod); err != nil {
return fmt.Errorf("failed to update pod: %s", err)
return fmt.Errorf("pod resources reversion failed: %s", err)
}
log.Info("pod resources reverted successfully")
}
return nil
}
Expand Down
31 changes: 15 additions & 16 deletions internal/controller/boost_controller.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -63,8 +63,7 @@ func (r *StartupCPUBoostReconciler) Reconcile(ctx context.Context, req ctrl.Requ
if err = r.Client.Get(ctx, req.NamespacedName, &boostObj); err != nil {
return ctrl.Result{}, client.IgnoreNotFound(err)
}
log := r.Log.WithName("reconcile").WithValues("name", boostObj.Name, "namespace", boostObj.Namespace)
log.V(2).Info("reconciling")
log := r.Log.WithValues("name", boostObj.Name, "namespace", boostObj.Namespace)
newBoostObj := boostObj.DeepCopy()
activeCondition := metav1.Condition{
Type: "Active",
Expand All @@ -84,23 +83,23 @@ func (r *StartupCPUBoostReconciler) Reconcile(ctx context.Context, req ctrl.Requ
}
meta.SetStatusCondition(&newBoostObj.Status.Conditions, activeCondition)
if !equality.Semantic.DeepEqual(newBoostObj.Status, boostObj.Status) {
log.V(5).Info("updating status")
log.V(5).Info("updating boost status")
err = r.Client.Status().Update(ctx, newBoostObj)
}
if err != nil {
if apierrors.IsConflict(err) {
log.V(5).Info("status update conflict, requeueing")
log.V(5).Info("boost status update conflict, requeueing")
return ctrl.Result{Requeue: true}, nil
}
log.V(5).Error(err, "failed to update status")
log.Error(err, "boost status update error")
return ctrl.Result{}, client.IgnoreNotFound(err)
}
return ctrl.Result{}, nil
}

// SetupWithManager sets up the controller with the Manager.
func (r *StartupCPUBoostReconciler) SetupWithManager(mgr ctrl.Manager) error {
boostPodHandler := NewBoostPodHandler(r.Manager, r.Log.WithName("pod-handler"))
boostPodHandler := NewBoostPodHandler(r.Manager, ctrl.Log.WithName("pod-handler"))
lsPredicate, err := predicate.LabelSelectorPredicate(*boostPodHandler.GetPodLabelSelector())
if err != nil {
return err
Expand All @@ -119,15 +118,15 @@ func (r *StartupCPUBoostReconciler) Create(e event.CreateEvent) bool {
if !ok {
return true
}
log := r.Log.WithName("create").WithValues("name", boostObj.Name, "namespace", boostObj.Namespace)
log.V(2).Info("creating")
log := r.Log.WithValues("name", boostObj.Name, "namespace", boostObj.Namespace)
log.V(5).Info("handling boost create event")
ctx := ctrl.LoggerInto(context.Background(), log)
boost, err := boost.NewStartupCPUBoost(r.Client, boostObj)
if err != nil {
log.Error(err, "failed to create startup-cpu-boost from spec")
log.Error(err, "boost creation error")
}
if err := r.Manager.AddStartupCPUBoost(ctx, boost); err != nil {
log.Error(err, "failed to register startup-cpu-boost in manager")
log.Error(err, "boost registration error")
}
return true
}
Expand All @@ -137,8 +136,8 @@ func (r *StartupCPUBoostReconciler) Delete(e event.DeleteEvent) bool {
if !ok {
return true
}
log := r.Log.WithName("delete").WithValues("name", boostObj.Name, "namespace", boostObj.Namespace)
log.V(2).Info("deleting")
log := r.Log.WithValues("name", boostObj.Name, "namespace", boostObj.Namespace)
log.V(5).Info("handling boost delete event")
ctx := ctrl.LoggerInto(context.Background(), log)
r.Manager.RemoveStartupCPUBoost(ctx, boostObj.Namespace, boostObj.Name)
return true
Expand All @@ -149,13 +148,13 @@ func (r *StartupCPUBoostReconciler) Update(e event.UpdateEvent) bool {
if !ok {
return true
}
log := r.Log.WithName("update").WithValues("name", boostObj.Name, "namespace", boostObj.Namespace)
log.V(2).Info("updating")
log := r.Log.WithValues("name", boostObj.Name, "namespace", boostObj.Namespace)
log.V(5).Info("handling boost update event")
return true
}

func (r *StartupCPUBoostReconciler) Generic(e event.GenericEvent) bool {
log := r.Log.WithName("generic").WithValues("object", klog.KObj(e.Object))
log.V(2).Info("handling generic event")
log := r.Log.WithValues("object", klog.KObj(e.Object))
log.V(5).Info("handling generic event")
return true
}
11 changes: 6 additions & 5 deletions internal/controller/boost_pod_handler.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -58,7 +58,7 @@ func (h *boostPodHandler) Create(ctx context.Context, e event.CreateEvent, wq wo
log.V(5).Info("handling pod create")
boost, ok := h.boostForPod(pod)
if !ok {
log.V(5).Info("failed to get boost for pod")
log.V(5).Info("pod create skipped: no boost for pod")
return
}
boostName := boost.Name()
Expand All @@ -83,7 +83,7 @@ func (h *boostPodHandler) Delete(ctx context.Context, e event.DeleteEvent, wq wo
log.V(5).Info("handling pod delete")
boost, ok := h.boostForPod(pod)
if !ok {
log.V(5).Info("failed to get boost for pod")
log.V(5).Info("pod delete skipped: no boost for pod")
return
}
if err := boost.DeletePod(ctx, pod); err != nil {
Expand All @@ -106,15 +106,16 @@ func (h *boostPodHandler) Update(ctx context.Context, e event.UpdateEvent, wq wo
log := h.log.WithValues("pod", pod.Name, "namespace", pod.Namespace)
log.V(5).Info("handling pod update")
if equality.Semantic.DeepEqual(pod.Status.Conditions, oldPod.Status.Conditions) {
log.V(5).Info("pod update skipped: conditions did not change")
return
}
boost, ok := h.boostForPod(pod)
if !ok {
log.V(5).Info("failed to get boost for pod")
log.V(5).Info("pod update skipped: no boost for pod")
return
}
if err := boost.UpsertPod(ctx, pod); err != nil {
log.Error(err, "failed to handle pod update")
log.Error(err, "pod update failed")
}
wq.Add(reconcile.Request{
NamespacedName: types.NamespacedName{
Expand All @@ -130,7 +131,7 @@ func (h *boostPodHandler) Generic(ctx context.Context, e event.GenericEvent, wq
return
}
log := h.log.WithValues("pod", pod.Name, "namespace", pod.Namespace)
log.V(5).Info("got pod generic event")
log.V(5).Info("handling pod generic event")
}

func (h *boostPodHandler) GetPodLabelSelector() *metav1.LabelSelector {
Expand Down
18 changes: 9 additions & 9 deletions internal/webhook/podcpuboost_webhook.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -51,13 +51,13 @@ func (h *podCPUBoostHandler) Handle(ctx context.Context, req admission.Request)
if err != nil {
return admission.Errored(http.StatusBadRequest, err)
}
log := ctrl.LoggerFrom(ctx).WithName("cpuboost-webhook")
log.V(5).Info("handling Pod")
log := ctrl.LoggerFrom(ctx).WithName("boost-pod-webhook")
log.V(5).Info("handling pod")

boostImpl, ok := h.manager.StartupCPUBoostForPod(ctx, pod)
if !ok {
log.V(5).Info("no startupCPUBoost matched")
return admission.Allowed("no StartupCPUBoost matched")
log.V(5).Info("no boost matched")
return admission.Allowed("no boost matched")
}
log = log.WithValues("boost", boostImpl.Name())
h.boostContainerResources(ctx, boostImpl, pod, log)
Expand All @@ -76,8 +76,8 @@ func (h *podCPUBoostHandler) boostContainerResources(ctx context.Context, b boos
continue
}
log = log.WithValues("container", container.Name,
"CPURequests", container.Resources.Requests.Cpu().String(),
"CPULimits", container.Resources.Limits.Cpu().String(),
"cpuRequests", container.Resources.Requests.Cpu().String(),
"cpuLimits", container.Resources.Limits.Cpu().String(),
)
if resizeRequiresRestart(container, corev1.ResourceCPU) {
log.Info("skipping container due to restart policy")
Expand All @@ -86,11 +86,11 @@ func (h *podCPUBoostHandler) boostContainerResources(ctx context.Context, b boos
updateBoostAnnotation(annotation, container.Name, container.Resources)
resources := policy.NewResources(ctx, &container)
log = log.WithValues(
"newCPURequests", resources.Requests.Cpu().String(),
"newCPULimits", resources.Limits.Cpu().String(),
"newCpuRequests", resources.Requests.Cpu().String(),
"newCpuLimits", resources.Limits.Cpu().String(),
)
log.V(2).Info("increasing resources")
pod.Spec.Containers[i].Resources = *resources
log.Info("pod resources increased")
}
if len(annotation.InitCPULimits) > 0 || len(annotation.InitCPURequests) > 0 {
if pod.Annotations == nil {
Expand Down
8 changes: 4 additions & 4 deletions internal/webhook/startupcpuboost_webhook.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -45,16 +45,16 @@ func setupWebhookForStartupCPUBoost(mgr ctrl.Manager) error {
// ValidateCreate implements webhook.CustomValidator so a webhook will be registered for the type
func (w *StartupCPUBoostWebhook) ValidateCreate(ctx context.Context, obj runtime.Object) (admission.Warnings, error) {
boost := obj.(*v1alpha1.StartupCPUBoost)
log := ctrl.LoggerFrom(ctx).WithName("startupcpuboost-webhook")
log.V(5).Info("validating create", "startupcpuboost", klog.KObj(boost))
log := ctrl.LoggerFrom(ctx).WithName("boost-validate-webhook")
log.V(5).Info("handling create validation", "boos", klog.KObj(boost))
return nil, validate(boost)
}

// ValidateUpdate implements webhook.CustomValidator so a webhook will be registered for the type
func (w *StartupCPUBoostWebhook) ValidateUpdate(ctx context.Context, oldObj, newObj runtime.Object) (admission.Warnings, error) {
boost := newObj.(*v1alpha1.StartupCPUBoost)
log := ctrl.LoggerFrom(ctx).WithName("startupcpuboost-webhook")
log.V(5).Info("validating update", "startupcpuboost", klog.KObj(boost))
log := ctrl.LoggerFrom(ctx).WithName("boost-validate-webhook")
log.V(5).Info("handling update validation", "startupcpuboost", klog.KObj(boost))
return nil, validate(boost)
}

Expand Down

0 comments on commit f0ed258

Please sign in to comment.