Bug #17289: Time#strftime occurs Segmentation Fault on ruby-2.7.2p137

• Status: Feedback
• Assignee: shyouhei (Shyouhei Urabe)
• Target version: -
• ruby -v: ruby 2.7.2p137 (2020-10-01 revision 5445e04352) [x86_64-linux]
• Backport: 2.5: UNKNOWN, 2.6: UNKNOWN, 2.7: REQUIRED

[joker1007 (Tomohiro Hashidate)]

Segmentation Fault occurred when I run Time#strftime via Time#iso8601 on ruby-2.7.2.
It occurs repeatedly about once a day in our system.
Because it was not possible to make a reproduction case in a simple environment, I share the C Level backtrace and the control frame information at the time of occurrence.

Also, I used strptime gem (https://github.com/nurse/strptime) to create the Time object.

Ruby version: ruby 2.7.2p137 (2020-10-01 revision 5445e04352) [x86_64-linux]

/opt/ruby/lib/ruby/2.7.0/time.rb:732: [BUG] Segmentation fault at 0x0000000077359419
ruby 2.7.2p137 (2020-10-01 revision 5445e04352) [x86_64-linux]
-- Control frame information -----------------------------------------------
c:0065 p:---- s:0380 e:000379 CFUNC  :*
c:0064 p:---- s:0377 e:000376 CFUNC  :strftime
c:0063 p:0014 s:0372 e:000371 METHOD /opt/ruby/lib/ruby/2.7.0/time.rb:732

-- C level backtrace information -------------------------------------------
/opt/ruby/lib/libruby.so.2.7(rb_vm_bugreport+0x54c) [0x7fc11890cf5c] vm_dump.c:755
/opt/ruby/lib/libruby.so.2.7(rb_bug_for_fatal_signal+0xe7) [0x7fc11873c937] error.c:660
/opt/ruby/lib/libruby.so.2.7(sigsegv+0x4b) [0x7fc1188732ab] signal.c:946
/lib/x86_64-linux-gnu/libpthread.so.0(__restore_rt+0x0) [0x7fc1182500e0]
/opt/ruby/lib/libruby.so.2.7(rb_rational_mul+0x40) [0x7fc1188370b0] rational.c:898
/opt/ruby/lib/libruby.so.2.7(vm_call0_cfunc_with_frame+0x10a) [0x7fc1188fe790] vm_eval.c:91
/opt/ruby/lib/libruby.so.2.7(vm_call0_cfunc) vm_eval.c:105
/opt/ruby/lib/libruby.so.2.7(vm_call0_body) vm_eval.c:140
/opt/ruby/lib/libruby.so.2.7(rb_funcallv_with_cc+0xdb) [0x7fc11890157b] vm_eval.c:1013
/opt/ruby/lib/libruby.so.2.7(mulv+0x50) [0x7fc1188bbf50] time.c:116
/opt/ruby/lib/libruby.so.2.7(timew_out_of_timet_range+0x1c) [0x7fc1188c2ef4] time.c:1664
/opt/ruby/lib/libruby.so.2.7(localtimew) time.c:1677
/opt/ruby/lib/libruby.so.2.7(time_localtime+0x61) [0x7fc1188c3411] time.c:3816
/opt/ruby/lib/libruby.so.2.7(time_strftime+0x7b) [0x7fc1188c53eb] time.c:5076
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc_with_frame+0xcf) [0x7fc1188e95a6] vm_insnhelper.c:2514
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc) vm_insnhelper.c:2539
/opt/ruby/lib/libruby.so.2.7(vm_sendish+0xa3) [0x7fc1188f55a7] vm_insnhelper.c:4023
/opt/ruby/lib/libruby.so.2.7(vm_exec_core) insns.def:801
/opt/ruby/lib/libruby.so.2.7(rb_vm_exec+0xab) [0x7fc1188fb6fb] vm.c:1920
/opt/ruby/lib/libruby.so.2.7(invoke_block+0x167) [0x7fc1189069d3] vm.c:1044
/opt/ruby/lib/libruby.so.2.7(invoke_iseq_block_from_c) vm.c:1116
/opt/ruby/lib/libruby.so.2.7(invoke_block_from_c_bh) vm.c:1134
/opt/ruby/lib/libruby.so.2.7(vm_yield) vm.c:1179
/opt/ruby/lib/libruby.so.2.7(rb_yield_0) vm_eval.c:1227
/opt/ruby/lib/libruby.so.2.7(rb_yield_1) vm_eval.c:1233
/opt/ruby/lib/libruby.so.2.7(int_dotimes+0x50) [0x7fc1187d8ac0] numeric.c:5201
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc_with_frame+0xcf) [0x7fc1188e95a6] vm_insnhelper.c:2514
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc) vm_insnhelper.c:2539
/opt/ruby/lib/libruby.so.2.7(vm_sendish+0x56) [0x7fc1188f6ab5] vm_insnhelper.c:4023
/opt/ruby/lib/libruby.so.2.7(vm_exec_core) insns.def:782
/opt/ruby/lib/libruby.so.2.7(rb_vm_exec+0x898) [0x7fc1188fbee8] vm.c:1929
/opt/ruby/lib/libruby.so.2.7(invoke_block+0x166) [0x7fc118906e19] vm.c:1044
/opt/ruby/lib/libruby.so.2.7(invoke_iseq_block_from_c) vm.c:1116
/opt/ruby/lib/libruby.so.2.7(invoke_block_from_c_bh) vm.c:1134
/opt/ruby/lib/libruby.so.2.7(vm_yield) vm.c:1179
/opt/ruby/lib/libruby.so.2.7(rb_yield_0) vm_eval.c:1227
/opt/ruby/lib/libruby.so.2.7(rb_yield_1) vm_eval.c:1233
/opt/ruby/lib/libruby.so.2.7(rb_yield) vm_eval.c:1243
/opt/ruby/lib/libruby.so.2.7(rb_array_len+0x0) [0x7fc1186ac63c] array.c:2135
/opt/ruby/lib/libruby.so.2.7(rb_ary_each) array.c:2134
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc_with_frame+0xcf) [0x7fc1188e95a6] vm_insnhelper.c:2514
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc) vm_insnhelper.c:2539
/opt/ruby/lib/libruby.so.2.7(vm_sendish+0x56) [0x7fc1188f6ab5] vm_insnhelper.c:4023
/opt/ruby/lib/libruby.so.2.7(vm_exec_core) insns.def:782
/opt/ruby/lib/libruby.so.2.7(rb_vm_exec+0xab) [0x7fc1188fb6fb] vm.c:1920
/opt/ruby/lib/libruby.so.2.7(invoke_block+0x167) [0x7fc118906593] vm.c:1044
/opt/ruby/lib/libruby.so.2.7(invoke_iseq_block_from_c) vm.c:1116
/opt/ruby/lib/libruby.so.2.7(invoke_block_from_c_bh) vm.c:1134
/opt/ruby/lib/libruby.so.2.7(vm_yield) vm.c:1179
/opt/ruby/lib/libruby.so.2.7(rb_yield_0) vm_eval.c:1227
/opt/ruby/lib/libruby.so.2.7(catch_i) vm_eval.c:2228
/opt/ruby/lib/libruby.so.2.7(vm_catch_protect+0xb1) [0x7fc1188eebe1] vm_eval.c:2310
/opt/ruby/lib/libruby.so.2.7(rb_catch_obj+0x2c) [0x7fc1188eecec] vm_eval.c:2336
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc_with_frame+0xcf) [0x7fc1188e95a6] vm_insnhelper.c:2514
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc) vm_insnhelper.c:2539
/opt/ruby/lib/libruby.so.2.7(vm_sendish+0x56) [0x7fc1188f6ab5] vm_insnhelper.c:4023
/opt/ruby/lib/libruby.so.2.7(vm_exec_core) insns.def:782
/opt/ruby/lib/libruby.so.2.7(rb_vm_exec+0xab) [0x7fc1188fb6fb] vm.c:1920
/opt/ruby/lib/libruby.so.2.7(invoke_block+0x166) [0x7fc118906e19] vm.c:1044
/opt/ruby/lib/libruby.so.2.7(invoke_iseq_block_from_c) vm.c:1116
/opt/ruby/lib/libruby.so.2.7(invoke_block_from_c_bh) vm.c:1134
/opt/ruby/lib/libruby.so.2.7(vm_yield) vm.c:1179
/opt/ruby/lib/libruby.so.2.7(rb_yield_0) vm_eval.c:1227
/opt/ruby/lib/libruby.so.2.7(rb_yield_1) vm_eval.c:1233
/opt/ruby/lib/libruby.so.2.7(rb_yield) vm_eval.c:1243
/opt/ruby/lib/libruby.so.2.7(rb_array_len+0x0) [0x7fc1186ac63c] array.c:2135
/opt/ruby/lib/libruby.so.2.7(rb_ary_each) array.c:2134
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc_with_frame+0xcf) [0x7fc1188e95a6] vm_insnhelper.c:2514
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc) vm_insnhelper.c:2539
/opt/ruby/lib/libruby.so.2.7(vm_sendish+0x56) [0x7fc1188f6ab5] vm_insnhelper.c:4023
/opt/ruby/lib/libruby.so.2.7(vm_exec_core) insns.def:782
/opt/ruby/lib/libruby.so.2.7(rb_vm_exec+0xab) [0x7fc1188fb6fb] vm.c:1920
/opt/ruby/lib/libruby.so.2.7(invoke_block+0x167) [0x7fc118906593] vm.c:1044
/opt/ruby/lib/libruby.so.2.7(invoke_iseq_block_from_c) vm.c:1116
/opt/ruby/lib/libruby.so.2.7(invoke_block_from_c_bh) vm.c:1134
/opt/ruby/lib/libruby.so.2.7(vm_yield) vm.c:1179
/opt/ruby/lib/libruby.so.2.7(rb_yield_0) vm_eval.c:1227
/opt/ruby/lib/libruby.so.2.7(catch_i) vm_eval.c:2228
/opt/ruby/lib/libruby.so.2.7(vm_catch_protect+0xb1) [0x7fc1188eebe1] vm_eval.c:2310
/opt/ruby/lib/libruby.so.2.7(rb_catch_obj+0x2c) [0x7fc1188eecec] vm_eval.c:2336
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc_with_frame+0xcf) [0x7fc1188e95a6] vm_insnhelper.c:2514
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc) vm_insnhelper.c:2539
/opt/ruby/lib/libruby.so.2.7(vm_sendish+0x56) [0x7fc1188f6ab5] vm_insnhelper.c:4023
/opt/ruby/lib/libruby.so.2.7(vm_exec_core) insns.def:782
/opt/ruby/lib/libruby.so.2.7(rb_vm_exec+0x898) [0x7fc1188fbee8] vm.c:1929
/opt/ruby/lib/libruby.so.2.7(invoke_block+0x16d) [0x7fc118905d82] vm.c:1044
/opt/ruby/lib/libruby.so.2.7(invoke_iseq_block_from_c) vm.c:1116
/opt/ruby/lib/libruby.so.2.7(invoke_block_from_c_bh) vm.c:1134
/opt/ruby/lib/libruby.so.2.7(vm_yield) vm.c:1179
/opt/ruby/lib/libruby.so.2.7(rb_yield_0) vm_eval.c:1227
/opt/ruby/lib/libruby.so.2.7(loop_i) vm_eval.c:1330
/opt/ruby/lib/libruby.so.2.7(rb_vrescue2+0xd4) [0x7fc118747064] eval.c:990
/opt/ruby/lib/libruby.so.2.7(rb_rescue2+0x8a) [0x7fc11874725a] eval.c:967
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc_with_frame+0xcf) [0x7fc1188e95a6] vm_insnhelper.c:2514
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc) vm_insnhelper.c:2539
/opt/ruby/lib/libruby.so.2.7(vm_sendish+0x56) [0x7fc1188f6ab5] vm_insnhelper.c:4023
/opt/ruby/lib/libruby.so.2.7(vm_exec_core) insns.def:782
/opt/ruby/lib/libruby.so.2.7(rb_vm_exec+0xab) [0x7fc1188fb6fb] vm.c:1920
/opt/ruby/lib/libruby.so.2.7(invoke_block+0x167) [0x7fc118906593] vm.c:1044
/opt/ruby/lib/libruby.so.2.7(invoke_iseq_block_from_c) vm.c:1116
/opt/ruby/lib/libruby.so.2.7(invoke_block_from_c_bh) vm.c:1134
/opt/ruby/lib/libruby.so.2.7(vm_yield) vm.c:1179
/opt/ruby/lib/libruby.so.2.7(rb_yield_0) vm_eval.c:1227
/opt/ruby/lib/libruby.so.2.7(catch_i) vm_eval.c:2228
/opt/ruby/lib/libruby.so.2.7(vm_catch_protect+0xb1) [0x7fc1188eebe1] vm_eval.c:2310
/opt/ruby/lib/libruby.so.2.7(rb_catch_obj+0x2c) [0x7fc1188eecec] vm_eval.c:2336
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc_with_frame+0xcf) [0x7fc1188e95a6] vm_insnhelper.c:2514
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc) vm_insnhelper.c:2539
/opt/ruby/lib/libruby.so.2.7(vm_sendish+0x56) [0x7fc1188f6ab5] vm_insnhelper.c:4023
/opt/ruby/lib/libruby.so.2.7(vm_exec_core) insns.def:782
/opt/ruby/lib/libruby.so.2.7(rb_vm_exec+0xab) [0x7fc1188fb6fb] vm.c:1920
/opt/ruby/lib/libruby.so.2.7(invoke_iseq_block_from_c+0x7c) [0x7fc118907076] vm.c:1116
/opt/ruby/lib/libruby.so.2.7(invoke_block_from_c_bh) vm.c:1134
/opt/ruby/lib/libruby.so.2.7(vm_yield) vm.c:1179
/opt/ruby/lib/libruby.so.2.7(rb_yield_0) vm_eval.c:1227
/opt/ruby/lib/libruby.so.2.7(rb_yield) vm_eval.c:1240
/opt/ruby/lib/libruby.so.2.7(rb_protect+0x158) [0x7fc1187473f8] eval.c:1087
/opt/ruby/lib/libruby.so.2.7(rb_f_fork+0x7f) [0x7fc11882697f] process.c:4129
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc_with_frame+0xcf) [0x7fc1188e95a6] vm_insnhelper.c:2514
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc) vm_insnhelper.c:2539
/opt/ruby/lib/libruby.so.2.7(vm_sendish+0x56) [0x7fc1188f6ab5] vm_insnhelper.c:4023
/opt/ruby/lib/libruby.so.2.7(vm_exec_core) insns.def:782
/opt/ruby/lib/libruby.so.2.7(rb_vm_exec+0xab) [0x7fc1188fb6fb] vm.c:1920
/opt/ruby/lib/libruby.so.2.7(invoke_block_from_c_bh+0x2bc) [0x7fc1188fc51c] vm.c:1116
/opt/ruby/lib/libruby.so.2.7(rb_yield_values2+0x56) [0x7fc1188fcd76] vm.c:1179
/opt/ruby/lib/libruby.so.2.7(each_with_index_i+0x6a) [0x7fc11872ce1a] enum.c:2365
/opt/ruby/lib/libruby.so.2.7(vm_yield_with_cfunc+0x115) [0x7fc1188f1b15] vm_insnhelper.c:3220
/opt/ruby/lib/libruby.so.2.7(invoke_block_from_c_bh+0x2c) [0x7fc118906eec] vm.c:1139
/opt/ruby/lib/libruby.so.2.7(vm_yield) vm.c:1179
/opt/ruby/lib/libruby.so.2.7(rb_yield_0) vm_eval.c:1227
/opt/ruby/lib/libruby.so.2.7(rb_yield_1) vm_eval.c:1233
/opt/ruby/lib/libruby.so.2.7(rb_yield) vm_eval.c:1243
/opt/ruby/lib/libruby.so.2.7(rb_array_len+0x0) [0x7fc1186ac63c] array.c:2135
/opt/ruby/lib/libruby.so.2.7(rb_ary_each) array.c:2134
/opt/ruby/lib/libruby.so.2.7(vm_call0_cfunc_with_frame+0x10a) [0x7fc1188fe790] vm_eval.c:91
/opt/ruby/lib/libruby.so.2.7(vm_call0_cfunc) vm_eval.c:105
/opt/ruby/lib/libruby.so.2.7(vm_call0_body) vm_eval.c:140
/opt/ruby/lib/libruby.so.2.7(rb_vm_call0+0xe6) [0x7fc1188fee36] vm_eval.c:52
/opt/ruby/lib/libruby.so.2.7(rb_vm_call_kw+0x6d) [0x7fc1188ff0ed] vm_eval.c:268
/opt/ruby/lib/libruby.so.2.7(iterate_method+0x39) [0x7fc1189001b9] vm_eval.c:718
/opt/ruby/lib/libruby.so.2.7(rb_iterate0+0xd5) [0x7fc1188ee7b5] vm_eval.c:1415
/opt/ruby/lib/libruby.so.2.7(rb_block_call+0x43) [0x7fc1188ee953] vm_eval.c:1480
/opt/ruby/lib/libruby.so.2.7(enum_each_with_index+0x44) [0x7fc1187261f4] enum.c:2395
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc_with_frame+0xcf) [0x7fc1188e95a6] vm_insnhelper.c:2514
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc) vm_insnhelper.c:2539
/opt/ruby/lib/libruby.so.2.7(vm_call_method+0x10a) [0x7fc11890442a] vm_insnhelper.c:3053
/opt/ruby/lib/libruby.so.2.7(vm_sendish+0x56) [0x7fc1188f6ab5] vm_insnhelper.c:4023
/opt/ruby/lib/libruby.so.2.7(vm_exec_core) insns.def:782
/opt/ruby/lib/libruby.so.2.7(rb_vm_exec+0x898) [0x7fc1188fbee8] vm.c:1929
/opt/ruby/lib/libruby.so.2.7(raise_load_if_failed+0x0) [0x7fc11879dc53] load.c:585
/opt/ruby/lib/libruby.so.2.7(rb_load_internal) load.c:645
/opt/ruby/lib/libruby.so.2.7(rb_f_load) load.c:701
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc_with_frame+0xcf) [0x7fc1188e95a6] vm_insnhelper.c:2514
/opt/ruby/lib/libruby.so.2.7(vm_call_cfunc) vm_insnhelper.c:2539
/opt/ruby/lib/libruby.so.2.7(vm_call_method+0x10a) [0x7fc11890442a] vm_insnhelper.c:3053
/opt/ruby/lib/libruby.so.2.7(vm_sendish+0xa3) [0x7fc1188f55a7] vm_insnhelper.c:4023
/opt/ruby/lib/libruby.so.2.7(vm_exec_core) insns.def:801
/opt/ruby/lib/libruby.so.2.7(rb_vm_exec+0xab) [0x7fc1188fb6fb] vm.c:1920
/opt/ruby/lib/libruby.so.2.7(rb_ec_exec_node+0xaa) [0x7fc118743bea] eval.c:278
/opt/ruby/lib/libruby.so.2.7(ruby_run_node+0x49) [0x7fc118749549] eval.c:336
/opt/ruby/bin/ruby(main+0x5b) [0x55cb7cb329db] ./main.c:50

