glog.go 19 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592
  1. // Go support for leveled logs, analogous to https://github.com/google/glog.
  2. //
  3. // Copyright 2023 Google Inc. All Rights Reserved.
  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. // Package glog implements logging analogous to the Google-internal C++ INFO/ERROR/V setup.
  17. // It provides functions Info, Warning, Error, Fatal, plus formatting variants such as
  18. // Infof. It also provides V-style logging controlled by the -v and -vmodule=file=2 flags.
  19. //
  20. // Basic examples:
  21. //
  22. // glog.Info("Prepare to repel boarders")
  23. //
  24. // glog.Fatalf("Initialization failed: %s", err)
  25. //
  26. // See the documentation for the V function for an explanation of these examples:
  27. //
  28. // if glog.V(2) {
  29. // glog.Info("Starting transaction...")
  30. // }
  31. //
  32. // glog.V(2).Infoln("Processed", nItems, "elements")
  33. //
  34. // Log output is buffered and written periodically using Flush. Programs
  35. // should call Flush before exiting to guarantee all log output is written.
  36. //
  37. // By default, all log statements write to files in a temporary directory.
  38. // This package provides several flags that modify this behavior.
  39. // As a result, flag.Parse must be called before any logging is done.
  40. //
  41. // -logtostderr=false
  42. // Logs are written to standard error instead of to files.
  43. // -alsologtostderr=false
  44. // Logs are written to standard error as well as to files.
  45. // -stderrthreshold=ERROR
  46. // Log events at or above this severity are logged to standard
  47. // error as well as to files.
  48. // -log_dir=""
  49. // Log files will be written to this directory instead of the
  50. // default temporary directory.
  51. //
  52. // Other flags provide aids to debugging.
  53. //
  54. // -log_backtrace_at=""
  55. // A comma-separated list of file and line numbers holding a logging
  56. // statement, such as
  57. // -log_backtrace_at=gopherflakes.go:234
  58. // A stack trace will be written to the Info log whenever execution
  59. // hits one of these statements. (Unlike with -vmodule, the ".go"
  60. // must bepresent.)
  61. // -v=0
  62. // Enable V-leveled logging at the specified level.
  63. // -vmodule=""
  64. // The syntax of the argument is a comma-separated list of pattern=N,
  65. // where pattern is a literal file name (minus the ".go" suffix) or
  66. // "glob" pattern and N is a V level. For instance,
  67. // -vmodule=gopher*=3
  68. // sets the V level to 3 in all Go files whose names begin with "gopher",
  69. // and
  70. // -vmodule=/path/to/glog/glog_test=1
  71. // sets the V level to 1 in the Go file /path/to/glog/glog_test.go.
  72. // If a glob pattern contains a slash, it is matched against the full path,
  73. // and the file name. Otherwise, the pattern is
  74. // matched only against the file's basename. When both -vmodule and -v
  75. // are specified, the -vmodule values take precedence for the specified
  76. // modules.
  77. package glog
  78. // This file contains the parts of the log package that are shared among all
  79. // implementations (file, envelope, and appengine).
  80. import (
  81. "bytes"
  82. "errors"
  83. "fmt"
  84. stdLog "log"
  85. "os"
  86. "reflect"
  87. "runtime"
  88. "runtime/pprof"
  89. "strconv"
  90. "sync"
  91. "sync/atomic"
  92. "time"
  93. "github.com/golang/glog/internal/logsink"
  94. "github.com/golang/glog/internal/stackdump"
  95. )
  96. var timeNow = time.Now // Stubbed out for testing.
  97. // MaxSize is the maximum size of a log file in bytes.
  98. var MaxSize uint64 = 1024 * 1024 * 1800
  99. // ErrNoLog is the error we return if no log file has yet been created
  100. // for the specified log type.
  101. var ErrNoLog = errors.New("log file not yet created")
  102. // OutputStats tracks the number of output lines and bytes written.
  103. type OutputStats struct {
  104. lines int64
  105. bytes int64
  106. }
  107. // Lines returns the number of lines written.
  108. func (s *OutputStats) Lines() int64 {
  109. return atomic.LoadInt64(&s.lines)
  110. }
  111. // Bytes returns the number of bytes written.
  112. func (s *OutputStats) Bytes() int64 {
  113. return atomic.LoadInt64(&s.bytes)
  114. }
  115. // Stats tracks the number of lines of output and number of bytes
  116. // per severity level. Values must be read with atomic.LoadInt64.
  117. var Stats struct {
  118. Info, Warning, Error OutputStats
  119. }
  120. var severityStats = [...]*OutputStats{
  121. logsink.Info: &Stats.Info,
  122. logsink.Warning: &Stats.Warning,
  123. logsink.Error: &Stats.Error,
  124. logsink.Fatal: nil,
  125. }
  126. // Level specifies a level of verbosity for V logs. The -v flag is of type
  127. // Level and should be modified only through the flag.Value interface.
  128. type Level int32
  129. var metaPool sync.Pool // Pool of *logsink.Meta.
  130. // metaPoolGet returns a *logsink.Meta from metaPool as both an interface and a
  131. // pointer, allocating a new one if necessary. (Returning the interface value
  132. // directly avoids an allocation if there was an existing pointer in the pool.)
  133. func metaPoolGet() (any, *logsink.Meta) {
  134. if metai := metaPool.Get(); metai != nil {
  135. return metai, metai.(*logsink.Meta)
  136. }
  137. meta := new(logsink.Meta)
  138. return meta, meta
  139. }
  140. type stack bool
  141. const (
  142. noStack = stack(false)
  143. withStack = stack(true)
  144. )
  145. func appendBacktrace(depth int, format string, args []any) (string, []any) {
  146. // Capture a backtrace as a stackdump.Stack (both text and PC slice).
  147. // Structured log sinks can extract the backtrace in whichever format they
  148. // prefer (PCs or text), and Text sinks will include it as just another part
  149. // of the log message.
  150. //
  151. // Use depth instead of depth+1 so that the backtrace always includes the
  152. // log function itself - otherwise the reason for the trace appearing in the
  153. // log may not be obvious to the reader.
  154. dump := stackdump.Caller(depth)
  155. // Add an arg and an entry in the format string for the stack dump.
  156. //
  157. // Copy the "args" slice to avoid a rare but serious aliasing bug
  158. // (corrupting the caller's slice if they passed it to a non-Fatal call
  159. // using "...").
  160. format = format + "\n\n%v\n"
  161. args = append(append([]any(nil), args...), dump)
  162. return format, args
  163. }
  164. // logf writes a log message for a log function call (or log function wrapper)
  165. // at the given depth in the current goroutine's stack.
  166. func logf(depth int, severity logsink.Severity, verbose bool, stack stack, format string, args ...any) {
  167. now := timeNow()
  168. _, file, line, ok := runtime.Caller(depth + 1)
  169. if !ok {
  170. file = "???"
  171. line = 1
  172. }
  173. if stack == withStack || backtraceAt(file, line) {
  174. format, args = appendBacktrace(depth+1, format, args)
  175. }
  176. metai, meta := metaPoolGet()
  177. *meta = logsink.Meta{
  178. Time: now,
  179. File: file,
  180. Line: line,
  181. Depth: depth + 1,
  182. Severity: severity,
  183. Verbose: verbose,
  184. Thread: int64(pid),
  185. }
  186. sinkf(meta, format, args...)
  187. metaPool.Put(metai)
  188. }
  189. func sinkf(meta *logsink.Meta, format string, args ...any) {
  190. meta.Depth++
  191. n, err := logsink.Printf(meta, format, args...)
  192. if stats := severityStats[meta.Severity]; stats != nil {
  193. atomic.AddInt64(&stats.lines, 1)
  194. atomic.AddInt64(&stats.bytes, int64(n))
  195. }
  196. if err != nil {
  197. logsink.Printf(meta, "glog: exiting because of error: %s", err)
  198. sinks.file.Flush()
  199. os.Exit(2)
  200. }
  201. }
  202. // CopyStandardLogTo arranges for messages written to the Go "log" package's
  203. // default logs to also appear in the Google logs for the named and lower
  204. // severities. Subsequent changes to the standard log's default output location
  205. // or format may break this behavior.
  206. //
  207. // Valid names are "INFO", "WARNING", "ERROR", and "FATAL". If the name is not
  208. // recognized, CopyStandardLogTo panics.
  209. func CopyStandardLogTo(name string) {
  210. sev, err := logsink.ParseSeverity(name)
  211. if err != nil {
  212. panic(fmt.Sprintf("log.CopyStandardLogTo(%q): %v", name, err))
  213. }
  214. // Set a log format that captures the user's file and line:
  215. // d.go:23: message
  216. stdLog.SetFlags(stdLog.Lshortfile)
  217. stdLog.SetOutput(logBridge(sev))
  218. }
  219. // NewStandardLogger returns a Logger that writes to the Google logs for the
  220. // named and lower severities.
  221. //
  222. // Valid names are "INFO", "WARNING", "ERROR", and "FATAL". If the name is not
  223. // recognized, NewStandardLogger panics.
  224. func NewStandardLogger(name string) *stdLog.Logger {
  225. sev, err := logsink.ParseSeverity(name)
  226. if err != nil {
  227. panic(fmt.Sprintf("log.NewStandardLogger(%q): %v", name, err))
  228. }
  229. return stdLog.New(logBridge(sev), "", stdLog.Lshortfile)
  230. }
  231. // logBridge provides the Write method that enables CopyStandardLogTo to connect
  232. // Go's standard logs to the logs provided by this package.
  233. type logBridge logsink.Severity
  234. // Write parses the standard logging line and passes its components to the
  235. // logger for severity(lb).
  236. func (lb logBridge) Write(b []byte) (n int, err error) {
  237. var (
  238. file = "???"
  239. line = 1
  240. text string
  241. )
  242. // Split "d.go:23: message" into "d.go", "23", and "message".
  243. if parts := bytes.SplitN(b, []byte{':'}, 3); len(parts) != 3 || len(parts[0]) < 1 || len(parts[2]) < 1 {
  244. text = fmt.Sprintf("bad log format: %s", b)
  245. } else {
  246. file = string(parts[0])
  247. text = string(parts[2][1:]) // skip leading space
  248. line, err = strconv.Atoi(string(parts[1]))
  249. if err != nil {
  250. text = fmt.Sprintf("bad line number: %s", b)
  251. line = 1
  252. }
  253. }
  254. // The depth below hard-codes details of how stdlog gets here. The alternative would be to walk
  255. // up the stack looking for src/log/log.go but that seems like it would be
  256. // unfortunately slow.
  257. const stdLogDepth = 4
  258. metai, meta := metaPoolGet()
  259. *meta = logsink.Meta{
  260. Time: timeNow(),
  261. File: file,
  262. Line: line,
  263. Depth: stdLogDepth,
  264. Severity: logsink.Severity(lb),
  265. Thread: int64(pid),
  266. }
  267. format := "%s"
  268. args := []any{text}
  269. if backtraceAt(file, line) {
  270. format, args = appendBacktrace(meta.Depth, format, args)
  271. }
  272. sinkf(meta, format, args...)
  273. metaPool.Put(metai)
  274. return len(b), nil
  275. }
  276. // defaultFormat returns a fmt.Printf format specifier that formats its
  277. // arguments as if they were passed to fmt.Print.
  278. func defaultFormat(args []any) string {
  279. n := len(args)
  280. switch n {
  281. case 0:
  282. return ""
  283. case 1:
  284. return "%v"
  285. }
  286. b := make([]byte, 0, n*3-1)
  287. wasString := true // Suppress leading space.
  288. for _, arg := range args {
  289. isString := arg != nil && reflect.TypeOf(arg).Kind() == reflect.String
  290. if wasString || isString {
  291. b = append(b, "%v"...)
  292. } else {
  293. b = append(b, " %v"...)
  294. }
  295. wasString = isString
  296. }
  297. return string(b)
  298. }
  299. // lnFormat returns a fmt.Printf format specifier that formats its arguments
  300. // as if they were passed to fmt.Println.
  301. func lnFormat(args []any) string {
  302. if len(args) == 0 {
  303. return "\n"
  304. }
  305. b := make([]byte, 0, len(args)*3)
  306. for range args {
  307. b = append(b, "%v "...)
  308. }
  309. b[len(b)-1] = '\n' // Replace the last space with a newline.
  310. return string(b)
  311. }
  312. // Verbose is a boolean type that implements Infof (like Printf) etc.
  313. // See the documentation of V for more information.
  314. type Verbose bool
  315. // V reports whether verbosity at the call site is at least the requested level.
  316. // The returned value is a boolean of type Verbose, which implements Info, Infoln
  317. // and Infof. These methods will write to the Info log if called.
  318. // Thus, one may write either
  319. //
  320. // if glog.V(2) { glog.Info("log this") }
  321. //
  322. // or
  323. //
  324. // glog.V(2).Info("log this")
  325. //
  326. // The second form is shorter but the first is cheaper if logging is off because it does
  327. // not evaluate its arguments.
  328. //
  329. // Whether an individual call to V generates a log record depends on the setting of
  330. // the -v and --vmodule flags; both are off by default. If the level in the call to
  331. // V is at most the value of -v, or of -vmodule for the source file containing the
  332. // call, the V call will log.
  333. func V(level Level) Verbose {
  334. return VDepth(1, level)
  335. }
  336. // VDepth acts as V but uses depth to determine which call frame to check vmodule for.
  337. // VDepth(0, level) is the same as V(level).
  338. func VDepth(depth int, level Level) Verbose {
  339. return Verbose(verboseEnabled(depth+1, level))
  340. }
  341. // Info is equivalent to the global Info function, guarded by the value of v.
  342. // See the documentation of V for usage.
  343. func (v Verbose) Info(args ...any) {
  344. v.InfoDepth(1, args...)
  345. }
  346. // InfoDepth is equivalent to the global InfoDepth function, guarded by the value of v.
  347. // See the documentation of V for usage.
  348. func (v Verbose) InfoDepth(depth int, args ...any) {
  349. if v {
  350. logf(depth+1, logsink.Info, true, noStack, defaultFormat(args), args...)
  351. }
  352. }
  353. // InfoDepthf is equivalent to the global InfoDepthf function, guarded by the value of v.
  354. // See the documentation of V for usage.
  355. func (v Verbose) InfoDepthf(depth int, format string, args ...any) {
  356. if v {
  357. logf(depth+1, logsink.Info, true, noStack, format, args...)
  358. }
  359. }
  360. // Infoln is equivalent to the global Infoln function, guarded by the value of v.
  361. // See the documentation of V for usage.
  362. func (v Verbose) Infoln(args ...any) {
  363. if v {
  364. logf(1, logsink.Info, true, noStack, lnFormat(args), args...)
  365. }
  366. }
  367. // Infof is equivalent to the global Infof function, guarded by the value of v.
  368. // See the documentation of V for usage.
  369. func (v Verbose) Infof(format string, args ...any) {
  370. if v {
  371. logf(1, logsink.Info, true, noStack, format, args...)
  372. }
  373. }
  374. // Info logs to the INFO log.
  375. // Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
  376. func Info(args ...any) {
  377. InfoDepth(1, args...)
  378. }
  379. // InfoDepth calls Info from a different depth in the call stack.
  380. // This enables a callee to emit logs that use the callsite information of its caller
  381. // or any other callers in the stack. When depth == 0, the original callee's line
  382. // information is emitted. When depth > 0, depth frames are skipped in the call stack
  383. // and the final frame is treated like the original callee to Info.
  384. func InfoDepth(depth int, args ...any) {
  385. logf(depth+1, logsink.Info, false, noStack, defaultFormat(args), args...)
  386. }
  387. // InfoDepthf acts as InfoDepth but with format string.
  388. func InfoDepthf(depth int, format string, args ...any) {
  389. logf(depth+1, logsink.Info, false, noStack, format, args...)
  390. }
  391. // Infoln logs to the INFO log.
  392. // Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
  393. func Infoln(args ...any) {
  394. logf(1, logsink.Info, false, noStack, lnFormat(args), args...)
  395. }
  396. // Infof logs to the INFO log.
  397. // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
  398. func Infof(format string, args ...any) {
  399. logf(1, logsink.Info, false, noStack, format, args...)
  400. }
  401. // Warning logs to the WARNING and INFO logs.
  402. // Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
  403. func Warning(args ...any) {
  404. WarningDepth(1, args...)
  405. }
  406. // WarningDepth acts as Warning but uses depth to determine which call frame to log.
  407. // WarningDepth(0, "msg") is the same as Warning("msg").
  408. func WarningDepth(depth int, args ...any) {
  409. logf(depth+1, logsink.Warning, false, noStack, defaultFormat(args), args...)
  410. }
  411. // WarningDepthf acts as Warningf but uses depth to determine which call frame to log.
  412. // WarningDepthf(0, "msg") is the same as Warningf("msg").
  413. func WarningDepthf(depth int, format string, args ...any) {
  414. logf(depth+1, logsink.Warning, false, noStack, format, args...)
  415. }
  416. // Warningln logs to the WARNING and INFO logs.
  417. // Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
  418. func Warningln(args ...any) {
  419. logf(1, logsink.Warning, false, noStack, lnFormat(args), args...)
  420. }
  421. // Warningf logs to the WARNING and INFO logs.
  422. // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
  423. func Warningf(format string, args ...any) {
  424. logf(1, logsink.Warning, false, noStack, format, args...)
  425. }
  426. // Error logs to the ERROR, WARNING, and INFO logs.
  427. // Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
  428. func Error(args ...any) {
  429. ErrorDepth(1, args...)
  430. }
  431. // ErrorDepth acts as Error but uses depth to determine which call frame to log.
  432. // ErrorDepth(0, "msg") is the same as Error("msg").
  433. func ErrorDepth(depth int, args ...any) {
  434. logf(depth+1, logsink.Error, false, noStack, defaultFormat(args), args...)
  435. }
  436. // ErrorDepthf acts as Errorf but uses depth to determine which call frame to log.
  437. // ErrorDepthf(0, "msg") is the same as Errorf("msg").
  438. func ErrorDepthf(depth int, format string, args ...any) {
  439. logf(depth+1, logsink.Error, false, noStack, format, args...)
  440. }
  441. // Errorln logs to the ERROR, WARNING, and INFO logs.
  442. // Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
  443. func Errorln(args ...any) {
  444. logf(1, logsink.Error, false, noStack, lnFormat(args), args...)
  445. }
  446. // Errorf logs to the ERROR, WARNING, and INFO logs.
  447. // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
  448. func Errorf(format string, args ...any) {
  449. logf(1, logsink.Error, false, noStack, format, args...)
  450. }
  451. func fatalf(depth int, format string, args ...any) {
  452. logf(depth+1, logsink.Fatal, false, withStack, format, args...)
  453. sinks.file.Flush()
  454. err := abortProcess() // Should not return.
  455. // Failed to abort the process using signals. Dump a stack trace and exit.
  456. Errorf("abortProcess returned unexpectedly: %v", err)
  457. sinks.file.Flush()
  458. pprof.Lookup("goroutine").WriteTo(os.Stderr, 1)
  459. os.Exit(2) // Exit with the same code as the default SIGABRT handler.
  460. }
  461. // Fatal logs to the FATAL, ERROR, WARNING, and INFO logs,
  462. // including a stack trace of all running goroutines, then calls os.Exit(2).
  463. // Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
  464. func Fatal(args ...any) {
  465. FatalDepth(1, args...)
  466. }
  467. // FatalDepth acts as Fatal but uses depth to determine which call frame to log.
  468. // FatalDepth(0, "msg") is the same as Fatal("msg").
  469. func FatalDepth(depth int, args ...any) {
  470. fatalf(depth+1, defaultFormat(args), args...)
  471. }
  472. // FatalDepthf acts as Fatalf but uses depth to determine which call frame to log.
  473. // FatalDepthf(0, "msg") is the same as Fatalf("msg").
  474. func FatalDepthf(depth int, format string, args ...any) {
  475. fatalf(depth+1, format, args...)
  476. }
  477. // Fatalln logs to the FATAL, ERROR, WARNING, and INFO logs,
  478. // including a stack trace of all running goroutines, then calls os.Exit(2).
  479. // Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
  480. func Fatalln(args ...any) {
  481. fatalf(1, lnFormat(args), args...)
  482. }
  483. // Fatalf logs to the FATAL, ERROR, WARNING, and INFO logs,
  484. // including a stack trace of all running goroutines, then calls os.Exit(2).
  485. // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
  486. func Fatalf(format string, args ...any) {
  487. fatalf(1, format, args...)
  488. }
  489. func exitf(depth int, format string, args ...any) {
  490. logf(depth+1, logsink.Fatal, false, noStack, format, args...)
  491. sinks.file.Flush()
  492. os.Exit(1)
  493. }
  494. // Exit logs to the FATAL, ERROR, WARNING, and INFO logs, then calls os.Exit(1).
  495. // Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
  496. func Exit(args ...any) {
  497. ExitDepth(1, args...)
  498. }
  499. // ExitDepth acts as Exit but uses depth to determine which call frame to log.
  500. // ExitDepth(0, "msg") is the same as Exit("msg").
  501. func ExitDepth(depth int, args ...any) {
  502. exitf(depth+1, defaultFormat(args), args...)
  503. }
  504. // ExitDepthf acts as Exitf but uses depth to determine which call frame to log.
  505. // ExitDepthf(0, "msg") is the same as Exitf("msg").
  506. func ExitDepthf(depth int, format string, args ...any) {
  507. exitf(depth+1, format, args...)
  508. }
  509. // Exitln logs to the FATAL, ERROR, WARNING, and INFO logs, then calls os.Exit(1).
  510. func Exitln(args ...any) {
  511. exitf(1, lnFormat(args), args...)
  512. }
  513. // Exitf logs to the FATAL, ERROR, WARNING, and INFO logs, then calls os.Exit(1).
  514. // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
  515. func Exitf(format string, args ...any) {
  516. exitf(1, format, args...)
  517. }