github.com/grafana/tail@v0.0.0-20230510142333-77b18831edf0/tail.go (about)

     1  // Copyright (c) 2015 HPE Software Inc. All rights reserved.
     2  // Copyright (c) 2013 ActiveState Software Inc. All rights reserved.
     3  
     4  package tail
     5  
     6  import (
     7  	"bufio"
     8  	"errors"
     9  	"fmt"
    10  	"io"
    11  	"io/ioutil"
    12  	"log"
    13  	"os"
    14  	"strings"
    15  	"sync"
    16  	"time"
    17  
    18  	"github.com/grafana/tail/ratelimiter"
    19  	"github.com/grafana/tail/util"
    20  	"github.com/grafana/tail/watch"
    21  	"gopkg.in/tomb.v1"
    22  )
    23  
    24  var (
    25  	ErrStop = errors.New("tail should now stop")
    26  )
    27  
    28  type Line struct {
    29  	Text string
    30  	Time time.Time
    31  	Err  error // Error from tail
    32  }
    33  
    34  // NewLine returns a Line with present time.
    35  func NewLine(text string) *Line {
    36  	return &Line{text, time.Now(), nil}
    37  }
    38  
    39  // SeekInfo represents arguments to `os.Seek`
    40  type SeekInfo struct {
    41  	Offset int64
    42  	Whence int // os.SEEK_*
    43  }
    44  
    45  type logger interface {
    46  	Fatal(v ...interface{})
    47  	Fatalf(format string, v ...interface{})
    48  	Fatalln(v ...interface{})
    49  	Panic(v ...interface{})
    50  	Panicf(format string, v ...interface{})
    51  	Panicln(v ...interface{})
    52  	Print(v ...interface{})
    53  	Printf(format string, v ...interface{})
    54  	Println(v ...interface{})
    55  }
    56  
    57  // Config is used to specify how a file must be tailed.
    58  type Config struct {
    59  	// File-specifc
    60  	Location    *SeekInfo // Seek to this location before tailing
    61  	ReOpen      bool      // Reopen recreated files (tail -F)
    62  	MustExist   bool      // Fail early if the file does not exist
    63  	Poll        bool      // Poll for file changes instead of using inotify
    64  	Pipe        bool      // Is a named pipe (mkfifo)
    65  	RateLimiter *ratelimiter.LeakyBucket
    66  	PollOptions watch.PollingFileWatcherOptions
    67  
    68  	// Generic IO
    69  	Follow      bool // Continue looking for new lines (tail -f)
    70  	MaxLineSize int  // If non-zero, split longer lines into multiple lines
    71  
    72  	// Logger, when nil, is set to tail.DefaultLogger
    73  	// To disable logging: set field to tail.DiscardingLogger
    74  	Logger logger
    75  }
    76  
    77  type Tail struct {
    78  	Filename string
    79  	Lines    chan *Line
    80  	Config
    81  
    82  	file   *os.File
    83  	reader *bufio.Reader
    84  
    85  	watcher watch.FileWatcher
    86  	changes *watch.FileChanges
    87  
    88  	tomb.Tomb // provides: Done, Kill, Dying
    89  
    90  	fileMtx sync.Mutex
    91  	lk      sync.Mutex
    92  }
    93  
    94  var (
    95  	// DefaultLogger is used when Config.Logger == nil
    96  	DefaultLogger = log.New(os.Stderr, "", log.LstdFlags)
    97  	// DiscardingLogger can be used to disable logging output
    98  	DiscardingLogger = log.New(ioutil.Discard, "", 0)
    99  )
   100  
   101  // TailFile begins tailing the file. Output stream is made available
   102  // via the `Tail.Lines` channel. To handle errors during tailing,
   103  // invoke the `Wait` or `Err` method after finishing reading from the
   104  // `Lines` channel.
   105  func TailFile(filename string, config Config) (*Tail, error) {
   106  	if config.ReOpen && !config.Follow {
   107  		util.Fatal("cannot set ReOpen without Follow.")
   108  	}
   109  
   110  	t := &Tail{
   111  		Filename: filename,
   112  		Lines:    make(chan *Line),
   113  		Config:   config,
   114  	}
   115  
   116  	// when Logger was not specified in config, use default logger
   117  	if t.Logger == nil {
   118  		t.Logger = log.New(os.Stderr, "", log.LstdFlags)
   119  	}
   120  
   121  	if t.Poll {
   122  		watcher, err := watch.NewPollingFileWatcher(filename, config.PollOptions)
   123  		if err != nil {
   124  			return nil, err
   125  		}
   126  		t.watcher = watcher
   127  	} else {
   128  		t.watcher = watch.NewInotifyFileWatcher(filename)
   129  	}
   130  
   131  	if t.MustExist {
   132  		var err error
   133  		t.file, err = OpenFile(t.Filename)
   134  		if err != nil {
   135  			return nil, err
   136  		}
   137  		t.watcher.SetFile(t.file)
   138  	}
   139  
   140  	go t.tailFileSync()
   141  
   142  	return t, nil
   143  }
   144  
   145  // Return the file's current position, like stdio's ftell().
   146  // But this value is not very accurate.
   147  // it may readed one line in the chan(tail.Lines),
   148  // so it may lost one line.
   149  func (tail *Tail) Tell() (int64, error) {
   150  	tail.fileMtx.Lock()
   151  	f := tail.file
   152  	tail.fileMtx.Unlock()
   153  	if f == nil {
   154  		return 0, os.ErrNotExist
   155  	}
   156  	offset, err := f.Seek(0, io.SeekCurrent)
   157  	if err != nil {
   158  		return 0, err
   159  	}
   160  
   161  	tail.lk.Lock()
   162  	defer tail.lk.Unlock()
   163  	if tail.reader == nil {
   164  		return 0, nil
   165  	}
   166  
   167  	offset -= int64(tail.reader.Buffered())
   168  	return offset, nil
   169  }
   170  
   171  // Size returns the length in bytes of the file being tailed,
   172  // or 0 with an error if there was an error Stat'ing the file.
   173  func (tail *Tail) Size() (int64, error) {
   174  	tail.fileMtx.Lock()
   175  	f := tail.file
   176  	tail.fileMtx.Unlock()
   177  	if f == nil {
   178  		return 0, os.ErrNotExist
   179  	}
   180  	fi, err := f.Stat()
   181  	if err != nil {
   182  		return 0, err
   183  	}
   184  	size := fi.Size()
   185  	return size, nil
   186  }
   187  
   188  // Stop stops the tailing activity.
   189  func (tail *Tail) Stop() error {
   190  	tail.Kill(nil)
   191  	return tail.Wait()
   192  }
   193  
   194  // StopAtEOF stops tailing as soon as the end of the file is reached.
   195  func (tail *Tail) StopAtEOF() error {
   196  	tail.Kill(errStopAtEOF)
   197  	return tail.Wait()
   198  }
   199  
   200  var errStopAtEOF = errors.New("tail: stop at eof")
   201  
   202  func (tail *Tail) close() {
   203  	close(tail.Lines)
   204  	tail.closeFile()
   205  }
   206  
   207  func (tail *Tail) closeFile() {
   208  	tail.fileMtx.Lock()
   209  	defer tail.fileMtx.Unlock()
   210  	if tail.file != nil {
   211  		tail.file.Close()
   212  		tail.file = nil
   213  	}
   214  }
   215  
   216  func (tail *Tail) reopen(truncated bool) error {
   217  
   218  	// There are cases where the file is reopened so quickly it's still the same file
   219  	// which causes the poller to hang on an open file handle to a file no longer being written to
   220  	// and which eventually gets deleted.  Save the current file handle info to make sure we only
   221  	// start tailing a different file.
   222  	cf, err := tail.file.Stat()
   223  	if !truncated && err != nil {
   224  		log.Print("stat of old file returned, this is not expected and may result in unexpected behavior")
   225  		// We don't action on this error but are logging it, not expecting to see it happen and not sure if we
   226  		// need to action on it, cf is checked for nil later on to accommodate this
   227  	}
   228  
   229  	tail.closeFile()
   230  	retries := 20
   231  	for {
   232  		var err error
   233  		tail.fileMtx.Lock()
   234  		tail.file, err = OpenFile(tail.Filename)
   235  		tail.watcher.SetFile(tail.file)
   236  		tail.fileMtx.Unlock()
   237  		if err != nil {
   238  			if os.IsNotExist(err) {
   239  				tail.Logger.Printf("Waiting for %s to appear...", tail.Filename)
   240  				if err := tail.watcher.BlockUntilExists(&tail.Tomb); err != nil {
   241  					if err == tomb.ErrDying {
   242  						return err
   243  					}
   244  					return fmt.Errorf("Failed to detect creation of %s: %s", tail.Filename, err)
   245  				}
   246  				continue
   247  			}
   248  			return fmt.Errorf("Unable to open file %s: %s", tail.Filename, err)
   249  		}
   250  
   251  		// File exists and is opened, get information about it.
   252  		nf, err := tail.file.Stat()
   253  		if err != nil {
   254  			tail.Logger.Print("Failed to stat new file to be tailed, will try to open it again")
   255  			tail.closeFile()
   256  			continue
   257  		}
   258  
   259  		// Check to see if we are trying to reopen and tail the exact same file (and it was not truncated).
   260  		if !truncated && cf != nil && os.SameFile(cf, nf) {
   261  			retries--
   262  			if retries <= 0 {
   263  				return errors.New("gave up trying to reopen log file with a different handle")
   264  			}
   265  
   266  			select {
   267  			case <-time.After(watch.DefaultPollingFileWatcherOptions.MaxPollFrequency):
   268  				tail.closeFile()
   269  				continue
   270  			case <-tail.Tomb.Dying():
   271  				return tomb.ErrDying
   272  			}
   273  		}
   274  		break
   275  	}
   276  	return nil
   277  }
   278  
   279  func (tail *Tail) readLine() (string, error) {
   280  	tail.lk.Lock()
   281  	line, err := tail.reader.ReadString('\n')
   282  	tail.lk.Unlock()
   283  	if err != nil {
   284  		// Note ReadString "returns the data read before the error" in
   285  		// case of an error, including EOF, so we return it as is. The
   286  		// caller is expected to process it if err is EOF.
   287  		return line, err
   288  	}
   289  
   290  	line = strings.TrimRight(line, "\n")
   291  
   292  	return line, err
   293  }
   294  
   295  func (tail *Tail) tailFileSync() {
   296  	defer tail.Done()
   297  	defer tail.close()
   298  
   299  	if !tail.MustExist {
   300  		// deferred first open, not technically truncated but we don't need to check for changed files
   301  		err := tail.reopen(true)
   302  		if err != nil {
   303  			if err != tomb.ErrDying {
   304  				tail.Kill(err)
   305  			}
   306  			return
   307  		}
   308  	}
   309  
   310  	// Seek to requested location on first open of the file.
   311  	if tail.Location != nil {
   312  		_, err := tail.file.Seek(tail.Location.Offset, tail.Location.Whence)
   313  		tail.Logger.Printf("Seeked %s - %+v\n", tail.Filename, tail.Location)
   314  		if err != nil {
   315  			tail.Killf("Seek error on %s: %s", tail.Filename, err)
   316  			return
   317  		}
   318  	}
   319  
   320  	tail.openReader()
   321  
   322  	var offset int64
   323  	var err error
   324  	oneMoreRun := false
   325  
   326  	// Read line by line.
   327  	for {
   328  		// do not seek in named pipes
   329  		if !tail.Pipe {
   330  			// grab the position in case we need to back up in the event of a half-line
   331  			offset, err = tail.Tell()
   332  			if err != nil {
   333  				tail.Kill(err)
   334  				return
   335  			}
   336  		}
   337  
   338  		line, err := tail.readLine()
   339  
   340  		// Process `line` even if err is EOF.
   341  		if err == nil {
   342  			cooloff := !tail.sendLine(line)
   343  			if cooloff {
   344  				// Wait a second before seeking till the end of
   345  				// file when rate limit is reached.
   346  				msg := ("Too much log activity; waiting a second " +
   347  					"before resuming tailing")
   348  				tail.Lines <- &Line{msg, time.Now(), errors.New(msg)}
   349  				select {
   350  				case <-time.After(time.Second):
   351  				case <-tail.Dying():
   352  					return
   353  				}
   354  				if err := tail.seekEnd(); err != nil {
   355  					tail.Kill(err)
   356  					return
   357  				}
   358  			}
   359  		} else if err == io.EOF {
   360  			if !tail.Follow {
   361  				if line != "" {
   362  					tail.sendLine(line)
   363  				}
   364  				return
   365  			}
   366  
   367  			if tail.Follow && line != "" {
   368  				// this has the potential to never return the last line if
   369  				// it's not followed by a newline; seems a fair trade here
   370  				err := tail.seekTo(SeekInfo{Offset: offset, Whence: 0})
   371  				if err != nil {
   372  					tail.Kill(err)
   373  					return
   374  				}
   375  			}
   376  
   377  			// oneMoreRun is set true when a file is deleted,
   378  			// this is to catch events which might get missed in polling mode.
   379  			// now that the last run is completed, finish deleting the file
   380  			if oneMoreRun {
   381  				oneMoreRun = false
   382  				err = tail.finishDelete()
   383  				if err != nil {
   384  					if err != ErrStop {
   385  						tail.Kill(err)
   386  					}
   387  					return
   388  				}
   389  			}
   390  
   391  			// When EOF is reached, wait for more data to become
   392  			// available. Wait strategy is based on the `tail.watcher`
   393  			// implementation (inotify or polling).
   394  			oneMoreRun, err = tail.waitForChanges()
   395  			if err != nil {
   396  				if err != ErrStop {
   397  					tail.Kill(err)
   398  				}
   399  				return
   400  			}
   401  		} else {
   402  			// non-EOF error
   403  			tail.Killf("Error reading %s: %s", tail.Filename, err)
   404  			return
   405  		}
   406  
   407  		select {
   408  		case <-tail.Dying():
   409  			if tail.Err() == errStopAtEOF {
   410  				continue
   411  			}
   412  			return
   413  		default:
   414  		}
   415  	}
   416  }
   417  
   418  // waitForChanges waits until the file has been appended, deleted,
   419  // moved or truncated. When moved or deleted - the file will be
   420  // reopened if ReOpen is true. Truncated files are always reopened.
   421  func (tail *Tail) waitForChanges() (bool, error) {
   422  	if tail.changes == nil {
   423  		pos, err := tail.file.Seek(0, io.SeekCurrent)
   424  		if err != nil {
   425  			return false, err
   426  		}
   427  		tail.changes, err = tail.watcher.ChangeEvents(&tail.Tomb, pos)
   428  		if err != nil {
   429  			return false, err
   430  		}
   431  	}
   432  
   433  	select {
   434  	case <-tail.changes.Modified:
   435  		return false, nil
   436  	case <-tail.changes.Deleted:
   437  		// In polling mode we could miss events when a file is deleted, so before we give up our file handle
   438  		// run the poll one more time to catch anything we may have missed since the last poll.
   439  		return true, nil
   440  	case <-tail.changes.Truncated:
   441  		// Always reopen truncated files (Follow is true)
   442  		tail.Logger.Printf("Re-opening truncated file %s ...", tail.Filename)
   443  		if err := tail.reopen(true); err != nil {
   444  			return false, err
   445  		}
   446  		tail.Logger.Printf("Successfully reopened truncated %s", tail.Filename)
   447  		tail.openReader()
   448  		return false, nil
   449  	case <-tail.Dying():
   450  		return false, ErrStop
   451  	}
   452  	panic("unreachable")
   453  }
   454  
   455  func (tail *Tail) finishDelete() error {
   456  	tail.changes = nil
   457  	if tail.ReOpen {
   458  		// XXX: we must not log from a library.
   459  		tail.Logger.Printf("Re-opening moved/deleted file %s ...", tail.Filename)
   460  		if err := tail.reopen(false); err != nil {
   461  			return err
   462  		}
   463  		tail.Logger.Printf("Successfully reopened %s", tail.Filename)
   464  		tail.openReader()
   465  		return nil
   466  	} else {
   467  		tail.Logger.Printf("Stopping tail as file no longer exists: %s", tail.Filename)
   468  		return ErrStop
   469  	}
   470  }
   471  
   472  func (tail *Tail) openReader() {
   473  	if tail.MaxLineSize > 0 {
   474  		// add 2 to account for newline characters
   475  		tail.reader = bufio.NewReaderSize(tail.file, tail.MaxLineSize+2)
   476  	} else {
   477  		tail.reader = bufio.NewReader(tail.file)
   478  	}
   479  }
   480  
   481  func (tail *Tail) seekEnd() error {
   482  	return tail.seekTo(SeekInfo{Offset: 0, Whence: os.SEEK_END})
   483  }
   484  
   485  func (tail *Tail) seekTo(pos SeekInfo) error {
   486  	_, err := tail.file.Seek(pos.Offset, pos.Whence)
   487  	if err != nil {
   488  		return fmt.Errorf("Seek error on %s: %s", tail.Filename, err)
   489  	}
   490  	// Reset the read buffer whenever the file is re-seek'ed
   491  	tail.reader.Reset(tail.file)
   492  	return nil
   493  }
   494  
   495  // sendLine sends the line(s) to Lines channel, splitting longer lines
   496  // if necessary. Return false if rate limit is reached.
   497  func (tail *Tail) sendLine(line string) bool {
   498  	now := time.Now()
   499  	lines := []string{line}
   500  
   501  	// Split longer lines
   502  	if tail.MaxLineSize > 0 && len(line) > tail.MaxLineSize {
   503  		lines = util.PartitionString(line, tail.MaxLineSize)
   504  	}
   505  
   506  	for _, line := range lines {
   507  		tail.Lines <- &Line{line, now, nil}
   508  	}
   509  
   510  	if tail.Config.RateLimiter != nil {
   511  		ok := tail.Config.RateLimiter.Pour(uint16(len(lines)))
   512  		if !ok {
   513  			tail.Logger.Printf("Leaky bucket full (%v); entering 1s cooloff period.\n",
   514  				tail.Filename)
   515  			return false
   516  		}
   517  	}
   518  
   519  	return true
   520  }
   521  
   522  // Cleanup removes inotify watches added by the tail package. This function is
   523  // meant to be invoked from a process's exit handler. Linux kernel may not
   524  // automatically remove inotify watches after the process exits.
   525  func (tail *Tail) Cleanup() {
   526  	watch.Cleanup(tail.Filename)
   527  }