LogCollector Test Fails for Windows Agents #4840

rafabailon · 2024-01-16T09:27:30Z

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/

nbertoldo · 2024-01-17T20:56:23Z

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

nbertoldo · 2024-01-18T19:48:35Z

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.

vikman90 · 2024-01-22T16:34:36Z

@nbertoldo @nmkoremblum @cborla we've confirmed there is an issue in the test. Can we get a fix?

nbertoldo · 2024-01-22T18:48:22Z

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?

nbertoldo · 2024-01-23T20:17:36Z

Update

The test has been run again and the error occurs in another test case, so the failure is random.

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'}

nbertoldo · 2024-01-23T20:27:10Z

Update

In a new test run, the test result has been successful, which confirms the random behaviour of the test.

vikman90 · 2024-01-25T17:05:14Z

Let's add it to the @wazuh/devel-core1-div3's backlog. It's not a stopper.

nbertoldo · 2024-06-03T22:27:43Z

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

cborla · 2024-06-05T16:00:00Z

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.
- Refactor and migrate logcollector integration tests from QA repository to Core repository
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.

rafabailon added level/task Task issue type/bug labels Jan 16, 2024

rafabailon mentioned this issue Jan 16, 2024

Release 4.8.0 - Alpha 2 - Integration tests wazuh/wazuh#21399

Closed

nbertoldo self-assigned this Jan 16, 2024

juliamagan mentioned this issue Jan 16, 2024

Release 4.8.0 - Alpha 2 wazuh/wazuh#21386

Closed

Nicogp mentioned this issue Apr 24, 2024

Migrate deprecated sha1 functions. wazuh/wazuh#22974

Merged

10 tasks

vikman90 added the module/analysis label May 3, 2024

juliamagan mentioned this issue May 7, 2024

Release 4.8.0 - RC 1 - Integration tests wazuh/wazuh#23296

Closed

Rebits mentioned this issue May 15, 2024

Release 4.8.0 - RC 2 - Integration tests wazuh/wazuh#23434

Closed

vikman90 added feature/logcollector and removed level/task Task issue labels May 21, 2024

vikman90 unassigned nbertoldo May 21, 2024

vikman90 added the level/task Task issue label May 21, 2024

damarisg mentioned this issue May 23, 2024

Release 4.7.5- RC 1 - Integration tests wazuh/wazuh#23601

Closed

cborla assigned nbertoldo Jun 3, 2024

nbertoldo mentioned this issue Jun 4, 2024

Fix logcollector integration test for Windows agent #5461

Closed

nbertoldo linked a pull request Jun 4, 2024 that will close this issue

Fix logcollector integration test for Windows agent #5461

Closed

vikman90 added the request/operational label Jun 5, 2024

cborla closed this as not planned Won't fix, can't repro, duplicate, stale Jun 5, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

LogCollector Test Fails for Windows Agents #4840

LogCollector Test Fails for Windows Agents #4840

rafabailon commented Jan 16, 2024

nbertoldo commented Jan 17, 2024

nbertoldo commented Jan 18, 2024

vikman90 commented Jan 22, 2024

nbertoldo commented Jan 22, 2024

nbertoldo commented Jan 23, 2024

nbertoldo commented Jan 23, 2024

vikman90 commented Jan 25, 2024 •

edited

nbertoldo commented Jun 3, 2024

cborla commented Jun 5, 2024 •

edited

LogCollector Test Fails for Windows Agents #4840

LogCollector Test Fails for Windows Agents #4840

Comments

rafabailon commented Jan 16, 2024

Description

Evidences

nbertoldo commented Jan 17, 2024

Update

nbertoldo commented Jan 18, 2024

vikman90 commented Jan 22, 2024

nbertoldo commented Jan 22, 2024

nbertoldo commented Jan 23, 2024

Update

nbertoldo commented Jan 23, 2024

Update

vikman90 commented Jan 25, 2024 • edited

nbertoldo commented Jun 3, 2024

Update

Steps to reproduce

cborla commented Jun 5, 2024 • edited

vikman90 commented Jan 25, 2024 •

edited

cborla commented Jun 5, 2024 •

edited