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.

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