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.

Sign up for GitHub

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

Jump to bottom

QA testing - Multi server connection on Windows agent #3184

Closed
jmv74211 opened this issue Aug 17, 2022 · 3 comments
Closed

QA testing - Multi server connection on Windows agent #3184

jmv74211 opened this issue Aug 17, 2022 · 3 comments
Assignees
@Deblintrake09
Labels
dev-testing
Milestone
Release 4.3.7 RC-1

Comments

@jmv74211
Copy link
Contributor

jmv74211 commented Aug 17, 2022 •
edited
Loading

While running the integration tests for the 4.3.7-rc1 release using the 4.3 branch of wazuh-qa, a problem was detected related to agentd on Windows. The same test has been rerun for several times and all other times it has passed successfully.

Round 1 Round 2 Round 3 Round 4 Round 5
🔴 🟢 🟢 🟢 🟢

The reported problem is the following

AssertionError: Expected message Requesting a key from server: testServer1 never arrived! Stage: 0, message number: 0

=========================== short test summary info ===========================
FAILED test_agentd/test_agentd_multi_server.py::test_agentd_multi_server[server_down_fallback_tcp]
======= 1 failed, 27 passed, 6 skipped, 1 warning in 2241.80s (0:37:21) =======

The same behavior has also been observed in the 4.4 branch, where this test has also failed

Round 1 Round 2 Round 3
🔴 🔴 🟢 
AssertionError: Expected message 'Requesting a key from server: testServer1' never arrived! Stage: 1, message number: 1

=========================== short test summary info ===========================
FAILED test_agentd/test_agentd_multi_server.py::test_agentd_multi_server[server_down_fallback_tcp]
======= 1 failed, 27 passed, 6 skipped, 1 warning in 2222.02s (0:37:02) =======

It is necessary to ensure that for the case where the integration test has failed in Windows, the product is working correctly and that it is a false positive test. For this it will be necessary to test it manually and attach the necessary tests.

The corresponding issue has also been opened to investigate the corresponding integration test and to apply the necessary fix in case the false positive test is confirmed.

The use case that has failed is the following https:/wazuh/wazuh-qa/blob/4.4/tests/integration/test_agentd/test_agentd_multi_server.py#L140-L169

In this case, we want to test that the Windows agent is able to connect to a new wazuh-manager after disconnecting from the first one due to a supposed crash.

Note: The same sequence of steps that the test performs should be reproduced (except for the use of simulators).
@jmv74211 jmv74211 added this to the Release 4.3.7 RC-1 milestone Aug 17, 2022
@jmv74211 jmv74211 mentioned this issue Aug 17, 2022
Closed
@Deblintrake09 Deblintrake09 self-assigned this Aug 17, 2022
@Deblintrake09
Copy link
Contributor

Deblintrake09 commented Aug 17, 2022 •
edited by damarisg
Loading

Review data

Tester PR commit
@Deblintrake09 Tag v4.3.7-1

Testing environment

OS OS version Deployment Image/AMI Notes
Centos 8 <LOCAL | Vagrant qactl/centos_8
Centos 8 <LOCAL | Vagrant qactl/windowsserver19

Tested packages

Manager Agent
.rpm manager win agent

Status

  • In progress
  • Pending Review
  • Team leader approved
  • Manager approved

@Deblintrake09
Copy link
Contributor

Deblintrake09 commented Aug 17, 2022 •
edited
Loading

Task results

Configuration details

  • Setup Cluster
    imagen

  • Setup agent pointing to with two managers

    <client>
 <server>
   <address>172.31.7.250</address>
   <port>1514</port>
   <protocol>tcp</protocol>
 </server>
 <server>
   <address>172.31.8.153</address>
   <port>1514</port>
   <protocol>tcp</protocol>
 </server>
 <crypto_method>aes</crypto_method>
 <notify_time>10</notify_time>
 <time-reconnect>60</time-reconnect>
 <auto_restart>yes</auto_restart>
</client>

  • Start Agent and check it is connected

    # /var/ossec/bin/agent_control -l