[joker1007 (Tomohiro Hashidate)]

Additional Information:

• I used to use v2.6.2 and Segmentation fault does not occur at that time.
• This stacktrace is reproducible. whenever this error occurs the stacktrace is the same.

[mame (Yusuke Endoh)]

• Status changed from Open to Assigned
• Assignee set to shyouhei (Shyouhei Urabe)

@shyouhei (Shyouhei Urabe) I suspect if this is due to 2.7's new method cache. Could you check it out?

/opt/ruby/lib/libruby.so.2.7(timew_out_of_timet_range+0x1c) [0x7fc1188c2ef4] time.c:1664

1664     if (lt(timexv, mulv(INT2FIX(TIME_SCALE), TIMET2NUM(TIMET_MIN))) ||

This line calls mulv with two arguments. The first is a FIXNUM and the second is a BIGNUM.

 108 static VALUE
 109 mulv(VALUE x, VALUE y)
 110 {
 111     if (FIXNUM_P(x) && FIXNUM_P(y)) {
 112         return rb_fix_mul_fix(x, y);
 113     }
 114     if (RB_TYPE_P(x, T_BIGNUM))
 115         return rb_big_mul(x, y);
 116     return rb_funcall(x, '*', 1, y);
 117 }

This falls back to rb_funcall. This rb_funcall is replaced with rb_funcallv_with_cc. This should call FIXNUM's plus, but it seems to wrongly invoke rb_rational_mul.

/opt/ruby/lib/libruby.so.2.7(rb_rational_mul+0x40) [0x7fc1188370b0] rational.c:898

[nagachika (Tomoyuki Chikanaga)]

• Backport changed from 2.5: UNKNOWN, 2.6: UNKNOWN, 2.7: UNKNOWN to 2.5: UNKNOWN, 2.6: UNKNOWN, 2.7: REQUIRED

[shyouhei (Shyouhei Urabe)]

Looking at it. Though I cannot reproduce this either.

mame (Yusuke Endoh) wrote in #note-2:

This falls back to rb_funcall. This rb_funcall is replaced with rb_funcallv_with_cc. This should call FIXNUM's plus, but it seems to wrongly invoke rb_rational_mul.

(Nit) This should call Fixnum's mul, not plus.

[shyouhei (Shyouhei Urabe)]

Let me tell you that I currently have no idea what is going on. If rb_funcall is broken the situation must be more catastrophic than what is reported here (happens once a day).

[joker1007 (Tomohiro Hashidate)]

FYI:

I downgraded ruby to v2.7.1.
But in our environment, this error occurred with the same stacktrace.

[mame (Yusuke Endoh)]

• Related to Bug #17362: Thread core dump added

[mame (Yusuke Endoh)]

• Related to Bug #17382: Segfault in String#inspect added

[jeremyevans0 (Jeremy Evans)]

• Status changed from Assigned to Feedback

@joker1007 (Tomohiro Hashidate) Can you reproduce this issue with Ruby 3.2 or the master branch? Can you reproduce this issue without the strptime gem?