def test_limit_to_two_records_per_two_seconds_with_initial_burst_of_three( self): f = RateLimitingFilter(rate=2, per=2, burst=3) result = self._filter_twenty_records_over_two_seconds(f) self.assertEqual(result.count(True), 4)
def test_rate_limit_messages_matching_substring(self): config = {'match': ['rate limited']} f = RateLimitingFilter(rate=1, per=1, burst=1, **config) mock_matching_record = Mock() mock_matching_record.msg = 'a rate limited test message' mock_non_matching_record = Mock() mock_non_matching_record.msg = 'a different test message' result = [] for _ in range(20): if f.filter(mock_matching_record): result.append( mock_matching_record.msg ) # Only 2 of these get logged as they match the substring if f.filter(mock_non_matching_record): result.append(mock_non_matching_record.msg ) # 20 of these get logged as they don't match self.mock_time.return_value += 0.1 self.assertEqual( len([m for m in result if 'a rate limited test message' in m]), 2) self.assertEqual(result.count('a different test message'), 20)
def test_rate_limit_messages_automatically(self): config = {'match': 'auto'} f = RateLimitingFilter(rate=1, per=1, burst=1, **config) result = [] for i in range(20): mock_varying_record = Mock() mock_varying_record.msg = 'a rate limited varying message: {varying}'.format( varying=i) mock_rate_limited_record = Mock() mock_rate_limited_record.msg = 'a completely different message' if f.filter(mock_varying_record): # Only 2 of these get logged as they are considered the same message, # even though they are not identical result.append(mock_varying_record.msg) if f.filter(mock_rate_limited_record): # Only 2 of these get logged as they are the all identical result.append(mock_rate_limited_record.msg) self.mock_time.return_value += 0.1 self.assertEqual( len([m for m in result if 'a rate limited varying message' in m]), 2) self.assertEqual( len([m for m in result if 'a completely different message' in m]), 2)
def init_logging(): """ init logging config :param debug: :return: """ base_logger = logging.getLogger("synch") debug = Settings.debug() if debug: base_logger.setLevel(logging.DEBUG) else: base_logger.setLevel(logging.INFO) fmt = logging.Formatter( fmt="%(asctime)s - %(name)s:%(lineno)d - %(levelname)s - %(message)s", datefmt="%Y-%m-%d %H:%M:%S", ) sh = logging.StreamHandler(sys.stdout) sh.setLevel(logging.DEBUG) sh.setFormatter(fmt) base_logger.addHandler(sh) mail = Settings.get("mail") if mail: rate_limit = RateLimitingFilter(per=60) sh = logging.handlers.SMTPHandler( mailhost=mail.get("mailhost"), fromaddr=mail.get("fromaddr"), toaddrs=mail.get("toaddrs"), subject=mail.get("subject"), credentials=(mail.get("user"), mail.get("password")), ) sh.setLevel(logging.ERROR) sh.setFormatter(fmt) sh.addFilter(rate_limit) base_logger.addHandler(sh)
def _setup_logging(self, config): log_config_file = config[u'log'][u'config_file'] self._logger.info(u'Logging configuration file: ' + log_config_file) try: logging.config.fileConfig(log_config_file) except Exception: exc_type, exc_value, exc_traceback = sys.exc_info() traceback.print_exception(exc_type, exc_value, exc_traceback, limit=2, file=sys.stderr) raise PanoptesConfigurationError( u'Could not instantiate logger with logging configuration provided in file "%s": (%s) %s' % (log_config_file, exc_type, exc_value)) # Create a filter to rate limit logs so that a misconfiguration or failure does not make the disk I/O go # beserk or fill up the disk space. We do this in code instead if configuration for two reasons: # - It enforces a filter on every handler, so no chance of messing them up in configuration # - We use fileConfig (nof dictConfig) to setup our logging and fileConfig does not support filter configuration throttle = RateLimitingFilter(rate=config[u'log'][u'rate'], per=config[u'log'][u'per'], burst=config[u'log'][u'burst']) # Apply the filter to all handlers. Note that this would be a shared filter across ALL logs generated by this # process and thus the rate/burst should be set appropriately high for handler in logging._handlerList: # _handlerList is a list of weakrefs, so the object returned has to be dereferenced handler().addFilter(throttle)
def test_log_exception(self): logger = logging.getLogger('test') handler = logging.StreamHandler() throttle = RateLimitingFilter(rate=1, per=1, burst=1) handler.addFilter(throttle) logger.addHandler(handler) try: logger.error('First') raise RuntimeError('Expected exception') except RuntimeError as e: logger.exception(e) # Should be throttled
def __init__(self, image_name, server_name, data_bind, container_cmd, host_only, fixed_tag=None, registry='docker.io', proxies=None): """Initialize the client.""" self.image_name = image_name self.server_name = server_name self.data_bind = data_bind self.container_cmd = container_cmd self.host_only = host_only self.fixed_tag = fixed_tag self.registry = registry self.proxies = proxies # TODO: plumb in registry self.logger = labslauncher.get_named_logger("DckrClnt") # throttle connection errors to once every 5 minutes spam = [ 'Could not create docker client', 'Failed to query docker client' ] self.logger.addFilter( RateLimitingFilter(rate=1, per=300, burst=1, match=spam)) self.logger.info("""Creating docker client with options: image name: {} server name: {} data bind: {} command: {} host only: {} fixed tag: {} proxies: {}""".format(image_name, server_name, data_bind, container_cmd, host_only, fixed_tag, proxies)) self._client = None self.total_size = None self.final_stats = None self.last_failure = "Unknown error" self.last_failure_type = None self.is_running() # sets up tag, status, and available # docker service heartbeat self.dheartbeat = QTimer() self.dheartbeat.setInterval(1000 * 5) # 5 seconds self.dheartbeat.start() self.dheartbeat.timeout.connect(self.is_running) # container status heartbeat self.cheartbeat = QTimer() self.cheartbeat.setInterval(1000 * 5) # 5 seconds self.cheartbeat.start() self.cheartbeat.timeout.connect(self.set_status)
def test_append_num_limited_records_to_message(self): filtered = [] f = RateLimitingFilter(rate=1, per=1, burst=4) for _ in range(30): mock_record = Mock() mock_record.msg = 'test message' if f.filter(mock_record): filtered.append(mock_record) self.mock_time.return_value += 0.1 self.assertEqual(len(filtered), 6) self.assertTrue( filtered[4].msg.endswith(os.linesep + '... 6 additional messages suppressed')) self.assertTrue( filtered[5].msg.endswith(os.linesep + '... 9 additional messages suppressed'))
def test_limit_to_no_records_per_second(self): f = RateLimitingFilter(rate=0, per=0, burst=0) result = self._filter_twenty_records_over_two_seconds(f) self.assertEqual(result.count(True), 0)
def test_limit_to_one_record_per_two_seconds(self): f = RateLimitingFilter(rate=1, per=2, burst=1) result = self._filter_twenty_records_over_two_seconds(f) self.assertEqual(result.count(True), 1)
import logging import time from ratelimitingfilter import RateLimitingFilter logger = logging.getLogger('substring_example') logger.setLevel(logging.DEBUG) # Create a console handler ch = logging.StreamHandler() ch.setLevel(logging.DEBUG) ch.setFormatter( logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')) logger.addHandler(ch) # Create a rate limiting filter and add it to the console handler. config = {'match': ['rate limited']} throttle = RateLimitingFilter(rate=1, per=1, burst=1, **config) ch.addFilter(throttle) for i in range(31): # Rate limiting will apply to this message because of the substring match logger.debug('a message that is rate limited') # Rate limiting will not apply to this message logger.debug('some message') time.sleep(0.1)
if not app.debug: credentials = None if app.config['MAIL_USERNAME'] or app.config['MAIL_PASSWORD']: credentials = (app.config['MAIL_USERNAME'], app.config['MAIL_PASSWORD']) mail_handler = SMTPHandler( (app.config['MAIL_SERVER'], app.config['MAIL_PORT']), app.config['MAIL_FROM'], app.config['ADMINS'], 'webfaf exception', credentials) mail_handler.setLevel(logging.ERROR) rate_limiter = RateLimitingFilter(app.config['THROTTLING_RATE'], app.config['THROTTLING_TIMEFRAME'], app.config['THROTTLING_BURST']) mail_handler.addFilter(rate_limiter) app.logger.addHandler(mail_handler) # pylint: disable=no-member @app.errorhandler(403) def forbidden(_) -> Tuple[str, int]: return flask.render_template("403.html"), 403 @app.errorhandler(404) def not_found(_) -> Tuple[str, int]: return flask.render_template("404.html"), 404
import logging import time from ratelimitingfilter import RateLimitingFilter logger = logging.getLogger('console_example') logger.setLevel(logging.DEBUG) # Create a console handler ch = logging.StreamHandler() ch.setLevel(logging.DEBUG) ch.setFormatter( logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')) logger.addHandler(ch) # Create a rate limiting filter and add it to the console handler. # We limit the throughput to 1 record per second, allowing a burst of 3. throttle = RateLimitingFilter(rate=1, per=1, burst=3) ch.addFilter(throttle) for i in range(31): # This attempts to log 31 messages in a little over 3 seconds. The messages are equally # spaced with 1/10 second between them. This allows the first 3 messages through in the # first second based on the burst, and then just 1 message in the 2nd, 3rd and 4th seconds, # based on the 1 per second rate, which totals 6. logger.debug('This is message {0}'.format(i)) time.sleep(0.1)
file_handler = RotatingFileHandler(logFile, mode='a', maxBytes=LOG_FILE_MAX_SIZE_MB * 1024 * 1024, backupCount=LOG_FILE_BACKUP_COUNT, encoding=None, delay=0) file_handler.setFormatter(log_formatter) file_handler.setLevel(logging.INFO) # Send email on critical errors. smtp_handler = SMTPHandler( mailhost=(EMAIL_HOST, EMAIL_PORT), fromaddr=EMAIL_FROM, toaddrs=EMAIL_TO, credentials=(EMAIL_USER, EMAIL_PASSWORD), subject=u"Anemio station: a critical error has occured.") smtp_handler.setLevel(logging.CRITICAL) ratelimit = RateLimitingFilter(rate=EMAIL_RATE, per=EMAIL_RATE_SECONDS, burst=EMAIL_RATE_BURST) smtp_handler.addFilter(ratelimit) logger = logging.getLogger('anemio') logger.setLevel(logging.INFO) logger.addHandler(file_handler) logger.addHandler(smtp_handler) radio_daemon = RadioDaemon(logger=logger) radio_daemon.run()
import logging.handlers import time from ratelimitingfilter import RateLimitingFilter logger = logging.getLogger('throttled_smtp_example') # Create an SMTPHandler smtp = logging.handlers.SMTPHandler(mailhost='relay.somehost.net', fromaddr='*****@*****.**', toaddrs='*****@*****.**', subject='An error has occurred') smtp.setLevel(logging.ERROR) # Create an instance of the RateLimitingFilter, and add it to the handler throttle = RateLimitingFilter() smtp.addFilter(throttle) # Create a formatter and set it on the handler formatter = logging.Formatter( '%(asctime)s - %(name)s - %(levelname)s - %(message)s') smtp.setFormatter(formatter) # Add the handler to the logger logger.addHandler(smtp) # Logged errors will now be restricted to 1 every 30 seconds while True: logger.error('An error message') time.sleep(2)