chore: improve attestation request handling logging

This makes it easier to debug verifier connectivity/setup issues.

Author: adg-flare

client/attestation/attestation.go

@@ -1,20 +1,20 @@
 package attestation
 
 import (
-	"bytes"
 	"context"
 	"encoding/hex"
-	"errors"
 	"fmt"
 	"math"
 	"math/big"
 	"sync"
 
+	"github.com/flare-foundation/fdc-client/client/utils"
 	"github.com/flare-foundation/go-flare-common/pkg/contracts/fdchub"
 	"github.com/flare-foundation/go-flare-common/pkg/database"
 	"github.com/flare-foundation/go-flare-common/pkg/events"
 	"github.com/flare-foundation/go-flare-common/pkg/logger"
 	"github.com/flare-foundation/go-flare-common/pkg/priority"
+	"github.com/pkg/errors"
 
 	bitvotes "github.com/flare-foundation/fdc-client/client/attestation/bitVotes"
 	"github.com/flare-foundation/fdc-client/client/config"
@@ -175,18 +175,18 @@ func (a *Attestation) Handle(ctx context.Context) error {
 	responseBytes, confirmed, err := ResolveAttestationRequest(ctx, a)
 	if err != nil {
 		a.Status = ProcessError
-		return fmt.Errorf("handle, resolve request: %s", err)
+		return errors.Wrap(err, "unable to resolve attestation request")
 	}
 	if !confirmed {
 		a.Status = Unconfirmed
-		logger.Debugf("unconfirmed request: ")
+		logger.Debugf("attestation request %s for round %d successfully verified but not confirmed", a.Request.TypeAndSourceString(), a.RoundID)
 		return nil
 	}
 
 	a.Response = responseBytes
 	err = a.validateResponse()
 	if err != nil {
-		return fmt.Errorf("handle, validate response: %s", err)
+		return errors.Wrap(err, "unable to validate attestation response")
 	}
 
 	return nil
@@ -209,7 +209,7 @@ func (a *Attestation) PrepareRequest(attestationTypesConfigs config.AttestationT
 	attestationTypeConfig, ok := attestationTypesConfigs[attType]
 	if !ok {
 		a.Status = UnsupportedPair
-		return fmt.Errorf("prepare request: no configs for: %s", string(bytes.Trim(attType[:], "\x00")))
+		return fmt.Errorf("prepare request: no configs for: %s", utils.Bytes32ToString(attType))
 	}
 
 	a.ResponseABI = &attestationTypeConfig.ResponseArguments
@@ -218,7 +218,7 @@ func (a *Attestation) PrepareRequest(attestationTypesConfigs config.AttestationT
 	sourceConfig, ok := attestationTypeConfig.SourcesConfig[source]
 	if !ok {
 		a.Status = UnsupportedPair
-		return fmt.Errorf("prepare request: no configs for: %s, %s", string(bytes.Trim(attType[:], "\x00")), string(bytes.Trim(source[:], "\x00")))
+		return fmt.Errorf("prepare request: no configs for: %s, %s", utils.Bytes32ToString(attType), utils.Bytes32ToString(source))
 	}
 
 	a.LUTLimit = sourceConfig.LUTLimit

client/attestation/verification.go

@@ -10,6 +10,7 @@ import (
 	"github.com/ethereum/go-ethereum/accounts/abi"
 	"github.com/ethereum/go-ethereum/common"
 	"github.com/ethereum/go-ethereum/crypto"
+	"github.com/flare-foundation/fdc-client/client/utils"
 
 	"github.com/flare-foundation/go-flare-common/pkg/logger"
 )
@@ -51,6 +52,23 @@ func (r Request) Source() ([32]byte, error) {
 	return res, nil
 }
 
+// TypeAndSourceString returns the attestation type and source name for debugging
+func (r Request) TypeAndSourceString() string {
+	attType, err := r.AttestationType()
+	attTypeString := "unknown_type"
+	if err == nil {
+		attTypeString = utils.Bytes32ToString(attType)
+	}
+
+	source, err := r.Source()
+	sourceString := "unknown_source"
+	if err == nil {
+		sourceString = utils.Bytes32ToString(source)
+	}
+
+	return fmt.Sprintf("%s/%s", attTypeString, sourceString)
+}
+
 // MIC returns Message Integrity code of the request (the third 32 bytes).
 func (r Request) MIC() (common.Hash, error) {
 	if len(r) < 96 {

client/attestation/verification_test.go

@@ -149,6 +149,9 @@ func TestRequest(t *testing.T) {
 		copy(expectedAttTypeAndSource[:], []byte(test.attType))
 		copy(expectedAttTypeAndSource[32:], []byte(test.source))
 
+		// type and source string
+		require.Equal(t, fmt.Sprintf("%s/%s", test.attType, test.source), req.TypeAndSourceString(), fmt.Sprintf("error type and source string in test %d", i))
+
 		// mic
 		expectedMic := common.HexToHash(test.mic)
 		mic, err := req.MIC()

client/attestation/verifiers.go

@@ -10,6 +10,8 @@ import (
 	"net/http"
 	"strings"
 	"time"
+
+	"github.com/pkg/errors"
 )
 
 const timeout = 5 * time.Second    // maximal duration for the verifier to resolve the query
@@ -40,19 +42,19 @@ func ResolveAttestationRequest(ctx context.Context, att *Attestation) ([]byte, b
 
 	encodedBody, err := json.Marshal(payload)
 	if err != nil {
-		return nil, false, err
+		return nil, false, errors.Wrap(err, "failed to encode request body")
 	}
 
 	request, err := http.NewRequestWithContext(ctx, "POST", att.Credentials.URL, bytes.NewBuffer(encodedBody))
 	if err != nil {
-		return nil, false, err
+		return nil, false, errors.Wrap(err, "failed to create http request")
 	}
 	request.Header.Set("Content-Type", "application/json")
 	request.Header.Set("X-API-KEY", att.Credentials.apiKey)
 
 	resp, err := client.Do(request)
 	if err != nil {
-		return nil, false, err
+		return nil, false, errors.Wrap(err, "failed to send http request")
 	}
 	if resp.StatusCode != http.StatusOK {
 		return nil, false, fmt.Errorf("request responded with code %d", resp.StatusCode)
@@ -69,15 +71,15 @@ func ResolveAttestationRequest(ctx context.Context, att *Attestation) ([]byte, b
 
 	err = decoder.Decode(&responseBody)
 	if err != nil {
-		return nil, false, err
+		return nil, false, errors.Wrap(err, "failed to decode response body")
 	}
 	if responseBody.Status != ValidResponseStatus {
 		return nil, false, nil
 	}
 
 	responseBytes, err := hex.DecodeString(strings.TrimPrefix(responseBody.ABIEncodedResponse, "0x"))
 	if err != nil {
-		return nil, false, err
+		return nil, false, errors.Wrap(err, "failed to decode ABI encoded response")
 	}
 
 	return responseBytes, true, nil

client/manager/queues.go

@@ -7,6 +7,7 @@ import (
 	"github.com/flare-foundation/fdc-client/client/config"
 	"github.com/flare-foundation/go-flare-common/pkg/logger"
 	"github.com/flare-foundation/go-flare-common/pkg/priority"
+	"github.com/pkg/errors"
 )
 
 type attestationQueue = priority.PriorityQueue[*attestation.Attestation, attestation.Weight]
@@ -28,7 +29,13 @@ func buildQueues(queuesConfigs config.Queues) attestationQueues {
 
 // handler handles dequeued attestation.
 func handler(ctx context.Context, at *attestation.Attestation) error {
-	return at.Handle(ctx)
+	err := at.Handle(ctx)
+	if err != nil {
+		wrapped := errors.Wrapf(err, "attestation request %s for round %d failed", at.Request.TypeAndSourceString(), at.RoundID)
+		logger.Info(wrapped.Error())
+		return wrapped
+	}
+	return nil
 }
 
 // discard discards requests that do not need to be handled.

client/round/round.go

@@ -155,7 +155,7 @@ func (r *Round) MerkleTree() (merkle.Tree, error) {
 	for i := range r.Attestations {
 		if r.Attestations[i].Consensus {
 			if r.Attestations[i].Status != attestation.Success {
-				return merkle.Tree{}, errors.Errorf("attestation %d in consensus but not confirmed", i)
+				return merkle.Tree{}, errors.Errorf("attestation %s, at index %d in consensus but not confirmed", r.Attestations[i].Request.TypeAndSourceString(), i)
 			}
 
 			hashes = append(hashes, r.Attestations[i].Hash)

client/utils/utils.go

@@ -1,5 +1,9 @@
 package utils
 
+import (
+	"bytes"
+)
+
 // prepend places the element at the beginning of the slice and moves the potentially replaced element to the end.
 func Prepend[T any](slice []T, element T) []T {
 	if len(slice) == 0 {
@@ -38,3 +42,7 @@ func Invert[K comparable, V comparable](m map[K]V) map[V]K {
 
 	return invertedMap
 }
+
+func Bytes32ToString(b [32]byte) string {
+	return string(bytes.Trim(b[:], "\x00"))
+}

go.mod

@@ -25,16 +25,13 @@ require (
 	github.com/bits-and-blooms/bitset v1.24.3 // indirect
 	github.com/buger/jsonparser v1.1.1 // indirect
 	github.com/cenkalti/backoff/v4 v4.3.0 // indirect
-	github.com/consensys/bavard v0.2.1 // indirect
 	github.com/consensys/gnark-crypto v0.19.2 // indirect
 	github.com/crate-crypto/go-eth-kzg v1.4.0 // indirect
 	github.com/crate-crypto/go-ipa v0.0.0-20240724233137-53bbb0ceb27a // indirect
-	github.com/crate-crypto/go-kzg-4844 v1.1.0 // indirect
 	github.com/davecgh/go-spew v1.1.1 // indirect
 	github.com/davidebianchi/gswagger v0.10.0 // indirect
 	github.com/deckarep/golang-set/v2 v2.7.0 // indirect
 	github.com/decred/dcrd/dcrec/secp256k1/v4 v4.4.0 // indirect
-	github.com/ethereum/c-kzg-4844 v1.0.3 // indirect
 	github.com/ethereum/c-kzg-4844/v2 v2.1.5 // indirect
 	github.com/ethereum/go-verkle v0.2.2 // indirect
 	github.com/fsnotify/fsnotify v1.8.0 // indirect
@@ -61,7 +58,6 @@ require (
 	github.com/mailru/easyjson v0.9.0 // indirect
 	github.com/mattn/go-sqlite3 v1.14.22 // indirect
 	github.com/mitchellh/mapstructure v1.5.0 // indirect
-	github.com/mmcloughlin/addchain v0.4.0 // indirect
 	github.com/mohae/deepcopy v0.0.0-20170929034955-c48cc78d4826 // indirect
 	github.com/perimeterx/marshmallow v1.1.5 // indirect
 	github.com/pmezard/go-difflib v1.0.0 // indirect
@@ -85,9 +81,9 @@ require (
 	golang.org/x/sys v0.37.0 // indirect
 	golang.org/x/text v0.30.0 // indirect
 	golang.org/x/time v0.9.0 // indirect
+	golang.org/x/tools/godoc v0.1.0-deprecated // indirect
 	gopkg.in/natefinch/lumberjack.v2 v2.2.1 // indirect
 	gopkg.in/yaml.v2 v2.4.0 // indirect
 	gopkg.in/yaml.v3 v3.0.1 // indirect
 	gorm.io/driver/mysql v1.5.7 // indirect
-	rsc.io/tmplfunc v0.0.3 // indirect
 )