author | Alberto Bertogli
<albertito@blitiri.com.ar> 2016-10-24 02:02:11 UTC |
committer | Alberto Bertogli
<albertito@blitiri.com.ar> 2016-11-01 23:56:04 UTC |
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) +}