OSDN Git Service

Optimize log printing (#1590)
authoryahtoo <yahtoo.ma@gmail.com>
Wed, 27 Feb 2019 03:09:59 +0000 (11:09 +0800)
committerPaladz <yzhu101@uottawa.ca>
Wed, 27 Feb 2019 03:09:59 +0000 (11:09 +0800)
42 files changed:
account/accounts.go
account/image.go
account/utxo_keeper.go
api/api.go
api/txfeeds.go
blockchain/pseudohsm/image.go
blockchain/pseudohsm/keycache.go
blockchain/txbuilder/rawtxsig_witness.go
blockchain/txbuilder/signature_witness.go
blockchain/txbuilder/txbuilder.go
blockchain/txfeed/txfeed.go
cmd/bytomd/commands/init.go
cmd/bytomd/commands/run_node.go
mining/cpuminer/cpuminer.go
mining/mining.go
net/http/httpjson/io.go
net/http/reqid/reqid.go
netsync/handle.go
netsync/peer.go
node/node.go
p2p/connection/connection.go
p2p/discover/database.go
p2p/discover/net.go
p2p/discover/ntp.go
p2p/discover/table.go
p2p/discover/ticket.go
p2p/discover/topic.go
p2p/discover/udp.go
p2p/listener.go
p2p/peer.go
p2p/switch.go
protocol/block.go
protocol/orphan_manage.go
protocol/protocol.go
protocol/tx.go
protocol/txpool.go
version/version.go
wallet/annotated.go
wallet/indexer.go
wallet/unconfirmed.go
wallet/utxo.go
wallet/wallet.go

index 6325a66..8e89273 100644 (file)
@@ -32,6 +32,7 @@ const (
        // HardenedKeyStart bip32 hierarchical deterministic wallets
        // keys with index ≥ 0x80000000 are hardened keys
        HardenedKeyStart = 0x80000000
+       logModule        = "account"
 )
 
 var (
index 0a7b115..3562c5e 100644 (file)
@@ -52,8 +52,9 @@ func (m *Manager) Restore(image *Image) error {
        for _, slice := range image.Slice {
                if existed := m.db.Get(Key(slice.Account.ID)); existed != nil {
                        log.WithFields(log.Fields{
-                               "alias": slice.Account.Alias,
-                               "id":    slice.Account.ID,
+                               "module": logModule,
+                               "alias":  slice.Account.Alias,
+                               "id":     slice.Account.ID,
                        }).Warning("skip restore account due to already existed")
                        continue
                }
index f0fdf15..9fa62ea 100644 (file)
@@ -219,7 +219,7 @@ func (uk *utxoKeeper) findUtxos(accountID string, assetID *bc.AssetID, useUnconf
        for utxoIter.Next() {
                u := &UTXO{}
                if err := json.Unmarshal(utxoIter.Value(), u); err != nil {
-                       log.WithField("err", err).Error("utxoKeeper findUtxos fail on unmarshal utxo")
+                       log.WithFields(log.Fields{"module": logModule, "err": err}).Error("utxoKeeper findUtxos fail on unmarshal utxo")
                        continue
                }
                appendUtxo(u)
index c6945cf..e460eee 100644 (file)
@@ -41,7 +41,8 @@ const (
        // SUCCESS indicates the rpc calling is successful.
        SUCCESS = "success"
        // FAIL indicated the rpc calling is failed.
-       FAIL = "fail"
+       FAIL      = "fail"
+       logModule = "api"
 )
 
 // Response describes the response standard.
@@ -153,7 +154,7 @@ func (a *API) initServer(config *cfg.Config) {
 
 // StartServer start the server
 func (a *API) StartServer(address string) {
-       log.WithField("api address:", address).Info("Rpc listen")
+       log.WithFields(log.Fields{"module": logModule, "api address:": address}).Info("Rpc listen")
        listener, err := net.Listen("tcp", address)
        if err != nil {
                cmn.Exit(cmn.Fmt("Failed to register tcp port: %v", err))
@@ -164,7 +165,7 @@ func (a *API) StartServer(address string) {
        // we call it.
        go func() {
                if err := a.server.Serve(listener); err != nil {
-                       log.WithField("error", errors.Wrap(err, "Serve")).Error("Rpc server")
+                       log.WithFields(log.Fields{"module": logModule, "error": errors.Wrap(err, "Serve")}).Error("Rpc server")
                }
        }()
 }
@@ -357,7 +358,7 @@ func AuthHandler(handler http.Handler, accessTokens *accesstoken.CredentialStore
                // TODO(tessr): check that this path exists; return early if this path isn't legit
                req, err := authenticator.Authenticate(req)
                if err != nil {
-                       log.WithField("error", errors.Wrap(err, "Serve")).Error("Authenticate fail")
+                       log.WithFields(log.Fields{"module": logModule, "error": errors.Wrap(err, "Serve")}).Error("Authenticate fail")
                        err = errors.WithDetail(errNotAuthenticated, err.Error())
                        errorFormatter.Write(req.Context(), rw, err)
                        return
index 9aee2fe..9f78317 100644 (file)
@@ -16,7 +16,7 @@ func (a *API) createTxFeed(ctx context.Context, in struct {
        Filter string `json:"filter"`
 }) Response {
        if err := a.txFeedTracker.Create(ctx, in.Alias, in.Filter); err != nil {
-               log.WithField("error", err).Error("Add TxFeed Failed")
+               log.WithFields(log.Fields{"module": logModule, "error": err}).Error("Add TxFeed Failed")
                return NewErrorResponse(err)
        }
        return NewSuccessResponse(nil)
@@ -58,7 +58,7 @@ func (a *API) updateTxFeed(ctx context.Context, in struct {
                return NewErrorResponse(err)
        }
        if err := a.txFeedTracker.Create(ctx, in.Alias, in.Filter); err != nil {
-               log.WithField("error", err).Error("Update TxFeed Failed")
+               log.WithFields(log.Fields{"module": logModule, "error": err}).Error("Update TxFeed Failed")
                return NewErrorResponse(err)
        }
        return NewSuccessResponse(nil)
index 3053601..2bc2a16 100644 (file)
@@ -12,6 +12,8 @@ import (
        "github.com/bytom/crypto/ed25519/chainkd"
 )
 
+const logModule = "pseudohsm"
+
 // KeyImage is the struct for hold export key data
 type KeyImage struct {
        XKeys []*encryptedKeyJSON `json:"xkeys"`
@@ -52,9 +54,10 @@ func (h *HSM) Restore(image *KeyImage) error {
                copy(xPub[:], data)
                if h.cache.hasKey(xPub) {
                        log.WithFields(log.Fields{
-                               "alias": xKey.Alias,
-                               "id":    xKey.ID,
-                               "xPub":  xKey.XPub,
+                               "module": logModule,
+                               "alias":  xKey.Alias,
+                               "id":     xKey.ID,
+                               "xPub":   xKey.XPub,
                        }).Warning("skip restore key due to already existed")
                        continue
                }
index 7af8805..02e244e 100644 (file)
@@ -169,7 +169,7 @@ func (kc *keyCache) find(xpub XPub) (XPub, error) {
 func (kc *keyCache) reload() {
        keys, err := kc.scan()
        if err != nil {
-               log.WithField("load keys error", err).Error("can't load keys")
+               log.WithFields(log.Fields{"module": logModule, "load keys error": err}).Error("can't load keys")
        }
        kc.all = keys
        sort.Sort(kc.all)
@@ -179,7 +179,7 @@ func (kc *keyCache) reload() {
        for _, k := range keys {
                kc.byPubs[k.XPub] = append(kc.byPubs[k.XPub], k)
        }
-       log.WithField("cache has keys:", len(kc.all)).Debug("reloaded keys")
+       log.WithFields(log.Fields{"module": logModule, "cache has keys:": len(kc.all)}).Debug("reloaded keys")
 }
 
 func (kc *keyCache) scan() ([]XPub, error) {
@@ -214,9 +214,10 @@ func (kc *keyCache) scan() ([]XPub, error) {
                err = json.NewDecoder(buf).Decode(&keyJSON)
                switch {
                case err != nil:
-                       log.WithField("decode json err", err).Errorf("can't decode key %s: %v", path, err)
+                       log.WithFields(log.Fields{"module": logModule, "decode json err": err}).Errorf("can't decode key %s: %v", path, err)
+
                case (keyJSON.Alias == ""):
-                       log.WithField("can't decode key, key path:", path).Warn("missing or void alias")
+                       log.WithFields(log.Fields{"module": logModule, "can't decode key, key path:": path}).Warn("missing or void alias")
                default:
                        keys = append(keys, XPub{XPub: keyJSON.XPub, Alias: keyJSON.Alias, File: path})
                }
index 750d36c..d5df57e 100644 (file)
@@ -40,7 +40,7 @@ func (sw *RawTxSigWitness) sign(ctx context.Context, tpl *Template, index uint32
                }
                sigBytes, err := signFn(ctx, keyID.XPub, path, tpl.Hash(index).Byte32(), auth)
                if err != nil {
-                       log.WithField("err", err).Warningf("computing signature %d", i)
+                       log.WithFields(log.Fields{"module": logModule, "err": err}).Warningf("computing signature %d", i)
                        continue
                }
 
index ebdb3fb..233b772 100644 (file)
@@ -86,7 +86,7 @@ func (sw *SignatureWitness) sign(ctx context.Context, tpl *Template, index uint3
                }
                sigBytes, err := signFn(ctx, keyID.XPub, path, h, auth)
                if err != nil {
-                       log.WithField("err", err).Warningf("computing signature %d", i)
+                       log.WithFields(log.Fields{"module": logModule, "err": err}).Warningf("computing signature %d", i)
                        continue
                }
 
index fc741c6..9660ae7 100644 (file)
@@ -17,6 +17,8 @@ import (
        "github.com/bytom/protocol/vm"
 )
 
+const logModule = "txbuilder"
+
 // errors
 var (
        //ErrBadRefData means invalid reference data
@@ -54,7 +56,7 @@ func Build(ctx context.Context, tx *types.TxData, actions []Action, maxTime time
        for i, action := range actions {
                err := action.Build(ctx, &builder)
                if err != nil {
-                       log.WithFields(log.Fields{"action index": i, "error": err}).Error("Loop tx's action")
+                       log.WithFields(log.Fields{"module": logModule, "action index": i, "error": err}).Error("Loop tx's action")
                        errs = append(errs, errors.WithDetailf(err, "action index %v", i))
                }
        }
index b5fa5da..d19f7f0 100644 (file)
@@ -20,6 +20,7 @@ import (
 const (
        //FilterNumMax max txfeed filter amount.
        FilterNumMax = 1024
+       logModule    = "txfeed"
 )
 
 var (
@@ -264,7 +265,7 @@ func (t *Tracker) Get(ctx context.Context, alias string) (*TxFeed, error) {
 
 //Delete delete txfeed with alias.
 func (t *Tracker) Delete(ctx context.Context, alias string) error {
-       log.WithField("delete", alias).Info("delete txfeed")
+       log.WithFields(log.Fields{"module": logModule, "delete": alias}).Info("delete txfeed")
 
        if alias == "" {
                return errors.WithDetail(ErrEmptyAlias, "del transaction feed with empty alias")
@@ -312,7 +313,7 @@ func (t *Tracker) TxFilter(tx *types.Tx) error {
                        if err != nil {
                                return err
                        }
-                       log.WithField("filter", string(b)).Info("find new tx match filter")
+                       log.WithFields(log.Fields{"module:": logModule, "filter": string(b)}).Info("find new tx match filter")
                        t.txfeedCh <- tx
                }
        }
index a3edadd..ea56539 100644 (file)
@@ -25,7 +25,7 @@ func init() {
 func initFiles(cmd *cobra.Command, args []string) {
        configFilePath := path.Join(config.RootDir, "config.toml")
        if _, err := os.Stat(configFilePath); !os.IsNotExist(err) {
-               log.WithField("config", configFilePath).Info("Already exists config file.")
+               log.WithFields(log.Fields{"module": logModule, "config": configFilePath}).Info("Already exists config file.")
                return
        }
 
@@ -36,5 +36,5 @@ func initFiles(cmd *cobra.Command, args []string) {
                cfg.EnsureRoot(config.RootDir, "solonet")
        }
 
-       log.WithField("config", configFilePath).Info("Initialized bytom")
+       log.WithFields(log.Fields{"module": logModule, "config": configFilePath}).Info("Initialized bytom")
 }
index 3e370e4..54fc02f 100644 (file)
@@ -10,6 +10,8 @@ import (
        "github.com/bytom/node"
 )
 
+const logModule = "cmd"
+
 var runNodeCmd = &cobra.Command{
        Use:   "node",
        Short: "Run the bytomd",
@@ -79,11 +81,12 @@ func runNode(cmd *cobra.Command, args []string) error {
        // Create & start node
        n := node.NewNode(config)
        if _, err := n.Start(); err != nil {
-               log.WithField("err", err).Fatal("failed to start node")
+               log.WithFields(log.Fields{"module": logModule, "err": err}).Fatal("failed to start node")
        }
 
        nodeInfo := n.NodeInfo()
        log.WithFields(log.Fields{
+               "module":   logModule,
                "version":  nodeInfo.Version,
                "network":  nodeInfo.Network,
                "duration": time.Since(startTime),
index ffc39f8..6742e2e 100644 (file)
@@ -18,6 +18,7 @@ const (
        maxNonce          = ^uint64(0) // 2^64 - 1
        defaultNumWorkers = 1
        hashUpdateSecs    = 1
+       logModule         = "cpuminer"
 )
 
 // CPUMiner provides facilities for solving blocks (mining) using the CPU in
@@ -94,6 +95,7 @@ out:
                if m.solveBlock(block, ticker, quit) {
                        if isOrphan, err := m.chain.ProcessBlock(block); err == nil {
                                log.WithFields(log.Fields{
+                                       "module":   logModule,
                                        "height":   block.BlockHeader.Height,
                                        "isOrphan": isOrphan,
                                        "tx":       len(block.Transactions),
@@ -101,10 +103,10 @@ out:
 
                                // Broadcast the block and announce chain insertion event
                                if err = m.eventDispatcher.Post(event.NewMinedBlockEvent{Block: block}); err != nil {
-                                       log.WithField("height", block.BlockHeader.Height).Errorf("Miner fail on post block, %v", err)
+                                       log.WithFields(log.Fields{"module": logModule, "height": block.BlockHeader.Height, "error": err}).Errorf("Miner fail on post block")
                                }
                        } else {
-                               log.WithField("height", block.BlockHeader.Height).Errorf("Miner fail on ProcessBlock, %v", err)
+                               log.WithFields(log.Fields{"module": logModule, "height": block.BlockHeader.Height, "error": err}).Errorf("Miner fail on ProcessBlock")
                        }
                }
        }
index 41f6c1c..e635976 100644 (file)
@@ -19,6 +19,8 @@ import (
        "github.com/bytom/protocol/vm/vmutil"
 )
 
+const logModule = "mining"
+
 // createCoinbaseTx returns a coinbase transaction paying an appropriate subsidy
 // based on the passed block height to the provided address.  When the address
 // is nil, the coinbase transaction will instead be redeemable by anyone.
@@ -159,6 +161,6 @@ func NewBlockTemplate(c *protocol.Chain, txPool *protocol.TxPool, accountManager
 }
 
 func blkGenSkipTxForErr(txPool *protocol.TxPool, txHash *bc.Hash, err error) {
-       log.WithField("error", err).Error("mining block generation: skip tx due to")
+       log.WithFields(log.Fields{"module": logModule, "error": err}).Error("mining block generation: skip tx due to")
        txPool.RemoveTransaction(txHash)
 }
index 9f9010d..d2221da 100644 (file)
@@ -11,6 +11,8 @@ import (
        log "github.com/sirupsen/logrus"
 )
 
+const logModule = "httpjson"
+
 // ErrBadRequest indicates the user supplied malformed JSON input,
 // possibly including a datatype that doesn't match what we expected.
 var ErrBadRequest = errors.New("httpjson: bad request")
@@ -42,7 +44,7 @@ func Write(ctx context.Context, w http.ResponseWriter, status int, v interface{}
 
        err := json.NewEncoder(w).Encode(Array(v))
        if err != nil {
-               log.WithField("error", err).Error("Error encountered during writing the Content-Type header using status")
+               log.WithFields(log.Fields{"module": logModule, "error": err}).Error("Error encountered during writing the Content-Type header using status")
        }
 }
 
index 6156741..f850269 100644 (file)
@@ -28,6 +28,7 @@ const (
        coreIDKey
        // pathKey is the key for the request path being handled.
        pathKey
+       logModule = "reqid"
 )
 
 // New generates a random request ID.
@@ -43,7 +44,7 @@ func New() string {
        b := make([]byte, l)
        _, err := rand.Read(b)
        if err != nil {
-               log.WithField("error", err).Info("error making reqID")
+               log.WithFields(log.Fields{"module": logModule, "error": err}).Info("error making reqID")
        }
        return hex.EncodeToString(b)
 }
index e8857c0..b412bee 100644 (file)
@@ -326,11 +326,7 @@ func (sm *SyncManager) handleStatusResponseMsg(basePeer BasePeer, msg *StatusRes
        }
 
        if genesisHash := msg.GetGenesisHash(); sm.genesisHash != *genesisHash {
-               log.WithFields(log.Fields{
-                       "module":         logModule,
-                       "remote genesis": genesisHash.String(),
-                       "local genesis":  sm.genesisHash.String(),
-               }).Warn("fail hand shake due to differnt genesis")
+               log.WithFields(log.Fields{"module": logModule, "remote genesis": genesisHash.String(), "local genesis": sm.genesisHash.String()}).Warn("fail hand shake due to differnt genesis")
                return
        }
 
index f96ee1d..586be2e 100644 (file)
@@ -3,6 +3,7 @@ package netsync
 import (
        "encoding/hex"
        "net"
+       "reflect"
        "sync"
 
        log "github.com/sirupsen/logrus"
@@ -118,6 +119,7 @@ func (p *peer) addFilterAddress(address []byte) {
                log.WithField("module", logModule).Warn("the size of filter address is greater than limit")
                return
        }
+
        p.filterAdds.Add(hex.EncodeToString(address))
 }
 
@@ -385,6 +387,7 @@ func (ps *peerSet) broadcastMinedBlock(block *types.Block) error {
                        continue
                }
                if ok := peer.TrySend(BlockchainChannel, struct{ BlockchainMessage }{msg}); !ok {
+                       log.WithFields(log.Fields{"module": logModule, "peer": peer.Addr(), "type": reflect.TypeOf(msg), "message": msg.String()}).Warning("send message to peer error")
                        ps.removePeer(peer.ID())
                        continue
                }
@@ -401,6 +404,7 @@ func (ps *peerSet) broadcastNewStatus(bestBlock, genesisBlock *types.Block) erro
        msg := NewStatusResponseMessage(&bestBlock.BlockHeader, &genesisHash)
        for _, peer := range peers {
                if ok := peer.TrySend(BlockchainChannel, struct{ BlockchainMessage }{msg}); !ok {
+                       log.WithFields(log.Fields{"module": logModule, "peer": peer.Addr(), "type": reflect.TypeOf(msg), "message": msg.String()}).Warning("send message to peer error")
                        ps.removePeer(peer.ID())
                        continue
                }
@@ -420,6 +424,12 @@ func (ps *peerSet) broadcastTx(tx *types.Tx) error {
                        continue
                }
                if ok := peer.TrySend(BlockchainChannel, struct{ BlockchainMessage }{msg}); !ok {
+                       log.WithFields(log.Fields{
+                               "module":  logModule,
+                               "peer":    peer.Addr(),
+                               "type":    reflect.TypeOf(msg),
+                               "message": msg.String(),
+                       }).Warning("send message to peer error")
                        ps.removePeer(peer.ID())
                        continue
                }
index 0b27d1c..6585097 100644 (file)
@@ -35,7 +35,10 @@ import (
        w "github.com/bytom/wallet"
 )
 
-const webHost = "http://127.0.0.1"
+const (
+       webHost   = "http://127.0.0.1"
+       logModule = "node"
+)
 
 // Node represent bytom node
 type Node struct {
@@ -92,7 +95,7 @@ func NewNode(config *cfg.Config) *Node {
        txFeed = txfeed.NewTracker(txFeedDB, chain)
 
        if err = txFeed.Prepare(ctx); err != nil {
-               log.WithField("error", err).Error("start txfeed")
+               log.WithFields(log.Fields{"module": logModule, "error": err}).Error("start txfeed")
                return nil
        }
 
@@ -107,7 +110,7 @@ func NewNode(config *cfg.Config) *Node {
                assets = asset.NewRegistry(walletDB, chain)
                wallet, err = w.NewWallet(walletDB, accounts, assets, hsm, chain, dispatcher)
                if err != nil {
-                       log.WithField("error", err).Error("init NewWallet")
+                       log.WithFields(log.Fields{"module": logModule, "error": err}).Error("init NewWallet")
                }
 
                // trigger rescan wallet
@@ -186,7 +189,7 @@ func initLogFile(config *cfg.Config) {
        if err == nil {
                log.SetOutput(file)
        } else {
-               log.WithField("err", err).Info("using default")
+               log.WithFields(log.Fields{"module": logModule, "err": err}).Info("using default")
        }
 
 }
index ee4e6a7..5a45ada 100644 (file)
@@ -36,6 +36,7 @@ const (
        defaultRecvMessageCapacity = 22020096      // 21MB
        defaultRecvRate            = int64(512000) // 500KB/s
        defaultSendTimeout         = 10 * time.Second
+       logModule                  = "p2p/conn"
 )
 
 type receiveCbFunc func(chID byte, msgBytes []byte)
@@ -182,12 +183,12 @@ func (c *MConnection) Send(chID byte, msg interface{}) bool {
 
        channel, ok := c.channelsIdx[chID]
        if !ok {
-               log.WithField("chID", chID).Error("cannot send bytes due to unknown channel")
+               log.WithFields(log.Fields{"module": logModule, "chID": chID}).Error("cannot send bytes due to unknown channel")
                return false
        }
 
        if !channel.sendBytes(wire.BinaryBytes(msg)) {
-               log.WithFields(log.Fields{"chID": chID, "conn": c, "msg": msg}).Error("MConnection send failed")
+               log.WithFields(log.Fields{"module": logModule, "chID": chID, "conn": c, "msg": msg}).Error("MConnection send failed")
                return false
        }
 
@@ -213,7 +214,7 @@ func (c *MConnection) TrySend(chID byte, msg interface{}) bool {
 
        channel, ok := c.channelsIdx[chID]
        if !ok {
-               log.WithField("chID", chID).Error("cannot send bytes due to unknown channel")
+               log.WithFields(log.Fields{"module": logModule, "chID": chID}).Error("cannot send bytes due to unknown channel")
                return false
        }
 
@@ -233,7 +234,7 @@ func (c *MConnection) String() string {
 
 func (c *MConnection) flush() {
        if err := c.bufWriter.Flush(); err != nil {
-               log.WithField("error", err).Error("MConnection flush failed")
+               log.WithFields(log.Fields{"module": logModule, "error": err}).Error("MConnection flush failed")
        }
 }
 
@@ -264,7 +265,7 @@ func (c *MConnection) recvRoutine() {
                c.recvMonitor.Update(int(n))
                if err != nil {
                        if c.IsRunning() {
-                               log.WithFields(log.Fields{"conn": c, "error": err}).Error("Connection failed @ recvRoutine (reading byte)")
+                               log.WithFields(log.Fields{"module": logModule, "conn": c, "error": err}).Error("Connection failed @ recvRoutine (reading byte)")
                                c.conn.Close()
                                c.stopForError(err)
                        }
@@ -274,14 +275,14 @@ func (c *MConnection) recvRoutine() {
                // Read more depending on packet type.
                switch pktType {
                case packetTypePing:
-                       log.Debug("receive Ping")
+                       log.WithFields(log.Fields{"module": logModule, "conn": c}).Debug("receive Ping")
                        select {
                        case c.pong <- struct{}{}:
                        default:
                        }
 
                case packetTypePong:
-                       log.Debug("receive Pong")
+                       log.WithFields(log.Fields{"module": logModule, "conn": c}).Debug("receive Pong")
 
                case packetTypeMsg:
                        pkt, n, err := msgPacket{}, int(0), error(nil)
@@ -289,7 +290,7 @@ func (c *MConnection) recvRoutine() {
                        c.recvMonitor.Update(int(n))
                        if err != nil {
                                if c.IsRunning() {
-                                       log.WithFields(log.Fields{"conn": c, "error": err}).Error("failed on recvRoutine")
+                                       log.WithFields(log.Fields{"module": logModule, "conn": c, "error": err}).Error("failed on recvRoutine")
                                        c.stopForError(err)
                                }
                                return
@@ -303,7 +304,7 @@ func (c *MConnection) recvRoutine() {
                        msgBytes, err := channel.recvMsgPacket(pkt)
                        if err != nil {
                                if c.IsRunning() {
-                                       log.WithFields(log.Fields{"conn": c, "error": err}).Error("failed on recvRoutine")
+                                       log.WithFields(log.Fields{"module": logModule, "conn": c, "error": err}).Error("failed on recvRoutine")
                                        c.stopForError(err)
                                }
                                return
@@ -338,7 +339,7 @@ func (c *MConnection) sendMsgPacket() bool {
 
        n, err := leastChannel.writeMsgPacketTo(c.bufWriter)
        if err != nil {
-               log.WithField("error", err).Error("failed to write msgPacket")
+               log.WithFields(log.Fields{"module": logModule, "error": err}).Error("failed to write msgPacket")
                c.stopForError(err)
                return true
        }
@@ -362,12 +363,12 @@ func (c *MConnection) sendRoutine() {
                                channel.updateStats()
                        }
                case <-c.pingTimer.C:
-                       log.Debug("send Ping")
+                       log.WithFields(log.Fields{"module": logModule, "conn": c}).Debug("send Ping")
                        wire.WriteByte(packetTypePing, c.bufWriter, &n, &err)
                        c.sendMonitor.Update(int(n))
                        c.flush()
                case <-c.pong:
-                       log.Debug("send Pong")
+                       log.WithFields(log.Fields{"module": logModule, "conn": c}).Debug("send Pong")
                        wire.WriteByte(packetTypePong, c.bufWriter, &n, &err)
                        c.sendMonitor.Update(int(n))
                        c.flush()
@@ -386,7 +387,7 @@ func (c *MConnection) sendRoutine() {
                        return
                }
                if err != nil {
-                       log.WithFields(log.Fields{"conn": c, "error": err}).Error("Connection failed @ sendRoutine")
+                       log.WithFields(log.Fields{"module": logModule, "conn": c, "error": err}).Error("Connection failed @ sendRoutine")
                        c.stopForError(err)
                        return
                }
index 15a4c87..3f4168c 100644 (file)
@@ -96,7 +96,7 @@ func newPersistentNodeDB(path string, version int, self NodeID) (*nodeDB, error)
                // Version not found (i.e. empty cache), insert it
                if err = db.Put(nodeDBVersionKey, currentVer, nil); err != nil {
                        if err := db.Close(); err != nil {
-                               log.Warn(fmt.Sprintf("db close err %v", err))
+                               log.WithFields(log.Fields{"module": logModule, "error": err}).Warn(fmt.Sprintf("db close err"))
                        }
                        return nil, err
                }
@@ -105,7 +105,7 @@ func newPersistentNodeDB(path string, version int, self NodeID) (*nodeDB, error)
                // Version present, flush if different
                if !bytes.Equal(blob, currentVer) {
                        if err = db.Close(); err != nil {
-                               log.Warn(fmt.Sprintf("db close err %v", err))
+                               log.WithFields(log.Fields{"module": logModule, "error": err}).Warn(fmt.Sprintf("db close err"))
                        }
                        if err = os.RemoveAll(path); err != nil {
                                return nil, err
@@ -175,13 +175,13 @@ func (db *nodeDB) node(id NodeID) *Node {
        key := makeKey(id, nodeDBDiscoverRoot)
        rawData, err := db.lvl.Get(key, nil)
        if err != nil {
-               log.Warn(fmt.Sprintf("get node rawdata err %v", err))
+               log.WithFields(log.Fields{"module": logModule, "error": err}).Warn(fmt.Sprintf("get node rawdata err"))
                return nil
        }
 
        wire.ReadBinary(node, bytes.NewReader(rawData), 0, &n, &err)
        if err != nil {
-               log.Warn(fmt.Sprintf("key %x (%T) %v", key, node, err))
+               log.WithFields(log.Fields{"module": logModule, "key": key, "node": node, "error": err}).Warn("get node from db err")
                return nil
        }
 
@@ -238,7 +238,7 @@ func (db *nodeDB) expirer() {
                select {
                case <-tick.C:
                        if err := db.expireNodes(); err != nil {
-                               log.Error(fmt.Sprintf("Failed to expire nodedb items: %v", err))
+                               log.WithFields(log.Fields{"module": logModule, "error": err}).Error("Failed to expire nodedb items")
                        }
                case <-db.quit:
                        return
@@ -325,7 +325,7 @@ seek:
                // of hitting all existing nodes in very small databases.
                ctr := id[0]
                if _, err := rand.Read(id[:]); err != nil {
-                       log.Warn("get rand date:", err)
+                       log.WithFields(log.Fields{"module": logModule, "error": err}).Warn("get rand date")
                }
                id[0] = ctr + id[0]%16
                it.Seek(makeKey(id, nodeDBDiscoverRoot))
@@ -355,7 +355,7 @@ func (db *nodeDB) fetchTopicRegTickets(id NodeID) (issued, used uint32) {
        key := makeKey(id, nodeDBTopicRegTickets)
        blob, err := db.lvl.Get(key, nil)
        if err != nil {
-               log.Warn("db get raw data:", err)
+               log.WithFields(log.Fields{"module": logModule, "error": err}).Warn("db get raw data")
        }
 
        if len(blob) != 8 {
@@ -391,7 +391,7 @@ func nextNode(it iterator.Iterator) *Node {
 
                wire.ReadBinary(node, bytes.NewReader(it.Value()), 0, &n, &err)
                if err != nil {
-                       log.Error("invalid node:", id, err)
+                       log.WithFields(log.Fields{"module": logModule, "id": id, "error": err}).Error("invalid node")
                        continue
                }
 
@@ -404,6 +404,6 @@ func nextNode(it iterator.Iterator) *Node {
 func (db *nodeDB) close() {
        close(db.quit)
        if err := db.lvl.Close(); err != nil {
-               log.Warn("db close err:", err)
+               log.WithFields(log.Fields{"module": logModule, "error": err}).Warn("db close err")
        }
 }
index 4dbea0e..ef067fc 100644 (file)
@@ -2,6 +2,7 @@ package discover
 
 import (
        "bytes"
+       "encoding/hex"
        "errors"
        "fmt"
        "net"
@@ -401,26 +402,25 @@ loop:
 
                select {
                case <-net.closeReq:
-                       log.Debug("<-net.closeReq")
+                       log.WithFields(log.Fields{"module": logModule}).Debug("close request")
                        break loop
 
                // Ingress packet handling.
                case pkt := <-net.read:
-                       //fmt.Println("read", pkt.ev)
-                       log.Debug("<-net.read")
+                       log.WithFields(log.Fields{"module": logModule}).Debug("read from net")
                        n := net.internNode(&pkt)
                        prestate := n.state
                        status := "ok"
                        if err := net.handle(n, pkt.ev, &pkt); err != nil {
                                status = err.Error()
                        }
-                       log.Debug("", "msg", net.tab.count, pkt.ev, pkt.remoteID[:8], pkt.remoteAddr, prestate, n.state, status)
+                       log.WithFields(log.Fields{"module": logModule, "node num": net.tab.count, "event": pkt.ev, "remote id": hex.EncodeToString(pkt.remoteID[:8]), "remote addr": pkt.remoteAddr, "pre state": prestate, "node state": n.state, "status": status}).Debug("handle ingress msg")
 
                        // TODO: persist state if n.state goes >= known, delete if it goes <= known
 
                // State transition timeouts.
                case timeout := <-net.timeout:
-                       log.Debug("<-net.timeout")
+                       log.WithFields(log.Fields{"module": logModule}).Debug("net timeout")
                        if net.timeoutTimers[timeout] == nil {
                                // Stale timer (was aborted).
                                continue
@@ -431,24 +431,24 @@ loop:
                        if err := net.handle(timeout.node, timeout.ev, nil); err != nil {
                                status = err.Error()
                        }
-                       log.Debug("", "msg", net.tab.count, timeout.ev, timeout.node.ID[:8], timeout.node.addr(), prestate, timeout.node.state, status)
+                       log.WithFields(log.Fields{"module": logModule, "node num": net.tab.count, "event": timeout.ev, "node id": hex.EncodeToString(timeout.node.ID[:8]), "node addr": timeout.node.addr(), "pre state": prestate, "node state": timeout.node.state, "status": status}).Debug("handle timeout")
 
                // Querying.
                case q := <-net.queryReq:
-                       log.Debug("<-net.queryReq")
+                       log.WithFields(log.Fields{"module": logModule}).Debug("net query request")
                        if !q.start(net) {
                                q.remote.deferQuery(q)
                        }
 
                // Interacting with the table.
                case f := <-net.tableOpReq:
-                       log.Debug("<-net.tableOpReq")
+                       log.WithFields(log.Fields{"module": logModule}).Debug("net table operate request")
                        f()
                        net.tableOpResp <- struct{}{}
 
                // Topic registration stuff.
                case req := <-net.topicRegisterReq:
-                       log.Debug("<-net.topicRegisterReq")
+                       log.WithFields(log.Fields{"module": logModule, "topic": req.topic}).Debug("net topic register request")
                        if !req.add {
                                net.ticketStore.removeRegisterTopic(req.topic)
                                continue
@@ -459,7 +459,7 @@ loop:
                        // determination for new topics.
                        // if topicRegisterLookupDone == nil {
                        if topicRegisterLookupTarget.target == (common.Hash{}) {
-                               log.Debug("topicRegisterLookupTarget == null")
+                               log.WithFields(log.Fields{"module": logModule, "topic": req.topic}).Debug("topic register lookup target null")
                                if topicRegisterLookupTick.Stop() {
                                        <-topicRegisterLookupTick.C
                                }
@@ -469,7 +469,7 @@ loop:
                        }
 
                case nodes := <-topicRegisterLookupDone:
-                       log.Debug("<-topicRegisterLookupDone")
+                       log.WithFields(log.Fields{"module": logModule}).Debug("topic register lookup done")
                        net.ticketStore.registerLookupDone(topicRegisterLookupTarget, nodes, func(n *Node) []byte {
                                net.ping(n, n.addr())
                                return n.pingEcho
@@ -480,7 +480,7 @@ loop:
                        topicRegisterLookupDone = nil
 
                case <-topicRegisterLookupTick.C:
-                       log.Debug("<-topicRegisterLookupTick")
+                       log.WithFields(log.Fields{"module": logModule}).Debug("topic register lookup tick")
                        if (topicRegisterLookupTarget.target == common.Hash{}) {
                                target, delay := net.ticketStore.nextRegisterLookup()
                                topicRegisterLookupTarget = target
@@ -493,14 +493,13 @@ loop:
                        }
 
                case <-nextRegisterTime:
-                       log.Debug("<-nextRegisterTime")
+                       log.WithFields(log.Fields{"module": logModule}).Debug("next register time")
                        net.ticketStore.ticketRegistered(*nextTicket)
-                       //fmt.Println("sendTopicRegister", nextTicket.t.node.addr().String(), nextTicket.t.topics, nextTicket.idx, nextTicket.t.pong)
                        net.conn.sendTopicRegister(nextTicket.t.node, nextTicket.t.topics, nextTicket.idx, nextTicket.t.pong)
 
                case req := <-net.topicSearchReq:
                        if refreshDone == nil {
-                               log.Debug("<-net.topicSearchReq")
+                               log.WithFields(log.Fields{"module": logModule, "topic": req.topic}).Debug("net topic rearch req")
                                info, ok := searchInfo[req.topic]
                                if ok {
                                        if req.delay == time.Duration(0) {
@@ -558,7 +557,7 @@ loop:
                        })
 
                case <-statsDump.C:
-                       log.Debug("<-statsDump.C")
+                       log.WithFields(log.Fields{"module": logModule}).Debug("stats dump clock")
                        /*r, ok := net.ticketStore.radius[testTopic]
                        if !ok {
                                fmt.Printf("(%x) no radius @ %v\n", net.tab.self.ID[:8], time.Now())
@@ -574,20 +573,20 @@ loop:
                                if printTestImgLogs {
                                        rad := r.radius / (maxRadius/1000000 + 1)
                                        minrad := r.minRadius / (maxRadius/1000000 + 1)
-                                       fmt.Printf("*R %d %v %016x %v\n", tm/1000000, topic, net.tab.self.sha[:8], rad)
-                                       fmt.Printf("*MR %d %v %016x %v\n", tm/1000000, topic, net.tab.self.sha[:8], minrad)
+                                       log.WithFields(log.Fields{"module": logModule}).Debug("*R %d %v %016x %v\n", tm/1000000, topic, net.tab.self.sha[:8], rad)
+                                       log.WithFields(log.Fields{"module": logModule}).Debug("*MR %d %v %016x %v\n", tm/1000000, topic, net.tab.self.sha[:8], minrad)
                                }
                        }
                        for topic, t := range net.topictab.topics {
                                wp := t.wcl.nextWaitPeriod(tm)
                                if printTestImgLogs {
-                                       fmt.Printf("*W %d %v %016x %d\n", tm/1000000, topic, net.tab.self.sha[:8], wp/1000000)
+                                       log.WithFields(log.Fields{"module": logModule}).Debug("*W %d %v %016x %d\n", tm/1000000, topic, net.tab.self.sha[:8], wp/1000000)
                                }
                        }
 
                // Periodic / lookup-initiated bucket refresh.
                case <-refreshTimer.C:
-                       log.Debug("<-refreshTimer.C")
+                       log.WithFields(log.Fields{"module": logModule}).Debug("refresh timer clock")
                        // TODO: ideally we would start the refresh timer after
                        // fallback nodes have been set for the first time.
                        if refreshDone == nil {
@@ -601,7 +600,7 @@ loop:
                                bucketRefreshTimer.Reset(bucketRefreshInterval)
                        }()
                case newNursery := <-net.refreshReq:
-                       log.Debug("<-net.refreshReq")
+                       log.WithFields(log.Fields{"module": logModule}).Debug("net refresh request")
                        if newNursery != nil {
                                net.nursery = newNursery
                        }
@@ -611,7 +610,7 @@ loop:
                        }
                        net.refreshResp <- refreshDone
                case <-refreshDone:
-                       log.Debug("<-net.refreshDone", "table size", net.tab.count)
+                       log.WithFields(log.Fields{"module": logModule, "table size": net.tab.count}).Debug("net refresh done")
                        if net.tab.count != 0 {
                                refreshDone = nil
                                list := searchReqWhenRefreshDone
@@ -627,9 +626,7 @@ loop:
                        }
                }
        }
-       log.Debug("loop stopped")
-
-       log.Debug(fmt.Sprintf("shutting down"))
+       log.WithFields(log.Fields{"module": logModule}).Debug("loop stopped,shutting down")
        if net.conn != nil {
                net.conn.Close()
        }
@@ -659,7 +656,7 @@ func (net *Network) refresh(done chan<- struct{}) {
                seeds = net.nursery
        }
        if len(seeds) == 0 {
-               log.Debug("no seed nodes found")
+               log.WithFields(log.Fields{"module": logModule}).Debug("no seed nodes found")
                time.AfterFunc(time.Second*10, func() { close(done) })
                return
        }
@@ -774,14 +771,14 @@ func (n *nodeNetGuts) startNextQuery(net *Network) {
 func (q *findnodeQuery) start(net *Network) bool {
        // Satisfy queries against the local node directly.
        if q.remote == net.tab.self {
-               log.Debug("findnodeQuery self")
+               log.WithFields(log.Fields{"module": logModule}).Debug("findnodeQuery self")
                closest := net.tab.closest(common.BytesToHash(q.target[:]), bucketSize)
 
                q.reply <- closest.entries
                return true
        }
        if q.remote.state.canQuery && q.remote.pendingNeighbours == nil {
-               log.Debug("findnodeQuery", "remote peer:", q.remote.ID, "targetID:", q.target)
+               log.WithFields(log.Fields{"module": logModule, "remote peer": q.remote.ID, "targetID": q.target}).Debug("find node query")
                net.conn.sendFindnodeHash(q.remote, q.target)
                net.timedEvent(respTimeout, q.remote, neighboursTimeout)
                q.remote.pendingNeighbours = q
@@ -791,7 +788,7 @@ func (q *findnodeQuery) start(net *Network) bool {
        // Initiate the transition to known.
        // The request will be sent later when the node reaches known state.
        if q.remote.state == unknown {
-               log.Debug("findnodeQuery", "id:", q.remote.ID, "status:", "unknown->verifyinit")
+               log.WithFields(log.Fields{"module": logModule, "id": q.remote.ID, "status": "unknown->verify init"}).Debug("find node query")
                net.transition(q.remote, verifyinit)
        }
        return false
@@ -1096,14 +1093,14 @@ func (net *Network) ping(n *Node, addr *net.UDPAddr) {
                //fmt.Println(" not sent")
                return
        }
-       log.Debug("Pinging remote node", "node", n.ID)
+       log.WithFields(log.Fields{"module": logModule, "node": n.ID}).Debug("Pinging remote node")
        n.pingTopics = net.ticketStore.regTopicSet()
        n.pingEcho = net.conn.sendPing(n, addr, n.pingTopics)
        net.timedEvent(respTimeout, n, pongTimeout)
 }
 
 func (net *Network) handlePing(n *Node, pkt *ingressPacket) {
-       log.Debug("Handling remote ping", "node", n.ID)
+       log.WithFields(log.Fields{"module": logModule, "node": n.ID}).Debug("Handling remote ping")
        ping := pkt.data.(*ping)
        n.TCP = ping.From.TCP
        t := net.topictab.getTicket(n, ping.Topics)
@@ -1118,7 +1115,7 @@ func (net *Network) handlePing(n *Node, pkt *ingressPacket) {
 }
 
 func (net *Network) handleKnownPong(n *Node, pkt *ingressPacket) error {
-       log.Debug("Handling known pong", "node", n.ID)
+       log.WithFields(log.Fields{"module": logModule, "node": n.ID}).Debug("Handling known pong")
        net.abortTimedEvent(n, pongTimeout)
        now := Now()
        ticket, err := pongToTicket(now, n.pingTopics, n, pkt)
@@ -1126,7 +1123,7 @@ func (net *Network) handleKnownPong(n *Node, pkt *ingressPacket) error {
                // fmt.Printf("(%x) ticket: %+v\n", net.tab.self.ID[:8], pkt.data)
                net.ticketStore.addTicket(now, pkt.data.(*pong).ReplyTok, ticket)
        } else {
-               log.Debug("Failed to convert pong to ticket", "err", err)
+               log.WithFields(log.Fields{"module": logModule, "error": err}).Debug("Failed to convert pong to ticket")
        }
        n.pingEcho = nil
        n.pingTopics = nil
@@ -1243,7 +1240,7 @@ func (net *Network) handleNeighboursPacket(n *Node, pkt *ingressPacket) error {
        for i, rn := range req.Nodes {
                nn, err := net.internNodeFromNeighbours(pkt.remoteAddr, rn)
                if err != nil {
-                       log.Debug(fmt.Sprintf("invalid neighbour (%v) from %x@%v: %v", rn.IP, n.ID[:8], pkt.remoteAddr, err))
+                       log.WithFields(log.Fields{"module": logModule, "ip": rn.IP, "id:": n.ID[:8], "addr:": pkt.remoteAddr, "error": err}).Debug("invalid neighbour")
                        continue
                }
                nodes[i] = nn
index 222620f..1064bc1 100644 (file)
@@ -38,12 +38,12 @@ func checkClockDrift() {
                howtofix := fmt.Sprintf("Please enable network time synchronisation in system settings")
                separator := strings.Repeat("-", len(warning))
 
-               log.Warn(separator)
-               log.Warn(warning)
-               log.Warn(howtofix)
-               log.Warn(separator)
+               log.WithFields(log.Fields{"module": logModule}).Warn(separator)
+               log.WithFields(log.Fields{"module": logModule}).Warn(warning)
+               log.WithFields(log.Fields{"module": logModule}).Warn(howtofix)
+               log.WithFields(log.Fields{"module": logModule}).Warn(separator)
        } else {
-               log.Debug(fmt.Sprintf("Sanity NTP check reported %v drift, all ok", drift))
+               log.WithFields(log.Fields{"module": logModule, "drift": drift}).Debug(fmt.Sprintf("Sanity NTP check reported all ok"))
        }
 }
 
index 02061b5..62a00e6 100644 (file)
@@ -9,10 +9,11 @@ package discover
 import (
        "crypto/rand"
        "encoding/binary"
-       "fmt"
        "net"
        "sort"
 
+       log "github.com/sirupsen/logrus"
+
        "github.com/bytom/common"
        "github.com/bytom/crypto"
 )
@@ -50,8 +51,6 @@ func newTable(ourID NodeID, ourAddr *net.UDPAddr) *Table {
        return tab
 }
 
-const printTable = false
-
 // chooseBucketRefreshTarget selects random refresh targets to keep all Kademlia
 // buckets filled with live connections and keep the network topology healthy.
 // This requires selecting addresses closer to our own with a higher probability
@@ -64,16 +63,11 @@ const printTable = false
 // used buckets.
 func (tab *Table) chooseBucketRefreshTarget() common.Hash {
        entries := 0
-       if printTable {
-               fmt.Println()
-               fmt.Println("self ", "id:", tab.self.ID, " hex:", crypto.Sha256Hash(tab.self.ID[:]).Hex())
-       }
+       log.WithFields(log.Fields{"module": logModule, "self id:": tab.self.ID, "hex": crypto.Sha256Hash(tab.self.ID[:]).Hex()}).Debug()
        for i, b := range &tab.buckets {
                entries += len(b.entries)
-               if printTable {
-                       for _, e := range b.entries {
-                               fmt.Println(i, e.state, e.addr().String(), e.ID.String(), e.sha.Hex())
-                       }
+               for _, e := range b.entries {
+                       log.WithFields(log.Fields{"module": logModule, "bucket": i, "status": e.state, "addr": e.addr().String(), "id": e.ID.String(), "hex": e.sha.Hex()}).Debug()
                }
        }
 
index 378b8ea..10de037 100644 (file)
@@ -104,7 +104,7 @@ func ticketToPong(t *ticket, pong *pong) {
        pong.Expiration = uint64(t.issueTime / AbsTime(time.Second))
        pong.TopicHash, _, err = wireHash(t.topics)
        if err != nil {
-               log.Error("wireHash err:", err)
+               log.WithFields(log.Fields{"module": logModule, "error": err}).Error("wireHash err")
        }
        pong.TicketSerial = t.serial
        pong.WaitPeriods = make([]uint32, len(t.regTime))
@@ -168,7 +168,7 @@ func newTicketStore() *ticketStore {
 // addTopic starts tracking a topic. If register is true,
 // the local node will register the topic and tickets will be collected.
 func (s *ticketStore) addTopic(topic Topic, register bool) {
-       log.Debug("Adding discovery topic", "topic", topic, "register", register)
+       log.WithFields(log.Fields{"module": logModule, "topic": topic, "register": register}).Debug("Adding discovery topic")
        if s.radius[topic] == nil {
                s.radius[topic] = newTopicRadius(topic)
        }
@@ -192,9 +192,9 @@ func (s *ticketStore) removeSearchTopic(t Topic) {
 
 // removeRegisterTopic deletes all tickets for the given topic.
 func (s *ticketStore) removeRegisterTopic(topic Topic) {
-       log.Debug("Removing discovery topic", "topic", topic)
+       log.WithFields(log.Fields{"module": logModule, "topic": topic}).Debug("Removing discovery topic")
        if s.tickets[topic] == nil {
-               log.Warn("Removing non-existent discovery topic", "topic", topic)
+               log.WithFields(log.Fields{"module": logModule, "topic": topic}).Warn("Removing non-existent discovery topic")
                return
        }
        for _, list := range s.tickets[topic].buckets {
@@ -239,13 +239,13 @@ func (s *ticketStore) nextRegisterLookup() (lookupInfo, time.Duration) {
                // If the topic needs more tickets, return it
                if s.tickets[topic].nextLookup < Now() {
                        next, delay := s.radius[topic].nextTarget(false), 100*time.Millisecond
-                       log.Debug("Found discovery topic to register", "topic", topic, "target", next.target, "delay", delay)
+                       log.WithFields(log.Fields{"module": logModule, "topic": topic, "target": next.target, "delay": delay}).Debug("Found discovery topic to register")
                        return next, delay
                }
        }
        // No registration topics found or all exhausted, sleep
        delay := 40 * time.Second
-       log.Debug("No topic found to register", "delay", delay)
+       log.WithFields(log.Fields{"module": logModule, "delay": delay}).Debug("No topic found to register")
        return lookupInfo{}, delay
 }
 
@@ -264,7 +264,7 @@ func (s *ticketStore) nextSearchLookup(topic Topic) lookupInfo {
 func (s *ticketStore) ticketsInWindow(topic Topic) []ticketRef {
        // Sanity check that the topic still exists before operating on it
        if s.tickets[topic] == nil {
-               log.Warn("Listing non-existing discovery tickets", "topic", topic)
+               log.WithFields(log.Fields{"module": logModule, "topic": topic}).Warn("Listing non-existing discovery tickets")
                return nil
        }
        // Gather all the tickers in the next time window
@@ -274,7 +274,7 @@ func (s *ticketStore) ticketsInWindow(topic Topic) []ticketRef {
        for idx := timeBucket(0); idx < timeWindow; idx++ {
                tickets = append(tickets, buckets[s.lastBucketFetched+idx]...)
        }
-       log.Debug("Retrieved discovery registration tickets", "topic", topic, "from", s.lastBucketFetched, "tickets", len(tickets))
+       log.WithFields(log.Fields{"module": logModule, "topic": topic, "from": s.lastBucketFetched, "tickets": len(tickets)}).Debug("Retrieved discovery registration tickets")
        return tickets
 }
 
@@ -315,7 +315,7 @@ func (s *ticketStore) addTicketRef(r ticketRef) {
        topic := r.t.topics[r.idx]
        tickets := s.tickets[topic]
        if tickets == nil {
-               log.Warn("Adding ticket to non-existent topic", "topic", topic)
+               log.WithFields(log.Fields{"module": logModule, "topic": topic}).Warn("Adding ticket to non-existent topic")
                return
        }
        bucket := timeBucket(r.t.regTime[r.idx] / AbsTime(ticketTimeBucketLen))
@@ -409,7 +409,7 @@ func (s *ticketStore) nextRegisterableTicket() (*ticketRef, time.Duration) {
 
 // removeTicket removes a ticket from the ticket store
 func (s *ticketStore) removeTicketRef(ref ticketRef) {
-       log.Debug("Removing discovery ticket reference", "node", ref.t.node.ID, "serial", ref.t.serial)
+       log.WithFields(log.Fields{"module": logModule, "node": ref.t.node.ID, "serial": ref.t.serial}).Debug("Removing discovery ticket reference")
 
        // Make nextRegisterableTicket return the next available ticket.
        s.nextTicketCached = nil
@@ -418,7 +418,7 @@ func (s *ticketStore) removeTicketRef(ref ticketRef) {
        tickets := s.tickets[topic]
 
        if tickets == nil {
-               log.Debug("Removing tickets from unknown topic", "topic", topic)
+               log.WithFields(log.Fields{"module": logModule, "topic": topic}).Debug("Removing tickets from unknown topic")
                return
        }
        bucket := timeBucket(ref.t.regTime[ref.idx] / AbsTime(ticketTimeBucketLen))
@@ -514,7 +514,7 @@ func (s *ticketStore) adjustWithTicket(now AbsTime, targetHash common.Hash, t *t
 }
 
 func (s *ticketStore) addTicket(localTime AbsTime, pingHash []byte, ticket *ticket) {
-       log.Debug("Adding discovery ticket", "node", ticket.node.ID, "serial", ticket.serial)
+       log.WithFields(log.Fields{"module": logModule, "node": ticket.node.ID, "serial": ticket.serial}).Debug("Adding discovery ticket")
 
        lastReq, ok := s.nodeLastReq[ticket.node]
        if !(ok && bytes.Equal(pingHash, lastReq.pingHash)) {
@@ -558,9 +558,9 @@ func (s *ticketStore) addTicket(localTime AbsTime, pingHash []byte, ticket *tick
 
 func (s *ticketStore) getNodeTicket(node *Node) *ticket {
        if s.nodes[node] == nil {
-               log.Debug("Retrieving node ticket", "node", node.ID, "serial", nil)
+               log.WithFields(log.Fields{"module": logModule, "node": node.ID, "serial": nil}).Debug("Retrieving node ticket")
        } else {
-               log.Debug("Retrieving node ticket", "node", node.ID, "serial", s.nodes[node].serial)
+               log.WithFields(log.Fields{"module": logModule, "node": node.ID, "serial": s.nodes[node].serial}).Debug("Retrieving node ticket")
        }
        return s.nodes[node]
 }
index 3a083c3..ef2d8a6 100644 (file)
@@ -225,10 +225,8 @@ func (t *topicTable) deleteEntry(e *topicEntry) {
 
 // It is assumed that topics and waitPeriods have the same length.
 func (t *topicTable) useTicket(node *Node, serialNo uint32, topics []Topic, idx int, issueTime uint64, waitPeriods []uint32) (registered bool) {
-       log.Debug("Using discovery ticket", "serial", serialNo, "topics", topics, "waits", waitPeriods)
-       //fmt.Println("useTicket", serialNo, topics, waitPeriods)
+       log.WithFields(log.Fields{"module": logModule, "serial": serialNo, "topics": topics, "waits": waitPeriods}).Debug("Using discovery ticket")
        t.collectGarbage()
-
        n := t.getOrNewNode(node)
        if serialNo < n.lastUsedTicket {
                return false
index 2f3e768..5caf6a9 100644 (file)
@@ -333,7 +333,7 @@ func ListenUDP(priv ed25519.PrivateKey, conn conn, realaddr *net.UDPAddr, nodeDB
        if err != nil {
                return nil, err
        }
-       log.Info("UDP listener up v5", "net", net.tab.self)
+       log.WithFields(log.Fields{"module": logModule, "net": net.tab.self}).Info("UDP listener up v5")
        transport.net = net
        go transport.readLoop()
        return net, nil
@@ -425,9 +425,9 @@ func (t *udp) sendPacket(toid NodeID, toaddr *net.UDPAddr, ptype byte, req inter
        if err != nil {
                return hash, err
        }
-       log.Debug(fmt.Sprintf(">>> %v to %x@%v", nodeEvent(ptype), toid[:8], toaddr))
+       log.WithFields(log.Fields{"module": logModule, "event": nodeEvent(ptype), "to id": hex.EncodeToString(toid[:8]), "to addr": toaddr}).Debug("send packet")
        if _, err = t.conn.WriteToUDP(packet, toaddr); err != nil {
-               log.Info(fmt.Sprint("UDP send failed:", err))
+               log.WithFields(log.Fields{"module": logModule, "error": err}).Info(fmt.Sprint("UDP send failed"))
        }
        return hash, err
 }
@@ -442,7 +442,7 @@ func encodePacket(priv ed25519.PrivateKey, ptype byte, req interface{}) (p, hash
        var size int
        wire.WriteJSON(req, b, &size, &err)
        if err != nil {
-               log.Error(fmt.Sprint("error encoding packet:", err))
+               log.WithFields(log.Fields{"module": logModule, "error": err}).Error("error encoding packet")
                return nil, nil, err
        }
        packet := b.Bytes()
@@ -468,11 +468,11 @@ func (t *udp) readLoop() {
                nbytes, from, err := t.conn.ReadFromUDP(buf)
                if netutil.IsTemporaryError(err) {
                        // Ignore temporary read errors.
-                       log.Debug(fmt.Sprintf("Temporary read error: %v", err))
+                       log.WithFields(log.Fields{"module": logModule, "error": err}).Debug("Temporary read error")
                        continue
                } else if err != nil {
                        // Shut down the loop for permament errors.
-                       log.Debug(fmt.Sprintf("Read error: %v", err))
+                       log.WithFields(log.Fields{"module": logModule, "error": err}).Debug("Read error")
                        return
                }
                t.handlePacket(from, buf[:nbytes])
@@ -482,8 +482,7 @@ func (t *udp) readLoop() {
 func (t *udp) handlePacket(from *net.UDPAddr, buf []byte) error {
        pkt := ingressPacket{remoteAddr: from}
        if err := decodePacket(buf, &pkt); err != nil {
-               log.Debug(fmt.Sprintf("Bad packet from %v: %v", from, err))
-               //fmt.Println("bad packet", err)
+               log.WithFields(log.Fields{"module": logModule, "from": from, "error": err}).Error("Bad packet")
                return err
        }
        t.net.reqReadPacket(pkt)
@@ -526,7 +525,7 @@ func decodePacket(buffer []byte, pkt *ingressPacket) error {
        var err error
        wire.ReadJSON(pkt.data, sigdata[1:], &err)
        if err != nil {
-               log.Error("wire readjson err:", err)
+               log.WithFields(log.Fields{"module": logModule, "error": err}).Error("wire readjson err")
        }
 
        return err
index 5ab438c..204b686 100644 (file)
@@ -153,7 +153,7 @@ func NewDefaultListener(protocol string, lAddr string, skipUPNP bool) (Listener,
        if !skipUPNP && (lAddrIP == "" || lAddrIP == "0.0.0.0") {
                extAddr, err = getUPNPExternalAddress(lAddrPort, listenerPort)
                upnpMap = err == nil
-               log.WithField("err", err).Info("get UPNP external address")
+               log.WithFields(log.Fields{"module": logModule, "err": err}).Info("get UPNP external address")
        }
 
        if extAddr == nil {
index 42b8811..5960e77 100644 (file)
@@ -9,8 +9,8 @@ import (
        "github.com/btcsuite/go-socks/socks"
        "github.com/pkg/errors"
        log "github.com/sirupsen/logrus"
-       crypto "github.com/tendermint/go-crypto"
-       wire "github.com/tendermint/go-wire"
+       "github.com/tendermint/go-crypto"
+       "github.com/tendermint/go-wire"
        cmn "github.com/tendermint/tmlibs/common"
        "github.com/tendermint/tmlibs/flowrate"
 
@@ -155,7 +155,7 @@ func (pc *peerConn) HandshakeTimeout(ourNodeInfo *NodeInfo, timeout time.Duratio
                func() {
                        var n int
                        wire.ReadBinary(peerNodeInfo, pc.conn, maxNodeInfoSize, &n, &err2)
-                       log.WithField("address", peerNodeInfo.ListenAddr).Info("Peer handshake")
+                       log.WithFields(log.Fields{"module": logModule, "address": peerNodeInfo.ListenAddr}).Info("Peer handshake")
                })
        if err1 != nil {
                return peerNodeInfo, errors.Wrap(err1, "Error during handshake/write")
@@ -228,6 +228,12 @@ func (p *Peer) TrySend(chID byte, msg interface{}) bool {
        if !p.IsRunning() {
                return false
        }
+
+       log.WithFields(log.Fields{
+               "module": logModule,
+               "peer":   p.Addr(),
+               "msg":    msg,
+       }).Info("send message to peer")
        return p.mconn.TrySend(chID, msg)
 }
 
index ab863a0..5d8018f 100644 (file)
@@ -27,6 +27,7 @@ const (
        bannedPeerKey       = "BannedPeer"
        defaultBanDuration  = time.Hour * 1
        minNumOutboundPeers = 3
+       logModule           = "p2p"
 )
 
 //pre-define errors for connecting fail
@@ -232,7 +233,7 @@ func (sw *Switch) AddListener(l Listener) {
 
 //DialPeerWithAddress dial node from net address
 func (sw *Switch) DialPeerWithAddress(addr *NetAddress) error {
-       log.Debug("Dialing peer address:", addr)
+       log.WithFields(log.Fields{"module": logModule, "address": addr}).Debug("Dialing peer")
        sw.dialing.Set(addr.IP.String(), addr)
        defer sw.dialing.Delete(addr.IP.String())
        if err := sw.filterConnByIP(addr.IP.String()); err != nil {
@@ -241,16 +242,16 @@ func (sw *Switch) DialPeerWithAddress(addr *NetAddress) error {
 
        pc, err := newOutboundPeerConn(addr, sw.nodePrivKey, sw.peerConfig)
        if err != nil {
-               log.WithFields(log.Fields{"address": addr, " err": err}).Error("DialPeer fail on newOutboundPeerConn")
+               log.WithFields(log.Fields{"module": logModule, "address": addr, " err": err}).Error("DialPeer fail on newOutboundPeerConn")
                return err
        }
 
        if err = sw.AddPeer(pc); err != nil {
-               log.WithFields(log.Fields{"address": addr, " err": err}).Error("DialPeer fail on switch AddPeer")
+               log.WithFields(log.Fields{"module": logModule, "address": addr, " err": err}).Error("DialPeer fail on switch AddPeer")
                pc.CloseConn()
                return err
        }
-       log.Debug("DialPeer added peer:", addr)
+       log.WithFields(log.Fields{"module": logModule, "address": addr, "peer num": sw.peers.Size()}).Debug("DialPeer added peer")
        return nil
 }
 
@@ -309,7 +310,7 @@ func (sw *Switch) Peers() *PeerSet {
 
 // StopPeerForError disconnects from a peer due to external error.
 func (sw *Switch) StopPeerForError(peer *Peer, reason interface{}) {
-       log.WithFields(log.Fields{"peer": peer, " err": reason}).Debug("stopping peer for error")
+       log.WithFields(log.Fields{"module": logModule, "peer": peer, " err": reason}).Debug("stopping peer for error")
        sw.stopAndRemovePeer(peer, reason)
 }
 
@@ -324,18 +325,19 @@ func (sw *Switch) addPeerWithConnection(conn net.Conn) error {
        peerConn, err := newInboundPeerConn(conn, sw.nodePrivKey, sw.Config.P2P)
        if err != nil {
                if err := conn.Close(); err != nil {
-                       log.WithFields(log.Fields{"remote peer:": conn.RemoteAddr().String(), " err:": err}).Error("closes connection err")
+                       log.WithFields(log.Fields{"module": logModule, "remote peer:": conn.RemoteAddr().String(), " err:": err}).Error("closes connection err")
                }
                return err
        }
 
        if err = sw.AddPeer(peerConn); err != nil {
                if err := conn.Close(); err != nil {
-                       log.WithFields(log.Fields{"remote peer:": conn.RemoteAddr().String(), " err:": err}).Error("closes connection err")
+                       log.WithFields(log.Fields{"module": logModule, "remote peer:": conn.RemoteAddr().String(), " err:": err}).Error("closes connection err")
                }
                return err
        }
 
+       log.WithFields(log.Fields{"module": logModule, "address": conn.RemoteAddr().String(), "peer num": sw.peers.Size()}).Debug("add inbound peer")
        return nil
 }
 
@@ -401,7 +403,7 @@ func (sw *Switch) listenerRoutine(l Listener) {
                // disconnect if we alrady have MaxNumPeers
                if sw.peers.Size() >= sw.Config.P2P.MaxNumPeers {
                        if err := inConn.Close(); err != nil {
-                               log.WithFields(log.Fields{"remote peer:": inConn.RemoteAddr().String(), " err:": err}).Error("closes connection err")
+                               log.WithFields(log.Fields{"module": logModule, "remote peer:": inConn.RemoteAddr().String(), " err:": err}).Error("closes connection err")
                        }
                        log.Info("Ignoring inbound connection: already have enough peers.")
                        continue
@@ -417,7 +419,7 @@ func (sw *Switch) listenerRoutine(l Listener) {
 
 func (sw *Switch) dialPeerWorker(a *NetAddress, wg *sync.WaitGroup) {
        if err := sw.DialPeerWithAddress(a); err != nil {
-               log.WithFields(log.Fields{"addr": a, "err": err}).Error("dialPeerWorker fail on dial peer")
+               log.WithFields(log.Fields{"module": logModule, "addr": a, "err": err}).Error("dialPeerWorker fail on dial peer")
        }
        wg.Done()
 }
@@ -425,7 +427,7 @@ func (sw *Switch) dialPeerWorker(a *NetAddress, wg *sync.WaitGroup) {
 func (sw *Switch) ensureOutboundPeers() {
        numOutPeers, _, numDialing := sw.NumPeers()
        numToDial := (minNumOutboundPeers - (numOutPeers + numDialing))
-       log.WithFields(log.Fields{"numOutPeers": numOutPeers, "numDialing": numDialing, "numToDial": numToDial}).Debug("ensure peers")
+       log.WithFields(log.Fields{"module": logModule, "numOutPeers": numOutPeers, "numDialing": numDialing, "numToDial": numToDial}).Debug("ensure peers")
        if numToDial <= 0 {
                return
        }
@@ -475,7 +477,7 @@ func (sw *Switch) ensureOutboundPeersRoutine() {
 func (sw *Switch) startInitPeer(peer *Peer) error {
        // spawn send/recv routines
        if _, err := peer.Start(); err != nil {
-               log.WithFields(log.Fields{"remote peer:": peer.RemoteAddr, " err:": err}).Error("init peer err")
+               log.WithFields(log.Fields{"module": logModule, "remote peer:": peer.RemoteAddr, " err:": err}).Error("init peer err")
        }
 
        for _, reactor := range sw.reactors {
@@ -495,6 +497,7 @@ func (sw *Switch) stopAndRemovePeer(peer *Peer, reason interface{}) {
 
        sentStatus, receivedStatus := peer.TrafficStatus()
        log.WithFields(log.Fields{
+               "module":                logModule,
                "address":               peer.Addr().String(),
                "reason":                reason,
                "duration":              sentStatus.Duration.String(),
@@ -502,5 +505,6 @@ func (sw *Switch) stopAndRemovePeer(peer *Peer, reason interface{}) {
                "total_received":        receivedStatus.Bytes,
                "average_sent_rate":     sentStatus.AvgRate,
                "average_received_rate": receivedStatus.AvgRate,
+               "peer num":              sw.peers.Size(),
        }).Info("disconnect with peer")
 }
index 72a2dd7..b29a3d9 100644 (file)
@@ -120,7 +120,7 @@ func (c *Chain) reorganizeChain(node *state.BlockNode) error {
                        return err
                }
 
-               log.WithFields(log.Fields{"height": node.Height, "hash": node.Hash.String()}).Debug("detach from mainchain")
+               log.WithFields(log.Fields{"module": logModule, "height": node.Height, "hash": node.Hash.String()}).Debug("detach from mainchain")
        }
 
        for _, attachNode := range attachNodes {
@@ -141,7 +141,7 @@ func (c *Chain) reorganizeChain(node *state.BlockNode) error {
                        return err
                }
 
-               log.WithFields(log.Fields{"height": node.Height, "hash": node.Hash.String()}).Debug("attach from mainchain")
+               log.WithFields(log.Fields{"module": logModule, "height": node.Height, "hash": node.Hash.String()}).Debug("attach from mainchain")
        }
 
        return c.setState(node, utxoView)
@@ -180,11 +180,11 @@ func (c *Chain) saveSubBlock(block *types.Block) *types.Block {
        for _, prevOrphan := range prevOrphans {
                orphanBlock, ok := c.orphanManage.Get(prevOrphan)
                if !ok {
-                       log.WithFields(log.Fields{"hash": prevOrphan.String()}).Warning("saveSubBlock fail to get block from orphanManage")
+                       log.WithFields(log.Fields{"module": logModule, "hash": prevOrphan.String()}).Warning("saveSubBlock fail to get block from orphanManage")
                        continue
                }
                if err := c.saveBlock(orphanBlock); err != nil {
-                       log.WithFields(log.Fields{"hash": prevOrphan.String(), "height": orphanBlock.Height}).Warning("saveSubBlock fail to save block")
+                       log.WithFields(log.Fields{"module": logModule, "hash": prevOrphan.String(), "height": orphanBlock.Height}).Warning("saveSubBlock fail to save block")
                        continue
                }
 
@@ -224,7 +224,7 @@ func (c *Chain) blockProcesser() {
 func (c *Chain) processBlock(block *types.Block) (bool, error) {
        blockHash := block.Hash()
        if c.BlockExist(&blockHash) {
-               log.WithFields(log.Fields{"hash": blockHash.String(), "height": block.Height}).Info("block has been processed")
+               log.WithFields(log.Fields{"module": logModule, "hash": blockHash.String(), "height": block.Height}).Info("block has been processed")
                return c.orphanManage.BlockExist(&blockHash), nil
        }
 
@@ -242,12 +242,12 @@ func (c *Chain) processBlock(block *types.Block) (bool, error) {
        bestNode := c.index.GetNode(&bestBlockHash)
 
        if bestNode.Parent == c.bestNode {
-               log.Debug("append block to the end of mainchain")
+               log.WithFields(log.Fields{"module": logModule}).Debug("append block to the end of mainchain")
                return false, c.connectBlock(bestBlock)
        }
 
        if bestNode.Height > c.bestNode.Height && bestNode.WorkSum.Cmp(c.bestNode.WorkSum) >= 0 {
-               log.Debug("start to reorganize chain")
+               log.WithFields(log.Fields{"module": logModule}).Debug("start to reorganize chain")
                return false, c.reorganizeChain(bestNode)
        }
        return false, nil
index 166282f..d250269 100644 (file)
@@ -58,14 +58,14 @@ func (o *OrphanManage) Add(block *types.Block) {
        }
 
        if len(o.orphan) >= numOrphanBlockLimit {
-               log.WithFields(log.Fields{"hash": blockHash.String(), "height": block.Height}).Info("the number of orphan blocks exceeds the limit")
+               log.WithFields(log.Fields{"module": logModule, "hash": blockHash.String(), "height": block.Height}).Info("the number of orphan blocks exceeds the limit")
                return
        }
 
        o.orphan[blockHash] = &orphanBlock{block, time.Now().Add(orphanBlockTTL)}
        o.prevOrphans[block.PreviousBlockHash] = append(o.prevOrphans[block.PreviousBlockHash], &blockHash)
 
-       log.WithFields(log.Fields{"hash": blockHash.String(), "height": block.Height}).Info("add block to orphan")
+       log.WithFields(log.Fields{"module": logModule, "hash": blockHash.String(), "height": block.Height}).Info("add block to orphan")
 }
 
 // Delete will delete the block from OrphanManage
index 29b9628..aa24aff 100644 (file)
@@ -136,7 +136,7 @@ func (c *Chain) setState(node *state.BlockNode, view *state.UtxoViewpoint) error
        c.index.SetMainChain(node)
        c.bestNode = node
 
-       log.WithFields(log.Fields{"height": c.bestNode.Height, "hash": c.bestNode.Hash.String()}).Debug("chain best status has been update")
+       log.WithFields(log.Fields{"module": logModule, "height": c.bestNode.Height, "hash": c.bestNode.Hash.String()}).Debug("chain best status has been update")
        c.cond.Broadcast()
        return nil
 }
index bbbe738..4797c1f 100644 (file)
@@ -40,7 +40,7 @@ func (c *Chain) ValidateTx(tx *types.Tx) (bool, error) {
        }
 
        if err != nil {
-               log.WithFields(log.Fields{"tx_id": tx.Tx.ID.String(), "error": err}).Info("transaction status fail")
+               log.WithFields(log.Fields{"module": logModule, "tx_id": tx.Tx.ID.String(), "error": err}).Info("transaction status fail")
        }
 
        return c.txPool.ProcessTransaction(tx, err != nil, block.BlockHeader.Height, gasStatus.BTMValue)
index 0916f16..edb6af0 100644 (file)
@@ -20,6 +20,7 @@ import (
 const (
        MsgNewTx = iota
        MsgRemoveTx
+       logModule = "protocol"
 )
 
 var (
@@ -138,7 +139,7 @@ func (tp *TxPool) RemoveTransaction(txHash *bc.Hash) {
 
        atomic.StoreInt64(&tp.lastUpdated, time.Now().Unix())
        tp.eventDispatcher.Post(TxMsgEvent{TxMsg: &TxPoolMsg{TxDesc: txD, MsgType: MsgRemoveTx}})
-       log.WithField("tx_id", txHash).Debug("remove tx from mempool")
+       log.WithFields(log.Fields{"module": logModule, "tx_id": txHash}).Debug("remove tx from mempool")
 }
 
 // GetTransaction return the TxDesc by hash
@@ -255,7 +256,7 @@ func (tp *TxPool) addTransaction(txD *TxDesc) error {
 
        atomic.StoreInt64(&tp.lastUpdated, time.Now().Unix())
        tp.eventDispatcher.Post(TxMsgEvent{TxMsg: &TxPoolMsg{TxDesc: txD, MsgType: MsgNewTx}})
-       log.WithField("tx_id", tx.ID.String()).Debug("Add tx to mempool")
+       log.WithFields(log.Fields{"module": logModule, "tx_id": tx.ID.String()}).Debug("Add tx to mempool")
        return nil
 }
 
@@ -302,7 +303,7 @@ func (tp *TxPool) processOrphans(txD *TxDesc) {
                processOrphan := processOrphans[0]
                requireParents, err := tp.checkOrphanUtxos(processOrphan.Tx)
                if err != nil {
-                       log.WithField("err", err).Error("processOrphans got unexpect error")
+                       log.WithFields(log.Fields{"module": logModule, "err": err}).Error("processOrphans got unexpect error")
                        continue
                }
 
index b2016fd..1136708 100644 (file)
@@ -42,6 +42,7 @@ const (
        noUpdate uint16 = iota
        hasUpdate
        hasMUpdate
+       logModule = "version"
 )
 
 var (
@@ -112,6 +113,7 @@ func (s *UpdateStatus) CheckUpdate(localVerStr string, remoteVerStr string, remo
        }
        if s.versionStatus != noUpdate {
                log.WithFields(log.Fields{
+                       "module":          logModule,
                        "Current version": localVerStr,
                        "Newer version":   remoteVerStr,
                        "seed":            remoteAddr,
index 2a49a3f..9ac57c6 100644 (file)
@@ -55,7 +55,7 @@ func (w *Wallet) getExternalDefinition(assetID *bc.AssetID) json.RawMessage {
        }
 
        if err := w.AssetReg.SaveAsset(externalAsset, alias); err != nil {
-               log.WithFields(log.Fields{"err": err, "assetID": alias}).Warning("fail on save external asset to internal asset DB")
+               log.WithFields(log.Fields{"module": logModule, "err": err, "assetID": alias}).Warning("fail on save external asset to internal asset DB")
        }
        return definitionByte
 }
index f2b1340..dad3b64 100644 (file)
@@ -103,7 +103,7 @@ func (w *Wallet) indexTransactions(batch db.Batch, b *types.Block, txStatus *bc.
        for _, tx := range annotatedTxs {
                rawTx, err := json.Marshal(tx)
                if err != nil {
-                       log.WithField("err", err).Error("inserting annotated_txs to db")
+                       log.WithFields(log.Fields{"module": logModule, "err": err}).Error("inserting annotated_txs to db")
                        return err
                }
 
index 2aba1e6..b616518 100644 (file)
@@ -36,7 +36,7 @@ func (a SortByTimestamp) Less(i, j int) bool { return a[i].Timestamp > a[j].Time
 // AddUnconfirmedTx handle wallet status update when tx add into txpool
 func (w *Wallet) AddUnconfirmedTx(txD *protocol.TxDesc) {
        if err := w.saveUnconfirmedTx(txD.Tx); err != nil {
-               log.WithField("err", err).Error("wallet fail on saveUnconfirmedTx")
+               log.WithFields(log.Fields{"module": logModule, "err": err}).Error("wallet fail on saveUnconfirmedTx")
        }
 
        utxos := txOutToUtxos(txD.Tx, txD.StatusFail, 0)
@@ -168,7 +168,7 @@ func (w *Wallet) delExpiredTxs() error {
 //delUnconfirmedTx periodically delete locally stored timeout did not confirm txs
 func (w *Wallet) delUnconfirmedTx() {
        if err := w.delExpiredTxs(); err != nil {
-               log.WithField("err", err).Error("wallet fail on delUnconfirmedTx")
+               log.WithFields(log.Fields{"module": logModule, "err": err}).Error("wallet fail on delUnconfirmedTx")
                return
        }
        ticker := time.NewTicker(UnconfirmedTxCheckPeriod)
@@ -176,7 +176,7 @@ func (w *Wallet) delUnconfirmedTx() {
        for {
                <-ticker.C
                if err := w.delExpiredTxs(); err != nil {
-                       log.WithField("err", err).Error("wallet fail on delUnconfirmedTx")
+                       log.WithFields(log.Fields{"module": logModule, "err": err}).Error("wallet fail on delUnconfirmedTx")
                }
        }
 }
index 5f60e90..6bb8216 100644 (file)
@@ -33,7 +33,7 @@ func (w *Wallet) GetAccountUtxos(accountID string, id string, unconfirmed, isSma
        for accountUtxoIter.Next() {
                accountUtxo := &account.UTXO{}
                if err := json.Unmarshal(accountUtxoIter.Value(), accountUtxo); err != nil {
-                       log.WithField("err", err).Warn("GetAccountUtxos fail on unmarshal utxo")
+                       log.WithFields(log.Fields{"module": logModule, "err": err}).Warn("GetAccountUtxos fail on unmarshal utxo")
                        continue
                }
 
@@ -48,7 +48,7 @@ func (w *Wallet) attachUtxos(batch db.Batch, b *types.Block, txStatus *bc.Transa
        for txIndex, tx := range b.Transactions {
                statusFail, err := txStatus.GetStatus(txIndex)
                if err != nil {
-                       log.WithField("err", err).Error("attachUtxos fail on get tx status")
+                       log.WithFields(log.Fields{"module": logModule, "err": err}).Error("attachUtxos fail on get tx status")
                        continue
                }
 
@@ -70,7 +70,7 @@ func (w *Wallet) attachUtxos(batch db.Batch, b *types.Block, txStatus *bc.Transa
                outputUtxos := txOutToUtxos(tx, statusFail, validHeight)
                utxos := w.filterAccountUtxo(outputUtxos)
                if err := batchSaveUtxos(utxos, batch); err != nil {
-                       log.WithField("err", err).Error("attachUtxos fail on batchSaveUtxos")
+                       log.WithFields(log.Fields{"module": logModule, "err": err}).Error("attachUtxos fail on batchSaveUtxos")
                }
        }
 }
@@ -93,14 +93,14 @@ func (w *Wallet) detachUtxos(batch db.Batch, b *types.Block, txStatus *bc.Transa
 
                statusFail, err := txStatus.GetStatus(txIndex)
                if err != nil {
-                       log.WithField("err", err).Error("detachUtxos fail on get tx status")
+                       log.WithFields(log.Fields{"module": logModule, "err": err}).Error("detachUtxos fail on get tx status")
                        continue
                }
 
                inputUtxos := txInToUtxos(tx, statusFail)
                utxos := w.filterAccountUtxo(inputUtxos)
                if err := batchSaveUtxos(utxos, batch); err != nil {
-                       log.WithField("err", err).Error("detachUtxos fail on batchSaveUtxos")
+                       log.WithFields(log.Fields{"module": logModule, "err": err}).Error("detachUtxos fail on batchSaveUtxos")
                        return
                }
        }
@@ -131,7 +131,7 @@ func (w *Wallet) filterAccountUtxo(utxos []*account.UTXO) []*account.UTXO {
 
                cp := &account.CtrlProgram{}
                if err := json.Unmarshal(data, cp); err != nil {
-                       log.WithField("err", err).Error("filterAccountUtxo fail on unmarshal control program")
+                       log.WithFields(log.Fields{"module": logModule, "err": err}).Error("filterAccountUtxo fail on unmarshal control program")
                        continue
                }
 
@@ -172,7 +172,7 @@ func txInToUtxos(tx *types.Tx, statusFail bool) []*account.UTXO {
 
                resOut, err := tx.Output(*sp.SpentOutputId)
                if err != nil {
-                       log.WithField("err", err).Error("txInToUtxos fail on get resOut")
+                       log.WithFields(log.Fields{"module": logModule, "err": err}).Error("txInToUtxos fail on get resOut")
                        continue
                }
 
index 08b2f56..8a46330 100644 (file)
@@ -126,7 +126,7 @@ func (w *Wallet) loadWalletInfo() error {
 func (w *Wallet) commitWalletInfo(batch db.Batch) error {
        rawWallet, err := json.Marshal(w.status)
        if err != nil {
-               log.WithField("err", err).Error("save wallet info")
+               log.WithFields(log.Fields{"module": logModule, "err": err}).Error("save wallet info")
                return err
        }
 
@@ -203,12 +203,12 @@ func (w *Wallet) walletUpdater() {
                for !w.chain.InMainChain(w.status.BestHash) {
                        block, err := w.chain.GetBlockByHash(&w.status.BestHash)
                        if err != nil {
-                               log.WithField("err", err).Error("walletUpdater GetBlockByHash")
+                               log.WithFields(log.Fields{"module": logModule, "err": err}).Error("walletUpdater GetBlockByHash")
                                return
                        }
 
                        if err := w.DetachBlock(block); err != nil {
-                               log.WithField("err", err).Error("walletUpdater detachBlock stop")
+                               log.WithFields(log.Fields{"module": logModule, "err": err}).Error("walletUpdater detachBlock stop")
                                return
                        }
                }
@@ -220,7 +220,7 @@ func (w *Wallet) walletUpdater() {
                }
 
                if err := w.AttachBlock(block); err != nil {
-                       log.WithField("err", err).Error("walletUpdater AttachBlock stop")
+                       log.WithFields(log.Fields{"module": logModule, "err": err}).Error("walletUpdater AttachBlock stop")
                        return
                }
        }