Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Admin] add log level customization command #1362

Merged
merged 7 commits into from
Oct 9, 2021
Merged
Show file tree
Hide file tree
Changes from 6 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
14 changes: 10 additions & 4 deletions admin/command_runner.go
Original file line number Diff line number Diff line change
Expand Up @@ -22,10 +22,15 @@ import (

const CommandRunnerShutdownTimeout = 5 * time.Second

type CommandHandler func(ctx context.Context, data map[string]interface{}) error
type CommandValidator func(data map[string]interface{}) error
type CommandHandler func(ctx context.Context, request *CommandRequest) error
type CommandValidator func(request *CommandRequest) error
type CommandRunnerOption func(*CommandRunner)

type CommandRequest struct {
Data map[string]interface{}
ValidatorData interface{}
}

func WithTLS(config *tls.Config) CommandRunnerOption {
return func(r *CommandRunner) {
r.tlsConfig = config
Expand Down Expand Up @@ -242,14 +247,15 @@ func (r *CommandRunner) runAdminServer(ctx context.Context) error {
func (r *CommandRunner) runCommand(ctx context.Context, command string, data map[string]interface{}) error {
r.logger.Info().Str("command", command).Msg("received new command")
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

better to log the input and output of each command call.

  1. if it receives a command, it should log received new command
  2. if it has run the command, it should log finish running the command
  3. if it fails to run the command, it should log failed to run the command with the error message.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this will be done in a separate PR :)


req := &CommandRequest{Data: data}
if validator := r.getValidator(command); validator != nil {
if validationErr := validator(data); validationErr != nil {
if validationErr := validator(req); validationErr != nil {
return status.Error(codes.InvalidArgument, validationErr.Error())
}
}

if handler := r.getHandler(command); handler != nil {
if handleErr := handler(ctx, data); handleErr != nil {
if handleErr := handler(ctx, req); handleErr != nil {
if errors.Is(handleErr, context.Canceled) {
return status.Error(codes.Canceled, "client canceled")
} else if errors.Is(handleErr, context.DeadlineExceeded) {
Expand Down
24 changes: 12 additions & 12 deletions admin/command_runner_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -86,15 +86,15 @@ func (suite *CommandRunnerSuite) SetupCommandRunner(opts ...CommandRunnerOption)
func (suite *CommandRunnerSuite) TestHandler() {
called := false

suite.bootstrapper.RegisterHandler("foo", func(ctx context.Context, data map[string]interface{}) error {
suite.bootstrapper.RegisterHandler("foo", func(ctx context.Context, req *CommandRequest) error {
select {
case <-ctx.Done():
return ctx.Err()
default:
}

suite.EqualValues(data["string"], "foo")
suite.EqualValues(data["number"], 123)
suite.EqualValues(req.Data["string"], "foo")
suite.EqualValues(req.Data["number"], 123)
called = true

return nil
Expand Down Expand Up @@ -142,7 +142,7 @@ func (suite *CommandRunnerSuite) TestUnimplementedHandler() {
func (suite *CommandRunnerSuite) TestValidator() {
calls := 0

suite.bootstrapper.RegisterHandler("foo", func(ctx context.Context, data map[string]interface{}) error {
suite.bootstrapper.RegisterHandler("foo", func(ctx context.Context, req *CommandRequest) error {
select {
case <-ctx.Done():
return ctx.Err()
Expand All @@ -155,8 +155,8 @@ func (suite *CommandRunnerSuite) TestValidator() {
})

validatorErr := errors.New("unexpected value")
suite.bootstrapper.RegisterValidator("foo", func(data map[string]interface{}) error {
if data["key"] != "value" {
suite.bootstrapper.RegisterValidator("foo", func(req *CommandRequest) error {
if req.Data["key"] != "value" {
return validatorErr
}
return nil
Expand Down Expand Up @@ -192,7 +192,7 @@ func (suite *CommandRunnerSuite) TestValidator() {

func (suite *CommandRunnerSuite) TestHandlerError() {
handlerErr := errors.New("handler error")
suite.bootstrapper.RegisterHandler("foo", func(ctx context.Context, data map[string]interface{}) error {
suite.bootstrapper.RegisterHandler("foo", func(ctx context.Context, req *CommandRequest) error {
select {
case <-ctx.Done():
return ctx.Err()
Expand Down Expand Up @@ -222,7 +222,7 @@ func (suite *CommandRunnerSuite) TestHandlerError() {
}

func (suite *CommandRunnerSuite) TestTimeout() {
suite.bootstrapper.RegisterHandler("foo", func(ctx context.Context, data map[string]interface{}) error {
suite.bootstrapper.RegisterHandler("foo", func(ctx context.Context, req *CommandRequest) error {
<-ctx.Done()
return ctx.Err()
})
Expand All @@ -248,14 +248,14 @@ func (suite *CommandRunnerSuite) TestTimeout() {
func (suite *CommandRunnerSuite) TestHTTPServer() {
called := false

suite.bootstrapper.RegisterHandler("foo", func(ctx context.Context, data map[string]interface{}) error {
suite.bootstrapper.RegisterHandler("foo", func(ctx context.Context, req *CommandRequest) error {
select {
case <-ctx.Done():
return ctx.Err()
default:
}

suite.EqualValues(data["key"], "value")
suite.EqualValues(req.Data["key"], "value")
called = true

return nil
Expand Down Expand Up @@ -387,14 +387,14 @@ func generateCerts(t *testing.T) (tls.Certificate, *x509.CertPool, tls.Certifica
func (suite *CommandRunnerSuite) TestTLS() {
called := false

suite.bootstrapper.RegisterHandler("foo", func(ctx context.Context, data map[string]interface{}) error {
suite.bootstrapper.RegisterHandler("foo", func(ctx context.Context, req *CommandRequest) error {
select {
case <-ctx.Done():
return ctx.Err()
default:
}

suite.EqualValues(data["key"], "value")
suite.EqualValues(req.Data["key"], "value")
called = true

return nil
Expand Down
8 changes: 8 additions & 0 deletions admin/commands/command.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,8 @@
package commands

import "github.com/onflow/flow-go/admin"

type AdminCommand struct {
Handler admin.CommandHandler
Validator admin.CommandValidator
}
36 changes: 36 additions & 0 deletions admin/commands/common/set_log_level.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,36 @@
package common

import (
"context"
"errors"
"fmt"

"github.com/rs/zerolog"

"github.com/onflow/flow-go/admin"
"github.com/onflow/flow-go/admin/commands"
)

var SetLogLevelCommand commands.AdminCommand = commands.AdminCommand{
Handler: func(ctx context.Context, req *admin.CommandRequest) error {
level := req.ValidatorData.(zerolog.Level)
zerolog.SetGlobalLevel(level)
return nil
},
Validator: func(req *admin.CommandRequest) error {
level, ok := req.Data["level"]
if !ok {
return errors.New("the \"level\" field must be provided")
}
levelStr, ok := level.(string)
if !ok {
return errors.New("\"level\" must be a string")
}
logLevel, err := zerolog.ParseLevel(levelStr)
if err != nil {
return fmt.Errorf("failed to parse level: %w", err)
}
req.ValidatorData = logLevel
return nil
},
}
2 changes: 2 additions & 0 deletions cmd/access/node_builder/staked_access_node_builder.go
Original file line number Diff line number Diff line change
Expand Up @@ -90,6 +90,8 @@ func (builder *StakedAccessNodeBuilder) Initialize() error {
return err
}

builder.EnqueueAdminServerInit(ctx)
vishalchangrani marked this conversation as resolved.
Show resolved Hide resolved

builder.EnqueueTracer()

return nil
Expand Down
16 changes: 8 additions & 8 deletions cmd/node_builder.go
Original file line number Diff line number Diff line change
Expand Up @@ -104,10 +104,10 @@ type NodeBuilder interface {
// while for a node running as a library, the config fields are expected to be initialized by the caller.
type BaseConfig struct {
nodeIDHex string
adminAddr string
adminCert string
adminKey string
adminClientCAs string
AdminAddr string
AdminCert string
AdminKey string
AdminClientCAs string
BindAddr string
NodeRole string
datadir string
Expand Down Expand Up @@ -176,10 +176,10 @@ func DefaultBaseConfig() *BaseConfig {

return &BaseConfig{
nodeIDHex: NotSet,
adminAddr: NotSet,
adminCert: NotSet,
adminKey: NotSet,
adminClientCAs: NotSet,
AdminAddr: NotSet,
AdminCert: NotSet,
AdminKey: NotSet,
AdminClientCAs: NotSet,
BindAddr: NotSet,
BootstrapDir: "bootstrap",
datadir: datadir,
Expand Down
83 changes: 45 additions & 38 deletions cmd/scaffold.go
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@ import (
"github.com/spf13/pflag"

"github.com/onflow/flow-go/admin"
"github.com/onflow/flow-go/admin/commands/common"
"github.com/onflow/flow-go/cmd/build"
"github.com/onflow/flow-go/fvm"
"github.com/onflow/flow-go/model/bootstrap"
Expand Down Expand Up @@ -138,10 +139,10 @@ func (fnb *FlowNodeBuilder) BaseFlags() {
fnb.flags.UintVar(&fnb.BaseConfig.tracerSensitivity, "tracer-sensitivity", defaultConfig.tracerSensitivity,
"adjusts the level of sampling when tracing is enabled. 0 means capture everything, higher value results in less samples")

fnb.flags.StringVar(&fnb.BaseConfig.adminAddr, "admin-addr", defaultConfig.adminAddr, "address to bind on for admin HTTP server")
fnb.flags.StringVar(&fnb.BaseConfig.adminCert, "admin-cert", defaultConfig.adminCert, "admin cert file (for TLS)")
fnb.flags.StringVar(&fnb.BaseConfig.adminKey, "admin-key", defaultConfig.adminKey, "admin key file (for TLS)")
fnb.flags.StringVar(&fnb.BaseConfig.adminClientCAs, "admin-client-certs", defaultConfig.adminClientCAs, "admin client certs (for mutual TLS)")
fnb.flags.StringVar(&fnb.BaseConfig.AdminAddr, "admin-addr", defaultConfig.AdminAddr, "address to bind on for admin HTTP server")
fnb.flags.StringVar(&fnb.BaseConfig.AdminCert, "admin-cert", defaultConfig.AdminCert, "admin cert file (for TLS)")
fnb.flags.StringVar(&fnb.BaseConfig.AdminKey, "admin-key", defaultConfig.AdminKey, "admin key file (for TLS)")
fnb.flags.StringVar(&fnb.BaseConfig.AdminClientCAs, "admin-client-certs", defaultConfig.AdminClientCAs, "admin client certs (for mutual TLS)")

fnb.flags.DurationVar(&fnb.BaseConfig.DNSCacheTTL, "dns-cache-ttl", dns.DefaultTimeToLive, "time-to-live for dns cache")
fnb.flags.UintVar(&fnb.BaseConfig.guaranteesCacheSize, "guarantees-cache-size", bstorage.DefaultCacheSize, "collection guarantees cache size")
Expand Down Expand Up @@ -261,37 +262,44 @@ func (fnb *FlowNodeBuilder) EnqueueMetricsServerInit() {
}

func (fnb *FlowNodeBuilder) EnqueueAdminServerInit(ctx context.Context) {
fnb.Component("admin server", func(builder NodeBuilder, node *NodeConfig) (module.ReadyDoneAware, error) {
var opts []admin.CommandRunnerOption
if fnb.AdminAddr != NotSet {
if (fnb.AdminCert != NotSet || fnb.AdminKey != NotSet || fnb.AdminClientCAs != NotSet) &&
!(fnb.AdminCert != NotSet && fnb.AdminKey != NotSet && fnb.AdminClientCAs != NotSet) {
fnb.Logger.Fatal().Msg("admin cert / key and client certs must all be provided to enable mutual TLS")
}
fnb.RegisterDefaultAdminCommands()
fnb.Component("admin server", func(builder NodeBuilder, node *NodeConfig) (module.ReadyDoneAware, error) {
var opts []admin.CommandRunnerOption

if node.adminCert != NotSet {
serverCert, err := tls.LoadX509KeyPair(node.adminCert, node.adminKey)
if err != nil {
return nil, err
if node.AdminCert != NotSet {
serverCert, err := tls.LoadX509KeyPair(node.AdminCert, node.AdminKey)
if err != nil {
return nil, err
}
clientCAs, err := ioutil.ReadFile(node.AdminClientCAs)
if err != nil {
return nil, err
}
certPool := x509.NewCertPool()
certPool.AppendCertsFromPEM(clientCAs)
config := &tls.Config{
MinVersion: tls.VersionTLS13,
Certificates: []tls.Certificate{serverCert},
ClientAuth: tls.RequireAndVerifyClientCert,
ClientCAs: certPool,
}

opts = append(opts, admin.WithTLS(config))
}
clientCAs, err := ioutil.ReadFile(node.adminClientCAs)
if err != nil {

command_runner := fnb.adminCommandBootstrapper.Bootstrap(fnb.Logger, fnb.AdminAddr, opts...)
if err := command_runner.Start(ctx); err != nil {
return nil, err
}
certPool := x509.NewCertPool()
certPool.AppendCertsFromPEM(clientCAs)
config := &tls.Config{
MinVersion: tls.VersionTLS13,
Certificates: []tls.Certificate{serverCert},
ClientAuth: tls.RequireAndVerifyClientCert,
ClientCAs: certPool,
}

opts = append(opts, admin.WithTLS(config))
}

command_runner := fnb.adminCommandBootstrapper.Bootstrap(fnb.Logger, fnb.adminAddr, opts...)
if err := command_runner.Start(ctx); err != nil {
return nil, err
}

return command_runner, nil
})
return command_runner, nil
})
}
}

func (fnb *FlowNodeBuilder) RegisterBadgerMetrics() error {
Expand Down Expand Up @@ -363,7 +371,8 @@ func (fnb *FlowNodeBuilder) initLogger() {
if err != nil {
log.Fatal().Err(err).Msg("invalid log level")
}
log = log.Level(lvl)
log = log.Level(zerolog.DebugLevel)
zerolog.SetGlobalLevel(lvl)
Comment on lines +390 to +391
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

why using debug level as global level?

Better to use InfoLevel as default

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The way this works, is that SetGlobalLevel sets the minimum level that will be logged, regardless of what the root logger has set.

So, I set the root logger to Debug level, and use SetGlobalLevel to set the actual level we want to use. This is the only way to make the log level dynamically configurable. I cannot do things the other way around, because once the root logger's level is set, you cannot change it.

Hope this makes sense.


fnb.Logger = log
}
Expand Down Expand Up @@ -915,19 +924,17 @@ func (fnb *FlowNodeBuilder) Initialize() error {
}
}

if fnb.adminAddr != NotSet {
if (fnb.adminCert != NotSet || fnb.adminKey != NotSet || fnb.adminClientCAs != NotSet) &&
!(fnb.adminCert != NotSet && fnb.adminKey != NotSet && fnb.adminClientCAs != NotSet) {
fnb.Logger.Fatal().Msg("admin cert / key and client certs must all be provided to enable mutual TLS")
}
fnb.EnqueueAdminServerInit(ctx)
}
fnb.EnqueueAdminServerInit(ctx)

fnb.EnqueueTracer()

return nil
}

func (fnb *FlowNodeBuilder) RegisterDefaultAdminCommands() {
fnb.AdminCommand("set-log-level", common.SetLogLevelCommand.Handler, common.SetLogLevelCommand.Validator)
}

// Run calls Ready() to start all the node modules and components. It also sets up a channel to gracefully shut
// down each component if a SIGINT is received. Until a SIGINT is received, Run will block.
// Since, Run is a blocking call it should only be used when running a node as it's own independent process.
Expand Down
2 changes: 1 addition & 1 deletion engine/common/synchronization/engine.go
Original file line number Diff line number Diff line change
Expand Up @@ -380,7 +380,7 @@ func (e *Engine) sendRequests(participants flow.IdentifierList, ranges []flow.Ra
errs = multierror.Append(errs, fmt.Errorf("could not submit range request: %w", err))
continue
}
e.log.Debug().
e.log.Info().
Uint64("range_from", req.FromHeight).
Uint64("range_to", req.ToHeight).
Uint64("range_nonce", req.Nonce).
Expand Down