Filebeat spams our Graylog server

1. Describe your incident:

We have various servers which create multi line PHP stack traces.
To collect these we use Filebeat.
We have a working config (see below) but it works only on one server as soon as we apply it to a second server, it starts to send huge amounts of logs.

We already use a similar config successfully on all our PHP servers, only the part with “drupal” is new.

Interestingly we don’t see the logs on the server, just in the license overview we see a huge spike and Graylog complains about too many messages.

2. Describe your environment:

  • OS Information:
    Ubuntu 22.04

  • Package Version:
    Graylog Enterprise is version 5.0.5 running in Docker
    Graylog Sidecar is Version: 1.4.0-2

3. What steps have you already taken to try and solve the problem?

We’ve tried various configs for many hours, e.g. trying different parsers (syslog) but the problem happens there as well.
When we use the syslog parser it happens immediately even when use just one server.

4. How can the community help?

Does someone know if there is a bug in Filebeat/Sidecar which might cause this?

Service logs, configurations, and environment variables:

Sidecar Config

# Needed for Graylog
fields_under_root: true
fields.collector_node_id: ${sidecar.nodeName}
fields.gl2_source_collector: ${sidecar.nodeId}

filebeat.inputs:
- type: filestream
  id: nginx-error
  paths:
    - /var/log/nginx/error.log
    - /var/log/nginx/error.log.1
  prospector.scanner.exclude_files: ['\.gz$']
  fields:
    application_name: "nginx-error"
    level: "3"
  parsers:
    - multiline:
        type: pattern
        pattern: '^[0-9]{4}/[0-9]{2}/[0-9]{2}'
        negate: true
        match: after

- type: journald
  id: php-error
  include_matches.and:
    - match:
      - "syslog.identifier=php"
  fields:
    application_name: "php-error"
  parsers:
    - multiline:
        type: pattern
        pattern: '^[0-9]{4}/[0-9]{2}/[0-9]{2}'
        negate: true
        match: after

- type: journald
  id: drupal
  include_matches.and:
    - match:
      - "syslog.identifier=drupallog"
  fields:
    application_name: "drupal"
  parsers:
    - multiline:
        type: pattern
        pattern: '^http'
        negate: true
        match: after
        
output.logstash:
   hosts: ["192.168.0.15:5044"]
path:
  data: /var/lib/graylog-sidecar/collectors/filebeat/data
  logs: /var/lib/graylog-sidecar/collectors/filebeat/log

docker-compose.yml

version: "3"
services:
  proxy:
    image: nginx:1.23.4
    volumes:
      - ./nginx:/etc/nginx/conf.d
      - "/etc/letsencrypt:/etc/letsencrypt:ro"
      - "/etc/timezone:/etc/timezone:ro"
      - "/etc/localtime:/etc/localtime:ro"
    restart: unless-stopped
    ports:
      - 80:80
      - 443:443
    networks:
      - graylog

  # MongoDB: https://hub.docker.com/_/mongo/
  mongo:
    image: mongo:5.0.15
    volumes:
      - ./mongo_data:/data/db
      - "/etc/timezone:/etc/timezone:ro"
      - "/etc/localtime:/etc/localtime:ro"
    restart: unless-stopped
    networks:
      - graylog

  # Elasticsearch: https://www.elastic.co/guide/en/elasticsearch/reference/6.x/docker.html
  elasticsearch:
    image: docker.elastic.co/elasticsearch/elasticsearch-oss:7.10.2
    volumes:
      - ./elasticsearch_data:/usr/share/elasticsearch/data
      - "/etc/timezone:/etc/timezone:ro"
      - "/etc/localtime:/etc/localtime:ro"
    restart: unless-stopped
    environment:
      - http.host=0.0.0.0
      - transport.host=localhost
      - network.host=0.0.0.0
      - "ES_JAVA_OPTS=-Xms512m -Xmx512m -Dlog4j2.formatMsgNoLookups=true"
    ulimits:
      memlock:
        soft: -1
        hard: -1
    networks:
      - graylog

  # Graylog: https://hub.docker.com/r/graylog/graylog-enterprise
  # https://www.graylog.org/downloads-2
  graylog:
    image: graylog/graylog-enterprise:5.0.5
    volumes:
      - ./graylog_journal:/usr/share/graylog/data/journal
      - ./geodb:/mnt/geodb
      - "/etc/timezone:/etc/timezone:ro"
      - "/etc/localtime:/etc/localtime:ro"
    restart: unless-stopped
    environment:
      - GRAYLOG_PASSWORD_SECRET
      - GRAYLOG_ROOT_PASSWORD_SHA2
      - GRAYLOG_HTTP_EXTERNAL_URI
      - GRAYLOG_HTTP_PUBLISH_URI
      - GRAYLOG_TRANSPORT_EMAIL_ENABLED
      - GRAYLOG_TRANSPORT_EMAIL_HOSTNAME
      - GRAYLOG_TRANSPORT_EMAIL_PORT
      - GRAYLOG_TRANSPORT_EMAIL_USE_AUTH
      - GRAYLOG_TRANSPORT_EMAIL_USE_TLS
      - GRAYLOG_TRANSPORT_EMAIL_USE_SSL
      - GRAYLOG_TRANSPORT_EMAIL_AUTH_USERNAME
      - GRAYLOG_TRANSPORT_EMAIL_AUTH_PASSWORD
      - GRAYLOG_TRANSPORT_EMAIL_FROM_EMAIL
      - GRAYLOG_ROOT_TIMEZONE
      - GRAYLOG_ROOT_EMAIL
      - GRAYLOG_REPORT_DISABLE_SANDBOX
    depends_on:
      - mongo
      - elasticsearch
    ports:
      # Syslog TCP
      - 5140:514
      # Syslog UDP
      - 5140:514/udp
      # Logstash
      - 5044:5044
    networks:
      graylog:
        ipv4_address: 172.20.0.10

