1 package 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 17 import (
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.
35 type LevelType uint32
36 37 const (
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 // LogAuth is a special case of LogDebug, it tells a logger to also log the body of an authentication request and response.
60 // NOTE: this can disclose sensitive information, use with care.
61 LogAuth
62 )
63 64 const (
65 logNone = "NONE"
66 logFatal = "FATAL"
67 logPanic = "PANIC"
68 logError = "ERROR"
69 logWarning = "WARNING"
70 logInfo = "INFO"
71 logDebug = "DEBUG"
72 logAuth = "AUTH"
73 logUnknown = "UNKNOWN"
74 )
75 76 // ParseLevel converts the specified string into the corresponding LevelType.
77 func ParseLevel(s string) (lt LevelType, err error) {
78 switch strings.ToUpper(s) {
79 case logFatal:
80 lt = LogFatal
81 case logPanic:
82 lt = LogPanic
83 case logError:
84 lt = LogError
85 case logWarning:
86 lt = LogWarning
87 case logInfo:
88 lt = LogInfo
89 case logDebug:
90 lt = LogDebug
91 case logAuth:
92 lt = LogAuth
93 default:
94 err = fmt.Errorf("bad log level '%s'", s)
95 }
96 return
97 }
98 99 // String implements the stringer interface for LevelType.
100 func (lt LevelType) String() string {
101 switch lt {
102 case LogNone:
103 return logNone
104 case LogFatal:
105 return logFatal
106 case LogPanic:
107 return logPanic
108 case LogError:
109 return logError
110 case LogWarning:
111 return logWarning
112 case LogInfo:
113 return logInfo
114 case LogDebug:
115 return logDebug
116 case LogAuth:
117 return logAuth
118 default:
119 return logUnknown
120 }
121 }
122 123 // Filter defines functions for filtering HTTP request/response content.
124 type Filter struct {
125 // URL returns a potentially modified string representation of a request URL.
126 URL func(u *url.URL) string
127 128 // Header returns a potentially modified set of values for the specified key.
129 // To completely exclude the header key/values return false.
130 Header func(key string, val []string) (bool, []string)
131 132 // Body returns a potentially modified request/response body.
133 Body func(b []byte) []byte
134 }
135 136 func (f Filter) processURL(u *url.URL) string {
137 if f.URL == nil {
138 return u.String()
139 }
140 return f.URL(u)
141 }
142 143 func (f Filter) processHeader(k string, val []string) (bool, []string) {
144 if f.Header == nil {
145 return true, val
146 }
147 return f.Header(k, val)
148 }
149 150 func (f Filter) processBody(b []byte) []byte {
151 if f.Body == nil {
152 return b
153 }
154 return f.Body(b)
155 }
156 157 // Writer defines methods for writing to a logging facility.
158 type Writer interface {
159 // Writeln writes the specified message with the standard log entry header and new-line character.
160 Writeln(level LevelType, message string)
161 162 // Writef writes the specified format specifier with the standard log entry header and no new-line character.
163 Writef(level LevelType, format string, a ...interface{})
164 165 // WriteRequest writes the specified HTTP request to the logger if the log level is greater than
166 // or equal to LogInfo. The request body, if set, is logged at level LogDebug or higher.
167 // Custom filters can be specified to exclude URL, header, and/or body content from the log.
168 // By default no request content is excluded.
169 WriteRequest(req *http.Request, filter Filter)
170 171 // WriteResponse writes the specified HTTP response to the logger if the log level is greater than
172 // or equal to LogInfo. The response body, if set, is logged at level LogDebug or higher.
173 // Custom filters can be specified to exclude URL, header, and/or body content from the log.
174 // By default no response content is excluded.
175 WriteResponse(resp *http.Response, filter Filter)
176 }
177 178 // Instance is the default log writer initialized during package init.
179 // This can be replaced with a custom implementation as required.
180 var Instance Writer
181 182 // default log level
183 var logLevel = LogNone
184 185 // Level returns the value specified in AZURE_GO_AUTOREST_LOG_LEVEL.
186 // If no value was specified the default value is LogNone.
187 // Custom loggers can call this to retrieve the configured log level.
188 func Level() LevelType {
189 return logLevel
190 }
191 192 func init() {
193 // separated for testing purposes
194 initDefaultLogger()
195 }
196 197 func initDefaultLogger() {
198 // init with nilLogger so callers don't have to do a nil check on Default
199 Instance = nilLogger{}
200 llStr := strings.ToLower(os.Getenv("AZURE_GO_SDK_LOG_LEVEL"))
201 if llStr == "" {
202 return
203 }
204 var err error
205 logLevel, err = ParseLevel(llStr)
206 if err != nil {
207 fmt.Fprintf(os.Stderr, "go-autorest: failed to parse log level: %s\n", err.Error())
208 return
209 }
210 if logLevel == LogNone {
211 return
212 }
213 // default to stderr
214 dest := os.Stderr
215 lfStr := os.Getenv("AZURE_GO_SDK_LOG_FILE")
216 if strings.EqualFold(lfStr, "stdout") {
217 dest = os.Stdout
218 } else if lfStr != "" {
219 lf, err := os.Create(lfStr)
220 if err == nil {
221 dest = lf
222 } else {
223 fmt.Fprintf(os.Stderr, "go-autorest: failed to create log file, using stderr: %s\n", err.Error())
224 }
225 }
226 Instance = fileLogger{
227 logLevel: logLevel,
228 mu: &sync.Mutex{},
229 logFile: dest,
230 }
231 }
232 233 // the nil logger does nothing
234 type nilLogger struct{}
235 236 func (nilLogger) Writeln(LevelType, string) {}
237 238 func (nilLogger) Writef(LevelType, string, ...interface{}) {}
239 240 func (nilLogger) WriteRequest(*http.Request, Filter) {}
241 242 func (nilLogger) WriteResponse(*http.Response, Filter) {}
243 244 // A File is used instead of a Logger so the stream can be flushed after every write.
245 type fileLogger struct {
246 logLevel LevelType
247 mu *sync.Mutex // for synchronizing writes to logFile
248 logFile *os.File
249 }
250 251 func (fl fileLogger) Writeln(level LevelType, message string) {
252 fl.Writef(level, "%s\n", message)
253 }
254 255 func (fl fileLogger) Writef(level LevelType, format string, a ...interface{}) {
256 if fl.logLevel >= level {
257 fl.mu.Lock()
258 defer fl.mu.Unlock()
259 fmt.Fprintf(fl.logFile, "%s %s", entryHeader(level), fmt.Sprintf(format, a...))
260 fl.logFile.Sync()
261 }
262 }
263 264 func (fl fileLogger) WriteRequest(req *http.Request, filter Filter) {
265 if req == nil || fl.logLevel < LogInfo {
266 return
267 }
268 b := &bytes.Buffer{}
269 fmt.Fprintf(b, "%s REQUEST: %s %s\n", entryHeader(LogInfo), req.Method, filter.processURL(req.URL))
270 // dump headers
271 for k, v := range req.Header {
272 if ok, mv := filter.processHeader(k, v); ok {
273 fmt.Fprintf(b, "%s: %s\n", k, strings.Join(mv, ","))
274 }
275 }
276 if fl.shouldLogBody(req.Header, req.Body) {
277 // dump body
278 body, err := ioutil.ReadAll(req.Body)
279 if err == nil {
280 fmt.Fprintln(b, string(filter.processBody(body)))
281 if nc, ok := req.Body.(io.Seeker); ok {
282 // rewind to the beginning
283 nc.Seek(0, io.SeekStart)
284 } else {
285 // recreate the body
286 req.Body = ioutil.NopCloser(bytes.NewReader(body))
287 }
288 } else {
289 fmt.Fprintf(b, "failed to read body: %v\n", err)
290 }
291 }
292 fl.mu.Lock()
293 defer fl.mu.Unlock()
294 fmt.Fprint(fl.logFile, b.String())
295 fl.logFile.Sync()
296 }
297 298 func (fl fileLogger) WriteResponse(resp *http.Response, filter Filter) {
299 if resp == nil || fl.logLevel < LogInfo {
300 return
301 }
302 b := &bytes.Buffer{}
303 fmt.Fprintf(b, "%s RESPONSE: %d %s\n", entryHeader(LogInfo), resp.StatusCode, filter.processURL(resp.Request.URL))
304 // dump headers
305 for k, v := range resp.Header {
306 if ok, mv := filter.processHeader(k, v); ok {
307 fmt.Fprintf(b, "%s: %s\n", k, strings.Join(mv, ","))
308 }
309 }
310 if fl.shouldLogBody(resp.Header, resp.Body) {
311 // dump body
312 defer resp.Body.Close()
313 body, err := ioutil.ReadAll(resp.Body)
314 if err == nil {
315 fmt.Fprintln(b, string(filter.processBody(body)))
316 resp.Body = ioutil.NopCloser(bytes.NewReader(body))
317 } else {
318 fmt.Fprintf(b, "failed to read body: %v\n", err)
319 }
320 }
321 fl.mu.Lock()
322 defer fl.mu.Unlock()
323 fmt.Fprint(fl.logFile, b.String())
324 fl.logFile.Sync()
325 }
326 327 // returns true if the provided body should be included in the log
328 func (fl fileLogger) shouldLogBody(header http.Header, body io.ReadCloser) bool {
329 ct := header.Get("Content-Type")
330 return fl.logLevel >= LogDebug && body != nil && !strings.Contains(ct, "application/octet-stream")
331 }
332 333 // creates standard header for log entries, it contains a timestamp and the log level
334 func entryHeader(level LevelType) string {
335 // this format provides a fixed number of digits so the size of the timestamp is constant
336 return fmt.Sprintf("(%s) %s:", time.Now().Format("2006-01-02T15:04:05.0000000Z07:00"), level.String())
337 }
338