[Filebeat] Filebeat process does not exit when stopping with CTRL-C #22813

marc-gr · 2020-12-01T11:37:33Z

Whenever an input is making use of a registry, filebeat fails to stop when CTRl-C is hit, and instead it keeps sending monitoring data, forcing you to either suspend and kill or kill the process from another session.

After some digging it seems to hang on https://github.com/elastic/beats/pull/19633/files#diff-97b65fad069be1072219d7ae6a1e8f64d287e8cb6c1f4e424c801a22200db104R233 while it waits for a reference to the registry to be released (was reclaimed 5 times and released 4 on my tests, for example), causing it to wait forever.

For confirmed bugs, please report:

Version: master
Operating System: macOS but also reproduced on linux
Steps to Reproduce:
- Configure an input that makes use of v2/cursor (registry)
- Start filebeat ./filebeat -e -v
- Hit CTRL-C
- The process then stops the input but it does not exit and keeps sending monitoring data instead, you need to kill/suspend it from another terminal

Logs of the issue:

2020-12-01T11:53:03.358+0100    INFO    instance/beat.go:635    Home path: [/go/src/github.com/elastic/beats/x-pack/filebeat] Config path: [/go/src/github.com/elastic/beats/x-pack/filebeat] Data path: [/go/src/github.com/elastic/beats/x-pack/filebeat/data] Logs path: [/go/src/github.com/elastic/beats/x-pack/filebeat/logs]
2020-12-01T11:53:03.358+0100    INFO    instance/beat.go:643    Beat ID: 6431981c-d1bd-4a93-bfd3-2fdc59f9e117
2020-12-01T11:53:03.358+0100    INFO    [beat]  instance/beat.go:964    Beat info       {"system_info": {"beat": {"path": {"config": "/go/src/github.com/elastic/beats/x-pack/filebeat", "data": "/go/src/github.com/elastic/beats/x-pack/filebeat/data", "home": "/go/src/github.com/elastic/beats/x-pack/filebeat", "logs": "/go/src/github.com/elastic/beats/x-pack/filebeat/logs"}, "type": "filebeat", "uuid": "6431981c-d1bd-4a93-bfd3-2fdc59f9e117"}}}
2020-12-01T11:53:03.358+0100    INFO    [beat]  instance/beat.go:973    Build info      {"system_info": {"build": {"commit": "488d194fa3a25cc4696a9a3bfcd77d3cf6ca748a", "libbeat": "8.0.0", "time": "2020-12-01T10:37:07.000Z", "version": "8.0.0"}}}
2020-12-01T11:53:03.359+0100    INFO    [beat]  instance/beat.go:976    Go runtime info {"system_info": {"go": {"os":"darwin","arch":"amd64","max_procs":16,"version":"go1.15.5"}}}
2020-12-01T11:53:03.359+0100    INFO    [beat]  instance/beat.go:980    Host info       {"system_info": {"host": {"architecture":"x86_64","boot_time":"2020-11-30T15:28:34.344197+01:00","name":"mbp.local","ip":["127.0.0.1/8","::1/128","fe80::1/64","fe80::aede:48ff:fe00:1122/64","fe80::109a:2b6b:9c4a:b75d/64","192.168.1.48/24","fe80::a82f:2eff:fea7:8486/64","fe80::a82f:2eff:fea7:8486/64","fe80::5f3c:8fda:844d:69b5/64","fe80::53f0:9c48:7e23:66ac/64"],"kernel_version":"19.6.0","mac":["ac:de:48:00:11:22","3e:22:fb:69:40:0f","3c:22:fb:69:40:0f","0e:22:fb:69:40:0f","aa:2f:2e:a7:84:86","aa:2f:2e:a7:84:86","82:65:fe:85:18:00","82:65:fe:85:18:01","82:65:fe:85:18:05","82:65:fe:85:18:04","82:65:fe:85:18:01"],"os":{"family":"darwin","platform":"darwin","name":"Mac OS X","version":"10.15.7","major":10,"minor":15,"patch":7,"build":"19H15"},"timezone":"CET","timezone_offset_sec":3600,"id":"350C4D9A-8A01-5D44-A8B6-9F6BD1B8C402"}}}
2020-12-01T11:53:03.359+0100    INFO    [beat]  instance/beat.go:1009   Process info    {"system_info": {"process": {"cwd": "/go/src/github.com/elastic/beats/x-pack/filebeat", "exe": "./filebeat", "name": "filebeat", "pid": 35019, "ppid": 20951, "start_time": "2020-12-01T11:53:03.290+0100"}}}
2020-12-01T11:53:03.359+0100    INFO    instance/beat.go:300    Setup Beat: filebeat; Version: 8.0.0
2020-12-01T11:53:03.359+0100    INFO    [publisher]     pipeline/module.go:113  Beat name: mbp.local
2020-12-01T11:53:03.360+0100    WARN    beater/filebeat.go:171  Filebeat is unable to load the Ingest Node pipelines for the configured modules because the Elasticsearch output is not configured/enabled. If you have already loaded the Ingest Node pipelines or are using Logstash pipelines, you can ignore this warning.
2020-12-01T11:53:03.360+0100    INFO    [monitoring]    log/log.go:120  Starting metrics logging every 30s
2020-12-01T11:53:03.360+0100    INFO    instance/beat.go:456    filebeat start running.
2020-12-01T11:53:03.360+0100    INFO    memlog/store.go:119     Loading data file of '/go/src/github.com/elastic/beats/x-pack/filebeat/data/registry/filebeat' succeeded. Active transaction id=0
2020-12-01T11:53:03.361+0100    INFO    memlog/store.go:124     Finished loading transaction log file for '/go/src/github.com/elastic/beats/x-pack/filebeat/data/registry/filebeat'. Active transaction id=10
2020-12-01T11:53:03.361+0100    WARN    beater/filebeat.go:292  Filebeat is unable to load the Ingest Node pipelines for the configured modules because the Elasticsearch output is not configured/enabled. If you have already loaded the Ingest Node pipelines or are using Logstash pipelines, you can ignore this warning.
2020-12-01T11:53:03.362+0100    INFO    [registrar]     registrar/registrar.go:109      States Loaded from registrar: 0
2020-12-01T11:53:03.363+0100    INFO    [crawler]       beater/crawler.go:71    Loading Inputs: 1
2020-12-01T11:53:03.363+0100    WARN    [input] v2/loader.go:104        BETA: The httpjson input is beta        {"input": "httpjson", "stability": "Beta", "deprecated": false}
2020-12-01T11:53:03.363+0100    INFO    [crawler]       beater/crawler.go:141   Starting input (ID: 3564074663099653663)
2020-12-01T11:53:03.363+0100    INFO    [crawler]       beater/crawler.go:108   Loading and starting Inputs completed. Enabled inputs: 1
2020-12-01T11:53:03.363+0100    INFO    [input.httpjson-cursor] compat/compat.go:112    Input httpjson-cursor starting
2020-12-01T11:53:03.373+0100    WARN    [tls]   tlscommon/tls_config.go:93      SSL/TLS verifications disabled.
^C
2020-12-01T11:53:05.515+0100  INFO    beater/filebeat.go:441  Stopping filebeat
2020-12-01T11:53:05.516+0100    INFO    beater/crawler.go:148   Stopping Crawler
2020-12-01T11:53:05.516+0100    INFO    beater/crawler.go:158   Stopping 1 inputs
2020-12-01T11:53:05.516+0100    INFO    [crawler]       beater/crawler.go:163   Stopping input: 3564074663099653663
2020-12-01T11:53:05.516+0100    INFO    [input.httpjson-cursor] v2/input.go:139 Input stopped because context was cancelled with: context canceled      {"source": "https://url", "url": "https://url"}
2020-12-01T11:53:05.516+0100    INFO    [input.httpjson-cursor] compat/compat.go:125    Input 'httpjson-cursor' stopped
2020-12-01T11:53:05.516+0100    INFO    [input.httpjson-cursor] compat/compat.go:133    Input 'httpjson-cursor' stopped
2020-12-01T11:53:05.516+0100    INFO    beater/crawler.go:178   Crawler stopped
2020-12-01T11:53:05.516+0100    INFO    [registrar]     registrar/registrar.go:132      Stopping Registrar
2020-12-01T11:53:05.516+0100    INFO    [registrar]     registrar/registrar.go:166      Ending Registrar
2020-12-01T11:53:05.516+0100    INFO    [registrar]     registrar/registrar.go:137      Registrar stopped
2020-12-01T11:53:33.389+0100    INFO    [monitoring]    log/log.go:147  Non-zero metrics in the last 30s        {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":44,"time":{"ms":3}},"total":{"ticks":147,"time":{"ms":9},"value":147},"user":{"ticks":103,"time":{"ms":6}}},"info":{"ephemeral_id":"fbfb136c-1fa9-40b0-bc07-017fb0357086","uptime":{"ms":120048}},"memstats":{"gc_next":17850656,"memory_alloc":14028480,"memory_total":49778032,"rss":36864},"runtime":{"goroutines":11}},"filebeat":{"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"pipeline":{"clients":0,"events":{"active":0}}},"registrar":{"states":{"current":0}},"system":{"load":{"1":1.8574,"15":2.6943,"5":2.373,"norm":{"1":0.1161,"15":0.1684,"5":0.1483}}}}}}
^Z
[1]  + 35019 suspended  ./filebeat -e -v

