better logging #267

Merged
tech merged 1 commits from tg-266 into main 2026-01-18 12:11:42 +00:00
8 changed files with 113 additions and 38 deletions

View File

@@ -22,7 +22,7 @@ require (
require ( require (
github.com/Microsoft/go-winio v0.6.2 // indirect github.com/Microsoft/go-winio v0.6.2 // indirect
github.com/ProjectZKM/Ziren/crates/go-runtime/zkvm_runtime v0.0.0-20260116123424-9c8b2bad3688 // indirect github.com/ProjectZKM/Ziren/crates/go-runtime/zkvm_runtime v0.0.0-20260118001747-ff01f1c4e24d // indirect
github.com/beorn7/perks v1.0.1 // indirect github.com/beorn7/perks v1.0.1 // indirect
github.com/bits-and-blooms/bitset v1.24.4 // indirect github.com/bits-and-blooms/bitset v1.24.4 // indirect
github.com/bmatcuk/doublestar/v4 v4.9.2 // indirect github.com/bmatcuk/doublestar/v4 v4.9.2 // indirect

View File

@@ -6,8 +6,8 @@ github.com/DataDog/zstd v1.4.5 h1:EndNeuB0l9syBZhut0wns3gV1hL8zX8LIu6ZiVHWLIQ=
github.com/DataDog/zstd v1.4.5/go.mod h1:1jcaCB/ufaK+sKp1NBhlGmpz41jOoPQ35bpF36t7BBo= github.com/DataDog/zstd v1.4.5/go.mod h1:1jcaCB/ufaK+sKp1NBhlGmpz41jOoPQ35bpF36t7BBo=
github.com/Microsoft/go-winio v0.6.2 h1:F2VQgta7ecxGYO8k3ZZz3RS8fVIXVxONVUPlNERoyfY= github.com/Microsoft/go-winio v0.6.2 h1:F2VQgta7ecxGYO8k3ZZz3RS8fVIXVxONVUPlNERoyfY=
github.com/Microsoft/go-winio v0.6.2/go.mod h1:yd8OoFMLzJbo9gZq8j5qaps8bJ9aShtEA8Ipt1oGCvU= github.com/Microsoft/go-winio v0.6.2/go.mod h1:yd8OoFMLzJbo9gZq8j5qaps8bJ9aShtEA8Ipt1oGCvU=
github.com/ProjectZKM/Ziren/crates/go-runtime/zkvm_runtime v0.0.0-20260116123424-9c8b2bad3688 h1:heyVIwznmKcWu1dhijYnRnHTvRzVgWduNlLcRXFVxP8= github.com/ProjectZKM/Ziren/crates/go-runtime/zkvm_runtime v0.0.0-20260118001747-ff01f1c4e24d h1:xetq9B0q0HG5s4NOlR4T7oOltvrV7FhjAru+qcKcIhI=
github.com/ProjectZKM/Ziren/crates/go-runtime/zkvm_runtime v0.0.0-20260116123424-9c8b2bad3688/go.mod h1:ioLG6R+5bUSO1oeGSDxOV3FADARuMoytZCSX6MEMQkI= github.com/ProjectZKM/Ziren/crates/go-runtime/zkvm_runtime v0.0.0-20260118001747-ff01f1c4e24d/go.mod h1:ioLG6R+5bUSO1oeGSDxOV3FADARuMoytZCSX6MEMQkI=
github.com/VictoriaMetrics/fastcache v1.13.0 h1:AW4mheMR5Vd9FkAPUv+NH6Nhw+fmbTMGMsNAoA/+4G0= github.com/VictoriaMetrics/fastcache v1.13.0 h1:AW4mheMR5Vd9FkAPUv+NH6Nhw+fmbTMGMsNAoA/+4G0=
github.com/VictoriaMetrics/fastcache v1.13.0/go.mod h1:hHXhl4DA2fTL2HTZDJFXWgW0LNjo6B+4aj2Wmng3TjU= github.com/VictoriaMetrics/fastcache v1.13.0/go.mod h1:hHXhl4DA2fTL2HTZDJFXWgW0LNjo6B+4aj2Wmng3TjU=
github.com/beorn7/perks v1.0.1 h1:VlbKKnNfV8bJzeqoa4cOKqO6bYr3WgKZxO8Z16+hsOM= github.com/beorn7/perks v1.0.1 h1:VlbKKnNfV8bJzeqoa4cOKqO6bYr3WgKZxO8Z16+hsOM=

View File

@@ -2,6 +2,7 @@ package gateway
import ( import (
"context" "context"
"errors"
"os" "os"
"strings" "strings"
"sync" "sync"
@@ -20,9 +21,9 @@ import (
"github.com/tech/sendico/pkg/mlogger" "github.com/tech/sendico/pkg/mlogger"
"github.com/tech/sendico/pkg/model" "github.com/tech/sendico/pkg/model"
"github.com/tech/sendico/pkg/mservice" "github.com/tech/sendico/pkg/mservice"
connectorv1 "github.com/tech/sendico/pkg/proto/connector/v1"
paymenttypes "github.com/tech/sendico/pkg/payments/types" paymenttypes "github.com/tech/sendico/pkg/payments/types"
moneyv1 "github.com/tech/sendico/pkg/proto/common/money/v1" moneyv1 "github.com/tech/sendico/pkg/proto/common/money/v1"
connectorv1 "github.com/tech/sendico/pkg/proto/connector/v1"
chainv1 "github.com/tech/sendico/pkg/proto/gateway/chain/v1" chainv1 "github.com/tech/sendico/pkg/proto/gateway/chain/v1"
"github.com/tech/sendico/pkg/server/grpcapp" "github.com/tech/sendico/pkg/server/grpcapp"
"go.uber.org/zap" "go.uber.org/zap"
@@ -69,9 +70,10 @@ type Service struct {
} }
func NewService(logger mlogger.Logger, repo storage.Repository, producer msg.Producer, broker mb.Broker, cfg Config) *Service { func NewService(logger mlogger.Logger, repo storage.Repository, producer msg.Producer, broker mb.Broker, cfg Config) *Service {
if logger != nil { if logger == nil {
logger = logger.Named("tgsettle_gateway") logger = zap.NewNop()
} }
logger = logger.Named("service")
svc := &Service{ svc := &Service{
logger: logger, logger: logger,
repo: repo, repo: repo,
@@ -126,7 +128,7 @@ func (s *Service) consumeProcessor(processor np.EnvelopeProcessor) {
} }
s.consumers = append(s.consumers, consumer) s.consumers = append(s.consumers, consumer)
go func() { go func() {
if err := consumer.ConsumeMessages(processor.Process); err != nil { if err := consumer.ConsumeMessages(processor.Process); err != nil && !errors.Is(err, context.Canceled) {
s.logger.Warn("Messaging consumer stopped", zap.Error(err), zap.String("event", processor.GetSubject().ToString())) s.logger.Warn("Messaging consumer stopped", zap.Error(err), zap.String("event", processor.GetSubject().ToString()))
} }
}() }()
@@ -211,7 +213,11 @@ func (s *Service) onIntent(ctx context.Context, intent *model.PaymentGatewayInte
return err return err
} }
if existing != nil { if existing != nil {
s.logger.Info("Payment gateway intent already executed", zap.String("idempotency_key", intent.IdempotencyKey)) s.logger.Info("Payment gateway intent already executed",
zap.String("idempotency_key", intent.IdempotencyKey),
zap.String("payment_intent_id", intent.PaymentIntentID),
zap.String("quote_ref", intent.QuoteRef),
zap.String("rail", intent.OutgoingLeg))
return nil return nil
} }
@@ -241,12 +247,19 @@ func (s *Service) onConfirmationResult(ctx context.Context, result *model.Confir
} }
if result.RawReply != nil && s.repo != nil && s.repo.TelegramConfirmations() != nil { if result.RawReply != nil && s.repo != nil && s.repo.TelegramConfirmations() != nil {
_ = s.repo.TelegramConfirmations().Upsert(ctx, &storagemodel.TelegramConfirmation{ if err := s.repo.TelegramConfirmations().Upsert(ctx, &storagemodel.TelegramConfirmation{
RequestID: requestID, RequestID: requestID,
PaymentIntentID: intent.PaymentIntentID, PaymentIntentID: intent.PaymentIntentID,
QuoteRef: intent.QuoteRef, QuoteRef: intent.QuoteRef,
RawReply: result.RawReply, RawReply: result.RawReply,
}) }); err != nil {
s.logger.Warn("Failed to store telegram confirmation", zap.Error(err), zap.String("request_id", requestID))
} else {
s.logger.Info("Stored telegram confirmation", zap.String("request_id", requestID),
zap.String("payment_intent_id", intent.PaymentIntentID),
zap.String("reply_text", result.RawReply.Text), zap.String("reply_user_id", result.RawReply.FromUserID),
zap.String("reply_user", result.RawReply.FromUsername))
}
} }
if result.Status == model.ConfirmationStatusConfirmed || result.Status == model.ConfirmationStatusClarified { if result.Status == model.ConfirmationStatusConfirmed || result.Status == model.ConfirmationStatusClarified {
@@ -305,7 +318,13 @@ func (s *Service) sendConfirmationRequest(request *model.ConfirmationRequest) er
} }
env := confirmations.ConfirmationRequest(string(mservice.PaymentGateway), request) env := confirmations.ConfirmationRequest(string(mservice.PaymentGateway), request)
if err := s.producer.SendMessage(env); err != nil { if err := s.producer.SendMessage(env); err != nil {
s.logger.Warn("Failed to publish confirmation request", zap.Error(err), zap.String("request_id", request.RequestID)) s.logger.Warn("Failed to publish confirmation request",
zap.Error(err),
zap.String("request_id", request.RequestID),
zap.String("payment_intent_id", request.PaymentIntentID),
zap.String("quote_ref", request.QuoteRef),
zap.String("rail", request.Rail),
zap.Int32("timeout_seconds", request.TimeoutSeconds))
return err return err
} }
return nil return nil
@@ -326,7 +345,13 @@ func (s *Service) publishExecution(intent *model.PaymentGatewayIntent, result *m
} }
env := paymentgateway.PaymentGatewayExecution(string(mservice.PaymentGateway), exec) env := paymentgateway.PaymentGatewayExecution(string(mservice.PaymentGateway), exec)
if err := s.producer.SendMessage(env); err != nil { if err := s.producer.SendMessage(env); err != nil {
s.logger.Warn("Failed to publish gateway execution result", zap.Error(err), zap.String("request_id", result.RequestID)) s.logger.Warn("Failed to publish gateway execution result",
zap.Error(err),
zap.String("request_id", result.RequestID),
zap.String("idempotency_key", intent.IdempotencyKey),
zap.String("payment_intent_id", intent.PaymentIntentID),
zap.String("quote_ref", intent.QuoteRef),
zap.String("status", string(result.Status)))
} }
} }

View File

@@ -23,6 +23,9 @@ type Repository struct {
} }
func New(logger mlogger.Logger, conn *db.MongoConnection) (*Repository, error) { func New(logger mlogger.Logger, conn *db.MongoConnection) (*Repository, error) {
if logger == nil {
logger = zap.NewNop()
}
if conn == nil { if conn == nil {
return nil, merrors.InvalidArgument("mongo connection is nil") return nil, merrors.InvalidArgument("mongo connection is nil")
} }
@@ -30,10 +33,19 @@ func New(logger mlogger.Logger, conn *db.MongoConnection) (*Repository, error) {
if client == nil { if client == nil {
return nil, merrors.Internal("mongo client is not initialised") return nil, merrors.Internal("mongo client is not initialised")
} }
db := conn.Database()
if db == nil {
return nil, merrors.Internal("mongo database is not initialised")
}
dbName := db.Name()
logger = logger.Named("storage").Named("mongo")
if dbName != "" {
logger = logger.With(zap.String("database", dbName))
}
result := &Repository{ result := &Repository{
logger: logger.Named("storage").Named("mongo"), logger: logger,
conn: conn, conn: conn,
db: conn.Database(), db: db,
} }
ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
defer cancel() defer cancel()
@@ -43,12 +55,12 @@ func New(logger mlogger.Logger, conn *db.MongoConnection) (*Repository, error) {
} }
paymentsStore, err := store.NewPayments(result.logger, result.db) paymentsStore, err := store.NewPayments(result.logger, result.db)
if err != nil { if err != nil {
result.logger.Error("Failed to initialise payments store", zap.Error(err)) result.logger.Error("Failed to initialise payments store", zap.Error(err), zap.String("store", "payments"))
return nil, err return nil, err
} }
tgStore, err := store.NewTelegramConfirmations(result.logger, result.db) tgStore, err := store.NewTelegramConfirmations(result.logger, result.db)
if err != nil { if err != nil {
result.logger.Error("Failed to initialise telegram confirmations store", zap.Error(err)) result.logger.Error("Failed to initialise telegram confirmations store", zap.Error(err), zap.String("store", "telegram_confirmations"))
return nil, err return nil, err
} }
result.payments = paymentsStore result.payments = paymentsStore

View File

@@ -2,16 +2,18 @@ package store
import ( import (
"context" "context"
"errors"
"strings" "strings"
"time" "time"
"github.com/tech/sendico/gateway/tgsettle/storage" "github.com/tech/sendico/gateway/tgsettle/storage"
"github.com/tech/sendico/gateway/tgsettle/storage/model" "github.com/tech/sendico/gateway/tgsettle/storage/model"
"github.com/tech/sendico/pkg/db/repository"
ri "github.com/tech/sendico/pkg/db/repository/index"
"github.com/tech/sendico/pkg/merrors" "github.com/tech/sendico/pkg/merrors"
"github.com/tech/sendico/pkg/mlogger" "github.com/tech/sendico/pkg/mlogger"
"go.mongodb.org/mongo-driver/bson" "go.mongodb.org/mongo-driver/bson"
"go.mongodb.org/mongo-driver/mongo" "go.mongodb.org/mongo-driver/mongo"
"go.mongodb.org/mongo-driver/mongo/options"
"go.uber.org/zap" "go.uber.org/zap"
) )
@@ -29,18 +31,25 @@ func NewPayments(logger mlogger.Logger, db *mongo.Database) (*Payments, error) {
if db == nil { if db == nil {
return nil, merrors.InvalidArgument("mongo database is nil") return nil, merrors.InvalidArgument("mongo database is nil")
} }
p := &Payments{ if logger == nil {
logger: logger.Named("payments"), logger = zap.NewNop()
coll: db.Collection(paymentsCollection),
} }
_, err := p.coll.Indexes().CreateOne(context.Background(), mongo.IndexModel{ logger = logger.Named("payments").With(zap.String("collection", paymentsCollection))
Keys: bson.D{{Key: fieldIdempotencyKey, Value: 1}},
Options: options.Index().SetUnique(true), repo := repository.CreateMongoRepository(db, paymentsCollection)
}) if err := repo.CreateIndex(&ri.Definition{
if err != nil { Keys: []ri.Key{{Field: fieldIdempotencyKey, Sort: ri.Asc}},
p.logger.Error("Failed to create payments idempotency index", zap.Error(err)) Unique: true,
}); err != nil {
logger.Error("Failed to create payments idempotency index", zap.Error(err), zap.String("index_field", fieldIdempotencyKey))
return nil, err return nil, err
} }
p := &Payments{
logger: logger,
coll: db.Collection(paymentsCollection),
}
p.logger.Debug("Payments store initialised")
return p, nil return p, nil
} }
@@ -55,6 +64,9 @@ func (p *Payments) FindByIdempotencyKey(ctx context.Context, key string) (*model
return nil, nil return nil, nil
} }
if err != nil { if err != nil {
if !errors.Is(err, context.Canceled) && !errors.Is(err, context.DeadlineExceeded) {
p.logger.Warn("Payment execution lookup failed", zap.String("idempotency_key", key), zap.Error(err))
}
return nil, err return nil, err
} }
return &result, nil return &result, nil
@@ -74,6 +86,13 @@ func (p *Payments) InsertExecution(ctx context.Context, exec *model.PaymentExecu
if mongo.IsDuplicateKeyError(err) { if mongo.IsDuplicateKeyError(err) {
return storage.ErrDuplicate return storage.ErrDuplicate
} }
if !errors.Is(err, context.Canceled) && !errors.Is(err, context.DeadlineExceeded) {
p.logger.Warn("Failed to insert payment execution",
zap.String("idempotency_key", exec.IdempotencyKey),
zap.String("payment_intent_id", exec.PaymentIntentID),
zap.String("quote_ref", exec.QuoteRef),
zap.Error(err))
}
return err return err
} }
return nil return nil

View File

@@ -2,11 +2,14 @@ package store
import ( import (
"context" "context"
"errors"
"strings" "strings"
"time" "time"
"github.com/tech/sendico/gateway/tgsettle/storage" "github.com/tech/sendico/gateway/tgsettle/storage"
"github.com/tech/sendico/gateway/tgsettle/storage/model" "github.com/tech/sendico/gateway/tgsettle/storage/model"
"github.com/tech/sendico/pkg/db/repository"
ri "github.com/tech/sendico/pkg/db/repository/index"
"github.com/tech/sendico/pkg/merrors" "github.com/tech/sendico/pkg/merrors"
"github.com/tech/sendico/pkg/mlogger" "github.com/tech/sendico/pkg/mlogger"
"go.mongodb.org/mongo-driver/bson" "go.mongodb.org/mongo-driver/bson"
@@ -29,18 +32,25 @@ func NewTelegramConfirmations(logger mlogger.Logger, db *mongo.Database) (*Teleg
if db == nil { if db == nil {
return nil, merrors.InvalidArgument("mongo database is nil") return nil, merrors.InvalidArgument("mongo database is nil")
} }
t := &TelegramConfirmations{ if logger == nil {
logger: logger.Named("telegram_confirmations"), logger = zap.NewNop()
coll: db.Collection(telegramCollection),
} }
_, err := t.coll.Indexes().CreateOne(context.Background(), mongo.IndexModel{ logger = logger.Named("telegram_confirmations").With(zap.String("collection", telegramCollection))
Keys: bson.D{{Key: fieldRequestID, Value: 1}},
Options: options.Index().SetUnique(true), repo := repository.CreateMongoRepository(db, telegramCollection)
}) if err := repo.CreateIndex(&ri.Definition{
if err != nil { Keys: []ri.Key{{Field: fieldRequestID, Sort: ri.Asc}},
t.logger.Error("Failed to create telegram confirmations request_id index", zap.Error(err)) Unique: true,
}); err != nil {
logger.Error("Failed to create telegram confirmations request_id index", zap.Error(err), zap.String("index_field", fieldRequestID))
return nil, err return nil, err
} }
t := &TelegramConfirmations{
logger: logger,
coll: db.Collection(telegramCollection),
}
t.logger.Debug("Telegram confirmations store initialised")
return t, nil return t, nil
} }
@@ -61,6 +71,16 @@ func (t *TelegramConfirmations) Upsert(ctx context.Context, record *model.Telegr
"$set": record, "$set": record,
} }
_, err := t.coll.UpdateOne(ctx, bson.M{fieldRequestID: record.RequestID}, update, options.Update().SetUpsert(true)) _, err := t.coll.UpdateOne(ctx, bson.M{fieldRequestID: record.RequestID}, update, options.Update().SetUpsert(true))
if err != nil && !errors.Is(err, context.Canceled) && !errors.Is(err, context.DeadlineExceeded) {
fields := []zap.Field{zap.String("request_id", record.RequestID)}
if record.PaymentIntentID != "" {
fields = append(fields, zap.String("payment_intent_id", record.PaymentIntentID))
}
if record.QuoteRef != "" {
fields = append(fields, zap.String("quote_ref", record.QuoteRef))
}
t.logger.Warn("Failed to upsert telegram confirmation", append(fields, zap.Error(err))...)
}
return err return err
} }

View File

@@ -16,7 +16,7 @@ publish_to: 'none' # Remove this line if you wish to publish to pub.dev
# https://developer.apple.com/library/archive/documentation/General/Reference/InfoPlistKeyReference/Articles/CoreFoundationKeys.html # https://developer.apple.com/library/archive/documentation/General/Reference/InfoPlistKeyReference/Articles/CoreFoundationKeys.html
# In Windows, build-name is used as the major, minor, and patch parts # In Windows, build-name is used as the major, minor, and patch parts
# of the product and file versions while build-number is used as the build suffix. # of the product and file versions while build-number is used as the build suffix.
version: 2.3.0+431 version: 2.3.1+408
environment: environment:
sdk: ^3.8.1 sdk: ^3.8.1
@@ -28,7 +28,6 @@ environment:
# the latest version available on pub.dev. To see which dependencies have newer # the latest version available on pub.dev. To see which dependencies have newer
# versions available, run `flutter pub outdated`. # versions available, run `flutter pub outdated`.
dependencies: dependencies:
analyzer: 9.0.0
amplitude_flutter: ^4.0.1 amplitude_flutter: ^4.0.1
flutter: flutter:
sdk: flutter sdk: flutter

View File

@@ -1 +1 @@
2.3.0 2.3.1