search

instructure / canvas-lms

The open LMS by Instructure, Inc.
https://github.com/instructure/canvas-lms/wiki
GNU Affero General Public License v3.0
5.6k stars 2.48k forks source link

AssessmentRequest#generate_stream_items jobs fail with PG::UniqueViolation #1202

Open grahamb opened 6 years ago

grahamb commented 6 years ago

Summary:

With a course that has peer reviews, a large number of failed AssessmentRequest#generate_stream_items jobs will happen with a PG::UniqueViolation error.

Steps to reproduce:

Unknown.

Expected behavior:

Jobs shouldn't fail.

Additional notes:

Full stack trace from a sample failed job: https://gist.github.com/grahamb/5da6f312a58be0fc9744972e6b1da7a1

Conversation in IRC with @simonista for context:

[simonista] hm, the error you reported is PG::UniqueViolation and unique_constraint_retry only catches ActiveRecord::RecordNotUnique [simonista] I wonder when the former gets wrapped into the latter… [simonista] ooo, PG::UniqueViolation is for the index [simonista] that may be a problem — unique_constraint_retry doesn’t seem handle indexes correctly [simonista] although.. wouldn’t all uniqueness be enforced be indexes? hm, need to think about this more [simonista] oh, no, i guess it could be column-level uniqueness [simonista] http://api.rubyonrails.org/classes/ActiveRecord/Validations/ClassMethods.html#method-i-validates_uniqueness_of seems to suggest that this should be an ActiveRecord::RecordNotUnique error… [simonista] @grahamb: can you verify that StreamItem.last.dup.save! raises ActiveRecord::RecordNotUnique: PG::UniqueViolation: ERROR: duplicate key value violates unique constraint "index_stream_items_on_asset_type_and_asset_id" for you? it does for me [simonista] I have no idea why the error in your gist didn’t get wrapped in a ActiveRecord::RecordNotUnique, but I think that’s the problem [simonista] what version of postgres are you running? [grahamb] Yup, it throws ActiveRecord::RecordNotUnique: PG::UniqueViolation [grahamb] Postgres 9.5.4 [simonista] weird…

grahamb commented 6 years ago

Bumping this up as it's still happening for us.

simonista commented 6 years ago

@grahamb, one way to "fix" this is to add PG::UniqueViolation to the list of things being rescued from here: https://github.com/instructure/canvas-lms/blob/stable/config/initializers/active_record.rb#L589.

I put "fix" in quotes because I still don't understand how this is happening, which always makes me a little nervous about just patching over things...

ccutrer commented 6 years ago

Just some clarification: examining the stack trace, the error is being thrown from https://github.com/instructure/canvas-lms/blob/stable/config/initializers/active_record.rb#L592 - AFTER it has already caught it once.

grahamb commented 6 years ago

@simonista @ccutrer I assume you guys aren't seeing similar issues on your end?

ccutrer commented 6 years ago

Oh we are, but only from our own monitoring. It doesn't seem to be causing using facing problems, so has just been lower priority.

grahamb commented 6 years ago

Gotcha. Same here, no apparent user-facing effects, just lights-up-my-alerts effects.

grahamb commented 6 years ago

Bumping this up; we're still getting this daily.

grahamb commented 4 years ago

👋 This started happening to us again. Error trace:

