Plugins use parent loggers

This PR fixes various instances of plugins being launched without using
the parent loggers. This meant that logs would not all go to the same
output, break formatting etc.
This commit is contained in:
Alex Dadgar 2019-01-09 15:06:58 -08:00
parent d2aeeee200
commit 14ed757a56
16 changed files with 92 additions and 69 deletions

View File

@ -187,7 +187,7 @@ func (a *AllocGarbageCollector) destroyAllocRunner(allocID string, ar AllocRunne
case <-a.shutdownCh:
}
a.logger.Debug("garbage collected %s", "alloc_id", allocID)
a.logger.Debug("alloc garbage collected", "alloc_id", allocID)
// Release the lock
<-a.destroyCh

View File

@ -3,7 +3,7 @@ package command
import (
"strings"
hclog "github.com/hashicorp/go-hclog"
log "github.com/hashicorp/go-hclog"
plugin "github.com/hashicorp/go-plugin"
"github.com/hashicorp/nomad/drivers/docker/docklog"
"github.com/hashicorp/nomad/plugins/base"
@ -25,12 +25,19 @@ func (e *DockerLoggerPluginCommand) Synopsis() string {
}
func (e *DockerLoggerPluginCommand) Run(args []string) int {
logger := log.New(&log.LoggerOptions{
Level: log.Trace,
JSONFormat: true,
Name: docklog.PluginName,
})
plugin.Serve(&plugin.ServeConfig{
HandshakeConfig: base.Handshake,
Plugins: map[string]plugin.Plugin{
docklog.PluginName: docklog.NewPlugin(docklog.NewDockerLogger(hclog.Default().Named(docklog.PluginName))),
docklog.PluginName: docklog.NewPlugin(docklog.NewDockerLogger(logger)),
},
GRPCServer: plugin.DefaultGRPCServer,
Logger: logger,
})
return 0
}

View File

@ -2,10 +2,12 @@ package command
import (
"encoding/json"
"io"
"os"
"strings"
hclog "github.com/hashicorp/go-hclog"
log "github.com/hashicorp/go-hclog"
plugin "github.com/hashicorp/go-plugin"
"github.com/hashicorp/nomad/drivers/shared/executor"
@ -32,24 +34,38 @@ func (e *ExecutorPluginCommand) Run(args []string) int {
e.Ui.Error("json configuration not provided")
return 1
}
config := args[0]
var executorConfig executor.ExecutorConfig
if err := json.Unmarshal([]byte(config), &executorConfig); err != nil {
return 1
}
stdo, err := os.OpenFile(executorConfig.LogFile, os.O_CREATE|os.O_RDWR|os.O_APPEND, 0666)
f, err := os.OpenFile(executorConfig.LogFile, os.O_CREATE|os.O_RDWR|os.O_APPEND, 0666)
if err != nil {
e.Ui.Error(err.Error())
return 1
}
// Tee the logs to stderr and the file so that they are streamed to the
// client
out := io.MultiWriter(f, os.Stderr)
// Create the logger
logger := log.New(&log.LoggerOptions{
Level: hclog.LevelFromString(executorConfig.LogLevel),
JSONFormat: true,
Output: out,
})
plugin.Serve(&plugin.ServeConfig{
HandshakeConfig: base.Handshake,
Plugins: executor.GetPluginMap(
stdo,
hclog.LevelFromString(executorConfig.LogLevel),
logger,
executorConfig.FSIsolation,
),
GRPCServer: plugin.DefaultGRPCServer,
Logger: logger,
})
return 0
}

View File

@ -36,6 +36,7 @@ func (e *LogMonPluginCommand) Run(args []string) int {
"logmon": logmon.NewPlugin(logmon.NewLogMon(logger)),
},
GRPCServer: plugin.DefaultGRPCServer,
Logger: logger,
})
return 0
}

View File

