diff --git a/CHANGELOG.md b/CHANGELOG.md index 8f3ae5c68..8aa1194ae 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,12 @@ CHANGELOG in development -------------- +### General changes +- It's now configurable how often the bots are logging how much events they have sent, based on both the amount and time. (fixes #743) + +### Configuration +- Added `log_processed_messages_count` (500) and `log_processed_messages_seconds` (900) to defaults.conf. + ### Documentation - Dropped install scripts, see INSTALL.md for more detailed instructions and explanations diff --git a/NEWS.md b/NEWS.md index 54956a3bf..06ed5a3de 100644 --- a/NEWS.md +++ b/NEWS.md @@ -13,6 +13,12 @@ See the changelog for a full list of changes. in development -------------- +### Configuration +Two new fields have been added to `defaults.conf` which are expected by the bots: +- `"log_processed_messages_count": 500` and +- `'log_processed_messages_seconds": 900` +Configure them in your setup and optionally adapt the values to your needs. + ### Postgres databases Use the following statement carefully to upgrade your database. ```SQL diff --git a/intelmq/etc/defaults.conf b/intelmq/etc/defaults.conf index a47a96d2d..a44dfd3bb 100644 --- a/intelmq/etc/defaults.conf +++ b/intelmq/etc/defaults.conf @@ -16,6 +16,8 @@ "http_verify_cert": true, "https_proxy": null, "load_balance": false, + "log_processed_messages_count": 500, + "log_processed_messages_seconds": 900, "logging_handler": "file", "logging_level": "INFO", "logging_path": "/opt/intelmq/var/log/", diff --git a/intelmq/lib/bot.py b/intelmq/lib/bot.py index 47c7a1695..d74c3ddcc 100644 --- a/intelmq/lib/bot.py +++ b/intelmq/lib/bot.py @@ -30,6 +30,7 @@ class Bot(object): """ Not to be reset when initialized again on reload. """ __current_message = None __message_counter = 0 + __message_counter_start = None # Bot is capable of SIGHUP delaying sighup_delay = True @@ -335,8 +336,13 @@ def send_message(self, *messages): self.logger.debug("Sending message.") self.__message_counter += 1 - if self.__message_counter % 500 == 0: - self.logger.info("Processed %s messages.", self.__message_counter) + if not self.__message_counter_start: + self.__message_counter_start = datetime.datetime.now() + if self.__message_counter % self.parameters.log_processed_messages_count == 0 or \ + datetime.datetime.now() - self.__message_counter_start > self.parameters.log_processed_messages_seconds: + self.logger.info("Processed %d messages since last logging.", self.__message_counter) + self.__message_counter = 0 + self.__message_counter_start = datetime.datetime.now() raw_message = libmessage.MessageFactory.serialize(message) self.__destination_pipeline.send(raw_message) @@ -414,6 +420,8 @@ def __load_defaults_configuration(self): setattr(self.parameters, option, value) self.__log_configuration_parameter("defaults", option, value) + self.parameters.log_processed_messages_seconds = datetime.timedelta(seconds=self.parameters.log_processed_messages_seconds) + def __load_system_configuration(self): if os.path.exists(SYSTEM_CONF_FILE): self.__log_buffer.append(('warning', "system.conf is deprecated " diff --git a/intelmq/tests/lib/test_bot.py b/intelmq/tests/lib/test_bot.py index 900961eb1..6d269bf23 100644 --- a/intelmq/tests/lib/test_bot.py +++ b/intelmq/tests/lib/test_bot.py @@ -12,10 +12,7 @@ import intelmq.lib.pipeline as pipeline import intelmq.lib.utils as utils import intelmq.lib.test as test - - -with mock.patch('intelmq.lib.utils.load_configuration', new=test.mocked_config()): - from intelmq.tests.lib import test_parser_bot +from intelmq.tests.lib import test_parser_bot class TestBot(unittest.TestCase): diff --git a/intelmq/tests/lib/test_parser_bot.py b/intelmq/tests/lib/test_parser_bot.py index 76d58696b..6916fea14 100644 --- a/intelmq/tests/lib/test_parser_bot.py +++ b/intelmq/tests/lib/test_parser_bot.py @@ -1,5 +1,6 @@ # -*- coding: utf-8 -*- import base64 +import datetime import unittest import unittest.mock as mock @@ -48,7 +49,6 @@ 192.0.2.3,bllaa #ending line """ -RAW_SPLIT = RAW.strip().splitlines() EXAMPLE_REPO_1 = {"feed.url": "http://www.example.com/", "time.observation": "2015-08-11T13:03:40+00:00", @@ -63,6 +63,9 @@ 'raw': 'c291cmNlLmlwLGZvb2Jhcg0KMTkyLjAuMi4zLGJsbGFhDQo=' } +EXAMPLE_SHORT = EXAMPLE_REPORT.copy() +EXAMPLE_SHORT['raw'] = utils.base64_encode('\n'.join(RAW_SPLIT[:2] + [RAW_SPLIT[1]])) + class DummyParserBot(bot.ParserBot): """ @@ -141,6 +144,21 @@ def test_missing_raw(self): 'bug or misconfiguration in previous bots.', levelname='WARNING') + def test_processed_mesages_count(self): + self.sysconfig = {'log_processed_messages_count': 1} + self.input_message = EXAMPLE_SHORT + self.run_bot() + self.assertAnyLoglineEqual(message='Processed 1 messages since last logging.', + levelname='INFO') + + def test_processed_mesages_seconds(self): + self.sysconfig = {'log_processed_messages_count': 10, + 'log_processed_messages_seconds': datetime.timedelta(seconds=0)} + self.input_message = EXAMPLE_SHORT + self.run_bot() + self.assertAnyLoglineEqual(message='Processed 1 messages since last logging.', + levelname='INFO') + class TestDummyCSVParserBot(test.BotTestCase, unittest.TestCase): @classmethod