Agents constantly changing ID's and losing assigned groups

[David Hayler]

Hi,

I am wondering if you can help me, or at least explain what might be happening.

we have  consistently seen our registered agents change id numbers and lose its assigned groups, we also see:

09:09:04 ossec-authd: INFO: New connection from 192.168.0.172

09:09:06 ossec-authd: INFO: Received request for a new agent (test-instance) from: 192.168.0.172

09:13:03 ossec-authd: INFO: Duplicated name 'test-instance' (619). Removing old agent.

09:13:03 ossec-authd: INFO: Agent key generated for 'test-instance' (requested by any)

in the logs for all of our agents, which seems to indicate the agent is constantly re-registering?

this is a problem for us because we have defined our own rulesets for instances, but each day we seem to see the instances that have been assigned to each group drop out and are back in the "default" group.

we have around 60 agents, but our current "highest" ID number is 1085, which means each agent has re-registered approx. 18 times each so far. I am aware there is an upper limit to the agent number (8 digits I believe?) and with the constant re-registering we will eventually hit this upper limit.

Regards

David

[jeremias...@wazuh.com]

Hi David,

As you may know, Wazuh doesn´t allow agents with duplicated names.

Probably your agents are re-registering because two or more of your agents share the same name (test_instance).

So, the first one registers and communicates, after that, the second agent registers with the same name replacing the first one. As the first one loses its keys, it will request a new one, replacing the second agent. And they will be in a loop replacing each other constantly.

This issue is targeted in this issue.

By default, Wazuh Agent uses the host name as the agent name. So you can modify the host name of your agents, or, you can specify the name of the agent in the ossec.conf file with a section like this:

<client>

  <enrollment>

    <agent_name>agent</agent_name>

  </enrollment>

</client>

You can check for other enrollment configurations here

It exists another possibility, but usually are isolated cases and not as constant as you mention. This other possibility is targeted in this issue , but again, it doesn't look to be your scenario. As you may see, this last issue is closed because Wazuh 4.2 already has a feature that prevents that behavior

On the other hand: Yes Wazuh can handle Agent Ids with 8 digits or less. Here is the  issue  that reflects this.

Let me know if this was the problem.
Any further doubt please don´t hesitate to ask.
Best regards.

[David Hayler]

Hi,

Thanks for your prompt response, i can confirm we do NOT have duplicate hostnames in our environment, we assign unique hostnames to each machine when they are initially built so this cannot be our issue.

is there a process we can use to debug this issue? can we enable verbosity to see exactly what is happening when the agent registers/re-registers?

Regards

David

[jeremias...@wazuh.com]

Yes, we can enable DEBUG logs, can you:

• Enable DEBUG logs in the manager for authd and remoted:
  • Add the following lines into managers's /var/ossec/etc/local_internal_options.conf
    
    remoted.debug=2
    

    authd.debug=2
    
• Enable DEBUG logs in one of the agents that re-register:
  • Add the following lines into agent's /var/ossec/etc/local_internal_options.conf
    
    agentd.debug=2
• Collect and share with us /var/ossec/logs/ossec.log from the manager and the agent.
  
• A few questions:
  
  • Which Wazuh version are you using in you manager and agents?
  • Did you noticed network issues that may cause agents disconnections?
    
  • Are you using a unique manager or a cluster environment?
    
  • Do you have any custom implementation that handles the agents keys? (like a script that periodically modifies /var/ossec/etc/client.keys)

With this information we can investigate what could be happening.
Best regards.

[charl...@gmail.com]

Hi!

See below my issue:

https://groups.google.com/g/wazuh/c/FE6z3OUS0e4/m/wNeQzOTVAgAJ

Have the same issue basically, for me it's the deployment method, SCCM. Perhaps its similar for you?

Regards,

Charl

[David Hayler]

Hi,

to answer your questions:

manager version 4.15

last registered agent version 4.2.2

we are not experiencing any network related issues, however user laptops will be offline for around 12 hours (overnight).

we are using a single node setup, with all required services (Elasticsearch, Kibana, wazuh-manager) all running on the same instance.
we have NO custom implementations other than rulesets applied to groups.

