Note: This is a public test instance of Red Hat Bugzilla. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback at bugzilla.redhat.com.
Bug 1361037
Summary: | [ruby] Invalid stdio handle error during tests run | ||
---|---|---|---|
Product: | [Fedora] Fedora | Reporter: | Rafael Fonseca <rdossant> |
Component: | ruby | Assignee: | Jeroen van Meeuwen <vanmeeuwen+fedora> |
Status: | CLOSED ERRATA | QA Contact: | Fedora Extras Quality Assurance <extras-qa> |
Severity: | unspecified | Docs Contact: | |
Priority: | unspecified | ||
Version: | rawhide | CC: | codonell, dan, fweimer, jcajka, mmorsi, mtasaka, pbrobinson, s, strzibny, tagoh, vanmeeuwen+fedora, vondruch |
Target Milestone: | --- | ||
Target Release: | --- | ||
Hardware: | ppc64 | ||
OS: | Unspecified | ||
Whiteboard: | |||
Fixed In Version: | ruby-2.3.1-58.fc25 | Doc Type: | If docs needed, set a value |
Doc Text: | Story Points: | --- | |
Clone Of: | Environment: | ||
Last Closed: | 2016-08-27 10:42:33 UTC | Type: | Bug |
Regression: | --- | Mount Type: | --- |
Documentation: | --- | CRM: | |
Verified Versions: | Category: | --- | |
oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
Cloudforms Team: | --- | Target Upstream Version: | |
Embargoed: | |||
Bug Depends On: | |||
Bug Blocks: | 1071880 |
Description
Rafael Fonseca
2016-07-28 08:32:22 UTC
For ppc64le, the error is a bit different: 1) Failure: TestSocketNonblock#test_udp_recv_nonblock [/builddir/build/BUILD/ruby-2.3.1/test/socket/test_nonblock.rb:128]: cygwin 1.5.19 has a problem to send an empty UDP packet. [ruby-dev:28915]. Exception raised: <#<Timeout::Error: execution expired>>. 2) Failure: TestSocketNonblock#test_udp_recvfrom_nonblock [/builddir/build/BUILD/ruby-2.3.1/test/socket/test_nonblock.rb:106]: cygwin 1.5.19 has a problem to send an empty UDP packet. [ruby-dev:28915]. Exception raised: <#<Timeout::Error: execution expired>>. 15847 tests, 2235440 assertions, 2 failures, 0 errors, 38 skips ruby -v: ruby 2.3.1p112 (2016-04-26 revision 54768) [powerpc64le-linux] uncommon.mk:612: recipe for target 'yes-test-almost' failed make: *** [yes-test-almost] Error 2 from a recent scratch build on f25 ppc64le ... test_thread.rb ...Fstderr output is not empty bootstraptest.tmp.rb:4:in `initialize': can't create Thread: Resource temporarily unavailable (ThreadError) from bootstraptest.tmp.rb:4:in `new' from bootstraptest.tmp.rb:4:in `block (2 levels) in <main>' from bootstraptest.tmp.rb:3:in `each' from bootstraptest.tmp.rb:3:in `map' from bootstraptest.tmp.rb:3:in `block in <main>' from bootstraptest.tmp.rb:2:in `times' from bootstraptest.tmp.rb:2:in `<main>' uncommon.mk:581: recipe for target 'yes-btest-ruby' failed make: *** [yes-btest-ruby] Error 1 in general it's unlikely a ruby issue as the change between successful -56 and unsuccessful -57 is http://pkgs.fedoraproject.org/cgit/rpms/ruby.git/commit/?id=b1466a4c8f2cd28556efcd93c5dc539bff041be9 and a F-24 build of the same srpm succeeds - http://ppc.koji.fedoraproject.org/koji/taskinfo?taskID=3582342 (In reply to Rafael Fonseca from comment #0) > Description of problem: when building ruby for ppc64 we're hitting the > following error > > Fiddle::TestImport#test_io = Fatal error: glibc detected an invalid stdio > handle > uncommon.mk:612: recipe for target 'yes-test-almost' failed > make: *** [yes-test-almost] Aborted (core dumped) > > > Version-Release number of selected component (if applicable): 2.3.1-57 > > > How reproducible: always on ppc-koji > > > > Additional info: build log > http://ppc.koji.fedoraproject.org/koji/taskinfo?taskID=3561716 the backtrace looks like (gdb) where #0 0x00003fff8e6a0888 in __GI_raise (sig=<optimized out>) at ../sysdeps/unix/sysv/linux/raise.c:54 #1 0x00003fff8e6a2af4 in __GI_abort () at abort.c:89 #2 0x00003fff8e6e9b88 in __libc_message (do_abort=<optimized out>, fmt=<optimized out>) at ../sysdeps/posix/libc_fatal.c:175 #3 0x00003fff8e6e9bf0 in __GI___libc_fatal (message=0x3fff8e7fb770 "Fatal error: glibc detected an invalid stdio handle\n") at ../sysdeps/posix/libc_fatal.c:185 #4 0x00003fff8e6ea774 in _IO_vtable_check () at vtables.c:69 #5 0x00003fff8e6be664 in IO_validate_vtable (vtable=0x3fff984a1bf0 <__GI__IO_file_jumps>) at ../libio/libioP.h:940 #6 _IO_vfprintf_internal (s=0x1001da241c0, format=0x1001b9bc3d0 "hello", ap=0x3fffd828aee0 "") at vfprintf.c:1320 #7 0x00003fff8e6c585c in __fprintf (stream=<optimized out>, format=<optimized out>) at fprintf.c:32 #8 0x00003fff8e8679a4 in .ffi_call_LINUX64 () at ../src/powerpc/linux64.S:133 #9 0x00003fff8e866ad0 in ffi_call (cif=0x10021a32860, fn=<optimized out>, rvalue=0x3fffd828b270, avalue=0x3fffd828b220) at ../src/powerpc/ffi.c:100 #10 0x00003fff8e8976c4 in nogvl_ffi_call (ptr=<optimized out>) at function.c:160 #11 0x00003fff988f98c4 in call_without_gvl (func=@0x3fff8e8af278: 0x3fff8e8976a0 <nogvl_ffi_call>, data1=0x3fffd828b258, ubf=<optimized out>, data2=<optimized out>, fail_if_interrupted=<optimized out>) at thread.c:1289 #12 0x00003fff8e897428 in function_call (argc=<optimized out>, argv=<optimized out>, self=1099982351040) at function.c:219 #13 0x00003fff988c5534 in call_cfunc_m1 (func=<optimized out>, recv=<optimized out>, argc=<optimized out>, argv=<optimized out>) at vm_insnhelper.c:1459 #14 0x00003fff988d1a24 in vm_call_cfunc_with_frame (ci=0x3fff98a18178 <ruby_vm_event_flags>, cc=0x1001b9515d0, calling=0x1001c0eaac0, reg_cfp=0x3fff916afa10, th=0x1001b9515d0) at vm_insnhelper.c:1638 ... the corresponding test code is ruby-2.3.1/test/fiddle/test_import.rb ... def test_io() if( RUBY_PLATFORM != BUILD_RUBY_PLATFORM ) return end io_in,io_out = IO.pipe() LIBC.fprintf(io_out, "hello") io_out.flush() io_out.close() str = io_in.read() io_in.close() assert_equal("hello", str) end This obviously calls fprintf from glibc via FFI. libffi have not changed for ages, so what about glibc? And looking at yesterdays build, it failed on PPC the same way as on primary ... interesting. I thought it is just some random threading glitch ... (In reply to Vít Ondruch from comment #6) > This obviously calls fprintf from glibc via FFI. > > libffi have not changed for ages, so what about glibc? I've tried with older glibc, was still failing. But now I understand nothing, same guest, no changes, 9 hours ago it was consistently failing with the "invalid stdio handle", now it gets over and fails much later with the "empty UDP packet" ... (In reply to Dan Horák from comment #2) > from a recent scratch build on f25 ppc64le > > ... > > > test_thread.rb ...Fstderr output is not empty > bootstraptest.tmp.rb:4:in `initialize': can't create Thread: Resource > temporarily unavailable (ThreadError) > from bootstraptest.tmp.rb:4:in `new' > from bootstraptest.tmp.rb:4:in `block (2 levels) in <main>' > from bootstraptest.tmp.rb:3:in `each' > from bootstraptest.tmp.rb:3:in `map' > from bootstraptest.tmp.rb:3:in `block in <main>' > from bootstraptest.tmp.rb:2:in `times' > from bootstraptest.tmp.rb:2:in `<main>' > uncommon.mk:581: recipe for target 'yes-btest-ruby' failed > make: *** [yes-btest-ruby] Error 1 This looks similar to an issue Carlos saw in recent glibc builds (on multiple architectures). pthread_create was failing with EAGAIN there as well. At present, we don't think this was caused by a change in glibc. (In reply to Dan Horák from comment #5) > #3 0x00003fff8e6e9bf0 in __GI___libc_fatal (message=0x3fff8e7fb770 "Fatal > error: glibc detected an invalid stdio handle\n") at > ../sysdeps/posix/libc_fatal.c:185 Can you please try this reduced test case: require 'fiddle' require 'fiddle/import' module Fiddle module LIBC extend Importer dlload 'libc.so.6' typealias 'FILE*', 'void*' extern "int fprintf(FILE*, char*)" end end io_in,io_out = IO.pipe() Fiddle::LIBC.fprintf(io_out, "hello\n") io_out.flush() io_out.close() str = io_in.read() io_in.close() print str Run it under GDB, set a breakpoint on fprintf, and get the value of the libio vtable pointer: (gdb) break fprintf Breakpoint 1 at 0x7ffff6c97c20: file fprintf.c, line 27. (gdb) r Starting program: /usr/bin/ruby-mri test_import.rb [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib64/libthread_db.so.1". [New Thread 0x7ffff7ff5700 (LWP 30422)] Breakpoint 1, __fprintf (stream=0x555555bba460, format=0x555555a7d038 "hello\n") at fprintf.c:27 27 { (gdb) bt #0 __fprintf (stream=0x555555bba460, format=0x555555a7d038 "hello\n") at fprintf.c:27 #1 0x00007fffef565d30 in ffi_call_unix64 () from /lib64/libffi.so.6 #2 0x00007fffef56579b in ffi_call () from /lib64/libffi.so.6 #3 0x00007fffef76b3d9 in function_call () from /usr/lib64/ruby/fiddle.so #4 0x00007ffff7adae11 in vm_call_cfunc () from /lib64/libruby.so.2.2 #5 0x00007ffff7aeb32e in vm_call_method () from /lib64/libruby.so.2.2 #6 0x00007ffff7ade917 in vm_exec_core () from /lib64/libruby.so.2.2 #7 0x00007ffff7ae420d in vm_exec () from /lib64/libruby.so.2.2 #8 0x00007ffff7ae573f in rb_iseq_eval_main () from /lib64/libruby.so.2.2 #9 0x00007ffff79cfcad in ruby_exec_internal () from /lib64/libruby.so.2.2 #10 0x00007ffff79d184d in ruby_exec_node () from /lib64/libruby.so.2.2 #11 0x00007ffff79d37ae in ruby_run_node () from /lib64/libruby.so.2.2 #12 0x00005555555549ab in main () (gdb) print *stream $1 = {_flags = -72539004, _IO_read_ptr = 0x0, _IO_read_end = 0x0, _IO_read_base = 0x0, _IO_write_base = 0x0, _IO_write_ptr = 0x0, _IO_write_end = 0x0, _IO_buf_base = 0x0, _IO_buf_end = 0x0, _IO_save_base = 0x0, _IO_backup_base = 0x0, _IO_save_end = 0x0, _markers = 0x0, _chain = 0x7ffff7000560 <_IO_2_1_stderr_>, _fileno = 8, _flags2 = 0, _old_offset = 93824998941808, _cur_column = 0, _vtable_offset = -89 '\247', _shortbuf = "U", _lock = 0x555555bba540, _offset = -1, _codecvt = 0x555555bba440, _wide_data = 0x555555bba550, _freeres_list = 0x0, _freeres_buf = 0x555555bba4d8, _freeres_size = 5, _mode = 0, _unused2 = "\000\000\000\000\002\000\000\000\000\000\000\000\200\246\273UUU\000"} (gdb) print stream + 1 $2 = (FILE *) 0x555555bba538 (gdb) print *(void **)(stream + 1) $3 = (void *) 0x7ffff6ffe6c0 <__GI__IO_file_jumps> I wonder if it is still equal to __GI__IO_file_jumps. self-note how to run the test_import.rb from command line (and get the Fatal error): LD_LIBRARY_PATH=. ./ruby --disable-gems -I. -Ilib -I.ext/common -I.ext/powerpc64-linux test/runner.rb test/fiddle/test_import.rb I wasn't able to reproduce the crash with the reduced test case, but the full test case returns (gdb) run Starting program: /home/sharkcz/ruby/ruby-2.3.1/ruby --disable-gems -I. -Ilib -I.ext/common -I.ext/powerpc64-linux test/runner.rb test/fiddle/test_import.rb [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib64/power8/libthread_db.so.1". [New Thread 0x3fffb75bf190 (LWP 21384)] Run options: # Running tests: [ 8/24] Fiddle::TestImport#test_io Thread 1 "ruby" hit Breakpoint 1, __fprintf (stream=0x206f7b10, format=0x200487a0 "hello") at fprintf.c:27 27 { (gdb) bt #0 __fprintf (stream=0x206f7b10, format=0x200487a0 "hello") at fprintf.c:27 #1 0x00003fffb7447924 in .ffi_call_LINUX64 () at ../src/powerpc/linux64.S:133 #2 0x00003fffb7446a50 in ffi_call (cif=0x204be420, fn=<optimized out>, rvalue=0x3fffffffb440, avalue=0x3fffffffb3f0) at ../src/powerpc/ffi.c:100 #3 0x00003fffb7485c84 in nogvl_ffi_call (ptr=<optimized out>) at function.c:160 #4 0x00003fffb7e5ba84 in call_without_gvl (func=@0x3fffb749f108: 0x3fffb7485c60 <nogvl_ffi_call>, data1=0x3fffffffb428, ubf=<optimized out>, data2=<optimized out>, fail_if_interrupted=<optimized out>) at thread.c:1289 #5 0x00003fffb74859e8 in function_call (argc=<optimized out>, argv=<optimized out>, self=537355600) at function.c:219 #6 0x00003fffb7e276f4 in call_cfunc_m1 (func=<optimized out>, recv=<optimized out>, argc=<optimized out>, argv=<optimized out>) at vm_insnhelper.c:1459 #7 0x00003fffb7e33be4 in vm_call_cfunc_with_frame (ci=0x3fffb7f782c8 <ruby_vm_event_flags>, cc=0x200320d0, calling=0x20076550, reg_cfp=0x3fffb76bfa10, th=0x200320d0) at vm_insnhelper.c:1638 #8 vm_call_cfunc (th=th@entry=0x200320d0, reg_cfp=reg_cfp@entry=0x3fffb76bfa10, calling=calling@entry=0x3fffffffb8b8, ci=ci@entry=0x20408a20, cc=cc@entry=0x204a1e58) at vm_insnhelper.c:1733 #9 0x00003fffb7e44464 in vm_call_method_each_type (th=0x200320d0, cfp=0x3fffb76bfa10, calling=0x3fffffffb8b8, ci=0x20408a20, cc=0x204a1e58) at vm_insnhelper.c:2022 #10 0x00003fffb7e45794 in vm_call_method (cc=0x204a1e58, ci=0x20408a20, calling=0x3fffffffb8b8, cfp=0x3fffb76bfa10, th=0x200320d0) at vm_insnhelper.c:2157 #11 vm_call_general (th=0x200320d0, reg_cfp=0x3fffb76bfa10, calling=0x3fffffffb8b8, ci=0x20408a20, cc=0x204a1e58) at vm_insnhelper.c:2189 #12 0x00003fffb7e38784 in vm_exec_core (th=th@entry=0x200320d0, initial=initial@entry=0) at insns.def:964 #13 0x00003fffb7e3dce8 in vm_exec (th=th@entry=0x200320d0) at vm.c:1650 #14 0x00003fffb7e4627c in invoke_block (block=0x3fffb76bfbb0, opt_pc=<optimized out>, type=<optimized out>, cref=0x0, self=537550960, iseq=0x20297820, th=0x200320d0) at vm.c:921 #15 invoke_block_from_c_0 (splattable=1, cref=0x0, blockptr=0x0, argv=0x3fffffffc170, argc=1, self=537550960, block=0x3fffb76bfbb0, th=0x200320d0) at vm.c:971 #16 invoke_block_from_c_splattable (cref=0x0, blockptr=0x0, argv=0x3fffffffc170, argc=1, self=537550960, block=0x3fffb76bfbb0, th=0x200320d0) at vm.c:988 #17 vm_yield (argv=0x3fffffffc170, argc=1, th=0x200320d0) at vm.c:1023 #18 rb_yield_0 (argv=0x3fffffffc170, argc=1) at vm_eval.c:1010 #19 rb_yield_1 (val=<optimized out>) at vm_eval.c:1016 #20 rb_yield (val=<optimized out>) at vm_eval.c:1026 #21 0x00003fffb7c7d594 in rb_ary_collect (ary=537172600) at array.c:2733 #22 0x00003fffb7e2774c in call_cfunc_0 (func=<optimized out>, recv=<optimized out>, argc=<optimized out>, argv=<optimized out>) at vm_insnhelper.c:1465 #23 0x00003fffb7e33be4 in vm_call_cfunc_with_frame (ci=<optimized out>, cc=<optimized out>, calling=<optimized out>, reg_cfp=0x3fffb76bfb90, th=0x200320d0) at vm_insnhelper.c:1638 #24 vm_call_cfunc (th=0x200320d0, reg_cfp=0x3fffb76bfb90, calling=<optimized out>, ci=<optimized out>, cc=<optimized out>) at vm_insnhelper.c:1733 #25 0x00003fffb7e38784 in vm_exec_core (th=th@entry=0x200320d0, initial=initial@entry=0) at insns.def:964 #26 0x00003fffb7e3dce8 in vm_exec (th=th@entry=0x200320d0) at vm.c:1650 #27 0x00003fffb7e4627c in invoke_block (block=0x3fffb76bfcb0, opt_pc=<optimized out>, type=<optimized out>, cref=0x0, self=537550960, iseq=0x20061448, th=0x200320d0) at vm.c:921 #28 invoke_block_from_c_0 (splattable=1, cref=0x0, blockptr=0x0, argv=0x3fffffffcd50, argc=1, self=537550960, block=0x3fffb76bfcb0, th=0x200320d0) at vm.c:971 #29 invoke_block_from_c_splattable (cref=0x0, blockptr=0x0, argv=0x3fffffffcd50, argc=1, self=537550960, block=0x3fffb76bfcb0, th=0x200320d0) at vm.c:988 #30 vm_yield (argv=0x3fffffffcd50, argc=1, th=0x200320d0) at vm.c:1023 #31 rb_yield_0 (argv=0x3fffffffcd50, argc=1) at vm_eval.c:1010 #32 rb_yield_1 (val=<optimized out>) at vm_eval.c:1016 #33 rb_yield (val=<optimized out>) at vm_eval.c:1026 #34 0x00003fffb7c78c14 in rb_ary_each (ary=544830040) at array.c:1815 #35 0x00003fffb7e2774c in call_cfunc_0 (func=<optimized out>, recv=<optimized out>, argc=<optimized out>, argv=<optimized out>) at vm_insnhelper.c:1465 #36 0x00003fffb7e33be4 in vm_call_cfunc_with_frame (ci=0x3fffb7f782c8 <ruby_vm_event_flags>, cc=0x200320d0, calling=0x20797258, reg_cfp=0x3fffb76bfc90, th=0x200320d0) at vm_insnhelper.c:1638 #37 vm_call_cfunc (th=th@entry=0x200320d0, reg_cfp=reg_cfp@entry=0x3fffb76bfc90, calling=calling@entry=0x3fffffffd218, ci=ci@entry=0x201b99b0, cc=cc@entry=0x2024f910) at vm_insnhelper.c:1733 #38 0x00003fffb7e44464 in vm_call_method_each_type (th=0x200320d0, cfp=0x3fffb76bfc90, calling=0x3fffffffd218, ci=0x201b99b0, cc=0x2024f910) at vm_insnhelper.c:2022 #39 0x00003fffb7e45794 in vm_call_method (cc=0x2024f910, ci=0x201b99b0, calling=0x3fffffffd218, cfp=0x3fffb76bfc90, th=0x200320d0) at vm_insnhelper.c:2157 #40 vm_call_general (th=0x200320d0, reg_cfp=0x3fffb76bfc90, calling=0x3fffffffd218, ci=0x201b99b0, cc=0x2024f910) at vm_insnhelper.c:2189 #41 0x00003fffb7e38784 in vm_exec_core (th=th@entry=0x200320d0, initial=initial@entry=0) at insns.def:964 #42 0x00003fffb7e3dce8 in vm_exec (th=th@entry=0x200320d0) at vm.c:1650 #43 0x00003fffb7e4627c in invoke_block (block=0x3fffb76bfe30, opt_pc=<optimized out>, type=<optimized out>, cref=0x0, self=537550960, iseq=0x20296128, th=0x200320d0) at vm.c:921 #44 invoke_block_from_c_0 (splattable=1, cref=0x0, blockptr=0x0, argv=0x3fffffffdad0, argc=1, self=537550960, block=0x3fffb76bfe30, th=0x200320d0) at vm.c:971 #45 invoke_block_from_c_splattable (cref=0x0, blockptr=0x0, argv=0x3fffffffdad0, argc=1, self=537550960, block=0x3fffb76bfe30, th=0x200320d0) at vm.c:988 #46 vm_yield (argv=0x3fffffffdad0, argc=1, th=0x200320d0) at vm.c:1023 #47 rb_yield_0 (argv=0x3fffffffdad0, argc=1) at vm_eval.c:1010 #48 rb_yield_1 (val=<optimized out>) at vm_eval.c:1016 #49 rb_yield (val=<optimized out>) at vm_eval.c:1026 #50 0x00003fffb7c78c14 in rb_ary_each (ary=544830240) at array.c:1815 #51 0x00003fffb7e2774c in call_cfunc_0 (func=<optimized out>, recv=<optimized out>, argc=<optimized out>, argv=<optimized out>) at vm_insnhelper.c:1465 ---Type <return> to continue, or q <return> to quit--- #52 0x00003fffb7e33be4 in vm_call_cfunc_with_frame (ci=0x3fffb7f782c8 <ruby_vm_event_flags>, cc=0x200320d0, calling=0x20797320, reg_cfp=0x3fffb76bfe10, th=0x200320d0) at vm_insnhelper.c:1638 #53 vm_call_cfunc (th=th@entry=0x200320d0, reg_cfp=reg_cfp@entry=0x3fffb76bfe10, calling=calling@entry=0x3fffffffdf98, ci=ci@entry=0x202a0cb0, cc=cc@entry=0x202a0e38) at vm_insnhelper.c:1733 #54 0x00003fffb7e44464 in vm_call_method_each_type (th=0x200320d0, cfp=0x3fffb76bfe10, calling=0x3fffffffdf98, ci=0x202a0cb0, cc=0x202a0e38) at vm_insnhelper.c:2022 #55 0x00003fffb7e45794 in vm_call_method (cc=0x202a0e38, ci=0x202a0cb0, calling=0x3fffffffdf98, cfp=0x3fffb76bfe10, th=0x200320d0) at vm_insnhelper.c:2157 #56 vm_call_general (th=0x200320d0, reg_cfp=0x3fffb76bfe10, calling=0x3fffffffdf98, ci=0x202a0cb0, cc=0x202a0e38) at vm_insnhelper.c:2189 #57 0x00003fffb7e38784 in vm_exec_core (th=th@entry=0x200320d0, initial=initial@entry=0) at insns.def:964 #58 0x00003fffb7e3dce8 in vm_exec (th=0x200320d0) at vm.c:1650 #59 0x00003fffb7cced54 in ruby_exec_internal (n=0x200563e0) at eval.c:245 #60 0x00003fffb7cd1478 in ruby_exec_node (n=<optimized out>) at eval.c:310 #61 0x00003fffb7cd4400 in ruby_run_node (n=0x200563e0) at eval.c:302 #62 0x0000000020000c80 in main (argc=<optimized out>, argv=<optimized out>) at main.c:36 (gdb) print *stream $1 = {_flags = -72539004, _IO_read_ptr = 0x0, _IO_read_end = 0x0, _IO_read_base = 0x0, _IO_write_base = 0x0, _IO_write_ptr = 0x0, _IO_write_end = 0x0, _IO_buf_base = 0x0, _IO_buf_end = 0x0, _IO_save_base = 0x0, _IO_backup_base = 0x0, _IO_save_end = 0x0, _markers = 0x0, _chain = 0x3fffb79518a0 <_IO_2_1_stderr_>, _fileno = 9, _flags2 = 0, _old_offset = 0, _cur_column = 0, _vtable_offset = 0 '\000', _shortbuf = "", _lock = 0x206f7bf0, _offset = -1, _codecvt = 0x6578706563746564, _wide_data = 0x206f7c00, _freeres_list = 0x0, _freeres_buf = 0x3a617267732c203a, __pad5 = 8243122744761003040, _mode = 0, _unused2 = "ck)\n", '\000' <repeats 15 times>} (gdb) print stream + 1 $2 = (FILE *) 0x206f7be8 (gdb) print *(void **)(stream + 1) $3 = (void *) 0x3fffb7941c30 <__GI__IO_file_jumps> (gdb) cont Continuing. Fatal error: glibc detected an invalid stdio handle Thread 1 "ruby" received signal SIGABRT, Aborted. 0x00003fffb72807ac in __libc_signal_restore_set (set=0x3fffffffa550) at ../sysdeps/unix/sysv/linux/nptl-signals.h:79 79 return INTERNAL_SYSCALL (rt_sigprocmask, err, 4, SIG_SETMASK, set, NULL, (gdb) The standalone case gives (gdb) run Starting program: /home/sharkcz/ruby/ruby-2.3.1/ruby --disable-gems -I. -Ilib -I.ext/common -I.ext/powerpc64-linux ../test_import.rb [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib64/power8/libthread_db.so.1". [New Thread 0x3fffb75bf190 (LWP 21413)] Thread 1 "ruby" hit Breakpoint 1, __fprintf (stream=0x201fe670, format=0x20202dc0 "hello\n") at fprintf.c:27 27 { Missing separate debuginfos, use: dnf debuginfo-install gmp-6.1.1-1.fc25.ppc64 (gdb) w Ambiguous command "w": watch, wh, whatis, where, while, while-stepping, winheight, ws. (gdb) bt #0 __fprintf (stream=0x201fe670, format=0x20202dc0 "hello\n") at fprintf.c:27 #1 0x00003fffb74d7924 in .ffi_call_LINUX64 () at ../src/powerpc/linux64.S:133 #2 0x00003fffb74d6a50 in ffi_call (cif=0x201e2820, fn=<optimized out>, rvalue=0x3fffffffdb30, avalue=0x3fffffffdae0) at ../src/powerpc/ffi.c:100 #3 0x00003fffb7515c84 in nogvl_ffi_call (ptr=<optimized out>) at function.c:160 #4 0x00003fffb7e5ba84 in call_without_gvl (func=@0x3fffb752f108: 0x3fffb7515c60 <nogvl_ffi_call>, data1=0x3fffffffdb18, ubf=<optimized out>, data2=<optimized out>, fail_if_interrupted=<optimized out>) at thread.c:1289 #5 0x00003fffb75159e8 in function_call (argc=<optimized out>, argv=<optimized out>, self=538982160) at function.c:219 #6 0x00003fffb7e276f4 in call_cfunc_m1 (func=<optimized out>, recv=<optimized out>, argc=<optimized out>, argv=<optimized out>) at vm_insnhelper.c:1459 #7 0x00003fffb7e33be4 in vm_call_cfunc_with_frame (ci=0x3fffb7f782c8 <ruby_vm_event_flags>, cc=0x200320d0, calling=0x20203710, reg_cfp=0x3fffb76bff50, th=0x200320d0) at vm_insnhelper.c:1638 #8 vm_call_cfunc (th=th@entry=0x200320d0, reg_cfp=reg_cfp@entry=0x3fffb76bff50, calling=calling@entry=0x3fffffffdfa8, ci=ci@entry=0x201ea9c0, cc=cc@entry=0x201f9788) at vm_insnhelper.c:1733 #9 0x00003fffb7e44464 in vm_call_method_each_type (th=0x200320d0, cfp=0x3fffb76bff50, calling=0x3fffffffdfa8, ci=0x201ea9c0, cc=0x201f9788) at vm_insnhelper.c:2022 #10 0x00003fffb7e45794 in vm_call_method (cc=0x201f9788, ci=0x201ea9c0, calling=0x3fffffffdfa8, cfp=0x3fffb76bff50, th=0x200320d0) at vm_insnhelper.c:2157 #11 vm_call_general (th=0x200320d0, reg_cfp=0x3fffb76bff50, calling=0x3fffffffdfa8, ci=0x201ea9c0, cc=0x201f9788) at vm_insnhelper.c:2189 #12 0x00003fffb7e38784 in vm_exec_core (th=th@entry=0x200320d0, initial=initial@entry=0) at insns.def:964 #13 0x00003fffb7e3dce8 in vm_exec (th=0x200320d0) at vm.c:1650 #14 0x00003fffb7cced54 in ruby_exec_internal (n=0x200584d8) at eval.c:245 #15 0x00003fffb7cd1478 in ruby_exec_node (n=<optimized out>) at eval.c:310 #16 0x00003fffb7cd4400 in ruby_run_node (n=0x200584d8) at eval.c:302 #17 0x0000000020000c80 in main (argc=<optimized out>, argv=<optimized out>) at main.c:36 (gdb) print *stream $1 = {_flags = -72539004, _IO_read_ptr = 0x0, _IO_read_end = 0x0, _IO_read_base = 0x0, _IO_write_base = 0x0, _IO_write_ptr = 0x0, _IO_write_end = 0x0, _IO_buf_base = 0x0, _IO_buf_end = 0x0, _IO_save_base = 0x0, _IO_backup_base = 0x0, _IO_save_end = 0x0, _markers = 0x0, _chain = 0x3fffb79518a0 <_IO_2_1_stderr_>, _fileno = 9, _flags2 = 0, _old_offset = 4294967296, _cur_column = 0, _vtable_offset = 63 '?', _shortbuf = "\377", _lock = 0x201fe750, _offset = -1, _codecvt = 0x3fffb7950ef0 <main_arena+88>, _wide_data = 0x201fe760, _freeres_list = 0x0, _freeres_buf = 0x201fe750, __pad5 = 70368744165384, _mode = 0, _unused2 = "\000\000\000\v\000\000\000\001\000\000\000\000\000\000\000\000 \037\347\020"} (gdb) print stream + 1 $2 = (FILE *) 0x201fe748 (gdb) print *(void **)(stream + 1) $3 = (void *) 0x3fffb7941c30 <__GI__IO_file_jumps> (gdb) cont Continuing. hello [Thread 0x3fffb75bf190 (LWP 21413) exited] [Inferior 1 (process 21410) exited normally] [sharkcz@ibm-p8-generic-01-guest09 ruby-2.3.1]$ ldd ./ruby linux-vdso64.so.1 (0x00003fffa7000000) libruby.so.2.3 => /home/sharkcz/ruby/ruby-2.3.1/libruby.so.2.3 (0x00003fffa6c50000) libpthread.so.0 => /lib64/power8/libpthread.so.0 (0x00003fffa6bf0000) libgmp.so.10 => /lib64/libgmp.so.10 (0x00003fffa6b30000) libdl.so.2 => /lib64/libdl.so.2 (0x00003fffa6b00000) libcrypt.so.1 => /lib64/libcrypt.so.1 (0x00003fffa6ab0000) libm.so.6 => /lib64/power8/libm.so.6 (0x00003fffa69b0000) libc.so.6 => /lib64/power8/libc.so.6 (0x00003fffa6780000) /lib64/ld64.so.1 (0x00000000542d0000) I have updated the system to latest glibc (scratch built) and rebuilt libffi in f25, just to try latest stuff. [sharkcz@ibm-p8-generic-01-guest09 ruby-2.3.1]$ rpm -q glibc libffi glibc-2.24-1.fc25.ppc64 libffi-3.1-9.fc25.1.ppc64 We also see few more test failures where popen() call is involved, might be related to this pipe() one ... (In reply to Rafael Fonseca from comment #1) > For ppc64le, the error is a bit different: > > 1) Failure: > TestSocketNonblock#test_udp_recv_nonblock > [/builddir/build/BUILD/ruby-2.3.1/test/socket/test_nonblock.rb:128]: > cygwin 1.5.19 has a problem to send an empty UDP packet. [ruby-dev:28915]. > Exception raised: > <#<Timeout::Error: execution expired>>. > > 2) Failure: > TestSocketNonblock#test_udp_recvfrom_nonblock > [/builddir/build/BUILD/ruby-2.3.1/test/socket/test_nonblock.rb:106]: > cygwin 1.5.19 has a problem to send an empty UDP packet. [ruby-dev:28915]. > Exception raised: > <#<Timeout::Error: execution expired>>. If I can see correctly in my environment, then this problem exists when the running kernel is 4.7 and goes away with kernels 4.6 or 4.5. libio vtable verification fails because there are two copies of libc.so.6 in the process: 0x00003fffb79413a8 - 0x00003fffb7941f78 is __libc_IO_vtables in /lib64/power8/libc.so.6 0x00003fffb74213c0 - 0x00003fffb7421f90 is __libc_IO_vtables in /lib64/libc.so.6 IO.pipe refers to a vtable from a the first copy, but the fprintf called via libffi comes from the second copy. The root cause is the Fiddle module loading libc.so.6 with an absolute path: #0 __dlopen (file=0x20728280 "/lib64/libc.so.6", mode=257) at dlopen.c:75 #1 0x00003fffb748782c in rb_fiddle_handle_initialize (argc=<optimized out>, argv=<optimized out>, self=544821280) at handle.c:179 This comes from test/fiddle/helper.rb: when /x86_64-linux/ libc_so = "/lib64/libc.so.6" libm_so = "/lib64/libm.so.6" when /linux/ libdir = '/lib' case [0].pack('L!').size when 4 # 32-bit ruby libdir = '/lib32' if File.directory? '/lib32' when 8 # 64-bit ruby libdir = '/lib64' if File.directory? '/lib64' end libc_so = File.join(libdir, "libc.so.6") libm_so = File.join(libdir, "libm.so.6") So the good news is that it's just a path. I expect the fix looks like this: when /linux/ libc_so = "libc.so.6" libm_so = "libm.so.6" (This replaces tehe x86_64-linux branch, too.) (In reply to Florian Weimer from comment #17) Wow, did not expected this. Now the question to me is why this got exposed now, since the code did not changed in Ruby ... (In reply to Vít Ondruch from comment #18) > (In reply to Florian Weimer from comment #17) > Wow, did not expected this. Now the question to me is why this got exposed > now, since the code did not changed in Ruby ... libio vtable verification is a new security hardening feature in Fedora 25. (In reply to Florian Weimer from comment #17) > libio vtable verification fails because there are two copies of libc.so.6 in > the process: > > 0x00003fffb79413a8 - 0x00003fffb7941f78 is __libc_IO_vtables in > /lib64/power8/libc.so.6 > 0x00003fffb74213c0 - 0x00003fffb7421f90 is __libc_IO_vtables in > /lib64/libc.so.6 > > IO.pipe refers to a vtable from a the first copy, but the fprintf called via > libffi comes from the second copy. > > The root cause is the Fiddle module loading libc.so.6 with an absolute path: > > #0 __dlopen (file=0x20728280 "/lib64/libc.so.6", mode=257) at dlopen.c:75 > #1 0x00003fffb748782c in rb_fiddle_handle_initialize (argc=<optimized out>, > argv=<optimized out>, self=544821280) at handle.c:179 This is an application defect. If you're using a path it's expected you know what you're loading. One _should_ be using '#include <gnu/lib-names.h>' to get LIBC_SO and then dlopen that, it's the only supported solution, particularly consider distributions that might have /usr/lib64, or multi-arched lib dirs. You could be loading libc.so.6 from an incompatible ABI. Loding by SONAME is the only safe option. ruby-2.3.1-58.fc25 has been submitted as an update to Fedora 25. https://bodhi.fedoraproject.org/updates/FEDORA-2016-491340cf7b ruby-2.3.1-58.fc25 has been pushed to the Fedora 25 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2016-491340cf7b ruby-2.3.1-58.fc25 has been pushed to the Fedora 25 stable repository. If problems still persist, please make note of it in this bug report. |