Skip to content

Segment silently fails to flush when a subsegment is created with a closed parent #456

@danielwhite

Description

@danielwhite

If a subsegment is created where the parent segment has been closed, then the entire trace segment will fail to be flushed.

The underlying reason seems to be that Segment.openSegments becomes negative resulting in Segment.flush ignoring the segment because it will only handle a segment with exactly zero openSegments.

func (seg *Segment) flush() bool {
if (seg.openSegments == 0 && seg.EndTime > 0) || seg.ContextDone {

The current silent loss of the entire trace segment is very surprising and difficult to diagnose.

Example

A more complete test case demonstrates this:

func TestSegment_Close_out_of_order(t *testing.T) {
	ctx, td := NewTestDaemon()
	defer td.Close()
	ctx, seg := BeginSegment(ctx, "test")

	ctxSubSeg1, subSeg1 := BeginSubsegment(ctx, "TestSubsegment1")
	subSeg1.Close(nil) // closed before it is used as a parent
	_, subSeg2 := BeginSubsegment(ctxSubSeg1, "TestSubsegment2")
	subSeg2.Close(nil)

	seg.Close(nil)

	assert.Zero(t, seg.openSegments)
	assert.True(t, seg.Emitted)
}

Currently, this will fail with the following:

=== RUN   TestSegment_Close_out_of_order
2024-03-08T01:31:26+11:00 [INFO] Emitter using address: 127.0.0.1:32794
    segment_test.go:170: 
        	Error Trace:	segment_test.go:170
        	Error:      	Should be zero, but was -1
        	Test:       	TestSegment_Close_out_of_order
    segment_test.go:171: 
        	Error Trace:	segment_test.go:171
        	Error:      	Should be true
        	Test:       	TestSegment_Close_out_of_order
--- FAIL: TestSegment_Close_out_of_order (0.00s)

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions