Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 5 additions & 0 deletions .changeset/vault-improve-logging.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,5 @@
---
"chainlink": patch
---

Add structured vault request ID logging across capability, OCR plugin, and workflow secrets paths. #internal
25 changes: 7 additions & 18 deletions core/capabilities/vault/capability.go
Original file line number Diff line number Diff line change
Expand Up @@ -121,20 +121,9 @@ func (s *Capability) Execute(ctx context.Context, request capabilities.Capabilit
}
}

// We need to generate sufficiently unique IDs accounting for two cases:
// 1. called during the subscription phase, in which case the executionID will be blank

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can you also move this comment to the request_id file?

// 2. called during execution, in which case it'll be present.
// The reference ID is unique per phase, so we need to differentiate when generating
// an ID.
md := request.Metadata
phaseOrExecution := md.WorkflowExecutionID
if phaseOrExecution == "" {
phaseOrExecution = "subscription"
}
id := fmt.Sprintf("%s::%s::%s", md.WorkflowID, phaseOrExecution, md.ReferenceID)

// Workflow DON reads populate secret identifiers explicitly; OCR paths do not rely on legacy
// top-level protobuf identity fields.
id := vaultutils.BuildWorkflowGetSecretsRequestID(md)
s.lggr.Debugw("received workflow get secrets request", "requestID", id, "request", r.String())

