Metric libbeat.output.write.bytes does not change for type elasticsearch #20752

EugRomanchenko · 2020-08-24T08:54:20Z

Version: 7.7.0+
Operating System: Debian 9.12
Discuss Forum URLs:
- https://discuss.elastic.co/t/filebeat-metric-libbeat-output-write-bytes-does-not-change-for-type-elasticsearch/245563
- https://discuss.elastic.co/t/filebeat-monitoring-metrics-sent-bytes-and-throughput-shown-as-0/246215
Steps to Reproduce:
- Update from Filebeat 7.6.2 to 7.7.0 +
- Configure sending logs to Elasticsearch
- Enable http Endpoint for gathering internal Filebeat metrics
- Make sure logs are successfully sent to ES
- Make a request to curl -s -XGET 'localhost:5066/stats?pretty'
- Make sure the metric libbeat.output.write.bytes doesn't change

    "libbeat": {
    "config": {
      "module": {
        "running": 0,
        "starts": 0,
        "stops": 0
      },
      "reloads": 1,
      "scans": 1
    },
    "output": {
      "events": {
        "acked": 803127,
        "active": 0,
        "batches": 58574,
        "dropped": 0,
        "duplicates": 0,
        "failed": 0,
        "toomany": 0,
        "total": 803127
      },
      "read": {
        "bytes": 0,
        "errors": 0
      },
      "type": "elasticsearch",
      "write": {
        "bytes": 0,
        "errors": 0
      }
    },

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

EugRomanchenko · 2020-08-24T11:54:27Z

Sorry, but I cannot add labels because I am not a contributor. If someone can add tags to the issue, I would be grateful (Filebeat, bug, Team: Integrations).

elasticmachine · 2020-08-24T13:44:52Z

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

EugRomanchenko · 2020-09-07T09:33:12Z

Any news about this bug? A small addition about the problem. We are using the Filebeat OSS version (We rolled it back to version 7.6.2. The bug was checked on all versions released after 7.6.2.). AWS Elasticsearch version 7.7 acts as the recipient of the logs.

bvader · 2020-09-16T15:36:51Z

@andresrc , @kvch I have a large user that is seeing this issue as well. Is there any update?
Below is all 7.9.1 Stack

ycombinator · 2020-09-17T09:48:20Z

More users are reporting this issue on discuss: https://discuss.elastic.co/t/filebeat-monitoring-metrics-sent-bytes-and-throughput-shown-as-0/246215

andresrc · 2020-09-17T12:49:37Z

Thanks, we'll take a look as soon as possible

## What does this PR do? This PR passes a missing parameter to the constructor `elasticsearch.Client`. ## Why is it important? The missing parameter prevented Beats from reporting the metrics `libbeat.output.write.bytes` and `libbeat.output.read.bytes` in case of Elasticsearch output. ## Related issues Closes #20752

…1197) ## What does this PR do? This PR passes a missing parameter to the constructor `elasticsearch.Client`. ## Why is it important? The missing parameter prevented Beats from reporting the metrics `libbeat.output.write.bytes` and `libbeat.output.read.bytes` in case of Elasticsearch output. ## Related issues Closes elastic#20752 (cherry picked from commit 78dc0cf)

…21211) * Add Known issues section with an issue about Functionbeat * Fix libbeat.output.*.bytes metrics of Elasticsearch output (#21197) ## What does this PR do? This PR passes a missing parameter to the constructor `elasticsearch.Client`. ## Why is it important? The missing parameter prevented Beats from reporting the metrics `libbeat.output.write.bytes` and `libbeat.output.read.bytes` in case of Elasticsearch output. ## Related issues Closes #20752 (cherry picked from commit 78dc0cf)

…21210) ## What does this PR do? This PR passes a missing parameter to the constructor `elasticsearch.Client`. ## Why is it important? The missing parameter prevented Beats from reporting the metrics `libbeat.output.write.bytes` and `libbeat.output.read.bytes` in case of Elasticsearch output. ## Related issues Closes #20752 (cherry picked from commit 78dc0cf)

