diff --git a/client/methods/helpers.go b/client/methods/helpers.go index a97c92c104bdf3ee08f1d3d99c9d7c281eb21b36..3cc52eb3260749ff03c2df38ab59404b3570e10e 100644 --- a/client/methods/helpers.go +++ b/client/methods/helpers.go @@ -20,10 +20,10 @@ import ( "github.com/eris-ltd/eris-db/definitions" "github.com/eris-ltd/eris-db/logging" "github.com/eris-ltd/eris-db/logging/lifecycle" - "github.com/eris-ltd/eris-db/logging/loggers" + logging_types "github.com/eris-ltd/eris-db/logging/types" ) -func unpackSignAndBroadcast(result *rpc.TxResult, logger loggers.InfoTraceLogger) { +func unpackSignAndBroadcast(result *rpc.TxResult, logger logging_types.InfoTraceLogger) { if result == nil { // if we don't provide --sign or --broadcast return @@ -45,10 +45,14 @@ func unpackSignAndBroadcast(result *rpc.TxResult, logger loggers.InfoTraceLogger logging.InfoMsg(logger, "SignAndBroadcast result") } -func loggerFromClientDo(do *definitions.ClientDo, scope string) (loggers.InfoTraceLogger, error) { +func loggerFromClientDo(do *definitions.ClientDo, scope string) (logging_types.InfoTraceLogger, error) { lc, err := core.LoadLoggingConfigFromClientDo(do) if err != nil { return nil, err } - return logging.WithScope(lifecycle.NewLoggerFromLoggingConfig(lc), scope), nil + logger, err := lifecycle.NewLoggerFromLoggingConfig(lc) + if err != nil { + return nil, err + } + return logging.WithScope(logger, scope), nil } diff --git a/client/mock/client_mock.go b/client/mock/client_mock.go index f1e80895ff184f0f39ffd9dec3d5004d83afc852..0e2ce1ee5f9fee31a3ccb66babfab1864ff9305b 100644 --- a/client/mock/client_mock.go +++ b/client/mock/client_mock.go @@ -22,6 +22,7 @@ import ( consensus_types "github.com/eris-ltd/eris-db/consensus/types" core_types "github.com/eris-ltd/eris-db/core/types" "github.com/eris-ltd/eris-db/logging/loggers" + logging_types "github.com/eris-ltd/eris-db/logging/types" "github.com/eris-ltd/eris-db/txs" ) @@ -117,6 +118,6 @@ func (mock *MockNodeClient) ListValidators() (blockHeight int, bondedValidators, return 0, nil, nil, nil } -func (mock *MockNodeClient) Logger() loggers.InfoTraceLogger { +func (mock *MockNodeClient) Logger() logging_types.InfoTraceLogger { return loggers.NewNoopInfoTraceLogger() } diff --git a/client/node_client.go b/client/node_client.go index 56dd425e22498741cb6efae6c6e381111a20e24d..078351e598bea6a6a4ca24d70165c6c3ed4b0732 100644 --- a/client/node_client.go +++ b/client/node_client.go @@ -24,7 +24,7 @@ import ( consensus_types "github.com/eris-ltd/eris-db/consensus/types" core_types "github.com/eris-ltd/eris-db/core/types" "github.com/eris-ltd/eris-db/logging" - "github.com/eris-ltd/eris-db/logging/loggers" + logging_types "github.com/eris-ltd/eris-db/logging/types" tendermint_client "github.com/eris-ltd/eris-db/rpc/tendermint/client" tendermint_types "github.com/eris-ltd/eris-db/rpc/tendermint/core/types" "github.com/eris-ltd/eris-db/txs" @@ -46,7 +46,7 @@ type NodeClient interface { ListValidators() (blockHeight int, bondedValidators, unbondingValidators []consensus_types.Validator, err error) // Logging context for this NodeClient - Logger() loggers.InfoTraceLogger + Logger() logging_types.InfoTraceLogger } type NodeWebsocketClient interface { @@ -64,12 +64,12 @@ var _ NodeClient = (*erisNodeClient)(nil) // Eris-Client is a simple struct exposing the client rpc methods type erisNodeClient struct { broadcastRPC string - logger loggers.InfoTraceLogger + logger logging_types.InfoTraceLogger } // ErisKeyClient.New returns a new eris-keys client for provided rpc location // Eris-keys connects over http request-responses -func NewErisNodeClient(rpcString string, logger loggers.InfoTraceLogger) *erisNodeClient { +func NewErisNodeClient(rpcString string, logger logging_types.InfoTraceLogger) *erisNodeClient { return &erisNodeClient{ broadcastRPC: rpcString, logger: logging.WithScope(logger, "ErisNodeClient"), @@ -265,6 +265,6 @@ func (erisNodeClient *erisNodeClient) ListValidators() (blockHeight int, return } -func (erisNodeClient *erisNodeClient) Logger() loggers.InfoTraceLogger { +func (erisNodeClient *erisNodeClient) Logger() logging_types.InfoTraceLogger { return erisNodeClient.logger } diff --git a/client/websocket_client.go b/client/websocket_client.go index d3949e652f2ab40ee357bdb95910f9032626e938..8534acff4471d5226045ac5083f0dbfa814c976d 100644 --- a/client/websocket_client.go +++ b/client/websocket_client.go @@ -19,11 +19,11 @@ import ( "fmt" "time" + logging_types "github.com/eris-ltd/eris-db/logging/types" "github.com/tendermint/go-rpc/client" "github.com/tendermint/go-wire" "github.com/eris-ltd/eris-db/logging" - "github.com/eris-ltd/eris-db/logging/loggers" ctypes "github.com/eris-ltd/eris-db/rpc/tendermint/core/types" "github.com/eris-ltd/eris-db/txs" ) @@ -46,7 +46,7 @@ var _ NodeWebsocketClient = (*erisNodeWebsocketClient)(nil) type erisNodeWebsocketClient struct { // TODO: assert no memory leak on closing with open websocket tendermintWebsocket *rpcclient.WSClient - logger loggers.InfoTraceLogger + logger logging_types.InfoTraceLogger } // Subscribe to an eventid diff --git a/cmd/serve.go b/cmd/serve.go index 4eceefc3810603f8fb3e091ce09317a1606b2c1b..f8e49debadbb459db1113da9b2bf1c13125b63e4 100644 --- a/cmd/serve.go +++ b/cmd/serve.go @@ -108,8 +108,12 @@ func NewCoreFromDo(do *definitions.Do) (*core.Core, error) { return nil, fmt.Errorf("Failed to load logging config: %s", err) } + logger, err := lifecycle.NewLoggerFromLoggingConfig(loggerConfig) + if err != nil { + return nil, fmt.Errorf("Failed to build logger from logging config: %s", err) + } // Create a root logger to pass through to dependencies - logger := logging.WithScope(lifecycle.NewLoggerFromLoggingConfig(loggerConfig), "Serve") + logger = logging.WithScope(logger, "Serve") // Capture all logging from tendermint/tendermint and tendermint/go-* // dependencies lifecycle.CaptureTendermintLog15Output(logger) diff --git a/consensus/tendermint/tendermint.go b/consensus/tendermint/tendermint.go index 2eda6171daa4742efe486bb1c958128299fb99e0..783ba241791cf20d612cb605b6a56fb795728d83 100644 --- a/consensus/tendermint/tendermint.go +++ b/consensus/tendermint/tendermint.go @@ -35,7 +35,7 @@ import ( blockchain_types "github.com/eris-ltd/eris-db/blockchain/types" consensus_types "github.com/eris-ltd/eris-db/consensus/types" "github.com/eris-ltd/eris-db/logging" - "github.com/eris-ltd/eris-db/logging/loggers" + logging_types "github.com/eris-ltd/eris-db/logging/types" "github.com/eris-ltd/eris-db/txs" "github.com/tendermint/go-wire" ) @@ -44,7 +44,7 @@ type Tendermint struct { tmintNode *node.Node tmintConfig *TendermintConfig chainId string - logger loggers.InfoTraceLogger + logger logging_types.InfoTraceLogger } // Compiler checks to ensure Tendermint successfully implements @@ -54,7 +54,7 @@ var _ blockchain_types.Blockchain = (*Tendermint)(nil) func NewTendermint(moduleConfig *config.ModuleConfig, application manager_types.Application, - logger loggers.InfoTraceLogger) (*Tendermint, error) { + logger logging_types.InfoTraceLogger) (*Tendermint, error) { // re-assert proper configuration for module if moduleConfig.Version != GetTendermintVersion().GetMinorVersionString() { return nil, fmt.Errorf("Version string %s did not match %s", diff --git a/core/config.go b/core/config.go index eb4813956c40f0e7a4d0b1782bd64945d63d20bb..c6278384569a2308d98fa7169e7b873e4cc2184c 100644 --- a/core/config.go +++ b/core/config.go @@ -26,7 +26,7 @@ import ( "github.com/eris-ltd/eris-db/config" "github.com/eris-ltd/eris-db/consensus" "github.com/eris-ltd/eris-db/definitions" - "github.com/eris-ltd/eris-db/logging" + lctypes "github.com/eris-ltd/eris-db/logging/config/types" "github.com/eris-ltd/eris-db/manager" "github.com/eris-ltd/eris-db/server" "github.com/eris-ltd/eris-db/util" @@ -113,14 +113,14 @@ func LoadServerConfig(do *definitions.Do) (*server.ServerConfig, error) { return serverConfig, err } -func LoadLoggingConfigFromDo(do *definitions.Do) (*logging.LoggingConfig, error) { +func LoadLoggingConfigFromDo(do *definitions.Do) (*lctypes.LoggingConfig, error) { //subConfig, err := SubConfig(conf, "logging") - loggingConfig := &logging.LoggingConfig{} + loggingConfig := &lctypes.LoggingConfig{} return loggingConfig, nil } -func LoadLoggingConfigFromClientDo(do *definitions.ClientDo) (*logging.LoggingConfig, error) { - loggingConfig := &logging.LoggingConfig{} +func LoadLoggingConfigFromClientDo(do *definitions.ClientDo) (*lctypes.LoggingConfig, error) { + loggingConfig := &lctypes.LoggingConfig{} return loggingConfig, nil } diff --git a/core/core.go b/core/core.go index 14725b6c2ac137df77f856577f25e897ddc432c2..144b4d4ef267c900b477afa4d74920ecc2f273e0 100644 --- a/core/core.go +++ b/core/core.go @@ -30,7 +30,7 @@ import ( // rpc_tendermint is carried over from Eris-DBv0.11 and before on port 46657 "github.com/eris-ltd/eris-db/logging" - "github.com/eris-ltd/eris-db/logging/loggers" + logging_types "github.com/eris-ltd/eris-db/logging/types" rpc_tendermint "github.com/eris-ltd/eris-db/rpc/tendermint/core" "github.com/eris-ltd/eris-db/server" ) @@ -46,7 +46,7 @@ type Core struct { func NewCore(chainId string, consensusConfig *config.ModuleConfig, managerConfig *config.ModuleConfig, - logger loggers.InfoTraceLogger) (*Core, error) { + logger logging_types.InfoTraceLogger) (*Core, error) { // start new event switch, TODO: [ben] replace with eris-db/event evsw := events.NewEventSwitch() evsw.Start() diff --git a/definitions/pipe.go b/definitions/pipe.go index e00e46ed80fb10674222a55c29c92f276e814632..0eb205ff21b885588af1f8a5a2fb719aa31e810b 100644 --- a/definitions/pipe.go +++ b/definitions/pipe.go @@ -29,7 +29,7 @@ import ( core_types "github.com/eris-ltd/eris-db/core/types" types "github.com/eris-ltd/eris-db/core/types" event "github.com/eris-ltd/eris-db/event" - "github.com/eris-ltd/eris-db/logging/loggers" + logging_types "github.com/eris-ltd/eris-db/logging/types" manager_types "github.com/eris-ltd/eris-db/manager/types" "github.com/eris-ltd/eris-db/txs" ) @@ -42,7 +42,7 @@ type Pipe interface { Transactor() Transactor // Hash of Genesis state GenesisHash() []byte - Logger() loggers.InfoTraceLogger + Logger() logging_types.InfoTraceLogger // NOTE: [ben] added to Pipe interface on 0.12 refactor GetApplication() manager_types.Application SetConsensusEngine(consensusEngine consensus_types.ConsensusEngine) error diff --git a/event/events.go b/event/events.go index 5ada94a52e994f7497c111300c65205a86894d12..c43d0b43d81aa2372b8a32b6a3b68a4911a8e704 100644 --- a/event/events.go +++ b/event/events.go @@ -22,7 +22,7 @@ import ( "fmt" "github.com/eris-ltd/eris-db/logging" - "github.com/eris-ltd/eris-db/logging/loggers" + logging_types "github.com/eris-ltd/eris-db/logging/types" "github.com/eris-ltd/eris-db/txs" go_events "github.com/tendermint/go-events" tm_types "github.com/tendermint/tendermint/types" @@ -42,7 +42,7 @@ type EventEmitter interface { Unsubscribe(subId string) error } -func NewEvents(eventSwitch go_events.EventSwitch, logger loggers.InfoTraceLogger) *events { +func NewEvents(eventSwitch go_events.EventSwitch, logger logging_types.InfoTraceLogger) *events { return &events{eventSwitch: eventSwitch, logger: logging.WithScope(logger, "Events")} } @@ -56,7 +56,7 @@ func Multiplex(events ...EventEmitter) *multiplexedEvents { // The events struct has methods for working with events. type events struct { eventSwitch go_events.EventSwitch - logger loggers.InfoTraceLogger + logger logging_types.InfoTraceLogger } // Subscribe to an event. diff --git a/glide.yaml b/glide.yaml index ed8e097c2828278365c0e7d158acd11a5a9fb6f5..35c29142daf31e378f402b25053c3d2d64a6f97e 100644 --- a/glide.yaml +++ b/glide.yaml @@ -32,3 +32,4 @@ import: - package: github.com/streadway/simpleuuid - package: github.com/Masterminds/glide version: ~0.12.3 +- package: github.com/Graylog2/go-gelf diff --git a/keys/key_client.go b/keys/key_client.go index edbc451123db1c069033cbce1cad4a1d0b2135b1..84a80085112ba04565516d2901ff20b322aab314 100644 --- a/keys/key_client.go +++ b/keys/key_client.go @@ -18,8 +18,8 @@ import ( "encoding/hex" "fmt" + logging_types "github.com/eris-ltd/eris-db/logging/types" "github.com/eris-ltd/eris-db/logging" - "github.com/eris-ltd/eris-db/logging/loggers" ) type KeyClient interface { @@ -36,12 +36,12 @@ var _ KeyClient = (*erisKeyClient)(nil) type erisKeyClient struct { rpcString string - logger loggers.InfoTraceLogger + logger logging_types.InfoTraceLogger } // erisKeyClient.New returns a new eris-keys client for provided rpc location // Eris-keys connects over http request-responses -func NewErisKeyClient(rpcString string, logger loggers.InfoTraceLogger) *erisKeyClient { +func NewErisKeyClient(rpcString string, logger logging_types.InfoTraceLogger) *erisKeyClient { return &erisKeyClient{ rpcString: rpcString, logger: logging.WithScope(logger, "ErisKeysClient"), diff --git a/keys/key_client_util.go b/keys/key_client_util.go index b59c61f6b37a9a1ffa2b21f6b7982eecd7f3fb12..98ffabd802a5923e97f4e14984ccc0b29a23dac8 100644 --- a/keys/key_client_util.go +++ b/keys/key_client_util.go @@ -22,7 +22,7 @@ import ( "net/http" "github.com/eris-ltd/eris-db/logging" - "github.com/eris-ltd/eris-db/logging/loggers" + logging_types "github.com/eris-ltd/eris-db/logging/types" ) // Eris-Keys server connects over http request-response structures @@ -32,7 +32,7 @@ type HTTPResponse struct { Error string } -func RequestResponse(addr, method string, args map[string]string, logger loggers.InfoTraceLogger) (string, error) { +func RequestResponse(addr, method string, args map[string]string, logger logging_types.InfoTraceLogger) (string, error) { body, err := json.Marshal(args) if err != nil { return "", err diff --git a/logging/adapters/logrus/logrus.go b/logging/adapters/logrus/logrus.go deleted file mode 100644 index 84b6837188e6c6712ef05461227b658372ccd0bb..0000000000000000000000000000000000000000 --- a/logging/adapters/logrus/logrus.go +++ /dev/null @@ -1,36 +0,0 @@ -// Copyright 2017 Monax Industries Limited -// -// Licensed under the Apache License, Version 2.0 (the "License"); -// you may not use this file except in compliance with the License. -// You may obtain a copy of the License at -// -// http://www.apache.org/licenses/LICENSE-2.0 -// -// Unless required by applicable law or agreed to in writing, software -// distributed under the License is distributed on an "AS IS" BASIS, -// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -// See the License for the specific language governing permissions and -// limitations under the License. - -package adapters - -import ( - "github.com/Sirupsen/logrus" - kitlog "github.com/go-kit/kit/log" -) - -type logrusLogger struct { - logger logrus.Logger -} - -var _ kitlog.Logger = (*logrusLogger)(nil) - -func NewLogrusLogger(logger logrus.Logger) *logrusLogger { - return &logrusLogger{ - logger: logger, - } -} - -func (ll *logrusLogger) Log(keyvals ...interface{}) error { - return nil -} diff --git a/logging/adapters/stdlib/capture.go b/logging/adapters/stdlib/capture.go index 3c8a2a88e14b4199b548c6cea441c67d3d1a90e5..4e8b6b6125d7cf19943482bac33d05e0d26c5d75 100644 --- a/logging/adapters/stdlib/capture.go +++ b/logging/adapters/stdlib/capture.go @@ -18,23 +18,23 @@ import ( "io" "log" - "github.com/eris-ltd/eris-db/logging/loggers" + "github.com/eris-ltd/eris-db/logging/types" kitlog "github.com/go-kit/kit/log" ) func Capture(stdLibLogger log.Logger, - logger loggers.InfoTraceLogger) io.Writer { + logger types.InfoTraceLogger) io.Writer { adapter := newAdapter(logger) stdLibLogger.SetOutput(adapter) return adapter } -func CaptureRootLogger(logger loggers.InfoTraceLogger) io.Writer { +func CaptureRootLogger(logger types.InfoTraceLogger) io.Writer { adapter := newAdapter(logger) log.SetOutput(adapter) return adapter } -func newAdapter(logger loggers.InfoTraceLogger) io.Writer { +func newAdapter(logger types.InfoTraceLogger) io.Writer { return kitlog.NewStdlibAdapter(logger) } diff --git a/logging/adapters/tendermint_log15/capture.go b/logging/adapters/tendermint_log15/capture.go index 64f5a139da1860ffc929c7e49c617be51099649b..b8fa60365da3d8708e7376ad7f089c3c69457a55 100644 --- a/logging/adapters/tendermint_log15/capture.go +++ b/logging/adapters/tendermint_log15/capture.go @@ -1,3 +1,4 @@ +package tendermint_log15 // Copyright 2017 Monax Industries Limited // // Licensed under the Apache License, Version 2.0 (the "License"); @@ -12,16 +13,14 @@ // See the License for the specific language governing permissions and // limitations under the License. -package adapters - import ( - "github.com/eris-ltd/eris-db/logging/loggers" + "github.com/eris-ltd/eris-db/logging/types" kitlog "github.com/go-kit/kit/log" "github.com/tendermint/log15" ) type infoTraceLoggerAsLog15Handler struct { - logger loggers.InfoTraceLogger + logger types.InfoTraceLogger } var _ log15.Handler = (*infoTraceLoggerAsLog15Handler)(nil) @@ -54,7 +53,7 @@ func Log15HandlerAsKitLogger(handler log15.Handler) kitlog.Logger { } } -func InfoTraceLoggerAsLog15Handler(logger loggers.InfoTraceLogger) log15.Handler { +func InfoTraceLoggerAsLog15Handler(logger types.InfoTraceLogger) log15.Handler { return &infoTraceLoggerAsLog15Handler{ logger: logger, } diff --git a/logging/adapters/tendermint_log15/convert.go b/logging/adapters/tendermint_log15/convert.go index f1668b262ab0dac75948274da43c97c52d12b0e3..fa7dc08bc48d72ccdfbafb9309aa26fb84789fc3 100644 --- a/logging/adapters/tendermint_log15/convert.go +++ b/logging/adapters/tendermint_log15/convert.go @@ -12,13 +12,13 @@ // See the License for the specific language governing permissions and // limitations under the License. -package adapters +package tendermint_log15 import ( "time" - "github.com/eris-ltd/eris-db/logging/loggers" "github.com/eris-ltd/eris-db/logging/structure" + "github.com/eris-ltd/eris-db/logging/types" . "github.com/eris-ltd/eris-db/util/slice" "github.com/go-stack/stack" "github.com/tendermint/log15" @@ -70,9 +70,9 @@ func Log15LvlFromString(level string) log15.Lvl { return log15.LvlDebug } switch level { - case loggers.InfoLevelName: + case types.InfoLevelName: return log15.LvlInfo - case loggers.TraceLevelName: + case types.TraceLevelName: return log15.LvlDebug default: lvl, err := log15.LvlFromString(level) diff --git a/logging/config.go b/logging/config.go deleted file mode 100644 index 5123b93695f9ee60ecb38e50ef58ad040fd6780c..0000000000000000000000000000000000000000 --- a/logging/config.go +++ /dev/null @@ -1,25 +0,0 @@ -// Copyright 2017 Monax Industries Limited -// -// Licensed under the Apache License, Version 2.0 (the "License"); -// you may not use this file except in compliance with the License. -// You may obtain a copy of the License at -// -// http://www.apache.org/licenses/LICENSE-2.0 -// -// Unless required by applicable law or agreed to in writing, software -// distributed under the License is distributed on an "AS IS" BASIS, -// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -// See the License for the specific language governing permissions and -// limitations under the License. - -package logging - -type ( - SinkConfig struct { - Channels []string - } - - LoggingConfig struct { - Sinks []SinkConfig - } -) diff --git a/logging/config/config.go b/logging/config/config.go new file mode 100644 index 0000000000000000000000000000000000000000..f3921b062d8ef2ea37803cfa7e8e91f6abfd18fc --- /dev/null +++ b/logging/config/config.go @@ -0,0 +1,2 @@ +package config + diff --git a/logging/config/config_test.go b/logging/config/config_test.go new file mode 100644 index 0000000000000000000000000000000000000000..c4368dec9328dba9475beb53371cb7594f1274bc --- /dev/null +++ b/logging/config/config_test.go @@ -0,0 +1,12 @@ +package config + +import ( + "testing" + "github.com/spf13/viper" + "strings" +) + +func TestUnmarshal(t *testing.T) { + conf := viper.New() + conf.ReadConfig(strings.NewReader(``)) +} \ No newline at end of file diff --git a/logging/config/filter.go b/logging/config/filter.go new file mode 100644 index 0000000000000000000000000000000000000000..204a09299e3ffc56495c9de6be801a2dbd67329d --- /dev/null +++ b/logging/config/filter.go @@ -0,0 +1,114 @@ +package config + +import ( + "fmt" + "os" + + "regexp" + + "github.com/eapache/channels" + "github.com/eris-ltd/eris-db/common/math/integral" + "github.com/eris-ltd/eris-db/logging/config/types" + "github.com/eris-ltd/eris-db/logging/loggers" + kitlog "github.com/go-kit/kit/log" +) + +func BuildFilterPredicate(filterConfig *types.FilterConfig) (func([]interface{}) bool, error) { + includePredicate, err := BuildKeyValuesPredicate(filterConfig.Include, true) + if err != nil { + return nil, err + } + excludePredicate, err := BuildKeyValuesPredicate(filterConfig.Exclude, false) + if err != nil { + return nil, err + } + return func(keyvals []interface{}) bool { + // When do we want to exclude a log line + return !includePredicate(keyvals) || excludePredicate(keyvals) + }, nil +} + +func BuildKeyValuesPredicate(kvpConfigs []*types.KeyValuePredicateConfig, + matchAll bool) (func([]interface{}) bool, error) { + length := len(kvpConfigs) + keyRegexes := make([]*regexp.Regexp, length) + valueRegexes := make([]*regexp.Regexp, length) + + // Compile all KV regexes + for i, kvpConfig := range kvpConfigs { + // Store a nil regex to indicate no key match should occur + if kvpConfig.KeyRegex != "" { + keyRegex, err := regexp.Compile(kvpConfig.KeyRegex) + if err != nil { + return nil, err + } + keyRegexes[i] = keyRegex + } + // Store a nil regex to indicate no value match should occur + if kvpConfig.ValueRegex != "" { + valueRegex, err := regexp.Compile(kvpConfig.ValueRegex) + if err != nil { + return nil, err + } + valueRegexes[i] = valueRegex + } + } + + return func(keyvals []interface{}) bool { + return matchLogLine(keyvals, keyRegexes, valueRegexes, matchAll) + }, nil +} + +// matchLogLine tries to match a log line by trying to match each key value pair with each pair of key value regexes +// if matchAll is true then matchLogLine returns true iff every key value regexes finds a match or the line or regexes +// are empty +func matchLogLine(keyvals []interface{}, keyRegexes, valueRegexes []*regexp.Regexp, matchAll bool) bool { + all := matchAll + // We should be passed an aligned list of keyRegexes and valueRegexes, but since we can't error here we'll guard + // against a failure of the caller to pass valid arguments + length := integral.MinInt(len(keyRegexes), len(valueRegexes)) + for i := 0; i < length; i++ { + matched := findMatchInLogLine(keyvals, keyRegexes[i], valueRegexes[i]) + if matchAll { + all = all && matched + } else if matched { + return true + } + } + return all +} + +func findMatchInLogLine(keyvals []interface{}, keyRegex, valueRegex *regexp.Regexp) bool { + for i := 0; i < 2*(len(keyvals)/2); i += 2 { + key := convertToString(keyvals[i]) + val := convertToString(keyvals[i+1]) + if key == nil && val == nil { + continue + } + // At least one of key or val could be converted from string, only match on either if the conversion worked + // Try to match on both key and value, falling back to a positive match if either or both or not supplied + if match(keyRegex, key) && match(valueRegex, val) { + return true + } + } + return false +} + +func match(regex *regexp.Regexp, text *string) bool { + // Always match on a nil regex (indicating no constraint on text), + // and otherwise never match on nil text (indicating a non-string convertible type) + return regex == nil || (text != nil && regex.MatchString(*text)) +} + +func convertToString(value interface{}) *string { + // We have the option of returning nil here to indicate a conversion was + // not possible/does not make sense. Although we are not opting to use it + // currently + switch v := value.(type) { + case string: + return &v + default: + s := fmt.Sprintf("%v", v) + return &s + } +} diff --git a/logging/config/filter_test.go b/logging/config/filter_test.go new file mode 100644 index 0000000000000000000000000000000000000000..a0bf18addc9dfb8bf16ed51a129f5072665ce9af --- /dev/null +++ b/logging/config/filter_test.go @@ -0,0 +1,54 @@ +package config + +import ( + "testing" + + "github.com/eris-ltd/eris-db/logging/config/types" + . "github.com/eris-ltd/eris-db/util/slice" + "github.com/stretchr/testify/assert" +) + +func TestBuildKeyValuesPredicateMatchAll(t *testing.T) { + conf := []*types.KeyValuePredicateConfig{ + { + KeyRegex: "Foo", + ValueRegex: "bar", + }, + } + kvp, err := BuildKeyValuesPredicate(conf, true) + assert.NoError(t, err) + assert.True(t, kvp(Slice("Foo", "bar", "Bosh", "Bish"))) +} + +func TestBuildKeyValuesPredicateMatchAny(t *testing.T) { + conf := []*types.KeyValuePredicateConfig{ + { + KeyRegex: "Bosh", + ValueRegex: "Bish", + }, + } + kvp, err := BuildKeyValuesPredicate(conf, false) + assert.NoError(t, err) + assert.True(t, kvp(Slice("Foo", "bar", "Bosh", "Bish"))) +} + +func TestBuildFilterPredicate(t *testing.T) { + fc := &types.FilterConfig{ + Include: []*types.KeyValuePredicateConfig{ + { + KeyRegex: "^Foo$", + }, + }, + Exclude: []*types.KeyValuePredicateConfig{ + { + KeyRegex: "Bosh", + ValueRegex: "Bish", + }, + }, + } + fp, err := BuildFilterPredicate(fc) + assert.NoError(t, err) + assert.False(t, fp(Slice("Foo", "bar", "Shoes", 42))) + assert.True(t, fp(Slice("Foo", "bar", "Shoes", 42, "Bosh", "Bish"))) + assert.True(t, fp(Slice("Food", 0.2, "Shoes", 42))) +} diff --git a/logging/config/sinks.go b/logging/config/sinks.go new file mode 100644 index 0000000000000000000000000000000000000000..080f7c42ed38161d051fd6df136df9146441b364 --- /dev/null +++ b/logging/config/sinks.go @@ -0,0 +1,103 @@ +package config + +import ( + "fmt" + "os" + + "regexp" + + "github.com/eapache/channels" + "github.com/eris-ltd/eris-db/common/math/integral" + "github.com/eris-ltd/eris-db/logging/config/types" + "github.com/eris-ltd/eris-db/logging/loggers" + kitlog "github.com/go-kit/kit/log" +) + +func BuildLoggerFromRootSinkConfig(sinkConfig *types.SinkConfig) (kitlog.Logger, map[string]*loggers.ChannelLogger, error) { + return BuildLoggerFromSinkConfig(sinkConfig, make(map[string]*loggers.ChannelLogger)) +} + +func BuildLoggerFromSinkConfig(sinkConfig *types.SinkConfig, + captures map[string]*loggers.ChannelLogger) (kitlog.Logger, map[string]*loggers.ChannelLogger, error) { + if sinkConfig == nil { + return kitlog.NewNopLogger(), captures, nil + } + numSinks := len(sinkConfig.Sinks) + outputLoggers := make([]kitlog.Logger, numSinks, numSinks+1) + for i, sc := range sinkConfig.Sinks { + l, captures, err := BuildLoggerFromSinkConfig(sc, captures) + if err != nil { + return nil, captures, err + } + outputLoggers[i] = l + } + + if sinkConfig.Output != nil && sinkConfig.Output.OutputType != types.NoOutput { + l, err := BuildOutputLogger(sinkConfig.Output) + if err != nil { + return nil, captures, err + } + outputLoggers = append(outputLoggers, l) + } + + outputLogger := loggers.NewMultipleOutputLogger(outputLoggers...) + + if sinkConfig.Transform != nil && sinkConfig.Transform.TransformType != types.NoTransform { + return BuildTransformLogger(sinkConfig.Transform, captures, outputLogger) + } + return outputLogger, captures, nil +} + +func BuildOutputLogger(outputConfig *types.OutputConfig) (kitlog.Logger, error) { + switch outputConfig.OutputType { + case types.NoOutput: + return kitlog.NewNopLogger(), nil + //case types.Graylog: + //case types.Syslog: + case types.Stdout: + return loggers.NewStreamLogger(os.Stdout), nil + case types.Stderr: + return loggers.NewStreamLogger(os.Stderr), nil + case types.File: + return loggers.NewFileLogger(outputConfig.FileConfig.Path) + default: + return nil, fmt.Errorf("Could not build logger for output: '%s'", outputConfig.OutputType) + } +} + +func BuildTransformLogger(transformConfig *types.TransformConfig, captures map[string]*loggers.ChannelLogger, + outputLogger kitlog.Logger) (kitlog.Logger, map[string]*loggers.ChannelLogger, error) { + switch transformConfig.TransformType { + case types.NoTransform: + return outputLogger, captures, nil + case types.Label: + keyvals := make([]interface{}, 0, len(transformConfig.Labels)*2) + for k, v := range transformConfig.LabelConfig.Labels { + keyvals = append(keyvals, k, v) + } + if transformConfig.LabelConfig.Prefix { + return kitlog.NewContext(outputLogger).WithPrefix(keyvals...), captures, nil + } else { + return kitlog.NewContext(outputLogger).With(keyvals...), captures, nil + } + case types.Capture: + name := transformConfig.CaptureConfig.Name + if _, ok := captures[name]; ok { + return nil, captures, fmt.Errorf("Could not register new logging capture since name '%s' already "+ + "registered", name) + } + // Create a buffered channel logger to capture logs from upstream + cl := loggers.NewChannelLogger(channels.BufferCap(transformConfig.CaptureConfig.BufferCap)) + captures[name] = cl + // Return a logger that tees intput logs to this ChannelLogger and the passed in output logger + return loggers.NewMultipleOutputLogger(cl, outputLogger), captures, nil + case types.Filter: + predicate, err := BuildFilterPredicate(transformConfig.FilterConfig) + if err != nil { + return nil, captures, fmt.Errorf("Could not build filter predicate: '%s'", err) + } + return loggers.NewFilterLogger(outputLogger, predicate), captures, nil + default: + return nil, captures, fmt.Errorf("Could not build logger for transform: '%s'", transformConfig.TransformType) + } +} diff --git a/logging/config/sinks_test.go b/logging/config/sinks_test.go new file mode 100644 index 0000000000000000000000000000000000000000..d300901af39d210314068b8859e326914b9e0660 --- /dev/null +++ b/logging/config/sinks_test.go @@ -0,0 +1,56 @@ +package config + +import ( + "testing" + + "github.com/eris-ltd/eris-db/logging/config/types" + . "github.com/eris-ltd/eris-db/util/slice" + "github.com/stretchr/testify/assert" +) + +func TestBuildLoggerFromSinkConfig(t *testing.T) { + sinkConfig := &types.SinkConfig{ + Transform: &types.TransformConfig{ + TransformType: types.NoTransform, + }, + Sinks: []*types.SinkConfig{ + { + Transform: &types.TransformConfig{ + TransformType: types.NoTransform, + }, + Sinks: []*types.SinkConfig{ + { + Transform: &types.TransformConfig{ + TransformType: types.Capture, + CaptureConfig: &types.CaptureConfig{ + Name: "cap", + BufferCap: 100, + }, + }, + Output: &types.OutputConfig{ + OutputType: types.Stderr, + }, + Sinks: []*types.SinkConfig{ + { + Transform: &types.TransformConfig{ + TransformType: types.Label, + LabelConfig: &types.LabelConfig{ + Prefix: true, + Labels: map[string]string{"Label": "A Label!"}, + }, + }, + Output: &types.OutputConfig{ + OutputType: types.Stdout, + }, + }, + }, + }, + }, + }, + }, + } + logger, captures, err := BuildLoggerFromRootSinkConfig(sinkConfig) + logger.Log("Foo", "Bar") + assert.NoError(t, err) + assert.Equal(t, []interface{}{"Foo", "Bar"}, captures["cap"].WaitReadLogLine()) +} diff --git a/logging/config/types/types.go b/logging/config/types/types.go new file mode 100644 index 0000000000000000000000000000000000000000..ec72db6f4ff84fa90393ca300438c471b56b3414 --- /dev/null +++ b/logging/config/types/types.go @@ -0,0 +1,90 @@ +package types + +type Source string +type OutputType string +type TransformType string + +const ( + NoOutput OutputType = "" + Graylog OutputType = "Graylog" + Syslog OutputType = "Syslog" + File OutputType = "File" + Stdout OutputType = "Stdout" + Stderr OutputType = "Stderr" + + NoTransform TransformType = "" + // Filter log lines + Filter TransformType = "Filter" + // Remove key-val pairs from each log line + Prune TransformType = "Prune" + Capture TransformType = "Capture" + Label TransformType = "Label" +) + +type ( + // Outputs + GraylogConfig struct { + } + + SyslogConfig struct { + } + + FileConfig struct { + Path string + } + + OutputConfig struct { + OutputType OutputType + *GraylogConfig + *FileConfig + *SyslogConfig + } + + // Transforms + LabelConfig struct { + Labels map[string]string + Prefix bool + } + + CaptureConfig struct { + Name string + BufferCap int + } + + // Generates true if KeyRegex matches a log line key and ValueRegex matches that key's value. + // If ValueRegex is empty then returns true if any key matches + // If KeyRegex is empty then returns true if any value matches + KeyValuePredicateConfig struct { + KeyRegex string + ValueRegex string + } + + FilterConfig struct { + // Only include log lines if they match ALL predicates in Include or include all log lines if empty + Include []*KeyValuePredicateConfig + // Of those log lines included by Include, exclude log lines matching ANY predicate in Exclude or include all log lines if empty + Exclude []*KeyValuePredicateConfig + } + + TransformConfig struct { + TransformType TransformType + *LabelConfig + *CaptureConfig + *FilterConfig + } + + // Sink + // A Sink describes a logger that logs to zero or one output and logs to zero or more child sinks. + // before transmitting its log it applies zero or one transforms to the stream of log lines. + // by chaining together many Sinks arbitrary transforms to and multi + SinkConfig struct { + Transform *TransformConfig + Sinks []*SinkConfig + Output *OutputConfig + } + + LoggingConfig struct { + InfoSink *SinkConfig + InfoAndTraceSink *SinkConfig + } +) diff --git a/logging/convention.go b/logging/convention.go index 8dc5b05da97bc2b9bf267ed55e281a47989f32f6..34767154e1370c3d0c4c0a90e082ddb734988e00 100644 --- a/logging/convention.go +++ b/logging/convention.go @@ -15,7 +15,7 @@ package logging import ( - "github.com/eris-ltd/eris-db/logging/loggers" + "github.com/eris-ltd/eris-db/logging/types" "github.com/eris-ltd/eris-db/logging/structure" "github.com/eris-ltd/eris-db/util/slice" kitlog "github.com/go-kit/kit/log" @@ -25,23 +25,13 @@ import ( // to centralise and establish logging conventions on top of in with the base // logging interface -// Record structured Info log line with a message and conventional keys -func InfoMsgVals(logger loggers.InfoTraceLogger, message string, vals ...interface{}) { - MsgVals(kitlog.LoggerFunc(logger.Info), message, vals...) -} - -// Record structured Trace log line with a message and conventional keys -func TraceMsgVals(logger loggers.InfoTraceLogger, message string, vals ...interface{}) { - MsgVals(kitlog.LoggerFunc(logger.Trace), message, vals...) -} - // Record structured Info log line with a message -func InfoMsg(logger loggers.InfoTraceLogger, message string, keyvals ...interface{}) { +func InfoMsg(logger types.InfoTraceLogger, message string, keyvals ...interface{}) { Msg(kitlog.LoggerFunc(logger.Info), message, keyvals...) } // Record structured Trace log line with a message -func TraceMsg(logger loggers.InfoTraceLogger, message string, keyvals ...interface{}) { +func TraceMsg(logger types.InfoTraceLogger, message string, keyvals ...interface{}) { Msg(kitlog.LoggerFunc(logger.Trace), message, keyvals...) } @@ -49,7 +39,7 @@ func TraceMsg(logger loggers.InfoTraceLogger, message string, keyvals ...interfa // Like With the logging scope is append only but can be used to provide parenthetical scopes by hanging on to the // parent scope and using once the scope has been exited. The scope mechanism does is agnostic to the type of scope // so can be used to identify certain segments of the call stack, a lexical scope, or any other nested scope. -func WithScope(logger loggers.InfoTraceLogger, scopeName string) loggers.InfoTraceLogger { +func WithScope(logger types.InfoTraceLogger, scopeName string) types.InfoTraceLogger { // InfoTraceLogger will collapse successive (ScopeKey, scopeName) pairs into a vector in the order which they appear return logger.With(structure.ScopeKey, scopeName) } @@ -60,13 +50,3 @@ func Msg(logger kitlog.Logger, message string, keyvals ...interface{}) error { return logger.Log(prepended...) } -// Record a structured log line with a message and conventional keys -func MsgVals(logger kitlog.Logger, message string, vals ...interface{}) error { - keyvals := make([]interface{}, len(vals)*2) - for i := 0; i < len(vals); i++ { - kv := i * 2 - keyvals[kv] = structure.KeyFromValue(vals[i]) - keyvals[kv+1] = vals[i] - } - return Msg(logger, message, keyvals) -} diff --git a/logging/lifecycle/lifecycle.go b/logging/lifecycle/lifecycle.go index 81f6a20df8e14b0265ba7017b7115a413cd54863..c04ad6cc1f57b18c18ba6cb8b3ad161a02d3ec9d 100644 --- a/logging/lifecycle/lifecycle.go +++ b/logging/lifecycle/lifecycle.go @@ -23,9 +23,12 @@ import ( "github.com/eris-ltd/eris-db/logging" "github.com/eris-ltd/eris-db/logging/adapters/stdlib" tmLog15adapter "github.com/eris-ltd/eris-db/logging/adapters/tendermint_log15" + "github.com/eris-ltd/eris-db/logging/config" "github.com/eris-ltd/eris-db/logging/loggers" "github.com/eris-ltd/eris-db/logging/structure" + lctypes "github.com/eris-ltd/eris-db/logging/config/types" + "github.com/eris-ltd/eris-db/logging/types" kitlog "github.com/go-kit/kit/log" "github.com/streadway/simpleuuid" tmLog15 "github.com/tendermint/log15" @@ -35,22 +38,39 @@ import ( // to set up their root logger and capture any other logging output. // Obtain a logger from a LoggingConfig -func NewLoggerFromLoggingConfig(LoggingConfig *logging.LoggingConfig) loggers.InfoTraceLogger { - return NewStdErrLogger() +func NewLoggerFromLoggingConfig(loggingConfig *lctypes.LoggingConfig) (types.InfoTraceLogger, error) { + if loggingConfig == nil { + return NewStdErrLogger(), nil + } + infoOnlyLogger, infoAndTraceLogger, err := infoTraceLoggersLoggingConfig(loggingConfig) + if err != nil { + return nil, err + } + return NewLogger(infoOnlyLogger, infoAndTraceLogger), nil +} + +// Hot swap logging config by replacing output loggers of passed InfoTraceLogger with those built from loggingConfig +func SwapOutputLoggersFromLoggingConfig(logger types.InfoTraceLogger, loggingConfig *lctypes.LoggingConfig) error { + infoOnlyLogger, infoAndTraceLogger, err := infoTraceLoggersLoggingConfig(loggingConfig) + if err != nil { + return err + } + logger.SwapInfoOnlyOutput(infoOnlyLogger) + logger.SwapInfoAndTraceOutput(infoAndTraceLogger) + return nil } -func NewStdErrLogger() loggers.InfoTraceLogger { - logger := tmLog15adapter.Log15HandlerAsKitLogger( - tmLog15.StreamHandler(os.Stderr, tmLog15.TerminalFormat())) - return NewLogger(logger, logger) +func NewStdErrLogger() types.InfoTraceLogger { + logger := loggers.NewStreamLogger(os.Stderr) + return NewLogger(nil, logger) } // Provided a standard eris logger that outputs to the supplied underlying info and trace // loggers -func NewLogger(infoLogger, traceLogger kitlog.Logger) loggers.InfoTraceLogger { +func NewLogger(infoOnlyLogger, infoAndTraceLogger kitlog.Logger) types.InfoTraceLogger { infoTraceLogger := loggers.NewInfoTraceLogger( - loggers.ErisFormatLogger(infoLogger), - loggers.ErisFormatLogger(traceLogger)) + loggers.ErisFormatLogger(infoOnlyLogger), + loggers.ErisFormatLogger(infoAndTraceLogger)) // Create a random ID based on start time uuid, _ := simpleuuid.NewTime(time.Now()) var runId string @@ -60,13 +80,27 @@ func NewLogger(infoLogger, traceLogger kitlog.Logger) loggers.InfoTraceLogger { return logging.WithMetadata(infoTraceLogger.With(structure.RunId, runId)) } -func CaptureTendermintLog15Output(infoTraceLogger loggers.InfoTraceLogger) { +func CaptureTendermintLog15Output(infoTraceLogger types.InfoTraceLogger) { tmLog15.Root().SetHandler( tmLog15adapter.InfoTraceLoggerAsLog15Handler(infoTraceLogger. With(structure.CapturedLoggingSourceKey, "tendermint_log15"))) } -func CaptureStdlibLogOutput(infoTraceLogger loggers.InfoTraceLogger) { +func CaptureStdlibLogOutput(infoTraceLogger types.InfoTraceLogger) { stdlib.CaptureRootLogger(infoTraceLogger. With(structure.CapturedLoggingSourceKey, "stdlib_log")) } + +// Helpers + +func infoTraceLoggersLoggingConfig(loggingConfig *lctypes.LoggingConfig) (kitlog.Logger, kitlog.Logger, error) { + infoOnlyLogger, err := config.BuildLoggerFromSinkConfig(loggingConfig.InfoSink) + if err != nil { + return nil, nil, err + } + infoAndTraceLogger, err := config.BuildLoggerFromSinkConfig(loggingConfig.InfoAndTraceSink) + if err != nil { + return nil, nil, err + } + return infoOnlyLogger, infoAndTraceLogger, nil +} diff --git a/logging/lifecycle/lifecycle_test.go b/logging/lifecycle/lifecycle_test.go new file mode 100644 index 0000000000000000000000000000000000000000..f37d27b7f12729f42b9d832042113e05835613b8 --- /dev/null +++ b/logging/lifecycle/lifecycle_test.go @@ -0,0 +1,14 @@ +package lifecycle + +import ( + "testing" + "time" + "runtime" +) + +func TestNewStdErrLogger(t *testing.T) { + logger := NewStdErrLogger() + logger.Info("Quick", "Test") + time.Sleep(time.Second) + runtime.Gosched() +} diff --git a/logging/loggers/channel_logger.go b/logging/loggers/channel_logger.go index 1bacfa44697847389ab8b689f0a672cb3a3fa53b..5b6405d5b13047c2bfd6accf52ef667c6aa9721d 100644 --- a/logging/loggers/channel_logger.go +++ b/logging/loggers/channel_logger.go @@ -20,7 +20,7 @@ import ( ) const ( - LoggingRingBufferCap channels.BufferCap = 100 + DefaultLoggingRingBufferCap channels.BufferCap = 100 ) type ChannelLogger struct { @@ -34,9 +34,9 @@ var _ kitlog.Logger = (*ChannelLogger)(nil) // We would like calls to Log to never block so we use a channel implementation // that is non-blocking on writes and is able to be so by using a finite ring // buffer. -func newChannelLogger() *ChannelLogger { +func NewChannelLogger(loggingRingBufferCap channels.BufferCap) *ChannelLogger { return &ChannelLogger{ - ch: channels.NewRingChannel(LoggingRingBufferCap), + ch: channels.NewRingChannel(loggingRingBufferCap), } } @@ -81,7 +81,7 @@ func (cl *ChannelLogger) DrainChannelToLogger(logger kitlog.Logger) { // Wraps an underlying Logger baseLogger to provide a Logger that is // is non-blocking on calls to Log. func NonBlockingLogger(logger kitlog.Logger) *ChannelLogger { - cl := newChannelLogger() + cl := NewChannelLogger(DefaultLoggingRingBufferCap) go cl.DrainChannelToLogger(logger) return cl } diff --git a/logging/loggers/channel_logger_test.go b/logging/loggers/channel_logger_test.go index 0573556e15f70b11ec1163e36ab5435106e612ab..42cfd4ac9792337ab938ff766b029ae908078063 100644 --- a/logging/loggers/channel_logger_test.go +++ b/logging/loggers/channel_logger_test.go @@ -17,21 +17,21 @@ package loggers import ( "testing" - "fmt" - + "github.com/eapache/channels" "github.com/stretchr/testify/assert" ) func TestChannelLogger(t *testing.T) { - cl := newChannelLogger() + loggingRingBufferCap := channels.BufferCap(5) + cl := NewChannelLogger(loggingRingBufferCap) // Push a larger number of log messages than will fit into ring buffer - for i := 0; i < int(LoggingRingBufferCap)+10; i++ { + for i := 0; i < int(loggingRingBufferCap)+10; i++ { cl.Log("log line", i) } // Observe that oldest 10 messages are overwritten (so first message is 10) - for i := 0; i < int(LoggingRingBufferCap); i++ { + for i := 0; i < int(loggingRingBufferCap); i++ { ll := cl.WaitReadLogLine() assert.Equal(t, 10+i, ll[1]) } @@ -39,9 +39,3 @@ func TestChannelLogger(t *testing.T) { assert.Nil(t, cl.ReadLogLine(), "Since we have drained the buffer there "+ "should be no more log lines.") } - -func TestBlether(t *testing.T) { - var bs []byte - ext := append(bs) - fmt.Println(ext) -} diff --git a/logging/loggers/eris_format_logger.go b/logging/loggers/eris_format_logger.go index aea07254d4d0356620a40919f8caad7165bb3e43..651396dde87d1dd363c1dcf396e0b46f90d6687d 100644 --- a/logging/loggers/eris_format_logger.go +++ b/logging/loggers/eris_format_logger.go @@ -34,6 +34,9 @@ type erisFormatLogger struct { var _ kitlog.Logger = &erisFormatLogger{} func (efl *erisFormatLogger) Log(keyvals ...interface{}) error { + if efl.logger == nil { + return nil + } return efl.logger.Log(structure.MapKeyValues(keyvals, erisFormatKeyValueMapper)...) } diff --git a/logging/loggers/filter_logger.go b/logging/loggers/filter_logger.go new file mode 100644 index 0000000000000000000000000000000000000000..ba9e542f525c41ec0b54b1b8e292ee2e22134ab6 --- /dev/null +++ b/logging/loggers/filter_logger.go @@ -0,0 +1,28 @@ +package loggers + +import kitlog "github.com/go-kit/kit/log" + +// Filter logger allows us to filter lines logged to it before passing on to underlying +// output logger +type filterLogger struct { + logger kitlog.Logger + predicate func(keyvals []interface{}) bool +} + +var _ kitlog.Logger = (*filterLogger)(nil) + +func (fl filterLogger) Log(keyvals ...interface{}) error { + if !fl.predicate(keyvals) { + return fl.logger.Log(keyvals...) + } + return nil +} + +// Creates a logger that removes lines from output when the predicate evaluates true +func NewFilterLogger(outputLogger kitlog.Logger, + predicate func(keyvals []interface{}) bool) kitlog.Logger { + return &filterLogger{ + logger: outputLogger, + predicate: predicate, + } +} diff --git a/logging/loggers/filter_logger_test.go b/logging/loggers/filter_logger_test.go new file mode 100644 index 0000000000000000000000000000000000000000..dd900dba8964d1985fd5d64a40ae724f52488b5c --- /dev/null +++ b/logging/loggers/filter_logger_test.go @@ -0,0 +1,17 @@ +package loggers + +import ( + "testing" + "github.com/stretchr/testify/assert" + . "github.com/eris-ltd/eris-db/util/slice" +) + +func TestFilterLogger(t *testing.T) { + testLogger := newTestLogger() + filterLogger := NewFilterLogger(testLogger, func(keyvals []interface{}) bool { + return len(keyvals) > 0 && keyvals[0] == "Spoon" + }) + filterLogger.Log("Fish", "Present") + filterLogger.Log("Spoon", "Present") + assert.Equal(t, [][]interface{}{Slice("Fish", "Present")}, testLogger.logLines) +} diff --git a/logging/loggers/graylog_logger.go b/logging/loggers/graylog_logger.go new file mode 100644 index 0000000000000000000000000000000000000000..769cc92bb9e6cfabf5657b2876089e18f79f2dfd --- /dev/null +++ b/logging/loggers/graylog_logger.go @@ -0,0 +1 @@ +package loggers diff --git a/logging/loggers/info_trace_logger.go b/logging/loggers/info_trace_logger.go index e127e10feef184c68b26fa2fe15131e6d17da3ea..58596f306c466a58375ec4b6faa73f1be3ec3e29 100644 --- a/logging/loggers/info_trace_logger.go +++ b/logging/loggers/info_trace_logger.go @@ -17,125 +17,91 @@ package loggers import ( "github.com/eris-ltd/eris-db/logging/structure" kitlog "github.com/go-kit/kit/log" -) - -const ( - InfoChannelName = "Info" - TraceChannelName = "Trace" - - InfoLevelName = InfoChannelName - TraceLevelName = TraceChannelName + "github.com/eris-ltd/eris-db/logging/types" ) type infoTraceLogger struct { - infoLogger *kitlog.Context - traceLogger *kitlog.Context -} - -// InfoTraceLogger maintains two independent concurrently-safe channels of -// logging. The idea behind the independence is that you can ignore one channel -// with no performance penalty. For more fine grained filtering or aggregation -// the Info and Trace loggers can be decorated loggers that perform arbitrary -// filtering/routing/aggregation on log messages. -type InfoTraceLogger interface { - // Send a log message to the default channel - kitlog.Logger - - // Send an log message to the Info channel, formed of a sequence of key value - // pairs. Info messages should be operationally interesting to a human who is - // monitoring the logs. But not necessarily a human who is trying to - // understand or debug the system. Any handled errors or warnings should be - // sent to the Info channel (where you may wish to tag them with a suitable - // key-value pair to categorise them as such). - Info(keyvals ...interface{}) error - - // Send an log message to the Trace channel, formed of a sequence of key-value - // pairs. Trace messages can be used for any state change in the system that - // may be of interest to a machine consumer or a human who is trying to debug - // the system or trying to understand the system in detail. If the messages - // are very point-like and contain little structure, consider using a metric - // instead. - Trace(keyvals ...interface{}) error - - // A logging context (see go-kit log's Context). Takes a sequence key values - // via With or WithPrefix and ensures future calls to log will have those - // contextual values appended to the call to an underlying logger. - // Values can be dynamic by passing an instance of the kitlog.Valuer interface - // This provides an interface version of the kitlog.Context struct to be used - // For implementations that wrap a kitlog.Context. In addition it makes no - // assumption about the name or signature of the logging method(s). - // See InfoTraceLogger - - // Establish a context by appending contextual key-values to any existing - // contextual values - With(keyvals ...interface{}) InfoTraceLogger - - // Establish a context by prepending contextual key-values to any existing - // contextual values - WithPrefix(keyvals ...interface{}) InfoTraceLogger + infoOnly *kitlog.Context + infoAndTrace *kitlog.Context + infoOnlyOutputLogger *kitlog.SwapLogger + infoAndTraceOutputLogger *kitlog.SwapLogger } // Interface assertions -var _ InfoTraceLogger = (*infoTraceLogger)(nil) -var _ kitlog.Logger = (InfoTraceLogger)(nil) +var _ types.InfoTraceLogger = (*infoTraceLogger)(nil) +var _ kitlog.Logger = (types.InfoTraceLogger)(nil) -func NewInfoTraceLogger(infoLogger, traceLogger kitlog.Logger) InfoTraceLogger { +// Create an InfoTraceLogger by passing the initial ouput loggers. The infoOnlyLogger will only be sent messages from +// the Info channel. The infoAndTraceLogger will be sent messages from both the Info and Trace channels. +func NewInfoTraceLogger(infoOnlyLogger, infoAndTraceLogger kitlog.Logger) types.InfoTraceLogger { // We will never halt the progress of a log emitter. If log output takes too // long will start dropping log lines by using a ring buffer. - // We also guard against any concurrency bugs in underlying loggers by feeding - // them from a single channel - logger := kitlog.NewContext(NonBlockingLogger(VectorValuedLogger( - MultipleChannelLogger( - map[string]kitlog.Logger{ - InfoChannelName: infoLogger, - TraceChannelName: traceLogger, - })))) - return &infoTraceLogger{ - infoLogger: logger.With( - structure.ChannelKey, InfoChannelName, - structure.LevelKey, InfoLevelName, + var infoOnlyOutputLogger, infoTraceOutputLogger kitlog.SwapLogger + infoOnlyOutputLogger.Swap(infoOnlyLogger) + infoTraceOutputLogger.Swap(infoAndTraceLogger) + return &infoTraceLogger { + infoOnlyOutputLogger: &infoOnlyOutputLogger, + infoAndTraceOutputLogger: &infoTraceOutputLogger, + infoOnly: wrapLogger(&infoOnlyOutputLogger).With( + structure.ChannelKey, types.InfoChannelName, + structure.LevelKey, types.InfoLevelName, ), - traceLogger: logger.With( - structure.ChannelKey, TraceChannelName, - structure.LevelKey, TraceLevelName, + infoAndTrace: wrapLogger(&infoTraceOutputLogger).With( + structure.ChannelKey, types.TraceChannelName, + structure.LevelKey, types.TraceLevelName, ), } } -func NewNoopInfoTraceLogger() InfoTraceLogger { - noopLogger := kitlog.NewNopLogger() - return NewInfoTraceLogger(noopLogger, noopLogger) +func NewNoopInfoTraceLogger() types.InfoTraceLogger { + return NewInfoTraceLogger(nil, nil) } -func (l *infoTraceLogger) With(keyvals ...interface{}) InfoTraceLogger { +func (l *infoTraceLogger) With(keyvals ...interface{}) types.InfoTraceLogger { return &infoTraceLogger{ - infoLogger: l.infoLogger.With(keyvals...), - traceLogger: l.traceLogger.With(keyvals...), + infoOnly: l.infoOnly.With(keyvals...), + infoAndTrace: l.infoAndTrace.With(keyvals...), } } -func (l *infoTraceLogger) WithPrefix(keyvals ...interface{}) InfoTraceLogger { +func (l *infoTraceLogger) WithPrefix(keyvals ...interface{}) types.InfoTraceLogger { return &infoTraceLogger{ - infoLogger: l.infoLogger.WithPrefix(keyvals...), - traceLogger: l.traceLogger.WithPrefix(keyvals...), + infoOnly: l.infoOnly.WithPrefix(keyvals...), + infoAndTrace: l.infoAndTrace.WithPrefix(keyvals...), } } func (l *infoTraceLogger) Info(keyvals ...interface{}) error { - // We send Info and Trace log lines down the same pipe to keep them ordered - return l.infoLogger.Log(keyvals...) + // We log Info to the info only + l.infoOnly.Log(keyvals...) + // And pass to infoAndTrace + l.infoAndTrace.Log(keyvals...) + return nil } func (l *infoTraceLogger) Trace(keyvals ...interface{}) error { - return l.traceLogger.Log(keyvals...) + l.infoAndTrace.Log(keyvals...) + return nil +} + +func (l *infoTraceLogger) SwapInfoOnlyOutput(infoLogger kitlog.Logger) { + l.infoOnlyOutputLogger.Swap(infoLogger) +} + +func (l *infoTraceLogger) SwapInfoAndTraceOutput(infoTraceLogger kitlog.Logger) { + l.infoAndTraceOutputLogger.Swap(infoTraceLogger) } // If logged to as a plain kitlog logger presume the message is for Trace // This favours keeping Info reasonably quiet. Note that an InfoTraceLogger -// aware adapter can make its own choices, but we tend to thing of logs from +// aware adapter can make its own choices, but we tend to think of logs from // dependencies as less interesting than logs generated by us or specifically // routed by us. func (l *infoTraceLogger) Log(keyvals ...interface{}) error { l.Trace(keyvals...) return nil } + +func wrapLogger(logger kitlog.Logger) *kitlog.Context { + return kitlog.NewContext(NonBlockingLogger(VectorValuedLogger(logger))) +} diff --git a/logging/loggers/info_trace_logger_test.go b/logging/loggers/info_trace_logger_test.go index 1717455401d50c787be69f7a9ee99991c3836366..32527cd1109b36a3b8cf48b51a0e07159a658e27 100644 --- a/logging/loggers/info_trace_logger_test.go +++ b/logging/loggers/info_trace_logger_test.go @@ -26,3 +26,8 @@ func TestLogger(t *testing.T) { logger := NewInfoTraceLogger(stderrLogger, stderrLogger) logger.Trace("hello", "barry") } + +func TestNewNoopInfoTraceLogger(t *testing.T) { + logger := NewNoopInfoTraceLogger() + logger.Trace("goodbye", "trevor") +} \ No newline at end of file diff --git a/logging/loggers/multiple_output_logger.go b/logging/loggers/multiple_output_logger.go index 89ae50a978964758ead7891c5e79ece832cd87ce..143160247e681d1be61da1433825e8be9d5107d1 100644 --- a/logging/loggers/multiple_output_logger.go +++ b/logging/loggers/multiple_output_logger.go @@ -39,7 +39,16 @@ func (mol MultipleOutputLogger) Log(keyvals ...interface{}) error { // Creates a logger that forks log messages to each of its outputLoggers func NewMultipleOutputLogger(outputLoggers ...kitlog.Logger) kitlog.Logger { - return MultipleOutputLogger(outputLoggers) + moLogger := make(MultipleOutputLogger, 0, len(outputLoggers)) + // Flatten any MultipleOutputLoggers + for _, ol := range outputLoggers { + if ls, ok := ol.(MultipleOutputLogger); ok { + moLogger = append(moLogger, ls...) + } else { + moLogger = append(moLogger, ol) + } + } + return moLogger } type multipleErrors []error diff --git a/logging/loggers/tendermint_log15_loggers.go b/logging/loggers/tendermint_log15_loggers.go new file mode 100644 index 0000000000000000000000000000000000000000..62745d45b73b1c5f2095a99a23224fe2d636516d --- /dev/null +++ b/logging/loggers/tendermint_log15_loggers.go @@ -0,0 +1,18 @@ +package loggers + +import ( + "io" + + kitlog "github.com/go-kit/kit/log" + "github.com/tendermint/log15" + log15a "github.com/eris-ltd/eris-db/logging/adapters/tendermint_log15" +) + +func NewStreamLogger(writer io.Writer) kitlog.Logger { + return log15a.Log15HandlerAsKitLogger(log15.StreamHandler(writer, log15.TerminalFormat())) +} + +func NewFileLogger(path string) (kitlog.Logger, error) { + handler, err := log15.FileHandler(path, log15.LogfmtFormat()) + return log15a.Log15HandlerAsKitLogger(handler), err +} diff --git a/logging/metadata.go b/logging/metadata.go index 258ca733c749698d85bc26fca949bc5eed0d5a2b..1eb661f55df256fbad5b5885afb94a2dfdc8bda0 100644 --- a/logging/metadata.go +++ b/logging/metadata.go @@ -17,8 +17,8 @@ package logging import ( "time" - "github.com/eris-ltd/eris-db/logging/loggers" "github.com/eris-ltd/eris-db/logging/structure" + "github.com/eris-ltd/eris-db/logging/types" kitlog "github.com/go-kit/kit/log" "github.com/go-stack/stack" ) @@ -36,12 +36,12 @@ var defaultTimestampUTCValuer kitlog.Valuer = func() interface{} { return time.Now() } -func WithMetadata(infoTraceLogger loggers.InfoTraceLogger) loggers.InfoTraceLogger { +func WithMetadata(infoTraceLogger types.InfoTraceLogger) types.InfoTraceLogger { return infoTraceLogger.With(structure.TimeKey, defaultTimestampUTCValuer, structure.CallerKey, kitlog.Caller(infoTraceLoggerCallDepth), - "trace", TraceValuer()) + structure.TraceKey, TraceValuer()) } func TraceValuer() kitlog.Valuer { - return func() interface{} { return stack.Trace() } + return func() interface{} { return stack.Trace().TrimBelow(stack.Caller(infoTraceLoggerCallDepth - 1)) } } diff --git a/logging/structure/structure.go b/logging/structure/structure.go index 43a55df87f7cd2f93a859dce5980ada59964e843..63bd0e16ff3b61ad119196e23414bac9600e332a 100644 --- a/logging/structure/structure.go +++ b/logging/structure/structure.go @@ -14,21 +14,19 @@ package structure -import ( - "reflect" - - . "github.com/eris-ltd/eris-db/util/slice" -) +import . "github.com/eris-ltd/eris-db/util/slice" const ( // Log time (time.Time) TimeKey = "time" // Call site for log invocation (go-stack.Call) CallerKey = "caller" + // Trace for log call + TraceKey = "trace" // Level name (string) LevelKey = "level" // Channel name in a vector channel logging context - ChannelKey = "channel" + ChannelKey = "log_channel" // Log message (string) MessageKey = "message" // Captured logging source (like tendermint_log15, stdlib_log) @@ -136,18 +134,6 @@ func Value(keyvals []interface{}, key interface{}) interface{} { return nil } -// Obtain a canonical key from a value. Useful for structured logging where the -// type of value alone may be sufficient to determine its key. Providing this -// function centralises any convention over type names -func KeyFromValue(val interface{}) string { - switch val.(type) { - case string: - return "text" - default: - return reflect.TypeOf(val).Name() - } -} - // Maps key values pairs with a function (key, value) -> (new key, new value) func MapKeyValues(keyvals []interface{}, fn func(interface{}, interface{}) (interface{}, interface{})) []interface{} { mappedKeyvals := make([]interface{}, len(keyvals)) diff --git a/logging/types/info_trace_logger.go b/logging/types/info_trace_logger.go new file mode 100644 index 0000000000000000000000000000000000000000..68e76eb548cbc6e7e9d7524d5320f59190a5093f --- /dev/null +++ b/logging/types/info_trace_logger.go @@ -0,0 +1,66 @@ +package types + +import kitlog "github.com/go-kit/kit/log" + +const ( + InfoChannelName = "Info" + TraceChannelName = "Trace" + + InfoLevelName = InfoChannelName + TraceLevelName = TraceChannelName +) + +// InfoTraceLogger maintains two independent concurrently-safe channels of +// logging. The idea behind the independence is that you can ignore one channel +// with no performance penalty. For more fine grained filtering or aggregation +// the Info and Trace loggers can be decorated loggers that perform arbitrary +// filtering/routing/aggregation on log messages. +type InfoTraceLogger interface { + // Send a log message to the default channel + kitlog.Logger + + // Send an log message to the Info channel, formed of a sequence of key value + // pairs. Info messages should be operationally interesting to a human who is + // monitoring the logs. But not necessarily a human who is trying to + // understand or debug the system. Any handled errors or warnings should be + // sent to the Info channel (where you may wish to tag them with a suitable + // key-value pair to categorise them as such). Info messages will be sent to + // the infoOnly and the infoAndTrace output loggers. + Info(keyvals ...interface{}) error + + // Send an log message to the Trace channel, formed of a sequence of key-value + // pairs. Trace messages can be used for any state change in the system that + // may be of interest to a machine consumer or a human who is trying to debug + // the system or trying to understand the system in detail. If the messages + // are very point-like and contain little structure, consider using a metric + // instead. Trace messages will only be sent to the infoAndTrace output logger. + Trace(keyvals ...interface{}) error + + // A logging context (see go-kit log's Context). Takes a sequence key values + // via With or WithPrefix and ensures future calls to log will have those + // contextual values appended to the call to an underlying logger. + // Values can be dynamic by passing an instance of the kitlog.Valuer interface + // This provides an interface version of the kitlog.Context struct to be used + // For implementations that wrap a kitlog.Context. In addition it makes no + // assumption about the name or signature of the logging method(s). + // See InfoTraceLogger + + // Establish a context by appending contextual key-values to any existing + // contextual values + With(keyvals ...interface{}) InfoTraceLogger + + // Establish a context by prepending contextual key-values to any existing + // contextual values + WithPrefix(keyvals ...interface{}) InfoTraceLogger + + // Hot swap the underlying infoOnlyLogger with another one to re-route messages + // on the Info channel + SwapInfoOnlyOutput(infoOnlyLogger kitlog.Logger) + + // Hot swap the underlying infoAndTraceLogger with another one to re-route messages + // on the Info and Trace channels + SwapInfoAndTraceOutput(infoTraceLogger kitlog.Logger) +} + +// Interface assertions +var _ kitlog.Logger = (InfoTraceLogger)(nil) diff --git a/manager/eris-mint/eris-mint.go b/manager/eris-mint/eris-mint.go index 9ba18441832ecf6bce0b500ba99fca9bc41b3a40..bb54c11b79001ee0e6e25b16b41c16c16eb9ec07 100644 --- a/manager/eris-mint/eris-mint.go +++ b/manager/eris-mint/eris-mint.go @@ -25,8 +25,8 @@ import ( wire "github.com/tendermint/go-wire" "github.com/eris-ltd/eris-db/logging" - "github.com/eris-ltd/eris-db/logging/loggers" + logging_types "github.com/eris-ltd/eris-db/logging/types" sm "github.com/eris-ltd/eris-db/manager/eris-mint/state" manager_types "github.com/eris-ltd/eris-db/manager/types" "github.com/eris-ltd/eris-db/txs" @@ -48,7 +48,7 @@ type ErisMint struct { evsw tendermint_events.EventSwitch nTxs int // count txs in a block - logger loggers.InfoTraceLogger + logger logging_types.InfoTraceLogger } // NOTE [ben] Compiler check to ensure ErisMint successfully implements @@ -72,7 +72,8 @@ func (app *ErisMint) GetCheckCache() *sm.BlockCache { return app.checkCache } -func NewErisMint(s *sm.State, evsw tendermint_events.EventSwitch, logger loggers.InfoTraceLogger) *ErisMint { +func NewErisMint(s *sm.State, evsw tendermint_events.EventSwitch, + logger logging_types.InfoTraceLogger) *ErisMint { return &ErisMint{ state: s, cache: sm.NewBlockCache(s), diff --git a/manager/eris-mint/pipe.go b/manager/eris-mint/pipe.go index f900b3f09d07989dbe8bdc8d244b5a8e2f5966b1..910727feed0af3a28bc2c9e7d88b682ccbccb721 100644 --- a/manager/eris-mint/pipe.go +++ b/manager/eris-mint/pipe.go @@ -35,7 +35,7 @@ import ( edb_event "github.com/eris-ltd/eris-db/event" genesis "github.com/eris-ltd/eris-db/genesis" "github.com/eris-ltd/eris-db/logging" - "github.com/eris-ltd/eris-db/logging/loggers" + logging_types "github.com/eris-ltd/eris-db/logging/types" vm "github.com/eris-ltd/eris-db/manager/eris-mint/evm" "github.com/eris-ltd/eris-db/manager/eris-mint/state" manager_types "github.com/eris-ltd/eris-db/manager/types" @@ -57,7 +57,7 @@ type erisMintPipe struct { // Genesis cache genesisDoc *genesis.GenesisDoc genesisState *state.State - logger loggers.InfoTraceLogger + logger logging_types.InfoTraceLogger } // NOTE [ben] Compiler check to ensure erisMintPipe successfully implements @@ -70,7 +70,7 @@ var _ definitions.TendermintPipe = (*erisMintPipe)(nil) func NewErisMintPipe(moduleConfig *config.ModuleConfig, eventSwitch go_events.EventSwitch, - logger loggers.InfoTraceLogger) (*erisMintPipe, error) { + logger logging_types.InfoTraceLogger) (*erisMintPipe, error) { startedState, genesisDoc, err := startState(moduleConfig.DataDir, moduleConfig.Config.GetString("db_backend"), moduleConfig.GenesisFile, @@ -180,7 +180,7 @@ func startState(dataDir, backend, genesisFile, chainId string) (*state.State, //------------------------------------------------------------------------------ // Implement definitions.Pipe for erisMintPipe -func (pipe *erisMintPipe) Logger() loggers.InfoTraceLogger { +func (pipe *erisMintPipe) Logger() logging_types.InfoTraceLogger { return pipe.logger } diff --git a/manager/manager.go b/manager/manager.go index d9a3b3d548044fbedbcc70ed292fd0eecaed1efe..103170f58d30d4715f233bdb8c15400b2c8f9254 100644 --- a/manager/manager.go +++ b/manager/manager.go @@ -21,11 +21,11 @@ import ( config "github.com/eris-ltd/eris-db/config" definitions "github.com/eris-ltd/eris-db/definitions" + logging_types "github.com/eris-ltd/eris-db/logging/types" erismint "github.com/eris-ltd/eris-db/manager/eris-mint" // types "github.com/eris-ltd/eris-db/manager/types" "github.com/eris-ltd/eris-db/logging" - "github.com/eris-ltd/eris-db/logging/loggers" ) // NewApplicationPipe returns an initialised Pipe interface @@ -34,7 +34,7 @@ import ( // of an application. It is feasible this will be insufficient to support // different types of applications later down the line. func NewApplicationPipe(moduleConfig *config.ModuleConfig, - evsw events.EventSwitch, logger loggers.InfoTraceLogger, + evsw events.EventSwitch, logger logging_types.InfoTraceLogger, consensusMinorVersion string) (definitions.Pipe, error) { switch moduleConfig.Name { diff --git a/rpc/v0/mock_pipe_test.go b/rpc/v0/mock_pipe_test.go index 6bb864d51f9cc57f42c2cdfbf56e7896ea088fca..b89f43cecf9af157820fd1331c5ff34a894a41c2 100644 --- a/rpc/v0/mock_pipe_test.go +++ b/rpc/v0/mock_pipe_test.go @@ -24,6 +24,7 @@ import ( blockchain_types "github.com/eris-ltd/eris-db/blockchain/types" consensus_types "github.com/eris-ltd/eris-db/consensus/types" + logging_types "github.com/eris-ltd/eris-db/logging/types" manager_types "github.com/eris-ltd/eris-db/manager/types" "github.com/eris-ltd/eris-db/txs" @@ -43,7 +44,7 @@ type MockPipe struct { events event.EventEmitter namereg definitions.NameReg transactor definitions.Transactor - logger loggers.InfoTraceLogger + logger logging_types.InfoTraceLogger } // Create a new mock tendermint pipe. @@ -85,7 +86,7 @@ func (pipe *MockPipe) Transactor() definitions.Transactor { return pipe.transactor } -func (pipe *MockPipe) Logger() loggers.InfoTraceLogger { +func (pipe *MockPipe) Logger() logging_types.InfoTraceLogger { return pipe.logger } diff --git a/util/slice/slice.go b/util/slice/slice.go index 8c2b7f8914b86539c04051f7077830c82ec4b835..485510ff78e6da218bb3cd6abf8628f41a0e449f 100644 --- a/util/slice/slice.go +++ b/util/slice/slice.go @@ -14,6 +14,7 @@ package slice +// Convenience function func Slice(elements ...interface{}) []interface{} { return elements }