Error 500 or 422 after enabling 2FA on existing user

giuseppe4 · December 3, 2023, 1:35am

Hello,

I’m experiencing a blocking issue with my Zammad self hosted installation.

I’ve also opened a GitHub Issue (#4963).

Could you please help me?

Thanks

Infos

Used Zammad Version

6.1

Environment

Installation method: package
Operating system: "Ubuntu 22.04.3 LTS
Database + version: psql (PostgreSQL) 14.9 (Ubuntu 14.9-0ubuntu0.22.04.1)
Elasticsearch version: 7.17.15
Browser + version: Microsoft Edge 119.0.2151.72

Actual behaviour

After enabling 2FA for one user, I cannot access to Zammad anymore, even to the home page.
Zammad is completely unusable.

It reports error 500 or error 422 (422 from private browsing session, 500 from the same browser session as used to enable 2FA).

It seems the problem is a null value in column id for “sessions”:

E, [2023-12-01T19:12:20.459410#169375-64880] ERROR -- : PG::NotNullViolation: ERROR:  null value in column "id" of relation "sessions" violates not-null constraint
DETAIL:  Failing row contains (null, 2::778cabff37e22e99114660535a597c2ff154a135c4cce9f0cd43541dc7d11..., null, BAh7AA==
, 2023-12-01 18:12:20.456792+00, 2023-12-01 18:12:20.456792+00).
 (ActiveRecord::NotNullViolation)

This is production.log:

I, [2023-12-01T19:12:15.434075#169375-64660]  INFO -- : Started GET "/" for XXX.XXX.XXX.XXX at 2023-12-01 19:12:15 +0100
F, [2023-12-01T19:12:15.452594#169375-64660] FATAL -- :   
[e408af47-4875-40c5-9262-796d406cc543] ActiveRecord::NotNullViolation (PG::NotNullViolation: ERROR:  null value in column "id" of relation "sessions" violates not-null constraint
DETAIL:  Failing row contains (null, 2::5c010b5205c4147277150dc31323526d3e8d19e9a93d396f1b3fd196c324a..., null, BAh7AA==
, 2023-12-01 18:12:15.450561+00, 2023-12-01 18:12:15.450561+00).
):
[e408af47-4875-40c5-9262-796d406cc543]   
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/connection_adapters/postgresql_adapter.rb:672:in `exec_params'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/connection_adapters/postgresql_adapter.rb:672:in `block (2 levels) in exec_no_cache'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/dependencies/interlock.rb:48:in `block in permit_concurrent_loads'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/dependencies/interlock.rb:47:in `permit_concurrent_loads'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/connection_adapters/postgresql_adapter.rb:671:in `block in exec_no_cache'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/connection_adapters/abstract_adapter.rb:696:in `block (2 levels) in log'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/connection_adapters/abstract_adapter.rb:695:in `block in log'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/notifications/instrumenter.rb:24:in `instrument'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/connection_adapters/abstract_adapter.rb:687:in `log'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/connection_adapters/postgresql_adapter.rb:670:in `exec_no_cache'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/connection_adapters/postgresql_adapter.rb:649:in `execute_and_clear'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/connection_adapters/postgresql/database_statements.rb:55:in `exec_query'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/connection_adapters/abstract/database_statements.rb:136:in `exec_insert'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/connection_adapters/postgresql/database_statements.rb:93:in `exec_insert'
[e408af47-4875-40c5-9262-796d406cc543] composite_primary_keys (13.0.7) lib/composite_primary_keys/connection_adapters/abstract/database_statements.rb:6:in `insert'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/connection_adapters/abstract/query_cache.rb:22:in `insert'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/persistence.rb:375:in `_insert_record'
[e408af47-4875-40c5-9262-796d406cc543] composite_primary_keys (13.0.7) lib/composite_primary_keys/persistence.rb:64:in `_create_record'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/counter_cache.rb:166:in `_create_record'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/locking/optimistic.rb:79:in `_create_record'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/attribute_methods/dirty.rb:201:in `_create_record'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/callbacks.rb:461:in `block in _create_record'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/callbacks.rb:106:in `run_callbacks'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/callbacks.rb:824:in `_run_create_callbacks'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/callbacks.rb:461:in `_create_record'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/timestamp.rb:108:in `_create_record'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/persistence.rb:900:in `create_or_update'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/callbacks.rb:457:in `block in create_or_update'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/callbacks.rb:106:in `run_callbacks'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/callbacks.rb:824:in `_run_save_callbacks'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/callbacks.rb:457:in `create_or_update'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/timestamp.rb:126:in `create_or_update'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/persistence.rb:474:in `save'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/validations.rb:47:in `save'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/transactions.rb:298:in `block in save'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/transactions.rb:354:in `block in with_transaction_returning_status'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/connection_adapters/abstract/database_statements.rb:320:in `block in transaction'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/connection_adapters/abstract/transaction.rb:319:in `block in within_new_transaction'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/connection_adapters/abstract/transaction.rb:317:in `within_new_transaction'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/connection_adapters/abstract/database_statements.rb:320:in `transaction'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/transactions.rb:350:in `with_transaction_returning_status'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/transactions.rb:298:in `save'
[e408af47-4875-40c5-9262-796d406cc543] activerecord (6.1.7.6) lib/active_record/suppressor.rb:44:in `save'
[e408af47-4875-40c5-9262-796d406cc543] activerecord-session_store (2.0.0) lib/action_dispatch/session/active_record_store.rb:124:in `block in get_session_model'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/logger_silence.rb:18:in `block in silence'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/logger_thread_safe_level.rb:52:in `log_at'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/logger_silence.rb:18:in `silence'
[e408af47-4875-40c5-9262-796d406cc543] activerecord-session_store (2.0.0) lib/action_dispatch/session/active_record_store.rb:119:in `get_session_model'
[e408af47-4875-40c5-9262-796d406cc543] activerecord-session_store (2.0.0) lib/action_dispatch/session/active_record_store.rb:147:in `find_session'
[e408af47-4875-40c5-9262-796d406cc543] rack (2.2.8) lib/rack/session/abstract/id.rb:314:in `load_session'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/middleware/session/abstract_store.rb:45:in `block in load_session'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/middleware/session/abstract_store.rb:53:in `stale_session_check!'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/middleware/session/abstract_store.rb:45:in `load_session'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/request/session.rb:234:in `load!'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/request/session.rb:226:in `load_for_read!'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/request/session.rb:92:in `[]'
[e408af47-4875-40c5-9262-796d406cc543] omniauth-twitter (1.4.0) lib/omniauth/strategies/twitter.rb:75:in `callback_path'
[e408af47-4875-40c5-9262-796d406cc543] omniauth (2.1.1) lib/omniauth/strategy.rb:290:in `on_callback_path?'
[e408af47-4875-40c5-9262-796d406cc543] omniauth (2.1.1) lib/omniauth/strategy.rb:278:in `on_auth_path?'
[e408af47-4875-40c5-9262-796d406cc543] omniauth (2.1.1) lib/omniauth/strategy.rb:187:in `call!'
[e408af47-4875-40c5-9262-796d406cc543] omniauth (2.1.1) lib/omniauth/strategy.rb:169:in `call'
[e408af47-4875-40c5-9262-796d406cc543] omniauth (2.1.1) lib/omniauth/builder.rb:44:in `call'
[e408af47-4875-40c5-9262-796d406cc543] rack-attack (6.7.0) lib/rack/attack.rb:127:in `call'
[e408af47-4875-40c5-9262-796d406cc543] rack (2.2.8) lib/rack/tempfile_reaper.rb:15:in `call'
[e408af47-4875-40c5-9262-796d406cc543] rack (2.2.8) lib/rack/etag.rb:27:in `call'
[e408af47-4875-40c5-9262-796d406cc543] rack (2.2.8) lib/rack/conditional_get.rb:27:in `call'
[e408af47-4875-40c5-9262-796d406cc543] rack (2.2.8) lib/rack/head.rb:12:in `call'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/http/permissions_policy.rb:22:in `call'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/http/content_security_policy.rb:19:in `call'
[e408af47-4875-40c5-9262-796d406cc543] rack (2.2.8) lib/rack/session/abstract/id.rb:266:in `context'
[e408af47-4875-40c5-9262-796d406cc543] rack (2.2.8) lib/rack/session/abstract/id.rb:260:in `call'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/middleware/cookies.rb:697:in `call'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/callbacks.rb:98:in `run_callbacks'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/middleware/callbacks.rb:26:in `call'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/middleware/actionable_exceptions.rb:18:in `call'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/middleware/debug_exceptions.rb:29:in `call'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
[e408af47-4875-40c5-9262-796d406cc543] railties (6.1.7.6) lib/rails/rack/logger.rb:37:in `call_app'
[e408af47-4875-40c5-9262-796d406cc543] railties (6.1.7.6) lib/rails/rack/logger.rb:26:in `block in call'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/tagged_logging.rb:99:in `block in tagged'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/tagged_logging.rb:37:in `tagged'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/tagged_logging.rb:99:in `tagged'
[e408af47-4875-40c5-9262-796d406cc543] railties (6.1.7.6) lib/rails/rack/logger.rb:26:in `call'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/middleware/request_id.rb:26:in `call'
[e408af47-4875-40c5-9262-796d406cc543] rack (2.2.8) lib/rack/method_override.rb:24:in `call'
[e408af47-4875-40c5-9262-796d406cc543] rack (2.2.8) lib/rack/runtime.rb:22:in `call'
[e408af47-4875-40c5-9262-796d406cc543] activesupport (6.1.7.6) lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/middleware/executor.rb:14:in `call'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/middleware/static.rb:24:in `call'
[e408af47-4875-40c5-9262-796d406cc543] rack (2.2.8) lib/rack/sendfile.rb:110:in `call'
[e408af47-4875-40c5-9262-796d406cc543] actionpack (6.1.7.6) lib/action_dispatch/middleware/host_authorization.rb:142:in `call'
[e408af47-4875-40c5-9262-796d406cc543] railties (6.1.7.6) lib/rails/engine.rb:539:in `call'
[e408af47-4875-40c5-9262-796d406cc543] railties (6.1.7.6) lib/rails/railtie.rb:207:in `public_send'
[e408af47-4875-40c5-9262-796d406cc543] railties (6.1.7.6) lib/rails/railtie.rb:207:in `method_missing'
[e408af47-4875-40c5-9262-796d406cc543] puma (6.3.1) lib/puma/configuration.rb:270:in `call'
[e408af47-4875-40c5-9262-796d406cc543] puma (6.3.1) lib/puma/request.rb:100:in `block in handle_request'
[e408af47-4875-40c5-9262-796d406cc543] puma (6.3.1) lib/puma/thread_pool.rb:344:in `with_force_shutdown'
[e408af47-4875-40c5-9262-796d406cc543] puma (6.3.1) lib/puma/request.rb:99:in `handle_request'
[e408af47-4875-40c5-9262-796d406cc543] puma (6.3.1) lib/puma/server.rb:443:in `process_client'
[e408af47-4875-40c5-9262-796d406cc543] puma (6.3.1) lib/puma/server.rb:245:in `block in run'
[e408af47-4875-40c5-9262-796d406cc543] puma (6.3.1) lib/puma/thread_pool.rb:151:in `block in spawn_thread'
I, [2023-12-01T19:12:15.532539#169388-5580]  INFO -- : Cleanup of left over locked delayed jobs 2023-12-01 18:12:15 UTC started.
I, [2023-12-01T19:12:15.533208#169388-64700]  INFO -- : ProcessScheduledJobs running...
I, [2023-12-01T19:12:15.546445#169388-5580]  INFO -- : Cleanup of left over locked delayed jobs 2023-12-01 18:12:15 UTC finished.
I, [2023-12-01T19:12:15.546596#169388-5580]  INFO -- : Cleanup of left over import jobs 2023-12-01 18:12:15 UTC started.
I, [2023-12-01T19:12:15.548330#169388-5580]  INFO -- : Cleanup of left over import jobs 2023-12-01 18:12:15 UTC finished.
I, [2023-12-01T19:12:15.562606#169388-64880]  INFO -- : execute Channel.stream (try_count 0)...
I, [2023-12-01T19:12:16.564151#169388-65040]  INFO -- : execute Sessions.jobs (try_count 0)...
I, [2023-12-01T19:12:20.439034#169375-64880]  INFO -- : Started GET "/" for 185.152.44.238 at 2023-12-01 19:12:20 +0100
I, [2023-12-01T19:12:20.443969#169375-64880]  INFO -- : Processing by InitController#index as HTML
E, [2023-12-01T19:12:20.459410#169375-64880] ERROR -- : PG::NotNullViolation: ERROR:  null value in column "id" of relation "sessions" violates not-null constraint
DETAIL:  Failing row contains (null, 2::778cabff37e22e99114660535a597c2ff154a135c4cce9f0cd43541dc7d11..., null, BAh7AA==
, 2023-12-01 18:12:20.456792+00, 2023-12-01 18:12:20.456792+00).
 (ActiveRecord::NotNullViolation)
app/controllers/application_controller/has_user.rb:74:in `session_update'
app/controllers/application_controller/handles_transitions.rb:16:in `handle_transaction'
I, [2023-12-01T19:12:20.462802#169375-64880]  INFO -- :   Rendered inline template (Duration: 0.6ms | Allocations: 391)
I, [2023-12-01T19:12:20.463108#169375-64880]  INFO -- : Completed 422 Unprocessable Entity in 19ms (Views: 2.0ms | ActiveRecord: 4.4ms | Allocations: 6738)

Expected behaviour

After enabling 2FA for one user, I should access to Zammad without any issue or error.

Steps to reproduce the behaviour

Upgrade to 6.1
Migrate from MySQL to PostgreSQL
Access to users 2FA settings
Set the group admin and agent to enable 2FA
Login with an user on that groups
Enable 2FA with Authenticator app
You cannot access anymore

MrGeneration · December 3, 2023, 12:28pm

Please don’t bump topics. Opening issue and thread on this community most likely is not going to speed up things or help you. It most likely keeps people busy twice the time one topic might have done.

Please be patient, as difficult it is in your situation.

If you cannot wait and require business grade support, consider a support contract or migration to hosted. This is the fastest way to get help. I’m not trying to force you into any direction, just want to give you all current options.

giuseppe4 · December 3, 2023, 1:15pm

I’m sorry, I didn’t consider GitHub issues and community were “linked”.
I’ll wait for some help.

If you have any hint, I’m here

system · November 27, 2024, 1:16pm

This topic was automatically closed 360 days after the last reply. New replies are no longer allowed.