Merge pull request #164 from aalda/logging

New logging system

api/apihttp/apihttp.go

@@ -565,19 +565,19 @@ func GetReqSanitizer(w http.ResponseWriter, r *http.Request) (http.ResponseWrite
 
 // LogHandler Logs the Http Status for a request into fileHandler and returns a
 // httphandler function which is a wrapper to log the requests.
-func LogHandler(handle http.Handler) http.HandlerFunc {
+func LogHandler(handle http.Handler, logger log.Logger) http.HandlerFunc {
 	return func(w http.ResponseWriter, request *http.Request) {
 		start := time.Now()
 		writer := statusWriter{w, 0, 0}
 		handle.ServeHTTP(&writer, request)
 		latency := time.Now().Sub(start)
 
-		log.Debugf("Request: lat %d %+v", latency, request)
+		logger.Debugf("Request: lat %d %+v", latency, request)
 		if writer.status >= 400 && writer.status < 500 {
-			log.Infof("Bad Request: %d %+v", latency, request)
+			logger.Infof("Bad Request: %d %+v", latency, request)
 		}
 		if writer.status >= 500 {
-			log.Infof("Server error: %d %+v", latency, request)
+			logger.Infof("Server error: %d %+v", latency, request)
 		}
 	}
 }

balloon/balloon.go

@@ -28,6 +28,7 @@ import (
 	"github.com/bbva/qed/balloon/history"
 	"github.com/bbva/qed/balloon/hyper"
 	"github.com/bbva/qed/crypto/hashing"
+	"github.com/bbva/qed/log"
 	"github.com/bbva/qed/storage"
 	"github.com/bbva/qed/util"
 )
@@ -46,22 +47,28 @@ type Balloon struct {
 	historyTree *history.HistoryTree
 	hyperTree   *hyper.HyperTree
 	sync.RWMutex
+	log log.Logger
 }
 
-// NewBalloon function instanciates a balloon given a storage and a hasher function.
 func NewBalloon(store storage.Store, hasherF func() hashing.Hasher) (*Balloon, error) {
+	return NewBalloonWithLogger(store, hasherF, log.L())
+}
+
+// NewBalloon function instanciates a balloon given a storage and a hasher function.
+func NewBalloonWithLogger(store storage.Store, hasherF func() hashing.Hasher, logger log.Logger) (*Balloon, error) {
 
 	// create trees
-	historyTree := history.NewHistoryTree(hasherF, store, 300)
+	historyTree := history.NewHistoryTreeWithLogger(hasherF, store, 300, logger.Named("history"))
 	batchCache := hyper.NewBatchCache(hyper.DefaultBatchLevels)
-	hyperTree := hyper.NewHyperTree(hasherF, store, batchCache)
+	hyperTree := hyper.NewHyperTreeWithLogger(hasherF, store, batchCache, logger.Named("hyper"))
 
 	balloon := &Balloon{
 		version:     0,
 		hasherF:     hasherF,
 		store:       store,
 		historyTree: historyTree,
 		hyperTree:   hyperTree,
+		log:         logger,
 	}
 
 	// update version

balloon/balloon_test.go

@@ -26,7 +26,6 @@ import (
 	"github.com/stretchr/testify/require"
 
 	"github.com/bbva/qed/crypto/hashing"
-	"github.com/bbva/qed/log"
 	metrics_utils "github.com/bbva/qed/testutils/metrics"
 	"github.com/bbva/qed/testutils/rand"
 	storage_utils "github.com/bbva/qed/testutils/storage"
@@ -35,8 +34,6 @@ import (
 
 func TestAdd(t *testing.T) {
 
-	log.SetLogger(t.Name(), log.SILENT)
-
 	store, closeF := storage_utils.OpenBPlusTreeStore()
 	defer closeF()
 
@@ -61,8 +58,6 @@ func TestAdd(t *testing.T) {
 }
 func TestAddBulk(t *testing.T) {
 
-	log.SetLogger(t.Name(), log.SILENT)
-
 	store, closeF := storage_utils.OpenBPlusTreeStore()
 	defer closeF()
 
@@ -102,8 +97,6 @@ func TestAddBulk(t *testing.T) {
 
 func TestQueryMembershipConsistency(t *testing.T) {
 
-	log.SetLogger(t.Name(), log.SILENT)
-
 	testCases := []struct {
 		key     []byte
 		version uint64
@@ -148,8 +141,6 @@ func TestQueryMembershipConsistency(t *testing.T) {
 
 func TestQueryMembership(t *testing.T) {
 
-	log.SetLogger(t.Name(), log.SILENT)
-
 	testCases := []struct {
 		key    []byte
 		exists bool
@@ -190,8 +181,6 @@ func TestQueryMembership(t *testing.T) {
 
 func TestQueryConsistencyProof(t *testing.T) {
 
-	log.SetLogger(t.Name(), log.SILENT)
-
 	testCases := []struct {
 		additions, start, end uint64
 		ok                    bool
@@ -237,8 +226,6 @@ func TestConsistencyProofVerify(t *testing.T) {
 
 func TestAddQueryAndVerify(t *testing.T) {
 
-	log.SetLogger(t.Name(), log.SILENT)
-
 	store, closeF := storage_utils.OpenRocksDBStore(t, "/var/tmp/balloon.test.1")
 	defer closeF()
 
@@ -264,8 +251,6 @@ func TestAddQueryAndVerify(t *testing.T) {
 
 func TestCacheWarmingUp(t *testing.T) {
 
-	log.SetLogger(t.Name(), log.SILENT)
-
 	store, closeF := storage_utils.OpenRocksDBStore(t, "/var/tmp/ballon_test.db")
 	defer closeF()
 
@@ -305,8 +290,6 @@ func TestCacheWarmingUp(t *testing.T) {
 
 func TestGenIncrementalAndVerify(t *testing.T) {
 
-	log.SetLogger(t.Name(), log.SILENT)
-
 	store, closeF := storage_utils.OpenRocksDBStore(t, "/var/tmp/balloon.test.3")
 	defer closeF()
 
@@ -335,8 +318,6 @@ func TestGenIncrementalAndVerify(t *testing.T) {
 
 func TestAddBulkAndQuery(t *testing.T) {
 
-	log.SetLogger(t.Name(), log.SILENT)
-
 	store, closeF := storage_utils.OpenRocksDBStore(t, "/var/tmp/balloon.test.6")
 	defer closeF()
 
@@ -371,8 +352,6 @@ func TestAddBulkAndQuery(t *testing.T) {
 
 func TestAddAndQuery(t *testing.T) {
 
-	log.SetLogger(t.Name(), log.SILENT)
-
 	store, closeF := storage_utils.OpenRocksDBStore(t, "/var/tmp/balloon.test.7")
 	defer closeF()
 
@@ -403,8 +382,6 @@ func TestAddAndQuery(t *testing.T) {
 
 func TestAddAndQueryConsistency(t *testing.T) {
 
-	log.SetLogger(t.Name(), log.SILENT)
-
 	store, closeF := storage_utils.OpenRocksDBStore(t, "/var/tmp/balloon.test.7")
 	defer closeF()
 
@@ -439,8 +416,6 @@ func TestAddAndQueryConsistency(t *testing.T) {
 
 func BenchmarkAddRocksDB(b *testing.B) {
 
-	log.SetLogger(b.Name(), log.SILENT)
-
 	store, closeF := storage_utils.OpenRocksDBStore(b, "/var/tmp/balloon_bench.db")
 	defer closeF()
 
@@ -465,8 +440,6 @@ func BenchmarkAddRocksDB(b *testing.B) {
 
 func BenchmarkAddBulkRocksDB(b *testing.B) {
 
-	log.SetLogger(b.Name(), log.SILENT)
-
 	store, closeF := storage_utils.OpenRocksDBStore(b, "/var/tmp/balloon_bench.db")
 	defer closeF()
 
@@ -499,8 +472,8 @@ func BenchmarkAddBulkRocksDB(b *testing.B) {
 	}
 }
 func BenchmarkQueryRocksDB(b *testing.B) {
+
 	var events [][]byte
-	log.SetLogger(b.Name(), log.SILENT)
 
 	store, closeF := storage_utils.OpenRocksDBStore(b, "/var/tmp/ballon_bench.db")
 	defer closeF()
@@ -526,8 +499,8 @@ func BenchmarkQueryRocksDB(b *testing.B) {
 }
 
 func BenchmarkQueryRocksDBParallel(b *testing.B) {
+
 	var events [][]byte
-	log.SetLogger(b.Name(), log.SILENT)
 
 	store, closeF := storage_utils.OpenRocksDBStore(b, "/var/tmp/ballon_bench.db")
 	defer closeF()

balloon/history/consistency_test.go

@@ -19,7 +19,6 @@ package history
 import (
 	"testing"
 
-	"github.com/bbva/qed/log"
 	"github.com/stretchr/testify/assert"
 )
 
@@ -361,8 +360,6 @@ func TestPruneToCheckConsistency(t *testing.T) {
 
 func BenchmarkPruneToFindConsistent(b *testing.B) {
 
-	log.SetLogger("BenchmarkPruneToFindConsistent", log.SILENT)
-
 	b.ResetTimer()
 	for i := uint64(0); i < uint64(b.N); i++ {
 		pruned := pruneToFindConsistent(0, i)
@@ -373,8 +370,6 @@ func BenchmarkPruneToFindConsistent(b *testing.B) {
 
 func BenchmarkPruneToCheckConsistency(b *testing.B) {
 
-	log.SetLogger("BenchmarkPruneToCheckConsistency", log.SILENT)
-
 	b.ResetTimer()
 	for i := uint64(0); i < uint64(b.N); i++ {
 		pruned := pruneToCheckConsistency(0, i)

balloon/history/insert_test.go

@@ -20,7 +20,6 @@ import (
 	"testing"
 
 	"github.com/bbva/qed/crypto/hashing"
-	"github.com/bbva/qed/log"
 	"github.com/bbva/qed/testutils/rand"
 	"github.com/stretchr/testify/assert"
 )
@@ -129,8 +128,6 @@ func TestPruneToInsert(t *testing.T) {
 
 func BenchmarkPruneToInsert(b *testing.B) {
 
-	log.SetLogger("BenchmarkPruneToInsert", log.SILENT)
-
 	b.ResetTimer()
 	for i := uint64(0); i < uint64(b.N); i++ {
 		pruned := pruneToInsert(i, rand.Bytes(32))

balloon/history/proof.go

@@ -23,7 +23,6 @@ import (
 	"strings"
 
 	"github.com/bbva/qed/crypto/hashing"
-	"github.com/bbva/qed/log"
 	"github.com/bbva/qed/util"
 )
 
@@ -76,8 +75,6 @@ func NewMembershipProof(index, version uint64, auditPath AuditPath, hasher hashi
 // Verify verifies a membership proof
 func (p MembershipProof) Verify(eventDigest []byte, expectedRootHash hashing.Digest) (correct bool) {
 
-	log.Debugf("Verifying membership proof for index %d and version %d", p.Index, p.Version)
-
 	// build a visitable pruned tree and then visit it to recompute root hash
 	visitor := newComputeHashVisitor(p.hasher, p.AuditPath)
 	recomputed := pruneToVerify(p.Index, p.Version, eventDigest).Accept(visitor)
@@ -102,8 +99,6 @@ func NewIncrementalProof(start, end uint64, auditPath AuditPath, hasher hashing.
 
 func (p IncrementalProof) Verify(startDigest, endDigest hashing.Digest) (correct bool) {
 
-	log.Debugf("Verifying incremental proof between versions %d and %d", p.StartVersion, p.EndVersion)
-
 	// build two visitable pruned trees and then visit them to recompute root hash
 	visitor := newComputeHashVisitor(p.hasher, p.AuditPath)
 	startRecomputed := pruneToVerifyIncrementalStart(p.StartVersion).Accept(visitor)

balloon/history/proof_test.go

@@ -20,7 +20,6 @@ import (
 	"testing"
 
 	"github.com/bbva/qed/crypto/hashing"
-	"github.com/bbva/qed/log"
 	"github.com/stretchr/testify/assert"
 )
 
@@ -104,8 +103,6 @@ func TestParseAuditPath(t *testing.T) {
 
 func TestVerifyMembershipProof(t *testing.T) {
 
-	log.SetLogger("TestVerifyMembershipProof", log.INFO)
-
 	testCases := []struct {
 		index, version uint64
 		auditPath      AuditPath
@@ -329,8 +326,6 @@ func TestVerifyMembershipProof(t *testing.T) {
 
 func TestVerifyIncrementalProof(t *testing.T) {
 
-	log.SetLogger("TestVerifyIncrementalProof", log.INFO)
-
 	testCases := []struct {
 		auditPath           AuditPath
 		start               uint64

balloon/history/search_test.go

@@ -19,7 +19,6 @@ package history
 import (
 	"testing"
 
-	"github.com/bbva/qed/log"
 	"github.com/stretchr/testify/assert"
 )
 
@@ -118,8 +117,6 @@ func TestPruneToFind(t *testing.T) {
 
 func BenchmarkPruneToFind(b *testing.B) {
 
-	log.SetLogger("BenchmarkPruneToFind", log.SILENT)
-
 	b.ResetTimer()
 	for i := uint64(0); i < uint64(b.N); i++ {
 		pruned := pruneToFind(i)

balloon/history/tree.go

@@ -22,6 +22,7 @@ package history
 import (
 	"github.com/bbva/qed/balloon/cache"
 	"github.com/bbva/qed/crypto/hashing"
+	"github.com/bbva/qed/log"
 	"github.com/bbva/qed/storage"
 )
 
@@ -30,9 +31,15 @@ type HistoryTree struct {
 	hasher     hashing.Hasher
 	writeCache cache.ModifiableCache
 	readCache  cache.Cache
+
+	log log.Logger
 }
 
 func NewHistoryTree(hasherF func() hashing.Hasher, store storage.Store, cacheSize uint16) *HistoryTree {
+	return NewHistoryTreeWithLogger(hasherF, store, cacheSize, log.L())
+}
+
+func NewHistoryTreeWithLogger(hasherF func() hashing.Hasher, store storage.Store, cacheSize uint16, logger log.Logger) *HistoryTree {
 
 	// create cache for Adding
 	writeCache := cache.NewLruReadThroughCache(storage.HistoryTable, store, cacheSize)
@@ -45,6 +52,7 @@ func NewHistoryTree(hasherF func() hashing.Hasher, store storage.Store, cacheSiz
 		hasher:     hasherF(),
 		writeCache: writeCache,
 		readCache:  readCache,
+		log:        logger,
 	}
 }
 
@@ -53,7 +61,7 @@ func NewHistoryTree(hasherF func() hashing.Hasher, store storage.Store, cacheSiz
 // with the storage mutations to be done at balloon level.
 func (t *HistoryTree) Add(eventDigest hashing.Digest, version uint64) (hashing.Digest, []*storage.Mutation, error) {
 
-	// log.Debugf("Adding new event digest %x with version %d", eventDigest, version)
+	// t.log.Tracef("Adding new event digest %x with version %d", eventDigest, version)
 
 	// build a visitable pruned tree and then visit it to generate the root hash
 	visitor := newInsertVisitor(t.hasher, t.writeCache, storage.HistoryTable)
@@ -82,7 +90,7 @@ func (t *HistoryTree) AddBulk(eventDigests []hashing.Digest, initialVersion uint
 // version. It builds an audit-path visitor to build the proof.
 func (t *HistoryTree) ProveMembership(index, version uint64) (*MembershipProof, error) {
 
-	//log.Debugf("Proving membership for index %d with version %d", index, version)
+	//t.log.Tracef("Proving membership for index %d with version %d", index, version)
 
 	// build a visitable pruned tree and then visit it to collect the audit path
 	visitor := newAuditPathVisitor(t.hasherF(), t.readCache)
@@ -100,7 +108,7 @@ func (t *HistoryTree) ProveMembership(index, version uint64) (*MembershipProof,
 // It builds an audit-path visitor to build the proof.
 func (t *HistoryTree) ProveConsistency(start, end uint64) (*IncrementalProof, error) {
 
-	//log.Debugf("Proving consistency between versions %d and %d", start, end)
+	//t.log.Tracef("Proving consistency between versions %d and %d", start, end)
 
 	// build a visitable pruned tree and then visit it to collect the audit path
 	visitor := newAuditPathVisitor(t.hasherF(), t.readCache)