From mboxrd@z Thu Jan 1 00:00:00 1970 Path: news.gmane.org!.POSTED.blaine.gmane.org!not-for-mail From: Mark H Weaver Newsgroups: gmane.lisp.guile.user,gmane.lisp.guile.devel Subject: Re: guile-2.9.2 and threading Date: Fri, 07 Jun 2019 00:26:27 -0400 Message-ID: <87h892ault.fsf@netris.org> References: Mime-Version: 1.0 Content-Type: text/plain Injection-Info: blaine.gmane.org; posting-host="blaine.gmane.org:195.159.176.226"; logging-data="88858"; mail-complaints-to="usenet@blaine.gmane.org" User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/26.2 (gnu/linux) Cc: Guile User , Guile Development To: Linas Vepstas Original-X-From: guile-user-bounces+guile-user=m.gmane.org@gnu.org Fri Jun 07 06:29:32 2019 Return-path: Envelope-to: guile-user@m.gmane.org Original-Received: from lists.gnu.org ([209.51.188.47]) by blaine.gmane.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.89) (envelope-from ) id 1hZ6VO-000Mye-Pz for guile-user@m.gmane.org; Fri, 07 Jun 2019 06:29:30 +0200 Original-Received: from localhost ([::1]:45888 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.86_2) (envelope-from ) id 1hZ6VN-0007Mv-8k for guile-user@m.gmane.org; Fri, 07 Jun 2019 00:29:29 -0400 Original-Received: from eggs.gnu.org ([2001:470:142:3::10]:35367) by lists.gnu.org with esmtp (Exim 4.86_2) (envelope-from ) id 1hZ6Uc-0007Mn-QP for guile-user@gnu.org; Fri, 07 Jun 2019 00:28:44 -0400 Original-Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1hZ6Ub-0006AN-JG for guile-user@gnu.org; Fri, 07 Jun 2019 00:28:42 -0400 Original-Received: from world.peace.net ([64.112.178.59]:33774) by eggs.gnu.org with esmtps (TLS1.0:RSA_AES_256_CBC_SHA1:32) (Exim 4.71) (envelope-from ) id 1hZ6Ub-00067d-FX; Fri, 07 Jun 2019 00:28:41 -0400 Original-Received: from mhw by world.peace.net with esmtpsa (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.89) (envelope-from ) id 1hZ6UZ-0003Zv-Rj; Fri, 07 Jun 2019 00:28:40 -0400 In-Reply-To: (Linas Vepstas's message of "Sun, 2 Jun 2019 18:25:27 -0500") X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.2.x-3.x [generic] X-Received-From: 64.112.178.59 X-BeenThere: guile-user@gnu.org X-Mailman-Version: 2.1.23 Precedence: list List-Id: General Guile related discussions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: guile-user-bounces+guile-user=m.gmane.org@gnu.org Original-Sender: "guile-user" Xref: news.gmane.org gmane.lisp.guile.user:15540 gmane.lisp.guile.devel:19948 Archived-At: Hi Linas, Linas Vepstas writes: > I'm trying to understand how scm_jit_enter_mcode leads to > scm_timed_lock_mutex ... This simply means that 'lock-mutex' was called from Scheme, and specifically from Scheme code that has been compiled to machine code by our JIT compiler. > I want to know who is attempting to lock, and why ... and how to work > around this... You'll need to look at the stack frames on the Scheme stack. It can be done from GDB if necessary, but it might be sufficient to use Guile's debugger. My first thought was to suggest ",break lock-mutex", but that doesn't work, presumably because it's a C primitive (although we should fix that), but I was able to patch in a pure Scheme wrapper for it, which then allows us to set a Scheme breakpoint: --8<---------------cut here---------------start------------->8--- mhw@jojen ~/guile-master$ meta/guile GNU Guile 2.9.2.14-1fb399-dirty Copyright (C) 1995-2019 Free Software Foundation, Inc. Guile comes with ABSOLUTELY NO WARRANTY; for details type `,show w'. This program is free software, and you are welcome to redistribute it under certain conditions; type `,show c' for details. Enter `,help' for help. scheme@(guile-user)> ,use (ice-9 threads) scheme@(guile-user)> (define (test n) (par-for-each + (iota n) (iota n))) scheme@(guile-user)> (define core-lock-mutex lock-mutex) scheme@(guile-user)> (set! lock-mutex (lambda* (mutex #:optional timeout) (core-lock-mutex mutex timeout))) scheme@(guile-user)> ,break lock-mutex Trap 0: Breakpoint at #. scheme@(guile-user)> (test 10000) Trap 0: Breakpoint at # Entering a new prompt. Type `,bt' for a backtrace or `,q' to continue. scheme@(guile-user) [1]> ,bt In current input: 2:0 2 (test 10000) In ice-9/threads.scm: 389:6 1 (_ #) In current input: 4:17 0 (lock-mutex #) scheme@(guile-user) [1]> --8<---------------cut here---------------end--------------->8--- Hopefully this should be enough to figure out what's calling 'lock-mutex' in your case. One possibility is that your code is accessing the module table too often. Does your code frequently call procedures like 'resolve-module', 'module-variable', 'module-ref', or any of the other procedures documented in section 6.20.8 (Module System Reflection) of the Guile manual? > I'm using (ice-9 threads) I see this: > > (define (n-par-for-each n proc . arglists) > (let ((m (make-mutex)) > (threads '())) > (do ((i 0 (+ 1 i))) > ((= i n) > (for-each join-thread threads)) > (set! threads > (cons (begin-thread > (let loop () > (lock-mutex m) > (if (null? (car arglists)) > (unlock-mutex m) > (let ((args (map car arglists))) > (set! arglists (map cdr arglists)) > (unlock-mutex m) > (apply proc args) > (loop))))) > threads))))) > > Oh, I says to myself: bad bad mutex. Let me write a lock-less loop: it > chops the list into n pieces, each in its own thread. (a bit sloppy, > but adequate): > > (define (my-for-each n proc args) > (define len (length args)) > (define quo (euclidean-quotient len n)) > (define rem (euclidean-remainder len n)) > (define threads '()) > (do ((i 0 (+ 1 i))) > ((= i n) (for-each join-thread threads)) > (set! threads > (cons > (begin-thread > (for-each proc (take (drop args (* i quo)) quo))) > threads))) > (for-each proc (drop args (* n quo))) > ) > > Let me go hog-wild: (my-for-each 12 proc list) (I have a cpu with that many cores) So... what happens? A little better .. not much. This time, gdb shows that there are four threads in my app. > Two are stuck here: > > #0 __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135 > #1 0x00007f343ca69bb5 in __GI___pthread_mutex_lock ( > mutex=mutex@entry=0x7f343d4f0f40 ) > at ../nptl/pthread_mutex_lock.c:80 > #2 0x00007f343d213e20 in scm_gc_register_allocation (size=size@entry=16) > at ../../libguile/gc.c:591 This is the global GC allocation lock, which might be an issue if your threads are performing a lot of heap allocation. Mark