Merge pull request #1312 from wazuh/1251_logcollector_reconnect_time

Logcollector integration tests T0: reconnect_time option

deps/wazuh_testing/wazuh_testing/logcollector.py

@@ -37,7 +37,6 @@ def callback_monitoring_command(log_format, command):
     Args:
         log_format (str): Log format of the command monitoring (full_command or command).
         command (str): Monitored command.
-        prefix (str): Daemon that generates the error log.
 
     Returns:
         callable: callback to detect this event.
@@ -53,7 +52,6 @@ def callback_monitoring_djb_multilog(program_name, multilog_file):
     Args:
         program_name (str): Program name of multilog file.
         multilog_file (str): Multilog file name.
-        prefix (str): Daemon that generates the error log.
 
     Returns:
         callable: callback to detect this event.
@@ -67,7 +65,6 @@ def callback_command_alias_output(alias):
 
     Args:
         alias (str): Command alias.
-        prefix (str): Daemon that generates the error log.
 
     Returns:
         callable: callback to detect this event.
@@ -81,7 +78,6 @@ def callback_eventchannel_bad_format(event_location):
 
     Args:
         event_location (str): Eventchannel location.
-        prefix (str): Daemon that generates the error log.
 
     Returns:
         callable: callback to detect this event.
@@ -96,7 +92,6 @@ def callback_socket_target(location, socket_name):
     Args:
         location (str): Name with the analyzed file.
         socket_name (str): Socket name.
-        prefix (str): Daemon that generates the error log.
 
     Returns:
         callable: callback to detect this event.
@@ -111,7 +106,6 @@ def callback_socket_not_defined(location, socket_name):
     Args:
         location (str): Name with the analyzed file.
         socket_name (str): Socket name.
-        prefix (str): Daemon that generates the error log.
 
     Returns:
         callable: callback to detect this event.
@@ -126,7 +120,6 @@ def callback_log_target_not_found(location, socket_name):
     Args:
         location (str): Name with the analyzed file.
         socket_name (str): Socket name.
-        prefix (str): Daemon that generates the error log.
 
     Returns:
         callable: callback to detect this event.
@@ -141,7 +134,6 @@ def callback_invalid_reconnection_time(severity='WARNING', default_value='5'):
     Args:
         severity (str): Severity of the error (WARNING, ERROR or CRITICAL)
         default_value (int): Default value used instead of specified reconnection time.
-        prefix (str): Daemon that generates the error log.
 
     Returns:
         callable: callback to detect this event.
@@ -236,7 +228,6 @@ def callback_running_command(log_format, command, escape=False):
     Args:
         log_format (str): Log format of the command monitoring (full_command or command).
         command (str): Command to be monitored.
-        prefix (str): Daemon that generates the log.
         escape (bool): Flag to escape special characters in the pattern.
 
     Returns:
@@ -247,6 +238,47 @@ def callback_running_command(log_format, command, escape=False):
     return monitoring.make_callback(pattern=msg, prefix=prefix, escape=escape)
 
 
