Merge pull request #16 from InVisionApp/update-err-logs

Update error handling and logging

Author: Shawn Hartsell

backend/mongo/masterlock.go

@@ -54,21 +54,18 @@ func (m *MongoBackend) Lock(info *backend.MasterInfo) error {
 		if err == mgo.ErrNotFound {
 			// perform an insert
 			if err := m.lock.Collection().Insert(mmi); err != nil {
-				m.log.Errorf("unable to insert initial lock: %v", err)
-				return err
+				return fmt.Errorf("unable to insert initial lock: %v", err)
 			}
 
-			m.log.Info("successfully inserted initial lock")
 			return nil
 		}
 
-		e := fmt.Errorf("failed to fetch current master info: %v", err)
-		m.log.Error(e)
+		err = fmt.Errorf("failed to fetch current master info: %v", err)
 
 		m.log.Debug("attempting to refresh sessions in case of db issues")
 		m.refresh()
 
-		return e
+		return err
 	}
 
 	// has not been long enough since the last valid heart beat
@@ -84,9 +81,8 @@ func (m *MongoBackend) Lock(info *backend.MasterInfo) error {
 	}
 
 	if _, err := m.lock.Collection().Find(query).Apply(change, mmi); err != nil {
-		lErr := fmt.Errorf("unable to complete findModify: %v", err)
-		m.log.Error(lErr)
-		return lErr
+		err = fmt.Errorf("unable to complete findModify: %v", err)
+		return err
 	}
 
 	return nil

backend/mongo/mongodb.go

@@ -10,10 +10,10 @@ import (
 	"strings"
 	"sync"
 
-	"github.com/InVisionApp/go-logger"
+	log "github.com/InVisionApp/go-logger"
 	"github.com/InVisionApp/go-logger/shims/logrus"
 	"github.com/globalsign/mgo"
-	"github.com/newrelic/go-agent"
+	newrelic "github.com/newrelic/go-agent"
 )
 
 const (
@@ -118,7 +118,7 @@ func (m *MongoBackend) Connect() error {
 		dialInfo.DialServer = func(addr *mgo.ServerAddr) (net.Conn, error) {
 			conn, err := tls.Dial("tcp", addr.String(), &tls.Config{})
 			if conn != nil {
-				m.log.Debugf("Connection local address: %s, remote address: %s", conn.LocalAddr(), conn.RemoteAddr())
+				m.log.Infof("Connection local address: %s, remote address: %s", conn.LocalAddr(), conn.RemoteAddr())
 			}
 			return conn, err
 		}
@@ -181,7 +181,7 @@ func (s *SmartCollection) Collection() *mgo.Collection {
 
 func (s *SmartCollection) EnsureIndexes(idxs []*mgo.Index) error {
 	for _, idx := range idxs {
-		s.log.Debugf("Ensuring index: %s", idx.Name)
+		s.log.Infof("Ensuring index: %s", idx.Name)
 		if err := s.UpsertIndex(idx); err != nil {
 			return fmt.Errorf("could not ensure indexes on DB: %v", err)
 		}

backend/mysql/masterlock.go

@@ -97,8 +97,7 @@ func (m *MySQLBackend) Lock(info *backend.MasterInfo) error {
 
 	res, err := m.db.NamedExec(query, fields)
 	if err != nil {
-		m.log.Errorf("failed to update lock: %v", err)
-		return err
+		return fmt.Errorf("failed to update lock: %v", err)
 	}
 
 	// if no rows were modified, then probably another master got the lock

backend/mysql/mysql.go

@@ -6,7 +6,7 @@ import (
 	"fmt"
 	"time"
 
-	"github.com/InVisionApp/go-logger"
+	log "github.com/InVisionApp/go-logger"
 	"github.com/InVisionApp/go-logger/shims/logrus"
 	_ "github.com/go-sql-driver/mysql"
 	"github.com/jmoiron/sqlx"
@@ -180,14 +180,14 @@ func (m *MySQLBackend) retryConnect() error {
 }
 
 func (m *MySQLBackend) createDB() error {
-	m.log.Debug("Creating new lock DB if it does not exist")
+	m.log.Info("Creating new lock DB if it does not exist")
 
 	_, err := m.db.Exec(fmt.Sprintf("CREATE DATABASE IF NOT EXISTS `%v`", m.DBName))
 	if err != nil {
 		return fmt.Errorf("unable to create initial lock DB: %v", err)
 	}
 
-	m.log.Debugf("Created new lock DB '%v' (or already existed)", m.DBName)
+	m.log.Infof("Created new lock DB '%v' (or already existed)", m.DBName)
 
 	return nil
 }
@@ -212,14 +212,14 @@ func (m *MySQLBackend) createTable() error {
 		`last_heartbeat TIMESTAMP`+
 		`);`, m.TableName)
 
-	m.log.Debug("Attempting to create lock table")
+	m.log.Info("Attempting to create lock table")
 
 	_, err := m.db.DB.Exec(query)
 	if err != nil {
 		return fmt.Errorf("unable to create lock table: %v", err)
 	}
 
-	m.log.Debugf("Created new lock table '%v' (or already existed)", m.TableName)
+	m.log.Infof("Created new lock table '%v' (or already existed)", m.TableName)
 
 	return nil
 }

example/example.go

@@ -5,7 +5,7 @@ import (
 	"sync"
 	"time"
 
-	"github.com/InVisionApp/go-logger"
+	log "github.com/InVisionApp/go-logger"
 	logshim "github.com/InVisionApp/go-logger/shims/logrus"
 	"github.com/InVisionApp/go-master"
 	"github.com/InVisionApp/go-master/backend"
@@ -20,7 +20,7 @@ var (
 
 func init() {
 	l := logrus.New()
-	l.SetLevel(logrus.DebugLevel)
+	l.SetLevel(logrus.InfoLevel)
 	logger = logshim.New(l)
 }
 

master.go

@@ -4,7 +4,7 @@ import (
 	"fmt"
 	"time"
 
-	"github.com/InVisionApp/go-logger"
+	log "github.com/InVisionApp/go-logger"
 	"github.com/gofrs/uuid"
 	"github.com/relistan/go-director"
 
@@ -162,8 +162,6 @@ func (m *master) runHeartBeat() {
 
 		// run the heartbeat
 		if err := m.lock.WriteHeartbeat(m.info); err != nil {
-			m.log.Debugf("failed to write heartbeat: %v", err)
-
 			m.sendError(fmt.Errorf("failed to write heartbeat: %v", err))
 			// if heartbeat fails or master lock lost, stop the tasks
 			m.cleanupMaster()
@@ -186,7 +184,7 @@ func (m *master) becomeMaster() bool {
 	}
 
 	if err := m.lock.Lock(mi); err != nil {
-		m.log.Debugf("failed to lock: %v", err)
+		m.sendError(fmt.Errorf("failed to acquire lock while becoming master: %v", err))
 		return false
 	}
 
@@ -226,7 +224,7 @@ func (m *master) Stop() error {
 	// this is a best effort. The heartbeat loop has been stopped,
 	// so the lock will be lost eventually either way
 	if err := m.lock.UnLock(m.uuid); err != nil {
-		m.log.Errorf("failed to release lock on master backend: %v", err)
+		m.sendError(fmt.Errorf("failed to release lock on master backend: %v", err))
 	}
 
 	// at this point, as far as this node is concerned, it is