From 028fe31efc6a511cacd88f4d853a490c1b3927e0 Mon Sep 17 00:00:00 2001 From: Kirill Pisarev Date: Tue, 29 Aug 2023 12:04:49 +0200 Subject: [PATCH 01/11] feat: add traces for monitored transaction --- chains/evm/calls/contracts/bridge/bridge.go | 7 ++ chains/evm/calls/contracts/contract.go | 7 +- .../calls/transactor/monitored/monitored.go | 100 ++++++++++++++---- .../transactor/signAndSend/signAndSend.go | 35 +++++- chains/evm/calls/transactor/transact.go | 3 +- 5 files changed, 123 insertions(+), 29 deletions(-) diff --git a/chains/evm/calls/contracts/bridge/bridge.go b/chains/evm/calls/contracts/bridge/bridge.go index a77a69cd..02e7fbc6 100644 --- a/chains/evm/calls/contracts/bridge/bridge.go +++ b/chains/evm/calls/contracts/bridge/bridge.go @@ -2,6 +2,7 @@ package bridge import ( "bytes" + "context" "math/big" "strconv" "strings" @@ -41,6 +42,7 @@ func (c *BridgeContract) AddRelayer( ) (*common.Hash, error) { log.Debug().Msgf("Adding new relayer %s", relayerAddr.String()) return c.ExecuteTransaction( + context.Background(), "adminAddRelayer", opts, relayerAddr, @@ -58,6 +60,7 @@ func (c *BridgeContract) AdminSetGenericResource( ) (*common.Hash, error) { log.Debug().Msgf("Setting generic resource %s", hexutil.Encode(rID[:])) return c.ExecuteTransaction( + context.Background(), "adminSetGenericResource", opts, handler, rID, addr, depositFunctionSig, depositerOffset, executeFunctionSig, @@ -72,6 +75,7 @@ func (c *BridgeContract) AdminSetResource( ) (*common.Hash, error) { log.Debug().Msgf("Setting resource %s", hexutil.Encode(rID[:])) return c.ExecuteTransaction( + context.Background(), "adminSetResource", opts, handlerAddr, rID, targetContractAddr, @@ -85,6 +89,7 @@ func (c *BridgeContract) SetDepositNonce( ) (*common.Hash, error) { log.Debug().Msgf("Setting deposit nonce %d for %d", depositNonce, domainId) return c.ExecuteTransaction( + context.Background(), "adminSetDepositNonce", opts, domainId, depositNonce, @@ -97,6 +102,7 @@ func (c *BridgeContract) AdminChangeRelayerThreshold( ) (*common.Hash, error) { log.Debug().Msgf("Setting threshold %d", threshold) return c.ExecuteTransaction( + context.Background(), "adminChangeRelayerThreshold", opts, big.NewInt(0).SetUint64(threshold), @@ -110,6 +116,7 @@ func (c *BridgeContract) SetBurnableInput( ) (*common.Hash, error) { log.Debug().Msgf("Setting burnable input for %s", tokenContractAddr.String()) return c.ExecuteTransaction( + context.Background(), "adminSetBurnable", opts, handlerAddr, tokenContractAddr, diff --git a/chains/evm/calls/contracts/contract.go b/chains/evm/calls/contracts/contract.go index 8c8a7070..07aeefbb 100644 --- a/chains/evm/calls/contracts/contract.go +++ b/chains/evm/calls/contracts/contract.go @@ -3,6 +3,7 @@ package contracts import ( "context" "fmt" + "github.com/ChainSafe/chainbridge-core/chains/evm/calls" "github.com/ChainSafe/chainbridge-core/chains/evm/calls/transactor" "github.com/ethereum/go-ethereum" @@ -60,12 +61,12 @@ func (c *Contract) UnpackResult(method string, output []byte) ([]interface{}, er return res, err } -func (c *Contract) ExecuteTransaction(method string, opts transactor.TransactOptions, args ...interface{}) (*common.Hash, error) { +func (c *Contract) ExecuteTransaction(ctx context.Context, method string, opts transactor.TransactOptions, args ...interface{}) (*common.Hash, error) { input, err := c.PackMethod(method, args...) if err != nil { return nil, err } - h, err := c.Transact(&c.contractAddress, input, opts) + h, err := c.Transact(ctx, &c.contractAddress, input, opts) if err != nil { log.Error(). Str("contract", c.contractAddress.String()). @@ -114,7 +115,7 @@ func (c *Contract) DeployContract(params ...interface{}) (common.Address, error) return common.Address{}, err } opts := transactor.TransactOptions{GasLimit: DefaultDeployGasLimit} - hash, err := c.Transact(nil, append(c.bytecode, input...), opts) + hash, err := c.Transact(context.Background(), nil, append(c.bytecode, input...), opts) if err != nil { return common.Address{}, err } diff --git a/chains/evm/calls/transactor/monitored/monitored.go b/chains/evm/calls/transactor/monitored/monitored.go index f8925396..dc10769a 100644 --- a/chains/evm/calls/transactor/monitored/monitored.go +++ b/chains/evm/calls/transactor/monitored/monitored.go @@ -2,16 +2,20 @@ package monitored import ( "context" + "fmt" "math/big" "sync" "time" + "github.com/ChainSafe/chainbridge-core/chains/evm/calls" + "github.com/ChainSafe/chainbridge-core/chains/evm/calls/transactor" "github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/core/types" "github.com/rs/zerolog/log" - - "github.com/ChainSafe/chainbridge-core/chains/evm/calls" - "github.com/ChainSafe/chainbridge-core/chains/evm/calls/transactor" + "go.opentelemetry.io/otel" + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/codes" + traceapi "go.opentelemetry.io/otel/trace" ) type RawTx struct { @@ -33,8 +37,10 @@ type MonitoredTransactor struct { maxGasPrice *big.Int increasePercentage *big.Int - pendingTxns map[common.Hash]RawTx - txLock sync.Mutex + pendingTxns map[common.Hash]RawTx + pendingTxnsTrace map[common.Hash]traceapi.TraceID + + txLock sync.Mutex } // NewMonitoredTransactor creates an instance of a transactor @@ -55,22 +61,29 @@ func NewMonitoredTransactor( gasPriceClient: gasPriceClient, txFabric: txFabric, pendingTxns: make(map[common.Hash]RawTx), + pendingTxnsTrace: make(map[common.Hash]traceapi.TraceID), maxGasPrice: maxGasPrice, increasePercentage: increasePercentage, } } -func (t *MonitoredTransactor) Transact(to *common.Address, data []byte, opts transactor.TransactOptions) (*common.Hash, error) { +func (t *MonitoredTransactor) Transact(ctx context.Context, to *common.Address, data []byte, opts transactor.TransactOptions) (*common.Hash, error) { + ctx, span := otel.Tracer("relayer-core").Start(ctx, "relayer.core.EVMListener.ListenToEvents") + t.client.LockNonce() defer t.client.UnlockNonce() n, err := t.client.UnsafeNonce() if err != nil { + span.RecordError(fmt.Errorf("unable to get unsafe nonce with err: %w", err)) + span.End() return &common.Hash{}, err } err = transactor.MergeTransactionOptions(&opts, &transactor.DefaultTransactionOptions) if err != nil { + span.RecordError(fmt.Errorf("unable to merge transaction options with err: %w", err)) + span.End() return &common.Hash{}, err } @@ -81,6 +94,11 @@ func (t *MonitoredTransactor) Transact(to *common.Address, data []byte, opts tra return &common.Hash{}, err } } + if len(gp) > 1 { + span.AddEvent("Calculated GasPrice", traceapi.WithAttributes(attribute.String("tx.gasTipCap", gp[0].String()), attribute.String("tx.gasFeeCap", gp[1].String()))) + } else { + span.AddEvent("Calculated GasPrice", traceapi.WithAttributes(attribute.String("tx.gp", gp[0].String()))) + } rawTx := RawTx{ to: to, @@ -94,20 +112,27 @@ func (t *MonitoredTransactor) Transact(to *common.Address, data []byte, opts tra } tx, err := t.txFabric(rawTx.nonce, rawTx.to, rawTx.value, rawTx.gasLimit, rawTx.gasPrice, rawTx.data) if err != nil { + span.RecordError(fmt.Errorf("unable to call TxFabric with err: %w", err)) + span.End() return &common.Hash{}, err } h, err := t.client.SignAndSendTransaction(context.TODO(), tx) if err != nil { + span.RecordError(fmt.Errorf("unable to SignAndSendTransaction with err: %w", err)) + span.End() return &common.Hash{}, err } t.txLock.Lock() t.pendingTxns[h] = rawTx + t.pendingTxnsTrace[h] = span.SpanContext().TraceID() t.txLock.Unlock() err = t.client.UnsafeIncreaseNonce() if err != nil { + span.RecordError(fmt.Errorf("unable to UnsafeIncreaseNonce with err: %w", err)) + span.End() return &common.Hash{}, err } @@ -133,52 +158,79 @@ func (t *MonitoredTransactor) Monitor( for k, v := range t.pendingTxns { pendingTxCopy[k] = v } + pendingTxTraceIDCopy := make(map[common.Hash]traceapi.TraceID, len(t.pendingTxnsTrace)) + for k, v := range t.pendingTxnsTrace { + pendingTxTraceIDCopy[k] = v + } t.txLock.Unlock() for oldHash, tx := range pendingTxCopy { + if time.Since(tx.submitTime) < tooNewTransaction { + continue + } + tID, ok := pendingTxTraceIDCopy[oldHash] + if ok { + // Creating span context with existing TraceID + spanCtx := traceapi.NewSpanContext(traceapi.SpanContextConfig{TraceID: tID, Remote: true}) + ctx = traceapi.ContextWithSpanContext(ctx, spanCtx) + } + ctx, span := otel.Tracer("relayer-sygma").Start(ctx, "relayer.sygma.evm.transactor.Monitor") + logger := log.With().Str("dd.trace_id", span.SpanContext().TraceID().String()).Logger() + receipt, err := t.client.TransactionReceipt(context.Background(), oldHash) if err == nil { if receipt.Status == types.ReceiptStatusSuccessful { - log.Info().Uint64("nonce", tx.nonce).Msgf("Executed transaction %s with nonce %d", oldHash, tx.nonce) + logger.Info().Uint64("nonce", tx.nonce).Msgf("Executed transaction %s with nonce %d", oldHash, tx.nonce) + span.AddEvent("Executed transaction", traceapi.WithAttributes(attribute.String("tx.hash", oldHash.String()), attribute.Int64("tx.nonce", int64(tx.nonce)))) + span.SetStatus(codes.Ok, "Executed transaction") + span.End() } else { - log.Error().Uint64("nonce", tx.nonce).Msgf("Transaction %s failed on chain", oldHash) + logger.Error().Uint64("nonce", tx.nonce).Msgf("Transaction %s failed on chain", oldHash) + span.RecordError(fmt.Errorf("transaction execution failed on chain with error %w", err), traceapi.WithAttributes(attribute.String("tx.hash", oldHash.String()), attribute.Int64("tx.nonce", int64(tx.nonce)))) + span.SetStatus(codes.Error, "Transaction execution failed on chain") + span.End() } - delete(t.pendingTxns, oldHash) + delete(t.pendingTxnsTrace, oldHash) continue } if time.Since(tx.creationTime) > txTimeout { - log.Error().Uint64("nonce", tx.nonce).Msgf("Transaction %s has timed out", oldHash) + logger.Error().Uint64("nonce", tx.nonce).Msgf("Transaction %s has timed out", oldHash) + span.RecordError(fmt.Errorf("transaction has timed out"), traceapi.WithAttributes(attribute.String("tx.hash", oldHash.String()), attribute.Int64("tx.nonce", int64(tx.nonce)))) + span.End() delete(t.pendingTxns, oldHash) - continue - } - if time.Since(tx.submitTime) < tooNewTransaction { + delete(t.pendingTxnsTrace, oldHash) continue } - hash, err := t.resendTransaction(&tx) + hash, err := t.resendTransaction(ctx, &tx) if err != nil { - log.Warn().Uint64("nonce", tx.nonce).Err(err).Msgf("Failed resending transaction %s", hash) + span.RecordError(fmt.Errorf("error resending transaction %w", err), traceapi.WithAttributes(attribute.String("tx.hash", oldHash.String()), attribute.Int64("tx.nonce", int64(tx.nonce)))) + logger.Warn().Uint64("nonce", tx.nonce).Err(err).Msgf("Failed resending transaction %s", oldHash) continue } + span.AddEvent("Resending transaction", traceapi.WithAttributes(attribute.String("tx.newHash", hash.String()))) + span.End() delete(t.pendingTxns, oldHash) + delete(t.pendingTxnsTrace, oldHash) t.pendingTxns[hash] = tx + t.pendingTxnsTrace[hash] = tID } } } } } -func (t *MonitoredTransactor) resendTransaction(tx *RawTx) (common.Hash, error) { - tx.gasPrice = t.IncreaseGas(tx.gasPrice) +func (t *MonitoredTransactor) resendTransaction(ctx context.Context, tx *RawTx) (common.Hash, error) { + tx.gasPrice = t.IncreaseGas(ctx, tx.gasPrice) newTx, err := t.txFabric(tx.nonce, tx.to, tx.value, tx.gasLimit, tx.gasPrice, tx.data) if err != nil { return common.Hash{}, err } - hash, err := t.client.SignAndSendTransaction(context.TODO(), newTx) + hash, err := t.client.SignAndSendTransaction(ctx, newTx) if err != nil { return common.Hash{}, err } @@ -188,15 +240,15 @@ func (t *MonitoredTransactor) resendTransaction(tx *RawTx) (common.Hash, error) return hash, nil } -// increase gas bumps gas price by preset percentage. +// IncreaseGas bumps gas price by preset percentage. // // If gas was 10 and the increaseFactor is 15 the new gas price // would be 11 (it floors the value). In case the gas price didn't // change it increases it by 1. -func (t *MonitoredTransactor) IncreaseGas(oldGp []*big.Int) []*big.Int { +func (t *MonitoredTransactor) IncreaseGas(ctx context.Context, oldGp []*big.Int) []*big.Int { + ctx, span := otel.Tracer("relayer-core").Start(ctx, "relayer.sygma.evm.transactor.Monitor.IncreaseGas") newGp := make([]*big.Int, len(oldGp)) for i, gp := range oldGp { - percentIncreaseValue := new(big.Int).Div(new(big.Int).Mul(gp, t.increasePercentage), big.NewInt(100)) increasedGp := new(big.Int).Add(gp, percentIncreaseValue) if increasedGp.Cmp(t.maxGasPrice) != -1 { @@ -209,5 +261,11 @@ func (t *MonitoredTransactor) IncreaseGas(oldGp []*big.Int) []*big.Int { newGp[i] = increasedGp } } + if len(newGp) > 1 { + span.AddEvent("Calculated GasPrice", traceapi.WithAttributes(attribute.String("tx.gasTipCap", newGp[0].String()), attribute.String("tx.gasFeeCap", newGp[1].String()))) + } else { + span.AddEvent("Calculated GasPrice", traceapi.WithAttributes(attribute.String("tx.gp", newGp[0].String()))) + } + span.End() return newGp } diff --git a/chains/evm/calls/transactor/signAndSend/signAndSend.go b/chains/evm/calls/transactor/signAndSend/signAndSend.go index 97bdad43..079d66fc 100644 --- a/chains/evm/calls/transactor/signAndSend/signAndSend.go +++ b/chains/evm/calls/transactor/signAndSend/signAndSend.go @@ -2,12 +2,18 @@ package signAndSend import ( "context" + "fmt" "math/big" + "go.opentelemetry.io/otel/codes" + + "go.opentelemetry.io/otel" + "go.opentelemetry.io/otel/attribute" + traceapi "go.opentelemetry.io/otel/trace" + "github.com/ChainSafe/chainbridge-core/chains/evm/calls" "github.com/ChainSafe/chainbridge-core/chains/evm/calls/transactor" "github.com/ethereum/go-ethereum/common" - "github.com/rs/zerolog/log" ) type signAndSendTransactor struct { @@ -24,17 +30,22 @@ func NewSignAndSendTransactor(txFabric calls.TxFabric, gasPriceClient calls.GasP } } -func (t *signAndSendTransactor) Transact(to *common.Address, data []byte, opts transactor.TransactOptions) (*common.Hash, error) { +func (t *signAndSendTransactor) Transact(ctx context.Context, to *common.Address, data []byte, opts transactor.TransactOptions) (*common.Hash, error) { + ctx, span := otel.Tracer("relayer-core").Start(ctx, "relayer.core.Transactor.signAndSendTransactor.Transact") t.client.LockNonce() n, err := t.client.UnsafeNonce() if err != nil { t.client.UnlockNonce() + span.RecordError(fmt.Errorf("unable to get unsafe nonce with err: %w", err)) + span.End() return &common.Hash{}, err } err = transactor.MergeTransactionOptions(&opts, &transactor.DefaultTransactionOptions) if err != nil { t.client.UnlockNonce() + span.RecordError(fmt.Errorf("unable to merge transaction options with err: %w", err)) + span.End() return &common.Hash{}, err } @@ -43,33 +54,49 @@ func (t *signAndSendTransactor) Transact(to *common.Address, data []byte, opts t gp, err = t.gasPriceClient.GasPrice(&opts.Priority) if err != nil { t.client.UnlockNonce() + span.RecordError(fmt.Errorf("unable to define gas price with err: %w", err)) + span.End() return &common.Hash{}, err } } + if len(gp) > 1 { + span.AddEvent("Calculated GasPrice", traceapi.WithAttributes(attribute.String("tx.gasTipCap", gp[0].String()), attribute.String("tx.gasFeeCap", gp[1].String()))) + } else { + span.AddEvent("Calculated GasPrice", traceapi.WithAttributes(attribute.String("tx.gp", gp[0].String()))) + } + tx, err := t.TxFabric(n.Uint64(), to, opts.Value, opts.GasLimit, gp, data) if err != nil { t.client.UnlockNonce() + span.RecordError(fmt.Errorf("unable to call TxFabric with err: %w", err)) + span.End() return &common.Hash{}, err } h, err := t.client.SignAndSendTransaction(context.TODO(), tx) if err != nil { t.client.UnlockNonce() - log.Error().Err(err) + span.RecordError(fmt.Errorf("unable to SignAndSendTransaction with err: %w", err)) + span.End() return &common.Hash{}, err } err = t.client.UnsafeIncreaseNonce() t.client.UnlockNonce() if err != nil { + span.RecordError(fmt.Errorf("unable to UnsafeIncreaseNonce with err: %w", err)) + span.End() return &common.Hash{}, err } _, err = t.client.WaitAndReturnTxReceipt(h) if err != nil { + span.RecordError(fmt.Errorf("unable to WaitAndReturnTxReceipt with err: %w", err)) + span.End() return &common.Hash{}, err } - + span.SetStatus(codes.Ok, "Transaction sent") + span.End() return &h, nil } diff --git a/chains/evm/calls/transactor/transact.go b/chains/evm/calls/transactor/transact.go index 621dd5c0..fe37d7e8 100644 --- a/chains/evm/calls/transactor/transact.go +++ b/chains/evm/calls/transactor/transact.go @@ -1,6 +1,7 @@ package transactor import ( + "context" "math/big" "github.com/imdario/mergo" @@ -40,5 +41,5 @@ func MergeTransactionOptions(primary *TransactOptions, additional *TransactOptio } type Transactor interface { - Transact(to *common.Address, data []byte, opts TransactOptions) (*common.Hash, error) + Transact(ctx context.Context, to *common.Address, data []byte, opts TransactOptions) (*common.Hash, error) } From 807e1ee5225d91e1aea3a54e4bf197faffd34ad4 Mon Sep 17 00:00:00 2001 From: Kirill Pisarev Date: Tue, 29 Aug 2023 14:08:31 +0200 Subject: [PATCH 02/11] fix: fix gomocks and tests --- chains/evm/calls/contracts/bridge/bridge.go | 7 ++++++- .../evm/calls/contracts/bridge/bridge_test.go | 17 ++++++++++++++++- chains/evm/calls/contracts/contract_test.go | 18 ++++++++++++------ chains/evm/calls/contracts/erc20/erc20.go | 12 +++++++----- chains/evm/calls/contracts/erc20/erc20_test.go | 3 +++ chains/evm/calls/contracts/erc721/erc721.go | 12 +++++++----- .../evm/calls/contracts/erc721/erc721_test.go | 3 +++ chains/evm/calls/transactor/mock/transact.go | 9 +++++---- .../transactor/monitored/monitored_test.go | 10 ++++++++-- chains/evm/calls/transactor/prepare/prepare.go | 9 +++------ .../calls/transactor/prepare/prepare_test.go | 2 ++ .../transactor/signAndSend/signAndSend_test.go | 2 ++ chains/evm/cli/account/transfer.go | 3 ++- 13 files changed, 76 insertions(+), 31 deletions(-) diff --git a/chains/evm/calls/contracts/bridge/bridge.go b/chains/evm/calls/contracts/bridge/bridge.go index 02e7fbc6..b1db2ff9 100644 --- a/chains/evm/calls/contracts/bridge/bridge.go +++ b/chains/evm/calls/contracts/bridge/bridge.go @@ -130,6 +130,7 @@ func (c *BridgeContract) deposit( opts transactor.TransactOptions, ) (*common.Hash, error) { return c.ExecuteTransaction( + context.Background(), "deposit", opts, destDomainID, resourceID, data, @@ -217,6 +218,7 @@ func (c *BridgeContract) ExecuteProposal( Str("handler", proposal.HandlerAddress.String()). Msgf("Execute proposal") return c.ExecuteTransaction( + context.Background(), "executeProposal", opts, proposal.Source, proposal.DepositNonce, proposal.Data, proposal.ResourceId, true, @@ -233,6 +235,7 @@ func (c *BridgeContract) VoteProposal( Str("handler", proposal.HandlerAddress.String()). Msgf("Vote proposal") return c.ExecuteTransaction( + context.Background(), "voteProposal", opts, proposal.Source, proposal.DepositNonce, proposal.ResourceId, proposal.Data, @@ -255,6 +258,7 @@ func (c *BridgeContract) SimulateVoteProposal(proposal *proposal.Proposal) error func (c *BridgeContract) Pause(opts transactor.TransactOptions) (*common.Hash, error) { log.Debug().Msg("Pause transfers") return c.ExecuteTransaction( + context.Background(), "adminPauseTransfers", opts, ) @@ -263,6 +267,7 @@ func (c *BridgeContract) Pause(opts transactor.TransactOptions) (*common.Hash, e func (c *BridgeContract) Unpause(opts transactor.TransactOptions) (*common.Hash, error) { log.Debug().Msg("Unpause transfers") return c.ExecuteTransaction( + context.Background(), "adminUnpauseTransfers", opts, ) @@ -284,7 +289,7 @@ func (c *BridgeContract) Withdraw( data.Write(common.LeftPadBytes(recipientAddress.Bytes(), 32)) data.Write(common.LeftPadBytes(amountOrTokenId.Bytes(), 32)) - return c.ExecuteTransaction("adminWithdraw", opts, handlerAddress, data.Bytes()) + return c.ExecuteTransaction(context.Background(), "adminWithdraw", opts, handlerAddress, data.Bytes()) } func (c *BridgeContract) GetThreshold() (uint8, error) { diff --git a/chains/evm/calls/contracts/bridge/bridge_test.go b/chains/evm/calls/contracts/bridge/bridge_test.go index 5c53b313..c2b064b5 100644 --- a/chains/evm/calls/contracts/bridge/bridge_test.go +++ b/chains/evm/calls/contracts/bridge/bridge_test.go @@ -1,6 +1,7 @@ package bridge_test import ( + "context" "encoding/hex" "errors" "math/big" @@ -100,7 +101,7 @@ func (s *ProposalStatusTestSuite) TestPrepare_WithdrawInput_Success() { recipientAddress := common.HexToAddress("0x8e5F72B158BEDf0ab50EDa78c70dFC118158C272") amountOrTokenId := big.NewInt(1) - s.mockTransactor.EXPECT().Transact(&s.bridgeAddress, gomock.Any(), gomock.Any()).Times(1).Return( + s.mockTransactor.EXPECT().Transact(context.Background(), &s.bridgeAddress, gomock.Any(), gomock.Any()).Times(1).Return( &common.Hash{}, nil, ) @@ -128,6 +129,7 @@ func (s *ProposalStatusTestSuite) TestDeployContract_Success() { func (s *ProposalStatusTestSuite) TestBridge_AddRelayer_Success() { s.mockTransactor.EXPECT().Transact( + context.Background(), gomock.Any(), gomock.Any(), gomock.Any(), @@ -142,6 +144,7 @@ func (s *ProposalStatusTestSuite) TestBridge_AddRelayer_Success() { func (s *ProposalStatusTestSuite) TestBridge_AdminSetGenericResource_Success() { s.mockTransactor.EXPECT().Transact( + context.Background(), gomock.Any(), gomock.Any(), gomock.Any(), @@ -156,6 +159,7 @@ func (s *ProposalStatusTestSuite) TestBridge_AdminSetGenericResource_Success() { func (s *ProposalStatusTestSuite) TestBridge_AdminSetResource_Success() { s.mockTransactor.EXPECT().Transact( + context.Background(), gomock.Any(), gomock.Any(), gomock.Any(), @@ -170,6 +174,7 @@ func (s *ProposalStatusTestSuite) TestBridge_AdminSetResource_Success() { func (s *ProposalStatusTestSuite) TestBridge_SetDepositNonce_Success() { s.mockTransactor.EXPECT().Transact( + context.Background(), gomock.Any(), gomock.Any(), gomock.Any(), @@ -184,6 +189,7 @@ func (s *ProposalStatusTestSuite) TestBridge_SetDepositNonce_Success() { func (s *ProposalStatusTestSuite) TestBridge_SetThresholdInput_Success() { s.mockTransactor.EXPECT().Transact( + context.Background(), gomock.Any(), gomock.Any(), gomock.Any(), @@ -198,6 +204,7 @@ func (s *ProposalStatusTestSuite) TestBridge_SetThresholdInput_Success() { func (s *ProposalStatusTestSuite) TestBridge_SetBurnableInput_Success() { s.mockTransactor.EXPECT().Transact( + context.Background(), gomock.Any(), gomock.Any(), gomock.Any(), @@ -212,6 +219,7 @@ func (s *ProposalStatusTestSuite) TestBridge_SetBurnableInput_Success() { func (s *ProposalStatusTestSuite) TestBridge_Erc20Deposit_Success() { s.mockTransactor.EXPECT().Transact( + context.Background(), gomock.Any(), gomock.Any(), gomock.Any(), @@ -226,6 +234,7 @@ func (s *ProposalStatusTestSuite) TestBridge_Erc20Deposit_Success() { func (s *ProposalStatusTestSuite) TestBridge_Erc721Deposit_Success() { s.mockTransactor.EXPECT().Transact( + context.Background(), gomock.Any(), gomock.Any(), gomock.Any(), @@ -240,6 +249,7 @@ func (s *ProposalStatusTestSuite) TestBridge_Erc721Deposit_Success() { func (s *ProposalStatusTestSuite) TestBridge_GenericDeposit_Success() { s.mockTransactor.EXPECT().Transact( + context.Background(), gomock.Any(), gomock.Any(), gomock.Any(), @@ -254,6 +264,7 @@ func (s *ProposalStatusTestSuite) TestBridge_GenericDeposit_Success() { func (s *ProposalStatusTestSuite) TestBridge_ExecuteProposal_Success() { s.mockTransactor.EXPECT().Transact( + context.Background(), gomock.Any(), gomock.Any(), gomock.Any(), @@ -268,6 +279,7 @@ func (s *ProposalStatusTestSuite) TestBridge_ExecuteProposal_Success() { func (s *ProposalStatusTestSuite) TestBridge_VoteProposal_Success() { s.mockTransactor.EXPECT().Transact( + context.Background(), gomock.Any(), gomock.Any(), gomock.Any(), @@ -293,6 +305,7 @@ func (s *ProposalStatusTestSuite) TestBridge_SimulateVoteProposal_Success() { func (s *ProposalStatusTestSuite) TestBridge_Pause_Success() { s.mockTransactor.EXPECT().Transact( + context.Background(), gomock.Any(), gomock.Any(), gomock.Any(), @@ -307,6 +320,7 @@ func (s *ProposalStatusTestSuite) TestBridge_Pause_Success() { func (s *ProposalStatusTestSuite) TestBridge_Unpause_Success() { s.mockTransactor.EXPECT().Transact( + context.Background(), gomock.Any(), gomock.Any(), gomock.Any(), @@ -321,6 +335,7 @@ func (s *ProposalStatusTestSuite) TestBridge_Unpause_Success() { func (s *ProposalStatusTestSuite) TestBridge_Withdraw_Success() { s.mockTransactor.EXPECT().Transact( + context.Background(), gomock.Any(), gomock.Any(), gomock.Any(), diff --git a/chains/evm/calls/contracts/contract_test.go b/chains/evm/calls/contracts/contract_test.go index db9000a5..d46c2fcf 100644 --- a/chains/evm/calls/contracts/contract_test.go +++ b/chains/evm/calls/contracts/contract_test.go @@ -1,7 +1,12 @@ package contracts import ( + "context" "errors" + "math/big" + "strings" + "testing" + "github.com/ChainSafe/chainbridge-core/chains/evm/calls/consts" mock_calls "github.com/ChainSafe/chainbridge-core/chains/evm/calls/mock" "github.com/ChainSafe/chainbridge-core/chains/evm/calls/transactor" @@ -10,9 +15,6 @@ import ( "github.com/ethereum/go-ethereum/common" "github.com/golang/mock/gomock" "github.com/stretchr/testify/suite" - "math/big" - "strings" - "testing" ) type ContractTestSuite struct { @@ -66,12 +68,13 @@ func (s *ContractTestSuite) TestContract_UnpackResult_InvalidRequest_Fail() { func (s *ContractTestSuite) TestContract_ExecuteTransaction_ValidRequest_Success() { s.mockTransactor.EXPECT().Transact( + context.Background(), &common.Address{}, gomock.Any(), transactor.TransactOptions{}, ).Return(&common.Hash{}, nil) hash, err := s.contract.ExecuteTransaction( - "approve", + context.Background(), "approve", transactor.TransactOptions{}, common.Address{}, big.NewInt(10), ) s.Nil(err) @@ -80,11 +83,13 @@ func (s *ContractTestSuite) TestContract_ExecuteTransaction_ValidRequest_Success func (s *ContractTestSuite) TestContract_ExecuteTransaction_TransactError_Fail() { s.mockTransactor.EXPECT().Transact( + context.Background(), &common.Address{}, gomock.Any(), transactor.TransactOptions{}, ).Return(nil, errors.New("error")) hash, err := s.contract.ExecuteTransaction( + context.Background(), "approve", transactor.TransactOptions{}, common.Address{}, big.NewInt(10), ) @@ -94,6 +99,7 @@ func (s *ContractTestSuite) TestContract_ExecuteTransaction_TransactError_Fail() func (s *ContractTestSuite) TestContract_ExecuteTransaction_InvalidRequest_Fail() { hash, err := s.contract.ExecuteTransaction( + context.Background(), "approve", transactor.TransactOptions{}, common.Address{}, // missing one argument ) @@ -149,7 +155,7 @@ func (s *ContractTestSuite) TestContract_DeployContract_InvalidRequest_Fail() { func (s *ContractTestSuite) TestContract_DeployContract_TransactionError_Fail() { s.mockTransactor.EXPECT().Transact( - nil, gomock.Any(), gomock.Any(), + context.Background(), nil, gomock.Any(), gomock.Any(), ).Times(1).Return(&common.Hash{}, errors.New("error")) res, err := s.contract.DeployContract("TestERC721", "TST721", "") s.Equal(common.Address{}, res) @@ -158,7 +164,7 @@ func (s *ContractTestSuite) TestContract_DeployContract_TransactionError_Fail() func (s *ContractTestSuite) TestContract_DeployContract_GetTxByHashError_Fail() { s.mockTransactor.EXPECT().Transact( - nil, gomock.Any(), gomock.Any(), + context.Background(), nil, gomock.Any(), gomock.Any(), ).Times(1).Return(&common.Hash{}, nil) s.mockContractCallerDispatcherClient.EXPECT().GetTransactionByHash( common.Hash{}, diff --git a/chains/evm/calls/contracts/erc20/erc20.go b/chains/evm/calls/contracts/erc20/erc20.go index e7bc3c12..9e0c1c51 100644 --- a/chains/evm/calls/contracts/erc20/erc20.go +++ b/chains/evm/calls/contracts/erc20/erc20.go @@ -1,11 +1,13 @@ package erc20 import ( + "context" + "math/big" + "strings" + "github.com/ChainSafe/chainbridge-core/chains/evm/calls" "github.com/ChainSafe/chainbridge-core/chains/evm/calls/contracts" "github.com/ChainSafe/chainbridge-core/chains/evm/calls/transactor" - "math/big" - "strings" "github.com/ChainSafe/chainbridge-core/chains/evm/calls/consts" "github.com/ethereum/go-ethereum/accounts/abi" @@ -43,7 +45,7 @@ func (c *ERC20Contract) MintTokens( opts transactor.TransactOptions, ) (*common.Hash, error) { log.Debug().Msgf("Minting %s tokens to %s", amount.String(), to.String()) - return c.ExecuteTransaction("mint", opts, to, amount) + return c.ExecuteTransaction(context.Background(), "mint", opts, to, amount) } func (c *ERC20Contract) ApproveTokens( @@ -52,7 +54,7 @@ func (c *ERC20Contract) ApproveTokens( opts transactor.TransactOptions, ) (*common.Hash, error) { log.Debug().Msgf("Approving %s tokens for %s", target.String(), amount.String()) - return c.ExecuteTransaction("approve", opts, target, amount) + return c.ExecuteTransaction(context.Background(), "approve", opts, target, amount) } func (c *ERC20Contract) MinterRole() ([32]byte, error) { @@ -73,5 +75,5 @@ func (c *ERC20Contract) AddMinter( if err != nil { return nil, err } - return c.ExecuteTransaction("grantRole", opts, role, minter) + return c.ExecuteTransaction(context.Background(), "grantRole", opts, role, minter) } diff --git a/chains/evm/calls/contracts/erc20/erc20_test.go b/chains/evm/calls/contracts/erc20/erc20_test.go index 1a98cda2..9f520200 100644 --- a/chains/evm/calls/contracts/erc20/erc20_test.go +++ b/chains/evm/calls/contracts/erc20/erc20_test.go @@ -62,6 +62,7 @@ func (s *ERC20ContractCallsTestSuite) TestErc20Contract_MintTokens_Success() { gomock.Any(), gomock.Any(), gomock.Any(), + gomock.Any(), ).Return(&common.Hash{1, 2, 3, 4, 5}, nil) res, err := s.erc20contract.MintTokens(common.HexToAddress(testInteractorAddress), big.NewInt(10), transactor.DefaultTransactionOptions) s.Equal( @@ -76,6 +77,7 @@ func (s *ERC20ContractCallsTestSuite) TestErc20Contract_ApproveTokens_Success() gomock.Any(), gomock.Any(), gomock.Any(), + gomock.Any(), ).Return(&common.Hash{1, 2, 3, 4, 5, 6, 7, 8, 9}, nil) res, err := s.erc20contract.ApproveTokens(common.HexToAddress(testInteractorAddress), big.NewInt(100), transactor.DefaultTransactionOptions) s.Equal( @@ -111,6 +113,7 @@ func (s *ERC20ContractCallsTestSuite) TestErc20Contract_AddMinter_Success() { gomock.Any(), gomock.Any(), gomock.Any(), + gomock.Any(), ).Return(&common.Hash{1, 2, 3}, nil) res, err := s.erc20contract.AddMinter(common.HexToAddress(testInteractorAddress), transactor.DefaultTransactionOptions) s.Equal( diff --git a/chains/evm/calls/contracts/erc721/erc721.go b/chains/evm/calls/contracts/erc721/erc721.go index 50120edc..b4bafcd3 100644 --- a/chains/evm/calls/contracts/erc721/erc721.go +++ b/chains/evm/calls/contracts/erc721/erc721.go @@ -1,11 +1,13 @@ package erc721 import ( + "context" + "math/big" + "strings" + "github.com/ChainSafe/chainbridge-core/chains/evm/calls" "github.com/ChainSafe/chainbridge-core/chains/evm/calls/consts" "github.com/ChainSafe/chainbridge-core/chains/evm/calls/contracts" - "math/big" - "strings" "github.com/ChainSafe/chainbridge-core/chains/evm/calls/transactor" "github.com/ethereum/go-ethereum/accounts/abi" @@ -35,21 +37,21 @@ func (c *ERC721Contract) AddMinter( if err != nil { return nil, err } - return c.ExecuteTransaction("grantRole", opts, role, minter) + return c.ExecuteTransaction(context.Background(), "grantRole", opts, role, minter) } func (c *ERC721Contract) Approve( tokenId *big.Int, recipient common.Address, opts transactor.TransactOptions, ) (*common.Hash, error) { log.Debug().Msgf("Approving %s token for %s", tokenId.String(), recipient.String()) - return c.ExecuteTransaction("approve", opts, recipient, tokenId) + return c.ExecuteTransaction(context.Background(), "approve", opts, recipient, tokenId) } func (c *ERC721Contract) Mint( tokenId *big.Int, metadata string, destination common.Address, opts transactor.TransactOptions, ) (*common.Hash, error) { log.Debug().Msgf("Minting tokens %s to %s", tokenId.String(), destination.String()) - return c.ExecuteTransaction("mint", opts, destination, tokenId, metadata) + return c.ExecuteTransaction(context.Background(), "mint", opts, destination, tokenId, metadata) } func (c *ERC721Contract) Owner(tokenId *big.Int) (*common.Address, error) { diff --git a/chains/evm/calls/contracts/erc721/erc721_test.go b/chains/evm/calls/contracts/erc721/erc721_test.go index 039b06ee..15ade1ff 100644 --- a/chains/evm/calls/contracts/erc721/erc721_test.go +++ b/chains/evm/calls/contracts/erc721/erc721_test.go @@ -80,6 +80,7 @@ func (s *ERC721CallsTestSuite) TestERC721Contract_UnpackResult_InvalidData_Fail( func (s *ERC721CallsTestSuite) TestERC721Contract_Approve_Success() { s.mockTransactor.EXPECT().Transact( + gomock.Any(), &s.erc721ContractAddress, gomock.Any(), transactor.TransactOptions{}, @@ -106,6 +107,7 @@ func (s *ERC721CallsTestSuite) TestERC721Contract_AddMinter_Success() { gomock.Any(), gomock.Any(), gomock.Any(), + gomock.Any(), ).Return(&common.Hash{1, 2, 3}, nil) res, err := s.erc721Contract.AddMinter(common.HexToAddress(testInteractorAddress), transactor.DefaultTransactionOptions) s.Equal( @@ -120,6 +122,7 @@ func (s *ERC721CallsTestSuite) TestERC721Contract_MintTokens_Success() { gomock.Any(), gomock.Any(), gomock.Any(), + gomock.Any(), ).Return(&common.Hash{1, 2, 3, 4, 5}, nil) res, err := s.erc721Contract.Mint(big.NewInt(5), "token_uri", common.HexToAddress(testInteractorAddress), transactor.DefaultTransactionOptions) s.Equal( diff --git a/chains/evm/calls/transactor/mock/transact.go b/chains/evm/calls/transactor/mock/transact.go index 78ff9faf..a7d7d83a 100644 --- a/chains/evm/calls/transactor/mock/transact.go +++ b/chains/evm/calls/transactor/mock/transact.go @@ -5,6 +5,7 @@ package mock_transactor import ( + context "context" reflect "reflect" transactor "github.com/ChainSafe/chainbridge-core/chains/evm/calls/transactor" @@ -36,16 +37,16 @@ func (m *MockTransactor) EXPECT() *MockTransactorMockRecorder { } // Transact mocks base method. -func (m *MockTransactor) Transact(to *common.Address, data []byte, opts transactor.TransactOptions) (*common.Hash, error) { +func (m *MockTransactor) Transact(ctx context.Context, to *common.Address, data []byte, opts transactor.TransactOptions) (*common.Hash, error) { m.ctrl.T.Helper() - ret := m.ctrl.Call(m, "Transact", to, data, opts) + ret := m.ctrl.Call(m, "Transact", ctx, to, data, opts) ret0, _ := ret[0].(*common.Hash) ret1, _ := ret[1].(error) return ret0, ret1 } // Transact indicates an expected call of Transact. -func (mr *MockTransactorMockRecorder) Transact(to, data, opts interface{}) *gomock.Call { +func (mr *MockTransactorMockRecorder) Transact(ctx, to, data, opts interface{}) *gomock.Call { mr.mock.ctrl.T.Helper() - return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "Transact", reflect.TypeOf((*MockTransactor)(nil).Transact), to, data, opts) + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "Transact", reflect.TypeOf((*MockTransactor)(nil).Transact), ctx, to, data, opts) } diff --git a/chains/evm/calls/transactor/monitored/monitored_test.go b/chains/evm/calls/transactor/monitored/monitored_test.go index 9b14083d..bbac2dfb 100644 --- a/chains/evm/calls/transactor/monitored/monitored_test.go +++ b/chains/evm/calls/transactor/monitored/monitored_test.go @@ -54,6 +54,7 @@ func (s *TransactorTestSuite) TestTransactor_SignAndSend_Success() { big.NewInt(1000), big.NewInt(15)) txHash, err := t.Transact( + context.Background(), &common.Address{}, byteData, transactor.TransactOptions{}, @@ -79,6 +80,7 @@ func (s *TransactorTestSuite) TestTransactor_SignAndSend_Fail() { big.NewInt(1000), big.NewInt(15)) _, err := t.Transact( + context.Background(), &common.Address{}, byteData, transactor.TransactOptions{}, @@ -108,6 +110,7 @@ func (s *TransactorTestSuite) TestTransactor_MonitoredTransaction_SuccessfulExec go t.Monitor(ctx, time.Millisecond*50, time.Minute, time.Millisecond) hash, err := t.Transact( + context.Background(), &common.Address{}, byteData, transactor.TransactOptions{}, @@ -143,6 +146,7 @@ func (s *TransactorTestSuite) TestTransactor_MonitoredTransaction_TxTimeout() { go t.Monitor(ctx, time.Millisecond*50, time.Millisecond, time.Millisecond) hash, err := t.Transact( + context.Background(), &common.Address{}, byteData, transactor.TransactOptions{}, @@ -178,6 +182,7 @@ func (s *TransactorTestSuite) TestTransactor_MonitoredTransaction_TransactionRes go t.Monitor(ctx, time.Millisecond*50, time.Minute, time.Millisecond) hash, err := t.Transact( + context.Background(), &common.Address{}, byteData, transactor.TransactOptions{}, @@ -217,6 +222,7 @@ func (s *TransactorTestSuite) TestTransactor_MonitoredTransaction_MaxGasPriceRea go t.Monitor(ctx, time.Millisecond*50, time.Minute, time.Millisecond) hash, err := t.Transact( + context.Background(), &common.Address{}, byteData, transactor.TransactOptions{}, @@ -240,7 +246,7 @@ func (s *TransactorTestSuite) TestTransactor_IncreaseGas_15PercentIncrease() { big.NewInt(150), big.NewInt(15)) - newGas := t.IncreaseGas([]*big.Int{big.NewInt(1), big.NewInt(10), big.NewInt(100)}) + newGas := t.IncreaseGas(context.Background(), []*big.Int{big.NewInt(1), big.NewInt(10), big.NewInt(100)}) s.Equal(newGas, []*big.Int{big.NewInt(2), big.NewInt(11), big.NewInt(115)}) } @@ -253,7 +259,7 @@ func (s *TransactorTestSuite) TestTransactor_IncreaseGas_MaxGasReached() { big.NewInt(15), big.NewInt(15)) - newGas := t.IncreaseGas([]*big.Int{big.NewInt(1), big.NewInt(10), big.NewInt(100)}) + newGas := t.IncreaseGas(context.Background(), []*big.Int{big.NewInt(1), big.NewInt(10), big.NewInt(100)}) s.Equal(newGas, []*big.Int{big.NewInt(2), big.NewInt(11), big.NewInt(15)}) } diff --git a/chains/evm/calls/transactor/prepare/prepare.go b/chains/evm/calls/transactor/prepare/prepare.go index bce364b1..d6ee4487 100644 --- a/chains/evm/calls/transactor/prepare/prepare.go +++ b/chains/evm/calls/transactor/prepare/prepare.go @@ -1,26 +1,23 @@ package prepare import ( + "context" "fmt" "github.com/ChainSafe/chainbridge-core/chains/evm/calls/transactor" - "github.com/ethereum/go-ethereum/common" ) -type Transactor interface { - Transact(to *common.Address, data []byte, opts transactor.TransactOptions) (*common.Hash, error) -} type prepareTransactor struct{} // Initializes PrepareTransactor which is used when --prepare flag value is set as true from CLI // PrepareTransactor outputs calldata to stdout for multisig calls (it doesn't make any contract calls) -func NewPrepareTransactor() Transactor { +func NewPrepareTransactor() transactor.Transactor { return &prepareTransactor{} } // Outputs calldata to stdout (called when --prepare flag value is set as true from CLI) -func (t *prepareTransactor) Transact(to *common.Address, data []byte, opts transactor.TransactOptions) (*common.Hash, error) { +func (t *prepareTransactor) Transact(ctx context.Context, to *common.Address, data []byte, opts transactor.TransactOptions) (*common.Hash, error) { fmt.Printf(` =============================================== To: diff --git a/chains/evm/calls/transactor/prepare/prepare_test.go b/chains/evm/calls/transactor/prepare/prepare_test.go index a3fbf1aa..d5bfc9e1 100644 --- a/chains/evm/calls/transactor/prepare/prepare_test.go +++ b/chains/evm/calls/transactor/prepare/prepare_test.go @@ -1,6 +1,7 @@ package prepare_test import ( + "context" "testing" erc20 "github.com/ChainSafe/chainbridge-core/chains/evm/calls/contracts/erc20" @@ -49,6 +50,7 @@ func (s *TransactorTestSuite) TestTransactor_WithPrepare_Success() { var trans = prepare.NewPrepareTransactor() txHash, err := trans.Transact( + context.Background(), &common.Address{}, byteData, transactor.TransactOptions{}, diff --git a/chains/evm/calls/transactor/signAndSend/signAndSend_test.go b/chains/evm/calls/transactor/signAndSend/signAndSend_test.go index aadca789..29153e69 100644 --- a/chains/evm/calls/transactor/signAndSend/signAndSend_test.go +++ b/chains/evm/calls/transactor/signAndSend/signAndSend_test.go @@ -1,6 +1,7 @@ package signAndSend_test import ( + "context" "math/big" "testing" @@ -54,6 +55,7 @@ func (s *TransactorTestSuite) TestTransactor_SignAndSend_Success() { s.mockContractCallerDispatcherClient, ) txHash, err := trans.Transact( + context.Background(), &common.Address{}, byteData, transactor.TransactOptions{}, diff --git a/chains/evm/cli/account/transfer.go b/chains/evm/cli/account/transfer.go index 3b857ebc..342a9e94 100644 --- a/chains/evm/cli/account/transfer.go +++ b/chains/evm/cli/account/transfer.go @@ -2,6 +2,7 @@ package account import ( "bufio" + "context" "fmt" "math/big" "os" @@ -78,7 +79,7 @@ func ProcessTransferBaseCurrencyFlags(cmd *cobra.Command, args []string) error { } func TransferBaseCurrency(cmd *cobra.Command, args []string, t transactor.Transactor) error { hash, err := t.Transact( - &RecipientAddress, nil, transactor.TransactOptions{Value: WeiAmount, GasLimit: gasLimit}, + context.Background(), &RecipientAddress, nil, transactor.TransactOptions{Value: WeiAmount, GasLimit: gasLimit}, ) if err != nil { log.Error().Err(fmt.Errorf("base currency deposit error: %v", err)) From 88dda81d63fdc966111e70a8e243f12d18c8f272 Mon Sep 17 00:00:00 2001 From: Kirill Pisarev Date: Tue, 29 Aug 2023 14:14:43 +0200 Subject: [PATCH 03/11] fix: fix linters --- chains/evm/calls/transactor/monitored/monitored.go | 4 ++-- chains/evm/calls/transactor/signAndSend/signAndSend.go | 2 +- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/chains/evm/calls/transactor/monitored/monitored.go b/chains/evm/calls/transactor/monitored/monitored.go index dc10769a..cd5ea203 100644 --- a/chains/evm/calls/transactor/monitored/monitored.go +++ b/chains/evm/calls/transactor/monitored/monitored.go @@ -68,7 +68,7 @@ func NewMonitoredTransactor( } func (t *MonitoredTransactor) Transact(ctx context.Context, to *common.Address, data []byte, opts transactor.TransactOptions) (*common.Hash, error) { - ctx, span := otel.Tracer("relayer-core").Start(ctx, "relayer.core.EVMListener.ListenToEvents") + _, span := otel.Tracer("relayer-core").Start(ctx, "relayer.core.EVMListener.ListenToEvents") t.client.LockNonce() defer t.client.UnlockNonce() @@ -246,7 +246,7 @@ func (t *MonitoredTransactor) resendTransaction(ctx context.Context, tx *RawTx) // would be 11 (it floors the value). In case the gas price didn't // change it increases it by 1. func (t *MonitoredTransactor) IncreaseGas(ctx context.Context, oldGp []*big.Int) []*big.Int { - ctx, span := otel.Tracer("relayer-core").Start(ctx, "relayer.sygma.evm.transactor.Monitor.IncreaseGas") + _, span := otel.Tracer("relayer-core").Start(ctx, "relayer.sygma.evm.transactor.Monitor.IncreaseGas") newGp := make([]*big.Int, len(oldGp)) for i, gp := range oldGp { percentIncreaseValue := new(big.Int).Div(new(big.Int).Mul(gp, t.increasePercentage), big.NewInt(100)) diff --git a/chains/evm/calls/transactor/signAndSend/signAndSend.go b/chains/evm/calls/transactor/signAndSend/signAndSend.go index 079d66fc..e353b2dd 100644 --- a/chains/evm/calls/transactor/signAndSend/signAndSend.go +++ b/chains/evm/calls/transactor/signAndSend/signAndSend.go @@ -31,7 +31,7 @@ func NewSignAndSendTransactor(txFabric calls.TxFabric, gasPriceClient calls.GasP } func (t *signAndSendTransactor) Transact(ctx context.Context, to *common.Address, data []byte, opts transactor.TransactOptions) (*common.Hash, error) { - ctx, span := otel.Tracer("relayer-core").Start(ctx, "relayer.core.Transactor.signAndSendTransactor.Transact") + _, span := otel.Tracer("relayer-core").Start(ctx, "relayer.core.Transactor.signAndSendTransactor.Transact") t.client.LockNonce() n, err := t.client.UnsafeNonce() if err != nil { From 77199fc51bf513a7f8333658fb48fa75b6f48a9d Mon Sep 17 00:00:00 2001 From: Kirill Pisarev Date: Tue, 29 Aug 2023 18:47:19 +0200 Subject: [PATCH 04/11] fix: replaced additional map with TraceID to structure in for monitored transaction --- .../calls/transactor/monitored/monitored.go | 67 ++++++++----------- .../transactor/signAndSend/signAndSend.go | 9 +-- 2 files changed, 29 insertions(+), 47 deletions(-) diff --git a/chains/evm/calls/transactor/monitored/monitored.go b/chains/evm/calls/transactor/monitored/monitored.go index cd5ea203..3679b4c3 100644 --- a/chains/evm/calls/transactor/monitored/monitored.go +++ b/chains/evm/calls/transactor/monitored/monitored.go @@ -29,6 +29,11 @@ type RawTx struct { creationTime time.Time } +type RawTxWithTraceID struct { + RawTx + traceID traceapi.TraceID +} + type MonitoredTransactor struct { txFabric calls.TxFabric gasPriceClient calls.GasPricer @@ -37,8 +42,7 @@ type MonitoredTransactor struct { maxGasPrice *big.Int increasePercentage *big.Int - pendingTxns map[common.Hash]RawTx - pendingTxnsTrace map[common.Hash]traceapi.TraceID + pendingTxns map[common.Hash]RawTxWithTraceID txLock sync.Mutex } @@ -60,30 +64,27 @@ func NewMonitoredTransactor( client: client, gasPriceClient: gasPriceClient, txFabric: txFabric, - pendingTxns: make(map[common.Hash]RawTx), - pendingTxnsTrace: make(map[common.Hash]traceapi.TraceID), + pendingTxns: make(map[common.Hash]RawTxWithTraceID), maxGasPrice: maxGasPrice, increasePercentage: increasePercentage, } } func (t *MonitoredTransactor) Transact(ctx context.Context, to *common.Address, data []byte, opts transactor.TransactOptions) (*common.Hash, error) { - _, span := otel.Tracer("relayer-core").Start(ctx, "relayer.core.EVMListener.ListenToEvents") - + _, span := otel.Tracer("relayer-core").Start(ctx, "relayer.core.evm.transactor.Monitor") + defer span.End() t.client.LockNonce() defer t.client.UnlockNonce() n, err := t.client.UnsafeNonce() if err != nil { span.RecordError(fmt.Errorf("unable to get unsafe nonce with err: %w", err)) - span.End() return &common.Hash{}, err } err = transactor.MergeTransactionOptions(&opts, &transactor.DefaultTransactionOptions) if err != nil { span.RecordError(fmt.Errorf("unable to merge transaction options with err: %w", err)) - span.End() return &common.Hash{}, err } @@ -100,39 +101,41 @@ func (t *MonitoredTransactor) Transact(ctx context.Context, to *common.Address, span.AddEvent("Calculated GasPrice", traceapi.WithAttributes(attribute.String("tx.gp", gp[0].String()))) } - rawTx := RawTx{ - to: to, - nonce: n.Uint64(), - value: opts.Value, - gasLimit: opts.GasLimit, - gasPrice: gp, - data: data, - submitTime: time.Now(), - creationTime: time.Now(), + rawTx := RawTxWithTraceID{ + RawTx{ + to: to, + nonce: n.Uint64(), + value: opts.Value, + gasLimit: opts.GasLimit, + gasPrice: gp, + data: data, + submitTime: time.Now(), + creationTime: time.Now(), + }, + span.SpanContext().TraceID(), } tx, err := t.txFabric(rawTx.nonce, rawTx.to, rawTx.value, rawTx.gasLimit, rawTx.gasPrice, rawTx.data) if err != nil { span.RecordError(fmt.Errorf("unable to call TxFabric with err: %w", err)) - span.End() return &common.Hash{}, err } h, err := t.client.SignAndSendTransaction(context.TODO(), tx) if err != nil { span.RecordError(fmt.Errorf("unable to SignAndSendTransaction with err: %w", err)) - span.End() + span.SetStatus(codes.Error, "unable to SignAndSendTransaction") return &common.Hash{}, err } + span.AddEvent("Executed transaction", traceapi.WithAttributes(attribute.String("tx.hash", h.String()))) t.txLock.Lock() t.pendingTxns[h] = rawTx - t.pendingTxnsTrace[h] = span.SpanContext().TraceID() t.txLock.Unlock() err = t.client.UnsafeIncreaseNonce() if err != nil { span.RecordError(fmt.Errorf("unable to UnsafeIncreaseNonce with err: %w", err)) - span.End() + span.SetStatus(codes.Error, "unable to UnsafeIncreaseNonce") return &common.Hash{}, err } @@ -154,27 +157,17 @@ func (t *MonitoredTransactor) Monitor( case <-ticker.C: { t.txLock.Lock() - pendingTxCopy := make(map[common.Hash]RawTx, len(t.pendingTxns)) + pendingTxCopy := make(map[common.Hash]RawTxWithTraceID, len(t.pendingTxns)) for k, v := range t.pendingTxns { pendingTxCopy[k] = v } - pendingTxTraceIDCopy := make(map[common.Hash]traceapi.TraceID, len(t.pendingTxnsTrace)) - for k, v := range t.pendingTxnsTrace { - pendingTxTraceIDCopy[k] = v - } t.txLock.Unlock() for oldHash, tx := range pendingTxCopy { if time.Since(tx.submitTime) < tooNewTransaction { continue } - tID, ok := pendingTxTraceIDCopy[oldHash] - if ok { - // Creating span context with existing TraceID - spanCtx := traceapi.NewSpanContext(traceapi.SpanContextConfig{TraceID: tID, Remote: true}) - ctx = traceapi.ContextWithSpanContext(ctx, spanCtx) - } - ctx, span := otel.Tracer("relayer-sygma").Start(ctx, "relayer.sygma.evm.transactor.Monitor") + txContextWithSpan, span := otel.Tracer("relayer-core").Start(traceapi.ContextWithSpanContext(ctx, traceapi.NewSpanContext(traceapi.SpanContextConfig{TraceID: tx.traceID})), "relayer.core.evm.transactor.Monitor") logger := log.With().Str("dd.trace_id", span.SpanContext().TraceID().String()).Logger() receipt, err := t.client.TransactionReceipt(context.Background(), oldHash) @@ -191,7 +184,6 @@ func (t *MonitoredTransactor) Monitor( span.End() } delete(t.pendingTxns, oldHash) - delete(t.pendingTxnsTrace, oldHash) continue } @@ -200,11 +192,10 @@ func (t *MonitoredTransactor) Monitor( span.RecordError(fmt.Errorf("transaction has timed out"), traceapi.WithAttributes(attribute.String("tx.hash", oldHash.String()), attribute.Int64("tx.nonce", int64(tx.nonce)))) span.End() delete(t.pendingTxns, oldHash) - delete(t.pendingTxnsTrace, oldHash) continue } - hash, err := t.resendTransaction(ctx, &tx) + hash, err := t.resendTransaction(txContextWithSpan, &tx.RawTx) if err != nil { span.RecordError(fmt.Errorf("error resending transaction %w", err), traceapi.WithAttributes(attribute.String("tx.hash", oldHash.String()), attribute.Int64("tx.nonce", int64(tx.nonce)))) logger.Warn().Uint64("nonce", tx.nonce).Err(err).Msgf("Failed resending transaction %s", oldHash) @@ -214,9 +205,7 @@ func (t *MonitoredTransactor) Monitor( span.End() delete(t.pendingTxns, oldHash) - delete(t.pendingTxnsTrace, oldHash) t.pendingTxns[hash] = tx - t.pendingTxnsTrace[hash] = tID } } } @@ -246,7 +235,7 @@ func (t *MonitoredTransactor) resendTransaction(ctx context.Context, tx *RawTx) // would be 11 (it floors the value). In case the gas price didn't // change it increases it by 1. func (t *MonitoredTransactor) IncreaseGas(ctx context.Context, oldGp []*big.Int) []*big.Int { - _, span := otel.Tracer("relayer-core").Start(ctx, "relayer.sygma.evm.transactor.Monitor.IncreaseGas") + _, span := otel.Tracer("relayer-core").Start(ctx, "relayer.core.evm.transactor.Monitor.IncreaseGas") newGp := make([]*big.Int, len(oldGp)) for i, gp := range oldGp { percentIncreaseValue := new(big.Int).Div(new(big.Int).Mul(gp, t.increasePercentage), big.NewInt(100)) diff --git a/chains/evm/calls/transactor/signAndSend/signAndSend.go b/chains/evm/calls/transactor/signAndSend/signAndSend.go index e353b2dd..b2dd9d78 100644 --- a/chains/evm/calls/transactor/signAndSend/signAndSend.go +++ b/chains/evm/calls/transactor/signAndSend/signAndSend.go @@ -32,12 +32,12 @@ func NewSignAndSendTransactor(txFabric calls.TxFabric, gasPriceClient calls.GasP func (t *signAndSendTransactor) Transact(ctx context.Context, to *common.Address, data []byte, opts transactor.TransactOptions) (*common.Hash, error) { _, span := otel.Tracer("relayer-core").Start(ctx, "relayer.core.Transactor.signAndSendTransactor.Transact") + defer span.End() t.client.LockNonce() n, err := t.client.UnsafeNonce() if err != nil { t.client.UnlockNonce() span.RecordError(fmt.Errorf("unable to get unsafe nonce with err: %w", err)) - span.End() return &common.Hash{}, err } @@ -45,7 +45,6 @@ func (t *signAndSendTransactor) Transact(ctx context.Context, to *common.Address if err != nil { t.client.UnlockNonce() span.RecordError(fmt.Errorf("unable to merge transaction options with err: %w", err)) - span.End() return &common.Hash{}, err } @@ -55,7 +54,6 @@ func (t *signAndSendTransactor) Transact(ctx context.Context, to *common.Address if err != nil { t.client.UnlockNonce() span.RecordError(fmt.Errorf("unable to define gas price with err: %w", err)) - span.End() return &common.Hash{}, err } } @@ -70,7 +68,6 @@ func (t *signAndSendTransactor) Transact(ctx context.Context, to *common.Address if err != nil { t.client.UnlockNonce() span.RecordError(fmt.Errorf("unable to call TxFabric with err: %w", err)) - span.End() return &common.Hash{}, err } @@ -78,7 +75,6 @@ func (t *signAndSendTransactor) Transact(ctx context.Context, to *common.Address if err != nil { t.client.UnlockNonce() span.RecordError(fmt.Errorf("unable to SignAndSendTransaction with err: %w", err)) - span.End() return &common.Hash{}, err } @@ -86,17 +82,14 @@ func (t *signAndSendTransactor) Transact(ctx context.Context, to *common.Address t.client.UnlockNonce() if err != nil { span.RecordError(fmt.Errorf("unable to UnsafeIncreaseNonce with err: %w", err)) - span.End() return &common.Hash{}, err } _, err = t.client.WaitAndReturnTxReceipt(h) if err != nil { span.RecordError(fmt.Errorf("unable to WaitAndReturnTxReceipt with err: %w", err)) - span.End() return &common.Hash{}, err } span.SetStatus(codes.Ok, "Transaction sent") - span.End() return &h, nil } From fe75ae09dd10eaff81729c79d94aab329fb13416 Mon Sep 17 00:00:00 2001 From: Kirill Pisarev Date: Fri, 8 Sep 2023 14:54:13 +0200 Subject: [PATCH 05/11] feat: refactoring of the traces usage with traceutils --- chains/evm/calls/contracts/contract.go | 2 +- chains/evm/calls/events/events.go | 10 +- chains/evm/calls/events/listener.go | 27 ++--- .../calls/transactor/monitored/monitored.go | 74 +++++------- .../transactor/monitored/monitored_test.go | 4 +- .../transactor/signAndSend/signAndSend.go | 37 +++--- chains/evm/cli/logger/logger.go | 4 +- chains/evm/listener/event-handler.go | 30 ++--- chains/evm/listener/listener.go | 24 ++-- example/app/app.go | 10 +- {logger => observability}/logger.go | 2 +- {opentelemetry => observability}/metrics.go | 2 +- {opentelemetry => observability}/traces.go | 2 +- observability/traceutils.go | 109 ++++++++++++++++++ relayer/message/message_processors.go | 68 ----------- .../message/processors/message_processors.go | 59 ++++++++++ .../message_processors_test.go | 8 +- relayer/relayer.go | 35 +++--- relayer/relayer_test.go | 4 +- 19 files changed, 297 insertions(+), 214 deletions(-) rename {logger => observability}/logger.go (94%) rename {opentelemetry => observability}/metrics.go (99%) rename {opentelemetry => observability}/traces.go (97%) create mode 100644 observability/traceutils.go delete mode 100644 relayer/message/message_processors.go create mode 100644 relayer/message/processors/message_processors.go rename relayer/message/{ => processors}/message_processors_test.go (88%) diff --git a/chains/evm/calls/contracts/contract.go b/chains/evm/calls/contracts/contract.go index 07aeefbb..96445fe6 100644 --- a/chains/evm/calls/contracts/contract.go +++ b/chains/evm/calls/contracts/contract.go @@ -78,7 +78,7 @@ func (c *Contract) ExecuteTransaction(ctx context.Context, method string, opts t Str("txHash", h.String()). Str("contract", c.contractAddress.String()). Msgf("method %s executed", method) - return h, err + return h, nil } func (c *Contract) CallContract(method string, args ...interface{}) ([]interface{}, error) { diff --git a/chains/evm/calls/events/events.go b/chains/evm/calls/events/events.go index 443cb3ba..14f432d4 100644 --- a/chains/evm/calls/events/events.go +++ b/chains/evm/calls/events/events.go @@ -3,6 +3,8 @@ package events import ( "fmt" + "github.com/status-im/keycard-go/hexutils" + "github.com/ChainSafe/chainbridge-core/types" "github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/crypto" @@ -42,5 +44,11 @@ type Deposit struct { } func (d *Deposit) TraceEventAttributes() []attribute.KeyValue { - return []attribute.KeyValue{attribute.Int("deposit.dstdomain", int(d.DestinationDomainID)), attribute.String("deposit.rID", fmt.Sprintf("%x", d.ResourceID)), attribute.String("tx.sender", d.SenderAddress.Hex())} + return []attribute.KeyValue{attribute.Int("deposit.dstdomain", int(d.DestinationDomainID)), attribute.String("deposit.rID", fmt.Sprintf("%x", d.ResourceID)), attribute.String("deposit.sender", d.SenderAddress.Hex())} +} + +func (d *Deposit) String() string { + return fmt.Sprintf( + `Destination: %d,DepositNonce: %d,ResourceID: %x,Sender: %s, Data: %s, HandlerResponse: %s`, + d.DestinationDomainID, d.DepositNonce, d.ResourceID, d.SenderAddress.Hex(), hexutils.BytesToHex(d.Data), hexutils.BytesToHex(d.HandlerResponse)) } diff --git a/chains/evm/calls/events/listener.go b/chains/evm/calls/events/listener.go index d1f5751e..4cd543f6 100644 --- a/chains/evm/calls/events/listener.go +++ b/chains/evm/calls/events/listener.go @@ -2,18 +2,16 @@ package events import ( "context" + "fmt" "math/big" "strings" "github.com/ChainSafe/chainbridge-core/chains/evm/calls/consts" + "github.com/ChainSafe/chainbridge-core/observability" "github.com/ethereum/go-ethereum/accounts/abi" "github.com/ethereum/go-ethereum/common" ethTypes "github.com/ethereum/go-ethereum/core/types" - "github.com/rs/zerolog/log" - "go.opentelemetry.io/otel" "go.opentelemetry.io/otel/attribute" - "go.opentelemetry.io/otel/codes" - traceapi "go.opentelemetry.io/otel/trace" ) type ChainClient interface { @@ -34,32 +32,29 @@ func NewListener(client ChainClient) *Listener { } func (l *Listener) FetchDeposits(ctx context.Context, contractAddress common.Address, startBlock *big.Int, endBlock *big.Int) ([]*Deposit, error) { - ctxWithSpan, span := otel.Tracer("relayer-core").Start(ctx, "relayer.core.Listener.FetchDeposits") + ctx, span, logger := observability.CreateSpanAndLoggerFromContext(ctx, "relayer-core", "relayer.core.Listener.FetchDeposits", attribute.String("startBlock", startBlock.String()), attribute.String("endBlock", endBlock.String())) defer span.End() - span.SetAttributes(attribute.String("startBlock", startBlock.String()), attribute.String("endBlock", endBlock.String())) - logger := log.With().Str("dd.trace_id", span.SpanContext().TraceID().String()).Logger() - logs, err := l.client.FetchEventLogs(ctxWithSpan, contractAddress, string(DepositSig), startBlock, endBlock) + logs, err := l.client.FetchEventLogs(ctx, contractAddress, string(DepositSig), startBlock, endBlock) if err != nil { - span.SetStatus(codes.Error, err.Error()) - return nil, err + return nil, observability.LogAndRecordErrorWithStatus(&logger, span, err, "failed FetchEventLogs") } deposits := make([]*Deposit, 0) for _, dl := range logs { d, err := l.UnpackDeposit(l.abi, dl.Data) if err != nil { - logger.Error().Msgf("failed unpacking deposit event log: %v", err) - span.RecordError(err) + _ = observability.LogAndRecordError(&logger, span, err, "failed unpacking deposit event log") continue } - d.SenderAddress = common.BytesToAddress(dl.Topics[1].Bytes()) - logger.Debug().Msgf("Found deposit log in block: %d, TxHash: %s, contractAddress: %s, sender: %s", dl.BlockNumber, dl.TxHash, dl.Address, d.SenderAddress) - span.AddEvent("Found deposit", traceapi.WithAttributes(append(d.TraceEventAttributes(), attribute.String("tx.hash", dl.TxHash.Hex()))...)) deposits = append(deposits, d) + observability.LogAndEvent( + logger.Debug(), + span, + fmt.Sprintf("Found deposit log in block: %d, TxHash: %s, contractAddress: %s, sender: %s", dl.BlockNumber, dl.TxHash, dl.Address, d.SenderAddress), + append(d.TraceEventAttributes(), attribute.String("tx.hash", dl.TxHash.Hex()))...) } - span.SetStatus(codes.Ok, "Deposits fetched") return deposits, nil } diff --git a/chains/evm/calls/transactor/monitored/monitored.go b/chains/evm/calls/transactor/monitored/monitored.go index 3679b4c3..ae186c07 100644 --- a/chains/evm/calls/transactor/monitored/monitored.go +++ b/chains/evm/calls/transactor/monitored/monitored.go @@ -7,14 +7,13 @@ import ( "sync" "time" + "github.com/ChainSafe/chainbridge-core/observability" + "github.com/ChainSafe/chainbridge-core/chains/evm/calls" "github.com/ChainSafe/chainbridge-core/chains/evm/calls/transactor" "github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/core/types" - "github.com/rs/zerolog/log" - "go.opentelemetry.io/otel" "go.opentelemetry.io/otel/attribute" - "go.opentelemetry.io/otel/codes" traceapi "go.opentelemetry.io/otel/trace" ) @@ -71,21 +70,20 @@ func NewMonitoredTransactor( } func (t *MonitoredTransactor) Transact(ctx context.Context, to *common.Address, data []byte, opts transactor.TransactOptions) (*common.Hash, error) { - _, span := otel.Tracer("relayer-core").Start(ctx, "relayer.core.evm.transactor.Monitor") + _, span, _ := observability.CreateSpanAndLoggerFromContext(ctx, "relayer-core", "relayer.core.evm.monitoredTransactor.Transact") defer span.End() + t.client.LockNonce() defer t.client.UnlockNonce() n, err := t.client.UnsafeNonce() if err != nil { - span.RecordError(fmt.Errorf("unable to get unsafe nonce with err: %w", err)) - return &common.Hash{}, err + return &common.Hash{}, observability.LogAndRecordErrorWithStatus(nil, span, err, "failed to call UnsafeNonce") } err = transactor.MergeTransactionOptions(&opts, &transactor.DefaultTransactionOptions) if err != nil { - span.RecordError(fmt.Errorf("unable to merge transaction options with err: %w", err)) - return &common.Hash{}, err + return &common.Hash{}, observability.LogAndRecordErrorWithStatus(nil, span, err, "failed to MergeTransactionOptions") } gp := []*big.Int{opts.GasPrice} @@ -116,17 +114,14 @@ func (t *MonitoredTransactor) Transact(ctx context.Context, to *common.Address, } tx, err := t.txFabric(rawTx.nonce, rawTx.to, rawTx.value, rawTx.gasLimit, rawTx.gasPrice, rawTx.data) if err != nil { - span.RecordError(fmt.Errorf("unable to call TxFabric with err: %w", err)) - return &common.Hash{}, err + return &common.Hash{}, observability.LogAndRecordErrorWithStatus(nil, span, err, "unable to call TxFabric") } h, err := t.client.SignAndSendTransaction(context.TODO(), tx) if err != nil { - span.RecordError(fmt.Errorf("unable to SignAndSendTransaction with err: %w", err)) - span.SetStatus(codes.Error, "unable to SignAndSendTransaction") - return &common.Hash{}, err + return &common.Hash{}, observability.LogAndRecordErrorWithStatus(nil, span, err, "unable to SignAndSendTransaction") } - span.AddEvent("Executed transaction", traceapi.WithAttributes(attribute.String("tx.hash", h.String()))) + span.AddEvent("Transaction sent", traceapi.WithAttributes(attribute.String("tx.hash", h.String()))) t.txLock.Lock() t.pendingTxns[h] = rawTx @@ -134,11 +129,8 @@ func (t *MonitoredTransactor) Transact(ctx context.Context, to *common.Address, err = t.client.UnsafeIncreaseNonce() if err != nil { - span.RecordError(fmt.Errorf("unable to UnsafeIncreaseNonce with err: %w", err)) - span.SetStatus(codes.Error, "unable to UnsafeIncreaseNonce") - return &common.Hash{}, err + return &common.Hash{}, observability.LogAndRecordErrorWithStatus(nil, span, err, "unable to UnsafeIncreaseNonce") } - return &h, nil } @@ -167,29 +159,25 @@ func (t *MonitoredTransactor) Monitor( if time.Since(tx.submitTime) < tooNewTransaction { continue } - txContextWithSpan, span := otel.Tracer("relayer-core").Start(traceapi.ContextWithSpanContext(ctx, traceapi.NewSpanContext(traceapi.SpanContextConfig{TraceID: tx.traceID})), "relayer.core.evm.transactor.Monitor") - logger := log.With().Str("dd.trace_id", span.SpanContext().TraceID().String()).Logger() - + txContextWithSpan, span, logger := observability.CreateSpanAndLoggerFromContext( + traceapi.ContextWithSpanContext(ctx, traceapi.NewSpanContext(traceapi.SpanContextConfig{TraceID: tx.traceID})), + "relayer-core", + "relayer.core.evm.transactor.Monitor", + attribute.String("tx.hash", oldHash.String()), attribute.Int64("tx.nonce", int64(tx.nonce))) receipt, err := t.client.TransactionReceipt(context.Background(), oldHash) if err == nil { if receipt.Status == types.ReceiptStatusSuccessful { - logger.Info().Uint64("nonce", tx.nonce).Msgf("Executed transaction %s with nonce %d", oldHash, tx.nonce) - span.AddEvent("Executed transaction", traceapi.WithAttributes(attribute.String("tx.hash", oldHash.String()), attribute.Int64("tx.nonce", int64(tx.nonce)))) - span.SetStatus(codes.Ok, "Executed transaction") - span.End() + observability.LogAndEvent(logger.Info(), span, fmt.Sprintf("Executed transaction %s with nonce %d", oldHash, tx.nonce)) } else { - logger.Error().Uint64("nonce", tx.nonce).Msgf("Transaction %s failed on chain", oldHash) - span.RecordError(fmt.Errorf("transaction execution failed on chain with error %w", err), traceapi.WithAttributes(attribute.String("tx.hash", oldHash.String()), attribute.Int64("tx.nonce", int64(tx.nonce)))) - span.SetStatus(codes.Error, "Transaction execution failed on chain") - span.End() + _ = observability.LogAndRecordErrorWithStatus(&logger, span, fmt.Errorf("on-chain execution fail"), fmt.Sprintf("transaction %s failed on chain", oldHash)) } + span.End() delete(t.pendingTxns, oldHash) continue } if time.Since(tx.creationTime) > txTimeout { - logger.Error().Uint64("nonce", tx.nonce).Msgf("Transaction %s has timed out", oldHash) - span.RecordError(fmt.Errorf("transaction has timed out"), traceapi.WithAttributes(attribute.String("tx.hash", oldHash.String()), attribute.Int64("tx.nonce", int64(tx.nonce)))) + _ = observability.LogAndRecordErrorWithStatus(&logger, span, fmt.Errorf("transaction has timed out"), fmt.Sprintf("transaction %s failed on chain", oldHash)) span.End() delete(t.pendingTxns, oldHash) continue @@ -199,9 +187,10 @@ func (t *MonitoredTransactor) Monitor( if err != nil { span.RecordError(fmt.Errorf("error resending transaction %w", err), traceapi.WithAttributes(attribute.String("tx.hash", oldHash.String()), attribute.Int64("tx.nonce", int64(tx.nonce)))) logger.Warn().Uint64("nonce", tx.nonce).Err(err).Msgf("Failed resending transaction %s", oldHash) + _ = observability.LogAndRecordError(&logger, span, err, "failed resending transaction") continue } - span.AddEvent("Resending transaction", traceapi.WithAttributes(attribute.String("tx.newHash", hash.String()))) + span.AddEvent("Transaction resent", traceapi.WithAttributes(attribute.String("tx.newHash", hash.String()))) span.End() delete(t.pendingTxns, oldHash) @@ -213,7 +202,14 @@ func (t *MonitoredTransactor) Monitor( } func (t *MonitoredTransactor) resendTransaction(ctx context.Context, tx *RawTx) (common.Hash, error) { - tx.gasPrice = t.IncreaseGas(ctx, tx.gasPrice) + ctx, span, logger := observability.CreateSpanAndLoggerFromContext(ctx, "relayer-core", "relayer.core.evm.transactor.Monitor.resendTransaction") + defer span.End() + tx.gasPrice = t.IncreaseGas(tx.gasPrice) + if len(tx.gasPrice) > 1 { + observability.LogAndEvent(logger.Debug(), span, "Calculated GasPrice", attribute.String("tx.gasTipCap", tx.gasPrice[0].String()), attribute.String("tx.gasFeeCap", tx.gasPrice[1].String())) + } else { + observability.LogAndEvent(logger.Debug(), span, "Calculated GasPrice", attribute.String("tx.gp", tx.gasPrice[0].String())) + } newTx, err := t.txFabric(tx.nonce, tx.to, tx.value, tx.gasLimit, tx.gasPrice, tx.data) if err != nil { return common.Hash{}, err @@ -223,9 +219,6 @@ func (t *MonitoredTransactor) resendTransaction(ctx context.Context, tx *RawTx) if err != nil { return common.Hash{}, err } - - log.Debug().Uint64("nonce", tx.nonce).Msgf("Resent transaction with hash %s", hash) - return hash, nil } @@ -234,8 +227,7 @@ func (t *MonitoredTransactor) resendTransaction(ctx context.Context, tx *RawTx) // If gas was 10 and the increaseFactor is 15 the new gas price // would be 11 (it floors the value). In case the gas price didn't // change it increases it by 1. -func (t *MonitoredTransactor) IncreaseGas(ctx context.Context, oldGp []*big.Int) []*big.Int { - _, span := otel.Tracer("relayer-core").Start(ctx, "relayer.core.evm.transactor.Monitor.IncreaseGas") +func (t *MonitoredTransactor) IncreaseGas(oldGp []*big.Int) []*big.Int { newGp := make([]*big.Int, len(oldGp)) for i, gp := range oldGp { percentIncreaseValue := new(big.Int).Div(new(big.Int).Mul(gp, t.increasePercentage), big.NewInt(100)) @@ -250,11 +242,5 @@ func (t *MonitoredTransactor) IncreaseGas(ctx context.Context, oldGp []*big.Int) newGp[i] = increasedGp } } - if len(newGp) > 1 { - span.AddEvent("Calculated GasPrice", traceapi.WithAttributes(attribute.String("tx.gasTipCap", newGp[0].String()), attribute.String("tx.gasFeeCap", newGp[1].String()))) - } else { - span.AddEvent("Calculated GasPrice", traceapi.WithAttributes(attribute.String("tx.gp", newGp[0].String()))) - } - span.End() return newGp } diff --git a/chains/evm/calls/transactor/monitored/monitored_test.go b/chains/evm/calls/transactor/monitored/monitored_test.go index bbac2dfb..16423f6b 100644 --- a/chains/evm/calls/transactor/monitored/monitored_test.go +++ b/chains/evm/calls/transactor/monitored/monitored_test.go @@ -246,7 +246,7 @@ func (s *TransactorTestSuite) TestTransactor_IncreaseGas_15PercentIncrease() { big.NewInt(150), big.NewInt(15)) - newGas := t.IncreaseGas(context.Background(), []*big.Int{big.NewInt(1), big.NewInt(10), big.NewInt(100)}) + newGas := t.IncreaseGas([]*big.Int{big.NewInt(1), big.NewInt(10), big.NewInt(100)}) s.Equal(newGas, []*big.Int{big.NewInt(2), big.NewInt(11), big.NewInt(115)}) } @@ -259,7 +259,7 @@ func (s *TransactorTestSuite) TestTransactor_IncreaseGas_MaxGasReached() { big.NewInt(15), big.NewInt(15)) - newGas := t.IncreaseGas(context.Background(), []*big.Int{big.NewInt(1), big.NewInt(10), big.NewInt(100)}) + newGas := t.IncreaseGas([]*big.Int{big.NewInt(1), big.NewInt(10), big.NewInt(100)}) s.Equal(newGas, []*big.Int{big.NewInt(2), big.NewInt(11), big.NewInt(15)}) } diff --git a/chains/evm/calls/transactor/signAndSend/signAndSend.go b/chains/evm/calls/transactor/signAndSend/signAndSend.go index b2dd9d78..8fbee462 100644 --- a/chains/evm/calls/transactor/signAndSend/signAndSend.go +++ b/chains/evm/calls/transactor/signAndSend/signAndSend.go @@ -2,12 +2,10 @@ package signAndSend import ( "context" - "fmt" "math/big" - "go.opentelemetry.io/otel/codes" + "github.com/ChainSafe/chainbridge-core/observability" - "go.opentelemetry.io/otel" "go.opentelemetry.io/otel/attribute" traceapi "go.opentelemetry.io/otel/trace" @@ -31,21 +29,20 @@ func NewSignAndSendTransactor(txFabric calls.TxFabric, gasPriceClient calls.GasP } func (t *signAndSendTransactor) Transact(ctx context.Context, to *common.Address, data []byte, opts transactor.TransactOptions) (*common.Hash, error) { - _, span := otel.Tracer("relayer-core").Start(ctx, "relayer.core.Transactor.signAndSendTransactor.Transact") + ctx, span, logger := observability.CreateSpanAndLoggerFromContext(ctx, "relayer-core", "relayer.core.Transactor.signAndSendTransactor.Transact") defer span.End() + t.client.LockNonce() n, err := t.client.UnsafeNonce() if err != nil { t.client.UnlockNonce() - span.RecordError(fmt.Errorf("unable to get unsafe nonce with err: %w", err)) - return &common.Hash{}, err + return &common.Hash{}, observability.LogAndRecordErrorWithStatus(nil, span, err, "failed to call UnsafeNonce") } err = transactor.MergeTransactionOptions(&opts, &transactor.DefaultTransactionOptions) if err != nil { t.client.UnlockNonce() - span.RecordError(fmt.Errorf("unable to merge transaction options with err: %w", err)) - return &common.Hash{}, err + return &common.Hash{}, observability.LogAndRecordErrorWithStatus(nil, span, err, "failed to MergeTransactionOptions") } gp := []*big.Int{opts.GasPrice} @@ -53,43 +50,39 @@ func (t *signAndSendTransactor) Transact(ctx context.Context, to *common.Address gp, err = t.gasPriceClient.GasPrice(&opts.Priority) if err != nil { t.client.UnlockNonce() - span.RecordError(fmt.Errorf("unable to define gas price with err: %w", err)) - return &common.Hash{}, err + return &common.Hash{}, observability.LogAndRecordErrorWithStatus(nil, span, err, "failed to define gas price") } } if len(gp) > 1 { - span.AddEvent("Calculated GasPrice", traceapi.WithAttributes(attribute.String("tx.gasTipCap", gp[0].String()), attribute.String("tx.gasFeeCap", gp[1].String()))) + observability.LogAndEvent(logger.Debug(), span, "Calculated GasPrice", attribute.String("tx.gasTipCap", gp[0].String()), attribute.String("tx.gasFeeCap", gp[1].String())) } else { - span.AddEvent("Calculated GasPrice", traceapi.WithAttributes(attribute.String("tx.gp", gp[0].String()))) + observability.LogAndEvent(logger.Debug(), span, "Calculated GasPrice", attribute.String("tx.gp", gp[0].String())) } tx, err := t.TxFabric(n.Uint64(), to, opts.Value, opts.GasLimit, gp, data) if err != nil { t.client.UnlockNonce() - span.RecordError(fmt.Errorf("unable to call TxFabric with err: %w", err)) - return &common.Hash{}, err + return &common.Hash{}, observability.LogAndRecordErrorWithStatus(nil, span, err, "unable to call TxFabric") } - h, err := t.client.SignAndSendTransaction(context.TODO(), tx) + h, err := t.client.SignAndSendTransaction(ctx, tx) if err != nil { t.client.UnlockNonce() - span.RecordError(fmt.Errorf("unable to SignAndSendTransaction with err: %w", err)) - return &common.Hash{}, err + return &common.Hash{}, observability.LogAndRecordErrorWithStatus(nil, span, err, "unable to SignAndSendTransaction") } + span.AddEvent("Transaction sent", traceapi.WithAttributes(attribute.String("tx.hash", h.String()))) + err = t.client.UnsafeIncreaseNonce() t.client.UnlockNonce() if err != nil { - span.RecordError(fmt.Errorf("unable to UnsafeIncreaseNonce with err: %w", err)) - return &common.Hash{}, err + return &common.Hash{}, observability.LogAndRecordErrorWithStatus(nil, span, err, "unable to UnsafeIncreaseNonce") } _, err = t.client.WaitAndReturnTxReceipt(h) if err != nil { - span.RecordError(fmt.Errorf("unable to WaitAndReturnTxReceipt with err: %w", err)) - return &common.Hash{}, err + return &common.Hash{}, observability.LogAndRecordErrorWithStatus(nil, span, err, "failed to WaitAndReturnTxReceipt") } - span.SetStatus(codes.Ok, "Transaction sent") return &h, nil } diff --git a/chains/evm/cli/logger/logger.go b/chains/evm/cli/logger/logger.go index cec60cb8..205b1eb4 100644 --- a/chains/evm/cli/logger/logger.go +++ b/chains/evm/cli/logger/logger.go @@ -5,7 +5,7 @@ import ( "os" "time" - "github.com/ChainSafe/chainbridge-core/logger" + "github.com/ChainSafe/chainbridge-core/observability" "github.com/rs/zerolog" "github.com/rs/zerolog/log" "github.com/spf13/pflag" @@ -43,5 +43,5 @@ func LoggerMetadata(cmdName string, flagSet *pflag.FlagSet) { // PartsExclude - omit log level and execution time from final log logConsoleWriter := zerolog.ConsoleWriter{Out: os.Stdout, PartsExclude: []string{"level", "time"}} logFileWriter := zerolog.ConsoleWriter{Out: file, PartsExclude: []string{"level", "time"}} - logger.ConfigureLogger(zerolog.DebugLevel, logConsoleWriter, logFileWriter) + observability.ConfigureLogger(zerolog.DebugLevel, logConsoleWriter, logFileWriter) } diff --git a/chains/evm/listener/event-handler.go b/chains/evm/listener/event-handler.go index 00f16911..d56491f7 100644 --- a/chains/evm/listener/event-handler.go +++ b/chains/evm/listener/event-handler.go @@ -2,17 +2,15 @@ package listener import ( "context" + "errors" "fmt" "math/big" - traceapi "go.opentelemetry.io/otel/trace" - "github.com/ChainSafe/chainbridge-core/chains/evm/calls/events" + "github.com/ChainSafe/chainbridge-core/observability" "github.com/ChainSafe/chainbridge-core/relayer/message" "github.com/ChainSafe/chainbridge-core/types" "github.com/ethereum/go-ethereum/common" - "github.com/rs/zerolog/log" - "go.opentelemetry.io/otel" "go.opentelemetry.io/otel/attribute" "go.opentelemetry.io/otel/codes" ) @@ -43,14 +41,16 @@ func NewDepositEventHandler(eventListener EventListener, depositHandler DepositH } func (eh *DepositEventHandler) HandleEvent(ctx context.Context, startBlock *big.Int, endBlock *big.Int, msgChan chan []*message.Message) error { - ctxWithSpan, span := otel.Tracer("relayer-core").Start(ctx, "relayer.core.DepositEventHandler.HandleEvent") + ctxWithSpan, span, logger := observability.CreateSpanAndLoggerFromContext( + ctx, + "relayer-core", + "relayer.core.DepositEventHandler.HandleEvent", + attribute.String("startBlock", startBlock.String()), attribute.String("endBlock", endBlock.String())) defer span.End() - span.SetAttributes(attribute.String("startBlock", startBlock.String()), attribute.String("endBlock", endBlock.String())) - logger := log.With().Str("dd.trace_id", span.SpanContext().TraceID().String()).Logger() + deposits, err := eh.eventListener.FetchDeposits(ctxWithSpan, eh.bridgeAddress, startBlock, endBlock) if err != nil { - span.SetStatus(codes.Error, err.Error()) - return fmt.Errorf("unable to fetch deposit events because of: %+v", err) + return observability.LogAndRecordErrorWithStatus(nil, span, err, "unable to fetch deposit events") } domainDeposits := make(map[uint8][]*message.Message) @@ -58,7 +58,7 @@ func (eh *DepositEventHandler) HandleEvent(ctx context.Context, startBlock *big. func(d *events.Deposit) { defer func() { if r := recover(); r != nil { - log.Error().Err(err).Msgf("panic occured while handling deposit %+v", d) + _ = observability.LogAndRecordError(&logger, span, errors.New("panic"), "panic occured while handling deposit", d.TraceEventAttributes()...) } }() @@ -68,10 +68,13 @@ func (eh *DepositEventHandler) HandleEvent(ctx context.Context, startBlock *big. span.SetStatus(codes.Error, err.Error()) return } - - logger.Debug().Str("msg.id", m.ID()).Msgf("Resolved message %s in block range: %s-%s", m.String(), startBlock.String(), endBlock.String()) - span.AddEvent("Resolved message", traceapi.WithAttributes(attribute.String("msg.id", m.ID()), attribute.String("msg.type", string(m.Type)))) domainDeposits[m.Destination] = append(domainDeposits[m.Destination], m) + observability.LogAndEvent( + logger.Debug(), + span, + fmt.Sprintf("Resolved message %s in block range: %s-%s", m.String(), startBlock.String(), endBlock.String()), + attribute.String("msg.id", m.ID()), + attribute.String("msg.type", string(m.Type))) }(d) } @@ -80,6 +83,5 @@ func (eh *DepositEventHandler) HandleEvent(ctx context.Context, startBlock *big. msgChan <- d }(deposits) } - span.SetStatus(codes.Ok, "Deposits handled") return nil } diff --git a/chains/evm/listener/listener.go b/chains/evm/listener/listener.go index 805fb99c..c8c0b076 100644 --- a/chains/evm/listener/listener.go +++ b/chains/evm/listener/listener.go @@ -9,12 +9,13 @@ import ( "math/big" "time" + "go.opentelemetry.io/otel/attribute" + + "github.com/ChainSafe/chainbridge-core/observability" "github.com/ChainSafe/chainbridge-core/relayer/message" "github.com/ChainSafe/chainbridge-core/store" "github.com/rs/zerolog" "github.com/rs/zerolog/log" - "go.opentelemetry.io/otel" - "go.opentelemetry.io/otel/codes" ) type EventHandler interface { @@ -77,13 +78,11 @@ func (l *EVMListener) ListenToEvents(ctx context.Context, startBlock *big.Int, m case <-ctx.Done(): return default: - ctxWithSpan, span := otel.Tracer("relayer-core").Start(ctx, "relayer.core.EVMListener.ListenToEvents") - logger := l.log.With().Str("dd.trace_id", span.SpanContext().TraceID().String()).Logger() + ctxWithSpan, span, logger := observability.CreateSpanAndLoggerFromContext(ctx, "relayer-core", "relayer.core.EVMListener.ListenToEvents") head, err := l.client.LatestBlock() if err != nil { - logger.Error().Err(err).Msg("Unable to get latest block") time.Sleep(l.blockRetryInterval) - span.RecordError(fmt.Errorf("unable to get latest block with err: %w", err)) + _ = observability.LogAndRecordError(&logger, span, err, "Unable to get latest block") span.End() continue } @@ -95,19 +94,19 @@ func (l *EVMListener) ListenToEvents(ctx context.Context, startBlock *big.Int, m // Sleep if the difference is less than needed block confirmations; (latest - current) < BlockDelay if new(big.Int).Sub(head, endBlock).Cmp(l.blockConfirmations) == -1 { time.Sleep(l.blockRetryInterval) - span.AddEvent("The block difference is too low") - span.SetStatus(codes.Ok, "The block difference is too low") + observability.LogAndEvent(logger.Debug(), span, fmt.Sprintf("Block difference is less then %s", l.blockConfirmations)) span.End() continue } l.metrics.TrackBlockDelta(l.domainID, head, endBlock) - logger.Debug().Msgf("Fetching evm events for block range %s-%s", startBlock, endBlock) + + observability.LogAndEvent(logger.Debug(), span, fmt.Sprintf("Fetching evm events for block range %s-%s", startBlock, endBlock), attribute.String("startBlock", startBlock.String()), attribute.String("endBlock", endBlock.String())) for _, handler := range l.eventHandlers { err := handler.HandleEvent(ctxWithSpan, startBlock, new(big.Int).Sub(endBlock, big.NewInt(1)), msgChan) if err != nil { - logger.Error().Err(err).Msgf("Unable to handle events") + _ = observability.LogAndRecordError(&logger, span, err, "Unable to handle event") continue } } @@ -115,12 +114,9 @@ func (l *EVMListener) ListenToEvents(ctx context.Context, startBlock *big.Int, m //Write to block store. Not a critical operation, no need to retry err = l.blockstore.StoreBlock(endBlock, l.domainID) if err != nil { - logger.Error().Str("block", endBlock.String()).Err(err).Msg("Failed to write latest block to blockstore") - span.RecordError(fmt.Errorf("failed to write latest block to blockstore: %w", err)) + _ = observability.LogAndRecordError(&logger, span, err, "Failed to write latest block to blockstore") } - startBlock.Add(startBlock, l.blockInterval) - span.SetStatus(codes.Ok, "Listened to events") span.End() } } diff --git a/example/app/app.go b/example/app/app.go index 0f4f575d..ed86fd7a 100644 --- a/example/app/app.go +++ b/example/app/app.go @@ -29,7 +29,7 @@ import ( "github.com/ChainSafe/chainbridge-core/e2e/dummy" "github.com/ChainSafe/chainbridge-core/flags" "github.com/ChainSafe/chainbridge-core/lvldb" - "github.com/ChainSafe/chainbridge-core/opentelemetry" + "github.com/ChainSafe/chainbridge-core/observability" "github.com/ChainSafe/chainbridge-core/relayer" "github.com/ChainSafe/chainbridge-core/store" "github.com/ethereum/go-ethereum/common" @@ -52,9 +52,9 @@ func Run() error { } blockstore := store.NewBlockStore(db) - OTLPResource := opentelemetry.InitResource(fmt.Sprintf("Relayer-%s", configuration.RelayerConfig.Id), configuration.RelayerConfig.Env) + OTLPResource := observability.InitResource(fmt.Sprintf("Relayer-%s", configuration.RelayerConfig.Id), configuration.RelayerConfig.Env) - mp, err := opentelemetry.InitMetricProvider(ctx, OTLPResource, configuration.RelayerConfig.OpenTelemetryCollectorURL) + mp, err := observability.InitMetricProvider(ctx, OTLPResource, configuration.RelayerConfig.OpenTelemetryCollectorURL) if err != nil { panic(err) } @@ -64,7 +64,7 @@ func Run() error { } }() - tp, err := opentelemetry.InitTracesProvider(ctx, OTLPResource, configuration.RelayerConfig.OpenTelemetryCollectorURL) + tp, err := observability.InitTracesProvider(ctx, OTLPResource, configuration.RelayerConfig.OpenTelemetryCollectorURL) if err != nil { panic(err) } @@ -74,7 +74,7 @@ func Run() error { } }() - metrics, err := opentelemetry.NewRelayerMetrics(mp.Meter("relayer-metric-provider"), attribute.String("relayer.id", configuration.RelayerConfig.Id), attribute.String("env", configuration.RelayerConfig.Env)) + metrics, err := observability.NewRelayerMetrics(mp.Meter("relayer-metric-provider"), attribute.String("relayer.id", configuration.RelayerConfig.Id), attribute.String("env", configuration.RelayerConfig.Env)) if err != nil { panic(err) } diff --git a/logger/logger.go b/observability/logger.go similarity index 94% rename from logger/logger.go rename to observability/logger.go index d1832286..49cca965 100644 --- a/logger/logger.go +++ b/observability/logger.go @@ -1,4 +1,4 @@ -package logger +package observability import ( "io" diff --git a/opentelemetry/metrics.go b/observability/metrics.go similarity index 99% rename from opentelemetry/metrics.go rename to observability/metrics.go index b39b8f0c..f24feb9f 100644 --- a/opentelemetry/metrics.go +++ b/observability/metrics.go @@ -1,4 +1,4 @@ -package opentelemetry +package observability import ( "context" diff --git a/opentelemetry/traces.go b/observability/traces.go similarity index 97% rename from opentelemetry/traces.go rename to observability/traces.go index a52e7d31..cdb224a9 100644 --- a/opentelemetry/traces.go +++ b/observability/traces.go @@ -1,4 +1,4 @@ -package opentelemetry +package observability import ( "context" diff --git a/observability/traceutils.go b/observability/traceutils.go new file mode 100644 index 00000000..de29f9b5 --- /dev/null +++ b/observability/traceutils.go @@ -0,0 +1,109 @@ +package observability + +import ( + "context" + "fmt" + + "github.com/rs/zerolog" + "go.opentelemetry.io/otel" + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/codes" + traceapi "go.opentelemetry.io/otel/trace" +) + +// CreateSpanAndLoggerFromContext creates span and logger from context with provided name. +// Logger explicitly extended with dd.trace_id attribute for DataDog logs and traces connections +func CreateSpanAndLoggerFromContext(ctx context.Context, tracerName, spanName string, kv ...attribute.KeyValue) (context.Context, traceapi.Span, zerolog.Logger) { + ctx, span := otel.Tracer(tracerName).Start(ctx, spanName) + l := zerolog.Ctx(ctx).With().Str("dd.trace_id", span.SpanContext().TraceID().String()).Logger() + setOTLPAttrsToLogger(&l, kv) + span.SetAttributes(kv...) + + return ctx, span, l +} + +func CreateSpanAndLoggerFromExternalTraceID(ctx context.Context, traceID, tracerName, spanName string, kv ...attribute.KeyValue) (context.Context, traceapi.Span, zerolog.Logger) { + tID, err := traceapi.TraceIDFromHex(traceID) + if err == nil { + ctx = traceapi.ContextWithSpanContext(ctx, traceapi.NewSpanContext(traceapi.SpanContextConfig{TraceID: tID, Remote: true})) + } + return CreateSpanAndLoggerFromContext(ctx, tracerName, spanName, kv...) +} + +func SetSpanAndLoggerAttrs(logger *zerolog.Logger, span traceapi.Span, kv ...attribute.KeyValue) { + setOTLPAttrsToLogger(logger, kv) + span.SetAttributes(kv...) +} + +// LogAndEvent CreatesTrace Span event with attributes and provided name and also creates log with the same attributes +// and name to keep necessary informing level for developers that are not using Trace onitoring tool +func LogAndEvent(logger *zerolog.Event, span traceapi.Span, msg string, kv ...attribute.KeyValue) { + span.AddEvent(msg, traceapi.WithAttributes(kv...)) + if logger != nil { + logger.Msg(msg) + addOTLPAttrsToLogEvent(logger, kv) + } +} + +// LogAndRecordError CreatesTrace Span event with attributes and provided name and also creates log with the same attributes +// and name to keep necessary informing level for developers that are not using Trace onitoring tool +// use logger == nil for not logging an error +func LogAndRecordError(logger *zerolog.Logger, span traceapi.Span, err error, msg string, kv ...attribute.KeyValue) error { + err = fmt.Errorf("%s with err: %e", msg, err) + span.RecordError(err, traceapi.WithAttributes(kv...)) + if logger != nil { + setOTLPAttrsToLogger(logger, kv) + logger.Err(err).Msg(msg) + } + return err +} + +// LogAndRecordErrorWithStatus Records error to traces logs it and set error status to span +// Should be used when span will be ended afterwards. Corresponding span will be marked as errored +// use logger == nil for not logging an error +// Returns error wrapped with message +func LogAndRecordErrorWithStatus(logger *zerolog.Logger, span traceapi.Span, err error, msg string, kv ...attribute.KeyValue) error { + err = fmt.Errorf("%s with err: %e", msg, err) + span.RecordError(err, traceapi.WithAttributes(kv...)) + span.SetStatus(codes.Error, err.Error()) + if logger != nil { + setOTLPAttrsToLogger(logger, kv) + logger.Err(err).Msg(msg) + } + return err +} + +func SetAttrsToSpanAnLogger(logger *zerolog.Logger, span traceapi.Span, kv ...attribute.KeyValue) { + span.SetAttributes(kv...) + setOTLPAttrsToLogger(logger, kv) +} + +func setOTLPAttrsToLogger(logger *zerolog.Logger, attrs []attribute.KeyValue) { + for _, attr := range attrs { + switch attr.Value.Type() { + case attribute.STRING: + logger.With().Str(string(attr.Key), attr.Value.AsString()) + case attribute.BOOL: + logger.With().Bool(string(attr.Key), attr.Value.AsBool()) + case attribute.INT64: + logger.With().Int64(string(attr.Key), attr.Value.AsInt64()) + default: + logger.With().Str(string(attr.Key), fmt.Sprintf("%+v", attr.Value)) + } + } +} + +func addOTLPAttrsToLogEvent(logger *zerolog.Event, attrs []attribute.KeyValue) { + for _, attr := range attrs { + switch attr.Value.Type() { + case attribute.STRING: + logger.Str(string(attr.Key), attr.Value.AsString()) + case attribute.BOOL: + logger.Bool(string(attr.Key), attr.Value.AsBool()) + case attribute.INT64: + logger.Int64(string(attr.Key), attr.Value.AsInt64()) + default: + logger.Str(string(attr.Key), fmt.Sprintf("%+v", attr.Value)) + } + } +} diff --git a/relayer/message/message_processors.go b/relayer/message/message_processors.go deleted file mode 100644 index 806e5697..00000000 --- a/relayer/message/message_processors.go +++ /dev/null @@ -1,68 +0,0 @@ -package message - -import ( - "context" - "errors" - "math/big" - - "go.opentelemetry.io/otel/attribute" - "go.opentelemetry.io/otel/codes" - - "go.opentelemetry.io/otel" - - "github.com/rs/zerolog/log" -) - -type MessageProcessor func(ctx context.Context, message *Message) error - -// AdjustDecimalsForERC20AmountMessageProcessor is a function, that accepts message and map[domainID uint8]{decimal uint} -// using this params processor converts amount for one chain to another for provided decimals with floor rounding -func AdjustDecimalsForERC20AmountMessageProcessor(args ...interface{}) MessageProcessor { - return func(ctx context.Context, m *Message) error { - _, span := otel.Tracer("relayer-core").Start(ctx, "relayer.core.MessageProcessor.AdjustDecimalsForERC20AmountMessageProcessor") - span.SetAttributes(attribute.String("msg.id", m.ID()), attribute.String("msg.type", string(m.Type))) - defer span.End() - if len(args) == 0 { - span.SetStatus(codes.Error, "processor requires 1 argument") - return errors.New("processor requires 1 argument") - } - decimalsMap, ok := args[0].(map[uint8]uint64) - if !ok { - span.SetStatus(codes.Error, "no decimals map found in args") - return errors.New("no decimals map found in args") - } - sourceDecimal, ok := decimalsMap[m.Source] - if !ok { - span.SetStatus(codes.Error, "no source decimals found at decimalsMap") - return errors.New("no source decimals found at decimalsMap") - } - destDecimal, ok := decimalsMap[m.Destination] - if !ok { - span.SetStatus(codes.Error, "no destination decimals found at decimalsMap") - return errors.New("no destination decimals found at decimalsMap") - } - amountByte, ok := m.Payload[0].([]byte) - if !ok { - span.SetStatus(codes.Error, "could not cast interface to byte slice") - return errors.New("could not cast interface to byte slice") - } - amount := new(big.Int).SetBytes(amountByte) - if sourceDecimal > destDecimal { - diff := sourceDecimal - destDecimal - roundedAmount := big.NewInt(0) - roundedAmount.Div(amount, big.NewInt(0).Exp(big.NewInt(10), big.NewInt(0).SetUint64(diff), nil)) - log.Info().Str("msg.id", m.ID()).Msgf("amount %s rounded to %s from chain %v to chain %v", amount.String(), roundedAmount.String(), m.Source, m.Destination) - m.Payload[0] = roundedAmount.Bytes() - span.SetStatus(codes.Ok, "msg processed") - return nil - } - if sourceDecimal < destDecimal { - diff := destDecimal - sourceDecimal - roundedAmount := big.NewInt(0) - roundedAmount.Mul(amount, big.NewInt(0).Exp(big.NewInt(10), big.NewInt(0).SetUint64(diff), nil)) - m.Payload[0] = roundedAmount.Bytes() - log.Info().Str("msg.id", m.ID()).Msgf("amount %s rounded to %s from chain %v to chain %v", amount.String(), roundedAmount.String(), m.Source, m.Destination) - } - return nil - } -} diff --git a/relayer/message/processors/message_processors.go b/relayer/message/processors/message_processors.go new file mode 100644 index 00000000..847b6dfa --- /dev/null +++ b/relayer/message/processors/message_processors.go @@ -0,0 +1,59 @@ +package processors + +import ( + "context" + "errors" + "fmt" + "math/big" + + "github.com/ChainSafe/chainbridge-core/observability" + "github.com/ChainSafe/chainbridge-core/relayer/message" + "go.opentelemetry.io/otel/attribute" +) + +type MessageProcessor func(ctx context.Context, message *message.Message) error + +// AdjustDecimalsForERC20AmountMessageProcessor is a function, that accepts message and map[domainID uint8]{decimal uint} +// using this params processor converts amount for one chain to another for provided decimals with floor rounding +func AdjustDecimalsForERC20AmountMessageProcessor(args ...interface{}) MessageProcessor { + return func(ctx context.Context, m *message.Message) error { + _, span, logger := observability.CreateSpanAndLoggerFromContext( + ctx, + "relayer-core", + "relayer.core.MessageProcessor.AdjustDecimalsForERC20AmountMessageProcessor", + attribute.String("msg.id", m.ID()), attribute.String("msg.type", string(m.Type))) + defer span.End() + if len(args) == 0 { + return observability.LogAndRecordErrorWithStatus(&logger, span, errors.New("processor requires 1 argument"), "failed to processMessage with AdjustDecimalsForERC20AmountMessageProcessor") + } + decimalsMap, ok := args[0].(map[uint8]uint64) + if !ok { + return observability.LogAndRecordErrorWithStatus(&logger, span, errors.New("no decimals map found in args"), "failed to processMessage with AdjustDecimalsForERC20AmountMessageProcessor") + } + sourceDecimal, ok := decimalsMap[m.Source] + if !ok { + return observability.LogAndRecordErrorWithStatus(&logger, span, errors.New("no source decimals found at decimalsMap"), "failed to processMessage with AdjustDecimalsForERC20AmountMessageProcessor") + } + destDecimal, ok := decimalsMap[m.Destination] + if !ok { + return observability.LogAndRecordErrorWithStatus(&logger, span, errors.New("no destination decimals found at decimalsMap"), "failed to processMessage with AdjustDecimalsForERC20AmountMessageProcessor") + } + amountByte, ok := m.Payload[0].([]byte) + if !ok { + return observability.LogAndRecordErrorWithStatus(&logger, span, errors.New("could not cast interface to byte slice"), "failed to processMessage with AdjustDecimalsForERC20AmountMessageProcessor") + } + amount := new(big.Int).SetBytes(amountByte) + roundedAmount := big.NewInt(0) + if sourceDecimal > destDecimal { + diff := sourceDecimal - destDecimal + roundedAmount.Div(amount, big.NewInt(0).Exp(big.NewInt(10), big.NewInt(0).SetUint64(diff), nil)) + m.Payload[0] = roundedAmount.Bytes() + } else if sourceDecimal < destDecimal { + diff := destDecimal - sourceDecimal + roundedAmount.Mul(amount, big.NewInt(0).Exp(big.NewInt(10), big.NewInt(0).SetUint64(diff), nil)) + m.Payload[0] = roundedAmount.Bytes() + } + observability.LogAndEvent(logger.Info(), span, fmt.Sprintf("amount %s rounded to %s from chain %v to chain %v", amount.String(), roundedAmount.String(), m.Source, m.Destination)) + return nil + } +} diff --git a/relayer/message/message_processors_test.go b/relayer/message/processors/message_processors_test.go similarity index 88% rename from relayer/message/message_processors_test.go rename to relayer/message/processors/message_processors_test.go index ea0d86fe..f2241f7e 100644 --- a/relayer/message/message_processors_test.go +++ b/relayer/message/processors/message_processors_test.go @@ -1,15 +1,17 @@ -package message +package processors import ( "context" "math/big" "testing" + + "github.com/ChainSafe/chainbridge-core/relayer/message" ) // TestRouter tests relayers router func TestAdjustDecimalsForERC20AmountMessageProcessor(t *testing.T) { a, _ := big.NewInt(0).SetString("145556700000000000000", 10) // 145.5567 tokens - msg := &Message{ + msg := &message.Message{ Destination: 2, Source: 1, Payload: []interface{}{ @@ -24,7 +26,7 @@ func TestAdjustDecimalsForERC20AmountMessageProcessor(t *testing.T) { if amount.Cmp(big.NewInt(14555)) != 0 { t.Fatal(amount.String()) } - msg2 := &Message{ + msg2 := &message.Message{ Destination: 1, Source: 2, Payload: []interface{}{ diff --git a/relayer/relayer.go b/relayer/relayer.go index d77456e2..150e5746 100644 --- a/relayer/relayer.go +++ b/relayer/relayer.go @@ -7,13 +7,14 @@ import ( "context" "fmt" + "github.com/ChainSafe/chainbridge-core/relayer/message/processors" + "go.opentelemetry.io/otel/codes" + "github.com/ChainSafe/chainbridge-core/observability" "github.com/ChainSafe/chainbridge-core/relayer/message" "github.com/rs/zerolog/log" - "go.opentelemetry.io/otel" "go.opentelemetry.io/otel/attribute" - traceapi "go.opentelemetry.io/otel/trace" ) type DepositMeter interface { @@ -28,7 +29,7 @@ type RelayedChain interface { DomainID() uint8 } -func NewRelayer(chains []RelayedChain, metrics DepositMeter, messageProcessors ...message.MessageProcessor) *Relayer { +func NewRelayer(chains []RelayedChain, metrics DepositMeter, messageProcessors ...processors.MessageProcessor) *Relayer { return &Relayer{relayedChains: chains, messageProcessors: messageProcessors, metrics: metrics} } @@ -36,21 +37,19 @@ type Relayer struct { metrics DepositMeter relayedChains []RelayedChain registry map[uint8]RelayedChain - messageProcessors []message.MessageProcessor + messageProcessors []processors.MessageProcessor } // Start function starts the relayer. Relayer routine is starting all the chains // and passing them with a channel that accepts unified cross chain message format func (r *Relayer) Start(ctx context.Context, sysErr chan error) { log.Debug().Msgf("Starting relayer") - messagesChannel := make(chan []*message.Message) for _, c := range r.relayedChains { log.Debug().Msgf("Starting chain %v", c.DomainID()) r.addRelayedChain(c) go c.PollEvents(ctx, sysErr, messagesChannel) } - for { select { case m := <-messagesChannel: @@ -64,38 +63,38 @@ func (r *Relayer) Start(ctx context.Context, sysErr chan error) { // Route function runs destination writer by mapping DestinationID from message to registered writer. func (r *Relayer) route(msgs []*message.Message) { - ctxWithSpan, span := otel.Tracer("relayer-core").Start(context.Background(), "relayer.core.Route") + ctx, span, logger := observability.CreateSpanAndLoggerFromContext(context.Background(), "relayer-core", "relayer.core.Route") defer span.End() destChain, ok := r.registry[msgs[0].Destination] if !ok { - log.Error().Msgf("no resolver for destID %v to send message registered", msgs[0].Destination) - span.SetStatus(codes.Error, fmt.Sprintf("no resolver for destID %v to send message registered", msgs[0].Destination)) + _ = observability.LogAndRecordErrorWithStatus(&logger, span, fmt.Errorf("no resolver for destID %v to send message registered", msgs[0].Destination), "Routing failed") return } - - log.Debug().Msgf("Routing %d messages to destination %d", len(msgs), destChain.DomainID()) for _, m := range msgs { - span.AddEvent("Routing message", traceapi.WithAttributes(attribute.String("msg.id", m.ID()), attribute.String("msg.type", string(m.Type)))) - log.Debug().Str("msg.id", m.ID()).Msgf("Routing message %+v", m.String()) + observability.LogAndEvent( + logger.Info(), + span, + fmt.Sprintf("routing message %s", m.String()), + attribute.String("msg.id", m.ID()), + attribute.String("msg.type", string(m.Type))) r.metrics.TrackDepositMessage(m) for _, mp := range r.messageProcessors { - if err := mp(ctxWithSpan, m); err != nil { - log.Error().Str("msg.id", m.ID()).Err(fmt.Errorf("error %w processing message %v", err, m.String())) + if err := mp(ctx, m); err != nil { + _ = observability.LogAndRecordErrorWithStatus(&logger, span, err, "message processing fail", attribute.String("msg.id", m.ID())) return } } } - err := destChain.Write(ctxWithSpan, msgs) + err := destChain.Write(ctx, msgs) if err != nil { for _, m := range msgs { - log.Err(err).Str("msg.id", m.ID()).Msgf("Failed sending message %s to destination %v", m.String(), destChain.DomainID()) + _ = observability.LogAndRecordErrorWithStatus(&logger, span, err, "failed sending message to destination", attribute.String("msg.id", m.ID())) r.metrics.TrackExecutionError(m) } return } - for _, m := range msgs { r.metrics.TrackSuccessfulExecutionLatency(m) } diff --git a/relayer/relayer_test.go b/relayer/relayer_test.go index 9c13ad30..3f021f0d 100644 --- a/relayer/relayer_test.go +++ b/relayer/relayer_test.go @@ -6,6 +6,8 @@ import ( "math/big" "testing" + "github.com/ChainSafe/chainbridge-core/relayer/message/processors" + "github.com/ChainSafe/chainbridge-core/relayer/message" mock_relayer "github.com/ChainSafe/chainbridge-core/relayer/mock" "github.com/golang/mock/gomock" @@ -51,7 +53,7 @@ func (s *RouteTestSuite) TestAdjustDecimalsForERC20AmountMessageProcessor() { a.Bytes(), // 145.5567 tokens }, } - err := message.AdjustDecimalsForERC20AmountMessageProcessor(map[uint8]uint64{1: 18, 2: 2})(context.Background(), msg) + err := processors.AdjustDecimalsForERC20AmountMessageProcessor(map[uint8]uint64{1: 18, 2: 2})(context.Background(), msg) s.Nil(err) amount := new(big.Int).SetBytes(msg.Payload[0].([]byte)) if amount.Cmp(big.NewInt(14555)) != 0 { From b2c04ccd7fbd3cfed4dd43394baeeeb6ccaa4ad3 Mon Sep 17 00:00:00 2001 From: Kirill Pisarev Date: Fri, 8 Sep 2023 15:28:34 +0200 Subject: [PATCH 06/11] fix: unit tests, add details to some event --- example/cfg/otel-collector-config.yml | 38 ++++++++++++++++++++------- example/cfg/prometheus.yml | 17 ++++++++++++ example/docker-compose.yml | 26 ++++++++++++++++++ relayer/relayer.go | 6 ++++- relayer/relayer_test.go | 2 +- 5 files changed, 78 insertions(+), 11 deletions(-) create mode 100644 example/cfg/prometheus.yml diff --git a/example/cfg/otel-collector-config.yml b/example/cfg/otel-collector-config.yml index c79beb6f..845c7ee5 100644 --- a/example/cfg/otel-collector-config.yml +++ b/example/cfg/otel-collector-config.yml @@ -4,22 +4,42 @@ receivers: grpc: http: +processors: + batch: + timeout: 10s + send_batch_max_size: 1000 + send_batch_size: 100 + exporters: + otlp: + endpoint: "jaeger:4317" + tls: + insecure: true + retry_on_failure: + enabled: true + prometheus: - endpoint: 0.0.0.0:8889 - namespace: default - jaeger: - endpoint: 0.0.0.0:14250 + endpoint: "otel-collector:8889" + namespace: relayer + send_timestamps: true + enable_open_metrics: true + add_metric_suffixes: false + resource_to_telemetry_conversion: + enabled: true + + logging: + loglevel: debug + sampling_initial: 5 + sampling_thereafter: 200 -extensions: - health_check: service: - extensions: [health_check] pipelines: metrics: - exporters: [prometheus] receivers: [otlp] + processors: [batch] + exporters: [prometheus, logging] traces: receivers: [otlp] - exporters: [jaeger] \ No newline at end of file + processors: [batch] + exporters: [otlp] \ No newline at end of file diff --git a/example/cfg/prometheus.yml b/example/cfg/prometheus.yml new file mode 100644 index 00000000..29473d7f --- /dev/null +++ b/example/cfg/prometheus.yml @@ -0,0 +1,17 @@ +global: + scrape_interval: 15s # Set the scrape interval to every 15 seconds. Default is every 1 minute. + evaluation_interval: 15s # Evaluate rules every 15 seconds. The default is every 1 minute. + # scrape_timeout is set to the global default (10s). + + +rule_files: +# - "first_rules.yml" +# - "second_rules.yml" + +scrape_configs: + - job_name: 'relayer' + scrape_interval: 10s + # metrics_path defaults to '/metrics' + # scheme defaults to 'http'. + static_configs: + - targets: [ 'otel-collector:8889' ] \ No newline at end of file diff --git a/example/docker-compose.yml b/example/docker-compose.yml index 9a7221e4..af67b943 100644 --- a/example/docker-compose.yml +++ b/example/docker-compose.yml @@ -86,15 +86,41 @@ services: - ./cfg:/cfg restart: always + otel-collector: container_name: otel-collector image: otel/opentelemetry-collector command: ["--config=/etc/otel-collector-config.yml"] + depends_on: + - jaeger + - prometheus volumes: - ./cfg/otel-collector-config.yml:/etc/otel-collector-config.yml ports: - "8889:8889" # Prometheus exporter metrics + jaeger: + container_name: jaeger + image: jaegertracing/all-in-one + ports: + - "4318:4318" + - "16686:16686" + - "4317:4317" + environment: + - COLLECTOR_OTLP_ENABLED=true + + prometheus: + container_name: prometheus + image: prom/prometheus:latest + volumes: + - ./cfg/prometheus.yml:/etc/prometheus/prometheus.yml + # - prometheus_data:/prometheus + command: + - '--config.file=/etc/prometheus/prometheus.yml' + - '--storage.tsdb.path=/prometheus' + ports: + - 9090:9090 + networks: evm2: evm1: diff --git a/relayer/relayer.go b/relayer/relayer.go index 150e5746..ff7466d7 100644 --- a/relayer/relayer.go +++ b/relayer/relayer.go @@ -77,7 +77,11 @@ func (r *Relayer) route(msgs []*message.Message) { span, fmt.Sprintf("routing message %s", m.String()), attribute.String("msg.id", m.ID()), - attribute.String("msg.type", string(m.Type))) + attribute.String("msg.type", string(m.Type)), + attribute.String("msg.dstChainId", fmt.Sprintf("%d", destChain.DomainID())), + attribute.String("msg.srcChainId", fmt.Sprintf("%d", m.Source)), + ) + r.metrics.TrackDepositMessage(m) for _, mp := range r.messageProcessors { if err := mp(ctx, m); err != nil { diff --git a/relayer/relayer_test.go b/relayer/relayer_test.go index 3f021f0d..b3ce5017 100644 --- a/relayer/relayer_test.go +++ b/relayer/relayer_test.go @@ -80,7 +80,7 @@ func (s *RouteTestSuite) TestLogsErrorIfMessageProcessorReturnsError() { func (s *RouteTestSuite) TestWriteFail() { s.mockMetrics.EXPECT().TrackDepositMessage(gomock.Any()) s.mockMetrics.EXPECT().TrackExecutionError(gomock.Any()) - s.mockRelayedChain.EXPECT().DomainID().Return(uint8(1)).Times(3) + s.mockRelayedChain.EXPECT().DomainID().Return(uint8(1)).Times(2) s.mockRelayedChain.EXPECT().Write(gomock.Any(), gomock.Any()).Return(fmt.Errorf("error")) relayer := NewRelayer( []RelayedChain{}, From 526acf4a58c6d4d7f7519bef6e54afe05a1fe4e2 Mon Sep 17 00:00:00 2001 From: Kirill Pisarev Date: Fri, 8 Sep 2023 16:12:53 +0200 Subject: [PATCH 07/11] feat: add jaeger to otel config --- example/cfg/otel-collector-config.yml | 38 +++++++-------------------- go.mod | 6 ++--- 2 files changed, 12 insertions(+), 32 deletions(-) diff --git a/example/cfg/otel-collector-config.yml b/example/cfg/otel-collector-config.yml index 845c7ee5..c79beb6f 100644 --- a/example/cfg/otel-collector-config.yml +++ b/example/cfg/otel-collector-config.yml @@ -4,42 +4,22 @@ receivers: grpc: http: -processors: - batch: - timeout: 10s - send_batch_max_size: 1000 - send_batch_size: 100 - exporters: - otlp: - endpoint: "jaeger:4317" - tls: - insecure: true - retry_on_failure: - enabled: true - prometheus: - endpoint: "otel-collector:8889" - namespace: relayer - send_timestamps: true - enable_open_metrics: true - add_metric_suffixes: false - resource_to_telemetry_conversion: - enabled: true - - logging: - loglevel: debug - sampling_initial: 5 - sampling_thereafter: 200 + endpoint: 0.0.0.0:8889 + namespace: default + jaeger: + endpoint: 0.0.0.0:14250 +extensions: + health_check: service: + extensions: [health_check] pipelines: metrics: + exporters: [prometheus] receivers: [otlp] - processors: [batch] - exporters: [prometheus, logging] traces: receivers: [otlp] - processors: [batch] - exporters: [otlp] \ No newline at end of file + exporters: [jaeger] \ No newline at end of file diff --git a/go.mod b/go.mod index cd4cc00a..216dfed3 100644 --- a/go.mod +++ b/go.mod @@ -13,10 +13,12 @@ require ( github.com/spf13/cobra v1.2.1 github.com/spf13/pflag v1.0.5 github.com/spf13/viper v1.9.0 + github.com/status-im/keycard-go v0.0.0-20211004132608-c32310e39b86 github.com/stretchr/testify v1.8.3 github.com/syndtr/goleveldb v1.0.1-0.20210819022825-2ae1ddf74ef7 go.opentelemetry.io/otel v1.16.0 go.opentelemetry.io/otel/exporters/otlp/otlpmetric/otlpmetrichttp v0.39.0 + go.opentelemetry.io/otel/exporters/otlp/otlptrace v1.16.0 go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp v1.16.0 go.opentelemetry.io/otel/metric v1.16.0 go.opentelemetry.io/otel/sdk/metric v0.39.0 @@ -29,10 +31,8 @@ require ( github.com/go-logr/logr v1.2.4 // indirect github.com/go-logr/stdr v1.2.2 // indirect github.com/grpc-ecosystem/grpc-gateway/v2 v2.7.0 // indirect - github.com/status-im/keycard-go v0.0.0-20211004132608-c32310e39b86 // indirect go.opentelemetry.io/otel/exporters/otlp/internal/retry v1.16.0 // indirect go.opentelemetry.io/otel/exporters/otlp/otlpmetric v0.39.0 // indirect - go.opentelemetry.io/otel/exporters/otlp/otlptrace v1.16.0 // indirect ) require ( @@ -78,7 +78,7 @@ require ( github.com/tklauser/numcpus v0.2.2 // indirect github.com/tyler-smith/go-bip39 v1.0.1-0.20181017060643-dbb3b84ba2ef // indirect go.opentelemetry.io/otel/sdk v1.16.0 - go.opentelemetry.io/otel/trace v1.16.0 // indirect + go.opentelemetry.io/otel/trace v1.16.0 go.opentelemetry.io/proto/otlp v0.19.0 // indirect golang.org/x/net v0.8.0 // indirect golang.org/x/sync v0.0.0-20210220032951-036812b2e83c // indirect From caa0d827875acda8950ed7eea36bcd90073abfe8 Mon Sep 17 00:00:00 2001 From: Kirill Pisarev Date: Fri, 8 Sep 2023 16:14:01 +0200 Subject: [PATCH 08/11] doc: add jaeger local example link to the Reame --- README.md | 3 +++ 1 file changed, 3 insertions(+) diff --git a/README.md b/README.md index 92452384..2bbfb2ef 100644 --- a/README.md +++ b/README.md @@ -56,6 +56,9 @@ You can also review our [Local Setup Guide](https://github.com/ChainSafe/chainbr   +### Tracing +Jaeger traces observer will be available at [http://localhost:16686/](http://localhost:16686/) + ## Contributing Chainbridge-core is a open project and welcomes contributions of all kinds: code, docs, and more. If you wish to submit more complex changes, From 7832d014537b2b79400856f0f475a40bbe067a8e Mon Sep 17 00:00:00 2001 From: Kirill Pisarev Date: Wed, 13 Sep 2023 12:44:44 +0200 Subject: [PATCH 09/11] fix: remove logger from FetchDeposits function err log that bubbles up --- chains/evm/calls/events/listener.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/chains/evm/calls/events/listener.go b/chains/evm/calls/events/listener.go index 4cd543f6..34a0b24a 100644 --- a/chains/evm/calls/events/listener.go +++ b/chains/evm/calls/events/listener.go @@ -37,7 +37,7 @@ func (l *Listener) FetchDeposits(ctx context.Context, contractAddress common.Add logs, err := l.client.FetchEventLogs(ctx, contractAddress, string(DepositSig), startBlock, endBlock) if err != nil { - return nil, observability.LogAndRecordErrorWithStatus(&logger, span, err, "failed FetchEventLogs") + return nil, observability.LogAndRecordErrorWithStatus(nil, span, err, "failed FetchEventLogs") } deposits := make([]*Deposit, 0) From 2820df08155628955ce45e888f227557da4fa410 Mon Sep 17 00:00:00 2001 From: Kirill Pisarev Date: Wed, 13 Sep 2023 13:23:17 +0200 Subject: [PATCH 10/11] fix: remove logic for logging gas price calculator result, instead log all the array --- chains/evm/calls/transactor/monitored/monitored.go | 6 +----- chains/evm/calls/transactor/signAndSend/signAndSend.go | 8 ++------ chains/evm/calls/util.go | 8 ++++++++ 3 files changed, 11 insertions(+), 11 deletions(-) diff --git a/chains/evm/calls/transactor/monitored/monitored.go b/chains/evm/calls/transactor/monitored/monitored.go index ae186c07..9f79f663 100644 --- a/chains/evm/calls/transactor/monitored/monitored.go +++ b/chains/evm/calls/transactor/monitored/monitored.go @@ -93,11 +93,7 @@ func (t *MonitoredTransactor) Transact(ctx context.Context, to *common.Address, return &common.Hash{}, err } } - if len(gp) > 1 { - span.AddEvent("Calculated GasPrice", traceapi.WithAttributes(attribute.String("tx.gasTipCap", gp[0].String()), attribute.String("tx.gasFeeCap", gp[1].String()))) - } else { - span.AddEvent("Calculated GasPrice", traceapi.WithAttributes(attribute.String("tx.gp", gp[0].String()))) - } + span.AddEvent("Calculated GasPrice", traceapi.WithAttributes(attribute.StringSlice("tx.gp", calls.BigIntSliceToStringSlice(gp)))) rawTx := RawTxWithTraceID{ RawTx{ diff --git a/chains/evm/calls/transactor/signAndSend/signAndSend.go b/chains/evm/calls/transactor/signAndSend/signAndSend.go index 8fbee462..8c1f6ac1 100644 --- a/chains/evm/calls/transactor/signAndSend/signAndSend.go +++ b/chains/evm/calls/transactor/signAndSend/signAndSend.go @@ -29,7 +29,7 @@ func NewSignAndSendTransactor(txFabric calls.TxFabric, gasPriceClient calls.GasP } func (t *signAndSendTransactor) Transact(ctx context.Context, to *common.Address, data []byte, opts transactor.TransactOptions) (*common.Hash, error) { - ctx, span, logger := observability.CreateSpanAndLoggerFromContext(ctx, "relayer-core", "relayer.core.Transactor.signAndSendTransactor.Transact") + ctx, span, _ := observability.CreateSpanAndLoggerFromContext(ctx, "relayer-core", "relayer.core.Transactor.signAndSendTransactor.Transact") defer span.End() t.client.LockNonce() @@ -54,11 +54,7 @@ func (t *signAndSendTransactor) Transact(ctx context.Context, to *common.Address } } - if len(gp) > 1 { - observability.LogAndEvent(logger.Debug(), span, "Calculated GasPrice", attribute.String("tx.gasTipCap", gp[0].String()), attribute.String("tx.gasFeeCap", gp[1].String())) - } else { - observability.LogAndEvent(logger.Debug(), span, "Calculated GasPrice", attribute.String("tx.gp", gp[0].String())) - } + span.AddEvent("Calculated GasPrice", traceapi.WithAttributes(attribute.StringSlice("tx.gp", calls.BigIntSliceToStringSlice(gp)))) tx, err := t.TxFabric(n.Uint64(), to, opts.Value, opts.GasLimit, gp, data) if err != nil { diff --git a/chains/evm/calls/util.go b/chains/evm/calls/util.go index e6ab4224..1a82c713 100644 --- a/chains/evm/calls/util.go +++ b/chains/evm/calls/util.go @@ -72,3 +72,11 @@ func WeiAmountToUser(amount *big.Int, decimals *big.Int) (*big.Float, error) { } return new(big.Float).Quo(amountFloat, big.NewFloat(gomath.Pow10(int(decimals.Int64())))), nil } + +func BigIntSliceToStringSlice(arr []*big.Int) []string { + var sArr = make([]string, len(arr)) + for i, v := range arr { + sArr[i] = v.String() + } + return sArr +} From e418c5fed0f33edfe20a832a194962ff4bc4c17b Mon Sep 17 00:00:00 2001 From: Kirill Pisarev Date: Wed, 13 Sep 2023 17:52:57 +0200 Subject: [PATCH 11/11] fix: remove unecessary structures nesting --- .../calls/transactor/monitored/monitored.go | 36 ++++++++----------- 1 file changed, 15 insertions(+), 21 deletions(-) diff --git a/chains/evm/calls/transactor/monitored/monitored.go b/chains/evm/calls/transactor/monitored/monitored.go index 9f79f663..a49442d0 100644 --- a/chains/evm/calls/transactor/monitored/monitored.go +++ b/chains/evm/calls/transactor/monitored/monitored.go @@ -26,11 +26,7 @@ type RawTx struct { data []byte submitTime time.Time creationTime time.Time -} - -type RawTxWithTraceID struct { - RawTx - traceID traceapi.TraceID + traceID traceapi.TraceID } type MonitoredTransactor struct { @@ -41,7 +37,7 @@ type MonitoredTransactor struct { maxGasPrice *big.Int increasePercentage *big.Int - pendingTxns map[common.Hash]RawTxWithTraceID + pendingTxns map[common.Hash]RawTx txLock sync.Mutex } @@ -63,7 +59,7 @@ func NewMonitoredTransactor( client: client, gasPriceClient: gasPriceClient, txFabric: txFabric, - pendingTxns: make(map[common.Hash]RawTxWithTraceID), + pendingTxns: make(map[common.Hash]RawTx), maxGasPrice: maxGasPrice, increasePercentage: increasePercentage, } @@ -95,18 +91,16 @@ func (t *MonitoredTransactor) Transact(ctx context.Context, to *common.Address, } span.AddEvent("Calculated GasPrice", traceapi.WithAttributes(attribute.StringSlice("tx.gp", calls.BigIntSliceToStringSlice(gp)))) - rawTx := RawTxWithTraceID{ - RawTx{ - to: to, - nonce: n.Uint64(), - value: opts.Value, - gasLimit: opts.GasLimit, - gasPrice: gp, - data: data, - submitTime: time.Now(), - creationTime: time.Now(), - }, - span.SpanContext().TraceID(), + rawTx := RawTx{ + to: to, + nonce: n.Uint64(), + value: opts.Value, + gasLimit: opts.GasLimit, + gasPrice: gp, + data: data, + submitTime: time.Now(), + creationTime: time.Now(), + traceID: span.SpanContext().TraceID(), } tx, err := t.txFabric(rawTx.nonce, rawTx.to, rawTx.value, rawTx.gasLimit, rawTx.gasPrice, rawTx.data) if err != nil { @@ -145,7 +139,7 @@ func (t *MonitoredTransactor) Monitor( case <-ticker.C: { t.txLock.Lock() - pendingTxCopy := make(map[common.Hash]RawTxWithTraceID, len(t.pendingTxns)) + pendingTxCopy := make(map[common.Hash]RawTx, len(t.pendingTxns)) for k, v := range t.pendingTxns { pendingTxCopy[k] = v } @@ -179,7 +173,7 @@ func (t *MonitoredTransactor) Monitor( continue } - hash, err := t.resendTransaction(txContextWithSpan, &tx.RawTx) + hash, err := t.resendTransaction(txContextWithSpan, &tx) if err != nil { span.RecordError(fmt.Errorf("error resending transaction %w", err), traceapi.WithAttributes(attribute.String("tx.hash", oldHash.String()), attribute.Int64("tx.nonce", int64(tx.nonce)))) logger.Warn().Uint64("nonce", tx.nonce).Err(err).Msgf("Failed resending transaction %s", oldHash)