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.

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

[BUG] The Command Manager re-autenticates on each request #192

Open
AlexRuiz7 opened this issue Dec 19, 2024 · 0 comments
Open

[BUG] The Command Manager re-autenticates on each request #192

AlexRuiz7 opened this issue Dec 19, 2024 · 0 comments
Labels
level/task Task issue type/bug Bug issue

Comments

@AlexRuiz7
Copy link
Member

Describe the bug
During the tests of the Data persistence model MVP refinement II, it has been detected that the Command Manager reauthenticates on the Wazuh Server instead of re-using the token from previous requests.

This represents an overload of requests that could be avoided. The Command Manager's HttpClient is failing to efficiently use its resources.

To Reproduce
Steps to reproduce the behavior:

  1. Using the latest packages from the MVP, generate a command on the Wazuh Server.
curl -X PUT https://127.0.0.1:55000/agents/restart -k -H "Authorization: Bearer $TOKEN"
  1. Check the /var/log/wazuh-indexer/wazuh-cluster.log
  2. Identify the request by the Received POST log
  3. Repeat and check that the Attempting authentication at [https://127.0.0.1:55000/security/user/authenticate log appears several times.

Expected behavior
The Command Manager should log in once to obtain the JWT token, and reuse it on the future requests to the Wazuh Server until the token expires. In that case, it should obtain a new token.

Plugins
Command Manager plugin.

Additional context

wazuh-indexer logs

[2024-12-19T11:34:32,570][INFO ][c.w.c.r.RestPostCommandAction] [node-1] Received POST /_plugins/_command_manager/commands request id [336] from host [127.0.0.1:9200]
[2024-12-19T11:34:32,571][INFO ][c.w.c.i.CommandIndex     ] [node-1] Adding command with id [jP6y3pMBAuApGoBpr457] to the bulk request
[2024-12-19T11:34:32,571][INFO ][c.w.c.i.CommandIndex     ] [node-1] Index template index-template-commands already exists. Skipping creation.
[2024-12-19T11:34:43,853][INFO ][c.w.c.u.h.AuthHttpRestClient] [node-1] Attempting authentication at [https://127.0.0.1:55000/security/user/authenticate]
[2024-12-19T11:34:43,854][INFO ][c.w.c.u.h.HttpRestClient ] [node-1] Sending payload with id [null] to [https://127.0.0.1:55000/security/user/authenticate]
[2024-12-19T11:34:44,033][INFO ][c.w.c.u.h.AuthHttpRestClient] [node-1] Authentication successful
[2024-12-19T11:34:44,034][INFO ][c.w.c.u.h.HttpRestClient ] [node-1] Sending payload with id [null] to [https://127.0.0.1:55000/orders]
[2024-12-19T11:34:44,053][INFO ][c.w.c.j.SearchThread     ] [node-1] Server replied with 200. Updating orders' status.
[2024-12-19T11:34:46,394][INFO ][c.w.c.r.RestPostCommandAction] [node-1] Received POST /_plugins/_command_manager/commands request id [347] from host [127.0.0.1:9200]
[2024-12-19T11:34:46,394][INFO ][c.w.c.i.CommandIndex     ] [node-1] Adding command with id [j_6y3pMBAuApGoBp5Y56] to the bulk request
[2024-12-19T11:34:46,394][INFO ][c.w.c.i.CommandIndex     ] [node-1] Index template index-template-commands already exists. Skipping creation.
[2024-12-19T11:34:56,619][INFO ][c.w.c.u.h.AuthHttpRestClient] [node-1] Attempting authentication at [https://127.0.0.1:55000/security/user/authenticate]
[2024-12-19T11:34:56,619][INFO ][c.w.c.u.h.HttpRestClient ] [node-1] Sending payload with id [null] to [https://127.0.0.1:55000/security/user/authenticate]
[2024-12-19T11:34:56,723][INFO ][c.w.c.u.h.AuthHttpRestClient] [node-1] Authentication successful
[2024-12-19T11:34:56,723][INFO ][c.w.c.u.h.HttpRestClient ] [node-1] Sending payload with id [null] to [https://127.0.0.1:55000/orders]
[2024-12-19T11:34:56,746][INFO ][c.w.c.j.SearchThread     ] [node-1] Server replied with 200. Updating orders' status.
[2024-12-19T11:34:58,572][INFO ][c.w.c.r.RestPostCommandAction] [node-1] Received POST /_plugins/_command_manager/commands request id [356] from host [127.0.0.1:9200]
[2024-12-19T11:34:58,572][INFO ][c.w.c.i.CommandIndex     ] [node-1] Adding command with id [kv6z3pMBAuApGoBpFY4M] to the bulk request
[2024-12-19T11:34:58,573][INFO ][c.w.c.i.CommandIndex     ] [node-1] Index template index-template-commands already exists. Skipping creation.
[2024-12-19T11:35:10,973][INFO ][c.w.c.u.h.AuthHttpRestClient] [node-1] Attempting authentication at [https://127.0.0.1:55000/security/user/authenticate]
[2024-12-19T11:35:10,973][INFO ][c.w.c.u.h.HttpRestClient ] [node-1] Sending payload with id [null] to [https://127.0.0.1:55000/security/user/authenticate]
[2024-12-19T11:35:11,077][INFO ][c.w.c.u.h.AuthHttpRestClient] [node-1] Authentication successful
[2024-12-19T11:35:11,078][INFO ][c.w.c.u.h.HttpRestClient ] [node-1] Sending payload with id [null] to [https://127.0.0.1:55000/orders]
[2024-12-19T11:35:11,094][INFO ][c.w.c.j.SearchThread     ] [node-1] Server replied with 200. Updating orders' status.

wazuh-server logs

Dec 19 11:34:32 rhel-server env[2903]: 2024/12/19 11:34:32 INFO: [Management API] wazuh 127.0.0.1 "PUT /agents/restart" with parameters {} and body {} done in 0.046s: 200
Dec 19 11:34:34 rhel-server env[2409]: 2024/12/19 11:34:34 INFO: [Master] [Local integrity] Starting.
Dec 19 11:34:34 rhel-server env[2409]: 2024/12/19 11:34:34 INFO: [Master] [Local integrity] Finished in 0.005s. Calculated metadata of 2 files.
Dec 19 11:34:42 rhel-server env[2409]: 2024/12/19 11:34:42 INFO: [Master] [Local integrity] Starting.
Dec 19 11:34:42 rhel-server env[2409]: 2024/12/19 11:34:42 INFO: [Master] [Local integrity] Finished in 0.003s. Calculated metadata of 2 files.
Dec 19 11:34:44 rhel-server env[2903]: 2024/12/19 11:34:44 INFO: [Management API] wazuh 127.0.0.1 "POST /security/user/authenticate" with parameters {} and body {} done in 0.166s: 200
Dec 19 11:34:44 rhel-server env[2903]: 2024/12/19 11:34:44 DEBUG: [Management API] Decoded token {'username': 'wazuh', 'roles': (1,), 'token_nbf_time': 1734608084, 'run_as': False, 'origin_node_type': 'master'}
Dec 19 11:34:44 rhel-server env[2409]: 2024/12/19 11:34:44 INFO: [Local 813197] [Main] Sending orders to the other nodes
Dec 19 11:34:44 rhel-server env[2409]: 2024/12/19 11:34:44 INFO: [Local 813197] [Main] Sending orders to the Communications API
Dec 19 11:34:44 rhel-server env[2903]: 2024/12/19 11:34:44 INFO: [Management API] wazuh 127.0.0.1 "POST /orders" with parameters {} and body {"orders": [{"action": {"args": [], "name": "restart", "version": "5.>
Dec 19 11:34:44 rhel-server env[2409]: 2024/12/19 11:34:44 ERROR: [Local 813197] [Main] Error 3041 - Server status check timed out after adding new servers: [Errno 2] No such file or directory
Dec 19 11:34:46 rhel-server env[2903]: 2024/12/19 11:34:46 DEBUG: [Management API] Decoded token {'username': 'wazuh', 'roles': (1,), 'token_nbf_time': 1734607561, 'run_as': False, 'origin_node_type': 'master'}
Dec 19 11:34:46 rhel-server env[2903]: 2024/12/19 11:34:46 DEBUG: [Management API] Connecting to the indexer client.
Dec 19 11:34:46 rhel-server env[2903]: 2024/12/19 11:34:46 DEBUG: [Management API] Closing the indexer client session.
Dec 19 11:34:46 rhel-server env[2903]: 2024/12/19 11:34:46 DEBUG: [Management API] Connecting to the indexer client.
Dec 19 11:34:46 rhel-server env[2903]: 2024/12/19 11:34:46 DEBUG: [Management API] Closing the indexer client session.
Dec 19 11:34:46 rhel-server env[2903]: 2024/12/19 11:34:46 INFO: [Management API] wazuh 127.0.0.1 "PUT /agents/restart" with parameters {} and body {} done in 0.047s: 200
Dec 19 11:34:50 rhel-server env[2409]: 2024/12/19 11:34:50 INFO: [Master] [Local integrity] Starting.
Dec 19 11:34:50 rhel-server env[2409]: 2024/12/19 11:34:50 INFO: [Master] [Local integrity] Finished in 0.004s. Calculated metadata of 2 files.
Dec 19 11:34:56 rhel-server env[2903]: 2024/12/19 11:34:56 INFO: [Management API] wazuh 127.0.0.1 "POST /security/user/authenticate" with parameters {} and body {} done in 0.091s: 200
Dec 19 11:34:56 rhel-server env[2903]: 2024/12/19 11:34:56 DEBUG: [Management API] Decoded token {'username': 'wazuh', 'roles': (1,), 'token_nbf_time': 1734608096, 'run_as': False, 'origin_node_type': 'master'}
Dec 19 11:34:56 rhel-server env[2409]: 2024/12/19 11:34:56 INFO: [Local 500381] [Main] Sending orders to the other nodes
Dec 19 11:34:56 rhel-server env[2409]: 2024/12/19 11:34:56 INFO: [Local 500381] [Main] Sending orders to the Communications API
Dec 19 11:34:56 rhel-server env[2903]: 2024/12/19 11:34:56 INFO: [Management API] wazuh 127.0.0.1 "POST /orders" with parameters {} and body {"orders": [{"action": {"args": [], "name": "restart", "version": "5.>
Dec 19 11:34:56 rhel-server env[2409]: 2024/12/19 11:34:56 ERROR: [Local 500381] [Main] Error 3041 - Server status check timed out after adding new servers: [Errno 2] No such file or directory
Dec 19 11:34:58 rhel-server env[2903]: 2024/12/19 11:34:58 DEBUG: [Management API] Decoded token {'username': 'wazuh', 'roles': (1,), 'token_nbf_time': 1734607561, 'run_as': False, 'origin_node_type': 'master'}
Dec 19 11:34:58 rhel-server env[2903]: 2024/12/19 11:34:58 DEBUG: [Management API] Connecting to the indexer client.
Dec 19 11:34:58 rhel-server env[2903]: 2024/12/19 11:34:58 DEBUG: [Management API] Closing the indexer client session.
Dec 19 11:34:58 rhel-server env[2903]: 2024/12/19 11:34:58 DEBUG: [Management API] Connecting to the indexer client.
Dec 19 11:34:58 rhel-server env[2903]: 2024/12/19 11:34:58 DEBUG: [Management API] Closing the indexer client session.
Dec 19 11:34:58 rhel-server env[2903]: 2024/12/19 11:34:58 INFO: [Management API] wazuh 127.0.0.1 "PUT /agents/restart" with parameters {} and body {} done in 0.045s: 200
Dec 19 11:34:58 rhel-server env[2409]: 2024/12/19 11:34:58 INFO: [Master] [Local integrity] Starting.
Dec 19 11:34:58 rhel-server env[2409]: 2024/12/19 11:34:58 INFO: [Master] [Local integrity] Finished in 0.004s. Calculated metadata of 2 files.
Dec 19 11:35:06 rhel-server env[2409]: 2024/12/19 11:35:06 INFO: [Master] [Local integrity] Starting.
Dec 19 11:35:06 rhel-server env[2409]: 2024/12/19 11:35:06 INFO: [Master] [Local integrity] Finished in 0.003s. Calculated metadata of 2 files.
Dec 19 11:35:11 rhel-server env[2903]: 2024/12/19 11:35:11 INFO: [Management API] wazuh 127.0.0.1 "POST /security/user/authenticate" with parameters {} and body {} done in 0.092s: 200
Dec 19 11:35:11 rhel-server env[2903]: 2024/12/19 11:35:11 DEBUG: [Management API] Decoded token {'username': 'wazuh', 'roles': (1,), 'token_nbf_time': 1734608111, 'run_as': False, 'origin_node_type': 'master'}
Dec 19 11:35:11 rhel-server env[2409]: 2024/12/19 11:35:11 INFO: [Local 985686] [Main] Sending orders to the other nodes
@AlexRuiz7 AlexRuiz7 added level/task Task issue type/bug Bug issue labels Dec 19, 2024
@AlexRuiz7 AlexRuiz7 changed the title [BUG] The Command Manager re-autenticates on each request to the M_API [BUG] The Command Manager re-autenticates on each request Dec 19, 2024
@AlexRuiz7 AlexRuiz7 added the mvp Minimum Viable Product label Dec 19, 2024
@wazuhci wazuhci moved this to Blocked in Release 5.0.0 Dec 19, 2024
@AlexRuiz7 AlexRuiz7 removed the mvp Minimum Viable Product label Dec 19, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
level/task Task issue type/bug Bug issue
Projects
Status: Blocked
Development

No branches or pull requests

1 participant