What happened?
Event records in sqlite database are created in batches (as if they are accumulated for some time and only then are flushed). Then, it looks like crowdsec makes decisions based on the record creation time, not the time from logs. As a result, the system triggers bans counting very old events.
What did you expect to happen?
Making decisions crowdsec should take into account the time
field from its sqlite3 database, table events
.
How can we reproduce it (as minimally and precisely as possible)?
Not sure, complete description below.
Anything else we need to know?
First of all, I have to note that my servers have lots of free resources, there are no lags and I see in real time that logs are generated without delay.
When I tried to introduce crowdsec, I noticed weird records in its logs. In my scenarios, I use leaky buckets with capacity of 10 and 1-minute leakspeed. Mostly it banned for 11 events in less than 1 minute. But sometimes I saw records like 15 events over 8m21.82413899s
which should have never taken place. And sometimes means a lot of false positives. Examining the case, I found out the events in the sqlite db have different created_at
/ updated_at
and time
dates. It looks to me that (for some reason) crowdsec doesn't process my logs in real time. Again, I see logs written to the local files and remote syslog server without delay, and crowdsec is not utilizing 100% of CPU and is not reloading or restarting.
The same thing happens with syslog data source as well as journald.
Tried using cache_size as suggested here https://github.com/crowdsecurity/crowdsec/issues/1464 with no effect
Considering that past events can get into the database after some time, I would like to have a function that allows crowdsec to rely on the time from logs and not the creation time of db entries.
Below is an example of logs and relevant db records (local time UTC+3).
Crowdsec version
$ cscli version
2022/08/05 15:48:59 version: v1.4.1-debian-pragmatic-e1954adc325baa9e3420c324caabd50b7074dd77
2022/08/05 15:48:59 Codename: alphaga
2022/08/05 15:48:59 BuildDate: 2022-07-25_09:19:19
2022/08/05 15:48:59 GoVersion: 1.17.5
2022/08/05 15:48:59 Platform: linux
2022/08/05 15:48:59 Constraint_parser: >= 1.0, <= 2.0
2022/08/05 15:48:59 Constraint_scenario: >= 1.0, < 3.0
2022/08/05 15:48:59 Constraint_api: v1
2022/08/05 15:48:59 Constraint_acquis: >= 1.0, < 2.0
OS version
# On Linux:
$ cat /etc/os-release
NAME="Ubuntu"
VERSION="18.04.6 LTS (Bionic Beaver)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 18.04.6 LTS"
VERSION_ID="18.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=bionic
UBUNTU_CODENAME=bionic
$ uname -a
Linux host_name 5.4.0-121-generic #137~18.04.1-Ubuntu SMP Mon Jun 20 07:25:24 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
# On Windows:
C:\> wmic os get Caption, Version, BuildNumber, OSArchitecture
# paste output here
Enabled collections and parsers
$ cscli hub list -o raw
my_nginx.yaml,"enabled,local",n/a,,collections
my_ssh.yaml,"enabled,local",n/a,,collections
my_vsftpd.yaml,"enabled,local",n/a,,collections
crowdsecurity/dateparse-enrich,enabled,0.2,,parsers
crowdsecurity/geoip-enrich,enabled,0.2,"Populate event with geoloc info : as, country, coords, source range.",parsers
crowdsecurity/http-logs,enabled,0.8,"Parse more Specifically HTTP logs, such as HTTP Code, HTTP path, HTTP args and if its a static ressource",parsers
crowdsecurity/syslog-logs,"enabled,tainted",?,,parsers
crowdsecurity/whitelists,enabled,0.2,Whitelist events from private ipv4 addresses,parsers
my_ftp_parser.yaml,"enabled,local",n/a,,parsers
my_nginx_parser.yaml,"enabled,local",n/a,,parsers
my_ssh_parser.yaml,"enabled,local",n/a,,parsers
whitelist.yaml,"enabled,local",n/a,,parsers
my_ftp_script.yaml,"enabled,local",n/a,,scenarios
my_nginx_script.yaml,"enabled,local",n/a,,scenarios
my_ssh_script.yaml,"enabled,local",n/a,,scenarios
local-whitelist.yaml,"enabled,local",n/a,,postoverflows
Acquisition config
```console
# On Linux:
$ cat /etc/crowdsec/acquis.yaml /etc/crowdsec/acquis.d/*
journalctl_filter:
- _SYSTEMD_UNIT=vsftpd.service
labels:
type: ftp
---
journalctl_filter:
- _SYSTEMD_UNIT=ssh.service
labels:
type: ssh
---
source: syslog
listen_addr: 127.0.0.1
listen_port: 1108
labels:
type: nginx
---
cat: '/etc/crowdsec/acquis.d/*': No such file or directory
On Windows:
C:> Get-Content C:\ProgramData\CrowdSec\config\acquis.yaml
paste output here
Config show
$ cscli config show
Global:
- Configuration Folder : /etc/crowdsec
- Data Folder : /var/lib/crowdsec/data
- Hub Folder : /etc/crowdsec/hub
- Simulation File : /etc/crowdsec/simulation.yaml
- Log Folder : /var/log/
- Log level : info
- Log Media : file
Crowdsec:
- Acquisition File : /etc/crowdsec/acquis.yaml
- Parsers routines : 1
cscli:
- Output : human
- Hub Branch :
- Hub Folder : /etc/crowdsec/hub
Local API Server:
- Listen URL : 127.0.0.1:8080
- Profile File : /etc/crowdsec/profiles.yaml
- Trusted IPs:
- 127.0.0.1
- ::1
- Database:
- Type : sqlite
- Path : /var/lib/crowdsec/data/crowdsec.db
- Flush age : 2d
- Flush size : 5000000
Prometheus metrics
$ cscli metrics
INFO[05-08-2022 04:25:01 PM] Buckets Metrics:
+--------------------------+---------------+-----------+--------------+--------+---------+
| BUCKET | CURRENT COUNT | OVERFLOWS | INSTANTIATED | POURED | EXPIRED |
+--------------------------+---------------+-----------+--------------+--------+---------+
| my/ftp_script | 3 | 598 | 2.05k | 9.71k | 1.45k |
| my/ftp_slow_brute_script | 18 | 7 | 1.33k | 9.71k | 1.30k |
| my/nginx_button_script | 155 | 1.95M | 2.18M | 22.24M | 224.36k |
| my/nginx_proxy_script | 331 | 79.84k | 311.34k | 1.40M | 231.17k |
| my/nginx_status_script | - | 107 | 13.98k | 35.52k | 13.87k |
| my/ssh_script | 4 | 73 | 4.20k | 29.19k | 4.13k |
| my/ssh_slow_brute_script | 25 | 40 | 2.46k | 29.19k | 2.39k |
+--------------------------+---------------+-----------+--------------+--------+---------+
INFO[05-08-2022 04:25:01 PM] Acquisition Metrics:
+----------------------------------------------------+------------+--------------+----------------+------------------------+
| SOURCE | LINES READ | LINES PARSED | LINES UNPARSED | LINES POURED TO BUCKET |
+----------------------------------------------------+------------+--------------+----------------+------------------------+
| journalctl:journalctl-_SYSTEMD_UNIT=ssh.service | 211.26k | 29.23k | 182.04k | 58.37k |
| journalctl:journalctl-_SYSTEMD_UNIT=vsftpd.service | 2.39M | 9.72k | 2.38M | 19.41k |
| syslog:127.0.0.1 | 156.28M | 34.64M | 121.64M | 23.67M |
+----------------------------------------------------+------------+--------------+----------------+------------------------+
INFO[05-08-2022 04:25:01 PM] Parser Metrics:
+--------------------------+---------+---------+----------+
| PARSERS | HITS | PARSED | UNPARSED |
+--------------------------+---------+---------+----------+
| child-my/ftp_parser | 2.39M | 9.72k | 2.38M |
| child-my/nginx_parser | 465.67M | 34.64M | 431.03M |
| child-my/ssh_parser | 411.12k | 29.23k | 381.89k |
| crowdsecurity/non-syslog | 158.88M | 158.88M | - |
| my/ftp_parser | 2.39M | 9.72k | 2.38M |
| my/local_whitelist | 99.25k | 99.25k | - |
| my/nginx_parser | 156.28M | 34.64M | 121.64M |
| my/ssh_parser | 211.26k | 29.23k | 182.04k |
| my/whitelist | 34.68M | 34.68M | - |
| my/whitelist_trusted | 34.68M | 34.68M | - |
+--------------------------+---------+---------+----------+
INFO[05-08-2022 04:25:01 PM] Local Api Metrics:
+-------------------------+--------+-------+
| ROUTE | METHOD | HITS |
+-------------------------+--------+-------+
| /credits-site-offers/.* | PURGE | 15 |
| /credits-site-one/.* | PURGE | 1 |
| /v1/alerts | POST | 80981 |
| /v1/decisions/stream | GET | 55234 |
| /v1/heartbeat | GET | 9205 |
| /v1/watchers/login | POST | 159 |
+-------------------------+--------+-------+
INFO[05-08-2022 04:25:01 PM] Local Api Machines Metrics:
+--------------------------------------------------+---------------+--------+-------+
| MACHINE | ROUTE | METHOD | HITS |
+--------------------------------------------------+---------------+--------+-------+
| c8e3e5b9d1e640a6bf0a63bb3f7c9d6eNKKvHnjnxx0NxNCH | /v1/heartbeat | GET | 9205 |
| c8e3e5b9d1e640a6bf0a63bb3f7c9d6eNKKvHnjnxx0NxNCH | /v1/alerts | POST | 80981 |
+--------------------------------------------------+---------------+--------+-------+
INFO[05-08-2022 04:25:01 PM] Local Api Bouncers Metrics:
+----------------------------+----------------------+--------+-------+
| BOUNCER | ROUTE | METHOD | HITS |
+----------------------------+----------------------+--------+-------+
| FirewallBouncer-1658923396 | /v1/decisions/stream | GET | 55234 |
+----------------------------+----------------------+--------+-------+
INFO[05-08-2022 04:25:01 PM] Local Api Decisions:
+--------------------------+----------+--------+-------+
| REASON | ORIGIN | ACTION | COUNT |
+--------------------------+----------+--------+-------+
| my/ssh_slow_brute_script | crowdsec | ban | 1 |
| my/ftp_script | crowdsec | ban | 9 |
| my/nginx_button_script | crowdsec | ban | 15 |
| my/nginx_proxy_script | crowdsec | ban | 72 |
| my/ssh_script | crowdsec | ban | 3 |
+--------------------------+----------+--------+-------+
INFO[05-08-2022 04:25:01 PM] Local Api Alerts:
+--------------------------+-------+
| REASON | COUNT |
+--------------------------+-------+
| my/ftp_script | 95 |
| my/ftp_slow_brute_script | 4 |
| my/nginx_button_script | 581 |
| my/nginx_proxy_script | 3812 |
| my/ssh_script | 24 |
| my/ssh_slow_brute_script | 9 |
+--------------------------+-------+
Related custom configs versions (if applicable) : notification plugins, custom scenarios, parsers etc.
$ grep 51.75.166.15 /var/log/crowdsec.log | grep "05-08-2022"
time="05-08-2022 13:06:04" level=info msg="Ip 51.75.166.15 performed 'my/nginx_button_script' (173 events over 4h35m50.833866353s) at 2022-08-05 10:06:04.165278018 +0000 UTC"
time="05-08-2022 13:06:04" level=info msg="(c8e3e5b9d1e640a6bf0a63bb3f7c9d6eNKKvHnjnxx0NxNCH/crowdsec) my/nginx_button_script by ip 51.75.166.15 : 1h ban on Ip 51.75.166.15"
time="05-08-2022 16:19:13" level=info msg="Ip 51.75.166.15 performed 'my/nginx_button_script' (18 events over 8m35.482457865s) at 2022-08-05 13:19:13.536115242 +0000 UTC"
time="05-08-2022 16:19:14" level=info msg="(c8e3e5b9d1e640a6bf0a63bb3f7c9d6eNKKvHnjnxx0NxNCH/crowdsec) my/nginx_button_script by ip 51.75.166.15 : 1h ban on Ip 51.75.166.15"
$ sqlite3 /var/lib/crowdsec/data/crowdsec.db
sqlite> select * from events where serialized like '%51.75.166.15%';
1464440|2022-08-05 10:06:04.170914908+00:00|2022-08-05 10:06:04.170915108+00:00|2022-08-05 09:59:35.803555621+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133017
1464441|2022-08-05 10:06:04.170915658+00:00|2022-08-05 10:06:04.170915798+00:00|2022-08-05 10:03:24.183895395+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133017
1464442|2022-08-05 10:06:04.170916038+00:00|2022-08-05 10:06:04.170916188+00:00|2022-08-05 10:03:24.51312344+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133017
1464443|2022-08-05 10:06:04.170916418+00:00|2022-08-05 10:06:04.170916548+00:00|2022-08-05 10:03:37.830518321+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133017
1464444|2022-08-05 10:06:04.170916778+00:00|2022-08-05 10:06:04.170916918+00:00|2022-08-05 10:03:38.164442578+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133017
1464445|2022-08-05 10:06:04.170917148+00:00|2022-08-05 10:06:04.170917278+00:00|2022-08-05 10:04:26.884540776+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133017
1464446|2022-08-05 10:06:04.170917518+00:00|2022-08-05 10:06:04.170917638+00:00|2022-08-05 10:04:27.233135766+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133017
1464447|2022-08-05 10:06:04.170917868+00:00|2022-08-05 10:06:04.170918068+00:00|2022-08-05 10:05:18.422935082+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133017
1464448|2022-08-05 10:06:04.170918308+00:00|2022-08-05 10:06:04.170918438+00:00|2022-08-05 10:05:18.718767843+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133017
1464449|2022-08-05 10:06:04.170918678+00:00|2022-08-05 10:06:04.170918808+00:00|2022-08-05 10:06:03.817144863+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133017
1464450|2022-08-05 10:06:04.170919008+00:00|2022-08-05 10:06:04.170919138+00:00|2022-08-05 10:06:04.164888438+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133017
1467590|2022-08-05 13:19:14.170761756+00:00|2022-08-05 13:19:14.170761916+00:00|2022-08-05 13:14:21.658032638+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133302
1467591|2022-08-05 13:19:14.170762426+00:00|2022-08-05 13:19:14.170762536+00:00|2022-08-05 13:14:45.588505246+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133302
1467592|2022-08-05 13:19:14.170762826+00:00|2022-08-05 13:19:14.170762926+00:00|2022-08-05 13:14:45.915124564+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133302
1467593|2022-08-05 13:19:14.170763086+00:00|2022-08-05 13:19:14.170763216+00:00|2022-08-05 13:16:17.626209489+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133302
1467594|2022-08-05 13:19:14.170763366+00:00|2022-08-05 13:19:14.170763586+00:00|2022-08-05 13:16:17.967371233+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133302
1467595|2022-08-05 13:19:14.170763756+00:00|2022-08-05 13:19:14.170763846+00:00|2022-08-05 13:16:54.867314065+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133302
1467596|2022-08-05 13:19:14.170763996+00:00|2022-08-05 13:19:14.170764086+00:00|2022-08-05 13:16:55.196026272+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133302
1467597|2022-08-05 13:19:14.170764226+00:00|2022-08-05 13:19:14.170764316+00:00|2022-08-05 13:18:55.488550354+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133302
1467598|2022-08-05 13:19:14.170764456+00:00|2022-08-05 13:19:14.170764546+00:00|2022-08-05 13:18:55.819360088+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133302
1467599|2022-08-05 13:19:14.170764686+00:00|2022-08-05 13:19:14.170764776+00:00|2022-08-05 13:19:13.114883349+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133302
1467600|2022-08-05 13:19:14.170764926+00:00|2022-08-05 13:19:14.170765026+00:00|2022-08-05 13:19:13.535783484+00:00|[{"key":"datasource_path","value":"127.0.0.1"},{"key":"datasource_type","value":"syslog"},{"key":"reason","value":"button"},{"key":"service","value":"http"},{"key":"source_ip","value":"51.75.166.15"}]|133302