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

[Security Solution][Case][Bug] Improve case logging #91924

Merged
merged 13 commits into from
Feb 26, 2021

Conversation

jonathan-buttner
Copy link
Contributor

@jonathan-buttner jonathan-buttner commented Feb 18, 2021

This PR improves the logging throughout the case plugin. This is to address feedback that about it being difficult to triage future issues relating to case because of the lack of logging of errors and failures.

I created a CaseError class to wrap the original error and store the original error object so that we can access the stacktrace if we need to in the future. The CaseError also allows converting itself to a Boom to be returned in the API handlers. If the original error was a Boom then it uses that error's statusCode otherwise it defaults to 500.

A lot of the changes look worse than they are because I added a try/catch and indented the code.

There were a couple jest tests that were expecting boom errors that I needed to update and a couple places where the tests would through a unhandled promise rejects which I fixed by adding return.

Reference: https://jestjs.io/docs/en/asynchronous#promises

If your code uses promises, there is a more straightforward way to handle asynchronous tests. Return a promise from your test, and Jest will wait for that promise to resolve. If the promise is rejected, the test will automatically fail.

This adds a lot of logging, some duplicative too. A call to log.error will happen each time we create CaseError. This may be unnecessary but more logging is better probably and we can always reduce it later.

Testing

The easiest way to test this PR is to run the integration tests and observe the console output for the kibana server. Here's some examples:

│ proc [kibana] server    log   [10:30:43.844] [error][case][plugins] Error on GET case fake-id: Error: Saved object [cases/fake-id] not found
   │ proc [kibana] server    log   [10:30:43.844] [error][case][plugins] Failed to get case id: fake-id: Error: Saved object [cases/fake-id] not found
   │ proc [kibana] server    log   [10:30:43.844] [error][case][plugins] Error getting case and/or connector and/or user actions: Failed to get case id: fake-id: Error: Saved object [cases/fake-id] not found
   │ proc [kibana] server    log   [10:30:43.844] [error][case][plugins] Failed to push case in route: CaseError: Error getting case and/or connector and/or user actions: Failed to get case id: fake-id: Error: Saved object [cases/fake-id] not found
   │ proc [kibana] server    log   [10:30:45.867] [error][case][plugins] Error getting case and/or connector and/or user actions: Saved object [action/fake-connector] not found
   │ proc [kibana] server    log   [10:30:45.867] [error][case][plugins] Failed to push case in route: CaseError: Error getting case and/or connector and/or user actions: Saved object [action/fake-connector] not found

@jonathan-buttner jonathan-buttner marked this pull request as ready for review February 19, 2021 15:53
@jonathan-buttner jonathan-buttner requested a review from a team as a code owner February 19, 2021 15:53
@elasticmachine
Copy link
Contributor

Pinging @elastic/security-threat-hunting (Team:Threat Hunting)

expect(e.isBoom).toBe(true);
expect(e.output.statusCode).toBe(400);
});
return (
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Adding return to tests so that the test will wait correctly.

See: https://jestjs.io/docs/en/asynchronous#promises

@@ -84,7 +78,7 @@ export const push = async ({
]);
} catch (e) {
const message = `Error getting case and/or connector and/or user actions: ${e.message}`;
throw createError(e, message);
throw createCaseError({ message, error: e, logger });
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Using a CaseError for these so that we can boomify it once we get to the route handler and keeping things consistent.

const boom = isBoom(error) ? error : boomify(error, options);
let boom: Boom;

if (isCaseError(error)) {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Handle unwrapping the CaseError and converting it to a boom.

@jonathan-buttner
Copy link
Contributor Author

@elasticmachine merge upstream

@jonathan-buttner
Copy link
Contributor Author

@elasticmachine merge upstream

return CasesResponseRt.encode(returnUpdatedCase);
return CasesResponseRt.encode(returnUpdatedCase);
} catch (error) {
const idVersions = cases.cases.map((caseInfo) => ({
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

cases.cases lol. Thoughts on updating this naming pattern in the future?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

haha 💯 I'll add it to the refactoring list.

id: caseInfo.id,
version: caseInfo.version,
}));
throw createCaseError({
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I initially thought the createCaseError identified errors for the createCase path, but it looks like a catch all for all case related errors. Think it's worth changing the name to just caseError or logCaseErrors or something?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah good idea. I'll switch it to caseError 👍

throw createCaseError({
message: `Failed to update alerts status using client ids: ${JSON.stringify(
args.ids
)} indices: ${JSON.stringify([...args.indices])} status: ${args.status} ${error}`,
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

More of a personal preference here. Could help readability depending on the size of any of these fields to include line breaks between the output string, so

`Failed to update alerts status using client ids: ${JSON.stringify(args.ids)} \n
 indices: ${JSON.stringify([...args.indices])} \n
 status: ${args.status} ${error}`

});
} catch (error) {
throw createCaseError({
message: `Failed to get alerts using client ids: ${JSON.stringify(
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

same thing here potentially re the line breaks

@@ -47,7 +47,6 @@ export const createCaseClientWithMockSavedObjectsClient = async ({
};
}> => {
const esClient = elasticsearchServiceMock.createElasticsearchClient();
// const actionsMock = createActionsClient();
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks

* Create a CaseError that wraps the original thrown error. This also logs the message that will be placed in the CaseError
* if the logger was defined.
*/
export function createCaseError({
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Okay, you can ignore my previous message. I thought of it as createCase Error and you mean it as create caseError 🤪

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

haha no worries

@@ -38,6 +38,9 @@ export function initGetCaseApi({ caseConfigureService, caseService, router }: Ro
}),
});
} catch (error) {
logger.error(
`Failed to retrieve case in route case id: ${request.params.case_id} include comments: ${request.query.includeComments} include sub comments: ${request.query.includeSubCaseComments}: ${error}`
Copy link
Contributor

@michaelolo24 michaelolo24 Feb 25, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

might be worth doing line breaks here too, if you decide it's worth it

}: UpdateAlertsStatusArgs) {
const sanitizedIndices = getValidIndices(indices);
if (sanitizedIndices.length <= 0) {
// log that we only had invalid indices
logger.warn(`Empty alert indices when updateAlertsStatus ids: ${JSON.stringify(ids)}`);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍🏾

Copy link
Contributor

@michaelolo24 michaelolo24 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Really nice job with this! Only had a few comments, but they were all really preference things

@kibanamachine
Copy link
Contributor

💚 Build Succeeded

Metrics [docs]

✅ unchanged

History

To update your PR or re-run it, just comment with:
@elasticmachine merge upstream

@jonathan-buttner jonathan-buttner merged commit 993ac50 into elastic:master Feb 26, 2021
@jonathan-buttner jonathan-buttner deleted the add-case-logging branch February 26, 2021 17:48
gmmorris added a commit to gmmorris/kibana that referenced this pull request Feb 26, 2021
…bana into task-manager/docs-monitoring

* 'task-manager/docs-monitoring' of github.com:gmmorris/kibana: (40 commits)
  [Security Solution][Case][Bug] Improve case logging (elastic#91924)
  [Alerts][Doc] Added README documentation for alerts plugin status and framework health checks configuration options. (elastic#92761)
  Add warning for EQL and Threshold rules if exception list contains value list items (elastic#92914)
  [Security Solution][Case] Fix subcases bugs on detections and case view (elastic#91836)
  [APM] Always allow access to Profiling via URL (elastic#92889)
  [Vega] Allow image loading without CORS policy by changing the default to crossOrigin=null (elastic#91991)
  skip flaky suite (elastic#92114)
  [APM] Fix for default fields in correlations view (elastic#91868) (elastic#92090)
  chore(NA): bump bazelisk to v1.7.5 (elastic#92905)
  [Maps] fix selecting EMS basemap does not populate input (elastic#92711)
  API docs (elastic#92827)
  [kbn/test] add import/export support to KbnClient (elastic#92526)
  Test fix management scripted field filter functional test and unskip it  (elastic#92756)
  [App Search] Create Curation view/functionality (elastic#92560)
  [Reporting/Discover] include the document's entire set of fields (elastic#92730)
  [Fleet] Add new index to fleet for artifacts being served out of fleet-server (elastic#92860)
  [Alerts][Doc] Added README documentation for API key invalidation configuration options. (elastic#92757)
  [Discover][docs] Add search for relevance (elastic#90611)
  [Alerts][Docs] Extended README.md and the user docs with the licensing information. (elastic#92564)
  [7.12][Telemetry] Security telemetry allowlist fix. (elastic#92850)
  ...
jonathan-buttner added a commit to jonathan-buttner/kibana that referenced this pull request Mar 1, 2021
* First pass at bringing in more logging

* Adding more logging to routes

* Adding more logging fixing tests

* Removing duplicate case string in logs

* Removing unneeded export

* Fixing type error

* Adding line breaks to make the messages more readable

* Fixing type errors

Co-authored-by: Kibana Machine <42973632+kibanamachine@users.noreply.github.com>
jonathan-buttner added a commit to jonathan-buttner/kibana that referenced this pull request Mar 1, 2021
* First pass at bringing in more logging

* Adding more logging to routes

* Adding more logging fixing tests

* Removing duplicate case string in logs

* Removing unneeded export

* Fixing type error

* Adding line breaks to make the messages more readable

* Fixing type errors

Co-authored-by: Kibana Machine <42973632+kibanamachine@users.noreply.github.com>
jonathan-buttner added a commit that referenced this pull request Mar 1, 2021
* First pass at bringing in more logging

* Adding more logging to routes

* Adding more logging fixing tests

* Removing duplicate case string in logs

* Removing unneeded export

* Fixing type error

* Adding line breaks to make the messages more readable

* Fixing type errors

Co-authored-by: Kibana Machine <42973632+kibanamachine@users.noreply.github.com>

Co-authored-by: Kibana Machine <42973632+kibanamachine@users.noreply.github.com>
jonathan-buttner added a commit that referenced this pull request Mar 1, 2021
* First pass at bringing in more logging

* Adding more logging to routes

* Adding more logging fixing tests

* Removing duplicate case string in logs

* Removing unneeded export

* Fixing type error

* Adding line breaks to make the messages more readable

* Fixing type errors

Co-authored-by: Kibana Machine <42973632+kibanamachine@users.noreply.github.com>

Co-authored-by: Kibana Machine <42973632+kibanamachine@users.noreply.github.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Feature:Cases Cases feature release_note:skip Skip the PR/issue when compiling release notes Team:Threat Hunting Security Solution Threat Hunting Team v7.12.0 v8.0.0
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants