fix: allow logging to user specified log files

This also cleans up some the of the error output to send to stderr.

This adds the Shutdown() to the logging interface, so we can keep the
log file open and just append entries.

This add HangUp() to the logging interface for log rotations.
This commit is contained in:
Ben McClelland
2023-07-25 22:53:48 -07:00
parent 5b31a7bafc
commit 5a9b744dd1
5 changed files with 223 additions and 156 deletions

View File

@@ -40,7 +40,7 @@ var (
kafkaURL, kafkaTopic, kafkaKey string
natsURL, natsTopic string
logWebhookURL string
accessLog bool
accessLog string
debug bool
)
@@ -147,14 +147,16 @@ func initFlags() []cli.Flag {
Usage: "enable debug output",
Destination: &debug,
},
&cli.BoolFlag{
&cli.StringFlag{
Name: "access-log",
Usage: "enable server access logging in the root directory",
Usage: "enable server access logging to specified file",
EnvVars: []string{"LOGFILE"},
Destination: &accessLog,
},
&cli.StringFlag{
Name: "log-webhook-url",
Usage: "webhook url to send the audit logs",
EnvVars: []string{"WEBHOOK"},
Destination: &logWebhookURL,
},
&cli.StringFlag{
@@ -229,7 +231,7 @@ func runGateway(ctx *cli.Context, be backend.Backend, s auth.Storer) error {
}
logger, err := s3log.InitLogger(&s3log.LogConfig{
IsFile: accessLog,
LogFile: accessLog,
WebhookURL: logWebhookURL,
})
if err != nil {
@@ -258,12 +260,32 @@ func runGateway(ctx *cli.Context, be backend.Backend, s auth.Storer) error {
c := make(chan error, 1)
go func() { c <- srv.Serve() }()
select {
case <-ctx.Done():
be.Shutdown()
return ctx.Err()
case err := <-c:
be.Shutdown()
return err
// for/select blocks until shutdown
Loop:
for {
select {
case <-ctx.Done():
err = ctx.Err()
break Loop
case err = <-c:
break Loop
case <-sigHup:
if logger != nil {
err = logger.HangUp()
if err != nil {
err = fmt.Errorf("HUP logger: %w", err)
break Loop
}
}
}
}
be.Shutdown()
if logger != nil {
lerr := logger.Shutdown()
if lerr != nil {
fmt.Fprintf(os.Stderr, "shutdown logger: %v\n", lerr)
}
}
return err
}

View File

@@ -23,6 +23,7 @@ import (
var (
sigDone = make(chan bool, 1)
sigHup = make(chan bool, 1)
)
func setupSignalHandler() {
@@ -36,6 +37,7 @@ func setupSignalHandler() {
case syscall.SIGINT, syscall.SIGTERM:
sigDone <- true
case syscall.SIGHUP:
sigHup <- true
}
}
}()

View File

@@ -27,6 +27,8 @@ import (
type AuditLogger interface {
Log(ctx *fiber.Ctx, err error, body []byte, meta LogMeta)
HangUp() error
Shutdown() error
}
type LogMeta struct {
@@ -36,7 +38,7 @@ type LogMeta struct {
}
type LogConfig struct {
IsFile bool
LogFile string
WebhookURL string
}
@@ -70,14 +72,14 @@ type LogFields struct {
}
func InitLogger(cfg *LogConfig) (AuditLogger, error) {
if cfg.WebhookURL != "" && cfg.IsFile {
if cfg.WebhookURL != "" && cfg.LogFile != "" {
return nil, fmt.Errorf("there should be specified one of the following: file, webhook")
}
if cfg.WebhookURL != "" {
return InitWebhookLogger(cfg.WebhookURL)
}
if cfg.IsFile {
return InitFileLogger()
if cfg.LogFile != "" {
return InitFileLogger(cfg.LogFile)
}
return nil, nil

View File

@@ -16,9 +16,7 @@ package s3log
import (
"crypto/tls"
"errors"
"fmt"
"io/fs"
"os"
"strings"
"sync"
@@ -29,36 +27,43 @@ import (
)
const (
logFile = "access.log"
logFileMode = 0600
timeFormat = "02/January/2006:15:04:05 -0700"
)
// FileLogger is a local file audit log
type FileLogger struct {
LogFields
mu sync.Mutex
logfile string
f *os.File
gotErr bool
mu sync.Mutex
}
var _ AuditLogger = &FileLogger{}
func InitFileLogger() (AuditLogger, error) {
_, err := os.ReadFile(logFile)
if err != nil && errors.Is(err, fs.ErrNotExist) {
err := os.WriteFile(logFile, []byte{}, logFileMode)
if err != nil {
return nil, err
} else {
return nil, err
}
// InitFileLogger initializes audit logs to local file
func InitFileLogger(logname string) (AuditLogger, error) {
f, err := os.OpenFile(logname, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
if err != nil {
return nil, fmt.Errorf("open log: %w", err)
}
return &FileLogger{}, nil
f.WriteString(fmt.Sprintf("log starts %v\n", time.Now()))
return &FileLogger{logfile: logname, f: f}, nil
}
// Log sends log message to file logger
func (f *FileLogger) Log(ctx *fiber.Ctx, err error, body []byte, meta LogMeta) {
f.mu.Lock()
defer f.mu.Unlock()
if f.gotErr {
return
}
lf := LogFields{}
access := "-"
reqURI := ctx.Request().URI().String()
path := strings.Split(ctx.Path(), "/")
@@ -68,8 +73,8 @@ func (f *FileLogger) Log(ctx *fiber.Ctx, err error, body []byte, meta LogMeta) {
startTime := ctx.Locals("startTime").(time.Time)
tlsConnState := ctx.Context().TLSConnectionState()
if tlsConnState != nil {
f.CipherSuite = tls.CipherSuiteName(tlsConnState.CipherSuite)
f.TLSVersion = getTLSVersionName(tlsConnState.Version)
lf.CipherSuite = tls.CipherSuiteName(tlsConnState.CipherSuite)
lf.TLSVersion = getTLSVersionName(tlsConnState.Version)
}
if err != nil {
@@ -88,117 +93,138 @@ func (f *FileLogger) Log(ctx *fiber.Ctx, err error, body []byte, meta LogMeta) {
access = ctx.Locals("access").(string)
}
f.BucketOwner = meta.BucketOwner
f.Bucket = bucket
f.Time = time.Now()
f.RemoteIP = ctx.IP()
f.Requester = access
f.RequestID = genID()
f.Operation = meta.Action
f.Key = object
f.RequestURI = reqURI
f.HttpStatus = httpStatus
f.ErrorCode = errorCode
f.BytesSent = len(body)
f.ObjectSize = meta.ObjectSize
f.TotalTime = time.Since(startTime).Milliseconds()
f.TurnAroundTime = time.Since(startTime).Milliseconds()
f.Referer = ctx.Get("Referer")
f.UserAgent = ctx.Get("User-Agent")
f.VersionID = ctx.Query("versionId")
f.HostID = ctx.Get("X-Amz-Id-2")
f.SignatureVersion = "SigV4"
f.AuthenticationType = "AuthHeader"
f.HostHeader = fmt.Sprintf("s3.%v.amazonaws.com", ctx.Locals("region").(string))
f.AccessPointARN = fmt.Sprintf("arn:aws:s3:::%v", strings.Join(path, "/"))
f.AclRequired = "Yes"
lf.BucketOwner = meta.BucketOwner
lf.Bucket = bucket
lf.Time = time.Now()
lf.RemoteIP = ctx.IP()
lf.Requester = access
lf.RequestID = genID()
lf.Operation = meta.Action
lf.Key = object
lf.RequestURI = reqURI
lf.HttpStatus = httpStatus
lf.ErrorCode = errorCode
lf.BytesSent = len(body)
lf.ObjectSize = meta.ObjectSize
lf.TotalTime = time.Since(startTime).Milliseconds()
lf.TurnAroundTime = time.Since(startTime).Milliseconds()
lf.Referer = ctx.Get("Referer")
lf.UserAgent = ctx.Get("User-Agent")
lf.VersionID = ctx.Query("versionId")
lf.HostID = ctx.Get("X-Amz-Id-2")
lf.SignatureVersion = "SigV4"
lf.AuthenticationType = "AuthHeader"
lf.HostHeader = fmt.Sprintf("s3.%v.amazonaws.com", ctx.Locals("region").(string))
lf.AccessPointARN = fmt.Sprintf("arn:aws:s3:::%v", strings.Join(path, "/"))
lf.AclRequired = "Yes"
f.writeLog()
f.writeLog(lf)
}
func (fl *FileLogger) writeLog() {
if fl.BucketOwner == "" {
fl.BucketOwner = "-"
func (f *FileLogger) writeLog(lf LogFields) {
if lf.BucketOwner == "" {
lf.BucketOwner = "-"
}
if fl.Bucket == "" {
fl.Bucket = "-"
if lf.Bucket == "" {
lf.Bucket = "-"
}
if fl.RemoteIP == "" {
fl.RemoteIP = "-"
if lf.RemoteIP == "" {
lf.RemoteIP = "-"
}
if fl.Requester == "" {
fl.Requester = "-"
if lf.Requester == "" {
lf.Requester = "-"
}
if fl.Operation == "" {
fl.Operation = "-"
if lf.Operation == "" {
lf.Operation = "-"
}
if fl.Key == "" {
fl.Key = "-"
if lf.Key == "" {
lf.Key = "-"
}
if fl.RequestURI == "" {
fl.RequestURI = "-"
if lf.RequestURI == "" {
lf.RequestURI = "-"
}
if fl.ErrorCode == "" {
fl.ErrorCode = "-"
if lf.ErrorCode == "" {
lf.ErrorCode = "-"
}
if fl.Referer == "" {
fl.Referer = "-"
if lf.Referer == "" {
lf.Referer = "-"
}
if fl.UserAgent == "" {
fl.UserAgent = "-"
if lf.UserAgent == "" {
lf.UserAgent = "-"
}
if fl.VersionID == "" {
fl.VersionID = "-"
if lf.VersionID == "" {
lf.VersionID = "-"
}
if fl.HostID == "" {
fl.HostID = "-"
if lf.HostID == "" {
lf.HostID = "-"
}
if fl.CipherSuite == "" {
fl.CipherSuite = "-"
if lf.CipherSuite == "" {
lf.CipherSuite = "-"
}
if fl.HostHeader == "" {
fl.HostHeader = "-"
if lf.HostHeader == "" {
lf.HostHeader = "-"
}
if fl.TLSVersion == "" {
fl.TLSVersion = "-"
if lf.TLSVersion == "" {
lf.TLSVersion = "-"
}
log := fmt.Sprintf("\n%v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v",
fl.BucketOwner,
fl.Bucket,
fmt.Sprintf("[%v]", fl.Time.Format(timeFormat)),
fl.RemoteIP,
fl.Requester,
fl.RequestID,
fl.Operation,
fl.Key,
fl.RequestURI,
fl.HttpStatus,
fl.ErrorCode,
fl.BytesSent,
fl.ObjectSize,
fl.TotalTime,
fl.TurnAroundTime,
fl.Referer,
fl.UserAgent,
fl.VersionID,
fl.HostID,
fl.SignatureVersion,
fl.CipherSuite,
fl.AuthenticationType,
fl.HostHeader,
fl.TLSVersion,
fl.AccessPointARN,
fl.AclRequired,
log := fmt.Sprintf("%v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v %v\n",
lf.BucketOwner,
lf.Bucket,
fmt.Sprintf("[%v]", lf.Time.Format(timeFormat)),
lf.RemoteIP,
lf.Requester,
lf.RequestID,
lf.Operation,
lf.Key,
lf.RequestURI,
lf.HttpStatus,
lf.ErrorCode,
lf.BytesSent,
lf.ObjectSize,
lf.TotalTime,
lf.TurnAroundTime,
lf.Referer,
lf.UserAgent,
lf.VersionID,
lf.HostID,
lf.SignatureVersion,
lf.CipherSuite,
lf.AuthenticationType,
lf.HostHeader,
lf.TLSVersion,
lf.AccessPointARN,
lf.AclRequired,
)
file, err := os.OpenFile(logFile, os.O_APPEND|os.O_CREATE|os.O_WRONLY, logFileMode)
_, err := f.f.WriteString(log)
if err != nil {
fmt.Printf("error opening the log file: %v", err.Error())
}
defer file.Close()
_, err = file.WriteString(log)
if err != nil {
fmt.Printf("error writing in log file: %v", err.Error())
fmt.Fprintf(os.Stderr, "error writing to log file: %v\n", err)
// TODO: do we need to terminate on log error?
// set err for now so that we don't spew errors
f.gotErr = true
}
}
// HangUp closes current logfile handle and opens a new one
// typically needed for log rotations
func (f *FileLogger) HangUp() error {
err := f.f.Close()
if err != nil {
return fmt.Errorf("close log: %w", err)
}
f.f, err = os.OpenFile(f.logfile, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
if err != nil {
return fmt.Errorf("open log: %w", err)
}
f.f.WriteString(fmt.Sprintf("log starts %v\n", time.Now()))
return nil
}
// Shutdown closes logfile handle
func (f *FileLogger) Shutdown() error {
return f.f.Close()
}

View File

@@ -21,6 +21,7 @@ import (
"fmt"
"net"
"net/http"
"os"
"strings"
"sync"
"time"
@@ -29,14 +30,15 @@ import (
"github.com/versity/versitygw/s3err"
)
// WebhookLogger is a webhook URL audit log
type WebhookLogger struct {
LogFields
mu sync.Mutex
url string
}
var _ AuditLogger = &WebhookLogger{}
// InitWebhookLogger initializes audit logs to webhook URL
func InitWebhookLogger(url string) (AuditLogger, error) {
client := &http.Client{
Timeout: 3 * time.Second,
@@ -44,7 +46,7 @@ func InitWebhookLogger(url string) (AuditLogger, error) {
_, err := client.Post(url, "application/json", nil)
if err != nil {
if err, ok := err.(net.Error); ok && !err.Timeout() {
return nil, fmt.Errorf("unreachable webhook url")
return nil, fmt.Errorf("unreachable webhook url: %w", err)
}
}
return &WebhookLogger{
@@ -52,10 +54,13 @@ func InitWebhookLogger(url string) (AuditLogger, error) {
}, nil
}
// Log sends log message to webhook
func (wl *WebhookLogger) Log(ctx *fiber.Ctx, err error, body []byte, meta LogMeta) {
wl.mu.Lock()
defer wl.mu.Unlock()
lf := LogFields{}
access := "-"
reqURI := ctx.Request().URI().String()
path := strings.Split(ctx.Path(), "/")
@@ -65,8 +70,8 @@ func (wl *WebhookLogger) Log(ctx *fiber.Ctx, err error, body []byte, meta LogMet
startTime := ctx.Locals("startTime").(time.Time)
tlsConnState := ctx.Context().TLSConnectionState()
if tlsConnState != nil {
wl.CipherSuite = tls.CipherSuiteName(tlsConnState.CipherSuite)
wl.TLSVersion = getTLSVersionName(tlsConnState.Version)
lf.CipherSuite = tls.CipherSuiteName(tlsConnState.CipherSuite)
lf.TLSVersion = getTLSVersionName(tlsConnState.Version)
}
if err != nil {
@@ -85,43 +90,43 @@ func (wl *WebhookLogger) Log(ctx *fiber.Ctx, err error, body []byte, meta LogMet
access = ctx.Locals("access").(string)
}
wl.BucketOwner = meta.BucketOwner
wl.Bucket = bucket
wl.Time = time.Now()
wl.RemoteIP = ctx.IP()
wl.Requester = access
wl.RequestID = genID()
wl.Operation = meta.Action
wl.Key = object
wl.RequestURI = reqURI
wl.HttpStatus = httpStatus
wl.ErrorCode = errorCode
wl.BytesSent = len(body)
wl.ObjectSize = meta.ObjectSize
wl.TotalTime = time.Since(startTime).Milliseconds()
wl.TurnAroundTime = time.Since(startTime).Milliseconds()
wl.Referer = ctx.Get("Referer")
wl.UserAgent = ctx.Get("User-Agent")
wl.VersionID = ctx.Query("versionId")
wl.HostID = ctx.Get("X-Amz-Id-2")
wl.SignatureVersion = "SigV4"
wl.AuthenticationType = "AuthHeader"
wl.HostHeader = fmt.Sprintf("s3.%v.amazonaws.com", ctx.Locals("region").(string))
wl.AccessPointARN = fmt.Sprintf("arn:aws:s3:::%v", strings.Join(path, "/"))
wl.AclRequired = "Yes"
lf.BucketOwner = meta.BucketOwner
lf.Bucket = bucket
lf.Time = time.Now()
lf.RemoteIP = ctx.IP()
lf.Requester = access
lf.RequestID = genID()
lf.Operation = meta.Action
lf.Key = object
lf.RequestURI = reqURI
lf.HttpStatus = httpStatus
lf.ErrorCode = errorCode
lf.BytesSent = len(body)
lf.ObjectSize = meta.ObjectSize
lf.TotalTime = time.Since(startTime).Milliseconds()
lf.TurnAroundTime = time.Since(startTime).Milliseconds()
lf.Referer = ctx.Get("Referer")
lf.UserAgent = ctx.Get("User-Agent")
lf.VersionID = ctx.Query("versionId")
lf.HostID = ctx.Get("X-Amz-Id-2")
lf.SignatureVersion = "SigV4"
lf.AuthenticationType = "AuthHeader"
lf.HostHeader = fmt.Sprintf("s3.%v.amazonaws.com", ctx.Locals("region").(string))
lf.AccessPointARN = fmt.Sprintf("arn:aws:s3:::%v", strings.Join(path, "/"))
lf.AclRequired = "Yes"
wl.sendLog()
wl.sendLog(lf)
}
func (wl *WebhookLogger) sendLog() {
jsonLog, err := json.Marshal(wl)
func (wl *WebhookLogger) sendLog(lf LogFields) {
jsonLog, err := json.Marshal(lf)
if err != nil {
fmt.Printf("\n failed to parse the log data: %v", err.Error())
fmt.Fprintf(os.Stderr, "failed to parse the log data: %v\n", err.Error())
}
req, err := http.NewRequest(http.MethodPost, wl.url, bytes.NewReader(jsonLog))
if err != nil {
fmt.Println(err)
fmt.Fprintln(os.Stderr, err)
}
req.Header.Set("Content-Type", "application/json; charset=utf-8")
@@ -135,7 +140,17 @@ func makeRequest(req *http.Request) {
_, err := client.Do(req)
if err != nil {
if err, ok := err.(net.Error); ok && !err.Timeout() {
fmt.Println("error sending the log to the specified url")
fmt.Fprintf(os.Stderr, "error sending webhook log: %v\n", err)
}
}
}
// HangUp does nothing for webhooks
func (wl *WebhookLogger) HangUp() error {
return nil
}
// Shutdown does nothing for webhooks
func (wl *WebhookLogger) Shutdown() error {
return nil
}