Why is this (specific) mutate not working?

Hi Folks,
it has been some time since i asked my last question here and i learned a lot in the meantime, but i still feel like a bloody beginner from time to time.
Here comes my Situation:
I am filtering several logs from different sources and i am trying to deploy some kind of alerting for some of the events via mail.

The Pipeline is loading, Events are passing, i even testet the mail-component (and sent around 15k mails to me by accident XD), so those parts are defenitely working as designed. The other filters (look below if unpatient) are working fine aswell. The only thing that does not seem to be working is the part of:

  if (([fields.loglevel] == "error") and ([fields.env] == "ekp")) {
    mutate {
      add_field => { "shouldimailit" => "You should have Mailed me - finally!" }
      add_tag => ["shouldmail"]
    }
  }

For example one of the events after passing logstash (note that there is no tag):

@timestamp|2020-02-12 @ 15:39:08.074|
@version|1|
_id|40jWOXABPVew1GGU5QBC|
_index|filebeat-7.4.2-2020.02.12|
_score| - |
_type|_doc|
agent.ephemeral_id|de1e2668-6d03-45b4-bd5f-f440691c2562|
agent.hostname|dehze01-lsv841.sec.rhs.zz|
agent.id|aa2e58b6-128b-4d55-85b1-b86f8aafdc69|
agent.type|filebeat|
agent.version|7.4.2|
ecs.version|1.1.0|
fields.env|ekp|
fields.loggername|[org.keycloak.adapters.RefreshableKeycloakSecurityContext]|
fields.loglevel|error|
fields.message|Refresh token failure status: 400 {"error":"invalid_grant","error_description":"Refresh token expired"}|
fields.stage|prod|
fields.thread|default task-77|
host.name|dehze01-lsv841.sec.rhs.zz|
input.type|log|
log.file.path|/software/bnp/wildfly_ekp/standalone/log/server.log|
log.offset|420 289 111|
message|2020-02-12 15:39:08,074 ERROR [org.keycloak.adapters.RefreshableKeycloakSecurityContext] (default task-77) Refresh token failure status: 400 {"error":"invalid_grant","error_description":"Refresh token expired"}|
tags|beats_input_codec_plain_applied|

Whole filter:

filter { 
  
  grok {
    match => { 
      "message" => "\A%{TIMESTAMP_ISO8601:fields.timestamp}%{SPACE}%{LOGLEVEL:fields.loglevel}%{SPACE}%{NOTSPACE:fields.loggername}%{SPACE}\(%{DATA:fields.thread}\)%{SPACE}%{GREEDYDATA:fields.message}"
    }
    match => {       
      "message" => "\A%{TIMESTAMP_ISO8601:fields.timestamp}%{SPACE}%{LOGLEVEL:fields.loglevel}%{SPACE}%{NOTSPACE:fields.loggername}%{SPACE}%{GREEDYDATA:fields.message}"
    }
    #match => { "message" => "%{COMBINEDAPACHELOG}" }
  }
  date {
    match => ["fields.timestamp", "ISO8601"]
    target => "@timestamp"
  }
  mutate {
    remove_field => ["fields.timestamp"]
  }  

# hier wird klein geschrieben!
  mutate {
    lowercase => [ "fields.env" ]
    lowercase => [ "fields.loglevel" ]
    lowercase => [ "fields.stage" ]
  }

# Filter für Keycloak von ca 01.12.2019
  if (([fields.loglevel] == "error") and ([fields.message] =~ "^Error from SAP:(.*)")) {
    mutate {
      replace => { "fields.loglevel" => "warn" }
      add_tag => ["reshaped"]
    }
  }

# Filter für EKP lt. Domme vom 14.01.2020
  if (([fields.loglevel] == "error") and ([fields.env] == "ekp") and ([fields.message] =~ "^UT005022: Exception generating error page \/pages\/error\.jsf: javax\.servlet\.ServletException: Index: 0, Size: 0(.*)")) {
    mutate {
      replace => { "fields.loglevel" => "warn" }
      add_tag => ["reshaped"]
    }
  }

# Filter für EKP lt. Domme vom 16.01.2020  
  if (([fields.loglevel] == "error") and ([fields.env] == "ekp") and ([fields.message] =~ "^UT000010: Session is invalid(.*)")) {
    mutate {
      replace => { "fields.loglevel" => "warn" }
      add_tag => ["reshaped"]
    }
  }

# Alle (restlichen) EKP-Error auf shouldmail setzen 
  if (([fields.loglevel] == "error") and ([fields.env] == "ekp")) {
    mutate {
      add_field => { "shouldtagit" => "You should have tagged me!" }
      add_tag => ["shouldmail"]
    }
  }
}

The big question: What am I missing? Why am I not getting Emails for this event?

Hi there,

are all those if conditions working properly? Do your fields actually have dots in their names without being nested objects?

I would expect them to be like if (([fields][loglevel] == "error") and ([fields][env] == "ekp")) unless they aren't nested fields but root fields with dots in their name (something terrible IMHO).

yes, the other conditions are working, but i always had the feeling, that some conditions were a bit unreliable (which i though could not be because "it either works or it does not").
i think i will try the approach to rename those objects. we were not aware that this might become a problem when we decided the names :-/
any more ideas?

Wait a minute, i think i miunderstood you.
This is how i made those fields in the corresponding filebeat.yml:

fields:
env: ekp

does this not create nested objects?

It does create nested object which you do not access to using the dot notation in logstash.

If in logstash you try accessing "foo.bar" field, it'll look for the root level field named "foo.bar", not for the value of the "bar" field nested in the "foo" one.

That's why I asked.

Try replacing your "this.name" convention with "[this][name]" and see how it goes.

Hi there again,

i did some (much) more testing and came to the conclusion, that the faulting part is not the [fields][env] - part, but that only (and really only) [fields.env]=="ekp" is not working at all. even if i exclude the other parameters of the if, it does not become "true".
it is not the mutate. that one is not working (tested that aswell (with ([fields.loglevel]=="error") - which worked as intended).

i also made sure, that there is no space in fields.env . the field is set in the filebeat-setting:

filebeat.inputs:
- type: log
  enabled: true
  paths:
    - /somewhere/server.log
    - /somewhereelse/server.log
  fields:
    env: ekp
    stage: prod

i am out of ideas now. this should be working, right?

p.s.: when i changed the notation to [fields][env] even the other filters were not working anymore.

Can you please post here the output of a pipeline without any added filter? It'd be useful to see what Logstash is seeing in input.

Just paste here the output of

input {
  ...whatever the input you are using...
}

filter {}

output {
  stdout{}
}

Thanks for all the help Fabio. Here is what i got first, when i disabled all the filters:

without filter: 

 "offset" => 165445593
 },
 "input" => {
 "type" => "log"
 },
 "@timestamp" => 2020-02-18T09:29:24.250Z,
 "agent" => {
 "hostname" => "dehze01-lsv841.sec.rhs.zz",
 "id" => "aa2e58b6-128b-4d55-85b1-b86f8aafdc69",
 "ephemeral_id" => "7983974d-89a0-4c27-8e7c-fe4b63984049",
 "type" => "filebeat",
 "version" => "7.6.0"
 },
 "message" => "2020-02-18 10:29:23,953 INFO  [de.rhenus.projects.bp2009.webservice.CxmlWebservice] (default task-78) CxmlWebservice getting response: <cXML payloadID=\"350604@PCH\" xml:lang=\"en\" timestamp=\"2020-02-18T10:29:23+01:00\">\n  <Response>\n    <Status code=\"200\" text=\"OK\"/>\n  </Response>\n</cXML>",
 "fields" => {
 "env" => "ekp",
 "stage" => "prod"
 },
 "host" => {
 "name" => "foo-hostname"
 },
 "tags" => [
 [0] "beats_input_codec_plain_applied"
 ]
 }
 {
 "@version" => "1",
 "ecs" => {
 "version" => "1.4.0"
 },
 "host" => {
 "name" => "foo-name"
 },
 "log" => {
 "file" => {
 "path" => "/somewhere/server.log"
 }

after that i reenabled the filters and got this:

 {
 "host" => {
 "name" => "foo-name"
 },
 "fields.message" => "Show Replace PunchoutArtikel : 0 - showPunchOutReplacements: TRUE",
 "ecs" => {
 "version" => "1.4.0"
 },
 "fields" => {
 "env" => "ekp",
 "stage" => "prod"
 },
 "message" => "2020-02-18 10:20:18,408 INFO  [de.rhenus.projects.bp2009.bean.abstr.AbstractBean] (default task-4) Show Replace PunchoutArtikel : 0 - showPunchOutReplacements: TRUE",
 "log" => {
 "offset" => 164745523,
 "file" => {
 "path" => "/somewhere/server.log"
 }
 },
 "tags" => [
 [0] "beats_input_codec_plain_applied"
 ],
 "fields.loglevel" => "info",
 "fields.thread" => "default task-4",
 "agent" => {
 "version" => "7.6.0",
 "id" => "aa2e58b6-128b-4d55-85b1-b86f8aafdc69",
 "hostname" => "dehze01-lsv841.sec.rhs.zz",
 "ephemeral_id" => "7983974d-89a0-4c27-8e7c-fe4b63984049",
 "type" => "filebeat"
 },
 "fields.loggername" => "[de.rhenus.projects.bp2009.bean.abstr.AbstractBean]",
 "@version" => "1",
 "@timestamp" => 2020-02-18T09:20:18.408Z,
 "input" => {
 "type" => "log"
 }
 }

if i am not blind, this looks fine, right?

anyone?
i even checked, if "fields.env" is a string. (it is)
checked, if something changes when i try to compare via =~ (it does not)

[fields] is an object that contains an [env] field. In logstash the way to refer to that is [fields][env], not [fields.env]. [fields.env] would refer to a field with a period embedded in its name.

i will add a long analysis of what happened later (hoping someone else might learn a bit from my mistakes later when that person is reading this).
badgers last post and a nights sleep managed to finally make me understand what i did do wrong.

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