Fail2ban-server running high CPU

FreePBX Security
,
1

fail2ban-server process runs at 90% CPU on avg. fluctuates sometimes to 30%, but then within seconds hovers around 90%.
This was occurring on FPBX14, went ahead and upgraded to FPBX15 and it’s still occurring. I’ll turn the “Intrusion Detection Sync Firewall” to legacy mode and still occurs.
Currently running FreePBX Version:15.0.17.46
PBX Distro: 12.7.8-2107-3.sng7
Asterisk Version: 18.5.0
Sysadmin module version: 15.0.21.70
firewall module version: 15.0.17

nothing is getting banned… so not sure what’s causing this… any ideas?
any logs i should look at?

2

/var/log/fail2ban.log and /var/log/firewall.log doesn’t show much of anything that stands out.
looks like normal activity.
only thing that’s weird is in asterisk CLI, when I run “pjsip show endpoints” I see a bunch of odd extensions that are prefixed with 99, 9999, and 99999999. I think that’s from the zulu module just odd??

3

AFAIK, these are UCP and Zulu/Sangoma Connect.

1 Like
4

I just updated one of my FreePBX 15 (SNG 7 Distro 64Bit) Servers to latest asterisk packages (yum update) and modules (fwconsole ma upgradeall) and after the reboot I now also have close to 100% (1 core) load on the fail2ban-server task… Nothing in fail2ban.log, I don’t have a /var/log/firewall.log

journalctl -u fail2ban doesn’t show anything either

Stopping fail2ban (systemctl stop fail2ban) brings cpu load down, starting it again and fail2ban immediately consumes 95-100%. Something is broken here…

5

installing fail2ban’s pyinotify backend might help if you are ‘log bound’

6

so not sure what happened but after a few hours it resolved itself… maybe just poor timing or coincidence with something else I wasn’t noticing. odd.

7

It is scanning all your log files and if you have huge logs sitting in /var/log/asterisk it will process for a while.

8

I did not know that. hmm… that is something. my log size has changed significantly. Whereas fail2ban.log is normally around 18,000kb, it grew to 1,040,982kb in just the past few hours.

9

post the last couple dozen lines of the log file.

10 
18398	[2021-08-02 12:13:13] SECURITY[1980] res_security_log.c: SecurityEvent="ChallengeSent",EventTV="2021-08-02T12:13:13.130-0500",Severity="Informational",Service="SIP",EventVersion="1",AccountID="270",SessionID="0x7f26b40af670",LocalAddress="IPV4/UDP/[OBFUSCATEDHOSTIP]/5060",RemoteAddress="IPV4/UDP/[OBFUSCATEDENDPOINTIP]/5060",Challenge="5c89c0f4"	
18399	[2021-08-02 12:13:13] SECURITY[1980] res_security_log.c: SecurityEvent="SuccessfulAuth",EventTV="2021-08-02T12:13:13.227-0500",Severity="Informational",Service="SIP",EventVersion="1",AccountID="270",SessionID="0x7f26b40af670",LocalAddress="IPV4/UDP/[OBFUSCATEDHOSTIP]/5060",RemoteAddress="IPV4/UDP/[OBFUSCATEDENDPOINTIP]/5060",UsingPassword="1"	
18400	[2021-08-02 12:13:13] SECURITY[1980] res_security_log.c: SecurityEvent="ChallengeSent",EventTV="2021-08-02T12:13:13.730-0500",Severity="Informational",Service="SIP",EventVersion="1",AccountID="271",SessionID="0x7f26b40b55a0",LocalAddress="IPV4/UDP/[OBFUSCATEDHOSTIP]/5060",RemoteAddress="IPV4/UDP/[OBFUSCATEDENDPOINTIP]/5070",Challenge="67371234"	
18401	[2021-08-02 12:13:13] SECURITY[1980] res_security_log.c: SecurityEvent="SuccessfulAuth",EventTV="2021-08-02T12:13:13.827-0500",Severity="Informational",Service="SIP",EventVersion="1",AccountID="271",SessionID="0x7f26b40b55a0",LocalAddress="IPV4/UDP/[OBFUSCATEDHOSTIP]/5060",RemoteAddress="IPV4/UDP/[OBFUSCATEDENDPOINTIP]/5070",UsingPassword="1"	
18402	[2021-08-02 12:13:15] SECURITY[1980] res_security_log.c: SecurityEvent="SuccessfulAuth",EventTV="2021-08-02T12:13:15.771-0500",Severity="Informational",Service="AMI",EventVersion="1",AccountID="admin",SessionID="0x7f269c04a4f0",LocalAddress="IPV4/TCP/0.0.0.0/5038",RemoteAddress="IPV4/TCP/127.0.0.1/34036",UsingPassword="0",SessionTV="2021-08-02T12:13:15.771-0500"	
18403	[2021-08-02 12:13:16] SECURITY[1980] res_security_log.c: SecurityEvent="ChallengeSent",EventTV="2021-08-02T12:13:16.218-0500",Severity="Informational",Service="PJSIP",EventVersion="1",AccountID="217",SessionID="5ffd0bed07bb3006",LocalAddress="IPV4/UDP/[OBFUSCATEDHOSTIP]/5160",RemoteAddress="IPV4/UDP/[OBFUSCATEDENDPOINTIP2]/3270",Challenge=""	
18404	[2021-08-02 12:13:16] SECURITY[1980] res_security_log.c: SecurityEvent="SuccessfulAuth",EventTV="2021-08-02T12:13:16.283-0500",Severity="Informational",Service="PJSIP",EventVersion="1",AccountID="217",SessionID="5ffd0bed07bb3006",LocalAddress="IPV4/UDP/[OBFUSCATEDHOSTIP]/5160",RemoteAddress="IPV4/UDP/[OBFUSCATEDENDPOINTIP2]/3270",UsingPassword="1"	
18405	[2021-08-02 12:13:19] SECURITY[1980] res_security_log.c: SecurityEvent="SuccessfulAuth",EventTV="2021-08-02T12:13:19.055-0500",Severity="Informational",Service="AMI",EventVersion="1",AccountID="admin",SessionID="0x7f26a889a530",LocalAddress="IPV4/TCP/0.0.0.0/5038",RemoteAddress="IPV4/TCP/127.0.0.1/34042",UsingPassword="0",SessionTV="2021-08-02T12:13:19.055-0500"	
18406	[2021-08-02 12:13:19] SECURITY[1980] res_security_log.c: SecurityEvent="ChallengeSent",EventTV="2021-08-02T12:13:19.328-0500",Severity="Informational",Service="PJSIP",EventVersion="1",AccountID="208",SessionID="b1846e5b52694a9d",LocalAddress="IPV4/UDP/[OBFUSCATEDHOSTIP]/5160",RemoteAddress="IPV4/UDP/[OBFUSCATEDENDPOINTIP2]/3273",Challenge=""	
18407	[2021-08-02 12:13:19] SECURITY[1980] res_security_log.c: SecurityEvent="SuccessfulAuth",EventTV="2021-08-02T12:13:19.389-0500",Severity="Informational",Service="PJSIP",EventVersion="1",AccountID="208",SessionID="b1846e5b52694a9d",LocalAddress="IPV4/UDP/[OBFUSCATEDHOSTIP]/5160",RemoteAddress="IPV4/UDP/[OBFUSCATEDENDPOINTIP2]/3273",UsingPassword="1"	
18408	[2021-08-02 12:13:20] SECURITY[1980] res_security_log.c: SecurityEvent="SuccessfulAuth",EventTV="2021-08-02T12:13:20.664-0500",Severity="Informational",Service="AMI",EventVersion="1",AccountID="admin",SessionID="0x7f26a40b2080",LocalAddress="IPV4/TCP/0.0.0.0/5038",RemoteAddress="IPV4/TCP/127.0.0.1/34048",UsingPassword="0",SessionTV="2021-08-02T12:13:20.664-0500"	
18409	[2021-08-02 12:13:22] SECURITY[1980] res_security_log.c: SecurityEvent="SuccessfulAuth",EventTV="2021-08-02T12:13:22.451-0500",Severity="Informational",Service="AMI",EventVersion="1",AccountID="admin",SessionID="0x7f26b00ced40",LocalAddress="IPV4/TCP/0.0.0.0/5038",RemoteAddress="IPV4/TCP/127.0.0.1/34056",UsingPassword="0",SessionTV="2021-08-02T12:13:22.451-0500"	
18410	[2021-08-02 12:13:25] SECURITY[1980] res_security_log.c: SecurityEvent="SuccessfulAuth",EventTV="2021-08-02T12:13:25.762-0500",Severity="Informational",Service="AMI",EventVersion="1",AccountID="admin",SessionID="0x7f26ac01ec30",LocalAddress="IPV4/TCP/0.0.0.0/5038",RemoteAddress="IPV4/TCP/127.0.0.1/34062",UsingPassword="0",SessionTV="2021-08-02T12:13:25.761-0500"
11

That is not the fail2ban log it is the log file that fail2ban is watching for the asterisk jail, v0.8 has three possible backends the slowest is ‘poll’ the next slowest ‘gamin’ by far the fastest is ‘pyinotify’, using ‘auto’ will select the fastest one available

When Sangoma get around to using a current version of fail2ban, your problems will go away as fail2ban >=v0.9 no longer needs to read every line of the logs it is watching on a restart.

12

I checked all log file locations mentioned in /etc/fail2ban/jail.local and the worst file found was 1.6M big. For some strange reason the high CPU load had already disappeared today, I’m not sure what it was. Now when I restart fail2ban it only consumes 100% cpu for a few seconds (yesterday it was very different and still running at 100% after >10 minutes).

I had some large pretty large /var/log/asterisk/freepbx.log files, but those do not seem to be scanned by fail2ban so I really don’t know what had causes this.

13

Likely the offending file was ‘logrotated’ out of fail2ban’s purview.

14

Ran into this today with one of my systems. Looked in /var/log/asterisk and found a 1/2Gb Fail2ban log file. Deleted it, restarted intrusion detection from the gui and all returned to normal…

15

This topic was automatically closed 31 days after the last reply. New replies are no longer allowed.