How to log when connections drop.

fuvm.py

"""usage 
python fuvm.py <external canary URL>
"""
import time
import socket
import requests
import sys
import logging

class CustomFormatter(logging.Formatter):

    grey = "\x1b[38;20m"
    yellow = "\x1b[33;20m"
    red = "\x1b[31;20m"
    bold_red = "\x1b[31;1m"
    reset = "\x1b[0m"
    format = "%(asctime)s - %(name)s - %(levelname)s - %(message)s (%(filename)s:%(lineno)d)"

    FORMATS = {
        logging.DEBUG: grey + format + reset,
        logging.INFO: grey + format + reset,
        logging.WARNING: yellow + format + reset,
        logging.ERROR: red + format + reset,
        logging.CRITICAL: bold_red + format + reset
    }

    def format(self, record):
        log_fmt = self.FORMATS.get(record.levelno)
        formatter = logging.Formatter(log_fmt)
        return formatter.format(record)

target_url = sys.argv[1]

logger = logging.getLogger('fuvm')
logger.setLevel(logging.DEBUG)

# create console handler with a higher log level
ch = logging.StreamHandler()
ch.setFormatter(CustomFormatter())

logger.addHandler(ch)


def tick():
    try:
        r = requests.get(target_url, timeout=2)
        return r.status_code==200
    except requests.exceptions.RequestException as err:
        return False

base_strikes = 3
last_seen = time.time()
assert tick(), f"Tick should really work the first time; had URL {target_url}"

# Outerloop, runs forever
while True:
    strikes = base_strikes
    # Innerloop, when things are good
    while strikes:
        if tick():
            time.sleep(1)
            if strikes != base_strikes:
                logging.debug(f"Recovered Tick with {strikes} remaining, resetting")
                strikes = base_strikes
            last_seen = time.time()
        else:
            logging.warn(f'Failed Tick: {strikes} remaining')
            strikes -=1
    # Waiting Loop; connection recovery
    waiting_time = time.time()
    while not tick():
        time.sleep(1)

    warning.critical(f"Lost connection for {time.time()-last_seen} seconds, spent {time.time() - waiting_time} for reconnection")