Scott Baker | 2d89798 | 2019-09-24 11:50:08 -0700 | [diff] [blame^] | 1 | // Copyright (c) 2016 Uber Technologies, Inc. |
| 2 | // |
| 3 | // Permission is hereby granted, free of charge, to any person obtaining a copy |
| 4 | // of this software and associated documentation files (the "Software"), to deal |
| 5 | // in the Software without restriction, including without limitation the rights |
| 6 | // to use, copy, modify, merge, publish, distribute, sublicense, and/or sell |
| 7 | // copies of the Software, and to permit persons to whom the Software is |
| 8 | // furnished to do so, subject to the following conditions: |
| 9 | // |
| 10 | // The above copyright notice and this permission notice shall be included in |
| 11 | // all copies or substantial portions of the Software. |
| 12 | // |
| 13 | // THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR |
| 14 | // IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, |
| 15 | // FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE |
| 16 | // AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER |
| 17 | // LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, |
| 18 | // OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN |
| 19 | // THE SOFTWARE. |
| 20 | |
| 21 | package zapcore |
| 22 | |
| 23 | import ( |
| 24 | "fmt" |
| 25 | "strings" |
| 26 | "sync" |
| 27 | "time" |
| 28 | |
| 29 | "go.uber.org/zap/internal/bufferpool" |
| 30 | "go.uber.org/zap/internal/exit" |
| 31 | |
| 32 | "go.uber.org/multierr" |
| 33 | ) |
| 34 | |
| 35 | var ( |
| 36 | _cePool = sync.Pool{New: func() interface{} { |
| 37 | // Pre-allocate some space for cores. |
| 38 | return &CheckedEntry{ |
| 39 | cores: make([]Core, 4), |
| 40 | } |
| 41 | }} |
| 42 | ) |
| 43 | |
| 44 | func getCheckedEntry() *CheckedEntry { |
| 45 | ce := _cePool.Get().(*CheckedEntry) |
| 46 | ce.reset() |
| 47 | return ce |
| 48 | } |
| 49 | |
| 50 | func putCheckedEntry(ce *CheckedEntry) { |
| 51 | if ce == nil { |
| 52 | return |
| 53 | } |
| 54 | _cePool.Put(ce) |
| 55 | } |
| 56 | |
| 57 | // NewEntryCaller makes an EntryCaller from the return signature of |
| 58 | // runtime.Caller. |
| 59 | func NewEntryCaller(pc uintptr, file string, line int, ok bool) EntryCaller { |
| 60 | if !ok { |
| 61 | return EntryCaller{} |
| 62 | } |
| 63 | return EntryCaller{ |
| 64 | PC: pc, |
| 65 | File: file, |
| 66 | Line: line, |
| 67 | Defined: true, |
| 68 | } |
| 69 | } |
| 70 | |
| 71 | // EntryCaller represents the caller of a logging function. |
| 72 | type EntryCaller struct { |
| 73 | Defined bool |
| 74 | PC uintptr |
| 75 | File string |
| 76 | Line int |
| 77 | } |
| 78 | |
| 79 | // String returns the full path and line number of the caller. |
| 80 | func (ec EntryCaller) String() string { |
| 81 | return ec.FullPath() |
| 82 | } |
| 83 | |
| 84 | // FullPath returns a /full/path/to/package/file:line description of the |
| 85 | // caller. |
| 86 | func (ec EntryCaller) FullPath() string { |
| 87 | if !ec.Defined { |
| 88 | return "undefined" |
| 89 | } |
| 90 | buf := bufferpool.Get() |
| 91 | buf.AppendString(ec.File) |
| 92 | buf.AppendByte(':') |
| 93 | buf.AppendInt(int64(ec.Line)) |
| 94 | caller := buf.String() |
| 95 | buf.Free() |
| 96 | return caller |
| 97 | } |
| 98 | |
| 99 | // TrimmedPath returns a package/file:line description of the caller, |
| 100 | // preserving only the leaf directory name and file name. |
| 101 | func (ec EntryCaller) TrimmedPath() string { |
| 102 | if !ec.Defined { |
| 103 | return "undefined" |
| 104 | } |
| 105 | // nb. To make sure we trim the path correctly on Windows too, we |
| 106 | // counter-intuitively need to use '/' and *not* os.PathSeparator here, |
| 107 | // because the path given originates from Go stdlib, specifically |
| 108 | // runtime.Caller() which (as of Mar/17) returns forward slashes even on |
| 109 | // Windows. |
| 110 | // |
| 111 | // See https://github.com/golang/go/issues/3335 |
| 112 | // and https://github.com/golang/go/issues/18151 |
| 113 | // |
| 114 | // for discussion on the issue on Go side. |
| 115 | // |
| 116 | // Find the last separator. |
| 117 | // |
| 118 | idx := strings.LastIndexByte(ec.File, '/') |
| 119 | if idx == -1 { |
| 120 | return ec.FullPath() |
| 121 | } |
| 122 | // Find the penultimate separator. |
| 123 | idx = strings.LastIndexByte(ec.File[:idx], '/') |
| 124 | if idx == -1 { |
| 125 | return ec.FullPath() |
| 126 | } |
| 127 | buf := bufferpool.Get() |
| 128 | // Keep everything after the penultimate separator. |
| 129 | buf.AppendString(ec.File[idx+1:]) |
| 130 | buf.AppendByte(':') |
| 131 | buf.AppendInt(int64(ec.Line)) |
| 132 | caller := buf.String() |
| 133 | buf.Free() |
| 134 | return caller |
| 135 | } |
| 136 | |
| 137 | // An Entry represents a complete log message. The entry's structured context |
| 138 | // is already serialized, but the log level, time, message, and call site |
| 139 | // information are available for inspection and modification. |
| 140 | // |
| 141 | // Entries are pooled, so any functions that accept them MUST be careful not to |
| 142 | // retain references to them. |
| 143 | type Entry struct { |
| 144 | Level Level |
| 145 | Time time.Time |
| 146 | LoggerName string |
| 147 | Message string |
| 148 | Caller EntryCaller |
| 149 | Stack string |
| 150 | } |
| 151 | |
| 152 | // CheckWriteAction indicates what action to take after a log entry is |
| 153 | // processed. Actions are ordered in increasing severity. |
| 154 | type CheckWriteAction uint8 |
| 155 | |
| 156 | const ( |
| 157 | // WriteThenNoop indicates that nothing special needs to be done. It's the |
| 158 | // default behavior. |
| 159 | WriteThenNoop CheckWriteAction = iota |
| 160 | // WriteThenPanic causes a panic after Write. |
| 161 | WriteThenPanic |
| 162 | // WriteThenFatal causes a fatal os.Exit after Write. |
| 163 | WriteThenFatal |
| 164 | ) |
| 165 | |
| 166 | // CheckedEntry is an Entry together with a collection of Cores that have |
| 167 | // already agreed to log it. |
| 168 | // |
| 169 | // CheckedEntry references should be created by calling AddCore or Should on a |
| 170 | // nil *CheckedEntry. References are returned to a pool after Write, and MUST |
| 171 | // NOT be retained after calling their Write method. |
| 172 | type CheckedEntry struct { |
| 173 | Entry |
| 174 | ErrorOutput WriteSyncer |
| 175 | dirty bool // best-effort detection of pool misuse |
| 176 | should CheckWriteAction |
| 177 | cores []Core |
| 178 | } |
| 179 | |
| 180 | func (ce *CheckedEntry) reset() { |
| 181 | ce.Entry = Entry{} |
| 182 | ce.ErrorOutput = nil |
| 183 | ce.dirty = false |
| 184 | ce.should = WriteThenNoop |
| 185 | for i := range ce.cores { |
| 186 | // don't keep references to cores |
| 187 | ce.cores[i] = nil |
| 188 | } |
| 189 | ce.cores = ce.cores[:0] |
| 190 | } |
| 191 | |
| 192 | // Write writes the entry to the stored Cores, returns any errors, and returns |
| 193 | // the CheckedEntry reference to a pool for immediate re-use. Finally, it |
| 194 | // executes any required CheckWriteAction. |
| 195 | func (ce *CheckedEntry) Write(fields ...Field) { |
| 196 | if ce == nil { |
| 197 | return |
| 198 | } |
| 199 | |
| 200 | if ce.dirty { |
| 201 | if ce.ErrorOutput != nil { |
| 202 | // Make a best effort to detect unsafe re-use of this CheckedEntry. |
| 203 | // If the entry is dirty, log an internal error; because the |
| 204 | // CheckedEntry is being used after it was returned to the pool, |
| 205 | // the message may be an amalgamation from multiple call sites. |
| 206 | fmt.Fprintf(ce.ErrorOutput, "%v Unsafe CheckedEntry re-use near Entry %+v.\n", time.Now(), ce.Entry) |
| 207 | ce.ErrorOutput.Sync() |
| 208 | } |
| 209 | return |
| 210 | } |
| 211 | ce.dirty = true |
| 212 | |
| 213 | var err error |
| 214 | for i := range ce.cores { |
| 215 | err = multierr.Append(err, ce.cores[i].Write(ce.Entry, fields)) |
| 216 | } |
| 217 | if ce.ErrorOutput != nil { |
| 218 | if err != nil { |
| 219 | fmt.Fprintf(ce.ErrorOutput, "%v write error: %v\n", time.Now(), err) |
| 220 | ce.ErrorOutput.Sync() |
| 221 | } |
| 222 | } |
| 223 | |
| 224 | should, msg := ce.should, ce.Message |
| 225 | putCheckedEntry(ce) |
| 226 | |
| 227 | switch should { |
| 228 | case WriteThenPanic: |
| 229 | panic(msg) |
| 230 | case WriteThenFatal: |
| 231 | exit.Exit() |
| 232 | } |
| 233 | } |
| 234 | |
| 235 | // AddCore adds a Core that has agreed to log this CheckedEntry. It's intended to be |
| 236 | // used by Core.Check implementations, and is safe to call on nil CheckedEntry |
| 237 | // references. |
| 238 | func (ce *CheckedEntry) AddCore(ent Entry, core Core) *CheckedEntry { |
| 239 | if ce == nil { |
| 240 | ce = getCheckedEntry() |
| 241 | ce.Entry = ent |
| 242 | } |
| 243 | ce.cores = append(ce.cores, core) |
| 244 | return ce |
| 245 | } |
| 246 | |
| 247 | // Should sets this CheckedEntry's CheckWriteAction, which controls whether a |
| 248 | // Core will panic or fatal after writing this log entry. Like AddCore, it's |
| 249 | // safe to call on nil CheckedEntry references. |
| 250 | func (ce *CheckedEntry) Should(ent Entry, should CheckWriteAction) *CheckedEntry { |
| 251 | if ce == nil { |
| 252 | ce = getCheckedEntry() |
| 253 | ce.Entry = ent |
| 254 | } |
| 255 | ce.should = should |
| 256 | return ce |
| 257 | } |