Skip to content

Commit d28c245

Browse files
authored
Refactor webhook logging (kubeflow#2799)
* refactor(webhook): get logger with predefined values from context Signed-off-by: Yi Chen <github@chenyicn.net> * refactor(webhook): use a customized log constructor Signed-off-by: Yi Chen <github@chenyicn.net> * Update logging statements Signed-off-by: Yi Chen <github@chenyicn.net> --------- Signed-off-by: Yi Chen <github@chenyicn.net>
1 parent 9b80960 commit d28c245

7 files changed

Lines changed: 51 additions & 26 deletions

File tree

cmd/operator/webhook/start.go

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -284,6 +284,7 @@ func start() {
284284
For(&v1beta2.SparkApplication{}).
285285
WithDefaulter(webhook.NewSparkApplicationDefaulter()).
286286
WithValidator(webhook.NewSparkApplicationValidator(mgr.GetClient(), enableResourceQuotaEnforcement)).
287+
WithLogConstructor(webhook.LogConstructor).
287288
Complete(); err != nil {
288289
logger.Error(err, "Failed to create mutating webhook for Spark application")
289290
os.Exit(1)
@@ -293,6 +294,7 @@ func start() {
293294
For(&v1beta2.ScheduledSparkApplication{}).
294295
WithDefaulter(webhook.NewScheduledSparkApplicationDefaulter()).
295296
WithValidator(webhook.NewScheduledSparkApplicationValidator()).
297+
WithLogConstructor(webhook.LogConstructor).
296298
Complete(); err != nil {
297299
logger.Error(err, "Failed to create mutating webhook for Scheduled Spark application")
298300
os.Exit(1)
@@ -301,6 +303,7 @@ func start() {
301303
if err := ctrl.NewWebhookManagedBy(mgr).
302304
For(&corev1.Pod{}).
303305
WithDefaulter(webhook.NewSparkPodDefaulter(mgr.GetClient(), namespaces)).
306+
WithLogConstructor(webhook.LogConstructor).
304307
Complete(); err != nil {
305308
logger.Error(err, "Failed to create mutating webhook for Spark pod")
306309
os.Exit(1)

internal/webhook/scheduledsparkapplication_defaulter.go

Lines changed: 5 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,7 @@ import (
2020
"context"
2121

2222
"k8s.io/apimachinery/pkg/runtime"
23+
"sigs.k8s.io/controller-runtime/pkg/log"
2324
"sigs.k8s.io/controller-runtime/pkg/webhook/admission"
2425

2526
"github.com/kubeflow/spark-operator/v2/api/v1beta2"
@@ -40,10 +41,11 @@ var _ admission.CustomDefaulter = &ScheduledSparkApplicationDefaulter{}
4041

4142
// Default implements admission.CustomDefaulter.
4243
func (d *ScheduledSparkApplicationDefaulter) Default(ctx context.Context, obj runtime.Object) error {
43-
app, ok := obj.(*v1beta2.ScheduledSparkApplication)
44-
if !ok {
44+
if _, ok := obj.(*v1beta2.ScheduledSparkApplication); !ok {
4545
return nil
4646
}
47-
logger.Info("Defaulting ScheduledSparkApplication", "name", app.Name, "namespace", app.Namespace)
47+
48+
logger := log.FromContext(ctx)
49+
logger.Info("Mutating ScheduledSparkApplication")
4850
return nil
4951
}

internal/webhook/scheduledsparkapplication_validator.go

Lines changed: 8 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -23,6 +23,7 @@ import (
2323

2424
"k8s.io/apimachinery/pkg/runtime"
2525
"k8s.io/apimachinery/pkg/util/validation"
26+
"sigs.k8s.io/controller-runtime/pkg/log"
2627
"sigs.k8s.io/controller-runtime/pkg/webhook/admission"
2728

2829
"github.com/kubeflow/spark-operator/v2/api/v1beta2"
@@ -47,7 +48,8 @@ func (v *ScheduledSparkApplicationValidator) ValidateCreate(ctx context.Context,
4748
if !ok {
4849
return nil, nil
4950
}
50-
logger.Info("Validating SchedulingSparkApplication create", "name", app.Name, "namespace", app.Namespace)
51+
logger := log.FromContext(ctx)
52+
logger.Info("Validating ScheduledSparkApplication create")
5153
// Validate metadata.name early to prevent downstream Service creation failures
5254
if err := v.validateName(app.Name); err != nil {
5355
return nil, err
@@ -64,7 +66,8 @@ func (v *ScheduledSparkApplicationValidator) ValidateUpdate(ctx context.Context,
6466
if !ok {
6567
return nil, nil
6668
}
67-
logger.Info("Validating SchedulingSparkApplication update", "name", newApp.Name, "namespace", newApp.Namespace)
69+
logger := log.FromContext(ctx)
70+
logger.Info("Validating ScheduledSparkApplication update")
6871
// Name is immutable in Kubernetes, but validate anyway for safety in case of admission reconcilers
6972
if err := v.validateName(newApp.Name); err != nil {
7073
return nil, err
@@ -77,11 +80,11 @@ func (v *ScheduledSparkApplicationValidator) ValidateUpdate(ctx context.Context,
7780

7881
// ValidateDelete implements admission.CustomValidator.
7982
func (v *ScheduledSparkApplicationValidator) ValidateDelete(ctx context.Context, obj runtime.Object) (warnings admission.Warnings, err error) {
80-
app, ok := obj.(*v1beta2.ScheduledSparkApplication)
81-
if !ok {
83+
if _, ok := obj.(*v1beta2.ScheduledSparkApplication); !ok {
8284
return nil, nil
8385
}
84-
logger.Info("Validating ScheduledSparkApplication delete", "name", app.Name, "namespace", app.Namespace)
86+
logger := log.FromContext(ctx)
87+
logger.Info("Validating ScheduledSparkApplication delete")
8588
return nil, nil
8689
}
8790

internal/webhook/sparkapplication_defaulter.go

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,7 @@ import (
2020
"context"
2121

2222
"k8s.io/apimachinery/pkg/runtime"
23+
"sigs.k8s.io/controller-runtime/pkg/log"
2324
"sigs.k8s.io/controller-runtime/pkg/webhook/admission"
2425

2526
"github.com/kubeflow/spark-operator/v2/api/v1beta2"
@@ -53,7 +54,8 @@ func (d *SparkApplicationDefaulter) Default(ctx context.Context, obj runtime.Obj
5354
return nil
5455
}
5556

56-
logger.Info("Defaulting SparkApplication", "name", app.Name, "namespace", app.Namespace, "state", util.GetApplicationState(app))
57+
logger := log.FromContext(ctx)
58+
logger.Info("Mutating SparkApplication", "state", util.GetApplicationState(app))
5759
operatorscheme.WebhookScheme.Default(app)
5860
return nil
5961
}

internal/webhook/sparkapplication_validator.go

Lines changed: 8 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -26,6 +26,7 @@ import (
2626
"k8s.io/apimachinery/pkg/runtime"
2727
"k8s.io/apimachinery/pkg/util/validation"
2828
"sigs.k8s.io/controller-runtime/pkg/client"
29+
"sigs.k8s.io/controller-runtime/pkg/log"
2930
"sigs.k8s.io/controller-runtime/pkg/webhook/admission"
3031

3132
"github.com/kubeflow/spark-operator/v2/api/v1beta2"
@@ -59,7 +60,8 @@ func (v *SparkApplicationValidator) ValidateCreate(ctx context.Context, obj runt
5960
if !ok {
6061
return nil, nil
6162
}
62-
logger.Info("Validating SparkApplication create", "name", app.Name, "namespace", app.Namespace, "state", util.GetApplicationState(app))
63+
logger := log.FromContext(ctx)
64+
logger.Info("Validating SparkApplication create", "state", util.GetApplicationState(app))
6365

6466
// Validate metadata.name early to prevent downstream Service creation failures
6567
if err := v.validateName(app.Name); err != nil {
@@ -90,7 +92,8 @@ func (v *SparkApplicationValidator) ValidateUpdate(ctx context.Context, oldObj r
9092
return nil, nil
9193
}
9294

93-
logger.Info("Validating SparkApplication update", "name", newApp.Name, "namespace", newApp.Namespace)
95+
logger := log.FromContext(ctx)
96+
logger.Info("Validating SparkApplication update", "state", util.GetApplicationState(newApp))
9497

9598
// Name is immutable in Kubernetes, but validate anyway for safety in case of admission reconcilers
9699
if err := v.validateName(newApp.Name); err != nil {
@@ -122,13 +125,12 @@ func (v *SparkApplicationValidator) ValidateDelete(ctx context.Context, obj runt
122125
if !ok {
123126
return nil, nil
124127
}
125-
logger.Info("Validating SparkApplication delete", "name", app.Name, "namespace", app.Namespace, "state", util.GetApplicationState(app))
128+
logger := log.FromContext(ctx)
129+
logger.Info("Validating SparkApplication delete", "state", util.GetApplicationState(app))
126130
return nil, nil
127131
}
128132

129-
func (v *SparkApplicationValidator) validateSpec(_ context.Context, app *v1beta2.SparkApplication) error {
130-
logger.V(1).Info("Validating SparkApplication spec", "name", app.Name, "namespace", app.Namespace, "state", util.GetApplicationState(app))
131-
133+
func (v *SparkApplicationValidator) validateSpec(ctx context.Context, app *v1beta2.SparkApplication) error {
132134
if err := v.validateSparkVersion(app); err != nil {
133135
return err
134136
}
@@ -181,8 +183,6 @@ func (v *SparkApplicationValidator) validateSparkVersion(app *v1beta2.SparkAppli
181183
}
182184

183185
func (v *SparkApplicationValidator) validateResourceUsage(ctx context.Context, app *v1beta2.SparkApplication) error {
184-
logger.V(1).Info("Validating SparkApplication resource usage", "name", app.Name, "namespace", app.Namespace, "state", util.GetApplicationState(app))
185-
186186
requests, err := getResourceList(app)
187187
if err != nil {
188188
return fmt.Errorf("failed to calculate resource quests: %v", err)

internal/webhook/sparkpod_defaulter.go

Lines changed: 7 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -29,6 +29,7 @@ import (
2929
"k8s.io/apimachinery/pkg/runtime"
3030
"k8s.io/apimachinery/pkg/types"
3131
"sigs.k8s.io/controller-runtime/pkg/client"
32+
"sigs.k8s.io/controller-runtime/pkg/log"
3233
"sigs.k8s.io/controller-runtime/pkg/webhook/admission"
3334

3435
"github.com/kubeflow/spark-operator/v2/api/v1beta2"
@@ -75,6 +76,7 @@ func (d *SparkPodDefaulter) Default(ctx context.Context, obj runtime.Object) err
7576
return nil
7677
}
7778

79+
logger := log.FromContext(ctx)
7880
namespace := pod.Namespace
7981
if !d.isSparkJobNamespace(namespace) {
8082
return nil
@@ -90,9 +92,8 @@ func (d *SparkPodDefaulter) Default(ctx context.Context, obj runtime.Object) err
9092
return fmt.Errorf("failed to get SparkApplication %s/%s: %v", namespace, appName, err)
9193
}
9294

93-
logger.Info("Mutating Spark pod", "name", pod.Name, "namespace", namespace, "phase", pod.Status.Phase)
95+
logger.Info("Mutating Pod", "phase", pod.Status.Phase)
9496
if err := mutateSparkPod(pod, app); err != nil {
95-
logger.Info("Denying Spark pod", "name", pod.Name, "namespace", namespace, "errorMessage", err.Error())
9697
return fmt.Errorf("failed to mutate Spark pod: %v", err)
9798
}
9899

@@ -128,7 +129,6 @@ func addMemoryLimit(pod *corev1.Pod, app *v1beta2.SparkApplication) error {
128129

129130
// Apply the memory limit to the container's resources
130131
pod.Spec.Containers[i].Resources.Limits[corev1.ResourceMemory] = limitQuantity
131-
logger.V(1).Info("Added memory limit to Spark container in pod", "name", pod.Name, "namespace", pod.Namespace, "memoryLimit", limitQuantity.String())
132132
return nil
133133
}
134134

@@ -336,11 +336,12 @@ func addGeneralConfigMaps(pod *corev1.Pod, app *v1beta2.SparkApplication) error
336336
configMaps = app.Spec.Executor.ConfigMaps
337337
}
338338

339+
logger := log.FromContext(context.TODO())
339340
for _, namePath := range configMaps {
340341
volumeName := namePath.Name + "-vol"
341342
if len(volumeName) > maxNameLength {
342343
volumeName = volumeName[0:maxNameLength]
343-
logger.Info(fmt.Sprintf("ConfigMap volume name is too long. Truncating to length %d. Result: %s.", maxNameLength, volumeName))
344+
logger.Info("ConfigMap volume name is too long. Truncating", "result", volumeName)
344345
}
345346
if err := addConfigMapVolume(pod, namePath.Name, volumeName); err != nil {
346347
return err
@@ -632,6 +633,8 @@ func addGPU(pod *corev1.Pod, app *v1beta2.SparkApplication) error {
632633
if gpu == nil {
633634
return nil
634635
}
636+
637+
logger := log.FromContext(context.TODO())
635638
if gpu.Name == "" {
636639
logger.V(1).Info(fmt.Sprintf("Please specify GPU resource name, such as: nvidia.com/gpu, amd.com/gpu etc. Current gpu spec: %+v", gpu))
637640
return nil

internal/webhook/webhook.go

Lines changed: 17 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -17,11 +17,9 @@ limitations under the License.
1717
package webhook
1818

1919
import (
20-
ctrl "sigs.k8s.io/controller-runtime"
21-
)
22-
23-
var (
24-
logger = ctrl.Log.WithName("")
20+
"github.com/go-logr/logr"
21+
"k8s.io/klog/v2"
22+
"sigs.k8s.io/controller-runtime/pkg/webhook/admission"
2523
)
2624

2725
type Options struct {
@@ -35,3 +33,17 @@ type Options struct {
3533
WebhookMetricsBindAddress string
3634
EnableResourceQuotaEnforcement bool
3735
}
36+
37+
// LogConstructor is used to customize the loggers used in webhooks.
38+
func LogConstructor(logger logr.Logger, req *admission.Request) logr.Logger {
39+
if req == nil {
40+
return logger
41+
}
42+
43+
return logger.WithValues(
44+
req.Kind.Kind,
45+
klog.KRef(req.Namespace, req.Name),
46+
"requestID",
47+
req.UID,
48+
)
49+
}

0 commit comments

Comments
 (0)