Add tag "truncated" to "log.flags" if incoming line is longer than configured limit #7991

kvch · 2018-08-16T13:39:30Z

A new field is added to store the flags of an event named "log.flags".
If a message is truncated, "truncated" flag is added to the list.

Example event with "truncated" flag:

{
  "@timestamp": "2018-08-16T13:00:46.759Z",
  "@metadata": {
    "beat": "filebeat",
    "type": "doc",
    "version": "7.0.0-alpha1"
  },
  "host": {
    "name": "sleipnir"
  },
  "source": "/home/n/test.log",
  "offset": 33,
  "log": {
    "flags": [
       "truncated"
    ],
  },
  "message": "test line",
  "prospector": {
    "type": "log"
  },
  "input": {
    "type": "log"
  },
  "beat": {
    "hostname": "sleipnir",
    "version": "7.0.0-alpha1",
    "name": "sleipnir"
  }
}

Blocks #7997
Closes #7022

ruflin · 2018-08-17T08:09:40Z

I like the idea of having this flag. Could we put it under log.truncated? Alternative suggestions? Looking at the current event it looks like it would more fit on the root level but with the change to ECS we will have very few top level fields.

ruflin

Forgot to select "request changes" to make it does not get merged before we discussed the naming of the field.

kvch · 2018-08-17T10:57:26Z

I am fine with log.truncated. I renamed the occurrences and refactored the code accordingly.

ruflin · 2018-08-17T14:50:42Z

filebeat/_meta/fields.common.yml

@@ -108,6 +108,11 @@
      description: >
        Logging level.

+    - name: log.truncated


Default type is keyword. I assume this needs to be integer/long?

I like that it's not just a bool but a value that tells how much was deleted.

urso · 2018-08-17T16:26:11Z

filebeat/reader/multiline/multiline.go

@@ -48,6 +49,7 @@ type Reader struct {
 	separator    []byte
 	last         []byte
 	numLines     int
+	truncated    int


Oh, I didn't think about multiline being able to capture truncated bytes as well. Good catch 👍

urso

When truncating, the multiline reader and limit reader must add the number of truncated bytes to the current value (in case a former phase did truncate the contents before).

This makes me wonder if we really want to count the bytes, or rather just want to add a tag to the event.

urso · 2018-08-17T16:30:22Z

filebeat/reader/readfile/limit.go

+			"log": common.MapStr{
+				"truncated": diff,
+			},
+		})


What if the contents is already truncated (multiline is applied before limit reader)? We should add the counters, no?

kvch · 2018-08-21T10:00:09Z

The implementation of counting the truncated bytes is correct with the current fixed pipeline.
Multiline is the first reader which might truncate a line. Thus, it does not require checking if a line's been truncated. LimitReader is the last element of the pipeline and it's able to truncate a line. If a line has been truncated by the multiline reader, it means that LimitReader has nothing to do. If multiline is not part of the pipeline than LimitReader is the first one with the ability to truncate. Thus, it does not need to check whether a reader truncated the message before.

However, it is not future-proof. When the reader pipeline refactoring is done, and the pipeline is flexible, more checking is required. I would not add the overhead of getting a value from a common.MapStr on every event. It's not worth it. As a wild alternative Truncated could be added to reader.Message. But I don't see that happening either.

Thus, I changed the field value to true. Also, I renamed the field to event.truncated, because of the problem described in #7997 (comment)

urso · 2018-08-21T11:50:34Z

@kvch @ruflin Not sure about the naming: log.truncated, event.truncated, log.message.truncated? In the end I'd prefer to be ecs compatible. WDYT @ruflin

Now that we changed it to a boolean, why do use a field instead of defining and inserting a tag. Please note, this is a more general question: Do we prefer boolean fields or tags?

ruflin · 2018-08-21T12:34:09Z

Having the lenght of truncated bytes would have been a nice feature but agree that it can make implementation more complex, so having simple bool could be sufficient. For the naming I would also like to push for log.truncated as log.* should contain all meta data around log messages.

For the tags: Definitively an interesting idea and I think Logstash uses tags for some things. At the same time I quite like specific fields that "describe" what happened and tags are more for users to add their own "free flow" meta information.

ph · 2018-08-21T13:48:49Z

filebeat/reader/multiline/multiline.go

+			},
+		})
+	}
+


The mlr.truncate > 0 branch do in the worst case 4 allocations on every run.
I would define the common.MapStr in a package variable that I would reuse.

