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

Database error due to failed constraint when syncing agent information #23349

Closed
fdalmaup opened this issue May 8, 2024 · 2 comments
Closed

Database error due to failed constraint when syncing agent information #23349

fdalmaup opened this issue May 8, 2024 · 2 comments
Assignees
@Nicogp
Labels
level/task type/bug Something isn't working

Comments

@fdalmaup
Copy link
Member

fdalmaup commented May 8, 2024 •
edited

Wazuh version Component Install type Install method Platform
v4.8.0-rc1 Wazuh-DB Manager Packages Ubuntu Focal

Description

During #23333, a modification in the src/wazuh_db/schema_global.sql file was found that may be the origin of an error that appears when agents are deleted with the DELETE /agents request and the Agent-info sync tries to synchronize the information between the worker and the master. The request does not directly modify the database to remove the agents, it instead sends a command to the authd process.

ossec.log 
2024/05/08 16:09:28 wazuh-db[142] wdb_parser.c:859 at wdb_parse(): DEBUG: Global query: sync-agent-groups-get {"condition": "sync_status", "set_synced": true, "get_global_hash": true}
2024/05/08 16:09:28 wazuh-db[142] wdb_integrity.c:759 at wdb_get_global_group_hash(): DEBUG: No group hash was found to calculate the global group hash.
2024/05/08 16:09:28 wazuh-db[142] main.c:335 at run_dealer(): DEBUG: New client connected (19).
2024/05/08 16:09:28 wazuh-db[142] wdb_parser.c:859 at wdb_parse(): DEBUG: Global query: sync-agent-info-set [{"id":2,"name":"f03f6fab78d9","ip":"172.26.0.5","os_name":"Ubuntu","os_version":"20.04.6 LTS","os_major":"20","os_minor":"04","os_codename":"Focal Fossa","os_platform":"ubuntu","os_uname":"Linux |f03f6fab78d9 |5.15.0-105-generic |#115~20.04.1-Ubuntu SMP Mon Apr 15 17:33:04 UTC 2024 |x86_64","os_arch":"x86_64","version":"Wazuh v4.8.0","config_sum":"ab73af41699f13fdd81903b5f23d8d00","merged_sum":"4a8724b20dee0124ff9656783c490c4e","manager_host":"f8a7c0e28eb8","node_name":"f8a7c0e28eb8","last_keepalive":1715177363,"connection_status":"active","disconnection_time":0,"group_config_status":"synced","status_code":0,"labels":[{"id":2,"key":"#\"_agent_ip\"","value":"172.26.0.5"},{"id":2,"key":"#\"_manager_hostname\"","value":"f8a7c0e28eb8"},{"id":2,"key":"#\"_node_name\"","value":"f8a7c0e28eb8"},{"id":2,"key":"#\"_wazuh_version\"","value":"Wazuh v4.8.0"}]}]
2024/05/08 16:09:28 wazuh-db[142] wdb.c:1112 at wdb_exec_stmt_silent(): DEBUG: SQL statement execution failed
2024/05/08 16:09:28 wazuh-db[142] wdb_parser.c:5997 at wdb_parse_global_sync_agent_info_set(): DEBUG: Global DB Cannot execute SQL query; err database queue/db/global.db: FOREIGN KEY constraint failed
2024/05/08 16:09:28 wazuh-db[142] main.c:397 at run_worker(): DEBUG: Client 19 disconnected.
@fdalmaup fdalmaup mentioned this issue May 8, 2024
Closed
4 tasks
@havidarou havidarou added type/bug Something isn't working level/task labels May 9, 2024
@Nicogp
Copy link
Member

Nicogp commented May 10, 2024 •
edited

I was able to reproduce the error, but under one condition:
Do the DELETE query DELETE “https://localhost:55000/agents?agents_list=003&status=all&older_than=0s” while the agent is connected, or immediately after stopping it.

The error could be reproduced in 4.8.0-rc1 and 4.7.4, but not in 4.7.3.

4.8.0-rc1

Detele agent:
2024/05/09 18:56:51 INFO: wazuh 127.0.0.1 "DELETE /agents" with parameters {"agents_list": "001", "status": "all", "older_than": "0s"} and body {} done in 0.137s: 200

cluster.log (master):

2024/05/09 18:56:55 DEBUG: [Worker worker01-node] [Main] Command received: b'new_str'
2024/05/09 18:56:55 DEBUG: [Worker worker01-node] [Main] Command received: b'str_upd'
2024/05/09 18:56:55 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_a_w_m'
2024/05/09 18:56:55 INFO: [Worker worker01-node] [Agent-info sync] Starting.
2024/05/09 18:56:55 DEBUG2: [Worker worker01-node] [Agent-info sync] Chunk 1/1: [{"id":1,"name":"LAPTOP-SI21F60O","ip":"192.168.0.4","os_name":"Microsoft Windows 11 Home","os_version":"10.0.22631.3447","os_major":"10","os_minor":"0","os_build":"22631.3447","os_platform":"windows","os_uname":"Microsoft Windows 11 Home","version":"Wazuh v4.7.3","config_sum":"ab73af41699f13fdd81903b5f23d8d00","merged_sum":"d0f51333bf62a0d4dbe082107c77e1a4","manager_host":"vagrant","node_name":"worker01-node","last_keepalive":1715291819,"connection_status":"active","disconnection_time":0,"group_config_status":"synced","status_code":0,"labels":[{"id":1,"key":"#\"_agent_ip\"","value":"192.168.0.4"},{"id":1,"key":"#\"_manager_hostname\"","value":"vagrant"},{"id":1,"key":"#\"_node_name\"","value":"worker01-node"},{"id":1,"key":"#\"_wazuh_version\"","value":"Wazuh v4.7.3"}]}]
2024/05/09 18:56:55 ERROR: [Worker worker01-node] [Agent-info sync] Wazuh-db response for chunk 1/1 was not "ok": Error 2003 - Error in wazuhdb request: Cannot execute Global database query; FOREIGN KEY constraint failed
NoneType: None
2024/05/09 18:56:55 DEBUG: [Worker worker01-node] [Agent-info sync] 0/1 chunks updated in wazuh-db in 0.001s.
2024/05/09 18:56:55 INFO: [Worker worker01-node] [Agent-info sync] Finished in 0.011s. Updated 0 chunks.

