Fixes parsing of GC entries in elasticsearch server log #9603

ycombinator · 2018-12-18T00:29:18Z

Resolves #9513.

This PR:

removes the incorrectly-parsed gc_overhead field. Turns out what we were parsing was actually an insignificant sequential number, not GC overhead,
parses out a new gc.collection_duration field, e.g. 1.2s, which is the time spent performing GC, and
parses out a new gc.observation_duration field, e.g. 1.8s, which is the overall time over which GC collection was performed

It also splits up the long grok expression in the ingest pipeline into smaller patterns and references those patterns, hopefully for easier readability.

elasticmachine · 2018-12-18T00:29:56Z

Pinging @elastic/stack-monitoring

ruflin · 2018-12-18T09:11:04Z

@ycombinator Could you rebase on master. The failing CI should be fixed there.

ycombinator · 2018-12-18T13:01:29Z

@ruflin Rebased on master now.

ycombinator · 2018-12-18T13:06:50Z

@radoondas has suggested a few improvements so I'm taking this PR out of review for now. I will put it back into review after I've incorporated his improvements.

ycombinator · 2018-12-18T15:00:06Z

Thanks to @radoondas's work, the ingest pipeline in this PR now includes a script processor to parse the GC durations into meaningful numeric millisecond values. It also further breaks down the grok expressions to make them even more readable.

tsouza · 2018-12-18T15:09:34Z

@ycombinator you've described the metrics as Old GC. According to https://github.com/elastic/elasticsearch/blob/master/server/src/main/java/org/elasticsearch/monitor/jvm/JvmGcMonitorService.java#L458 it's not only Old GC. It's the overhead of all the GCs.

ycombinator · 2018-12-18T15:10:11Z

Thanks @tsouza. Fixing both those things...

[UPDATE] Leaving the sequence number as-is per our conversation off-PR.

ycombinator · 2018-12-18T15:46:16Z

I've incorporated the latest feedback into this PR. It is ready for review again. Thanks!

radoondas

This looks now good to go. It does not break BC and build fields for future use.
Base of the changes - breaking the pattern - will help to build new special requests from user base.

ruflin · 2018-12-20T08:24:53Z

filebeat/module/elasticsearch/server/ingest/pipeline.json

