2FA fails with 500 on POST of the one-time-password after Geo DR promoting secondary to primary

Summary

2FA_failure_after_Geo_DR

Steps to reproduce

  • Setup Geo
  • Setup 2FA for a user
  • Follow https://docs.gitlab.com/ee/gitlab-geo/disaster-recovery.html#promoting-a-secondary-node
  • Attempt to log in to user with 2FA
  • See 500

What is the current bug behavior?

500 error

What is the expected correct behavior?

Logged in as usual.

Relevant logs and/or screenshots


==> /var/log/gitlab/gitlab-rails/production.log <==
Started GET "/users/sign_in" for 104.220.128.59 at 2017-12-19 18:07:30 +0000
Processing by SessionsController#new as HTML
Completed 200 OK in 22ms (Views: 11.2ms | ActiveRecord: 1.0ms | Elasticsearch: 0.0ms)

==> /var/log/gitlab/gitlab-rails/production_json.log <==
{"method":"GET","path":"/users/sign_in","format":"html","controller":"SessionsController","action":"new","status":200,"duration":23.03,"view":11.2,"db":1.02,"time":"2017-12-19T18:07:30.908Z","params":{},"remote_ip":"104.220.128.59","user_id":null,"username":null}

==> /var/log/gitlab/gitlab-workhorse/current <==
2017-12-19_18:07:30.93298 mike-demo-1.gogitlab.com @ - - [2017-12-19 18:07:30.900099961 +0000 UTC] "GET /users/sign_in HTTP/1.1" 200 10312 "" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.84 Safari/537.36" 0.032803

==> /var/log/gitlab/nginx/gitlab_access.log <==
104.220.128.59 - - [19/Dec/2017:18:07:30 +0000] "GET /users/sign_in HTTP/1.1" 200 3992 "" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.84 Safari/537.36"
   
