From mboxrd@z Thu Jan 1 00:00:00 1970 Path: news.gmane.io!.POSTED.blaine.gmane.org!not-for-mail From: Helmut Eller Newsgroups: gmane.emacs.devel Subject: Re: igc, macOS avoiding signals Date: Fri, 03 Jan 2025 19:37:59 +0100 Message-ID: <87pll3ivzs.fsf@gmail.com> References: <799DDBC5-2C14-4476-B1E0-7BA2FE9E7901@toadstyle.org> <87msgdkt29.fsf@gmail.com> <86h66lnjrt.fsf@gnu.org> <868qrxnfrw.fsf@gnu.org> <87a5ccl2zx.fsf@gmail.com> <875xn0p3l1.fsf@protonmail.com> <86ldvwm190.fsf@gnu.org> <87cyh8nczh.fsf@protonmail.com> <867c7fncom.fsf@gnu.org> Mime-Version: 1.0 Content-Type: multipart/mixed; boundary="=-=-=" Injection-Info: ciao.gmane.io; posting-host="blaine.gmane.org:116.202.254.214"; logging-data="28984"; mail-complaints-to="usenet@ciao.gmane.io" User-Agent: Gnus/5.13 (Gnus v5.13) Cc: Pip Cet , gerd.moellmann@gmail.com, spd@toadstyle.org, emacs-devel@gnu.org To: Eli Zaretskii Original-X-From: emacs-devel-bounces+ged-emacs-devel=m.gmane-mx.org@gnu.org Fri Jan 03 19:39:10 2025 Return-path: Envelope-to: ged-emacs-devel@m.gmane-mx.org Original-Received: from lists.gnu.org ([209.51.188.17]) by ciao.gmane.io with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1tTmZi-0007Ng-30 for ged-emacs-devel@m.gmane-mx.org; Fri, 03 Jan 2025 19:39:10 +0100 Original-Received: from localhost ([::1] helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1tTmYm-0007ps-Rz; Fri, 03 Jan 2025 13:38:12 -0500 Original-Received: from eggs.gnu.org ([2001:470:142:3::10]) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1tTmYh-0007pe-TA for emacs-devel@gnu.org; Fri, 03 Jan 2025 13:38:07 -0500 Original-Received: from mail-wr1-x435.google.com ([2a00:1450:4864:20::435]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.90_1) (envelope-from ) id 1tTmYf-0004We-0L; Fri, 03 Jan 2025 13:38:06 -0500 Original-Received: by mail-wr1-x435.google.com with SMTP id ffacd0b85a97d-385d7b4da2bso10621585f8f.1; Fri, 03 Jan 2025 10:38:03 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20230601; t=1735929482; x=1736534282; darn=gnu.org; h=mime-version:user-agent:message-id:date:references:in-reply-to :subject:cc:to:from:from:to:cc:subject:date:message-id:reply-to; bh=Namb+qxfrt0iNyWV/XPoEHgmPyTkCPWKfV+54pEjiM0=; b=QTFik7tprWWEMjsEi4ZkvV/y3t76YFVBnbsx0ZnHEQv4EFCkIPRZv78Nrn2dr9839C 91fUM4IURHUQJUBQGRLJ2zRtZQ9N6JJPgljRXFFX58b5M6TaZKrN57/wfs6VFR8V0nma /bgvVkN35VTqj+2K0OBtqYmKqzIDtGyIgImakYSms8lNDCHedBeKDfDeewAgqU/Hih9Y EsZRPPO15myjZerCPGCDj/f4Ztie9XPcvmUhL8KFyvNQAJFtyMv+EQtgmTzO1CXyDW2e X9hDh8gWA5qtUmxhlSz/H2ruOQgIFeM1JL3JcfoSTfTXOSzPRHiPfyWyc4ucX59FxGfR T46A== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1735929482; x=1736534282; h=mime-version:user-agent:message-id:date:references:in-reply-to :subject:cc:to:from:x-gm-message-state:from:to:cc:subject:date :message-id:reply-to; bh=Namb+qxfrt0iNyWV/XPoEHgmPyTkCPWKfV+54pEjiM0=; b=Xz3vTllAAROMqhFVtH0+WCFV6oTIG9Xu40BUiQLIkvvXb/+RIwCPhCAG/RBkMfV0ZR Vsc+xQ5bltQrOnyp34pBH4FnaYb2gVrOEOkGBjkvgP7JnMUubTHhoPnVWie7u8bv/b0Y k4vzxLweiBrppdSdqTDuaJNn2EIrxNHEBGlDoKuFRceK/P3f1PyFZJ29AVGgE3xDfPZU 91DEBHGv1qxzrjJbe3dXffQAGYqDtXS8I4BRDPQJAjd1kCPBTbSXSVgGrJYnSs92/XGr FeznBd28ZkrVOg/5Ra4WqnRKZ/Myv92Vs32FM68iKche8Qr/H+XwCrS2+47a71d1yJir acfw== X-Forwarded-Encrypted: i=1; AJvYcCX781b3nNAK+RuF9tegVbibXeQqQ9INcsi5xvMnnhuTCqjBkegAkJ9DSt0QEMNXmfKrS7JzcyvbZjjNDw==@gnu.org X-Gm-Message-State: AOJu0YwXj2yqv7OoNkT8n06t7tGdbnIxcFxAFHnHkbcCAxU0OLlVVJdl 5oX/LF7L+nbFY1lGbJ8h3G29h/rjp8+haUy9wogE0rk7JGgYVzRB7Xi/5Q== X-Gm-Gg: ASbGnct2dwrtIfKK7O0H/DPLD5/AhM323DIy/DUwN5Kh7k1+gBR6g1VX/aYvnx/L4uQ m8ajvXyLHAP6dC0EWz9CiCiBPL5oiyAX9XfoJG8zC07vq9kjwm4tU1LSFDMA/yUkomnhv2ya3Pc EzD+SuKZ+ZcQrPB1n3EmBmicWT4hCX2H70mbgqaVqkDsnfFt/fxrWNmrEIQhzu+tp1IUP1bMqA3 kzakmhQCMrdy1rCvk+0uxFZUA5lsC4lAKjM1BDnCRib/AB3uzbPRA== X-Google-Smtp-Source: AGHT+IE6szDoGrdKiVtkKJvGAhtcyWo7fW8OqQ6JFZJXuNnf8Z6wQ6uiQWP88D7MgdsnkPmOuqoUWw== X-Received: by 2002:a5d:64c8:0:b0:386:43c9:3ac2 with SMTP id ffacd0b85a97d-38a221ea74cmr43814731f8f.15.1735929481894; Fri, 03 Jan 2025 10:38:01 -0800 (PST) Original-Received: from caladan ([89.107.106.84]) by smtp.gmail.com with ESMTPSA id ffacd0b85a97d-38a1c8472casm41985975f8f.45.2025.01.03.10.38.00 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Fri, 03 Jan 2025 10:38:00 -0800 (PST) In-Reply-To: <867c7fncom.fsf@gnu.org> (Eli Zaretskii's message of "Tue, 31 Dec 2024 16:34:49 +0200") Received-SPF: pass client-ip=2a00:1450:4864:20::435; envelope-from=eller.helmut@gmail.com; helo=mail-wr1-x435.google.com X-Spam_score_int: -20 X-Spam_score: -2.1 X-Spam_bar: -- X-Spam_report: (-2.1 / 5.0 requ) BAYES_00=-1.9, DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, DKIM_VALID_EF=-0.1, FREEMAIL_FROM=0.001, RCVD_IN_DNSWL_NONE=-0.0001, SPF_HELO_NONE=0.001, SPF_PASS=-0.001 autolearn=ham autolearn_force=no X-Spam_action: no action X-BeenThere: emacs-devel@gnu.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: "Emacs development discussions." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: emacs-devel-bounces+ged-emacs-devel=m.gmane-mx.org@gnu.org Original-Sender: emacs-devel-bounces+ged-emacs-devel=m.gmane-mx.org@gnu.org Xref: news.gmane.io gmane.emacs.devel:327633 Archived-At: --=-=-= Content-Type: text/plain On Tue, Dec 31 2024, Eli Zaretskii wrote: > We'd need to add a new function to process_pending_signals, which > would process SIGPROF and maybe also SIGALRM. The signal handlers for > those would then only set a flag (not pending_signals, some other > flag). I implemented this with the two attached patches. The trouble is that, the recorded backtraces are not same. This can be seen by looking at the call tree produced by profiler.el and the attached profiler-test.el. When add_sample is called in the signal handler, then the call tree for the foo example looks so: ... 1986 100% main 1986 100% record-samples 1986 100% foo 1074 54% float-time 0 0% ... When add_sample is called from process_pending_signals, it looks like this: ... 1986 100% main 1986 100% record-samples 1986 100% foo 0 0% ... Not the absence of float-time. The reason for this is, that in bytecode.c, maybe_quit is called before the function is pushed to the backtrace with record_in_backtrace. In the second patch, I moved this call forward to before the function is popped with lisp_eval_depth--. With this patch, the call tree includes float-time again: ... 1989 100% main 1989 100% record-samples 1989 100% foo 1981 99% float-time 0 0% ... However, float-time has now 99% as opposed to 54% in the first call tree. A more complex pair of call trees is attached in the files bar-0.report and bar-2.report. A significant difference there is in this section: ... 781 73% animate-place-char 19 1% delete-char 16 1% floor 4 0% undo-auto--undoable-change 4 0% undo-auto--boundary-ensure-timer 96 9% insert-char 14 1% undo-auto--undoable-change 6 0% undo-auto--boundary-ensure-timer 5 0% beginning-of-line 232 21% move-to-column ... compared to the version with both patches applied: ... 693 72% animate-place-char 32 3% delete-char 29 3% window-start 43 4% insert-char 309 32% move-to-column 222 23% beginning-of-line 8 0% undo-auto--undoable-change 8 0% undo-auto--boundary-ensure-timer 8 0% run-at-time 8 0% timer-set-function 8 0% timerp 8 0% vectorp ... E.g. the percentage attributed to beginning-of-line is quite different in those two versions (23% and 0%). I'm not sure if those differences are acceptable. I also have no good idea how to reduce it, except inserting more calls to maybe_quit. (In eval_sub and Ffuncall, it would also help the profiler to move the maybe_quit call forward before lisp_eval_depth--. This would only matter for interpreted functions, not in byte compiled code. Curiously, apply_lambda doesn't call maybe_quit at all.) Helmut --=-=-= Content-Type: text/x-diff Content-Disposition: attachment; filename=0001-Delay-processing-of-SIGPROF-to-the-next-safepoint.patch >From ed26a2e8fc92a321f0afeb38c1f88db46ec957a6 Mon Sep 17 00:00:00 2001 From: Helmut Eller Date: Fri, 3 Jan 2025 17:27:10 +0100 Subject: [PATCH 1/2] Delay processing of SIGPROF to the next safepoint * src/lisp.h (process_pending_profiler_signals): New function. * src/profiler.c (pending_profiler_signals): New variable. (handle_profiler_signal): Instead of calling add_sample, set pending_signals and increment pending_profiler_signals. (process_pending_profiler_signals): New function. * src/keyboard.c (process_pending_signals): Call process_pending_profiler_signals. --- src/keyboard.c | 1 + src/lisp.h | 1 + src/profiler.c | 17 ++++++++++++++++- 3 files changed, 18 insertions(+), 1 deletion(-) diff --git a/src/keyboard.c b/src/keyboard.c index e875e98fde6..5d6cebdc990 100644 --- a/src/keyboard.c +++ b/src/keyboard.c @@ -8191,6 +8191,7 @@ process_pending_signals (void) handle_async_input (); do_pending_atimers (); do_async_work (); + process_pending_profiler_signals (); } /* Undo any number of BLOCK_INPUT calls down to level LEVEL, diff --git a/src/lisp.h b/src/lisp.h index 48585c2d8a1..774667a4f9c 100644 --- a/src/lisp.h +++ b/src/lisp.h @@ -5938,6 +5938,7 @@ maybe_disable_address_randomization (int argc, char **argv) extern void malloc_probe (size_t); extern void syms_of_profiler (void); extern void mark_profiler (void); +extern void process_pending_profiler_signals (void); #ifdef DOS_NT diff --git a/src/profiler.c b/src/profiler.c index 3db7fe0eb3e..47367982cab 100644 --- a/src/profiler.c +++ b/src/profiler.c @@ -387,6 +387,9 @@ add_sample (struct profiler_log *plog, EMACS_INT count) /* Hash-table log of CPU profiler. */ static struct profiler_log cpu; +/* Number of unprocessed profiler signals. */ +static uintptr_t pending_profiler_signals; + /* The current sampling interval in nanoseconds. */ static EMACS_INT current_sampling_interval; @@ -402,7 +405,19 @@ handle_profiler_signal (int signal) count += overruns; } #endif - add_sample (&cpu, count); + pending_signals = true; + pending_profiler_signals += count; +} + +void +process_pending_profiler_signals (void) +{ + uintptr_t count = pending_profiler_signals; + if (count) + { + pending_profiler_signals = 0; + add_sample (&cpu, count); + } } static void -- 2.39.5 --=-=-= Content-Type: text/x-diff Content-Disposition: attachment; filename=0002-Call-maybe_quit-at-a-different-point-to-the-help-the.patch >From ec3227c060f12ca137b5a5bd1e607b922a6dafec Mon Sep 17 00:00:00 2001 From: Helmut Eller Date: Fri, 3 Jan 2025 18:12:41 +0100 Subject: [PATCH 2/2] Call maybe_quit at a different point to the help the profiler. * src/bytecode.c (exec_byte_code): In the docall sequence, move the to maybe_quit forward immediately before lisp_eval_depth--. This helps the profiler to see the function that was interrupted by the SIGPROF signal. --- src/bytecode.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/bytecode.c b/src/bytecode.c index 31f7404cbd1..53c200e2c18 100644 --- a/src/bytecode.c +++ b/src/bytecode.c @@ -784,7 +784,6 @@ #define DEFINE(name, value) [name] = &&insn_ ## name, } } #endif - maybe_quit (); if (++lisp_eval_depth > max_lisp_eval_depth) { @@ -829,6 +828,7 @@ #define DEFINE(name, value) [name] = &&insn_ ## name, else val = funcall_general (original_fun, call_nargs, call_args); + maybe_quit (); lisp_eval_depth--; if (backtrace_debug_on_exit (specpdl_ptr - 1)) val = call_debugger (list2 (Qexit, val)); -- 2.39.5 --=-=-= Content-Type: application/emacs-lisp Content-Disposition: attachment; filename=profiler-test.el Content-Transfer-Encoding: quoted-printable ;; -*- lexical-binding: t = -*- (require 'profiler) (require 'cl-lib) (defun foo () (let ((start (float-time))) (while (< (- (float-time) start) 1) )) nil) (defun bar () (animate-birthday-present "----")) (defun record-samples (sampling-interval fun) (profiler-cpu-start sampling-interval) (funcall fun) (profiler-cpu-stop) (profiler-cpu-log)) (defun print-calltree (tree depth) (princ (format "%8d %4s %s%s\n" (profiler-calltree-count tree) (profiler-calltree-count-percent tree) (make-string (* depth 2) ?\ ) (profiler-calltree-entry tree))) (let ((children (profiler-calltree-children tree))) (dolist (child children) (print-calltree child (1+ depth))))) (defun save-samples (log filename) (with-temp-file filename (let (print-level print-length) (print log (current-buffer))))) (defun load-samples (filename) (with-temp-buffer (insert-file-contents filename) (goto-char (point-min)) (read (current-buffer)))) (defun usage () (princ "Usage: emacs -batch -l profler-test -f main CMD where CMD is one of record FUNCTION FILENAME -- call FUNCTION and write samples to FILENAME report FILENAME -- print call tree for samples in FILENAME ")) (defun main () (pcase-exhaustive command-line-args-left (`("record" ,function-name ,filename) (let ((log (record-samples 500000 (intern function-name)))) (save-samples log filename))) (`("report" ,filename) (let* ((log (load-samples filename)) (calltree (profiler-calltree-build log))) (print-calltree calltree 0))) (_ (usage)))) --=-=-= Content-Type: text/plain Content-Disposition: attachment; filename=bar-0.report 0 0% nil 1056 100% normal-top-level 1056 100% command-line 1056 100% command-line-1 1056 100% main 1056 100% record-samples 1056 100% bar 1056 100% animate-birthday-present 1046 99% animate-string 61 5% sit-for 61 5% sleep-for 805 76% animate-step 781 73% animate-place-char 19 1% delete-char 16 1% floor 4 0% undo-auto--undoable-change 4 0% undo-auto--boundary-ensure-timer 96 9% insert-char 14 1% undo-auto--undoable-change 6 0% undo-auto--boundary-ensure-timer 5 0% beginning-of-line 232 21% move-to-column 132 12% primitive-undo 6 0% undo-auto--undoable-change 10 0% capitalize 10 0% load-with-code-conversion 8 0% hack-read-symbol-shorthands 8 0% hack-local-variables--find-variables 8 0% search-backward 2 0% generate-new-buffer 2 0% get-buffer-create 0 0% ... --=-=-= Content-Type: text/plain Content-Disposition: attachment; filename=bar-2.report 0 0% nil 959 100% normal-top-level 959 100% command-line 959 100% command-line-1 959 100% main 959 100% record-samples 959 100% bar 959 100% animate-birthday-present 953 99% animate-string 12 1% animate-initialize 12 1% window-width 139 14% sit-for 139 14% sleep-for 109 11% primitive-undo 15 1% markerp 32 3% abs 693 72% animate-step 693 72% animate-place-char 32 3% delete-char 29 3% window-start 43 4% insert-char 309 32% move-to-column 222 23% beginning-of-line 8 0% undo-auto--undoable-change 8 0% undo-auto--boundary-ensure-timer 8 0% run-at-time 8 0% timer-set-function 8 0% timerp 8 0% vectorp 6 0% capitalize 6 0% load-with-code-conversion 6 0% eval-buffer 6 0% read 0 0% ... --=-=-=--