search

rethinkdb / logstash-input-rethinkdb

Other
55 stars 13 forks source link

Throwing stack traces with Rethinkdb 2.3 #13

Open baconcheeseburger opened 8 years ago

baconcheeseburger commented 8 years ago

Updating rethinkdb causes the following error to be thrown:

{:timestamp=>"2016-04-11T15:02:25.220000+0000", :message=>"SANITY CHECK FAILED: [ss.squash == datum_t::boolean(false)] at `src/rdb_protocol/changefeed.cc:3966` (server is buggy).  Backtrace:\nMon Apr 11 15:01:54 2016\n\n1 [0xab4a60]: backtrace_t::backtrace_t() at 0xab4a60 (/usr/bin/rethinkdb)\n2 [0xab4d2e]: lazy_backtrace_formatter_t::lazy_backtrace_formatter_t() at 0xab4d2e (/usr/bin/rethinkdb)\n3 [0x803c33]: ql::runtime_sanity_check_failed(char const*, int, char const*, std::string const&) at 0x803c33 (/usr/bin/rethinkdb)\n4 [0x8e1be1]: ql::changefeed::artificial_t::subscribe(ql::env_t*, ql::changefeed::streamspec_t const&, std::string const&, std::vector<ql::datum_t, std::allocator<ql::datum_t> > const&, ql::backtrace_id_t) at 0x8e1be1 (/usr/bin/rethinkdb)\n5 [0x981f48]: cfeed_artificial_table_backend_t::read_changes(ql::env_t*, ql::changefeed::streamspec_t const&, ql::backtrace_id_t, signal_t*, counted_t<ql::datum_stream_t>*, admin_err_t*) at 0x981f48 (/usr/bin/rethinkdb)\n6 [0x984945]: artificial_table_t::read_changes(ql::env_t*, ql::changefeed::streamspec_t const&, ql::backtrace_id_t) at 0x984945 (/usr/bin/rethinkdb)\n7 [0x8871da]: ql::changes_term_t::eval_impl(ql::scope_env_t*, ql::args_t*, ql::eval_flags_t) const at 0x8871da (/usr/bin/rethinkdb)\n8 [0x820430]: ql::op_term_t::term_eval(ql::scope_env_t*, ql::eval_flags_t) const at 0x820430 (/usr/bin/rethinkdb)\n9 [0x92e058]: ql::runtime_term_t::eval_on_current_stack(ql::scope_env_t*, ql::eval_flags_t) const at 0x92e058 (/usr/bin/rethinkdb)\n10 [0x92e46f]: ql::runtime_term_t::eval(ql::scope_env_t*, ql::eval_flags_t) const at 0x92e46f (/usr/bin/rethinkdb)\n11 [0x81e53a]: ql::op_term_t::maybe_grouped_data(ql::scope_env_t*, ql::argvec_t*, ql::eval_flags_t, counted_t<ql::grouped_data_t>*, scoped_ptr_t<ql::val_t>*) const at 0x81e53a (/usr/bin/rethinkdb)\n12 [0x81fe89]: ql::op_term_t::term_eval(ql::scope_env_t*, ql::eval_flags_t) const at 0x81fe89 (/usr/bin/rethinkdb)\n13 [0x92e058]: ql::runtime_term_t::eval_on_current_stack(ql::scope_env_t*, ql::eval_flags_t) const at 0x92e058 (/usr/bin/rethinkdb)\n14 [0x92e46f]: ql::runtime_term_t::eval(ql::scope_env_t*, ql::eval_flags_t) const at 0x92e46f (/usr/bin/rethinkdb)\n15 [0x81e53a]: ql::op_term_t::maybe_grouped_data(ql::scope_env_t*, ql::argvec_t*, ql::eval_flags_t, counted_t<ql::grouped_data_t>*, scoped_ptr_t<ql::val_t>*) const at 0x81e53a (/usr/bin/rethinkdb)\n16 [0x81fe89]: ql::op_term_t::term_eval(ql::scope_env_t*, ql::eval_flags_t) const at 0x81fe89 (/usr/bin/rethinkdb)\n17 [0x92e058]: ql::runtime_term_t::eval_on_current_stack(ql::scope_env_t*, ql::eval_flags_t) const at 0x92e058 (/usr/bin/rethinkdb)\n18 [0x92e46f]: ql::runtime_term_t::eval(ql::scope_env_t*, ql::eval_flags_t) const at 0x92e46f (/usr/bin/rethinkdb)\n19 [0x7505e6]: ql::query_cache_t::ref_t::run(ql::env_t*, ql::response_t*) at 0x7505e6 (/usr/bin/rethinkdb)\n20 [0x752253]: ql::query_cache_t::ref_t::fill_response(ql::response_t*) at 0x752253 (/usr/bin/rethinkdb)\n21 [0x81c6d3]: rdb_query_server_t::run_query(ql::query_params_t*, ql::response_t*, signal_t*) at 0x81c6d3 (/usr/bin/rethinkdb)\n22 [0xab0d77]: void save_exception<void query_server_t::connection_loop<json_protocol_t>(linux_tcp_conn_t*, unsigned long, ql::query_cache_t*, signal_t*)::{lambda()#1}::operator()() const::{lambda()#1}>(std::__exception_ptr::exception_ptr*, std::string*, cond_t*, void query_server_t::connection_loop<json_protocol_t>(linux_tcp_conn_t*, unsigned long, ql::query_cache_t*, signal_t*)::{lambda()#1}::operator()() const::{lambda()#1}&&) at 0xab0d77 (/usr/bin/rethinkdb)\n23 [0xab12f5]: void query_server_t::connection_loop<json_protocol_t>(linux_tcp_conn_t*, unsigned long, ql::query_cache_t*, signal_t*)::{lambda()#1}::operator()() const at 0xab12f5 (/usr/bin/rethinkdb)\n24 [0x9d4fa8]: coro_t::run() at 0x9d4fa8 (/usr/bin/rethinkdb)\n\nBacktrace:\nr.db(\"rethinkdb\").table(\n^^^^^^^^^^^^^^^^^^^^^^^^\n  \"table_status\"\n  ^^^^^^^^^^^^^^\n).changes({\"include_initial\" =>\n^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n     true,\n     ^^^^^\n   \"squash\" =>\n   ^^^^^^^^^^^\n     true,\n     ^^^^^\n   \"include_states\" =>\n   ^^^^^^^^^^^^^^^^^^^\n     true}\n     ^^^^^\n).filter {|var_1|\n^\n  var_1[\"db\"].eq(\"local\").and(var_1[\"status\"][\"all_replicas_ready\"])\n}.pluck({\"new_val\" => [\"db\", \"name\"], \"old_val\" => [\"db\", \"name\"]})", :level=>:error}
baconcheeseburger commented 8 years ago

