Testing Explain Logger Output

Any quick tips?

I've been getting the SQL Server adapter up to passing for 3.2 and I wanted to test our explain printer. It will be very much like mysql2's printer. But I think my brain is mush and my meta-fu weak at the moment and I need some help. I tried stubbing ActiveRecord::Base.logger.warn but to no avail. Any thoughts?

- Ken

Fantastic!

The high-level API is implemented in Active Record. You do not need to test via the logger, at the adapter level you only need to write #explain, which should return a string[*], and test that very return value. Just ensure the string itself is correct.

The caller code takes that string and does stuff with it, but that's handled above and it's tested in Active Record itself in an agnostic way.

For example, this is the implementation in the SQLite adapter:

    https://github.com/rails/rails/blob/master/activerecord/lib/active_record/connection_adapters/sqlite_adapter.rb#L219-236

and these are its tests:

    https://github.com/rails/rails/blob/master/activerecord/test/cases/adapters/sqlite3/explain_test.rb

Your adapter should do something like that.

Remember also to define a predicate #supports_explain? that returns true.

Hope that helps, please write again if more questions arise.

Xavier

[*] This string should ideally be a carbon copy of the one users are familiar with. I don't know if that makes sense for SQL Server, maybe they are used to some GUI output there?

Hey Xavier,

I'm well past most of the things you outlined. I do have to test the output because, as usual, the SQL Server adapter has to jump thru a few hoops to get things working and I want to black box test the final output of that behavior. Our parameterized SQL is a formatted string to a stored procedure called sp_executesql, details here. http://www.engineyard.com/blog/2011/sql-server-10xs-faster-with-rails-3-1/

Because SQL Server's show plan (explain) needs the unprepared statement, our implementation has to (1) method chain ActiveRecord::Explain#exec_explain to parse the unquoted first arg of the previous query now formatted with sp_executesql and (2) write a simple case inside our #exec_query that replaces the parameters with the binds when an EXPLAIN sql name is happening. All in all I am happy with our little hacks, but just wanted a nice way to test that we are generating an "explain" plan properly.

I have tests for simple stuff that does not have binds, but wanted to write a test for something like `with_threshold(0) { Car.find(1) }` which does leverage a bind parameter but only logs to ActiveRecord's logger. So basically, I was looking for a nice way to do that which would make sure I was testing at a high level all the low level hacks.

- Ken

Then, I guess you're familiar with the test coverage at all levels related to EXPLAIN in Active Record and that still does not help, right?

If that is correct, could you perhaps temporarily assign a new Logger wrapping a StringIO to AR::Base.logger and check the buffer?

Duh, :slight_smile: That works like a champ!

  • Thanks Xavier!

Ken