Logger updates 3 (#3730)

* accounts, cmd, eth, ethdb: port logs over to new system

* ethdb: drop concept of cache distribution between dbs

* eth: fix some log nitpicks to make them nicer

9 files changed, 56 insertions, 60 deletions

diff --git a/cmd/geth/chaincmd.go b/cmd/geth/chaincmd.go
index 1c21c4ded..784692261 100644
--- a/cmd/geth/chaincmd.go
+++ b/cmd/geth/chaincmd.go
@@ -117,7 +117,7 @@ func initGenesis(ctx *cli.Context) error {
 	if err != nil {
 		utils.Fatalf("failed to write genesis block: %v", err)
 	}
-	log.Info(fmt.Sprintf("successfully wrote genesis block and/or chain rule set: %x", block.Hash()))
+	log.Info("Successfully wrote genesis state", "hash", block.Hash())
 	return nil
 }
 
diff --git a/cmd/geth/main.go b/cmd/geth/main.go
index fa61f7386..79893cc04 100644
--- a/cmd/geth/main.go
+++ b/cmd/geth/main.go
@@ -29,6 +29,7 @@ import (
 	"github.com/ethereum/go-ethereum/accounts/keystore"
 	"github.com/ethereum/go-ethereum/cmd/utils"
 	"github.com/ethereum/go-ethereum/common"
+	"github.com/ethereum/go-ethereum/common/hexutil"
 	"github.com/ethereum/go-ethereum/console"
 	"github.com/ethereum/go-ethereum/contracts/release"
 	"github.com/ethereum/go-ethereum/eth"
@@ -202,11 +203,10 @@ func makeFullNode(ctx *cli.Context) *node.Node {
 	}{uint(params.VersionMajor<<16 | params.VersionMinor<<8 | params.VersionPatch), clientIdentifier, runtime.Version(), runtime.GOOS}
 	extra, err := rlp.EncodeToBytes(clientInfo)
 	if err != nil {
-		log.Warn(fmt.Sprint("error setting canonical miner information:", err))
+		log.Warn("Failed to set canonical miner information", "err", err)
 	}
 	if uint64(len(extra)) > params.MaximumExtraDataSize {
-		log.Warn(fmt.Sprint("error setting canonical miner information: extra exceeds", params.MaximumExtraDataSize))
-		log.Debug(fmt.Sprintf("extra: %x\n", extra))
+		log.Warn("Miner extra data exceed limit", "extra", hexutil.Bytes(extra), "limit", params.MaximumExtraDataSize)
 		extra = nil
 	}
 	stack := utils.MakeNode(ctx, clientIdentifier, gitCommit)
@@ -271,7 +271,7 @@ func startNode(ctx *cli.Context, stack *node.Node) {
 		// Open and self derive any wallets already attached
 		for _, wallet := range stack.AccountManager().Wallets() {
 			if err := wallet.Open(""); err != nil {
-				log.Warn(fmt.Sprintf("Failed to open wallet %s: %v", wallet.URL(), err))
+				log.Warn("Failed to open wallet", "url", wallet.URL(), "err", err)
 			} else {
 				wallet.SelfDerive(accounts.DefaultBaseDerivationPath, stateReader)
 			}
@@ -280,13 +280,13 @@ func startNode(ctx *cli.Context, stack *node.Node) {
 		for event := range events {
 			if event.Arrive {
 				if err := event.Wallet.Open(""); err != nil {
-					log.Info(fmt.Sprintf("New wallet appeared: %s, failed to open: %s", event.Wallet.URL(), err))
+					log.Warn("New wallet appeared, failed to open", "url", event.Wallet.URL(), "err", err)
 				} else {
-					log.Info(fmt.Sprintf("New wallet appeared: %s, %s", event.Wallet.URL(), event.Wallet.Status()))
+					log.Info("New wallet appeared", "url", event.Wallet.URL(), "status", event.Wallet.Status())
 					event.Wallet.SelfDerive(accounts.DefaultBaseDerivationPath, stateReader)
 				}
 			} else {
-				log.Info(fmt.Sprintf("Old wallet dropped:  %s", event.Wallet.URL()))
+				log.Info("Old wallet dropped", "url", event.Wallet.URL())
 				event.Wallet.Close()
 			}
 		}
diff --git a/cmd/swarm/cleandb.go b/cmd/swarm/cleandb.go
index 81636ada5..29d01ba0f 100644
--- a/cmd/swarm/cleandb.go
+++ b/cmd/swarm/cleandb.go
@@ -17,8 +17,7 @@
 package main
 
 import (
-	"log"
-
+	"github.com/ethereum/go-ethereum/cmd/utils"
 	"github.com/ethereum/go-ethereum/swarm/storage"
 	"gopkg.in/urfave/cli.v1"
 )
@@ -26,14 +25,14 @@ import (
 func cleandb(ctx *cli.Context) {
 	args := ctx.Args()
 	if len(args) != 1 {
-		log.Fatal("need path to chunks database as the first and only argument")
+		utils.Fatalf("Need path to chunks database as the first and only argument")
 	}
 
 	chunkDbPath := args[0]
 	hash := storage.MakeHashFunc("SHA3")
 	dbStore, err := storage.NewDbStore(chunkDbPath, hash, 10000000, 0)
 	if err != nil {
-		log.Fatalf("cannot initialise dbstore: %v", err)
+		utils.Fatalf("Cannot initialise dbstore: %v", err)
 	}
 	dbStore.Cleanup()
 }
diff --git a/cmd/swarm/hash.go b/cmd/swarm/hash.go
index bcba77a2a..792e8d0d7 100644
--- a/cmd/swarm/hash.go
+++ b/cmd/swarm/hash.go
@@ -19,9 +19,9 @@ package main
 
 import (
 	"fmt"
-	"log"
 	"os"
 
+	"github.com/ethereum/go-ethereum/cmd/utils"
 	"github.com/ethereum/go-ethereum/swarm/storage"
 	"gopkg.in/urfave/cli.v1"
 )
@@ -29,12 +29,11 @@ import (
 func hash(ctx *cli.Context) {
 	args := ctx.Args()
 	if len(args) < 1 {
-		log.Fatal("Usage: swarm hash <file name>")
+		utils.Fatalf("Usage: swarm hash <file name>")
 	}
 	f, err := os.Open(args[0])
 	if err != nil {
-		fmt.Println("Error opening file " + args[1])
-		os.Exit(1)
+		utils.Fatalf("Error opening file " + args[1])
 	}
 	defer f.Close()
 
@@ -42,7 +41,7 @@ func hash(ctx *cli.Context) {
 	chunker := storage.NewTreeChunker(storage.NewChunkerParams())
 	key, err := chunker.Split(f, stat.Size(), nil, nil, nil)
 	if err != nil {
-		log.Fatalf("%v\n", err)
+		utils.Fatalf("%v\n", err)
 	} else {
 		fmt.Printf("%v\n", key)
 	}
diff --git a/cmd/swarm/main.go b/cmd/swarm/main.go
index 12cad328f..171677146 100644
--- a/cmd/swarm/main.go
+++ b/cmd/swarm/main.go
@@ -277,7 +277,7 @@ func bzzd(ctx *cli.Context) error {
 		signal.Notify(sigc, syscall.SIGTERM)
 		defer signal.Stop(sigc)
 		<-sigc
-		log.Info(fmt.Sprint("Got sigterm, shutting down..."))
+		log.Info("Got sigterm, shutting swarm down...")
 		stack.Stop()
 	}()
 	networkId := ctx.GlobalUint64(SwarmNetworkIdFlag.Name)
@@ -342,7 +342,7 @@ func getAccount(ctx *cli.Context, stack *node.Node) *ecdsa.PrivateKey {
 	}
 	// Try to load the arg as a hex key file.
 	if key, err := crypto.LoadECDSA(keyid); err == nil {
-		log.Info(fmt.Sprintf("swarm account key loaded: %#x", crypto.PubkeyToAddress(key.PublicKey)))
+		log.Info("Swarm account key loaded", "address", crypto.PubkeyToAddress(key.PublicKey))
 		return key
 	}
 	// Otherwise try getting it from the keystore.
@@ -399,7 +399,7 @@ func injectBootnodes(srv *p2p.Server, nodes []string) {
 	for _, url := range nodes {
 		n, err := discover.ParseNode(url)
 		if err != nil {
-			log.Error(fmt.Sprintf("invalid bootnode %q", err))
+			log.Error("Invalid swarm bootnode", "err", err)
 			continue
 		}
 		srv.AddPeer(n)
diff --git a/cmd/swarm/manifest.go b/cmd/swarm/manifest.go
index f64792689..2b6b02313 100644
--- a/cmd/swarm/manifest.go
+++ b/cmd/swarm/manifest.go
@@ -20,19 +20,18 @@ package main
 import (
 	"encoding/json"
 	"fmt"
-	"log"
 	"mime"
 	"path/filepath"
 	"strings"
 
+	"github.com/ethereum/go-ethereum/cmd/utils"
 	"gopkg.in/urfave/cli.v1"
 )
 
 func add(ctx *cli.Context) {
-
 	args := ctx.Args()
 	if len(args) < 3 {
-		log.Fatal("need atleast three arguments <MHASH> <path> <HASH> [<content-type>]")
+		utils.Fatalf("Need atleast three arguments <MHASH> <path> <HASH> [<content-type>]")
 	}
 
 	var (
@@ -66,7 +65,7 @@ func update(ctx *cli.Context) {
 
 	args := ctx.Args()
 	if len(args) < 3 {
-		log.Fatal("need atleast three arguments <MHASH> <path> <HASH>")
+		utils.Fatalf("Need atleast three arguments <MHASH> <path> <HASH>")
 	}
 
 	var (
@@ -98,7 +97,7 @@ func update(ctx *cli.Context) {
 func remove(ctx *cli.Context) {
 	args := ctx.Args()
 	if len(args) < 2 {
-		log.Fatal("need atleast two arguments <MHASH> <path>")
+		utils.Fatalf("Need atleast two arguments <MHASH> <path>")
 	}
 
 	var (
@@ -134,19 +133,19 @@ func addEntryToManifest(ctx *cli.Context, mhash, path, hash, ctype string) strin
 
 	mroot, err := client.downloadManifest(mhash)
 	if err != nil {
-		log.Fatalln("manifest download failed:", err)
+		utils.Fatalf("Manifest download failed: %v", err)
 	}
 
 	//TODO: check if the "hash" to add is valid and present in swarm
 	_, err = client.downloadManifest(hash)
 	if err != nil {
-		log.Fatalln("hash to add is not present:", err)
+		utils.Fatalf("Hash to add is not present: %v", err)
 	}
 
 	// See if we path is in this Manifest or do we have to dig deeper
 	for _, entry := range mroot.Entries {
 		if path == entry.Path {
-			log.Fatal(path, "Already present, not adding anything")
+			utils.Fatalf("Path %s already present, not adding anything", path)
 		} else {
 			if entry.ContentType == "application/bzz-manifest+json" {
 				prfxlen := strings.HasPrefix(path, entry.Path)
@@ -183,7 +182,7 @@ func addEntryToManifest(ctx *cli.Context, mhash, path, hash, ctype string) strin
 
 	newManifestHash, err := client.uploadManifest(mroot)
 	if err != nil {
-		log.Fatalln("manifest upload failed:", err)
+		utils.Fatalf("Manifest upload failed: %v", err)
 	}
 	return newManifestHash
 
@@ -208,7 +207,7 @@ func updateEntryInManifest(ctx *cli.Context, mhash, path, hash, ctype string) st
 
 	mroot, err := client.downloadManifest(mhash)
 	if err != nil {
-		log.Fatalln("manifest download failed:", err)
+		utils.Fatalf("Manifest download failed: %v", err)
 	}
 
 	//TODO: check if the "hash" with which to update is valid and present in swarm
@@ -228,7 +227,7 @@ func updateEntryInManifest(ctx *cli.Context, mhash, path, hash, ctype string) st
 	}
 
 	if longestPathEntry.Path == "" && newEntry.Path == "" {
-		log.Fatal(path, " Path not present in the Manifest, not setting anything")
+		utils.Fatalf("Path %s not present in the Manifest, not setting anything", path)
 	}
 
 	if longestPathEntry.Path != "" {
@@ -268,7 +267,7 @@ func updateEntryInManifest(ctx *cli.Context, mhash, path, hash, ctype string) st
 
 	newManifestHash, err := client.uploadManifest(mroot)
 	if err != nil {
-		log.Fatalln("manifest upload failed:", err)
+		utils.Fatalf("Manifest upload failed: %v", err)
 	}
 	return newManifestHash
 }
@@ -292,7 +291,7 @@ func removeEntryFromManifest(ctx *cli.Context, mhash, path string) string {
 
 	mroot, err := client.downloadManifest(mhash)
 	if err != nil {
-		log.Fatalln("manifest download failed:", err)
+		utils.Fatalf("Manifest download failed: %v", err)
 	}
 
 	// See if we path is in this Manifest or do we have to dig deeper
@@ -310,7 +309,7 @@ func removeEntryFromManifest(ctx *cli.Context, mhash, path string) string {
 	}
 
 	if longestPathEntry.Path == "" && entryToRemove.Path == "" {
-		log.Fatal(path, "Path not present in the Manifest, not removing anything")
+		utils.Fatalf("Path %s not present in the Manifest, not removing anything", path)
 	}
 
 	if longestPathEntry.Path != "" {
@@ -342,8 +341,7 @@ func removeEntryFromManifest(ctx *cli.Context, mhash, path string) string {
 
 	newManifestHash, err := client.uploadManifest(mroot)
 	if err != nil {
-		log.Fatalln("manifest upload failed:", err)
+		utils.Fatalf("Manifest upload failed: %v", err)
 	}
 	return newManifestHash
-
 }
diff --git a/cmd/swarm/upload.go b/cmd/swarm/upload.go
index 9f3a2abe0..7b4961778 100644
--- a/cmd/swarm/upload.go
+++ b/cmd/swarm/upload.go
@@ -23,7 +23,6 @@ import (
 	"fmt"
 	"io"
 	"io/ioutil"
-	"log"
 	"mime"
 	"net/http"
 	"os"
@@ -32,6 +31,8 @@ import (
 	"path/filepath"
 	"strings"
 
+	"github.com/ethereum/go-ethereum/cmd/utils"
+	"github.com/ethereum/go-ethereum/log"
 	"gopkg.in/urfave/cli.v1"
 )
 
@@ -44,7 +45,7 @@ func upload(ctx *cli.Context) {
 		defaultPath  = ctx.GlobalString(SwarmUploadDefaultPath.Name)
 	)
 	if len(args) != 1 {
-		log.Fatal("need filename as the first and only argument")
+		utils.Fatalf("Need filename as the first and only argument")
 	}
 
 	var (
@@ -53,25 +54,25 @@ func upload(ctx *cli.Context) {
 	)
 	fi, err := os.Stat(expandPath(file))
 	if err != nil {
-		log.Fatal(err)
+		utils.Fatalf("Failed to stat file: %v", err)
 	}
 	if fi.IsDir() {
 		if !recursive {
-			log.Fatal("argument is a directory and recursive upload is disabled")
+			utils.Fatalf("Argument is a directory and recursive upload is disabled")
 		}
 		if !wantManifest {
-			log.Fatal("manifest is required for directory uploads")
+			utils.Fatalf("Manifest is required for directory uploads")
 		}
 		mhash, err := client.uploadDirectory(file, defaultPath)
 		if err != nil {
-			log.Fatal(err)
+			utils.Fatalf("Failed to upload directory: %v", err)
 		}
 		fmt.Println(mhash)
 		return
 	}
 	entry, err := client.uploadFile(file, fi)
 	if err != nil {
-		log.Fatalln("upload failed:", err)
+		utils.Fatalf("Upload failed: %v", err)
 	}
 	mroot := manifest{[]manifestEntry{entry}}
 	if !wantManifest {
@@ -82,7 +83,7 @@ func upload(ctx *cli.Context) {
 	}
 	hash, err := client.uploadManifest(mroot)
 	if err != nil {
-		log.Fatalln("manifest upload failed:", err)
+		utils.Fatalf("Manifest upload failed: %v", err)
 	}
 	fmt.Println(hash)
 }
@@ -173,7 +174,7 @@ func (c *client) uploadFileContent(file string, fi os.FileInfo) (string, error)
 		return "", err
 	}
 	defer fd.Close()
-	log.Printf("uploading file %s (%d bytes)", file, fi.Size())
+	log.Info("Uploading swarm content", "file", file, "bytes", fi.Size())
 	return c.postRaw("application/octet-stream", fi.Size(), fd)
 }
 
@@ -182,7 +183,7 @@ func (c *client) uploadManifest(m manifest) (string, error) {
 	if err != nil {
 		panic(err)
 	}
-	log.Println("uploading manifest")
+	log.Info("Uploading swarm manifest")
 	return c.postRaw("application/json", int64(len(jsm)), ioutil.NopCloser(bytes.NewReader(jsm)))
 }
 
@@ -192,7 +193,7 @@ func (c *client) uploadToManifest(mhash string, path string, fpath string, fi os
 		return "", err
 	}
 	defer fd.Close()
-	log.Printf("uploading file %s (%d bytes) and adding path %v", fpath, fi.Size(), path)
+	log.Info("Uploading swarm content and path", "file", fpath, "bytes", fi.Size(), "path", path)
 	req, err := http.NewRequest("PUT", c.api+"/bzz:/"+mhash+"/"+path, fd)
 	if err != nil {
 		return "", err
diff --git a/cmd/utils/cmd.go b/cmd/utils/cmd.go
index 843cb5b4e..17c258c6c 100644
--- a/cmd/utils/cmd.go
+++ b/cmd/utils/cmd.go
@@ -67,12 +67,12 @@ func StartNode(stack *node.Node) {
 		signal.Notify(sigc, os.Interrupt)
 		defer signal.Stop(sigc)
 		<-sigc
-		log.Info(fmt.Sprint("Got interrupt, shutting down..."))
+		log.Info("Got interrupt, shutting down...")
 		go stack.Stop()
 		for i := 10; i > 0; i-- {
 			<-sigc
 			if i > 1 {
-				log.Info(fmt.Sprintf("Already shutting down, interrupt %d more times for panic.", i-1))
+				log.Warn("Already shutting down, interrupt more to panic.", "times", i-1)
 			}
 		}
 		debug.Exit() // ensure trace and CPU profile data is flushed.
@@ -90,7 +90,7 @@ func ImportChain(chain *core.BlockChain, fn string) error {
 	defer close(interrupt)
 	go func() {
 		if _, ok := <-interrupt; ok {
-			log.Info(fmt.Sprint("caught interrupt during import, will stop at next batch"))
+			log.Info("Interrupted during import, stopping at next batch")
 		}
 		close(stop)
 	}()
@@ -103,7 +103,7 @@ func ImportChain(chain *core.BlockChain, fn string) error {
 		}
 	}
 
-	log.Info(fmt.Sprint("Importing blockchain ", fn))
+	log.Info("Importing blockchain", "file", fn)
 	fh, err := os.Open(fn)
 	if err != nil {
 		return err
@@ -151,8 +151,7 @@ func ImportChain(chain *core.BlockChain, fn string) error {
 			return fmt.Errorf("interrupted")
 		}
 		if hasAllBlocks(chain, blocks[:i]) {
-			log.Info(fmt.Sprintf("skipping batch %d, all blocks present [%x / %x]",
-				batch, blocks[0].Hash().Bytes()[:4], blocks[i-1].Hash().Bytes()[:4]))
+			log.Info("Skipping batch as all blocks present", "batch", batch, "first", blocks[0].Hash(), "last", blocks[i-1].Hash())
 			continue
 		}
 
@@ -173,7 +172,7 @@ func hasAllBlocks(chain *core.BlockChain, bs []*types.Block) bool {
 }
 
 func ExportChain(blockchain *core.BlockChain, fn string) error {
-	log.Info(fmt.Sprint("Exporting blockchain to ", fn))
+	log.Info("Exporting blockchain", "file", fn)
 	fh, err := os.OpenFile(fn, os.O_CREATE|os.O_WRONLY|os.O_TRUNC, os.ModePerm)
 	if err != nil {
 		return err
@@ -189,13 +188,13 @@ func ExportChain(blockchain *core.BlockChain, fn string) error {
 	if err := blockchain.Export(writer); err != nil {
 		return err
 	}
-	log.Info(fmt.Sprint("Exported blockchain to ", fn))
+	log.Info("Exported blockchain", "file", fn)
 
 	return nil
 }
 
 func ExportAppendChain(blockchain *core.BlockChain, fn string, first uint64, last uint64) error {
-	log.Info(fmt.Sprint("Exporting blockchain to ", fn))
+	log.Info("Exporting blockchain", "file", fn)
 	// TODO verify mode perms
 	fh, err := os.OpenFile(fn, os.O_CREATE|os.O_APPEND|os.O_WRONLY, os.ModePerm)
 	if err != nil {
@@ -212,6 +211,6 @@ func ExportAppendChain(blockchain *core.BlockChain, fn string, first uint64, las
 	if err := blockchain.ExportN(writer, first, last); err != nil {
 		return err
 	}
-	log.Info(fmt.Sprint("Exported blockchain to ", fn))
+	log.Info("Exported blockchain to", "file", fn)
 	return nil
 }
diff --git a/cmd/utils/flags.go b/cmd/utils/flags.go
index a586ffeb3..adc18a203 100644
--- a/cmd/utils/flags.go
+++ b/cmd/utils/flags.go
@@ -492,7 +492,7 @@ func MakeBootstrapNodes(ctx *cli.Context) []*discover.Node {
 	for _, url := range urls {
 		node, err := discover.ParseNode(url)
 		if err != nil {
-			log.Error(fmt.Sprintf("Bootstrap URL %s: %v\n", url, err))
+			log.Error("Bootstrap URL invalid", "enode", url, "err", err)
 			continue
 		}
 		bootnodes = append(bootnodes, node)
@@ -512,7 +512,7 @@ func MakeBootstrapNodesV5(ctx *cli.Context) []*discv5.Node {
 	for _, url := range urls {
 		node, err := discv5.ParseNode(url)
 		if err != nil {
-			log.Error(fmt.Sprintf("Bootstrap URL %s: %v\n", url, err))
+			log.Error("Bootstrap URL invalid", "enode", url, "err", err)
 			continue
 		}
 		bootnodes = append(bootnodes, node)
@@ -609,7 +609,7 @@ func MakeAddress(ks *keystore.KeyStore, account string) (accounts.Account, error
 func MakeEtherbase(ks *keystore.KeyStore, ctx *cli.Context) common.Address {
 	accounts := ks.Accounts()
 	if !ctx.GlobalIsSet(EtherbaseFlag.Name) && len(accounts) == 0 {
-		log.Error(fmt.Sprint("WARNING: No etherbase set and no accounts found as default"))
+		log.Warn("No etherbase set and no accounts found as default")
 		return common.Address{}
 	}
 	etherbase := ctx.GlobalString(EtherbaseFlag.Name)