test/dummy/log/test.log in bento_search-0.0.1 vs test/dummy/log/test.log in bento_search-0.5.0

- old
+ new

@@ -1,202 +1,167 @@ Connecting to database specified by database.yml -  (0.6ms) begin transaction +  (0.5ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -EDS timing AUTH: 0.070969s -EDS timing GET: 0.005073:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n -EDS timing GET: 0.006575:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 -EDS timing GET: 0.006726:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.009707s  (0.0ms) rollback transaction  (0.0ms) begin transaction -EDS timing AUTH: 0.007806s  (0.0ms) rollback transaction  (0.0ms) begin transaction -EDS timing AUTH: 0.012039s -EDS timing GET: 0.0048:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.003999:http://eds-api.ebscohost.com/edsapi/rest/info -EDS timing GET: 0.006441:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.047924s -EDS timing GET: 0.003037:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.002784:http://eds-api.ebscohost.com/edsapi/rest/info -EDS auth failed, getting auth again -EDS timing AUTH: 0.002967s -EDS timing GET: 0.006095:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D -  (0.1ms) rollback transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +BentoSearch::SearchEngine failed results: #<Exception: I am a horrible engine> + /home/rochkind/bento_search/test/unit/search_engine_base_test.rb:183:in `search_implementation' + /home/rochkind/bento_search/app/models/bento_search/search_engine.rb:89:in `search' + /home/rochkind/bento_search/test/unit/search_engine_base_test.rb:189:in `test_rescues_exceptions' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:949:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit/testcase.rb:17:in `run' + activesupport (3.2.8) lib/active_support/testing/setup_and_teardown.rb:36:in `block in run' + activesupport (3.2.8) lib/active_support/callbacks.rb:425:in `_run__2886462068739794106__setup__4058406264532479739__callbacks' + activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `__run_callback' + activesupport (3.2.8) lib/active_support/callbacks.rb:385:in `_run_setup_callbacks' + activesupport (3.2.8) lib/active_support/callbacks.rb:81:in `run_callbacks' + activesupport (3.2.8) lib/active_support/testing/setup_and_teardown.rb:35:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:787:in `block in _run_suite' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:780:in `map' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:780:in `_run_suite' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:565:in `block in _run_suites' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:563:in `each' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:563:in `_run_suites' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:746:in `_run_anything' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:909:in `run_tests' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:896:in `block in _run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:895:in `each' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:895:in `_run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:884:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:21:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:326:in `block (2 levels) in autorun' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:27:in `run_once' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:325:in `block in autorun' +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction Connecting to database specified by database.yml -  (0.6ms) begin transaction -EDS timing AUTH: 0.942925s -EDS timing GET: 2.945485:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n -EDS timing GET: 3.844817:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 -EDS timing GET: 0.055401:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d2df8c3b-da33-4d1e-a3ab-e2afc1e41da6.Q7ANUPMiBwCr%2FNJnBQZrMjs4UrxU7dpLQYwSjj0iNEE%3D -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.754436s -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.801104s -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.769531s -EDS timing GET: 0.642401:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.044779:http://eds-api.ebscohost.com/edsapi/rest/info -EDS timing GET: 0.048195:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=58b3b9c6-92d1-4fa0-ba7b-ae4c23e7e7a3.5tU1TZLDfOTSQgUcBezVdLzYXaL3VNxPjzDRYHfDHNs%3D -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.740568s -EDS timing GET: 0.762168:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.029053:http://eds-api.ebscohost.com/edsapi/rest/info -EDS auth failed, getting auth again -EDS timing AUTH: 0.034124s -EDS timing GET: 0.047491:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=0d63a4d8-e7fa-4471-91ef-78a8103e7ad0.oXqfM9hzTYfdOtBRBfTDa5Sn997deM5tz0HoFtbmRb0%3D -  (0.1ms) rollback transaction -Connecting to database specified by database.yml  (0.4ms) begin transaction -EDS timing AUTH: 0.816647s -EDS timing GET: 0.734006:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n -EDS timing GET: 4.183034:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 -EDS timing GET: 0.080037:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c856851e-8416-4806-b27c-6096205f4f52.myEqzXNyOK9WYYUlQQitYatMbPVDlOhLAG1qlMsHtmY%3D -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -EDS timing AUTH: 0.78661s -EDS timing GET: 0.683898:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n -EDS timing GET: 4.399789:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 -EDS timing GET: 0.053621:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=90049bcf-67f4-4aba-af04-f4c0fb95eaa5.P6odna3tDqyu7fIySaFqy7Or01Gdg0Q3BoERf9lEUVg%3D -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.778231s -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.793426s -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.757648s -EDS timing GET: 1.020794:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.0458:http://eds-api.ebscohost.com/edsapi/rest/info -EDS timing GET: 0.048433:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=78add2c0-afa4-4949-ba82-718571fcc06e.1F0MavT%2FSMH9yMsy6KdX3rHXUPgvIRHBDda2OLkY4AY%3D -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.753987s -EDS timing GET: 0.660385:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.029827:http://eds-api.ebscohost.com/edsapi/rest/info -EDS auth failed, getting auth again -EDS timing AUTH: 0.034799s -EDS timing GET: 0.049002:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=a0fe0db5-c65d-43ae-a965-29f51c8983fa.7wTBtxFhBedyDhGIzkK16tDYXfzZiOVrFdvsDcCfY1s%3D -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.5ms) begin transaction Processing by BentoSearch::SearchControllerTest::CustomSearchController#search as HTML Parameters: {"engine_id"=>"mock", "query"=>"my search"} Rendered text template (0.0ms) -Completed 403 Forbidden in 37ms (Views: 36.6ms | ActiveRecord: 0.0ms) +Completed 403 Forbidden in 43ms (Views: 42.2ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction -  (0.0ms) begin transaction +  (0.1ms) begin transaction Processing by BentoSearch::SearchController#search as HTML Parameters: {"query"=>"my search", "engine_id"=>"not_existing"} -Completed 404 Not Found in 1ms (Views: 0.7ms | ActiveRecord: 0.0ms) -  (0.0ms) rollback transaction +Completed 404 Not Found in 1ms (Views: 0.6ms | ActiveRecord: 0.0ms) +  (0.1ms) rollback transaction  (0.0ms) begin transaction Processing by BentoSearch::SearchController#search as HTML Parameters: {"query"=>"my search", "engine_id"=>"not_routable"} Completed 403 Forbidden in 1ms (Views: 0.2ms | ActiveRecord: 0.0ms)  (0.0ms) rollback transaction -  (0.0ms) begin transaction +  (0.1ms) begin transaction Processing by BentoSearch::SearchController#search as HTML Parameters: {"query"=>"my search", "engine_id"=>"mock"} - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (29.6ms) -Completed 200 OK in 37ms (Views: 36.6ms | ActiveRecord: 0.0ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.2ms) +Completed 200 OK in 41ms (Views: 40.6ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.0ms) +  (0.1ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.3ms) -  (0.0ms) rollback transaction -  (0.0ms) begin transaction Rendered /home/rochkind/bento_search/app/views/bento_search/_search_error.html.erb (0.7ms)  (0.0ms) rollback transaction +  (0.1ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.3ms) +  (0.1ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.6ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.3ms)  (0.0ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.6ms) +  (0.1ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction +  (0.0ms) begin transaction +  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction -EDS timing AUTH: 0.073708s -EDS timing GET: 0.005134:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n -EDS timing GET: 0.006819:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 -EDS timing GET: 0.006465:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D +  (0.1ms) begin transaction +EDS timing AUTH: 0.078106s +EDS timing GET: 0.005008:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n +EDS timing GET: 0.006394:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 +EDS timing GET: 0.006792:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.010242s  (0.0ms) rollback transaction  (0.0ms) begin transaction -EDS timing AUTH: 0.007863s +EDS timing AUTH: 0.009413s  (0.0ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.012104s -EDS timing GET: 0.005099:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.004049:http://eds-api.ebscohost.com/edsapi/rest/info -EDS timing GET: 0.006265:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D +  (0.0ms) begin transaction +EDS timing AUTH: 0.007506s +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +EDS timing AUTH: 0.011699s +EDS timing GET: 0.004569:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y +EDS timing GET: 0.003736:http://eds-api.ebscohost.com/edsapi/rest/info +EDS timing GET: 0.005847:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D  (0.1ms) rollback transaction  (0.0ms) begin transaction -EDS timing AUTH: 0.015177s -EDS timing GET: 0.002972:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.002839:http://eds-api.ebscohost.com/edsapi/rest/info +EDS timing AUTH: 0.014803s +EDS timing GET: 0.002677:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y +EDS timing GET: 0.00258:http://eds-api.ebscohost.com/edsapi/rest/info EDS auth failed, getting auth again -EDS timing AUTH: 0.002995s -EDS timing GET: 0.006212:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D +EDS timing AUTH: 0.002711s +EDS timing GET: 0.005764:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D  (0.1ms) rollback transaction  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction @@ -204,34 +169,72 @@  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction  (0.1ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction +  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction +BentoSearch::SearchEngine failed results: #<Exception: I am a horrible engine> + /home/rochkind/bento_search/test/unit/search_engine_base_test.rb:183:in `search_implementation' + /home/rochkind/bento_search/app/models/bento_search/search_engine.rb:89:in `search' + /home/rochkind/bento_search/test/unit/search_engine_base_test.rb:189:in `test_rescues_exceptions' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:949:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit/testcase.rb:17:in `run' + activesupport (3.2.8) lib/active_support/testing/setup_and_teardown.rb:36:in `block in run' + activesupport (3.2.8) lib/active_support/callbacks.rb:425:in `_run__4029929672233217244__setup__1248707290308868027__callbacks' + activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `__run_callback' + activesupport (3.2.8) lib/active_support/callbacks.rb:385:in `_run_setup_callbacks' + activesupport (3.2.8) lib/active_support/callbacks.rb:81:in `run_callbacks' + activesupport (3.2.8) lib/active_support/testing/setup_and_teardown.rb:35:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:787:in `block in _run_suite' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:780:in `map' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:780:in `_run_suite' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:565:in `block in _run_suites' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:563:in `each' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:563:in `_run_suites' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:746:in `_run_anything' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:909:in `run_tests' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:896:in `block in _run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:895:in `each' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:895:in `_run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:884:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:21:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:326:in `block (2 levels) in autorun' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:27:in `run_once' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:325:in `block in autorun' +  (0.1ms) rollback transaction +  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction @@ -244,79 +247,87 @@  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction +  (0.1ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction +  (0.1ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction +  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction +  (0.1ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction +  (0.1ms) begin transaction  (0.0ms) rollback transaction +  (0.1ms) begin transaction +  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction +  (0.1ms) begin transaction +  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction +  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction -  (0.1ms) begin transaction +  (0.0ms) begin transaction  (0.1ms) rollback transaction +  (0.0ms) begin transaction +  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.3ms) +  (0.1ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.2ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.4ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.2ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_link.html.erb (0.5ms) - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (3.7ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_link.html.erb (0.4ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (3.6ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.2ms)  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction +  (0.0ms) begin transaction +  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction @@ -326,25 +337,40 @@  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction +Connecting to database specified by database.yml +  (0.6ms) begin transaction +  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction Connecting to database specified by database.yml  (0.6ms) begin transaction Processing by BentoSearch::SearchControllerTest::CustomSearchController#search as HTML Parameters: {"engine_id"=>"mock", "query"=>"my search"} Rendered text template (0.0ms) -Completed 403 Forbidden in 45ms (Views: 44.5ms | ActiveRecord: 0.0ms) +Completed 403 Forbidden in 50ms (Views: 49.6ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction Processing by BentoSearch::SearchController#search as HTML Parameters: {"query"=>"my search", "engine_id"=>"not_existing"} Completed 404 Not Found in 2ms (Views: 0.8ms | ActiveRecord: 0.0ms) @@ -355,93 +381,93 @@ Completed 403 Forbidden in 1ms (Views: 0.3ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction Processing by BentoSearch::SearchController#search as HTML Parameters: {"query"=>"my search", "engine_id"=>"mock"} - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (34.8ms) -Completed 200 OK in 45ms (Views: 44.0ms | ActiveRecord: 0.0ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.8ms) +Completed 200 OK in 49ms (Views: 48.3ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (3.3ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.8ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction Rendered /home/rochkind/bento_search/app/views/bento_search/_search_error.html.erb (0.9ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.4ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.8ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.3ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.8ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.4ms) rollback transaction -  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.06438s -EDS timing GET: 0.0071:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n -EDS timing GET: 0.009651:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 -EDS timing GET: 0.009427:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.013872s +EDS timing AUTH: 0.117406s +EDS timing GET: 0.007868:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n +EDS timing GET: 0.009791:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 +EDS timing GET: 0.010209:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.011271s  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.01771s -EDS timing GET: 0.006997:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.005779:http://eds-api.ebscohost.com/edsapi/rest/info -EDS timing GET: 0.008878:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D +EDS timing AUTH: 0.014126s +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +EDS timing AUTH: 0.008935s +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +EDS timing AUTH: 0.015443s +EDS timing GET: 0.005282:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y +EDS timing GET: 0.004674:http://eds-api.ebscohost.com/edsapi/rest/info +EDS timing GET: 0.007372:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.022158s -EDS timing GET: 0.043772:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.004092:http://eds-api.ebscohost.com/edsapi/rest/info +  (0.0ms) begin transaction +EDS timing AUTH: 0.016862s +EDS timing GET: 0.002832:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y +EDS timing GET: 0.002659:http://eds-api.ebscohost.com/edsapi/rest/info EDS auth failed, getting auth again -EDS timing AUTH: 0.004375s -EDS timing GET: 0.00912:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D +EDS timing AUTH: 0.002879s +EDS timing GET: 0.010923:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction  (0.0ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction @@ -451,21 +477,27 @@  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction +  (0.1ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction @@ -475,36 +507,62 @@  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction +BentoSearch::SearchEngine failed results: #<Exception: I am a horrible engine> + /home/rochkind/bento_search/test/unit/search_engine_base_test.rb:183:in `search_implementation' + /home/rochkind/bento_search/app/models/bento_search/search_engine.rb:89:in `search' + /home/rochkind/bento_search/test/unit/search_engine_base_test.rb:189:in `test_rescues_exceptions' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:949:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit/testcase.rb:17:in `run' + activesupport (3.2.8) lib/active_support/testing/setup_and_teardown.rb:36:in `block in run' + activesupport (3.2.8) lib/active_support/callbacks.rb:425:in `_run__2079895681877932289__setup__2619043652292814868__callbacks' + activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `__run_callback' + activesupport (3.2.8) lib/active_support/callbacks.rb:385:in `_run_setup_callbacks' + activesupport (3.2.8) lib/active_support/callbacks.rb:81:in `run_callbacks' + activesupport (3.2.8) lib/active_support/testing/setup_and_teardown.rb:35:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:787:in `block in _run_suite' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:780:in `map' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:780:in `_run_suite' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:565:in `block in _run_suites' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:563:in `each' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:563:in `_run_suites' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:746:in `_run_anything' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:909:in `run_tests' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:896:in `block in _run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:895:in `each' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:895:in `_run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:884:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:21:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:326:in `block (2 levels) in autorun' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:27:in `run_once' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:325:in `block in autorun'  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction +  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction +  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction @@ -515,416 +573,267 @@  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.3ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.4ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.2ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_link.html.erb (0.5ms) - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (3.7ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.2ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction +  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction +  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction +  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -  (0.2ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.6ms) begin transaction -  (0.2ms) rollback transaction -Connecting to database specified by database.yml -  (0.6ms) begin transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -  (0.2ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -  (0.2ms) rollback transaction -Connecting to database specified by database.yml -  (0.5ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.8ms)  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction  (0.1ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.5ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_link.html.erb (0.6ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (5.3ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.2ms) rollback transaction -  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.2ms) rollback transaction -  (0.1ms) begin transaction -  (0.2ms) rollback transaction -  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -  (0.1ms) rollback transaction  (0.1ms) begin transaction -Connecting to database specified by database.yml -  (0.6ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction Connecting to database specified by database.yml -  (0.4ms) begin transaction +  (0.6ms) begin transaction Processing by BentoSearch::SearchControllerTest::CustomSearchController#search as HTML Parameters: {"engine_id"=>"mock", "query"=>"my search"} Rendered text template (0.0ms) -Completed 403 Forbidden in 44ms (Views: 43.5ms | ActiveRecord: 0.0ms) +Completed 403 Forbidden in 58ms (Views: 57.2ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction Processing by BentoSearch::SearchController#search as HTML Parameters: {"query"=>"my search", "engine_id"=>"not_existing"} -Completed 404 Not Found in 1ms (Views: 0.6ms | ActiveRecord: 0.0ms) -  (0.0ms) rollback transaction -  (0.0ms) begin transaction +Completed 404 Not Found in 2ms (Views: 0.8ms | ActiveRecord: 0.0ms) +  (0.1ms) rollback transaction +  (0.1ms) begin transaction Processing by BentoSearch::SearchController#search as HTML Parameters: {"query"=>"my search", "engine_id"=>"not_routable"} -Completed 403 Forbidden in 1ms (Views: 0.2ms | ActiveRecord: 0.0ms) -  (0.0ms) rollback transaction -  (0.0ms) begin transaction +Completed 403 Forbidden in 1ms (Views: 0.3ms | ActiveRecord: 0.0ms) +  (0.1ms) rollback transaction +  (0.1ms) begin transaction Processing by BentoSearch::SearchController#search as HTML Parameters: {"query"=>"my search", "engine_id"=>"mock"} - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.5ms) -Completed 200 OK in 42ms (Views: 41.7ms | ActiveRecord: 0.0ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.9ms) +Completed 200 OK in 57ms (Views: 55.9ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.0ms) begin transaction +  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.4ms) -  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_search_error.html.erb (0.7ms) -  (0.0ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.7ms)  (0.1ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.7ms) -  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (3.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.0ms) rollback transaction -  (0.1ms) begin transaction -  (0.3ms) rollback transaction -  (0.1ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_search_error.html.erb (0.9ms)  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.043661s -EDS timing GET: 0.004922:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n -EDS timing GET: 0.006663:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 -EDS timing GET: 0.006671:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.8ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.009951s + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.8ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.008161s  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.012415s -EDS timing GET: 0.004849:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.004031:http://eds-api.ebscohost.com/edsapi/rest/info -EDS timing GET: 0.006333:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.054686s -EDS timing GET: 0.003129:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.002867:http://eds-api.ebscohost.com/edsapi/rest/info -EDS auth failed, getting auth again -EDS timing AUTH: 0.002965s -EDS timing GET: 0.006157:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction +EDS timing AUTH: 0.077074s +EDS timing GET: 0.004982:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n +EDS timing GET: 0.006347:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 +EDS timing GET: 0.006829:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.0ms) rollback transaction  (0.0ms) begin transaction +EDS timing AUTH: 0.009381s  (0.0ms) rollback transaction  (0.0ms) begin transaction +EDS timing AUTH: 0.007484s  (0.0ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction  (0.0ms) begin transaction +EDS timing AUTH: 0.011696s +EDS timing GET: 0.00455:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y +EDS timing GET: 0.003848:http://eds-api.ebscohost.com/edsapi/rest/info +EDS timing GET: 0.005859:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D  (0.0ms) rollback transaction  (0.0ms) begin transaction +EDS timing AUTH: 0.014784s +EDS timing GET: 0.002692:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y +EDS timing GET: 0.002586:http://eds-api.ebscohost.com/edsapi/rest/info +EDS auth failed, getting auth again +EDS timing AUTH: 0.002719s +EDS timing GET: 0.005805:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction +  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction  (0.1ms) begin transaction -Connecting to database specified by database.yml -  (0.6ms) begin transaction -Processing by BentoSearch::SearchControllerTest::CustomSearchController#search as HTML - Parameters: {"engine_id"=>"mock", "query"=>"my search"} - Rendered text template (0.0ms) -Completed 403 Forbidden in 61ms (Views: 60.1ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"not_existing"} -Completed 404 Not Found in 2ms (Views: 0.9ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"not_routable"} -Completed 403 Forbidden in 1ms (Views: 0.3ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"mock"} - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (3.4ms) -Completed 200 OK in 56ms (Views: 55.3ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (3.5ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_search_error.html.erb (1.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.3ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.3ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.4ms) rollback transaction -  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.071979s -EDS timing GET: 0.008061:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n -EDS timing GET: 0.010516:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 -EDS timing GET: 0.009709:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.014261s  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.011495s  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.022385s -EDS timing GET: 0.007735:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.006302:http://eds-api.ebscohost.com/edsapi/rest/info -EDS timing GET: 0.008894:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D +BentoSearch::SearchEngine failed results: #<Exception: I am a horrible engine> + /home/rochkind/bento_search/test/unit/search_engine_base_test.rb:183:in `search_implementation' + /home/rochkind/bento_search/app/models/bento_search/search_engine.rb:95:in `search' + /home/rochkind/bento_search/test/unit/search_engine_base_test.rb:189:in `test_rescues_exceptions' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:949:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit/testcase.rb:17:in `run' + activesupport (3.2.8) lib/active_support/testing/setup_and_teardown.rb:36:in `block in run' + activesupport (3.2.8) lib/active_support/callbacks.rb:425:in `_run__2269524022906288665__setup__2247867715169516960__callbacks' + activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `__run_callback' + activesupport (3.2.8) lib/active_support/callbacks.rb:385:in `_run_setup_callbacks' + activesupport (3.2.8) lib/active_support/callbacks.rb:81:in `run_callbacks' + activesupport (3.2.8) lib/active_support/testing/setup_and_teardown.rb:35:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:787:in `block in _run_suite' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:780:in `map' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:780:in `_run_suite' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:565:in `block in _run_suites' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:563:in `each' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:563:in `_run_suites' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:746:in `_run_anything' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:909:in `run_tests' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:896:in `block in _run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:895:in `each' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:895:in `_run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:884:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:21:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:326:in `block (2 levels) in autorun' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:27:in `run_once' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:325:in `block in autorun'  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.075015s -EDS timing GET: 0.004969:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.004604:http://eds-api.ebscohost.com/edsapi/rest/info -EDS auth failed, getting auth again -EDS timing AUTH: 0.004581s -EDS timing GET: 0.009077:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction @@ -995,63 +904,21 @@  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.9ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.5ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.6ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.4ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction Rendered /home/rochkind/bento_search/app/views/bento_search/_link.html.erb (0.7ms) - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (5.3ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (5.6ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction @@ -1078,224 +945,252 @@  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction Connecting to database specified by database.yml  (0.6ms) begin transaction Processing by BentoSearch::SearchControllerTest::CustomSearchController#search as HTML Parameters: {"engine_id"=>"mock", "query"=>"my search"} Rendered text template (0.0ms) -Completed 403 Forbidden in 56ms (Views: 55.2ms | ActiveRecord: 0.0ms) +Completed 403 Forbidden in 52ms (Views: 51.5ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction Processing by BentoSearch::SearchController#search as HTML Parameters: {"query"=>"my search", "engine_id"=>"not_existing"} -Completed 404 Not Found in 2ms (Views: 0.9ms | ActiveRecord: 0.0ms) +Completed 404 Not Found in 2ms (Views: 0.8ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction Processing by BentoSearch::SearchController#search as HTML Parameters: {"query"=>"my search", "engine_id"=>"not_routable"} Completed 403 Forbidden in 1ms (Views: 0.3ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction Processing by BentoSearch::SearchController#search as HTML Parameters: {"query"=>"my search", "engine_id"=>"mock"} - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (3.3ms) -Completed 200 OK in 14ms (Views: 13.0ms | ActiveRecord: 0.0ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.7ms) +Completed 200 OK in 14ms (Views: 12.6ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (3.3ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.7ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_search_error.html.erb (0.9ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_search_error.html.erb (1.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.3ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.8ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.3ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.8ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.2ms) rollback transaction -  (0.1ms) begin transaction -  (0.5ms) rollback transaction -  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.1ms) rollback transaction +  (0.2ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.109974s -EDS timing GET: 0.007293:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n -EDS timing GET: 0.009908:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 -EDS timing GET: 0.009392:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.057918s  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.011815s +EDS timing AUTH: 0.114534s +EDS timing GET: 0.00752:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n +EDS timing GET: 0.00934:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 +EDS timing GET: 0.010051:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.017784s -EDS timing GET: 0.007053:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.005884:http://eds-api.ebscohost.com/edsapi/rest/info -EDS timing GET: 0.009079:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.022592s -EDS timing GET: 0.004198:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.004137:http://eds-api.ebscohost.com/edsapi/rest/info -EDS auth failed, getting auth again -EDS timing AUTH: 0.00425s -EDS timing GET: 0.008915:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D +EDS timing AUTH: 0.013759s  (0.1ms) rollback transaction  (0.1ms) begin transaction +EDS timing AUTH: 0.011291s  (0.1ms) rollback transaction  (0.1ms) begin transaction +EDS timing AUTH: 0.018216s +EDS timing GET: 0.006731:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y +EDS timing GET: 0.005505:http://eds-api.ebscohost.com/edsapi/rest/info +EDS timing GET: 0.008787:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D  (0.1ms) rollback transaction  (0.1ms) begin transaction +EDS timing AUTH: 0.022271s +EDS timing GET: 0.003924:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y +EDS timing GET: 0.003742:http://eds-api.ebscohost.com/edsapi/rest/info +EDS auth failed, getting auth again +EDS timing AUTH: 0.004073s +EDS timing GET: 0.008721:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction  (0.1ms) rollback transaction -  (0.1ms) begin transaction +  (0.0ms) begin transaction  (0.1ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.1ms) rollback transaction +  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.1ms) rollback transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction  (0.1ms) begin transaction -  (0.1ms) rollback transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.1ms) begin transaction +  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.1ms) rollback transaction +  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.1ms) rollback transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.1ms) rollback transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction  (0.1ms) rollback transaction -  (0.1ms) begin transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.1ms) begin transaction +  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.1ms) begin transaction +  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.1ms) rollback transaction +  (0.0ms) rollback transaction +  (0.0ms) begin transaction +  (0.0ms) rollback transaction  (0.1ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.8ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.5ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_link.html.erb (0.6ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (5.3ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.0ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.6ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_link.html.erb (0.7ms) - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (5.5ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction @@ -1317,344 +1212,125 @@  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction Connecting to database specified by database.yml -  (0.4ms) begin transaction +  (0.5ms) begin transaction Processing by BentoSearch::SearchControllerTest::CustomSearchController#search as HTML Parameters: {"engine_id"=>"mock", "query"=>"my search"} - Rendered text template (0.1ms) -Completed 403 Forbidden in 48ms (Views: 47.3ms | ActiveRecord: 0.0ms) + Rendered text template (0.0ms) +Completed 403 Forbidden in 52ms (Views: 51.8ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction Processing by BentoSearch::SearchController#search as HTML Parameters: {"query"=>"my search", "engine_id"=>"not_existing"} -Completed 404 Not Found in 2ms (Views: 0.9ms | ActiveRecord: 0.0ms) +Completed 404 Not Found in 1ms (Views: 0.8ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction Processing by BentoSearch::SearchController#search as HTML Parameters: {"query"=>"my search", "engine_id"=>"not_routable"} Completed 403 Forbidden in 1ms (Views: 0.3ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction -  (0.1ms) begin transaction +  (0.0ms) begin transaction Processing by BentoSearch::SearchController#search as HTML Parameters: {"query"=>"my search", "engine_id"=>"mock"} - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (3.2ms) -Completed 200 OK in 13ms (Views: 12.7ms | ActiveRecord: 0.0ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.2ms) +Completed 200 OK in 11ms (Views: 10.3ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.1ms) begin transaction +  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (3.3ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.2ms)  (0.1ms) rollback transaction -  (0.1ms) begin transaction +  (0.0ms) begin transaction Rendered /home/rochkind/bento_search/app/views/bento_search/_search_error.html.erb (0.9ms)  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.3ms) +  (0.0ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.4ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.3ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.4ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.2ms) rollback transaction -  (0.1ms) begin transaction -  (0.4ms) rollback transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.886671s -EDS timing GET: 3.565897:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n -EDS timing GET: 8.262243:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 -EDS timing GET: 0.053914:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=ee4f8bdb-6a38-4637-b6dd-63c53f23cbea.xkR6p6hqA4xWmTAs16G5C2YxpKeW0Ub%2B8ReDzUfURY8%3D  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.036653s  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.055097s  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.036847s -EDS timing GET: 0.05633:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.046132:http://eds-api.ebscohost.com/edsapi/rest/info -EDS timing GET: 0.046947:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c00efbcf-87dd-4200-ac24-3182907ab329.SRYKjnBKAw248Vgo%2F%2FIeNUiXCjyzsA%2BJjq6yjSs19OE%3D -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.036877s -EDS timing GET: 0.05172:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.029549:http://eds-api.ebscohost.com/edsapi/rest/info -EDS auth failed, getting auth again -EDS timing AUTH: 0.03488s -EDS timing GET: 0.046689:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=aaa69d32-2f87-432e-9cb7-f42519d973b7.AzfaP%2Fvm9GQ79nSLxtB7S89VKQP%2FGMOlUfY4KyHZ6hM%3D -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction +  (0.1ms) begin transaction +EDS timing AUTH: 0.086025s +EDS timing GET: 0.005316:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n +EDS timing GET: 0.006612:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 +EDS timing GET: 0.007108:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction  (0.0ms) begin transaction +EDS timing AUTH: 0.009966s  (0.0ms) rollback transaction  (0.0ms) begin transaction +EDS timing AUTH: 0.007636s  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction +EDS timing AUTH: 0.011923s +EDS timing GET: 0.004743:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y +EDS timing GET: 0.003808:http://eds-api.ebscohost.com/edsapi/rest/info +EDS timing GET: 0.006032:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D  (0.1ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction +EDS timing AUTH: 0.015207s +EDS timing GET: 0.002758:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y +EDS timing GET: 0.002669:http://eds-api.ebscohost.com/edsapi/rest/info +EDS auth failed, getting auth again +EDS timing AUTH: 0.002789s +EDS timing GET: 0.005928:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.0ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.6ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_link.html.erb (0.7ms) - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (5.4ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -Processing by BentoSearch::SearchControllerTest::CustomSearchController#search as HTML - Parameters: {"engine_id"=>"mock", "query"=>"my search"} - Rendered text template (0.0ms) -Completed 403 Forbidden in 48ms (Views: 46.9ms | ActiveRecord: 0.0ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"not_existing"} -Completed 404 Not Found in 1ms (Views: 0.7ms | ActiveRecord: 0.0ms) -  (0.1ms) rollback transaction  (0.0ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"not_routable"} -Completed 403 Forbidden in 1ms (Views: 0.2ms | ActiveRecord: 0.0ms)  (0.0ms) rollback transaction  (0.1ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"mock"} - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.3ms) -Completed 200 OK in 10ms (Views: 9.5ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.3ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_search_error.html.erb (0.6ms)  (0.0ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.6ms) +  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.6ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.2ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -EDS timing AUTH: 0.08755s -EDS timing GET: 0.005166:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n -EDS timing GET: 0.006805:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 -EDS timing GET: 0.006515:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=ee4f8bdb-6a38-4637-b6dd-63c53f23cbea.xkR6p6hqA4xWmTAs16G5C2YxpKeW0Ub%2B8ReDzUfURY8%3D  (0.1ms) rollback transaction -  (0.3ms) begin transaction -EDS timing AUTH: 0.059025s -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.00896s -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.012106s -EDS timing GET: 0.00496:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.004069:http://eds-api.ebscohost.com/edsapi/rest/info -EDS timing GET: 0.006315:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c00efbcf-87dd-4200-ac24-3182907ab329.SRYKjnBKAw248Vgo%2F%2FIeNUiXCjyzsA%2BJjq6yjSs19OE%3D -  (0.1ms) rollback transaction  (0.0ms) begin transaction -EDS timing AUTH: 0.013408s -EDS timing GET: 0.00293:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.002887:http://eds-api.ebscohost.com/edsapi/rest/info -EDS auth failed, getting auth again -EDS timing AUTH: 0.00294s -EDS timing GET: 0.006263:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=aaa69d32-2f87-432e-9cb7-f42519d973b7.AzfaP%2Fvm9GQ79nSLxtB7S89VKQP%2FGMOlUfY4KyHZ6hM%3D -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction @@ -1682,10 +1358,38 @@  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction +BentoSearch::SearchEngine failed results: #<Timeout::Error: I am a horrible engine> + /home/rochkind/bento_search/test/unit/search_engine_base_test.rb:183:in `search_implementation' + /home/rochkind/bento_search/app/models/bento_search/search_engine.rb:101:in `search' + /home/rochkind/bento_search/test/unit/search_engine_base_test.rb:189:in `test_rescues_exceptions' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:949:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit/testcase.rb:17:in `run' + activesupport (3.2.8) lib/active_support/testing/setup_and_teardown.rb:36:in `block in run' + activesupport (3.2.8) lib/active_support/callbacks.rb:425:in `_run__2927298851373187549__setup__1905595697193905917__callbacks' + activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `__run_callback' + activesupport (3.2.8) lib/active_support/callbacks.rb:385:in `_run_setup_callbacks' + activesupport (3.2.8) lib/active_support/callbacks.rb:81:in `run_callbacks' + activesupport (3.2.8) lib/active_support/testing/setup_and_teardown.rb:35:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:787:in `block in _run_suite' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:780:in `map' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:780:in `_run_suite' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:565:in `block in _run_suites' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:563:in `each' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:563:in `_run_suites' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:746:in `_run_anything' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:909:in `run_tests' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:896:in `block in _run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:895:in `each' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:895:in `_run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:884:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:21:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:326:in `block (2 levels) in autorun' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:27:in `run_once' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:325:in `block in autorun'  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction @@ -1758,23 +1462,21 @@  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.8ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.9ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.5ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_link.html.erb (0.7ms) - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (5.5ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_link.html.erb (0.6ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (5.3ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction @@ -1801,352 +1503,143 @@  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction +  (0.1ms) begin transaction +  (0.1ms) rollback transaction Connecting to database specified by database.yml -  (0.4ms) begin transaction +  (0.6ms) begin transaction Processing by BentoSearch::SearchControllerTest::CustomSearchController#search as HTML Parameters: {"engine_id"=>"mock", "query"=>"my search"} Rendered text template (0.0ms) -Completed 403 Forbidden in 48ms (Views: 47.1ms | ActiveRecord: 0.0ms) +Completed 403 Forbidden in 52ms (Views: 51.0ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction Processing by BentoSearch::SearchController#search as HTML Parameters: {"query"=>"my search", "engine_id"=>"not_existing"} -Completed 404 Not Found in 1ms (Views: 0.7ms | ActiveRecord: 0.0ms) +Completed 404 Not Found in 2ms (Views: 0.8ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction -  (0.0ms) begin transaction +  (0.1ms) begin transaction Processing by BentoSearch::SearchController#search as HTML Parameters: {"query"=>"my search", "engine_id"=>"not_routable"} -Completed 403 Forbidden in 1ms (Views: 0.2ms | ActiveRecord: 0.0ms) -  (0.0ms) rollback transaction -  (0.0ms) begin transaction +Completed 403 Forbidden in 1ms (Views: 0.3ms | ActiveRecord: 0.0ms) +  (0.1ms) rollback transaction +  (0.1ms) begin transaction Processing by BentoSearch::SearchController#search as HTML Parameters: {"query"=>"my search", "engine_id"=>"mock"} - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.4ms) -Completed 200 OK in 10ms (Views: 9.6ms | ActiveRecord: 0.0ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.7ms) +Completed 200 OK in 13ms (Views: 12.4ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.6ms) -  (0.1ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_search_error.html.erb (0.9ms) -  (0.1ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.8ms) -  (0.1ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.8ms) -  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.2ms) rollback transaction -  (0.1ms) begin transaction -  (0.6ms) rollback transaction -  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.7ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_search_error.html.erb (0.9ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.111301s -EDS timing GET: 0.007247:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n -EDS timing GET: 0.009797:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 -EDS timing GET: 0.009449:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.8ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.058024s + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.8ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.012156s -  (0.2ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.018197s -EDS timing GET: 0.007098:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.005803:http://eds-api.ebscohost.com/edsapi/rest/info -EDS timing GET: 0.009082:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.022607s -EDS timing GET: 0.004252:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.00402:http://eds-api.ebscohost.com/edsapi/rest/info -EDS auth failed, getting auth again -EDS timing AUTH: 0.004232s -EDS timing GET: 0.008979:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction  (0.1ms) begin transaction +EDS timing AUTH: 0.078203s +EDS timing GET: 0.005192:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n +EDS timing GET: 0.006392:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 +EDS timing GET: 0.006761:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.1ms) begin transaction +EDS timing AUTH: 0.009677s  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.0ms) rollback transaction  (0.0ms) begin transaction +EDS timing AUTH: 0.007724s  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.1ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction +EDS timing AUTH: 0.011688s +EDS timing GET: 0.00463:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y +EDS timing GET: 0.003752:http://eds-api.ebscohost.com/edsapi/rest/info +EDS timing GET: 0.005909:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction +EDS timing AUTH: 0.015047s +EDS timing GET: 0.002669:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y +EDS timing GET: 0.002573:http://eds-api.ebscohost.com/edsapi/rest/info +EDS auth failed, getting auth again +EDS timing AUTH: 0.002704s +EDS timing GET: 0.005807:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.4ms) -  (0.1ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.4ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.2ms)  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_link.html.erb (0.5ms) - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (3.7ms) -  (0.1ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.2ms) -  (0.0ms) rollback transaction -  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.5ms) begin transaction -Processing by BentoSearch::SearchControllerTest::CustomSearchController#search as HTML - Parameters: {"engine_id"=>"mock", "query"=>"my search"} - Rendered text template (0.0ms) -Completed 403 Forbidden in 44ms (Views: 43.7ms | ActiveRecord: 0.0ms) -  (0.1ms) rollback transaction  (0.0ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"not_existing"} -Completed 404 Not Found in 1ms (Views: 0.6ms | ActiveRecord: 0.0ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"not_routable"} -Completed 403 Forbidden in 1ms (Views: 0.2ms | ActiveRecord: 0.0ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"mock"} - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.4ms) -Completed 200 OK in 43ms (Views: 42.5ms | ActiveRecord: 0.0ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.4ms)  (0.1ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_search_error.html.erb (0.7ms) -  (0.0ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.7ms) -  (0.0ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.6ms) -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -EDS timing AUTH: 0.043864s -EDS timing GET: 0.00513:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n -EDS timing GET: 0.006678:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 -EDS timing GET: 0.007244:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D -  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.011299s  (0.1ms) rollback transaction  (0.0ms) begin transaction -EDS timing AUTH: 0.009049s -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.012877s -EDS timing GET: 0.004989:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.004046:http://eds-api.ebscohost.com/edsapi/rest/info -EDS timing GET: 0.006187:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -EDS timing AUTH: 0.055436s -EDS timing GET: 0.003133:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.002843:http://eds-api.ebscohost.com/edsapi/rest/info -EDS auth failed, getting auth again -EDS timing AUTH: 0.00315s -EDS timing GET: 0.0063:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction @@ -2158,12 +1651,38 @@  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction +BentoSearch::SearchEngine failed results: #<Timeout::Error: I am a horrible engine> + /home/rochkind/bento_search/test/unit/search_engine_base_test.rb:183:in `search_implementation' + /home/rochkind/bento_search/app/models/bento_search/search_engine.rb:95:in `search' + /home/rochkind/bento_search/test/unit/search_engine_base_test.rb:189:in `test_rescues_exceptions' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:949:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit/testcase.rb:17:in `run' + activesupport (3.2.8) lib/active_support/testing/setup_and_teardown.rb:36:in `block in run' + activesupport (3.2.8) lib/active_support/callbacks.rb:425:in `_run__4341096706219397571__setup__437050511900262550__callbacks' + activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `__run_callback' + activesupport (3.2.8) lib/active_support/callbacks.rb:385:in `_run_setup_callbacks' + activesupport (3.2.8) lib/active_support/callbacks.rb:81:in `run_callbacks' + activesupport (3.2.8) lib/active_support/testing/setup_and_teardown.rb:35:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:787:in `block in _run_suite' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:780:in `map' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:780:in `_run_suite' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:565:in `block in _run_suites' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:563:in `each' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:563:in `_run_suites' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:746:in `_run_anything' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:909:in `run_tests' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:896:in `block in _run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:895:in `each' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:895:in `_run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:884:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:21:in `run' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:326:in `block (2 levels) in autorun' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:27:in `run_once' + /home/rochkind/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/test/unit.rb:325:in `block in autorun'  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction @@ -2174,927 +1693,110 @@  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.2ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.2ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.6ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_link.html.erb (0.8ms) - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (6.0ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.1ms) begin transaction -  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -EDS timing AUTH: 0.044499s -EDS timing GET: 0.005264:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n -EDS timing GET: 0.006844:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 -EDS timing GET: 0.00697:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.010266s -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -EDS timing AUTH: 0.007862s  (0.0ms) rollback transaction  (0.0ms) begin transaction -EDS timing AUTH: 0.011978s -EDS timing GET: 0.004904:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.005731:http://eds-api.ebscohost.com/edsapi/rest/info -EDS timing GET: 0.008848:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.022218s -EDS timing GET: 0.004177:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.004018:http://eds-api.ebscohost.com/edsapi/rest/info -EDS auth failed, getting auth again -EDS timing AUTH: 0.004208s -EDS timing GET: 0.008946:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -Processing by BentoSearch::SearchControllerTest::CustomSearchController#search as HTML - Parameters: {"engine_id"=>"mock", "query"=>"my search"} - Rendered text template (0.0ms) -Completed 403 Forbidden in 43ms (Views: 42.1ms | ActiveRecord: 0.0ms) -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"not_existing"} -Completed 404 Not Found in 1ms (Views: 0.6ms | ActiveRecord: 0.0ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"not_routable"} -Completed 403 Forbidden in 1ms (Views: 0.2ms | ActiveRecord: 0.0ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"mock"} - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.4ms) -Completed 200 OK in 43ms (Views: 42.8ms | ActiveRecord: 0.0ms) -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.4ms) -  (0.1ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_search_error.html.erb (0.7ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.7ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.6ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -EDS timing AUTH: 0.043403s -EDS timing GET: 0.004929:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n -EDS timing GET: 0.00662:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 -EDS timing GET: 0.006599:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.00965s -  (0.0ms) rollback transaction  (0.0ms) begin transaction -EDS timing AUTH: 0.007815s  (0.0ms) rollback transaction  (0.0ms) begin transaction -EDS timing AUTH: 0.012251s -EDS timing GET: 0.004834:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.004091:http://eds-api.ebscohost.com/edsapi/rest/info -EDS timing GET: 0.00608:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -EDS timing AUTH: 0.053019s -EDS timing GET: 0.003031:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.002826:http://eds-api.ebscohost.com/edsapi/rest/info -EDS auth failed, getting auth again -EDS timing AUTH: 0.002944s -EDS timing GET: 0.006158:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D -  (0.1ms) rollback transaction -  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction  (0.1ms) rollback transaction -  (0.0ms) begin transaction +  (0.1ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.0ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.6ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_link.html.erb (0.7ms) - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (5.2ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -Processing by BentoSearch::SearchControllerTest::CustomSearchController#search as HTML - Parameters: {"engine_id"=>"mock", "query"=>"my search"} - Rendered text template (0.0ms) -Completed 403 Forbidden in 46ms (Views: 45.1ms | ActiveRecord: 0.0ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"not_existing"} -Completed 404 Not Found in 1ms (Views: 0.6ms | ActiveRecord: 0.0ms) -  (0.1ms) rollback transaction  (0.0ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"not_routable"} -Completed 403 Forbidden in 1ms (Views: 0.2ms | ActiveRecord: 0.0ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"mock"} - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.7ms) -Completed 200 OK in 45ms (Views: 44.4ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.6ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_search_error.html.erb (0.7ms) -  (0.1ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.8ms) -  (0.1ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.9ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -EDS timing AUTH: 0.043853s -EDS timing GET: 0.004974:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n -EDS timing GET: 0.006681:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 -EDS timing GET: 0.006663:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D -  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.00969s -  (0.0ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.00786s -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -EDS timing AUTH: 0.01203s -EDS timing GET: 0.004857:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.004047:http://eds-api.ebscohost.com/edsapi/rest/info -EDS timing GET: 0.006295:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.3ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction -EDS timing AUTH: 0.053803s -EDS timing GET: 0.003052:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.002809:http://eds-api.ebscohost.com/edsapi/rest/info -EDS auth failed, getting auth again -EDS timing AUTH: 0.002982s -EDS timing GET: 0.006214:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D -  (0.1ms) rollback transaction -  (0.1ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.2ms)  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction  (0.1ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_link.html.erb (0.4ms) + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (3.7ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.1ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction + Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.2ms)  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.1ms) begin transaction  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.1ms) begin transaction -  (0.0ms) rollback transaction -  (0.1ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.9ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.6ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_link.html.erb (0.7ms) - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (5.4ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.3ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.5ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.5ms) begin transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -Connecting to database specified by database.yml -  (0.6ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -  (0.2ms) rollback transaction -Connecting to database specified by database.yml -  (0.7ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -Connecting to database specified by database.yml -  (0.6ms) begin transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.5ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.5ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.6ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.6ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.6ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.6ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.6ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.5ms) begin transaction -Processing by BentoSearch::SearchControllerTest::CustomSearchController#search as HTML - Parameters: {"engine_id"=>"mock", "query"=>"my search"} - Rendered text template (0.0ms) -Completed 403 Forbidden in 54ms (Views: 53.8ms | ActiveRecord: 0.0ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"not_existing"} -Completed 404 Not Found in 1ms (Views: 0.7ms | ActiveRecord: 0.0ms) -  (0.1ms) rollback transaction  (0.0ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"not_routable"} -Completed 403 Forbidden in 1ms (Views: 0.2ms | ActiveRecord: 0.0ms) -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -Processing by BentoSearch::SearchController#search as HTML - Parameters: {"query"=>"my search", "engine_id"=>"mock"} - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.9ms) -Completed 200 OK in 56ms (Views: 55.4ms | ActiveRecord: 0.0ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (2.4ms) -  (0.1ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_search_error.html.erb (0.7ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.8ms) -  (0.0ms) rollback transaction -  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.7ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.064803s -EDS timing GET: 0.007394:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=n -EDS timing GET: 0.010537:http://eds-api.ebscohost.com/edsapi/rest/search?view=detailed&query=AND%2Ccancer&searchmode=all&highlight=y&resultsperpage=10 -EDS timing GET: 0.009236:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2%2Fw9Gjg%2BwmkWnBdUv3As%3D -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.058206s -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.011972s -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.018014s -EDS timing GET: 0.006907:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.005718:http://eds-api.ebscohost.com/edsapi/rest/info -EDS timing GET: 0.008916:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=c6f7d532-8726-47a7-8e75-b3851a615c68.lS%2FLBviHYcah4372jECVTkM%2Fb4%2FDpExjKLExBuNU0eA%3D -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -EDS timing AUTH: 0.022451s -EDS timing GET: 0.004318:http://eds-api.ebscohost.com/edsapi/rest/createsession?profile=edsapi&guest=y -EDS timing GET: 0.004042:http://eds-api.ebscohost.com/edsapi/rest/info -EDS auth failed, getting auth again -EDS timing AUTH: 0.004225s -EDS timing GET: 0.008844:http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=d389e524-95ea-4518-bd4a-6b0eb7c0af44.kEvPxolRdsxALTno8ChwQHJ3j2LNLih2ApF64T4yK4w%3D -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.0ms) rollback transaction -  (0.1ms) begin transaction -  (0.0ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.0ms) rollback transaction -  (0.1ms) begin transaction -  (0.0ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (1.4ms) -  (0.1ms) rollback transaction -  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.4ms) -  (0.0ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.2ms)  (0.0ms) rollback transaction  (0.1ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_link.html.erb (0.5ms) - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (3.7ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction - Rendered /home/rochkind/bento_search/app/views/bento_search/_std_item.html.erb (0.2ms) -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.1ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.1ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.0ms) rollback transaction -  (0.0ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.4ms) begin transaction -  (0.1ms) rollback transaction -Connecting to database specified by database.yml -  (0.5ms) begin transaction  (0.1ms) rollback transaction