diff --git a/client/gc.go b/client/gc.go index 2ec640d08..07ff4e7c0 100644 --- a/client/gc.go +++ b/client/gc.go @@ -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 diff --git a/command/docker_logger_plugin.go b/command/docker_logger_plugin.go index 4b79fa4a4..707def19f 100644 --- a/command/docker_logger_plugin.go +++ b/command/docker_logger_plugin.go @@ -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 } diff --git a/command/executor_plugin.go b/command/executor_plugin.go index 7e7522bc5..9bde337ad 100644 --- a/command/executor_plugin.go +++ b/command/executor_plugin.go @@ -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 } diff --git a/command/logmon_plugin.go b/command/logmon_plugin.go index 57d7eb8c4..4d3bda20c 100644 --- a/command/logmon_plugin.go +++ b/command/logmon_plugin.go @@ -36,6 +36,7 @@ func (e *LogMonPluginCommand) Run(args []string) int { "logmon": logmon.NewPlugin(logmon.NewLogMon(logger)), }, GRPCServer: plugin.DefaultGRPCServer, + Logger: logger, }) return 0 } diff --git a/demo/vagrant/client1.hcl b/demo/vagrant/client1.hcl index 6ba1e5fc9..c2ec49261 100644 --- a/demo/vagrant/client1.hcl +++ b/demo/vagrant/client1.hcl @@ -21,3 +21,9 @@ client { ports { http = 5656 } + +plugin "raw_exec" { + config { + enabled = true + } +} diff --git a/drivers/docker/cmd/main.go b/drivers/docker/cmd/main.go index e0f898f3a..faa77e5f6 100644 --- a/drivers/docker/cmd/main.go +++ b/drivers/docker/cmd/main.go @@ -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 diff --git a/drivers/docker/docklog/plugin.go b/drivers/docker/docklog/plugin.go index bc81d0ce7..967eeb9ca 100644 --- a/drivers/docker/docklog/plugin.go +++ b/drivers/docker/docklog/plugin.go @@ -31,6 +31,7 @@ func LaunchDockerLogger(logger hclog.Logger) (DockerLogger, *plugin.Client, erro AllowedProtocols: []plugin.Protocol{ plugin.ProtocolGRPC, }, + Logger: logger, }) rpcClient, err := client.Client() diff --git a/drivers/exec/driver.go b/drivers/exec/driver.go index 069d27fa8..19640ed63 100644 --- a/drivers/exec/driver.go +++ b/drivers/exec/driver.go @@ -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) } diff --git a/drivers/java/driver.go b/drivers/java/driver.go index 9cd42d3eb..27f8ce875 100644 --- a/drivers/java/driver.go +++ b/drivers/java/driver.go @@ -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) } diff --git a/drivers/qemu/driver.go b/drivers/qemu/driver.go index 251615a6d..06fcb9c2c 100644 --- a/drivers/qemu/driver.go +++ b/drivers/qemu/driver.go @@ -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 } diff --git a/drivers/rawexec/driver.go b/drivers/rawexec/driver.go index fc0b4c00f..3ab3ee57e 100644 --- a/drivers/rawexec/driver.go +++ b/drivers/rawexec/driver.go @@ -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) } diff --git a/drivers/shared/executor/executor.go b/drivers/shared/executor/executor.go index f9576e738..39dfef1ce 100644 --- a/drivers/shared/executor/executor.go +++ b/drivers/shared/executor/executor.go @@ -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. diff --git a/drivers/shared/executor/executor_linux.go b/drivers/shared/executor/executor_linux.go index 66795377f..c359b605f 100644 --- a/drivers/shared/executor/executor_linux.go +++ b/drivers/shared/executor/executor_linux.go @@ -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 { diff --git a/drivers/shared/executor/executor_windows.go b/drivers/shared/executor/executor_windows.go index f7e05b8fa..9d0b14070 100644 --- a/drivers/shared/executor/executor_windows.go +++ b/drivers/shared/executor/executor_windows.go @@ -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 } diff --git a/drivers/shared/executor/plugins.go b/drivers/shared/executor/plugins.go index 55441e702..0e3b977e9 100644 --- a/drivers/shared/executor/plugins.go +++ b/drivers/shared/executor/plugins.go @@ -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, + }, } } diff --git a/drivers/shared/executor/utils.go b/drivers/shared/executor/utils.go index c23c9d3b8..58c613223 100644 --- a/drivers/shared/executor/utils.go +++ b/drivers/shared/executor/utils.go @@ -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{ - Cmd: exec.Command(bin, "executor", string(c)), + 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} + // TODO: Use versioned plugin map to support backwards compatibility with + // existing pre-0.9 executors + AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC}, + Logger: logger.Named("executor"), + } executorClient := plugin.NewClient(config) rpcClient, err := executorClient.Client()