Implement Logger (#228)

* Added new base logger

* updated example and test configs

* updated exchange helpers restful router & server

* logPath is now passed to the logger to remove dependency on common package

* updated everything besides exchanges to use new logger

* alphapoint to bitmex done

* updated bitmex bitstamp bittrex btcc and also performance changes to logger

* btcmarkets coinbase coinut exmo gateio wrappers updated

* gateio and gemini logger updated

* hitbtc huobi itbit & kraken updated

* All exchanges updatd

* return correct error for disabled websocket

* don't disconnect client on invalid json

* updated router internal logging

* log.Fatal to t.Error for tests

* Changed from fatal to error failure to set maxprocs

* output ANSI codes for everything but windows for now due to lack of windows support

* added error handling to logger and unit tests

* clear wording on print -> log.print

* added benchmark test

* cleaned up import sections

* Updated logger based on PR requests (added default config options on failure/setting errors)

* ah this should fix travici enc config issue

* Load entire config and clear out logging to hopefully fix travisci issue

* wording & test error handling

* fixed formatting issues based on feedback

* fixed formatting issues based on feedback

* changed CheckDir to use mkdirall instead of mkdir and other changes based on feedback

logger/logger.go

@@ -0,0 +1,120 @@
+package logger
+
+import (
+	"fmt"
+	"io"
+	"io/ioutil"
+	"log"
+	"os"
+	"path"
+	"runtime"
+	"time"
+)
+
+func init() {
+	setDefaultOutputs()
+}
+
+// SetupLogger configure logger instance with user provided settings
+func SetupLogger() (err error) {
+	if *Logger.Enabled {
+		err = setupOutputs()
+		if err != nil {
+			return
+		}
+		logLevel()
+		if Logger.ColourOutput {
+			colourOutput()
+		}
+	} else {
+		clearAllLoggers()
+	}
+	return
+}
+
+// setDefaultOutputs() this setups defaults used by the logger
+// This allows it to be used without any user configuration
+func setDefaultOutputs() {
+	debugLogger = log.New(os.Stdout,
+		"[DEBUG]: ",
+		log.Ldate|log.Ltime)
+
+	infoLogger = log.New(os.Stdout,
+		"[INFO]: ",
+		log.Ldate|log.Ltime)
+
+	warnLogger = log.New(os.Stdout,
+		"[WARN]: ",
+		log.Ldate|log.Ltime)
+
+	errorLogger = log.New(os.Stdout,
+		"[ERROR]: ",
+		log.Ldate|log.Ltime)
+
+	fatalLogger = log.New(os.Stdout,
+		"[FATAL]: ",
+		log.Ldate|log.Ltime)
+}
+
+// colorOutput() sets the prefix of each log type to matching colour
+// TODO: add windows support
+func colourOutput() {
+	if runtime.GOOS != "windows" {
+		debugLogger.SetPrefix("\033[34m[DEBUG]\033[0m: ")
+		infoLogger.SetPrefix("\033[32m[INFO]\033[0m: ")
+		warnLogger.SetPrefix("\033[33m[WARN]\033[0m: ")
+		errorLogger.SetPrefix("\033[31m[ERROR]\033[0m: ")
+		fatalLogger.SetPrefix("\033[31m[FATAL]\033[0m: ")
+	}
+}
+
+// clearAllLoggers() sets all logger flags to 0 and outputs to Discard
+func clearAllLoggers() {
+	debugLogger.SetFlags(0)
+	infoLogger.SetFlags(0)
+	warnLogger.SetFlags(0)
+	errorLogger.SetFlags(0)
+	fatalLogger.SetFlags(0)
+
+	debugLogger.SetOutput(ioutil.Discard)
+	infoLogger.SetOutput(ioutil.Discard)
+	warnLogger.SetOutput(ioutil.Discard)
+	errorLogger.SetOutput(ioutil.Discard)
+	fatalLogger.SetOutput(ioutil.Discard)
+}
+
+// setupOutputs() sets up the io.writer to use for logging
+// TODO: Fix up rotating at the moment its a quick job
+func setupOutputs() (err error) {
+	if len(Logger.File) > 0 {
+		logFile := path.Join(LogPath, Logger.File)
+		if Logger.Rotate {
+			if _, err = os.Stat(logFile); !os.IsNotExist(err) {
+				currentTime := time.Now()
+				newName := currentTime.Format("2006-01-02 15-04-05")
+				newFile := newName + " " + Logger.File
+				err = os.Rename(logFile, path.Join(LogPath, newFile))
+				if err != nil {
+					err = fmt.Errorf("Failed to rename old log file %s", err)
+					return
+				}
+			}
+		}
+		logFileHandle, err = os.OpenFile(logFile, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0666)
+		if err != nil {
+			return
+		}
+		logOutput = io.MultiWriter(os.Stdout, logFileHandle)
+	} else {
+		logOutput = os.Stdout
+	}
+	return
+}
+
+// CloseLogFile close the handler for any open log files
+func CloseLogFile() (err error) {
+	if logFileHandle != nil {
+		err = logFileHandle.Close()
+	}
+	return
+}

logger/logger_levels.go

@@ -0,0 +1,33 @@
+package logger
+
+import (
+	"log"
+	"strings"
+)
+
+func logLevel() {
+	clearAllLoggers()
+	enabledLevels := strings.Split(Logger.Level, "|")
+
+	for x := range enabledLevels {
+		switch level := enabledLevels[x]; level {
+		case "DEBUG":
+			debugLogger.SetOutput(logOutput)
+			debugLogger.SetFlags(log.Ldate | log.Ltime)
+		case "INFO":
+			infoLogger.SetOutput(logOutput)
+			infoLogger.SetFlags(log.Ldate | log.Ltime)
+		case "WARN":
+			warnLogger.SetOutput(logOutput)
+			warnLogger.SetFlags(log.Ldate | log.Ltime)
+		case "ERROR":
+			errorLogger.SetOutput(logOutput)
+			errorLogger.SetFlags(log.Ldate | log.Ltime)
+		case "FATAL":
+			fatalLogger.SetOutput(logOutput)
+			fatalLogger.SetFlags(log.Ldate | log.Ltime | log.Lshortfile)
+		default:
+			continue
+		}
+	}
+}

logger/logger_test.go

@@ -0,0 +1,75 @@
+package logger
+
+import (
+	"os"
+	"path"
+	"testing"
+)
+
+var (
+	trueptr  = func(b bool) *bool { return &b }(true)
+	falseptr = func(b bool) *bool { return &b }(false)
+)
+
+func TestCloseLogFile(t *testing.T) {
+	Logger = &Logging{
+		Enabled:      trueptr,
+		Level:        "DEBUG",
+		ColourOutput: false,
+		File:         "",
+		Rotate:       false,
+	}
+	SetupLogger()
+	err := CloseLogFile()
+	if err != nil {
+		t.Fatalf("CloseLogFile failed with %v", err)
+	}
+	os.Remove(path.Join(LogPath, Logger.File))
+}
+
+func TestSetupOutputsValidPath(t *testing.T) {
+	Logger.Enabled = trueptr
+	Logger.File = "debug.txt"
+	LogPath = "../testdata/"
+	err := setupOutputs()
+	if err != nil {
+		t.Fatalf("SetupOutputs failed expected nil got %v", err)
+	}
+	os.Remove(path.Join(LogPath, Logger.File))
+}
+
+func TestSetupOutputsInValidPath(t *testing.T) {
+	Logger.Enabled = trueptr
+	Logger.File = "debug.txt"
+	LogPath = "../testdataa/"
+	err := setupOutputs()
+	if err != nil {
+		if !os.IsNotExist(err) {
+			t.Fatalf("SetupOutputs failed expected %v got %v", os.ErrNotExist, err)
+		}
+	}
+	os.Remove(path.Join(LogPath, Logger.File))
+}
+
+func BenchmarkDebugf(b *testing.B) {
+	Logger = &Logging{
+		Enabled:      trueptr,
+		Level:        "DEBUG",
+		ColourOutput: false,
+		File:         "",
+		Rotate:       false,
+	}
+	SetupLogger()
+	b.ResetTimer()
+	for n := 0; n < b.N; n++ {
+		Debugf("This is a debug benchmark %d", n)
+	}
+}
+
+func BenchmarkDebugfLoggerDisabled(b *testing.B) {
+	clearAllLoggers()
+	b.ResetTimer()
+	for n := 0; n < b.N; n++ {
+		Debugf("this is a debug benchmark")
+	}
+}

logger/logger_types.go

@@ -0,0 +1,34 @@
+package logger
+
+import (
+	"io"
+	"log"
+	"os"
+)
+
+// Logging struct that holds all user configurable options for the logger
+type Logging struct {
+	Enabled      *bool  `json:"enabled,omitempty"`
+	File         string `json:"file"`
+	ColourOutput bool   `json:"colour"`
+	Level        string `json:"level"`
+	Rotate       bool   `json:"rotate"`
+}
+
+var (
+	debugLogger *log.Logger
+	infoLogger  *log.Logger
+	warnLogger  *log.Logger
+	errorLogger *log.Logger
+	fatalLogger *log.Logger
+
+	logFileHandle *os.File
+
+	logOutput io.Writer
+
+	// LogPath location to store logs in
+	LogPath string
+
+	// Logger create a pointer to Logging struct for holding data
+	Logger = &Logging{}
+)

logger/loggers.go

@@ -0,0 +1,80 @@
+package logger
+
+import (
+	"fmt"
+	"log"
+	"os"
+)
+
+// Info handler takes any input returns unformatted output to infoLogger writer
+func Info(v ...interface{}) {
+	infoLogger.Print(v...)
+}
+
+// Infof handler takes any input infoLogger returns formatted output to infoLogger writer
+func Infof(data string, v ...interface{}) {
+	infoLogger.Printf(data, v...)
+}
+
+// Infoln handler takes any input infoLogger returns formatted output to infoLogger writer
+func Infoln(v ...interface{}) {
+	infoLogger.Println(v...)
+}
+
+// Print aliased to Standard log.Print
+var Print = log.Print
+
+// Printf aliased to Standard log.Printf
+var Printf = log.Printf
+
+// Println aliased to Standard log.Println
+var Println = log.Println
+
+// Debug handler takes any input returns unformatted output to infoLogger writer
+func Debug(v ...interface{}) {
+	debugLogger.Print(v...)
+}
+
+// Debugf handler takes any input infoLogger returns formatted output to infoLogger writer
+func Debugf(data string, v ...interface{}) {
+	debugLogger.Printf(data, v...)
+}
+
+// Debugln handler takes any input infoLogger returns formatted output to infoLogger writer
+func Debugln(v ...interface{}) {
+	debugLogger.Println(v...)
+}
+
+// Warn handler takes any input returns unformatted output to warnLogger writer
+func Warn(v ...interface{}) {
+	warnLogger.Print(v...)
+}
+
+// Warnf handler takes any input returns unformatted output to warnLogger writer
+func Warnf(data string, v ...interface{}) {
+	warnLogger.Printf(data, v...)
+}
+
+// Error handler takes any input returns unformatted output to errorLogger writer
+func Error(v ...interface{}) {
+	errorLogger.Print(v...)
+}
+
+// Errorf handler takes any input returns unformatted output to errorLogger writer
+func Errorf(data string, v ...interface{}) {
+	errorLogger.Printf(data, v...)
+}
+
+// Fatal handler takes any input returns unformatted output to fatalLogger writer
+func Fatal(v ...interface{}) {
+	// Send to Output instead of Fatal to allow us to increase the output depth by 1 to make sure the correct file is displayed
+	fatalLogger.Output(2, fmt.Sprint(v...))
+	os.Exit(1)
+}
+
+// Fatalf handler takes any input returns unformatted output to fatalLogger writer
+func Fatalf(data string, v ...interface{}) {
+	// Send to Output instead of Fatal to allow us to increase the output depth by 1 to make sure the correct file is displayed
+	fatalLogger.Output(2, fmt.Sprintf(data, v...))
+	os.Exit(1)
+}