EugRomanchenko · 2020-10-06T08:33:09Z

Looks like this bug is still present in 7.9.2 version (#21197).

andresrc · 2020-10-08T05:33:58Z

@kvch can you take a look?

kvch · 2020-10-08T09:47:51Z

@EugRomanchenko could you please share the logs of Filebeat?

EugRomanchenko · 2020-10-08T10:11:34Z

Sure.

2020-10-08T10:01:53.520Z	INFO	instance/beat.go:648	Beat ID: c52ef7f0-3a6e-4092-8111-7e6b40f4637c
2020-10-08T10:01:53.522Z	INFO	[api]	api/server.go:62	Starting stats endpoint
2020-10-08T10:01:53.522Z	INFO	[seccomp]	seccomp/seccomp.go:124	Syscall filter successfully installed
2020-10-08T10:01:53.522Z	INFO	[beat]	instance/beat.go:976	Beat info	{"system_info": {"beat": {"path": {"config": "/etc/filebeat", "data": "/var/lib/filebeat", "home": "/usr/share/filebeat", "logs": "/var/log/filebeat"}, "type": "filebeat", "uuid": "c52ef7f0-3a6e-4092-8111-7e6b40f4637c"}}}
2020-10-08T10:01:53.522Z	INFO	[beat]	instance/beat.go:985	Build info	{"system_info": {"build": {"commit": "2ab907f5ccecf9fd82fe37105082e89fd871f684", "libbeat": "7.9.2", "time": "2020-09-22T22:22:35.000Z", "version": "7.9.2"}}}
2020-10-08T10:01:53.523Z	INFO	[beat]	instance/beat.go:988	Go runtime info	{"system_info": {"go": {"os":"linux","arch":"amd64","max_procs":2,"version":"go1.14.7"}}}
2020-10-08T10:01:53.523Z	INFO	[add_cloud_metadata]	add_cloud_metadata/add_cloud_metadata.go:93	add_cloud_metadata: hosting provider type detected as aws, metadata={"account":{"id":"413248584035"},"availability_zone":"eu-west-1b","image":{"id":"ami-9569727f"},"instance":{"id":"i-0a0f814d07d6fb74e"},"machine":{"type":"t3a.small"},"provider":"aws","region":"eu-west-1"}
2020-10-08T10:01:53.523Z	INFO	[beat]	instance/beat.go:992	Host info	{"system_info": {"host": {"architecture":"x86_64","boot_time":"2020-08-12T11:05:17Z","containerized":false,"name":"dc6dev-kp00","ip":["127.0.0.1/8","10.30.50.70/26","172.17.0.1/16"],"kernel_version":"4.9.0-13-amd64","mac":["0a:4a:35:e4:3c:a2","02:42:51:d1:7c:c3"],"os":{"family":"debian","platform":"debian","name":"Debian GNU/Linux","version":"9 (stretch)","major":9,"minor":0,"patch":0,"codename":"stretch"},"timezone":"UTC","timezone_offset_sec":0,"id":"c494cb49c0f94a0582cf0ce163145bc5"}}}
2020-10-08T10:01:53.524Z	INFO	[api]	api/server.go:64	Metrics endpoint listening on: 127.0.0.1:5066 (configured: localhost)
2020-10-08T10:01:53.524Z	INFO	[beat]	instance/beat.go:1021	Process info	{"system_info": {"process": {"capabilities": {"inheritable":null,"permitted":["chown","dac_override","dac_read_search","fowner","fsetid","kill","setgid","setuid","setpcap","linux_immutable","net_bind_service","net_broadcast","net_admin","net_raw","ipc_lock","ipc_owner","sys_module","sys_rawio","sys_chroot","sys_ptrace","sys_pacct","sys_admin","sys_boot","sys_nice","sys_resource","sys_time","sys_tty_config","mknod","lease","audit_write","audit_control","setfcap","mac_override","mac_admin","syslog","wake_alarm","block_suspend","audit_read"],"effective":["chown","dac_override","dac_read_search","fowner","fsetid","kill","setgid","setuid","setpcap","linux_immutable","net_bind_service","net_broadcast","net_admin","net_raw","ipc_lock","ipc_owner","sys_module","sys_rawio","sys_chroot","sys_ptrace","sys_pacct","sys_admin","sys_boot","sys_nice","sys_resource","sys_time","sys_tty_config","mknod","lease","audit_write","audit_control","setfcap","mac_override","mac_admin","syslog","wake_alarm","block_suspend","audit_read"],"bounding":["chown","dac_override","dac_read_search","fowner","fsetid","kill","setgid","setuid","setpcap","linux_immutable","net_bind_service","net_broadcast","net_admin","net_raw","ipc_lock","ipc_owner","sys_module","sys_rawio","sys_chroot","sys_ptrace","sys_pacct","sys_admin","sys_boot","sys_nice","sys_resource","sys_time","sys_tty_config","mknod","lease","audit_write","audit_control","setfcap","mac_override","mac_admin","syslog","wake_alarm","block_suspend","audit_read"],"ambient":null}, "cwd": "/", "exe": "/usr/share/filebeat/bin/filebeat", "name": "filebeat", "pid": 4424, "ppid": 1, "seccomp": {"mode":"filter"}, "start_time": "2020-10-08T10:01:53.240Z"}}}
2020-10-08T10:01:53.524Z	INFO	instance/beat.go:299	Setup Beat: filebeat; Version: 7.9.2
2020-10-08T10:01:53.525Z	INFO	eslegclient/connection.go:99	elasticsearch url: https://ES_URL:443
2020-10-08T10:01:53.525Z	INFO	[publisher]	pipeline/module.go:113	Beat name: XXXXXX
2020-10-08T10:01:53.526Z	INFO	[monitoring]	log/log.go:118	Starting metrics logging every 1h0m0s
2020-10-08T10:01:53.526Z	INFO	instance/beat.go:450	filebeat start running.
2020-10-08T10:01:53.528Z	INFO	memlog/store.go:119	Loading data file of '/var/lib/filebeat/registry/filebeat' succeeded. Active transaction id=225306
2020-10-08T10:01:54.031Z	INFO	memlog/store.go:124	Finished loading transaction log file for '/var/lib/filebeat/registry/filebeat'. Active transaction id=240815
2020-10-08T10:01:54.031Z	INFO	[registrar]	registrar/registrar.go:109	States Loaded from registrar: 4
2020-10-08T10:01:54.031Z	INFO	[crawler]	beater/crawler.go:71	Loading Inputs: 1
2020-10-08T10:01:54.032Z	INFO	log/input.go:157	Configured paths: [/log_path_1/application_1-json.log /log_path_2/application_2.json /log_path_3/application_3.json]
2020-10-08T10:01:54.033Z	INFO	[crawler]	beater/crawler.go:141	Starting input (ID: 1150674913014489370)
2020-10-08T10:01:54.033Z	INFO	[crawler]	beater/crawler.go:108	Loading and starting Inputs completed. Enabled inputs: 1
2020-10-08T10:01:54.034Z	INFO	cfgfile/reload.go:164	Config reloader started
2020-10-08T10:02:34.038Z	INFO	log/harvester.go:299	Harvester started for file: /var/log/assist/dispatch/profile5/test/dispatchd.json
2020-10-08T10:02:34.039Z	INFO	log/harvester.go:299	Harvester started for file: /var/log/assist/dispatch/profilefiscal/test/dispatchd.json
2020-10-08T10:02:35.039Z	INFO	[publisher_pipeline_output]	pipeline/output.go:143	Connecting to backoff(elasticsearch(https://ES_URL:443))
2020-10-08T10:02:35.039Z	INFO	[publisher]	pipeline/retry.go:219	retryer: send unwait signal to consumer
2020-10-08T10:02:35.039Z	INFO	[publisher]	pipeline/retry.go:223	  done
2020-10-08T10:02:35.373Z	INFO	[esclientleg]	eslegclient/connection.go:314	Attempting to connect to Elasticsearch version 7.7.0
2020-10-08T10:02:35.375Z	INFO	[esclientleg]	eslegclient/connection.go:314	Attempting to connect to Elasticsearch version 7.7.0
2020-10-08T10:02:35.379Z	INFO	template/load.go:89	Template filebeat-7.9.2 already exists and will not be overwritten.
2020-10-08T10:02:35.379Z	INFO	[index-management]	idxmgmt/std.go:298	Loaded index template.
2020-10-08T10:02:35.382Z	INFO	[publisher_pipeline_output]	pipeline/output.go:151	Connection to backoff(elasticsearch(https://ES_URL:443)) established

kvch · 2020-10-08T11:11:09Z

Could you please include lines which include metrics? Lines which start with "Total non-zero metrics"? Also, the output of the metrics endpoint would be nice (curl -s -XGET 'localhost:5066/stats?pretty').

EugRomanchenko · 2020-10-08T11:20:02Z

Filebeat Logs

2020-10-08T11:01:53.531Z        INFO    [monitoring]    log/log.go:145  Non-zero metrics in the last 1h0m0s     {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1350,"time":{"ms":1356}},"total":{"ticks":3450,"time":{"ms":3460},"value":0},"user":{"ticks":2100,"time":{"ms":2104}}},"handles":{"limit":{"hard":4096,"soft":1024},"open":15},"info":{"ephemeral_id":"2155e5ac-f295-44d4-918d-12974fdec8c8","uptime":{"ms":3600050}},"memstats":{"gc_next":11924496,"memory_alloc":7318816,"memory_total":155496064,"rss":36954112},"runtime":{"goroutines":36}},"filebeat":{"events":{"added":1518,"done":1518},"harvester":{"closed":1,"files":{"77bc38e5-c90f-4ee1-91ef-8c4dff15e76f":{"last_event_published_time":"2020-10-08T11:00:07.270Z","last_event_timestamp":"2020-10-08T11:00:07.269Z","name":"/var/log/octopus/wstation/octopus-ws1-json.log","read_offset":123248,"size":123248,"start_time":"2020-10-08T11:00:04.268Z"},"94b98891-5fdd-437c-9afe-c06cd49398a2":{"last_event_published_time":"2020-10-08T11:01:00.509Z","last_event_timestamp":"2020-10-08T11:01:00.509Z","name":"/var/log/assist/dispatch/profile5/test/dispatchd.json","read_offset":2934545,"size":2934545,"start_time":"2020-10-08T10:02:34.038Z"},"c836bf6f-d921-458d-8671-af47c1176bcf":{"last_event_published_time":"2020-10-08T11:01:36.211Z","last_event_timestamp":"2020-10-08T11:01:36.211Z","name":"/var/log/assist/dispatch/profilefiscal/test/dispatchd.json","read_offset":77373,"size":75875,"start_time":"2020-10-08T10:02:34.038Z"}},"open_files":3,"running":3,"started":4}},"libbeat":{"config":{"module":{"running":0},"reloads":1,"scans":119},"output":{"events":{"acked":1507,"active":2,"batches":96,"dropped":2,"total":1511},"type":"elasticsearch"},"pipeline":{"clients":1,"events":{"active":0,"filtered":9,"published":1509,"retry":8,"total":1518},"queue":{"acked":1509}}},"registrar":{"states":{"current":4,"update":1518},"writes":{"success":103,"total":103}},"system":{"cpu":{"cores":2},"load":{"1":0.09,"15":0.09,"5":0.09,"norm":{"1":0.045,"15":0.045,"5":0.045}}}}}}

curl -s -XGET 'localhost:5066/stats?pretty'

{
  "beat": {
    "cpu": {
      "system": {
        "ticks": 1640,
        "time": {
          "ms": 1644
        }
      },
      "total": {
        "ticks": 4040,
        "time": {
          "ms": 4044
        },
        "value": 4040
      },
      "user": {
        "ticks": 2400,
        "time": {
          "ms": 2400
        }
      }
    },
    "handles": {
      "limit": {
        "hard": 4096,
        "soft": 1024
      },
      "open": 14
    },
    "info": {
      "ephemeral_id": "2155e5ac-f295-44d4-918d-12974fdec8c8",
      "uptime": {
        "ms": 4335351
      }
    },
    "memstats": {
      "gc_next": 11502288,
      "memory_alloc": 10121408,
      "memory_total": 176896680,
      "rss": 37867520
    },
    "runtime": {
      "goroutines": 31
    }
  },
  "filebeat": {
    "events": {
      "active": 0,
      "added": 1875,
      "done": 1875
    },
    "harvester": {
      "closed": 2,
      "files": {
        "94b98891-5fdd-437c-9afe-c06cd49398a2": {
          "last_event_published_time": "2020-10-08T11:12:57.604Z",
          "last_event_timestamp": "2020-10-08T11:12:57.603Z",
          "name": "/var/log/assist/dispatch/profile5/test/dispatchd.json",
          "read_offset": 3102966,
          "size": 3102966,
          "start_time": "2020-10-08T10:02:34.038Z"
        },
        "c836bf6f-d921-458d-8671-af47c1176bcf": {
          "last_event_published_time": "2020-10-08T11:12:41.232Z",
          "last_event_timestamp": "2020-10-08T11:12:41.232Z",
          "name": "/var/log/assist/dispatch/profilefiscal/test/dispatchd.json",
          "read_offset": 79236,
          "size": 79236,
          "start_time": "2020-10-08T10:02:34.038Z"
        }
      },
      "open_files": 2,
      "running": 2,
      "skipped": 0,
      "started": 4
    },
    "input": {
      "log": {
        "files": {
          "renamed": 0,
          "truncated": 0
        }
      }
    }
  },
  "libbeat": {
    "config": {
      "module": {
        "running": 0,
        "starts": 0,
        "stops": 0
      },
      "reloads": 1,
      "scans": 144
    },
    "output": {
      "events": {
        "acked": 1863,
        "active": 2,
        "batches": 115,
        "dropped": 2,
        "duplicates": 0,
        "failed": 0,
        "toomany": 0,
        "total": 1867
      },
      "read": {
        "bytes": 0,
        "errors": 0
      },
      "type": "elasticsearch",
      "write": {
        "bytes": 0,
        "errors": 0
      }
    },
    "pipeline": {
      "clients": 1,
      "events": {
        "active": 0,
        "dropped": 0,
        "failed": 0,
        "filtered": 10,
        "published": 1865,
        "retry": 8,
        "total": 1875
      },
      "queue": {
        "acked": 1865
      }
    }
  },
  "registrar": {
    "states": {
      "cleanup": 0,
      "current": 4,
      "update": 1875
    },
    "writes": {
      "fail": 0,
      "success": 123,
      "total": 123
    }
  },
  "system": {
    "cpu": {
      "cores": 2
    },
    "load": {
      "1": 0.12,
      "15": 0.1,
      "5": 0.14,
      "norm": {
        "1": 0.06,
        "15": 0.05,
        "5": 0.07
      }
    }
  }
}

