Mistake on configuring watches


(marc) #1

Hi,

I don't know the best way to do this, so i try to explain it the best i can.
I want to set watches to search if there are errors in my logs. I.e. more than 50 error logs in hte last 5 minutes, and isolate it by host. This means if host1 sent more than 50 error logs in the last 5 minutes i want to receive an e-mail, the same for host2 host3..etc

I guess that i need one watcher per host, right? So i configured it like this:

curl -XPUT 'http://localhost:9200/_watcher/watch/log_error_watch' -d '{
"metadata" : {
"color" : "red"
},
"trigger" : {
"schedule" : {
"interval" : "1m"
}
},
"input" : {
"search" : {
"request" : {
"indices" : "logs",
"body" : {
"size" : 0,
"query": {
"filtered": {
"query" : { "match" : { "message" : "error" } },
"filter": {
"query": {
"term": {
"host": "host1"
},
"query": {
"range": {
"@timestamp": {
"gte": "now-5m",
"lte": "now"
}
}
}
}
}
}
}
}
}
}
},
"condition" : {
"compare" : { "ctx.payload.hits.total" : { "gt" : 50 }}
},
"actions" : {
"email_administrator" : {
"throttle_period": "5m",
"email" : {
"to" : "miemail",
"subject" : "TOMCAT {{ctx.payload.hits.total}} errors",
"body" : "bla bla bla",
"attach_data" : true,
"priority" : "high"
}
}
}
}'

I can create the watch but it does nothing...i don't know how to debug.
So to test it i create data in elasticsearch, ie:

curl -XPOST 'http://localhost:9200/logs/event' -d '{
"timestamp" : "2017-01-09T13:39:29.613Z",
"request" : "GET index.html",
"status_code" : 404,
"host" : "host1",
"message" : "Error: File not found"
}'

Does anyone knows why is not working?

Thank you


(Alexander Reelsen) #2

Hey,

you can always use the Execute Watch API to execute a watch and check what data the search returned (also you can just paste it here and we can debug that output further).

In your example I assume, that there are no results being returned, because the search uses a field called @timestamp where as your document indexed a field called timestamp.

--Alex


(marc) #3

Hi Alexander,

Thanks for your suggestion.
Here is the response of the watcher API.

{
"_id" : "log_error_watch_19-2017-01-09T14:04:30.772Z",
"watch_record" : {
"watch_id" : "log_error_watch",
"state" : "executed",
"trigger_event" : {
"type" : "manual",
"triggered_time" : "2017-01-09T14:04:30.772Z",
"manual" : {
"schedule" : {
"scheduled_time" : "2017-01-09T14:04:30.772Z"
}
}
},
"input" : {
"search" : {
"request" : {
"search_type" : "query_then_fetch",
"indices" : [ "logs" ],
"types" : [ ],
"body" : {
"size" : 0,
"query" : {
"filtered" : {
"query" : {
"match" : {
"message" : "error"
}
},
"filter" : {
"query" : {
"range" : {
"timestamp" : {
"gte" : "now-5m",
"lte" : "now"
}
}
}
}
}
}
}
}
}
},
"condition" : {
"always" : { }
},
"messages" : [ ],
"metadata" : {
"color" : "red"
},
"result" : {
"execution_time" : "2017-01-09T14:04:30.772Z",
"execution_duration" : 7,
"input" : {
"type" : "search",
"status" : "success",
"payload" : {
"hits" : {
"total" : 0,
"hits" : [ ],
"max_score" : 0.0
},
"_shards" : {
"total" : 5,
"failed" : 0,
"successful" : 5
},
"timed_out" : false,
"took" : 6
},
"search" : {
"request" : {
"search_type" : "query_then_fetch",
"indices" : [ "logs" ],
"types" : [ ],
"template" : {
"template" : {
"size" : 0,
"query" : {
"filtered" : {
"query" : {
"match" : {
"message" : "error"
}
},
"filter" : {
"query" : {
"range" : {
"timestamp" : {
"gte" : "now-5m",
"lte" : "now"
}
}
}
}
}
}
},
"params" : {
"ctx" : {
"id" : "log_error_watch_19-2017-01-09T14:04:30.772Z",
"vars" : { },
"trigger" : {
"triggered_time" : "2017-01-09T14:04:30.772Z",
"scheduled_time" : "2017-01-09T14:04:30.772Z"
},
"execution_time" : "2017-01-09T14:04:30.772Z",
"watch_id" : "log_error_watch",
"metadata" : {
"color" : "red"
}
}
}
}
}
}
},
"condition" : {
"type" : "always",
"status" : "success",
"met" : true
},
"actions" : [ ]
}
}
}

