(24.5ms)  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') 
   (15.3ms)  CREATE TABLE "schema_migrations" ("version" varchar NOT NULL) 
   (0.1ms)  select sqlite_version(*)
   (44.7ms)  CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version")
   (0.1ms)  begin transaction
  SQL (0.3ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d36712"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]
   (25.7ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d36205"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (13.2ms)  commit transaction
Processing by Api::UserController#reauth as HTML
  Parameters: {"uid"=>"nonexistent-user"}
  User Load (0.2ms)  SELECT  "users".* FROM "users" WHERE "users"."uid" = ?  ORDER BY "users"."id" ASC LIMIT 1  [["uid", "nonexistent-user"]]
Completed 200 OK in 6ms (ActiveRecord: 0.2ms)
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d35653"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]
   (35.2ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d39384"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (18.1ms)  commit transaction
Processing by Api::UserController#reauth as HTML
  Parameters: {"uid"=>"a1s2d35653"}
  User Load (0.1ms)  SELECT  "users".* FROM "users" WHERE "users"."uid" = ?  ORDER BY "users"."id" ASC LIMIT 1  [["uid", "a1s2d35653"]]
   (0.1ms)  begin transaction
  SQL (0.2ms)  UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ?  [["remotely_signed_out", "t"], ["id", 3]]
   (16.7ms)  commit transaction
Completed 200 OK in 21ms (ActiveRecord: 17.1ms)
  User Load (0.2ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1  [["id", 3]]
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d39946"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]
   (9.6ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d34132"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (13.1ms)  commit transaction
Processing by Api::UserController#reauth as HTML
  Parameters: {"uid"=>"a1s2d39946"}
  Rendered /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.3ms)
Completed 403 Forbidden in 9ms (Views: 8.7ms | ActiveRecord: 0.0ms)
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d39843"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]
   (18.1ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.1ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d34615"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (15.5ms)  commit transaction
Processing by Api::UserController#update as HTML
  Parameters: {"uid"=>"a1s2d39843"}
  User Load (0.1ms)  SELECT  "users".* FROM "users" WHERE "users"."uid" = ?  ORDER BY "users"."id" ASC LIMIT 1  [["uid", "a1s2d39843"]]
   (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", 7]]
   (18.3ms)  commit transaction
Completed 200 OK in 23ms (ActiveRecord: 18.7ms)
  User Load (0.1ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1  [["id", 7]]
   (0.1ms)  begin transaction
  SQL (0.1ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d3479"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]
   (10.7ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d36505"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (9.8ms)  commit transaction
Processing by Api::UserController#update as HTML
  Parameters: {"uid"=>"a1s2d3479"}
  Rendered /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.1ms)
Completed 403 Forbidden in 1ms (Views: 0.6ms | 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.2ms)  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]]
   (13.5ms)  commit transaction
  User Load (0.1ms)  SELECT  "users".* FROM "users" WHERE "users"."uid" = ?  ORDER BY "users"."id" ASC LIMIT 1  [["uid", "asd"]]
   (0.1ms)  begin transaction
   (0.1ms)  commit transaction
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:26 +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"]]
  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]]
   (52.1ms)  commit transaction
  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.1ms)  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.1ms)  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.1ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ?  [["remotely_signed_out", "f"], ["id", 12]]
   (9.7ms)  commit transaction
  Rendered text template (0.0ms)
Completed 200 OK in 386ms (Views: 1.4ms | ActiveRecord: 63.5ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:26 +0000
Processing by ExampleController#restricted as JSON
Completed   in 17ms (ActiveRecord: 0.0ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:26 +0000
Processing by ExampleController#restricted as JSON
Completed   in 29ms (ActiveRecord: 0.0ms)
Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-12-20 12:13:26 +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 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.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.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.1ms)  begin transaction
   (0.1ms)  commit transaction
   (0.1ms)  begin transaction
   (0.1ms)  commit transaction
  Rendered text template (0.0ms)
Completed 200 OK in 73ms (Views: 0.3ms | ActiveRecord: 1.0ms)
Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-12-20 12:13:26 +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 2016-12-20 12:13:26 +0000
Started GET "/auth/gds/callback?code=de1b1f9a5f817b4c5056335f3605ea461d9af17cc482b46464b7c6c5c2dadf7d&state=3b9f926e0d91f1510f4eb1ae914e097c934e99c0f7e00835" for 127.0.0.1 at 2016-12-20 12:13:38 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"de1b1f9a5f817b4c5056335f3605ea461d9af17cc482b46464b7c6c5c2dadf7d", "state"=>"3b9f926e0d91f1510f4eb1ae914e097c934e99c0f7e00835"}
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", 12]]
   (81.7ms)  commit transaction
   (0.1ms)  begin transaction
   (0.1ms)  commit transaction
Redirected to http://www.example-client.com/this_requires_signin_permission
Completed 302 Found in 88ms (ActiveRecord: 82.3ms)
Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-12-20 12:13:38 +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 1  [["uid", "integration-uid"], ["remotely_signed_out", "f"]]
  Rendered text template (0.0ms)
Completed 200 OK in 2ms (Views: 0.4ms | ActiveRecord: 0.2ms)
Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-12-20 12:13:38 +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 2016-12-20 12:13:38 +0000
Started GET "/auth/gds/callback?code=81a39364e7be9158e0087c8d911cd1bf803a2ec649d26ad2c3cf6e87e1d0c65f&state=8006dd92f3a1ce45dfda380f87af525550a0c04630cc18ac" for 127.0.0.1 at 2016-12-20 12:13:38 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"81a39364e7be9158e0087c8d911cd1bf803a2ec649d26ad2c3cf6e87e1d0c65f", "state"=>"8006dd92f3a1ce45dfda380f87af525550a0c04630cc18ac"}
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.1ms)  commit transaction
   (0.1ms)  begin transaction
   (0.1ms)  commit transaction
Redirected to http://www.example-client.com/this_requires_signin_permission
Completed 302 Found in 6ms (ActiveRecord: 0.5ms)
Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-12-20 12:13:38 +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 "/restricted" for 127.0.0.1 at 2016-12-20 12:13:38 +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 2016-12-20 12:13:38 +0000
Started GET "/auth/gds/callback?code=62941e74cdcee54d19756dc8d4878b1842ae56c3f476128a16a4786bbdf6af50&state=1cad8d6d414084b60e21cb12cd8e1cabaddf906cf35b73a5" for 127.0.0.1 at 2016-12-20 12:13:39 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"62941e74cdcee54d19756dc8d4878b1842ae56c3f476128a16a4786bbdf6af50", "state"=>"1cad8d6d414084b60e21cb12cd8e1cabaddf906cf35b73a5"}
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 5ms (ActiveRecord: 0.4ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:39 +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 2ms (Views: 0.3ms | ActiveRecord: 0.1ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:39 +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 2016-12-20 12:13:39 +0000
Started GET "/auth/gds/callback?code=135beefaeab8cbb75e0c23bfe939009fe38e4ca915fdaf79a52a7b4cd07ac7e9&state=d4aab73e45047f92804335bae78a926312ef65d6ce7d9fd0" for 127.0.0.1 at 2016-12-20 12:13:39 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"135beefaeab8cbb75e0c23bfe939009fe38e4ca915fdaf79a52a7b4cd07ac7e9", "state"=>"d4aab73e45047f92804335bae78a926312ef65d6ce7d9fd0"}
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 5ms (ActiveRecord: 0.4ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:39 +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 2ms (Views: 0.3ms | ActiveRecord: 0.1ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:39 +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 2016-12-20 12:13:39 +0000
Started GET "/auth/gds/callback?code=4755abe3e81e73b9d8aeb594407867d2d86d6b9c42f88e1152959404f6a376ec&state=5484c7035dcf78a67094e81301c4342219bfe24f5e1ba124" for 127.0.0.1 at 2016-12-20 12:13:39 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"4755abe3e81e73b9d8aeb594407867d2d86d6b9c42f88e1152959404f6a376ec", "state"=>"5484c7035dcf78a67094e81301c4342219bfe24f5e1ba124"}
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 5ms (ActiveRecord: 0.4ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:39 +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 2ms (Views: 0.3ms | ActiveRecord: 0.1ms)
Started GET "/" for 127.0.0.1 at 2016-12-20 12:13:39 +0000
Processing by ExampleController#index as HTML
  Rendered text template (0.0ms)
Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.0ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:39 +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 2016-12-20 12:13:39 +0000
Started GET "/auth/gds/callback?code=de9732b79db33c8d7a6bdd545f54ae922c0676b29118451c314ec444767e3ff2&state=21c7e39676db8e33228d0d8b9ed5592365cd7d72446c9a7f" for 127.0.0.1 at 2016-12-20 12:13:39 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"de9732b79db33c8d7a6bdd545f54ae922c0676b29118451c314ec444767e3ff2", "state"=>"21c7e39676db8e33228d0d8b9ed5592365cd7d72446c9a7f"}
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.1ms)  commit transaction
   (0.1ms)  begin transaction
   (0.1ms)  commit transaction
Redirected to http://www.example-client.com/restricted
Completed 302 Found in 6ms (ActiveRecord: 0.5ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:39 +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 2ms (Views: 0.3ms | ActiveRecord: 0.1ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-21 08:18:39 +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 2016-12-21 08:18:39 +0000
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:40 +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 2016-12-20 12:13:40 +0000
Started GET "/auth/gds/callback?code=b0c0798cd4048315f2195c7f6c46ce9f1484e5e3dca69e63888d363df233d593&state=3d3a16c647c1d6c5263992925b92da57c3c361827d012892" for 127.0.0.1 at 2016-12-20 12:13:40 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"b0c0798cd4048315f2195c7f6c46ce9f1484e5e3dca69e63888d363df233d593", "state"=>"3d3a16c647c1d6c5263992925b92da57c3c361827d012892"}
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.2ms)  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 39ms (ActiveRecord: 0.6ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:40 +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.5ms | ActiveRecord: 0.2ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-21 08:08:40 +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 2ms (Views: 0.4ms | ActiveRecord: 0.1ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:40 +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 2016-12-20 12:13:40 +0000
Started GET "/auth/gds/callback?code=21d581ed8bbb4d27a73cc823b03adeb098300af5f279362c46c72daa26fe2956&state=0aca4107c24efac67ba0dca7998edb05c6ec90a4b6cb65d5" for 127.0.0.1 at 2016-12-20 12:13:40 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"21d581ed8bbb4d27a73cc823b03adeb098300af5f279362c46c72daa26fe2956", "state"=>"0aca4107c24efac67ba0dca7998edb05c6ec90a4b6cb65d5"}
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 5ms (ActiveRecord: 0.4ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:40 +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 2ms (Views: 0.3ms | ActiveRecord: 0.1ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-21 08:18:40 +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 2016-12-21 08:18:40 +0000
Started GET "/auth/gds/callback?code=cb65563af847e5f0ee8f1f31521243ba6a7be4dd39af40faf65963f2eab5cfe3&state=8cb244238e8c33ecaec6d1dfc96948214da200a484a9042c" for 127.0.0.1 at 2016-12-21 08:18:40 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"cb65563af847e5f0ee8f1f31521243ba6a7be4dd39af40faf65963f2eab5cfe3", "state"=>"8cb244238e8c33ecaec6d1dfc96948214da200a484a9042c"}
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.1ms)  commit transaction
   (0.1ms)  begin transaction
   (0.1ms)  commit transaction
Redirected to http://www.example-client.com/restricted
Completed 302 Found in 5ms (ActiveRecord: 0.6ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-21 08:18:40 +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 2ms (Views: 0.3ms | ActiveRecord: 0.1ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:40 +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 2016-12-20 12:13:40 +0000
Started GET "/auth/gds/callback?code=a3cfeb5bc3f0559f6c71b07255dbbcaaf14106a2bfdd84f3ef6da71999a12751&state=cdaa23b210d09c4b22389cde774e4cf95f5b42113f5ef06c" for 127.0.0.1 at 2016-12-20 12:13:40 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"a3cfeb5bc3f0559f6c71b07255dbbcaaf14106a2bfdd84f3ef6da71999a12751", "state"=>"cdaa23b210d09c4b22389cde774e4cf95f5b42113f5ef06c"}
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 5ms (ActiveRecord: 0.4ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:40 +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 2ms (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.2ms)  UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ?  [["remotely_signed_out", "t"], ["id", 12]]
   (35.6ms)  commit transaction
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:40 +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 2016-12-20 12:13:40 +0000
Started GET "/auth/gds/callback?code=2f79647f0aad9bb1826d098bffa2c472a3ff75927c4c08965f33a23a26e440e7&state=3751200c9e5faef8aed92355841f12ffa40faf3f2a3fb047" for 127.0.0.1 at 2016-12-20 12:13:41 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"2f79647f0aad9bb1826d098bffa2c472a3ff75927c4c08965f33a23a26e440e7", "state"=>"3751200c9e5faef8aed92355841f12ffa40faf3f2a3fb047"}
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
  SQL (0.2ms)  UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ?  [["remotely_signed_out", "f"], ["id", 12]]
   (9.6ms)  commit transaction
Redirected to http://www.example-client.com/restricted
Completed 302 Found in 15ms (ActiveRecord: 10.0ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:41 +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 2ms (Views: 0.3ms | ActiveRecord: 0.1ms)
   (50.1ms)  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')
   (28.4ms)  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.2ms)  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", 2016-12-20 12:13:53 UTC], ["updated_at", 2016-12-20 12:13:53 UTC]]
   (33.5ms)  commit transaction
   (13.7ms)  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.1ms)  commit transaction
Started GET "/" for 127.0.0.1 at 2016-12-20 12:13:53 +0000
Processing by ExampleController#index as HTML
  Rendering text template
  Rendered text template (0.0ms)
Completed 200 OK in 5ms (Views: 4.8ms | ActiveRecord: 0.0ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:53 +0000
Processing by ExampleController#restricted as HTML
Authenticating with gds_sso strategy
Completed   in 10ms (ActiveRecord: 0.0ms)
Started GET "/auth/gds" for 127.0.0.1 at 2016-12-20 12:13:53 +0000
Started GET "/auth/gds/callback?code=b53a54e8b0b3cbdfabdc8a15b70ed0aa08fe90dd93f967f52093010b75deca87&state=75a80f5775406deb80c295cf799b777f47d1fa156a6eddfe" for 127.0.0.1 at 2016-12-20 12:13:53 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"b53a54e8b0b3cbdfabdc8a15b70ed0aa08fe90dd93f967f52093010b75deca87", "state"=>"75a80f5775406deb80c295cf799b777f47d1fa156a6eddfe"}
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"]]
   (7.4ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ?  [["remotely_signed_out", false], ["id", 1]]
   (9.3ms)  commit transaction
Redirected to http://www.example-client.com/restricted
Completed 302 Found in 51ms (ActiveRecord: 18.5ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:53 +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 2016-12-20 12:13:53 +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 2016-12-20 12:13:53 +0000
Started GET "/auth/gds/callback?code=2dff3e30ade4d365c8963faf730f164a395b501db877cfcdf7e523a995519d44&state=b73d837ffa9c011e212f1292017d24b7a1a040de5d6f0ac9" for 127.0.0.1 at 2016-12-20 12:13:54 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"2dff3e30ade4d365c8963faf730f164a395b501db877cfcdf7e523a995519d44", "state"=>"b73d837ffa9c011e212f1292017d24b7a1a040de5d6f0ac9"}
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.1ms)  commit transaction
Redirected to http://www.example-client.com/this_requires_signin_permission
Completed 302 Found in 4ms (ActiveRecord: 0.4ms)
Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-12-20 12:13:54 +0000
Processing by ExampleController#this_requires_signin_permission 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.4ms | ActiveRecord: 0.3ms)
Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-12-20 12:13:54 +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 2016-12-20 12:13:54 +0000
Started GET "/auth/gds/callback?code=2b1e005823ea196c061b627a79d864db70127925341c1bd635a2f76e1c976455&state=0a0fba517482b78dcc12e46edad4a167ec962019cb53bb72" for 127.0.0.1 at 2016-12-20 12:13:54 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"2b1e005823ea196c061b627a79d864db70127925341c1bd635a2f76e1c976455", "state"=>"0a0fba517482b78dcc12e46edad4a167ec962019cb53bb72"}
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.1ms)  commit transaction
Redirected to http://www.example-client.com/this_requires_signin_permission
Completed 302 Found in 4ms (ActiveRecord: 0.4ms)
Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-12-20 12:13:54 +0000
Processing by ExampleController#this_requires_signin_permission 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 2016-12-20 12:13:54 +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 2016-12-20 12:13:54 +0000
Started GET "/auth/gds/callback?code=2fe545bca5ab9ced8a80b07063bf7005b1ba3b2b3fc02c370f1fd0ea366535e1&state=b6cec9870ae3c453c1ce03e01a251bad2134617d3a92b425" for 127.0.0.1 at 2016-12-20 12:13:54 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"2fe545bca5ab9ced8a80b07063bf7005b1ba3b2b3fc02c370f1fd0ea366535e1", "state"=>"b6cec9870ae3c453c1ce03e01a251bad2134617d3a92b425"}
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.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 2016-12-20 12:13:54 +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 3ms (Views: 0.3ms | ActiveRecord: 0.2ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:54 +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 2016-12-20 12:13:54 +0000
Started GET "/auth/gds/callback?code=9e72ca947db57c4a38a57cebb7278dc1136149a72edcdce5b9b5da90f9a6b332&state=a1db84704077308e11bc62eb6f4eb9abc0c1101a0d5e534a" for 127.0.0.1 at 2016-12-20 12:13:54 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"9e72ca947db57c4a38a57cebb7278dc1136149a72edcdce5b9b5da90f9a6b332", "state"=>"a1db84704077308e11bc62eb6f4eb9abc0c1101a0d5e534a"}
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.1ms)  commit transaction
Redirected to http://www.example-client.com/restricted
Completed 302 Found in 6ms (ActiveRecord: 0.4ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:54 +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 2016-12-20 12:13:54 +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 2016-12-20 12:13:54 +0000
Started GET "/auth/gds/callback?code=f754f3fc8f691d7761bb423ce1a32714eb5033a9ec610293b36b3f960bed6326&state=d53ac52bd80f458329539de3659c9930f94961c168bb7ff3" for 127.0.0.1 at 2016-12-20 12:13:55 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"f754f3fc8f691d7761bb423ce1a32714eb5033a9ec610293b36b3f960bed6326", "state"=>"d53ac52bd80f458329539de3659c9930f94961c168bb7ff3"}
Authenticating with gds_sso strategy
  User Load (0.4ms)  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 5ms (ActiveRecord: 0.6ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:55 +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 3ms (Views: 0.5ms | ActiveRecord: 0.3ms)
  User Load (0.3ms)  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", 1]]
   (10.8ms)  commit transaction
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:55 +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 2ms (ActiveRecord: 0.2ms)
Started GET "/auth/gds" for 127.0.0.1 at 2016-12-20 12:13:55 +0000
Started GET "/auth/gds/callback?code=93557adfd1170e5330a63bc9d3ccbcd44bcf850746ad17f1b80b32f7bfc6d61e&state=f958569a1792a0691bc38738bc879814229af5d76b183065" for 127.0.0.1 at 2016-12-20 12:13:55 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"93557adfd1170e5330a63bc9d3ccbcd44bcf850746ad17f1b80b32f7bfc6d61e", "state"=>"f958569a1792a0691bc38738bc879814229af5d76b183065"}
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.1ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.3ms)  UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ?  [["remotely_signed_out", false], ["id", 1]]
   (12.7ms)  commit transaction
Redirected to http://www.example-client.com/restricted
Completed 302 Found in 20ms (ActiveRecord: 13.6ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:55 +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 2016-12-20 12:13:55 +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 2016-12-20 12:13:55 +0000
Started GET "/auth/gds/callback?code=2f4c371ee353aa938a0c0b4884d678c9ca1a3b8f0c4c0ba4f6062409d7a2678b&state=80046ff1a8d68fb5fd872abbbd7a277d13b173fd02bec941" for 127.0.0.1 at 2016-12-20 12:13:55 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"2f4c371ee353aa938a0c0b4884d678c9ca1a3b8f0c4c0ba4f6062409d7a2678b", "state"=>"80046ff1a8d68fb5fd872abbbd7a277d13b173fd02bec941"}
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.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 2016-12-20 12:13:55 +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 2016-12-21 08:18:55 +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 2016-12-21 08:18:55 +0000
Started GET "/auth/gds/callback?code=cf55602d6aac2394eaa6601b069943fbabbfb2b9648bbd7c3d4e463c1ff20a3a&state=d4945f2e66485f1f80aa6c5b875367524a245bfb194ca9e6" for 127.0.0.1 at 2016-12-21 08:18:55 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"cf55602d6aac2394eaa6601b069943fbabbfb2b9648bbd7c3d4e463c1ff20a3a", "state"=>"d4945f2e66485f1f80aa6c5b875367524a245bfb194ca9e6"}
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.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 2016-12-21 08:18:55 +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 2016-12-20 12:13:55 +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 2016-12-20 12:13:55 +0000
Started GET "/auth/gds/callback?code=eda09e29bd8e2830e0075c5db8fe57e905af2effeb707f71ed2d81fad615311e&state=0c893c6f4a0c2c3084337e46e77fbc9f4494a2f5b5d53004" for 127.0.0.1 at 2016-12-20 12:13:56 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"eda09e29bd8e2830e0075c5db8fe57e905af2effeb707f71ed2d81fad615311e", "state"=>"0c893c6f4a0c2c3084337e46e77fbc9f4494a2f5b5d53004"}
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.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 2016-12-20 12:13:56 +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.1ms)
Completed 200 OK in 2ms (Views: 0.4ms | ActiveRecord: 0.2ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-21 08:18:56 +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 2016-12-21 08:18:56 +0000
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:56 +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 2016-12-20 12:13:56 +0000
Started GET "/auth/gds/callback?code=d9773150bbaed328cbc0e9467a34f1a9e64ea2b90e6bc724f57ed6d02b33887d&state=4db4e0eb8647cf92aa8bc997695258ce59a493270ae07002" for 127.0.0.1 at 2016-12-20 12:13:56 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"d9773150bbaed328cbc0e9467a34f1a9e64ea2b90e6bc724f57ed6d02b33887d", "state"=>"4db4e0eb8647cf92aa8bc997695258ce59a493270ae07002"}
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.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 2016-12-20 12:13:56 +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 2016-12-21 08:08:56 +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 2016-12-20 12:13:56 +0000
Processing by ExampleController#restricted as JSON
Completed   in 24ms (ActiveRecord: 0.0ms)
Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-12-20 12:13:56 +0000
Processing by ExampleController#this_requires_signin_permission as JSON
  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
  SQL (0.2ms)  UPDATE "users" SET "disabled" = ? WHERE "users"."id" = ?  [["disabled", nil], ["id", 1]]
   (16.8ms)  commit transaction
  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.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.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.1ms)  commit transaction
  Rendering text template
  Rendered text template (0.0ms)
Completed 200 OK in 97ms (Views: 0.4ms | ActiveRecord: 18.2ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:56 +0000
Processing by ExampleController#restricted as JSON
  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.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.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.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.1ms)  commit transaction
  Rendering text template
  Rendered text template (0.0ms)
Completed 200 OK in 86ms (Views: 0.4ms | ActiveRecord: 1.0ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:13:56 +0000
Processing by ExampleController#restricted as JSON
Completed   in 19ms (ActiveRecord: 0.0ms)
  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]]
   (11.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.1ms)  begin transaction
   (0.1ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.3ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "Moshua Jarshall"], ["uid", "a1s2d38884"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]
   (11.3ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "SSO Push user"], ["uid", "a1s2d37324"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (5.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 2ms (ActiveRecord: 0.1ms)
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "Moshua Jarshall"], ["uid", "a1s2d38288"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]
   (8.7ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "SSO Push user"], ["uid", "a1s2d36018"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (7.0ms)  commit transaction
Processing by Api::UserController#reauth as HTML
  Parameters: {"uid"=>"a1s2d38288"}
  Rendering /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised
  Rendered /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.3ms)
Completed 403 Forbidden in 8ms (Views: 7.0ms | ActiveRecord: 0.0ms)
   (0.1ms)  begin transaction
  SQL (0.4ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "Moshua Jarshall"], ["uid", "a1s2d34383"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]
   (17.2ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "SSO Push user"], ["uid", "a1s2d31988"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (8.7ms)  commit transaction
Processing by Api::UserController#reauth as HTML
  Parameters: {"uid"=>"a1s2d34383"}
  User Load (0.2ms)  SELECT  "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ?  [["uid", "a1s2d34383"], ["LIMIT", 1]]
   (0.1ms)  begin transaction
  SQL (0.2ms)  UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ?  [["remotely_signed_out", true], ["id", 7]]
   (7.6ms)  commit transaction
Completed 200 OK in 11ms (ActiveRecord: 8.1ms)
  User Load (0.2ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = ? LIMIT ?  [["id", 7], ["LIMIT", 1]]
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "Moshua Jarshall"], ["uid", "a1s2d34858"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]
   (8.2ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "SSO Push user"], ["uid", "a1s2d37304"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (9.1ms)  commit transaction
Processing by Api::UserController#update as HTML
  Parameters: {"uid"=>"a1s2d34858"}
  User Load (0.2ms)  SELECT  "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ?  [["uid", "a1s2d34858"], ["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", 9]]
   (9.1ms)  commit transaction
Completed 200 OK in 14ms (ActiveRecord: 9.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", "a1s2d38853"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]
   (24.6ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.3ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "SSO Push user"], ["uid", "a1s2d3825"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (21.1ms)  commit transaction
Processing by Api::UserController#update as HTML
  Parameters: {"uid"=>"a1s2d38853"}
  Rendering /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised
  Rendered /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.1ms)
Completed 403 Forbidden in 2ms (Views: 1.3ms | ActiveRecord: 0.0ms)
   (18.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') 
   (11.8ms)  CREATE TABLE "schema_migrations" ("version" varchar NOT NULL) 
   (0.1ms)  select sqlite_version(*)
   (8.7ms)  CREATE UNIQUE INDEX "unique_schema_migrations" ON "schema_migrations" ("version")
  User Load (0.2ms)  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.3ms)  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]]
   (17.0ms)  commit transaction
  User Load (0.1ms)  SELECT  "users".* FROM "users" WHERE "users"."uid" = ?  ORDER BY "users"."id" ASC LIMIT 1  [["uid", "asd"]]
   (0.1ms)  begin transaction
   (0.1ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.3ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d34590"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]
   (49.8ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d36466"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (127.9ms)  commit transaction
Processing by Api::UserController#reauth as HTML
  Parameters: {"uid"=>"a1s2d34590"}
  Rendered /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.3ms)
Completed 403 Forbidden in 9ms (Views: 8.7ms | ActiveRecord: 0.0ms)
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d39434"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]
   (33.3ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d36793"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (57.5ms)  commit transaction
Processing by Api::UserController#reauth as HTML
  Parameters: {"uid"=>"a1s2d39434"}
  User Load (0.1ms)  SELECT  "users".* FROM "users" WHERE "users"."uid" = ?  ORDER BY "users"."id" ASC LIMIT 1  [["uid", "a1s2d39434"]]
   (0.1ms)  begin transaction
  SQL (0.2ms)  UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ?  [["remotely_signed_out", "t"], ["id", 4]]
   (28.2ms)  commit transaction
Completed 200 OK in 32ms (ActiveRecord: 28.6ms)
  User Load (0.2ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1  [["id", 4]]
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d39628"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]
   (21.9ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d34159"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (45.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 1  [["uid", "nonexistent-user"]]
Completed 200 OK in 1ms (ActiveRecord: 0.1ms)
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d37093"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]
   (29.8ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d37407"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (26.3ms)  commit transaction
Processing by Api::UserController#update as HTML
  Parameters: {"uid"=>"a1s2d37093"}
  Rendered /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.1ms)
Completed 403 Forbidden in 1ms (Views: 0.5ms | ActiveRecord: 0.0ms)
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d34602"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]
   (18.3ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?)  [["uid", "a1s2d32032"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (8.4ms)  commit transaction
Processing by Api::UserController#update as HTML
  Parameters: {"uid"=>"a1s2d34602"}
  User Load (0.1ms)  SELECT  "users".* FROM "users" WHERE "users"."uid" = ?  ORDER BY "users"."id" ASC LIMIT 1  [["uid", "a1s2d34602"]]
   (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", 10]]
   (56.6ms)  commit transaction
Completed 200 OK in 61ms (ActiveRecord: 57.0ms)
  User Load (0.2ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1  [["id", 10]]
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:01 +0000
Processing by ExampleController#restricted as HTML
Authenticating with gds_sso strategy
Completed   in 9ms (ActiveRecord: 0.0ms)
Started GET "/auth/gds" for 127.0.0.1 at 2016-12-20 12:14:01 +0000
Started GET "/auth/gds/callback?code=e83c574e24c350ff3a8edc04116dd82d5c6d5423807be6f248399172b2249c86&state=1c6f0e587f72cbd849afd01c9e44eb50d3eda24fadf36c2d" for 127.0.0.1 at 2016-12-20 12:14:01 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"e83c574e24c350ff3a8edc04116dd82d5c6d5423807be6f248399172b2249c86", "state"=>"1c6f0e587f72cbd849afd01c9e44eb50d3eda24fadf36c2d"}
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"]]
  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"]]
   (55.8ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ?  [["remotely_signed_out", "f"], ["id", 12]]
   (59.9ms)  commit transaction
Redirected to http://www.example-client.com/restricted
Completed 302 Found in 124ms (ActiveRecord: 116.6ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:01 +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: 1.3ms | ActiveRecord: 0.2ms)
Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-12-20 12:14:01 +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 2016-12-20 12:14:01 +0000
Started GET "/auth/gds/callback?code=815014e9b0d21da1e755c05a6ec370c5dcf1281a4a0d5163a3ab154749c5e5b9&state=d2f7ed5aa6a311325022c700508774724d382acaf0e7bf63" for 127.0.0.1 at 2016-12-20 12:14:02 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"815014e9b0d21da1e755c05a6ec370c5dcf1281a4a0d5163a3ab154749c5e5b9", "state"=>"d2f7ed5aa6a311325022c700508774724d382acaf0e7bf63"}
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/this_requires_signin_permission
Completed 302 Found in 4ms (ActiveRecord: 0.4ms)
Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-12-20 12:14:02 +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 2016-12-20 12:14:02 +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 2016-12-20 12:14:02 +0000
Started GET "/auth/gds/callback?code=5e9b99cb06e1c34740db954da63a7eb2e560d3192cacf8909335c94021848514&state=697b0a2a06803b0b60b94edcfa5e06d51bbffdc801f042e8" for 127.0.0.1 at 2016-12-20 12:14:02 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"5e9b99cb06e1c34740db954da63a7eb2e560d3192cacf8909335c94021848514", "state"=>"697b0a2a06803b0b60b94edcfa5e06d51bbffdc801f042e8"}
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.1ms)  commit transaction
   (0.1ms)  begin transaction
   (0.1ms)  commit transaction
Redirected to http://www.example-client.com/this_requires_signin_permission
Completed 302 Found in 5ms (ActiveRecord: 0.5ms)
Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-12-20 12:14:02 +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 "/restricted" for 127.0.0.1 at 2016-12-20 12:14:02 +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 2016-12-20 12:14:02 +0000
Started GET "/auth/gds/callback?code=f61dc7b0678d75071939e02a36a56ffe8cedfb1080fdbf3ebed8f6457c149323&state=652b84b2aec0cb3cfeaeacec285ccabd80e515f432676b10" for 127.0.0.1 at 2016-12-20 12:14:02 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"f61dc7b0678d75071939e02a36a56ffe8cedfb1080fdbf3ebed8f6457c149323", "state"=>"652b84b2aec0cb3cfeaeacec285ccabd80e515f432676b10"}
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 2016-12-20 12:14:02 +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 2ms (Views: 0.3ms | ActiveRecord: 0.1ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:02 +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 2016-12-20 12:14:02 +0000
Started GET "/auth/gds/callback?code=ddb00bddd9c83f7f2fef1957866c328b0fbc5497ed58aff9cf450dde57cfd78d&state=37b1f68c09a1a2ab6d6c363cb0bebe09a9bf02f3ed77fc79" for 127.0.0.1 at 2016-12-20 12:14:02 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"ddb00bddd9c83f7f2fef1957866c328b0fbc5497ed58aff9cf450dde57cfd78d", "state"=>"37b1f68c09a1a2ab6d6c363cb0bebe09a9bf02f3ed77fc79"}
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 2016-12-20 12:14:02 +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 2ms (Views: 0.3ms | ActiveRecord: 0.1ms)
Started GET "/" for 127.0.0.1 at 2016-12-20 12:14:02 +0000
Processing by ExampleController#index as HTML
  Rendered text template (0.0ms)
Completed 200 OK in 0ms (Views: 0.3ms | ActiveRecord: 0.0ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:02 +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 2016-12-20 12:14:02 +0000
Started GET "/auth/gds/callback?code=5d782eb8f92316cc6e1c2aa278e5bdb71e9c1fb7aa5d295ccf21198682694534&state=d3cfca2752cbf51b944c5e70e1738df35602e8c3f640ab23" for 127.0.0.1 at 2016-12-20 12:14:03 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"5d782eb8f92316cc6e1c2aa278e5bdb71e9c1fb7aa5d295ccf21198682694534", "state"=>"d3cfca2752cbf51b944c5e70e1738df35602e8c3f640ab23"}
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 5ms (ActiveRecord: 0.4ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:03 +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 2ms (Views: 0.3ms | ActiveRecord: 0.1ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-21 08:19:03 +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 2016-12-21 08:19:03 +0000
Started GET "/auth/gds/callback?code=1b136b2495606a2bf087a88aaf75a16938bc4c46478aaaf986b56dd879ee0741&state=b0bd5ae90cd2d6153d28844ec95ab09ff0f0a6872cec177b" for 127.0.0.1 at 2016-12-21 08:19:03 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"1b136b2495606a2bf087a88aaf75a16938bc4c46478aaaf986b56dd879ee0741", "state"=>"b0bd5ae90cd2d6153d28844ec95ab09ff0f0a6872cec177b"}
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.1ms)  commit transaction
   (0.1ms)  begin transaction
   (0.1ms)  commit transaction
Redirected to http://www.example-client.com/restricted
Completed 302 Found in 5ms (ActiveRecord: 0.5ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-21 08:19:03 +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 2ms (Views: 0.3ms | ActiveRecord: 0.1ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:03 +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 2016-12-20 12:14:03 +0000
Started GET "/auth/gds/callback?code=03db107ba23a498b84abac261855f02c826e2cc5911ac3472d5d24adf6735430&state=cce2324be8ea1af35578a28cbab9fc3f7ff1ba2058e318b2" for 127.0.0.1 at 2016-12-20 12:14:03 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"03db107ba23a498b84abac261855f02c826e2cc5911ac3472d5d24adf6735430", "state"=>"cce2324be8ea1af35578a28cbab9fc3f7ff1ba2058e318b2"}
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 5ms (ActiveRecord: 0.4ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:03 +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 2016-12-21 08:09:03 +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.1ms)
Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.1ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:03 +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 2016-12-20 12:14:03 +0000
Started GET "/auth/gds/callback?code=339c75ffaa47170c9f408b88132d9d4f2b5d87690c36819a1216662484ae81d0&state=4fbd0c12c577843925499060671b572d7f4e49879704627a" for 127.0.0.1 at 2016-12-20 12:14:03 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"339c75ffaa47170c9f408b88132d9d4f2b5d87690c36819a1216662484ae81d0", "state"=>"4fbd0c12c577843925499060671b572d7f4e49879704627a"}
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 5ms (ActiveRecord: 0.4ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:03 +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 2ms (Views: 0.3ms | ActiveRecord: 0.1ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-21 08:19:03 +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 2016-12-21 08:19:03 +0000
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:03 +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 2016-12-20 12:14:03 +0000
Started GET "/auth/gds/callback?code=45976954b052808db424af8655041bfd5636b8ab31e88300a2bfc6e4af321335&state=e9b07ec972a760de7b8eae193c3258cb02d35379ba595005" for 127.0.0.1 at 2016-12-20 12:14:03 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"45976954b052808db424af8655041bfd5636b8ab31e88300a2bfc6e4af321335", "state"=>"e9b07ec972a760de7b8eae193c3258cb02d35379ba595005"}
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 5ms (ActiveRecord: 0.4ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14: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 2ms (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.2ms)  UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ?  [["remotely_signed_out", "t"], ["id", 12]]
   (283.7ms)  commit transaction
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14: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"]]
Authenticating with gds_sso strategy
Completed   in 1ms (ActiveRecord: 0.1ms)
Started GET "/auth/gds" for 127.0.0.1 at 2016-12-20 12:14:04 +0000
Started GET "/auth/gds/callback?code=e8aaee5efec2952249ba030aa7f13a3fdefe8310081596ef31995a008cc1e839&state=136e87f9ea15c62569bded7132587fea1c23d5c22c26a2d7" for 127.0.0.1 at 2016-12-20 12:14:04 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"e8aaee5efec2952249ba030aa7f13a3fdefe8310081596ef31995a008cc1e839", "state"=>"136e87f9ea15c62569bded7132587fea1c23d5c22c26a2d7"}
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
  SQL (0.1ms)  UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ?  [["remotely_signed_out", "f"], ["id", 12]]
   (109.5ms)  commit transaction
Redirected to http://www.example-client.com/restricted
Completed 302 Found in 115ms (ActiveRecord: 110.0ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14: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 2ms (Views: 0.3ms | ActiveRecord: 0.1ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:04 +0000
Processing by ExampleController#restricted as JSON
  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
  SQL (0.2ms)  UPDATE "users" SET "disabled" = ? WHERE "users"."id" = ?  [["disabled", nil], ["id", 12]]
   (44.2ms)  commit transaction
  User Load (0.2ms)  SELECT  "users".* FROM "users" WHERE "users"."uid" = ?  ORDER BY "users"."id" ASC LIMIT 1  [["uid", "integration-uid"]]
   (0.2ms)  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.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.1ms)  begin transaction
   (0.1ms)  commit transaction
   (0.1ms)  begin transaction
   (0.1ms)  commit transaction
  Rendered text template (0.0ms)
Completed 200 OK in 118ms (Views: 0.3ms | ActiveRecord: 45.6ms)
Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-12-20 12:14:04 +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 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.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.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.1ms)  begin transaction
   (0.1ms)  commit transaction
   (0.1ms)  begin transaction
   (0.1ms)  commit transaction
  Rendered text template (0.0ms)
Completed 200 OK in 70ms (Views: 0.4ms | ActiveRecord: 1.0ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:04 +0000
Processing by ExampleController#restricted as JSON
Completed   in 16ms (ActiveRecord: 0.0ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:04 +0000
Processing by ExampleController#restricted as JSON
Completed   in 16ms (ActiveRecord: 0.0ms)
   (62.8ms)  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')
   (26.6ms)  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.2ms)  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", 2016-12-20 12:14:08 UTC], ["updated_at", 2016-12-20 12:14:08 UTC]]
   (48.2ms)  commit transaction
   (22.5ms)  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.1ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "Moshua Jarshall"], ["uid", "a1s2d32278"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]
   (16.2ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "SSO Push user"], ["uid", "a1s2d38130"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (20.4ms)  commit transaction
Processing by Api::UserController#update as HTML
  Parameters: {"uid"=>"a1s2d32278"}
  User Load (0.2ms)  SELECT  "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ?  [["uid", "a1s2d32278"], ["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", 1]]
   (15.5ms)  commit transaction
Completed 200 OK in 22ms (ActiveRecord: 16.0ms)
  User Load (0.2ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = ? LIMIT ?  [["id", 1], ["LIMIT", 1]]
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "Moshua Jarshall"], ["uid", "a1s2d36805"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]
   (17.4ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "SSO Push user"], ["uid", "a1s2d3981"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (14.4ms)  commit transaction
Processing by Api::UserController#update as HTML
  Parameters: {"uid"=>"a1s2d36805"}
  Rendering /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised
  Rendered /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.3ms)
Completed 403 Forbidden in 9ms (Views: 8.6ms | ActiveRecord: 0.0ms)
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "Moshua Jarshall"], ["uid", "a1s2d36327"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]
   (15.0ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "SSO Push user"], ["uid", "a1s2d31900"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (10.8ms)  commit transaction
Processing by Api::UserController#reauth as HTML
  Parameters: {"uid"=>"a1s2d36327"}
  User Load (0.1ms)  SELECT  "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ?  [["uid", "a1s2d36327"], ["LIMIT", 1]]
   (0.1ms)  begin transaction
  SQL (0.2ms)  UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ?  [["remotely_signed_out", true], ["id", 5]]
   (11.5ms)  commit transaction
Completed 200 OK in 15ms (ActiveRecord: 11.8ms)
  User Load (0.1ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = ? LIMIT ?  [["id", 5], ["LIMIT", 1]]
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "Moshua Jarshall"], ["uid", "a1s2d31201"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]
   (16.8ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "SSO Push user"], ["uid", "a1s2d35356"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (55.4ms)  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.2ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "Moshua Jarshall"], ["uid", "a1s2d35825"], ["email", "old@domain.com"], ["permissions", "---\n- signin\n"]]
   (53.0ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  INSERT INTO "users" ("name", "uid", "email", "permissions") VALUES (?, ?, ?, ?)  [["name", "SSO Push user"], ["uid", "a1s2d33840"], ["email", "ssopushuser@legit.com"], ["permissions", "---\n- signin\n- user_update_permission\n"]]
   (12.5ms)  commit transaction
Processing by Api::UserController#reauth as HTML
  Parameters: {"uid"=>"a1s2d35825"}
  Rendering /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised
  Rendered /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.0ms)
Completed 403 Forbidden in 1ms (Views: 0.7ms | ActiveRecord: 0.0ms)
  User Load (0.1ms)  SELECT  "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ?  [["uid", "asd"], ["LIMIT", 1]]
  User Load (0.2ms)  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]]
   (34.1ms)  commit transaction
  User Load (0.2ms)  SELECT  "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT ?  [["uid", "asd"], ["LIMIT", 1]]
   (0.1ms)  begin transaction
   (0.1ms)  commit transaction
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:09 +0000
Processing by ExampleController#restricted as HTML
Authenticating with gds_sso strategy
Completed   in 8ms (ActiveRecord: 0.0ms)
Started GET "/auth/gds" for 127.0.0.1 at 2016-12-20 12:14:09 +0000
Started GET "/auth/gds/callback?code=d8dc5f3f1e4f979188078210eb672cc65e65886a1911d3a04e007b6920639aae&state=aacd9976277328788208a01786c2d724c983a1af89b3428c" for 127.0.0.1 at 2016-12-20 12:14:09 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"d8dc5f3f1e4f979188078210eb672cc65e65886a1911d3a04e007b6920639aae", "state"=>"aacd9976277328788208a01786c2d724c983a1af89b3428c"}
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]]
  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"]]
   (41.4ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ?  [["remotely_signed_out", false], ["id", 12]]
   (32.3ms)  commit transaction
Redirected to http://www.example-client.com/restricted
Completed 302 Found in 81ms (ActiveRecord: 74.8ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:09 +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 3ms (Views: 1.4ms | ActiveRecord: 0.2ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:09 +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 2016-12-20 12:14:09 +0000
Started GET "/auth/gds/callback?code=6454c026e285afaade3a0287a25f253e179535e150366a539d95c1abb56c781c&state=bd7243c7e76af115c65015bda69fe6ba81f9d5990191e936" for 127.0.0.1 at 2016-12-20 12:14:09 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"6454c026e285afaade3a0287a25f253e179535e150366a539d95c1abb56c781c", "state"=>"bd7243c7e76af115c65015bda69fe6ba81f9d5990191e936"}
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.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 2016-12-20 12:14:09 +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 2016-12-20 12:14:09 +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 2016-12-20 12:14:09 +0000
Started GET "/auth/gds/callback?code=80e5e5b28eee67bab0781cf4c142b6780cc1b7880cf6d51136b354cd3fb5cf9f&state=7a704ce64594ad2f0d857d02e7e650ca49316059a861cec9" for 127.0.0.1 at 2016-12-20 12:14:09 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"80e5e5b28eee67bab0781cf4c142b6780cc1b7880cf6d51136b354cd3fb5cf9f", "state"=>"7a704ce64594ad2f0d857d02e7e650ca49316059a861cec9"}
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 4ms (ActiveRecord: 0.4ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:09 +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 2016-12-20 12:14:09 +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 2016-12-20 12:14:09 +0000
Started GET "/auth/gds/callback?code=d67a4a1b558a511c1ad6b1f2c3812383c8cb3f0f0a26b57165027a34b7cabf66&state=015ab0b69b3f7d1ee20818ddfa8ac11a9531568e29cf0cde" for 127.0.0.1 at 2016-12-20 12:14:10 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"d67a4a1b558a511c1ad6b1f2c3812383c8cb3f0f0a26b57165027a34b7cabf66", "state"=>"015ab0b69b3f7d1ee20818ddfa8ac11a9531568e29cf0cde"}
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.1ms)  commit transaction
Redirected to http://www.example-client.com/this_requires_signin_permission
Completed 302 Found in 4ms (ActiveRecord: 0.4ms)
Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-12-20 12:14:10 +0000
Processing by ExampleController#this_requires_signin_permission as HTML
  User Load (0.4ms)  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.4ms)
Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-12-20 12:14:10 +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 2016-12-20 12:14:10 +0000
Started GET "/auth/gds/callback?code=cdad962a36a08db481fe4fecede9f8cc1cad75e8b062efc1f2f9ca7d914cd492&state=7e5b155263da27fc8d73ea1f08761c51db8fb1548965f534" for 127.0.0.1 at 2016-12-20 12:14:10 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"cdad962a36a08db481fe4fecede9f8cc1cad75e8b062efc1f2f9ca7d914cd492", "state"=>"7e5b155263da27fc8d73ea1f08761c51db8fb1548965f534"}
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.1ms)  commit transaction
Redirected to http://www.example-client.com/this_requires_signin_permission
Completed 302 Found in 4ms (ActiveRecord: 0.4ms)
Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-12-20 12:14:10 +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 2ms (Views: 0.3ms | ActiveRecord: 0.2ms)
Started GET "/" for 127.0.0.1 at 2016-12-20 12:14:10 +0000
Processing by ExampleController#index as HTML
  Rendering text template
  Rendered text template (0.0ms)
