Fixes leak of open file during capture fifo

This change fixes a leak that occurs when using context cancel or
stopping the VM. The goroutine in `captureFifoToFile` spins up a
goroutine to copy the contents of the file, but will continue reading
from the file even if the VM shuts down. To prevent this, we now look at
if the machine has closed its exit channel

Signed-off-by: xibz <[email protected]>

Author: xibz

handlers.go

@@ -152,7 +152,7 @@ var CreateLogFilesHandler = Handler{
 		)
 
 		if m.Cfg.FifoLogWriter != nil {
-			if err := captureFifoToFile(m.logger, logFifoPath, m.Cfg.FifoLogWriter); err != nil {
+			if err := m.captureFifoToFile(m.logger, logFifoPath, m.Cfg.FifoLogWriter); err != nil {
 				m.logger.Warnf("captureFifoToFile() returned %s. Continuing anyway.", err)
 			}
 		}

machine.go

@@ -576,7 +576,7 @@ func (m *Machine) setupLogging(ctx context.Context) error {
 	return nil
 }
 
-func captureFifoToFile(logger *log.Entry, fifoPath string, w io.Writer) error {
+func (m *Machine) captureFifoToFile(logger *log.Entry, fifoPath string, w io.Writer) error {
 	// open the fifo pipe which will be used
 	// to write its contents to a file.
 	fd, err := syscall.Open(fifoPath, syscall.O_RDONLY|syscall.O_NONBLOCK, 0600)
@@ -591,6 +591,16 @@ func captureFifoToFile(logger *log.Entry, fifoPath string, w io.Writer) error {
 
 	logger.Debugf("Capturing %q to writer", fifoPath)
 
+	// this goroutine is to track the life of the application along with whether
+	// or not the context has been cancelled which is signified by the exitCh. In
+	// the event that the exitCh has been closed, we will close the fifo file.
+	go func() {
+		<-m.exitCh
+		if err := fifoPipe.Close(); err != nil {
+			logger.WithError(err).Debug("failed to close fifo")
+		}
+	}()
+
 	// Uses a goroutine to copy the contents of the fifo pipe to the io.Writer.
 	// In the event that the goroutine finishes, which is caused by either the
 	// context being closed or the application being closed, we will close the

machine_test.go

@@ -14,6 +14,7 @@
 package firecracker
 
 import (
+	"bytes"
 	"context"
 	"errors"
 	"flag"
@@ -30,6 +31,7 @@ import (
 	"testing"
 	"time"
 
+	"github.com/sirupsen/logrus"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 
@@ -830,7 +832,10 @@ func TestCaptureFifoToFile(t *testing.T) {
 		},
 	}
 
-	if err := captureFifoToFile(fctesting.NewLogEntry(t), fifoPath, testWriter); err != nil {
+	m := &Machine{
+		exitCh: make(chan struct{}),
+	}
+	if err := m.captureFifoToFile(fctesting.NewLogEntry(t), fifoPath, testWriter); err != nil {
 		t.Errorf("Unexpected error: %v", err)
 	}
 
@@ -869,7 +874,10 @@ func TestCaptureFifoToFile_nonblock(t *testing.T) {
 		},
 	}
 
-	if err := captureFifoToFile(fctesting.NewLogEntry(t), fifoPath, testWriter); err != nil {
+	m := &Machine{
+		exitCh: make(chan struct{}),
+	}
+	if err := m.captureFifoToFile(fctesting.NewLogEntry(t), fifoPath, testWriter); err != nil {
 		t.Errorf("Unexpected error: %v", err)
 	}
 
@@ -1025,3 +1033,45 @@ func TestPID(t *testing.T) {
 	}
 
 }
+
+func TestCaptureFifoToFile_leak(t *testing.T) {
+	m := &Machine{
+		exitCh: make(chan struct{}),
+	}
+
+	fifoPath := filepath.Join(testDataPath, "TestCaptureFifoToFileLeak.fifo")
+	err := syscall.Mkfifo(fifoPath, 0700)
+	require.NoError(t, err, "failed to make fifo")
+	defer os.Remove(fifoPath)
+
+	fd, err := syscall.Open(fifoPath, syscall.O_RDWR|syscall.O_NONBLOCK, 0600)
+	require.NoError(t, err, "failed to open fifo path")
+	f := os.NewFile(uintptr(fd), fifoPath)
+	assert.NotNil(t, f, "failed to create new  file")
+	go func() {
+		for {
+			select {
+			case <-m.exitCh:
+				break
+			default:
+				_, err := f.Write([]byte("A"))
+				assert.NoError(t, err, "failed to write bytes to fifo")
+			}
+		}
+	}()
+
+	buf := bytes.NewBuffer(nil)
+
+	loggerBuffer := bytes.NewBuffer(nil)
+	logger := fctesting.NewLogEntry(t)
+	logger.Logger.Level = logrus.WarnLevel
+	logger.Logger.Out = loggerBuffer
+	err = m.captureFifoToFile(logger, fifoPath, buf)
+	assert.NoError(t, err, "failed to capture fifo to file")
+	close(m.exitCh)
+
+	// wait sometime for the logs to populate
+	time.Sleep(250 * time.Millisecond)
+	expected := `io.Copy failed to copy contents of fifo pipe: read testdata/TestCaptureFifoToFileLeak.fifo: file already closed`
+	assert.Contains(t, loggerBuffer.String(), expected)
+}