New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Sidekiq experiencing regular segmentation faults #6734

Closed
ashfurrow opened this Issue Mar 10, 2018 · 28 comments

Comments

Projects
None yet
9 participants
@ashfurrow
Collaborator

ashfurrow commented Mar 10, 2018

Hello! Since upgrading to 2.3.0 this morning (from 2.1.3), Sidekiq has been crashing every 15 minutes or so. Here is the most recent error, though other errors seem to have other stack traces:

2018-03-10T22:59:56.022Z 7 TID-gpz80i1pc ActivityPub::ProcessingWorker JID-712cbf43a75190afb0871fa6 INFO: start
/mastodon/vendor/bundle/ruby/2.5.0/gems/addressable-2.5.2/lib/addressable/uri.rb:439: [BUG] Segmentation fault at 0x00007fc02737fbc0
ruby 2.5.0p0 (2017-12-25 revision 61468) [x86_64-linux-musl]
Full stack trace
2018-03-10T22:59:56.022Z 7 TID-gpz80i1pc ActivityPub::ProcessingWorker JID-712cbf43a75190afb0871fa6 INFO: start
/mastodon/vendor/bundle/ruby/2.5.0/gems/addressable-2.5.2/lib/addressable/uri.rb:439: [BUG] Segmentation fault at 0x00007fc02737fbc0
ruby 2.5.0p0 (2017-12-25 revision 61468) [x86_64-linux-musl]

-- Control frame information -----------------------------------------------
c:0055 p:0137 s:0296 e:000294 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/addressable-2.5.2/lib/addressable/uri.rb:439
c:0054 p:0069 s:0287 e:000285 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/addressable-2.5.2/lib/addressable/uri.rb:1093
c:0053 p:0021 s:0281 e:000280 METHOD /mastodon/app/lib/activitypub/tag_manager.rb:86
c:0052 p:0006 s:0275 e:000274 METHOD /mastodon/app/lib/activitypub/tag_manager.rb:98
c:0051 p:0024 s:0269 e:000268 METHOD /mastodon/app/lib/activitypub/activity.rb:60
c:0050 p:0034 s:0264 e:000263 METHOD /mastodon/app/lib/activitypub/activity/create.rb:169
c:0049 p:0125 s:0260 e:000238 METHOD /mastodon/app/lib/activitypub/activity/create.rb:54
c:0048 p:0004 s:0235 e:000234 METHOD /mastodon/app/lib/activitypub/activity/create.rb:23
c:0047 p:0027 s:0230 e:000229 BLOCK  /mastodon/app/lib/activitypub/activity/create.rb:13 [FINISH]
c:0046 p:0064 s:0226 e:000225 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/mario-redis-lock-1.2.0/lib/redis_lock.rb:46
c:0045 p:0046 s:0219 E:0022e0 METHOD /mastodon/app/lib/activitypub/activity/create.rb:10
c:0044 p:0030 s:0215 e:000214 METHOD /mastodon/app/services/activitypub/process_collection_service.rb:43
c:0043 p:0007 s:0209 e:000208 BLOCK  /mastodon/app/services/activitypub/process_collection_service.rb:34 [FINISH]
c:0042 p:---- s:0205 e:000204 IFUNC
c:0041 p:---- s:0202 e:000201 CFUNC  :reverse_each
c:0040 p:---- s:0199 e:000198 CFUNC  :each
c:0039 p:---- s:0196 e:000195 CFUNC  :map
c:0038 p:0009 s:0192 e:000191 METHOD /mastodon/app/services/activitypub/process_collection_service.rb:34
c:0037 p:0119 s:0187 e:000186 METHOD /mastodon/app/services/activitypub/process_collection_service.rb:21
c:0036 p:0031 s:0180 e:000179 METHOD /mastodon/app/workers/activitypub/processing_worker.rb:9
c:0035 p:0009 s:0174 e:000173 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:188
c:0034 p:0019 s:0168 e:000167 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:170
c:0033 p:0010 s:0165 e:000164 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:128
c:0032 p:0002 s:0162 e:000161 METHOD /mastodon/app/lib/sidekiq_error_handler.rb:5
c:0031 p:0026 s:0156 e:000155 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:130
c:0030 p:0031 s:0153 e:000152 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-5.0.10/lib/sidekiq_unique_jobs/server/middleware.rb:17
c:0029 p:0026 s:0144 e:000143 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:130 [FINISH]
c:0028 p:0021 s:0141 E:0026f8 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:133
c:0027 p:0021 s:0134 E:000358 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:169
c:0026 p:0005 s:0130 e:000129 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:141
c:0025 p:0002 s:0127 e:000126 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/job_retry.rb:97
c:0024 p:0051 s:0117 e:000116 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:140
c:0023 p:0003 s:0112 e:000111 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/rails.rb:42
c:0022 p:0017 s:0109 e:000108 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/execution_wrapper.rb:85
c:0021 p:0007 s:0104 e:000103 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/reloader.rb:68
c:0020 p:0017 s:0101 e:000100 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/execution_wrapper.rb:85
c:0019 p:0008 s:0096 e:000095 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/reloader.rb:67
c:0018 p:0010 s:0092 e:000091 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/rails.rb:41
c:0017 p:0008 s:0088 e:000087 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:136
c:0016 p:0046 s:0085 e:000084 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:204
c:0015 p:0012 s:0078 e:000077 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:131
c:0014 p:0024 s:0075 e:000074 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/job_logger.rb:7
c:0013 p:0014 s:0068 e:000067 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:130
c:0012 p:0002 s:0065 e:000064 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/job_retry.rb:72
c:0011 p:0012 s:0056 e:000055 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:129
c:0010 p:0054 s:0053 e:000052 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/logging.rb:44
c:0009 p:0013 s:0048 e:000047 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/logging.rb:38
c:0008 p:0023 s:0042 e:000041 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:128
c:0007 p:0051 s:0035 E:0001a8 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:168
c:0006 p:0019 s:0024 e:000023 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:85
c:0005 p:0010 s:0020 e:000019 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:73 [FINISH]
c:0004 p:---- s:0015 e:000014 IFUNC
c:0003 p:0002 s:0012 e:000011 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/util.rb:16
c:0002 p:0028 s:0006 e:000005 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/util.rb:25 [FINISH]
c:0001 p:---- s:0003 e:000002 (none) [FINISH]

