Merge pull request #60 from sideprotocol/extension_log

optimized log level

Author: Lazy Luis

x/oracle/abci/extension.go

@@ -45,7 +45,7 @@ func NewPriceOracleVoteExtHandler(logger log.Logger, valStore baseapp.ValidatorS
 	}
 
 	return PriceOracleVoteExtHandler{
-		logger:        logger,
+		logger:        logger.With("module", types.ModuleName),
 		currentBlock:  0,
 		valStore:      valStore,
 		Keeper:        oracleKeeper,
@@ -94,7 +94,6 @@ func (h *PriceOracleVoteExtHandler) VerifyVoteExtensionHandler() sdk.VerifyVoteE
 		}
 
 		validator := hex.EncodeToString(req.ValidatorAddress)
-		h.logger.Info("VerifyVoteExtensionHandler", "height", req.Height, "validator", validator)
 		var voteExt types.OracleVoteExtension
 		err := voteExt.Unmarshal(req.VoteExtension)
 		if err != nil {
@@ -105,16 +104,7 @@ func (h *PriceOracleVoteExtHandler) VerifyVoteExtensionHandler() sdk.VerifyVoteE
 			return nil, fmt.Errorf("vote extension height does not match request height; expected: %d, got: %d", req.Height, voteExt.Height)
 		}
 
-		// if len(voteExt.Prices) > 0 {
-		// 	// check if a fack price is existing.
-		// 	if _, ok := voteExt.Prices[types.NULL_SYMBOL]; !ok {
-		// 		return &abci.ResponseVerifyVoteExtension{Status: abci.ResponseVerifyVoteExtension_REJECT}, nil
-		// 	}
-		// }
-
-		// if voteExt.HasError {
-		// 	return &abci.ResponseVerifyVoteExtension{Status: abci.ResponseVerifyVoteExtension_REJECT}, nil
-		// }
+		h.logger.Debug("verify", "height", req.Height, "validator", validator, "prices", voteExt.Prices, "blocks", voteExt.Blocks)
 
 		for _, blk := range voteExt.Blocks {
 			if err = blk.Validate(); err != nil {
@@ -222,7 +212,7 @@ func (h *PriceOracleVoteExtHandler) getAllVolumeWeightedPrices() map[string]stri
 		}
 	}
 
-	h.logger.Info("AvgPrice", "prices", avgPrices)
+	h.logger.Debug("avg exchange prices", "prices", avgPrices)
 
 	textPrices := make(map[string]string)
 	for symbol, price := range avgPrices {
@@ -321,7 +311,7 @@ func (h *PriceOracleVoteExtHandler) PreBlocker(ctx sdk.Context, req *abci.Reques
 		return nil, err
 	}
 
-	h.logger.Warn("Oracle Final States", "price", prices)
+	h.logger.Info("Oracle Final States", "price", prices, "headers", headers)
 
 	return res, nil
 }
@@ -345,7 +335,7 @@ func (h *PriceOracleVoteExtHandler) extractPricesAndBlockHeaders(_ sdk.Context,
 			return nil, nil, err
 		}
 
-		h.logger.Warn("extension", "validator", hex.EncodeToString(v.Validator.Address), "extension", voteExt)
+		h.logger.Debug("received", "validator", hex.EncodeToString(v.Validator.Address), "extension", voteExt)
 
 		totalStake += v.Validator.Power
 
@@ -390,10 +380,11 @@ func (h *PriceOracleVoteExtHandler) extractPricesAndBlockHeaders(_ sdk.Context,
 	}
 
 	// finalize average by dividing by total stake, i.e. total weights
