logger.go 9.3 KB

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