intlogger.go 11 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511
  1. package hclog
  2. import (
  3. "bytes"
  4. "encoding"
  5. "encoding/json"
  6. "fmt"
  7. "io"
  8. "log"
  9. "reflect"
  10. "runtime"
  11. "sort"
  12. "strconv"
  13. "strings"
  14. "sync"
  15. "sync/atomic"
  16. "time"
  17. )
  18. // TimeFormat to use for logging. This is a version of RFC3339 that contains
  19. // contains millisecond precision
  20. const TimeFormat = "2006-01-02T15:04:05.000Z0700"
  21. var (
  22. _levelToBracket = map[Level]string{
  23. Debug: "[DEBUG]",
  24. Trace: "[TRACE]",
  25. Info: "[INFO] ",
  26. Warn: "[WARN] ",
  27. Error: "[ERROR]",
  28. }
  29. )
  30. // Make sure that intLogger is a Logger
  31. var _ Logger = &intLogger{}
  32. // intLogger is an internal logger implementation. Internal in that it is
  33. // defined entirely by this package.
  34. type intLogger struct {
  35. json bool
  36. caller bool
  37. name string
  38. timeFormat string
  39. // This is a pointer so that it's shared by any derived loggers, since
  40. // those derived loggers share the bufio.Writer as well.
  41. mutex *sync.Mutex
  42. writer *writer
  43. level *int32
  44. implied []interface{}
  45. }
  46. // New returns a configured logger.
  47. func New(opts *LoggerOptions) Logger {
  48. if opts == nil {
  49. opts = &LoggerOptions{}
  50. }
  51. output := opts.Output
  52. if output == nil {
  53. output = DefaultOutput
  54. }
  55. level := opts.Level
  56. if level == NoLevel {
  57. level = DefaultLevel
  58. }
  59. mutex := opts.Mutex
  60. if mutex == nil {
  61. mutex = new(sync.Mutex)
  62. }
  63. l := &intLogger{
  64. json: opts.JSONFormat,
  65. caller: opts.IncludeLocation,
  66. name: opts.Name,
  67. timeFormat: TimeFormat,
  68. mutex: mutex,
  69. writer: newWriter(output),
  70. level: new(int32),
  71. }
  72. if opts.TimeFormat != "" {
  73. l.timeFormat = opts.TimeFormat
  74. }
  75. atomic.StoreInt32(l.level, int32(level))
  76. return l
  77. }
  78. // Log a message and a set of key/value pairs if the given level is at
  79. // or more severe that the threshold configured in the Logger.
  80. func (l *intLogger) Log(level Level, msg string, args ...interface{}) {
  81. if level < Level(atomic.LoadInt32(l.level)) {
  82. return
  83. }
  84. t := time.Now()
  85. l.mutex.Lock()
  86. defer l.mutex.Unlock()
  87. if l.json {
  88. l.logJSON(t, level, msg, args...)
  89. } else {
  90. l.log(t, level, msg, args...)
  91. }
  92. l.writer.Flush(level)
  93. }
  94. // Cleanup a path by returning the last 2 segments of the path only.
  95. func trimCallerPath(path string) string {
  96. // lovely borrowed from zap
  97. // nb. To make sure we trim the path correctly on Windows too, we
  98. // counter-intuitively need to use '/' and *not* os.PathSeparator here,
  99. // because the path given originates from Go stdlib, specifically
  100. // runtime.Caller() which (as of Mar/17) returns forward slashes even on
  101. // Windows.
  102. //
  103. // See https://github.com/golang/go/issues/3335
  104. // and https://github.com/golang/go/issues/18151
  105. //
  106. // for discussion on the issue on Go side.
  107. // Find the last separator.
  108. idx := strings.LastIndexByte(path, '/')
  109. if idx == -1 {
  110. return path
  111. }
  112. // Find the penultimate separator.
  113. idx = strings.LastIndexByte(path[:idx], '/')
  114. if idx == -1 {
  115. return path
  116. }
  117. return path[idx+1:]
  118. }
  119. // Non-JSON logging format function
  120. func (l *intLogger) log(t time.Time, level Level, msg string, args ...interface{}) {
  121. l.writer.WriteString(t.Format(l.timeFormat))
  122. l.writer.WriteByte(' ')
  123. s, ok := _levelToBracket[level]
  124. if ok {
  125. l.writer.WriteString(s)
  126. } else {
  127. l.writer.WriteString("[?????]")
  128. }
  129. if l.caller {
  130. if _, file, line, ok := runtime.Caller(3); ok {
  131. l.writer.WriteByte(' ')
  132. l.writer.WriteString(trimCallerPath(file))
  133. l.writer.WriteByte(':')
  134. l.writer.WriteString(strconv.Itoa(line))
  135. l.writer.WriteByte(':')
  136. }
  137. }
  138. l.writer.WriteByte(' ')
  139. if l.name != "" {
  140. l.writer.WriteString(l.name)
  141. l.writer.WriteString(": ")
  142. }
  143. l.writer.WriteString(msg)
  144. args = append(l.implied, args...)
  145. var stacktrace CapturedStacktrace
  146. if args != nil && len(args) > 0 {
  147. if len(args)%2 != 0 {
  148. cs, ok := args[len(args)-1].(CapturedStacktrace)
  149. if ok {
  150. args = args[:len(args)-1]
  151. stacktrace = cs
  152. } else {
  153. args = append(args, "<unknown>")
  154. }
  155. }
  156. l.writer.WriteByte(':')
  157. FOR:
  158. for i := 0; i < len(args); i = i + 2 {
  159. var (
  160. val string
  161. raw bool
  162. )
  163. switch st := args[i+1].(type) {
  164. case string:
  165. val = st
  166. case int:
  167. val = strconv.FormatInt(int64(st), 10)
  168. case int64:
  169. val = strconv.FormatInt(int64(st), 10)
  170. case int32:
  171. val = strconv.FormatInt(int64(st), 10)
  172. case int16:
  173. val = strconv.FormatInt(int64(st), 10)
  174. case int8:
  175. val = strconv.FormatInt(int64(st), 10)
  176. case uint:
  177. val = strconv.FormatUint(uint64(st), 10)
  178. case uint64:
  179. val = strconv.FormatUint(uint64(st), 10)
  180. case uint32:
  181. val = strconv.FormatUint(uint64(st), 10)
  182. case uint16:
  183. val = strconv.FormatUint(uint64(st), 10)
  184. case uint8:
  185. val = strconv.FormatUint(uint64(st), 10)
  186. case CapturedStacktrace:
  187. stacktrace = st
  188. continue FOR
  189. case Format:
  190. val = fmt.Sprintf(st[0].(string), st[1:]...)
  191. default:
  192. v := reflect.ValueOf(st)
  193. if v.Kind() == reflect.Slice {
  194. val = l.renderSlice(v)
  195. raw = true
  196. } else {
  197. val = fmt.Sprintf("%v", st)
  198. }
  199. }
  200. l.writer.WriteByte(' ')
  201. l.writer.WriteString(args[i].(string))
  202. l.writer.WriteByte('=')
  203. if !raw && strings.ContainsAny(val, " \t\n\r") {
  204. l.writer.WriteByte('"')
  205. l.writer.WriteString(val)
  206. l.writer.WriteByte('"')
  207. } else {
  208. l.writer.WriteString(val)
  209. }
  210. }
  211. }
  212. l.writer.WriteString("\n")
  213. if stacktrace != "" {
  214. l.writer.WriteString(string(stacktrace))
  215. }
  216. }
  217. func (l *intLogger) renderSlice(v reflect.Value) string {
  218. var buf bytes.Buffer
  219. buf.WriteRune('[')
  220. for i := 0; i < v.Len(); i++ {
  221. if i > 0 {
  222. buf.WriteString(", ")
  223. }
  224. sv := v.Index(i)
  225. var val string
  226. switch sv.Kind() {
  227. case reflect.String:
  228. val = sv.String()
  229. case reflect.Int, reflect.Int16, reflect.Int32, reflect.Int64:
  230. val = strconv.FormatInt(sv.Int(), 10)
  231. case reflect.Uint, reflect.Uint16, reflect.Uint32, reflect.Uint64:
  232. val = strconv.FormatUint(sv.Uint(), 10)
  233. default:
  234. val = fmt.Sprintf("%v", sv.Interface())
  235. }
  236. if strings.ContainsAny(val, " \t\n\r") {
  237. buf.WriteByte('"')
  238. buf.WriteString(val)
  239. buf.WriteByte('"')
  240. } else {
  241. buf.WriteString(val)
  242. }
  243. }
  244. buf.WriteRune(']')
  245. return buf.String()
  246. }
  247. // JSON logging function
  248. func (l *intLogger) logJSON(t time.Time, level Level, msg string, args ...interface{}) {
  249. vals := map[string]interface{}{
  250. "@message": msg,
  251. "@timestamp": t.Format("2006-01-02T15:04:05.000000Z07:00"),
  252. }
  253. var levelStr string
  254. switch level {
  255. case Error:
  256. levelStr = "error"
  257. case Warn:
  258. levelStr = "warn"
  259. case Info:
  260. levelStr = "info"
  261. case Debug:
  262. levelStr = "debug"
  263. case Trace:
  264. levelStr = "trace"
  265. default:
  266. levelStr = "all"
  267. }
  268. vals["@level"] = levelStr
  269. if l.name != "" {
  270. vals["@module"] = l.name
  271. }
  272. if l.caller {
  273. if _, file, line, ok := runtime.Caller(3); ok {
  274. vals["@caller"] = fmt.Sprintf("%s:%d", file, line)
  275. }
  276. }
  277. args = append(l.implied, args...)
  278. if args != nil && len(args) > 0 {
  279. if len(args)%2 != 0 {
  280. cs, ok := args[len(args)-1].(CapturedStacktrace)
  281. if ok {
  282. args = args[:len(args)-1]
  283. vals["stacktrace"] = cs
  284. } else {
  285. args = append(args, "<unknown>")
  286. }
  287. }
  288. for i := 0; i < len(args); i = i + 2 {
  289. if _, ok := args[i].(string); !ok {
  290. // As this is the logging function not much we can do here
  291. // without injecting into logs...
  292. continue
  293. }
  294. val := args[i+1]
  295. switch sv := val.(type) {
  296. case error:
  297. // Check if val is of type error. If error type doesn't
  298. // implement json.Marshaler or encoding.TextMarshaler
  299. // then set val to err.Error() so that it gets marshaled
  300. switch sv.(type) {
  301. case json.Marshaler, encoding.TextMarshaler:
  302. default:
  303. val = sv.Error()
  304. }
  305. case Format:
  306. val = fmt.Sprintf(sv[0].(string), sv[1:]...)
  307. }
  308. vals[args[i].(string)] = val
  309. }
  310. }
  311. err := json.NewEncoder(l.writer).Encode(vals)
  312. if err != nil {
  313. panic(err)
  314. }
  315. }
  316. // Emit the message and args at DEBUG level
  317. func (l *intLogger) Debug(msg string, args ...interface{}) {
  318. l.Log(Debug, msg, args...)
  319. }
  320. // Emit the message and args at TRACE level
  321. func (l *intLogger) Trace(msg string, args ...interface{}) {
  322. l.Log(Trace, msg, args...)
  323. }
  324. // Emit the message and args at INFO level
  325. func (l *intLogger) Info(msg string, args ...interface{}) {
  326. l.Log(Info, msg, args...)
  327. }
  328. // Emit the message and args at WARN level
  329. func (l *intLogger) Warn(msg string, args ...interface{}) {
  330. l.Log(Warn, msg, args...)
  331. }
  332. // Emit the message and args at ERROR level
  333. func (l *intLogger) Error(msg string, args ...interface{}) {
  334. l.Log(Error, msg, args...)
  335. }
  336. // Indicate that the logger would emit TRACE level logs
  337. func (l *intLogger) IsTrace() bool {
  338. return Level(atomic.LoadInt32(l.level)) == Trace
  339. }
  340. // Indicate that the logger would emit DEBUG level logs
  341. func (l *intLogger) IsDebug() bool {
  342. return Level(atomic.LoadInt32(l.level)) <= Debug
  343. }
  344. // Indicate that the logger would emit INFO level logs
  345. func (l *intLogger) IsInfo() bool {
  346. return Level(atomic.LoadInt32(l.level)) <= Info
  347. }
  348. // Indicate that the logger would emit WARN level logs
  349. func (l *intLogger) IsWarn() bool {
  350. return Level(atomic.LoadInt32(l.level)) <= Warn
  351. }
  352. // Indicate that the logger would emit ERROR level logs
  353. func (l *intLogger) IsError() bool {
  354. return Level(atomic.LoadInt32(l.level)) <= Error
  355. }
  356. // Return a sub-Logger for which every emitted log message will contain
  357. // the given key/value pairs. This is used to create a context specific
  358. // Logger.
  359. func (l *intLogger) With(args ...interface{}) Logger {
  360. if len(args)%2 != 0 {
  361. panic("With() call requires paired arguments")
  362. }
  363. sl := *l
  364. result := make(map[string]interface{}, len(l.implied)+len(args))
  365. keys := make([]string, 0, len(l.implied)+len(args))
  366. // Read existing args, store map and key for consistent sorting
  367. for i := 0; i < len(l.implied); i += 2 {
  368. key := l.implied[i].(string)
  369. keys = append(keys, key)
  370. result[key] = l.implied[i+1]
  371. }
  372. // Read new args, store map and key for consistent sorting
  373. for i := 0; i < len(args); i += 2 {
  374. key := args[i].(string)
  375. _, exists := result[key]
  376. if !exists {
  377. keys = append(keys, key)
  378. }
  379. result[key] = args[i+1]
  380. }
  381. // Sort keys to be consistent
  382. sort.Strings(keys)
  383. sl.implied = make([]interface{}, 0, len(l.implied)+len(args))
  384. for _, k := range keys {
  385. sl.implied = append(sl.implied, k)
  386. sl.implied = append(sl.implied, result[k])
  387. }
  388. return &sl
  389. }
  390. // Create a new sub-Logger that a name decending from the current name.
  391. // This is used to create a subsystem specific Logger.
  392. func (l *intLogger) Named(name string) Logger {
  393. sl := *l
  394. if sl.name != "" {
  395. sl.name = sl.name + "." + name
  396. } else {
  397. sl.name = name
  398. }
  399. return &sl
  400. }
  401. // Create a new sub-Logger with an explicit name. This ignores the current
  402. // name. This is used to create a standalone logger that doesn't fall
  403. // within the normal hierarchy.
  404. func (l *intLogger) ResetNamed(name string) Logger {
  405. sl := *l
  406. sl.name = name
  407. return &sl
  408. }
  409. // Update the logging level on-the-fly. This will affect all subloggers as
  410. // well.
  411. func (l *intLogger) SetLevel(level Level) {
  412. atomic.StoreInt32(l.level, int32(level))
  413. }
  414. // Create a *log.Logger that will send it's data through this Logger. This
  415. // allows packages that expect to be using the standard library log to actually
  416. // use this logger.
  417. func (l *intLogger) StandardLogger(opts *StandardLoggerOptions) *log.Logger {
  418. if opts == nil {
  419. opts = &StandardLoggerOptions{}
  420. }
  421. return log.New(l.StandardWriter(opts), "", 0)
  422. }
  423. func (l *intLogger) StandardWriter(opts *StandardLoggerOptions) io.Writer {
  424. return &stdlogAdapter{l, opts.InferLevels}
  425. }