Adds a new command line flag -log-file for file based logging. (#4581)

* Added log-file flag to capture Consul logs in a user specified file

* Refactored code.

* Refactored code. Added flags to rotate logs based on bytes and duration

* Added the flags for log file and log rotation on the webpage

* Fixed TestSantize from failing due to the addition of 3 flags

* Introduced changes : mutex, data-dir log writes, rotation logic

* Added test for logfile and updated the default log destination for docs

* Log name now uses UnixNano

* TestLogFile is now uses t.Parallel()

* Removed unnecessary int64Val function

* Updated docs to reflect default log name for log-file

* No longer writes to data-dir and adds .log if the filename has no extension

agent/config/builder.go

@@ -717,6 +717,9 @@ func (b *Builder) Build() (rt RuntimeConfig, err error) {
 		LeaveDrainTime:                          b.durationVal("performance.leave_drain_time", c.Performance.LeaveDrainTime),
 		LeaveOnTerm:                             leaveOnTerm,
 		LogLevel:                                b.stringVal(c.LogLevel),
+		LogFile:                                 b.stringVal(c.LogFile),
+		LogRotateBytes:                          b.intVal(c.LogRotateBytes),
+		LogRotateDuration:                       b.durationVal("log_rotate_duration", c.LogRotateDuration),
 		NodeID:                                  types.NodeID(b.stringVal(c.NodeID)),
 		NodeMeta:                                c.NodeMeta,
 		NodeName:                                b.nodeName(c.NodeName),

agent/config/config.go

@@ -191,6 +191,9 @@ type Config struct {
 	LeaveOnTerm                      *bool                    `json:"leave_on_terminate,omitempty" hcl:"leave_on_terminate" mapstructure:"leave_on_terminate"`
 	Limits                           Limits                   `json:"limits,omitempty" hcl:"limits" mapstructure:"limits"`
 	LogLevel                         *string                  `json:"log_level,omitempty" hcl:"log_level" mapstructure:"log_level"`
+	LogFile                          *string                  `json:"log_file,omitempty" hcl:"log_file" mapstructure:"log_file"`
+	LogRotateDuration                *string                  `json:"log_rotate_duration,omitempty" hcl:"log_rotate_duration" mapstructure:"log_rotate_duration"`
+	LogRotateBytes                   *int                     `json:"log_rotate_bytes,omitempty" hcl:"log_rotate_bytes" mapstructure:"log_rotate_bytes"`
 	NodeID                           *string                  `json:"node_id,omitempty" hcl:"node_id" mapstructure:"node_id"`
 	NodeMeta                         map[string]string        `json:"node_meta,omitempty" hcl:"node_meta" mapstructure:"node_meta"`
 	NodeName                         *string                  `json:"node_name,omitempty" hcl:"node_name" mapstructure:"node_name"`

agent/config/flags.go

@@ -76,6 +76,9 @@ func AddFlags(fs *flag.FlagSet, f *Flags) {
 	add(&f.Config.StartJoinAddrsLAN, "join", "Address of an agent to join at start time. Can be specified multiple times.")
 	add(&f.Config.StartJoinAddrsWAN, "join-wan", "Address of an agent to join -wan at start time. Can be specified multiple times.")
 	add(&f.Config.LogLevel, "log-level", "Log level of the agent.")
+	add(&f.Config.LogFile, "log-file", "Path to the file the logs get written to")
+	add(&f.Config.LogRotateBytes, "log-rotate-bytes", "Maximum number of bytes that should be written to a log file")
+	add(&f.Config.LogRotateDuration, "log-rotate-duration", "Time after which log rotation needs to be performed")
 	add(&f.Config.NodeName, "node", "Name of this node. Must be unique in the cluster.")
 	add(&f.Config.NodeID, "node-id", "A unique ID for this node across space and time. Defaults to a randomly-generated ID that persists in the data-dir.")
 	add(&f.Config.NodeMeta, "node-meta", "An arbitrary metadata key/value pair for this node, of the format `key:value`. Can be specified multiple times.")

agent/config/runtime.go

@@ -720,6 +720,24 @@ type RuntimeConfig struct {
 	// hcl: log_level = string
 	LogLevel string
 
+	// LogFile is the path to the file where the logs get written to. Defaults to empty string.
+	//
+	// hcl: log_file = string
+	// flags: -log-file string
+	LogFile string
+
+	// LogRotateDuration is the time configured to rotate logs based on time
+	//
+	// hcl: log_rotate_duration = string
+	// flags: -log-rotate-duration string
+	LogRotateDuration time.Duration
+
+	// LogRotateBytes is the time configured to rotate logs based on bytes written
+	//
+	// hcl: log_rotate_bytes = int
+	// flags: -log-rotate-bytes int
+	LogRotateBytes int
+
 	// Node ID is a unique ID for this node across space and time. Defaults
 	// to a randomly-generated ID that persists in the data-dir.
 	//

agent/config/runtime_test.go

@@ -4366,8 +4366,7 @@ func TestSanitize(t *testing.T) {
 		"CheckDeregisterIntervalMin": "0s",
 		"CheckReapInterval": "0s",
 		"CheckUpdateInterval": "0s",
-    "Checks": [
+		"Checks": [{
-        {
 			"AliasNode": "",
 			"AliasService": "",
 			"DeregisterCriticalServiceAfter": "0s",
@@ -4390,8 +4389,7 @@ func TestSanitize(t *testing.T) {
 			"TTL": "0s",
 			"Timeout": "0s",
 			"Token": "hidden"
-        }
+		}],
-    ],
 		"ClientAddrs": [],
 		"ConnectCAConfig": {},
 		"ConnectCAProvider": "",
@@ -4476,6 +4474,9 @@ func TestSanitize(t *testing.T) {
 		"LeaveDrainTime": "0s",
 		"LeaveOnTerm": false,
 		"LogLevel": "",
+		"LogFile": "",
+		"LogRotateBytes": 0,
+		"LogRotateDuration": "0s",
 		"NodeID": "",
 		"NodeMeta": {},
 		"NodeName": "",
@@ -4517,8 +4518,7 @@ func TestSanitize(t *testing.T) {
 		"ServerMode": false,
 		"ServerName": "",
 		"ServerPort": 0,
-    "Services": [
+		"Services": [{
-        {
 			"Address": "",
 			"Check": {
 				"AliasNode": "",
@@ -4553,8 +4553,7 @@ func TestSanitize(t *testing.T) {
 			"ProxyDestination": "",
 			"Tags": [],
 			"Token": "hidden"
-        }
+		}],
-    ],
 		"SessionTTLMin": "0s",
 		"SkipLeaveOnInt": false,
 		"StartJoinAddrsLAN": [],
@@ -4566,7 +4565,7 @@ func TestSanitize(t *testing.T) {
 		"TLSMinVersion": "",
 		"TLSPreferServerCipherSuites": false,
 		"TaggedAddresses": {},
-    "Telemetry":{
+		"Telemetry": {
 			"AllowedPrefixes": [],
 			"BlockedPrefixes": [],
 			"CirconusAPIApp": "",
@@ -4604,8 +4603,7 @@ func TestSanitize(t *testing.T) {
 		"Version": "",
 		"VersionPrerelease": "",
 		"Watches": []
-}`
+	}`
-
 	b, err := json.MarshalIndent(rt.Sanitized(), "", "    ")
 	if err != nil {
 		t.Fatal(err)

command/agent/agent.go

@@ -190,6 +190,9 @@ func (c *cmd) run(args []string) int {
 		LogLevel:          config.LogLevel,
 		EnableSyslog:      config.EnableSyslog,
 		SyslogFacility:    config.SyslogFacility,
+		LogFilePath:       config.LogFile,
+		LogRotateDuration: config.LogRotateDuration,
+		LogRotateBytes:    config.LogRotateBytes,
 	}
 	logFilter, logGate, logWriter, logOutput, ok := logger.Setup(logConfig, c.UI)
 	if !ok {

logger/logfile.go

@@ -0,0 +1,94 @@
+package logger
+
+import (
+	"os"
+	"path/filepath"
+	"strconv"
+	"strings"
+	"sync"
+	"time"
+)
+
+var (
+	now = time.Now
+)
+
+//LogFile is used to setup a file based logger that also performs log rotation
+type LogFile struct {
+	//Name of the log file
+	fileName string
+
+	//Path to the log file
+	logPath string
+
+	//Duration between each file rotation operation
+	duration time.Duration
+
+	//LastCreated represents the creation time of the latest log
+	LastCreated time.Time
+
+	//FileInfo is the pointer to the current file being written to
+	FileInfo *os.File
+
+	//MaxBytes is the maximum number of desired bytes for a log file
+	MaxBytes int
+
+	//BytesWritten is the number of bytes written in the current log file
+	BytesWritten int64
+
+	//acquire is the mutex utilized to ensure we have no concurrency issues
+	acquire sync.Mutex
+}
+
+func (l *LogFile) openNew() error {
+	// Extract the file extention
+	fileExt := filepath.Ext(l.fileName)
+	// If we have no file extension we append .log
+	if fileExt == "" {
+		fileExt = ".log"
+	}
+	// Remove the file extention from the filename
+	fileName := strings.TrimSuffix(l.fileName, fileExt)
+	// New file name has the format : filename-timestamp.extension
+	createTime := now()
+	newfileName := fileName + "-" + strconv.FormatInt(createTime.UnixNano(), 10) + fileExt
+	newfilePath := filepath.Join(l.logPath, newfileName)
+	// Try creating a file. We truncate the file because we are the only authority to write the logs
+	filePointer, err := os.OpenFile(newfilePath, os.O_CREATE|os.O_TRUNC|os.O_WRONLY, 640)
+	if err != nil {
+		return err
+	}
+	l.FileInfo = filePointer
+	// New file, new bytes tracker, new creation time :)
+	l.LastCreated = createTime
+	l.BytesWritten = 0
+	return nil
+}
+
+func (l *LogFile) rotate() error {
+	// Get the time from the last point of contact
+	timeElapsed := time.Since(l.LastCreated)
+	// Rotate if we hit the byte file limit or the time limit
+	if (l.BytesWritten >= int64(l.MaxBytes) && (l.MaxBytes > 0)) || timeElapsed >= l.duration {
+		l.FileInfo.Close()
+		return l.openNew()
+	}
+	return nil
+}
+
+func (l *LogFile) Write(b []byte) (n int, err error) {
+	l.acquire.Lock()
+	defer l.acquire.Unlock()
+	//Create a new file if we have no file to write to
+	if l.FileInfo == nil {
+		if err := l.openNew(); err != nil {
+			return 0, err
+		}
+	}
+	// Check for the last contact and rotate if necessary
+	if err := l.rotate(); err != nil {
+		return 0, err
+	}
+	l.BytesWritten += int64(len(b))
+	return l.FileInfo.Write(b)
+}

logger/logfile_test.go

@@ -0,0 +1,44 @@
+package logger
+
+import (
+	"io/ioutil"
+	"os"
+	"testing"
+	"time"
+
+	"github.com/hashicorp/consul/testutil"
+)
+
+const (
+	testFileName = "Consul.log"
+	testDuration = 2 * time.Second
+	testBytes    = 10
+)
+
+func TestLogFile_timeRotation(t *testing.T) {
+	t.Parallel()
+	tempDir := testutil.TempDir(t, "LogWriterTime")
+	defer os.Remove(tempDir)
+	logFile := LogFile{fileName: testFileName, logPath: tempDir, duration: testDuration}
+	logFile.Write([]byte("Hello World"))
+	time.Sleep(2 * time.Second)
+	logFile.Write([]byte("Second File"))
+	want := 2
+	if got, _ := ioutil.ReadDir(tempDir); len(got) != want {
+		t.Errorf("Expected %d files, got %v file(s)", want, len(got))
+	}
+}
+
+func TestLogFile_byteRotation(t *testing.T) {
+	t.Parallel()
+	tempDir := testutil.TempDir(t, "LogWriterBytes")
+	defer os.Remove(tempDir)
+	logFile := LogFile{fileName: testFileName, logPath: tempDir, MaxBytes: testBytes, duration: 24 * time.Hour}
+	logFile.Write([]byte("Hello World"))
+	logFile.Write([]byte("Second File"))
+	want := 2
+	tempFiles, _ := ioutil.ReadDir(tempDir)
+	if got := tempFiles; len(got) != want {
+		t.Errorf("Expected %d files, got %v file(s)", want, len(got))
+	}
+}

logger/logger.go

@@ -3,6 +3,7 @@ package logger
 import (
 	"fmt"
 	"io"
+	"path/filepath"
 	"strings"
 	"time"
 
@@ -21,8 +22,27 @@ type Config struct {
 
 	// SyslogFacility is the destination for syslog forwarding.
 	SyslogFacility string
+
+	//LogFilePath is the path to write the logs to the user specified file.
+	LogFilePath string
+
+	//LogRotateDuration is the user specified time to rotate logs
+	LogRotateDuration time.Duration
+
+	//LogRotateBytes is the user specified byte limit to rotate logs
+	LogRotateBytes int
 }
 
+const (
+	// defaultRotateDuration is the default time taken by the agent to rotate logs
+	defaultRotateDuration = 24 * time.Hour
+)
+
+var (
+	logRotateDuration time.Duration
+	logRotateBytes    int
+)
+
 // Setup is used to perform setup of several logging objects:
 //
 // * A LevelFilter is used to perform filtering by log level.
@@ -76,14 +96,37 @@ func Setup(config *Config, ui cli.Ui) (*logutils.LevelFilter, *GatedWriter, *Log
 			time.Sleep(delay)
 		}
 	}
-
 	// Create a log writer, and wrap a logOutput around it
 	logWriter := NewLogWriter(512)
+	writers := []io.Writer{logFilter, logWriter}
+
 	var logOutput io.Writer
 	if syslog != nil {
-		logOutput = io.MultiWriter(logFilter, logWriter, syslog)
+		writers = append(writers, syslog)
-	} else {
-		logOutput = io.MultiWriter(logFilter, logWriter)
 	}
+
+	// Create a file logger if the user has specified the path to the log file
+	if config.LogFilePath != "" {
+		dir, fileName := filepath.Split(config.LogFilePath)
+		// If a path is provided but has no fileName a default is provided.
+		if fileName == "" {
+			fileName = "consul.log"
+		}
+		// Try to enter the user specified log rotation duration first
+		if config.LogRotateDuration != 0 {
+			logRotateDuration = config.LogRotateDuration
+		} else {
+			// Default to 24 hrs if no rotation period is specified
+			logRotateDuration = defaultRotateDuration
+		}
+		// User specified byte limit for log rotation if one is provided
+		if config.LogRotateBytes != 0 {
+			logRotateBytes = config.LogRotateBytes
+		}
+		logFile := &LogFile{fileName: fileName, logPath: dir, duration: logRotateDuration, MaxBytes: logRotateBytes}
+		writers = append(writers, logFile)
+	}
+
+	logOutput = io.MultiWriter(writers...)
 	return logFilter, logGate, logWriter, logOutput, true
 }

website/source/docs/agent/options.html.md

@@ -225,6 +225,11 @@ will exit with an error at startup.
   This overrides the default port 8500. This option is very useful when deploying Consul
   to an environment which communicates the HTTP port through the environment e.g. PaaS like CloudFoundry, allowing
   you to set the port directly via a Procfile.
+* <a name="_log_file"></a><a href="#_log_file">`-log-file`</a> - to redirect all the Consul agent log messages to a file. This can be specified with the complete path along with the name of the log. In case the path doesn't have the filename, the filename defaults to Consul-timestamp.log .  Can be combined with <a href="#_log_rotate_bytes"> -log-rotate-bytes</a> and <a href="#_log_rotate_duration"> -log-rotate-duration </a> for a fine-grained log rotation experience. 
+
+* <a name="_log_rotate_bytes"></a><a href="#_log_rotate_bytes">`-log-rotate-bytes`</a> - to specify the number of bytes that should be written to a log before it needs to be rotated. Unless specified, there is no limit to the number of bytes that can be written to a log file.
+
+* <a name="_log_rotate_duration"></a><a href="#_log_rotate_rotation">`-log-rotate-rotation`</a> - to specify the maximum duration a log should be written to before it needs to be rotated. Unless specified, logs are rotated on a daily basis (24 hrs).
 
 * <a name="_join"></a><a href="#_join">`-join`</a> - Address of another agent
   to join upon starting up. This can be