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