@ -21,3 +21,9 @@ client {
ports {
http = 5656
}
plugin "raw_exec" {
config {
enabled = true
}
}

View File

@ -22,12 +22,19 @@ func main() {
// Detect if we are being launched as a docker logging plugin
switch os.Args[1] {
case docklog.PluginName:
logger := log.New(&log.LoggerOptions{
Level: log.Trace,
JSONFormat: true,
Name: docklog.PluginName,
})
plugin.Serve(&plugin.ServeConfig{
HandshakeConfig: base.Handshake,
Plugins: map[string]plugin.Plugin{
docklog.PluginName: docklog.NewPlugin(docklog.NewDockerLogger(log.Default().Named(docklog.PluginName))),
docklog.PluginName: docklog.NewPlugin(docklog.NewDockerLogger(logger)),
},
GRPCServer: plugin.DefaultGRPCServer,
Logger: logger,
})
return

View File

@ -31,6 +31,7 @@ func LaunchDockerLogger(logger hclog.Logger) (DockerLogger, *plugin.Client, erro
AllowedProtocols: []plugin.Protocol{
plugin.ProtocolGRPC,
},
Logger: logger,
})
rpcClient, err := client.Client()

View File

@ -10,7 +10,6 @@ import (
"github.com/hashicorp/consul-template/signals"
hclog "github.com/hashicorp/go-hclog"
plugin "github.com/hashicorp/go-plugin"
"github.com/hashicorp/nomad/client/fingerprint"
"github.com/hashicorp/nomad/drivers/shared/eventer"
"github.com/hashicorp/nomad/drivers/shared/executor"
@ -242,11 +241,8 @@ func (d *Driver) RecoverTask(handle *drivers.TaskHandle) error {
return fmt.Errorf("failed to build ReattachConfig from task state: %v", err)
}
pluginConfig := &plugin.ClientConfig{
Reattach: plugRC,
}
exec, pluginClient, err := executor.CreateExecutorWithConfig(pluginConfig, os.Stderr)
exec, pluginClient, err := executor.CreateExecutorWithConfig(plugRC,
d.logger.With("task_name", handle.Config.Name, "alloc_id", handle.Config.AllocID))
if err != nil {
d.logger.Error("failed to reattach to executor", "error", err, "task_id", handle.Config.ID)
return fmt.Errorf("failed to reattach to executor: %v", err)
@ -289,8 +285,9 @@ func (d *Driver) StartTask(cfg *drivers.TaskConfig) (*drivers.TaskHandle, *drive
FSIsolation: true,
}
// TODO: best way to pass port ranges in from client config
exec, pluginClient, err := executor.CreateExecutor(os.Stderr, hclog.Debug, d.nomadConfig, executorConfig)
exec, pluginClient, err := executor.CreateExecutor(
d.logger.With("task_name", handle.Config.Name, "alloc_id", handle.Config.AllocID),
d.nomadConfig, executorConfig)
if err != nil {
return nil, nil, fmt.Errorf("failed to create executor: %v", err)
}

View File

@ -10,8 +10,7 @@ import (
"time"
"github.com/hashicorp/consul-template/signals"
"github.com/hashicorp/go-hclog"
"github.com/hashicorp/go-plugin"
hclog "github.com/hashicorp/go-hclog"
"github.com/hashicorp/nomad/client/fingerprint"
"github.com/hashicorp/nomad/drivers/shared/eventer"
"github.com/hashicorp/nomad/drivers/shared/executor"
@ -264,11 +263,8 @@ func (d *Driver) RecoverTask(handle *drivers.TaskHandle) error {
return fmt.Errorf("failed to build ReattachConfig from taskConfig state: %v", err)
}
pluginConfig := &plugin.ClientConfig{
Reattach: plugRC,
}
execImpl, pluginClient, err := executor.CreateExecutorWithConfig(pluginConfig, os.Stderr)
execImpl, pluginClient, err := executor.CreateExecutorWithConfig(plugRC,
d.logger.With("task_name", handle.Config.Name, "alloc_id", handle.Config.AllocID))
if err != nil {
d.logger.Error("failed to reattach to executor", "error", err, "task_id", handle.Config.ID)
return fmt.Errorf("failed to reattach to executor: %v", err)
@ -323,7 +319,9 @@ func (d *Driver) StartTask(cfg *drivers.TaskConfig) (*drivers.TaskHandle, *drive
FSIsolation: capabilities.FSIsolation == drivers.FSIsolationChroot,
}
exec, pluginClient, err := executor.CreateExecutor(os.Stderr, hclog.Debug, d.nomadConfig, executorConfig)
exec, pluginClient, err := executor.CreateExecutor(
d.logger.With("task_name", handle.Config.Name, "alloc_id", handle.Config.AllocID),
d.nomadConfig, executorConfig)
if err != nil {
return nil, nil, fmt.Errorf("failed to create executor: %v", err)
}

View File

@ -5,7 +5,6 @@ import (
"errors"
"fmt"
"net"
"os"
"os/exec"
"path/filepath"
"regexp"
@ -14,8 +13,7 @@ import (
"time"
"github.com/coreos/go-semver/semver"
"github.com/hashicorp/go-hclog"
"github.com/hashicorp/go-plugin"
hclog "github.com/hashicorp/go-hclog"
"github.com/hashicorp/nomad/drivers/shared/eventer"
"github.com/hashicorp/nomad/drivers/shared/executor"
"github.com/hashicorp/nomad/plugins/base"
@ -263,11 +261,8 @@ func (d *Driver) RecoverTask(handle *drivers.TaskHandle) error {
return fmt.Errorf("failed to build ReattachConfig from taskConfig state: %v", err)
}
pluginConfig := &plugin.ClientConfig{
Reattach: plugRC,
}
execImpl, pluginClient, err := executor.CreateExecutorWithConfig(pluginConfig, os.Stderr)
execImpl, pluginClient, err := executor.CreateExecutorWithConfig(plugRC,
d.logger.With("task_name", handle.Config.Name, "alloc_id", handle.Config.AllocID))
if err != nil {
d.logger.Error("failed to reattach to executor", "error", err, "task_id", handle.Config.ID)
return fmt.Errorf("failed to reattach to executor: %v", err)
@ -417,7 +412,9 @@ func (d *Driver) StartTask(cfg *drivers.TaskConfig) (*drivers.TaskHandle, *drive
LogLevel: "debug",
}
execImpl, pluginClient, err := executor.CreateExecutor(os.Stderr, hclog.Debug, d.nomadConfig, executorConfig)
execImpl, pluginClient, err := executor.CreateExecutor(
d.logger.With("task_name", handle.Config.Name, "alloc_id", handle.Config.AllocID),
d.nomadConfig, executorConfig)
if err != nil {
return nil, nil, err
}

View File

@ -12,7 +12,6 @@ import (
"github.com/hashicorp/consul-template/signals"
hclog "github.com/hashicorp/go-hclog"
plugin "github.com/hashicorp/go-plugin"
"github.com/hashicorp/nomad/drivers/shared/eventer"
"github.com/hashicorp/nomad/drivers/shared/executor"
"github.com/hashicorp/nomad/plugins/base"
@ -269,12 +268,9 @@ func (d *Driver) RecoverTask(handle *drivers.TaskHandle) error {
return fmt.Errorf("failed to build ReattachConfig from task state: %v", err)
}
pluginConfig := &plugin.ClientConfig{
Reattach: plugRC,
}
// Create client for reattached executor
exec, pluginClient, err := executor.CreateExecutorWithConfig(pluginConfig, os.Stderr)
exec, pluginClient, err := executor.CreateExecutorWithConfig(plugRC,
d.logger.With("task_name", handle.Config.Name, "alloc_id", handle.Config.AllocID))
if err != nil {
d.logger.Error("failed to reattach to executor", "error", err, "task_id", handle.Config.ID)
return fmt.Errorf("failed to reattach to executor: %v", err)
@ -316,7 +312,9 @@ func (d *Driver) StartTask(cfg *drivers.TaskConfig) (*drivers.TaskHandle, *drive
LogLevel: "debug",
}
exec, pluginClient, err := executor.CreateExecutor(os.Stderr, hclog.Debug, d.nomadConfig, executorConfig)
exec, pluginClient, err := executor.CreateExecutor(
d.logger.With("task_name", handle.Config.Name, "alloc_id", handle.Config.AllocID),
d.nomadConfig, executorConfig)
if err != nil {
return nil, nil, fmt.Errorf("failed to create executor: %v", err)
}

View File

@ -248,7 +248,7 @@ func (e *UniversalExecutor) Version() (*ExecutorVersion, error) {
// Launch launches the main process and returns its state. It also
// configures an applies isolation on certain platforms.
func (e *UniversalExecutor) Launch(command *ExecCommand) (*ProcessState, error) {
e.logger.Info("launching command", "command", command.Cmd, "args", strings.Join(command.Args, " "))
e.logger.Debug("launching command", "command", command.Cmd, "args", strings.Join(command.Args, " "))
e.commandCfg = command
@ -419,7 +419,7 @@ var (
// Exit cleans up the alloc directory, destroys resource container and kills the
// user process
func (e *UniversalExecutor) Shutdown(signal string, grace time.Duration) error {
e.logger.Info("shutdown requested", "signal", signal, "grace_period_ms", grace.Round(time.Millisecond))
e.logger.Debug("shutdown requested", "signal", signal, "grace_period_ms", grace.Round(time.Millisecond))
var merr multierror.Error
// If the executor did not launch a process, return.

View File

@ -95,7 +95,7 @@ func NewExecutorWithIsolation(logger hclog.Logger) Executor {
// Launch creates a new container in libcontainer and starts a new process with it
func (l *LibcontainerExecutor) Launch(command *ExecCommand) (*ProcessState, error) {
l.logger.Info("launching command", "command", command.Cmd, "args", strings.Join(command.Args, " "))
l.logger.Debug("launching command", "command", command.Cmd, "args", strings.Join(command.Args, " "))
// Find the nomad executable to launch the executor process with
bin, err := discover.NomadExecutable()
if err != nil {

View File

@ -63,7 +63,7 @@ func (e *UniversalExecutor) shutdownProcess(_ os.Signal, proc *os.Process) error
if err := sendCtrlBreak(proc.Pid); err != nil {
return fmt.Errorf("executor shutdown error: %v", err)
}
e.logger.Info("sent Ctrl-Break to process", "pid", proc.Pid)
e.logger.Debug("sent Ctrl-Break to process", "pid", proc.Pid)
return nil
}

View File

@ -1,7 +1,6 @@
package executor
import (
"io"
"net"
hclog "github.com/hashicorp/go-hclog"
@ -22,18 +21,12 @@ type ExecutorConfig struct {
FSIsolation bool
}
func GetPluginMap(w io.Writer, logLevel hclog.Level, fsIsolation bool) map[string]plugin.Plugin {
e := new(ExecutorPlugin)
e.logger = hclog.New(&hclog.LoggerOptions{
Output: w,
Level: logLevel,
})
e.fsIsolation = fsIsolation
func GetPluginMap(logger hclog.Logger, fsIsolation bool) map[string]plugin.Plugin {
return map[string]plugin.Plugin{
"executor": e,
"executor": &ExecutorPlugin{
logger: logger,
fsIsolation: fsIsolation,
},
}
}

View File

@ -3,7 +3,6 @@ package executor
import (
"encoding/json"
"fmt"
"io"
"os/exec"
"github.com/golang/protobuf/ptypes"
@ -26,7 +25,7 @@ const (
// CreateExecutor launches an executor plugin and returns an instance of the
// Executor interface
func CreateExecutor(w io.Writer, level hclog.Level, driverConfig *base.ClientDriverConfig,
func CreateExecutor(logger hclog.Logger, driverConfig *base.ClientDriverConfig,
executorConfig *ExecutorConfig) (Executor, *plugin.Client, error) {
c, err := json.Marshal(executorConfig)
@ -39,11 +38,12 @@ func CreateExecutor(w io.Writer, level hclog.Level, driverConfig *base.ClientDri
}
config := &plugin.ClientConfig{
HandshakeConfig: base.Handshake,
Plugins: map[string]plugin.Plugin{"executor": &ExecutorPlugin{}},
Cmd: exec.Command(bin, "executor", string(c)),
AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC},
Logger: logger.Named("executor"),
}
config.HandshakeConfig = base.Handshake
config.Plugins = GetPluginMap(w, level, executorConfig.FSIsolation)
config.AllowedProtocols = []plugin.Protocol{plugin.ProtocolGRPC}
if driverConfig != nil {
config.MaxPort = driverConfig.ClientMaxPort
@ -74,15 +74,17 @@ func CreateExecutor(w io.Writer, level hclog.Level, driverConfig *base.ClientDri
}
// CreateExecutorWithConfig launches a plugin with a given plugin config
func CreateExecutorWithConfig(config *plugin.ClientConfig, w io.Writer) (Executor, *plugin.Client, error) {
config.HandshakeConfig = base.Handshake
func CreateExecutorWithConfig(reattachConfig *plugin.ReattachConfig, logger hclog.Logger) (Executor, *plugin.Client, error) {
config := &plugin.ClientConfig{
HandshakeConfig: base.Handshake,
Reattach: reattachConfig,
Plugins: map[string]plugin.Plugin{"executor": &ExecutorPlugin{}},
// Setting this to DEBUG since the log level at the executor server process
// is already set, and this effects only the executor client.
// TODO: Use versioned plugin map to support backwards compatibility with
// existing pre-0.9 executors
config.Plugins = GetPluginMap(w, hclog.Debug, false)
config.AllowedProtocols = []plugin.Protocol{plugin.ProtocolGRPC}
AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC},
Logger: logger.Named("executor"),
}
executorClient := plugin.NewClient(config)
rpcClient, err := executorClient.Client()