Means something for you?

BR


(Alexander Reelsen) #4

Hey,

this means, that the watch you pasted is not the watch that gets executed (did you not properly PUT it maybe). The condition is not the same (you dont seem to have one defined) and there are no actions.

In addition you can see that the search does not return any hits, see the payload field, which contains the JSON a regular search would return as well. Which means that you query might not be what you are trying to do. The first step now is to get your query right, that it returns valid documents. Then put this valid query into your watch and retest. And please make sure that what you paste is in sync, which simplifies debugging a lot.

Also, please use a copy and paste mechanism that preserves the indenting, the format you chose makes it crazy hard to read and debug. Thank you so much!

--Alex


(marc) #5

Hi Alexander,

Sorry for not keeping the indentation.
The watcher is the same, and i put email for the action. However as you say, there's no action which is weird.
I'm using Inline watch execution to debug watcher.

I used this watch, and notice that i put an action. However, in the response there's no answer.

curl -XPOST 'localhost:9200/_watcher/watch/_execute?pretty' -d '{
"watch" : {
  "trigger" : {
    "schedule" : {
      "interval" : "30s"
    }
  },
  "input" : {
    "search" : {
      "request" : {
        "indices" : "logs",
        "body" : {
          "query": {
            "filtered": {
              "query" : { 
                "match" : { "message" : "error" }
                }
              }
            }
          }
        }
      }
    }
  }
  },
  "condition" : {
    "compare" : { "ctx.payload.hits.total" : { "gt" : 5 }}
  },
  "actions" : {
    "email_administrator" : {
      "throttle_period": "5m",
      "email" : {
        "to" : "miemail",
        "subject" : "{{ctx.payload.hits.total}} errors",
        "body" : "bla bla bla",
        "attach_data" : true,
        "priority" : "high"
      }
    }
  }
}'

(marc) #6

