mirror of
https://github.com/kemko/nomad.git
synced 2026-01-08 11:25:41 +03:00
agent: Introduce File Logger
This commit introduces a rotating file logger for Nomad Agent Logs. The logger implementation itself is a lift and shift from Consul, with tests updated to fit with the Nomad pattern of using require, and not having a testutil for creating tempdirs cleanly.
This commit is contained in:
Danielle Lancashire
138
command/agent/log_file.go
Normal file
138
command/agent/log_file.go
Normal file
@@ -0,0 +1,138 @@
|
||||
package agent
|
||||
|
||||
import (
|
||||
"fmt"
|
||||
"os"
|
||||
"path/filepath"
|
||||
"strconv"
|
||||
"strings"
|
||||
"sync"
|
||||
"time"
|
||||
|
||||
"github.com/hashicorp/logutils"
|
||||
)
|
||||
|
||||
var (
|
||||
now = time.Now
|
||||
)
|
||||
|
||||
// logFile is used to setup a file based logger that also performs log rotation
|
||||
type logFile struct {
|
||||
// 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
|
||||
}
|
||||
// Prune if there are more files stored than the configured max
|
||||
stale := len(matches) - l.MaxFiles
|
||||
for i := 0; i < stale; i++ {
|
||||
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) (n int, err 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 {
|
||||
return 0, err
|
||||
}
|
||||
l.BytesWritten += int64(len(b))
|
||||
return l.FileInfo.Write(b)
|
||||
}
|
||||
171
command/agent/log_file_test.go
Normal file
171
command/agent/log_file_test.go
Normal file
@@ -0,0 +1,171 @@
|
||||
package agent
|
||||
|
||||
import (
|
||||
"io/ioutil"
|
||||
"os"
|
||||
"path/filepath"
|
||||
"testing"
|
||||
"time"
|
||||
|
||||
"github.com/hashicorp/logutils"
|
||||
"github.com/stretchr/testify/require"
|
||||
)
|
||||
|
||||
const (
|
||||
testFileName = "Nomad.log"
|
||||
testDuration = 2 * time.Second
|
||||
testBytes = 10
|
||||
)
|
||||
|
||||
func TestLogFile_timeRotation(t *testing.T) {
|
||||
t.Parallel()
|
||||
require := require.New(t)
|
||||
|
||||
tempDir, err := ioutil.TempDir("", "LogWriterTimeTest")
|
||||
require.NoError(err)
|
||||
|
||||
defer os.Remove(tempDir)
|
||||
|
||||
filt := LevelFilter()
|
||||
logFile := logFile{
|
||||
logFilter: filt,
|
||||
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_openNew(t *testing.T) {
|
||||
t.Parallel()
|
||||
require := require.New(t)
|
||||
|
||||
tempDir, err := ioutil.TempDir("", "LogWriterOpenTest")
|
||||
require.NoError(err)
|
||||
defer os.Remove(tempDir)
|
||||
|
||||
logFile := logFile{fileName: testFileName, logPath: tempDir, duration: testDuration}
|
||||
require.NoError(logFile.openNew())
|
||||
|
||||
_, err = ioutil.ReadFile(logFile.FileInfo.Name())
|
||||
require.NoError(err)
|
||||
}
|
||||
|
||||
func TestLogFile_byteRotation(t *testing.T) {
|
||||
t.Parallel()
|
||||
require := require.New(t)
|
||||
|
||||
tempDir, err := ioutil.TempDir("", "LogWriterByteTest")
|
||||
require.NoError(err)
|
||||
defer os.Remove(tempDir)
|
||||
|
||||
filt := LevelFilter()
|
||||
filt.MinLevel = logutils.LogLevel("INFO")
|
||||
logFile := logFile{
|
||||
logFilter: filt,
|
||||
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)
|
||||
require.Equal(want, len(tempFiles))
|
||||
}
|
||||
|
||||
func TestLogFile_logLevelFiltering(t *testing.T) {
|
||||
t.Parallel()
|
||||
require := require.New(t)
|
||||
|
||||
tempDir, err := ioutil.TempDir("", "LogWriterFilterTest")
|
||||
require.NoError(err)
|
||||
defer os.Remove(tempDir)
|
||||
filt := LevelFilter()
|
||||
logFile := logFile{
|
||||
logFilter: filt,
|
||||
fileName: testFileName,
|
||||
logPath: tempDir,
|
||||
MaxBytes: testBytes,
|
||||
duration: testDuration,
|
||||
}
|
||||
logFile.Write([]byte("[INFO] This is an info message"))
|
||||
logFile.Write([]byte("[DEBUG] This is a debug message"))
|
||||
logFile.Write([]byte("[ERR] This is an error message"))
|
||||
want := 2
|
||||
tempFiles, _ := ioutil.ReadDir(tempDir)
|
||||
require.Equal(want, len(tempFiles))
|
||||
}
|
||||
|
||||
func TestLogFile_deleteArchives(t *testing.T) {
|
||||
t.Parallel()
|
||||
require := require.New(t)
|
||||
|
||||
tempDir, err := ioutil.TempDir("", "LogWriterDeleteArchivesTest")
|
||||
require.NoError(err)
|
||||
defer os.Remove(tempDir)
|
||||
|
||||
filt := LevelFilter()
|
||||
filt.MinLevel = logutils.LogLevel("INFO")
|
||||
logFile := logFile{
|
||||
logFilter: filt,
|
||||
fileName: testFileName,
|
||||
logPath: tempDir,
|
||||
MaxBytes: testBytes,
|
||||
duration: 24 * time.Hour,
|
||||
MaxFiles: 1,
|
||||
}
|
||||
logFile.Write([]byte("[INFO] Hello World"))
|
||||
logFile.Write([]byte("[INFO] Second File"))
|
||||
logFile.Write([]byte("[INFO] Third File"))
|
||||
want := 2
|
||||
tempFiles, _ := ioutil.ReadDir(tempDir)
|
||||
|
||||
require.Equal(want, len(tempFiles))
|
||||
|
||||
for _, tempFile := range tempFiles {
|
||||
var bytes []byte
|
||||
var err error
|
||||
path := filepath.Join(tempDir, tempFile.Name())
|
||||
if bytes, err = ioutil.ReadFile(path); err != nil {
|
||||
t.Errorf(err.Error())
|
||||
return
|
||||
}
|
||||
contents := string(bytes)
|
||||
|
||||
require.NotEqual("[INFO] Hellow World", contents, "oldest log should have been deleted")
|
||||
}
|
||||
}
|
||||
|
||||
func TestLogFile_deleteArchivesDisabled(t *testing.T) {
|
||||
t.Parallel()
|
||||
|
||||
require := require.New(t)
|
||||
tempDir, err := ioutil.TempDir("", "LogWriterDeleteArchivesDisabledTest")
|
||||
require.NoError(err)
|
||||
defer os.Remove(tempDir)
|
||||
|
||||
filt := LevelFilter()
|
||||
filt.MinLevel = logutils.LogLevel("INFO")
|
||||
logFile := logFile{
|
||||
logFilter: filt,
|
||||
fileName: testFileName,
|
||||
logPath: tempDir,
|
||||
MaxBytes: testBytes,
|
||||
duration: 24 * time.Hour,
|
||||
MaxFiles: 0,
|
||||
}
|
||||
logFile.Write([]byte("[INFO] Hello World"))
|
||||
logFile.Write([]byte("[INFO] Second File"))
|
||||
logFile.Write([]byte("[INFO] Third File"))
|
||||
want := 3
|
||||
tempFiles, _ := ioutil.ReadDir(tempDir)
|
||||
require.Equal(want, len(tempFiles))
|
||||
}
|
||||
Reference in New Issue
Block a user