+def callback_event_log_service_down(location, severity='WARNING'):
+    """Create a callback to detect if eventlog service is down.
+
+    Args:
+        location (str): Event channel.
+        severity (str): Severity of the error (WARNING, ERROR or CRITICAL).
+
+    Returns:
+        callable: callback to detect this event.
+    """
+    log_format_message = f"{severity}: The eventlog service is down. Unable to collect logs from '{location}' channel."
+    return monitoring.make_callback(pattern=log_format_message, prefix=monitoring.AGENT_DETECTOR_PREFIX)
+
+
+def callback_trying_to_reconnect(location, reconnect_time):
+    """Create a callback to detect if `wazuh-agentd` is trying to reconnect to specified channel.
+
+    Args:
+        location (str): Event log channel.
+        reconnect_time (str): Reconnect time.
+
+    Returns:
+        callable: callback to detect this event.
+    """
+    log_format_message = f"DEBUG: Trying to reconnect {location} channel in {reconnect_time} seconds."
+    return monitoring.make_callback(pattern=log_format_message, prefix=monitoring.AGENT_DETECTOR_PREFIX)
+
+
+def callback_reconnect_eventchannel(location):
+    """Create a callback to detect if specified channel has been reconnected successfully.
+
+    Args:
+        location (str): Location channel.
+
+    Returns:
+        callable: callback to detect this event.
+    """
+    log_format_message = f"INFO: '{location}' channel has been reconnected succesfully."
+    return monitoring.make_callback(pattern=log_format_message, prefix=monitoring.AGENT_DETECTOR_PREFIX)
+
+
 def callback_match_pattern_file(file_pattern, file):
     """Create a callback to detect if logcollector is monitoring a file with wildcard.
     Args:

deps/wazuh_testing/wazuh_testing/tools/services.py

@@ -204,7 +204,7 @@ def check_daemon_status(daemon=None, running=True, timeout=10, extra_sockets=Non
                 # Finish main for loop if both daemon and socket checks are ok
                 break
 
-        time.sleep(timeout/3)
+        time.sleep(timeout / 3)
     else:
         raise TimeoutError(f"{'wazuh-service' if daemon is None else daemon} "
                            f"{'is not' if running else 'is'} running")
@@ -234,3 +234,33 @@ def check_if_process_is_running(process_name):
         pass
 
     return is_running
+
+
+def control_event_log_service(control):
+    """Control Windows event log service.
+
+    Args:
+        control (str): Start or Stop.
+
+    Raises:
+        ValueError: If the event log channel does not start/stop correctly.
+    """
+    for _ in range(10):
+        control_sc = 'disabled' if control == 'stop' else 'auto'
+
+        command = subprocess.run(f'sc config eventlog start= {control_sc}', stderr=subprocess.PIPE)
+        result = command.returncode
+        if result != 0:
+            raise ValueError(f'Event log service did not stop correctly')
+
+        command = subprocess.run(f"net {control} eventlog /y", stderr=subprocess.PIPE)
+        result = command.returncode
+        if result == 0:
+            break
+        else:
+            time.sleep(1)
+    else:
+        raise ValueError(f"Event log service did not stop correctly")
+
+    time.sleep(1)
+

docs/tests/integration/test_logcollector/test_reconnect_time.md

@@ -0,0 +1,29 @@
+# Test reconnect time
+
+## Overview 
+
+Check if Wazuh Windows agent reconnect to Windows event log channels using the specified `reconnect_time` 
+option. These tests will disable Windows event log service and check that expected warning debugs are generated.
+Then, system time is changed using `reconnect_time` value. After that, Wazuh should generate reconnect time debug log.
+
+## Objective
+
+- To confirm `reconnect_time` option works correctly.
+- To confirm that Wazuh detect when Windows event log service is up.
+- To confirm that Wazuh detect when Windows event log service is down.
+- To confirm that Wazuh can reconnect to Windows event log service. 
+
+## General info
+
+|Tier | Number of tests | Time spent |
+|:--:|:--:|:--:|
+| 0 | 9 | 1m4s |
+
+## Expected behavior
+
+- Fail if Wazuh agent does not reconnect to Windows event log at the time specified by `reconnect_time`.
+- Fail if Wazuh agent does not generate a debug message when the Windows event log is down.
+
+## Code documentation
+
+::: tests.integration.test_logcollector.test_reconnect_time.test_reconnect_time

docs/tests/integration/test_vulnerability_detector/test_feeds/archlinux/test_extra_tags_archlinux_feed.md

@@ -0,0 +1,3 @@
+## Code documentation
+
+::: tests.integration.test_vulnerability_detector.test_feeds.archlinux.test_extra_tags_archlinux_feed

docs/tests/integration/test_vulnerability_detector/test_feeds/archlinux/test_missing_tags_archlinux_feed.md

@@ -0,0 +1,3 @@
+## Code documentation
+
+::: tests.integration.test_vulnerability_detector.test_feeds.archlinux.test_missing_tags_archlinux_feed

mkdocs.yml

@@ -454,6 +454,7 @@ nav:
                 - Overview: tests/integration/test_logcollector/test_command_monitoring/index.md
                 - Test command execution: tests/integration/test_logcollector/test_command_monitoring/test_command_execution.md
                 - Test command execution freq: tests/integration/test_logcollector/test_command_monitoring/test_command_execution_freq.md
+            - Test reconnect time: tests/integration/test_logcollector/test_reconnect_time.md
             - Test keep running:
                 - Test keep running: tests/integration/test_logcollector/test_keep_running/test_keep_running.md
             - Test location:

tests/integration/test_logcollector/test_reconnect_time/data/wazuh_reconnect_time.yaml

@@ -0,0 +1,13 @@
+- tags:
+  - test_reconnect_time
+  apply_to_modules:
+  - test_reconnect_time
+  sections:
+  - section: localfile
+    elements:
+    - location:
+        value: LOCATION
+    -  log_format:
+         value: LOG_FORMAT
+    -  reconnect_time:
+         value: RECONNECT_TIME

tests/integration/test_logcollector/test_reconnect_time/test_reconnect_time.py

@@ -0,0 +1,120 @@
+# Copyright (C) 2015-2021, Wazuh Inc.
+# Created by Wazuh, Inc. <[email protected]>.
+# This program is free software; you can redistribute it and/or modify it under the terms of GPLv2
+import os
+import pytest
+from datetime import timedelta, datetime
+import time
+import sys
+from wazuh_testing.tools.configuration import load_wazuh_configurations
+from wazuh_testing import global_parameters, logger
+from wazuh_testing.tools.time import TimeMachine
+import wazuh_testing.logcollector as logcollector
+from wazuh_testing.tools.time import time_to_seconds
+import wazuh_testing.tools.services as services
+
+pytestmark = [pytest.mark.win32, pytest.mark.tier(level=0)]
+
+local_internal_options = {
+    'logcollector.remote_commands': 1,
+    'logcollector.debug': 2,
+    'monitord.rotate_log': 0
+}
+
+# Configuration
+test_data_path = os.path.join(os.path.dirname(os.path.realpath(__file__)), 'data')
+configurations_path = os.path.join(test_data_path, 'wazuh_reconnect_time.yaml')
+
+timeout_callback_reconnect_time = 30
+
+parameters = [
+    {'LOCATION': 'Application', 'LOG_FORMAT': 'eventchannel', 'RECONNECT_TIME': '5s'},
+    {'LOCATION': 'Security', 'LOG_FORMAT': 'eventchannel', 'RECONNECT_TIME': '5s'},
+    {'LOCATION': 'System', 'LOG_FORMAT': 'eventchannel', 'RECONNECT_TIME': '5s'},
+    {'LOCATION': 'Application', 'LOG_FORMAT': 'eventchannel', 'RECONNECT_TIME': '40m'},
+    {'LOCATION': 'Security', 'LOG_FORMAT': 'eventchannel', 'RECONNECT_TIME': '40m'},
+    {'LOCATION': 'System', 'LOG_FORMAT': 'eventchannel', 'RECONNECT_TIME': '40m'},
+    {'LOCATION': 'Application', 'LOG_FORMAT': 'eventchannel', 'RECONNECT_TIME': '20h'},
+    {'LOCATION': 'Security', 'LOG_FORMAT': 'eventchannel', 'RECONNECT_TIME': '20h'},
+    {'LOCATION': 'System', 'LOG_FORMAT': 'eventchannel', 'RECONNECT_TIME': '20h'},
+
+]
+metadata = [
+    {'location': 'Application', 'log_format': 'eventchannel', 'reconnect_time': '5s'},
+    {'location': 'Security', 'log_format': 'eventchannel', 'reconnect_time': '5s'},
+    {'location': 'System', 'log_format': 'eventchannel', 'reconnect_time': '5s'},
+    {'location': 'Application', 'log_format': 'eventchannel', 'reconnect_time': '40m'},
+    {'location': 'Security', 'log_format': 'eventchannel', 'reconnect_time': '40m'},
+    {'location': 'System', 'log_format': 'eventchannel', 'reconnect_time': '40m'},
+    {'location': 'Application', 'log_format': 'eventchannel', 'reconnect_time': '20h'},
+    {'location': 'Security', 'log_format': 'eventchannel', 'reconnect_time': '20h'},
+    {'location': 'System', 'log_format': 'eventchannel', 'reconnect_time': '20h'},
+]
+configurations = load_wazuh_configurations(configurations_path, __name__,
+                                           params=parameters,
+                                           metadata=metadata)
+configuration_ids = [f"{x['LOCATION'], x['LOG_FORMAT'], x['RECONNECT_TIME']}" for x in parameters]
+
+
+@pytest.fixture(scope="module", params=configurations, ids=configuration_ids)
+def get_configuration(request):
+    """Get configurations from the module."""
+    return request.param
+
+
+@pytest.fixture(scope="module")
+def get_local_internal_options():
+    """Get configurations from the module."""
+    return local_internal_options
+
+
+def test_reconnect_time(get_local_internal_options, configure_local_internal_options, get_configuration,
+                        configure_environment, restart_logcollector):
+    """Check if reconnect_time value works properly
+
+    Ensure correspond debug logs are generated when Windows event log service stop. Also, when event log service is
+    restarted, `wazuh-agent` should reconnect to it using reconnect_time value.
+    """
+
+    config = get_configuration['metadata']
+
+    if time_to_seconds(config['reconnect_time']) >= timeout_callback_reconnect_time:
+        pytest.xfail("Expected fail: https://github.com/wazuh/wazuh/issues/8580")
+
+    log_callback = logcollector.callback_eventchannel_analyzing(config['location'])
+    wazuh_log_monitor.start(timeout=global_parameters.default_timeout, callback=log_callback,
+                            error_message=logcollector.GENERIC_CALLBACK_ERROR_ANALYZING_EVENTCHANNEL)
+
+    services.control_event_log_service('stop')
+
+    log_callback = logcollector.callback_event_log_service_down(config['location'])
+    wazuh_log_monitor.start(timeout=30, callback=log_callback,
+                            error_message=logcollector.GENERIC_CALLBACK_ERROR_ANALYZING_EVENTCHANNEL)
+
+    log_callback = logcollector.callback_trying_to_reconnect(config['location'],
+                                                             time_to_seconds(config['reconnect_time']))
+    wazuh_log_monitor.start(timeout=30, callback=log_callback,
+                            error_message=logcollector.GENERIC_CALLBACK_ERROR_ANALYZING_EVENTCHANNEL)
+
+    services.control_event_log_service('start')
+
+    time.sleep(1)
+
+    if time_to_seconds(config['reconnect_time']) >= timeout_callback_reconnect_time:
+        before = str(datetime.now())
+        seconds_to_travel = time_to_seconds(config['reconnect_time']) / 2
+        TimeMachine.travel_to_future(timedelta(seconds=seconds_to_travel))
+        logger.debug(f"Changing the system clock from {before} to {datetime.now()}")
+
+    log_callback = logcollector.callback_reconnect_eventchannel(config['location'])
+
+    before = str(datetime.now())
+
+    if time_to_seconds(config['reconnect_time']) >= timeout_callback_reconnect_time:
+        TimeMachine.travel_to_future(timedelta(seconds=(seconds_to_travel)))
+        logger.debug(f"Changing the system clock from {before} to {datetime.now()}")
+
+    wazuh_log_monitor.start(timeout=30, callback=log_callback,
+                            error_message=logcollector.GENERIC_CALLBACK_ERROR_COMMAND_MONITORING)
+
+    TimeMachine.time_rollback()