Migrated pod-security-admission to contextual logging (#114471)

* migrated pod-security-admission to contextual logging

Signed-off-by: Naman <namanlakhwani@gmail.com>

* updating test files for contextual logging

Signed-off-by: Naman <namanlakhwani@gmail.com>

* smalll nit

Signed-off-by: Naman <namanlakhwani@gmail.com>

* doing inline if

Signed-off-by: Naman <namanlakhwani@gmail.com>

---------

Signed-off-by: Naman <namanlakhwani@gmail.com>
This commit is contained in:
Naman Lakhwani 2023-04-12 04:04:43 +05:30 committed by GitHub
parent 4e6da50c56
commit 9c15d75f23
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 38 additions and 33 deletions

View File

@ -233,12 +233,12 @@ func (a *Admission) ValidateNamespace(ctx context.Context, attrs api.Attributes)
} }
obj, err := attrs.GetObject() obj, err := attrs.GetObject()
if err != nil { if err != nil {
klog.ErrorS(err, "failed to decode object") klog.FromContext(ctx).Error(err, "failed to decode object")
return errorResponse(err, &apierrors.NewBadRequest("failed to decode object").ErrStatus) return errorResponse(err, &apierrors.NewBadRequest("failed to decode object").ErrStatus)
} }
namespace, ok := obj.(*corev1.Namespace) namespace, ok := obj.(*corev1.Namespace)
if !ok { if !ok {
klog.InfoS("failed to assert namespace type", "type", reflect.TypeOf(obj)) klog.FromContext(ctx).Info("failed to assert namespace type", "type", reflect.TypeOf(obj))
return errorResponse(nil, &apierrors.NewBadRequest("failed to decode namespace").ErrStatus) return errorResponse(nil, &apierrors.NewBadRequest("failed to decode namespace").ErrStatus)
} }
@ -263,12 +263,12 @@ func (a *Admission) ValidateNamespace(ctx context.Context, attrs api.Attributes)
// if update, check if policy labels changed // if update, check if policy labels changed
oldObj, err := attrs.GetOldObject() oldObj, err := attrs.GetOldObject()
if err != nil { if err != nil {
klog.ErrorS(err, "failed to decode old object") klog.FromContext(ctx).Error(err, "failed to decode old object")
return errorResponse(err, &apierrors.NewBadRequest("failed to decode old object").ErrStatus) return errorResponse(err, &apierrors.NewBadRequest("failed to decode old object").ErrStatus)
} }
oldNamespace, ok := oldObj.(*corev1.Namespace) oldNamespace, ok := oldObj.(*corev1.Namespace)
if !ok { if !ok {
klog.InfoS("failed to assert old namespace type", "type", reflect.TypeOf(oldObj)) klog.FromContext(ctx).Info("failed to assert old namespace type", "type", reflect.TypeOf(oldObj))
return errorResponse(nil, &apierrors.NewBadRequest("failed to decode old namespace").ErrStatus) return errorResponse(nil, &apierrors.NewBadRequest("failed to decode old namespace").ErrStatus)
} }
oldPolicy, oldErrs := a.PolicyToEvaluate(oldNamespace.Labels) oldPolicy, oldErrs := a.PolicyToEvaluate(oldNamespace.Labels)
@ -345,7 +345,7 @@ func (a *Admission) ValidatePod(ctx context.Context, attrs api.Attributes) *admi
// short-circuit on privileged enforce+audit+warn namespaces // short-circuit on privileged enforce+audit+warn namespaces
namespace, err := a.NamespaceGetter.GetNamespace(ctx, attrs.GetNamespace()) namespace, err := a.NamespaceGetter.GetNamespace(ctx, attrs.GetNamespace())
if err != nil { if err != nil {
klog.ErrorS(err, "failed to fetch pod namespace", "namespace", attrs.GetNamespace()) klog.FromContext(ctx).Error(err, "failed to fetch pod namespace", "namespace", attrs.GetNamespace())
a.Metrics.RecordError(true, attrs) a.Metrics.RecordError(true, attrs)
return errorResponse(err, &apierrors.NewInternalError(fmt.Errorf("failed to lookup namespace %q", attrs.GetNamespace())).ErrStatus) return errorResponse(err, &apierrors.NewInternalError(fmt.Errorf("failed to lookup namespace %q", attrs.GetNamespace())).ErrStatus)
} }
@ -357,26 +357,26 @@ func (a *Admission) ValidatePod(ctx context.Context, attrs api.Attributes) *admi
obj, err := attrs.GetObject() obj, err := attrs.GetObject()
if err != nil { if err != nil {
klog.ErrorS(err, "failed to decode object") klog.FromContext(ctx).Error(err, "failed to decode object")
a.Metrics.RecordError(true, attrs) a.Metrics.RecordError(true, attrs)
return errorResponse(err, &apierrors.NewBadRequest("failed to decode object").ErrStatus) return errorResponse(err, &apierrors.NewBadRequest("failed to decode object").ErrStatus)
} }
pod, ok := obj.(*corev1.Pod) pod, ok := obj.(*corev1.Pod)
if !ok { if !ok {
klog.InfoS("failed to assert pod type", "type", reflect.TypeOf(obj)) klog.FromContext(ctx).Info("failed to assert pod type", "type", reflect.TypeOf(obj))
a.Metrics.RecordError(true, attrs) a.Metrics.RecordError(true, attrs)
return errorResponse(nil, &apierrors.NewBadRequest("failed to decode pod").ErrStatus) return errorResponse(nil, &apierrors.NewBadRequest("failed to decode pod").ErrStatus)
} }
if attrs.GetOperation() == admissionv1.Update { if attrs.GetOperation() == admissionv1.Update {
oldObj, err := attrs.GetOldObject() oldObj, err := attrs.GetOldObject()
if err != nil { if err != nil {
klog.ErrorS(err, "failed to decode old object") klog.FromContext(ctx).Error(err, "failed to decode old object")
a.Metrics.RecordError(true, attrs) a.Metrics.RecordError(true, attrs)
return errorResponse(err, &apierrors.NewBadRequest("failed to decode old object").ErrStatus) return errorResponse(err, &apierrors.NewBadRequest("failed to decode old object").ErrStatus)
} }
oldPod, ok := oldObj.(*corev1.Pod) oldPod, ok := oldObj.(*corev1.Pod)
if !ok { if !ok {
klog.InfoS("Failed to assert old pod type", "type", reflect.TypeOf(oldObj)) klog.FromContext(ctx).Info("failed to assert old pod type", "type", reflect.TypeOf(oldObj))
a.Metrics.RecordError(true, attrs) a.Metrics.RecordError(true, attrs)
return errorResponse(nil, &apierrors.NewBadRequest("failed to decode old pod").ErrStatus) return errorResponse(nil, &apierrors.NewBadRequest("failed to decode old pod").ErrStatus)
} }
@ -409,7 +409,7 @@ func (a *Admission) ValidatePodController(ctx context.Context, attrs api.Attribu
// short-circuit on privileged audit+warn namespaces // short-circuit on privileged audit+warn namespaces
namespace, err := a.NamespaceGetter.GetNamespace(ctx, attrs.GetNamespace()) namespace, err := a.NamespaceGetter.GetNamespace(ctx, attrs.GetNamespace())
if err != nil { if err != nil {
klog.ErrorS(err, "failed to fetch pod namespace", "namespace", attrs.GetNamespace()) klog.FromContext(ctx).Error(err, "failed to fetch pod namespace", "namespace", attrs.GetNamespace())
a.Metrics.RecordError(true, attrs) a.Metrics.RecordError(true, attrs)
response := allowedResponse() response := allowedResponse()
response.AuditAnnotations = map[string]string{ response.AuditAnnotations = map[string]string{
@ -424,7 +424,7 @@ func (a *Admission) ValidatePodController(ctx context.Context, attrs api.Attribu
obj, err := attrs.GetObject() obj, err := attrs.GetObject()
if err != nil { if err != nil {
klog.ErrorS(err, "failed to decode object") klog.FromContext(ctx).Error(err, "failed to decode object")
a.Metrics.RecordError(true, attrs) a.Metrics.RecordError(true, attrs)
response := allowedResponse() response := allowedResponse()
response.AuditAnnotations = map[string]string{ response.AuditAnnotations = map[string]string{
@ -434,7 +434,7 @@ func (a *Admission) ValidatePodController(ctx context.Context, attrs api.Attribu
} }
podMetadata, podSpec, err := a.PodSpecExtractor.ExtractPodSpec(obj) podMetadata, podSpec, err := a.PodSpecExtractor.ExtractPodSpec(obj)
if err != nil { if err != nil {
klog.ErrorS(err, "failed to extract pod spec") klog.FromContext(ctx).Error(err, "failed to extract pod spec")
a.Metrics.RecordError(true, attrs) a.Metrics.RecordError(true, attrs)
response := allowedResponse() response := allowedResponse()
response.AuditAnnotations = map[string]string{ response.AuditAnnotations = map[string]string{
@ -453,6 +453,7 @@ func (a *Admission) ValidatePodController(ctx context.Context, attrs api.Attribu
// The enforce policy is only checked if enforce=true. // The enforce policy is only checked if enforce=true.
// The returned response may be shared between evaluations and must not be mutated. // The returned response may be shared between evaluations and must not be mutated.
func (a *Admission) EvaluatePod(ctx context.Context, nsPolicy api.Policy, nsPolicyErr error, podMetadata *metav1.ObjectMeta, podSpec *corev1.PodSpec, attrs api.Attributes, enforce bool) *admissionv1.AdmissionResponse { func (a *Admission) EvaluatePod(ctx context.Context, nsPolicy api.Policy, nsPolicyErr error, podMetadata *metav1.ObjectMeta, podSpec *corev1.PodSpec, attrs api.Attributes, enforce bool) *admissionv1.AdmissionResponse {
logger := klog.FromContext(ctx)
// short-circuit on exempt runtimeclass // short-circuit on exempt runtimeclass
if a.exemptRuntimeClass(podSpec.RuntimeClassName) { if a.exemptRuntimeClass(podSpec.RuntimeClassName) {
a.Metrics.RecordExemption(attrs) a.Metrics.RecordExemption(attrs)
@ -461,14 +462,13 @@ func (a *Admission) EvaluatePod(ctx context.Context, nsPolicy api.Policy, nsPoli
auditAnnotations := map[string]string{} auditAnnotations := map[string]string{}
if nsPolicyErr != nil { if nsPolicyErr != nil {
klog.V(2).InfoS("failed to parse PodSecurity namespace labels", "err", nsPolicyErr) logger.V(2).Info("failed to parse PodSecurity namespace labels", "err", nsPolicyErr)
auditAnnotations["error"] = fmt.Sprintf("Failed to parse policy: %v", nsPolicyErr) auditAnnotations["error"] = fmt.Sprintf("Failed to parse policy: %v", nsPolicyErr)
a.Metrics.RecordError(false, attrs) a.Metrics.RecordError(false, attrs)
} }
klogV := klog.V(5) if klogV := logger.V(5); klogV.Enabled() {
if klogV.Enabled() { klogV.Info("PodSecurity evaluation", "policy", fmt.Sprintf("%v", nsPolicy), "op", attrs.GetOperation(), "resource", attrs.GetResource(), "namespace", attrs.GetNamespace(), "name", attrs.GetName())
klogV.InfoS("PodSecurity evaluation", "policy", fmt.Sprintf("%v", nsPolicy), "op", attrs.GetOperation(), "resource", attrs.GetResource(), "namespace", attrs.GetNamespace(), "name", attrs.GetName())
} }
cachedResults := make(map[api.LevelVersion]policy.AggregateCheckResult) cachedResults := make(map[api.LevelVersion]policy.AggregateCheckResult)
response := allowedResponse() response := allowedResponse()
@ -551,7 +551,7 @@ func (a *Admission) EvaluatePodsInNamespace(ctx context.Context, namespace strin
pods, err := a.PodLister.ListPods(ctx, namespace) pods, err := a.PodLister.ListPods(ctx, namespace)
if err != nil { if err != nil {
klog.ErrorS(err, "failed to list pods", "namespace", namespace) klog.FromContext(ctx).Error(err, "failed to list pods", "namespace", namespace)
return []string{"failed to list pods while checking new PodSecurity enforce level"} return []string{"failed to list pods while checking new PodSecurity enforce level"}
} }

View File

@ -38,6 +38,7 @@ import (
"k8s.io/apimachinery/pkg/runtime/schema" "k8s.io/apimachinery/pkg/runtime/schema"
"k8s.io/apimachinery/pkg/types" "k8s.io/apimachinery/pkg/types"
"k8s.io/apimachinery/pkg/util/uuid" "k8s.io/apimachinery/pkg/util/uuid"
"k8s.io/klog/v2/ktesting"
admissionapi "k8s.io/pod-security-admission/admission/api" admissionapi "k8s.io/pod-security-admission/admission/api"
"k8s.io/pod-security-admission/admission/api/load" "k8s.io/pod-security-admission/admission/api/load"
"k8s.io/pod-security-admission/api" "k8s.io/pod-security-admission/api"
@ -504,6 +505,7 @@ func TestValidateNamespace(t *testing.T) {
for _, tc := range testcases { for _, tc := range testcases {
t.Run(tc.name, func(t *testing.T) { t.Run(tc.name, func(t *testing.T) {
_, ctx := ktesting.NewTestContext(t)
newObject := &corev1.Namespace{ newObject := &corev1.Namespace{
ObjectMeta: metav1.ObjectMeta{ ObjectMeta: metav1.ObjectMeta{
Name: "test", Name: "test",
@ -587,7 +589,7 @@ func TestValidateNamespace(t *testing.T) {
namespacePodCheckTimeout: time.Second, namespacePodCheckTimeout: time.Second,
namespaceMaxPodsToCheck: 4, namespaceMaxPodsToCheck: 4,
} }
result := a.ValidateNamespace(context.TODO(), attrs) result := a.ValidateNamespace(ctx, attrs)
if result.Allowed != tc.expectAllowed { if result.Allowed != tc.expectAllowed {
t.Errorf("expected allowed=%v, got %v", tc.expectAllowed, result.Allowed) t.Errorf("expected allowed=%v, got %v", tc.expectAllowed, result.Allowed)
} }
@ -960,6 +962,7 @@ func TestValidatePodAndController(t *testing.T) {
for _, tc := range testCases { for _, tc := range testCases {
t.Run(tc.desc, func(t *testing.T) { t.Run(tc.desc, func(t *testing.T) {
_, ctx := ktesting.NewTestContext(t)
if tc.obj != nil { if tc.obj != nil {
tc.obj.(metav1.ObjectMetaAccessor).GetObjectMeta().SetNamespace(tc.namespace) tc.obj.(metav1.ObjectMetaAccessor).GetObjectMeta().SetNamespace(tc.namespace)
} }
@ -999,7 +1002,7 @@ func TestValidatePodAndController(t *testing.T) {
require.NoError(t, a.CompleteConfiguration(), "CompleteConfiguration()") require.NoError(t, a.CompleteConfiguration(), "CompleteConfiguration()")
require.NoError(t, a.ValidateConfiguration(), "ValidateConfiguration()") require.NoError(t, a.ValidateConfiguration(), "ValidateConfiguration()")
response := a.Validate(context.TODO(), attrs) response := a.Validate(ctx, attrs)
var expectedEvaluations []MetricsRecord var expectedEvaluations []MetricsRecord
var expectedAuditAnnotationKeys []string var expectedAuditAnnotationKeys []string

View File

@ -112,6 +112,7 @@ type Server struct {
func (s *Server) Start(ctx context.Context) error { func (s *Server) Start(ctx context.Context) error {
s.informerFactory.Start(ctx.Done()) s.informerFactory.Start(ctx.Done())
logger := klog.FromContext(ctx)
mux := http.NewServeMux() mux := http.NewServeMux()
healthz.InstallHandler(mux, healthz.PingHealthz) healthz.InstallHandler(mux, healthz.PingHealthz)
@ -141,11 +142,11 @@ func (s *Server) Start(ctx context.Context) error {
} }
<-listenerStoppedCh <-listenerStoppedCh
klog.V(1).InfoS("[graceful-termination] HTTP Server has stopped listening") logger.V(1).Info("[graceful-termination] HTTP Server has stopped listening")
// Wait for graceful shutdown. // Wait for graceful shutdown.
<-shutdownCh <-shutdownCh
klog.V(1).Info("[graceful-termination] HTTP Server is exiting") logger.V(1).Info("[graceful-termination] HTTP Server is exiting")
return nil return nil
} }
@ -157,14 +158,15 @@ func (s *Server) HandleValidate(w http.ResponseWriter, r *http.Request) {
}) })
var ( var (
body []byte body []byte
err error err error
ctx = r.Context() ctx = r.Context()
logger = klog.FromContext(ctx)
) )
if timeout, ok, err := parseTimeout(r); err != nil { if timeout, ok, err := parseTimeout(r); err != nil {
// Ignore an invalid timeout. // Ignore an invalid timeout.
klog.V(2).InfoS("Invalid timeout", "error", err) logger.V(2).Info("Invalid timeout", "error", err)
} else if ok { } else if ok {
var cancel context.CancelFunc var cancel context.CancelFunc
ctx, cancel = context.WithTimeout(ctx, timeout) ctx, cancel = context.WithTimeout(ctx, timeout)
@ -173,7 +175,7 @@ func (s *Server) HandleValidate(w http.ResponseWriter, r *http.Request) {
if r.Body == nil || r.Body == http.NoBody { if r.Body == nil || r.Body == http.NoBody {
err = errors.New("request body is empty") err = errors.New("request body is empty")
klog.ErrorS(err, "bad request") logger.Error(err, "bad request")
http.Error(w, err.Error(), http.StatusBadRequest) http.Error(w, err.Error(), http.StatusBadRequest)
return return
} }
@ -181,12 +183,12 @@ func (s *Server) HandleValidate(w http.ResponseWriter, r *http.Request) {
defer r.Body.Close() defer r.Body.Close()
limitedReader := &io.LimitedReader{R: r.Body, N: maxRequestSize} limitedReader := &io.LimitedReader{R: r.Body, N: maxRequestSize}
if body, err = ioutil.ReadAll(limitedReader); err != nil { if body, err = ioutil.ReadAll(limitedReader); err != nil {
klog.ErrorS(err, "unable to read the body from the incoming request") logger.Error(err, "unable to read the body from the incoming request")
http.Error(w, "unable to read the body from the incoming request", http.StatusBadRequest) http.Error(w, "unable to read the body from the incoming request", http.StatusBadRequest)
return return
} }
if limitedReader.N <= 0 { if limitedReader.N <= 0 {
klog.ErrorS(err, "unable to read the body from the incoming request; limit reached") logger.Error(err, "unable to read the body from the incoming request; limit reached")
http.Error(w, fmt.Sprintf("request entity is too large; limit is %d bytes", maxRequestSize), http.StatusRequestEntityTooLarge) http.Error(w, fmt.Sprintf("request entity is too large; limit is %d bytes", maxRequestSize), http.StatusRequestEntityTooLarge)
return return
} }
@ -194,7 +196,7 @@ func (s *Server) HandleValidate(w http.ResponseWriter, r *http.Request) {
// verify the content type is accurate // verify the content type is accurate
if contentType := r.Header.Get("Content-Type"); contentType != "application/json" { if contentType := r.Header.Get("Content-Type"); contentType != "application/json" {
err = fmt.Errorf("contentType=%s, expected application/json", contentType) err = fmt.Errorf("contentType=%s, expected application/json", contentType)
klog.ErrorS(err, "unable to process a request with an unknown content type", "contentType", contentType) logger.Error(err, "unable to process a request with an unknown content type", "type", contentType)
http.Error(w, "unable to process a request with a non-json content type", http.StatusBadRequest) http.Error(w, "unable to process a request with a non-json content type", http.StatusBadRequest)
return return
} }
@ -202,21 +204,21 @@ func (s *Server) HandleValidate(w http.ResponseWriter, r *http.Request) {
v1AdmissionReviewKind := admissionv1.SchemeGroupVersion.WithKind("AdmissionReview") v1AdmissionReviewKind := admissionv1.SchemeGroupVersion.WithKind("AdmissionReview")
reviewObject, gvk, err := codecs.UniversalDeserializer().Decode(body, &v1AdmissionReviewKind, nil) reviewObject, gvk, err := codecs.UniversalDeserializer().Decode(body, &v1AdmissionReviewKind, nil)
if err != nil { if err != nil {
klog.ErrorS(err, "unable to decode the request") logger.Error(err, "unable to decode the request")
http.Error(w, "unable to decode the request", http.StatusBadRequest) http.Error(w, "unable to decode the request", http.StatusBadRequest)
return return
} }
if *gvk != v1AdmissionReviewKind { if *gvk != v1AdmissionReviewKind {
klog.InfoS("Unexpected AdmissionReview kind", "kind", gvk.String()) logger.Info("Unexpected AdmissionReview kind", "kind", gvk.String())
http.Error(w, fmt.Sprintf("unexpected AdmissionReview kind: %s", gvk.String()), http.StatusBadRequest) http.Error(w, fmt.Sprintf("unexpected AdmissionReview kind: %s", gvk.String()), http.StatusBadRequest)
return return
} }
review, ok := reviewObject.(*admissionv1.AdmissionReview) review, ok := reviewObject.(*admissionv1.AdmissionReview)
if !ok { if !ok {
klog.InfoS("Failed admissionv1.AdmissionReview type assertion") logger.Info("Failed admissionv1.AdmissionReview type assertion")
http.Error(w, "unexpected AdmissionReview type", http.StatusBadRequest) http.Error(w, "unexpected AdmissionReview type", http.StatusBadRequest)
} }
klog.V(1).InfoS("received request", "UID", review.Request.UID, "kind", review.Request.Kind, "resource", review.Request.Resource) logger.V(1).Info("received request", "UID", review.Request.UID, "kind", review.Request.Kind, "resource", review.Request.Resource)
attributes := api.RequestAttributes(review.Request, codecs.UniversalDeserializer()) attributes := api.RequestAttributes(review.Request, codecs.UniversalDeserializer())
response := s.delegate.Validate(ctx, attributes) response := s.delegate.Validate(ctx, attributes)