Create & Init Project...

library/log/internal/filewriter/BUILD

@@ -0,0 +1,40 @@
+package(default_visibility = ["//visibility:public"])
+
+load(
+    "@io_bazel_rules_go//go:def.bzl",
+    "go_test",
+    "go_library",
+)
+
+go_test(
+    name = "go_default_test",
+    srcs = ["filewriter_test.go"],
+    embed = [":go_default_library"],
+    tags = ["automanaged"],
+    deps = ["//vendor/github.com/stretchr/testify/assert:go_default_library"],
+)
+
+go_library(
+    name = "go_default_library",
+    srcs = [
+        "filewriter.go",
+        "option.go",
+    ],
+    importpath = "go-common/library/log/internal/filewriter",
+    tags = ["automanaged"],
+    visibility = ["//visibility:public"],
+)
+
+filegroup(
+    name = "package-srcs",
+    srcs = glob(["**"]),
+    tags = ["automanaged"],
+    visibility = ["//visibility:private"],
+)
+
+filegroup(
+    name = "all-srcs",
+    srcs = [":package-srcs"],
+    tags = ["automanaged"],
+    visibility = ["//visibility:public"],
+)

library/log/internal/filewriter/filewriter.go

@@ -0,0 +1,344 @@
+package filewriter
+
+import (
+	"bytes"
+	"container/list"
+	"fmt"
+	"io/ioutil"
+	"log"
+	"os"
+	"path/filepath"
+	"sort"
+	"strconv"
+	"strings"
+	"sync"
+	"sync/atomic"
+	"time"
+)
+
+// FileWriter create file log writer
+type FileWriter struct {
+	opt    option
+	dir    string
+	fname  string
+	ch     chan *bytes.Buffer
+	stdlog *log.Logger
+	pool   *sync.Pool
+
+	lastRotateFormat string
+	lastSplitNum     int
+
+	current *wrapFile
+	files   *list.List
+
+	closed int32
+	wg     sync.WaitGroup
+}
+
+type rotateItem struct {
+	rotateTime int64
+	rotateNum  int
+	fname      string
+}
+
+func parseRotateItem(dir, fname, rotateFormat string) (*list.List, error) {
+	fis, err := ioutil.ReadDir(dir)
+	if err != nil {
+		return nil, err
+	}
+
+	// parse exists log file filename
+	parse := func(s string) (rt rotateItem, err error) {
+		// remove filename and left "." error.log.2018-09-12.001 -> 2018-09-12.001
+		rt.fname = s
+		s = strings.TrimLeft(s[len(fname):], ".")
+		seqs := strings.Split(s, ".")
+		var t time.Time
+		switch len(seqs) {
+		case 2:
+			if rt.rotateNum, err = strconv.Atoi(seqs[1]); err != nil {
+				return
+			}
+			fallthrough
+		case 1:
+			if t, err = time.Parse(rotateFormat, seqs[0]); err != nil {
+				return
+			}
+			rt.rotateTime = t.Unix()
+		}
+		return
+	}
+
+	var items []rotateItem
+	for _, fi := range fis {
+		if strings.HasPrefix(fi.Name(), fname) && fi.Name() != fname {
+			rt, err := parse(fi.Name())
+			if err != nil {
+				// TODO deal with error
+				continue
+			}
+			items = append(items, rt)
+		}
+	}
+	sort.Slice(items, func(i, j int) bool {
+		if items[i].rotateTime == items[j].rotateTime {
+			return items[i].rotateNum > items[j].rotateNum
+		}
+		return items[i].rotateTime > items[j].rotateTime
+	})
+	l := list.New()
+
+	for _, item := range items {
+		l.PushBack(item)
+	}
+	return l, nil
+}
+
+type wrapFile struct {
+	fsize int64
+	fp    *os.File
+}
+
+func (w *wrapFile) size() int64 {
+	return w.fsize
+}
+
+func (w *wrapFile) write(p []byte) (n int, err error) {
+	n, err = w.fp.Write(p)
+	w.fsize += int64(n)
+	return
+}
+
+func newWrapFile(fpath string) (*wrapFile, error) {
+	fp, err := os.OpenFile(fpath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
+	if err != nil {
+		return nil, err
+	}
+	fi, err := fp.Stat()
+	if err != nil {
+		return nil, err
+	}
+	return &wrapFile{fp: fp, fsize: fi.Size()}, nil
+}
+
+// New FileWriter A FileWriter is safe for use by multiple goroutines simultaneously.
+func New(fpath string, fns ...Option) (*FileWriter, error) {
+	opt := defaultOption
+	for _, fn := range fns {
+		fn(&opt)
+	}
+
+	fname := filepath.Base(fpath)
+	if fname == "" {
+		return nil, fmt.Errorf("filename can't empty")
+	}
+	dir := filepath.Dir(fpath)
+	fi, err := os.Stat(dir)
+	if err == nil && !fi.IsDir() {
+		return nil, fmt.Errorf("%s already exists and not a directory", dir)
+	}
+	if os.IsNotExist(err) {
+		if err = os.MkdirAll(dir, 0755); err != nil {
+			return nil, fmt.Errorf("create dir %s error: %s", dir, err.Error())
+		}
+	}
+
+	current, err := newWrapFile(fpath)
+	if err != nil {
+		return nil, err
+	}
+
+	stdlog := log.New(os.Stderr, "flog ", log.LstdFlags)
+	ch := make(chan *bytes.Buffer, opt.ChanSize)
+
+	files, err := parseRotateItem(dir, fname, opt.RotateFormat)
+	if err != nil {
+		// set files a empty list
+		files = list.New()
+		stdlog.Printf("parseRotateItem error: %s", err)
+	}
+
+	lastRotateFormat := time.Now().Format(opt.RotateFormat)
+	var lastSplitNum int
+	if files.Len() > 0 {
+		rt := files.Front().Value.(rotateItem)
+		//  check contains is mush esay than compared with timestamp
+		if strings.Contains(rt.fname, lastRotateFormat) {
+			lastSplitNum = rt.rotateNum
+		}
+	}
+
+	fw := &FileWriter{
+		opt:    opt,
+		dir:    dir,
+		fname:  fname,
+		stdlog: stdlog,
+		ch:     ch,
+		pool:   &sync.Pool{New: func() interface{} { return new(bytes.Buffer) }},
+
+		lastSplitNum:     lastSplitNum,
+		lastRotateFormat: lastRotateFormat,
+
+		files:   files,
+		current: current,
+	}
+
+	fw.wg.Add(1)
+	go fw.daemon()
+
+	return fw, nil
+}
+
+// Write write data to log file, return write bytes is pseudo just for implement io.Writer.
+func (f *FileWriter) Write(p []byte) (int, error) {
+	// atomic is not necessary
+	if atomic.LoadInt32(&f.closed) == 1 {
+		f.stdlog.Printf("%s", p)
+		return 0, fmt.Errorf("filewriter already closed")
+	}
+	// because write to file is asynchronousc,
+	// copy p to internal buf prevent p be change on outside
+	buf := f.getBuf()
+	buf.Write(p)
+
+	if f.opt.WriteTimeout == 0 {
+		select {
+		case f.ch <- buf:
+			return len(p), nil
+		default:
+			// TODO: write discard log to to stdout?
+			return 0, fmt.Errorf("log channel is full, discard log")
+		}
+	}
+
+	// write log with timeout
+	timeout := time.NewTimer(f.opt.WriteTimeout)
+	select {
+	case f.ch <- buf:
+		return len(p), nil
+	case <-timeout.C:
+		// TODO: write discard log to to stdout?
+		return 0, fmt.Errorf("log channel is full, discard log")
+	}
+}
+
+func (f *FileWriter) daemon() {
+	// TODO: check aggsbuf size prevent it too big
+	aggsbuf := &bytes.Buffer{}
+	tk := time.NewTicker(f.opt.RotateInterval)
+	// TODO: make it configrable
+	aggstk := time.NewTicker(10 * time.Millisecond)
+	var err error
+	for {
+		select {
+		case t := <-tk.C:
+			f.checkRotate(t)
+		case buf, ok := <-f.ch:
+			if ok {
+				aggsbuf.Write(buf.Bytes())
+				f.putBuf(buf)
+			}
+		case <-aggstk.C:
+			if aggsbuf.Len() > 0 {
+				if err = f.write(aggsbuf.Bytes()); err != nil {
+					f.stdlog.Printf("write log error: %s", err)
+				}
+				aggsbuf.Reset()
+			}
+		}
+		if atomic.LoadInt32(&f.closed) != 1 {
+			continue
+		}
+		// read all buf from channel and break loop
+		if err = f.write(aggsbuf.Bytes()); err != nil {
+			f.stdlog.Printf("write log error: %s", err)
+		}
+		for buf := range f.ch {
+			if err = f.write(buf.Bytes()); err != nil {
+				f.stdlog.Printf("write log error: %s", err)
+			}
+			f.putBuf(buf)
+		}
+		break
+	}
+	f.wg.Done()
+}
+
+// Close close file writer
+func (f *FileWriter) Close() error {
+	atomic.StoreInt32(&f.closed, 1)
+	close(f.ch)
+	f.wg.Wait()
+	return nil
+}
+
+func (f *FileWriter) checkRotate(t time.Time) {
+	formatFname := func(format string, num int) string {
+		if num == 0 {
+			return fmt.Sprintf("%s.%s", f.fname, format)
+		}
+		return fmt.Sprintf("%s.%s.%03d", f.fname, format, num)
+	}
+	format := t.Format(f.opt.RotateFormat)
+
+	if f.opt.MaxFile != 0 {
+		for f.files.Len() > f.opt.MaxFile {
+			rt := f.files.Remove(f.files.Front()).(rotateItem)
+			fpath := filepath.Join(f.dir, rt.fname)
+			if err := os.Remove(fpath); err != nil {
+				f.stdlog.Printf("remove file %s error: %s", fpath, err)
+			}
+		}
+	}
+
+	if format != f.lastRotateFormat || (f.opt.MaxSize != 0 && f.current.size() > f.opt.MaxSize) {
+		var err error
+		// close current file first
+		if err = f.current.fp.Close(); err != nil {
+			f.stdlog.Printf("close current file error: %s", err)
+		}
+
+		// rename file
+		fname := formatFname(f.lastRotateFormat, f.lastSplitNum)
+		oldpath := filepath.Join(f.dir, f.fname)
+		newpath := filepath.Join(f.dir, fname)
+		if err = os.Rename(oldpath, newpath); err != nil {
+			f.stdlog.Printf("rename file %s to %s error: %s", oldpath, newpath, err)
+			return
+		}
+
+		f.files.PushBack(rotateItem{fname: fname /*rotateNum: f.lastSplitNum, rotateTime: t.Unix() unnecessary*/})
+
+		if format != f.lastRotateFormat {
+			f.lastRotateFormat = format
+			f.lastSplitNum = 0
+		} else {
+			f.lastSplitNum++
+		}
+
+		// recreate current file
+		f.current, err = newWrapFile(filepath.Join(f.dir, f.fname))
+		if err != nil {
+			f.stdlog.Printf("create log file error: %s", err)
+		}
+	}
+}
+
+func (f *FileWriter) write(p []byte) error {
+	// f.current may be nil, if newWrapFile return err in checkRotate, redirect log to stderr
+	if f.current == nil {
+		f.stdlog.Printf("can't write log to file, please check stderr log for detail")
+		f.stdlog.Printf("%s", p)
+	}
+	_, err := f.current.write(p)
+	return err
+}
+
+func (f *FileWriter) putBuf(buf *bytes.Buffer) {
+	buf.Reset()
+	f.pool.Put(buf)
+}
+
+func (f *FileWriter) getBuf() *bytes.Buffer {
+	return f.pool.Get().(*bytes.Buffer)
+}

library/log/internal/filewriter/filewriter_test.go

@@ -0,0 +1,221 @@
+package filewriter
+
+import (
+	"fmt"
+	"io/ioutil"
+	"os"
+	"path/filepath"
+	"testing"
+	"time"
+
+	"github.com/stretchr/testify/assert"
+)
+
+const logdir = "testlog"
+
+func touch(dir, name string) {
+	os.MkdirAll(dir, 0755)
+	fp, err := os.OpenFile(filepath.Join(dir, name), os.O_CREATE, 0644)
+	if err != nil {
+		panic(err)
+	}
+	fp.Close()
+}
+
+func TestMain(m *testing.M) {
+	ret := m.Run()
+	os.RemoveAll(logdir)
+	os.Exit(ret)
+}
+
+func TestParseRotate(t *testing.T) {
+	touch := func(dir, name string) {
+		os.MkdirAll(dir, 0755)
+		fp, err := os.OpenFile(filepath.Join(dir, name), os.O_CREATE, 0644)
+		if err != nil {
+			t.Fatal(err)
+		}
+		fp.Close()
+	}
+	dir := filepath.Join(logdir, "test-parse-rotate")
+	names := []string{"info.log.2018-11-11", "info.log.2018-11-11.001", "info.log.2018-11-11.002", "info.log." + time.Now().Format("2006-01-02") + ".005"}
+	for _, name := range names {
+		touch(dir, name)
+	}
+	l, err := parseRotateItem(dir, "info.log", "2006-01-02")
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	assert.Equal(t, len(names), l.Len())
+
+	rt := l.Front().Value.(rotateItem)
+
+	assert.Equal(t, 5, rt.rotateNum)
+}
+
+func TestRotateExists(t *testing.T) {
+	dir := filepath.Join(logdir, "test-rotate-exists")
+	names := []string{"info.log." + time.Now().Format("2006-01-02") + ".005"}
+	for _, name := range names {
+		touch(dir, name)
+	}
+	fw, err := New(logdir+"/test-rotate-exists/info.log",
+		MaxSize(1024*1024),
+		func(opt *option) { opt.RotateInterval = time.Millisecond },
+	)
+	if err != nil {
+		t.Fatal(err)
+	}
+	data := make([]byte, 1024)
+	for i := range data {
+		data[i] = byte(i)
+	}
+	for i := 0; i < 10; i++ {
+		for i := 0; i < 1024; i++ {
+			_, err = fw.Write(data)
+			if err != nil {
+				t.Error(err)
+			}
+		}
+		time.Sleep(10 * time.Millisecond)
+	}
+	fw.Close()
+	fis, err := ioutil.ReadDir(logdir + "/test-rotate-exists")
+	if err != nil {
+		t.Fatal(err)
+	}
+	var fnams []string
+	for _, fi := range fis {
+		fnams = append(fnams, fi.Name())
+	}
+	assert.Contains(t, fnams, "info.log."+time.Now().Format("2006-01-02")+".006")
+}
+
+func TestSizeRotate(t *testing.T) {
+	fw, err := New(logdir+"/test-rotate/info.log",
+		MaxSize(1024*1024),
+		func(opt *option) { opt.RotateInterval = 1 * time.Millisecond },
+	)
+	if err != nil {
+		t.Fatal(err)
+	}
+	data := make([]byte, 1024)
+	for i := range data {
+		data[i] = byte(i)
+	}
+	for i := 0; i < 10; i++ {
+		for i := 0; i < 1024; i++ {
+			_, err = fw.Write(data)
+			if err != nil {
+				t.Error(err)
+			}
+		}
+		time.Sleep(10 * time.Millisecond)
+	}
+	fw.Close()
+	fis, err := ioutil.ReadDir(logdir + "/test-rotate")
+	if err != nil {
+		t.Fatal(err)
+	}
+	assert.True(t, len(fis) > 5, "expect more than 5 file get %d", len(fis))
+}
+
+func TestMaxFile(t *testing.T) {
+	fw, err := New(logdir+"/test-maxfile/info.log",
+		MaxSize(1024*1024),
+		MaxFile(1),
+		func(opt *option) { opt.RotateInterval = 1 * time.Millisecond },
+	)
+	if err != nil {
+		t.Fatal(err)
+	}
+	data := make([]byte, 1024)
+	for i := range data {
+		data[i] = byte(i)
+	}
+	for i := 0; i < 10; i++ {
+		for i := 0; i < 1024; i++ {
+			_, err = fw.Write(data)
+			if err != nil {
+				t.Error(err)
+			}
+		}
+		time.Sleep(10 * time.Millisecond)
+	}
+	fw.Close()
+	fis, err := ioutil.ReadDir(logdir + "/test-maxfile")
+	if err != nil {
+		t.Fatal(err)
+	}
+	assert.True(t, len(fis) <= 2, fmt.Sprintf("expect 2 file get %d", len(fis)))
+}
+
+func TestMaxFile2(t *testing.T) {
+	files := []string{
+		"info.log.2018-12-01",
+		"info.log.2018-12-02",
+		"info.log.2018-12-03",
+		"info.log.2018-12-04",
+		"info.log.2018-12-05",
+		"info.log.2018-12-05.001",
+	}
+	for _, file := range files {
+		touch(logdir+"/test-maxfile2", file)
+	}
+	fw, err := New(logdir+"/test-maxfile2/info.log",
+		MaxSize(1024*1024),
+		MaxFile(3),
+		func(opt *option) { opt.RotateInterval = 1 * time.Millisecond },
+	)
+	if err != nil {
+		t.Fatal(err)
+	}
+	data := make([]byte, 1024)
+	for i := range data {
+		data[i] = byte(i)
+	}
+	for i := 0; i < 10; i++ {
+		for i := 0; i < 1024; i++ {
+			_, err = fw.Write(data)
+			if err != nil {
+				t.Error(err)
+			}
+		}
+		time.Sleep(10 * time.Millisecond)
+	}
+	fw.Close()
+	fis, err := ioutil.ReadDir(logdir + "/test-maxfile2")
+	if err != nil {
+		t.Fatal(err)
+	}
+	assert.True(t, len(fis) == 4, fmt.Sprintf("expect 4 file get %d", len(fis)))
+}
+
+func TestFileWriter(t *testing.T) {
+	fw, err := New("testlog/info.log")
+	if err != nil {
+		t.Fatal(err)
+	}
+	defer fw.Close()
+	_, err = fw.Write([]byte("Hello World!\n"))
+	if err != nil {
+		t.Error(err)
+	}
+}
+
+func BenchmarkFileWriter(b *testing.B) {
+	fw, err := New("testlog/bench/info.log",
+		func(opt *option) { opt.WriteTimeout = time.Second }, MaxSize(1024*1024*8), /*32MB*/
+		func(opt *option) { opt.RotateInterval = 10 * time.Millisecond },
+	)
+	if err != nil {
+		b.Fatal(err)
+	}
+	for i := 0; i < b.N; i++ {
+		_, err = fw.Write([]byte("Hello World!\n"))
+		if err != nil {
+			b.Error(err)
+		}
+	}
+}

library/log/internal/filewriter/option.go

@@ -0,0 +1,69 @@
+package filewriter
+
+import (
+	"fmt"
+	"strings"
+	"time"
+)
+
+// RotateFormat
+const (
+	RotateDaily = "2006-01-02"
+)
+
+var defaultOption = option{
+	RotateFormat:   RotateDaily,
+	MaxSize:        1 << 30,
+	ChanSize:       1024 * 8,
+	RotateInterval: 10 * time.Second,
+}
+
+type option struct {
+	RotateFormat string
+	MaxFile      int
+	MaxSize      int64
+	ChanSize     int
+
+	// TODO export Option
+	RotateInterval time.Duration
+	WriteTimeout   time.Duration
+}
+
+// Option filewriter option
+type Option func(opt *option)
+
+// RotateFormat e.g 2006-01-02 meaning rotate log file every day.
+// NOTE: format can't contain ".", "." will cause panic ヽ(*。>Д<)o゜.
+func RotateFormat(format string) Option {
+	if strings.Contains(format, ".") {
+		panic(fmt.Sprintf("rotate format can't contain '.' format: %s", format))
+	}
+	return func(opt *option) {
+		opt.RotateFormat = format
+	}
+}
+
+// MaxFile default 999, 0 meaning unlimit.
+// TODO: don't create file list if MaxSize is unlimt.
+func MaxFile(n int) Option {
+	return func(opt *option) {
+		opt.MaxFile = n
+	}
+}
+
+// MaxSize set max size for single log file,
+// defult 1GB, 0 meaning unlimit.
+func MaxSize(n int64) Option {
+	return func(opt *option) {
+		opt.MaxSize = n
+	}
+}
+
+// ChanSize set internal chan size default 8192 use about 64k memory on x64 platfrom static,
+// because filewriter has internal object pool, change chan size bigger may cause filewriter use
+// a lot of memory, because sync.Pool can't set expire time memory won't free until program exit.
+func ChanSize(n int) Option {
+	return func(opt *option) {
+		opt.ChanSize = n
+	}
+}