networks:
  graylog:
    ipam:
      config:
        - subnet: 172.20.0.0/24

example log entries

Mar 31 09:50:28 SERVERNAME drupallog[2195001]: http://example.com|1680249028|page not found|10.20.0.10|http://example.com/de||0||/de
Mar 31 09:50:29 SERVERNAME drupallog[2195183]: http://example.com|1680249029|page not found|10.20.0.10|http://example.com/de||0||/de
Mar 31 09:51:45 SERVERNAME drupallog[2195182]: http://example.com php http://example.com/de/Stiftung  0  Error: Call to a member fun>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #1 [internal function]: Drupal\Core\Entity\EntityViewBuilder->build()
Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #2 /var/www/example.com/src/drupal/core/lib/Drupal/Core/Security/DoTrustedCallbackTrait.php(101): call_user_func_array()
Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #3 /var/www/example.com/src/drupal/core/lib/Drupal/Core/Render/Renderer.php(788): Drupal\Core\Render\Renderer->doTrustedCallba>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #4 /var/www/example.com/src/drupal/core/lib/Drupal/Core/Render/Renderer.php(374): Drupal\Core\Render\Renderer->doCallback()    Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #5 /var/www/example.com/src/drupal/core/lib/Drupal/Core/Render/Renderer.php(204): Drupal\Core\Render\Renderer->doRender()      Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #6 /var/www/example.com/src/drupal/core/lib/Drupal/Core/Template/TwigExtension.php(479): Drupal\Core\Render\Renderer->render() Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #7 /var/www/example.com/src/drupal/sites/default/files/php/twig/6422e766066a7_field.html.twig_p4L31WYsjEHswxsFt-jp_ir6r/PWxP_p>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #8 /var/www/example.com/src/drupal/vendor/twig/twig/src/Template.php(405): __TwigTemplate_05c49682a6db42eee4f6afc25c3dd445->do>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #9 /var/www/example.com/src/drupal/vendor/twig/twig/src/Template.php(378): Twig\Template->displayWithErrorHandling()
Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #10 /var/www/example.com/src/drupal/vendor/twig/twig/src/Template.php(390): Twig\Template->display()
Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #11 /var/www/example.com/src/drupal/core/themes/engines/twig/twig.engine(55): Twig\Template->render()
Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #12 /var/www/example.com/src/drupal/core/lib/Drupal/Core/Theme/ThemeManager.php(384): twig_render_template()
Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #13 /var/www/example.com/src/drupal/core/lib/Drupal/Core/Render/Renderer.php(433): Drupal\Core\Theme\ThemeManager->render()
Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #14 /var/www/example.com/src/drupal/core/lib/Drupal/Core/Render/Renderer.php(446): Drupal\Core\Render\Renderer->doRender()     Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #15 /var/www/example.com/src/drupal/core/lib/Drupal/Core/Render/Renderer.php(204): Drupal\Core\Render\Renderer->doRender()     Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #16 /var/www/example.com/src/drupal/core/lib/Drupal/Core/Template/TwigExtension.php(479): Drupal\Core\Render\Renderer->render()Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #17 /var/www/example.com/src/drupal/sites/default/files/php/twig/6422e766066a7_node.html.twig_nu-hH4aanjF28oByQszk9PFQ5/uZev0E>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #18 /var/www/example.com/src/drupal/vendor/twig/twig/src/Template.php(405): __TwigTemplate_cea69740ec70771c43771577b5b30e56->d>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #19 /var/www/example.com/src/drupal/vendor/twig/twig/src/Template.php(378): Twig\Template->displayWithErrorHandling()
Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #20 /var/www/example.com/src/drupal/vendor/twig/twig/src/Template.php(390): Twig\Template->display()
Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #21 /var/www/example.com/src/drupal/core/themes/engines/twig/twig.engine(55): Twig\Template->render()
Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #22 /var/www/example.com/src/drupal/core/lib/Drupal/Core/Theme/ThemeManager.php(384): twig_render_template()
Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #23 /var/www/example.com/src/drupal/core/lib/Drupal/Core/Render/Renderer.php(433): Drupal\Core\Theme\ThemeManager->render()
Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #24 /var/www/example.com/src/drupal/core/lib/Drupal/Core/Render/Renderer.php(204): Drupal\Core\Render\Renderer->doRender()     Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #25 /var/www/example.com/src/drupal/core/lib/Drupal/Core/Render/MainContent/HtmlRenderer.php(242): Drupal\Core\Render\Renderer>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #26 /var/www/example.com/src/drupal/core/lib/Drupal/Core/Render/Renderer.php(580): Drupal\Core\Render\MainContent\HtmlRenderer>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #27 /var/www/example.com/src/drupal/core/lib/Drupal/Core/Render/MainContent/HtmlRenderer.php(243): Drupal\Core\Render\Renderer>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #28 /var/www/example.com/src/drupal/core/lib/Drupal/Core/Render/MainContent/HtmlRenderer.php(132): Drupal\Core\Render\MainCont>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #29 /var/www/example.com/src/drupal/core/lib/Drupal/Core/EventSubscriber/MainContentViewSubscriber.php(90): Drupal\Core\Render>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #30 [internal function]: Drupal\Core\EventSubscriber\MainContentViewSubscriber->onViewRenderArray()
Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #31 /var/www/example.com/src/drupal/core/lib/Drupal/Component/EventDispatcher/ContainerAwareEventDispatcher.php(142): call_use>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #32 /var/www/example.com/src/drupal/vendor/symfony/http-kernel/HttpKernel.php(174): Drupal\Component\EventDispatcher\Container>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #33 /var/www/example.com/src/drupal/vendor/symfony/http-kernel/HttpKernel.php(81): Symfony\Component\HttpKernel\HttpKernel->ha>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #34 /var/www/example.com/src/drupal/core/lib/Drupal/Core/StackMiddleware/Session.php(58): Symfony\Component\HttpKernel\HttpKer>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #35 /var/www/example.com/src/drupal/core/lib/Drupal/Core/StackMiddleware/KernelPreHandle.php(48): Drupal\Core\StackMiddleware\>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #36 /var/www/example.com/src/drupal/core/modules/page_cache/src/StackMiddleware/PageCache.php(191): Drupal\Core\StackMiddlewar>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #37 /var/www/example.com/src/drupal/core/modules/page_cache/src/StackMiddleware/PageCache.php(128): Drupal\page_cache\StackMid>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #38 /var/www/example.com/src/drupal/core/modules/page_cache/src/StackMiddleware/PageCache.php(82): Drupal\page_cache\StackMidd>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #39 /var/www/example.com/src/drupal/core/lib/Drupal/Core/StackMiddleware/ReverseProxyMiddleware.php(48): Drupal\page_cache\Sta>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #40 /var/www/example.com/src/drupal/core/lib/Drupal/Core/StackMiddleware/NegotiationMiddleware.php(51): Drupal\Core\StackMiddl>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #41 /var/www/example.com/src/drupal/vendor/stack/builder/src/Stack/StackedHttpKernel.php(23): Drupal\Core\StackMiddleware\Nego>Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #42 /var/www/example.com/src/drupal/core/lib/Drupal/Core/DrupalKernel.php(718): Stack\StackedHttpKernel->handle()
Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #43 /var/www/example.com/src/drupal/index.php(19): Drupal\Core\DrupalKernel->handle()
Mar 31 09:51:45 SERVERNAME drupallog[2195182]: #44 {main}.

Hey @ContriaConnect ,

It would be useful to see exactly what logs are hitting the Graylog server. Could a pcap be done or tcpdump to make sure you are receiving what is what is expected given your sidecar config.

Seeing as the log messages are being ingested but are not appearing in search, is there a possibility they are arriving with timestamp either within the past or future?

I can try to do that, it’s a bit difficult given the amount of traffic we’re generating.
It constantly kicks us over the 2 GB / day license limit.

I thought about that as well but I don’t see them when I look at the whole time range.
In addition, all logs on one server are around 4-5 GB combined. Even if I would ingest all logs by accident I would expect an increase of max. 5 GB but we hit 37 GB on the 29th.
For comparison all our systems combined generate around 1.7 GB / day, which are around 70 VMs all together plus all the physical hardware.

Instead you could query OS/ES directly to list messages by source. Without understanding what is being ingested it’s difficult to see where the problem is.

You could try removing one instance on journald from the Filebeat config, start with only the id match for drupal and see if ingest drops.

Querying the ES is a good idea, might be easier to understand than tcpdumps.

I tried that, the problem persists.

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