// Copyright (c) 2013-2014 The btcsuite developers // Use of this source code is governed by an ISC // license that can be found in the LICENSE file. package main import ( "fmt" "os" "strings" "time" "github.com/btcsuite/btcd/addrmgr" "github.com/btcsuite/btcd/blockchain" database "github.com/btcsuite/btcd/database2" "github.com/btcsuite/btcd/peer" "github.com/btcsuite/btcd/txscript" "github.com/btcsuite/btcd/wire" "github.com/btcsuite/btclog" "github.com/btcsuite/seelog" ) const ( // maxRejectReasonLen is the maximum length of a sanitized reject reason // that will be logged. maxRejectReasonLen = 250 ) // 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 ( backendLog = seelog.Disabled adxrLog = btclog.Disabled amgrLog = btclog.Disabled bcdbLog = btclog.Disabled bmgrLog = btclog.Disabled btcdLog = btclog.Disabled chanLog = btclog.Disabled discLog = btclog.Disabled minrLog = btclog.Disabled peerLog = btclog.Disabled rpcsLog = btclog.Disabled scrpLog = btclog.Disabled srvrLog = btclog.Disabled txmpLog = btclog.Disabled ) // subsystemLoggers maps each subsystem identifier to its associated logger. var subsystemLoggers = map[string]btclog.Logger{ "ADXR": adxrLog, "AMGR": amgrLog, "BCDB": bcdbLog, "BMGR": bmgrLog, "BTCD": btcdLog, "CHAN": chanLog, "DISC": discLog, "MINR": minrLog, "PEER": peerLog, "RPCS": rpcsLog, "SCRP": scrpLog, "SRVR": srvrLog, "TXMP": txmpLog, } // 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. type logClosure func() string // String invokes the underlying function and returns the result. func (c logClosure) String() string { return c() } // newLogClosure returns a new closure over a function that returns a string // which itself provides a Stringer interface so that it can be used with the // logging system. func newLogClosure(c func() string) logClosure { return logClosure(c) } // useLogger updates the logger references for subsystemID to logger. Invalid // subsystems are ignored. func useLogger(subsystemID string, logger btclog.Logger) { if _, ok := subsystemLoggers[subsystemID]; !ok { return } subsystemLoggers[subsystemID] = logger switch subsystemID { case "ADXR": adxrLog = logger case "AMGR": amgrLog = logger addrmgr.UseLogger(logger) case "BCDB": bcdbLog = logger database.UseLogger(logger) case "BMGR": bmgrLog = logger case "BTCD": btcdLog = logger case "CHAN": chanLog = logger blockchain.UseLogger(logger) case "DISC": discLog = logger case "MINR": minrLog = logger case "PEER": peerLog = logger peer.UseLogger(logger) case "RPCS": rpcsLog = logger case "SCRP": scrpLog = logger txscript.UseLogger(logger) case "SRVR": srvrLog = logger case "TXMP": txmpLog = logger } } // initSeelogLogger initializes a new seelog logger that is used as the backend // for all logging subsytems. func initSeelogLogger(logFile string) { config := ` ` config = fmt.Sprintf(config, logFile) logger, err := seelog.LoggerFromConfigAsString(config) if err != nil { fmt.Fprintf(os.Stderr, "failed to create logger: %v", err) os.Exit(1) } backendLog = logger } // setLogLevel sets the logging level for provided subsystem. Invalid // subsystems are ignored. Uninitialized subsystems are dynamically created as // needed. func setLogLevel(subsystemID string, logLevel string) { // 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) } // setLogLevels sets the log level for all subsystem loggers to the passed // level. It also dynamically creates the subsystem loggers as needed, so it // can be used to initialize the logging system. func setLogLevels(logLevel string) { // Configure all sub-systems with the new logging level. Dynamically // create loggers as needed. for subsystemID := range subsystemLoggers { setLogLevel(subsystemID, logLevel) } } // directionString is a helper function that returns a string that represents // the direction of a connection (inbound or outbound). func directionString(inbound bool) string { if inbound { return "inbound" } return "outbound" } // formatLockTime returns a transaction lock time as a human-readable string. func formatLockTime(lockTime uint32) string { // The lock time field of a transaction is either a block height at // which the transaction is finalized or a timestamp depending on if the // value is before the txscript.LockTimeThreshold. When it is under the // threshold it is a block height. if lockTime < txscript.LockTimeThreshold { return fmt.Sprintf("height %d", lockTime) } return time.Unix(int64(lockTime), 0).String() } // invSummary returns an inventory message as a human-readable string. func invSummary(invList []*wire.InvVect) string { // No inventory. invLen := len(invList) if invLen == 0 { return "empty" } // One inventory item. if invLen == 1 { iv := invList[0] switch iv.Type { case wire.InvTypeError: return fmt.Sprintf("error %s", iv.Hash) case wire.InvTypeBlock: return fmt.Sprintf("block %s", iv.Hash) case wire.InvTypeTx: return fmt.Sprintf("tx %s", iv.Hash) } return fmt.Sprintf("unknown (%d) %s", uint32(iv.Type), iv.Hash) } // More than one inv item. return fmt.Sprintf("size %d", invLen) } // locatorSummary returns a block locator as a human-readable string. func locatorSummary(locator []*wire.ShaHash, stopHash *wire.ShaHash) string { if len(locator) > 0 { return fmt.Sprintf("locator %s, stop %s", locator[0], stopHash) } return fmt.Sprintf("no locator, stop %s", stopHash) } // sanitizeString strips any characters which are even remotely dangerous, such // as html control characters, from the passed string. It also limits it to // the passed maximum size, which can be 0 for unlimited. When the string is // limited, it will also add "..." to the string to indicate it was truncated. func sanitizeString(str string, maxLength uint) string { const safeChars = "abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXY" + "Z01234567890 .,;_/:?@" // Strip any characters not in the safeChars string removed. str = strings.Map(func(r rune) rune { if strings.IndexRune(safeChars, r) >= 0 { return r } return -1 }, str) // Limit the string to the max allowed length. if maxLength > 0 && uint(len(str)) > maxLength { str = str[:maxLength] str = str + "..." } return str } // messageSummary returns a human-readable string which summarizes a message. // Not all messages have or need a summary. This is used for debug logging. func messageSummary(msg wire.Message) string { switch msg := msg.(type) { case *wire.MsgVersion: return fmt.Sprintf("agent %s, pver %d, block %d", msg.UserAgent, msg.ProtocolVersion, msg.LastBlock) case *wire.MsgVerAck: // No summary. case *wire.MsgGetAddr: // No summary. case *wire.MsgAddr: return fmt.Sprintf("%d addr", len(msg.AddrList)) case *wire.MsgPing: // No summary - perhaps add nonce. case *wire.MsgPong: // No summary - perhaps add nonce. case *wire.MsgAlert: // No summary. case *wire.MsgMemPool: // No summary. case *wire.MsgTx: return fmt.Sprintf("hash %s, %d inputs, %d outputs, lock %s", msg.TxSha(), len(msg.TxIn), len(msg.TxOut), formatLockTime(msg.LockTime)) case *wire.MsgBlock: header := &msg.Header return fmt.Sprintf("hash %s, ver %d, %d tx, %s", msg.BlockSha(), header.Version, len(msg.Transactions), header.Timestamp) case *wire.MsgInv: return invSummary(msg.InvList) case *wire.MsgNotFound: return invSummary(msg.InvList) case *wire.MsgGetData: return invSummary(msg.InvList) case *wire.MsgGetBlocks: return locatorSummary(msg.BlockLocatorHashes, &msg.HashStop) case *wire.MsgGetHeaders: return locatorSummary(msg.BlockLocatorHashes, &msg.HashStop) case *wire.MsgHeaders: return fmt.Sprintf("num %d", len(msg.Headers)) case *wire.MsgReject: // Ensure the variable length strings don't contain any // characters which are even remotely dangerous such as HTML // control characters, etc. Also limit them to sane length for // logging. rejCommand := sanitizeString(msg.Cmd, wire.CommandSize) rejReason := sanitizeString(msg.Reason, maxRejectReasonLen) summary := fmt.Sprintf("cmd %v, code %v, reason %v", rejCommand, msg.Code, rejReason) if rejCommand == wire.CmdBlock || rejCommand == wire.CmdTx { summary += fmt.Sprintf(", hash %v", msg.Hash) } return summary } // No summary for other messages. return "" }