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.

1028 lines
30 KiB

11 years ago
  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", true, "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(5, 15, pid) // TODO: should be TID
  502. buf.tmp[20] = ' '
  503. buf.Write(buf.tmp[:21])
  504. buf.WriteString(file)
  505. buf.tmp[0] = ':'
  506. n := buf.someDigits(1, line)
  507. buf.tmp[n+1] = ']'
  508. buf.tmp[n+2] = ' '
  509. buf.Write(buf.tmp[:n+3])
  510. return buf
  511. }
  512. // Some custom tiny helper functions to print the log header efficiently.
  513. const digits = "0123456789"
  514. // twoDigits formats a zero-prefixed two-digit integer at buf.tmp[i].
  515. func (buf *buffer) twoDigits(i, d int) {
  516. buf.tmp[i+1] = digits[d%10]
  517. d /= 10
  518. buf.tmp[i] = digits[d%10]
  519. }
  520. // nDigits formats a zero-prefixed n-digit integer at buf.tmp[i].
  521. func (buf *buffer) nDigits(n, i, d int) {
  522. for j := n - 1; j >= 0; j-- {
  523. buf.tmp[i+j] = digits[d%10]
  524. d /= 10
  525. }
  526. }
  527. // someDigits formats a zero-prefixed variable-width integer at buf.tmp[i].
  528. func (buf *buffer) someDigits(i, d int) int {
  529. // Print into the top, then copy down. We know there's space for at least
  530. // a 10-digit number.
  531. j := len(buf.tmp)
  532. for {
  533. j--
  534. buf.tmp[j] = digits[d%10]
  535. d /= 10
  536. if d == 0 {
  537. break
  538. }
  539. }
  540. return copy(buf.tmp[i:], buf.tmp[j:])
  541. }
  542. func (l *loggingT) println(s severity, args ...interface{}) {
  543. buf := l.header(s)
  544. fmt.Fprintln(buf, args...)
  545. l.output(s, buf)
  546. }
  547. func (l *loggingT) print(s severity, args ...interface{}) {
  548. buf := l.header(s)
  549. fmt.Fprint(buf, args...)
  550. if buf.Bytes()[buf.Len()-1] != '\n' {
  551. buf.WriteByte('\n')
  552. }
  553. l.output(s, buf)
  554. }
  555. func (l *loggingT) printf(s severity, format string, args ...interface{}) {
  556. buf := l.header(s)
  557. fmt.Fprintf(buf, format, args...)
  558. if buf.Bytes()[buf.Len()-1] != '\n' {
  559. buf.WriteByte('\n')
  560. }
  561. l.output(s, buf)
  562. }
  563. // output writes the data to the log files and releases the buffer.
  564. func (l *loggingT) output(s severity, buf *buffer) {
  565. l.mu.Lock()
  566. if l.traceLocation.isSet() {
  567. _, file, line, ok := runtime.Caller(3) // It's always the same number of frames to the user's call (same as header).
  568. if ok && l.traceLocation.match(file, line) {
  569. buf.Write(stacks(false))
  570. }
  571. }
  572. data := buf.Bytes()
  573. if l.toStderr {
  574. os.Stderr.Write(data)
  575. } else {
  576. if l.alsoToStderr || s >= l.stderrThreshold.get() {
  577. os.Stderr.Write(data)
  578. }
  579. if l.file[s] == nil {
  580. if err := l.createFiles(s); err != nil {
  581. os.Stderr.Write(data) // Make sure the message appears somewhere.
  582. l.exit(err)
  583. }
  584. }
  585. switch s {
  586. case fatalLog:
  587. l.file[fatalLog].Write(data)
  588. fallthrough
  589. case errorLog:
  590. l.file[errorLog].Write(data)
  591. fallthrough
  592. case warningLog:
  593. l.file[warningLog].Write(data)
  594. fallthrough
  595. case infoLog:
  596. l.file[infoLog].Write(data)
  597. }
  598. }
  599. if s == fatalLog {
  600. // Make sure we see the trace for the current goroutine on standard error.
  601. if !l.toStderr {
  602. os.Stderr.Write(stacks(false))
  603. }
  604. // Write the stack trace for all goroutines to the files.
  605. trace := stacks(true)
  606. logExitFunc = func(error) {} // If we get a write error, we'll still exit below.
  607. for log := fatalLog; log >= infoLog; log-- {
  608. if f := l.file[log]; f != nil { // Can be nil if -logtostderr is set.
  609. f.Write(trace)
  610. }
  611. }
  612. l.mu.Unlock()
  613. timeoutFlush(10 * time.Second)
  614. os.Exit(255) // C++ uses -1, which is silly because it's anded with 255 anyway.
  615. }
  616. l.putBuffer(buf)
  617. l.mu.Unlock()
  618. if stats := severityStats[s]; stats != nil {
  619. atomic.AddInt64(&stats.lines, 1)
  620. atomic.AddInt64(&stats.bytes, int64(len(data)))
  621. }
  622. }
  623. // timeoutFlush calls Flush and returns when it completes or after timeout
  624. // elapses, whichever happens first. This is needed because the hooks invoked
  625. // by Flush may deadlock when glog.Fatal is called from a hook that holds
  626. // a lock.
  627. func timeoutFlush(timeout time.Duration) {
  628. done := make(chan bool, 1)
  629. go func() {
  630. Flush() // calls logging.lockAndFlushAll()
  631. done <- true
  632. }()
  633. select {
  634. case <-done:
  635. case <-time.After(timeout):
  636. fmt.Fprintln(os.Stderr, "glog: Flush took longer than", timeout)
  637. }
  638. }
  639. // stacks is a wrapper for runtime.Stack that attempts to recover the data for all goroutines.
  640. func stacks(all bool) []byte {
  641. // We don't know how big the traces are, so grow a few times if they don't fit. Start large, though.
  642. n := 10000
  643. if all {
  644. n = 100000
  645. }
  646. var trace []byte
  647. for i := 0; i < 5; i++ {
  648. trace = make([]byte, n)
  649. nbytes := runtime.Stack(trace, all)
  650. if nbytes < len(trace) {
  651. return trace[:nbytes]
  652. }
  653. n *= 2
  654. }
  655. return trace
  656. }
  657. // logExitFunc provides a simple mechanism to override the default behavior
  658. // of exiting on error. Used in testing and to guarantee we reach a required exit
  659. // for fatal logs. Instead, exit could be a function rather than a method but that
  660. // would make its use clumsier.
  661. var logExitFunc func(error)
  662. // exit is called if there is trouble creating or writing log files.
  663. // It flushes the logs and exits the program; there's no point in hanging around.
  664. // l.mu is held.
  665. func (l *loggingT) exit(err error) {
  666. fmt.Fprintf(os.Stderr, "log: exiting because of error: %s\n", err)
  667. // If logExitFunc is set, we do that instead of exiting.
  668. if logExitFunc != nil {
  669. logExitFunc(err)
  670. return
  671. }
  672. l.flushAll()
  673. os.Exit(2)
  674. }
  675. // syncBuffer joins a bufio.Writer to its underlying file, providing access to the
  676. // file's Sync method and providing a wrapper for the Write method that provides log
  677. // file rotation. There are conflicting methods, so the file cannot be embedded.
  678. // l.mu is held for all its methods.
  679. type syncBuffer struct {
  680. logger *loggingT
  681. *bufio.Writer
  682. file *os.File
  683. sev severity
  684. nbytes uint64 // The number of bytes written to this file
  685. }
  686. func (sb *syncBuffer) Sync() error {
  687. return sb.file.Sync()
  688. }
  689. func (sb *syncBuffer) Write(p []byte) (n int, err error) {
  690. if sb.nbytes+uint64(len(p)) >= MaxSize {
  691. if err := sb.rotateFile(time.Now()); err != nil {
  692. sb.logger.exit(err)
  693. }
  694. }
  695. n, err = sb.Writer.Write(p)
  696. sb.nbytes += uint64(n)
  697. if err != nil {
  698. sb.logger.exit(err)
  699. }
  700. return
  701. }
  702. // rotateFile closes the syncBuffer's file and starts a new one.
  703. func (sb *syncBuffer) rotateFile(now time.Time) error {
  704. if sb.file != nil {
  705. sb.Flush()
  706. sb.file.Close()
  707. }
  708. var err error
  709. sb.file, _, err = create(severityName[sb.sev], now)
  710. sb.nbytes = 0
  711. if err != nil {
  712. return err
  713. }
  714. sb.Writer = bufio.NewWriterSize(sb.file, bufferSize)
  715. // Write header.
  716. var buf bytes.Buffer
  717. fmt.Fprintf(&buf, "Log file created at: %s\n", now.Format("2006/01/02 15:04:05"))
  718. fmt.Fprintf(&buf, "Running on machine: %s\n", host)
  719. fmt.Fprintf(&buf, "Binary: Built with %s %s for %s/%s\n", runtime.Compiler, runtime.Version(), runtime.GOOS, runtime.GOARCH)
  720. fmt.Fprintf(&buf, "Log line format: [IWEF]mmdd hh:mm:ss threadid file:line] msg\n")
  721. n, err := sb.file.Write(buf.Bytes())
  722. sb.nbytes += uint64(n)
  723. return err
  724. }
  725. // bufferSize sizes the buffer associated with each log file. It's large
  726. // so that log records can accumulate without the logging thread blocking
  727. // on disk I/O. The flushDaemon will block instead.
  728. const bufferSize = 256 * 1024
  729. // createFiles creates all the log files for severity from sev down to infoLog.
  730. // l.mu is held.
  731. func (l *loggingT) createFiles(sev severity) error {
  732. now := time.Now()
  733. // Files are created in decreasing severity order, so as soon as we find one
  734. // has already been created, we can stop.
  735. for s := sev; s >= infoLog && l.file[s] == nil; s-- {
  736. sb := &syncBuffer{
  737. logger: l,
  738. sev: s,
  739. }
  740. if err := sb.rotateFile(now); err != nil {
  741. return err
  742. }
  743. l.file[s] = sb
  744. }
  745. return nil
  746. }
  747. const flushInterval = 30 * time.Second
  748. // flushDaemon periodically flushes the log file buffers.
  749. func (l *loggingT) flushDaemon() {
  750. for _ = range time.NewTicker(flushInterval).C {
  751. l.lockAndFlushAll()
  752. }
  753. }
  754. // lockAndFlushAll is like flushAll but locks l.mu first.
  755. func (l *loggingT) lockAndFlushAll() {
  756. l.mu.Lock()
  757. l.flushAll()
  758. l.mu.Unlock()
  759. }
  760. // flushAll flushes all the logs and attempts to "sync" their data to disk.
  761. // l.mu is held.
  762. func (l *loggingT) flushAll() {
  763. // Flush from fatal down, in case there's trouble flushing.
  764. for s := fatalLog; s >= infoLog; s-- {
  765. file := l.file[s]
  766. if file != nil {
  767. file.Flush() // ignore error
  768. file.Sync() // ignore error
  769. }
  770. }
  771. }
  772. // setV computes and remembers the V level for a given PC
  773. // when vmodule is enabled.
  774. // File pattern matching takes the basename of the file, stripped
  775. // of its .go suffix, and uses filepath.Match, which is a little more
  776. // general than the *? matching used in C++.
  777. // l.mu is held.
  778. func (l *loggingT) setV(pc uintptr) Level {
  779. fn := runtime.FuncForPC(pc)
  780. file, _ := fn.FileLine(pc)
  781. // The file is something like /a/b/c/d.go. We want just the d.
  782. if strings.HasSuffix(file, ".go") {
  783. file = file[:len(file)-3]
  784. }
  785. if slash := strings.LastIndex(file, "/"); slash >= 0 {
  786. file = file[slash+1:]
  787. }
  788. for _, filter := range l.vmodule.filter {
  789. if filter.match(file) {
  790. l.vmap[pc] = filter.level
  791. return filter.level
  792. }
  793. }
  794. l.vmap[pc] = 0
  795. return 0
  796. }
  797. // Verbose is a boolean type that implements Infof (like Printf) etc.
  798. // See the documentation of V for more information.
  799. type Verbose bool
  800. // V reports whether verbosity at the call site is at least the requested level.
  801. // The returned value is a boolean of type Verbose, which implements Info, Infoln
  802. // and Infof. These methods will write to the Info log if called.
  803. // Thus, one may write either
  804. // if glog.V(2) { glog.Info("log this") }
  805. // or
  806. // glog.V(2).Info("log this")
  807. // The second form is shorter but the first is cheaper if logging is off because it does
  808. // not evaluate its arguments.
  809. //
  810. // Whether an individual call to V generates a log record depends on the setting of
  811. // the -v and --vmodule flags; both are off by default. If the level in the call to
  812. // V is at least the value of -v, or of -vmodule for the source file containing the
  813. // call, the V call will log.
  814. func V(level Level) Verbose {
  815. // This function tries hard to be cheap unless there's work to do.
  816. // The fast path is two atomic loads and compares.
  817. // Here is a cheap but safe test to see if V logging is enabled globally.
  818. if logging.verbosity.get() >= level {
  819. return Verbose(true)
  820. }
  821. // It's off globally but it vmodule may still be set.
  822. // Here is another cheap but safe test to see if vmodule is enabled.
  823. if atomic.LoadInt32(&logging.filterLength) > 0 {
  824. // Now we need a proper lock to use the logging structure. The pcs field
  825. // is shared so we must lock before accessing it. This is fairly expensive,
  826. // but if V logging is enabled we're slow anyway.
  827. logging.mu.Lock()
  828. defer logging.mu.Unlock()
  829. if runtime.Callers(2, logging.pcs[:]) == 0 {
  830. return Verbose(false)
  831. }
  832. v, ok := logging.vmap[logging.pcs[0]]
  833. if !ok {
  834. v = logging.setV(logging.pcs[0])
  835. }
  836. return Verbose(v >= level)
  837. }
  838. return Verbose(false)
  839. }
  840. // Info is equivalent to the global Info function, guarded by the value of v.
  841. // See the documentation of V for usage.
  842. func (v Verbose) Info(args ...interface{}) {
  843. if v {
  844. logging.print(infoLog, args...)
  845. }
  846. }
  847. // Infoln is equivalent to the global Infoln function, guarded by the value of v.
  848. // See the documentation of V for usage.
  849. func (v Verbose) Infoln(args ...interface{}) {
  850. if v {
  851. logging.println(infoLog, args...)
  852. }
  853. }
  854. // Infof is equivalent to the global Infof function, guarded by the value of v.
  855. // See the documentation of V for usage.
  856. func (v Verbose) Infof(format string, args ...interface{}) {
  857. if v {
  858. logging.printf(infoLog, format, args...)
  859. }
  860. }
  861. // Info logs to the INFO log.
  862. // Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
  863. func Info(args ...interface{}) {
  864. logging.print(infoLog, args...)
  865. }
  866. // Infoln logs to the INFO log.
  867. // Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
  868. func Infoln(args ...interface{}) {
  869. logging.println(infoLog, args...)
  870. }
  871. // Infof logs to the INFO log.
  872. // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
  873. func Infof(format string, args ...interface{}) {
  874. logging.printf(infoLog, format, args...)
  875. }
  876. // Warning logs to the WARNING and INFO logs.
  877. // Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
  878. func Warning(args ...interface{}) {
  879. logging.print(warningLog, args...)
  880. }
  881. // Warningln logs to the WARNING and INFO logs.
  882. // Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
  883. func Warningln(args ...interface{}) {
  884. logging.println(warningLog, args...)
  885. }
  886. // Warningf logs to the WARNING and INFO logs.
  887. // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
  888. func Warningf(format string, args ...interface{}) {
  889. logging.printf(warningLog, format, args...)
  890. }
  891. // Error logs to the ERROR, WARNING, and INFO logs.
  892. // Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
  893. func Error(args ...interface{}) {
  894. logging.print(errorLog, args...)
  895. }
  896. // Errorln logs to the ERROR, WARNING, and INFO logs.
  897. // Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
  898. func Errorln(args ...interface{}) {
  899. logging.println(errorLog, args...)
  900. }
  901. // Errorf logs to the ERROR, WARNING, and INFO logs.
  902. // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
  903. func Errorf(format string, args ...interface{}) {
  904. logging.printf(errorLog, format, args...)
  905. }
  906. // Fatal logs to the FATAL, ERROR, WARNING, and INFO logs,
  907. // including a stack trace of all running goroutines, then calls os.Exit(255).
  908. // Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
  909. func Fatal(args ...interface{}) {
  910. logging.print(fatalLog, args...)
  911. }
  912. // Fatalln logs to the FATAL, ERROR, WARNING, and INFO logs,
  913. // including a stack trace of all running goroutines, then calls os.Exit(255).
  914. // Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
  915. func Fatalln(args ...interface{}) {
  916. logging.println(fatalLog, args...)
  917. }
  918. // Fatalf logs to the FATAL, ERROR, WARNING, and INFO logs,
  919. // including a stack trace of all running goroutines, then calls os.Exit(255).
  920. // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
  921. func Fatalf(format string, args ...interface{}) {
  922. logging.printf(fatalLog, format, args...)
  923. }