tech/sendico
2
0
Fork 0
Code Issues 22 Pull Requests 1 Actions Packages Projects Releases Wiki Activity

fx/oracle logging

Browse Source
This commit is contained in:
Stephan D
2025-12-12 00:44:04 +01:00
parent 8b202e0c60
commit a5ad4f4c3c
2 changed files with 160 additions and 14 deletions
Download Patch File Download Diff File Expand all files Collapse all files

90
api/fx/oracle/internal/service/oracle/logging.go Normal file
View File

@@ -0,0 +1,90 @@
package oracle
import (
"strings"
fxv1 "github.com/tech/sendico/pkg/proto/common/fx/v1"
moneyv1 "github.com/tech/sendico/pkg/proto/common/money/v1"
tracev1 "github.com/tech/sendico/pkg/proto/common/trace/v1"
oraclev1 "github.com/tech/sendico/pkg/proto/oracle/v1"
"go.uber.org/zap"
)
func quoteRequestFields(req *oraclev1.GetQuoteRequest) []zap.Field {
if req == nil {
return nil
}
fields := requestMetaFields(req.GetMeta())
if pair := req.GetPair(); pair != nil {
if base := strings.TrimSpace(pair.GetBase()); base != "" {
fields = append(fields, zap.String("pair_base", base))
}
if quote := strings.TrimSpace(pair.GetQuote()); quote != "" {
fields = append(fields, zap.String("pair_quote", quote))
}
}
if side := req.GetSide(); side != fxv1.Side_SIDE_UNSPECIFIED {
fields = append(fields, zap.String("side", side.String()))
}
if req.GetFirm() {
fields = append(fields, zap.Bool("firm", req.GetFirm()))
}
if ttl := req.GetTtlMs(); ttl > 0 {
fields = append(fields, zap.Int64("ttl_ms", ttl))
}
if maxAge := req.GetMaxAgeMs(); maxAge > 0 {
fields = append(fields, zap.Int32("max_age_ms", maxAge))
}
if provider := strings.TrimSpace(req.GetPreferredProvider()); provider != "" {
fields = append(fields, zap.String("preferred_provider", provider))
}
fields = append(fields, moneyFields("base_amount", req.GetBaseAmount())...)
fields = append(fields, moneyFields("quote_amount", req.GetQuoteAmount())...)
return fields
}
func requestMetaFields(meta *oraclev1.RequestMeta) []zap.Field {
if meta == nil {
return nil
}
fields := make([]zap.Field, 0, 4)
if org := strings.TrimSpace(meta.GetOrganizationRef()); org != "" {
fields = append(fields, zap.String("organization_ref", org))
}
if tenant := strings.TrimSpace(meta.GetTenantRef()); tenant != "" {
fields = append(fields, zap.String("tenant_ref", tenant))
}
fields = append(fields, traceFields(meta.GetTrace())...)
return fields
}
func moneyFields(prefix string, money *moneyv1.Money) []zap.Field {
if money == nil {
return nil
}
fields := make([]zap.Field, 0, 2)
if amt := strings.TrimSpace(money.GetAmount()); amt != "" {
fields = append(fields, zap.String(prefix, amt))
}
if ccy := strings.TrimSpace(money.GetCurrency()); ccy != "" {
fields = append(fields, zap.String(prefix+"_currency", ccy))
}
return fields
}
func traceFields(trace *tracev1.TraceContext) []zap.Field {
if trace == nil {
return nil
}
fields := make([]zap.Field, 0, 3)
if ref := strings.TrimSpace(trace.GetTraceRef()); ref != "" {
fields = append(fields, zap.String("trace_ref", ref))
}
if idem := strings.TrimSpace(trace.GetIdempotencyKey()); idem != "" {
fields = append(fields, zap.String("idempotency_key", idem))
}
if req := strings.TrimSpace(trace.GetRequestRef()); req != "" {
fields = append(fields, zap.String("request_ref", req))
}
return fields
}

84
api/fx/oracle/internal/service/oracle/service.go
View File

