1//  Copyright (c) 2016-2019 Couchbase, Inc.
2//  Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file
3//  except in compliance with the License. You may obtain a copy of the License at
4//    http://www.apache.org/licenses/LICENSE-2.0
5//  Unless required by applicable law or agreed to in writing, software distributed under the
6//  License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND,
7//  either express or implied. See the License for the specific language governing permissions
8//  and limitations under the License.
9
10package logging
11
12import (
13	"bytes"
14	"encoding/json"
15	"fmt"
16	"io"
17	"log"
18	"time"
19)
20
21type goLogger struct {
22	logger         *log.Logger
23	level          Level
24	entryFormatter formatter
25}
26
27const (
28	_LEVEL  = "_level"
29	_MSG    = "_msg"
30	_TIME   = "_time"
31	_RLEVEL = "_rlevel"
32)
33
34func NewLogger(out io.Writer, lvl Level, fmtLogging LogEntryFormatter, fmtArgs ...interface{}) *goLogger {
35	logger := &goLogger{
36		logger: log.New(out, "", 0),
37		level:  lvl,
38	}
39	if fmtLogging == JSONFORMATTER {
40		logger.entryFormatter = &jsonFormatter{}
41	} else if fmtLogging == KVFORMATTER {
42		logger.entryFormatter = &keyvalueFormatter{}
43	} else if fmtLogging == UNIFORMFORMATTER {
44		logger.entryFormatter = &uniformFormatter{
45			callback: fmtArgs[0].(ComponentCallback),
46		}
47	} else {
48		logger.entryFormatter = &textFormatter{}
49	}
50	return logger
51}
52
53func (gl *goLogger) Logp(level Level, msg string, kv ...Pair) {
54	if gl.logger == nil {
55		return
56	}
57	if level <= gl.level {
58		e := newLogEntry(msg, level)
59		copyPairs(e, kv)
60		gl.log(e)
61	}
62}
63
64func (gl *goLogger) Debugp(msg string, kv ...Pair) {
65	gl.Logp(DEBUG, msg, kv...)
66}
67
68func (gl *goLogger) Tracep(msg string, kv ...Pair) {
69	gl.Logp(TRACE, msg, kv...)
70}
71
72func (gl *goLogger) Requestp(rlevel Level, msg string, kv ...Pair) {
73	if gl.logger == nil {
74		return
75	}
76	if REQUEST <= gl.level {
77		e := newLogEntry(msg, REQUEST)
78		e.Rlevel = rlevel
79		copyPairs(e, kv)
80		gl.log(e)
81	}
82}
83
84func (gl *goLogger) Infop(msg string, kv ...Pair) {
85	gl.Logp(INFO, msg, kv...)
86}
87
88func (gl *goLogger) Warnp(msg string, kv ...Pair) {
89	gl.Logp(WARN, msg, kv...)
90}
91
92func (gl *goLogger) Errorp(msg string, kv ...Pair) {
93	gl.Logp(ERROR, msg, kv...)
94}
95
96func (gl *goLogger) Severep(msg string, kv ...Pair) {
97	gl.Logp(SEVERE, msg, kv...)
98}
99
100func (gl *goLogger) Fatalp(msg string, kv ...Pair) {
101	gl.Logp(FATAL, msg, kv...)
102}
103
104func (gl *goLogger) Logm(level Level, msg string, kv Map) {
105	if gl.logger == nil {
106		return
107	}
108	if level <= gl.level {
109		e := newLogEntry(msg, level)
110		e.Data = kv
111		gl.log(e)
112	}
113}
114
115func (gl *goLogger) Debugm(msg string, kv Map) {
116	gl.Logm(DEBUG, msg, kv)
117}
118
119func (gl *goLogger) Tracem(msg string, kv Map) {
120	gl.Logm(TRACE, msg, kv)
121}
122
123func (gl *goLogger) Requestm(rlevel Level, msg string, kv Map) {
124	if gl.logger == nil {
125		return
126	}
127	if REQUEST <= gl.level {
128		e := newLogEntry(msg, REQUEST)
129		e.Rlevel = rlevel
130		e.Data = kv
131		gl.log(e)
132	}
133}
134
135func (gl *goLogger) Infom(msg string, kv Map) {
136	gl.Logm(INFO, msg, kv)
137}
138
139func (gl *goLogger) Warnm(msg string, kv Map) {
140	gl.Logm(WARN, msg, kv)
141}
142
143func (gl *goLogger) Errorm(msg string, kv Map) {
144	gl.Logm(ERROR, msg, kv)
145}
146
147func (gl *goLogger) Severem(msg string, kv Map) {
148	gl.Logm(SEVERE, msg, kv)
149}
150
151func (gl *goLogger) Fatalm(msg string, kv Map) {
152	gl.Logm(FATAL, msg, kv)
153}
154
155func (gl *goLogger) Logf(level Level, format string, args ...interface{}) {
156	if gl.logger == nil {
157		return
158	}
159	if level <= gl.level {
160		e := newLogEntry(fmt.Sprintf(format, args...), level)
161		gl.log(e)
162	}
163}
164
165func (gl *goLogger) Debugf(format string, args ...interface{}) {
166	gl.Logf(DEBUG, format, args...)
167}
168
169func (gl *goLogger) Tracef(format string, args ...interface{}) {
170	gl.Logf(TRACE, format, args...)
171}
172
173func (gl *goLogger) Requestf(rlevel Level, format string, args ...interface{}) {
174	if gl.logger == nil {
175		return
176	}
177	if REQUEST <= gl.level {
178		e := newLogEntry(fmt.Sprintf(format, args...), REQUEST)
179		e.Rlevel = rlevel
180		gl.log(e)
181	}
182}
183
184func (gl *goLogger) Infof(format string, args ...interface{}) {
185	gl.Logf(INFO, format, args...)
186}
187
188func (gl *goLogger) Warnf(format string, args ...interface{}) {
189	gl.Logf(WARN, format, args...)
190}
191
192func (gl *goLogger) Errorf(format string, args ...interface{}) {
193	gl.Logf(ERROR, format, args...)
194}
195
196func (gl *goLogger) Severef(format string, args ...interface{}) {
197	gl.Logf(SEVERE, format, args...)
198}
199
200func (gl *goLogger) Fatalf(format string, args ...interface{}) {
201	gl.Logf(FATAL, format, args...)
202}
203
204func (gl *goLogger) Level() Level {
205	return gl.level
206}
207
208func (gl *goLogger) SetLevel(level Level) {
209	gl.level = level
210}
211
212func (gl *goLogger) log(newEntry *logEntry) {
213	s := gl.entryFormatter.format(newEntry)
214	gl.logger.Print(s)
215}
216
217type logEntry struct {
218	Time    string
219	Level   Level
220	Rlevel  Level
221	Message string
222	Data    Map
223}
224
225func newLogEntry(msg string, level Level) *logEntry {
226	return &logEntry{
227		Time:    time.Now().Format("2006-01-02T15:04:05.000-07:00"), // time.RFC3339 with milliseconds
228		Level:   level,
229		Rlevel:  NONE,
230		Message: msg,
231	}
232}
233
234func copyPairs(newEntry *logEntry, pairs []Pair) {
235	newEntry.Data = make(Map, len(pairs))
236	for _, p := range pairs {
237		newEntry.Data[p.Name] = p.Value
238	}
239}
240
241type formatter interface {
242	format(*logEntry) string
243}
244
245type textFormatter struct {
246}
247
248// ex. 2016-02-10T09:15:25.498-08:00 [INFO] This is a message from test in text format
249
250func (*textFormatter) format(newEntry *logEntry) string {
251	b := &bytes.Buffer{}
252	appendValue(b, newEntry.Time)
253	if newEntry.Rlevel != NONE {
254		fmt.Fprintf(b, "[%s,%s] ", newEntry.Level.String(), newEntry.Rlevel.String())
255	} else {
256		fmt.Fprintf(b, "[%s] ", newEntry.Level.String())
257	}
258	appendValue(b, newEntry.Message)
259	for key, value := range newEntry.Data {
260		appendKeyValue(b, key, value)
261	}
262	b.WriteByte('\n')
263	s := bytes.NewBuffer(b.Bytes())
264	return s.String()
265}
266
267func appendValue(b *bytes.Buffer, value interface{}) {
268	if _, ok := value.(string); ok {
269		fmt.Fprintf(b, "%s ", value)
270	} else {
271		fmt.Fprintf(b, "%v ", value)
272	}
273}
274
275type keyvalueFormatter struct {
276}
277
278// ex. _time=2016-02-10T09:15:25.498-08:00 _level=INFO _msg=This is a message from test in key-value format
279
280func (*keyvalueFormatter) format(newEntry *logEntry) string {
281	b := &bytes.Buffer{}
282	appendKeyValue(b, _TIME, newEntry.Time)
283	appendKeyValue(b, _LEVEL, newEntry.Level.String())
284	if newEntry.Rlevel != NONE {
285		appendKeyValue(b, _RLEVEL, newEntry.Rlevel.String())
286	}
287	appendKeyValue(b, _MSG, newEntry.Message)
288	for key, value := range newEntry.Data {
289		appendKeyValue(b, key, value)
290	}
291	b.WriteByte('\n')
292	s := bytes.NewBuffer(b.Bytes())
293	return s.String()
294}
295
296func appendKeyValue(b *bytes.Buffer, key, value interface{}) {
297	if _, ok := value.(string); ok {
298		fmt.Fprintf(b, "%v=%s ", key, value)
299	} else {
300		fmt.Fprintf(b, "%v=%v ", key, value)
301	}
302}
303
304type jsonFormatter struct {
305}
306
307// ex. {"_level":"INFO","_msg":"This is a message from test in json format","_time":"2016-02-10T09:12:59.518-08:00"}
308
309func (*jsonFormatter) format(newEntry *logEntry) string {
310	if newEntry.Data == nil {
311		newEntry.Data = make(Map, 5)
312	}
313	newEntry.Data[_TIME] = newEntry.Time
314	newEntry.Data[_LEVEL] = newEntry.Level.String()
315	if newEntry.Rlevel != NONE {
316		newEntry.Data[_RLEVEL] = newEntry.Rlevel.String()
317	}
318	newEntry.Data[_MSG] = newEntry.Message
319	serialized, _ := json.Marshal(newEntry.Data)
320	s := bytes.NewBuffer(append(serialized, '\n'))
321	return s.String()
322}
323
324type ComponentCallback func() string
325
326type uniformFormatter struct {
327	callback ComponentCallback
328}
329
330// ex. 2019-03-15T11:28:07.652-04:00 DEBU COMPONENT.subcomponent This is a message from test in uniform format
331
332var _LEVEL_UNIFORM = []string{
333	DEBUG:   "DEBU",
334	TRACE:   "TRAC",
335	REQUEST: "REQU",
336	INFO:    "INFO",
337	WARN:    "WARN",
338	ERROR:   "ERRO",
339	SEVERE:  "SEVE",
340	FATAL:   "FATA",
341	NONE:    "NONE",
342}
343
344func (level Level) UniformString() string {
345	return _LEVEL_UNIFORM[level]
346}
347
348func (uf *uniformFormatter) format(newEntry *logEntry) string {
349	b := &bytes.Buffer{}
350	appendValue(b, newEntry.Time)
351	component := uf.callback()
352	if newEntry.Rlevel != NONE {
353		// not really any accommodation for a composite level in the uniform standard; just output as abbr,abbr
354		fmt.Fprintf(b, "%s,%s %s ", newEntry.Level.UniformString(), newEntry.Rlevel.UniformString(), component)
355	} else {
356		fmt.Fprintf(b, "%s %s ", newEntry.Level.UniformString(), component)
357	}
358	appendValue(b, newEntry.Message)
359	for key, value := range newEntry.Data {
360		appendKeyValue(b, key, value)
361	}
362	b.WriteByte('\n')
363	s := bytes.NewBuffer(b.Bytes())
364	return s.String()
365}
366