Fix osquery result logging when queries are configured outside of Fleet (#15393)

#15168

- [X] Changes file added for user-visible changes in `changes/` or
`orbit/changes/`.
See [Changes
files](https://fleetdm.com/docs/contributing/committing-changes#changes-files)
for more information.
- [X] Added/updated tests.
- [X] Manual QA for all new/changed functionality.

The issue can be reproduced by running `osqueryd` with
`--config_plugin=filesystem --config_path=/path/to/config.json`
This means the osquery config is fetched from a file rather than from
Fleet's agent settings.
The `/path/to/config.json` has the agent settings, e.g.:
```
{
  "decorators": {
    "load": [
      "SELECT uuid AS host_uuid FROM system_info;",
      "SELECT hostname AS hostname FROM system_info;"
    ]
  },
  "options": {
    "disable_distributed": false,
    "distributed_interval": 10,
    "distributed_plugin": "tls",
    "distributed_tls_max_attempts": 3,
    "logger_tls_endpoint": "/api/osquery/log",
    "logger_tls_period": 10,
    "pack_delimiter": "/"
  },
  "schedule": {
    "USB devices": {
      "query": "SELECT * FROM usb_devices;",
      "interval": 15
    },
    "OS version": {
      "query": "SELECT * FROM os_version;",
      "interval": 10
    }
  },
  "packs": {
    "Elsewhere": {
      "queries": {
        "Osquery Info": {
          "query": "SELECT * FROM osquery_info;",
          "interval": 30,
          "platform": "",
          "version": "",
          "snapshot": true
        }
      }
    }
  }
}
```

The three queries should be logged to Fleet's configured result logging
destination (default is `filesystem`).
This commit is contained in:
Lucas Manuel Rodriguez 2023-12-04 11:18:49 -03:00 committed by GitHub
parent a7be0be9e9
commit ab0700b4e0
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
3 changed files with 88 additions and 46 deletions

View file

@ -0,0 +1 @@
* Fixed logging of results for scheduled queries configured outside of Fleet, when `server_settings.query_reports_disabled` is set to `true`.

View file

@ -1402,15 +1402,44 @@ func submitLogsEndpoint(ctx context.Context, request interface{}, svc fleet.Serv
return submitLogsResponse{Err: err}, nil
}
func (svc *Service) preProcessOsqueryResults(ctx context.Context, osqueryResults []json.RawMessage, queryReportsDisabled bool) (unmarshaledResults []*fleet.ScheduledQueryResult, queriesDBData map[string]*fleet.Query) {
// preProcessOsqueryResults will attempt to unmarshal `osqueryResults` and will return:
// - `unmarshaledResults` with each result unmarshaled to `fleet.ScheduledQueryResult`s, where if an item is `nil` it means the corresponding
// `osqueryResults` item could not be unmarshaled.
// - queriesDBData has the corresponding DB query to each unmarshalled result in `osqueryResults`.
//
// If queryReportsDisabled is true then it returns only t he `unmarshaledResults` without querying the DB.
func (svc *Service) preProcessOsqueryResults(
ctx context.Context,
osqueryResults []json.RawMessage,
queryReportsDisabled bool,
) (unmarshaledResults []*fleet.ScheduledQueryResult, queriesDBData map[string]*fleet.Query) {
// skipauth: Authorization is currently for user endpoints only.
svc.authz.SkipAuthorization(ctx)
lograw := func(raw json.RawMessage) string {
logr := raw
if len(raw) >= 64 {
logr = raw[:64]
}
return string(logr)
}
for _, raw := range osqueryResults {
var result *fleet.ScheduledQueryResult
if err := json.Unmarshal(raw, &result); err != nil {
level.Error(svc.logger).Log("msg", "unmarshalling result", "err", err)
// Note we store a nil item if the result could not be unmarshaled.
level.Debug(svc.logger).Log("msg", "unmarshalling result", "err", err, "result", lograw(raw))
// Note that if err != nil we have two scenarios:
// - result == nil: which means the result could not be unmarshalled, e.g. not JSON.
// - result != nil: which means that the result was (partially) unmarshalled but some specific
// field could not be unmarshalled.
//
// In both scenarios we want to add `result` to `unmarshaledResults`.
} else {
// If the unmarshaled result doesn't have a "name" field then we ignore the result.
if result != nil && result.QueryName == "" {
level.Debug(svc.logger).Log("msg", "missing name field", "result", lograw(raw))
result = nil
}
}
unmarshaledResults = append(unmarshaledResults, result)
}
@ -1427,7 +1456,7 @@ func (svc *Service) preProcessOsqueryResults(ctx context.Context, osqueryResults
}
teamID, queryName, err := getQueryNameAndTeamIDFromResult(queryResult.QueryName)
if err != nil {
level.Error(svc.logger).Log("msg", "querying name and team ID from result", "err", err)
level.Debug(svc.logger).Log("msg", "querying name and team ID from result", "err", err)
continue
}
if _, ok := queriesDBData[queryResult.QueryName]; ok {
@ -1463,6 +1492,9 @@ func (svc *Service) SubmitResultLogs(ctx context.Context, logs []json.RawMessage
// otherwise the results will never clear from its local DB and
// will keep retrying forever.
//
// We do return errors if we fail to write to the external logging destination,
// so that the logs are not lost and osquery retries on its next log interval.
//
var queryReportsDisabled bool
appConfig, err := svc.ds.AppConfig(ctx)
@ -1486,32 +1518,35 @@ func (svc *Service) SubmitResultLogs(ctx context.Context, logs []json.RawMessage
// Ignore results that could not be unmarshaled.
continue
}
if queryReportsDisabled {
// If query_reports_disabled=true we write the logs
// to the logging destination without any extra processing.
// If query_reports_disabled=true we write the logs to the logging destination without any extra processing.
//
// If a query has automations_enabled = 0 we may still write the results for it here.
// Eventually the query will be removed from the host schedule and thus Fleet
// won't receive any further results anymore (/api/v1/osquery/config).
// If a query was recently configured with automations_enabled = 0 we may still write
// the results for it here. Eventually the query will be removed from the host schedule
// and thus Fleet won't receive any further results anymore.
filteredLogs = append(filteredLogs, logs[i])
continue
}
//
// If query_reports_disabled=false then we need to filter
// the queries that have automations_enabled=false because
// the query might have been scheduled because of discard_data=false.
//
dbQuery, ok := queriesDBData[unmarshaledResult.QueryName]
if !ok {
// Ignore results for unknown queries.
// If Fleet doesn't know of the query we write the logs to the logging destination
// without any extra processing. This is to support osquery nodes that load their
// config from elsewhere (e.g. using `--config_plugin=filesystem`).
//
// If a query was configured from Fleet but was recently removed, we may still write
// the results for it here. Eventually the query will be removed from the host schedule
// and thus Fleet won't receive any further results anymore.
filteredLogs = append(filteredLogs, logs[i])
continue
}
if !dbQuery.AutomationsEnabled {
// Ignore results for queries that have automations disabled.
continue
}
filteredLogs = append(filteredLogs, logs[i])
}
@ -1646,7 +1681,7 @@ func getQueryNameAndTeamIDFromResult(path string) (*uint, string, error) {
if strings.HasPrefix(path, "pack/team-") {
parts := strings.SplitN(path, "/", 3)
if len(parts) != 3 {
return nil, "", fmt.Errorf("unknown format: %s", path)
return nil, "", fmt.Errorf("unknown format: %q", path)
}
teamNumberStr := strings.TrimPrefix(parts[1], "team-")
@ -1663,11 +1698,11 @@ func getQueryNameAndTeamIDFromResult(path string) (*uint, string, error) {
if strings.HasPrefix(path, "pack/") {
parts := strings.SplitN(path, "/", 3)
if len(parts) != 3 {
return nil, "", fmt.Errorf("unknown format: %s", path)
return nil, "", fmt.Errorf("unknown format: %q", path)
}
return nil, parts[2], nil
}
// If none of the above patterns match, return error
return nil, "", fmt.Errorf("unknown format: %s", path)
return nil, "", fmt.Errorf("unknown format: %q", path)
}

View file

@ -7,6 +7,7 @@ import (
"errors"
"fmt"
"io"
"os"
"reflect"
"sort"
"strconv"
@ -533,7 +534,7 @@ func TestSubmitStatusLogs(t *testing.T) {
func TestSubmitResultLogs(t *testing.T) {
ds := new(mock.Store)
svc, ctx := newTestService(t, ds, nil, nil)
svc, ctx := newTestService(t, ds, nil, nil, &TestServerOpts{Logger: log.NewJSONLogger(os.Stdout)})
ds.AppConfigFunc = func(ctx context.Context) (*fleet.AppConfig, error) {
return &fleet.AppConfig{}, nil
@ -614,60 +615,65 @@ func TestSubmitResultLogs(t *testing.T) {
serv.osqueryLogWriter = &OsqueryLogger{Result: testLogger}
validLogResults := []string{
`{"name":"pack/Global/system_info","hostIdentifier":"some_uuid","calendarTime":"Fri Sep 30 17:55:15 2016 UTC","unixTime":"1475258115","decorations":{"host_uuid":"some_uuid","username":"zwass"},"columns":{"cpu_brand":"Intel(R) Core(TM) i7-4770HQ CPU @ 2.20GHz","hostname":"hostimus","physical_memory":"17179869184"},"action":"added"}`,
`{"name":"pack/Global/system_info","hostIdentifier":"some_uuid","calendarTime":"Fri Sep 30 17:55:15 2016 UTC","unixTime":1475258115,"decorations":{"host_uuid":"some_uuid","username":"zwass"},"columns":{"cpu_brand":"Intel(R) Core(TM) i7-4770HQ CPU @ 2.20GHz","hostname":"hostimus","physical_memory":"17179869184"},"action":"added"}`,
`{"name":"pack/SomePack/encrypted","hostIdentifier":"some_uuid","calendarTime":"Fri Sep 30 21:19:15 2016 UTC","unixTime":"1475270355","decorations":{"host_uuid":"4740D59F-699E-5B29-960B-979AAF9BBEEB","username":"zwass"},"columns":{"encrypted":"1","name":"\/dev\/disk1","type":"AES-XTS","uid":"","user_uuid":"","uuid":"some_uuid"},"action":"added"}`,
`{"name":"pack/SomePack/encrypted","hostIdentifier":"some_uuid","calendarTime":"Fri Sep 30 21:19:14 2016 UTC","unixTime":"1475270354","decorations":{"host_uuid":"4740D59F-699E-5B29-960B-979AAF9BBEEB","username":"zwass"},"columns":{"encrypted":"1","name":"\/dev\/disk1","type":"AES-XTS","uid":"","user_uuid":"","uuid":"some_uuid"},"action":"added"}`,
`{"name":"pack/SomePack/encrypted","hostIdentifier":"some_uuid","calendarTime":"Fri Sep 30 21:19:15 2016 UTC","unixTime":1475270355,"decorations":{"host_uuid":"4740D59F-699E-5B29-960B-979AAF9BBEEB","username":"zwass"},"columns":{"encrypted":"1","name":"\/dev\/disk1","type":"AES-XTS","uid":"","user_uuid":"","uuid":"some_uuid"},"action":"added"}`,
`{"name":"pack/SomePack/encrypted","hostIdentifier":"some_uuid","calendarTime":"Fri Sep 30 21:19:14 2016 UTC","unixTime":1475270354,"decorations":{"host_uuid":"4740D59F-699E-5B29-960B-979AAF9BBEEB","username":"zwass"},"columns":{"encrypted":"1","name":"\/dev\/disk1","type":"AES-XTS","uid":"","user_uuid":"","uuid":"some_uuid"},"action":"added"}`,
// These results belong to the same query but have 1 second difference.
`{"snapshot":[{"hour":"20","minutes":"8"}],"action":"snapshot","name":"pack/Global/time","hostIdentifier":"1379f59d98f4","calendarTime":"Tue Jan 10 20:08:51 2017 UTC","unixTime":1484078931,"decorations":{"host_uuid":"EB714C9D-C1F8-A436-B6DA-3F853C5502EA"}}`,
`{"snapshot":[{"hour":"20","minutes":"8"}],"action":"snapshot","name":"pack/Global/time","hostIdentifier":"1379f59d98f4","calendarTime":"Tue Jan 10 20:08:50 2017 UTC","unixTime":1484078930,"decorations":{"host_uuid":"EB714C9D-C1F8-A436-B6DA-3F853C5502EA"}}`,
`{"snapshot":[{"hour":"20","minutes":"8"}],"action":"snapshot","name":"pack/Global/time","hostIdentifier":"1379f59d98f4","calendarTime":"Tue Jan 10 20:08:52 2017 UTC","unixTime":1484078932,"decorations":{"host_uuid":"EB714C9D-C1F8-A436-B6DA-3F853C5502EA"}}`,
`{"diffResults":{"removed":[{"address":"127.0.0.1","hostnames":"kl.groob.io"}],"added":""},"name":"pack\/team-1/hosts","hostIdentifier":"FA01680E-98CA-5557-8F59-7716ECFEE964","calendarTime":"Sun Nov 19 00:02:08 2017 UTC","unixTime":"1511049728","epoch":"0","counter":"10","decorations":{"host_uuid":"FA01680E-98CA-5557-8F59-7716ECFEE964","hostname":"kl.groob.io"}}`,
`{"diffResults":{"removed":[{"address":"127.0.0.1","hostnames":"kl.groob.io"}],"added":""},"name":"pack\/team-1/hosts","hostIdentifier":"FA01680E-98CA-5557-8F59-7716ECFEE964","calendarTime":"Sun Nov 19 00:02:08 2017 UTC","unixTime":1511049728,"epoch":"0","counter":"10","decorations":{"host_uuid":"FA01680E-98CA-5557-8F59-7716ECFEE964","hostname":"kl.groob.io"}}`,
`{"snapshot":[{"hour":"20","minutes":"8"}],"action":"snapshot","name":"pack/Global/query_should_be_saved_and_submitted","hostIdentifier":"1379f59d98f4","calendarTime":"Tue Jan 10 20:08:51 2017 UTC","unixTime":1484078931,"decorations":{"host_uuid":"EB714C9D-C1F8-A436-B6DA-3F853C5502EA"}}`,
//`{"snapshot":[],"action":"snapshot","name":"pack/Global/query_no_rows","hostIdentifier":"1379f59d98f4","calendarTime":"Tue Jan 10 20:08:51 2017 UTC","unixTime":1484078931,"decorations":{"host_uuid":"EB714C9D-C1F8-A436-B6DA-3F853C5502EA"}}`,
// Fleet doesn't know of this query, so this result should be streamed as is (This is to support streaming results for osquery nodes that are configured outside of Fleet, e.g. `--config_plugin=filesystem`).
`{"snapshot":[{"hour":"20","minutes":"8"}],"action":"snapshot","name":"pack/Global/doesntexist","hostIdentifier":"1379f59d98f4","calendarTime":"Tue Jan 10 20:08:51 2017 UTC","unixTime":1484078931,"decorations":{"host_uuid":"EB714C9D-C1F8-A436-B6DA-3F853C5502EA"}}`,
// The "name" field has invalid format, so this result will be streamed as is (This is to support streaming results for osquery nodes that are configured outside of Fleet, e.g. `--config_plugin=filesystem`).
`{"snapshot":[{"hour":"20","minutes":"8"}],"action":"snapshot","name":"some_name","hostIdentifier":"1379f59d98f4","calendarTime":"Tue Jan 10 20:08:51 2017 UTC","unixTime":1484078931,"decorations":{"host_uuid":"EB714C9D-C1F8-A436-B6DA-3F853C5502EA"}}`,
`{"snapshot":[{"hour":"20","minutes":"8"}],"action":"snapshot","name":"pack/team-foo/bar","hostIdentifier":"1379f59d98f4","calendarTime":"Tue Jan 10 20:08:51 2017 UTC","unixTime":1484078931,"decorations":{"host_uuid":"EB714C9D-C1F8-A436-B6DA-3F853C5502EA"}}`,
`{"snapshot":[{"hour":"20","minutes":"8"}],"action":"snapshot","name":"pack/team-","hostIdentifier":"1379f59d98f4","calendarTime":"Tue Jan 10 20:08:51 2017 UTC","unixTime":1484078931,"decorations":{"host_uuid":"EB714C9D-C1F8-A436-B6DA-3F853C5502EA"}}`,
`{"snapshot":[{"hour":"20","minutes":"8"}],"action":"snapshot","name":"pack/PackName","hostIdentifier":"1379f59d98f4","calendarTime":"Tue Jan 10 20:08:51 2017 UTC","unixTime":1484078931,"decorations":{"host_uuid":"EB714C9D-C1F8-A436-B6DA-3F853C5502EA"}}`,
}
logJSON := fmt.Sprintf("[%s]", strings.Join(validLogResults, ","))
resultWithInvalidJSON := []byte("foobar:\n\t123")
resultWithInvalidJSONLong := []byte("foobar:\n\t1233333333333333333333333333333333333333333333333333333333")
// The "name" field will be empty, so this result will be ignored.
resultWithoutName := []byte(`{"unknown":{"foo": [] }}`)
// The "name" field has invalid format, so this result will be ignored.
resultWithInvalidNameFmt1 := []byte(`{"snapshot":[{"hour":"20","minutes":"8"}],"action":"snapshot","name":"pack/team-foo/bar","hostIdentifier":"1379f59d98f4","calendarTime":"Tue Jan 10 20:08:51 2017 UTC","unixTime":"1484078931","decorations":{"host_uuid":"EB714C9D-C1F8-A436-B6DA-3F853C5502EA"}}`)
resultWithInvalidNameFmt2 := []byte(`{"snapshot":[{"hour":"20","minutes":"8"}],"action":"snapshot","name":"pack/team-","hostIdentifier":"1379f59d98f4","calendarTime":"Tue Jan 10 20:08:51 2017 UTC","unixTime":"1484078931","decorations":{"host_uuid":"EB714C9D-C1F8-A436-B6DA-3F853C5502EA"}}`)
resultWithInvalidNameFmt3 := []byte(`{"snapshot":[{"hour":"20","minutes":"8"}],"action":"snapshot","name":"pack/PackName","hostIdentifier":"1379f59d98f4","calendarTime":"Tue Jan 10 20:08:51 2017 UTC","unixTime":"1484078931","decorations":{"host_uuid":"EB714C9D-C1F8-A436-B6DA-3F853C5502EA"}}`)
// The query doesn't exist, so this result will be ignored.
resultWithQueryDoesNotExist := []byte(`{"snapshot":[{"hour":"20","minutes":"8"}],"action":"snapshot","name":"pack/Global/doesntexist","hostIdentifier":"1379f59d98f4","calendarTime":"Tue Jan 10 20:08:51 2017 UTC","unixTime":"1484078931","decorations":{"host_uuid":"EB714C9D-C1F8-A436-B6DA-3F853C5502EA"}}`)
// The query was configured with automations disabled, so this result will be ignored.
resultWithQueryNotAutomated := []byte(`{"snapshot":[{"hour":"20","minutes":"8"}],"action":"snapshot","name":"pack/Global/query_not_automated","hostIdentifier":"1379f59d98f4","calendarTime":"Tue Jan 10 20:08:51 2017 UTC","unixTime":"1484078931","decorations":{"host_uuid":"EB714C9D-C1F8-A436-B6DA-3F853C5502EA"}}`)
resultWithQueryNotAutomated := []byte(`{"snapshot":[{"hour":"20","minutes":"8"}],"action":"snapshot","name":"pack/Global/query_not_automated","hostIdentifier":"1379f59d98f4","calendarTime":"Tue Jan 10 20:08:51 2017 UTC","unixTime":1484078931,"decorations":{"host_uuid":"EB714C9D-C1F8-A436-B6DA-3F853C5502EA"}}`)
// The query is supposed to be saved but with automations disabled (and has two columns).
resultWithQuerySavedNotAutomated := []byte(`{"snapshot":[{"hour":"20","minutes":"8"},{"hour":"21","minutes":"9"}],"action":"snapshot","name":"pack/Global/query_should_be_saved_but_not_submitted","hostIdentifier":"1379f59d98f4","calendarTime":"Tue Jan 10 20:08:51 2017 UTC","unixTime":1484078931,"decorations":{"host_uuid":"EB714C9D-C1F8-A436-B6DA-3F853C5502EA"}}`)
var results []json.RawMessage
err := json.Unmarshal([]byte(logJSON), &results)
var validResults []json.RawMessage
err := json.Unmarshal([]byte(logJSON), &validResults)
require.NoError(t, err)
host := fleet.Host{
ID: 999,
}
ctx = hostctx.NewContext(ctx, &host)
// Submit valid and invalid log results mixed.
err = serv.SubmitResultLogs(ctx, append(append(results[:3],
resultWithInvalidJSON,
resultWithoutName,
resultWithInvalidNameFmt1,
resultWithInvalidNameFmt2,
resultWithInvalidNameFmt3,
resultWithQueryDoesNotExist,
resultWithQueryNotAutomated,
resultWithQuerySavedNotAutomated,
), results[3:]...))
// Submit valid, invalid and to-be-ignored log results mixed.
validAndInvalidResults := make([]json.RawMessage, 0, len(validResults)+5)
for i, result := range validResults {
validAndInvalidResults = append(validAndInvalidResults, result)
if i == 2 {
validAndInvalidResults = append(validAndInvalidResults,
resultWithInvalidJSON, resultWithInvalidJSONLong,
resultWithoutName, resultWithQueryNotAutomated,
resultWithQuerySavedNotAutomated,
)
}
}
err = serv.SubmitResultLogs(ctx, validAndInvalidResults)
require.NoError(t, err)
assert.Equal(t, results, testLogger.logs)
assert.Equal(t, validResults, testLogger.logs)
}
func TestSaveResultLogsToQueryReports(t *testing.T) {