Filebeat log input not re-scanning at scan_duration

Short description:

I have a log input set to scan every 5 seconds. With full debug logs turned on I
see
2020-05-20T19:29:06.606Z DEBUG [input] log/input.go:191 Start next scan

Which discovers some files, but then I never see it again

ubuntu@ip-192-168-16-196:~$ docker logs f233 2>&1 | grep "scan"
2020-05-20T19:29:06.606Z        DEBUG   [input] log/input.go:191        Start next scan

Furthermore I never see the line "Run input" which should be printed here https://github.com/elastic/beats/blob/52fa26598cef8a90c8981970414c780e4fd31dbf/filebeat/input/input.go#L141

Indicating the loop isnt running

Not sure if I'm missing something but it seems like maybe theres a bug where the scan is stuck and not returning, so it never runs again.

More details:

All input logs

ubuntu@ip-192-168-16-196:~$ date
Wed May 20 19:43:37 UTC 2020

ubuntu@ip-192-168-16-196:~$ docker logs f233 2>&1 | grep "input"
2020-05-20T19:29:06.476Z        DEBUG   [input] log/config.go:204       recursive glob enabled
2020-05-20T19:29:06.476Z        DEBUG   [input] log/input.go:164        exclude_files: []. Number of states: 99
2020-05-20T19:29:06.476Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/10f8f0f3-a83f-955f-b68d-a90d6e222961/alloc/logs/browser.stdout.0
2020-05-20T19:29:06.476Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/88c2a7b3-cf94-be86-f259-6de0c244aa78/alloc/logs/filebeat.stderr.0
2020-05-20T19:29:06.476Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/94d697ef-ee5e-548b-a274-c2b852550694/alloc/logs/browser.stderr.0
2020-05-20T19:29:06.480Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/41d4d191-713a-d653-aff7-66a1c1855f22/alloc/logs/browser.stderr.0
2020-05-20T19:29:06.480Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/58d622fa-196c-3255-3bde-951fca64b15f/alloc/logs/filebeat.stderr.0
2020-05-20T19:29:06.483Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/c6d5b648-d40c-df30-a45e-b91d2e367e3a/alloc/logs/browser.stderr.0
2020-05-20T19:29:06.486Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/85ce842c-037a-48cf-7150-3b218d6c7e4e/alloc/logs/browser.stderr.0
2020-05-20T19:29:06.490Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/47d90b32-410a-e367-069b-5f1126651159/alloc/logs/browser.stdout.0
2020-05-20T19:29:06.493Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/4e47f814-df09-ce2d-4c53-2432ec235afc/alloc/logs/filebeat.stderr.0
2020-05-20T19:29:06.498Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/47af4bf0-557b-5ddf-148d-d0969900dfd2/alloc/logs/orchestrator.stdout.0
2020-05-20T19:29:06.502Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/55e0f41a-3258-2d07-02b5-6e234eb4bdfd/alloc/logs/browser.stderr.0
2020-05-20T19:29:06.505Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/f30588e4-096a-c7cb-d51f-6cdc76a217a1/alloc/logs/browser.stderr.0
2020-05-20T19:29:06.509Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/b5374f8f-9da5-2896-16a1-8bc1a0a9ac1c/alloc/logs/browser.stderr.0
2020-05-20T19:29:06.513Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/d01919b0-f3e5-31b0-0945-e11eea70a833/alloc/logs/browser.stderr.0
2020-05-20T19:29:06.516Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/0f5bc890-9f74-4595-5236-fa050692845e/alloc/logs/browser.stdout.0
2020-05-20T19:29:06.521Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/924c33b5-329d-5eb4-7487-1753a339d967/alloc/logs/browser.stdout.0
2020-05-20T19:29:06.525Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/309ca6f5-53f4-3572-28c8-f4cc46a3746a/alloc/logs/browser.stdout.0
2020-05-20T19:29:06.529Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/5d722831-7783-07bc-da5e-5ebc10398adc/alloc/logs/browser.stdout.0
2020-05-20T19:29:06.533Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/3d5e13ff-73d4-1901-2c00-43d64fd9e2c8/alloc/logs/filebeat.stdout.0
2020-05-20T19:29:06.538Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/1a6576c3-ae7d-cc97-f959-dfac7e1a3e1c/alloc/logs/orchestrator.stdout.0
2020-05-20T19:29:06.543Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/441383f3-611d-d574-1037-c0006b99c598/alloc/logs/browser.stdout.0
2020-05-20T19:29:06.548Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/8d1275c0-362e-fe06-7be2-58ff6a52a37a/alloc/logs/browser.stdout.0
2020-05-20T19:29:06.553Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/9efdb723-3770-cedf-dc3f-f14c4f9b30c7/alloc/logs/browser.stderr.0
2020-05-20T19:29:06.558Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/0d03482e-0246-8586-b6dc-2f1bcf1ecadc/alloc/logs/browser.stdout.0
2020-05-20T19:29:06.562Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/e7a7ee76-8c5f-a880-039c-8f7f3e4d263e/alloc/logs/browser.stdout.0
2020-05-20T19:29:06.566Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/23453bc0-84c0-571b-c4e1-ae52348cc207/alloc/logs/orchestrator.stdout.0
2020-05-20T19:29:06.571Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/5d722831-7783-07bc-da5e-5ebc10398adc/alloc/logs/browser.stderr.0
2020-05-20T19:29:06.575Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/810917a8-28b8-db76-5a49-b312ec653141/alloc/logs/browser.stdout.0
2020-05-20T19:29:06.580Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/1098a232-9abd-fcc9-8607-04c4da3855b2/alloc/logs/orchestrator.stdout.0
2020-05-20T19:29:06.585Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/700e2d2c-0fd4-841f-08ff-e27fd335790b/alloc/logs/orchestrator.stdout.0
2020-05-20T19:29:06.589Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/95f34a81-9283-0e67-9228-ba9ff4dd3048/alloc/logs/test2.stderr.0
2020-05-20T19:29:06.594Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/9674274e-db84-caa7-8dc9-c86a4bae9ce2/alloc/logs/filebeat.stdout.0
2020-05-20T19:29:06.598Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/0687b2a0-2846-4c06-6cb0-865c66bfba2f/alloc/logs/browser.stdout.0
2020-05-20T19:29:06.602Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/5b7d4852-c981-5904-9428-e86e591cfc66/alloc/logs/browser.stdout.0
2020-05-20T19:29:06.606Z        DEBUG   [input] log/input.go:185        input with previous states loaded: 34
2020-05-20T19:29:06.606Z        INFO    log/input.go:152        Configured paths: [/opt/nomad/data/alloc/*/alloc/logs/*]
2020-05-20T19:29:06.606Z        INFO    input/input.go:114      Starting input of type: log; ID: 6359703886156017179 
2020-05-20T19:29:06.606Z        INFO    beater/crawler.go:105   Loading and starting Inputs completed. Enabled inputs: 1
2020-05-20T19:29:06.606Z        DEBUG   [input] log/input.go:191        Start next scan
2020-05-20T19:29:06.610Z        DEBUG   [input] log/input.go:421        Check file for harvesting: /opt/nomad/data/alloc/673b8a8e-4d96-ce56-3979-ae34831c6d2c/alloc/logs/filebeat.stdout.0
2020-05-20T19:29:06.610Z        DEBUG   [input] log/input.go:494        Start harvester for new file: /opt/nomad/data/alloc/673b8a8e-4d96-ce56-3979-ae34831c6d2c/alloc/logs/filebeat.stdout.0
2020-05-20T19:29:06.613Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/673b8a8e-4d96-ce56-3979-ae34831c6d2c/alloc/logs/filebeat.stdout.0
2020-05-20T19:29:06.613Z        DEBUG   [input] log/input.go:421        Check file for harvesting: /opt/nomad/data/alloc/95f34a81-9283-0e67-9228-ba9ff4dd3048/alloc/logs/test2.stderr.0
2020-05-20T19:29:06.613Z        DEBUG   [input] log/input.go:511        Update existing file for harvesting: /opt/nomad/data/alloc/95f34a81-9283-0e67-9228-ba9ff4dd3048/alloc/logs/test2.stderr.0, offset: 2
2020-05-20T19:29:06.613Z        DEBUG   [input] log/input.go:565        File didn't change: /opt/nomad/data/alloc/95f34a81-9283-0e67-9228-ba9ff4dd3048/alloc/logs/test2.stderr.0
2020-05-20T19:29:06.613Z        DEBUG   [input] log/input.go:421        Check file for harvesting: /opt/nomad/data/alloc/bff55475-edc1-2eee-9495-3aa4687d90a5/alloc/logs/.browser.stderr.fifo
2020-05-20T19:29:06.613Z        DEBUG   [input] log/input.go:494        Start harvester for new file: /opt/nomad/data/alloc/bff55475-edc1-2eee-9495-3aa4687d90a5/alloc/logs/.browser.stderr.fifo
2020-05-20T19:29:06.626Z        DEBUG   [input] file/states.go:68       New state added for /opt/nomad/data/alloc/673b8a8e-4d96-ce56-3979-ae34831c6d2c/alloc/logs/filebeat.stdout.0

My config:

ubuntu@ip-192-168-16-196:~$ docker exec f233a cat /local/config/filebeat.yml
setup.ilm:
  # TODO: Enable once bug is fixed; in the meantime policy must be created manually
  # https://github.com/elastic/beats/issues/11866
  enabled: false
  policy_name: filebeat-2
setup.template:
  enabled: true
  overwrite: false
  json:
    enabled: true
    name: "filebeat-2"
  name: filebeat-2
  pattern: "filebeat-2-*"
logging.level: debug
filebeat.inputs:
  - type: log
    fields:
      source: nomad-task
    paths:
      - /opt/nomad/data/alloc/*/alloc/logs/*
    scan_frequency: 5s
    processors:
      - add_cloud_metadata: ~

processors:
  - drop_fields:
      fields:
        [
          "agent.id",
          "agent.ephemeral_id",
          "agent.type",
          "ecs.version",
          "agent.hostname",
          "docker.container.labels.com_amazonaws_ecs_task-definition-family",
          "docker.container.labels.com_amazonaws_ecs_task-arn",
          "docker.container.labels.org_label-schema_build-date"
        ]
  - add_fields:
      target: ""
      fields:
        environment: "bbuzbee"
        region: "us-west-2"
        nomad_pool: "browsers"

output.elasticsearch:
  hosts:
    [
      "<REDACTED>",
    ]
  index: "<REDACTED>"
  username: "<REDACTED>"
  password: ""

Debugged. The issue happens if a FIFO not opened for writing exists in the path glob pattern

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.