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

[Logging] more tests and added robustness to log formatting #15035

Merged
merged 8 commits into from Nov 27, 2017

Conversation

Projects
None yet
3 participants
@tsullivan
Contributor

tsullivan commented Nov 17, 2017

The log formatter had a potential to cause a TypeError in a scenario where the event object to log looks something like:

{
  type: 'error',
  error: {}
}

This PR handles that scenario by using the stringifed event object in place of an error message.

@tsullivan

This comment has been minimized.

Contributor

tsullivan commented Nov 17, 2017

please test this

@jbudz

This comment has been minimized.

Contributor

jbudz commented Nov 20, 2017

 └- ✖ fail: "dashboard app dashboard queries "after all" hook"
00:09:35      │        tryForTime timeout: [POST http://localhost:9515/session/1821ff396d00fbc20f228f7cd953f927/element / {"using":"css selector","value":"[data-test-subj=\"globalLoadingIndicator\"].ng-hide"}] no such element: Unable to locate element: {"method":"css selector","selector":"[data-test-subj="globalLoadingIndicator"].ng-hide"}
00:09:35      │         (Session info: chrome=62.0.3202.75)

jenkins, test it

@jbudz jbudz added v6.0.1 and removed v6.0.0 labels Nov 20, 2017

data.error = serializeError(event.data);
const message = _.get(event, 'data.message');
data.message = (message && message !== '') ? message : JSON.stringify(event);

This comment has been minimized.

@jbudz

jbudz Nov 20, 2017

Contributor

I'm iffy on stringifying the entire event in case it contains sensitive information - we'd have to audit usage of this to really make sure it's okay.

Thoughts on using a default empty string instead?

This comment has been minimized.

@tsullivan

tsullivan Nov 20, 2017

Contributor

Good catch. Empty string would be better. Or what about a static string like The error to be logged contained no message!

This comment has been minimized.

@jbudz

jbudz Nov 20, 2017

Contributor

👍 the static string, it'll be easier for processing. My only concern with the longer message is if it gets messaged frequently. - seems to be relatively common in logs, thoughts on that?

This comment has been minimized.

@jbudz

jbudz Nov 20, 2017

Contributor

spoke with @tsullivan offline, this case shouldn't happen so we want the error to be more verbose than -

@jbudz

This comment has been minimized.

Contributor

jbudz commented Nov 20, 2017

image

@tsullivan

This comment has been minimized.

Contributor

tsullivan commented Nov 20, 2017

I rebased to address the functional test failures. I saw my branch was behind by a few commits and needed some test fixes. So it should be good now.

@tsullivan

This comment has been minimized.

Contributor

tsullivan commented Nov 20, 2017

@jbudz I've addressed your feedback, and the PR is green as well. Can you take another look?

data.error = serializeError(event.error);
data.url = event.url;
const message = _.get(event, 'error.message');
data.message = (message && message !== '') ? message : `Event Error stack: ${_.get(event, 'error.stack')}`;

This comment has been minimized.

@jbudz

jbudz Nov 20, 2017

Contributor

nit, we don't need the && message !== '' portion

> message = ''
''
> !!message
false

This comment has been minimized.

@jbudz

jbudz Nov 20, 2017

Contributor

we could use the _.get default arg as an alternative

This comment has been minimized.

@tsullivan

tsullivan Nov 20, 2017

Contributor

if _.get() results in an empty string, it won't pick the default arg though

@jbudz

jbudz approved these changes Nov 20, 2017

@spalger

spalger approved these changes Nov 20, 2017 edited

minor nit, but LGTM

data.error = serializeError(event.data);
const message = get(event, 'data.message');
data.message = message || `Event Data Error stack: ${get(event, 'data.stack')}`;

This comment has been minimized.

@spalger

spalger Nov 20, 2017

Member

nit: I think the Event Data Error stack: prefix here is unnecessary. Also, what would possibly cause there to be a stack when there is no message? It's generally done the other way around because stack traces are not produced in all situations, so error.stack || error.message would produce something everywhere even if stack traces are not supported.

This comment has been minimized.

@tsullivan

tsullivan Nov 20, 2017

Contributor

Event Data Error stack: prefix here is unnecessary

I added that as a safety in case the stack is also undefined, that way we don't just log undefined, but have a label that we can use to work backwards and try to figure out what happened.

It's generally done the other way around because stack traces are not produced in all situations, so error.stack || error.message would produce something everywhere even if stack traces are not supported.

If there is both a stack and a message, we wouldn't want to have just the stack right? I think this is something we need to figure out. What about concatenating the 2 fields instead of or-ing them?

This comment has been minimized.

@spalger

spalger Nov 21, 2017

Member

Well, stack starts with the message, so concatenating them is just messy. My point is more that if message isn't defined I don't think there's any reason to think that stack will be, so perhaps it would be better if we did something like:

data.message = message || 'Unknown error (no message)'

@tsullivan tsullivan added the review label Nov 23, 2017

@tsullivan tsullivan merged commit 0e7c426 into elastic:master Nov 27, 2017

2 checks passed

CLA Commit author is a member of Elasticsearch
Details
kibana-ci Build finished.
Details

@tsullivan tsullivan deleted the tsullivan:fix/log-format-more-robust branch Nov 27, 2017

tsullivan added a commit to tsullivan/kibana that referenced this pull request Nov 27, 2017

[Logging] more tests and added robustness to log formatting (elastic#…
…15035)

* [Logging] more tests and added robustness to log formatting

* empty string for default error message, along with TODO question comment

* try to use stack trace from error when there is no error message

* simplify using the stack as the default error message

* destructure get from lodash

* default no-message to static string instead of error stack

* fix tests

tsullivan added a commit to tsullivan/kibana that referenced this pull request Nov 27, 2017

[Logging] more tests and added robustness to log formatting (elastic#…
…15035)

* [Logging] more tests and added robustness to log formatting

* empty string for default error message, along with TODO question comment

* try to use stack trace from error when there is no error message

* simplify using the stack as the default error message

* destructure get from lodash

* default no-message to static string instead of error stack

* fix tests

tsullivan added a commit to tsullivan/kibana that referenced this pull request Nov 27, 2017

[Logging] more tests and added robustness to log formatting (elastic#…
…15035)

* [Logging] more tests and added robustness to log formatting

* empty string for default error message, along with TODO question comment

* try to use stack trace from error when there is no error message

* simplify using the stack as the default error message

* destructure get from lodash

* default no-message to static string instead of error stack

* fix tests
@tsullivan

This comment has been minimized.

Contributor

tsullivan commented Nov 27, 2017

6.x/6.2.0: #15161
6.1/6.1.0: #15162
6.0/6.0.1: #15163

tsullivan added a commit that referenced this pull request Nov 27, 2017

[6.0] [Logging] more tests and added robustness to log formatting (#1…
…5035) (#15163)

* [Logging] more tests and added robustness to log formatting (#15035)

* [Logging] more tests and added robustness to log formatting

* empty string for default error message, along with TODO question comment

* try to use stack trace from error when there is no error message

* simplify using the stack as the default error message

* destructure get from lodash

* default no-message to static string instead of error stack

* fix tests

* remove ineligible useUTC tests

tsullivan added a commit that referenced this pull request Nov 27, 2017

[Logging] more tests and added robustness to log formatting (#15035) (#…
…15162)

* [Logging] more tests and added robustness to log formatting

* empty string for default error message, along with TODO question comment

* try to use stack trace from error when there is no error message

* simplify using the stack as the default error message

* destructure get from lodash

* default no-message to static string instead of error stack

* fix tests

tsullivan added a commit that referenced this pull request Nov 27, 2017

[Logging] more tests and added robustness to log formatting (#15035) (#…
…15161)

* [Logging] more tests and added robustness to log formatting

* empty string for default error message, along with TODO question comment

* try to use stack trace from error when there is no error message

* simplify using the stack as the default error message

* destructure get from lodash

* default no-message to static string instead of error stack

* fix tests

tsullivan added a commit to tsullivan/kibana that referenced this pull request Nov 30, 2017

[6.0] [Logging] more tests and added robustness to log formatting (el…
…astic#15035) (elastic#15163)

* [Logging] more tests and added robustness to log formatting (elastic#15035)

* [Logging] more tests and added robustness to log formatting

* empty string for default error message, along with TODO question comment

* try to use stack trace from error when there is no error message

* simplify using the stack as the default error message

* destructure get from lodash

* default no-message to static string instead of error stack

* fix tests

* remove ineligible useUTC tests
@tsullivan

This comment has been minimized.

Contributor

tsullivan commented Nov 30, 2017

Whoops, this was supposed to be backported to 5.6 also

5.6/5.6.5: #15310

tsullivan added a commit that referenced this pull request Nov 30, 2017

[6.0] [Logging] more tests and added robustness to log formatting (#1…
…5035) (#15163) (#15310)

* [Logging] more tests and added robustness to log formatting (#15035)

* [Logging] more tests and added robustness to log formatting

* empty string for default error message, along with TODO question comment

* try to use stack trace from error when there is no error message

* simplify using the stack as the default error message

* destructure get from lodash

* default no-message to static string instead of error stack

* fix tests

* remove ineligible useUTC tests

chrisronline added a commit to chrisronline/kibana that referenced this pull request Dec 1, 2017

[Logging] more tests and added robustness to log formatting (elastic#…
…15035)

* [Logging] more tests and added robustness to log formatting

* empty string for default error message, along with TODO question comment

* try to use stack trace from error when there is no error message

* simplify using the stack as the default error message

* destructure get from lodash

* default no-message to static string instead of error stack

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