-- Ruby level backtrace information ----------------------------------------
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/util.rb:25:in `block in safe_thread'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/util.rb:16:in `watchdog'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:73:in `run'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:85:in `process_one'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:168:in `process'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:128:in `dispatch'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/logging.rb:38:in `with_job_hash_context'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/logging.rb:44:in `with_context'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:129:in `block in dispatch'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/job_retry.rb:72:in `global'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:130:in `block (2 levels) in dispatch'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/job_logger.rb:7:in `call'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:131:in `block (3 levels) in dispatch'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:204:in `stats'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:136:in `block (4 levels) in dispatch'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/rails.rb:41:in `call'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/reloader.rb:67:in `wrap'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/execution_wrapper.rb:85:in `wrap'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/reloader.rb:68:in `block in wrap'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/execution_wrapper.rb:85:in `wrap'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/rails.rb:42:in `block in call'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:140:in `block (5 levels) in dispatch'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/job_retry.rb:97:in `local'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:141:in `block (6 levels) in dispatch'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:169:in `block in process'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:133:in `invoke'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-5.0.10/lib/sidekiq_unique_jobs/server/middleware.rb:17:in `call'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
/mastodon/app/lib/sidekiq_error_handler.rb:5:in `call'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:128:in `block in invoke'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:170:in `block (2 levels) in process'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:188:in `execute_job'
/mastodon/app/workers/activitypub/processing_worker.rb:9:in `perform'
/mastodon/app/services/activitypub/process_collection_service.rb:21:in `call'
/mastodon/app/services/activitypub/process_collection_service.rb:34:in `process_items'
/mastodon/app/services/activitypub/process_collection_service.rb:34:in `map'
/mastodon/app/services/activitypub/process_collection_service.rb:34:in `each'
/mastodon/app/services/activitypub/process_collection_service.rb:34:in `reverse_each'
/mastodon/app/services/activitypub/process_collection_service.rb:34:in `block in process_items'
/mastodon/app/services/activitypub/process_collection_service.rb:43:in `process_item'
/mastodon/app/lib/activitypub/activity/create.rb:10:in `perform'
/mastodon/vendor/bundle/ruby/2.5.0/gems/mario-redis-lock-1.2.0/lib/redis_lock.rb:46:in `acquire'
/mastodon/app/lib/activitypub/activity/create.rb:13:in `block in perform'
/mastodon/app/lib/activitypub/activity/create.rb:23:in `process_status'
/mastodon/app/lib/activitypub/activity/create.rb:54:in `process_status_params'
/mastodon/app/lib/activitypub/activity/create.rb:169:in `replied_to_status'
/mastodon/app/lib/activitypub/activity.rb:60:in `status_from_uri'
/mastodon/app/lib/activitypub/tag_manager.rb:98:in `uri_to_resource'
/mastodon/app/lib/activitypub/tag_manager.rb:86:in `local_uri?'
/mastodon/vendor/bundle/ruby/2.5.0/gems/addressable-2.5.2/lib/addressable/uri.rb:1093:in `normalized_host'
/mastodon/vendor/bundle/ruby/2.5.0/gems/addressable-2.5.2/lib/addressable/uri.rb:439:in `unencode'

I have searched the internet for this kind of problem but haven't had any luck. Does anyone have any suggestions for next steps?

EDIT: Forgot to mention my server config! I'm using Docker version 17.05.0-ce, build 89658be.


  • I searched or browsed the repo’s other issues to ensure this is not a duplicate.
  • This bug happens on a tagged release and not on master (If you're a user, don't worry about this).
@ashfurrow

This comment has been minimized.

Collaborator

ashfurrow commented Mar 10, 2018

Here's another stack trace, in case it's helpful:

2018-03-10T23:13:06.273Z 7 TID-gpy6hxs4c ActivityPub::ProcessingWorker JID-e0074de6ad762624bd9e1379 INFO: start
Scoped order is ignored, it's forced to be batch order.
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/relation/query_methods.rb:945: [BUG] Segmentation fault at 0x00007f5e4b0a4bc0
ruby 2.5.0p0 (2017-12-25 revision 61468) [x86_64-linux-musl]