EugRomanchenko · 2020-10-08T11:36:04Z

I attach an image confirming that the logs successfully get into ES.

kvch · 2020-10-08T13:07:14Z

I think the tagging went wrong on the issue. Unfortunately, the fix was not released in v7.9.2. It is going to be published in v7.9.3. I can see it on our 7.9 branch, but it is after the 7.9.2 tag. I am sorry for your inconvenience.

EugRomanchenko · 2020-10-08T13:18:40Z

Thanks. We will wait for the release of 7.9.3.

…for ES (elastic#21211) * Add Known issues section with an issue about Functionbeat * Fix libbeat.output.*.bytes metrics of Elasticsearch output (elastic#21197) ## What does this PR do? This PR passes a missing parameter to the constructor `elasticsearch.Client`. ## Why is it important? The missing parameter prevented Beats from reporting the metrics `libbeat.output.write.bytes` and `libbeat.output.read.bytes` in case of Elasticsearch output. ## Related issues Closes elastic#20752 (cherry picked from commit ab955b8)

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

EugRomanchenko changed the title ~~Filebeat metric libbeat.output.write.bytes does not change for type elasticsearch~~ [Filebeat] [bug] [Team: Integrations] metric libbeat.output.write.bytes does not change for type elasticsearch Aug 24, 2020

andresrc removed the needs_team Indicates that the issue/PR needs a Team:* label label Aug 24, 2020

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

andresrc added Team:Services (Deprecated) Label for the former Integrations-Services team and removed needs_team Indicates that the issue/PR needs a Team:* label labels Aug 24, 2020

andresrc assigned kvch Aug 24, 2020

andresrc changed the title ~~[Filebeat] [bug] [Team: Integrations] metric libbeat.output.write.bytes does not change for type elasticsearch~~ Metric libbeat.output.write.bytes does not change for type elasticsearch Aug 24, 2020

ycombinator added the libbeat label Sep 17, 2020

kvch mentioned this issue Sep 21, 2020

Fix libbeat.output.*.bytes metrics for ES #21197

Merged

4 tasks

kvch closed this as completed in #21197 Sep 22, 2020

kvch mentioned this issue Sep 22, 2020

Cherry-pick #21197 to 7.x: Fix libbeat.output.*.bytes metrics for ES #21210

Merged

4 tasks

kvch mentioned this issue Sep 22, 2020

Cherry-pick #21197 to 7.9: Fix libbeat.output.*.bytes metrics for ES #21211

Merged

4 tasks

ycombinator mentioned this issue Sep 24, 2020

stack monitoring: libbeat bytes sent rate is always 0 #21322

Closed

graphaelli mentioned this issue Sep 25, 2020

stack monitoring: apm-server bytes sent rate is always 0 elastic/apm-server#4235

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Metric libbeat.output.write.bytes does not change for type elasticsearch #20752

Metric libbeat.output.write.bytes does not change for type elasticsearch #20752

EugRomanchenko commented Aug 24, 2020 •

edited by ycombinator

Loading

EugRomanchenko commented Aug 24, 2020 •

edited

Loading

elasticmachine commented Aug 24, 2020

EugRomanchenko commented Sep 7, 2020

bvader commented Sep 16, 2020 •

edited by kvch

Loading

ycombinator commented Sep 17, 2020 •

edited

Loading

andresrc commented Sep 17, 2020

EugRomanchenko commented Oct 6, 2020 •

edited

Loading

andresrc commented Oct 8, 2020

kvch commented Oct 8, 2020

EugRomanchenko commented Oct 8, 2020

kvch commented Oct 8, 2020

EugRomanchenko commented Oct 8, 2020

EugRomanchenko commented Oct 8, 2020

kvch commented Oct 8, 2020

EugRomanchenko commented Oct 8, 2020

Metric libbeat.output.write.bytes does not change for type elasticsearch #20752

Metric libbeat.output.write.bytes does not change for type elasticsearch #20752

Comments

EugRomanchenko commented Aug 24, 2020 • edited by ycombinator Loading

EugRomanchenko commented Aug 24, 2020 • edited Loading

elasticmachine commented Aug 24, 2020

EugRomanchenko commented Sep 7, 2020

bvader commented Sep 16, 2020 • edited by kvch Loading

ycombinator commented Sep 17, 2020 • edited Loading

andresrc commented Sep 17, 2020

EugRomanchenko commented Oct 6, 2020 • edited Loading

andresrc commented Oct 8, 2020

kvch commented Oct 8, 2020

EugRomanchenko commented Oct 8, 2020

kvch commented Oct 8, 2020

EugRomanchenko commented Oct 8, 2020

EugRomanchenko commented Oct 8, 2020

kvch commented Oct 8, 2020

EugRomanchenko commented Oct 8, 2020

EugRomanchenko commented Aug 24, 2020 •

edited by ycombinator

Loading

EugRomanchenko commented Aug 24, 2020 •

edited

Loading

bvader commented Sep 16, 2020 •

edited by kvch

Loading

ycombinator commented Sep 17, 2020 •

edited

Loading

EugRomanchenko commented Oct 6, 2020 •

edited

Loading