1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240 241 242 243 244 245 246 247 248 249 250 251 252 253 254 255 256 257 258 259 260 261 262 263 264 265 266 267 268 269 270 271 272 273 274 275 276 277 278 279 280 281 282 283 284 285 286 287 288 289 290 291 292 293 294 295 296 297 298 299 300 301 302 303 304 305 306 307 308 309 310 311 312 313 314 315 316 317 318 319 320 321 322 323 324 325 326 327 328 329 330 331 332 333 334 335 336 337 338 339 340 341 342 343 344 345 346 347 348 349 350 351 352 353 354 355 356 357 358 359 360 361 362 363 364 365 366 367 368 369 370 371 372 373 374 375 376 377 378 379 380 381 382 383 384 385 386 387 388 389 390 391 392 393
|
// Copyright 2023 Google Inc. All Rights Reserved.
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
package logsink
import (
"bytes"
"context"
"fmt"
"strconv"
"strings"
"sync"
"time"
"github.com/golang/glog/internal/stackdump"
)
// MaxLogMessageLen is the limit on length of a formatted log message, including
// the standard line prefix and trailing newline.
//
// Chosen to match C++ glog.
const MaxLogMessageLen = 15000
// A Severity is a severity at which a message can be logged.
type Severity int8
// These constants identify the log levels in order of increasing severity.
// A message written to a high-severity log file is also written to each
// lower-severity log file.
const (
Info Severity = iota
Warning
Error
// Fatal contains logs written immediately before the process terminates.
//
// Sink implementations should not terminate the process themselves: the log
// package will perform any necessary cleanup and terminate the process as
// appropriate.
Fatal
)
func (s Severity) String() string {
switch s {
case Info:
return "INFO"
case Warning:
return "WARNING"
case Error:
return "ERROR"
case Fatal:
return "FATAL"
}
return fmt.Sprintf("%T(%d)", s, s)
}
// ParseSeverity returns the case-insensitive Severity value for the given string.
func ParseSeverity(name string) (Severity, error) {
name = strings.ToUpper(name)
for s := Info; s <= Fatal; s++ {
if s.String() == name {
return s, nil
}
}
return -1, fmt.Errorf("logsink: invalid severity %q", name)
}
// Meta is metadata about a logging call.
type Meta struct {
// The context with which the log call was made (or nil). If set, the context
// is only valid during the logsink.Structured.Printf call, it should not be
// retained.
Context context.Context
// Time is the time at which the log call was made.
Time time.Time
// File is the source file from which the log entry originates.
File string
// Line is the line offset within the source file.
Line int
// Depth is the number of stack frames between the logsink and the log call.
Depth int
Severity Severity
// Verbose indicates whether the call was made via "log.V". Log entries below
// the current verbosity threshold are not sent to the sink.
Verbose bool
// Thread ID. This can be populated with a thread ID from another source,
// such as a system we are importing logs from. In the normal case, this
// will be set to the process ID (PID), since Go doesn't have threads.
Thread int64
// Stack trace starting in the logging function. May be nil.
// A logsink should implement the StackWanter interface to request this.
//
// Even if WantStack returns false, this field may be set (e.g. if another
// sink wants a stack trace).
Stack *stackdump.Stack
}
// Structured is a logging destination that accepts structured data as input.
type Structured interface {
// Printf formats according to a fmt.Printf format specifier and writes a log
// entry. The precise result of formatting depends on the sink, but should
// aim for consistency with fmt.Printf.
//
// Printf returns the number of bytes occupied by the log entry, which
// may not be equal to the total number of bytes written.
//
// Printf returns any error encountered *if* it is severe enough that the log
// package should terminate the process.
//
// The sink must not modify the *Meta parameter, nor reference it after
// Printf has returned: it may be reused in subsequent calls.
Printf(meta *Meta, format string, a ...any) (n int, err error)
}
// StackWanter can be implemented by a logsink.Structured to indicate that it
// wants a stack trace to accompany at least some of the log messages it receives.
type StackWanter interface {
// WantStack returns true if the sink requires a stack trace for a log message
// with this metadata.
//
// NOTE: Returning true implies that meta.Stack will be non-nil. Returning
// false does NOT imply that meta.Stack will be nil.
WantStack(meta *Meta) bool
}
// Text is a logging destination that accepts pre-formatted log lines (instead of
// structured data).
type Text interface {
// Enabled returns whether this sink should output messages for the given
// Meta. If the sink returns false for a given Meta, the Printf function will
// not call Emit on it for the corresponding log message.
Enabled(*Meta) bool
// Emit writes a pre-formatted text log entry (including any applicable
// header) to the log. It returns the number of bytes occupied by the entry
// (which may differ from the length of the passed-in slice).
//
// Emit returns any error encountered *if* it is severe enough that the log
// package should terminate the process.
//
// The sink must not modify the *Meta parameter, nor reference it after
// Printf has returned: it may be reused in subsequent calls.
//
// NOTE: When developing a text sink, keep in mind the surface in which the
// logs will be displayed, and whether it's important that the sink be
// resistent to tampering in the style of b/211428300. Standard text sinks
// (like `stderrSink`) do not protect against this (e.g. by escaping
// characters) because the cases where they would show user-influenced bytes
// are vanishingly small.
Emit(*Meta, []byte) (n int, err error)
}
// bufs is a pool of *bytes.Buffer used in formatting log entries.
var bufs sync.Pool // Pool of *bytes.Buffer.
// textPrintf formats a text log entry and emits it to all specified Text sinks.
//
// The returned n is the maximum across all Emit calls.
// The returned err is the first non-nil error encountered.
// Sinks that are disabled by configuration should return (0, nil).
func textPrintf(m *Meta, textSinks []Text, format string, args ...any) (n int, err error) {
// We expect at most file, stderr, and perhaps syslog. If there are more,
// we'll end up allocating - no big deal.
const maxExpectedTextSinks = 3
var noAllocSinks [maxExpectedTextSinks]Text
sinks := noAllocSinks[:0]
for _, s := range textSinks {
if s.Enabled(m) {
sinks = append(sinks, s)
}
}
if len(sinks) == 0 && m.Severity != Fatal {
return 0, nil // No TextSinks specified; don't bother formatting.
}
bufi := bufs.Get()
var buf *bytes.Buffer
if bufi == nil {
buf = bytes.NewBuffer(nil)
bufi = buf
} else {
buf = bufi.(*bytes.Buffer)
buf.Reset()
}
// Lmmdd hh:mm:ss.uuuuuu PID/GID file:line]
//
// The "PID" entry arguably ought to be TID for consistency with other
// environments, but TID is not meaningful in a Go program due to the
// multiplexing of goroutines across threads.
//
// Avoid Fprintf, for speed. The format is so simple that we can do it quickly by hand.
// It's worth about 3X. Fprintf is hard.
const severityChar = "IWEF"
buf.WriteByte(severityChar[m.Severity])
_, month, day := m.Time.Date()
hour, minute, second := m.Time.Clock()
twoDigits(buf, int(month))
twoDigits(buf, day)
buf.WriteByte(' ')
twoDigits(buf, hour)
buf.WriteByte(':')
twoDigits(buf, minute)
buf.WriteByte(':')
twoDigits(buf, second)
buf.WriteByte('.')
nDigits(buf, 6, uint64(m.Time.Nanosecond()/1000), '0')
buf.WriteByte(' ')
nDigits(buf, 7, uint64(m.Thread), ' ')
buf.WriteByte(' ')
{
file := m.File
if i := strings.LastIndex(file, "/"); i >= 0 {
file = file[i+1:]
}
buf.WriteString(file)
}
buf.WriteByte(':')
{
var tmp [19]byte
buf.Write(strconv.AppendInt(tmp[:0], int64(m.Line), 10))
}
buf.WriteString("] ")
msgStart := buf.Len()
fmt.Fprintf(buf, format, args...)
if buf.Len() > MaxLogMessageLen-1 {
buf.Truncate(MaxLogMessageLen - 1)
}
msgEnd := buf.Len()
if b := buf.Bytes(); b[len(b)-1] != '\n' {
buf.WriteByte('\n')
}
for _, s := range sinks {
sn, sErr := s.Emit(m, buf.Bytes())
if sn > n {
n = sn
}
if sErr != nil && err == nil {
err = sErr
}
}
if m.Severity == Fatal {
savedM := *m
fatalMessageStore(savedEntry{
meta: &savedM,
msg: buf.Bytes()[msgStart:msgEnd],
})
} else {
bufs.Put(bufi)
}
return n, err
}
const digits = "0123456789"
// twoDigits formats a zero-prefixed two-digit integer to buf.
func twoDigits(buf *bytes.Buffer, d int) {
buf.WriteByte(digits[(d/10)%10])
buf.WriteByte(digits[d%10])
}
// nDigits formats an n-digit integer to buf, padding with pad on the left. It
// assumes d != 0.
func nDigits(buf *bytes.Buffer, n int, d uint64, pad byte) {
var tmp [20]byte
cutoff := len(tmp) - n
j := len(tmp) - 1
for ; d > 0; j-- {
tmp[j] = digits[d%10]
d /= 10
}
for ; j >= cutoff; j-- {
tmp[j] = pad
}
j++
buf.Write(tmp[j:])
}
// Printf writes a log entry to all registered TextSinks in this package, then
// to all registered StructuredSinks.
//
// The returned n is the maximum across all Emit and Printf calls.
// The returned err is the first non-nil error encountered.
// Sinks that are disabled by configuration should return (0, nil).
func Printf(m *Meta, format string, args ...any) (n int, err error) {
m.Depth++
n, err = textPrintf(m, TextSinks, format, args...)
for _, sink := range StructuredSinks {
// TODO: Support TextSinks that implement StackWanter?
if sw, ok := sink.(StackWanter); ok && sw.WantStack(m) {
if m.Stack == nil {
// First, try to find a stacktrace in args, otherwise generate one.
for _, arg := range args {
if stack, ok := arg.(stackdump.Stack); ok {
m.Stack = &stack
break
}
}
if m.Stack == nil {
stack := stackdump.Caller( /* skipDepth = */ m.Depth)
m.Stack = &stack
}
}
}
sn, sErr := sink.Printf(m, format, args...)
if sn > n {
n = sn
}
if sErr != nil && err == nil {
err = sErr
}
}
return n, err
}
// The sets of sinks to which logs should be written.
//
// These must only be modified during package init, and are read-only thereafter.
var (
// StructuredSinks is the set of Structured sink instances to which logs
// should be written.
StructuredSinks []Structured
// TextSinks is the set of Text sink instances to which logs should be
// written.
//
// These are registered separately from Structured sink implementations to
// avoid the need to repeat the work of formatting a message for each Text
// sink that writes it. The package-level Printf function writes to both sets
// independenty, so a given log destination should only register a Structured
// *or* a Text sink (not both).
TextSinks []Text
)
type savedEntry struct {
meta *Meta
msg []byte
}
// StructuredTextWrapper is a Structured sink which forwards logs to a set of Text sinks.
//
// The purpose of this sink is to allow applications to intercept logging calls before they are
// serialized and sent to Text sinks. For example, if one needs to redact PII from logging
// arguments before they reach STDERR, one solution would be to do the redacting in a Structured
// sink that forwards logs to a StructuredTextWrapper instance, and make STDERR a child of that
// StructuredTextWrapper instance. This is how one could set this up in their application:
//
// func init() {
//
// wrapper := logsink.StructuredTextWrapper{TextSinks: logsink.TextSinks}
// // sanitizersink will intercept logs and remove PII
// sanitizer := sanitizersink{Sink: &wrapper}
// logsink.StructuredSinks = append(logsink.StructuredSinks, &sanitizer)
// logsink.TextSinks = nil
//
// }
type StructuredTextWrapper struct {
// TextSinks is the set of Text sinks that should receive logs from this
// StructuredTextWrapper instance.
TextSinks []Text
}
// Printf forwards logs to all Text sinks registered in the StructuredTextWrapper.
func (w *StructuredTextWrapper) Printf(meta *Meta, format string, args ...any) (n int, err error) {
return textPrintf(meta, w.TextSinks, format, args...)
}
|