From 10536f71def2026279285999779023d98f505e56 Mon Sep 17 00:00:00 2001 From: panwenxing Date: Fri, 19 Oct 2018 15:00:34 +0800 Subject: [PATCH] runc: runc logs forwarding to syslog reason:runc logs forwarding to syslog and using the config "--log-level" to control the number of logs Change-Id: Ia93f6f5c56131ea8558c4b7b7e5c4bec827a1bad Conflicts: libcontainer/container_linux.go libcontainer/process_linux.go libcontainer/state_linux.go --- create.go | 2 +- libcontainer/configs/config.go | 70 +++++++++--- libcontainer/container_linux.go | 2 +- main.go | 20 ++++ vendor/github.com/sirupsen/logrus/Checklist | 1 + .../logrus/hooks/airbrake/airbrake.go | 54 ++++++++++ .../sirupsen/logrus/hooks/bugsnag/bugsnag.go | 68 ++++++++++++ .../logrus/hooks/papertrail/README.md | 28 +++++ .../logrus/hooks/papertrail/papertrail.go | 55 ++++++++++ .../sirupsen/logrus/hooks/sentry/README.md | 61 +++++++++++ .../sirupsen/logrus/hooks/sentry/sentry.go | 100 ++++++++++++++++++ .../sirupsen/logrus/hooks/syslog/README.md | 20 ++++ .../sirupsen/logrus/hooks/syslog/syslog.go | 59 +++++++++++ 13 files changed, 523 insertions(+), 17 deletions(-) create mode 100644 vendor/github.com/sirupsen/logrus/Checklist create mode 100644 vendor/github.com/sirupsen/logrus/hooks/airbrake/airbrake.go create mode 100644 vendor/github.com/sirupsen/logrus/hooks/bugsnag/bugsnag.go create mode 100644 vendor/github.com/sirupsen/logrus/hooks/papertrail/README.md create mode 100644 vendor/github.com/sirupsen/logrus/hooks/papertrail/papertrail.go create mode 100644 vendor/github.com/sirupsen/logrus/hooks/sentry/README.md create mode 100644 vendor/github.com/sirupsen/logrus/hooks/sentry/sentry.go create mode 100644 vendor/github.com/sirupsen/logrus/hooks/syslog/README.md create mode 100644 vendor/github.com/sirupsen/logrus/hooks/syslog/syslog.go diff --git a/create.go b/create.go index 97854b8..46ef1ef 100644 --- a/create.go +++ b/create.go @@ -2,9 +2,9 @@ package main import ( "fmt" - "os" "github.com/urfave/cli" + "os" ) var createCommand = cli.Command{ diff --git a/libcontainer/configs/config.go b/libcontainer/configs/config.go index 72910ff..9076846 100644 --- a/libcontainer/configs/config.go +++ b/libcontainer/configs/config.go @@ -4,15 +4,22 @@ import ( "bytes" "encoding/json" "fmt" - "os/exec" - "time" - "github.com/sirupsen/logrus" - "github.com/opencontainers/runc/libcontainer/devices" "github.com/opencontainers/runtime-spec/specs-go" + "os/exec" + "time" +) + +const ( + minHookTimeOut = 0 + defaultHookTimeOut = 5 * time.Second + maxHookTimeOut = 120 * time.Second + //the runc default timeout is 120s, so set the defaultWarnTime to 80% of the default timeout. + defaultWarnTime = 96 * time.Second ) + type Rlimit struct { Type int `json:"type"` Hard uint64 `json:"hard"` @@ -279,11 +286,11 @@ type Capabilities struct { func (hooks HookList) RunHooks(state *specs.State) error { for i, h := range hooks { - logrus.Infof("run hooks %d:%T", i, h) + logrus.Infof("run hooks %d:%T, ContainerId: %s", i, h, state.ID) if err := h.Run(state); err != nil { - return fmt.Errorf("error running hook #%d: %w", i, err) + return fmt.Errorf("error running hook #%d: %w, ContainerId: %s", i, err, state.ID) } - logrus.Infof("hooks %d:%T done", i, h) + logrus.Infof("hooks %d:%T done, ContainerId: %s", i, h, state.ID) } return nil @@ -388,29 +395,62 @@ func (c Command) Run(s *specs.State) error { Stdout: &stdout, Stderr: &stderr, } + startTime := time.Now() if err := cmd.Start(); err != nil { return err } + if c.Timeout != nil && *c.Timeout <= minHookTimeOut { + *c.Timeout = defaultHookTimeOut + logrus.Warnf("hook timeout should not be negative or zero, set hook timeout as 5s") + } + if c.Timeout != nil && *c.Timeout > maxHookTimeOut { + logrus.Warnf("hook timeout: %s is too long, use 120s as timeout. ContainerID: %s", *c.Timeout, s.ID) + *c.Timeout = maxHookTimeOut + } errC := make(chan error, 1) + var ( + timerCh <-chan time.Time + warnTime = defaultWarnTime.Seconds() + ) go func() { err := cmd.Wait() if err != nil { err = fmt.Errorf("error running hook: %w, stdout: %s, stderr: %s", err, stdout.String(), stderr.String()) } + elapsedTime := time.Since(startTime) + logrus.Infof("hook spends time %s, ContainerID: %s", elapsedTime, s.ID) + if c.Timeout != nil { + if elapsedTime.Seconds() >= (c.Timeout.Seconds() * 0.8) { + logrus.Warnf("elapsed %s, more than 80%% of the timeout %s, ContainerID: %s", elapsedTime, c.Timeout, s.ID) + } + } else { + if elapsedTime.Seconds() >= warnTime { + logrus.Warnf("elapsed %s, more than 80%% of the default timeout 120s, ContainerID: %s", elapsedTime, s.ID) + } + } errC <- err }() - var timerCh <-chan time.Time if c.Timeout != nil { timer := time.NewTimer(*c.Timeout) defer timer.Stop() timerCh = timer.C + warnTime = (*c.Timeout).Seconds() * 0.8 } - select { - case err := <-errC: - return err - case <-timerCh: - _ = cmd.Process.Kill() - <-errC - return fmt.Errorf("hook ran past specified timeout of %.1fs", c.Timeout.Seconds()) + timeAfter := time.After(time.Duration(warnTime) * time.Second) + for { + select { + case err := <-errC: + return err + case <-timerCh: + cmd.Process.Kill() + cmd.Wait() + return fmt.Errorf("hook ran past specified timeout of %.1fs", c.Timeout.Seconds()) + case <-timeAfter: + if c.Timeout != nil { + logrus.Warnf("hook ran more than 80%% of the timeout %s, ContainerID: %s", *c.Timeout, s.ID) + } else { + logrus.Warnf("hook ran more than 80%% of the default timeout 120s, ContainerID: %s", s.ID) + } + } } } diff --git a/libcontainer/container_linux.go b/libcontainer/container_linux.go index f8ce1cc..8fbd04d 100644 --- a/libcontainer/container_linux.go +++ b/libcontainer/container_linux.go @@ -370,7 +370,7 @@ func (c *linuxContainer) start(process *Process) (retErr error) { if err := c.config.Hooks[configs.Poststart].RunHooks(s); err != nil { if err := ignoreTerminateErrors(parent.terminate()); err != nil { - logrus.Warn(fmt.Errorf("error running poststart hook: %w", err)) + logrus.Warn(fmt.Errorf("error running poststart hook: %w, ContainerId: %s", err, s.ID)) } return err } diff --git a/main.go b/main.go index 4d66638..9e14976 100644 --- a/main.go +++ b/main.go @@ -100,6 +100,10 @@ func main() { Value: root, Usage: "root directory for storage of container state (this should be located in tmpfs)", }, + cli.StringFlag{ + Name: "log-level", + Usage: "set the logging level [debug, info, warn, error, fatal, panic]", + }, cli.StringFlag{ Name: "criu", Value: "criu", @@ -211,7 +215,23 @@ func configLogrus(context *cli.Context) error { return err } logrus.SetOutput(f) + hook, serr := logrus_syslog.NewSyslogHook("", "", syslog.LOG_INFO|syslog.LOG_USER, "docker-runc") + if serr != nil { + fmt.Fprint(f, fmt.Sprintf("Leo: new syslog hook get %s", serr)) + } + logrus.AddHook(hook) + } + if logLevel := context.GlobalString("log-level"); logLevel != "" { + lvl, err := logrus.ParseLevel(logLevel) + if err != nil { + fmt.Fprintf(os.Stderr, "Unable to parse logging level: %s\n", logLevel) + os.Exit(1) + } + logrus.SetLevel(lvl) } + if context.GlobalBool("debug") { + logrus.SetLevel(logrus.DebugLevel) + } return nil } diff --git a/vendor/github.com/sirupsen/logrus/Checklist b/vendor/github.com/sirupsen/logrus/Checklist new file mode 100644 index 0000000..7117b24 --- /dev/null +++ b/vendor/github.com/sirupsen/logrus/Checklist @@ -0,0 +1 @@ +imported from runc v1.0.0-Release Candidate 2: Godeps/_workspace/src/github.com/Sirupsen/logrus/hooks diff --git a/vendor/github.com/sirupsen/logrus/hooks/airbrake/airbrake.go b/vendor/github.com/sirupsen/logrus/hooks/airbrake/airbrake.go new file mode 100644 index 0000000..b0502c3 --- /dev/null +++ b/vendor/github.com/sirupsen/logrus/hooks/airbrake/airbrake.go @@ -0,0 +1,54 @@ +package airbrake + +import ( + "errors" + "fmt" + + "github.com/Sirupsen/logrus" + "github.com/tobi/airbrake-go" +) + +// AirbrakeHook to send exceptions to an exception-tracking service compatible +// with the Airbrake API. +type airbrakeHook struct { + APIKey string + Endpoint string + Environment string +} + +func NewHook(endpoint, apiKey, env string) *airbrakeHook { + return &airbrakeHook{ + APIKey: apiKey, + Endpoint: endpoint, + Environment: env, + } +} + +func (hook *airbrakeHook) Fire(entry *logrus.Entry) error { + airbrake.ApiKey = hook.APIKey + airbrake.Endpoint = hook.Endpoint + airbrake.Environment = hook.Environment + + var notifyErr error + err, ok := entry.Data["error"].(error) + if ok { + notifyErr = err + } else { + notifyErr = errors.New(entry.Message) + } + + airErr := airbrake.Notify(notifyErr) + if airErr != nil { + return fmt.Errorf("Failed to send error to Airbrake: %s", airErr) + } + + return nil +} + +func (hook *airbrakeHook) Levels() []logrus.Level { + return []logrus.Level{ + logrus.ErrorLevel, + logrus.FatalLevel, + logrus.PanicLevel, + } +} diff --git a/vendor/github.com/sirupsen/logrus/hooks/bugsnag/bugsnag.go b/vendor/github.com/sirupsen/logrus/hooks/bugsnag/bugsnag.go new file mode 100644 index 0000000..d20a0f5 --- /dev/null +++ b/vendor/github.com/sirupsen/logrus/hooks/bugsnag/bugsnag.go @@ -0,0 +1,68 @@ +package logrus_bugsnag + +import ( + "errors" + + "github.com/Sirupsen/logrus" + "github.com/bugsnag/bugsnag-go" +) + +type bugsnagHook struct{} + +// ErrBugsnagUnconfigured is returned if NewBugsnagHook is called before +// bugsnag.Configure. Bugsnag must be configured before the hook. +var ErrBugsnagUnconfigured = errors.New("bugsnag must be configured before installing this logrus hook") + +// ErrBugsnagSendFailed indicates that the hook failed to submit an error to +// bugsnag. The error was successfully generated, but `bugsnag.Notify()` +// failed. +type ErrBugsnagSendFailed struct { + err error +} + +func (e ErrBugsnagSendFailed) Error() string { + return "failed to send error to Bugsnag: " + e.err.Error() +} + +// NewBugsnagHook initializes a logrus hook which sends exceptions to an +// exception-tracking service compatible with the Bugsnag API. Before using +// this hook, you must call bugsnag.Configure(). The returned object should be +// registered with a log via `AddHook()` +// +// Entries that trigger an Error, Fatal or Panic should now include an "error" +// field to send to Bugsnag. +func NewBugsnagHook() (*bugsnagHook, error) { + if bugsnag.Config.APIKey == "" { + return nil, ErrBugsnagUnconfigured + } + return &bugsnagHook{}, nil +} + +// Fire forwards an error to Bugsnag. Given a logrus.Entry, it extracts the +// "error" field (or the Message if the error isn't present) and sends it off. +func (hook *bugsnagHook) Fire(entry *logrus.Entry) error { + var notifyErr error + err, ok := entry.Data["error"].(error) + if ok { + notifyErr = err + } else { + notifyErr = errors.New(entry.Message) + } + + bugsnagErr := bugsnag.Notify(notifyErr) + if bugsnagErr != nil { + return ErrBugsnagSendFailed{bugsnagErr} + } + + return nil +} + +// Levels enumerates the log levels on which the error should be forwarded to +// bugsnag: everything at or above the "Error" level. +func (hook *bugsnagHook) Levels() []logrus.Level { + return []logrus.Level{ + logrus.ErrorLevel, + logrus.FatalLevel, + logrus.PanicLevel, + } +} diff --git a/vendor/github.com/sirupsen/logrus/hooks/papertrail/README.md b/vendor/github.com/sirupsen/logrus/hooks/papertrail/README.md new file mode 100644 index 0000000..ae61e92 --- /dev/null +++ b/vendor/github.com/sirupsen/logrus/hooks/papertrail/README.md @@ -0,0 +1,28 @@ +# Papertrail Hook for Logrus :walrus: + +[Papertrail](https://papertrailapp.com) provides hosted log management. Once stored in Papertrail, you can [group](http://help.papertrailapp.com/kb/how-it-works/groups/) your logs on various dimensions, [search](http://help.papertrailapp.com/kb/how-it-works/search-syntax) them, and trigger [alerts](http://help.papertrailapp.com/kb/how-it-works/alerts). + +In most deployments, you'll want to send logs to Papertrail via their [remote_syslog](http://help.papertrailapp.com/kb/configuration/configuring-centralized-logging-from-text-log-files-in-unix/) daemon, which requires no application-specific configuration. This hook is intended for relatively low-volume logging, likely in managed cloud hosting deployments where installing `remote_syslog` is not possible. + +## Usage + +You can find your Papertrail UDP port on your [Papertrail account page](https://papertrailapp.com/account/destinations). Substitute it below for `YOUR_PAPERTRAIL_UDP_PORT`. + +For `YOUR_APP_NAME`, substitute a short string that will readily identify your application or service in the logs. + +```go +import ( + "log/syslog" + "github.com/Sirupsen/logrus" + "github.com/Sirupsen/logrus/hooks/papertrail" +) + +func main() { + log := logrus.New() + hook, err := logrus_papertrail.NewPapertrailHook("logs.papertrailapp.com", YOUR_PAPERTRAIL_UDP_PORT, YOUR_APP_NAME) + + if err == nil { + log.Hooks.Add(hook) + } +} +``` diff --git a/vendor/github.com/sirupsen/logrus/hooks/papertrail/papertrail.go b/vendor/github.com/sirupsen/logrus/hooks/papertrail/papertrail.go new file mode 100644 index 0000000..c0f10c1 --- /dev/null +++ b/vendor/github.com/sirupsen/logrus/hooks/papertrail/papertrail.go @@ -0,0 +1,55 @@ +package logrus_papertrail + +import ( + "fmt" + "net" + "os" + "time" + + "github.com/Sirupsen/logrus" +) + +const ( + format = "Jan 2 15:04:05" +) + +// PapertrailHook to send logs to a logging service compatible with the Papertrail API. +type PapertrailHook struct { + Host string + Port int + AppName string + UDPConn net.Conn +} + +// NewPapertrailHook creates a hook to be added to an instance of logger. +func NewPapertrailHook(host string, port int, appName string) (*PapertrailHook, error) { + conn, err := net.Dial("udp", fmt.Sprintf("%s:%d", host, port)) + return &PapertrailHook{host, port, appName, conn}, err +} + +// Fire is called when a log event is fired. +func (hook *PapertrailHook) Fire(entry *logrus.Entry) error { + date := time.Now().Format(format) + msg, _ := entry.String() + payload := fmt.Sprintf("<22> %s %s: %s", date, hook.AppName, msg) + + bytesWritten, err := hook.UDPConn.Write([]byte(payload)) + if err != nil { + fmt.Fprintf(os.Stderr, "Unable to send log line to Papertrail via UDP. Wrote %d bytes before error: %v", bytesWritten, err) + return err + } + + return nil +} + +// Levels returns the available logging levels. +func (hook *PapertrailHook) Levels() []logrus.Level { + return []logrus.Level{ + logrus.PanicLevel, + logrus.FatalLevel, + logrus.ErrorLevel, + logrus.WarnLevel, + logrus.InfoLevel, + logrus.DebugLevel, + } +} diff --git a/vendor/github.com/sirupsen/logrus/hooks/sentry/README.md b/vendor/github.com/sirupsen/logrus/hooks/sentry/README.md new file mode 100644 index 0000000..19e58bb --- /dev/null +++ b/vendor/github.com/sirupsen/logrus/hooks/sentry/README.md @@ -0,0 +1,61 @@ +# Sentry Hook for Logrus :walrus: + +[Sentry](https://getsentry.com) provides both self-hosted and hosted +solutions for exception tracking. +Both client and server are +[open source](https://github.com/getsentry/sentry). + +## Usage + +Every sentry application defined on the server gets a different +[DSN](https://www.getsentry.com/docs/). In the example below replace +`YOUR_DSN` with the one created for your application. + +```go +import ( + "github.com/Sirupsen/logrus" + "github.com/Sirupsen/logrus/hooks/sentry" +) + +func main() { + log := logrus.New() + hook, err := logrus_sentry.NewSentryHook(YOUR_DSN, []logrus.Level{ + logrus.PanicLevel, + logrus.FatalLevel, + logrus.ErrorLevel, + }) + + if err == nil { + log.Hooks.Add(hook) + } +} +``` + +## Special fields + +Some logrus fields have a special meaning in this hook, +these are server_name and logger. +When logs are sent to sentry these fields are treated differently. +- server_name (also known as hostname) is the name of the server which +is logging the event (hostname.example.com) +- logger is the part of the application which is logging the event. +In go this usually means setting it to the name of the package. + +## Timeout + +`Timeout` is the time the sentry hook will wait for a response +from the sentry server. + +If this time elapses with no response from +the server an error will be returned. + +If `Timeout` is set to 0 the SentryHook will not wait for a reply +and will assume a correct delivery. + +The SentryHook has a default timeout of `100 milliseconds` when created +with a call to `NewSentryHook`. This can be changed by assigning a value to the `Timeout` field: + +```go +hook, _ := logrus_sentry.NewSentryHook(...) +hook.Timeout = 20*time.Second +``` diff --git a/vendor/github.com/sirupsen/logrus/hooks/sentry/sentry.go b/vendor/github.com/sirupsen/logrus/hooks/sentry/sentry.go new file mode 100644 index 0000000..379f281 --- /dev/null +++ b/vendor/github.com/sirupsen/logrus/hooks/sentry/sentry.go @@ -0,0 +1,100 @@ +package logrus_sentry + +import ( + "fmt" + "time" + + "github.com/Sirupsen/logrus" + "github.com/getsentry/raven-go" +) + +var ( + severityMap = map[logrus.Level]raven.Severity{ + logrus.DebugLevel: raven.DEBUG, + logrus.InfoLevel: raven.INFO, + logrus.WarnLevel: raven.WARNING, + logrus.ErrorLevel: raven.ERROR, + logrus.FatalLevel: raven.FATAL, + logrus.PanicLevel: raven.FATAL, + } +) + +func getAndDel(d logrus.Fields, key string) (string, bool) { + var ( + ok bool + v interface{} + val string + ) + if v, ok = d[key]; !ok { + return "", false + } + + if val, ok = v.(string); !ok { + return "", false + } + delete(d, key) + return val, true +} + +// SentryHook delivers logs to a sentry server. +type SentryHook struct { + // Timeout sets the time to wait for a delivery error from the sentry server. + // If this is set to zero the server will not wait for any response and will + // consider the message correctly sent + Timeout time.Duration + + client *raven.Client + levels []logrus.Level +} + +// NewSentryHook creates a hook to be added to an instance of logger +// and initializes the raven client. +// This method sets the timeout to 100 milliseconds. +func NewSentryHook(DSN string, levels []logrus.Level) (*SentryHook, error) { + client, err := raven.NewClient(DSN, nil) + if err != nil { + return nil, err + } + return &SentryHook{100 * time.Millisecond, client, levels}, nil +} + +// Called when an event should be sent to sentry +// Special fields that sentry uses to give more information to the server +// are extracted from entry.Data (if they are found) +// These fields are: logger and server_name +func (hook *SentryHook) Fire(entry *logrus.Entry) error { + packet := &raven.Packet{ + Message: entry.Message, + Timestamp: raven.Timestamp(entry.Time), + Level: severityMap[entry.Level], + Platform: "go", + } + + d := entry.Data + + if logger, ok := getAndDel(d, "logger"); ok { + packet.Logger = logger + } + if serverName, ok := getAndDel(d, "server_name"); ok { + packet.ServerName = serverName + } + packet.Extra = map[string]interface{}(d) + + _, errCh := hook.client.Capture(packet, nil) + timeout := hook.Timeout + if timeout != 0 { + timeoutCh := time.After(timeout) + select { + case err := <-errCh: + return err + case <-timeoutCh: + return fmt.Errorf("no response from sentry server in %s", timeout) + } + } + return nil +} + +// Levels returns the available logging levels. +func (hook *SentryHook) Levels() []logrus.Level { + return hook.levels +} diff --git a/vendor/github.com/sirupsen/logrus/hooks/syslog/README.md b/vendor/github.com/sirupsen/logrus/hooks/syslog/README.md new file mode 100644 index 0000000..4dbb8e7 --- /dev/null +++ b/vendor/github.com/sirupsen/logrus/hooks/syslog/README.md @@ -0,0 +1,20 @@ +# Syslog Hooks for Logrus :walrus: + +## Usage + +```go +import ( + "log/syslog" + "github.com/Sirupsen/logrus" + logrus_syslog "github.com/Sirupsen/logrus/hooks/syslog" +) + +func main() { + log := logrus.New() + hook, err := logrus_syslog.NewSyslogHook("udp", "localhost:514", syslog.LOG_INFO, "") + + if err == nil { + log.Hooks.Add(hook) + } +} +``` diff --git a/vendor/github.com/sirupsen/logrus/hooks/syslog/syslog.go b/vendor/github.com/sirupsen/logrus/hooks/syslog/syslog.go new file mode 100644 index 0000000..b6fa374 --- /dev/null +++ b/vendor/github.com/sirupsen/logrus/hooks/syslog/syslog.go @@ -0,0 +1,59 @@ +package logrus_syslog + +import ( + "fmt" + "github.com/Sirupsen/logrus" + "log/syslog" + "os" +) + +// SyslogHook to send logs via syslog. +type SyslogHook struct { + Writer *syslog.Writer + SyslogNetwork string + SyslogRaddr string +} + +// Creates a hook to be added to an instance of logger. This is called with +// `hook, err := NewSyslogHook("udp", "localhost:514", syslog.LOG_DEBUG, "")` +// `if err == nil { log.Hooks.Add(hook) }` +func NewSyslogHook(network, raddr string, priority syslog.Priority, tag string) (*SyslogHook, error) { + w, err := syslog.Dial(network, raddr, priority, tag) + return &SyslogHook{w, network, raddr}, err +} + +func (hook *SyslogHook) Fire(entry *logrus.Entry) error { + line, err := entry.String() + if err != nil { + fmt.Fprintf(os.Stderr, "Unable to read entry, %v", err) + return err + } + + switch entry.Level { + case logrus.PanicLevel: + return hook.Writer.Crit(line) + case logrus.FatalLevel: + return hook.Writer.Crit(line) + case logrus.ErrorLevel: + return hook.Writer.Err(line) + case logrus.WarnLevel: + return hook.Writer.Warning(line) + case logrus.InfoLevel: + return hook.Writer.Info(line) + case logrus.DebugLevel: + return hook.Writer.Debug(line) + default: + return nil + } +} + +func (hook *SyslogHook) Levels() []logrus.Level { + return []logrus.Level{ + logrus.PanicLevel, + logrus.FatalLevel, + logrus.ErrorLevel, + logrus.WarnLevel, + logrus.InfoLevel, + logrus.DebugLevel, + } +} -- 2.33.0