apass
March 9, 2022, 2:02pm
1
Hi all,
I’m trying to create a custom parser+scenario for banning an IP address after 5 login wrong login attempts in 5 minutes.
The parser read the file /var/log/user.log.
This is the parser:
onsuccess: next_stage
filter: "evt.Parsed.program == 'php'"
name: whoami/custom_fd
description: "Parse user.log for failed authentications"
#for clarity, we create our pattern syntax beforehand
pattern_syntax:
FD_UNAUTH: Authentication failed for user "%{HTTPDUSER}" \[from %{IP:source_ip}\]
nodes:
#and we use them to parse our type of logs
- grok:
name: "FD_UNAUTH"
apply_on: message
statics:
- meta: log_type
value: fd_failed_auth
statics:
- meta: service
value: fd
- meta: username
expression: evt.Parsed.user
- meta: source_ip
expression: "evt.Parsed.source_ip"
And this is the scenario:
type: leaky
format: 2.0
#debug: true
name: whoami/custom_fd
description: "Detect failed authentications"
filter: "evt.Meta.log_type == 'fd_failed_auth'"
leakspeed: 5m
capacity: 5
groupby: "evt.Meta.source_ip"
blackhole: 1m
reprocess: true
labels:
service: fd
type: auth_failed
remediation: true
The problem is that the IP is banned just after the first attempt.
This is the log:
time="09-03-2022 14:17:17" level=info msg="Ip 111.222.333.444 performed 'whoami/custom_fd' (6 events over 1.043457ms) at 2022-03-09 13:17:17.94126056 +0000 UTC"
time="09-03-2022 14:17:18" level=info msg="(machine/crowdsec) whoami/custom_fd by ip 111.222.333.444 (IT/1267) : 12h ban on Ip 111.222.333.444"
What’s wrong?
Thanks in advance.
Hello @apass ,
From crowdsec logs, the scenario got triggered after 6 log lines (cf. (6 events over 1.043457ms)
).
For more details, can you get the ID of the alert with cscli alerts list
and then paste the output of cscli alerts inspect <ALERT_ID> -d
please ?
apass
March 10, 2022, 2:28pm
3
Hi @alteredCoder ,
many thanks for the help.
This is the output:
sudo cscli alerts inspect 365 -d
################################################################################################
- ID : 365
- Date : 2022-03-10T14:08:21Z
- Machine : machine
- Simulation : true
- Reason : whoami/custom_fd
- Events Count : 6
- Scope:Value: Ip:111.222.333.444
- Country : IT
- AS : XXXXXXXX
- Begin : 2022-03-10 14:08:20.720038746 +0000 UTC
- End : 2022-03-10 14:08:20.732885009 +0000 UTC
- Active Decisions :
+--------+-------------------+--------+---------------------+----------------------+
| ID | SCOPE:VALUE | ACTION | EXPIRATION | CREATED AT |
+--------+-------------------+--------+---------------------+----------------------+
| 456296 | Ip:111.222.333.444 | ban | 11h58m42.659413911s | 2022-03-10T14:08:21Z |
+--------+-------------------+--------+---------------------+----------------------+
- Events :
- Date: 2022-03-10 15:08:20 +0000 UTC
+-----------------+-----------------------------+
| KEY | VALUE |
+-----------------+-----------------------------+
| ASNNumber | 1267 |
| ASNOrg | XXXXXXXX |
| IsInEU | true |
| IsoCode | IT |
| SourceRange | 111.222.0.0/15 |
| datasource_path | /var/log/messages |
| datasource_type | file |
| log_type | fd_failed_auth |
| machine | machine |
| service | fd |
| source_ip | 111.222.333.444 |
| timestamp | 2022-03-10T15:08:20Z |
+-----------------+-----------------------------+
- Date: 2022-03-10 15:08:20 +0000 UTC
+-----------------+-----------------------------+
| KEY | VALUE |
+-----------------+-----------------------------+
| ASNNumber | 1267 |
| ASNOrg | XXXXXXXX |
| IsInEU | true |
| IsoCode | IT |
| SourceRange | 111.222.0.0/15 |
| datasource_path | /var/log/user.log |
| datasource_type | file |
| log_type | fd_failed_auth |
| machine | machine |
| service | fd |
| source_ip | 111.222.333.444 |
| timestamp | 2022-03-10T15:08:20Z |
+-----------------+-----------------------------+
- Date: 2022-03-10 15:08:20 +0000 UTC
+-----------------+-----------------------------+
| KEY | VALUE |
+-----------------+-----------------------------+
| ASNNumber | 1267 |
| ASNOrg | XXXXXXXX |
| IsInEU | true |
| IsoCode | IT |
| SourceRange | 111.222.0.0/15 |
| datasource_path | /var/log/messages |
| datasource_type | file |
| log_type | fd_failed_auth |
| machine | machine |
| service | fd |
| source_ip | 111.222.333.444 |
| timestamp | 2022-03-10T15:08:20Z |
+-----------------+-----------------------------+
- Date: 2022-03-10 15:08:20 +0000 UTC
+-----------------+-----------------------------+
| KEY | VALUE |
+-----------------+-----------------------------+
| ASNNumber | 1267 |
| ASNOrg | XXXXXXXX |
| IsInEU | true |
| IsoCode | IT |
| SourceRange | 111.222.0.0/15 |
| datasource_path | /var/log/syslog |
| datasource_type | file |
| log_type | fd_failed_auth |
| machine | machine |
| service | fd |
| source_ip | 111.222.333.444 |
| timestamp | 2022-03-10T15:08:20Z |
+-----------------+-----------------------------+
- Date: 2022-03-10 15:08:20 +0000 UTC
+-----------------+-----------------------------+
| KEY | VALUE |
+-----------------+-----------------------------+
| ASNNumber | 1267 |
| ASNOrg | XXXXXXXX |
| IsInEU | true |
| IsoCode | IT |
| SourceRange | 111.222.0.0/15 |
| datasource_path | /var/log/messages |
| datasource_type | file |
| log_type | fd_failed_auth |
| machine | machine |
| service | fd |
| source_ip | 111.222.333.444 |
| timestamp | 2022-03-10T15:08:20Z |
+-----------------+-----------------------------+
- Date: 2022-03-10 15:08:20 +0000 UTC
+-----------------+-----------------------------+
| KEY | VALUE |
+-----------------+-----------------------------+
| ASNNumber | 1267 |
| ASNOrg | XXXXXXXX |
| IsInEU | true |
| IsoCode | IT |
| SourceRange | 111.222.0.0/15 |
| datasource_path | /var/log/syslog |
| datasource_type | file |
| log_type | fd_failed_auth |
| machine | machine |
| service | fd |
| source_ip | 111.222.333.444 |
| timestamp | 2022-03-10T15:08:20Z |
+-----------------+-----------------------------+
I can see that probably the scenario is triggered because the parser reads more files than the /var/log/user.log
How can I limited the parsing only to the interested file?
I appended at the end of acquis.yaml file these rows:
filenames:
- /var/log/user.log
labels:
type: syslog
Is it wrong?
Thanks in advance.
Indeed it seems that the log line is wrote into 3 differents log files (/var/log/syslog, /var/log/messages, /var/log/user.log).
You can filter this in your parser with evt.Meta.datasource_path == "/var/log/user.log"
.
You can also remove the acqusition (in acquis.yaml
) for log files that you don’t want to read.
I also can see one thing that you can improve if you want to see the targeted username when inspecting the alert. (cscli alerts inspect -d
only show the Meta
object associated with each event.
For this, in your parser, you should name the HTTPDUSER
grok like this: %{HTTPDUSER:user}
so in your static, the evt.Parsed.user
will be fill and then evt.Meta.username
will be fill too.
apass
March 11, 2022, 9:37am
5
Hi,
thanks again.
There’s something yet not working correctly…
Due to the fact that this program writes on more log files I choose to use syslog file so the new parser is:
onsuccess: next_stage
filter: "evt.Meta.datasource_path == '/var/log/syslog' && evt.Parsed.program == 'php'"
#filter: "evt.Parsed.program == 'php'"
name: whoami/custom_fd
description: "Parse user.log for failed authentications"
#for clarity, we create our pattern syntax beforehand
pattern_syntax:
FD_UNAUTH: Authentication failed for user "%{HTTPDUSER:user}" \[from %{IP:source_ip}\]
nodes:
#and we use them to parse our type of logs
- grok:
name: "FD_UNAUTH"
apply_on: message
statics:
- meta: log_type
value: fd_failed_auth
#- meta: log_subtype
#value: fd_bad_auth
statics:
- meta: service
value: fd
- meta: username
expression: evt.Parsed.user
- meta: source_ip
expression: "evt.Parsed.source_ip"
And the scenario is:
type: leaky
format: 2.0
#debug: true
name: whoami/custom_fd
description: "Detect failed authentications"
filter: "evt.Meta.log_type == 'fd_failed_auth'"
leakspeed: 5m
capacity: 5
groupby: "evt.Meta.source_ip"
blackhole: 1m
#reprocess: true
reprocess: false
labels:
service: fd
type: auth_failed
remediation: true
This is the syslog with the failed authentications:
Mar 11 10:24:10 machine php: FD [unauthenticated]: (security) login: Authentication failed for user "a" [from 111.222.333.444]
Mar 11 10:24:10 machine user Mar 11 10:24:10 machine php: FD [unauthenticated]: (security) login: Authentication failed for user "a" [from 111.222.333.444]
Mar 11 10:24:16 machine php: FD [unauthenticated]: (security) login: Authentication failed for user "a" [from 111.222.333.444]
Mar 11 10:24:16 machine user Mar 11 10:24:16 machine php: FD [unauthenticated]: (security) login: Authentication failed for user "a" [from 111.222.333.444]
I think that only the first and third rows are read by the parser but the crowdsec log shows:
time="11-03-2022 10:24:16" level=info msg="Ip 111.222.333.444 performed 'whoami/custom_fd' (9 events over 23m51.315870269s) at 2022-03-11 09:24:16.152723047 +0000 UTC"
time="11-03-2022 10:24:16" level=info msg="(machine/crowdsec) whoami/custom_fd by ip 176.206.42.133 (IT/1267) : 12h ban on Ip 111.222.333.444"
The cscli alerts inspect ID -d
shows:
################################################################################################
- ID : 472
- Date : 2022-03-11T09:24:16Z
- Machine : machine
- Simulation : false
- Reason : whoami/custom_fd
- Events Count : 9
- Scope:Value: Ip:111.222.333.444
- Country : IT
- AS : XXXXXXXX
- Begin : 2022-03-11 09:00:24.836857718 +0000 UTC
- End : 2022-03-11 09:24:16.152727987 +0000 UTC
- Active Decisions :
+--------+-------------------+--------+---------------------+----------------------+
| ID | SCOPE:VALUE | ACTION | EXPIRATION | CREATED AT |
+--------+-------------------+--------+---------------------+----------------------+
| 556821 | Ip:111.222.333.444 | ban | 11h54m41.756945634s | 2022-03-11T09:24:16Z |
+--------+-------------------+--------+---------------------+----------------------+
- Events :
- Date: 2022-03-11 10:24:16 +0000 UTC
+-----------------+-----------------------------+
| KEY | VALUE |
+-----------------+-----------------------------+
| ASNNumber | 1267 |
| ASNOrg | XXXXXXXX |
| IsInEU | true |
| IsoCode | IT |
| SourceRange | 111.222.0.0/15 |
| datasource_path | /var/log/syslog |
| datasource_type | file |
| log_type | fd_failed_auth |
| machine | machine |
| service | fd |
| source_ip | 111.222.333.444 |
| timestamp | 2022-03-11T10:24:10Z |
| username | a |
+-----------------+-----------------------------+
- Date: 2022-03-11 10:24:16 +0000 UTC
+-----------------+-----------------------------+
| KEY | VALUE |
+-----------------+-----------------------------+
| ASNNumber | 1267 |
| ASNOrg | XXXXXXXX |
| IsInEU | true |
| IsoCode | IT |
| SourceRange | 111.222.0.0/15 |
| datasource_path | /var/log/syslog |
| datasource_type | file |
| log_type | fd_failed_auth |
| machine | machine |
| service | fd |
| source_ip | 111.222.333.444 |
| timestamp | 2022-03-11T10:24:10Z |
| username | a |
+-----------------+-----------------------------+
- Date: 2022-03-11 10:24:16 +0000 UTC
+-----------------+-----------------------------+
| KEY | VALUE |
+-----------------+-----------------------------+
| ASNNumber | 1267 |
| ASNOrg | XXXXXXXX |
| IsInEU | true |
| IsoCode | IT |
| SourceRange | 111.222.0.0/15 |
| datasource_path | /var/log/syslog |
| datasource_type | file |
| log_type | fd_failed_auth |
| machine | machine |
| service | fd |
| source_ip | 111.222.333.444 |
| timestamp | 2022-03-11T10:24:10Z |
| username | a |
+-----------------+-----------------------------+
- Date: 2022-03-11 10:24:16 +0000 UTC
+-----------------+-----------------------------+
| KEY | VALUE |
+-----------------+-----------------------------+
| ASNNumber | 1267 |
| ASNOrg | XXXXXXXX |
| IsInEU | true |
| IsoCode | IT |
| SourceRange | 111.222.0.0/15 |
| datasource_path | /var/log/syslog |
| datasource_type | file |
| log_type | fd_failed_auth |
| machine | machine |
| service | fd |
| source_ip | 111.222.333.444 |
| timestamp | 2022-03-11T10:24:16Z |
| username | a |
+-----------------+-----------------------------+
- Date: 2022-03-11 10:24:16 +0000 UTC
+-----------------+-----------------------------+
| KEY | VALUE |
+-----------------+-----------------------------+
| ASNNumber | 1267 |
| ASNOrg | XXXXXXXX |
| IsInEU | true |
| IsoCode | IT |
| SourceRange | 111.222.0.0/15 |
| datasource_path | /var/log/syslog |
| datasource_type | file |
| log_type | fd_failed_auth |
| machine | machine |
| service | fd |
| source_ip | 111.222.333.444 |
| timestamp | 2022-03-11T10:24:16Z |
| username | a |
+-----------------+-----------------------------+
- Date: 2022-03-11 10:24:16 +0000 UTC
+-----------------+-----------------------------+
| KEY | VALUE |
+-----------------+-----------------------------+
| ASNNumber | 1267 |
| ASNOrg | XXXXXXXX |
| IsInEU | true |
| IsoCode | IT |
| SourceRange | 111.222.0.0/15 |
| datasource_path | /var/log/syslog |
| datasource_type | file |
| log_type | fd_failed_auth |
| machine | machine |
| service | fd |
| source_ip | 111.222.333.444 |
| timestamp | 2022-03-11T10:24:16Z |
| username | a |
+-----------------+-----------------------------+
Crowdsec banned the IP after just 2 attempts and not 5 as reported in the scenario.
What’s wrong?
Thanks.
Hello,
I think your GROK pattern matches the 4 logs lines.
Furthermore, are you sure there is not more lines than those 4 in your /var/log/syslog ? When looking to cscli alerts inspect -d
output, we can see that there is 3 event with timestamp at 10:24:10 and 3 others with 10:24:16
apass
March 11, 2022, 10:03am
7
I think it matches only the first and the third because there is a filter evt.Parsed.program == 'php'
but even if it matches all, they are 4 log rows and the ban is after 5.
I got them in tail:
sudo tail -f /var/log/syslog | grep 'Authentication failed for user'
and the output was what I wrote in the previous post.
Hello @apass ,
Can you paste the content of your /etc/crowdsec/acquis.yaml
file please ?
apass
March 11, 2022, 3:25pm
9
Yes, this is:
#Generated acquisition file - wizard.sh (service: apache2) / files : /var/log/apache2/access.log /var/log/apache2/error.log
filenames:
- /var/log/apache2/access.log
- /var/log/apache2/error.log
labels:
type: apache2
---
#Generated acquisition file - wizard.sh (service: sshd) / files : /var/log/auth.log
filenames:
- /var/log/auth.log
labels:
type: syslog
---
#Generated acquisition file - wizard.sh (service: linux) / files : /var/log/syslog /var/log/kern.log /var/log/messages
filenames:
- /var/log/syslog
- /var/log/kern.log
- /var/log/messages
labels:
type: syslog
---
#Generated acquisition file - wizard.sh (service: apache2) / files : /var/log/apache2/access.log /var/log/apache2/error.log
filenames:
- /var/log/apache2/access.log
- /var/log/apache2/error.log
labels:
type: apache2
---
#Generated acquisition file - wizard.sh (service: sshd) / files : /var/log/auth.log
filenames:
- /var/log/auth.log
labels:
type: syslog
---
#Generated acquisition file - wizard.sh (service: linux) / files : /var/log/syslog /var/log/kern.log /var/log/messages
filenames:
- /var/log/syslog
- /var/log/kern.log
- /var/log/messages
labels:
type: syslog
---
#Generated acquisition file - wizard.sh (service: apache2) / files : /var/log/apache2/access.log /var/log/apache2/error.log
filenames:
- /var/log/apache2/access.log
- /var/log/apache2/error.log
labels:
type: apache2
---
#Generated acquisition file - wizard.sh (service: sshd) / files : /var/log/auth.log
filenames:
- /var/log/auth.log
labels:
type: syslog
---
#Generated acquisition file - wizard.sh (service: linux) / files : /var/log/syslog /var/log/kern.log /var/log/messages
filenames:
- /var/log/syslog
- /var/log/kern.log
- /var/log/messages
labels:
type: syslog
---
# Manually inserted acquisition file - FD / files : /var/log/user.log
#filenames:
# - /var/log/user.log
#labels:
# type: syslog
---
Hello @apass ,
As you can see in your acquisition file, crowdsec acquire the same files multiple times (3 times), which means it read one log line 3 times.
I think that this configuration is enough:
#Generated acquisition file - wizard.sh (service: apache2) / files : /var/log/apache2/access.log /var/log/apache2/error.log
filenames:
- /var/log/apache2/access.log
- /var/log/apache2/error.log
labels:
type: apache2
---
#Generated acquisition file - wizard.sh (service: sshd) / files : /var/log/auth.log
filenames:
- /var/log/auth.log
labels:
type: syslog
---
#Generated acquisition file - wizard.sh (service: linux) / files : /var/log/syslog /var/log/kern.log /var/log/messages
filenames:
- /var/log/syslog
- /var/log/kern.log
- /var/log/messages
labels:
type: syslog
apass
March 11, 2022, 3:45pm
11
Oook! Many thanks now it seems it works.
Maybe my acquis.yaml file had multiple lines because I launched the wizard several times?
apass
March 11, 2022, 8:20pm
13
Thanks @alteredCoder for your help!