2019-07-30 18:51:29 +00:00
|
|
|
// Package logger provides logging capabilities.
|
|
|
|
// It is a wrapper around zerolog for logging and lumberjack for log rotation.
|
2019-07-31 06:14:31 +00:00
|
|
|
// Logs are written to the specified log file.
|
|
|
|
// Logging on the console is provided to print initialization info, errors and warnings.
|
|
|
|
// The package provides a request logger to log the HTTP requests for REST API too.
|
2019-07-30 18:51:29 +00:00
|
|
|
// The request logger uses chi.middleware.RequestLogger,
|
|
|
|
// chi.middleware.LogFormatter and chi.middleware.LogEntry to build a structured
|
2019-10-08 08:29:16 +00:00
|
|
|
// logger using zerolog
|
2019-07-20 10:26:52 +00:00
|
|
|
package logger
|
|
|
|
|
|
|
|
import (
|
2020-06-22 17:11:53 +00:00
|
|
|
"errors"
|
2019-07-20 10:26:52 +00:00
|
|
|
"fmt"
|
2019-07-31 06:14:31 +00:00
|
|
|
"os"
|
2020-03-02 23:34:06 +00:00
|
|
|
"path/filepath"
|
2019-08-07 20:46:13 +00:00
|
|
|
"runtime"
|
2019-07-20 10:26:52 +00:00
|
|
|
|
|
|
|
"github.com/rs/zerolog"
|
|
|
|
lumberjack "gopkg.in/natefinch/lumberjack.v2"
|
|
|
|
)
|
|
|
|
|
|
|
|
const (
|
2019-11-11 14:20:00 +00:00
|
|
|
dateFormat = "2006-01-02T15:04:05.000" // YYYY-MM-DDTHH:MM:SS.ZZZ
|
2019-07-20 10:26:52 +00:00
|
|
|
)
|
|
|
|
|
2019-09-06 13:19:01 +00:00
|
|
|
// LogLevel defines log levels.
|
|
|
|
type LogLevel uint8
|
|
|
|
|
|
|
|
// defines our own log level, just in case we'll change logger in future
|
|
|
|
const (
|
|
|
|
LevelDebug LogLevel = iota
|
|
|
|
LevelInfo
|
|
|
|
LevelWarn
|
|
|
|
LevelError
|
|
|
|
)
|
|
|
|
|
2019-07-20 10:26:52 +00:00
|
|
|
var (
|
2019-07-31 06:14:31 +00:00
|
|
|
logger zerolog.Logger
|
|
|
|
consoleLogger zerolog.Logger
|
2020-06-22 17:11:53 +00:00
|
|
|
rollingLogger *lumberjack.Logger
|
2019-07-20 10:26:52 +00:00
|
|
|
)
|
|
|
|
|
2021-01-03 09:38:28 +00:00
|
|
|
// StdLoggerWrapper is a wrapper for standard logger compatibility
|
|
|
|
type StdLoggerWrapper struct {
|
|
|
|
Sender string
|
|
|
|
}
|
|
|
|
|
|
|
|
// Write implements the io.Writer interface. This is useful to set as a writer
|
|
|
|
// for the standard library log.
|
|
|
|
func (l *StdLoggerWrapper) Write(p []byte) (n int, err error) {
|
|
|
|
n = len(p)
|
|
|
|
if n > 0 && p[n-1] == '\n' {
|
|
|
|
// Trim CR added by stdlog.
|
|
|
|
p = p[0 : n-1]
|
|
|
|
}
|
|
|
|
|
|
|
|
Log(LevelError, l.Sender, "", string(p))
|
|
|
|
return
|
|
|
|
}
|
|
|
|
|
2021-02-12 20:42:49 +00:00
|
|
|
// LeveledLogger is a logger that accepts a message string and a variadic number of key-value pairs
|
|
|
|
type LeveledLogger struct {
|
|
|
|
Sender string
|
|
|
|
}
|
|
|
|
|
|
|
|
func (l *LeveledLogger) addKeysAndValues(ev *zerolog.Event, keysAndValues ...interface{}) {
|
2021-02-13 08:10:35 +00:00
|
|
|
kvLen := len(keysAndValues)
|
|
|
|
if kvLen%2 != 0 {
|
|
|
|
extra := keysAndValues[kvLen-1]
|
|
|
|
keysAndValues = append(keysAndValues[:kvLen-1], "EXTRA_VALUE_AT_END", extra)
|
|
|
|
}
|
|
|
|
for i := 0; i < len(keysAndValues); i = i + 2 {
|
2021-02-12 20:42:49 +00:00
|
|
|
key, val := keysAndValues[i], keysAndValues[i+1]
|
|
|
|
if keyStr, ok := key.(string); ok {
|
|
|
|
ev.Str(keyStr, fmt.Sprintf("%v", val))
|
|
|
|
}
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
// Error logs at error level for the specified sender
|
|
|
|
func (l *LeveledLogger) Error(msg string, keysAndValues ...interface{}) {
|
|
|
|
ev := logger.Error()
|
|
|
|
ev.Timestamp().Str("sender", l.Sender)
|
|
|
|
l.addKeysAndValues(ev, keysAndValues...)
|
2021-02-13 08:10:35 +00:00
|
|
|
ev.Msg(msg)
|
2021-02-12 20:42:49 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
// Info logs at info level for the specified sender
|
|
|
|
func (l *LeveledLogger) Info(msg string, keysAndValues ...interface{}) {
|
|
|
|
ev := logger.Info()
|
|
|
|
ev.Timestamp().Str("sender", l.Sender)
|
|
|
|
l.addKeysAndValues(ev, keysAndValues...)
|
2021-02-13 08:10:35 +00:00
|
|
|
ev.Msg(msg)
|
2021-02-12 20:42:49 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
// Debug logs at debug level for the specified sender
|
|
|
|
func (l *LeveledLogger) Debug(msg string, keysAndValues ...interface{}) {
|
|
|
|
ev := logger.Debug()
|
|
|
|
ev.Timestamp().Str("sender", l.Sender)
|
|
|
|
l.addKeysAndValues(ev, keysAndValues...)
|
2021-02-13 08:10:35 +00:00
|
|
|
ev.Msg(msg)
|
2021-02-12 20:42:49 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
// Warn logs at warn level for the specified sender
|
|
|
|
func (l *LeveledLogger) Warn(msg string, keysAndValues ...interface{}) {
|
|
|
|
ev := logger.Warn()
|
|
|
|
ev.Timestamp().Str("sender", l.Sender)
|
|
|
|
l.addKeysAndValues(ev, keysAndValues...)
|
2021-02-13 08:10:35 +00:00
|
|
|
ev.Msg(msg)
|
2021-02-12 20:42:49 +00:00
|
|
|
}
|
|
|
|
|
2019-07-30 18:51:29 +00:00
|
|
|
// GetLogger get the configured logger instance
|
2019-07-20 10:26:52 +00:00
|
|
|
func GetLogger() *zerolog.Logger {
|
|
|
|
return &logger
|
|
|
|
}
|
|
|
|
|
2019-07-31 12:06:55 +00:00
|
|
|
// InitLogger configures the logger using the given parameters
|
|
|
|
func InitLogger(logFilePath string, logMaxSize int, logMaxBackups int, logMaxAge int, logCompress bool, level zerolog.Level) {
|
2019-07-20 10:26:52 +00:00
|
|
|
zerolog.TimeFieldFormat = dateFormat
|
2020-03-03 08:09:58 +00:00
|
|
|
if isLogFilePathValid(logFilePath) {
|
2020-06-22 17:11:53 +00:00
|
|
|
rollingLogger = &lumberjack.Logger{
|
2019-09-03 21:13:33 +00:00
|
|
|
Filename: logFilePath,
|
|
|
|
MaxSize: logMaxSize,
|
|
|
|
MaxBackups: logMaxBackups,
|
|
|
|
MaxAge: logMaxAge,
|
|
|
|
Compress: logCompress,
|
2020-06-22 17:11:53 +00:00
|
|
|
}
|
|
|
|
logger = zerolog.New(rollingLogger)
|
2019-10-26 16:25:53 +00:00
|
|
|
EnableConsoleLogger(level)
|
2019-09-03 21:13:33 +00:00
|
|
|
} else {
|
2020-07-24 21:39:38 +00:00
|
|
|
logger = zerolog.New(&logSyncWrapper{
|
2019-09-03 21:13:33 +00:00
|
|
|
output: os.Stdout,
|
2020-07-24 21:39:38 +00:00
|
|
|
})
|
2019-09-03 21:13:33 +00:00
|
|
|
consoleLogger = zerolog.Nop()
|
2019-07-31 06:14:31 +00:00
|
|
|
}
|
2020-04-28 20:29:41 +00:00
|
|
|
logger = logger.Level(level)
|
2019-07-20 10:26:52 +00:00
|
|
|
}
|
|
|
|
|
2020-10-29 18:23:33 +00:00
|
|
|
// InitStdErrLogger configures the logger to write to stderr
|
|
|
|
func InitStdErrLogger(level zerolog.Level) {
|
|
|
|
logger = zerolog.New(&logSyncWrapper{
|
|
|
|
output: os.Stderr,
|
|
|
|
}).Level(level)
|
|
|
|
consoleLogger = zerolog.Nop()
|
|
|
|
}
|
|
|
|
|
2019-10-26 16:25:53 +00:00
|
|
|
// DisableLogger disable the main logger.
|
|
|
|
// ConsoleLogger will not be affected
|
|
|
|
func DisableLogger() {
|
|
|
|
logger = zerolog.Nop()
|
2020-06-22 17:11:53 +00:00
|
|
|
rollingLogger = nil
|
2019-10-26 16:25:53 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
// EnableConsoleLogger enables the console logger
|
|
|
|
func EnableConsoleLogger(level zerolog.Level) {
|
|
|
|
consoleOutput := zerolog.ConsoleWriter{
|
|
|
|
Out: os.Stdout,
|
|
|
|
TimeFormat: dateFormat,
|
|
|
|
NoColor: runtime.GOOS == "windows",
|
|
|
|
}
|
|
|
|
consoleLogger = zerolog.New(consoleOutput).With().Timestamp().Logger().Level(level)
|
|
|
|
}
|
|
|
|
|
2020-06-22 17:11:53 +00:00
|
|
|
// RotateLogFile closes the existing log file and immediately create a new one
|
|
|
|
func RotateLogFile() error {
|
|
|
|
if rollingLogger != nil {
|
|
|
|
return rollingLogger.Rotate()
|
|
|
|
}
|
|
|
|
return errors.New("logging to file is disabled")
|
|
|
|
}
|
|
|
|
|
2019-09-06 13:19:01 +00:00
|
|
|
// Log logs at the specified level for the specified sender
|
|
|
|
func Log(level LogLevel, sender string, connectionID string, format string, v ...interface{}) {
|
2020-10-05 13:51:17 +00:00
|
|
|
var ev *zerolog.Event
|
2019-09-06 13:19:01 +00:00
|
|
|
switch level {
|
|
|
|
case LevelDebug:
|
2020-10-05 13:51:17 +00:00
|
|
|
ev = logger.Debug()
|
2019-09-06 13:19:01 +00:00
|
|
|
case LevelInfo:
|
2020-10-05 13:51:17 +00:00
|
|
|
ev = logger.Info()
|
2019-09-06 13:19:01 +00:00
|
|
|
case LevelWarn:
|
2020-10-05 13:51:17 +00:00
|
|
|
ev = logger.Warn()
|
2019-09-06 13:19:01 +00:00
|
|
|
default:
|
2020-10-05 13:51:17 +00:00
|
|
|
ev = logger.Error()
|
2019-09-06 13:19:01 +00:00
|
|
|
}
|
2020-10-05 13:51:17 +00:00
|
|
|
ev.Timestamp().Str("sender", sender)
|
|
|
|
if connectionID != "" {
|
|
|
|
ev.Str("connection_id", connectionID)
|
|
|
|
}
|
|
|
|
ev.Msg(fmt.Sprintf(format, v...))
|
2019-09-06 13:19:01 +00:00
|
|
|
}
|
|
|
|
|
2019-07-30 18:51:29 +00:00
|
|
|
// Debug logs at debug level for the specified sender
|
2019-09-05 14:21:35 +00:00
|
|
|
func Debug(sender string, connectionID string, format string, v ...interface{}) {
|
2020-10-05 13:51:17 +00:00
|
|
|
Log(LevelDebug, sender, connectionID, format, v...)
|
2019-07-20 10:26:52 +00:00
|
|
|
}
|
|
|
|
|
2019-07-30 18:51:29 +00:00
|
|
|
// Info logs at info level for the specified sender
|
2019-09-05 14:21:35 +00:00
|
|
|
func Info(sender string, connectionID string, format string, v ...interface{}) {
|
2020-10-05 13:51:17 +00:00
|
|
|
Log(LevelInfo, sender, connectionID, format, v...)
|
2019-07-20 10:26:52 +00:00
|
|
|
}
|
|
|
|
|
2019-07-30 18:51:29 +00:00
|
|
|
// Warn logs at warn level for the specified sender
|
2019-09-05 14:21:35 +00:00
|
|
|
func Warn(sender string, connectionID string, format string, v ...interface{}) {
|
2020-10-05 13:51:17 +00:00
|
|
|
Log(LevelWarn, sender, connectionID, format, v...)
|
2019-07-20 10:26:52 +00:00
|
|
|
}
|
|
|
|
|
2019-07-30 18:51:29 +00:00
|
|
|
// Error logs at error level for the specified sender
|
2019-09-05 14:21:35 +00:00
|
|
|
func Error(sender string, connectionID string, format string, v ...interface{}) {
|
2020-10-05 13:51:17 +00:00
|
|
|
Log(LevelError, sender, connectionID, format, v...)
|
2019-07-20 10:26:52 +00:00
|
|
|
}
|
|
|
|
|
2019-07-31 06:14:31 +00:00
|
|
|
// DebugToConsole logs at debug level to stdout
|
|
|
|
func DebugToConsole(format string, v ...interface{}) {
|
|
|
|
consoleLogger.Debug().Msg(fmt.Sprintf(format, v...))
|
|
|
|
}
|
|
|
|
|
|
|
|
// InfoToConsole logs at info level to stdout
|
|
|
|
func InfoToConsole(format string, v ...interface{}) {
|
|
|
|
consoleLogger.Info().Msg(fmt.Sprintf(format, v...))
|
|
|
|
}
|
|
|
|
|
|
|
|
// WarnToConsole logs at info level to stdout
|
|
|
|
func WarnToConsole(format string, v ...interface{}) {
|
|
|
|
consoleLogger.Warn().Msg(fmt.Sprintf(format, v...))
|
|
|
|
}
|
|
|
|
|
|
|
|
// ErrorToConsole logs at error level to stdout
|
|
|
|
func ErrorToConsole(format string, v ...interface{}) {
|
|
|
|
consoleLogger.Error().Msg(fmt.Sprintf(format, v...))
|
|
|
|
}
|
|
|
|
|
2021-02-14 21:08:08 +00:00
|
|
|
// TransferLog logs uploads or downloads
|
2019-08-24 12:41:15 +00:00
|
|
|
func TransferLog(operation string, path string, elapsed int64, size int64, user string, connectionID string, protocol string) {
|
2019-07-20 10:26:52 +00:00
|
|
|
logger.Info().
|
2019-11-11 14:20:00 +00:00
|
|
|
Timestamp().
|
2019-07-20 10:26:52 +00:00
|
|
|
Str("sender", operation).
|
|
|
|
Int64("elapsed_ms", elapsed).
|
|
|
|
Int64("size_bytes", size).
|
|
|
|
Str("username", user).
|
|
|
|
Str("file_path", path).
|
|
|
|
Str("connection_id", connectionID).
|
2019-08-24 12:41:15 +00:00
|
|
|
Str("protocol", protocol).
|
2020-10-29 18:23:33 +00:00
|
|
|
Send()
|
2019-07-20 10:26:52 +00:00
|
|
|
}
|
|
|
|
|
2019-11-19 10:38:39 +00:00
|
|
|
// CommandLog logs an SFTP/SCP/SSH command
|
2020-08-20 11:54:36 +00:00
|
|
|
func CommandLog(command, path, target, user, fileMode, connectionID, protocol string, uid, gid int, atime, mtime,
|
|
|
|
sshCommand string, size int64) {
|
2019-07-20 10:26:52 +00:00
|
|
|
logger.Info().
|
2019-11-11 14:20:00 +00:00
|
|
|
Timestamp().
|
2019-07-20 10:26:52 +00:00
|
|
|
Str("sender", command).
|
|
|
|
Str("username", user).
|
|
|
|
Str("file_path", path).
|
|
|
|
Str("target_path", target).
|
2019-11-15 11:15:07 +00:00
|
|
|
Str("filemode", fileMode).
|
|
|
|
Int("uid", uid).
|
|
|
|
Int("gid", gid).
|
2019-11-16 09:23:41 +00:00
|
|
|
Str("access_time", atime).
|
|
|
|
Str("modification_time", atime).
|
2020-08-20 11:54:36 +00:00
|
|
|
Int64("size", size).
|
2019-11-19 10:38:39 +00:00
|
|
|
Str("ssh_command", sshCommand).
|
2019-07-20 10:26:52 +00:00
|
|
|
Str("connection_id", connectionID).
|
2019-08-24 12:41:15 +00:00
|
|
|
Str("protocol", protocol).
|
2020-10-29 18:23:33 +00:00
|
|
|
Send()
|
2019-07-20 10:26:52 +00:00
|
|
|
}
|
2019-11-11 14:20:00 +00:00
|
|
|
|
|
|
|
// ConnectionFailedLog logs failed attempts to initialize a connection.
|
|
|
|
// A connection can fail for an authentication error or other errors such as
|
|
|
|
// a client abort or a time out if the login does not happen in two minutes.
|
|
|
|
// These logs are useful for better integration with Fail2ban and similar tools.
|
2020-08-12 14:15:12 +00:00
|
|
|
func ConnectionFailedLog(user, ip, loginType, protocol, errorString string) {
|
2019-11-11 14:20:00 +00:00
|
|
|
logger.Debug().
|
|
|
|
Timestamp().
|
|
|
|
Str("sender", "connection_failed").
|
2019-11-11 18:53:27 +00:00
|
|
|
Str("client_ip", ip).
|
2019-11-11 14:20:00 +00:00
|
|
|
Str("username", user).
|
|
|
|
Str("login_type", loginType).
|
2020-08-12 14:15:12 +00:00
|
|
|
Str("protocol", protocol).
|
2019-11-11 14:20:00 +00:00
|
|
|
Str("error", errorString).
|
2020-10-29 18:23:33 +00:00
|
|
|
Send()
|
2019-11-11 14:20:00 +00:00
|
|
|
}
|
2020-03-03 08:09:58 +00:00
|
|
|
|
|
|
|
func isLogFilePathValid(logFilePath string) bool {
|
|
|
|
cleanInput := filepath.Clean(logFilePath)
|
|
|
|
if cleanInput == "." || cleanInput == ".." {
|
|
|
|
return false
|
|
|
|
}
|
|
|
|
return true
|
|
|
|
}
|