Completed 200 OK in 1ms (Views: 0.3ms | ActiveRecord: 0.0ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:10 +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 2016-12-20 12:14:10 +0000
Started GET "/auth/gds/callback?code=999e4432f7bc83f228510f96699d778c15f0c70804900a679decfecca294149b&state=8c12733cf664d98a06a6ff8733f940688ea9bdef5d6dfcbf" for 127.0.0.1 at 2016-12-20 12:14:10 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"999e4432f7bc83f228510f96699d778c15f0c70804900a679decfecca294149b", "state"=>"8c12733cf664d98a06a6ff8733f940688ea9bdef5d6dfcbf"}
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.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 2016-12-20 12:14:10 +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.1ms)  begin transaction
  SQL (0.3ms)  UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ?  [["remotely_signed_out", true], ["id", 12]]
   (16.3ms)  commit transaction
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:10 +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 2ms (ActiveRecord: 0.2ms)
Started GET "/auth/gds" for 127.0.0.1 at 2016-12-20 12:14:10 +0000
Started GET "/auth/gds/callback?code=587251ab2106b620669466be04d27c6654c5e7c8d2b7c17bd1612e6f84b5edae&state=28d71131564fb6b03e614171919d5ba4d9301592c363a253" for 127.0.0.1 at 2016-12-20 12:14:10 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"587251ab2106b620669466be04d27c6654c5e7c8d2b7c17bd1612e6f84b5edae", "state"=>"28d71131564fb6b03e614171919d5ba4d9301592c363a253"}
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.1ms)  commit transaction
   (0.1ms)  begin transaction
  SQL (0.2ms)  UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ?  [["remotely_signed_out", false], ["id", 12]]
   (31.1ms)  commit transaction
Redirected to http://www.example-client.com/restricted
Completed 302 Found in 36ms (ActiveRecord: 31.7ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:11 +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 2016-12-20 12:14:11 +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 2016-12-20 12:14:11 +0000
Started GET "/auth/gds/callback?code=cfc2685d922c20e75a7f1d20b934df05f23e946e3f15ecef516f23905acedb07&state=aea99e3314d693dbb15b849aab75622a8a02c6879af64e94" for 127.0.0.1 at 2016-12-20 12:14:11 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"cfc2685d922c20e75a7f1d20b934df05f23e946e3f15ecef516f23905acedb07", "state"=>"aea99e3314d693dbb15b849aab75622a8a02c6879af64e94"}
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.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 2016-12-20 12:14:11 +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 3ms (Views: 0.3ms | ActiveRecord: 0.3ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-21 08:19:11 +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 2016-12-21 08:19:11 +0000
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:11 +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 2016-12-20 12:14:11 +0000
Started GET "/auth/gds/callback?code=cc8e3d9ba9293b955555a89768762ce042047954203cc212ff0c40084773b2a3&state=ea6a2412469dde362d03b75a0c8564f429102b049922442c" for 127.0.0.1 at 2016-12-20 12:14:11 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"cc8e3d9ba9293b955555a89768762ce042047954203cc212ff0c40084773b2a3", "state"=>"ea6a2412469dde362d03b75a0c8564f429102b049922442c"}
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.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 2016-12-20 12:14:11 +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 2016-12-21 08:19:11 +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 2016-12-21 08:19:11 +0000
Started GET "/auth/gds/callback?code=265d8668574607c86d4d00412135ca852843df7d4f2d7763a0ab34cb035e7ec1&state=2cb9733c5a52d5b5baca3dc7d994508d94e68134fce016e0" for 127.0.0.1 at 2016-12-21 08:19:11 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"265d8668574607c86d4d00412135ca852843df7d4f2d7763a0ab34cb035e7ec1", "state"=>"2cb9733c5a52d5b5baca3dc7d994508d94e68134fce016e0"}
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.1ms)  commit transaction
Redirected to http://www.example-client.com/restricted
Completed 302 Found in 4ms (ActiveRecord: 0.5ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-21 08:19:11 +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.4ms | ActiveRecord: 0.3ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:11 +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 2016-12-20 12:14:11 +0000
Started GET "/auth/gds/callback?code=31e8519894ba3863039ba3f1e53d8fc6af605386299e4dd3df858f748027c413&state=0d3dfd7f5d02df402964f955d6e1556024c3c1a61076779d" for 127.0.0.1 at 2016-12-20 12:14:11 +0000
Processing by AuthenticationsController#callback as HTML
  Parameters: {"code"=>"31e8519894ba3863039ba3f1e53d8fc6af605386299e4dd3df858f748027c413", "state"=>"0d3dfd7f5d02df402964f955d6e1556024c3c1a61076779d"}
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.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 2016-12-20 12:14:11 +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 2016-12-21 08:09:11 +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 2016-12-20 12:14:11 +0000
Processing by ExampleController#restricted as JSON
Completed   in 20ms (ActiveRecord: 0.0ms)
Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-12-20 12:14:12 +0000
Processing by ExampleController#this_requires_signin_permission as JSON
  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
  SQL (0.2ms)  UPDATE "users" SET "disabled" = ? WHERE "users"."id" = ?  [["disabled", nil], ["id", 12]]
   (14.7ms)  commit transaction
  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.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.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.1ms)  commit transaction
  Rendering text template
  Rendered text template (0.0ms)
Completed 200 OK in 95ms (Views: 0.4ms | ActiveRecord: 16.0ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:12 +0000
Processing by ExampleController#restricted as JSON
  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.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.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.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.1ms)  commit transaction
  Rendering text template
  Rendered text template (0.0ms)
Completed 200 OK in 91ms (Views: 0.5ms | ActiveRecord: 1.0ms)
Started GET "/restricted" for 127.0.0.1 at 2016-12-20 12:14:12 +0000
Processing by ExampleController#restricted as JSON
Completed   in 21ms (ActiveRecord: 0.0ms)