Compare commits

...

2 Commits

View File

@ -1,5 +1,7 @@
#!/usr/bin/env python3 #!/usr/bin/env python3
DEBUG = False
import re import re
import os import os
import sys import sys
@ -20,8 +22,11 @@ from modules.Logger import Logger
from modules.IPTables import IPTables from modules.IPTables import IPTables
from modules.NFTables import NFTables from modules.NFTables import NFTables
def logdebug(msg):
if DEBUG:
logger.logInfo("DEBUG: %s" % msg)
# globals # Globals
WHITELIST = [] WHITELIST = []
BLACKLIST = [] BLACKLIST = []
bans = {} bans = {}
@ -33,12 +38,10 @@ r = None
pubsub = None pubsub = None
clear_before_quit = False clear_before_quit = False
def refreshF2boptions(): def refreshF2boptions():
global f2boptions global f2boptions
global quit_now global quit_now
global exit_code global exit_code
f2boptions = {} f2boptions = {}
if not r.get('F2B_OPTIONS'): if not r.get('F2B_OPTIONS'):
@ -52,8 +55,9 @@ def refreshF2boptions():
else: else:
try: try:
f2boptions = json.loads(r.get('F2B_OPTIONS')) f2boptions = json.loads(r.get('F2B_OPTIONS'))
except ValueError: except ValueError as e:
logger.logCrit('Error loading F2B options: F2B_OPTIONS is not json') logger.logCrit(
'Error loading F2B options: F2B_OPTIONS is not json. Exception: %s' % e)
quit_now = True quit_now = True
exit_code = 2 exit_code = 2
@ -111,7 +115,7 @@ def get_ip(address):
def ban(address): def ban(address):
global f2boptions global f2boptions
global lock global lock
logdebug("ban() called with address=%s" % address)
refreshF2boptions() refreshF2boptions()
MAX_ATTEMPTS = int(f2boptions['max_attempts']) MAX_ATTEMPTS = int(f2boptions['max_attempts'])
RETRY_WINDOW = int(f2boptions['retry_window']) RETRY_WINDOW = int(f2boptions['retry_window'])
@ -119,31 +123,43 @@ def ban(address):
NETBAN_IPV6 = '/' + str(f2boptions['netban_ipv6']) NETBAN_IPV6 = '/' + str(f2boptions['netban_ipv6'])
ip = get_ip(address) ip = get_ip(address)
if not ip: return if not ip:
logdebug("No valid IP -- skipping ban()")
return
address = str(ip) address = str(ip)
self_network = ipaddress.ip_network(address) self_network = ipaddress.ip_network(address)
with lock: with lock:
temp_whitelist = set(WHITELIST) temp_whitelist = set(WHITELIST)
logdebug("Checking if %s overlaps with any WHITELIST entries" % self_network)
if temp_whitelist: if temp_whitelist:
for wl_key in temp_whitelist: for wl_key in temp_whitelist:
wl_net = ipaddress.ip_network(wl_key, False) wl_net = ipaddress.ip_network(wl_key, False)
logdebug("Checking overlap between %s and %s" % (self_network, wl_net))
if wl_net.overlaps(self_network): if wl_net.overlaps(self_network):
logger.logInfo('Address %s is whitelisted by rule %s' % (self_network, wl_net)) logger.logInfo(
'Address %s is whitelisted by rule %s' % (self_network, wl_net))
return return
net = ipaddress.ip_network((address + (NETBAN_IPV4 if type(ip) is ipaddress.IPv4Address else NETBAN_IPV6)), strict=False) net = ipaddress.ip_network(
(address + (NETBAN_IPV4 if type(ip) is ipaddress.IPv4Address else NETBAN_IPV6)), strict=False)
net = str(net) net = str(net)
logdebug("Ban net: %s" % net)
if not net in bans: if not net in bans:
bans[net] = {'attempts': 0, 'last_attempt': 0, 'ban_counter': 0} bans[net] = {'attempts': 0, 'last_attempt': 0, 'ban_counter': 0}
logdebug("Initing new ban counter for %s" % net)
current_attempt = time.time() current_attempt = time.time()
logdebug("Current attempt ts=%s, previous: %s, retry_window: %s" %
(current_attempt, bans[net]['last_attempt'], RETRY_WINDOW))
if current_attempt - bans[net]['last_attempt'] > RETRY_WINDOW: if current_attempt - bans[net]['last_attempt'] > RETRY_WINDOW:
bans[net]['attempts'] = 0 bans[net]['attempts'] = 0
logdebug("Ban counter for %s reset as window expired" % net)
bans[net]['attempts'] += 1 bans[net]['attempts'] += 1
bans[net]['last_attempt'] = current_attempt bans[net]['last_attempt'] = current_attempt
logdebug("%s attempts now %d" % (net, bans[net]['attempts']))
if bans[net]['attempts'] >= MAX_ATTEMPTS: if bans[net]['attempts'] >= MAX_ATTEMPTS:
cur_time = int(round(time.time())) cur_time = int(round(time.time()))
@ -151,34 +167,41 @@ def ban(address):
logger.logCrit('Banning %s for %d minutes' % (net, NET_BAN_TIME / 60 )) logger.logCrit('Banning %s for %d minutes' % (net, NET_BAN_TIME / 60 ))
if type(ip) is ipaddress.IPv4Address and int(f2boptions['manage_external']) != 1: if type(ip) is ipaddress.IPv4Address and int(f2boptions['manage_external']) != 1:
with lock: with lock:
logdebug("Calling tables.banIPv4(%s)" % net)
tables.banIPv4(net) tables.banIPv4(net)
elif int(f2boptions['manage_external']) != 1: elif int(f2boptions['manage_external']) != 1:
with lock: with lock:
logdebug("Calling tables.banIPv6(%s)" % net)
tables.banIPv6(net) tables.banIPv6(net)
logdebug("Updating F2B_ACTIVE_BANS[%s]=%d" %
(net, cur_time + NET_BAN_TIME))
r.hset('F2B_ACTIVE_BANS', '%s' % net, cur_time + NET_BAN_TIME) r.hset('F2B_ACTIVE_BANS', '%s' % net, cur_time + NET_BAN_TIME)
else: else:
logger.logWarn('%d more attempts in the next %d seconds until %s is banned' % (MAX_ATTEMPTS - bans[net]['attempts'], RETRY_WINDOW, net)) logger.logWarn('%d more attempts in the next %d seconds until %s is banned' % (
MAX_ATTEMPTS - bans[net]['attempts'], RETRY_WINDOW, net))
def unban(net): def unban(net):
global lock global lock
logdebug("Calling unban() with net=%s" % net)
if not net in bans: if not net in bans:
logger.logInfo('%s is not banned, skipping unban and deleting from queue (if any)' % net) logger.logInfo(
'%s is not banned, skipping unban and deleting from queue (if any)' % net)
r.hdel('F2B_QUEUE_UNBAN', '%s' % net) r.hdel('F2B_QUEUE_UNBAN', '%s' % net)
return return
logger.logInfo('Unbanning %s' % net) logger.logInfo('Unbanning %s' % net)
if type(ipaddress.ip_network(net)) is ipaddress.IPv4Network: if type(ipaddress.ip_network(net)) is ipaddress.IPv4Network:
with lock: with lock:
logdebug("Calling tables.unbanIPv4(%s)" % net)
tables.unbanIPv4(net) tables.unbanIPv4(net)
else: else:
with lock: with lock:
logdebug("Calling tables.unbanIPv6(%s)" % net)
tables.unbanIPv6(net) tables.unbanIPv6(net)
r.hdel('F2B_ACTIVE_BANS', '%s' % net) r.hdel('F2B_ACTIVE_BANS', '%s' % net)
r.hdel('F2B_QUEUE_UNBAN', '%s' % net) r.hdel('F2B_QUEUE_UNBAN', '%s' % net)
if net in bans: if net in bans:
logdebug("Unban for %s, setting attempts=0, ban_counter+=1" % net)
bans[net]['attempts'] = 0 bans[net]['attempts'] = 0
bans[net]['ban_counter'] += 1 bans[net]['ban_counter'] += 1
@ -213,8 +236,10 @@ def clear():
global lock global lock
logger.logInfo('Clearing all bans') logger.logInfo('Clearing all bans')
for net in bans.copy(): for net in bans.copy():
logdebug("Unbanning net: %s" % net)
unban(net) unban(net)
with lock: with lock:
logdebug("Clearing IPv4/IPv6 table")
tables.clearIPv4Table() tables.clearIPv4Table()
tables.clearIPv6Table() tables.clearIPv6Table()
try: try:
@ -275,21 +300,35 @@ def snat6(snat_target):
def autopurge(): def autopurge():
global f2boptions global f2boptions
logdebug("autopurge thread started")
while not quit_now: while not quit_now:
logdebug("autopurge tick")
time.sleep(10) time.sleep(10)
refreshF2boptions() refreshF2boptions()
MAX_ATTEMPTS = int(f2boptions['max_attempts']) MAX_ATTEMPTS = int(f2boptions['max_attempts'])
QUEUE_UNBAN = r.hgetall('F2B_QUEUE_UNBAN') QUEUE_UNBAN = r.hgetall('F2B_QUEUE_UNBAN')
logdebug("QUEUE_UNBAN: %s" % QUEUE_UNBAN)
if QUEUE_UNBAN: if QUEUE_UNBAN:
for net in QUEUE_UNBAN: for net in QUEUE_UNBAN:
logdebug("Autopurge: unbanning queued net: %s" % net)
unban(str(net)) unban(str(net))
for net in bans.copy(): # Only check expiry for actively banned IPs:
if bans[net]['attempts'] >= MAX_ATTEMPTS: active_bans = r.hgetall('F2B_ACTIVE_BANS')
NET_BAN_TIME = calcNetBanTime(bans[net]['ban_counter']) now = time.time()
TIME_SINCE_LAST_ATTEMPT = time.time() - bans[net]['last_attempt'] for net_str, expire_str in active_bans.items():
if TIME_SINCE_LAST_ATTEMPT > NET_BAN_TIME: logdebug("Checking ban expiry for (actively banned): %s" % net_str)
unban(net) # Defensive: always process if timer missing or expired
try:
expire = float(expire_str)
except Exception:
logdebug("Invalid expire time for %s; unbanning" % net_str)
unban(net_str)
continue
time_left = expire - now
logdebug("Time left for %s: %.1f seconds" % (net_str, time_left))
if time_left <= 0:
logdebug("Ban expired for %s" % net_str)
unban(net_str)
def mailcowChainOrder(): def mailcowChainOrder():
global lock global lock
@ -386,25 +425,25 @@ def blacklistUpdate():
def sigterm_quit(signum, frame): def sigterm_quit(signum, frame):
global clear_before_quit global clear_before_quit
logdebug("SIGTERM received, setting clear_before_quit to True and exiting")
clear_before_quit = True clear_before_quit = True
sys.exit(exit_code) sys.exit(exit_code)
def berfore_quit(): def before_quit():
logdebug("before_quit called, clear_before_quit=%s" % clear_before_quit)
if clear_before_quit: if clear_before_quit:
clear() clear()
if pubsub is not None: if pubsub is not None:
pubsub.unsubscribe() pubsub.unsubscribe()
if __name__ == '__main__': if __name__ == '__main__':
atexit.register(berfore_quit) logger = Logger()
logdebug("Sys.argv: %s" % sys.argv)
atexit.register(before_quit)
signal.signal(signal.SIGTERM, sigterm_quit) signal.signal(signal.SIGTERM, sigterm_quit)
# init Logger
logger = Logger()
# init backend
backend = sys.argv[1] backend = sys.argv[1]
logdebug("Backend: %s" % backend)
if backend == "nftables": if backend == "nftables":
logger.logInfo('Using NFTables backend') logger.logInfo('Using NFTables backend')
tables = NFTables(chain_name, logger) tables = NFTables(chain_name, logger)
@ -412,16 +451,12 @@ if __name__ == '__main__':
logger.logInfo('Using IPTables backend') logger.logInfo('Using IPTables backend')
tables = IPTables(chain_name, logger) tables = IPTables(chain_name, logger)
# In case a previous session was killed without cleanup
clear() clear()
# Reinit MAILCOW chain
# Is called before threads start, no locking
logger.logInfo("Initializing mailcow netfilter chain") logger.logInfo("Initializing mailcow netfilter chain")
tables.initChainIPv4() tables.initChainIPv4()
tables.initChainIPv6() tables.initChainIPv6()
if os.getenv("DISABLE_NETFILTER_ISOLATION_RULE").lower() in ("y", "yes"): if os.getenv("DISABLE_NETFILTER_ISOLATION_RULE", "").lower() in ("y", "yes"):
logger.logInfo(f"Skipping {chain_name} isolation") logger.logInfo(f"Skipping {chain_name} isolation")
else: else:
logger.logInfo(f"Setting {chain_name} isolation") logger.logInfo(f"Setting {chain_name} isolation")
@ -432,23 +467,28 @@ if __name__ == '__main__':
try: try:
redis_slaveof_ip = os.getenv('REDIS_SLAVEOF_IP', '') redis_slaveof_ip = os.getenv('REDIS_SLAVEOF_IP', '')
redis_slaveof_port = os.getenv('REDIS_SLAVEOF_PORT', '') redis_slaveof_port = os.getenv('REDIS_SLAVEOF_PORT', '')
logdebug(
"Connecting redis (SLAVEOF_IP:%s, PORT:%s)" % (redis_slaveof_ip, redis_slaveof_port))
if "".__eq__(redis_slaveof_ip): if "".__eq__(redis_slaveof_ip):
r = redis.StrictRedis(host=os.getenv('IPV4_NETWORK', '172.22.1') + '.249', decode_responses=True, port=6379, db=0, password=os.environ['REDISPASS']) r = redis.StrictRedis(
host=os.getenv('IPV4_NETWORK', '172.22.1') + '.249', decode_responses=True, port=6379, db=0, password=os.environ['REDISPASS'])
else: else:
r = redis.StrictRedis(host=redis_slaveof_ip, decode_responses=True, port=redis_slaveof_port, db=0, password=os.environ['REDISPASS']) r = redis.StrictRedis(
host=redis_slaveof_ip, decode_responses=True, port=redis_slaveof_port, db=0, password=os.environ['REDISPASS'])
r.ping() r.ping()
pubsub = r.pubsub() pubsub = r.pubsub()
except Exception as ex: except Exception as ex:
print('%s - trying again in 3 seconds' % (ex)) logdebug(
'Redis connection failed: %s - trying again in 3 seconds' % (ex))
time.sleep(3) time.sleep(3)
else: else:
break break
logger.set_redis(r) logger.set_redis(r)
logdebug("Redis connection established, setting up F2B keys")
# rename fail2ban to netfilter
if r.exists('F2B_LOG'): if r.exists('F2B_LOG'):
logdebug("Renaming F2B_LOG to NETFILTER_LOG")
r.rename('F2B_LOG', 'NETFILTER_LOG') r.rename('F2B_LOG', 'NETFILTER_LOG')
# clear bans in redis
r.delete('F2B_ACTIVE_BANS') r.delete('F2B_ACTIVE_BANS')
r.delete('F2B_PERM_BANS') r.delete('F2B_PERM_BANS')
@ -499,4 +539,5 @@ if __name__ == '__main__':
while not quit_now: while not quit_now:
time.sleep(0.5) time.sleep(0.5)
logdebug("Exiting with code %s" % exit_code)
sys.exit(exit_code) sys.exit(exit_code)