glog_file.go

Documentation: github.com/golang/glog

     1  // Go support for leveled logs, analogous to https://github.com/google/glog.
     2  //
     3  // Copyright 2023 Google Inc. All Rights Reserved.
     4  //
     5  // Licensed under the Apache License, Version 2.0 (the "License");
     6  // you may not use this file except in compliance with the License.
     7  // You may obtain a copy of the License at
     8  //
     9  //     http://www.apache.org/licenses/LICENSE-2.0
    10  //
    11  // Unless required by applicable law or agreed to in writing, software
    12  // distributed under the License is distributed on an "AS IS" BASIS,
    13  // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
    14  // See the License for the specific language governing permissions and
    15  // limitations under the License.
    16  
    17  // File I/O for logs.
    18  
    19  package glog
    20  
    21  import (
    22  	"bufio"
    23  	"bytes"
    24  	"errors"
    25  	"flag"
    26  	"fmt"
    27  	"io"
    28  	"os"
    29  	"os/user"
    30  	"path/filepath"
    31  	"runtime"
    32  	"strings"
    33  	"sync"
    34  	"time"
    35  
    36  	"github.com/golang/glog/internal/logsink"
    37  )
    38  
    39  // logDirs lists the candidate directories for new log files.
    40  var logDirs []string
    41  
    42  var (
    43  	// If non-empty, overrides the choice of directory in which to write logs.
    44  	// See createLogDirs for the full list of possible destinations.
    45  	logDir      = flag.String("log_dir", "", "If non-empty, write log files in this directory")
    46  	logLink     = flag.String("log_link", "", "If non-empty, add symbolic links in this directory to the log files")
    47  	logBufLevel = flag.Int("logbuflevel", int(logsink.Info), "Buffer log messages logged at this level or lower"+
    48  		" (-1 means don't buffer; 0 means buffer INFO only; ...). Has limited applicability on non-prod platforms.")
    49  )
    50  
    51  func createLogDirs() {
    52  	if *logDir != "" {
    53  		logDirs = append(logDirs, *logDir)
    54  	}
    55  	logDirs = append(logDirs, os.TempDir())
    56  }
    57  
    58  var (
    59  	pid      = os.Getpid()
    60  	program  = filepath.Base(os.Args[0])
    61  	host     = "unknownhost"
    62  	userName = "unknownuser"
    63  )
    64  
    65  func init() {
    66  	h, err := os.Hostname()
    67  	if err == nil {
    68  		host = shortHostname(h)
    69  	}
    70  
    71  	current, err := user.Current()
    72  	if err == nil {
    73  		userName = current.Username
    74  	}
    75  	// Sanitize userName since it is used to construct file paths.
    76  	userName = strings.Map(func(r rune) rune {
    77  		switch {
    78  		case r >= 'a' && r <= 'z':
    79  		case r >= 'A' && r <= 'Z':
    80  		case r >= '0' && r <= '9':
    81  		default:
    82  			return '_'
    83  		}
    84  		return r
    85  	}, userName)
    86  }
    87  
    88  // shortHostname returns its argument, truncating at the first period.
    89  // For instance, given "www.google.com" it returns "www".
    90  func shortHostname(hostname string) string {
    91  	if i := strings.Index(hostname, "."); i >= 0 {
    92  		return hostname[:i]
    93  	}
    94  	return hostname
    95  }
    96  
    97  // logName returns a new log file name containing tag, with start time t, and
    98  // the name for the symlink for tag.
    99  func logName(tag string, t time.Time) (name, link string) {
   100  	name = fmt.Sprintf("%s.%s.%s.log.%s.%04d%02d%02d-%02d%02d%02d.%d",
   101  		program,
   102  		host,
   103  		userName,
   104  		tag,
   105  		t.Year(),
   106  		t.Month(),
   107  		t.Day(),
   108  		t.Hour(),
   109  		t.Minute(),
   110  		t.Second(),
   111  		pid)
   112  	return name, program + "." + tag
   113  }
   114  
   115  var onceLogDirs sync.Once
   116  
   117  // create creates a new log file and returns the file and its filename, which
   118  // contains tag ("INFO", "FATAL", etc.) and t.  If the file is created
   119  // successfully, create also attempts to update the symlink for that tag, ignoring
   120  // errors.
   121  func create(tag string, t time.Time) (f *os.File, filename string, err error) {
   122  	onceLogDirs.Do(createLogDirs)
   123  	if len(logDirs) == 0 {
   124  		return nil, "", errors.New("log: no log dirs")
   125  	}
   126  	name, link := logName(tag, t)
   127  	var lastErr error
   128  	for _, dir := range logDirs {
   129  		fname := filepath.Join(dir, name)
   130  		f, err := os.Create(fname)
   131  		if err == nil {
   132  			symlink := filepath.Join(dir, link)
   133  			os.Remove(symlink)        // ignore err
   134  			os.Symlink(name, symlink) // ignore err
   135  			if *logLink != "" {
   136  				lsymlink := filepath.Join(*logLink, link)
   137  				os.Remove(lsymlink)         // ignore err
   138  				os.Symlink(fname, lsymlink) // ignore err
   139  			}
   140  			return f, fname, nil
   141  		}
   142  		lastErr = err
   143  	}
   144  	return nil, "", fmt.Errorf("log: cannot create log: %v", lastErr)
   145  }
   146  
   147  // flushSyncWriter is the interface satisfied by logging destinations.
   148  type flushSyncWriter interface {
   149  	Flush() error
   150  	Sync() error
   151  	io.Writer
   152  	filenames() []string
   153  }
   154  
   155  var sinks struct {
   156  	stderr stderrSink
   157  	file   fileSink
   158  }
   159  
   160  func init() {
   161  	// Register stderr first: that way if we crash during file-writing at least
   162  	// the log will have gone somewhere.
   163  	logsink.TextSinks = append(logsink.TextSinks, &sinks.stderr, &sinks.file)
   164  
   165  	sinks.file.flushChan = make(chan logsink.Severity, 1)
   166  	go sinks.file.flushDaemon()
   167  }
   168  
   169  // stderrSink is a logsink.Text that writes log entries to stderr
   170  // if they meet certain conditions.
   171  type stderrSink struct {
   172  	mu sync.Mutex
   173  	w  io.Writer // if nil Emit uses os.Stderr directly
   174  }
   175  
   176  // Enabled implements logsink.Text.Enabled.  It returns true if any of the
   177  // various stderr flags are enabled for logs of the given severity, if the log
   178  // message is from the standard "log" package, or if google.Init has not yet run
   179  // (and hence file logging is not yet initialized).
   180  func (s *stderrSink) Enabled(m *logsink.Meta) bool {
   181  	return toStderr || alsoToStderr || m.Severity >= stderrThreshold.get()
   182  }
   183  
   184  // Emit implements logsink.Text.Emit.
   185  func (s *stderrSink) Emit(m *logsink.Meta, data []byte) (n int, err error) {
   186  	s.mu.Lock()
   187  	defer s.mu.Unlock()
   188  	w := s.w
   189  	if w == nil {
   190  		w = os.Stderr
   191  	}
   192  	dn, err := w.Write(data)
   193  	n += dn
   194  	return n, err
   195  }
   196  
   197  // severityWriters is an array of flushSyncWriter with a value for each
   198  // logsink.Severity.
   199  type severityWriters [4]flushSyncWriter
   200  
   201  // fileSink is a logsink.Text that prints to a set of Google log files.
   202  type fileSink struct {
   203  	mu sync.Mutex
   204  	// file holds writer for each of the log types.
   205  	file      severityWriters
   206  	flushChan chan logsink.Severity
   207  }
   208  
   209  // Enabled implements logsink.Text.Enabled.  It returns true if google.Init
   210  // has run and both --disable_log_to_disk and --logtostderr are false.
   211  func (s *fileSink) Enabled(m *logsink.Meta) bool {
   212  	return !toStderr
   213  }
   214  
   215  // Emit implements logsink.Text.Emit
   216  func (s *fileSink) Emit(m *logsink.Meta, data []byte) (n int, err error) {
   217  	s.mu.Lock()
   218  	defer s.mu.Unlock()
   219  
   220  	if err = s.createMissingFiles(m.Severity); err != nil {
   221  		return 0, err
   222  	}
   223  	for sev := m.Severity; sev >= logsink.Info; sev-- {
   224  		if _, fErr := s.file[sev].Write(data); fErr != nil && err == nil {
   225  			err = fErr // Take the first error.
   226  		}
   227  	}
   228  	n = len(data)
   229  	if int(m.Severity) > *logBufLevel {
   230  		select {
   231  		case s.flushChan <- m.Severity:
   232  		default:
   233  		}
   234  	}
   235  
   236  	return n, err
   237  }
   238  
   239  // syncBuffer joins a bufio.Writer to its underlying file, providing access to the
   240  // file's Sync method and providing a wrapper for the Write method that provides log
   241  // file rotation. There are conflicting methods, so the file cannot be embedded.
   242  // s.mu is held for all its methods.
   243  type syncBuffer struct {
   244  	sink *fileSink
   245  	*bufio.Writer
   246  	file   *os.File
   247  	names  []string
   248  	sev    logsink.Severity
   249  	nbytes uint64 // The number of bytes written to this file
   250  }
   251  
   252  func (sb *syncBuffer) Sync() error {
   253  	return sb.file.Sync()
   254  }
   255  
   256  func (sb *syncBuffer) Write(p []byte) (n int, err error) {
   257  	if sb.nbytes+uint64(len(p)) >= MaxSize {
   258  		if err := sb.rotateFile(time.Now()); err != nil {
   259  			return 0, err
   260  		}
   261  	}
   262  	n, err = sb.Writer.Write(p)
   263  	sb.nbytes += uint64(n)
   264  	return n, err
   265  }
   266  
   267  func (sb *syncBuffer) filenames() []string {
   268  	return sb.names
   269  }
   270  
   271  const footer = "\nCONTINUED IN NEXT FILE\n"
   272  
   273  // rotateFile closes the syncBuffer's file and starts a new one.
   274  func (sb *syncBuffer) rotateFile(now time.Time) error {
   275  	var err error
   276  	pn := "<none>"
   277  	file, name, err := create(sb.sev.String(), now)
   278  
   279  	if sb.file != nil {
   280  		// The current log file becomes the previous log at the end of
   281  		// this block, so save its name for use in the header of the next
   282  		// file.
   283  		pn = sb.file.Name()
   284  		sb.Flush()
   285  		// If there's an existing file, write a footer with the name of
   286  		// the next file in the chain, followed by the constant string
   287  		// \nCONTINUED IN NEXT FILE\n to make continuation detection simple.
   288  		sb.file.Write([]byte("Next log: "))
   289  		sb.file.Write([]byte(name))
   290  		sb.file.Write([]byte(footer))
   291  		sb.file.Close()
   292  	}
   293  
   294  	sb.file = file
   295  	sb.names = append(sb.names, name)
   296  	sb.nbytes = 0
   297  	if err != nil {
   298  		return err
   299  	}
   300  
   301  	sb.Writer = bufio.NewWriterSize(sb.file, bufferSize)
   302  
   303  	// Write header.
   304  	var buf bytes.Buffer
   305  	fmt.Fprintf(&buf, "Log file created at: %s\n", now.Format("2006/01/02 15:04:05"))
   306  	fmt.Fprintf(&buf, "Running on machine: %s\n", host)
   307  	fmt.Fprintf(&buf, "Binary: Built with %s %s for %s/%s\n", runtime.Compiler, runtime.Version(), runtime.GOOS, runtime.GOARCH)
   308  	fmt.Fprintf(&buf, "Previous log: %s\n", pn)
   309  	fmt.Fprintf(&buf, "Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg\n")
   310  	n, err := sb.file.Write(buf.Bytes())
   311  	sb.nbytes += uint64(n)
   312  	return err
   313  }
   314  
   315  // bufferSize sizes the buffer associated with each log file. It's large
   316  // so that log records can accumulate without the logging thread blocking
   317  // on disk I/O. The flushDaemon will block instead.
   318  const bufferSize = 256 * 1024
   319  
   320  // createMissingFiles creates all the log files for severity from infoLog up to
   321  // upTo that have not already been created.
   322  // s.mu is held.
   323  func (s *fileSink) createMissingFiles(upTo logsink.Severity) error {
   324  	if s.file[upTo] != nil {
   325  		return nil
   326  	}
   327  	now := time.Now()
   328  	// Files are created in increasing severity order, so we can be assured that
   329  	// if a high severity logfile exists, then so do all of lower severity.
   330  	for sev := logsink.Info; sev <= upTo; sev++ {
   331  		if s.file[sev] != nil {
   332  			continue
   333  		}
   334  		sb := &syncBuffer{
   335  			sink: s,
   336  			sev:  sev,
   337  		}
   338  		if err := sb.rotateFile(now); err != nil {
   339  			return err
   340  		}
   341  		s.file[sev] = sb
   342  	}
   343  	return nil
   344  }
   345  
   346  // flushDaemon periodically flushes the log file buffers.
   347  func (s *fileSink) flushDaemon() {
   348  	tick := time.NewTicker(30 * time.Second)
   349  	defer tick.Stop()
   350  	for {
   351  		select {
   352  		case <-tick.C:
   353  			s.Flush()
   354  		case sev := <-s.flushChan:
   355  			s.flush(sev)
   356  		}
   357  	}
   358  }
   359  
   360  // Flush flushes all pending log I/O.
   361  func Flush() {
   362  	sinks.file.Flush()
   363  }
   364  
   365  // Flush flushes all the logs and attempts to "sync" their data to disk.
   366  func (s *fileSink) Flush() error {
   367  	return s.flush(logsink.Info)
   368  }
   369  
   370  // flush flushes all logs of severity threshold or greater.
   371  func (s *fileSink) flush(threshold logsink.Severity) error {
   372  	var firstErr error
   373  	updateErr := func(err error) {
   374  		if err != nil && firstErr == nil {
   375  			firstErr = err
   376  		}
   377  	}
   378  
   379  	// Remember where we flushed, so we can call sync without holding
   380  	// the lock.
   381  	var files []flushSyncWriter
   382  	func() {
   383  		s.mu.Lock()
   384  		defer s.mu.Unlock()
   385  		// Flush from fatal down, in case there's trouble flushing.
   386  		for sev := logsink.Fatal; sev >= threshold; sev-- {
   387  			if file := s.file[sev]; file != nil {
   388  				updateErr(file.Flush())
   389  				files = append(files, file)
   390  			}
   391  		}
   392  	}()
   393  
   394  	for _, file := range files {
   395  		updateErr(file.Sync())
   396  	}
   397  
   398  	return firstErr
   399  }
   400  
   401  // Names returns the names of the log files holding the FATAL, ERROR,
   402  // WARNING, or INFO logs. Returns ErrNoLog if the log for the given
   403  // level doesn't exist (e.g. because no messages of that level have been
   404  // written). This may return multiple names if the log type requested
   405  // has rolled over.
   406  func Names(s string) ([]string, error) {
   407  	severity, err := logsink.ParseSeverity(s)
   408  	if err != nil {
   409  		return nil, err
   410  	}
   411  
   412  	sinks.file.mu.Lock()
   413  	defer sinks.file.mu.Unlock()
   414  	f := sinks.file.file[severity]
   415  	if f == nil {
   416  		return nil, ErrNoLog
   417  	}
   418  
   419  	return f.filenames(), nil
   420  }
   421
View as plain text