You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.

1030 lines
30 KiB

  1. // Go support for leveled logs, analogous to https://code.google.com/p/google-glog/
  2. //
  3. // Copyright 2013 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. //
  40. // -logtostderr=false
  41. // Logs are written to standard error instead of to files.
  42. // -alsologtostderr=false
  43. // Logs are written to standard error as well as to files.
  44. // -stderrthreshold=ERROR
  45. // Log events at or above this severity are logged to standard
  46. // error as well as to files.
  47. //
  48. // Other flags provide aids to debugging.
  49. //
  50. // -log_backtrace_at=""
  51. // When set to a file and line number holding a logging statement,
  52. // such as
  53. // -log_backtrace_at=gopherflakes.go:234
  54. // a stack trace will be written to the Info log whenever execution
  55. // hits that statement. (Unlike with -vmodule, the ".go" must be
  56. // present.)
  57. // -v=0
  58. // Enable V-leveled logging at the specified level.
  59. // -vmodule=""
  60. // The syntax of the argument is a comma-separated list of pattern=N,
  61. // where pattern is a literal file name (minus the ".go" suffix) or
  62. // "glob" pattern and N is a V level. For instance,
  63. // -vmodule=gopher*=3
  64. // sets the V level to 3 in all Go files whose names begin "gopher".
  65. //
  66. package glog
  67. import (
  68. "bufio"
  69. "bytes"
  70. "errors"
  71. "flag"
  72. "fmt"
  73. "io"
  74. "os"
  75. "path/filepath"
  76. "runtime"
  77. "strconv"
  78. "strings"
  79. "sync"
  80. "sync/atomic"
  81. "time"
  82. )
  83. // severity identifies the sort of log: info, warning etc. It also implements
  84. // the flag.Value interface. The -stderrthreshold flag is of type severity and
  85. // should be modified only through the flag.Value interface. The values match
  86. // the corresponding constants in C++.
  87. type severity int32 // sync/atomic int32
  88. const (
  89. infoLog severity = iota
  90. warningLog
  91. errorLog
  92. fatalLog
  93. numSeverity = 4
  94. )
  95. const severityChar = "IWEF"
  96. var severityName = []string{
  97. infoLog: "INFO",
  98. warningLog: "WARNING",
  99. errorLog: "ERROR",
  100. fatalLog: "FATAL",
  101. }
  102. // get returns the value of the severity.
  103. func (s *severity) get() severity {
  104. return severity(atomic.LoadInt32((*int32)(s)))
  105. }
  106. // set sets the value of the severity.
  107. func (s *severity) set(val severity) {
  108. atomic.StoreInt32((*int32)(s), int32(val))
  109. }
  110. // String is part of the flag.Value interface.
  111. func (s *severity) String() string {
  112. return strconv.FormatInt(int64(*s), 10)
  113. }
  114. // Get is part of the flag.Value interface.
  115. func (s *severity) Get() interface{} {
  116. return *s
  117. }
  118. // Set is part of the flag.Value interface.
  119. func (s *severity) Set(value string) error {
  120. var threshold severity
  121. // Is it a known name?
  122. if v, ok := severityByName(value); ok {
  123. threshold = v
  124. } else {
  125. v, err := strconv.Atoi(value)
  126. if err != nil {
  127. return err
  128. }
  129. threshold = severity(v)
  130. }
  131. logging.stderrThreshold.set(threshold)
  132. return nil
  133. }
  134. func severityByName(s string) (severity, bool) {
  135. s = strings.ToUpper(s)
  136. for i, name := range severityName {
  137. if name == s {
  138. return severity(i), true
  139. }
  140. }
  141. return 0, false
  142. }
  143. // OutputStats tracks the number of output lines and bytes written.
  144. type OutputStats struct {
  145. lines int64
  146. bytes int64
  147. }
  148. // Lines returns the number of lines written.
  149. func (s *OutputStats) Lines() int64 {
  150. return atomic.LoadInt64(&s.lines)
  151. }
  152. // Bytes returns the number of bytes written.
  153. func (s *OutputStats) Bytes() int64 {
  154. return atomic.LoadInt64(&s.bytes)
  155. }
  156. // Stats tracks the number of lines of output and number of bytes
  157. // per severity level. Values must be read with atomic.LoadInt64.
  158. var Stats struct {
  159. Info, Warning, Error OutputStats
  160. }
  161. var severityStats = [numSeverity]*OutputStats{
  162. infoLog: &Stats.Info,
  163. warningLog: &Stats.Warning,
  164. errorLog: &Stats.Error,
  165. }
  166. // Level is exported because it appears in the arguments to V and is
  167. // the type of the v flag, which can be set programmatically.
  168. // It's a distinct type because we want to discriminate it from logType.
  169. // Variables of type level are only changed under logging.mu.
  170. // The -v flag is read only with atomic ops, so the state of the logging
  171. // module is consistent.
  172. // Level is treated as a sync/atomic int32.
  173. // Level specifies a level of verbosity for V logs. *Level implements
  174. // flag.Value; the -v flag is of type Level and should be modified
  175. // only through the flag.Value interface.
  176. type Level int32
  177. // get returns the value of the Level.
  178. func (l *Level) get() Level {
  179. return Level(atomic.LoadInt32((*int32)(l)))
  180. }
  181. // set sets the value of the Level.
  182. func (l *Level) set(val Level) {
  183. atomic.StoreInt32((*int32)(l), int32(val))
  184. }
  185. // String is part of the flag.Value interface.
  186. func (l *Level) String() string {
  187. return strconv.FormatInt(int64(*l), 10)
  188. }
  189. // Get is part of the flag.Value interface.
  190. func (l *Level) Get() interface{} {
  191. return *l
  192. }
  193. // Set is part of the flag.Value interface.
  194. func (l *Level) Set(value string) error {
  195. v, err := strconv.Atoi(value)
  196. if err != nil {
  197. return err
  198. }
  199. logging.mu.Lock()
  200. defer logging.mu.Unlock()
  201. logging.setVState(Level(v), logging.vmodule.filter, false)
  202. return nil
  203. }
  204. // moduleSpec represents the setting of the -vmodule flag.
  205. type moduleSpec struct {
  206. filter []modulePat
  207. }
  208. // modulePat contains a filter for the -vmodule flag.
  209. // It holds a verbosity level and a file pattern to match.
  210. type modulePat struct {
  211. pattern string
  212. literal bool // The pattern is a literal string
  213. level Level
  214. }
  215. // match reports whether the file matches the pattern. It uses a string
  216. // comparison if the pattern contains no metacharacters.
  217. func (m *modulePat) match(file string) bool {
  218. if m.literal {
  219. return file == m.pattern
  220. }
  221. match, _ := filepath.Match(m.pattern, file)
  222. return match
  223. }
  224. func (m *moduleSpec) String() string {
  225. // Lock because the type is not atomic. TODO: clean this up.
  226. logging.mu.Lock()
  227. defer logging.mu.Unlock()
  228. var b bytes.Buffer
  229. for i, f := range m.filter {
  230. if i > 0 {
  231. b.WriteRune(',')
  232. }
  233. fmt.Fprintf(&b, "%s=%d", f.pattern, f.level)
  234. }
  235. return b.String()
  236. }
  237. // Get is part of the (Go 1.2) flag.Getter interface. It always returns nil for this flag type since the
  238. // struct is not exported.
  239. func (m *moduleSpec) Get() interface{} {
  240. return nil
  241. }
  242. var errVmoduleSyntax = errors.New("syntax error: expect comma-separated list of filename=N")
  243. // Syntax: -vmodule=recordio=2,file=1,gfs*=3
  244. func (m *moduleSpec) Set(value string) error {
  245. var filter []modulePat
  246. for _, pat := range strings.Split(value, ",") {
  247. if len(pat) == 0 {
  248. // Empty strings such as from a trailing comma can be ignored.
  249. continue
  250. }
  251. patLev := strings.Split(pat, "=")
  252. if len(patLev) != 2 || len(patLev[0]) == 0 || len(patLev[1]) == 0 {
  253. return errVmoduleSyntax
  254. }
  255. pattern := patLev[0]
  256. v, err := strconv.Atoi(patLev[1])
  257. if err != nil {
  258. return errors.New("syntax error: expect comma-separated list of filename=N")
  259. }
  260. if v < 0 {
  261. return errors.New("negative value for vmodule level")
  262. }
  263. if v == 0 {
  264. continue // Ignore. It's harmless but no point in paying the overhead.
  265. }
  266. // TODO: check syntax of filter?
  267. filter = append(filter, modulePat{pattern, isLiteral(pattern), Level(v)})
  268. }
  269. logging.mu.Lock()
  270. defer logging.mu.Unlock()
  271. logging.setVState(logging.verbosity, filter, true)
  272. return nil
  273. }
  274. // isLiteral reports whether the pattern is a literal string, that is, has no metacharacters
  275. // that require filepath.Match to be called to match the pattern.
  276. func isLiteral(pattern string) bool {
  277. return !strings.ContainsAny(pattern, `*?[]\`)
  278. }
  279. // traceLocation represents the setting of the -log_backtrace_at flag.
  280. type traceLocation struct {
  281. file string
  282. line int
  283. }
  284. // isSet reports whether the trace location has been specified.
  285. // logging.mu is held.
  286. func (t *traceLocation) isSet() bool {
  287. return t.line > 0
  288. }
  289. // match reports whether the specified file and line matches the trace location.
  290. // The argument file name is the full path, not the basename specified in the flag.
  291. // logging.mu is held.
  292. func (t *traceLocation) match(file string, line int) bool {
  293. if t.line != line {
  294. return false
  295. }
  296. if i := strings.LastIndex(file, "/"); i >= 0 {
  297. file = file[i+1:]
  298. }
  299. return t.file == file
  300. }
  301. func (t *traceLocation) String() string {
  302. // Lock because the type is not atomic. TODO: clean this up.
  303. logging.mu.Lock()
  304. defer logging.mu.Unlock()
  305. return fmt.Sprintf("%s:%d", t.file, t.line)
  306. }
  307. // Get is part of the (Go 1.2) flag.Getter interface. It always returns nil for this flag type since the
  308. // struct is not exported
  309. func (t *traceLocation) Get() interface{} {
  310. return nil
  311. }
  312. var errTraceSyntax = errors.New("syntax error: expect file.go:234")
  313. // Syntax: -log_backtrace_at=gopherflakes.go:234
  314. // Note that unlike vmodule the file extension is included here.
  315. func (t *traceLocation) Set(value string) error {
  316. if value == "" {
  317. // Unset.
  318. t.line = 0
  319. t.file = ""
  320. }
  321. fields := strings.Split(value, ":")
  322. if len(fields) != 2 {
  323. return errTraceSyntax
  324. }
  325. file, line := fields[0], fields[1]
  326. if !strings.Contains(file, ".") {
  327. return errTraceSyntax
  328. }
  329. v, err := strconv.Atoi(line)
  330. if err != nil {
  331. return errTraceSyntax
  332. }
  333. if v <= 0 {
  334. return errors.New("negative or zero value for level")
  335. }
  336. logging.mu.Lock()
  337. defer logging.mu.Unlock()
  338. t.line = v
  339. t.file = file
  340. return nil
  341. }
  342. // flushSyncWriter is the interface satisfied by logging destinations.
  343. type flushSyncWriter interface {
  344. Flush() error
  345. Sync() error
  346. io.Writer
  347. }
  348. func init() {
  349. flag.BoolVar(&logging.toStderr, "logtostderr", false, "log to standard error instead of files")
  350. flag.BoolVar(&logging.alsoToStderr, "alsologtostderr", false, "log to standard error as well as files")
  351. flag.Var(&logging.verbosity, "v", "log level for V logs")
  352. flag.Var(&logging.stderrThreshold, "stderrthreshold", "logs at or above this threshold go to stderr")
  353. flag.Var(&logging.vmodule, "vmodule", "comma-separated list of pattern=N settings for file-filtered logging")
  354. flag.Var(&logging.traceLocation, "log_backtrace_at", "when logging hits line file:N, emit a stack trace")
  355. // Default stderrThreshold is ERROR.
  356. logging.stderrThreshold = errorLog
  357. logging.setVState(0, nil, false)
  358. go logging.flushDaemon()
  359. }
  360. // Flush flushes all pending log I/O.
  361. func Flush() {
  362. logging.lockAndFlushAll()
  363. }
  364. // loggingT collects all the global state of the logging setup.
  365. type loggingT struct {
  366. // Boolean flags. Not handled atomically because the flag.Value interface
  367. // does not let us avoid the =true, and that shorthand is necessary for
  368. // compatibility. TODO: does this matter enough to fix? Seems unlikely.
  369. toStderr bool // The -logtostderr flag.
  370. alsoToStderr bool // The -alsologtostderr flag.
  371. // Level flag. Handled atomically.
  372. stderrThreshold severity // The -stderrthreshold flag.
  373. // freeList is a list of byte buffers, maintained under freeListMu.
  374. freeList *buffer
  375. // freeListMu maintains the free list. It is separate from the main mutex
  376. // so buffers can be grabbed and printed to without holding the main lock,
  377. // for better parallelization.
  378. freeListMu sync.Mutex
  379. // mu protects the remaining elements of this structure and is
  380. // used to synchronize logging.
  381. mu sync.Mutex
  382. // file holds writer for each of the log types.
  383. file [numSeverity]flushSyncWriter
  384. // pcs is used in V to avoid an allocation when computing the caller's PC.
  385. pcs [1]uintptr
  386. // vmap is a cache of the V Level for each V() call site, identified by PC.
  387. // It is wiped whenever the vmodule flag changes state.
  388. vmap map[uintptr]Level
  389. // filterLength stores the length of the vmodule filter chain. If greater
  390. // than zero, it means vmodule is enabled. It may be read safely
  391. // using sync.LoadInt32, but is only modified under mu.
  392. filterLength int32
  393. // traceLocation is the state of the -log_backtrace_at flag.
  394. traceLocation traceLocation
  395. // These flags are modified only under lock, although verbosity may be fetched
  396. // safely using atomic.LoadInt32.
  397. vmodule moduleSpec // The state of the -vmodule flag.
  398. verbosity Level // V logging level, the value of the -v flag/
  399. }
  400. // buffer holds a byte Buffer for reuse. The zero value is ready for use.
  401. type buffer struct {
  402. bytes.Buffer
  403. tmp [64]byte // temporary byte array for creating headers.
  404. next *buffer
  405. }
  406. var logging loggingT
  407. // setVState sets a consistent state for V logging.
  408. // l.mu is held.
  409. func (l *loggingT) setVState(verbosity Level, filter []modulePat, setFilter bool) {
  410. // Turn verbosity off so V will not fire while we are in transition.
  411. logging.verbosity.set(0)
  412. // Ditto for filter length.
  413. logging.filterLength = 0
  414. // Set the new filters and wipe the pc->Level map if the filter has changed.
  415. if setFilter {
  416. logging.vmodule.filter = filter
  417. logging.vmap = make(map[uintptr]Level)
  418. }
  419. // Things are consistent now, so enable filtering and verbosity.
  420. // They are enabled in order opposite to that in V.
  421. atomic.StoreInt32(&logging.filterLength, int32(len(filter)))
  422. logging.verbosity.set(verbosity)
  423. }
  424. // getBuffer returns a new, ready-to-use buffer.
  425. func (l *loggingT) getBuffer() *buffer {
  426. l.freeListMu.Lock()
  427. b := l.freeList
  428. if b != nil {
  429. l.freeList = b.next
  430. }
  431. l.freeListMu.Unlock()
  432. if b == nil {
  433. b = new(buffer)
  434. } else {
  435. b.next = nil
  436. b.Reset()
  437. }
  438. return b
  439. }
  440. // putBuffer returns a buffer to the free list.
  441. func (l *loggingT) putBuffer(b *buffer) {
  442. if b.Len() >= 256 {
  443. // Let big buffers die a natural death.
  444. return
  445. }
  446. l.freeListMu.Lock()
  447. b.next = l.freeList
  448. l.freeList = b
  449. l.freeListMu.Unlock()
  450. }
  451. var timeNow = time.Now // Stubbed out for testing.
  452. /*
  453. header formats a log header as defined by the C++ implementation.
  454. It returns a buffer containing the formatted header.
  455. Log lines have this form:
  456. Lmmdd hh:mm:ss.uuuuuu threadid file:line] msg...
  457. where the fields are defined as follows:
  458. L A single character, representing the log level (eg 'I' for INFO)
  459. mm The month (zero padded; ie May is '05')
  460. dd The day (zero padded)
  461. hh:mm:ss.uuuuuu Time in hours, minutes and fractional seconds
  462. threadid The space-padded thread ID as returned by GetTID()
  463. file The file name
  464. line The line number
  465. msg The user-supplied message
  466. */
  467. func (l *loggingT) header(s severity) *buffer {
  468. // Lmmdd hh:mm:ss.uuuuuu threadid file:line]
  469. now := timeNow()
  470. _, file, line, ok := runtime.Caller(3) // It's always the same number of frames to the user's call.
  471. if !ok {
  472. file = "???"
  473. line = 1
  474. } else {
  475. slash := strings.LastIndex(file, "/")
  476. if slash >= 0 {
  477. file = file[slash+1:]
  478. }
  479. }
  480. if line < 0 {
  481. line = 0 // not a real line number, but acceptable to someDigits
  482. }
  483. if s > fatalLog {
  484. s = infoLog // for safety.
  485. }
  486. buf := l.getBuffer()
  487. // Avoid Fprintf, for speed. The format is so simple that we can do it quickly by hand.
  488. // It's worth about 3X. Fprintf is hard.
  489. _, month, day := now.Date()
  490. hour, minute, second := now.Clock()
  491. buf.tmp[0] = severityChar[s]
  492. buf.twoDigits(1, int(month))
  493. buf.twoDigits(3, day)
  494. buf.tmp[5] = ' '
  495. buf.twoDigits(6, hour)
  496. buf.tmp[8] = ':'
  497. buf.twoDigits(9, minute)
  498. buf.tmp[11] = ':'
  499. buf.twoDigits(12, second)
  500. //buf.tmp[14] = '.'
  501. //buf.nDigits(6, 15, now.Nanosecond()/1000)
  502. buf.tmp[21] = ' '
  503. buf.nDigits(5, 22, pid) // TODO: should be TID
  504. buf.tmp[27] = ' '
  505. buf.Write(buf.tmp[:28])
  506. buf.WriteString(file)
  507. buf.tmp[0] = ':'
  508. n := buf.someDigits(1, line)
  509. buf.tmp[n+1] = ']'
  510. buf.tmp[n+2] = ' '
  511. buf.Write(buf.tmp[:n+3])
  512. return buf
  513. }
  514. // Some custom tiny helper functions to print the log header efficiently.
  515. const digits = "0123456789"
  516. // twoDigits formats a zero-prefixed two-digit integer at buf.tmp[i].
  517. func (buf *buffer) twoDigits(i, d int) {
  518. buf.tmp[i+1] = digits[d%10]
  519. d /= 10
  520. buf.tmp[i] = digits[d%10]
  521. }
  522. // nDigits formats a zero-prefixed n-digit integer at buf.tmp[i].
  523. func (buf *buffer) nDigits(n, i, d int) {
  524. for j := n - 1; j >= 0; j-- {
  525. buf.tmp[i+j] = digits[d%10]
  526. d /= 10
  527. }
  528. }
  529. // someDigits formats a zero-prefixed variable-width integer at buf.tmp[i].
  530. func (buf *buffer) someDigits(i, d int) int {
  531. // Print into the top, then copy down. We know there's space for at least
  532. // a 10-digit number.
  533. j := len(buf.tmp)
  534. for {
  535. j--
  536. buf.tmp[j] = digits[d%10]
  537. d /= 10
  538. if d == 0 {
  539. break
  540. }
  541. }
  542. return copy(buf.tmp[i:], buf.tmp[j:])
  543. }
  544. func (l *loggingT) println(s severity, args ...interface{}) {
  545. buf := l.header(s)
  546. fmt.Fprintln(buf, args...)
  547. l.output(s, buf)
  548. }
  549. func (l *loggingT) print(s severity, args ...interface{}) {
  550. buf := l.header(s)
  551. fmt.Fprint(buf, args...)
  552. if buf.Bytes()[buf.Len()-1] != '\n' {
  553. buf.WriteByte('\n')
  554. }
  555. l.output(s, buf)
  556. }
  557. func (l *loggingT) printf(s severity, format string, args ...interface{}) {
  558. buf := l.header(s)
  559. fmt.Fprintf(buf, format, args...)
  560. if buf.Bytes()[buf.Len()-1] != '\n' {
  561. buf.WriteByte('\n')
  562. }
  563. l.output(s, buf)
  564. }
  565. // output writes the data to the log files and releases the buffer.
  566. func (l *loggingT) output(s severity, buf *buffer) {
  567. l.mu.Lock()
  568. if l.traceLocation.isSet() {
  569. _, file, line, ok := runtime.Caller(3) // It's always the same number of frames to the user's call (same as header).
  570. if ok && l.traceLocation.match(file, line) {
  571. buf.Write(stacks(false))
  572. }
  573. }
  574. data := buf.Bytes()
  575. if l.toStderr {
  576. os.Stderr.Write(data)
  577. } else {
  578. if l.alsoToStderr || s >= l.stderrThreshold.get() {
  579. os.Stderr.Write(data)
  580. }
  581. if l.file[s] == nil {
  582. if err := l.createFiles(s); err != nil {
  583. os.Stderr.Write(data) // Make sure the message appears somewhere.
  584. l.exit(err)
  585. }
  586. }
  587. switch s {
  588. case fatalLog:
  589. l.file[fatalLog].Write(data)
  590. fallthrough
  591. case errorLog:
  592. l.file[errorLog].Write(data)
  593. fallthrough
  594. case warningLog:
  595. l.file[warningLog].Write(data)
  596. fallthrough
  597. case infoLog:
  598. l.file[infoLog].Write(data)
  599. }
  600. }
  601. if s == fatalLog {
  602. // Make sure we see the trace for the current goroutine on standard error.
  603. if !l.toStderr {
  604. os.Stderr.Write(stacks(false))
  605. }
  606. // Write the stack trace for all goroutines to the files.
  607. trace := stacks(true)
  608. logExitFunc = func(error) {} // If we get a write error, we'll still exit below.
  609. for log := fatalLog; log >= infoLog; log-- {
  610. if f := l.file[log]; f != nil { // Can be nil if -logtostderr is set.
  611. f.Write(trace)
  612. }
  613. }
  614. l.mu.Unlock()
  615. timeoutFlush(10 * time.Second)
  616. os.Exit(255) // C++ uses -1, which is silly because it's anded with 255 anyway.
  617. }
  618. l.putBuffer(buf)
  619. l.mu.Unlock()
  620. if stats := severityStats[s]; stats != nil {
  621. atomic.AddInt64(&stats.lines, 1)
  622. atomic.AddInt64(&stats.bytes, int64(len(data)))
  623. }
  624. }
  625. // timeoutFlush calls Flush and returns when it completes or after timeout
  626. // elapses, whichever happens first. This is needed because the hooks invoked
  627. // by Flush may deadlock when glog.Fatal is called from a hook that holds
  628. // a lock.
  629. func timeoutFlush(timeout time.Duration) {
  630. done := make(chan bool, 1)
  631. go func() {
  632. Flush() // calls logging.lockAndFlushAll()
  633. done <- true
  634. }()
  635. select {
  636. case <-done:
  637. case <-time.After(timeout):
  638. fmt.Fprintln(os.Stderr, "glog: Flush took longer than", timeout)
  639. }
  640. }
  641. // stacks is a wrapper for runtime.Stack that attempts to recover the data for all goroutines.
  642. func stacks(all bool) []byte {
  643. // We don't know how big the traces are, so grow a few times if they don't fit. Start large, though.
  644. n := 10000
  645. if all {
  646. n = 100000
  647. }
  648. var trace []byte
  649. for i := 0; i < 5; i++ {
  650. trace = make([]byte, n)
  651. nbytes := runtime.Stack(trace, all)
  652. if nbytes < len(trace) {
  653. return trace[:nbytes]
  654. }
  655. n *= 2
  656. }
  657. return trace
  658. }
  659. // logExitFunc provides a simple mechanism to override the default behavior
  660. // of exiting on error. Used in testing and to guarantee we reach a required exit
  661. // for fatal logs. Instead, exit could be a function rather than a method but that
  662. // would make its use clumsier.
  663. var logExitFunc func(error)
  664. // exit is called if there is trouble creating or writing log files.
  665. // It flushes the logs and exits the program; there's no point in hanging around.
  666. // l.mu is held.
  667. func (l *loggingT) exit(err error) {
  668. fmt.Fprintf(os.Stderr, "log: exiting because of error: %s\n", err)
  669. // If logExitFunc is set, we do that instead of exiting.
  670. if logExitFunc != nil {
  671. logExitFunc(err)
  672. return
  673. }
  674. l.flushAll()
  675. os.Exit(2)
  676. }
  677. // syncBuffer joins a bufio.Writer to its underlying file, providing access to the
  678. // file's Sync method and providing a wrapper for the Write method that provides log
  679. // file rotation. There are conflicting methods, so the file cannot be embedded.
  680. // l.mu is held for all its methods.
  681. type syncBuffer struct {
  682. logger *loggingT
  683. *bufio.Writer
  684. file *os.File
  685. sev severity
  686. nbytes uint64 // The number of bytes written to this file
  687. }
  688. func (sb *syncBuffer) Sync() error {
  689. return sb.file.Sync()
  690. }
  691. func (sb *syncBuffer) Write(p []byte) (n int, err error) {
  692. if sb.nbytes+uint64(len(p)) >= MaxSize {
  693. if err := sb.rotateFile(time.Now()); err != nil {
  694. sb.logger.exit(err)
  695. }
  696. }
  697. n, err = sb.Writer.Write(p)
  698. sb.nbytes += uint64(n)
  699. if err != nil {
  700. sb.logger.exit(err)
  701. }
  702. return
  703. }
  704. // rotateFile closes the syncBuffer's file and starts a new one.
  705. func (sb *syncBuffer) rotateFile(now time.Time) error {
  706. if sb.file != nil {
  707. sb.Flush()
  708. sb.file.Close()
  709. }
  710. var err error
  711. sb.file, _, err = create(severityName[sb.sev], now)
  712. sb.nbytes = 0
  713. if err != nil {
  714. return err
  715. }
  716. sb.Writer = bufio.NewWriterSize(sb.file, bufferSize)
  717. // Write header.
  718. var buf bytes.Buffer
  719. fmt.Fprintf(&buf, "Log file created at: %s\n", now.Format("2006/01/02 15:04:05"))
  720. fmt.Fprintf(&buf, "Running on machine: %s\n", host)
  721. fmt.Fprintf(&buf, "Binary: Built with %s %s for %s/%s\n", runtime.Compiler, runtime.Version(), runtime.GOOS, runtime.GOARCH)
  722. fmt.Fprintf(&buf, "Log line format: [IWEF]mmdd hh:mm:ss threadid file:line] msg\n")
  723. n, err := sb.file.Write(buf.Bytes())
  724. sb.nbytes += uint64(n)
  725. return err
  726. }
  727. // bufferSize sizes the buffer associated with each log file. It's large
  728. // so that log records can accumulate without the logging thread blocking
  729. // on disk I/O. The flushDaemon will block instead.
  730. const bufferSize = 256 * 1024
  731. // createFiles creates all the log files for severity from sev down to infoLog.
  732. // l.mu is held.
  733. func (l *loggingT) createFiles(sev severity) error {
  734. now := time.Now()
  735. // Files are created in decreasing severity order, so as soon as we find one
  736. // has already been created, we can stop.
  737. for s := sev; s >= infoLog && l.file[s] == nil; s-- {
  738. sb := &syncBuffer{
  739. logger: l,
  740. sev: s,
  741. }
  742. if err := sb.rotateFile(now); err != nil {
  743. return err
  744. }
  745. l.file[s] = sb
  746. }
  747. return nil
  748. }
  749. const flushInterval = 30 * time.Second
  750. // flushDaemon periodically flushes the log file buffers.
  751. func (l *loggingT) flushDaemon() {
  752. for _ = range time.NewTicker(flushInterval).C {
  753. l.lockAndFlushAll()
  754. }
  755. }
  756. // lockAndFlushAll is like flushAll but locks l.mu first.
  757. func (l *loggingT) lockAndFlushAll() {
  758. l.mu.Lock()
  759. l.flushAll()
  760. l.mu.Unlock()
  761. }
  762. // flushAll flushes all the logs and attempts to "sync" their data to disk.
  763. // l.mu is held.
  764. func (l *loggingT) flushAll() {
  765. // Flush from fatal down, in case there's trouble flushing.
  766. for s := fatalLog; s >= infoLog; s-- {
  767. file := l.file[s]
  768. if file != nil {
  769. file.Flush() // ignore error
  770. file.Sync() // ignore error
  771. }
  772. }
  773. }
  774. // setV computes and remembers the V level for a given PC
  775. // when vmodule is enabled.
  776. // File pattern matching takes the basename of the file, stripped
  777. // of its .go suffix, and uses filepath.Match, which is a little more
  778. // general than the *? matching used in C++.
  779. // l.mu is held.
  780. func (l *loggingT) setV(pc uintptr) Level {
  781. fn := runtime.FuncForPC(pc)
  782. file, _ := fn.FileLine(pc)
  783. // The file is something like /a/b/c/d.go. We want just the d.
  784. if strings.HasSuffix(file, ".go") {
  785. file = file[:len(file)-3]
  786. }
  787. if slash := strings.LastIndex(file, "/"); slash >= 0 {
  788. file = file[slash+1:]
  789. }
  790. for _, filter := range l.vmodule.filter {
  791. if filter.match(file) {
  792. l.vmap[pc] = filter.level
  793. return filter.level
  794. }
  795. }
  796. l.vmap[pc] = 0
  797. return 0
  798. }
  799. // Verbose is a boolean type that implements Infof (like Printf) etc.
  800. // See the documentation of V for more information.
  801. type Verbose bool
  802. // V reports whether verbosity at the call site is at least the requested level.
  803. // The returned value is a boolean of type Verbose, which implements Info, Infoln
  804. // and Infof. These methods will write to the Info log if called.
  805. // Thus, one may write either
  806. // if glog.V(2) { glog.Info("log this") }
  807. // or
  808. // glog.V(2).Info("log this")
  809. // The second form is shorter but the first is cheaper if logging is off because it does
  810. // not evaluate its arguments.
  811. //
  812. // Whether an individual call to V generates a log record depends on the setting of
  813. // the -v and --vmodule flags; both are off by default. If the level in the call to
  814. // V is at least the value of -v, or of -vmodule for the source file containing the
  815. // call, the V call will log.
  816. func V(level Level) Verbose {
  817. // This function tries hard to be cheap unless there's work to do.
  818. // The fast path is two atomic loads and compares.
  819. // Here is a cheap but safe test to see if V logging is enabled globally.
  820. if logging.verbosity.get() >= level {
  821. return Verbose(true)
  822. }
  823. // It's off globally but it vmodule may still be set.
  824. // Here is another cheap but safe test to see if vmodule is enabled.
  825. if atomic.LoadInt32(&logging.filterLength) > 0 {
  826. // Now we need a proper lock to use the logging structure. The pcs field
  827. // is shared so we must lock before accessing it. This is fairly expensive,
  828. // but if V logging is enabled we're slow anyway.
  829. logging.mu.Lock()
  830. defer logging.mu.Unlock()
  831. if runtime.Callers(2, logging.pcs[:]) == 0 {
  832. return Verbose(false)
  833. }
  834. v, ok := logging.vmap[logging.pcs[0]]
  835. if !ok {
  836. v = logging.setV(logging.pcs[0])
  837. }
  838. return Verbose(v >= level)
  839. }
  840. return Verbose(false)
  841. }
  842. // Info is equivalent to the global Info function, guarded by the value of v.
  843. // See the documentation of V for usage.
  844. func (v Verbose) Info(args ...interface{}) {
  845. if v {
  846. logging.print(infoLog, args...)
  847. }
  848. }
  849. // Infoln is equivalent to the global Infoln function, guarded by the value of v.
  850. // See the documentation of V for usage.
  851. func (v Verbose) Infoln(args ...interface{}) {
  852. if v {
  853. logging.println(infoLog, args...)
  854. }
  855. }
  856. // Infof is equivalent to the global Infof function, guarded by the value of v.
  857. // See the documentation of V for usage.
  858. func (v Verbose) Infof(format string, args ...interface{}) {
  859. if v {
  860. logging.printf(infoLog, format, args...)
  861. }
  862. }
  863. // Info logs to the INFO log.
  864. // Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
  865. func Info(args ...interface{}) {
  866. logging.print(infoLog, args...)
  867. }
  868. // Infoln logs to the INFO log.
  869. // Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
  870. func Infoln(args ...interface{}) {
  871. logging.println(infoLog, args...)
  872. }
  873. // Infof logs to the INFO log.
  874. // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
  875. func Infof(format string, args ...interface{}) {
  876. logging.printf(infoLog, format, args...)
  877. }
  878. // Warning logs to the WARNING and INFO logs.
  879. // Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
  880. func Warning(args ...interface{}) {
  881. logging.print(warningLog, args...)
  882. }
  883. // Warningln logs to the WARNING and INFO logs.
  884. // Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
  885. func Warningln(args ...interface{}) {
  886. logging.println(warningLog, args...)
  887. }
  888. // Warningf logs to the WARNING and INFO logs.
  889. // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
  890. func Warningf(format string, args ...interface{}) {
  891. logging.printf(warningLog, format, args...)
  892. }
  893. // Error logs to the ERROR, WARNING, and INFO logs.
  894. // Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
  895. func Error(args ...interface{}) {
  896. logging.print(errorLog, args...)
  897. }
  898. // Errorln logs to the ERROR, WARNING, and INFO logs.
  899. // Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
  900. func Errorln(args ...interface{}) {
  901. logging.println(errorLog, args...)
  902. }
  903. // Errorf logs to the ERROR, WARNING, and INFO logs.
  904. // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
  905. func Errorf(format string, args ...interface{}) {
  906. logging.printf(errorLog, format, args...)
  907. }
  908. // Fatal logs to the FATAL, ERROR, WARNING, and INFO logs,
  909. // including a stack trace of all running goroutines, then calls os.Exit(255).
  910. // Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
  911. func Fatal(args ...interface{}) {
  912. logging.print(fatalLog, args...)
  913. }
  914. // Fatalln logs to the FATAL, ERROR, WARNING, and INFO logs,
  915. // including a stack trace of all running goroutines, then calls os.Exit(255).
  916. // Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
  917. func Fatalln(args ...interface{}) {
  918. logging.println(fatalLog, args...)
  919. }
  920. // Fatalf logs to the FATAL, ERROR, WARNING, and INFO logs,
  921. // including a stack trace of all running goroutines, then calls os.Exit(255).
  922. // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
  923. func Fatalf(format string, args ...interface{}) {
  924. logging.printf(fatalLog, format, args...)
  925. }