ossec.log (master):

2024/05/09 18:56:55 wazuh-db[182880] main.c:335 at run_dealer(): DEBUG: New client connected (25).
2024/05/09 18:56:55 wazuh-db[182880] wdb_parser.c:859 at wdb_parse(): DEBUG: Global query: sync-agent-info-set [{"id":1,"name":"LAPTOP-SI21F60O","ip":"192.168.0.4","os_name":"Microsoft Windows 11 Home","os_version":"10.0.22631.3447","os_major":"10","os_minor":"0","os_build":"22631.3447","os_platform":"windows","os_uname":"Microsoft Windows 11 Home","version":"Wazuh v4.7.3","config_sum":"ab73af41699f13fdd81903b5f23d8d00","merged_sum":"d0f51333bf62a0d4dbe082107c77e1a4","manager_host":"vagrant","node_name":"worker01-node","last_keepalive":1715291819,"connection_status":"active","disconnection_time":0,"group_config_status":"synced","status_code":0,"labels":[{"id":1,"key":"#\"_agent_ip\"","value":"192.168.0.4"},{"id":1,"key":"#\"_manager_hostname\"","value":"vagrant"},{"id":1,"key":"#\"_node_name\"","value":"worker01-node"},{"id":1,"key":"#\"_wazuh_version\"","value":"Wazuh v4.7.3"}]}]
2024/05/09 18:56:55 wazuh-db[182880] wdb.c:1112 at wdb_exec_stmt_silent(): DEBUG: SQL statement execution failed
2024/05/09 18:56:55 wazuh-db[182880] wdb_parser.c:5997 at wdb_parse_global_sync_agent_info_set(): DEBUG: Global DB Cannot execute SQL query; err database queue/db/global.db: FOREIGN KEY constraint failed
2024/05/09 18:56:55 wazuh-db[182880] main.c:397 at run_worker(): DEBUG: Client 25 disconnected.
4.7.4

Detele agent:
2024/05/09 16:32:19 INFO: wazuh 127.0.0.1 "DELETE /agents" with parameters {"agents_list": "004", "status": "all", "older_than": "0s"} and body {} done in 0.018s: 200

cluster.log (master):

2024/05/09 16:32:26 INFO: [Worker worker01-node] [Agent-info sync] Starting.
2024/05/09 16:32:26 DEBUG2: [Worker worker01-node] [Agent-info sync] Chunk 1/1: [{"id":4,"name":"LAPTOP-SI21F60O","ip":"192.168.0.4","os_name":"Microsoft Windows 11 Home","os_version":"10.0.22631.3447","os_major":"10","os_minor":"0","os_build":"22631.3447","os_platform":"windows","os_uname":"Microsoft Windows 11 Home","version":"Wazuh v4.7.3","config_sum":"ab73af41699f13fdd81903b5f23d8d00","merged_sum":"4a8724b20dee0124ff9656783c490c4e","manager_host":"vagrant","node_name":"worker01-node","last_keepalive":1715283133,"connection_status":"disconnected","disconnection_time":1715283140,"group_config_status":"synced","status_code":3,"labels":[{"id":4,"key":"#\"_agent_ip\"","value":"192.168.0.4"},{"id":4,"key":"#\"_manager_hostname\"","value":"vagrant"},{"id":4,"key":"#\"_node_name\"","value":"worker01-node"},{"id":4,"key":"#\"_wazuh_version\"","value":"Wazuh v4.7.3"}]}]
2024/05/09 16:32:26 ERROR: [Worker worker01-node] [Agent-info sync] Wazuh-db response for chunk 1/1 was not "ok": Error 2003 - Error in wazuhdb request: Cannot execute Global database query; FOREIGN KEY constraint failed
NoneType: None
2024/05/09 16:32:26 DEBUG: [Worker worker01-node] [Agent-info sync] 0/1 chunks updated in wazuh-db in 0.001s.
2024/05/09 16:32:26 INFO: [Worker worker01-node] [Agent-info sync] Finished in 0.008s. Updated 0 chunks.

ossec.log (master):

