Merge pull request #67 from muir/fiftyfive

simplify time formats

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
 

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

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=

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,

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")
-)
-*/

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) {

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) {

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),

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
+}