+        {
+            "script": {
+                "lang": "painless",
+                "source": "if (ctx.elasticsearch.server.gc != null && ctx.elasticsearch.server.gc.observation_duration != null) { if (ctx.elasticsearch.server.gc.observation_duration.unit == 's') { ctx.elasticsearch.server.gc.observation_duration.time_in_millis = ctx.elasticsearch.server.gc.observation_duration.time * 1000;}if (ctx.elasticsearch.server.gc.observation_duration.unit == 'ms') { ctx.elasticsearch.server.gc.observation_duration.time_in_millis = ctx.elasticsearch.server.gc.observation_duration.time; } if (ctx.elasticsearch.server.gc.observation_duration.unit == 'm') { ctx.elasticsearch.server.gc.observation_duration.time_in_millis = ctx.elasticsearch.server.gc.observation_duration.time * 60000; }} if (ctx.elasticsearch.server.gc != null && ctx.elasticsearch.server.gc.collection_duration != null) { if (ctx.elasticsearch.server.gc.collection_duration.unit == 's') { ctx.elasticsearch.server.gc.collection_duration.time_in_millis = ctx.elasticsearch.server.gc.collection_duration.time * 1000;} if (ctx.elasticsearch.server.gc.collection_duration.unit == 'ms') {ctx.elasticsearch.server.gc.collection_duration.time_in_millis = ctx.elasticsearch.server.gc.collection_duration.time; } if (ctx.elasticsearch.server.gc.collection_duration.unit == 'm') { ctx.elasticsearch.server.gc.collection_duration.time_in_millis = ctx.elasticsearch.server.gc.collection_duration.time * 60000; }}"


@jpountz Great use case for a duration type (mostly) ;-)

ruflin · 2018-12-20T08:26:16Z

@ycombinator I wonder if an improvement can be made later on on the ES side to always log in the same unit?

ycombinator · 2018-12-20T14:16:54Z

I wonder if an improvement can be made later on on the ES side to always log in the same unit?

@ruflin Added ~~elastic/elasticsearch#32850 (comment)~~ elastic/elasticsearch#36896.

I've also spoken with @jakelandis about the possibility of adding a duration Ingest processor, similar to the bytes one we have today for performing the necessary parsing and conversion from string durations to numeric durations.

filebeat/docs/fields.asciidoc

filebeat/module/elasticsearch/server/ingest/pipeline.json

ycombinator · 2018-12-20T20:14:38Z

@jsoriano Thanks for your review. I've addressed all your feedback now. Ready for your 👀 again!

Additionally I've also shortened the painless expression a bit by using the null-safe operator.

tsouza

Thanks everyone for fixing this!

LGTM

ycombinator · 2018-12-21T15:50:22Z

jenkins, test this

…ore readable Co-authored-by: Radovan Ondas <[email protected]>

I missed adding CHANGELOG entries in #9603 so this PR follows up with said entries. No need to backport as the CHANGELOG entries were added in the original backport PR: #9810.

…h server log (#9810) * Regenerating fields * Fixing up for 6.x * Adding CHANGELOG entries

ycombinator requested a review from a team as a code owner December 18, 2018 00:29

ycombinator mentioned this pull request Dec 18, 2018

[filebeat] Wrong "gc_overhead" parsed by Elasticsearch module #9513

Closed

ycombinator requested a review from tsouza December 18, 2018 00:29

ycombinator added module review labels Dec 18, 2018

ycombinator added Filebeat Filebeat Feature:Stack Monitoring labels Dec 18, 2018

ycombinator requested review from ruflin and radoondas December 18, 2018 00:31

ycombinator force-pushed the bugfix-fb-es-gc branch from c7ac077 to 274d3d0 Compare December 18, 2018 13:01

ycombinator removed the review label Dec 18, 2018

ycombinator force-pushed the bugfix-fb-es-gc branch from f7de3c7 to 6bb5e28 Compare December 18, 2018 14:58

ycombinator added the review label Dec 18, 2018

radoondas approved these changes Dec 18, 2018

View reviewed changes

ruflin reviewed Dec 20, 2018

View reviewed changes

ycombinator requested a review from monicasarbu December 20, 2018 14:17

ycombinator force-pushed the bugfix-fb-es-gc branch from 153e9e7 to 8e66bf4 Compare December 20, 2018 14:19

ycombinator requested review from jsoriano and removed request for monicasarbu December 20, 2018 14:26

jsoriano reviewed Dec 20, 2018

View reviewed changes

filebeat/docs/fields.asciidoc Outdated Show resolved Hide resolved

filebeat/docs/fields.asciidoc Outdated Show resolved Hide resolved

filebeat/module/elasticsearch/server/ingest/pipeline.json Outdated Show resolved Hide resolved

tsouza approved these changes Dec 20, 2018

View reviewed changes

jsoriano approved these changes Dec 20, 2018

View reviewed changes

ycombinator force-pushed the bugfix-fb-es-gc branch from 9876e36 to 8a26241 Compare December 21, 2018 00:48

ycombinator force-pushed the bugfix-fb-es-gc branch from 8a26241 to 18cd81f Compare December 22, 2018 13:38

ycombinator and others added 11 commits December 27, 2018 09:11

Removing incorrectly-parsed field + parsing out two new fields

57eda3e

Parsing numeric value of GC durations; making grok expressions even m…

7007e24

…ore readable Co-authored-by: Radovan Ondas <[email protected]>

GC_OLD -> GC_ALL

0bcf3b7

Renaming old GC fields to all GC fields

9032834

Renaming field per conventions

23d1c37

Removing intermediate fields

d809a0c

Ignore missing fields when removing GC fields

bd3f7ae

Fixing expected log

538fc7e

Parameterizing literals

dcee7ac

Using the null-safe operator to shorten conditional checks

8b976a6

Fixing syntax error in painless script

d92bd73

ycombinator force-pushed the bugfix-fb-es-gc branch from 18cd81f to d92bd73 Compare December 27, 2018 17:11

ycombinator merged commit 11a1917 into elastic:master Dec 27, 2018

ycombinator added needs_backport PR is waiting to be backported to other branches. v6.7.0 v7.0.0-alpha2 labels Dec 27, 2018

ycombinator mentioned this pull request Dec 27, 2018

Cherry-pick #9603 to 6.x: Fixes parsing of GC entries in elasticsearch server log #9810

Merged

ycombinator removed the needs_backport PR is waiting to be backported to other branches. label Dec 27, 2018

ycombinator mentioned this pull request Dec 28, 2018

Adding missed CHANGELOG entries #9829

Merged

ycombinator added a commit that referenced this pull request Jan 8, 2019

Cherry-pick #9603 to 6.x: Fixes parsing of GC entries in elasticsearc…

ec704cd

…h server log (#9810) * Regenerating fields * Fixing up for 6.x * Adding CHANGELOG entries

jbaiera mentioned this pull request Apr 3, 2019

Add a Duration Processor implementation elastic/elasticsearch#40753

Closed

ycombinator deleted the bugfix-fb-es-gc branch December 25, 2019 11:14

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fixes parsing of GC entries in elasticsearch server log #9603

Fixes parsing of GC entries in elasticsearch server log #9603

ycombinator commented Dec 18, 2018 •

edited

Loading

elasticmachine commented Dec 18, 2018

ruflin commented Dec 18, 2018

ycombinator commented Dec 18, 2018

ycombinator commented Dec 18, 2018

ycombinator commented Dec 18, 2018

tsouza commented Dec 18, 2018 •

edited

Loading

ycombinator commented Dec 18, 2018 •

edited

Loading

ycombinator commented Dec 18, 2018

radoondas left a comment

ruflin Dec 20, 2018 •

edited

Loading

jpountz Dec 31, 2018

ruflin commented Dec 20, 2018

ycombinator commented Dec 20, 2018 •

edited

Loading

ycombinator commented Dec 20, 2018

tsouza left a comment

ycombinator commented Dec 21, 2018

Fixes parsing of GC entries in elasticsearch server log #9603

Fixes parsing of GC entries in elasticsearch server log #9603

Conversation

ycombinator commented Dec 18, 2018 • edited Loading

elasticmachine commented Dec 18, 2018

ruflin commented Dec 18, 2018

ycombinator commented Dec 18, 2018

ycombinator commented Dec 18, 2018

ycombinator commented Dec 18, 2018

tsouza commented Dec 18, 2018 • edited Loading

ycombinator commented Dec 18, 2018 • edited Loading

ycombinator commented Dec 18, 2018

radoondas left a comment

Choose a reason for hiding this comment

ruflin Dec 20, 2018 • edited Loading

Choose a reason for hiding this comment

jpountz Dec 31, 2018

Choose a reason for hiding this comment

ruflin commented Dec 20, 2018

ycombinator commented Dec 20, 2018 • edited Loading

ycombinator commented Dec 20, 2018

tsouza left a comment

Choose a reason for hiding this comment

ycombinator commented Dec 21, 2018

ycombinator commented Dec 18, 2018 •

edited

Loading

tsouza commented Dec 18, 2018 •

edited

Loading

ycombinator commented Dec 18, 2018 •

edited

Loading

ruflin Dec 20, 2018 •

edited

Loading

ycombinator commented Dec 20, 2018 •

edited

Loading