git » log » commit c82a0ea

log: Replace glog with a new logging module

author Alberto Bertogli
2016-10-24 02:02:11 UTC
committer Alberto Bertogli
2016-11-01 23:56:04 UTC

log: Replace glog with a new logging module

glog works fine and has great features, but it does not play along well
with systemd or standard log rotators (as it does the rotation itself).

So this patch replaces glog with a new logging module "log", which by
default logs to stderr, in a systemd-friendly manner.

Logging to files or syslog is still supported.

log.go +249 -0
log_test.go +104 -0

diff --git a/log.go b/log.go
new file mode 100644
index 0000000..9cde2d1
--- /dev/null
+++ b/log.go
@@ -0,0 +1,249 @@
+// Package log implements a simple logger.
+//
+// It implements an API somewhat similar to "github.com/google/glog" with a
+// focus towards logging to stderr, which is useful for systemd-based
+// environments.
+//
+// There are command line flags (defined using the flag package) to control
+// the behaviour of the default logger. By default, it will write to stderr
+// without timestamps; this is suitable for systemd (or equivalent) logging.
+package log
+
+import (
+	"flag"
+	"fmt"
+	"io"
+	"log/syslog"
+	"os"
+	"path/filepath"
+	"runtime"
+	"strconv"
+	"strings"
+	"sync"
+	"time"
+)
+
+// Flags that control the default logging.
+var (
+	vLevel = flag.Int("v", 0, "Verbosity level (1 = debug)")
+
+	logFile = flag.String("logfile", "",
+		"file to log to (enables logtime)")
+
+	logToSyslog = flag.String("logtosyslog", "",
+		"log to syslog, with the given tag")
+
+	logTime = flag.Bool("logtime", false,
+		"include the time when writing the log to stderr")
+
+	alsoLogToStderr = flag.Bool("alsologtostderr", false,
+		"also log to stderr, in addition to the file")
+)
+
+// Logging levels.
+type Level int
+
+const (
+	Error = Level(-1)
+	Info  = Level(0)
+	Debug = Level(1)
+)
+
+var levelToLetter = map[Level]string{
+	Error: "E",
+	Info:  "_",
+	Debug: ".",
+}
+
+// A Logger represents a logging object that writes logs to the given writer.
+type Logger struct {
+	Level   Level
+	LogTime bool
+
+	CallerSkip int
+
+	w io.WriteCloser
+	sync.Mutex
+}
+
+func New(w io.WriteCloser) *Logger {
+	return &Logger{
+		w:          w,
+		CallerSkip: 0,
+		Level:      Info,
+		LogTime:    true,
+	}
+}
+
+func NewFile(path string) (*Logger, error) {
+	f, err := os.OpenFile(path, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0644)
+	if err != nil {
+		return nil, err
+	}
+
+	l := New(f)
+	l.LogTime = true
+	return l, nil
+}
+
+func NewSyslog(priority syslog.Priority, tag string) (*Logger, error) {
+	w, err := syslog.New(priority, tag)
+	if err != nil {
+		return nil, err
+	}
+
+	l := New(w)
+	l.LogTime = false
+	return l, nil
+}
+
+func (l *Logger) Close() {
+	l.w.Close()
+}
+
+func (l *Logger) V(level Level) bool {
+	return level <= l.Level
+}
+
+func (l *Logger) Log(level Level, skip int, format string, a ...interface{}) {
+	if !l.V(level) {
+		return
+	}
+
+	// Message.
+	msg := fmt.Sprintf(format, a...)
+
+	// Caller.
+	_, file, line, ok := runtime.Caller(1 + l.CallerSkip + skip)
+	if !ok {
+		file = "unknown"
+	}
+	fl := fmt.Sprintf("%s:%-4d", filepath.Base(file), line)
+	if len(fl) > 18 {
+		fl = fl[len(fl)-18:]
+	}
+	msg = fmt.Sprintf("%-18s", fl) + " " + msg
+
+	// Level.
+	letter, ok := levelToLetter[level]
+	if !ok {
+		letter = strconv.Itoa(int(level))
+	}
+	msg = letter + " " + msg
+
+	// Time.
+	if l.LogTime {
+		msg = time.Now().Format("20060102 15:04:05.000000 ") + msg
+	}
+
+	if !strings.HasSuffix(msg, "\n") {
+		msg += "\n"
+	}
+
+	l.Lock()
+	l.w.Write([]byte(msg))
+	l.Unlock()
+}
+
+func (l *Logger) Debugf(format string, a ...interface{}) {
+	l.Log(Debug, 1, format, a...)
+}
+
+func (l *Logger) Infof(format string, a ...interface{}) {
+	l.Log(Info, 1, format, a...)
+}
+
+func (l *Logger) Errorf(format string, a ...interface{}) error {
+	l.Log(Error, 1, format, a...)
+	return fmt.Errorf(format, a...)
+}
+
+func (l *Logger) Fatalf(format string, a ...interface{}) {
+	l.Log(-2, 1, format, a...)
+	// TODO: Log traceback?
+	os.Exit(1)
+}
+
+// The default logger, used by the top-level functions below.
+var Default = &Logger{
+	w:          os.Stderr,
+	CallerSkip: 1,
+	Level:      Info,
+	LogTime:    false,
+}
+
+// Init the default logger, based on the command-line flags.
+// Must be called after flag.Parse().
+func Init() {
+	var err error
+
+	if *logToSyslog != "" {
+		Default, err = NewSyslog(syslog.LOG_DAEMON|syslog.LOG_INFO, *logToSyslog)
+		if err != nil {
+			panic(err)
+		}
+	} else if *logFile != "" {
+		Default, err = NewFile(*logFile)
+		if err != nil {
+			panic(err)
+		}
+		*logTime = true
+	}
+
+	if *alsoLogToStderr && Default.w != os.Stderr {
+		Default.w = multiWriteCloser(Default.w, os.Stderr)
+	}
+
+	Default.CallerSkip = 1
+	Default.Level = Level(*vLevel)
+	Default.LogTime = *logTime
+}
+
+func V(level Level) bool {
+	return Default.V(level)
+}
+
+func Log(level Level, skip int, format string, a ...interface{}) {
+	Default.Log(level, skip, format, a...)
+}
+
+func Debugf(format string, a ...interface{}) {
+	Default.Debugf(format, a...)
+}
+
+func Infof(format string, a ...interface{}) {
+	Default.Infof(format, a...)
+}
+
+func Errorf(format string, a ...interface{}) error {
+	return Default.Errorf(format, a...)
+}
+
+func Fatalf(format string, a ...interface{}) {
+	Default.Fatalf(format, a...)
+}
+
+// multiWriteCloser creates a WriteCloser that duplicates its writes and
+// closes to all the provided writers.
+func multiWriteCloser(wc ...io.WriteCloser) io.WriteCloser {
+	return mwc(wc)
+}
+
+type mwc []io.WriteCloser
+
+func (m mwc) Write(p []byte) (n int, err error) {
+	for _, w := range m {
+		if n, err = w.Write(p); err != nil {
+			return
+		}
+	}
+	return
+}
+func (m mwc) Close() error {
+	for _, w := range m {
+		if err := w.Close(); err != nil {
+			return err
+		}
+	}
+	return nil
+}
diff --git a/log_test.go b/log_test.go
new file mode 100644
index 0000000..06764d6
--- /dev/null
+++ b/log_test.go
@@ -0,0 +1,104 @@
+package log
+
+import (
+	"io/ioutil"
+	"os"
+	"regexp"
+	"testing"
+)
+
+func mustNewFile(t *testing.T) (string, *Logger) {
+	f, err := ioutil.TempFile("", "log_test-")
+	if err != nil {
+		t.Fatalf("failed to create temp file: %v", err)
+	}
+
+	l, err := NewFile(f.Name())
+	if err != nil {
+		t.Fatalf("failed to open new log file: %v", err)
+	}
+
+	return f.Name(), l
+}
+
+func checkContentsMatch(t *testing.T, name, path, expected string) {
+	content, err := ioutil.ReadFile(path)
+	if err != nil {
+		panic(err)
+	}
+
+	got := string(content)
+	if !regexp.MustCompile(expected).Match(content) {
+		t.Errorf("%s: regexp %q did not match %q",
+			name, expected, got)
+	}
+}
+
+func testLogger(t *testing.T, fname string, l *Logger) {
+	l.LogTime = false
+	l.Infof("message %d", 1)
+	checkContentsMatch(t, "info-no-time", fname,
+		"^_ log_test.go:....   message 1\n")
+
+	os.Truncate(fname, 0)
+	l.Infof("message %d\n", 1)
+	checkContentsMatch(t, "info-with-newline", fname,
+		"^_ log_test.go:....   message 1\n")
+
+	os.Truncate(fname, 0)
+	l.LogTime = true
+	l.Infof("message %d", 1)
+	checkContentsMatch(t, "info-with-time", fname,
+		`^\d{8} ..:..:..\.\d{6} _ log_test.go:....   message 1\n`)
+
+	os.Truncate(fname, 0)
+	l.LogTime = false
+	l.Errorf("error %d", 1)
+	checkContentsMatch(t, "error", fname, `^E log_test.go:....   error 1\n`)
+
+	if l.V(Debug) {
+		t.Fatalf("Debug level enabled by default (level: %v)", l.Level)
+	}
+
+	os.Truncate(fname, 0)
+	l.LogTime = false
+	l.Debugf("debug %d", 1)
+	checkContentsMatch(t, "debug-no-log", fname, `^$`)
+
+	os.Truncate(fname, 0)
+	l.Level = Debug
+	l.Debugf("debug %d", 1)
+	checkContentsMatch(t, "debug", fname, `^\. log_test.go:....   debug 1\n`)
+
+	if !l.V(Debug) {
+		t.Errorf("l.Level = Debug, but V(Debug) = false")
+	}
+
+	os.Truncate(fname, 0)
+	l.Level = Info
+	l.Log(Debug, 0, "log debug %d", 1)
+	l.Log(Info, 0, "log info %d", 1)
+	checkContentsMatch(t, "log", fname,
+		`^_ log_test.go:....   log info 1\n`)
+
+}
+
+func TestBasic(t *testing.T) {
+	fname, l := mustNewFile(t)
+	defer l.Close()
+	defer os.Remove(fname)
+
+	testLogger(t, fname, l)
+}
+
+func TestDefaultFile(t *testing.T) {
+	fname, l := mustNewFile(t)
+	l.Close()
+	defer os.Remove(fname)
+
+	*logFile = fname
+
+	Init()
+
+	testLogger(t, fname, Default)
+}