Summary
Discourse DB constraint error because of duplicate key values generated when users without an account attempt to log in via SSO. Causes internal server error (500) to be seen via external proxy.
Discussion
On August 28th or 29th, I updated Discourse to the latest beta (v2.4.0.beta2) along with all the installed Discourse plug-ins. Around the same time, I also updated SeAT, and reconfigured Discourse to use a UNIX socket, which the external Apache can proxy/reverse proxy to. Prior to that, people were able to login via SeAT’s EvE Online SSO and new Discourse user accounts would be created for them if they didn’t already have one.
Since then, no new user accounts have successfully been created. Instead, the three people who have tried have generated Failed to create or lookup user: ERROR: duplicate key value violates constraint "idx_category_users_user_id_category_id" DETAIL: Key (user_id, category_id)=(36, 6) already exists.
errors. The category_id
is always 6
but the user_id
varies between 33 and 44, even repeating numbers.
Assuming that category_id
refers to entries in categories
, then 6
seems to be Grass Clippings
. Assuming that user_id
refers to entries in users
, then we don’t have any entries higher than 32
.
Grass Clippings
as a category is restricted for at least reading to people in the 2GTHRDiscourse
, 2GTHRHighCouncil
, and GRoLLake
groups. At least one of the people trying to connect had an add_groups
command that included all three groups. The first person did not yet have one of the three, and the middle person had at least one of the three. They all generate the same kind of database error with the identical details except except the user_id
.
People with Discourse accounts created by logging in via SSO prior to the upgrades do not seem to be experiencing problems logging in.
Things Tried or Looked At
-
Turning off
force https
and reverting back to external Apache proxying to nginx ports.
Unsurprisingly, this had no effect. -
Followed through the backtrace and could see Discourse made it to
models/discourse_single_sign_on.rb
at line 203 ofmatch_email_or_create_user()
where it makes a call toUser.create!()
. Alas, the logging of the params, etc. is after that point, which it never gets to because it stops processing and returns a HTTP error 500. I checkedshared/log/rails/production.log.*
just in case.
Other Comments
-
SeAT: While the SeAT Discourse plug-in wasn’t updated, many components of SeAT were. It’s possible something in there has changed. However, the error is clearly on the Discourse side when trying to create or lookup a non-existent user, so I’m somewhat dubious the problem is on the SeAT side.
-
Discourse: I can’t remember what beta version of Discourse I was running before the upgrade. I’d guess it had probably been at least a month or two since I’d last upgraded.
Additional Details
Error
Failed to create or lookup user: ERROR: duplicate key value violates unique constraint "idx_category_users_user_id_category_id"
DETAIL: Key (user_id, category_id)=(36, 6) already exists.
. add_groups: CORPBLUEP,2GTHRAllianceMember,2GTHRALL,2GTHRHighCouncil,2GTHRCorpDirector,2GTHROfficer,DoWCitadelGunner,HCDIM,CORPDIRBLUEP,2GTHRCorpRecruiter,CORPDIRLAWNS,CORPDIR123HC,GRoLLake,DoWCapital,DoWFax,User,CORPHRBLUEP,2GTHRDiscourse
admin:
moderator:
avatar_force_update:
avatar_url: http://image.eveonline.com/Character/740426190_128.jpg
bio:
card_background_url:
email: something@somewhere.com
external_id: 740426190
groups:
locale:
locale_force_update:
name: Mindframe
nonce: e6f9da9e62b720a1efd97348ca20f101
profile_background_url:
remove_groups: Superuser,SPRKYAllianceMember,DoWFieldMarshall,DoWScoutCoordinator,DoWFCGang,DoWFCAlliance,DoWFCSenior,DoWScout,DoWSuper,DoWTitan,DoWFC,2GTHRCorpCEO,DoWTitanBridging,DoLLogisticsSov,DoLLogisticsShipping,HCDoW,HCDoL,HCDoC,HCDoF,DoCDoIT,DoCTechnoMage,DoCDiplomat,DoCDepartmentLead,DoCRecruiterPilots,DoCRecruiterCorporations,DoCDiplomatLead,DoWBLOP,ViewGroups,CORPAIEU,CORPDIRAIEU,CORPZBMC,CORPC.R.Y,CORP123HC,CORPALTBH,CORPLAWNS,CORPDIRZBMC,CORPDIRC.R.Y,CORPDIRALTBH,CORPF3R4L,CORPDIRF3R4L,CORPSPRKY,CORPDIRSPRKY,CORPRMKR,CORPDIRRMKR,CORPHR123HC,CORPHRAIEU,CORPHRZBMC,CORPHRC.R.Y,CORPHRF3R4L,SPRKYDiscourse,CORPHRLAWNS,CORPDIROUSYN,CORPHROUSYN,CORPOUSYN,DoWReimbursementTeam,DoWCarrier,DoWDread,WCMember,WCALL,WCMindframesMarketVisitors
require_activation:
return_sso_url:
suppress_welcome_message:
title:
username: Mindframe
website: /var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-mini-profiler-1.0.2/lib/patches/db/pg.rb:110:in `async_exec'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-mini-profiler-1.0.2/lib/patches/db/pg.rb:110:in `async_exec'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/mini_sql-0.2.2/lib/mini_sql/postgres/connection.rb:118:in `run'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/mini_sql-0.2.2/lib/mini_sql/postgres/connection.rb:90:in `exec'
/var/www/discourse/app/models/user.rb:1403:in `set_default_categories_preferences'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.3/lib/active_support/callbacks.rb:426:in `block in make_lambda'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.3/lib/active_support/callbacks.rb:236:in `block in halting_and_conditional'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.3/lib/active_support/callbacks.rb:517:in `block in invoke_after'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.3/lib/active_support/callbacks.rb:517:in `each'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.3/lib/active_support/callbacks.rb:517:in `invoke_after'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.3/lib/active_support/callbacks.rb:133:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.3/lib/active_support/callbacks.rb:816:in `_run_create_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/callbacks.rb:346:in `_create_record'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/timestamp.rb:102:in `_create_record'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/persistence.rb:705:in `create_or_update'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/callbacks.rb:342:in `block in create_or_update'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.3/lib/active_support/callbacks.rb:132:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.3/lib/active_support/callbacks.rb:816:in `_run_save_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/callbacks.rb:342:in `create_or_update'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/persistence.rb:308:in `save!'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/validations.rb:52:in `save!'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/transactions.rb:315:in `block in save!'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/transactions.rb:387:in `block in with_transaction_returning_status'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/database_statements.rb:267:in `block in transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/transaction.rb:239:in `block in within_new_transaction'
/usr/local/lib/ruby/2.6.0/monitor.rb:230:in `mon_synchronize'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/transaction.rb:236:in `within_new_transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/database_statements.rb:267:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/transactions.rb:212:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/transactions.rb:385:in `with_transaction_returning_status'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/transactions.rb:315:in `save!'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/suppressor.rb:48:in `save!'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/persistence.rb:53:in `create!'
/var/www/discourse/app/models/discourse_single_sign_on.rb:203:in `block in match_email_or_create_user'
/var/www/discourse/lib/distributed_mutex.rb:31:in `block in synchronize'
/var/www/discourse/lib/distributed_mutex.rb:27:in `synchronize'
/var/www/discourse/lib/distributed_mutex.rb:27:in `synchronize'
/var/www/discourse/lib/distributed_mutex.rb:12:in `synchronize'
/var/www/discourse/app/models/discourse_single_sign_on.rb:186:in `match_email_or_create_user'
/var/www/discourse/app/models/discourse_single_sign_on.rb:74:in `lookup_or_create_user'
/var/www/discourse/app/controllers/session_controller.rb:169:in `sso_login'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/abstract_controller/base.rb:194:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_controller/metal/rendering.rb:30:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.3/lib/active_support/callbacks.rb:132:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/abstract_controller/callbacks.rb:41:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_controller/metal/rescue.rb:22:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.3/lib/active_support/notifications.rb:168:in `block in instrument'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.3/lib/active_support/notifications/instrumenter.rb:23:in `instrument'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.3/lib/active_support/notifications.rb:168:in `instrument'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_controller/metal/instrumentation.rb:32:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_controller/metal/params_wrapper.rb:256:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/railties/controller_runtime.rb:24:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/abstract_controller/base.rb:134:in `process'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionview-5.2.3/lib/action_view/rendering.rb:32:in `process'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-mini-profiler-1.0.2/lib/mini_profiler/profiling_methods.rb:78:in `block in profile_method'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_controller/metal.rb:191:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_controller/metal.rb:252:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/routing/route_set.rb:52:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/routing/route_set.rb:34:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/journey/router.rb:52:in `block in serve'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/journey/router.rb:35:in `each'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/journey/router.rb:35:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/routing/route_set.rb:840:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-protection-2.0.7/lib/rack/protection/frame_options.rb:31:in `call'
/var/www/discourse/lib/middleware/omniauth_bypass_middleware.rb:68:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/tempfile_reaper.rb:15:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/conditional_get.rb:25:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/head.rb:12:in `call'
/var/www/discourse/lib/content_security_policy/middleware.rb:12:in `call'
/var/www/discourse/lib/middleware/anonymous_cache.rb:219:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/session/abstract/id.rb:232:in `context'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/session/abstract/id.rb:226:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/cookies.rb:670:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.3/lib/active_support/callbacks.rb:98:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/debug_exceptions.rb:61:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/logster-2.3.2/lib/logster/middleware/reporter.rb:43:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/railties-5.2.3/lib/rails/rack/logger.rb:38:in `call_app'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/railties-5.2.3/lib/rails/rack/logger.rb:28:in `call'
/var/www/discourse/config/initializers/100-quiet_logger.rb:18:in `call'
/var/www/discourse/config/initializers/100-silence_logger.rb:31:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/request_id.rb:27:in `call'
/var/www/discourse/lib/middleware/enforce_hostname.rb:17:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/method_override.rb:22:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.3/lib/action_dispatch/middleware/executor.rb:14:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/sendfile.rb:111:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-mini-profiler-1.0.2/lib/mini_profiler/profiler.rb:171:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/message_bus-2.2.2/lib/message_bus/rack/middleware.rb:57:in `call'
/var/www/discourse/lib/middleware/request_tracker.rb:169:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/railties-5.2.3/lib/rails/engine.rb:524:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/railties-5.2.3/lib/rails/railtie.rb:190:in `public_send'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/railties-5.2.3/lib/rails/railtie.rb:190:in `method_missing'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/urlmap.rb:68:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/urlmap.rb:53:in `each'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/urlmap.rb:53:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.1/lib/unicorn/http_server.rb:605:in `process_client'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.1/lib/unicorn/http_server.rb:700:in `worker_loop'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.1/lib/unicorn/http_server.rb:548:in `spawn_missing_workers'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.1/lib/unicorn/http_server.rb:144:in `start'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.1/bin/unicorn:128:in `<top (required)>'
/var/www/discourse/vendor/bundle/ruby/2.6.0/bin/unicorn:23:in `load'
/var/www/discourse/vendor/bundle/ruby/2.6.0/bin/unicorn:23:in `<main>'