handlers: moved fifo setup/cleanup to handler

fifos for Firecracker logs and metrics are now created and queued for
cleanup in CreateLogFilesHandler.  This removes warnings when using the
jailer and setting other paths for the fifos.

Fixes: #133
Original contribution: #134
Signed-off-by: Samuel Karp <[email protected]>

Author: Corbin Phelps

.gitignore

@@ -2,3 +2,5 @@ firecracker
 jailer
 firecracker-*
 vmlinux
+root-drive.img
+TestPID.img

handlers.go

@@ -16,6 +16,7 @@ package firecracker
 import (
 	"context"
 	"fmt"
+	"os"
 )
 
 // Handler name constants
@@ -135,6 +136,27 @@ var CreateLogFilesHandler = Handler{
 			return err
 		}
 
+		m.cleanupFuncs = append(m.cleanupFuncs,
+			func() error {
+				if err := os.Remove(logFifoPath); !os.IsNotExist(err) {
+					return err
+				}
+				return nil
+			},
+			func() error {
+				if err := os.Remove(metricsFifoPath); !os.IsNotExist(err) {
+					return err
+				}
+				return nil
+			},
+		)
+
+		if m.Cfg.FifoLogWriter != nil {
+			if err := captureFifoToFile(m.logger, logFifoPath, m.Cfg.FifoLogWriter); err != nil {
+				m.logger.Warnf("captureFifoToFile() returned %s. Continuing anyway.", err)
+			}
+		}
+
 		m.logger.Debug("Created metrics and logging fifos.")
 
 		return nil

handlers_test.go

@@ -1,16 +1,19 @@
 package firecracker
 
 import (
+	"bytes"
 	"context"
 	"fmt"
 	"os"
 	"path/filepath"
 	"reflect"
 	"testing"
+	"time"
 
 	models "github.com/firecracker-microvm/firecracker-go-sdk/client/models"
 	ops "github.com/firecracker-microvm/firecracker-go-sdk/client/operations"
 	"github.com/firecracker-microvm/firecracker-go-sdk/fctesting"
+	"github.com/pkg/errors"
 )
 
 func TestHandlerListAppend(t *testing.T) {
@@ -660,6 +663,76 @@ func TestHandlers(t *testing.T) {
 	}
 }
 
+func TestCreateLogFilesHandler(t *testing.T) {
+	logWriterBuf := &bytes.Buffer{}
+	config := Config{
+		LogFifo:       filepath.Join(testDataPath, "firecracker-log.fifo"),
+		MetricsFifo:   filepath.Join(testDataPath, "firecracker-metrics.fifo"),
+		FifoLogWriter: logWriterBuf,
+	}
+
+	defer func() {
+		os.Remove(config.LogFifo)
+		os.Remove(config.MetricsFifo)
+	}()
+
+	ctx := context.Background()
+	m, err := NewMachine(ctx, config, WithLogger(fctesting.NewLogEntry(t)))
+	if err != nil {
+		t.Fatalf("failed to create machine: %v", err)
+	}
+
+	// spin off goroutine to write to Log fifo so we don't block
+	doneChan := make(chan struct{}, 1)
+	go func() {
+		defer close(doneChan)
+
+		// try to open file
+		fifoPipe, err := openFileRetry(config.LogFifo)
+		if err != nil {
+			t.Error(err)
+		}
+
+		if _, err := fifoPipe.WriteString("data\n"); err != nil {
+			t.Errorf("Failed to write to fifo %v", err)
+		}
+
+		fifoPipe.Close()
+		return
+	}()
+
+	// Execute Handler
+	if err := CreateLogFilesHandler.Fn(ctx, m); err != nil {
+		t.Errorf("failed to call CreateLogFilesHandler function: %v", err)
+		return
+	}
+
+	// Block until writing go routine is done to check data that was written
+	<-doneChan
+
+	// Poll for verifying logs were written as we need to allow time
+	// for copying from the log fifo into the FifoLogWriter
+	timer := time.NewTimer(1 * time.Second)
+	for {
+		select {
+		case <-timer.C:
+			t.Fatal("timed out reading from log writer")
+		default:
+			logData, err := logWriterBuf.ReadString('\n')
+			if err != nil {
+				time.Sleep(10 * time.Millisecond)
+				continue
+			}
+
+			if logData != "data\n" {
+				t.Errorf("expected 'data' written to log got '%s'", logData)
+			}
+			return
+		}
+	}
+
+}
+
 func compareHandlerLists(l1, l2 HandlerList) bool {
 	if l1.Len() != l2.Len() {
 		return false
@@ -681,3 +754,21 @@ func compareHandlerLists(l1, l2 HandlerList) bool {
 
 	return true
 }
+
+func openFileRetry(filePath string) (file *os.File, err error) {
+	timer := time.NewTimer(1 * time.Second)
+	for {
+		select {
+		case <-timer.C:
+			err = errors.New("timed out waiting for file")
+			return
+		default:
+			file, err = os.OpenFile(filePath, os.O_WRONLY, os.ModePerm)
+			if err == nil {
+				timer.Stop()
+				return
+			}
+			time.Sleep(10 * time.Millisecond)
+		}
+	}
+}

machine.go

@@ -455,18 +455,6 @@ func (m *Machine) startVMM(ctx context.Context) error {
 			}
 			return nil
 		},
-		func() error {
-			if err := os.Remove(m.Cfg.LogFifo); !os.IsNotExist(err) {
-				return err
-			}
-			return nil
-		},
-		func() error {
-			if err := os.Remove(m.Cfg.MetricsFifo); !os.IsNotExist(err) {
-				return err
-			}
-			return nil
-		},
 	)
 
 	errCh := make(chan error)
@@ -585,12 +573,6 @@ func (m *Machine) setupLogging(ctx context.Context) error {
 		m.Cfg.MetricsFifo,
 	)
 
-	if m.Cfg.FifoLogWriter != nil {
-		if err := captureFifoToFile(m.logger, m.Cfg.LogFifo, m.Cfg.FifoLogWriter); err != nil {
-			return err
-		}
-	}
-
 	return nil
 }