Bug report to pull request in under 1 hour

A user came in to our IRC channel today complaining about an issue with searching:

[16:31] <user> Why is it that when I search parent_hostgroup = “somerandom” in
the “Hosts” searchbox, where “somerandom” doesn’t match anything, it gives me a 
list of all hosts instead of none? I have some issues with this behavior when 
performing searches using the API
[16:40] <tbrisker> user: sounds like a bug, can you open an issue on 
projects.theforeman.org?
[16:49] <user> tbrisker, https://projects.theforeman.org/issues/22556

Luckily, this one was a quick fix. But let’s dive in together and understand why it failed in the first place.

We use a gem called Scoped Search to handle searches in our application. It allows us to provide our users with the ability to search the various resources in the application using a powerful query language and auto-completer. While for most cases scoped search Just Works™, sometimes more complex logic is needed for certain queries. This is possible by telling scoped search to use an external method to generate the query by passing an :ext_method parameter to the search definition.

The case of parent_hostgroup is one such case. A host in Foreman can belong to a host group, which in turn might be a child of one or more host groups. To allow searching by parent host group, i.e. any hosts that belong to a certain host group or any of its children, an external method is needed:

def search_by_hostgroup_and_descendants(key, operator, value)
  conditions = sanitize_sql_for_conditions(["hostgroups.title #{operator} ?", value_to_sql(operator, value)])
  # Only one hostgroup (first) is used to determined descendants. Future TODO - alert if result results more than one hostgroup
  hostgroup     = Hostgroup.unscoped.with_taxonomy_scope.where(conditions).first
  hostgroup_ids = hostgroup.subtree_ids
  if hostgroup_ids.any?
    opts = "hosts.hostgroup_id IN (#{hostgroup_ids.join(',')})"
  else
    opts = "hosts.id < 0"
  end
  {:conditions => opts}
end

Can you spot the bug?

It’s on line 5. If no host groups match the search on line 4, hostgroup will be nil. That means that hostgroup.subtree_ids should raise an exception:

NoMethodError: undefined method `subtree_ids' for nil:NilClass

That will be easy to fix, we just need to make sure that the hostgroup is present before collecting its sub-tree ids:

def search_by_hostgroup_and_descendants(key, operator, value)
  conditions = sanitize_sql_for_conditions(["hostgroups.title #{operator} ?", value_to_sql(operator, value)])
  # Only one hostgroup (first) is used to determined descendants. Future TODO - alert if result results more than one hostgroup
  hostgroup     = Hostgroup.unscoped.with_taxonomy_scope.where(conditions).first
  if hostgroup.present?
    hostgroup_ids = hostgroup.subtree_ids
    opts = "hosts.hostgroup_id IN (#{hostgroup_ids.join(',')})"
  else
    opts = "1 < 0"
  end
  {:conditions => opts}
end

And sure enough, less then an hour after the initial report, I had a pull request ready, which also included a unit test to ensure this function won’t break again in the future:

[17:23] <tbrisker> user: https://github.com/theforeman/foreman/pull/5249
[17:24] <user> tbrisker, thanks! :)

34 minutes of work and one happy user!

Since I try to follow the Boy Scout Rule, I also fixed a minor issue on line 9: the idea here is to return a condition that is always evaluated to false, thereby returning no results for the search. However, when the DB sees a condition like host.id < 0, it checks if any of the IDs are in fact smaller then 0. When you have tens of thousands of objects, this condition combined with other conditions (like default scope, default order, STI type etc.), even when executed against the index, can still take some time:

foreman=# explain analyze SELECT “hosts”.* FROM “hosts” WHERE “hosts”.”type” IN (‘Host::Managed’) AND ((hosts.id < 0)) ORDER BY “hosts”.”name” ASC;
 QUERY PLAN 
— — — — — — — — — — — — — — — — — — — — — — — — — — — — — — — — — 
 Sort (cost=62.19..62.20 rows=4 width=6134) (actual time=17.702..17.702 rows=0 loops=1)
 Sort Key: name
 Sort Method: quicksort Memory: 25kB
 -> Bitmap Heap Scan on hosts (cost=16.50..62.15 rows=4 width=6134) (actual time=17.692..17.692 rows=0 loops=1)
 Recheck Cond: ((type)::text = ‘Host::Managed’::text)
 Filter: (id < 0)
 Rows Removed by Filter: 43835
 Heap Blocks: exact=1429
 -> Bitmap Index Scan on index_hosts_on_type (cost=0.00..16.50 rows=12 width=0) (actual time=9.268..9.268 rows=43835 loops=1)
 Index Cond: ((type)::text = ‘Host::Managed’::text)
 Planning time: 0.359 ms
 Execution time: 17.808 ms
(12 rows)

Ok, that’s not too bad 😄

But on the other hand, when the RDBMS sees a condition like 1 < 0 it immediately evaluates it to false and returns much faster (by about 3 orders of magnitude):

foreman=# explain analyze SELECT "hosts".* FROM "hosts" WHERE "hosts"."type" IN ('Host::Managed') AND ((1 < 0)) ORDER BY "hosts"."name" ASC;
 QUERY PLAN 
------------------------------------------------------------------
 Sort (cost=0.01..0.02 rows=0 width=6134) (actual time=0.011..0.011 rows=0 loops=1)
 Sort Key: name
 Sort Method: quicksort Memory: 25kB
 -> Result (cost=0.00..0.00 rows=0 width=6134) (actual time=0.001..0.001 rows=0 loops=1)
 One-Time Filter: false
 Planning time: 0.241 ms
 Execution time: 0.077 ms
(7 rows)

Not a huge gain, but doesn’t hurt either. Perhaps learning this trick may come in handy for other cases, where it may lead to a more significant gain.

But wait, the user wasn’t actually complaining about an error. They complained that when the parent host group doesn’t exist, all hosts are returned instead of none of them. Why didn’t they get the NoMethodError? That’s peculiar!

Good thing the Scoped Search gem is Open Source, I can take a look inside and try to figure out what happened.

Here is the code that handles the external method definitions inside Scoped Search:

def to_ext_method_sql(key, operator, value, &block)
  raise ScopedSearch::QueryNotSupported, "'#{definition.klass}' doesn't respond to '#{ext_method}'" unless definition.klass.respond_to?(ext_method)
  conditions = definition.klass.send(ext_method.to_sym,key, operator, value) rescue {}
  raise ScopedSearch::QueryNotSupported, "external method '#{ext_method}' should return hash" unless conditions.kind_of?(Hash)
  sql = ''
  conditions.map do |notification, content|
    case notification
      when :include then yield(:include, content)
      when :joins then yield(:joins, content)
      when :conditions then sql = content
      when :parameter then content.map{|c| yield(:parameter, c)}
    end
  end
  return sql
end

Line 3 is the line that actually calls the external method when needed.

But what is that rescue {} doing there? That means that any error that occurs in the external method is swallowed silently, and the search will execute as if there was no condition at all! This is effectively suppressing any errors inside the external method, which is considered bad practice in Ruby and in programming in general. There are two reasons this is considered bad practice:

1. A user hitting an error (for example, by sending an invalid search query) will receive no indication that something went wrong. They may incorrectly assume the results they received were correct, which could lead them to take further actions that are mistaken. In our example, say a user wants to create a script that deletes all hosts in a certain host group and its children. If they mistype the host group name, instead of receiving an error or no results, they may end up deleting all of their hosts!
2. The developer creating the method who’s exceptions are being suppressed may think it is functioning correctly, and receive no indication that there is any issue in it. In this case, looking at the git history, this bug has existed for 3.5 years without being noticed!

So, thanks to the power of Open Source, I fixed the issue in Scoped Search and sent the maintainers a Pull Request as well:

def to_ext_method_sql(key, operator, value, &block)
  raise ScopedSearch::QueryNotSupported, "'#{definition.klass}' doesn't respond to '#{ext_method}'" unless definition.klass.respond_to?(ext_method)
  begin
    conditions = definition.klass.send(ext_method.to_sym, key, operator, value)
  rescue StandardError => e
    raise ScopedSearch::QueryNotSupported, "external method '#{ext_method}' failed with error: #{e}"
  end
  raise ScopedSearch::QueryNotSupported, "external method '#{ext_method}' should return hash" unless conditions.kind_of?(Hash)
  sql = ''
  conditions.map do |notification, content|
    case notification
      when :include then yield(:include, content)
      when :joins then yield(:joins, content)
      when :conditions then sql = content
      when :parameter then content.map{|c| yield(:parameter, c)}
    end
  end
  return sql
end

Now let’s just hope they like it enough to merge it into the project! 😃

Thank you for reading, I would be happy to hear feedback in the comments below or on twitter.