Problem with backlog message

Hello to every one,

I have a problem with the email alert in graylog 4.0.5 .
When I received any alert I insert in the body message an backlog to analyzed the alerting.
The problem is that user change in message backlog, how is possible?

Regards,
Domenico

@DomenicoLicciardi
Not sure what your question is.
Need some more information to help troubleshoot your issue.

https://community.graylog.org/t/community-guidelines/6649#before-ask

Hi,
i have created alert for office 365 stream and I would a backlog of 10 messages.
The alert is correct but when I check the backlog isn’t correct.
For example:
— [Event Definition] ---------------------------
Title: More Country for Login
Description:
Type: aggregation-v1
— [Event] --------------------------------------
Timestamp: 2021-03-24T09:43:03.009Z
Message: More Country for Login: x@mail.it - card(ClientIP_country_code)=2.0
Source: auditlog4
Key:
Priority: 2
Alert: true
Timestamp Processing: 2021-03-24T09:43:03.009Z
Timerange Start: 2021-03-24T08:43:03.009Z
Timerange End: 2021-03-24T09:43:03.008Z
Fields:
Geo: [::]
UserId: x@mail.it

In the backlog, i have UserId: y@mail.it

So the UserId in the alert is different in the backlog.

@DomenicoLicciardi
Hello,
If I understand you correct, you get notification/s but your backlog messages is not what you wanted? or your missing a backlog?

This is the default notification settings. I think your missing the bottom half of “Fields”.

--- [Event Definition] ---------------------------
Title:       ${event_definition_title}
Description: ${event_definition_description}
Type:        ${event_definition_type}
--- [Event] --------------------------------------
Timestamp:            ${event.timestamp}
Message:              ${event.message}
Source:               ${event.source}
Key:                  ${event.key}
Priority:             ${event.priority}
Alert:                ${event.alert}
Timestamp Processing: ${event.timestamp}
Timerange Start:      ${event.timerange_start}
Timerange End:        ${event.timerange_end}
Fields:
${foreach event.fields field}  ${field.key}: ${field.value}
${end}
${if backlog}
--- [Backlog] ------------------------------------
Last messages accounting for this alert:
${foreach backlog message}
${message}
${end}
${end}

Have you seen this here

For the number backlog message needed, you can set that in your “Event Definitions” ,this is shown below.

Hope that helps

Thanks for your answer.
notif
This is my notification settings.

I get the backlog messages bit is not what I wanted because is wrong and I don’t know why.

@DomenicoLicciardi

I think your missing this section of your notification email body.

Fields:
${foreach event.fields field} ${field.key}: ${field.value}
${end}
${if backlog}
— [Backlog] ------------------------------------
Last messages accounting for this alert:
${foreach backlog message}
${message}
${end}

Hi Gsmith,

i have this section in my notification email body.
I have the backlog message in email but they are wrong…
I aspect that user is same is backlog message and in top email, because I have a “group by Fields” UserId.

Hello,

I’m not sure what you mean by wrong, can you explain in greater detail about this?

From your post above this doesnt look right?

Is this the message field you want in your email?

Hi,
I know could be strange but wrong mean wrong.
I have the aggregation group by field UserID so I expect the same user stamp in email alert but in body Event i have the right user, in backlog message the user is different and this is wrong because I can’t check the correct information.

Hello,
I apologize for not understanding your problem fully.

So, to recap of my understanding about this issue is, and please correct me if I’m wrong.

Your Notification is sending the wrong UserID?

You configured your UserID for that Notification as shown below?

It should look something like this.

UserId: ${event.some_name}

Reference:
Email alert notification

Hope this helps.

hi,
The UserId x@mail.it is correct, the problem is in backlog i have y@mail.it and for me is wrong because I expect to have x@mail.it to verify the alert information

@DomenicoLicciardi

Hello,
Maybe I can explain this in further detail.

Here is an example below of what Im talking about.

UserId: ${message.some_data} <------ It should look something like this.

Here is example of what my Notification configuration below. Please take notice at the bottom of the configuration please.

--- [Event Definition] ---------------------------
Title:       ${event_definition_title}
Description: ${event_definition_description}
Type:        ${event_definition_type}
--- [Event] --------------------------------------
Timestamp:            ${event.timestamp}
Message:              ${event.message}
Source:               ${event.source}
Key:                  ${event.key}
Priority:             ${event.priority}
Alert:                ${event.alert}
Timestamp Processing: ${event.timestamp}
Timerange Start:      ${event.timerange_start}
Timerange End:        ${event.timerange_end}
Fields:
${foreach event.fields field}  ${field.key}: ${field.value}
${end}
${if backlog}
--- [Backlog] ------------------------------------
Last messages accounting for this alert:
${foreach backlog message}
Source device: ${message.source} 
Severity: ${message.fields.Severity}
Level: ${message.fields.level}
${end}
${end}

