Capture logs for all containers used in tests (#1869)

Co-authored-by: Giles Hutton <[email protected]>

.github/workflows/integration-tests-vm-type.yml

@@ -127,5 +127,6 @@ jobs:
         with:
           name: ${{ inputs.vm_type }}-logs
           path: |
-            ${{ github.workspace }}/integration-tests/container-logs/**/*
-            ${{ github.workspace }}/integration-tests/performance-logs/**/*
+            ${{ github.workspace }}/integration-tests/container-logs/
+            ${{ github.workspace }}/integration-tests/performance-logs/
+          if-no-files-found: ignore

Makefile

@@ -102,7 +102,7 @@ teardown-builder:
 clean:
 	rm -rf cmake-build*
 	make -C collector clean
-	make -C integration-tests docker-clean
+	make -C integration-tests clean
 
 .PHONY: shfmt-check
 shfmt-check:

ansible/roles/run-test-target/tasks/test-collection-method.yml

@@ -8,7 +8,7 @@
 #
 
 - set_fact:
-    logs_root: "{{ collector_root }}/integration-tests/container-logs/{{ vm_config }}/{{ collection_method }}"
+    logs_root: "{{ collector_root }}/integration-tests/container-logs"
 
 - name: Cleanup old containers
   become: "{{ runtime_as_root }}"
@@ -122,19 +122,16 @@
         path: "{{ logs_root }}"
       delegate_to: localhost
 
-    - name: Get log files
-      find:
-        paths: "{{ remote_log_mount }}/{{ vm_config }}/{{ collection_method }}/"
-      register: remote_log_files
+    - name: Compress log files
+      ansible.builtin.archive:
+        path: "{{ remote_log_mount }}"
+        dest: /tmp/{{ vm_config }}-{{ collection_method }}.tar.gz
 
     - name: Fetch log files
       fetch:
-        src: "{{ remote_log_path }}"
+        src: /tmp/{{ vm_config }}-{{ collection_method }}.tar.gz
         dest: "{{ logs_root }}/"
         flat: true
-      loop: "{{ remote_log_files.files | map(attribute='path') | list }}"
-      loop_control:
-        loop_var: remote_log_path
 
     - name: Write integration test log
       copy:

integration-tests/Makefile

@@ -95,6 +95,10 @@ ci-benchmarks: benchmark
 docker-clean:
 	docker rm -fv container-stats benchmark collector grpc-server 2>/dev/null || true
 
+.PHONY: clean
+clean: docker-clean
+	rm -rf container-logs/
+
 .PHONY:
 benchmark: TestBenchmarkCollector
 

integration-tests/pkg/collector/collector_docker.go

@@ -11,7 +11,6 @@ import (
 	"github.com/stackrox/collector/integration-tests/pkg/common"
 	"github.com/stackrox/collector/integration-tests/pkg/config"
 	"github.com/stackrox/collector/integration-tests/pkg/executor"
-	"github.com/stackrox/collector/integration-tests/pkg/log"
 )
 
 type DockerCollectorManager struct {
@@ -156,19 +155,7 @@ func (c *DockerCollectorManager) launchCollector() error {
 }
 
 func (c *DockerCollectorManager) captureLogs(containerName string) (string, error) {
-	logs, err := c.executor.GetContainerLogs(containerName)
-	if err != nil {
-		return "", log.Error("logs error (%v) for container %s\n", err, containerName)
-	}
-
-	logFile, err := common.PrepareLog(c.testName, "collector.log")
-	if err != nil {
-		return "", err
-	}
-	defer logFile.Close()
-
-	_, err = logFile.WriteString(logs)
-	return logs, nil
+	return c.executor.CaptureLogs(c.testName, containerName)
 }
 
 func (c *DockerCollectorManager) killContainer(name string) error {

integration-tests/pkg/common/utils.go

@@ -58,13 +58,20 @@ func ArchSupported(supported ...string) (bool, string) {
 
 // Creates a new file to dump logs into
 func PrepareLog(testName string, logName string) (*os.File, error) {
-	logDirectory := filepath.Join(".", "container-logs", config.VMInfo().Config, config.CollectionMethod())
+	pathSections := []string{
+		".", "container-logs",
+		config.VMInfo().Config,
+		config.CollectionMethod(),
+		testName,
+	}
+
+	logDirectory := filepath.Join(pathSections...)
 	err := os.MkdirAll(logDirectory, os.ModePerm)
 	if err != nil {
 		return nil, err
 	}
 
-	logPath := filepath.Join(logDirectory, strings.ReplaceAll(testName, "/", "_")+"-"+logName)
+	logPath := filepath.Join(logDirectory, logName)
 	return os.Create(logPath)
 }
 

integration-tests/pkg/executor/executor.go

@@ -11,6 +11,25 @@ type ContainerFilter struct {
 	Namespace string
 }
 
+type ContainerLogs struct {
+	Stdout string
+	Stderr string
+}
+
+func (c *ContainerLogs) Empty() bool {
+	return *c == (ContainerLogs{})
+}
+
+// Will return Stderr if it is not empty, otherwise it returns Stdout.
+// Useful for accessing the logs for collector and container-stats
+// that use a single stream.
+func (l *ContainerLogs) GetSingleLog() string {
+	if l.Stderr != "" {
+		return l.Stderr
+	}
+	return l.Stdout
+}
+
 type Executor interface {
 	PullImage(image string) error
 	IsContainerRunning(container string) (bool, error)
@@ -23,7 +42,8 @@ type Executor interface {
 	StartContainer(config config.ContainerStartConfig) (string, error)
 	GetContainerHealthCheck(containerID string) (string, error)
 	GetContainerIP(containerID string) (string, error)
-	GetContainerLogs(containerID string) (string, error)
+	GetContainerLogs(containerID string) (ContainerLogs, error)
+	CaptureLogs(testName, containerName string) (string, error)
 	GetContainerPort(containerID string) (string, error)
 	IsContainerFoundFiltered(containerID, filter string) (bool, error)
 }

integration-tests/pkg/executor/executor_docker_api.go

@@ -170,30 +170,74 @@ func (d *dockerAPIExecutor) ExecContainer(containerName string, command []string
 	return stdoutBuf.String(), nil
 }
 
-func (d *dockerAPIExecutor) GetContainerLogs(containerID string) (string, error) {
+func (d *dockerAPIExecutor) GetContainerLogs(containerID string) (ContainerLogs, error) {
 	timeoutContext, cancel := context.WithTimeout(context.Background(), 30*time.Second)
 	defer cancel()
 	logsReader, err := d.client.ContainerLogs(timeoutContext, containerID,
 		container.LogsOptions{ShowStdout: true, ShowStderr: true})
 	if err != nil {
-		return "", fmt.Errorf("error getting container logs: %w", err)
+		return ContainerLogs{}, fmt.Errorf("error getting container logs: %w", err)
 	}
 	defer logsReader.Close()
 
 	var sbStdOut, sbStdErr strings.Builder
 	// if container doesn't have TTY (c.Config.Tty), output is multiplexed
 	if _, err := stdcopy.StdCopy(&sbStdOut, &sbStdErr, logsReader); err != nil {
-		return "", fmt.Errorf("error copying logs: %w", err)
+		return ContainerLogs{}, fmt.Errorf("error copying logs: %w", err)
 	}
 	log.Info("logs %s (%d bytes stdout, %d bytes stderr)", containerID, sbStdOut.Len(), sbStdErr.Len())
-	if sbStdErr.Len() > 0 {
-		if sbStdOut.Len() > 0 {
-			// not implemented
-			return "", errors.New("unhandled container output to stdout and stderr")
+	return ContainerLogs{
+		Stdout: sbStdOut.String(),
+		Stderr: sbStdErr.String(),
+	}, nil
+}
+
+func (c *dockerAPIExecutor) CaptureLogs(testName, containerName string) (string, error) {
+	log.Info("%s: Gathering logs for %q", testName, containerName)
+	logs, err := c.GetContainerLogs(containerName)
+	if err != nil {
+		return "", log.Error("logs error (%v) for container %s\n", err, containerName)
+	}
+
+	type logFile = struct {
+		name    string
+		content string
+	}
+
+	var logFiles []logFile
+	if logs.Empty() {
+		// Nothing to log, still we create an empty file for awareness
+		logFiles = []logFile{{
+			name: fmt.Sprintf("%s.log", containerName),
+		}}
+	} else if logs.Stderr == "" || logs.Stdout == "" {
+		// We only have stdout OR stderr to log
+		logFiles = []logFile{{
+			name:    fmt.Sprintf("%s.log", containerName),
+			content: logs.GetSingleLog(),
+		}}
+	} else {
+		// We need to log both stdout and stderr, do so on separate files
+		logFiles = []logFile{{
+			name:    fmt.Sprintf("%s-stderr.log", containerName),
+			content: logs.Stderr,
+		}, {
+			name:    fmt.Sprintf("%s-stdout.log", containerName),
+			content: logs.Stdout,
+		}}
+	}
+
+	for _, lf := range logFiles {
+		file, err := common.PrepareLog(testName, lf.name)
+		if err != nil {
+			return "", err
 		}
-		return sbStdErr.String(), nil
+		defer file.Close()
+
+		file.WriteString(lf.content)
 	}
-	return sbStdOut.String(), nil
+
+	return logFiles[0].content, nil
 }
 
 func (d *dockerAPIExecutor) KillContainer(containerID string) (string, error) {

integration-tests/pkg/mock_sensor/server.go

@@ -5,7 +5,6 @@ import (
 	"log"
 	"net"
 	"os"
-	"path/filepath"
 	"strings"
 	"sync"
 	"time"
@@ -17,7 +16,7 @@ import (
 	"google.golang.org/grpc"
 	"google.golang.org/grpc/keepalive"
 
-	"github.com/stackrox/collector/integration-tests/pkg/config"
+	"github.com/stackrox/collector/integration-tests/pkg/common"
 	"github.com/stackrox/collector/integration-tests/pkg/types"
 )
 
@@ -223,10 +222,7 @@ func (m *MockSensor) HasEndpoint(containerID string, endpoint types.EndpointInfo
 func (m *MockSensor) Start() {
 	var err error
 
-	m.logFile, err = os.OpenFile(
-		filepath.Join(config.LogPath(), strings.ReplaceAll(m.testName, "/", "_")+"-events.log"),
-		os.O_CREATE|os.O_WRONLY, 0644,
-	)
+	m.logFile, err = common.PrepareLog(m.testName, "events.log")
 
 	if err != nil {
 		log.Fatalf("failed to open log file: %v", err)

integration-tests/suites/base.go

@@ -192,7 +192,7 @@ func (s *IntegrationTestSuiteBase) GetContainerStats() []ContainerStat {
 			return nil
 		}
 
-		logLines := strings.Split(logs, "\n")
+		logLines := strings.Split(logs.Stderr, "\n")
 		for i, line := range logLines {
 			var stat ContainerStat
 
@@ -304,13 +304,6 @@ func (s *IntegrationTestSuiteBase) AssertProcessInfoEqual(expected, actual types
 	assert.Equal(expected.Args, actual.Args)
 }
 
-func (s *IntegrationTestSuiteBase) GetLogLines(containerName string) []string {
-	logs, err := s.containerLogs(containerName)
-	s.Require().NoError(err, containerName+" failure")
-	logLines := strings.Split(logs, "\n")
-	return logLines
-}
-
 // Wait for a container to become a certain status.
 //   - tickSeconds -- how often to check for the status
 //   - timeoutThreshold -- the overall time limit for waiting,
@@ -410,8 +403,12 @@ func (s *IntegrationTestSuiteBase) execContainerShellScript(containerName string
 
 func (s *IntegrationTestSuiteBase) cleanupContainers(containers ...string) {
 	for _, container := range containers {
-		s.Executor().KillContainer(container)
-		s.Executor().RemoveContainer(executor.ContainerFilter{Name: container})
+		exists, _ := s.Executor().ContainerExists(executor.ContainerFilter{Name: container})
+		if exists {
+			s.Executor().KillContainer(container)
+			s.Executor().CaptureLogs(s.T().Name(), container)
+			s.Executor().RemoveContainer(executor.ContainerFilter{Name: container})
+		}
 	}
 }
 
@@ -427,7 +424,7 @@ func (s *IntegrationTestSuiteBase) removeContainers(containers ...string) {
 	}
 }
 
-func (s *IntegrationTestSuiteBase) containerLogs(containerName string) (string, error) {
+func (s *IntegrationTestSuiteBase) containerLogs(containerName string) (executor.ContainerLogs, error) {
 	return s.Executor().GetContainerLogs(containerName)
 }
 

integration-tests/suites/perf_event_open.go

@@ -42,13 +42,13 @@ func (s *PerfEventOpenTestSuite) TestReadingTracepoints() {
 	if finished, _ := s.waitForContainerToExit("perf-event-open", containerID, 5*time.Second, 0); finished {
 		logs, err := s.containerLogs("perf-event-open")
 		if err != nil {
-			log.Info(logs)
+			log.Info(logs.GetSingleLog())
 			assert.FailNow(s.T(), "Failed to initialize host for performance testing")
 		}
 
-		count, err := strconv.Atoi(strings.TrimSpace(logs))
+		count, err := strconv.Atoi(strings.TrimSpace(logs.GetSingleLog()))
 		if err != nil {
-			log.Info(logs)
+			log.Info(logs.GetSingleLog())
 			assert.FailNow(s.T(), "Cannot convert result to the integer type")
 		}