From fe7ae1b8d556b0147a3107a4146ca52e367ffccd Mon Sep 17 00:00:00 2001 From: Bolek <1416262+bolekk@users.noreply.github.com> Date: Mon, 25 Sep 2023 06:46:27 -0700 Subject: [PATCH] [Functions] Minor logging improvements (#10774) --- core/services/gateway/handlers/functions/allowlist.go | 3 ++- core/services/ocr2/plugins/functions/reporting.go | 6 ++++++ core/services/ocr2/plugins/s4/plugin.go | 7 ++++--- core/services/ocr2/plugins/threshold/decryption_queue.go | 4 ++-- 4 files changed, 14 insertions(+), 6 deletions(-) diff --git a/core/services/gateway/handlers/functions/allowlist.go b/core/services/gateway/handlers/functions/allowlist.go index 19bc61aabad..0ee9b5bcfb9 100644 --- a/core/services/gateway/handlers/functions/allowlist.go +++ b/core/services/gateway/handlers/functions/allowlist.go @@ -2,6 +2,7 @@ package functions import ( "context" + "encoding/hex" "fmt" "math/big" "sync" @@ -177,7 +178,7 @@ func (a *onchainAllowlist) updateFromContractV1(ctx context.Context, blockNum *b if err != nil { return errors.Wrap(err, "unexpected error during functions_router.GetAllowListId") } - a.lggr.Debugw("successfully fetched allowlist route ID", "id", tosID) + a.lggr.Debugw("successfully fetched allowlist route ID", "id", hex.EncodeToString(tosID[:])) if tosID == [32]byte{} { return errors.New("allowlist route ID has not been set") } diff --git a/core/services/ocr2/plugins/functions/reporting.go b/core/services/ocr2/plugins/functions/reporting.go index 9f6c6848edf..f2e2f86aba2 100644 --- a/core/services/ocr2/plugins/functions/reporting.go +++ b/core/services/ocr2/plugins/functions/reporting.go @@ -62,6 +62,11 @@ var ( Help: "Metric to track number of reporting plugin Report calls", }, []string{"jobID"}) + promReportingPluginsReportNumObservations = promauto.NewGaugeVec(prometheus.GaugeOpts{ + Name: "functions_reporting_plugin_report_num_observations", + Help: "Metric to track number of observations available in the report phase", + }, []string{"jobID"}) + promReportingAcceptReports = promauto.NewCounterVec(prometheus.CounterOpts{ Name: "functions_reporting_plugin_accept", Help: "Metric to track number of accepting reports", @@ -265,6 +270,7 @@ func (r *functionsReporting) Report(ctx context.Context, ts types.ReportTimestam "oracleID": r.genericConfig.OracleID, "nObservations": len(obs), }) + promReportingPluginsReportNumObservations.WithLabelValues(r.jobID.String()).Set(float64(len(obs))) queryProto := &encoding.Query{} err := proto.Unmarshal(query, queryProto) diff --git a/core/services/ocr2/plugins/s4/plugin.go b/core/services/ocr2/plugins/s4/plugin.go index 0aca93e55e6..7e4b91be97e 100644 --- a/core/services/ocr2/plugins/s4/plugin.go +++ b/core/services/ocr2/plugins/s4/plugin.go @@ -226,9 +226,10 @@ func (c *plugin) Report(_ context.Context, ts types.ReportTimestamp, _ types.Que promReportingPluginsReportRowsCount.WithLabelValues(c.config.ProductName).Set(float64(len(reportRows))) c.logger.Debug("S4StorageReporting Report", commontypes.LogFields{ - "epoch": ts.Epoch, - "round": ts.Round, - "nReportRows": len(reportRows), + "epoch": ts.Epoch, + "round": ts.Round, + "nReportRows": len(reportRows), + "nObservations": len(aos), }) return true, report, nil diff --git a/core/services/ocr2/plugins/threshold/decryption_queue.go b/core/services/ocr2/plugins/threshold/decryption_queue.go index 1ffc63e5898..442fcffe8b4 100644 --- a/core/services/ocr2/plugins/threshold/decryption_queue.go +++ b/core/services/ocr2/plugins/threshold/decryption_queue.go @@ -148,7 +148,7 @@ func (dq *decryptionQueue) GetRequests(requestCountLimit int, totalBytesLimit in pendingRequest, exists := dq.pendingRequests[string(ciphertextId)] if !exists { - dq.lggr.Debugf("pending decryption request for ciphertextId %s expired", ciphertextId) + dq.lggr.Debugf("decryption request for ciphertextId %s already processed or expired", ciphertextId) indicesToRemove[i] = struct{}{} continue } @@ -232,7 +232,7 @@ func (dq *decryptionQueue) SetResult(ciphertextId decryptionPlugin.CiphertextId, // Cache plaintext result in completedRequests map for cacheTimeoutMs to account for delayed Decrypt() calls timer := time.AfterFunc(dq.completedRequestsCacheTimeout, func() { - dq.lggr.Debugf("expired decryption result for ciphertextId %s from completedRequests cache", ciphertextId) + dq.lggr.Debugf("removing completed decryption result for ciphertextId %s from cache", ciphertextId) dq.mu.Lock() delete(dq.completedRequests, string(ciphertextId)) dq.mu.Unlock()