Redesign logging for v2

always_new_file_writer.go

@@ -2,14 +2,20 @@ package log
 
 import (
 	"fmt"
+	"io/ioutil"
 	"os"
 	"path"
+	"path/filepath"
+	"sort"
+	"strings"
 	"time"
 )
 
 // AlwaysNewFileWriter create new log for every process
 type AlwaysNewFileWriter struct {
-	Name string
+	Name     string
+	MaxCount int
+
 	file *os.File
 }
 
@@ -38,5 +44,38 @@ func (w *AlwaysNewFileWriter) openFile() (err error) {
 		return err
 	}
 
+	if w.MaxCount > 0 {
+		go w.cleanFiles()
+	}
+
 	return nil
 }
+
+// clean old files
+func (w *AlwaysNewFileWriter) cleanFiles() {
+	dir := path.Dir(w.Name)
+
+	fileList, err := ioutil.ReadDir(dir)
+	if err != nil {
+		return
+	}
+
+	prefix := path.Base(w.Name) + "."
+
+	var matches []string
+	for _, f := range fileList {
+		if !f.IsDir() && strings.HasPrefix(f.Name(), prefix) {
+			matches = append(matches, f.Name())
+		}
+	}
+
+	if len(matches) > w.MaxCount {
+		sort.Sort(sort.Reverse(sort.StringSlice(matches)))
+		fmt.Println(matches)
+
+		for _, f := range matches[w.MaxCount:] {
+			file := filepath.Join(dir, f)
+			os.Remove(file)
+		}
+	}
+}

always_new_file_writer_test.go

@@ -1,16 +0,0 @@
-package log
-
-import (
-	"testing"
-)
-
-func TestAlwaysNewFileWriter(t *testing.T) {
-	log := New(&AlwaysNewFileWriter{
-		Name: "/tmp/test.log",
-	})
-	log.SetTimeLayout("15:04:05.999")
-	log.SetName("main")
-	for i := 0; i < 100; i++ {
-		log.Info("i = %d", i)
-	}
-}

composite_writers.go

@@ -1,14 +0,0 @@
-package log
-
-import (
-	"io"
-)
-
-type CompositeWriters []io.Writer
-
-func (ws *CompositeWriters) Write(p []byte) (n int, err error) {
-	for _, w := range *ws {
-		n, err = w.Write(p)
-	}
-	return
-}

composite_writers_test.go

@@ -1,20 +0,0 @@
-package log
-
-import (
-	"os"
-	"testing"
-)
-
-func TestCompositeWriters(t *testing.T) {
-	log := New(&CompositeWriters{
-		os.Stdout,
-		&DailyFileWriter{
-			Name: "/tmp/test.log",
-		},
-	})
-	log.SetTimeLayout("15:04:05.999")
-	log.SetName("main")
-	for i := 0; i < 5; i++ {
-		log.Info("i = %d", i)
-	}
-}

daily_file_writer.go

@@ -2,14 +2,20 @@ package log
 
 import (
 	"fmt"
+	"io/ioutil"
 	"os"
 	"path"
+	"path/filepath"
+	"sort"
+	"strings"
 	"time"
 )
 
 // DailyFileWriter create new log for every day
 type DailyFileWriter struct {
-	Name        string
+	Name     string
+	MaxCount int
+
 	file        *os.File
 	nextDayTime int64
 }
