github.com/rumpl/bof@v23.0.0-rc.2+incompatible/daemon/logger/loggerutils/follow.go (about)

     1  package loggerutils // import "github.com/docker/docker/daemon/logger/loggerutils"
     2  
     3  import (
     4  	"fmt"
     5  	"io"
     6  	"os"
     7  	"time"
     8  
     9  	"github.com/docker/docker/daemon/logger"
    10  	"github.com/pkg/errors"
    11  	"github.com/sirupsen/logrus"
    12  )
    13  
    14  type follow struct {
    15  	LogFile      *LogFile
    16  	Watcher      *logger.LogWatcher
    17  	Decoder      Decoder
    18  	Since, Until time.Time
    19  
    20  	log *logrus.Entry
    21  	c   chan logPos
    22  }
    23  
    24  // Do follows the log file as it is written, starting from f at read.
    25  func (fl *follow) Do(f *os.File, read logPos) {
    26  	fl.log = logrus.WithFields(logrus.Fields{
    27  		"module": "logger",
    28  		"file":   f.Name(),
    29  	})
    30  	// Optimization: allocate the write-notifications channel only once and
    31  	// reuse it for multiple invocations of nextPos().
    32  	fl.c = make(chan logPos, 1)
    33  
    34  	defer func() {
    35  		if err := f.Close(); err != nil && !errors.Is(err, os.ErrClosed) {
    36  			fl.log.WithError(err).Warn("error closing current log file")
    37  		}
    38  	}()
    39  
    40  	for {
    41  		wrote, ok := fl.nextPos(read)
    42  		if !ok {
    43  			return
    44  		}
    45  
    46  		if wrote.rotation != read.rotation {
    47  			// Flush the current file before moving on to the next.
    48  			if _, err := f.Seek(read.size, io.SeekStart); err != nil {
    49  				fl.Watcher.Err <- err
    50  				return
    51  			}
    52  			if fl.decode(f) {
    53  				return
    54  			}
    55  
    56  			// Open the new file, which has the same name as the old
    57  			// file thanks to file rotation. Make no mistake: they
    58  			// are different files, with distinct identities.
    59  			// Atomically capture the wrote position to make
    60  			// absolutely sure that the position corresponds to the
    61  			// file we have opened; more rotations could have
    62  			// occurred since we previously received it.
    63  			if err := f.Close(); err != nil {
    64  				fl.log.WithError(err).Warn("error closing rotated log file")
    65  			}
    66  			var err error
    67  			func() {
    68  				fl.LogFile.fsopMu.RLock()
    69  				st := <-fl.LogFile.read
    70  				defer func() {
    71  					fl.LogFile.read <- st
    72  					fl.LogFile.fsopMu.RUnlock()
    73  				}()
    74  				f, err = open(f.Name())
    75  				wrote = st.pos
    76  			}()
    77  			// We tried to open the file inside a critical section
    78  			// so we shouldn't have been racing the rotation of the
    79  			// file. Any error, even fs.ErrNotFound, is exceptional.
    80  			if err != nil {
    81  				fl.Watcher.Err <- fmt.Errorf("logger: error opening log file for follow after rotation: %w", err)
    82  				return
    83  			}
    84  
    85  			if nrot := wrote.rotation - read.rotation; nrot > 1 {
    86  				fl.log.WithField("missed-rotations", nrot).
    87  					Warn("file rotations were missed while following logs; some log messages have been skipped over")
    88  			}
    89  
    90  			// Set up our read position to start from the top of the file.
    91  			read.size = 0
    92  		}
    93  
    94  		if fl.decode(io.NewSectionReader(f, read.size, wrote.size-read.size)) {
    95  			return
    96  		}
    97  		read = wrote
    98  	}
    99  }
   100  
   101  // nextPos waits until the write position of the LogFile being followed has
   102  // advanced from current and returns the new position.
   103  func (fl *follow) nextPos(current logPos) (next logPos, ok bool) {
   104  	var st logReadState
   105  	select {
   106  	case <-fl.Watcher.WatchConsumerGone():
   107  		return current, false
   108  	case st = <-fl.LogFile.read:
   109  	}
   110  
   111  	// Have any any logs been written since we last checked?
   112  	if st.pos == current { // Nope.
   113  		// Add ourself to the notify list.
   114  		st.wait = append(st.wait, fl.c)
   115  	} else { // Yes.
   116  		// "Notify" ourself immediately.
   117  		fl.c <- st.pos
   118  	}
   119  	fl.LogFile.read <- st
   120  
   121  	select {
   122  	case <-fl.LogFile.closed: // No more logs will be written.
   123  		select { // Have we followed to the end?
   124  		case next = <-fl.c: // No: received a new position.
   125  		default: // Yes.
   126  			return current, false
   127  		}
   128  	case <-fl.Watcher.WatchConsumerGone():
   129  		return current, false
   130  	case next = <-fl.c:
   131  	}
   132  	return next, true
   133  }
   134  
   135  // decode decodes log messages from r and sends messages with timestamps between
   136  // Since and Until to the log watcher.
   137  //
   138  // The return value, done, signals whether following should end due to a
   139  // condition encountered during decode.
   140  func (fl *follow) decode(r io.Reader) (done bool) {
   141  	fl.Decoder.Reset(r)
   142  	for {
   143  		msg, err := fl.Decoder.Decode()
   144  		if err != nil {
   145  			if errors.Is(err, io.EOF) {
   146  				return false
   147  			}
   148  			fl.Watcher.Err <- err
   149  			return true
   150  		}
   151  
   152  		if !fl.Since.IsZero() && msg.Timestamp.Before(fl.Since) {
   153  			continue
   154  		}
   155  		if !fl.Until.IsZero() && msg.Timestamp.After(fl.Until) {
   156  			return true
   157  		}
   158  		// send the message, unless the consumer is gone
   159  		select {
   160  		case fl.Watcher.Msg <- msg:
   161  		case <-fl.Watcher.WatchConsumerGone():
   162  			return true
   163  		}
   164  	}
   165  }