is it possible to only enable debug on the manager? as previously stated we have 60 agents and i am unsure which agents will re-register and when (the assumption is they will ALL eventually re-register but unsure what mechanism causes it so i would probably have to enable debug on ALL agents)

i will collect logs from manager to start and report back ASAP, thanks.

Regards,

David

[David Hayler]

Hi,

unfortunately no we are installing manually (scripted install on ubuntu, manual on windows) and our .db files seem at a reasonable size (largest is 32mb)

thanks

David

[jeremias...@wazuh.com]

Hello David, 
Probably, with the manager logs will be enough.
But, maybe this is related with your problem:
You mention that your agents version is 4.2.2 while your manager version is 4.15 (I assume it's 4.1.5 with just a typo, right?)
If this is the case, you must always use a Manager version newer or equal to the agents version, here is a link to the documentation with the compatibility matrix.

In example:
Wazuh 4.2.2 has a new feature that solves this related issue. This feature is implemented on both agent and manager sides, but it's assumed the rule of always having manager >= agents.

Beside this particular problem, I suggest you to upgrade your manager, and of course, as soon as you have the manager logs, we can take a look at them.
Best regards.

[David Hayler]

Hi, 

thanks for your response, just to confirm we do have agents on other versions, but I was unable to edit my response to you to update this fact.

we have agents on 4.1.5, 4.2.0, 4.2.1 and 4.2.2. but I shall try upgrading the manager and agents to the same version as per your advice.

Will report back ASAP

regards

David

[jeremias...@wazuh.com]

Hello David,
To be more precise:
The feature that I mention in 4.2.2 improves the control to avoid agents re-registering when the manager is starting or there are temporary network issues.
It adds a control in the manager and the agent, and eliminates the old control that has some problems.
Having an old manager with a new agent, there are none of the controls. So, it's expected to experience what you observed.
Let me know how it goes after the upgrade.
Best regards.

[David Hayler]

Hello again,

after leaving Wazuh for a few days we have again noticed  multiple agents are losing the assigned groups, I have tried to collect the relevant parts of the logs for a single agent, if you have a command that might grep more succinctly that would be helpful.

2021/10/17 08:58:39 wazuh-remoted[1582] manager.c:1058 at lookfor_agent_group(): DEBUG: Agent '1045' group is 'UbuntuHardening,Servers'

2021/10/17 09:00:38 wazuh-remoted[1582] secure.c:339 at close_fp_main(): DEBUG: Checking rids_node of agent 1045.

2021/10/17 09:00:38 wazuh-remoted[1582] secure.c:343 at close_fp_main(): DEBUG: Pop rids_node of agent 1045.

2021/10/17 09:00:38 wazuh-remoted[1582] secure.c:345 at close_fp_main(): DEBUG: Closing rids for agent 1045.

2021/10/17 09:12:12 wazuh-authd[1490] auth.c:254 at w_auth_validate_data(): INFO: Duplicate name 'a-test-instance' (1045).

2021/10/17 09:12:12 wazuh-authd[1490] auth.c:216 at w_auth_replace_agent(): INFO: Removing old agent '1045'.

2021/10/17 09:12:12 wazuh-authd[1490] main-server.c:873 at run_writer(): DEBUG: [Writer] Performing delete([1045] a-test-instance).

2021/10/17 09:12:13 wazuh-authd[1490] validate.c:727 at OS_RemoveAgentGroup(): DEBUG: At OS_RemoveAgentGroup(): Could not open file 'queue/agent-groups/1045'

2021/10/17 09:12:23 wazuh-modulesd:vulnerability-detector: INFO: (5450): Analyzing agent '1045' vulnerabilities.

09:12:12 wazuh-authd[1490] main-server.c:592 at run_dispatcher(): INFO: New connection from 192.168.0.175

2021/10/17 09:12:12 wazuh-authd[1490] main-server.c:625 at run_dispatcher(): DEBUG: Request received: <OSSEC A:'a-test-machine'

2021/10/17 09:12:12 wazuh-authd[1490] auth.c:101 at w_auth_parse_data(): INFO: Received request for a new agent (a-test-machine) from: 192.168.0.175

2021/10/17 09:12:12 wazuh-authd[1490] auth.c:254 at w_auth_validate_data(): INFO: Duplicate name 'a-test-machine' (1045).

2021/10/17 09:12:12 wazuh-authd[1490] auth.c:216 at w_auth_replace_agent(): INFO: Removing old agent '1045'.

2021/10/17 09:12:12 wazuh-authd[1490] main-server.c:654 at run_dispatcher(): INFO: Agent key generated for 'a-test-machine' (requested by any)

2021/10/17 09:12:12 wazuh-authd[1490] main-server.c:808 at run_writer(): DEBUG: Dumping changes into disk.

2021/10/17 09:12:12 wazuh-authd[1490] main-server.c:829 at run_writer(): DEBUG: [Writer] OS_WriteKeys(): 604 µs.

2021/10/17 09:12:12 wazuh-authd[1490] main-server.c:838 at run_writer(): DEBUG: [Writer] OS_WriteTimestamps(): 436 µs.

2021/10/17 09:12:12 wazuh-authd[1490] main-server.c:846 at run_writer(): DEBUG: [Writer] Performing insert([1097] a-test-machine).

2021/10/17 09:12:12 wazuh-authd[1490] main-server.c:857 at run_writer(): DEBUG: [Writer] set_agent_group(): 681 µs.

2021/10/17 09:12:12 wazuh-authd[1490] main-server.c:873 at run_writer(): DEBUG: [Writer] Performing delete([1045] a-test-machine).

2021/10/17 09:12:12 wazuh-authd[1490] main-server.c:846 at run_writer(): DEBUG: [Writer] Performing insert([1097] a-test-machine).

2021/10/17 09:12:33 wazuh-remoted[1582] agent_op.c:276 at get_agent_group(): DEBUG: At get_agent_group(): file 'queue/agent-groups/1097' not found.

2021/10/17 09:12:33 wazuh-remoted[1582] manager.c:1058 at lookfor_agent_group(): DEBUG: Agent '1097' group is ''

2021/10/17 09:12:33 wazuh-remoted[1582] manager.c:1110 at lookfor_agent_group(): DEBUG: Agent '1097' with group '' file 'merged.mg' MD5 'f6de615537949074ff84b6cc73883af0'

2021/10/17 09:12:33 wazuh-remoted[1582] manager.c:1213 at read_controlmsg(): DEBUG: Sending file 'default/merged.mg' to agent '1097'.

2021/10/17 09:12:33 wazuh-remoted[1582] ar-forward.c:40 at AR_Forward(): DEBUG: Active response request received: (msg_to_agent) [] N!S 1097 fim_file dbsync no_data {"id":1634457848,"version":2,"begin":"/bin/bash","end":"/usr/sbin/zic"}

2021/10/17 09:12:33 wazuh-remoted[1582] msgs.c:194 at StoreCounter(): DEBUG: Opening rids for agent 1097.

2021/10/17 09:12:33 wazuh-remoted[1582] msgs.c:204 at StoreCounter(): DEBUG: Pushing rids_node for agent 1097.

2021/10/17 09:12:33 wazuh-remoted[1582] msgs.c:207 at StoreCounter(): DEBUG: Updating rids_node for agent 1097.

2021/10/17 09:12:33 wazuh-remoted[1582] manager.c:1229 at read_controlmsg(): DEBUG: End sending file 'default/merged.mg' to agent '1097'.

2021/10/17 09:12:33 wazuh-remoted[1582] msgs.c:207 at StoreCounter(): DEBUG: Updating rids_node for agent 1097.

2021/10/17 09:12:33 wazuh-remoted[1582] msgs.c:207 at StoreCounter(): DEBUG: Updating rids_node for agent 1097.

2021/10/17 09:12:34 wazuh-remoted[1582] sendmsg.c:124 at send_msg(): DEBUG: (1218): Unable to send message to '1097': Agent may have disconnected. [11]

2021/10/17 09:12:39 wazuh-remoted[1582] manager.c:1058 at lookfor_agent_group(): DEBUG: Agent '1097' group is 'default'

this agent is running Wazuh v4.2.1

Regards

David

[David Hayler]

apologies, a-test-instance and a-test-machine are the same machine, i typo'ed whilst sanitising the output!

Regards
David

[jeremias...@wazuh.com]

Hi David, sorry for the late response.

Let me confirm:

- Have you updated Wazuh Manager with a version greater or equal to the agents' version (4.2.2)?

- We will need the complete manager log to identify what was happening during the agent re-registration.

- If possible, the agent log, even without DEBUG level, will be useful too.

- Regarding the grep command: In this case, the complete log file will be more consistent because any information could be useful.

Let me highlight again that a manager older than the agents will present the following problem and must be updated.

Regards.

[David Hayler]

Hi,

wazuh manager is now on version:  v4.2.3

the complete log from wazuh-manager is 329MB which i would need to sanitise 1st, obviously it wont be possible to supply this file.

However the ossec log for the 17th (date mentioned in last post) is only 15MB but this still seems too large to sanitise and upload.

if there is any way we could use grep to output the logs you require that would be most helpful.

here is the output from the agent which seems to match the date/timestamp of the logs i previously supplied. note the hostname has been sanitised to CLIENT-HOSTNAME and the server IP has been sanitised to SERVER-IP:

2021/10/17 00:00:10 wazuh-agentd: INFO: Starting new log after rotation.

2021/10/17 00:44:20 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 00:44:20 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 01:43:18 sca: INFO: Starting Security Configuration Assessment scan.

2021/10/17 01:43:18 sca: INFO: Starting evaluation of policy: '/var/ossec/ruleset/sca/cis_debian10.yml'

2021/10/17 01:43:57 sca: INFO: Evaluation finished for policy '/var/ossec/ruleset/sca/cis_debian10.yml'

2021/10/17 01:43:57 sca: WARNING: Found duplicated check ID: 2500. First appearance at policy 'cis_debian10'

2021/10/17 01:43:57 sca: WARNING: Error found while validating policy file: '/var/ossec/etc/shared/hardening.yml'. Skipping it.

2021/10/17 01:43:57 sca: INFO: Security Configuration Assessment scan finished. Duration: 39 seconds.

2021/10/17 01:44:21 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 01:44:21 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 01:44:45 wazuh-syscheckd: INFO: (6008): File integrity monitoring scan started.

2021/10/17 01:44:54 wazuh-syscheckd: INFO: (6009): File integrity monitoring scan ended.

2021/10/17 01:45:37 rootcheck: INFO: Starting rootcheck scan.

2021/10/17 01:45:37 rootcheck: ERROR: No rootcheck_files file: 'etc/shared/rootkit_files.txt'

2021/10/17 01:45:37 rootcheck: ERROR: No rootcheck_trojans file: 'etc/shared/rootkit_trojans.txt'

2021/10/17 01:46:05 rootcheck: INFO: Ending rootcheck scan.

2021/10/17 02:44:22 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 02:44:23 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 03:44:23 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 03:44:24 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 04:44:24 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 04:44:25 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 05:44:26 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 05:44:26 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 06:44:27 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 06:44:27 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 07:24:07 wazuh-agentd: WARNING: Server unavailable. Setting lock.

2021/10/17 07:24:07 wazuh-agentd: INFO: Closing connection to server (SERVER-IP:1514/tcp).

2021/10/17 07:24:07 wazuh-agentd: INFO: Trying to connect to server (SERVER-IP:1514/tcp).

2021/10/17 07:24:47 wazuh-agentd: INFO: (4102): Connected to the server (SERVER-IP:1514/tcp).

2021/10/17 07:24:47 wazuh-agentd: INFO: Server responded. Releasing lock.

2021/10/17 07:44:28 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 07:44:28 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 08:44:29 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 08:44:29 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 08:59:40 wazuh-agentd: WARNING: Server unavailable. Setting lock.

2021/10/17 08:59:40 wazuh-agentd: INFO: Closing connection to server (SERVER-IP:1514/tcp).

2021/10/17 08:59:40 wazuh-agentd: INFO: Trying to connect to server (SERVER-IP:1514/tcp).

2021/10/17 09:00:03 wazuh-logcollector: WARNING: Process locked due to agent is offline. Waiting for connection...

2021/10/17 09:00:50 wazuh-agentd: INFO: Closing connection to server (SERVER-IP:1514/tcp).

2021/10/17 09:00:50 wazuh-agentd: INFO: Trying to connect to server (SERVER-IP:1514/tcp).

2021/10/17 09:02:00 wazuh-agentd: INFO: Closing connection to server (SERVER-IP:1514/tcp).

2021/10/17 09:02:00 wazuh-agentd: INFO: Trying to connect to server (SERVER-IP:1514/tcp).

2021/10/17 09:03:10 wazuh-agentd: INFO: Closing connection to server (SERVER-IP:1514/tcp).

2021/10/17 09:03:10 wazuh-agentd: INFO: Trying to connect to server (SERVER-IP:1514/tcp).

2021/10/17 09:04:08 wazuh-syscheckd: WARNING: Process locked due to agent is offline. Waiting for connection...

2021/10/17 09:04:20 wazuh-agentd: INFO: Closing connection to server (SERVER-IP:1514/tcp).

2021/10/17 09:04:20 wazuh-agentd: INFO: Trying to connect to server (SERVER-IP:1514/tcp).

2021/10/17 09:06:20 wazuh-agentd: WARNING: Polling server 'SERVER-IP' failed. Skipping enrollment.

2021/10/17 09:06:30 wazuh-agentd: WARNING: (4101): Waiting for server reply (not started). Tried: 'SERVER-IP'.

2021/10/17 09:06:30 wazuh-agentd: WARNING: Unable to connect to any server.

2021/10/17 09:06:30 wazuh-agentd: INFO: Closing connection to server (SERVER-IP:1514/tcp).

2021/10/17 09:06:30 wazuh-agentd: INFO: Trying to connect to server (SERVER-IP:1514/tcp).

2021/10/17 09:07:40 wazuh-agentd: INFO: Closing connection to server (SERVER-IP:1514/tcp).

2021/10/17 09:07:40 wazuh-agentd: INFO: Trying to connect to server (SERVER-IP:1514/tcp).

2021/10/17 09:08:50 wazuh-agentd: INFO: Closing connection to server (SERVER-IP:1514/tcp).

2021/10/17 09:08:50 wazuh-agentd: INFO: Trying to connect to server (SERVER-IP:1514/tcp).

2021/10/17 09:10:00 wazuh-agentd: INFO: Closing connection to server (SERVER-IP:1514/tcp).

2021/10/17 09:10:00 wazuh-agentd: INFO: Trying to connect to server (SERVER-IP:1514/tcp).

2021/10/17 09:11:10 wazuh-agentd: INFO: Closing connection to server (SERVER-IP:1514/tcp).

2021/10/17 09:11:10 wazuh-agentd: INFO: Trying to connect to server (SERVER-IP:1514/tcp).

2021/10/17 09:12:12 wazuh-agentd: INFO: Requesting a key from server: SERVER-IP

2021/10/17 09:12:12 wazuh-agentd: INFO: No authentication password provided

2021/10/17 09:12:12 wazuh-agentd: INFO: Using agent name as: CLIENT-HOSTNAME

2021/10/17 09:12:12 wazuh-agentd: INFO: Waiting for server reply

2021/10/17 09:12:12 wazuh-agentd: INFO: Valid key received

2021/10/17 09:12:12 wazuh-agentd: INFO: Waiting 20 seconds before server connection

2021/10/17 09:12:32 wazuh-agentd: INFO: (1410): Reading authentication keys file.

2021/10/17 09:12:32 wazuh-agentd: INFO: Closing connection to server (SERVER-IP:1514/tcp).

2021/10/17 09:12:32 wazuh-agentd: INFO: Trying to connect to server (SERVER-IP:1514/tcp).

2021/10/17 09:12:32 wazuh-agentd: INFO: (4102): Connected to the server (SERVER-IP:1514/tcp).

2021/10/17 09:12:32 wazuh-agentd: INFO: Server responded. Releasing lock.

2021/10/17 09:12:33 wazuh-syscheckd: INFO: Agent is now online. Process unlocked, continuing...

2021/10/17 09:12:33 wazuh-logcollector: INFO: Agent is now online. Process unlocked, continuing...

2021/10/17 09:12:33 wazuh-agentd: INFO: Agent is restarting due to shared configuration changes.

2021/10/17 09:12:33 wazuh-modulesd:syscollector: INFO: Stop received for Syscollector.

2021/10/17 09:12:33 wazuh-modulesd:syscollector: INFO: Module finished.

2021/10/17 09:12:33 wazuh-logcollector: INFO: (1225): SIGNAL [(15)-(Terminated)] Received. Exit Cleaning...

2021/10/17 09:12:34 wazuh-syscheckd: INFO: (1225): SIGNAL [(15)-(Terminated)] Received. Exit Cleaning...

2021/10/17 09:12:34 wazuh-agentd: INFO: (1225): SIGNAL [(15)-(Terminated)] Received. Exit Cleaning...

2021/10/17 09:12:34 wazuh-execd: INFO: (1314): Shutdown received. Deleting responses.

2021/10/17 09:12:34 wazuh-execd: INFO: (1225): SIGNAL [(15)-(Terminated)] Received. Exit Cleaning...

2021/10/17 09:12:34 wazuh-execd: INFO: Started (pid: 4159071).

2021/10/17 09:12:35 wazuh-agentd: INFO: (1410): Reading authentication keys file.

2021/10/17 09:12:35 wazuh-agentd: INFO: Using notify time: 10 and max time to reconnect: 60

2021/10/17 09:12:35 wazuh-agentd: INFO: Version detected -> Linux |CLIENT-HOSTNAME |5.4.0-81-generic |#91-Ubuntu SMP Thu Jul 15 19:09:17 UTC 2021 |x86_64 [Ubuntu|ubuntu: 20.04.3 LTS (Focal Fossa)] - Wazuh v4.2.1

2021/10/17 09:12:35 wazuh-agentd: INFO: Started (pid: 4159082).

2021/10/17 09:12:35 wazuh-agentd: INFO: Server IP Address: SERVER-IP

2021/10/17 09:12:35 wazuh-agentd: INFO: Using AES as encryption method.

2021/10/17 09:12:35 wazuh-agentd: INFO: Trying to connect to server (SERVER-IP:1514/tcp).

2021/10/17 09:12:36 wazuh-syscheckd: INFO: Started (pid: 4159095).

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6003): Monitoring path: '/bin', with options 'size | permissions | owner | group | mtime | inode | hash_md5 | hash_sha1 | hash_sha256 | scheduled'.

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6003): Monitoring path: '/boot', with options 'size | permissions | owner | group | mtime | inode | hash_md5 | hash_sha1 | hash_sha256 | scheduled'.

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6003): Monitoring path: '/etc', with options 'size | permissions | owner | group | mtime | inode | hash_md5 | hash_sha1 | hash_sha256 | scheduled'.

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6003): Monitoring path: '/sbin', with options 'size | permissions | owner | group | mtime | inode | hash_md5 | hash_sha1 | hash_sha256 | scheduled'.

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6003): Monitoring path: '/usr/bin', with options 'size | permissions | owner | group | mtime | inode | hash_md5 | hash_sha1 | hash_sha256 | scheduled'.

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6003): Monitoring path: '/usr/sbin', with options 'size | permissions | owner | group | mtime | inode | hash_md5 | hash_sha1 | hash_sha256 | scheduled'.

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6206): Ignore 'file' entry '/etc/mtab'

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6206): Ignore 'file' entry '/etc/hosts.deny'

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6206): Ignore 'file' entry '/etc/mail/statistics'

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6206): Ignore 'file' entry '/etc/random-seed'

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6206): Ignore 'file' entry '/etc/random.seed'

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6206): Ignore 'file' entry '/etc/adjtime'

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6206): Ignore 'file' entry '/etc/httpd/logs'

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6206): Ignore 'file' entry '/etc/utmpx'

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6206): Ignore 'file' entry '/etc/wtmpx'

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6206): Ignore 'file' entry '/etc/cups/certs'

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6206): Ignore 'file' entry '/etc/dumpdates'

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6206): Ignore 'file' entry '/etc/svc/volatile'

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6207): Ignore 'file' sregex '.log$|.swp$'

