SCA commands randomly fails

[Jaz470]

Wazuh version: 4.4.1 - 4.7.0
Custom SCA template: registry, file and command checks on Windows agents
Schedule: daily

The problem arises as more than hundred agents consistently report failed checks, specifically in the command checks, while other types of checks, such as file or registry checks, consistently succeed. And random agents report failure.

For instance, commands within the custom SCA template may run successfully on a agent on one day, report a failed status the next day, and then return to success the following day. The failures are sporadic, occurring at a rate of 1-2 failed command checks per week per agent.

In an attempt to troubleshoot, we scheduled the exact same command to run every 5 minutes on one system. However, this execution consistently produces the expected output without any failures. This raises suspicions that the issue might reside on the Wazuh server side rather than with the command or agent itself.

ossec.conf:

  <sca>
    <enabled>yes</enabled>
    <scan_on_start>yes</scan_on_start>
    <interval>12h</interval>
    <skip_nfs>yes</skip_nfs>
  </sca>

internal_options.conf:

    analysisd.sca_threads=0
    analysisd.decode_sca_queue_size=16384
    sca.request_db_interval=5
    sca.remote_commands=1
    sca.commands_timeout=30

local_internal_options.conf:

    analysisd.decode_sca_queue_size=262144`

shared/agent.conf:

    <sca>
      <policies>
        <policy>shared/sca_custom_policy.yml</policy>
        <policy enabled="no">ruleset/sca/cis_win2012r2.yml</policy>
        <policy enabled="no">ruleset/sca/cis_win2016.yml</policy>
        <policy enabled="no">ruleset/sca/cis_win2019.yml</policy>
        <policy enabled="no">ruleset/sca/cis_win2022.yml</policy>
        <policy enabled="no">ruleset/sca/sca_win_audit.yml</policy>
      </policies>
    </sca>

Agent debug log (SCA check c:sc query service -> r:RUNNING):

SCA check result: PASSED

2023/10/17 03:30:34 sca[18964] wm_sca.c:1028 at wm_sca_do_scan(): DEBUG: Considering rule: 'c:sc query AppIDSvc -> r:RUNNING'
2023/10/17 03:30:34 sca[18964] wm_sca.c:1037 at wm_sca_do_scan(): DEBUG: Rule after variable expansion: 'c:sc query AppIDSvc -> r:RUNNING'
2023/10/17 03:30:34 sca[18964] wm_sca.c:1142 at wm_sca_do_scan(): DEBUG: Running command: 'sc query AppIDSvc'
2023/10/17 03:30:34 sca[18964] wm_sca.c:1637 at wm_sca_read_command(): DEBUG: Executing command 'sc query AppIDSvc', and testing output with pattern 'r:RUNNING'
2023/10/17 03:30:34 sca[18964] wm_sca.c:1643 at wm_sca_read_command(): DEBUG: Command 'sc query AppIDSvc' returned code 0
2023/10/17 03:30:34 sca[18964] wm_sca.c:1909 at wm_sca_pattern_matches(): DEBUG: Testing minterm (r:RUNNING)(EMPTY_LINE) -> 0
2023/10/17 03:30:34 sca[18964] wm_sca.c:1912 at wm_sca_pattern_matches(): DEBUG: Pattern test result: (r:RUNNING)(EMPTY_LINE) -> 0
2023/10/17 03:30:34 sca[18964] wm_sca.c:1909 at wm_sca_pattern_matches(): DEBUG: Testing minterm (r:RUNNING)(SERVICE_NAME: AppIDSvc ) -> 0
2023/10/17 03:30:34 sca[18964] wm_sca.c:1912 at wm_sca_pattern_matches(): DEBUG: Pattern test result: (r:RUNNING)(SERVICE_NAME: AppIDSvc ) -> 0
2023/10/17 03:30:34 sca[18964] wm_sca.c:1909 at wm_sca_pattern_matches(): DEBUG: Testing minterm (r:RUNNING)(        TYPE               : 10  WIN32_OWN_PROCESS  ) -> 0
2023/10/17 03:30:34 sca[18964] wm_sca.c:1912 at wm_sca_pattern_matches(): DEBUG: Pattern test result: (r:RUNNING)(        TYPE               : 10  WIN32_OWN_PROCESS  ) -> 0
2023/10/17 03:30:34 sca[18964] wm_sca.c:1909 at wm_sca_pattern_matches(): DEBUG: Testing minterm (r:RUNNING)(        STATE              : 4  RUNNING ) -> 1
2023/10/17 03:30:34 sca[18964] wm_sca.c:1912 at wm_sca_pattern_matches(): DEBUG: Pattern test result: (r:RUNNING)(        STATE              : 4  RUNNING ) -> 1
2023/10/17 03:30:34 sca[18964] wm_sca.c:1699 at wm_sca_read_command(): DEBUG: Result for (r:RUNNING)(sc query AppIDSvc) -> 1
2023/10/17 03:30:34 sca[18964] wm_sca.c:1145 at wm_sca_do_scan(): DEBUG: Command output matched.
2023/10/17 03:30:34 sca[18964] wm_sca.c:1232 at wm_sca_do_scan(): DEBUG: Result for rule 'c:sc query AppIDSvc -> r:RUNNING': 1
2023/10/17 03:30:34 sca[18964] wm_sca.c:1255 at wm_sca_do_scan(): DEBUG: Result for check id: 31013 'Service AppIDSvc is running' -> 1

SCA check result: FAILED

2023/10/17 04:02:42 sca[19736] wm_sca.c:1028 at wm_sca_do_scan(): DEBUG: Considering rule: 'c:sc query AppIDSvc -> r:RUNNING'
2023/10/17 04:02:42 sca[19736] wm_sca.c:1037 at wm_sca_do_scan(): DEBUG: Rule after variable expansion: 'c:sc query AppIDSvc -> r:RUNNING'
2023/10/17 04:02:42 sca[19736] wm_sca.c:1142 at wm_sca_do_scan(): DEBUG: Running command: 'sc query AppIDSvc'
2023/10/17 04:02:42 sca[19736] wm_sca.c:1637 at wm_sca_read_command(): DEBUG: Executing command 'sc query AppIDSvc', and testing output with pattern 'r:RUNNING'
2023/10/17 04:02:43 sca[19736] wm_sca.c:1643 at wm_sca_read_command(): DEBUG: Command 'sc query AppIDSvc' returned code 0
2023/10/17 04:02:43 sca[19736] wm_sca.c:1909 at wm_sca_pattern_matches(): DEBUG: Testing minterm (r:RUNNING)(EMPTY_LINE) -> 0
2023/10/17 04:02:43 sca[19736] wm_sca.c:1912 at wm_sca_pattern_matches(): DEBUG: Pattern test result: (r:RUNNING)(EMPTY_LINE) -> 0
2023/10/17 04:02:43 sca[19736] wm_sca.c:1699 at wm_sca_read_command(): DEBUG: Result for (r:RUNNING)(sc query AppIDSvc) -> 0
2023/10/17 04:02:43 sca[19736] wm_sca.c:1232 at wm_sca_do_scan(): DEBUG: Result for rule 'c:sc query AppIDSvc -> r:RUNNING': 0
2023/10/17 04:02:43 sca[19736] wm_sca.c:1239 at wm_sca_do_scan(): DEBUG: Breaking from rule aggregator 'all' with found = 0
2023/10/17 04:02:43 sca[19736] wm_sca.c:1255 at wm_sca_do_scan(): DEBUG: Result for check id: 31013 'Service AppIDSvc is running' -> 0