I've verified that this plugin works fine on 2.2.

deontologician commented 8 years ago

ping @coffeemug it looks like a server crash

mlucy commented 8 years ago

@deontologician -- are you subscribing to an artificial changefeed with squash set to true anywhere?

mlucy commented 8 years ago

It looks like that's probably what's causing it (or at least I can make the server produce this error by doing that).

@deontologician -- the plugin should probably not be passing squash: true when subscribing to artificial changefeeds. (I mean, the server should be failing gracefully rather than returning this error, but I would guess the old behavior was to just silently ignore the problem, and we might well patch it to produce a good error instead of this bad error.)

@baconcheeseburger -- you should be able to work around this by configuring the plugin to use squash: false.

deontologician commented 8 years ago

So if someone wants to throttle changes from the system tables, is there a better option than squash?

mlucy commented 8 years ago

I don't think so. (Honestly this is a little bit of a weird convention, because my understanding is that unsquashed changes from system tables behave more like squashed changes from normal tables than unsquashed changes from normal tables. @VeXocide, do you know any more?)

mlucy commented 8 years ago

Actually, nevermind @deontologician, I think we should continue having the behavior where we ignore the squash flag for artificial changefeeds rather than erroring when it's set to true.

deontologician commented 8 years ago

I know the artificial changefeeds have some sample rate, can we just forward squash to modify that?

mlucy commented 8 years ago

Currently we have a global sampling that's shared across feeds. We could theoretically set the rate of that sampling to the smallest sample rate that's specified by any changefeed using squash; that might be worth opening an issue for.