jRPC - Review Logs (0xPolygonHermez#2883) (0xPolygonHermez#2899)

event/eventlog.go

@@ -31,6 +31,19 @@ func (e *EventLog) LogEvent(ctx context.Context, event *Event) error {
 // LogExecutorError is used to store Executor error for runtime debugging
 func (e *EventLog) LogExecutorError(ctx context.Context, responseError executor.ExecutorError, processBatchRequest *executor.ProcessBatchRequest) {
 	timestamp := time.Now()
+
+	// if it's a user related error, ignore it
+	if responseError == executor.ExecutorError_EXECUTOR_ERROR_SM_MAIN_COUNTERS_OVERFLOW_STEPS ||
+		responseError == executor.ExecutorError_EXECUTOR_ERROR_SM_MAIN_COUNTERS_OVERFLOW_KECCAK ||
+		responseError == executor.ExecutorError_EXECUTOR_ERROR_SM_MAIN_COUNTERS_OVERFLOW_BINARY ||
+		responseError == executor.ExecutorError_EXECUTOR_ERROR_SM_MAIN_COUNTERS_OVERFLOW_MEM ||
+		responseError == executor.ExecutorError_EXECUTOR_ERROR_SM_MAIN_COUNTERS_OVERFLOW_ARITH ||
+		responseError == executor.ExecutorError_EXECUTOR_ERROR_SM_MAIN_COUNTERS_OVERFLOW_PADDING ||
+		responseError == executor.ExecutorError_EXECUTOR_ERROR_SM_MAIN_COUNTERS_OVERFLOW_POSEIDON ||
+		responseError == executor.ExecutorError_EXECUTOR_ERROR_INVALID_BATCH_L2_DATA {
+		return
+	}
+
 	log.Errorf("error found in the executor: %v at %v", responseError, timestamp)
 	payload, err := json.Marshal(processBatchRequest)
 	if err != nil {

jsonrpc/endpoints_eth.go

@@ -114,7 +114,7 @@ func (e *EthEndpoints) Call(arg *types.TxArgs, blockArg *types.BlockNumberOrHash
 			copy(data, result.ReturnValue)
 			return nil, types.NewRPCErrorWithData(types.RevertedErrorCode, result.Err.Error(), &data)
 		} else if result.Failed() {
-			return nil, types.NewRPCErrorWithData(types.DefaultErrorCode, result.Err.Error(), nil)
+			return nil, types.NewRPCError(types.DefaultErrorCode, result.Err.Error())
 		}
 
 		return types.ArgBytesPtr(result.ReturnValue), nil
@@ -193,8 +193,7 @@ func (e *EthEndpoints) EstimateGas(arg *types.TxArgs, blockArg *types.BlockNumbe
 			return nil, types.NewRPCErrorWithData(types.RevertedErrorCode, err.Error(), &data)
 		} else if err != nil {
 			errMsg := fmt.Sprintf("failed to estimate gas: %v", err.Error())
-			logError := !runtime.IsOutOfCounterError(err) && !errors.Is(err, runtime.ErrOutOfGas)
-			return RPCErrorResponse(types.DefaultErrorCode, errMsg, nil, logError)
+			return nil, types.NewRPCError(types.DefaultErrorCode, errMsg)
 		}
 		return hex.EncodeUint64(gasEstimation), nil
 	})
@@ -883,7 +882,7 @@ func (e *EthEndpoints) SendRawTransaction(httpRequest *http.Request, input strin
 
 		// TODO: this is temporary patch remove this log
 		realIp := httpRequest.Header.Get("X-Real-IP")
-		log.Infof("X-Forwarded-For: %s, X-Real-IP: %s", ips, realIp)
+		log.Debugf("X-Forwarded-For: %s, X-Real-IP: %s", ips, realIp)
 
 		if ips != "" {
 			ip = strings.Split(ips, ",")[0]

jsonrpc/handler.go

@@ -126,7 +126,7 @@ func (h *Handler) Handle(req handleRequest) types.Response {
 
 	output := fd.fv.Call(inArgs)
 	if err := getError(output[1]); err != nil {
-		log.Infof("failed call: [%v]%v. Params: %v", err.ErrorCode(), err.Error(), string(req.Params))
+		log.Debugf("failed call: [%v]%v. Params: %v", err.ErrorCode(), err.Error(), string(req.Params))
 		return types.NewResponse(req.Request, nil, err)
 	}
 
@@ -233,7 +233,7 @@ func (h *Handler) getFnHandler(req types.Request) (*serviceData, *funcData, type
 
 	service, ok := h.serviceMap[serviceName]
 	if !ok {
-		log.Infof("Method %s not found", req.Method)
+		log.Debugf("Method %s not found", req.Method)
 		return nil, nil, types.NewRPCError(types.NotFoundErrorCode, methodNotFoundErrorMessage)
 	}
 	fd, ok := service.funcMap[funcName]

jsonrpc/metrics/metrics.go

@@ -12,6 +12,7 @@ const (
 	requestPrefix       = prefix + "request_"
 	requestsHandledName = requestPrefix + "handled"
 	requestDurationName = requestPrefix + "duration"
+	connName            = requestPrefix + "connection"
 
 	requestHandledTypeLabelName = "type"
 )
@@ -20,6 +21,10 @@ const (
 // `jsonrpc_request_handled` metric `type` label.
 type RequestHandledLabel string
 
+// ConnLabel represents the possible values for the
+// `jsonrpc_request_connection` metric `type` label.
+type ConnLabel string
+
 const (
 	// RequestHandledLabelInvalid represents an request of type invalid
 	RequestHandledLabelInvalid RequestHandledLabel = "invalid"
@@ -29,6 +34,11 @@ const (
 	RequestHandledLabelSingle RequestHandledLabel = "single"
 	// RequestHandledLabelBatch represents an request of type batch
 	RequestHandledLabelBatch RequestHandledLabel = "batch"
+
+	// HTTPConnLabel represents a HTTP connection
+	HTTPConnLabel ConnLabel = "HTTP"
+	// WSConnLabel represents a WS connection
+	WSConnLabel ConnLabel = "WS"
 )
 
 // Register the metrics for the jsonrpc package.
@@ -63,6 +73,12 @@ func Register() {
 	metrics.RegisterHistograms(histograms...)
 }
 
+// CountConn increments the connection counter vector by one for the
+// given label.
+func CountConn(label ConnLabel) {
+	metrics.CounterVecInc(connName, string(label))
+}
+
 // RequestHandled increments the requests handled counter vector by one for the
 // given label.
 func RequestHandled(label RequestHandledLabel) {

jsonrpc/server.go

@@ -10,7 +10,6 @@ import (
 	"mime"
 	"net"
 	"net/http"
-	"sync"
 	"syscall"
 	"time"
 
@@ -51,10 +50,6 @@ type Server struct {
 	srv        *http.Server
 	wsSrv      *http.Server
 	wsUpgrader websocket.Upgrader
-
-	connCounterMutex *sync.Mutex
-	httpConnCounter  int64
-	wsConnCounter    int64
 }
 
 // Service defines a struct that will provide public methods to be exposed
@@ -90,10 +85,9 @@ func NewServer(
 	}
 
 	srv := &Server{
-		config:           cfg,
-		handler:          handler,
-		chainID:          chainID,
-		connCounterMutex: &sync.Mutex{},
+		config:  cfg,
+		handler: handler,
+		chainID: chainID,
 	}
 	return srv
 }
@@ -251,7 +245,6 @@ func (s *Server) handle(w http.ResponseWriter, req *http.Request) {
 	}
 
 	s.increaseHttpConnCounter()
-	defer s.decreaseHttpConnCounter()
 
 	start := time.Now()
 	var respLen int
@@ -408,7 +401,6 @@ func (s *Server) handleWs(w http.ResponseWriter, req *http.Request) {
 	}(wsConn)
 
 	s.increaseWsConnCounter()
-	defer s.decreaseWsConnCounter()
 
 	// recover
 	defer func() {
@@ -447,54 +439,29 @@ func (s *Server) handleWs(w http.ResponseWriter, req *http.Request) {
 }
 
 func (s *Server) increaseHttpConnCounter() {
-	s.connCounterMutex.Lock()
-	s.httpConnCounter++
-	s.logConnCounters()
-	s.connCounterMutex.Unlock()
-}
-
-func (s *Server) decreaseHttpConnCounter() {
-	s.connCounterMutex.Lock()
-	s.httpConnCounter--
-	s.logConnCounters()
-	s.connCounterMutex.Unlock()
+	metrics.CountConn(metrics.HTTPConnLabel)
 }
 
 func (s *Server) increaseWsConnCounter() {
-	s.connCounterMutex.Lock()
-	s.wsConnCounter++
-	s.logConnCounters()
-	s.connCounterMutex.Unlock()
-}
-
-func (s *Server) decreaseWsConnCounter() {
-	s.connCounterMutex.Lock()
-	s.wsConnCounter--
-	s.logConnCounters()
-	s.connCounterMutex.Unlock()
-}
-
-func (s *Server) logConnCounters() {
-	totalConnCounter := s.httpConnCounter + s.wsConnCounter
-	log.Infof("[ HTTP conns: %v | WS conns: %v | Total conns: %v ]", s.httpConnCounter, s.wsConnCounter, totalConnCounter)
+	metrics.CountConn(metrics.WSConnLabel)
 }
 
 func handleInvalidRequest(w http.ResponseWriter, err error, code int) {
 	defer metrics.RequestHandled(metrics.RequestHandledLabelInvalid)
-	log.Infof("Invalid Request: %v", err.Error())
+	log.Debugf("Invalid Request: %v", err.Error())
 	http.Error(w, err.Error(), code)
 }
 
 func handleError(w http.ResponseWriter, err error) {
 	defer metrics.RequestHandled(metrics.RequestHandledLabelError)
-	log.Errorf("Error processing request: %v", err)
 
 	if errors.Is(err, syscall.EPIPE) {
 		// if it is a broken pipe error, return
 		return
 	}
 
 	// if it is a different error, write it to the response
+	log.Errorf("Error processing request: %v", err)
 	http.Error(w, err.Error(), http.StatusInternalServerError)
 }
 
@@ -507,9 +474,9 @@ func RPCErrorResponse(code int, message string, err error, logError bool) (inter
 func RPCErrorResponseWithData(code int, message string, data *[]byte, err error, logError bool) (interface{}, types.Error) {
 	if logError {
 		if err != nil {
-			log.Errorf("%v: %v", message, err.Error())
+			log.Debugf("%v: %v", message, err.Error())
 		} else {
-			log.Error(message)
+			log.Debug(message)
 		}
 	}
 	return nil, types.NewRPCErrorWithData(code, message, data)

pool/pool.go

@@ -155,6 +155,7 @@ func (p *Pool) refreshBlockedAddresses() {
 
 // StartPollingMinSuggestedGasPrice starts polling the minimum suggested gas price
 func (p *Pool) StartPollingMinSuggestedGasPrice(ctx context.Context) {
+	p.tryUpdateMinSuggestedGasPrice(p.cfg.DefaultMinGasPriceAllowed)
 	p.pollMinSuggestedGasPrice(ctx)
 	go func() {
 		for {
@@ -573,6 +574,8 @@ func (p *Pool) validateTx(ctx context.Context, poolTx Transaction) error {
 	return nil
 }
 
+// pollMinSuggestedGasPrice polls the minimum L2 gas price since the previous
+// check accordingly to the configured interval and tries to update it
 func (p *Pool) pollMinSuggestedGasPrice(ctx context.Context) {
 	fromTimestamp := time.Now().UTC().Add(-p.cfg.MinAllowedGasPriceInterval.Duration)
 	// Ensuring we don't use a timestamp before the pool start as it may be using older L1 gas price factor
@@ -582,24 +585,26 @@ func (p *Pool) pollMinSuggestedGasPrice(ctx context.Context) {
 
 	l2GasPrice, err := p.storage.MinL2GasPriceSince(ctx, fromTimestamp)
 	if err != nil {
-		p.minSuggestedGasPriceMux.Lock()
-		// Ensuring we always have suggested minimum gas price
-		if p.minSuggestedGasPrice == nil {
-			p.minSuggestedGasPrice = big.NewInt(0).SetUint64(p.cfg.DefaultMinGasPriceAllowed)
-			log.Infof("Min allowed gas price updated to: %d", p.cfg.DefaultMinGasPriceAllowed)
-		}
-		p.minSuggestedGasPriceMux.Unlock()
 		if err == state.ErrNotFound {
 			log.Warnf("No suggested min gas price since: %v", fromTimestamp)
 		} else {
 			log.Errorf("Error getting min gas price since: %v", fromTimestamp)
 		}
 	} else {
-		p.minSuggestedGasPriceMux.Lock()
-		p.minSuggestedGasPrice = big.NewInt(0).SetUint64(l2GasPrice)
-		p.minSuggestedGasPriceMux.Unlock()
-		log.Infof("Min allowed gas price updated to: %d", l2GasPrice)
+		p.tryUpdateMinSuggestedGasPrice(l2GasPrice)
+	}
+}
+
+// tryUpdateMinSuggestedGasPrice tries to update the min suggested gas price
+// with the provided minSuggestedGasPrice, it updates if the provided value
+// is different from the value already store in p.minSuggestedGasPriceMux
+func (p *Pool) tryUpdateMinSuggestedGasPrice(minSuggestedGasPrice uint64) {
+	p.minSuggestedGasPriceMux.Lock()
+	if p.minSuggestedGasPrice == nil || p.minSuggestedGasPrice.Uint64() != minSuggestedGasPrice {
+		p.minSuggestedGasPrice = big.NewInt(0).SetUint64(minSuggestedGasPrice)
+		log.Infof("Min suggested gas price updated to: %d", minSuggestedGasPrice)
 	}
+	p.minSuggestedGasPriceMux.Unlock()
 }
 
 // checkTxFieldCompatibilityWithExecutor checks the field sizes of the transaction to make sure

state/transaction.go

@@ -823,9 +823,9 @@ func (s *State) EstimateGas(transaction *types.Transaction, senderAddress common
 
 	executions := int64(len(txExecutions))
 	if executions > 0 {
-		log.Infof("EstimateGas executed TX %v %d times in %d milliseconds", transaction.Hash(), executions, totalExecutionTime.Milliseconds())
+		log.Debugf("EstimateGas executed TX %v %d times in %d milliseconds", transaction.Hash(), executions, totalExecutionTime.Milliseconds())
 	} else {
-		log.Error("Estimate gas. Tx not executed")
+		log.Debug("Estimate gas. Tx not executed")
 	}
 	return highEnd, nil, nil
 }