search

doorkeeper-gem / doorkeeper

Doorkeeper is an OAuth 2 provider for Ruby on Rails / Grape.
https://doorkeeper.gitbook.io/guides/
MIT License
5.31k stars 1.06k forks source link

Cannot insert duplicate key row in object dbo.oauth_access_tokens with unique index index_oauth_access_tokens_on_refresh_token #520

Closed jfrux closed 9 years ago

jfrux commented 9 years ago

Hello,

I'm sure I'm unique in this but I have a Rails 4.1.8 app running Tiny Tds / activerecord-sqlserver-adapter to MS SQL Server.

Upon calling /oauth/token it's generating an error: Cannot insert duplicate key row in object dbo.oauth_access_tokens with unique index index_oauth_access_tokens_on_refresh_token

Why would it be trying to insert a new record instead of updating it?

jfrux commented 9 years ago

For what it's worth, I feel like it's somehow looking up an access token that doesn't exist and then when it doesn't find it, it's inserting the record and failing on the unique index.

Any tips on this?

Started POST "/oauth/token" for 127.0.0.1 at 2014-12-11 21:09:02 -0500
  SQL (53.4ms)  USE [CCPD_PROD]
  ActiveRecord::SchemaMigration Load (55.6ms)  EXEC sp_executesql N'SELECT [schema_migrations].* FROM [schema_migrations]'
Processing by Doorkeeper::TokensController#create as HTML
  Parameters: {"client_id"=>"45e62866b8b3efea6286796c9f71b2c4ac7c5cbad6f140bc59d3d7b09eb9ae16", "grant_type"=>"password", "password"=>"[FILTERED]", "client_secret"=>"cf6d22582403db29b598dbf8cc26c2784e6cadb76702273907ce198063c4b8d8", "username"=>"rountrjf@ucmail.uc.edu"}
  User Load (56.0ms)  EXEC sp_executesql N'SELECT TOP (1) [users].* FROM [users] WHERE [users].[email] = N''rountrjf@ucmail.uc.edu'' ORDER BY [users].[personid] ASC'
  SQL (47.8ms)  BEGIN TRANSACTION
  SQL (50.1ms)  EXEC sp_executesql N'UPDATE [users] SET [encrypted_password] = @0 WHERE [users].[personid] = 169841; SELECT @@ROWCOUNT AS AffectedRows', N'@0 nvarchar(255)', @0 = N'$2a$12$iXGg5cqtmSp2xbW0BDyac.YnEQmnIdkn7IyVBa/dOXqu1b/7b33di'  [["encrypted_password", "$2a$12$iXGg5cqtmSp2xbW0BDyac.YnEQmnIdkn7IyVBa/dOXqu1b/7b33di"]]
  SQL (55.3ms)  COMMIT TRANSACTION
  Doorkeeper::Application Load (50.1ms)  EXEC sp_executesql N'SELECT TOP (1) [oauth_applications].* FROM [oauth_applications] WHERE [oauth_applications].[uid] = N''45e62866b8b3efea6286796c9f71b2c4ac7c5cbad6f140bc59d3d7b09eb9ae16'' AND [oauth_applications].[secret] = N''cf6d22582403db29b598dbf8cc26c2784e6cadb76702273907ce198063c4b8d8'' ORDER BY [oauth_applications].[id] ASC'
  SQL (49.0ms)  BEGIN TRANSACTION
  Doorkeeper::AccessToken Exists (47.7ms)  EXEC sp_executesql N'SELECT TOP (1) 1 AS one FROM [oauth_access_tokens] WHERE [oauth_access_tokens].[token] = N''107f221d5a07c78a17a6610462a192dba80889ac5026eb06c908219d63a7700b'' COLLATE Latin1_General_CS_AS_WS'
  SQL (100.6ms)  EXEC sp_executesql N'INSERT INTO [oauth_access_tokens] ([application_id], [created_at], [expires_in], [resource_owner_id], [scopes], [token]) OUTPUT inserted.id VALUES (@0, @1, @2, @3, @4, @5)', N'@0 int, @1 datetime, @2 int, @3 int, @4 nvarchar(255), @5 nvarchar(255)', @0 = 1, @1 = '2014-12-12T02:09:05.182', @2 = 7200, @3 = 169841, @4 = N'public', @5 = N'107f221d5a07c78a17a6610462a192dba80889ac5026eb06c908219d63a7700b'  [["application_id", 1], ["created_at", Fri, 12 Dec 2014 02:09:05 UTC +00:00], ["expires_in", 7200], ["resource_owner_id", 169841], ["scopes", "public"], ["token", "107f221d5a07c78a17a6610462a192dba80889ac5026eb06c908219d63a7700b"]]
TinyTds::Error: Cannot insert duplicate key row in object 'dbo.oauth_access_tokens' with unique index 'index_oauth_access_tokens_on_refresh_token'.: EXEC sp_executesql N'INSERT INTO [oauth_access_tokens] ([application_id], [created_at], [expires_in], [resource_owner_id], [scopes], [token]) OUTPUT inserted.id VALUES (@0, @1, @2, @3, @4, @5)', N'@0 int, @1 datetime, @2 int, @3 int, @4 nvarchar(255), @5 nvarchar(255)', @0 = 1, @1 = '2014-12-12T02:09:05.182', @2 = 7200, @3 = 169841, @4 = N'public', @5 = N'107f221d5a07c78a17a6610462a192dba80889ac5026eb06c908219d63a7700b'
  SQL (46.2ms)  IF @@TRANCOUNT > 0 ROLLBACK TRANSACTION
Completed 500 Internal Server Error in 1339ms

ActiveRecord::RecordNotUnique (TinyTds::Error: Cannot insert duplicate key row in object 'dbo.oauth_access_tokens' with unique index 'index_oauth_access_tokens_on_refresh_token'.: EXEC sp_executesql N'INSERT INTO [oauth_access_tokens] ([application_id], [created_at], [expires_in], [resource_owner_id], [scopes], [token]) OUTPUT inserted.id VALUES (@0, @1, @2, @3, @4, @5)', N'@0 int, @1 datetime, @2 int, @3 int, @4 nvarchar(255), @5 nvarchar(255)', @0 = 1, @1 = '2014-12-12T02:09:05.182', @2 = 7200, @3 = 169841, @4 = N'public', @5 = N'107f221d5a07c78a17a6610462a192dba80889ac5026eb06c908219d63a7700b'):
  activerecord-sqlserver-adapter (4.1.0) lib/active_record/connection_adapters/sqlserver/database_statements.rb:423:in `each'
  activerecord-sqlserver-adapter (4.1.0) lib/active_record/connection_adapters/sqlserver/database_statements.rb:423:in `handle_to_names_and_values_dblib'
  activerecord-sqlserver-adapter (4.1.0) lib/active_record/connection_adapters/sqlserver/database_statements.rb:412:in `handle_to_names_and_values'
  activerecord-sqlserver-adapter (4.1.0) lib/active_record/connection_adapters/sqlserver/database_statements.rb:385:in `_raw_select'
  activerecord-sqlserver-adapter (4.1.0) lib/active_record/connection_adapters/sqlserver/database_statements.rb:380:in `block in raw_select'
  activerecord (4.1.8) lib/active_record/connection_adapters/abstract_adapter.rb:373:in `block in log'
  activesupport (4.1.8) lib/active_support/notifications/instrumenter.rb:20:in `instrument'
  activerecord (4.1.8) lib/active_record/connection_adapters/abstract_adapter.rb:367:in `log'
  activerecord-sqlserver-adapter (4.1.0) lib/active_record/connection_adapters/sqlserver/database_statements.rb:380:in `raw_select'
  activerecord-sqlserver-adapter (4.1.0) lib/active_record/connection_adapters/sqlserver/database_statements.rb:363:in `do_exec_query'
  activerecord-sqlserver-adapter (4.1.0) lib/active_record/connection_adapters/sqlserver/database_statements.rb:24:in `exec_query'
  activerecord-sqlserver-adapter (4.1.0) lib/active_record/connection_adapters/sqlserver/database_statements.rb:30:in `exec_insert'
  activerecord (4.1.8) lib/active_record/connection_adapters/abstract/database_statements.rb:95:in `insert'
  activerecord (4.1.8) lib/active_record/connection_adapters/abstract/query_cache.rb:14:in `insert'
  activerecord (4.1.8) lib/active_record/relation.rb:64:in `insert'
  activerecord (4.1.8) lib/active_record/persistence.rb:503:in `_create_record'
  activerecord (4.1.8) lib/active_record/attribute_methods/dirty.rb:87:in `_create_record'
  activerecord (4.1.8) lib/active_record/callbacks.rb:306:in `block in _create_record'
  activesupport (4.1.8) lib/active_support/callbacks.rb:82:in `run_callbacks'
  activerecord (4.1.8) lib/active_record/callbacks.rb:306:in `_create_record'
  activerecord (4.1.8) lib/active_record/timestamp.rb:57:in `_create_record'
  activerecord (4.1.8) lib/active_record/persistence.rb:483:in `create_or_update'
  activerecord (4.1.8) lib/active_record/callbacks.rb:302:in `block in create_or_update'
  activesupport (4.1.8) lib/active_support/callbacks.rb:113:in `call'
  activesupport (4.1.8) lib/active_support/callbacks.rb:113:in `call'
  activesupport (4.1.8) lib/active_support/callbacks.rb:166:in `block in halting'
  activesupport (4.1.8) lib/active_support/callbacks.rb:86:in `call'
  activesupport (4.1.8) lib/active_support/callbacks.rb:86:in `run_callbacks'
  activerecord (4.1.8) lib/active_record/callbacks.rb:302:in `create_or_update'
  activerecord (4.1.8) lib/active_record/persistence.rb:125:in `save!'
  activerecord (4.1.8) lib/active_record/validations.rb:57:in `save!'
  activerecord (4.1.8) lib/active_record/attribute_methods/dirty.rb:29:in `save!'
  activerecord (4.1.8) lib/active_record/transactions.rb:273:in `block in save!'
  activerecord (4.1.8) lib/active_record/transactions.rb:329:in `block in with_transaction_returning_status'
  activerecord (4.1.8) lib/active_record/connection_adapters/abstract/database_statements.rb:201:in `block in transaction'
  activerecord (4.1.8) lib/active_record/connection_adapters/abstract/database_statements.rb:209:in `within_new_transaction'
  activerecord (4.1.8) lib/active_record/connection_adapters/abstract/database_statements.rb:201:in `transaction'
  activerecord (4.1.8) lib/active_record/transactions.rb:208:in `transaction'
  activerecord (4.1.8) lib/active_record/transactions.rb:326:in `with_transaction_returning_status'
  activerecord (4.1.8) lib/active_record/transactions.rb:273:in `save!'
  activerecord (4.1.8) lib/active_record/validations.rb:41:in `create!'
  doorkeeper (1.4.0) lib/doorkeeper/models/access_token.rb:60:in `find_or_create_for'
  doorkeeper (1.4.0) lib/doorkeeper/oauth/request_concern.rb:33:in `find_or_create_access_token'
  doorkeeper (1.4.0) lib/doorkeeper/oauth/password_access_token_request.rb:30:in `before_successful_response'
  doorkeeper (1.4.0) lib/doorkeeper/oauth/request_concern.rb:7:in `authorize'
  doorkeeper (1.4.0) lib/doorkeeper/request/password.rb:19:in `authorize'
  doorkeeper (1.4.0) app/controllers/doorkeeper/tokens_controller.rb:4:in `create'
  actionpack (4.1.8) lib/abstract_controller/base.rb:189:in `process_action'
  actionpack (4.1.8) lib/action_controller/metal/instrumentation.rb:31:in `block in process_action'
  activesupport (4.1.8) lib/active_support/notifications.rb:159:in `block in instrument'
  activesupport (4.1.8) lib/active_support/notifications/instrumenter.rb:20:in `instrument'
  activesupport (4.1.8) lib/active_support/notifications.rb:159:in `instrument'
  actionpack (4.1.8) lib/action_controller/metal/instrumentation.rb:30:in `process_action'
  actionpack (4.1.8) lib/action_controller/metal/rendering.rb:10:in `process_action'
  actionpack (4.1.8) lib/abstract_controller/base.rb:136:in `process'
  actionpack (4.1.8) lib/action_controller/metal.rb:196:in `dispatch'
  actionpack (4.1.8) lib/action_controller/metal/rack_delegation.rb:13:in `dispatch'
  actionpack (4.1.8) lib/action_controller/metal.rb:232:in `block in action'
  actionpack (4.1.8) lib/action_dispatch/routing/route_set.rb:82:in `call'
  actionpack (4.1.8) lib/action_dispatch/routing/route_set.rb:82:in `dispatch'
  actionpack (4.1.8) lib/action_dispatch/routing/route_set.rb:50:in `call'
  actionpack (4.1.8) lib/action_dispatch/journey/router.rb:73:in `block in call'
  actionpack (4.1.8) lib/action_dispatch/journey/router.rb:59:in `each'
  actionpack (4.1.8) lib/action_dispatch/journey/router.rb:59:in `call'
  actionpack (4.1.8) lib/action_dispatch/routing/route_set.rb:678:in `call'
  omniauth (1.2.2) lib/omniauth/strategy.rb:186:in `call!'
  omniauth (1.2.2) lib/omniauth/strategy.rb:164:in `call'
  omniauth (1.2.2) lib/omniauth/strategy.rb:186:in `call!'
  omniauth (1.2.2) lib/omniauth/strategy.rb:164:in `call'
  omniauth (1.2.2) lib/omniauth/builder.rb:59:in `call'
  omniauth (1.2.2) lib/omniauth/strategy.rb:186:in `call!'
  omniauth (1.2.2) lib/omniauth/strategy.rb:164:in `call'
  omniauth (1.2.2) lib/omniauth/strategy.rb:186:in `call!'
  omniauth (1.2.2) lib/omniauth/strategy.rb:164:in `call'
  omniauth (1.2.2) lib/omniauth/builder.rb:59:in `call'
  warden (1.2.3) lib/warden/manager.rb:35:in `block in call'
  warden (1.2.3) lib/warden/manager.rb:34:in `catch'
  warden (1.2.3) lib/warden/manager.rb:34:in `call'
  rack (1.5.2) lib/rack/etag.rb:23:in `call'
  rack (1.5.2) lib/rack/conditionalget.rb:35:in `call'
  rack (1.5.2) lib/rack/head.rb:11:in `call'
  actionpack (4.1.8) lib/action_dispatch/middleware/params_parser.rb:27:in `call'
  actionpack (4.1.8) lib/action_dispatch/middleware/flash.rb:254:in `call'
  rack (1.5.2) lib/rack/session/abstract/id.rb:225:in `context'
  rack (1.5.2) lib/rack/session/abstract/id.rb:220:in `call'
  actionpack (4.1.8) lib/action_dispatch/middleware/cookies.rb:560:in `call'
  activerecord (4.1.8) lib/active_record/query_cache.rb:36:in `call'
  activerecord (4.1.8) lib/active_record/connection_adapters/abstract/connection_pool.rb:621:in `call'
  activerecord (4.1.8) lib/active_record/migration.rb:380:in `call'
  actionpack (4.1.8) lib/action_dispatch/middleware/callbacks.rb:29:in `block in call'
  activesupport (4.1.8) lib/active_support/callbacks.rb:82:in `run_callbacks'
  actionpack (4.1.8) lib/action_dispatch/middleware/callbacks.rb:27:in `call'
  actionpack (4.1.8) lib/action_dispatch/middleware/reloader.rb:73:in `call'
  actionpack (4.1.8) lib/action_dispatch/middleware/remote_ip.rb:76:in `call'
  actionpack (4.1.8) lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call'
  actionpack (4.1.8) lib/action_dispatch/middleware/show_exceptions.rb:30:in `call'
  railties (4.1.8) lib/rails/rack/logger.rb:38:in `call_app'
  railties (4.1.8) lib/rails/rack/logger.rb:20:in `block in call'
  activesupport (4.1.8) lib/active_support/tagged_logging.rb:68:in `block in tagged'
  activesupport (4.1.8) lib/active_support/tagged_logging.rb:26:in `tagged'
  activesupport (4.1.8) lib/active_support/tagged_logging.rb:68:in `tagged'
  railties (4.1.8) lib/rails/rack/logger.rb:20:in `call'
  quiet_assets (1.0.3) lib/quiet_assets.rb:23:in `call_with_quiet_assets'
  actionpack (4.1.8) lib/action_dispatch/middleware/request_id.rb:21:in `call'
  rack (1.5.2) lib/rack/methodoverride.rb:21:in `call'
  rack (1.5.2) lib/rack/runtime.rb:17:in `call'
  activesupport (4.1.8) lib/active_support/cache/strategy/local_cache_middleware.rb:26:in `call'
  rack (1.5.2) lib/rack/lock.rb:17:in `call'
  actionpack (4.1.8) lib/action_dispatch/middleware/static.rb:84:in `call'
  rack (1.5.2) lib/rack/sendfile.rb:112:in `call'
  railties (4.1.8) lib/rails/engine.rb:514:in `call'
  railties (4.1.8) lib/rails/application.rb:144:in `call'
  /Users/Joshua/Library/Application Support/Pow/Versions/0.5.0/node_modules/nack/lib/nack/server.rb:155:in `handle'
  /Users/Joshua/Library/Application Support/Pow/Versions/0.5.0/node_modules/nack/lib/nack/server.rb:109:in `rescue in block (2 levels) in start'
  /Users/Joshua/Library/Application Support/Pow/Versions/0.5.0/node_modules/nack/lib/nack/server.rb:106:in `block (2 levels) in start'
  /Users/Joshua/Library/Application Support/Pow/Versions/0.5.0/node_modules/nack/lib/nack/server.rb:96:in `each'
  /Users/Joshua/Library/Application Support/Pow/Versions/0.5.0/node_modules/nack/lib/nack/server.rb:96:in `block in start'
  /Users/Joshua/Library/Application Support/Pow/Versions/0.5.0/node_modules/nack/lib/nack/server.rb:76:in `loop'
  /Users/Joshua/Library/Application Support/Pow/Versions/0.5.0/node_modules/nack/lib/nack/server.rb:76:in `start'
  /Users/Joshua/Library/Application Support/Pow/Versions/0.5.0/node_modules/nack/lib/nack/server.rb:12:in `run'
  /Users/Joshua/Library/Application Support/Pow/Versions/0.5.0/node_modules/nack/bin/nack_worker:4:in `<main>'

  Rendered /Users/Joshua/.rbenv/versions/2.1.5/lib/ruby/gems/2.1.0/gems/actionpack-4.1.8/lib/action_dispatch/middleware/templates/rescues/_source.erb (0.5ms)
  Rendered /Users/Joshua/.rbenv/versions/2.1.5/lib/ruby/gems/2.1.0/gems/actionpack-4.1.8/lib/action_dispatch/middleware/templates/rescues/_trace.html.erb (0.9ms)
  Rendered /Users/Joshua/.rbenv/versions/2.1.5/lib/ruby/gems/2.1.0/gems/actionpack-4.1.8/lib/action_dispatch/middleware/templates/rescues/_request_and_response.html.erb (10.3ms)
  Rendered /Users/Joshua/.rbenv/versions/2.1.5/lib/ruby/gems/2.1.0/gems/actionpack-4.1.8/lib/action_dispatch/middleware/templates/rescues/diagnostics.erb within rescues/layout (32.8ms)
