Merge pull request #3696 from karalabe/contextual-logger

Contextual logger

5 files changed, 418 insertions, 13 deletions

diff --git a/vendor/github.com/ethereum/ethash/ethash.go b/vendor/github.com/ethereum/ethash/ethash.go
index 2a31aaf2d..8e5cd8128 100644
--- a/vendor/github.com/ethereum/ethash/ethash.go
+++ b/vendor/github.com/ethereum/ethash/ethash.go
@@ -42,8 +42,7 @@ import (
 
 	"github.com/ethereum/go-ethereum/common"
 	"github.com/ethereum/go-ethereum/crypto"
-	"github.com/ethereum/go-ethereum/logger"
-	"github.com/ethereum/go-ethereum/logger/glog"
+	"github.com/ethereum/go-ethereum/log"
 	"github.com/ethereum/go-ethereum/pow"
 )
 
@@ -89,14 +88,14 @@ func (cache *cache) generate() {
 	cache.gen.Do(func() {
 		started := time.Now()
 		seedHash := makeSeedHash(cache.epoch)
-		glog.V(logger.Debug).Infof("Generating cache for epoch %d (%x)", cache.epoch, seedHash)
+		log.Debug(fmt.Sprintf("Generating cache for epoch %d (%x)", cache.epoch, seedHash))
 		size := C.ethash_get_cachesize(C.uint64_t(cache.epoch * epochLength))
 		if cache.test {
 			size = cacheSizeForTesting
 		}
 		cache.ptr = C.ethash_light_new_internal(size, (*C.ethash_h256_t)(unsafe.Pointer(&seedHash[0])))
 		runtime.SetFinalizer(cache, freeCache)
-		glog.V(logger.Debug).Infof("Done generating cache for epoch %d, it took %v", cache.epoch, time.Since(started))
+		log.Debug(fmt.Sprintf("Done generating cache for epoch %d, it took %v", cache.epoch, time.Since(started)))
 	})
 }
 
@@ -132,7 +131,7 @@ func (l *Light) Verify(block pow.Block) bool {
 	// to prevent DOS attacks.
 	blockNum := block.NumberU64()
 	if blockNum >= epochLength*2048 {
-		glog.V(logger.Debug).Infof("block number %d too high, limit is %d", epochLength*2048)
+		log.Debug(fmt.Sprintf("block number %d too high, limit is %d", epochLength*2048))
 		return false
 	}
 
@@ -143,7 +142,7 @@ func (l *Light) Verify(block pow.Block) bool {
 	   Ethereum protocol consensus rules here which are not in scope of Ethash
 	*/
 	if difficulty.Cmp(common.Big0) == 0 {
-		glog.V(logger.Debug).Infof("invalid block difficulty")
+		log.Debug(fmt.Sprintf("invalid block difficulty"))
 		return false
 	}
 
@@ -198,22 +197,22 @@ func (l *Light) getCache(blockNum uint64) *cache {
 					evict = cache
 				}
 			}
-			glog.V(logger.Debug).Infof("Evicting DAG for epoch %d in favour of epoch %d", evict.epoch, epoch)
+			log.Debug(fmt.Sprintf("Evicting DAG for epoch %d in favour of epoch %d", evict.epoch, epoch))
 			delete(l.caches, evict.epoch)
 		}
 		// If we have the new DAG pre-generated, use that, otherwise create a new one
 		if l.future != nil && l.future.epoch == epoch {
-			glog.V(logger.Debug).Infof("Using pre-generated DAG for epoch %d", epoch)
+			log.Debug(fmt.Sprintf("Using pre-generated DAG for epoch %d", epoch))
 			c, l.future = l.future, nil
 		} else {
-			glog.V(logger.Debug).Infof("No pre-generated DAG available, creating new for epoch %d", epoch)
+			log.Debug(fmt.Sprintf("No pre-generated DAG available, creating new for epoch %d", epoch))
 			c = &cache{epoch: epoch, test: l.test}
 		}
 		l.caches[epoch] = c
 
 		// If we just used up the future cache, or need a refresh, regenerate
 		if l.future == nil || l.future.epoch <= epoch {
-			glog.V(logger.Debug).Infof("Pre-generating DAG for epoch %d", epoch+1)
+			log.Debug(fmt.Sprintf("Pre-generating DAG for epoch %d", epoch+1))
 			l.future = &cache{epoch: epoch + 1, test: l.test}
 			go l.future.generate()
 		}
