1// Copyright (c) 2017 Daniel Oaks <daniel@danieloaks.net>
2// released under the MIT license
3
4package logger
5
6import (
7	"bufio"
8	"bytes"
9	"fmt"
10	"os"
11	"time"
12
13	"sync"
14	"sync/atomic"
15)
16
17// Level represents the level to log messages at.
18type Level int
19
20const (
21	// LogDebug represents debug messages.
22	LogDebug Level = iota
23	// LogInfo represents informational messages.
24	LogInfo
25	// LogWarning represents warnings.
26	LogWarning
27	// LogError represents errors.
28	LogError
29)
30
31var (
32	// LogLevelNames takes a config name and gives the real log level.
33	LogLevelNames = map[string]Level{
34		"debug":    LogDebug,
35		"info":     LogInfo,
36		"warn":     LogWarning,
37		"warning":  LogWarning,
38		"warnings": LogWarning,
39		"error":    LogError,
40		"errors":   LogError,
41	}
42	// LogLevelDisplayNames gives the display name to use for our log levels.
43	LogLevelDisplayNames = map[Level]string{
44		LogDebug:   "debug",
45		LogInfo:    "info",
46		LogWarning: "warn",
47		LogError:   "error",
48	}
49
50	// these are old names for log types that might still appear in yaml configs,
51	// but have been replaced in the code. this is used for canonicalization when
52	// loading configs, but not during logging.
53	typeAliases = map[string]string{
54		"localconnect":    "connect",
55		"localconnect-ip": "connect-ip",
56	}
57)
58
59func resolveTypeAlias(typeName string) (result string) {
60	if canonicalized, ok := typeAliases[typeName]; ok {
61		return canonicalized
62	}
63	return typeName
64}
65
66// Manager is the main interface used to log debug/info/error messages.
67type Manager struct {
68	configMutex     sync.RWMutex
69	loggers         []singleLogger
70	stdoutWriteLock sync.Mutex // use one lock for both stdout and stderr
71	fileWriteLock   sync.Mutex
72	loggingRawIO    uint32
73}
74
75// LoggingConfig represents the configuration of a single logger.
76type LoggingConfig struct {
77	Method        string
78	MethodStdout  bool
79	MethodStderr  bool
80	MethodFile    bool
81	Filename      string
82	TypeString    string   `yaml:"type"`
83	Types         []string `yaml:"real-types"`
84	ExcludedTypes []string `yaml:"real-excluded-types"`
85	LevelString   string   `yaml:"level"`
86	Level         Level    `yaml:"level-real"`
87}
88
89// NewManager returns a new log manager.
90func NewManager(config []LoggingConfig) (*Manager, error) {
91	var logger Manager
92
93	if err := logger.ApplyConfig(config); err != nil {
94		return nil, err
95	}
96
97	return &logger, nil
98}
99
100// ApplyConfig applies the given config to this logger (rehashes the config, in other words).
101func (logger *Manager) ApplyConfig(config []LoggingConfig) error {
102	logger.configMutex.Lock()
103	defer logger.configMutex.Unlock()
104
105	for _, logger := range logger.loggers {
106		logger.Close()
107	}
108
109	logger.loggers = nil
110	atomic.StoreUint32(&logger.loggingRawIO, 0)
111
112	// for safety, this deep-copies all mutable data in `config`
113	// XXX let's keep it that way
114	var lastErr error
115	for _, logConfig := range config {
116		typeMap := make(map[string]bool)
117		for _, name := range logConfig.Types {
118			typeMap[resolveTypeAlias(name)] = true
119		}
120		excludedTypeMap := make(map[string]bool)
121		for _, name := range logConfig.ExcludedTypes {
122			excludedTypeMap[resolveTypeAlias(name)] = true
123		}
124
125		sLogger := singleLogger{
126			MethodSTDOUT: logConfig.MethodStdout,
127			MethodSTDERR: logConfig.MethodStderr,
128			MethodFile: fileMethod{
129				Enabled:  logConfig.MethodFile,
130				Filename: logConfig.Filename,
131			},
132			Level:           logConfig.Level,
133			Types:           typeMap,
134			ExcludedTypes:   excludedTypeMap,
135			stdoutWriteLock: &logger.stdoutWriteLock,
136			fileWriteLock:   &logger.fileWriteLock,
137		}
138		ioEnabled := typeMap["userinput"] || typeMap["useroutput"] || (typeMap["*"] && !(excludedTypeMap["userinput"] && excludedTypeMap["useroutput"]))
139		// raw I/O is only logged at level debug;
140		if ioEnabled && logConfig.Level == LogDebug {
141			atomic.StoreUint32(&logger.loggingRawIO, 1)
142		}
143		if sLogger.MethodFile.Enabled {
144			file, err := os.OpenFile(sLogger.MethodFile.Filename, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0666)
145			if err != nil {
146				lastErr = fmt.Errorf("Could not open log file %s [%s]", sLogger.MethodFile.Filename, err.Error())
147			}
148			writer := bufio.NewWriter(file)
149			sLogger.MethodFile.File = file
150			sLogger.MethodFile.Writer = writer
151		}
152		logger.loggers = append(logger.loggers, sLogger)
153	}
154
155	return lastErr
156}
157
158// IsLoggingRawIO returns true if raw user input and output is being logged.
159func (logger *Manager) IsLoggingRawIO() bool {
160	return atomic.LoadUint32(&logger.loggingRawIO) == 1
161}
162
163// Log logs the given message with the given details.
164func (logger *Manager) Log(level Level, logType string, messageParts ...string) {
165	logger.configMutex.RLock()
166	defer logger.configMutex.RUnlock()
167
168	for _, singleLogger := range logger.loggers {
169		singleLogger.Log(level, logType, messageParts...)
170	}
171}
172
173// Debug logs the given message as a debug message.
174func (logger *Manager) Debug(logType string, messageParts ...string) {
175	logger.Log(LogDebug, logType, messageParts...)
176}
177
178// Info logs the given message as an info message.
179func (logger *Manager) Info(logType string, messageParts ...string) {
180	logger.Log(LogInfo, logType, messageParts...)
181}
182
183// Warning logs the given message as a warning message.
184func (logger *Manager) Warning(logType string, messageParts ...string) {
185	logger.Log(LogWarning, logType, messageParts...)
186}
187
188// Error logs the given message as an error message.
189func (logger *Manager) Error(logType string, messageParts ...string) {
190	logger.Log(LogError, logType, messageParts...)
191}
192
193type fileMethod struct {
194	Enabled  bool
195	Filename string
196	File     *os.File
197	Writer   *bufio.Writer
198}
199
200// singleLogger represents a single logger instance.
201type singleLogger struct {
202	stdoutWriteLock *sync.Mutex
203	fileWriteLock   *sync.Mutex
204	MethodSTDOUT    bool
205	MethodSTDERR    bool
206	MethodFile      fileMethod
207	Level           Level
208	Types           map[string]bool
209	ExcludedTypes   map[string]bool
210}
211
212func (logger *singleLogger) Close() error {
213	if logger.MethodFile.Enabled {
214		flushErr := logger.MethodFile.Writer.Flush()
215		closeErr := logger.MethodFile.File.Close()
216		if flushErr != nil {
217			return flushErr
218		}
219		return closeErr
220	}
221	return nil
222}
223
224// Log logs the given message with the given details.
225func (logger *singleLogger) Log(level Level, logType string, messageParts ...string) {
226	// no logging enabled
227	if !(logger.MethodSTDOUT || logger.MethodSTDERR || logger.MethodFile.Enabled) {
228		return
229	}
230
231	// ensure we're logging to the given level
232	if level < logger.Level {
233		return
234	}
235
236	// ensure we're capturing this logType
237	capturing := (logger.Types["*"] || logger.Types[logType]) && !logger.ExcludedTypes["*"] && !logger.ExcludedTypes[logType]
238	if !capturing {
239		return
240	}
241
242	// assemble full line
243
244	var rawBuf bytes.Buffer
245	// XXX magic number here: 10 is len("connect-ip"), the longest log category name
246	// in current use. it's not a big deal if this number gets out of date.
247	fmt.Fprintf(&rawBuf, "%s : %-5s : %-10s : ", time.Now().UTC().Format("2006-01-02T15:04:05.000Z"), LogLevelDisplayNames[level], logType)
248	for i, p := range messageParts {
249		rawBuf.WriteString(p)
250
251		if i != len(messageParts)-1 {
252			rawBuf.WriteString(" : ")
253		}
254	}
255	rawBuf.WriteRune('\n')
256
257	// output
258	if logger.MethodSTDOUT {
259		logger.stdoutWriteLock.Lock()
260		os.Stdout.Write(rawBuf.Bytes())
261		logger.stdoutWriteLock.Unlock()
262	}
263	if logger.MethodSTDERR {
264		logger.stdoutWriteLock.Lock()
265		os.Stderr.Write(rawBuf.Bytes())
266		logger.stdoutWriteLock.Unlock()
267	}
268	if logger.MethodFile.Enabled {
269		logger.fileWriteLock.Lock()
270		logger.MethodFile.Writer.Write(rawBuf.Bytes())
271		logger.MethodFile.Writer.Flush()
272		logger.fileWriteLock.Unlock()
273	}
274}
275