Panic handlers in notifiers (#142)

* add log statement * Add panic handler in ws APIs --------- Co-authored-by: Shubham Goyal <[email protected]>
hubble-exchange · Dec 27, 2023 · 1e2cfeb · 1e2cfeb
1 parent 036cc2e
commit 1e2cfeb
Show file tree

Hide file tree

Showing 4 changed files with 44 additions and 15 deletions.
diff --git a/plugin/evm/orderbook/metrics.go b/plugin/evm/orderbook/metrics.go
@@ -23,6 +23,7 @@ var (
 	HandleChainAcceptedLogsPanicsCounter     = metrics.NewRegisteredCounter("handle_chain_accepted_logs_panics", nil)
 	HandleChainAcceptedEventPanicsCounter    = metrics.NewRegisteredCounter("handle_chain_accepted_event_panics", nil)
 	HandleMatchingPipelineTimerPanicsCounter = metrics.NewRegisteredCounter("handle_matching_pipeline_timer_panics", nil)
+	RPCPanicsCounter                         = metrics.NewRegisteredCounter("rpc_panic", nil)
 
 	BuildBlockFailedWithLowBlockGasCounter = metrics.NewRegisteredCounter("build_block_failed_low_block_gas", nil)
 

diff --git a/plugin/evm/orderbook/service.go b/plugin/evm/orderbook/service.go
@@ -7,16 +7,20 @@ import (
 	"context"
 	"fmt"
 	"math/big"
+	"runtime"
+	"runtime/debug"
 	"strconv"
 	"strings"
 	"time"
 
 	"github.com/ava-labs/subnet-evm/core"
 	"github.com/ava-labs/subnet-evm/eth"
+	"github.com/ava-labs/subnet-evm/metrics"
 	hu "github.com/ava-labs/subnet-evm/plugin/evm/orderbook/hubbleutils"
 	"github.com/ava-labs/subnet-evm/rpc"
 	"github.com/ethereum/go-ethereum/common"
 	"github.com/ethereum/go-ethereum/event"
+	"github.com/ethereum/go-ethereum/log"
 )
 
 type OrderBookAPI struct {
@@ -213,7 +217,7 @@ func (api *OrderBookAPI) NewOrderBookState(ctx context.Context) (*rpc.Subscripti
 
 	rpcSub := notifier.CreateSubscription()
 
-	go func() {
+	go executeFuncAndRecoverPanic(func() {
 		var (
 			headers    = make(chan core.ChainHeadEvent)
 			headersSub event.Subscription
@@ -226,6 +230,7 @@ func (api *OrderBookAPI) NewOrderBookState(ctx context.Context) (*rpc.Subscripti
 			select {
 			case <-headers:
 				orderBookData := api.GetDetailedOrderBookData(ctx)
+				log.Info("New order book state", "orderBookData", orderBookData)
 				notifier.Notify(rpcSub.ID, &orderBookData)
 			case <-rpcSub.Err():
 				headersSub.Unsubscribe()
@@ -235,7 +240,7 @@ func (api *OrderBookAPI) NewOrderBookState(ctx context.Context) (*rpc.Subscripti
 				return
 			}
 		}
-	}()
+	}, "panic in NewOrderBookState", RPCPanicsCounter)
 
 	return rpcSub, nil
 }
@@ -253,7 +258,7 @@ func (api *OrderBookAPI) StreamDepthUpdateForMarket(ctx context.Context, market
 
 	var oldMarketDepth = &MarketDepth{}
 
-	go func() {
+	go executeFuncAndRecoverPanic(func() {
 		for {
 			select {
 			case <-ticker.C:
@@ -266,7 +271,7 @@ func (api *OrderBookAPI) StreamDepthUpdateForMarket(ctx context.Context, market
 				return
 			}
 		}
-	}()
+	}, "panic in StreamDepthUpdateForMarket", RPCPanicsCounter)
 
 	return rpcSub, nil
 }
@@ -276,7 +281,6 @@ func (api *OrderBookAPI) StreamDepthUpdateForMarket(ctx context.Context, market
 func (api *OrderBookAPI) StreamDepthUpdateForMarketAndFreq(ctx context.Context, market int, updateFreq string) (*rpc.Subscription, error) {
 	notifier, _ := rpc.NotifierFromContext(ctx)
 	rpcSub := notifier.CreateSubscription()
-
 	if updateFreq == "" {
 		updateFreq = "1s"
 	}
@@ -289,20 +293,21 @@ func (api *OrderBookAPI) StreamDepthUpdateForMarketAndFreq(ctx context.Context,
 
 	var oldMarketDepth = &MarketDepth{}
 
-	go func() {
+	go executeFuncAndRecoverPanic(func() {
 		for {
 			select {
 			case <-ticker.C:
 				newMarketDepth := getDepthForMarket(api.db, Market(market))
 				depthUpdate := getUpdateInDepth(newMarketDepth, oldMarketDepth)
+				log.Info("Depth update", "depthUpdate", depthUpdate)
 				notifier.Notify(rpcSub.ID, depthUpdate)
 				oldMarketDepth = newMarketDepth
 			case <-notifier.Closed():
 				ticker.Stop()
 				return
 			}
 		}
-	}()
+	}, "panic in StreamDepthUpdateForMarketAndFreq", RPCPanicsCounter)
 
 	return rpcSub, nil
 }
@@ -372,3 +377,25 @@ type MarketDepth struct {
 	Longs  map[string]string `json:"longs"`
 	Shorts map[string]string `json:"shorts"`
 }
+
+func executeFuncAndRecoverPanic(fn func(), panicMessage string, panicCounter metrics.Counter) {
+	defer func() {
+		if panicInfo := recover(); panicInfo != nil {
+			var errorMessage string
+			switch panicInfo := panicInfo.(type) {
+			case string:
+				errorMessage = fmt.Sprintf("recovered (string) panic: %s", panicInfo)
+			case runtime.Error:
+				errorMessage = fmt.Sprintf("recovered (runtime.Error) panic: %s", panicInfo.Error())
+			case error:
+				errorMessage = fmt.Sprintf("recovered (error) panic: %s", panicInfo.Error())
+			default:
+				errorMessage = fmt.Sprintf("recovered (default) panic: %v", panicInfo)
+			}
+
+			log.Error(panicMessage, "errorMessage", errorMessage, "stack_trace", string(debug.Stack()))
+			panicCounter.Inc(1)
+		}
+	}()
+	fn()
+}
diff --git a/plugin/evm/orderbook/trading_apis.go b/plugin/evm/orderbook/trading_apis.go
@@ -213,7 +213,7 @@ func (api *TradingAPI) StreamDepthUpdateForMarket(ctx context.Context, market in
 
 	var oldMarketDepth = &MarketDepth{}
 
-	go func() {
+	go executeFuncAndRecoverPanic(func() {
 		for {
 			select {
 			case <-ticker.C:
@@ -233,7 +233,7 @@ func (api *TradingAPI) StreamDepthUpdateForMarket(ctx context.Context, market in
 				return
 			}
 		}
-	}()
+	}, "panic in StreamDepthUpdateForMarket", RPCPanicsCounter)
 
 	return rpcSub, nil
 }
@@ -268,7 +268,7 @@ func (api *TradingAPI) StreamTraderUpdates(ctx context.Context, trader string, b
 
 	traderFeedCh := make(chan TraderEvent)
 	traderFeedSubscription := traderFeed.Subscribe(traderFeedCh)
-	go func() {
+	go executeFuncAndRecoverPanic(func() {
 		defer traderFeedSubscription.Unsubscribe()
 
 		for {
@@ -281,7 +281,7 @@ func (api *TradingAPI) StreamTraderUpdates(ctx context.Context, trader string, b
 				return
 			}
 		}
-	}()
+	}, "panic in StreamTraderUpdates", RPCPanicsCounter)
 
 	return rpcSub, nil
 }
@@ -293,7 +293,7 @@ func (api *TradingAPI) StreamMarketTrades(ctx context.Context, market Market, bl
 
 	marketFeedCh := make(chan MarketFeedEvent)
 	acceptedLogsSubscription := marketFeed.Subscribe(marketFeedCh)
-	go func() {
+	go executeFuncAndRecoverPanic(func() {
 		defer acceptedLogsSubscription.Unsubscribe()
 
 		for {
@@ -306,7 +306,7 @@ func (api *TradingAPI) StreamMarketTrades(ctx context.Context, market Market, bl
 				return
 			}
 		}
-	}()
+	}, "panic in StreamMarketTrades", RPCPanicsCounter)
 
 	return rpcSub, nil
 }
diff --git a/scripts/run_local.sh b/scripts/run_local.sh
@@ -19,7 +19,8 @@ then
     echo "31b571bf6894a248831ff937bb49f7754509fe93bbd2517c9c73c4144c0e97dc" > $FILE
 fi
 
-avalanche subnet create hubblenet --force --custom --genesis genesis.json --custom-vm-path custom_evm.bin --custom-vm-branch main --custom-vm-build-script scripts/build.sh --custom-vm-repo-url https://github.com/hubble-exchange/hubblenet --config .avalanche-cli.json
+# avalanche subnet create hubblenet --force --custom --genesis genesis.json --custom-vm-path custom_evm.bin --custom-vm-branch main --custom-vm-build-script scripts/build.sh --custom-vm-repo-url https://github.com/hubble-exchange/hubblenet --config .avalanche-cli.json
+avalanche subnet create hubblenet --force --custom --genesis genesis.json --vm custom_evm.bin --config .avalanche-cli.json
 
 # configure and add chain.json
 avalanche subnet configure hubblenet --chain-config chain.json --config .avalanche-cli.json
@@ -28,6 +29,6 @@ avalanche subnet configure hubblenet --subnet-config subnet.json --config .avala
 
 # use the same avalanchego version as the one used in subnet-evm
 # use tee to keep showing outut while storing in a var
-OUTPUT=$(avalanche subnet deploy hubblenet -l --avalanchego-version v1.10.14 --config .avalanche-cli.json | tee /dev/fd/2)
+OUTPUT=$(avalanche subnet deploy hubblenet -l --avalanchego-version v1.10.13 --config .avalanche-cli.json | tee /dev/fd/2)
 
 setStatus