Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Merged
merged 3 commits into from
Sep 20, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions .gitignore
Original file line number Diff line number Diff line change
Expand Up @@ -30,3 +30,5 @@ server/html

# autogenerated with `cd cli; make docgen`
docs/docs/cli/reference/

__debug*
4 changes: 2 additions & 2 deletions agent/workers/poller.go
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Expand Down
2 changes: 2 additions & 0 deletions server/executor/trigger_result_processor_worker.go
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Expand Down Expand Up @@ -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))

Expand Down
17 changes: 13 additions & 4 deletions server/http/mappings/traces.go
Original file line number Diff line number Diff line change
Expand Up @@ -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"
)
Expand Down Expand Up @@ -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)
Expand Down
37 changes: 26 additions & 11 deletions server/pkg/timing/timing.go
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
package timing

import (
"math"
"fmt"
"time"
)

Expand All @@ -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
}
47 changes: 10 additions & 37 deletions server/test/run.go
Original file line number Diff line number Diff line change
Expand Up @@ -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()
)

Expand All @@ -28,7 +25,7 @@ func NewRun() Run {
TraceID: IDGen.TraceID(),
SpanID: IDGen.SpanID(),
State: RunStateCreated,
CreatedAt: Now(),
CreatedAt: timing.Now(),
}
}

Expand All @@ -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
}
Expand Down Expand Up @@ -128,7 +101,7 @@ func (r Run) SuccessfullyAsserted(
}

func (r Run) Finish() Run {
r.CompletedAt = Now()
r.CompletedAt = timing.Now()
return r
}

Expand Down
45 changes: 23 additions & 22 deletions server/test/run_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand All @@ -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
})
}
}
Expand All @@ -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
})
}
}
Expand Down
Loading
Loading