Skip to content
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.

Sign up for GitHub

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

Jump to bottom

Segmentation fault in Formatters::Base for async appender #255

Closed
Antsiscool opened this issue Dec 14, 2022 · 2 comments
Closed

Segmentation fault in Formatters::Base for async appender #255

Antsiscool opened this issue Dec 14, 2022 · 2 comments

Comments

@Antsiscool
Copy link

I have been attempting to upgrade a Rails application from Ruby 2.6.10 to 2.7.7 and am receiving a segmentation fault when running cucumber tests on a CI server. The issue does not occur when the same tests are run locally.

Environment

  • Ruby 2.7.7 (Same issue exists on Ruby 2.7.6)
  • Semantic Logger Version: 4.12.0 (Same issue exists with 4.11.0)
  • Rails Semantic Logger: A fork off the latest GitHub commit that removes the Monkey Patch for rails_semantic_logger/extensions/action_dispatch/debug_exceptions
  • Rails 5.2.8.1
  • Concurrent-ruby: 1.1.10
  • Knapsack: 4.0.0
  • Cucumber: 8.0.0
/var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semantic_logger-4.12.0/lib/semantic_logger/formatters/base.rb:85: [BUG] Segmentation fault at 0x0000000000000008

ruby 2.7.7p221 (2022-11-24 revision 168ec2b1e5) [x86_64-linux]



-- Control frame information -----------------------------------------------

c:0014 p:---- s:0069 e:000068 CFUNC  :==

c:0013 p:---- s:0066 e:000065 CFUNC  :===

c:0012 p:0052 s:0063 e:000059 METHOD /var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semanti

c:0011 p:0013 s:0055 e:000054 METHOD /var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semanti

c:0010 p:0015 s:0051 e:000050 METHOD /var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semanti

c:0009 p:0021 s:0045 e:000044 METHOD /var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semanti

c:0008 p:0020 s:0039 e:000038 METHOD /var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semanti

c:0007 p:0015 s:0031 e:000030 BLOCK  /var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semanti [FINISH]

c:0006 p:---- s:0026 e:000025 CFUNC  :each

c:0005 p:0004 s:0022 e:000021 METHOD /var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semanti

c:0004 p:0031 s:0017 e:000016 METHOD /var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semanti

c:0003 p:0030 s:0011 e:000010 METHOD /var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semanti

c:0002 p:0004 s:0006 e:000005 BLOCK  /var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semanti [FINISH]

c:0001 p:---- s:0003 e:000002 (none) [FINISH]



-- Ruby level backtrace information ----------------------------------------

/var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semantic_logger-4.12.0/lib/semantic_logger/appender/async.rb:63:in `block in reopen'

/var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semantic_logger-4.12.0/lib/semantic_logger/appender/async.rb:121:in `process'

/var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semantic_logger-4.12.0/lib/semantic_logger/appender/async.rb:152:in `process_messages'

/var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semantic_logger-4.12.0/lib/semantic_logger/appenders.rb:30:in `log'

/var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semantic_logger-4.12.0/lib/semantic_logger/appenders.rb:30:in `each'

/var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semantic_logger-4.12.0/lib/semantic_logger/appenders.rb:31:in `block in log'

/var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semantic_logger-4.12.0/lib/semantic_logger/appender/file.rb:188:in `log'

/var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semantic_logger-4.12.0/lib/semantic_logger/formatters/color.rb:131:in `call'

/var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semantic_logger-4.12.0/lib/semantic_logger/formatters/default.rb:83:in `call'

/var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semantic_logger-4.12.0/lib/semantic_logger/formatters/base.rb:61:in `time'

/var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semantic_logger-4.12.0/lib/semantic_logger/formatters/base.rb:85:in `format_time'

/var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semantic_logger-4.12.0/lib/semantic_logger/formatters/base.rb:85:in `==='