ph · 2018-08-21T13:49:20Z

filebeat/reader/readfile/limit.go

+				"truncated": true,
+			},
+		})
+


same comment as above for allocations.

ph · 2018-08-21T13:49:57Z

@kvch really minor comments, good catch on multiline!

kvch · 2018-08-21T13:51:06Z

I will name this field/tag log.truncated as it turns out that the problem in my other PR was caused by an outdated end-to-end test. But first let's decide if it's a field or tag.

houndci-bot · 2018-08-27T17:16:04Z

filebeat/reader/message.go

@@ -59,3 +59,15 @@ func (msg *Message) AddFields(fields common.MapStr) {
 	}
 	msg.Fields.Update(fields)
 }
+
+func (msg *Message) AddTagsWithKey(key string, tags []string) error {


exported method Message.AddTagsWithKey should have comment or be unexported
receiver name msg should be consistent with previous receiver name m for Message

houndci-bot · 2018-08-27T17:35:24Z

filebeat/reader/message.go

+
+// AddTagsWithKey adds tags to the message with an arbitrary key.
+// If the field does not exist, it is created.
+func (msg *Message) AddTagsWithKey(key string, tags []string) error {


receiver name msg should be consistent with previous receiver name m for Message

ph

Code LGTM, I have added a remark about variadic function I think this would be a better API considering the usage we will make.

@ruflin are you OK with log.status? I think this field could have the dissect_parse_failure

ph · 2018-08-28T17:50:50Z

filebeat/reader/message.go

+}
+
+// AddTagsWithKey adds tags to the message with an arbitrary key.
+// If the field does not exist, it is created.


Maybe make AddTagsWithKey takes a variadic arguments for tags?
Common use case its probably to add a single tag.

AddTagsWithKey(key string, tags ...[]string) error

We should name it in the code the same as it's in the event again. If we stay with status this should be AddStatusWithKey. Alternative as proposed above we could call it flags so it would be AddFlagsWithKey. Or if we stick with tags here it should probably be log.tags?

Would AddFlagWithKey(key string, flag string) error be enough here? It seems all the usage we have below is only adding 1 flag.

urso · 2018-08-28T20:12:13Z

I like log.status :)

Please add AddTagsWithKeys to the developer docs. Everything MapStr related is very much used/required by all beats (including community beats).

ruflin · 2018-08-29T07:41:38Z

filebeat/_meta/fields.common.yml

@@ -108,6 +108,10 @@
      description: >
        Logging level.

+    - name: log.status


What about calling it log.flags? I somehow expect a different content for status like unprocessed or processed. flags is inspired by your field description and I kind of like it because we flagged a certain event.

Alternative would be log.tags?

ruflin · 2018-08-29T07:43:18Z

filebeat/reader/message.go

+}
+
+// AddTagsWithKey adds tags to the message with an arbitrary key.
+// If the field does not exist, it is created.


We should name it in the code the same as it's in the event again. If we stay with status this should be AddStatusWithKey. Alternative as proposed above we could call it flags so it would be AddFlagsWithKey. Or if we stick with tags here it should probably be log.tags?

Would AddFlagWithKey(key string, flag string) error be enough here? It seems all the usage we have below is only adding 1 flag.

ruflin · 2018-08-29T07:49:50Z

