test/dummy/log/development.log in oauth_service-0.0.1 vs test/dummy/log/development.log in oauth_service-0.0.2

- old
+ new

@@ -17798,5 +17798,1360 @@ Parameters: {"code"=>"4/q01WuQIzdfWobwzkuYYzPzduTslK35drcTLJUM2UCj4", "provider_name"=>"google"} User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."name" = ? LIMIT 1 [["name", "guest"]] SQL (0.3ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."users_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "users_groups"."id" AS t2_r0, "users_groups"."user_group_id" AS t2_r1, "users_groups"."user_id" AS t2_r2, "users"."id" AS t3_r0, "users"."name" AS t3_r1, "users"."api_code" AS t3_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "users_groups" ON "users_groups"."id" = "users_urls"."users_group_id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 1 User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."name" = ? LIMIT 1 [["name", "y.barkovskij@unact.ru"]] Completed 404 Not Found in 554ms (Views: 0.2ms | ActiveRecord: 0.6ms) + + +Started GET "/login" for 127.0.0.1 at 2016-05-15 00:59:08 +0300 + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" +Processing by LoginController#index as HTML + User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."name" = ? LIMIT 1 [["name", "guest"]] + SQL (0.2ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."users_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "users_groups"."id" AS t2_r0, "users_groups"."user_group_id" AS t2_r1, "users_groups"."user_id" AS t2_r2, "users"."id" AS t3_r0, "users"."name" AS t3_r1, "users"."api_code" AS t3_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "users_groups" ON "users_groups"."id" = "users_urls"."users_group_id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 1 + Rendered login/index.html.erb within layouts/application (2.2ms) +Completed 200 OK in 176ms (Views: 140.1ms | ActiveRecord: 1.1ms) + + +Started GET "/assets/application.self-e80e8f2318043e8af94dddc2adad5a4f09739a8ebb323b3ab31cd71d45fd9113.css?body=1" for 127.0.0.1 at 2016-05-15 00:59:08 +0300 + + +Started GET "/assets/application.self-8f06a73c35179188914ab50e057157639fce1401c1cdca640ac9cec33746fc5b.js?body=1" for 127.0.0.1 at 2016-05-15 00:59:08 +0300 + + +Started GET "/" for 127.0.0.1 at 2016-05-15 01:14:05 +0300 + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" +Processing by Rails::WelcomeController#index as HTML + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/railties-4.2.6/lib/rails/templates/rails/welcome/index.html.erb (0.9ms) +Completed 200 OK in 5ms (Views: 4.8ms | ActiveRecord: 0.0ms) + + +Started GET "/login" for 127.0.0.1 at 2016-05-15 01:14:09 +0300 +Processing by LoginController#index as HTML + User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."name" = ? LIMIT 1 [["name", "guest"]] + SQL (0.2ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."users_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "users_groups"."id" AS t2_r0, "users_groups"."user_group_id" AS t2_r1, "users_groups"."user_id" AS t2_r2, "users"."id" AS t3_r0, "users"."name" AS t3_r1, "users"."api_code" AS t3_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "users_groups" ON "users_groups"."id" = "users_urls"."users_group_id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 1 + Rendered login/index.html.erb within layouts/application (1.8ms) +Completed 200 OK in 174ms (Views: 131.2ms | ActiveRecord: 1.1ms) + + +Started GET "/login" for 127.0.0.1 at 2016-05-15 01:14:09 +0300 +Processing by LoginController#index as HTML + User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."name" = ? LIMIT 1 [["name", "guest"]] + SQL (0.2ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."users_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "users_groups"."id" AS t2_r0, "users_groups"."user_group_id" AS t2_r1, "users_groups"."user_id" AS t2_r2, "users"."id" AS t3_r0, "users"."name" AS t3_r1, "users"."api_code" AS t3_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "users_groups" ON "users_groups"."id" = "users_urls"."users_group_id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 1 + Rendered login/index.html.erb within layouts/application (0.6ms) +Completed 200 OK in 17ms (Views: 13.2ms | ActiveRecord: 0.3ms) + + +Started GET "/oauth/yandex?code=4015634" for 127.0.0.1 at 2016-05-15 01:14:11 +0300 +Processing by LoginController#oauth_callback as HTML + Parameters: {"code"=>"4015634", "provider_name"=>"yandex"} + User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."name" = ? LIMIT 1 [["name", "guest"]] + SQL (0.4ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."users_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "users_groups"."id" AS t2_r0, "users_groups"."user_group_id" AS t2_r1, "users_groups"."user_id" AS t2_r2, "users"."id" AS t3_r0, "users"."name" AS t3_r1, "users"."api_code" AS t3_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "users_groups" ON "users_groups"."id" = "users_urls"."users_group_id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 1 + User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."name" = ? LIMIT 1 [["name", "bar555@yandex.ru"]] +Completed 404 Not Found in 222ms (Views: 0.2ms | ActiveRecord: 0.7ms) + + +Started GET "/__identify__" for 127.0.0.1 at 2016-05-15 01:35:42 +0300 + +ActionController::RoutingError (No route matches [GET] "/__identify__"): + actionpack (4.2.6) lib/action_dispatch/middleware/debug_exceptions.rb:21:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/show_exceptions.rb:30:in `call' + railties (4.2.6) lib/rails/rack/logger.rb:38:in `call_app' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `block in call' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `block in tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:26:in `tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `tagged' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/request_id.rb:21:in `call' + rack (1.6.4) lib/rack/methodoverride.rb:22:in `call' + rack (1.6.4) lib/rack/runtime.rb:18:in `call' + activesupport (4.2.6) lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/static.rb:120:in `call' + rack (1.6.4) lib/rack/sendfile.rb:113:in `call' + railties (4.2.6) lib/rails/engine.rb:518:in `call' + railties (4.2.6) lib/rails/application.rb:165:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + rack (1.6.4) lib/rack/content_length.rb:15:in `call' + rack (1.6.4) lib/rack/handler/webrick.rb:88:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:138:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:94:in `run' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/server.rb:294:in `block in start_thread' + + + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_trace.html.erb (1.0ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/routes/_route.html.erb (0.6ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/routes/_table.html.erb (7.2ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_request_and_response.html.erb (0.8ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/routing_error.html.erb within rescues/layout (25.7ms) + + +Started GET "/__identify__" for 127.0.0.1 at 2016-05-15 01:35:42 +0300 + +ActionController::RoutingError (No route matches [GET] "/__identify__"): + actionpack (4.2.6) lib/action_dispatch/middleware/debug_exceptions.rb:21:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/show_exceptions.rb:30:in `call' + railties (4.2.6) lib/rails/rack/logger.rb:38:in `call_app' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `block in call' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `block in tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:26:in `tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `tagged' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/request_id.rb:21:in `call' + rack (1.6.4) lib/rack/methodoverride.rb:22:in `call' + rack (1.6.4) lib/rack/runtime.rb:18:in `call' + activesupport (4.2.6) lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/static.rb:120:in `call' + rack (1.6.4) lib/rack/sendfile.rb:113:in `call' + railties (4.2.6) lib/rails/engine.rb:518:in `call' + railties (4.2.6) lib/rails/application.rb:165:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + rack (1.6.4) lib/rack/content_length.rb:15:in `call' + rack (1.6.4) lib/rack/handler/webrick.rb:88:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:138:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:94:in `run' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/server.rb:294:in `block in start_thread' + + + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_trace.html.erb (1.0ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/routes/_route.html.erb (0.6ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/routes/_table.html.erb (0.9ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_request_and_response.html.erb (0.7ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/routing_error.html.erb within rescues/layout (13.0ms) + User Load (0.4ms) SELECT "users".* FROM "users" + User Load (0.1ms) SELECT "users".* FROM "users" + User Load (0.2ms) SELECT "users".* FROM "users" +  (85.1ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  +  (0.3ms) select sqlite_version(*) +  (97.8ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version") + ActiveRecord::SchemaMigration Load (0.2ms) SELECT "schema_migrations".* FROM "schema_migrations" +Migrating to CreateTables (20160514163909) +  (0.1ms) begin transaction +  (0.8ms) CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar, "api_code" varchar) +  (0.4ms) CREATE INDEX "index_users_on_name" ON "users" ("name") +  (0.4ms) CREATE TABLE "urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "url_pattern" varchar, "name" varchar, "http_method" varchar) +  (0.4ms) CREATE TABLE "user_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)  +  (0.4ms) CREATE INDEX "index_user_groups_on_name" ON "user_groups" ("name") +  (0.4ms) CREATE TABLE "users_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "user_group_id" integer, "user_id" integer)  +  (0.4ms) CREATE TABLE "users_urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "users_group_id" integer, "url_id" integer) + SQL (0.2ms) INSERT INTO "users" ("name", "id") VALUES (?, ?) [["name", "guest"], ["id", 1]] + SQL (0.2ms) INSERT INTO "urls" ("url_pattern", "name", "http_method", "id") VALUES (?, ?, ?, ?) [["url_pattern", "^/login"], ["name", "Login page"], ["http_method", "GET"], ["id", 1]] + SQL (0.1ms) INSERT INTO "urls" ("url_pattern", "name", "http_method", "id") VALUES (?, ?, ?, ?) [["url_pattern", "^/oauth/.*"], ["name", "AuthCallback page"], ["http_method", "GET"], ["id", 2]] + SQL (0.1ms) INSERT INTO "user_groups" ("id", "name") VALUES (?, ?) [["id", 1], ["name", "Guest"]] + SQL (0.1ms) INSERT INTO "users_groups" ("id", "user_id", "user_group_id") VALUES (?, ?, ?) [["id", 1], ["user_id", 1], ["user_group_id", 1]] + SQL (0.1ms) INSERT INTO "users_urls" ("id", "url_id", "users_group_id") VALUES (?, ?, ?) [["id", 1], ["url_id", 1], ["users_group_id", 1]] + SQL (0.0ms) INSERT INTO "users_urls" ("id", "url_id", "users_group_id") VALUES (?, ?, ?) [["id", 2], ["url_id", 2], ["users_group_id", 1]] + SQL (0.1ms) INSERT INTO "schema_migrations" ("version") VALUES (?) [["version", "20160514163909"]] +  (126.1ms) commit transaction + ActiveRecord::SchemaMigration Load (0.3ms) SELECT "schema_migrations".* FROM "schema_migrations" +  (0.4ms)  SELECT sql + FROM sqlite_master + WHERE name='index_user_groups_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_user_groups_on_name' AND type='index' + +  (0.3ms) SELECT sql + FROM sqlite_master + WHERE name='index_users_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_users_on_name' AND type='index' + +  (103.0ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  +  (0.3ms) select sqlite_version(*) +  (97.7ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version") + ActiveRecord::SchemaMigration Load (0.3ms) SELECT "schema_migrations".* FROM "schema_migrations" +Migrating to CreateTables (20160514163909) +  (0.2ms) begin transaction +  (0.9ms) CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar, "api_code" varchar) +  (0.4ms) CREATE INDEX "index_users_on_name" ON "users" ("name") +  (0.5ms) CREATE TABLE "urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "url_pattern" varchar, "name" varchar, "http_method" varchar) +  (0.4ms) CREATE TABLE "user_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)  +  (0.4ms) CREATE INDEX "index_user_groups_on_name" ON "user_groups" ("name") +  (0.4ms) CREATE TABLE "users_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "user_group_id" integer, "user_id" integer)  +  (0.4ms) CREATE TABLE "users_urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "users_group_id" integer, "url_id" integer) + SQL (0.3ms) INSERT INTO "users" ("name", "id") VALUES (?, ?) [["name", "guest"], ["id", 1]] + SQL (0.2ms) INSERT INTO "urls" ("url_pattern", "name", "http_method", "id") VALUES (?, ?, ?, ?) [["url_pattern", "^/login"], ["name", "Login page"], ["http_method", "GET"], ["id", 1]] + SQL (0.1ms) INSERT INTO "urls" ("url_pattern", "name", "http_method", "id") VALUES (?, ?, ?, ?) [["url_pattern", "^/oauth/.*"], ["name", "AuthCallback page"], ["http_method", "GET"], ["id", 2]] + SQL (0.1ms) INSERT INTO "user_groups" ("id", "name") VALUES (?, ?) [["id", 1], ["name", "Guest"]] + SQL (0.1ms) INSERT INTO "users_groups" ("id", "user_id", "user_group_id") VALUES (?, ?, ?) [["id", 1], ["user_id", 1], ["user_group_id", 1]] + SQL (0.1ms) INSERT INTO "users_urls" ("id", "url_id", "users_group_id") VALUES (?, ?, ?) [["id", 1], ["url_id", 1], ["users_group_id", 1]] + SQL (0.1ms) INSERT INTO "users_urls" ("id", "url_id", "users_group_id") VALUES (?, ?, ?) [["id", 2], ["url_id", 2], ["users_group_id", 1]] + SQL (0.1ms) INSERT INTO "schema_migrations" ("version") VALUES (?) [["version", "20160514163909"]] +  (105.7ms) commit transaction + ActiveRecord::SchemaMigration Load (0.2ms) SELECT "schema_migrations".* FROM "schema_migrations" +  (0.2ms)  SELECT sql + FROM sqlite_master + WHERE name='index_user_groups_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_user_groups_on_name' AND type='index' + +  (0.2ms) SELECT sql + FROM sqlite_master + WHERE name='index_users_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_users_on_name' AND type='index' + + SQL (0.5ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."users_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "users_groups"."id" AS t2_r0, "users_groups"."user_group_id" AS t2_r1, "users_groups"."user_id" AS t2_r2, "users"."id" AS t3_r0, "users"."name" AS t3_r1, "users"."api_code" AS t3_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "users_groups" ON "users_groups"."id" = "users_urls"."users_group_id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 2 + SQL (0.9ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."users_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "users_groups"."id" AS t2_r0, "users_groups"."user_group_id" AS t2_r1, "users_groups"."user_id" AS t2_r2, "users"."id" AS t3_r0, "users"."name" AS t3_r1, "users"."api_code" AS t3_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "users_groups" ON "users_groups"."id" = "users_urls"."users_group_id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 1 + Url Load (0.4ms) SELECT "urls".* FROM "urls" +  (0.2ms) begin transaction + SQL (0.6ms) INSERT INTO "users" ("name") VALUES (?) [["name", "bar555@yandex.ru"]] +  (120.0ms) commit transaction +  (0.1ms) begin transaction + SQL (0.4ms) INSERT INTO "user_groups" ("name") VALUES (?) [["name", "Test"]] +  (106.8ms) commit transaction +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "users_groups" ("user_id", "user_group_id") VALUES (?, ?) [["user_id", 2], ["user_group_id", 2]] +  (110.8ms) commit transaction +  (0.1ms) begin transaction + SQL (0.5ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/test"], ["name", "Test page"], ["http_method", "GET"]] +  (106.3ms) commit transaction +  (0.2ms) begin transaction + SQL (0.6ms) INSERT INTO "users_urls" ("url_id") VALUES (?) [["url_id", 3]] +  (280.6ms) commit transaction + SQL (0.8ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."users_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "users_groups"."id" AS t2_r0, "users_groups"."user_group_id" AS t2_r1, "users_groups"."user_id" AS t2_r2, "users"."id" AS t3_r0, "users"."name" AS t3_r1, "users"."api_code" AS t3_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "users_groups" ON "users_groups"."id" = "users_urls"."users_group_id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 2 +  (0.2ms) begin transaction + SQL (0.6ms) INSERT INTO "users_urls" ("url_id", "users_group_id") VALUES (?, ?) [["url_id", 3], ["users_group_id", 2]] +  (120.8ms) commit transaction + SQL (0.9ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."users_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "users_groups"."id" AS t2_r0, "users_groups"."user_group_id" AS t2_r1, "users_groups"."user_id" AS t2_r2, "users"."id" AS t3_r0, "users"."name" AS t3_r1, "users"."api_code" AS t3_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "users_groups" ON "users_groups"."id" = "users_urls"."users_group_id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 2 +  (94.1ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  +  (0.1ms) select sqlite_version(*) +  (74.5ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version") + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" +Migrating to CreateTables (20160514163909) +  (0.1ms) begin transaction +  (0.4ms) CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar, "api_code" varchar) +  (0.3ms) CREATE INDEX "index_users_on_name" ON "users" ("name") +  (0.3ms) CREATE TABLE "urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "url_pattern" varchar, "name" varchar, "http_method" varchar) +  (0.3ms) CREATE TABLE "user_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)  +  (0.2ms) CREATE INDEX "index_user_groups_on_name" ON "user_groups" ("name") +  (0.3ms) CREATE TABLE "users_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "user_group_id" integer, "user_id" integer)  +  (0.4ms) CREATE TABLE "users_urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "users_group_id" integer, "url_id" integer) + SQL (0.2ms) INSERT INTO "users" ("name", "id") VALUES (?, ?) [["name", "guest"], ["id", 1]] + SQL (0.1ms) INSERT INTO "urls" ("url_pattern", "name", "http_method", "id") VALUES (?, ?, ?, ?) [["url_pattern", "^/login"], ["name", "Login page"], ["http_method", "GET"], ["id", 1]] + SQL (0.1ms) INSERT INTO "urls" ("url_pattern", "name", "http_method", "id") VALUES (?, ?, ?, ?) [["url_pattern", "^/oauth/.*"], ["name", "AuthCallback page"], ["http_method", "GET"], ["id", 2]] + SQL (0.1ms) INSERT INTO "user_groups" ("id", "name") VALUES (?, ?) [["id", 1], ["name", "Guest"]] + SQL (0.1ms) INSERT INTO "users_groups" ("id", "user_id", "user_group_id") VALUES (?, ?, ?) [["id", 1], ["user_id", 1], ["user_group_id", 1]] + SQL (0.1ms) INSERT INTO "users_urls" ("id", "url_id", "users_group_id") VALUES (?, ?, ?) [["id", 1], ["url_id", 1], ["users_group_id", 1]] + SQL (0.0ms) INSERT INTO "users_urls" ("id", "url_id", "users_group_id") VALUES (?, ?, ?) [["id", 2], ["url_id", 2], ["users_group_id", 1]] + SQL (0.1ms) INSERT INTO "schema_migrations" ("version") VALUES (?) [["version", "20160514163909"]] +  (110.8ms) commit transaction + ActiveRecord::SchemaMigration Load (0.2ms) SELECT "schema_migrations".* FROM "schema_migrations" +  (0.2ms)  SELECT sql + FROM sqlite_master + WHERE name='index_user_groups_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_user_groups_on_name' AND type='index' + +  (0.2ms) SELECT sql + FROM sqlite_master + WHERE name='index_users_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_users_on_name' AND type='index' + +  (103.8ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  +  (0.2ms) select sqlite_version(*) +  (98.8ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version") + ActiveRecord::SchemaMigration Load (0.2ms) SELECT "schema_migrations".* FROM "schema_migrations" +Migrating to CreateTables (20160514163909) +  (0.2ms) begin transaction +  (0.9ms) CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar, "api_code" varchar) +  (0.4ms) CREATE INDEX "index_users_on_name" ON "users" ("name") +  (0.4ms) CREATE TABLE "urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "url_pattern" varchar, "name" varchar, "http_method" varchar) +  (0.4ms) CREATE TABLE "user_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)  +  (0.4ms) CREATE INDEX "index_user_groups_on_name" ON "user_groups" ("name") +  (0.5ms) CREATE TABLE "users_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "user_group_id" integer, "user_id" integer)  +  (0.2ms) CREATE TABLE "users_urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "users_group_id" integer, "url_id" integer) + SQL (0.2ms) INSERT INTO "users" ("name", "id") VALUES (?, ?) [["name", "guest"], ["id", 1]] + SQL (0.1ms) INSERT INTO "urls" ("url_pattern", "name", "http_method", "id") VALUES (?, ?, ?, ?) [["url_pattern", "^/login"], ["name", "Login page"], ["http_method", "GET"], ["id", 1]] + SQL (0.0ms) INSERT INTO "urls" ("url_pattern", "name", "http_method", "id") VALUES (?, ?, ?, ?) [["url_pattern", "^/oauth/.*"], ["name", "AuthCallback page"], ["http_method", "GET"], ["id", 2]] + SQL (0.1ms) INSERT INTO "user_groups" ("id", "name") VALUES (?, ?) [["id", 1], ["name", "Guest"]] + SQL (0.1ms) INSERT INTO "users_groups" ("id", "user_id", "user_group_id") VALUES (?, ?, ?) [["id", 1], ["user_id", 1], ["user_group_id", 1]] + SQL (0.1ms) INSERT INTO "users_urls" ("id", "url_id", "users_group_id") VALUES (?, ?, ?) [["id", 1], ["url_id", 1], ["users_group_id", 1]] + SQL (0.0ms) INSERT INTO "users_urls" ("id", "url_id", "users_group_id") VALUES (?, ?, ?) [["id", 2], ["url_id", 2], ["users_group_id", 1]] + SQL (0.1ms) INSERT INTO "schema_migrations" ("version") VALUES (?) [["version", "20160514163909"]] +  (121.3ms) commit transaction + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" +  (0.2ms)  SELECT sql + FROM sqlite_master + WHERE name='index_user_groups_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_user_groups_on_name' AND type='index' + +  (0.2ms) SELECT sql + FROM sqlite_master + WHERE name='index_users_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_users_on_name' AND type='index' + + + +Started GET "/login" for 127.0.0.1 at 2016-05-15 17:25:14 +0300 + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" +Processing by LoginController#index as HTML + User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."name" = ? LIMIT 1 [["name", "guest"]] + CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."name" = ? LIMIT 1 [["name", "guest"]] + SQL (0.2ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."users_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "users_groups"."id" AS t2_r0, "users_groups"."user_group_id" AS t2_r1, "users_groups"."user_id" AS t2_r2, "users"."id" AS t3_r0, "users"."name" AS t3_r1, "users"."api_code" AS t3_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "users_groups" ON "users_groups"."id" = "users_urls"."users_group_id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 1 + Rendered login/index.html.erb within layouts/application (2.3ms) +Completed 200 OK in 178ms (Views: 138.1ms | ActiveRecord: 1.6ms) + + +Started GET "/login/logout" for 127.0.0.1 at 2016-05-15 17:25:17 +0300 + +ActionController::RoutingError (No route matches [GET] "/login/logout"): + actionpack (4.2.6) lib/action_dispatch/middleware/debug_exceptions.rb:21:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/show_exceptions.rb:30:in `call' + railties (4.2.6) lib/rails/rack/logger.rb:38:in `call_app' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `block in call' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `block in tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:26:in `tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `tagged' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/request_id.rb:21:in `call' + rack (1.6.4) lib/rack/methodoverride.rb:22:in `call' + rack (1.6.4) lib/rack/runtime.rb:18:in `call' + activesupport (4.2.6) lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/static.rb:120:in `call' + rack (1.6.4) lib/rack/sendfile.rb:113:in `call' + railties (4.2.6) lib/rails/engine.rb:518:in `call' + railties (4.2.6) lib/rails/application.rb:165:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + rack (1.6.4) lib/rack/content_length.rb:15:in `call' + rack (1.6.4) lib/rack/handler/webrick.rb:88:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:138:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:94:in `run' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/server.rb:294:in `block in start_thread' + + + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_trace.html.erb (1.0ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/routes/_route.html.erb (0.7ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/routes/_table.html.erb (4.5ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_request_and_response.html.erb (0.9ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/routing_error.html.erb within rescues/layout (19.0ms) + + +Started GET "/oauth/logout" for 127.0.0.1 at 2016-05-15 17:25:40 +0300 +Processing by LoginController#oauth_callback as HTML + Parameters: {"provider_name"=>"logout"} + User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."name" = ? LIMIT 1 [["name", "guest"]] + CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."name" = ? LIMIT 1 [["name", "guest"]] + SQL (0.6ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."users_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "users_groups"."id" AS t2_r0, "users_groups"."user_group_id" AS t2_r1, "users_groups"."user_id" AS t2_r2, "users"."id" AS t3_r0, "users"."name" AS t3_r1, "users"."api_code" AS t3_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "users_groups" ON "users_groups"."id" = "users_urls"."users_group_id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 1 +Completed 500 Internal Server Error in 8ms (ActiveRecord: 0.9ms) + +NoMethodError (undefined method `token_url' for nil:NilClass): + /home/dcrow/Desktop/Work/oauth_service/app/controllers/oauth_service/login_controller.rb:40:in `get_user_info' + /home/dcrow/Desktop/Work/oauth_service/app/controllers/oauth_service/login_controller.rb:6:in `oauth_callback' + actionpack (4.2.6) lib/action_controller/metal/implicit_render.rb:4:in `send_action' + actionpack (4.2.6) lib/abstract_controller/base.rb:198:in `process_action' + actionpack (4.2.6) lib/action_controller/metal/rendering.rb:10:in `process_action' + actionpack (4.2.6) lib/abstract_controller/callbacks.rb:20:in `block in process_action' + activesupport (4.2.6) lib/active_support/callbacks.rb:117:in `call' + activesupport (4.2.6) lib/active_support/callbacks.rb:117:in `call' + activesupport (4.2.6) lib/active_support/callbacks.rb:555:in `block (2 levels) in compile' + activesupport (4.2.6) lib/active_support/callbacks.rb:505:in `call' + activesupport (4.2.6) lib/active_support/callbacks.rb:505:in `call' + activesupport (4.2.6) lib/active_support/callbacks.rb:92:in `__run_callbacks__' + activesupport (4.2.6) lib/active_support/callbacks.rb:778:in `_run_process_action_callbacks' + activesupport (4.2.6) lib/active_support/callbacks.rb:81:in `run_callbacks' + actionpack (4.2.6) lib/abstract_controller/callbacks.rb:19:in `process_action' + actionpack (4.2.6) lib/action_controller/metal/rescue.rb:29:in `process_action' + actionpack (4.2.6) lib/action_controller/metal/instrumentation.rb:32:in `block in process_action' + activesupport (4.2.6) lib/active_support/notifications.rb:164:in `block in instrument' + activesupport (4.2.6) lib/active_support/notifications/instrumenter.rb:20:in `instrument' + activesupport (4.2.6) lib/active_support/notifications.rb:164:in `instrument' + actionpack (4.2.6) lib/action_controller/metal/instrumentation.rb:30:in `process_action' + actionpack (4.2.6) lib/action_controller/metal/params_wrapper.rb:250:in `process_action' + activerecord (4.2.6) lib/active_record/railties/controller_runtime.rb:18:in `process_action' + actionpack (4.2.6) lib/abstract_controller/base.rb:137:in `process' + actionview (4.2.6) lib/action_view/rendering.rb:30:in `process' + actionpack (4.2.6) lib/action_controller/metal.rb:196:in `dispatch' + actionpack (4.2.6) lib/action_controller/metal/rack_delegation.rb:13:in `dispatch' + actionpack (4.2.6) lib/action_controller/metal.rb:237:in `block in action' + actionpack (4.2.6) lib/action_dispatch/routing/route_set.rb:74:in `call' + actionpack (4.2.6) lib/action_dispatch/routing/route_set.rb:74:in `dispatch' + actionpack (4.2.6) lib/action_dispatch/routing/route_set.rb:43:in `serve' + actionpack (4.2.6) lib/action_dispatch/journey/router.rb:43:in `block in serve' + actionpack (4.2.6) lib/action_dispatch/journey/router.rb:30:in `each' + actionpack (4.2.6) lib/action_dispatch/journey/router.rb:30:in `serve' + actionpack (4.2.6) lib/action_dispatch/routing/route_set.rb:817:in `call' + rack (1.6.4) lib/rack/etag.rb:24:in `call' + rack (1.6.4) lib/rack/conditionalget.rb:25:in `call' + rack (1.6.4) lib/rack/head.rb:13:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/params_parser.rb:27:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/flash.rb:260:in `call' + rack (1.6.4) lib/rack/session/abstract/id.rb:225:in `context' + rack (1.6.4) lib/rack/session/abstract/id.rb:220:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/cookies.rb:560:in `call' + activerecord (4.2.6) lib/active_record/query_cache.rb:36:in `call' + activerecord (4.2.6) lib/active_record/connection_adapters/abstract/connection_pool.rb:653:in `call' + activerecord (4.2.6) lib/active_record/migration.rb:377:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/callbacks.rb:29:in `block in call' + activesupport (4.2.6) lib/active_support/callbacks.rb:88:in `__run_callbacks__' + activesupport (4.2.6) lib/active_support/callbacks.rb:778:in `_run_call_callbacks' + activesupport (4.2.6) lib/active_support/callbacks.rb:81:in `run_callbacks' + actionpack (4.2.6) lib/action_dispatch/middleware/callbacks.rb:27:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/reloader.rb:73:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/remote_ip.rb:78:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/show_exceptions.rb:30:in `call' + railties (4.2.6) lib/rails/rack/logger.rb:38:in `call_app' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `block in call' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `block in tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:26:in `tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `tagged' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/request_id.rb:21:in `call' + rack (1.6.4) lib/rack/methodoverride.rb:22:in `call' + rack (1.6.4) lib/rack/runtime.rb:18:in `call' + activesupport (4.2.6) lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/static.rb:120:in `call' + rack (1.6.4) lib/rack/sendfile.rb:113:in `call' + railties (4.2.6) lib/rails/engine.rb:518:in `call' + railties (4.2.6) lib/rails/application.rb:165:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + rack (1.6.4) lib/rack/content_length.rb:15:in `call' + rack (1.6.4) lib/rack/handler/webrick.rb:88:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:138:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:94:in `run' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/server.rb:294:in `block in start_thread' + + + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_source.erb (5.8ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_trace.html.erb (2.5ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_request_and_response.html.erb (1.2ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/diagnostics.html.erb within rescues/layout (20.2ms) + + +Started GET "/oauth/logout" for 127.0.0.1 at 2016-05-15 17:27:20 +0300 + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" +Processing by LoginController#oauth_callback as HTML + Parameters: {"provider_name"=>"logout"} + User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."name" = ? LIMIT 1 [["name", "guest"]] + CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."name" = ? LIMIT 1 [["name", "guest"]] + SQL (0.2ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."users_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "users_groups"."id" AS t2_r0, "users_groups"."user_group_id" AS t2_r1, "users_groups"."user_id" AS t2_r2, "users"."id" AS t3_r0, "users"."name" AS t3_r1, "users"."api_code" AS t3_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "users_groups" ON "users_groups"."id" = "users_urls"."users_group_id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 1 +Completed 500 Internal Server Error in 41ms (ActiveRecord: 1.0ms) + +NoMethodError (undefined method `token_url' for nil:NilClass): + /home/dcrow/Desktop/Work/oauth_service/app/controllers/oauth_service/login_controller.rb:40:in `get_user_info' + /home/dcrow/Desktop/Work/oauth_service/app/controllers/oauth_service/login_controller.rb:6:in `oauth_callback' + actionpack (4.2.6) lib/action_controller/metal/implicit_render.rb:4:in `send_action' + actionpack (4.2.6) lib/abstract_controller/base.rb:198:in `process_action' + actionpack (4.2.6) lib/action_controller/metal/rendering.rb:10:in `process_action' + actionpack (4.2.6) lib/abstract_controller/callbacks.rb:20:in `block in process_action' + activesupport (4.2.6) lib/active_support/callbacks.rb:117:in `call' + activesupport (4.2.6) lib/active_support/callbacks.rb:117:in `call' + activesupport (4.2.6) lib/active_support/callbacks.rb:555:in `block (2 levels) in compile' + activesupport (4.2.6) lib/active_support/callbacks.rb:505:in `call' + activesupport (4.2.6) lib/active_support/callbacks.rb:505:in `call' + activesupport (4.2.6) lib/active_support/callbacks.rb:92:in `__run_callbacks__' + activesupport (4.2.6) lib/active_support/callbacks.rb:778:in `_run_process_action_callbacks' + activesupport (4.2.6) lib/active_support/callbacks.rb:81:in `run_callbacks' + actionpack (4.2.6) lib/abstract_controller/callbacks.rb:19:in `process_action' + actionpack (4.2.6) lib/action_controller/metal/rescue.rb:29:in `process_action' + actionpack (4.2.6) lib/action_controller/metal/instrumentation.rb:32:in `block in process_action' + activesupport (4.2.6) lib/active_support/notifications.rb:164:in `block in instrument' + activesupport (4.2.6) lib/active_support/notifications/instrumenter.rb:20:in `instrument' + activesupport (4.2.6) lib/active_support/notifications.rb:164:in `instrument' + actionpack (4.2.6) lib/action_controller/metal/instrumentation.rb:30:in `process_action' + actionpack (4.2.6) lib/action_controller/metal/params_wrapper.rb:250:in `process_action' + activerecord (4.2.6) lib/active_record/railties/controller_runtime.rb:18:in `process_action' + actionpack (4.2.6) lib/abstract_controller/base.rb:137:in `process' + actionview (4.2.6) lib/action_view/rendering.rb:30:in `process' + actionpack (4.2.6) lib/action_controller/metal.rb:196:in `dispatch' + actionpack (4.2.6) lib/action_controller/metal/rack_delegation.rb:13:in `dispatch' + actionpack (4.2.6) lib/action_controller/metal.rb:237:in `block in action' + actionpack (4.2.6) lib/action_dispatch/routing/route_set.rb:74:in `call' + actionpack (4.2.6) lib/action_dispatch/routing/route_set.rb:74:in `dispatch' + actionpack (4.2.6) lib/action_dispatch/routing/route_set.rb:43:in `serve' + actionpack (4.2.6) lib/action_dispatch/journey/router.rb:43:in `block in serve' + actionpack (4.2.6) lib/action_dispatch/journey/router.rb:30:in `each' + actionpack (4.2.6) lib/action_dispatch/journey/router.rb:30:in `serve' + actionpack (4.2.6) lib/action_dispatch/routing/route_set.rb:817:in `call' + rack (1.6.4) lib/rack/etag.rb:24:in `call' + rack (1.6.4) lib/rack/conditionalget.rb:25:in `call' + rack (1.6.4) lib/rack/head.rb:13:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/params_parser.rb:27:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/flash.rb:260:in `call' + rack (1.6.4) lib/rack/session/abstract/id.rb:225:in `context' + rack (1.6.4) lib/rack/session/abstract/id.rb:220:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/cookies.rb:560:in `call' + activerecord (4.2.6) lib/active_record/query_cache.rb:36:in `call' + activerecord (4.2.6) lib/active_record/connection_adapters/abstract/connection_pool.rb:653:in `call' + activerecord (4.2.6) lib/active_record/migration.rb:377:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/callbacks.rb:29:in `block in call' + activesupport (4.2.6) lib/active_support/callbacks.rb:88:in `__run_callbacks__' + activesupport (4.2.6) lib/active_support/callbacks.rb:778:in `_run_call_callbacks' + activesupport (4.2.6) lib/active_support/callbacks.rb:81:in `run_callbacks' + actionpack (4.2.6) lib/action_dispatch/middleware/callbacks.rb:27:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/reloader.rb:73:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/remote_ip.rb:78:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/show_exceptions.rb:30:in `call' + railties (4.2.6) lib/rails/rack/logger.rb:38:in `call_app' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `block in call' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `block in tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:26:in `tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `tagged' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/request_id.rb:21:in `call' + rack (1.6.4) lib/rack/methodoverride.rb:22:in `call' + rack (1.6.4) lib/rack/runtime.rb:18:in `call' + activesupport (4.2.6) lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/static.rb:120:in `call' + rack (1.6.4) lib/rack/sendfile.rb:113:in `call' + railties (4.2.6) lib/rails/engine.rb:518:in `call' + railties (4.2.6) lib/rails/application.rb:165:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + rack (1.6.4) lib/rack/content_length.rb:15:in `call' + rack (1.6.4) lib/rack/handler/webrick.rb:88:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:138:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:94:in `run' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/server.rb:294:in `block in start_thread' + + + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_source.erb (7.7ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_trace.html.erb (1.8ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_request_and_response.html.erb (7.2ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/diagnostics.html.erb within rescues/layout (24.8ms) + + +Started GET "/login/logout" for 127.0.0.1 at 2016-05-15 17:29:16 +0300 +Processing by LoginController#logout as HTML + User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."name" = ? LIMIT 1 [["name", "guest"]] + CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."name" = ? LIMIT 1 [["name", "guest"]] + SQL (0.3ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."users_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "users_groups"."id" AS t2_r0, "users_groups"."user_group_id" AS t2_r1, "users_groups"."user_id" AS t2_r2, "users"."id" AS t3_r0, "users"."name" AS t3_r1, "users"."api_code" AS t3_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "users_groups" ON "users_groups"."id" = "users_urls"."users_group_id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 1 +Filter chain halted as :check_access rendered or redirected +Completed 403 Forbidden in 29ms (Views: 0.2ms | ActiveRecord: 1.7ms) + + +Started GET "/login/logout" for 127.0.0.1 at 2016-05-15 17:33:55 +0300 + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" +Processing by LoginController#logout as HTML +Completed 500 Internal Server Error in 4ms (ActiveRecord: 0.0ms) + +NameError (undefined local variable or method `api_code' for #<LoginController:0x007f4a701b2530>): + /home/dcrow/Desktop/Work/oauth_service/app/controllers/oauth_service/login_controller.rb:23:in `logout' + actionpack (4.2.6) lib/action_controller/metal/implicit_render.rb:4:in `send_action' + actionpack (4.2.6) lib/abstract_controller/base.rb:198:in `process_action' + actionpack (4.2.6) lib/action_controller/metal/rendering.rb:10:in `process_action' + actionpack (4.2.6) lib/abstract_controller/callbacks.rb:20:in `block in process_action' + activesupport (4.2.6) lib/active_support/callbacks.rb:117:in `call' + activesupport (4.2.6) lib/active_support/callbacks.rb:117:in `call' + activesupport (4.2.6) lib/active_support/callbacks.rb:555:in `block (2 levels) in compile' + activesupport (4.2.6) lib/active_support/callbacks.rb:505:in `call' + activesupport (4.2.6) lib/active_support/callbacks.rb:505:in `call' + activesupport (4.2.6) lib/active_support/callbacks.rb:92:in `__run_callbacks__' + activesupport (4.2.6) lib/active_support/callbacks.rb:778:in `_run_process_action_callbacks' + activesupport (4.2.6) lib/active_support/callbacks.rb:81:in `run_callbacks' + actionpack (4.2.6) lib/abstract_controller/callbacks.rb:19:in `process_action' + actionpack (4.2.6) lib/action_controller/metal/rescue.rb:29:in `process_action' + actionpack (4.2.6) lib/action_controller/metal/instrumentation.rb:32:in `block in process_action' + activesupport (4.2.6) lib/active_support/notifications.rb:164:in `block in instrument' + activesupport (4.2.6) lib/active_support/notifications/instrumenter.rb:20:in `instrument' + activesupport (4.2.6) lib/active_support/notifications.rb:164:in `instrument' + actionpack (4.2.6) lib/action_controller/metal/instrumentation.rb:30:in `process_action' + actionpack (4.2.6) lib/action_controller/metal/params_wrapper.rb:250:in `process_action' + activerecord (4.2.6) lib/active_record/railties/controller_runtime.rb:18:in `process_action' + actionpack (4.2.6) lib/abstract_controller/base.rb:137:in `process' + actionview (4.2.6) lib/action_view/rendering.rb:30:in `process' + actionpack (4.2.6) lib/action_controller/metal.rb:196:in `dispatch' + actionpack (4.2.6) lib/action_controller/metal/rack_delegation.rb:13:in `dispatch' + actionpack (4.2.6) lib/action_controller/metal.rb:237:in `block in action' + actionpack (4.2.6) lib/action_dispatch/routing/route_set.rb:74:in `call' + actionpack (4.2.6) lib/action_dispatch/routing/route_set.rb:74:in `dispatch' + actionpack (4.2.6) lib/action_dispatch/routing/route_set.rb:43:in `serve' + actionpack (4.2.6) lib/action_dispatch/journey/router.rb:43:in `block in serve' + actionpack (4.2.6) lib/action_dispatch/journey/router.rb:30:in `each' + actionpack (4.2.6) lib/action_dispatch/journey/router.rb:30:in `serve' + actionpack (4.2.6) lib/action_dispatch/routing/route_set.rb:817:in `call' + rack (1.6.4) lib/rack/etag.rb:24:in `call' + rack (1.6.4) lib/rack/conditionalget.rb:25:in `call' + rack (1.6.4) lib/rack/head.rb:13:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/params_parser.rb:27:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/flash.rb:260:in `call' + rack (1.6.4) lib/rack/session/abstract/id.rb:225:in `context' + rack (1.6.4) lib/rack/session/abstract/id.rb:220:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/cookies.rb:560:in `call' + activerecord (4.2.6) lib/active_record/query_cache.rb:36:in `call' + activerecord (4.2.6) lib/active_record/connection_adapters/abstract/connection_pool.rb:653:in `call' + activerecord (4.2.6) lib/active_record/migration.rb:377:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/callbacks.rb:29:in `block in call' + activesupport (4.2.6) lib/active_support/callbacks.rb:88:in `__run_callbacks__' + activesupport (4.2.6) lib/active_support/callbacks.rb:778:in `_run_call_callbacks' + activesupport (4.2.6) lib/active_support/callbacks.rb:81:in `run_callbacks' + actionpack (4.2.6) lib/action_dispatch/middleware/callbacks.rb:27:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/reloader.rb:73:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/remote_ip.rb:78:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/show_exceptions.rb:30:in `call' + railties (4.2.6) lib/rails/rack/logger.rb:38:in `call_app' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `block in call' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `block in tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:26:in `tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `tagged' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/request_id.rb:21:in `call' + rack (1.6.4) lib/rack/methodoverride.rb:22:in `call' + rack (1.6.4) lib/rack/runtime.rb:18:in `call' + activesupport (4.2.6) lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/static.rb:120:in `call' + rack (1.6.4) lib/rack/sendfile.rb:113:in `call' + railties (4.2.6) lib/rails/engine.rb:518:in `call' + railties (4.2.6) lib/rails/application.rb:165:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + rack (1.6.4) lib/rack/content_length.rb:15:in `call' + rack (1.6.4) lib/rack/handler/webrick.rb:88:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:138:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:94:in `run' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/server.rb:294:in `block in start_thread' + + + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_source.erb (4.3ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_trace.html.erb (1.8ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_request_and_response.html.erb (7.4ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/diagnostics.html.erb within rescues/layout (22.8ms) + + +Started GET "/login/logout" for 127.0.0.1 at 2016-05-15 17:34:33 +0300 + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" +Processing by LoginController#logout as HTML + User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."api_code" IS NULL LIMIT 1 +  (0.1ms) begin transaction +  (0.0ms) commit transaction +Completed 200 OK in 11ms (Views: 0.2ms | ActiveRecord: 0.5ms) + + +Started GET "/login" for 127.0.0.1 at 2016-05-15 17:37:17 +0300 + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" +Processing by LoginController#index as HTML + Rendered login/index.html.erb within layouts/application (2.1ms) +Completed 200 OK in 136ms (Views: 136.2ms | ActiveRecord: 0.0ms) + + +Started GET "/login/logout" for 127.0.0.1 at 2016-05-15 17:37:19 +0300 +Processing by LoginController#logout as HTML +Completed 400 Bad Request in 0ms (Views: 0.2ms | ActiveRecord: 0.0ms) + + +Started GET "/__identify__" for 127.0.0.1 at 2016-05-15 17:44:19 +0300 + +ActionController::RoutingError (No route matches [GET] "/__identify__"): + actionpack (4.2.6) lib/action_dispatch/middleware/debug_exceptions.rb:21:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/show_exceptions.rb:30:in `call' + railties (4.2.6) lib/rails/rack/logger.rb:38:in `call_app' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `block in call' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `block in tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:26:in `tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `tagged' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/request_id.rb:21:in `call' + rack (1.6.4) lib/rack/methodoverride.rb:22:in `call' + rack (1.6.4) lib/rack/runtime.rb:18:in `call' + activesupport (4.2.6) lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/static.rb:120:in `call' + rack (1.6.4) lib/rack/sendfile.rb:113:in `call' + railties (4.2.6) lib/rails/engine.rb:518:in `call' + railties (4.2.6) lib/rails/application.rb:165:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + rack (1.6.4) lib/rack/content_length.rb:15:in `call' + rack (1.6.4) lib/rack/handler/webrick.rb:88:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:138:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:94:in `run' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/server.rb:294:in `block in start_thread' + + + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_trace.html.erb (2.8ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/routes/_route.html.erb (1.6ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/routes/_table.html.erb (10.1ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_request_and_response.html.erb (1.0ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/routing_error.html.erb within rescues/layout (44.8ms) + + +Started GET "/__identify__" for 127.0.0.1 at 2016-05-15 17:44:20 +0300 + +ActionController::RoutingError (No route matches [GET] "/__identify__"): + actionpack (4.2.6) lib/action_dispatch/middleware/debug_exceptions.rb:21:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/show_exceptions.rb:30:in `call' + railties (4.2.6) lib/rails/rack/logger.rb:38:in `call_app' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `block in call' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `block in tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:26:in `tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `tagged' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/request_id.rb:21:in `call' + rack (1.6.4) lib/rack/methodoverride.rb:22:in `call' + rack (1.6.4) lib/rack/runtime.rb:18:in `call' + activesupport (4.2.6) lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/static.rb:120:in `call' + rack (1.6.4) lib/rack/sendfile.rb:113:in `call' + railties (4.2.6) lib/rails/engine.rb:518:in `call' + railties (4.2.6) lib/rails/application.rb:165:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + rack (1.6.4) lib/rack/content_length.rb:15:in `call' + rack (1.6.4) lib/rack/handler/webrick.rb:88:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:138:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:94:in `run' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/server.rb:294:in `block in start_thread' + + + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_trace.html.erb (1.2ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/routes/_route.html.erb (0.8ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/routes/_table.html.erb (1.1ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_request_and_response.html.erb (0.8ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/routing_error.html.erb within rescues/layout (15.7ms) +  (119.4ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  +  (0.2ms) select sqlite_version(*) +  (73.0ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version") + ActiveRecord::SchemaMigration Load (0.2ms) SELECT "schema_migrations".* FROM "schema_migrations" +Migrating to CreateTables (20160514163909) +  (0.2ms) begin transaction +  (0.7ms) CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar, "api_code" varchar) +  (0.3ms) CREATE INDEX "index_users_on_name" ON "users" ("name") +  (0.4ms) CREATE TABLE "urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "url_pattern" varchar, "name" varchar, "http_method" varchar) +  (0.3ms) CREATE TABLE "user_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)  +  (0.3ms) CREATE INDEX "index_user_groups_on_name" ON "user_groups" ("name") +  (0.4ms) CREATE TABLE "users_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "user_group_id" integer, "user_id" integer)  +  (0.3ms) CREATE TABLE "users_urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "users_group_id" integer, "url_id" integer) + SQL (0.2ms) INSERT INTO "users" ("name", "id") VALUES (?, ?) [["name", "guest"], ["id", 1]] + SQL (0.2ms) INSERT INTO "urls" ("url_pattern", "name", "http_method", "id") VALUES (?, ?, ?, ?) [["url_pattern", "^/login"], ["name", "Login page"], ["http_method", "GET"], ["id", 1]] + SQL (0.1ms) INSERT INTO "urls" ("url_pattern", "name", "http_method", "id") VALUES (?, ?, ?, ?) [["url_pattern", "^/oauth/.*"], ["name", "AuthCallback page"], ["http_method", "GET"], ["id", 2]] + SQL (0.1ms) INSERT INTO "user_groups" ("id", "name") VALUES (?, ?) [["id", 1], ["name", "Guest"]] + SQL (0.1ms) INSERT INTO "users_groups" ("id", "user_id", "user_group_id") VALUES (?, ?, ?) [["id", 1], ["user_id", 1], ["user_group_id", 1]] + SQL (0.1ms) INSERT INTO "users_urls" ("id", "url_id", "users_group_id") VALUES (?, ?, ?) [["id", 1], ["url_id", 1], ["users_group_id", 1]] + SQL (0.0ms) INSERT INTO "users_urls" ("id", "url_id", "users_group_id") VALUES (?, ?, ?) [["id", 2], ["url_id", 2], ["users_group_id", 1]] + SQL (0.1ms) INSERT INTO "schema_migrations" ("version") VALUES (?) [["version", "20160514163909"]] +  (115.7ms) commit transaction + ActiveRecord::SchemaMigration Load (0.3ms) SELECT "schema_migrations".* FROM "schema_migrations" +  (0.3ms)  SELECT sql + FROM sqlite_master + WHERE name='index_user_groups_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_user_groups_on_name' AND type='index' + +  (0.3ms) SELECT sql + FROM sqlite_master + WHERE name='index_users_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_users_on_name' AND type='index' + +  (102.7ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  +  (0.1ms) select sqlite_version(*) +  (99.3ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version") + ActiveRecord::SchemaMigration Load (0.3ms) SELECT "schema_migrations".* FROM "schema_migrations" +Migrating to CreateTables (20160514163909) +  (0.1ms) begin transaction +  (0.4ms) CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar, "api_code" varchar) +  (0.2ms) CREATE INDEX "index_users_on_name" ON "users" ("name") +  (0.2ms) CREATE TABLE "urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "url_pattern" varchar, "name" varchar, "http_method" varchar) +  (0.2ms) CREATE TABLE "user_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)  +  (0.2ms) CREATE INDEX "index_user_groups_on_name" ON "user_groups" ("name") +  (0.2ms) CREATE TABLE "users_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "user_group_id" integer, "user_id" integer)  +  (0.2ms) CREATE TABLE "users_urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "users_group_id" integer, "url_id" integer) + SQL (0.1ms) INSERT INTO "users" ("name", "id") VALUES (?, ?) [["name", "guest"], ["id", 1]] + SQL (0.1ms) INSERT INTO "urls" ("url_pattern", "name", "http_method", "id") VALUES (?, ?, ?, ?) [["url_pattern", "^/login"], ["name", "Login page"], ["http_method", "GET"], ["id", 1]] + SQL (0.0ms) INSERT INTO "urls" ("url_pattern", "name", "http_method", "id") VALUES (?, ?, ?, ?) [["url_pattern", "^/oauth/.*"], ["name", "AuthCallback page"], ["http_method", "GET"], ["id", 2]] + SQL (0.1ms) INSERT INTO "user_groups" ("id", "name") VALUES (?, ?) [["id", 1], ["name", "Guest"]] + SQL (0.1ms) INSERT INTO "users_groups" ("id", "user_id", "user_group_id") VALUES (?, ?, ?) [["id", 1], ["user_id", 1], ["user_group_id", 1]] + SQL (0.1ms) INSERT INTO "users_urls" ("id", "url_id", "users_group_id") VALUES (?, ?, ?) [["id", 1], ["url_id", 1], ["users_group_id", 1]] + SQL (0.0ms) INSERT INTO "users_urls" ("id", "url_id", "users_group_id") VALUES (?, ?, ?) [["id", 2], ["url_id", 2], ["users_group_id", 1]] + SQL (0.1ms) INSERT INTO "schema_migrations" ("version") VALUES (?) [["version", "20160514163909"]] +  (97.5ms) commit transaction + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" +  (0.3ms)  SELECT sql + FROM sqlite_master + WHERE name='index_user_groups_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_user_groups_on_name' AND type='index' + +  (0.3ms) SELECT sql + FROM sqlite_master + WHERE name='index_users_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_users_on_name' AND type='index' + + + +Started GET "/login" for 127.0.0.1 at 2016-05-15 17:49:22 +0300 + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" +Processing by LoginController#index as HTML + User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."name" = ? LIMIT 1 [["name", "guest"]] + SQL (0.2ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."users_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "users_groups"."id" AS t2_r0, "users_groups"."user_group_id" AS t2_r1, "users_groups"."user_id" AS t2_r2, "users"."id" AS t3_r0, "users"."name" AS t3_r1, "users"."api_code" AS t3_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "users_groups" ON "users_groups"."id" = "users_urls"."users_group_id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 1 + Rendered login/index.html.erb within layouts/application (2.1ms) +Completed 200 OK in 178ms (Views: 139.5ms | ActiveRecord: 1.0ms) + + +Started GET "/__identify__" for 127.0.0.1 at 2016-05-15 17:49:52 +0300 + +ActionController::RoutingError (No route matches [GET] "/__identify__"): + actionpack (4.2.6) lib/action_dispatch/middleware/debug_exceptions.rb:21:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/show_exceptions.rb:30:in `call' + railties (4.2.6) lib/rails/rack/logger.rb:38:in `call_app' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `block in call' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `block in tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:26:in `tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `tagged' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/request_id.rb:21:in `call' + rack (1.6.4) lib/rack/methodoverride.rb:22:in `call' + rack (1.6.4) lib/rack/runtime.rb:18:in `call' + activesupport (4.2.6) lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/static.rb:120:in `call' + rack (1.6.4) lib/rack/sendfile.rb:113:in `call' + railties (4.2.6) lib/rails/engine.rb:518:in `call' + railties (4.2.6) lib/rails/application.rb:165:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + rack (1.6.4) lib/rack/content_length.rb:15:in `call' + rack (1.6.4) lib/rack/handler/webrick.rb:88:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:138:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:94:in `run' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/server.rb:294:in `block in start_thread' + + + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_trace.html.erb (2.6ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/routes/_route.html.erb (0.9ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/routes/_table.html.erb (8.5ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_request_and_response.html.erb (1.1ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/routing_error.html.erb within rescues/layout (38.5ms) + + +Started GET "/__identify__" for 127.0.0.1 at 2016-05-15 17:49:52 +0300 + +ActionController::RoutingError (No route matches [GET] "/__identify__"): + actionpack (4.2.6) lib/action_dispatch/middleware/debug_exceptions.rb:21:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/show_exceptions.rb:30:in `call' + railties (4.2.6) lib/rails/rack/logger.rb:38:in `call_app' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `block in call' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `block in tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:26:in `tagged' + activesupport (4.2.6) lib/active_support/tagged_logging.rb:68:in `tagged' + railties (4.2.6) lib/rails/rack/logger.rb:20:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/request_id.rb:21:in `call' + rack (1.6.4) lib/rack/methodoverride.rb:22:in `call' + rack (1.6.4) lib/rack/runtime.rb:18:in `call' + activesupport (4.2.6) lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + actionpack (4.2.6) lib/action_dispatch/middleware/static.rb:120:in `call' + rack (1.6.4) lib/rack/sendfile.rb:113:in `call' + railties (4.2.6) lib/rails/engine.rb:518:in `call' + railties (4.2.6) lib/rails/application.rb:165:in `call' + rack (1.6.4) lib/rack/lock.rb:17:in `call' + rack (1.6.4) lib/rack/content_length.rb:15:in `call' + rack (1.6.4) lib/rack/handler/webrick.rb:88:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:138:in `service' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/httpserver.rb:94:in `run' + /home/dcrow/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/webrick/server.rb:294:in `block in start_thread' + + + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_trace.html.erb (1.3ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/routes/_route.html.erb (0.7ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/routes/_table.html.erb (1.0ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/_request_and_response.html.erb (0.8ms) + Rendered /home/dcrow/.rvm/gems/ruby-2.2.1/gems/actionpack-4.2.6/lib/action_dispatch/middleware/templates/rescues/routing_error.html.erb within rescues/layout (15.2ms) + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" +  (0.1ms)  SELECT sql + FROM sqlite_master + WHERE name='index_user_groups_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_user_groups_on_name' AND type='index' + +  (0.1ms) SELECT sql + FROM sqlite_master + WHERE name='index_users_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_users_on_name' AND type='index' + +  (102.4ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  +  (0.3ms) select sqlite_version(*) +  (97.7ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version") + ActiveRecord::SchemaMigration Load (0.3ms) SELECT "schema_migrations".* FROM "schema_migrations" +Migrating to CreateTables (20160514163909) +  (0.1ms) begin transaction +  (0.7ms) CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar, "api_code" varchar) +  (0.3ms) CREATE INDEX "index_users_on_name" ON "users" ("name") +  (0.3ms) CREATE TABLE "urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "url_pattern" varchar, "name" varchar, "http_method" varchar) +  (0.3ms) CREATE TABLE "user_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)  +  (0.3ms) CREATE INDEX "index_user_groups_on_name" ON "user_groups" ("name") +  (0.3ms) CREATE TABLE "users_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "user_group_id" integer, "user_id" integer)  +  (0.3ms) CREATE TABLE "users_urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "users_group_id" integer, "url_id" integer) + SQL (0.3ms) INSERT INTO "users" ("name", "id") VALUES (?, ?) [["name", "guest"], ["id", 1]] + SQL (0.2ms) INSERT INTO "urls" ("url_pattern", "name", "http_method", "id") VALUES (?, ?, ?, ?) [["url_pattern", "^/login"], ["name", "Login page"], ["http_method", "GET"], ["id", 1]] + SQL (0.1ms) INSERT INTO "urls" ("url_pattern", "name", "http_method", "id") VALUES (?, ?, ?, ?) [["url_pattern", "^/oauth/.*"], ["name", "AuthCallback page"], ["http_method", "GET"], ["id", 2]] + SQL (0.1ms) INSERT INTO "user_groups" ("id", "name") VALUES (?, ?) [["id", 1], ["name", "Guest"]] + SQL (0.1ms) INSERT INTO "users_groups" ("id", "user_id", "user_group_id") VALUES (?, ?, ?) [["id", 1], ["user_id", 1], ["user_group_id", 1]] + SQL (0.1ms) INSERT INTO "users_urls" ("id", "url_id", "users_group_id") VALUES (?, ?, ?) [["id", 1], ["url_id", 1], ["users_group_id", 1]] + SQL (0.1ms) INSERT INTO "users_urls" ("id", "url_id", "users_group_id") VALUES (?, ?, ?) [["id", 2], ["url_id", 2], ["users_group_id", 1]] + SQL (0.1ms) INSERT INTO "schema_migrations" ("version") VALUES (?) [["version", "20160514163909"]] +  (115.8ms) commit transaction + ActiveRecord::SchemaMigration Load (0.2ms) SELECT "schema_migrations".* FROM "schema_migrations" +  (0.3ms)  SELECT sql + FROM sqlite_master + WHERE name='index_user_groups_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_user_groups_on_name' AND type='index' + +  (0.2ms) SELECT sql + FROM sqlite_master + WHERE name='index_users_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_users_on_name' AND type='index' + +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "users" ("name") VALUES (?) [["name", "bar555@yandex.ru"]] +  (100.8ms) commit transaction +  (0.1ms) begin transaction + SQL (0.5ms) INSERT INTO "user_groups" ("name") VALUES (?) [["name", "Test"]] +  (83.3ms) commit transaction +  (0.1ms) begin transaction + SQL (0.4ms) INSERT INTO "users_groups" ("user_id", "user_group_id") VALUES (?, ?) [["user_id", 2], ["user_group_id", 2]] +  (101.6ms) commit transaction +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/test"], ["name", "Test page"], ["http_method", "GET"]] +  (112.2ms) commit transaction +  (0.2ms) begin transaction + SQL (0.5ms) INSERT INTO "users_urls" ("url_id", "users_group_id") VALUES (?, ?) [["url_id", 3], ["users_group_id", 2]] +  (98.3ms) commit transaction + SQL (0.6ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."users_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "users_groups"."id" AS t2_r0, "users_groups"."user_group_id" AS t2_r1, "users_groups"."user_id" AS t2_r2, "users"."id" AS t3_r0, "users"."name" AS t3_r1, "users"."api_code" AS t3_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "users_groups" ON "users_groups"."id" = "users_urls"."users_group_id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 2 + UsersGroup Load (0.4ms) SELECT "users_groups".* FROM "users_groups" +  (79.6ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  +  (0.3ms) select sqlite_version(*) +  (107.4ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version") + ActiveRecord::SchemaMigration Load (0.3ms) SELECT "schema_migrations".* FROM "schema_migrations" +Migrating to CreateTables (20160514163909) +  (0.2ms) begin transaction +  (0.8ms) CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar, "api_code" varchar) +  (0.4ms) CREATE INDEX "index_users_on_name" ON "users" ("name") +  (0.4ms) CREATE TABLE "urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "url_pattern" varchar, "name" varchar, "http_method" varchar) +  (0.4ms) CREATE TABLE "user_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)  +  (0.4ms) CREATE INDEX "index_user_groups_on_name" ON "user_groups" ("name") +  (0.5ms) CREATE TABLE "users_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "user_group_id" integer, "user_id" integer)  +  (0.4ms) CREATE TABLE "users_urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "users_group_id" integer, "url_id" integer) + SQL (0.3ms) INSERT INTO "schema_migrations" ("version") VALUES (?) [["version", "20160514163909"]] +  (104.8ms) commit transaction + ActiveRecord::SchemaMigration Load (0.3ms) SELECT "schema_migrations".* FROM "schema_migrations" +  (0.3ms) SELECT sql + FROM sqlite_master + WHERE name='index_user_groups_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_user_groups_on_name' AND type='index' + +  (0.3ms)  SELECT sql + FROM sqlite_master + WHERE name='index_users_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_users_on_name' AND type='index' + +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "users" ("name") VALUES (?) [["name", "guest"]] +  (107.0ms) commit transaction +  (0.1ms) begin transaction + SQL (0.4ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/login"], ["name", "Login page"], ["http_method", "GET"]] +  (97.3ms) commit transaction +  (0.2ms) begin transaction + SQL (0.4ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/oauth/.*"], ["name", "AuthCallback page"], ["http_method", "GET"]] +  (118.3ms) commit transaction +  (0.2ms) begin transaction + SQL (0.4ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/login/logout"], ["name", "Logout page"], ["http_method", "GET"]] +  (85.2ms) commit transaction +  (0.1ms) begin transaction + SQL (0.5ms) INSERT INTO "user_groups" ("name") VALUES (?) [["name", "Guest"]] +  (110.4ms) commit transaction +  (0.2ms) begin transaction + SQL (0.4ms) INSERT INTO "users_groups" ("user_id", "user_group_id") VALUES (?, ?) [["user_id", 1], ["user_group_id", 1]] +  (117.6ms) commit transaction +  (0.1ms) begin transaction + SQL (0.4ms) INSERT INTO "users_urls" ("url_id", "users_group_id") VALUES (?, ?) [["url_id", 1], ["users_group_id", 1]] +  (107.7ms) commit transaction +  (0.2ms) begin transaction + SQL (0.4ms) INSERT INTO "users_urls" ("url_id", "users_group_id") VALUES (?, ?) [["url_id", 2], ["users_group_id", 1]] +  (104.4ms) commit transaction +  (0.2ms) begin transaction + SQL (0.4ms) INSERT INTO "users_urls" ("url_id", "users_group_id") VALUES (?, ?) [["url_id", 3], ["users_group_id", 1]] +  (97.1ms) commit transaction +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "users" ("name") VALUES (?) [["name", "bar555@yandex.ru"]] +  (101.6ms) commit transaction +  (0.1ms) begin transaction + SQL (0.4ms) INSERT INTO "user_groups" ("name") VALUES (?) [["name", "Test"]] +  (101.1ms) commit transaction +  (0.1ms) begin transaction + SQL (0.2ms) INSERT INTO "users_groups" ("user_id", "user_group_id") VALUES (?, ?) [["user_id", 2], ["user_group_id", 2]] +  (102.7ms) commit transaction +  (0.1ms) begin transaction + SQL (0.2ms) INSERT INTO "users_groups" ("user_id", "user_group_id") VALUES (?, ?) [["user_id", 2], ["user_group_id", 1]] +  (93.6ms) commit transaction +  (0.2ms) begin transaction + SQL (0.4ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/test"], ["name", "Test page"], ["http_method", "GET"]] +  (106.4ms) commit transaction +  (0.2ms) begin transaction + SQL (0.4ms) INSERT INTO "users_urls" ("url_id", "users_group_id") VALUES (?, ?) [["url_id", 4], ["users_group_id", 2]] +  (105.1ms) commit transaction +  (0.2ms) begin transaction + SQL (0.5ms) INSERT INTO "users_urls" ("url_id", "users_group_id") VALUES (?, ?) [["url_id", 4], ["users_group_id", 3]] +  (107.3ms) commit transaction + SQL (0.7ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."users_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "users_groups"."id" AS t2_r0, "users_groups"."user_group_id" AS t2_r1, "users_groups"."user_id" AS t2_r2, "users"."id" AS t3_r0, "users"."name" AS t3_r1, "users"."api_code" AS t3_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "users_groups" ON "users_groups"."id" = "users_urls"."users_group_id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 2 + UserGroup Load (0.5ms) SELECT "user_groups".* FROM "user_groups" + UsersGroup Load (0.4ms) SELECT "users_groups".* FROM "users_groups" +  (88.1ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  +  (0.3ms) select sqlite_version(*) +  (114.4ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version") + ActiveRecord::SchemaMigration Load (0.3ms) SELECT "schema_migrations".* FROM "schema_migrations" +Migrating to CreateTables (20160514163909) +  (0.2ms) begin transaction +  (0.8ms) CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar, "api_code" varchar) +  (0.4ms) CREATE INDEX "index_users_on_name" ON "users" ("name") +  (0.4ms) CREATE TABLE "urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "url_pattern" varchar, "name" varchar, "http_method" varchar) +  (0.4ms) CREATE TABLE "user_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)  +  (0.4ms) CREATE INDEX "index_user_groups_on_name" ON "user_groups" ("name") +  (0.4ms) CREATE TABLE "users_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "user_group_id" integer, "user_id" integer)  +  (0.4ms) CREATE TABLE "users_urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "users_group_id" integer, "url_id" integer) + SQL (0.2ms) INSERT INTO "schema_migrations" ("version") VALUES (?) [["version", "20160514163909"]] +  (98.3ms) commit transaction + ActiveRecord::SchemaMigration Load (0.3ms) SELECT "schema_migrations".* FROM "schema_migrations" +  (0.4ms) SELECT sql + FROM sqlite_master + WHERE name='index_user_groups_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_user_groups_on_name' AND type='index' + +  (0.3ms)  SELECT sql + FROM sqlite_master + WHERE name='index_users_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_users_on_name' AND type='index' + +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "users" ("name") VALUES (?) [["name", "guest"]] +  (105.7ms) commit transaction +  (0.1ms) begin transaction + SQL (0.4ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/login"], ["name", "Login page"], ["http_method", "GET"]] +  (102.0ms) commit transaction +  (0.2ms) begin transaction + SQL (0.3ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/oauth/.*"], ["name", "AuthCallback page"], ["http_method", "GET"]] +  (102.8ms) commit transaction +  (0.2ms) begin transaction + SQL (0.4ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/login/logout"], ["name", "Logout page"], ["http_method", "GET"]] +  (86.2ms) commit transaction +  (0.1ms) begin transaction + SQL (0.4ms) INSERT INTO "user_groups" ("name") VALUES (?) [["name", "Guest"]] +  (83.9ms) commit transaction +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "users_groups" ("user_id", "user_group_id") VALUES (?, ?) [["user_id", 1], ["user_group_id", 1]] +  (98.9ms) commit transaction +  (0.2ms) begin transaction + SQL (0.5ms) INSERT INTO "users_urls" ("url_id", "users_group_id") VALUES (?, ?) [["url_id", 1], ["users_group_id", 1]] +  (96.5ms) commit transaction +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "users_urls" ("url_id", "users_group_id") VALUES (?, ?) [["url_id", 2], ["users_group_id", 1]] +  (100.3ms) commit transaction +  (0.2ms) begin transaction + SQL (0.4ms) INSERT INTO "users_urls" ("url_id", "users_group_id") VALUES (?, ?) [["url_id", 3], ["users_group_id", 1]] +  (98.3ms) commit transaction +  (0.2ms) begin transaction + SQL (0.4ms) INSERT INTO "users" ("name") VALUES (?) [["name", "bar555@yandex.ru"]] +  (98.0ms) commit transaction +  (0.2ms) begin transaction + SQL (0.4ms) INSERT INTO "user_groups" ("name") VALUES (?) [["name", "Test"]] +  (100.7ms) commit transaction +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "users_groups" ("user_id", "user_group_id") VALUES (?, ?) [["user_id", 2], ["user_group_id", 2]] +  (89.6ms) commit transaction +  (0.2ms) begin transaction + SQL (0.4ms) INSERT INTO "users_groups" ("user_id", "user_group_id") VALUES (?, ?) [["user_id", 2], ["user_group_id", 1]] +  (102.2ms) commit transaction +  (0.2ms) begin transaction + SQL (0.4ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/test"], ["name", "Test page"], ["http_method", "GET"]] +  (85.8ms) commit transaction +  (0.2ms) begin transaction + SQL (0.5ms) INSERT INTO "users_urls" ("url_id", "users_group_id") VALUES (?, ?) [["url_id", 4], ["users_group_id", 2]] +  (102.8ms) commit transaction +  (87.7ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  +  (0.3ms) select sqlite_version(*) +  (97.9ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version") + ActiveRecord::SchemaMigration Load (0.3ms) SELECT "schema_migrations".* FROM "schema_migrations" +Migrating to CreateTables (20160514163909) +  (0.2ms) begin transaction +  (0.8ms) CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar, "api_code" varchar) +  (0.4ms) CREATE INDEX "index_users_on_name" ON "users" ("name") +  (0.4ms) CREATE TABLE "urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "url_pattern" varchar, "name" varchar, "http_method" varchar) +  (0.4ms) CREATE TABLE "user_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)  +  (0.4ms) CREATE INDEX "index_user_groups_on_name" ON "user_groups" ("name") +  (0.4ms) CREATE TABLE "users_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "user_group_id" integer, "user_id" integer)  +  (0.4ms) CREATE TABLE "users_urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "user_group_id" integer, "url_id" integer) + SQL (0.4ms) INSERT INTO "schema_migrations" ("version") VALUES (?) [["version", "20160514163909"]] +  (122.2ms) commit transaction + ActiveRecord::SchemaMigration Load (0.3ms) SELECT "schema_migrations".* FROM "schema_migrations" +  (0.4ms) SELECT sql + FROM sqlite_master + WHERE name='index_user_groups_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_user_groups_on_name' AND type='index' + +  (0.3ms)  SELECT sql + FROM sqlite_master + WHERE name='index_users_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_users_on_name' AND type='index' + +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "users" ("name") VALUES (?) [["name", "guest"]] +  (106.5ms) commit transaction +  (0.1ms) begin transaction + SQL (0.4ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/login"], ["name", "Login page"], ["http_method", "GET"]] +  (112.8ms) commit transaction +  (0.2ms) begin transaction + SQL (0.3ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/oauth/.*"], ["name", "AuthCallback page"], ["http_method", "GET"]] +  (96.1ms) commit transaction +  (0.1ms) begin transaction + SQL (0.5ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/login/logout"], ["name", "Logout page"], ["http_method", "GET"]] +  (105.1ms) commit transaction +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "user_groups" ("name") VALUES (?) [["name", "Guest"]] +  (119.7ms) commit transaction +  (0.1ms) begin transaction + SQL (0.5ms) INSERT INTO "users_groups" ("user_id", "user_group_id") VALUES (?, ?) [["user_id", 1], ["user_group_id", 1]] +  (92.0ms) commit transaction +  (0.2ms) begin transaction + SQL (0.5ms) INSERT INTO "users_urls" ("url_id", "user_group_id") VALUES (?, ?) [["url_id", 1], ["user_group_id", 1]] +  (88.2ms) commit transaction +  (0.1ms) begin transaction + SQL (0.2ms) INSERT INTO "users_urls" ("url_id", "user_group_id") VALUES (?, ?) [["url_id", 2], ["user_group_id", 1]] +  (84.8ms) commit transaction +  (0.2ms) begin transaction + SQL (0.5ms) INSERT INTO "users_urls" ("url_id", "user_group_id") VALUES (?, ?) [["url_id", 3], ["user_group_id", 1]] +  (98.7ms) commit transaction + SQL (0.4ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."user_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "user_groups"."id" AS t2_r0, "user_groups"."name" AS t2_r1, "users_groups"."id" AS t3_r0, "users_groups"."user_group_id" AS t3_r1, "users_groups"."user_id" AS t3_r2, "users"."id" AS t4_r0, "users"."name" AS t4_r1, "users"."api_code" AS t4_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "user_groups" ON "user_groups"."id" = "users_urls"."user_group_id" LEFT OUTER JOIN "users_groups" ON "users_groups"."user_group_id" = "user_groups"."id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 1 +  (0.2ms) begin transaction + SQL (0.6ms) INSERT INTO "users" ("name") VALUES (?) [["name", "bar555@yandex.ru"]] +  (101.0ms) commit transaction +  (0.2ms) begin transaction + SQL (0.6ms) INSERT INTO "user_groups" ("name") VALUES (?) [["name", "Test"]] +  (94.2ms) commit transaction +  (0.2ms) begin transaction + SQL (0.5ms) INSERT INTO "users_groups" ("user_id", "user_group_id") VALUES (?, ?) [["user_id", 2], ["user_group_id", 2]] +  (104.0ms) commit transaction +  (0.2ms) begin transaction + SQL (0.5ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/test"], ["name", "Test page"], ["http_method", "GET"]] +  (90.1ms) commit transaction +  (0.2ms) begin transaction + SQL (0.5ms) INSERT INTO "users_urls" ("url_id", "user_group_id") VALUES (?, ?) [["url_id", 4], ["user_group_id", 2]] +  (88.5ms) commit transaction + SQL (1.0ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."user_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "user_groups"."id" AS t2_r0, "user_groups"."name" AS t2_r1, "users_groups"."id" AS t3_r0, "users_groups"."user_group_id" AS t3_r1, "users_groups"."user_id" AS t3_r2, "users"."id" AS t4_r0, "users"."name" AS t4_r1, "users"."api_code" AS t4_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "user_groups" ON "user_groups"."id" = "users_urls"."user_group_id" LEFT OUTER JOIN "users_groups" ON "users_groups"."user_group_id" = "user_groups"."id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 1 + SQL (0.9ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."user_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "user_groups"."id" AS t2_r0, "user_groups"."name" AS t2_r1, "users_groups"."id" AS t3_r0, "users_groups"."user_group_id" AS t3_r1, "users_groups"."user_id" AS t3_r2, "users"."id" AS t4_r0, "users"."name" AS t4_r1, "users"."api_code" AS t4_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "user_groups" ON "user_groups"."id" = "users_urls"."user_group_id" LEFT OUTER JOIN "users_groups" ON "users_groups"."user_group_id" = "user_groups"."id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 2 + User Load (0.1ms) SELECT "users".* FROM "users" + User Load (0.5ms) SELECT "users".* FROM "users" INNER JOIN "users_groups" ON "users_groups"."user_id" = "users"."id" + User Load (0.5ms) SELECT "users".* FROM "users" INNER JOIN "users_groups" ON "users_groups"."user_id" = "users"."id" +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "users_groups" ("user_id", "user_group_id") VALUES (?, ?) [["user_id", 2], ["user_group_id", 1]] +  (96.3ms) commit transaction + SQL (0.4ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."user_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "user_groups"."id" AS t2_r0, "user_groups"."name" AS t2_r1, "users_groups"."id" AS t3_r0, "users_groups"."user_group_id" AS t3_r1, "users_groups"."user_id" AS t3_r2, "users"."id" AS t4_r0, "users"."name" AS t4_r1, "users"."api_code" AS t4_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "user_groups" ON "user_groups"."id" = "users_urls"."user_group_id" LEFT OUTER JOIN "users_groups" ON "users_groups"."user_group_id" = "user_groups"."id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 2 +  (116.2ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  +  (0.2ms) select sqlite_version(*) +  (98.7ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version") + ActiveRecord::SchemaMigration Load (0.3ms) SELECT "schema_migrations".* FROM "schema_migrations" +Migrating to CreateTables (20160514163909) +  (0.1ms) begin transaction +  (0.8ms) CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar, "api_code" varchar) +  (0.3ms) CREATE INDEX "index_users_on_name" ON "users" ("name") +  (0.3ms) CREATE TABLE "urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "url_pattern" varchar, "name" varchar, "http_method" varchar) +  (0.4ms) CREATE TABLE "user_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)  +  (0.4ms) CREATE INDEX "index_user_groups_on_name" ON "user_groups" ("name") +  (0.4ms) CREATE TABLE "users_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "user_group_id" integer, "user_id" integer)  +  (0.4ms) CREATE TABLE "users_urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "user_group_id" integer, "url_id" integer) + SQL (0.3ms) INSERT INTO "schema_migrations" ("version") VALUES (?) [["version", "20160514163909"]] +  (98.7ms) commit transaction + ActiveRecord::SchemaMigration Load (0.3ms) SELECT "schema_migrations".* FROM "schema_migrations" +  (0.3ms) SELECT sql + FROM sqlite_master + WHERE name='index_user_groups_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_user_groups_on_name' AND type='index' + +  (0.2ms)  SELECT sql + FROM sqlite_master + WHERE name='index_users_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_users_on_name' AND type='index' + +  (0.1ms) begin transaction + SQL (0.4ms) INSERT INTO "users" ("name") VALUES (?) [["name", "guest"]] +  (99.7ms) commit transaction +  (0.0ms) begin transaction + SQL (0.2ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/login"], ["name", "Login page"], ["http_method", "GET"]] +  (107.1ms) commit transaction +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/oauth/.*"], ["name", "AuthCallback page"], ["http_method", "GET"]] +  (97.9ms) commit transaction +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/login/logout"], ["name", "Logout page"], ["http_method", "GET"]] +  (96.5ms) commit transaction +  (0.1ms) begin transaction + SQL (0.4ms) INSERT INTO "user_groups" ("name") VALUES (?) [["name", "Guest"]] +  (100.8ms) commit transaction +  (0.1ms) begin transaction + SQL (0.5ms) INSERT INTO "users_groups" ("user_id", "user_group_id") VALUES (?, ?) [["user_id", 1], ["user_group_id", 1]] +  (98.3ms) commit transaction +  (0.1ms) begin transaction + SQL (0.5ms) INSERT INTO "users_urls" ("url_id", "user_group_id") VALUES (?, ?) [["url_id", 1], ["user_group_id", 1]] +  (96.5ms) commit transaction +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "users_urls" ("url_id", "user_group_id") VALUES (?, ?) [["url_id", 2], ["user_group_id", 1]] +  (82.7ms) commit transaction +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "users_urls" ("url_id", "user_group_id") VALUES (?, ?) [["url_id", 3], ["user_group_id", 1]] +  (117.5ms) commit transaction +  (0.2ms) begin transaction + SQL (0.5ms) INSERT INTO "users" ("name") VALUES (?) [["name", "bar555@yandex.ru"]] +  (114.2ms) commit transaction +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "user_groups" ("name") VALUES (?) [["name", "Test"]] +  (119.8ms) commit transaction +  (0.2ms) begin transaction + SQL (0.4ms) INSERT INTO "users_groups" ("user_id", "user_group_id") VALUES (?, ?) [["user_id", 2], ["user_group_id", 2]] +  (194.3ms) commit transaction +  (0.1ms) begin transaction + SQL (0.3ms) INSERT INTO "users_groups" ("user_id", "user_group_id") VALUES (?, ?) [["user_id", 2], ["user_group_id", 1]] +  (115.2ms) commit transaction +  (0.2ms) begin transaction + SQL (0.5ms) INSERT INTO "urls" ("url_pattern", "name", "http_method") VALUES (?, ?, ?) [["url_pattern", "^/test"], ["name", "Test page"], ["http_method", "GET"]] +  (119.1ms) commit transaction +  (0.2ms) begin transaction + SQL (0.5ms) INSERT INTO "users_urls" ("url_id", "user_group_id") VALUES (?, ?) [["url_id", 4], ["user_group_id", 2]] +  (93.1ms) commit transaction + SQL (0.8ms) SELECT "urls"."id" AS t0_r0, "urls"."url_pattern" AS t0_r1, "urls"."name" AS t0_r2, "urls"."http_method" AS t0_r3, "users_urls"."id" AS t1_r0, "users_urls"."user_group_id" AS t1_r1, "users_urls"."url_id" AS t1_r2, "user_groups"."id" AS t2_r0, "user_groups"."name" AS t2_r1, "users_groups"."id" AS t3_r0, "users_groups"."user_group_id" AS t3_r1, "users_groups"."user_id" AS t3_r2, "users"."id" AS t4_r0, "users"."name" AS t4_r1, "users"."api_code" AS t4_r2 FROM "urls" LEFT OUTER JOIN "users_urls" ON "users_urls"."url_id" = "urls"."id" LEFT OUTER JOIN "user_groups" ON "user_groups"."id" = "users_urls"."user_group_id" LEFT OUTER JOIN "users_groups" ON "users_groups"."user_group_id" = "user_groups"."id" LEFT OUTER JOIN "users" ON "users"."id" = "users_groups"."user_id" WHERE "users_groups"."user_id" = 2 + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" +  (0.1ms)  SELECT sql + FROM sqlite_master + WHERE name='index_user_groups_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_user_groups_on_name' AND type='index' + +  (0.1ms) SELECT sql + FROM sqlite_master + WHERE name='index_users_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_users_on_name' AND type='index' + +  (104.4ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  +  (0.3ms) select sqlite_version(*) +  (97.7ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version") + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" +Migrating to CreateTables (20160514163909) +  (0.1ms) begin transaction +  (0.5ms) CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar, "api_code" varchar) +  (0.2ms) CREATE INDEX "index_users_on_name" ON "users" ("name") +  (0.2ms) CREATE TABLE "urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "url_pattern" varchar, "name" varchar, "http_method" varchar) +  (0.2ms) CREATE TABLE "user_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)  +  (0.2ms) CREATE INDEX "index_user_groups_on_name" ON "user_groups" ("name") +  (0.2ms) CREATE TABLE "users_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "user_group_id" integer, "user_id" integer)  +  (0.2ms) CREATE TABLE "users_urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "user_group_id" integer, "url_id" integer) + SQL (0.2ms) INSERT INTO "schema_migrations" ("version") VALUES (?) [["version", "20160514163909"]] +  (98.7ms) commit transaction + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" +  (0.2ms) SELECT sql + FROM sqlite_master + WHERE name='index_user_groups_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_user_groups_on_name' AND type='index' + +  (0.2ms)  SELECT sql + FROM sqlite_master + WHERE name='index_users_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_users_on_name' AND type='index' + +  (99.8ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  +  (0.1ms) select sqlite_version(*) +  (99.5ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version") + ActiveRecord::SchemaMigration Load (0.3ms) SELECT "schema_migrations".* FROM "schema_migrations" +Migrating to CreateTables (20160514163909) +  (0.1ms) begin transaction +  (0.9ms) CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar, "api_code" varchar) +  (0.4ms) CREATE INDEX "index_users_on_name" ON "users" ("name") +  (0.4ms) CREATE TABLE "urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "url_pattern" varchar, "name" varchar, "http_method" varchar) +  (0.4ms) CREATE TABLE "user_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar)  +  (0.4ms) CREATE INDEX "index_user_groups_on_name" ON "user_groups" ("name") +  (0.4ms) CREATE TABLE "users_groups" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "user_group_id" integer, "user_id" integer)  +  (0.4ms) CREATE TABLE "users_urls" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "user_group_id" integer, "url_id" integer) + SQL (0.3ms) INSERT INTO "schema_migrations" ("version") VALUES (?) [["version", "20160514163909"]] +  (97.1ms) commit transaction + ActiveRecord::SchemaMigration Load (0.1ms) SELECT "schema_migrations".* FROM "schema_migrations" +  (0.2ms) SELECT sql + FROM sqlite_master + WHERE name='index_user_groups_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_user_groups_on_name' AND type='index' + +  (0.2ms)  SELECT sql + FROM sqlite_master + WHERE name='index_users_on_name' AND type='index' + UNION ALL + SELECT sql + FROM sqlite_temp_master + WHERE name='index_users_on_name' AND type='index' +