jfrux commented 9 years ago

Okay, so when I enable use_refresh_token in initializers/doorkeeper.rb it seems to be okay? I assume I just do not understand enough about doorkeeper at this point!

jfrux commented 9 years ago

well, if I set the config to "reuse_access_token" in the initializer... it seems to work but I don't know if it's the safest way to run oauth2... :-/

If I don't reuse_access_token... shouldn't it update the access token instead of trying to insert a new one therefor breaking the unique index?

jfrux commented 9 years ago

Also, I suspect that when it does expire, it'll do the same thing?

jfrux commented 9 years ago

Okay so this is definitely not a doorkeeper issue (as I'm sure you are not surprised). It is related to Microsoft SQL Server.
More specifically, SQL Server 2005 not allowing multiple NULL values on a unique index.

So for this particular situation, I found a workaround that solves the problem for me until I can get this database migrated to a different DBMS system.

I rolled back my database using:

$ rake db:rollback

I then modified the db migrate file for doorkeeper to reflect this:

# edited file: db/migrate/00000000000000_create_doorkeeper_tables.rb
class CreateDoorkeeperTables < ActiveRecord::Migration
  def up
    create_table :oauth_applications do |t|
      t.string  :name,         null: false
      t.string  :uid,          null: false
      t.string  :secret,       null: false
      t.text    :redirect_uri, null: false
      t.timestamps
    end

    add_index :oauth_applications, :uid, unique: true

    create_table :oauth_access_grants do |t|
      t.integer  :resource_owner_id, null: false
      t.integer  :application_id,    null: false
      t.string   :token,             null: false
      t.integer  :expires_in,        null: false
      t.text     :redirect_uri,      null: false
      t.datetime :created_at,        null: false
      t.datetime :revoked_at
      t.string   :scopes
    end

    add_index :oauth_access_grants, :token, unique: true

    create_table :oauth_access_tokens do |t|
      t.integer  :resource_owner_id
      t.integer  :application_id
      t.string   :token,             null: false
      t.string   :refresh_token
      t.integer  :expires_in
      t.datetime :revoked_at
      t.datetime :created_at,        null: false
      t.string   :scopes
    end

    add_index :oauth_access_tokens, :token, unique: true
    add_index :oauth_access_tokens, :resource_owner_id
    # add_index :oauth_access_tokens, :refresh_token, unique: true
    execute "ALTER TABLE oauth_access_tokens ADD refresh_token_nullfix AS (CASE WHEN refresh_token IS NULL THEN CAST(id AS NVARCHAR(256)) ELSE refresh_token END);"
    execute "CREATE UNIQUE INDEX UX_TEST_ON_NULLFIX ON oauth_access_tokens (refresh_token_nullfix);"
  end

  def down
    drop_table :oauth_applications
    drop_table :oauth_access_grants
    drop_table :oauth_access_tokens
  end
end

This allows the Doorkeeper system to function as it was intended.

Thank you all for all you do for the community.