Merge pull request #2034 from masters-of-cats/pr-child-logging

Support for logging from children processes
2026-07-11 06:03:57 +08:00 · 2019-05-07 10:35:48 -04:00
parent dae70e8efe a146081828
commit 70bc4cd847
38 changed files with 1429 additions and 601 deletions
@@ -136,6 +136,12 @@ func execProcess(context *cli.Context) (int, error) {
 	if err != nil {
 		return -1, err
 	}
+
+	logLevel := "info"
+	if context.GlobalBool("debug") {
+		logLevel = "debug"
+	}
+
 	r := &runner{
 		enableSubreaper: false,
 		shouldDestroy:   false,
@@ -146,6 +152,7 @@ func execProcess(context *cli.Context) (int, error) {
 		action:          CT_ACT_RUN,
 		init:            false,
 		preserveFDs:     context.Int("preserve-fds"),
+		logLevel:        logLevel,
 	}
 	return r.run(p)
 }
@@ -1,11 +1,14 @@
 package main

 import (
+	"fmt"
 	"os"
 	"runtime"

 	"github.com/opencontainers/runc/libcontainer"
+	"github.com/opencontainers/runc/libcontainer/logs"
 	_ "github.com/opencontainers/runc/libcontainer/nsenter"
+	"github.com/sirupsen/logrus"
 	"github.com/urfave/cli"
 )

@@ -13,6 +16,22 @@ func init() {
 	if len(os.Args) > 1 && os.Args[1] == "init" {
 		runtime.GOMAXPROCS(1)
 		runtime.LockOSThread()
+
+		level := os.Getenv("_LIBCONTAINER_LOGLEVEL")
+		logLevel, err := logrus.ParseLevel(level)
+		if err != nil {
+			panic(fmt.Sprintf("libcontainer: failed to parse log level: %q: %v", level, err))
+		}
+
+		err = logs.ConfigureLogging(logs.Config{
+			LogPipeFd: os.Getenv("_LIBCONTAINER_LOGPIPE"),
+			LogFormat: "json",
+			LogLevel:  logLevel,
+		})
+		if err != nil {
+			panic(fmt.Sprintf("libcontainer: failed to configure logging: %v", err))
+		}
+		logrus.Debug("child process in init()")
 	}
 }

@@ -337,6 +337,7 @@ func (c *linuxContainer) start(process *Process) error {
 	if err != nil {
 		return newSystemErrorWithCause(err, "creating new parent process")
 	}
+	parent.forwardChildLogs()
 	if err := parent.start(); err != nil {
 		// terminate the process to ensure that it properly is reaped.
 		if err := ignoreTerminateErrors(parent.terminate()); err != nil {
@@ -438,16 +439,24 @@ func (c *linuxContainer) includeExecFifo(cmd *exec.Cmd) error {
 }

 func (c *linuxContainer) newParentProcess(p *Process) (parentProcess, error) {
-	parentPipe, childPipe, err := utils.NewSockPair("init")
+	parentInitPipe, childInitPipe, err := utils.NewSockPair("init")
 	if err != nil {
 		return nil, newSystemErrorWithCause(err, "creating new init pipe")
 	}
-	cmd, err := c.commandTemplate(p, childPipe)
+	messageSockPair := filePair{parentInitPipe, childInitPipe}
+
+	parentLogPipe, childLogPipe, err := os.Pipe()
+	if err != nil {
+		return nil, fmt.Errorf("Unable to create the log pipe:  %s", err)
+	}
+	logFilePair := filePair{parentLogPipe, childLogPipe}
+
+	cmd, err := c.commandTemplate(p, childInitPipe, childLogPipe)
 	if err != nil {
 		return nil, newSystemErrorWithCause(err, "creating new command template")
 	}
 	if !p.Init {
-		return c.newSetnsProcess(p, cmd, parentPipe, childPipe)
+		return c.newSetnsProcess(p, cmd, messageSockPair, logFilePair)
 	}

 	// We only set up fifoFd if we're not doing a `runc exec`. The historic
@@ -458,10 +467,10 @@ func (c *linuxContainer) newParentProcess(p *Process) (parentProcess, error) {
 	if err := c.includeExecFifo(cmd); err != nil {
 		return nil, newSystemErrorWithCause(err, "including execfifo in cmd.Exec setup")
 	}
-	return c.newInitProcess(p, cmd, parentPipe, childPipe)
+	return c.newInitProcess(p, cmd, messageSockPair, logFilePair)
 }

-func (c *linuxContainer) commandTemplate(p *Process, childPipe *os.File) (*exec.Cmd, error) {
+func (c *linuxContainer) commandTemplate(p *Process, childInitPipe *os.File, childLogPipe *os.File) (*exec.Cmd, error) {
 	cmd := exec.Command(c.initPath, c.initArgs[1:]...)
 	cmd.Args[0] = c.initArgs[0]
 	cmd.Stdin = p.Stdin
@@ -479,11 +488,18 @@ func (c *linuxContainer) commandTemplate(p *Process, childPipe *os.File) (*exec.
 			fmt.Sprintf("_LIBCONTAINER_CONSOLE=%d", stdioFdCount+len(cmd.ExtraFiles)-1),
 		)
 	}
-	cmd.ExtraFiles = append(cmd.ExtraFiles, childPipe)
+	cmd.ExtraFiles = append(cmd.ExtraFiles, childInitPipe)
 	cmd.Env = append(cmd.Env,
 		fmt.Sprintf("_LIBCONTAINER_INITPIPE=%d", stdioFdCount+len(cmd.ExtraFiles)-1),
 		fmt.Sprintf("_LIBCONTAINER_STATEDIR=%s", c.root),
 	)
+
+	cmd.ExtraFiles = append(cmd.ExtraFiles, childLogPipe)
+	cmd.Env = append(cmd.Env,
+		fmt.Sprintf("_LIBCONTAINER_LOGPIPE=%d", stdioFdCount+len(cmd.ExtraFiles)-1),
+		fmt.Sprintf("_LIBCONTAINER_LOGLEVEL=%s", p.LogLevel),
+	)
+
 	// NOTE: when running a container with no PID namespace and the parent process spawning the container is
 	// PID1 the pdeathsig is being delivered to the container's init process by the kernel for some reason
 	// even with the parent still running.
@@ -493,7 +509,7 @@ func (c *linuxContainer) commandTemplate(p *Process, childPipe *os.File) (*exec.
 	return cmd, nil
 }

-func (c *linuxContainer) newInitProcess(p *Process, cmd *exec.Cmd, parentPipe, childPipe *os.File) (*initProcess, error) {
+func (c *linuxContainer) newInitProcess(p *Process, cmd *exec.Cmd, messageSockPair, logFilePair filePair) (*initProcess, error) {
 	cmd.Env = append(cmd.Env, "_LIBCONTAINER_INITTYPE="+string(initStandard))
 	nsMaps := make(map[configs.NamespaceType]string)
 	for _, ns := range c.config.Namespaces {
@@ -508,8 +524,8 @@ func (c *linuxContainer) newInitProcess(p *Process, cmd *exec.Cmd, parentPipe, c
 	}
 	init := &initProcess{
 		cmd:             cmd,
-		childPipe:       childPipe,
-		parentPipe:      parentPipe,
+		messageSockPair: messageSockPair,
+		logFilePair:     logFilePair,
 		manager:         c.cgroupManager,
 		intelRdtManager: c.intelRdtManager,
 		config:          c.newInitConfig(p),
@@ -522,7 +538,7 @@ func (c *linuxContainer) newInitProcess(p *Process, cmd *exec.Cmd, parentPipe, c
 	return init, nil
 }

-func (c *linuxContainer) newSetnsProcess(p *Process, cmd *exec.Cmd, parentPipe, childPipe *os.File) (*setnsProcess, error) {
+func (c *linuxContainer) newSetnsProcess(p *Process, cmd *exec.Cmd, messageSockPair, logFilePair filePair) (*setnsProcess, error) {
 	cmd.Env = append(cmd.Env, "_LIBCONTAINER_INITTYPE="+string(initSetns))
 	state, err := c.currentState()
 	if err != nil {
@@ -539,8 +555,8 @@ func (c *linuxContainer) newSetnsProcess(p *Process, cmd *exec.Cmd, parentPipe,
 		cgroupPaths:     c.cgroupManager.GetPaths(),
 		rootlessCgroups: c.config.RootlessCgroups,
 		intelRdtPath:    state.IntelRdtPath,
-		childPipe:       childPipe,
-		parentPipe:      parentPipe,
+		messageSockPair: messageSockPair,
+		logFilePair:     logFilePair,
 		config:          c.newInitConfig(p),
 		process:         p,
 		bootstrapData:   data,
@@ -114,6 +114,9 @@ func (m *mockProcess) externalDescriptors() []string {
 func (m *mockProcess) setExternalDescriptors(newFds []string) {
 }

+func (m *mockProcess) forwardChildLogs() {
+}
+
 func TestGetContainerPids(t *testing.T) {
 	container := &linuxContainer{
 		id:            "myid",
@@ -0,0 +1,102 @@
+package logs
+
+import (
+	"bufio"
+	"encoding/json"
+	"fmt"
+	"io"
+	"os"
+	"strconv"
+	"sync"
+
+	"github.com/sirupsen/logrus"
+)
+
+var (
+	configureMutex = sync.Mutex{}
+	// loggingConfigured will be set once logging has been configured via invoking `ConfigureLogging`.
+	// Subsequent invocations of `ConfigureLogging` would be no-op
+	loggingConfigured = false
+)
+
+type Config struct {
+	LogLevel    logrus.Level
+	LogFormat   string
+	LogFilePath string
+	LogPipeFd   string
+}
+
+func ForwardLogs(logPipe io.Reader) {
+	lineReader := bufio.NewReader(logPipe)
+	for {
+		line, err := lineReader.ReadBytes('\n')
+		if len(line) > 0 {
+			processEntry(line)
+		}
+		if err == io.EOF {
+			logrus.Debugf("log pipe has been closed: %+v", err)
+			return
+		}
+		if err != nil {
+			logrus.Errorf("log pipe read error: %+v", err)
+		}
+	}
+}
+
+func processEntry(text []byte) {
+	type jsonLog struct {
+		Level string `json:"level"`
+		Msg   string `json:"msg"`
+	}
+
+	var jl jsonLog
+	if err := json.Unmarshal(text, &jl); err != nil {
+		logrus.Errorf("failed to decode %q to json: %+v", text, err)
+		return
+	}
+
+	lvl, err := logrus.ParseLevel(jl.Level)
+	if err != nil {
+		logrus.Errorf("failed to parse log level %q: %v\n", jl.Level, err)
+		return
+	}
+	logrus.StandardLogger().Logf(lvl, jl.Msg)
+}
+
+func ConfigureLogging(config Config) error {
+	configureMutex.Lock()
+	defer configureMutex.Unlock()
+
+	if loggingConfigured {
+		logrus.Debug("logging has already been configured")
+		return nil
+	}
+
+	logrus.SetLevel(config.LogLevel)
+
+	if config.LogPipeFd != "" {
+		logPipeFdInt, err := strconv.Atoi(config.LogPipeFd)
+		if err != nil {
+			return fmt.Errorf("failed to convert _LIBCONTAINER_LOGPIPE environment variable value %q to int: %v", config.LogPipeFd, err)
+		}
+		logrus.SetOutput(os.NewFile(uintptr(logPipeFdInt), "logpipe"))
+	} else if config.LogFilePath != "" {
+		f, err := os.OpenFile(config.LogFilePath, os.O_CREATE|os.O_WRONLY|os.O_APPEND|os.O_SYNC, 0644)
+		if err != nil {
+			return err
+		}
+		logrus.SetOutput(f)
+	}
+
+	switch config.LogFormat {
+	case "text":
+		// retain logrus's default.
+	case "json":
+		logrus.SetFormatter(new(logrus.JSONFormatter))
+	default:
+		return fmt.Errorf("unknown log-format %q", config.LogFormat)
+	}
+
+	loggingConfigured = true
+	return nil
+}
@@ -0,0 +1,160 @@
+package logs
+
+import (
+	"errors"
+	"io/ioutil"
+	"os"
+	"strings"
+	"testing"
+	"time"
+
+	"github.com/sirupsen/logrus"
+)
+
+func TestLoggingToFile(t *testing.T) {
+	logW, logFile, _ := runLogForwarding(t)
+	defer os.Remove(logFile)
+	defer logW.Close()
+
+	logToLogWriter(t, logW, `{"level": "info","msg":"kitten"}`)
+
+	logFileContent := waitForLogContent(t, logFile)
+	if !strings.Contains(string(logFileContent), "kitten") {
+		t.Fatalf("%s does not contain kitten", string(logFileContent))
+	}
+}
+
+func TestLogForwardingDoesNotStopOnJsonDecodeErr(t *testing.T) {
+	logW, logFile, _ := runLogForwarding(t)
+	defer os.Remove(logFile)
+	defer logW.Close()
+
+	logToLogWriter(t, logW, "invalid-json-with-kitten")
+
+	logFileContent := waitForLogContent(t, logFile)
+	if !strings.Contains(string(logFileContent), "failed to decode") {
+		t.Fatalf("%q does not contain decoding error", string(logFileContent))
+	}
+
+	truncateLogFile(t, logFile)
+
+	logToLogWriter(t, logW, `{"level": "info","msg":"puppy"}`)
+
+	logFileContent = waitForLogContent(t, logFile)
+	if !strings.Contains(string(logFileContent), "puppy") {
+		t.Fatalf("%s does not contain puppy", string(logFileContent))
+	}
+}
+
+func TestLogForwardingDoesNotStopOnLogLevelParsingErr(t *testing.T) {
+	logW, logFile, _ := runLogForwarding(t)
+	defer os.Remove(logFile)
+	defer logW.Close()
+
+	logToLogWriter(t, logW, `{"level": "alert","msg":"puppy"}`)
+
+	logFileContent := waitForLogContent(t, logFile)
+	if !strings.Contains(string(logFileContent), "failed to parse log level") {
+		t.Fatalf("%q does not contain log level parsing error", string(logFileContent))
+	}
+
+	truncateLogFile(t, logFile)
+
+	logToLogWriter(t, logW, `{"level": "info","msg":"puppy"}`)
+
+	logFileContent = waitForLogContent(t, logFile)
+	if !strings.Contains(string(logFileContent), "puppy") {
+		t.Fatalf("%s does not contain puppy", string(logFileContent))
+	}
+}
+
+func TestLogForwardingStopsAfterClosingTheWriter(t *testing.T) {
+	logW, logFile, doneForwarding := runLogForwarding(t)
+	defer os.Remove(logFile)
+
+	logToLogWriter(t, logW, `{"level": "info","msg":"sync"}`)
+
+	logFileContent := waitForLogContent(t, logFile)
+	if !strings.Contains(string(logFileContent), "sync") {
+		t.Fatalf("%q does not contain sync message", string(logFileContent))
+	}
+
+	logW.Close()
+	select {
+	case <-doneForwarding:
+	case <-time.After(10 * time.Second):
+		t.Fatal("log forwarding did not stop after closing the pipe")
+	}
+}
+
+func logToLogWriter(t *testing.T, logW *os.File, message string) {
+	_, err := logW.Write([]byte(message + "\n"))
+	if err != nil {
+		t.Fatalf("failed to write %q to log writer: %v", message, err)
+	}
+}
+
+func runLogForwarding(t *testing.T) (*os.File, string, chan struct{}) {
+	logR, logW, err := os.Pipe()
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	tempFile, err := ioutil.TempFile("", "")
+	if err != nil {
+		t.Fatal(err)
+	}
+	logFile := tempFile.Name()
+
+	logConfig := Config{LogLevel: logrus.InfoLevel, LogFormat: "json", LogFilePath: logFile}
+	return logW, logFile, startLogForwarding(t, logConfig, logR)
+}
+
+func startLogForwarding(t *testing.T, logConfig Config, logR *os.File) chan struct{} {
+	loggingConfigured = false
+	if err := ConfigureLogging(logConfig); err != nil {
+		t.Fatal(err)
+	}
+	doneForwarding := make(chan struct{})
+	go func() {
+		ForwardLogs(logR)
+		close(doneForwarding)
+	}()
+	return doneForwarding
+}
+
+func waitForLogContent(t *testing.T, logFile string) string {
+	startTime := time.Now()
+
+	for {
+		if time.Now().After(startTime.Add(10 * time.Second)) {
+			t.Fatal(errors.New("No content in log file after 10 seconds"))
+			break
+		}
+
+		fileContent, err := ioutil.ReadFile(logFile)
+		if err != nil {
+			t.Fatal(err)
+		}
+		if len(fileContent) == 0 {
+			continue
+		}
+		return string(fileContent)
+	}
+
+	return ""
+}
+
+func truncateLogFile(t *testing.T, logFile string) {
+	file, err := os.OpenFile(logFile, os.O_RDWR, 0666)
+	if err != nil {
+		t.Fatalf("failed to open log file: %v", err)
+		return
+	}
+	defer file.Close()
+
+	err = file.Truncate(0)
+	if err != nil {
+		t.Fatalf("failed to truncate log file: %v", err)
+	}
+}
@@ -21,6 +21,11 @@ type pid struct {
 	Pid int `json:"Pid"`
 }

+type logentry struct {
+	Msg   string `json:"msg"`
+	Level string `json:"level"`
+}
+
 func TestNsenterValidPaths(t *testing.T) {
 	args := []string{"nsenter-exec"}
 	parent, child, err := newPipe()
@@ -159,6 +164,65 @@ func TestNsenterIncorrectPathType(t *testing.T) {
 	}
 }

+func TestNsenterChildLogging(t *testing.T) {
+	args := []string{"nsenter-exec"}
+	parent, child, err := newPipe()
+	if err != nil {
+		t.Fatalf("failed to create exec pipe %v", err)
+	}
+	logread, logwrite, err := os.Pipe()
+	if err != nil {
+		t.Fatalf("failed to create log pipe %v", err)
+	}
+	defer logread.Close()
+	defer logwrite.Close()
+
+	namespaces := []string{
+		// join pid ns of the current process
+		fmt.Sprintf("pid:/proc/%d/ns/pid", os.Getpid()),
+	}
+	cmd := &exec.Cmd{
+		Path:       os.Args[0],
+		Args:       args,
+		ExtraFiles: []*os.File{child, logwrite},
+		Env:        []string{"_LIBCONTAINER_INITPIPE=3", "_LIBCONTAINER_LOGPIPE=4"},
+		Stdout:     os.Stdout,
+		Stderr:     os.Stderr,
+	}
+
+	if err := cmd.Start(); err != nil {
+		t.Fatalf("nsenter failed to start %v", err)
+	}
+	// write cloneFlags
+	r := nl.NewNetlinkRequest(int(libcontainer.InitMsg), 0)
+	r.AddData(&libcontainer.Int32msg{
+		Type:  libcontainer.CloneFlagsAttr,
+		Value: uint32(unix.CLONE_NEWNET),
+	})
+	r.AddData(&libcontainer.Bytemsg{
+		Type:  libcontainer.NsPathsAttr,
+		Value: []byte(strings.Join(namespaces, ",")),
+	})
+	if _, err := io.Copy(parent, bytes.NewReader(r.Serialize())); err != nil {
+		t.Fatal(err)
+	}
+
+	logsDecoder := json.NewDecoder(logread)
+	var logentry *logentry
+
+	err = logsDecoder.Decode(&logentry)
+	if err != nil {
+		t.Fatalf("child log: %v", err)
+	}
+	if logentry.Level == "" || logentry.Msg == "" {
+		t.Fatalf("child log: empty log fileds: level=\"%s\" msg=\"%s\"", logentry.Level, logentry.Msg)
+	}
+
+	if err := cmd.Wait(); err != nil {
+		t.Fatalf("nsenter exits with a non-zero exit status")
+	}
+}
+
 func init() {
 	if strings.HasPrefix(os.Args[0], "nsenter-") {
 		os.Exit(0)
@@ -37,9 +37,6 @@ enum sync_t {
 	SYNC_RECVPID_ACK = 0x43,	/* PID was correctly received by parent. */
 	SYNC_GRANDCHILD = 0x44,	/* The grandchild is ready to run. */
 	SYNC_CHILD_READY = 0x45,	/* The child or grandchild is ready to return. */
-
-	/* XXX: This doesn't help with segfaults and other such issues. */
-	SYNC_ERR = 0xFF,	/* Fatal error, no turning back. The error code follows. */
 };

 /*
@@ -95,6 +92,15 @@ struct nlconfig_t {
 	size_t gidmappath_len;
 };

+#define PANIC   "panic"
+#define FATAL   "fatal"
+#define ERROR   "error"
+#define WARNING "warning"
+#define INFO    "info"
+#define DEBUG   "debug"
+
+static int logfd = -1;
+
 /*
 * List of netlink message types sent to us as part of bootstrapping the init.
 * These constants are defined in libcontainer/message_linux.go.
@@ -131,22 +137,34 @@ int setns(int fd, int nstype)
 }
 #endif

+static void write_log_with_info(const char *level, const char *function, int line, const char *format, ...)
+{
+	char message[1024] = {};
+
+	va_list args;
+
+	if (logfd < 0 || level == NULL)
+		return;
+
+	va_start(args, format);
+	if (vsnprintf(message, sizeof(message), format, args) < 0)
+		return;
+	va_end(args);
+
+	if (dprintf(logfd, "{\"level\":\"%s\", \"msg\": \"%s:%d %s\"}\n", level, function, line, message) < 0)
+		return;
+}
+
+#define write_log(level, fmt, ...) \
+	write_log_with_info((level), __FUNCTION__, __LINE__, (fmt), ##__VA_ARGS__)
+
 /* XXX: This is ugly. */
 static int syncfd = -1;

-/* TODO(cyphar): Fix this so it correctly deals with syncT. */
-#define bail(fmt, ...)								\
-	do {									\
-		int ret = __COUNTER__ + 1;					\
-		fprintf(stderr, "nsenter: " fmt ": %m\n", ##__VA_ARGS__);	\
-		if (syncfd >= 0) {						\
-			enum sync_t s = SYNC_ERR;				\
-			if (write(syncfd, &s, sizeof(s)) != sizeof(s))		\
-				fprintf(stderr, "nsenter: failed: write(s)");	\
-			if (write(syncfd, &ret, sizeof(ret)) != sizeof(ret))	\
-				fprintf(stderr, "nsenter: failed: write(ret)");	\
-		}								\
-		exit(ret);							\
+#define bail(fmt, ...)                                       \
+	do {                                                       \
+		write_log(FATAL, "nsenter: " fmt ": %m", ##__VA_ARGS__); \
+		exit(1);                                                 \
 	} while(0)

 static int write_file(char *data, size_t data_len, char *pathfmt, ...)
@@ -352,6 +370,23 @@ static int initpipe(void)
 	return pipenum;
 }

+static void setup_logpipe(void)
+{
+	char *logpipe, *endptr;
+
+	logpipe = getenv("_LIBCONTAINER_LOGPIPE");
+	if (logpipe == NULL || *logpipe == '\0') {
+		return;
+	}
+
+	logfd = strtol(logpipe, &endptr, 10);
+	if (logpipe == endptr || *endptr != '\0') {
+		fprintf(stderr, "unable to parse _LIBCONTAINER_LOGPIPE, value: %s\n", logpipe);
+		/* It is too early to use bail */
+		exit(1);
+	}
+}
+
 /* Returns the clone(2) flag for a namespace, given the name of a namespace. */
 static int nsflag(char *name)
 {
@@ -544,6 +579,12 @@ void nsexec(void)
 	int sync_child_pipe[2], sync_grandchild_pipe[2];
 	struct nlconfig_t config = { 0 };

+	/*
+	 * Setup a pipe to send logs to the parent. This should happen
+	 * first, because bail will use that pipe.
+	 */
+	setup_logpipe();
+
 	/*
 	 * If we don't have an init pipe, just return to the go routine.
 	 * We'll only get an init pipe for start or exec.
@@ -560,6 +601,8 @@ void nsexec(void)
 	if (ensure_cloned_binary() < 0)
 		bail("could not ensure we are a cloned binary");

+	write_log(DEBUG, "nsexec started");
+
 	/* Parse all of the netlink configuration. */
 	nl_parse(pipenum, &config);

@@ -676,7 +719,6 @@ void nsexec(void)
 			 */
 			while (!ready) {
 				enum sync_t s;
-				int ret;

 				syncfd = sync_child_pipe[1];
 				close(sync_child_pipe[0]);
@@ -685,12 +727,6 @@ void nsexec(void)
 					bail("failed to sync with child: next state");

 				switch (s) {
-				case SYNC_ERR:
-					/* We have to mirror the error code of the child. */
-					if (read(syncfd, &ret, sizeof(ret)) != sizeof(ret))
-						bail("failed to sync with child: read(error code)");
-
-					exit(ret);
 				case SYNC_USERMAP_PLS:
 					/*
 					 * Enable setgroups(2) if we've been asked to. But we also
@@ -759,7 +795,6 @@ void nsexec(void)
 			ready = false;
 			while (!ready) {
 				enum sync_t s;
-				int ret;

 				syncfd = sync_grandchild_pipe[1];
 				close(sync_grandchild_pipe[0]);
@@ -774,12 +809,6 @@ void nsexec(void)
 					bail("failed to sync with child: next state");

 				switch (s) {
-				case SYNC_ERR:
-					/* We have to mirror the error code of the child. */
-					if (read(syncfd, &ret, sizeof(ret)) != sizeof(ret))
-						bail("failed to sync with child: read(error code)");
-
-					exit(ret);
 				case SYNC_CHILD_READY:
 					ready = true;
 					break;
@@ -76,6 +76,8 @@ type Process struct {
 	Init bool

 	ops processOperations
+
+	LogLevel string
 }

 // Wait waits for the process to exit.
@@ -16,6 +16,7 @@ import (
 	"github.com/opencontainers/runc/libcontainer/cgroups"
 	"github.com/opencontainers/runc/libcontainer/configs"
 	"github.com/opencontainers/runc/libcontainer/intelrdt"
+	"github.com/opencontainers/runc/libcontainer/logs"
 	"github.com/opencontainers/runc/libcontainer/system"
 	"github.com/opencontainers/runc/libcontainer/utils"

@@ -47,12 +48,19 @@ type parentProcess interface {
 	externalDescriptors() []string

 	setExternalDescriptors(fds []string)
+
+	forwardChildLogs()
+}
+
+type filePair struct {
+	parent *os.File
+	child  *os.File
 }

 type setnsProcess struct {
 	cmd             *exec.Cmd
-	parentPipe      *os.File
-	childPipe       *os.File
+	messageSockPair filePair
+	logFilePair     filePair
 	cgroupPaths     map[string]string
 	rootlessCgroups bool
 	intelRdtPath    string
@@ -76,14 +84,16 @@ func (p *setnsProcess) signal(sig os.Signal) error {
 }

 func (p *setnsProcess) start() (err error) {
-	defer p.parentPipe.Close()
+	defer p.messageSockPair.parent.Close()
 	err = p.cmd.Start()
-	p.childPipe.Close()
+	// close the write-side of the pipes (controlled by child)
+	p.messageSockPair.child.Close()
+	p.logFilePair.child.Close()
 	if err != nil {
 		return newSystemErrorWithCause(err, "starting setns process")
 	}
 	if p.bootstrapData != nil {
-		if _, err := io.Copy(p.parentPipe, p.bootstrapData); err != nil {
+		if _, err := io.Copy(p.messageSockPair.parent, p.bootstrapData); err != nil {
 			return newSystemErrorWithCause(err, "copying bootstrap data to pipe")
 		}
 	}
@@ -109,11 +119,11 @@ func (p *setnsProcess) start() (err error) {
 	if err := setupRlimits(p.config.Rlimits, p.pid()); err != nil {
 		return newSystemErrorWithCause(err, "setting rlimits for process")
 	}
-	if err := utils.WriteJSON(p.parentPipe, p.config); err != nil {
+	if err := utils.WriteJSON(p.messageSockPair.parent, p.config); err != nil {
 		return newSystemErrorWithCause(err, "writing config to pipe")
 	}

-	ierr := parseSync(p.parentPipe, func(sync *syncT) error {
+	ierr := parseSync(p.messageSockPair.parent, func(sync *syncT) error {
 		switch sync.Type {
 		case procReady:
 			// This shouldn't happen.
@@ -126,7 +136,7 @@ func (p *setnsProcess) start() (err error) {
 		}
 	})

-	if err := unix.Shutdown(int(p.parentPipe.Fd()), unix.SHUT_WR); err != nil {
+	if err := unix.Shutdown(int(p.messageSockPair.parent.Fd()), unix.SHUT_WR); err != nil {
 		return newSystemErrorWithCause(err, "calling shutdown on init pipe")
 	}
 	// Must be done after Shutdown so the child will exit and we can wait for it.
@@ -152,7 +162,7 @@ func (p *setnsProcess) execSetns() error {
 		return newSystemError(&exec.ExitError{ProcessState: status})
 	}
 	var pid *pid
-	if err := json.NewDecoder(p.parentPipe).Decode(&pid); err != nil {
+	if err := json.NewDecoder(p.messageSockPair.parent).Decode(&pid); err != nil {
 		p.cmd.Wait()
 		return newSystemErrorWithCause(err, "reading pid from init pipe")
 	}
@@ -205,10 +215,14 @@ func (p *setnsProcess) setExternalDescriptors(newFds []string) {
 	p.fds = newFds
 }

+func (p *setnsProcess) forwardChildLogs() {
+	go logs.ForwardLogs(p.logFilePair.parent)
+}
+
 type initProcess struct {
 	cmd             *exec.Cmd
-	parentPipe      *os.File
-	childPipe       *os.File
+	messageSockPair filePair
+	logFilePair     filePair
 	config          *initConfig
 	manager         cgroups.Manager
 	intelRdtManager intelrdt.Manager
@@ -230,7 +244,7 @@ func (p *initProcess) externalDescriptors() []string {
 // getChildPid receives the final child's pid over the provided pipe.
 func (p *initProcess) getChildPid() (int, error) {
 	var pid pid
-	if err := json.NewDecoder(p.parentPipe).Decode(&pid); err != nil {
+	if err := json.NewDecoder(p.messageSockPair.parent).Decode(&pid); err != nil {
 		p.cmd.Wait()
 		return -1, err
 	}
@@ -266,10 +280,12 @@ func (p *initProcess) waitForChildExit(childPid int) error {
 }

 func (p *initProcess) start() error {
-	defer p.parentPipe.Close()
+	defer p.messageSockPair.parent.Close()
 	err := p.cmd.Start()
 	p.process.ops = p
-	p.childPipe.Close()
+	// close the write-side of the pipes (controlled by child)
+	p.messageSockPair.child.Close()
+	p.logFilePair.child.Close()
 	if err != nil {
 		p.process.ops = nil
 		return newSystemErrorWithCause(err, "starting init process command")
@@ -295,7 +311,7 @@ func (p *initProcess) start() error {
 		}
 	}()

-	if _, err := io.Copy(p.parentPipe, p.bootstrapData); err != nil {
+	if _, err := io.Copy(p.messageSockPair.parent, p.bootstrapData); err != nil {
 		return newSystemErrorWithCause(err, "copying bootstrap data to pipe")
 	}
 	childPid, err := p.getChildPid()
@@ -323,7 +339,7 @@ func (p *initProcess) start() error {
 	}
 	// Now it's time to setup cgroup namesapce
 	if p.config.Config.Namespaces.Contains(configs.NEWCGROUP) && p.config.Config.Namespaces.PathOf(configs.NEWCGROUP) == "" {
-		if _, err := p.parentPipe.Write([]byte{createCgroupns}); err != nil {
+		if _, err := p.messageSockPair.parent.Write([]byte{createCgroupns}); err != nil {
 			return newSystemErrorWithCause(err, "sending synchronization value to init process")
 		}
 	}
@@ -350,7 +366,7 @@ func (p *initProcess) start() error {
 		sentResume bool
 	)

-	ierr := parseSync(p.parentPipe, func(sync *syncT) error {
+	ierr := parseSync(p.messageSockPair.parent, func(sync *syncT) error {
 		switch sync.Type {
 		case procReady:
 			// set rlimits, this has to be done here because we lose permissions
@@ -386,7 +402,7 @@ func (p *initProcess) start() error {
 				}
 			}
 			// Sync with child.
-			if err := writeSync(p.parentPipe, procRun); err != nil {
+			if err := writeSync(p.messageSockPair.parent, procRun); err != nil {
 				return newSystemErrorWithCause(err, "writing syncT 'run'")
 			}
 			sentRun = true
@@ -415,7 +431,7 @@ func (p *initProcess) start() error {
 				}
 			}
 			// Sync with child.
-			if err := writeSync(p.parentPipe, procResume); err != nil {
+			if err := writeSync(p.messageSockPair.parent, procResume); err != nil {
 				return newSystemErrorWithCause(err, "writing syncT 'resume'")
 			}
 			sentResume = true
@@ -432,7 +448,7 @@ func (p *initProcess) start() error {
 	if p.config.Config.Namespaces.Contains(configs.NEWNS) && !sentResume {
 		return newSystemError(fmt.Errorf("could not synchronise after executing prestart hooks with container process"))
 	}
-	if err := unix.Shutdown(int(p.parentPipe.Fd()), unix.SHUT_WR); err != nil {
+	if err := unix.Shutdown(int(p.messageSockPair.parent.Fd()), unix.SHUT_WR); err != nil {
 		return newSystemErrorWithCause(err, "shutting down init pipe")
 	}

@@ -476,7 +492,7 @@ func (p *initProcess) sendConfig() error {
 	// send the config to the container's init process, we don't use JSON Encode
 	// here because there might be a problem in JSON decoder in some cases, see:
 	// https://github.com/docker/docker/issues/14203#issuecomment-174177790
-	return utils.WriteJSON(p.parentPipe, p.config)
+	return utils.WriteJSON(p.messageSockPair.parent, p.config)
 }

 func (p *initProcess) createNetworkInterfaces() error {
@@ -508,6 +524,10 @@ func (p *initProcess) setExternalDescriptors(newFds []string) {
 	p.fds = newFds
 }

+func (p *initProcess) forwardChildLogs() {
+	go logs.ForwardLogs(p.logFilePair.parent)
+}
+
 func getPipeFds(pid int) ([]string, error) {
 	fds := make([]string, 3)

@@ -76,6 +76,9 @@ func (p *restoredProcess) setExternalDescriptors(newFds []string) {
 	p.fds = newFds
 }

+func (p *restoredProcess) forwardChildLogs() {
+}
+
 // nonChildProcess represents a process where the calling process is not
 // the parent process.  This process is created when a factory loads a container from
 // a persisted state.
@@ -120,3 +123,6 @@ func (p *nonChildProcess) externalDescriptors() []string {
 func (p *nonChildProcess) setExternalDescriptors(newFds []string) {
 	p.fds = newFds
 }
+
+func (p *nonChildProcess) forwardChildLogs() {
+}
@@ -6,6 +6,8 @@ import (
 	"os"
 	"strings"

+	"github.com/opencontainers/runc/libcontainer/logs"
+
 	"github.com/opencontainers/runtime-spec/specs-go"

 	"github.com/sirupsen/logrus"
@@ -85,7 +87,7 @@ func main() {
 		},
 		cli.StringFlag{
 			Name:  "log",
-			Value: "/dev/null",
+			Value: "/dev/stderr",
 			Usage: "set the log file path where internal debug information is written",
 		},
 		cli.StringFlag{
@@ -133,26 +135,9 @@ func main() {
 		updateCommand,
 	}
 	app.Before = func(context *cli.Context) error {
-		if context.GlobalBool("debug") {
-			logrus.SetLevel(logrus.DebugLevel)
-		}
-		if path := context.GlobalString("log"); path != "" {
-			f, err := os.OpenFile(path, os.O_CREATE|os.O_WRONLY|os.O_APPEND|os.O_SYNC, 0666)
-			if err != nil {
-				return err
-			}
-			logrus.SetOutput(f)
-		}
-		switch context.GlobalString("log-format") {
-		case "text":
-			// retain logrus's default.
-		case "json":
-			logrus.SetFormatter(new(logrus.JSONFormatter))
-		default:
-			return fmt.Errorf("unknown log-format %q", context.GlobalString("log-format"))
-		}
-		return nil
+		return logs.ConfigureLogging(createLogConfig(context))
 	}
+
 	// If the command returns an error, cli takes upon itself to print
 	// the error on cli.ErrWriter and exit.
 	// Use our own writer here to ensure the log gets sent to the right location.
@@ -170,3 +155,16 @@ func (f *FatalWriter) Write(p []byte) (n int, err error) {
 	logrus.Error(string(p))
 	return f.cliErrWriter.Write(p)
 }
+
+func createLogConfig(context *cli.Context) logs.Config {
+	config := logs.Config{
+		LogLevel:    logrus.InfoLevel,
+		LogFilePath: context.GlobalString("log"),
+		LogFormat:   context.GlobalString("log-format"),
+	}
+	if context.GlobalBool("debug") {
+		config.LogLevel = logrus.DebugLevel
+	}
+
+	return config
+}
@@ -16,6 +16,11 @@ function teardown() {
  runc --debug run test_hello
  echo "${output}"
  [ "$status" -eq 0 ]
+
+  # check expected debug output was sent to stderr
+  [[ "${output}" == *"level=debug"* ]]
+  [[ "${output}" == *"nsexec started"* ]]
+  [[ "${output}" == *"child process in init()"* ]]
 }

@test "global --debug to --log" {
@@ -33,6 +38,8 @@ function teardown() {
  run cat log.out
  [ "$status" -eq 0 ]
  [[ "${output}" == *"level=debug"* ]]
+  [[ "${output}" == *"nsexec started"* ]]
+  [[ "${output}" == *"child process in init()"* ]]
 }

@test "global --debug to --log --log-format 'text'" {
@@ -50,6 +57,8 @@ function teardown() {
  run cat log.out
  [ "$status" -eq 0 ]
  [[ "${output}" == *"level=debug"* ]]
+  [[ "${output}" == *"nsexec started"* ]]
+  [[ "${output}" == *"child process in init()"* ]]
 }

@test "global --debug to --log --log-format 'json'" {
@@ -67,4 +76,6 @@ function teardown() {
  run cat log.out
  [ "$status" -eq 0 ]
  [[ "${output}" == *'"level":"debug"'* ]]
+  [[ "${output}" == *"nsexec started"* ]]
+  [[ "${output}" == *"child process in init()"* ]]
 }
@@ -65,7 +65,7 @@ function runc() {

 # Raw wrapper for runc.
 function __runc() {
-	"$RUNC" ${RUNC_USE_SYSTEMD+--systemd-cgroup} --log /proc/self/fd/2 --root "$ROOT" "$@"
+	"$RUNC" ${RUNC_USE_SYSTEMD+--systemd-cgroup} --root "$ROOT" "$@"
 }

 # Wrapper for runc spec, which takes only one argument (the bundle path).
@@ -105,7 +105,7 @@ func getDefaultImagePath(context *cli.Context) string {

 // newProcess returns a new libcontainer Process with the arguments from the
 // spec and stdio from the current process.
-func newProcess(p specs.Process, init bool) (*libcontainer.Process, error) {
+func newProcess(p specs.Process, init bool, logLevel string) (*libcontainer.Process, error) {
 	lp := &libcontainer.Process{
 		Args: p.Args,
 		Env:  p.Env,
@@ -116,6 +116,7 @@ func newProcess(p specs.Process, init bool) (*libcontainer.Process, error) {
 		NoNewPrivileges: &p.NoNewPrivileges,
 		AppArmorProfile: p.ApparmorProfile,
 		Init:            init,
+		LogLevel:        logLevel,
 	}

 	if p.ConsoleSize != nil {
@@ -264,6 +265,7 @@ type runner struct {
 	action          CtAct
 	notifySocket    *notifySocket
 	criuOpts        *libcontainer.CriuOpts
+	logLevel        string
 }

 func (r *runner) run(config *specs.Process) (int, error) {
@@ -271,7 +273,7 @@ func (r *runner) run(config *specs.Process) (int, error) {
 		r.destroy()
 		return -1, err
 	}
-	process, err := newProcess(*config, r.init)
+	process, err := newProcess(*config, r.init, r.logLevel)
 	if err != nil {
 		r.destroy()
 		return -1, err
@@ -430,6 +432,12 @@ func startContainer(context *cli.Context, spec *specs.Spec, action CtAct, criuOp
 	if os.Getenv("LISTEN_FDS") != "" {
 		listenFDs = activation.Files(false)
 	}
+
+	logLevel := "info"
+	if context.GlobalBool("debug") {
+		logLevel = "debug"
+	}
+
 	r := &runner{
 		enableSubreaper: !context.Bool("no-subreaper"),
 		shouldDestroy:   true,
@@ -443,6 +451,7 @@ func startContainer(context *cli.Context, spec *specs.Spec, action CtAct, criuOp
 		action:          action,
 		criuOpts:        criuOpts,
 		init:            true,
+		logLevel:        logLevel,
 	}
 	return r.run(spec.Process)
 }
@@ -7,7 +7,7 @@ github.com/checkpoint-restore/go-criu v3.11
 github.com/mrunalp/fileutils ed869b029674c0e9ce4c0dfa781405c2d9946d08
 github.com/opencontainers/selinux v1.2.2
 github.com/seccomp/libseccomp-golang 84e90a91acea0f4e51e62bc1a75de18b1fc0790f
-github.com/sirupsen/logrus a3f95b5c423586578a4e099b11a46c2479628cac
+github.com/sirupsen/logrus 8bdbc7bcc01dcbb8ec23dc8a28e332258d25251f
 github.com/syndtr/gocapability db04d3cc01c8b54962a58ec7e491717d06cfcc16
 github.com/vishvananda/netlink 1e2e08e8a2dcdacaae3f14ac44c5cfa31361f270
 # systemd integration.
@@ -1,7 +1,7 @@
 # Logrus <img src="http://i.imgur.com/hTeVwmJ.png" width="40" height="40" alt=":walrus:" class="emoji" title=":walrus:"/>&nbsp;[![Build Status](https://travis-ci.org/sirupsen/logrus.svg?branch=master)](https://travis-ci.org/sirupsen/logrus)&nbsp;[![GoDoc](https://godoc.org/github.com/sirupsen/logrus?status.svg)](https://godoc.org/github.com/sirupsen/logrus)

 Logrus is a structured logger for Go (golang), completely API compatible with
-the standard library logger. [Godoc][godoc].
+the standard library logger.

 **Seeing weird case-sensitive problems?** It's in the past been possible to
 import Logrus as both upper- and lower-case. Due to the Go package environment,
@@ -56,8 +56,39 @@ time="2015-03-26T01:27:38-04:00" level=warning msg="The group's number increased
 time="2015-03-26T01:27:38-04:00" level=debug msg="Temperature changes" temperature=-4
 time="2015-03-26T01:27:38-04:00" level=panic msg="It's over 9000!" animal=orca size=9009
 time="2015-03-26T01:27:38-04:00" level=fatal msg="The ice breaks!" err=&{0x2082280c0 map[animal:orca size:9009] 2015-03-26 01:27:38.441574009 -0400 EDT panic It's over 9000!} number=100 omg=true
-exit status 1
 ```
+To ensure this behaviour even if a TTY is attached, set your formatter as follows:
+
+```go
+	log.SetFormatter(&log.TextFormatter{
+		DisableColors: true,
+		FullTimestamp: true,
+	})
+```
+
+#### Logging Method Name
+
+If you wish to add the calling method as a field, instruct the logger via:
+```go
+log.SetReportCaller(true)
+```
+This adds the caller as 'method' like so:
+
+```json
+{"animal":"penguin","level":"fatal","method":"github.com/sirupsen/arcticcreatures.migrate","msg":"a penguin swims by",
+"time":"2014-03-10 19:57:38.562543129 -0400 EDT"}
+```
+
+```text
+time="2015-03-26T01:27:38-04:00" level=fatal method=github.com/sirupsen/arcticcreatures.migrate msg="a penguin swims by" animal=penguin
+```
+Note that this does add measurable overhead - the cost will depend on the version of Go, but is
+between 20 and 40% in recent tests with 1.6 and 1.7.  You can validate this in your
+environment via benchmarks: 
+```
+go test -bench=.*CallerTracing
+```
+

 #### Case-sensitivity

@@ -220,7 +251,7 @@ Logrus comes with [built-in hooks](hooks/). Add those, or your custom hook, in
 ```go
 import (
  log "github.com/sirupsen/logrus"
-  "gopkg.in/gemnasium/logrus-airbrake-hook.v2" // the package is named "aibrake"
+  "gopkg.in/gemnasium/logrus-airbrake-hook.v2" // the package is named "airbrake"
  logrus_syslog "github.com/sirupsen/logrus/hooks/syslog"
  "log/syslog"
 )
@@ -241,60 +272,15 @@ func init() {
 ```
 Note: Syslog hook also support connecting to local syslog (Ex. "/dev/log" or "/var/run/syslog" or "/var/run/log"). For the detail, please check the [syslog hook README](hooks/syslog/README.md).

-| Hook  | Description |
-| ----- | ----------- |
-| [Airbrake "legacy"](https://github.com/gemnasium/logrus-airbrake-legacy-hook) | Send errors to an exception tracking service compatible with the Airbrake API V2. Uses [`airbrake-go`](https://github.com/tobi/airbrake-go) behind the scenes. |
-| [Airbrake](https://github.com/gemnasium/logrus-airbrake-hook) | Send errors to the Airbrake API V3. Uses the official [`gobrake`](https://github.com/airbrake/gobrake) behind the scenes. |
-| [Amazon Kinesis](https://github.com/evalphobia/logrus_kinesis) | Hook for logging to [Amazon Kinesis](https://aws.amazon.com/kinesis/) |
-| [Amqp-Hook](https://github.com/vladoatanasov/logrus_amqp) | Hook for logging to Amqp broker (Like RabbitMQ) |
-| [Bugsnag](https://github.com/Shopify/logrus-bugsnag/blob/master/bugsnag.go) | Send errors to the Bugsnag exception tracking service. |
-| [DeferPanic](https://github.com/deferpanic/dp-logrus) | Hook for logging to DeferPanic |
-| [Discordrus](https://github.com/kz/discordrus) | Hook for logging to [Discord](https://discordapp.com/) |
-| [ElasticSearch](https://github.com/sohlich/elogrus) | Hook for logging to ElasticSearch|
-| [Firehose](https://github.com/beaubrewer/logrus_firehose) | Hook for logging to [Amazon Firehose](https://aws.amazon.com/kinesis/firehose/)
-| [Fluentd](https://github.com/evalphobia/logrus_fluent) | Hook for logging to fluentd |
-| [Go-Slack](https://github.com/multiplay/go-slack) | Hook for logging to [Slack](https://slack.com) |
-| [Graylog](https://github.com/gemnasium/logrus-graylog-hook) | Hook for logging to [Graylog](http://graylog2.org/) |
-| [Hiprus](https://github.com/nubo/hiprus) | Send errors to a channel in hipchat. |
-| [Honeybadger](https://github.com/agonzalezro/logrus_honeybadger) | Hook for sending exceptions to Honeybadger |
-| [InfluxDB](https://github.com/Abramovic/logrus_influxdb) | Hook for logging to influxdb |
-| [Influxus](http://github.com/vlad-doru/influxus) | Hook for concurrently logging to [InfluxDB](http://influxdata.com/) |
-| [Journalhook](https://github.com/wercker/journalhook) | Hook for logging to `systemd-journald` |
-| [KafkaLogrus](https://github.com/goibibo/KafkaLogrus) | Hook for logging to kafka |
-| [LFShook](https://github.com/rifflock/lfshook) | Hook for logging to the local filesystem |
-| [Logentries](https://github.com/jcftang/logentriesrus) | Hook for logging to [Logentries](https://logentries.com/) |
-| [Logentrus](https://github.com/puddingfactory/logentrus) | Hook for logging to [Logentries](https://logentries.com/) |
-| [Logmatic.io](https://github.com/logmatic/logmatic-go) | Hook for logging to [Logmatic.io](http://logmatic.io/) |
-| [Logrusly](https://github.com/sebest/logrusly) | Send logs to [Loggly](https://www.loggly.com/) |
-| [Logstash](https://github.com/bshuster-repo/logrus-logstash-hook) | Hook for logging to [Logstash](https://www.elastic.co/products/logstash) |
-| [Mail](https://github.com/zbindenren/logrus_mail) | Hook for sending exceptions via mail |
-| [Mattermost](https://github.com/shuLhan/mattermost-integration/tree/master/hooks/logrus) | Hook for logging to [Mattermost](https://mattermost.com/) |
-| [Mongodb](https://github.com/weekface/mgorus) | Hook for logging to mongodb |
-| [NATS-Hook](https://github.com/rybit/nats_logrus_hook) | Hook for logging to [NATS](https://nats.io) |
-| [Octokit](https://github.com/dorajistyle/logrus-octokit-hook) | Hook for logging to github via octokit |
-| [Papertrail](https://github.com/polds/logrus-papertrail-hook) | Send errors to the [Papertrail](https://papertrailapp.com) hosted logging service via UDP. |
-| [PostgreSQL](https://github.com/gemnasium/logrus-postgresql-hook) | Send logs to [PostgreSQL](http://postgresql.org) |
-| [Pushover](https://github.com/toorop/logrus_pushover) | Send error via [Pushover](https://pushover.net) |
-| [Raygun](https://github.com/squirkle/logrus-raygun-hook) | Hook for logging to [Raygun.io](http://raygun.io/) |
-| [Redis-Hook](https://github.com/rogierlommers/logrus-redis-hook) | Hook for logging to a ELK stack (through Redis) |
-| [Rollrus](https://github.com/heroku/rollrus) | Hook for sending errors to rollbar |
-| [Scribe](https://github.com/sagar8192/logrus-scribe-hook) | Hook for logging to [Scribe](https://github.com/facebookarchive/scribe)|
-| [Sentry](https://github.com/evalphobia/logrus_sentry) | Send errors to the Sentry error logging and aggregation service. |
-| [Slackrus](https://github.com/johntdyer/slackrus) | Hook for Slack chat. |
-| [Stackdriver](https://github.com/knq/sdhook) | Hook for logging to [Google Stackdriver](https://cloud.google.com/logging/) |
-| [Sumorus](https://github.com/doublefree/sumorus) | Hook for logging to [SumoLogic](https://www.sumologic.com/)|
-| [Syslog](https://github.com/sirupsen/logrus/blob/master/hooks/syslog/syslog.go) | Send errors to remote syslog server. Uses standard library `log/syslog` behind the scenes. |
-| [Syslog TLS](https://github.com/shinji62/logrus-syslog-ng) | Send errors to remote syslog server with TLS support. |
-| [TraceView](https://github.com/evalphobia/logrus_appneta) | Hook for logging to [AppNeta TraceView](https://www.appneta.com/products/traceview/) |
-| [Typetalk](https://github.com/dragon3/logrus-typetalk-hook) | Hook for logging to [Typetalk](https://www.typetalk.in/) |
-| [logz.io](https://github.com/ripcurld00d/logrus-logzio-hook) | Hook for logging to [logz.io](https://logz.io), a Log as a Service using Logstash |
-| [SQS-Hook](https://github.com/tsarpaul/logrus_sqs) | Hook for logging to [Amazon Simple Queue Service (SQS)](https://aws.amazon.com/sqs/) |
+A list of currently known of service hook can be found in this wiki [page](https://github.com/sirupsen/logrus/wiki/Hooks)
+

 #### Level logging

-Logrus has six logging levels: Debug, Info, Warning, Error, Fatal and Panic.
+Logrus has seven logging levels: Trace, Debug, Info, Warning, Error, Fatal and Panic.

 ```go
+log.Trace("Something very low level.")
 log.Debug("Useful debugging information.")
 log.Info("Something noteworthy happened!")
 log.Warn("You should probably take a look at this.")
@@ -366,15 +352,20 @@ The built-in logging formatters are:
    field to `true`.  To force no colored output even if there is a TTY  set the
    `DisableColors` field to `true`. For Windows, see
    [github.com/mattn/go-colorable](https://github.com/mattn/go-colorable).
+  * When colors are enabled, levels are truncated to 4 characters by default. To disable
+    truncation set the `DisableLevelTruncation` field to `true`.
  * All options are listed in the [generated docs](https://godoc.org/github.com/sirupsen/logrus#TextFormatter).
 * `logrus.JSONFormatter`. Logs fields as JSON.
  * All options are listed in the [generated docs](https://godoc.org/github.com/sirupsen/logrus#JSONFormatter).

 Third party logging formatters:

+* [`FluentdFormatter`](https://github.com/joonix/log). Formats entries that can be parsed by Kubernetes and Google Container Engine.
+* [`GELF`](https://github.com/fabienm/go-logrus-formatters). Formats entries so they comply to Graylog's [GELF 1.1 specification](http://docs.graylog.org/en/2.4/pages/gelf.html).
 * [`logstash`](https://github.com/bshuster-repo/logrus-logstash-hook). Logs fields as [Logstash](http://logstash.net) Events.
 * [`prefixed`](https://github.com/x-cray/logrus-prefixed-formatter). Displays log entry source along with alternative layout.
 * [`zalgo`](https://github.com/aybabtme/logzalgo). Invoking the P͉̫o̳̼̊w̖͈̰͎e̬͔̭͂r͚̼̹̲ ̫͓͉̳͈ō̠͕͖̚f̝͍̠ ͕̲̞͖͑Z̖̫̤̫ͪa͉̬͈̗l͖͎g̳̥o̰̥̅!̣͔̲̻͊̄ ̙̘̦̹̦.
+* [`nested-logrus-formatter`](https://github.com/antonfisher/nested-logrus-formatter). Converts logrus fields to a nested structure.

 You can define your formatter by implementing the `Formatter` interface,
 requiring a `Format` method. `Format` takes an `*Entry`. `entry.Data` is a
@@ -488,7 +479,7 @@ logrus.RegisterExitHandler(handler)

 #### Thread safety

-By default Logger is protected by mutex for concurrent writes, this mutex is invoked when calling hooks and writing logs.
+By default, Logger is protected by a mutex for concurrent writes. The mutex is held when calling hooks and writing logs.
 If you are sure such locking is not needed, you can call logger.SetNoLock() to disable the locking.

 Situation when locking is not needed includes:
@@ -51,9 +51,9 @@ func Exit(code int) {
 	os.Exit(code)
 }

-// RegisterExitHandler adds a Logrus Exit handler, call logrus.Exit to invoke
-// all handlers. The handlers will also be invoked when any Fatal log entry is
-// made.
+// RegisterExitHandler appends a Logrus Exit handler to the list of handlers,
+// call logrus.Exit to invoke all handlers. The handlers will also be invoked when
+// any Fatal log entry is made.
 //
 // This method is useful when a caller wishes to use logrus to log a fatal
 // message but also needs to gracefully shutdown. An example usecase could be
@@ -62,3 +62,15 @@ func Exit(code int) {
 func RegisterExitHandler(handler func()) {
 	handlers = append(handlers, handler)
 }
+
+// DeferExitHandler prepends a Logrus Exit handler to the list of handlers,
+// call logrus.Exit to invoke all handlers. The handlers will also be invoked when
+// any Fatal log entry is made.
+//
+// This method is useful when a caller wishes to use logrus to log a fatal
+// message but also needs to gracefully shutdown. An example usecase could be
+// closing database connections, or sending a alert that the application is
+// closing.
+func DeferExitHandler(handler func()) {
+	handlers = append([]func(){handler}, handlers...)
+}
@@ -2,13 +2,33 @@ package logrus

 import (
 	"bytes"
+	"context"
 	"fmt"
 	"os"
+	"reflect"
+	"runtime"
+	"strings"
 	"sync"
 	"time"
 )

-var bufferPool *sync.Pool
+var (
+	bufferPool *sync.Pool
+
+	// qualified package name, cached at first use
+	logrusPackage string
+
+	// Positions in the call stack when tracing to report the calling method
+	minimumCallerDepth int
+
+	// Used for caller information initialisation
+	callerInitOnce sync.Once
+)
+
+const (
+	maximumCallerDepth int = 25
+	knownLogrusFrames  int = 4
+)

 func init() {
 	bufferPool = &sync.Pool{
@@ -16,15 +36,18 @@ func init() {
 			return new(bytes.Buffer)
 		},
 	}
+
+	// start at the bottom of the stack before the package-name cache is primed
+	minimumCallerDepth = 1
 }

 // Defines the key when adding errors using WithError.
 var ErrorKey = "error"

 // An entry is the final or intermediate Logrus logging entry. It contains all
-// the fields passed with WithField{,s}. It's finally logged when Debug, Info,
-// Warn, Error, Fatal or Panic is called on it. These objects can be reused and
-// passed around as much as you wish to avoid field duplication.
+// the fields passed with WithField{,s}. It's finally logged when Trace, Debug,
+// Info, Warn, Error, Fatal or Panic is called on it. These objects can be
+// reused and passed around as much as you wish to avoid field duplication.
 type Entry struct {
 	Logger *Logger

@@ -34,21 +57,31 @@ type Entry struct {
 	// Time at which the log entry was created
 	Time time.Time

-	// Level the log entry was logged at: Debug, Info, Warn, Error, Fatal or Panic
+	// Level the log entry was logged at: Trace, Debug, Info, Warn, Error, Fatal or Panic
+	// This field will be set on entry firing and the value will be equal to the one in Logger struct field.
 	Level Level

-	// Message passed to Debug, Info, Warn, Error, Fatal or Panic
+	// Calling method, with package name
+	Caller *runtime.Frame
+
+	// Message passed to Trace, Debug, Info, Warn, Error, Fatal or Panic
 	Message string

-	// When formatter is called in entry.log(), an Buffer may be set to entry
+	// When formatter is called in entry.log(), a Buffer may be set to entry
 	Buffer *bytes.Buffer
+
+	// Contains the context set by the user. Useful for hook processing etc.
+	Context context.Context
+
+	// err may contain a field formatting error
+	err string
 }

 func NewEntry(logger *Logger) *Entry {
 	return &Entry{
 		Logger: logger,
-		// Default is three fields, give a little extra room
-		Data: make(Fields, 5),
+		// Default is three fields, plus one optional.  Give a little extra room.
+		Data: make(Fields, 6),
 	}
 }

@@ -68,6 +101,11 @@ func (entry *Entry) WithError(err error) *Entry {
 	return entry.WithField(ErrorKey, err)
 }

+// Add a context to the Entry.
+func (entry *Entry) WithContext(ctx context.Context) *Entry {
+	return &Entry{Logger: entry.Logger, Data: entry.Data, Time: entry.Time, err: entry.err, Context: ctx}
+}
+
 // Add a single field to the Entry.
 func (entry *Entry) WithField(key string, value interface{}) *Entry {
 	return entry.WithFields(Fields{key: value})
@@ -79,43 +117,120 @@ func (entry *Entry) WithFields(fields Fields) *Entry {
 	for k, v := range entry.Data {
 		data[k] = v
 	}
+	fieldErr := entry.err
 	for k, v := range fields {
-		data[k] = v
+		isErrField := false
+		if t := reflect.TypeOf(v); t != nil {
+			switch t.Kind() {
+			case reflect.Func:
+				isErrField = true
+			case reflect.Ptr:
+				isErrField = t.Elem().Kind() == reflect.Func
+			}
+		}
+		if isErrField {
+			tmp := fmt.Sprintf("can not add field %q", k)
+			if fieldErr != "" {
+				fieldErr = entry.err + ", " + tmp
+			} else {
+				fieldErr = tmp
+			}
+		} else {
+			data[k] = v
+		}
 	}
-	return &Entry{Logger: entry.Logger, Data: data}
+	return &Entry{Logger: entry.Logger, Data: data, Time: entry.Time, err: fieldErr, Context: entry.Context}
+}
+
+// Overrides the time of the Entry.
+func (entry *Entry) WithTime(t time.Time) *Entry {
+	return &Entry{Logger: entry.Logger, Data: entry.Data, Time: t, err: entry.err, Context: entry.Context}
+}
+
+// getPackageName reduces a fully qualified function name to the package name
+// There really ought to be to be a better way...
+func getPackageName(f string) string {
+	for {
+		lastPeriod := strings.LastIndex(f, ".")
+		lastSlash := strings.LastIndex(f, "/")
+		if lastPeriod > lastSlash {
+			f = f[:lastPeriod]
+		} else {
+			break
+		}
+	}
+
+	return f
+}
+
+// getCaller retrieves the name of the first non-logrus calling function
+func getCaller() *runtime.Frame {
+
+	// cache this package's fully-qualified name
+	callerInitOnce.Do(func() {
+		pcs := make([]uintptr, 2)
+		_ = runtime.Callers(0, pcs)
+		logrusPackage = getPackageName(runtime.FuncForPC(pcs[1]).Name())
+
+		// now that we have the cache, we can skip a minimum count of known-logrus functions
+		// XXX this is dubious, the number of frames may vary
+		minimumCallerDepth = knownLogrusFrames
+	})
+
+	// Restrict the lookback frames to avoid runaway lookups
+	pcs := make([]uintptr, maximumCallerDepth)
+	depth := runtime.Callers(minimumCallerDepth, pcs)
+	frames := runtime.CallersFrames(pcs[:depth])
+
+	for f, again := frames.Next(); again; f, again = frames.Next() {
+		pkg := getPackageName(f.Function)
+
+		// If the caller isn't part of this package, we're done
+		if pkg != logrusPackage {
+			return &f
+		}
+	}
+
+	// if we got here, we failed to find the caller's context
+	return nil
+}
+
+func (entry Entry) HasCaller() (has bool) {
+	return entry.Logger != nil &&
+		entry.Logger.ReportCaller &&
+		entry.Caller != nil
 }

 // This function is not declared with a pointer value because otherwise
 // race conditions will occur when using multiple goroutines
 func (entry Entry) log(level Level, msg string) {
 	var buffer *bytes.Buffer
-	entry.Time = time.Now()
+
+	// Default to now, but allow users to override if they want.
+	//
+	// We don't have to worry about polluting future calls to Entry#log()
+	// with this assignment because this function is declared with a
+	// non-pointer receiver.
+	if entry.Time.IsZero() {
+		entry.Time = time.Now()
+	}
+
 	entry.Level = level
 	entry.Message = msg
-
-	if err := entry.Logger.Hooks.Fire(level, &entry); err != nil {
-		entry.Logger.mu.Lock()
-		fmt.Fprintf(os.Stderr, "Failed to fire hook: %v\n", err)
-		entry.Logger.mu.Unlock()
+	if entry.Logger.ReportCaller {
+		entry.Caller = getCaller()
 	}
+
+	entry.fireHooks()
+
 	buffer = bufferPool.Get().(*bytes.Buffer)
 	buffer.Reset()
 	defer bufferPool.Put(buffer)
 	entry.Buffer = buffer
-	serialized, err := entry.Logger.Formatter.Format(&entry)
+
+	entry.write()
+
 	entry.Buffer = nil
-	if err != nil {
-		entry.Logger.mu.Lock()
-		fmt.Fprintf(os.Stderr, "Failed to obtain reader, %v\n", err)
-		entry.Logger.mu.Unlock()
-	} else {
-		entry.Logger.mu.Lock()
-		_, err = entry.Logger.Out.Write(serialized)
-		if err != nil {
-			fmt.Fprintf(os.Stderr, "Failed to write to log, %v\n", err)
-		}
-		entry.Logger.mu.Unlock()
-	}

 	// To avoid Entry#log() returning a value that only would make sense for
 	// panic() to use in Entry#Panic(), we avoid the allocation by checking
@@ -125,26 +240,53 @@ func (entry Entry) log(level Level, msg string) {
 	}
 }

-func (entry *Entry) Debug(args ...interface{}) {
-	if entry.Logger.level() >= DebugLevel {
-		entry.log(DebugLevel, fmt.Sprint(args...))
+func (entry *Entry) fireHooks() {
+	entry.Logger.mu.Lock()
+	defer entry.Logger.mu.Unlock()
+	err := entry.Logger.Hooks.Fire(entry.Level, entry)
+	if err != nil {
+		fmt.Fprintf(os.Stderr, "Failed to fire hook: %v\n", err)
 	}
 }

+func (entry *Entry) write() {
+	entry.Logger.mu.Lock()
+	defer entry.Logger.mu.Unlock()
+	serialized, err := entry.Logger.Formatter.Format(entry)
+	if err != nil {
+		fmt.Fprintf(os.Stderr, "Failed to obtain reader, %v\n", err)
+	} else {
+		_, err = entry.Logger.Out.Write(serialized)
+		if err != nil {
+			fmt.Fprintf(os.Stderr, "Failed to write to log, %v\n", err)
+		}
+	}
+}
+
+func (entry *Entry) Log(level Level, args ...interface{}) {
+	if entry.Logger.IsLevelEnabled(level) {
+		entry.log(level, fmt.Sprint(args...))
+	}
+}
+
+func (entry *Entry) Trace(args ...interface{}) {
+	entry.Log(TraceLevel, args...)
+}
+
+func (entry *Entry) Debug(args ...interface{}) {
+	entry.Log(DebugLevel, args...)
+}
+
 func (entry *Entry) Print(args ...interface{}) {
 	entry.Info(args...)
 }

 func (entry *Entry) Info(args ...interface{}) {
-	if entry.Logger.level() >= InfoLevel {
-		entry.log(InfoLevel, fmt.Sprint(args...))
-	}
+	entry.Log(InfoLevel, args...)
 }

 func (entry *Entry) Warn(args ...interface{}) {
-	if entry.Logger.level() >= WarnLevel {
-		entry.log(WarnLevel, fmt.Sprint(args...))
-	}
+	entry.Log(WarnLevel, args...)
 }

 func (entry *Entry) Warning(args ...interface{}) {
@@ -152,37 +294,37 @@ func (entry *Entry) Warning(args ...interface{}) {
 }

 func (entry *Entry) Error(args ...interface{}) {
-	if entry.Logger.level() >= ErrorLevel {
-		entry.log(ErrorLevel, fmt.Sprint(args...))
-	}
+	entry.Log(ErrorLevel, args...)
 }

 func (entry *Entry) Fatal(args ...interface{}) {
-	if entry.Logger.level() >= FatalLevel {
-		entry.log(FatalLevel, fmt.Sprint(args...))
-	}
-	Exit(1)
+	entry.Log(FatalLevel, args...)
+	entry.Logger.Exit(1)
 }

 func (entry *Entry) Panic(args ...interface{}) {
-	if entry.Logger.level() >= PanicLevel {
-		entry.log(PanicLevel, fmt.Sprint(args...))
-	}
+	entry.Log(PanicLevel, args...)
 	panic(fmt.Sprint(args...))
 }

 // Entry Printf family functions

-func (entry *Entry) Debugf(format string, args ...interface{}) {
-	if entry.Logger.level() >= DebugLevel {
-		entry.Debug(fmt.Sprintf(format, args...))
+func (entry *Entry) Logf(level Level, format string, args ...interface{}) {
+	if entry.Logger.IsLevelEnabled(level) {
+		entry.Log(level, fmt.Sprintf(format, args...))
 	}
 }

+func (entry *Entry) Tracef(format string, args ...interface{}) {
+	entry.Logf(TraceLevel, format, args...)
+}
+
+func (entry *Entry) Debugf(format string, args ...interface{}) {
+	entry.Logf(DebugLevel, format, args...)
+}
+
 func (entry *Entry) Infof(format string, args ...interface{}) {
-	if entry.Logger.level() >= InfoLevel {
-		entry.Info(fmt.Sprintf(format, args...))
-	}
+	entry.Logf(InfoLevel, format, args...)
 }

 func (entry *Entry) Printf(format string, args ...interface{}) {
@@ -190,9 +332,7 @@ func (entry *Entry) Printf(format string, args ...interface{}) {
 }

 func (entry *Entry) Warnf(format string, args ...interface{}) {
-	if entry.Logger.level() >= WarnLevel {
-		entry.Warn(fmt.Sprintf(format, args...))
-	}
+	entry.Logf(WarnLevel, format, args...)
 }

 func (entry *Entry) Warningf(format string, args ...interface{}) {
@@ -200,36 +340,36 @@ func (entry *Entry) Warningf(format string, args ...interface{}) {
 }

 func (entry *Entry) Errorf(format string, args ...interface{}) {
-	if entry.Logger.level() >= ErrorLevel {
-		entry.Error(fmt.Sprintf(format, args...))
-	}
+	entry.Logf(ErrorLevel, format, args...)
 }

 func (entry *Entry) Fatalf(format string, args ...interface{}) {
-	if entry.Logger.level() >= FatalLevel {
-		entry.Fatal(fmt.Sprintf(format, args...))
-	}
-	Exit(1)
+	entry.Logf(FatalLevel, format, args...)
+	entry.Logger.Exit(1)
 }

 func (entry *Entry) Panicf(format string, args ...interface{}) {
-	if entry.Logger.level() >= PanicLevel {
-		entry.Panic(fmt.Sprintf(format, args...))
-	}
+	entry.Logf(PanicLevel, format, args...)
 }

 // Entry Println family functions

-func (entry *Entry) Debugln(args ...interface{}) {
-	if entry.Logger.level() >= DebugLevel {
-		entry.Debug(entry.sprintlnn(args...))
+func (entry *Entry) Logln(level Level, args ...interface{}) {
+	if entry.Logger.IsLevelEnabled(level) {
+		entry.Log(level, entry.sprintlnn(args...))
 	}
 }

+func (entry *Entry) Traceln(args ...interface{}) {
+	entry.Logln(TraceLevel, args...)
+}
+
+func (entry *Entry) Debugln(args ...interface{}) {
+	entry.Logln(DebugLevel, args...)
+}
+
 func (entry *Entry) Infoln(args ...interface{}) {
-	if entry.Logger.level() >= InfoLevel {
-		entry.Info(entry.sprintlnn(args...))
-	}
+	entry.Logln(InfoLevel, args...)
 }

 func (entry *Entry) Println(args ...interface{}) {
@@ -237,9 +377,7 @@ func (entry *Entry) Println(args ...interface{}) {
 }

 func (entry *Entry) Warnln(args ...interface{}) {
-	if entry.Logger.level() >= WarnLevel {
-		entry.Warn(entry.sprintlnn(args...))
-	}
+	entry.Logln(WarnLevel, args...)
 }

 func (entry *Entry) Warningln(args ...interface{}) {
@@ -247,22 +385,16 @@ func (entry *Entry) Warningln(args ...interface{}) {
 }

 func (entry *Entry) Errorln(args ...interface{}) {
-	if entry.Logger.level() >= ErrorLevel {
-		entry.Error(entry.sprintlnn(args...))
-	}
+	entry.Logln(ErrorLevel, args...)
 }

 func (entry *Entry) Fatalln(args ...interface{}) {
-	if entry.Logger.level() >= FatalLevel {
-		entry.Fatal(entry.sprintlnn(args...))
-	}
-	Exit(1)
+	entry.Logln(FatalLevel, args...)
+	entry.Logger.Exit(1)
 }

 func (entry *Entry) Panicln(args ...interface{}) {
-	if entry.Logger.level() >= PanicLevel {
-		entry.Panic(entry.sprintlnn(args...))
-	}
+	entry.Logln(PanicLevel, args...)
 }

 // Sprintlnn => Sprint no newline. This is to get the behavior of how
@@ -1,7 +1,9 @@
 package logrus

 import (
+	"context"
 	"io"
+	"time"
 )

 var (
@@ -15,37 +17,38 @@ func StandardLogger() *Logger {

 // SetOutput sets the standard logger output.
 func SetOutput(out io.Writer) {
-	std.mu.Lock()
-	defer std.mu.Unlock()
-	std.Out = out
+	std.SetOutput(out)
 }

 // SetFormatter sets the standard logger formatter.
 func SetFormatter(formatter Formatter) {
-	std.mu.Lock()
-	defer std.mu.Unlock()
-	std.Formatter = formatter
+	std.SetFormatter(formatter)
+}
+
+// SetReportCaller sets whether the standard logger will include the calling
+// method as a field.
+func SetReportCaller(include bool) {
+	std.SetReportCaller(include)
 }

 // SetLevel sets the standard logger level.
 func SetLevel(level Level) {
-	std.mu.Lock()
-	defer std.mu.Unlock()
 	std.SetLevel(level)
 }

 // GetLevel returns the standard logger level.
 func GetLevel() Level {
-	std.mu.Lock()
-	defer std.mu.Unlock()
-	return std.level()
+	return std.GetLevel()
+}
+
+// IsLevelEnabled checks if the log level of the standard logger is greater than the level param
+func IsLevelEnabled(level Level) bool {
+	return std.IsLevelEnabled(level)
 }

 // AddHook adds a hook to the standard logger hooks.
 func AddHook(hook Hook) {
-	std.mu.Lock()
-	defer std.mu.Unlock()
-	std.Hooks.Add(hook)
+	std.AddHook(hook)
 }

 // WithError creates an entry from the standard logger and adds an error to it, using the value defined in ErrorKey as key.
@@ -53,6 +56,11 @@ func WithError(err error) *Entry {
 	return std.WithField(ErrorKey, err)
 }

+// WithContext creates an entry from the standard logger and adds a context to it.
+func WithContext(ctx context.Context) *Entry {
+	return std.WithContext(ctx)
+}
+
 // WithField creates an entry from the standard logger and adds a field to
 // it. If you want multiple fields, use `WithFields`.
 //
@@ -72,6 +80,20 @@ func WithFields(fields Fields) *Entry {
 	return std.WithFields(fields)
 }

+// WithTime creats an entry from the standard logger and overrides the time of
+// logs generated with it.
+//
+// Note that it doesn't log until you call Debug, Print, Info, Warn, Fatal
+// or Panic on the Entry it returns.
+func WithTime(t time.Time) *Entry {
+	return std.WithTime(t)
+}
+
+// Trace logs a message at level Trace on the standard logger.
+func Trace(args ...interface{}) {
+	std.Trace(args...)
+}
+
 // Debug logs a message at level Debug on the standard logger.
 func Debug(args ...interface{}) {
 	std.Debug(args...)
@@ -107,11 +129,16 @@ func Panic(args ...interface{}) {
 	std.Panic(args...)
 }

-// Fatal logs a message at level Fatal on the standard logger.
+// Fatal logs a message at level Fatal on the standard logger then the process will exit with status set to 1.
 func Fatal(args ...interface{}) {
 	std.Fatal(args...)
 }

+// Tracef logs a message at level Trace on the standard logger.
+func Tracef(format string, args ...interface{}) {
+	std.Tracef(format, args...)
+}
+
 // Debugf logs a message at level Debug on the standard logger.
 func Debugf(format string, args ...interface{}) {
 	std.Debugf(format, args...)
@@ -147,11 +174,16 @@ func Panicf(format string, args ...interface{}) {
 	std.Panicf(format, args...)
 }

-// Fatalf logs a message at level Fatal on the standard logger.
+// Fatalf logs a message at level Fatal on the standard logger then the process will exit with status set to 1.
 func Fatalf(format string, args ...interface{}) {
 	std.Fatalf(format, args...)
 }

+// Traceln logs a message at level Trace on the standard logger.
+func Traceln(args ...interface{}) {
+	std.Traceln(args...)
+}
+
 // Debugln logs a message at level Debug on the standard logger.
 func Debugln(args ...interface{}) {
 	std.Debugln(args...)
@@ -187,7 +219,7 @@ func Panicln(args ...interface{}) {
 	std.Panicln(args...)
 }

-// Fatalln logs a message at level Fatal on the standard logger.
+// Fatalln logs a message at level Fatal on the standard logger then the process will exit with status set to 1.
 func Fatalln(args ...interface{}) {
 	std.Fatalln(args...)
 }
@@ -2,7 +2,16 @@ package logrus

 import "time"

-const DefaultTimestampFormat = time.RFC3339
+// Default key names for the default fields
+const (
+	defaultTimestampFormat = time.RFC3339
+	FieldKeyMsg            = "msg"
+	FieldKeyLevel          = "level"
+	FieldKeyTime           = "time"
+	FieldKeyLogrusError    = "logrus_error"
+	FieldKeyFunc           = "func"
+	FieldKeyFile           = "file"
+)

 // The Formatter interface is used to implement a custom Formatter. It takes an
 // `Entry`. It exposes all the fields, including the default ones:
@@ -18,7 +27,7 @@ type Formatter interface {
 	Format(*Entry) ([]byte, error)
 }

-// This is to not silently overwrite `time`, `msg` and `level` fields when
+// This is to not silently overwrite `time`, `msg`, `func` and `level` fields when
 // dumping it. If this code wasn't there doing:
 //
 //  logrus.WithField("level", 1).Info("hello")
@@ -30,16 +39,40 @@ type Formatter interface {
 //
 // It's not exported because it's still using Data in an opinionated way. It's to
 // avoid code duplication between the two default formatters.
-func prefixFieldClashes(data Fields) {
-	if t, ok := data["time"]; ok {
-		data["fields.time"] = t
+func prefixFieldClashes(data Fields, fieldMap FieldMap, reportCaller bool) {
+	timeKey := fieldMap.resolve(FieldKeyTime)
+	if t, ok := data[timeKey]; ok {
+		data["fields."+timeKey] = t
+		delete(data, timeKey)
 	}

-	if m, ok := data["msg"]; ok {
-		data["fields.msg"] = m
+	msgKey := fieldMap.resolve(FieldKeyMsg)
+	if m, ok := data[msgKey]; ok {
+		data["fields."+msgKey] = m
+		delete(data, msgKey)
 	}

-	if l, ok := data["level"]; ok {
-		data["fields.level"] = l
+	levelKey := fieldMap.resolve(FieldKeyLevel)
+	if l, ok := data[levelKey]; ok {
+		data["fields."+levelKey] = l
+		delete(data, levelKey)
+	}
+
+	logrusErrKey := fieldMap.resolve(FieldKeyLogrusError)
+	if l, ok := data[logrusErrKey]; ok {
+		data["fields."+logrusErrKey] = l
+		delete(data, logrusErrKey)
+	}
+
+	// If reportCaller is not set, 'func' will not conflict.
+	if reportCaller {
+		funcKey := fieldMap.resolve(FieldKeyFunc)
+		if l, ok := data[funcKey]; ok {
+			data["fields."+funcKey] = l
+		}
+		fileKey := fieldMap.resolve(FieldKeyFile)
+		if l, ok := data[fileKey]; ok {
+			data["fields."+fileKey] = l
+		}
 	}
 }
@@ -1,18 +1,16 @@
 package logrus

 import (
+	"bytes"
 	"encoding/json"
 	"fmt"
+	"runtime"
 )

 type fieldKey string
-type FieldMap map[fieldKey]string

-const (
-	FieldKeyMsg   = "msg"
-	FieldKeyLevel = "level"
-	FieldKeyTime  = "time"
-)
+// FieldMap allows customization of the key names for default fields.
+type FieldMap map[fieldKey]string

 func (f FieldMap) resolve(key fieldKey) string {
 	if k, ok := f[key]; ok {
@@ -22,6 +20,7 @@ func (f FieldMap) resolve(key fieldKey) string {
 	return string(key)
 }

+// JSONFormatter formats logs into parsable json
 type JSONFormatter struct {
 	// TimestampFormat sets the format used for marshaling timestamps.
 	TimestampFormat string
@@ -29,20 +28,34 @@ type JSONFormatter struct {
 	// DisableTimestamp allows disabling automatic timestamps in output
 	DisableTimestamp bool

-	// FieldMap allows users to customize the names of keys for various fields.
+	// DataKey allows users to put all the log entry parameters into a nested dictionary at a given key.
+	DataKey string
+
+	// FieldMap allows users to customize the names of keys for default fields.
 	// As an example:
 	// formatter := &JSONFormatter{
 	//   	FieldMap: FieldMap{
-	// 		 FieldKeyTime: "@timestamp",
+	// 		 FieldKeyTime:  "@timestamp",
 	// 		 FieldKeyLevel: "@level",
-	// 		 FieldKeyMsg: "@message",
+	// 		 FieldKeyMsg:   "@message",
+	// 		 FieldKeyFunc:  "@caller",
 	//    },
 	// }
 	FieldMap FieldMap
+
+	// CallerPrettyfier can be set by the user to modify the content
+	// of the function and file keys in the json data when ReportCaller is
+	// activated. If any of the returned value is the empty string the
+	// corresponding key will be removed from json fields.
+	CallerPrettyfier func(*runtime.Frame) (function string, file string)
+
+	// PrettyPrint will indent all json logs
+	PrettyPrint bool
 }

+// Format renders a single log entry
 func (f *JSONFormatter) Format(entry *Entry) ([]byte, error) {
-	data := make(Fields, len(entry.Data)+3)
+	data := make(Fields, len(entry.Data)+4)
 	for k, v := range entry.Data {
 		switch v := v.(type) {
 		case error:
@@ -53,22 +66,56 @@ func (f *JSONFormatter) Format(entry *Entry) ([]byte, error) {
 			data[k] = v
 		}
 	}
-	prefixFieldClashes(data)
+
+	if f.DataKey != "" {
+		newData := make(Fields, 4)
+		newData[f.DataKey] = data
+		data = newData
+	}
+
+	prefixFieldClashes(data, f.FieldMap, entry.HasCaller())

 	timestampFormat := f.TimestampFormat
 	if timestampFormat == "" {
-		timestampFormat = DefaultTimestampFormat
+		timestampFormat = defaultTimestampFormat
 	}

+	if entry.err != "" {
+		data[f.FieldMap.resolve(FieldKeyLogrusError)] = entry.err
+	}
 	if !f.DisableTimestamp {
 		data[f.FieldMap.resolve(FieldKeyTime)] = entry.Time.Format(timestampFormat)
 	}
 	data[f.FieldMap.resolve(FieldKeyMsg)] = entry.Message
 	data[f.FieldMap.resolve(FieldKeyLevel)] = entry.Level.String()
-
-	serialized, err := json.Marshal(data)
-	if err != nil {
-		return nil, fmt.Errorf("Failed to marshal fields to JSON, %v", err)
+	if entry.HasCaller() {
+		funcVal := entry.Caller.Function
+		fileVal := fmt.Sprintf("%s:%d", entry.Caller.File, entry.Caller.Line)
+		if f.CallerPrettyfier != nil {
+			funcVal, fileVal = f.CallerPrettyfier(entry.Caller)
+		}
+		if funcVal != "" {
+			data[f.FieldMap.resolve(FieldKeyFunc)] = funcVal
+		}
+		if fileVal != "" {
+			data[f.FieldMap.resolve(FieldKeyFile)] = fileVal
+		}
 	}
-	return append(serialized, '\n'), nil
+
+	var b *bytes.Buffer
+	if entry.Buffer != nil {
+		b = entry.Buffer
+	} else {
+		b = &bytes.Buffer{}
+	}
+
+	encoder := json.NewEncoder(b)
+	if f.PrettyPrint {
+		encoder.SetIndent("", "  ")
+	}
+	if err := encoder.Encode(data); err != nil {
+		return nil, fmt.Errorf("failed to marshal fields to JSON, %v", err)
+	}
+
+	return b.Bytes(), nil
 }
@@ -1,16 +1,18 @@
 package logrus

 import (
+	"context"
 	"io"
 	"os"
 	"sync"
 	"sync/atomic"
+	"time"
 )

 type Logger struct {
 	// The logs are `io.Copy`'d to this in a mutex. It's common to set this to a
 	// file, or leave it default which is `os.Stderr`. You can also set this to
-	// something more adventorous, such as logging to Kafka.
+	// something more adventurous, such as logging to Kafka.
 	Out io.Writer
 	// Hooks for the logger instance. These allow firing events based on logging
 	// levels and log entries. For example, to send errors to an error tracking
@@ -23,16 +25,24 @@ type Logger struct {
 	// own that implements the `Formatter` interface, see the `README` or included
 	// formatters for examples.
 	Formatter Formatter
+
+	// Flag for whether to log caller info (off by default)
+	ReportCaller bool
+
 	// The logging level the logger should log at. This is typically (and defaults
 	// to) `logrus.Info`, which allows Info(), Warn(), Error() and Fatal() to be
-	// logged. `logrus.Debug` is useful in
+	// logged.
 	Level Level
 	// Used to sync writing to the log. Locking is enabled by Default
 	mu MutexWrap
 	// Reusable empty entry
 	entryPool sync.Pool
+	// Function to exit the application, defaults to `os.Exit()`
+	ExitFunc exitFunc
 }

+type exitFunc func(int)
+
 type MutexWrap struct {
 	lock     sync.Mutex
 	disabled bool
@@ -68,10 +78,12 @@ func (mw *MutexWrap) Disable() {
 // It's recommended to make this a global instance called `log`.
 func New() *Logger {
 	return &Logger{
-		Out:       os.Stderr,
-		Formatter: new(TextFormatter),
-		Hooks:     make(LevelHooks),
-		Level:     InfoLevel,
+		Out:          os.Stderr,
+		Formatter:    new(TextFormatter),
+		Hooks:        make(LevelHooks),
+		Level:        InfoLevel,
+		ExitFunc:     os.Exit,
+		ReportCaller: false,
 	}
 }

@@ -84,11 +96,12 @@ func (logger *Logger) newEntry() *Entry {
 }

 func (logger *Logger) releaseEntry(entry *Entry) {
+	entry.Data = map[string]interface{}{}
 	logger.entryPool.Put(entry)
 }

 // Adds a field to the log entry, note that it doesn't log until you call
-// Debug, Print, Info, Warn, Fatal or Panic. It only creates a log entry.
+// Debug, Print, Info, Warn, Error, Fatal or Panic. It only creates a log entry.
 // If you want multiple fields, use `WithFields`.
 func (logger *Logger) WithField(key string, value interface{}) *Entry {
 	entry := logger.newEntry()
@@ -112,20 +125,38 @@ func (logger *Logger) WithError(err error) *Entry {
 	return entry.WithError(err)
 }

-func (logger *Logger) Debugf(format string, args ...interface{}) {
-	if logger.level() >= DebugLevel {
+// Add a context to the log entry.
+func (logger *Logger) WithContext(ctx context.Context) *Entry {
+	entry := logger.newEntry()
+	defer logger.releaseEntry(entry)
+	return entry.WithContext(ctx)
+}
+
+// Overrides the time of the log entry.
+func (logger *Logger) WithTime(t time.Time) *Entry {
+	entry := logger.newEntry()
+	defer logger.releaseEntry(entry)
+	return entry.WithTime(t)
+}
+
+func (logger *Logger) Logf(level Level, format string, args ...interface{}) {
+	if logger.IsLevelEnabled(level) {
 		entry := logger.newEntry()
-		entry.Debugf(format, args...)
+		entry.Logf(level, format, args...)
 		logger.releaseEntry(entry)
 	}
 }

+func (logger *Logger) Tracef(format string, args ...interface{}) {
+	logger.Logf(TraceLevel, format, args...)
+}
+
+func (logger *Logger) Debugf(format string, args ...interface{}) {
+	logger.Logf(DebugLevel, format, args...)
+}
+
 func (logger *Logger) Infof(format string, args ...interface{}) {
-	if logger.level() >= InfoLevel {
-		entry := logger.newEntry()
-		entry.Infof(format, args...)
-		logger.releaseEntry(entry)
-	}
+	logger.Logf(InfoLevel, format, args...)
 }

 func (logger *Logger) Printf(format string, args ...interface{}) {
@@ -135,123 +166,91 @@ func (logger *Logger) Printf(format string, args ...interface{}) {
 }

 func (logger *Logger) Warnf(format string, args ...interface{}) {
-	if logger.level() >= WarnLevel {
-		entry := logger.newEntry()
-		entry.Warnf(format, args...)
-		logger.releaseEntry(entry)
-	}
+	logger.Logf(WarnLevel, format, args...)
 }

 func (logger *Logger) Warningf(format string, args ...interface{}) {
-	if logger.level() >= WarnLevel {
-		entry := logger.newEntry()
-		entry.Warnf(format, args...)
-		logger.releaseEntry(entry)
-	}
+	logger.Warnf(format, args...)
 }

 func (logger *Logger) Errorf(format string, args ...interface{}) {
-	if logger.level() >= ErrorLevel {
-		entry := logger.newEntry()
-		entry.Errorf(format, args...)
-		logger.releaseEntry(entry)
-	}
+	logger.Logf(ErrorLevel, format, args...)
 }

 func (logger *Logger) Fatalf(format string, args ...interface{}) {
-	if logger.level() >= FatalLevel {
-		entry := logger.newEntry()
-		entry.Fatalf(format, args...)
-		logger.releaseEntry(entry)
-	}
-	Exit(1)
+	logger.Logf(FatalLevel, format, args...)
+	logger.Exit(1)
 }

 func (logger *Logger) Panicf(format string, args ...interface{}) {
-	if logger.level() >= PanicLevel {
+	logger.Logf(PanicLevel, format, args...)
+}
+
+func (logger *Logger) Log(level Level, args ...interface{}) {
+	if logger.IsLevelEnabled(level) {
 		entry := logger.newEntry()
-		entry.Panicf(format, args...)
+		entry.Log(level, args...)
 		logger.releaseEntry(entry)
 	}
 }

+func (logger *Logger) Trace(args ...interface{}) {
+	logger.Log(TraceLevel, args...)
+}
+
 func (logger *Logger) Debug(args ...interface{}) {
-	if logger.level() >= DebugLevel {
-		entry := logger.newEntry()
-		entry.Debug(args...)
-		logger.releaseEntry(entry)
-	}
+	logger.Log(DebugLevel, args...)
 }

 func (logger *Logger) Info(args ...interface{}) {
-	if logger.level() >= InfoLevel {
-		entry := logger.newEntry()
-		entry.Info(args...)
-		logger.releaseEntry(entry)
-	}
+	logger.Log(InfoLevel, args...)
 }

 func (logger *Logger) Print(args ...interface{}) {
 	entry := logger.newEntry()
-	entry.Info(args...)
+	entry.Print(args...)
 	logger.releaseEntry(entry)
 }

 func (logger *Logger) Warn(args ...interface{}) {
-	if logger.level() >= WarnLevel {
-		entry := logger.newEntry()
-		entry.Warn(args...)
-		logger.releaseEntry(entry)
-	}
+	logger.Log(WarnLevel, args...)
 }

 func (logger *Logger) Warning(args ...interface{}) {
-	if logger.level() >= WarnLevel {
-		entry := logger.newEntry()
-		entry.Warn(args...)
-		logger.releaseEntry(entry)
-	}
+	logger.Warn(args...)
 }

 func (logger *Logger) Error(args ...interface{}) {
-	if logger.level() >= ErrorLevel {
-		entry := logger.newEntry()
-		entry.Error(args...)
-		logger.releaseEntry(entry)
-	}
+	logger.Log(ErrorLevel, args...)
 }

 func (logger *Logger) Fatal(args ...interface{}) {
-	if logger.level() >= FatalLevel {
-		entry := logger.newEntry()
-		entry.Fatal(args...)
-		logger.releaseEntry(entry)
-	}
-	Exit(1)
+	logger.Log(FatalLevel, args...)
+	logger.Exit(1)
 }

 func (logger *Logger) Panic(args ...interface{}) {
-	if logger.level() >= PanicLevel {
+	logger.Log(PanicLevel, args...)
+}
+
+func (logger *Logger) Logln(level Level, args ...interface{}) {
+	if logger.IsLevelEnabled(level) {
 		entry := logger.newEntry()
-		entry.Panic(args...)
+		entry.Logln(level, args...)
 		logger.releaseEntry(entry)
 	}
 }

+func (logger *Logger) Traceln(args ...interface{}) {
+	logger.Logln(TraceLevel, args...)
+}
+
 func (logger *Logger) Debugln(args ...interface{}) {
-	if logger.level() >= DebugLevel {
-		entry := logger.newEntry()
-		entry.Debugln(args...)
-		logger.releaseEntry(entry)
-	}
+	logger.Logln(DebugLevel, args...)
 }

 func (logger *Logger) Infoln(args ...interface{}) {
-	if logger.level() >= InfoLevel {
-		entry := logger.newEntry()
-		entry.Infoln(args...)
-		logger.releaseEntry(entry)
-	}
+	logger.Logln(InfoLevel, args...)
 }

 func (logger *Logger) Println(args ...interface{}) {
@@ -261,44 +260,32 @@ func (logger *Logger) Println(args ...interface{}) {
 }

 func (logger *Logger) Warnln(args ...interface{}) {
-	if logger.level() >= WarnLevel {
-		entry := logger.newEntry()
-		entry.Warnln(args...)
-		logger.releaseEntry(entry)
-	}
+	logger.Logln(WarnLevel, args...)
 }

 func (logger *Logger) Warningln(args ...interface{}) {
-	if logger.level() >= WarnLevel {
-		entry := logger.newEntry()
-		entry.Warnln(args...)
-		logger.releaseEntry(entry)
-	}
+	logger.Warnln(args...)
 }

 func (logger *Logger) Errorln(args ...interface{}) {
-	if logger.level() >= ErrorLevel {
-		entry := logger.newEntry()
-		entry.Errorln(args...)
-		logger.releaseEntry(entry)
-	}
+	logger.Logln(ErrorLevel, args...)
 }

 func (logger *Logger) Fatalln(args ...interface{}) {
-	if logger.level() >= FatalLevel {
-		entry := logger.newEntry()
-		entry.Fatalln(args...)
-		logger.releaseEntry(entry)
-	}
-	Exit(1)
+	logger.Logln(FatalLevel, args...)
+	logger.Exit(1)
 }

 func (logger *Logger) Panicln(args ...interface{}) {
-	if logger.level() >= PanicLevel {
-		entry := logger.newEntry()
-		entry.Panicln(args...)
-		logger.releaseEntry(entry)
+	logger.Logln(PanicLevel, args...)
+}
+
+func (logger *Logger) Exit(code int) {
+	runHandlers()
+	if logger.ExitFunc == nil {
+		logger.ExitFunc = os.Exit
 	}
+	logger.ExitFunc(code)
 }

 //When file is opened with appending mode, it's safe to
@@ -312,6 +299,53 @@ func (logger *Logger) level() Level {
 	return Level(atomic.LoadUint32((*uint32)(&logger.Level)))
 }

+// SetLevel sets the logger level.
 func (logger *Logger) SetLevel(level Level) {
 	atomic.StoreUint32((*uint32)(&logger.Level), uint32(level))
 }
+
+// GetLevel returns the logger level.
+func (logger *Logger) GetLevel() Level {
+	return logger.level()
+}
+
+// AddHook adds a hook to the logger hooks.
+func (logger *Logger) AddHook(hook Hook) {
+	logger.mu.Lock()
+	defer logger.mu.Unlock()
+	logger.Hooks.Add(hook)
+}
+
+// IsLevelEnabled checks if the log level of the logger is greater than the level param
+func (logger *Logger) IsLevelEnabled(level Level) bool {
+	return logger.level() >= level
+}
+
+// SetFormatter sets the logger formatter.
+func (logger *Logger) SetFormatter(formatter Formatter) {
+	logger.mu.Lock()
+	defer logger.mu.Unlock()
+	logger.Formatter = formatter
+}
+
+// SetOutput sets the logger output.
+func (logger *Logger) SetOutput(output io.Writer) {
+	logger.mu.Lock()
+	defer logger.mu.Unlock()
+	logger.Out = output
+}
+
+func (logger *Logger) SetReportCaller(reportCaller bool) {
+	logger.mu.Lock()
+	defer logger.mu.Unlock()
+	logger.ReportCaller = reportCaller
+}
+
+// ReplaceHooks replaces the logger hooks and returns the old ones
+func (logger *Logger) ReplaceHooks(hooks LevelHooks) LevelHooks {
+	logger.mu.Lock()
+	oldHooks := logger.Hooks
+	logger.Hooks = hooks
+	logger.mu.Unlock()
+	return oldHooks
+}
@@ -14,22 +14,11 @@ type Level uint32

 // Convert the Level to a string. E.g. PanicLevel becomes "panic".
 func (level Level) String() string {
-	switch level {
-	case DebugLevel:
-		return "debug"
-	case InfoLevel:
-		return "info"
-	case WarnLevel:
-		return "warning"
-	case ErrorLevel:
-		return "error"
-	case FatalLevel:
-		return "fatal"
-	case PanicLevel:
-		return "panic"
+	if b, err := level.MarshalText(); err == nil {
+		return string(b)
+	} else {
+		return "unknown"
 	}
-
-	return "unknown"
 }

 // ParseLevel takes a string level and returns the Logrus log level constant.
@@ -47,12 +36,47 @@ func ParseLevel(lvl string) (Level, error) {
 		return InfoLevel, nil
 	case "debug":
 		return DebugLevel, nil
+	case "trace":
+		return TraceLevel, nil
 	}

 	var l Level
 	return l, fmt.Errorf("not a valid logrus Level: %q", lvl)
 }

+// UnmarshalText implements encoding.TextUnmarshaler.
+func (level *Level) UnmarshalText(text []byte) error {
+	l, err := ParseLevel(string(text))
+	if err != nil {
+		return err
+	}
+
+	*level = Level(l)
+
+	return nil
+}
+
+func (level Level) MarshalText() ([]byte, error) {
+	switch level {
+	case TraceLevel:
+		return []byte("trace"), nil
+	case DebugLevel:
+		return []byte("debug"), nil
+	case InfoLevel:
+		return []byte("info"), nil
+	case WarnLevel:
+		return []byte("warning"), nil
+	case ErrorLevel:
+		return []byte("error"), nil
+	case FatalLevel:
+		return []byte("fatal"), nil
+	case PanicLevel:
+		return []byte("panic"), nil
+	}
+
+	return nil, fmt.Errorf("not a valid logrus level %d", level)
+}
+
 // A constant exposing all logging levels
 var AllLevels = []Level{
 	PanicLevel,
@@ -61,6 +85,7 @@ var AllLevels = []Level{
 	WarnLevel,
 	InfoLevel,
 	DebugLevel,
+	TraceLevel,
 }

 // These are the different logging levels. You can set the logging level to log
@@ -69,7 +94,7 @@ const (
 	// PanicLevel level, highest level of severity. Logs and then calls panic with the
 	// message passed to Debug, Info, ...
 	PanicLevel Level = iota
-	// FatalLevel level. Logs and then calls `os.Exit(1)`. It will exit even if the
+	// FatalLevel level. Logs and then calls `logger.Exit(1)`. It will exit even if the
 	// logging level is set to Panic.
 	FatalLevel
 	// ErrorLevel level. Logs. Used for errors that should definitely be noted.
@@ -82,6 +107,8 @@ const (
 	InfoLevel
 	// DebugLevel level. Usually only enabled when debugging. Very verbose logging.
 	DebugLevel
+	// TraceLevel level. Designates finer-grained informational events than the Debug.
+	TraceLevel
 )

 // Won't compile if StdLogger can't be realized by a log.Logger
@@ -140,4 +167,20 @@ type FieldLogger interface {
 	Errorln(args ...interface{})
 	Fatalln(args ...interface{})
 	Panicln(args ...interface{})
+
+	// IsDebugEnabled() bool
+	// IsInfoEnabled() bool
+	// IsWarnEnabled() bool
+	// IsErrorEnabled() bool
+	// IsFatalEnabled() bool
+	// IsPanicEnabled() bool
+}
+
+// Ext1FieldLogger (the first extension to FieldLogger) is superfluous, it is
+// here for consistancy. Do not use. Use Logger or Entry instead.
+type Ext1FieldLogger interface {
+	FieldLogger
+	Tracef(format string, args ...interface{})
+	Trace(args ...interface{})
+	Traceln(args ...interface{})
 }
@@ -1,10 +0,0 @@
-// +build appengine
-
-package logrus
-
-import "io"
-
-// IsTerminal returns true if stderr's file descriptor is a terminal.
-func IsTerminal(f io.Writer) bool {
-	return true
-}
@@ -1,10 +0,0 @@
-// +build darwin freebsd openbsd netbsd dragonfly
-// +build !appengine
-
-package logrus
-
-import "syscall"
-
-const ioctlReadTermios = syscall.TIOCGETA
-
-type Termios syscall.Termios
@@ -0,0 +1,11 @@
+// +build appengine
+
+package logrus
+
+import (
+	"io"
+)
+
+func checkIfTerminal(w io.Writer) bool {
+	return true
+}
@@ -0,0 +1,13 @@
+// +build darwin dragonfly freebsd netbsd openbsd
+
+package logrus
+
+import "golang.org/x/sys/unix"
+
+const ioctlReadTermios = unix.TIOCGETA
+
+func isTerminal(fd int) bool {
+	_, err := unix.IoctlGetTermios(fd, ioctlReadTermios)
+	return err == nil
+}
+
@@ -0,0 +1,11 @@
+// +build js
+
+package logrus
+
+import (
+	"io"
+)
+
+func checkIfTerminal(w io.Writer) bool {
+	return false
+}
@@ -0,0 +1,17 @@
+// +build !appengine,!js,!windows
+
+package logrus
+
+import (
+	"io"
+	"os"
+)
+
+func checkIfTerminal(w io.Writer) bool {
+	switch v := w.(type) {
+	case *os.File:
+		return isTerminal(int(v.Fd()))
+	default:
+		return false
+	}
+}
@@ -0,0 +1,13 @@
+// +build linux aix
+
+package logrus
+
+import "golang.org/x/sys/unix"
+
+const ioctlReadTermios = unix.TCGETS
+
+func isTerminal(fd int) bool {
+	_, err := unix.IoctlGetTermios(fd, ioctlReadTermios)
+	return err == nil
+}
+
@@ -0,0 +1,20 @@
+// +build !appengine,!js,windows
+
+package logrus
+
+import (
+	"io"
+	"os"
+	"syscall"
+)
+
+func checkIfTerminal(w io.Writer) bool {
+	switch v := w.(type) {
+	case *os.File:
+		var mode uint32
+		err := syscall.GetConsoleMode(syscall.Handle(v.Fd()), &mode)
+		return err == nil
+	default:
+		return false
+	}
+}
@@ -1,14 +0,0 @@
-// Based on ssh/terminal:
-// Copyright 2013 The Go Authors. All rights reserved.
-// Use of this source code is governed by a BSD-style
-// license that can be found in the LICENSE file.
-
-// +build !appengine
-
-package logrus
-
-import "syscall"
-
-const ioctlReadTermios = syscall.TCGETS
-
-type Termios syscall.Termios
@@ -1,28 +1,8 @@
-// Based on ssh/terminal:
-// Copyright 2011 The Go Authors. All rights reserved.
-// Use of this source code is governed by a BSD-style
-// license that can be found in the LICENSE file.
-
-// +build linux darwin freebsd openbsd netbsd dragonfly
-// +build !appengine
+// +build !windows

 package logrus

-import (
-	"io"
-	"os"
-	"syscall"
-	"unsafe"
-)
+import "io"

-// IsTerminal returns true if stderr's file descriptor is a terminal.
-func IsTerminal(f io.Writer) bool {
-	var termios Termios
-	switch v := f.(type) {
-	case *os.File:
-		_, _, err := syscall.Syscall6(syscall.SYS_IOCTL, uintptr(v.Fd()), ioctlReadTermios, uintptr(unsafe.Pointer(&termios)), 0, 0, 0)
-		return err == 0
-	default:
-		return false
-	}
+func initTerminal(w io.Writer) {
 }
@@ -1,21 +0,0 @@
-// +build solaris,!appengine
-
-package logrus
-
-import (
-	"io"
-	"os"
-
-	"golang.org/x/sys/unix"
-)
-
-// IsTerminal returns true if the given file descriptor is a terminal.
-func IsTerminal(f io.Writer) bool {
-	switch v := f.(type) {
-	case *os.File:
-		_, err := unix.IoctlGetTermios(int(v.Fd()), unix.TCGETA)
-		return err == nil
-	default:
-		return false
-	}
-}
@@ -1,82 +1,18 @@
-// Based on ssh/terminal:
-// Copyright 2011 The Go Authors. All rights reserved.
-// Use of this source code is governed by a BSD-style
-// license that can be found in the LICENSE file.
-
-// +build windows,!appengine
+// +build !appengine,!js,windows

 package logrus

 import (
-	"bytes"
-	"errors"
 	"io"
 	"os"
-	"os/exec"
-	"strconv"
-	"strings"
 	"syscall"
-	"unsafe"
+
+	sequences "github.com/konsorten/go-windows-terminal-sequences"
 )

-var kernel32 = syscall.NewLazyDLL("kernel32.dll")
-
-var (
-	procGetConsoleMode = kernel32.NewProc("GetConsoleMode")
-	procSetConsoleMode = kernel32.NewProc("SetConsoleMode")
-)
-
-const (
-	enableProcessedOutput           = 0x0001
-	enableWrapAtEolOutput           = 0x0002
-	enableVirtualTerminalProcessing = 0x0004
-)
-
-func getVersion() (float64, error) {
-	stdout, stderr := &bytes.Buffer{}, &bytes.Buffer{}
-	cmd := exec.Command("cmd", "ver")
-	cmd.Stdout = stdout
-	cmd.Stderr = stderr
-	err := cmd.Run()
-	if err != nil {
-		return -1, err
-	}
-	
-	// The output should be like "Microsoft Windows [Version XX.X.XXXXXX]"
-	version := strings.Replace(stdout.String(), "\n", "", -1)
-	version = strings.Replace(version, "\r\n", "", -1)
-
-	x1 := strings.Index(version, "[Version")
-
-	if x1 == -1 || strings.Index(version, "]") == -1 {
-		return -1, errors.New("Can't determine Windows version")
-	}
-
-	return strconv.ParseFloat(version[x1+9:x1+13], 64)
-}
-
-func init() {
-	ver, err := getVersion()
-	if err != nil {
-		return
-	}
-
-	// Activate Virtual Processing for Windows CMD
-	// Info: https://msdn.microsoft.com/en-us/library/windows/desktop/ms686033(v=vs.85).aspx
-	if ver >= 10 {
-		handle := syscall.Handle(os.Stderr.Fd())
-		procSetConsoleMode.Call(uintptr(handle), enableProcessedOutput|enableWrapAtEolOutput|enableVirtualTerminalProcessing)
-	}
-}
-
-// IsTerminal returns true if stderr's file descriptor is a terminal.
-func IsTerminal(f io.Writer) bool {
-	switch v := f.(type) {
+func initTerminal(w io.Writer) {
+	switch v := w.(type) {
 	case *os.File:
-		var st uint32
-		r, _, e := syscall.Syscall(procGetConsoleMode.Addr(), 2, uintptr(v.Fd()), uintptr(unsafe.Pointer(&st)), 0)
-		return r != 0 && e == 0
-	default:
-		return false
+		sequences.EnableVirtualTerminalProcessing(syscall.Handle(v.Fd()), true)
 	}
 }
@@ -3,6 +3,8 @@ package logrus
 import (
 	"bytes"
 	"fmt"
+	"os"
+	"runtime"
 	"sort"
 	"strings"
 	"sync"
@@ -10,22 +12,19 @@ import (
 )

 const (
-	nocolor = 0
-	red     = 31
-	green   = 32
-	yellow  = 33
-	blue    = 36
-	gray    = 37
+	red    = 31
+	yellow = 33
+	blue   = 36
+	gray   = 37
 )

-var (
-	baseTimestamp time.Time
-)
+var baseTimestamp time.Time

 func init() {
 	baseTimestamp = time.Now()
 }

+// TextFormatter formats logs into text
 type TextFormatter struct {
 	// Set to true to bypass checking for a TTY before outputting colors.
 	ForceColors bool
@@ -33,6 +32,9 @@ type TextFormatter struct {
 	// Force disabling colors.
 	DisableColors bool

+	// Override coloring based on CLICOLOR and CLICOLOR_FORCE. - https://bixense.com/clicolors/
+	EnvironmentOverrideColors bool
+
 	// Disable timestamp logging. useful when output is redirected to logging
 	// system that already adds timestamps.
 	DisableTimestamp bool
@@ -49,66 +51,155 @@ type TextFormatter struct {
 	// be desired.
 	DisableSorting bool

+	// The keys sorting function, when uninitialized it uses sort.Strings.
+	SortingFunc func([]string)
+
+	// Disables the truncation of the level text to 4 characters.
+	DisableLevelTruncation bool
+
 	// QuoteEmptyFields will wrap empty fields in quotes if true
 	QuoteEmptyFields bool

-	// QuoteCharacter can be set to the override the default quoting character "
-	// with something else. For example: ', or `.
-	QuoteCharacter string
-
 	// Whether the logger's out is to a terminal
 	isTerminal bool

-	sync.Once
+	// FieldMap allows users to customize the names of keys for default fields.
+	// As an example:
+	// formatter := &TextFormatter{
+	//     FieldMap: FieldMap{
+	//         FieldKeyTime:  "@timestamp",
+	//         FieldKeyLevel: "@level",
+	//         FieldKeyMsg:   "@message"}}
+	FieldMap FieldMap
+
+	// CallerPrettyfier can be set by the user to modify the content
+	// of the function and file keys in the data when ReportCaller is
+	// activated. If any of the returned value is the empty string the
+	// corresponding key will be removed from fields.
+	CallerPrettyfier func(*runtime.Frame) (function string, file string)
+
+	terminalInitOnce sync.Once
 }

 func (f *TextFormatter) init(entry *Entry) {
-	if len(f.QuoteCharacter) == 0 {
-		f.QuoteCharacter = "\""
-	}
 	if entry.Logger != nil {
-		f.isTerminal = IsTerminal(entry.Logger.Out)
+		f.isTerminal = checkIfTerminal(entry.Logger.Out)
+
+		if f.isTerminal {
+			initTerminal(entry.Logger.Out)
+		}
 	}
 }

+func (f *TextFormatter) isColored() bool {
+	isColored := f.ForceColors || (f.isTerminal && (runtime.GOOS != "windows"))
+
+	if f.EnvironmentOverrideColors {
+		if force, ok := os.LookupEnv("CLICOLOR_FORCE"); ok && force != "0" {
+			isColored = true
+		} else if ok && force == "0" {
+			isColored = false
+		} else if os.Getenv("CLICOLOR") == "0" {
+			isColored = false
+		}
+	}
+
+	return isColored && !f.DisableColors
+}
+
+// Format renders a single log entry
 func (f *TextFormatter) Format(entry *Entry) ([]byte, error) {
-	var b *bytes.Buffer
-	keys := make([]string, 0, len(entry.Data))
-	for k := range entry.Data {
+	data := make(Fields)
+	for k, v := range entry.Data {
+		data[k] = v
+	}
+	prefixFieldClashes(data, f.FieldMap, entry.HasCaller())
+	keys := make([]string, 0, len(data))
+	for k := range data {
 		keys = append(keys, k)
 	}

-	if !f.DisableSorting {
-		sort.Strings(keys)
+	var funcVal, fileVal string
+
+	fixedKeys := make([]string, 0, 4+len(data))
+	if !f.DisableTimestamp {
+		fixedKeys = append(fixedKeys, f.FieldMap.resolve(FieldKeyTime))
 	}
+	fixedKeys = append(fixedKeys, f.FieldMap.resolve(FieldKeyLevel))
+	if entry.Message != "" {
+		fixedKeys = append(fixedKeys, f.FieldMap.resolve(FieldKeyMsg))
+	}
+	if entry.err != "" {
+		fixedKeys = append(fixedKeys, f.FieldMap.resolve(FieldKeyLogrusError))
+	}
+	if entry.HasCaller() {
+		if f.CallerPrettyfier != nil {
+			funcVal, fileVal = f.CallerPrettyfier(entry.Caller)
+		} else {
+			funcVal = entry.Caller.Function
+			fileVal = fmt.Sprintf("%s:%d", entry.Caller.File, entry.Caller.Line)
+		}
+
+		if funcVal != "" {
+			fixedKeys = append(fixedKeys, f.FieldMap.resolve(FieldKeyFunc))
+		}
+		if fileVal != "" {
+			fixedKeys = append(fixedKeys, f.FieldMap.resolve(FieldKeyFile))
+		}
+	}
+
+	if !f.DisableSorting {
+		if f.SortingFunc == nil {
+			sort.Strings(keys)
+			fixedKeys = append(fixedKeys, keys...)
+		} else {
+			if !f.isColored() {
+				fixedKeys = append(fixedKeys, keys...)
+				f.SortingFunc(fixedKeys)
+			} else {
+				f.SortingFunc(keys)
+			}
+		}
+	} else {
+		fixedKeys = append(fixedKeys, keys...)
+	}
+
+	var b *bytes.Buffer
 	if entry.Buffer != nil {
 		b = entry.Buffer
 	} else {
 		b = &bytes.Buffer{}
 	}

-	prefixFieldClashes(entry.Data)
-
-	f.Do(func() { f.init(entry) })
-
-	isColored := (f.ForceColors || f.isTerminal) && !f.DisableColors
+	f.terminalInitOnce.Do(func() { f.init(entry) })

 	timestampFormat := f.TimestampFormat
 	if timestampFormat == "" {
-		timestampFormat = DefaultTimestampFormat
+		timestampFormat = defaultTimestampFormat
 	}
-	if isColored {
-		f.printColored(b, entry, keys, timestampFormat)
+	if f.isColored() {
+		f.printColored(b, entry, keys, data, timestampFormat)
 	} else {
-		if !f.DisableTimestamp {
-			f.appendKeyValue(b, "time", entry.Time.Format(timestampFormat))
-		}
-		f.appendKeyValue(b, "level", entry.Level.String())
-		if entry.Message != "" {
-			f.appendKeyValue(b, "msg", entry.Message)
-		}
-		for _, key := range keys {
-			f.appendKeyValue(b, key, entry.Data[key])
+
+		for _, key := range fixedKeys {
+			var value interface{}
+			switch {
+			case key == f.FieldMap.resolve(FieldKeyTime):
+				value = entry.Time.Format(timestampFormat)
+			case key == f.FieldMap.resolve(FieldKeyLevel):
+				value = entry.Level.String()
+			case key == f.FieldMap.resolve(FieldKeyMsg):
+				value = entry.Message
+			case key == f.FieldMap.resolve(FieldKeyLogrusError):
+				value = entry.err
+			case key == f.FieldMap.resolve(FieldKeyFunc) && entry.HasCaller():
+				value = funcVal
+			case key == f.FieldMap.resolve(FieldKeyFile) && entry.HasCaller():
+				value = fileVal
+			default:
+				value = data[key]
+			}
+			f.appendKeyValue(b, key, value)
 		}
 	}

@@ -116,10 +207,10 @@ func (f *TextFormatter) Format(entry *Entry) ([]byte, error) {
 	return b.Bytes(), nil
 }

-func (f *TextFormatter) printColored(b *bytes.Buffer, entry *Entry, keys []string, timestampFormat string) {
+func (f *TextFormatter) printColored(b *bytes.Buffer, entry *Entry, keys []string, data Fields, timestampFormat string) {
 	var levelColor int
 	switch entry.Level {
-	case DebugLevel:
+	case DebugLevel, TraceLevel:
 		levelColor = gray
 	case WarnLevel:
 		levelColor = yellow
@@ -129,17 +220,42 @@ func (f *TextFormatter) printColored(b *bytes.Buffer, entry *Entry, keys []strin
 		levelColor = blue
 	}

-	levelText := strings.ToUpper(entry.Level.String())[0:4]
+	levelText := strings.ToUpper(entry.Level.String())
+	if !f.DisableLevelTruncation {
+		levelText = levelText[0:4]
+	}
+
+	// Remove a single newline if it already exists in the message to keep
+	// the behavior of logrus text_formatter the same as the stdlib log package
+	entry.Message = strings.TrimSuffix(entry.Message, "\n")
+
+	caller := ""
+	if entry.HasCaller() {
+		funcVal := fmt.Sprintf("%s()", entry.Caller.Function)
+		fileVal := fmt.Sprintf("%s:%d", entry.Caller.File, entry.Caller.Line)
+
+		if f.CallerPrettyfier != nil {
+			funcVal, fileVal = f.CallerPrettyfier(entry.Caller)
+		}
+
+		if fileVal == "" {
+			caller = funcVal
+		} else if funcVal == "" {
+			caller = fileVal
+		} else {
+			caller = fileVal + " " + funcVal
+		}
+	}

 	if f.DisableTimestamp {
-		fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m %-44s ", levelColor, levelText, entry.Message)
+		fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m%s %-44s ", levelColor, levelText, caller, entry.Message)
 	} else if !f.FullTimestamp {
-		fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%04d] %-44s ", levelColor, levelText, int(entry.Time.Sub(baseTimestamp)/time.Second), entry.Message)
+		fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%04d]%s %-44s ", levelColor, levelText, int(entry.Time.Sub(baseTimestamp)/time.Second), caller, entry.Message)
 	} else {
-		fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%s] %-44s ", levelColor, levelText, entry.Time.Format(timestampFormat), entry.Message)
+		fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%s]%s %-44s ", levelColor, levelText, entry.Time.Format(timestampFormat), caller, entry.Message)
 	}
 	for _, k := range keys {
-		v := entry.Data[k]
+		v := data[k]
 		fmt.Fprintf(b, " \x1b[%dm%s\x1b[0m=", levelColor, k)
 		f.appendValue(b, v)
 	}
@@ -161,11 +277,12 @@ func (f *TextFormatter) needsQuoting(text string) bool {
 }

 func (f *TextFormatter) appendKeyValue(b *bytes.Buffer, key string, value interface{}) {
-
+	if b.Len() > 0 {
+		b.WriteByte(' ')
+	}
 	b.WriteString(key)
 	b.WriteByte('=')
 	f.appendValue(b, value)
-	b.WriteByte(' ')
 }

 func (f *TextFormatter) appendValue(b *bytes.Buffer, value interface{}) {
@@ -177,13 +294,6 @@ func (f *TextFormatter) appendValue(b *bytes.Buffer, value interface{}) {
 	if !f.needsQuoting(stringVal) {
 		b.WriteString(stringVal)
 	} else {
-		b.WriteString(f.quoteString(stringVal))
+		b.WriteString(fmt.Sprintf("%q", stringVal))
 	}
 }
-
-func (f *TextFormatter) quoteString(v string) string {
-	escapedQuote := fmt.Sprintf("\\%s", f.QuoteCharacter)
-	escapedValue := strings.Replace(v, f.QuoteCharacter, escapedQuote, -1)
-
-	return fmt.Sprintf("%s%v%s", f.QuoteCharacter, escapedValue, f.QuoteCharacter)
-}
@@ -24,6 +24,8 @@ func (entry *Entry) WriterLevel(level Level) *io.PipeWriter {
 	var printFunc func(args ...interface{})

 	switch level {
+	case TraceLevel:
+		printFunc = entry.Trace
 	case DebugLevel:
 		printFunc = entry.Debug
 	case InfoLevel: