Skip to content

Commit

Permalink
Re-open the log file by filesystem notify (#43359)
Browse files Browse the repository at this point in the history
* Re-open the log file on OS Signal trigger

This PR implements an handler for the CONT signal.
The handler will close and re-open the log file.
If the log destination is not a file, this is a no-op.

Useful for logrotate postrotate hook.

* signal replaced with the fsnotify

* code review changes:
- refactored to launch watcher with process context
- make file shared writer as singleton
- add test for logrotate case

* add locking for write, reopen

* - configuration for log section update
- test simplification

* code review changes:
- add closing for file shared writer
- make runWatcherFunc not exported

* linter fixes

* change default file mode for log file
simplify setting global watcher

* terminate watcher after override global one
added test for validating global override

* make log file name static for shared writer

* replace logic to use finalizer instead

* fix possible locking write while reopen is triggered

* wrap internal error, fix incorrect unlock

* drop configuration flag, make watcher always enabled

* tune context passing

---------

Co-authored-by: Vadym Popov <vadym.popov@goteleport.com>
  • Loading branch information
marcoandredinis and vapopov authored Jul 18, 2024
1 parent a0e7b47 commit 56587ff
Show file tree
Hide file tree
Showing 10 changed files with 407 additions and 14 deletions.
2 changes: 1 addition & 1 deletion go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -84,6 +84,7 @@ require (
github.com/elastic/go-elasticsearch/v8 v8.14.0
github.com/elimity-com/scim v0.0.0-20240320110924-172bf2aee9c8
github.com/evanphx/json-patch v5.9.0+incompatible
github.com/fsnotify/fsnotify v1.7.0
github.com/fsouza/fake-gcs-server v1.49.2
github.com/fxamacker/cbor/v2 v2.7.0
github.com/ghodss/yaml v1.0.0
Expand Down Expand Up @@ -321,7 +322,6 @@ require (
github.com/fatih/camelcase v1.0.0 // indirect
github.com/fatih/color v1.16.0 // indirect
github.com/felixge/httpsnoop v1.0.4 // indirect
github.com/fsnotify/fsnotify v1.7.0 // indirect
github.com/fvbommel/sortorder v1.1.0 // indirect
github.com/gabriel-vasile/mimetype v1.4.3 // indirect
github.com/go-asn1-ber/asn1-ber v1.5.5 // indirect
Expand Down
1 change: 1 addition & 0 deletions integrations/event-handler/go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -128,6 +128,7 @@ require (
github.com/exponent-io/jsonpath v0.0.0-20151013193312-d6023ce2651d // indirect
github.com/fatih/color v1.16.0 // indirect
github.com/felixge/httpsnoop v1.0.4 // indirect
github.com/fsnotify/fsnotify v1.7.0 // indirect
github.com/fxamacker/cbor/v2 v2.7.0 // indirect
github.com/ghodss/yaml v1.0.0 // indirect
github.com/go-errors/errors v1.4.2 // indirect
Expand Down
2 changes: 2 additions & 0 deletions integrations/event-handler/go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -938,6 +938,8 @@ github.com/foxcpp/go-mockdns v1.0.0 h1:7jBqxd3WDWwi/6WhDvacvH1XsN3rOLXyHM1uhvIx6
github.com/foxcpp/go-mockdns v1.0.0/go.mod h1:lgRN6+KxQBawyIghpnl5CezHFGS9VLzvtVlwxvzXTQ4=
github.com/frankban/quicktest v1.14.6 h1:7Xjx+VpznH+oBnejlPUj8oUpdxnVs4f8XU8WnHkI4W8=
github.com/frankban/quicktest v1.14.6/go.mod h1:4ptaffx2x8+WTWXmUCuVU6aPUX1/Mz7zb5vbUoiM6w0=
github.com/fsnotify/fsnotify v1.7.0 h1:8JEhPFa5W2WU7YfeZzPNqzMP6Lwt7L2715Ggo0nosvA=
github.com/fsnotify/fsnotify v1.7.0/go.mod h1:40Bi/Hjc2AVfZrqy+aj+yEI+/bRxZnMJyTJwOpGvigM=
github.com/fxamacker/cbor/v2 v2.7.0 h1:iM5WgngdRBanHcxugY4JySA0nk1wZorNOpTgCMedv5E=
github.com/fxamacker/cbor/v2 v2.7.0/go.mod h1:pxXPTn3joSm21Gbwsv0w9OSA2y1HFR9qXEeXQVeNoDQ=
github.com/ghodss/yaml v1.0.0 h1:wQHKEahhL6wmXdzwWG11gIVCkOv05bNOh+Rxn0yngAk=
Expand Down
1 change: 1 addition & 0 deletions integrations/terraform/go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -173,6 +173,7 @@ require (
github.com/exponent-io/jsonpath v0.0.0-20151013193312-d6023ce2651d // indirect
github.com/fatih/color v1.16.0 // indirect
github.com/felixge/httpsnoop v1.0.4 // indirect
github.com/fsnotify/fsnotify v1.7.0 // indirect
github.com/fxamacker/cbor/v2 v2.7.0 // indirect
github.com/ghodss/yaml v1.0.0 // indirect
github.com/go-asn1-ber/asn1-ber v1.5.5 // indirect
Expand Down
2 changes: 2 additions & 0 deletions integrations/terraform/go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -1088,6 +1088,8 @@ github.com/foxcpp/go-mockdns v1.0.0 h1:7jBqxd3WDWwi/6WhDvacvH1XsN3rOLXyHM1uhvIx6
github.com/foxcpp/go-mockdns v1.0.0/go.mod h1:lgRN6+KxQBawyIghpnl5CezHFGS9VLzvtVlwxvzXTQ4=
github.com/frankban/quicktest v1.14.6 h1:7Xjx+VpznH+oBnejlPUj8oUpdxnVs4f8XU8WnHkI4W8=
github.com/frankban/quicktest v1.14.6/go.mod h1:4ptaffx2x8+WTWXmUCuVU6aPUX1/Mz7zb5vbUoiM6w0=
github.com/fsnotify/fsnotify v1.7.0 h1:8JEhPFa5W2WU7YfeZzPNqzMP6Lwt7L2715Ggo0nosvA=
github.com/fsnotify/fsnotify v1.7.0/go.mod h1:40Bi/Hjc2AVfZrqy+aj+yEI+/bRxZnMJyTJwOpGvigM=
github.com/fsouza/fake-gcs-server v1.49.2 h1:fukDqzEQM50QkA0jAbl6cLqeDu3maQjwZBuys759TR4=
github.com/fsouza/fake-gcs-server v1.49.2/go.mod h1:17SYzJEXRcaAA5ATwwvgBkSIqIy7r1icnGM0y/y4foY=
github.com/fxamacker/cbor/v2 v2.7.0 h1:iM5WgngdRBanHcxugY4JySA0nk1wZorNOpTgCMedv5E=
Expand Down
35 changes: 22 additions & 13 deletions lib/config/configuration.go
Original file line number Diff line number Diff line change
Expand Up @@ -23,9 +23,11 @@
package config

import (
"context"
"crypto/x509"
"errors"
"io"
"io/fs"
"log/slog"
"maps"
"net"
Expand Down Expand Up @@ -70,6 +72,13 @@ import (
logutils "github.com/gravitational/teleport/lib/utils/log"
)

const (
// logFileDefaultMode is the preferred permissions mode for log file.
logFileDefaultMode fs.FileMode = 0o644
// logFileDefaultFlag is the preferred flags set to log file.
logFileDefaultFlag = os.O_WRONLY | os.O_CREATE | os.O_APPEND
)

// CommandLineFlags stores command line flag values, it's a much simplified subset
// of Teleport configuration (which is fully expressed via YAML config file)
type CommandLineFlags struct {
Expand Down Expand Up @@ -757,12 +766,12 @@ func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error {
var w io.Writer
switch loggerConfig.Output {
case "":
w = os.Stderr
w = logutils.NewSharedWriter(os.Stderr)
case "stderr", "error", "2":
w = os.Stderr
w = logutils.NewSharedWriter(os.Stderr)
cfg.Console = io.Discard // disable console printing
case "stdout", "out", "1":
w = os.Stdout
w = logutils.NewSharedWriter(os.Stdout)
cfg.Console = io.Discard // disable console printing
case teleport.Syslog:
w = os.Stderr
Expand All @@ -780,14 +789,20 @@ func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error {

logger.ReplaceHooks(make(log.LevelHooks))
logger.AddHook(hook)
// If syslog output has been configured and is supported by the operating system,
// then the shared writer is not needed because the syslog writer is already
// protected with a mutex.
w = sw
default:
// assume it's a file path:
logFile, err := os.Create(loggerConfig.Output)
// Assume this is a file path.
sharedWriter, err := logutils.NewFileSharedWriter(loggerConfig.Output, logFileDefaultFlag, logFileDefaultMode)
if err != nil {
return trace.Wrap(err, "failed to create the log file")
return trace.Wrap(err, "failed to init the log file shared writer")
}
w = logutils.NewWriterFinalizer[*logutils.FileSharedWriter](sharedWriter)
if err := sharedWriter.RunWatcherReopen(context.Background()); err != nil {
return trace.Wrap(err)
}
w = logFile
}

level := new(slog.LevelVar)
Expand Down Expand Up @@ -816,12 +831,6 @@ func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error {
return trace.Wrap(err)
}

// If syslog output has been configured and is supported by the operating system,
// then the shared writer is not needed because the syslog writer is already
// protected with a mutex.
if len(logger.Hooks) == 0 {
w = logutils.NewSharedWriter(w)
}
var slogLogger *slog.Logger
switch strings.ToLower(loggerConfig.Format.Output) {
case "":
Expand Down
2 changes: 2 additions & 0 deletions lib/service/servicecfg/config.go
Original file line number Diff line number Diff line change
Expand Up @@ -222,9 +222,11 @@ type Config struct {
// Log optionally specifies the logger.
// Deprecated: use Logger instead.
Log utils.Logger

// Logger outputs messages using slog. The underlying handler respects
// the user supplied logging config.
Logger *slog.Logger

// LoggerLevel defines the Logger log level.
LoggerLevel *slog.LevelVar

Expand Down
164 changes: 164 additions & 0 deletions lib/utils/log/file_writer.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,164 @@
/*
* Teleport
* Copyright (C) 2024 Gravitational, Inc.
*
* This program is free software: you can redistribute it and/or modify
* it under the terms of the GNU Affero General Public License as published by
* the Free Software Foundation, either version 3 of the License, or
* (at your option) any later version.
*
* This program is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU Affero General Public License for more details.
*
* You should have received a copy of the GNU Affero General Public License
* along with this program. If not, see <http://www.gnu.org/licenses/>.
*/

package log

import (
"context"
"errors"
"io/fs"
"log/slog"
"os"
"path/filepath"
"sync"

"github.com/fsnotify/fsnotify"
"github.com/gravitational/trace"
)

var (
// ErrFileSharedWriterClosed is returned when file shared writer is already closed.
ErrFileSharedWriterClosed = errors.New("file shared writer is closed")
)

// FileSharedWriter is similar to SharedWriter except that it requires a `os.File` instead of a `io.Writer`.
// This is to allow the File reopen required by logrotate and similar tools.
type FileSharedWriter struct {
logFileName string
fileFlag int
fileMode fs.FileMode
file *os.File
watcher *fsnotify.Watcher
closed bool

lock sync.Mutex
}

// NewFileSharedWriter wraps the provided [os.File] in a writer that is thread safe,
// with ability to enable filesystem notification watch and reopen file on specific events.
func NewFileSharedWriter(logFileName string, flag int, mode fs.FileMode) (*FileSharedWriter, error) {
if logFileName == "" {
return nil, trace.BadParameter("log file name is not set")
}
logFile, err := os.OpenFile(logFileName, flag, mode)
if err != nil {
return nil, trace.ConvertSystemError(err)
}
watcher, err := fsnotify.NewWatcher()
if err != nil {
return nil, trace.Wrap(err)
}

return &FileSharedWriter{
logFileName: logFileName,
fileFlag: flag,
fileMode: mode,
file: logFile,
watcher: watcher,
}, nil
}

// Write writes len(b) bytes from b to the File.
func (s *FileSharedWriter) Write(b []byte) (int, error) {
s.lock.Lock()
defer s.lock.Unlock()
if s.closed {
return 0, ErrFileSharedWriterClosed
}

return s.file.Write(b)
}

// Reopen closes the file and opens it again using APPEND mode.
func (s *FileSharedWriter) Reopen() error {
// If opening the file is locked we should not acquire a lock and block write.
file, err := os.OpenFile(s.logFileName, s.fileFlag, s.fileMode)
if err != nil {
return trace.Wrap(err)
}

s.lock.Lock()
if s.closed {
s.lock.Unlock()
_ = file.Close()
return trace.Wrap(ErrFileSharedWriterClosed)
}
oldLogFile := s.file
s.file = file
s.lock.Unlock()

return trace.Wrap(oldLogFile.Close())
}

// RunWatcherReopen runs a filesystem watcher for rename/remove events to reopen the log.
func (s *FileSharedWriter) RunWatcherReopen(ctx context.Context) error {
s.lock.Lock()
defer s.lock.Unlock()
if s.closed {
return trace.Wrap(ErrFileSharedWriterClosed)
}

return s.runWatcherFunc(ctx, s.Reopen)
}

// runWatcherFunc spawns goroutine with the watcher loop to consume events of renaming
// or removing the log file to trigger the action function when event appeared.
func (s *FileSharedWriter) runWatcherFunc(ctx context.Context, action func() error) error {
go func() {
for {
select {
case event, ok := <-s.watcher.Events:
if !ok {
return
}
if s.logFileName == event.Name && (event.Has(fsnotify.Rename) || event.Has(fsnotify.Remove)) {
slog.DebugContext(ctx, "Log file was moved/removed", "file", event.Name)
if err := action(); err != nil {
slog.ErrorContext(ctx, "Failed to reopen file", "error", err, "file", event.Name)
continue
}
}
case err, ok := <-s.watcher.Errors:
if !ok {
return
}
slog.ErrorContext(ctx, "Error received on logger watcher", "error", err)
}
}
}()

logDirParent := filepath.Dir(s.logFileName)
if err := s.watcher.Add(logDirParent); err != nil {
return trace.Wrap(err)
}

return nil
}

// Close stops the internal watcher and close the log file.
func (s *FileSharedWriter) Close() error {
s.lock.Lock()
defer s.lock.Unlock()

if s.closed {
return trace.Wrap(ErrFileSharedWriterClosed)
}
s.closed = true

return trace.NewAggregate(s.watcher.Close(), s.file.Close())
}
Loading

0 comments on commit 56587ff

Please sign in to comment.