PG::UniqueViolation: ERROR:  duplicate key value violates unique constraint "index_stream_items_on_asset_type_and_asset_id"
DETAIL:  Key (asset_type, asset_id)=(Submission, 21849605) already exists.
: INSERT INTO "stream_items" ("data", "created_at", "updated_at", "context_type", "context_id", "asset_type", "asset_id") VALUES ('---
id: 21849605
url: 
attachment_id: 
grade: ''3''
score: 3.0
submitted_at: 
assignment_id: [REDACTED]
user_id: [REDACTED]
submission_type: 
workflow_state: graded
created_at: !ruby/object:ActiveSupport::TimeWithZone
  utc: 2020-01-20 19:24:39.897462000 Z
  zone: !ruby/object:ActiveSupport::TimeZone
    name: Etc/UTC
  time: 2020-01-20 19:24:39.897462000 Z
updated_at: !ruby/object:ActiveSupport::TimeWithZone
  utc: 2020-01-20 19:25:45.845187000 Z
  zone: !ruby/object:ActiveSupport::TimeZone
    name: Etc/UTC
  time: 2020-01-20 19:25:45.845187000 Z
group_id: 
attachment_ids: 
processed: 
grade_matches_current_submission: true
published_score: 3.0
published_grade: ''3''
graded_at: !ruby/object:ActiveSupport::TimeWithZone
  utc: 2020-01-20 19:25:45.812462000 Z
  zone: !ruby/object:ActiveSupport::TimeZone
    name: Etc/UTC
  time: 2020-01-20 19:25:45.812462000 Z
student_entered_score: 
grader_id: [REDACTED]
media_comment_id: 
media_comment_type: 
quiz_submission_id: 
submission_comments_count: 
attempt: 
context_code: [REDACTED]
media_object_id: 
turnitin_data: {}
cached_due_date: 
excused: false
graded_anonymously: false
late_policy_status: 
points_deducted: 
grading_period_id: 
seconds_late_override: 
lti_user_id: 
anonymous_id: ev7w9
last_comment_at: 
extra_attempts: 
posted_at: 
cached_quiz_lti: false
assignment:
  id: [REDACTED]
  title: Clinic 1
  due_at: 
  points_possible: 3.0
  submission_types: none
  group_category_id: 
:course_id: [REDACTED]
context_short_name: MATH100 D100
type: Submission
user_short_name: [REDACTED]
', '2020-01-20 19:25:46.774948', '2020-01-20 19:25:46.774948', 'Course', 49528, 'Submission', 21849605) RETURNING "id" /*job_tag:Submission#generate_stream_items,hostname:canvas-mp2.f5lms.sfu.ca,pid:31944,context_id:267043156*/
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/postgresql_adapter.rb:611:in `async_exec_params'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/postgresql_adapter.rb:611:in `block (2 levels) in exec_no_cache'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activesupport-5.2.3/lib/active_support/dependencies/interlock.rb:48:in `block in permit_concurrent_loads'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activesupport-5.2.3/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activesupport-5.2.3/lib/active_support/dependencies/interlock.rb:47:in `permit_concurrent_loads'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/postgresql_adapter.rb:610:in `block in exec_no_cache'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract_adapter.rb:581:in `block (2 levels) in log'
/usr/local/lib/ruby/2.4.0/monitor.rb:214:in `mon_synchronize'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract_adapter.rb:580:in `block in log'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activesupport-5.2.3/lib/active_support/notifications/instrumenter.rb:23:in `instrument'
/usr/local/lib/ruby/2.4.0/delegate.rb:83:in `method_missing'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/lib/switchman/sharded_instrumenter.rb:20:in `instrument'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract_adapter.rb:571:in `log'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/lib/switchman/active_record/abstract_adapter.rb:37:in `log'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/postgresql_adapter.rb:609:in `exec_no_cache'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/postgresql_adapter.rb:596:in `execute_and_clear'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/marginalia-1.8.0/lib/marginalia.rb:94:in `execute_and_clear_with_marginalia'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/postgresql/database_statements.rb:81:in `exec_query'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/database_statements.rb:130:in `exec_insert'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/postgresql/database_statements.rb:115:in `exec_insert'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/database_statements.rb:162:in `insert'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/query_cache.rb:21:in `insert'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/persistence.rb:187:in `_insert_record'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/persistence.rb:734:in `_create_record'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/counter_cache.rb:184:in `_create_record'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/locking/optimistic.rb:70:in `_create_record'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/attribute_methods/dirty.rb:140:in `_create_record'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/callbacks.rb:346:in `block in _create_record'
/var/rails/canvas/current/gems/activesupport-suspend_callbacks/lib/active_support/callbacks/suspension.rb:182:in `run_callbacks'
/var/rails/canvas/releases/20200110024514/config/initializers/active_record.rb:1460:in `block in run_callbacks'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/relation.rb:281:in `scoping'
/var/rails/canvas/releases/20200110024514/config/initializers/active_record.rb:1460:in `run_callbacks'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activesupport-5.2.3/lib/active_support/callbacks.rb:816:in `_run_create_callbacks'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/callbacks.rb:346:in `_create_record'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/timestamp.rb:102:in `_create_record'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/persistence.rb:705:in `create_or_update'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/callbacks.rb:342:in `block in create_or_update'
/var/rails/canvas/current/gems/activesupport-suspend_callbacks/lib/active_support/callbacks/suspension.rb:182:in `run_callbacks'
/var/rails/canvas/releases/20200110024514/config/initializers/active_record.rb:1460:in `block in run_callbacks'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/relation.rb:281:in `scoping'
/var/rails/canvas/releases/20200110024514/config/initializers/active_record.rb:1460:in `run_callbacks'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activesupport-5.2.3/lib/active_support/callbacks.rb:816:in `_run_save_callbacks'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/callbacks.rb:342:in `create_or_update'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/persistence.rb:308:in `save!'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/validations.rb:52:in `save!'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/transactions.rb:315:in `block in save!'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/transactions.rb:387:in `block in with_transaction_returning_status'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/database_statements.rb:265:in `transaction'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/transactions.rb:212:in `transaction'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/lib/switchman/active_record/base.rb:41:in `block in transaction'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/lib/switchman/active_record/relation.rb:102:in `activate'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/lib/switchman/active_record/base.rb:36:in `transaction'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/transactions.rb:385:in `with_transaction_returning_status'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/transactions.rb:315:in `save!'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/suppressor.rb:48:in `save!'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/lib/switchman/active_record/base.rb:107:in `block in save!'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/relation.rb:281:in `scoping'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/lib/switchman/active_record/base.rb:107:in `save!'
/var/rails/canvas/releases/20200110024514/app/models/stream_item.rb:241:in `block in generate_or_update'
/var/rails/canvas/releases/20200110024514/config/initializers/active_record.rb:618:in `block (3 levels) in unique_constraint_retry'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/query_cache.rb:78:in `uncached'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/query_cache.rb:21:in `uncached'
/var/rails/canvas/releases/20200110024514/config/initializers/active_record.rb:618:in `block (2 levels) in unique_constraint_retry'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/database_statements.rb:267:in `block in transaction'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.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.4.0/monitor.rb:214:in `mon_synchronize'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/transaction.rb:236:in `within_new_transaction'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/database_statements.rb:267:in `transaction'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.3/lib/active_record/transactions.rb:212:in `transaction'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/lib/switchman/active_record/base.rb:49:in `transaction'
/var/rails/canvas/releases/20200110024514/config/initializers/active_record.rb:618:in `block in unique_constraint_retry'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/lib/switchman/shackles.rb:22:in `activate'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-inst-jobs-1.3.7/lib/switchman_inst_jobs/shackles.rb:8:in `activate'
/var/rails/canvas/releases/20200110024514/config/initializers/active_record.rb:617:in `unique_constraint_retry'
/var/rails/canvas/releases/20200110024514/app/models/stream_item.rb:231:in `generate_or_update'
/var/rails/canvas/releases/20200110024514/app/models/stream_item.rb:260:in `generate_all'
/var/rails/canvas/releases/20200110024514/lib/send_to_stream.rb:70:in `generate_stream_items'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/performable_method.rb:23:in `perform'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/backend/base.rb:254:in `block in invoke_job'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:67:in `block in initialize'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:72:in `execute'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:45:in `run_callbacks'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/backend/base.rb:251:in `invoke_job'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-inst-jobs-1.3.7/lib/switchman_inst_jobs/delayed/backend/base.rb:62:in `block in invoke_job'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/app/models/switchman/shard_internal.rb:605:in `block in activate'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/app/models/switchman/shard_internal.rb:93:in `activate'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/app/models/switchman/shard_internal.rb:604:in `activate'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-inst-jobs-1.3.7/lib/switchman_inst_jobs/delayed/backend/base.rb:62:in `invoke_job'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:210:in `block (2 levels) in perform'
/usr/local/lib/ruby/2.4.0/benchmark.rb:308:in `realtime'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:204:in `block in perform'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-statsd-1.2.3/lib/inst_jobs_statsd/stats/timing/perform.rb:22:in `block (2 levels) in enable_perform_timing'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-statsd-1.2.3/lib/inst_jobs_statsd/stats/timing.rb:8:in `block in report_timing'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst_statsd-2.1.6/lib/inst_statsd/statsd.rb:89:in `time'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-statsd-1.2.3/lib/inst_jobs_statsd/stats/timing.rb:8:in `report_timing'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-statsd-1.2.3/lib/inst_jobs_statsd/stats/timing/perform.rb:21:in `block in enable_perform_timing'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:85:in `block (2 levels) in add'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-statsd-1.2.3/lib/inst_jobs_statsd/stats/timing/perform.rb:13:in `block (2 levels) in enable_batching'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst_statsd-2.1.6/lib/inst_statsd/statsd.rb:98:in `block in batch'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/statsd-ruby-1.4.0/lib/statsd.rb:73:in `easy'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/statsd-ruby-1.4.0/lib/statsd.rb:429:in `batch'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst_statsd-2.1.6/lib/inst_statsd/statsd.rb:96:in `batch'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-statsd-1.2.3/lib/inst_jobs_statsd/stats/timing/perform.rb:12:in `block in enable_batching'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:85:in `block (2 levels) in add'
/var/rails/canvas/releases/20200110024514/config/initializers/delayed_job.rb:136:in `block (2 levels) in <top (required)>'
/var/rails/canvas/releases/20200110024514/lib/temp_cache.rb:23:in `enable'
/var/rails/canvas/releases/20200110024514/config/initializers/delayed_job.rb:135:in `block in <top (required)>'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:85:in `block (2 levels) in add'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:67:in `block in initialize'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:85:in `block in add'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:85:in `block in add'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:85:in `block in add'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:72:in `execute'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:45:in `run_callbacks'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:201:in `perform'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:236:in `block (2 levels) in perform_batch'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:271:in `block in configure_for_job'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:40:in `running_job'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:267:in `configure_for_job'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:235:in `block in perform_batch'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:232:in `each'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:232:in `perform_batch'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:208:in `block (2 levels) in perform'
/usr/local/lib/ruby/2.4.0/benchmark.rb:308:in `realtime'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:204:in `block in perform'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-statsd-1.2.3/lib/inst_jobs_statsd/stats/timing/perform.rb:22:in `block (2 levels) in enable_perform_timing'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-statsd-1.2.3/lib/inst_jobs_statsd/stats/timing.rb:8:in `block in report_timing'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst_statsd-2.1.6/lib/inst_statsd/statsd.rb:89:in `time'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-statsd-1.2.3/lib/inst_jobs_statsd/stats/timing.rb:8:in `report_timing'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-statsd-1.2.3/lib/inst_jobs_statsd/stats/timing/perform.rb:21:in `block in enable_perform_timing'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:85:in `block (2 levels) in add'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-statsd-1.2.3/lib/inst_jobs_statsd/stats/timing/perform.rb:13:in `block (2 levels) in enable_batching'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst_statsd-2.1.6/lib/inst_statsd/statsd.rb:98:in `block in batch'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/statsd-ruby-1.4.0/lib/statsd.rb:73:in `easy'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/statsd-ruby-1.4.0/lib/statsd.rb:429:in `batch'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst_statsd-2.1.6/lib/inst_statsd/statsd.rb:96:in `batch'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-statsd-1.2.3/lib/inst_jobs_statsd/stats/timing/perform.rb:12:in `block in enable_batching'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:85:in `block (2 levels) in add'
/var/rails/canvas/releases/20200110024514/config/initializers/delayed_job.rb:136:in `block (2 levels) in <top (required)>'
/var/rails/canvas/releases/20200110024514/lib/temp_cache.rb:28:in `enable'
/var/rails/canvas/releases/20200110024514/config/initializers/delayed_job.rb:135:in `block in <top (required)>'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:85:in `block (2 levels) in add'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:67:in `block in initialize'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:85:in `block in add'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:85:in `block in add'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:85:in `block in add'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:72:in `execute'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:45:in `run_callbacks'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:201:in `perform'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:174:in `block (2 levels) in run'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:271:in `block in configure_for_job'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:40:in `running_job'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:267:in `configure_for_job'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:173:in `block in run'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:67:in `block in initialize'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:72:in `execute'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:45:in `run_callbacks'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:166:in `run'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-inst-jobs-1.3.7/lib/switchman_inst_jobs/delayed/worker.rb:26:in `block in run'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/app/models/switchman/shard_internal.rb:605:in `block in activate'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/app/models/switchman/shard_internal.rb:93:in `activate'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/app/models/switchman/shard_internal.rb:604:in `activate'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-inst-jobs-1.3.7/lib/switchman_inst_jobs/delayed/worker.rb:26:in `run'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:133:in `block in start'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:67:in `block in initialize'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:72:in `execute'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/lifecycle.rb:45:in `run_callbacks'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/worker.rb:131:in `start'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-inst-jobs-1.3.7/lib/switchman_inst_jobs/delayed/worker.rb:19:in `block in start'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/app/models/switchman/shard_internal.rb:605:in `block in activate'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/app/models/switchman/shard_internal.rb:93:in `activate'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-1.14.7/app/models/switchman/shard_internal.rb:604:in `activate'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/switchman-inst-jobs-1.3.7/lib/switchman_inst_jobs/delayed/worker.rb:19:in `start'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/pool.rb:97:in `block in spawn_worker'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/pool.rb:108:in `block in fork_with_reconnects'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/pool.rb:105:in `fork'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/pool.rb:105:in `fork_with_reconnects'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/pool.rb:96:in `spawn_worker'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/pool.rb:74:in `block (2 levels) in spawn_all_workers'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/pool.rb:74:in `times'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/pool.rb:74:in `block in spawn_all_workers'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/pool.rb:73:in `each'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/pool.rb:73:in `spawn_all_workers'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/pool.rb:40:in `start'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/cli.rb:96:in `start'
/var/rails/canvas/releases/20200110024514/vendor/bundle/ruby/2.4.0/gems/inst-jobs-0.15.14/lib/delayed/cli.rb:48:in `run'
/var/rails/canvas/current/script/delayed_job:11:in `<main>'
bzdk commented 3 years ago

@grahamb Any update on the fix? We are experiencing the same problem now.