Skip to content

Commit 8f4bbab

Browse files
authored
Set shutdown timeout for beat receivers to 5s by default (#51940)
Beat receivers need a longer timeout than the default 1s, as it needs to exceed the batcher flush timeout. The current code gives the impression of this already happening, but in reality, if the beater handles pipeline shutdown on its own, the default timeout wins.
1 parent 8674b2f commit 8f4bbab

2 files changed

Lines changed: 105 additions & 0 deletions

File tree

x-pack/filebeat/fbreceiver/receiver_test.go

Lines changed: 93 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -20,12 +20,16 @@ import (
2020
"runtime"
2121
"strconv"
2222
"strings"
23+
"sync"
2324
"sync/atomic"
2425
"testing"
2526
"time"
2627

2728
"github.com/gofrs/uuid/v5"
29+
"go.opentelemetry.io/collector/component/componenttest"
30+
"go.opentelemetry.io/collector/consumer"
2831
"go.opentelemetry.io/collector/pdata/pcommon"
32+
"go.opentelemetry.io/collector/pdata/plog"
2933

3034
"github.com/stretchr/testify/assert"
3135
"github.com/stretchr/testify/require"
@@ -699,6 +703,95 @@ func TestConsumeContract(t *testing.T) {
699703
})
700704
}
701705

706+
// TestShutdownDrainTimeout is a regression test for the filebeat receiver
707+
// shutdown drain duration.
708+
//
709+
// The slow consumer blocks until the drain context is cancelled, so the
710+
// elapsed shutdown time equals the drain timeout. We only assert a lower bound
711+
// (>= receiverPublisherCloseTimeout - 500ms) rather than an upper bound, so
712+
// the test never flakes due to CI load while still catching any regression that
713+
// reduces the drain timeout below the expected value.
714+
func TestShutdownDrainTimeout(t *testing.T) {
715+
defer oteltest.VerifyNoLeaks(t)
716+
717+
tmpDir := t.TempDir()
718+
logFile := filepath.Join(tmpDir, "input.log")
719+
for range 20 {
720+
writeFile(t, logFile, `{"message": "drain timeout test"}`)
721+
}
722+
723+
consumerCalledCh := make(chan struct{})
724+
var consumerCalledOnce sync.Once
725+
slowConsumer, err := consumer.NewLogs(func(ctx context.Context, _ plog.Logs) error {
726+
consumerCalledOnce.Do(func() { close(consumerCalledCh) })
727+
select {
728+
case <-ctx.Done():
729+
return ctx.Err()
730+
case <-time.After(30 * time.Second):
731+
return nil
732+
}
733+
})
734+
require.NoError(t, err)
735+
736+
cfg := &Config{
737+
Beatconfig: map[string]any{
738+
"queue.mem.flush.timeout": "0s",
739+
"filebeat": map[string]any{
740+
"inputs": []map[string]any{
741+
{
742+
"type": "filestream",
743+
"enabled": true,
744+
"id": "drain-timeout-test",
745+
"paths": []string{logFile},
746+
"file_identity.native": map[string]any{},
747+
"prospector": map[string]any{
748+
"scanner": map[string]any{
749+
"check_interval": "50ms",
750+
"fingerprint.enabled": false,
751+
},
752+
},
753+
},
754+
},
755+
},
756+
"path.home": tmpDir,
757+
"path.logs": tmpDir,
758+
"logging": map[string]any{"level": "info"},
759+
},
760+
}
761+
762+
factory := NewFactoryWithSettings(Settings{Home: tmpDir})
763+
var settings receiver.Settings
764+
settings.ID = component.NewIDWithName(factory.Type(), "r1")
765+
settings.Logger = zap.NewNop()
766+
767+
r, err := factory.CreateLogs(t.Context(), settings, cfg, slowConsumer)
768+
require.NoError(t, err)
769+
require.NoError(t, r.Start(t.Context(), componenttest.NewNopHost()))
770+
771+
// Guard: wait until events are in flight before triggering shutdown.
772+
// Without this, shutdown starts before any batches exist and the drain
773+
// completes trivially fast, making the test a no-op.
774+
select {
775+
case <-consumerCalledCh:
776+
case <-time.After(30 * time.Second):
777+
t.Fatal("ConsumeLogs was never called; events never reached the pipeline")
778+
}
779+
780+
start := time.Now()
781+
require.NoError(t, r.Shutdown(t.Context()))
782+
elapsed := time.Since(start)
783+
784+
// Only a lower bound: CI load can make wall-clock time arbitrarily large,
785+
// so an upper bound would cause spurious failures on loaded runners.
786+
const (
787+
receiverPublisherCloseTimeout = 5 * time.Second
788+
minExpected = receiverPublisherCloseTimeout - 500*time.Millisecond
789+
)
790+
assert.GreaterOrEqual(t, elapsed, minExpected,
791+
"shutdown completed in %v, expected >= %v; was shutdown_timeout injection removed?",
792+
elapsed, minExpected)
793+
}
794+
702795
func TestReceiverHook(t *testing.T) {
703796
cfg := Config{
704797
Beatconfig: map[string]any{

x-pack/libbeat/cmd/instance/beat.go

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -97,6 +97,18 @@ func NewBeatForReceiver(settings instance.Settings, receiverConfig map[string]an
9797
logger.Warnf("Output configuration is not supported by Beats receivers. Configure output behavior via exporter settings.")
9898
}
9999

100+
// Set the default shutdown timeout to 5s. The beat default is 1s, which can be too short for the otel pipeline.
101+
switch beatSection := receiverConfig[b.Info.Beat].(type) {
102+
case map[string]any:
103+
if _, alreadySet := beatSection["shutdown_timeout"]; !alreadySet {
104+
beatSection["shutdown_timeout"] = receiverPublisherCloseTimeout.String()
105+
}
106+
case nil:
107+
receiverConfig[b.Info.Beat] = map[string]any{
108+
"shutdown_timeout": receiverPublisherCloseTimeout.String(),
109+
}
110+
}
111+
100112
tmp, err := ucfg.NewFrom(receiverConfig, cfOpts...)
101113
if err != nil {
102114
return nil, fmt.Errorf("error converting receiver config to ucfg: %w", err)

0 commit comments

Comments
 (0)