The output of my notification from the configuration above.
This is how I received that notification as shown below.

--- [Event Definition] ---------------------------
Title:       Windows: Active Directory Device was  Deleted
Description: Device  was removed for Domain
Type:        aggregation-v1
--- [Event] --------------------------------------
Timestamp:            2021-03-31T05:21:21.186Z
Message:              Windows: Active Directory Device was  Deleted: lab-VM6|some.domain - count()=1.0
Source:               graylog.some.domain
Key:                  
Priority:             2
Alert:                true
Timestamp Processing: 2021-03-31T05:21:21.186Z
Timerange Start:      2021-03-31T05:20:21.186Z
Timerange End:        2021-03-31T05:21:21.185Z
Fields:


--- [Backlog] ------------------------------------
Last messages accounting for this alert:

Source device: lab-VM6.some.domain 
Severity: INFO
Level: 6

If your getting a different name I would look at your stream that was created for your notifcation.
Might want to look at this link.

https://docs.graylog.org/en/4.0/pages/alerts.html#data-available-to-notifications

If this doesn’t help, at this point I’m not sure. All I can do is offer suggestions and speculate sorry I cant be more help.
Maybe someone else can jump in help.

Hi @gsmith, I work with @DomenicoLicciardi at this project… I’ll try to add some details.

This is the Event definition:

Search Query: Operation:UserLoggedIn OR Operation:MailboxLogin
Search within the last 1 hour 
Execute search every 10 minutes
Group by Field(s): UserId
Condition: card(ClientIP_country_code) > 1

We want to identify Users that log in from different country in a small timeframe (1 hour).
The Event is triggered correctly, and if we run again the query in the console we can find the expected details.

We would expect to have a backlog with only events that contributed to trigger the alert. Isn’t that true?

This is the kind of backlog we get:

--- [Backlog] ------------------------------------
Last messages accounting for this alert:

{index=o365_0, message=-, timestamp=2021-04-02T06:33:04.000Z, ..., UserId=user02@example.com, ...
{index=o365_0, message=-, timestamp=2021-04-02T06:34:17.000Z, ..., UserId=user03@example.com, ...
{index=o365_0, message=-, timestamp=2021-04-02T06:34:24.000Z, ..., UserId=user04@example.com, ...
{index=o365_0, message=-, timestamp=2021-04-02T06:34:52.000Z, ..., UserId=user05@example.com, ...
{index=o365_0, message=-, timestamp=2021-04-02T06:37:04.000Z, ..., UserId=user06@example.com, ...
{index=o365_0, message=-, timestamp=2021-04-02T06:37:38.000Z, ..., UserId=user06@example.com, ...
{index=o365_0, message=-, timestamp=2021-04-02T06:37:46.000Z, ..., UserId=user06@example.com, ...
{index=o365_0, message=-, timestamp=2021-04-02T06:37:58.000Z, ..., UserId=user07@example.com, ...
{index=o365_0, message=-, timestamp=2021-04-02T06:38:43.000Z, ..., UserId=user08@example.com, ...
{index=o365_0, message=-, timestamp=2021-04-02T06:39:25.000Z, ..., UserId=user09@example.com, ...

Do we find in backlog ALL the messages that match the “Search Querry” or only the messages that contributed to trigger the condition (which should be all with the same UserId) ?

Thanks for your help.

@fabulus

Hello,

See if I understand this correctly and maybe sum this up.

Your using the 365 Stream as @DomenicoLicciardi stated earlier in this post, you created Event Definition with a Search Query: Operation:UserLoggedIn OR Operation:MailboxLogin.

So, either one of these you wanted to search within in a lotted time frame… correct?

Looks like you are searching every 10 minutes from the past 1 hour.
So, let’s say if its 5PM you execute a search which will get all users from 4PM till 5PM, then wait 10 minutes execute a search again at 5:10PM this executes a search which will get all users from 4:10 PM to 5:10 PM, so you want it to overlap the search? Is this correct?
I normally execute a search every XX minutes/hour for the past XX minutes/hour. I have both XX with the same time frame.

Your also grouping by field using “UserID” so if a UserID is greater than 1 show each user logon attempts. This tells me if you have just 1 UserID in the stream it will not send notification but unless there are 2 you won’t get that message hence >1. Have you tried setting it to Greater than 0? This means if there are just 1 UserID within that time, send notification.

Yes, you will find all the messages from the “Search Query"
Here is an example of two messages for 24 hours as shown below.

If you configure your Aggregation with certain conditions then you will receive only those messages that you filtered out.

Here is an example.

  1. Your Event Definition filters what messages you want from the stream being used. I believe you said that was correct as shown below. Is this correct?
  1. Your notification is how you recieve those filtered messages (i.e. from Event Definition) you want.

So if number 1 is not the problem then I would look at number two.

Judging from all thats been stated, I think your Event Definition configuration might be whats creating your issue. This is just a guess and I’m not sure at this point because there is a lack of information.
Hope this helps

All correct.
We search every 10 min in the last 1 hour because we want to identify events in a moving window of 1 hour. We could check it every minute but that could be too “heavy” for the system. (Obviously we should tacitate the same alert for 1 hour to avoid alert duplication… but that’s not a problem).

We group on UserID because we are looking for every user that has logged in from different countries in one hour.

The condition of cardinality > 1 is NOT on the UserId but on the Country (ClientIP_country_code).

As I already said the event is triggered correctly. What is wrong is the content of the backlog: looks like in the backlog we find ALL the messages that matched the query, before the group by UserId, and before the cardinality condition.

The documentation states that in the backlog will be included only the messages that contributed to trigger the event. So, let’s say a user logged in from 2 different countries in the last hour, due to the “group by” the event is generated for that particular user. I expect to find in the backlog only messages associated to that user. That’s why I don’t think that finding all the messages is the expected behaviour.

Am I missing something?

Thanks again for your precious help.

Cheers,
Fabio.

@fabulus

Hello,

That statement is correct,

That also is correct.

Here is an example of mine for failed user logon.
I have Event Definition called “Windows User Failed Logon Attempt”
Here is my configuration.

Here is my notification configuration.

--- [Event Definition] ---------------------------
Title:       ${event_definition_title}
Description: ${event_definition_description}
Type:        ${event_definition_type}
--- [Event] --------------------------------------
Timestamp:            ${event.timestamp}
Message:              ${event.message}
Source:               ${event.source}
Priority:             ${event.priority}
Alert:                ${event.alert}
Timestamp Processing: ${event.timestamp}
Timerange Start:      ${event.timerange_start}
Timerange End:        ${event.timerange_end}
Stream URL:           ${event.stream_name}          
${if stream_url}Stream URL: ${stream_url}${end}

${if backlog}
--- [Backlog] ------------------------------------
Last messages accounting for this alert:
${foreach backlog message}
User:             ${message.fields.TargetUserName}
WorkStation Name:  ${message.fields.WorkstationName}
Event Time:       ${message.fields.EventReceivedTime}
Source:           ${message.source}
Logon Type:       ${message.LogonType}
---[backlog end]---------------------------------
${end}
${end}

This is the end result for the email received from Graylog . If there are 5 failed logon attempts they will be displayed at the bottom of my email. As you know this can be raised to what ever number you choose.

As I stated before.

Since your Event Definition configuration are not completely shown here, and from the Notification configuration as shown above doesnt look correct, or am I just seeing parts of your configurations? Its hard to tell where your issue is.

I dont know if you tried this. Instead of using “Condition: card(ClientIP_country_code) > 1”
try using count() instead of card. just a thought…

Knowing what you have tried and the full configuration would be greatly apperciated.

I don’t understand what others information I can give you.
Here’s a screenshot of the full event definition:

and this is our current notification definition:

— [Event Definition] ---------------------------
Title: ${event_definition_title}
Description: ${event_definition_description}
Type: ${event_definition_type}
— [Event] --------------------------------------
Timestamp: ${event.timestamp}
Message: ${event.message}
Source: ${event.source}
Key: ${event.key}
Priority: ${event.priority}
Alert: ${event.alert}
Timestamp Processing: ${event.timestamp}
Timerange Start: ${event.timerange_start}
Timerange End: ${event.timerange_end}
Fields:
${foreach event.fields field} ${field.key}: ${field.value}
${end}

${if backlog}

Client IP country code:
${foreach backlog message}
${message.fields.ClientIPAddress_country_code}
${end}

— [Backlog] ------------------------------------
Last messages accounting for this alert:
${foreach backlog message}
${message}
${end}
${end}

But I repeat that the event definition it’s correct becaouse it’s triggered exactly when needed.

TIA,
Fabio.

@fabulus
Hello,
Thank you for the screen shots. My apologies, I’ve overlooked some of your statements. Let me recap on the problem/issue you’re having.

Correct me if I’m wrong. What you see in "Event Definition Preview” compared to what you are receiving in the Email notification is different. Correct? The Email notification your receiving has ALL the messages that matched the query, before the group by UserId., Correct?

If the statement below is correct, then you should only receive 10 backlog messages.

I did a test from your configuration as shown below. This was to see if I received ALL the backlog messages that I filtered prior to Aggregation section . And I shortened the time frame also.

The following was received from my Email. I only received 10 backlog messages even thou there are a lot more in that stream that matches my filter.

--- [Event Definition] ---------------------------
Title:       Test Notification
Description: this is only a test
Type:        aggregation-v1
--- [Event] --------------------------------------
Timestamp:            2021-04-09T00:51:56.809Z
Message:              Test Notification: S-1-5-18 - card(Category)=5.0
Source:               graylog
Key:                  
Priority:             3
Alert:                true
Timestamp Processing: 2021-04-09T00:51:56.809Z
Timerange Start:      2021-04-09T00:21:56.809Z
Timerange End:        2021-04-09T00:51:56.808Z
Fields:



Category:
--- [Backlog] ------------------------------------
Last messages accounting for this alert:

UserID: S-1-5-19
EventType: WARNING
Level: 4
Time: 2021-04-08 17:22:01

UserID: S-1-5-19
EventType: WARNING
Level: 4
Time: 2021-04-08 17:22:01

UserID: S-1-5-18
EventType: ERROR
Level: 3
Time: 2021-04-08 17:22:02

UserID: S-1-5-18
EventType: WARNING
Level: 4
Time: 2021-04-08 17:22:02

UserID: S-1-5-18
EventType: WARNING
Level: 4
Time: 2021-04-08 17:22:02

UserID: S-1-5-18
EventType: WARNING
Level: 4
Time: 2021-04-08 17:22:12

UserID: S-1-5-18
EventType: WARNING
Level: 4
Time: 2021-04-08 17:22:12

UserID: S-1-5-18
EventType: ERROR
Level: 3
Time: 2021-04-08 17:22:12

UserID: S-1-5-18
EventType: WARNING
Level: 4
Time: 2021-04-08 17:22:22

UserID: S-1-5-18
EventType: WARNING
Level: 4
Time: 2021-04-08 17:22:22

And just to give you an Idea of how many message I get in 30 minutes by filtering out the following.

EventType:ERROR OR EventType:WARNING

I do not revieve all 954 messages in my email. Only 10 message are sent.
I belive in your case you would have received ALL 954 messages, am I correct on this?.

My Alert & Events section shows this.

If your getting more messages then you want try testing out the notification section or use different filters to see if you get the exspected results. Just a thought, maybe fine tune your Stream your using to narrowing down what you want. Have you tried to adjust the time frame you using for the query? Did you check your Date/Time on the host and client are correct. I have known some problems generating from a date/time difference. What different configurations did you do to try to get the exspected results?
What I dont understand is how you get ALL the messages from the filter when you set the notification to #10. Seams like I’m missing something.
Just another Idea on the Stream part
If this field is unique (ClientIP_country_code) maybe create a stream with rules as shown below.

Then maybe reconfigure your event Definition to something simpler. See if that works.

What I was looking for is something along the lines of, What the messages in the steam look like and how you configured the stream, because there can be configuration made on the stream. Making sure I understand how your configuration are configured because I wanted to test this out in my lab. I was looking at the title of this thread “Problems with backlog message’ I could not understand the full picture on what they looked like ( i.e. Backlog Messages). What the email looks like when it received the messages sent. This would show me the comparison from beginning to end results.
Sometimes just clips of configuration or messages do not help, kind of need to see all the configuration and messages what it looks like in your environment. So far, I understand your configuration in Event Definition and your Notification template looks standard. Your using a stream called office 365. When you showed me your backlog message is that what they should it look like? or if its different can you demonstrate what you want to see. That would give a little light on how I can tell you what you need or dont need to configure. I hope this makes senses. At this point I’m unsure how to replicate your problem.

I hope this helps.

Hi, and sorry for the late reply but I don’t receive update notifications :-/

First, I receive only 10 messages in the backlog. That’s Ok.

Looking to your test: you grouped by UserID.
As stated in the Event definition form, as example: “Assuming you created a Filter with all failed log-in attempts in your network, Graylog could alert you when there are more than 5 failed log-in attempts overall. Now, add username as Group by Field and Graylog will alert you for each username with more than 5 failed log-in attempts.”

I read that as:

  • graylog generates a different alert for each username with more than 5 failed logins.
  • username is “unique” for each alert generated

But, coming back to your test, in which UserID should be unique in each alert, you have 2 different UserIDs (S-1-5-19 and S-1-5-18) reported in the backlog.

And that looks exactly like the behaviour we are facing. At this point I don’t get if it’s an error or if I’m not understanding the logic behind.

Thanks,
Fabio.

I can add that if I look at “Filter Preview” in the event definition form, it reflects what actually I get in the backlog, so the result of the query.

What I put in the aggregation section (group by or conditions) doesn’t affect what appears in the “Filter Preview”. Changes in that section don’t even trigger the Filter Preview content refresh.

So, again, my question is: in the backlog shoud I expect to find the same messages of the Filter Preview, and so the result of the query before the aggregation filter or I should expect to find only the messages that triggered the event, and so the ones which match also the aggregation filter?

TIA,
Fabio.