LBRYCommunity/lbcd
1
0
Fork 0
Code Issues 17 Pull requests 4 Projects Releases 28 Packages Wiki Activity

Convert btcd to use new btclog package.

Browse source 
Also, make every subsystem within btcd use its own logger instance so each
subsystem can have its own level specified independent of the others.

This is work towards #48.
This commit is contained in:
Dave Collins 2013-11-21 12:03:56 -06:00
parent 41d2d36643
commit eb8688df79
12 changed files with 312 additions and 236 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

40
addrmanager.go
View file

@ -153,7 +153,7 @@ func (a *AddrManager) updateAddress(netAddr, srcAddr *btcwire.NetAddress) {
// Enforce max addresses. // Enforce max addresses.
if len(a.addrNew[bucket]) > newBucketSize { if len(a.addrNew[bucket]) > newBucketSize {
log.Tracef("AMGR: new bucket is full, expiring old ") amgrLog.Tracef("new bucket is full, expiring old ")
a.expireNew(bucket) a.expireNew(bucket)
} }
@ -161,7 +161,7 @@ func (a *AddrManager) updateAddress(netAddr, srcAddr *btcwire.NetAddress) {
ka.refs++ ka.refs++
a.addrNew[bucket][addr] = ka a.addrNew[bucket][addr] = ka
log.Tracef("AMGR: Added new address %s for a total of %d addresses", amgrLog.Tracef("Added new address %s for a total of %d addresses",
addr, a.nTried+a.nNew) addr, a.nTried+a.nNew)
} }
@ -259,7 +259,7 @@ func (a *AddrManager) expireNew(bucket int) {
var oldest *knownAddress var oldest *knownAddress
for k, v := range a.addrNew[bucket] { for k, v := range a.addrNew[bucket] {
if bad(v) { if bad(v) {
log.Tracef("AMGR: expiring bad address %v", k) amgrLog.Tracef("expiring bad address %v", k)
delete(a.addrNew[bucket], k) delete(a.addrNew[bucket], k)
v.refs-- v.refs--
if v.refs == 0 { if v.refs == 0 {
@ -277,7 +277,7 @@ func (a *AddrManager) expireNew(bucket int) {
if oldest != nil { if oldest != nil {
key := NetAddressKey(oldest.na) key := NetAddressKey(oldest.na)
log.Tracef("AMGR: expiring oldest address %v", key) amgrLog.Tracef("expiring oldest address %v", key)
delete(a.addrNew[bucket], key) delete(a.addrNew[bucket], key)
oldest.refs-- oldest.refs--
@ -393,7 +393,7 @@ out:
dumpAddressTicker.Stop() dumpAddressTicker.Stop()
a.savePeers() a.savePeers()
a.wg.Done() a.wg.Done()
log.Trace("AMGR: Address handler done") amgrLog.Trace("Address handler done")
} }
type serialisedKnownAddress struct { type serialisedKnownAddress struct {
@ -465,7 +465,7 @@ func (a *AddrManager) savePeers() {
w, err := os.Create(filePath) w, err := os.Create(filePath)
if err != nil { if err != nil {
log.Error("Error opening file: ", filePath, err) amgrLog.Error("Error opening file: ", filePath, err)
return return
} }
enc := json.NewEncoder(w) enc := json.NewEncoder(w)
@ -485,19 +485,17 @@ func (a *AddrManager) loadPeers() {
err := a.deserialisePeers(filePath) err := a.deserialisePeers(filePath)
if err != nil { if err != nil {
log.Errorf("AMGR: Failed to parse %s: %v", filePath, amgrLog.Errorf("Failed to parse %s: %v", filePath, err)
err)
// if it is invalid we nuke the old one unconditionally. // if it is invalid we nuke the old one unconditionally.
err = os.Remove(filePath) err = os.Remove(filePath)
if err != nil { if err != nil {
log.Warn("Failed to remove corrupt peers "+ amgrLog.Warn("Failed to remove corrupt peers "+
"file: ", err) "file: ", err)
} }
a.reset() a.reset()
return return
} }
log.Infof("AMGR: Loaded %d addresses from '%s'", a.nNew+a.nTried, amgrLog.Infof("Loaded %d addresses from '%s'", a.nNew+a.nTried, filePath)
filePath)
} }
func (a *AddrManager) deserialisePeers(filePath string) error { func (a *AddrManager) deserialisePeers(filePath string) error {
@ -611,7 +609,7 @@ func (a *AddrManager) Start() {
return return
} }
log.Trace("AMGR: Starting address manager") amgrLog.Trace("Starting address manager")
a.wg.Add(1) a.wg.Add(1)
@ -625,12 +623,12 @@ func (a *AddrManager) Start() {
// Stop gracefully shuts down the address manager by stopping the main handler. // Stop gracefully shuts down the address manager by stopping the main handler.
func (a *AddrManager) Stop() error { func (a *AddrManager) Stop() error {
if atomic.AddInt32(&a.shutdown, 1) != 1 { if atomic.AddInt32(&a.shutdown, 1) != 1 {
log.Warnf("AMGR: Address manager is already in the process of " + amgrLog.Warnf("Address manager is already in the process of " +
"shutting down") "shutting down")
return nil return nil
} }
log.Infof("AMGR: Address manager shutting down") amgrLog.Infof("Address manager shutting down")
close(a.quit) close(a.quit)
a.wg.Wait() a.wg.Wait()
return nil return nil
@ -660,7 +658,7 @@ func (a *AddrManager) AddAddressByIP(addrIP string) {
// Split IP and port // Split IP and port
addr, portStr, err := net.SplitHostPort(addrIP) addr, portStr, err := net.SplitHostPort(addrIP)
if err != nil { if err != nil {
log.Warnf("AMGR: AddADddressByIP given bullshit adddress"+ amgrLog.Warnf("AddADddressByIP given bullshit adddress"+
"(%s): %v", err) "(%s): %v", err)
return return
} }
@ -669,12 +667,12 @@ func (a *AddrManager) AddAddressByIP(addrIP string) {
na.Timestamp = time.Now() na.Timestamp = time.Now()
na.IP = net.ParseIP(addr) na.IP = net.ParseIP(addr)
if na.IP == nil { if na.IP == nil {
log.Error("AMGR: Invalid ip address:", addr) amgrLog.Error("Invalid ip address:", addr)
return return
} }
port, err := strconv.ParseUint(portStr, 10, 0) port, err := strconv.ParseUint(portStr, 10, 0)
if err != nil { if err != nil {
log.Error("AMGR: Invalid port: ", portStr, err) amgrLog.Error("Invalid port: ", portStr, err)
return return
} }
na.Port = uint16(port) na.Port = uint16(port)
@ -809,8 +807,8 @@ func (a *AddrManager) GetAddress(class string, newBias int) *knownAddress {
ka := e.Value.(*knownAddress) ka := e.Value.(*knownAddress)
randval := a.rand.Intn(large) randval := a.rand.Intn(large)
if float64(randval) < (factor * chance(ka) * float64(large)) { if float64(randval) < (factor * chance(ka) * float64(large)) {
log.Tracef("AMGR: Selected %v from tried "+ amgrLog.Tracef("Selected %v from tried bucket",
"bucket", NetAddressKey(ka.na)) NetAddressKey(ka.na))
return ka return ka
} }
factor *= 1.2 factor *= 1.2
@ -837,7 +835,7 @@ func (a *AddrManager) GetAddress(class string, newBias int) *knownAddress {
} }
randval := a.rand.Intn(large) randval := a.rand.Intn(large)
if float64(randval) < (factor * chance(ka) * float64(large)) { if float64(randval) < (factor * chance(ka) * float64(large)) {
log.Tracef("AMGR: Selected %v from new bucket", amgrLog.Tracef("Selected %v from new bucket",
NetAddressKey(ka.na)) NetAddressKey(ka.na))
return ka return ka
} }
@ -972,7 +970,7 @@ func (a *AddrManager) Good(addr *btcwire.NetAddress) {
a.nNew++ a.nNew++
rmkey := NetAddressKey(rmka.na) rmkey := NetAddressKey(rmka.na)
log.Tracef("AMGR: replacing %s with %s in tried", rmkey, addrKey) amgrLog.Tracef("Replacing %s with %s in tried", rmkey, addrKey)
// We made sure there is space here just above. // We made sure there is space here just above.
a.addrNew[newBucket][rmkey] = rmka a.addrNew[newBucket][rmkey] = rmka

64
blockmanager.go
View file

@ -92,7 +92,7 @@ func (b *blockManager) startSync(peers *list.List) {
// Find the height of the current known best block. // Find the height of the current known best block.
_, height, err := b.server.db.NewestSha() _, height, err := b.server.db.NewestSha()
if err != nil { if err != nil {
log.Errorf("BMGR: %v", err) bmgrLog.Errorf("%v", err)
return return
} }
@ -122,17 +122,17 @@ func (b *blockManager) startSync(peers *list.List) {
if bestPeer != nil { if bestPeer != nil {
locator, err := b.blockChain.LatestBlockLocator() locator, err := b.blockChain.LatestBlockLocator()
if err != nil { if err != nil {
log.Errorf("BMGR: Failed to get block locator for the "+ bmgrLog.Errorf("Failed to get block locator for the "+
"latest block: %v", err) "latest block: %v", err)
return return
} }
log.Infof("BMGR: Syncing to block height %d from peer %v", bmgrLog.Infof("Syncing to block height %d from peer %v",
bestPeer.lastBlock, bestPeer.addr) bestPeer.lastBlock, bestPeer.addr)
bestPeer.PushGetBlocksMsg(locator, &zeroHash) bestPeer.PushGetBlocksMsg(locator, &zeroHash)
b.syncPeer = bestPeer b.syncPeer = bestPeer
} else { } else {
log.Warnf("BMGR: No sync peer candidates available") bmgrLog.Warnf("No sync peer candidates available")
} }
} }
@ -173,7 +173,7 @@ func (b *blockManager) handleNewPeerMsg(peers *list.List, p *peer) {
return return
} }
log.Infof("BMGR: New valid peer %s", p) bmgrLog.Infof("New valid peer %s", p)
// Ignore the peer if it's not a sync candidate. // Ignore the peer if it's not a sync candidate.
if !b.isSyncCandidate(p) { if !b.isSyncCandidate(p) {
@ -200,7 +200,7 @@ func (b *blockManager) handleDonePeerMsg(peers *list.List, p *peer) {
} }
} }
log.Infof("BMGR: Lost peer %s", p) bmgrLog.Infof("Lost peer %s", p)
// Remove requested transactions from the global map so that they will // Remove requested transactions from the global map so that they will
// be fetched from elsewhere next time we get an inv. // be fetched from elsewhere next time we get an inv.
@ -257,7 +257,7 @@ func (b *blockManager) logBlockHeight(numTx, height int64, latestHash *btcwire.S
if b.receivedLogTx == 1 { if b.receivedLogTx == 1 {
txStr = "transaction" txStr = "transaction"
} }
log.Infof("BMGR: Processed %d %s in the last %s (%d %s, height %d%s)", bmgrLog.Infof("Processed %d %s in the last %s (%d %s, height %d%s)",
b.receivedLogBlocks, blockStr, tDuration, b.receivedLogTx, b.receivedLogBlocks, blockStr, tDuration, b.receivedLogTx,
txStr, height, blockTimeStr) txStr, height, blockTimeStr)
@ -273,7 +273,7 @@ func (b *blockManager) handleTxMsg(tmsg *txMsg) {
// If we didn't ask for this transaction then the peer is misbehaving. // If we didn't ask for this transaction then the peer is misbehaving.
if _, ok := tmsg.peer.requestedTxns[*txHash]; !ok { if _, ok := tmsg.peer.requestedTxns[*txHash]; !ok {
log.Warnf("BMGR: Got unrequested transaction %v from %s -- "+ bmgrLog.Warnf("Got unrequested transaction %v from %s -- "+
"disconnecting", txHash, tmsg.peer.addr) "disconnecting", txHash, tmsg.peer.addr)
tmsg.peer.Disconnect() tmsg.peer.Disconnect()
return return
@ -296,9 +296,9 @@ func (b *blockManager) handleTxMsg(tmsg *txMsg) {
// so log it as such. Otherwise, something really did go wrong, // so log it as such. Otherwise, something really did go wrong,
// so log it as an actual error. // so log it as an actual error.
if _, ok := err.(TxRuleError); ok { if _, ok := err.(TxRuleError); ok {
log.Debugf("Rejected transaction %v: %v", txHash, err) bmgrLog.Debugf("Rejected transaction %v: %v", txHash, err)
} else { } else {
log.Errorf("Failed to process transaction %v: %v", txHash, err) bmgrLog.Errorf("Failed to process transaction %v: %v", txHash, err)
} }
return return
} }
@ -343,7 +343,7 @@ func (b *blockManager) handleBlockMsg(bmsg *blockMsg) {
// mode in this case so the chain code is actually fed the // mode in this case so the chain code is actually fed the
// duplicate blocks. // duplicate blocks.
if !cfg.RegressionTest { if !cfg.RegressionTest {
log.Warnf("BMGR: Got unrequested block %v from %s -- "+ bmgrLog.Warnf("Got unrequested block %v from %s -- "+
"disconnecting", blockSha, bmsg.peer.addr) "disconnecting", blockSha, bmsg.peer.addr)
bmsg.peer.Disconnect() bmsg.peer.Disconnect()
return return
@ -369,9 +369,9 @@ func (b *blockManager) handleBlockMsg(bmsg *blockMsg) {
// it as such. Otherwise, something really did go wrong, so log // it as such. Otherwise, something really did go wrong, so log
// it as an actual error. // it as an actual error.
if _, ok := err.(btcchain.RuleError); ok { if _, ok := err.(btcchain.RuleError); ok {
log.Infof("BMGR: Rejected block %v: %v", blockSha, err) bmgrLog.Infof("Rejected block %v: %v", blockSha, err)
} else { } else {
log.Errorf("BMGR: Failed to process block %v: %v", blockSha, err) bmgrLog.Errorf("Failed to process block %v: %v", blockSha, err)
} }
return return
} }
@ -385,7 +385,7 @@ func (b *blockManager) handleBlockMsg(bmsg *blockMsg) {
// Log info about the new block height. // Log info about the new block height.
latestHash, height, err := b.server.db.NewestSha() latestHash, height, err := b.server.db.NewestSha()
if err != nil { if err != nil {
log.Warnf("BMGR: Failed to obtain latest sha - %v", err) bmgrLog.Warnf("Failed to obtain latest sha - %v", err)
return return
} }
b.logBlockHeight(int64(len(bmsg.block.MsgBlock().Transactions)), height, b.logBlockHeight(int64(len(bmsg.block.MsgBlock().Transactions)), height,
@ -484,7 +484,7 @@ func (b *blockManager) handleInvMsg(imsg *invMsg) {
orphanRoot := chain.GetOrphanRoot(&iv.Hash) orphanRoot := chain.GetOrphanRoot(&iv.Hash)
locator, err := chain.LatestBlockLocator() locator, err := chain.LatestBlockLocator()
if err != nil { if err != nil {
log.Errorf("PEER: Failed to get block "+ bmgrLog.Errorf("PEER: Failed to get block "+
"locator for the latest block: "+ "locator for the latest block: "+
"%v", err) "%v", err)
continue continue
@ -586,7 +586,7 @@ out:
} }
} }
b.wg.Done() b.wg.Done()
log.Trace("BMGR: Block handler done") bmgrLog.Trace("Block handler done")
} }
// handleNotifyMsg handles notifications from btcchain. It does things such // handleNotifyMsg handles notifications from btcchain. It does things such
@ -601,14 +601,14 @@ func (b *blockManager) handleNotifyMsg(notification *btcchain.Notification) {
orphanRoot := b.blockChain.GetOrphanRoot(orphanHash) orphanRoot := b.blockChain.GetOrphanRoot(orphanHash)
locator, err := b.blockChain.LatestBlockLocator() locator, err := b.blockChain.LatestBlockLocator()
if err != nil { if err != nil {
log.Errorf("BMGR: Failed to get block locator "+ bmgrLog.Errorf("Failed to get block locator "+
"for the latest block: %v", err) "for the latest block: %v", err)
break break
} }
peer.PushGetBlocksMsg(locator, orphanRoot) peer.PushGetBlocksMsg(locator, orphanRoot)
delete(b.blockPeer, *orphanRoot) delete(b.blockPeer, *orphanRoot)
} else { } else {
log.Warnf("Notification for orphan %v with no peer", bmgrLog.Warnf("Notification for orphan %v with no peer",
orphanHash) orphanHash)
} }
@ -624,7 +624,7 @@ func (b *blockManager) handleNotifyMsg(notification *btcchain.Notification) {
block, ok := notification.Data.(*btcutil.Block) block, ok := notification.Data.(*btcutil.Block)
if !ok { if !ok {
log.Warnf("BMGR: Chain accepted notification is not a block.") bmgrLog.Warnf("Chain accepted notification is not a block.")
break break
} }
@ -640,7 +640,7 @@ func (b *blockManager) handleNotifyMsg(notification *btcchain.Notification) {
case btcchain.NTBlockConnected: case btcchain.NTBlockConnected:
block, ok := notification.Data.(*btcutil.Block) block, ok := notification.Data.(*btcutil.Block)
if !ok { if !ok {
log.Warnf("BMGR: Chain connected notification is not a block.") bmgrLog.Warnf("Chain connected notification is not a block.")
break break
} }
@ -667,7 +667,7 @@ func (b *blockManager) handleNotifyMsg(notification *btcchain.Notification) {
case btcchain.NTBlockDisconnected: case btcchain.NTBlockDisconnected:
block, ok := notification.Data.(*btcutil.Block) block, ok := notification.Data.(*btcutil.Block)
if !ok { if !ok {
log.Warnf("BMGR: Chain disconnected notification is not a block.") bmgrLog.Warnf("Chain disconnected notification is not a block.")
break break
} }
@ -751,7 +751,7 @@ func (b *blockManager) Start() {
return return
} }
log.Trace("BMGR: Starting block manager") bmgrLog.Trace("Starting block manager")
b.wg.Add(1) b.wg.Add(1)
go b.blockHandler() go b.blockHandler()
} }
@ -760,12 +760,12 @@ func (b *blockManager) Start() {
// handlers and waiting for them to finish. // handlers and waiting for them to finish.
func (b *blockManager) Stop() error { func (b *blockManager) Stop() error {
if atomic.AddInt32(&b.shutdown, 1) != 1 { if atomic.AddInt32(&b.shutdown, 1) != 1 {
log.Warnf("BMGR: Block manager is already in the process of " + bmgrLog.Warnf("Block manager is already in the process of " +
"shutting down") "shutting down")
return nil return nil
} }
log.Infof("BMGR: Block manager shutting down") bmgrLog.Infof("Block manager shutting down")
close(b.quit) close(b.quit)
b.wg.Wait() b.wg.Wait()
return nil return nil
@ -786,16 +786,16 @@ func newBlockManager(s *server) (*blockManager, error) {
bm.blockChain = btcchain.New(s.db, s.btcnet, bm.handleNotifyMsg) bm.blockChain = btcchain.New(s.db, s.btcnet, bm.handleNotifyMsg)
bm.blockChain.DisableCheckpoints(cfg.DisableCheckpoints) bm.blockChain.DisableCheckpoints(cfg.DisableCheckpoints)
if cfg.DisableCheckpoints { if cfg.DisableCheckpoints {
log.Info("BMGR: Checkpoints are disabled") bmgrLog.Info("Checkpoints are disabled")
} }
log.Infof("BMGR: Generating initial block node index. This may " + bmgrLog.Infof("Generating initial block node index. This may " +
"take a while...") "take a while...")
err := bm.blockChain.GenerateInitialIndex() err := bm.blockChain.GenerateInitialIndex()
if err != nil { if err != nil {
return nil, err return nil, err
} }
log.Infof("BMGR: Block index generation complete") bmgrLog.Infof("Block index generation complete")
return &bm, nil return &bm, nil
} }
@ -811,7 +811,7 @@ func removeRegressionDB(dbPath string) error {
// Remove the old regression test database if it already exists. // Remove the old regression test database if it already exists.
fi, err := os.Stat(dbPath) fi, err := os.Stat(dbPath)
if err == nil { if err == nil {
log.Infof("BMGR: Removing regression test database from '%s'", dbPath) btcdLog.Infof("Removing regression test database from '%s'", dbPath)
if fi.IsDir() { if fi.IsDir() {
err := os.RemoveAll(dbPath) err := os.RemoveAll(dbPath)
if err != nil { if err != nil {
@ -863,7 +863,7 @@ func warnMultipeDBs() {
// Warn if there are extra databases. // Warn if there are extra databases.
if len(duplicateDbPaths) > 0 { if len(duplicateDbPaths) > 0 {
selectedDbPath := blockDbPath(cfg.DbType) selectedDbPath := blockDbPath(cfg.DbType)
log.Warnf("WARNING: There are multiple block chain databases "+ btcdLog.Warnf("WARNING: There are multiple block chain databases "+
"using different database types.\nYou probably don't "+ "using different database types.\nYou probably don't "+
"want to waste disk space by having more than one.\n"+ "want to waste disk space by having more than one.\n"+
"Your current database is located at [%v].\nThe "+ "Your current database is located at [%v].\nThe "+
@ -883,7 +883,7 @@ func loadBlockDB() (btcdb.Db, error) {
// each run, so remove it now if it already exists. // each run, so remove it now if it already exists.
removeRegressionDB(dbPath) removeRegressionDB(dbPath)
log.Infof("BMGR: Loading block database from '%s'", dbPath) btcdLog.Infof("Loading block database from '%s'", dbPath)
db, err := btcdb.OpenDB(cfg.DbType, dbPath) db, err := btcdb.OpenDB(cfg.DbType, dbPath)
if err != nil { if err != nil {
// Return the error if it's not because the database doesn't // Return the error if it's not because the database doesn't
@ -919,11 +919,11 @@ func loadBlockDB() (btcdb.Db, error) {
db.Close() db.Close()
return nil, err return nil, err
} }
log.Infof("BMGR: Inserted genesis block %v", btcdLog.Infof("Inserted genesis block %v",
activeNetParams.genesisHash) activeNetParams.genesisHash)
height = 0 height = 0
} }
log.Infof("BMGR: Block database loaded with block height %d", height) btcdLog.Infof("Block database loaded with block height %d", height)
return db, nil return db, nil
} }

31
btcd.go
View file

@ -21,14 +21,9 @@ var (
// btcdMain is the real main function for btcd. It is necessary to work around // btcdMain is the real main function for btcd. It is necessary to work around
// the fact that deferred functions do not run when os.Exit() is called. // the fact that deferred functions do not run when os.Exit() is called.
func btcdMain() error { func btcdMain() error {
// Initialize logging and setup deferred flushing to ensure all // Initialize logging at the default logging level.
// outstanding messages are written on shutdown. setLogLevels(defaultLogLevel)
loggers := setLogLevel(defaultLogLevel) defer backendLog.Flush()
defer func() {
for _, logger := range loggers {
logger.Flush()
}
}()
// Load configuration and parse command line. // Load configuration and parse command line.
tcfg, _, err := loadConfig() tcfg, _, err := loadConfig()
@ -39,21 +34,21 @@ func btcdMain() error {
// Change the logging level if needed. // Change the logging level if needed.
if cfg.DebugLevel != defaultLogLevel { if cfg.DebugLevel != defaultLogLevel {
loggers = setLogLevel(cfg.DebugLevel) setLogLevels(cfg.DebugLevel)
} }
// Show version at startup. // Show version at startup.
log.Infof("Version %s", version()) btcdLog.Infof("Version %s", version())
// Enable http profiling server if requested. // Enable http profiling server if requested.
if cfg.Profile != "" { if cfg.Profile != "" {
go func() { go func() {
listenAddr := net.JoinHostPort("", cfg.Profile) listenAddr := net.JoinHostPort("", cfg.Profile)
log.Infof("Profile server listening on %s", listenAddr) btcdLog.Infof("Profile server listening on %s", listenAddr)
profileRedirect := http.RedirectHandler("/debug/pprof", profileRedirect := http.RedirectHandler("/debug/pprof",
http.StatusSeeOther) http.StatusSeeOther)
http.Handle("/", profileRedirect) http.Handle("/", profileRedirect)
log.Errorf("%v", http.ListenAndServe(listenAddr, nil)) btcdLog.Errorf("%v", http.ListenAndServe(listenAddr, nil))
}() }()
} }
@ -61,7 +56,7 @@ func btcdMain() error {
if cfg.CpuProfile != "" { if cfg.CpuProfile != "" {
f, err := os.Create(cfg.CpuProfile) f, err := os.Create(cfg.CpuProfile)
if err != nil { if err != nil {
log.Errorf("Unable to create cpu profile: %v", err) btcdLog.Errorf("Unable to create cpu profile: %v", err)
return err return err
} }
pprof.StartCPUProfile(f) pprof.StartCPUProfile(f)
@ -70,21 +65,21 @@ func btcdMain() error {
// Perform upgrades to btcd as new versions require it. // Perform upgrades to btcd as new versions require it.
if err := doUpgrades(); err != nil { if err := doUpgrades(); err != nil {
log.Errorf("%v", err) btcdLog.Errorf("%v", err)
return err return err
} }
// Load the block database. // Load the block database.
db, err := loadBlockDB() db, err := loadBlockDB()
if err != nil { if err != nil {
log.Errorf("%v", err) btcdLog.Errorf("%v", err)
return err return err
} }
defer db.Close() defer db.Close()
// Ensure the database is sync'd and closed on Ctrl+C. // Ensure the database is sync'd and closed on Ctrl+C.
addInterruptHandler(func() { addInterruptHandler(func() {
log.Infof("Gracefully shutting down the database...") btcdLog.Infof("Gracefully shutting down the database...")
db.RollbackClose() db.RollbackClose()
}) })
@ -92,7 +87,7 @@ func btcdMain() error {
server, err := newServer(cfg.Listeners, db, activeNetParams.btcnet) server, err := newServer(cfg.Listeners, db, activeNetParams.btcnet)
if err != nil { if err != nil {
// TODO(oga) this logging could do with some beautifying. // TODO(oga) this logging could do with some beautifying.
log.Errorf("Unable to start server on %v: %v", btcdLog.Errorf("Unable to start server on %v: %v",
cfg.Listeners, err) cfg.Listeners, err)
return err return err
} }
@ -112,7 +107,7 @@ func btcdMain() error {
// Wait for shutdown signal from either a graceful server stop or from // Wait for shutdown signal from either a graceful server stop or from
// the interrupt handler. // the interrupt handler.
<-shutdownChannel <-shutdownChannel
log.Info("Shutdown complete") btcdLog.Info("Shutdown complete")
return nil return nil
} }

4
config.go
View file

@ -189,7 +189,7 @@ func loadConfig() (*config, []string, error) {
// Create the home directory if it doesn't already exist. // Create the home directory if it doesn't already exist.
err := os.MkdirAll(btcdHomeDir, 0700) err := os.MkdirAll(btcdHomeDir, 0700)
if err != nil { if err != nil {
log.Errorf("%v", err) btcdLog.Errorf("%v", err)
return nil, nil, err return nil, nil, err
} }
@ -218,7 +218,7 @@ func loadConfig() (*config, []string, error) {
parser.WriteHelp(os.Stderr) parser.WriteHelp(os.Stderr)
return nil, nil, err return nil, nil, err
} }
log.Warnf("%v", err) btcdLog.Warnf("%v", err)
} }
} }

6
discovery.go
View file

@ -150,7 +150,7 @@ func torLookupIP(host, proxy string) ([]net.IP, error) {
// any hosts in the list. Therefore if all hosts failed an empty slice of // any hosts in the list. Therefore if all hosts failed an empty slice of
// strings will be returned. // strings will be returned.
func dnsDiscover(seeder string, proxy string) []net.IP { func dnsDiscover(seeder string, proxy string) []net.IP {
log.Debugf("DISC: Fetching list of seeds from %v", seeder) discLog.Debugf("Fetching list of seeds from %v", seeder)
peers, err := doDNSLookup(seeder, proxy) peers, err := doDNSLookup(seeder, proxy)
if err != nil { if err != nil {
seederPlusProxy := seeder seederPlusProxy := seeder
@ -158,8 +158,8 @@ func dnsDiscover(seeder string, proxy string) []net.IP {
seederPlusProxy = fmt.Sprintf("%s (proxy %s)", seederPlusProxy = fmt.Sprintf("%s (proxy %s)",
seeder, proxy) seeder, proxy)
} }
log.Debugf("DISC: Unable to fetch dns seeds "+ discLog.Debugf("Unable to fetch dns seeds from %s: %v",
"from %s: %v", seederPlusProxy, err) seederPlusProxy, err)
return []net.IP{} return []net.IP{}
} }

159
log.go
View file

@ -8,6 +8,7 @@ import (
"fmt" "fmt"
"github.com/conformal/btcchain" "github.com/conformal/btcchain"
"github.com/conformal/btcdb" "github.com/conformal/btcdb"
"github.com/conformal/btclog"
"github.com/conformal/btcscript" "github.com/conformal/btcscript"
"github.com/conformal/btcwire" "github.com/conformal/btcwire"
"github.com/conformal/seelog" "github.com/conformal/seelog"
@ -24,10 +25,40 @@ const (
lockTimeThreshold uint32 = 5e8 // Tue Nov 5 00:53:20 1985 UTC lockTimeThreshold uint32 = 5e8 // Tue Nov 5 00:53:20 1985 UTC
) )
// Loggers per subsytem. Note that backendLog is a seelog logger that all of
// the subsystem loggers route their messages to. When adding new subsystems,
// add a reference here, to the subsystemLoggers map, and the useLogger
// function.
var ( var (
log = seelog.Disabled backendLog = seelog.Disabled
btcdLog = btclog.Disabled
bcdbLog = btclog.Disabled
chanLog = btclog.Disabled
scrpLog = btclog.Disabled
amgrLog = btclog.Disabled
bmgrLog = btclog.Disabled
discLog = btclog.Disabled
peerLog = btclog.Disabled
rpcsLog = btclog.Disabled
srvrLog = btclog.Disabled
txmpLog = btclog.Disabled
) )
// subsystemLoggers maps each subsystem identifier to its associated logger.
var subsystemLoggers = map[string]btclog.Logger{
"BTCD": btcdLog,
"BCDB": bcdbLog,
"CHAN": chanLog,
"SCRP": scrpLog,
"AMGR": amgrLog,
"BMGR": bmgrLog,
"DISC": discLog,
"PEER": peerLog,
"RPCS": rpcsLog,
"SRVR": srvrLog,
"TXMP": txmpLog,
}
// logClosure is used to provide a closure over expensive logging operations // logClosure is used to provide a closure over expensive logging operations
// so don't have to be performed when the logging level doesn't warrant it. // so don't have to be performed when the logging level doesn't warrant it.
type logClosure func() string type logClosure func() string
@ -44,22 +75,67 @@ func newLogClosure(c func() string) logClosure {
return logClosure(c) return logClosure(c)
} }
// newLogger creates a new seelog logger using the provided logging level and // useLogger updates the logger references for subsystemID to logger. Invalid
// log message prefix. // subsystems are ignored.
func newLogger(level string, prefix string) seelog.LoggerInterface { func useLogger(subsystemID string, logger btclog.Logger) {
//<seelog type="adaptive" mininterval="2000000" maxinterval="100000000" if _, ok := subsystemLoggers[subsystemID]; !ok {
// critmsgcount="500" minlevel="%s"> return
}
subsystemLoggers[subsystemID] = logger
fmtstring := ` switch subsystemID {
<seelog type="sync" minlevel="%s"> case "BTCD":
btcdLog = logger
case "BCDB":
bcdbLog = logger
btcdb.UseLogger(logger)
case "CHAN":
chanLog = logger
btcchain.UseLogger(logger)
case "SCRP":
scrpLog = logger
btcscript.UseLogger(logger)
case "AMGR":
amgrLog = logger
case "BMGR":
bmgrLog = logger
case "DISC":
discLog = logger
case "PEER":
peerLog = logger
case "RPCS":
rpcsLog = logger
case "SRVR":
srvrLog = logger
case "TXMP":
txmpLog = logger
}
}
// newSeelogLogger creates a new seelog logger.
func newSeelogLogger() seelog.LoggerInterface {
// <seelog type="sync" minlevel="trace">
config := `
<seelog type="adaptive" mininterval="2000000" maxinterval="100000000"
critmsgcount="500" minlevel="trace">
<outputs formatid="all"> <outputs formatid="all">
<console/> <console/>
</outputs> </outputs>
<formats> <formats>
<format id="all" format="%%Time %%Date [%%LEV] %s: %%Msg%%n" /> <format id="all" format="%Time %Date [%LEV] %Msg%n" />
</formats> </formats>
</seelog>` </seelog>`
config := fmt.Sprintf(fmtstring, level, prefix)
logger, err := seelog.LoggerFromConfigAsString(config) logger, err := seelog.LoggerFromConfigAsString(config)
if err != nil { if err != nil {
@ -70,37 +146,44 @@ func newLogger(level string, prefix string) seelog.LoggerInterface {
return logger return logger
} }
// useLogger sets the btcd logger to the passed logger. // setLogLevel sets the logging level for provided subsystem. Invalid
func useLogger(logger seelog.LoggerInterface) { // subsystems are ignored. Uninitialized subsystems are dynamically created as
log = logger // needed.
func setLogLevel(subsystemID string, logLevel string) {
// Create the backend seelog logger if needed.
if backendLog == seelog.Disabled {
backendLog = newSeelogLogger()
}
// Ignore invalid subsystems.
logger, ok := subsystemLoggers[subsystemID]
if !ok {
return
}
// Default to info if the log level is invalid.
level, ok := btclog.LogLevelFromString(logLevel)
if !ok {
level = btclog.InfoLvl
}
// Create new logger for the subsystem if needed.
if logger == btclog.Disabled {
logger = btclog.NewSubsystemLogger(backendLog, subsystemID+": ")
useLogger(subsystemID, logger)
}
logger.SetLevel(level)
} }
// setLogLevel sets the log level for the logging system. It initializes a // setLogLevels sets the log level for all subsystem loggers to the passed
// logger for each subsystem at the provided level. // level. It also dynamically creates the subsystem loggers as needed, so it
func setLogLevel(logLevel string) []seelog.LoggerInterface { // can be used to initialize the logging system.
var loggers []seelog.LoggerInterface func setLogLevels(logLevel string) {
// Configure all sub-systems with the new logging level. Dynamically
// Define sub-systems. // create loggers as needed.
subSystems := []struct { for subsystemID := range subsystemLoggers {
level string setLogLevel(subsystemID, logLevel)
prefix string
useLogger func(seelog.LoggerInterface)
}{
{logLevel, "BTCD", useLogger},
{logLevel, "BCDB", btcdb.UseLogger},
{logLevel, "CHAN", btcchain.UseLogger},
{logLevel, "SCRP", btcscript.UseLogger},
} }
// Configure all sub-systems with new loggers while keeping track of
// the created loggers to return so they can be flushed.
for _, s := range subSystems {
newLog := newLogger(s.level, s.prefix)
loggers = append(loggers, newLog)
s.useLogger(newLog)
}
return loggers
} }
// directionString is a helper function that returns a string that represents // directionString is a helper function that returns a string that represents

6
mempool.go
View file

@ -465,7 +465,7 @@ func (mp *txMemPool) addOrphan(tx *btcutil.Tx) {
mp.orphansByPrev[originTxHash].PushBack(tx) mp.orphansByPrev[originTxHash].PushBack(tx)
} }
log.Debugf("TXMP: Stored orphan transaction %v (total: %d)", tx.Sha(), txmpLog.Debugf("Stored orphan transaction %v (total: %d)", tx.Sha(),
len(mp.orphans)) len(mp.orphans))
} }
@ -858,7 +858,7 @@ func (mp *txMemPool) maybeAcceptTransaction(tx *btcutil.Tx, isOrphan *bool) erro
// Add to transaction pool. // Add to transaction pool.
mp.addTransaction(tx) mp.addTransaction(tx)
log.Debugf("TXMP: Accepted transaction %v (pool size: %v)", txHash, txmpLog.Debugf("Accepted transaction %v (pool size: %v)", txHash,
len(mp.pool)) len(mp.pool))
// TODO(davec): Notifications // TODO(davec): Notifications
@ -953,7 +953,7 @@ func (mp *txMemPool) ProcessTransaction(tx *btcutil.Tx) error {
mp.Lock() mp.Lock()
defer mp.Unlock() defer mp.Unlock()
log.Tracef("TXMP: Processing transaction %v", tx.Sha()) txmpLog.Tracef("Processing transaction %v", tx.Sha())
// Potentially accept the transaction to the memory pool. // Potentially accept the transaction to the memory pool.
var isOrphan bool var isOrphan bool

88
peer.go
View file

@ -224,7 +224,7 @@ func (p *peer) pushVersionMsg() error {
func (p *peer) handleVersionMsg(msg *btcwire.MsgVersion) { func (p *peer) handleVersionMsg(msg *btcwire.MsgVersion) {
// Detect self connections. // Detect self connections.
if msg.Nonce == p.server.nonce { if msg.Nonce == p.server.nonce {
log.Debugf("PEER: Disconnecting peer connected to self %s", peerLog.Debugf("Disconnecting peer connected to self %s",
p.addr) p.addr)
p.Disconnect() p.Disconnect()
return return
@ -241,7 +241,7 @@ func (p *peer) handleVersionMsg(msg *btcwire.MsgVersion) {
// Negotiate the protocol version. // Negotiate the protocol version.
p.protocolVersion = minUint32(p.protocolVersion, uint32(msg.ProtocolVersion)) p.protocolVersion = minUint32(p.protocolVersion, uint32(msg.ProtocolVersion))
p.versionKnown = true p.versionKnown = true
log.Debugf("PEER: Negotiated protocol version %d for peer %s", peerLog.Debugf("Negotiated protocol version %d for peer %s",
p.protocolVersion, p.addr) p.protocolVersion, p.addr)
p.lastBlock = msg.LastBlock p.lastBlock = msg.LastBlock
@ -257,7 +257,7 @@ func (p *peer) handleVersionMsg(msg *btcwire.MsgVersion) {
// Send version. // Send version.
err := p.pushVersionMsg() err := p.pushVersionMsg()
if err != nil { if err != nil {
p.logError("PEER: Can't send version message: %v", err) p.logError("Can't send version message: %v", err)
p.Disconnect() p.Disconnect()
return return
} }
@ -267,7 +267,7 @@ func (p *peer) handleVersionMsg(msg *btcwire.MsgVersion) {
// at connection time and no point recomputing. // at connection time and no point recomputing.
na, err := newNetAddress(p.conn.RemoteAddr(), p.services) na, err := newNetAddress(p.conn.RemoteAddr(), p.services)
if err != nil { if err != nil {
p.logError("PEER: Can't get remote address: %v", err) p.logError("Can't get remote address: %v", err)
p.Disconnect() p.Disconnect()
return return
} }
@ -285,7 +285,7 @@ func (p *peer) handleVersionMsg(msg *btcwire.MsgVersion) {
// Advertise the local address. // Advertise the local address.
na, err := newNetAddress(p.conn.LocalAddr(), p.services) na, err := newNetAddress(p.conn.LocalAddr(), p.services)
if err != nil { if err != nil {
p.logError("PEER: Can't advertise local "+ p.logError("Can't advertise local "+
"address: %v", err) "address: %v", err)
p.Disconnect() p.Disconnect()
return return
@ -329,7 +329,7 @@ func (p *peer) pushTxMsg(sha *btcwire.ShaHash, doneChan chan bool) error {
// to fetch a missing transaction results in the same behavior. // to fetch a missing transaction results in the same behavior.
tx, err := p.server.txMemPool.FetchTransaction(sha) tx, err := p.server.txMemPool.FetchTransaction(sha)
if err != nil { if err != nil {
log.Tracef("PEER: Unable to fetch tx %v from transaction "+ peerLog.Tracef("Unable to fetch tx %v from transaction "+
"pool: %v", sha, err) "pool: %v", sha, err)
return err return err
} }
@ -357,7 +357,7 @@ func (p *peer) pushBlockMsg(sha *btcwire.ShaHash, doneChan chan bool) error {
blk, err := p.server.db.FetchBlockBySha(sha) blk, err := p.server.db.FetchBlockBySha(sha)
if err != nil { if err != nil {
log.Tracef("PEER: Unable to fetch requested block sha %v: %v", peerLog.Tracef("Unable to fetch requested block sha %v: %v",
sha, err) sha, err)
return err return err
} }
@ -410,7 +410,7 @@ func (p *peer) PushGetBlocksMsg(locator btcchain.BlockLocator, stopHash *btcwire
beginHash != nil && stopHash.IsEqual(p.prevGetBlocksStop) && beginHash != nil && stopHash.IsEqual(p.prevGetBlocksStop) &&
beginHash.IsEqual(p.prevGetBlocksBegin) { beginHash.IsEqual(p.prevGetBlocksBegin) {
log.Tracef("PEER: Filtering duplicate [getblocks] with begin "+ peerLog.Tracef("Filtering duplicate [getblocks] with begin "+
"hash %v, stop hash %v", beginHash, stopHash) "hash %v, stop hash %v", beginHash, stopHash)
return nil return nil
} }
@ -492,7 +492,7 @@ func (p *peer) handleBlockMsg(msg *btcwire.MsgBlock, buf []byte) {
// Add the block to the known inventory for the peer. // Add the block to the known inventory for the peer.
hash, err := block.Sha() hash, err := block.Sha()
if err != nil { if err != nil {
log.Errorf("Unable to get block hash: %v", err) peerLog.Errorf("Unable to get block hash: %v", err)
return return
} }
iv := btcwire.NewInvVect(btcwire.InvTypeBlock, hash) iv := btcwire.NewInvVect(btcwire.InvTypeBlock, hash)
@ -541,7 +541,7 @@ out:
case btcwire.InvTypeBlock: case btcwire.InvTypeBlock:
err = p.pushBlockMsg(&iv.Hash, c) err = p.pushBlockMsg(&iv.Hash, c)
default: default:
log.Warnf("PEER: Unknown type in inventory request %d", peerLog.Warnf("Unknown type in inventory request %d",
iv.Type) iv.Type)
break out break out
} }
@ -607,7 +607,7 @@ func (p *peer) handleGetBlocksMsg(msg *btcwire.MsgGetBlocks) {
// Fetch the inventory from the block database. // Fetch the inventory from the block database.
hashList, err := p.server.db.FetchHeightRange(start, endIdx) hashList, err := p.server.db.FetchHeightRange(start, endIdx)
if err != nil { if err != nil {
log.Warnf("PEER: Block lookup failed: %v", err) peerLog.Warnf("Block lookup failed: %v", err)
return return
} }
@ -701,7 +701,7 @@ func (p *peer) handleGetHeadersMsg(msg *btcwire.MsgGetHeaders) {
// Fetch the inventory from the block database. // Fetch the inventory from the block database.
hashList, err := p.server.db.FetchHeightRange(start, endIdx) hashList, err := p.server.db.FetchHeightRange(start, endIdx)
if err != nil { if err != nil {
log.Warnf("PEER: Header lookup failed: %v", err) peerLog.Warnf("Header lookup failed: %v", err)
return return
} }
@ -715,7 +715,7 @@ func (p *peer) handleGetHeadersMsg(msg *btcwire.MsgGetHeaders) {
for _, hash := range hashList { for _, hash := range hashList {
block, err := p.server.db.FetchBlockBySha(&hash) block, err := p.server.db.FetchBlockBySha(&hash)
if err != nil { if err != nil {
log.Warnf("PEER: Lookup of known block hash "+ peerLog.Warnf("Lookup of known block hash "+
"failed: %v", err) "failed: %v", err)
continue continue
} }
@ -741,7 +741,7 @@ func (p *peer) handleGetAddrMsg(msg *btcwire.MsgGetAddr) {
// Push the addresses. // Push the addresses.
err := p.pushAddrMsg(addrCache) err := p.pushAddrMsg(addrCache)
if err != nil { if err != nil {
p.logError("PEER: Can't push address message: %v", err) p.logError("Can't push address message: %v", err)
p.Disconnect() p.Disconnect()
return return
} }
@ -794,7 +794,7 @@ func (p *peer) handleAddrMsg(msg *btcwire.MsgAddr) {
// A message that has no addresses is invalid. // A message that has no addresses is invalid.
if len(msg.AddrList) == 0 { if len(msg.AddrList) == 0 {
p.logError("PEER: Command [%s] from %s does not contain any addresses", p.logError("Command [%s] from %s does not contain any addresses",
msg.Command(), p.addr) msg.Command(), p.addr)
p.Disconnect() p.Disconnect()
return return
@ -847,20 +847,20 @@ func (p *peer) readMessage() (msg btcwire.Message, buf []byte, err error) {
// Use closures to log expensive operations so they are only run when // Use closures to log expensive operations so they are only run when
// the logging level requires it. // the logging level requires it.
log.Debugf("%v", newLogClosure(func() string { peerLog.Debugf("%v", newLogClosure(func() string {
// Debug summary of message. // Debug summary of message.
summary := messageSummary(msg) summary := messageSummary(msg)
if len(summary) > 0 { if len(summary) > 0 {
summary = " (" + summary + ")" summary = " (" + summary + ")"
} }
return fmt.Sprintf("PEER: Received %v%s from %s", return fmt.Sprintf("Received %v%s from %s",
msg.Command(), summary, p.addr) msg.Command(), summary, p.addr)
})) }))
log.Tracef("%v", newLogClosure(func() string { peerLog.Tracef("%v", newLogClosure(func() string {
return "PEER: " + spew.Sdump(msg) return spew.Sdump(msg)
})) }))
log.Tracef("%v", newLogClosure(func() string { peerLog.Tracef("%v", newLogClosure(func() string {
return "PEER: " + spew.Sdump(buf) return spew.Sdump(buf)
})) }))
return return
@ -885,32 +885,32 @@ func (p *peer) writeMessage(msg btcwire.Message) {
// Use closures to log expensive operations so they are only run when // Use closures to log expensive operations so they are only run when
// the logging level requires it. // the logging level requires it.
log.Debugf("%v", newLogClosure(func() string { peerLog.Debugf("%v", newLogClosure(func() string {
// Debug summary of message. // Debug summary of message.
summary := messageSummary(msg) summary := messageSummary(msg)
if len(summary) > 0 { if len(summary) > 0 {
summary = " (" + summary + ")" summary = " (" + summary + ")"
} }
return fmt.Sprintf("PEER: Sending %v%s to %s", msg.Command(), return fmt.Sprintf("Sending %v%s to %s", msg.Command(),
summary, p.addr) summary, p.addr)
})) }))
log.Tracef("%v", newLogClosure(func() string { peerLog.Tracef("%v", newLogClosure(func() string {
return "PEER: " + spew.Sdump(msg) return spew.Sdump(msg)
})) }))
log.Tracef("%v", newLogClosure(func() string { peerLog.Tracef("%v", newLogClosure(func() string {
var buf bytes.Buffer var buf bytes.Buffer
err := btcwire.WriteMessage(&buf, msg, p.protocolVersion, p.btcnet) err := btcwire.WriteMessage(&buf, msg, p.protocolVersion, p.btcnet)
if err != nil { if err != nil {
return err.Error() return err.Error()
} }
return "PEER: " + spew.Sdump(buf.Bytes()) return spew.Sdump(buf.Bytes())
})) }))
// Write the message to the peer. // Write the message to the peer.
err := btcwire.WriteMessage(p.conn, msg, p.protocolVersion, p.btcnet) err := btcwire.WriteMessage(p.conn, msg, p.protocolVersion, p.btcnet)
if err != nil { if err != nil {
p.Disconnect() p.Disconnect()
p.logError("PEER: Can't send message: %v", err) p.logError("Can't send message: %v", err)
return return
} }
} }
@ -948,7 +948,7 @@ func (p *peer) inHandler() {
// XXX technically very very very slightly racy, doesn't really // XXX technically very very very slightly racy, doesn't really
// matter. // matter.
if p.versionKnown { if p.versionKnown {
log.Warnf("Peer %s no answer for %d minutes, "+ peerLog.Warnf("Peer %s no answer for %d minutes, "+
"disconnecting", p, idleTimeoutMinutes) "disconnecting", p, idleTimeoutMinutes)
} }
p.Disconnect() p.Disconnect()
@ -964,7 +964,7 @@ out:
// regression test mode and the error is one of the // regression test mode and the error is one of the
// allowed errors. // allowed errors.
if cfg.RegressionTest && p.isAllowedByRegression(err) { if cfg.RegressionTest && p.isAllowedByRegression(err) {
log.Errorf("PEER: Allowed regression test "+ peerLog.Errorf("Allowed regression test "+
"error: %v", err) "error: %v", err)
idleTimer.Reset(idleTimeoutMinutes * time.Minute) idleTimer.Reset(idleTimeoutMinutes * time.Minute)
continue continue
@ -1042,7 +1042,7 @@ out:
p.handleGetHeadersMsg(msg) p.handleGetHeadersMsg(msg)
default: default:
log.Debugf("PEER: Received unhandled message of type %v: Fix Me", peerLog.Debugf("Received unhandled message of type %v: Fix Me",
rmsg.Command()) rmsg.Command())
} }
@ -1050,7 +1050,7 @@ out:
// now if one of the messages that trigger it was processed. // now if one of the messages that trigger it was processed.
if markConnected && atomic.LoadInt32(&p.disconnect) == 0 { if markConnected && atomic.LoadInt32(&p.disconnect) == 0 {
if p.na == nil { if p.na == nil {
log.Warnf("we're getting stuff before we " + peerLog.Warnf("we're getting stuff before we " +
"got a version message. that's bad") "got a version message. that's bad")
continue continue
} }
@ -1072,7 +1072,7 @@ out:
p.server.blockManager.DonePeer(p) p.server.blockManager.DonePeer(p)
} }
log.Tracef("PEER: Peer input handler done for %s", p.addr) peerLog.Tracef("Peer input handler done for %s", p.addr)
} }
// outHandler handles all outgoing messages for the peer. It must be run as a // outHandler handles all outgoing messages for the peer. It must be run as a
@ -1083,7 +1083,7 @@ func (p *peer) outHandler() {
pingTimer := time.AfterFunc(pingTimeoutMinutes*time.Minute, func() { pingTimer := time.AfterFunc(pingTimeoutMinutes*time.Minute, func() {
nonce, err := btcwire.RandomUint64() nonce, err := btcwire.RandomUint64()
if err != nil { if err != nil {
log.Errorf("Not sending ping on timeout to %s: %v", peerLog.Errorf("Not sending ping on timeout to %s: %v",
p, err) p, err)
return return
} }
@ -1192,7 +1192,7 @@ cleanup:
break cleanup break cleanup
} }
} }
log.Tracef("PEER: Peer output handler done for %s", p.addr) peerLog.Tracef("Peer output handler done for %s", p.addr)
} }
// QueueMessage adds the passed bitcoin message to the peer send queue. It // QueueMessage adds the passed bitcoin message to the peer send queue. It
@ -1243,7 +1243,7 @@ func (p *peer) Start() error {
return nil return nil
} }
log.Tracef("PEER: Starting peer %s", p.addr) peerLog.Tracef("Starting peer %s", p.addr)
// Send an initial version message if this is an outbound connection. // Send an initial version message if this is an outbound connection.
if !p.inbound { if !p.inbound {
@ -1265,7 +1265,7 @@ func (p *peer) Start() error {
// Shutdown gracefully shuts down the peer by disconnecting it. // Shutdown gracefully shuts down the peer by disconnecting it.
func (p *peer) Shutdown() { func (p *peer) Shutdown() {
log.Tracef("PEER: Shutdown peer %s", p.addr) peerLog.Tracef("Shutdown peer %s", p.addr)
p.Disconnect() p.Disconnect()
} }
@ -1356,11 +1356,11 @@ func newOutboundPeer(s *server, addr string, persistent bool) *peer {
// this is a persistent connection, retry after the retry // this is a persistent connection, retry after the retry
// interval. // interval.
for atomic.LoadInt32(&p.disconnect) == 0 { for atomic.LoadInt32(&p.disconnect) == 0 {
log.Debugf("SRVR: Attempting to connect to %s", faddr) srvrLog.Debugf("Attempting to connect to %s", faddr)
conn, err := dial("tcp", addr) conn, err := dial("tcp", addr)
if err != nil { if err != nil {
p.retrycount += 1 p.retrycount += 1
log.Debugf("SRVR: Failed to connect to %s: %v", srvrLog.Debugf("Failed to connect to %s: %v",
faddr, err) faddr, err)
if !persistent { if !persistent {
p.server.donePeers <- p p.server.donePeers <- p
@ -1368,8 +1368,8 @@ func newOutboundPeer(s *server, addr string, persistent bool) *peer {
} }
scaledInterval := connectionRetryInterval.Nanoseconds() * p.retrycount / 2 scaledInterval := connectionRetryInterval.Nanoseconds() * p.retrycount / 2
scaledDuration := time.Duration(scaledInterval) scaledDuration := time.Duration(scaledInterval)
log.Debugf("SRVR: Retrying connection to %s "+ srvrLog.Debugf("Retrying connection to %s in "+
"in %s", faddr, scaledDuration) "%s", faddr, scaledDuration)
time.Sleep(scaledDuration) time.Sleep(scaledDuration)
continue continue
} }
@ -1382,7 +1382,7 @@ func newOutboundPeer(s *server, addr string, persistent bool) *peer {
p.server.addrManager.Attempt(p.na) p.server.addrManager.Attempt(p.na)
// Connection was successful so log it and start peer. // Connection was successful so log it and start peer.
log.Debugf("SRVR: Connected to %s", srvrLog.Debugf("Connected to %s",
conn.RemoteAddr()) conn.RemoteAddr())
p.conn = conn p.conn = conn
atomic.AddInt32(&p.connected, 1) atomic.AddInt32(&p.connected, 1)
@ -1399,8 +1399,8 @@ func newOutboundPeer(s *server, addr string, persistent bool) *peer {
// logError makes sure that we only log errors loudly on user peers. // logError makes sure that we only log errors loudly on user peers.
func (p *peer) logError(fmt string, args ...interface{}) { func (p *peer) logError(fmt string, args ...interface{}) {
if p.persistent { if p.persistent {
log.Errorf(fmt, args...) peerLog.Errorf(fmt, args...)
} else { } else {
log.Debugf(fmt, args...) peerLog.Debugf(fmt, args...)
} }
} }

100
rpcserver.go
View file

@ -272,7 +272,7 @@ func (s *rpcServer) Start() {
return return
} }
log.Trace("RPCS: Starting RPC server") rpcsLog.Trace("Starting RPC server")
rpcServeMux := http.NewServeMux() rpcServeMux := http.NewServeMux()
httpServer := &http.Server{Handler: rpcServeMux} httpServer := &http.Server{Handler: rpcServeMux}
rpcServeMux.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) { rpcServeMux.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {
@ -282,7 +282,7 @@ func (s *rpcServer) Start() {
if len(authhdr) > 0 && authhdr[0] == auth { if len(authhdr) > 0 && authhdr[0] == auth {
jsonRPCRead(w, r, s) jsonRPCRead(w, r, s)
} else { } else {
log.Warnf("RPCS: Auth failure.") rpcsLog.Warnf("Auth failure.")
jsonAuthFail(w, r, s) jsonAuthFail(w, r, s)
} }
}) })
@ -305,9 +305,9 @@ func (s *rpcServer) Start() {
for _, listener := range s.listeners { for _, listener := range s.listeners {
s.wg.Add(1) s.wg.Add(1)
go func(listener net.Listener) { go func(listener net.Listener) {
log.Infof("RPCS: RPC server listening on %s", listener.Addr()) rpcsLog.Infof("RPC server listening on %s", listener.Addr())
httpServer.Serve(listener) httpServer.Serve(listener)
log.Tracef("RPCS: RPC listener done for %s", listener.Addr()) rpcsLog.Tracef("RPC listener done for %s", listener.Addr())
s.wg.Done() s.wg.Done()
}(listener) }(listener)
} }
@ -316,18 +316,18 @@ func (s *rpcServer) Start() {
// Stop is used by server.go to stop the rpc listener. // Stop is used by server.go to stop the rpc listener.
func (s *rpcServer) Stop() error { func (s *rpcServer) Stop() error {
if atomic.AddInt32(&s.shutdown, 1) != 1 { if atomic.AddInt32(&s.shutdown, 1) != 1 {
log.Infof("RPCS: RPC server is already in the process of shutting down") rpcsLog.Infof("RPC server is already in the process of shutting down")
return nil return nil
} }
log.Warnf("RPCS: RPC server shutting down") rpcsLog.Warnf("RPC server shutting down")
for _, listener := range s.listeners { for _, listener := range s.listeners {
err := listener.Close() err := listener.Close()
if err != nil { if err != nil {
log.Errorf("RPCS: Problem shutting down rpc: %v", err) rpcsLog.Errorf("Problem shutting down rpc: %v", err)
return err return err
} }
} }
log.Infof("RPCS: RPC server shutdown complete") rpcsLog.Infof("RPC server shutdown complete")
s.wg.Wait() s.wg.Wait()
close(s.quit) close(s.quit)
return nil return nil
@ -336,7 +336,7 @@ func (s *rpcServer) Stop() error {
// genkey generates a key/cert pair to the paths provided. // genkey generates a key/cert pair to the paths provided.
// TODO(oga) wrap errors with fmt.Errorf for more context? // TODO(oga) wrap errors with fmt.Errorf for more context?
func genKey(key, cert string) error { func genKey(key, cert string) error {
log.Infof("RPCS: Generating TLS certificates...") rpcsLog.Infof("Generating TLS certificates...")
priv, err := ecdsa.GenerateKey(elliptic.P521(), rand.Reader) priv, err := ecdsa.GenerateKey(elliptic.P521(), rand.Reader)
if err != nil { if err != nil {
return err return err
@ -419,7 +419,7 @@ func genKey(key, cert string) error {
pem.Encode(keyOut, &pem.Block{Type: "EC PRIVATE KEY", Bytes: keybytes}) pem.Encode(keyOut, &pem.Block{Type: "EC PRIVATE KEY", Bytes: keybytes})
keyOut.Close() keyOut.Close()
log.Infof("RPCS: Done generating TLS certificates") rpcsLog.Infof("Done generating TLS certificates")
return nil return nil
} }
@ -470,7 +470,7 @@ func newRPCServer(listenAddrs []string, s *server) (*rpcServer, error) {
var listener net.Listener var listener net.Listener
listener, err = tls.Listen("tcp4", addr, &tlsConfig) listener, err = tls.Listen("tcp4", addr, &tlsConfig)
if err != nil { if err != nil {
log.Warnf("RPCS: Can't listen on %s: %v", addr, rpcsLog.Warnf("Can't listen on %s: %v", addr,
err) err)
continue continue
} }
@ -481,7 +481,7 @@ func newRPCServer(listenAddrs []string, s *server) (*rpcServer, error) {
var listener net.Listener var listener net.Listener
listener, err = tls.Listen("tcp6", addr, &tlsConfig) listener, err = tls.Listen("tcp6", addr, &tlsConfig)
if err != nil { if err != nil {
log.Warnf("RPCS: Can't listen on %s: %v", addr, rpcsLog.Warnf("Can't listen on %s: %v", addr,
err) err)
continue continue
} }
@ -510,7 +510,7 @@ func jsonRPCRead(w http.ResponseWriter, r *http.Request, s *rpcServer) {
} }
body, err := btcjson.GetRaw(r.Body) body, err := btcjson.GetRaw(r.Body)
if err != nil { if err != nil {
log.Errorf("RPCS: Error getting json message: %v", err) rpcsLog.Errorf("Error getting json message: %v", err)
return return
} }
@ -528,14 +528,14 @@ func jsonRPCRead(w http.ResponseWriter, r *http.Request, s *rpcServer) {
reply = standardCmdReply(cmd, s, nil) reply = standardCmdReply(cmd, s, nil)
} }
log.Tracef("[RPCS] reply: %v", reply) rpcsLog.Tracef("reply: %v", reply)
msg, err := btcjson.MarshallAndSend(reply, w) msg, err := btcjson.MarshallAndSend(reply, w)
if err != nil { if err != nil {
log.Errorf(msg) rpcsLog.Errorf(msg)
return return
} }
log.Debugf(msg) rpcsLog.Debugf(msg)
} }
// TODO(jrick): Remove the wallet notification chan. // TODO(jrick): Remove the wallet notification chan.
@ -674,7 +674,7 @@ func handleGetBestBlockHash(s *rpcServer, cmd btcjson.Cmd, walletNotification ch
var sha *btcwire.ShaHash var sha *btcwire.ShaHash
sha, _, err := s.server.db.NewestSha() sha, _, err := s.server.db.NewestSha()
if err != nil { if err != nil {
log.Errorf("RPCS: Error getting newest sha: %v", err) rpcsLog.Errorf("Error getting newest sha: %v", err)
return nil, btcjson.ErrBestBlockHash return nil, btcjson.ErrBestBlockHash
} }
@ -686,18 +686,18 @@ func handleGetBlock(s *rpcServer, cmd btcjson.Cmd, walletNotification chan []byt
c := cmd.(*btcjson.GetBlockCmd) c := cmd.(*btcjson.GetBlockCmd)
sha, err := btcwire.NewShaHashFromStr(c.Hash) sha, err := btcwire.NewShaHashFromStr(c.Hash)
if err != nil { if err != nil {
log.Errorf("RPCS: Error generating sha: %v", err) rpcsLog.Errorf("Error generating sha: %v", err)
return nil, btcjson.ErrBlockNotFound return nil, btcjson.ErrBlockNotFound
} }
blk, err := s.server.db.FetchBlockBySha(sha) blk, err := s.server.db.FetchBlockBySha(sha)
if err != nil { if err != nil {
log.Errorf("RPCS: Error fetching sha: %v", err) rpcsLog.Errorf("Error fetching sha: %v", err)
return nil, btcjson.ErrBlockNotFound return nil, btcjson.ErrBlockNotFound
} }
idx := blk.Height() idx := blk.Height()
buf, err := blk.Bytes() buf, err := blk.Bytes()
if err != nil { if err != nil {
log.Errorf("RPCS: Error fetching block: %v", err) rpcsLog.Errorf("Error fetching block: %v", err)
return nil, btcjson.ErrBlockNotFound return nil, btcjson.ErrBlockNotFound
} }
@ -710,7 +710,7 @@ func handleGetBlock(s *rpcServer, cmd btcjson.Cmd, walletNotification chan []byt
_, maxidx, err := s.server.db.NewestSha() _, maxidx, err := s.server.db.NewestSha()
if err != nil { if err != nil {
log.Errorf("RPCS: Cannot get newest sha: %v", err) rpcsLog.Errorf("Cannot get newest sha: %v", err)
return nil, btcjson.ErrBlockNotFound return nil, btcjson.ErrBlockNotFound
} }
@ -735,7 +735,7 @@ func handleGetBlock(s *rpcServer, cmd btcjson.Cmd, walletNotification chan []byt
var shaNext *btcwire.ShaHash var shaNext *btcwire.ShaHash
shaNext, err = s.server.db.FetchBlockShaByHeight(int64(idx + 1)) shaNext, err = s.server.db.FetchBlockShaByHeight(int64(idx + 1))
if err != nil { if err != nil {
log.Errorf("RPCS: No next block: %v", err) rpcsLog.Errorf("No next block: %v", err)
return nil, btcjson.ErrBlockNotFound return nil, btcjson.ErrBlockNotFound
} }
blockReply.NextHash = shaNext.String() blockReply.NextHash = shaNext.String()
@ -748,7 +748,7 @@ func handleGetBlock(s *rpcServer, cmd btcjson.Cmd, walletNotification chan []byt
func handleGetBlockCount(s *rpcServer, cmd btcjson.Cmd, walletNotification chan []byte) (interface{}, error) { func handleGetBlockCount(s *rpcServer, cmd btcjson.Cmd, walletNotification chan []byte) (interface{}, error) {
_, maxidx, err := s.server.db.NewestSha() _, maxidx, err := s.server.db.NewestSha()
if err != nil { if err != nil {
log.Errorf("RPCS: Error getting newest sha: %v", err) rpcsLog.Errorf("Error getting newest sha: %v", err)
return nil, btcjson.ErrBlockCount return nil, btcjson.ErrBlockCount
} }
@ -760,7 +760,7 @@ func handleGetBlockHash(s *rpcServer, cmd btcjson.Cmd, walletNotification chan [
c := cmd.(*btcjson.GetBlockHashCmd) c := cmd.(*btcjson.GetBlockHashCmd)
sha, err := s.server.db.FetchBlockShaByHeight(c.Index) sha, err := s.server.db.FetchBlockShaByHeight(c.Index)
if err != nil { if err != nil {
log.Errorf("[RCPS] Error getting block: %v", err) rpcsLog.Errorf("Error getting block: %v", err)
return nil, btcjson.ErrOutOfRange return nil, btcjson.ErrOutOfRange
} }
@ -776,12 +776,12 @@ func handleGetConnectionCount(s *rpcServer, cmd btcjson.Cmd, walletNotification
func handleGetDifficulty(s *rpcServer, cmd btcjson.Cmd, walletNotification chan []byte) (interface{}, error) { func handleGetDifficulty(s *rpcServer, cmd btcjson.Cmd, walletNotification chan []byte) (interface{}, error) {
sha, _, err := s.server.db.NewestSha() sha, _, err := s.server.db.NewestSha()
if err != nil { if err != nil {
log.Errorf("RPCS: Error getting sha: %v", err) rpcsLog.Errorf("Error getting sha: %v", err)
return nil, btcjson.ErrDifficulty return nil, btcjson.ErrDifficulty
} }
blk, err := s.server.db.FetchBlockBySha(sha) blk, err := s.server.db.FetchBlockBySha(sha)
if err != nil { if err != nil {
log.Errorf("RPCS: Error getting block: %v", err) rpcsLog.Errorf("Error getting block: %v", err)
return nil, btcjson.ErrDifficulty return nil, btcjson.ErrDifficulty
} }
blockHeader := &blk.MsgBlock().Header blockHeader := &blk.MsgBlock().Header
@ -829,7 +829,7 @@ func handleGetRawTransaction(s *rpcServer, cmd btcjson.Cmd, walletNotification c
if err != nil { if err != nil {
txList, err := s.server.db.FetchTxBySha(txSha) txList, err := s.server.db.FetchTxBySha(txSha)
if err != nil || len(txList) == 0 { if err != nil || len(txList) == 0 {
log.Errorf("RPCS: Error fetching tx: %v", err) rpcsLog.Errorf("Error fetching tx: %v", err)
return nil, btcjson.ErrNoTxInfo return nil, btcjson.ErrNoTxInfo
} }
@ -852,7 +852,7 @@ func handleGetRawTransaction(s *rpcServer, cmd btcjson.Cmd, walletNotification c
disbuf, _ := btcscript.DisasmString(v.SignatureScript) disbuf, _ := btcscript.DisasmString(v.SignatureScript)
vinList[i].ScriptSig.Asm = strings.Replace(disbuf, " ", "", -1) vinList[i].ScriptSig.Asm = strings.Replace(disbuf, " ", "", -1)
vinList[i].Vout = i + 1 vinList[i].Vout = i + 1
log.Debugf(disbuf) rpcsLog.Debugf(disbuf)
} }
for i, v := range txOutList { for i, v := range txOutList {
@ -864,7 +864,7 @@ func handleGetRawTransaction(s *rpcServer, cmd btcjson.Cmd, walletNotification c
_, addrhash, err := btcscript.ScriptToAddrHash(v.PkScript) _, addrhash, err := btcscript.ScriptToAddrHash(v.PkScript)
if err != nil { if err != nil {
// TODO: set and return error? // TODO: set and return error?
log.Errorf("RPCS: Error getting address hash for %v: %v", txSha, err) rpcsLog.Errorf("Error getting address hash for %v: %v", txSha, err)
} }
if addr, err := btcutil.EncodeAddress(addrhash, s.server.btcnet); err == nil { if addr, err := btcutil.EncodeAddress(addrhash, s.server.btcnet); err == nil {
// TODO: set and return error? // TODO: set and return error?
@ -884,14 +884,14 @@ func handleGetRawTransaction(s *rpcServer, cmd btcjson.Cmd, walletNotification c
if blksha != nil { if blksha != nil {
blk, err := s.server.db.FetchBlockBySha(blksha) blk, err := s.server.db.FetchBlockBySha(blksha)
if err != nil { if err != nil {
log.Errorf("RPCS: Error fetching sha: %v", err) rpcsLog.Errorf("Error fetching sha: %v", err)
return nil, btcjson.ErrBlockNotFound return nil, btcjson.ErrBlockNotFound
} }
idx := blk.Height() idx := blk.Height()
_, maxidx, err := s.server.db.NewestSha() _, maxidx, err := s.server.db.NewestSha()
if err != nil { if err != nil {
log.Errorf("RPCS: Cannot get newest sha: %v", err) rpcsLog.Errorf("Cannot get newest sha: %v", err)
return nil, btcjson.ErrNoNewestBlockInfo return nil, btcjson.ErrNoNewestBlockInfo
} }
@ -937,10 +937,10 @@ func handleSendRawTransaction(s *rpcServer, cmd btcjson.Cmd, walletNotification
// so log it as such. Otherwise, something really did go wrong, // so log it as such. Otherwise, something really did go wrong,
// so log it as an actual error. // so log it as an actual error.
if _, ok := err.(TxRuleError); ok { if _, ok := err.(TxRuleError); ok {
log.Debugf("RPCS: Rejected transaction %v: %v", tx.Sha(), rpcsLog.Debugf("Rejected transaction %v: %v", tx.Sha(),
err) err)
} else { } else {
log.Errorf("RPCS: Failed to process transaction %v: %v", rpcsLog.Errorf("Failed to process transaction %v: %v",
tx.Sha(), err) tx.Sha(), err)
err = btcjson.Error{ err = btcjson.Error{
Code: btcjson.ErrDeserialization.Code, Code: btcjson.ErrDeserialization.Code,
@ -974,7 +974,7 @@ func handleStop(s *rpcServer, cmd btcjson.Cmd, walletNotification chan []byte) (
func verifyChain(db btcdb.Db, level, depth int32) error { func verifyChain(db btcdb.Db, level, depth int32) error {
_, curheight64, err := db.NewestSha() _, curheight64, err := db.NewestSha()
if err != nil { if err != nil {
log.Errorf("RPCS: verify is unable to fetch current block "+ rpcsLog.Errorf("Verify is unable to fetch current block "+
"height: %v", err) "height: %v", err)
} }
@ -988,14 +988,14 @@ func verifyChain(db btcdb.Db, level, depth int32) error {
// Level 0 just looks up the block. // Level 0 just looks up the block.
sha, err := db.FetchBlockShaByHeight(int64(height)) sha, err := db.FetchBlockShaByHeight(int64(height))
if err != nil { if err != nil {
log.Errorf("RPCS: verify is unable to fetch block at "+ rpcsLog.Errorf("Verify is unable to fetch block at "+
"height %d: %v", height, err) "height %d: %v", height, err)
return err return err
} }
block, err := db.FetchBlockBySha(sha) block, err := db.FetchBlockBySha(sha)
if err != nil { if err != nil {
log.Errorf("RPCS: verify is unable to fetch block at "+ rpcsLog.Errorf("Verify is unable to fetch block at "+
"sha %v height %d: %v", sha, height, err) "sha %v height %d: %v", sha, height, err)
return err return err
} }
@ -1005,14 +1005,14 @@ func verifyChain(db btcdb.Db, level, depth int32) error {
err := btcchain.CheckBlockSanity(block, err := btcchain.CheckBlockSanity(block,
activeNetParams.powLimit) activeNetParams.powLimit)
if err != nil { if err != nil {
log.Errorf("RPCS: verify is unable to "+ rpcsLog.Errorf("Verify is unable to "+
"validate block at sha %v height "+ "validate block at sha %v height "+
"%s: %v", sha, height, err) "%s: %v", sha, height, err)
return err return err
} }
} }
} }
log.Infof("RPCS: Chain verify completed successfully") rpcsLog.Infof("Chain verify completed successfully")
return nil return nil
} }
@ -1181,7 +1181,7 @@ func handleRescan(s *rpcServer, cmd btcjson.Cmd,
return btcjson.ErrInternal return btcjson.ErrInternal
} }
log.Debugf("RPCS: Begining rescan") rpcsLog.Debugf("Begining rescan")
minblock := int64(rescanCmd.BeginBlock) minblock := int64(rescanCmd.BeginBlock)
maxblock := int64(rescanCmd.EndBlock) maxblock := int64(rescanCmd.EndBlock)
@ -1219,7 +1219,7 @@ func handleRescan(s *rpcServer, cmd btcjson.Cmd,
} }
txaddr, err := btcutil.EncodeAddress(txaddrhash, s.server.btcnet) txaddr, err := btcutil.EncodeAddress(txaddrhash, s.server.btcnet)
if err != nil { if err != nil {
log.Errorf("Error encoding address: %v", err) rpcsLog.Errorf("Error encoding address: %v", err)
return err return err
} }
if _, ok := rescanCmd.Addresses[txaddr]; ok { if _, ok := rescanCmd.Addresses[txaddr]; ok {
@ -1261,7 +1261,7 @@ func handleRescan(s *rpcServer, cmd btcjson.Cmd,
mreply, _ := json.Marshal(reply) mreply, _ := json.Marshal(reply)
walletNotification <- mreply walletNotification <- mreply
log.Debug("RPCS: Finished rescan") rpcsLog.Debug("Finished rescan")
return nil return nil
} }
@ -1327,7 +1327,7 @@ func getDifficultyRatio(bits uint32) float64 {
outString := difficulty.FloatString(2) outString := difficulty.FloatString(2)
diff, err := strconv.ParseFloat(outString, 64) diff, err := strconv.ParseFloat(outString, 64)
if err != nil { if err != nil {
log.Errorf("RPCS: Cannot get difficulty: %v", err) rpcsLog.Errorf("Cannot get difficulty: %v", err)
return 0 return 0
} }
return diff return diff
@ -1476,7 +1476,7 @@ func (s *rpcServer) websocketJSONHandler(walletNotification chan []byte,
func (s *rpcServer) NotifyBlockConnected(block *btcutil.Block) { func (s *rpcServer) NotifyBlockConnected(block *btcutil.Block) {
hash, err := block.Sha() hash, err := block.Sha()
if err != nil { if err != nil {
log.Error("Bad block; connected block notification dropped.") rpcsLog.Error("Bad block; connected block notification dropped.")
return return
} }
@ -1511,7 +1511,7 @@ func (s *rpcServer) NotifyBlockConnected(block *btcutil.Block) {
func (s *rpcServer) NotifyBlockDisconnected(block *btcutil.Block) { func (s *rpcServer) NotifyBlockDisconnected(block *btcutil.Block) {
hash, err := block.Sha() hash, err := block.Sha()
if err != nil { if err != nil {
log.Error("Bad block; connected block notification dropped.") rpcsLog.Error("Bad block; connected block notification dropped.")
return return
} }
@ -1540,7 +1540,7 @@ func notifySpentData(ctx *notificationCtx, txhash *btcwire.ShaHash, index uint32
err := spender.MsgTx().Serialize(&buf) err := spender.MsgTx().Serialize(&buf)
if err != nil { if err != nil {
// This really shouldn't ever happen... // This really shouldn't ever happen...
log.Warnf("RPCS: Can't serialize tx: %v", err) rpcsLog.Warnf("Can't serialize tx: %v", err)
return return
} }
txStr = string(buf.Bytes()) txStr = string(buf.Bytes())
@ -1561,7 +1561,7 @@ func notifySpentData(ctx *notificationCtx, txhash *btcwire.ShaHash, index uint32
} }
replyBytes, err := json.Marshal(reply) replyBytes, err := json.Marshal(reply)
if err != nil { if err != nil {
log.Errorf("RPCS: Unable to marshal spent notification: %v", err) rpcsLog.Errorf("Unable to marshal spent notification: %v", err)
return return
} }
ctx.connection <- replyBytes ctx.connection <- replyBytes
@ -1595,7 +1595,7 @@ func (s *rpcServer) newBlockNotifyCheckTxOut(block *btcutil.Block,
for i, txout := range tx.MsgTx().TxOut { for i, txout := range tx.MsgTx().TxOut {
_, txaddrhash, err := btcscript.ScriptToAddrHash(txout.PkScript) _, txaddrhash, err := btcscript.ScriptToAddrHash(txout.PkScript)
if err != nil { if err != nil {
log.Debug("Error getting payment address from tx; dropping any Tx notifications.") rpcsLog.Debug("Error getting payment address from tx; dropping any Tx notifications.")
break break
} }
if idlist, ok := s.ws.txNotifications[string(txaddrhash)]; ok { if idlist, ok := s.ws.txNotifications[string(txaddrhash)]; ok {
@ -1604,12 +1604,12 @@ func (s *rpcServer) newBlockNotifyCheckTxOut(block *btcutil.Block,
blkhash, err := block.Sha() blkhash, err := block.Sha()
if err != nil { if err != nil {
log.Error("Error getting block sha; dropping Tx notification.") rpcsLog.Error("Error getting block sha; dropping Tx notification.")
break break
} }
txaddr, err := btcutil.EncodeAddress(txaddrhash, s.server.btcnet) txaddr, err := btcutil.EncodeAddress(txaddrhash, s.server.btcnet)
if err != nil { if err != nil {
log.Error("Error encoding address; dropping Tx notification.") rpcsLog.Error("Error encoding address; dropping Tx notification.")
break break
} }
reply := &btcjson.Reply{ reply := &btcjson.Reply{
@ -1637,7 +1637,7 @@ func (s *rpcServer) newBlockNotifyCheckTxOut(block *btcutil.Block,
} }
replyBytes, err := json.Marshal(reply) replyBytes, err := json.Marshal(reply)
if err != nil { if err != nil {
log.Errorf("RPCS: Unable to marshal tx notification: %v", err) rpcsLog.Errorf("Unable to marshal tx notification: %v", err)
continue continue
} }
ctx.connection <- replyBytes ctx.connection <- replyBytes

44
server.go
View file

@ -101,7 +101,7 @@ func (s *server) handleAddPeerMsg(state *peerState, p *peer) bool {
// Ignore new peers if we're shutting down. // Ignore new peers if we're shutting down.
if atomic.LoadInt32(&s.shutdown) != 0 { if atomic.LoadInt32(&s.shutdown) != 0 {
log.Infof("SRVR: New peer %s ignored - server is shutting "+ srvrLog.Infof("New peer %s ignored - server is shutting "+
"down", p) "down", p)
p.Shutdown() p.Shutdown()
return false return false
@ -110,19 +110,19 @@ func (s *server) handleAddPeerMsg(state *peerState, p *peer) bool {
// Disconnect banned peers. // Disconnect banned peers.
host, _, err := net.SplitHostPort(p.addr) host, _, err := net.SplitHostPort(p.addr)
if err != nil { if err != nil {
log.Debugf("SRVR: can't split hostport %v", err) srvrLog.Debugf("can't split hostport %v", err)
p.Shutdown() p.Shutdown()
return false return false
} }
if banEnd, ok := state.banned[host]; ok { if banEnd, ok := state.banned[host]; ok {
if time.Now().Before(banEnd) { if time.Now().Before(banEnd) {
log.Debugf("SRVR: Peer %s is banned for another %v - "+ srvrLog.Debugf("Peer %s is banned for another %v - "+
"disconnecting", host, banEnd.Sub(time.Now())) "disconnecting", host, banEnd.Sub(time.Now()))
p.Shutdown() p.Shutdown()
return false return false
} }
log.Infof("SRVR: Peer %s is no longer banned", host) srvrLog.Infof("Peer %s is no longer banned", host)
delete(state.banned, host) delete(state.banned, host)
} }
@ -130,7 +130,7 @@ func (s *server) handleAddPeerMsg(state *peerState, p *peer) bool {
// Limit max number of total peers. // Limit max number of total peers.
if state.Count() >= cfg.MaxPeers { if state.Count() >= cfg.MaxPeers {
log.Infof("SRVR: Max peers reached [%d] - disconnecting "+ srvrLog.Infof("Max peers reached [%d] - disconnecting "+
"peer %s", cfg.MaxPeers, p) "peer %s", cfg.MaxPeers, p)
p.Shutdown() p.Shutdown()
// TODO(oga) how to handle permanent peers here? // TODO(oga) how to handle permanent peers here?
@ -139,7 +139,7 @@ func (s *server) handleAddPeerMsg(state *peerState, p *peer) bool {
} }
// Add the new peer and start it. // Add the new peer and start it.
log.Debugf("SRVR: New peer %s", p) srvrLog.Debugf("New peer %s", p)
if p.inbound { if p.inbound {
state.peers.PushBack(p) state.peers.PushBack(p)
p.Start() p.Start()
@ -179,7 +179,7 @@ func (s *server) handleDonePeerMsg(state *peerState, p *peer) {
state.outboundGroups[GroupKey(p.na)]-- state.outboundGroups[GroupKey(p.na)]--
} }
list.Remove(e) list.Remove(e)
log.Debugf("SRVR: Removed peer %s", p) srvrLog.Debugf("Removed peer %s", p)
return return
} }
} }
@ -192,11 +192,11 @@ func (s *server) handleDonePeerMsg(state *peerState, p *peer) {
func (s *server) handleBanPeerMsg(state *peerState, p *peer) { func (s *server) handleBanPeerMsg(state *peerState, p *peer) {
host, _, err := net.SplitHostPort(p.addr) host, _, err := net.SplitHostPort(p.addr)
if err != nil { if err != nil {
log.Debugf("SRVR: can't split ban peer %s %v", p.addr, err) srvrLog.Debugf("can't split ban peer %s %v", p.addr, err)
return return
} }
direction := directionString(p.inbound) direction := directionString(p.inbound)
log.Infof("SRVR: Banned peer %s (%s) for %v", host, direction, srvrLog.Infof("Banned peer %s (%s) for %v", host, direction,
cfg.BanDuration) cfg.BanDuration)
state.banned[host] = time.Now().Add(cfg.BanDuration) state.banned[host] = time.Now().Add(cfg.BanDuration)
@ -382,13 +382,13 @@ func (s *server) handleQuery(querymsg interface{}, state *peerState) {
// listenHandler is the main listener which accepts incoming connections for the // listenHandler is the main listener which accepts incoming connections for the
// server. It must be run as a goroutine. // server. It must be run as a goroutine.
func (s *server) listenHandler(listener net.Listener) { func (s *server) listenHandler(listener net.Listener) {
log.Infof("SRVR: Server listening on %s", listener.Addr()) srvrLog.Infof("Server listening on %s", listener.Addr())
for atomic.LoadInt32(&s.shutdown) == 0 { for atomic.LoadInt32(&s.shutdown) == 0 {
conn, err := listener.Accept() conn, err := listener.Accept()
if err != nil { if err != nil {
// Only log the error if we're not forcibly shutting down. // Only log the error if we're not forcibly shutting down.
if atomic.LoadInt32(&s.shutdown) == 0 { if atomic.LoadInt32(&s.shutdown) == 0 {
log.Errorf("SRVR: can't accept connection: %v", srvrLog.Errorf("can't accept connection: %v",
err) err)
} }
continue continue
@ -396,7 +396,7 @@ func (s *server) listenHandler(listener net.Listener) {
s.AddPeer(newInboundPeer(s, conn)) s.AddPeer(newInboundPeer(s, conn))
} }
s.wg.Done() s.wg.Done()
log.Tracef("SRVR: Listener handler done for %s", listener.Addr()) srvrLog.Tracef("Listener handler done for %s", listener.Addr())
} }
// seedFromDNS uses DNS seeding to populate the address manager with peers. // seedFromDNS uses DNS seeding to populate the address manager with peers.
@ -452,7 +452,7 @@ func (s *server) peerHandler() {
s.addrManager.Start() s.addrManager.Start()
s.blockManager.Start() s.blockManager.Start()
log.Tracef("SRVR: Starting peer handler") srvrLog.Tracef("Starting peer handler")
state := &peerState{ state := &peerState{
peers: list.New(), peers: list.New(),
persistentPeers: list.New(), persistentPeers: list.New(),
@ -595,7 +595,7 @@ out:
s.blockManager.Stop() s.blockManager.Stop()
s.addrManager.Stop() s.addrManager.Stop()
s.wg.Done() s.wg.Done()
log.Tracef("SRVR: Peer handler done") srvrLog.Tracef("Peer handler done")
} }
// AddPeer adds a new peer that has already been connected to the server. // AddPeer adds a new peer that has already been connected to the server.
@ -670,7 +670,7 @@ func (s *server) Start() {
return return
} }
log.Trace("SRVR: Starting server") srvrLog.Trace("Starting server")
// Start all the listeners. There will not be any if listening is // Start all the listeners. There will not be any if listening is
// disabled. // disabled.
@ -695,11 +695,11 @@ func (s *server) Start() {
func (s *server) Stop() error { func (s *server) Stop() error {
// Make sure this only happens once. // Make sure this only happens once.
if atomic.AddInt32(&s.shutdown, 1) != 1 { if atomic.AddInt32(&s.shutdown, 1) != 1 {
log.Infof("SRVR: Server is already in the process of shutting down") srvrLog.Infof("Server is already in the process of shutting down")
return nil return nil
} }
log.Warnf("SRVR: Server shutting down") srvrLog.Warnf("Server shutting down")
// Stop all the listeners. There will not be any listeners if // Stop all the listeners. There will not be any listeners if
// listening is disabled. // listening is disabled.
@ -723,7 +723,7 @@ func (s *server) Stop() error {
// WaitForShutdown blocks until the main listener and peer handlers are stopped. // WaitForShutdown blocks until the main listener and peer handlers are stopped.
func (s *server) WaitForShutdown() { func (s *server) WaitForShutdown() {
s.wg.Wait() s.wg.Wait()
log.Infof("SRVR: Server shutdown complete") srvrLog.Infof("Server shutdown complete")
} }
// ScheduleShutdown schedules a server shutdown after the specified duration. // ScheduleShutdown schedules a server shutdown after the specified duration.
@ -734,7 +734,7 @@ func (s *server) ScheduleShutdown(duration time.Duration) {
if atomic.AddInt32(&s.shutdownSched, 1) != 1 { if atomic.AddInt32(&s.shutdownSched, 1) != 1 {
return return
} }
log.Warnf("SRVR: Server shutdown in %v", duration) srvrLog.Warnf("Server shutdown in %v", duration)
go func() { go func() {
remaining := duration remaining := duration
tickDuration := dynamicTickDuration(remaining) tickDuration := dynamicTickDuration(remaining)
@ -760,7 +760,7 @@ func (s *server) ScheduleShutdown(duration time.Duration) {
ticker.Stop() ticker.Stop()
ticker = time.NewTicker(tickDuration) ticker = time.NewTicker(tickDuration)
} }
log.Warnf("SRVR: Server shutdown in %v", remaining) srvrLog.Warnf("Server shutdown in %v", remaining)
} }
} }
}() }()
@ -826,7 +826,7 @@ func newServer(listenAddrs []string, db btcdb.Db, btcnet btcwire.BitcoinNet) (*s
for _, addr := range ipv4Addrs { for _, addr := range ipv4Addrs {
listener, err := net.Listen("tcp4", addr) listener, err := net.Listen("tcp4", addr)
if err != nil { if err != nil {
log.Warnf("SRVR: Can't listen on %s: %v", addr, srvrLog.Warnf("Can't listen on %s: %v", addr,
err) err)
continue continue
} }
@ -836,7 +836,7 @@ func newServer(listenAddrs []string, db btcdb.Db, btcnet btcwire.BitcoinNet) (*s
for _, addr := range ipv6Addrs { for _, addr := range ipv6Addrs {
listener, err := net.Listen("tcp6", addr) listener, err := net.Listen("tcp6", addr)
if err != nil { if err != nil {
log.Warnf("SRVR: Can't listen on %s: %v", addr, srvrLog.Warnf("Can't listen on %s: %v", addr,
err) err)
continue continue
} }

2
signal.go
View file

@ -27,7 +27,7 @@ func mainInterruptHandler() {
for { for {
select { select {
case <-interruptChannel: case <-interruptChannel:
log.Infof("Received SIGINT (Ctrl+C). Shutting down...") btcdLog.Infof("Received SIGINT (Ctrl+C). Shutting down...")
for _, callback := range interruptCallbacks { for _, callback := range interruptCallbacks {
callback() callback()
} }

4
upgrade.go
View file

@ -119,7 +119,7 @@ func upgradeDataPaths() error {
// Only migrate if the old path exists and the new one doesn't. // Only migrate if the old path exists and the new one doesn't.
if fileExists(oldHomePath) && !fileExists(newHomePath) { if fileExists(oldHomePath) && !fileExists(newHomePath) {
// Create the new path. // Create the new path.
log.Infof("Migrating application home path from '%s' to '%s'", btcdLog.Infof("Migrating application home path from '%s' to '%s'",
oldHomePath, newHomePath) oldHomePath, newHomePath)
err := os.MkdirAll(newHomePath, 0700) err := os.MkdirAll(newHomePath, 0700)
if err != nil { if err != nil {
@ -157,7 +157,7 @@ func upgradeDataPaths() error {
return err return err
} }
} else { } else {
log.Warnf("Not removing '%s' since it contains files "+ btcdLog.Warnf("Not removing '%s' since it contains files "+
"not created by this application. You may "+ "not created by this application. You may "+
"want to manually move them or delete them.", "want to manually move them or delete them.",
oldHomePath) oldHomePath)