core, log: track field length and pad to align

3 files changed, 32 insertions, 10 deletions

diff --git a/core/blockchain.go b/core/blockchain.go
index 27dbf6c6d..88ba76bc7 100644
--- a/core/blockchain.go
+++ b/core/blockchain.go
@@ -798,8 +798,8 @@ func (self *BlockChain) InsertReceiptChain(blockChain types.Blocks, receiptChain
 
 	// Report some public statistics so the user has a clue what's going on
 	last := blockChain[len(blockChain)-1]
-	log.Info("Imported new block receipts", "count", stats.processed, "number", last.Number(), "hash", last.Hash(),
-		"elapsed", common.PrettyDuration(time.Since(start)), "ignored", stats.ignored)
+	log.Info("Imported new block receipts", "count", stats.processed, "elapsed", common.PrettyDuration(time.Since(start)),
+		"number", last.Number(), "hash", last.Hash(), "ignored", stats.ignored)
 
 	return 0, nil
 }
@@ -1054,9 +1054,9 @@ func (st *insertStats) report(chain []*types.Block, index int) {
 			txs = countTransactions(chain[st.lastIndex : index+1])
 		)
 		context := []interface{}{
-			"blocks", st.processed, "number", end.Number(), "hash", end.Hash(), "txs", txs,
-			"mgas", float64(st.usedGas) / 1000000, "elapsed", common.PrettyDuration(elapsed),
-			"mgasps", float64(st.usedGas) * 1000 / float64(elapsed),
+			"blocks", st.processed, "txs", txs, "mgas", float64(st.usedGas) / 1000000,
+			"elapsed", common.PrettyDuration(elapsed), "mgasps", float64(st.usedGas) * 1000 / float64(elapsed),
+			"number", end.Number(), "hash", end.Hash(),
 		}
 		if st.queued > 0 {
 			context = append(context, []interface{}{"queued", st.queued}...)
diff --git a/core/headerchain.go b/core/headerchain.go
index 775321bc6..5f6073917 100644
--- a/core/headerchain.go
+++ b/core/headerchain.go
@@ -330,8 +330,8 @@ func (hc *HeaderChain) InsertHeaderChain(chain []*types.Header, checkFreq int, w
 	}
 	// Report some public statistics so the user has a clue what's going on
 	last := chain[len(chain)-1]
-	log.Info("Imported new block headers", "count", stats.processed, "number", last.Number, "hash", last.Hash(),
-		"elapsed", common.PrettyDuration(time.Since(start)), "ignored", stats.ignored)
+	log.Info("Imported new block headers", "count", stats.processed, "elapsed", common.PrettyDuration(time.Since(start)),
+		"number", last.Number, "hash", last.Hash(), "ignored", stats.ignored)
 
 	return 0, nil
 }
diff --git a/log/format.go b/log/format.go
index e8f4b4f24..c44ea8ed4 100644
--- a/log/format.go
+++ b/log/format.go
@@ -10,6 +10,7 @@ import (
 	"sync"
 	"sync/atomic"
 	"time"
+	"unicode/utf8"
 )
 
 const (
@@ -43,6 +44,13 @@ var locationEnabled uint32
 // padded to to aid in alignment.
 var locationLength uint32
 
+// fieldPadding is a global map with maximum field value lengths seen until now
+// to allow padding log contexts in a bit smarter way.
+var fieldPadding = make(map[string]int)
+
+// fieldPaddingLock is a global mutex protecting the field padding map.
+var fieldPaddingLock sync.RWMutex
+
 type Format interface {
 	Format(r *Record) []byte
 }
@@ -163,15 +171,29 @@ func logfmt(buf *bytes.Buffer, ctx []interface{}, color int, term bool) {
 		}
 
 		// XXX: we should probably check that all of your key bytes aren't invalid
+		fieldPaddingLock.RLock()
+		padding := fieldPadding[k]
+		fieldPaddingLock.RUnlock()
+
+		length := utf8.RuneCountInString(v)
+		if padding < length {
+			padding = length
+
+			fieldPaddingLock.Lock()
+			fieldPadding[k] = padding
+			fieldPaddingLock.Unlock()
+		}
 		if color > 0 {
-			fmt.Fprintf(buf, "\x1b[%dm%s\x1b[0m=%s", color, k, v)
+			fmt.Fprintf(buf, "\x1b[%dm%s\x1b[0m=", color, k)
 		} else {
 			buf.WriteString(k)
 			buf.WriteByte('=')
-			buf.WriteString(v)
+		}
+		buf.WriteString(v)
+		if i < len(ctx)-2 {
+			buf.Write(bytes.Repeat([]byte{' '}, padding-length))
 		}
 	}
-
 	buf.WriteByte('\n')
 }