Possible fail2ban regression in lat update causing high CPU usage

[vhsantos]

Hi everyone,

I suspect that the latest update (4fd791c) introduced a regression.

Since the update, my CPU usage has been at 100% almost constantly. The issue appears to be related to fail2ban, which adds IPs to ipset, but then the fail2ban service becomes unresponsive for a moment. As a result, all IPs are removed, and fail2ban starts over, repeatedly adding them again.

I linked this issue to the update because my monitoring graphs show that CPU usage spiked right after 02:30 AM, which is when the update was applied.

Here some outputs when it is "working":

# fail2ban-client status mc-exim-1m
Status for the jail: mc-exim-1m
|- filter
|  |- File list:	/var/mailcleaner/log/exim_stage1/rejectlog 
|  |- Currently failed:	9
|  `- Total failed:	57284
`- action
   |- Currently banned:	1026
   |  `- IP list:	here all the IPs bloqued
   `- Total banned:	1026

then:

fail2ban-client status mc-exim-1m
ERROR  Unable to contact server. Is it running?

maybe 30-90 seconds later:

 fail2ban-client status mc-exim-1m
Status for the jail: mc-exim-1m
|- filter
|  |- File list:	/var/mailcleaner/log/exim_stage1/rejectlog 
|  |- Currently failed:	10
|  `- Total failed:	4785
`- action
   |- Currently banned:	47
   |  `- IP list:	here all the IPs bloqued
   `- Total banned:	47

I have looked on the kernel/syslog logs to check for a possible OOM, but nothing..
on the fail2ban.log nothing except this,

2025-03-04 16:14:13,839 fail2ban.actions.action[1629]: ERROR   ipset destroy mc-ssh-1y returned 100
2025-03-04 16:14:14,834 fail2ban.actions.action[1629]: ERROR   ipset destroy mc-webauth-1d returned 100
2025-03-04 16:14:15,819 fail2ban.actions.action[1629]: ERROR   ipset destroy mc-exim-1d returned 100
2025-03-04 16:14:15,834 fail2ban.actions.action[1629]: ERROR   ipset destroy mc-webauth-1m returned 100
2025-03-04 16:14:16,827 fail2ban.actions.action[1629]: ERROR   ipset destroy mc-exim-1m returned 100
2025-03-04 16:14:16,832 fail2ban.actions.action[1629]: ERROR   ipset destroy mc-ssh-1w returned 100
2025-03-04 16:14:16,838 fail2ban.actions.action[1629]: ERROR   ipset destroy mc-webauth-1w returned 100
2025-03-04 16:14:17,835 fail2ban.actions.action[1629]: ERROR   ipset destroy mc-ssh-1m returned 100
2025-03-04 16:14:20,569 fail2ban.actions.action[2455]: ERROR   ipset create mc-exim-1d hash:ip returned 100
2025-03-04 16:14:20,572 fail2ban.actions.action[2455]: ERROR   ipset create mc-exim-1m hash:ip returned 100
2025-03-04 16:14:20,577 fail2ban.actions.action[2455]: ERROR   ipset create mc-exim-1w hash:ip returned 100
2025-03-04 16:14:20,581 fail2ban.actions.action[2455]: ERROR   ipset create mc-exim-1y hash:ip returned 100
2025-03-04 16:14:20,584 fail2ban.actions.action[2455]: ERROR   ipset create mc-ssh-1d hash:ip returned 100
2025-03-04 16:14:20,588 fail2ban.actions.action[2455]: ERROR   ipset create mc-ssh-1m hash:ip returned 100
2025-03-04 16:14:20,592 fail2ban.actions.action[2455]: ERROR   ipset create mc-ssh-1w hash:ip returned 100
2025-03-04 16:14:20,602 fail2ban.actions.action[2455]: ERROR   ipset create mc-ssh-1y hash:ip returned 100
2025-03-04 16:14:20,608 fail2ban.actions.action[2455]: ERROR   ipset create mc-webauth-1d hash:ip returned 100
2025-03-04 16:14:20,612 fail2ban.actions.action[2455]: ERROR   ipset create mc-webauth-1m hash:ip returned 100
2025-03-04 16:14:20,614 fail2ban.actions.action[2455]: ERROR   ipset create mc-webauth-1w hash:ip returned 100
2025-03-04 16:14:20,616 fail2ban.actions.action[2455]: ERROR   ipset create mc-webauth-1y hash:ip returned 100
2025-03-04 16:15:02,656 fail2ban.filter [2455]: ERROR   Error in FilterPyinotify callback: 'module' object has no attribute '_strptime_time'
2025-03-04 16:15:02,657 fail2ban.filter [2455]: ERROR   Error in FilterPyinotify callback: 'module' object has no attribute '_strptime_time'
2025-03-04 16:15:02,657 fail2ban.filter [2455]: ERROR   Error in FilterPyinotify callback: 'module' object has no attribute '_strptime_time'
2025-03-04 17:00:18,003 fail2ban.actions.action[64104]: ERROR   ipset create mc-exim-1d hash:ip returned 7f00
2025-03-04 17:00:18,007 fail2ban.actions.action[64104]: ERROR   ipset create mc-exim-1m hash:ip returned 7f00
2025-03-04 17:00:18,012 fail2ban.actions.action[64104]: ERROR   ipset create mc-exim-1w hash:ip returned 7f00
2025-03-04 17:00:18,020 fail2ban.actions.action[64104]: ERROR   ipset create mc-exim-1y hash:ip returned 7f00
2025-03-04 17:00:18,023 fail2ban.actions.action[64104]: ERROR   ipset create mc-ssh-1d hash:ip returned 7f00
2025-03-04 17:00:18,026 fail2ban.actions.action[64104]: ERROR   ipset create mc-ssh-1m hash:ip returned 7f00
2025-03-04 17:00:18,029 fail2ban.actions.action[64104]: ERROR   ipset create mc-ssh-1w hash:ip returned 7f00
2025-03-04 17:00:18,032 fail2ban.actions.action[64104]: ERROR   ipset create mc-ssh-1y hash:ip returned 7f00
2025-03-04 17:00:18,035 fail2ban.actions.action[64104]: ERROR   ipset create mc-webauth-1d hash:ip returned 7f00
2025-03-04 17:00:18,038 fail2ban.actions.action[64104]: ERROR   ipset create mc-webauth-1m hash:ip returned 7f00
2025-03-04 17:00:18,057 fail2ban.actions.action[64104]: ERROR   ipset create mc-webauth-1w hash:ip returned 7f00
2025-03-04 17:00:18,058 fail2ban.actions.action[64104]: ERROR   ipset create mc-webauth-1y hash:ip returned 7f00
2025-03-04 17:15:17,259 fail2ban.actions.action[49981]: ERROR   ipset create mc-exim-1d hash:ip returned 7f00
2025-03-04 17:15:17,265 fail2ban.actions.action[49981]: ERROR   ipset create mc-exim-1m hash:ip returned 7f00
2025-03-04 17:15:17,271 fail2ban.actions.action[49981]: ERROR   ipset create mc-exim-1w hash:ip returned 7f00
2025-03-04 17:15:17,279 fail2ban.actions.action[49981]: ERROR   ipset create mc-exim-1y hash:ip returned 7f00
2025-03-04 17:15:17,282 fail2ban.actions.action[49981]: ERROR   ipset create mc-ssh-1d hash:ip returned 7f00
2025-03-04 17:15:17,287 fail2ban.actions.action[49981]: ERROR   ipset create mc-ssh-1m hash:ip returned 7f00
2025-03-04 17:15:17,293 fail2ban.actions.action[49981]: ERROR   ipset create mc-ssh-1w hash:ip returned 7f00
2025-03-04 17:15:17,299 fail2ban.actions.action[49981]: ERROR   ipset create mc-ssh-1y hash:ip returned 7f00
2025-03-04 17:15:17,306 fail2ban.actions.action[49981]: ERROR   ipset create mc-webauth-1d hash:ip returned 7f00
2025-03-04 17:15:17,309 fail2ban.actions.action[49981]: ERROR   ipset create mc-webauth-1m hash:ip returned 7f00
2025-03-04 17:15:17,313 fail2ban.actions.action[49981]: ERROR   ipset create mc-webauth-1w hash:ip returned 7f00
2025-03-04 17:15:17,324 fail2ban.actions.action[49981]: ERROR   ipset create mc-webauth-1y hash:ip returned 7f00
2025-03-04 17:15:28,941 fail2ban.filter [49981]: ERROR   Error in FilterPyinotify callback: 'module' object has no attribute '_strptime_time'
2025-03-04 17:15:28,942 fail2ban.filter [49981]: ERROR   Error in FilterPyinotify callback: 'module' object has no attribute '_strptime_time'
2025-03-04 17:15:28,942 fail2ban.filter [49981]: ERROR   Error in FilterPyinotify callback: 'module' object has no attribute '_strptime_time'
2025-03-04 17:30:19,231 fail2ban.actions.action[45650]: ERROR   ipset create mc-exim-1d hash:ip returned 7f00
2025-03-04 17:30:19,238 fail2ban.actions.action[45650]: ERROR   ipset create mc-exim-1m hash:ip returned 7f00
2025-03-04 17:30:19,241 fail2ban.actions.action[45650]: ERROR   ipset create mc-exim-1w hash:ip returned 7f00
2025-03-04 17:30:19,247 fail2ban.actions.action[45650]: ERROR   ipset create mc-exim-1y hash:ip returned 7f00
2025-03-04 17:30:19,251 fail2ban.actions.action[45650]: ERROR   ipset create mc-ssh-1d hash:ip returned 7f00
2025-03-04 17:30:19,259 fail2ban.actions.action[45650]: ERROR   ipset create mc-ssh-1m hash:ip returned 7f00
2025-03-04 17:30:19,262 fail2ban.actions.action[45650]: ERROR   ipset create mc-ssh-1w hash:ip returned 7f00
2025-03-04 17:30:19,267 fail2ban.actions.action[45650]: ERROR   ipset create mc-ssh-1y hash:ip returned 7f00
2025-03-04 17:30:19,274 fail2ban.actions.action[45650]: ERROR   ipset create mc-webauth-1d hash:ip returned 7f00
2025-03-04 17:30:19,277 fail2ban.actions.action[45650]: ERROR   ipset create mc-webauth-1m hash:ip returned 7f00
2025-03-04 17:30:19,280 fail2ban.actions.action[45650]: ERROR   ipset create mc-webauth-1w hash:ip returned 7f00
2025-03-04 17:30:19,293 fail2ban.actions.action[45650]: ERROR   ipset create mc-webauth-1y hash:ip returned 7f00
2025-03-04 17:30:30,994 fail2ban.filter [45650]: ERROR   Error in FilterPyinotify callback: 'module' object has no attribute '_strptime_time'
2025-03-04 17:30:30,994 fail2ban.filter [45650]: ERROR   Error in FilterPyinotify callback: 'module' object has no attribute '_strptime_time'
2025-03-04 17:30:30,995 fail2ban.filter [45650]: ERROR   Error in FilterPyinotify callback: 'module' object has no attribute '_strptime_time'

Putting the fail2ban in debug mode (loglevel 4), show nothing outside of normal neither.

Any idea or suggestions ??

[vhsantos]

Just in case, the output of the ps command:

ps aux | grep fail2ban
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root     35533  0.0  0.0   4340   720 ?        Ss   18:15   0:00 /bin/sh -c PYENV_VERSION=3.7.7; /var/mailcleaner/.pyenv/versions/3.7.7/bin/fail2ban.py internal cron-job > /dev/null 2>&1 
root     35536  5.7  1.3 376696 56284 ?        Sl   18:15   0:14 /var/mailcleaner/.pyenv/versions/3.7.7/bin/python3.7 /var/mailcleaner/.pyenv/versions/3.7.7/bin/fail2ban.py internal cron-job
root     55090  0.0  0.0   4340   708 ?        S    18:19   0:00 sh -c PYENV_VERSION=3.7.7 fail2ban.py internal send-rbl mc-exim 218.201.125.126
root     55091 86.0  1.0 133056 43256 ?        R    18:19   0:00 /var/mailcleaner/.pyenv/versions/3.7.7/bin/python3.7 /var/mailcleaner/.pyenv/versions/3.7.7/bin/fail2ban.py internal send-rbl mc-exim 218.201.125.126
root     55172  0.0  0.0  15428  2912 ?        S    18:19   0:00 /bin/bash -c fail2ban-client status mc-exim-1y |grep 112.102.48.129
root     65115  2.9  0.5 783616 21928 ?        Sl   17:51   0:49 /usr/bin/python /usr/bin/fail2ban-server -b -s /var/run/fail2ban/fail2ban.sock -p /var/run/fail2ban/fail2ban.pid

[vhsantos]

And just to show some DEBUG logs, here, we can see the system working (fail2ban.py ban -j mc-exim-1y -i 98.110.70.2 returned successfully and then, it restart (2025-03-04 18:30:17,693 fail2ban.server [17170]: INFO Changed logging target to /var/log/fail2ban.log for Fail2ban v0.8.13)

2025-03-04 18:30:01,862 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:01,862 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:01,863 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:01,863 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3776 hits
2025-03-04 18:30:01,863 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:01,863 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:01,863 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:01,864 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:01,864 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3775 hits
2025-03-04 18:30:01,864 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:01,864 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:01,864 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:01,865 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:01,865 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3775 hits
2025-03-04 18:30:02,693 fail2ban.actions.action[65115]: DEBUG   PYENV_VERSION=3.7.7 fail2ban.py internal send-rbl mc-exim 140.82.157.126 returned successfully
2025-03-04 18:30:02,694 fail2ban.actions[65115]: WARNING [mc-exim-1y] Ban 153.141.57.213
2025-03-04 18:30:02,694 fail2ban.actions.action[65115]: DEBUG   ipset list mc-exim-1y | sed '0,/^Members:$/d'
2025-03-04 18:30:02,715 fail2ban.actions.action[65115]: DEBUG   ipset list mc-exim-1y | sed '0,/^Members:$/d' returned successfully
2025-03-04 18:30:02,715 fail2ban.actions.action[65115]: DEBUG   PYENV_VERSION=3.7.7 fail2ban.py ban -j mc-exim-1y -i 153.141.57.213
2025-03-04 18:30:02,883 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:02,884 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:02,884 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:02,884 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:02,884 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3776 hits
2025-03-04 18:30:02,885 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:02,885 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:02,885 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:02,885 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:02,885 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3777 hits
2025-03-04 18:30:02,885 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:02,885 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:02,885 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:02,886 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:02,886 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3776 hits
2025-03-04 18:30:02,886 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:02,886 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:02,886 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:02,886 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:02,886 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3776 hits
2025-03-04 18:30:05,836 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:05,837 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:05,837 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:05,837 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:05,837 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3777 hits
2025-03-04 18:30:05,837 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:05,837 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:05,838 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:05,838 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:05,838 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3778 hits
2025-03-04 18:30:05,838 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:05,838 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:05,838 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:05,838 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:05,838 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3777 hits
2025-03-04 18:30:05,839 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:05,839 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:05,839 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:05,839 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:05,839 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3777 hits
2025-03-04 18:30:06,211 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:06,211 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:06,211 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:06,211 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:06,212 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3778 hits
2025-03-04 18:30:06,212 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:06,212 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:06,212 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:06,212 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:06,212 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3779 hits
2025-03-04 18:30:06,212 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:06,212 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:06,213 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:06,213 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:06,213 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3778 hits
2025-03-04 18:30:06,213 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:06,213 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:06,213 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:06,213 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:06,214 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3778 hits
2025-03-04 18:30:06,242 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:06,242 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:06,243 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:06,243 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:06,243 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3779 hits
2025-03-04 18:30:06,243 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:06,244 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:06,244 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:06,244 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:06,244 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3780 hits
2025-03-04 18:30:06,245 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:06,245 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:06,245 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:06,246 fail2ban.filter [65115]: DEBUG   Default Callback for Event: <Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=2 >
2025-03-04 18:30:06,246 fail2ban.filter.datedetector[65115]: DEBUG   Matched time template MONTH Day Hour:Minute:Second
2025-03-04 18:30:06,246 fail2ban.filter.datedetector[65115]: DEBUG   Got time using template MONTH Day Hour:Minute:Second
2025-03-04 18:30:06,247 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:06,247 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3779 hits
2025-03-04 18:30:06,245 fail2ban.filter.datedetector[65115]: DEBUG   Sorting the template list
2025-03-04 18:30:06,247 fail2ban.filter.datedetector[65115]: DEBUG   Winning template: MONTH Day Hour:Minute:Second with 3779 hits
2025-03-04 18:30:06,483 fail2ban.actions.action[65115]: DEBUG   PYENV_VERSION=3.7.7 fail2ban.py ban -j mc-exim-1y -i 153.141.57.213 returned successfully
2025-03-04 18:30:06,483 fail2ban.actions.action[65115]: DEBUG   
2025-03-04 18:30:06,483 fail2ban.actions.action[65115]: DEBUG   Nothing to do
2025-03-04 18:30:06,483 fail2ban.actions.action[65115]: DEBUG   PYENV_VERSION=3.7.7 fail2ban.py internal send-rbl mc-exim 153.141.57.213
2025-03-04 18:30:08,695 fail2ban.actions.action[65115]: DEBUG   PYENV_VERSION=3.7.7 fail2ban.py internal send-rbl mc-exim 153.141.57.213 returned successfully
2025-03-04 18:30:08,695 fail2ban.actions[65115]: WARNING [mc-exim-1y] Ban 116.116.156.198
2025-03-04 18:30:08,696 fail2ban.actions.action[65115]: DEBUG   ipset list mc-exim-1y | sed '0,/^Members:$/d'
2025-03-04 18:30:08,699 fail2ban.actions.action[65115]: DEBUG   ipset list mc-exim-1y | sed '0,/^Members:$/d' returned successfully
2025-03-04 18:30:08,700 fail2ban.actions.action[65115]: DEBUG   PYENV_VERSION=3.7.7 fail2ban.py ban -j mc-exim-1y -i 116.116.156.198
2025-03-04 18:30:09,620 fail2ban.actions.action[65115]: DEBUG   PYENV_VERSION=3.7.7 fail2ban.py ban -j mc-exim-1y -i 116.116.156.198 returned successfully
2025-03-04 18:30:09,621 fail2ban.actions.action[65115]: DEBUG   
2025-03-04 18:30:09,621 fail2ban.actions.action[65115]: DEBUG   Nothing to do
2025-03-04 18:30:09,621 fail2ban.actions.action[65115]: DEBUG   PYENV_VERSION=3.7.7 fail2ban.py internal send-rbl mc-exim 116.116.156.198
2025-03-04 18:30:11,581 fail2ban.actions.action[65115]: DEBUG   PYENV_VERSION=3.7.7 fail2ban.py internal send-rbl mc-exim 116.116.156.198 returned successfully
2025-03-04 18:30:11,581 fail2ban.actions[65115]: WARNING [mc-exim-1y] Ban 98.110.70.2
2025-03-04 18:30:11,581 fail2ban.actions.action[65115]: DEBUG   ipset list mc-exim-1y | sed '0,/^Members:$/d'
2025-03-04 18:30:11,585 fail2ban.actions.action[65115]: DEBUG   ipset list mc-exim-1y | sed '0,/^Members:$/d' returned successfully
2025-03-04 18:30:11,586 fail2ban.actions.action[65115]: DEBUG   PYENV_VERSION=3.7.7 fail2ban.py ban -j mc-exim-1y -i 98.110.70.2
2025-03-04 18:30:12,687 fail2ban.actions.action[65115]: DEBUG   PYENV_VERSION=3.7.7 fail2ban.py ban -j mc-exim-1y -i 98.110.70.2 returned successfully
2025-03-04 18:30:12,687 fail2ban.actions.action[65115]: DEBUG   
2025-03-04 18:30:12,687 fail2ban.actions.action[65115]: DEBUG   Nothing to do
2025-03-04 18:30:12,688 fail2ban.actions.action[65115]: DEBUG   PYENV_VERSION=3.7.7 fail2ban.py internal send-rbl mc-exim 98.110.70.2
2025-03-04 18:30:17,693 fail2ban.server [17170]: INFO    Changed logging target to /var/log/fail2ban.log for Fail2ban v0.8.13
2025-03-04 18:30:17,695 fail2ban.comm   [17170]: DEBUG   Command: ['add', 'mc-exim-1d', 'pyinotify']
2025-03-04 18:30:17,695 fail2ban.jail   [17170]: INFO    Creating new jail 'mc-exim-1d'
2025-03-04 18:30:17,735 fail2ban.jail   [17170]: INFO    Jail 'mc-exim-1d' uses pyinotify
2025-03-04 18:30:17,743 fail2ban.filter [17170]: DEBUG   Setting usedns = warn for FilterPyinotify(Jail('mc-exim-1d'))
2025-03-04 18:30:17,748 fail2ban.filter [17170]: DEBUG   Created FilterPyinotify(Jail('mc-exim-1d'))
2025-03-04 18:30:17,752 fail2ban.filter [17170]: DEBUG   Created FilterPyinotify
2025-03-04 18:30:17,752 fail2ban.jail   [17170]: INFO    Initiated 'pyinotify' backend
2025-03-04 18:30:17,753 fail2ban.comm   [17170]: DEBUG   Command: ['status', 'mc-exim-1d']
2025-03-04 18:30:17,756 fail2ban.comm   [17170]: DEBUG   Command: ['set', 'mc-exim-1d', 'usedns', 'warn']
2025-03-04 18:30:17,757 fail2ban.filter [17170]: DEBUG   Setting usedns = warn for FilterPyinotify(Jail('mc-exim-1d'))
2025-03-04 18:30:17,758 fail2ban.comm   [17170]: DEBUG   Command: ['set', 'mc-exim-1d', 'addlogpath', '/var/mailcleaner/log/exim_stage1/rejectlog']
2025-03-04 18:30:17,758 fail2ban.filter [17170]: INFO    Added logfile = /var/mailcleaner/log/exim_stage1/rejectlog
2025-03-04 18:30:17,759 fail2ban.filter [17170]: DEBUG   Added monitor for the parent directory /var/mailcleaner/log/exim_stage1
2025-03-04 18:30:17,759 fail2ban.filter [17170]: DEBUG   Added file watcher for /var/mailcleaner/log/exim_stage1/rejectlog
2025-03-04 18:30:17,760 fail2ban.filter.datedetector[17170]: DEBUG   Sorting the template list
2025-03-04 18:30:17,760 fail2ban.filter.datedetector[17170]: DEBUG   Winning template: WEEKDAY MONTH Day Hour:Minute:Second[.subsecond] Year with 0 hits