# Filebeat перестаёт отправлять логи

**URL:** <https://discuss.elastic.co/t/filebeat/200967>\
**Category:** Вопросы на русском языке\
**Created:** [September 25, 2019, 6:51am UTC](https://discuss.elastic.co/t/filebeat/200967 "2019-09-25T06:51:27Z")\
**Posts on this page:** 20\
**Page:** 1

<div class="post-metadata">

**Author:** ![Axizdkr](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/axizdkr/32/54875_2.png) [@Axizdkr](https://discuss.elastic.co/u/Axizdkr)\
**Post date:** [September 25, 2019, 6:51am UTC](https://discuss.elastic.co/t/filebeat/200967/1 "2019-09-25T06:51:27Z")

</div>

День добрый.

попробую сначала на русском.

У меня есть папка в которой хранится большое количетсов фалйов (минимум 300 тысяч).  
Для этих файлов я сделал отдельный модуль, все записи через этот модуль отправляются на прямую в elastic.

Если запустить файлбит первый раз, или удалить registry, то всё работает. Но если перезапустить файлбит, перезапустить хост, или был случай когда там оперативка закончилась, файлбит перестаёт отправлять что-либо, полностью игнорирует новые записи итп.

Так же при повторной попытке переазапустить сепрвис пишет:

```auto
filebeat.service: State 'stop-sigterm' timed out. Killing.
25 09:38:16 bisArch systemd[1]: filebeat.service: Main process exited, code=killed, status=9/KILL

```

Если ничего не делать, то спустя какой-то случайное время от 8 до 10 часов, всё начинает работать снова, в логах при этом никаких ошибок нет, ни в syslog, ни в filebeat.

filebeat 7.3.2, ubuntu 16.04.

Может быть есть какие-то идеи в чём может быть проблема?

---

<div class="post-metadata">

**Author:** ![Igor\_Motov](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/igor_motov/32/45193_2.png) [@Igor\_Motov](https://discuss.elastic.co/u/Igor_Motov)\
**Post date:** [September 25, 2019, 1:00pm UTC](https://discuss.elastic.co/t/filebeat/200967/2 "2019-09-25T13:00:32Z")

</div>

А можно на логи filebeat-а посмотреть?

---

<div class="post-metadata">

**Author:** ![Axizdkr](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/axizdkr/32/54875_2.png) [@Axizdkr](https://discuss.elastic.co/u/Axizdkr)\
**Post date:** [September 25, 2019, 2:51pm UTC](https://discuss.elastic.co/t/filebeat/200967/3 "2019-09-25T14:51:49Z")

</div>

конечно, только вопрос какой режим включить? сейчас у меня warn стоит, и после перезапуска в логах файлбита ни одной новой строчки не добавилось.

---

<div class="post-metadata">

**Author:** ![Igor\_Motov](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/igor_motov/32/45193_2.png) [@Igor\_Motov](https://discuss.elastic.co/u/Igor_Motov)\
**Post date:** [September 25, 2019, 2:54pm UTC](https://discuss.elastic.co/t/filebeat/200967/4 "2019-09-25T14:54:42Z")

</div>

как минимум INFO

---

<div class="post-metadata">

**Author:** ![Axizdkr](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/axizdkr/32/54875_2.png) [@Axizdkr](https://discuss.elastic.co/u/Axizdkr)\
**Post date:** [September 25, 2019, 5:57pm UTC](https://discuss.elastic.co/t/filebeat/200967/5 "2019-09-25T17:57:38Z")

</div>

вот кусок сначала и с конца  
[https://pastebin.com/RK9qiJbj](https://pastebin.com/RK9qiJbj)

---

<div class="post-metadata">

**Author:** ![Dima\_I](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/dima_i/32/54877_2.png) [@Dima\_I](https://discuss.elastic.co/u/Dima_I)\
**Post date:** [September 25, 2019, 7:18pm UTC](https://discuss.elastic.co/t/filebeat/200967/6 "2019-09-25T19:18:16Z")

</div>

Alexey,

здраствуйте! расскажите пожалуйста подробнее, что подразумевается под "работает" в данном случае? после запуска filebeat, что происходит с файлами в директории, что вы ожидаете от filebeat? Например, эти файлы - это логи, или статические файлы? новые файлы появляются в директории, и ожидается что filebeat их "увидит" и проиндексирует?

Также, можно посмотреть еще несколько вещей - вне зависимости от того, что происходит с файлами:

- journalctl -r filebeat.service
- strace -vttf -p filebeat process pid во время этих 8 часов, когда "не работает"; или увеличить log level до debug у filebeat, что дает значительно больше информации в логах
- что происходит с процессом filebeat в эти 8 часов - использует ли CPU, например 50-100-200%? память?
- судя по логам, filebeat настроен отсылать мониторинговую информацию в elasticsearch - попробуйте посмотреть в kibana для кластера, куда отсылается мониторинговая инофрмация, на состояние filebeat в течении этих 8 часов
- проверьте, что происходит с elasticsearch в эти 8 часов

И еще, из догадок, проблема может быть вокруг [https://www.elastic.co/guide/en/beats/filebeat/current/inode-reuse-issue.html](https://www.elastic.co/guide/en/beats/filebeat/current/inode-reuse-issue.html) и - возможно - некоторые из close\_\* опций помогут [https://www.elastic.co/guide/en/beats/filebeat/7.3/filebeat-input-log.html#filebeat-input-log-close-options](https://www.elastic.co/guide/en/beats/filebeat/7.3/filebeat-input-log.html#filebeat-input-log-close-options)

---

<div class="post-metadata">

**Author:** ![Axizdkr](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/axizdkr/32/54875_2.png) [@Axizdkr](https://discuss.elastic.co/u/Axizdkr)\
**Post date:** [September 25, 2019, 9:02pm UTC](https://discuss.elastic.co/t/filebeat/200967/7 "2019-09-25T21:02:41Z")

</div>

4 раза в час появляются новые файлы, думаю что реже строчки в самих файлах, lftp работает.  
пока я не делаю рестарт сервиса, filebeat видит новые файлы, и отправляет информацию.  
[http://prntscr.com/paznvb](http://prntscr.com/paznvb) - вот график работы.  
процессор и память - ничего необычного.  
в кибане я не вижу состояние файлбита, или не понял где смотреть, остальное с утра добавлю.

---

<div class="post-metadata">

**Author:** ![Dima\_I](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/dima_i/32/54877_2.png) [@Dima\_I](https://discuss.elastic.co/u/Dima_I)\
**Post date:** [September 25, 2019, 11:02pm UTC](https://discuss.elastic.co/t/filebeat/200967/8 "2019-09-25T23:02:07Z")

</div>

> пока я не делаю рестарт сервиса, filebeat видит новые файлы, и отправляет информацию.

Тогда еще стоит глянуть на systemctl status filebeat.service, до и после рестарта. И проверить, сколько процессов filebeat запущено в системе до и после рестарта, и перезапускается ли процесс вообще. Ну и посмотреть, что происходит в логе с level=DEBUG во время [попытки] перезапуска. и systemctl cat filebeat.service.

Опять же, теория/догадка, но судя по ошибке

> filebeat.service: State 'stop-sigterm' timed out. Killing.

и тому, что там 300к файлов, возможно sigkill прерывает запись registry и после перезапуска новый filebeat процесс как-то странно себя ведет из-за не совсем "здорового" registry. Systemd документация, вроде как, говорит что по-умолчанию systemd будет ждать 90 секунд после sigterm перед тем, как посылать sigkill. Гипотетически, это очень долго. Поэтому либо systemd делает что-то не то, либо filebeat действительно нужно больше времени...

---

<div class="post-metadata">

**Author:** ![Axizdkr](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/axizdkr/32/54875_2.png) [@Axizdkr](https://discuss.elastic.co/u/Axizdkr)\
**Post date:** [September 26, 2019, 5:31pm UTC](https://discuss.elastic.co/t/filebeat/200967/9 "2019-09-26T17:31:36Z")

</div>

Да, где-то 90 секунд и приходится ждать, НО, это если второй раз рестартить, первый раз когда всё работает рестарт происходит быстро, т.е. если запись и прерывается то это ненормальное поведение, там никакого sigkill'а нет.

systemctl до рестарта с режимом info и после рестартам с режимом debug - [https://pastebin.com/SbLd34iY](https://pastebin.com/SbLd34iY)

1000 строчек из лога с режимом дебаг - [https://pastebin.com/5kUyw5ky](https://pastebin.com/5kUyw5ky)

close\_\* пока не пробовал вписывать, сегодня к сожалению руки не дошли.

---

<div class="post-metadata">

**Author:** ![Axizdkr](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/axizdkr/32/54875_2.png) [@Axizdkr](https://discuss.elastic.co/u/Axizdkr)\
**Post date:** [September 26, 2019, 5:38pm UTC](https://discuss.elastic.co/t/filebeat/200967/10 "2019-09-26T17:38:11Z")

</div>

соврал, в модуле я уже дописывал:

```auto
    close_removed: true
    close_inactive: 1m
    scan_frequency: 60s

```

но это не помогло.

---

<div class="post-metadata">

**Author:** ![Dima\_I](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/dima_i/32/54877_2.png) [@Dima\_I](https://discuss.elastic.co/u/Dima_I)\
**Post date:** [September 26, 2019, 6:08pm UTC](https://discuss.elastic.co/t/filebeat/200967/11 "2019-09-26T18:08:41Z")

</div>

Pastebin с логами filebeat и статусами из systemd - это после первого рестарта, или после второго? в логе filebeat видно sigterm/sigkill в районе "Sep 26 20:21:41" - это первый или второй рестарт? после второго рестарта все так же, один filebeat процесс в системе ("ps uax | grep filebeat| grep -v grep") и его PID совпадает с systemd? ничего - например, configuration management system - не меняет файлы конфигурации filebeat?

> Sep 26 20:21:46 bisArch filebeat[7747]: 2019-09-26T20:21:46.796+0300#011INFO#011crawler/crawler.go:72#011Loading Inputs: 0

выглядит странно, потому как командная строка для filebeat не меняется (судя по systemd status), значит используются те же пути к файлам конфигурации. ну и к Kibana/Elasticsearch подключается. почему тогда 0 inputs после sigterm/sigkill?

---

<div class="post-metadata">

**Author:** ![Axizdkr](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/axizdkr/32/54875_2.png) [@Axizdkr](https://discuss.elastic.co/u/Axizdkr)\
**Post date:** [September 26, 2019, 7:53pm UTC](https://discuss.elastic.co/t/filebeat/200967/12 "2019-09-26T19:53:08Z")

</div>

все логи после 2го и последующего.  
не знаю почему он пишет 0, но в data.json у него 48 метров файлов чего-то, я так понимаю если бы инпут был реально 0, там было ты тоже 0?  
процентов на 99 уверен что если вот сейчас rm по /var/lib/filebeat/registry/filebeat то у меня через 10 минут файлбит начнёт файлы в еластик отправлять, и после рестарта опять перестанет это делать.

---

<div class="post-metadata">

**Author:** ![Dima\_I](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/dima_i/32/54877_2.png) [@Dima\_I](https://discuss.elastic.co/u/Dima_I)\
**Post date:** [September 26, 2019, 8:06pm UTC](https://discuss.elastic.co/t/filebeat/200967/13 "2019-09-26T20:06:48Z")

</div>

data.json - это registry. просто статус. inputs:0 - это, как я понимаю, к такому выводу приходит filebeat после чтения конфигурации. я бы попробовал запустить с DEBUG "с нуля" - например, после удаления файлов. и посмотреть, что пишет log на тему inputs изначально, после первого рестарта и после второго рестарта.  
проблема с удалением регистра в том, что это вообще не должно быть нужно, и заставляет filebeat переиндексировать все файлы во всех inputs, т.е. если какие-то данные из файлов уже в ES - filebeat их запишет заново. к тому же, исходя из логов, data.json filebeat как раз без проблем читает.

---

<div class="post-metadata">

**Author:** ![Axizdkr](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/axizdkr/32/54875_2.png) [@Axizdkr](https://discuss.elastic.co/u/Axizdkr)\
**Post date:** [September 26, 2019, 9:26pm UTC](https://discuss.elastic.co/t/filebeat/200967/14 "2019-09-26T21:26:13Z")

</div>

именно поэтому я и решил тему начать, потому что действительно заново запишет в ес данные, и потому что процесс повторяется, если первые два раза можно было списать на непонятные какие-то случаи, то когда 3й раз картина 1 в 1 повторилась...  
завтра дебаг попробую сделать после удаления регистра.

---

<div class="post-metadata">

**Author:** ![Dima\_I](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/dima_i/32/54877_2.png) [@Dima\_I](https://discuss.elastic.co/u/Dima_I)\
**Post date:** [September 26, 2019, 9:45pm UTC](https://discuss.elastic.co/t/filebeat/200967/15 "2019-09-26T21:45:26Z")

</div>

Отлично, попробуйте. Если проблема действительно в filebeat, желательно установить очень точный список действий для ее воспроизведения, и собрать как можно больше DEBUG логов и вывода strace после воспроизведения проблемы. Открыть issue с filebeat, или даже поглядеть в код - не проблема, но информации пока не густо. И, соответственно, сложно будет получить решение, окончательное или временное.

---

<div class="post-metadata">

**Author:** ![Axizdkr](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/axizdkr/32/54875_2.png) [@Axizdkr](https://discuss.elastic.co/u/Axizdkr)\
**Post date:** [September 27, 2019, 9:18am UTC](https://discuss.elastic.co/t/filebeat/200967/16 "2019-09-27T09:18:38Z")

</div>

ну в общем как и ожижал, после удаление регистра всё заработало, в конфиге только лог на дебаг поменял  
я предполагаю что по достижении какого-то размера самого data.json файлбит начинает некорректно работать, но опять же, у меня только после перезапуска.  
[https://pastebin.com/8K0xa7ie](https://pastebin.com/8K0xa7ie) - после перезапуска, файлбит отсылает данные

```auto
Sep 27 12:02:38 bisArch filebeat[6360]: 2019-09-27T12:02:37.748+0300#011INFO#011instance/beat.go:432#011filebeat stopped.

```

[https://pastebin.com/1qyD1BaN](https://pastebin.com/1qyD1BaN) - момент перезапуска и файлбит больше не отправляет данные, размер data.json всего 3.5 мегабайта.  
хотя после перезапуска не видно что бы появлялись строчки откуда файлы должны читаться, какой ingest будет использоваться, хотя они есть при первоначальном запуске.

---

<div class="post-metadata">

**Author:** ![Axizdkr](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/axizdkr/32/54875_2.png) [@Axizdkr](https://discuss.elastic.co/u/Axizdkr)\
**Post date:** [September 27, 2019, 11:44am UTC](https://discuss.elastic.co/t/filebeat/200967/17 "2019-09-27T11:44:46Z")

</div>

хотя возможно я накосячил когда модуль правил, но в любом случае не могу понять даже примерно куда смотреть.  
нет никаких ошибок которые бы хотя бы направление указали что-ли.

---

<div class="post-metadata">

**Author:** ![Axizdkr](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/axizdkr/32/54875_2.png) [@Axizdkr](https://discuss.elastic.co/u/Axizdkr)\
**Post date:** [September 27, 2019, 11:54am UTC](https://discuss.elastic.co/t/filebeat/200967/18 "2019-09-27T11:54:55Z")

</div>

на небольшом количестве файлов удалось воспроизвести ситуацию  
сначала в логах было

> **inputs 0**
>
> ```auto
> Sep 27 14:41:20 bisArch filebeat[2192]: 2019-09-27T14:41:20.955+0300#011INFO#011[publisher]#011pipeline/module.go:97#011Beat name: bisArch
> Sep 27 14:41:20 bisArch filebeat[2192]: 2019-09-27T14:41:20.956+0300#011INFO#011[monitoring]#011log/log.go:118#011Starting metrics logging every 30s
> Sep 27 14:41:20 bisArch filebeat[2192]: 2019-09-27T14:41:20.957+0300#011INFO#011kibana/client.go:117#011Kibana url: http://johannesburg.cmp.org:5601
> Sep 27 14:41:21 bisArch filebeat[2192]: 2019-09-27T14:41:21.384+0300#011INFO#011kibana/client.go:117#011Kibana url: http://johannesburg.cmp.org:5601
> Sep 27 14:41:23 bisArch filebeat[2192]: 2019-09-27T14:41:23.027+0300#011INFO#011instance/beat.go:777#011Kibana dashboards successfully loaded.
> Sep 27 14:41:23 bisArch filebeat[2192]: 2019-09-27T14:41:23.029+0300#011INFO#011instance/beat.go:422#011filebeat start running.
> Sep 27 14:41:23 bisArch filebeat[2192]: 2019-09-27T14:41:23.029+0300#011INFO#011registrar/registrar.go:145#011Loading registrar data from /var/lib/filebeat/registry/filebeat/data.json
> Sep 27 14:41:23 bisArch filebeat[2192]: 2019-09-27T14:41:23.033+0300#011INFO#011registrar/registrar.go:152#011States Loaded from registrar: 135
> Sep 27 14:41:23 bisArch filebeat[2192]: 2019-09-27T14:41:23.034+0300#011INFO#011crawler/crawler.go:72#011Loading Inputs: 0
> 
> ```

опять же пишет inputs: 0, но через 3 минуты сначала Config reloader started

> **inputs 0**
>
> ```auto
> Sep 27 14:43:55 bisArch filebeat[2192]: 2019-09-27T14:43:55.998+0300#011INFO#011log/input.go:148#011Configured paths: [/bis/PATH/*.txt]
> Sep 27 14:43:55 bisArch filebeat[2192]: 2019-09-27T14:43:55.999+0300#011INFO#011crawler/crawler.go:106#011Loading and starting Inputs completed. Enabled inputs: 0
> Sep 27 14:43:55 bisArch filebeat[2192]: 2019-09-27T14:43:55.999+0300#011INFO#011cfgfile/reload.go:171#011Config reloader started
> 
> ```

и ещё через 3 минуты начинает собирать данные

> **inputs type log**
>
> ```auto
> Sep 27 14:46:17 bisArch filebeat[2192]: 2019-09-27T14:46:17.638+0300#011INFO#011log/input.go:148#011Configured paths: [//bis/PATH/*.txt]
> Sep 27 14:46:17 bisArch filebeat[2192]: 2019-09-27T14:46:17.639+0300#011INFO#011elasticsearch/client.go:170#011Elasticsearch url: http://johannesburg.cmp.org:9200
> Sep 27 14:46:17 bisArch filebeat[2192]: 2019-09-27T14:46:17.640+0300#011INFO#011elasticsearch/client.go:170#011Elasticsearch url: http://johannesburg.cmp.org:9200
> Sep 27 14:46:17 bisArch filebeat[2192]: 2019-09-27T14:46:17.641+0300#011INFO#011elasticsearch/client.go:170#011Elasticsearch url: http://johannesburg.cmp.org:9200
> Sep 27 14:46:17 bisArch filebeat[2192]: 2019-09-27T14:46:17.641+0300#011INFO#011elasticsearch/client.go:170#011Elasticsearch url: http://johannesburg.cmp.org:9200
> Sep 27 14:46:17 bisArch filebeat[2192]: 2019-09-27T14:46:17.740+0300#011INFO#011elasticsearch/client.go:743#011Attempting to connect to Elasticsearch version 7.3.1
> Sep 27 14:46:17 bisArch filebeat[2192]: 2019-09-27T14:46:17.818+0300#011INFO#011fileset/pipelines.go:134#011Elasticsearch pipeline with ID 'filebeat-7.3.2-pipeline' loaded
> Sep 27 14:46:17 bisArch filebeat[2192]: 2019-09-27T14:46:17.818+0300#011INFO#011input/input.go:114#011Starting input of type: log; ID: 14283980320964143642
> Sep 27 14:46:17 bisArch filebeat[2192]: 2019-09-27T14:46:17.818+0300#011INFO#011cfgfile/reload.go:226#011Loading of config files completed.
> Sep 27 14:46:20 bisArch filebeat[2192]: 2019-09-27T14:46:20.288+0300#011INFO#011log/harvester.go:253#011Harvester started for file: //bis/PATH/cut_20190925_050827_008362.txt
> 
> ```

это размер data.json 27кб, 6 минут.

---

<div class="post-metadata">

**Author:** ![Dima\_I](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/dima_i/32/54877_2.png) [@Dima\_I](https://discuss.elastic.co/u/Dima_I)\
**Post date:** [September 27, 2019, 4:16pm UTC](https://discuss.elastic.co/t/filebeat/200967/19 "2019-09-27T16:16:20Z")

</div>

К сожалению, не вижу причин проблемы ☹ Судя по логам, filebeat загружает registry и начинает обрабатывать events после второго перезапуска. Почему они не появляются в Elasticsearch - загадка. Я подозреваю, что отсутствие записей о elasticsearch client и crawler в логе после второго перезапуска - это нормально. Постараюсь поглядеть код или пообщаться с разработчиками.

> [@Axizdkr](#):
>
> я предполагаю что по достижении какого-то размера самого data.json файлбит начинает некорректно работать, но опять же, у меня только после перезапуска.

судя по логам, ничего пока не подтверждает данную теорию.

---

<div class="post-metadata">

**Author:** ![Axizdkr](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/axizdkr/32/54875_2.png) [@Axizdkr](https://discuss.elastic.co/u/Axizdkr)\
**Post date:** [September 27, 2019, 7:40pm UTC](https://discuss.elastic.co/t/filebeat/200967/20 "2019-09-27T19:40:19Z")

</div>

> [@Dima\_I](#):
>
> Судя по логам, filebeat загружает registry и начинает обрабатывать events после второго перезапуска.

да же по логам не видно что бы файлбит начал данные отправлять, когда он работает появляются строчки вроде

```auto
Sep 27 14:46:20 bisArch filebeat[2192]: 2019-09-27T14:46:20.288+0300#011INFO#011log/harvester.go:253#011Harvester started for file: //bis/PATH/cut_20190925_050827_008362.txt

```

а когда не работает их просто нет, при чём нет ни в дебаге, не в инфо, может быть он при повторном запуске все файлы которые уже записал в регистр проверяет? Но судя по времени делает это даже дольше чем если бы просто их передавал с нуля в эластик, а на большом количестве файлов время слишком много тратит, я просто не успеваю дождаться.

[Next page](https://discuss.elastic.co/t/filebeat/200967.md?page=2)