spacecruft
/
blockbook
1
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

Use glog for logging with verbosity levels

pull/1/head
Martin Boehm 2018-01-30 18:22:25 +01:00
parent 3b2067a32d
commit e22e1a946d
6 changed files with 105 additions and 68 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

5
README.md
View File

@ -33,6 +33,11 @@ Install Go interface to ZeroMQ:
go get github.com/pebbe/zmq4
```
Install glog logging:
```
go get github.com/golang/glog
```
Install blockbook:
```

20
bitcoin/bitcoinrpc.go
View File

@ -5,9 +5,10 @@ import (
"encoding/hex"
"encoding/json"
"fmt"
"log"
"net/http"
"time"
"github.com/golang/glog"
)
type RPCError struct {
@ -145,7 +146,8 @@ func NewBitcoinRPC(url string, user string, password string, timeout time.Durati
// GetBestBlockHash returns hash of the tip of the best-block-chain.
func (b *BitcoinRPC) GetBestBlockHash() (string, error) {
log.Printf("rpc: getbestblockhash")
glog.V(1).Info("rpc: getbestblockhash")
res := resGetBestBlockHash{}
req := cmdGetBestBlockHash{Method: "getbestblockhash"}
@ -162,7 +164,7 @@ func (b *BitcoinRPC) GetBestBlockHash() (string, error) {
// GetBestBlockHeight returns height of the tip of the best-block-chain.
func (b *BitcoinRPC) GetBestBlockHeight() (uint32, error) {
log.Printf("rpc: getblockcount")
glog.V(1).Info("rpc: getblockcount")
res := resGetBlockCount{}
req := cmdGetBlockCount{Method: "getblockcount"}
@ -179,7 +181,7 @@ func (b *BitcoinRPC) GetBestBlockHeight() (uint32, error) {
// GetBlockHash returns hash of block in best-block-chain at given height.
func (b *BitcoinRPC) GetBlockHash(height uint32) (string, error) {
log.Printf("rpc: getblockhash %v", height)
glog.V(1).Info("rpc: getblockhash ", height)
res := resGetBlockHash{}
req := cmdGetBlockHash{Method: "getblockhash"}
@ -197,7 +199,7 @@ func (b *BitcoinRPC) GetBlockHash(height uint32) (string, error) {
// GetBlockHeader returns header of block with given hash.
func (b *BitcoinRPC) GetBlockHeader(hash string) (*BlockHeader, error) {
log.Printf("rpc: getblockheader")
glog.V(1).Info("rpc: getblockheader")
res := resGetBlockHeaderVerbose{}
req := cmdGetBlockHeader{Method: "getblockheader"}
@ -237,7 +239,7 @@ func (b *BitcoinRPC) GetBlock(hash string) (*Block, error) {
// GetBlockRaw returns block with given hash as bytes.
func (b *BitcoinRPC) GetBlockRaw(hash string) ([]byte, error) {
log.Printf("rpc: getblock (verbosity=0) %v", hash)
glog.V(1).Info("rpc: getblock (verbosity=0) ", hash)
res := resGetBlockRaw{}
req := cmdGetBlock{Method: "getblock"}
@ -257,7 +259,7 @@ func (b *BitcoinRPC) GetBlockRaw(hash string) ([]byte, error) {
// GetBlockList returns block with given hash by downloading block
// transactions one by one.
func (b *BitcoinRPC) GetBlockList(hash string) (*Block, error) {
log.Printf("rpc: getblock (verbosity=1) %v", hash)
glog.V(1).Info("rpc: getblock (verbosity=1) ", hash)
res := resGetBlockThin{}
req := cmdGetBlock{Method: "getblock"}
@ -289,7 +291,7 @@ func (b *BitcoinRPC) GetBlockList(hash string) (*Block, error) {
// GetBlockFull returns block with given hash.
func (b *BitcoinRPC) GetBlockFull(hash string) (*Block, error) {
log.Printf("rpc: getblock (verbosity=2) %v", hash)
glog.V(1).Info("rpc: getblock (verbosity=2) ", hash)
res := resGetBlockFull{}
req := cmdGetBlock{Method: "getblock"}
@ -308,7 +310,7 @@ func (b *BitcoinRPC) GetBlockFull(hash string) (*Block, error) {
// GetTransaction returns a transaction by the transaction ID.
func (b *BitcoinRPC) GetTransaction(txid string) (*Tx, error) {
log.Printf("rpc: getrawtransaction %v", txid)
glog.V(1).Info("rpc: getrawtransaction ", txid)
res := resGetRawTransactionVerbose{}
req := cmdGetRawTransaction{Method: "getrawtransaction"}

12
bitcoin/mq.go
View File

@ -2,8 +2,8 @@ package bitcoin
import (
"encoding/binary"
"log"
"github.com/golang/glog"
zmq "github.com/pebbe/zmq4"
)
@ -38,7 +38,7 @@ func New(binding string, callback func(*MQMessage)) (*MQ, error) {
socket.SetSubscribe("rawblock")
socket.SetSubscribe("rawtx")
socket.Connect(binding)
log.Printf("MQ listening to %s", binding)
glog.Info("MQ listening to ", binding)
mq := &MQ{context, socket, true, make(chan bool)}
go mq.run(callback)
return mq, nil
@ -51,10 +51,10 @@ func (mq *MQ) run(callback func(*MQMessage)) {
if err != nil {
if zmq.AsErrno(err) == zmq.Errno(zmq.ETERM) {
close(mq.finished)
log.Print("MQ loop terminated")
glog.Info("MQ loop terminated")
break
}
log.Printf("MQ RecvMessageBytes error %v", err)
glog.Error("MQ RecvMessageBytes error ", err)
}
if msg != nil && len(msg) >= 3 {
sequence := uint32(0)
@ -74,7 +74,7 @@ func (mq *MQ) run(callback func(*MQMessage)) {
// Shutdown stops listening to the ZeroMQ and closes the connection
func (mq *MQ) Shutdown() error {
log.Printf("MQ server shutdown")
glog.Info("MQ server shutdown")
if mq.isRunning {
// if errors in socket.Close or context.Term, let it close ungracefully
if err := mq.socket.Close(); err != nil {
@ -84,7 +84,7 @@ func (mq *MQ) Shutdown() error {
return err
}
_, _ = <-mq.finished
log.Printf("MQ server shutdown finished")
glog.Info("MQ server shutdown finished")
}
return nil
}

61
blockbook.go
View File

@ -4,7 +4,6 @@ import (
"context"
"encoding/hex"
"flag"
"log"
"os"
"os/signal"
"sync"
@ -15,6 +14,7 @@ import (
"blockbook/db"
"blockbook/server"
"github.com/golang/glog"
"github.com/pkg/profile"
)
@ -66,13 +66,16 @@ var (
func main() {
flag.Parse()
// override setting for glog to log only to stderr, to match the http handler
flag.Lookup("logtostderr").Value.Set("true")
if *prof {
defer profile.Start().Stop()
}
if *repair {
if err := db.RepairRocksDB(*dbPath); err != nil {
log.Fatalf("RepairRocksDB %s: %v", *dbPath, err)
glog.Fatalf("RepairRocksDB %s: %v", *dbPath, err)
}
return
}
@ -91,21 +94,21 @@ func main() {
db, err := db.NewRocksDB(*dbPath)
if err != nil {
log.Fatalf("NewRocksDB %v", err)
glog.Fatalf("NewRocksDB %v", err)
}
defer db.Close()
if *rollbackHeight >= 0 {
bestHeight, _, err := db.GetBestBlock()
if err != nil {
log.Fatalf("rollbackHeight: %v", err)
glog.Fatalf("rollbackHeight: %v", err)
}
if uint32(*rollbackHeight) > bestHeight {
log.Printf("nothing to rollback, rollbackHeight %d, bestHeight: %d", *rollbackHeight, bestHeight)
glog.Infof("nothing to rollback, rollbackHeight %d, bestHeight: %d", *rollbackHeight, bestHeight)
} else {
err = db.DisconnectBlocks(uint32(*rollbackHeight), bestHeight)
if err != nil {
log.Fatalf("rollbackHeight: %v", err)
glog.Fatalf("rollbackHeight: %v", err)
}
}
return
@ -113,7 +116,7 @@ func main() {
if *resync {
if err := resyncIndex(rpc, db); err != nil {
log.Fatalf("resyncIndex %v", err)
glog.Fatal("resyncIndex ", err)
}
}
@ -121,12 +124,12 @@ func main() {
if *httpServerBinding != "" {
httpServer, err = server.New(*httpServerBinding, db)
if err != nil {
log.Fatalf("https: %v", err)
glog.Fatalf("https: %v", err)
}
go func() {
err = httpServer.Run()
if err != nil {
log.Fatalf("https: %v", err)
glog.Fatalf("https: %v", err)
}
}()
}
@ -135,7 +138,7 @@ func main() {
if *zeroMQBinding != "" {
mq, err = bitcoin.New(*zeroMQBinding, mqHandler)
if err != nil {
log.Fatalf("mq: %v", err)
glog.Fatalf("mq: %v", err)
}
}
@ -150,10 +153,10 @@ func main() {
if address != "" {
script, err := bitcoin.AddressToOutputScript(address)
if err != nil {
log.Fatalf("GetTransactions %v", err)
glog.Fatalf("GetTransactions %v", err)
}
if err = db.GetTransactions(script, height, until, printResult); err != nil {
log.Fatalf("GetTransactions %v", err)
glog.Fatalf("GetTransactions %v", err)
}
} else if !*resync {
if err = connectBlocksParallel(
@ -164,7 +167,7 @@ func main() {
*syncChunk,
*syncWorkers,
); err != nil {
log.Fatalf("connectBlocksParallel %v", err)
glog.Fatalf("connectBlocksParallel %v", err)
}
}
}
@ -176,7 +179,7 @@ func main() {
func mqHandler(m *bitcoin.MQMessage) {
body := hex.EncodeToString(m.Body)
log.Printf("MQ: %s-%d %s", m.Topic, m.Sequence, body)
glog.Infof("MQ: %s-%d %s", m.Topic, m.Sequence, body)
}
func waitForSignalAndShutdown(s *server.HttpServer, mq *bitcoin.MQ, timeout time.Duration) {
@ -188,24 +191,25 @@ func waitForSignalAndShutdown(s *server.HttpServer, mq *bitcoin.MQ, timeout time
ctx, cancel := context.WithTimeout(context.Background(), timeout)
defer cancel()
log.Printf("Shutdown: %v", sig)
glog.Infof("Shutdown: %v", sig)
if mq != nil {
if err := mq.Shutdown(); err != nil {
log.Printf("MQ.Shutdown error: %v", err)
glog.Error("MQ.Shutdown error: ", err)
}
}
if s != nil {
if err := s.Shutdown(ctx); err != nil {
log.Printf("HttpServer.Shutdown error: %v", err)
glog.Error("HttpServer.Shutdown error: ", err)
}
}
glog.Flush()
}
func printResult(txid string) error {
log.Printf("%s", txid)
glog.Info(txid)
return nil
}
@ -222,7 +226,7 @@ func resyncIndex(chain Blockchain, index Index) error {
// If the locally indexed block is the same as the best block on the
// network, we're done.
if local == remote {
log.Printf("resync: synced on %d %s", localBestHeight, local)
glog.Infof("resync: synced on %d %s", localBestHeight, local)
return nil
}
@ -245,7 +249,7 @@ func resyncIndex(chain Blockchain, index Index) error {
if forked {
// find and disconnect forked blocks and then synchronize again
log.Printf("resync: local is forked")
glog.Info("resync: local is forked")
var height uint32
for height = localBestHeight - 1; height >= 0; height-- {
local, err = index.GetBlockHash(height)
@ -271,7 +275,7 @@ func resyncIndex(chain Blockchain, index Index) error {
startHeight := uint32(0)
var hash string
if header != nil {
log.Printf("resync: local is behind")
glog.Info("resync: local is behind")
hash = header.Next
startHeight = localBestHeight
} else {
@ -280,7 +284,7 @@ func resyncIndex(chain Blockchain, index Index) error {
if *blockHeight > 0 {
startHeight = uint32(*blockHeight)
}
log.Printf("resync: genesis from block %d", startHeight)
glog.Info("resync: genesis from block ", startHeight)
hash, err = chain.GetBlockHash(startHeight)
if err != nil {
return err
@ -295,7 +299,7 @@ func resyncIndex(chain Blockchain, index Index) error {
return err
}
if chainBestHeight-startHeight > uint32(*syncChunk) {
log.Printf("resync: parallel sync of blocks %d-%d", startHeight, chainBestHeight)
glog.Infof("resync: parallel sync of blocks %d-%d", startHeight, chainBestHeight)
err = connectBlocksParallel(
chain,
index,
@ -327,7 +331,9 @@ func connectBlocks(
go getBlockChain(hash, chain, bch, done)
var lastRes blockResult
for res := range bch {
lastRes = res
if res.err != nil {
return res.err
}
@ -337,6 +343,10 @@ func connectBlocks(
}
}
if lastRes.block != nil {
glog.Infof("resync: synced on %d %s", lastRes.block.Height, lastRes.block.Hash)
}
return nil
}
@ -366,7 +376,7 @@ func connectBlocksParallel(
if e, ok := err.(*bitcoin.RPCError); ok && (e.Message == "Block height out of range" || e.Message == "Block not found") {
break
}
log.Fatalf("connectBlocksParallel %d-%d %v", low, high, err)
glog.Fatalf("connectBlocksParallel %d-%d %v", low, high, err)
}
}
}
@ -413,6 +423,9 @@ func connectBlockChunk(
if err != nil {
return err
}
if block.Height%1000 == 0 {
glog.Info("connected block ", block.Height, " ", block.Hash)
}
}
return nil

60
db/rocksdb.go
View File

@ -6,15 +6,15 @@ import (
"encoding/binary"
"encoding/hex"
"errors"
"log"
"github.com/bsm/go-vlq"
"github.com/golang/glog"
"github.com/tecbot/gorocksdb"
)
func RepairRocksDB(name string) error {
log.Printf("rocksdb: repair")
glog.Infof("rocksdb: repair")
opts := gorocksdb.NewDefaultOptions()
return gorocksdb.RepairDb(name, opts)
}
@ -39,7 +39,7 @@ var cfNames = []string{"default", "height", "outputs", "inputs"}
// NewRocksDB opens an internal handle to RocksDB environment. Close
// needs to be called to release it.
func NewRocksDB(path string) (d *RocksDB, err error) {
log.Printf("rocksdb: open %s", path)
glog.Infof("rocksdb: open %s", path)
fp := gorocksdb.NewBloomFilter(10)
bbto := gorocksdb.NewDefaultBlockBasedTableOptions()
@ -73,7 +73,7 @@ func NewRocksDB(path string) (d *RocksDB, err error) {
// Close releases the RocksDB environment opened in NewRocksDB.
func (d *RocksDB) Close() error {
log.Printf("rocksdb: close")
glog.Infof("rocksdb: close")
for _, h := range d.cfh {
h.Destroy()
}
@ -86,7 +86,9 @@ func (d *RocksDB) Close() error {
// GetTransactions finds all input/output transactions for address specified by outputScript.
// Transaction are passed to callback function.
func (d *RocksDB) GetTransactions(outputScript []byte, lower uint32, higher uint32, fn func(txid string) error) (err error) {
log.Printf("rocksdb: address get %s %d-%d ", unpackOutputScript(outputScript), lower, higher)
if glog.V(1) {
glog.Infof("rocksdb: address get %s %d-%d ", unpackOutputScript(outputScript), lower, higher)
}
kstart, err := packOutputKey(outputScript, lower)
if err != nil {
@ -110,7 +112,9 @@ func (d *RocksDB) GetTransactions(outputScript []byte, lower uint32, higher uint
if err != nil {
return err
}
log.Printf("rocksdb: output %s: %s", hex.EncodeToString(key), hex.EncodeToString(val))
if glog.V(2) {
glog.Infof("rocksdb: output %s: %s", hex.EncodeToString(key), hex.EncodeToString(val))
}
for _, o := range outpoints {
if err := fn(o.txid); err != nil {
return err
@ -124,7 +128,9 @@ func (d *RocksDB) GetTransactions(outputScript []byte, lower uint32, higher uint
return err
}
if input != nil {
log.Printf("rocksdb: input %s: %s", hex.EncodeToString(boutpoint), hex.EncodeToString(input))
if glog.V(2) {
glog.Infof("rocksdb: input %s: %s", hex.EncodeToString(boutpoint), hex.EncodeToString(input))
}
inpoints, err := unpackOutputValue(input)
if err != nil {
return err
@ -157,11 +163,13 @@ func (d *RocksDB) writeBlock(block *bitcoin.Block, op int) error {
wb := gorocksdb.NewWriteBatch()
defer wb.Destroy()
switch op {
case opInsert:
log.Printf("rocksdb: insert %d %s", block.Height, block.Hash)
case opDelete:
log.Printf("rocksdb: delete %d %s", block.Height, block.Hash)
if glog.V(2) {
switch op {
case opInsert:
glog.Infof("rocksdb: insert %d %s", block.Height, block.Hash)
case opDelete:
glog.Infof("rocksdb: delete %d %s", block.Height, block.Hash)
}
}
if err := d.writeHeight(wb, block, op); err != nil {
@ -206,17 +214,17 @@ func (d *RocksDB) writeOutputs(
for outputScript, outpoints := range records {
bOutputScript, err := packOutputScript(outputScript)
if err != nil {
log.Printf("rocksdb: packOutputScript warning: %v - %d %s", err, block.Height, outputScript)
glog.Warningf("rocksdb: packOutputScript: %v - %d %s", err, block.Height, outputScript)
continue
}
key, err := packOutputKey(bOutputScript, block.Height)
if err != nil {
log.Printf("rocksdb: packOutputKey warning: %v - %d %s", err, block.Height, outputScript)
glog.Warningf("rocksdb: packOutputKey: %v - %d %s", err, block.Height, outputScript)
continue
}
val, err := packOutputValue(outpoints)
if err != nil {
log.Printf("rocksdb: packOutputValue warning: %v", err)
glog.Warningf("rocksdb: packOutputValue: %v", err)
continue
}
@ -323,7 +331,9 @@ func (d *RocksDB) GetBestBlock() (uint32, string, error) {
if it.SeekToLast(); it.Valid() {
bestHeight := unpackUint(it.Key().Data())
val, err := unpackBlockValue(it.Value().Data())
log.Printf("rocksdb: bestblock %d %s", bestHeight, val)
if glog.V(1) {
glog.Infof("rocksdb: bestblock %d %s", bestHeight, val)
}
return bestHeight, val, err
}
return 0, "", nil
@ -375,7 +385,7 @@ func (d *RocksDB) DisconnectBlocks(
lower uint32,
higher uint32,
) error {
log.Printf("rocksdb: disconnecting blocks %d-%d", lower, higher)
glog.Infof("rocksdb: disconnecting blocks %d-%d", lower, higher)
it := d.db.NewIteratorCF(d.ro, d.cfh[cfOutputs])
defer it.Close()
outputKeys := [][]byte{}
@ -398,11 +408,13 @@ func (d *RocksDB) DisconnectBlocks(
}
}
}
log.Printf("rocksdb: about to disconnect %d outputs from %d", len(outputKeys), totalOutputs)
glog.Infof("rocksdb: about to disconnect %d outputs from %d", len(outputKeys), totalOutputs)
wb := gorocksdb.NewWriteBatch()
defer wb.Destroy()
for i := 0; i < len(outputKeys); i++ {
log.Printf("output %s", hex.EncodeToString(outputKeys[i]))
if glog.V(2) {
glog.Info("output ", hex.EncodeToString(outputKeys[i]))
}
wb.DeleteCF(d.cfh[cfOutputs], outputKeys[i])
outpoints, err := unpackOutputValue(outputValues[i])
if err != nil {
@ -413,17 +425,21 @@ func (d *RocksDB) DisconnectBlocks(
if err != nil {
return err
}
log.Printf("input %s", hex.EncodeToString(boutpoint))
if glog.V(2) {
glog.Info("input ", hex.EncodeToString(boutpoint))
}
wb.DeleteCF(d.cfh[cfInputs], boutpoint)
}
}
for height := lower; height <= higher; height++ {
log.Printf("height %d", height)
if glog.V(2) {
glog.Info("height ", height)
}
wb.DeleteCF(d.cfh[cfHeight], packUint(height))
}
err := d.db.Write(d.wo, wb)
if err == nil {
log.Printf("rocksdb: blocks %d-%d disconnected", lower, higher)
glog.Infof("rocksdb: blocks %d-%d disconnected", lower, higher)
}
return err
}

15
server/https.go
View File

@ -6,11 +6,12 @@ import (
"context"
"encoding/json"
"fmt"
"log"
"net/http"
"os"
"strconv"
"github.com/golang/glog"
"github.com/gorilla/handlers"
"github.com/gorilla/mux"
)
@ -37,7 +38,7 @@ func New(httpServerBinding string, db *db.RocksDB) (*HttpServer, error) {
r.HandleFunc("/transactions/{address}/{lower}/{higher}", s.transactions)
var h http.Handler = r
h = handlers.LoggingHandler(os.Stdout, h)
h = handlers.LoggingHandler(os.Stderr, h)
https.Handler = h
return s, nil
@ -45,25 +46,25 @@ func New(httpServerBinding string, db *db.RocksDB) (*HttpServer, error) {
// Run starts the server
func (s *HttpServer) Run() error {
log.Printf("http server starting to listen on %s", s.https.Addr)
glog.Infof("http server starting to listen on %s", s.https.Addr)
return s.https.ListenAndServe()
}
// Close closes the server
func (s *HttpServer) Close() error {
log.Printf("http server closing")
glog.Infof("http server closing")
return s.https.Close()
}
// Shutdown shuts down the server
func (s *HttpServer) Shutdown(ctx context.Context) error {
log.Printf("http server shutdown")
glog.Infof("http server shutdown")
return s.https.Shutdown(ctx)
}
func respondError(w http.ResponseWriter, err error, context string) {
w.WriteHeader(http.StatusBadRequest)
log.Printf("http server %s error: %v", context, err)
glog.Errorf("http server %s error: %v", context, err)
}
func respondHashData(w http.ResponseWriter, hash string) {
@ -84,7 +85,7 @@ func (s *HttpServer) info(w http.ResponseWriter, r *http.Request) {
height, hash, err := s.db.GetBestBlock()
if err != nil {
log.Printf("https info: %v", err)
glog.Errorf("https info: %v", err)
}
json.NewEncoder(w).Encode(info{