(8.0ms) CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar NOT NULL, "uid" varchar NOT NULL, "email" varchar NOT NULL, "remotely_signed_out" boolean, "permissions" text, "organisation_slug" varchar, "organisation_content_id" varchar, "disabled" boolean DEFAULT 'f')   (6.1ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  (0.1ms) select sqlite_version(*)  (4.3ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version") Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:16:24 +0000 Processing by ExampleController#this_requires_signin_permission as JSON User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]] User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."email" = ? ORDER BY "users"."id" ASC LIMIT 1 [["email", "test@example-client.com"]]  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions", "disabled") VALUES (?, ?, ?, ?, ?) [["uid", "integration-uid"], ["email", "test@example-client.com"], ["name", "Test User"], ["permissions", "---\n- signin\n"], ["disabled", nil]]  (7.0ms) commit transaction User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.0ms) begin transaction  (0.0ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction SQL (0.2ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "f"], ["id", 1]]  (5.4ms) commit transaction Rendered text template (0.0ms) Completed 200 OK in 305ms (Views: 4.0ms | ActiveRecord: 13.9ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:25 +0000 Processing by ExampleController#restricted as JSON Completed in 19ms (ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:25 +0000 Processing by ExampleController#restricted as JSON User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.1ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.0ms) begin transaction  (0.0ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.0ms) begin transaction  (0.0ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) commit transaction Rendered text template (0.0ms) Completed 200 OK in 59ms (Views: 0.3ms | ActiveRecord: 0.7ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:25 +0000 Processing by ExampleController#restricted as JSON Completed in 20ms (ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:25 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:25 +0000 Started GET "/auth/gds/callback?code=d92f84011a50094b7aed7bd36bb2dc487a6d8d8d005cc75a11943725807db0da&state=f6c8c683cebd89d812d85a1c930e391a9aab133f146668e7" for 127.0.0.1 at 2017-12-08 09:16:34 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"d92f84011a50094b7aed7bd36bb2dc487a6d8d8d005cc75a11943725807db0da", "state"=>"f6c8c683cebd89d812d85a1c930e391a9aab133f146668e7"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "disabled" = ? WHERE "users"."id" = ? [["disabled", "f"], ["id", 1]]  (14.5ms) commit transaction  (0.0ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 19ms (ActiveRecord: 15.0ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:34 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 3ms (Views: 0.3ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:34 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:34 +0000 Started GET "/auth/gds/callback?code=af47fb9789619f5fc4bcffc8416a23b28e4f54616c0101453774849c36d0c8d6&state=c0bccfcfa703158f83a203f637344f9db2dde880e71eb7f9" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"af47fb9789619f5fc4bcffc8416a23b28e4f54616c0101453774849c36d0c8d6", "state"=>"c0bccfcfa703158f83a203f637344f9db2dde880e71eb7f9"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 4ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Started GET "/auth/gds/callback?code=78cb632dba24cdf695bf02e022bfda3f65682e9c5ebcd4c7c4328553a77eb64b&state=7371ad93aa4aa519139e15f9ed044f29aa8e83de479e2013" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"78cb632dba24cdf695bf02e022bfda3f65682e9c5ebcd4c7c4328553a77eb64b", "state"=>"7371ad93aa4aa519139e15f9ed044f29aa8e83de479e2013"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 4ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.1ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Started GET "/auth/gds/callback?code=f3ad2550047bcd71f432a75c3869242cc365dddc0619d99fdaf096d62c22a309&state=aa253c92054a27a7cade43eea0c68465c648def1d4c66039" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"f3ad2550047bcd71f432a75c3869242cc365dddc0619d99fdaf096d62c22a309", "state"=>"aa253c92054a27a7cade43eea0c68465c648def1d4c66039"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 4ms (ActiveRecord: 0.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.1ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Started GET "/auth/gds/callback?code=f01dd1d5ac1fe419835f1697ce79b98eb358155d22085876aaf1a8d63f8a0436&state=d6aad2ea181e08b726c78d9ad6856ef343f9c746f2325c0d" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"f01dd1d5ac1fe419835f1697ce79b98eb358155d22085876aaf1a8d63f8a0436", "state"=>"d6aad2ea181e08b726c78d9ad6856ef343f9c746f2325c0d"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.2ms | ActiveRecord: 0.1ms) Started GET "/" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Processing by ExampleController#index as HTML Rendered text template (0.0ms) Completed 200 OK in 0ms (Views: 0.2ms | ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Started GET "/auth/gds/callback?code=c691d9611ba30187c803f3d2f761a2e0b841967309cbb1f5a3964e933606293d&state=91c1b1597d8c03818dc1fb949c23da49e990b81f3fe4462b" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"c691d9611ba30187c803f3d2f761a2e0b841967309cbb1f5a3964e933606293d", "state"=>"91c1b1597d8c03818dc1fb949c23da49e990b81f3fe4462b"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 4ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-09 05:21:35 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-09 05:21:35 +0000 Started GET "/auth/gds/callback?code=05aeadc5aa44d6406fc554a6343d9872bbeae0feea9d34ed1df59d17aa1d512d&state=682f93024676f2802e2975bfb17885410678cf7c1ce42674" for 127.0.0.1 at 2017-12-09 05:21:35 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"05aeadc5aa44d6406fc554a6343d9872bbeae0feea9d34ed1df59d17aa1d512d", "state"=>"682f93024676f2802e2975bfb17885410678cf7c1ce42674"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-09 05:21:35 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.2ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:35 +0000 Started GET "/auth/gds/callback?code=1a6cfec97fe11e2461a71ee8bdbf57aea3765d824dd4652fa8357e958b885ec4&state=6f5d43549f09de07fa0c7bfa6d61f40398e8f4cb21674d78" for 127.0.0.1 at 2017-12-08 09:16:36 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"1a6cfec97fe11e2461a71ee8bdbf57aea3765d824dd4652fa8357e958b885ec4", "state"=>"6f5d43549f09de07fa0c7bfa6d61f40398e8f4cb21674d78"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.1ms) commit transaction  (0.0ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 4ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:36 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-09 05:11:36 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.2ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:36 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:36 +0000 Started GET "/auth/gds/callback?code=d27c2026d4977688b3481a6299783fbb7e5f5dfe7fa10530c6af91d59200deaf&state=bf5cebd4bda79ef168638e74ba840749c0a3e34e5a08ec17" for 127.0.0.1 at 2017-12-08 09:16:36 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"d27c2026d4977688b3481a6299783fbb7e5f5dfe7fa10530c6af91d59200deaf", "state"=>"bf5cebd4bda79ef168638e74ba840749c0a3e34e5a08ec17"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.1ms) commit transaction  (0.0ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 4ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:36 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-09 05:21:36 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-09 05:21:36 +0000 Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:36 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:36 +0000 Started GET "/auth/gds/callback?code=898f4ce3a736f6e2010ff4ff80658592debe844c05212d499a23fdde59359d28&state=38e017ec36bb74ebb64d287aead6899b070a94442f6e9328" for 127.0.0.1 at 2017-12-08 09:16:36 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"898f4ce3a736f6e2010ff4ff80658592debe844c05212d499a23fdde59359d28", "state"=>"38e017ec36bb74ebb64d287aead6899b070a94442f6e9328"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 4ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:36 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.1ms) User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."email" = ? ORDER BY "users"."id" ASC LIMIT 1 [["email", "test@example-client.com"]]  (0.1ms) begin transaction SQL (0.1ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "t"], ["id", 1]]  (6.4ms) commit transaction Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:36 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Authenticating with gds_sso strategy Completed in 1ms (ActiveRecord: 0.1ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:36 +0000 Started GET "/auth/gds/callback?code=1536f0c355d3e69ab067eb9b277ca8a1e55a994f351cdd0a4000216ec8b9373d&state=a5a7bdcf03de4298f063b99dd9af9f9dc38e55c46e1250af" for 127.0.0.1 at 2017-12-08 09:16:37 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"1536f0c355d3e69ab067eb9b277ca8a1e55a994f351cdd0a4000216ec8b9373d", "state"=>"a5a7bdcf03de4298f063b99dd9af9f9dc38e55c46e1250af"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction SQL (0.1ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "f"], ["id", 1]]  (4.9ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 9ms (ActiveRecord: 5.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:37 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.1ms)  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d38537"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (4.2ms) commit transaction  (0.0ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d39615"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (4.8ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d38537"} Rendered /var/lib/jenkins/workspace/gds-sso_master-7MNGHJETCC7W4ACW54GEWCZ7RU2E7EW7NZYEBGCKG2QG3YLPM53Q/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.2ms) Completed 403 Forbidden in 7ms (Views: 6.2ms | ActiveRecord: 0.0ms)  (0.0ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d35045"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (5.4ms) commit transaction  (0.0ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d38178"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (4.9ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d35045"} User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "a1s2d35045"]]  (0.0ms) begin transaction SQL (0.2ms) UPDATE "users" SET "email" = ?, "name" = ?, "permissions" = ?, "organisation_slug" = ?, "organisation_content_id" = ? WHERE "users"."id" = ? [["email", "user@domain.com"], ["name", "Joshua Marshall"], ["permissions", "---\n- signin\n- new permission\n"], ["organisation_slug", "justice-league"], ["organisation_content_id", "aae1319e-5788-4677-998c-f1a53af528d0"], ["id", 4]]  (5.6ms) commit transaction Completed 200 OK in 9ms (ActiveRecord: 5.9ms) User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 4]]  (0.0ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d3648"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (8.7ms) commit transaction  (0.0ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d336"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (5.1ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"nonexistent-user"} User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "nonexistent-user"]] Completed 200 OK in 1ms (ActiveRecord: 0.1ms)  (0.1ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d35314"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (4.1ms) commit transaction  (0.0ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d34145"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (5.1ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d35314"} User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "a1s2d35314"]]  (0.1ms) begin transaction SQL (0.1ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "t"], ["id", 8]]  (4.8ms) commit transaction Completed 200 OK in 7ms (ActiveRecord: 5.1ms) User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 8]]  (0.0ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d3145"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (7.6ms) commit transaction  (0.0ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d38931"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (4.2ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d3145"} Rendered /var/lib/jenkins/workspace/gds-sso_master-7MNGHJETCC7W4ACW54GEWCZ7RU2E7EW7NZYEBGCKG2QG3YLPM53Q/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.0ms) Completed 403 Forbidden in 1ms (Views: 0.4ms | ActiveRecord: 0.0ms) User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "asd"]] User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."email" = ? ORDER BY "users"."id" ASC LIMIT 1 [["email", "user@example.com"]]  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions", "organisation_slug", "organisation_content_id", "disabled") VALUES (?, ?, ?, ?, ?, ?, ?) [["uid", "asd"], ["email", "user@example.com"], ["name", "A Name"], ["permissions", "---\n- signin\n"], ["organisation_slug", "hmrc"], ["organisation_content_id", "67a2b78d-eee3-45b3-80e2-792e7f71cecc"], ["disabled", nil]]  (5.3ms) commit transaction User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "asd"]]  (0.0ms) begin transaction  (0.0ms) commit transaction  (7.9ms) CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar NOT NULL, "uid" varchar NOT NULL, "email" varchar NOT NULL, "remotely_signed_out" boolean, "permissions" text, "organisation_slug" varchar, "organisation_content_id" varchar, "disabled" boolean DEFAULT 'f')  (6.3ms) CREATE TABLE "ar_internal_metadata" ("key" varchar NOT NULL PRIMARY KEY, "value" varchar, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) ActiveRecord::InternalMetadata Load (0.1ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = ? LIMIT ? [["key", :environment], ["LIMIT", 1]]  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["key", "environment"], ["value", "test"], ["created_at", 2017-12-08 09:16:47 UTC], ["updated_at", 2017-12-08 09:16:47 UTC]]  (6.6ms) commit transaction  (4.9ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL PRIMARY KEY) ActiveRecord::InternalMetadata Load (0.1ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = ? LIMIT ? [["key", :environment], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.0ms) commit transaction User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "asd"], ["LIMIT", 1]] User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."email" = ? ORDER BY "users"."id" ASC LIMIT ? [["email", "user@example.com"], ["LIMIT", 1]]  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions", "organisation_slug", "organisation_content_id", "disabled") VALUES (?, ?, ?, ?, ?, ?, ?) [["name", "A Name"], ["uid", "asd"], ["email", "user@example.com"], ["permissions", "---\n- signin\n"], ["organisation_slug", "hmrc"], ["organisation_content_id", "67a2b78d-eee3-45b3-80e2-792e7f71cecc"], ["disabled", nil]]  (8.4ms) commit transaction User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "asd"], ["LIMIT", 1]]  (0.0ms) begin transaction  (0.1ms) commit transaction  (0.0ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "Moshua Jarshall"], ["uid", "a1s2d34536"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]  (5.4ms) commit transaction  (0.0ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "SSO Push user"], ["uid", "a1s2d36440"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (6.4ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d34536"} Rendering /var/lib/jenkins/workspace/gds-sso_master-7MNGHJETCC7W4ACW54GEWCZ7RU2E7EW7NZYEBGCKG2QG3YLPM53Q/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised Rendered /var/lib/jenkins/workspace/gds-sso_master-7MNGHJETCC7W4ACW54GEWCZ7RU2E7EW7NZYEBGCKG2QG3YLPM53Q/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.2ms) Completed 403 Forbidden in 10ms (Views: 9.6ms | ActiveRecord: 0.0ms)  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "Moshua Jarshall"], ["uid", "a1s2d32239"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]  (5.8ms) commit transaction  (0.0ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "SSO Push user"], ["uid", "a1s2d31177"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (4.7ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d32239"} User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "a1s2d32239"], ["LIMIT", 1]]  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "email" = ?, "name" = ?, "permissions" = ?, "organisation_slug" = ?, "organisation_content_id" = ? WHERE "users"."id" = ? [["email", "user@domain.com"], ["name", "Joshua Marshall"], ["permissions", "---\n- signin\n- new permission\n"], ["organisation_slug", "justice-league"], ["organisation_content_id", "aae1319e-5788-4677-998c-f1a53af528d0"], ["id", 4]]  (6.2ms) commit transaction Completed 200 OK in 10ms (ActiveRecord: 6.6ms) User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT ? [["id", 4], ["LIMIT", 1]]  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "Moshua Jarshall"], ["uid", "a1s2d34143"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]  (5.0ms) commit transaction  (0.0ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "SSO Push user"], ["uid", "a1s2d31147"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (5.6ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d34143"} User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "a1s2d34143"], ["LIMIT", 1]]  (0.0ms) begin transaction SQL (0.1ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", true], ["id", 6]]  (5.3ms) commit transaction Completed 200 OK in 7ms (ActiveRecord: 5.5ms) User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT ? [["id", 6], ["LIMIT", 1]]  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "Moshua Jarshall"], ["uid", "a1s2d37829"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]  (5.1ms) commit transaction  (0.0ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "SSO Push user"], ["uid", "a1s2d37721"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (4.9ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d37829"} Rendering /var/lib/jenkins/workspace/gds-sso_master-7MNGHJETCC7W4ACW54GEWCZ7RU2E7EW7NZYEBGCKG2QG3YLPM53Q/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised Rendered /var/lib/jenkins/workspace/gds-sso_master-7MNGHJETCC7W4ACW54GEWCZ7RU2E7EW7NZYEBGCKG2QG3YLPM53Q/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.0ms) Completed 403 Forbidden in 1ms (Views: 0.6ms | ActiveRecord: 0.0ms)  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "Moshua Jarshall"], ["uid", "a1s2d33038"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]  (5.2ms) commit transaction  (0.0ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "SSO Push user"], ["uid", "a1s2d33797"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (4.0ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"nonexistent-user"} User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "nonexistent-user"], ["LIMIT", 1]] Completed 200 OK in 1ms (ActiveRecord: 0.1ms) Started GET "/" for 127.0.0.1 at 2017-12-08 09:16:48 +0000 Processing by ExampleController#index as HTML Rendering text template Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 1.0ms | ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:48 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 7ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:48 +0000 Started GET "/auth/gds/callback?code=a540b134e03a1cf4285c1aeedbdd48127f6b4f7783e9e5d98f9831c66a39d908&state=ab157cfff8d5c2d7e5437d5181384eebe5b4bac526386278" for 127.0.0.1 at 2017-12-08 09:16:48 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"a540b134e03a1cf4285c1aeedbdd48127f6b4f7783e9e5d98f9831c66a39d908", "state"=>"ab157cfff8d5c2d7e5437d5181384eebe5b4bac526386278"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]] User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."email" = ? ORDER BY "users"."id" ASC LIMIT ? [["email", "test@example-client.com"], ["LIMIT", 1]]  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "Test User"], ["uid", "integration-uid"], ["email", "test@example-client.com"], ["permissions", "---\n- signin\n"]]  (5.9ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", false], ["id", 12]]  (4.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 15ms (ActiveRecord: 10.8ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:48 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.2ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:16:48 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:48 +0000 Started GET "/auth/gds/callback?code=926668ccbab6eded785b4638585f1c4a8a8b5f2856f6b35fc11508f4daa9bb4b&state=8de071844bdac351ed218a4c4eaf9e6348cfb58f51358fc3" for 127.0.0.1 at 2017-12-08 09:16:48 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"926668ccbab6eded785b4638585f1c4a8a8b5f2856f6b35fc11508f4daa9bb4b", "state"=>"8de071844bdac351ed218a4c4eaf9e6348cfb58f51358fc3"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.0ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:16:48 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.1ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:16:48 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:48 +0000 Started GET "/auth/gds/callback?code=08640100dab3990aa91c70de73b834800ed7c557848f9e8be3687a55b16026c4&state=231c81ff35e4db84ac997834586691c6a1c0fd829c0ca8f6" for 127.0.0.1 at 2017-12-08 09:16:48 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"08640100dab3990aa91c70de73b834800ed7c557848f9e8be3687a55b16026c4", "state"=>"231c81ff35e4db84ac997834586691c6a1c0fd829c0ca8f6"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.0ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:16:48 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:48 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:48 +0000 Started GET "/auth/gds/callback?code=6cbb7ec7ec3bfd123e1f313ae0298209695c81fcf92137be4878bea828cf451f&state=4d9441cb36807b4262d29e06c7b3d0844eb6fa83533ae93e" for 127.0.0.1 at 2017-12-08 09:16:49 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"6cbb7ec7ec3bfd123e1f313ae0298209695c81fcf92137be4878bea828cf451f", "state"=>"4d9441cb36807b4262d29e06c7b3d0844eb6fa83533ae93e"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.0ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:49 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:49 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:49 +0000 Started GET "/auth/gds/callback?code=31fb37a8b21c9b4eb7ed9da0f1506596c06eadb989970646e07a829aeaccae5b&state=250b7a8cb4dc7606b675902a52934a61b84a11d6899a5af1" for 127.0.0.1 at 2017-12-08 09:16:49 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"31fb37a8b21c9b4eb7ed9da0f1506596c06eadb989970646e07a829aeaccae5b", "state"=>"250b7a8cb4dc7606b675902a52934a61b84a11d6899a5af1"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:49 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:49 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:49 +0000 Started GET "/auth/gds/callback?code=74b45cc5555a6a5bfb276496136711730ea7978d709105ddf78d9cae1b544f90&state=7598ab70da1d47b340827175ef1cf7788873f28d8923b8e9" for 127.0.0.1 at 2017-12-08 09:16:49 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"74b45cc5555a6a5bfb276496136711730ea7978d709105ddf78d9cae1b544f90", "state"=>"7598ab70da1d47b340827175ef1cf7788873f28d8923b8e9"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:49 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-09 05:21:49 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-09 05:21:49 +0000 Started GET "/auth/gds/callback?code=da18ce32aec1c829161714064fa31f815aa8933ca7d8a83a77ab55e3d9b60868&state=e1207a673bcef09649729d9a6666e4312b15e161bfec7953" for 127.0.0.1 at 2017-12-09 05:21:49 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"da18ce32aec1c829161714064fa31f815aa8933ca7d8a83a77ab55e3d9b60868", "state"=>"e1207a673bcef09649729d9a6666e4312b15e161bfec7953"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-09 05:21:49 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:49 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:49 +0000 Started GET "/auth/gds/callback?code=58c7e11d1ae291f9c591783f4c71f4af516dbb4146d02898b0f912e139e777a1&state=7e72609b30d7d1d70ea74c63d41181d8c19a00f5bba20732" for 127.0.0.1 at 2017-12-08 09:16:49 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"58c7e11d1ae291f9c591783f4c71f4af516dbb4146d02898b0f912e139e777a1", "state"=>"7e72609b30d7d1d70ea74c63d41181d8c19a00f5bba20732"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.0ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:49 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-09 05:21:49 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-09 05:21:49 +0000 Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:49 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:49 +0000 Started GET "/auth/gds/callback?code=3aa6475c92e4417d0fa1a2fdb9869fa10b99ddf699dbbb2d52eca04fecf51a08&state=77551c720e4670a1b2115632ab1cad15b2f55159342b032c" for 127.0.0.1 at 2017-12-08 09:16:50 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"3aa6475c92e4417d0fa1a2fdb9869fa10b99ddf699dbbb2d52eca04fecf51a08", "state"=>"77551c720e4670a1b2115632ab1cad15b2f55159342b032c"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:50 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-09 05:11:50 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.2ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:50 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:50 +0000 Started GET "/auth/gds/callback?code=f8c8576c9d5afde443e07373373e97002818174408070e8c3340dbde30b84bb6&state=40c040b0446ea9419c144c0543ac5b0adf75822aa21cb2d2" for 127.0.0.1 at 2017-12-08 09:16:50 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"f8c8576c9d5afde443e07373373e97002818174408070e8c3340dbde30b84bb6", "state"=>"40c040b0446ea9419c144c0543ac5b0adf75822aa21cb2d2"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:50 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.1ms) User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."email" = ? ORDER BY "users"."id" ASC LIMIT ? [["email", "test@example-client.com"], ["LIMIT", 1]]  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", true], ["id", 12]]  (6.3ms) commit transaction Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:50 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Authenticating with gds_sso strategy Completed in 1ms (ActiveRecord: 0.1ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:16:50 +0000 Started GET "/auth/gds/callback?code=c8a34750a48051b788fb570b3f5556df02b0fe9f76023902b25a3680a7454daf&state=68b7074a255aa3deadba4630549a3d420bdbab8d21a4aaf8" for 127.0.0.1 at 2017-12-08 09:16:50 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"c8a34750a48051b788fb570b3f5556df02b0fe9f76023902b25a3680a7454daf", "state"=>"68b7074a255aa3deadba4630549a3d420bdbab8d21a4aaf8"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction SQL (0.1ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", false], ["id", 12]]  (4.9ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 9ms (ActiveRecord: 5.4ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:50 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.4ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:50 +0000 Processing by ExampleController#restricted as JSON User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "disabled" = ? WHERE "users"."id" = ? [["disabled", nil], ["id", 12]]  (4.7ms) commit transaction User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.0ms) begin transaction  (0.0ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.0ms) begin transaction  (0.1ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.0ms) commit transaction Rendering text template Rendered text template (0.0ms) Completed 200 OK in 72ms (Views: 0.3ms | ActiveRecord: 5.6ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:16:50 +0000 Processing by ExampleController#this_requires_signin_permission as JSON User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.0ms) begin transaction  (0.0ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.0ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.0ms) begin transaction  (0.0ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.0ms) begin transaction  (0.1ms) commit transaction Rendering text template Rendered text template (0.0ms) Completed 200 OK in 61ms (Views: 0.4ms | ActiveRecord: 0.7ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:50 +0000 Processing by ExampleController#restricted as JSON Completed in 22ms (ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:16:50 +0000 Processing by ExampleController#restricted as JSON Completed in 11ms (ActiveRecord: 0.0ms)  (10.3ms) CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar NOT NULL, "uid" varchar NOT NULL, "email" varchar NOT NULL, "remotely_signed_out" boolean, "permissions" text, "organisation_slug" varchar, "organisation_content_id" varchar, "disabled" boolean DEFAULT 'f')   (9.4ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL)  (0.1ms) select sqlite_version(*)  (4.9ms) CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version") Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:17:04 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 7ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:04 +0000 Started GET "/auth/gds/callback?code=a0bb939fa177185880182d0d43f2f0da9a15cc571e9d33d183ddd5db005f89ec&state=1cdec6ea848f871b8a6eb9701259fa58a5a39f48669980c6" for 127.0.0.1 at 2017-12-08 09:17:04 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"a0bb939fa177185880182d0d43f2f0da9a15cc571e9d33d183ddd5db005f89ec", "state"=>"1cdec6ea848f871b8a6eb9701259fa58a5a39f48669980c6"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]] User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."email" = ? ORDER BY "users"."id" ASC LIMIT 1 [["email", "test@example-client.com"]]  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "integration-uid"], ["email", "test@example-client.com"], ["name", "Test User"], ["permissions", "---\n- signin\n"]]  (6.5ms) commit transaction  (0.0ms) begin transaction SQL (0.2ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "f"], ["id", 1]]  (4.7ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 31ms (ActiveRecord: 12.4ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:17:04 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 6ms (Views: 3.7ms | ActiveRecord: 0.1ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:17:04 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:04 +0000 Started GET "/auth/gds/callback?code=d7169f0667be1e98222c2e42da39fd2e422d90100b37b523c69546b65cda27cd&state=0f1c18bb5fb347ee0138172a92f3d93b6058d74bcd3371e2" for 127.0.0.1 at 2017-12-08 09:17:04 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"d7169f0667be1e98222c2e42da39fd2e422d90100b37b523c69546b65cda27cd", "state"=>"0f1c18bb5fb347ee0138172a92f3d93b6058d74bcd3371e2"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 4ms (ActiveRecord: 0.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:17:04 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.2ms | ActiveRecord: 0.1ms) Started GET "/" for 127.0.0.1 at 2017-12-08 09:17:04 +0000 Processing by ExampleController#index as HTML Rendered text template (0.0ms) Completed 200 OK in 0ms (Views: 0.2ms | ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:04 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:04 +0000 Started GET "/auth/gds/callback?code=8ca2448fd6723932527823757aa0ec35553a6481644d3cb98526931b9de53dc7&state=a54747189e06216ea5482b16110d13c9d4ff2d7f81e4cf98" for 127.0.0.1 at 2017-12-08 09:17:04 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"8ca2448fd6723932527823757aa0ec35553a6481644d3cb98526931b9de53dc7", "state"=>"a54747189e06216ea5482b16110d13c9d4ff2d7f81e4cf98"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 4ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:04 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:04 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:04 +0000 Started GET "/auth/gds/callback?code=b2df58a55f63a216a25b4a426b10d339600fc0d92b221bf0d0399a094ebb3987&state=1c464472d1e1f36f327090ec8558e0368ac9923d2f49702c" for 127.0.0.1 at 2017-12-08 09:17:05 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"b2df58a55f63a216a25b4a426b10d339600fc0d92b221bf0d0399a094ebb3987", "state"=>"1c464472d1e1f36f327090ec8558e0368ac9923d2f49702c"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 4ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:05 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.2ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:05 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:05 +0000 Started GET "/auth/gds/callback?code=3e721ef987ddff6e720dc56d4f31d0ce6094361a6bcd042a6c55a1a98ac9e2ed&state=0ee6cae582dfc1131c58ba413cf54c5f830415f4cedd909e" for 127.0.0.1 at 2017-12-08 09:17:05 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"3e721ef987ddff6e720dc56d4f31d0ce6094361a6bcd042a6c55a1a98ac9e2ed", "state"=>"0ee6cae582dfc1131c58ba413cf54c5f830415f4cedd909e"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 4ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:05 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:05 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:05 +0000 Started GET "/auth/gds/callback?code=c2f18f2dfecc5450d1b6193c01132aa0462b9d9afe48d502e97658010c778b67&state=646fedba10beaedfe3100d6dd91e88ed23ad2bd8e6f455d7" for 127.0.0.1 at 2017-12-08 09:17:05 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"c2f18f2dfecc5450d1b6193c01132aa0462b9d9afe48d502e97658010c778b67", "state"=>"646fedba10beaedfe3100d6dd91e88ed23ad2bd8e6f455d7"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 4ms (ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:05 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.1ms) User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."email" = ? ORDER BY "users"."id" ASC LIMIT 1 [["email", "test@example-client.com"]]  (0.0ms) begin transaction SQL (0.1ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "t"], ["id", 1]]  (5.6ms) commit transaction Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:05 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Authenticating with gds_sso strategy Completed in 1ms (ActiveRecord: 0.1ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:05 +0000 Started GET "/auth/gds/callback?code=e3f8312a7cd2a30482279235f9746f314c3f81f158be73be48673f93ed843f46&state=e454f96b7bf27192f655c3faa1ba2e41dbfa614a7d5d7aa1" for 127.0.0.1 at 2017-12-08 09:17:05 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"e3f8312a7cd2a30482279235f9746f314c3f81f158be73be48673f93ed843f46", "state"=>"e454f96b7bf27192f655c3faa1ba2e41dbfa614a7d5d7aa1"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.1ms) begin transaction SQL (0.1ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "f"], ["id", 1]]  (5.9ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 10ms (ActiveRecord: 6.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:05 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.2ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:05 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:05 +0000 Started GET "/auth/gds/callback?code=60356317240338bc7b4a9f9f78b34ac1e664ad4f8154a193f8f6b94efb44f9eb&state=1b443d8b1ae9416f629b7fb6f82fcdc2bd490062a1bc7858" for 127.0.0.1 at 2017-12-08 09:17:06 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"60356317240338bc7b4a9f9f78b34ac1e664ad4f8154a193f8f6b94efb44f9eb", "state"=>"1b443d8b1ae9416f629b7fb6f82fcdc2bd490062a1bc7858"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.1ms) commit transaction  (0.0ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 4ms (ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:06 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.2ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-09 05:12:06 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.2ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:06 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:06 +0000 Started GET "/auth/gds/callback?code=92ca5975be3bd33149ea4a4a20bca4a196829b2346c084ccb97c530a71c7eea7&state=7c3d5656db2ae7501506441aa07fda6f97379cd54ee26605" for 127.0.0.1 at 2017-12-08 09:17:06 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"92ca5975be3bd33149ea4a4a20bca4a196829b2346c084ccb97c530a71c7eea7", "state"=>"7c3d5656db2ae7501506441aa07fda6f97379cd54ee26605"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 4ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:06 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.2ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-09 05:22:06 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 1ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-09 05:22:06 +0000 Started GET "/auth/gds/callback?code=452a43c6724a91466805dac7948ac2c6e7f565fefae52aea7ccd9171d42163bb&state=6560c6a842a8f24f856c46dd59291474dfcdc384594121b9" for 127.0.0.1 at 2017-12-09 05:22:06 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"452a43c6724a91466805dac7948ac2c6e7f565fefae52aea7ccd9171d42163bb", "state"=>"6560c6a842a8f24f856c46dd59291474dfcdc384594121b9"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.1ms) commit transaction  (0.1ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 4ms (ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-09 05:22:06 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:06 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:06 +0000 Started GET "/auth/gds/callback?code=c8277e7236338bbd9169657daa908ff7c608c11ae2976ce08fed4bef75d9883f&state=52479bdbd91ad10bdaee20749b1c5409b001398c13ce0716" for 127.0.0.1 at 2017-12-08 09:17:06 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"c8277e7236338bbd9169657daa908ff7c608c11ae2976ce08fed4bef75d9883f", "state"=>"52479bdbd91ad10bdaee20749b1c5409b001398c13ce0716"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 5ms (ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:06 +0000 Processing by ExampleController#restricted as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-09 05:22:06 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 1ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-09 05:22:06 +0000 Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:06 +0000 Processing by ExampleController#restricted as JSON Completed in 15ms (ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:06 +0000 Processing by ExampleController#restricted as JSON User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "disabled" = ? WHERE "users"."id" = ? [["disabled", nil], ["id", 1]]  (5.5ms) commit transaction User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.0ms) begin transaction  (0.0ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.0ms) begin transaction  (0.0ms) commit transaction Rendered text template (0.0ms) Completed 200 OK in 70ms (Views: 0.3ms | ActiveRecord: 6.6ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:06 +0000 Processing by ExampleController#restricted as JSON Completed in 23ms (ActiveRecord: 0.0ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:17:06 +0000 Processing by ExampleController#this_requires_signin_permission as JSON User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.1ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.0ms) begin transaction  (0.0ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.0ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.1ms) begin transaction  (0.0ms) commit transaction Rendered text template (0.0ms) Completed 200 OK in 63ms (Views: 0.3ms | ActiveRecord: 0.7ms) User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "asd"]] User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."email" = ? ORDER BY "users"."id" ASC LIMIT 1 [["email", "user@example.com"]]  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions", "organisation_slug", "organisation_content_id", "disabled") VALUES (?, ?, ?, ?, ?, ?, ?) [["uid", "asd"], ["email", "user@example.com"], ["name", "A Name"], ["permissions", "---\n- signin\n"], ["organisation_slug", "hmrc"], ["organisation_content_id", "67a2b78d-eee3-45b3-80e2-792e7f71cecc"], ["disabled", nil]]  (4.3ms) commit transaction User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "asd"]]  (0.0ms) begin transaction  (0.0ms) commit transaction  (0.1ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d33176"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (4.0ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d31421"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (5.2ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d33176"} Rendered /var/lib/jenkins/workspace/gds-sso_master-7MNGHJETCC7W4ACW54GEWCZ7RU2E7EW7NZYEBGCKG2QG3YLPM53Q/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.2ms) Completed 403 Forbidden in 7ms (Views: 6.6ms | ActiveRecord: 0.0ms)  (0.1ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d36988"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (4.0ms) commit transaction  (0.1ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d33638"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (3.7ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d36988"} User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "a1s2d36988"]]  (0.0ms) begin transaction SQL (0.1ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "t"], ["id", 5]]  (4.0ms) commit transaction Completed 200 OK in 6ms (ActiveRecord: 4.3ms) User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 5]]  (0.0ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d34986"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (4.0ms) commit transaction  (0.0ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d39939"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (3.8ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"nonexistent-user"} User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "nonexistent-user"]] Completed 200 OK in 1ms (ActiveRecord: 0.1ms)  (0.1ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d34377"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (5.0ms) commit transaction  (0.0ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d38245"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (4.0ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d34377"} User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "a1s2d34377"]]  (0.0ms) begin transaction SQL (0.2ms) UPDATE "users" SET "email" = ?, "name" = ?, "permissions" = ?, "organisation_slug" = ?, "organisation_content_id" = ? WHERE "users"."id" = ? [["email", "user@domain.com"], ["name", "Joshua Marshall"], ["permissions", "---\n- signin\n- new permission\n"], ["organisation_slug", "justice-league"], ["organisation_content_id", "aae1319e-5788-4677-998c-f1a53af528d0"], ["id", 9]]  (4.2ms) commit transaction Completed 200 OK in 7ms (ActiveRecord: 4.5ms) User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 9]]  (0.1ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d37090"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (4.1ms) commit transaction  (0.1ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d32452"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (5.2ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d37090"} Rendered /var/lib/jenkins/workspace/gds-sso_master-7MNGHJETCC7W4ACW54GEWCZ7RU2E7EW7NZYEBGCKG2QG3YLPM53Q/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.0ms) Completed 403 Forbidden in 1ms (Views: 0.4ms | ActiveRecord: 0.0ms)  (6.6ms) CREATE TABLE "users" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar NOT NULL, "uid" varchar NOT NULL, "email" varchar NOT NULL, "remotely_signed_out" boolean, "permissions" text, "organisation_slug" varchar, "organisation_content_id" varchar, "disabled" boolean DEFAULT 'f')  (4.5ms) CREATE TABLE "ar_internal_metadata" ("key" varchar NOT NULL PRIMARY KEY, "value" varchar, "created_at" datetime NOT NULL, "updated_at" datetime NOT NULL) ActiveRecord::InternalMetadata Load (0.1ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = ? LIMIT ? [["key", :environment], ["LIMIT", 1]]  (0.0ms) begin transaction SQL (0.1ms) INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES (?, ?, ?, ?) [["key", "environment"], ["value", "test"], ["created_at", 2017-12-08 09:17:17 UTC], ["updated_at", 2017-12-08 09:17:17 UTC]]  (5.6ms) commit transaction  (5.2ms) CREATE TABLE "schema_migrations" ("version" varchar NOT NULL PRIMARY KEY) ActiveRecord::InternalMetadata Load (0.1ms) SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = ? LIMIT ? [["key", :environment], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.0ms) commit transaction Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:17:17 +0000 Processing by ExampleController#this_requires_signin_permission as JSON User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]] User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."email" = ? ORDER BY "users"."id" ASC LIMIT ? [["email", "test@example-client.com"], ["LIMIT", 1]]  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions", "disabled") VALUES (?, ?, ?, ?, ?) [["name", "Test User"], ["uid", "integration-uid"], ["email", "test@example-client.com"], ["permissions", "---\n- signin\n"], ["disabled", nil]]  (8.9ms) commit transaction User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.0ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.2ms) begin transaction  (0.0ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.1ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", false], ["id", 1]]  (7.2ms) commit transaction Rendering text template Rendered text template (0.0ms) Completed 200 OK in 111ms (Views: 3.4ms | ActiveRecord: 18.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:18 +0000 Processing by ExampleController#restricted as JSON Completed in 26ms (ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:18 +0000 Processing by ExampleController#restricted as JSON Completed in 14ms (ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:18 +0000 Processing by ExampleController#restricted as JSON User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.0ms) begin transaction  (0.0ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.0ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.0ms) begin transaction  (0.0ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.0ms) commit transaction Rendering text template Rendered text template (0.0ms) Completed 200 OK in 64ms (Views: 0.3ms | ActiveRecord: 0.7ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:17:18 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:18 +0000 Started GET "/auth/gds/callback?code=b6c285330f7d7aa4479fe6886516bdf3677fa3e3c2d5a34ada606fb3ae6d9c40&state=e3fff9e95e31722aa25220048f1ccde86b18718e17155c2a" for 127.0.0.1 at 2017-12-08 09:17:18 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"b6c285330f7d7aa4479fe6886516bdf3677fa3e3c2d5a34ada606fb3ae6d9c40", "state"=>"e3fff9e95e31722aa25220048f1ccde86b18718e17155c2a"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "disabled" = ? WHERE "users"."id" = ? [["disabled", false], ["id", 1]]  (5.9ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 10ms (ActiveRecord: 6.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:17:18 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 3ms (Views: 0.3ms | ActiveRecord: 0.2ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:17:18 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:18 +0000 Started GET "/auth/gds/callback?code=d06de1284eb7ed2d0cd68b0360a20683aae6391d242a06ac48d1e752acac15a2&state=2b6a0eb982c0145fcadfa51d3e5c2c68534e2a62a13c2d81" for 127.0.0.1 at 2017-12-08 09:17:18 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"d06de1284eb7ed2d0cd68b0360a20683aae6391d242a06ac48d1e752acac15a2", "state"=>"2b6a0eb982c0145fcadfa51d3e5c2c68534e2a62a13c2d81"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2017-12-08 09:17:18 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.1ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:18 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:18 +0000 Started GET "/auth/gds/callback?code=9f11c347d968ef4b5b53bc35aec59477e6306323de1b2703947cf700b1d1a130&state=6e4134fbd2d2dc49e9da7cf3210e135beb9647022dacf4f6" for 127.0.0.1 at 2017-12-08 09:17:18 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"9f11c347d968ef4b5b53bc35aec59477e6306323de1b2703947cf700b1d1a130", "state"=>"6e4134fbd2d2dc49e9da7cf3210e135beb9647022dacf4f6"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.0ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:18 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.4ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:18 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:18 +0000 Started GET "/auth/gds/callback?code=4ab451f7918f92e11632dc5576b608925c7001af8934429ede61439ed0928708&state=96dbe154f60af4d0e5cc90e5cabaca9cfc8dc633fde8f0f6" for 127.0.0.1 at 2017-12-08 09:17:19 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"4ab451f7918f92e11632dc5576b608925c7001af8934429ede61439ed0928708", "state"=>"96dbe154f60af4d0e5cc90e5cabaca9cfc8dc633fde8f0f6"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.0ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:19 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.2ms) Started GET "/" for 127.0.0.1 at 2017-12-08 09:17:19 +0000 Processing by ExampleController#index as HTML Rendering text template Rendered text template (0.0ms) Completed 200 OK in 0ms (Views: 0.2ms | ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:19 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:19 +0000 Started GET "/auth/gds/callback?code=1f141bb76e0021d4d8d3e98609e78e21dffc6a0e5236f82301c2cb1e96b7181f&state=d44608a1842cba5ee47a9dfaa5149dfb8bf6b05cce879b6e" for 127.0.0.1 at 2017-12-08 09:17:19 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"1f141bb76e0021d4d8d3e98609e78e21dffc6a0e5236f82301c2cb1e96b7181f", "state"=>"d44608a1842cba5ee47a9dfaa5149dfb8bf6b05cce879b6e"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 3ms (ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:19 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:19 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:19 +0000 Started GET "/auth/gds/callback?code=c853a93efe549f49ea16b0dd9be991b7a72222e8eff69ab81c09a96b82bcde30&state=4c75ae3fcd60644e360c01ed31bf718f7ca906185dba0a10" for 127.0.0.1 at 2017-12-08 09:17:19 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"c853a93efe549f49ea16b0dd9be991b7a72222e8eff69ab81c09a96b82bcde30", "state"=>"4c75ae3fcd60644e360c01ed31bf718f7ca906185dba0a10"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 3ms (ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:19 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.2ms) User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."email" = ? ORDER BY "users"."id" ASC LIMIT ? [["email", "test@example-client.com"], ["LIMIT", 1]]  (0.0ms) begin transaction SQL (0.2ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", true], ["id", 1]]  (5.6ms) commit transaction Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:19 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Authenticating with gds_sso strategy Completed in 1ms (ActiveRecord: 0.2ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:19 +0000 Started GET "/auth/gds/callback?code=3051cd86e0c5c80c80ad2b5d7ff85f916ca42cc17174bb338bb97be21972c1ba&state=ff8ab90e60f71a6b01bd9a3587edc804104ea2b498836926" for 127.0.0.1 at 2017-12-08 09:17:19 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"3051cd86e0c5c80c80ad2b5d7ff85f916ca42cc17174bb338bb97be21972c1ba", "state"=>"ff8ab90e60f71a6b01bd9a3587edc804104ea2b498836926"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.0ms) begin transaction  (0.1ms) commit transaction  (0.0ms) begin transaction SQL (0.2ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", false], ["id", 1]]  (6.2ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 11ms (ActiveRecord: 6.8ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:19 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:19 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:19 +0000 Started GET "/auth/gds/callback?code=e8e93eacd2cfd06665dc343aed1a0b89b0ba609be336b99159cf58d9e0f000c8&state=453d14f4e3327c6132f8bc5ce231d3cc7c4e1b5a6d335669" for 127.0.0.1 at 2017-12-08 09:17:20 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"e8e93eacd2cfd06665dc343aed1a0b89b0ba609be336b99159cf58d9e0f000c8", "state"=>"453d14f4e3327c6132f8bc5ce231d3cc7c4e1b5a6d335669"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 3ms (ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:20 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-09 05:22:20 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-09 05:22:20 +0000 Started GET "/auth/gds/callback?code=110078bd2324d66ccdb485fb5e843adf07b264085fb986f8a3263b4e9f85267b&state=9941d26bd73d4ad1e52c3a0fcb54a94f185c6f6dbf77fcb9" for 127.0.0.1 at 2017-12-09 05:22:20 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"110078bd2324d66ccdb485fb5e843adf07b264085fb986f8a3263b4e9f85267b", "state"=>"9941d26bd73d4ad1e52c3a0fcb54a94f185c6f6dbf77fcb9"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 3ms (ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-09 05:22:20 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:20 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:20 +0000 Started GET "/auth/gds/callback?code=459f1919bbce1a6fddb01cb06c645e16466d233dca1e006079d856f3ea72834a&state=51a3299c4bc40a81a9de747eccea3cd2e3f656016b5cc6b0" for 127.0.0.1 at 2017-12-08 09:17:20 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"459f1919bbce1a6fddb01cb06c645e16466d233dca1e006079d856f3ea72834a", "state"=>"51a3299c4bc40a81a9de747eccea3cd2e3f656016b5cc6b0"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 4ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:20 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-09 05:22:20 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 1ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-09 05:22:20 +0000 Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:20 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2017-12-08 09:17:20 +0000 Started GET "/auth/gds/callback?code=ff39b5d2bc1d38ea11f69c668156fc9119772a163fa8186e9a245717b1f70211&state=45d5479b2a870b9f5838f7645c3be3cd6da1ed6e8b0b475a" for 127.0.0.1 at 2017-12-08 09:17:20 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"ff39b5d2bc1d38ea11f69c668156fc9119772a163fa8186e9a245717b1f70211", "state"=>"45d5479b2a870b9f5838f7645c3be3cd6da1ed6e8b0b475a"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["LIMIT", 1]]  (0.1ms) begin transaction  (0.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 3ms (ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-08 09:17:20 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2017-12-09 05:12:20 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "integration-uid"], ["remotely_signed_out", false], ["LIMIT", 1]] Rendering text template Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.4ms | ActiveRecord: 0.2ms) User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "asd"], ["LIMIT", 1]] User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."email" = ? ORDER BY "users"."id" ASC LIMIT ? [["email", "user@example.com"], ["LIMIT", 1]]  (0.0ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions", "organisation_slug", "organisation_content_id", "disabled") VALUES (?, ?, ?, ?, ?, ?, ?) [["name", "A Name"], ["uid", "asd"], ["email", "user@example.com"], ["permissions", "---\n- signin\n"], ["organisation_slug", "hmrc"], ["organisation_content_id", "67a2b78d-eee3-45b3-80e2-792e7f71cecc"], ["disabled", nil]]  (6.5ms) commit transaction User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "asd"], ["LIMIT", 1]]  (0.0ms) begin transaction  (0.1ms) commit transaction  (0.0ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "Moshua Jarshall"], ["uid", "a1s2d34992"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]  (5.2ms) commit transaction  (0.0ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "SSO Push user"], ["uid", "a1s2d34920"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (4.8ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d34992"} User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "a1s2d34992"], ["LIMIT", 1]]  (0.0ms) begin transaction SQL (0.2ms) UPDATE "users" SET "email" = ?, "name" = ?, "permissions" = ?, "organisation_slug" = ?, "organisation_content_id" = ? WHERE "users"."id" = ? [["email", "user@domain.com"], ["name", "Joshua Marshall"], ["permissions", "---\n- signin\n- new permission\n"], ["organisation_slug", "justice-league"], ["organisation_content_id", "aae1319e-5788-4677-998c-f1a53af528d0"], ["id", 3]]  (5.3ms) commit transaction Completed 200 OK in 9ms (ActiveRecord: 5.6ms) User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT ? [["id", 3], ["LIMIT", 1]]  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "Moshua Jarshall"], ["uid", "a1s2d36717"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]  (5.2ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "SSO Push user"], ["uid", "a1s2d34089"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (4.9ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d36717"} Rendering /var/lib/jenkins/workspace/gds-sso_master-7MNGHJETCC7W4ACW54GEWCZ7RU2E7EW7NZYEBGCKG2QG3YLPM53Q/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised Rendered /var/lib/jenkins/workspace/gds-sso_master-7MNGHJETCC7W4ACW54GEWCZ7RU2E7EW7NZYEBGCKG2QG3YLPM53Q/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.2ms) Completed 403 Forbidden in 8ms (Views: 7.9ms | ActiveRecord: 0.0ms)  (0.0ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "Moshua Jarshall"], ["uid", "a1s2d35029"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]  (5.3ms) commit transaction  (0.0ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "SSO Push user"], ["uid", "a1s2d33609"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (4.9ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"nonexistent-user"} User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "nonexistent-user"], ["LIMIT", 1]] Completed 200 OK in 1ms (ActiveRecord: 0.1ms)  (0.1ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "Moshua Jarshall"], ["uid", "a1s2d38184"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]  (5.3ms) commit transaction  (0.1ms) begin transaction SQL (0.1ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "SSO Push user"], ["uid", "a1s2d38755"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (4.9ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d38184"} User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ? [["uid", "a1s2d38184"], ["LIMIT", 1]]  (0.0ms) begin transaction SQL (0.1ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", true], ["id", 9]]  (5.2ms) commit transaction Completed 200 OK in 8ms (ActiveRecord: 5.5ms) User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT ? [["id", 9], ["LIMIT", 1]]  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "Moshua Jarshall"], ["uid", "a1s2d31951"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]  (5.8ms) commit transaction  (0.0ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?) [["name", "SSO Push user"], ["uid", "a1s2d32948"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (5.2ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d31951"} Rendering /var/lib/jenkins/workspace/gds-sso_master-7MNGHJETCC7W4ACW54GEWCZ7RU2E7EW7NZYEBGCKG2QG3YLPM53Q/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised Rendered /var/lib/jenkins/workspace/gds-sso_master-7MNGHJETCC7W4ACW54GEWCZ7RU2E7EW7NZYEBGCKG2QG3YLPM53Q/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.0ms) Completed 403 Forbidden in 1ms (Views: 0.4ms | ActiveRecord: 0.0ms)