During the testing in Release 4.7.3 - RC 1 - System tests, an error has been encountered in the one_manager_agent environment, specifically in this test: test_fim/test_synchronization/test_synchronization.py::test_synchronization[testdir1-delete-wazuh-agent1].
The test was executed in a Ubuntu 22.04.2 LTS T3.Large 30GB SSD instance, provided by the devops team.
Current behavior
Error details
```
folder_path = "'/testdir1/testdir1.txt'", case = 'delete', host = 'wazuh-agent1'
@pytest.mark.parametrize('host', ['wazuh-agent1', 'wazuh-manager'])
@pytest.mark.parametrize('case', ['add', 'modify', 'delete'])
@pytest.mark.parametrize('folder_path', ['testdir1'])
def test_synchronization(folder_path, case, host):
'''
Description: The test will monitor a directory and apply changes when agent/manager is stopped.
Finally, it will verify that the FIM 'Synchronization' event is generated
in agent and manager side.
wazuh_min_version: 4.2.0
parameters:
- folder_path:
type: str
brief: Name of the folder that will be created in the test.
- case:
type: str
brief: Name of the test case that will be created in the test.
- host:
type: str
brief: Name of the endpoint that will be use in the test.
assertions:
- Verify that FIM sync events are generated correctly on the manager and agent sides.
input_description: Different test cases are included with Pytest parametrize.
The test cases are: add, modify and delete files.
expected_output:
- Different test cases are contained in external YAML file
(agent_initializing_synchronization.yml and manager_initializing_synchronization.yaml)
tags:
- fim_basic_usage
- scheduled
'''
message_path = messages_path[3]
# Clear logs, create folder to monitored and restart the service
create_folder_file(host_manager, folder_path)
host_manager.control_service(host='wazuh-agent1', service='wazuh', state="restarted")
# Check that the manager contains data to monitor
try:
HostMonitor(inventory_path=inventory_path,
messages_path=messages_path[0],
tmp_path=tmp_path).run()
except Exception:
host_manager.run_command('wazuh-agent1', f'rm -rf {folder_path}')
clean_environment(host_manager, enviroment_files)
# Stop host
host_manager.run_command(host, '/var/ossec/bin/wazuh-control stop')
if (case == 'add'):
host_manager.run_command('wazuh-agent1', f'touch {folder_path}/{folder_path}.txt')
elif (case == 'modify'):
host_manager.modify_file_content(host='wazuh-agent1', path=folder_path, content=folder_path)
else:
host_manager.run_command('wazuh-agent1', f'rm -rf {folder_path}')
folder_path = f"'/{folder_path}/{folder_path}.txt'"
query = " select * from fim_entry where full_path='\"{}\"'".format(folder_path)
# Start host
host_manager.run_command(host, '/var/ossec/bin/wazuh-control start')
if (host == 'wazuh-manager'):
message_path = messages_path[4]
try:
HostMonitor(inventory_path=inventory_path,
messages_path=message_path,
tmp_path=tmp_path).run()
if (case == 'delete'):
# Execute query to DB
sleep(5)
result = query_db(host_manager, db_script, db_path, f'\"{query}\"')
> assert not json.loads(result)
tests/system/test_fim/test_synchronization/test_synchronization.py:154:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
/usr/lib/python3.10/json/__init__.py:346: in loads
return _default_decoder.decode(s)
/usr/lib/python3.10/json/decoder.py:337: in decode
obj, end = self.raw_decode(s, idx=_w(s, 0).end())
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self =
s = "[(u'/testdir1/testdir1.txt', u'/testdir1/testdir1.txt', u'file', 1708941796, 1, None, None, None, 0, u'rw-r--r--', u'...44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855', u'', None, u'2f0d51ab6e087d9175a7865ebdbdf6d557bc71d9')]"
idx = 0
def raw_decode(self, s, idx=0):
"""Decode a JSON document from ``s`` (a ``str`` beginning with
a JSON document) and return a 2-tuple of the Python
representation and the index in ``s`` where the document ended.
This can be used to decode a JSON document from a string that may
have extraneous data at the end.
"""
try:
obj, end = self.scan_once(s, idx)
except StopIteration as err:
> raise JSONDecodeError("Expecting value", s, err.value) from None
E json.decoder.JSONDecodeError: Expecting value: line 1 column 2 (char 1)
/usr/lib/python3.10/json/decoder.py:355: JSONDecodeError
------------------------------Captured stderr call------------------------------
2024-02-26 10:04:21,628 - wazuh_testing - DEBUG - Add new file composer process for wazuh-agent1 and path: /var/ossec/logs/ossec.log 2024-02-26 10:04:21,632 - wazuh_testing - DEBUG - Add new file monitor process for wazuh-agent1 and path: /var/ossec/logs/ossec.log 2024-02-26 10:04:21,635 - wazuh_testing - DEBUG - Add new file composer process for wazuh-manager and path: /var/ossec/logs/ossec.log 2024-02-26 10:04:21,638 - wazuh_testing - DEBUG - Starting file composer for wazuh-agent1 and path: /var/ossec/logs/ossec.log. Composite file in /home/ubuntu/wazuh-qa/tests/system/test_fim/test_synchronization/tmp/wazuh-agent1_ossec.log.tmp 2024-02-26 10:04:21,640 - wazuh_testing - DEBUG - Add new file monitor process for wazuh-manager and path: /var/ossec/logs/ossec.log 2024-02-26 10:04:21,645 - wazuh_testing - DEBUG - Starting file composer for wazuh-manager and path: /var/ossec/logs/ossec.log. Composite file in /home/ubuntu/wazuh-qa/tests/system/test_fim/test_synchronization/tmp/wazuh-manager_ossec.log.tmp 2024-02-26 10:04:21,647 - wazuh_testing - DEBUG - Starting QueueMonitor for wazuh-agent1 and message: .*Sending integrity control message: (.+)$ 2024-02-26 10:04:21,653 - wazuh_testing - DEBUG - Starting QueueMonitor for wazuh-manager and message: .*Agent 001 query: (.+) save2 2024-02-26 10:04:23,179 - wazuh_testing - DEBUG - Finishing QueueMonitor for wazuh-agent1 and message: .*Sending integrity control message: (.+)$ 2024-02-26 10:04:25,878 - wazuh_testing - DEBUG - Finishing QueueMonitor for wazuh-manager and message: .*Agent 001 query: (.+) save2 2024-02-26 10:04:26,652 - wazuh_testing - DEBUG - Cleaning temporal files... 2024-02-26 10:04:26,653 - wazuh_testing - DEBUG - Checking results... 2024-02-26 10:04:26,655 - wazuh_testing - DEBUG - Received from wazuh-agent1 the expected message: True 2024-02-26 10:04:26,655 - wazuh_testing - DEBUG - Received from wazuh-manager the expected message: True 2024-02-26 10:04:47,876 - wazuh_testing - DEBUG - Add new file composer process for wazuh-agent1 and path: /var/ossec/logs/ossec.log 2024-02-26 10:04:47,880 - wazuh_testing - DEBUG - Starting file composer for wazuh-agent1 and path: /var/ossec/logs/ossec.log. Composite file in /home/ubuntu/wazuh-qa/tests/system/test_fim/test_synchronization/tmp/wazuh-agent1_ossec.log.tmp 2024-02-26 10:04:47,880 - wazuh_testing - DEBUG - Add new file monitor process for wazuh-agent1 and path: /var/ossec/logs/ossec.log 2024-02-26 10:04:47,886 - wazuh_testing - DEBUG - Starting QueueMonitor for wazuh-agent1 and message: .*Finished FIM sync. 2024-02-26 10:04:49,409 - wazuh_testing - DEBUG - Finishing QueueMonitor for wazuh-agent1 and message: .*Finished FIM sync. 2024-02-26 10:04:50,388 - wazuh_testing - DEBUG - Cleaning temporal files... 2024-02-26 10:04:50,388 - wazuh_testing - DEBUG - Checking results... 2024-02-26 10:04:50,391 - wazuh_testing - DEBUG - Received from wazuh-agent1 the expected message: True
-------------------------------Captured log call--------------------------------
DEBUG wazuh_testing:monitoring.py:921 Add new file composer process for wazuh-agent1 and path: /var/ossec/logs/ossec.log DEBUG wazuh_testing:monitoring.py:925 Add new file monitor process for wazuh-agent1 and path: /var/ossec/logs/ossec.log DEBUG wazuh_testing:monitoring.py:921 Add new file composer process for wazuh-manager and path: /var/ossec/logs/ossec.log DEBUG wazuh_testing:monitoring.py:925 Add new file monitor process for wazuh-manager and path: /var/ossec/logs/ossec.log DEBUG wazuh_testing:monitoring.py:1028 Cleaning temporal files... DEBUG wazuh_testing:monitoring.py:1017 Checking results... DEBUG wazuh_testing:monitoring.py:1023 Received from wazuh-agent1 the expected message: True DEBUG wazuh_testing:monitoring.py:1023 Received from wazuh-manager the expected message: True DEBUG wazuh_testing:monitoring.py:921 Add new file composer process for wazuh-agent1 and path: /var/ossec/logs/ossec.log DEBUG wazuh_testing:monitoring.py:925 Add new file monitor process for wazuh-agent1 and path: /var/ossec/logs/ossec.log DEBUG wazuh_testing:monitoring.py:1028 Cleaning temporal files... DEBUG wazuh_testing:monitoring.py:1017 Checking results... DEBUG wazuh_testing:monitoring.py:1023 Received from wazuh-agent1 the expected message: True
```
Case 1 :green_circle:
- Found errors in Wazuh agent ossec.log
- Probably related to the environment itself
- A Vagrant Ubuntu 22 box does not include this directory by default
- Confirmed, the provided environment does not have the secure file in any instance
```
root@ubuntu22:/home/vagrant# ls -l /var/log/secure
ls: cannot access '/var/log/secure': No such file or directory
root@ubuntu22:/home/vagrant# cat /etc/os-release
PRETTY_NAME="Ubuntu 22.04.2 LTS"
NAME="Ubuntu"
VERSION_ID="22.04"
VERSION="22.04.2 LTS (Jammy Jellyfish)"
VERSION_CODENAME=jammy
ID=ubuntu
ID_LIKE=debian
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
UBUNTU_CODENAME=jammy
```
```
2024/02/26 10:55:01 wazuh-logcollector: ERROR: (1103): Could not open file '/var/log/secure' due to [(2)-(No such file or directory)].
```
Case 2 :red_circle:
- Found timeout error in `check_result(self)` call:
- Already reported at https://github.com/wazuh/wazuh-qa/issues/5025
```
E TimeoutError: Did not found the expected callback in wazuh-manager: .*Agent 001 query: (.+) save2
```
---
Case 3 :yellow_circle:
- Found warning in the Wazuh manager ossec.log file
- Related https://github.com/wazuh/wazuh-qa/issues/3225
- https://github.com/wazuh/wazuh-qa/issues/3262
- Probably a missing change in the wazuh-qa repository, the configuration must be fixed to use actual configuration
- This should not have a significant impact in the test results
- Reported at https://github.com/wazuh/wazuh-qa/issues/5040
```
2024/02/26 11:03:43 wazuh-authd: WARNING: The tag is deprecated. Use instead.
2024/02/26 11:03:43 wazuh-authd: WARNING: The tag is deprecated. Use instead.
2024/02/26 11:03:43 wazuh-modulesd: WARNING: The tag at module 'vulnerability-detector' is deprecated for version newer than 4.3.
```
- The following configuration should be reviewed and updated if necessary
```
tests/integration/test_authd/force_options/data/test_cases/valid_config/enablement_force_options.yaml: name: force_insert_disabled
tests/integration/test_authd/force_options/data/test_cases/valid_config/enablement_force_options.yaml: description: Check that legacy force_insert overrides force.enabled
tests/integration/test_authd/force_options/data/test_cases/valid_config/enablement_force_options.yaml: - force_insert:
tests/integration/test_authd/force_options/data/test_cases/valid_config/enablement_force_options.yaml: - The tag is deprecated. Use instead.
tests/integration/test_authd/force_options/data/test_cases/valid_config/enablement_force_options.yaml: description: Don´t replace an agent if force_insert disabled force options
tests/integration/test_authd/force_options/data/test_cases/valid_config/enablement_force_options.yaml: name: force_insert_enabled_no_force_block
tests/integration/test_authd/force_options/data/test_cases/valid_config/enablement_force_options.yaml: description: Check that legacy force_insert overrides force.enabled
tests/integration/test_authd/force_options/data/test_cases/valid_config/enablement_force_options.yaml: - force_insert:
tests/integration/test_authd/force_options/data/test_cases/valid_config/enablement_force_options.yaml: - The tag is deprecated. Use instead.
tests/integration/test_authd/force_options/data/test_cases/valid_config/enablement_force_options.yaml: - Setting tag to 'yes' to comply with the legacy option found.
tests/integration/test_authd/force_options/data/test_cases/valid_config/enablement_force_options.yaml: description: Replace an agent if force_insert enabled force options
tests/integration/test_fim/test_files/test_audit/data/ossec.conf: yes
tests/system/provisioning/one_manager_agent/roles/manager-role/files/ossec.conf: yes
tests/system/provisioning/manager_agent/roles/manager-role/files/ossec.conf: yes
tests/system/provisioning/manager_agent/roles/master-role/files/ossec.conf: yes
tests/system/test_cluster/test_agent_key_polling/data/config.yaml: - force_insert:
tests/integration/test_authd/force_options/data/test_cases/valid_config/enablement_force_options.yaml: - force_time:
tests/integration/test_authd/force_options/data/test_cases/valid_config/enablement_force_options.yaml: - The tag is deprecated. Use instead.
tests/integration/test_authd/force_options/data/test_cases/valid_config/enablement_force_options.yaml: - force_time:
tests/integration/test_authd/force_options/data/test_cases/valid_config/enablement_force_options.yaml: - The tag is deprecated. Use instead.
tests/integration/test_authd/force_options/data/test_cases/valid_config/enablement_force_options.yaml: - Setting tag to '5' to comply with the legacy option found.
tests/integration/test_fim/test_files/test_audit/data/ossec.conf: 0
tests/system/provisioning/one_manager_agent/roles/manager-role/files/ossec.conf: 0
tests/system/provisioning/manager_agent/roles/manager-role/files/ossec.conf: 0
tests/system/provisioning/manager_agent/roles/master-role/files/ossec.conf: 0
tests/system/test_cluster/test_agent_key_polling/data/config.yaml: - force_time:
tests/integration/test_fim/test_files/test_audit/data/ossec.conf: 6h
tests/system/provisioning/big_cluster_40_agents/roles/worker-role/files/ossec.conf: 6h
tests/system/provisioning/big_cluster_40_agents/roles/master-role/files/ossec.conf: 6h
tests/system/provisioning/basic_cluster/roles/worker-role/files/ossec.conf: 6h
tests/system/provisioning/basic_cluster/roles/master-role/files/ossec.conf: 6h
tests/system/provisioning/four_manager_disconnected_node/roles/worker-role/files/ossec.conf: 6h
tests/system/provisioning/four_manager_disconnected_node/roles/master-role/files/ossec.conf: 6h
tests/system/provisioning/one_manager_agent/roles/manager-role/files/ossec.conf: 6h
tests/system/provisioning/manager_agent/roles/manager-role/files/ossec.conf: 6h
tests/system/provisioning/manager_agent/roles/master-role/files/ossec.conf: 6h
tests/system/provisioning/enrollment_cluster/roles/worker-role/files/ossec.conf: 6h
tests/system/provisioning/enrollment_cluster/roles/master-role/files/ossec.conf: 6h
tests/system/provisioning/agentless_cluster/roles/worker-role/files/ossec.conf: 6h
tests/system/provisioning/agentless_cluster/roles/master-role/files/ossec.conf: 6h
```
Case 4 :green_circle:
- Found errors/warnings in the Wazuh agent ossec.log file
- Probably related to the environment
- Confirmed, the provided environment does not have the secure file in any instance
- Confirmed, the provided environment does not have the Auditd package installed in any instance
```
2024/02/26 11:04:42 wazuh-syscheckd[19502] syscheck_audit.c:330 at audit_init(): WARNING: (6923): Who-data engine cannot start because Auditd is not running.
2024/02/26 11:04:42 wazuh-syscheckd[19502] main.c:300 at main(): WARNING: (6913): Who-data engine could not start. Switching who-data to real-time.
2024/02/26 11:04:43 wazuh-logcollector: ERROR: (1103): Could not open file '/var/log/secure' due to [(2)-(No such file or directory)].
```
Case 5 :red_circle:
- Found JSONDecoderError exception in `raw_decode(self, s, idx=0):` call
- Reported at https://github.com/wazuh/wazuh-qa/issues/5043
```
s = "[(u'/testdir1/testdir1.txt', u'/testdir1/testdir1.txt', u'file', 1708941796, 1, None, None, None, 0, u'rw-r--r--', u'...44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855', u'', None, u'2f0d51ab6e087d9175a7865ebdbdf6d557bc71d9')]"
(...)
E json.decoder.JSONDecodeError: Expecting value: line 1 column 2 (char 1)
```
---
- Asked for access to the environment: https://github.com/wazuh/internal-devel-requests/issues/794#issuecomment-1966627579
- A new test has been executed and the following output has been obtained:
Test
```
(system_env) root@ip-172-31-32-151:/home/ubuntu/wazuh-qa# python3 -m pytest tests/system/ -m one_manager_agent_env --html=one_manager_agent.html
========================================= test session starts ==========================================
platform linux -- Python 3.10.12, pytest-7.1.2, pluggy-1.4.0
rootdir: /home/ubuntu/wazuh-qa/tests/system, configfile: pytest.ini
plugins: testinfra-5.0.0, metadata-3.1.1, html-3.1.1
collected 144 items / 129 deselected / 15 selected
tests/system/test_fim/test_files/test_files_cud.py .F....... [ 60%]
tests/system/test_fim/test_synchronization/test_synchronization.py .....F [100%]
=============================================== FAILURES ===============================================
____________________________________ test_file_cud[testdir1-modify] ____________________________________
folder_path = 'testdir1', case = 'modify'
@pytest.mark.parametrize('case', ['add', 'modify', 'delete'])
@pytest.mark.parametrize('folder_path', ['testdir1', 'testdir2', 'testdir3'])
def test_file_cud(folder_path, case):
'''
description: The test will monitor a directory.
Finally, it will verify that the FIM event is generated
in agent and manager side.
wazuh_min_version: 4.2.0
parameters:
- folder_path:
type: str
brief: Name of the folder that will be created in the test.
- case:
type: str
brief: Name of the test case that will be created in the test.
assertions:
- Verify that FIM events are generated correctly on the manager and agent sides.
input_description: Different test cases are included with Pytest parametrize.
The test cases are: add, modify and delete files.
expected_output:
- Different test cases are contained in external YAML file (delete_message.yml and messages.yml)
tags:
- fim_basic_usage
- scheduled
- realtime
- who_data
'''
messages = messages_path[0]
enviroment_files = [('wazuh-manager', os.path.join(WAZUH_LOGS_PATH, 'ossec.log')),
('wazuh-agent1', os.path.join(WAZUH_LOGS_PATH, 'ossec.log'))]
clean_environment(host_manager, enviroment_files)
create_folder_file(host_manager, folder_path)
# Restart Wazuh agent
host_manager.control_service(host='wazuh-agent1', service='wazuh', state="restarted")
# Check if the scan monitors end
if (folder_path == scheduled_mode):
wait_for_fim_scan_end(HostMonitor, inventory_path, messages_path[2], tmp_path)
if (case == 'modify'):
host_manager.modify_file_content(host='wazuh-agent1', path=folder_path, content=folder_path)
elif(case == 'delete'):
host_manager.run_command('wazuh-agent1', f'rm -rf {folder_path}')
messages = messages_path[1]
try:
# Run the callback checks for the ossec.log
HostMonitor(inventory_path=inventory_path,
messages_path=messages,
> tmp_path=tmp_path).run()
tests/system/test_fim/test_files/test_files_cud.py:126:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
system_env/lib/python3.10/site-packages/wazuh_testing-4.7.3-py3.10.egg/wazuh_testing/tools/monitoring.py:937: in run
self.check_result()
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self =
def check_result(self):
"""Check if a TimeoutError occurred."""
logger.debug(f'Checking results...')
while not self._queue.empty():
result = self._queue.get(block=True)
for host, msg in result.items():
if isinstance(msg, TimeoutError):
> raise msg
E TimeoutError: Did not found the expected callback in wazuh-manager: .*Agent 001 query: (.+) save2
system_env/lib/python3.10/site-packages/wazuh_testing-4.7.3-py3.10.egg/wazuh_testing/tools/monitoring.py:1022: TimeoutError
----------------------------------------- Captured stderr call -----------------------------------------
2024-02-27 16:24:14,354 - wazuh_testing - DEBUG - Add new file composer process for wazuh-agent1 and path: /var/ossec/logs/ossec.log
2024-02-27 16:24:14,362 - wazuh_testing - DEBUG - Starting file composer for wazuh-agent1 and path: /var/ossec/logs/ossec.log. Composite file in /home/ubuntu/wazuh-qa/tests/system/test_fim/test_files/tmp/wazuh-agent1_ossec.log.tmp
2024-02-27 16:24:14,362 - wazuh_testing - DEBUG - Add new file monitor process for wazuh-agent1 and path: /var/ossec/logs/ossec.log
2024-02-27 16:24:14,375 - wazuh_testing - DEBUG - Starting QueueMonitor for wazuh-agent1 and message: .*File integrity monitoring scan ended.$
2024-02-27 16:24:16,397 - wazuh_testing - DEBUG - Finishing QueueMonitor for wazuh-agent1 and message: .*File integrity monitoring scan ended.$
2024-02-27 16:24:17,369 - wazuh_testing - DEBUG - Cleaning temporal files...
2024-02-27 16:24:17,370 - wazuh_testing - DEBUG - Checking results...
2024-02-27 16:24:17,371 - wazuh_testing - DEBUG - Received from wazuh-agent1 the expected message: True
2024-02-27 16:24:21,168 - wazuh_testing - DEBUG - Add new file composer process for wazuh-agent1 and path: /var/ossec/logs/ossec.log
2024-02-27 16:24:21,171 - wazuh_testing - DEBUG - Starting file composer for wazuh-agent1 and path: /var/ossec/logs/ossec.log. Composite file in /home/ubuntu/wazuh-qa/tests/system/test_fim/test_files/tmp/wazuh-agent1_ossec.log.tmp
2024-02-27 16:24:21,171 - wazuh_testing - DEBUG - Add new file monitor process for wazuh-agent1 and path: /var/ossec/logs/ossec.log
2024-02-27 16:24:21,176 - wazuh_testing - DEBUG - Add new file composer process for wazuh-manager and path: /var/ossec/logs/ossec.log
2024-02-27 16:24:21,181 - wazuh_testing - DEBUG - Add new file monitor process for wazuh-manager and path: /var/ossec/logs/ossec.log
2024-02-27 16:24:21,185 - wazuh_testing - DEBUG - Starting QueueMonitor for wazuh-agent1 and message: .*Sending integrity control message: (.+)$
2024-02-27 16:24:21,186 - wazuh_testing - DEBUG - Starting QueueMonitor for wazuh-manager and message: .*Agent 001 query: (.+) save2
2024-02-27 16:24:21,189 - wazuh_testing - DEBUG - Starting file composer for wazuh-manager and path: /var/ossec/logs/ossec.log. Composite file in /home/ubuntu/wazuh-qa/tests/system/test_fim/test_files/tmp/wazuh-manager_ossec.log.tmp
2024-02-27 16:24:23,195 - wazuh_testing - DEBUG - Finishing QueueMonitor for wazuh-agent1 and message: .*Sending integrity control message: (.+)$
2024-02-27 16:25:21,226 - wazuh_testing - DEBUG - Finishing QueueMonitor for wazuh-manager and message: .*Agent 001 query: (.+) save2
2024-02-27 16:25:21,287 - wazuh_testing - DEBUG - Cleaning temporal files...
2024-02-27 16:25:21,293 - wazuh_testing - DEBUG - Checking results...
2024-02-27 16:25:21,294 - wazuh_testing - DEBUG - Received from wazuh-agent1 the expected message: True
------------------------------------------ Captured log call -------------------------------------------
DEBUG wazuh_testing:monitoring.py:921 Add new file composer process for wazuh-agent1 and path: /var/ossec/logs/ossec.log
DEBUG wazuh_testing:monitoring.py:925 Add new file monitor process for wazuh-agent1 and path: /var/ossec/logs/ossec.log
DEBUG wazuh_testing:monitoring.py:1028 Cleaning temporal files...
DEBUG wazuh_testing:monitoring.py:1017 Checking results...
DEBUG wazuh_testing:monitoring.py:1023 Received from wazuh-agent1 the expected message: True
DEBUG wazuh_testing:monitoring.py:921 Add new file composer process for wazuh-agent1 and path: /var/ossec/logs/ossec.log
DEBUG wazuh_testing:monitoring.py:925 Add new file monitor process for wazuh-agent1 and path: /var/ossec/logs/ossec.log
DEBUG wazuh_testing:monitoring.py:921 Add new file composer process for wazuh-manager and path: /var/ossec/logs/ossec.log
DEBUG wazuh_testing:monitoring.py:925 Add new file monitor process for wazuh-manager and path: /var/ossec/logs/ossec.log
DEBUG wazuh_testing:monitoring.py:1028 Cleaning temporal files...
DEBUG wazuh_testing:monitoring.py:1017 Checking results...
DEBUG wazuh_testing:monitoring.py:1023 Received from wazuh-agent1 the expected message: True
_________________________ test_synchronization[testdir1-delete-wazuh-manager] __________________________
folder_path = "'/testdir1/testdir1.txt'", case = 'delete', host = 'wazuh-manager'
@pytest.mark.parametrize('host', ['wazuh-agent1', 'wazuh-manager'])
@pytest.mark.parametrize('case', ['add', 'modify', 'delete'])
@pytest.mark.parametrize('folder_path', ['testdir1'])
def test_synchronization(folder_path, case, host):
'''
Description: The test will monitor a directory and apply changes when agent/manager is stopped.
Finally, it will verify that the FIM 'Synchronization' event is generated
in agent and manager side.
wazuh_min_version: 4.2.0
parameters:
- folder_path:
type: str
brief: Name of the folder that will be created in the test.
- case:
type: str
brief: Name of the test case that will be created in the test.
- host:
type: str
brief: Name of the endpoint that will be use in the test.
assertions:
- Verify that FIM sync events are generated correctly on the manager and agent sides.
input_description: Different test cases are included with Pytest parametrize.
The test cases are: add, modify and delete files.
expected_output:
- Different test cases are contained in external YAML file
(agent_initializing_synchronization.yml and manager_initializing_synchronization.yaml)
tags:
- fim_basic_usage
- scheduled
'''
message_path = messages_path[3]
# Clear logs, create folder to monitored and restart the service
create_folder_file(host_manager, folder_path)
host_manager.control_service(host='wazuh-agent1', service='wazuh', state="restarted")
# Check that the manager contains data to monitor
try:
HostMonitor(inventory_path=inventory_path,
messages_path=messages_path[0],
tmp_path=tmp_path).run()
except Exception:
host_manager.run_command('wazuh-agent1', f'rm -rf {folder_path}')
clean_environment(host_manager, enviroment_files)
# Stop host
host_manager.run_command(host, '/var/ossec/bin/wazuh-control stop')
if (case == 'add'):
host_manager.run_command('wazuh-agent1', f'touch {folder_path}/{folder_path}.txt')
elif (case == 'modify'):
host_manager.modify_file_content(host='wazuh-agent1', path=folder_path, content=folder_path)
else:
host_manager.run_command('wazuh-agent1', f'rm -rf {folder_path}')
folder_path = f"'/{folder_path}/{folder_path}.txt'"
query = " select * from fim_entry where full_path='\"{}\"'".format(folder_path)
# Start host
host_manager.run_command(host, '/var/ossec/bin/wazuh-control start')
if (host == 'wazuh-manager'):
message_path = messages_path[4]
try:
HostMonitor(inventory_path=inventory_path,
messages_path=message_path,
> tmp_path=tmp_path).run()
tests/system/test_fim/test_synchronization/test_synchronization.py:149:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
system_env/lib/python3.10/site-packages/wazuh_testing-4.7.3-py3.10.egg/wazuh_testing/tools/monitoring.py:937: in run
self.check_result()
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self =
def check_result(self):
"""Check if a TimeoutError occurred."""
logger.debug(f'Checking results...')
while not self._queue.empty():
result = self._queue.get(block=True)
for host, msg in result.items():
if isinstance(msg, TimeoutError):
> raise msg
E TimeoutError: Did not found the expected callback in wazuh-manager: .*Finished FIM sync.
system_env/lib/python3.10/site-packages/wazuh_testing-4.7.3-py3.10.egg/wazuh_testing/tools/monitoring.py:1022: TimeoutError
----------------------------------------- Captured stderr call -----------------------------------------
2024-02-27 16:34:42,538 - wazuh_testing - DEBUG - Add new file composer process for wazuh-agent1 and path: /var/ossec/logs/ossec.log
2024-02-27 16:34:42,542 - wazuh_testing - DEBUG - Starting file composer for wazuh-agent1 and path: /var/ossec/logs/ossec.log. Composite file in /home/ubuntu/wazuh-qa/tests/system/test_fim/test_synchronization/tmp/wazuh-agent1_ossec.log.tmp
2024-02-27 16:34:42,542 - wazuh_testing - DEBUG - Add new file monitor process for wazuh-agent1 and path: /var/ossec/logs/ossec.log
2024-02-27 16:34:42,546 - wazuh_testing - DEBUG - Add new file composer process for wazuh-manager and path: /var/ossec/logs/ossec.log
2024-02-27 16:34:42,550 - wazuh_testing - DEBUG - Add new file monitor process for wazuh-manager and path: /var/ossec/logs/ossec.log
2024-02-27 16:34:42,555 - wazuh_testing - DEBUG - Starting file composer for wazuh-manager and path: /var/ossec/logs/ossec.log. Composite file in /home/ubuntu/wazuh-qa/tests/system/test_fim/test_synchronization/tmp/wazuh-manager_ossec.log.tmp
2024-02-27 16:34:42,568 - wazuh_testing - DEBUG - Starting QueueMonitor for wazuh-agent1 and message: .*Sending integrity control message: (.+)$
2024-02-27 16:34:42,587 - wazuh_testing - DEBUG - Starting QueueMonitor for wazuh-manager and message: .*Agent 001 query: (.+) save2
2024-02-27 16:34:44,585 - wazuh_testing - DEBUG - Finishing QueueMonitor for wazuh-agent1 and message: .*Sending integrity control message: (.+)$
2024-02-27 16:34:44,648 - wazuh_testing - DEBUG - Finishing QueueMonitor for wazuh-manager and message: .*Agent 001 query: (.+) save2
2024-02-27 16:34:45,559 - wazuh_testing - DEBUG - Cleaning temporal files...
2024-02-27 16:34:45,560 - wazuh_testing - DEBUG - Checking results...
2024-02-27 16:34:45,563 - wazuh_testing - DEBUG - Received from wazuh-agent1 the expected message: True
2024-02-27 16:34:45,564 - wazuh_testing - DEBUG - Received from wazuh-manager the expected message: True
2024-02-27 16:35:20,844 - wazuh_testing - DEBUG - Add new file composer process for wazuh-manager and path: /var/ossec/logs/ossec.log
2024-02-27 16:35:20,848 - wazuh_testing - DEBUG - Add new file monitor process for wazuh-manager and path: /var/ossec/logs/ossec.log
2024-02-27 16:35:20,855 - wazuh_testing - DEBUG - Starting QueueMonitor for wazuh-manager and message: .*Finished FIM sync.
2024-02-27 16:35:20,861 - wazuh_testing - DEBUG - Starting file composer for wazuh-manager and path: /var/ossec/logs/ossec.log. Composite file in /home/ubuntu/wazuh-qa/tests/system/test_fim/test_synchronization/tmp/wazuh-manager_ossec.log.tmp
2024-02-27 16:36:20,901 - wazuh_testing - DEBUG - Finishing QueueMonitor for wazuh-manager and message: .*Finished FIM sync.
2024-02-27 16:36:20,932 - wazuh_testing - DEBUG - Cleaning temporal files...
2024-02-27 16:36:20,934 - wazuh_testing - DEBUG - Checking results...
------------------------------------------ Captured log call -------------------------------------------
DEBUG wazuh_testing:monitoring.py:921 Add new file composer process for wazuh-agent1 and path: /var/ossec/logs/ossec.log
DEBUG wazuh_testing:monitoring.py:925 Add new file monitor process for wazuh-agent1 and path: /var/ossec/logs/ossec.log
DEBUG wazuh_testing:monitoring.py:921 Add new file composer process for wazuh-manager and path: /var/ossec/logs/ossec.log
DEBUG wazuh_testing:monitoring.py:925 Add new file monitor process for wazuh-manager and path: /var/ossec/logs/ossec.log
DEBUG wazuh_testing:monitoring.py:1028 Cleaning temporal files...
DEBUG wazuh_testing:monitoring.py:1017 Checking results...
DEBUG wazuh_testing:monitoring.py:1023 Received from wazuh-agent1 the expected message: True
DEBUG wazuh_testing:monitoring.py:1023 Received from wazuh-manager the expected message: True
DEBUG wazuh_testing:monitoring.py:921 Add new file composer process for wazuh-manager and path: /var/ossec/logs/ossec.log
DEBUG wazuh_testing:monitoring.py:925 Add new file monitor process for wazuh-manager and path: /var/ossec/logs/ossec.log
DEBUG wazuh_testing:monitoring.py:1028 Cleaning temporal files...
DEBUG wazuh_testing:monitoring.py:1017 Checking results...
=========================================== warnings summary ===========================================
system_env/lib/python3.10/site-packages/wazuh_testing-4.7.3-py3.10.egg/wazuh_testing/modules/__init__.py:24
/home/ubuntu/wazuh-qa/system_env/lib/python3.10/site-packages/wazuh_testing-4.7.3-py3.10.egg/wazuh_testing/modules/__init__.py:24: PytestUnknownMarkWarning: Unknown pytest.mark.win32 - is this a typo? You can register custom marks to avoid this warning - for details, see https://docs.pytest.org/en/stable/how-to/mark.html
WINDOWS = pytest.mark.win32
system_env/lib/python3.10/site-packages/wazuh_testing-4.7.3-py3.10.egg/wazuh_testing/modules/__init__.py:25
/home/ubuntu/wazuh-qa/system_env/lib/python3.10/site-packages/wazuh_testing-4.7.3-py3.10.egg/wazuh_testing/modules/__init__.py:25: PytestUnknownMarkWarning: Unknown pytest.mark.linux - is this a typo? You can register custom marks to avoid this warning - for details, see https://docs.pytest.org/en/stable/how-to/mark.html
LINUX = pytest.mark.linux
system_env/lib/python3.10/site-packages/wazuh_testing-4.7.3-py3.10.egg/wazuh_testing/modules/__init__.py:26
/home/ubuntu/wazuh-qa/system_env/lib/python3.10/site-packages/wazuh_testing-4.7.3-py3.10.egg/wazuh_testing/modules/__init__.py:26: PytestUnknownMarkWarning: Unknown pytest.mark.darwin - is this a typo? You can register custom marks to avoid this warning - for details, see https://docs.pytest.org/en/stable/how-to/mark.html
MACOS = pytest.mark.darwin
system_env/lib/python3.10/site-packages/wazuh_testing-4.7.3-py3.10.egg/wazuh_testing/modules/__init__.py:27
/home/ubuntu/wazuh-qa/system_env/lib/python3.10/site-packages/wazuh_testing-4.7.3-py3.10.egg/wazuh_testing/modules/__init__.py:27: PytestUnknownMarkWarning: Unknown pytest.mark.sunos5 - is this a typo? You can register custom marks to avoid this warning - for details, see https://docs.pytest.org/en/stable/how-to/mark.html
SOLARIS = pytest.mark.sunos5
system_env/lib/python3.10/site-packages/wazuh_testing-4.7.3-py3.10.egg/wazuh_testing/modules/__init__.py:29
/home/ubuntu/wazuh-qa/system_env/lib/python3.10/site-packages/wazuh_testing-4.7.3-py3.10.egg/wazuh_testing/modules/__init__.py:29: PytestUnknownMarkWarning: Unknown pytest.mark.agent - is this a typo? You can register custom marks to avoid this warning - for details, see https://docs.pytest.org/en/stable/how-to/mark.html
AGENT = pytest.mark.agent
-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
--------------- generated html file: file:///home/ubuntu/wazuh-qa/one_manager_agent.html ---------------
======================================= short test summary info ========================================
FAILED tests/system/test_fim/test_files/test_files_cud.py::test_file_cud[testdir1-modify] - TimeoutEr...
FAILED tests/system/test_fim/test_synchronization/test_synchronization.py::test_synchronization[testdir1-delete-wazuh-manager]
================= 2 failed, 13 passed, 129 deselected, 5 warnings in 792.06s (0:13:12) =================
```
- It can be observed that the test_syncronization error has changed from:
```
E json.decoder.JSONDecodeError: Expecting value: line 1 column 2 (char 1)
```
to:
```
E TimeoutError: Did not found the expected callback in wazuh-manager: .*Finished FIM sync.
system_env/lib/python3.10/site-packages/wazuh_testing-4.7.3-py3.10.egg/wazuh_testing/tools/monitoring.py:1022: TimeoutError
```
which is a similar error to case 2.
- A new execution test has ended successfully
```
(system_env) root@ip-172-31-32-151:/home/ubuntu/wazuh-qa# python3 -m pytest tests/system/ -m one_manager_agent_env --html=one_manager_agent.html -k test_synchronization
========================================= test session starts ==========================================
platform linux -- Python 3.10.12, pytest-7.1.2, pluggy-1.4.0
rootdir: /home/ubuntu/wazuh-qa/tests/system, configfile: pytest.ini
plugins: testinfra-5.0.0, metadata-3.1.1, html-3.1.1
collected 144 items / 138 deselected / 6 selected
tests/system/test_fim/test_synchronization/test_synchronization.py ...... [100%]
```
- After talking with @mhamra, we have discovered that the query result is provided with Unicode references, comparing with framework code, we have seen that they manage the result to adapt the encoding and some fields
- Finally, the cause of the error is produced because we are trying to load a `list` as a `JSON`, and the query result is returned as:
```
root@wazuh-manager: /var/ossec/queue/db# python /var/system_query_db.py --db_path /var/ossec/queue/db/001.db --query "select * from fim_entry where full_path='/testdir1/testdir1.txt'"
[(u'/testdir1/testdir1.txt', u'/testdir1/testdir1.txt', u'file', 1709054500, 1, None, None, None, 0, u'rw-r--r--', u'0', u'0', u'd41d8cd98f00b204e9800998ecf8427e', u'da39a3ee5e6b4b0d3255bfef95601890afd80709', u'root', u'root', 1709054494, 2079376, u'e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855', None, None, u'e79c68b86d746f1c88bcf337ba9462aeee68fad6')]
```
- This is not correct and the test should be modified to parse a list as JSON, if the query result is empty, the list is accepted as empty, and the test will pass
About /var/log/secure and audit logs
No instance in the provided environment has the mentioned file or audit package installed, so the error/warning messages are expected.
Description
During the testing in Release 4.7.3 - RC 1 - System tests, an error has been encountered in the one_manager_agent environment, specifically in this test:
test_fim/test_synchronization/test_synchronization.py::test_synchronization[testdir1-delete-wazuh-agent1]
.The test was executed in a Ubuntu 22.04.2 LTS T3.Large 30GB SSD instance, provided by the devops team.
Current behavior
Error details
``` folder_path = "'/testdir1/testdir1.txt'", case = 'delete', host = 'wazuh-agent1' @pytest.mark.parametrize('host', ['wazuh-agent1', 'wazuh-manager']) @pytest.mark.parametrize('case', ['add', 'modify', 'delete']) @pytest.mark.parametrize('folder_path', ['testdir1']) def test_synchronization(folder_path, case, host): ''' Description: The test will monitor a directory and apply changes when agent/manager is stopped. Finally, it will verify that the FIM 'Synchronization' event is generated in agent and manager side. wazuh_min_version: 4.2.0 parameters: - folder_path: type: str brief: Name of the folder that will be created in the test. - case: type: str brief: Name of the test case that will be created in the test. - host: type: str brief: Name of the endpoint that will be use in the test. assertions: - Verify that FIM sync events are generated correctly on the manager and agent sides. input_description: Different test cases are included with Pytest parametrize. The test cases are: add, modify and delete files. expected_output: - Different test cases are contained in external YAML file (agent_initializing_synchronization.yml and manager_initializing_synchronization.yaml) tags: - fim_basic_usage - scheduled ''' message_path = messages_path[3] # Clear logs, create folder to monitored and restart the service create_folder_file(host_manager, folder_path) host_manager.control_service(host='wazuh-agent1', service='wazuh', state="restarted") # Check that the manager contains data to monitor try: HostMonitor(inventory_path=inventory_path, messages_path=messages_path[0], tmp_path=tmp_path).run() except Exception: host_manager.run_command('wazuh-agent1', f'rm -rf {folder_path}') clean_environment(host_manager, enviroment_files) # Stop host host_manager.run_command(host, '/var/ossec/bin/wazuh-control stop') if (case == 'add'): host_manager.run_command('wazuh-agent1', f'touch {folder_path}/{folder_path}.txt') elif (case == 'modify'): host_manager.modify_file_content(host='wazuh-agent1', path=folder_path, content=folder_path) else: host_manager.run_command('wazuh-agent1', f'rm -rf {folder_path}') folder_path = f"'/{folder_path}/{folder_path}.txt'" query = " select * from fim_entry where full_path='\"{}\"'".format(folder_path) # Start host host_manager.run_command(host, '/var/ossec/bin/wazuh-control start') if (host == 'wazuh-manager'): message_path = messages_path[4] try: HostMonitor(inventory_path=inventory_path, messages_path=message_path, tmp_path=tmp_path).run() if (case == 'delete'): # Execute query to DB sleep(5) result = query_db(host_manager, db_script, db_path, f'\"{query}\"') > assert not json.loads(result) tests/system/test_fim/test_synchronization/test_synchronization.py:154: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ /usr/lib/python3.10/json/__init__.py:346: in loads return _default_decoder.decode(s) /usr/lib/python3.10/json/decoder.py:337: in decode obj, end = self.raw_decode(s, idx=_w(s, 0).end()) _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ self =Expected results
All the tests should be passed
Report: one_manager_agent_env.tar.gz