+	finalPrices := make(map[string]math.LegacyDec, len(types.PRICE_CACHE))
 	for base, price := range stakeWeightedPrices {
 		if price.GT(math.LegacyZeroDec()) {
 			if vp, ok := stakeWeightedVotingPower[base]; ok && vp.RoundInt64()*3 > totalStake*2 {
-				stakeWeightedPrices[base] = price.Quo(vp)
+				finalPrices[base] = price.Quo(vp)
 			}
 		} else {
 			h.logger.Error("Got invalid price.", "symbal", base, "price", price)
@@ -407,7 +398,7 @@ func (h *PriceOracleVoteExtHandler) extractPricesAndBlockHeaders(_ sdk.Context,
 			break
 		}
 	}
-	return stakeWeightedPrices, headers, nil
+	return finalPrices, headers, nil
 }
 
 func voteExtensionEnabled(ctx sdk.Context, height int64) bool {

x/oracle/module/service.go

@@ -20,7 +20,7 @@ func Start(svrCtx *server.Context, clientCtx client.Context, ctx context.Context
 
 	if types.StartProviders {
 
-		svrCtx.Logger.Info("price service", "module", "oracle", "msg", "Start Oracle Price Subscriber")
+		svrCtx.Logger.With("module", types.ModuleName).Info("price service", "module", "oracle", "msg", "Start Oracle Price Subscriber")
 
 		go binance.Subscribe(svrCtx, ctx)
 		go okex.Subscribe(svrCtx, ctx)
@@ -33,7 +33,7 @@ func Start(svrCtx *server.Context, clientCtx client.Context, ctx context.Context
 		// g.Go(func() error { return bybit.Subscribe(svrCtx, ctx) })
 		// g.Go(func() error { return bitget.Subscribe(svrCtx, ctx) })
 	} else {
-		svrCtx.Logger.Warn("Price service is disabled. It is required if your node is a validator. ")
+		svrCtx.Logger.With("module", types.ModuleName).Warn("Price service is disabled. It is required if your node is a validator. ")
 	}
 
 	return nil

x/oracle/providers/binance/provider.go

@@ -30,7 +30,7 @@ var (
 	SymbolMap    = map[string]string{
 		"BTCUSDT": types.BTCUSD,
 	}
-	URL          = "wss://stream.binance.com:443/stream?streams=btcusdt@miniTicker/atomusdt@miniTicker"
+	URL          = "wss://stream.binance.com:443/stream?streams=btcusdt@miniTicker/ethbtc@miniTicker"
 	SubscribeMsg = ""
 )
 

x/oracle/providers/bybit/provider.go

@@ -18,7 +18,7 @@ var (
     "op": "subscribe",
     "args": [
         "tickers.BTCUSDT",
-		"tickers.ATOMUSDT"
+		"tickers.ETHBTC"
     ]
 }`
 	SymbolMap = map[string]string{

x/oracle/types/cache.go

@@ -26,25 +26,6 @@ func CachePrice(exchange string, price Price) {
 		v[exchange] = price
 		PRICE_CACHE[price.Symbol] = v
 	}
-
-	// a null price is used to identify whether price provider is working
-	nullPrice := nullPrice(price.Time)
-	if v, ok := PRICE_CACHE[nullPrice.Symbol]; ok {
-		v[exchange] = nullPrice
-		PRICE_CACHE[nullPrice.Symbol] = v
-	} else {
-		v = make(map[string]Price)
-		v[exchange] = nullPrice
-		PRICE_CACHE[nullPrice.Symbol] = v
-	}
-}
-
-func nullPrice(pTime int64) Price {
-	return Price{
-		Symbol: NULL_SYMBOL,
-		Price:  "0",
-		Time:   pTime,
-	}
 }
 
 func GetPrices(lastBlockTime int64) map[string][]math.LegacyDec {
@@ -65,15 +46,3 @@ func GetPrices(lastBlockTime int64) map[string][]math.LegacyDec {
 	}
 	return symbolPrices
 }
-
-// func setMapValue(target map[string][]Price, ex string, p Price) {
-// 	if list, ok := target[ex]; ok {
-// 		if len(list) > 100 {
-// 			list = list[100:]
-// 		}
-// 		list = append(list, p)
-// 		target[ex] = list
-// 	} else {
-// 		target[ex] = []Price{p}
-// 	}
-// }

x/oracle/types/provider.go

@@ -34,10 +34,10 @@ func Subscribe(provider string, svrCtx *server.Context, ctx context.Context, url
 				if c, _, err = websocket.DefaultDialer.Dial(url, nil); err == nil {
 					reconnect = false
 					sendMessage(c, msg)
-					svrCtx.Logger.Info("connected price provider", "url", url)
+					svrCtx.Logger.With("module", ModuleName).Info("connected price provider", "url", url)
 					break
 				} else {
-					svrCtx.Logger.Error("re-connecting...", "error", err, "provider", provider)
+					svrCtx.Logger.With("module", ModuleName).Error("re-connecting...", "error", err, "provider", provider)
 				}
 			}
 		}
@@ -48,7 +48,7 @@ func Subscribe(provider string, svrCtx *server.Context, ctx context.Context, url
 				CachePrice(provider, p)
 			}
 		} else {
-			svrCtx.Logger.Error("provider disconnected", "error", err, "provider", provider)
+			svrCtx.Logger.With("module", ModuleName).Error("provider disconnected", "error", err, "provider", provider)
 			c.Close()
 			reconnect = true
 		}