# Logfile created on 2016-08-10 12:35:43 +0300 by logger.rb/54362
D, [2016-08-10T12:35:43.750680 #4206] DEBUG -- :    (0.3ms)  CREATE TABLE "books" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "title" varchar)
D, [2016-08-10T12:35:43.755259 #4206] DEBUG -- :    (0.1ms)  CREATE TABLE "delayed_jobs" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "priority" integer DEFAULT 0 NOT NULL, "attempts" integer DEFAULT 0 NOT NULL, "handler" text NOT NULL, "last_error" text, "run_at" datetime, "locked_at" datetime, "failed_at" datetime, "locked_by" varchar, "queue" varchar, "created_at" datetime, "updated_at" datetime)
D, [2016-08-10T12:35:43.755483 #4206] DEBUG -- :    (0.0ms)  select sqlite_version(*)
D, [2016-08-10T12:35:43.755779 #4206] DEBUG -- :    (0.1ms)  CREATE  INDEX "delayed_jobs_priority" ON "delayed_jobs" ("priority", "run_at")
D, [2016-08-10T12:35:43.757049 #4206] DEBUG -- :    (0.1ms)  CREATE TABLE "ar_internal_metadata" ("key" varchar NOT NULL PRIMARY KEY, "value" varchar, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
D, [2016-08-10T12:35:43.765141 #4206] DEBUG -- :   ActiveRecord::InternalMetadata Load (0.1ms)  SELECT  "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = ? LIMIT ?  [["key", :environment], ["LIMIT", 1]]
D, [2016-08-10T12:35:43.768353 #4206] DEBUG -- :    (0.0ms)  begin transaction
D, [2016-08-10T12:35:43.769278 #4206] DEBUG -- :   SQL (0.1ms)  INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES (?, ?, ?, ?)  [["key", "environment"], ["value", "test"], ["created_at", 2016-08-10 09:35:43 UTC], ["updated_at", 2016-08-10 09:35:43 UTC]]
D, [2016-08-10T12:35:43.769417 #4206] DEBUG -- :    (0.0ms)  commit transaction
I, [2016-08-10T12:35:43.803154 #4206]  INFO -- : Started GET "/active_job" for 127.0.0.1 at 2016-08-10 12:35:43 +0300
I, [2016-08-10T12:35:43.805881 #4206]  INFO -- : Processing by DummyController#active_job as HTML
I, [2016-08-10T12:35:43.810363 #4206]  INFO -- :   Rendering dummy/active_job.html.erb within layouts/application
I, [2016-08-10T12:35:43.811179 #4206]  INFO -- :   Rendered dummy/active_job.html.erb within layouts/application (0.7ms)
I, [2016-08-10T12:35:43.811610 #4206]  INFO -- : Completed 200 OK in 6ms (Views: 3.5ms | ActiveRecord: 0.0ms)
D, [2016-08-10T12:36:47.718343 #4349] DEBUG -- :    (0.3ms)  CREATE TABLE "books" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "title" varchar)
D, [2016-08-10T12:36:47.722896 #4349] DEBUG -- :    (0.1ms)  CREATE TABLE "delayed_jobs" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "priority" integer DEFAULT 0 NOT NULL, "attempts" integer DEFAULT 0 NOT NULL, "handler" text NOT NULL, "last_error" text, "run_at" datetime, "locked_at" datetime, "failed_at" datetime, "locked_by" varchar, "queue" varchar, "created_at" datetime, "updated_at" datetime)
D, [2016-08-10T12:36:47.723114 #4349] DEBUG -- :    (0.0ms)  select sqlite_version(*)
D, [2016-08-10T12:36:47.723394 #4349] DEBUG -- :    (0.1ms)  CREATE  INDEX "delayed_jobs_priority" ON "delayed_jobs" ("priority", "run_at")
D, [2016-08-10T12:36:47.724704 #4349] DEBUG -- :    (0.1ms)  CREATE TABLE "ar_internal_metadata" ("key" varchar NOT NULL PRIMARY KEY, "value" varchar, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
D, [2016-08-10T12:36:47.732833 #4349] DEBUG -- :   ActiveRecord::InternalMetadata Load (0.1ms)  SELECT  "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = ? LIMIT ?  [["key", :environment], ["LIMIT", 1]]
D, [2016-08-10T12:36:47.736285 #4349] DEBUG -- :    (0.0ms)  begin transaction
D, [2016-08-10T12:36:47.737196 #4349] DEBUG -- :   SQL (0.1ms)  INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES (?, ?, ?, ?)  [["key", "environment"], ["value", "test"], ["created_at", 2016-08-10 09:36:47 UTC], ["updated_at", 2016-08-10 09:36:47 UTC]]
D, [2016-08-10T12:36:47.737354 #4349] DEBUG -- :    (0.0ms)  commit transaction
I, [2016-08-10T12:37:08.109580 #4349]  INFO -- : Started GET "/active_job" for 127.0.0.1 at 2016-08-10 12:37:08 +0300
I, [2016-08-10T12:37:08.111992 #4349]  INFO -- : Processing by DummyController#active_job as HTML
I, [2016-08-10T12:37:08.118060 #4349]  INFO -- :   Rendering dummy/active_job.html.erb within layouts/application
I, [2016-08-10T12:37:08.119176 #4349]  INFO -- :   Rendered dummy/active_job.html.erb within layouts/application (1.0ms)
I, [2016-08-10T12:37:08.119926 #4349]  INFO -- : Completed 200 OK in 8ms (Views: 5.1ms | ActiveRecord: 0.0ms)
I, [2016-08-10T12:37:40.825870 #4349]  INFO -- : Started GET "/active_job" for 127.0.0.1 at 2016-08-10 12:37:40 +0300
I, [2016-08-10T12:37:40.826565 #4349]  INFO -- : Processing by DummyController#active_job as HTML
I, [2016-08-10T12:37:40.828584 #4349]  INFO -- :   Rendering dummy/active_job.html.erb within layouts/application
I, [2016-08-10T12:37:40.828873 #4349]  INFO -- :   Rendered dummy/active_job.html.erb within layouts/application (0.2ms)
I, [2016-08-10T12:37:40.829435 #4349]  INFO -- : Completed 200 OK in 3ms (Views: 1.2ms | ActiveRecord: 0.0ms)
D, [2016-08-10T12:42:59.286655 #5238] DEBUG -- :    (0.3ms)  CREATE TABLE "books" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "title" varchar)
D, [2016-08-10T12:42:59.291184 #5238] DEBUG -- :    (0.1ms)  CREATE TABLE "delayed_jobs" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "priority" integer DEFAULT 0 NOT NULL, "attempts" integer DEFAULT 0 NOT NULL, "handler" text NOT NULL, "last_error" text, "run_at" datetime, "locked_at" datetime, "failed_at" datetime, "locked_by" varchar, "queue" varchar, "created_at" datetime, "updated_at" datetime)
D, [2016-08-10T12:42:59.291391 #5238] DEBUG -- :    (0.0ms)  select sqlite_version(*)
D, [2016-08-10T12:42:59.291706 #5238] DEBUG -- :    (0.1ms)  CREATE  INDEX "delayed_jobs_priority" ON "delayed_jobs" ("priority", "run_at")
D, [2016-08-10T12:42:59.292994 #5238] DEBUG -- :    (0.1ms)  CREATE TABLE "ar_internal_metadata" ("key" varchar NOT NULL PRIMARY KEY, "value" varchar, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
D, [2016-08-10T12:42:59.302093 #5238] DEBUG -- :   ActiveRecord::InternalMetadata Load (0.1ms)  SELECT  "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = ? LIMIT ?  [["key", :environment], ["LIMIT", 1]]
D, [2016-08-10T12:42:59.305323 #5238] DEBUG -- :    (0.0ms)  begin transaction
D, [2016-08-10T12:42:59.306367 #5238] DEBUG -- :   SQL (0.1ms)  INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES (?, ?, ?, ?)  [["key", "environment"], ["value", "test"], ["created_at", 2016-08-10 09:42:59 UTC], ["updated_at", 2016-08-10 09:42:59 UTC]]
D, [2016-08-10T12:42:59.306580 #5238] DEBUG -- :    (0.1ms)  commit transaction
I, [2016-08-10T12:42:59.338781 #5238]  INFO -- : Started GET "/active_job" for 127.0.0.1 at 2016-08-10 12:42:59 +0300
I, [2016-08-10T12:42:59.340618 #5238]  INFO -- : Processing by DummyController#active_job as HTML
I, [2016-08-10T12:42:59.345004 #5238]  INFO -- :   Rendering dummy/active_job.html.erb within layouts/application
I, [2016-08-10T12:42:59.345774 #5238]  INFO -- :   Rendered dummy/active_job.html.erb within layouts/application (0.7ms)
I, [2016-08-10T12:42:59.346120 #5238]  INFO -- : Completed 200 OK in 5ms (Views: 3.3ms | ActiveRecord: 0.0ms)
D, [2016-08-10T12:52:02.755195 #6062] DEBUG -- :    (0.3ms)  CREATE TABLE "books" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "title" varchar)
D, [2016-08-10T12:52:02.759774 #6062] DEBUG -- :    (0.1ms)  CREATE TABLE "delayed_jobs" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "priority" integer DEFAULT 0 NOT NULL, "attempts" integer DEFAULT 0 NOT NULL, "handler" text NOT NULL, "last_error" text, "run_at" datetime, "locked_at" datetime, "failed_at" datetime, "locked_by" varchar, "queue" varchar, "created_at" datetime, "updated_at" datetime)
D, [2016-08-10T12:52:02.759952 #6062] DEBUG -- :    (0.0ms)  select sqlite_version(*)
D, [2016-08-10T12:52:02.760267 #6062] DEBUG -- :    (0.1ms)  CREATE  INDEX "delayed_jobs_priority" ON "delayed_jobs" ("priority", "run_at")
D, [2016-08-10T12:52:02.761559 #6062] DEBUG -- :    (0.1ms)  CREATE TABLE "ar_internal_metadata" ("key" varchar NOT NULL PRIMARY KEY, "value" varchar, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL)
D, [2016-08-10T12:52:02.769129 #6062] DEBUG -- :   ActiveRecord::InternalMetadata Load (0.1ms)  SELECT  "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = ? LIMIT ?  [["key", :environment], ["LIMIT", 1]]
D, [2016-08-10T12:52:02.772322 #6062] DEBUG -- :    (0.1ms)  begin transaction
D, [2016-08-10T12:52:02.773153 #6062] DEBUG -- :   SQL (0.1ms)  INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES (?, ?, ?, ?)  [["key", "environment"], ["value", "test"], ["created_at", 2016-08-10 09:52:02 UTC], ["updated_at", 2016-08-10 09:52:02 UTC]]
D, [2016-08-10T12:52:02.773279 #6062] DEBUG -- :    (0.0ms)  commit transaction
I, [2016-08-10T12:52:02.802749 #6062]  INFO -- : Started GET "/active_job" for 127.0.0.1 at 2016-08-10 12:52:02 +0300
I, [2016-08-10T12:52:02.805089 #6062]  INFO -- : Processing by DummyController#active_job as HTML
I, [2016-08-10T12:52:02.810308 #6062]  INFO -- :   Rendering dummy/active_job.html.erb within layouts/application
I, [2016-08-10T12:52:02.811215 #6062]  INFO -- :   Rendered dummy/active_job.html.erb within layouts/application (0.8ms)
I, [2016-08-10T12:52:02.811620 #6062]  INFO -- : Completed 200 OK in 6ms (Views: 4.0ms | ActiveRecord: 0.0ms)