-- Control frame information -----------------------------------------------
c:0083 p:0071 s:0414 e:000410 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/relation/query_methods.rb:945
c:0082 p:0018 s:0406 e:000405 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/relation/query_methods.rb:918
c:0081 p:0022 s:0402 e:000400 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/relation.rb:667
c:0080 p:0006 s:0394 e:000393 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/association_relation.rb:32
c:0079 p:0013 s:0390 e:000389 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/relation.rb:546
c:0078 p:0004 s:0385 e:000384 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/relation.rb:255
c:0077 p:0004 s:0381 e:000380 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/relation.rb:251
c:0076 p:0013 s:0377 e:000376 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/associations/collection_association.rb:303
c:0075 p:0011 s:0370 e:000368 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/associations/collection_association.rb:270
c:0074 p:0133 s:0365 e:000364 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/associations/has_many_association.rb:25
c:0073 p:0011 s:0360 e:000359 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/associations/builder/association.rb:140 [FINISH]
c:0072 p:---- s:0356 e:000355 CFUNC  :instance_exec
c:0071 p:0036 s:0351 e:000350 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:413 [FINISH]
c:0070 p:0011 s:0343 e:000342 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:197 [FINISH]
c:0069 p:0020 s:0340 e:000339 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:601 [FINISH]
c:0068 p:---- s:0337 e:000336 CFUNC  :catch
c:0067 p:0012 s:0332 e:000331 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:600 [FINISH]
c:0066 p:0045 s:0326 E:0019f8 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:198 [FINISH]
c:0065 p:0008 s:0317 e:000316 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:507 [FINISH]
c:0064 p:---- s:0313 e:000312 CFUNC  :each
c:0063 p:0007 s:0309 e:000308 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:507
c:0062 p:0084 s:0304 E:001698 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:130
c:0061 p:0009 s:0295 e:000294 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:827
c:0060 p:0043 s:0290 E:0024b8 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/callbacks.rb:321
c:0059 p:0007 s:0285 e:000284 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/transactions.rb:303
c:0058 p:0008 s:0282 e:000281 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/transactions.rb:384
c:0057 p:0003 s:0279 e:000278 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/connection_adapters/abstract/database_statements.r
c:0056 p:0011 s:0276 e:000275 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/connection_adapters/abstract/transaction.rb:194
c:0055 p:0007 s:0271 e:000270 METHOD /usr/local/lib/ruby/2.5.0/monitor.rb:226
c:0054 p:0014 s:0267 e:000266 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/connection_adapters/abstract/transaction.rb:191
c:0053 p:0052 s:0262 e:000261 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/connection_adapters/abstract/database_statements.r
c:0052 p:0016 s:0254 e:000253 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/transactions.rb:210
c:0051 p:0011 s:0248 e:000247 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/transactions.rb:381
c:0050 p:0005 s:0243 e:000242 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/transactions.rb:303
c:0049 p:0004 s:0239 e:000238 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/persistence.rb:211
c:0048 p:0143 s:0235 e:000234 METHOD /mastodon/app/services/remove_status_service.rb:24
c:0047 p:0015 s:0229 e:000228 METHOD /mastodon/app/lib/activitypub/activity/delete.rb:43
c:0046 p:0107 s:0224 e:000223 METHOD /mastodon/app/lib/activitypub/activity/delete.rb:28
c:0045 p:0024 s:0219 e:000218 METHOD /mastodon/app/lib/activitypub/activity/delete.rb:8
c:0044 p:0030 s:0215 e:000214 METHOD /mastodon/app/services/activitypub/process_collection_service.rb:43
c:0043 p:0007 s:0209 e:000208 BLOCK  /mastodon/app/services/activitypub/process_collection_service.rb:34 [FINISH]
c:0042 p:---- s:0205 e:000204 IFUNC
c:0041 p:---- s:0202 e:000201 CFUNC  :reverse_each
c:0040 p:---- s:0199 e:000198 CFUNC  :each
c:0039 p:---- s:0196 e:000195 CFUNC  :map
c:0038 p:0009 s:0192 e:000191 METHOD /mastodon/app/services/activitypub/process_collection_service.rb:34
c:0037 p:0119 s:0187 e:000186 METHOD /mastodon/app/services/activitypub/process_collection_service.rb:21
c:0036 p:0031 s:0180 e:000179 METHOD /mastodon/app/workers/activitypub/processing_worker.rb:9
c:0035 p:0009 s:0174 e:000173 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:188
c:0034 p:0019 s:0168 e:000167 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:170
c:0033 p:0010 s:0165 e:000164 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:128
c:0032 p:0002 s:0162 e:000161 METHOD /mastodon/app/lib/sidekiq_error_handler.rb:5
c:0031 p:0026 s:0156 e:000155 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:130
c:0030 p:0031 s:0153 e:000152 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-5.0.10/lib/sidekiq_unique_jobs/server/middleware.rb:17
c:0029 p:0026 s:0144 e:000143 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:130 [FINISH]
c:0028 p:0021 s:0141 E:001f08 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:133
c:0027 p:0021 s:0134 E:001918 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:169
c:0026 p:0005 s:0130 e:000129 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:141
c:0025 p:0002 s:0127 e:000126 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/job_retry.rb:97
c:0024 p:0051 s:0117 e:000116 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:140
c:0023 p:0003 s:0112 e:000111 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/rails.rb:42
c:0022 p:0017 s:0109 e:000108 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/execution_wrapper.rb:85
c:0021 p:0007 s:0104 e:000103 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/reloader.rb:68
c:0020 p:0017 s:0101 e:000100 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/execution_wrapper.rb:85
c:0019 p:0008 s:0096 e:000095 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/reloader.rb:67
c:0018 p:0010 s:0092 e:000091 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/rails.rb:41
c:0017 p:0008 s:0088 e:000087 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:136
c:0016 p:0046 s:0085 e:000084 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:204
c:0015 p:0012 s:0078 e:000077 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:131
c:0014 p:0024 s:0075 e:000074 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/job_logger.rb:7
c:0013 p:0014 s:0068 e:000067 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:130
c:0012 p:0002 s:0065 e:000064 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/job_retry.rb:72
c:0011 p:0012 s:0056 e:000055 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:129
c:0010 p:0054 s:0053 e:000052 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/logging.rb:44
c:0009 p:0013 s:0048 e:000047 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/logging.rb:38
c:0008 p:0023 s:0042 e:000041 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:128
c:0007 p:0051 s:0035 E:002398 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:168
c:0006 p:0019 s:0024 e:000023 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:85
c:0005 p:0010 s:0020 e:000019 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:73 [FINISH]
c:0004 p:---- s:0015 e:000014 IFUNC
c:0003 p:0002 s:0012 e:000011 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/util.rb:16
c:0002 p:0028 s:0006 e:000005 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/util.rb:25 [FINISH]
c:0001 p:---- s:0003 e:000002 (none) [FINISH]

-- Ruby level backtrace information ----------------------------------------
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/util.rb:25:in `block in safe_thread'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/util.rb:16:in `watchdog'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:73:in `run'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:85:in `process_one'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:168:in `process'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:128:in `dispatch'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/logging.rb:38:in `with_job_hash_context'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/logging.rb:44:in `with_context'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:129:in `block in dispatch'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/job_retry.rb:72:in `global'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:130:in `block (2 levels) in dispatch'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/job_logger.rb:7:in `call'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:131:in `block (3 levels) in dispatch'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:204:in `stats'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:136:in `block (4 levels) in dispatch'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/rails.rb:41:in `call'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/reloader.rb:67:in `wrap'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/execution_wrapper.rb:85:in `wrap'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/reloader.rb:68:in `block in wrap'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/execution_wrapper.rb:85:in `wrap'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/rails.rb:42:in `block in call'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:140:in `block (5 levels) in dispatch'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/job_retry.rb:97:in `local'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:141:in `block (6 levels) in dispatch'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:169:in `block in process'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:133:in `invoke'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-unique-jobs-5.0.10/lib/sidekiq_unique_jobs/server/middleware.rb:17:in `call'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
/mastodon/app/lib/sidekiq_error_handler.rb:5:in `call'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/middleware/chain.rb:128:in `block in invoke'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:170:in `block (2 levels) in process'
/mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:188:in `execute_job'
/mastodon/app/workers/activitypub/processing_worker.rb:9:in `perform'
/mastodon/app/services/activitypub/process_collection_service.rb:21:in `call'
/mastodon/app/services/activitypub/process_collection_service.rb:34:in `process_items'
/mastodon/app/services/activitypub/process_collection_service.rb:34:in `map'
/mastodon/app/services/activitypub/process_collection_service.rb:34:in `each'
/mastodon/app/services/activitypub/process_collection_service.rb:34:in `reverse_each'
/mastodon/app/services/activitypub/process_collection_service.rb:34:in `block in process_items'
/mastodon/app/services/activitypub/process_collection_service.rb:43:in `process_item'
/mastodon/app/lib/activitypub/activity/delete.rb:8:in `perform'
/mastodon/app/lib/activitypub/activity/delete.rb:28:in `delete_note'
/mastodon/app/lib/activitypub/activity/delete.rb:43:in `delete_now!'
/mastodon/app/services/remove_status_service.rb:24:in `call'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/persistence.rb:211:in `destroy!'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/transactions.rb:303:in `destroy'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/transactions.rb:381:in `with_transaction_returning_status'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/transactions.rb:210:in `transaction'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/connection_adapters/abstract/database_statements.rb:235:in `transaction'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/connection_adapters/abstract/transaction.rb:191:in `within_new_transaction'
/usr/local/lib/ruby/2.5.0/monitor.rb:226:in `mon_synchronize'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/connection_adapters/abstract/transaction.rb:194:in `block in within_new_transaction'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/connection_adapters/abstract/database_statements.rb:235:in `block in transaction'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/transactions.rb:384:in `block in with_transaction_returning_status'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/transactions.rb:303:in `block in destroy'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/callbacks.rb:321:in `destroy'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:827:in `_run_destroy_callbacks'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:130:in `run_callbacks'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:507:in `invoke_before'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:507:in `each'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:507:in `block in invoke_before'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:198:in `block in halting'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:600:in `block in default_terminator'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:600:in `catch'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:601:in `block (2 levels) in default_terminator'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:197:in `block (2 levels) in halting'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:413:in `block in make_lambda'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:413:in `instance_exec'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/associations/builder/association.rb:140:in `block in add_destroy_callbacks'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/associations/has_many_association.rb:25:in `handle_dependency'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/associations/collection_association.rb:270:in `load_target'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/associations/collection_association.rb:303:in `find_target'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/relation.rb:251:in `to_a'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/relation.rb:255:in `records'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/relation.rb:546:in `load'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/association_relation.rb:32:in `exec_queries'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/relation.rb:667:in `exec_queries'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/relation/query_methods.rb:918:in `arel'
/mastodon/vendor/bundle/ruby/2.5.0/gems/activerecord-5.1.4/lib/active_record/relation/query_methods.rb:945:in `build_arel'
@Gargron

This comment has been minimized.

Member

Gargron commented Mar 10, 2018

Unfortunately the two stack traces do not seem related at all, which suggests the cause is not in the code.

@ashfurrow

This comment has been minimized.

Collaborator

ashfurrow commented Mar 11, 2018

Yeah that’s I’m thinking. I decreased the RAM used by ElasticSearch to try and troubleshoot this but it’s still persisting. Any tips on where to start looking for confit problems? My Docker config is here if anyone is interested: https://github.com/ashfurrow/mastodon/blob/master/docker-compose.yml

@ashfurrow

This comment has been minimized.

Collaborator

ashfurrow commented Mar 11, 2018

Just tried disabling ElasticSearch in a last-ditch effort to fix, but it didn't work.

@ashfurrow

This comment has been minimized.

Collaborator

ashfurrow commented Mar 11, 2018

I tried updating Docker but that didn't work either.

But! A friend suggested I look at the Ruby version and it did change from the last stable Mastodon version I was running (2.1.3) to 2.3.0. The Ruby version was updated from 2.4.2 to 2.5.0, so I downgraded the Ruby version and rebuilt the Docker containers. Ran into a little trouble but the changes are all in the linked commit. The Sidekiq Docker container has been running for over an hour with no crashes 🎉

I'm uncertain of next steps – I don't know if I have a reproducible-enough situation to file an adequate bug report with either Sidekiq or Ruby. Hopefully this issue will help other Mastodon admins and if they experience the same problem, we can work together to report this problem to the appropriate project.

@hugogameiro

This comment has been minimized.

Contributor

hugogameiro commented Mar 14, 2018

I am also getting loads of Segmentation faults with Sidekiq since upgrading to v2.3.1 (Docker). The Segmentation faults are not related (activerecord, openssl, rdf, etc). The containers keep restarting. I found this explanation of the issue. Can anyone else confirm that this is an issue that needs fixing in Docker?

@skoji

This comment has been minimized.

Contributor

skoji commented Mar 15, 2018

Just FYI; It is same here. I've downgraded ruby version of the sidekiq container and it seems to work.

@Elizafox

This comment has been minimized.

Contributor

Elizafox commented Mar 15, 2018

@hugogameiro that's not the problem. It crashed in my sleep. I'm going to keep trying to debug it. In the meantime I guess I'll try downgrading ruby.

@akihikodaki

This comment has been minimized.

Collaborator

akihikodaki commented Mar 16, 2018

I'd like to know if it is reproducible even for non-Docker (and non-Alpine) environment.

@akihikodaki

This comment has been minimized.

Collaborator

akihikodaki commented Mar 16, 2018

I have been trying to reproduce this issue for a few hours but I have not succeeded so far. (Using Docker version 17.12.1-ce, build 7390fc6)

It would be nice if anyone provides more information. Specifically, arguments for ActivityPub::ProcessingWorker should be helpful for people trying to reproduce the bug. Note that they could include sensitive information and should be masked if you are willing to share.

@hugogameiro

This comment has been minimized.

Contributor

hugogameiro commented Mar 16, 2018

@akihikodaki I looked at instances running non-Docker (Ruby 2.5.0) and I didn't find segmentation faults in the logs or restarts of Sidekiq.

I also looked at instances running Docker and it only happen on instances with activity, so probably this issue will not be reproducible unless you have external connections and activity going back and forth.

I can share more details but my logs look very similar to what @ashfurrow posted above. I am not sure how to get the arguments for ActivityPub::ProcessingWorker but let me know how to get them and I try to get it.

@akihikodaki

This comment has been minimized.

Collaborator

akihikodaki commented Mar 16, 2018

@hugogameiro

I looked at instances running non-Docker (Ruby 2.5.0) and I didn't find segmentation faults in the logs or restarts of Sidekiq.

Thanks for your report. I asked some other admins but they did not report any case that the bug is reproduced on non-Docker environment. I wonder if the difference of the compiler is leading to the problem since Alpine has new compilers than LTS distributions.

I also looked at instances running Docker and it only happen on instances with activity, so probably this issue will not be reproducible unless you have external connections and activity going back and forth.

I made a local federation network in a way similar to #6357, but I could not reproduce. I suspect interacts with other ActivityPub implementation or different Mastodon version may be necessary. (It is just a suspecion anyway. Maybe wrong.)

I can share more details but my logs look very similar to what @ashfurrow posted above. I am not sure how to get the arguments for ActivityPub::ProcessingWorker but let me know how to get them and I try to get it.

The simplest way is to apply the following change:

diff --git a/app/services/activitypub/process_collection_service.rb b/app/services/activitypub/process_collection_service.rb
index eb93329e9..a1f5861bf 100644
--- a/app/services/activitypub/process_collection_service.rb
+++ b/app/services/activitypub/process_collection_service.rb
@@ -31,6 +31,7 @@ class ActivityPub::ProcessCollectionService < BaseService
   end
 
   def process_items(items)
+    Rails.logger.info items
     items.reverse_each.map { |item| process_item(item) }.compact
   end

So add line Rails.logger.info items immediately after line with def process_items(items) in app/services/activitypub/process_collection_service.rb, and then rebuild Docker image and container. You will have logs something like this:

[{"@context"=>["https://www.w3.org/ns/activitystreams", "https://w3id.org/security/v1", {"manuallyApprovesFollowers"=>"as:manuallyApprovesFollowers", "sensitive"=>"as:sensitive", "movedTo"=>"as:movedTo", "Hashtag"=>"as:Hashtag", "ostatus"=>"http://ostatus.org#", "atomUri"=>"ostatus:atomUri", "inReplyToAtomUri"=>"ostatus:inReplyToAtomUri", "conversation"=>"ostatus:conversation", "toot"=>"http://joinmastodon.org/ns#", "Emoji"=>"toot:Emoji", "focalPoint"=>{"@container"=>"@list", "@id"=>"toot:focalPoint"}, "featured"=>"toot:featured"}], "id"=>"https://mastodon2.localdomain/users/admin#likes/6", "type"=>"Like", "actor"=>"https://mastodon2.localdomain/users/admin", "object"=>"https://mastodon1.localdomain/users/admin/statuses/99693423691961050", "signature"=>{"type"=>"RsaSignature2017", "creator"=>"https://mastodon2.localdomain/users/admin#main-key", "created"=>"2018-03-16T11:49:10Z", "signatureValue"=>"GVkVgns1O9dcKHBi++TAl/NUYkTw+7DIMrGqYLj7+38ik2M4qjkYKo5gMGoXVFMcWHBLLFthq31mC6Ure0fcK9kcR6mih/FHi/dbOs7aM3y4IyuJytY+ih50AAMcfu2blVbPsj7n4LZ6QUiDe7qKJ+BHt7H+QgDPKN870RWuLS0Ss/u/krl1/soUH3p84igZsyT/DrFbay6hKea7OKp1KiNGyi3Xrd9VLjzWUgi+gscumNV1an5uT50LuqjygepT3+7KuOS6IcdICk6S3oux9QJcYVR3vMjisSTiOjZc1qLp/wpTYdDHllFU9O2t2dGJmr3sEr4+Y1ZX21cidJMgsA=="}}]

Please be advised that as it is so simple, it emits everything from federation and will flood logs. This change should be reverted after you get a log.

@hugogameiro

This comment has been minimized.

Contributor

hugogameiro commented Mar 16, 2018

@akihikodaki this would require me to cause downtime and I would like to avoid that as much as possible because the instances I host are from others and in multi instance servers.

If there is no other way, I can try and find a way to do it.

Also, I would like you to know that the segmentation is not only on ActivityPub::ProcessingWorker, I also see:

2018-03-15T17:01:30.125Z 6 TID-gon108bzw LinkCrawlWorker JID-078d8094f8630a959d155dda INFO: done: 2.293 sec
/mastodon/vendor/bundle/ruby/2.5.0/gems/connection_pool-2.2.1/lib/connection_pool.rb:63: [BUG] Segmentation fault at 0x00007fc02a768bc0
ruby 2.5.0p0 (2017-12-25 revision 61468) [x86_64-linux-musl]
2018-03-14T16:20:18.837Z 5 TID-gp1amt0pw FeedInsertWorker JID-17093e79c2c8d86a3512ba98 INFO: done: 0.049 sec
/mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/connection/ruby.rb:86: [BUG] Segmentation fault at 0x00007f306203dbc0
ruby 2.5.0p0 (2017-12-25 revision 61468) [x86_64-linux-musl]
/mastodon/vendor/bundle/ruby/2.5.0/gems/et-orbi-1.0.8/lib/et-orbi.rb:19: [BUG] Segmentation fault at 0x00007fe72571ebc0
ruby 2.5.0p0 (2017-12-25 revision 61468) [x86_64-linux-musl]
2018-03-14T17:48:45.474Z 6 TID-gnkq2akoo WARN: /mastodon/vendor/bundle/ruby/2.5.0/gems/http-3.0.0/lib/http/timeout/per_operation.rb:34:in `con$
/mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/connection/command_helper.rb:28: [BUG] Segmentation fault at 0x00007f46245c2bc0
ruby 2.5.0p0 (2017-12-25 revision 61468) [x86_64-linux-musl]

On high activity instances there are a bunch of crashes, like hourly.

@akihikodaki

This comment has been minimized.

Collaborator

akihikodaki commented Mar 16, 2018

@hugogameiro

this would require me to cause downtime and I would like to avoid that as much as possible because the instances I host are from others and in multi instance servers.

Letting Sidekiq down practically does not cause downtime because it is an internal service. However it may require complex procedure to recreate only Sidekiq.

Also, I would like you to know that the segmentation is not only on ActivityPub::ProcessingWorker, I also see:

That is really informative. I have ran all tests on containers created with #6357, but I didn't have segfault then. I am not sure why I had no segfault yet it has random failures on your environment.

[BUG] Segmentation fault at 0x00007f46245c2bc0

The program counter always has a same suffix. They should be the same bug.

UPDATE: I checked the binary and found its ELF type is DYN, which means it is position independent executable. The different prefix could be explained by ALSR.

@hugogameiro

This comment has been minimized.

Contributor

hugogameiro commented Mar 16, 2018

@akihikodaki

I checked the binary and found its ELF type is DYN, which means it is position independent executable. The different prefix could be explained by ALSR.

I have no idea what that means :) but do let me know if I can help with anything else.

@akihikodaki

This comment has been minimized.

Collaborator

akihikodaki commented Mar 17, 2018

