Devise Omniauth - 请求阶段启动了两次
Devise Omniauth - Request phase initiated twice
我已经绞尽脑汁大约 8 个小时了。我正在设置一个设计客户端，以与基于门卫的自定义提供程序一起工作。
除了设计客户端的授权外，一切正常。出于某种原因，每当我单击 user_omniauth_authorize_path(:doorkeeper) 时，omniauth Request phase initiated 都会被触发两次。我不知道是什么原因造成的。
这是来自客户端和提供商的事件序列的日志。
客户端日志
jonathan@Jonathan doorkeeper-client (master) $ rails s -p 3001
=> Booting WEBrick
=> Rails 4.2.4 application starting in development on http://localhost:3001
=> Run `rails server -h` for more startup options
=> Ctrl-C to shutdown server
[2015-10-24 23:37:27] INFO WEBrick 1.3.1
[2015-10-24 23:37:27] INFO ruby 2.2.2 (2015-04-13) [x86_64-darwin15]
[2015-10-24 23:37:27] INFO WEBrick::HTTPServer#start: pid=59452 port=3001
Started GET "/" for ::1 at 2015-10-24 23:37:33 -0500
ActiveRecord::SchemaMigration Load (0.4ms) SELECT "schema_migrations".* FROM "schema_migrations"
Processing by ApplicationController#index as HTML
Rendered application/index.html.erb within layouts/application (1.9ms)
Completed 200 OK in 157ms (Views: 143.7ms | ActiveRecord: 0.0ms)
Started GET "/users/auth/doorkeeper" for ::1 at 2015-10-24 23:37:40 -0500
I, [2015-10-24T23:37:40.521903 #59452] INFO -- omniauth: (doorkeeper) Request phase initiated.
Started GET "/users/auth/doorkeeper" for ::1 at 2015-10-24 23:37:40 -0500
I, [2015-10-24T23:37:40.615061 #59452] INFO -- omniauth: (doorkeeper) Request phase initiated.
Started GET "/users/auth/doorkeeper/callback?code=e1aa1b123ecadb91088527dfa3529181a99fa1f607a88738badd51b24aa2e8ee&state=d5166e94b40231ac06d65ae52f5a9b97a6aee828505f02b9" for ::1 at 2015-10-24 23:38:37 -0500
I, [2015-10-24T23:38:37.618820 #59452] INFO -- omniauth: (doorkeeper) Callback phase initiated.
E, [2015-10-24T23:38:37.640490 #59452] ERROR -- omniauth: (doorkeeper) Authentication failure! invalid_credentials: OAuth2::Error, invalid_grant: The provided authorization grant is invalid, expired, revoked, does not match the redirection URI used in the authorization request, or was issued to another client.
{"error":"invalid_grant","error_description":"The provided authorization grant is invalid, expired, revoked, does not match the redirection URI used in the authorization request, or was issued to another client."}
Processing by Users::OmniauthCallbacksController#failure as HTML
Parameters: {"code"=>"e1aa1b123ecadb91088527dfa3529181a99fa1f607a88738badd51b24aa2e8ee", "state"=>"d5166e94b40231ac06d65ae52f5a9b97a6aee828505f02b9"}
Redirected to http://localhost:3001/
Completed 302 Found in 332ms (ActiveRecord: 0.0ms)
Started GET "/" for ::1 at 2015-10-24 23:38:37 -0500
Processing by ApplicationController#index as HTML
Rendered application/index.html.erb within layouts/application (0.3ms)
Completed 200 OK in 21ms (Views: 20.3ms | ActiveRecord: 0.0ms)
提供商日志
jonathan@Jonathan doorkeeper-provider (master) $ rails s
=> Booting WEBrick
=> Rails 4.2.4 application starting in development on http://localhost:3000
=> Run `rails server -h` for more startup options
=> Ctrl-C to shutdown server
[2015-10-24 23:37:24] INFO WEBrick 1.3.1
[2015-10-24 23:37:24] INFO ruby 2.2.3 (2015-08-18) [x86_64-darwin15]
[2015-10-24 23:37:24] INFO WEBrick::HTTPServer#start: pid=59448 port=3000
Started GET "/oauth/authorize?client_id=867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed&redirect_uri=http%3A%2F%2Flocalhost%3A3001%2Fusers%2Fauth%2Fdoorkeeper%2Fcallback&response_type=code&scope=user&state=61dbe5751135b43d5465f979e4dd1bcbbe9dc6935c65e595" for ::1 at 2015-10-24 23:37:40 -0500
ActiveRecord::SchemaMigration Load (0.5ms) SELECT "schema_migrations".* FROM "schema_migrations"
Processing by Doorkeeper::AuthorizationsController#new as HTML
Parameters: {"client_id"=>"867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed", "redirect_uri"=>"http://localhost:3001/users/auth/doorkeeper/callback", "response_type"=>"code", "scope"=>"user", "state"=>"61dbe5751135b43d5465f979e4dd1bcbbe9dc6935c65e595"}
Redirected to http://localhost:3000/users/sign_in
Filter chain halted as :authenticate_resource_owner! rendered or redirected
Completed 302 Found in 11ms (ActiveRecord: 0.0ms)
Started GET "/oauth/authorize?client_id=867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed&redirect_uri=http%3A%2F%2Flocalhost%3A3001%2Fusers%2Fauth%2Fdoorkeeper%2Fcallback&response_type=code&scope=user&state=d5166e94b40231ac06d65ae52f5a9b97a6aee828505f02b9" for ::1 at 2015-10-24 23:37:40 -0500
Processing by Doorkeeper::AuthorizationsController#new as HTML
Parameters: {"client_id"=>"867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed", "redirect_uri"=>"http://localhost:3001/users/auth/doorkeeper/callback", "response_type"=>"code", "scope"=>"user", "state"=>"d5166e94b40231ac06d65ae52f5a9b97a6aee828505f02b9"}
User Load (0.9ms) SELECT "users".* FROM "users" WHERE "users"."id" = ORDER BY "users"."id" ASC LIMIT 1 [["id", 1]]
Doorkeeper::Application Load (0.9ms) SELECT "oauth_applications".* FROM "oauth_applications" WHERE "oauth_applications"."uid" = LIMIT 1 [["uid", "867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed"]]
Doorkeeper::AccessToken Load (0.7ms) SELECT "oauth_access_tokens".* FROM "oauth_access_tokens" WHERE "oauth_access_tokens"."application_id" = AND "oauth_access_tokens"."resource_owner_id" = AND "oauth_access_tokens"."revoked_at" IS NULL ORDER BY created_at desc LIMIT 1 [["application_id", 1], ["resource_owner_id", 1]]
Rendered /Users/jonathan/.rvm/gems/ruby-2.2.3/gems/doorkeeper-3.0.1/app/views/doorkeeper/authorizations/new.html.erb within layouts/doorkeeper/application (10.2ms)
Completed 200 OK in 168ms (Views: 129.9ms | ActiveRecord: 10.5ms)
Started POST "/oauth/authorize" for ::1 at 2015-10-24 23:38:37 -0500
Processing by Doorkeeper::AuthorizationsController#create as HTML
Parameters: {"utf8"=>"✓", "authenticity_token"=>"[FILTERED]", "client_id"=>"867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed", "redirect_uri"=>"http://localhost:3001/users/auth/doorkeeper/callback", "state"=>"d5166e94b40231ac06d65ae52f5a9b97a6aee828505f02b9", "response_type"=>"code", "scope"=>"user", "commit"=>"Authorize"}
User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."id" = ORDER BY "users"."id" ASC LIMIT 1 [["id", 1]]
Doorkeeper::Application Load (0.3ms) SELECT "oauth_applications".* FROM "oauth_applications" WHERE "oauth_applications"."uid" = LIMIT 1 [["uid", "867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed"]]
(0.2ms) BEGIN
Doorkeeper::AccessGrant Exists (0.7ms) SELECT 1 AS one FROM "oauth_access_grants" WHERE "oauth_access_grants"."token" = 'e1aa1b123ecadb91088527dfa3529181a99fa1f607a88738badd51b24aa2e8ee' LIMIT 1
SQL (0.5ms) INSERT INTO "oauth_access_grants" ("application_id", "resource_owner_id", "expires_in", "redirect_uri", "scopes", "token", "created_at") VALUES (, , , , , , ) RETURNING "id" [["application_id", 1], ["resource_owner_id", 1], ["expires_in", 1200], ["redirect_uri", "http://localhost:3001/users/auth/doorkeeper/callback"], ["scopes", "user"], ["token", "e1aa1b123ecadb91088527dfa3529181a99fa1f607a88738badd51b24aa2e8ee"], ["created_at", "2015-10-25 04:38:37.602105"]]
(0.4ms) COMMIT
Redirected to http://localhost:3001/users/auth/doorkeeper/callback?code=e1aa1b123ecadb91088527dfa3529181a99fa1f607a88738badd51b24aa2e8ee&state=d5166e94b40231ac06d65ae52f5a9b97a6aee828505f02b9
Completed 302 Found in 24ms (ActiveRecord: 4.2ms)
Started POST "/oauth/token" for ::1 at 2015-10-24 23:38:37 -0500
Processing by Doorkeeper::TokensController#create as */*
Parameters: {"client_id"=>"867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed", "client_secret"=>"[FILTERED]", "code"=>"[FILTERED]", "grant_type"=>"authorization_code", "redirect_uri"=>"http://localhost:3001/users/auth/doorkeeper/callback?code=e1aa1b123ecadb91088527dfa3529181a99fa1f607a88738badd51b24aa2e8ee&state=d5166e94b40231ac06d65ae52f5a9b97a6aee828505f02b9"}
Doorkeeper::AccessGrant Load (0.4ms) SELECT "oauth_access_grants".* FROM "oauth_access_grants" WHERE "oauth_access_grants"."token" = LIMIT 1 [["token", "e1aa1b123ecadb91088527dfa3529181a99fa1f607a88738badd51b24aa2e8ee"]]
Doorkeeper::Application Load (0.3ms) SELECT "oauth_applications".* FROM "oauth_applications" WHERE "oauth_applications"."uid" = AND "oauth_applications"."secret" = LIMIT 1 [["uid", "867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed"], ["secret", "857c7e1f887d52064703ef19852032729e321643ab4638d302ab33eb0afe1a57"]]
Completed 401 Unauthorized in 4ms
所以重复请求问题最终只是 javascript，可能是 turbolinks 出于某种原因触发了两次请求。
谢谢马克斯
我已经绞尽脑汁大约 8 个小时了。我正在设置一个设计客户端，以与基于门卫的自定义提供程序一起工作。
除了设计客户端的授权外，一切正常。出于某种原因，每当我单击 user_omniauth_authorize_path(:doorkeeper) 时，omniauth Request phase initiated 都会被触发两次。我不知道是什么原因造成的。
这是来自客户端和提供商的事件序列的日志。
客户端日志
jonathan@Jonathan doorkeeper-client (master) $ rails s -p 3001
=> Booting WEBrick
=> Rails 4.2.4 application starting in development on http://localhost:3001
=> Run `rails server -h` for more startup options
=> Ctrl-C to shutdown server
[2015-10-24 23:37:27] INFO WEBrick 1.3.1
[2015-10-24 23:37:27] INFO ruby 2.2.2 (2015-04-13) [x86_64-darwin15]
[2015-10-24 23:37:27] INFO WEBrick::HTTPServer#start: pid=59452 port=3001
Started GET "/" for ::1 at 2015-10-24 23:37:33 -0500
ActiveRecord::SchemaMigration Load (0.4ms) SELECT "schema_migrations".* FROM "schema_migrations"
Processing by ApplicationController#index as HTML
Rendered application/index.html.erb within layouts/application (1.9ms)
Completed 200 OK in 157ms (Views: 143.7ms | ActiveRecord: 0.0ms)
Started GET "/users/auth/doorkeeper" for ::1 at 2015-10-24 23:37:40 -0500
I, [2015-10-24T23:37:40.521903 #59452] INFO -- omniauth: (doorkeeper) Request phase initiated.
Started GET "/users/auth/doorkeeper" for ::1 at 2015-10-24 23:37:40 -0500
I, [2015-10-24T23:37:40.615061 #59452] INFO -- omniauth: (doorkeeper) Request phase initiated.
Started GET "/users/auth/doorkeeper/callback?code=e1aa1b123ecadb91088527dfa3529181a99fa1f607a88738badd51b24aa2e8ee&state=d5166e94b40231ac06d65ae52f5a9b97a6aee828505f02b9" for ::1 at 2015-10-24 23:38:37 -0500
I, [2015-10-24T23:38:37.618820 #59452] INFO -- omniauth: (doorkeeper) Callback phase initiated.
E, [2015-10-24T23:38:37.640490 #59452] ERROR -- omniauth: (doorkeeper) Authentication failure! invalid_credentials: OAuth2::Error, invalid_grant: The provided authorization grant is invalid, expired, revoked, does not match the redirection URI used in the authorization request, or was issued to another client.
{"error":"invalid_grant","error_description":"The provided authorization grant is invalid, expired, revoked, does not match the redirection URI used in the authorization request, or was issued to another client."}
Processing by Users::OmniauthCallbacksController#failure as HTML
Parameters: {"code"=>"e1aa1b123ecadb91088527dfa3529181a99fa1f607a88738badd51b24aa2e8ee", "state"=>"d5166e94b40231ac06d65ae52f5a9b97a6aee828505f02b9"}
Redirected to http://localhost:3001/
Completed 302 Found in 332ms (ActiveRecord: 0.0ms)
Started GET "/" for ::1 at 2015-10-24 23:38:37 -0500
Processing by ApplicationController#index as HTML
Rendered application/index.html.erb within layouts/application (0.3ms)
Completed 200 OK in 21ms (Views: 20.3ms | ActiveRecord: 0.0ms)
提供商日志
jonathan@Jonathan doorkeeper-provider (master) $ rails s
=> Booting WEBrick
=> Rails 4.2.4 application starting in development on http://localhost:3000
=> Run `rails server -h` for more startup options
=> Ctrl-C to shutdown server
[2015-10-24 23:37:24] INFO WEBrick 1.3.1
[2015-10-24 23:37:24] INFO ruby 2.2.3 (2015-08-18) [x86_64-darwin15]
[2015-10-24 23:37:24] INFO WEBrick::HTTPServer#start: pid=59448 port=3000
Started GET "/oauth/authorize?client_id=867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed&redirect_uri=http%3A%2F%2Flocalhost%3A3001%2Fusers%2Fauth%2Fdoorkeeper%2Fcallback&response_type=code&scope=user&state=61dbe5751135b43d5465f979e4dd1bcbbe9dc6935c65e595" for ::1 at 2015-10-24 23:37:40 -0500
ActiveRecord::SchemaMigration Load (0.5ms) SELECT "schema_migrations".* FROM "schema_migrations"
Processing by Doorkeeper::AuthorizationsController#new as HTML
Parameters: {"client_id"=>"867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed", "redirect_uri"=>"http://localhost:3001/users/auth/doorkeeper/callback", "response_type"=>"code", "scope"=>"user", "state"=>"61dbe5751135b43d5465f979e4dd1bcbbe9dc6935c65e595"}
Redirected to http://localhost:3000/users/sign_in
Filter chain halted as :authenticate_resource_owner! rendered or redirected
Completed 302 Found in 11ms (ActiveRecord: 0.0ms)
Started GET "/oauth/authorize?client_id=867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed&redirect_uri=http%3A%2F%2Flocalhost%3A3001%2Fusers%2Fauth%2Fdoorkeeper%2Fcallback&response_type=code&scope=user&state=d5166e94b40231ac06d65ae52f5a9b97a6aee828505f02b9" for ::1 at 2015-10-24 23:37:40 -0500
Processing by Doorkeeper::AuthorizationsController#new as HTML
Parameters: {"client_id"=>"867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed", "redirect_uri"=>"http://localhost:3001/users/auth/doorkeeper/callback", "response_type"=>"code", "scope"=>"user", "state"=>"d5166e94b40231ac06d65ae52f5a9b97a6aee828505f02b9"}
User Load (0.9ms) SELECT "users".* FROM "users" WHERE "users"."id" = ORDER BY "users"."id" ASC LIMIT 1 [["id", 1]]
Doorkeeper::Application Load (0.9ms) SELECT "oauth_applications".* FROM "oauth_applications" WHERE "oauth_applications"."uid" = LIMIT 1 [["uid", "867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed"]]
Doorkeeper::AccessToken Load (0.7ms) SELECT "oauth_access_tokens".* FROM "oauth_access_tokens" WHERE "oauth_access_tokens"."application_id" = AND "oauth_access_tokens"."resource_owner_id" = AND "oauth_access_tokens"."revoked_at" IS NULL ORDER BY created_at desc LIMIT 1 [["application_id", 1], ["resource_owner_id", 1]]
Rendered /Users/jonathan/.rvm/gems/ruby-2.2.3/gems/doorkeeper-3.0.1/app/views/doorkeeper/authorizations/new.html.erb within layouts/doorkeeper/application (10.2ms)
Completed 200 OK in 168ms (Views: 129.9ms | ActiveRecord: 10.5ms)
Started POST "/oauth/authorize" for ::1 at 2015-10-24 23:38:37 -0500
Processing by Doorkeeper::AuthorizationsController#create as HTML
Parameters: {"utf8"=>"✓", "authenticity_token"=>"[FILTERED]", "client_id"=>"867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed", "redirect_uri"=>"http://localhost:3001/users/auth/doorkeeper/callback", "state"=>"d5166e94b40231ac06d65ae52f5a9b97a6aee828505f02b9", "response_type"=>"code", "scope"=>"user", "commit"=>"Authorize"}
User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."id" = ORDER BY "users"."id" ASC LIMIT 1 [["id", 1]]
Doorkeeper::Application Load (0.3ms) SELECT "oauth_applications".* FROM "oauth_applications" WHERE "oauth_applications"."uid" = LIMIT 1 [["uid", "867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed"]]
(0.2ms) BEGIN
Doorkeeper::AccessGrant Exists (0.7ms) SELECT 1 AS one FROM "oauth_access_grants" WHERE "oauth_access_grants"."token" = 'e1aa1b123ecadb91088527dfa3529181a99fa1f607a88738badd51b24aa2e8ee' LIMIT 1
SQL (0.5ms) INSERT INTO "oauth_access_grants" ("application_id", "resource_owner_id", "expires_in", "redirect_uri", "scopes", "token", "created_at") VALUES (, , , , , , ) RETURNING "id" [["application_id", 1], ["resource_owner_id", 1], ["expires_in", 1200], ["redirect_uri", "http://localhost:3001/users/auth/doorkeeper/callback"], ["scopes", "user"], ["token", "e1aa1b123ecadb91088527dfa3529181a99fa1f607a88738badd51b24aa2e8ee"], ["created_at", "2015-10-25 04:38:37.602105"]]
(0.4ms) COMMIT
Redirected to http://localhost:3001/users/auth/doorkeeper/callback?code=e1aa1b123ecadb91088527dfa3529181a99fa1f607a88738badd51b24aa2e8ee&state=d5166e94b40231ac06d65ae52f5a9b97a6aee828505f02b9
Completed 302 Found in 24ms (ActiveRecord: 4.2ms)
Started POST "/oauth/token" for ::1 at 2015-10-24 23:38:37 -0500
Processing by Doorkeeper::TokensController#create as */*
Parameters: {"client_id"=>"867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed", "client_secret"=>"[FILTERED]", "code"=>"[FILTERED]", "grant_type"=>"authorization_code", "redirect_uri"=>"http://localhost:3001/users/auth/doorkeeper/callback?code=e1aa1b123ecadb91088527dfa3529181a99fa1f607a88738badd51b24aa2e8ee&state=d5166e94b40231ac06d65ae52f5a9b97a6aee828505f02b9"}
Doorkeeper::AccessGrant Load (0.4ms) SELECT "oauth_access_grants".* FROM "oauth_access_grants" WHERE "oauth_access_grants"."token" = LIMIT 1 [["token", "e1aa1b123ecadb91088527dfa3529181a99fa1f607a88738badd51b24aa2e8ee"]]
Doorkeeper::Application Load (0.3ms) SELECT "oauth_applications".* FROM "oauth_applications" WHERE "oauth_applications"."uid" = AND "oauth_applications"."secret" = LIMIT 1 [["uid", "867e46cc052aafc5c580d328daa475d7024328df71eedfe3d640e197f651f0ed"], ["secret", "857c7e1f887d52064703ef19852032729e321643ab4638d302ab33eb0afe1a57"]]
Completed 401 Unauthorized in 4ms
所以重复请求问题最终只是 javascript，可能是 turbolinks 出于某种原因触发了两次请求。
谢谢马克斯