[ruby-core:86457] [Ruby trunk Bug#14662] Stack consistency error in 2.5.1

Issue #14662 has been updated by jacobevelyn (Jacob Evelyn).


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)>'
~~~

----------------------------------------
Bug #14662: Stack consistency error in 2.5.1
https://bugs.ruby-lang.org/issues/14662#change-71393

* Author: jacobevelyn (Jacob Evelyn)
* Status: Open
* Priority: Normal
* Assignee: 
* Target version: 
* ruby -v: 2.5.1
* Backport: 2.3: UNKNOWN, 2.4: UNKNOWN, 2.5: UNKNOWN
----------------------------------------
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:

https://github.com/jeremyevans/sequel/blob/d9104d2cf0611f749a16fe93c4171a1147dfd4b2/lib/sequel/dataset/query.rb#L1257

https://github.com/rails/rails/blob/813af4655f9bf3c712cf50205eebd337070cee52/activesupport/lib/active_support/ordered_options.rb#L52

https://github.com/rails/rails/blob/813af4655f9bf3c712cf50205eebd337070cee52/activesupport/lib/active_support/log_subscriber.rb#L109

https://github.com/rails/sprockets/blob/10dada6c30016ca89662c0aa48591f071b069420/lib/sprockets/mime.rb#L122

https://github.com/rspec/rspec-core/blob/3bef84bf4cce96a4417a6550d39f53390ec81439/lib/rspec/core/example_group.rb#L52

https://github.com/rails/rails/blob/813af4655f9bf3c712cf50205eebd337070cee52/activesupport/lib/active_support/notifications/instrumenter.rb#L80

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--------------------------------
bug-14662.log (81 KB)


-- 
https://bugs.ruby-lang.org/

Unsubscribe: <mailto:[e-mail]?subject=unsubscribe>
<http://lists.ruby-lang.org/cgi-bin/mailman/options/ruby-core>