wazuh-qa
wazuh-qa copied to clipboard
Published
20 hours ago •
wazuh
wazuh
LogCollector Test Fails for Windows Agents
Description
During the tests of Release 4.8.0 - Alpha 2 - Integration tests I have detected an error in Windows Agent. The specific error is
PermissionError: [Errno 13] Permission denied: 'c:\\test'
The error has been detected in the LogCollector tests.
Pipeline Error
10:57:53 TASK [Launch windows pytests] **************************************************
10:57:53 task path: /home/ec2-user/workspace/Test_integration/quality/tests/integration/test_integration.yaml:37
10:57:53 fatal: [ID2_B45823_Test_integration_windows_agent]: FAILED! => {
10:57:53 "ansible_async_watchdog_pid": 1516,
10:57:53 "ansible_job_id": "71624031561.408",
10:57:53 "changed": true,
10:57:53 "cmd": "powershell.exe -",
10:57:53 "delta": "0:19:50.318822",
10:57:53 "end": "2024-01-12 09:55:48.128232",
10:57:53 "failed_when_result": true,
10:57:53 "finished": 1,
10:57:53 "rc": 1,
10:57:53 "results_file": "C:\\Users\\Jenkins\\.ansible_async\\71624031561.408",
10:57:53 "start": "2024-01-12 09:35:57.809409",
10:57:53 "started": 1
10:57:53 }
10:57:53
10:57:53 MSG:
10:57:53
10:57:53 non-zero return code
10:57:54 Using module file /usr/local/lib/python3.7/site-packages/ansible/modules/windows/win_stat.ps1
10:57:54 Pipelining is enabled.
10:57:54 <172.31.13.5> ESTABLISH WINRM CONNECTION FOR USER: Jenkins on PORT 5986 TO 172.31.13.5
10:57:54 EXEC (via pipeline wrapper)
10:57:57 <172.31.13.5> FETCH "C:\tmp\Test_integration_B45823_20240112095642\pytest_plain_report.txt" TO "/home/ec2-user/workspace/Test_integration/windows_agent_tests_Test_integration_B45823_20240112095642.txt"
...
10:58:04 PLAY RECAP *********************************************************************
10:58:04 ID2_B45823_Test_integration_windows_agent : ok=3 changed=3 unreachable=0 failed=1 skipped=8 rescued=0 ignored=0
10:58:04
10:58:04 Playbook run took 0 days, 0 hours, 22 minutes, 12 seconds
10:58:05 FATAL: command execution failed
10:58:05 hudson.AbortException: Ansible playbook execution failed
10:58:05 at org.jenkinsci.plugins.ansible.AnsiblePlaybookBuilder.perform(AnsiblePlaybookBuilder.java:262)
10:58:05 at org.jenkinsci.plugins.ansible.workflow.AnsiblePlaybookStep$AnsiblePlaybookExecution.run(AnsiblePlaybookStep.java:430)
10:58:05 at org.jenkinsci.plugins.ansible.workflow.AnsiblePlaybookStep$AnsiblePlaybookExecution.run(AnsiblePlaybookStep.java:351)
10:58:05 at org.jenkinsci.plugins.workflow.steps.AbstractSynchronousNonBlockingStepExecution$1$1.call(AbstractSynchronousNonBlockingStepExecution.java:47)
10:58:05 at hudson.security.ACL.impersonate2(ACL.java:449)
10:58:05 at hudson.security.ACL.impersonate(ACL.java:461)
10:58:05 at org.jenkinsci.plugins.workflow.steps.AbstractSynchronousNonBlockingStepExecution$1.run(AbstractSynchronousNonBlockingStepExecution.java:44)
10:58:05 at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
10:58:05 at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
10:58:05 at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
10:58:05 at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
10:58:05 at java.base/java.lang.Thread.run(Thread.java:829)
10:58:05 [Pipeline] echo
10:58:05 hudson.AbortException: Ansible playbook execution failed
10:58:05
10:58:05 [Pipeline] }
10:58:05 [Pipeline] // stage
10:58:05 [Pipeline] }
10:58:05 Failed in branch windows_agent
Error in the Logs
=================================== ERRORS ====================================
_ ERROR at setup of test_ignore_multiple_regex[Log match - Two ignore tags - Match second tag-] _
new_file_path = 'c:\\test'
@pytest.fixture(scope='function')
def create_file(new_file_path):
"""Create an empty file.
Args:
new_file_path (str): File path to create.
"""
> write_file(new_file_path)
conftest.py:1340:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
file_path = 'c:\\test', data = ''
def write_file(file_path, data=''):
> with open(file_path, 'w') as f:
E PermissionError: [Errno 13] Permission denied: 'c:\\test'
C:\Python311\Lib\site-packages\wazuh_testing\tools\file.py:177: PermissionError
_ ERROR at setup of test_restrict_multiple_regex[No match - Two Restrict tags-] _
new_file_path = 'c:\\test'
@pytest.fixture(scope='function')
def create_file(new_file_path):
"""Create an empty file.
Args:
new_file_path (str): File path to create.
"""
> write_file(new_file_path)
conftest.py:1340:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
file_path = 'c:\\test', data = ''
def write_file(file_path, data=''):
> with open(file_path, 'w') as f:
E PermissionError: [Errno 13] Permission denied: 'c:\\test'
C:\Python311\Lib\site-packages\wazuh_testing\tools\file.py:177: PermissionError
- generated html file: file://C:\tmp\Test_integration_B45823_20240112095642\report.html -
=========================== short test summary info ===========================
ERROR test_logcollector/test_log_filter_options/test_ignore_regex.py::test_ignore_multiple_regex[Log match - Two ignore tags - Match second tag-]
ERROR test_logcollector/test_log_filter_options/test_restrict_regex.py::test_restrict_multiple_regex[No match - Two Restrict tags-]
= 135 passed, 356 skipped, 176 deselected, 35 xfailed, 5 xpassed, 2 errors in 1183.93s (0:19:43) =
Evidences
- Report: agent_windows_html_report_Test_integration_B45823.zip
- Build: https://ci.wazuh.info/job/Test_integration/45823/
Update
I have run locally on a Windows 11 agent the logcollector integration tests (test_logcollector/test_log_filter_options) without errors.
PS C:\Users\vagrant\wazuh-qa\tests\integration> python -m pytest -v --html=report.html .\test_logcollector\test_log_filter_options
============================= test session starts =============================
platform win32 -- Python 3.12.1, pytest-7.4.4, pluggy-1.3.0 -- C:\Users\vagrant\AppData\Local\Programs\Python\Python312\python.exe
cachedir: .pytest_cache
metadata: {'Python': '3.12.1', 'Platform': 'Windows-11-10.0.22621-SP0', 'Packages': {'pytest': '7.4.4', 'pluggy': '1.3.0'}, 'Plugins': {'html': '2.0.1', 'metadata': '3.0.0', 'testinfra': '10.0.0'}}
rootdir: C:\Users\vagrant\wazuh-qa\tests\integration
configfile: pytest.ini
plugins: html-2.0.1, metadata-3.0.0, testinfra-10.0.0
collecting ... collected 14 items
test_logcollector/test_log_filter_options/test_ignore_regex.py::test_ignore_multiple_regex[Log match - Two ignore tags - Match first tag-] PASSED [ 7%]
test_logcollector/test_log_filter_options/test_ignore_regex.py::test_ignore_multiple_regex[Log match - Two ignore tags - Match both tags-] PASSED [ 14%]
test_logcollector/test_log_filter_options/test_ignore_regex.py::test_ignore_multiple_regex[Log match - Two ignore tags - Match second tag-] PASSED [ 21%]
test_logcollector/test_log_filter_options/test_ignore_regex.py::test_ignore_multiple_regex[No match - Two ignore tags-] PASSED [ 28%]
test_logcollector/test_log_filter_options/test_restrict_ignore_regex.py::test_restrict_ignore_regex_values[Matches with restrict tag - Ignore and restrict tags with PCRE2 regex-] PASSED [ 35%]
test_logcollector/test_log_filter_options/test_restrict_ignore_regex.py::test_restrict_ignore_regex_values[Matches with ignore tag - Ignore and restrict tags with osregex regex-] PASSED [ 42%]
test_logcollector/test_log_filter_options/test_restrict_ignore_regex.py::test_restrict_ignore_regex_values[Log match - Ignore and restrict tags with osmatch regex-] PASSED [ 50%]
test_logcollector/test_log_filter_options/test_restrict_ignore_regex.py::test_restrict_ignore_regex_values[Matches with restrict tag - Ignore and restrict tags with pcre2 and osregex regex-] PASSED [ 57%]
test_logcollector/test_log_filter_options/test_restrict_ignore_regex.py::test_restrict_ignore_regex_values[Matches with ignore tag - Ignore and restrict tags with pcre2 and osmatch regex-] PASSED [ 64%]
test_logcollector/test_log_filter_options/test_restrict_ignore_regex.py::test_restrict_ignore_regex_values[Log match - Ignore and restrict tags with osregex and osmatch regex-] PASSED [ 71%]
test_logcollector/test_log_filter_options/test_restrict_regex.py::test_restrict_multiple_regex[Log match - Two Restrict tags - Match first tag-] PASSED [ 78%]
test_logcollector/test_log_filter_options/test_restrict_regex.py::test_restrict_multiple_regex[Log match - Two Restrict tags - Match both tags-] PASSED [ 85%]
test_logcollector/test_log_filter_options/test_restrict_regex.py::test_restrict_multiple_regex[Log match - Two Restrict tags - Match second tag-] PASSED [ 92%]
test_logcollector/test_log_filter_options/test_restrict_regex.py::test_restrict_multiple_regex[No match - Two Restrict tags-] PASSED [100%]
============================== warnings summary ===============================
test_logcollector/test_log_filter_options/test_ignore_regex.py: 20 warnings
test_logcollector/test_log_filter_options/test_restrict_ignore_regex.py: 30 warnings
test_logcollector/test_log_filter_options/test_restrict_regex.py: 20 warnings
C:\Users\vagrant\AppData\Local\Programs\Python\Python312\Lib\site-packages\wazuh_testing\tools\configuration.py:334: DeprecationWarning: Testing an element's truth value will raise an exception in future versions. Use specific 'len(elem)' or 'elem is not None' test instead.
if not section_conf:
test_logcollector/test_log_filter_options/test_ignore_regex.py: 4 warnings
test_logcollector/test_log_filter_options/test_restrict_ignore_regex.py: 6 warnings
test_logcollector/test_log_filter_options/test_restrict_regex.py: 4 warnings
C:\Users\vagrant\wazuh-qa\tests\integration\conftest.py:461: DeprecationWarning: datetime.datetime.utcnow() is deprecated and scheduled for removal in a future version. Use timezone-aware objects to represent datetimes in UTC: datetime.datetime.now(datetime.UTC).
cells.insert(1, html.td(datetime.utcnow(), class_='col-time'))
-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
- generated html file: file://C:\Users\vagrant\wazuh-qa\tests\integration\report.html -
================= 14 passed, 84 warnings in 232.89s (0:03:52) =================
HTML report: report.zip
A further analysis was made and it is observed that in both cases the error occurs when the script tries to create the file c:\\test.
new_file_path = 'c:\\test'
@pytest.fixture(scope='function')
def create_file(new_file_path):
"""Create an empty file.
Args:
new_file_path (str): File path to create.
"""
> write_file(new_file_path)
conftest.py:1340:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
file_path = 'c:\\test', data = ''
def write_file(file_path, data=''):
> with open(file_path, 'w') as f:
E PermissionError: [Errno 13] Permission denied: 'c:\\test'
C:\Python311\Lib\site-packages\wazuh_testing\tools\file.py:177: PermissionError
The "PermissionError: [Errno 13] Permission denied error" can occur for multiple reasons:
- Trying to open a file, but the specified path is a folder.
- Not having the necessary permissions to open a file.
- Trying to open a file that is already opened in another application.
It is probably due to the first option as the filepath does not contain the extension but we have not been able to reproduce the error locally. In addition, we checked the changes between versions of both the integration tests and logcollector and no relevant issues were detected. However, we can confirm that this is a test issue and not a product issue.
@nbertoldo @nmkoremblum @cborla we've confirmed there is an issue in the test. Can we get a fix?
Considering that it was possible to run the tests locally several times without errors, I think it may be a problem with the environment. @wazuh/qa Is it possible to relaunch this test?
Update
The test has been run again and the error occurs in another test case, so the failure is random.
- Build: https://ci.wazuh.info/job/Test_integration/45893/
- Report: agent_windows_html_report_Test_integration_B45893.zip
Log error
conftest.py:1330: in create_files_in_folder
delete_path_recursively(folder_path)
C:\Python311\Lib\site-packages\wazuh_testing\tools\file.py:244: in delete_path_recursively
shutil.rmtree(path, onerror=on_write_error)
C:\Python311\Lib\shutil.py:759: in rmtree
return _rmtree_unsafe(path, onerror)
C:\Python311\Lib\shutil.py:626: in _rmtree_unsafe
onerror(os.rmdir, path, sys.exc_info())
C:\Python311\Lib\shutil.py:624: in _rmtree_unsafe
os.rmdir(path)
E OSError: [WinError 145] The directory is not empty: 'c:\\testfolder\\subfolder'
-----------------------------Captured stdout setup------------------------------
The Wazuh service was stopped successfully.
The Wazuh service is starting.
The Wazuh service was started successfully.
-----------------------------Captured stderr setup------------------------------
2024-01-23 17:13:18,157 - wazuh_testing - DEBUG - Set local_internal_option to {'windows.debug': '2', 'agent.debug': '2'}
2024-01-23 17:13:18,158 - wazuh_testing - DEBUG - Restarting all daemon
-------------------------------Captured log setup-------------------------------
DEBUG wazuh_testing:conftest.py:694 Set local_internal_option to {'windows.debug': '2', 'agent.debug': '2'}
DEBUG wazuh_testing:conftest.py:144 Restarting all daemon
----------------------------Captured stdout teardown----------------------------
The Wazuh service was stopped successfully.
----------------------------Captured stderr teardown----------------------------
2024-01-23 17:13:23,396 - wazuh_testing - DEBUG - Stopping all daemons
2024-01-23 17:13:23,586 - wazuh_testing - DEBUG - Restore local_internal_option to {'syscheck.debug': '2\n', 'agent.debug': '2\n', 'monitord.rotate_log': '0\n', 'analysisd.debug': '2\n', 'wazuh_modules.debug': '2\n', 'wazuh_database.interval': '1\n', 'wazuh_db.commit_time': '2\n', 'wazuh_db.commit_time_max': '3\n', 'remoted.debug': '2\n'}
-----------------------------Captured log teardown------------------------------
DEBUG wazuh_testing:conftest.py:156 Stopping all daemons
DEBUG wazuh_testing:conftest.py:699 Restore local_internal_option to {'syscheck.debug': '2\n', 'agent.debug': '2\n', 'monitord.rotate_log': '0\n', 'analysisd.debug': '2\n', 'wazuh_modules.debug': '2\n', 'wazuh_database.interval': '1\n', 'wazuh_db.commit_time': '2\n', 'wazuh_db.commit_time_max': '3\n', 'remoted.debug': '2\n'}
Update
In a new test run, the test result has been successful, which confirms the random behaviour of the test.
- Build: https://ci.wazuh.info/job/Test_integration/45906/
- Report: agent_windows_html_report_Test_integration_B45906.zip
Let's add it to the @wazuh/devel-core1-div3's backlog. It's not a stopper.
Update
I have been able to reproduce the error locally.
Steps to reproduce
-
Create manually the folder
C:\test -
Execute the test:
Administrator@vm-win2016 MINGW64 ~/wazuh-qa/tests/integration (4.8.0)
$ python -m pytest -vvx --html=report.html test_logcollector/test_log_filter_options/
============================= test session starts =============================
platform win32 -- Python 3.11.9, pytest-7.1.2, pluggy-1.5.0 -- C:\Users\Administrator\AppData\Local\Programs\Python\Python311\python.exe
cachedir: .pytest_cache
metadata: {'Python': '3.11.9', 'Platform': 'Windows-10-10.0.14393-SP0', 'Packages': {'pytest': '7.1.2', 'pluggy': '1.5.0'}, 'Plugins': {'html': '3.1.1', 'metadata': '3.1.1'}}
rootdir: C:\Users\Administrator\wazuh-qa\tests\integration, configfile: pytest.ini
plugins: html-3.1.1, metadata-3.1.1
collecting ... collected 14 items
test_logcollector/test_log_filter_options/test_ignore_regex.py::test_ignore_multiple_regex[Log match - Two ignore tags - Match first tag-] ERROR [ 7%]
=================================== ERRORS ====================================
_ ERROR at setup of test_ignore_multiple_regex[Log match - Two ignore tags - Match first tag-] _
new_file_path = 'c:\\test'
@pytest.fixture(scope='function')
def create_file(new_file_path):
"""Create an empty file.
Args:
new_file_path (str): File path to create.
"""
> write_file(new_file_path)
conftest.py:1340:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
file_path = 'c:\\test', data = ''
def write_file(file_path, data=''):
> with open(file_path, 'w') as f:
E PermissionError: [Errno 13] Permission denied: 'c:\\test'
..\..\..\AppData\Local\Programs\Python\Python311\Lib\site-packages\wazuh_testing\tools\file.py:177: PermissionError
- generated html file: file://C:\Users\Administrator\wazuh-qa\tests\integration\report.html -
=========================== short test summary info ===========================
ERROR test_logcollector/test_log_filter_options/test_ignore_regex.py::test_ignore_multiple_regex[Log match - Two ignore tags - Match first tag-]
!!!!!!!!!!!!!!!!!!!!!!!!!! stopping after 1 failures !!!!!!!!!!!!!!!!!!!!!!!!!!
============================== 1 error in 0.13s ===============================
Report: report.zip
Could this situation occur in the test environment?
In any case, it is recommended to create the file with the corresponding extension: C:\test.log
The issue is closed for the following reasons:
- It is a faulty test of 4.8.0, which is no longer a stopper.
- The test should have been migrated to 4.9.0 in the next issue.
- This comment indicates that the migration process will demand a major effort, which mangement tells us is not necessary, due to the proximity to start with 5.0.0.