2021/10/17 09:12:36 wazuh-syscheckd: INFO: (6004): No diff for file: '/etc/ssl/private.key'

2021/10/17 09:12:37 wazuh-agentd: INFO: (4102): Connected to the server (SERVER-IP:1514/tcp).

2021/10/17 09:12:37 wazuh-logcollector: INFO: Monitoring output of command(360): df -P

2021/10/17 09:12:37 wazuh-logcollector: INFO: Monitoring full output of command(360): netstat -tulpn | sed 's/\([[:alnum:]]\+\)\ \+[[:digit:]]\+\ \+[[:digit:]]\+\ \+\(.*\):\([[:digit:]]*\)\ \+\([0-9\.\:\*]\+\).\+\ \([[:digit:]]*\/[[:alnum:]\-]*\).*/\1 \2 == \3 == \4 \5/' | sort -k 4 -g | sed 's/ == \(.*\) ==/:\1/' | sed 1,2d

2021/10/17 09:12:37 wazuh-logcollector: INFO: Monitoring full output of command(360): last -n 20

2021/10/17 09:12:37 wazuh-logcollector: INFO: (1950): Analyzing file: '/var/log/apache2/error.log'.

2021/10/17 09:12:37 wazuh-logcollector: INFO: (1950): Analyzing file: '/var/log/apache2/access.log'.

