How to run down source of mutate error?

[mistrhanky]

I have an error like the one below. In fact I get a fair number of them, lets say a few hundred each day on a production system(7.12) that logs fairly heavy, 800 million or so records a day. So the amount of these errors is not considered a big problem to me, but I would like to clean up any errors and ensure I get everything I am looking for. My problem is that I probably take in 15 different sources or so, including windows and linux via ossec, and I cannot run down what log record exactly causes this issue. Loading all the logs I can think of on a dev system that mirrors the prod setup does not through this error. Is there any way to get better detail from this type of log error that would give away what the source line was, etc? Grepping for 'bobmacbook.local' produces very few results in any log I can find and none of those lines ever seem to trigger this exception in my code. I could understand if I had this problem on every log record, but I only get it sporadically so I think it must be related to data in one specific log format that shows up on occaision.

[2021-09-29T07:11:14,277][WARN ][logstash.filters.mutate ] Exception caught while applying mutate filter {:exception=>"Could not set field 'name' on object '' to value 'bobmacbook.local'.This is probably due to trying to set a field like [foo][bar] = someValuewhen [foo] is not either a map or a string"}

[aaron-nimocks]

I would set a mutate ID and it should show in log. I am not quite sure why yours does not have a pipeline ID though.

[TIME][WARN ][logstash.filters.mutate ][main][mutate-id] Exception caught..
[main] = Pipeline ID
[mutate-id] = Mutate ID

[Badger]

To understand what is happening consider

input { generator { count => 1 lines => [ '' ] } }
filter {
    mutate { add_field => { "foo1" => "" } }
    mutate { add_field => { "[foo1][bar]" => "1" } }
    mutate { add_field => { "foo" => "a" } }
    mutate { add_field => { "[foo][bar]" => "2" } }
}
output { stdout { codec => rubydebug { metadata => false } } }

That generates

[2021-09-29T14:20:46,878][WARN ][logstash.filters.mutate ][main][7b4b29026fb3b4e2ca120f9681a9c336324b1e7c46bccdc1e02cc51bfc76e3ec] Exception caught while applying mutate filter {:exception=>"Could not set field 'bar' on object '' to value '1'.This is probably due to trying to set a field like [foo][bar] = someValuewhen [foo] is not either a map or a string"}
[2021-09-29T14:20:46,886][WARN ][logstash.filters.mutate ][main][336b225f2b3d8066dd7abea8a0cd836e5705eb0605607d3262538797068ed604] Exception caught while applying mutate filter {:exception=>"Could not set field 'bar' on object 'a' to value '2'.This is probably due to trying to set a field like [foo][bar] = someValuewhen [foo] is not either a map or a string"}

So you have a field that contains an empty string and you are trying to create another field nested within. Once a field is a string you cannot use this technique to make it an object with nested fields.

The error message is badly worded ("is not either a map or a string"), missing a space in "someValuewhen", and would be a lot more useful if it logged the name of the field rather than the value. Unfortunately by the time the code is down in setChild it no longer has the name.

[mistrhanky]

It is indeed interesting as to why the mutate-id is not shown. I am not as concerned with pipeline id, although, probably related.

[mistrhanky]

For clarity, it turns out a co-worker had changed my log4j pattern which is why I did not get mutate or pipeline id's.

[aaron-nimocks]

That would do it. Was going to share the default so you can set it back if you wanted.

appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c]%notEmpty{[%X{pipeline.id}]}%notEmpty{[%X{plugin.id}]} %m%n