Skip to content

Commit

Permalink
Revert "Adding logger around electrum client calls"
Browse files Browse the repository at this point in the history 
This reverts commit 678a2ff.
  • Loading branch information
@dimpar
dimpar committed Sep 14, 2023
1 parent 678a2ff commit d768be0
Showing 1 changed file with 11 additions and 142 deletions.
153 changes: 11 additions & 142 deletions pkg/bitcoin/electrum/electrum.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -82,9 +82,6 @@ func (c *Connection) GetTransaction(
) (*bitcoin.Transaction, error) {
txID := transactionHash.Hex(bitcoin.ReversedByteOrder)

logger.Infof("starting [%s] call to Electrum server", "GetRawTransaction")

startTime := time.Now()
rawTransaction, err := requestWithRetry(
c,
func(ctx context.Context, client *electrum.Client) (string, error) {
Expand All @@ -93,21 +90,14 @@ func (c *Connection) GetTransaction(
// See: https://github.com/Blockstream/electrs/pull/36
return client.GetRawTransaction(ctx, txID)
})
elapsed := time.Since(startTime)
if err != nil {
return nil, fmt.Errorf(
"failed to get raw transaction with ID [%s] after [%s]: [%w]",
"failed to get raw transaction with ID [%s]: [%w]",
txID,
elapsed,
err,
)
}

logger.Infof("successfully completed [%s] call to Electrum server after [%s]",
"GetRawTransaction",
elapsed,
)

result, err := convertRawTransaction(rawTransaction)
if err != nil {
return nil, fmt.Errorf("failed to convert transaction: [%w]", err)
Expand All @@ -128,9 +118,6 @@ func (c *Connection) GetTransactionConfirmations(
zap.String("txID", txID),
)

logger.Infof("starting [%s] call to Electrum server", "GetRawTransaction")

startTime := time.Now()
rawTransaction, err := requestWithRetry(
c,
func(ctx context.Context, client *electrum.Client) (string, error) {
Expand All @@ -139,22 +126,15 @@ func (c *Connection) GetTransactionConfirmations(
// See: https://github.com/Blockstream/electrs/pull/36
return client.GetRawTransaction(ctx, txID)
})
elapsed := time.Since(startTime)
if err != nil {
return 0,
fmt.Errorf(
"failed to get raw transaction with ID [%s] after [%s]: [%w]",
"failed to get raw transaction with ID [%s]: [%w]",
txID,
elapsed,
err,
)
}

logger.Infof("successfully completed [%s] call to Electrum server after [%s]",
"GetRawTransaction",
elapsed,
)

tx, err := decodeTransaction(rawTransaction)
if err != nil {
return 0, fmt.Errorf(
Expand Down Expand Up @@ -187,9 +167,6 @@ txOutLoop:
reversedScriptHash := byteutils.Reverse(scriptHash[:])
reversedScriptHashString := hex.EncodeToString(reversedScriptHash)

logger.Infof("starting [%s] call to Electrum server", "GetHistory")

startTime := time.Now()
scriptHashHistory, err := requestWithRetry(
c,
func(
Expand All @@ -198,21 +175,12 @@ txOutLoop:
) ([]*electrum.GetMempoolResult, error) {
return client.GetHistory(ctx, reversedScriptHashString)
})
elapsed := time.Since(startTime)
if err != nil {
// Don't return an error, but continue to the next TxOut entry.
txLogger.Errorf("failed to get history for script hash after [%s]: [%v]",
elapsed,
err,
)
txLogger.Errorf("failed to get history for script hash: [%v]", err)
continue txOutLoop
}

logger.Infof("successfully completed [%s] call to Electrum server after [%s]",
"GetHistory",
elapsed,
)

for _, transaction := range scriptHashHistory {
if transaction.Hash == txID {
txBlockHeight = transaction.Height
Expand Down Expand Up @@ -265,27 +233,16 @@ func (c *Connection) BroadcastTransaction(
)
rawTxLogger.Debugf("broadcasting transaction")

logger.Infof("starting [%s] call to Electrum server", "BroadcastTransaction")

var response string

startTime := time.Now()
response, err := requestWithRetry(
c,
func(ctx context.Context, client *electrum.Client) (string, error) {
return client.BroadcastTransaction(ctx, rawTx)
})
elapsed := time.Since(startTime)
if err != nil {
return fmt.Errorf("failed to broadcast the transaction after [%s]: [%w]",
elapsed,
err,
)
return fmt.Errorf("failed to broadcast the transaction: [%w]", err)
}
logger.Infof("successfully completed [%s] call to Electrum server after [%s]",
"BroadcastTransaction",
elapsed,
)

rawTxLogger.Infof("transaction broadcast successful: [%s]", response)

Expand All @@ -295,9 +252,6 @@ func (c *Connection) BroadcastTransaction(
// GetLatestBlockHeight gets the height of the latest block (tip). If the
// latest block was not determined, this function returns an error.
func (c *Connection) GetLatestBlockHeight() (uint, error) {
logger.Infof("starting [%s] call to Electrum server", "SubscribeHeaders")

startTime := time.Now()
blockHeight, err := requestWithRetry(
c,
func(ctx context.Context, client *electrum.Client) (int32, error) {
Expand All @@ -308,19 +262,10 @@ func (c *Connection) GetLatestBlockHeight() (uint, error) {
tip := <-headersChan
return tip.Height, nil
})
elapsed := time.Since(startTime)
if err != nil {
return 0, fmt.Errorf("failed to subscribe for headers after [%s]: [%w]",
elapsed,
err,
)
return 0, fmt.Errorf("failed to subscribe for headers: [%w]", err)
}

logger.Infof("successfully completed [%s] call to Electrum server after [%s]",
"SubscribeHeaders",
elapsed,
)

if blockHeight > 0 {
return uint(blockHeight), nil
}
Expand All @@ -334,10 +279,6 @@ func (c *Connection) GetLatestBlockHeight() (uint, error) {
func (c *Connection) GetBlockHeader(
blockHeight uint,
) (*bitcoin.BlockHeader, error) {

logger.Infof("starting [%s] call to Electrum server", "GetBlockHeader")

startTime := time.Now()
getBlockHeaderResult, err := requestWithRetry(
c,
func(
Expand All @@ -347,19 +288,10 @@ func (c *Connection) GetBlockHeader(
return client.GetBlockHeader(ctx, uint32(blockHeight), 0)
},
)
elapsed := time.Since(startTime)
if err != nil {
return nil, fmt.Errorf("failed to get block header after [%s]: [%w]",
elapsed,
err,
)
return nil, fmt.Errorf("failed to get block header: [%w]", err)
}

logger.Infof("successfully completed [%s] call to Electrum server after [%s]",
"GetBlockHeader",
elapsed,
)

blockHeader, err := convertBlockHeader(getBlockHeaderResult)
if err != nil {
return nil, fmt.Errorf("failed to convert block header: %w", err)
Expand All @@ -377,9 +309,6 @@ func (c *Connection) GetTransactionMerkleProof(
) (*bitcoin.TransactionMerkleProof, error) {
txID := transactionHash.Hex(bitcoin.ReversedByteOrder)

logger.Infof("starting [%s] call to Electrum server", "GetMerkleProof")

startTime := time.Now()
getMerkleProofResult, err := requestWithRetry(
c,
func(
Expand All @@ -393,19 +322,10 @@ func (c *Connection) GetTransactionMerkleProof(
)
},
)
elapsed := time.Since(startTime)
if err != nil {
return nil, fmt.Errorf("failed to get merkle proof after [%s]: [%w]",
"GetMerkleProof",
err,
)
return nil, fmt.Errorf("failed to get merkle proof: [%w]", err)
}

logger.Infof("successfully completed [%s] call to Electrum server after [%s]",
"GetMerkleProof",
elapsed,
)

return convertMerkleProof(getMerkleProofResult), nil
}

Expand Down Expand Up @@ -503,9 +423,6 @@ func (c *Connection) getConfirmedScriptHistory(
reversedScriptHash := byteutils.Reverse(scriptHash[:])
reversedScriptHashString := hex.EncodeToString(reversedScriptHash)

logger.Infof("starting [%s] call to Electrum server", "GetHistory")

startTime := time.Now()
items, err := requestWithRetry(
c,
func(
Expand All @@ -514,21 +431,14 @@ func (c *Connection) getConfirmedScriptHistory(
) ([]*electrum.GetMempoolResult, error) {
return client.GetHistory(ctx, reversedScriptHashString)
})
elapsed := time.Since(startTime)
if err != nil {
return nil, fmt.Errorf(
"failed to get history for script [0x%x] after [%s]: [%v]",
"failed to get history for script [0x%x]: [%v]",
script,
elapsed,
err,
)
}

logger.Infof("successfully completed [%s] call to Electrum server after [%s]",
"GetHistory",
elapsed,
)

// According to https://electrumx.readthedocs.io/en/latest/protocol-methods.html#blockchain-scripthash-get-history
// unconfirmed items living in the mempool are appended at the end of the
// returned list and their height value is either -1 or 0. That means
Expand Down Expand Up @@ -644,9 +554,6 @@ func (c *Connection) getScriptMempool(
reversedScriptHash := byteutils.Reverse(scriptHash[:])
reversedScriptHashString := hex.EncodeToString(reversedScriptHash)

logger.Infof("starting [%s] call to Electrum server", "GetMempool")

startTime := time.Now()
items, err := requestWithRetry(
c,
func(
Expand All @@ -655,7 +562,6 @@ func (c *Connection) getScriptMempool(
) ([]*electrum.GetMempoolResult, error) {
return client.GetMempool(ctx, reversedScriptHashString)
})
elapsed := time.Since(startTime)
if err != nil {
return nil, fmt.Errorf(
"failed to get mempool for script [0x%x]: [%v]",
Expand All @@ -664,11 +570,6 @@ func (c *Connection) getScriptMempool(
)
}

logger.Infof("successfully completed [%s] call to Electrum server after [%s]",
"GetMempool",
elapsed,
)

convertedItems := make([]*scriptMempoolItem, len(items))
for i, item := range items {
txHash, err := bitcoin.NewHashFromString(
Expand Down Expand Up @@ -696,9 +597,6 @@ func (c *Connection) getScriptMempool(
// EstimateSatPerVByteFee returns the estimated sat/vbyte fee for a
// transaction to be confirmed within the given number of blocks.
func (c *Connection) EstimateSatPerVByteFee(blocks uint32) (int64, error) {
logger.Infof("starting [%s] call to Electrum server", "GetFee")

startTime := time.Now()
// According to Electrum protocol docs, the returned fee is BTC/KB.
btcPerKbFee, err := requestWithRetry(
c,
Expand All @@ -713,19 +611,10 @@ func (c *Connection) EstimateSatPerVByteFee(blocks uint32) (int64, error) {
// somehow once it disappears from Electrum implementations.
return client.GetFee(ctx, blocks)
})
elapsed := time.Since(startTime)
if err != nil {
return 0, fmt.Errorf("failed to get fee after [%s]: [%v]",
elapsed,
err,
)
return 0, fmt.Errorf("failed to get fee: [%v]", err)
}

logger.Infof("successfully completed [%s] call to Electrum server after [%s]",
"GetFee",
elapsed,
)

// According to Electrum protocol docs, if the daemon does not have
// enough information to make an estimate, the integer -1 is returned.
if btcPerKbFee < 0 {
Expand Down Expand Up @@ -770,9 +659,7 @@ func (c *Connection) verifyServer() error {
version string
protocol string
}
logger.Infof("starting [%s] call to Electrum server", "ServerVersion")

startTime := time.Now()
server, err := requestWithRetry(
c,
func(ctx context.Context, client *electrum.Client) (*Server, error) {
Expand All @@ -783,19 +670,10 @@ func (c *Connection) verifyServer() error {
return &Server{serverVersion, protocolVersion}, nil
},
)
elapsed := time.Since(startTime)
if err != nil {
return fmt.Errorf("failed to get server version after [%s]: [%w]",
elapsed,
err,
)
return fmt.Errorf("failed to get server version: [%w]", err)
}

logger.Infof("successfully completed [%s] call to Electrum server after [%s]",
"ServerVersion",
elapsed,
)

logger.Infof(
"connected to electrum server [version: [%s], protocol: [%s]]",
server.version,
Expand All @@ -821,30 +699,21 @@ func (c *Connection) keepAlive() {
for {
select {
case <-ticker.C:
logger.Infof("starting [%s] call to Electrum server", "Ping")

startTime := time.Now()
_, err := requestWithRetry(
c,
func(ctx context.Context, client *electrum.Client) (interface{}, error) {
return nil, client.Ping(ctx)
},
)
elapsed := time.Since(startTime)
if err != nil {
logger.Errorf(
"failed to ping the electrum server after [%s]; "+
"failed to ping the electrum server; "+
"please verify health of the electrum server: [%v]",
elapsed,
err,
)
} else {
// Adjust ticker starting at the time of the latest successful ping.
ticker = time.NewTicker(c.config.KeepAliveInterval)
logger.Infof("successfully completed [%s] call to Electrum server after [%s]",
"Ping",
elapsed,
)
}
case <-c.parentCtx.Done():
ticker.Stop()
Expand Down

0 comments on commit d768be0

Please sign in to comment.