do let me know if I can help with anything else.

I'm afraid not for now. I think at least backtrace with debug symbols is necessary, but it is difficult to get one. It is unfortunate that Docker does not provide debug symbols.

@Gargron

This comment has been minimized.

Member

Gargron commented Mar 17, 2018

Another log entry:

/mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/connection/ruby.rb:78: [BUG] Segmentation fault at 0x00007f06f3d53bc0
ruby 2.5.0p0 (2017-12-25 revision 61468) [x86_64-linux-musl]

-- Control frame information -----------------------------------------------
c:0039 p:---- s:0184 e:000183 CFUNC  :slice!
c:0038 p:0068 s:0178 e:000177 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/connection/ruby.rb:78
c:0037 p:0006 s:0173 e:000172 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/connection/ruby.rb:380
c:0036 p:0008 s:0167 e:000166 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/client.rb:262
c:0035 p:0002 s:0163 e:000162 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/client.rb:250
c:0034 p:0005 s:0156 e:000155 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/client.rb:261
c:0033 p:0005 s:0152 e:000151 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/client.rb:120
c:0032 p:0017 s:0149 e:000148 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/client.rb:231
c:0031 p:0088 s:0146 e:000145 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/client.rb:367
c:0030 p:0006 s:0141 e:000140 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/client.rb:221
c:0029 p:0015 s:0138 e:000137 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/client.rb:306
c:0028 p:0007 s:0132 e:000131 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/client.rb:220
c:0027 p:0009 s:0127 e:000126 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/client.rb:120
c:0026 p:0010 s:0121 e:000120 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/client.rb:209
c:0025 p:0023 s:0118 e:000117 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/client.rb:280
c:0024 p:0007 s:0113 e:000112 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis/client.rb:208
c:0023 p:0040 s:0106 e:000105 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis.rb:1137
c:0022 p:0006 s:0101 e:000100 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis.rb:58
c:0021 p:0007 s:0098 e:000097 METHOD /usr/local/lib/ruby/2.5.0/monitor.rb:226
c:0020 p:0005 s:0094 e:000093 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis.rb:58
c:0019 p:0097 s:0090 e:000089 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis.rb:1134
c:0018 p:0008 s:0081 e:000080 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/redis-3.3.5/lib/redis.rb:1179
c:0017 p:0012 s:0076 e:000075 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/fetch.rb:36
c:0016 p:0009 s:0072 e:000071 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq.rb:95
c:0015 p:0005 s:0066 e:000065 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/connection_pool-2.2.1/lib/connection_pool.rb:64 [FINISH]
c:0014 p:---- s:0063 e:000062 CFUNC  :handle_interrupt
c:0013 p:0031 s:0058 e:000057 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/connection_pool-2.2.1/lib/connection_pool.rb:63 [FINISH]
c:0012 p:---- s:0054 e:000053 CFUNC  :handle_interrupt
c:0011 p:0026 s:0049 e:000048 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/connection_pool-2.2.1/lib/connection_pool.rb:60
c:0010 p:0028 s:0044 e:000043 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq.rb:92
c:0009 p:0011 s:0040 e:000039 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/fetch.rb:36
c:0008 p:0006 s:0035 e:000034 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:91
c:0007 p:0004 s:0029 e:000028 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:101
c:0006 p:0004 s:0024 e:000023 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:84
c:0005 p:0010 s:0020 e:000019 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/processor.rb:73 [FINISH]
c:0004 p:---- s:0015 e:000014 IFUNC
c:0003 p:0002 s:0012 e:000011 METHOD /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/util.rb:16
c:0002 p:0028 s:0006 e:000005 BLOCK  /mastodon/vendor/bundle/ruby/2.5.0/gems/sidekiq-5.0.5/lib/sidekiq/util.rb:25 [FINISH]
c:0001 p:---- s:0003 e:000002 (none) [FINISH]

