Project

General

Profile

Actions
Copy link

Bug #15395

closed

Stack consistency error (2.6.0-rc1, JIT)

Added by Tietew (Toru Iwase) over 5 years ago. Updated over 5 years ago.

Status:
Closed
Assignee:
k0kubun (Takashi Kokubun)
Target version:
-
ruby -v:
ruby 2.6.0dev (2018-12-10 trunk 66307) [x86_64-linux]
Backport:
2.4: UNKNOWN, 2.5: UNKNOWN
[ruby-dev:50690]

Description

ものは試しと Rails 5.2.2 app をJIT下で動かしたところ、Stack consistency error になりました。

OS: Ubuntu 18.04.1 TLS
GCC: 7.3.0-27ubuntu1~18.04
Puma Started as: $ ruby --jit-verbose=1 --jit-save-temps bin/rails server -pXXXX
Ruby versions:
ruby 2.6.0rc1 (2018-12-06 trunk 66253) [x86_64-linux]
ruby 2.6.0dev (2018-12-10 trunk 66307) [x86_64-linux]

最初は順調だったのですが、しばらくJITコンパイルが落ち着くのを待ってから遷移したところエラーが出ました。
2度試して、2度とも同じ箇所でエラーが出たのですが、このクラスだけ切り出しても再現しませんでした。
ただしtrunkの最新版でも再現しました。
修正のヒントになればいいと思いポストします。

Error Message:

fatal (Stack consistency error (sp: 801, bp: 802)
== disasm: #<ISeq:block in each@/home/***/vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/map.rb:21 (21,16)-(21,40)> (catch: FALSE)
== catch table
| catch type: redo   st: 0001 ed: 0011 sp: 0000 cont: 0001
| catch type: next   st: 0001 ed: 0011 sp: 0000 cont: 0011
|------------------------------------------------------------------------
local table (size: 1, argc: 1 [opts: 0, rest: -1, post: 0, block: -1, kw: -1@-1, kwrest: -1])
[ 1] k@0<Arg>
0000 nop                                                              (  21)[Bc]
0001 getlocal_WC_0                k@0[Li]
0003 putself
0004 getlocal_WC_0                k@0
0006 opt_aref                     <callinfo!mid:[], argc:1, FCALL|ARGS_SIMPLE>, <callcache>
0009 invokeblock                  <callinfo!argc:2, ARGS_SIMPLE>
0011 leave                        [Br]
):

Ruby code:
https://github.com/judofyr/temple/blob/v0.8.0/lib/temple/map.rb

module Temple
  class ImmutableMap
    include Enumerable
    # (snip)
    def each
      keys.each {|k| yield(k, self[k]) } # <= here
    end

Compiled C code:

#include "/tmp/_ruby_mjit_hp24627u0.h"
/* block in each@/home/***/vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/map.rb:21 */

#undef OPT_CHECKED_RUN
#define OPT_CHECKED_RUN 0

VALUE
_mjit1128(rb_execution_context_t *ec, rb_control_frame_t *reg_cfp)
{
    VALUE stack[3];
    static const VALUE *const original_body_iseq = (VALUE *)0x5559463fe030;

label_0: /* nop */
{
    MAYBE_UNUSED(unsigned int) stack_size = 0;
    {
        /* none */
    }
}

label_1: /* getlocal_WC_0 */
{
    MAYBE_UNUSED(unsigned int) stack_size = 0;
    MAYBE_UNUSED(VALUE) val;
    MAYBE_UNUSED(lindex_t) idx;
    MAYBE_UNUSED(rb_num_t) level;
    level = 0;
    idx = (lindex_t)0x3;
    {
        val = *(vm_get_ep(GET_EP(), level) - idx);
        RB_DEBUG_COUNTER_INC(lvar_get);
        (void)RB_DEBUG_COUNTER_INC_IF(lvar_get_dynamic, level > 0);
    }
    stack[0] = val;
}

label_3: /* putself */
{
    MAYBE_UNUSED(unsigned int) stack_size = 1;
    MAYBE_UNUSED(VALUE) val;
    {
        val = GET_SELF();
    }
    stack[1] = val;
}

label_4: /* getlocal_WC_0 */
{
    MAYBE_UNUSED(unsigned int) stack_size = 2;
    MAYBE_UNUSED(VALUE) val;
    MAYBE_UNUSED(lindex_t) idx;
    MAYBE_UNUSED(rb_num_t) level;
    level = 0;
    idx = (lindex_t)0x3;
    {
        val = *(vm_get_ep(GET_EP(), level) - idx);
        RB_DEBUG_COUNTER_INC(lvar_get);
        (void)RB_DEBUG_COUNTER_INC_IF(lvar_get_dynamic, level > 0);
    }
    stack[2] = val;
}

label_6: /* opt_aref */
{
    MAYBE_UNUSED(unsigned int) stack_size = 3;
    if (UNLIKELY(GET_GLOBAL_METHOD_STATE() != 195 ||
        RCLASS_SERIAL(CLASS_OF(stack[1])) != 129007)) {
        reg_cfp->pc = original_body_iseq + 6;
        reg_cfp->sp = (VALUE *)reg_cfp->bp + 4;
        goto cancel;
    }
    reg_cfp->pc = original_body_iseq + 9;
    reg_cfp->sp = (VALUE *)reg_cfp->bp + 2 + 1;
    *(reg_cfp->sp + -2) = stack[1];
    *(reg_cfp->sp + -1) = stack[2];
    {
        struct rb_calling_info calling;
        calling.block_handler = VM_BLOCK_HANDLER_NONE;
        calling.argc = 1;
        calling.recv = stack[1];
        {
            VALUE v;
            vm_call_iseq_setup_normal(ec, reg_cfp, &calling, (const rb_callable_method_entry_t *)0x5559464066f0, 0, 1, 1);
            if ((v = mjit_exec(ec)) == Qundef) {
                VM_ENV_FLAGS_SET(ec->cfp->ep, VM_FRAME_FLAG_FINISH);
                v = vm_exec(ec, FALSE);
            }
            stack[1] = v;
        }
    }
    if (UNLIKELY(ruby_vm_event_enabled_global_flags & ISEQ_TRACE_EVENTS)) {
        reg_cfp->sp = (VALUE *)reg_cfp->bp + 3;
        goto cancel;
    }
}

label_9: /* invokeblock */
{
    MAYBE_UNUSED(unsigned int) stack_size = 2;
    MAYBE_UNUSED(CALL_INFO) ci;
    MAYBE_UNUSED(VALUE) val;
    ci = (CALL_INFO)0x5559463fdef0;
    reg_cfp->pc = original_body_iseq + 11;
    reg_cfp->sp = (VALUE *)reg_cfp->bp + 2 + 1;
    *(reg_cfp->sp + -2) = stack[0];
    *(reg_cfp->sp + -1) = stack[1];
    {
        struct rb_calling_info calling;
        VALUE block_handler;

        calling.argc = ci->orig_argc;
        calling.block_handler = VM_BLOCK_HANDLER_NONE;
        calling.recv = Qundef; /* should not be used */

        block_handler = VM_CF_BLOCK_HANDLER(GET_CFP());
        if (block_handler == VM_BLOCK_HANDLER_NONE) {
            rb_vm_localjump_error("no block given (yield)", Qnil, 0);
        }

        val = vm_invoke_block(ec, GET_CFP(), &calling, ci, block_handler);
        if (val == Qundef) {
            EXEC_EC_CFP(val);
        }
    }
    stack[0] = val;
    if (UNLIKELY(ruby_vm_event_enabled_global_flags & ISEQ_TRACE_EVENTS)) {
        reg_cfp->sp = (VALUE *)reg_cfp->bp + 2;
        goto cancel;
    }
}

label_11: /* leave */
{
    MAYBE_UNUSED(unsigned int) stack_size = 1;
    MAYBE_UNUSED(VALUE) val;
    val = stack[0];
    reg_cfp->pc = original_body_iseq + 12;
    reg_cfp->sp = (VALUE *)reg_cfp->bp + 0 + 1;
    {
        if (OPT_CHECKED_RUN) {
            const VALUE *const bp = vm_base_ptr(reg_cfp);
            if (reg_cfp->sp != bp) {
                vm_stack_consistency_error(ec, reg_cfp, bp);
            }
        }

        RUBY_VM_CHECK_INTS(ec);

        if (vm_pop_frame(ec, GET_CFP(), GET_EP())) {
#if OPT_CALL_THREADED_CODE
            rb_ec_thread_ptr(ec)->retval = val;
            return 0;
#else
            return val;
#endif
        }
        else {
#if OPT_CALL_THREADED_CODE
            rb_ec_thread_ptr(ec)->retval = val;
            return 0;
#else
            return val;
#endif
        }
    }
    stack[0] = val;
    if (UNLIKELY(ruby_vm_event_enabled_global_flags & ISEQ_TRACE_EVENTS)) {
        reg_cfp->sp = (VALUE *)reg_cfp->bp + 2;
        goto cancel;
    }
}

cancel:
    *((VALUE *)reg_cfp->bp + 1) = stack[0];
    *((VALUE *)reg_cfp->bp + 2) = stack[1];
    *((VALUE *)reg_cfp->bp + 3) = stack[2];
    return Qundef;

} /* end of _mjit1128 */