@@ -256,7 +255,7 @@ func (d *dag) generate() {
 		if d.dir == "" {
 			d.dir = DefaultDir
 		}
-		glog.V(logger.Info).Infof("Generating DAG for epoch %d (size %d) (%x)", d.epoch, dagSize, seedHash)
+		log.Info(fmt.Sprintf("Generating DAG for epoch %d (size %d) (%x)", d.epoch, dagSize, seedHash))
 		// Generate a temporary cache.
 		// TODO: this could share the cache with Light
 		cache := C.ethash_light_new_internal(cacheSize, (*C.ethash_h256_t)(unsafe.Pointer(&seedHash[0])))
@@ -273,7 +272,7 @@ func (d *dag) generate() {
 			panic("ethash_full_new IO or memory error")
 		}
 		runtime.SetFinalizer(d, freeDAG)
-		glog.V(logger.Info).Infof("Done generating DAG for epoch %d, it took %v", d.epoch, time.Since(started))
+		log.Info(fmt.Sprintf("Done generating DAG for epoch %d, it took %v", d.epoch, time.Since(started)))
 	})
 }
 
@@ -288,7 +287,7 @@ func (d *dag) Ptr() unsafe.Pointer {
 
 //export ethashGoCallback
 func ethashGoCallback(percent C.unsigned) C.int {
-	glog.V(logger.Info).Infof("Generating DAG: %d%%", percent)
+	log.Info(fmt.Sprintf("Generating DAG: %d%%", percent))
 	return 0
 }
 
diff --git a/vendor/github.com/go-stack/stack/LICENSE.md b/vendor/github.com/go-stack/stack/LICENSE.md
new file mode 100644
index 000000000..c8ca66c5e
--- /dev/null
+++ b/vendor/github.com/go-stack/stack/LICENSE.md
@@ -0,0 +1,13 @@
+Copyright 2014 Chris Hines
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+   http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
diff --git a/vendor/github.com/go-stack/stack/README.md b/vendor/github.com/go-stack/stack/README.md
new file mode 100644
index 000000000..f11ccccaa
--- /dev/null
+++ b/vendor/github.com/go-stack/stack/README.md
@@ -0,0 +1,38 @@
+[![GoDoc](https://godoc.org/github.com/go-stack/stack?status.svg)](https://godoc.org/github.com/go-stack/stack)
+[![Go Report Card](https://goreportcard.com/badge/go-stack/stack)](https://goreportcard.com/report/go-stack/stack)
+[![TravisCI](https://travis-ci.org/go-stack/stack.svg?branch=master)](https://travis-ci.org/go-stack/stack)
+[![Coverage Status](https://coveralls.io/repos/github/go-stack/stack/badge.svg?branch=master)](https://coveralls.io/github/go-stack/stack?branch=master)
+
+# stack
+
+Package stack implements utilities to capture, manipulate, and format call
+stacks. It provides a simpler API than package runtime.
+
+The implementation takes care of the minutia and special cases of interpreting
+the program counter (pc) values returned by runtime.Callers.
+
+## Versioning
+
+Package stack publishes releases via [semver](http://semver.org/) compatible Git
+tags prefixed with a single 'v'. The master branch always contains the latest
+release. The develop branch contains unreleased commits.
+
+## Formatting
+
+Package stack's types implement fmt.Formatter, which provides a simple and
+flexible way to declaratively configure formatting when used with logging or
+error tracking packages.
+
+```go
+func DoTheThing() {
+    c := stack.Caller(0)
+    log.Print(c)          // "source.go:10"
+    log.Printf("%+v", c)  // "pkg/path/source.go:10"
+    log.Printf("%n", c)   // "DoTheThing"
+
+    s := stack.Trace().TrimRuntime()
+    log.Print(s)          // "[source.go:15 caller.go:42 main.go:14]"
+}
+```
+
+See the docs for all of the supported formatting options.
diff --git a/vendor/github.com/go-stack/stack/stack.go b/vendor/github.com/go-stack/stack/stack.go
new file mode 100644
index 000000000..a614eeebf
--- /dev/null
+++ b/vendor/github.com/go-stack/stack/stack.go
@@ -0,0 +1,349 @@
+// Package stack implements utilities to capture, manipulate, and format call
+// stacks. It provides a simpler API than package runtime.
+//
+// The implementation takes care of the minutia and special cases of
+// interpreting the program counter (pc) values returned by runtime.Callers.
+//
+// Package stack's types implement fmt.Formatter, which provides a simple and
+// flexible way to declaratively configure formatting when used with logging
+// or error tracking packages.
+package stack
+
+import (
+	"bytes"
+	"errors"
+	"fmt"
+	"io"
+	"runtime"
+	"strconv"
+	"strings"
+)
+
+// Call records a single function invocation from a goroutine stack.
+type Call struct {
+	fn *runtime.Func
+	pc uintptr
+}
+
+// Caller returns a Call from the stack of the current goroutine. The argument
+// skip is the number of stack frames to ascend, with 0 identifying the
+// calling function.
+func Caller(skip int) Call {
+	var pcs [2]uintptr
+	n := runtime.Callers(skip+1, pcs[:])
+
+	var c Call
+
+	if n < 2 {
+		return c
+	}
+
+	c.pc = pcs[1]
+	if runtime.FuncForPC(pcs[0]) != sigpanic {
+		c.pc--
+	}
+	c.fn = runtime.FuncForPC(c.pc)
+	return c
+}
+
+// String implements fmt.Stinger. It is equivalent to fmt.Sprintf("%v", c).
+func (c Call) String() string {
+	return fmt.Sprint(c)
+}
+
+// MarshalText implements encoding.TextMarshaler. It formats the Call the same
+// as fmt.Sprintf("%v", c).
+func (c Call) MarshalText() ([]byte, error) {
+	if c.fn == nil {
+		return nil, ErrNoFunc
+	}
+	buf := bytes.Buffer{}
+	fmt.Fprint(&buf, c)
+	return buf.Bytes(), nil
+}
+
+// ErrNoFunc means that the Call has a nil *runtime.Func. The most likely
+// cause is a Call with the zero value.
+var ErrNoFunc = errors.New("no call stack information")
+
+// Format implements fmt.Formatter with support for the following verbs.
+//
+//    %s    source file
+//    %d    line number
+//    %n    function name
+//    %v    equivalent to %s:%d
+//
+// It accepts the '+' and '#' flags for most of the verbs as follows.
+//
+//    %+s   path of source file relative to the compile time GOPATH
+//    %#s   full path of source file
+//    %+n   import path qualified function name
+//    %+v   equivalent to %+s:%d
+//    %#v   equivalent to %#s:%d
+func (c Call) Format(s fmt.State, verb rune) {
+	if c.fn == nil {
+		fmt.Fprintf(s, "%%!%c(NOFUNC)", verb)
+		return
+	}
+
+	switch verb {
+	case 's', 'v':
+		file, line := c.fn.FileLine(c.pc)
+		switch {
+		case s.Flag('#'):
+			// done
+		case s.Flag('+'):
+			file = file[pkgIndex(file, c.fn.Name()):]
+		default:
+			const sep = "/"
+			if i := strings.LastIndex(file, sep); i != -1 {
+				file = file[i+len(sep):]
+			}
+		}
+		io.WriteString(s, file)
+		if verb == 'v' {
+			buf := [7]byte{':'}
+			s.Write(strconv.AppendInt(buf[:1], int64(line), 10))
+		}
+
+	case 'd':
+		_, line := c.fn.FileLine(c.pc)
+		buf := [6]byte{}
+		s.Write(strconv.AppendInt(buf[:0], int64(line), 10))
+
+	case 'n':
+		name := c.fn.Name()
+		if !s.Flag('+') {
+			const pathSep = "/"
+			if i := strings.LastIndex(name, pathSep); i != -1 {
+				name = name[i+len(pathSep):]
+			}
+			const pkgSep = "."
+			if i := strings.Index(name, pkgSep); i != -1 {
+				name = name[i+len(pkgSep):]
+			}
+		}
+		io.WriteString(s, name)
+	}
+}
+
+// PC returns the program counter for this call frame; multiple frames may
+// have the same PC value.
+func (c Call) PC() uintptr {
+	return c.pc
+}
+
+// name returns the import path qualified name of the function containing the
+// call.
+func (c Call) name() string {
+	if c.fn == nil {
+		return "???"
+	}
+	return c.fn.Name()
+}
+
+func (c Call) file() string {
+	if c.fn == nil {
+		return "???"
+	}
+	file, _ := c.fn.FileLine(c.pc)
+	return file
+}
+
+func (c Call) line() int {
+	if c.fn == nil {
+		return 0
+	}
+	_, line := c.fn.FileLine(c.pc)
+	return line
+}
+
+// CallStack records a sequence of function invocations from a goroutine
+// stack.
+type CallStack []Call
+
+// String implements fmt.Stinger. It is equivalent to fmt.Sprintf("%v", cs).
+func (cs CallStack) String() string {
+	return fmt.Sprint(cs)
+}
+
+var (
+	openBracketBytes  = []byte("[")
+	closeBracketBytes = []byte("]")
+	spaceBytes        = []byte(" ")
+)
+
+// MarshalText implements encoding.TextMarshaler. It formats the CallStack the
+// same as fmt.Sprintf("%v", cs).
+func (cs CallStack) MarshalText() ([]byte, error) {
+	buf := bytes.Buffer{}
+	buf.Write(openBracketBytes)
+	for i, pc := range cs {
+		if pc.fn == nil {
+			return nil, ErrNoFunc
+		}
+		if i > 0 {
+			buf.Write(spaceBytes)
+		}
+		fmt.Fprint(&buf, pc)
+	}
+	buf.Write(closeBracketBytes)
+	return buf.Bytes(), nil
+}
+
+// Format implements fmt.Formatter by printing the CallStack as square brackets
+// ([, ]) surrounding a space separated list of Calls each formatted with the
+// supplied verb and options.
+func (cs CallStack) Format(s fmt.State, verb rune) {
+	s.Write(openBracketBytes)
+	for i, pc := range cs {
+		if i > 0 {
+			s.Write(spaceBytes)
+		}
+		pc.Format(s, verb)
+	}
+	s.Write(closeBracketBytes)
+}
+
+// findSigpanic intentionally executes faulting code to generate a stack trace
+// containing an entry for runtime.sigpanic.
+func findSigpanic() *runtime.Func {
+	var fn *runtime.Func
+	var p *int
+	func() int {
+		defer func() {
+			if p := recover(); p != nil {
+				var pcs [512]uintptr
+				n := runtime.Callers(2, pcs[:])
+				for _, pc := range pcs[:n] {
+					f := runtime.FuncForPC(pc)
+					if f.Name() == "runtime.sigpanic" {
+						fn = f
+						break
+					}
+				}
+			}
+		}()
+		// intentional nil pointer dereference to trigger sigpanic
+		return *p
+	}()
+	return fn
+}
+
+var sigpanic = findSigpanic()
+
+// Trace returns a CallStack for the current goroutine with element 0
+// identifying the calling function.
+func Trace() CallStack {
+	var pcs [512]uintptr
+	n := runtime.Callers(2, pcs[:])
+	cs := make([]Call, n)
+
+	for i, pc := range pcs[:n] {
+		pcFix := pc
+		if i > 0 && cs[i-1].fn != sigpanic {
+			pcFix--
+		}
+		cs[i] = Call{
+			fn: runtime.FuncForPC(pcFix),
+			pc: pcFix,
+		}
+	}
+
+	return cs
+}
+
+// TrimBelow returns a slice of the CallStack with all entries below c
+// removed.
+func (cs CallStack) TrimBelow(c Call) CallStack {
+	for len(cs) > 0 && cs[0].pc != c.pc {
+		cs = cs[1:]
+	}
+	return cs
+}
+
+// TrimAbove returns a slice of the CallStack with all entries above c
+// removed.
+func (cs CallStack) TrimAbove(c Call) CallStack {
+	for len(cs) > 0 && cs[len(cs)-1].pc != c.pc {
+		cs = cs[:len(cs)-1]
+	}
+	return cs
+}
+
+// pkgIndex returns the index that results in file[index:] being the path of
+// file relative to the compile time GOPATH, and file[:index] being the
+// $GOPATH/src/ portion of file. funcName must be the name of a function in
+// file as returned by runtime.Func.Name.
+func pkgIndex(file, funcName string) int {
+	// As of Go 1.6.2 there is no direct way to know the compile time GOPATH
+	// at runtime, but we can infer the number of path segments in the GOPATH.
+	// We note that runtime.Func.Name() returns the function name qualified by
+	// the import path, which does not include the GOPATH. Thus we can trim
+	// segments from the beginning of the file path until the number of path
+	// separators remaining is one more than the number of path separators in
+	// the function name. For example, given:
+	//
+	//    GOPATH     /home/user
+	//    file       /home/user/src/pkg/sub/file.go
+	//    fn.Name()  pkg/sub.Type.Method
+	//
+	// We want to produce:
+	//
+	//    file[:idx] == /home/user/src/
+	//    file[idx:] == pkg/sub/file.go
+	//
+	// From this we can easily see that fn.Name() has one less path separator
+	// than our desired result for file[idx:]. We count separators from the
+	// end of the file path until it finds two more than in the function name
+	// and then move one character forward to preserve the initial path
+	// segment without a leading separator.
+	const sep = "/"
+	i := len(file)
+	for n := strings.Count(funcName, sep) + 2; n > 0; n-- {
+		i = strings.LastIndex(file[:i], sep)
+		if i == -1 {
+			i = -len(sep)
+			break
+		}
+	}
+	// get back to 0 or trim the leading separator
+	return i + len(sep)
+}
+
+var runtimePath string
+
+func init() {
+	var pcs [1]uintptr
+	runtime.Callers(0, pcs[:])
+	fn := runtime.FuncForPC(pcs[0])
+	file, _ := fn.FileLine(pcs[0])
+
+	idx := pkgIndex(file, fn.Name())
+
+	runtimePath = file[:idx]
+	if runtime.GOOS == "windows" {
+		runtimePath = strings.ToLower(runtimePath)
+	}
+}
+
+func inGoroot(c Call) bool {
+	file := c.file()
+	if len(file) == 0 || file[0] == '?' {
+		return true
+	}
+	if runtime.GOOS == "windows" {
+		file = strings.ToLower(file)
+	}
+	return strings.HasPrefix(file, runtimePath) || strings.HasSuffix(file, "/_testmain.go")
+}
+
+// TrimRuntime returns a slice of the CallStack with the topmost entries from
+// the go runtime removed. It considers any calls originating from unknown
+// files, files under GOROOT, or _testmain.go as part of the runtime.
+func (cs CallStack) TrimRuntime() CallStack {
+	for len(cs) > 0 && inGoroot(cs[len(cs)-1]) {
+		cs = cs[:len(cs)-1]
+	}
+	return cs
+}
diff --git a/vendor/vendor.json b/vendor/vendor.json
index e19d011f1..eda007745 100644
--- a/vendor/vendor.json
+++ b/vendor/vendor.json
@@ -53,6 +53,12 @@
 			"revisionTime": "2017-01-17T22:23:42Z"
 		},
 		{
+			"checksumSHA1": "2sj/DbXoXdnPAfjAEyhS0Jj5QL0=",
+			"path": "github.com/go-stack/stack",
+			"revision": "100eb0c0a9c5b306ca2fb4f165df21d80ada4b82",
+			"revisionTime": "2016-05-14T03:44:11Z"
+		},
+		{
 			"checksumSHA1": "p/8vSviYF91gFflhrt5vkyksroo=",
 			"path": "github.com/golang/snappy",
 			"revision": "553a641470496b2327abcac10b36396bd98e45c9",