Merge pull request #102526 from pohly/csi-driver-pod-events

storage e2e: capture driver pod events

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
 }