Stacktrace:

▶ kill -s SIGABRT %1
SIGABRT: abort                                                                                                                                                                                                                                                 
PC=0x7fff6fbf381c m=0 sigcode=0

goroutine 0 [idle]:
runtime.sigNoteSleep(0x88a2cc0)
        /usr/local/Cellar/go/1.15.5/libexec/src/runtime/os_darwin.go:118 +0x25 fp=0xc000231fa0 sp=0xc000231f68 pc=0x40357e5
os/signal.signal_recv(0x6f53500)
        /usr/local/Cellar/go/1.15.5/libexec/src/runtime/sigqueue.go:144 +0x9d fp=0xc000231fc0 sp=0xc000231fa0 pc=0x406eadd
os/signal.loop()
        /usr/local/Cellar/go/1.15.5/libexec/src/os/signal/signal_unix.go:23 +0x25 fp=0xc000231fe0 sp=0xc000231fc0 pc=0x4899205
runtime.goexit()
        /usr/local/Cellar/go/1.15.5/libexec/src/runtime/asm_amd64.s:1374 +0x1 fp=0xc000231fe8 sp=0xc000231fe0 pc=0x4072861
created by os/signal.Notify.func1.1
        /usr/local/Cellar/go/1.15.5/libexec/src/os/signal/signal.go:150 +0x45

