switch to logrusorigin/logrus

losing filename and line number. Critical for debugging.

16 files changed, 138 insertions, 47 deletions

diff --git a/weed/util/bounded_tree/bounded_tree.go b/weed/util/bounded_tree/bounded_tree.go
index 0e8af2520..d40b82a7f 100644
--- a/weed/util/bounded_tree/bounded_tree.go
+++ b/weed/util/bounded_tree/bounded_tree.go
@@ -3,7 +3,7 @@ package bounded_tree
 import (
 	"sync"
 
-	"github.com/chrislusf/seaweedfs/weed/glog"
+	"github.com/chrislusf/seaweedfs/weed/util/log"
 	"github.com/chrislusf/seaweedfs/weed/util"
 )
 
@@ -77,7 +77,7 @@ func (t *BoundedTree) ensureVisited(n *Node, currentPath util.FullPath, componen
 
 		children, err := visitFn(filerPath)
 		if err != nil {
-			glog.V(0).Infof("failed to visit %s: %v", currentPath, err)
+			log.Infof("failed to visit %s: %v", currentPath, err)
 			return false, err
 		}
 
diff --git a/weed/util/chunk_cache/chunk_cache.go b/weed/util/chunk_cache/chunk_cache.go
index 3615aee0e..887f39c3f 100644
--- a/weed/util/chunk_cache/chunk_cache.go
+++ b/weed/util/chunk_cache/chunk_cache.go
@@ -3,7 +3,7 @@ package chunk_cache
 import (
 	"sync"
 
-	"github.com/chrislusf/seaweedfs/weed/glog"
+	"github.com/chrislusf/seaweedfs/weed/util/log"
 	"github.com/chrislusf/seaweedfs/weed/storage/needle"
 )
 
@@ -60,7 +60,7 @@ func (c *TieredChunkCache) doGetChunk(fileId string, minSize uint64) (data []byt
 
 	fid, err := needle.ParseFileIdFromString(fileId)
 	if err != nil {
-		glog.Errorf("failed to parse file id %s", fileId)
+		log.Errorf("failed to parse file id %s", fileId)
 		return nil
 	}
 
@@ -94,7 +94,7 @@ func (c *TieredChunkCache) SetChunk(fileId string, data []byte) {
 	c.Lock()
 	defer c.Unlock()
 
-	glog.V(4).Infof("SetChunk %s size %d\n", fileId, len(data))
+	log.Tracef("SetChunk %s size %d\n", fileId, len(data))
 
 	c.doSetChunk(fileId, data)
 }
@@ -107,7 +107,7 @@ func (c *TieredChunkCache) doSetChunk(fileId string, data []byte) {
 
 	fid, err := needle.ParseFileIdFromString(fileId)
 	if err != nil {
-		glog.Errorf("failed to parse file id %s", fileId)
+		log.Errorf("failed to parse file id %s", fileId)
 		return
 	}
 
diff --git a/weed/util/chunk_cache/chunk_cache_on_disk.go b/weed/util/chunk_cache/chunk_cache_on_disk.go
index 356dfe188..1ca096031 100644
--- a/weed/util/chunk_cache/chunk_cache_on_disk.go
+++ b/weed/util/chunk_cache/chunk_cache_on_disk.go
@@ -7,7 +7,7 @@ import (
 
 	"github.com/syndtr/goleveldb/leveldb/opt"
 
-	"github.com/chrislusf/seaweedfs/weed/glog"
+	"github.com/chrislusf/seaweedfs/weed/util/log"
 	"github.com/chrislusf/seaweedfs/weed/storage"
 	"github.com/chrislusf/seaweedfs/weed/storage/backend"
 	"github.com/chrislusf/seaweedfs/weed/storage/types"
@@ -63,7 +63,7 @@ func LoadOrCreateChunkCacheVolume(fileName string, preallocate int64) (*ChunkCac
 		return nil, fmt.Errorf("cannot write cache index %s.idx: %v", v.fileName, err)
 	}
 
-	glog.V(1).Infoln("loading leveldb", v.fileName+".ldb")
+	log.Debug("loading leveldb", v.fileName+".ldb")
 	opts := &opt.Options{
 		BlockCacheCapacity:            2 * 1024 * 1024, // default value is 8MiB
 		WriteBuffer:                   1 * 1024 * 1024, // default value is 4MiB
diff --git a/weed/util/chunk_cache/on_disk_cache_layer.go b/weed/util/chunk_cache/on_disk_cache_layer.go
index eebd89798..33f877d3a 100644
--- a/weed/util/chunk_cache/on_disk_cache_layer.go
+++ b/weed/util/chunk_cache/on_disk_cache_layer.go
@@ -5,7 +5,7 @@ import (
 	"path"
 	"sort"
 
-	"github.com/chrislusf/seaweedfs/weed/glog"
+	"github.com/chrislusf/seaweedfs/weed/util/log"
 	"github.com/chrislusf/seaweedfs/weed/storage"
 	"github.com/chrislusf/seaweedfs/weed/storage/types"
 )
@@ -26,7 +26,7 @@ func NewOnDiskCacheLayer(dir, namePrefix string, diskSize int64, segmentCount in
 		fileName := path.Join(dir, fmt.Sprintf("%s_%d", namePrefix, i))
 		diskCache, err := LoadOrCreateChunkCacheVolume(fileName, volumeSize)
 		if err != nil {
-			glog.Errorf("failed to add cache %s : %v", fileName, err)
+			log.Errorf("failed to add cache %s : %v", fileName, err)
 		} else {
 			c.diskCaches = append(c.diskCaches, diskCache)
 		}
@@ -45,7 +45,7 @@ func (c *OnDiskCacheLayer) setChunk(needleId types.NeedleId, data []byte) {
 	if c.diskCaches[0].fileSize+int64(len(data)) > c.diskCaches[0].sizeLimit {
 		t, resetErr := c.diskCaches[len(c.diskCaches)-1].Reset()
 		if resetErr != nil {
-			glog.Errorf("failed to reset cache file %s", c.diskCaches[len(c.diskCaches)-1].fileName)
+			log.Errorf("failed to reset cache file %s", c.diskCaches[len(c.diskCaches)-1].fileName)
 			return
 		}
 		for i := len(c.diskCaches) - 1; i > 0; i-- {
@@ -55,7 +55,7 @@ func (c *OnDiskCacheLayer) setChunk(needleId types.NeedleId, data []byte) {
 	}
 
 	if err := c.diskCaches[0].WriteNeedle(needleId, data); err != nil {
-		glog.V(0).Infof("cache write %v size %d: %v", needleId, len(data), err)
+		log.Infof("cache write %v size %d: %v", needleId, len(data), err)
 	}
 
 }
@@ -70,7 +70,7 @@ func (c *OnDiskCacheLayer) getChunk(needleId types.NeedleId) (data []byte) {
 			continue
 		}
 		if err != nil {
-			glog.Errorf("failed to read cache file %s id %d", diskCache.fileName, needleId)
+			log.Errorf("failed to read cache file %s id %d", diskCache.fileName, needleId)
 			continue
 		}
 		if len(data) != 0 {
diff --git a/weed/util/cipher.go b/weed/util/cipher.go
index f044c2ca3..6e9153015 100644
--- a/weed/util/cipher.go
+++ b/weed/util/cipher.go
@@ -7,7 +7,7 @@ import (
 	"errors"
 	"io"
 
-	"github.com/chrislusf/seaweedfs/weed/glog"
+	"github.com/chrislusf/seaweedfs/weed/util/log"
 )
 
 type CipherKey []byte
@@ -15,7 +15,7 @@ type CipherKey []byte
 func GenCipherKey() CipherKey {
 	key := make([]byte, 32)
 	if _, err := io.ReadFull(rand.Reader, key); err != nil {
-		glog.Fatalf("random key gen: %v", err)
+		log.Fatalf("random key gen: %v", err)
 	}
 	return CipherKey(key)
 }
diff --git a/weed/util/compression.go b/weed/util/compression.go
index cf3ac7c57..c5ef84484 100644
--- a/weed/util/compression.go
+++ b/weed/util/compression.go
@@ -8,7 +8,7 @@ import (
 	"io/ioutil"
 	"strings"
 
-	"github.com/chrislusf/seaweedfs/weed/glog"
+	"github.com/chrislusf/seaweedfs/weed/util/log"
 	"github.com/klauspost/compress/zstd"
 )
 
@@ -34,7 +34,7 @@ func MaybeDecompressData(input []byte) []byte {
 	uncompressed, err := DecompressData(input)
 	if err != nil {
 		if err != UnsupportedCompression {
-			glog.Errorf("decompressed data: %v", err)
+			log.Errorf("decompressed data: %v", err)
 		}
 		return input
 	}
@@ -45,11 +45,11 @@ func GzipData(input []byte) ([]byte, error) {
 	buf := new(bytes.Buffer)
 	w, _ := gzip.NewWriterLevel(buf, flate.BestSpeed)
 	if _, err := w.Write(input); err != nil {
-		glog.V(2).Infof("error gzip data: %v", err)
+		log.Debugf("error gzip data: %v", err)
 		return nil, err
 	}
 	if err := w.Close(); err != nil {
-		glog.V(2).Infof("error closing gzipped data: %v", err)
+		log.Debugf("error closing gzipped data: %v", err)
 		return nil, err
 	}
 	return buf.Bytes(), nil
@@ -77,7 +77,7 @@ func ungzipData(input []byte) ([]byte, error) {
 	defer r.Close()
 	output, err := ioutil.ReadAll(r)
 	if err != nil {
-		glog.V(2).Infof("error ungzip data: %v", err)
+		log.Debugf("error ungzip data: %v", err)
 	}
 	return output, err
 }
diff --git a/weed/util/config.go b/weed/util/config.go
index 6acf21c12..9d7552064 100644
--- a/weed/util/config.go
+++ b/weed/util/config.go
@@ -5,7 +5,7 @@ import (
 
 	"github.com/spf13/viper"
 
-	"github.com/chrislusf/seaweedfs/weed/glog"
+	"github.com/chrislusf/seaweedfs/weed/util/log"
 )
 
 type Configuration interface {
@@ -24,16 +24,16 @@ func LoadConfiguration(configFileName string, required bool) (loaded bool) {
 	viper.AddConfigPath("$HOME/.seaweedfs") // call multiple times to add many search paths
 	viper.AddConfigPath("/etc/seaweedfs/")  // path to look for the config file in
 
-	glog.V(1).Infof("Reading %s.toml from %s", configFileName, viper.ConfigFileUsed())
+	log.Debugf("Reading %s.toml from %s", configFileName, viper.ConfigFileUsed())
 
 	if err := viper.MergeInConfig(); err != nil { // Handle errors reading the config file
-		logLevel := glog.Level(0)
 		if strings.Contains(err.Error(), "Not Found") {
-			logLevel = 1
+			log.Warnf("Reading %s: %v", viper.ConfigFileUsed(), err)
+		} else {
+			log.Infof("Reading %s: %v", viper.ConfigFileUsed(), err)
 		}
-		glog.V(logLevel).Infof("Reading %s: %v", viper.ConfigFileUsed(), err)
 		if required {
-			glog.Fatalf("Failed to load %s.toml file from current directory, or $HOME/.seaweedfs/, or /etc/seaweedfs/"+
+			log.Fatalf("Failed to load %s.toml file from current directory, or $HOME/.seaweedfs/, or /etc/seaweedfs/"+
 				"\n\nPlease use this command to generate the default %s.toml file\n"+
 				"    weed scaffold -config=%s -output=.\n\n\n",
 				configFileName, configFileName, configFileName)
diff --git a/weed/util/file_util.go b/weed/util/file_util.go
index 70135180d..bdc66afa4 100644
--- a/weed/util/file_util.go
+++ b/weed/util/file_util.go
@@ -8,7 +8,7 @@ import (
 	"strings"
 	"time"
 
-	"github.com/chrislusf/seaweedfs/weed/glog"
+	"github.com/chrislusf/seaweedfs/weed/util/log"
 )
 
 func TestFolderWritable(folder string) (err error) {
@@ -20,7 +20,7 @@ func TestFolderWritable(folder string) (err error) {
 		return errors.New("Not a valid folder!")
 	}
 	perm := fileInfo.Mode().Perm()
-	glog.V(0).Infoln("Folder", folder, "Permission:", perm)
+	log.Infoln("Folder", folder, "Permission:", perm)
 	if 0200&perm != 0 {
 		return nil
 	}
@@ -53,7 +53,7 @@ func CheckFile(filename string) (exists, canRead, canWrite bool, modTime time.Ti
 		return
 	}
 	if err != nil {
-		glog.Errorf("check %s: %v", filename, err)
+		log.Errorf("check %s: %v", filename, err)
 		return
 	}
 	if fi.Mode()&0400 != 0 {
diff --git a/weed/util/grace/pprof.go b/weed/util/grace/pprof.go
index 14686bfc8..68c3920af 100644
--- a/weed/util/grace/pprof.go
+++ b/weed/util/grace/pprof.go
@@ -5,14 +5,14 @@ import (
 	"runtime"
 	"runtime/pprof"
 
-	"github.com/chrislusf/seaweedfs/weed/glog"
+	"github.com/chrislusf/seaweedfs/weed/util/log"
 )
 
 func SetupProfiling(cpuProfile, memProfile string) {
 	if cpuProfile != "" {
 		f, err := os.Create(cpuProfile)
 		if err != nil {
-			glog.Fatal(err)
+			log.Fatal(err)
 		}
 		pprof.StartCPUProfile(f)
 		OnInterrupt(func() {
@@ -23,7 +23,7 @@ func SetupProfiling(cpuProfile, memProfile string) {
 		runtime.MemProfileRate = 1
 		f, err := os.Create(memProfile)
 		if err != nil {
-			glog.Fatal(err)
+			log.Fatal(err)
 		}
 		OnInterrupt(func() {
 			pprof.WriteHeapProfile(f)
diff --git a/weed/util/http_util.go b/weed/util/http_util.go
index 7851d8293..9887fd312 100644
--- a/weed/util/http_util.go
+++ b/weed/util/http_util.go
@@ -11,7 +11,7 @@ import (
 	"net/url"
 	"strings"
 
-	"github.com/chrislusf/seaweedfs/weed/glog"
+	"github.com/chrislusf/seaweedfs/weed/util/log"
 )
 
 var (
@@ -251,7 +251,7 @@ func ReadUrl(fileUrl string, cipherKey []byte, isContentCompressed bool, isFullC
 	// drains the response body to avoid memory leak
 	data, _ := ioutil.ReadAll(reader)
 	if len(data) != 0 {
-		glog.V(1).Infof("%s reader has remaining %d bytes", contentEncoding, len(data))
+		log.Debugf("%s reader has remaining %d bytes", contentEncoding, len(data))
 	}
 	return n, err
 }
@@ -323,7 +323,7 @@ func readEncryptedUrl(fileUrl string, cipherKey []byte, isContentCompressed bool
 	if isContentCompressed {
 		decryptedData, err = DecompressData(decryptedData)
 		if err != nil {
-			glog.V(0).Infof("unzip decrypt %s: %v", fileUrl, err)
+			log.Infof("unzip decrypt %s: %v", fileUrl, err)
 		}
 	}
 	if len(decryptedData) < int(offset)+size {
diff --git a/weed/util/log/logger.go b/weed/util/log/logger.go
new file mode 100644
index 000000000..54c4f35ff
--- /dev/null
+++ b/weed/util/log/logger.go
@@ -0,0 +1,91 @@
+package log
+
+import (
+	"fmt"
+	"os"
+
+	"github.com/sirupsen/logrus"
+)
+
+const (
+	LogLevel = "LOG"
+)
+
+var (
+	logger = logrus.New()
+)
+
+func init() {
+	envLevel, _ := os.LookupEnv(LogLevel)
+	if envLevel == "" {
+		envLevel = "info"
+	}
+	level := logLevel(envLevel)
+	logger.SetLevel(level)
+	formatter := &logrus.TextFormatter{
+		FullTimestamp:          false,
+		DisableLevelTruncation: true,
+	}
+	logger.SetFormatter(formatter)
+
+}
+
+func logLevel(lvl string) logrus.Level {
+
+	switch lvl {
+	case "trace":
+		return logrus.TraceLevel
+	case "debug":
+		return logrus.DebugLevel
+	case "info":
+		return logrus.InfoLevel
+	case "warn":
+		return logrus.WarnLevel
+	case "error":
+		return logrus.ErrorLevel
+	case "fatal":
+		return logrus.FatalLevel
+	default:
+		panic(fmt.Sprintf("the specified %s log level is not supported. Use [trace|debug|info|warn|error|fatal]", lvl))
+	}
+}
+
+func Info(values ...interface{}) {
+	logger.Info(values...)
+}
+func Infof(fmt string, values ...interface{}) {
+	logger.Infof(fmt, values...)
+}
+func Infoln(values ...interface{}) {
+	logger.Infoln(values...)
+}
+func Debugf(fmt string, values ...interface{}) {
+	logger.Debugf(fmt, values...)
+}
+func Debug(values ...interface{}) {
+	logger.Debug(values...)
+}
+func Tracef(fmt string, values ...interface{}) {
+	logger.Tracef(fmt, values...)
+}
+func Trace(values ...interface{}) {
+	logger.Trace(values...)
+}
+func Warnf(fmt string, values ...interface{}) {
+	logger.Warnf(fmt, values...)
+}
+func Fatalf(fmt string, values ...interface{}) {
+	logger.Fatalf(fmt, values...)
+}
+func Errorf(fmt string, values ...interface{}) {
+	logger.Errorf(fmt, values...)
+}
+func Error(values ...interface{}) {
+	logger.Error(values...)
+}
+func Fatal(values ...interface{}) {
+	logger.Fatal(values...)
+}
+func IsTrace() bool {
+	return logger.IsLevelEnabled(logrus.TraceLevel)
+}
diff --git a/weed/util/log_buffer/log_buffer.go b/weed/util/log_buffer/log_buffer.go
index e4310b5c5..a122799a1 100644
--- a/weed/util/log_buffer/log_buffer.go
+++ b/weed/util/log_buffer/log_buffer.go
@@ -7,7 +7,7 @@ import (
 
 	"github.com/golang/protobuf/proto"
 
-	"github.com/chrislusf/seaweedfs/weed/glog"
+	"github.com/chrislusf/seaweedfs/weed/util/log"
 	"github.com/chrislusf/seaweedfs/weed/pb/filer_pb"
 	"github.com/chrislusf/seaweedfs/weed/util"
 )
@@ -189,7 +189,7 @@ func (m *LogBuffer) ReadFromBuffer(lastReadTime time.Time) (bufferCopy *bytes.Bu
 		return nil
 	}
 	if lastReadTime.After(m.stopTime) {
-		// glog.Fatalf("unexpected last read time %v, older than latest %v", lastReadTime, m.stopTime)
+		// log.Fatalf("unexpected last read time %v, older than latest %v", lastReadTime, m.stopTime)
 		return nil
 	}
 	if lastReadTime.Before(m.startTime) {
@@ -279,7 +279,7 @@ func readTs(buf []byte, pos int) (size int, ts int64) {
 
 	err := proto.Unmarshal(entryData, logEntry)
 	if err != nil {
-		glog.Fatalf("unexpected unmarshal filer_pb.LogEntry: %v", err)
+		log.Fatalf("unexpected unmarshal filer_pb.LogEntry: %v", err)
 	}
 	return size, logEntry.TsNs
 
diff --git a/weed/util/log_buffer/log_read.go b/weed/util/log_buffer/log_read.go
index 57f4b0115..47c76d570 100644
--- a/weed/util/log_buffer/log_read.go
+++ b/weed/util/log_buffer/log_read.go
@@ -7,7 +7,7 @@ import (
 
 	"github.com/golang/protobuf/proto"
 
-	"github.com/chrislusf/seaweedfs/weed/glog"
+	"github.com/chrislusf/seaweedfs/weed/util/log"
 	"github.com/chrislusf/seaweedfs/weed/pb/filer_pb"
 	"github.com/chrislusf/seaweedfs/weed/util"
 )
@@ -55,14 +55,14 @@ func (logBuffer *LogBuffer) LoopProcessLogData(
 			size := util.BytesToUint32(buf[pos : pos+4])
 			if pos+4+int(size) > len(buf) {
 				err = ResumeError
-				glog.Errorf("LoopProcessLogData: read buffer %v read %d [%d,%d) from [0,%d)", lastReadTime, batchSize, pos, pos+int(size)+4, len(buf))
+				log.Errorf("LoopProcessLogData: read buffer %v read %d [%d,%d) from [0,%d)", lastReadTime, batchSize, pos, pos+int(size)+4, len(buf))
 				return
 			}
 			entryData := buf[pos+4 : pos+4+int(size)]
 
 			logEntry := &filer_pb.LogEntry{}
 			if err = proto.Unmarshal(entryData, logEntry); err != nil {
-				glog.Errorf("unexpected unmarshal messaging_pb.Message: %v", err)
+				log.Errorf("unexpected unmarshal messaging_pb.Message: %v", err)
 				pos += 4 + int(size)
 				continue
 			}
diff --git a/weed/util/network.go b/weed/util/network.go
index 7108cfea6..c1b7a08ad 100644
--- a/weed/util/network.go
+++ b/weed/util/network.go
@@ -3,13 +3,13 @@ package util
 import (
 	"net"
 
-	"github.com/chrislusf/seaweedfs/weed/glog"
+	"github.com/chrislusf/seaweedfs/weed/util/log"
 )
 
 func DetectedHostAddress() string {
 	addrs, err := net.InterfaceAddrs()
 	if err != nil {
-		glog.V(0).Infof("failed to detect ip address: %v", err)
+		log.Infof("failed to detect ip address: %v", err)
 		return ""
 	}
 
diff --git a/weed/util/retry.go b/weed/util/retry.go
index 85c4d150d..c1063685b 100644
--- a/weed/util/retry.go
+++ b/weed/util/retry.go
@@ -4,7 +4,7 @@ import (
 	"strings"
 	"time"
 
-	"github.com/chrislusf/seaweedfs/weed/glog"
+	"github.com/chrislusf/seaweedfs/weed/util/log"
 )
 
 var RetryWaitTime = 6 * time.Second
@@ -16,13 +16,13 @@ func Retry(name string, job func() error) (err error) {
 		err = job()
 		if err == nil {
 			if hasErr {
-				glog.V(0).Infof("retry %s successfully", name)
+				log.Infof("retry %s successfully", name)
 			}
 			break
 		}
 		if strings.Contains(err.Error(), "transport") {
 			hasErr = true
-			glog.V(0).Infof("retry %s", name)
+			log.Infof("retry %s", name)
 			time.Sleep(waitTime)
 			waitTime += waitTime / 2
 		}
diff --git a/weed/util/throttler.go b/weed/util/throttler.go
index 873161e37..bac899658 100644
--- a/weed/util/throttler.go
+++ b/weed/util/throttler.go
@@ -25,7 +25,7 @@ func (wt *WriteThrottler) MaybeSlowdown(delta int64) {
 			if overLimitBytes > 0 {
 				overRatio := float64(overLimitBytes) / float64(wt.compactionBytePerSecond)
 				sleepTime := time.Duration(overRatio*1000) * time.Millisecond
-				// glog.V(0).Infof("currently %d bytes, limit to %d bytes, over by %d bytes, sleeping %v over %.4f", wt.lastSizeCounter, wt.compactionBytePerSecond/10, overLimitBytes, sleepTime, overRatio)
+				// log.Infof("currently %d bytes, limit to %d bytes, over by %d bytes, sleeping %v over %.4f", wt.lastSizeCounter, wt.compactionBytePerSecond/10, overLimitBytes, sleepTime, overRatio)
 				time.Sleep(sleepTime)
 			}
 			wt.lastSizeCounter, wt.lastSizeCheckTime = 0, time.Now()