github.com/anth0d/nomad@v0.0.0-20221214183521-ae3a0a2cad06/client/logmon/logmon.go (about)

     1  package logmon
     2  
     3  import (
     4  	"fmt"
     5  	"io"
     6  	"os"
     7  	"strings"
     8  	"sync"
     9  	"time"
    10  
    11  	hclog "github.com/hashicorp/go-hclog"
    12  	"github.com/hashicorp/nomad/client/lib/fifo"
    13  	"github.com/hashicorp/nomad/client/logmon/logging"
    14  )
    15  
    16  const (
    17  	// processOutputCloseTolerance is the length of time we will wait for the
    18  	// launched process to close its stdout/stderr before we force close it. If
    19  	// data is written after this tolerance, we will not capture it.
    20  	processOutputCloseTolerance = 2 * time.Second
    21  )
    22  
    23  type LogConfig struct {
    24  	// LogDir is the host path where logs are to be written to
    25  	LogDir string
    26  
    27  	// StdoutLogFile is the path relative to LogDir for stdout logging
    28  	StdoutLogFile string
    29  
    30  	// StderrLogFile is the path relative to LogDir for stderr logging
    31  	StderrLogFile string
    32  
    33  	// StdoutFifo is the path on the host to the stdout pipe
    34  	StdoutFifo string
    35  
    36  	// StderrFifo is the path on the host to the stderr pipe
    37  	StderrFifo string
    38  
    39  	// MaxFiles is the max rotated files allowed
    40  	MaxFiles int
    41  
    42  	// MaxFileSizeMB is the max log file size in MB allowed before rotation occures
    43  	MaxFileSizeMB int
    44  }
    45  
    46  type LogMon interface {
    47  	Start(*LogConfig) error
    48  	Stop() error
    49  }
    50  
    51  func NewLogMon(logger hclog.Logger) LogMon {
    52  	return &logmonImpl{
    53  		logger: logger,
    54  	}
    55  }
    56  
    57  type logmonImpl struct {
    58  	logger hclog.Logger
    59  	tl     *TaskLogger
    60  	lock   sync.Mutex
    61  }
    62  
    63  func (l *logmonImpl) Start(cfg *LogConfig) error {
    64  	l.lock.Lock()
    65  	defer l.lock.Unlock()
    66  
    67  	// first time Start has been called
    68  	if l.tl == nil {
    69  		return l.start(cfg)
    70  	}
    71  
    72  	// stdout and stderr have been closed, this happens during task restarts
    73  	// restart the TaskLogger
    74  	if !l.tl.IsRunning() {
    75  		l.tl.Close()
    76  		return l.start(cfg)
    77  	}
    78  
    79  	// if the TaskLogger has been created and is currently running, noop
    80  	return nil
    81  }
    82  
    83  func (l *logmonImpl) start(cfg *LogConfig) error {
    84  	tl, err := NewTaskLogger(cfg, l.logger)
    85  	if err != nil {
    86  		return err
    87  	}
    88  	l.tl = tl
    89  	return nil
    90  }
    91  
    92  func (l *logmonImpl) Stop() error {
    93  	l.lock.Lock()
    94  	defer l.lock.Unlock()
    95  	if l.tl != nil {
    96  		l.tl.Close()
    97  	}
    98  	return nil
    99  }
   100  
   101  type TaskLogger struct {
   102  	config *LogConfig
   103  
   104  	// rotator for stdout
   105  	lro *logRotatorWrapper
   106  
   107  	// rotator for stderr
   108  	lre *logRotatorWrapper
   109  }
   110  
   111  // IsRunning will return true as long as one rotator wrapper is still running
   112  func (tl *TaskLogger) IsRunning() bool {
   113  	lroRunning := tl.lro != nil && tl.lro.isRunning()
   114  	lreRunning := tl.lre != nil && tl.lre.isRunning()
   115  
   116  	return lroRunning && lreRunning
   117  }
   118  
   119  func (tl *TaskLogger) Close() {
   120  	var wg sync.WaitGroup
   121  	if tl.lro != nil {
   122  		wg.Add(1)
   123  		go func() {
   124  			tl.lro.Close()
   125  			wg.Done()
   126  		}()
   127  	}
   128  	if tl.lre != nil {
   129  		wg.Add(1)
   130  		go func() {
   131  			tl.lre.Close()
   132  			wg.Done()
   133  		}()
   134  	}
   135  	wg.Wait()
   136  }
   137  
   138  func NewTaskLogger(cfg *LogConfig, logger hclog.Logger) (*TaskLogger, error) {
   139  	tl := &TaskLogger{config: cfg}
   140  
   141  	logFileSize := int64(cfg.MaxFileSizeMB * 1024 * 1024)
   142  	lro, err := logging.NewFileRotator(cfg.LogDir, cfg.StdoutLogFile,
   143  		cfg.MaxFiles, logFileSize, logger)
   144  	if err != nil {
   145  		return nil, fmt.Errorf("failed to create stdout logfile for %q: %v", cfg.StdoutLogFile, err)
   146  	}
   147  
   148  	wrapperOut, err := newLogRotatorWrapper(cfg.StdoutFifo, logger, lro)
   149  	if err != nil {
   150  		return nil, err
   151  	}
   152  
   153  	tl.lro = wrapperOut
   154  
   155  	lre, err := logging.NewFileRotator(cfg.LogDir, cfg.StderrLogFile,
   156  		cfg.MaxFiles, logFileSize, logger)
   157  	if err != nil {
   158  		return nil, fmt.Errorf("failed to create stderr logfile for %q: %v", cfg.StderrLogFile, err)
   159  	}
   160  
   161  	wrapperErr, err := newLogRotatorWrapper(cfg.StderrFifo, logger, lre)
   162  	if err != nil {
   163  		return nil, err
   164  	}
   165  
   166  	tl.lre = wrapperErr
   167  
   168  	return tl, nil
   169  
   170  }
   171  
   172  // logRotatorWrapper wraps our log rotator and exposes a pipe that can feed the
   173  // log rotator data. The processOutWriter should be attached to the process and
   174  // data will be copied from the reader to the rotator.
   175  type logRotatorWrapper struct {
   176  	fifoPath          string
   177  	rotatorWriter     io.WriteCloser
   178  	hasFinishedCopied chan struct{}
   179  	logger            hclog.Logger
   180  
   181  	processOutReader io.ReadCloser
   182  	openCompleted    chan struct{}
   183  }
   184  
   185  // isRunning will return true until the reader is closed
   186  func (l *logRotatorWrapper) isRunning() bool {
   187  	select {
   188  	case <-l.hasFinishedCopied:
   189  		return false
   190  	default:
   191  		return true
   192  	}
   193  }
   194  
   195  // newLogRotatorWrapper takes a rotator and returns a wrapper that has the
   196  // processOutWriter to attach to the stdout or stderr of a process.
   197  func newLogRotatorWrapper(path string, logger hclog.Logger, rotator io.WriteCloser) (*logRotatorWrapper, error) {
   198  	logger.Info("opening fifo", "path", path)
   199  
   200  	var openFn func() (io.ReadCloser, error)
   201  	var err error
   202  
   203  	_, serr := os.Stat(path)
   204  	if os.IsNotExist(serr) {
   205  		openFn, err = fifo.CreateAndRead(path)
   206  	} else {
   207  		openFn = func() (io.ReadCloser, error) {
   208  			return fifo.OpenReader(path)
   209  		}
   210  	}
   211  
   212  	if err != nil {
   213  		logger.Error("failed to create FIFO", "stat_error", serr, "create_err", err)
   214  		return nil, fmt.Errorf("failed to create fifo for extracting logs: %v", err)
   215  	}
   216  
   217  	wrap := &logRotatorWrapper{
   218  		fifoPath:          path,
   219  		rotatorWriter:     rotator,
   220  		hasFinishedCopied: make(chan struct{}),
   221  		openCompleted:     make(chan struct{}),
   222  		logger:            logger,
   223  	}
   224  
   225  	wrap.start(openFn)
   226  	return wrap, nil
   227  }
   228  
   229  // start starts a goroutine that copies from the pipe into the rotator. This is
   230  // called by the constructor and not the user of the wrapper.
   231  func (l *logRotatorWrapper) start(openFn func() (io.ReadCloser, error)) {
   232  	go func() {
   233  		defer close(l.hasFinishedCopied)
   234  
   235  		reader, err := openFn()
   236  		if err != nil {
   237  			l.logger.Warn("failed to open fifo", "error", err)
   238  			return
   239  		}
   240  		l.processOutReader = reader
   241  		close(l.openCompleted)
   242  
   243  		_, err = io.Copy(l.rotatorWriter, reader)
   244  		if err != nil {
   245  			l.logger.Warn("failed to read from log fifo", "error", err)
   246  			// Close reader to propagate io error across pipe.
   247  			// Note that this may block until the process exits on
   248  			// Windows due to
   249  			// https://github.com/PowerShell/PowerShell/issues/4254
   250  			// or similar issues. Since this is already running in
   251  			// a goroutine its safe to block until the process is
   252  			// force-killed.
   253  			reader.Close()
   254  		}
   255  	}()
   256  }
   257  
   258  // Close closes the rotator and the process writer to ensure that the Wait
   259  // command exits.
   260  func (l *logRotatorWrapper) Close() {
   261  	// Wait up to the close tolerance before we force close
   262  	select {
   263  	case <-l.hasFinishedCopied:
   264  	case <-time.After(processOutputCloseTolerance):
   265  	}
   266  
   267  	// Closing the read side of a pipe may block on Windows if the process
   268  	// is being debugged as in:
   269  	// https://github.com/PowerShell/PowerShell/issues/4254
   270  	// The pipe will be closed and cleaned up when the process exits.
   271  	closeDone := make(chan struct{})
   272  	go func() {
   273  		defer close(closeDone)
   274  
   275  		// we must wait until reader is opened before we can close it, and cannot inteerrupt an in-flight open request
   276  		// The Close function uses processOutputCloseTolerance to protect against long running open called
   277  		// and then request will be interrupted and file will be closed on process shutdown
   278  		<-l.openCompleted
   279  
   280  		if l.processOutReader != nil {
   281  			err := l.processOutReader.Close()
   282  			if err != nil && !strings.Contains(err.Error(), "file already closed") {
   283  				l.logger.Warn("error closing read-side of process output pipe", "error", err)
   284  			}
   285  		}
   286  
   287  	}()
   288  
   289  	select {
   290  	case <-closeDone:
   291  	case <-time.After(processOutputCloseTolerance):
   292  		l.logger.Warn("timed out waiting for read-side of process output pipe to close")
   293  	}
   294  
   295  	l.rotatorWriter.Close()
   296  }