Stack Trace:

vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/map.rb:21:in `block in each'
vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/map.rb:21:in `each'
vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/map.rb:21:in `each'
vendor/bundle/ruby/2.6.0/gems/haml-5.0.4/lib/haml/options.rb:172:in `initialize'
vendor/bundle/ruby/2.6.0/gems/haml-5.0.4/lib/haml/options.rb:44:in `new'
vendor/bundle/ruby/2.6.0/gems/haml-5.0.4/lib/haml/options.rb:44:in `wrap'
vendor/bundle/ruby/2.6.0/gems/haml-5.0.4/lib/haml/parser.rb:93:in `initialize'
vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/mixins/engine_dsl.rb:101:in `new'
vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/mixins/engine_dsl.rb:101:in `block in chain_proc_constructor'
vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/engine.rb:61:in `block in call_chain'
vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/engine.rb:60:in `map'
vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/engine.rb:60:in `call_chain'
vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/engine.rb:50:in `call'
vendor/bundle/ruby/2.6.0/gems/haml-5.0.4/lib/haml/temple_engine.rb:41:in `compile'
vendor/bundle/ruby/2.6.0/gems/haml-5.0.4/lib/haml/engine.rb:61:in `initialize'
vendor/bundle/ruby/2.6.0/gems/haml-5.0.4/lib/haml/plugin.rb:16:in `new'
vendor/bundle/ruby/2.6.0/gems/haml-5.0.4/lib/haml/plugin.rb:16:in `compile'
vendor/bundle/ruby/2.6.0/gems/haml-5.0.4/lib/haml/plugin.rb:23:in `call'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/template.rb:283:in `compile'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/template.rb:259:in `block (2 levels) in compile!'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.2/lib/active_support/notifications.rb:170:in `instrument'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/template.rb:350:in `instrument'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/template.rb:258:in `block in compile!'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/template.rb:246:in `synchronize'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/template.rb:246:in `compile!'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/template.rb:158:in `block in render'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.2/lib/active_support/notifications.rb:170:in `instrument'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/template.rb:354:in `instrument_render_template'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/template.rb:157:in `render'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/renderer/template_renderer.rb:54:in `block (2 levels) in render_template'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/renderer/abstract_renderer.rb:44:in `block in instrument'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.2/lib/active_support/notifications.rb:168:in `block in instrument'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.2/lib/active_support/notifications/instrumenter.rb:23:in `instrument'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.2/lib/active_support/notifications.rb:168:in `instrument'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/renderer/abstract_renderer.rb:43:in `instrument'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/renderer/template_renderer.rb:53:in `block in render_template'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/renderer/template_renderer.rb:61:in `render_with_layout'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/renderer/template_renderer.rb:52:in `render_template'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/renderer/template_renderer.rb:16:in `render'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/renderer/renderer.rb:44:in `render_template'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/renderer/renderer.rb:25:in `render'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/rendering.rb:103:in `_render_template'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal/streaming.rb:219:in `_render_template'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/rendering.rb:84:in `render_to_body'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal/rendering.rb:52:in `render_to_body'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal/renderers.rb:142:in `render_to_body'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/abstract_controller/rendering.rb:25:in `render'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal/rendering.rb:36:in `render'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal/instrumentation.rb:46:in `block (2 levels) in render'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.2/lib/active_support/core_ext/benchmark.rb:14:in `block in ms'
/usr/local/anyenv/envs/rbenv/versions/2.6.0-rc1/lib/ruby/2.6.0/benchmark.rb:308:in `realtime'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.2/lib/active_support/core_ext/benchmark.rb:14:in `ms'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal/instrumentation.rb:46:in `block in render'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal/instrumentation.rb:87:in `cleanup_view_runtime'
vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.2/lib/active_record/railties/controller_runtime.rb:31:in `cleanup_view_runtime'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal/instrumentation.rb:45:in `render'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal/implicit_render.rb:35:in `default_render'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal/basic_implicit_render.rb:6:in `block in send_action'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal/basic_implicit_render.rb:6:in `tap'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/abstract_controller/base.rb:194:in `process_action'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal/rendering.rb:30:in `process_action'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:132:in `run_callbacks'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/abstract_controller/callbacks.rb:41:in `process_action'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal/rescue.rb:22:in `process_action'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.2/lib/active_support/notifications.rb:168:in `block in instrument'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.2/lib/active_support/notifications/instrumenter.rb:23:in `instrument'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.2/lib/active_support/notifications.rb:168:in `instrument'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal/instrumentation.rb:32:in `process_action'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal/params_wrapper.rb:256:in `process_action'
vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.2/lib/active_record/railties/controller_runtime.rb:24:in `process_action'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/abstract_controller/base.rb:134:in `process'
vendor/bundle/ruby/2.6.0/gems/actionview-5.2.2/lib/action_view/rendering.rb:32:in `process'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal.rb:191:in `dispatch'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_controller/metal.rb:252:in `dispatch'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_dispatch/routing/route_set.rb:52:in `dispatch'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_dispatch/routing/route_set.rb:34:in `serve'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_dispatch/journey/router.rb:52:in `block in serve'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_dispatch/journey/router.rb:35:in `each'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_dispatch/journey/router.rb:35:in `serve'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_dispatch/routing/route_set.rb:840:in `call'
vendor/bundle/ruby/2.6.0/gems/http_accept_language-2.1.1/lib/http_accept_language/middleware.rb:14:in `call'
vendor/bundle/ruby/2.6.0/gems/rack-2.0.6/lib/rack/tempfile_reaper.rb:15:in `call'
vendor/bundle/ruby/2.6.0/gems/rack-2.0.6/lib/rack/etag.rb:25:in `call'
vendor/bundle/ruby/2.6.0/gems/rack-2.0.6/lib/rack/conditional_get.rb:25:in `call'
vendor/bundle/ruby/2.6.0/gems/rack-2.0.6/lib/rack/head.rb:12:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_dispatch/http/content_security_policy.rb:18:in `call'
vendor/bundle/ruby/2.6.0/gems/rack-2.0.6/lib/rack/session/abstract/id.rb:232:in `context'
vendor/bundle/ruby/2.6.0/gems/rack-2.0.6/lib/rack/session/abstract/id.rb:226:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/cookies.rb:670:in `call'
vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.2/lib/active_record/migration.rb:559:in `call'
config/initializers/check_access_control.rb:14:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:98:in `run_callbacks'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/executor.rb:14:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/debug_exceptions.rb:61:in `call'
vendor/bundle/ruby/2.6.0/gems/web-console-3.7.0/lib/web_console/middleware.rb:135:in `call_app'
vendor/bundle/ruby/2.6.0/gems/web-console-3.7.0/lib/web_console/middleware.rb:30:in `block in call'
vendor/bundle/ruby/2.6.0/gems/web-console-3.7.0/lib/web_console/middleware.rb:20:in `catch'
vendor/bundle/ruby/2.6.0/gems/web-console-3.7.0/lib/web_console/middleware.rb:20:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
vendor/bundle/ruby/2.6.0/gems/railties-5.2.2/lib/rails/rack/logger.rb:38:in `call_app'
vendor/bundle/ruby/2.6.0/gems/railties-5.2.2/lib/rails/rack/logger.rb:26:in `block in call'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.2/lib/active_support/tagged_logging.rb:71:in `block in tagged'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.2/lib/active_support/tagged_logging.rb:28:in `tagged'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.2/lib/active_support/tagged_logging.rb:71:in `tagged'
vendor/bundle/ruby/2.6.0/gems/railties-5.2.2/lib/rails/rack/logger.rb:26:in `call'
vendor/bundle/ruby/2.6.0/gems/sprockets-rails-3.2.1/lib/sprockets/rails/quiet_assets.rb:13:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/request_id.rb:27:in `call'
vendor/bundle/ruby/2.6.0/gems/rack-2.0.6/lib/rack/method_override.rb:22:in `call'
vendor/bundle/ruby/2.6.0/gems/rack-2.0.6/lib/rack/runtime.rb:22:in `call'
vendor/bundle/ruby/2.6.0/gems/activesupport-5.2.2/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/executor.rb:14:in `call'
vendor/bundle/ruby/2.6.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/static.rb:127:in `call'
vendor/bundle/ruby/2.6.0/gems/rack-2.0.6/lib/rack/sendfile.rb:111:in `call'
vendor/bundle/ruby/2.6.0/gems/railties-5.2.2/lib/rails/engine.rb:524:in `call'
vendor/bundle/ruby/2.6.0/gems/puma-3.12.0/lib/puma/configuration.rb:225:in `call'
vendor/bundle/ruby/2.6.0/gems/puma-3.12.0/lib/puma/server.rb:658:in `handle_request'
vendor/bundle/ruby/2.6.0/gems/puma-3.12.0/lib/puma/server.rb:472:in `process_client'
vendor/bundle/ruby/2.6.0/gems/puma-3.12.0/lib/puma/server.rb:332:in `block in run'
vendor/bundle/ruby/2.6.0/gems/puma-3.12.0/lib/puma/thread_pool.rb:133:in `block in spawn_thread'
Actions
Copy link
 #1 [ruby-dev:50691]

Updated by k0kubun (Takashi Kokubun) over 5 years ago

  • Assignee set to k0kubun (Takashi Kokubun)
Actions
Copy link
 #2 [ruby-dev:50693]

Updated by k0kubun (Takashi Kokubun) over 5 years ago

手元でHamlを使った簡単なアプリ https://github.com/k0kubun/railsapp/tree/bug15398 を作ったところ再現できました。
デバッグ中に--jitなしでrailsを起動している最中bootsnapでSEGVしてしまったのでbootsnapを無効にしてみたところ、再現しなくなりました。もしお使いの開発環境でbootsnapを有効にしている場合、Gemfileの gem 'bootsnap' とconfig/boot.rbの require 'bootsnap/setup' をコメントアウトして再現するかご確認いただけないでしょうか。

また、その状態でも再現できた場合は、 ruby --jit-verbose=1 --jit-save-temps bin/rails server -pXXXX で起動するコマンドからSEGVするまでの出力のうち、コンパイルされたメソッドの一覧とSEGVの出力部分を可能な限り全てご共有いただけると助かります。JITコンパイル済のメソッド一覧とCのバックトレース全体を確認したいためです。

Actions
Copy link
 #3 [ruby-dev:50698]

Updated by Tietew (Toru Iwase) over 5 years ago

bootsnapを無効にしたところ、再現しなくなりました。
なお明記しませんでしたが、SEGVはしていません。
ただしPumaがfatalが起きても動き続けていたせいか、^Cで落とせずにKILLしました。

追試：

  • bootsnapを有効にしつつ、bootsnapのキャッシュを削除して起動→再現せず
  • そのままPumaを再起動→再現、かつ [BUG] vm_call_cfunc: cfp consistency error (0x00005634298876e8, 0x0000563429887b80) でSEGV
Actions
Copy link
 #4 [ruby-dev:50699]

Updated by k0kubun (Takashi Kokubun) over 5 years ago

承知しました。切り分けの助けになります、ありがとうございます。

なお明記しませんでしたが、SEGVはしていません。

これに関して、"--jitなしでrailsを起動している最中bootsnapでSEGVしてしまった" のはload_from_binary内で、cfp consistency errorとは全く別の問題の話でした。混同させてしまったようでしたらすみません。
いずれにせよ、これら2つの問題からbootsnapが現在Ruby 2.6では正しく動作しないように見えるため、ひとまずbootsnapを無効にしてお試しいただければと思います。

Actions
Copy link
 #5 [ruby-dev:50700]

Updated by Tietew (Toru Iwase) over 5 years ago

これで再現しました。ただ、temple/map.rb そのままじゃないと再現しないので、何が引っかかっているのか。

Gemfile

source "https://rubygems.org"
gem "bootsnap", require: false
gem "temple"

test.rb