resp, err := s.handleRequest(ctx, id, r)
if err != nil {
Expand All @@ -160,7 +149,7 @@ func (s *Capability) Execute(ctx context.Context, request capabilities.Capabilit
}

func (s *Capability) CreateSecrets(ctx context.Context, request *vaultcommon.CreateSecretsRequest) (*vaulttypes.Response, error) {
s.lggr.Debugw("received create secrets request", "request", request.String())
s.lggr.Debugw("received create secrets request", "requestID", request.RequestId, "request", request.String())
if err := validateEncryptedSecretsUniformOwners(request.EncryptedSecrets); err != nil {
return nil, err
}
Expand All @@ -173,7 +162,7 @@ func (s *Capability) CreateSecrets(ctx context.Context, request *vaultcommon.Cre
}

func (s *Capability) UpdateSecrets(ctx context.Context, request *vaultcommon.UpdateSecretsRequest) (*vaulttypes.Response, error) {
s.lggr.Debugw("received update secrets request", "request", request.String())
s.lggr.Debugw("received update secrets request", "requestID", request.RequestId, "request", request.String())
if err := validateEncryptedSecretsUniformOwners(request.EncryptedSecrets); err != nil {
return nil, err
}
Expand All @@ -186,7 +175,7 @@ func (s *Capability) UpdateSecrets(ctx context.Context, request *vaultcommon.Upd
}

func (s *Capability) DeleteSecrets(ctx context.Context, request *vaultcommon.DeleteSecretsRequest) (*vaulttypes.Response, error) {
s.lggr.Debugw("received delete secrets request", "request", request.String())
s.lggr.Debugw("received delete secrets request", "requestID", request.RequestId, "request", request.String())
err := s.ValidateDeleteSecretsRequest(ctx, request)
if err != nil {
s.lggr.Debugw("failed validation checks", "requestID", request.RequestId, "request", request.String(), "err", err)
Expand All @@ -200,7 +189,7 @@ func (s *Capability) DeleteSecrets(ctx context.Context, request *vaultcommon.Del
}

func (s *Capability) GetSecrets(ctx context.Context, requestID string, request *vaultcommon.GetSecretsRequest) (*vaulttypes.Response, error) {
s.lggr.Debugw("received get secrets request", "request", request.String())
s.lggr.Debugw("received get secrets request", "requestID", requestID, "request", request.String())
if err := s.ValidateGetSecretsRequest(ctx, request); err != nil {
s.lggr.Debugw("failed validation checks", "requestID", requestID, "request", request.String(), "err", err)
return nil, err
Expand All @@ -211,7 +200,7 @@ func (s *Capability) GetSecrets(ctx context.Context, requestID string, request *
}

func (s *Capability) ListSecretIdentifiers(ctx context.Context, request *vaultcommon.ListSecretIdentifiersRequest) (*vaulttypes.Response, error) {
s.lggr.Debugw("received list secret identifiers request", "request", request.String())
s.lggr.Debugw("received list secret identifiers request", "requestID", request.RequestId, "request", request.String())
err := s.ValidateListSecretIdentifiersRequest(ctx, request)
if err != nil {
s.lggr.Debugw("failed validation checks", "requestID", request.RequestId, "request", request.String(), "err", err)
Expand Down
30 changes: 25 additions & 5 deletions core/capabilities/vault/capability_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@ import (
"github.com/smartcontractkit/chainlink-common/pkg/settings/limits"
coreCapabilities "github.com/smartcontractkit/chainlink/v2/core/capabilities"
"github.com/smartcontractkit/chainlink/v2/core/capabilities/vault/vaulttypes"
"github.com/smartcontractkit/chainlink/v2/core/capabilities/vault/vaultutils"
"github.com/smartcontractkit/chainlink/v2/core/logger"
)

Expand Down Expand Up @@ -52,7 +53,11 @@ func TestCapability_CapabilityCall(t *testing.T) {
workflowExecutionID := "test-workflow-execution-id"
referenceID := "test-reference-id"

requestID := fmt.Sprintf("%s::%s::%s", workflowID, workflowExecutionID, referenceID)
requestID := vaultutils.BuildWorkflowGetSecretsRequestID(capabilities.RequestMetadata{
WorkflowID: workflowID,
WorkflowExecutionID: workflowExecutionID,
ReferenceID: referenceID,
})

sid := &vault.SecretIdentifier{
Key: "Foo",
Expand Down Expand Up @@ -148,7 +153,10 @@ func TestCapability_CapabilityCall_DuringSubscriptionPhase(t *testing.T) {
workflowID := "test-workflow-id"
referenceID := "0"

requestID := fmt.Sprintf("%s::%s::%s", workflowID, "subscription", referenceID)
requestID := vaultutils.BuildWorkflowGetSecretsRequestID(capabilities.RequestMetadata{
WorkflowID: workflowID,
ReferenceID: referenceID,
})

sid := &vault.SecretIdentifier{
Key: "Foo",
Expand Down Expand Up @@ -463,7 +471,11 @@ func TestCapability_CapabilityCall_SecretIdentifierOwnerMismatch(t *testing.T) {
require.NoError(t, err)
servicetest.Run(t, capability)

requestID := fmt.Sprintf("%s::%s::%s", "wf-id", "exec-id", "ref-id")
requestID := vaultutils.BuildWorkflowGetSecretsRequestID(capabilities.RequestMetadata{
WorkflowID: "wf-id",
WorkflowExecutionID: "exec-id",
ReferenceID: "ref-id",
})

reqs := []*vault.SecretRequest{}
for _, s := range tc.secretOwners {
Expand Down Expand Up @@ -809,7 +821,11 @@ func TestCapability_CapabilityCall_ReturnsIncorrectType(t *testing.T) {
workflowExecutionID := "test-workflow-execution-id"
referenceID := "test-reference-id"

requestID := fmt.Sprintf("%s::%s::%s", workflowID, workflowExecutionID, referenceID)
requestID := vaultutils.BuildWorkflowGetSecretsRequestID(capabilities.RequestMetadata{
WorkflowID: workflowID,
WorkflowExecutionID: workflowExecutionID,
ReferenceID: referenceID,
})

sid := &vault.SecretIdentifier{
Key: "Foo",
Expand Down Expand Up @@ -883,7 +899,11 @@ func TestCapability_CapabilityCall_TimeOut(t *testing.T) {
workflowExecutionID := "test-workflow-execution-id"
referenceID := "test-reference-id"

requestID := fmt.Sprintf("%s::%s::%s", workflowID, workflowExecutionID, referenceID)
requestID := vaultutils.BuildWorkflowGetSecretsRequestID(capabilities.RequestMetadata{
WorkflowID: workflowID,
WorkflowExecutionID: workflowExecutionID,
ReferenceID: referenceID,
})

sid := &vault.SecretIdentifier{
Key: "Foo",
Expand Down
13 changes: 9 additions & 4 deletions core/capabilities/vault/gw_handler.go
Original file line number Diff line number Diff line change
Expand Up @@ -173,8 +173,13 @@ func (h *GatewayHandler) Methods() []string {
return vaulttypes.Methods
}

func (h *GatewayHandler) requestLogger(req *jsonrpc.Request[json.RawMessage], gatewayID string) logger.Logger {
return h.lggr.With("requestID", req.ID, "method", req.Method, "gatewayID", gatewayID)
}

func (h *GatewayHandler) HandleGatewayMessage(ctx context.Context, gatewayID string, req *jsonrpc.Request[json.RawMessage]) (err error) {
h.lggr.Debugw("received message from gateway", "gatewayID", gatewayID, "req", req, "requestID", req.ID)
reqLggr := h.requestLogger(req, gatewayID)
reqLggr.Debugw("received message from gateway", "req", req)

var response *jsonrpc.Response[json.RawMessage]
var authResult *AuthResult
Expand Down Expand Up @@ -219,11 +224,11 @@ func (h *GatewayHandler) HandleGatewayMessage(ctx context.Context, gatewayID str
}

if err = h.gatewayConnector.SendToGateway(ctx, gatewayID, response); err != nil {
h.lggr.Errorw("Failed to send message to gateway", "gatewayID", gatewayID, "error", err)
reqLggr.Errorw("Failed to send message to gateway", "error", err)
return err
}

h.lggr.Infow("Sent message to gateway", "gatewayID", gatewayID, "resp", response, "requestID", req.ID)
reqLggr.Infow("Sent message to gateway", "resp", response)
h.metrics.requestSuccess.Add(ctx, 1, metric.WithAttributes(
attribute.String("gateway_id", gatewayID),
))
Expand Down Expand Up @@ -387,7 +392,7 @@ func (h *GatewayHandler) errorResponse(
errorCode api.ErrorCode,
err error,
) *jsonrpc.Response[json.RawMessage] {
h.lggr.Errorw("gateway handler error response", "gatewayID", gatewayID, "requestID", req.ID, "method", req.Method, "errorCode", errorCode, "error", err)
h.requestLogger(req, gatewayID).Errorw("gateway handler error response", "errorCode", errorCode, "error", err)
h.metrics.requestInternalError.Add(ctx, 1, metric.WithAttributes(
attribute.String("gateway_id", gatewayID),
attribute.String("error", errorCode.String()),
Expand Down
25 changes: 25 additions & 0 deletions core/capabilities/vault/vaultutils/request_id.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,25 @@
package vaultutils

import (
"fmt"

"github.com/smartcontractkit/chainlink-common/pkg/capabilities"
)

const subscriptionPhaseKey = "subscription"

// BuildWorkflowGetSecretsRequestID returns the pending-queue / OCR request ID for a
// workflow GetSecrets call. This is the only place this format should be defined.
//
// We need to generate sufficiently unique IDs accounting for two cases:
// 1. called during the subscription phase, in which case the executionID will be blank
// 2. called during execution, in which case it'll be present.
// The reference ID is unique per phase, so we need to differentiate when generating
// an ID.
func BuildWorkflowGetSecretsRequestID(md capabilities.RequestMetadata) string {
phaseOrExecution := md.WorkflowExecutionID
if phaseOrExecution == "" {
phaseOrExecution = subscriptionPhaseKey
}
return fmt.Sprintf("%s::%s::%s", md.WorkflowID, phaseOrExecution, md.ReferenceID)
}
52 changes: 52 additions & 0 deletions core/capabilities/vault/vaultutils/request_id_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,52 @@
package vaultutils

import (
"testing"

"github.com/stretchr/testify/assert"

"github.com/smartcontractkit/chainlink-common/pkg/capabilities"
)

func TestBuildWorkflowGetSecretsRequestID(t *testing.T) {
t.Parallel()

tests := []struct {
name string
md capabilities.RequestMetadata
want string
}{
{
name: "execution path",
md: capabilities.RequestMetadata{
WorkflowID: "wf-1",
WorkflowExecutionID: "abc123sha",
ReferenceID: "42",
},
want: "wf-1::abc123sha::42",
},
{
name: "subscription path",
md: capabilities.RequestMetadata{
WorkflowID: "wf-1",
ReferenceID: "7",
},
want: "wf-1::subscription::7",
},
{
name: "gate off empty workflow ID",
md: capabilities.RequestMetadata{
WorkflowExecutionID: "abc123sha",
ReferenceID: "42",
},
want: "::abc123sha::42",
},
}

for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
t.Parallel()
assert.Equal(t, tt.want, BuildWorkflowGetSecretsRequestID(tt.md))
})
}
}
Loading
Loading