2024/05/09 16:32:26 wazuh-db[45985] main.c:321 at run_dealer(): DEBUG: New client connected (29).
2024/05/09 16:32:26 wazuh-db[45985] wdb_parser.c:868 at wdb_parse(): DEBUG: Global query: sync-agent-info-set [{"id":4,"name":"LAPTOP-SI21F60O","ip":"192.168.0.4","os_name":"Microsoft Windows 11 Home","os_version":"10.0.22631.3447","os_major":"10","os_minor":"0","os_build":"22631.3447","os_platform":"windows","os_uname":"Microsoft Windows 11 Home","version":"Wazuh v4.7.3","config_sum":"ab73af41699f13fdd81903b5f23d8d00","merged_sum":"4a8724b20dee0124ff9656783c490c4e","manager_host":"vagrant","node_name":"worker01-node","last_keepalive":1715283133,"connection_status":"disconnected","disconnection_time":1715283140,"group_config_status":"synced","status_code":3,"labels":[{"id":4,"key":"#\"_agent_ip\"","value":"192.168.0.4"},{"id":4,"key":"#\"_manager_hostname\"","value":"vagrant"},{"id":4,"key":"#\"_node_name\"","value":"worker01-node"},{"id":4,"key":"#\"_wazuh_version\"","value":"Wazuh v4.7.3"}]}]
2024/05/09 16:32:26 wazuh-db[45985] wdb_global.c:355 at wdb_global_set_agent_label(): DEBUG: SQLite: FOREIGN KEY constraint failed
2024/05/09 16:32:26 wazuh-db[45985] wdb_parser.c:5975 at wdb_parse_global_sync_agent_info_set(): DEBUG: Global DB Cannot execute SQL query; err database queue/db/global.db: FOREIGN KEY constraint failed
2024/05/09 16:32:26 wazuh-db[45985] main.c:383 at run_worker(): DEBUG: Client 29 disconnected.

Note: The error could not be reproduced if the agent is stopped prior to the execution of the deletion and waiting a few seconds for the information to be synchronized and marked as disconnected.

Log analysis (4.8.0-rc1 master)

At 18:56:51 the agent is deleted:
2024/05/09 18:56:51 INFO: wazuh 127.0.0.1 "DELETE /agents" with parameters {"agents_list": "001", "status": "all", "older_than": "0s"} and body {} done in 0.137s: 200

In the ossec.log (master) we see how the agent is deleted

2024/05/09 18:56:51 wazuh-authd: INFO: Agent '001' (LAPTOP-SI21F60O) deleted (requested locally)
2024/05/09 18:56:51 wazuh-db[182880] wdb_parser.c:859 at wdb_parse(): DEBUG: Global query: delete-agent 1
2024/05/09 18:56:51 wazuh-db[182880] wdb.c:1475 at wdb_remove_multiple_agents(): DEBUG: Removing db for agent '001'
2024/05/09 18:56:51 wazuh-db[182880] wdb.c:1423 at wdb_remove_database(): DEBUG: (1123): Unable to delete file: 'queue/db/001.db' due to [(2)-(No such file or directory)].
2024/05/09 18:56:51 wazuh-db[182880] wdb.c:1488 at wdb_remove_multiple_agents(): DEBUG: Deleting databases. JSON output: {"agents":{"001":"Can't delete"}}
2024/05/09 18:56:52 wazuh-remoted: INFO: (1409): Authentication file changed. Updating.
2024/05/09 18:56:52 wazuh-remoted: INFO: (1410): Reading authentication keys file.

and then a few seconds later a query “sync-agent-info-set” is received updating data from the previously deleted agent:

2024/05/09 18:56:55 wazuh-db[182880] wdb_parser.c:859 at wdb_parse(): DEBUG: Global query: sync-agent-groups-get {"condition": "sync_status", "set_synced": true, "get_global_hash": true}
2024/05/09 18:56:55 wazuh-db[182880] wdb_integrity.c:759 at wdb_get_global_group_hash(): DEBUG: No group hash was found to calculate the global group hash.
2024/05/09 18:56:55 wazuh-db[182880] main.c:335 at run_dealer(): DEBUG: New client connected (25).
2024/05/09 18:56:55 wazuh-db[182880] wdb_parser.c:859 at wdb_parse(): DEBUG: Global query: sync-agent-info-set [{"id":1,"name":"LAPTOP-SI21F60O","ip":"192.168.0.4","os_name":"Microsoft Windows 11 Home","os_version":"10.0.22631.3447","os_major":"10","os_minor":"0","os_build":"22631.3447","os_platform":"windows","os_uname":"Microsoft Windows 11 Home","version":"Wazuh v4.7.3","config_sum":"ab73af41699f13fdd81903b5f23d8d00","merged_sum":"d0f51333bf62a0d4dbe082107c77e1a4","manager_host":"vagrant","node_name":"worker01-node","last_keepalive":1715291819,"connection_status":"active","disconnection_time":0,"group_config_status":"synced","status_code":0,"labels":[{"id":1,"key":"#\"_agent_ip\"","value":"192.168.0.4"},{"id":1,"key":"#\"_manager_hostname\"","value":"vagrant"},{"id":1,"key":"#\"_node_name\"","value":"worker01-node"},{"id":1,"key":"#\"_wazuh_version\"","value":"Wazuh v4.7.3"}]}]
2024/05/09 18:56:55 wazuh-db[182880] wdb.c:1112 at wdb_exec_stmt_silent(): DEBUG: SQL statement execution failed
2024/05/09 18:56:55 wazuh-db[182880] wdb_parser.c:5997 at wdb_parse_global_sync_agent_info_set(): DEBUG: Global DB Cannot execute SQL query; err database queue/db/global.db: FOREIGN KEY constraint failed
2024/05/09 18:56:55 wazuh-db[182880] main.c:397 at run_worker(): DEBUG: Client 25 disconnected.

