Bug #14662
closed
Stack consistency error in 2.5.1
Description
We've been trying to upgrade an app to Ruby 2.5 and are seeing interpreter crashes with Stack consistency error messages on both 2.5.0 and 2.5.1 when running our RSpec test suite. I've spent several days trying to pin this down but haven't been able to yet--it seems to happen nondeterministically about 10% of the time. I have not been able to produce these crashes on Ruby 2.4.4 or earlier (but because they're nondeterministic, it's possible I just got unlucky).
Because we randomize our test ordering, stack traces for the crashes have occurred in a handful of different places in gems we depend on, but if we run the tests in the same order (using pinned seeds) the crashes--when they occur, which is not every time, even with a pinned seed--will usually give the same stack trace.
The stack traces we've seen have pointed us to these lines in these versions of these gems:
In trying to pin this down, I've been able to reproduce with some regularity with a subset of around 100 of our tests, but not fewer. I don't know what about running all those tests triggers it -- some combination of code, or a garbage collection or timing issue. Based on which tests run (lots of complex behavior involving Queue and WeakRef) I suspected the issue might be related to https://bugs.ruby-lang.org/issues/13552, but when I checked out Ruby's git version 79d99551801812f2513dacc73b6dea716cc07096 (right before the changes for #13552), the crash--or a similar Stack consistency error--still occurred.
As I mentioned, the core dumps/stack traces vary but here's one of them from Ruby 2.5.1 (I'm happy to provide more if that's helpful):
/bundle/gems/sprockets-3.7.1/lib/sprockets/mime.rb:122: [BUG] Stack consistency error (sp: 960, bp: 959)
ruby 2.5.1p57 (2018-03-29 revision 63029) [x86_64-linux]
(snip)
Also, sometimes immediately after the Stack consistency error occurs and prints, a Segmentation fault occurs and prints the same stack trace. One additional thing I noticed is that the stack trace includes both the strings 2.5.1 and 2.5.0--I'm not sure if that's expected or the sign of a bad Ruby installation.
I know this isn't a particularly helpful bug report but I've unfortunately reached the limit of my expertise. Let me know if there's anything else I can provide or any additional investigation I can do!
Files
Updated by nobu (Nobuyoshi Nakada) over 6 years ago
- File bug-14662.log bug-14662.log added
- Description updated (diff)
Thank you for the report.
Could you try with the trunk, which would dump running instructions on the error?
Updated by jacobevelyn (Jacob Evelyn) over 6 years ago
Thanks for the quick response! Here it is in trunk (commit ab73022cb2357db5e757aed6a7c2f0c4268aa7c7):
Failure/Error: <%= stylesheet_link_tag "stylist", media: "all" %>
fatal:
Stack consistency error (sp: 960, bp: 959)
== disasm: #<ISeq:block (4 levels) in compute_extname_map@/bundle/gems/sprockets-3.7.1/lib/sprockets/mime.rb:118 (118,56)-(122,17)> (catch: FALSE)
== catch table
| catch type: redo st: 0001 ed: 0098 sp: 0000 cont: 0001
| catch type: next st: 0001 ed: 0098 sp: 0000 cont: 0098
|------------------------------------------------------------------------
local table (size: 3, argc: 1 [opts: 0, rest: -1, post: 0, block: -1, kw: -1@-1, kwrest: -1])
[ 3] engine_extnames@0<Arg>[ 2] key@1 [ 1] type@2
0000 nop ( 118)[Bc]
0001 putobject "" ( 119)[Li]
0003 getlocal pipeline_extname@1, 3
0006 dup
0007 branchiftype T_STRING, 15
0010 dup
0011 opt_send_without_block <callinfo!mid:to_s, argc:0, FCALL|ARGS_SIMPLE>, <callcache>
0014 tostring
0015 getlocal format_extname@0, 2
0018 dup
0019 branchiftype T_STRING, 27
0022 dup
0023 opt_send_without_block <callinfo!mid:to_s, argc:0, FCALL|ARGS_SIMPLE>, <callcache>
0026 tostring
0027 getlocal_WC_0 engine_extnames@0
0029 opt_send_without_block <callinfo!mid:join, argc:0, ARGS_SIMPLE>, <callcache>
0032 dup
0033 branchiftype T_STRING, 41
0036 dup
0037 opt_send_without_block <callinfo!mid:to_s, argc:0, FCALL|ARGS_SIMPLE>, <callcache>
0040 tostring
0041 concatstrings 4
0043 setlocal_WC_0 key@1
0045 getlocal format_type@1, 2 ( 120)[Li]
0048 dup
0049 branchif 69
0051 pop
0052 putself
0053 opt_send_without_block <callinfo!mid:config, argc:0, FCALL|VCALL|ARGS_SIMPLE>, <callcache>
0056 putobject :engine_mime_types
0058 opt_aref <callinfo!mid:[], argc:1, ARGS_SIMPLE>, <callcache>
0061 getlocal_WC_0 engine_extnames@0
0063 opt_send_without_block <callinfo!mid:first, argc:0, ARGS_SIMPLE>, <callcache>
0066 opt_aref <callinfo!mid:[], argc:1, ARGS_SIMPLE>, <callcache>
0069 setlocal_WC_0 type@2
0071 putnil ( 121)[Li]
0072 getlocal graph@0, 4
0075 getlocal_WC_0 key@1
0077 putobject :type
0079 getlocal_WC_0 type@2
0081 putobject :engines
0083 getlocal_WC_0 engine_extnames@0
0085 putobject :pipeline
0087 getlocal pipeline@0, 3
0090 newhash 6
0092 setn 3
0094 opt_aset <callinfo!mid:[]=, argc:2, ARGS_SIMPLE>, <callcache>
0097 pop
0098 leave ( 122)[Br]
# /bundle/gems/sprockets-3.7.1/lib/sprockets/mime.rb:122:in `block (4 levels) in compute_extname_map'
# /bundle/gems/sprockets-3.7.1/lib/sprockets/mime.rb:118:in `permutation'
# /bundle/gems/sprockets-3.7.1/lib/sprockets/mime.rb:118:in `each'
# /bundle/gems/sprockets-3.7.1/lib/sprockets/mime.rb:118:in `block (3 levels) in compute_extname_map'
# /bundle/gems/sprockets-3.7.1/lib/sprockets/mime.rb:117:in `times'
# /bundle/gems/sprockets-3.7.1/lib/sprockets/mime.rb:117:in `block (2 levels) in compute_extname_map'
# /bundle/gems/sprockets-3.7.1/lib/sprockets/mime.rb:116:in `each'
# /bundle/gems/sprockets-3.7.1/lib/sprockets/mime.rb:116:in `block in compute_extname_map'
# /bundle/gems/sprockets-3.7.1/lib/sprockets/mime.rb:114:in `each'
# /bundle/gems/sprockets-3.7.1/lib/sprockets/mime.rb:114:in `compute_extname_map'
# /bundle/gems/sprockets-3.7.1/lib/sprockets/mime.rb:108:in `extname_map'
# /bundle/gems/sprockets-3.7.1/lib/sprockets/resolve.rb:201:in `parse_path_extnames'
# /bundle/gems/sprockets-3.7.1/lib/sprockets/resolve.rb:105:in `resolve_logical_path'
# /bundle/gems/sprockets-3.7.1/lib/sprockets/resolve.rb:35:in `resolve'
# /bundle/gems/sprockets-3.7.1/lib/sprockets/legacy.rb:66:in `resolve_with_compat'
# /bundle/gems/sprockets-3.7.1/lib/sprockets/base.rb:64:in `find_asset'
# /bundle/gems/sprockets-3.7.1/lib/sprockets/base.rb:92:in `[]'
# /bundle/gems/sprockets-rails-3.2.1/lib/sprockets/rails/helper.rb:355:in `find_asset'
# /bundle/gems/sprockets-rails-3.2.1/lib/sprockets/rails/helper.rb:336:in `digest_path'
# /bundle/gems/sprockets-rails-3.2.1/lib/sprockets/rails/helper.rb:325:in `asset_path'
# /bundle/gems/sprockets-rails-3.2.1/lib/sprockets/rails/helper.rb:102:in `block in resolve_asset_path'
# /bundle/gems/sprockets-rails-3.2.1/lib/sprockets/rails/helper.rb:242:in `block in resolve_asset'
# /bundle/gems/sprockets-rails-3.2.1/lib/sprockets/rails/helper.rb:241:in `each'
# /bundle/gems/sprockets-rails-3.2.1/lib/sprockets/rails/helper.rb:241:in `detect'
# /bundle/gems/sprockets-rails-3.2.1/lib/sprockets/rails/helper.rb:241:in `resolve_asset'
# /bundle/gems/sprockets-rails-3.2.1/lib/sprockets/rails/helper.rb:101:in `resolve_asset_path'
# /bundle/gems/sprockets-rails-3.2.1/lib/sprockets/rails/helper.rb:79:in `compute_asset_path'
# /bundle/gems/sprockets-rails-3.2.1/lib/sprockets/rails/helper.rb:185:in `block in stylesheet_link_tag'
# /bundle/gems/sprockets-rails-3.2.1/lib/sprockets/rails/helper.rb:183:in `map'
# /bundle/gems/sprockets-rails-3.2.1/lib/sprockets/rails/helper.rb:183:in `stylesheet_link_tag'
# ./app/views/stylist/index.html.erb:7:in `_app_views_stylist_index_html_erb__3484216634633236914_47095196963200'
# /bundle/gems/rack-mini-profiler-0.10.5/lib/mini_profiler/profiling_methods.rb:76:in `block in profile_method'
# /bundle/gems/sequel-rails-0.9.17/lib/sequel_rails/railties/controller_runtime.rb:24:in `cleanup_view_runtime'
# ./app/controllers/stylist_controller.rb:3:in `index'
# /bundle/gems/sequel-rails-0.9.17/lib/sequel_rails/railties/controller_runtime.rb:18:in `process_action'
# /bundle/gems/rack-mini-profiler-0.10.5/lib/mini_profiler/profiling_methods.rb:76:in `block in profile_method'
# /bundle/gems/rails-controller-testing-0.1.1/lib/rails/controller/testing/template_assertions.rb:61:in `process'
# /bundle/gems/devise-4.4.1/lib/devise/test/controller_helpers.rb:35:in `block in process'
# /bundle/gems/devise-4.4.1/lib/devise/test/controller_helpers.rb:102:in `catch'
# /bundle/gems/devise-4.4.1/lib/devise/test/controller_helpers.rb:102:in `_catch_warden'
# /bundle/gems/devise-4.4.1/lib/devise/test/controller_helpers.rb:35:in `process'
# /bundle/gems/gon-6.1.0/lib/gon/spec_helpers.rb:15:in `process'
# /bundle/gems/rails-controller-testing-0.1.1/lib/rails/controller/testing/integration.rb:12:in `block (2 levels) in <module:Integration>'
# ./spec/controllers/stylist_controller_spec.rb:10:in `block (3 levels) in <top (required)>'
# ./spec/controllers/stylist_controller_spec.rb:14:in `block (3 levels) in <top (required)>'
# ./spec/rails_helper.rb:69:in `block (3 levels) in <top (required)>'
# /bundle/gems/sequel-4.49.0/lib/sequel/database/transactions.rb:217:in `_transaction'
# /bundle/gems/sequel-4.49.0/lib/sequel/database/transactions.rb:199:in `block in transaction'
# /bundle/gems/sequel-4.49.0/lib/sequel/database/connecting.rb:301:in `block in synchronize'
# /bundle/gems/sequel-4.49.0/lib/sequel/connection_pool/threaded.rb:107:in `hold'
# /bundle/gems/sequel-4.49.0/lib/sequel/database/connecting.rb:301:in `synchronize'
# /bundle/gems/sequel-4.49.0/lib/sequel/database/transactions.rb:165:in `transaction'
# ./spec/rails_helper.rb:69:in `block (2 levels) in <top (required)>'
Updated by jacobevelyn (Jacob Evelyn) over 6 years ago
Is there anything else I can do to help investigate this?
Updated by nobu (Nobuyoshi Nakada) over 6 years ago
The dumped instructions seem no problem.
Can't you make small code to reproduce?
Updated by jacobevelyn (Jacob Evelyn) over 6 years ago
Unfortunately I haven't found a way to reproduce this without a large portion of our code running, and because the error happens in different places I haven't been able to track it down. I'll keep trying but I think it is unlikely that I'll be able to. :(
Updated by jeremyevans0 (Jeremy Evans) about 5 years ago
- Status changed from Open to Closed