goroutine 116 [syscall]:
runtime.sigNoteSleep(0x88a2cc0)
        /usr/local/Cellar/go/1.15.5/libexec/src/runtime/os_darwin.go:118 +0x25 fp=0xc000231fa0 sp=0xc000231f68 pc=0x40357e5
os/signal.signal_recv(0x6f53500)
        /usr/local/Cellar/go/1.15.5/libexec/src/runtime/sigqueue.go:144 +0x9d fp=0xc000231fc0 sp=0xc000231fa0 pc=0x406eadd
os/signal.loop()
        /usr/local/Cellar/go/1.15.5/libexec/src/os/signal/signal_unix.go:23 +0x25 fp=0xc000231fe0 sp=0xc000231fc0 pc=0x4899205
runtime.goexit()
        /usr/local/Cellar/go/1.15.5/libexec/src/runtime/asm_amd64.s:1374 +0x1 fp=0xc000231fe8 sp=0xc000231fe0 pc=0x4072861
created by os/signal.Notify.func1.1
        /usr/local/Cellar/go/1.15.5/libexec/src/os/signal/signal.go:150 +0x45

goroutine 1 [semacquire]:
sync.runtime_Semacquire(0xc0003ca1a8)
        /usr/local/Cellar/go/1.15.5/libexec/src/runtime/sema.go:56 +0x45
sync.(*WaitGroup).Wait(0xc0003ca1a0)
        /usr/local/Cellar/go/1.15.5/libexec/src/sync/waitgroup.go:130 +0x65
github.com/elastic/beats/v7/libbeat/statestore.(*Registry).Close(0xc0003ca180, 0xc00018a008, 0xc0004b6c10)
        /go/src/github.com/elastic/beats/libbeat/statestore/registry.go:54 +0x8d
