Skip to content

Raise logging level for 'invalid_index_name_exception' ES exceptions to ERROR #771

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

Closed
wants to merge 2 commits into from

Conversation

webmat
Copy link
Contributor

@webmat webmat commented May 17, 2018

As discussed in #759, an invalid index exception should log at the ERROR level.
Presumably, most of these will happen just after an update to a user's Logstash
configuration.

Still missing in this PR

  • Add tests
  • Version bump

Questions

  • Does dlq_writer.write already support (event, reason, params_hash)?
  • When we get an ES exception, are response['index'] and response['index']['error']
    guaranteed to be set, or should I guard against anything in there being nil?
    • Got nil exceptions in the integration tests. Now guarding.

I would posit that making the list of exceptions that are elevated to ERROR is
out of scope for this. We could release this as is, and if there's interest we
make it configurable later on.

Generate an invalid_index_name_exception with

bin/logstash -e "input { generator { count => 1 } }
  output { elasticsearch { user => 'elastic' password => 'elastic'
    index => 'bad,index'
  }}"

Generate another ES exception (mapping) with

bin/logstash -e "input { generator { count => 2 } }
  filter { ruby { code => \" event.set('mapping_fail', (event.get('sequence') == 0 ? {'foo' => 'bar'} : 'foobar' ) ) \"} }
  output { elasticsearch { user => 'elastic' password => 'elastic' }}"

closes #759

@webmat webmat self-assigned this May 17, 2018
@webmat
Copy link
Contributor Author

webmat commented May 17, 2018

This new if is deep in the submit method. This will not be easy to get to for testing purposes. Perhaps I should extract the error logging to a small helper method?

@webmat
Copy link
Contributor Author

webmat commented May 17, 2018

Test failures on 3a848c8 with older versions of ES answered my question about guarding for response['index']['error']. Got nil exceptions there. I'll guard against this and move this code to a small method that'll be easier to test.

@webmat
Copy link
Contributor Author

webmat commented May 17, 2018

I could not repro the nil exceptions as they happened in Travis. Tried with ES 1.7, 2.4, 5.6 and 6.2.4 LOL (all those that failed).

This small method is pretty easy to test and doesn't require much setup.

@jsvd Quick question. There's a TODO in there about sending "status", "action" and "response" as a params hash to dlq_writer.write instead of baking it into the message string. But looking at DeadLetterQueueWriter or DLQEntry, it's not obvious to me whether it supports params args. It looks like it doesn't. Am I missing something?

@webmat webmat changed the title [WIP] Raise 'invalid_index_name_exception' ES exceptions to ERROR Raise 'invalid_index_name_exception' ES exceptions to ERROR May 17, 2018
@webmat webmat requested a review from jsvd May 17, 2018 19:19
@jsvd
Copy link
Member

jsvd commented May 18, 2018

@jsvd Quick question. There's a TODO in there about sending "status", "action" and "response" as a params hash to dlq_writer.write instead of baking it into the message string. But looking at DeadLetterQueueWriter or DLQEntry, it's not obvious to me whether it supports params args. It looks like it doesn't. Am I missing something?

I don't think you are, we can see in the java code for the DLQ writer that we expect two objects as arguments, but quickly those get coerced into a LogStash::Event and a string

# To support bwc, we check if DLQ exists. otherwise we log and drop event (previous behavior)
if @dlq_writer
# TODO: Change this to send a map with { :status => status, :action => action } in the future
@dlq_writer.write(action[2], "#{message} status: #{status}, action: #{action}, response: #{response}")
Copy link
Member

Choose a reason for hiding this comment

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

I'm not a huge fan of this "report_doc_level_error" to be writing data to the DLQ. Maybe we can have this method only take care of the else case in this if, where the DLQ isn't available.
Another alternative is to call this method something like handle_doc_level_error. the word "handle" works for everything, yay

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Yes, handle_ is a better name

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Actually this method is specifically for statuses that are candidates for the DLQ. I'll go even further and rename it to handle_dlq_status. It logs if DLQ is not enabled, and it sends to DLQ if it's enabled.

@webmat
Copy link
Contributor Author

webmat commented May 18, 2018

Ah, I had missed the PluginDeadLetterQueueWriter class sitting in the middle. Now it makes sense 😂

@webmat
Copy link
Contributor Author

webmat commented May 18, 2018

We should be good to go for PR, as of commit 5c074c1. Version bump is done, invalid_index_name_exception logs an error instead of a warning, and I've started adding significant tests around handling of events getting statuses that are candidates for the DLQ (whether or not it's enabled/available).

I've noticed a few things while working on this, and I've created follow-up issue #772 to handle them.

@webmat webmat changed the title Raise 'invalid_index_name_exception' ES exceptions to ERROR Raise logging level for 'invalid_index_name_exception' ES exceptions to ERROR May 18, 2018
# TODO: Change this to send a map with { :status => status, :action => action } in the future
@dlq_writer.write(action[2], "#{message} status: #{status}, action: #{action}, response: #{response}")
else
error_type = response['index'] && response['index']['error'] && response['index']['error']['type']
Copy link
Member

Choose a reason for hiding this comment

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

We can do response.fetch('index', {}).fetch('error', {}).get('type') instead.

@webmat webmat self-assigned this May 22, 2018
@webmat
Copy link
Contributor Author

webmat commented May 22, 2018

Ok @jsvd All tests are passing now. I'd like to merge tomorrow if there's nothing else.

Thanks for the terser syntax for digging into nested hashes :-)

Copy link
Member

@jsvd jsvd left a comment

Choose a reason for hiding this comment

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

LGTM (please squash the commits)

@webmat webmat force-pushed the error-on-bad-index branch from 3c1f97b to 2be7d9b Compare May 23, 2018 12:40
@webmat webmat force-pushed the error-on-bad-index branch from 2be7d9b to 9e73149 Compare May 23, 2018 13:21
@elasticsearch-bot
Copy link

Mathieu Martin merged this into the following branches!

Branch Commits
master b48c0bf, 9e10ad7

elasticsearch-bot pushed a commit that referenced this pull request May 23, 2018
@webmat webmat deleted the error-on-bad-index branch May 23, 2018 17:06
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.

WARN message in logstash.log
3 participants