From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Original-To: poffice@blade.nagaokaut.ac.jp Delivered-To: poffice@blade.nagaokaut.ac.jp Received: from kankan.nagaokaut.ac.jp (kankan.nagaokaut.ac.jp [133.44.2.24]) by blade.nagaokaut.ac.jp (Postfix) with ESMTP id 1345619C001F for ; Wed, 25 Nov 2015 10:43:18 +0900 (JST) Received: from voscc.nagaokaut.ac.jp (voscc.nagaokaut.ac.jp [133.44.1.100]) by kankan.nagaokaut.ac.jp (Postfix) with ESMTP id 176F4B5D87B for ; Wed, 25 Nov 2015 11:14:22 +0900 (JST) Received: from neon.ruby-lang.org (neon.ruby-lang.org [221.186.184.75]) by voscc.nagaokaut.ac.jp (Postfix) with ESMTP id 6C48E18CC7B6 for ; Wed, 25 Nov 2015 11:14:22 +0900 (JST) Received: from [221.186.184.76] (localhost [IPv6:::1]) by neon.ruby-lang.org (Postfix) with ESMTP id CD1301204E8; Wed, 25 Nov 2015 11:14:20 +0900 (JST) X-Original-To: ruby-core@ruby-lang.org Delivered-To: ruby-core@ruby-lang.org Received: from o10.shared.sendgrid.net (o10.shared.sendgrid.net [173.193.132.135]) by neon.ruby-lang.org (Postfix) with ESMTPS id 78934120455 for ; Wed, 25 Nov 2015 11:14:17 +0900 (JST) DKIM-Signature: v=1; a=rsa-sha1; c=relaxed; d=sendgrid.me; h=from:to:references:subject:mime-version:content-type:content-transfer-encoding:list-id; s=smtpapi; bh=hME9NrPKRNNYTu32J6ETnxWSs/c=; b=YTujhIvVHnfdPwjJk4 +9UcrRwsM9ys1YvKcok2xLCo/jgkuyB0u41SjW93ylWWxwVQmOdGr9tkxa5yXku1 iZNTPGP8YD1/L6H6TSZ7/uACEp2pOyEsouSspaRCZyv0wvJV9Usp/Mvs0SRRt99J 6VAP2P8t6cY3nhQWWOOZh/MQY= Received: by filter0527p1mdw1.sendgrid.net with SMTP id filter0527p1mdw1.29565.5655197620 2015-11-25 02:14:14.734922549 +0000 UTC Received: from herokuapp.com (ec2-54-196-117-39.compute-1.amazonaws.com [54.196.117.39]) by ismtpd0002p1iad1.sendgrid.net (SG) with ESMTP id RXLsNG3vTHiFJtBmyNU23A for ; Wed, 25 Nov 2015 02:14:14.744 +0000 (UTC) Date: Wed, 25 Nov 2015 02:14:14 +0000 From: charlez.leu@gmail.com To: ruby-core@ruby-lang.org Message-ID: References: Mime-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 7bit X-Redmine-MailingListIntegration-Message-Ids: 46348 X-Redmine-Project: ruby-trunk X-Redmine-Issue-Id: 11549 X-Redmine-Issue-Author: charlez X-Redmine-Issue-Assignee: ko1 X-Redmine-Sender: charlez X-Mailer: Redmine X-Redmine-Host: bugs.ruby-lang.org X-Redmine-Site: Ruby Issue Tracking System X-Auto-Response-Suppress: All Auto-Submitted: auto-generated X-SG-EID: ync6xU2WACa70kv/Ymy4QrNMhiuLXJG8OTL2vJD1yS4BmzWMFvCaqNvznk+L1vbWj2UjQOuFJCHxVn sEuvAoZU8mMoyJPefFjVx7hmYUe6EKNFGStWx8aqp1/OBWI8AbhQ+0VZfosEKKHd2wXvx3HSLBneFR q9IgGQK3tUKVQwxq+DI9ORO0CoXbqdXtyhA6 X-SendGrid-Contentd-ID: {"test_id":"1448417655"} X-ML-Name: ruby-core X-Mail-Count: 71672 Subject: [ruby-core:71672] [Ruby trunk - Bug #11549] Object allocation during garbage collection phase terminates the Ruby process X-BeenThere: ruby-core@ruby-lang.org X-Mailman-Version: 2.1.15 Precedence: list Reply-To: Ruby developers List-Id: Ruby developers List-Unsubscribe: , List-Post: List-Help: List-Subscribe: , Errors-To: ruby-core-bounces@ruby-lang.org Sender: "ruby-core" Issue #11549 has been updated by Charles Leu. File ruby_bug_redis_connection.txt added Here is some follow-up information: > RE: file ruby_bug_redis_connection.txt * This is a typical stack trace for the described problem/bug. * The Ruby app uses the Redis gem (version 3.2.1) that performs I/O on the client app's behalf. * The Redis gem makes use of read_nonblock to read data available from a Socket. * Per the C level backtrace information (and my potentially flawed interpretation) it appears that a string is being allocated and gc is being invoked within the context of io_getpartial: ~~~ -- C level backtrace information ------------------------------------------- /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(rb_vm_bugreport+0x5b8) [0x7ff99a88a688] vm_dump.c:693 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(rb_bug+0xd5) [0x7ff99a739585] error.c:409 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(newobj_of+0x5aa) [0x7ff99a75e7ea] gc.c:1635 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(str_new0+0x39) [0x7ff99a8157f9] string.c:552 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(rb_str_new_static+0xbf) [0x7ff99a81a14f] string.c:598 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(io_getpartial+0x309) [0x7ff99a770429] io.c:2347 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(io_read_nonblock+0x99) [0x7ff99a770659] io.c:2681 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(vm_call_cfunc_with_frame+0x11a) [0x7ff99a87042a] vm_insnhelper.c:1380 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(vm_exec_core+0x30f5) [0x7ff99a879ed5] insns.def:1054 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(vm_exec+0x7b) [0x7ff99a87f4fb] vm.c:1429 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(invoke_block_from_c+0x2f4) [0x7ff99a880334] vm.c:813 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(rb_yield+0x75) [0x7ff99a8812a5] vm.c:853 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(int_dotimes+0x42) [0x7ff99a78ea42] numeric.c:3868 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(vm_call_cfunc_with_frame+0x11a) [0x7ff99a87042a] vm_insnhelper.c:1380 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(vm_exec_core+0x14e8) [0x7ff99a8782c8] insns.def:1024 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(vm_exec+0x7b) [0x7ff99a87f4fb] vm.c:1429 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(invoke_block_from_c+0x2f4) [0x7ff99a880334] vm.c:813 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(loop_i+0x5c) [0x7ff99a88100c] vm.c:853 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(rb_rescue2+0xdf) [0x7ff99a73d55f] eval.c:808 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(rb_f_loop+0x2e) [0x7ff99a86b9ee] vm_eval.c:1097 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(vm_call_cfunc_with_frame+0x11a) [0x7ff99a87042a] vm_insnhelper.c:1380 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(vm_call_method+0x4d8) [0x7ff99a887df8] vm_insnhelper.c:1473 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(vm_exec_core+0x14e8) [0x7ff99a8782c8] insns.def:1024 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(vm_exec+0x7b) [0x7ff99a87f4fb] vm.c:1429 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(invoke_block_from_c+0x2f4) [0x7ff99a880334] vm.c:813 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(vm_invoke_proc+0xe8) [0x7ff99a880828] vm.c:878 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(rb_vm_invoke_proc+0x1a) [0x7ff99a880a0a] vm.c:897 /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2 [0x7ff99a894e76] /usr/local/rvm/rubies/ruby-2.2.3/lib/libruby.so.2.2(thread_start_func_1+0x71) [0x7ff99a8950f1] thread_pthread.c:852 /lib64/libpthread.so.0(start_thread+0xd1) [0x7ff99a4afa51] /lib64/libc.so.6(__clone+0x6d) [0x7ff99992893d] ~~~ * Examination of the Control Frame Information, Ruby level backtrace information, and C level backtrace information lead me to believe the logic of the Ruby App and Redis gem are as desired. What, if anything, do you conclude from the supplied information to suggest there is something awry within the Ruby App and/or Redis gem? ---------------------------------------- Bug #11549: Object allocation during garbage collection phase terminates the Ruby process https://bugs.ruby-lang.org/issues/11549#change-55075 * Author: Charles Leu * Status: Feedback * Priority: Normal * Assignee: Koichi Sasada * ruby -v: ruby 2.2.3p173 (2015-08-18 revision 51636) [x86_64-linux] * Backport: 2.0.0: UNKNOWN, 2.1: UNKNOWN, 2.2: UNKNOWN ---------------------------------------- Multi-Threaded Ruby apps are often problematic; especially so when utilizing thread pools, and scheduling work to worker threads. RE: attached file ruby_2.2.3_obj_alloc_gc_bug.txt Following is the section of sap_consumer_control.rb that is presented by the Ruby interpreter as being the current execution context when the problem occurs. 408: loop do 409: @worker_threads.schedule(@work_queue.pop, &@consumer) 410: @sap_packets_consumed += 1 411: end Notes: * @work_queue is a Ruby Queue (allocated within the main thread) into which a producer thread places work requests. * @worker_threads is a thread pool (allocated within the main thread). * @worker_threads schedule method simply puts a work request into the thread pool's internal work queue. One of the worker threads within the thread pool will consume/effect the work request, by executing the specified consumer Proc. * The main program thread simply loops forever scheduling work to thread pool threads. * It appears that an object is being allocated by virtue of the @work_queue.pop Questions: * Does Ruby garbage collection potentially run within each thread context? * If answer to prior question is 'Yes', then how can object allocation be prevented when a sibling thread is attempting garbage collection? * How does one write multi-threaded Ruby apps on multi-core systems that permit multiple-concurrent execution contexts that don't employ a mutex to effectively single thread the entire app? ---Files-------------------------------- ruby_2.2.3_obj_alloc_gc_bug.txt (49.1 KB) ruby_bug_redis_connection.txt (53.3 KB) -- https://bugs.ruby-lang.org/