Sidekiq jobs are failing for 1 of my users

For some reason one of my users appears to be bugged. He cannot view the forums due to a 500 Internal Error and all of the pending Sidekiq jobs for him also fail. Here’s an example of one of the failing Sidekiq jobs:

Jobs::UserEmail

{"type"=>"digest", "user_id"=>3530, "current_site_id"=>"default"}

Jobs::HandledExceptionWrapper: Wrapped NoMethodError: undefined method 'bounce_score' for nil:NilClass

In all instances the logs indicate the problem with his account is due to undefined method 'bounce_score' for nil:NilClass except with a different undefined method depending on which database object was trying to be accessed. For example his 500 Internal Error viewing the main page is generated by:

Processing by ListController#latest as HTML
Completed 500 Internal Server Error in 30ms (ActiveRecord: 13.1ms)
NoMethodError (undefined method 'topic_reply_count' for nil:NilClass)
/var/www/discourse/app/serializers/current_user_serializer.rb:51:in 'reply_count'
Job exception: undefined method 'days_visited' for nil:NilClass

I’ve checked the records in the database and they exist. Is the Redis cache somehow corrupted? I’m running the latest version of Discourse (I just upgraded to latest commit) and it didn’t resolve these problems.

Lastly I can’t do a search for users through my admin panel anymore due to a similar error:

Started GET "/admin/users/list/regular.json?_=1474829263900" for **** at 2016-09-25 19:03:37 +0000
Processing by Admin::UsersController#index as JSON
  Parameters: {"_"=>"1474829263900", "query"=>"regular"}
