From d2e952a903be0c4c3973e6c931dd925db4f31be4 Mon Sep 17 00:00:00 2001 From: Sebastian Wagner Date: Wed, 23 Apr 2025 23:37:44 +0200 Subject: [PATCH] wip: ctl: fix logging level filtering fixes https://github.com/certtools/intelmq/issues/2596 --- CHANGELOG.md | 1 + intelmq/bin/intelmqctl.py | 7 +++-- intelmq/tests/assets/test-bot.log | 37 +++++++++++++++++++++++ intelmq/tests/assets/test-bot.log.license | 2 ++ intelmq/tests/bin/test_intelmqctl.py | 23 ++++++++++++++ 5 files changed, 67 insertions(+), 3 deletions(-) create mode 100644 intelmq/tests/assets/test-bot.log create mode 100644 intelmq/tests/assets/test-bot.log.license diff --git a/CHANGELOG.md b/CHANGELOG.md index f4f4cada70..e88bde251e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -64,6 +64,7 @@ Please refer to the [NEWS](NEWS.md) for a list of changes which have an affect o - `intelmq.bin.intelmq_psql_initdb`: Use `JSONB` type by default, Postgres supports it since version 9 (PR#2597 by Sebastian Wagner). - `intelmq.bin.rewrite_config_files`: Removed obsolete JSON configuration file rewriter (PR#2613 by Sebastian Wagner). - `intelmq/lib/bot_debugger.py`: Fix overwriting the runtime logging level by command line parameter (PR#2603 by Sebastian Wagner, fixes #2563). +- `intelmq.bin.intelmqctl`: Fix bot log level filtering (PR#2607 by Sebastian Wagner, fixes #2596). ### Contrib diff --git a/intelmq/bin/intelmqctl.py b/intelmq/bin/intelmqctl.py index 91a0ec9420..80cce887b4 100644 --- a/intelmq/bin/intelmqctl.py +++ b/intelmq/bin/intelmqctl.py @@ -771,7 +771,8 @@ def clear_queue(self, queue): self._logger.exception("Error while clearing queue %s.", queue) return 1, 'error' - def read_bot_log(self, bot_id, log_level, number_of_lines): + def read_bot_log(self, bot_id: str, log_level: str, number_of_lines: int): + """ Read logs of a bot filtered by logging level """ if self._parameters.logging_handler == 'file': bot_log_path = os.path.join(self._parameters.logging_path, bot_id + '.log') @@ -799,13 +800,13 @@ def read_bot_log(self, bot_id, log_level, number_of_lines): if self._parameters.logging_handler == 'syslog': log_message = utils.parse_logline(line, regex=utils.SYSLOG_REGEX) - if type(log_message) is not dict: + if not isinstance(log_message, dict): if self._parameters.logging_handler == 'file': message_overflow = '\n'.join([line, message_overflow]) continue if log_message['bot_id'] != bot_id: continue - if LogLevel[log_message['log_level']].value > LogLevel[log_level].value: + if LogLevel[log_message['log_level']].value < LogLevel[log_level].value: continue if message_overflow: diff --git a/intelmq/tests/assets/test-bot.log b/intelmq/tests/assets/test-bot.log new file mode 100644 index 0000000000..9a4b4579c2 --- /dev/null +++ b/intelmq/tests/assets/test-bot.log @@ -0,0 +1,37 @@ +2025-04-23 23:17:52,212 - test-bot - INFO - ASNLookupExpertBot initialized with id asn-expert and intelmq 3.4.1.alpha1 and python 3.13.2 (main, Feb 05 2025, 09:57:44) [GCC] as process 257689. Standalone mode: True. +2025-04-23 23:17:52,212 - test-bot - DEBUG - Library path: '/home/sebastianw/dev/intelmq/intelmq/lib/bot.py'. +2025-04-23 23:17:52,212 - test-bot - DEBUG - Loading runtime configuration from '/etc/intelmq/runtime.yaml'. +2025-04-23 23:17:52,212 - test-bot - DEBUG - Defaults configuration: parameter 'autoupdate_cached_database' loaded with value False. +2025-04-23 23:17:52,212 - test-bot - DEBUG - Defaults configuration: parameter 'destination_pipeline_broker' loaded with value 'redis'. +2025-04-23 23:17:52,212 - test-bot - DEBUG - Defaults configuration: parameter 'process_manager' loaded with value 'intelmq'. +2025-04-23 23:17:52,212 - test-bot - DEBUG - Defaults configuration: parameter 'source_pipeline_broker' loaded with value 'redis'. +2025-04-23 23:17:52,212 - test-bot - DEBUG - Defaults configuration: parameter 'ssl_ca_certificate' loaded with value None. +2025-04-23 23:17:52,212 - test-bot - DEBUG - Defaults configuration: parameter 'statistics_database' loaded with value 3. +2025-04-23 23:17:52,212 - test-bot - DEBUG - Defaults configuration: parameter 'statistics_host' loaded with value '127.0.0.1'. +2025-04-23 23:17:52,212 - test-bot - DEBUG - Defaults configuration: parameter 'statistics_password' loaded with value 'HIDDEN'. +2025-04-23 23:17:52,212 - test-bot - DEBUG - Defaults configuration: parameter 'statistics_port' loaded with value 6379. +2025-04-23 23:17:52,212 - test-bot - DEBUG - System configuration: parameter 'module' loaded with value 'intelmq.bots.experts.asn_lookup.expert'. +2025-04-23 23:17:52,212 - test-bot - DEBUG - Runtime configuration: parameter 'database' loaded with value '/etc/resolv.conf'. +2025-04-23 23:17:52,212 - test-bot - DEBUG - Runtime configuration: parameter 'autoupdate_cached_database' loaded with value True. +2025-04-23 23:17:52,212 - test-bot - DEBUG - Environment configuration: parameter 'paths_no_opt' loaded with value 1. +2025-04-23 23:17:52,212 - test-bot - INFO - Bot is starting. +2025-04-23 23:17:52,212 - test-bot - DEBUG - Loading Harmonization configuration from '/etc/intelmq/harmonization.conf'. +2025-04-23 23:17:52,239 - test-bot - INFO - Loading source pipeline and queue 'asn-expert-queue'. +2025-04-23 23:17:52,240 - test-bot - INFO - Connected to source queue. +2025-04-23 23:17:52,240 - test-bot - WARNING - Something is abnormal. +2025-04-23 23:17:52,240 - test-bot - INFO - No destination queues to load. +2025-04-23 23:17:52,240 - test-bot - ERROR - Bot initialization failed. +Traceback (most recent call last): + File "/home/sebastianw/dev/intelmq/intelmq/lib/bot.py", line 241, in __init__ + self.init() + ~~~~~~~~~^^ + File "/home/sebastianw/dev/intelmq/intelmq/bots/experts/asn_lookup/expert.py", line 37, in init + self._database = pyasn.pyasn(self.database) + ~~~~~~~~~~~^^^^^^^^^^^^^^^ + File "/usr/lib64/python3.13/site-packages/pyasn/__init__.py", line 71, in __init__ + self._records = self.radix.load_ipasndb(ipasn_file, "") + ~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^ +RuntimeError: Error while parsing/adding IPASN database (record: 1)! +2025-04-23 23:17:52,241 - test-bot - DEBUG - Disconnected from source pipeline. +2025-04-23 23:17:52,241 - test-bot - INFO - Bot stopped. +2025-04-23 23:17:52,241 - test-bot - INFO - Bot stopped. diff --git a/intelmq/tests/assets/test-bot.log.license b/intelmq/tests/assets/test-bot.log.license new file mode 100644 index 0000000000..8c20de533c --- /dev/null +++ b/intelmq/tests/assets/test-bot.log.license @@ -0,0 +1,2 @@ +SPDX-FileCopyrightText: 2025 Institute for Common Good Technology +SPDX-License-Identifier: AGPL-3.0-or-later diff --git a/intelmq/tests/bin/test_intelmqctl.py b/intelmq/tests/bin/test_intelmqctl.py index 88ef46a71c..fa5f36f864 100644 --- a/intelmq/tests/bin/test_intelmqctl.py +++ b/intelmq/tests/bin/test_intelmqctl.py @@ -7,6 +7,7 @@ import unittest from tempfile import TemporaryDirectory from unittest import mock +from pathlib import Path from pkg_resources import resource_filename @@ -137,6 +138,28 @@ def test_check_imports_real_bot_module(self): import_mock.assert_called_once_with("mocked-module") + def test_intelmqctl_log(self): + path = Path(__file__).absolute().parent / '../assets/' + self.intelmqctl._parameters.logging_path = path + retval, error_log = self.intelmqctl.read_bot_log('test-bot', 'ERROR', 10) + assert retval == 0 and len(error_log) == 1 + assert error_log[0]['extended_message'].startswith('Traceback') + del error_log[0]['extended_message'] + assert error_log[0] == {'date': '2025-04-23T23:17:52.240000', + 'bot_id': 'test-bot', 'thread_id': None, 'log_level': 'ERROR', + 'message': 'Bot initialization failed.'} + for level, allowed_levels, number_messages in ( + ('DEBUG', ('DEBUG', 'INFO', 'WARNING', 'ERROR'), 26), + ('INFO', ('INFO', 'WARNING', 'ERROR'), 9), + ('WARNING', ('WARNING', 'ERROR'), 2), + ('ERROR', ('ERROR', ), 1), + ('CRITICAL', ('CRITICAL', ), 0), + ): + retval, log_messages = self.intelmqctl.read_bot_log('test-bot', level, 30) + assert retval == 0 and len(log_messages) == number_messages + for log_message in log_messages: + assert log_message['log_level'] in allowed_levels + if __name__ == '__main__': # pragma: nocover unittest.main()