Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add support for logging to a file #6429

Merged
merged 5 commits into from
Oct 11, 2019
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
54 changes: 42 additions & 12 deletions command/agent/command.go
Original file line number Diff line number Diff line change
Expand Up @@ -391,28 +391,58 @@ func (c *Command) setupLoggers(config *Config) (*gatedwriter.Writer, *logWriter,
return nil, nil, nil
}

// Create a log writer, and wrap a logOutput around it
logWriter := NewLogWriter(512)
writers := []io.Writer{c.logFilter, logWriter}

// Check if syslog is enabled
var syslog io.Writer
if config.EnableSyslog {
l, err := gsyslog.NewLogger(gsyslog.LOG_NOTICE, config.SyslogFacility, "nomad")
if err != nil {
c.Ui.Error(fmt.Sprintf("Syslog setup failed: %v", err))
return nil, nil, nil
}
syslog = &SyslogWrapper{l, c.logFilter}
writers = append(writers, &SyslogWrapper{l, c.logFilter})
}

// Create a log writer, and wrap a logOutput around it
logWriter := NewLogWriter(512)
var logOutput io.Writer
if syslog != nil {
logOutput = io.MultiWriter(c.logFilter, logWriter, syslog)
} else {
logOutput = io.MultiWriter(c.logFilter, logWriter)
// Check if file logging is enabled
if config.LogFile != "" {
dir, fileName := filepath.Split(config.LogFile)

// if a path is provided, but has no filename, then a default is used.
if fileName == "" {
fileName = "nomad.log"
}

// Try to enter the user specified log rotation duration first
var logRotateDuration time.Duration
if config.LogRotateDuration != "" {
duration, err := time.ParseDuration(config.LogRotateDuration)
if err != nil {
c.Ui.Error(fmt.Sprintf("Failed to parse log rotation duration: %v", err))
return nil, nil, nil
}
logRotateDuration = duration
} else {
// Default to 24 hrs if no rotation period is specified
logRotateDuration = 24 * time.Hour
}

logFile := &logFile{
logFilter: c.logFilter,
fileName: fileName,
logPath: dir,
duration: logRotateDuration,
MaxBytes: config.LogRotateBytes,
MaxFiles: config.LogRotateMaxFiles,
}

writers = append(writers, logFile)
}
c.logOutput = logOutput
log.SetOutput(logOutput)
return logGate, logWriter, logOutput

c.logOutput = io.MultiWriter(writers...)
log.SetOutput(c.logOutput)
return logGate, logWriter, c.logOutput
}

