1package logger
2
3// Copyright 2017 Microsoft Corporation
4//
5//  Licensed under the Apache License, Version 2.0 (the "License");
6//  you may not use this file except in compliance with the License.
7//  You may obtain a copy of the License at
8//
9//      http://www.apache.org/licenses/LICENSE-2.0
10//
11//  Unless required by applicable law or agreed to in writing, software
12//  distributed under the License is distributed on an "AS IS" BASIS,
13//  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14//  See the License for the specific language governing permissions and
15//  limitations under the License.
16
17import (
18	"bytes"
19	"fmt"
20	"io"
21	"io/ioutil"
22	"net/http"
23	"net/url"
24	"os"
25	"strings"
26	"sync"
27	"time"
28)
29
30// LevelType tells a logger the minimum level to log. When code reports a log entry,
31// the LogLevel indicates the level of the log entry. The logger only records entries
32// whose level is at least the level it was told to log. See the Log* constants.
33// For example, if a logger is configured with LogError, then LogError, LogPanic,
34// and LogFatal entries will be logged; lower level entries are ignored.
35type LevelType uint32
36
37const (
38	// LogNone tells a logger not to log any entries passed to it.
39	LogNone LevelType = iota
40
41	// LogFatal tells a logger to log all LogFatal entries passed to it.
42	LogFatal
43
44	// LogPanic tells a logger to log all LogPanic and LogFatal entries passed to it.
45	LogPanic
46
47	// LogError tells a logger to log all LogError, LogPanic and LogFatal entries passed to it.
48	LogError
49
50	// LogWarning tells a logger to log all LogWarning, LogError, LogPanic and LogFatal entries passed to it.
51	LogWarning
52
53	// LogInfo tells a logger to log all LogInfo, LogWarning, LogError, LogPanic and LogFatal entries passed to it.
54	LogInfo
55
56	// LogDebug tells a logger to log all LogDebug, LogInfo, LogWarning, LogError, LogPanic and LogFatal entries passed to it.
57	LogDebug
58)
59
60const (
61	logNone    = "NONE"
62	logFatal   = "FATAL"
63	logPanic   = "PANIC"
64	logError   = "ERROR"
65	logWarning = "WARNING"
66	logInfo    = "INFO"
67	logDebug   = "DEBUG"
68	logUnknown = "UNKNOWN"
69)
70
71// ParseLevel converts the specified string into the corresponding LevelType.
72func ParseLevel(s string) (lt LevelType, err error) {
73	switch strings.ToUpper(s) {
74	case logFatal:
75		lt = LogFatal
76	case logPanic:
77		lt = LogPanic
78	case logError:
79		lt = LogError
80	case logWarning:
81		lt = LogWarning
82	case logInfo:
83		lt = LogInfo
84	case logDebug:
85		lt = LogDebug
86	default:
87		err = fmt.Errorf("bad log level '%s'", s)
88	}
89	return
90}
91
92// String implements the stringer interface for LevelType.
93func (lt LevelType) String() string {
94	switch lt {
95	case LogNone:
96		return logNone
97	case LogFatal:
98		return logFatal
99	case LogPanic:
100		return logPanic
101	case LogError:
102		return logError
103	case LogWarning:
104		return logWarning
105	case LogInfo:
106		return logInfo
107	case LogDebug:
108		return logDebug
109	default:
110		return logUnknown
111	}
112}
113
114// Filter defines functions for filtering HTTP request/response content.
115type Filter struct {
116	// URL returns a potentially modified string representation of a request URL.
117	URL func(u *url.URL) string
118
119	// Header returns a potentially modified set of values for the specified key.
120	// To completely exclude the header key/values return false.
121	Header func(key string, val []string) (bool, []string)
122
123	// Body returns a potentially modified request/response body.
124	Body func(b []byte) []byte
125}
126
127func (f Filter) processURL(u *url.URL) string {
128	if f.URL == nil {
129		return u.String()
130	}
131	return f.URL(u)
132}
133
134func (f Filter) processHeader(k string, val []string) (bool, []string) {
135	if f.Header == nil {
136		return true, val
137	}
138	return f.Header(k, val)
139}
140
141func (f Filter) processBody(b []byte) []byte {
142	if f.Body == nil {
143		return b
144	}
145	return f.Body(b)
146}
147
148// Writer defines methods for writing to a logging facility.
149type Writer interface {
150	// Writeln writes the specified message with the standard log entry header and new-line character.
151	Writeln(level LevelType, message string)
152
153	// Writef writes the specified format specifier with the standard log entry header and no new-line character.
154	Writef(level LevelType, format string, a ...interface{})
155
156	// WriteRequest writes the specified HTTP request to the logger if the log level is greater than
157	// or equal to LogInfo.  The request body, if set, is logged at level LogDebug or higher.
158	// Custom filters can be specified to exclude URL, header, and/or body content from the log.
159	// By default no request content is excluded.
160	WriteRequest(req *http.Request, filter Filter)
161
162	// WriteResponse writes the specified HTTP response to the logger if the log level is greater than
163	// or equal to LogInfo.  The response body, if set, is logged at level LogDebug or higher.
164	// Custom filters can be specified to exclude URL, header, and/or body content from the log.
165	// By default no response content is excluded.
166	WriteResponse(resp *http.Response, filter Filter)
167}
168
169// Instance is the default log writer initialized during package init.
170// This can be replaced with a custom implementation as required.
171var Instance Writer
172
173// default log level
174var logLevel = LogNone
175
176// Level returns the value specified in AZURE_GO_AUTOREST_LOG_LEVEL.
177// If no value was specified the default value is LogNone.
178// Custom loggers can call this to retrieve the configured log level.
179func Level() LevelType {
180	return logLevel
181}
182
183func init() {
184	// separated for testing purposes
185	initDefaultLogger()
186}
187
188func initDefaultLogger() {
189	// init with nilLogger so callers don't have to do a nil check on Default
190	Instance = nilLogger{}
191	llStr := strings.ToLower(os.Getenv("AZURE_GO_SDK_LOG_LEVEL"))
192	if llStr == "" {
193		return
194	}
195	var err error
196	logLevel, err = ParseLevel(llStr)
197	if err != nil {
198		fmt.Fprintf(os.Stderr, "go-autorest: failed to parse log level: %s\n", err.Error())
199		return
200	}
201	if logLevel == LogNone {
202		return
203	}
204	// default to stderr
205	dest := os.Stderr
206	lfStr := os.Getenv("AZURE_GO_SDK_LOG_FILE")
207	if strings.EqualFold(lfStr, "stdout") {
208		dest = os.Stdout
209	} else if lfStr != "" {
210		lf, err := os.Create(lfStr)
211		if err == nil {
212			dest = lf
213		} else {
214			fmt.Fprintf(os.Stderr, "go-autorest: failed to create log file, using stderr: %s\n", err.Error())
215		}
216	}
217	Instance = fileLogger{
218		logLevel: logLevel,
219		mu:       &sync.Mutex{},
220		logFile:  dest,
221	}
222}
223
224// the nil logger does nothing
225type nilLogger struct{}
226
227func (nilLogger) Writeln(LevelType, string) {}
228
229func (nilLogger) Writef(LevelType, string, ...interface{}) {}
230
231func (nilLogger) WriteRequest(*http.Request, Filter) {}
232
233func (nilLogger) WriteResponse(*http.Response, Filter) {}
234
235// A File is used instead of a Logger so the stream can be flushed after every write.
236type fileLogger struct {
237	logLevel LevelType
238	mu       *sync.Mutex // for synchronizing writes to logFile
239	logFile  *os.File
240}
241
242func (fl fileLogger) Writeln(level LevelType, message string) {
243	fl.Writef(level, "%s\n", message)
244}
245
246func (fl fileLogger) Writef(level LevelType, format string, a ...interface{}) {
247	if fl.logLevel >= level {
248		fl.mu.Lock()
249		defer fl.mu.Unlock()
250		fmt.Fprintf(fl.logFile, "%s %s", entryHeader(level), fmt.Sprintf(format, a...))
251		fl.logFile.Sync()
252	}
253}
254
255func (fl fileLogger) WriteRequest(req *http.Request, filter Filter) {
256	if req == nil || fl.logLevel < LogInfo {
257		return
258	}
259	b := &bytes.Buffer{}
260	fmt.Fprintf(b, "%s REQUEST: %s %s\n", entryHeader(LogInfo), req.Method, filter.processURL(req.URL))
261	// dump headers
262	for k, v := range req.Header {
263		if ok, mv := filter.processHeader(k, v); ok {
264			fmt.Fprintf(b, "%s: %s\n", k, strings.Join(mv, ","))
265		}
266	}
267	if fl.shouldLogBody(req.Header, req.Body) {
268		// dump body
269		body, err := ioutil.ReadAll(req.Body)
270		if err == nil {
271			fmt.Fprintln(b, string(filter.processBody(body)))
272			if nc, ok := req.Body.(io.Seeker); ok {
273				// rewind to the beginning
274				nc.Seek(0, io.SeekStart)
275			} else {
276				// recreate the body
277				req.Body = ioutil.NopCloser(bytes.NewReader(body))
278			}
279		} else {
280			fmt.Fprintf(b, "failed to read body: %v\n", err)
281		}
282	}
283	fl.mu.Lock()
284	defer fl.mu.Unlock()
285	fmt.Fprint(fl.logFile, b.String())
286	fl.logFile.Sync()
287}
288
289func (fl fileLogger) WriteResponse(resp *http.Response, filter Filter) {
290	if resp == nil || fl.logLevel < LogInfo {
291		return
292	}
293	b := &bytes.Buffer{}
294	fmt.Fprintf(b, "%s RESPONSE: %d %s\n", entryHeader(LogInfo), resp.StatusCode, filter.processURL(resp.Request.URL))
295	// dump headers
296	for k, v := range resp.Header {
297		if ok, mv := filter.processHeader(k, v); ok {
298			fmt.Fprintf(b, "%s: %s\n", k, strings.Join(mv, ","))
299		}
300	}
301	if fl.shouldLogBody(resp.Header, resp.Body) {
302		// dump body
303		defer resp.Body.Close()
304		body, err := ioutil.ReadAll(resp.Body)
305		if err == nil {
306			fmt.Fprintln(b, string(filter.processBody(body)))
307			resp.Body = ioutil.NopCloser(bytes.NewReader(body))
308		} else {
309			fmt.Fprintf(b, "failed to read body: %v\n", err)
310		}
311	}
312	fl.mu.Lock()
313	defer fl.mu.Unlock()
314	fmt.Fprint(fl.logFile, b.String())
315	fl.logFile.Sync()
316}
317
318// returns true if the provided body should be included in the log
319func (fl fileLogger) shouldLogBody(header http.Header, body io.ReadCloser) bool {
320	ct := header.Get("Content-Type")
321	return fl.logLevel >= LogDebug && body != nil && !strings.Contains(ct, "application/octet-stream")
322}
323
324// creates standard header for log entries, it contains a timestamp and the log level
325func entryHeader(level LevelType) string {
326	// this format provides a fixed number of digits so the size of the timestamp is constant
327	return fmt.Sprintf("(%s) %s:", time.Now().Format("2006-01-02T15:04:05.0000000Z07:00"), level.String())
328}
329