@@ -101,22 +101,27 @@ func (s *Service) getQuoteResponder(ctx context.Context, req *oraclev1.GetQuoteR
if req == nil {
req = &oraclev1.GetQuoteRequest{}
}
s.logger.Debug("Handling GetQuote", zap.String("pair", req.GetPair().GetBase()+"/"+req.GetPair().GetQuote()), zap.Bool("firm", req.GetFirm()))
logger := s.logger.With(quoteRequestFields(req)...)
logger.Debug("Handling GetQuote")
if req.GetSide() == fxv1.Side_SIDE_UNSPECIFIED {
logger.Warn("GetQuote invalid: side missing")
return gsresponse.InvalidArgument[oraclev1.GetQuoteResponse](s.logger, mservice.FXOracle, errSideRequired)
}
if req.GetBaseAmount() != nil && req.GetQuoteAmount() != nil {
logger.Warn("GetQuote invalid: both base_amount and quote_amount provided")
return gsresponse.InvalidArgument[oraclev1.GetQuoteResponse](s.logger, mservice.FXOracle, errAmountsMutuallyExclusive)
}
if req.GetBaseAmount() == nil && req.GetQuoteAmount() == nil {
logger.Warn("GetQuote invalid: amount missing")
return gsresponse.InvalidArgument[oraclev1.GetQuoteResponse](s.logger, mservice.FXOracle, errAmountRequired)
}
if err := s.pingStorage(ctx); err != nil {
s.logger.Warn("Storage unavailable during GetQuote", zap.Error(err))
logger.Warn("Storage unavailable during GetQuote", zap.Error(err))
return gsresponse.Unavailable[oraclev1.GetQuoteResponse](s.logger, mservice.FXOracle, err)
}
pairMsg := req.GetPair()
if pairMsg == nil || strings.TrimSpace(pairMsg.GetBase()) == "" || strings.TrimSpace(pairMsg.GetQuote()) == "" {
logger.Warn("GetQuote invalid: pair missing")
return gsresponse.InvalidArgument[oraclev1.GetQuoteResponse](s.logger, mservice.FXOracle, errEmptyRequest)
}
pairKey := model.CurrencyPair{Base: strings.ToUpper(pairMsg.GetBase()), Quote: strings.ToUpper(pairMsg.GetQuote())}
@@ -125,8 +130,10 @@ func (s *Service) getQuoteResponder(ctx context.Context, req *oraclev1.GetQuoteR
if err != nil {
switch {
case errors.Is(err, merrors.ErrNoData):
logger.Warn("pair not supported", zap.String("pair", pairKey.Base+"/"+pairKey.Quote))
return gsresponse.InvalidArgument[oraclev1.GetQuoteResponse](s.logger, mservice.FXOracle, merrors.InvalidArgument("pair_not_supported"))
default:
logger.Warn("GetQuote failed to load pair", zap.Error(err))
return gsresponse.Internal[oraclev1.GetQuoteResponse](s.logger, mservice.FXOracle, err)
}
}
@@ -143,8 +150,10 @@ func (s *Service) getQuoteResponder(ctx context.Context, req *oraclev1.GetQuoteR
if err != nil {
switch {
case errors.Is(err, merrors.ErrNoData):
logger.Warn("rate not found", zap.String("pair", pairKey.Base+"/"+pairKey.Quote), zap.String("provider", provider))
return gsresponse.FailedPrecondition[oraclev1.GetQuoteResponse](s.logger, mservice.FXOracle, "rate_not_found", err)
default:
logger.Warn("GetQuote failed to load rate", zap.Error(err), zap.String("pair", pairKey.Base+"/"+pairKey.Quote), zap.String("provider", provider))
return gsresponse.Internal[oraclev1.GetQuoteResponse](s.logger, mservice.FXOracle, err)
}
}
@@ -153,27 +162,31 @@ func (s *Service) getQuoteResponder(ctx context.Context, req *oraclev1.GetQuoteR
if maxAge := req.GetMaxAgeMs(); maxAge > 0 {
age := now.UnixMilli() - rate.AsOfUnixMs
if age > int64(maxAge) {
s.logger.Warn("Rate snapshot stale", zap.Int64("age_ms", age), zap.Int32("max_age_ms", req.GetMaxAgeMs()), zap.String("pair", pairKey.Base+"/"+pairKey.Quote), zap.String("provider", provider))
logger.Warn("Rate snapshot stale", zap.Int64("age_ms", age), zap.Int32("max_age_ms", req.GetMaxAgeMs()), zap.String("pair", pairKey.Base+"/"+pairKey.Quote), zap.String("provider", provider))
return gsresponse.FailedPrecondition[oraclev1.GetQuoteResponse](s.logger, mservice.FXOracle, "stale_rate", merrors.InvalidArgument("rate older than allowed window"))
}
}
comp, err := newQuoteComputation(pair, rate, req.GetSide(), provider)
if err != nil {
logger.Warn("GetQuote invalid input", zap.Error(err))
return gsresponse.InvalidArgument[oraclev1.GetQuoteResponse](s.logger, mservice.FXOracle, err)
}
if req.GetBaseAmount() != nil {
if err := comp.withBaseInput(req.GetBaseAmount()); err != nil {
logger.Warn("GetQuote invalid base input", zap.Error(err))
return gsresponse.InvalidArgument[oraclev1.GetQuoteResponse](s.logger, mservice.FXOracle, err)
}
} else if req.GetQuoteAmount() != nil {
if err := comp.withQuoteInput(req.GetQuoteAmount()); err != nil {
logger.Warn("GetQuote invalid quote input", zap.Error(err))
return gsresponse.InvalidArgument[oraclev1.GetQuoteResponse](s.logger, mservice.FXOracle, err)
}
}
if err := comp.compute(); err != nil {
logger.Warn("GetQuote computation failed", zap.Error(err))
return gsresponse.Internal[oraclev1.GetQuoteResponse](s.logger, mservice.FXOracle, err)
}
@@ -195,12 +208,14 @@ func (s *Service) getQuoteResponder(ctx context.Context, req *oraclev1.GetQuoteR
if err := s.storage.Quotes().Issue(ctx, quoteModel); err != nil {
switch {
case errors.Is(err, merrors.ErrDataConflict):
logger.Warn("GetQuote conflict issuing firm quote", zap.Error(err), zap.String("quote_ref", quoteModel.QuoteRef))
return gsresponse.Conflict[oraclev1.GetQuoteResponse](s.logger, mservice.FXOracle, err)
default:
logger.Warn("GetQuote failed to issue firm quote", zap.Error(err), zap.String("quote_ref", quoteModel.QuoteRef))
return gsresponse.Internal[oraclev1.GetQuoteResponse](s.logger, mservice.FXOracle, err)
}
}
s.logger.Info("Firm quote stored", zap.String("quote_ref", quoteModel.QuoteRef), zap.String("pair", pairKey.Base+"/"+pairKey.Quote), zap.String("provider", quoteModel.Provider), zap.Int64("expires_at_ms", quoteModel.ExpiresAtUnixMs))
logger.Info("Firm quote stored", zap.String("quote_ref", quoteModel.QuoteRef), zap.String("pair", pairKey.Base+"/"+pairKey.Quote), zap.String("provider", quoteModel.Provider), zap.Int64("expires_at_ms", quoteModel.ExpiresAtUnixMs))
}
resp := &oraclev1.GetQuoteResponse{
@@ -214,18 +229,24 @@ func (s *Service) validateQuoteResponder(ctx context.Context, req *oraclev1.Vali
if req == nil {
req = &oraclev1.ValidateQuoteRequest{}
}
s.logger.Debug("Handling ValidateQuote", zap.String("quote_ref", req.GetQuoteRef()))
logger := s.logger.With(requestMetaFields(req.GetMeta())...)
if ref := strings.TrimSpace(req.GetQuoteRef()); ref != "" {
logger = logger.With(zap.String("quote_ref", ref))
}
logger.Debug("Handling ValidateQuote")
if req.GetQuoteRef() == "" {
logger.Warn("ValidateQuote invalid: quote_ref missing")
return gsresponse.InvalidArgument[oraclev1.ValidateQuoteResponse](s.logger, mservice.FXOracle, errQuoteRefRequired)
}
if err := s.pingStorage(ctx); err != nil {
s.logger.Warn("Storage unavailable during ValidateQuote", zap.Error(err))
logger.Warn("Storage unavailable during ValidateQuote", zap.Error(err))
return gsresponse.Unavailable[oraclev1.ValidateQuoteResponse](s.logger, mservice.FXOracle, err)
}
quote, err := s.storage.Quotes().GetByRef(ctx, req.GetQuoteRef())
if err != nil {
switch {
case errors.Is(err, merrors.ErrNoData):
logger.Warn("ValidateQuote: quote not found", zap.String("quote_ref", req.GetQuoteRef()))
resp := &oraclev1.ValidateQuoteResponse{
Meta: buildResponseMeta(req.GetMeta()),
Quote: nil,
@@ -234,6 +255,7 @@ func (s *Service) validateQuoteResponder(ctx context.Context, req *oraclev1.Vali
}
return gsresponse.Success(resp)
default:
logger.Warn("ValidateQuote failed", zap.Error(err))
return gsresponse.Internal[oraclev1.ValidateQuoteResponse](s.logger, mservice.FXOracle, err)
}
}
@@ -255,6 +277,11 @@ func (s *Service) validateQuoteResponder(ctx context.Context, req *oraclev1.Vali
Valid: valid,
Reason: reason,
}
if !valid {
logger.Info("ValidateQuote invalid", zap.String("reason", reason), zap.Bool("firm", quote.Firm))
} else {
logger.Debug("ValidateQuote valid", zap.Bool("firm", quote.Firm))
}
return gsresponse.Success(resp)
}
@@ -262,29 +289,43 @@ func (s *Service) consumeQuoteResponder(ctx context.Context, req *oraclev1.Consu
if req == nil {
req = &oraclev1.ConsumeQuoteRequest{}
}
s.logger.Debug("Handling ConsumeQuote", zap.String("quote_ref", req.GetQuoteRef()), zap.String("ledger_txn_ref", req.GetLedgerTxnRef()))
logger := s.logger.With(requestMetaFields(req.GetMeta())...)
if ref := strings.TrimSpace(req.GetQuoteRef()); ref != "" {
logger = logger.With(zap.String("quote_ref", ref))
}
if ledger := strings.TrimSpace(req.GetLedgerTxnRef()); ledger != "" {
logger = logger.With(zap.String("ledger_txn_ref", ledger))
}
logger.Debug("Handling ConsumeQuote")
if req.GetQuoteRef() == "" {
logger.Warn("ConsumeQuote invalid: quote_ref missing")
return gsresponse.InvalidArgument[oraclev1.ConsumeQuoteResponse](s.logger, mservice.FXOracle, errQuoteRefRequired)
}
if req.GetLedgerTxnRef() == "" {
logger.Warn("ConsumeQuote invalid: ledger_txn_ref missing")
return gsresponse.InvalidArgument[oraclev1.ConsumeQuoteResponse](s.logger, mservice.FXOracle, errLedgerTxnRefRequired)
}
if err := s.pingStorage(ctx); err != nil {
s.logger.Warn("Storage unavailable during ConsumeQuote", zap.Error(err))
logger.Warn("Storage unavailable during ConsumeQuote", zap.Error(err))
return gsresponse.Unavailable[oraclev1.ConsumeQuoteResponse](s.logger, mservice.FXOracle, err)
}
_, err := s.storage.Quotes().Consume(ctx, req.GetQuoteRef(), req.GetLedgerTxnRef(), time.Now())
if err != nil {
switch {
case errors.Is(err, storage.ErrQuoteExpired):
logger.Warn("ConsumeQuote failed: expired")
return gsresponse.FailedPrecondition[oraclev1.ConsumeQuoteResponse](s.logger, mservice.FXOracle, "expired", err)
case errors.Is(err, storage.ErrQuoteConsumed):
logger.Warn("ConsumeQuote failed: already consumed")
return gsresponse.FailedPrecondition[oraclev1.ConsumeQuoteResponse](s.logger, mservice.FXOracle, "consumed", err)
case errors.Is(err, storage.ErrQuoteNotFirm):
logger.Warn("ConsumeQuote failed: quote not firm")
return gsresponse.FailedPrecondition[oraclev1.ConsumeQuoteResponse](s.logger, mservice.FXOracle, "not_firm", err)
case errors.Is(err, merrors.ErrNoData):
logger.Warn("ConsumeQuote failed: quote not found")
return gsresponse.NotFound[oraclev1.ConsumeQuoteResponse](s.logger, mservice.FXOracle, err)
default:
logger.Warn("ConsumeQuote failed", zap.Error(err))
return gsresponse.Internal[oraclev1.ConsumeQuoteResponse](s.logger, mservice.FXOracle, err)
}
}
@@ -294,7 +335,7 @@ func (s *Service) consumeQuoteResponder(ctx context.Context, req *oraclev1.Consu
Consumed: true,
Reason: "consumed",
}
s.logger.Debug("Quote consumed", zap.String("quote_ref", req.GetQuoteRef()), zap.String("ledger_txn_ref", req.GetLedgerTxnRef()))
logger.Info("Quote consumed")
return gsresponse.Success(resp)
}
@@ -302,13 +343,21 @@ func (s *Service) latestRateResponder(ctx context.Context, req *oraclev1.LatestR
if req == nil {
req = &oraclev1.LatestRateRequest{}
}
s.logger.Debug("Handling LatestRate", zap.String("pair", req.GetPair().GetBase()+"/"+req.GetPair().GetQuote()))
logger := s.logger.With(requestMetaFields(req.GetMeta())...)
if pair := req.GetPair(); pair != nil {
logger = logger.With(zap.String("pair_base", strings.TrimSpace(pair.GetBase())), zap.String("pair_quote", strings.TrimSpace(pair.GetQuote())))
}
if provider := strings.TrimSpace(req.GetProvider()); provider != "" {
logger = logger.With(zap.String("provider", provider))
}
logger.Debug("Handling LatestRate")
if err := s.pingStorage(ctx); err != nil {
s.logger.Warn("Storage unavailable during LatestRate", zap.Error(err))
logger.Warn("Storage unavailable during LatestRate", zap.Error(err))
return gsresponse.Unavailable[oraclev1.LatestRateResponse](s.logger, mservice.FXOracle, err)
}
pairMsg := req.GetPair()
if pairMsg == nil || strings.TrimSpace(pairMsg.GetBase()) == "" || strings.TrimSpace(pairMsg.GetQuote()) == "" {
logger.Warn("LatestRate invalid: pair missing")
return gsresponse.InvalidArgument[oraclev1.LatestRateResponse](s.logger, mservice.FXOracle, errEmptyRequest)
}
pair := model.CurrencyPair{Base: strings.ToUpper(pairMsg.GetBase()), Quote: strings.ToUpper(pairMsg.GetQuote())}
@@ -317,8 +366,10 @@ func (s *Service) latestRateResponder(ctx context.Context, req *oraclev1.LatestR
if err != nil {
switch {
case errors.Is(err, merrors.ErrNoData):
logger.Warn("LatestRate pair not found")
return gsresponse.NotFound[oraclev1.LatestRateResponse](s.logger, mservice.FXOracle, err)
default:
logger.Warn("LatestRate failed to load pair", zap.Error(err))
return gsresponse.Internal[oraclev1.LatestRateResponse](s.logger, mservice.FXOracle, err)
}
}
@@ -335,8 +386,10 @@ func (s *Service) latestRateResponder(ctx context.Context, req *oraclev1.LatestR
if err != nil {
switch {
case errors.Is(err, merrors.ErrNoData):
logger.Warn("LatestRate not found", zap.String("provider", provider))
return gsresponse.NotFound[oraclev1.LatestRateResponse](s.logger, mservice.FXOracle, err)
default:
logger.Warn("LatestRate failed", zap.Error(err))
return gsresponse.Internal[oraclev1.LatestRateResponse](s.logger, mservice.FXOracle, err)
}
}
@@ -345,6 +398,7 @@ func (s *Service) latestRateResponder(ctx context.Context, req *oraclev1.LatestR
Meta: buildResponseMeta(req.GetMeta()),
Rate: rateModelToProto(rate),
}
logger.Debug("LatestRate succeeded", zap.String("provider", provider), zap.Int64("asof_unix_ms", rate.AsOfUnixMs))
return gsresponse.Success(resp)
}
@@ -352,13 +406,15 @@ func (s *Service) listPairsResponder(ctx context.Context, req *oraclev1.ListPair
if req == nil {
req = &oraclev1.ListPairsRequest{}
}
s.logger.Debug("Handling ListPairs")
logger := s.logger.With(requestMetaFields(req.GetMeta())...)
logger.Debug("Handling ListPairs")
if err := s.pingStorage(ctx); err != nil {
s.logger.Warn("Storage unavailable during ListPairs", zap.Error(err))
logger.Warn("Storage unavailable during ListPairs", zap.Error(err))
return gsresponse.Unavailable[oraclev1.ListPairsResponse](s.logger, mservice.FXOracle, err)
}
pairs, err := s.storage.Pairs().ListEnabled(ctx)
if err != nil {
logger.Warn("ListPairs failed", zap.Error(err))
return gsresponse.Internal[oraclev1.ListPairsResponse](s.logger, mservice.FXOracle, err)
}
result := make([]*oraclev1.PairMeta, 0, len(pairs))
@@ -369,7 +425,7 @@ func (s *Service) listPairsResponder(ctx context.Context, req *oraclev1.ListPair
Meta: buildResponseMeta(req.GetMeta()),
Pairs: result,
}
s.logger.Debug("ListPairs returning metadata", zap.Int("pairs", len(resp.GetPairs())))
logger.Debug("ListPairs returning metadata", zap.Int("pairs", len(resp.GetPairs())))
return gsresponse.Success(resp)
}