[exporter/elasticsearch] Integration test TestExporter failing

[crobert-1]

Component(s)

exporter/elasticsearch

Describe the issue you're reporting

Failing CI/CD action link

This failure occurred on Windows, I'm not sure if it's related or not.

Failure output: (Note that multiple tests are failing, all with similar failure output, so I'm just including one here)

=== FAIL: . TestExporter/traces/es_intermittent_failure (re-run 1) (17.75s)
    exporter_test.go:37: test otel collector configuration: 
        receivers:
          otlp:
            protocols:
              grpc:
                endpoint: "127.0.0.1:61686"
        exporters:
          elasticsearch:
            endpoints: [http://127.0.0.1:61687/]
            logs_index: logs-test-idx
            traces_index: traces-test-idx
            flush:
              interval: 1s
            sending_queue:
              enabled: true
            retry:
              enabled: true
              max_requests: 10000
        
          debug:
            verbosity: basic
        
        processors:
          
        
        extensions:
          
        
        service:
          telemetry:
            metrics:
              address: 127.0.0.1:61688
          extensions: []
          pipelines:
            traces:
              receivers: [otlp]
              processors: []
              exporters: [elasticsearch]
        
2024/07/11 15:03:45 Starting mock backend...
2024-07-11T15:03:45.471Z	info	[email protected]/service.go:115	Setting up own telemetry...
2024-07-11T15:03:45.473Z	info	[email protected]/telemetry.go:96	Serving metrics	{"address": "127.0.0.1:61688", "metrics level": "Normal"}
2024-07-11T15:03:45.475Z	warn	elasticsearchexporter/config.go:329	dedot has been deprecated: in the future, dedotting will always be performed in ECS mode only	{"kind": "exporter", "data_type": "traces", "name": "elasticsearch"}
2024-07-11T15:03:45.478Z	info	[email protected]/service.go:193	Starting otelcol...	{"Version": "latest", "NumCPU": 4}
2024-07-11T15:03:45.478Z	info	extensions/extensions.go:34	Starting extensions...
2024-07-11T15:03:45.479Z	info	[email protected]/otlp.go:102	Starting GRPC server	{"kind": "receiver", "name": "otlp", "data_type": "traces", "endpoint": "127.0.0.1:61686"}
2024-07-11T15:03:45.479Z	info	[email protected]/service.go:219	Everything is ready. Begin running and processing data.
2024-07-11T15:03:45.479Z	info	localhostgate/featuregate.go:63	The default endpoints for all servers in components have changed to use localhost instead of 0.0.0.0. Disable the feature gate to temporarily revert to the previous default.	{"feature gate ID": "component.UseLocalHostAsDefaultHost"}
2024/07/11 15:03:46 Starting load generator at 1000 items/sec.
2024/07/11 15:03:48  | Sent:     1,620 traces (811/sec) | Received:       797 items (265/sec)
2024/07/11 15:03:51  | Sent:     4,170 traces (834/sec) | Received:     3,400 items (566/sec)
2024/07/11 15:03:52 Stopped generator. Sent:     5,000 traces ([832](https://github.com/open-telemetry/opentelemetry-collector-contrib/actions/runs/9893603717/job/27329120354#step:6:833)/sec)
2024/07/11 15:03:54  | Sent:     5,000 traces (624/sec) | Received:     4,990 items (553/sec)
2024/07/11 15:03:57  | Sent:     5,000 traces (454/sec) | Received:     4,990 items (415/sec)
2024/07/11 15:04:00  | Sent:     5,000 traces (356/sec) | Received:     4,990 items (332/sec)
2024/07/11 15:04:02 Time out waiting for backend should receive all sent items
    test_case.go:289: Time out waiting for backend should receive all sent items
2024-07-11T15:04:02.[833](https://github.com/open-telemetry/opentelemetry-collector-contrib/actions/runs/9893603717/job/27329120354#step:6:834)Z	info	[email protected]/collector.go:331	Received shutdown request
2024-07-11T15:04:02.833Z	info	[email protected]/service.go:256	Starting shutdown...
2024-07-11T15:04:02.[834](https://github.com/open-telemetry/opentelemetry-collector-contrib/actions/runs/9893603717/job/27329120354#step:6:835)Z	info	extensions/extensions.go:59	Stopping extensions...
2024-07-11T15:04:02.834Z	info	[email protected]/service.go:270	Shutdown complete.
2024/07/11 15:04:02 Stopping mock backend...
2024/07/11 15:04:02 Stopped backend. Received:     4,990 items (287/sec)

=== FAIL: . TestExporter (re-run 1) (17.75s)

[github-actions]

Pinging code owners:

• exporter/elasticsearch: @JaredTan95 @ycombinator @carsonip

See Adding Labels via Comments if you do not have permissions to add labels yourself.

[carsonip]

ack, will look into it soon.

[crobert-1]

+1 freq: https://github.com/open-telemetry/opentelemetry-collector-contrib/actions/runs/9895354454/job/27335178983#step:5:714

[lahsivjar]

I am able to reproduce this locally. Working on this actively to dig the root cause, will put a fix soon.

[lahsivjar]

There is a bug in the ProviderSender load generator (ref)

	logData, done := ps.Provider.GenerateLogs()
	if done {
		return nil
	}

	for {
		select {
		case <-ps.stopSignal:
			return nil
		default:
			err := logSender.ConsumeLogs(context.Background(), logData)

The generated count is incremented when GenerateLogs() is called but if the stop signal has been received then the last generated logs will never be consumed and thus just disappear from accounting. Created an issue: #34057. I am working on a fix.

[lahsivjar]

Fix PR is up: #34061

[atoulme]

Happening on ubuntu as well: https://github.com/open-telemetry/opentelemetry-collector-contrib/actions/runs/9909907422/job/27396469852?pr=33224

[TylerHelmuth]

Another: https://github.com/open-telemetry/opentelemetry-collector-contrib/actions/runs/9914250968/job/27413995744

[lahsivjar]

This should be fixed with #34061.

[crobert-1]

I'll close for now and we can reopen if it continues failing. Thanks for fixing @lahsivjar!