import logging import itertools import time from datetime import timedelta, datetime from celery import task from django.db.models import Q, F from django.db import transaction from django.conf import settings from django.utils import timezone from django.template.loader import get_template from django.core.mail import send_mass_mail, send_mail from constance import config as site_config import django_lcore import lcoreapi from ccvpn.common import parse_integer_list from lambdainst.models import User, VPNUser ROOT_URL = settings.ROOT_URL SITE_NAME = settings.TICKETS_SITE_NAME logger = logging.getLogger(__name__) @task(autoretry_for=(Exception,), default_retry_delay=60 * 60) def push_all_users(): count = 0 for u in User.objects.all(): # skip 'empty' accounts if u.vpnuser.expiration is None: continue logger.debug("pushing user #%d %r", user.id, user) django_lcore.sync_user(u.vpnuser, fail_silently=False) count += 1 logger.info("pushed %d users", count) @task(autoretry_for=(Exception,), max_retries=10, retry_backoff=True) def push_user(user_id): user = User.objects.get(id=user_id) logger.info("pushing user #%d %r", user.id, user) django_lcore.sync_user(user.vpnuser, fail_silently=False) @task def notify_vpn_auth_fails(): """ due to the high number of regular authentication fails, we'll start sending a periodic reminder to accounts with high rates. it could be a misconfigured client or a payment failure 3 years, >0 payments: 7 marked, 883 skipped 6 years, >0 payments: 11 marked, 1582 skipped 3 years, incl 0 paym: 9 marked, 3590 skipped 6 years, incl 0 paym: 14 marked, 6313 skipped [12m25s] """ logger.info("searching for recent openvpn auth failures") api = django_lcore.api from_email = settings.DEFAULT_FROM_EMAIL FETCH_EVENTS_PER_USER = 90 MIN_EXP = timezone.now() - timedelta(days=6 * 365) MIN_EVENTS = 5 # that threshold is automatically negative MAX_FAILS = 15 # that threshold is automatically positive MIN_DT_SINCE_LAST = timedelta(days=1) NOTIFY_EVERY = timedelta(days=180) # users notified recently should be ignored def find_fails_for_user(u): """ returns true if there are 'many' recent fails """ path = api.info["current_instance"] + "/users/" + u.username + "/auth-events/" try: r = api.get(path) except lcoreapi.APINotFoundError: return False assert r["object"] == "list", repr(r) items = list(itertools.islice(r.list_iter(), FETCH_EVENTS_PER_USER)) # split the dataset, errors are ignored fails = [i for i in items if i["auth_status"] == "fail"] ok = [i for i in items if i["auth_status"] == "ok"] # do we have enough failures if len(fails) == 0: return False if len(fails) < MIN_EVENTS: logger.debug( f"#{u.id} '{u.username}': too few fails ({len(fails)} < {MIN_EVENTS})" ) return False # are they recent dates = [e["event_date"] for e in fails] first = min(dates) last = max(dates) dt_fails = last - first dt_last_fail = datetime.utcnow() - last if dt_last_fail > MIN_DT_SINCE_LAST: logger.debug( f"#{u.id} '{u.username}': no recent enough failure ({dt_last_fail} ago > {MIN_DT_SINCE_LAST} ago)" ) return False # ~ end of checks. now we filter positive matches ~ # do we have only fails in the recent events? if len(fails) > MAX_FAILS and len(ok) == 0: logger.info(f"#{u.id} '{u.username}': {len(fails)} fails and 0 ok") return True # do we have many fails per hour? fails_per_hour = len(fails) / (dt_fails.total_seconds() / 3600.0) if fails_per_hour > 1: logger.info( f"#{u.id} '{u.username}': fail/hour is high ({fails_per_hour:.2f} > 1)" ) return True # otherwise there are some of both. let's check the ratio fail_ratio = len(fails) / len(ok) if fail_ratio > 1: # more fails than oks logger.info( f"#{u.id} '{u.username}': fail ratio is high ({fail_ratio:.2f} > 1)" ) return True else: logger.debug( f"#{u.id} '{u.username}': fail ratio is low ({fail_ratio:.2f} < 1)" ) return False def notify_user(user): if user.vpnuser.notify_vpn_auth_fail is not True: logger.warning("this user should not be sent a notice") return ctx = dict(user=user, url=ROOT_URL) text = get_template("lambdainst/mail_vpn_auth_fails.txt").render(ctx) send_mail("CCrypto VPN Authentication Errors", text, from_email, [user.email]) logger.debug("sending vpn auth fails notify to %s", user.email) user.vpnuser.last_vpn_auth_fail_notice = timezone.now() user.vpnuser.save() def examine_users(): skipped = 0 marked = 0 users = User.objects # skip accounts that opt out of this users = users.exclude(vpnuser__notify_vpn_auth_fail=False) # skip accounts with no email address users = users.exclude(email__exact="") # skip accounts where exp was never set users = users.exclude(vpnuser__expiration=None) # skip accounts that expired a long time ago users = users.exclude(vpnuser__expiration__lt=MIN_EXP) # skip accounts that already received a notice recently users = users.exclude( vpnuser__last_vpn_auth_fail_notice__gt=timezone.now() - NOTIFY_EVERY ) # require at least one payment # users = users.filter(payment__status='confirmed').annotate(Count('payment')).filter(payment__count__gt=0) users = users.order_by("id") for u in users: if find_fails_for_user(u): notify_user(u) marked += 1 else: skipped += 1 time.sleep(0.100) logger.debug("auth fails: notified %d, reviewed %d", marked, skipped) examine_users() @task def notify_account_expiration(): """ Notify users near the end of their subscription """ from_email = settings.DEFAULT_FROM_EMAIL for v in parse_integer_list(site_config.NOTIFY_DAYS_BEFORE): emails = [] users = list(get_next_expirations(v)) logger.info("sending -%d day notification to %d users", v, len(users)) with transaction.atomic(): for u in users: # Ignore users with active subscriptions # They will get notified only if it gets cancelled (payments # processors will cancel after a few failed payments) if u.get_subscription(): continue ctx = dict( site_name=SITE_NAME, user=u.user, exp=u.expiration, url=ROOT_URL ) text = get_template("lambdainst/mail_expire_soon.txt").render(ctx) emails.append( ("CCrypto VPN Expiration", text, from_email, [u.user.email]) ) logger.debug("sending -%d days notify to %s" % (v, u.user.email)) u.last_expiry_notice = timezone.now() u.save() send_mass_mail(emails) def get_next_expirations(days=3): """ Gets users whose subscription will expire in some days """ limit_date = timezone.now() + timedelta(days=days) users = VPNUser.objects.exclude(user__email__exact="") users = users.filter(expiration__gt=timezone.now()) # Not expired users = users.filter(expiration__lt=limit_date) # Expire in a few days # Make sure we dont send the notice twice users = users.filter( Q(last_expiry_notice__isnull=True) | Q(expiration__gt=F("last_expiry_notice") + timedelta(days=days)) ) return users