==> /var/log/gitlab/gitlab-monitor/current <==
2017-12-19_18:07:36.65269 Passing 'script' command to redis as is; administrative commands cannot be effectively namespaced and should be called on the redis connection directly; passthrough has been deprecated and will be removed in redis-namespace 2.0 (at /opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/gitlab-monitor-1.9.0/lib/gitlab_monitor/sidekiq.rb:127:in `block in ensure_queue_job_stats_script_loaded')
2017-12-19_18:07:36.67754 127.0.0.1 - - [19/Dec/2017:18:07:36 UTC] "GET /sidekiq HTTP/1.1" 200 5990
2017-12-19_18:07:36.67769 - -> /sidekiq

==> /var/log/gitlab/sidekiq/current <==
2017-12-19_18:07:37.30102 127.0.0.1 - - [19/Dec/2017:18:07:37 UTC] "GET /metrics HTTP/1.1" 200 25
2017-12-19_18:07:37.30117 - -> /metrics

==> /var/log/gitlab/gitlab-monitor/current <==
2017-12-19_18:07:38.62992 127.0.0.1 - - [19/Dec/2017:18:07:38 UTC] "GET /database HTTP/1.1" 200 68955
2017-12-19_18:07:38.63007 - -> /database
2017-12-19_18:07:40.85290 127.0.0.1 - - [19/Dec/2017:18:07:40 UTC] "GET /process HTTP/1.1" 200 1178
2017-12-19_18:07:40.85331 - -> /process

==> /var/log/gitlab/gitlab-rails/production.log <==
Started POST "/users/sign_in" for 104.220.128.59 at 2017-12-19 18:07:41 +0000
Processing by SessionsController#create as HTML
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"[FILTERED]", "user"=>{"login"=>"mkozono", "password"=>"[FILTERED]", "remember_me"=>"0"}}
Filter chain halted as :authenticate_with_two_factor rendered or redirected
Completed 200 OK in 83ms (Views: 10.1ms | ActiveRecord: 1.6ms | Elasticsearch: 0.0ms)

==> /var/log/gitlab/gitlab-rails/production_json.log <==
{"method":"POST","path":"/users/sign_in","format":"html","controller":"SessionsController","action":"create","status":200,"duration":84.07,"view":10.11,"db":1.65,"time":"2017-12-19T18:07:41.353Z","params":{"utf8":"✓","authenticity_token":"[FILTERED]","user":{"login":"mkozono","password":"[FILTERED]","remember_me":"0"}},"remote_ip":"104.220.128.59","user_id":null,"username":null}

==> /var/log/gitlab/gitlab-workhorse/current <==
2017-12-19_18:07:41.43866 mike-demo-1.gogitlab.com @ - - [2017-12-19 18:07:41.345167778 +0000 UTC] "POST /users/sign_in HTTP/1.1" 200 6433 "http://mike-demo-1.gogitlab.com/users/sign_in" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.84 Safari/537.36" 0.093407

==> /var/log/gitlab/nginx/gitlab_access.log <==
104.220.128.59 - - [19/Dec/2017:18:07:41 +0000] "POST /users/sign_in HTTP/1.1" 200 2821 "http://mike-demo-1.gogitlab.com/users/sign_in" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.84 Safari/537.36"

==> /var/log/gitlab/gitlab-rails/production.log <==
Started POST "/users/sign_in" for 104.220.128.59 at 2017-12-19 18:07:43 +0000
Processing by SessionsController#create as HTML
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"[FILTERED]", "user"=>{"remember_me"=>"0", "otp_attempt"=>"[FILTERED]"}}
Completed 500 Internal Server Error in 7ms (ActiveRecord: 0.7ms | Elasticsearch: 0.0ms)

==> /var/log/gitlab/gitlab-rails/production_json.log <==
{"method":"POST","path":"/users/sign_in","format":"html","controller":"SessionsController","action":"create","status":500,"error":"OpenSSL::Cipher::CipherError: bad decrypt","duration":7.74,"view":0.0,"db":0.74,"time":"2017-12-19T18:07:43.280Z","params":{"utf8":"✓","authenticity_token":"[FILTERED]","user":{"remember_me":"0","otp_attempt":"[FILTERED]"}},"remote_ip":"104.220.128.59","user_id":null,"username":null}

==> /var/log/gitlab/gitlab-rails/production.log <==

OpenSSL::Cipher::CipherError (bad decrypt):
  app/controllers/sessions_controller.rb:141:in `valid_otp_attempt?'
  app/controllers/concerns/authenticates_with_two_factor.rb:54:in `authenticate_with_two_factor_via_otp'
  app/controllers/concerns/authenticates_with_two_factor.rb:43:in `authenticate_with_two_factor'
  lib/gitlab/middleware/multipart.rb:93:in `call'
  lib/gitlab/request_profiler/middleware.rb:14:in `call'
  lib/gitlab/jira/middleware.rb:15:in `call'
  lib/gitlab/middleware/go.rb:18:in `call'
  lib/gitlab/etag_caching/middleware.rb:11:in `call'
  lib/gitlab/middleware/read_only.rb:31:in `call'
  lib/gitlab/request_context.rb:18:in `call'
  lib/gitlab/metrics/requests_rack_middleware.rb:27:in `call'



==> /var/log/gitlab/gitlab-workhorse/current <==
2017-12-19_18:07:43.28967 mike-demo-1.gogitlab.com @ - - [2017-12-19 18:07:43.271167838 +0000 UTC] "POST /users/sign_in HTTP/1.1" 500 2902 "http://mike-demo-1.gogitlab.com/users/sign_in" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.84 Safari/537.36" 0.018418

==> /var/log/gitlab/nginx/gitlab_access.log <==
104.220.128.59 - - [19/Dec/2017:18:07:43 +0000] "POST /users/sign_in HTTP/1.1" 500 2902 "http://mike-demo-1.gogitlab.com/users/sign_in" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.84 Safari/537.36"
Assignee Loading
Time tracking Loading