Increase logging output of Kubernetes pluginskube

Signed-off-by: Christian Heimes <cheimes@redhat.com>

3 files changed, 25 insertions, 10 deletions

diff --git a/custodia/httpd/server.py b/custodia/httpd/server.py
index decf401..392d8fb 100644
--- a/custodia/httpd/server.py
+++ b/custodia/httpd/server.py
@@ -159,7 +159,7 @@ class HTTPRequestHandler(BaseHTTPRequestHandler):
         try:
             creds = self.request.getsockopt(socket.SOL_SOCKET, SO_PEERSEC,
                                             SELINUX_CONTEXT_LEN)
-            context = creds.decode('utf-8')
+            context = creds.rstrip(b'\x00').decode('utf-8')
         except Exception:  # pylint: disable=broad-except
             logger.debug("Couldn't retrieve SELinux Context", exc_info=True)
             context = None
@@ -245,7 +245,13 @@ class HTTPRequestHandler(BaseHTTPRequestHandler):
                        'version': self.request_version,
                        'headers': self.headers,
                        'body': self.body}
-            logger.debug("REQUEST: %r", request)
+            logger.debug(
+                "REQUEST: %s %s, query: %r, cred: %r, client_id: %s, "
+                "headers: %r, body: %r",
+                request['command'], request['path'], request['query'],
+                request['creds'], request['client_id'],
+                dict(request['headers']), request['body']
+            )
             try:
                 response = self.pipeline(self.server.config, request)
                 if response is None:
diff --git a/custodia/kubernetes/authz.py b/custodia/kubernetes/authz.py
index 4342f6f..cb9c68d 100644
--- a/custodia/kubernetes/authz.py
+++ b/custodia/kubernetes/authz.py
@@ -36,7 +36,7 @@ class KubeAuthz(HTTPAuthorizer):
         trail = path[len(prefix) + 1:]
 
         (namespace, podname, secret) = trail.split('/', 2)
-        self.logger.debug("Checking if pod %s,%s has access to secret %s",
+        self.logger.debug("Checking if pod %s/%s has access to secret %s",
                           namespace, podname, secret)
 
         try:
@@ -52,6 +52,10 @@ class KubeAuthz(HTTPAuthorizer):
                                   request['client_id'], path)
             return False
 
+        self.logger.debug(
+            "Pod %s/%s runs on node %s with secret namespace %s.",
+            namespace, podname, node_id, secrets_namespace)
+
         if node_id != request.get("remote_user"):
             self.logger.debug("Node authenticated as %s, but pod is believed "
                               "to be running on %s",
diff --git a/custodia/kubernetes/node.py b/custodia/kubernetes/node.py
index 5d4f863..99f5d1b 100644
--- a/custodia/kubernetes/node.py
+++ b/custodia/kubernetes/node.py
@@ -38,7 +38,7 @@ class NodeAuth(HTTPAuthenticator):
             return None
         dockerid = self._pid2dockerid(int(creds['pid']))
         if dockerid is None:
-            self.logger.debug("Didn't find docker ID for pid %s", creds['pid'])
+            self.logger.debug("Didn't find Docker ID for pid %s", creds['pid'])
             return None
 
         try:
@@ -50,24 +50,29 @@ class NodeAuth(HTTPAuthenticator):
             self.logger.debug("Failed to query docker for [%s:%s]: %s",
                               creds['pid'], dockerid, err)
             self.audit_svc_access(log.AUDIT_SVC_AUTH_FAIL,
-                                      request['client_id'], dockerid)
+                                  request['client_id'], dockerid)
             return False
 
         if data_id != dockerid:
-            self.logger.debug("Docker ID %s not found!", dockerid)
+            self.logger.debug("Docker ID %s not found for pid %s!",
+                              dockerid, creds['pid'])
             self.audit_svc_access(log.AUDIT_SVC_AUTH_FAIL,
-                                      request['client_id'], dockerid)
+                                  request['client_id'], dockerid)
             return False
 
         podname = data_labels.get('io.kubernetes.pod.name')
         if podname is None:
-            self.logger.debug("Pod Name not found for Docker ID %s", dockerid)
+            self.logger.debug("Pod Name not found for Docker ID %s, pid %s",
+                              dockerid, creds['pid'])
             self.audit_svc_access(log.AUDIT_SVC_AUTH_FAIL,
-                                      request['client_id'], dockerid)
+                                  request['client_id'], dockerid)
             return False
 
+        self.logger.debug("PID %s runs in Docker container %s of pod '%s'",
+                          creds['pid'], dockerid, podname)
+
         self.audit_svc_access(log.AUDIT_SVC_AUTH_PASS,
-                                  request['client_id'], dockerid)
+                              request['client_id'], dockerid)
         request['client_id'] = dockerid
         request['remote_user'] = podname
         return True