/var/lib/buildkite-agent/builds/build-server-2022-12-s056-1/myfoodlink-pty-ltd/myfoodlink/vendor/bundle/ruby/2.7.0/gems/semantic_logger-4.12.0/lib/semantic_logger/formatters/base.rb:85:in `=='

-- Machine register context ------------------------------------------------

 RIP: 0x00005625a6ba2aed RBP: 0x0000000000000008 RSP: 0x00007f62639eb3f0

 RAX: 0x0000000000554065 RBX: 0x00005625ae793cc0 RCX: 0x00005625a6ba2a90

 RDX: 0x0000000000000005 RDI: 0x0000000000000008 RSI: 0x00005625ae793cc0

  R8: 0x0000000000000000  R9: 0x0000000000000001 R10: 0x0000000000000000

 R11: 0x0000000000000206 R12: 0x00005625a82d3448 R13: 0x00005625a831f5c0

 R14: 0x0000000000000008 R15: 0x00007f62639eb520 EFL: 0x0000000000010246



-- C level backtrace information -------------------------------------------

/opt/rubies/ruby-2.7.7/bin/ruby(rb_print_backtrace+0x15) [0x5625a6bfb7d5] vm_dump.c:755

/opt/rubies/ruby-2.7.7/bin/ruby(rb_vm_bugreport+0x21b) [0x5625a6bfba0b] vm_dump.c:941

/opt/rubies/ruby-2.7.7/bin/ruby(rb_bug_for_fatal_signal+0xe4) [0x5625a6c79074] error.c:660

/opt/rubies/ruby-2.7.7/bin/ruby(sigsegv+0x4b) [0x5625a6b8085b] signal.c:946

/lib/x86_64-linux-gnu/libpthread.so.0(__restore_rt+0x0) [0x7f626f635390]

/opt/rubies/ruby-2.7.7/bin/ruby(rb_str_equal+0x5d) [0x5625a6ba2aed] string.c:3270

/opt/rubies/ruby-2.7.7/bin/ruby(vm_call0_body+0x24a) [0x5625a6be949a] vm_eval.c:91

/opt/rubies/ruby-2.7.7/bin/ruby(rb_funcallv_with_cc+0xce) [0x5625a6becb0e] vm_eval.c:1013

/opt/rubies/ruby-2.7.7/bin/ruby(rb_equal+0x70) [0x5625a6b0deb0] object.c:139

/opt/rubies/ruby-2.7.7/bin/ruby(vm_call0_body+0x24a) [0x5625a6be949a] vm_eval.c:91

/opt/rubies/ruby-2.7.7/bin/ruby(rb_vm_call0+0xe8) [0x5625a6be9af8] vm_eval.c:52

/opt/rubies/ruby-2.7.7/bin/ruby(check_match+0xcb) [0x5625a6becc7b] vm_insnhelper.c:1807

/opt/rubies/ruby-2.7.7/bin/ruby(vm_exec_core+0x3d7d) [0x5625a6bf1b1d] vm_insnhelper.c:3704

/opt/rubies/ruby-2.7.7/bin/ruby(rb_vm_exec+0xb0) [0x5625a6be5740] vm.c:1929

/opt/rubies/ruby-2.7.7/bin/ruby(rb_yield+0x241) [0x5625a6bf57a1] vm.c:1044

/opt/rubies/ruby-2.7.7/bin/ruby(rb_array_len+0x0) [0x5625a6c056ed] array.c:2135

/opt/rubies/ruby-2.7.7/bin/ruby(rb_ary_each) array.c:2134

/opt/rubies/ruby-2.7.7/bin/ruby(vm_call_cfunc+0x12a) [0x5625a6bdc8da] vm_insnhelper.c:2514

/opt/rubies/ruby-2.7.7/bin/ruby(vm_sendish+0x70) [0x5625a6bd9450] vm_insnhelper.c:4023

/opt/rubies/ruby-2.7.7/bin/ruby(vm_exec_core+0xb30) [0x5625a6bee8d0] insns.def:782

/opt/rubies/ruby-2.7.7/bin/ruby(rb_vm_exec+0xb0) [0x5625a6be5740] vm.c:1929

/opt/rubies/ruby-2.7.7/bin/ruby(rb_vm_invoke_proc+0x271) [0x5625a6be9131] vm.c:1044

/opt/rubies/ruby-2.7.7/bin/ruby(thread_do_start+0x19f) [0x5625a6bb394f] thread.c:692

/opt/rubies/ruby-2.7.7/bin/ruby(thread_start_func_2+0x1fe) [0x5625a6bb3e7e] thread.c:740

/opt/rubies/ruby-2.7.7/bin/ruby(thread_start_func_1+0xa9) [0x5625a6bb4ed9] thread_pthread.c:969

/lib/x86_64-linux-gnu/libpthread.so.0(0x76ba) [0x7f626f62b6ba]

/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7f626ea1451d]

Expected Behavior

No seg-fault

Actual Behavior

Cucumber tests always fail. Rspec tests have no issue.

The stack trace always shows it on the comparison with nil in the case statement.

We run our tests with knapsack over multiple CI servers. Different sets of tests fail on different runs of the same commit.
@keithrbennett
Copy link
Contributor

I don't have a reason for the problem, but it looks like the error occurs during the comparison of the appender's log formatter's time formatter object (time_format) with nil. Could you maybe set a time formatter and see if the problem remains? (See the format_time method in ...formatters/base.rb for options.)

@Antsiscool
Copy link
Author

I just configured a default formatter with a time format in application.rb. (time_format: :iso_8601). And now all of the cucumber tests have passed.

I may retry the commit a couple of times to see that it continues working.

It seems weird this would fix it, as the default value for time_format is not nil, but a formatting string.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@keithrbennett @reidmorrison @Antsiscool