Skip to content
This repository has been archived by the owner on Apr 4, 2024. It is now read-only.

server: logger handler #343

Merged
merged 13 commits into from
Aug 19, 2021
Prev Previous commit
Next Next commit
logger handler
  • Loading branch information
fedekunze committed Jul 23, 2021
commit 9aaa73bb470b69e84678df227a73082ca676f52d
19 changes: 13 additions & 6 deletions app/ante/ante.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,8 @@ import (

"github.com/palantir/stacktrace"

tmlog "github.com/tendermint/tendermint/libs/log"

sdk "github.com/cosmos/cosmos-sdk/types"
sdkerrors "github.com/cosmos/cosmos-sdk/types/errors"
"github.com/cosmos/cosmos-sdk/types/tx/signing"
Expand All @@ -14,7 +16,6 @@ import (
authtypes "github.com/cosmos/cosmos-sdk/x/auth/types"

"github.com/tharsis/ethermint/crypto/ethsecp256k1"
mintlog "github.com/tharsis/ethermint/log"
)

const (
Expand Down Expand Up @@ -50,7 +51,7 @@ func NewAnteHandler(
) (newCtx sdk.Context, err error) {
var anteHandler sdk.AnteHandler

defer Recover(&err)
defer Recover(ctx.Logger(), &err)

txWithExtensions, ok := tx.(authante.HasExtensionOptionsTx)
if ok {
Expand Down Expand Up @@ -116,15 +117,21 @@ func NewAnteHandler(
}
}

func Recover(err *error) {
func Recover(logger tmlog.Logger, err *error) {
if r := recover(); r != nil {
*err = sdkerrors.Wrapf(sdkerrors.ErrPanic, "%v", r)

if e, ok := r.(error); ok {
(*mintlog.EthermintLoggerInstance.TendermintLogger).Error(fmt.Sprintf("ante handler panicked with an error %v", e))
(*mintlog.EthermintLoggerInstance.TendermintLogger).Debug(string(debug.Stack()))
logger.Error(
"ante handler panicked",
"error", e,
"stack trace", string(debug.Stack()),
)
} else {
(*mintlog.EthermintLoggerInstance.TendermintLogger).Error(fmt.Sprintf("%v", r))
logger.Error(
"ante handler panicked",
"recover", fmt.Sprintf("%v", r),
)
}
}
}
Expand Down
2 changes: 1 addition & 1 deletion go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -28,7 +28,7 @@ require (
github.com/regen-network/cosmos-proto v0.3.1
github.com/rjeczalik/notify v0.9.2 // indirect
github.com/rs/cors v1.7.0
github.com/sirupsen/logrus v1.8.1
github.com/rs/zerolog v1.23.0
github.com/spf13/cast v1.3.1
github.com/spf13/cobra v1.1.3
github.com/spf13/viper v1.8.1
Expand Down
2 changes: 0 additions & 2 deletions go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -864,8 +864,6 @@ github.com/shurcooL/sanitized_anchor_name v1.0.0/go.mod h1:1NzhyTcUVG4SuEtjjoZeV
github.com/sirupsen/logrus v1.2.0/go.mod h1:LxeOpSwHxABJmUn/MG1IvRgCAasNZTLOkJPxbbu5VWo=
github.com/sirupsen/logrus v1.4.2/go.mod h1:tLMulIdttU9McNUspp0xgXVQah82FyeX6MwdIuYE2rE=
github.com/sirupsen/logrus v1.6.0/go.mod h1:7uNnSEd1DgxDLC74fIahvMZmmYsHGZGEOFrfsX/uA88=
github.com/sirupsen/logrus v1.8.1 h1:dJKuHgqk1NNQlqoA6BTlM1Wf9DOH3NBjQyu0h9+AZZE=
github.com/sirupsen/logrus v1.8.1/go.mod h1:yWOB1SBYBC5VeMP7gHvWumXLIWorT60ONWic61uBYv0=
github.com/smartystreets/assertions v0.0.0-20180927180507-b2de0cb4f26d h1:zE9ykElWQ6/NYmHa3jpm/yHnI4xSofP+UP6SpjHcSeM=
github.com/smartystreets/assertions v0.0.0-20180927180507-b2de0cb4f26d/go.mod h1:OnSkiWE9lh6wB0YB77sQom3nweQdgAjqCqsofrRNTgc=
github.com/smartystreets/goconvey v1.6.4 h1:fv0U8FUIMPNf1L9lnHLvLhgicrIVChEkdzIKYqbNC9s=
Expand Down
4 changes: 2 additions & 2 deletions init.sh
Original file line number Diff line number Diff line change
Expand Up @@ -6,8 +6,8 @@ KEYRING="test"
KEYALGO="eth_secp256k1"
LOGLEVEL="info"
# to trace evm
#TRACE="--trace"
TRACE=""
TRACE="--trace"
# TRACE=""


# remove existing daemon and client
Expand Down
76 changes: 76 additions & 0 deletions log/handler.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,76 @@
package log

import (
"github.com/rs/zerolog"

"github.com/cosmos/cosmos-sdk/server"
ethlog "github.com/ethereum/go-ethereum/log"
tmlog "github.com/tendermint/tendermint/libs/log"
)

var _ ethlog.Handler = &Handler{}

// Logger wraps the zero log Wrapper and extends it to support the ethereum logger interface.
type Handler struct {
*server.ZeroLogWrapper
}

func NewHandler(logger tmlog.Logger) ethlog.Handler {
zerologger, ok := logger.(*server.ZeroLogWrapper)
if !ok {
// default to Stdout if not an SDK logger wrapper
return ethlog.StdoutHandler
}

return &Handler{
ZeroLogWrapper: zerologger,
}
}

// Log implements the go-ethereum Logger Handler interface
func (h *Handler) Log(r *ethlog.Record) error {
lvl := EthLogLvlToZerolog(r.Lvl)

h.ZeroLogWrapper.
WithLevel(lvl).
Fields(getLogFields(r.Ctx...)).
Time(r.KeyNames.Time, r.Time).
Msg(r.Msg)
return nil
}

func EthLogLvlToZerolog(lvl ethlog.Lvl) zerolog.Level {
var level zerolog.Level

switch lvl {
case ethlog.LvlCrit:
level = zerolog.FatalLevel
case ethlog.LvlDebug:
level = zerolog.DebugLevel
case ethlog.LvlError:
level = zerolog.ErrorLevel
case ethlog.LvlInfo:
level = zerolog.InfoLevel
case ethlog.LvlTrace:
level = zerolog.TraceLevel
case ethlog.LvlWarn:
level = zerolog.WarnLevel
default:
level = zerolog.NoLevel
}

return level
}

func getLogFields(keyVals ...interface{}) map[string]interface{} {
if len(keyVals)%2 != 0 {
return nil
}

fields := make(map[string]interface{})
for i := 0; i < len(keyVals); i += 2 {
fields[keyVals[i].(string)] = keyVals[i+1]
}

return fields
}
25 changes: 0 additions & 25 deletions log/log.go

This file was deleted.

17 changes: 5 additions & 12 deletions server/start.go
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,6 @@ package server

import (
"context"
"fmt"
"io"
"net"
"net/http"
Expand Down Expand Up @@ -43,7 +42,7 @@ import (
"github.com/tharsis/ethermint/cmd/ethermintd/config"
"github.com/tharsis/ethermint/ethereum/rpc"
ethdebug "github.com/tharsis/ethermint/ethereum/rpc/namespaces/debug"
mintlog "github.com/tharsis/ethermint/log"
"github.com/tharsis/ethermint/log"
)

// Tendermint full-node start flags
Expand Down Expand Up @@ -173,10 +172,6 @@ func startInProcess(ctx *server.Context, clientCtx client.Context, appCreator ty
home := cfg.RootDir
logger := ctx.Logger

mintlog.EthermintLoggerInstance.TendermintLogger = &logger

(*mintlog.EthermintLoggerInstance.TendermintLogger).Info(fmt.Sprintf("startInProcess ~~~~~~~~ %s", ctx.Config.LogLevel))

traceWriterFile := ctx.Viper.GetString(flagTraceStore)
db, err := openDB(home)
if err != nil {
Expand Down Expand Up @@ -245,15 +240,13 @@ func startInProcess(ctx *server.Context, clientCtx client.Context, appCreator ty
var httpSrvDone = make(chan struct{}, 1)
var wsSrv rpc.WebsocketsServer

if ctx.Config.LogLevel == "debug" {
ethlog.Root().SetHandler(ethlog.StdoutHandler)
}
ethlog.Root().SetHandler(log.NewHandler(ctx.Logger))

if config.EVMRPC.Enable {
tmEndpoint := "/websocket"
tmRPCAddr := cfg.RPC.ListenAddress
logger.Info("EVM RPC Connecting to Tendermint WebSocket at", "address", tmRPCAddr+tmEndpoint)
tmWsClient := ConnectTmWS(tmRPCAddr, tmEndpoint)
tmWsClient := ConnectTmWS(tmRPCAddr, tmEndpoint, ctx.Logger)

rpcServer := ethrpc.NewServer()
apis := rpc.GetRPCAPIs(ctx, clientCtx, tmWsClient)
Expand All @@ -273,7 +266,7 @@ func startInProcess(ctx *server.Context, clientCtx client.Context, appCreator ty
r.HandleFunc("/", rpcServer.ServeHTTP).Methods("POST")
if grpcSrv != nil {
grpcWeb := grpcweb.WrapServer(grpcSrv)
MountGRPCWebServices(r, grpcWeb, grpcweb.ListGRPCResources(grpcSrv))
MountGRPCWebServices(r, grpcWeb, grpcweb.ListGRPCResources(grpcSrv), ctx.Logger)
}

handlerWithCors := cors.New(cors.Options{
Expand Down Expand Up @@ -321,7 +314,7 @@ func startInProcess(ctx *server.Context, clientCtx client.Context, appCreator ty
_, port, _ := net.SplitHostPort(config.EVMRPC.RPCAddress)

// allocate separate WS connection to Tendermint
tmWsClient = ConnectTmWS(tmRPCAddr, tmEndpoint)
tmWsClient = ConnectTmWS(tmRPCAddr, tmEndpoint, ctx.Logger)
wsSrv = rpc.NewWebsocketsServer(logger, tmWsClient, "localhost:"+port, config.EVMRPC.WsAddress)
go wsSrv.Start()
}
Expand Down
22 changes: 15 additions & 7 deletions server/util.go
Original file line number Diff line number Diff line change
@@ -1,19 +1,18 @@
package server

import (
"fmt"
"net/http"
"time"

"github.com/gorilla/mux"
"github.com/improbable-eng/grpc-web/go/grpcweb"
"github.com/spf13/cobra"
mintlog "github.com/tharsis/ethermint/log"

sdkserver "github.com/cosmos/cosmos-sdk/server"
"github.com/cosmos/cosmos-sdk/server/types"
"github.com/cosmos/cosmos-sdk/version"

tmlog "github.com/tendermint/tendermint/libs/log"
rpcclient "github.com/tendermint/tendermint/rpc/jsonrpc/client"

"github.com/tharsis/ethermint/app"
Expand Down Expand Up @@ -45,21 +44,29 @@ func AddCommands(rootCmd *cobra.Command, defaultNodeHome string, appCreator type
)
}

func ConnectTmWS(tmRPCAddr, tmEndpoint string) *rpcclient.WSClient {
func ConnectTmWS(tmRPCAddr, tmEndpoint string, logger tmlog.Logger) *rpcclient.WSClient {
tmWsClient, err := rpcclient.NewWS(tmRPCAddr, tmEndpoint,
rpcclient.MaxReconnectAttempts(256),
rpcclient.ReadWait(120*time.Second),
rpcclient.WriteWait(120*time.Second),
rpcclient.PingPeriod(50*time.Second),
rpcclient.OnReconnect(func() {
(*mintlog.EthermintLoggerInstance.TendermintLogger).Debug(fmt.Sprintf("EVM RPC reconnects to Tendermint WS %s", tmRPCAddr+tmEndpoint))
logger.Debug("EVM RPC reconnects to Tendermint WS", "address", tmRPCAddr+tmEndpoint)
}),
)

if err != nil {
(*mintlog.EthermintLoggerInstance.TendermintLogger).Error(fmt.Sprintf("Tendermint WS client could not be created for %s, Error %v", tmRPCAddr+tmEndpoint, err))
logger.Error(
"Tendermint WS client could not be created",
"address", tmRPCAddr+tmEndpoint,
"error", err,
)
} else if err := tmWsClient.OnStart(); err != nil {
(*mintlog.EthermintLoggerInstance.TendermintLogger).Error(fmt.Sprintf("Tendermint WS client could not start for %s, Error %v", tmRPCAddr+tmEndpoint, err))
logger.Error(
"Tendermint WS client could not start",
"address", tmRPCAddr+tmEndpoint,
"error", err,
)
}

return tmWsClient
Expand All @@ -69,10 +76,11 @@ func MountGRPCWebServices(
router *mux.Router,
grpcWeb *grpcweb.WrappedGrpcServer,
grpcResources []string,
logger tmlog.Logger,
) {
for _, res := range grpcResources {

(*mintlog.EthermintLoggerInstance.TendermintLogger).Info(fmt.Sprintf("[GRPC Web] HTTP POST mounted on %s", res))
logger.Info("[GRPC Web] HTTP POST mounted", "resource", res)

s := router.Methods("POST").Subrouter()
s.HandleFunc(res, func(resp http.ResponseWriter, req *http.Request) {
Expand Down
2 changes: 1 addition & 1 deletion tests/solidity/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -56,7 +56,7 @@ The [`init-test-node.sh`](./init-test-node.sh) script sets up ethermint with the

Each with roughly 100 ETH available (1e18 photon).

Running `ethermintd list keys` should output:
Running `ethermintd keys list --keyring-backend=test` should output:

```json
[
Expand Down
4 changes: 2 additions & 2 deletions testutil/network/util.go
Original file line number Diff line number Diff line change
Expand Up @@ -117,7 +117,7 @@ func startInProcess(cfg Config, val *Validator) error {
if val.AppConfig.EVMRPC.Enable {
tmEndpoint := "/websocket"
tmRPCAddr := val.Ctx.Config.RPC.ListenAddress
tmWsClient := ethsrv.ConnectTmWS(tmRPCAddr, tmEndpoint)
tmWsClient := ethsrv.ConnectTmWS(tmRPCAddr, tmEndpoint, val.Ctx.Logger)

val.jsonRPC = jsonrpc.NewServer()

Expand All @@ -132,7 +132,7 @@ func startInProcess(cfg Config, val *Validator) error {
r.HandleFunc("/", val.jsonRPC.ServeHTTP).Methods("POST")
if val.grpc != nil {
grpcWeb := grpcweb.WrapServer(val.grpc)
ethsrv.MountGRPCWebServices(r, grpcWeb, grpcweb.ListGRPCResources(val.grpc))
ethsrv.MountGRPCWebServices(r, grpcWeb, grpcweb.ListGRPCResources(val.grpc), val.Ctx.Logger)
}

handlerWithCors := cors.New(cors.Options{
Expand Down
19 changes: 12 additions & 7 deletions x/evm/handler.go
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,7 @@ import (
"fmt"
"runtime/debug"

mintlog "github.com/tharsis/ethermint/log"
tmlog "github.com/tendermint/tendermint/libs/log"

sdk "github.com/cosmos/cosmos-sdk/types"
sdkerrors "github.com/cosmos/cosmos-sdk/types/errors"
Expand All @@ -15,7 +15,7 @@ import (
// NewHandler returns a handler for Ethermint type messages.
func NewHandler(server types.MsgServer) sdk.Handler {
return func(ctx sdk.Context, msg sdk.Msg) (result *sdk.Result, err error) {
defer Recover(&err)
defer Recover(ctx.Logger(), &err)

ctx = ctx.WithEventManager(sdk.NewEventManager())

Expand All @@ -32,16 +32,21 @@ func NewHandler(server types.MsgServer) sdk.Handler {
}
}

func Recover(err *error) {
func Recover(logger tmlog.Logger, err *error) {
if r := recover(); r != nil {
*err = sdkerrors.Wrapf(sdkerrors.ErrPanic, "%v", r)

if e, ok := r.(error); ok {

(*mintlog.EthermintLoggerInstance.TendermintLogger).Error(fmt.Sprintf("evm msg handler panicked with an error %v", e))
(*mintlog.EthermintLoggerInstance.TendermintLogger).Debug(string(debug.Stack()))
logger.Error(
"message handler panicked",
"error", e,
"stack trace", string(debug.Stack()),
)
} else {
(*mintlog.EthermintLoggerInstance.TendermintLogger).Error(fmt.Sprintf("%v", r))
logger.Error(
"message handler panicked",
"recover", fmt.Sprintf("%v", r),
)
}
}
}
Loading