2021/10/17 09:12:37 wazuh-logcollector: INFO: (1950): Analyzing file: '/var/ossec/logs/active-responses.log'.

2021/10/17 09:12:37 wazuh-logcollector: INFO: (1950): Analyzing file: '/var/log/auth.log'.

2021/10/17 09:12:37 wazuh-logcollector: INFO: (1950): Analyzing file: '/var/log/syslog'.

2021/10/17 09:12:37 wazuh-logcollector: ERROR: (1103): Could not open file '/var/log/squid/access.log' due to [(2)-(No such file or directory)].

2021/10/17 09:12:37 wazuh-logcollector: INFO: (1950): Analyzing file: '/var/log/squid/access.log'.

2021/10/17 09:12:37 wazuh-logcollector: INFO: (1950): Analyzing file: '/var/log/dpkg.log'.

2021/10/17 09:12:37 wazuh-logcollector: INFO: (1950): Analyzing file: '/var/log/kern.log'.

2021/10/17 09:12:37 wazuh-logcollector: INFO: Started (pid: 4159107).

2021/10/17 09:12:38 wazuh-modulesd: INFO: Started (pid: 4159124).

2021/10/17 09:12:38 wazuh-modulesd:agent-upgrade: INFO: (8153): Module Agent Upgrade started.

