diff --git a/TODO.md b/TODO.md index 899b2d8a..41721766 100644 --- a/TODO.md +++ b/TODO.md @@ -52,9 +52,21 @@ # Just do it (build ready) -- simplify time formatting in xopjson: instead of current options, allow user to pass in a time format function +- redaction - `WithTimeFormat(func(time.Time, []byte) []byte)` + - add log setting for redacting Any types. + + `type RedactAnyFunc(*Log, key string, value interface{}) interface{}` + + The idea being that it can log an additional thing if it wants + + - add log setting for redacting string types. + + `type RedactAnyFunc(*Log, key string, value string) string` + + The idea being that it can log an additional thing if it wants + + - add redaction option to pre-registering attributes. - dictionary support diff --git a/go.mod b/go.mod index 37e50a07..018eccfc 100644 --- a/go.mod +++ b/go.mod @@ -7,7 +7,7 @@ require ( github.com/gorilla/mux v1.8.0 github.com/mohae/deepcopy v0.0.0-20170929034955-c48cc78d4826 github.com/muir/rest v0.0.0-20210822233606-6d02fb885933 - github.com/phuslu/fasttime v1.0.0 + github.com/phuslu/fasttime v1.0.2 github.com/stretchr/testify v1.8.0 go.opentelemetry.io/otel v1.10.0 go.opentelemetry.io/otel/exporters/stdout/stdouttrace v1.10.0 diff --git a/go.sum b/go.sum index 8c27d80c..18ebcee6 100644 --- a/go.sum +++ b/go.sum @@ -18,6 +18,8 @@ github.com/muir/rest v0.0.0-20210822233606-6d02fb885933 h1:gBIILIoUpMUWpQNSRdVSz github.com/muir/rest v0.0.0-20210822233606-6d02fb885933/go.mod h1:sUUGdWPRJgmDYo14DPXmZbkyqPOuy+Ec1gaEnhRuu0I= github.com/phuslu/fasttime v1.0.0 h1:SUkNta9tJLy54glGb/Z4+/NJ7aXiLogVuSPEXAya6i8= github.com/phuslu/fasttime v1.0.0/go.mod h1:1zflhZFowg3RSL0IpmWQ0AprKCKbTRKV9PEpVXDBZ7A= +github.com/phuslu/fasttime v1.0.2 h1:gmD27yB6vnQuhk4vtmoBOmjaXsF+wwmyjMtayoHHUko= +github.com/phuslu/fasttime v1.0.2/go.mod h1:1zflhZFowg3RSL0IpmWQ0AprKCKbTRKV9PEpVXDBZ7A= github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4= github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= diff --git a/logger.go b/logger.go index 0a2cf677..27670387 100644 --- a/logger.go +++ b/logger.go @@ -13,14 +13,14 @@ import ( ) type Log struct { - request *Log // The ancestor request-level Log - span *span // span associated with this Log - capSpan *Span // Span associated with this Log - parent *Log // immediate parent Log - shared *shared // shared between logs with same request-level Log - settings LogSettings // settings for this Log - prefilled xopbase.Prefilled // XXX double-check, in request? - nonSpanSubLog bool // true if created by log.Sub().Log() + request *Log // The ancestor request-level Log + span *span // span associated with this Log + capSpan *Span // Span associated with this Log + parent *Log // immediate parent Log + shared *shared // shared between logs with same request-level Log + settings LogSettings // settings for this Log + nonSpanSubLog bool // true if created by log.Sub().Log() + prefilled xopbase.Prefilled } type Span struct { @@ -70,7 +70,6 @@ func (seed Seed) request(descriptionOrName string) *Log { alloc := singleAlloc{ Log: Log{ settings: seed.settings.Copy(), - // XXX prefilled? }, span: span{ seed: seed.spanSeed.copy(false), @@ -128,7 +127,6 @@ func (sub *Sub) Log() *Log { shared: sub.log.shared, settings: sub.settings, nonSpanSubLog: true, - // XXX prefilled? }, Span: Span{ span: sub.log.span, @@ -156,7 +154,6 @@ func (old *Log) newChildLog(seed Seed, description string, detached bool) *Log { parent: old, shared: old.shared, settings: seed.settings, - // XXX prefilled? }, span: span{ seed: seed.spanSeed, diff --git a/xopconst/standard.go b/xopconst/standard.go index 5861a3c9..447fb152 100644 --- a/xopconst/standard.go +++ b/xopconst/standard.go @@ -31,16 +31,3 @@ var ( SpanTypeHTTPClientRequest = SpanType.Iota("REST") SpanTypeCronJob = SpanType.Iota("cron_job") ) - -/* -XXX -var LineType = xopat.Make{Key: "line.type", Namespace: "xop", Indexed: false, Prominence: 30, - Description: "what kind of log line this is. Often added automatically."}. - EmbeddedEnumAttribute() - -var ( - LineTypeDefault = SpanType.Iota("line") // omitted - LineTypeRequest = SpanType.Iota("REST") - LineTypeTable = SpanType.Iota("table") -) -*/ diff --git a/xopjson/jsonlogger.go b/xopjson/jsonlogger.go index bad2a567..faf8139a 100644 --- a/xopjson/jsonlogger.go +++ b/xopjson/jsonlogger.go @@ -18,7 +18,6 @@ import ( "github.com/muir/xop-go/xoputil" "github.com/google/uuid" - "github.com/phuslu/fasttime" ) const ( @@ -29,10 +28,10 @@ const ( func New(w xopbytes.BytesWriter, opts ...Option) *Logger { log := &Logger{ - writer: w, - id: uuid.New(), - timeDivisor: time.Microsecond, - closeRequest: make(chan struct{}), + writer: w, + id: uuid.New(), + closeRequest: make(chan struct{}), + timeFormatter: defaultTimeFormatter, } prealloc := xoputil.NewPrealloc(log.preallocatedKeys[:]) for _, f := range opts { @@ -555,22 +554,7 @@ func (b *builder) Time(k string, t time.Time) { } func (b *builder) AddTime(t time.Time) { - switch b.span.logger.timeOption { - case strftimeTime: - b.AppendByte('"') - b.B = fasttime.AppendStrftime(b.B, b.span.logger.timeFormat, t) - b.AppendByte('"') - case timeTimeFormat: - b.AppendByte('"') - b.B = t.AppendFormat(b.B, b.span.logger.timeFormat) - b.AppendByte('"') - case epochTime: - b.AddInt64(t.UnixNano() / int64(b.span.logger.timeDivisor)) - case epochQuoted: - b.AppendByte('"') - b.AddInt64(t.UnixNano() / int64(b.span.logger.timeDivisor)) - b.AppendByte('"') - } + b.B = b.span.logger.timeFormatter(b.B, t) } func (b *builder) Link(k string, v trace.Trace) { diff --git a/xopjson/jsonlogger.zzzgo b/xopjson/jsonlogger.zzzgo index 5a2d6353..54f513cc 100644 --- a/xopjson/jsonlogger.zzzgo +++ b/xopjson/jsonlogger.zzzgo @@ -26,10 +26,10 @@ const ( func New(w xopbytes.BytesWriter, opts ...Option) *Logger { log := &Logger{ - writer: w, - id: uuid.New(), - timeDivisor: time.Microsecond, - closeRequest: make(chan struct{}), + writer: w, + id: uuid.New(), + closeRequest: make(chan struct{}), + timeFormatter: defaultTimeFormatter, } prealloc := xoputil.NewPrealloc(log.preallocatedKeys[:]) for _, f := range opts { @@ -552,22 +552,7 @@ func (b *builder) Time(k string, t time.Time) { } func (b *builder) AddTime(t time.Time) { - switch b.span.logger.timeOption { - case strftimeTime: - b.AppendByte('"') - b.B = fasttime.AppendStrftime(b.B, b.span.logger.timeFormat, t) - b.AppendByte('"') - case timeTimeFormat: - b.AppendByte('"') - b.B = t.AppendFormat(b.B, b.span.logger.timeFormat) - b.AppendByte('"') - case epochTime: - b.AddInt64(t.UnixNano() / int64(b.span.logger.timeDivisor)) - case epochQuoted: - b.AppendByte('"') - b.AddInt64(t.UnixNano() / int64(b.span.logger.timeDivisor)) - b.AppendByte('"') - } + b.B = b.span.logger.timeFormatter(b.B, t) } func (b *builder) Link(k string, v trace.Trace) { diff --git a/xopjson/jsonlogger_test.go b/xopjson/jsonlogger_test.go index 6b43b1a6..8c6c81b7 100644 --- a/xopjson/jsonlogger_test.go +++ b/xopjson/jsonlogger_test.go @@ -82,7 +82,6 @@ func TestASingleLine(t *testing.T) { var buffer xoputil.Buffer jlog := xopjson.New( xopbytes.WriteToIOWriter(&buffer), - xopjson.WithEpochTime(time.Microsecond), xopjson.WithDuration("dur", xopjson.AsString), xopjson.WithSpanTags(xopjson.SpanIDTagOption), xopjson.WithAttributesObject(true), @@ -173,7 +172,6 @@ func TestParameters(t *testing.T) { t.Run(mc.Name, func(t *testing.T) { var buffer xoputil.Buffer joptions := []xopjson.Option{ - xopjson.WithTimeFormat(time.RFC3339Nano), xopjson.WithDuration("dur", xopjson.AsNanos), xopjson.WithSpanStarts(true), xopjson.WithBufferedLines(8 * 1024 * 1024), diff --git a/xopjson/models.go b/xopjson/models.go index f0aed9e0..2d15b03b 100644 --- a/xopjson/models.go +++ b/xopjson/models.go @@ -23,23 +23,28 @@ var _ xopbase.Prefilled = &prefilled{} type Option func(*Logger, *xoputil.Prealloc) -type timeOption int - -const ( - epochTime timeOption = iota - epochQuoted - strftimeTime - timeTimeFormat -) +// TimeFormatter is the function signature for custom time formatters +// if anything other than time.RFC3339Nano is desired. The value must +// be appended to the byte slice (which must be returned). +// +// For example: +// +// func timeFormatter(b []byte, t time.Time) []byte { +// b = append(b, '"') +// b = append(b, []byte(t.Format(time.RFC3339))...) +// b = append(b, '"') +// return b +// } +// +// The slice may not be safely accessed outside of the duration of the +// call. The only acceptable operation on the slice is to append. +type TimeFormatter func(b []byte, t time.Time) []byte type Logger struct { writer xopbytes.BytesWriter withGoroutine bool fastKeys bool durationFormat DurationOption - timeOption timeOption - timeFormat string - timeDivisor time.Duration spanStarts bool spanChangesOnly bool id uuid.UUID @@ -53,6 +58,7 @@ type Logger struct { preallocatedKeys [100]byte durationKey []byte stackLineRewrite func(string) string + timeFormatter TimeFormatter // TODO: prefilledPool sync.Pool // TODO: timeKey []byte // TODO: timestampKey []byte @@ -120,7 +126,9 @@ const ( ) // WithDuration specifies the format used for durations. If -// set, durations will be recorded for spans and requests. +// set, durations will be recorded for spans and requests. If not +// set, durations explicitly recorded will be recoreded as nanosecond +// numbers. func WithDuration(key string, durationFormat DurationOption) Option { return func(l *Logger, p *xoputil.Prealloc) { l.durationKey = p.Pack(xoputil.BuildKey(key)) @@ -216,53 +224,15 @@ func WithAttributesObject(b bool) Option { // TODO: allow custom error formats -// WithStrftime specifies how to format timestamps. -// See // https://github.com/phuslu/fasttime for the supported -// formats. -func WithStrftime(format string) Option { - return func(l *Logger, _ *xoputil.Prealloc) { - l.timeOption = strftimeTime - l.timeFormat = format - } -} - -// WithTimeFormat specifies the use of the "time" package's -// Time.Format for formatting times. -func WithTimeFormat(format string) Option { - return func(l *Logger, _ *xoputil.Prealloc) { - l.timeOption = timeTimeFormat - l.timeFormat = format - } -} - -// WithEpochTime specifies that time values are formatted as an -// integer time since Jan 1 1970. If the units is seconds, then -// it is seconds since Jan 1 1970. If the units is nanoseconds, -// then it is nanoseconds since Jan 1 1970. Etc. +// WithTimeFormatter specifies how time.Time should be +// serialized to JSON. The default is time.RFC3339Nano. // -// Note that the JSON specification specifies int's are 32 bits, -// not 64 bits so a compliant JSON parser could fail for seconds -// since 1970 starting in year 2038. For microseconds, and -// nanoseconds, a complicant parser alerady fails. -func WithEpochTime(units time.Duration) Option { +// Note: if serializing as a number, integers beyond 2^50 +// may lose precision because they're actually read as +// float64s. +func WithTimeFormatter(formatter TimeFormatter) Option { return func(l *Logger, _ *xoputil.Prealloc) { - l.timeOption = epochTime - l.timeDivisor = units - } -} - -// WithQuotedEpochTime specifies that time values are formatted an -// integer string (integer with quotes around it) representing time -// since Jan 1 1970. If the units is seconds, then -// it is seconds since Jan 1 1970. If the units is nanoseconds, -// then it is nanoseconds since Jan 1 1970. Etc. -// -// Note most JSON parsers can parse into an integer if given a -// a quoted integer. -func WithQuotedEpochTime(units time.Duration) Option { - return func(l *Logger, _ *xoputil.Prealloc) { - l.timeOption = epochQuoted - l.timeDivisor = units + l.timeFormatter = formatter } } @@ -294,3 +264,19 @@ func WithStackLineRewrite(f func(string) string) Option { // The default encoding is simply a string: error.Error(). // // TODO + +/* TODO +func defaultTimeFormatter2(b []byte, t time.Time) []byte { + b = append(b, '"') + b = fasttime.AppendStrftime(b, fasttime.RFC3339Nano, t) + b = append(b, '"') + return b +} +*/ + +func defaultTimeFormatter(b []byte, t time.Time) []byte { + b = append(b, '"') + b = append(b, []byte(t.Format(time.RFC3339Nano))...) + b = append(b, '"') + return b +}