Wazuh agent_control. List of available agents:
   ID: 000, Name: ip-172-31-7-250.ec2.internal (server), IP: 127.0.0.1, Active/Local
   ID: 001, Name: EC2AMAZ-N9OLJ1L, IP: any, Active

    imagen
    imagen

Results on 4.3.7-1

Stop manager1 with agent connected - agent connects to manager2 🟢

  • Stop manager1

    # /var/ossec/bin/wazuh-control stop
Killing wazuh-clusterd...
Killing wazuh-modulesd...
Killing wazuh-monitord...
Killing wazuh-logcollector...
Killing wazuh-remoted...
Killing wazuh-syscheckd...
Killing wazuh-analysisd...
wazuh-maild not running...
Killing wazuh-execd...
Killing wazuh-db...
Killing wazuh-authd...
wazuh-agentlessd not running...
wazuh-integratord not running...
wazuh-dbd not running...
wazuh-csyslogd not running...
Killing wazuh-apid...
Wazuh v4.3.7 Stopped

  • Check the agent's logs

    2022/08/17 19:26:02 wazuh-agent: INFO: (6008): File integrity monitoring scan started.
2022/08/17 19:26:08 rootcheck: INFO: Ending rootcheck scan.
2022/08/17 19:26:24 wazuh-agent: INFO: (6009): File integrity monitoring scan ended.
2022/08/17 19:26:24 wazuh-agent: INFO: (6012): Real-time file integrity monitoring started.
2022/08/17 19:26:52 wazuh-agent: ERROR: (1137): Lost connection with manager. Setting lock.
2022/08/17 19:26:52 wazuh-agent: INFO: Closing connection to server (172.31.7.250:1514/tcp).
2022/08/17 19:26:52 wazuh-agent: INFO: Trying to connect to server (172.31.7.250:1514/tcp).
2022/08/17 19:26:53 wazuh-agent: WARNING: Process locked due to agent is offline. Waiting for connection...
2022/08/17 19:26:53 wazuh-agent: WARNING: Process locked due to agent is offline. Waiting for connection...
2022/08/17 19:26:54 wazuh-agent: ERROR: (1216): Unable to connect to '172.31.7.250:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:27:04 wazuh-agent: INFO: Trying to connect to server (172.31.7.250:1514/tcp).
2022/08/17 19:27:06 wazuh-agent: ERROR: (1216): Unable to connect to '172.31.7.250:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:27:11 wazuh-agent: WARNING: Process locked due to agent is offline. Waiting for connection...
2022/08/17 19:27:16 wazuh-agent: INFO: Trying to connect to server (172.31.7.250:1514/tcp).
2022/08/17 19:27:19 wazuh-agent: ERROR: (1216): Unable to connect to '172.31.7.250:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:27:29 wazuh-agent: INFO: Trying to connect to server (172.31.7.250:1514/tcp).
2022/08/17 19:27:31 wazuh-agent: ERROR: (1216): Unable to connect to '172.31.7.250:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:27:41 wazuh-agent: INFO: Trying to connect to server (172.31.7.250:1514/tcp).
2022/08/17 19:27:43 wazuh-agent: ERROR: (1216): Unable to connect to '172.31.7.250:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:27:43 wazuh-agent: INFO: Requesting a key from server: 172.31.7.250
2022/08/17 19:27:45 wazuh-agent: ERROR: (1208): Unable to connect to the Auth service at '172.31.7.250:1515'.
2022/08/17 19:27:50 wazuh-agent: WARNING: Process locked due to agent is offline. Waiting for connection...
2022/08/17 19:27:55 wazuh-agent: WARNING: (4101): Waiting for server reply (not started). Tried: '172.31.7.250'.
2022/08/17 19:27:55 wazuh-agent: INFO: Trying next server ip in the line: '172.31.8.153'.
2022/08/17 19:27:55 wazuh-agent: INFO: Trying to connect to server (172.31.8.153:1514/tcp).
2022/08/17 19:27:55 wazuh-agent: INFO: (4102): Connected to the server (172.31.8.153:1514/tcp).
2022/08/17 19:27:55 wazuh-agent: INFO: Server responded. Releasing lock.
2022/08/17 19:27:56 wazuh-agent: INFO: Agent is now online. Process unlocked, continuing...
2022/08/17 19:27:56 sca: INFO: Evaluation finished for policy 'C:\Program Files (x86)\ossec-agent\ruleset\sca\cis_win2022.yml'
2022/08/17 19:27:56 sca: INFO: Starting evaluation of policy: 'C:\Program Files (x86)\ossec-agent\ruleset\sca\sca_win_audit.yml'
2022/08/17 19:27:58 wazuh-agent: INFO: Agent is now online. Process unlocked, continuing...
2022/08/17 19:27:58 wazuh-agent: INFO: Agent is now online. Process unlocked, continuing...
2022/08/17 19:27:59 sca: INFO: Evaluation finished for policy 'C:\Program Files (x86)\ossec-agent\ruleset\sca\sca_win_audit.yml'
2022/08/17 19:27:59 sca: INFO: Security Configuration Assessment scan finished. Duration: 117 seconds.
2022/08/17 19:28:00 wazuh-agent: INFO: Agent is now online. Process unlocked, continuing...
Stop manager2 with agent connected - agent connects to manager1 🟢

  • Stop manager2

    # /var/ossec/bin/wazuh-control stop
Killing wazuh-clusterd...
Killing wazuh-modulesd...
Killing wazuh-monitord...
Killing wazuh-logcollector...
Killing wazuh-remoted...
Killing wazuh-syscheckd...
Killing wazuh-analysisd...
wazuh-maild not running...
Killing wazuh-execd...
Killing wazuh-db...
Killing wazuh-authd...
wazuh-agentlessd not running...
wazuh-integratord not running...
wazuh-dbd not running...
wazuh-csyslogd not running...
Killing wazuh-apid...
Wazuh v4.3.7 Stopped

  • Check the agent's logs for agent connecting to manager2 node.

    2022/08/17 19:29:57 wazuh-agent: ERROR: (1137): Lost connection with manager. Setting lock.
2022/08/17 19:29:57 wazuh-agent: INFO: Closing connection to server (172.31.8.153:1514/tcp).
2022/08/17 19:29:57 wazuh-agent: INFO: Trying to connect to server (172.31.8.153:1514/tcp).
2022/08/17 19:29:57 wazuh-agent: WARNING: Process locked due to agent is offline. Waiting for connection...
2022/08/17 19:29:59 wazuh-agent: ERROR: (1216): Unable to connect to '172.31.8.153:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:30:09 wazuh-agent: INFO: Trying to connect to server (172.31.8.153:1514/tcp).
2022/08/17 19:30:11 wazuh-agent: ERROR: (1216): Unable to connect to '172.31.8.153:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:30:21 wazuh-agent: INFO: Trying to connect to server (172.31.8.153:1514/tcp).
2022/08/17 19:30:24 wazuh-agent: ERROR: (1216): Unable to connect to '172.31.8.153:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:30:34 wazuh-agent: INFO: Trying to connect to server (172.31.8.153:1514/tcp).
2022/08/17 19:30:36 wazuh-agent: ERROR: (1216): Unable to connect to '172.31.8.153:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:30:46 wazuh-agent: INFO: Trying to connect to server (172.31.8.153:1514/tcp).
2022/08/17 19:30:48 wazuh-agent: ERROR: (1216): Unable to connect to '172.31.8.153:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:30:48 wazuh-agent: INFO: Requesting a key from server: 172.31.8.153
2022/08/17 19:30:50 wazuh-agent: ERROR: (1208): Unable to connect to the Auth service at '172.31.8.153:1515'.
2022/08/17 19:31:00 wazuh-agent: WARNING: (4101): Waiting for server reply (not started). Tried: '172.31.8.153'.
2022/08/17 19:31:00 wazuh-agent: WARNING: Unable to connect to any server.
2022/08/17 19:31:00 wazuh-agent: INFO: Trying to connect to server (172.31.7.250:1514/tcp).
2022/08/17 19:31:00 wazuh-agent: INFO: (4102): Connected to the server (172.31.7.250:1514/tcp).
2022/08/17 19:31:00 wazuh-agent: INFO: Server responded. Releasing lock.

Results on 4.4.0

Stop manager1 with agent connected - agent connects to manager2 🟢

  • Start 4.4.0 Agent
    imagen

  • Stop manager1

    # /var/ossec/bin/wazuh-control stop
Killing wazuh-clusterd...
Killing wazuh-modulesd...
Killing wazuh-monitord...
Killing wazuh-logcollector...
Killing wazuh-remoted...
Killing wazuh-syscheckd...
Killing wazuh-analysisd...
wazuh-maild not running...
Killing wazuh-execd...
Killing wazuh-db...
Killing wazuh-authd...
wazuh-agentlessd not running...
wazuh-integratord not running...
wazuh-dbd not running...
wazuh-csyslogd not running...
Killing wazuh-apid...
Wazuh v4.3.7 Stopped

  • Check the agent's logs

    
2022/08/17 19:53:44 wazuh-agent: INFO: (6012): Real-time file integrity monitoring started.
2022/08/17 19:53:48 wazuh-agent: ERROR: (1137): Lost connection with manager. Setting lock.
2022/08/17 19:53:48 wazuh-agent: INFO: Closing connection to server ([172.31.7.250]:1514/tcp).
2022/08/17 19:53:48 wazuh-agent: INFO: Trying to connect to server ([172.31.7.250]:1514/tcp).
2022/08/17 19:53:48 wazuh-agent: WARNING: Process locked due to agent is offline. Waiting for connection...
2022/08/17 19:53:50 wazuh-agent: ERROR: (1216): Unable to connect to '[172.31.7.250]:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:53:59 wazuh-agent: WARNING: Process locked due to agent is offline. Waiting for connection...
2022/08/17 19:54:00 wazuh-agent: INFO: Trying to connect to server ([172.31.7.250]:1514/tcp).
2022/08/17 19:54:02 wazuh-agent: ERROR: (1216): Unable to connect to '[172.31.7.250]:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:54:06 wazuh-agent: WARNING: Process locked due to agent is offline. Waiting for connection...
2022/08/17 19:54:09 wazuh-agent: WARNING: Process locked due to agent is offline. Waiting for connection...
2022/08/17 19:54:12 wazuh-agent: INFO: Trying to connect to server ([172.31.7.250]:1514/tcp).
2022/08/17 19:54:14 wazuh-agent: ERROR: (1216): Unable to connect to '[172.31.7.250]:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:54:24 wazuh-agent: INFO: Trying to connect to server ([172.31.7.250]:1514/tcp).
2022/08/17 19:54:27 wazuh-agent: ERROR: (1216): Unable to connect to '[172.31.7.250]:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:54:37 wazuh-agent: INFO: Trying to connect to server ([172.31.7.250]:1514/tcp).
2022/08/17 19:54:39 wazuh-agent: ERROR: (1216): Unable to connect to '[172.31.7.250]:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:54:39 wazuh-agent: INFO: Requesting a key from server: 172.31.7.250
2022/08/17 19:54:41 wazuh-agent: ERROR: (1208): Unable to connect to enrollment service at '[172.31.7.250]:1515'
2022/08/17 19:54:51 wazuh-agent: WARNING: (4101): Waiting for server reply (not started). Tried: '172.31.7.250'.
2022/08/17 19:54:51 wazuh-agent: INFO: Trying next server ip in the line: '172.31.8.153'.
2022/08/17 19:54:51 wazuh-agent: INFO: Trying to connect to server ([172.31.8.153]:1514/tcp).
2022/08/17 19:54:51 wazuh-agent: INFO: (4102): Connected to the server ([172.31.8.153]:1514/tcp).
2022/08/17 19:54:51 wazuh-agent: INFO: Server responded. Releasing lock.
2022/08/17 19:54:51 wazuh-agent: INFO: Agent is now online. Process unlocked, continuing...
Stop manager2 with agent connected - agent connects to manager1 🟢

  • Stop manager2

    # /var/ossec/bin/wazuh-control stop