github.com/elastic/beats/v7/filebeat/beater.(*filebeatStore).Close(...)
        /go/src/github.com/elastic/beats/filebeat/beater/store.go:54
github.com/elastic/beats/v7/filebeat/beater.(*Filebeat).Run.func1(0xc00039c540)
        /go/src/github.com/elastic/beats/filebeat/beater/filebeat.go:255 +0x8b
github.com/elastic/beats/v7/filebeat/beater.(*Filebeat).Run(0xc000e30d20, 0xc00095c000, 0x0, 0x0)
        /go/src/github.com/elastic/beats/filebeat/beater/filebeat.go:436 +0x1818
github.com/elastic/beats/v7/libbeat/cmd/instance.(*Beat).launch(0xc00095c000, 0x6a412f2, 0x8, 0x6a412f2, 0x8, 0x0, 0x0, 0x101, 0x0, 0x0, ...)
        /go/src/github.com/elastic/beats/libbeat/cmd/instance/beat.go:462 +0x7d2
github.com/elastic/beats/v7/libbeat/cmd/instance.Run.func1(0x6a412f2, 0x8, 0x6a412f2, 0x8, 0x0, 0x0, 0x101, 0xc000d2fc40, 0xc000111eb0, 0x0, ...)
        /go/src/github.com/elastic/beats/libbeat/cmd/instance/beat.go:189 +0x5a8
github.com/elastic/beats/v7/libbeat/cmd/instance.Run(0x6a412f2, 0x8, 0x6a412f2, 0x8, 0x0, 0x0, 0x101, 0x0, 0x0, 0x0, ...)
        /go/src/github.com/elastic/beats/libbeat/cmd/instance/beat.go:190 +0x105
github.com/elastic/beats/v7/libbeat/cmd.genRunCmd.func1(0xc00095d8c0, 0xc000b5ac40, 0x0, 0x2)
        /go/src/github.com/elastic/beats/libbeat/cmd/run.go:36 +0x85
github.com/spf13/cobra.(*Command).execute(0xc00095d8c0, 0xc0001840a0, 0x2, 0x2, 0xc00095d8c0, 0xc0001840a0)
        /go/pkg/mod/github.com/spf13/[email protected]/command.go:830 +0x2c2
github.com/spf13/cobra.(*Command).ExecuteC(0xc00095d8c0, 0x0, 0xffffffff, 0xc0000c8058)
        /go/pkg/mod/github.com/spf13/[email protected]/command.go:914 +0x30b
github.com/spf13/cobra.(*Command).Execute(...)
        /go/pkg/mod/github.com/spf13/[email protected]/command.go:864
main.main()
        /go/src/github.com/elastic/beats/x-pack/filebeat/main.go:22 +0x34

goroutine 16 [chan receive]:
k8s.io/klog.(*loggingT).flushDaemon(0x886d4e0)
        /go/pkg/mod/k8s.io/[email protected]/klog.go:1010 +0x8b
created by k8s.io/klog.init.0
        /go/pkg/mod/k8s.io/[email protected]/klog.go:411 +0xd8

goroutine 51 [select]:
go.opencensus.io/stats/view.(*worker).start(0xc00011c4b0)
        /go/pkg/mod/[email protected]/stats/view/worker.go:154 +0x105
created by go.opencensus.io/stats/view.init.0
        /go/pkg/mod/[email protected]/stats/view/worker.go:32 +0x57

goroutine 103 [select]:
github.com/elastic/beats/v7/libbeat/publisher/queue/memqueue.(*bufferingEventLoop).run(0xc00035c0a0)
        /go/src/github.com/elastic/beats/libbeat/publisher/queue/memqueue/eventloop.go:316 +0x1d0
github.com/elastic/beats/v7/libbeat/publisher/queue/memqueue.NewQueue.func1(0xc000bf1730, 0x6f48840, 0xc00035c0a0)
        /go/src/github.com/elastic/beats/libbeat/publisher/queue/memqueue/broker.go:171 +0x63
created by github.com/elastic/beats/v7/libbeat/publisher/queue/memqueue.NewQueue
        /go/src/github.com/elastic/beats/libbeat/publisher/queue/memqueue/broker.go:169 +0x37f