@@ -28,7 +34,7 @@ func (w *DailyFileWriter) Write(p []byte) (n int, err error) {
 }
 
 func (w *DailyFileWriter) openFile(now *time.Time) (err error) {
-	name := fmt.Sprintf("%s.%s", w.Name, now.Format("2006-01-02"))
+	name := fmt.Sprintf("%s.%s", w.Name, now.Format("20060102"))
 
 	// remove symbol link if exist
 	os.Remove(w.Name)
@@ -47,5 +53,37 @@ func (w *DailyFileWriter) openFile(now *time.Time) (err error) {
 	year, month, day := now.Date()
 	w.nextDayTime = time.Date(year, month, day+1, 0, 0, 0, 0, now.Location()).Unix()
 
+	if w.MaxCount > 0 {
+		go w.cleanFiles()
+	}
+
 	return nil
 }
+
+// clean old files
+func (w *DailyFileWriter) cleanFiles() {
+	dir := path.Dir(w.Name)
+
+	fileList, err := ioutil.ReadDir(dir)
+	if err != nil {
+		return
+	}
+
+	prefix := path.Base(w.Name) + "."
+
+	var matches []string
+	for _, f := range fileList {
+		if !f.IsDir() && strings.HasPrefix(f.Name(), prefix) {
+			matches = append(matches, f.Name())
+		}
+	}
+
+	if len(matches) > w.MaxCount {
+		sort.Sort(sort.Reverse(sort.StringSlice(matches)))
+
+		for _, f := range matches[w.MaxCount:] {
+			file := filepath.Join(dir, f)
+			os.Remove(file)
+		}
+	}
+}

daily_file_writer_test.go

@@ -1,16 +0,0 @@
-package log
-
-import (
-	"testing"
-)
-
-func TestDailyFileWriter(t *testing.T) {
-	log := New(&DailyFileWriter{
-		Name: "/tmp/test.log",
-	})
-	log.SetTimeLayout("15:04:05.999")
-	log.SetName("main")
-	for i := 0; i < 100; i++ {
-		log.Info("i = %d", i)
-	}
-}

doc.go

@@ -1,2 +0,0 @@
-// Logging package similar to log4j for the Golang.
-package log

example_test.go

@@ -0,0 +1,40 @@
+package log_test
+
+import (
+	"github.com/subchen/go-log"
+	"os"
+)
+
+func ExampleNew() {
+	logger := log.New(os.Stdout)
+	logger.SetAppName("app")
+	logger.SetFlags(log.DEFAULT_FLAGS | log.F_GID)
+
+	logger.Info("testing ...")
+	logger.Errorf("err = %v", os.ErrInvalid)
+	// Outputs:
+	// 2001-10-10 12:00:00,000 1234 app 987 INFO main.go:13 testing ...
+	// 2001-10-10 12:00:00,000 1234 app 987 ERROR main.go:14 err = invalid argument
+}
+
+func ExampleAlwaysNewFileWriter() {
+	log.SetWriter(&log.AlwaysNewFileWriter{
+		Name:     "/tmp/test.log",
+		MaxCount: 10,
+	})
+}
+
+func ExampleDailyFileWriter() {
+	log.SetWriter(&log.DailyFileWriter{
+		Name:     "/tmp/test.log",
+		MaxCount: 10,
+	})
+}
+
+func ExampleFixedSizeFileWriter() {
+	log.SetWriter(&log.FixedSizeFileWriter{
+		Name:     "/tmp/test.log",
+		MaxSize:  10 * 1024 * 1024, // 10M
+		MaxCount: 10,
+	})
+}

fixed_size_file_writer_test.go

@@ -1,18 +0,0 @@
-package log
-
-import (
-	"testing"
-)
-
-func TestFixedSizeFileWriter(t *testing.T) {
-	log := New(&FixedSizeFileWriter{
-		Name:     "/tmp/test.log",
-		MaxSize:  1024 * 3,
-		MaxCount: 5,
-	})
-	log.SetTimeLayout("15:04:05.999")
-	log.SetName("main")
-	for i := 0; i < 100; i++ {
-		log.Info("i = %d", i)
-	}
-}

log.go

@@ -1,12 +1,21 @@
+// Package log implements a common logging like log4j.
 package log
 
 import (
 	"io"
 	"os"
+
+	"github.com/mattn/go-isatty"
 )
 
 // std is a default logger for console
-var std = New(os.Stdout).EnableColorizedLevel(true).SkipCaller(3)
+var std = New(os.Stdout).SkipCaller(3)
+
+func init() {
+	if isatty.IsTerminal(os.Stdout.Fd()) {
+		std.SetFlags(DEFAULT_FLAGS | F_COLOR)
+	}
+}
 
 // Get log level
 func GetLevel() int {
@@ -18,29 +27,44 @@ func SetLevel(level int) {
 	std.SetLevel(level)
 }
 
-// Set a name to indicate a process
+// Get log level name
-func SetName(name string) {
+func GetLevelName() string {
-	std.SetName(name)
+	return std.GetLevelName()
+}
+
+// Set log level name
+func SetLevelName(level string) {
+	std.SetLevelName(level)
+}
+
+// Get the flags for output format
+func GetFlags() int {
+	return std.GetFlags()
+}
+
+// Set flags for output format
+func SetFlags(flags int) {
+	std.SetFlags(flags)
 }
 
-// Set time layout for log line
+// Get the process name
-func SetTimeLayout(layout string) {
+func GetAppName() string {
-	std.SetTimeLayout(layout)
+	return std.GetAppName()
 }
 
-// EnableGoroutineId output goroutinue id
+// Set a process name
-func EnableGoroutineId(enable bool) {
+func SetAppName(name string) {
-	std.EnableGoroutineId(enable)
+	std.SetAppName(name)
 }
 
-// EnableLongFileFormat output long file name
+// Get time format for log line
-func EnableLongFileFormat(enable bool) {
+func GetTimeFormat() string {
-	std.EnableLongFileFormat(enable)
+	return std.GetTimeFormat()
 }
 
-// EnableColorizedLevel output colorized level
+// Set time format for log line
-func EnableColorizedLevel(enable bool) {
+func SetTimeFormat(format string) {
-	std.EnableColorizedLevel(enable)
+	std.SetTimeFormat(format)
 }
 
 // Set a writer
@@ -68,27 +92,52 @@ func IsErrorEnabled() bool {
 	return std.IsErrorEnabled()
 }
 
-// Output an debug message
+// Output a debug message
-func Debug(msg string, args ...interface{}) {
+func Debug(obj ...interface{}) {
-	std.Debug(msg, args...)
+	std.Debug(obj...)
+}
+
+// Output an info message
+func Info(obj ...interface{}) {
+	std.Info(obj...)
+}
+
+// Output a warning message
+func Warn(obj ...interface{}) {
+	std.Warn(obj...)
+}
+
+// Output an error message
+func Error(obj ...interface{}) {
+	std.Error(obj...)
+}
+
+// Output a fatal message with full stack
+func Fatal(obj ...interface{}) {
+	std.Fatal(obj...)
+}
+
+// Output a debug message
+func Debugf(msg string, args ...interface{}) {
+	std.Debugf(msg, args...)
 }
 
 // Output an info message
-func Info(msg string, args ...interface{}) {
+func Infof(msg string, args ...interface{}) {
-	std.Info(msg, args...)
+	std.Infof(msg, args...)
 }
 
 // Output a warning message
-func Warn(msg string, args ...interface{}) {
+func Warnf(msg string, args ...interface{}) {
-	std.Warn(msg, args...)
+	std.Warnf(msg, args...)
 }
 
 // Output an error message
-func Error(msg string, args ...interface{}) {
+func Errorf(msg string, args ...interface{}) {
-	std.Error(msg, args)
+	std.Errorf(msg, args...)
 }
 
 // Output a fatal message with full stack
-func Fatal(msg string, args ...interface{}) {
+func Fatalf(msg string, args ...interface{}) {
-	std.Fatal(msg, args)
+	std.Fatalf(msg, args...)
 }

logger.go

@@ -14,13 +14,27 @@ import (
 	"github.com/subchen/gstack/gls"
 )
 
-// Log Level
 const (
-	DEBUG = iota
+	// log level
-	INFO
+	L_DEBUG = iota
-	WARN
+	L_INFO
-	ERROR
+	L_WARN
-	FATAL
+	L_ERROR
+	L_FATAL
+
+	// Bits or'ed together to control what's printed.
+	F_TIME = 1 << iota
+	F_LONG_FILE
+	F_SHORT_FILE
+	F_PID
+	F_GID
+	F_COLOR
+
+	// default flags
+	DEFAULT_FLAGS = F_TIME | F_SHORT_FILE | F_PID
+
+	// default time format
+	DEFAULT_TIME_FORMAT = "2006-01-02 15:04:05,000"
 )
 
 var (
@@ -38,33 +52,35 @@ var (
 		"\033[31mERROR\033[0m",
 		"\033[35mFATAL\033[0m",
 	}
+
+	buffer = sync.Pool{
+		New: func() interface{} {
+			return new(bytes.Buffer)
+		},
+	}
 )
 
 func New(out io.Writer) *Logger {
 	return &Logger{
-		out:            out,
+		writer:     out,
-		level:          INFO,
+		level:      L_INFO,
-		pid:            os.Getpid(),
+		pid:        os.Getpid(),
-		name:           "",
+		name:       "",
-		timeLayout:     "2006-01-02 15:04:05.000",
+		timeFormat: DEFAULT_TIME_FORMAT,
-		goroutineId:    false,
+		flags:      DEFAULT_FLAGS,
-		longFileFormat: false,
+		callerSkip: 2,
-		colorizedLevel: false,
-		callerSkip:     2,
 	}
 }
 
 type Logger struct {
-	mu             sync.Mutex
+	m          sync.Mutex
-	out            io.Writer
+	writer     io.Writer
-	level          int
+	level      int
-	pid            int
+	pid        int
-	name           string
+	name       string
-	timeLayout     string
+	timeFormat string
-	goroutineId    bool
+	flags      int
-	longFileFormat bool
+	callerSkip int
-	colorizedLevel bool
-	callerSkip     int
 }
 
 func (l *Logger) GetLevel() int {
@@ -72,130 +88,205 @@ func (l *Logger) GetLevel() int {
 }
 
 func (l *Logger) SetLevel(level int) *Logger {
+	if level < L_DEBUG || level > L_FATAL {
+		panic("unknown log level")
+	}
+
+	l.m.Lock()
 	l.level = level
+	l.m.Unlock()
 	return l
 }
 
-func (l *Logger) SetName(name string) *Logger {
+func (l *Logger) GetLevelName() string {
-	l.name = name
+	return levelStr[l.level]
-	return l
 }
 
-func (l *Logger) SetTimeLayout(layout string) *Logger {
+func (l *Logger) SetLevelName(level string) {
-	l.timeLayout = layout
+	level = strings.ToUpper(level)
-	return l
+	for i, v := range levelStr {
+		if v == level {
+			l.SetLevel(i)
+			return
+		}
+	}
+
+	panic("unknown log level: " + level)
+}
+
+func (l *Logger) GetFlags() int {
+	return l.flags
 }
 
-func (l *Logger) EnableGoroutineId(enable bool) *Logger {
+func (l *Logger) SetFlags(flags int) *Logger {
-	l.goroutineId = enable
+	l.m.Lock()
+	l.flags = flags
+	l.m.Unlock()
 	return l
 }
 
-func (l *Logger) EnableLongFileFormat(enable bool) *Logger {
+func (l *Logger) GetAppName() string {
-	l.longFileFormat = enable
+	return l.name
+}
+
+func (l *Logger) SetAppName(name string) *Logger {
+	l.m.Lock()
+	l.name = name
+	l.m.Unlock()
 	return l
 }
 
-func (l *Logger) EnableColorizedLevel(enable bool) *Logger {
+func (l *Logger) GetTimeFormat() string {
-	l.colorizedLevel = enable
+	return l.timeFormat
+}
+
+func (l *Logger) SetTimeFormat(format string) *Logger {
+	l.m.Lock()
+	l.timeFormat = format
+	l.m.Unlock()
 	return l
 }
 
 func (l *Logger) SkipCaller(skip int) *Logger {
+	l.m.Lock()
+	defer l.m.Unlock()
 	l.callerSkip = skip
 	return l
 }
 
 func (l *Logger) SetWriter(w io.Writer) *Logger {
-	l.out = w
+	l.m.Lock()
+	defer l.m.Unlock()
+	l.writer = w
 	return l
 }
 
 func (l *Logger) IsDebugEnabled() bool {
-	return l.level <= DEBUG
+	return l.level <= L_DEBUG
 }
 
 func (l *Logger) IsInfoEnabled() bool {
-	return l.level <= INFO
+	return l.level <= L_INFO
 }
 
 func (l *Logger) IsWarnEnabled() bool {
-	return l.level <= WARN
+	return l.level <= L_WARN
 }
 
 func (l *Logger) IsErrorEnabled() bool {
-	return l.level <= ERROR
+	return l.level <= L_ERROR
 }
 
-func (l *Logger) Debug(msg string, args ...interface{}) {
+func (l *Logger) Debug(obj ...interface{}) {
-	if l.level <= DEBUG {
+	if l.level <= L_DEBUG {
-		l.log(DEBUG, msg, args...)
+		l.log(L_DEBUG, fmt.Sprint(obj...))
 	}
 }
 
-func (l *Logger) Info(msg string, args ...interface{}) {
+func (l *Logger) Info(obj ...interface{}) {
-	if l.level <= INFO {
+	if l.level <= L_INFO {
-		l.log(INFO, msg, args...)
+		l.log(L_INFO, fmt.Sprint(obj...))
 	}
 }
 
-func (l *Logger) Warn(msg string, args ...interface{}) {
+func (l *Logger) Warn(obj ...interface{}) {
-	if l.level <= WARN {
+	if l.level <= L_WARN {
-		l.log(WARN, msg, args...)
+		l.log(L_WARN, fmt.Sprint(obj...))
 	}
 }
 
-func (l *Logger) Error(msg string, args ...interface{}) {
+func (l *Logger) Error(obj ...interface{}) {
-	if l.level <= ERROR {
+	if l.level <= L_ERROR {
-		l.log(ERROR, msg, args...)
+		l.log(L_ERROR, fmt.Sprint(obj...))
 	}
 }
 
-func (l *Logger) Fatal(msg string, args ...interface{}) {
+func (l *Logger) Fatal(obj ...interface{}) {
-	l.log(FATAL, msg, args...)
+	if l.level <= L_FATAL {
+		l.log(L_FATAL, fmt.Sprint(obj...))
+	}
 }
 
-func (l *Logger) log(level int, msg string, args ...interface{}) {
+func (l *Logger) Debugf(msg string, args ...interface{}) {
-	_, file, line, ok := runtime.Caller(l.callerSkip)
+	if l.level <= L_DEBUG {
-	if !ok {
+		l.log(L_DEBUG, fmt.Sprintf(msg, args...))
-		file = "???"
+	}
-		line = 0
+}
-	} else if !l.longFileFormat {
+
-		if index := strings.LastIndex(file, "/"); index >= 0 {
+func (l *Logger) Infof(msg string, args ...interface{}) {
-			file = file[index+1:]
+	if l.level <= L_INFO {
-		} else if index = strings.LastIndex(file, "\\"); index >= 0 {
+		l.log(L_INFO, fmt.Sprintf(msg, args...))
-			file = file[index+1:]
+	}
-		}
+}
+
+func (l *Logger) Warnf(msg string, args ...interface{}) {
+	if l.level <= L_WARN {
+		l.log(L_WARN, fmt.Sprintf(msg, args...))
+	}
+}
+
+func (l *Logger) Errorf(msg string, args ...interface{}) {
+	if l.level <= L_ERROR {
+		l.log(L_ERROR, fmt.Sprintf(msg, args...))
 	}
+}
+
+func (l *Logger) Fatalf(msg string, args ...interface{}) {
+	l.log(L_FATAL, fmt.Sprintf(msg, args...))
+}
 
+func (l *Logger) log(level int, msg string) {
 	// output format: DATE PID [NAME] [GID] LEVEL file:line message
 	// 2001-10-10 12:00:00,000+0800 1234 app 987 INFO main.go:1234 log message ...
-	buf := new(bytes.Buffer)
+
-	buf.WriteByte(' ')
+	buf := buffer.Get().(*bytes.Buffer)
-	buf.WriteString(strconv.Itoa(l.pid))
+	defer buffer.Put(buf)
-	buf.WriteByte(' ')
+
+	if l.flags&F_TIME != 0 {
+		timeStr := time.Now().Format(l.timeFormat)
+		buf.WriteString(timeStr)
+		buf.WriteByte(' ')
+	}
+	if l.flags&F_PID != 0 {
+		buf.WriteString(strconv.Itoa(l.pid))
+		buf.WriteByte(' ')
+	}
 	if l.name != "" {
 		buf.WriteString(l.name)
 		buf.WriteByte(' ')
 	}
-	if l.goroutineId || l.level == DEBUG {
+	if l.flags&F_GID != 0 {
 		buf.WriteString(strconv.FormatUint(gls.GoroutineID(), 10))
 		buf.WriteByte(' ')
 	}
-	if l.colorizedLevel {
+	if l.flags&F_COLOR != 0 {
 		buf.WriteString(levelStrWithColor[level])
 	} else {
 		buf.WriteString(levelStr[level])
 	}
 	buf.WriteByte(' ')
-	buf.WriteString(file)
+
-	buf.WriteByte(':')
+	if l.flags&(F_LONG_FILE|F_SHORT_FILE) != 0 {
-	buf.WriteString(strconv.Itoa(line))
+		_, file, line, ok := runtime.Caller(l.callerSkip)
-	buf.WriteByte(' ')
+		if !ok {
-	fmt.Fprintf(buf, msg, args...)
+			file = "???"
+			line = 0
+		} else if l.flags&F_SHORT_FILE != 0 {
+			if index := strings.LastIndex(file, "/"); index >= 0 {
+				file = file[index+1:]
+			} else if index = strings.LastIndex(file, "\\"); index >= 0 {
+				file = file[index+1:]
+			}
+		}
+		buf.WriteString(file)
+		buf.WriteByte(':')
+		buf.WriteString(strconv.Itoa(line))
+		buf.WriteByte(' ')
+	}
+	buf.WriteString(msg)
 	buf.WriteByte('\n')
 
-	if level == FATAL {
+	if level == L_FATAL {
 		for i := l.callerSkip; ; i++ {
 			pc, file, line, ok := runtime.Caller(i)
 			if !ok {
@@ -205,11 +296,11 @@ func (l *Logger) log(level int, msg string, args ...interface{}) {
 		}
 	}
 
-	l.mu.Lock()
+	line := buf.Bytes()
-	defer l.mu.Unlock()
+	buf.Reset()
 
-	timeStr := time.Now().Format(l.timeLayout)
+	l.m.Lock()
+	defer l.m.Unlock()
 
-	l.out.Write([]byte(timeStr))
+	l.writer.Write(line)
-	l.out.Write(buf.Bytes())
 }

logger_test.go

@@ -2,33 +2,38 @@ package log
 
 import (
 	"os"
+	"sync"
 	"testing"
-	"time"
 )
 
 func TestLogger(t *testing.T) {
 	stdout := New(os.Stdout)
-	stdout.SetTimeLayout("15:04:05.999")
+	stdout.SetTimeFormat("15:04:05.999")
-	stdout.SetName("main")
+	stdout.SetAppName("main")
-	stdout.SetLevel(DEBUG)
+	stdout.SetLevel(L_DEBUG)
-	stdout.EnableColorizedLevel(true)
+	stdout.SetFlags(DEFAULT_FLAGS | F_GID | F_COLOR)
-	stdout.EnableGoroutineId(true)
+
+	wg := sync.WaitGroup{}
 	for i := 0; i < 3; i++ {
+		wg.Add(1)
 		go func(i int) {
-			stdout.Debug("i = %d", i)
+			stdout.Debugf("i = %d", i)
-			stdout.Info("i = %d", i)
+			stdout.Infof("i = %d", i)
+			wg.Done()
 		}(i)
 	}
 	for i := 0; i < 3; i++ {
+		wg.Add(1)
 		go func(i int) {
-			stdout.Debug("i = %d", i)
+			stdout.Debugf("i = %d", i)
-			stdout.Info("i = %d", i)
+			stdout.Infof("i = %d", i)
+			wg.Done()
 		}(i)
 	}
 
-	stdout.Warn("warning")
+	wg.Wait()
+
+	stdout.Warn("warning", "message")
 	stdout.Error("error")
 	stdout.Fatal("fatal")
-
-	time.Sleep(1 * time.Second)
 }