2021/10/17 09:12:38 wazuh-modulesd:ciscat: INFO: Module disabled. Exiting...

2021/10/17 09:12:38 wazuh-modulesd:osquery: INFO: Module disabled. Exiting...

2021/10/17 09:12:38 sca: INFO: Module started.

2021/10/17 09:12:38 wazuh-modulesd:control: INFO: Starting control thread.

2021/10/17 09:12:38 sca: INFO: Loaded policy '/var/ossec/ruleset/sca/cis_debian10.yml'

2021/10/17 09:12:38 sca: INFO: Starting Security Configuration Assessment scan.

2021/10/17 09:12:38 wazuh-modulesd:syscollector: INFO: Module started.

2021/10/17 09:12:38 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 09:12:38 sca: INFO: Starting evaluation of policy: '/var/ossec/ruleset/sca/cis_debian10.yml'

2021/10/17 09:12:38 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 09:12:41 wazuh-syscheckd: INFO: (6000): Starting daemon...

2021/10/17 09:12:41 wazuh-syscheckd: INFO: (6010): File integrity monitoring scan frequency: 43200 seconds

2021/10/17 09:12:41 wazuh-syscheckd: INFO: (6008): File integrity monitoring scan started.

2021/10/17 09:12:41 rootcheck: INFO: Starting rootcheck scan.

2021/10/17 09:12:50 wazuh-syscheckd: INFO: (6009): File integrity monitoring scan ended.

2021/10/17 09:13:07 rootcheck: INFO: Ending rootcheck scan.

2021/10/17 09:13:17 sca: INFO: Evaluation finished for policy '/var/ossec/ruleset/sca/cis_debian10.yml'

2021/10/17 09:13:17 sca: INFO: Security Configuration Assessment scan finished. Duration: 39 seconds.

2021/10/17 09:13:39 sca: INFO: Integration checksum failed for policy '/var/ossec/ruleset/sca/cis_debian10.yml'. Resending scan results in 147 seconds.

2021/10/17 09:16:15 sca: INFO: Integration checksum failed for policy '/var/ossec/ruleset/sca/cis_debian10.yml'. Resending scan results in 75 seconds.

2021/10/17 09:17:39 sca: INFO: Integration checksum failed for policy '/var/ossec/ruleset/sca/cis_debian10.yml'. Resending scan results in 159 seconds.

2021/10/17 09:21:09 wazuh-logcollector: INFO: (1904): File not available, ignoring it: '/var/log/squid/access.log'.

2021/10/17 10:12:39 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 10:12:40 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 11:12:40 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 11:12:41 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 12:12:41 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 12:12:42 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 13:12:42 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 13:12:43 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 14:12:43 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 14:12:44 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 15:12:45 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 15:12:46 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 16:12:46 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 16:12:47 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 17:12:47 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 17:12:48 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 18:12:48 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 18:12:49 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 19:12:50 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 19:12:50 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 20:12:51 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 20:12:51 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 21:12:38 sca: INFO: Starting Security Configuration Assessment scan.

