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 // 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 64const ( 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. 77func 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. 100func (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. 124type 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 136func (f Filter) processURL(u *url.URL) string { 137 if f.URL == nil { 138 return u.String() 139 } 140 return f.URL(u) 141} 142 143func (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 150func (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. 158type 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. 180var Instance Writer 181 182// default log level 183var 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. 188func Level() LevelType { 189 return logLevel 190} 191 192func init() { 193 // separated for testing purposes 194 initDefaultLogger() 195} 196 197func 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 234type nilLogger struct{} 235 236func (nilLogger) Writeln(LevelType, string) {} 237 238func (nilLogger) Writef(LevelType, string, ...interface{}) {} 239 240func (nilLogger) WriteRequest(*http.Request, Filter) {} 241 242func (nilLogger) WriteResponse(*http.Response, Filter) {} 243 244// A File is used instead of a Logger so the stream can be flushed after every write. 245type fileLogger struct { 246 logLevel LevelType 247 mu *sync.Mutex // for synchronizing writes to logFile 248 logFile *os.File 249} 250 251func (fl fileLogger) Writeln(level LevelType, message string) { 252 fl.Writef(level, "%s\n", message) 253} 254 255func (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 264func (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 298func (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 328func (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 334func 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