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.

Sign up for GitHub

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

Jump to bottom

Flaky test TestBatchProcessor/DroppedLogs #5384

Closed
pellared opened this issue May 20, 2024 · 2 comments · Fixed by #5386 or #5421
Closed

Flaky test TestBatchProcessor/DroppedLogs #5384

pellared opened this issue May 20, 2024 · 2 comments · Fixed by #5386 or #5421
Labels
area:logs Part of OpenTelemetry logs bug Something isn't working help wanted Extra attention is needed pkg:SDK Related to an SDK package
Milestone
v1.28.0

Comments

@pellared
Copy link
Member

https://github.com/open-telemetry/opentelemetry-go/actions/runs/9153962106/job/25163732175

go test -timeout 60s -short ./sdk/log/...
--- FAIL: TestBatchProcessor (0.06s)
    --- FAIL: TestBatchProcessor/DroppedLogs (0.01s)
make: *** [test/./sdk/log] Error 1
        batch_test.go:449: 
            	Error Trace:	/Users/runner/work/opentelemetry-go/opentelemetry-go/sdk/log/batch_test.go:449
            	Error:      	"" does not contain "\"level\"=1 \"msg\"=\"dropped log records\" \"dropped\"=1"
            	Test:       	TestBatchProcessor/DroppedLogs
@pellared pellared added bug Something isn't working help wanted Extra attention is needed pkg:SDK Related to an SDK package area:logs Part of OpenTelemetry logs labels May 20, 2024
MrAlias added a commit to MrAlias/opentelemetry-go that referenced this issue May 20, 2024
@MrAlias
Recheck log message in TestBatchProcessor
0dd02dc 
Fix open-telemetry#5384

On single-threaded, or in general slow, systems where the log message
may not be emitted, use assert.Everything to allow multiple lookups for
the expected log message.
@MrAlias MrAlias mentioned this issue May 20, 2024
Merged
@MrAlias MrAlias self-assigned this May 20, 2024
@MrAlias MrAlias moved this from Todo to In Progress in Go: Logs (GA) May 20, 2024
MrAlias added a commit that referenced this issue May 21, 2024
@MrAlias @XSAM
Recheck log message in TestBatchProcessor (#5386)
281aeb5 
Fix #5384

On single-threaded, or in general slow, systems where the log message
may not be emitted, use assert.Everything to allow multiple lookups for
the expected log message.

Co-authored-by: Sam Xie <sam@samxie.me>
@github-project-automation github-project-automation bot moved this from In Progress to Done in Go: Logs (GA) May 21, 2024
@pellared pellared reopened this May 22, 2024
@github-project-automation github-project-automation bot moved this from Done to Todo in Go: Logs (GA) May 22, 2024
@pellared
Copy link
Member Author

@MrAlias, it is still failing. See https://github.com/open-telemetry/opentelemetry-go/actions/runs/9184173706/job/25256066673?pr=5267

go test -timeout 60s -short ./sdk/log/...
--- FAIL: TestBatchProcessor (2.06s)
    --- FAIL: TestBatchProcessor/DroppedLogs (2.00s)
        batch_test.go:449: 
            	Error Trace:	/home/runner/work/opentelemetry-go/opentelemetry-go/sdk/log/batch_test.go:449
            	Error:      	Condition never satisfied
            	Test:       	TestBatchProcessor/DroppedLogs

@MrAlias MrAlias removed their assignment May 22, 2024
@amanakin amanakin mentioned this issue May 27, 2024
Merged
@MrAlias
Copy link
Contributor

MrAlias commented May 29, 2024

@amanakin is working on this.

@MrAlias MrAlias moved this from Todo to In Progress in Go: Logs (GA) May 29, 2024
@MrAlias MrAlias added this to the v1.28.0 milestone May 29, 2024
MrAlias pushed a commit that referenced this issue May 29, 2024
@amanakin @XSAM
sdk/log: Fix TestBatchProcessor/DroppedLogs flaky test (#5421)
982e96d 
Fix #5384

Run of `go test  -count=1000000 -run="TestBatchProcessor/DroppedLogs"`
**Before**:
Failed with either `Condition never satisfied` or panic
**After**:
Passed

First, bytes.Buffer is not thread-safe, so writing log and reading
(`bytes.String()`) caused panic. Added `concurrentBuffer`
Second, fixed flaky test with 4 records:
1. Record goes to `testExporter.Export` function and blocks in this
function because of `ExportTrigger`
(https://github.com/open-telemetry/opentelemetry-go/blob/19ee6d4775d578357e251828215213782eafed54/sdk/log/exporter_test.go#L87)
2. Record goes to `bufferExporter.input`
(https://github.com/open-telemetry/opentelemetry-go/blob/7c5e64cccc16710b2e75f3d60e96acc07dacd7a7/sdk/log/exporter.go#L129)
3. Record goes to `BatchProcessor.q` queue and it could not be enqueued
to export, because `bufferExporter.input` is full
4. Record goes to `BatchProcessor.q` and because of overfill, drops
third record

---------

Co-authored-by: Sam Xie <sam@samxie.me>
@github-project-automation github-project-automation bot moved this from In Progress to Done in Go: Logs (GA) May 29, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
area:logs Part of OpenTelemetry logs bug Something isn't working help wanted Extra attention is needed pkg:SDK Related to an SDK package
Projects
Go: Logs (GA)
Status: Done
Milestone
v1.28.0
2 participants
@pellared @MrAlias