Killing wazuh-clusterd...
Killing wazuh-modulesd...
Killing wazuh-monitord...
Killing wazuh-logcollector...
Killing wazuh-remoted...
Killing wazuh-syscheckd...
Killing wazuh-analysisd...
wazuh-maild not running...
Killing wazuh-execd...
Killing wazuh-db...
Killing wazuh-authd...
wazuh-agentlessd not running...
wazuh-integratord not running...
wazuh-dbd not running...
wazuh-csyslogd not running...
Killing wazuh-apid...
Wazuh v4.3.7 Stopped

  • Check the agent's logs for agent connecting to manager1 node.

    2022/08/17 19:54:54 wazuh-agent: INFO: Agent is now online. Process unlocked, continuing...
2022/08/17 19:56:45 wazuh-agent: ERROR: (1137): Lost connection with manager. Setting lock.
2022/08/17 19:56:45 wazuh-agent: INFO: Closing connection to server ([172.31.8.153]:1514/tcp).
2022/08/17 19:56:45 wazuh-agent: INFO: Trying to connect to server ([172.31.8.153]:1514/tcp).
2022/08/17 19:56:45 wazuh-agent: WARNING: Process locked due to agent is offline. Waiting for connection...
2022/08/17 19:56:46 wazuh-agent: WARNING: Process locked due to agent is offline. Waiting for connection...
2022/08/17 19:56:47 wazuh-agent: ERROR: (1216): Unable to connect to '[172.31.8.153]:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:56:57 wazuh-agent: INFO: Trying to connect to server ([172.31.8.153]:1514/tcp).
2022/08/17 19:56:59 wazuh-agent: ERROR: (1216): Unable to connect to '[172.31.8.153]:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:57:09 wazuh-agent: INFO: Trying to connect to server ([172.31.8.153]:1514/tcp).
2022/08/17 19:57:11 wazuh-agent: ERROR: (1216): Unable to connect to '[172.31.8.153]:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:57:21 wazuh-agent: INFO: Trying to connect to server ([172.31.8.153]:1514/tcp).
2022/08/17 19:57:23 wazuh-agent: ERROR: (1216): Unable to connect to '[172.31.8.153]:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:57:33 wazuh-agent: INFO: Trying to connect to server ([172.31.8.153]:1514/tcp).
2022/08/17 19:57:35 wazuh-agent: ERROR: (1216): Unable to connect to '[172.31.8.153]:1514/tcp': 'No connection could be made because the target machine actively refused it.'.
2022/08/17 19:57:35 wazuh-agent: INFO: Requesting a key from server: 172.31.8.153
2022/08/17 19:57:37 wazuh-agent: ERROR: (1208): Unable to connect to enrollment service at '[172.31.8.153]:1515'
2022/08/17 19:57:47 wazuh-agent: WARNING: (4101): Waiting for server reply (not started). Tried: '172.31.8.153'.
2022/08/17 19:57:47 wazuh-agent: WARNING: Unable to connect to any server.
2022/08/17 19:57:47 wazuh-agent: INFO: Trying to connect to server ([172.31.7.250]:1514/tcp).
2022/08/17 19:57:47 wazuh-agent: INFO: (4102): Connected to the server ([172.31.7.250]:1514/tcp).
2022/08/17 19:57:47 wazuh-agent: INFO: Server responded. Releasing lock.
2022/08/17 19:57:50 wazuh-agent: INFO: Agent is now online. Process unlocked, continuing...

@jmv74211
Copy link
Contributor Author

🟢 Everything seems to be working properly, therefore, the failure detected by the test was a false positive. This will be investigated in #3183

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@Deblintrake09 Deblintrake09

Labels
dev-testing
Projects
None yet
Milestone
Release 4.3.7 RC-1
Development

No branches or pull requests
2 participants
@Deblintrake09 @jmv74211