logger.go 9.6 KB

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