Connecting to database specified by database.yml Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:52:56 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 3.0ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:52:56 +0000 Started GET "/auth/gds/callback?code=f67c74248e9d73e3f31ac5ffa83df9588aeb8f3f44081a67b8515e893c759553&state=394e8a4b045ec2ba159b259a6dd7077323719d4743153bf3" for 127.0.0.1 at 2016-02-12 10:53:10 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"f67c74248e9d73e3f31ac5ffa83df9588aeb8f3f44081a67b8515e893c759553", "state"=>"394e8a4b045ec2ba159b259a6dd7077323719d4743153bf3"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1 User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."email" = 'test@example-client.com' LIMIT 1  (0.1ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "test@example-client.com"], ["name", "Test User"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "integration-uid"]]  (22.8ms) commit transaction  (0.1ms) begin transaction  (0.4ms) UPDATE "users" SET "remotely_signed_out" = 'f', "permissions" = '--- - signin ' WHERE "users"."id" = 1  (18.6ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 73.0ms (ActiveRecord: 43.8ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:11 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Rendered text template (0.0ms) Completed 200 OK in 21.0ms (Views: 16.9ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:11 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.4ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:53:11 +0000 Started GET "/auth/gds/callback?code=601344f988bf65236b0d894c1606c6c3e425a3d3708f0e09617302d41b0bd4c1&state=1b7d67be60e52fa2abf1857932f2c6daa37cb7ad80e7ab49" for 127.0.0.1 at 2016-02-12 10:53:11 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"601344f988bf65236b0d894c1606c6c3e425a3d3708f0e09617302d41b0bd4c1", "state"=>"1b7d67be60e52fa2abf1857932f2c6daa37cb7ad80e7ab49"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (12.8ms) commit transaction  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (11.8ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 31.0ms (ActiveRecord: 25.4ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:11 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Rendered text template (0.0ms) Completed 200 OK in 1.8ms (Views: 0.4ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:11 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.3ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:53:11 +0000 Started GET "/auth/gds/callback?code=4c401f73016f62386dae6d1eddfe01fedb4e57fa92017ef899d24b0d9f925d85&state=ea1fa0533a0a1be049376bbe6a6c71073b559fdc6591a234" for 127.0.0.1 at 2016-02-12 10:53:11 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"4c401f73016f62386dae6d1eddfe01fedb4e57fa92017ef899d24b0d9f925d85", "state"=>"ea1fa0533a0a1be049376bbe6a6c71073b559fdc6591a234"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (12.6ms) commit transaction  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (12.8ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 32.6ms (ActiveRecord: 26.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:11 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.0ms (Views: 0.3ms | ActiveRecord: 0.2ms) Started GET "/" for 127.0.0.1 at 2016-02-12 10:53:11 +0000 Processing by ExampleController#index as HTML Completed 200 OK in 0.9ms (Views: 0.5ms | ActiveRecord: 0.0ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:53:11 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 0.6ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:53:11 +0000 Started GET "/auth/gds/callback?code=178b7e0aa9d347d0c31a5cd4c578b3e60a63011c413f74dc2f5d9f18af89f349&state=14aa145f4573b27b907023b316cce9accbdfdae5070c9292" for 127.0.0.1 at 2016-02-12 10:53:12 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"178b7e0aa9d347d0c31a5cd4c578b3e60a63011c413f74dc2f5d9f18af89f349", "state"=>"14aa145f4573b27b907023b316cce9accbdfdae5070c9292"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (18.9ms) commit transaction  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (9.6ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 35.8ms (ActiveRecord: 29.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:53:12 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.1ms (Views: 0.4ms | ActiveRecord: 0.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:53:12 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 0.2ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:53:12 +0000 Started GET "/auth/gds/callback?code=84653d862f432804c9d442f705684defc1442fc850a0a1183af718694edd6d60&state=d904885e41de583b1b201f1417cb33b671fcbbc4f89aaa64" for 127.0.0.1 at 2016-02-12 10:53:12 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"84653d862f432804c9d442f705684defc1442fc850a0a1183af718694edd6d60", "state"=>"d904885e41de583b1b201f1417cb33b671fcbbc4f89aaa64"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (10.4ms) commit transaction  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (7.0ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 24.6ms (ActiveRecord: 18.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:53:12 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 1.9ms (Views: 0.2ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:12 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.3ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:53:12 +0000 Started GET "/auth/gds/callback?code=2123debbf7690643476684410315afde0a36c67359570abce159b273e2172a09&state=0a7e954524533ba7b00d43d2c063b8af3eb444dd9512a36d" for 127.0.0.1 at 2016-02-12 10:53:12 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"2123debbf7690643476684410315afde0a36c67359570abce159b273e2172a09", "state"=>"0a7e954524533ba7b00d43d2c063b8af3eb444dd9512a36d"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (10.3ms) commit transaction  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (13.5ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 31.3ms (ActiveRecord: 24.7ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:12 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.2ms (Views: 0.4ms | ActiveRecord: 0.3ms) User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."email" = 'test@example-client.com' LIMIT 1  (0.0ms) begin transaction  (0.2ms) UPDATE "users" SET "remotely_signed_out" = 't', "permissions" = '--- - signin ' WHERE "users"."id" = 1  (10.3ms) commit transaction Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:12 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Authenticating with gds_sso strategy Completed in 1.3ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:53:12 +0000 Started GET "/auth/gds/callback?code=3bc3226ac450e509858e085611c6d7192999b729b2f33e2f1d4b9cc9f585eaa0&state=7b1209f611587bb28fe14545e4a9fc7317eff2934bf074a7" for 127.0.0.1 at 2016-02-12 10:53:13 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"3bc3226ac450e509858e085611c6d7192999b729b2f33e2f1d4b9cc9f585eaa0", "state"=>"7b1209f611587bb28fe14545e4a9fc7317eff2934bf074a7"} Authenticating with gds_sso strategy User Load (0.7ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.5ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (14.8ms) commit transaction  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "remotely_signed_out" = 'f', "permissions" = '--- - signin ' WHERE "users"."id" = 1  (9.8ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 34.4ms (ActiveRecord: 26.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:13 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 1.9ms (Views: 0.3ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:13 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.3ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:53:13 +0000 Started GET "/auth/gds/callback?code=a3b9c71529bf1bbec42779baf57bc9b05a60cbe6dc658d554a0e84d48bff911e&state=25861e84b4c637dfa17b56000bc67c84149ace47ec1e5854" for 127.0.0.1 at 2016-02-12 10:53:13 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"a3b9c71529bf1bbec42779baf57bc9b05a60cbe6dc658d554a0e84d48bff911e", "state"=>"25861e84b4c637dfa17b56000bc67c84149ace47ec1e5854"} Authenticating with gds_sso strategy User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (14.9ms) commit transaction  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (9.2ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 31.4ms (ActiveRecord: 25.1ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:13 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 1.8ms (Views: 0.4ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 06:58:13 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.4ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-13 06:58:13 +0000 Started GET "/auth/gds/callback?code=b0f468d9f632ede82115c384503cb5be8b987811b897ee26af390c2dd700a83c&state=833913710a36ef4aa7b31fb3806ab92a68e597fbac9202e6" for 127.0.0.1 at 2016-02-13 06:58:13 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"b0f468d9f632ede82115c384503cb5be8b987811b897ee26af390c2dd700a83c", "state"=>"833913710a36ef4aa7b31fb3806ab92a68e597fbac9202e6"} Authenticating with gds_sso strategy User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (11.2ms) commit transaction  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (12.2ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 31.1ms (ActiveRecord: 24.5ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 06:58:13 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.0ms (Views: 0.3ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:13 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.3ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:53:13 +0000 Started GET "/auth/gds/callback?code=93053311a83178173429c8cee1502d04b5b2c3e512a9a87145f60e7608530b4a&state=2fe1662210193b4e039b5ab3f13f2bc2bd1422964ebe36e0" for 127.0.0.1 at 2016-02-12 10:53:14 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"93053311a83178173429c8cee1502d04b5b2c3e512a9a87145f60e7608530b4a", "state"=>"2fe1662210193b4e039b5ab3f13f2bc2bd1422964ebe36e0"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (11.4ms) commit transaction  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (11.7ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 32.1ms (ActiveRecord: 24.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:14 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.2ms (Views: 0.5ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 06:48:14 +0000 Processing by ExampleController#restricted as HTML User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.4ms (Views: 0.4ms | ActiveRecord: 0.4ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:53:14 +0000 Processing by ExampleController#this_requires_signin_permission as JSON User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "disabled" = NULL, "permissions" = '--- - signin ' WHERE "users"."id" = 1  (19.0ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.0ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (15.0ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (29.0ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.0ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (17.9ms) commit transaction  (0.2ms) begin transaction  (0.5ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (25.5ms) commit transaction Completed 200 OK in 373.6ms (Views: 0.5ms | ActiveRecord: 109.6ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:14 +0000 Processing by ExampleController#restricted as JSON User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (18.6ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (21.8ms) commit transaction User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (12.6ms) commit transaction User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.0ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (37.7ms) commit transaction  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (36.3ms) commit transaction Completed 200 OK in 226.3ms (Views: 0.7ms | ActiveRecord: 130.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:14 +0000 Processing by ExampleController#restricted as JSON Completed in 22.3ms Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:14 +0000 Processing by ExampleController#restricted as JSON Completed in 28.0ms  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "a1s2d31012"]]  (16.3ms) commit transaction  (0.1ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n- user_update_permission\n"], ["remotely_signed_out", nil], ["uid", "a1s2d3267"]]  (13.4ms) commit transaction WARNING: Can't mass-assign protected attributes: uid, name, permissions Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d31012"} Completed 403 Forbidden in 5.2ms (Views: 3.7ms | ActiveRecord: 0.0ms)  (0.1ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "a1s2d36130"]]  (37.4ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n- user_update_permission\n"], ["remotely_signed_out", nil], ["uid", "a1s2d39378"]]  (20.5ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d36130"} User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'a1s2d36130' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "email" = 'user@domain.com', "name" = 'Joshua Marshall', "permissions" = '--- - signin - new permission ', "organisation_slug" = 'justice-league', "organisation_content_id" = 'aae1319e-5788-4677-998c-f1a53af528d0' WHERE "users"."id" = 4  (26.8ms) commit transaction Completed 200 OK in 33.5ms (ActiveRecord: 27.6ms) User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 4]]  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "a1s2d34563"]]  (26.1ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n- user_update_permission\n"], ["remotely_signed_out", nil], ["uid", "a1s2d37792"]]  (17.1ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"nonexistent-user"} User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'nonexistent-user' LIMIT 1 Completed 200 OK in 1.8ms (ActiveRecord: 0.3ms)  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "a1s2d34891"]]  (13.2ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n- user_update_permission\n"], ["remotely_signed_out", nil], ["uid", "a1s2d36388"]]  (16.1ms) commit transaction WARNING: Can't mass-assign protected attributes: uid, name, permissions Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d34891"} Completed 403 Forbidden in 2.0ms (Views: 1.5ms | ActiveRecord: 0.0ms)  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "a1s2d36882"]]  (17.0ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n- user_update_permission\n"], ["remotely_signed_out", nil], ["uid", "a1s2d35104"]]  (15.6ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d36882"} User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'a1s2d36882' LIMIT 1  (0.0ms) begin transaction  (0.2ms) UPDATE "users" SET "remotely_signed_out" = 't', "permissions" = '--- - signin ' WHERE "users"."id" = 10  (16.8ms) commit transaction Completed 200 OK in 20.9ms (ActiveRecord: 17.4ms) User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 10]] Started GET "/" for 127.0.0.1 at 2016-02-12 10:53:43 +0000 Processing by ExampleController#index as HTML Rendered text template (0.0ms) Completed 200 OK in 14ms (Views: 13.5ms | ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:43 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 150ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:53:43 +0000 Started GET "/auth/gds/callback?code=cef23829b34253676de73819b7dc3cd75e77b8a17531b36453155058bcbe1ab4&state=ea298ca4fb04159f359af6d707f4c0dd749513274fb41ef1" for 127.0.0.1 at 2016-02-12 10:53:58 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"cef23829b34253676de73819b7dc3cd75e77b8a17531b36453155058bcbe1ab4", "state"=>"ea298ca4fb04159f359af6d707f4c0dd749513274fb41ef1"} Authenticating with gds_sso strategy User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1 User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."email" = 'test@example-client.com' ORDER BY "users"."id" ASC LIMIT 1  (0.2ms) begin transaction SQL (0.6ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "test@example-client.com"], ["name", "Test User"], ["permissions", "---\n- signin\n"], ["uid", "integration-uid"]]  (11.7ms) commit transaction  (0.1ms) begin transaction SQL (0.4ms) UPDATE "users" SET "permissions" = ?, "remotely_signed_out" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"], ["remotely_signed_out", "f"]]  (7.7ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 117ms (ActiveRecord: 22.7ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:58 +0000 Processing by ExampleController#restricted as HTML User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 5ms (Views: 0.5ms | ActiveRecord: 0.4ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:53:58 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 1ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:53:58 +0000 Started GET "/auth/gds/callback?code=e2fa42aa2602a042cc1ea8706df496559e3c64eb8186b22493e459d9a22136cc&state=33a77d70c9867053d04cb442872902aed9ac9892bd9d65bc" for 127.0.0.1 at 2016-02-12 10:53:59 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"e2fa42aa2602a042cc1ea8706df496559e3c64eb8186b22493e459d9a22136cc", "state"=>"33a77d70c9867053d04cb442872902aed9ac9892bd9d65bc"} Authenticating with gds_sso strategy User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (30.9ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (30.8ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 71ms (ActiveRecord: 63.0ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:53:59 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 4ms (Views: 0.8ms | ActiveRecord: 0.4ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:53:59 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 1ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:53:59 +0000 Started GET "/auth/gds/callback?code=f20c801b9b0a68403e96ea656119d0c869586369768436555dff3d37d0c06b5b&state=18d2902f520f895387918671de2a7312e1c9f37c13655225" for 127.0.0.1 at 2016-02-12 10:53:59 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"f20c801b9b0a68403e96ea656119d0c869586369768436555dff3d37d0c06b5b", "state"=>"18d2902f520f895387918671de2a7312e1c9f37c13655225"} Authenticating with gds_sso strategy User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (16.5ms) commit transaction  (0.2ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (13.7ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 38ms (ActiveRecord: 31.4ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:53:59 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 4ms (Views: 0.4ms | ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:59 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 1ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:53:59 +0000 Started GET "/auth/gds/callback?code=5f77abe39273e8580de9ff7fc97a55974a1a1b4ec1d41d061277a7b802801ab0&state=163bf6f60c8ecf5700fac032a096e273d1674bf2c67c4aed" for 127.0.0.1 at 2016-02-12 10:53:59 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"5f77abe39273e8580de9ff7fc97a55974a1a1b4ec1d41d061277a7b802801ab0", "state"=>"163bf6f60c8ecf5700fac032a096e273d1674bf2c67c4aed"} Authenticating with gds_sso strategy User Load (0.6ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.2ms) begin transaction SQL (0.4ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (22.4ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (14.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 49ms (ActiveRecord: 38.1ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:59 +0000 Processing by ExampleController#restricted as HTML User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 4ms (Views: 0.7ms | ActiveRecord: 0.5ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:53:59 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 1ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:53:59 +0000 Started GET "/auth/gds/callback?code=d34573e3d96ff9def513da6d10f357635def8f380bebb50cdfd7c1f5ed48884f&state=6c185cf0bf485e659dca874b4528290bbc71e278d51a257d" for 127.0.0.1 at 2016-02-12 10:54:00 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"d34573e3d96ff9def513da6d10f357635def8f380bebb50cdfd7c1f5ed48884f", "state"=>"6c185cf0bf485e659dca874b4528290bbc71e278d51a257d"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (11.8ms) commit transaction  (0.2ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (12.5ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 32ms (ActiveRecord: 25.5ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:00 +0000 Processing by ExampleController#restricted as HTML User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 4ms (Views: 0.7ms | ActiveRecord: 0.5ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:00 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 1ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:54:00 +0000 Started GET "/auth/gds/callback?code=e9550724434a5559eb5e7b14c5d4a316e6250337f4dfd04f81b1087fccb8e3d1&state=c215b9cdfd072d645632f1fe4290fbbd2ffab2488e7c267d" for 127.0.0.1 at 2016-02-12 10:54:00 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"e9550724434a5559eb5e7b14c5d4a316e6250337f4dfd04f81b1087fccb8e3d1", "state"=>"c215b9cdfd072d645632f1fe4290fbbd2ffab2488e7c267d"} Authenticating with gds_sso strategy User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (8.8ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (11.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 29ms (ActiveRecord: 21.1ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:00 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 3ms (Views: 0.4ms | ActiveRecord: 0.3ms) User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."email" = 'test@example-client.com' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ?, "remotely_signed_out" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"], ["remotely_signed_out", "t"]]  (19.5ms) commit transaction Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:00 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Authenticating with gds_sso strategy Completed in 2ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:54:00 +0000 Started GET "/auth/gds/callback?code=6912fe6fb4a59da044ef222ccddb2b2cc06892f3b437b124fc3c724210370ebc&state=35d04b3fbc16a83899c53a25a3caf01cba9ea144db41bbee" for 127.0.0.1 at 2016-02-12 10:54:01 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"6912fe6fb4a59da044ef222ccddb2b2cc06892f3b437b124fc3c724210370ebc", "state"=>"35d04b3fbc16a83899c53a25a3caf01cba9ea144db41bbee"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (12.0ms) commit transaction  (0.3ms) begin transaction SQL (0.4ms) UPDATE "users" SET "permissions" = ?, "remotely_signed_out" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"], ["remotely_signed_out", "f"]]  (13.4ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 34ms (ActiveRecord: 26.8ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:01 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 3ms (Views: 0.4ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:01 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 1ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:54:01 +0000 Started GET "/auth/gds/callback?code=ce62ccc4665d8be70711b11a599140dccb05b61bd425a8746cb4985541af0da2&state=d7f48ddb3934e5d5a9874f6fc34763c081de602391f550d5" for 127.0.0.1 at 2016-02-12 10:54:01 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"ce62ccc4665d8be70711b11a599140dccb05b61bd425a8746cb4985541af0da2", "state"=>"d7f48ddb3934e5d5a9874f6fc34763c081de602391f550d5"} Authenticating with gds_sso strategy User Load (0.6ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.3ms) begin transaction SQL (0.8ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (15.7ms) commit transaction  (0.2ms) begin transaction SQL (0.4ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (17.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 47ms (ActiveRecord: 35.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:01 +0000 Processing by ExampleController#restricted as HTML User Load (0.6ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 5ms (Views: 1.1ms | ActiveRecord: 0.6ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 06:59:01 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 2ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-13 06:59:01 +0000 Started GET "/auth/gds/callback?code=4aa603b7308aa12abf95b6ae36c623d69c8c190a3429a00ef345ec7658e9c19f&state=7e015203304ec1a954128d65aa151b551237692f03295252" for 127.0.0.1 at 2016-02-13 06:59:01 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"4aa603b7308aa12abf95b6ae36c623d69c8c190a3429a00ef345ec7658e9c19f", "state"=>"7e015203304ec1a954128d65aa151b551237692f03295252"} Authenticating with gds_sso strategy User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (200.9ms) commit transaction  (0.2ms) begin transaction SQL (0.4ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (18.2ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 228ms (ActiveRecord: 220.5ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 06:59:01 +0000 Processing by ExampleController#restricted as HTML User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 3ms (Views: 0.4ms | ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:01 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 1ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:54:01 +0000 Started GET "/auth/gds/callback?code=6022c79870a80991fea52d929e4d11a01cbb3dc5547d2389e31fffd1dfb3b745&state=0668c4d319caf0f00fc4d19fd045454affe097a796568697" for 127.0.0.1 at 2016-02-12 10:54:02 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"6022c79870a80991fea52d929e4d11a01cbb3dc5547d2389e31fffd1dfb3b745", "state"=>"0668c4d319caf0f00fc4d19fd045454affe097a796568697"} Authenticating with gds_sso strategy User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (26.3ms) commit transaction  (0.1ms) begin transaction SQL (0.4ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (11.5ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 46ms (ActiveRecord: 39.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:02 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 3ms (Views: 0.5ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 06:49:02 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 3ms (Views: 0.3ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:02 +0000 Processing by ExampleController#restricted as JSON Completed in 45ms Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:02 +0000 Processing by ExampleController#restricted as JSON User Load (0.6ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.7ms) UPDATE "users" SET "disabled" = ?, "permissions" = ? WHERE "users"."id" = 1 [["disabled", nil], ["permissions", "---\n- signin\n"]]  (17.0ms) commit transaction User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.2ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (23.5ms) commit transaction User Load (0.9ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (27.2ms) commit transaction User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (30.3ms) commit transaction  (0.4ms) begin transaction SQL (0.4ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (14.3ms) commit transaction Completed 200 OK in 242ms (Views: 0.7ms | ActiveRecord: 117.4ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:02 +0000 Processing by ExampleController#restricted as JSON Completed in 33ms Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:54:02 +0000 Processing by ExampleController#this_requires_signin_permission as JSON User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (12.4ms) commit transaction User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.4ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (14.5ms) commit transaction User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (18.4ms) commit transaction User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.4ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (26.8ms) commit transaction  (0.3ms) begin transaction SQL (0.5ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (18.2ms) commit transaction Completed 200 OK in 230ms (Views: 0.7ms | ActiveRecord: 94.6ms)  (0.3ms) begin transaction SQL (0.5ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"], ["uid", "a1s2d39527"]]  (16.2ms) commit transaction  (0.1ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"], ["uid", "a1s2d3773"]]  (22.2ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d39527"} Completed 403 Forbidden in 10ms (Views: 8.3ms | ActiveRecord: 0.0ms)  (0.3ms) begin transaction SQL (0.5ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"], ["uid", "a1s2d37678"]]  (14.3ms) commit transaction  (0.1ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"], ["uid", "a1s2d36978"]]  (7.4ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d37678"} User Load (0.7ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'a1s2d37678' ORDER BY "users"."id" ASC LIMIT 1  (0.2ms) begin transaction SQL (0.7ms) UPDATE "users" SET "email" = ?, "name" = ?, "organisation_content_id" = ?, "organisation_slug" = ?, "permissions" = ? WHERE "users"."id" = 4 [["email", "user@domain.com"], ["name", "Joshua Marshall"], ["organisation_content_id", "aae1319e-5788-4677-998c-f1a53af528d0"], ["organisation_slug", "justice-league"], ["permissions", "---\n- signin\n- new permission\n"]]  (20.8ms) commit transaction Completed 200 OK in 29ms (ActiveRecord: 22.4ms) User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 4]]  (0.3ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"], ["uid", "a1s2d33852"]]  (13.4ms) commit transaction  (0.2ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"], ["uid", "a1s2d33326"]]  (13.3ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d33852"} Completed 403 Forbidden in 2ms (Views: 1.5ms | ActiveRecord: 0.0ms)  (0.2ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"], ["uid", "a1s2d38799"]]  (26.2ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"], ["uid", "a1s2d38547"]]  (28.9ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"nonexistent-user"} User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'nonexistent-user' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 2ms (ActiveRecord: 0.3ms)  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"], ["uid", "a1s2d33001"]]  (15.3ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"], ["uid", "a1s2d34483"]]  (12.3ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d33001"} User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'a1s2d33001' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.4ms) UPDATE "users" SET "permissions" = ?, "remotely_signed_out" = ? WHERE "users"."id" = 10 [["permissions", "---\n- signin\n"], ["remotely_signed_out", "t"]]  (20.2ms) commit transaction Completed 200 OK in 25ms (ActiveRecord: 21.1ms) User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 10]] Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:54:33 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 26ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:54:33 +0000 Started GET "/auth/gds/callback?code=fc64c5458da9424d1bff21dcca96871ce502adc177c614c1369189d5cdd8ac5e&state=68301378eb6149f729b5e29c83169779e3776d688987a5f0" for 127.0.0.1 at 2016-02-12 10:54:46 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"fc64c5458da9424d1bff21dcca96871ce502adc177c614c1369189d5cdd8ac5e", "state"=>"68301378eb6149f729b5e29c83169779e3776d688987a5f0"} Authenticating with gds_sso strategy User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]] User Load (0.3ms) 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.5ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "integration-uid"], ["email", "test@example-client.com"], ["name", "Test User"], ["permissions", "---\n- signin\n"]]  (11.6ms) commit transaction  (0.1ms) begin transaction SQL (0.5ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "f"], ["id", 1]]  (8.9ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 159ms (ActiveRecord: 23.4ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:54:47 +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 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 65ms (Views: 62.2ms | ActiveRecord: 0.4ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:54:47 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 1ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:54:47 +0000 Started GET "/auth/gds/callback?code=028e97d45a86731d5f23e6cb7d624aff0504776c1e9cbcbe360c22e1623412ff&state=50834c040fd14775e7114fbe62785e22e5bc82547d92d528" for 127.0.0.1 at 2016-02-12 10:54:47 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"028e97d45a86731d5f23e6cb7d624aff0504776c1e9cbcbe360c22e1623412ff", "state"=>"50834c040fd14775e7114fbe62785e22e5bc82547d92d528"} 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-02-12 10:54:47 +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 3ms (Views: 0.5ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:47 +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-02-12 10:54:47 +0000 Started GET "/auth/gds/callback?code=cc33f78e1c69f4f9fe92fd0408c4048350cad30862a4d94172409cf8352cb3f8&state=08b7d085d1af6c4f379fa591c1759b07067f3719039fd8ee" for 127.0.0.1 at 2016-02-12 10:54:47 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"cc33f78e1c69f4f9fe92fd0408c4048350cad30862a4d94172409cf8352cb3f8", "state"=>"08b7d085d1af6c4f379fa591c1759b07067f3719039fd8ee"} 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 7ms (ActiveRecord: 0.6ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:47 +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.6ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:47 +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-02-12 10:54:47 +0000 Started GET "/auth/gds/callback?code=a4c2569aff3248a7bb518f9be0708b2ea6eec5f794a0a5fa69b0b446e5590c33&state=d2f637ac1dec94d2e2d2554a73b7258e63f28209628c0024" for 127.0.0.1 at 2016-02-12 10:54:47 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"a4c2569aff3248a7bb518f9be0708b2ea6eec5f794a0a5fa69b0b446e5590c33", "state"=>"d2f637ac1dec94d2e2d2554a73b7258e63f28209628c0024"} 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.2ms) commit transaction  (0.1ms) begin transaction  (0.2ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 11ms (ActiveRecord: 0.8ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:48 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 3ms (Views: 0.7ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:48 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:54:48 +0000 Started GET "/auth/gds/callback?code=67eb6bee34cac856499161f21eb9b6a05c168cd49d21b0f8ced23dea91c79807&state=09171331a65dd872f49d41a1dde5e5d3ef00d0c62bc10b9f" for 127.0.0.1 at 2016-02-12 10:54:48 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"67eb6bee34cac856499161f21eb9b6a05c168cd49d21b0f8ced23dea91c79807", "state"=>"09171331a65dd872f49d41a1dde5e5d3ef00d0c62bc10b9f"} 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.2ms) commit transaction  (0.1ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 8ms (ActiveRecord: 0.7ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:48 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.1ms) Completed 200 OK in 3ms (Views: 0.7ms | ActiveRecord: 0.2ms) Started GET "/" for 127.0.0.1 at 2016-02-12 10:54:48 +0000 Processing by ExampleController#index as HTML Rendered text template (0.0ms) Completed 200 OK in 1ms (Views: 0.6ms | ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:48 +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-02-12 10:54:48 +0000 Started GET "/auth/gds/callback?code=95b2b7366dead9b7737ee2b0db8c5b0023cfee9b2fce2ce4178edba876f1a138&state=fa36397f907dbf5b9dba9ea93ef437b8654ef017ca95f056" for 127.0.0.1 at 2016-02-12 10:54:48 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"95b2b7366dead9b7737ee2b0db8c5b0023cfee9b2fce2ce4178edba876f1a138", "state"=>"fa36397f907dbf5b9dba9ea93ef437b8654ef017ca95f056"} 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 8ms (ActiveRecord: 0.6ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:48 +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 3ms (Views: 0.6ms | ActiveRecord: 0.1ms) User Load (0.3ms) 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.3ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "t"], ["id", 1]]  (17.1ms) commit transaction Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:48 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Authenticating with gds_sso strategy Completed in 2ms (ActiveRecord: 0.2ms) Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:54:48 +0000 Started GET "/auth/gds/callback?code=9527f33aee3a838ddf5feca4744af576987e458d53dabbc1d18e2e699b150019&state=c162b31c15e0278afa7637e656ae43b8671b98362e88bc89" for 127.0.0.1 at 2016-02-12 10:54:49 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"9527f33aee3a838ddf5feca4744af576987e458d53dabbc1d18e2e699b150019", "state"=>"c162b31c15e0278afa7637e656ae43b8671b98362e88bc89"} 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 SQL (0.3ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "f"], ["id", 1]]  (14.5ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 24ms (ActiveRecord: 15.4ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:49 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 3ms (Views: 0.4ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:49 +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-02-12 10:54:49 +0000 Started GET "/auth/gds/callback?code=43d05139823017a5409cf97185a8f71e85ccd0b3ad527dc72edb6b491a614ea9&state=d1c626338a17618509a01c991c6503dd172a563c6d51e35e" for 127.0.0.1 at 2016-02-12 10:54:49 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"43d05139823017a5409cf97185a8f71e85ccd0b3ad527dc72edb6b491a614ea9", "state"=>"d1c626338a17618509a01c991c6503dd172a563c6d51e35e"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.1ms) commit transaction  (0.1ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 9ms (ActiveRecord: 0.7ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:49 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 3ms (Views: 0.6ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 06:59:49 +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-02-13 06:59:49 +0000 Started GET "/auth/gds/callback?code=974de4ab9ad214b93006ae15e69f62f9f5c959b59f8d928bbabafae54feeeba1&state=bba5266d4ab5233200a6ca04c4c5b0dc7fdc6c9730a453e9" for 127.0.0.1 at 2016-02-13 06:59:49 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"974de4ab9ad214b93006ae15e69f62f9f5c959b59f8d928bbabafae54feeeba1", "state"=>"bba5266d4ab5233200a6ca04c4c5b0dc7fdc6c9730a453e9"} 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-02-13 06:59:49 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.1ms) Completed 200 OK in 3ms (Views: 0.5ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:49 +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-02-12 10:54:49 +0000 Started GET "/auth/gds/callback?code=f68fc51ffaca32242e1a6fe3c3ece1f25b05871964d0f96dd6d2f1748f1b811e&state=81ea3ef614e82cff1ed3baa6c9ea5b99d1475c11ee90c444" for 127.0.0.1 at 2016-02-12 10:54:49 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"f68fc51ffaca32242e1a6fe3c3ece1f25b05871964d0f96dd6d2f1748f1b811e", "state"=>"81ea3ef614e82cff1ed3baa6c9ea5b99d1475c11ee90c444"} Authenticating with gds_sso strategy User Load (0.3ms) 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 10ms (ActiveRecord: 0.8ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:49 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 3ms (Views: 0.7ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 06:49:49 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 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-02-12 10:54:49 +0000 Processing by ExampleController#restricted as JSON Completed in 40ms (ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:50 +0000 Processing by ExampleController#restricted as JSON User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction SQL (0.4ms) UPDATE "users" SET "disabled" = ? WHERE "users"."id" = ? [["disabled", nil], ["id", 1]]  (15.0ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (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.2ms) begin transaction  (0.1ms) commit transaction  (0.1ms) begin transaction  (0.1ms) commit transaction Rendered text template (0.0ms) Completed 200 OK in 131ms (Views: 0.7ms | ActiveRecord: 17.0ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:54:50 +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 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.1ms) commit transaction CACHE (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.1ms) commit transaction CACHE (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.2ms) 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.2ms) commit transaction  (0.1ms) begin transaction  (0.2ms) commit transaction Rendered text template (0.1ms) Completed 200 OK in 112ms (Views: 0.8ms | ActiveRecord: 1.8ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:54:50 +0000 Processing by ExampleController#restricted as JSON Completed in 20ms (ActiveRecord: 0.0ms)  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d37077"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (32.4ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d37989"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (23.9ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d37077"} Rendered /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.5ms) Completed 403 Forbidden in 5ms (Views: 4.3ms | ActiveRecord: 0.0ms)  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d39324"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (37.3ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d31928"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (20.7ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d39324"} User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "a1s2d39324"]]  (0.1ms) begin transaction SQL (0.4ms) UPDATE "users" SET "email" = ?, "name" = ?, "permissions" = ?, "organisation_slug" = ?, "organisation_content_id" = ? WHERE "users"."id" = ? [["email", "user@domain.com"], ["name", "Joshua Marshall"], ["permissions", "---\n- signin\n- new permission\n"], ["organisation_slug", "justice-league"], ["organisation_content_id", "aae1319e-5788-4677-998c-f1a53af528d0"], ["id", 4]]  (24.7ms) commit transaction Completed 200 OK in 33ms (ActiveRecord: 25.4ms) User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 4]]  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d35448"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (27.3ms) commit transaction  (0.2ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d38560"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (22.5ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d35448"} User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "a1s2d35448"]]  (0.2ms) begin transaction SQL (0.3ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "t"], ["id", 6]]  (36.5ms) commit transaction Completed 200 OK in 42ms (ActiveRecord: 37.3ms) User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 6]]  (0.1ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d3252"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (43.6ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d35637"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (26.4ms) 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 1ms (ActiveRecord: 0.2ms)  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d33199"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (26.7ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d31810"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (58.7ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d33199"} Rendered /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.3ms) Completed 403 Forbidden in 2ms (Views: 1.3ms | ActiveRecord: 0.0ms) Connecting to database specified by database.yml  (0.1ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "a1s2d34729"]]  (16.7ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n- user_update_permission\n"], ["remotely_signed_out", nil], ["uid", "a1s2d32913"]]  (21.6ms) commit transaction WARNING: Can't mass-assign protected attributes: uid, name, permissions Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d34729"} Rendered /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.4ms) Completed 403 Forbidden in 22.2ms (Views: 21.5ms | ActiveRecord: 0.0ms)  (0.1ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "a1s2d35049"]]  (22.8ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n- user_update_permission\n"], ["remotely_signed_out", nil], ["uid", "a1s2d34637"]]  (19.2ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d35049"} User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'a1s2d35049' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "email" = 'user@domain.com', "name" = 'Joshua Marshall', "permissions" = '--- - signin - new permission ', "organisation_slug" = 'justice-league', "organisation_content_id" = 'aae1319e-5788-4677-998c-f1a53af528d0' WHERE "users"."id" = 3  (20.0ms) commit transaction Completed 200 OK in 31.6ms (ActiveRecord: 20.6ms) User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 3]]  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "a1s2d35387"]]  (16.7ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n- user_update_permission\n"], ["remotely_signed_out", nil], ["uid", "a1s2d35625"]]  (15.1ms) commit transaction WARNING: Can't mass-assign protected attributes: uid, name, permissions Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d35387"} Completed 403 Forbidden in 1.9ms (Views: 1.2ms | ActiveRecord: 0.0ms)  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "a1s2d35121"]]  (26.9ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n- user_update_permission\n"], ["remotely_signed_out", nil], ["uid", "a1s2d32731"]]  (37.9ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d35121"} User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'a1s2d35121' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "remotely_signed_out" = 't', "permissions" = '--- - signin ' WHERE "users"."id" = 7  (24.4ms) commit transaction Completed 200 OK in 28.3ms (ActiveRecord: 24.9ms) User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 7]]  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "a1s2d39344"]]  (45.7ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n- user_update_permission\n"], ["remotely_signed_out", nil], ["uid", "a1s2d35250"]]  (39.7ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"nonexistent-user"} User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'nonexistent-user' LIMIT 1 Completed 200 OK in 1.2ms (ActiveRecord: 0.2ms) Started GET "/" for 127.0.0.1 at 2016-02-12 10:55:24 +0000 Processing by ExampleController#index as HTML Completed 200 OK in 5.0ms (Views: 4.7ms | ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:55:25 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.5ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:55:25 +0000 Started GET "/auth/gds/callback?code=ee33e0eb80416e2d77fdab0d6982329726f74deb5ab96a2558d9315f3bf1bd89&state=a62c842f611856d06d956da5cd65eb2cd422509a8d282fa6" for 127.0.0.1 at 2016-02-12 10:55:38 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"ee33e0eb80416e2d77fdab0d6982329726f74deb5ab96a2558d9315f3bf1bd89", "state"=>"a62c842f611856d06d956da5cd65eb2cd422509a8d282fa6"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1 User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."email" = 'test@example-client.com' LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "test@example-client.com"], ["name", "Test User"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "integration-uid"]]  (17.2ms) commit transaction  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "remotely_signed_out" = 'f', "permissions" = '--- - signin ' WHERE "users"."id" = 11  (16.9ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 42.1ms (ActiveRecord: 35.1ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:55:38 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 3.5ms (Views: 0.3ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:55:38 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.3ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:55:38 +0000 Started GET "/auth/gds/callback?code=d02aec3cb38d7a4f08164f72fa30a4c39f6a81f283b0a98c0a8b0b2807ec9ac7&state=f769bcde53d46b6adb2998032ae8749e2e383f74b7360fd3" for 127.0.0.1 at 2016-02-12 10:55:39 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"d02aec3cb38d7a4f08164f72fa30a4c39f6a81f283b0a98c0a8b0b2807ec9ac7", "state"=>"f769bcde53d46b6adb2998032ae8749e2e383f74b7360fd3"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (58.9ms) commit transaction  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (25.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 91.1ms (ActiveRecord: 84.9ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:55:39 +0000 Processing by ExampleController#restricted as HTML User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.8ms (Views: 0.4ms | ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:55:39 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.2ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:55:39 +0000 Started GET "/auth/gds/callback?code=ae8e94a16a4ab11f37c39d4063ca1ab169073c5c601c357c85d43e4bac39ca7f&state=116432ae7adb6868d12df839fab15f5babb56507a747b4e4" for 127.0.0.1 at 2016-02-12 10:55:39 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"ae8e94a16a4ab11f37c39d4063ca1ab169073c5c601c357c85d43e4bac39ca7f", "state"=>"116432ae7adb6868d12df839fab15f5babb56507a747b4e4"} Authenticating with gds_sso strategy User Load (0.6ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.4ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (27.1ms) commit transaction  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (35.4ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 72.2ms (ActiveRecord: 64.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:55:39 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.0ms (Views: 0.4ms | ActiveRecord: 0.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:55:39 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 0.7ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:55:39 +0000 Started GET "/auth/gds/callback?code=bc26d8ac43f7b0575abd74a662220844a97af6d689d17e6a7aa561a91150b795&state=f41bdf34e402fb1a42849e67d72e268c7d6a15612b0133aa" for 127.0.0.1 at 2016-02-12 10:55:39 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"bc26d8ac43f7b0575abd74a662220844a97af6d689d17e6a7aa561a91150b795", "state"=>"f41bdf34e402fb1a42849e67d72e268c7d6a15612b0133aa"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.0ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (24.3ms) commit transaction  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (30.3ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 62.1ms (ActiveRecord: 55.6ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:55:40 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.2ms (Views: 0.4ms | ActiveRecord: 0.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:55:40 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 0.2ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:55:40 +0000 Started GET "/auth/gds/callback?code=cf9710df851d940d57bae5cb53c2025942d07bb3578d06721d88506ce41b1b87&state=dd7963823ac5008e40f64fd670525bbe4f0a358943fd949a" for 127.0.0.1 at 2016-02-12 10:55:40 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"cf9710df851d940d57bae5cb53c2025942d07bb3578d06721d88506ce41b1b87", "state"=>"dd7963823ac5008e40f64fd670525bbe4f0a358943fd949a"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.0ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (29.4ms) commit transaction  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (31.4ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 71.0ms (ActiveRecord: 61.8ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:55:40 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.0ms (Views: 0.4ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:55:40 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.2ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:55:40 +0000 Started GET "/auth/gds/callback?code=e165aa8d289bdaf0a81e24e3834843fc62a56ad087c2899f80998ca79e5fc216&state=38382d97eb9b42342d51d5aa6e7238d95fcd0ed7222dcdea" for 127.0.0.1 at 2016-02-12 10:55:40 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"e165aa8d289bdaf0a81e24e3834843fc62a56ad087c2899f80998ca79e5fc216", "state"=>"38382d97eb9b42342d51d5aa6e7238d95fcd0ed7222dcdea"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (27.4ms) commit transaction  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (24.2ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 58.5ms (ActiveRecord: 52.6ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:55:40 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 1.8ms (Views: 0.3ms | ActiveRecord: 0.3ms) User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."email" = 'test@example-client.com' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "remotely_signed_out" = 't', "permissions" = '--- - signin ' WHERE "users"."id" = 11  (25.2ms) commit transaction Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:55:40 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Authenticating with gds_sso strategy Completed in 1.4ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:55:40 +0000 Started GET "/auth/gds/callback?code=2cc6d813fe1f5cf5bce5909583c0f6d442ab228ed34539fa5f63e013e7daaefd&state=5871eadaa6fed7dac78773f0b6925d6795d2091cf7197fcd" for 127.0.0.1 at 2016-02-12 10:55:41 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"2cc6d813fe1f5cf5bce5909583c0f6d442ab228ed34539fa5f63e013e7daaefd", "state"=>"5871eadaa6fed7dac78773f0b6925d6795d2091cf7197fcd"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.0ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (24.5ms) commit transaction  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "remotely_signed_out" = 'f', "permissions" = '--- - signin ' WHERE "users"."id" = 11  (54.7ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 91.5ms (ActiveRecord: 80.1ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:55:41 +0000 Processing by ExampleController#restricted as HTML User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.4ms (Views: 0.3ms | ActiveRecord: 0.5ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:55:41 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.2ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:55:41 +0000 Started GET "/auth/gds/callback?code=cc54eeaf6940339d86b9c44f588b2c244c7805a0bafb180b909bf794d201e41c&state=dac5973978fc88e9d80da278d6c894b9e474c4856935308c" for 127.0.0.1 at 2016-02-12 10:55:41 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"cc54eeaf6940339d86b9c44f588b2c244c7805a0bafb180b909bf794d201e41c", "state"=>"dac5973978fc88e9d80da278d6c894b9e474c4856935308c"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.0ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (23.1ms) commit transaction  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (29.2ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 59.5ms (ActiveRecord: 53.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:55:41 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 1.9ms (Views: 0.3ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 07:00:41 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.5ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-13 07:00:41 +0000 Started GET "/auth/gds/callback?code=e98518df1a8447f73377a71819b5eb53626812330362897520521e6f09ea34f7&state=5bbd8a61d05126e4e6fd0cc428a972491461f2ee20604665" for 127.0.0.1 at 2016-02-13 07:00:41 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"e98518df1a8447f73377a71819b5eb53626812330362897520521e6f09ea34f7", "state"=>"5bbd8a61d05126e4e6fd0cc428a972491461f2ee20604665"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (23.4ms) commit transaction  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (21.7ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 52.7ms (ActiveRecord: 46.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 07:00:41 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 1.9ms (Views: 0.2ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:55:41 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.3ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:55:41 +0000 Started GET "/auth/gds/callback?code=ea3a4b2bda51b56561f07029c9064d8018fb53bb053537330f74341f30f6270b&state=ebab85ca2cfd10e4498c593d03dbf92198b79b657c065941" for 127.0.0.1 at 2016-02-12 10:55:42 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"ea3a4b2bda51b56561f07029c9064d8018fb53bb053537330f74341f30f6270b", "state"=>"ebab85ca2cfd10e4498c593d03dbf92198b79b657c065941"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (70.1ms) commit transaction  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (48.9ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 125.9ms (ActiveRecord: 119.9ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:55:42 +0000 Processing by ExampleController#restricted as HTML User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.6ms (Views: 0.5ms | ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 06:50:42 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.4ms (Views: 0.4ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:55:42 +0000 Processing by ExampleController#restricted as JSON Completed in 60.7ms Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:55:42 +0000 Processing by ExampleController#this_requires_signin_permission as JSON User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "disabled" = NULL, "permissions" = '--- - signin ' WHERE "users"."id" = 11  (71.6ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.0ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (23.7ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.4ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (259.9ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (71.8ms) commit transaction  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (55.4ms) commit transaction Completed 200 OK in 589.3ms (Views: 0.4ms | ActiveRecord: 485.5ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:55:42 +0000 Processing by ExampleController#restricted as JSON User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (42.7ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.0ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (52.5ms) commit transaction User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (38.8ms) commit transaction User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (32.8ms) commit transaction  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 11  (48.5ms) commit transaction Completed 200 OK in 319.9ms (Views: 0.4ms | ActiveRecord: 218.1ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:55:43 +0000 Processing by ExampleController#restricted as JSON Completed in 25.5ms Started GET "/" for 127.0.0.1 at 2016-02-12 10:56:02 +0000 Processing by ExampleController#index as HTML Rendered text template (0.1ms) Completed 200 OK in 28ms (Views: 27.4ms | ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:02 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 17ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:56:02 +0000 Started GET "/auth/gds/callback?code=bac6e788ca62d64a6388966dc8152e48bd72a3031f2f4c0671a95f995b447410&state=3dd9bd4b21a6db58faa74f4abadf9aad670372c6358c0a1d" for 127.0.0.1 at 2016-02-12 10:56:17 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"bac6e788ca62d64a6388966dc8152e48bd72a3031f2f4c0671a95f995b447410", "state"=>"3dd9bd4b21a6db58faa74f4abadf9aad670372c6358c0a1d"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1 User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."email" = 'test@example-client.com' ORDER BY "users"."id" ASC LIMIT 1  (0.2ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "test@example-client.com"], ["name", "Test User"], ["permissions", "---\n- signin\n"], ["uid", "integration-uid"]]  (24.2ms) commit transaction  (0.1ms) begin transaction SQL (0.4ms) UPDATE "users" SET "permissions" = ?, "remotely_signed_out" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"], ["remotely_signed_out", "f"]]  (19.8ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 133ms (ActiveRecord: 46.4ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:17 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 5ms (Views: 0.4ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:17 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 1ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:56:17 +0000 Started GET "/auth/gds/callback?code=238e9fc293ff210d30f633f7bd8f0f8afde54b53352742550039dbe5bbdd868c&state=c43bbe8eaa1d6dfc07fe2cf0ce312e8fdfe3daafb834c257" for 127.0.0.1 at 2016-02-12 10:56:18 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"238e9fc293ff210d30f633f7bd8f0f8afde54b53352742550039dbe5bbdd868c", "state"=>"c43bbe8eaa1d6dfc07fe2cf0ce312e8fdfe3daafb834c257"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (34.3ms) commit transaction  (0.1ms) begin transaction SQL (0.4ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (34.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 75ms (ActiveRecord: 69.5ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:18 +0000 Processing by ExampleController#restricted as HTML User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 4ms (Views: 0.6ms | ActiveRecord: 0.5ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:18 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 1ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:56:18 +0000 Started GET "/auth/gds/callback?code=2482d4f4b3bc1efbb17dacc386db82662a712ff73d916507365f6e40f0512c02&state=4832df77411c8470cd915e6b150036d2933e99003ebf22ba" for 127.0.0.1 at 2016-02-12 10:56:18 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"2482d4f4b3bc1efbb17dacc386db82662a712ff73d916507365f6e40f0512c02", "state"=>"4832df77411c8470cd915e6b150036d2933e99003ebf22ba"} Authenticating with gds_sso strategy User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.7ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (247.3ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (94.9ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 350ms (ActiveRecord: 343.6ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:18 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:56:18 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 0ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:56:18 +0000 Started GET "/auth/gds/callback?code=28bfb30512b1471f492ac3b77da1f7a6cd2b17031d4e45ec819d4c2ea22fa427&state=55ed84a507ba4dcea3ab74c8bb03c7c3de135b7f8653fd0d" for 127.0.0.1 at 2016-02-12 10:56:19 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"28bfb30512b1471f492ac3b77da1f7a6cd2b17031d4e45ec819d4c2ea22fa427", "state"=>"55ed84a507ba4dcea3ab74c8bb03c7c3de135b7f8653fd0d"} Authenticating with gds_sso strategy User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (75.1ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (54.9ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 138ms (ActiveRecord: 131.1ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:56:19 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 3ms (Views: 0.3ms | ActiveRecord: 0.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:56:19 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 1ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:56:19 +0000 Started GET "/auth/gds/callback?code=a3ac82ec8ed36cbbd1da750d3fdd0ae0c4b48b22d6acc31f3ed09fe37696b83b&state=6849146c849f49a5b51fa8e622eec6f646e8b462e4d89378" for 127.0.0.1 at 2016-02-12 10:56:19 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"a3ac82ec8ed36cbbd1da750d3fdd0ae0c4b48b22d6acc31f3ed09fe37696b83b", "state"=>"6849146c849f49a5b51fa8e622eec6f646e8b462e4d89378"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (70.5ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (62.8ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 140ms (ActiveRecord: 134.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:56:19 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 3ms (Views: 0.4ms | ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:19 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 1ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:56:19 +0000 Started GET "/auth/gds/callback?code=dbf93d0ba053aee95a77b74254b8ff2957fde9aa393acdd005641f9a4f46c6be&state=9102c8096bc85d31c935e607fe5d9eb0d04320aca4676d7d" for 127.0.0.1 at 2016-02-12 10:56:19 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"dbf93d0ba053aee95a77b74254b8ff2957fde9aa393acdd005641f9a4f46c6be", "state"=>"9102c8096bc85d31c935e607fe5d9eb0d04320aca4676d7d"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (19.7ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (16.2ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 43ms (ActiveRecord: 36.8ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:20 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 2ms (Views: 0.5ms | ActiveRecord: 0.3ms) User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."email" = 'test@example-client.com' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ?, "remotely_signed_out" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"], ["remotely_signed_out", "t"]]  (15.2ms) commit transaction Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:20 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Authenticating with gds_sso strategy Completed in 2ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:56:20 +0000 Started GET "/auth/gds/callback?code=cdb5d498f7066ec0c1840ee79f615c01868810aa33a48f89efbbe9a874142290&state=82762437b4e351131e4fb9072aeed17b6f2d345a3291b45b" for 127.0.0.1 at 2016-02-12 10:56:20 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"cdb5d498f7066ec0c1840ee79f615c01868810aa33a48f89efbbe9a874142290", "state"=>"82762437b4e351131e4fb9072aeed17b6f2d345a3291b45b"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (26.5ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ?, "remotely_signed_out" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"], ["remotely_signed_out", "f"]]  (21.6ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 54ms (ActiveRecord: 49.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:20 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 2ms (Views: 0.2ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:20 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:56:20 +0000 Started GET "/auth/gds/callback?code=2f2675cbdfdb9c1c9c5cb2a1b3675db95186e49a274768c8e21148bd6ef56b50&state=047017432720a52680123c54988650f8cb3b584845b41391" for 127.0.0.1 at 2016-02-12 10:56:20 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"2f2675cbdfdb9c1c9c5cb2a1b3675db95186e49a274768c8e21148bd6ef56b50", "state"=>"047017432720a52680123c54988650f8cb3b584845b41391"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (57.5ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (32.3ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 97ms (ActiveRecord: 90.8ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:20 +0000 Processing by ExampleController#restricted as HTML User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 3ms (Views: 0.4ms | ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 07:01:20 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 1ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-13 07:01:20 +0000 Started GET "/auth/gds/callback?code=b48f7716eef5debea1ca350c386e5aaa4b7c728a2364ea421655c6566965a45b&state=267838bcb9970165740b578a57b3b97351d9910a27f5ee0b" for 127.0.0.1 at 2016-02-13 07:01:20 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"b48f7716eef5debea1ca350c386e5aaa4b7c728a2364ea421655c6566965a45b", "state"=>"267838bcb9970165740b578a57b3b97351d9910a27f5ee0b"} Authenticating with gds_sso strategy User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (63.4ms) commit transaction  (0.2ms) begin transaction SQL (0.4ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (31.6ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 103ms (ActiveRecord: 96.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 07:01:21 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 3ms (Views: 0.5ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:21 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 1ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:56:21 +0000 Started GET "/auth/gds/callback?code=70ecabfab4547e6e5f31a848065f32515171a33af7524ae75676a1d54d49154e&state=a7f20aaa640911918358b44b49b323b4dc0bf343ae4ab428" for 127.0.0.1 at 2016-02-12 10:56:21 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"70ecabfab4547e6e5f31a848065f32515171a33af7524ae75676a1d54d49154e", "state"=>"a7f20aaa640911918358b44b49b323b4dc0bf343ae4ab428"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (22.3ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (39.8ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 71ms (ActiveRecord: 63.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:21 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 06:51:21 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:21 +0000 Processing by ExampleController#restricted as JSON Completed in 58ms Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:21 +0000 Processing by ExampleController#restricted as JSON User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.8ms) UPDATE "users" SET "disabled" = ?, "permissions" = ? WHERE "users"."id" = 1 [["disabled", nil], ["permissions", "---\n- signin\n"]]  (35.5ms) commit transaction User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (21.5ms) commit transaction User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (22.0ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (18.2ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (17.9ms) commit transaction Completed 200 OK in 237ms (Views: 0.5ms | ActiveRecord: 119.1ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:56:21 +0000 Processing by ExampleController#this_requires_signin_permission as JSON User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (21.3ms) commit transaction User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (19.8ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (11.3ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (19.2ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (27.8ms) commit transaction Completed 200 OK in 208ms (Views: 0.5ms | ActiveRecord: 102.6ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:22 +0000 Processing by ExampleController#restricted as JSON Completed in 34ms  (0.2ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"], ["uid", "a1s2d32562"]]  (19.3ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"], ["uid", "a1s2d32560"]]  (21.1ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d32562"} Completed 403 Forbidden in 5ms (Views: 4.9ms | ActiveRecord: 0.0ms)  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"], ["uid", "a1s2d35762"]]  (25.0ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"], ["uid", "a1s2d31981"]]  (24.8ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d35762"} User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'a1s2d35762' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "email" = ?, "name" = ?, "organisation_content_id" = ?, "organisation_slug" = ?, "permissions" = ? WHERE "users"."id" = 4 [["email", "user@domain.com"], ["name", "Joshua Marshall"], ["organisation_content_id", "aae1319e-5788-4677-998c-f1a53af528d0"], ["organisation_slug", "justice-league"], ["permissions", "---\n- signin\n- new permission\n"]]  (14.0ms) commit transaction Completed 200 OK in 18ms (ActiveRecord: 14.6ms) User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 4]]  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"], ["uid", "a1s2d3948"]]  (17.3ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"], ["uid", "a1s2d35296"]]  (24.3ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d3948"} Completed 403 Forbidden in 3ms (Views: 1.8ms | ActiveRecord: 0.0ms)  (0.2ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"], ["uid", "a1s2d36507"]]  (25.6ms) commit transaction  (0.2ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"], ["uid", "a1s2d31050"]]  (53.7ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"nonexistent-user"} User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'nonexistent-user' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 2ms (ActiveRecord: 0.4ms)  (0.2ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"], ["uid", "a1s2d3827"]]  (34.0ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"], ["uid", "a1s2d39004"]]  (23.7ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d3827"} User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'a1s2d3827' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ?, "remotely_signed_out" = ? WHERE "users"."id" = 10 [["permissions", "---\n- signin\n"], ["remotely_signed_out", "t"]]  (24.4ms) commit transaction Completed 200 OK in 28ms (ActiveRecord: 25.0ms) User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 10]]  (0.2ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d3760"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (24.4ms) commit transaction  (0.2ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d32063"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (13.5ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d3760"} Rendered /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.4ms) Completed 403 Forbidden in 23ms (Views: 22.6ms | ActiveRecord: 0.0ms)  (0.3ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d36272"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (17.6ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d35195"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (17.3ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d36272"} User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "a1s2d36272"]]  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "email" = ?, "name" = ?, "permissions" = ?, "organisation_slug" = ?, "organisation_content_id" = ? WHERE "users"."id" = ? [["email", "user@domain.com"], ["name", "Joshua Marshall"], ["permissions", "---\n- signin\n- new permission\n"], ["organisation_slug", "justice-league"], ["organisation_content_id", "aae1319e-5788-4677-998c-f1a53af528d0"], ["id", 3]]  (15.2ms) commit transaction Completed 200 OK in 35ms (ActiveRecord: 15.8ms) 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", "a1s2d38634"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (45.2ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d36713"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (16.9ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d38634"} Rendered /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.3ms) Completed 403 Forbidden in 1ms (Views: 1.0ms | ActiveRecord: 0.0ms)  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d37162"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (18.5ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d36834"], ["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"=>"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 2ms (ActiveRecord: 0.1ms)  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d3207"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (29.5ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d36994"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (25.9ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d3207"} User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "a1s2d3207"]]  (0.2ms) begin transaction SQL (0.3ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "t"], ["id", 9]]  (17.2ms) commit transaction Completed 200 OK in 22ms (ActiveRecord: 17.9ms) User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 9]] Started GET "/" for 127.0.0.1 at 2016-02-12 10:56:40 +0000 Processing by ExampleController#index as HTML Rendered text template (0.0ms) Completed 200 OK in 4ms (Views: 3.5ms | ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:40 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 19ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:56:40 +0000 Started GET "/auth/gds/callback?code=b5a9c9c0b87dfd23cc08790e5936bb43922003c6dcab84ea9785116bcf2f6485&state=8035ab53307a11fb5c0ffd6fbe20f6c80d42d8dcec233a54" for 127.0.0.1 at 2016-02-12 10:56:53 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"b5a9c9c0b87dfd23cc08790e5936bb43922003c6dcab84ea9785116bcf2f6485", "state"=>"8035ab53307a11fb5c0ffd6fbe20f6c80d42d8dcec233a54"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]] User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."email" = ? ORDER BY "users"."id" ASC LIMIT 1 [["email", "test@example-client.com"]]  (0.2ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "integration-uid"], ["email", "test@example-client.com"], ["name", "Test User"], ["permissions", "---\n- signin\n"]]  (18.5ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "f"], ["id", 11]]  (21.0ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 52ms (ActiveRecord: 40.7ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:54 +0000 Processing by ExampleController#restricted as HTML User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? AND "users"."remotely_signed_out" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 6ms (Views: 0.8ms | ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56: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-02-12 10:56:54 +0000 Started GET "/auth/gds/callback?code=cb0e4de358e3d3f1e3defd3d0306a8c3e08d61229474f08073e283ae4a24082c&state=b22583465c6539d0e4c93e772556903d43eeb8f2884995de" for 127.0.0.1 at 2016-02-12 10:56:54 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"cb0e4de358e3d3f1e3defd3d0306a8c3e08d61229474f08073e283ae4a24082c", "state"=>"b22583465c6539d0e4c93e772556903d43eeb8f2884995de"} 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.0ms) 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-02-12 10:56: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 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-02-12 10:56: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-02-12 10:56:54 +0000 Started GET "/auth/gds/callback?code=22e4567561011b339cce0fe3c37fa719c02826866c7bf63615bfffb4d10a42e7&state=1876b8df4ac3b0f2a0a17e3bd11da0cbcb88b8eac46308bc" for 127.0.0.1 at 2016-02-12 10:56:54 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"22e4567561011b339cce0fe3c37fa719c02826866c7bf63615bfffb4d10a42e7", "state"=>"1876b8df4ac3b0f2a0a17e3bd11da0cbcb88b8eac46308bc"} 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-02-12 10:56: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 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 "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:56: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-02-12 10:56:54 +0000 Started GET "/auth/gds/callback?code=d71c72ec53b1644864c3e98fd2f60266f5f5ca3b832c57cd3bcacc2fcd660fd6&state=c1d9903c8a7ec17858ebb765df0f8e3fc93367006995fa72" for 127.0.0.1 at 2016-02-12 10:56:55 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"d71c72ec53b1644864c3e98fd2f60266f5f5ca3b832c57cd3bcacc2fcd660fd6", "state"=>"c1d9903c8a7ec17858ebb765df0f8e3fc93367006995fa72"} 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.6ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:56:55 +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 3ms (Views: 0.7ms | ActiveRecord: 0.2ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:56:55 +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-02-12 10:56:55 +0000 Started GET "/auth/gds/callback?code=96154ee2d9dc239eb6c9fbd8592b33f71f8ecb07d0c8a26eebeec44e01e42818&state=2a7cb7ff202b8cd990eb0d24f631d8093319bb26288a6a8e" for 127.0.0.1 at 2016-02-12 10:56:55 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"96154ee2d9dc239eb6c9fbd8592b33f71f8ecb07d0c8a26eebeec44e01e42818", "state"=>"2a7cb7ff202b8cd990eb0d24f631d8093319bb26288a6a8e"} 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 7ms (ActiveRecord: 0.5ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:56:55 +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 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 3ms (Views: 0.5ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56: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-02-12 10:56:55 +0000 Started GET "/auth/gds/callback?code=1023f13916eaced25ab3979f659b747d802be8792a2a5b68ebc86f1e7b97e2f6&state=2c0019886999d5271f2399fb142acfdace37d3a257cad736" for 127.0.0.1 at 2016-02-12 10:56:55 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"1023f13916eaced25ab3979f659b747d802be8792a2a5b68ebc86f1e7b97e2f6", "state"=>"2c0019886999d5271f2399fb142acfdace37d3a257cad736"} 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.3ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 7ms (ActiveRecord: 0.8ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56: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 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.4ms | ActiveRecord: 0.2ms) User Load (0.2ms) 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.3ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "t"], ["id", 11]]  (12.3ms) commit transaction Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56: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 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Authenticating with gds_sso strategy Completed in 2ms (ActiveRecord: 0.2ms) Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 10:56:55 +0000 Started GET "/auth/gds/callback?code=062a8c38ef5b4278ec7a7932da6bc7566e1773615179b549a2d3e8e7082eeb41&state=7e7ef0624d55cdf57311a31553a570f218c03038f6a4bea8" for 127.0.0.1 at 2016-02-12 10:56:56 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"062a8c38ef5b4278ec7a7932da6bc7566e1773615179b549a2d3e8e7082eeb41", "state"=>"7e7ef0624d55cdf57311a31553a570f218c03038f6a4bea8"} 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.0ms) begin transaction SQL (0.2ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "f"], ["id", 11]]  (32.9ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 40ms (ActiveRecord: 33.5ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56: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 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 "/restricted" for 127.0.0.1 at 2016-02-12 10:56: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-02-12 10:56:56 +0000 Started GET "/auth/gds/callback?code=248a1c1eb5c3f9ff2baa39e5864e69fc7ea0916a5783d658c2abd93e889c32d7&state=da2082f0abcc7e541a31346d0a5a216cf34df6ed3eb6b89e" for 127.0.0.1 at 2016-02-12 10:56:56 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"248a1c1eb5c3f9ff2baa39e5864e69fc7ea0916a5783d658c2abd93e889c32d7", "state"=>"da2082f0abcc7e541a31346d0a5a216cf34df6ed3eb6b89e"} 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-02-12 10:56: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 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 "/restricted" for 127.0.0.1 at 2016-02-13 07:01: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-02-13 07:01:56 +0000 Started GET "/auth/gds/callback?code=457b0243301a5e87fcdfabba9f1424d76638f5e0c15e5f07f5a293559f722c8c&state=2e2a6a521e5fa078edaed7887c638fc18d60387d9af9bcfb" for 127.0.0.1 at 2016-02-13 07:01:56 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"457b0243301a5e87fcdfabba9f1424d76638f5e0c15e5f07f5a293559f722c8c", "state"=>"2e2a6a521e5fa078edaed7887c638fc18d60387d9af9bcfb"} 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.6ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 07:01: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 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 "/restricted" for 127.0.0.1 at 2016-02-12 10:56: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-02-12 10:56:56 +0000 Started GET "/auth/gds/callback?code=4074aa1e4f81612956357ae268328013da3882f5ab97f91344c20569a37f1dce&state=fe1f726f1da90da87135a73d69b3b9cd321fd93ae24943ae" for 127.0.0.1 at 2016-02-12 10:56:56 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"4074aa1e4f81612956357ae268328013da3882f5ab97f91344c20569a37f1dce", "state"=>"fe1f726f1da90da87135a73d69b3b9cd321fd93ae24943ae"} 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-02-12 10:56: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 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.5ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 06:51: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 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 2ms (Views: 0.6ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:56 +0000 Processing by ExampleController#restricted as JSON Completed in 39ms (ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:57 +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.4ms) UPDATE "users" SET "disabled" = ? WHERE "users"."id" = ? [["disabled", nil], ["id", 11]]  (11.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  (0.1ms) commit transaction Rendered text template (0.0ms) Completed 200 OK in 100ms (Views: 0.6ms | ActiveRecord: 12.7ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 10:56:57 +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.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.1ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.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.0ms) begin transaction  (0.1ms) commit transaction Rendered text template (0.0ms) Completed 200 OK in 92ms (Views: 0.4ms | ActiveRecord: 1.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 10:56:57 +0000 Processing by ExampleController#restricted as JSON Completed in 23ms (ActiveRecord: 0.0ms) Connecting to database specified by database.yml Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:00:24 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 2.9ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:00:24 +0000 Started GET "/auth/gds/callback?code=0573f8eb46c63c539c846dd3e34f37535d79d7db4f12413766ed005b842dce88&state=cedc4cb1abc58545954c48556cfcb36fb8054f560e3ad696" for 127.0.0.1 at 2016-02-12 11:00:39 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"0573f8eb46c63c539c846dd3e34f37535d79d7db4f12413766ed005b842dce88", "state"=>"cedc4cb1abc58545954c48556cfcb36fb8054f560e3ad696"} Authenticating with gds_sso strategy User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1 User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."email" = 'test@example-client.com' LIMIT 1  (0.1ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "test@example-client.com"], ["name", "Test User"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "integration-uid"]]  (21.7ms) commit transaction  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "remotely_signed_out" = 'f', "permissions" = '--- - signin ' WHERE "users"."id" = 1  (33.7ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 77.7ms (ActiveRecord: 57.1ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:00:39 +0000 Processing by ExampleController#restricted as HTML User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Rendered text template (0.0ms) Completed 200 OK in 10.2ms (Views: 6.7ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:00:39 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.2ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:00:39 +0000 Started GET "/auth/gds/callback?code=2cd4826be0914c711079755f83a918056e5efe49e0af8c8d1dbba95bf28ba2d3&state=639779cc2b4fbc771d44b6499a1ee5a9c7dd4c841bbf93b1" for 127.0.0.1 at 2016-02-12 11:00:40 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"2cd4826be0914c711079755f83a918056e5efe49e0af8c8d1dbba95bf28ba2d3", "state"=>"639779cc2b4fbc771d44b6499a1ee5a9c7dd4c841bbf93b1"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (21.4ms) commit transaction  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (32.8ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 60.8ms (ActiveRecord: 55.1ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:00:40 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Rendered text template (0.0ms) Completed 200 OK in 2.0ms (Views: 0.4ms | ActiveRecord: 0.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 11:00:40 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 0.8ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:00:40 +0000 Started GET "/auth/gds/callback?code=489698aa9006cd855d1e6ca7c8493ad92c8f6afd952d2dc6bb825b590f662d02&state=a530dc9924608bf6689a0e36beaab98d70bdf9eb58c386cd" for 127.0.0.1 at 2016-02-12 11:00:40 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"489698aa9006cd855d1e6ca7c8493ad92c8f6afd952d2dc6bb825b590f662d02", "state"=>"a530dc9924608bf6689a0e36beaab98d70bdf9eb58c386cd"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (42.3ms) commit transaction  (0.1ms) begin transaction  (0.4ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (23.0ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 72.8ms (ActiveRecord: 66.4ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 11:00:40 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.4ms (Views: 0.5ms | ActiveRecord: 0.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 11:00:40 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 0.2ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:00:40 +0000 Started GET "/auth/gds/callback?code=38616f8520cced20de6f02939ae34e3ea9b4a9e320d90d319d406d19254d340c&state=8e758ecc4068ae7c6247af058ece29fa7d31509466a9fd33" for 127.0.0.1 at 2016-02-12 11:00:40 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"38616f8520cced20de6f02939ae34e3ea9b4a9e320d90d319d406d19254d340c", "state"=>"8e758ecc4068ae7c6247af058ece29fa7d31509466a9fd33"} Authenticating with gds_sso strategy User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (30.8ms) commit transaction  (0.2ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (25.3ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 64.8ms (ActiveRecord: 57.4ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 11:00:41 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 3.1ms (Views: 0.4ms | ActiveRecord: 0.4ms) Started GET "/" for 127.0.0.1 at 2016-02-12 11:00:41 +0000 Processing by ExampleController#index as HTML Completed 200 OK in 0.8ms (Views: 0.4ms | ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:00:41 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.3ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:00:41 +0000 Started GET "/auth/gds/callback?code=329f916698d6baff1cab17fb15884f51b59b43d4604687fb49bd00b9d12b6161&state=3dca1b25ebb98add0866bd7471e3a152fbab7bb9d15e1fad" for 127.0.0.1 at 2016-02-12 11:00:41 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"329f916698d6baff1cab17fb15884f51b59b43d4604687fb49bd00b9d12b6161", "state"=>"3dca1b25ebb98add0866bd7471e3a152fbab7bb9d15e1fad"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.2ms) begin transaction  (0.4ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (22.2ms) commit transaction  (0.1ms) begin transaction  (0.4ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (22.4ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 55.4ms (ActiveRecord: 45.8ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:00:41 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 1.9ms (Views: 0.3ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:00:41 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.3ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:00:41 +0000 Started GET "/auth/gds/callback?code=a03b69f1d98475921a6f6a0b96856ebc6929fdbff4a4768c4c08672f1c54d816&state=94efe59198edb87d984df367bd9653eb7be7bc4a9a1a520e" for 127.0.0.1 at 2016-02-12 11:00:41 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"a03b69f1d98475921a6f6a0b96856ebc6929fdbff4a4768c4c08672f1c54d816", "state"=>"94efe59198edb87d984df367bd9653eb7be7bc4a9a1a520e"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (77.5ms) commit transaction  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (22.6ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 107.6ms (ActiveRecord: 101.1ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:00:41 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.0ms (Views: 0.3ms | ActiveRecord: 0.3ms) User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."email" = 'test@example-client.com' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "remotely_signed_out" = 't', "permissions" = '--- - signin ' WHERE "users"."id" = 1  (46.1ms) commit transaction Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:00:42 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Authenticating with gds_sso strategy Completed in 1.5ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:00:42 +0000 Started GET "/auth/gds/callback?code=86d98a4e8d75cc3340a1620d6cbf6d3f6e155e1b956ca10251bde8abe1798a08&state=c0451a4fac8ced87735d2b4c023e80061ee8adc2835d448f" for 127.0.0.1 at 2016-02-12 11:00:42 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"86d98a4e8d75cc3340a1620d6cbf6d3f6e155e1b956ca10251bde8abe1798a08", "state"=>"c0451a4fac8ced87735d2b4c023e80061ee8adc2835d448f"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (17.2ms) commit transaction  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "remotely_signed_out" = 'f', "permissions" = '--- - signin ' WHERE "users"."id" = 1  (22.5ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 46.8ms (ActiveRecord: 40.7ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:00:42 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.1ms (Views: 0.3ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:00:42 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.3ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:00:42 +0000 Started GET "/auth/gds/callback?code=9f0845133291de721d77da15190fe7358b1f857e3f548df14438c84e4eec975a&state=f494cd6ac81d9d3a97c0cfd70f4b73bfdd17406f92c169c4" for 127.0.0.1 at 2016-02-12 11:00:42 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"9f0845133291de721d77da15190fe7358b1f857e3f548df14438c84e4eec975a", "state"=>"f494cd6ac81d9d3a97c0cfd70f4b73bfdd17406f92c169c4"} Authenticating with gds_sso strategy User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (23.7ms) commit transaction  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (24.6ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 57.0ms (ActiveRecord: 49.4ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:00:42 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 1.7ms (Views: 0.3ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 07:05:42 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.8ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-13 07:05:42 +0000 Started GET "/auth/gds/callback?code=68183ba1c678dd1bfdb6f6c48c9fbc40c6dcc938696560a0476577c4b3254750&state=9122c5ab320a7131361a0ae7c4554045e3ad9beac4ff00b4" for 127.0.0.1 at 2016-02-13 07:05:42 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"68183ba1c678dd1bfdb6f6c48c9fbc40c6dcc938696560a0476577c4b3254750", "state"=>"9122c5ab320a7131361a0ae7c4554045e3ad9beac4ff00b4"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (33.6ms) commit transaction  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (34.2ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 75.2ms (ActiveRecord: 68.8ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 07:05:43 +0000 Processing by ExampleController#restricted as HTML User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.7ms (Views: 0.4ms | ActiveRecord: 0.5ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:00:43 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0.4ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:00:43 +0000 Started GET "/auth/gds/callback?code=bb9cf09d366608587a1e6056dae98b20e973faa27ec136cfedf95d1b2b9eb691&state=1cd91f902472a226bad1755bf1a0985e28774f166aa68caf" for 127.0.0.1 at 2016-02-12 11:00:43 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"bb9cf09d366608587a1e6056dae98b20e973faa27ec136cfedf95d1b2b9eb691", "state"=>"1cd91f902472a226bad1755bf1a0985e28774f166aa68caf"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (28.0ms) commit transaction  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (26.8ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 62.6ms (ActiveRecord: 55.8ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:00:43 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.1ms (Views: 0.4ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 06:55:43 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' LIMIT 1 Completed 200 OK in 2.2ms (Views: 0.3ms | ActiveRecord: 0.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 11:00:43 +0000 Processing by ExampleController#this_requires_signin_permission as JSON User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "disabled" = NULL, "permissions" = '--- - signin ' WHERE "users"."id" = 1  (15.4ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (30.8ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (22.5ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (23.1ms) commit transaction  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (13.0ms) commit transaction Completed 200 OK in 219.6ms (Views: 0.5ms | ActiveRecord: 107.8ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:00:43 +0000 Processing by ExampleController#restricted as JSON Completed in 28.0ms Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:00:43 +0000 Processing by ExampleController#restricted as JSON Completed in 25.6ms Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:00:43 +0000 Processing by ExampleController#restricted as JSON User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (20.4ms) commit transaction User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.2ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (26.1ms) commit transaction User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (21.5ms) commit transaction User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' LIMIT 1  (0.1ms) begin transaction  (0.2ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (22.7ms) commit transaction  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "permissions" = '--- - signin ' WHERE "users"."id" = 1  (20.8ms) commit transaction Completed 200 OK in 204.6ms (Views: 0.4ms | ActiveRecord: 114.1ms)  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "a1s2d34709"]]  (43.8ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n- user_update_permission\n"], ["remotely_signed_out", nil], ["uid", "a1s2d33269"]]  (20.6ms) commit transaction WARNING: Can't mass-assign protected attributes: uid, name, permissions Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d34709"} Completed 403 Forbidden in 3.6ms (Views: 2.9ms | ActiveRecord: 0.0ms)  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "a1s2d36544"]]  (42.3ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n- user_update_permission\n"], ["remotely_signed_out", nil], ["uid", "a1s2d33513"]]  (43.5ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d36544"} User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'a1s2d36544' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "email" = 'user@domain.com', "name" = 'Joshua Marshall', "permissions" = '--- - signin - new permission ', "organisation_slug" = 'justice-league', "organisation_content_id" = 'aae1319e-5788-4677-998c-f1a53af528d0' WHERE "users"."id" = 4  (36.7ms) commit transaction Completed 200 OK in 43.2ms (ActiveRecord: 37.5ms) User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 4]]  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "a1s2d37708"]]  (33.4ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n- user_update_permission\n"], ["remotely_signed_out", nil], ["uid", "a1s2d32690"]]  (20.4ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"nonexistent-user"} User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'nonexistent-user' LIMIT 1 Completed 200 OK in 1.6ms (ActiveRecord: 0.3ms)  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "a1s2d33149"]]  (27.2ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n- user_update_permission\n"], ["remotely_signed_out", nil], ["uid", "a1s2d33729"]]  (13.6ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d33149"} User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'a1s2d33149' LIMIT 1  (0.1ms) begin transaction  (0.3ms) UPDATE "users" SET "remotely_signed_out" = 't', "permissions" = '--- - signin ' WHERE "users"."id" = 8  (23.3ms) commit transaction Completed 200 OK in 27.8ms (ActiveRecord: 24.0ms) User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 8]]  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n"], ["remotely_signed_out", nil], ["uid", "a1s2d37083"]]  (21.9ms) commit transaction  (0.2ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("disabled", "email", "name", "organisation_content_id", "organisation_slug", "permissions", "remotely_signed_out", "uid") VALUES (?, ?, ?, ?, ?, ?, ?, ?) [["disabled", false], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["organisation_content_id", nil], ["organisation_slug", nil], ["permissions", "---\n- signin\n- user_update_permission\n"], ["remotely_signed_out", nil], ["uid", "a1s2d39447"]]  (21.3ms) commit transaction WARNING: Can't mass-assign protected attributes: uid, name, permissions Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d37083"} Completed 403 Forbidden in 1.5ms (Views: 1.0ms | ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:01:33 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 20ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:01:33 +0000 Started GET "/auth/gds/callback?code=774cf936f09b82f12c96fb3ef1e64ca2300f2a04206329069784a4637afbbbc8&state=db29381ffad15658e3c8c6435dfb00a375b7fd9c57e50881" for 127.0.0.1 at 2016-02-12 11:01:47 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"774cf936f09b82f12c96fb3ef1e64ca2300f2a04206329069784a4637afbbbc8", "state"=>"db29381ffad15658e3c8c6435dfb00a375b7fd9c57e50881"} Authenticating with gds_sso strategy User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1 User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."email" = 'test@example-client.com' ORDER BY "users"."id" ASC LIMIT 1  (0.2ms) begin transaction SQL (0.5ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "test@example-client.com"], ["name", "Test User"], ["permissions", "---\n- signin\n"], ["uid", "integration-uid"]]  (41.7ms) commit transaction  (0.2ms) begin transaction SQL (0.5ms) UPDATE "users" SET "permissions" = ?, "remotely_signed_out" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"], ["remotely_signed_out", "f"]]  (31.4ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 123ms (ActiveRecord: 76.1ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:01:47 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Rendered text template (0.1ms) Completed 200 OK in 12ms (Views: 8.1ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:01:47 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 1ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:01:47 +0000 Started GET "/auth/gds/callback?code=a6601d5620a388423a4a898c0020154fe5d058fb54420015922e388da55c48a0&state=c7ed68bcdc02daf2dbd1ca5a1af4f04feb0ad8bb1f72eb52" for 127.0.0.1 at 2016-02-12 11:01:47 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"a6601d5620a388423a4a898c0020154fe5d058fb54420015922e388da55c48a0", "state"=>"c7ed68bcdc02daf2dbd1ca5a1af4f04feb0ad8bb1f72eb52"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (126.3ms) commit transaction  (0.2ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (36.2ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 170ms (ActiveRecord: 163.7ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:01:48 +0000 Processing by ExampleController#restricted as HTML User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Rendered text template (0.0ms) Completed 200 OK in 4ms (Views: 0.9ms | ActiveRecord: 0.4ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 11:01:48 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 1ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:01:48 +0000 Started GET "/auth/gds/callback?code=c33c1c3456a27807d5be8f205e08ca5785433ccae68f5ed2eb0a0cf228e0fba2&state=1dcfddb292a9fbc56ffa5c2586bc54a0742168da368ea94b" for 127.0.0.1 at 2016-02-12 11:01:48 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"c33c1c3456a27807d5be8f205e08ca5785433ccae68f5ed2eb0a0cf228e0fba2", "state"=>"1dcfddb292a9fbc56ffa5c2586bc54a0742168da368ea94b"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (36.3ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (33.0ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 77ms (ActiveRecord: 70.2ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 11:01:48 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 3ms (Views: 0.5ms | ActiveRecord: 0.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 11:01:48 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 0ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:01:48 +0000 Started GET "/auth/gds/callback?code=893f6dac7daa9bb20c144b9ec1ac8d434224ac8c37b1313bf742613fdbf1d294&state=c26d500d91d850f20bfe641240c54eed1e575d369a1aaa6e" for 127.0.0.1 at 2016-02-12 11:01:48 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"893f6dac7daa9bb20c144b9ec1ac8d434224ac8c37b1313bf742613fdbf1d294", "state"=>"c26d500d91d850f20bfe641240c54eed1e575d369a1aaa6e"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (100.6ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (27.7ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 135ms (ActiveRecord: 129.2ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 11:01:49 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 3ms (Views: 0.3ms | ActiveRecord: 0.4ms) Started GET "/" for 127.0.0.1 at 2016-02-12 11:01:49 +0000 Processing by ExampleController#index as HTML Completed 200 OK in 1ms (Views: 0.4ms | ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:01:49 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:01:49 +0000 Started GET "/auth/gds/callback?code=f85b65403a1e3b35fbb0ee3ab0da6993731008f55d06026d6f43ff25f0019963&state=a9034ad534f1c27bcdc3b9ca1c358ae0f58e59821d56e273" for 127.0.0.1 at 2016-02-12 11:01:49 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"f85b65403a1e3b35fbb0ee3ab0da6993731008f55d06026d6f43ff25f0019963", "state"=>"a9034ad534f1c27bcdc3b9ca1c358ae0f58e59821d56e273"} Authenticating with gds_sso strategy User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (21.7ms) commit transaction  (0.2ms) begin transaction SQL (0.4ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (97.5ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 129ms (ActiveRecord: 120.7ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:01:49 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:01:49 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:01:49 +0000 Started GET "/auth/gds/callback?code=6341f1de006edcbbaf7a3cb6759f9ab8923a898b579d29ffcc5c0e3240da8954&state=5ff0d7730e4f9f5277ef45c94862c5407e5c68abe482f8ab" for 127.0.0.1 at 2016-02-12 11:01:49 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"6341f1de006edcbbaf7a3cb6759f9ab8923a898b579d29ffcc5c0e3240da8954", "state"=>"5ff0d7730e4f9f5277ef45c94862c5407e5c68abe482f8ab"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (21.7ms) commit transaction  (0.3ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (16.9ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 47ms (ActiveRecord: 40.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:01:49 +0000 Processing by ExampleController#restricted as HTML User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 3ms (Views: 0.6ms | ActiveRecord: 0.4ms) User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."email" = 'test@example-client.com' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ?, "remotely_signed_out" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"], ["remotely_signed_out", "t"]]  (180.0ms) commit transaction Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:01:50 +0000 Processing by ExampleController#restricted as HTML User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Authenticating with gds_sso strategy Completed in 2ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:01:50 +0000 Started GET "/auth/gds/callback?code=f35a7afafab36f306134584cfb1f575be1480d3dbb7062024379df7fcd63eca0&state=5638338c2cb9f7507d76b2080d571109084cc6bf1955b5d9" for 127.0.0.1 at 2016-02-12 11:01:50 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"f35a7afafab36f306134584cfb1f575be1480d3dbb7062024379df7fcd63eca0", "state"=>"5638338c2cb9f7507d76b2080d571109084cc6bf1955b5d9"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (19.4ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ?, "remotely_signed_out" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"], ["remotely_signed_out", "f"]]  (24.2ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 51ms (ActiveRecord: 44.5ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:01:50 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 2ms (Views: 0.3ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:01:50 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:01:50 +0000 Started GET "/auth/gds/callback?code=c9dd4f8e261952a015687447552213a546c8f7c2136b053f7ea48d4712f8f4a3&state=f8d14652af53fdc4ab25a6a4b86b9f7971532ecb62fb75e8" for 127.0.0.1 at 2016-02-12 11:01:50 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"c9dd4f8e261952a015687447552213a546c8f7c2136b053f7ea48d4712f8f4a3", "state"=>"f8d14652af53fdc4ab25a6a4b86b9f7971532ecb62fb75e8"} Authenticating with gds_sso strategy User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.4ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (20.0ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (21.4ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 51ms (ActiveRecord: 42.8ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:01:50 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 2ms (Views: 0.4ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 07:06:50 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 1ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-13 07:06:50 +0000 Started GET "/auth/gds/callback?code=9d547d7829a1b56491d26f7d2ffdae4777ca13c0bdbbb7a3397db037098bd038&state=169511f8990b547bf019ec2e05540ee7ec4d0701b6530756" for 127.0.0.1 at 2016-02-13 07:06:50 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"9d547d7829a1b56491d26f7d2ffdae4777ca13c0bdbbb7a3397db037098bd038", "state"=>"169511f8990b547bf019ec2e05540ee7ec4d0701b6530756"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (42.3ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (11.3ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 61ms (ActiveRecord: 54.7ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 07:06:51 +0000 Processing by ExampleController#restricted as HTML User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 3ms (Views: 0.4ms | ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:01:51 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 0ms Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:01:51 +0000 Started GET "/auth/gds/callback?code=97b3dc6968962fefb01c5eb988d3f7d82ea9349ed21948a208016e54fae56644&state=9b3ec10b5d53476cbfc701d31fad0d3f3d76f9bbdcbd790f" for 127.0.0.1 at 2016-02-12 11:01:51 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"97b3dc6968962fefb01c5eb988d3f7d82ea9349ed21948a208016e54fae56644", "state"=>"9b3ec10b5d53476cbfc701d31fad0d3f3d76f9bbdcbd790f"} Authenticating with gds_sso strategy User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (81.1ms) commit transaction  (0.1ms) begin transaction SQL (0.4ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (30.2ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 119ms (ActiveRecord: 112.6ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:01:51 +0000 Processing by ExampleController#restricted as HTML User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 3ms (Views: 0.4ms | ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 06:56:51 +0000 Processing by ExampleController#restricted as HTML User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' AND "users"."remotely_signed_out" = 'f' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 3ms (Views: 0.4ms | ActiveRecord: 0.3ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 11:01:51 +0000 Processing by ExampleController#this_requires_signin_permission as JSON User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "disabled" = ?, "permissions" = ? WHERE "users"."id" = 1 [["disabled", nil], ["permissions", "---\n- signin\n"]]  (14.8ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (19.7ms) commit transaction User Load (0.6ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (15.5ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (18.4ms) commit transaction  (0.2ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (19.8ms) commit transaction Completed 200 OK in 200ms (Views: 0.4ms | ActiveRecord: 91.4ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:01:51 +0000 Processing by ExampleController#restricted as JSON Completed in 25ms Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:01:51 +0000 Processing by ExampleController#restricted as JSON Completed in 28ms Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:01:51 +0000 Processing by ExampleController#restricted as JSON User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (12.0ms) commit transaction User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (60.3ms) commit transaction User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (110.0ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'integration-uid' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.2ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (242.0ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ? WHERE "users"."id" = 1 [["permissions", "---\n- signin\n"]]  (66.9ms) commit transaction Completed 200 OK in 606ms (Views: 0.5ms | ActiveRecord: 494.4ms)  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"], ["uid", "a1s2d33005"]]  (74.1ms) commit transaction  (0.2ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"], ["uid", "a1s2d32692"]]  (19.0ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d33005"} Completed 403 Forbidden in 5ms (Views: 4.7ms | ActiveRecord: 0.0ms)  (0.1ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"], ["uid", "a1s2d33798"]]  (19.4ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"], ["uid", "a1s2d33210"]]  (18.2ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d33798"} User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'a1s2d33798' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "email" = ?, "name" = ?, "organisation_content_id" = ?, "organisation_slug" = ?, "permissions" = ? WHERE "users"."id" = 4 [["email", "user@domain.com"], ["name", "Joshua Marshall"], ["organisation_content_id", "aae1319e-5788-4677-998c-f1a53af528d0"], ["organisation_slug", "justice-league"], ["permissions", "---\n- signin\n- new permission\n"]]  (62.1ms) commit transaction Completed 200 OK in 67ms (ActiveRecord: 62.8ms) User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 4]]  (0.2ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"], ["uid", "a1s2d36755"]]  (14.9ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"], ["uid", "a1s2d32429"]]  (18.3ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"nonexistent-user"} User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'nonexistent-user' ORDER BY "users"."id" ASC LIMIT 1 Completed 200 OK in 1ms (ActiveRecord: 0.3ms)  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"], ["uid", "a1s2d33442"]]  (87.4ms) commit transaction  (0.1ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"], ["uid", "a1s2d36609"]]  (60.2ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d33442"} User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = 'a1s2d33442' ORDER BY "users"."id" ASC LIMIT 1  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "permissions" = ?, "remotely_signed_out" = ? WHERE "users"."id" = 8 [["permissions", "---\n- signin\n"], ["remotely_signed_out", "t"]]  (62.4ms) commit transaction Completed 200 OK in 67ms (ActiveRecord: 63.3ms) User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 8]]  (0.2ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"], ["uid", "a1s2d39439"]]  (21.2ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("email", "name", "permissions", "uid") VALUES (?, ?, ?, ?) [["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"], ["uid", "a1s2d33840"]]  (19.6ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d39439"} Completed 403 Forbidden in 2ms (Views: 1.2ms | ActiveRecord: 0.0ms)  (0.2ms) begin transaction SQL (0.5ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d36027"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (29.4ms) commit transaction  (0.2ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d3169"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (17.4ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d36027"} Rendered /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.4ms) Completed 403 Forbidden in 9ms (Views: 8.5ms | ActiveRecord: 0.0ms)  (0.2ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d31992"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (16.5ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d34802"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (20.8ms) commit transaction Processing by Api::UserController#update as HTML Parameters: {"uid"=>"a1s2d31992"} User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "a1s2d31992"]]  (0.1ms) begin transaction SQL (0.4ms) UPDATE "users" SET "email" = ?, "name" = ?, "permissions" = ?, "organisation_slug" = ?, "organisation_content_id" = ? WHERE "users"."id" = ? [["email", "user@domain.com"], ["name", "Joshua Marshall"], ["permissions", "---\n- signin\n- new permission\n"], ["organisation_slug", "justice-league"], ["organisation_content_id", "aae1319e-5788-4677-998c-f1a53af528d0"], ["id", 3]]  (11.9ms) commit transaction Completed 200 OK in 27ms (ActiveRecord: 12.9ms) User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 3]]  (0.1ms) begin transaction SQL (0.3ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d33130"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (25.4ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d32916"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (11.6ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d33130"} Rendered /home/jenkins/workspace/govuk_gds_sso/app/views/authorisations/unauthorised.html.erb within layouts/unauthorised (0.2ms) Completed 403 Forbidden in 1ms (Views: 1.1ms | ActiveRecord: 0.0ms)  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d35160"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (19.2ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d36770"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (20.8ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"nonexistent-user"} User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "nonexistent-user"]] Completed 200 OK in 1ms (ActiveRecord: 0.1ms)  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d33368"], ["email", "old@domain.com"], ["name", "Moshua Jarshall"], ["permissions", "---\n- signin\n"]]  (13.9ms) commit transaction  (0.1ms) begin transaction SQL (0.2ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "a1s2d35602"], ["email", "ssopushuser@legit.com"], ["name", "SSO Push user"], ["permissions", "---\n- signin\n- user_update_permission\n"]]  (10.6ms) commit transaction Processing by Api::UserController#reauth as HTML Parameters: {"uid"=>"a1s2d33368"} User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "a1s2d33368"]]  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "t"], ["id", 9]]  (17.6ms) commit transaction Completed 200 OK in 21ms (ActiveRecord: 18.2ms) User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1 [["id", 9]] Started GET "/" for 127.0.0.1 at 2016-02-12 11:02:46 +0000 Processing by ExampleController#index as HTML Rendered text template (0.1ms) Completed 200 OK in 3ms (Views: 2.2ms | ActiveRecord: 0.0ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 11:02:46 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 15ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:02:46 +0000 Started GET "/auth/gds/callback?code=d388f2a1ce30570d9a4b1ca4772af3c20b736badedf632b17b1e13c8d4d48f83&state=1aee046d1204d2697defd655c31f0dff8936b3a31ccdfd99" for 127.0.0.1 at 2016-02-12 11:03:02 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"d388f2a1ce30570d9a4b1ca4772af3c20b736badedf632b17b1e13c8d4d48f83", "state"=>"1aee046d1204d2697defd655c31f0dff8936b3a31ccdfd99"} Authenticating with gds_sso strategy User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]] User Load (0.6ms) SELECT "users".* FROM "users" WHERE "users"."email" = ? ORDER BY "users"."id" ASC LIMIT 1 [["email", "test@example-client.com"]]  (0.2ms) begin transaction SQL (0.4ms) INSERT INTO "users" ("uid", "email", "name", "permissions") VALUES (?, ?, ?, ?) [["uid", "integration-uid"], ["email", "test@example-client.com"], ["name", "Test User"], ["permissions", "---\n- signin\n"]]  (56.3ms) commit transaction  (0.1ms) begin transaction SQL (0.3ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "f"], ["id", 11]]  (50.7ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 122ms (ActiveRecord: 109.1ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 11:03:02 +0000 Processing by ExampleController#this_requires_signin_permission as HTML User Load (0.5ms) 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 4ms (Views: 0.5ms | ActiveRecord: 0.5ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 11:03:02 +0000 Processing by ExampleController#this_requires_signin_permission as HTML Authenticating with gds_sso strategy Completed in 1ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:03:02 +0000 Started GET "/auth/gds/callback?code=8d0c0910705f02f65292d93e85ede8af0c084e2fa44b37a380dada9e9bf519aa&state=6459c1d8cc0cceb8ae028d3434abcb408ad26e882e1470e0" for 127.0.0.1 at 2016-02-12 11:03:03 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"8d0c0910705f02f65292d93e85ede8af0c084e2fa44b37a380dada9e9bf519aa", "state"=>"6459c1d8cc0cceb8ae028d3434abcb408ad26e882e1470e0"} Authenticating with gds_sso strategy User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.2ms) commit transaction  (0.1ms) begin transaction  (0.2ms) commit transaction Redirected to http://www.example-client.com/this_requires_signin_permission Completed 302 Found in 10ms (ActiveRecord: 0.9ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 11:03:03 +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 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 4ms (Views: 0.5ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:03: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-02-12 11:03:03 +0000 Started GET "/auth/gds/callback?code=52bc2b911de00813f54a66092d473f3d588192caea2f1289802fbbd5316e9957&state=9e7aae46b8655bb18e86a7e3ad4ff20d9b5232a7b989666c" for 127.0.0.1 at 2016-02-12 11:03:03 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"52bc2b911de00813f54a66092d473f3d588192caea2f1289802fbbd5316e9957", "state"=>"9e7aae46b8655bb18e86a7e3ad4ff20d9b5232a7b989666c"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.3ms) commit transaction  (0.1ms) begin transaction  (0.2ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 11ms (ActiveRecord: 0.9ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:03:03 +0000 Processing by ExampleController#restricted as HTML User Load (0.4ms) 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 4ms (Views: 0.7ms | ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:03: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-02-12 11:03:03 +0000 Started GET "/auth/gds/callback?code=9a7ed55c8b030c99592ddeaa8750e4384715ce81afec2102dcf50d8ebb842867&state=b5b7f496be06cc0f8332fd22473cd801fca1cc251a144112" for 127.0.0.1 at 2016-02-12 11:03:04 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"9a7ed55c8b030c99592ddeaa8750e4384715ce81afec2102dcf50d8ebb842867", "state"=>"b5b7f496be06cc0f8332fd22473cd801fca1cc251a144112"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.1ms) begin transaction  (0.2ms) commit transaction  (0.1ms) begin transaction  (0.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 8ms (ActiveRecord: 0.7ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:03:04 +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 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 3ms (Views: 0.5ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:03:04 +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-02-12 11:03:04 +0000 Started GET "/auth/gds/callback?code=b31b13165d02b0f06aec209ff8d6173aff883b739209acea30ef6c16e4ab8ba5&state=6961871f9a5d015ca7557361d64ff13f98d138712a20cebe" for 127.0.0.1 at 2016-02-12 11:03:04 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"b31b13165d02b0f06aec209ff8d6173aff883b739209acea30ef6c16e4ab8ba5", "state"=>"6961871f9a5d015ca7557361d64ff13f98d138712a20cebe"} 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.6ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:03:04 +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.6ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:03:04 +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-02-12 11:03:04 +0000 Started GET "/auth/gds/callback?code=8cfa410d00f6baa80597f5ce7adb209f058bf23df3cce686e48a095b65e5d3f3&state=b86a382aaf5b49cda07d9215944a66fb863e1ec4a3fdfa57" for 127.0.0.1 at 2016-02-12 11:03:04 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"8cfa410d00f6baa80597f5ce7adb209f058bf23df3cce686e48a095b65e5d3f3", "state"=>"b86a382aaf5b49cda07d9215944a66fb863e1ec4a3fdfa57"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.4ms) begin transaction  (0.2ms) commit transaction  (0.4ms) begin transaction  (0.2ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 17ms (ActiveRecord: 1.5ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:03:04 +0000 Processing by ExampleController#restricted as HTML User Load (0.4ms) 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 5ms (Views: 0.7ms | ActiveRecord: 0.4ms) User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."email" = ? ORDER BY "users"."id" ASC LIMIT 1 [["email", "test@example-client.com"]]  (0.5ms) begin transaction SQL (0.4ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "t"], ["id", 11]]  (21.1ms) commit transaction Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:03:05 +0000 Processing by ExampleController#restricted as HTML User Load (0.5ms) 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 4ms (ActiveRecord: 0.5ms) Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:03:05 +0000 Started GET "/auth/gds/callback?code=4399094db411be9c12a3aa37066e266e88d57ade889f2d03e2a2ae7cf8fc63e7&state=a4a8c8d6c6ec6ca4bbc0b4f2faf68f6e2d6493039347bc43" for 127.0.0.1 at 2016-02-12 11:03:05 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"4399094db411be9c12a3aa37066e266e88d57ade889f2d03e2a2ae7cf8fc63e7", "state"=>"a4a8c8d6c6ec6ca4bbc0b4f2faf68f6e2d6493039347bc43"} 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 SQL (0.3ms) UPDATE "users" SET "remotely_signed_out" = ? WHERE "users"."id" = ? [["remotely_signed_out", "f"], ["id", 11]]  (38.1ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 47ms (ActiveRecord: 38.9ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:03:05 +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.1ms) Completed 200 OK in 3ms (Views: 0.5ms | ActiveRecord: 0.2ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:03:05 +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-02-12 11:03:05 +0000 Started GET "/auth/gds/callback?code=37a96ea20363c3e35d0cc9707aa627e2573dc222fb1553911964767a6137d922&state=f10c4e526c943f571677ee8c4dce67ebcd2fa2f8fcd1fdf7" for 127.0.0.1 at 2016-02-12 11:03:05 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"37a96ea20363c3e35d0cc9707aa627e2573dc222fb1553911964767a6137d922", "state"=>"f10c4e526c943f571677ee8c4dce67ebcd2fa2f8fcd1fdf7"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.2ms) begin transaction  (0.2ms) commit transaction  (0.1ms) begin transaction  (0.2ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 11ms (ActiveRecord: 0.9ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:03:05 +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 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.0ms) Completed 200 OK in 4ms (Views: 0.6ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 07:08:06 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 2ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2016-02-13 07:08:06 +0000 Started GET "/auth/gds/callback?code=b219568eae04c347c17f771f2794d7cf8cc468dd53acab8d4cc7bc53f04f4180&state=e21a7c0d4fb79a8c448ddf9b0d16b416f8e6f7000d2c6bbc" for 127.0.0.1 at 2016-02-13 07:08:06 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"b219568eae04c347c17f771f2794d7cf8cc468dd53acab8d4cc7bc53f04f4180", "state"=>"e21a7c0d4fb79a8c448ddf9b0d16b416f8e6f7000d2c6bbc"} Authenticating with gds_sso strategy User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.3ms) begin transaction  (0.2ms) commit transaction  (0.1ms) begin transaction  (0.2ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 11ms (ActiveRecord: 1.1ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 07:08:06 +0000 Processing by ExampleController#restricted as HTML User Load (0.4ms) 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 4ms (Views: 0.8ms | ActiveRecord: 0.4ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:03:06 +0000 Processing by ExampleController#restricted as HTML Authenticating with gds_sso strategy Completed in 1ms (ActiveRecord: 0.0ms) Started GET "/auth/gds" for 127.0.0.1 at 2016-02-12 11:03:06 +0000 Started GET "/auth/gds/callback?code=78b33a4a197e8849dbafc0108b4793bfd04816db2100b9005cc9a64e1800ae44&state=93118a20098390d8c93023dbd8b0fe5e35bdd9f4abe8c690" for 127.0.0.1 at 2016-02-12 11:03:06 +0000 Processing by AuthenticationsController#callback as HTML Parameters: {"code"=>"78b33a4a197e8849dbafc0108b4793bfd04816db2100b9005cc9a64e1800ae44", "state"=>"93118a20098390d8c93023dbd8b0fe5e35bdd9f4abe8c690"} Authenticating with gds_sso strategy User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.2ms) begin transaction  (0.3ms) commit transaction  (0.2ms) begin transaction  (0.2ms) commit transaction Redirected to http://www.example-client.com/restricted Completed 302 Found in 16ms (ActiveRecord: 1.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:03:06 +0000 Processing by ExampleController#restricted as HTML User Load (0.8ms) 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 6ms (Views: 1.2ms | ActiveRecord: 0.8ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-13 06:58:06 +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 1 [["uid", "integration-uid"], ["remotely_signed_out", "f"]] Rendered text template (0.1ms) Completed 200 OK in 5ms (Views: 0.8ms | ActiveRecord: 0.3ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:03:06 +0000 Processing by ExampleController#restricted as JSON Completed in 42ms (ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:03:06 +0000 Processing by ExampleController#restricted as JSON Completed in 45ms (ActiveRecord: 0.0ms) Started GET "/restricted" for 127.0.0.1 at 2016-02-12 11:03:06 +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.6ms) UPDATE "users" SET "disabled" = ? WHERE "users"."id" = ? [["disabled", nil], ["id", 11]]  (28.9ms) commit transaction User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.2ms) begin transaction  (0.2ms) commit transaction CACHE (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.2ms) begin transaction  (0.2ms) commit transaction CACHE (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.2ms) begin transaction  (0.2ms) commit transaction  (0.1ms) begin transaction  (0.1ms) commit transaction Rendered text template (0.0ms) Completed 200 OK in 199ms (Views: 0.7ms | ActiveRecord: 31.8ms) Started GET "/this_requires_signin_permission" for 127.0.0.1 at 2016-02-12 11:03:07 +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.2ms) 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.2ms) commit transaction CACHE (0.0ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.2ms) begin transaction  (0.2ms) commit transaction CACHE (0.1ms) SELECT "users".* FROM "users" WHERE "users"."uid" = ? ORDER BY "users"."id" ASC LIMIT 1 [["uid", "integration-uid"]]  (0.4ms) begin transaction  (0.3ms) commit transaction  (0.2ms) begin transaction  (0.2ms) commit transaction Rendered text template (0.0ms) Completed 200 OK in 195ms (Views: 1.2ms | ActiveRecord: 2.4ms)