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

V2 Agent actions acks/results are delayed by 5 minutes #2410

Closed
aleksmaus opened this issue Jan 5, 2023 · 14 comments · Fixed by #2406
Closed

V2 Agent actions acks/results are delayed by 5 minutes #2410

aleksmaus opened this issue Jan 5, 2023 · 14 comments · Fixed by #2406
Labels
bug Something isn't working Team:Fleet Label for the Fleet team v8.6.0

Comments

@aleksmaus
Copy link
Member

Testing osquery live queries running 40-100 queries (actions) at a time.
Noticed a significant issue with acking delay.

Osquerybeat completes the queries execution almost right away and posts the query results to elastic search
but the “action completed” response document comes in 5 minutes(!) later.
This introduces significant delay on UI, because UI for example shows the progress bar until it receives the count action result that contains the number of returned records and it can match that number to the number query results document.

Example query results document timestamp :

GET logs-osquery_manager.result-default/_search
{
  "query" : {
    "term": {
      "action_id": {
        "value": "54d7e976-6cbd-4c22-ac06-5788b97747eb"
      }
    }
  },
  "size": 1000
}

"@timestamp": "2023-01-05T19:23:44.536Z"

While the fleet action result (ack) document was received 5 minutes later:

GET .fleet-actions-results/_search
{
  "query" : {
    "term": {
      "action_id": {
        "value": "54d7e976-6cbd-4c22-ac06-5788b97747eb"
      }
    }
  }
}

"@timestamp": "2023-01-05T19:28:21Z"

This seems that it is related to the change in check-in and action dispatching loop. Before V2 check-in and the action dispatching was happening in the same loop, so the next check-in was happening after all the actions were processed.
With V2 these loops were separated (which is a good thing, since blocking check-ins because of the long running actions is bad), but the side-effect of the change seems to be that the acks are not sent until the next check-in comes around in 5 minutes.

For confirmed bugs, please report:

  • Version: 8.6
  • Operating System: Tested on Windows (but it's platform independent part)
@aleksmaus aleksmaus added bug Something isn't working v8.6.0 labels Jan 5, 2023
@cmacknz cmacknz mentioned this issue Jan 5, 2023
Closed
2 tasks
@cmacknz cmacknz added the Team:Elastic-Agent Label for the Agent team label Jan 5, 2023
@cmacknz cmacknz removed their assignment Jan 5, 2023
@cmacknz cmacknz mentioned this issue Jan 5, 2023
Closed
@cmacknz
Copy link
Member

cmacknz commented Jan 9, 2023 •
edited

Since this is because we potentially have to wait for the next checkin, it seems like the way we'd solve this on the agent would be to checkin again immediately once the action actually completes. Either that, or we make wait for actions to complete before the next check in again but we know this cause us to miss checkins when actions run too long.

Checking in more frequently based on the frequency of completed actions would work here but would have scalability implications for fleet server. We would at least need to rate limit how fast we can checkin again which is always going to put an artificial limit on the action response time. An even better fix on the agent would be to use a streaming protocol and eliminate the checkin period entirely but that's not a change we can make quickly.

Osquerybeat completes the queries execution almost right away and posts the query results to elastic search
but the “action completed” response document comes in 5 minutes(!) later.

Given that Osquerybeat responds immediately, I think my preferred way to solve this would be for Osquery in Kibana to look for the response from Osquerybeat instead of waiting for the agent action response. Presumably it needs to look for the Osquerybeat response regardless. @aleksmaus I believe you already mentioned Endpoint does something similar for response actions already, is this approach feasiable for Osquery as well?

@cmacknz
Copy link
Member

cmacknz commented Jan 10, 2023

Update: the acks responses involved here use a separate Fleet server endpoint, so we likely don't need to adjust the frequency of checkins.

@michalpristas
Copy link
Contributor

michalpristas commented Jan 11, 2023 •
edited

i created custom very verbose agent and i've seen this
pack1 is acking whole batch of actions at once (80 actions) it takes roughly 5 minutes to complete them 1 by 1.
this is on clean env

pack2 and 3 uses modified agents which forces commit on ack when there's more than 10 items in a queue
env is not clean anymore. pack 1 was running there
when we take a look at logs (visible in pack3)

we see something like this

{"timestamp":"2023-01-11T08:14:50.640Z","message":"handlerAppAction: action 'action_id: 747bdb79-9962-4b31-81df-9867102a9d20, type: INPUT_ACTION, input_type: osquery' received"}
{"timestamp":"2023-01-11T08:14:50.640Z","message":"handlerAppAction: action 'INPUT_ACTION' started with timeout: 1m0s"}
{"timestamp":"2023-01-11T08:14:53.979Z","message":"handlerAppAction: action 'osquery' finished, startFormatted: 2023-01-11T08:14:50.640764Z, endFormatted: 2023-01-11T08:14:53.9790828Z, err: <nil>"}
{"timestamp":"2023-01-11T08:14:53.979Z","message":" Acked action %q747bdb79-9962-4b31-81df-9867102a9d20"}
{"timestamp":"2023-01-11T08:14:53.979Z","message":"appending action with id '747bdb79-9962-4b31-81df-9867102a9d20' to the queue"}
{"timestamp":"2023-01-11T08:14:53.979Z","message":"lazy acker: ack batch: [action_id: d30abd19-44db-408e-a603-afb7064dc5a5, type: INPUT_ACTION, input_type: osquery action_id: 721e3ce6-b3a4-4ec3-8fbf-35280d4cc3d1, type: INPUT_ACTION, input_type: osquery action_id: ce333d42-dac6-4b9f-a604-c1326061a3a1, type: INPUT_ACTION, input_type: osquery action_id: 838570b4-bf8c-4fb5-81c8-c983ec8f134e, type: INPUT_ACTION, input_type: osquery action_id: 66be747c-4a02-43a5-9f2a-07a078d8b617, type: INPUT_ACTION, input_type: osquery action_id: 3b31a44f-f2a4-409e-a47a-108cfb5b036a, type: INPUT_ACTION, input_type: osquery action_id: f6d504f9-de08-439d-8050-5da0633b928a, type: INPUT_ACTION, input_type: osquery action_id: 6d0b09f8-a8e7-4abb-b16a-bce5f157dfcc, type: INPUT_ACTION, input_type: osquery action_id: 859529c7-a741-446b-af13-f6cbbe9c7947, type: INPUT_ACTION, input_type: osquery action_id: 50ad0048-0fa9-455e-a6b3-28441da6404c, type: INPUT_ACTION, input_type: osquery action_id: 747bdb79-9962-4b31-81df-9867102a9d20, type: INPUT_ACTION, input_type: osquery]"}
{"timestamp":"2023-01-11T08:14:53.979Z","message":"acknowledging 11 actions with ids 'd30abd19-44db-408e-a603-afb7064dc5a5,721e3ce6-b3a4-4ec3-8fbf-35280d4cc3d1,ce333d42-dac6-4b9f-a604-c1326061a3a1,838570b4-bf8c-4fb5-81c8-c983ec8f134e,66be747c-4a02-43a5-9f2a-07a078d8b617,3b31a44f-f2a4-409e-a47a-108cfb5b036a,f6d504f9-de08-439d-8050-5da0633b928a,6d0b09f8-a8e7-4abb-b16a-bce5f157dfcc,859529c7-a741-446b-af13-f6cbbe9c7947,50ad0048-0fa9-455e-a6b3-28441da6404c,747bdb79-9962-4b31-81df-9867102a9d20'"}
{"timestamp":"2023-01-11T08:19:37.836Z","message":"acknowledged 11 actions with ids 'd30abd19-44db-408e-a603-afb7064dc5a5,721e3ce6-b3a4-4ec3-8fbf-35280d4cc3d1,ce333d42-dac6-4b9f-a604-c1326061a3a1,838570b4-bf8c-4fb5-81c8-c983ec8f134e,66be747c-4a02-43a5-9f2a-07a078d8b617,3b31a44f-f2a4-409e-a47a-108cfb5b036a,f6d504f9-de08-439d-8050-5da0633b928a,6d0b09f8-a8e7-4abb-b16a-bce5f157dfcc,859529c7-a741-446b-af13-f6cbbe9c7947,50ad0048-0fa9-455e-a6b3-28441da6404c,747bdb79-9962-4b31-81df-9867102a9d20'"}
{"timestamp":"2023-01-11T08:19:37.836Z","message":"lazy acker: acked batch: [action_id: d30abd19-44db-408e-a603-afb7064dc5a5, type: INPUT_ACTION, input_type: osquery action_id: 721e3ce6-b3a4-4ec3-8fbf-35280d4cc3d1, type: INPUT_ACTION, input_type: osquery action_id: ce333d42-dac6-4b9f-a604-c1326061a3a1, type: INPUT_ACTION, input_type: osquery action_id: 838570b4-bf8c-4fb5-81c8-c983ec8f134e, type: INPUT_ACTION, input_type: osquery action_id: 66be747c-4a02-43a5-9f2a-07a078d8b617, type: INPUT_ACTION, input_type: osquery action_id: 3b31a44f-f2a4-409e-a47a-108cfb5b036a, type: INPUT_ACTION, input_type: osquery action_id: f6d504f9-de08-439d-8050-5da0633b928a, type: INPUT_ACTION, input_type: osquery action_id: 6d0b09f8-a8e7-4abb-b16a-bce5f157dfcc, type: INPUT_ACTION, input_type: osquery action_id: 859529c7-a741-446b-af13-f6cbbe9c7947, type: INPUT_ACTION, input_type: osquery action_id: 50ad0048-0fa9-455e-a6b3-28441da6404c, type: INPUT_ACTION, input_type: osquery action_id: 747bdb79-9962-4b31-81df-9867102a9d20, type: INPUT_ACTION, input_type: osquery]"}
{"timestamp":"2023-01-11T08:19:37.836Z","message":"lazy acker: commit [action_id: d30abd19-44db-408e-a603-afb7064dc5a5, type: INPUT_ACTION, input_type: osquery action_id: 721e3ce6-b3a4-4ec3-8fbf-35280d4cc3d1, type: INPUT_ACTION, input_type: osquery action_id: ce333d42-dac6-4b9f-a604-c1326061a3a1, type: INPUT_ACTION, input_type: osquery action_id: 838570b4-bf8c-4fb5-81c8-c983ec8f134e, type: INPUT_ACTION, input_type: osquery action_id: 66be747c-4a02-43a5-9f2a-07a078d8b617, type: INPUT_ACTION, input_type: osquery action_id: 3b31a44f-f2a4-409e-a47a-108cfb5b036a, type: INPUT_ACTION, input_type: osquery action_id: f6d504f9-de08-439d-8050-5da0633b928a, type: INPUT_ACTION, input_type: osquery action_id: 6d0b09f8-a8e7-4abb-b16a-bce5f157dfcc, type: INPUT_ACTION, input_type: osquery action_id: 859529c7-a741-446b-af13-f6cbbe9c7947, type: INPUT_ACTION, input_type: osquery action_id: 50ad0048-0fa9-455e-a6b3-28441da6404c, type: INPUT_ACTION, input_type: osquery action_id: 747bdb79-9962-4b31-81df-9867102a9d20, type: INPUT_ACTION, input_type: osquery]"}

previous to this we see pretty swift execution of actions. this one is 11th so we force Commit. Commit is normally processed but it taked 4-5 minutes to perform REQUEST to fleet.

Interesting thing, although action was present in an Acked batch for some spinning icon did not change in UI, they all had results present when clicking on details.

Finally pack 4 is waiting for completing whole batch (same as pack 1) but it's not clean env
we see processing started with first action

{"log.level":"warn","@timestamp":"2023-01-11T08:44:45.750Z","log.origin":{"file.name":"handlers/handler_action_application.go","file.line":45},"message":"handlerAppAction: action 'action_id: 63c2d329-1ef5-4f6a-bee6-87f0538cd2a2, type: INPUT_ACTION, input_type: osquery' received","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-01-11T08:44:45.750Z","log.origin":{"file.name":"handlers/handler_action_application.go","file.line":78},"message":"handlerAppAction: action 'INPUT_ACTION' started with timeout: 1m0s","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-01-11T08:44:45.891Z","log.origin":{"file.name":"handlers/handler_action_application.go","file.line":87},"message":"handlerAppAction: action 'osquery' finished, startFormatted: 2023-01-11T08:44:45.7503085Z, endFormatted: 2023-01-11T08:44:45.890714Z, err: <nil>","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-01-11T08:44:45.891Z","log.origin":{"file.name":"handlers/handler_action_application.go","file.line":98},"message":" Acked action %q63c2d329-1ef5-4f6a-bee6-87f0538cd2a2","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-01-11T08:44:45.891Z","log.origin":{"file.name":"lazy/lazy_acker.go","file.line":137},"message":"appending action with id '63c2d329-1ef5-4f6a-bee6-87f0538cd2a2' to the queue","ecs.version":"1.6.0"}

and finished with last one

{"log.level":"warn","@timestamp":"2023-01-11T08:48:39.993Z","log.origin":{"file.name":"handlers/handler_action_application.go","file.line":45},"message":"handlerAppAction: action 'action_id: 46863222-9ab4-42f4-a86a-9e3d1b6d708b, type: INPUT_ACTION, input_type: osquery' received","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-01-11T08:48:39.993Z","log.origin":{"file.name":"handlers/handler_action_application.go","file.line":78},"message":"handlerAppAction: action 'INPUT_ACTION' started with timeout: 1m0s","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-01-11T08:48:43.299Z","log.origin":{"file.name":"handlers/handler_action_application.go","file.line":87},"message":"handlerAppAction: action 'osquery' finished, startFormatted: 2023-01-11T08:48:39.993842Z, endFormatted: 2023-01-11T08:48:43.2993688Z, err: <nil>","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-01-11T08:48:43.299Z","log.origin":{"file.name":"handlers/handler_action_application.go","file.line":98},"message":" Acked action %q46863222-9ab4-42f4-a86a-9e3d1b6d708b","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-01-11T08:48:43.299Z","log.origin":{"file.name":"lazy/lazy_acker.go","file.line":137},"message":"appending action with id '46863222-9ab4-42f4-a86a-9e3d1b6d708b' to the queue","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-01-11T08:48:43.299Z","log.origin":{"file.name":"dispatcher/dispatcher.go","file.line":158},"message":"commit for acctions: 63c2d329-1ef5-4f6a-bee6-87f0538cd2a2,246d0292-abbb-436a-9940-b0d1fbd6d473,b7227cf5-55f9-4735-8d73-76c20f4bbc40,51d1b2cc-47fc-4edf-a02d-1d999ceed486,ac395ce1-a96e-490d-ba9c-2e263a536a19,4a342fe8-7348-45ef-81a2-51a0464194ff,3dfa2e89-1f33-438f-a4c1-c6eaddf8d0ab,fd4579e7-1a9c-4dc5-8044-21f063076eb9,5ab0e046-e1fd-4817-9ebb-908385e74a5b,b010cd72-76a8-42d5-bbe2-4aa27abc315a,3e4a2268-9428-428f-9f71-e88db16d731d,cd7f1842-e31c-4008-bf75-8f2eefb21b53,f318f988-0725-4518-af89-fafd91d3972b,61ec4244-73f6-43a4-9f26-cc380289f3fc,77b03393-48b2-4b18-a2c0-c3c88916f633,5c2f89e9-a25b-4a10-9f6e-9ed2ed4be941,b4217136-3cd9-4ad0-8a08-8b6a39342a12,13d18a4e-7227-4a6c-b0d4-64a4bc87a6b2,b45956d0-4102-4812-ae27-991d28939633,e7c17462-a032-4eca-a56d-fd445de55926,578f0c32-29b3-47b1-8f12-21612244a0df,34c2e13e-7973-462e-9d53-9dcdded6acdc,95cadf80-2377-4add-9234-1e7d20acb070,9e6392cd-379d-4e01-9fa5-2784fedd4980,9533c517-13af-410d-873b-d6639201a275,d67cf6d4-42b2-4338-9294-4bae8b63bf64,cc01acf7-57b0-4e88-83c8-9d33098f526d,2e1775af-1891-4773-adff-4c2b849cf43e,9925ff01-f96e-449e-a278-76286b7bfb5d,f991dff1-e2a2-4e1b-8bae-f42c9a50a3aa,5de5f329-5dd8-472a-ac2e-e2b5e67c46cc,29384920-9fa7-4673-9963-8560c0f28656,c6699672-d584-449c-82d2-44aa79409aa6,34f1e251-8c80-4069-a078-e1d688f2d6a8,b51363c6-a844-40f9-a560-029ccbedacc4,29442ec3-8848-4118-984e-f4b7e3ae3f0a,80feb1f2-5c2c-4bf5-8907-2a62fd076204,2781d06b-da55-4a70-9c8d-c472f300de63,94b2da4d-e306-4217-bce7-a2dcb714ce56,2daa34aa-1b2c-41a1-a9be-96bb00efdd20,cbcadff9-7882-4fde-ab87-60de662362e5,3211eab9-3a32-44fa-b28b-4a3f2d533a51,0666e261-8899-4a57-8dd9-dd059725fe2a,a63d57a6-1329-420a-977c-7f0d57e31843,80b2a7c6-f54c-452c-8507-49103725cf60,ea3bfd12-bf0c-48d9-a044-4838877e31a8,5b1f232a-2cb0-4b94-a739-a00a7fc879a8,5e8a9d30-e39f-4f00-af0b-63f6a581e391,51a5975d-90c3-4a32-bf4b-f85acf7f3167,a1940628-9739-4cde-9847-eaaf35f21818,ce002006-1c6b-407f-a148-3973ccb68816,69ac6db4-aba1-434b-8a21-fe7194a3f8c7,4f936f72-c79c-4c87-8d8b-ddd6d6570241,3b793207-542a-4dde-a73b-71b4b4e70dfd,f273b267-1826-46ff-8f38-054d3a596e15,89333e6e-e426-4b96-abd4-98b03e3fd906,0f923b30-fbf0-48bf-aee3-21c68eefa8f3,4e2ab88a-37a3-4d89-b508-9030a6f9b31e,cdfe6260-7ce7-4438-873f-43725cd572e9,8b7271f9-9479-471e-bb95-128496a7523d,ea219145-e2ca-44ee-a1c5-fd0e61fe7b31,1ff5b5b9-29a0-4ad9-994d-2843e2469cab,fd5a125d-9ef5-42ea-869e-45165d0474de,434f147f-5ccc-439f-acb4-3857351cad59,fad5a060-980e-4298-99f4-9633ec5c3e09,3e5009a6-e1d2-4fb9-957f-4eb2322f4605,6b661af2-15e4-4c39-a99d-170e6ac860c6,573b17b3-be63-4414-a15e-deeb329d4e88,080b1e8a-9442-4838-bb91-e01e4a3c88f1,cd89db7a-6a0f-4dd7-bba0-35d348916dcb,0c9072dd-60ff-45da-858a-19faedf9cd2e,a93caba6-5f87-4d31-a180-ad71ddf0c41f,6e2277c4-a4b7-4e7e-b6b4-ddd27f509944,9bd8993b-a1c8-4500-b490-a2979df28814,bb8eba2f-677a-4956-ab5e-875e97ac2e4b,eccbd260-3376-430b-9180-e480952e7bc3,b27bd722-7f6e-430d-984b-7776c2df8ed3,bef27697-0292-4624-a8d7-8fd4b81a63fc,32f671ca-7e09-45b8-9b9d-459a0445c2e3,46863222-9ab4-42f4-a86a-9e3d1b6d708b","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-01-11T08:48:43.299Z","log.origin":{"file.name":"lazy/lazy_acker.go","file.line":92},"message":"lazy acker: ack batch: [action_id: 63c2d329-1ef5-4f6a-bee6-87f0538cd2a2, type: INPUT_ACTION, input_type: osquery action_id: 246d0292-abbb-436a-9940-b0d1fbd6d473, type: INPUT_ACTION, input_type: osquery action_id: b7227cf5-55f9-4735-8d73-76c20f4bbc40, type: INPUT_ACTION, input_type: osquery action_id: 51d1b2cc-47fc-4edf-a02d-1d999ceed486, type: INPUT_ACTION, input_type: osquery action_id: ac395ce1-a96e-490d-ba9c-2e263a536a19, type: INPUT_ACTION, input_type: osquery action_id: 4a342fe8-7348-45ef-81a2-51a0464194ff, type: INPUT_ACTION, input_type: osquery action_id: 3dfa2e89-1f33-438f-a4c1-c6eaddf8d0ab, type: INPUT_ACTION, input_type: osquery action_id: fd4579e7-1a9c-4dc5-8044-21f063076eb9, type: INPUT_ACTION, input_type: osquery action_id: 5ab0e046-e1fd-4817-9ebb-908385e74a5b, type: INPUT_ACTION, input_type: osquery action_id: b010cd72-76a8-42d5-bbe2-4aa27abc315a, type: INPUT_ACTION, input_type: osquery action_id: 3e4a2268-9428-428f-9f71-e88db16d731d, type: INPUT_ACTION, input_type: osquery action_id: cd7f1842-e31c-4008-bf75-8f2eefb21b53, type: INPUT_ACTION, input_type: osquery action_id: f318f988-0725-4518-af89-fafd91d3972b, type: INPUT_ACTION, input_type: osquery action_id: 61ec4244-73f6-43a4-9f26-cc380289f3fc, type: INPUT_ACTION, input_type: osquery action_id: 77b03393-48b2-4b18-a2c0-c3c88916f633, type: INPUT_ACTION, input_type: osquery action_id: 5c2f89e9-a25b-4a10-9f6e-9ed2ed4be941, type: INPUT_ACTION, input_type: osquery action_id: b4217136-3cd9-4ad0-8a08-8b6a39342a12, type: INPUT_ACTION, input_type: osquery action_id: 13d18a4e-7227-4a6c-b0d4-64a4bc87a6b2, type: INPUT_ACTION, input_type: osquery action_id: b45956d0-4102-4812-ae27-991d28939633, type: INPUT_ACTION, input_type: osquery action_id: e7c17462-a032-4eca-a56d-fd445de55926, type: INPUT_ACTION, input_type: osquery action_id: 578f0c32-29b3-47b1-8f12-21612244a0df, type: INPUT_ACTION, input_type: osquery action_id: 34c2e13e-7973-462e-9d53-9dcdded6acdc, type: INPUT_ACTION, input_type: osquery action_id: 95cadf80-2377-4add-9234-1e7d20acb070, type: INPUT_ACTION, input_type: osquery action_id: 9e6392cd-379d-4e01-9fa5-2784fedd4980, type: INPUT_ACTION, input_type: osquery action_id: 9533c517-13af-410d-873b-d6639201a275, type: INPUT_ACTION, input_type: osquery action_id: d67cf6d4-42b2-4338-9294-4bae8b63bf64, type: INPUT_ACTION, input_type: osquery action_id: cc01acf7-57b0-4e88-83c8-9d33098f526d, type: INPUT_ACTION, input_type: osquery action_id: 2e1775af-1891-4773-adff-4c2b849cf43e, type: INPUT_ACTION, input_type: osquery action_id: 9925ff01-f96e-449e-a278-76286b7bfb5d, type: INPUT_ACTION, input_type: osquery action_id: f991dff1-e2a2-4e1b-8bae-f42c9a50a3aa, type: INPUT_ACTION, input_type: osquery action_id: 5de5f329-5dd8-472a-ac2e-e2b5e67c46cc, type: INPUT_ACTION, input_type: osquery action_id: 29384920-9fa7-4673-9963-8560c0f28656, type: INPUT_ACTION, input_type: osquery action_id: c6699672-d584-449c-82d2-44aa79409aa6, type: INPUT_ACTION, input_type: osquery action_id: 34f1e251-8c80-4069-a078-e1d688f2d6a8, type: INPUT_ACTION, input_type: osquery action_id: b51363c6-a844-40f9-a560-029ccbedacc4, type: INPUT_ACTION, input_type: osquery action_id: 29442ec3-8848-4118-984e-f4b7e3ae3f0a, type: INPUT_ACTION, input_type: osquery action_id: 80feb1f2-5c2c-4bf5-8907-2a62fd076204, type: INPUT_ACTION, input_type: osquery action_id: 2781d06b-da55-4a70-9c8d-c472f300de63, type: INPUT_ACTION, input_type: osquery action_id: 94b2da4d-e306-4217-bce7-a2dcb714ce56, type: INPUT_ACTION, input_type: osquery action_id: 2daa34aa-1b2c-41a1-a9be-96bb00efdd20, type: INPUT_ACTION, input_type: osquery action_id: cbcadff9-7882-4fde-ab87-60de662362e5, type: INPUT_ACTION, input_type: osquery action_id: 3211eab9-3a32-44fa-b28b-4a3f2d533a51, type: INPUT_ACTION, input_type: osquery action_id: 0666e261-8899-4a57-8dd9-dd059725fe2a, type: INPUT_ACTION, input_type: osquery action_id: a63d57a6-1329-420a-977c-7f0d57e31843, type: INPUT_ACTION, input_type: osquery action_id: 80b2a7c6-f54c-452c-8507-49103725cf60, type: INPUT_ACTION, input_type: osquery action_id: ea3bfd12-bf0c-48d9-a044-4838877e31a8, type: INPUT_ACTION, input_type: osquery action_id: 5b1f232a-2cb0-4b94-a739-a00a7fc879a8, type: INPUT_ACTION, input_type: osquery action_id: 5e8a9d30-e39f-4f00-af0b-63f6a581e391, type: INPUT_ACTION, input_type: osquery action_id: 51a5975d-90c3-4a32-bf4b-f85acf7f3167, type: INPUT_ACTION, input_type: osquery action_id: a1940628-9739-4cde-9847-eaaf35f21818, type: INPUT_ACTION, input_type: osquery action_id: ce002006-1c6b-407f-a148-3973ccb68816, type: INPUT_ACTION, input_type: osquery action_id: 69ac6db4-aba1-434b-8a21-fe7194a3f8c7, type: INPUT_ACTION, input_type: osquery action_id: 4f936f72-c79c-4c87-8d8b-ddd6d6570241, type: INPUT_ACTION, input_type: osquery action_id: 3b793207-542a-4dde-a73b-71b4b4e70dfd, type: INPUT_ACTION, input_type: osquery action_id: f273b267-1826-46ff-8f38-054d3a596e15, type: INPUT_ACTION, input_type: osquery action_id: 89333e6e-e426-4b96-abd4-98b03e3fd906, type: INPUT_ACTION, input_type: osquery action_id: 0f923b30-fbf0-48bf-aee3-21c68eefa8f3, type: INPUT_ACTION, input_type: osquery action_id: 4e2ab88a-37a3-4d89-b508-9030a6f9b31e, type: INPUT_ACTION, input_type: osquery action_id: cdfe6260-7ce7-4438-873f-43725cd572e9, type: INPUT_ACTION, input_type: osquery action_id: 8b7271f9-9479-471e-bb95-128496a7523d, type: INPUT_ACTION, input_type: osquery action_id: ea219145-e2ca-44ee-a1c5-fd0e61fe7b31, type: INPUT_ACTION, input_type: osquery action_id: 1ff5b5b9-29a0-4ad9-994d-2843e2469cab, type: INPUT_ACTION, input_type: osquery action_id: fd5a125d-9ef5-42ea-869e-45165d0474de, type: INPUT_ACTION, input_type: osquery action_id: 434f147f-5ccc-439f-acb4-3857351cad59, type: INPUT_ACTION, input_type: osquery action_id: fad5a060-980e-4298-99f4-9633ec5c3e09, type: INPUT_ACTION, input_type: osquery action_id: 3e5009a6-e1d2-4fb9-957f-4eb2322f4605, type: INPUT_ACTION, input_type: osquery action_id: 6b661af2-15e4-4c39-a99d-170e6ac860c6, type: INPUT_ACTION, input_type: osquery action_id: 573b17b3-be63-4414-a15e-deeb329d4e88, type: INPUT_ACTION, input_type: osquery action_id: 080b1e8a-9442-4838-bb91-e01e4a3c88f1, type: INPUT_ACTION, input_type: osquery action_id: cd89db7a-6a0f-4dd7-bba0-35d348916dcb, type: INPUT_ACTION, input_type: osquery action_id: 0c9072dd-60ff-45da-858a-19faedf9cd2e, type: INPUT_ACTION, input_type: osquery action_id: a93caba6-5f87-4d31-a180-ad71ddf0c41f, type: INPUT_ACTION, input_type: osquery action_id: 6e2277c4-a4b7-4e7e-b6b4-ddd27f509944, type: INPUT_ACTION, input_type: osquery action_id: 9bd8993b-a1c8-4500-b490-a2979df28814, type: INPUT_ACTION, input_type: osquery action_id: bb8eba2f-677a-4956-ab5e-875e97ac2e4b, type: INPUT_ACTION, input_type: osquery action_id: eccbd260-3376-430b-9180-e480952e7bc3, type: INPUT_ACTION, input_type: osquery action_id: b27bd722-7f6e-430d-984b-7776c2df8ed3, type: INPUT_ACTION, input_type: osquery action_id: bef27697-0292-4624-a8d7-8fd4b81a63fc, type: INPUT_ACTION, input_type: osquery action_id: 32f671ca-7e09-45b8-9b9d-459a0445c2e3, type: INPUT_ACTION, input_type: osquery action_id: 46863222-9ab4-42f4-a86a-9e3d1b6d708b, type: INPUT_ACTION, input_type: osquery]","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-01-11T08:48:43.300Z","log.origin":{"file.name":"fleet/fleet_acker.go","file.line":107},"message":"acknowledging 80 actions with ids '63c2d329-1ef5-4f6a-bee6-87f0538cd2a2,246d0292-abbb-436a-9940-b0d1fbd6d473,b7227cf5-55f9-4735-8d73-76c20f4bbc40,51d1b2cc-47fc-4edf-a02d-1d999ceed486,ac395ce1-a96e-490d-ba9c-2e263a536a19,4a342fe8-7348-45ef-81a2-51a0464194ff,3dfa2e89-1f33-438f-a4c1-c6eaddf8d0ab,fd4579e7-1a9c-4dc5-8044-21f063076eb9,5ab0e046-e1fd-4817-9ebb-908385e74a5b,b010cd72-76a8-42d5-bbe2-4aa27abc315a,3e4a2268-9428-428f-9f71-e88db16d731d,cd7f1842-e31c-4008-bf75-8f2eefb21b53,f318f988-0725-4518-af89-fafd91d3972b,61ec4244-73f6-43a4-9f26-cc380289f3fc,77b03393-48b2-4b18-a2c0-c3c88916f633,5c2f89e9-a25b-4a10-9f6e-9ed2ed4be941,b4217136-3cd9-4ad0-8a08-8b6a39342a12,13d18a4e-7227-4a6c-b0d4-64a4bc87a6b2,b45956d0-4102-4812-ae27-991d28939633,e7c17462-a032-4eca-a56d-fd445de55926,578f0c32-29b3-47b1-8f12-21612244a0df,34c2e13e-7973-462e-9d53-9dcdded6acdc,95cadf80-2377-4add-9234-1e7d20acb070,9e6392cd-379d-4e01-9fa5-2784fedd4980,9533c517-13af-410d-873b-d6639201a275,d67cf6d4-42b2-4338-9294-4bae8b63bf64,cc01acf7-57b0-4e88-83c8-9d33098f526d,2e1775af-1891-4773-adff-4c2b849cf43e,9925ff01-f96e-449e-a278-76286b7bfb5d,f991dff1-e2a2-4e1b-8bae-f42c9a50a3aa,5de5f329-5dd8-472a-ac2e-e2b5e67c46cc,29384920-9fa7-4673-9963-8560c0f28656,c6699672-d584-449c-82d2-44aa79409aa6,34f1e251-8c80-4069-a078-e1d688f2d6a8,b51363c6-a844-40f9-a560-029ccbedacc4,29442ec3-8848-4118-984e-f4b7e3ae3f0a,80feb1f2-5c2c-4bf5-8907-2a62fd076204,2781d06b-da55-4a70-9c8d-c472f300de63,94b2da4d-e306-4217-bce7-a2dcb714ce56,2daa34aa-1b2c-41a1-a9be-96bb00efdd20,cbcadff9-7882-4fde-ab87-60de662362e5,3211eab9-3a32-44fa-b28b-4a3f2d533a51,0666e261-8899-4a57-8dd9-dd059725fe2a,a63d57a6-1329-420a-977c-7f0d57e31843,80b2a7c6-f54c-452c-8507-49103725cf60,ea3bfd12-bf0c-48d9-a044-4838877e31a8,5b1f232a-2cb0-4b94-a739-a00a7fc879a8,5e8a9d30-e39f-4f00-af0b-63f6a581e391,51a5975d-90c3-4a32-bf4b-f85acf7f3167,a1940628-9739-4cde-9847-eaaf35f21818,ce002006-1c6b-407f-a148-3973ccb68816,69ac6db4-aba1-434b-8a21-fe7194a3f8c7,4f936f72-c79c-4c87-8d8b-ddd6d6570241,3b793207-542a-4dde-a73b-71b4b4e70dfd,f273b267-1826-46ff-8f38-054d3a596e15,89333e6e-e426-4b96-abd4-98b03e3fd906,0f923b30-fbf0-48bf-aee3-21c68eefa8f3,4e2ab88a-37a3-4d89-b508-9030a6f9b31e,cdfe6260-7ce7-4438-873f-43725cd572e9,8b7271f9-9479-471e-bb95-128496a7523d,ea219145-e2ca-44ee-a1c5-fd0e61fe7b31,1ff5b5b9-29a0-4ad9-994d-2843e2469cab,fd5a125d-9ef5-42ea-869e-45165d0474de,434f147f-5ccc-439f-acb4-3857351cad59,fad5a060-980e-4298-99f4-9633ec5c3e09,3e5009a6-e1d2-4fb9-957f-4eb2322f4605,6b661af2-15e4-4c39-a99d-170e6ac860c6,573b17b3-be63-4414-a15e-deeb329d4e88,080b1e8a-9442-4838-bb91-e01e4a3c88f1,cd89db7a-6a0f-4dd7-bba0-35d348916dcb,0c9072dd-60ff-45da-858a-19faedf9cd2e,a93caba6-5f87-4d31-a180-ad71ddf0c41f,6e2277c4-a4b7-4e7e-b6b4-ddd27f509944,9bd8993b-a1c8-4500-b490-a2979df28814,bb8eba2f-677a-4956-ab5e-875e97ac2e4b,eccbd260-3376-430b-9180-e480952e7bc3,b27bd722-7f6e-430d-984b-7776c2df8ed3,bef27697-0292-4624-a8d7-8fd4b81a63fc,32f671ca-7e09-45b8-9b9d-459a0445c2e3,46863222-9ab4-42f4-a86a-9e3d1b6d708b'","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-01-11T08:50:04.302Z","log.origin":{"file.name":"fleet/fleet_acker.go","file.line":110},"message":"acknowledged 80 actions with ids '63c2d329-1ef5-4f6a-bee6-87f0538cd2a2,246d0292-abbb-436a-9940-b0d1fbd6d473,b7227cf5-55f9-4735-8d73-76c20f4bbc40,51d1b2cc-47fc-4edf-a02d-1d999ceed486,ac395ce1-a96e-490d-ba9c-2e263a536a19,4a342fe8-7348-45ef-81a2-51a0464194ff,3dfa2e89-1f33-438f-a4c1-c6eaddf8d0ab,fd4579e7-1a9c-4dc5-8044-21f063076eb9,5ab0e046-e1fd-4817-9ebb-908385e74a5b,b010cd72-76a8-42d5-bbe2-4aa27abc315a,3e4a2268-9428-428f-9f71-e88db16d731d,cd7f1842-e31c-4008-bf75-8f2eefb21b53,f318f988-0725-4518-af89-fafd91d3972b,61ec4244-73f6-43a4-9f26-cc380289f3fc,77b03393-48b2-4b18-a2c0-c3c88916f633,5c2f89e9-a25b-4a10-9f6e-9ed2ed4be941,b4217136-3cd9-4ad0-8a08-8b6a39342a12,13d18a4e-7227-4a6c-b0d4-64a4bc87a6b2,b45956d0-4102-4812-ae27-991d28939633,e7c17462-a032-4eca-a56d-fd445de55926,578f0c32-29b3-47b1-8f12-21612244a0df,34c2e13e-7973-462e-9d53-9dcdded6acdc,95cadf80-2377-4add-9234-1e7d20acb070,9e6392cd-379d-4e01-9fa5-2784fedd4980,9533c517-13af-410d-873b-d6639201a275,d67cf6d4-42b2-4338-9294-4bae8b63bf64,cc01acf7-57b0-4e88-83c8-9d33098f526d,2e1775af-1891-4773-adff-4c2b849cf43e,9925ff01-f96e-449e-a278-76286b7bfb5d,f991dff1-e2a2-4e1b-8bae-f42c9a50a3aa,5de5f329-5dd8-472a-ac2e-e2b5e67c46cc,29384920-9fa7-4673-9963-8560c0f28656,c6699672-d584-449c-82d2-44aa79409aa6,34f1e251-8c80-4069-a078-e1d688f2d6a8,b51363c6-a844-40f9-a560-029ccbedacc4,29442ec3-8848-4118-984e-f4b7e3ae3f0a,80feb1f2-5c2c-4bf5-8907-2a62fd076204,2781d06b-da55-4a70-9c8d-c472f300de63,94b2da4d-e306-4217-bce7-a2dcb714ce56,2daa34aa-1b2c-41a1-a9be-96bb00efdd20,cbcadff9-7882-4fde-ab87-60de662362e5,3211eab9-3a32-44fa-b28b-4a3f2d533a51,0666e261-8899-4a57-8dd9-dd059725fe2a,a63d57a6-1329-420a-977c-7f0d57e31843,80b2a7c6-f54c-452c-8507-49103725cf60,ea3bfd12-bf0c-48d9-a044-4838877e31a8,5b1f232a-2cb0-4b94-a739-a00a7fc879a8,5e8a9d30-e39f-4f00-af0b-63f6a581e391,51a5975d-90c3-4a32-bf4b-f85acf7f3167,a1940628-9739-4cde-9847-eaaf35f21818,ce002006-1c6b-407f-a148-3973ccb68816,69ac6db4-aba1-434b-8a21-fe7194a3f8c7,4f936f72-c79c-4c87-8d8b-ddd6d6570241,3b793207-542a-4dde-a73b-71b4b4e70dfd,f273b267-1826-46ff-8f38-054d3a596e15,89333e6e-e426-4b96-abd4-98b03e3fd906,0f923b30-fbf0-48bf-aee3-21c68eefa8f3,4e2ab88a-37a3-4d89-b508-9030a6f9b31e,cdfe6260-7ce7-4438-873f-43725cd572e9,8b7271f9-9479-471e-bb95-128496a7523d,ea219145-e2ca-44ee-a1c5-fd0e61fe7b31,1ff5b5b9-29a0-4ad9-994d-2843e2469cab,fd5a125d-9ef5-42ea-869e-45165d0474de,434f147f-5ccc-439f-acb4-3857351cad59,fad5a060-980e-4298-99f4-9633ec5c3e09,3e5009a6-e1d2-4fb9-957f-4eb2322f4605,6b661af2-15e4-4c39-a99d-170e6ac860c6,573b17b3-be63-4414-a15e-deeb329d4e88,080b1e8a-9442-4838-bb91-e01e4a3c88f1,cd89db7a-6a0f-4dd7-bba0-35d348916dcb,0c9072dd-60ff-45da-858a-19faedf9cd2e,a93caba6-5f87-4d31-a180-ad71ddf0c41f,6e2277c4-a4b7-4e7e-b6b4-ddd27f509944,9bd8993b-a1c8-4500-b490-a2979df28814,bb8eba2f-677a-4956-ab5e-875e97ac2e4b,eccbd260-3376-430b-9180-e480952e7bc3,b27bd722-7f6e-430d-984b-7776c2df8ed3,bef27697-0292-4624-a8d7-8fd4b81a63fc,32f671ca-7e09-45b8-9b9d-459a0445c2e3,46863222-9ab4-42f4-a86a-9e3d1b6d708b'","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-01-11T08:50:04.302Z","log.origin":{"file.name":"lazy/lazy_acker.go","file.line":96},"message":"lazy acker: acked batch: [action_id: 63c2d329-1ef5-4f6a-bee6-87f0538cd2a2, type: INPUT_ACTION, input_type: osquery action_id: 246d0292-abbb-436a-9940-b0d1fbd6d473, type: INPUT_ACTION, input_type: osquery action_id: b7227cf5-55f9-4735-8d73-76c20f4bbc40, type: INPUT_ACTION, input_type: osquery action_id: 51d1b2cc-47fc-4edf-a02d-1d999ceed486, type: INPUT_ACTION, input_type: osquery action_id: ac395ce1-a96e-490d-ba9c-2e263a536a19, type: INPUT_ACTION, input_type: osquery action_id: 4a342fe8-7348-45ef-81a2-51a0464194ff, type: INPUT_ACTION, input_type: osquery action_id: 3dfa2e89-1f33-438f-a4c1-c6eaddf8d0ab, type: INPUT_ACTION, input_type: osquery action_id: fd4579e7-1a9c-4dc5-8044-21f063076eb9, type: INPUT_ACTION, input_type: osquery action_id: 5ab0e046-e1fd-4817-9ebb-908385e74a5b, type: INPUT_ACTION, input_type: osquery action_id: b010cd72-76a8-42d5-bbe2-4aa27abc315a, type: INPUT_ACTION, input_type: osquery action_id: 3e4a2268-9428-428f-9f71-e88db16d731d, type: INPUT_ACTION, input_type: osquery action_id: cd7f1842-e31c-4008-bf75-8f2eefb21b53, type: INPUT_ACTION, input_type: osquery action_id: f318f988-0725-4518-af89-fafd91d3972b, type: INPUT_ACTION, input_type: osquery action_id: 61ec4244-73f6-43a4-9f26-cc380289f3fc, type: INPUT_ACTION, input_type: osquery action_id: 77b03393-48b2-4b18-a2c0-c3c88916f633, type: INPUT_ACTION, input_type: osquery action_id: 5c2f89e9-a25b-4a10-9f6e-9ed2ed4be941, type: INPUT_ACTION, input_type: osquery action_id: b4217136-3cd9-4ad0-8a08-8b6a39342a12, type: INPUT_ACTION, input_type: osquery action_id: 13d18a4e-7227-4a6c-b0d4-64a4bc87a6b2, type: INPUT_ACTION, input_type: osquery action_id: b45956d0-4102-4812-ae27-991d28939633, type: INPUT_ACTION, input_type: osquery action_id: e7c17462-a032-4eca-a56d-fd445de55926, type: INPUT_ACTION, input_type: osquery action_id: 578f0c32-29b3-47b1-8f12-21612244a0df, type: INPUT_ACTION, input_type: osquery action_id: 34c2e13e-7973-462e-9d53-9dcdded6acdc, type: INPUT_ACTION, input_type: osquery action_id: 95cadf80-2377-4add-9234-1e7d20acb070, type: INPUT_ACTION, input_type: osquery action_id: 9e6392cd-379d-4e01-9fa5-2784fedd4980, type: INPUT_ACTION, input_type: osquery action_id: 9533c517-13af-410d-873b-d6639201a275, type: INPUT_ACTION, input_type: osquery action_id: d67cf6d4-42b2-4338-9294-4bae8b63bf64, type: INPUT_ACTION, input_type: osquery action_id: cc01acf7-57b0-4e88-83c8-9d33098f526d, type: INPUT_ACTION, input_type: osquery action_id: 2e1775af-1891-4773-adff-4c2b849cf43e, type: INPUT_ACTION, input_type: osquery action_id: 9925ff01-f96e-449e-a278-76286b7bfb5d, type: INPUT_ACTION, input_type: osquery action_id: f991dff1-e2a2-4e1b-8bae-f42c9a50a3aa, type: INPUT_ACTION, input_type: osquery action_id: 5de5f329-5dd8-472a-ac2e-e2b5e67c46cc, type: INPUT_ACTION, input_type: osquery action_id: 29384920-9fa7-4673-9963-8560c0f28656, type: INPUT_ACTION, input_type: osquery action_id: c6699672-d584-449c-82d2-44aa79409aa6, type: INPUT_ACTION, input_type: osquery action_id: 34f1e251-8c80-4069-a078-e1d688f2d6a8, type: INPUT_ACTION, input_type: osquery action_id: b51363c6-a844-40f9-a560-029ccbedacc4, type: INPUT_ACTION, input_type: osquery action_id: 29442ec3-8848-4118-984e-f4b7e3ae3f0a, type: INPUT_ACTION, input_type: osquery action_id: 80feb1f2-5c2c-4bf5-8907-2a62fd076204, type: INPUT_ACTION, input_type: osquery action_id: 2781d06b-da55-4a70-9c8d-c472f300de63, type: INPUT_ACTION, input_type: osquery action_id: 94b2da4d-e306-4217-bce7-a2dcb714ce56, type: INPUT_ACTION, input_type: osquery action_id: 2daa34aa-1b2c-41a1-a9be-96bb00efdd20, type: INPUT_ACTION, input_type: osquery action_id: cbcadff9-7882-4fde-ab87-60de662362e5, type: INPUT_ACTION, input_type: osquery action_id: 3211eab9-3a32-44fa-b28b-4a3f2d533a51, type: INPUT_ACTION, input_type: osquery action_id: 0666e261-8899-4a57-8dd9-dd059725fe2a, type: INPUT_ACTION, input_type: osquery action_id: a63d57a6-1329-420a-977c-7f0d57e31843, type: INPUT_ACTION, input_type: osquery action_id: 80b2a7c6-f54c-452c-8507-49103725cf60, type: INPUT_ACTION, input_type: osquery action_id: ea3bfd12-bf0c-48d9-a044-4838877e31a8, type: INPUT_ACTION, input_type: osquery action_id: 5b1f232a-2cb0-4b94-a739-a00a7fc879a8, type: INPUT_ACTION, input_type: osquery action_id: 5e8a9d30-e39f-4f00-af0b-63f6a581e391, type: INPUT_ACTION, input_type: osquery action_id: 51a5975d-90c3-4a32-bf4b-f85acf7f3167, type: INPUT_ACTION, input_type: osquery action_id: a1940628-9739-4cde-9847-eaaf35f21818, type: INPUT_ACTION, input_type: osquery action_id: ce002006-1c6b-407f-a148-3973ccb68816, type: INPUT_ACTION, input_type: osquery action_id: 69ac6db4-aba1-434b-8a21-fe7194a3f8c7, type: INPUT_ACTION, input_type: osquery action_id: 4f936f72-c79c-4c87-8d8b-ddd6d6570241, type: INPUT_ACTION, input_type: osquery action_id: 3b793207-542a-4dde-a73b-71b4b4e70dfd, type: INPUT_ACTION, input_type: osquery action_id: f273b267-1826-46ff-8f38-054d3a596e15, type: INPUT_ACTION, input_type: osquery action_id: 89333e6e-e426-4b96-abd4-98b03e3fd906, type: INPUT_ACTION, input_type: osquery action_id: 0f923b30-fbf0-48bf-aee3-21c68eefa8f3, type: INPUT_ACTION, input_type: osquery action_id: 4e2ab88a-37a3-4d89-b508-9030a6f9b31e, type: INPUT_ACTION, input_type: osquery action_id: cdfe6260-7ce7-4438-873f-43725cd572e9, type: INPUT_ACTION, input_type: osquery action_id: 8b7271f9-9479-471e-bb95-128496a7523d, type: INPUT_ACTION, input_type: osquery action_id: ea219145-e2ca-44ee-a1c5-fd0e61fe7b31, type: INPUT_ACTION, input_type: osquery action_id: 1ff5b5b9-29a0-4ad9-994d-2843e2469cab, type: INPUT_ACTION, input_type: osquery action_id: fd5a125d-9ef5-42ea-869e-45165d0474de, type: INPUT_ACTION, input_type: osquery action_id: 434f147f-5ccc-439f-acb4-3857351cad59, type: INPUT_ACTION, input_type: osquery action_id: fad5a060-980e-4298-99f4-9633ec5c3e09, type: INPUT_ACTION, input_type: osquery action_id: 3e5009a6-e1d2-4fb9-957f-4eb2322f4605, type: INPUT_ACTION, input_type: osquery action_id: 6b661af2-15e4-4c39-a99d-170e6ac860c6, type: INPUT_ACTION, input_type: osquery action_id: 573b17b3-be63-4414-a15e-deeb329d4e88, type: INPUT_ACTION, input_type: osquery action_id: 080b1e8a-9442-4838-bb91-e01e4a3c88f1, type: INPUT_ACTION, input_type: osquery action_id: cd89db7a-6a0f-4dd7-bba0-35d348916dcb, type: INPUT_ACTION, input_type: osquery action_id: 0c9072dd-60ff-45da-858a-19faedf9cd2e, type: INPUT_ACTION, input_type: osquery action_id: a93caba6-5f87-4d31-a180-ad71ddf0c41f, type: INPUT_ACTION, input_type: osquery action_id: 6e2277c4-a4b7-4e7e-b6b4-ddd27f509944, type: INPUT_ACTION, input_type: osquery action_id: 9bd8993b-a1c8-4500-b490-a2979df28814, type: INPUT_ACTION, input_type: osquery action_id: bb8eba2f-677a-4956-ab5e-875e97ac2e4b, type: INPUT_ACTION, input_type: osquery action_id: eccbd260-3376-430b-9180-e480952e7bc3, type: INPUT_ACTION, input_type: osquery action_id: b27bd722-7f6e-430d-984b-7776c2df8ed3, type: INPUT_ACTION, input_type: osquery action_id: bef27697-0292-4624-a8d7-8fd4b81a63fc, type: INPUT_ACTION, input_type: osquery action_id: 32f671ca-7e09-45b8-9b9d-459a0445c2e3, type: INPUT_ACTION, input_type: osquery action_id: 46863222-9ab4-42f4-a86a-9e3d1b6d708b, type: INPUT_ACTION, input_type: osquery]","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-01-11T08:50:04.303Z","log.origin":{"file.name":"lazy/lazy_acker.go","file.line":124},"message":"lazy acker: commit [action_id: 63c2d329-1ef5-4f6a-bee6-87f0538cd2a2, type: INPUT_ACTION, input_type: osquery action_id: 246d0292-abbb-436a-9940-b0d1fbd6d473, type: INPUT_ACTION, input_type: osquery action_id: b7227cf5-55f9-4735-8d73-76c20f4bbc40, type: INPUT_ACTION, input_type: osquery action_id: 51d1b2cc-47fc-4edf-a02d-1d999ceed486, type: INPUT_ACTION, input_type: osquery action_id: ac395ce1-a96e-490d-ba9c-2e263a536a19, type: INPUT_ACTION, input_type: osquery action_id: 4a342fe8-7348-45ef-81a2-51a0464194ff, type: INPUT_ACTION, input_type: osquery action_id: 3dfa2e89-1f33-438f-a4c1-c6eaddf8d0ab, type: INPUT_ACTION, input_type: osquery action_id: fd4579e7-1a9c-4dc5-8044-21f063076eb9, type: INPUT_ACTION, input_type: osquery action_id: 5ab0e046-e1fd-4817-9ebb-908385e74a5b, type: INPUT_ACTION, input_type: osquery action_id: b010cd72-76a8-42d5-bbe2-4aa27abc315a, type: INPUT_ACTION, input_type: osquery action_id: 3e4a2268-9428-428f-9f71-e88db16d731d, type: INPUT_ACTION, input_type: osquery action_id: cd7f1842-e31c-4008-bf75-8f2eefb21b53, type: INPUT_ACTION, input_type: osquery action_id: f318f988-0725-4518-af89-fafd91d3972b, type: INPUT_ACTION, input_type: osquery action_id: 61ec4244-73f6-43a4-9f26-cc380289f3fc, type: INPUT_ACTION, input_type: osquery action_id: 77b03393-48b2-4b18-a2c0-c3c88916f633, type: INPUT_ACTION, input_type: osquery action_id: 5c2f89e9-a25b-4a10-9f6e-9ed2ed4be941, type: INPUT_ACTION, input_type: osquery action_id: b4217136-3cd9-4ad0-8a08-8b6a39342a12, type: INPUT_ACTION, input_type: osquery action_id: 13d18a4e-7227-4a6c-b0d4-64a4bc87a6b2, type: INPUT_ACTION, input_type: osquery action_id: b45956d0-4102-4812-ae27-991d28939633, type: INPUT_ACTION, input_type: osquery action_id: e7c17462-a032-4eca-a56d-fd445de55926, type: INPUT_ACTION, input_type: osquery action_id: 578f0c32-29b3-47b1-8f12-21612244a0df, type: INPUT_ACTION, input_type: osquery action_id: 34c2e13e-7973-462e-9d53-9dcdded6acdc, type: INPUT_ACTION, input_type: osquery action_id: 95cadf80-2377-4add-9234-1e7d20acb070, type: INPUT_ACTION, input_type: osquery action_id: 9e6392cd-379d-4e01-9fa5-2784fedd4980, type: INPUT_ACTION, input_type: osquery action_id: 9533c517-13af-410d-873b-d6639201a275, type: INPUT_ACTION, input_type: osquery action_id: d67cf6d4-42b2-4338-9294-4bae8b63bf64, type: INPUT_ACTION, input_type: osquery action_id: cc01acf7-57b0-4e88-83c8-9d33098f526d, type: INPUT_ACTION, input_type: osquery action_id: 2e1775af-1891-4773-adff-4c2b849cf43e, type: INPUT_ACTION, input_type: osquery action_id: 9925ff01-f96e-449e-a278-76286b7bfb5d, type: INPUT_ACTION, input_type: osquery action_id: f991dff1-e2a2-4e1b-8bae-f42c9a50a3aa, type: INPUT_ACTION, input_type: osquery action_id: 5de5f329-5dd8-472a-ac2e-e2b5e67c46cc, type: INPUT_ACTION, input_type: osquery action_id: 29384920-9fa7-4673-9963-8560c0f28656, type: INPUT_ACTION, input_type: osquery action_id: c6699672-d584-449c-82d2-44aa79409aa6, type: INPUT_ACTION, input_type: osquery action_id: 34f1e251-8c80-4069-a078-e1d688f2d6a8, type: INPUT_ACTION, input_type: osquery action_id: b51363c6-a844-40f9-a560-029ccbedacc4, type: INPUT_ACTION, input_type: osquery action_id: 29442ec3-8848-4118-984e-f4b7e3ae3f0a, type: INPUT_ACTION, input_type: osquery action_id: 80feb1f2-5c2c-4bf5-8907-2a62fd076204, type: INPUT_ACTION, input_type: osquery action_id: 2781d06b-da55-4a70-9c8d-c472f300de63, type: INPUT_ACTION, input_type: osquery action_id: 94b2da4d-e306-4217-bce7-a2dcb714ce56, type: INPUT_ACTION, input_type: osquery action_id: 2daa34aa-1b2c-41a1-a9be-96bb00efdd20, type: INPUT_ACTION, input_type: osquery action_id: cbcadff9-7882-4fde-ab87-60de662362e5, type: INPUT_ACTION, input_type: osquery action_id: 3211eab9-3a32-44fa-b28b-4a3f2d533a51, type: INPUT_ACTION, input_type: osquery action_id: 0666e261-8899-4a57-8dd9-dd059725fe2a, type: INPUT_ACTION, input_type: osquery action_id: a63d57a6-1329-420a-977c-7f0d57e31843, type: INPUT_ACTION, input_type: osquery action_id: 80b2a7c6-f54c-452c-8507-49103725cf60, type: INPUT_ACTION, input_type: osquery action_id: ea3bfd12-bf0c-48d9-a044-4838877e31a8, type: INPUT_ACTION, input_type: osquery action_id: 5b1f232a-2cb0-4b94-a739-a00a7fc879a8, type: INPUT_ACTION, input_type: osquery action_id: 5e8a9d30-e39f-4f00-af0b-63f6a581e391, type: INPUT_ACTION, input_type: osquery action_id: 51a5975d-90c3-4a32-bf4b-f85acf7f3167, type: INPUT_ACTION, input_type: osquery action_id: a1940628-9739-4cde-9847-eaaf35f21818, type: INPUT_ACTION, input_type: osquery action_id: ce002006-1c6b-407f-a148-3973ccb68816, type: INPUT_ACTION, input_type: osquery action_id: 69ac6db4-aba1-434b-8a21-fe7194a3f8c7, type: INPUT_ACTION, input_type: osquery action_id: 4f936f72-c79c-4c87-8d8b-ddd6d6570241, type: INPUT_ACTION, input_type: osquery action_id: 3b793207-542a-4dde-a73b-71b4b4e70dfd, type: INPUT_ACTION, input_type: osquery action_id: f273b267-1826-46ff-8f38-054d3a596e15, type: INPUT_ACTION, input_type: osquery action_id: 89333e6e-e426-4b96-abd4-98b03e3fd906, type: INPUT_ACTION, input_type: osquery action_id: 0f923b30-fbf0-48bf-aee3-21c68eefa8f3, type: INPUT_ACTION, input_type: osquery action_id: 4e2ab88a-37a3-4d89-b508-9030a6f9b31e, type: INPUT_ACTION, input_type: osquery action_id: cdfe6260-7ce7-4438-873f-43725cd572e9, type: INPUT_ACTION, input_type: osquery action_id: 8b7271f9-9479-471e-bb95-128496a7523d, type: INPUT_ACTION, input_type: osquery action_id: ea219145-e2ca-44ee-a1c5-fd0e61fe7b31, type: INPUT_ACTION, input_type: osquery action_id: 1ff5b5b9-29a0-4ad9-994d-2843e2469cab, type: INPUT_ACTION, input_type: osquery action_id: fd5a125d-9ef5-42ea-869e-45165d0474de, type: INPUT_ACTION, input_type: osquery action_id: 434f147f-5ccc-439f-acb4-3857351cad59, type: INPUT_ACTION, input_type: osquery action_id: fad5a060-980e-4298-99f4-9633ec5c3e09, type: INPUT_ACTION, input_type: osquery action_id: 3e5009a6-e1d2-4fb9-957f-4eb2322f4605, type: INPUT_ACTION, input_type: osquery action_id: 6b661af2-15e4-4c39-a99d-170e6ac860c6, type: INPUT_ACTION, input_type: osquery action_id: 573b17b3-be63-4414-a15e-deeb329d4e88, type: INPUT_ACTION, input_type: osquery action_id: 080b1e8a-9442-4838-bb91-e01e4a3c88f1, type: INPUT_ACTION, input_type: osquery action_id: cd89db7a-6a0f-4dd7-bba0-35d348916dcb, type: INPUT_ACTION, input_type: osquery action_id: 0c9072dd-60ff-45da-858a-19faedf9cd2e, type: INPUT_ACTION, input_type: osquery action_id: a93caba6-5f87-4d31-a180-ad71ddf0c41f, type: INPUT_ACTION, input_type: osquery action_id: 6e2277c4-a4b7-4e7e-b6b4-ddd27f509944, type: INPUT_ACTION, input_type: osquery action_id: 9bd8993b-a1c8-4500-b490-a2979df28814, type: INPUT_ACTION, input_type: osquery action_id: bb8eba2f-677a-4956-ab5e-875e97ac2e4b, type: INPUT_ACTION, input_type: osquery action_id: eccbd260-3376-430b-9180-e480952e7bc3, type: INPUT_ACTION, input_type: osquery action_id: b27bd722-7f6e-430d-984b-7776c2df8ed3, type: INPUT_ACTION, input_type: osquery action_id: bef27697-0292-4624-a8d7-8fd4b81a63fc, type: INPUT_ACTION, input_type: osquery action_id: 32f671ca-7e09-45b8-9b9d-459a0445c2e3, type: INPUT_ACTION, input_type: osquery action_id: 46863222-9ab4-42f4-a86a-9e3d1b6d708b, type: INPUT_ACTION, input_type: osquery]","ecs.version":"1.6.0"}

between START of first and last action it's 4 mintues diff.
and it took almost 2 minutes to finish ACK request

{"log.level":"warn","@timestamp":"2023-01-11T08:48:43.300Z","log.origin":{"file.name":"fleet/fleet_acker.go","file.line":107},"message":"acknowledging 80 actions with ids '63c2d329-1ef5-4f6a-bee6-87f0538cd2a2,246d0292-abbb-436a-9940-b0d1fbd6d473,b7227cf5-55f9-4735-8d73-76c20f4bbc40,51d1b2cc-47fc-4edf-a02d-1d999ceed486,ac395ce1-a96e-490d-ba9c-2e263a536a19,4a342fe8-7348-45ef-81a2-51a0464194ff,3dfa2e89-1f33-438f-a4c1-c6eaddf8d0ab,fd4579e7-1a9c-4dc5-8044-21f063076eb9,5ab0e046-e1fd-4817-9ebb-908385e74a5b,b010cd72-76a8-42d5-bbe2-4aa27abc315a,3e4a2268-9428-428f-9f71-e88db16d731d,cd7f1842-e31c-4008-bf75-8f2eefb21b53,f318f988-0725-4518-af89-fafd91d3972b,61ec4244-73f6-43a4-9f26-cc380289f3fc,77b03393-48b2-4b18-a2c0-c3c88916f633,5c2f89e9-a25b-4a10-9f6e-9ed2ed4be941,b4217136-3cd9-4ad0-8a08-8b6a39342a12,13d18a4e-7227-4a6c-b0d4-64a4bc87a6b2,b45956d0-4102-4812-ae27-991d28939633,e7c17462-a032-4eca-a56d-fd445de55926,578f0c32-29b3-47b1-8f12-21612244a0df,34c2e13e-7973-462e-9d53-9dcdded6acdc,95cadf80-2377-4add-9234-1e7d20acb070,9e6392cd-379d-4e01-9fa5-2784fedd4980,9533c517-13af-410d-873b-d6639201a275,d67cf6d4-42b2-4338-9294-4bae8b63bf64,cc01acf7-57b0-4e88-83c8-9d33098f526d,2e1775af-1891-4773-adff-4c2b849cf43e,9925ff01-f96e-449e-a278-76286b7bfb5d,f991dff1-e2a2-4e1b-8bae-f42c9a50a3aa,5de5f329-5dd8-472a-ac2e-e2b5e67c46cc,29384920-9fa7-4673-9963-8560c0f28656,c6699672-d584-449c-82d2-44aa79409aa6,34f1e251-8c80-4069-a078-e1d688f2d6a8,b51363c6-a844-40f9-a560-029ccbedacc4,29442ec3-8848-4118-984e-f4b7e3ae3f0a,80feb1f2-5c2c-4bf5-8907-2a62fd076204,2781d06b-da55-4a70-9c8d-c472f300de63,94b2da4d-e306-4217-bce7-a2dcb714ce56,2daa34aa-1b2c-41a1-a9be-96bb00efdd20,cbcadff9-7882-4fde-ab87-60de662362e5,3211eab9-3a32-44fa-b28b-4a3f2d533a51,0666e261-8899-4a57-8dd9-dd059725fe2a,a63d57a6-1329-420a-977c-7f0d57e31843,80b2a7c6-f54c-452c-8507-49103725cf60,ea3bfd12-bf0c-48d9-a044-4838877e31a8,5b1f232a-2cb0-4b94-a739-a00a7fc879a8,5e8a9d30-e39f-4f00-af0b-63f6a581e391,51a5975d-90c3-4a32-bf4b-f85acf7f3167,a1940628-9739-4cde-9847-eaaf35f21818,ce002006-1c6b-407f-a148-3973ccb68816,69ac6db4-aba1-434b-8a21-fe7194a3f8c7,4f936f72-c79c-4c87-8d8b-ddd6d6570241,3b793207-542a-4dde-a73b-71b4b4e70dfd,f273b267-1826-46ff-8f38-054d3a596e15,89333e6e-e426-4b96-abd4-98b03e3fd906,0f923b30-fbf0-48bf-aee3-21c68eefa8f3,4e2ab88a-37a3-4d89-b508-9030a6f9b31e,cdfe6260-7ce7-4438-873f-43725cd572e9,8b7271f9-9479-471e-bb95-128496a7523d,ea219145-e2ca-44ee-a1c5-fd0e61fe7b31,1ff5b5b9-29a0-4ad9-994d-2843e2469cab,fd5a125d-9ef5-42ea-869e-45165d0474de,434f147f-5ccc-439f-acb4-3857351cad59,fad5a060-980e-4298-99f4-9633ec5c3e09,3e5009a6-e1d2-4fb9-957f-4eb2322f4605,6b661af2-15e4-4c39-a99d-170e6ac860c6,573b17b3-be63-4414-a15e-deeb329d4e88,080b1e8a-9442-4838-bb91-e01e4a3c88f1,cd89db7a-6a0f-4dd7-bba0-35d348916dcb,0c9072dd-60ff-45da-858a-19faedf9cd2e,a93caba6-5f87-4d31-a180-ad71ddf0c41f,6e2277c4-a4b7-4e7e-b6b4-ddd27f509944,9bd8993b-a1c8-4500-b490-a2979df28814,bb8eba2f-677a-4956-ab5e-875e97ac2e4b,eccbd260-3376-430b-9180-e480952e7bc3,b27bd722-7f6e-430d-984b-7776c2df8ed3,bef27697-0292-4624-a8d7-8fd4b81a63fc,32f671ca-7e09-45b8-9b9d-459a0445c2e3,46863222-9ab4-42f4-a86a-9e3d1b6d708b'","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2023-01-11T08:50:04.302Z","log.origin":{"file.name":"fleet/fleet_acker.go","file.line":110},"message":"acknowledged 80 actions with ids '63c2d329-1ef5-4f6a-bee6-87f0538cd2a2,246d0292-abbb-436a-9940-b0d1fbd6d473,b7227cf5-55f9-4735-8d73-76c20f4bbc40,51d1b2cc-47fc-4edf-a02d-1d999ceed486,ac395ce1-a96e-490d-ba9c-2e263a536a19,4a342fe8-7348-45ef-81a2-51a0464194ff,3dfa2e89-1f33-438f-a4c1-c6eaddf8d0ab,fd4579e7-1a9c-4dc5-8044-21f063076eb9,5ab0e046-e1fd-4817-9ebb-908385e74a5b,b010cd72-76a8-42d5-bbe2-4aa27abc315a,3e4a2268-9428-428f-9f71-e88db16d731d,cd7f1842-e31c-4008-bf75-8f2eefb21b53,f318f988-0725-4518-af89-fafd91d3972b,61ec4244-73f6-43a4-9f26-cc380289f3fc,77b03393-48b2-4b18-a2c0-c3c88916f633,5c2f89e9-a25b-4a10-9f6e-9ed2ed4be941,b4217136-3cd9-4ad0-8a08-8b6a39342a12,13d18a4e-7227-4a6c-b0d4-64a4bc87a6b2,b45956d0-4102-4812-ae27-991d28939633,e7c17462-a032-4eca-a56d-fd445de55926,578f0c32-29b3-47b1-8f12-21612244a0df,34c2e13e-7973-462e-9d53-9dcdded6acdc,95cadf80-2377-4add-9234-1e7d20acb070,9e6392cd-379d-4e01-9fa5-2784fedd4980,9533c517-13af-410d-873b-d6639201a275,d67cf6d4-42b2-4338-9294-4bae8b63bf64,cc01acf7-57b0-4e88-83c8-9d33098f526d,2e1775af-1891-4773-adff-4c2b849cf43e,9925ff01-f96e-449e-a278-76286b7bfb5d,f991dff1-e2a2-4e1b-8bae-f42c9a50a3aa,5de5f329-5dd8-472a-ac2e-e2b5e67c46cc,29384920-9fa7-4673-9963-8560c0f28656,c6699672-d584-449c-82d2-44aa79409aa6,34f1e251-8c80-4069-a078-e1d688f2d6a8,b51363c6-a844-40f9-a560-029ccbedacc4,29442ec3-8848-4118-984e-f4b7e3ae3f0a,80feb1f2-5c2c-4bf5-8907-2a62fd076204,2781d06b-da55-4a70-9c8d-c472f300de63,94b2da4d-e306-4217-bce7-a2dcb714ce56,2daa34aa-1b2c-41a1-a9be-96bb00efdd20,cbcadff9-7882-4fde-ab87-60de662362e5,3211eab9-3a32-44fa-b28b-4a3f2d533a51,0666e261-8899-4a57-8dd9-dd059725fe2a,a63d57a6-1329-420a-977c-7f0d57e31843,80b2a7c6-f54c-452c-8507-49103725cf60,ea3bfd12-bf0c-48d9-a044-4838877e31a8,5b1f232a-2cb0-4b94-a739-a00a7fc879a8,5e8a9d30-e39f-4f00-af0b-63f6a581e391,51a5975d-90c3-4a32-bf4b-f85acf7f3167,a1940628-9739-4cde-9847-eaaf35f21818,ce002006-1c6b-407f-a148-3973ccb68816,69ac6db4-aba1-434b-8a21-fe7194a3f8c7,4f936f72-c79c-4c87-8d8b-ddd6d6570241,3b793207-542a-4dde-a73b-71b4b4e70dfd,f273b267-1826-46ff-8f38-054d3a596e15,89333e6e-e426-4b96-abd4-98b03e3fd906,0f923b30-fbf0-48bf-aee3-21c68eefa8f3,4e2ab88a-37a3-4d89-b508-9030a6f9b31e,cdfe6260-7ce7-4438-873f-43725cd572e9,8b7271f9-9479-471e-bb95-128496a7523d,ea219145-e2ca-44ee-a1c5-fd0e61fe7b31,1ff5b5b9-29a0-4ad9-994d-2843e2469cab,fd5a125d-9ef5-42ea-869e-45165d0474de,434f147f-5ccc-439f-acb4-3857351cad59,fad5a060-980e-4298-99f4-9633ec5c3e09,3e5009a6-e1d2-4fb9-957f-4eb2322f4605,6b661af2-15e4-4c39-a99d-170e6ac860c6,573b17b3-be63-4414-a15e-deeb329d4e88,080b1e8a-9442-4838-bb91-e01e4a3c88f1,cd89db7a-6a0f-4dd7-bba0-35d348916dcb,0c9072dd-60ff-45da-858a-19faedf9cd2e,a93caba6-5f87-4d31-a180-ad71ddf0c41f,6e2277c4-a4b7-4e7e-b6b4-ddd27f509944,9bd8993b-a1c8-4500-b490-a2979df28814,bb8eba2f-677a-4956-ab5e-875e97ac2e4b,eccbd260-3376-430b-9180-e480952e7bc3,b27bd722-7f6e-430d-984b-7776c2df8ed3,bef27697-0292-4624-a8d7-8fd4b81a63fc,32f671ca-7e09-45b8-9b9d-459a0445c2e3,46863222-9ab4-42f4-a86a-9e3d1b6d708b'","ecs.version":"1.6.0"}

From this we can make feedback loop a bit more efficient by implementing some batching of actions (not waiting for whole batch)
But from what i see agent wise everything is ok. ACK requests are taking a long time.

pack1-whole.txt
pack2-split.txt
pack3-split.txt
pack4.txt

cc @cmacknz

@dedemorton dedemorton mentioned this issue Jan 25, 2023
Merged
@cmacknz cmacknz mentioned this issue Jan 31, 2023
Merged
6 tasks
@michalpristas
Copy link
Contributor

looking at it again, from agent point of view it looks ok.
agent schedules action and then batches ack responses together and sends them to fleet server.
here it's getting interesting. with fairly small queries e.g. select * from users or select * from processes everything is reported and saved pretty quickly.

i did some stats on top of few runs with 100 agents performing 80 queries each.

on mac

Mean find: 0s
Mean ack: 375ms

P95 find: 358ms
P95 ack: 747ms

P99 find: 565ms
P99 ack: 904ms

mean time to find an action is 0ms, it's almost immediate, 95% of finds were under 358ms and 99% of finds were under 565ms
Similarly acks were pretty quick, 99% of acks were under 904ms
50 out of 8000 acks took slightly less than 3s not more than 3,2s

for windows numbers are very similar

Mean find: 304ms
Mean ack: 618ms

P95 find: 330ms
P95 ack: 647ms

i had just one windows client (darwin is a horde one)
out of all acks not a single one took longer than 3s.

interesting thing happened with shellbags query. ack response is significantly larger in this case.

Mean find: 306ms
Mean ack: 622ms

Avg find: 307.25
Avg ack: 4932.9625

P95 find: 318ms
P95 ack: 646ms

looking at this, everything seems fine except this one ack
agent-id, action id, wasCached, ack duration, find action duration
f439336c-c19a-4d9a-a020-01007508735b,56a1c051-6c18-4ca3-b087-9b5175eb94ea,false,345354,302

find action was fast, just 300ms, but when it came to ack (meaning dl.CreateActionResult(ctx, ack.bulk, acr);)
it took almost 6 minutes.
by the time this finished agent gave up (hit the predefined response timeout) and retried whole batch again.

with shellbags there's always at least 1 slow writer.
maybe it's because bulker hit during this call, i did not go into more depth from here.

Ack is time between start of the handleAckEvents process for each event until dl.CreateActionResult is finished
Find is a fraction of this time spent in dl.FindAction

@pierrehilbert
Copy link
Contributor

@kpollich, @michalpristas's conclusion is that we can't optimize anything from our side. Do you think something can be done in Fleet side?

@kpollich
Copy link
Member

kpollich commented Mar 2, 2023

@juliaElastic - Does the delay in action results creation ring any bells for you? @michel-laterman you might also be able to provide some insight. I'm not sure what part of action results is slow here, but @michalpristas's findings above seem to suggest the slowdown is coming from action results specifically.

@pierrehilbert
Copy link
Contributor

Closing this one as we can't do anything from Agent side.

@cmacknz cmacknz reopened this Mar 2, 2023
@cmacknz
Copy link
Member

cmacknz commented Mar 2, 2023

Let's transfer this to the Fleet server repository instead of closing it so we keep the history.

@cmacknz cmacknz transferred this issue from elastic/elastic-agent Mar 2, 2023
@cmacknz cmacknz added Team:Fleet Label for the Fleet team and removed Team:Elastic-Agent Label for the Agent team labels Mar 2, 2023
@juliaElastic
Copy link
Contributor

@kpollich I remember we experienced the delay at Request diagnostics. #1703 (comment)
It was indeed a delay in creating action results in Fleet Server. I think @michel-laterman added a fix for this, not sure where we are with that. Last time I tested, I still saw the delay, so tweaked the implementation on the UI so Request diagnostics doesn't wait for action results, and relies on the uploaded file status instead.

@aleksmaus
Copy link
Member Author

Last time I tested, I still saw the delay, so tweaked the implementation on the UI so Request diagnostics doesn't wait for action results, and relies on the uploaded file status instead.

It looks like another customer might be experiencing the similar issue, to be confirmed tomorrow by our team.
In our (osquery) case the actions-result contains the overall count of records returned by the query or the error returned by the query. It is used to render the progress on UI while the actual results data is coming in trough the libbeat publisher and to stop the progress when the number of received documents matches the "count" or the query resulted in error.
So it would be nice to have this working as designed.

@cmacknz I remember vaguely that somebody on the Agent team was looking at it. What was the culprit of the delay? Any solution planned for 8.8.0? Do you need help?

@cmacknz
Copy link
Member

cmacknz commented Mar 23, 2023

Michal investigated the agent side and found that the problem is likely isolated to Fleet server in #2410.

I don't think there has been any follow up progress since we transferred it here.

Any solution planned for 8.8.0? Do you need help?

It doesn't look like this is currently planned for 8.8, so I think we do need help.

@aleksmaus
Copy link
Member Author

Hmm, something odd is going with the agent actions acks flushing I think.

Testing the actions with osquery and here is what I’m seeing:

  1. sent 1 action/query, got ack right away
  2. sent a pack 32 actions/queries, no acks
  3. until I send 1 more action, then all 32 acks got flushed to fleet server with one http request, (!) except that last one
  4. then I sent another 1 action, and I got 2 http requests: one for the ack that was missed and another ack request for the action I just posted

The fleet server had no issues accepting acks if they come in.
I'll keep digging

@aleksmaus
Copy link
Member Author

aleksmaus commented Mar 27, 2023 •
edited

So here is the 5 mins delay in the agent

elastic-agent/internal/pkg/remote/client.go

Line 29 in 018bc0b

retryOnBadConnTimeout = 5 * time.Minute

And correct me if I’m wrong here. I need to dig further, but this is the theory.

The agent has just one “client” per fleet server and this lock locks the request for the whole duration of the check-in long poll

elastic-agent/internal/pkg/remote/client.go

Line 164 in 018bc0b

defer c.clientLock.Unlock()

So no other clients can make the request, including the ack request. And then you have a race between checkin and acks.

I think before the check-in loop got separated from the actions dispatch loop it was not a problem because it was sequential. there were always acks after check-in, then the next check-in etc.

Now you have the race for grabbing that lock and the long poll checkin will grab that lock for long time, preventing any other clients from issuing request to the fleet server.

That’s why you receive “pending” acks after sending another action to the agent, because this causes the checkin request to return and allows the ack request to grab that lock.

Does this make sense?

@aleksmaus aleksmaus mentioned this issue Mar 27, 2023
Merged
6 tasks
@cmacknz cmacknz transferred this issue from elastic/fleet-server Mar 28, 2023
@arvindersingh-qasource
Copy link

Hi @kevinlog , @aleksmaus

We have validated this ticket with Kibana v8.7.1_Snapshot build, where we have deployed 12 8.7.1 Agents with Osquery Manager. On running a Pack with 51 Queries in it , Results of all the queries were returned in time and we don't have any queries that are hanging or timing out.

Please find the below observations

Build Details

VERSION: 8.7.1
BUILD: 61162
COMMIT: 9c2031b89f9c0cea77e58638d8a43593b3e84cf7

Observations

  • Running 51 Queries Pack on 12 Agents at once and getting success response from each agent on each query.
Packs.-.Osquery.-.Elastic.-.Google.Chrome.2023-04-11.13-06-14.mp4

Please let us know if anything else is required from our end.

Thanks.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working Team:Fleet Label for the Fleet team v8.6.0
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fix actions acks delay aleksmaus/elastic-agent
7 participants
@pierrehilbert @aleksmaus @michalpristas @cmacknz @kpollich @juliaElastic @arvindersingh-qasource