github.com/rita33cool1/iot-system-gateway@v0.0.0-20200911033302-e65bde238cc5/docker-engine/daemon/logger/loggerutils/logfile.go (about)

     1  package loggerutils // import "github.com/docker/docker/daemon/logger/loggerutils"
     2  
     3  import (
     4  	"bytes"
     5  	"context"
     6  	"fmt"
     7  	"io"
     8  	"os"
     9  	"strconv"
    10  	"sync"
    11  	"time"
    12  
    13  	"github.com/docker/docker/daemon/logger"
    14  	"github.com/docker/docker/daemon/logger/loggerutils/multireader"
    15  	"github.com/docker/docker/pkg/filenotify"
    16  	"github.com/docker/docker/pkg/pubsub"
    17  	"github.com/docker/docker/pkg/tailfile"
    18  	"github.com/fsnotify/fsnotify"
    19  	"github.com/pkg/errors"
    20  	"github.com/sirupsen/logrus"
    21  )
    22  
    23  // LogFile is Logger implementation for default Docker logging.
    24  type LogFile struct {
    25  	f             *os.File // store for closing
    26  	closed        bool
    27  	mu            sync.RWMutex
    28  	capacity      int64 //maximum size of each file
    29  	currentSize   int64 // current size of the latest file
    30  	maxFiles      int   //maximum number of files
    31  	notifyRotate  *pubsub.Publisher
    32  	marshal       logger.MarshalFunc
    33  	createDecoder makeDecoderFunc
    34  }
    35  
    36  type makeDecoderFunc func(rdr io.Reader) func() (*logger.Message, error)
    37  
    38  //NewLogFile creates new LogFile
    39  func NewLogFile(logPath string, capacity int64, maxFiles int, marshaller logger.MarshalFunc, decodeFunc makeDecoderFunc) (*LogFile, error) {
    40  	log, err := os.OpenFile(logPath, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0640)
    41  	if err != nil {
    42  		return nil, err
    43  	}
    44  
    45  	size, err := log.Seek(0, os.SEEK_END)
    46  	if err != nil {
    47  		return nil, err
    48  	}
    49  
    50  	return &LogFile{
    51  		f:             log,
    52  		capacity:      capacity,
    53  		currentSize:   size,
    54  		maxFiles:      maxFiles,
    55  		notifyRotate:  pubsub.NewPublisher(0, 1),
    56  		marshal:       marshaller,
    57  		createDecoder: decodeFunc,
    58  	}, nil
    59  }
    60  
    61  // WriteLogEntry writes the provided log message to the current log file.
    62  // This may trigger a rotation event if the max file/capacity limits are hit.
    63  func (w *LogFile) WriteLogEntry(msg *logger.Message) error {
    64  	b, err := w.marshal(msg)
    65  	if err != nil {
    66  		return errors.Wrap(err, "error marshalling log message")
    67  	}
    68  
    69  	logger.PutMessage(msg)
    70  
    71  	w.mu.Lock()
    72  	if w.closed {
    73  		w.mu.Unlock()
    74  		return errors.New("cannot write because the output file was closed")
    75  	}
    76  
    77  	if err := w.checkCapacityAndRotate(); err != nil {
    78  		w.mu.Unlock()
    79  		return err
    80  	}
    81  
    82  	n, err := w.f.Write(b)
    83  	if err == nil {
    84  		w.currentSize += int64(n)
    85  	}
    86  	w.mu.Unlock()
    87  	return err
    88  }
    89  
    90  func (w *LogFile) checkCapacityAndRotate() error {
    91  	if w.capacity == -1 {
    92  		return nil
    93  	}
    94  
    95  	if w.currentSize >= w.capacity {
    96  		name := w.f.Name()
    97  		if err := w.f.Close(); err != nil {
    98  			return errors.Wrap(err, "error closing file")
    99  		}
   100  		if err := rotate(name, w.maxFiles); err != nil {
   101  			return err
   102  		}
   103  		file, err := os.OpenFile(name, os.O_WRONLY|os.O_TRUNC|os.O_CREATE, 0640)
   104  		if err != nil {
   105  			return err
   106  		}
   107  		w.f = file
   108  		w.currentSize = 0
   109  		w.notifyRotate.Publish(struct{}{})
   110  	}
   111  
   112  	return nil
   113  }
   114  
   115  func rotate(name string, maxFiles int) error {
   116  	if maxFiles < 2 {
   117  		return nil
   118  	}
   119  	for i := maxFiles - 1; i > 1; i-- {
   120  		toPath := name + "." + strconv.Itoa(i)
   121  		fromPath := name + "." + strconv.Itoa(i-1)
   122  		if err := os.Rename(fromPath, toPath); err != nil && !os.IsNotExist(err) {
   123  			return errors.Wrap(err, "error rotating old log entries")
   124  		}
   125  	}
   126  
   127  	if err := os.Rename(name, name+".1"); err != nil && !os.IsNotExist(err) {
   128  		return errors.Wrap(err, "error rotating current log")
   129  	}
   130  	return nil
   131  }
   132  
   133  // MaxFiles return maximum number of files
   134  func (w *LogFile) MaxFiles() int {
   135  	return w.maxFiles
   136  }
   137  
   138  // Close closes underlying file and signals all readers to stop.
   139  func (w *LogFile) Close() error {
   140  	w.mu.Lock()
   141  	defer w.mu.Unlock()
   142  	if w.closed {
   143  		return nil
   144  	}
   145  	if err := w.f.Close(); err != nil {
   146  		return err
   147  	}
   148  	w.closed = true
   149  	return nil
   150  }
   151  
   152  // ReadLogs decodes entries from log files and sends them the passed in watcher
   153  func (w *LogFile) ReadLogs(config logger.ReadConfig, watcher *logger.LogWatcher) {
   154  	w.mu.RLock()
   155  	files, err := w.openRotatedFiles()
   156  	if err != nil {
   157  		w.mu.RUnlock()
   158  		watcher.Err <- err
   159  		return
   160  	}
   161  	defer func() {
   162  		for _, f := range files {
   163  			f.Close()
   164  		}
   165  	}()
   166  
   167  	currentFile, err := os.Open(w.f.Name())
   168  	if err != nil {
   169  		w.mu.RUnlock()
   170  		watcher.Err <- err
   171  		return
   172  	}
   173  	defer currentFile.Close()
   174  
   175  	currentChunk, err := newSectionReader(currentFile)
   176  	w.mu.RUnlock()
   177  
   178  	if err != nil {
   179  		watcher.Err <- err
   180  		return
   181  	}
   182  
   183  	if config.Tail != 0 {
   184  		seekers := make([]io.ReadSeeker, 0, len(files)+1)
   185  		for _, f := range files {
   186  			seekers = append(seekers, f)
   187  		}
   188  		if currentChunk.Size() > 0 {
   189  			seekers = append(seekers, currentChunk)
   190  		}
   191  		if len(seekers) > 0 {
   192  			tailFile(multireader.MultiReadSeeker(seekers...), watcher, w.createDecoder, config)
   193  		}
   194  	}
   195  
   196  	w.mu.RLock()
   197  	if !config.Follow || w.closed {
   198  		w.mu.RUnlock()
   199  		return
   200  	}
   201  	w.mu.RUnlock()
   202  
   203  	notifyRotate := w.notifyRotate.Subscribe()
   204  	defer w.notifyRotate.Evict(notifyRotate)
   205  	followLogs(currentFile, watcher, notifyRotate, w.createDecoder, config.Since, config.Until)
   206  }
   207  
   208  func (w *LogFile) openRotatedFiles() (files []*os.File, err error) {
   209  	defer func() {
   210  		if err == nil {
   211  			return
   212  		}
   213  		for _, f := range files {
   214  			f.Close()
   215  		}
   216  	}()
   217  
   218  	for i := w.maxFiles; i > 1; i-- {
   219  		f, err := os.Open(fmt.Sprintf("%s.%d", w.f.Name(), i-1))
   220  		if err != nil {
   221  			if !os.IsNotExist(err) {
   222  				return nil, err
   223  			}
   224  			continue
   225  		}
   226  		files = append(files, f)
   227  	}
   228  
   229  	return files, nil
   230  }
   231  
   232  func newSectionReader(f *os.File) (*io.SectionReader, error) {
   233  	// seek to the end to get the size
   234  	// we'll leave this at the end of the file since section reader does not advance the reader
   235  	size, err := f.Seek(0, os.SEEK_END)
   236  	if err != nil {
   237  		return nil, errors.Wrap(err, "error getting current file size")
   238  	}
   239  	return io.NewSectionReader(f, 0, size), nil
   240  }
   241  
   242  type decodeFunc func() (*logger.Message, error)
   243  
   244  func tailFile(f io.ReadSeeker, watcher *logger.LogWatcher, createDecoder makeDecoderFunc, config logger.ReadConfig) {
   245  	var rdr io.Reader = f
   246  	if config.Tail > 0 {
   247  		ls, err := tailfile.TailFile(f, config.Tail)
   248  		if err != nil {
   249  			watcher.Err <- err
   250  			return
   251  		}
   252  		rdr = bytes.NewBuffer(bytes.Join(ls, []byte("\n")))
   253  	}
   254  
   255  	decodeLogLine := createDecoder(rdr)
   256  	for {
   257  		msg, err := decodeLogLine()
   258  		if err != nil {
   259  			if err != io.EOF {
   260  				watcher.Err <- err
   261  			}
   262  			return
   263  		}
   264  		if !config.Since.IsZero() && msg.Timestamp.Before(config.Since) {
   265  			continue
   266  		}
   267  		if !config.Until.IsZero() && msg.Timestamp.After(config.Until) {
   268  			return
   269  		}
   270  		select {
   271  		case <-watcher.WatchClose():
   272  			return
   273  		case watcher.Msg <- msg:
   274  		}
   275  	}
   276  }
   277  
   278  func followLogs(f *os.File, logWatcher *logger.LogWatcher, notifyRotate chan interface{}, createDecoder makeDecoderFunc, since, until time.Time) {
   279  	decodeLogLine := createDecoder(f)
   280  
   281  	name := f.Name()
   282  	fileWatcher, err := watchFile(name)
   283  	if err != nil {
   284  		logWatcher.Err <- err
   285  		return
   286  	}
   287  	defer func() {
   288  		f.Close()
   289  		fileWatcher.Remove(name)
   290  		fileWatcher.Close()
   291  	}()
   292  
   293  	ctx, cancel := context.WithCancel(context.Background())
   294  	defer cancel()
   295  	go func() {
   296  		select {
   297  		case <-logWatcher.WatchClose():
   298  			fileWatcher.Remove(name)
   299  			cancel()
   300  		case <-ctx.Done():
   301  			return
   302  		}
   303  	}()
   304  
   305  	var retries int
   306  	handleRotate := func() error {
   307  		f.Close()
   308  		fileWatcher.Remove(name)
   309  
   310  		// retry when the file doesn't exist
   311  		for retries := 0; retries <= 5; retries++ {
   312  			f, err = os.Open(name)
   313  			if err == nil || !os.IsNotExist(err) {
   314  				break
   315  			}
   316  		}
   317  		if err != nil {
   318  			return err
   319  		}
   320  		if err := fileWatcher.Add(name); err != nil {
   321  			return err
   322  		}
   323  		decodeLogLine = createDecoder(f)
   324  		return nil
   325  	}
   326  
   327  	errRetry := errors.New("retry")
   328  	errDone := errors.New("done")
   329  	waitRead := func() error {
   330  		select {
   331  		case e := <-fileWatcher.Events():
   332  			switch e.Op {
   333  			case fsnotify.Write:
   334  				decodeLogLine = createDecoder(f)
   335  				return nil
   336  			case fsnotify.Rename, fsnotify.Remove:
   337  				select {
   338  				case <-notifyRotate:
   339  				case <-ctx.Done():
   340  					return errDone
   341  				}
   342  				if err := handleRotate(); err != nil {
   343  					return err
   344  				}
   345  				return nil
   346  			}
   347  			return errRetry
   348  		case err := <-fileWatcher.Errors():
   349  			logrus.Debug("logger got error watching file: %v", err)
   350  			// Something happened, let's try and stay alive and create a new watcher
   351  			if retries <= 5 {
   352  				fileWatcher.Close()
   353  				fileWatcher, err = watchFile(name)
   354  				if err != nil {
   355  					return err
   356  				}
   357  				retries++
   358  				return errRetry
   359  			}
   360  			return err
   361  		case <-ctx.Done():
   362  			return errDone
   363  		}
   364  	}
   365  
   366  	handleDecodeErr := func(err error) error {
   367  		if err != io.EOF {
   368  			return err
   369  		}
   370  
   371  		for {
   372  			err := waitRead()
   373  			if err == nil {
   374  				break
   375  			}
   376  			if err == errRetry {
   377  				continue
   378  			}
   379  			return err
   380  		}
   381  		return nil
   382  	}
   383  
   384  	// main loop
   385  	for {
   386  		msg, err := decodeLogLine()
   387  		if err != nil {
   388  			if err := handleDecodeErr(err); err != nil {
   389  				if err == errDone {
   390  					return
   391  				}
   392  				// we got an unrecoverable error, so return
   393  				logWatcher.Err <- err
   394  				return
   395  			}
   396  			// ready to try again
   397  			continue
   398  		}
   399  
   400  		retries = 0 // reset retries since we've succeeded
   401  		if !since.IsZero() && msg.Timestamp.Before(since) {
   402  			continue
   403  		}
   404  		if !until.IsZero() && msg.Timestamp.After(until) {
   405  			return
   406  		}
   407  		select {
   408  		case logWatcher.Msg <- msg:
   409  		case <-ctx.Done():
   410  			logWatcher.Msg <- msg
   411  			for {
   412  				msg, err := decodeLogLine()
   413  				if err != nil {
   414  					return
   415  				}
   416  				if !since.IsZero() && msg.Timestamp.Before(since) {
   417  					continue
   418  				}
   419  				if !until.IsZero() && msg.Timestamp.After(until) {
   420  					return
   421  				}
   422  				logWatcher.Msg <- msg
   423  			}
   424  		}
   425  	}
   426  }
   427  
   428  func watchFile(name string) (filenotify.FileWatcher, error) {
   429  	fileWatcher, err := filenotify.New()
   430  	if err != nil {
   431  		return nil, err
   432  	}
   433  
   434  	logger := logrus.WithFields(logrus.Fields{
   435  		"module": "logger",
   436  		"fille":  name,
   437  	})
   438  
   439  	if err := fileWatcher.Add(name); err != nil {
   440  		logger.WithError(err).Warnf("falling back to file poller")
   441  		fileWatcher.Close()
   442  		fileWatcher = filenotify.NewPollingWatcher()
   443  
   444  		if err := fileWatcher.Add(name); err != nil {
   445  			fileWatcher.Close()
   446  			logger.WithError(err).Debugf("error watching log file for modifications")
   447  			return nil, err
   448  		}
   449  	}
   450  	return fileWatcher, nil
   451  }