require 'bundler/setup'
require 'bootsnap'
Bootsnap.setup(
  cache_dir: 'bootsnap',
  development_mode: true,
  load_path_cache: true,
  autoload_paths_cache: false,
  disable_trace: false,
  compile_cache_iseq: true,
  compile_cache_yaml: true
)

require 'temple/map'

orig = {}
10000.times { orig[rand(100000)] = rand(100000) }

a = Temple::ImmutableMap.new(orig)
i = 0
1000.times { a.each { |k, v| puts(i += 1) } }

Run:

$ ruby --jit-verbose=1 test.rb
1
2
...(snip)...
94735
94736
94737JIT success (98.6ms): block (2 levels) in initialize@/home/tietew/projects/test/ruby260/vendor/bundle/ruby/2.6.0/gems/bootsnap-1.3.2/lib/bootsnap/load_path_cache/loaded_features_index.rb:35 -> /tmp/_ruby_mjit_p30674u328.c

94738
94739
...(snip)...
162234
162235
1622JIT success (297.5ms): block in each@/home/tietew/projects/test/ruby260/vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/map.rb:21 -> /tmp/_ruby_mjit_p30674u368.c
36
162237
162238
...(snip)...
214929
214930
2149JIT success (98.7ms): []@/home/tietew/projects/test/ruby260/vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/map.rb:15 -> /tmp/_ruby_mjit_p30674u369.c
31
214932
214933
...(snip)...
216099
216100
216101/home/tietew/projects/test/ruby260/vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/map.rb:21:in `block in each': Stack consistency error (sp: 27, bp: 28) (fatal)
== disasm: #<ISeq:block in each@/home/tietew/projects/test/ruby260/vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/map.rb:21 (21,16)-(21,40)> (catch: FALSE)
== catch table
| catch type: redo   st: 0001 ed: 0011 sp: 0000 cont: 0001
| catch type: next   st: 0001 ed: 0011 sp: 0000 cont: 0011
|------------------------------------------------------------------------
local table (size: 1, argc: 1 [opts: 0, rest: -1, post: 0, block: -1, kw: -1@-1, kwrest: -1])
[ 1] k@0<Arg>
0000 nop                                                              (  21)[Bc]
0001 getlocal_WC_0                k@0[Li]
0003 putself
0004 getlocal_WC_0                k@0
0006 opt_aref                     <callinfo!mid:[], argc:1, FCALL|ARGS_SIMPLE>, <callcache>
0009 invokeblock                  <callinfo!argc:2, ARGS_SIMPLE>
0011 leave                        [Br]
	from /home/tietew/projects/test/ruby260/vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/map.rb:21:in `each'
	from /home/tietew/projects/test/ruby260/vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/map.rb:21:in `each'
	from test.rb:20:in `block in <main>'
	from test.rb:20:in `times'
	from test.rb:20:in `<main>'
JIT success (95.5ms): block in []@/home/tietew/projects/test/ruby260/vendor/bundle/ruby/2.6.0/gems/temple-0.8.0/lib/temple/map.rb:16 -> /tmp/_ruby_mjit_p30674u370.c
Successful MJIT finish

216102
Actions
Copy link
 #6 [ruby-dev:50701]

Updated by k0kubun (Takashi Kokubun) over 5 years ago

再現コードを小さくしていただきありがとうございます。非常に助かります。

Actions
Copy link
 #7

Updated by ko1 (Koichi Sasada) over 5 years ago

  • Status changed from Open to Closed

Applied in changeset trunk|r66366.

restore catch_except_p flag.

  • compile.c: we need to restore catch_except_p flag at
    load_from_binary. [Bug #15395]
Actions
Copy link
 #8 [ruby-dev:50703]

Updated by ko1 (Koichi Sasada) over 5 years ago

r66366 で治るんじゃないかと思うんですが、試して頂けませんでしょうか。
よろしくお願いします。

Actions
Copy link
 #9 [ruby-dev:50704]

Updated by Tietew (Toru Iwase) over 5 years ago

治りました。
ruby 2.6.0dev (2018-12-13 trunk 66372) [x86_64-linux]
で試しまして、テストコードのほうもRailsのほうも落ちなくなりました。
ありがとうございます。

Actions
Copy link

Also available in: Atom PDF

Like0
Like0Like0Like0Like0Like0Like0Like0Like0Like0