goroutine 104 [select]:
github.com/elastic/beats/v7/libbeat/publisher/queue/memqueue.(*ackLoop).run(0xc0000c6dc0)
        /go/src/github.com/elastic/beats/libbeat/publisher/queue/memqueue/ackloop.go:60 +0x118
github.com/elastic/beats/v7/libbeat/publisher/queue/memqueue.NewQueue.func2(0xc000bf1730, 0xc0000c6dc0)
        /go/src/github.com/elastic/beats/libbeat/publisher/queue/memqueue/broker.go:175 +0x59
created by github.com/elastic/beats/v7/libbeat/publisher/queue/memqueue.NewQueue
        /go/src/github.com/elastic/beats/libbeat/publisher/queue/memqueue/broker.go:173 +0x3ae

goroutine 105 [select]:
github.com/elastic/beats/v7/libbeat/publisher/queue/memqueue.(*consumer).Get(0xc00039c480, 0x0, 0x0, 0x0, 0x0, 0x0)
        /go/src/github.com/elastic/beats/libbeat/publisher/queue/memqueue/consume.go:65 +0xf1
github.com/elastic/beats/v7/libbeat/publisher/pipeline.(*eventConsumer).loop(0xc000039440, 0x6f48880, 0xc00039c480)
        /go/src/github.com/elastic/beats/libbeat/publisher/pipeline/consumer.go:182 +0x1a2
github.com/elastic/beats/v7/libbeat/publisher/pipeline.newEventConsumer.func1(0xc000039440, 0x6f48880, 0xc00039c460)
        /go/src/github.com/elastic/beats/libbeat/publisher/pipeline/consumer.go:86 +0x6c
created by github.com/elastic/beats/v7/libbeat/publisher/pipeline.newEventConsumer
        /go/src/github.com/elastic/beats/libbeat/publisher/pipeline/consumer.go:84 +0x153

goroutine 106 [select]:
github.com/elastic/beats/v7/libbeat/publisher/pipeline.(*retryer).loop(0xc000039560)
        /go/src/github.com/elastic/beats/libbeat/publisher/pipeline/retry.go:135 +0x253
created by github.com/elastic/beats/v7/libbeat/publisher/pipeline.newRetryer
        /go/src/github.com/elastic/beats/libbeat/publisher/pipeline/retry.go:94 +0x15d

goroutine 107 [select]:
github.com/elastic/beats/v7/libbeat/publisher/pipeline.(*clientWorker).run(0xc000861740)
        /go/src/github.com/elastic/beats/libbeat/publisher/pipeline/output.go:96 +0xc8
created by github.com/elastic/beats/v7/libbeat/publisher/pipeline.makeClientWorker
        /go/src/github.com/elastic/beats/libbeat/publisher/pipeline/output.go:79 +0x194

goroutine 114 [select]:
github.com/elastic/beats/v7/libbeat/monitoring/report/log.(*reporter).snapshotLoop(0xc000e30d80)
        /go/src/github.com/elastic/beats/libbeat/monitoring/report/log/log.go:131 +0x3d5
github.com/elastic/beats/v7/libbeat/monitoring/report/log.MakeReporter.func1(0xc000e30d80)
        /go/src/github.com/elastic/beats/libbeat/monitoring/report/log/log.go:108 +0x50
created by github.com/elastic/beats/v7/libbeat/monitoring/report/log.MakeReporter
        /go/src/github.com/elastic/beats/libbeat/monitoring/report/log/log.go:106 +0x15c

goroutine 144 [select]:
reflect.rselect(0xc00040ed20, 0x1, 0x4, 0x4, 0x0)
        /usr/local/Cellar/go/1.15.5/libexec/src/runtime/select.go:566 +0x390
reflect.Select(0xc000122c60, 0x1, 0x3, 0x1, 0x64e6880, 0x88a1f98, 0x99, 0x0)
        /usr/local/Cellar/go/1.15.5/libexec/src/reflect/value.go:2260 +0x19c
github.com/elastic/beats/v7/libbeat/publisher/pipeline.(*Pipeline).runSignalPropagation(0xc000bee140)
        /go/src/github.com/elastic/beats/libbeat/publisher/pipeline/pipeline.go:363 +0x1bd
created by github.com/elastic/beats/v7/libbeat/publisher/pipeline.(*Pipeline).registerSignalPropagation.func1
        /go/src/github.com/elastic/beats/libbeat/publisher/pipeline/pipeline.go:348 +0x7e