2021/10/17 21:12:38 sca: INFO: Starting evaluation of policy: '/var/ossec/ruleset/sca/cis_debian10.yml'

2021/10/17 21:12:51 wazuh-syscheckd: INFO: (6008): File integrity monitoring scan started.

2021/10/17 21:12:52 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 21:12:52 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 21:13:08 wazuh-syscheckd: INFO: (6009): File integrity monitoring scan ended.

2021/10/17 21:13:08 rootcheck: INFO: Starting rootcheck scan.

2021/10/17 21:13:17 sca: INFO: Evaluation finished for policy '/var/ossec/ruleset/sca/cis_debian10.yml'

2021/10/17 21:13:17 sca: INFO: Security Configuration Assessment scan finished. Duration: 39 seconds.

2021/10/17 21:13:36 rootcheck: INFO: Ending rootcheck scan.

2021/10/17 22:12:53 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 22:12:53 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/17 23:12:54 wazuh-modulesd:syscollector: INFO: Starting evaluation.

2021/10/17 23:12:54 wazuh-modulesd:syscollector: INFO: Evaluation finished.

2021/10/18 00:00:10 wazuh-agentd: INFO: Running daily rotation of log files.

this agent is on Wazuh v4.2.1

[jeremias...@wazuh.com]

Hello David.
The agent log that you provided perfectly matches the behavior reported in the issue that I shared before.
Having a manager with a version lower than the agent aggravated the scenario. But, having an agent with a version lower than 4.2.2 still allows this problem to occure. Let me explain what issue 8227 is about:
Since Wazuh 4.0, an automated registration mechanism was added. This mechanism asks for new keys when the agent starts without any key, or when the agent fails several times to communicate with the manager.
This last scenario only has to occur when Wazuh Remoted was running and able to respond (to avoid requesting keys just because a network problem or any Remoted issue). To achieve this, a ping logic was introduced to check the availability of Remoted previous asking for a key.
But, it was detected that this mechanism has a time window in which the network problem could be solved right after the connection errors but before the ping. If you check at your agent logs you can observe:
- Several errors to connect with the manager.

- A ping fail at  09:06:20

- More several errors to connect with the manager.

- A succesfull key request (because the ping succeed)

This is the typical behavior of the problem covered in the issue 8227.

In Wazuh 4.2.2 we improved this mechanism eliminating this problem. To use this improvement, you have to upgrade both agent and manager. Because they both have to handle the new mechanism.

Let me know how it goes.
If you have further doubts please don´t hesitate to ask.
Regards.