here is where the error occurs, because the cluster is trying to insert a label belonging to an agent whose id is no longer in the database because it has been previously deleted, this is due to the new clause REFERENCES agent (id) for the id column of the labels table:
id INTEGER REFERENCES agent (id) ON DELETE CASCADE
which requires that the agent_id must exist, otherwise it will fail with the error we see:
FOREIGN KEY constraint failed

Continuing looking at the cluster logs and it is seen that the error only occurs at that time, then the cluster can complete the synchronization:

cluster.log 
2024/05/09 18:56:55 INFO: [Worker worker01-node] [Agent-info sync] Starting.
2024/05/09 18:56:55 DEBUG2: [Worker worker01-node] [Agent-info sync] Chunk 1/1: [{"id":1,"name":"LAPTOP-SI21F60O","ip":"192.168.0.4","os_name":"Microsoft Windows 11 Home","os_version":"10.0.22631.3447","os_major":"10","os_minor":"0","os_build":"22631.3447","os_platform":"windows","os_uname":"Microsoft Windows 11 Home","version":"Wazuh v4.7.3","config_sum":"ab73af41699f13fdd81903b5f23d8d00","merged_sum":"d0f51333bf62a0d4dbe082107c77e1a4","manager_host":"vagrant","node_name":"worker01-node","last_keepalive":1715291819,"connection_status":"active","disconnection_time":0,"group_config_status":"synced","status_code":0,"labels":[{"id":1,"key":"#\"_agent_ip\"","value":"192.168.0.4"},{"id":1,"key":"#\"_manager_hostname\"","value":"vagrant"},{"id":1,"key":"#\"_node_name\"","value":"worker01-node"},{"id":1,"key":"#\"_wazuh_version\"","value":"Wazuh v4.7.3"}]}]
2024/05/09 18:56:55 ERROR: [Worker worker01-node] [Agent-info sync] Wazuh-db response for chunk 1/1 was not "ok": Error 2003 - Error in wazuhdb request: Cannot execute Global database query; FOREIGN KEY constraint failed
NoneType: None
2024/05/09 18:56:55 DEBUG: [Worker worker01-node] [Agent-info sync] 0/1 chunks updated in wazuh-db in 0.001s.
2024/05/09 18:56:55 INFO: [Worker worker01-node] [Agent-info sync] Finished in 0.011s. Updated 0 chunks.
2024/05/09 18:56:59 INFO: [Master] [Local integrity] Starting.
2024/05/09 18:56:59 INFO: [Master] [Local integrity] Finished in 0.004s. Calculated metadata of 35 files.
2024/05/09 18:57:02 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_p'
2024/05/09 18:57:02 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m'
2024/05/09 18:57:02 INFO: [Worker worker01-node] [Integrity check] Starting.
2024/05/09 18:57:02 DEBUG: [Worker worker01-node] [Main] Command received: b'new_file'
2024/05/09 18:57:02 DEBUG: [Worker worker01-node] [Main] Command received: b'file_upd'
2024/05/09 18:57:02 DEBUG: [Worker worker01-node] [Main] Command received: b'file_end'
2024/05/09 18:57:02 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_e'
2024/05/09 18:57:02 DEBUG: [Worker worker01-node] [Integrity check] Received file from worker: '/var/ossec/queue/cluster/worker01-node/worker01-node-1715291828.802602-879bce936367463791c47c80b4b294e2.zip'
2024/05/09 18:57:02 INFO: [Worker worker01-node] [Integrity check] Finished in 0.011s. Received metadata of 35 files. Sync required.
2024/05/09 18:57:02 INFO: [Worker worker01-node] [Integrity sync] Starting.
2024/05/09 18:57:02 INFO: [Worker worker01-node] [Integrity sync] Files to create in worker: 0 | Files to update in worker: 1 | Files to delete in worker: 0
2024/05/09 18:57:02 DEBUG: [Worker worker01-node] [Integrity sync] Compressing files and 'files_metadata.json' of 1 files.
2024/05/09 18:57:02 DEBUG: [Worker worker01-node] [Integrity sync] Sending zip file.
2024/05/09 18:57:02 DEBUG: [Worker worker01-node] [Integrity sync] Zip file sent.
2024/05/09 18:57:02 INFO: [Worker worker01-node] [Integrity sync] Finished in 0.052s.
2024/05/09 18:57:03 DEBUG: [Worker worker01-node] [Main] Command received: b'sendsync'
2024/05/09 18:57:03 DEBUG: [Worker worker01-node] [SendSync] Received request: b'worker01-node*317191 {"daemon_name":"remoted","message":{"command":"assigngroup","parameters":{"agent":"001","md5":"d0f51333bf62a0d4dbe082107c77e1a4"}}}'
2024/05/09 18:57:03 DEBUG: [Master] [SendSync] Receiving SendSync request (remoted) from worker01-node (317191)
2024/05/09 18:57:05 INFO: [Master] [Local agent-groups] Starting.
2024/05/09 18:57:05 DEBUG: [Master] [Local agent-groups] Obtained 1 chunks of data in 0.000s.
2024/05/09 18:57:05 DEBUG2: [Master] [Main] Added broadcast request to execute "send_agent_groups_information" in worker01-node.
2024/05/09 18:57:05 INFO: [Master] [Local agent-groups] Finished in 0.001s.
2024/05/09 18:57:05 INFO: [Worker worker01-node] [Agent-groups send] Starting.
2024/05/09 18:57:05 DEBUG: [Worker worker01-node] [Agent-groups send] Sending chunks.
2024/05/09 18:57:05 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_w_g_e'
2024/05/09 18:57:05 INFO: [Worker worker01-node] [Agent-groups send] Finished in -10799.945s. Updated 1 chunks.
2024/05/09 18:57:05 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_a_w_m_p'
2024/05/09 18:57:07 INFO: [Master] [Local integrity] Starting.
2024/05/09 18:57:07 INFO: [Master] [Local integrity] Finished in 0.003s. Calculated metadata of 35 files.
2024/05/09 18:57:11 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_p'
2024/05/09 18:57:11 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m'
2024/05/09 18:57:11 INFO: [Worker worker01-node] [Integrity check] Starting.
2024/05/09 18:57:11 DEBUG: [Worker worker01-node] [Main] Command received: b'new_file'
2024/05/09 18:57:11 DEBUG: [Worker worker01-node] [Main] Command received: b'file_upd'
2024/05/09 18:57:11 DEBUG: [Worker worker01-node] [Main] Command received: b'file_end'
2024/05/09 18:57:11 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_e'
2024/05/09 18:57:11 DEBUG: [Worker worker01-node] [Integrity check] Received file from worker: '/var/ossec/queue/cluster/worker01-node/worker01-node-1715291838.028192-57a0b1fca3d84367a1495af2ee5e257e.zip'
2024/05/09 18:57:11 INFO: [Worker worker01-node] [Integrity check] Finished in 0.015s. Received metadata of 35 files. Sync not required.
2024/05/09 18:57:15 INFO: [Master] [Local agent-groups] Starting.
2024/05/09 18:57:15 DEBUG: [Master] [Local agent-groups] Obtained 1 chunks of data in 0.000s.
2024/05/09 18:57:15 DEBUG2: [Master] [Main] Added broadcast request to execute "send_agent_groups_information" in worker01-node.
2024/05/09 18:57:15 INFO: [Master] [Local agent-groups] Finished in 0.001s.
2024/05/09 18:57:15 INFO: [Worker worker01-node] [Agent-groups send] Starting.
2024/05/09 18:57:15 DEBUG: [Worker worker01-node] [Agent-groups send] Sending chunks.
2024/05/09 18:57:15 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_w_g_e'
2024/05/09 18:57:15 INFO: [Worker worker01-node] [Agent-groups send] Finished in -10799.971s. Updated 1 chunks.
2024/05/09 18:57:15 INFO: [Master] [Local integrity] Starting.
2024/05/09 18:57:15 INFO: [Master] [Local integrity] Finished in 0.005s. Calculated metadata of 35 files.
2024/05/09 18:57:15 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_a_w_m_p'
2024/05/09 18:57:20 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_p'
2024/05/09 18:57:20 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m'
2024/05/09 18:57:20 INFO: [Worker worker01-node] [Integrity check] Starting.
2024/05/09 18:57:20 DEBUG: [Worker worker01-node] [Main] Command received: b'new_file'
2024/05/09 18:57:20 DEBUG: [Worker worker01-node] [Main] Command received: b'file_upd'
2024/05/09 18:57:20 DEBUG: [Worker worker01-node] [Main] Command received: b'file_end'
2024/05/09 18:57:20 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_e'
2024/05/09 18:57:20 DEBUG: [Worker worker01-node] [Integrity check] Received file from worker: '/var/ossec/queue/cluster/worker01-node/worker01-node-1715291847.052186-9ae900fccea542949b866da56075e381.zip'
2024/05/09 18:57:20 INFO: [Worker worker01-node] [Integrity check] Finished in 0.013s. Received metadata of 35 files. Sync not required.
2024/05/09 18:57:23 INFO: [Master] [Local integrity] Starting.
2024/05/09 18:57:23 INFO: [Master] [Local integrity] Finished in 0.002s. Calculated metadata of 35 files.
2024/05/09 18:57:23 DEBUG: [Worker worker01-node] [Main] Command received: b'echo-c'
2024/05/09 18:57:25 INFO: [Master] [Local agent-groups] Starting.
2024/05/09 18:57:25 DEBUG: [Master] [Local agent-groups] Obtained 1 chunks of data in 0.000s.
2024/05/09 18:57:25 DEBUG2: [Master] [Main] Added broadcast request to execute "send_agent_groups_information" in worker01-node.
2024/05/09 18:57:25 INFO: [Master] [Local agent-groups] Finished in 0.001s.
2024/05/09 18:57:25 INFO: [Worker worker01-node] [Agent-groups send] Starting.
2024/05/09 18:57:25 DEBUG: [Worker worker01-node] [Agent-groups send] Sending chunks.
2024/05/09 18:57:25 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_w_g_e'
2024/05/09 18:57:25 INFO: [Worker worker01-node] [Agent-groups send] Finished in -10799.941s. Updated 1 chunks.
2024/05/09 18:57:25 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_a_w_m_p'
2024/05/09 18:57:29 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_p'
2024/05/09 18:57:29 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m'
2024/05/09 18:57:29 INFO: [Worker worker01-node] [Integrity check] Starting.
2024/05/09 18:57:29 DEBUG: [Worker worker01-node] [Main] Command received: b'new_file'
2024/05/09 18:57:29 DEBUG: [Worker worker01-node] [Main] Command received: b'file_upd'
2024/05/09 18:57:29 DEBUG: [Worker worker01-node] [Main] Command received: b'file_end'
2024/05/09 18:57:29 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_e'
2024/05/09 18:57:29 DEBUG: [Worker worker01-node] [Integrity check] Received file from worker: '/var/ossec/queue/cluster/worker01-node/worker01-node-1715291856.077096-d3bd62b0dc574e7b8f3f0dd6e371f4f6.zip'
2024/05/09 18:57:29 INFO: [Worker worker01-node] [Integrity check] Finished in 0.027s. Received metadata of 35 files. Sync not required.
2024/05/09 18:57:31 INFO: [Master] [Local integrity] Starting.
2024/05/09 18:57:31 INFO: [Master] [Local integrity] Finished in 0.004s. Calculated metadata of 35 files.
2024/05/09 18:57:35 INFO: [Master] [Local agent-groups] Starting.
2024/05/09 18:57:35 DEBUG: [Master] [Local agent-groups] Obtained 1 chunks of data in 0.002s.
2024/05/09 18:57:35 DEBUG2: [Master] [Main] Added broadcast request to execute "send_agent_groups_information" in worker01-node.
2024/05/09 18:57:35 INFO: [Master] [Local agent-groups] Finished in 0.003s.
2024/05/09 18:57:35 INFO: [Worker worker01-node] [Agent-groups send] Starting.
2024/05/09 18:57:35 DEBUG: [Worker worker01-node] [Agent-groups send] Sending chunks.
2024/05/09 18:57:35 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_w_g_e'
2024/05/09 18:57:35 INFO: [Worker worker01-node] [Agent-groups send] Finished in -10799.989s. Updated 1 chunks.
2024/05/09 18:57:35 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_a_w_m_p'
2024/05/09 18:57:38 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_p'
2024/05/09 18:57:38 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m'
2024/05/09 18:57:38 INFO: [Worker worker01-node] [Integrity check] Starting.
2024/05/09 18:57:38 DEBUG: [Worker worker01-node] [Main] Command received: b'new_file'
2024/05/09 18:57:38 DEBUG: [Worker worker01-node] [Main] Command received: b'file_upd'
2024/05/09 18:57:38 DEBUG: [Worker worker01-node] [Main] Command received: b'file_end'
2024/05/09 18:57:38 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_e'
2024/05/09 18:57:38 DEBUG: [Worker worker01-node] [Integrity check] Received file from worker: '/var/ossec/queue/cluster/worker01-node/worker01-node-1715291865.114865-b4c10fa421dd4baf9f83269f9a1a25e4.zip'
2024/05/09 18:57:38 INFO: [Worker worker01-node] [Integrity check] Finished in 0.014s. Received metadata of 35 files. Sync not required.
2024/05/09 18:57:39 INFO: [Master] [Local integrity] Starting.
2024/05/09 18:57:39 INFO: [Master] [Local integrity] Finished in 0.002s. Calculated metadata of 35 files.
2024/05/09 18:57:44 DEBUG: [Local Server] [Keep alive] Calculating.
2024/05/09 18:57:44 DEBUG: [Local Server] [Keep alive] Calculated.
2024/05/09 18:57:44 DEBUG: [Master] [Keep alive] Calculating.
2024/05/09 18:57:44 DEBUG: [Master] [Keep alive] Calculated.
2024/05/09 18:57:45 INFO: [Master] [Local agent-groups] Starting.
2024/05/09 18:57:45 DEBUG: [Master] [Local agent-groups] Obtained 1 chunks of data in 0.029s.
2024/05/09 18:57:45 DEBUG2: [Master] [Main] Added broadcast request to execute "send_agent_groups_information" in worker01-node.
2024/05/09 18:57:45 INFO: [Master] [Local agent-groups] Finished in 0.029s.
2024/05/09 18:57:45 INFO: [Worker worker01-node] [Agent-groups send] Starting.
2024/05/09 18:57:45 DEBUG: [Worker worker01-node] [Agent-groups send] Sending chunks.
2024/05/09 18:57:45 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_w_g_e'
2024/05/09 18:57:45 INFO: [Worker worker01-node] [Agent-groups send] Finished in -10799.806s. Updated 1 chunks.
2024/05/09 18:57:45 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_a_w_m_p'
2024/05/09 18:57:47 INFO: [Master] [Local integrity] Starting.
2024/05/09 18:57:47 INFO: [Master] [Local integrity] Finished in 0.003s. Calculated metadata of 35 files.
2024/05/09 18:57:47 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_p'
2024/05/09 18:57:47 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m'
2024/05/09 18:57:47 INFO: [Worker worker01-node] [Integrity check] Starting.
2024/05/09 18:57:47 DEBUG: [Worker worker01-node] [Main] Command received: b'new_file'
2024/05/09 18:57:47 DEBUG: [Worker worker01-node] [Main] Command received: b'file_upd'
2024/05/09 18:57:47 DEBUG: [Worker worker01-node] [Main] Command received: b'file_end'
2024/05/09 18:57:47 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_e'
2024/05/09 18:57:47 DEBUG: [Worker worker01-node] [Integrity check] Received file from worker: '/var/ossec/queue/cluster/worker01-node/worker01-node-1715291874.153225-bb4e8ee6b38b43f28793d7152dc425f0.zip'
2024/05/09 18:57:47 INFO: [Worker worker01-node] [Integrity check] Finished in 0.012s. Received metadata of 35 files. Sync not required.
2024/05/09 18:57:53 DEBUG: [Worker worker01-node] [Main] Command received: b'sendsync'
2024/05/09 18:57:53 DEBUG: [Worker worker01-node] [SendSync] Received request: b'worker01-node*182466 {"daemon_name":"authd","message":{"arguments":{"name":"LAPTOP-SI21F60O","ip":"any","key_hash":"aac91ff0af2abf9f4d70f0ea2b696332a2f4e77b"},"function":"add"}}'
2024/05/09 18:57:53 DEBUG: [Master] [SendSync] Receiving SendSync request (authd) from worker01-node (182466)
2024/05/09 18:57:55 INFO: [Master] [Local agent-groups] Starting.
2024/05/09 18:57:55 DEBUG: [Master] [Local agent-groups] Obtained 1 chunks of data in 0.001s.
2024/05/09 18:57:55 DEBUG2: [Master] [Main] Added broadcast request to execute "send_agent_groups_information" in worker01-node.
2024/05/09 18:57:55 INFO: [Master] [Local agent-groups] Finished in 0.001s.
2024/05/09 18:57:55 INFO: [Worker worker01-node] [Agent-groups send] Starting.
2024/05/09 18:57:55 DEBUG: [Worker worker01-node] [Agent-groups send] Sending chunks.
2024/05/09 18:57:55 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_w_g_e'
2024/05/09 18:57:55 INFO: [Worker worker01-node] [Agent-groups send] Finished in -10799.990s. Updated 1 chunks.
2024/05/09 18:57:55 INFO: [Master] [Local integrity] Starting.
2024/05/09 18:57:55 INFO: [Master] [Local integrity] Finished in 0.005s. Calculated metadata of 35 files.
2024/05/09 18:57:55 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_a_w_m_p'
2024/05/09 18:57:57 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_p'
2024/05/09 18:57:57 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m'
2024/05/09 18:57:57 INFO: [Worker worker01-node] [Integrity check] Starting.
2024/05/09 18:57:57 DEBUG: [Worker worker01-node] [Main] Command received: b'new_file'
2024/05/09 18:57:57 DEBUG: [Worker worker01-node] [Main] Command received: b'file_upd'
2024/05/09 18:57:57 DEBUG: [Worker worker01-node] [Main] Command received: b'file_end'
2024/05/09 18:57:57 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_e'
2024/05/09 18:57:57 DEBUG: [Worker worker01-node] [Integrity check] Received file from worker: '/var/ossec/queue/cluster/worker01-node/worker01-node-1715291883.275829-2c2e30a161b24fd69a8dbda34270f6a7.zip'
2024/05/09 18:57:57 INFO: [Worker worker01-node] [Integrity check] Finished in 0.053s. Received metadata of 35 files. Sync required.
2024/05/09 18:57:57 INFO: [Worker worker01-node] [Integrity sync] Starting.
2024/05/09 18:57:57 INFO: [Worker worker01-node] [Integrity sync] Files to create in worker: 0 | Files to update in worker: 1 | Files to delete in worker: 0
2024/05/09 18:57:57 DEBUG: [Worker worker01-node] [Integrity sync] Compressing files and 'files_metadata.json' of 1 files.
2024/05/09 18:57:57 DEBUG: [Worker worker01-node] [Integrity sync] Sending zip file.
2024/05/09 18:57:57 DEBUG: [Worker worker01-node] [Integrity sync] Zip file sent.
2024/05/09 18:57:57 INFO: [Worker worker01-node] [Integrity sync] Finished in 0.014s.
2024/05/09 18:58:03 INFO: [Master] [Local integrity] Starting.
2024/05/09 18:58:03 INFO: [Master] [Local integrity] Finished in 0.010s. Calculated metadata of 35 files.
2024/05/09 18:58:05 INFO: [Master] [Local agent-groups] Starting.
2024/05/09 18:58:05 DEBUG: [Master] [Local agent-groups] Obtained 1 chunks of data in 0.002s.
2024/05/09 18:58:05 DEBUG2: [Master] [Main] Added broadcast request to execute "send_agent_groups_information" in worker01-node.
2024/05/09 18:58:05 INFO: [Master] [Local agent-groups] Finished in 0.002s.
2024/05/09 18:58:05 INFO: [Worker worker01-node] [Agent-groups send] Starting.
2024/05/09 18:58:05 DEBUG: [Worker worker01-node] [Agent-groups send] Sending chunks.
2024/05/09 18:58:05 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_w_g_e'
2024/05/09 18:58:05 INFO: [Worker worker01-node] [Agent-groups send] Finished in -10799.963s. Updated 1 chunks.
2024/05/09 18:58:05 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_a_w_m_p'
2024/05/09 18:58:06 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_p'
2024/05/09 18:58:06 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m'
2024/05/09 18:58:06 INFO: [Worker worker01-node] [Integrity check] Starting.
2024/05/09 18:58:06 DEBUG: [Worker worker01-node] [Main] Command received: b'new_file'
2024/05/09 18:58:06 DEBUG: [Worker worker01-node] [Main] Command received: b'file_upd'
2024/05/09 18:58:06 DEBUG: [Worker worker01-node] [Main] Command received: b'file_end'
2024/05/09 18:58:06 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_e'
2024/05/09 18:58:06 DEBUG: [Worker worker01-node] [Integrity check] Received file from worker: '/var/ossec/queue/cluster/worker01-node/worker01-node-1715291892.349026-deea7fe6455446a3960f9d36659e6016.zip'
2024/05/09 18:58:06 INFO: [Worker worker01-node] [Integrity check] Finished in 0.019s. Received metadata of 35 files. Sync not required.
2024/05/09 18:58:11 INFO: [Master] [Local integrity] Starting.
2024/05/09 18:58:11 INFO: [Master] [Local integrity] Finished in 0.004s. Calculated metadata of 35 files.
2024/05/09 18:58:13 DEBUG: [Worker worker01-node] [Main] Command received: b'sendsync'
2024/05/09 18:58:13 DEBUG: [Worker worker01-node] [SendSync] Received request: b'worker01-node*774526 {"daemon_name":"remoted","message":{"command":"assigngroup","parameters":{"agent":"002","md5":"d0f51333bf62a0d4dbe082107c77e1a4"}}}'
2024/05/09 18:58:13 DEBUG: [Master] [SendSync] Receiving SendSync request (remoted) from worker01-node (774526)
2024/05/09 18:58:15 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_p'
2024/05/09 18:58:15 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m'
2024/05/09 18:58:15 INFO: [Worker worker01-node] [Integrity check] Starting.
2024/05/09 18:58:15 DEBUG: [Worker worker01-node] [Main] Command received: b'new_file'
2024/05/09 18:58:15 DEBUG: [Worker worker01-node] [Main] Command received: b'file_upd'
2024/05/09 18:58:15 DEBUG: [Worker worker01-node] [Main] Command received: b'file_end'
2024/05/09 18:58:15 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_e'
2024/05/09 18:58:15 INFO: [Master] [Local agent-groups] Starting.
2024/05/09 18:58:15 DEBUG: [Worker worker01-node] [Integrity check] Received file from worker: '/var/ossec/queue/cluster/worker01-node/worker01-node-1715291901.437433-69d430e8fce9481eb9f73dd04fe0c705.zip'
2024/05/09 18:58:15 INFO: [Worker worker01-node] [Integrity check] Finished in 0.030s. Received metadata of 35 files. Sync not required.
2024/05/09 18:58:15 DEBUG: [Master] [Local agent-groups] Obtained 1 chunks of data in 0.003s.
2024/05/09 18:58:15 DEBUG2: [Master] [Main] Added broadcast request to execute "send_agent_groups_information" in worker01-node.
2024/05/09 18:58:15 INFO: [Master] [Local agent-groups] Finished in 0.003s.
2024/05/09 18:58:15 INFO: [Worker worker01-node] [Agent-groups send] Starting.
2024/05/09 18:58:15 DEBUG: [Worker worker01-node] [Agent-groups send] Sending chunks.
2024/05/09 18:58:15 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_w_g_e'
2024/05/09 18:58:15 INFO: [Worker worker01-node] [Agent-groups send] Finished in -10799.971s. Updated 1 chunks.
2024/05/09 18:58:15 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_a_w_m_p'
2024/05/09 18:58:15 DEBUG: [Worker worker01-node] [Main] Command received: b'new_str'
2024/05/09 18:58:15 DEBUG: [Worker worker01-node] [Main] Command received: b'str_upd'
2024/05/09 18:58:15 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_a_w_m'
2024/05/09 18:58:15 INFO: [Worker worker01-node] [Agent-info sync] Starting.
2024/05/09 18:58:15 DEBUG: [Worker worker01-node] [Agent-info sync] 1/1 chunks updated in wazuh-db in 0.001s.
2024/05/09 18:58:15 INFO: [Worker worker01-node] [Agent-info sync] Finished in 0.007s. Updated 1 chunks.
2024/05/09 18:58:19 INFO: [Master] [Local integrity] Starting.
2024/05/09 18:58:19 INFO: [Master] [Local integrity] Finished in 0.009s. Calculated metadata of 35 files.
2024/05/09 18:58:23 DEBUG: [Worker worker01-node] [Main] Command received: b'echo-c'
2024/05/09 18:58:24 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_p'
2024/05/09 18:58:24 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m'
2024/05/09 18:58:24 INFO: [Worker worker01-node] [Integrity check] Starting.
2024/05/09 18:58:24 DEBUG: [Worker worker01-node] [Main] Command received: b'new_file'
2024/05/09 18:58:24 DEBUG: [Worker worker01-node] [Main] Command received: b'file_upd'
2024/05/09 18:58:24 DEBUG: [Worker worker01-node] [Main] Command received: b'file_end'
2024/05/09 18:58:24 DEBUG: [Worker worker01-node] [Main] Command received: b'syn_i_w_m_e'

Conclusion

In my opinion, the inclusion of the clause “REFERENCES agent(id)” is correct and evidences cluster failures in the synchronization of agent information, since as we saw, after the agent deletion, information of that deleted agent is synchronized.

@davidjiglesias
Copy link
Member

davidjiglesias commented May 10, 2024 •
edited

In my opinion, the inclusion of the clause “REFERENCES agent(id)” is correct and evidences cluster failures in the synchronization of agent information, since as we saw, after the agent deletion, information of that deleted agent is synchronized.

I disagree with it being a cluster failure, as we understand from a design perspective that the cluster synchronization tasks are not atomic with other operations taking place in local databases, and as such, those databases are responsible for their own mechanisms to protect integrity.

However, I also understand from the investigation that we do not have any failure from the db itself and that it is recovering properly without any consequences.

I consider this as completed with not further actions required.

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

@Nicogp Nicogp

Labels
level/task type/bug Something isn't working
Projects
Release 4.8.0
Status: Done
Milestone
No milestone
Development

No branches or pull requests
4 participants
@havidarou @Nicogp @fdalmaup @davidjiglesias