The response is:

  "_id" : "_inlined__0-2017-01-09T15:46:31.267Z",
  "watch_record" : {
    "watch_id" : "_inlined_",
    "state" : "executed",
    "trigger_event" : {
      "type" : "manual",
      "triggered_time" : "2017-01-09T15:46:31.267Z",
      "manual" : {
        "schedule" : {
          "scheduled_time" : "2017-01-09T15:46:31.267Z"
        }
      }
    },
    "input" : {
      "search" : {
        "request" : {
          "search_type" : "query_then_fetch",
          "indices" : [ "logs" ],
          "types" : [ ],
          "body" : {
            "query" : {
              "filtered" : {
                "query" : {
                  "match" : {
                    "message" : "error"
                  }
                }
              }
            }
          }
        }
      }
    },
    "condition" : {
      "always" : { }
    },
    "messages" : [ ],
    "result" : {
      "execution_time" : "2017-01-09T15:46:31.267Z",
      "execution_duration" : 6,
      "input" : {
        "type" : "search",
        "status" : "success",
        "payload" : {
          "hits" : {
            "total" : 52,
            "hits" : [ {
              "_type" : "event",
              "_source" : {
                "message" : "Error",
                "status_code" : 404,
                "timestamp" : "2017-01-09T15:34:29.613Z",
                "host" : "host1",
                "request" : "GET index.html"
              },
              "_id" : "AVmDp6v46s0G7HLOofiT",
              "_index" : "logs",
              "_score" : 0.9393754
            }, {
              "_type" : "event",
              "_source" : {
                "message" : "Error",
                "status_code" : 404,
                "timestamp" : "2017-01-09T15:34:29.613Z",
                "host" : "host1",
                "request" : "GET index.html"
              },
              "_id" : "AVmDp7HY6s0G7HLOofiX",
              "_index" : "logs",
              "_score" : 0.9393754
            }, {
              "_type" : "event",
              "_source" : {
                "message" : "Error",
                "status_code" : 404,
                "timestamp" : "2017-01-09T15:34:29.613Z",
                "host" : "host1",
                "request" : "GET index.html"
              },
              "_id" : "AVmDp5SI6s0G7HLOofiP",
              "_index" : "logs",
              "_score" : 0.93100715
            }, {
              "_type" : "event",
              "_source" : {
                "message" : "Error",
                "status_code" : 404,
                "timestamp" : "2017-01-09T15:34:29.613Z",
                "host" : "host1",
                "request" : "GET index.html"
              },
              "_id" : "AVmDp68Y6s0G7HLOofiV",
              "_index" : "logs",
              "_score" : 0.93100715
            }, {
              "_type" : "event",
              "_source" : {
                "message" : "Error",
                "status_code" : 404,
                "timestamp" : "2017-01-09T15:34:29.613Z",
                "host" : "host",
                "request" : "GET index.html"
              },
              "_id" : "AVmDp7R46s0G7HLOofiZ",
              "_index" : "logs",
              "_score" : 0.9199573
            }, {
              "_type" : "event",
              "_source" : {
                "message" : "Error",
                "status_code" : 404,
                "timestamp" : "2017-01-09T15:34:29.613Z",
                "host" : "host1",
                "request" : "GET index.html"
              },
              "_id" : "AVmDp7XI6s0G7HLOofia",
              "_index" : "logs",
              "_score" : 0.9199573
            } ],
            "max_score" : 0.9393754
          },
          "_shards" : {
            "total" : 5,
            "failed" : 0,
            "successful" : 5
          },
          "timed_out" : false,
          "took" : 4
        },
        "search" : {
          "request" : {
            "search_type" : "query_then_fetch",
            "indices" : [ "logs" ],
            "types" : [ ],
            "template" : {
              "template" : {
                "query" : {
                  "filtered" : {
                    "query" : {
                      "match" : {
                        "message" : "error"
                      }
                    }
                  }
                }
              },
              "params" : {
                "ctx" : {
                  "id" : "_inlined__0-2017-01-09T15:46:31.267Z",
                  "vars" : { },
                  "trigger" : {
                    "triggered_time" : "2017-01-09T15:46:31.267Z",
                    "scheduled_time" : "2017-01-09T15:46:31.267Z"
                  },
                  "execution_time" : "2017-01-09T15:46:31.267Z",
                  "watch_id" : "_inlined_",
                  "metadata" : null
                }
              }
            }
          }
        }
      },
      "condition" : {
        "type" : "always",
        "status" : "success",
        "met" : true
      },
      "actions" : [ ]
    }
  }
}

In payloads there's hits, but there's no action. Is that normal?


(Alexander Reelsen) #7

Hey,

looks as if your JSON is invalid, because you have two closing brackets when closing the input - it seems that watcher does not throw an exception here but it should. However this also means, that you do not have any action or any condition configured for your watch, because of that.

Can you try to remove that one closing bracket and see what happens?

--Alex


(marc) #8

Hi Alexander,

That was! the closing "}". This was making all to have no sense.


(Alexander Reelsen) #9

Hey,

that was inconvenient from the watcher side, I'll open up an issue to get this fixed in watcher and throw a proper exception when this happens. Thanks so much for your help and patience!

--Alex


(marc) #10

OK Alex,

Anyway i'm no cappable of configuring the query i want. the main problem is in the range. I don't know how to mix it with other filters...
I created data in elasticsearch like this:

curl -XPOST 'http://localhost:9200/logs/event' -d '{
  "timestamp" : "2017-01-10T11:52:29.613Z",
  "request" : "GET index.html",
  "status_code" : 404,
  "host" : "testfinal",
  "message" : "Error"
  }'