I'm going to try downgrading Dockerfile to ruby-2.4.2-alpine3.7 (same Alpine version, older ruby) and see if it helps. It might also be necessary to check ruby-2.5.0-alpine3.6 if possible, in case it's a problem with the alpine version.

I think that because of this issue, Sidekiq jobs may be disappearing for good. I had some reports of confirmation e-mails never getting sent. That should not be possible without any logs or failing jobs, so the easiest explanation is that the Sidekiq process crashes after picking up the job, so the job just disappears.

@Gargron

This comment has been minimized.

Member

Gargron commented Mar 17, 2018

More evidence that it's an Alpine 3.7 issue: phusion/passenger#2030

@tateisu

This comment has been minimized.

Contributor

tateisu commented Mar 17, 2018

this crash generates /core in container, check it with gdb...

$ gdb /usr/local/bin/ruby core
GNU gdb (GDB) 8.0.1
Copyright (C) 2017 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-alpine-linux-musl".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/local/bin/ruby...done.
[New LWP 17]
[New LWP 10]
[New LWP 8]
[New LWP 9]
[New LWP 15]
[New LWP 14]
[New LWP 262]
[New LWP 12]
[New LWP 263]
[New LWP 194]
[New LWP 7]
[New LWP 11]
[New LWP 21]
[New LWP 20]
[New LWP 19]

