search

crowdsecurity / cs-wordpress-bouncer

CrowdSec is an open-source cyber security tool. This plugin blocks detected attackers or display them a captcha to check they are not bots.
https://wordpress.org/plugins/crowdsec/
MIT License
37 stars 6 forks source link

Cache refreshing in STREAM mode #96

Closed cRUSHr2012 closed 2 years ago

cRUSHr2012 commented 2 years ago

Refreshing the cache in STREAM mode doesn't seem to work. I am manually adding an IP with the following command: cscli decisions add -i 81.196.86.92 --reason "web bruteforce" I can see the IP in cscli decisions list table. In LIVE mode, the requests from the IP receive 403, as expected. If I use STREAM mode, and click "Refresh cache now" i get : The cache has just been refreshed (0 new decision, 0 deleted). I have tested with Techonolgy : File system / Redis

The changes are picked up only using the "Clear now button". When i add an IP, i get "CrowdSec cache has just been cleared. As the stream mode is enabled, the cache has just been warmed up, there are now 16000 decisions in cache." The requests from the IP are blocked, as expected. If I delete the IP with cscli decisions delete --ip 81.196.86.92, and click Refresh the cache now, i get "(0 new decision, 0 deleted)". I was expecting "1 deleted" If i click "Clear now button" i get ""CrowdSec cache has just been cleared. As the stream mode is enabled, the cache has just been warmed up, there are now 15999 decisions in cache." - This is OK, we have 1 less decision. Adding a bunch of IP's has the same result.

Wordpress 5.9.3 / Crowdec plugin 1.4.3

LtSich commented 2 years ago

Hi, quick question. How frequently do you refresh your cache ? Try to do it every 30s, at least < 60s.

A weird bug is happening when you don't refresh fast enough. (experimented on my side at least).

cRUSHr2012 commented 2 years ago

I refreshed at 5s, 15 sec, 30sec and over 60sec, but it's the same. Sometimes I can see that after using "Clear now" button, it only picks up the first added IP. If I add other IP's , it doesn't pick them ( and click "Refresh cache now" after each one) If I delete them one after the other, and click "Refresh cache now" between deletes , I still see "(0 new decision, 0 deleted)".

LtSich commented 2 years ago

ok, now the hard work is to find is the problem is related to the bouncer or the LAPI... I don't use the WP bouncer, won't be able to help you more here...

cRUSHr2012 commented 2 years ago

I've manually banned 10 IP's from 81.196.86.90 to 81.196.86.99. Then i unbanned them. I activated the debug option for the plugin and in the debug log I see the following:

22-05-15T19:02:27.211844+00:00|100|{"type":"REST_CLIENT_INIT","base_uri":"http://127.0.0.1:8888","timeout":1}
2022-05-15T19:02:27.211886+00:00|100|{"type":"API_CLIENT_INIT","user_agent":"WordPress CrowdSec Bouncer/v1.4.3"}
2022-05-15T19:02:27.211921+00:00|100|{"type":"START_CACHE_UPDATE"}
2022-05-15T19:02:27.211968+00:00|100|{"type":"HTTP CALL","method":"GET","uri":"http://127.0.0.1:8888/v1/decisions/stream?startup=false&scopes=Ip%2CRange","content":null}
2022-05-15T19:02:27.286831+00:00|100|{"type":"CACHE_ITEM_REMOVED","cache_key":"Ip:81.196.86.99"}
2022-05-15T19:02:27.287355+00:00|100|{"type":"DECISION_REMOVED","decision":1203187,"value":"81.196.86.99"}
2022-05-15T19:02:27.287702+00:00|100|{"type":"DECISION_TO_REMOVE_NOT_FOUND_IN_CACHE","decision":1203186}
2022-05-15T19:02:27.288106+00:00|100|{"type":"DECISION_TO_REMOVE_NOT_FOUND_IN_CACHE","decision":1203185}
2022-05-15T19:02:27.288385+00:00|100|{"type":"DECISION_TO_REMOVE_NOT_FOUND_IN_CACHE","decision":1203183}
2022-05-15T19:02:27.288692+00:00|100|{"type":"CACHE_ITEM_REMOVED","cache_key":"Ip:81.196.86.96"}
2022-05-15T19:02:27.289125+00:00|100|{"type":"DECISION_REMOVED","decision":1203184,"value":"81.196.86.96"}
2022-05-15T19:02:27.289398+00:00|100|{"type":"CACHE_ITEM_REMOVED","cache_key":"Ip:81.196.86.95"}
2022-05-15T19:02:27.289821+00:00|100|{"type":"DECISION_REMOVED","decision":1203181,"value":"81.196.86.95"}
2022-05-15T19:02:27.290097+00:00|100|{"type":"DECISION_TO_REMOVE_NOT_FOUND_IN_CACHE","decision":1203180}
2022-05-15T19:02:27.290357+00:00|100|{"type":"DECISION_TO_REMOVE_NOT_FOUND_IN_CACHE","decision":1203179}
2022-05-15T19:02:27.290606+00:00|100|{"type":"DECISION_TO_REMOVE_NOT_FOUND_IN_CACHE","decision":1203178}
2022-05-15T19:02:27.290871+00:00|100|{"type":"DECISION_TO_REMOVE_NOT_FOUND_IN_CACHE","decision":1203177}
2022-05-15T19:02:27.290965+00:00|100|{"type":"CACHE_UPDATED","deleted":0,"new":0}

Shouldn't the last line be : deleted 10 ?

LtSich commented 2 years ago

It seem that thoses decisions where not in the cache. This is why you have deleted 0. This is an interesting point, you have to check if the decisions are correctly added in the cache, and if they are, why there are not delete correctly. The dev can probably do a better debug than me as I don't use this plugin atm.

cRUSHr2012 commented 2 years ago

I've set the refresh at 600 seconds to manually trigger the "Refresh cache now button". After re-adding 10 IP's and waiting for 20 seconds, then manually refreshing, the debug log is:

2022-05-15T19:21:24.590711+00:00|100|{"type":"START_CACHE_UPDATE"}
2022-05-15T19:21:24.590888+00:00|100|{"type":"HTTP CALL","method":"GET","uri":"http://127.0.0.1:8888/v1/decisions/stream?startup=false&scopes=Ip%2CRange","content":null}
2022-05-15T19:21:24.653869+00:00|100|{"type":"CACHE_UPDATED","deleted":0,"new":0}

Deleting 9 of the IP's and waiting 20 seconds shows in the log:

2022-05-15T19:25:57.099122+00:00|100|{"type":"START_CACHE_UPDATE"}
2022-05-15T19:25:57.099202+00:00|100|{"type":"HTTP CALL","method":"GET","uri":"http://127.0.0.1:8888/v1/decisions/stream?startup=false&scopes=Ip%2CRange","content":null}
2022-05-15T19:25:57.197004+00:00|100|{"type":"DECISION_TO_REMOVE_NOT_FOUND_IN_CACHE","decision":1203206}
2022-05-15T19:25:57.197410+00:00|100|{"type":"DECISION_TO_REMOVE_NOT_FOUND_IN_CACHE","decision":1203207}
2022-05-15T19:25:57.197710+00:00|100|{"type":"DECISION_TO_REMOVE_NOT_FOUND_IN_CACHE","decision":1203208}
2022-05-15T19:25:57.197983+00:00|100|{"type":"DECISION_TO_REMOVE_NOT_FOUND_IN_CACHE","decision":1203209}
2022-05-15T19:25:57.198276+00:00|100|{"type":"DECISION_TO_REMOVE_NOT_FOUND_IN_CACHE","decision":1203210}
2022-05-15T19:25:57.198550+00:00|100|{"type":"DECISION_TO_REMOVE_NOT_FOUND_IN_CACHE","decision":1203211}
2022-05-15T19:25:57.198817+00:00|100|{"type":"DECISION_TO_REMOVE_NOT_FOUND_IN_CACHE","decision":1203212}
2022-05-15T19:25:57.199088+00:00|100|{"type":"DECISION_TO_REMOVE_NOT_FOUND_IN_CACHE","decision":1203213}
2022-05-15T19:25:57.199360+00:00|100|{"type":"DECISION_TO_REMOVE_NOT_FOUND_IN_CACHE","decision":1203214}
2022-05-15T19:25:57.199450+00:00|100|{"type":"CACHE_UPDATED","deleted":0,"new":0}

The cache doesn't seem to be updated.

cRUSHr2012 commented 2 years ago

@LtSich , after more tests I think you are right about adding an entry with cscli and the refreshing after 5-15 seconds. I did this (banning 1 IP then clicking the refresh button, after a few seconds) multiple times and it picks them UP.


2022-05-16T06:33:33.466562+00:00|100|{"type":"CACHE_UPDATED","deleted":0,"new":1}
...
2022-05-16T06:33:55.197582+00:00|100|{"type":"CACHE_UPDATED","deleted":0,"new":1}
...
2022-05-16T06:34:16.388279+00:00|100|{"type":"CACHE_UPDATED","deleted":0,"new":1}
...
2022-05-16T06:37:54.704993+00:00|100|{"type":"CACHE_UPDATED","deleted":0,"new":1}
...
2022-05-16T06:38:19.625397+00:00|100|{"type":"CACHE_UPDATED","deleted":0,"new":2}

If i wait over 30 seconds, the log says "deleted":0,"new":0

LtSich commented 2 years ago

@buixor any link with the bug we found on my side with my bouncers when refresh is > 60s ?

julienloizelet commented 2 years ago

Hi, I just tested and, for me, the cache is well updated BUT the deleted count is always 0.

Here is what I tested :

In other word, I think that decisions are deleted and added as expected, but displayed counts are wrong.

cRUSHr2012 commented 2 years ago

In my tests, the behavior is not consistent. With 2 WP sites, the ban works. I un-ban the IP, click refresh on both, and only one of them is now permitting access. Both in STREAM mode, with filesystem cache. Any hints on how can I inspect the local cache to see the IP / decision / ID ?

For the one that still bans the IP the log contains:

2022-05-16T13:57:15.911641+00:00|100|{"type":"API_CACHE_INIT","adapter":"Symfony\\Component\\Cache\\Adapter\\PhpFilesAdapter","mode":"stream","exp_clean_ips":1,"exp_bad_ips":1,"warmed_up":"true","geolocation":{"save_in_session":true,"enabled":false,"type":"maxmind","maxmind":{"database_type":"country"}}}
2022-05-16T13:57:15.912139+00:00|100|{"type":"REST_CLIENT_INIT","base_uri":"http://127.0.0.1:8888","timeout":1}
2022-05-16T13:57:15.912181+00:00|100|{"type":"API_CLIENT_INIT","user_agent":"WordPress CrowdSec Bouncer/v1.4.3"}
2022-05-16T13:57:15.914596+00:00|300|{"type":"NON_AUTHORIZED_X_FORWARDED_FOR_USAGE","original_ip":"81.196.86.90","x_forwarded_for_ip":"81.196.86.90"}
2022-05-16T13:57:15.915415+00:00|100|{"type":"START_IP_CHECK","ip":"81.196.86.90"}
2022-05-16T13:57:15.915870+00:00|300|{"type":"BAD_VALUE","value":"81.196.86.90","scope":"Ip","remediation":"ban","cache":"hit"}
2022-05-16T13:57:15.916495+00:00|200|{"type":"FINAL_REMEDIATION","ip":"81.196.86.90","remediation":"ban"}

Both sites PHP 7.4 / WP 5.9.3, Plugin v.1.4.3, no caching plugins or wordfence.

cRUSHr2012 commented 2 years ago

With a third site, it's the same with Redis cache, after i un-ban the IP, I am still blocked, even if the log says :


2022-05-16T14:45:55.306166+00:00|100|{"type":"API_CACHE_INIT","adapter":"Symfony\\Component\\Cache\\Adapter\\RedisAdapter","mode":"stream","exp_clean_ips":1,"exp_bad_ips":1,"warmed_up":"true","geolocation":{"save_in_session":true,"enabled":false,"type":"maxmind","maxmind":{"database_type":"country"}}}
2022-05-16T14:45:55.306689+00:00|100|{"type":"REST_CLIENT_INIT","base_uri":"http://127.0.0.1:8888","timeout":1}
2022-05-16T14:45:55.306763+00:00|100|{"type":"API_CLIENT_INIT","user_agent":"WordPress CrowdSec Bouncer/v1.4.3"}
2022-05-16T14:45:55.306834+00:00|100|{"type":"START_CACHE_UPDATE"}
2022-05-16T14:45:55.306921+00:00|100|{"type":"HTTP CALL","method":"GET","uri":"http://127.0.0.1:8888/v1/decisions/stream?startup=false&scopes=Ip%2CRange","content":null}
2022-05-16T14:45:55.385452+00:00|100|{"type":"DECISION_REMOVED","decision":1340270,"cache_key":"Ip:81.196.86.90"}
2022-05-16T14:45:55.385610+00:00|100|{"type":"DECISION_REMOVED","decision":1340270,"value":"81.196.86.90"}
2022-05-16T14:45:55.386001+00:00|100|{"type":"CACHE_UPDATED","deleted":0,"new":0}
julienloizelet commented 2 years ago

Hi,

I guess it will be impossible to refresh 2 filesystem caches ( or a mix of filsystem and Redis cache) with the stream mode : a refresh will only update since it last pulled. (https://docs.crowdsec.net/docs/local_api/bouncers/#stream-mode) So if you refresh on the first WP, a refresh on the second will not retrieve the decisions that have been updated for the first one ...

Do you have the same inconsistent behavior with a shared Redis cache (for all your WP) ?

cRUSHr2012 commented 2 years ago

Now I think I understand : the API does more than providing a list of IP's, it sends the ban / unban decisions. And because I am using multiple sites, subsequently refreshes won't get the same decisions as the first one. Right ?

julienloizelet commented 2 years ago

Now I think I understand : the API does more than providing a list of IP's, it sends the ban / unban decisions. And because I am using multiple sites, subsequently refreshes won't get the same decisions as the first one. Right ?

Yes, the cache stores the IP and some other information: the remediation (ban, captcha or bypass), the timestamp of this decision and the decision ID.

And yes, in stream mode, a refresh only retrieves decisions that have not been already pulled.

So, multiple website refreshes should only work with a shared cache (a single redis database seems to be the simplest way to achieve it)

cRUSHr2012 commented 2 years ago

All good with one Redis shared DB. The site with the most traffic has 60 sec refresh interval (i will lower it with a dedicated system cron job). The others have big numbers. But, being a shared DB it doesn't matter which site updates the Redis DB, because the API will provide only new decisions from the last update. So the conclusion is that we need a single Redis DB per crowdsec server, for multiple WP sites. Their logs must be available for parsing and they need to be able to access Redis + crowdsec API URL.

julienloizelet commented 2 years ago

Hi, I created an issue in the php lib repo (https://github.com/crowdsecurity/php-cs-bouncer/issues/88) to solve the "wrong deleted count issue". As the stream refresh process seems to be "ok", I close this one. Thanks