Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Logcollector integration tests T0: reconnect_time option #1312

Merged
merged 11 commits into from
May 12, 2021
50 changes: 41 additions & 9 deletions deps/wazuh_testing/wazuh_testing/logcollector.py
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand All @@ -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.
Expand All @@ -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.
Expand All @@ -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.
Expand All @@ -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.
Expand All @@ -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.
Expand All @@ -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.
Expand All @@ -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.
Expand Down Expand Up @@ -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:
Expand All @@ -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:
Expand Down
32 changes: 31 additions & 1 deletion deps/wazuh_testing/wazuh_testing/tools/services.py
Original file line number Diff line number Diff line change
Expand Up @@ -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")
Expand Down Expand Up @@ -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)

29 changes: 29 additions & 0 deletions docs/tests/integration/test_logcollector/test_reconnect_time.md
Original file line number Diff line number Diff line change
@@ -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

This file was deleted.

Original file line number Diff line number Diff line change
@@ -0,0 +1,3 @@
## Code documentation

::: tests.integration.test_vulnerability_detector.test_feeds.archlinux.test_extra_tags_archlinux_feed

This file was deleted.

Original file line number Diff line number Diff line change
@@ -0,0 +1,3 @@
## Code documentation

::: tests.integration.test_vulnerability_detector.test_feeds.archlinux.test_missing_tags_archlinux_feed
1 change: 1 addition & 0 deletions mkdocs.yml
Original file line number Diff line number Diff line change
Expand Up @@ -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:
Expand Down
Original file line number Diff line number Diff line change
@@ -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
Original file line number Diff line number Diff line change
@@ -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()