fix(server): improve handling of unix time attributes (#3170)

.gitignore

@@ -30,3 +30,5 @@ server/html
 
 # autogenerated with `cd cli; make docgen`
 docs/docs/cli/reference/
+
+__debug*

agent/workers/poller.go

@@ -168,8 +168,8 @@ func convertTraceInToProtoSpans(trace traces.Trace) []*proto.Span {
 			ParentId:   getParentID(span),
 			Name:       span.Name,
 			Kind:       string(span.Kind),
-			StartTime:  span.StartTime.UnixMicro(),
-			EndTime:    span.EndTime.UnixMicro(),
+			StartTime:  span.StartTime.UnixNano(),
+			EndTime:    span.EndTime.UnixNano(),
 			Attributes: attributes,
 		}
 		spans = append(spans, &protoSpan)

server/executor/trigger_result_processor_worker.go

@@ -92,6 +92,7 @@ func (r triggerResultProcessorWorker) ProcessItem(ctx context.Context, job Job)
 	}
 
 	job.Run.State = test.RunStateAwaitingTrace
+
 	r.handleDBError(job.Run, r.updater.Update(ctx, job.Run))
 
 	r.outputQueue.Enqueue(ctx, job)
@@ -120,6 +121,7 @@ func (r triggerResultProcessorWorker) emitMismatchEndpointEvent(ctx context.Cont
 }
 
 func (r triggerResultProcessorWorker) handleExecutionResult(run test.Run) test.Run {
+	run = run.TriggerCompleted(run.TriggerResult)
 	if run.TriggerResult.Error != nil {
 		run = run.TriggerFailed(fmt.Errorf(run.TriggerResult.Error.ErrorMessage))
 

server/http/mappings/traces.go

@@ -2,9 +2,9 @@ package mappings
 
 import (
 	"strconv"
-	"time"
 
 	"github.com/kubeshop/tracetest/server/openapi"
+	"github.com/kubeshop/tracetest/server/pkg/timing"
 	"github.com/kubeshop/tracetest/server/traces"
 	"go.opentelemetry.io/otel/trace"
 )
@@ -81,21 +81,30 @@ func (m Model) Trace(in openapi.Trace) *traces.Trace {
 		flat[sid] = &span
 	}
 
+	tree := m.Span(in.Tree, nil)
+	if spanIsEmpty(tree) && len(flat) == 0 {
+		return nil
+	}
+
 	return &traces.Trace{
 		ID:       tid,
-		RootSpan: m.Span(in.Tree, nil),
+		RootSpan: tree,
 		Flat:     flat,
 	}
 }
 
+func spanIsEmpty(span traces.Span) bool {
+	return span.ID == trace.SpanID{} && len(span.Attributes) == 0 && span.Name == "" && len(span.Children) == 0
+}
+
 func (m Model) Span(in openapi.Span, parent *traces.Span) traces.Span {
 	sid, _ := trace.SpanIDFromHex(in.Id)
 	span := traces.Span{
 		ID:         sid,
 		Attributes: in.Attributes,
 		Name:       in.Name,
-		StartTime:  time.UnixMilli(int64(in.StartTime)),
-		EndTime:    time.UnixMilli(int64(in.EndTime)),
+		StartTime:  timing.ParseUnix(int64(in.StartTime)),
+		EndTime:    timing.ParseUnix(int64(in.EndTime)),
 		Parent:     parent,
 	}
 	span.Children = m.Spans(in.Children, &span)

server/pkg/timing/timing.go

@@ -1,7 +1,7 @@
 package timing
 
 import (
-	"math"
+	"fmt"
 	"time"
 )
 
@@ -12,25 +12,40 @@ var Now = func() time.Time {
 func TimeDiff(start, end time.Time) time.Duration {
 	var endDate time.Time
 	if !dateIsZero(end) {
-		endDate = end
+		endDate = end.UTC()
 	} else {
 		endDate = Now()
 	}
 	return endDate.Sub(start)
 }
 
-func DurationInMillieconds(d time.Duration) int {
-	return int(d.Milliseconds())
+func dateIsZero(in time.Time) bool {
+	return in.IsZero() || in.Unix() == 0
 }
 
-func DurationInNanoseconds(d time.Duration) int {
-	return int(d.Nanoseconds())
-}
+// ParseUnix parses a unix timestamp into a time.Time
+// it accepts an integer which can be either milli or nano
+func ParseUnix(timestamp int64) time.Time {
+	// Determine the number of digits in the timestamp
+	numDigits := len(fmt.Sprintf("%d", timestamp))
 
-func DurationInSeconds(d time.Duration) int {
-	return int(math.Ceil(d.Seconds()))
+	switch {
+	case numDigits <= 10:
+		// Timestamp is in seconds
+		return time.Unix(timestamp, 0)
+	case numDigits <= 13:
+		// Timestamp is in milliseconds, convert to nanoseconds and then to time.Time
+		return time.Unix(0, timestamp*int64(time.Millisecond))
+	default:
+		// Timestamp is in nanoseconds, convert directly to time.Time
+		return time.Unix(0, timestamp)
+	}
 }
 
-func dateIsZero(in time.Time) bool {
-	return in.IsZero() || in.Unix() == 0
+func MustParse(in string) time.Time {
+	date, err := time.Parse(time.RFC3339Nano, in)
+	if err != nil {
+		panic(fmt.Sprintf("error parsing date: %s", err))
+	}
+	return date
 }

server/test/run.go

@@ -9,16 +9,13 @@ import (
 	"github.com/kubeshop/tracetest/server/linter/analyzer"
 	"github.com/kubeshop/tracetest/server/pkg/id"
 	"github.com/kubeshop/tracetest/server/pkg/maps"
+	"github.com/kubeshop/tracetest/server/pkg/timing"
 	"github.com/kubeshop/tracetest/server/test/trigger"
 	"github.com/kubeshop/tracetest/server/traces"
 	"github.com/kubeshop/tracetest/server/variableset"
 )
 
 var (
-	Now = func() time.Time {
-		return time.Now().UTC()
-	}
-
 	IDGen = id.NewRandGenerator()
 )
 
@@ -28,7 +25,7 @@ func NewRun() Run {
 		TraceID:   IDGen.TraceID(),
 		SpanID:    IDGen.SpanID(),
 		State:     RunStateCreated,
-		CreatedAt: Now(),
+		CreatedAt: timing.Now(),
 	}
 }
 
@@ -43,53 +40,29 @@ func (r Run) TransactionStepResourceID() string {
 func (r Run) Copy() Run {
 	r.ID = 0
 	r.Results = nil
-	r.CreatedAt = Now()
+	r.CreatedAt = timing.Now()
 
 	return r
 }
 
 func (r Run) ExecutionTime() int {
-	return durationInSeconds(
-		timeDiff(r.CreatedAt, r.CompletedAt),
-	)
+	diff := timing.TimeDiff(r.CreatedAt, r.CompletedAt)
+	return int(math.Ceil(diff.Seconds()))
 }
 
 func (r Run) TriggerTime() int {
-	return durationInMillieconds(
-		timeDiff(r.ServiceTriggeredAt, r.ServiceTriggerCompletedAt),
-	)
-}
-
-func timeDiff(start, end time.Time) time.Duration {
-	var endDate time.Time
-	if !dateIsZero(end) {
-		endDate = end
-	} else {
-		endDate = Now()
-	}
-	return endDate.Sub(start)
-}
-
-func durationInMillieconds(d time.Duration) int {
-	return int(d.Milliseconds())
-}
-
-func durationInSeconds(d time.Duration) int {
-	return int(math.Ceil(d.Seconds()))
-}
-
-func dateIsZero(in time.Time) bool {
-	return in.IsZero() || in.Unix() == 0
+	diff := timing.TimeDiff(r.ServiceTriggeredAt, r.ServiceTriggerCompletedAt)
+	return int(diff.Milliseconds())
 }
 
 func (r Run) Start() Run {
 	r.State = RunStateExecuting
-	r.ServiceTriggeredAt = Now()
+	r.ServiceTriggeredAt = timing.Now()
 	return r
 }
 
 func (r Run) TriggerCompleted(tr trigger.TriggerResult) Run {
-	r.ServiceTriggerCompletedAt = Now()
+	r.ServiceTriggerCompletedAt = timing.Now()
 	r.TriggerResult = tr
 	return r
 }
@@ -128,7 +101,7 @@ func (r Run) SuccessfullyAsserted(
 }
 
 func (r Run) Finish() Run {
-	r.CompletedAt = Now()
+	r.CompletedAt = timing.Now()
 	return r
 }
 

server/test/run_test.go

@@ -8,6 +8,7 @@ import (
 	"github.com/kubeshop/tracetest/server/executor/testrunner"
 	"github.com/kubeshop/tracetest/server/linter/analyzer"
 	"github.com/kubeshop/tracetest/server/pkg/maps"
+	"github.com/kubeshop/tracetest/server/pkg/timing"
 	"github.com/kubeshop/tracetest/server/test"
 	"github.com/kubeshop/tracetest/server/variableset"
 	"github.com/stretchr/testify/assert"
@@ -23,49 +24,49 @@ func TestRunExecutionTime(t *testing.T) {
 		{
 			name: "CompletedOk",
 			run: test.Run{
-				CreatedAt:   time.Date(2022, 01, 25, 12, 45, 33, int(100*time.Millisecond), time.UTC),
-				CompletedAt: time.Date(2022, 01, 25, 12, 45, 36, int(400*time.Millisecond), time.UTC),
+				CreatedAt:   timing.MustParse("2022-01-25T12:45:33.100000000Z"),
+				CompletedAt: timing.MustParse("2022-01-25T12:45:36.400000000Z"),
 			},
 			expected: 4,
 		},
 		{
 			name: "LessThan1Sec",
 			run: test.Run{
-				CreatedAt:   time.Date(2022, 01, 25, 12, 45, 33, int(100*time.Millisecond), time.UTC),
-				CompletedAt: time.Date(2022, 01, 25, 12, 45, 33, int(400*time.Millisecond), time.UTC),
+				CreatedAt:   timing.MustParse("2022-01-25T12:45:33.100000000Z"),
+				CompletedAt: timing.MustParse("2022-01-25T12:45:33.400000000Z"),
 			},
 			expected: 1,
 		},
 		{
 			name: "StillRunning",
 			run: test.Run{
-				CreatedAt: time.Date(2022, 01, 25, 12, 45, 33, int(100*time.Millisecond), time.UTC),
+				CreatedAt: timing.MustParse("2022-01-25T12:45:33.100000000Z"),
 			},
-			now:      time.Date(2022, 01, 25, 12, 45, 34, int(300*time.Millisecond), time.UTC),
+			now:      timing.MustParse("2022-01-25T12:45:34.300000000Z"),
 			expected: 2,
 		},
 		{
 			name: "ZeroedDate",
 			run: test.Run{
-				CreatedAt:   time.Date(2022, 01, 25, 12, 45, 33, int(100*time.Millisecond), time.UTC),
+				CreatedAt:   timing.MustParse("2022-01-25T12:45:33.100000000Z"),
 				CompletedAt: time.Unix(0, 0),
 			},
-			now:      time.Date(2022, 01, 25, 12, 45, 34, int(300*time.Millisecond), time.UTC),
+			now:      timing.MustParse("2022-01-25T12:45:34.300000000Z"),
 			expected: 2,
 		},
 	}
 
 	for _, c := range cases {
 		t.Run(c.name, func(t *testing.T) {
-			now := test.Now
+			now := timing.Now
 			if c.now.Unix() > 0 {
-				test.Now = func() time.Time {
+				timing.Now = func() time.Time {
 					return c.now
 				}
 			}
 
 			assert.Equal(t, c.expected, c.run.ExecutionTime())
-			test.Now = now
+			timing.Now = now
 		})
 	}
 }
@@ -80,49 +81,49 @@ func TestRunTriggerTime(t *testing.T) {
 		{
 			name: "CompletedOk",
 			run: test.Run{
-				ServiceTriggeredAt:        time.Date(2022, 01, 25, 12, 45, 33, int(100*time.Millisecond), time.UTC),
-				ServiceTriggerCompletedAt: time.Date(2022, 01, 25, 12, 45, 36, int(400*time.Millisecond), time.UTC),
+				ServiceTriggeredAt:        timing.MustParse("2022-01-25T12:45:33.100000000Z"),
+				ServiceTriggerCompletedAt: timing.MustParse("2022-01-25T12:45:36.400000000Z"),
 			},
 			expected: 3300,
 		},
 		{
 			name: "LessThan1Sec",
 			run: test.Run{
-				ServiceTriggeredAt:        time.Date(2022, 01, 25, 12, 45, 33, int(100*time.Millisecond), time.UTC),
-				ServiceTriggerCompletedAt: time.Date(2022, 01, 25, 12, 45, 33, int(400*time.Millisecond), time.UTC),
+				ServiceTriggeredAt:        timing.MustParse("2022-01-25T12:45:33.100000000Z"),
+				ServiceTriggerCompletedAt: timing.MustParse("2022-01-25T12:45:33.400000000Z"),
 			},
 			expected: 300,
 		},
 		{
 			name: "StillRunning",
 			run: test.Run{
-				ServiceTriggeredAt: time.Date(2022, 01, 25, 12, 45, 33, int(100*time.Millisecond), time.UTC),
+				ServiceTriggeredAt: timing.MustParse("2022-01-25T12:45:33.100000000Z"),
 			},
-			now:      time.Date(2022, 01, 25, 12, 45, 34, int(300*time.Millisecond), time.UTC),
+			now:      timing.MustParse("2022-01-25T12:45:34.300000000Z"),
 			expected: 1200,
 		},
 		{
 			name: "ZeroedDate",
 			run: test.Run{
-				ServiceTriggeredAt:        time.Date(2022, 01, 25, 12, 45, 33, int(100*time.Millisecond), time.UTC),
+				ServiceTriggeredAt:        timing.MustParse("2022-01-25T12:45:33.100000000Z"),
 				ServiceTriggerCompletedAt: time.Unix(0, 0),
 			},
-			now:      time.Date(2022, 01, 25, 12, 45, 34, int(300*time.Millisecond), time.UTC),
+			now:      timing.MustParse("2022-01-25T12:45:34.300000000Z"),
 			expected: 1200,
 		},
 	}
 
 	for _, c := range cases {
 		t.Run(c.name, func(t *testing.T) {
-			now := test.Now
+			now := timing.Now
 			if c.now.Unix() > 0 {
-				test.Now = func() time.Time {
+				timing.Now = func() time.Time {
 					return c.now
 				}
 			}
 
 			assert.Equal(t, c.expected, c.run.TriggerTime())
-			test.Now = now
+			timing.Now = now
 		})
 	}
 }