if i check a watcher with the API it returns a hits:0 which is not possible, because i created several entries with the current date, and i executed the watch just after that.
What is wrong with my query? could you give me any clue?

curl -XPOST 'localhost:9200/_watcher/watch/_execute?pretty' -d '{
"watch" : {
  "trigger" : {
    "schedule" : {
      "interval" : "30s"
    }
  },
  "input" : {
    "search" : {
      "request" : {
        "indices" : "logs",
        "body" : {
          "query": {
              "filtered" : {
                "query" : {
                  "match" : { "message" : "error" }
                },
                "filter" : {
                  "query" : {
                    "term" : {
                      "host" : "testfinal"
                    }
                  },
                  "query" : {
                    "range" : {
                      "timestamp" : {
                        "gte": "now-5m",
                        "lte": "now"
                      }
                    }
                  }  
                }
              }
            }
          }
        }
      }
    },
  "condition" : {
    "compare" : { "ctx.payload.hits.total" : { "gt" : 5 }}
  },
  "actions" : {
    "email_administrator" : {
      "throttle_period": "5m",
      "email" : {
        "to" : "miemail",
        "subject" : "TOMCAT {{ctx.payload.hits.total}} errors",
        "body" : "body message",
        "attach_data" : true,
        "priority" : "high"
      }
    }
  }
  }
}'

(Alexander Reelsen) #11

Hey,

you can use a bool query that consists of a must part that contains the match query and a filter array, that contains the range and the term query.

Hope this helps.

--Alex


(marc) #12

Alex,

Ok i'll give it a try. What is rare is that if i delete "now-5m" and i use a date like 2017-01-10T11:52:29.613Z then it works. But when i write

"timestamp" : {
                        "gte": "now-5m"
                      }

Then it don't filter the last 5 minutes.
if i use

              "timestamp" : {
                "gte": "now-5m",
                "lte": "now"
              }

it finds no hits. I don't understand why...


(marc) #13

Hi there,

no, finally i can't.
I think what i'm trying is a common use of watcher. I want to search entries that has "error" in the message field, also that has a specific word in the host field (or the fields i require) and finally that the entrie's timestamp is in the last 5 minutes.

I can't configure watcher like that because i don't know how to do several queries mixed with range, etc...

Does anyone has an example that will help me?

Thanks


(marc) #14

Hi Alex,

It was all a syntax error....
Now i have an issue with the timezone. I create data with this command:

curl -XPOST 'http://localhost:9200/logs/event' -d '{
  "timestamp" : "2017-01-10T16:50:30.613Z",
  "request" : "GET index.html",
  "status_code" : 404,
  "host" : "host1",
  "message" : "Error"
  }'

Imagine that ow is 16:50 if I use the range now-15m it won't find it. If i use a timestamp 1 hour before (15:50) it finds the register.
So its a timezone issue, but i don't know where...my system's tz is ok UTC+1

I tried this with no success:

              "timestamp" : {
                "gte" : "now-30m",
                "lte" : "now",
                "time_zone" : "+01:00"
              }

Any idea?

Thanks


(Alexander Reelsen) #15

Hey,

your system clock is irrelevant here, because you specified the timestamp date to be UTC when you indexed the document using the Z identifier.

--Alex


(marc) #16

Ok Alex,

However, i can't filter by range, because it take time as UTC not UTC +1
I think that "now" word is not taking my current time, it takes 1 hour ago.

Do you know how may i fix that?

Thanks


(Alexander Reelsen) #17

See the range query documentation


(marc) #18

Hi Alex,

As i wrote above, i used:

"timestamp" : {
                "gte" : "now-30m",
                "lte" : "now",
                "time_zone" : "+01:00"
              }

with no success. That's why i'm asking for help.

Thanks


(Alexander Reelsen) #19

Hey,

can you recreate an example (including document creation and the exact query) that shows your problem?

--Alex


(system) #20

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