storage e2e: capture driver pod changes, including all events

As seen in https://github.com/kubernetes/kubernetes/issues/102452, we
currently don't have pod events for the CSI driver pods because of the
different namespace and would need them to determine whether the
driver gets evicted.

Previously, only changes of the pods where logged. Perhaps even more
interesting are events in the namespace.

test/e2e/storage/podlogs/podlogs.go

@@ -33,6 +33,7 @@ import (
 	"regexp"
 	"strings"
 	"sync"
+	"time"
 
 	"github.com/pkg/errors"
 
@@ -266,18 +267,42 @@ func logsForPod(ctx context.Context, cs clientset.Interface, ns, pod string, opt
 }
 
 // WatchPods prints pod status events for a certain namespace or all namespaces
-// when namespace name is empty.
-func WatchPods(ctx context.Context, cs clientset.Interface, ns string, to io.Writer) error {
-	watcher, err := cs.CoreV1().Pods(ns).Watch(context.TODO(), meta.ListOptions{})
+// when namespace name is empty. The closer can be nil if the caller doesn't want
+// the file to be closed when watching stops.
+func WatchPods(ctx context.Context, cs clientset.Interface, ns string, to io.Writer, toCloser io.Closer) (finalErr error) {
+	defer func() {
+		if finalErr != nil && toCloser != nil {
+			toCloser.Close()
+		}
+	}()
+
+	pods, err := cs.CoreV1().Pods(ns).Watch(context.Background(), meta.ListOptions{})
 	if err != nil {
-		return errors.Wrap(err, "cannot create Pod event watcher")
+		return fmt.Errorf("cannot create Pod watcher: %w", err)
+	}
+	defer func() {
+		if finalErr != nil {
+			pods.Stop()
+		}
+	}()
+
+	events, err := cs.CoreV1().Events(ns).Watch(context.Background(), meta.ListOptions{})
+	if err != nil {
+		return fmt.Errorf("cannot create Event watcher: %w", err)
 	}
 
 	go func() {
-		defer watcher.Stop()
+		defer func() {
+			pods.Stop()
+			events.Stop()
+			if toCloser != nil {
+				toCloser.Close()
+			}
+		}()
+		timeFormat := "15:04:05.000"
 		for {
 			select {
-			case e := <-watcher.ResultChan():
+			case e := <-pods.ResultChan():
 				if e.Object == nil {
 					continue
 				}
@@ -288,7 +313,8 @@ func WatchPods(ctx context.Context, cs clientset.Interface, ns string, to io.Wri
 				}
 				buffer := new(bytes.Buffer)
 				fmt.Fprintf(buffer,
-					"pod event: %s: %s/%s %s: %s %s\n",
+					"%s pod: %s: %s/%s %s: %s %s\n",
+					time.Now().Format(timeFormat),
 					e.Type,
 					pod.Namespace,
 					pod.Name,
@@ -314,7 +340,29 @@ func WatchPods(ctx context.Context, cs clientset.Interface, ns string, to io.Wri
 					fmt.Fprintf(buffer, "\n")
 				}
 				to.Write(buffer.Bytes())
+			case e := <-events.ResultChan():
+				if e.Object == nil {
+					continue
+				}
+
+				event, ok := e.Object.(*v1.Event)
+				if !ok {
+					continue
+				}
+				to.Write([]byte(fmt.Sprintf("%s event: %s/%s %s: %s %s: %s (%v - %v)\n",
+					time.Now().Format(timeFormat),
+					event.InvolvedObject.APIVersion,
+					event.InvolvedObject.Kind,
+					event.InvolvedObject.Name,
+					event.Source.Component,
+					event.Type,
+					event.Message,
+					event.FirstTimestamp,
+					event.LastTimestamp,
+				)))
 			case <-ctx.Done():
+				to.Write([]byte(fmt.Sprintf("%s ==== stopping pod watch ====\n",
+					time.Now().Format(timeFormat))))
 				return
 			}
 		}

test/e2e/storage/utils/pod.go

@@ -19,6 +19,9 @@ package utils
 import (
 	"context"
 	"fmt"
+	"io"
+	"os"
+	"path"
 	"regexp"
 	"strings"
 	"time"
@@ -46,6 +49,8 @@ func StartPodLogs(f *framework.Framework, driverNamespace *v1.Namespace) func()
 
 	ns := driverNamespace.Name
 
+	podEventLog := ginkgo.GinkgoWriter
+	var podEventLogCloser io.Closer
 	to := podlogs.LogOutput{
 		StatusWriter: ginkgo.GinkgoWriter,
 	}
@@ -69,17 +74,22 @@ func StartPodLogs(f *framework.Framework, driverNamespace *v1.Namespace) func()
 		// keeps each directory name smaller (the full test
 		// name at one point exceeded 256 characters, which was
 		// too much for some filesystems).
-		to.LogPathPrefix = framework.TestContext.ReportDir + "/" +
-			strings.Join(components, "/") + "/"
+		logDir := framework.TestContext.ReportDir + "/" + strings.Join(components, "/")
+		to.LogPathPrefix = logDir + "/"
+
+		err := os.MkdirAll(logDir, 0755)
+		framework.ExpectNoError(err, "create pod log directory")
+		f, err := os.Create(path.Join(logDir, "pod-event.log"))
+		framework.ExpectNoError(err, "create pod events log file")
+		podEventLog = f
+		podEventLogCloser = f
 	}
 	podlogs.CopyAllLogs(ctx, cs, ns, to)
 
-	// pod events are something that the framework already collects itself
-	// after a failed test. Logging them live is only useful for interactive
-	// debugging, not when we collect reports.
-	if framework.TestContext.ReportDir == "" {
-		podlogs.WatchPods(ctx, cs, ns, ginkgo.GinkgoWriter)
-	}
+	// The framework doesn't know about the driver pods because of
+	// the separate namespace.  Therefore we always capture the
+	// events ourselves.
+	podlogs.WatchPods(ctx, cs, ns, podEventLog, podEventLogCloser)
 
 	return cancel
 }