filebeat/reader/multiline/multiline.go

 	if maxBytesReached && maxLinesReached {
 		if space < 0 || space > len(m.Content) {
+			truncated = space - len(m.Content)


What happens if space < 0 here?

Nice catch. I think it was a leftover. This value of truncated was never used, because it was only added if len(m.Content) was bigger than space. However, in this branch space equals len(m.Content), so the truncated value here was unnecessary.

ruflin · 2018-08-29T07:51:17Z

filebeat/reader/multiline/multiline_test.go

+	}
+
+	for _, message := range messages {
+		fmt.Println(message)


ruflin · 2018-08-29T07:53:12Z

filebeat/reader/multiline/multiline_test.go

+func TestMultilineAfterTruncated(t *testing.T) {
+	pattern := match.MustCompile(`^[ ]`) // next line is indented a space
+	maxLines := 2
+	testMultilineTruncated(t,


Could you also add a test where the truncated flag should be misssing?

ruflin · 2018-08-29T07:54:41Z

filebeat/reader/readfile/limit_test.go

+		}
+
+		found := false
+		switch flags := statusFlags.(type) {


Why can it be both types? Same question for the other test.

I added it to mimic the testing of the old AddTags. But as the input is never interface, I am removing it.

ruflin · 2018-08-29T07:55:17Z

filebeat/reader/readfile/limit_test.go

+	maxBytes int
+}{
+	{"long-long-line", 5},
+	{"long-long-line", 3},


Could you add a third param here truncated: bool and then add also a test that is not truncated and checks that the flag does not exist?

ruflin · 2018-08-29T07:56:12Z

libbeat/common/mapstr.go

+// AddTagsWithKey appends a tag to the key field of ms. If the field does not
+// exist then it will be created. If the field exists and is not a []string
+// then an error will be returned. It does not deduplicate the list.
+func AddTagsWithKey(ms MapStr, key string, tags []string) error {


Could you add a test for the AddTagsWithKey method?

ruflin · 2018-08-29T07:57:04Z

libbeat/common/mapstr.go

+// AddTagsWithKey appends a tag to the key field of ms. If the field does not
+// exist then it will be created. If the field exists and is not a []string
+// then an error will be returned. It does not deduplicate the list.
+func AddTagsWithKey(ms MapStr, key string, tags []string) error {


Note: I would keep the naming here as Tags even though I would rename everything in filebeat code above to Flags.

Agreed. Done.

ruflin · 2018-08-29T07:58:24Z

libbeat/common/mapstr.go

-	if !exists {
-		ms[TagsKey] = tags
+
+	k, subMap, oldTags, present, err := mapFind(key, ms, true)


I wodner if this has a perfomance impact on the old AddTags method.

No. Keys without dots can be processed in the first loop on a fast path in mapFind. If the key exists as is, it's simply returned at the beginning.

// Fast path, key is present as is. if v, exists := data[key]; exists { return key, data, v, true, nil }

If not, the only additional cost is one IndexRune which looks for a dot in the key. But currently old tags don't have dots in their keys. Thus, the function returns at the second possible point without doing anything "expensive" e.g. creating additional submaps.

idx := strings.IndexRune(key, '.') if idx < 0 { return key, data, nil, false, nil }

houndci-bot · 2018-08-30T08:27:43Z

filebeat/reader/message.go

+	m.Fields.Update(fields)
+}
+
+// AddTagsWithKey adds tags to the message with an arbitrary key.


comment on exported method Message.AddFlagsWithKey should be of the form "AddFlagsWithKey ..."

ruflin

LGTM. Please make sure to update the PR description.

@timestamp

…nfigured limit (elastic#7991) A new field is added to store the flags of an event named "log.flags". If a message is truncated, "truncated" flag is added to the list. Example event with "truncated" flag: { "@timestamp": "2018-08-16T13:00:46.759Z", "@metadata": { "beat": "filebeat", "type": "doc", "version": "7.0.0-alpha1" }, "host": { "name": "sleipnir" }, "source": "/home/n/test.log", "offset": 33, "log": { "flags": [ "truncated" ], }, "message": "test line", "prospector": { "type": "log" }, "input": { "type": "log" }, "beat": { "hostname": "sleipnir", "version": "7.0.0-alpha1", "name": "sleipnir" } } Closes elastic#7022 (cherry picked from commit 0884236)

@timestamp

…ing line is longer than configured limit (#8165) * Add tag "truncated" to "log.flags" if incoming line is longer than configured limit (#7991) A new field is added to store the flags of an event named "log.flags". If a message is truncated, "truncated" flag is added to the list. Example event with "truncated" flag: { "@timestamp": "2018-08-16T13:00:46.759Z", "@metadata": { "beat": "filebeat", "type": "doc", "version": "7.0.0-alpha1" }, "host": { "name": "sleipnir" }, "source": "/home/n/test.log", "offset": 33, "log": { "flags": [ "truncated" ], }, "message": "test line", "prospector": { "type": "log" }, "input": { "type": "log" }, "beat": { "hostname": "sleipnir", "version": "7.0.0-alpha1", "name": "sleipnir" } } Closes #7022 (cherry picked from commit 0884236) * fix changelog && rebase

kvch added review Filebeat Filebeat needs_backport PR is waiting to be backported to other branches. labels Aug 16, 2018

kvch requested review from ph and urso August 16, 2018 13:39

ruflin requested changes Aug 17, 2018

View reviewed changes

kvch changed the title ~~Add field "truncated" if incoming line is too long~~ Add field "log.truncated" if incoming line is too long Aug 17, 2018

ruflin reviewed Aug 17, 2018

View reviewed changes

urso reviewed Aug 17, 2018

View reviewed changes

urso suggested changes Aug 17, 2018

View reviewed changes

kvch changed the title ~~Add field "log.truncated" if incoming line is too long~~ Add field "event.truncated" if incoming line is too long Aug 21, 2018

ph suggested changes Aug 21, 2018

View reviewed changes

webmat mentioned this pull request Aug 21, 2018

For boolean values, should we recommend using tags or a boolean field? elastic/ecs#100

Closed

2 tasks

kvch added 6 commits August 27, 2018 19:09

provide arbitrary name for tags

5aaadff

add function to add tag to a message

e13ab92

add truncated flag in LimitReader

a81626a

add "truncated" flag to MultilineReader

af7c81d

add documentation for log.status

f8eb9c7

add changelog entry

b16cff8

kvch force-pushed the feature/filebeat/add-number-of-truncated-bytes-if-too-long branch from 702fa8c to b16cff8 Compare August 27, 2018 17:14

kvch changed the title ~~Add field "event.truncated" if incoming line is too long~~ Add tag "truncated" to "log.status" if incoming line is longer than configured limit Aug 27, 2018

houndci-bot reviewed Aug 27, 2018

View reviewed changes

feed the hound with comments

84584c5

houndci-bot reviewed Aug 27, 2018

View reviewed changes

kvch added 3 commits August 27, 2018 19:50

rename reciever

03ee796

fix variable

496ebe4

rm debug print

a01440c

kvch mentioned this pull request Aug 27, 2018

Add tag "multiline" to "log.flags" if event consists of multiple lines. #7997

Merged

kvch force-pushed the feature/filebeat/add-number-of-truncated-bytes-if-too-long branch from 4706510 to a01440c Compare August 28, 2018 15:08

ph approved these changes Aug 28, 2018

View reviewed changes

kvch added 2 commits August 28, 2018 20:42

make AddTagsWithKey variadic function

b9aa508

rename d to subMap

cd0561e

urso approved these changes Aug 28, 2018

View reviewed changes

ruflin requested changes Aug 29, 2018

View reviewed changes

address review notes

43b8c57

houndci-bot reviewed Aug 30, 2018

View reviewed changes

kvch added 2 commits August 30, 2018 10:30

feed the hound

da33c4d

add AddTagsWithKey to developer changelog

2870f20

kvch changed the title ~~Add tag "truncated" to "log.status" if incoming line is longer than configured limit~~ Add tag "truncated" to "log.flags" if incoming line is longer than configured limit Aug 30, 2018

follow up changelog

5d8cb05

ph approved these changes Aug 30, 2018

View reviewed changes

ruflin approved these changes Aug 30, 2018

View reviewed changes

kvch merged commit 0884236 into elastic:master Aug 30, 2018

kvch mentioned this pull request Aug 30, 2018

Cherry-pick #7991 to 6.x: Add tag "truncated" to "log.flags" if incoming line is longer than configured limit #8165

Merged

kvch added v6.5.0 and removed needs_backport PR is waiting to be backported to other branches. labels Aug 30, 2018

kvch mentioned this pull request Sep 3, 2018

Cherry-pick #7997 to 6.x: Add tag "multiline" to "log.flags" if event consists of multiple lines. #8207

Merged

ruflin mentioned this pull request Nov 28, 2018

Introduce event.flags elastic/ecs#191

Open

Add tag "truncated" to "log.flags" if incoming line is longer than configured limit #7991

Add tag "truncated" to "log.flags" if incoming line is longer than configured limit #7991

Conversation

kvch commented Aug 16, 2018 • edited Loading

ruflin commented Aug 17, 2018

ruflin left a comment

Choose a reason for hiding this comment

kvch commented Aug 17, 2018 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

urso left a comment • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

kvch commented Aug 21, 2018

urso commented Aug 21, 2018

ruflin commented Aug 21, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ph commented Aug 21, 2018

kvch commented Aug 21, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ph left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

urso commented Aug 28, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ruflin left a comment

Choose a reason for hiding this comment

kvch commented Aug 16, 2018 •

edited

Loading

kvch commented Aug 17, 2018 •

edited

Loading

urso left a comment •

edited

Loading