Wrong (future) date from logs, trying to drop with pipelines

[nnsense]

Hi
I’m having hard time figuring out this. Here’s an example of one of my messages:

[ERROR] 2018-04-07T10:16:01,201 MONIT_LOG_ERROR: Log file monit on host CERBERUS contains error (error value: 2018-07-20T13:08:05Z | ERROR | 'mongod' mem usage of 88.9% matches resource limit [mem usage>80.0%])

As you can see, we clearly have a bug on our app, creating wrong dates set in the future (2018-07-20T13:08:05Z when we’re in April).

I wanted to drop that messages while somebody’s taking care of the bug, because we’re flooded by these messages, so I’ve created an extractor with the following regex:
(?:error value\:\s(\d{4}-\d{2}-\d{2})), which is creating a new field (errorlog_timestamp) with, in this case, “2018-07-20”

Then, I’ve started messing around with a new pipeline, this is my last attempt:

rule "Dropping future messages"
when
    parse_date(to_string($message.errorlog_timestamp), "yyyy-MM-dd") > now()
then
    drop_message();
end

Searching on this forum I’ve find out that I need to move “Pipeline processor” after “Message filter chain” in "
Message Processors Configuration" for custom fields to work, but with no luck, what happen if I use this rule in a pipeline is that no messages are getting in at all.

I’ve tried searching the forum but I cannot find “How compare” but only “how create a field” with an extracted date.
From Pipelines documentation instead, I cannot find an example or a hint on how parse a date and evaluate if it’s in the future. I’ve also thought to delete the extractor (trying to reduce “point of failure” - and make it more clean) and work on $message.message directly, creating a var with the same regex I’ve used for the extractor but still, I really cannot figure out what would be the right syntax to compare the extracted date and now(). Is this even possible to do?

Thanks for you help!

[jochen]

I’m not sure whether comparing complex objects (such as DateTime) is possible in the pipeline rules.

You can try comparing a purely numeric value instead, e. g. the number of milliseconds since the UNIX epoch (also see BaseDateTime.html#getMillis()):

rule "drop"
when
  parse_date(to_string($message.errorlog_timestamp), "yyyy-MM-dd").millis > now().millis
then
  drop_message();
end

[nnsense]

Hi Jochen, thanks for your replay
something strange is happenening when I add the rule: no messages in “All messages” anymore. When I remove the rule leaving only the two other rules (which are basically dropping messages basing on substring), messages are flowing again in All stream.
Also, if I try the simulator, it get stuck when the rule is enabled.
The new field is correctly showing on my streams, so the extractor is working, and it displays the right date, I really don’t understand the reason of this behaviour. Please note that the same was happening with my rule, without millis, but I didn’t give importance because I’ve tried so many things that I thought was a temporary problem due to my tests.

Any hint on why this could happen?

[jochen]

You can use the debug() to find out what the specific values of the message fields and variables in that pipeline rule are when it’s being evaluated.

[nnsense]

I’ve now changed the rule into

when
    true
then
    debug($message.errorlog_timestamp);
    drop_message();
end

Server log is reporting:

2018-04-09T10:32:02.933Z INFO  [Function] PIPELINE DEBUG: Passed value is NULL.

Odd. Why the extracted field errorlog_timestamp is present and has a value on streams but then is NULL on pipelines? Is $message.errorlog_timestamp the right way to use a value from extractors ?

My current Message Processors Configuration is

#	Processor	Status
1	GeoIP Resolver	active
2	Message Filter Chain	active
3	Pipeline Processor	active
4	AWS Instance Name Lookup	active

Thanks!

[jochen]

How exactly are you creating the “errorlog_timestamp” message field?

[nnsense]

Given the following example message :

[ERROR] 2018-04-09T10:24:01,497 MONIT_LOG_ERROR: Log file monit on host CERBERUS contains error (error value: 2018-07-20T04:40:49Z | ERROR | 'mongod' mem usage of 85.3% matches resource limit [mem usage>80.0%])

I’ve used the following values:

Extractor type: Regular expression
Source field: message
Regular expression: (?:error value:\s(\d{4}-\d{2}-\d{2}))
Condition: Only attempt extraction if field matches regular expression
Field matches regular expression: (?:error value:\s(\d{4}-\d{2}-\d{2}))
Store as field: errlog_timestamp
Extraction strategy: Copy

Both “Regular expression” and “Field matches regular expression” tests are giving the right value (respectively “2018-07-20” and “Matches! Extractor would run against this example.”) and actually a value is shown into the new field on Steams tab

[nnsense]

Store as field: errlog_timestamp

Ok, I’ve spent already some minute beating me on my head because of that stupid error: I’ve called the field “errorlog_timestamp” in the extractor and “errlog_timestamp” on pipeline.

Once found that, the debug() function started showing the right value, but the pipeline was still not working.
Since we’re using parse_date here, I thought trying converting the extractor into a date, so I went on the extractors page, clicked on Add converter, Convert to date type with format string: yyyy-MM-dd.

Then (after some minute of trial and error) I’ve changed my rule into:

when
    parse_date(to_string($message.errlog_timestamp), "yyyy-MM-dd'T'HH:mm:ss.SSSZ").millis > now().millis
then
    drop_message();
end

Now, it seems working, I’m cautious but monitoring the feed the last 30 minutes no one of that “future” messages shown itself.

Thanks for your help Jochen! I’ll keep monitoring the feed but I’m pretty confident it worked…

(still crossing fingers…)

[nnsense]

Looks good, no messages so far. Debug function is very useful and allowed me to create a second rule for messages with a very old date using the same method you suggested (working with milliseconds).
As you can see, we’re having quite some issues with our log’s dates

If any future usr is looking for a rule dropping old messages based on a custom field, here it is (drops messages older than 3 days):

rule "Dropping very old error.log messages"

when
    parse_date(to_string($message.errlog_timestamp), "yyyy-MM-dd'T'HH:mm:ss.SSSZ").millis < (now() - days(3)).millis
then
    drop_message();
end