rax    0x2000003
rbx    0xc000231f68
rcx    0x7ffeefbff508
rdx    0x1
rdi    0x9
rsi    0xc000231f8f
rbp    0x7ffeefbff510
rsp    0x7ffeefbff508
r8     0xc0002dcf00
r9     0x0
r10    0xc000231f68
r11    0x212
r12    0xc
r13    0x0
r14    0xffffffffffffffff
r15    0xc0001accf0
rip    0x7fff6fbf381c
rflags 0x212
cs     0x7
fs     0x0
gs     0x0
[1]  + 35019 exit 2     ./filebeat -e -v

The text was updated successfully, but these errors were encountered:

elasticmachine · 2020-12-02T08:17:17Z

Pinging @elastic/integrations-services (Team:Services)

ppine7 · 2021-10-01T19:36:57Z

Filebeat also does not stop when it fails to send data into its output, and is in retry stage. Below are example logs form Filebeat when it cannot connect to Elastic cluster due to auth errors. In this state, killing it with Cntrl+C does not produce any result, only 'kill pid' from another terminal works.

2021-10-01T15:28:00.011-0400	INFO	[publisher_pipeline_output]	pipeline/output.go:145	Attempting to reconnect to backoff(elasticsearch(https://xxx.gcp.elastic-cloud.com:9243/)) with 11 reconnect attempt(s)
2021-10-01T15:28:00.011-0400	DEBUG	[esclientleg]	eslegclient/connection.go:249	ES Ping(url=https://xxx.gcp.elastic-cloud.com:9243/)
2021-10-01T15:28:00.011-0400	INFO	[publisher]	pipeline/retry.go:219	retryer: send unwait signal to consumer
2021-10-01T15:28:00.011-0400	INFO	[publisher]	pipeline/retry.go:223	  done
2021-10-01T15:28:00.060-0400	DEBUG	[esclientleg]	eslegclient/connection.go:253	Ping request failed with: 401 Unauthorized: <div/>
2021-10-01T15:28:33.868-0400	ERROR	[publisher_pipeline_output]	pipeline/output.go:154	Failed to connect to backoff(elasticsearch(https://xxx.gcp.elastic-cloud.com:9243/)): 401 Unauthorized: <div/>
2021-10-01T15:28:33.868-0400	INFO	[publisher_pipeline_output]	pipeline/output.go:145	Attempting to reconnect to backoff(elasticsearch(https://xxx.gcp.elastic-cloud.com:9243/)) with 12 reconnect attempt(s)
2021-10-01T15:28:33.868-0400	DEBUG	[esclientleg]	eslegclient/connection.go:249	ES Ping(url=https://xxx.gcp.elastic-cloud.com:9243/)
2021-10-01T15:28:33.868-0400	INFO	[publisher]	pipeline/retry.go:219	retryer: send unwait signal to consumer
2021-10-01T15:28:33.868-0400	INFO	[publisher]	pipeline/retry.go:223	  done
2021-10-01T15:28:33.918-0400	DEBUG	[esclientleg]	eslegclient/connection.go:253	Ping request failed with: 401 Unauthorized: <div/>
2021-10-01T15:29:31.633-0400	ERROR	[publisher_pipeline_output]	pipeline/output.go:154	Failed to connect to backoff(elasticsearch(https://xxx.gcp.elastic-cloud.com:9243/)): 401 Unauthorized: <div/>
2021-10-01T15:29:31.633-0400	INFO	[publisher_pipeline_output]	pipeline/output.go:145	Attempting to reconnect to backoff(elasticsearch(https://xxx.gcp.elastic-cloud.com:9243/)) with 13 reconnect attempt(s)
2021-10-01T15:29:31.633-0400	DEBUG	[esclientleg]	eslegclient/connection.go:249	ES Ping(url=https://xxx.gcp.elastic-cloud.com:9243/)
2021-10-01T15:29:31.633-0400	INFO	[publisher]	pipeline/retry.go:219	retryer: send unwait signal to consumer
2021-10-01T15:29:31.633-0400	INFO	[publisher]	pipeline/retry.go:223	  done
2021-10-01T15:29:31.688-0400	DEBUG	[esclientleg]	eslegclient/connection.go:253	Ping request failed with: 401 Unauthorized: <div/>
^C
2021-10-01T15:30:22.929-0400	ERROR	[publisher_pipeline_output]	pipeline/output.go:154	Failed to connect to backoff(elasticsearch(https://xxx.gcp.elastic-cloud.com:9243/)): 401 Unauthorized: <div/>
2021-10-01T15:30:22.929-0400	INFO	[publisher_pipeline_output]	pipeline/output.go:145	Attempting to reconnect to backoff(elasticsearch(https://xxx.gcp.elastic-cloud.com:9243/)) with 14 reconnect attempt(s)
2021-10-01T15:30:22.929-0400	DEBUG	[esclientleg]	eslegclient/connection.go:249	ES Ping(url=https://xxx.gcp.elastic-cloud.com:9243/)

elasticmachine · 2022-03-31T08:26:00Z

Pinging @elastic/elastic-agent-data-plane (Team:Elastic-Agent-Data-Plane)

thekofimensah · 2023-09-28T22:42:55Z

I'm finding the same thing in Filebeat 8.9, I run from CL with ./filebeat -e -c filebeat.yml and it doesn't die. I need to do it in Activity Monitor or kill it on the CL. Really annoying to do that everytime I need to restart filebeat while testing

belimawr · 2023-10-24T14:00:08Z

@thekofimensah could you elaborate a bit more on how you are reproducing it?
Does Filebeat fails to exit every time you press CRTL + C? Or is it only in specific moments?
Could you also provide your filebeat.yml? Don't forget to redact any sensitive information like the output credentials.

belimawr · 2023-11-08T20:08:17Z

I finally managed to reproduce it, it happens when the queue is full and the output is blocked.
On my test I had two inputs:

Filestream: it shutdown about 1m after the CTRL+C
Httpjson: it does not seem to shutdown at all. I let it running for 15+m and it did not stop.

I'm working on a fix.

thekofimensah · 2023-11-13T18:29:06Z

Sorry for the delay in responding, the notification got hidden.

In my situations, I parse 20 different log files with a wildcard under the filestream input plugin. Once the ingest finishes and the data has all sent, I will CTRL+C, many times, and filebeat doesn't shut down (even after 1m)

I get these messages perpetually, and filebeat doesn't ever shut down:

{"log.level":"info","@timestamp":"2023-11-13T08:26:50.239-1000","log.logger":"monitoring","log.origin":{"file.name":"log/log.go","file.line":187},"message":"Non-zero metrics in the last 30s","service.name":"filebeat","monitoring":{"metrics":{"beat":{"cpu":{"system":{"ticks":23,"time":{"ms":1}},"total":....

I can try on the next version to see if your fix did it or not

belimawr · 2023-11-21T10:58:09Z

Sorry for the delay in responding, the notification got hidden.

In my situations, I parse 20 different log files with a wildcard under the filestream input plugin. Once the ingest finishes and the data has all sent, I will CTRL+C, many times, and filebeat doesn't shut down (even after 1m)

I get these messages perpetually, and filebeat doesn't ever shut down:
{"log.level":"info","@timestamp":"2023-11-13T08:26:50.239-1000","log.logger":"monitoring","log.origin":{"file.name":"log/log.go","file.line":187},"message":"Non-zero metrics in the last 30s","service.name":"filebeat","monitoring":{"metrics":{"beat":{"cpu":{"system":{"ticks":23,"time":{"ms":1}},"total":....
I can try on the next version to see if your fix did it or not

Is Filebeat successfully sending data to the output?
What happens if you send the signal directly: kill -TERM <Filebeat PID>?

thekofimensah · 2023-11-21T18:29:29Z

Yes filebeat is sending to elasticsearch without problem.

Yes, if I send the signal directly, it stops filebeat, but having to manually do that each time is a bit annoying for rapid problem solving

belimawr · 2023-11-22T10:07:25Z

Yes, if I send the signal directly, it stops filebeat

If sending the signal directly works, this means Filebeat is able to correct receive and react to the signal.

It looks like your terminal might not be correctly sending the signal when CTRL+C is pressed.

A few ways to debug it:

Run Filebeat with log level debug, once you press CTRL+C look for a log message like this:
```
{"log.level":"debug","@timestamp":"2023-11-22T10:50:47.105+0100","log.logger":"service","log.origin":{"file.name":"service/service.go","file.line":54},"message":"Received sigterm/sigint, stopping","service.name":"filebeat","ecs.version":"1.6.0"}
```
This means Filebeat received the signal and it will start its shutdown process. If the message is there and Filebeat does not exit, then there is still an issue with the shutdown process that I need to further investigate
If you do not see the log message, try running Filebeat with log level debug and sending the signal using the kill command. You can try both: SIGINT and TERM. If Filebeat correctly receives and shutdown, then Filebeat is working as expected.
Use strace to look if Filebeat is receiving the correct signal when you press CTRL+C.
1. Start Filebeat with log level debug
2. Get Filebeat's PID (e.g: ps aux|grep filebeat)
3. In another terminal run sudo strace -e signal=SIGINT,TERM -p <Filebeat PID>.
4. Go to the terminal Filebeat is running and press CTRL+C
5. Check strace for entries like;
```
--- SIGINT {si_signo=SIGINT, si_code=SI_KERNEL} ---
```
  or
```
--- SIGTERM {si_signo=SIGTERM, si_code=SI_USER, si_pid=2430553, si_uid=1000} ---
```

If strace does not show any signals, it is very likely because your terminal is not sending the correct signal when CTRL+C is pressed.

marc-gr added bug Filebeat Filebeat labels Dec 1, 2020

marc-gr self-assigned this Dec 1, 2020

botelastic bot added the needs_team Indicates that the issue/PR needs a Team:* label label Dec 1, 2020

andresrc added the Team:Services (Deprecated) Label for the former Integrations-Services team label Dec 2, 2020

botelastic bot removed the needs_team Indicates that the issue/PR needs a Team:* label label Dec 2, 2020

jlind23 removed the Team:Services (Deprecated) Label for the former Integrations-Services team label Mar 31, 2022

botelastic bot added the needs_team Indicates that the issue/PR needs a Team:* label label Mar 31, 2022

jlind23 added the Team:Elastic-Agent-Data-Plane Label for the Agent Data Plane team label Mar 31, 2022

botelastic bot removed the needs_team Indicates that the issue/PR needs a Team:* label label Mar 31, 2022

marc-gr removed their assignment Oct 19, 2022

pierrehilbert assigned belimawr Oct 23, 2023

belimawr mentioned this issue Nov 9, 2023

Fix memqueue getting stuck on shutdown #37077

Merged

4 tasks

belimawr closed this as completed in #37077 Nov 13, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[Filebeat] Filebeat process does not exit when stopping with CTRL-C #22813

[Filebeat] Filebeat process does not exit when stopping with CTRL-C #22813

marc-gr commented Dec 1, 2020 •

edited

Loading

elasticmachine commented Dec 2, 2020

ppine7 commented Oct 1, 2021 •

edited by belimawr

Loading

elasticmachine commented Mar 31, 2022

thekofimensah commented Sep 28, 2023

belimawr commented Oct 24, 2023

belimawr commented Nov 8, 2023

thekofimensah commented Nov 13, 2023 •

edited

Loading

belimawr commented Nov 21, 2023

thekofimensah commented Nov 21, 2023

belimawr commented Nov 22, 2023

[Filebeat] Filebeat process does not exit when stopping with CTRL-C #22813

[Filebeat] Filebeat process does not exit when stopping with CTRL-C #22813

Comments

marc-gr commented Dec 1, 2020 • edited Loading

elasticmachine commented Dec 2, 2020

ppine7 commented Oct 1, 2021 • edited by belimawr Loading

elasticmachine commented Mar 31, 2022

thekofimensah commented Sep 28, 2023

belimawr commented Oct 24, 2023

belimawr commented Nov 8, 2023

thekofimensah commented Nov 13, 2023 • edited Loading

belimawr commented Nov 21, 2023

thekofimensah commented Nov 21, 2023

belimawr commented Nov 22, 2023

marc-gr commented Dec 1, 2020 •

edited

Loading

ppine7 commented Oct 1, 2021 •

edited by belimawr

Loading

thekofimensah commented Nov 13, 2023 •

edited

Loading