Improve logging for auction module

This commit is contained in:
Prathamesh Musale 2024-02-27 17:35:12 +05:30
parent 4def3a9cf4
commit a16586458c
3 changed files with 39 additions and 27 deletions

View File

@ -3,6 +3,7 @@
rm -r ~/.laconic2d || true rm -r ~/.laconic2d || true
LACONIC2D_BIN=$(which laconic2d) LACONIC2D_BIN=$(which laconic2d)
# configure laconic2d # configure laconic2d
$LACONIC2D_BIN config set config log_level "*:error,p2p:info,state:info,auction:info,bond:info,registry:info" --skip-validate
$LACONIC2D_BIN config set client chain-id demo $LACONIC2D_BIN config set client chain-id demo
$LACONIC2D_BIN config set client keyring-backend test $LACONIC2D_BIN config set client keyring-backend test
$LACONIC2D_BIN keys add alice $LACONIC2D_BIN keys add alice

View File

@ -11,6 +11,7 @@ import (
"cosmossdk.io/collections/indexes" "cosmossdk.io/collections/indexes"
storetypes "cosmossdk.io/core/store" storetypes "cosmossdk.io/core/store"
errorsmod "cosmossdk.io/errors" errorsmod "cosmossdk.io/errors"
"cosmossdk.io/log"
"github.com/cosmos/cosmos-sdk/codec" "github.com/cosmos/cosmos-sdk/codec"
sdk "github.com/cosmos/cosmos-sdk/types" sdk "github.com/cosmos/cosmos-sdk/types"
@ -108,6 +109,15 @@ func NewKeeper(
return &k return &k
} }
// Logger returns a module-specific logger.
func (k Keeper) Logger(ctx sdk.Context) log.Logger {
return logger(ctx)
}
func logger(ctx sdk.Context) log.Logger {
return ctx.Logger().With("module", auctiontypes.ModuleName)
}
func (k *Keeper) SetUsageKeepers(usageKeepers []auctiontypes.AuctionUsageKeeper) { func (k *Keeper) SetUsageKeepers(usageKeepers []auctiontypes.AuctionUsageKeeper) {
if k.usageKeepers != nil { if k.usageKeepers != nil {
panic("cannot set auction hooks twice") panic("cannot set auction hooks twice")
@ -546,7 +556,7 @@ func (k Keeper) processAuctionPhases(ctx sdk.Context) error {
return err return err
} }
ctx.Logger().Info(fmt.Sprintf("Moved auction %s to reveal phase.", auction.Id)) k.Logger(ctx).Info(fmt.Sprintf("Moved auction %s to reveal phase.", auction.Id))
} }
// Reveal -> Expired state. // Reveal -> Expired state.
@ -556,7 +566,7 @@ func (k Keeper) processAuctionPhases(ctx sdk.Context) error {
return err return err
} }
ctx.Logger().Info(fmt.Sprintf("Moved auction %s to expired state.", auction.Id)) k.Logger(ctx).Info(fmt.Sprintf("Moved auction %s to expired state.", auction.Id))
} }
// If auction has expired, pick a winner from revealed bids. // If auction has expired, pick a winner from revealed bids.
@ -581,7 +591,7 @@ func (k Keeper) deleteCompletedAuctions(ctx sdk.Context) error {
} }
for _, auction := range auctions { for _, auction := range auctions {
ctx.Logger().Info(fmt.Sprintf("Deleting completed auction %s after timeout.", auction.Id)) k.Logger(ctx).Info(fmt.Sprintf("Deleting completed auction %s after timeout.", auction.Id))
if err := k.DeleteAuction(ctx, *auction); err != nil { if err := k.DeleteAuction(ctx, *auction); err != nil {
return err return err
} }
@ -591,7 +601,7 @@ func (k Keeper) deleteCompletedAuctions(ctx sdk.Context) error {
} }
func (k Keeper) pickAuctionWinner(ctx sdk.Context, auction *auctiontypes.Auction) error { func (k Keeper) pickAuctionWinner(ctx sdk.Context, auction *auctiontypes.Auction) error {
ctx.Logger().Info(fmt.Sprintf("Picking auction %s winner.", auction.Id)) k.Logger(ctx).Info(fmt.Sprintf("Picking auction %s winner.", auction.Id))
var highestBid *auctiontypes.Bid var highestBid *auctiontypes.Bid
var secondHighestBid *auctiontypes.Bid var secondHighestBid *auctiontypes.Bid
@ -602,38 +612,38 @@ func (k Keeper) pickAuctionWinner(ctx sdk.Context, auction *auctiontypes.Auction
} }
for _, bid := range bids { for _, bid := range bids {
ctx.Logger().Info(fmt.Sprintf("Processing bid %s %s", bid.BidderAddress, bid.BidAmount.String())) k.Logger(ctx).Info(fmt.Sprintf("Processing bid %s %s", bid.BidderAddress, bid.BidAmount.String()))
// Only consider revealed bids. // Only consider revealed bids.
if bid.Status != auctiontypes.BidStatusRevealed { if bid.Status != auctiontypes.BidStatusRevealed {
ctx.Logger().Info(fmt.Sprintf("Ignoring unrevealed bid %s %s", bid.BidderAddress, bid.BidAmount.String())) k.Logger(ctx).Info(fmt.Sprintf("Ignoring unrevealed bid %s %s", bid.BidderAddress, bid.BidAmount.String()))
continue continue
} }
// Init highest bid. // Init highest bid.
if highestBid == nil { if highestBid == nil {
highestBid = bid highestBid = bid
ctx.Logger().Info(fmt.Sprintf("Initializing 1st bid %s %s", bid.BidderAddress, bid.BidAmount.String())) k.Logger(ctx).Info(fmt.Sprintf("Initializing 1st bid %s %s", bid.BidderAddress, bid.BidAmount.String()))
continue continue
} }
//nolint: all //nolint: all
if highestBid.BidAmount.IsLT(bid.BidAmount) { if highestBid.BidAmount.IsLT(bid.BidAmount) {
ctx.Logger().Info(fmt.Sprintf("New highest bid %s %s", bid.BidderAddress, bid.BidAmount.String())) k.Logger(ctx).Info(fmt.Sprintf("New highest bid %s %s", bid.BidderAddress, bid.BidAmount.String()))
secondHighestBid = highestBid secondHighestBid = highestBid
highestBid = bid highestBid = bid
ctx.Logger().Info(fmt.Sprintf("Updated 1st bid %s %s", highestBid.BidderAddress, highestBid.BidAmount.String())) k.Logger(ctx).Info(fmt.Sprintf("Updated 1st bid %s %s", highestBid.BidderAddress, highestBid.BidAmount.String()))
ctx.Logger().Info(fmt.Sprintf("Updated 2nd bid %s %s", secondHighestBid.BidderAddress, secondHighestBid.BidAmount.String())) k.Logger(ctx).Info(fmt.Sprintf("Updated 2nd bid %s %s", secondHighestBid.BidderAddress, secondHighestBid.BidAmount.String()))
} else if secondHighestBid == nil || secondHighestBid.BidAmount.IsLT(bid.BidAmount) { } else if secondHighestBid == nil || secondHighestBid.BidAmount.IsLT(bid.BidAmount) {
ctx.Logger().Info(fmt.Sprintf("New 2nd highest bid %s %s", bid.BidderAddress, bid.BidAmount.String())) k.Logger(ctx).Info(fmt.Sprintf("New 2nd highest bid %s %s", bid.BidderAddress, bid.BidAmount.String()))
secondHighestBid = bid secondHighestBid = bid
ctx.Logger().Info(fmt.Sprintf("Updated 2nd bid %s %s", secondHighestBid.BidderAddress, secondHighestBid.BidAmount.String())) k.Logger(ctx).Info(fmt.Sprintf("Updated 2nd bid %s %s", secondHighestBid.BidderAddress, secondHighestBid.BidAmount.String()))
} else { } else {
ctx.Logger().Info(fmt.Sprintf("Ignoring bid as it doesn't affect 1st/2nd price %s %s", bid.BidderAddress, bid.BidAmount.String())) k.Logger(ctx).Info(fmt.Sprintf("Ignoring bid as it doesn't affect 1st/2nd price %s %s", bid.BidderAddress, bid.BidAmount.String()))
} }
} }
@ -649,11 +659,11 @@ func (k Keeper) pickAuctionWinner(ctx sdk.Context, auction *auctiontypes.Auction
if secondHighestBid != nil { if secondHighestBid != nil {
auction.WinningPrice = secondHighestBid.BidAmount auction.WinningPrice = secondHighestBid.BidAmount
} }
ctx.Logger().Info(fmt.Sprintf("Auction %s winner %s.", auction.Id, auction.WinnerAddress)) k.Logger(ctx).Info(fmt.Sprintf("Auction %s winner %s.", auction.Id, auction.WinnerAddress))
ctx.Logger().Info(fmt.Sprintf("Auction %s winner bid %s.", auction.Id, auction.WinningBid.String())) k.Logger(ctx).Info(fmt.Sprintf("Auction %s winner bid %s.", auction.Id, auction.WinningBid.String()))
ctx.Logger().Info(fmt.Sprintf("Auction %s winner price %s.", auction.Id, auction.WinningPrice.String())) k.Logger(ctx).Info(fmt.Sprintf("Auction %s winner price %s.", auction.Id, auction.WinningPrice.String()))
} else { } else {
ctx.Logger().Info(fmt.Sprintf("Auction %s has no valid revealed bids (no winner).", auction.Id)) k.Logger(ctx).Info(fmt.Sprintf("Auction %s has no valid revealed bids (no winner).", auction.Id))
} }
if err := k.SaveAuction(ctx, auction); err != nil { if err := k.SaveAuction(ctx, auction); err != nil {
@ -663,7 +673,7 @@ func (k Keeper) pickAuctionWinner(ctx sdk.Context, auction *auctiontypes.Auction
for _, bid := range bids { for _, bid := range bids {
bidderAddress, err := sdk.AccAddressFromBech32(bid.BidderAddress) bidderAddress, err := sdk.AccAddressFromBech32(bid.BidderAddress)
if err != nil { if err != nil {
ctx.Logger().Error(fmt.Sprintf("Invalid bidderAddress address. %v", err)) k.Logger(ctx).Error(fmt.Sprintf("Invalid bidderAddress address. %v", err))
panic("Invalid bidder address.") panic("Invalid bidder address.")
} }
@ -671,7 +681,7 @@ func (k Keeper) pickAuctionWinner(ctx sdk.Context, auction *auctiontypes.Auction
// Send reveal fee back to bidders that've revealed the bid. // Send reveal fee back to bidders that've revealed the bid.
sdkErr := k.bankKeeper.SendCoinsFromModuleToAccount(ctx, auctiontypes.ModuleName, bidderAddress, sdk.NewCoins(bid.RevealFee)) sdkErr := k.bankKeeper.SendCoinsFromModuleToAccount(ctx, auctiontypes.ModuleName, bidderAddress, sdk.NewCoins(bid.RevealFee))
if sdkErr != nil { if sdkErr != nil {
ctx.Logger().Error(fmt.Sprintf("Auction error returning reveal fee: %v", sdkErr)) k.Logger(ctx).Error(fmt.Sprintf("Auction error returning reveal fee: %v", sdkErr))
panic(sdkErr) panic(sdkErr)
} }
} }
@ -679,7 +689,7 @@ func (k Keeper) pickAuctionWinner(ctx sdk.Context, auction *auctiontypes.Auction
// Send back locked bid amount to all bidders. // Send back locked bid amount to all bidders.
sdkErr := k.bankKeeper.SendCoinsFromModuleToAccount(ctx, auctiontypes.ModuleName, bidderAddress, sdk.NewCoins(bid.BidAmount)) sdkErr := k.bankKeeper.SendCoinsFromModuleToAccount(ctx, auctiontypes.ModuleName, bidderAddress, sdk.NewCoins(bid.BidAmount))
if sdkErr != nil { if sdkErr != nil {
ctx.Logger().Error(fmt.Sprintf("Auction error returning bid amount: %v", sdkErr)) k.Logger(ctx).Error(fmt.Sprintf("Auction error returning bid amount: %v", sdkErr))
panic(sdkErr) panic(sdkErr)
} }
} }
@ -688,36 +698,36 @@ func (k Keeper) pickAuctionWinner(ctx sdk.Context, auction *auctiontypes.Auction
if auction.WinnerAddress != "" { if auction.WinnerAddress != "" {
winnerAddress, err := sdk.AccAddressFromBech32(auction.WinnerAddress) winnerAddress, err := sdk.AccAddressFromBech32(auction.WinnerAddress)
if err != nil { if err != nil {
ctx.Logger().Error(fmt.Sprintf("Invalid winner address. %v", err)) k.Logger(ctx).Error(fmt.Sprintf("Invalid winner address. %v", err))
panic("Invalid winner address.") panic("Invalid winner address.")
} }
// Take 2nd price from winner. // Take 2nd price from winner.
sdkErr := k.bankKeeper.SendCoinsFromAccountToModule(ctx, winnerAddress, auctiontypes.ModuleName, sdk.NewCoins(auction.WinningPrice)) sdkErr := k.bankKeeper.SendCoinsFromAccountToModule(ctx, winnerAddress, auctiontypes.ModuleName, sdk.NewCoins(auction.WinningPrice))
if sdkErr != nil { if sdkErr != nil {
ctx.Logger().Error(fmt.Sprintf("Auction error taking funds from winner: %v", sdkErr)) k.Logger(ctx).Error(fmt.Sprintf("Auction error taking funds from winner: %v", sdkErr))
panic(sdkErr) panic(sdkErr)
} }
// Burn anything over the min. bid amount. // Burn anything over the min. bid amount.
amountToBurn := auction.WinningPrice.Sub(auction.MinimumBid) amountToBurn := auction.WinningPrice.Sub(auction.MinimumBid)
if amountToBurn.IsNegative() { if amountToBurn.IsNegative() {
ctx.Logger().Error("Auction coins to burn cannot be negative.") k.Logger(ctx).Error("Auction coins to burn cannot be negative.")
panic("Auction coins to burn cannot be negative.") panic("Auction coins to burn cannot be negative.")
} }
// Use auction burn module account instead of actually burning coins to better keep track of supply. // Use auction burn module account instead of actually burning coins to better keep track of supply.
sdkErr = k.bankKeeper.SendCoinsFromModuleToModule(ctx, auctiontypes.ModuleName, auctiontypes.AuctionBurnModuleAccountName, sdk.NewCoins(amountToBurn)) sdkErr = k.bankKeeper.SendCoinsFromModuleToModule(ctx, auctiontypes.ModuleName, auctiontypes.AuctionBurnModuleAccountName, sdk.NewCoins(amountToBurn))
if sdkErr != nil { if sdkErr != nil {
ctx.Logger().Error(fmt.Sprintf("Auction error burning coins: %v", sdkErr)) k.Logger(ctx).Error(fmt.Sprintf("Auction error burning coins: %v", sdkErr))
panic(sdkErr) panic(sdkErr)
} }
} }
// Notify other modules (hook). // Notify other modules (hook).
ctx.Logger().Info(fmt.Sprintf("Auction %s notifying %d modules.", auction.Id, len(k.usageKeepers))) k.Logger(ctx).Info(fmt.Sprintf("Auction %s notifying %d modules.", auction.Id, len(k.usageKeepers)))
for _, keeper := range k.usageKeepers { for _, keeper := range k.usageKeepers {
ctx.Logger().Info(fmt.Sprintf("Auction %s notifying module %s.", auction.Id, keeper.ModuleName())) k.Logger(ctx).Info(fmt.Sprintf("Auction %s notifying module %s.", auction.Id, keeper.ModuleName()))
keeper.OnAuctionWinnerSelected(ctx, auction.Id) keeper.OnAuctionWinnerSelected(ctx, auction.Id)
} }

View File

@ -13,13 +13,14 @@ import (
auctiontypes "git.vdb.to/cerc-io/laconic2d/x/auction" auctiontypes "git.vdb.to/cerc-io/laconic2d/x/auction"
auctionkeeper "git.vdb.to/cerc-io/laconic2d/x/auction/keeper" auctionkeeper "git.vdb.to/cerc-io/laconic2d/x/auction/keeper"
bondtypes "git.vdb.to/cerc-io/laconic2d/x/bond"
registrytypes "git.vdb.to/cerc-io/laconic2d/x/registry" registrytypes "git.vdb.to/cerc-io/laconic2d/x/registry"
) )
// Record keeper implements the bond usage keeper interface. // Record keeper implements the bond usage keeper interface.
var ( var (
_ auctiontypes.AuctionUsageKeeper = RecordKeeper{} _ auctiontypes.AuctionUsageKeeper = RecordKeeper{}
// _ bondtypes.BondUsageKeeper = (*RecordKeeper)(nil) _ bondtypes.BondUsageKeeper = RecordKeeper{}
) )
// RecordKeeper exposes the bare minimal read-only API for other modules. // RecordKeeper exposes the bare minimal read-only API for other modules.