Completed 500 Internal Server Error in 22ms (ActiveRecord: 6.0ms)
NoMethodError (undefined method `time_read' for nil:NilClass)
/var/www/discourse/app/serializers/admin_user_list_serializer.rb:72:in `time_read'

Hmm, perhaps @zogstrip would know as that relates to email bounces for that user.

Nah, isn’t directly mail related, as other undefined methods include topic_reply_count, days_visited, and time_read. The problem is that the entire object just isn’t being instantiated.

@corillian, are you able to visit the /logs endpoint on your site, and pull out a complete backtrace of one or more of the exceptions? That’ll give a much better picture of how exactly the problem is happening. The rails logs, unfortunately, aren’t polite enough to include a backtrace.

2 Likes

Here’s the email error with 12181 occurences:

Job exception: undefined method `bounce_score' for nil:NilClass
/var/www/discourse/app/jobs/regular/user_email.rb:137:in `message_for_email'
/var/www/discourse/app/jobs/regular/user_email.rb:31:in `execute'
/var/www/discourse/app/jobs/base.rb:154:in `block (2 levels) in perform'

and another with 207 occurences:

NoMethodError (undefined method `topic_reply_count' for nil:NilClass) 
/var/www/discourse/app/serializers/current_user_serializer.rb:51:in `reply_count'
(eval):16:in `_fast_attributes'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/active_model_serializers-0.8.3/lib/active_model/serializer.rb:467:in `rescue in attributes'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/active_model_serializers-0.8.3/lib/active_model/serializer.rb:455:in `attributes'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/active_model_serializers-0.8.3/lib/active_model/serializer.rb:479:in `_serializable_hash'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/active_model_serializers-0.8.3/lib/active_model/serializer.rb:361:in `serializable_hash'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/active_model_serializers-0.8.3/lib/active_model/serializer.rb:349:in `as_json'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/multi_json-1.12.1/lib/multi_json/adapters/oj.rb:21:in `dump'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/multi_json-1.12.1/lib/multi_json/adapters/oj.rb:21:in `dump'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/multi_json-1.12.1/lib/multi_json/adapter.rb:25:in `dump'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/multi_json-1.12.1/lib/multi_json.rb:139:in `dump'
/var/www/discourse/app/controllers/application_controller.rb:361:in `preload_current_user_data'
/var/www/discourse/app/controllers/application_controller.rb:217:in `preload_json'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:432:in `block in make_lambda'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:164:in `block in halting'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:504:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:504:in `each'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:504:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:92:in `__run_callbacks__'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:778:in `_run_process_action_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:81:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/abstract_controller/callbacks.rb:19:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_controller/metal/rescue.rb:29:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7/lib/active_support/notifications.rb:164:in `block in instrument'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7/lib/active_support/notifications.rb:164:in `instrument'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_controller/metal/params_wrapper.rb:250:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activerecord-4.2.7/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/abstract_controller/base.rb:137:in `process'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionview-4.2.7/lib/action_view/rendering.rb:30:in `process'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-mini-profiler-0.10.1/lib/mini_profiler/profiling_methods.rb:76:in `block in profile_method'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_controller/metal.rb:196:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_controller/metal/rack_delegation.rb:13:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_controller/metal.rb:237:in `block in action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_dispatch/routing/route_set.rb:74:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_dispatch/routing/route_set.rb:43:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_dispatch/routing/mapper.rb:49:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_dispatch/journey/router.rb:43:in `block in serve'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_dispatch/journey/router.rb:30:in `each'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_dispatch/journey/router.rb:30:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_dispatch/routing/route_set.rb:817:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-protection-1.5.3/lib/rack/protection/frame_options.rb:31:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/builder.rb:63:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/conditionalget.rb:25:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/head.rb:13:in `call'
/var/www/discourse/lib/middleware/anonymous_cache.rb:129:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_dispatch/middleware/params_parser.rb:27:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_dispatch/middleware/flash.rb:260:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/session/abstract/id.rb:225:in `context'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/session/abstract/id.rb:220:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_dispatch/middleware/cookies.rb:560:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activerecord-4.2.7/lib/active_record/query_cache.rb:36:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activerecord-4.2.7/lib/active_record/connection_adapters/abstract/connection_pool.rb:653:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_dispatch/middleware/callbacks.rb:29:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:88:in `__run_callbacks__'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:778:in `_run_call_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:81:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_dispatch/middleware/callbacks.rb:27:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_dispatch/middleware/remote_ip.rb:78:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_dispatch/middleware/show_exceptions.rb:30:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/logster-1.2.5/lib/logster/middleware/reporter.rb:31:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/railties-4.2.7/lib/rails/rack/logger.rb:38:in `call_app'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/railties-4.2.7/lib/rails/rack/logger.rb:22:in `call'
/var/www/discourse/config/initializers/100-quiet_logger.rb:13:in `call_with_quiet_assets'
/var/www/discourse/config/initializers/100-silence_logger.rb:26:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7/lib/action_dispatch/middleware/request_id.rb:21:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/methodoverride.rb:22:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/runtime.rb:18:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/sendfile.rb:113:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-mini-profiler-0.10.1/lib/mini_profiler/profiler.rb:171:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/message_bus-2.0.1/lib/message_bus/rack/middleware.rb:62:in `call'
/var/www/discourse/lib/middleware/request_tracker.rb:73:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/railties-4.2.7/lib/rails/engine.rb:518:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/railties-4.2.7/lib/rails/application.rb:165:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/railties-4.2.7/lib/rails/railtie.rb:194:in `public_send'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/railties-4.2.7/lib/rails/railtie.rb:194:in `method_missing'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/urlmap.rb:66:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/urlmap.rb:50:in `each'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/urlmap.rb:50:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/unicorn-5.1.0/lib/unicorn/http_server.rb:562:in `process_client'
/var/www/discourse/lib/scheduler/defer.rb:85:in `process_client'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/unicorn-5.1.0/lib/unicorn/http_server.rb:658:in `worker_loop'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/unicorn-5.1.0/lib/unicorn/http_server.rb:508:in `spawn_missing_workers'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/unicorn-5.1.0/lib/unicorn/http_server.rb:132:in `start'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/unicorn-5.1.0/bin/unicorn:126:in `<top (required)>'
/var/www/discourse/vendor/bundle/ruby/2.3.0/bin/unicorn:23:in `load'
/var/www/discourse/vendor/bundle/ruby/2.3.0/bin/unicorn:23:in `<main>'

and another with 100 occurences:

Job exception: undefined method `days_visited' for nil:NilClass
/var/www/discourse/app/models/user.rb:430:in `create_visit_record!'
/var/www/discourse/app/models/user.rb:439:in `update_visit_record!'
/var/www/discourse/app/models/user.rb:1002:in `update_previous_visit'
/var/www/discourse/app/models/user.rb:477:in `update_last_seen!'
/var/www/discourse/lib/auth/default_current_user_provider.rb:62:in `block in current_user'
/var/www/discourse/lib/scheduler/defer.rb:68:in `do_work'
/var/www/discourse/lib/scheduler/defer.rb:46:in `do_all_work'
/var/www/discourse/lib/scheduler/defer.rb:86:in `process_client'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/unicorn-5.1.0/lib/unicorn/http_server.rb:658:in `worker_loop'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/unicorn-5.1.0/lib/unicorn/http_server.rb:508:in `spawn_missing_workers'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/unicorn-5.1.0/lib/unicorn/http_server.rb:132:in `start'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/unicorn-5.1.0/bin/unicorn:126:in `<top (required)>'
/var/www/discourse/vendor/bundle/ruby/2.3.0/bin/unicorn:23:in `load'
/var/www/discourse/vendor/bundle/ruby/2.3.0/bin/unicorn:23:in `<main>'

Oh and here’s the error generated when trying to search for a user through the admin panel:

NoMethodError (undefined method `time_read' for nil:NilClass) 
/var/www/discourse/app/serializers/admin_user_list_serializer.rb:72:in `time_read'
(eval):27:in `_fast_attributes'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/active_model_serializers-0.8.3/lib/active_model/serializer.rb:467:in `rescue in attributes'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/active_model_serializers-0.8.3/lib/active_model/serializer.rb:455:in `attributes'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/active_model_serializers-0.8.3/lib/active_model/serializer.rb:479:in `_serializable_hash'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/active_model_serializers-0.8.3/lib/active_model/serializer.rb:361:in `serializable_hash'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/active_model_serializers-0.8.3/lib/active_model/array_serializer.rb:89:in `block in _serializable_array'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/active_model_serializers-0.8.3/lib/active_model/array_serializer.rb:79:in `map'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/active_model_serializers-0.8.3/lib/active_model/array_serializer.rb:79:in `_serializable_array'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/active_model_serializers-0.8.3/lib/active_model/array_serializer.rb:73:in `serializable_array'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/active_model_serializers-0.8.3/lib/active_model/array_serializer.rb:53:in `as_json'
/var/www/discourse/app/controllers/application_controller.rb:260:in `serialize_data'
/var/www/discourse/app/controllers/application_controller.rb:271:in `render_serialized'
/var/www/discourse/app/controllers/admin/users_controller.rb:37:in `index'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_controller/metal/implicit_render.rb:4:in `send_action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/abstract_controller/base.rb:198:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_controller/metal/rendering.rb:10:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/abstract_controller/callbacks.rb:20:in `block in process_action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7.1/lib/active_support/callbacks.rb:117:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7.1/lib/active_support/callbacks.rb:555:in `block (2 levels) in compile'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7.1/lib/active_support/callbacks.rb:505:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7.1/lib/active_support/callbacks.rb:92:in `__run_callbacks__'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7.1/lib/active_support/callbacks.rb:778:in `_run_process_action_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7.1/lib/active_support/callbacks.rb:81:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/abstract_controller/callbacks.rb:19:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_controller/metal/rescue.rb:29:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7.1/lib/active_support/notifications.rb:164:in `block in instrument'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7.1/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7.1/lib/active_support/notifications.rb:164:in `instrument'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_controller/metal/params_wrapper.rb:250:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activerecord-4.2.7.1/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/abstract_controller/base.rb:137:in `process'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionview-4.2.7.1/lib/action_view/rendering.rb:30:in `process'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-mini-profiler-0.10.1/lib/mini_profiler/profiling_methods.rb:102:in `block in profile_method'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_controller/metal.rb:196:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_controller/metal/rack_delegation.rb:13:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_controller/metal.rb:237:in `block in action'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_dispatch/routing/route_set.rb:74:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_dispatch/routing/route_set.rb:43:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_dispatch/routing/mapper.rb:49:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_dispatch/journey/router.rb:43:in `block in serve'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_dispatch/journey/router.rb:30:in `each'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_dispatch/journey/router.rb:30:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_dispatch/routing/route_set.rb:817:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-protection-1.5.3/lib/rack/protection/frame_options.rb:31:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/omniauth-1.3.1/lib/omniauth/builder.rb:63:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/conditionalget.rb:25:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/head.rb:13:in `call'
/var/www/discourse/lib/middleware/anonymous_cache.rb:129:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_dispatch/middleware/params_parser.rb:27:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_dispatch/middleware/flash.rb:260:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/session/abstract/id.rb:225:in `context'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/session/abstract/id.rb:220:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_dispatch/middleware/cookies.rb:560:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activerecord-4.2.7.1/lib/active_record/query_cache.rb:36:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activerecord-4.2.7.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:653:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_dispatch/middleware/callbacks.rb:29:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7.1/lib/active_support/callbacks.rb:88:in `__run_callbacks__'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7.1/lib/active_support/callbacks.rb:778:in `_run_call_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/activesupport-4.2.7.1/lib/active_support/callbacks.rb:81:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_dispatch/middleware/callbacks.rb:27:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_dispatch/middleware/remote_ip.rb:78:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_dispatch/middleware/show_exceptions.rb:30:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/logster-1.2.5/lib/logster/middleware/reporter.rb:31:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/railties-4.2.7.1/lib/rails/rack/logger.rb:38:in `call_app'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/railties-4.2.7.1/lib/rails/rack/logger.rb:22:in `call'
/var/www/discourse/config/initializers/100-quiet_logger.rb:13:in `call_with_quiet_assets'
/var/www/discourse/config/initializers/100-silence_logger.rb:26:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/actionpack-4.2.7.1/lib/action_dispatch/middleware/request_id.rb:21:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/methodoverride.rb:22:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/runtime.rb:18:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/sendfile.rb:113:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-mini-profiler-0.10.1/lib/mini_profiler/profiler.rb:278:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/message_bus-2.0.2/lib/message_bus/rack/middleware.rb:62:in `call'
/var/www/discourse/lib/middleware/request_tracker.rb:73:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/railties-4.2.7.1/lib/rails/engine.rb:518:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/railties-4.2.7.1/lib/rails/application.rb:165:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/railties-4.2.7.1/lib/rails/railtie.rb:194:in `public_send'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/railties-4.2.7.1/lib/rails/railtie.rb:194:in `method_missing'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/urlmap.rb:66:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/urlmap.rb:50:in `each'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-1.6.4/lib/rack/urlmap.rb:50:in `call'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/unicorn-5.1.0/lib/unicorn/http_server.rb:562:in `process_client'
/var/www/discourse/lib/scheduler/defer.rb:85:in `process_client'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/unicorn-5.1.0/lib/unicorn/http_server.rb:658:in `worker_loop'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/unicorn-5.1.0/lib/unicorn/http_server.rb:508:in `spawn_missing_workers'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/unicorn-5.1.0/lib/unicorn/http_server.rb:519:in `maintain_worker_count'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/unicorn-5.1.0/lib/unicorn/http_server.rb:283:in `join'
/var/www/discourse/vendor/bundle/ruby/2.3.0/gems/unicorn-5.1.0/bin/unicorn:126:in `<top (required)>'
/var/www/discourse/vendor/bundle/ruby/2.3.0/bin/unicorn:23:in `load'
/var/www/discourse/vendor/bundle/ruby/2.3.0/bin/unicorn:23:in `<main>'

Looks like this instance has been upgraded a few times and now somehow a bunch of data ins missing in the user summary table or something.

So first step, can you update to latest

cd /var/discourse
git pull
./launcher rebuild app

If still an issue after upgrade

./launcher enter app
rails c
% u = User.find(USER_ID_HERE)
% u.build_user_stat.save

Where USER_ID_HERE is the id of the problem user.

2 Likes

Yeah it’s been around 2-3 years now - since the beta. I just rebuilt/upgraded Discourse to the latest commit this morning so all of the logs I posted are from that version. After entering my app I tried executing the code you provided both on bash and in irb and both gave me errors:

bash:

/var/www/discourse# u = User.find(3530)
bash: syntax error near unexpected token `('

irb:

irb(main):002:0> u = User.find(3530)
NameError: uninitialized constant User
        from (irb):2
        from /usr/local/bin/irb:11:in `<main>'

Where and with what exactly am I supposed to execute those commands?

Sorry, forgot a rails c there, fixed it up :slight_smile:

Ah thank you that worked =). Unfortunately I got another error once I executed u.build_user_stat.save:

ActiveRecord::StatementInvalid: PG::NotNullViolation: ERROR:  null value in colu                      mn "new_since" violates not-null constraint
DETAIL:  Failing row contains (3530, 0, 0, 0, 0, 0, 0, 0, null, null, null, 0, 0                      , 0, null).
: INSERT INTO "user_stats" ("user_id") VALUES (3530) RETURNING "user_id"
from /var/www/discourse/vendor/bundle/ruby/2.3.0/gems/rack-mini-profiler-0.10.1/                      lib/patches/db/pg.rb:90:in `exec'

For what it’s worth I checked user_stats and the user already has an entry in the table. I tried to locate build_user_stat in the Discourse code but I couldn’t find it anywhere?

Ok I found the answer to my question about build_user_stat here: http://stackoverflow.com/questions/783584/ruby-on-rails-how-do-i-use-the-active-record-build-method-in-a-belongs-to-rel

After investigating this some more it does seem that most of the problems are with the user_stat table. What I don’t understand is that this problem is affecting only one user and on top of that he’s had an entry in user_stat the entire time. In fact he was one of my most active users up until Discourse recently decided it had enough of him :stuck_out_tongue:.

What’s more disturbing is that it looks like whatever is causing his user_stat to fail to load is inside of the black box that is the Rails ActiveRecord ORM. This seems to even apply to creating a new entry via your suggested build_user_stat.save. I don’t see any obvious point of conflict in the logic of Discourse code.

I have never seen this issue and it is very hard for me to diagnose without a DB dump. Is said user banned or deleted or something?

The user was neither banned or deleted - again he’s one of our most active users. I can provide you with a DB dump, how would you like to handle that?

1 Like

Database was apparently corrupted. @corillian managed to restore it on another server and everything is fine now.