Skip to content

Commit

Permalink
Integrate with lumberjack for log rotation (#1504)
Browse files Browse the repository at this point in the history
* integrate with lumberjack

* run perf test

* fix fio error

* fix operations tests

* reduce number of  log rotations to reduce integration test execution time

* review comments

* temp commit to run perf tests with trace logs

* fix lint issues

* temp commit

* review comments

* fix lint

* revert perf changes

* refactoring based on review comments
  • Loading branch information
ashmeenkaur authored and gargnitingoogle committed Nov 28, 2023
1 parent eee69e4 commit dfe5281
Show file tree
Hide file tree
Showing 12 changed files with 324 additions and 30 deletions.
1 change: 1 addition & 0 deletions go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,7 @@ require (
golang.org/x/text v0.13.0
golang.org/x/time v0.3.0
google.golang.org/api v0.149.0
gopkg.in/natefinch/lumberjack.v2 v2.2.1
gopkg.in/yaml.v3 v3.0.1
)

Expand Down
2 changes: 2 additions & 0 deletions go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -696,6 +696,8 @@ gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8
gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127 h1:qIbj1fsPNlZgppZ+VLlY7N33q108Sa+fhmuc+sWQYwY=
gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
gopkg.in/errgo.v2 v2.1.0/go.mod h1:hNsd1EY+bozCKY1Ytp96fpM3vjJbqLJn88ws8XvfDNI=
gopkg.in/natefinch/lumberjack.v2 v2.2.1 h1:bBRl1b0OH9s/DuPhuXpNl+VtCaJXFZ5/uEFST95x9zc=
gopkg.in/natefinch/lumberjack.v2 v2.2.1/go.mod h1:YD8tP3GAjkrDg1eZH7EGmyESg/lsYskCTPBJVb9jqSc=
gopkg.in/yaml.v2 v2.2.2/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI=
gopkg.in/yaml.v2 v2.2.3/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI=
gopkg.in/yaml.v2 v2.2.8/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI=
Expand Down
4 changes: 2 additions & 2 deletions internal/fs/fs_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -163,11 +163,11 @@ func (t *fsTest) SetUpTestSuite() {
mountCfg.OpContext = ctx

if mountCfg.ErrorLogger == nil {
mountCfg.ErrorLogger = logger.NewError("fuse_errors: ")
mountCfg.ErrorLogger = logger.NewLegacyLogger(logger.LevelError, "fuse_errors: ")
}

if *fDebug {
mountCfg.DebugLogger = logger.NewDebug("fuse: ")
mountCfg.DebugLogger = logger.NewLegacyLogger(logger.LevelDebug, "fuse: ")
}

mfs, err = fuse.Mount(mntDir, server, &mountCfg)
Expand Down
36 changes: 12 additions & 24 deletions internal/logger/logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -18,13 +18,13 @@ import (
"context"
"fmt"
"io"
"log"
"log/slog"
"log/syslog"
"os"
"runtime/debug"

"github.com/googlecloudplatform/gcsfuse/internal/config"
"gopkg.in/natefinch/lumberjack.v2"
)

// Syslog file contains logs from all different programmes running on the VM.
Expand All @@ -49,6 +49,7 @@ var (
func InitLogFile(logConfig config.LogConfig) error {
var f *os.File
var sysWriter *syslog.Writer
var fileWriter *lumberjack.Logger
var err error
if logConfig.FilePath != "" {
f, err = os.OpenFile(
Expand All @@ -59,6 +60,12 @@ func InitLogFile(logConfig config.LogConfig) error {
if err != nil {
return err
}
fileWriter = &lumberjack.Logger{
Filename: f.Name(),
MaxSize: logConfig.LogRotateConfig.MaxFileSizeMB,
MaxBackups: logConfig.LogRotateConfig.FileCount - 1,
Compress: logConfig.LogRotateConfig.Compress,
}
} else {
if _, ok := os.LookupEnv(GCSFuseInBackgroundMode); ok {
// Priority consist of facility and severity, here facility to specify the
Expand All @@ -77,6 +84,7 @@ func InitLogFile(logConfig config.LogConfig) error {
defaultLoggerFactory = &loggerFactory{
file: f,
sysWriter: sysWriter,
fileWriter: fileWriter,
format: logConfig.Format,
level: logConfig.Severity,
logRotateConfig: logConfig.LogRotateConfig,
Expand Down Expand Up @@ -104,27 +112,6 @@ func Close() {
}
}

// NewDebug returns a new logger for logging debug messages with given prefix
// to the log file or stdout.
func NewDebug(prefix string) *log.Logger {
// TODO: delete this method after all slog changed are merged.
return NewLegacyLogger(LevelDebug, prefix)
}

// NewInfo returns a new logger for logging info with given prefix to the log
// file or stdout.
func NewInfo(prefix string) *log.Logger {
// TODO: delete this method after all slog changed are merged.
return NewLegacyLogger(LevelInfo, prefix)
}

// NewError returns a new logger for logging errors with given prefix to the log
// file or stderr.
func NewError(prefix string) *log.Logger {
// TODO: delete this method after all slog changed are merged.
return NewLegacyLogger(LevelError, prefix)
}

// Tracef prints the message with TRACE severity in the specified format.
func Tracef(format string, v ...interface{}) {
defaultLogger.Log(context.Background(), LevelTrace, fmt.Sprintf(format, v...))
Expand Down Expand Up @@ -169,6 +156,7 @@ type loggerFactory struct {
format string
level config.LogSeverity
logRotateConfig config.LogRotateConfig
fileWriter *lumberjack.Logger
}

func (f *loggerFactory) newLogger(level config.LogSeverity) *slog.Logger {
Expand All @@ -188,8 +176,8 @@ func (f *loggerFactory) createJsonOrTextHandler(writer io.Writer, levelVar *slog
}

func (f *loggerFactory) handler(levelVar *slog.LevelVar, prefix string) slog.Handler {
if f.file != nil {
return f.createJsonOrTextHandler(f.file, levelVar, prefix)
if f.fileWriter != nil {
return f.createJsonOrTextHandler(f.fileWriter, levelVar, prefix)
}

if f.sysWriter != nil {
Expand Down
102 changes: 102 additions & 0 deletions tools/integration_tests/log_rotation/log_rotation_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,102 @@
// Copyright 2023 Google Inc. All Rights Reserved.
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.

// Provides integration tests for log rotation of gcsfuse logs.

package log_rotation

import (
"os"
"path"
"testing"

"github.com/googlecloudplatform/gcsfuse/internal/config"
"github.com/googlecloudplatform/gcsfuse/tools/integration_tests/util/mounting/static_mounting"
"github.com/googlecloudplatform/gcsfuse/tools/integration_tests/util/setup"
)

const (
testDirName = "LogRotationTest"
logFileName = "log.txt"
logDirName = "gcsfuse_integration_test_logs"
maxFileSizeMB = 2
activeLogFileCount = 1
backupLogFileCount = 2
logFileCount = activeLogFileCount + backupLogFileCount
)

var logDirPath string
var logFilePath string

func getMountConfigForLogRotation(maxFileSizeMB, fileCount int, compress bool,
logFilePath string) config.MountConfig {
mountConfig := config.MountConfig{
LogConfig: config.LogConfig{
Severity: config.TRACE,
FilePath: logFilePath,
LogRotateConfig: config.LogRotateConfig{
MaxFileSizeMB: maxFileSizeMB,
FileCount: fileCount,
Compress: compress,
},
},
}
return mountConfig
}

////////////////////////////////////////////////////////////////////////
// TestMain
////////////////////////////////////////////////////////////////////////

func TestMain(m *testing.M) {
setup.ParseSetUpFlags()

setup.ExitWithFailureIfBothTestBucketAndMountedDirectoryFlagsAreNotSet()

// Run tests for mountedDirectory only if --mountedDirectory flag is set.

logDirPath = setup.ValidateLogDirForMountedDirTests(logDirName)
logFilePath = path.Join(logDirPath, logFileName)
setup.RunTestsForMountedDirectoryFlag(m)

// Else run tests for testBucket.
// Set up test directory.
setup.SetUpTestDirForTestBucketFlag()

// Set up directory for logs.
logDirPath = setup.SetUpLogDirForTestDirTests(logDirName)
logFilePath = path.Join(logDirPath, logFileName)

// Set up config files.
configFile1 := setup.YAMLConfigFile(
getMountConfigForLogRotation(maxFileSizeMB, logFileCount, true, logFilePath),
"config1.yaml")
configFile2 := setup.YAMLConfigFile(
getMountConfigForLogRotation(maxFileSizeMB, logFileCount, false, logFilePath),
"config2.yaml")

// Set up flags to run tests on.
// Not setting config file explicitly with 'create-empty-file: false' as it is default.
flags := [][]string{
{"--config-file=" + configFile1},
{"--config-file=" + configFile2},
}

successCode := static_mounting.RunTests(flags, m)

// Clean up test directory created.
setup.CleanupDirectoryOnGCS(path.Join(setup.TestBucket(), testDirName))
setup.RemoveBinFileCopiedForTesting()
os.Exit(successCode)
}
139 changes: 139 additions & 0 deletions tools/integration_tests/log_rotation/logrotate_logfile_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,139 @@
// Copyright 2023 Google Inc. All Rights Reserved.
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.

package log_rotation

import (
"fmt"
"os"
"path"
"strings"
"sync"
"testing"
"time"

"github.com/googlecloudplatform/gcsfuse/tools/integration_tests/util/operations"
"github.com/googlecloudplatform/gcsfuse/tools/integration_tests/util/setup"
)

const (
MiB = 1024 * 1024
filePerms = 0644
testFileName = "foo"
)

////////////////////////////////////////////////////////////////////////
// Helpers
////////////////////////////////////////////////////////////////////////

func runOperationsOnFileTillLogRotation(t *testing.T, wg *sync.WaitGroup, fileName string) {
defer wg.Done()

// Generate random data to write to file.
randomData, err := operations.GenerateRandomData(5 * MiB)
if err != nil {
t.Errorf("operations.GenerateRandomData: %v", err)
}
// Setup file with 5 MiB content in test directory.
testDirPath := path.Join(setup.MntDir(), testDirName)
filePath := path.Join(testDirPath, fileName)
operations.CreateFileWithContent(filePath, filePerms, string(randomData), t)

// Keep performing operations in mounted directory until log file is rotated.
var lastLogFileSize int64 = 0
for {
// Perform Read operation to generate logs.
_, err = operations.ReadFile(filePath)
if err != nil {
t.Errorf("ReadFile failed: %v", err)
}

// Break the loop when log file is rotated.
fi, err := operations.StatFile(logFilePath)
if err != nil {
t.Errorf("stat operation on file %s: %v", logFilePath, err)
}
if (*fi).Size() < lastLogFileSize {
// Log file got rotated as current log file size < last log file size.
break
}
lastLogFileSize = (*fi).Size()
}
}

func runParallelOperationsInMountedDirectoryTillLogRotation(t *testing.T) {
// Parallelly performs operations on 5 files in-order to generate logs.
var wg sync.WaitGroup
wg.Add(5)
for i := 0; i < 5; i++ {
go runOperationsOnFileTillLogRotation(t, &wg, fmt.Sprintf(testFileName+"-%d", i))
}
wg.Wait()
}

func validateLogFileSize(t *testing.T, dirEntry os.DirEntry) {
fi, err := dirEntry.Info()
if err != nil {
t.Fatalf("log file size could not be fetched: %v", err)
}
if fi.Size() > maxFileSizeMB*MiB {
t.Errorf("log file size: expected (max): %d, actual: %d", maxFileSizeMB*MiB, fi.Size())
}
}

////////////////////////////////////////////////////////////////////////
// Tests
////////////////////////////////////////////////////////////////////////

func TestLogRotation(t *testing.T) {
setup.SetupTestDirectory(testDirName)

// Perform log rotation 4 times.
for i := 0; i < 4; i++ {
runParallelOperationsInMountedDirectoryTillLogRotation(t)
}
// Adding 1-second sleep here because there is slight delay in compression
// of log files.
time.Sleep(1 * time.Second)

// Validate log files generated.
dirEntries := operations.ReadDirectory(logDirPath, t)
if len(dirEntries) != logFileCount {
t.Errorf("Expected log files in dirEntries folder: %d, got: %d",
logFileCount, len(dirEntries))
}
rotatedCompressedFileCtr := 0
logFileCtr := 0
rotatedUncompressedFileCtr := 0
for i := 0; i < logFileCount; i++ {
if dirEntries[i].Name() == logFileName {
logFileCtr++
validateLogFileSize(t, dirEntries[i])
} else if strings.Contains(dirEntries[i].Name(), "txt.gz") {
rotatedCompressedFileCtr++
} else {
rotatedUncompressedFileCtr++
validateLogFileSize(t, dirEntries[i])
}
}

if logFileCtr != activeLogFileCount {
t.Errorf("expected countOfLogFile: %d, got: %d", activeLogFileCount, logFileCtr)
}

rotatedLogFiles := rotatedCompressedFileCtr + rotatedUncompressedFileCtr
if rotatedLogFiles != backupLogFileCount {
t.Errorf("expected rotated files: %d, got: %d", backupLogFileCount, rotatedLogFiles)
}
}
8 changes: 6 additions & 2 deletions tools/integration_tests/operations/operations_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -100,16 +100,20 @@ func TestMain(m *testing.M) {
// Run tests for testBucket
// Set up test directory.
setup.SetUpTestDirForTestBucketFlag()
// Set up config file with create-empty-file: false.
// Set up config file with create-empty-file: true.
mountConfig := config.MountConfig{
WriteConfig: config.WriteConfig{
CreateEmptyFile: true,
},
LogConfig: config.LogConfig{
Severity: config.TRACE,
LogRotateConfig: config.LogRotateConfig{
MaxFileSizeMB: 10,
FileCount: 1,
},
},
}
configFile := setup.YAMLConfigFile(mountConfig)
configFile := setup.YAMLConfigFile(mountConfig, "config.yaml")
// Set up flags to run tests on.
flags := [][]string{
// By default, creating emptyFile is disabled.
Expand Down
Loading

0 comments on commit dfe5281

Please sign in to comment.