// setupAgent is used to start the agent and various interfaces
Expand Down
24 changes: 24 additions & 0 deletions command/agent/config.go
Original file line number Diff line number Diff line change
Expand Up @@ -57,6 +57,18 @@ type Config struct {
// LogJson enables log output in a JSON format
LogJson bool `hcl:"log_json"`

// LogFile enables logging to a file
LogFile string `hcl:"log_file"`

// LogRotateDuration is the time period that logs should be rotated in
LogRotateDuration string `hcl:"log_rotate_duration"`

// LogRotateBytes is the max number of bytes that should be written to a file
LogRotateBytes int `hcl:"log_rotate_bytes"`

// LogRotateMaxFiles is the max number of log files to keep
LogRotateMaxFiles int `hcl:"log_rotate_max_files"`

// BindAddr is the address on which all of nomad's services will
// be bound. If not specified, this defaults to 127.0.0.1.
BindAddr string `hcl:"bind_addr"`
Expand Down Expand Up @@ -898,6 +910,18 @@ func (c *Config) Merge(b *Config) *Config {
if b.LogJson {
result.LogJson = true
}
if b.LogFile != "" {
result.LogFile = b.LogFile
}
if b.LogRotateDuration != "" {
result.LogRotateDuration = b.LogRotateDuration
}
if b.LogRotateBytes != 0 {
result.LogRotateBytes = b.LogRotateBytes
}
if b.LogRotateMaxFiles != 0 {
result.LogRotateMaxFiles = b.LogRotateMaxFiles
}
if b.BindAddr != "" {
result.BindAddr = b.BindAddr
}
Expand Down
9 changes: 3 additions & 6 deletions command/agent/config_parse_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@ var basicConfig = &Config{
NodeName: "my-web",
DataDir: "/tmp/nomad",
PluginDir: "/tmp/nomad-plugins",
LogFile: "/var/log/nomad.log",
LogLevel: "ERR",
LogJson: true,
BindAddr: "192.168.0.1",
Expand Down Expand Up @@ -409,14 +410,10 @@ func TestConfig_Parse(t *testing.T) {
t.Run(tc.File, func(t *testing.T) {
require := require.New(t)
path, err := filepath.Abs(filepath.Join("./testdata", tc.File))
if err != nil {
t.Fatalf("file: %s\n\n%s", tc.File, err)
}
require.NoError(err)

actual, err := ParseConfigFile(path)
if (err != nil) != tc.Err {
t.Fatalf("file: %s\n\n%s", tc.File, err)
}
require.NoError(err)

// ParseConfig used to re-merge defaults for these three objects,
// despite them already being merged in LoadConfig. The test structs
Expand Down
146 changes: 146 additions & 0 deletions command/agent/log_file.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,146 @@
package agent

import (
"fmt"
"os"
"path/filepath"
"sort"
"strconv"
"strings"
"sync"
"time"

"github.com/hashicorp/logutils"
)

var (
now = time.Now
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This would be easier to override in tests if it were on the logFile struct, but we never touch it in tests anyway so I guess it's not worth fixing.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yeah there's a bunch of stuff I'm not a fan of in here, but the incremental benefit of adding support and improving later felt worthwhile to me. (and reduces the surface area for scary bugs bc we know this ~works)

)

// logFile is used to setup a file based logger that also performs log rotation
type logFile struct {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let's link to https://github.com/hashicorp/consul/blob/53f3962cab68ec3590cbbe16af4e54b500b0570f/logger/logfile.go
in a comment so when people wonder why this file looks so funny they know it's shared.

// Log level Filter to filter out logs that do not matcch LogLevel criteria
logFilter *logutils.LevelFilter

//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

// Max rotated files to keep before removing them.
MaxFiles int

//acquire is the mutex utilized to ensure we have no concurrency issues
acquire sync.Mutex
}

func (l *logFile) fileNamePattern() string {
// Extract the file extension
fileExt := filepath.Ext(l.fileName)
// If we have no file extension we append .log
if fileExt == "" {
fileExt = ".log"
}
// Remove the file extension from the filename
return strings.TrimSuffix(l.fileName, fileExt) + "-%s" + fileExt
}

func (l *logFile) openNew() error {
fileNamePattern := l.fileNamePattern()
// New file name has the format : filename-timestamp.extension
createTime := now()
newfileName := fmt.Sprintf(fileNamePattern, strconv.FormatInt(createTime.UnixNano(), 10))
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, 0640)
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()
if err := l.pruneFiles(); err != nil {
return err
}
return l.openNew()
}
return nil
}

func (l *logFile) pruneFiles() error {
if l.MaxFiles == 0 {
return nil
}
pattern := l.fileNamePattern()
//get all the files that match the log file pattern
globExpression := filepath.Join(l.logPath, fmt.Sprintf(pattern, "*"))
matches, err := filepath.Glob(globExpression)
if err != nil {
return err
}

// Stort the strings as filepath.Glob does not publicly guarantee that files
// are sorted, so here we add an extra defensive sort.
sort.Strings(matches)

// Prune if there are more files stored than the configured max
stale := len(matches) - l.MaxFiles
for i := 0; i < stale; i++ {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't see that Glob guarantees ordered results so we should probably sort.Strings first. Might want to mention this to Consul to?

Copy link
Contributor Author

@endocrimes endocrimes Oct 10, 2019

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Glob internally guarantees (in filepath.glob) that files are returned in lexographical order by doing a sort.Strings after it performs a Readdirnames, but this doesn't get surfaced in the Glob public documentation so I'll add a sort.Strings to be defensive.

if err := os.Remove(matches[i]); err != nil {
return err
}
}
return nil
}

// Write is used to implement io.Writer
func (l *logFile) Write(b []byte) (int, error) {
// Filter out log entries that do not match log level criteria
if !l.logFilter.Check(b) {
return 0, nil
}

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 {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This approach will create files larger than the size limit which isn't correct but also shouldn't hurt much.

Let's not worry about fixing it I guess.

return 0, err
}

n, err := l.FileInfo.Write(b)
l.BytesWritten += int64(n)
return n, err
}
Loading