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

Direct plugin logs through vault's logger #3142

Merged
merged 2 commits into from
Aug 15, 2017
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 3 additions & 2 deletions builtin/logical/database/dbplugin/client.go
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@ import (

"github.com/hashicorp/go-plugin"
"github.com/hashicorp/vault/helper/pluginutil"
log "github.com/mgutz/logxi/v1"
)

// DatabasePluginClient embeds a databasePluginRPCClient and wraps it's Close
Expand All @@ -29,13 +30,13 @@ func (dc *DatabasePluginClient) Close() error {
// newPluginClient returns a databaseRPCClient with a connection to a running
// plugin. The client is wrapped in a DatabasePluginClient object to ensure the
// plugin is killed on call of Close().
func newPluginClient(sys pluginutil.RunnerUtil, pluginRunner *pluginutil.PluginRunner) (Database, error) {
func newPluginClient(sys pluginutil.RunnerUtil, pluginRunner *pluginutil.PluginRunner, logger log.Logger) (Database, error) {
// pluginMap is the map of plugins we can dispense.
var pluginMap = map[string]plugin.Plugin{
"database": new(DatabasePlugin),
}

client, err := pluginRunner.Run(sys, pluginMap, handshakeConfig, []string{})
client, err := pluginRunner.Run(sys, pluginMap, handshakeConfig, []string{}, logger)
if err != nil {
return nil, err
}
Expand Down
2 changes: 1 addition & 1 deletion builtin/logical/database/dbplugin/plugin.go
Original file line number Diff line number Diff line change
Expand Up @@ -62,7 +62,7 @@ func PluginFactory(pluginName string, sys pluginutil.LookRunnerUtil, logger log.

} else {
// create a DatabasePluginClient instance
db, err = newPluginClient(sys, pluginRunner)
db, err = newPluginClient(sys, pluginRunner, logger)
if err != nil {
return nil, err
}
Expand Down
2 changes: 1 addition & 1 deletion builtin/plugin/backend.go
Original file line number Diff line number Diff line change
Expand Up @@ -30,7 +30,7 @@ func Backend(conf *logical.BackendConfig) (logical.Backend, error) {
name := conf.Config["plugin_name"]
sys := conf.System

b, err := bplugin.NewBackend(name, sys)
b, err := bplugin.NewBackend(name, sys, conf.Logger)
if err != nil {
return nil, err
}
Expand Down
4 changes: 3 additions & 1 deletion builtin/plugin/backend_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -4,12 +4,14 @@ import (
"os"
"testing"

"github.com/hashicorp/vault/helper/logformat"
"github.com/hashicorp/vault/helper/pluginutil"
vaulthttp "github.com/hashicorp/vault/http"
"github.com/hashicorp/vault/logical"
"github.com/hashicorp/vault/logical/plugin"
"github.com/hashicorp/vault/logical/plugin/mock"
"github.com/hashicorp/vault/vault"
log "github.com/mgutz/logxi/v1"
)

func TestBackend(t *testing.T) {
Expand Down Expand Up @@ -71,7 +73,7 @@ func testConfig(t *testing.T) (*logical.BackendConfig, func()) {
sys := vault.TestDynamicSystemView(core.Core)

config := &logical.BackendConfig{
Logger: nil,
Logger: logformat.NewVaultLogger(log.LevelTrace),
System: sys,
Config: map[string]string{
"plugin_name": "mock-plugin",
Expand Down
158 changes: 158 additions & 0 deletions helper/pluginutil/logger.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,158 @@
package pluginutil

import (
"bytes"
"fmt"
stdlog "log"
"strings"

hclog "github.com/hashicorp/go-hclog"
log "github.com/mgutz/logxi/v1"
)

// pluginLogFaker is a wrapper on logxi.Logger that
// implements hclog.Logger
type hclogFaker struct {
logger log.Logger

name string
implied []interface{}
}

func (f *hclogFaker) buildLog(msg string, args ...interface{}) (string, []interface{}) {
if f.name != "" {
msg = fmt.Sprintf("%s: %s", f.name, msg)
}
args = append(f.implied, args...)

return msg, args
}

func (f *hclogFaker) Trace(msg string, args ...interface{}) {
msg, args = f.buildLog(msg, args...)
f.logger.Trace(msg, args...)
}

func (f *hclogFaker) Debug(msg string, args ...interface{}) {
msg, args = f.buildLog(msg, args...)
f.logger.Debug(msg, args...)
}

func (f *hclogFaker) Info(msg string, args ...interface{}) {
msg, args = f.buildLog(msg, args...)
f.logger.Info(msg, args...)
}

func (f *hclogFaker) Warn(msg string, args ...interface{}) {
msg, args = f.buildLog(msg, args...)
f.logger.Warn(msg, args...)
}

func (f *hclogFaker) Error(msg string, args ...interface{}) {
msg, args = f.buildLog(msg, args...)
f.logger.Error(msg, args...)
}

func (f *hclogFaker) IsTrace() bool {
return f.logger.IsTrace()
}

func (f *hclogFaker) IsDebug() bool {
return f.logger.IsDebug()
}

func (f *hclogFaker) IsInfo() bool {
return f.logger.IsInfo()
}

func (f *hclogFaker) IsWarn() bool {
return f.logger.IsWarn()
}

func (f *hclogFaker) IsError() bool {
return !f.logger.IsTrace() && !f.logger.IsDebug() && !f.logger.IsInfo() && !f.IsWarn()
}

func (f *hclogFaker) With(args ...interface{}) hclog.Logger {
var nf = *f
Copy link
Member

Choose a reason for hiding this comment

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

Was this actually necessary? The pointer access should be transparent I thought.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I went with this since hclog was doing the same, unless it applies differently in that case: https://github.com/hashicorp/go-hclog/blob/master/int.go#L346

Copy link
Member

Choose a reason for hiding this comment

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

Pretty sure it's unnecessary there too. But it doesn't matter either way, really.

nf.implied = append(nf.implied, args...)
return f
}

func (f *hclogFaker) Named(name string) hclog.Logger {
var nf = *f
if nf.name != "" {
nf.name = nf.name + "." + name
}
return &nf
}

func (f *hclogFaker) ResetNamed(name string) hclog.Logger {
var nf = *f
nf.name = name
return &nf
}

func (f *hclogFaker) StandardLogger(opts *hclog.StandardLoggerOptions) *stdlog.Logger {
if opts == nil {
opts = &hclog.StandardLoggerOptions{}
}

return stdlog.New(&stdlogAdapter{f, opts.InferLevels}, "", 0)
}

// Provides a io.Writer to shim the data out of *log.Logger
// and back into our Logger. This is basically the only way to
// build upon *log.Logger.
type stdlogAdapter struct {
hl hclog.Logger
inferLevels bool
}

// Take the data, infer the levels if configured, and send it through
// a regular Logger
func (s *stdlogAdapter) Write(data []byte) (int, error) {
str := string(bytes.TrimRight(data, " \t\n"))

if s.inferLevels {
level, str := s.pickLevel(str)
switch level {
case hclog.Trace:
s.hl.Trace(str)
case hclog.Debug:
s.hl.Debug(str)
case hclog.Info:
s.hl.Info(str)
case hclog.Warn:
s.hl.Warn(str)
case hclog.Error:
s.hl.Error(str)
default:
s.hl.Info(str)
}
} else {
s.hl.Info(str)
}

return len(data), nil
}

// Detect, based on conventions, what log level this is
func (s *stdlogAdapter) pickLevel(str string) (hclog.Level, string) {
switch {
case strings.HasPrefix(str, "[DEBUG]"):
return hclog.Debug, strings.TrimSpace(str[7:])
case strings.HasPrefix(str, "[TRACE]"):
return hclog.Trace, strings.TrimSpace(str[7:])
case strings.HasPrefix(str, "[INFO]"):
return hclog.Info, strings.TrimSpace(str[6:])
case strings.HasPrefix(str, "[WARN]"):
return hclog.Warn, strings.TrimSpace(str[7:])
case strings.HasPrefix(str, "[ERROR]"):
return hclog.Error, strings.TrimSpace(str[7:])
case strings.HasPrefix(str, "[ERR]"):
return hclog.Error, strings.TrimSpace(str[5:])
default:
return hclog.Info, str
}
}
10 changes: 9 additions & 1 deletion helper/pluginutil/runner.go
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@ import (
plugin "github.com/hashicorp/go-plugin"
"github.com/hashicorp/vault/api"
"github.com/hashicorp/vault/helper/wrapping"
log "github.com/mgutz/logxi/v1"
)

// Looker defines the plugin Lookup function that looks into the plugin catalog
Expand Down Expand Up @@ -45,7 +46,7 @@ type PluginRunner struct {

// Run takes a wrapper instance, and the go-plugin paramaters and executes a
// plugin.
func (r *PluginRunner) Run(wrapper RunnerUtil, pluginMap map[string]plugin.Plugin, hs plugin.HandshakeConfig, env []string) (*plugin.Client, error) {
func (r *PluginRunner) Run(wrapper RunnerUtil, pluginMap map[string]plugin.Plugin, hs plugin.HandshakeConfig, env []string, logger log.Logger) (*plugin.Client, error) {
// Get a CA TLS Certificate
certBytes, key, err := generateCert()
if err != nil {
Expand Down Expand Up @@ -79,12 +80,19 @@ func (r *PluginRunner) Run(wrapper RunnerUtil, pluginMap map[string]plugin.Plugi
Hash: sha256.New(),
}

// Create logger for the plugin client
clogger := &hclogFaker{
logger: logger,
}
namedLogger := clogger.ResetNamed("plugin")

client := plugin.NewClient(&plugin.ClientConfig{
HandshakeConfig: hs,
Plugins: pluginMap,
Cmd: cmd,
TLSConfig: clientTLSConfig,
SecureConfig: secureConfig,
Logger: namedLogger,
})

return client, nil
Expand Down
5 changes: 2 additions & 3 deletions logical/plugin/backend_client.go
Original file line number Diff line number Diff line change
Expand Up @@ -11,9 +11,8 @@ import (
// backendPluginClient implements logical.Backend and is the
// go-plugin client.
type backendPluginClient struct {
broker *plugin.MuxBroker
client *rpc.Client
pluginClient *plugin.Client
broker *plugin.MuxBroker
client *rpc.Client

system logical.SystemView
logger log.Logger
Expand Down
9 changes: 5 additions & 4 deletions logical/plugin/plugin.go
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@ import (
"github.com/hashicorp/go-plugin"
"github.com/hashicorp/vault/helper/pluginutil"
"github.com/hashicorp/vault/logical"
log "github.com/mgutz/logxi/v1"
)

// Register these types since we have to serialize and de-serialize tls.ConnectionState
Expand Down Expand Up @@ -40,7 +41,7 @@ func (b *BackendPluginClient) Cleanup() {
// NewBackend will return an instance of an RPC-based client implementation of the backend for
// external plugins, or a concrete implementation of the backend if it is a builtin backend.
// The backend is returned as a logical.Backend interface.
func NewBackend(pluginName string, sys pluginutil.LookRunnerUtil) (logical.Backend, error) {
func NewBackend(pluginName string, sys pluginutil.LookRunnerUtil, logger log.Logger) (logical.Backend, error) {
// Look for plugin in the plugin catalog
pluginRunner, err := sys.LookupPlugin(pluginName)
if err != nil {
Expand All @@ -64,7 +65,7 @@ func NewBackend(pluginName string, sys pluginutil.LookRunnerUtil) (logical.Backe

} else {
// create a backendPluginClient instance
backend, err = newPluginClient(sys, pluginRunner)
backend, err = newPluginClient(sys, pluginRunner, logger)
if err != nil {
return nil, err
}
Expand All @@ -73,12 +74,12 @@ func NewBackend(pluginName string, sys pluginutil.LookRunnerUtil) (logical.Backe
return backend, nil
}

func newPluginClient(sys pluginutil.RunnerUtil, pluginRunner *pluginutil.PluginRunner) (logical.Backend, error) {
func newPluginClient(sys pluginutil.RunnerUtil, pluginRunner *pluginutil.PluginRunner, logger log.Logger) (logical.Backend, error) {
// pluginMap is the map of plugins we can dispense.
pluginMap := map[string]plugin.Plugin{
"backend": &BackendPlugin{},
}
client, err := pluginRunner.Run(sys, pluginMap, handshakeConfig, []string{})
client, err := pluginRunner.Run(sys, pluginMap, handshakeConfig, []string{}, logger)
if err != nil {
return nil, err
}
Expand Down