(3.7ms) CREATE TABLE "books" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" text, "created_at" datetime, "updated_at" datetime, "service_id" varchar)   (2.7ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  (0.1ms) select sqlite_version(*)  (1.6ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version")  (0.1ms) SELECT version FROM "schema_migrations"  (1.2ms) INSERT INTO "schema_migrations" (version) VALUES ('20150312044151')  (0.8ms) INSERT INTO "schema_migrations" (version) VALUES ('20140407202136') ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations"  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.5ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:38:10.764058"], ["updated_at", "2016-05-10 19:38:10.764058"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:38:10.768306"], ["updated_at", "2016-05-10 19:38:10.768306"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:38:10.770564"], ["updated_at", "2016-05-10 19:38:10.770564"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction -------------------------------- BooksControllerTest: test_create --------------------------------  (0.1ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:10.799357"], ["updated_at", "2016-05-10 19:38:10.799357"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.8ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:10.800630"], ["updated_at", "2016-05-10 19:38:10.800630"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:10.802404"], ["updated_at", "2016-05-10 19:38:10.802404"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:10.803290"], ["updated_at", "2016-05-10 19:38:10.803290"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:10.804153"], ["updated_at", "2016-05-10 19:38:10.804153"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) SELECT COUNT(*) FROM "books" Processing by BooksController#create as HTML Parameters: {"book"=>{"name"=>"newly-created-book"}}  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "created_at", "updated_at") VALUES (?, ?, ?) [["name", "newly-created-book"], ["created_at", "2016-05-10 19:38:10.807507"], ["updated_at", "2016-05-10 19:38:10.807507"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://test.host/books Completed 302 Found in 1ms (ActiveRecord: 0.2ms)  (0.0ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.1ms) begin transaction ------------------------------- BooksControllerTest: test_index -------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:10.810247"], ["updated_at", "2016-05-10 19:38:10.810247"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:10.811345"], ["updated_at", "2016-05-10 19:38:10.811345"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:10.812425"], ["updated_at", "2016-05-10 19:38:10.812425"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:10.813413"], ["updated_at", "2016-05-10 19:38:10.813413"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:10.814293"], ["updated_at", "2016-05-10 19:38:10.814293"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Rendered books/index.html.erb within layouts/application (1.0ms) Completed 200 OK in 238ms (Views: 237.1ms | ActiveRecord: 0.1ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.0ms) begin transaction ---------------------------------------------------- BooksControllerTest: test_index_with_multiple_params ----------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:11.055863"], ["updated_at", "2016-05-10 19:38:11.055863"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:11.057044"], ["updated_at", "2016-05-10 19:38:11.057044"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:11.058043"], ["updated_at", "2016-05-10 19:38:11.058043"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:11.058946"], ["updated_at", "2016-05-10 19:38:11.058946"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:11.059956"], ["updated_at", "2016-05-10 19:38:11.059956"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Rendered books/index.html.erb within layouts/application (0.0ms) Completed 200 OK in 1ms (Views: 0.9ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction ------------------------------ BooksControllerTest: test_show ------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:11.063783"], ["updated_at", "2016-05-10 19:38:11.063783"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:11.064714"], ["updated_at", "2016-05-10 19:38:11.064714"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:11.065639"], ["updated_at", "2016-05-10 19:38:11.065639"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:11.066459"], ["updated_at", "2016-05-10 19:38:11.066459"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:38:11.067253"], ["updated_at", "2016-05-10 19:38:11.067253"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#show as HTML Parameters: {"id"=>"1"} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]] Rendered books/show.html.erb within layouts/application (0.3ms) Completed 200 OK in 6ms (Views: 1.6ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:38:11.077491"], ["updated_at", "2016-05-10 19:38:11.077491"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:38:11.079307"], ["updated_at", "2016-05-10 19:38:11.079307"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:38:11.081670"], ["updated_at", "2016-05-10 19:38:11.081670"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:38:11.083429"], ["updated_at", "2016-05-10 19:38:11.083429"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction ------------------------------------------------------------------------------------------------- FastlyRails::CacheControlHeadersTest: test_sets_cache_control_headers_on_actioncontroller_request -------------------------------------------------------------------------------------------------  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction ----------------------------------------------------------------------- FastlyHeadersTest: test_/books/:id_show_page_should_have_fastly_headers -----------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:38:11.114449"], ["updated_at", "2016-05-10 19:38:11.114449"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started GET "/books/1" for 127.0.0.1 at 2016-05-10 19:38:11 +0000 Processing by BooksController#show as HTML Parameters: {"id"=>"1"} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]] Rendered books/show.html.erb within layouts/application (0.0ms) Completed 200 OK in 2ms (Views: 1.1ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction -------------------------------------------------------------------- FastlyHeadersTest: test_/books_index_page_should_have_fastly_headers -------------------------------------------------------------------- Started GET "/books" for 127.0.0.1 at 2016-05-10 19:38:11 +0000 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Rendered books/index.html.erb within layouts/application (0.1ms) Completed 200 OK in 3ms (Views: 1.9ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction ---------------------------------------------------------------------------------------------- FastlyHeadersTest: test_DELETE_/books/:id_should_not_have_fastly_headers/_fastly_header_values ----------------------------------------------------------------------------------------------  (0.1ms) SAVEPOINT active_record_1 SQL (0.3ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:38:11.133503"], ["updated_at", "2016-05-10 19:38:11.133503"]]  (0.1ms) RELEASE SAVEPOINT active_record_1 Started DELETE "/books/1" for 127.0.0.1 at 2016-05-10 19:38:11 +0000 Processing by BooksController#destroy as HTML Parameters: {"id"=>"1"} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) DELETE FROM "books" WHERE "books"."id" = ? [["id", 1]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books Completed 302 Found in 2ms (ActiveRecord: 0.3ms)  (0.1ms) SELECT COUNT(*) FROM "books" WHERE "books"."id" = ? [["id", 1]]  (0.1ms) rollback transaction  (0.0ms) begin transaction ---------------------------------------------------------------------------------------- FastlyHeadersTest: test_POST_/books_should_not_have_fastly_headers/_fastly_header_values ----------------------------------------------------------------------------------------  (0.1ms) SELECT COUNT(*) FROM "books" Started POST "/books" for 127.0.0.1 at 2016-05-10 19:38:11 +0000 Processing by BooksController#create as HTML Parameters: {"book"=>{"name"=>"some new book"}}  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "created_at", "updated_at") VALUES (?, ?, ?) [["name", "some new book"], ["created_at", "2016-05-10 19:38:11.147111"], ["updated_at", "2016-05-10 19:38:11.147111"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books Completed 302 Found in 2ms (ActiveRecord: 0.2ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.0ms) begin transaction ------------------------------------------------------------------------------------------- FastlyHeadersTest: test_PUT_/books/:id_should_not_have_fastly_headers/_fastly_header_values -------------------------------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some new book"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:38:11.150304"], ["updated_at", "2016-05-10 19:38:11.150304"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started PUT "/books/1" for 127.0.0.1 at 2016-05-10 19:38:11 +0000 Processing by BooksController#update as HTML Parameters: {"id"=>"1", "book"=>{"name"=>"changed book"}} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) UPDATE "books" SET "name" = ?, "updated_at" = ? WHERE "books"."id" = ? [["name", "changed book"], ["updated_at", "2016-05-10 19:38:11.155336"], ["id", 1]]  (0.1ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books/1 Completed 302 Found in 3ms (ActiveRecord: 0.4ms) Book Load (0.0ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations"  (12.0ms) CREATE TABLE "books" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" text, "created_at" datetime, "updated_at" datetime, "service_id" varchar)   (1.8ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  (0.1ms) select sqlite_version(*)  (2.9ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version")  (0.1ms) SELECT version FROM "schema_migrations"  (1.0ms) INSERT INTO "schema_migrations" (version) VALUES ('20150312044151')  (1.0ms) INSERT INTO "schema_migrations" (version) VALUES ('20140407202136') ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations"  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) SAVEPOINT active_record_1 SQL (0.3ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:40:50.364634"], ["updated_at", "2016-05-10 19:40:50.364634"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:40:50.368310"], ["updated_at", "2016-05-10 19:40:50.368310"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:40:50.371476"], ["updated_at", "2016-05-10 19:40:50.371476"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -------------------------------- BooksControllerTest: test_create --------------------------------  (0.1ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.412248"], ["updated_at", "2016-05-10 19:40:50.412248"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.413602"], ["updated_at", "2016-05-10 19:40:50.413602"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.414464"], ["updated_at", "2016-05-10 19:40:50.414464"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.415325"], ["updated_at", "2016-05-10 19:40:50.415325"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.416184"], ["updated_at", "2016-05-10 19:40:50.416184"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) SELECT COUNT(*) FROM "books" Processing by BooksController#create as HTML Parameters: {"book"=>{"name"=>"newly-created-book"}}  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "created_at", "updated_at") VALUES (?, ?, ?) [["name", "newly-created-book"], ["created_at", "2016-05-10 19:40:50.419660"], ["updated_at", "2016-05-10 19:40:50.419660"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://test.host/books Completed 302 Found in 2ms (ActiveRecord: 0.1ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.1ms) begin transaction ------------------------------- BooksControllerTest: test_index -------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.423967"], ["updated_at", "2016-05-10 19:40:50.423967"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.425057"], ["updated_at", "2016-05-10 19:40:50.425057"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.425979"], ["updated_at", "2016-05-10 19:40:50.425979"]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.426866"], ["updated_at", "2016-05-10 19:40:50.426866"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.427675"], ["updated_at", "2016-05-10 19:40:50.427675"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Rendered books/index.html.erb within layouts/application (1.0ms) Completed 200 OK in 294ms (Views: 293.0ms | ActiveRecord: 0.1ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.2ms) rollback transaction  (0.1ms) begin transaction ---------------------------------------------------- BooksControllerTest: test_index_with_multiple_params ----------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.725370"], ["updated_at", "2016-05-10 19:40:50.725370"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.736679"], ["updated_at", "2016-05-10 19:40:50.736679"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.737781"], ["updated_at", "2016-05-10 19:40:50.737781"]]  (0.2ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.738918"], ["updated_at", "2016-05-10 19:40:50.738918"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.739939"], ["updated_at", "2016-05-10 19:40:50.739939"]]  (0.1ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Rendered books/index.html.erb within layouts/application (0.1ms) Completed 200 OK in 2ms (Views: 1.4ms | ActiveRecord: 0.1ms)  (0.2ms) rollback transaction  (0.1ms) begin transaction ------------------------------ BooksControllerTest: test_show ------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.759271"], ["updated_at", "2016-05-10 19:40:50.759271"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.760482"], ["updated_at", "2016-05-10 19:40:50.760482"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.761537"], ["updated_at", "2016-05-10 19:40:50.761537"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.762355"], ["updated_at", "2016-05-10 19:40:50.762355"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:40:50.763112"], ["updated_at", "2016-05-10 19:40:50.763112"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#show as HTML Parameters: {"id"=>"1"} Book Load (0.2ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]] Rendered books/show.html.erb within layouts/application (0.5ms) Completed 200 OK in 30ms (Views: 1.8ms | ActiveRecord: 0.2ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction ----------------------------------------------------------------------- FastlyHeadersTest: test_/books/:id_show_page_should_have_fastly_headers -----------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:40:50.796096"], ["updated_at", "2016-05-10 19:40:50.796096"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started GET "/books/1" for 127.0.0.1 at 2016-05-10 19:40:50 +0000 Processing by BooksController#show as HTML Parameters: {"id"=>"1"} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]] Rendered books/show.html.erb within layouts/application (0.0ms) Completed 200 OK in 1ms (Views: 0.9ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction -------------------------------------------------------------------- FastlyHeadersTest: test_/books_index_page_should_have_fastly_headers -------------------------------------------------------------------- Started GET "/books" for 127.0.0.1 at 2016-05-10 19:40:50 +0000 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Rendered books/index.html.erb within layouts/application (0.0ms) Completed 200 OK in 2ms (Views: 1.1ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction ---------------------------------------------------------------------------------------------- FastlyHeadersTest: test_DELETE_/books/:id_should_not_have_fastly_headers/_fastly_header_values ----------------------------------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:40:50.812766"], ["updated_at", "2016-05-10 19:40:50.812766"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started DELETE "/books/1" for 127.0.0.1 at 2016-05-10 19:40:50 +0000 Processing by BooksController#destroy as HTML Parameters: {"id"=>"1"} Book Load (0.0ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) DELETE FROM "books" WHERE "books"."id" = ? [["id", 1]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books Completed 302 Found in 1ms (ActiveRecord: 0.3ms)  (0.1ms) SELECT COUNT(*) FROM "books" WHERE "books"."id" = ? [["id", 1]]  (0.1ms) rollback transaction  (0.1ms) begin transaction ---------------------------------------------------------------------------------------- FastlyHeadersTest: test_POST_/books_should_not_have_fastly_headers/_fastly_header_values ----------------------------------------------------------------------------------------  (0.1ms) SELECT COUNT(*) FROM "books" Started POST "/books" for 127.0.0.1 at 2016-05-10 19:40:50 +0000 Processing by BooksController#create as HTML Parameters: {"book"=>{"name"=>"some new book"}}  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "created_at", "updated_at") VALUES (?, ?, ?) [["name", "some new book"], ["created_at", "2016-05-10 19:40:50.825153"], ["updated_at", "2016-05-10 19:40:50.825153"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books Completed 302 Found in 1ms (ActiveRecord: 0.2ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.0ms) begin transaction ------------------------------------------------------------------------------------------- FastlyHeadersTest: test_PUT_/books/:id_should_not_have_fastly_headers/_fastly_header_values -------------------------------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some new book"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:40:50.828206"], ["updated_at", "2016-05-10 19:40:50.828206"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started PUT "/books/1" for 127.0.0.1 at 2016-05-10 19:40:50 +0000 Processing by BooksController#update as HTML Parameters: {"id"=>"1", "book"=>{"name"=>"changed book"}} Book Load (0.0ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.6ms) SAVEPOINT active_record_1 SQL (0.2ms) UPDATE "books" SET "name" = ?, "updated_at" = ? WHERE "books"."id" = ? [["name", "changed book"], ["updated_at", "2016-05-10 19:40:50.834284"], ["id", 1]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books/1 Completed 302 Found in 4ms (ActiveRecord: 0.9ms) Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:40:50.839662"], ["updated_at", "2016-05-10 19:40:50.839662"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:40:50.842382"], ["updated_at", "2016-05-10 19:40:50.842382"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:40:50.844238"], ["updated_at", "2016-05-10 19:40:50.844238"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:40:50.846099"], ["updated_at", "2016-05-10 19:40:50.846099"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction ------------------------------------------------------------------------------------------------- FastlyRails::CacheControlHeadersTest: test_sets_cache_control_headers_on_actioncontroller_request -------------------------------------------------------------------------------------------------  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.1ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations"  (2.7ms) CREATE TABLE "books" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" text, "created_at" datetime, "updated_at" datetime, "service_id" varchar)   (1.8ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  (0.1ms) select sqlite_version(*)  (1.9ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version")  (0.1ms) SELECT version FROM "schema_migrations"  (1.7ms) INSERT INTO "schema_migrations" (version) VALUES ('20150312044151')  (1.2ms) INSERT INTO "schema_migrations" (version) VALUES ('20140407202136') ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations"  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) SAVEPOINT active_record_1 SQL (0.3ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:41:23.605449"], ["updated_at", "2016-05-10 19:41:23.605449"]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) commit transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:41:23.611038"], ["updated_at", "2016-05-10 19:41:23.611038"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:41:23.613370"], ["updated_at", "2016-05-10 19:41:23.613370"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction -------------------------------- BooksControllerTest: test_create --------------------------------  (0.1ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.645040"], ["updated_at", "2016-05-10 19:41:23.645040"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.646506"], ["updated_at", "2016-05-10 19:41:23.646506"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.647370"], ["updated_at", "2016-05-10 19:41:23.647370"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.648268"], ["updated_at", "2016-05-10 19:41:23.648268"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.649075"], ["updated_at", "2016-05-10 19:41:23.649075"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) SELECT COUNT(*) FROM "books" Processing by BooksController#create as HTML Parameters: {"book"=>{"name"=>"newly-created-book"}}  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "created_at", "updated_at") VALUES (?, ?, ?) [["name", "newly-created-book"], ["created_at", "2016-05-10 19:41:23.652416"], ["updated_at", "2016-05-10 19:41:23.652416"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://test.host/books Completed 302 Found in 1ms (ActiveRecord: 0.1ms)  (0.0ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.0ms) begin transaction ------------------------------- BooksControllerTest: test_index -------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.654974"], ["updated_at", "2016-05-10 19:41:23.654974"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.655978"], ["updated_at", "2016-05-10 19:41:23.655978"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.656876"], ["updated_at", "2016-05-10 19:41:23.656876"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.657865"], ["updated_at", "2016-05-10 19:41:23.657865"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.658702"], ["updated_at", "2016-05-10 19:41:23.658702"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Rendered books/index.html.erb within layouts/application (0.7ms) Completed 200 OK in 207ms (Views: 206.2ms | ActiveRecord: 0.1ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.2ms) rollback transaction  (0.0ms) begin transaction ---------------------------------------------------- BooksControllerTest: test_index_with_multiple_params ----------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.869892"], ["updated_at", "2016-05-10 19:41:23.869892"]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.871552"], ["updated_at", "2016-05-10 19:41:23.871552"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.872956"], ["updated_at", "2016-05-10 19:41:23.872956"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.874240"], ["updated_at", "2016-05-10 19:41:23.874240"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.875406"], ["updated_at", "2016-05-10 19:41:23.875406"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Rendered books/index.html.erb within layouts/application (0.1ms) Completed 200 OK in 2ms (Views: 1.1ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction ------------------------------ BooksControllerTest: test_show ------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.880427"], ["updated_at", "2016-05-10 19:41:23.880427"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.881500"], ["updated_at", "2016-05-10 19:41:23.881500"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.882520"], ["updated_at", "2016-05-10 19:41:23.882520"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.883413"], ["updated_at", "2016-05-10 19:41:23.883413"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:41:23.884299"], ["updated_at", "2016-05-10 19:41:23.884299"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#show as HTML Parameters: {"id"=>"1"} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]] Rendered books/show.html.erb within layouts/application (0.2ms) Completed 200 OK in 6ms (Views: 1.6ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.1ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:41:23.895738"], ["updated_at", "2016-05-10 19:41:23.895738"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:41:23.897637"], ["updated_at", "2016-05-10 19:41:23.897637"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:41:23.899858"], ["updated_at", "2016-05-10 19:41:23.899858"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:41:23.901507"], ["updated_at", "2016-05-10 19:41:23.901507"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.2ms) begin transaction  (0.1ms) commit transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction ----------------------------------------------------------------------- FastlyHeadersTest: test_/books/:id_show_page_should_have_fastly_headers -----------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:41:23.916487"], ["updated_at", "2016-05-10 19:41:23.916487"]]  (0.1ms) RELEASE SAVEPOINT active_record_1 Started GET "/books/1" for 127.0.0.1 at 2016-05-10 19:41:23 +0000 Processing by BooksController#show as HTML Parameters: {"id"=>"1"} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]] Rendered books/show.html.erb within layouts/application (0.0ms) Completed 200 OK in 2ms (Views: 1.3ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction -------------------------------------------------------------------- FastlyHeadersTest: test_/books_index_page_should_have_fastly_headers -------------------------------------------------------------------- Started GET "/books" for 127.0.0.1 at 2016-05-10 19:41:23 +0000 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Rendered books/index.html.erb within layouts/application (0.0ms) Completed 200 OK in 1ms (Views: 0.8ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction ---------------------------------------------------------------------------------------------- FastlyHeadersTest: test_DELETE_/books/:id_should_not_have_fastly_headers/_fastly_header_values ----------------------------------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:41:23.932800"], ["updated_at", "2016-05-10 19:41:23.932800"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started DELETE "/books/1" for 127.0.0.1 at 2016-05-10 19:41:23 +0000 Processing by BooksController#destroy as HTML Parameters: {"id"=>"1"} Book Load (0.0ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) DELETE FROM "books" WHERE "books"."id" = ? [["id", 1]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books Completed 302 Found in 1ms (ActiveRecord: 0.2ms)  (0.1ms) SELECT COUNT(*) FROM "books" WHERE "books"."id" = ? [["id", 1]]  (0.1ms) rollback transaction  (0.0ms) begin transaction ---------------------------------------------------------------------------------------- FastlyHeadersTest: test_POST_/books_should_not_have_fastly_headers/_fastly_header_values ----------------------------------------------------------------------------------------  (0.1ms) SELECT COUNT(*) FROM "books" Started POST "/books" for 127.0.0.1 at 2016-05-10 19:41:23 +0000 Processing by BooksController#create as HTML Parameters: {"book"=>{"name"=>"some new book"}}  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "created_at", "updated_at") VALUES (?, ?, ?) [["name", "some new book"], ["created_at", "2016-05-10 19:41:23.942933"], ["updated_at", "2016-05-10 19:41:23.942933"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books Completed 302 Found in 2ms (ActiveRecord: 0.2ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.0ms) begin transaction ------------------------------------------------------------------------------------------- FastlyHeadersTest: test_PUT_/books/:id_should_not_have_fastly_headers/_fastly_header_values -------------------------------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some new book"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:41:23.946182"], ["updated_at", "2016-05-10 19:41:23.946182"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started PUT "/books/1" for 127.0.0.1 at 2016-05-10 19:41:23 +0000 Processing by BooksController#update as HTML Parameters: {"id"=>"1", "book"=>{"name"=>"changed book"}} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) UPDATE "books" SET "name" = ?, "updated_at" = ? WHERE "books"."id" = ? [["name", "changed book"], ["updated_at", "2016-05-10 19:41:23.951271"], ["id", 1]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books/1 Completed 302 Found in 2ms (ActiveRecord: 0.3ms) Book Load (0.0ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.1ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction ------------------------------------------------------------------------------------------------- FastlyRails::CacheControlHeadersTest: test_sets_cache_control_headers_on_actioncontroller_request -------------------------------------------------------------------------------------------------  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction ActiveRecord::SchemaMigration Load (0.2ms) SELECT "schema_migrations".* FROM "schema_migrations"  (2.7ms) CREATE TABLE "books" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" text, "created_at" datetime, "updated_at" datetime, "service_id" varchar)   (2.0ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  (0.1ms) select sqlite_version(*)  (2.1ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version")  (0.1ms) SELECT version FROM "schema_migrations"  (1.0ms) INSERT INTO "schema_migrations" (version) VALUES ('20150312044151')  (1.0ms) INSERT INTO "schema_migrations" (version) VALUES ('20140407202136') ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations"  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction ------------------------------------------------------------------------------------------------- FastlyRails::CacheControlHeadersTest: test_sets_cache_control_headers_on_actioncontroller_request -------------------------------------------------------------------------------------------------  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction ----------------------------------------------------------------------- FastlyHeadersTest: test_/books/:id_show_page_should_have_fastly_headers -----------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:43:46.277788"], ["updated_at", "2016-05-10 19:43:46.277788"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started GET "/books/1" for 127.0.0.1 at 2016-05-10 19:43:46 +0000 Processing by BooksController#show as HTML Parameters: {"id"=>"1"} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]] Rendered books/show.html.erb within layouts/application (0.7ms) Completed 200 OK in 207ms (Views: 203.7ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction -------------------------------------------------------------------- FastlyHeadersTest: test_/books_index_page_should_have_fastly_headers -------------------------------------------------------------------- Started GET "/books" for 127.0.0.1 at 2016-05-10 19:43:46 +0000 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Rendered books/index.html.erb within layouts/application (0.2ms) Completed 200 OK in 2ms (Views: 1.6ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction ---------------------------------------------------------------------------------------------- FastlyHeadersTest: test_DELETE_/books/:id_should_not_have_fastly_headers/_fastly_header_values ----------------------------------------------------------------------------------------------  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:43:46.526956"], ["updated_at", "2016-05-10 19:43:46.526956"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started DELETE "/books/1" for 127.0.0.1 at 2016-05-10 19:43:46 +0000 Processing by BooksController#destroy as HTML Parameters: {"id"=>"1"} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) DELETE FROM "books" WHERE "books"."id" = ? [["id", 1]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books Completed 302 Found in 2ms (ActiveRecord: 0.3ms)  (0.1ms) SELECT COUNT(*) FROM "books" WHERE "books"."id" = ? [["id", 1]]  (0.1ms) rollback transaction  (0.1ms) begin transaction ---------------------------------------------------------------------------------------- FastlyHeadersTest: test_POST_/books_should_not_have_fastly_headers/_fastly_header_values ----------------------------------------------------------------------------------------  (0.1ms) SELECT COUNT(*) FROM "books" Started POST "/books" for 127.0.0.1 at 2016-05-10 19:43:46 +0000 Processing by BooksController#create as HTML Parameters: {"book"=>{"name"=>"some new book"}}  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "created_at", "updated_at") VALUES (?, ?, ?) [["name", "some new book"], ["created_at", "2016-05-10 19:43:46.539488"], ["updated_at", "2016-05-10 19:43:46.539488"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books Completed 302 Found in 1ms (ActiveRecord: 0.2ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.0ms) begin transaction ------------------------------------------------------------------------------------------- FastlyHeadersTest: test_PUT_/books/:id_should_not_have_fastly_headers/_fastly_header_values -------------------------------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some new book"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:43:46.542420"], ["updated_at", "2016-05-10 19:43:46.542420"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started PUT "/books/1" for 127.0.0.1 at 2016-05-10 19:43:46 +0000 Processing by BooksController#update as HTML Parameters: {"id"=>"1", "book"=>{"name"=>"changed book"}} Book Load (0.0ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) UPDATE "books" SET "name" = ?, "updated_at" = ? WHERE "books"."id" = ? [["name", "changed book"], ["updated_at", "2016-05-10 19:43:46.547208"], ["id", 1]]  (0.1ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books/1 Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Book Load (0.0ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.1ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:43:46.552437"], ["updated_at", "2016-05-10 19:43:46.552437"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:43:46.554191"], ["updated_at", "2016-05-10 19:43:46.554191"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:43:46.556099"], ["updated_at", "2016-05-10 19:43:46.556099"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.1ms) commit transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -------------------------------- BooksControllerTest: test_create --------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.570205"], ["updated_at", "2016-05-10 19:43:46.570205"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.571427"], ["updated_at", "2016-05-10 19:43:46.571427"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.572395"], ["updated_at", "2016-05-10 19:43:46.572395"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.573188"], ["updated_at", "2016-05-10 19:43:46.573188"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.574120"], ["updated_at", "2016-05-10 19:43:46.574120"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SELECT COUNT(*) FROM "books" Processing by BooksController#create as HTML Parameters: {"book"=>{"name"=>"newly-created-book"}}  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "created_at", "updated_at") VALUES (?, ?, ?) [["name", "newly-created-book"], ["created_at", "2016-05-10 19:43:46.576917"], ["updated_at", "2016-05-10 19:43:46.576917"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://test.host/books Completed 302 Found in 1ms (ActiveRecord: 0.2ms)  (0.0ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.0ms) begin transaction ------------------------------- BooksControllerTest: test_index -------------------------------  (0.1ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.579604"], ["updated_at", "2016-05-10 19:43:46.579604"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.581421"], ["updated_at", "2016-05-10 19:43:46.581421"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.582492"], ["updated_at", "2016-05-10 19:43:46.582492"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.583457"], ["updated_at", "2016-05-10 19:43:46.583457"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.584391"], ["updated_at", "2016-05-10 19:43:46.584391"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Rendered books/index.html.erb within layouts/application (0.0ms) Completed 200 OK in 2ms (Views: 1.0ms | ActiveRecord: 0.1ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.0ms) begin transaction ---------------------------------------------------- BooksControllerTest: test_index_with_multiple_params ----------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.588973"], ["updated_at", "2016-05-10 19:43:46.588973"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.590036"], ["updated_at", "2016-05-10 19:43:46.590036"]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.591327"], ["updated_at", "2016-05-10 19:43:46.591327"]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.592890"], ["updated_at", "2016-05-10 19:43:46.592890"]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.594461"], ["updated_at", "2016-05-10 19:43:46.594461"]]  (0.1ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Rendered books/index.html.erb within layouts/application (0.1ms) Completed 200 OK in 3ms (Views: 1.7ms | ActiveRecord: 0.1ms)  (0.2ms) rollback transaction  (0.1ms) begin transaction ------------------------------ BooksControllerTest: test_show ------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.601269"], ["updated_at", "2016-05-10 19:43:46.601269"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.603089"], ["updated_at", "2016-05-10 19:43:46.603089"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.604018"], ["updated_at", "2016-05-10 19:43:46.604018"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.604790"], ["updated_at", "2016-05-10 19:43:46.604790"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:43:46.605614"], ["updated_at", "2016-05-10 19:43:46.605614"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#show as HTML Parameters: {"id"=>"1"} Book Load (0.0ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]] Rendered books/show.html.erb within layouts/application (0.0ms) Completed 200 OK in 1ms (Views: 0.8ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:43:46.611138"], ["updated_at", "2016-05-10 19:43:46.611138"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:43:46.613292"], ["updated_at", "2016-05-10 19:43:46.613292"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:43:46.614871"], ["updated_at", "2016-05-10 19:43:46.614871"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:43:46.616757"], ["updated_at", "2016-05-10 19:43:46.616757"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.1ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction Connecting to database specified by database.yml Connecting to database specified by database.yml Connecting to database specified by database.yml Connecting to database specified by database.yml ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations"  (2.3ms) CREATE TABLE "books" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" text, "created_at" datetime, "updated_at" datetime, "service_id" varchar)   (4.8ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  (0.1ms) select sqlite_version(*)  (1.6ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version")  (0.1ms) SELECT version FROM "schema_migrations"  (1.1ms) INSERT INTO "schema_migrations" (version) VALUES ('20150312044151')  (1.7ms) INSERT INTO "schema_migrations" (version) VALUES ('20140407202136') ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations"  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -------------------------------- BooksControllerTest: test_create --------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.3ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.161892"], ["updated_at", "2016-05-10 19:56:10.161892"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.164424"], ["updated_at", "2016-05-10 19:56:10.164424"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.165392"], ["updated_at", "2016-05-10 19:56:10.165392"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.166327"], ["updated_at", "2016-05-10 19:56:10.166327"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.167310"], ["updated_at", "2016-05-10 19:56:10.167310"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) SELECT COUNT(*) FROM "books" Processing by BooksController#create as HTML Parameters: {"book"=>{"name"=>"newly-created-book"}}  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "created_at", "updated_at") VALUES (?, ?, ?) [["name", "newly-created-book"], ["created_at", "2016-05-10 19:56:10.171367"], ["updated_at", "2016-05-10 19:56:10.171367"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://test.host/books Completed 302 Found in 2ms (ActiveRecord: 0.2ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.1ms) begin transaction ------------------------------- BooksControllerTest: test_index -------------------------------  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.175642"], ["updated_at", "2016-05-10 19:56:10.175642"]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.177025"], ["updated_at", "2016-05-10 19:56:10.177025"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.178015"], ["updated_at", "2016-05-10 19:56:10.178015"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.178904"], ["updated_at", "2016-05-10 19:56:10.178904"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.179802"], ["updated_at", "2016-05-10 19:56:10.179802"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Rendered books/index.html.erb within layouts/application (0.7ms) Completed 200 OK in 228ms (Views: 227.0ms | ActiveRecord: 0.1ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.1ms) begin transaction ---------------------------------------------------- BooksControllerTest: test_index_with_multiple_params ----------------------------------------------------  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.410979"], ["updated_at", "2016-05-10 19:56:10.410979"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.412294"], ["updated_at", "2016-05-10 19:56:10.412294"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.413334"], ["updated_at", "2016-05-10 19:56:10.413334"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.414440"], ["updated_at", "2016-05-10 19:56:10.414440"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.415323"], ["updated_at", "2016-05-10 19:56:10.415323"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Rendered books/index.html.erb within layouts/application (0.1ms) Completed 200 OK in 2ms (Views: 1.0ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction ------------------------------ BooksControllerTest: test_show ------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.419694"], ["updated_at", "2016-05-10 19:56:10.419694"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.420667"], ["updated_at", "2016-05-10 19:56:10.420667"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.421619"], ["updated_at", "2016-05-10 19:56:10.421619"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.422482"], ["updated_at", "2016-05-10 19:56:10.422482"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("name", "service_id", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["created_at", "2016-05-10 19:56:10.423325"], ["updated_at", "2016-05-10 19:56:10.423325"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#show as HTML Parameters: {"id"=>"1"} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]] Rendered books/show.html.erb within layouts/application (0.3ms) Completed 200 OK in 6ms (Views: 1.5ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.1ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction ----------------------------------------------------------------------- FastlyHeadersTest: test_/books/:id_show_page_should_have_fastly_headers -----------------------------------------------------------------------  (0.1ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:56:10.442010"], ["updated_at", "2016-05-10 19:56:10.442010"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started GET "/books/1" for 127.0.0.1 at 2016-05-10 19:56:10 +0000 Processing by BooksController#show as HTML Parameters: {"id"=>"1"} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]] Rendered books/show.html.erb within layouts/application (0.1ms) Completed 200 OK in 2ms (Views: 1.0ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction -------------------------------------------------------------------- FastlyHeadersTest: test_/books_index_page_should_have_fastly_headers -------------------------------------------------------------------- Started GET "/books" for 127.0.0.1 at 2016-05-10 19:56:10 +0000 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Rendered books/index.html.erb within layouts/application (0.0ms) Completed 200 OK in 2ms (Views: 0.9ms | ActiveRecord: 0.1ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction ---------------------------------------------------------------------------------------------- FastlyHeadersTest: test_DELETE_/books/:id_should_not_have_fastly_headers/_fastly_header_values ----------------------------------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:56:10.458900"], ["updated_at", "2016-05-10 19:56:10.458900"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started DELETE "/books/1" for 127.0.0.1 at 2016-05-10 19:56:10 +0000 Processing by BooksController#destroy as HTML Parameters: {"id"=>"1"} Book Load (0.0ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) DELETE FROM "books" WHERE "books"."id" = ? [["id", 1]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books Completed 302 Found in 1ms (ActiveRecord: 0.2ms)  (0.1ms) SELECT COUNT(*) FROM "books" WHERE "books"."id" = ? [["id", 1]]  (0.1ms) rollback transaction  (0.0ms) begin transaction ---------------------------------------------------------------------------------------- FastlyHeadersTest: test_POST_/books_should_not_have_fastly_headers/_fastly_header_values ----------------------------------------------------------------------------------------  (0.1ms) SELECT COUNT(*) FROM "books" Started POST "/books" for 127.0.0.1 at 2016-05-10 19:56:10 +0000 Processing by BooksController#create as HTML Parameters: {"book"=>{"name"=>"some new book"}}  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "created_at", "updated_at") VALUES (?, ?, ?) [["name", "some new book"], ["created_at", "2016-05-10 19:56:10.470275"], ["updated_at", "2016-05-10 19:56:10.470275"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books Completed 302 Found in 2ms (ActiveRecord: 0.2ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.0ms) begin transaction ------------------------------------------------------------------------------------------- FastlyHeadersTest: test_PUT_/books/:id_should_not_have_fastly_headers/_fastly_header_values -------------------------------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some new book"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:56:10.473360"], ["updated_at", "2016-05-10 19:56:10.473360"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started PUT "/books/1" for 127.0.0.1 at 2016-05-10 19:56:10 +0000 Processing by BooksController#update as HTML Parameters: {"id"=>"1", "book"=>{"name"=>"changed book"}} Book Load (0.0ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.1ms) SAVEPOINT active_record_1 SQL (0.2ms) UPDATE "books" SET "name" = ?, "updated_at" = ? WHERE "books"."id" = ? [["name", "changed book"], ["updated_at", "2016-05-10 19:56:10.477946"], ["id", 1]]  (0.1ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books/1 Completed 302 Found in 3ms (ActiveRecord: 0.4ms) Book Load (0.0ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.3ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.1ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:56:10.488584"], ["updated_at", "2016-05-10 19:56:10.488584"]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:56:10.490645"], ["updated_at", "2016-05-10 19:56:10.490645"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:56:10.493598"], ["updated_at", "2016-05-10 19:56:10.493598"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction ------------------------------------------------------------------------------------------------- FastlyRails::CacheControlHeadersTest: test_sets_cache_control_headers_on_actioncontroller_request -------------------------------------------------------------------------------------------------  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:56:10.503453"], ["updated_at", "2016-05-10 19:56:10.503453"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:56:10.505248"], ["updated_at", "2016-05-10 19:56:10.505248"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:56:10.507528"], ["updated_at", "2016-05-10 19:56:10.507528"]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("name", "service_id", "id", "created_at", "updated_at") VALUES (?, ?, ?, ?, ?) [["name", "some book name"], ["service_id", "asdf"], ["id", 1], ["created_at", "2016-05-10 19:56:10.509252"], ["updated_at", "2016-05-10 19:56:10.509252"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction Connecting to database specified by database.yml Connecting to database specified by database.yml ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations"  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -------------------------------- BooksControllerTest: test_create --------------------------------  (0.1ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.064604"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.064604"]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.067211"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.067211"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.068112"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.068112"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.068882"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.068882"]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.069697"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.069697"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SELECT COUNT(*) FROM "books" Processing by BooksController#create as HTML Parameters: {"book"=>{"name"=>"newly-created-book"}}  (0.2ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "updated_at") VALUES (?, ?, ?) [["created_at", "2016-05-10 20:03:47.074292"], ["name", "newly-created-book"], ["updated_at", "2016-05-10 20:03:47.074292"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://test.host/books Completed 302 Found in 3ms (ActiveRecord: 0.3ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.3ms) begin transaction ------------------------------- BooksControllerTest: test_index -------------------------------  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.078630"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.078630"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.079590"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.079590"]]  (5.3ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.085748"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.085748"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.086504"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.086504"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.087207"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.087207"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Completed 200 OK in 171ms (Views: 170.6ms | ActiveRecord: 0.1ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.0ms) begin transaction ---------------------------------------------------- BooksControllerTest: test_index_with_multiple_params ----------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.261884"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.261884"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.262992"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.262992"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.263893"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.263893"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.264712"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.264712"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.265543"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.265543"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Completed 200 OK in 1ms (Views: 0.9ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction ------------------------------ BooksControllerTest: test_show ------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.269538"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.269538"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.270392"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.270392"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.271169"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.271169"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.271890"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.271890"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.272596"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.272596"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#show as HTML Parameters: {"id"=>"1"} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]] Completed 200 OK in 3ms (Views: 1.3ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction ----------------------------------------------------------------------- FastlyHeadersTest: test_/books/:id_show_page_should_have_fastly_headers -----------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.278675"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.278675"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started GET "/books/1" for 127.0.0.1 at 2016-05-10 20:03:47 +0000 Processing by BooksController#show as HTML Parameters: {"id"=>"1"} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]] Completed 200 OK in 2ms (Views: 1.0ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction -------------------------------------------------------------------- FastlyHeadersTest: test_/books_index_page_should_have_fastly_headers -------------------------------------------------------------------- Started GET "/books" for 127.0.0.1 at 2016-05-10 20:03:47 +0000 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Completed 200 OK in 1ms (Views: 0.7ms | ActiveRecord: 0.1ms)  (0.0ms) rollback transaction  (0.0ms) begin transaction ---------------------------------------------------------------------------------------------- FastlyHeadersTest: test_DELETE_/books/:id_should_not_have_fastly_headers/_fastly_header_values ----------------------------------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.289953"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.289953"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started DELETE "/books/1" for 127.0.0.1 at 2016-05-10 20:03:47 +0000 Processing by BooksController#destroy as HTML Parameters: {"id"=>"1"} Book Load (0.0ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) DELETE FROM "books" WHERE "books"."id" = ? [["id", 1]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books Completed 302 Found in 1ms (ActiveRecord: 0.2ms)  (0.1ms) SELECT COUNT(*) FROM "books" WHERE "books"."id" = 1  (0.2ms) rollback transaction  (0.0ms) begin transaction ---------------------------------------------------------------------------------------- FastlyHeadersTest: test_POST_/books_should_not_have_fastly_headers/_fastly_header_values ----------------------------------------------------------------------------------------  (0.1ms) SELECT COUNT(*) FROM "books" Started POST "/books" for 127.0.0.1 at 2016-05-10 20:03:47 +0000 Processing by BooksController#create as HTML Parameters: {"book"=>{"name"=>"some new book"}}  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "updated_at") VALUES (?, ?, ?) [["created_at", "2016-05-10 20:03:47.298104"], ["name", "some new book"], ["updated_at", "2016-05-10 20:03:47.298104"]]  (0.1ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books Completed 302 Found in 1ms (ActiveRecord: 0.2ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.0ms) begin transaction ------------------------------------------------------------------------------------------- FastlyHeadersTest: test_PUT_/books/:id_should_not_have_fastly_headers/_fastly_header_values -------------------------------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.301191"], ["id", 1], ["name", "some new book"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.301191"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started PUT "/books/1" for 127.0.0.1 at 2016-05-10 20:03:47 +0000 Processing by BooksController#update as HTML Parameters: {"id"=>"1", "book"=>{"name"=>"changed book"}} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) UPDATE "books" SET "name" = ?, "updated_at" = ? WHERE "books"."id" = 1 [["name", "changed book"], ["updated_at", "2016-05-10 20:03:47.304498"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books/1 Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Book Load (0.0ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.2ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.327820"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.327820"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.330055"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.330055"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.331663"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.331663"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.333320"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.333320"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.336118"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.336118"]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.338486"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.338486"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:03:47.339951"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:03:47.339951"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.2ms) begin transaction ------------------------------------------------------------------------------------------------- FastlyRails::CacheControlHeadersTest: test_sets_cache_control_headers_on_actioncontroller_request -------------------------------------------------------------------------------------------------  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction Connecting to database specified by database.yml Connecting to database specified by database.yml  (0.0ms) SELECT "schema_migrations"."version" FROM "schema_migrations"  Migrating to CreateBooks (20140407202136) Migrating to AddServiceIdToBooks (20150312044151)  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (2.9ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.3ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SELECT COUNT(*) FROM "books"  Processing by BooksController#create as HTML Parameters: {"book"=>{"name"=>"newly-created-book"}}  (0.1ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "newly-created-book"], ["service_id", nil], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://test.host/books Completed 302 Found in 3.1ms (ActiveRecord: 0.3ms)  (0.0ms) SELECT COUNT(*) FROM "books"   (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books"  Completed 200 OK in 7.7ms (Views: 6.9ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books"  Completed 200 OK in 1.4ms (Views: 0.8ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:05:24 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:05:24 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#show as HTML Parameters: {"id"=>"1"} Book Load (0.2ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", "1"]] Completed 200 OK in 4.3ms (Views: 1.6ms | ActiveRecord: 0.2ms)  (0.2ms) 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.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction Connecting to database specified by database.yml Connecting to database specified by database.yml  (0.0ms) SELECT "schema_migrations"."version" FROM "schema_migrations"  Migrating to CreateBooks (20140407202136) Migrating to AddServiceIdToBooks (20150312044151)  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (2.0ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.1ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) SELECT COUNT(*) FROM "books"  Processing by BooksController#create as HTML Parameters: {"book"=>{"name"=>"newly-created-book"}}  (0.1ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "newly-created-book"], ["service_id", nil], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://test.host/books Completed 302 Found in 1.6ms (ActiveRecord: 0.2ms)  (0.0ms) SELECT COUNT(*) FROM "books"   (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.4ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.1ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books"  Completed 200 OK in 5.4ms (Views: 4.5ms | ActiveRecord: 0.1ms)  (0.2ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books"  Completed 200 OK in 1.1ms (Views: 0.6ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", Tue, 10 May 2016 20:08:43 UTC +00:00], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", Tue, 10 May 2016 20:08:43 UTC +00:00]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#show as HTML Parameters: {"id"=>"1"} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", "1"]] Completed 200 OK in 2.3ms (Views: 0.9ms | ActiveRecord: 0.1ms)  (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.1ms) rollback transaction  (0.0ms) begin transaction  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations"  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.3ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.494285"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.494285"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.497536"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.497536"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.499208"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.499208"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.500776"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.500776"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.506828"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.506828"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.508432"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.508432"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.510057"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.510057"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction ----------------------------------------------------------------------- FastlyHeadersTest: test_/books/:id_show_page_should_have_fastly_headers -----------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.520011"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.520011"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started GET "/books/1" for 127.0.0.1 at 2016-05-10 20:09:03 +0000 Processing by BooksController#show as HTML Parameters: {"id"=>"1"} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]] Rendered books/show.html.erb within layouts/application (1.2ms) Completed 200 OK in 139ms (Views: 137.2ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction -------------------------------------------------------------------- FastlyHeadersTest: test_/books_index_page_should_have_fastly_headers -------------------------------------------------------------------- Started GET "/books" for 127.0.0.1 at 2016-05-10 20:09:03 +0000 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Completed 200 OK in 2ms (Views: 1.4ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction ---------------------------------------------------------------------------------------------- FastlyHeadersTest: test_DELETE_/books/:id_should_not_have_fastly_headers/_fastly_header_values ----------------------------------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.703417"], ["id", 1], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.703417"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started DELETE "/books/1" for 127.0.0.1 at 2016-05-10 20:09:03 +0000 Processing by BooksController#destroy as HTML Parameters: {"id"=>"1"} Book Load (0.0ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) DELETE FROM "books" WHERE "books"."id" = ? [["id", 1]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books Completed 302 Found in 2ms (ActiveRecord: 0.3ms)  (0.1ms) SELECT COUNT(*) FROM "books" WHERE "books"."id" = 1  (0.1ms) rollback transaction  (0.0ms) begin transaction ---------------------------------------------------------------------------------------- FastlyHeadersTest: test_POST_/books_should_not_have_fastly_headers/_fastly_header_values ----------------------------------------------------------------------------------------  (0.1ms) SELECT COUNT(*) FROM "books" Started POST "/books" for 127.0.0.1 at 2016-05-10 20:09:03 +0000 Processing by BooksController#create as HTML Parameters: {"book"=>{"name"=>"some new book"}}  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "updated_at") VALUES (?, ?, ?) [["created_at", "2016-05-10 20:09:03.712601"], ["name", "some new book"], ["updated_at", "2016-05-10 20:09:03.712601"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books Completed 302 Found in 2ms (ActiveRecord: 0.2ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.0ms) begin transaction ------------------------------------------------------------------------------------------- FastlyHeadersTest: test_PUT_/books/:id_should_not_have_fastly_headers/_fastly_header_values -------------------------------------------------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "id", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.715684"], ["id", 1], ["name", "some new book"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.715684"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Started PUT "/books/1" for 127.0.0.1 at 2016-05-10 20:09:03 +0000 Processing by BooksController#update as HTML Parameters: {"id"=>"1", "book"=>{"name"=>"changed book"}} Book Load (0.1ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) UPDATE "books" SET "name" = ?, "updated_at" = ? WHERE "books"."id" = 1 [["name", "changed book"], ["updated_at", "2016-05-10 20:09:03.718692"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://www.example.com/books/1 Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Book Load (0.0ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]]  (0.1ms) rollback transaction  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction ------------------------------------------------------------------------------------------------- FastlyRails::CacheControlHeadersTest: test_sets_cache_control_headers_on_actioncontroller_request -------------------------------------------------------------------------------------------------  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.1ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction -------------------------------- BooksControllerTest: test_create --------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.729849"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.729849"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.730854"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.730854"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.731618"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.731618"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.732398"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.732398"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.733120"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.733120"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.1ms) SELECT COUNT(*) FROM "books" Processing by BooksController#create as HTML Parameters: {"book"=>{"name"=>"newly-created-book"}}  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "updated_at") VALUES (?, ?, ?) [["created_at", "2016-05-10 20:09:03.736395"], ["name", "newly-created-book"], ["updated_at", "2016-05-10 20:09:03.736395"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Redirected to http://test.host/books Completed 302 Found in 1ms (ActiveRecord: 0.2ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.1ms) begin transaction ------------------------------- BooksControllerTest: test_index -------------------------------  (0.1ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.739647"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.739647"]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.2ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.741016"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.741016"]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.742303"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.742303"]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.743939"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.743939"]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.1ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.745631"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.745631"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Completed 200 OK in 2ms (Views: 1.2ms | ActiveRecord: 0.1ms)  (0.1ms) SELECT COUNT(*) FROM "books"  (0.1ms) rollback transaction  (0.0ms) begin transaction ---------------------------------------------------- BooksControllerTest: test_index_with_multiple_params ----------------------------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.750431"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.750431"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.751308"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.751308"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.752105"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.752105"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.752832"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.752832"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.753607"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.753607"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#index as HTML Book Load (0.1ms) SELECT "books".* FROM "books" Completed 200 OK in 1ms (Views: 0.8ms | ActiveRecord: 0.1ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction ------------------------------ BooksControllerTest: test_show ------------------------------  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.757319"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.757319"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.758188"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.758188"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.758984"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.758984"]]  (0.1ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.0ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.759769"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.759769"]]  (0.0ms) RELEASE SAVEPOINT active_record_1  (0.0ms) SAVEPOINT active_record_1 SQL (0.1ms) INSERT INTO "books" ("created_at", "name", "service_id", "updated_at") VALUES (?, ?, ?, ?) [["created_at", "2016-05-10 20:09:03.760514"], ["name", "some book name"], ["service_id", "asdf"], ["updated_at", "2016-05-10 20:09:03.760514"]]  (0.0ms) RELEASE SAVEPOINT active_record_1 Processing by BooksController#show as HTML Parameters: {"id"=>"1"} Book Load (0.0ms) SELECT "books".* FROM "books" WHERE "books"."id" = ? LIMIT 1 [["id", 1]] Completed 200 OK in 1ms (Views: 0.9ms | ActiveRecord: 0.0ms)  (0.1ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) rollback transaction