SQL Trace Scripts

When Slacker executes an example, every call to query and sql produces a SQL sub-script which is executed against the target database.

Before Slacker runs this sub-script, however, it logs it in a SQL trace script file created separately for each example. This SQL trace script file accumulates SQL sub-scripts until the example completes or fails. Once the example is complete, depending on the outcome of the example, Slacker stores the SQL script in debug/passed_examples or debug/failed_examples.

SQL trace scripts are a powerful tool for troubleshooting failing examples.

Consider the following example:

describe 'My Database' do
  it 'contains a user table when one is created' do
    # Use inline query to create the table
    query('create table MyTable(id int, name varchar(100));')

    # Now lookup the table by type and name using a more elaborate dynamic SQL template.
    # See template sql/sample_1/sysobject_with_params_2.sql.erb
    query_result = sql.sample_1.sysobjects_with_params_2(:xtype => 'U', :name => 'MyTable')
    expect(query_result.count).to be == 2
  end
end

The above example invokes the following template sysobject_with_params_2.sql.erb:

<%# Query sysobjects by a dynamic criteria depending on the presence of parameters %>
select * from sysobjects
  where 1 = 1
<%= options[:xtype].nil? ? '' : " and xtype = '#{options[:xtype]}'" %>
<%= options[:name].nil? ? '' : " and name = '#{options[:name]}'" %>;

The example creates a table, then queries SQL Server's schema for that object by name, but then incorrectly expects to see two objects with that name. Excerpt from the example above:

  ...
  expect(query_result.count).to be == 2
  ...

This will make the example fail.
Executing slacker produces the following:

1) My database contains a user table when one is created
   Failure/Error: expect(query_result.count).to be == 2
     expected: 2
          got: 1 (using ==)
   # ./spec/sample_1.rb:46:in `block (2 levels) in <top (required)>'

Assuming that this is the first failed example, the failure produces the following SQL trace script file - debug/failed_examples/example_001.sql:

-- Example "My database contains a user table when one is created"
-- C:/test/project/spec/sample_1.rb:39
-- Executed at 2011-07-01 10:13:51 -0400

-- Initiate the example script
begin transaction;

-- Set default options
set textsize 2147483647;
set language us_english;
set dateformat mdy;
set datefirst 7;
set lock_timeout -1;
set quoted_identifier on;
set arithabort on;
set ansi_null_dflt_on on;
set ansi_warnings on;
set ansi_padding on;
set ansi_nulls on;
set concat_null_yields_null on;


-- query 'create table MyTable(id int, name varchar(100));'
create table MyTable(id int, name varchar(100));

-- query '/sample_1/sysobjects_with_params_2.sql.erb', options = {:xtype=>"U", :name=>"MyTable"}
select * from sysobjects
where 1 = 1
 and xtype = 'U' and name = 'MyTable';

-- Rollback the changes made by the example script
rollback transaction;

--               SLACKER RESULTS
-- *******************************************
-- Failure/Error: expect(query_result.count).to be == 2
-- expected: 2
--      got: 1 (using ==)
-- # ./spec/sample_1.rb:46:in `block (2 levels) in <top (required)>'
-- *******************************************

As you can see the script is wrapped in a transaction which is rolled back at the end, so you can safely load it and execute it in SQL Server Management Studio.

Since this is the exact script that Slacker executed against the database, running it in Management Studio will produce the same results as the ones Slacker got from the database so you can see exactly what went wrong.

It is important to note that in case of a failure, the SQL trace script contains the SQL sub-scripts up to the point of failure. This means that the results of the last statement in the script (prior to rollback transaction) is directly related to the failure.

In our example, the failure is caused by the fact that the last select statement in the SQL trace script returns only one record, while we expected to see two.

Next, see Variable Interpolation.