adham90
commented
9 months ago the issue was that i was using execution_mode async when i change it to external it worked fine 😬
Closed adham90 closed 9 months ago
adham90
commented
9 months ago the issue was that i was using execution_mode async when i change it to external it worked fine 😬
bensheldon
commented
9 months ago the issue was that i was using execution_mode async when i change it to external it worked fine 😬
That's weird! I don't imagine it's fixing the underlying cause, just maybe deferring it.
I'm imagining that maybe there is a problem with your production schema (e.g. unapplied database migrations). The error you're seeing implies that the good_jobs table does not have an active_job_id column (which seems really weird on its own because that column has existed since GoodJob 1.0).
adham90
commented
9 months ago @bensheldon thank you for replay, i checked the production schema and it has active_job_id in (good_jobs, good_job_executions) tables
tvararu
commented
8 months ago We're getting this issue as well, and weirdly enough it's only in our production environment. It worked fine in 3 other environments we tested before we shipped to production.
Our code is open if you want to take a look, we're currently trying to debug what's the underlying issue: https://github.com/nhsuk/manage-childrens-vaccinations
We connected to the production database and confirmed that both our good_jobs and good_job_executions tables contained active_job_id fields and that there were populated values in them.
Production was working and processing jobs 24 hours before we did this deploy, and now it's failing to run any new jobs. We think it's something that we changed recently, but we don't know what... We reverted from 3.25.0 to 3.24.0 as that's something we deployed in the last day, but that didn't help. (Also, all other envs are running jobs fine with 3.25.0)
bensheldon
commented
8 months ago @tvararu nuts! Sorry to hear you're also experiencing this. Could you share the error backtrace?
Also, that's great I can peak at your code. I'll take a look.
benilovj
commented
8 months ago @bensheldon here's our stack trace:
ActiveModel::MissingAttributeError: can't write unknown attribute `active_job_id` (ActiveModel::MissingAttributeError)
raise ActiveModel::MissingAttributeError, "can't write unknown attribute `#{name}`"
^^^^^
from activemodel (7.1.3.2) lib/active_model/attribute.rb:236:in `with_value_from_database'
from activemodel (7.1.3.2) lib/active_model/attribute_set.rb:60:in `write_from_user'
from activerecord (7.1.3.2) lib/active_record/attribute_methods/write.rb:42:in `_write_attribute'
from activemodel (7.1.3.2) lib/active_model/attribute_methods.rb:286:in `active_job_id='
from activemodel (7.1.3.2) lib/active_model/attribute_assignment.rb:49:in `public_send'
from activemodel (7.1.3.2) lib/active_model/attribute_assignment.rb:49:in `_assign_attribute'
from activerecord (7.1.3.2) lib/active_record/attribute_assignment.rb:19:in `block in _assign_attributes'
from activerecord (7.1.3.2) lib/active_record/attribute_assignment.rb:11:in `each'
from activerecord (7.1.3.2) lib/active_record/attribute_assignment.rb:11:in `_assign_attributes'
from activemodel (7.1.3.2) lib/active_model/attribute_assignment.rb:34:in `assign_attributes'
from activerecord (7.1.3.2) lib/active_record/core.rb:453:in `initialize'
from activerecord (7.1.3.2) lib/active_record/inheritance.rb:76:in `new'
from activerecord (7.1.3.2) lib/active_record/inheritance.rb:76:in `new'
from good_job (3.25.0) app/models/good_job/execution.rb:206:in `build_for_enqueue'
from good_job (3.25.0) app/models/good_job/execution.rb:330:in `block in enqueue'
from activesupport (7.1.3.2) lib/active_support/notifications.rb:206:in `block in instrument'
from activesupport (7.1.3.2) lib/active_support/notifications/instrumenter.rb:58:in `instrument'
from sentry-rails (5.16.1) lib/sentry/rails/tracing.rb:54:in `instrument'
from activesupport (7.1.3.2) lib/active_support/notifications.rb:206:in `instrument'
from good_job (3.25.0) app/models/good_job/execution.rb:313:in `enqueue'
from good_job (3.25.0) lib/good_job/adapter.rb:181:in `block in enqueue_at'
from activesupport (7.1.3.2) lib/active_support/execution_wrapper.rb:88:in `wrap'
from good_job (3.25.0) lib/good_job/adapter.rb:149:in `enqueue_at'
from good_job (3.25.0) lib/good_job/adapter.rb:42:in `enqueue'
from activejob (7.1.3.2) lib/active_job/enqueuing.rb:97:in `block in enqueue'
from activesupport (7.1.3.2) lib/active_support/callbacks.rb:121:in `block in run_callbacks'
from activejob (7.1.3.2) lib/active_job/instrumentation.rb:40:in `block in instrument'
from activesupport (7.1.3.2) lib/active_support/notifications.rb:206:in `block in instrument'
from activesupport (7.1.3.2) lib/active_support/notifications/instrumenter.rb:58:in `instrument'
from sentry-rails (5.16.1) lib/sentry/rails/tracing.rb:54:in `instrument'
from activesupport (7.1.3.2) lib/active_support/notifications.rb:206:in `instrument'
from activejob (7.1.3.2) lib/active_job/instrumentation.rb:39:in `instrument'
from activerecord (7.1.3.2) lib/active_record/railties/job_runtime.rb:18:in `instrument'
from activejob (7.1.3.2) lib/active_job/instrumentation.rb:21:in `block (2 levels) in <module:Instrumentation>'
from activesupport (7.1.3.2) lib/active_support/callbacks.rb:130:in `instance_exec'
from activesupport (7.1.3.2) lib/active_support/callbacks.rb:130:in `block in run_callbacks'
from activesupport (7.1.3.2) lib/active_support/tagged_logging.rb:135:in `block in tagged'
from activesupport (7.1.3.2) lib/active_support/tagged_logging.rb:39:in `tagged'
from activesupport (7.1.3.2) lib/active_support/tagged_logging.rb:135:in `tagged'
from activesupport (7.1.3.2) lib/active_support/broadcast_logger.rb:240:in `method_missing'
from activejob (7.1.3.2) lib/active_job/logging.rb:25:in `tag_logger'
from activejob (7.1.3.2) lib/active_job/logging.rb:14:in `block (2 levels) in <module:Logging>'
from activesupport (7.1.3.2) lib/active_support/callbacks.rb:130:in `instance_exec'
from activesupport (7.1.3.2) lib/active_support/callbacks.rb:130:in `block in run_callbacks'
from activesupport (7.1.3.2) lib/active_support/callbacks.rb:141:in `run_callbacks'
from activejob (7.1.3.2) lib/active_job/enqueuing.rb:93:in `enqueue'
from activejob (7.1.3.2) lib/active_job/enqueuing.rb:60:in `perform_later'
from app/controllers/parent_interface/consent_forms_controller.rb:42:in `record'
from actionpack (7.1.3.2) lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
from actionpack (7.1.3.2) lib/abstract_controller/base.rb:224:in `process_action'
from actionpack (7.1.3.2) lib/action_controller/metal/rendering.rb:165:in `process_action'
from actionpack (7.1.3.2) lib/abstract_controller/callbacks.rb:259:in `block in process_action'
from activesupport (7.1.3.2) lib/active_support/callbacks.rb:121:in `block in run_callbacks'
from turbo-rails (2.0.2) lib/turbo-rails.rb:24:in `with_request_id'
from turbo-rails (2.0.2) app/controllers/concerns/turbo/request_id_tracking.rb:10:in `turbo_tracking_request_id'
from activesupport (7.1.3.2) lib/active_support/callbacks.rb:130:in `block in run_callbacks'
from actiontext (7.1.3.2) lib/action_text/rendering.rb:23:in `with_renderer'
from actiontext (7.1.3.2) lib/action_text/engine.rb:69:in `block (4 levels) in <class:Engine>'
from activesupport (7.1.3.2) lib/active_support/callbacks.rb:130:in `instance_exec'
from activesupport (7.1.3.2) lib/active_support/callbacks.rb:130:in `block in run_callbacks'
from audited (5.4.3) lib/audited/sweeper.rb:16:in `around'
from activesupport (7.1.3.2) lib/active_support/callbacks.rb:130:in `block in run_callbacks'
from audited (5.4.3) lib/audited/sweeper.rb:16:in `around'
from activesupport (7.1.3.2) lib/active_support/callbacks.rb:130:in `block in run_callbacks'
from sentry-rails (5.16.1) lib/sentry/rails/controller_transaction.rb:17:in `block in sentry_around_action'
from sentry-ruby (5.16.1) lib/sentry/hub.rb:109:in `block in with_child_span'
from sentry-ruby (5.16.1) lib/sentry/span.rb:206:in `with_child_span'
from sentry-ruby (5.16.1) lib/sentry/hub.rb:107:in `with_child_span'
from sentry-ruby (5.16.1) lib/sentry-ruby.rb:478:in `with_child_span'
from sentry-rails (5.16.1) lib/sentry/rails/controller_transaction.rb:14:in `sentry_around_action'
from activesupport (7.1.3.2) lib/active_support/callbacks.rb:130:in `block in run_callbacks'
from activesupport (7.1.3.2) lib/active_support/callbacks.rb:141:in `run_callbacks'
from actionpack (7.1.3.2) lib/abstract_controller/callbacks.rb:258:in `process_action'
from actionpack (7.1.3.2) lib/action_controller/metal/rescue.rb:25:in `process_action'
from actionpack (7.1.3.2) lib/action_controller/metal/instrumentation.rb:74:in `block in process_action'
from activesupport (7.1.3.2) lib/active_support/notifications.rb:206:in `block in instrument'
from activesupport (7.1.3.2) lib/active_support/notifications/instrumenter.rb:58:in `instrument'
from sentry-rails (5.16.1) lib/sentry/rails/tracing.rb:54:in `instrument'
from activesupport (7.1.3.2) lib/active_support/notifications.rb:206:in `instrument'
from actionpack (7.1.3.2) lib/action_controller/metal/instrumentation.rb:73:in `process_action'
from actionpack (7.1.3.2) lib/action_controller/metal/params_wrapper.rb:261:in `process_action'
from activerecord (7.1.3.2) lib/active_record/railties/controller_runtime.rb:32:in `process_action'
from actionpack (7.1.3.2) lib/abstract_controller/base.rb:160:in `process'
from actionview (7.1.3.2) lib/action_view/rendering.rb:40:in `process'
from actionpack (7.1.3.2) lib/action_controller/metal.rb:227:in `dispatch'
from actionpack (7.1.3.2) lib/action_controller/metal.rb:309:in `dispatch'
from actionpack (7.1.3.2) lib/action_dispatch/routing/route_set.rb:49:in `dispatch'
from actionpack (7.1.3.2) lib/action_dispatch/routing/route_set.rb:32:in `serve'
from actionpack (7.1.3.2) lib/action_dispatch/journey/router.rb:51:in `block in serve'
from actionpack (7.1.3.2) lib/action_dispatch/journey/router.rb:131:in `block in find_routes'
from actionpack (7.1.3.2) lib/action_dispatch/journey/router.rb:124:in `each'
from actionpack (7.1.3.2) lib/action_dispatch/journey/router.rb:124:in `find_routes'
from actionpack (7.1.3.2) lib/action_dispatch/journey/router.rb:32:in `serve'
from actionpack (7.1.3.2) lib/action_dispatch/routing/route_set.rb:882:in `call'
from flipper (1.2.2) lib/flipper/middleware/memoizer.rb:87:in `memoized_call'
from flipper (1.2.2) lib/flipper/middleware/memoizer.rb:45:in `call'
from warden (1.2.9) lib/warden/manager.rb:36:in `block in call'
from warden (1.2.9) lib/warden/manager.rb:34:in `catch'
from warden (1.2.9) lib/warden/manager.rb:34:in `call'
from rack (3.0.9.1) lib/rack/static.rb:161:in `call'
from rack (3.0.9.1) lib/rack/tempfile_reaper.rb:20:in `call'
from rack (3.0.9.1) lib/rack/etag.rb:29:in `call'
from rack (3.0.9.1) lib/rack/conditional_get.rb:43:in `call'
from rack (3.0.9.1) lib/rack/head.rb:15:in `call'
from actionpack (7.1.3.2) lib/action_dispatch/http/permissions_policy.rb:36:in `call'
from actionpack (7.1.3.2) lib/action_dispatch/http/content_security_policy.rb:33:in `call'
from rack-session (2.0.0) lib/rack/session/abstract/id.rb:272:in `context'
from rack-session (2.0.0) lib/rack/session/abstract/id.rb:266:in `call'
from actionpack (7.1.3.2) lib/action_dispatch/middleware/cookies.rb:689:in `call'
from actionpack (7.1.3.2) lib/action_dispatch/middleware/callbacks.rb:29:in `block in call'
from activesupport (7.1.3.2) lib/active_support/callbacks.rb:101:in `run_callbacks'
from actionpack (7.1.3.2) lib/action_dispatch/middleware/callbacks.rb:28:in `call'
from sentry-rails (5.16.1) lib/sentry/rails/rescued_exception_interceptor.rb:12:in `call'
from actionpack (7.1.3.2) lib/action_dispatch/middleware/debug_exceptions.rb:29:in `call'
from sentry-ruby (5.16.1) lib/sentry/rack/capture_exceptions.rb:28:in `block (2 levels) in call'
from sentry-ruby (5.16.1) lib/sentry/hub.rb:251:in `with_session_tracking'
from sentry-ruby (5.16.1) lib/sentry-ruby.rb:391:in `with_session_tracking'
from sentry-ruby (5.16.1) lib/sentry/rack/capture_exceptions.rb:19:in `block in call'
from sentry-ruby (5.16.1) lib/sentry/hub.rb:59:in `with_scope'
from sentry-ruby (5.16.1) lib/sentry-ruby.rb:371:in `with_scope'
from sentry-ruby (5.16.1) lib/sentry/rack/capture_exceptions.rb:18:in `call'
from actionpack (7.1.3.2) lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
from railties (7.1.3.2) lib/rails/rack/logger.rb:37:in `call_app'
from railties (7.1.3.2) lib/rails/rack/logger.rb:24:in `block in call'
from activesupport (7.1.3.2) lib/active_support/tagged_logging.rb:135:in `block in tagged'
from activesupport (7.1.3.2) lib/active_support/tagged_logging.rb:39:in `tagged'
from activesupport (7.1.3.2) lib/active_support/tagged_logging.rb:135:in `tagged'
from activesupport (7.1.3.2) lib/active_support/broadcast_logger.rb:240:in `method_missing'
from railties (7.1.3.2) lib/rails/rack/logger.rb:24:in `call'
from silencer (2.0.0) lib/silencer/rails/logger.rb:37:in `call'
from actionpack (7.1.3.2) lib/action_dispatch/middleware/remote_ip.rb:92:in `call'
from request_store (1.5.1) lib/request_store/middleware.rb:19:in `call'
from actionpack (7.1.3.2) lib/action_dispatch/middleware/request_id.rb:28:in `call'
from rack (3.0.9.1) lib/rack/method_override.rb:28:in `call'
from rack (3.0.9.1) lib/rack/runtime.rb:24:in `call'
from actionpack (7.1.3.2) lib/action_dispatch/middleware/executor.rb:14:in `call'
from actionpack (7.1.3.2) lib/action_dispatch/middleware/static.rb:25:in `call'
from rack (3.0.9.1) lib/rack/sendfile.rb:114:in `call'
from actionpack (7.1.3.2) lib/action_dispatch/middleware/ssl.rb:79:in `call'
from railties (7.1.3.2) lib/rails/engine.rb:536:in `call'
from puma (6.4.2) lib/puma/configuration.rb:272:in `call'
from puma (6.4.2) lib/puma/request.rb:100:in `block in handle_request'
from puma (6.4.2) lib/puma/thread_pool.rb:378:in `with_force_shutdown'
from puma (6.4.2) lib/puma/request.rb:99:in `handle_request'
from puma (6.4.2) lib/puma/server.rb:464:in `process_client'
from puma (6.4.2) lib/puma/server.rb:245:in `block in run'
from puma (6.4.2) lib/puma/thread_pool.rb:155:in `block in spawn_thread'
misaka
commented
8 months ago I'm also working with @tvararu and @benilovj.
Another data-point to add, we've been able to enqueue jobs from the Rails console without triggering this error.
bensheldon
commented
8 months ago hmm, this is really tough. The exception being raised is coming from the Rails framework where it is aware of the column (you can see there is an active_job_id= setter) but then seems to think the column doesn't exist when it goes to write that value.
I don't imagine this is just a GoodJob issue (though GoodJob does some complex things), but rather than something is happening to Active Record to cause it to be initialized in a weird way.
It sounds like you're not doing continuous deployments. Can you share the commit that was previously deployed that worked?
tvararu
commented
8 months ago @bensheldon thanks for looking into this!
Yeah, it does seem like it could be something deeper in Rails...
I believe the jobs were working correctly at the time when we had af9bdd0 deployed to production.
We're not CDing production at the moment, that's right.
tvararu
commented
8 months ago We just migrated from async to external and can confirm that jobs are now running successfully on production... We'll continue investigating into the root cause, hopefully we can find what the actual underlying issue is, as we agree that it could just be deferring the real issue.
bensheldon
commented
8 months ago I'm so happy I was able to try to reproduce this on your project (yay Open Source!). I was successful in reproducing it under these conditions:
async execution modeWEB_CONCURRENCY > 1 <-- I'm curious if this is indeed enabled in your production environment?Add the configuration to config/puma.rb to shut down and restart GoodJob on fork: https://github.com/bensheldon/good_job?tab=readme-ov-file#execute-jobs-async--in-process (the 4th list item; this should probably be its own subhead so it's more prominent and I can link to it easier 😅 )
Why it happens? I'm not entirely sure. I think it's likely something like the schema cache becomes invalid/corrupted during the fork.
tvararu
commented
8 months ago @bensheldon wow, thank you so much for looking into this. Yay open source! 🎉
Yes, we are indeed setting WEB_CONCURRENCY: 2, and only in the production environment... We also only made this change a week ago so haven't had much time to test it, which is why it caught us off guard. I think we'll consider switching the other deployed envs to use the same setting to help catch these issues in the future. Thanks for your help in identifying a root cause.
We were planning to switch to external execution mode at some point anyway, so if it doesn't experience this same issue, we'll probably stick to it and roll forward now that we've done the work.
Hello good ppl,
I've encountered an issue while working with
good_joband I'm having difficulty resolving it despite my attempts. Here’s a detailed description of the problem and my observations:whenever i try to run any ActionMailer i got this issue:
can't write unknown attribute active_job_idalso this issue only happens on production, its working fine on my localhostWhat I've tried:
3.22.0bin/rails g good_job:updateEnvironment:
Any insights or guidance on this matter would be greatly appreciated. I'm looking forward to your suggestions or solutions to resolve this issue.
Thank you for your time and assistance!
Best regards,
can't write unknown attribute
active_job_idlib/puma/thread_pool.rb:155 block in spawn_thread