warning: Can't read pathname for load map: No error information.
Core was generated by `sidekiq 5.0.5 mastodon [0 of 10 busy]         '.
Program terminated with signal SIGABRT, Aborted.
#0  0x00007f14983ac8e3 in __restore_sigs () from /lib/ld-musl-x86_64.so.1
[Current thread is 1 (LWP 17)]
(gdb) thread apply all where

Thread 15 (LWP 19):
#0  0x00007f14983baf33 in __clone () from /lib/ld-musl-x86_64.so.1
#1  0x00007f14983b8663 in ?? () from /lib/ld-musl-x86_64.so.1
#2  0x00007f14888a8b30 in ?? ()
#3  0x0000000000000000 in ?? ()

Thread 14 (LWP 20):
#0  0x00007f14983baf33 in __clone () from /lib/ld-musl-x86_64.so.1
#1  0x00007f14983b8663 in ?? () from /lib/ld-musl-x86_64.so.1
#2  0x00007f14886a4b30 in ?? ()
#3  0x0000000000000000 in ?? ()

Thread 13 (LWP 21):
#0  0x00007f14983baf33 in __clone () from /lib/ld-musl-x86_64.so.1
#1  0x00007f14983b8663 in ?? () from /lib/ld-musl-x86_64.so.1
#2  0x00007f14884a0b30 in ?? ()
#3  0x0000000000000000 in ?? ()

Thread 12 (LWP 11):
#0  0x00007f14983baf33 in __clone () from /lib/ld-musl-x86_64.so.1
#1  0x00007f14983b8663 in ?? () from /lib/ld-musl-x86_64.so.1
#2  0x00007f14898c8b30 in ?? ()
#3  0x0000000000000000 in ?? ()

Thread 11 (LWP 7):
#0  0x00007f14983baf33 in __clone () from /lib/ld-musl-x86_64.so.1
#1  0x00007f14983b8663 in ?? () from /lib/ld-musl-x86_64.so.1
#2  0x00007f14985f2bd0 in ?? () from /lib/ld-musl-x86_64.so.1
#3  0x0000000000000000 in ?? ()

Thread 10 (LWP 194):
#0  0x00007f14983baf33 in __clone () from /lib/ld-musl-x86_64.so.1
#1  0x00007f14983b8663 in ?? () from /lib/ld-musl-x86_64.so.1
#2  0x00007f14894c0b30 in ?? ()
#3  0x0000000000000000 in ?? ()

Thread 9 (LWP 263):
#0  0x00007f14983baf33 in __clone () from /lib/ld-musl-x86_64.so.1
#1  0x00007f14983b8663 in ?? () from /lib/ld-musl-x86_64.so.1
#2  0x00007f1488eb4b30 in ?? ()
#3  0x0000000000000000 in ?? ()

Thread 8 (LWP 12):
#0  0x00007f14983baf33 in __clone () from /lib/ld-musl-x86_64.so.1
#1  0x00007f14983b8663 in ?? () from /lib/ld-musl-x86_64.so.1
#2  0x00007f14896c4b30 in ?? ()
#3  0x0000000000000000 in ?? ()

Thread 7 (LWP 262):
#0  0x00007f14983baf33 in __clone () from /lib/ld-musl-x86_64.so.1
#1  0x00007f14983b8663 in ?? () from /lib/ld-musl-x86_64.so.1
#2  0x00007f1487dbcb30 in ?? ()
#3  0x0000000000000000 in ?? ()

Thread 6 (LWP 14):
#0  0x00007f14983baf33 in __clone () from /lib/ld-musl-x86_64.so.1
#1  0x00007f14983b8663 in ?? () from /lib/ld-musl-x86_64.so.1
#2  0x00007f14892bcb30 in ?? ()
#3  0x0000000000000000 in ?? ()

Thread 5 (LWP 15):
#0  0x00007f14983baf33 in __clone () from /lib/ld-musl-x86_64.so.1
#1  0x00007f14983b8663 in ?? () from /lib/ld-musl-x86_64.so.1
#2  0x00007f14890b8b30 in ?? ()
#3  0x0000000000000000 in ?? ()

Thread 4 (LWP 9):
#0  0x00007f14983baf33 in __clone () from /lib/ld-musl-x86_64.so.1
#1  0x00007f14983b8663 in ?? () from /lib/ld-musl-x86_64.so.1
#2  0x00007f1489d6cb30 in ?? ()
#3  0x0000000000000000 in ?? ()

Thread 3 (LWP 8):
#0  0x00007f14983baf33 in __clone () from /lib/ld-musl-x86_64.so.1
#1  0x00007f14983b8663 in ?? () from /lib/ld-musl-x86_64.so.1
#2  0x00007f14984edb30 in ?? ()
#3  0x0000000000000000 in ?? ()

Thread 2 (LWP 10):
#0  0x00007f14983baf33 in __clone () from /lib/ld-musl-x86_64.so.1
#1  0x00007f14983b8663 in ?? () from /lib/ld-musl-x86_64.so.1
#2  0x00007f1489b68b30 in ?? ()
#3  0x0000000000000000 in ?? ()

Thread 1 (LWP 17):
#0  0x00007f14983ac8e3 in __restore_sigs () from /lib/ld-musl-x86_64.so.1
#1  0x00007f14983ac9fd in raise () from /lib/ld-musl-x86_64.so.1
#2  0x0000000000000000 in ?? ()
(gdb) 
@akihikodaki

This comment has been minimized.

Collaborator

akihikodaki commented Mar 17, 2018

@tateisu The result seems quite a different from other reports. Is it the binary from Docker?

@tateisu

This comment has been minimized.

Contributor

tateisu commented Mar 17, 2018

  • login to sidekiq container: docker exec -it mastodon1_sidekiq_mailers_1 bash
  • add 'gdb' from alpine apt package on the container
  • run "gdb /usr/local/bin/ruby core" on the container

0xa added a commit to maastodon/mastodon-docker-builder that referenced this issue Mar 17, 2018

@akihikodaki

This comment has been minimized.

Collaborator

akihikodaki commented Mar 17, 2018

So your /usr/local/bin/ruby is the one prebuilt? It is weird…

@tateisu

This comment has been minimized.

Contributor

tateisu commented Mar 17, 2018

yes, it's default ruby binary on ruby:2.5.0-alpine3.7
I've check "nm /usr/local/bin/ruby" and "nm /usr/local/lib/libruby.so", seems it has some symbols. (I dont know it's enough to debug)

@taoeffect

This comment has been minimized.

taoeffect commented Mar 22, 2018

Hey @Gargron, are you aware that all JIT-based interpreters (e.g. python, Ruby, nodejs, etc.) need paxctl to be run on the interpreter?

Otherwise segfaults can happen. This is because Alpine uses grsecurity kernel which has special protections in place to prevent code from getting compiled + executed at runtime.

E.g. You need to install paxctl and have this in your Dockerfile:

paxctl -Cm $(which ruby)
@nightpool

This comment has been minimized.

Collaborator

nightpool commented Mar 22, 2018

@taoeffect how could this be the source of the problem if we haven't seen any errors before updating to ruby 2.5.0 from 2.4.3? And why is it only affecting sidekiq workers?

@taoeffect

This comment has been minimized.

taoeffect commented Mar 22, 2018

@taoeffect how could this be the source of the problem if we haven't seen any errors before updating to ruby 2.5.0 from 2.4.3? And why is it only affecting sidekiq workers?

All I know is that this is a known issue that will happen if you don't run paxctl on the interpreter. As to "why" it happens sometimes and not others, well, I don't know if this is what's happening this time, but it is generally true that JITs can be unpredictable, and only kick in sometimes for certain "hot spots" in the codepath, which could explain why you're only seeing it in some places and only sometimes.

So I recommend trying with the command above to see if it fixes the problem.

@akihikodaki

This comment has been minimized.

Collaborator

akihikodaki commented Mar 25, 2018

Ruby does not have JIT to execute code not loaded by the operating system. Docker uses the kernel of the host and therefore the kernel of Alpine Linux does not matter unless the host is also on Alpine Linux.

It is too thoughtless to consider it is the same problem just because both problems cause segmentation fault.

@taoeffect

This comment has been minimized.

taoeffect commented Mar 26, 2018

Docker uses the kernel of the host and therefore the kernel of Alpine Linux does not matter unless the host is also on Alpine Linux.

@akihikodaki You're right about that, I thought they were using an Alpine kernel.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment