Skip to content

Conversation

bleskes
Copy link
Contributor

@bleskes bleskes commented Feb 12, 2016

To make API's output more easy to read we are suppressing stack traces (#12991) unless explicitly requested by setting error_trace=true on the request. To compensate we are logging the stacktrace into the logs so people can look it up even the error_trace wasn't enabled. Currently we do so using the INFO level which can be verbose if an api is called repeatedly by some automation. For example, if someone tries to read from an index that doesn't exist we will respond with a 404 exception and log under info every time. We should reduce the level to DEBUG as we do with other API driven errors (internal issues that are not related to the API should be logged by other components already, based on their severity)

Closes #15329
Closes #16622

@nik9000
Copy link
Member

nik9000 commented Feb 12, 2016

I wonder if it makes more sense to have a severity on ESExceptions and use that. The 404 exception can be debug or trace or whatever and unexpected ones can stay info or warn even. I dunno. I'm not picky though.

@nik9000
Copy link
Member

nik9000 commented Feb 12, 2016

Actually, we already have a status to return. How about we log all 4xx statuses as debug and all 5xx statuses as info?

@s1monw
Copy link
Contributor

s1monw commented Feb 12, 2016

Actually, we already have a status to return. How about we log all 4xx statuses as debug and all 5xx statuses as info?

+1

@bleskes
Copy link
Contributor Author

bleskes commented Feb 13, 2016

Actually, we already have a status to return. How about we log all 4xx statuses as debug and all 5xx statuses as info?

I was thinking along the same line but didn't want to open the discussion (and I also see some downsides). It seems that using rest status occurred to more people. I'll do that.

@nik9000
Copy link
Member

nik9000 commented Feb 13, 2016

I also see some downsides

Please post them when you can. I can't think of any but I certainly don't know all there is to know.

@bleskes
Copy link
Contributor Author

bleskes commented Feb 13, 2016

@nik9000 @s1monw I pushed an update

@nik9000
Copy link
Member

nik9000 commented Feb 13, 2016

Fine by me.

if (status.getStatus() < 500) {
SUPPRESSED_ERROR_LOGGER.debug("{} Params: {}", t, channel.request().path(), channel.request().params());
} else {
SUPPRESSED_ERROR_LOGGER.info("{} Params: {}", t, channel.request().path(), channel.request().params());
Copy link
Member

Choose a reason for hiding this comment

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

Since we know this was a 5xx, should this be warn or 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.

I can go with error. Will update the PR unless people object soon :)

Copy link
Member

Choose a reason for hiding this comment

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

I'd prefer warning 😄 Mentally I reserve error for issues like "oh no I'm going to lose data" or "oh boy I have to crash now" rather than "sorry, I'm busted and can't do what you wanted". That feels like solid warning territory for me.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

You wish is my command. Warn it is :)

@bleskes
Copy link
Contributor Author

bleskes commented Feb 15, 2016

I updated the PR log with ERROR for 5xx codes.

I also see some downsides

Please post them when you can. I can't think of any but I certainly don't know all there is to know.

There are high traffic APIs that can respond with 503 - hitting a node that can't join it's master. Indexing to a shard whose primary is having problems etc. This will spam the logs. I wanted to have an easy win so I think logging an error on 5xx (instead of the current info) and debug on other errors gives an improvement to what we doing now (info all the time).

@nik9000
Copy link
Member

nik9000 commented Feb 15, 2016

This will spam the logs. I wanted to have an easy win so I think logging an error on 5xx (instead of the current info) and debug on other errors gives an improvement to what we doing now (info all the time).

That makes sense. I think we should fix that but I don't know how really. On the other hand this change is obviously an improvement and we should get it. LGTM.

@s1monw
Copy link
Contributor

s1monw commented Mar 13, 2016

@bleskes wanna merge this? LGTM

To make API's output more easy to read we are suppressing stack traces (elastic#12991) unless explicitly requested by setting `error_trace=true` on the request. To compensate we are logging the stacktrace into the logs so people can look it up even the error_trace wasn't enabled. Currently we do so using the `INFO` level which can be verbose if an api is called repeatedly by some automation.  For example, if someone tries to read from an index that doesn't exist we will respond with a 404 exception and log under info every time. We should reduce the level to `DEBUG` as we do with other API driven errors. Internal errors (rest codes >=500) are logged as WARN.

Closes elastic#16627
@bleskes bleskes force-pushed the rest_suppress_debug branch from 79c1206 to e472d78 Compare March 13, 2016 20:52
@bleskes bleskes merged commit e472d78 into elastic:master Mar 13, 2016
@bleskes bleskes deleted the rest_suppress_debug branch March 13, 2016 20:56
bleskes added a commit that referenced this pull request Mar 13, 2016
To make API's output more easy to read we are suppressing stack traces (#12991) unless explicitly requested by setting `error_trace=true` on the request. To compensate we are logging the stacktrace into the logs so people can look it up even the error_trace wasn't enabled. Currently we do so using the `INFO` level which can be verbose if an api is called repeatedly by some automation.  For example, if someone tries to read from an index that doesn't exist we will respond with a 404 exception and log under info every time. We should reduce the level to `DEBUG` as we do with other API driven errors. Internal errors (rest codes >=500) are logged as WARN.

Closes #16627
bleskes added a commit that referenced this pull request Mar 13, 2016
To make API's output more easy to read we are suppressing stack traces (#12991) unless explicitly requested by setting `error_trace=true` on the request. To compensate we are logging the stacktrace into the logs so people can look it up even the error_trace wasn't enabled. Currently we do so using the `INFO` level which can be verbose if an api is called repeatedly by some automation.  For example, if someone tries to read from an index that doesn't exist we will respond with a 404 exception and log under info every time. We should reduce the level to `DEBUG` as we do with other API driven errors. Internal errors (rest codes >=500) are logged as WARN.

Closes #16627
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants